> -----Original Message----- > From: Jens Axboe [mailto:axboe@xxxxxxxxx] > Sent: Tuesday, 16 December, 2014 11:43 PM ... > > (gdb) print td->tv_cache > > $51 = {tv_sec = 1099511, tv_usec = 641885} > ^^^^^^^ > > This is the key. If this multiplication overflows: > > usecs = (t * inv_cycles_per_usec) / 16777216UL; > > then usecs is 2^64/2^24, which is 1099511627776. Divide that by 10^6 to > get seconds, and that is 1099511... I initially thought this was a buggy > backwards timer, but it's just this overflow. Fix: > > http://git.kernel.dk/?p=fio.git;a=commit;h=b3fa625b38a638cd1783e9fdcac1b95 > 8e37e48fa Good find. The 64-bit RDTSC won't wrap for over 10 years, but that multiplication must be stealing too many bits. fio --debug=time shows this: time 28459 inv_cycles_per_usec=8397 Is anything in the linux kernel susceptible to a similar problem? Anyway, I detached gdb and hit ^C to terminate fio, confirming that the 64-bit counters are working - it's reporting more than 4B IOs for devices now: * total IOs: 572,018,473,400 * 15 devices: 37,703,868,929 (example) * (1 device (sdi) is lower, but fio gave up on it after IO errors) drive_b: (groupid=0, jobs=224): err= 5 (file:io_u.c:1534, func=io_u error, error=Input/output error): pid=6510: Wed Dec 17 10:30:44 2014 read : io=272760GB, bw=4102.9MB/s, iops=8402.7K, runt=68076097msec cpu : usr=0.78%, sys=37.24%, ctx=401925558097, majf=0, minf=2927 IO depths : 1=0.0%, 2=0.1%, 4=0.1%, 8=0.3%, 16=0.4%, 32=0.6%, >=64=0.3% submit : 0=0.0%, 4=5.8%, 8=0.6%, 16=3.4%, 32=0.0%, 64=0.0%, >=64=0.0% complete : 0=0.0%, 4=0.0%, 8=0.0%, 16=5.4%, 32=0.1%, 64=0.1%, >=64=0.1% issued : total=r=572018473400/w=0/d=0, short=r=0/w=0/d=0, drop=r=0/w=0/d=0 latency : target=0, window=0, percentile=100.00%, depth=96 Run status group 0 (all jobs): READ: io=272760GB, aggrb=4102.9MB/s, minb=4102.9MB/s, maxb=4102.9MB/s, mint=68076097msec, maxt=68076097msec Disk stats (read/write): sdb: ios=37703868929/0, merge=0/0, ticks=68454382/0, in_queue=129910494, util=100.00% sdc: ios=37712378473/0, merge=0/0, ticks=77399794/0, in_queue=119899831, util=100.00% sdd: ios=37707967388/0, merge=0/0, ticks=75432313/0, in_queue=187703422, util=100.00% sde: ios=37698239552/0, merge=0/0, ticks=68544916/0, in_queue=179384002, util=100.00% sdf: ios=37716299315/0, merge=0/0, ticks=84593922/0, in_queue=199961411, util=100.00% sdg: ios=37699099568/0, merge=0/0, ticks=75257519/0, in_queue=175502802, util=100.00% sdh: ios=37701332642/0, merge=0/0, ticks=74572660/0, in_queue=192088623, util=100.00% sdi: ios= 2218175796/0, merge=0/0, ticks=2303073961/0, in_queue=2306683517, util=86.68% sdj: ios=37707221334/0, merge=0/0, ticks=78701197/0, in_queue=180717546, util=100.00% sdk: ios=37698155959/0, merge=0/0, ticks=77357378/0, in_queue=187489699, util=100.00% sdl: ios=37692589221/0, merge=0/0, ticks=75227670/0, in_queue=186780751, util=100.00% sdm: ios=37692481205/0, merge=0/0, ticks=73056936/0, in_queue=187474248, util=100.00% sdn: ios=37695237426/0, merge=0/0, ticks=77270328/0, in_queue=191649153, util=100.00% sdo: ios=37688493826/0, merge=0/0, ticks=72485901/0, in_queue=182735443, util=100.00% sdp: ios=39851839290/0, merge=0/0, ticks=48724465/0, in_queue=139505151, util=100.00% sdq: ios=39835069533/0, merge=0/0, ticks=44151762/0, in_queue=136927387, util=100.00% -- To unsubscribe from this list: send the line "unsubscribe fio" in the body of a message to majordomo@xxxxxxxxxxxxxxx More majordomo info at http://vger.kernel.org/majordomo-info.html
