blktrace -n 64 -b 16384 -d /dev/vdisks/kernel3 -o - | blkparse -i - 254,25 1 1 0.000000000 0 C WS 33403560 + 152 [0] ^C254,25 1 0 0.000122104 0 m N throtl /notimportant [W] bio. bdisp=798144 sz=245760 bps=10000000 iodisp=3 iops=4294967295 queued=0/143 254,25 1 0 0.000140283 0 m N throtl /notimportant [W] bio. bdisp=798144 sz=245760 bps=10000000 iodisp=3 iops=4294967295 queued=0/144 254,25 1 0 0.000156251 0 m N throtl /notimportant [W] bio. bdisp=798144 sz=155648 bps=10000000 iodisp=3 iops=4294967295 queued=0/145 254,25 1 2 0.000157274 3753 U N [qemu-kvm] 0 254,25 1 3 0.000295027 0 C WS 33403712 + 480 [0] 254,25 1 4 0.000316287 0 C WS 33404192 + 480 [0] 254,25 1 5 0.000434196 0 C WS 33404672 + 480 [0] 254,25 3 0 0.000760552 0 m N throtl /notimportant [W] bio. bdisp=798144 sz=245760 bps=10000000 iodisp=3 iops=4294967295 queued=0/146 254,25 3 0 0.000775394 0 m N throtl /notimportant [W] bio. bdisp=798144 sz=192512 bps=10000000 iodisp=3 iops=4294967295 queued=0/147 254,25 3 6 0.000776845 3814 U N [qemu-kvm] 0 254,25 3 0 0.099825192 0 m N throtl dispatch nr_queued=148 read=0 write=148 254,25 3 0 0.099828429 0 m N throtl /notimportant [W] extend slice start=4295010014 end=4295010075 jiffies=4295010040 254,25 3 0 0.099831100 0 m N throtl /notimportant [W] trim slice nr=1 bytes=1000000 io=429496729 start=4295010039 end=4295010075 jiffies=4295010040 254,25 3 0 0.099833751 0 m N throtl bios disp=5 254,25 3 0 0.099835752 0 m N throtl schedule work. delay=27 jiffies=4295010040 254,25 3 7 0.099838159 485 Q WS 33405152 + 480 [kworker/3:1] 254,25 3 8 0.099856682 485 Q WS 33405632 + 480 [kworker/3:1] 254,25 3 9 0.099861824 485 Q WS 33406112 + 256 [kworker/3:1] 254,25 3 10 0.099900841 485 Q WS 33406368 + 480 [kworker/3:1] 254,25 3 11 0.099910061 485 Q WS 33406848 + 480 [kworker/3:1] 254,25 3 12 0.099935372 485 U N [kworker/3:1] 0 254,25 1 6 0.100349152 0 C WS 33405632 + 480 [0] 254,25 1 7 0.100354988 0 C WS 33405152 + 480 [0] 254,25 1 8 0.100836456 0 C WS 33406368 + 480 [0] 254,25 1 9 0.100842199 0 C WS 33406848 + 480 [0] 254,25 1 10 0.100845180 0 C WS 33406112 + 256 [0] 254,25 1 0 0.100933070 0 m N throtl /notimportant [W] bio. bdisp=912256 sz=4096 bps=10000000 iodisp=4 iops=4294967295 queued=0/143 254,25 1 11 0.100934493 3754 U N [qemu-kvm] 0 254,25 3 0 0.207812916 0 m N throtl dispatch nr_queued=144 read=0 write=144 254,25 3 0 0.207815442 0 m N throtl /notimportant [W] extend slice start=4295010039 end=4295010100 jiffies=4295010067 254,25 3 0 0.207817686 0 m N throtl /notimportant [W] trim slice nr=1 bytes=1000000 io=429496729 start=4295010064 end=4295010100 jiffies=4295010067 254,25 3 0 0.207820439 0 m N throtl bios disp=6 254,25 3 0 0.207822168 0 m N throtl schedule work. delay=23 jiffies=4295010067 254,25 3 13 0.207823157 485 Q WS 33407328 + 480 [kworker/3:1] 254,25 3 14 0.207830523 485 Q WS 33407808 + 48 [kworker/3:1] 254,25 3 15 0.207833596 485 Q WS 33407864 + 480 [kworker/3:1] 254,25 3 16 0.207837361 485 Q WS 33408344 + 480 [kworker/3:1] 254,25 3 17 0.207841101 485 Q WS 33408824 + 56 [kworker/3:1] 254,25 3 18 0.207844084 485 Q WS 33408880 + 144 [kworker/3:1] 254,25 3 19 0.207848057 485 U N [kworker/3:1] 0 254,25 1 12 0.218236185 0 C WS 33407808 + 48 [0] 254,25 1 13 0.218249222 0 C WS 33407328 + 480 [0] 254,25 1 14 0.218288739 3659 C WS 33407864 + 480 [0] 254,25 3 0 0.218331025 0 m N throtl /notimportant [W] bio. bdisp=776512 sz=245760 bps=10000000 iodisp=5 iops=4294967295 queued=0/138 254,25 3 0 0.218348178 0 m N throtl /notimportant [W] bio. bdisp=776512 sz=245760 bps=10000000 iodisp=5 iops=4294967295 queued=0/139 254,25 3 0 0.218365013 0 m N throtl /notimportant [W] bio. bdisp=776512 sz=245760 bps=10000000 iodisp=5 iops=4294967295 queued=0/140 254,25 3 0 0.218380791 0 m N throtl /notimportant [W] bio. bdisp=776512 sz=245760 bps=10000000 iodisp=5 iops=4294967295 queued=0/141 254,25 3 0 0.218396397 0 m N throtl /notimportant [W] bio. bdisp=776512 sz=245760 bps=10000000 iodisp=5 iops=4294967295 queued=0/142 254,25 3 0 0.218412518 0 m N throtl /notimportant [W] bio. bdisp=776512 sz=245760 bps=10000000 iodisp=5 iops=4294967295 queued=0/143 254,25 3 0 0.218418538 0 m N throtl /notimportant [W] bio. bdisp=776512 sz=77824 bps=10000000 iodisp=5 iops=4294967295 queued=0/144 254,25 3 20 0.218419836 3755 U N [qemu-kvm] 0 254,25 1 15 0.219849783 0 C WS 33408824 + 56 [0] 254,25 1 16 0.219850886 0 C WS 33408880 + 144 [0] 254,25 1 17 0.219867346 0 C WS 33408344 + 480 [0] 254,25 3 0 0.219924854 0 m N throtl /notimportant [W] bio. bdisp=776512 sz=8192 bps=10000000 iodisp=5 iops=4294967295 queued=0/145 254,25 3 21 0.219930309 3756 U N [qemu-kvm] 0 254,25 1 0 0.219943422 0 m N throtl /notimportant [W] bio. bdisp=776512 sz=245760 bps=10000000 iodisp=5 iops=4294967295 queued=0/146 254,25 1 0 0.219969139 0 m N throtl /notimportant [W] bio. bdisp=776512 sz=245760 bps=10000000 iodisp=5 iops=4294967295 queued=0/147 254,25 1 0 0.219985715 0 m N throtl /notimportant [W] bio. bdisp=776512 sz=245760 bps=10000000 iodisp=5 iops=4294967295 queued=0/148 254,25 1 0 0.220001491 0 m N throtl /notimportant [W] bio. bdisp=776512 sz=245760 bps=10000000 iodisp=5 iops=4294967295 queued=0/149 254,25 1 0 0.220017719 0 m N throtl /notimportant [W] bio. bdisp=776512 sz=245760 bps=10000000 iodisp=5 iops=4294967295 queued=0/150 254,25 1 0 0.220034195 0 m N throtl /notimportant [W] bio. bdisp=776512 sz=245760 bps=10000000 iodisp=5 iops=4294967295 queued=0/151 254,25 1 0 0.220039806 0 m N throtl /notimportant [W] bio. bdisp=776512 sz=77824 bps=10000000 iodisp=5 iops=4294967295 queued=0/152 254,25 1 18 0.220040765 3757 U N [qemu-kvm] 0 254,25 3 0 0.299819416 0 m N throtl dispatch nr_queued=153 read=0 write=153 254,25 3 0 0.299821891 0 m N throtl /notimportant [W] extend slice start=4295010064 end=4295010125 jiffies=4295010090 254,25 3 0 0.299824342 0 m N throtl /notimportant [W] trim slice nr=1 bytes=1000000 io=429496729 start=4295010089 end=4295010125 jiffies=4295010090 254,25 3 0 0.299826876 0 m N throtl bios disp=5 254,25 3 0 0.299828406 0 m N throtl schedule work. delay=25 jiffies=4295010090 254,25 3 22 0.299829722 485 Q WS 33411584 + 480 [kworker/3:1] 254,25 3 23 0.343892373 485 Q WS 33412064 + 480 [kworker/3:1] 254,25 3 24 0.343902311 485 Q WS 33412544 + 480 [kworker/3:1] 254,25 3 25 0.343905823 485 Q WS 33413024 + 480 [kworker/3:1] 254,25 3 26 0.343909295 485 Q WS 33413504 + 104 [kworker/3:1] 254,25 3 27 0.343912320 485 U N [kworker/3:1] 0 254,25 1 19 0.385082759 0 C WS 33412064 + 480 [0] 254,25 1 20 0.385095303 0 C WS 33411584 + 480 [0] 254,25 1 21 0.385972488 0 C WS 33413024 + 480 [0] 254,25 1 22 0.385989075 0 C WS 33413504 + 104 [0] 254,25 1 23 0.386003645 0 C WS 33412544 + 480 [0] 254,25 3 0 0.386076045 0 m N throtl /notimportant [W] bio. bdisp=812800 sz=245760 bps=10000000 iodisp=4 iops=4294967295 queued=0/148 254,25 3 0 0.386094537 0 m N throtl /notimportant [W] bio. bdisp=812800 sz=245760 bps=10000000 iodisp=4 iops=4294967295 queued=0/149 254,25 3 0 0.386112874 0 m N throtl /notimportant [W] bio. bdisp=812800 sz=245760 bps=10000000 iodisp=4 iops=4294967295 queued=0/150 254,25 3 0 0.386130213 0 m N throtl /notimportant [W] bio. bdisp=812800 sz=245760 bps=10000000 iodisp=4 iops=4294967295 queued=0/151 254,25 3 0 0.386140202 0 m N throtl /notimportant [W] bio. bdisp=812800 sz=94208 bps=10000000 iodisp=4 iops=4294967295 queued=0/152 254,25 3 28 0.386141308 3758 U N [qemu-kvm] 0 254,25 3 0 0.465033350 0 m N throtl dispatch nr_queued=153 read=0 write=153 254,25 3 0 0.465035309 0 m N throtl /notimportant [W] new slice start=4295010131 end=4295010156 jiffies=4295010131 254,25 3 0 0.465037689 0 m N throtl bios disp=4 254,25 3 0 0.465039514 0 m N throtl schedule work. delay=30 jiffies=4295010131 254,25 3 29 0.465040021 485 Q WS 33413608 + 480 [kworker/3:1] 254,25 3 30 0.465044569 485 Q WS 33414088 + 480 [kworker/3:1] 254,25 3 31 0.465050773 485 Q WS 33414568 + 480 [kworker/3:1] 254,25 3 32 0.465055521 485 Q WS 33415048 + 480 [kworker/3:1] 254,25 3 33 0.465059274 485 U N [kworker/3:1] 0 254,25 3 0 1266874889.709370470 0 m N throtl dispatch nr_queued=147 read=0 write=147 254,25 3 0 1266874889.709373700 0 m N throtl /notimportant [W] extend slice start=4295009989 end=4295010050 jiffies=4295010015 254,25 3 0 1266874889.709376574 0 m N throtl /notimportant [W] trim slice nr=1 bytes=1000000 io=429496729 start=4295010014 end=4295010050 jiffies=4295010015 254,25 3 0 1266874889.709378973 0 m N throtl bios disp=4 254,25 3 0 1266874889.709380910 0 m N throtl schedule work. delay=25 jiffies=4295010015 254,25 3 1 1266874889.709382849 485 Q WS 33403560 + 152 [kworker/3:1] 254,25 3 2 1266874889.709407336 485 Q WS 33403712 + 480 [kworker/3:1] 254,25 3 3 1266874889.709411964 485 Q WS 33404192 + 480 [kworker/3:1] 254,25 3 4 1266874889.709416459 485 Q WS 33404672 + 480 [kworker/3:1] 254,25 3 5 1266874889.709419852 485 U N [kworker/3:1] 0 CPU1 (254,25): Reads Queued: 0, 0KiB Writes Queued: 0, 0KiB Read Dispatches: 0, 0KiB Write Dispatches: 0, 0KiB Reads Requeued: 0 Writes Requeued: 0 Reads Completed: 0, 0KiB Writes Completed: 20, 3740KiB Read Merges: 0, 0KiB Write Merges: 0, 0KiB Read depth: 0 Write depth: 0 IO unplugs: 3 Timer unplugs: 0 CPU3 (254,25): Reads Queued: 0, 0KiB Writes Queued: 24, 4700KiB Read Dispatches: 0, 0KiB Write Dispatches: 0, 0KiB Reads Requeued: 0 Writes Requeued: 0 Reads Completed: 0, 0KiB Writes Completed: 0, 0KiB Read Merges: 0, 0KiB Write Merges: 0, 0KiB Read depth: 0 Write depth: 0 IO unplugs: 9 Timer unplugs: 0 Total (254,25): Reads Queued: 0, 0KiB Writes Queued: 24, 4700KiB Read Dispatches: 0, 0KiB Write Dispatches: 0, 0KiB Reads Requeued: 0 Writes Requeued: 0 Reads Completed: 0, 0KiB Writes Completed: 20, 3740KiB Read Merges: 0, 0KiB Write Merges: 0, 0KiB IO unplugs: 12 Timer unplugs: 0 Throughput (R/W): 0KiB/s / 0KiB/s Events (254,25): 106 entries Skips: 11 forward (166 - 61.0%)