Windows: --cpuclock-test fails on HP workstation with 32 cores (2 socket)

[bcran]

On my HP Z820 workstation, FIO 3.0 running on Windows fails the cpuclock-test, reporting:

...
cs: CPU clock mismatch (diff=2):
         CPU 14: TSC=692869176424707, SEQ=8312573
         CPU 15: TSC=692869176424705, SEQ=8312574
cs: CPU clock mismatch (diff=2):
         CPU 14: TSC=692869176425439, SEQ=8312589
         CPU 15: TSC=692869176425437, SEQ=8312590
cs: CPU clock mismatch (diff=5):
         CPU 14: TSC=692869176573058, SEQ=8314218
         CPU 15: TSC=692869176573053, SEQ=8314219
cs: CPU clock mismatch (diff=5):
         CPU 14: TSC=692869176702281, SEQ=8315615
         CPU 15: TSC=692869176702276, SEQ=8315616
cs: CPU clock mismatch (diff=5):
         CPU 14: TSC=692869176702833, SEQ=8315631
         CPU 15: TSC=692869176702828, SEQ=8315632
cs: CPU clock mismatch (diff=2):
         CPU 14: TSC=692869176703270, SEQ=8315643
         CPU 15: TSC=692869176703268, SEQ=8315644
cs: CPU clock mismatch (diff=2):
         CPU 14: TSC=692869176703568, SEQ=8315651
         CPU 15: TSC=692869176703566, SEQ=8315652
cs: CPU clock mismatch (diff=2):
         CPU 14: TSC=692869176832103, SEQ=8317036
         CPU 15: TSC=692869176832101, SEQ=8317037
cs: CPU clock mismatch (diff=5):
         CPU 14: TSC=692869176976504, SEQ=8318620
         CPU 15: TSC=692869176976499, SEQ=8318621
cs: CPU clock mismatch (diff=5):
         CPU 14: TSC=692869176976740, SEQ=8318626
         CPU 15: TSC=692869176976735, SEQ=8318627
cs: CPU clock mismatch (diff=5):
         CPU 14: TSC=692869177078556, SEQ=8319747
         CPU 15: TSC=692869177078551, SEQ=8319748
cs: Failed: 25318

[sitsofe]

@bcran Do you have hyperthreading turned on?

[bcran]

@sitsofe Yes, I do. The CPU configuration is:

	Number of cores		8 (max 8)
	Number of threads	16 (max 16)
	Name			Intel Xeon E5 2687W
	Codename		Sandy Bridge-EP/EX
	Specification		Intel(R) Xeon(R) CPU E5-2687W 0 @ 3.10GHz
	Package (platform ID)	Socket 2011 LGA (0x0)
	CPUID			6.D.7
	Extended CPUID		6.2D
	Core Stepping		C2
	Technology		32 nm
	TDP Limit		150.0 Watts
	Tjmax			92.0 °C
	Core Speed		3490.4 MHz
	Multiplier x Bus Speed	35.0 x 99.7 MHz
	Rated Bus speed		3989.0 MHz
	Stock frequency		3100 MHz
	Instructions sets	MMX, SSE, SSE2, SSE3, SSSE3, SSE4.1, SSE4.2, EM64T, VT-x, AES, AVX
	L1 Data cache		8 x 32 KBytes, 8-way set associative, 64-byte line size
	L1 Instruction cache	8 x 32 KBytes, 8-way set associative, 64-byte line size
	L2 cache		8 x 256 KBytes, 8-way set associative, 64-byte line size
	L3 cache		20 MBytes, 20-way set associative, 64-byte line size
	Max CPUID level		0000000Dh
	Max CPUID ext. level	80000008h
	Cache descriptor	Level 1, D, 32 KB, 2 thread(s)
	Cache descriptor	Level 1, I, 32 KB, 2 thread(s)
	Cache descriptor	Level 2, U, 256 KB, 2 thread(s)
	Cache descriptor	Level 3, U, 20 MB, 32 thread(s)
	FID/VID Control		yes

[sitsofe]

Can you include the first few lines of cpuclock-test that talk about whether reliable_tsc is yes or no?

[bcran]

cs: reliable_tsc: yes
...
cs: Testing 32 CPUs
cs: cpu 30: 482045631 clocks seen, first 781860601663043
cs: cpu 25: 517951112 clocks seen, first 781860600429191
cs: cpu 24: 527388014 clocks seen, first 781860600260528
cs: cpu 21: 561430587 clocks seen, first 781860599799415
cs: cpu 26: 566856836 clocks seen, first 781860600566208
cs: cpu 27: 567955476 clocks seen, first 781860600764701
cs: cpu 29: 570438854 clocks seen, first 781860601223275
cs: cpu 28: 571304911 clocks seen, first 781860600892701
cs: cpu 20: 590085230 clocks seen, first 781860599597046
cs: cpu 31: 470144099 clocks seen, first 781860721893516
cs: cpu 17: 595590266 clocks seen, first 781860599016974
cs: cpu 19: 595545700 clocks seen, first 781860599427562
cs: cpu 18: 596322495 clocks seen, first 781860599213531
cs: cpu 16: 598410097 clocks seen, first 781860598765454
cs: cpu 23: 597406890 clocks seen, first 781860600107847
cs: cpu 22: 597636219 clocks seen, first 781860599928106
cs: cpu 11: 867388125 clocks seen, first 781860597183359
cs: cpu 13: 876457987 clocks seen, first 781860597615213
cs: cpu 10: 881324131 clocks seen, first 781860596858673
cs: cpu 15: 890661688 clocks seen, first 781860598594096
cs: cpu 12: 895911169 clocks seen, first 781860597384801
cs: cpu 14: 907898243 clocks seen, first 781860598006249
cs: cpu  3: 937044907 clocks seen, first 781860593099862
cs: cpu  2: 939007077 clocks seen, first 781860592725417
cs: cpu  1: 940324144 clocks seen, first 781860592116906
cs: cpu  0: 945839445 clocks seen, first 781860591614617
cs: cpu  4: 946174362 clocks seen, first 781860593499790
cs: cpu  5: 945259406 clocks seen, first 781860594496926
cs: cpu  7: 945756981 clocks seen, first 781860595489191
cs: cpu  6: 947376861 clocks seen, first 781860595066787
cs: cpu  8: 946507278 clocks seen, first 781860595972986
cs: cpu  9: 946232944 clocks seen, first 781860596380291
cs: CPU clock mismatch (diff=4):
         CPU 16: TSC=781860599035112, SEQ=89366
         CPU 17: TSC=781860599035108, SEQ=89367
cs: CPU clock mismatch (diff=7):
         CPU 16: TSC=781860599063142, SEQ=89556
         CPU 17: TSC=781860599063135, SEQ=89557
cs: CPU clock mismatch (diff=1):
         CPU 16: TSC=781860599071264, SEQ=89608
         CPU 17: TSC=781860599071263, SEQ=89609
cs: CPU clock mismatch (diff=4):
         CPU 16: TSC=781860599092350, SEQ=89752
         CPU 17: TSC=781860599092346, SEQ=89753
...

[bcran]

Disabling hyperthreading causes it to pass most times, but it still occasionally fails (twice in twenty runs just now).

[bcran]

I've also run fio-3.0 on the same hardware under Linux (openSUSE). In that environment, it passes every time.

[sitsofe]

I'm starting to wonder if it's got something to do with the number of CPUs being used and the scheduling order created by the OS' scheduler. Across multiple runs do you find it is always the same CPUs (e.g. CPU 16/CPU 17) that the failure is reported on?

[sitsofe]

@bcran could you see if https://github.com/sitsofe/fio/tree/cycletest is any good for you? If so I'll open a pull request.

[sitsofe]

Note that the branch changes the logic associated with seq wraparound - it could be I've misinterpreted how to cope with that...

[bcran]

That branch does seem to fix the problem - I saw no failures on over 25 runs.
Thanks!

[sitsofe]

Frustratingly the branch doesn't seem to fix the problem, only make it less frequent. Using the following shows the problem is still there (but it can take over 30 iterations before the problem appears):

cls; $c=0; $LASTEXITCODE=0; while ($LASTEXITCODE -eq 0) { fio.exe --cpuclock-test; $c+=1 }; write-host $c

[axboe]

Looks to me like all that's missing is actually a memory syncronization at the end of the while loop. But I think the compare-and-exchange is a better approach, so we should switch to that.

Can both of you try my cpuclock-test branch? It's just this single patch on top of master:

http://git.kernel.dk/cgit/fio/commit/?h=cpuclock-test&id=a250edd0678ac6aef34bfbd01423a7b87a1d5f8d

I've tested it on my laptop, test box, and two development skylake boxes. Don't see any failures, but on the other hand, neither of them had any failures with the existing code... So that may not mean a lot.

[sitsofe]

@axboe Kudos to you Jens - your solution is both faster AND more correct than my attempts. I'm above 600 runs and no problems reported.

[axboe]

Thanks for testing! I'm going to pull this in.

[bcran]

Work here too. Thanks!