> So I went and tried to throttle I/O of kernel3-8 to 10MB/s instead of > weighing I/O. First I rebooted everything so that no old configuration > of cgroup was left in place and then setup everything except the 100 and > 1000 weight configuration. > > quote from blkio.txt: > ------------ > - blkio.throttle.write_bps_device > - Specifies upper limit on WRITE rate to the device. IO rate is > specified in bytes per second. Rules are per deivce. Following is > the format. > > echo "<major>:<minor> <rate_bytes_per_second>" > > /cgrp/blkio.write_bps_device > ------------- > > for vm in kernel1 kernel2 kernel3 kernel4 kernel5 kernel6 kernel7 > kernel8; do ls -lH /dev/vdisks/$vm; done > brw-rw---- 1 root root 254, 23 Feb 18 13:45 /dev/vdisks/kernel1 > brw-rw---- 1 root root 254, 24 Feb 18 13:45 /dev/vdisks/kernel2 > brw-rw---- 1 root root 254, 25 Feb 18 13:45 /dev/vdisks/kernel3 > brw-rw---- 1 root root 254, 26 Feb 18 13:45 /dev/vdisks/kernel4 > brw-rw---- 1 root root 254, 27 Feb 18 13:45 /dev/vdisks/kernel5 > brw-rw---- 1 root root 254, 28 Feb 18 13:45 /dev/vdisks/kernel6 > brw-rw---- 1 root root 254, 29 Feb 18 13:45 /dev/vdisks/kernel7 > brw-rw---- 1 root root 254, 30 Feb 18 13:45 /dev/vdisks/kernel8 > > /bin/echo 254:25 10000000 > > /mnt/notimportant/blkio.throttle.write_bps_device > /bin/echo 254:26 10000000 > > /mnt/notimportant/blkio.throttle.write_bps_device > /bin/echo 254:27 10000000 > > /mnt/notimportant/blkio.throttle.write_bps_device > /bin/echo 254:28 10000000 > > /mnt/notimportant/blkio.throttle.write_bps_device > /bin/echo 254:29 10000000 > > /mnt/notimportant/blkio.throttle.write_bps_device > /bin/echo 254:30 10000000 > > /mnt/notimportant/blkio.throttle.write_bps_device > /bin/echo 254:30 10000000 > > /mnt/notimportant/blkio.throttle.write_bps_device > > Then I ran the previous test again. This resulted in an ever increasing > load (last I checked was ~ 300) on the host system. (This is perfectly > reproducible). > > uptime > Fri Feb 18 14:42:17 2011 > 14:42:17 up 12 min, 9 users, load average: 286.51, 142.22, 56.71 Have you run top or something to figure out why load average is shooting up. I suspect that because of throttling limit, IO threads have been blocked and qemu is forking more IO threads. Can you just run top/ps and figure out what's happening. Again, is it some kind of linear volume group from which you have carved out logical volumes for each virtual machine? For throttling to begin with, can we do a simple test first. That is run a single virtual machine, put some throttling limit on logical volume and try to do READs. Once READs work, lets test WRITES and check why does system load go up.

On Fri, Feb 18, 2011 at 03:42:45PM +0100, Dominik Klein wrote: > Hi Vivek > > I don't know whether you follow the libvirt list, I assume you don't. So > I thought I'd forward you an E-Mail involving the blkio controller and a > terrible situation arising from using it (maybe in a wrong way). > > I'd truely appreciate it if you read it and commented on it. Maybe I did > something wrong, but maybe also I found a bug in some way. Hi Dominik, Thanks for forwarding me this mail. Yes, I am not on libvir-list. I have just now subscribed. Few questions inline. > -------- Original Message -------- > Subject: Re: [libvirt] [PATCH 0/6 v3] Add blkio cgroup support > Date: Fri, 18 Feb 2011 14:42:51 +0100 > From: Dominik Klein <dk(a)in-telegence.net&gt; > To: libvir-list(a)redhat.com > > Hi > > back with some testing results. > > >> how about the start Guest with option "cache=none" to bypass pagecache? > >> This should help i think. > > > > I will read up on where to set that and give it a try. Thanks for the hint. > > So here's what I did and found out: > > The host system has 2 12 core CPUs and 128 GB of Ram. > > I have 8 test VMs named kernel1 to kernel8. Each VM has 4 VCPUs, 2 GB of > RAm and one disk, which is an lv on the host. Cache mode is "none": So you have only one root SATA disk and setup a linear logical volume on that? I not, can you give more info about the storage configuration? - I am assuming you are using CFQ on your underlying physical disk. - What kernel version are you testing with. - Cache=none mode is good which should make all the IO O_DIRECT on host and should show up as SYNC IO on CFQ without losing io context info. The onlly probelm is intermediate dm layer and if it is changing the io context somehow. I am not sure at this point of time. - Is it possible to capture 10-15 second blktrace on your underlying physical device. That should give me some idea what's happening. - Can you also try setting /sys/block/<disk>/queue/iosched/group_isolation=1 on your underlying physical device where CFQ is running and see if it makes any difference.

Dominik, Would you try "oflag=direct" when you do tests in Guests. And make sure /sys/block/xxx/queue/iosched/group_isolation is set to 1.

I guess with such setting, your tests should goes well. Thanks, Gui Vivek Goyal wrote: > On Fri, Feb 18, 2011 at 03:42:45PM +0100, Dominik Klein wrote: >> Hi Vivek >> >> I don't know whether you follow the libvirt list, I assume you don't. So >> I thought I'd forward you an E-Mail involving the blkio controller and a >> terrible situation arising from using it (maybe in a wrong way). >> >> I'd truely appreciate it if you read it and commented on it. Maybe I did >> something wrong, but maybe also I found a bug in some way. > > Hi Dominik, > > Thanks for forwarding me this mail. Yes, I am not on libvir-list. I have > just now subscribed. > > Few questions inline. > >> -------- Original Message -------- >> Subject: Re: [libvirt] [PATCH 0/6 v3] Add blkio cgroup support >> Date: Fri, 18 Feb 2011 14:42:51 +0100 >> From: Dominik Klein <dk(a)in-telegence.net&gt; >> To: libvir-list(a)redhat.com >> >> Hi >> >> back with some testing results. >> >>>> how about the start Guest with option "cache=none" to bypass pagecache? >>>> This should help i think. >>> I will read up on where to set that and give it a try. Thanks for the hint. >> So here's what I did and found out: >> >> The host system has 2 12 core CPUs and 128 GB of Ram. >> >> I have 8 test VMs named kernel1 to kernel8. Each VM has 4 VCPUs, 2 GB of >> RAm and one disk, which is an lv on the host. Cache mode is "none": > > So you have only one root SATA disk and setup a linear logical volume on > that? I not, can you give more info about the storage configuration? > > - I am assuming you are using CFQ on your underlying physical disk. > > - What kernel version are you testing with. > > - Cache=none mode is good which should make all the IO O_DIRECT on host > and should show up as SYNC IO on CFQ without losing io context info. > The onlly probelm is intermediate dm layer and if it is changing the > io context somehow. I am not sure at this point of time. > > - Is it possible to capture 10-15 second blktrace on your underlying > physical device. That should give me some idea what's happening. > > - Can you also try setting /sys/block/<disk>/queue/iosched/group_isolation=1 > on your underlying physical device where CFQ is running and see if it makes > any difference. > >> for vm in kernel1 kernel2 kernel3 kernel4 kernel5 kernel6 kernel7 >> kernel8; do virsh dumpxml $vm|grep cache; done >> <driver name='qemu' type='raw' cache='none'/> >> <driver name='qemu' type='raw' cache='none'/> >> <driver name='qemu' type='raw' cache='none'/> >> <driver name='qemu' type='raw' cache='none'/> >> <driver name='qemu' type='raw' cache='none'/> >> <driver name='qemu' type='raw' cache='none'/> >> <driver name='qemu' type='raw' cache='none'/> >> <driver name='qemu' type='raw' cache='none'/> >> >> My goal is to give more I/O time to kernel1 and kernel2 than to the rest >> of the VMs. >> >> mount -t cgroup -o blkio none /mnt >> cd /mnt >> mkdir important >> mkdir notimportant >> >> echo 1000 > important/blkio.weight >> echo 100 > notimportant/blkio.weight >> for vm in kernel3 kernel4 kernel5 kernel6 kernel7 kernel8; do >> cd /proc/$(pgrep -f "qemu-kvm.*$vm")/task >> for task in *; do >> /bin/echo $task > /mnt/notimportant/tasks >> done >> done >> >> for vm in kernel1 kernel2; do >> cd /proc/$(pgrep -f "qemu-kvm.*$vm")/task >> for task in *; do >> /bin/echo $task > /mnt/important/tasks >> done >> done >> >> Then I used cssh to connect to all 8 VMs and execute >> dd if=/dev/zero of=testfile bs=1M count=1500 >> in all VMs simultaneously. >> >> Results are: >> kernel1: 47.5593 s, 33.1 MB/s >> kernel2: 60.1464 s, 26.2 MB/s >> kernel3: 74.204 s, 21.2 MB/s >> kernel4: 77.0759 s, 20.4 MB/s >> kernel5: 65.6309 s, 24.0 MB/s >> kernel6: 81.1402 s, 19.4 MB/s >> kernel7: 70.3881 s, 22.3 MB/s >> kernel8: 77.4475 s, 20.3 MB/s >> >> Results vary a little bit from run to run, but it is nothing >> spectacular, as weights of 1000 vs. 100 would suggest. >> >> So I went and tried to throttle I/O of kernel3-8 to 10MB/s instead of >> weighing I/O. First I rebooted everything so that no old configuration >> of cgroup was left in place and then setup everything except the 100 and >> 1000 weight configuration. >> >> quote from blkio.txt: >> ------------ >> - blkio.throttle.write_bps_device >> - Specifies upper limit on WRITE rate to the device. IO rate is >> specified in bytes per second. Rules are per deivce. Following is >> the format. >> >> echo "<major>:<minor> <rate_bytes_per_second>" > >> /cgrp/blkio.write_bps_device >> ------------- >> >> for vm in kernel1 kernel2 kernel3 kernel4 kernel5 kernel6 kernel7 >> kernel8; do ls -lH /dev/vdisks/$vm; done >> brw-rw---- 1 root root 254, 23 Feb 18 13:45 /dev/vdisks/kernel1 >> brw-rw---- 1 root root 254, 24 Feb 18 13:45 /dev/vdisks/kernel2 >> brw-rw---- 1 root root 254, 25 Feb 18 13:45 /dev/vdisks/kernel3 >> brw-rw---- 1 root root 254, 26 Feb 18 13:45 /dev/vdisks/kernel4 >> brw-rw---- 1 root root 254, 27 Feb 18 13:45 /dev/vdisks/kernel5 >> brw-rw---- 1 root root 254, 28 Feb 18 13:45 /dev/vdisks/kernel6 >> brw-rw---- 1 root root 254, 29 Feb 18 13:45 /dev/vdisks/kernel7 >> brw-rw---- 1 root root 254, 30 Feb 18 13:45 /dev/vdisks/kernel8 >> >> /bin/echo 254:25 10000000 > >> /mnt/notimportant/blkio.throttle.write_bps_device >> /bin/echo 254:26 10000000 > >> /mnt/notimportant/blkio.throttle.write_bps_device >> /bin/echo 254:27 10000000 > >> /mnt/notimportant/blkio.throttle.write_bps_device >> /bin/echo 254:28 10000000 > >> /mnt/notimportant/blkio.throttle.write_bps_device >> /bin/echo 254:29 10000000 > >> /mnt/notimportant/blkio.throttle.write_bps_device >> /bin/echo 254:30 10000000 > >> /mnt/notimportant/blkio.throttle.write_bps_device >> /bin/echo 254:30 10000000 > >> /mnt/notimportant/blkio.throttle.write_bps_device >> >> Then I ran the previous test again. This resulted in an ever increasing >> load (last I checked was ~ 300) on the host system. (This is perfectly >> reproducible). >> >> uptime >> Fri Feb 18 14:42:17 2011 >> 14:42:17 up 12 min, 9 users, load average: 286.51, 142.22, 56.71 > > Have you run top or something to figure out why load average is shooting > up. I suspect that because of throttling limit, IO threads have been > blocked and qemu is forking more IO threads. Can you just run top/ps > and figure out what's happening. > > Again, is it some kind of linear volume group from which you have carved > out logical volumes for each virtual machine? > > For throttling to begin with, can we do a simple test first. That is > run a single virtual machine, put some throttling limit on logical volume > and try to do READs. Once READs work, lets test WRITES and check why > does system load go up. > > Thanks > Vivek > > -- > libvir-list mailing list > libvir-list(a)redhat.com > https://www.redhat.com/mailman/listinfo/libvir-list > -- Regards Gui Jianfeng

> - Is it possible to capture 10-15 second blktrace on your underlying > physical device. That should give me some idea what's happening. Will do, read on.

On 02/21/2011 09:19 AM, Dominik Klein wrote: >>> - Is it possible to capture 10-15 second blktrace on your underlying >>> physical device. That should give me some idea what's happening. >> >> Will do, read on. > > Just realized I missed this one ... Had better done it right away. > > So here goes. > > Setup as in first email. 8 Machines, 2 important, 6 not important ones > with a throttle of ~10M. group_isolation=1. Each vm dd'ing zeroes. > > blktrace -d /dev/sdb -w 30 > === sdb === > CPU 0: 4769 events, 224 KiB data > CPU 1: 28079 events, 1317 KiB data > CPU 2: 1179 events, 56 KiB data > CPU 3: 5529 events, 260 KiB data > CPU 4: 295 events, 14 KiB data > CPU 5: 649 events, 31 KiB data > CPU 6: 185 events, 9 KiB data > CPU 7: 180 events, 9 KiB data > CPU 8: 17 events, 1 KiB data > CPU 9: 12 events, 1 KiB data > CPU 10: 6 events, 1 KiB data > CPU 11: 55 events, 3 KiB data > CPU 12: 28005 events, 1313 KiB data > CPU 13: 1542 events, 73 KiB data > CPU 14: 4814 events, 226 KiB data > CPU 15: 389 events, 19 KiB data > CPU 16: 1545 events, 73 KiB data > CPU 17: 119 events, 6 KiB data > CPU 18: 3019 events, 142 KiB data > CPU 19: 62 events, 3 KiB data > CPU 20: 800 events, 38 KiB data > CPU 21: 17 events, 1 KiB data > CPU 22: 243 events, 12 KiB data > CPU 23: 1 events, 1 KiB data > Total: 81511 events (dropped 0), 3822 KiB data > > Very constant 296 blocked processes in vmstat during this run. But... > apparently no data is written at all (see "bo" column).

> > vmstat 2 > procs -----------memory---------- ---swap-- -----io---- -system-- > ----cpu---- > r b swpd free buff cache si so bi bo in cs us sy > id wa > 0 296 0 125254224 21432 142016 0 0 16 633 181 331 0 > 0 93 7 > 0 296 0 125253728 21432 142016 0 0 0 0 17115 33794 > 0 0 25 75 > 0 296 0 125254112 21432 142016 0 0 0 0 17084 33721 > 0 0 25 74 > 1 296 0 125254352 21440 142012 0 0 0 18 17047 33736 > 0 0 25 75 > 0 296 0 125304224 21440 131060 0 0 0 0 17630 33989 > 0 1 23 76 > 1 296 0 125306496 21440 130260 0 0 0 0 16810 33401 > 0 0 20 80 > 4 296 0 125307208 21440 129856 0 0 0 0 17169 33744 > 0 0 26 74 > 0 296 0 125307496 21448 129508 0 0 0 14 17105 33650 > 0 0 36 64 > 0 296 0 125307712 21452 129672 0 0 2 1340 17117 33674 > 0 0 22 78 > 1 296 0 125307752 21452 129520 0 0 0 0 16875 33438 > 0 0 29 70 > 1 296 0 125307776 21452 129520 0 0 0 0 16959 33560 > 0 0 21 79 > 1 296 0 125307792 21460 129520 0 0 0 12 16700 33239 > 0 0 15 85 > 1 296 0 125307808 21460 129520 0 0 0 0 16750 33274 > 0 0 25 74 > 1 296 0 125307808 21460 129520 0 0 0 0 17020 33601 > 0 0 26 74 > 1 296 0 125308272 21460 129520 0 0 0 0 17080 33616 > 0 0 20 80 > 1 296 0 125308408 21460 129520 0 0 0 0 16428 32972 > 0 0 42 58 > 1 296 0 125308016 21460 129524 0 0 0 0 17021 33624 > 0 0 22 77 While we're on that ... It is impossible for me now to recover from this state without pulling the power plug. On the VMs console I see messages like INFO: task (kjournald|flush-254|dd|rs:main|...) blocked for more than 120 seconds.

While the ssh sessions through which the dd was started seem intact (pressing enter gives a new line), it is impossible to cancel the dd command. Logging in on the VMs console also is impossible. Opening a new ssh session to the host also does not work. Killing the qemu-kvm processes from a session opened earlier leaves zomby processes. Moving the VMs back to the root cgroup makes no difference either. Regards Dominik -- libvir-list mailing list libvir-list(a)redhat.com https://www.redhat.com/mailman/listinfo/libvir-list

Hi to be as verbose and clear as possible, I will write every command I use.

This sets everything up for the test: # setup start importantvms="kernel1 kernel2" notimportantvms="kernel3 kernel4 kernel5 kernel6 kernel7 kernel8" for vm in $importantvms $notimportantvms; do virsh domstate $vm|grep -q running || virsh start $vm; done echo 1 > /sys/block/sdb/queue/iosched/group_isolation mount -t cgroup -o blkio none /mnt cd /mnt mkdir important mkdir notimportant for vm in $notimportantvms; do cd /proc/$(pgrep -f "qemu-kvm.*$vm")/task for task in *; do /bin/echo $task > /mnt/notimportant/tasks done done for vm in $importantvms; do cd /proc/$(pgrep -f "qemu-kvm.*$vm")/task for task in *; do /bin/echo $task > /mnt/important/tasks done done #ls -lH /dev/vdisks/kernel[3-8] #brw-rw---- 1 root root 254, 25 Feb 22 13:42 kernel3 #brw-rw---- 1 root root 254, 26 Feb 22 13:42 kernel4 #brw-rw---- 1 root root 254, 27 Feb 22 13:42 kernel5 #brw-rw---- 1 root root 254, 28 Feb 22 13:42 kernel6 #brw-rw---- 1 root root 254, 29 Feb 22 13:43 kernel7 #brw-rw---- 1 root root 254, 30 Feb 22 13:43 kernel8 for i in $(seq 25 30); do /bin/echo 254:$i 10000000 > /mnt/notimportant/blkio.throttle.write_bps_device done # setup complete > Hm..., this sounds bad. If you have put a limit of ~10Mb/s then no > "bo" is bad. That would explain that why your box is not responding > and you need to do power reset. > > - I am assuming that you have not put any throttling limits on root group. > Is your system root also on /dev/sdb or on a separate disk altogether. No throttling on root. Correct. system root is on sda vms are on sdb > - This sounds like a bug in throttling logic. To narrow it down can you > start running "deadline" on end device. If it still happens, it is more > or less in throttling layer. cat /sys/block/sdb/queue/scheduler noop deadline [cfq] echo deadline > /sys/block/sdb/queue/scheduler cat /sys/block/sdb/queue/scheduler noop [deadline] cfq This changes things: vmstat before test (nothing going on): r b swpd free buff cache si so bi bo in cs us sy id wa 1 0 0 130231696 17968 69424 0 0 0 0 16573 32834 0 0 100 0 vmstat during test while all 8 vms are writing (2 unthrottled, 6 at 10M): r b swpd free buff cache si so bi bo in cs us sy id wa 2 9 0 126257984 17968 69424 0 0 8 164462 20114 36751 5 4 52 39 vmstat during test when only throttled vms are still dd'ing 2 21 0 124518928 17976 69424 0 0 0 63876 17410 33670 1 1 59 39 Load is 12-ish during the test and the results are as expected: Throttled VMs write with approx 10M, unthrottled get like 80 each, which sums up to about the 200M max capacity of the device for direct io.

> - We can also try to remove dm layers and just create partitions on > /dev/sdb and export as virtio disks to virtual machines and take > dm layer out of picture and see if it still happens. Did that. Also happens when scheduler is cfq. Also does not happen when scheduler is deadline. So it does not seem to be a dm issue.

> - In one of the mails you mentioned that with 1 virutal machine throttling > READs and WRITEs is working for you. So it looks like 1 virtual machine > does not hang but once you launch 8 virtual machines it hangs. Can we > try increasing the number of vitual machines gragually and confirm that > it happens only if some certain number of virtual machines are launched. Back on cfq here. 1 throttled vm: works, load ~4 2 throttled vms: works, load ~6 3 throttled vms: works, load ~9 4 throttled vms: works, load ~12 6 throttled vms: works, load ~20 The number of blocked threads increases with the number of vms dd'ing. At the beginning of each test, the blocked threads number goes really high (4 vms 160, 6 vms 220), but then drops significantly and stays low. So it seems that when only throttled vms are running, the problem does not occur. 1 throttled + 1 unthrottled vm: works, load ~5 2 throttled + 1 unthrottled vm: boom

Constantly 144 blocked threads, bo=0, load increasing to 144. System needs power reset. So, thinking about what I did in the initial setup, I re-tested without the for vm in $importantvms; do cd /proc/$(pgrep -f "qemu-kvm.*$vm")/task for task in *; do /bin/echo $task > /mnt/important/tasks done done since I don't do anything with that "important" cgroup (yet) anyway. It did not make a difference though. > - Can you also paste me the rules you have put on important and non-important > groups. Somehow I suspect that some of the rule has gone horribly bad > in the sense that it is very low and effectively no virtual machine > is making any progress. See setup commands in the beginning of this email. > - How long does it take to reach in this locked state where bo=0. It goes there "instantly", right after the dd commands start. > - you can also try to redirect blktrace output to blkparse and redirect > it to standard output and see capture some output by copying pasting > last messages. I hope this is what you meant: blktrace -d /dev/sdb -o - | blkparse -i -

Hi so I ran these tests again. No patch applied yet. And - at least once - it worked. I did everything exactly the same way as before. Since the logs are 8 MB, even when best-bzip2'd, and I don't want everybody to have to download these, I uploaded them to an external hoster: http://www.megaupload.com/?d=SWKTC0V4 Traces were created with blktrace -n 64 -b 16384 -d /dev/sdb -o - | blkparse -i - blktrace -n 64 -b 16384 -d /dev/vdisks/kernel3 -o - | blkparse -i - > Can you please apply attached patch. Unfortunately not. Cannot be applied to 2.6.37. I guess your source is newer and I fail to find the places in the file to patch manually. > This just makes CFQ output little > more verbose and run the test again and capture the trace. > > - Start the trace on /dev/sdb > - Start the dd jobs in virt machines > - Wait for system to hang > - Press CTRL-C > - Make sure there were no lost events otherwise increase the size and > number of buffers. Tried that. Unfortunately, even with max buffer size of 16 M [1], this leaves some Skips. I also tried to increase the number of buffers over 64, but that produced Oops'es. However, I attached kernel3's blktrace of a case where the error occured. Maybe you can read something from that. > Can you also open tracing in another window and also trace one of the > throttled dm deivces, say /dev/disks/kernel3. Following the same procedure > as above. So let the two traces run in parallel. So what next? Regards Dominik [1] http://git.kernel.org/?p=linux/kernel/git/axboe/blktrace.git;a=blob_plain... and look for "Invalid buffer"

On Thu, Feb 24, 2011 at 10:18:00AM +0100, Dominik Klein wrote: Hi Dominik, Thanks for the tests and reports. I checked the latest logs also and I see that cfq has scheduled a work but that work never gets scheduled. I never see the trace message which says cfq_kick_queue(). I am ccing it to lkml and tejun to see if he has any suggestions. Tejun, I will give you some details about what we have discussed so far. Dominik is trying blkio throttling feature and trying to throttle some virtual machines. He is using 2.6.37 kernels and once he launches 3 virtual machines he notices that system is kind of frozen. After running some traces we noticed that CFQ has requests but it is not dispatching these to devices any more. This problem does not show up with deadline scheduler and also goes away with 2.6.38-rc6 kernels.

Hi > Hmmm... Maybe the following commit? > > commit 7576958a9d5a4a677ad7dd40901cdbb6c1110c98 Unfortunately not. This does not fix it for me. Vivek introduced me to git bisect and I will try to do that tomorrow to find the changeset.

> Maybe watching what the workqueue is doing using the following trace > events could be helpful. > > # grep workqueue /sys/kernel/debug/tracing/available_events > workqueue:workqueue_insertion > workqueue:workqueue_execution > workqueue:workqueue_creation > workqueue:workqueue_destruction Since I've never done this before, I will tell you how I captured the trace so you know what I did and can see whether I did something wrong and can correct me if necessary. echo blk > /sys/kernel/debug/tracing/current_tracer echo 1 > /sys/block/sdb/trace/enable echo workqueue_queue_work >> /sys/kernel/debug/tracing/set_event echo workqueue_activate_work >> /sys/kernel/debug/tracing/set_event echo workqueue_execute_start >> /sys/kernel/debug/tracing/set_event echo workqueue_execute_end >> /sys/kernel/debug/tracing/set_event cat /sys/kernel/debug/tracing/trace_pipe And that output i gzip'd. This was taken with 2.6.37 plus the patch you mentioned on a Dell R815 with 2 12 core AMD Opteron 6174 CPUs. If you need any more information, please let me know.

With 2.6.37 (also tried .1 and .2) it does not work but end up like I documented. With 2.6.38-rc1, it does work. With deadline scheduler, it also works in 2.6.37.

See attached logs of another run. sysctl -w kernel.sysrq=1 echo blk > /sys/kernel/debug/tracing/current_tracer echo 1 > /sys/block/sdb/trace/enable echo workqueue_queue_work >> /sys/kernel/debug/tracing/set_event echo workqueue_activate_work >> /sys/kernel/debug/tracing/set_event echo workqueue_execute_start >> /sys/kernel/debug/tracing/set_event echo workqueue_execute_end >> /sys/kernel/debug/tracing/set_event That makes attachment trace_pipe5.gz echo 8 > /proc/sysrq-trigger echo t > /proc/sysrq-trigger That makes attachment console.gz

blk_throtl_work() calls generic_make_request() to dispatch some bios and I guess blk_throtl_work() has been put to sleep because threre are no request descriptors available and CFQ is frozen so no requests descriptors get freed hence blk_throtl_work() never finishes. Following caught my eye. ksoftirqd/0-3 [000] 1640.983585: 8,16 m N cfq4810 slice expired t=0 ksoftirqd/0-3 [000] 1640.983588: 8,16 m N cfq4810 sl_used=2 disp=6 charge=2 iops=0 sect=2080 ksoftirqd/0-3 [000] 1640.983589: 8,16 m N cfq4810 del_from_rr ksoftirqd/0-3 [000] 1640.983591: 8,16 m N cfq schedule dispatch sshd-3125 [004] 1640.983597: workqueue_queue_work: work struct=ffff88102c3a3110 function=flush_to_ldisc workqueue=ffff88182c834a00 req_cpu=4 cpu=4 sshd-3125 [004] 1640.983598: workqueue_activate_work: work struct ffff88102c3a3110 CFQ tries to schedule a work and but there is no associated "workqueue_queue_work" trace. So it looks like that work never got queued. CFQ calls following. cfq_log(cfqd, "schedule dispatch"); kblockd_schedule_work(cfqd->queue, &cfqd->unplug_work); We do see "schedule dispatch" message and kblockd_schedule_work() calls queue_work(). So what happended here? This is strange. I will put one more trace after kblockd_schedule_work() to trace that function returned.

On Fri, Feb 25, 2011 at 04:03:29PM +0100, Tejun Heo wrote: > Hello, > > On Fri, Feb 25, 2011 at 09:57:08AM -0500, Vivek Goyal wrote: > > blk_throtl_work() calls generic_make_request() to dispatch some bios and I > > guess blk_throtl_work() has been put to sleep because threre are no request > > descriptors available and CFQ is frozen so no requests descriptors get freed > > hence blk_throtl_work() never finishes. > > > > Following caught my eye. > > > > ksoftirqd/0-3 [000] 1640.983585: 8,16 m N cfq4810 slice > > expired t=0 > > ksoftirqd/0-3 [000] 1640.983588: 8,16 m N cfq4810 > > sl_used=2 disp=6 charge=2 iops=0 sect=2080 > > ksoftirqd/0-3 [000] 1640.983589: 8,16 m N cfq4810 > > del_from_rr > > ksoftirqd/0-3 [000] 1640.983591: 8,16 m N cfq schedule > > dispatch > > sshd-3125 [004] 1640.983597: workqueue_queue_work: work > > struct=ffff88102c3a3110 function=flush_to_ldisc workqueue=ffff88182c834a00 > > req_cpu=4 cpu=4 > > sshd-3125 [004] 1640.983598: workqueue_activate_work: work > > struct ffff88102c3a3110 > > > > CFQ tries to schedule a work and but there is no associated > > "workqueue_queue_work" trace. So it looks like that work never got queued. > > > > CFQ calls following. > > > > cfq_log(cfqd, "schedule dispatch"); > > kblockd_schedule_work(cfqd->queue, &cfqd->unplug_work); > > > > We do see "schedule dispatch" message and kblockd_schedule_work() calls > > queue_work(). So what happended here? This is strange. I will put one > > more trace after kblockd_schedule_work() to trace that function returned. > > It could be that the unplug work was already queued and in pending > state. The second queueing request will be ignored then. So, I think > the problem is that blk_throtl_work() occupies kblockd but requires > another work item (unplug_work) to make forward progress. In such > cases, forward progress cannot be guaranteed. Either > blk_throtl_work() or cfq unplug work should use a separate workqueue. Ok, that would make sense. So blk_throtl_work() can not finish as CFQ is not making progress and no request descriptors are being freed and unplug_work() is not being called because blk_throtl_work() has not finished. So that's cyclic dependency and I should use a separate work queue for queueing throttle related work. I will write a patch.

> Maybe watching what the workqueue is doing using the following trace > events could be helpful. > > # grep workqueue /sys/kernel/debug/tracing/available_events > workqueue:workqueue_insertion > workqueue:workqueue_execution > workqueue:workqueue_creation > workqueue:workqueue_destruction Since I've never done this before, I will tell you how I captured the trace so you know what I did and can see whether I did something wrong and can correct me if necessary. echo blk > /sys/kernel/debug/tracing/current_tracer echo 1 > /sys/block/sdb/trace/enable echo workqueue_queue_work >> /sys/kernel/debug/tracing/set_event echo workqueue_activate_work >> /sys/kernel/debug/tracing/set_event echo workqueue_execute_start >> /sys/kernel/debug/tracing/set_event echo workqueue_execute_end >> /sys/kernel/debug/tracing/set_event cat /sys/kernel/debug/tracing/trace_pipe

And that output i gzip'd. This was taken with 2.6.37 plus the patch you mentioned on a Dell R815 with 2 12 core AMD Opteron 6174 CPUs. If you need any more information, please let me know.

Thanks Steve. In this case this feature of sending trace data over network would have helped. We were running into issues where IO scheduler was freezing so we could not read anything from disk(including saved traces). Hence we were directing everything to console and then doing copy paste. So sending it over network would have probably worked even in this case. Will give trace-cmd a try next time.