Btrfs devel - Oct 2010 - btrfs hang (deadlock?) when trying to create a ext4 filesystem in KVM guest

There are a couple of problems when running KVM guests with images stored on
btrfs filesystem.

One of them is inability to create a filesystem (i.e. ext4) in the guest:

- btrfs filesystem on the host was mounted with noatime,compress-force
- guest was using a 50 GB sparse file,
- attempt to create a ext4 filesystem within the guest does not succeed (hangs);
host prints below messages in dmesg - some deadlock in btrfs?

kernel: 2.6.36
qemu-kvm: 0.13.0


[22748.830644] INFO: task qemu-system-x86:5186 blocked for more than 120
seconds.
[22748.830649] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"
disables this message.
[22748.830653] qemu-system-x D ffff880001e34cc0     0  5186   4768 0x00000004
[22748.830660]  ffff8801ed3f9b38 0000000000000086 ffff8801ed3f9fd8
0000000000014cc0
[22748.830666]  0000000000014cc0 ffff8801ed3f9fd8 0000000000014cc0
ffff8801ed3f9fd8
[22748.830672]  0000000000014cc0 ffff88002dc43158 ffff88002dc43160
ffff88002dc42dc0
[22748.830678] Call Trace:
[22748.830712]  [<ffffffffa024252c>] btrfs_start_ordered_extent+0x6c/0xb0
[btrfs]
[22748.830723]  [<ffffffff81083200>] ? autoremove_wake_function+0x0/0x40
[22748.830744]  [<ffffffffa02431c2>] btrfs_wait_ordered_range+0xd2/0x160
[btrfs]
[22748.830762]  [<ffffffffa0236059>] btrfs_file_aio_write+0x269/0x990
[btrfs]
[22748.830767]  [<ffffffff8105ca94>] ? try_to_wake_up+0xf4/0x3f0
[22748.830773]  [<ffffffff81168119>] ? __pollwake+0x49/0x50
[22748.830776]  [<ffffffff8105cd90>] ? default_wake_function+0x0/0x20
[22748.830780]  [<ffffffff8116813b>] ? pollwake+0x1b/0x20
[22748.830795]  [<ffffffffa0235df0>] ? btrfs_file_aio_write+0x0/0x990
[btrfs]
[22748.830799]  [<ffffffff8115664b>] do_sync_readv_writev+0xcb/0x110
[22748.830804]  [<ffffffff81076736>] ? send_signal+0x56/0xa0
[22748.830808]  [<ffffffff81294d98>] ? apparmor_file_permission+0x18/0x20
[22748.830813]  [<ffffffff8126356e>] ? security_file_permission+0x1e/0x80
[22748.830817]  [<ffffffff811576e0>] do_readv_writev+0xd0/0x1d0
[22748.830821]  [<ffffffff8115781e>] vfs_writev+0x3e/0x60
[22748.830824]  [<ffffffff811578e7>] sys_pwritev+0xa7/0xc0
[22748.830828]  [<ffffffff8100b0f2>] system_call_fastpath+0x16/0x1b
[22748.830832] INFO: task qemu-system-x86:5187 blocked for more than 120
seconds.
[22748.830834] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"
disables this message.
[22748.830837] qemu-system-x D ffff880001ed4cc0     0  5187   4768 0x00000004
[22748.830841]  ffff8801b264db38 0000000000000086 ffff8801b264dfd8
0000000000014cc0
[22748.830846]  0000000000014cc0 ffff8801b264dfd8 0000000000014cc0
ffff8801b264dfd8
[22748.830850]  0000000000014cc0 ffff88002dc45f18 ffff88002dc45f20
ffff88002dc45b80
[22748.830854] Call Trace:
[22748.830869]  [<ffffffffa024252c>] btrfs_start_ordered_extent+0x6c/0xb0
[btrfs]
[22748.830874]  [<ffffffff81083200>] ? autoremove_wake_function+0x0/0x40
[22748.830889]  [<ffffffffa02431c2>] btrfs_wait_ordered_range+0xd2/0x160
[btrfs]
[22748.830904]  [<ffffffffa0236059>] btrfs_file_aio_write+0x269/0x990
[btrfs]
[22748.830910]  [<ffffffff81044221>] ? gup_pud_range+0xb1/0x100
[22748.830915]  [<ffffffff812c5590>] ? vsnprintf+0x390/0x530
[22748.830930]  [<ffffffffa0235df0>] ? btrfs_file_aio_write+0x0/0x990
[btrfs]
[22748.830934]  [<ffffffff8115664b>] do_sync_readv_writev+0xcb/0x110
[22748.830938]  [<ffffffff8115753d>] ? rw_copy_check_uvector+0x7d/0x150
[22748.830942]  [<ffffffff81294d98>] ? apparmor_file_permission+0x18/0x20
[22748.830946]  [<ffffffff8126356e>] ? security_file_permission+0x1e/0x80
[22748.830949]  [<ffffffff811576e0>] do_readv_writev+0xd0/0x1d0
[22748.830953]  [<ffffffff8115781e>] vfs_writev+0x3e/0x60
[22748.830956]  [<ffffffff811578e7>] sys_pwritev+0xa7/0xc0
[22748.830960]  [<ffffffff8100b0f2>] system_call_fastpath+0x16/0x1b
[22748.830963] INFO: task qemu-system-x86:5188 blocked for more than 120
seconds.
[22748.830965] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"
disables this message.
[22748.830968] qemu-system-x D ffff880001e34cc0     0  5188   4768 0x00000004
[22748.830972]  ffff880134911b38 0000000000000086 ffff880134911fd8
0000000000014cc0
[22748.830976]  0000000000014cc0 ffff880134911fd8 0000000000014cc0
ffff880134911fd8
[22748.830980]  0000000000014cc0 ffff88002dc41a78 ffff88002dc41a80
ffff88002dc416e0
[22748.830984] Call Trace:
[22748.830999]  [<ffffffffa024252c>] btrfs_start_ordered_extent+0x6c/0xb0
[btrfs]
[22748.831004]  [<ffffffff81083200>] ? autoremove_wake_function+0x0/0x40
[22748.831019]  [<ffffffffa02431c2>] btrfs_wait_ordered_range+0xd2/0x160
[btrfs]
[22748.831034]  [<ffffffffa0236059>] btrfs_file_aio_write+0x269/0x990
[btrfs]
[22748.831038]  [<ffffffff8105b564>] ? find_busiest_group+0x544/0xa70
[22748.831054]  [<ffffffffa0235df0>] ? btrfs_file_aio_write+0x0/0x990
[btrfs]
[22748.831058]  [<ffffffff8115664b>] do_sync_readv_writev+0xcb/0x110
[22748.831063]  [<ffffffff8104dd56>] ? update_shares+0x16/0x60
[22748.831067]  [<ffffffff81294d98>] ? apparmor_file_permission+0x18/0x20
[22748.831071]  [<ffffffff8126356e>] ? security_file_permission+0x1e/0x80
[22748.831074]  [<ffffffff811576e0>] do_readv_writev+0xd0/0x1d0
[22748.831079]  [<ffffffff8115781e>] vfs_writev+0x3e/0x60
[22748.831082]  [<ffffffff811578e7>] sys_pwritev+0xa7/0xc0
[22748.831085]  [<ffffffff8100b0f2>] system_call_fastpath+0x16/0x1b
[22748.831088] INFO: task qemu-system-x86:5189 blocked for more than 120
seconds.
[22748.831090] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"
disables this message.
[22748.831093] qemu-system-x D ffff880001ef4cc0     0  5189   4768 0x00000004
[22748.831097]  ffff88012e711b38 0000000000000086 ffff88012e711fd8
0000000000014cc0
[22748.831101]  0000000000014cc0 ffff88012e711fd8 0000000000014cc0
ffff88012e711fd8
[22748.831105]  0000000000014cc0 ffff88002dc44838 ffff88002dc44840
ffff88002dc444a0
[22748.831109] Call Trace:
[22748.831124]  [<ffffffffa024252c>] btrfs_start_ordered_extent+0x6c/0xb0
[btrfs]
[22748.831129]  [<ffffffff81083200>] ? autoremove_wake_function+0x0/0x40
[22748.831144]  [<ffffffffa02431c2>] btrfs_wait_ordered_range+0xd2/0x160
[btrfs]
[22748.831159]  [<ffffffffa0236059>] btrfs_file_aio_write+0x269/0x990
[btrfs]
[22748.831163]  [<ffffffff8105b564>] ? find_busiest_group+0x544/0xa70
[22748.831179]  [<ffffffffa0235df0>] ? btrfs_file_aio_write+0x0/0x990
[btrfs]
[22748.831183]  [<ffffffff8115664b>] do_sync_readv_writev+0xcb/0x110
[22748.831187]  [<ffffffff8105d2f9>] ? load_balance+0x99/0x390
[22748.831191]  [<ffffffff81294d98>] ? apparmor_file_permission+0x18/0x20
[22748.831195]  [<ffffffff8126356e>] ? security_file_permission+0x1e/0x80
[22748.831198]  [<ffffffff811576e0>] do_readv_writev+0xd0/0x1d0
[22748.831202]  [<ffffffff8115781e>] vfs_writev+0x3e/0x60
[22748.831205]  [<ffffffff811578e7>] sys_pwritev+0xa7/0xc0
[22748.831209]  [<ffffffff8100b0f2>] system_call_fastpath+0x16/0x1b



-- 
Tomasz Chmielewski
http://wpkg.org
--
To unsubscribe from this list: send the line "unsubscribe linux-btrfs"
in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

On Wed, Oct 27, 2010 at 03:29:38PM +0200, Tomasz Chmielewski
wrote:
> There are a couple of problems when running KVM guests with images stored
on btrfs filesystem.
> 
> One of them is inability to create a filesystem (i.e. ext4) in the guest:
> 
> - btrfs filesystem on the host was mounted with noatime,compress-force
> - guest was using a 50 GB sparse file,
> - attempt to create a ext4 filesystem within the guest does not succeed
(hangs); host prints below messages in dmesg - some deadlock in btrfs?
> 
> kernel: 2.6.36
> qemu-kvm: 0.13.0
Is this the full dmesg output?  I think there are other messages hiding
in there.

Is this a single disk btrfs?

-chris
> 
> 
> [22748.830644] INFO: task qemu-system-x86:5186 blocked for more than 120
seconds.
> [22748.830649] "echo 0 >
/proc/sys/kernel/hung_task_timeout_secs" disables this message.
> [22748.830653] qemu-system-x D ffff880001e34cc0     0  5186   4768
0x00000004
> [22748.830660]  ffff8801ed3f9b38 0000000000000086 ffff8801ed3f9fd8
0000000000014cc0
> [22748.830666]  0000000000014cc0 ffff8801ed3f9fd8 0000000000014cc0
ffff8801ed3f9fd8
> [22748.830672]  0000000000014cc0 ffff88002dc43158 ffff88002dc43160
ffff88002dc42dc0
> [22748.830678] Call Trace:
> [22748.830712]  [<ffffffffa024252c>]
btrfs_start_ordered_extent+0x6c/0xb0 [btrfs]
> [22748.830723]  [<ffffffff81083200>] ?
autoremove_wake_function+0x0/0x40
> [22748.830744]  [<ffffffffa02431c2>]
btrfs_wait_ordered_range+0xd2/0x160 [btrfs]
> [22748.830762]  [<ffffffffa0236059>] btrfs_file_aio_write+0x269/0x990
[btrfs]
> [22748.830767]  [<ffffffff8105ca94>] ? try_to_wake_up+0xf4/0x3f0
> [22748.830773]  [<ffffffff81168119>] ? __pollwake+0x49/0x50
> [22748.830776]  [<ffffffff8105cd90>] ? default_wake_function+0x0/0x20
> [22748.830780]  [<ffffffff8116813b>] ? pollwake+0x1b/0x20
> [22748.830795]  [<ffffffffa0235df0>] ? btrfs_file_aio_write+0x0/0x990
[btrfs]
> [22748.830799]  [<ffffffff8115664b>] do_sync_readv_writev+0xcb/0x110
> [22748.830804]  [<ffffffff81076736>] ? send_signal+0x56/0xa0
> [22748.830808]  [<ffffffff81294d98>] ?
apparmor_file_permission+0x18/0x20
> [22748.830813]  [<ffffffff8126356e>] ?
security_file_permission+0x1e/0x80
> [22748.830817]  [<ffffffff811576e0>] do_readv_writev+0xd0/0x1d0
> [22748.830821]  [<ffffffff8115781e>] vfs_writev+0x3e/0x60
> [22748.830824]  [<ffffffff811578e7>] sys_pwritev+0xa7/0xc0
> [22748.830828]  [<ffffffff8100b0f2>] system_call_fastpath+0x16/0x1b
> [22748.830832] INFO: task qemu-system-x86:5187 blocked for more than 120
seconds.
> [22748.830834] "echo 0 >
/proc/sys/kernel/hung_task_timeout_secs" disables this message.
> [22748.830837] qemu-system-x D ffff880001ed4cc0     0  5187   4768
0x00000004
> [22748.830841]  ffff8801b264db38 0000000000000086 ffff8801b264dfd8
0000000000014cc0
> [22748.830846]  0000000000014cc0 ffff8801b264dfd8 0000000000014cc0
ffff8801b264dfd8
> [22748.830850]  0000000000014cc0 ffff88002dc45f18 ffff88002dc45f20
ffff88002dc45b80
> [22748.830854] Call Trace:
> [22748.830869]  [<ffffffffa024252c>]
btrfs_start_ordered_extent+0x6c/0xb0 [btrfs]
> [22748.830874]  [<ffffffff81083200>] ?
autoremove_wake_function+0x0/0x40
> [22748.830889]  [<ffffffffa02431c2>]
btrfs_wait_ordered_range+0xd2/0x160 [btrfs]
> [22748.830904]  [<ffffffffa0236059>] btrfs_file_aio_write+0x269/0x990
[btrfs]
> [22748.830910]  [<ffffffff81044221>] ? gup_pud_range+0xb1/0x100
> [22748.830915]  [<ffffffff812c5590>] ? vsnprintf+0x390/0x530
> [22748.830930]  [<ffffffffa0235df0>] ? btrfs_file_aio_write+0x0/0x990
[btrfs]
> [22748.830934]  [<ffffffff8115664b>] do_sync_readv_writev+0xcb/0x110
> [22748.830938]  [<ffffffff8115753d>] ?
rw_copy_check_uvector+0x7d/0x150
> [22748.830942]  [<ffffffff81294d98>] ?
apparmor_file_permission+0x18/0x20
> [22748.830946]  [<ffffffff8126356e>] ?
security_file_permission+0x1e/0x80
> [22748.830949]  [<ffffffff811576e0>] do_readv_writev+0xd0/0x1d0
> [22748.830953]  [<ffffffff8115781e>] vfs_writev+0x3e/0x60
> [22748.830956]  [<ffffffff811578e7>] sys_pwritev+0xa7/0xc0
> [22748.830960]  [<ffffffff8100b0f2>] system_call_fastpath+0x16/0x1b
> [22748.830963] INFO: task qemu-system-x86:5188 blocked for more than 120
seconds.
> [22748.830965] "echo 0 >
/proc/sys/kernel/hung_task_timeout_secs" disables this message.
> [22748.830968] qemu-system-x D ffff880001e34cc0     0  5188   4768
0x00000004
> [22748.830972]  ffff880134911b38 0000000000000086 ffff880134911fd8
0000000000014cc0
> [22748.830976]  0000000000014cc0 ffff880134911fd8 0000000000014cc0
ffff880134911fd8
> [22748.830980]  0000000000014cc0 ffff88002dc41a78 ffff88002dc41a80
ffff88002dc416e0
> [22748.830984] Call Trace:
> [22748.830999]  [<ffffffffa024252c>]
btrfs_start_ordered_extent+0x6c/0xb0 [btrfs]
> [22748.831004]  [<ffffffff81083200>] ?
autoremove_wake_function+0x0/0x40
> [22748.831019]  [<ffffffffa02431c2>]
btrfs_wait_ordered_range+0xd2/0x160 [btrfs]
> [22748.831034]  [<ffffffffa0236059>] btrfs_file_aio_write+0x269/0x990
[btrfs]
> [22748.831038]  [<ffffffff8105b564>] ? find_busiest_group+0x544/0xa70
> [22748.831054]  [<ffffffffa0235df0>] ? btrfs_file_aio_write+0x0/0x990
[btrfs]
> [22748.831058]  [<ffffffff8115664b>] do_sync_readv_writev+0xcb/0x110
> [22748.831063]  [<ffffffff8104dd56>] ? update_shares+0x16/0x60
> [22748.831067]  [<ffffffff81294d98>] ?
apparmor_file_permission+0x18/0x20
> [22748.831071]  [<ffffffff8126356e>] ?
security_file_permission+0x1e/0x80
> [22748.831074]  [<ffffffff811576e0>] do_readv_writev+0xd0/0x1d0
> [22748.831079]  [<ffffffff8115781e>] vfs_writev+0x3e/0x60
> [22748.831082]  [<ffffffff811578e7>] sys_pwritev+0xa7/0xc0
> [22748.831085]  [<ffffffff8100b0f2>] system_call_fastpath+0x16/0x1b
> [22748.831088] INFO: task qemu-system-x86:5189 blocked for more than 120
seconds.
> [22748.831090] "echo 0 >
/proc/sys/kernel/hung_task_timeout_secs" disables this message.
> [22748.831093] qemu-system-x D ffff880001ef4cc0     0  5189   4768
0x00000004
> [22748.831097]  ffff88012e711b38 0000000000000086 ffff88012e711fd8
0000000000014cc0
> [22748.831101]  0000000000014cc0 ffff88012e711fd8 0000000000014cc0
ffff88012e711fd8
> [22748.831105]  0000000000014cc0 ffff88002dc44838 ffff88002dc44840
ffff88002dc444a0
> [22748.831109] Call Trace:
> [22748.831124]  [<ffffffffa024252c>]
btrfs_start_ordered_extent+0x6c/0xb0 [btrfs]
> [22748.831129]  [<ffffffff81083200>] ?
autoremove_wake_function+0x0/0x40
> [22748.831144]  [<ffffffffa02431c2>]
btrfs_wait_ordered_range+0xd2/0x160 [btrfs]
> [22748.831159]  [<ffffffffa0236059>] btrfs_file_aio_write+0x269/0x990
[btrfs]
> [22748.831163]  [<ffffffff8105b564>] ? find_busiest_group+0x544/0xa70
> [22748.831179]  [<ffffffffa0235df0>] ? btrfs_file_aio_write+0x0/0x990
[btrfs]
> [22748.831183]  [<ffffffff8115664b>] do_sync_readv_writev+0xcb/0x110
> [22748.831187]  [<ffffffff8105d2f9>] ? load_balance+0x99/0x390
> [22748.831191]  [<ffffffff81294d98>] ?
apparmor_file_permission+0x18/0x20
> [22748.831195]  [<ffffffff8126356e>] ?
security_file_permission+0x1e/0x80
> [22748.831198]  [<ffffffff811576e0>] do_readv_writev+0xd0/0x1d0
> [22748.831202]  [<ffffffff8115781e>] vfs_writev+0x3e/0x60
> [22748.831205]  [<ffffffff811578e7>] sys_pwritev+0xa7/0xc0
> [22748.831209]  [<ffffffff8100b0f2>] system_call_fastpath+0x16/0x1b
> 
> 
> 
> -- 
> Tomasz Chmielewski
> http://wpkg.org
> --
> To unsubscribe from this list: send the line "unsubscribe
linux-btrfs" in
> the body of a message to majordomo@vger.kernel.org
> More majordomo info at  http://vger.kernel.org/majordomo-info.html
--
To unsubscribe from this list: send the line "unsubscribe linux-btrfs"
in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

On 28.10.2010 00:55, Chris Mason wrote:
> On Wed, Oct 27, 2010 at 03:29:38PM +0200, Tomasz Chmielewski wrote:
>> There are a couple of problems when running KVM guests with images
stored on btrfs filesystem.
>>
>> One of them is inability to create a filesystem (i.e. ext4) in the
guest:
>>
>> - btrfs filesystem on the host was mounted with noatime,compress-force
>> - guest was using a 50 GB sparse file,
>> - attempt to create a ext4 filesystem within the guest does not succeed
(hangs); host prints below messages in dmesg - some deadlock in btrfs?
>>
>> kernel: 2.6.36
>> qemu-kvm: 0.13.0
> 
> Is this the full dmesg output?  I think there are other messages hiding
> in there.
There were indeed "bad ordered accounting left" (see below), I think
they are coming from btrfs?

> Is this a single disk btrfs?
Yes.



[ 8072.773053] device fsid 1142843480ad2d13-4bdc742fd9b1f7b0 devid 1 transid
1508 /dev/sdb4
[ 8072.773674] btrfs: forcing compression
[ 8122.052221] device tap0 entered promiscuous mode
[ 8122.052245] br0: port 2(tap0) entering learning state
[ 8122.052248] br0: port 2(tap0) entering learning state
[ 8122.451587] br0: port 2(tap0) entering learning state
[ 8122.543477] br0: port 2(tap0) entering disabled state
[ 8122.609645] device tap0 left promiscuous mode
[ 8122.609650] br0: port 2(tap0) entering disabled state
[ 8131.325647] EXT4-fs (md4): recovery complete
[ 8131.325809] EXT4-fs (md4): mounted filesystem with ordered data mode. Opts:
(null)
[ 8133.392100] device tap0 entered promiscuous mode
[ 8133.392127] br0: port 2(tap0) entering learning state
[ 8133.392131] br0: port 2(tap0) entering learning state
[ 8134.106594] kvm: 5004: cpu0 unhandled wrmsr: 0x198 data 0
[ 8134.106618] kvm: 5004: cpu1 unhandled wrmsr: 0x198 data 0
[ 8143.460927] tap0: no IPv6 routers present
[ 8148.359485] br0: port 2(tap0) entering forwarding state
[ 8309.103502] bad ordered accounting left 65536 size 385024
[ 8309.106206] bad ordered accounting left 65536 size 385024
[ 8309.108915] bad ordered accounting left 65536 size 385024
[ 8309.111630] bad ordered accounting left 36864 size 385024
[ 8501.965625] INFO: task qemu-system-x86:5148 blocked for more than 120
seconds.
[ 8501.965629] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"
disables this message.
[ 8501.965632] qemu-system-x D ffff880001e14cc0     0  5148   4924 0x00000000
[ 8501.965638]  ffff880223bc3b38 0000000000000086 ffff880223bc3fd8
0000000000014cc0
[ 8501.965642]  0000000000014cc0 ffff880223bc3fd8 0000000000014cc0
ffff880223bc3fd8
[ 8501.965647]  0000000000014cc0 ffff880221965f18 ffff880221965f20
ffff880221965b80
[ 8501.965651] Call Trace:
[ 8501.965678]  [<ffffffffa024c52c>] btrfs_start_ordered_extent+0x6c/0xb0
[btrfs]
[ 8501.965685]  [<ffffffff81083200>] ? autoremove_wake_function+0x0/0x40
[ 8501.965701]  [<ffffffffa024d1c2>] btrfs_wait_ordered_range+0xd2/0x160
[btrfs]
[ 8501.965716]  [<ffffffffa0240059>] btrfs_file_aio_write+0x269/0x990
[btrfs]
[ 8501.965721]  [<ffffffff8105ca94>] ? try_to_wake_up+0xf4/0x3f0
[ 8501.965726]  [<ffffffff81168119>] ? __pollwake+0x49/0x50
[ 8501.965730]  [<ffffffff8105cd90>] ? default_wake_function+0x0/0x20
[ 8501.965733]  [<ffffffff8105ca94>] ? try_to_wake_up+0xf4/0x3f0
[ 8501.965737]  [<ffffffff8116813b>] ? pollwake+0x1b/0x20
[ 8501.965752]  [<ffffffffa023fdf0>] ? btrfs_file_aio_write+0x0/0x990
[btrfs]
[ 8501.965761]  [<ffffffff8115664b>] do_sync_readv_writev+0xcb/0x110
[ 8501.965769]  [<ffffffff81294d98>] ? apparmor_file_permission+0x18/0x20
[ 8501.965776]  [<ffffffff8126356e>] ? security_file_permission+0x1e/0x80
[ 8501.965781]  [<ffffffff811576e0>] do_readv_writev+0xd0/0x1d0
[ 8501.965787]  [<ffffffff81076d72>] ? kill_something_info+0x42/0x130
[ 8501.965793]  [<ffffffff81076ee0>] ? sys_kill+0x80/0x90
[ 8501.965798]  [<ffffffff8115781e>] vfs_writev+0x3e/0x60
[ 8501.965802]  [<ffffffff811578e7>] sys_pwritev+0xa7/0xc0
[ 8501.965806]  [<ffffffff8100b0f2>] system_call_fastpath+0x16/0x1b
[ 8501.965810] INFO: task qemu-system-x86:5150 blocked for more than 120
seconds.
[ 8501.965812] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"
disables this message.
[ 8501.965814] qemu-system-x D ffff880001e94cc0     0  5150   4924 0x00000000
[ 8501.965819]  ffff8801aba4bb38 0000000000000086 ffff8801aba4bfd8
0000000000014cc0
[ 8501.965823]  0000000000014cc0 ffff8801aba4bfd8 0000000000014cc0
ffff8801aba4bfd8
[ 8501.965827]  0000000000014cc0 ffff880226d14838 ffff880226d14840
ffff880226d144a0
[ 8501.965832] Call Trace:
[ 8501.965847]  [<ffffffffa024c52c>] btrfs_start_ordered_extent+0x6c/0xb0
[btrfs]
[ 8501.965852]  [<ffffffff81083200>] ? autoremove_wake_function+0x0/0x40
[ 8501.965867]  [<ffffffffa024d1c2>] btrfs_wait_ordered_range+0xd2/0x160
[btrfs]
[ 8501.965883]  [<ffffffffa0240059>] btrfs_file_aio_write+0x269/0x990
[btrfs]
[ 8501.965887]  [<ffffffff8105ca94>] ? try_to_wake_up+0xf4/0x3f0
[ 8501.965891]  [<ffffffff81168119>] ? __pollwake+0x49/0x50
[ 8501.965894]  [<ffffffff8105cd90>] ? default_wake_function+0x0/0x20
[ 8501.965897]  [<ffffffff8105ca94>] ? try_to_wake_up+0xf4/0x3f0
[ 8501.965901]  [<ffffffff8116813b>] ? pollwake+0x1b/0x20
[ 8501.965916]  [<ffffffffa023fdf0>] ? btrfs_file_aio_write+0x0/0x990
[btrfs]
[ 8501.965920]  [<ffffffff8115664b>] do_sync_readv_writev+0xcb/0x110
[ 8501.965924]  [<ffffffff81076736>] ? send_signal+0x56/0xa0
[ 8501.965928]  [<ffffffff81294d98>] ? apparmor_file_permission+0x18/0x20
[ 8501.965932]  [<ffffffff8126356e>] ? security_file_permission+0x1e/0x80
[ 8501.965936]  [<ffffffff811576e0>] do_readv_writev+0xd0/0x1d0
[ 8501.965940]  [<ffffffff8115781e>] vfs_writev+0x3e/0x60
[ 8501.965943]  [<ffffffff811578e7>] sys_pwritev+0xa7/0xc0
[ 8501.965946]  [<ffffffff8100b0f2>] system_call_fastpath+0x16/0x1b
[ 8501.965950] INFO: task qemu-system-x86:5151 blocked for more than 120
seconds.
[ 8501.965952] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"
disables this message.
[ 8501.965954] qemu-system-x D ffff880001e94cc0     0  5151   4924 0x00000000
[ 8501.965958]  ffff88021923fb38 0000000000000086 ffff88021923ffd8
0000000000014cc0
[ 8501.965963]  0000000000014cc0 ffff88021923ffd8 0000000000014cc0
ffff88021923ffd8
[ 8501.965967]  0000000000014cc0 ffff880226d13158 ffff880226d13160
ffff880226d12dc0
[ 8501.965971] Call Trace:
[ 8501.965986]  [<ffffffffa024c52c>] btrfs_start_ordered_extent+0x6c/0xb0
[btrfs]
[ 8501.965990]  [<ffffffff81083200>] ? autoremove_wake_function+0x0/0x40
[ 8501.966005]  [<ffffffffa024d1c2>] btrfs_wait_ordered_range+0xd2/0x160
[btrfs]
[ 8501.966021]  [<ffffffffa0240059>] btrfs_file_aio_write+0x269/0x990
[btrfs]
[ 8501.966025]  [<ffffffff8105ca94>] ? try_to_wake_up+0xf4/0x3f0
[ 8501.966029]  [<ffffffff81168119>] ? __pollwake+0x49/0x50
[ 8501.966032]  [<ffffffff8105cd90>] ? default_wake_function+0x0/0x20
[ 8501.966036]  [<ffffffff8105ca94>] ? try_to_wake_up+0xf4/0x3f0
[ 8501.966039]  [<ffffffff8116813b>] ? pollwake+0x1b/0x20
[ 8501.966054]  [<ffffffffa023fdf0>] ? btrfs_file_aio_write+0x0/0x990
[btrfs]
[ 8501.966058]  [<ffffffff8115664b>] do_sync_readv_writev+0xcb/0x110
[ 8501.966062]  [<ffffffff81076736>] ? send_signal+0x56/0xa0
[ 8501.966066]  [<ffffffff81294d98>] ? apparmor_file_permission+0x18/0x20
[ 8501.966070]  [<ffffffff8126356e>] ? security_file_permission+0x1e/0x80
[ 8501.966074]  [<ffffffff811576e0>] do_readv_writev+0xd0/0x1d0
[ 8501.966078]  [<ffffffff8115781e>] vfs_writev+0x3e/0x60
[ 8501.966081]  [<ffffffff811578e7>] sys_pwritev+0xa7/0xc0
[ 8501.966084]  [<ffffffff8100b0f2>] system_call_fastpath+0x16/0x1b


-- 
Tomasz Chmielewski
http://wpkg.org
--
To unsubscribe from this list: send the line "unsubscribe linux-btrfs"
in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

On Thu, Oct 28, 2010 at 1:29 AM, Tomasz Chmielewski <mangoo@wpkg.org>
wrote:
> On 28.10.2010 00:55, Chris Mason wrote:
>> On Wed, Oct 27, 2010 at 03:29:38PM +0200, Tomasz Chmielewski wrote:
>>> There are a couple of problems when running KVM guests with images
stored on btrfs filesystem.
>>>
>>> One of them is inability to create a filesystem (i.e. ext4) in the
guest:
>>>
>>> - btrfs filesystem on the host was mounted with
noatime,compress-force
>>> - guest was using a 50 GB sparse file,
>>> - attempt to create a ext4 filesystem within the guest does not
succeed (hangs); host prints below messages in dmesg - some deadlock in btrfs?
>>>
>>> kernel: 2.6.36
>>> qemu-kvm: 0.13.0
>>
>> Is this the full dmesg output?  I think there are other messages hiding
>> in there.
>
> There were indeed "bad ordered accounting left" (see below), I
think they are coming from btrfs?
>
>
>> Is this a single disk btrfs?
>
> Yes.
>
>
>
> [ 8072.773053] device fsid 1142843480ad2d13-4bdc742fd9b1f7b0 devid 1
transid 1508 /dev/sdb4
> [ 8072.773674] btrfs: forcing compression
> [ 8122.052221] device tap0 entered promiscuous mode
> [ 8122.052245] br0: port 2(tap0) entering learning state
> [ 8122.052248] br0: port 2(tap0) entering learning state
> [ 8122.451587] br0: port 2(tap0) entering learning state
> [ 8122.543477] br0: port 2(tap0) entering disabled state
> [ 8122.609645] device tap0 left promiscuous mode
> [ 8122.609650] br0: port 2(tap0) entering disabled state
> [ 8131.325647] EXT4-fs (md4): recovery complete
> [ 8131.325809] EXT4-fs (md4): mounted filesystem with ordered data mode.
Opts: (null)
> [ 8133.392100] device tap0 entered promiscuous mode
> [ 8133.392127] br0: port 2(tap0) entering learning state
> [ 8133.392131] br0: port 2(tap0) entering learning state
> [ 8134.106594] kvm: 5004: cpu0 unhandled wrmsr: 0x198 data 0
> [ 8134.106618] kvm: 5004: cpu1 unhandled wrmsr: 0x198 data 0
> [ 8143.460927] tap0: no IPv6 routers present
> [ 8148.359485] br0: port 2(tap0) entering forwarding state
> [ 8309.103502] bad ordered accounting left 65536 size 385024
> [ 8309.106206] bad ordered accounting left 65536 size 385024
> [ 8309.108915] bad ordered accounting left 65536 size 385024
> [ 8309.111630] bad ordered accounting left 36864 size 385024
> [ 8501.965625] INFO: task qemu-system-x86:5148 blocked for more than 120
seconds.
> [ 8501.965629] "echo 0 >
/proc/sys/kernel/hung_task_timeout_secs" disables this message.
> [ 8501.965632] qemu-system-x D ffff880001e14cc0     0  5148   4924
0x00000000
> [ 8501.965638]  ffff880223bc3b38 0000000000000086 ffff880223bc3fd8
0000000000014cc0
> [ 8501.965642]  0000000000014cc0 ffff880223bc3fd8 0000000000014cc0
ffff880223bc3fd8
> [ 8501.965647]  0000000000014cc0 ffff880221965f18 ffff880221965f20
ffff880221965b80
> [ 8501.965651] Call Trace:
> [ 8501.965678]  [<ffffffffa024c52c>]
btrfs_start_ordered_extent+0x6c/0xb0 [btrfs]
> [ 8501.965685]  [<ffffffff81083200>] ?
autoremove_wake_function+0x0/0x40
> [ 8501.965701]  [<ffffffffa024d1c2>]
btrfs_wait_ordered_range+0xd2/0x160 [btrfs]
> [ 8501.965716]  [<ffffffffa0240059>] btrfs_file_aio_write+0x269/0x990
[btrfs]
> [ 8501.965721]  [<ffffffff8105ca94>] ? try_to_wake_up+0xf4/0x3f0
> [ 8501.965726]  [<ffffffff81168119>] ? __pollwake+0x49/0x50
> [ 8501.965730]  [<ffffffff8105cd90>] ? default_wake_function+0x0/0x20
> [ 8501.965733]  [<ffffffff8105ca94>] ? try_to_wake_up+0xf4/0x3f0
> [ 8501.965737]  [<ffffffff8116813b>] ? pollwake+0x1b/0x20
> [ 8501.965752]  [<ffffffffa023fdf0>] ? btrfs_file_aio_write+0x0/0x990
[btrfs]
> [ 8501.965761]  [<ffffffff8115664b>] do_sync_readv_writev+0xcb/0x110
> [ 8501.965769]  [<ffffffff81294d98>] ?
apparmor_file_permission+0x18/0x20
> [ 8501.965776]  [<ffffffff8126356e>] ?
security_file_permission+0x1e/0x80
> [ 8501.965781]  [<ffffffff811576e0>] do_readv_writev+0xd0/0x1d0
> [ 8501.965787]  [<ffffffff81076d72>] ? kill_something_info+0x42/0x130
> [ 8501.965793]  [<ffffffff81076ee0>] ? sys_kill+0x80/0x90
> [ 8501.965798]  [<ffffffff8115781e>] vfs_writev+0x3e/0x60
> [ 8501.965802]  [<ffffffff811578e7>] sys_pwritev+0xa7/0xc0
> [ 8501.965806]  [<ffffffff8100b0f2>] system_call_fastpath+0x16/0x1b
> [ 8501.965810] INFO: task qemu-system-x86:5150 blocked for more than 120
seconds.
> [ 8501.965812] "echo 0 >
/proc/sys/kernel/hung_task_timeout_secs" disables this message.
> [ 8501.965814] qemu-system-x D ffff880001e94cc0     0  5150   4924
0x00000000
> [ 8501.965819]  ffff8801aba4bb38 0000000000000086 ffff8801aba4bfd8
0000000000014cc0
> [ 8501.965823]  0000000000014cc0 ffff8801aba4bfd8 0000000000014cc0
ffff8801aba4bfd8
> [ 8501.965827]  0000000000014cc0 ffff880226d14838 ffff880226d14840
ffff880226d144a0
> [ 8501.965832] Call Trace:
> [ 8501.965847]  [<ffffffffa024c52c>]
btrfs_start_ordered_extent+0x6c/0xb0 [btrfs]
> [ 8501.965852]  [<ffffffff81083200>] ?
autoremove_wake_function+0x0/0x40
> [ 8501.965867]  [<ffffffffa024d1c2>]
btrfs_wait_ordered_range+0xd2/0x160 [btrfs]
> [ 8501.965883]  [<ffffffffa0240059>] btrfs_file_aio_write+0x269/0x990
[btrfs]
> [ 8501.965887]  [<ffffffff8105ca94>] ? try_to_wake_up+0xf4/0x3f0
> [ 8501.965891]  [<ffffffff81168119>] ? __pollwake+0x49/0x50
> [ 8501.965894]  [<ffffffff8105cd90>] ? default_wake_function+0x0/0x20
> [ 8501.965897]  [<ffffffff8105ca94>] ? try_to_wake_up+0xf4/0x3f0
> [ 8501.965901]  [<ffffffff8116813b>] ? pollwake+0x1b/0x20
> [ 8501.965916]  [<ffffffffa023fdf0>] ? btrfs_file_aio_write+0x0/0x990
[btrfs]
> [ 8501.965920]  [<ffffffff8115664b>] do_sync_readv_writev+0xcb/0x110
> [ 8501.965924]  [<ffffffff81076736>] ? send_signal+0x56/0xa0
> [ 8501.965928]  [<ffffffff81294d98>] ?
apparmor_file_permission+0x18/0x20
> [ 8501.965932]  [<ffffffff8126356e>] ?
security_file_permission+0x1e/0x80
> [ 8501.965936]  [<ffffffff811576e0>] do_readv_writev+0xd0/0x1d0
> [ 8501.965940]  [<ffffffff8115781e>] vfs_writev+0x3e/0x60
> [ 8501.965943]  [<ffffffff811578e7>] sys_pwritev+0xa7/0xc0
> [ 8501.965946]  [<ffffffff8100b0f2>] system_call_fastpath+0x16/0x1b
> [ 8501.965950] INFO: task qemu-system-x86:5151 blocked for more than 120
seconds.
> [ 8501.965952] "echo 0 >
/proc/sys/kernel/hung_task_timeout_secs" disables this message.
> [ 8501.965954] qemu-system-x D ffff880001e94cc0     0  5151   4924
0x00000000
> [ 8501.965958]  ffff88021923fb38 0000000000000086 ffff88021923ffd8
0000000000014cc0
> [ 8501.965963]  0000000000014cc0 ffff88021923ffd8 0000000000014cc0
ffff88021923ffd8
> [ 8501.965967]  0000000000014cc0 ffff880226d13158 ffff880226d13160
ffff880226d12dc0
> [ 8501.965971] Call Trace:
> [ 8501.965986]  [<ffffffffa024c52c>]
btrfs_start_ordered_extent+0x6c/0xb0 [btrfs]
> [ 8501.965990]  [<ffffffff81083200>] ?
autoremove_wake_function+0x0/0x40
> [ 8501.966005]  [<ffffffffa024d1c2>]
btrfs_wait_ordered_range+0xd2/0x160 [btrfs]
> [ 8501.966021]  [<ffffffffa0240059>] btrfs_file_aio_write+0x269/0x990
[btrfs]
> [ 8501.966025]  [<ffffffff8105ca94>] ? try_to_wake_up+0xf4/0x3f0
> [ 8501.966029]  [<ffffffff81168119>] ? __pollwake+0x49/0x50
> [ 8501.966032]  [<ffffffff8105cd90>] ? default_wake_function+0x0/0x20
> [ 8501.966036]  [<ffffffff8105ca94>] ? try_to_wake_up+0xf4/0x3f0
> [ 8501.966039]  [<ffffffff8116813b>] ? pollwake+0x1b/0x20
> [ 8501.966054]  [<ffffffffa023fdf0>] ? btrfs_file_aio_write+0x0/0x990
[btrfs]
> [ 8501.966058]  [<ffffffff8115664b>] do_sync_readv_writev+0xcb/0x110
> [ 8501.966062]  [<ffffffff81076736>] ? send_signal+0x56/0xa0
> [ 8501.966066]  [<ffffffff81294d98>] ?
apparmor_file_permission+0x18/0x20
> [ 8501.966070]  [<ffffffff8126356e>] ?
security_file_permission+0x1e/0x80
> [ 8501.966074]  [<ffffffff811576e0>] do_readv_writev+0xd0/0x1d0
> [ 8501.966078]  [<ffffffff8115781e>] vfs_writev+0x3e/0x60
> [ 8501.966081]  [<ffffffff811578e7>] sys_pwritev+0xa7/0xc0
> [ 8501.966084]  [<ffffffff8100b0f2>] system_call_fastpath+0x16/0x1b
i decided to revive this thread because i''m getting the identical
problem on a near identical setup, but im NOT using compression, only
nodatacow/noatime.

) 2.6.36.2 kernel
) qemu-kvm 0.13.0
) kvm-amd
) 8.0GB raw image file:

# uname -a
Linux extofme-w0 2.6.36-ARCH #1 SMP PREEMPT Fri Dec 10 20:32:37 CET
2010 x86_64 AMD Athlon(tm) II X3 435 Processor AuthenticAMD GNU/Linux

# mount -t btrfs
...
/dev/sda3 on /var/lib/libvirt/images type btrfs (rw,noatime,nodatacow)
...

# pacman -Qi qemu-kvm
Name           : qemu-kvm
Version        : 0.13.0-1
...

(qemu command generated by libvirt [winXPPro])
/usr/bin/qemu-kvm -S -M pc-0.13 -enable-kvm -m 1024 -smp
3,sockets=3,cores=1,threads=1 -name XPPro -uuid
ed78cc76-006f-b408-b8f6-f1f30be43589 -nodefconfig -nodefaults -chardev
socket,id=monitor,path=/var/lib/libvirt/qemu/XPPro.monitor,server,nowait
-mon chardev=monitor,mode=control -rtc base=localtime -no-reboot -boot
c -drive
file=/var/lib/libvirt/images/XPPro.img,if=none,id=drive-ide0-0-0,format=raw,cache=none
-device ide-drive,bus=ide.0,unit=0,drive=drive-ide0-0-0,id=ide0-0-0
-drive file=/mnt/Backups/Disk Images/Windows XP
Professional.iso,if=none,media=cdrom,id=drive-ide0-1-0,readonly=on,format=raw
-device ide-drive,bus=ide.1,unit=0,drive=drive-ide0-1-0,id=ide0-1-0
-netdev tap,fd=41,id=hostnet0 -device
rtl8139,netdev=hostnet0,id=net0,mac=52:54:00:8e:e4:14,bus=pci.0,addr=0x3
-chardev pty,id=serial0 -device isa-serial,chardev=serial0 -usb
-device usb-tablet,id=input0 -vnc 127.0.0.1:0 -vga cirrus -device
AC97,id=sound0,bus=pci.0,addr=0x4 -device
virtio-balloon-pci,id=balloon0,bus=pci.0,addr=0x5

----------------------[dmesg]-------------------------
bad ordered accounting left 4096 size 57344
INFO: task qemu-kvm:6451 blocked for more than 120 seconds.
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this
message.
qemu-kvm      D 00000001000850d5     0  6451      1 0x00000000
 ffff880008d7bb38 0000000000000086 ffff880008d7baa8 ffff880008d7bfd8
 ffff880008d7a000 ffff8800089df5f0 ffff880008d7bfd8 ffff880008d7bfd8
 ffff8800089df8b0 ffff880008d7bfd8 ffff880008d7a000 0000000000014400
Call Trace:
 [<ffffffff81075ddb>] ? prepare_to_wait+0x5b/0x90
 [<ffffffffa023a225>] btrfs_start_ordered_extent+0x75/0xc0 [btrfs]
 [<ffffffff81075b40>] ? autoremove_wake_function+0x0/0x40
 [<ffffffffa023a819>] btrfs_wait_ordered_range+0xb9/0x150 [btrfs]
 [<ffffffffa022b650>] ? btrfs_file_aio_write+0x0/0x9a0 [btrfs]
 [<ffffffffa022bb82>] btrfs_file_aio_write+0x532/0x9a0 [btrfs]
 [<ffffffff81079b6a>] ? hrtimer_cancel+0x1a/0x30
 [<ffffffff810877c2>] ? futex_wait+0x222/0x380
 [<ffffffffa022b650>] ? btrfs_file_aio_write+0x0/0x9a0 [btrfs]
 [<ffffffff8112e3fb>] do_sync_readv_writev+0xcb/0x110
 [<ffffffff8106882b>] ? do_send_sig_info+0x6b/0x90
 [<ffffffff811b0844>] ? security_file_permission+0x24/0xa0
 [<ffffffff8112e6af>] do_readv_writev+0xcf/0x1e0
 [<ffffffff81068bfa>] ? kill_pid_info+0x4a/0xa0
 [<ffffffff81069f84>] ? sys_kill+0xa4/0x1f0
 [<ffffffff8112e800>] vfs_writev+0x40/0x50
 [<ffffffff8112eb0a>] sys_pwritev+0x9a/0xb0
 [<ffffffff81155ca0>] ? do_fsync+0x40/0x60
 [<ffffffff8100af42>] system_call_fastpath+0x16/0x1b
(... repeated every 120s ...)
----------------------[dmesg]-------------------------

any idea what''s happening here, or anything i can try/test?  seems to
happen consistently within about 2-4min of starting the window xp
installation.

C Anthony
--
To unsubscribe from this list: send the line "unsubscribe linux-btrfs"
in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Excerpts from C Anthony Risinger''s message of 2010-12-15 11:46:11
-0500:
> On Thu, Oct 28, 2010 at 1:29 AM, Tomasz Chmielewski <mangoo@wpkg.org>
wrote:
> > On 28.10.2010 00:55, Chris Mason wrote:
> >> On Wed, Oct 27, 2010 at 03:29:38PM +0200, Tomasz Chmielewski
wrote:
> >>> There are a couple of problems when running KVM guests with
images stored on btrfs filesystem.
> >>>
> >>> One of them is inability to create a filesystem (i.e. ext4) in
the guest:
> >>>
> >>> - btrfs filesystem on the host was mounted with
noatime,compress-force
> >>> - guest was using a 50 GB sparse file,
> >>> - attempt to create a ext4 filesystem within the guest does
not succeed (hangs); host prints below messages in dmesg - some deadlock in
btrfs?
> >>>
> >>> kernel: 2.6.36
> >>> qemu-kvm: 0.13.0
> >>
> >> Is this the full dmesg output?  I think there are other messages
hiding
> >> in there.
> >
> > There were indeed "bad ordered accounting left" (see below),
I think they are coming from btrfs?
> >
> >
> >> Is this a single disk btrfs?
> >
> > Yes.
> >
> >
> >
> > [ 8072.773053] device fsid 1142843480ad2d13-4bdc742fd9b1f7b0 devid 1
transid 1508 /dev/sdb4
> > [ 8072.773674] btrfs: forcing compression
> > [ 8122.052221] device tap0 entered promiscuous mode
> > [ 8122.052245] br0: port 2(tap0) entering learning state
> > [ 8122.052248] br0: port 2(tap0) entering learning state
> > [ 8122.451587] br0: port 2(tap0) entering learning state
> > [ 8122.543477] br0: port 2(tap0) entering disabled state
> > [ 8122.609645] device tap0 left promiscuous mode
> > [ 8122.609650] br0: port 2(tap0) entering disabled state
> > [ 8131.325647] EXT4-fs (md4): recovery complete
> > [ 8131.325809] EXT4-fs (md4): mounted filesystem with ordered data
mode. Opts: (null)
> > [ 8133.392100] device tap0 entered promiscuous mode
> > [ 8133.392127] br0: port 2(tap0) entering learning state
> > [ 8133.392131] br0: port 2(tap0) entering learning state
> > [ 8134.106594] kvm: 5004: cpu0 unhandled wrmsr: 0x198 data 0
> > [ 8134.106618] kvm: 5004: cpu1 unhandled wrmsr: 0x198 data 0
> > [ 8143.460927] tap0: no IPv6 routers present
> > [ 8148.359485] br0: port 2(tap0) entering forwarding state
> > [ 8309.103502] bad ordered accounting left 65536 size 385024
> > [ 8309.106206] bad ordered accounting left 65536 size 385024
> > [ 8309.108915] bad ordered accounting left 65536 size 385024
> > [ 8309.111630] bad ordered accounting left 36864 size 385024
> > [ 8501.965625] INFO: task qemu-system-x86:5148 blocked for more than
120 seconds.
> > [ 8501.965629] "echo 0 >
/proc/sys/kernel/hung_task_timeout_secs" disables this message.
> > [ 8501.965632] qemu-system-x D ffff880001e14cc0     0  5148   4924
0x00000000
> > [ 8501.965638]  ffff880223bc3b38 0000000000000086 ffff880223bc3fd8
0000000000014cc0
> > [ 8501.965642]  0000000000014cc0 ffff880223bc3fd8 0000000000014cc0
ffff880223bc3fd8
> > [ 8501.965647]  0000000000014cc0 ffff880221965f18 ffff880221965f20
ffff880221965b80
> > [ 8501.965651] Call Trace:
> > [ 8501.965678]  [<ffffffffa024c52c>]
btrfs_start_ordered_extent+0x6c/0xb0 [btrfs]
> > [ 8501.965685]  [<ffffffff81083200>] ?
autoremove_wake_function+0x0/0x40
> > [ 8501.965701]  [<ffffffffa024d1c2>]
btrfs_wait_ordered_range+0xd2/0x160 [btrfs]
> > [ 8501.965716]  [<ffffffffa0240059>]
btrfs_file_aio_write+0x269/0x990 [btrfs]
> > [ 8501.965721]  [<ffffffff8105ca94>] ?
try_to_wake_up+0xf4/0x3f0
> > [ 8501.965726]  [<ffffffff81168119>] ? __pollwake+0x49/0x50
> > [ 8501.965730]  [<ffffffff8105cd90>] ?
default_wake_function+0x0/0x20
> > [ 8501.965733]  [<ffffffff8105ca94>] ?
try_to_wake_up+0xf4/0x3f0
> > [ 8501.965737]  [<ffffffff8116813b>] ? pollwake+0x1b/0x20
> > [ 8501.965752]  [<ffffffffa023fdf0>] ?
btrfs_file_aio_write+0x0/0x990 [btrfs]
> > [ 8501.965761]  [<ffffffff8115664b>]
do_sync_readv_writev+0xcb/0x110
> > [ 8501.965769]  [<ffffffff81294d98>] ?
apparmor_file_permission+0x18/0x20
> > [ 8501.965776]  [<ffffffff8126356e>] ?
security_file_permission+0x1e/0x80
> > [ 8501.965781]  [<ffffffff811576e0>] do_readv_writev+0xd0/0x1d0
> > [ 8501.965787]  [<ffffffff81076d72>] ?
kill_something_info+0x42/0x130
> > [ 8501.965793]  [<ffffffff81076ee0>] ? sys_kill+0x80/0x90
> > [ 8501.965798]  [<ffffffff8115781e>] vfs_writev+0x3e/0x60
> > [ 8501.965802]  [<ffffffff811578e7>] sys_pwritev+0xa7/0xc0
> > [ 8501.965806]  [<ffffffff8100b0f2>]
system_call_fastpath+0x16/0x1b
> > [ 8501.965810] INFO: task qemu-system-x86:5150 blocked for more than
120 seconds.
> > [ 8501.965812] "echo 0 >
/proc/sys/kernel/hung_task_timeout_secs" disables this message.
> > [ 8501.965814] qemu-system-x D ffff880001e94cc0     0  5150   4924
0x00000000
> > [ 8501.965819]  ffff8801aba4bb38 0000000000000086 ffff8801aba4bfd8
0000000000014cc0
> > [ 8501.965823]  0000000000014cc0 ffff8801aba4bfd8 0000000000014cc0
ffff8801aba4bfd8
> > [ 8501.965827]  0000000000014cc0 ffff880226d14838 ffff880226d14840
ffff880226d144a0
> > [ 8501.965832] Call Trace:
> > [ 8501.965847]  [<ffffffffa024c52c>]
btrfs_start_ordered_extent+0x6c/0xb0 [btrfs]
> > [ 8501.965852]  [<ffffffff81083200>] ?
autoremove_wake_function+0x0/0x40
> > [ 8501.965867]  [<ffffffffa024d1c2>]
btrfs_wait_ordered_range+0xd2/0x160 [btrfs]
> > [ 8501.965883]  [<ffffffffa0240059>]
btrfs_file_aio_write+0x269/0x990 [btrfs]
> > [ 8501.965887]  [<ffffffff8105ca94>] ?
try_to_wake_up+0xf4/0x3f0
> > [ 8501.965891]  [<ffffffff81168119>] ? __pollwake+0x49/0x50
> > [ 8501.965894]  [<ffffffff8105cd90>] ?
default_wake_function+0x0/0x20
> > [ 8501.965897]  [<ffffffff8105ca94>] ?
try_to_wake_up+0xf4/0x3f0
> > [ 8501.965901]  [<ffffffff8116813b>] ? pollwake+0x1b/0x20
> > [ 8501.965916]  [<ffffffffa023fdf0>] ?
btrfs_file_aio_write+0x0/0x990 [btrfs]
> > [ 8501.965920]  [<ffffffff8115664b>]
do_sync_readv_writev+0xcb/0x110
> > [ 8501.965924]  [<ffffffff81076736>] ? send_signal+0x56/0xa0
> > [ 8501.965928]  [<ffffffff81294d98>] ?
apparmor_file_permission+0x18/0x20
> > [ 8501.965932]  [<ffffffff8126356e>] ?
security_file_permission+0x1e/0x80
> > [ 8501.965936]  [<ffffffff811576e0>] do_readv_writev+0xd0/0x1d0
> > [ 8501.965940]  [<ffffffff8115781e>] vfs_writev+0x3e/0x60
> > [ 8501.965943]  [<ffffffff811578e7>] sys_pwritev+0xa7/0xc0
> > [ 8501.965946]  [<ffffffff8100b0f2>]
system_call_fastpath+0x16/0x1b
> > [ 8501.965950] INFO: task qemu-system-x86:5151 blocked for more than
120 seconds.
> > [ 8501.965952] "echo 0 >
/proc/sys/kernel/hung_task_timeout_secs" disables this message.
> > [ 8501.965954] qemu-system-x D ffff880001e94cc0     0  5151   4924
0x00000000
> > [ 8501.965958]  ffff88021923fb38 0000000000000086 ffff88021923ffd8
0000000000014cc0
> > [ 8501.965963]  0000000000014cc0 ffff88021923ffd8 0000000000014cc0
ffff88021923ffd8
> > [ 8501.965967]  0000000000014cc0 ffff880226d13158 ffff880226d13160
ffff880226d12dc0
> > [ 8501.965971] Call Trace:
> > [ 8501.965986]  [<ffffffffa024c52c>]
btrfs_start_ordered_extent+0x6c/0xb0 [btrfs]
> > [ 8501.965990]  [<ffffffff81083200>] ?
autoremove_wake_function+0x0/0x40
> > [ 8501.966005]  [<ffffffffa024d1c2>]
btrfs_wait_ordered_range+0xd2/0x160 [btrfs]
> > [ 8501.966021]  [<ffffffffa0240059>]
btrfs_file_aio_write+0x269/0x990 [btrfs]
> > [ 8501.966025]  [<ffffffff8105ca94>] ?
try_to_wake_up+0xf4/0x3f0
> > [ 8501.966029]  [<ffffffff81168119>] ? __pollwake+0x49/0x50
> > [ 8501.966032]  [<ffffffff8105cd90>] ?
default_wake_function+0x0/0x20
> > [ 8501.966036]  [<ffffffff8105ca94>] ?
try_to_wake_up+0xf4/0x3f0
> > [ 8501.966039]  [<ffffffff8116813b>] ? pollwake+0x1b/0x20
> > [ 8501.966054]  [<ffffffffa023fdf0>] ?
btrfs_file_aio_write+0x0/0x990 [btrfs]
> > [ 8501.966058]  [<ffffffff8115664b>]
do_sync_readv_writev+0xcb/0x110
> > [ 8501.966062]  [<ffffffff81076736>] ? send_signal+0x56/0xa0
> > [ 8501.966066]  [<ffffffff81294d98>] ?
apparmor_file_permission+0x18/0x20
> > [ 8501.966070]  [<ffffffff8126356e>] ?
security_file_permission+0x1e/0x80
> > [ 8501.966074]  [<ffffffff811576e0>] do_readv_writev+0xd0/0x1d0
> > [ 8501.966078]  [<ffffffff8115781e>] vfs_writev+0x3e/0x60
> > [ 8501.966081]  [<ffffffff811578e7>] sys_pwritev+0xa7/0xc0
> > [ 8501.966084]  [<ffffffff8100b0f2>]
system_call_fastpath+0x16/0x1b
> 
> i decided to revive this thread because i''m getting the identical
> problem on a near identical setup, but im NOT using compression, only
> nodatacow/noatime.
> 
> ) 2.6.36.2 kernel
> ) qemu-kvm 0.13.0
> ) kvm-amd
> ) 8.0GB raw image file:
> 
> # uname -a
> Linux extofme-w0 2.6.36-ARCH #1 SMP PREEMPT Fri Dec 10 20:32:37 CET
> 2010 x86_64 AMD Athlon(tm) II X3 435 Processor AuthenticAMD GNU/Linux
> 
> # mount -t btrfs
> ...
> /dev/sda3 on /var/lib/libvirt/images type btrfs (rw,noatime,nodatacow)
> ...
> 
> # pacman -Qi qemu-kvm
> Name           : qemu-kvm
> Version        : 0.13.0-1
> ...
> 
> (qemu command generated by libvirt [winXPPro])
> /usr/bin/qemu-kvm -S -M pc-0.13 -enable-kvm -m 1024 -smp
> 3,sockets=3,cores=1,threads=1 -name XPPro -uuid
> ed78cc76-006f-b408-b8f6-f1f30be43589 -nodefconfig -nodefaults -chardev
> socket,id=monitor,path=/var/lib/libvirt/qemu/XPPro.monitor,server,nowait
> -mon chardev=monitor,mode=control -rtc base=localtime -no-reboot -boot
> c -drive
file=/var/lib/libvirt/images/XPPro.img,if=none,id=drive-ide0-0-0,format=raw,cache=none
> -device ide-drive,bus=ide.0,unit=0,drive=drive-ide0-0-0,id=ide0-0-0
> -drive file=/mnt/Backups/Disk Images/Windows XP
>
Professional.iso,if=none,media=cdrom,id=drive-ide0-1-0,readonly=on,format=raw
> -device ide-drive,bus=ide.1,unit=0,drive=drive-ide0-1-0,id=ide0-1-0
> -netdev tap,fd=41,id=hostnet0 -device
> rtl8139,netdev=hostnet0,id=net0,mac=52:54:00:8e:e4:14,bus=pci.0,addr=0x3
> -chardev pty,id=serial0 -device isa-serial,chardev=serial0 -usb
> -device usb-tablet,id=input0 -vnc 127.0.0.1:0 -vga cirrus -device
> AC97,id=sound0,bus=pci.0,addr=0x4 -device
> virtio-balloon-pci,id=balloon0,bus=pci.0,addr=0x5
> 
> ----------------------[dmesg]-------------------------
> bad ordered accounting left 4096 size 57344
> INFO: task qemu-kvm:6451 blocked for more than 120 seconds.
> "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables
this message.
> qemu-kvm      D 00000001000850d5     0  6451      1 0x00000000
>  ffff880008d7bb38 0000000000000086 ffff880008d7baa8 ffff880008d7bfd8
>  ffff880008d7a000 ffff8800089df5f0 ffff880008d7bfd8 ffff880008d7bfd8
>  ffff8800089df8b0 ffff880008d7bfd8 ffff880008d7a000 0000000000014400
> Call Trace:
>  [<ffffffff81075ddb>] ? prepare_to_wait+0x5b/0x90
>  [<ffffffffa023a225>] btrfs_start_ordered_extent+0x75/0xc0 [btrfs]
>  [<ffffffff81075b40>] ? autoremove_wake_function+0x0/0x40
>  [<ffffffffa023a819>] btrfs_wait_ordered_range+0xb9/0x150 [btrfs]
>  [<ffffffffa022b650>] ? btrfs_file_aio_write+0x0/0x9a0 [btrfs]
>  [<ffffffffa022bb82>] btrfs_file_aio_write+0x532/0x9a0 [btrfs]
>  [<ffffffff81079b6a>] ? hrtimer_cancel+0x1a/0x30
>  [<ffffffff810877c2>] ? futex_wait+0x222/0x380
>  [<ffffffffa022b650>] ? btrfs_file_aio_write+0x0/0x9a0 [btrfs]
>  [<ffffffff8112e3fb>] do_sync_readv_writev+0xcb/0x110
>  [<ffffffff8106882b>] ? do_send_sig_info+0x6b/0x90
>  [<ffffffff811b0844>] ? security_file_permission+0x24/0xa0
>  [<ffffffff8112e6af>] do_readv_writev+0xcf/0x1e0
>  [<ffffffff81068bfa>] ? kill_pid_info+0x4a/0xa0
>  [<ffffffff81069f84>] ? sys_kill+0xa4/0x1f0
>  [<ffffffff8112e800>] vfs_writev+0x40/0x50
>  [<ffffffff8112eb0a>] sys_pwritev+0x9a/0xb0
>  [<ffffffff81155ca0>] ? do_fsync+0x40/0x60
>  [<ffffffff8100af42>] system_call_fastpath+0x16/0x1b
> (... repeated every 120s ...)
> ----------------------[dmesg]-------------------------
> 
> any idea what''s happening here, or anything i can try/test?  seems
to
> happen consistently within about 2-4min of starting the window xp
> installation.
I think these are fixed up in the current btrfs git tree.  2.6.37-rcX
has the fixes, and you can pull from the git tree for 2.6.36.

-chris
--
To unsubscribe from this list: send the line "unsubscribe linux-btrfs"
in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html