[Linux-cachefs] Issues
Edward "Koko" Konetzko
konetzed at quixoticagony.com
Mon Jun 22 21:17:49 UTC 2009
David Howells wrote:
> If you could turn:
> + _debug("discard tail %llx", oi_size);
>
> back to:
>
> + kdebug("discard tail %llx", oi_size);
>
> I'd be interested in knowing if that's triggering at all. If it is, that
> could be slowing things down (it indicates a truncation will be performed).
>
>
Nothing about "discard" in dmesg I do however get this.
BUG: soft lockup - CPU#1 stuck for 61s! [kswapd1:383]
Modules linked in: ipv6 nfs lockd nfs_acl auth_rpcgss sunrpc cachefiles
fscache dm_mirror dm_region_hash dm_log dm_multipath scsi_dh dm_mod
video output sbs sbshc battery acpi_memhotplug ac parport_pc lp parport
ipmi_devintf serio_raw bnx2 button k8temp hwmon i2c_piix4 ipmi_si
i2c_core shpchp ipmi_msghandler hpilo rtc_cmos rtc_core pcspkr rtc_lib
usb_storage cciss sd_mod scsi_mod ext3 jbd uhci_hcd ohci_hcd ehci_hcd
CPU 1:
Modules linked in: ipv6 nfs lockd nfs_acl auth_rpcgss sunrpc cachefiles
fscache dm_mirror dm_region_hash dm_log dm_multipath scsi_dh dm_mod
video output sbs sbshc battery acpi_memhotplug ac parport_pc lp parport
ipmi_devintf serio_raw bnx2 button k8temp hwmon i2c_piix4 ipmi_si
i2c_core shpchp ipmi_msghandler hpilo rtc_cmos rtc_core pcspkr rtc_lib
usb_storage cciss sd_mod scsi_mod ext3 jbd uhci_hcd ohci_hcd ehci_hcd
Pid: 383, comm: kswapd1 Not tainted 2.6.30-dh #3 ProLiant DL385 G2
RIP: 0010:[<ffffffff8028077a>] [<ffffffff8028077a>]
find_get_pages+0x48/0xbf
RSP: 0018:ffff88007ed33c70 EFLAGS: 00000246
RAX: ffff8800425dab30 RBX: 0000000000000000 RCX: 0000000000000000
RDX: 0000000000000002 RSI: ffffe200010ba7c0 RDI: ffffe200010ba7b8
RBP: ffffffff8020c44e R08: 0000000000000003 R09: 0000000000000040
R10: 0000000000000002 R11: 0000000000000040 R12: ffffe200010a4478
R13: ffffffff802a64d4 R14: 0000000000000000 R15: ffff8800426db198
FS: 00007fb0b47db6e0(0000) GS:ffffc20000013000(0000) knlGS:0000000000000000
CS: 0010 DS: 0018 ES: 0018 CR0: 000000008005003b
CR2: 00007f6a44b28000 CR3: 000000012c478000 CR4: 00000000000006e0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
Call Trace:
[<ffffffff80287294>] ? pagevec_lookup+0x17/0x1f
[<ffffffff802875e6>] ? __invalidate_mapping_pages+0xfc/0x119
[<ffffffff802bc8f5>] ? shrink_icache_memory+0xed/0x20a
[<ffffffff802894bb>] ? shrink_slab+0xd8/0x150
[<ffffffff8028a156>] ? kswapd+0x37c/0x54c
[<ffffffff80287ad7>] ? isolate_pages_global+0x0/0x1f8
[<ffffffff8024a422>] ? autoremove_wake_function+0x0/0x2e
[<ffffffff8022bb4b>] ? __wake_up_common+0x3f/0x71
[<ffffffff80289dda>] ? kswapd+0x0/0x54c
[<ffffffff80289dda>] ? kswapd+0x0/0x54c
[<ffffffff8024a2f3>] ? kthread+0x54/0x81
[<ffffffff8020c93a>] ? child_rip+0xa/0x20
[<ffffffff8024a29f>] ? kthread+0x0/0x81
[<ffffffff8020c930>] ? child_rip+0x0/0x20
BUG: soft lockup - CPU#1 stuck for 61s! [kswapd1:383]
Modules linked in: ipv6 nfs lockd nfs_acl auth_rpcgss sunrpc cachefiles
fscache dm_mirror dm_region_hash dm_log dm_multipath scsi_dh dm_mod
video output sbs sbshc battery acpi_memhotplug ac parport_pc lp parport
ipmi_devintf serio_raw bnx2 button k8temp hwmon i2c_piix4 ipmi_si
i2c_core shpchp ipmi_msghandler hpilo rtc_cmos rtc_core pcspkr rtc_lib
usb_storage cciss sd_mod scsi_mod ext3 jbd uhci_hcd ohci_hcd ehci_hcd
CPU 1:
Modules linked in: ipv6 nfs lockd nfs_acl auth_rpcgss sunrpc cachefiles
fscache dm_mirror dm_region_hash dm_log dm_multipath scsi_dh dm_mod
video output sbs sbshc battery acpi_memhotplug ac parport_pc lp parport
ipmi_devintf serio_raw bnx2 button k8temp hwmon i2c_piix4 ipmi_si
i2c_core shpchp ipmi_msghandler hpilo rtc_cmos rtc_core pcspkr rtc_lib
usb_storage cciss sd_mod scsi_mod ext3 jbd uhci_hcd ohci_hcd ehci_hcd
Pid: 383, comm: kswapd1 Not tainted 2.6.30-dh #3 ProLiant DL385 G2
RIP: 0010:[<ffffffff8028077e>] [<ffffffff8028077e>]
find_get_pages+0x4c/0xbf
RSP: 0018:ffff88007ed33c70 EFLAGS: 00000246
RAX: ffff8800425dab30 RBX: 0000000000000000 RCX: 0000000000000000
RDX: 0000000000000002 RSI: ffffe200010ba7c0 RDI: ffffe200010ba7b8
RBP: ffffffff8020c44e R08: 0000000000000003 R09: 0000000000000040
R10: 0000000000000002 R11: 0000000000000040 R12: ffffe200010a4478
R13: ffffffff802a64d4 R14: 0000000000000000 R15: ffff8800426db198
FS: 00007fb0b47db6e0(0000) GS:ffffc20000013000(0000) knlGS:0000000000000000
CS: 0010 DS: 0018 ES: 0018 CR0: 000000008005003b
CR2: 00007f6a44b28000 CR3: 000000012c478000 CR4: 00000000000006e0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
Call Trace:
[<ffffffff80287294>] ? pagevec_lookup+0x17/0x1f
[<ffffffff802875e6>] ? __invalidate_mapping_pages+0xfc/0x119
[<ffffffff802bc8f5>] ? shrink_icache_memory+0xed/0x20a
[<ffffffff802894bb>] ? shrink_slab+0xd8/0x150
[<ffffffff8028a156>] ? kswapd+0x37c/0x54c
[<ffffffff80287ad7>] ? isolate_pages_global+0x0/0x1f8
[<ffffffff8024a422>] ? autoremove_wake_function+0x0/0x2e
[<ffffffff8022bb4b>] ? __wake_up_common+0x3f/0x71
[<ffffffff80289dda>] ? kswapd+0x0/0x54c
[<ffffffff80289dda>] ? kswapd+0x0/0x54c
[<ffffffff8024a2f3>] ? kthread+0x54/0x81
[<ffffffff8020c93a>] ? child_rip+0xa/0x20
[<ffffffff8024a29f>] ? kthread+0x0/0x81
[<ffffffff8020c930>] ? child_rip+0x0/0x20
INFO: task kswapd0:382 blocked for more than 120 seconds.
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
kswapd0 D ffffc200000106c0 0 382 2
ffff88007ffc4080 0000000000000046 ffffffff8064d740 0000000000000001
0000000000000000 ffff88007ed1d840 ffff88007ed1dbc8 ffff88007ed31fd8
ffffc200000236c0 0000000000000001 ffff88007ed32000 ffffffff8064d740
Call Trace:
[<ffffffff804bcdb3>] ? __mutex_lock_slowpath+0xbf/0x109
[<ffffffff804bcc67>] ? mutex_lock+0x1a/0x31
[<ffffffff802bc848>] ? shrink_icache_memory+0x40/0x20a
[<ffffffff802894bb>] ? shrink_slab+0xd8/0x150
[<ffffffff8028a156>] ? kswapd+0x37c/0x54c
[<ffffffff80287ad7>] ? isolate_pages_global+0x0/0x1f8
[<ffffffff8024a422>] ? autoremove_wake_function+0x0/0x2e
[<ffffffff8022bb4b>] ? __wake_up_common+0x3f/0x71
[<ffffffff80289dda>] ? kswapd+0x0/0x54c
[<ffffffff80289dda>] ? kswapd+0x0/0x54c
[<ffffffff8024a2f3>] ? kthread+0x54/0x81
[<ffffffff8020c93a>] ? child_rip+0xa/0x20
[<ffffffff8024a29f>] ? kthread+0x0/0x81
[<ffffffff8020c930>] ? child_rip+0x0/0x20
INFO: task kjournald:644 blocked for more than 120 seconds.
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
kjournald D ffffc200000496c0 0 644 2
ffff88007ffc4780 0000000000000046 0000000000000008 0000000000000000
ffffffff80339cb1 ffff88007ed7a780 ffff88007ed7ab08 000000010016dcdf
ffff88012c09ed48 ffff88007edd89f0 ffff88012c036080 ffffffff803377b5
Call Trace:
[<ffffffff80339cb1>] ? blk_recount_segments+0x17/0x27
[<ffffffff803377b5>] ? __make_request+0x310/0x40b
[<ffffffff802c89b5>] ? sync_buffer+0x0/0x40
[<ffffffff804bc473>] ? schedule+0x9/0x1d
[<ffffffff804bc6ea>] ? io_schedule+0x5d/0x9e
[<ffffffff802c89f0>] ? sync_buffer+0x3b/0x40
[<ffffffff804bca0d>] ? __wait_on_bit+0x40/0x6f
[<ffffffff802c89b5>] ? sync_buffer+0x0/0x40
[<ffffffff804bcaa8>] ? out_of_line_wait_on_bit+0x6c/0x78
[<ffffffff8024a450>] ? wake_bit_function+0x0/0x23
[<ffffffffa00263a1>] ? journal_commit_transaction+0x841/0xd0c [jbd]
[<ffffffff80240ff2>] ? lock_timer_base+0x26/0x4c
[<ffffffffa002900b>] ? kjournald+0xc5/0x1ff [jbd]
[<ffffffff8024a422>] ? autoremove_wake_function+0x0/0x2e
[<ffffffffa0028f46>] ? kjournald+0x0/0x1ff [jbd]
[<ffffffffa0028f46>] ? kjournald+0x0/0x1ff [jbd]
[<ffffffff8024a2f3>] ? kthread+0x54/0x81
[<ffffffff8020c93a>] ? child_rip+0xa/0x20
[<ffffffff8024a29f>] ? kthread+0x0/0x81
[<ffffffff8020c930>] ? child_rip+0x0/0x20
INFO: task syslogd:2832 blocked for more than 120 seconds.
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
syslogd D ffffc200000496c0 0 2832 1
ffff88007ed7a780 0000000000000082 0000000000000000 0000000000000000
ffff8800c8ce4f00 ffff88007e9fb880 ffff88007e9fbc08 ffff8800c8ce4f00
0000000300000409 ffff88007e875cc8 ffff880126406738 0000000000000000
Call Trace:
[<ffffffff804bc473>] ? schedule+0x9/0x1d
[<ffffffffa0028892>] ? log_wait_commit+0x9f/0xed [jbd]
[<ffffffff8024a422>] ? autoremove_wake_function+0x0/0x2e
[<ffffffff8022cbc2>] ? __wake_up+0x30/0x44
[<ffffffffa002456b>] ? journal_stop+0x1d9/0x209 [jbd]
[<ffffffffa0024d61>] ? journal_start+0x9b/0xd2 [jbd]
[<ffffffff802c4096>] ? __writeback_single_inode+0x19b/0x2b9
[<ffffffff802c49c1>] ? sync_inode+0x24/0x33
[<ffffffffa003755a>] ? ext3_sync_file+0x9e/0xb0 [ext3]
[<ffffffff802c6d58>] ? vfs_fsync+0x6d/0xc5
[<ffffffff802c6dd7>] ? do_fsync+0x27/0x3a
[<ffffffff802c6e08>] ? sys_fsync+0xb/0x10
[<ffffffff8020b96b>] ? system_call_fastpath+0x16/0x1b
BUG: soft lockup - CPU#1 stuck for 61s! [kswapd1:383]
Modules linked in: ipv6 nfs lockd nfs_acl auth_rpcgss sunrpc cachefiles
fscache dm_mirror dm_region_hash dm_log dm_multipath scsi_dh dm_mod
video output sbs sbshc battery acpi_memhotplug ac parport_pc lp parport
ipmi_devintf serio_raw bnx2 button k8temp hwmon i2c_piix4 ipmi_si
i2c_core shpchp ipmi_msghandler hpilo rtc_cmos rtc_core pcspkr rtc_lib
usb_storage cciss sd_mod scsi_mod ext3 jbd uhci_hcd ohci_hcd ehci_hcd
CPU 1:
Modules linked in: ipv6 nfs lockd nfs_acl auth_rpcgss sunrpc cachefiles
fscache dm_mirror dm_region_hash dm_log dm_multipath scsi_dh dm_mod
video output sbs sbshc battery acpi_memhotplug ac parport_pc lp parport
ipmi_devintf serio_raw bnx2 button k8temp hwmon i2c_piix4 ipmi_si
i2c_core shpchp ipmi_msghandler hpilo rtc_cmos rtc_core pcspkr rtc_lib
usb_storage cciss sd_mod scsi_mod ext3 jbd uhci_hcd ohci_hcd ehci_hcd
Pid: 383, comm: kswapd1 Not tainted 2.6.30-dh #3 ProLiant DL385 G2
RIP: 0010:[<ffffffff80280780>] [<ffffffff80280780>]
find_get_pages+0x4e/0xbf
RSP: 0018:ffff88007ed33c70 EFLAGS: 00000246
RAX: ffff8800425dab30 RBX: 0000000000000000 RCX: 0000000000000000
RDX: 0000000000000002 RSI: ffffe200010ba7c0 RDI: ffffe200010ba7b8
RBP: ffffffff8020c44e R08: 0000000000000003 R09: 0000000000000040
R10: 0000000000000002 R11: 0000000000000040 R12: ffffe200010a4478
R13: ffffffff802a64d4 R14: 0000000000000000 R15: ffff8800426db198
FS: 00007fb0b47db6e0(0000) GS:ffffc20000013000(0000) knlGS:0000000000000000
CS: 0010 DS: 0018 ES: 0018 CR0: 000000008005003b
CR2: 00007f6a44b28000 CR3: 000000012c478000 CR4: 00000000000006e0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
Call Trace:
[<ffffffff80287294>] ? pagevec_lookup+0x17/0x1f
[<ffffffff802875e6>] ? __invalidate_mapping_pages+0xfc/0x119
[<ffffffff802bc8f5>] ? shrink_icache_memory+0xed/0x20a
[<ffffffff802894bb>] ? shrink_slab+0xd8/0x150
[<ffffffff8028a156>] ? kswapd+0x37c/0x54c
[<ffffffff80287ad7>] ? isolate_pages_global+0x0/0x1f8
[<ffffffff8024a422>] ? autoremove_wake_function+0x0/0x2e
[<ffffffff8022bb4b>] ? __wake_up_common+0x3f/0x71
[<ffffffff80289dda>] ? kswapd+0x0/0x54c
[<ffffffff80289dda>] ? kswapd+0x0/0x54c
[<ffffffff8024a2f3>] ? kthread+0x54/0x81
[<ffffffff8020c93a>] ? child_rip+0xa/0x20
[<ffffffff8024a29f>] ? kthread+0x0/0x81
[<ffffffff8020c930>] ? child_rip+0x0/0x20
BUG: soft lockup - CPU#1 stuck for 61s! [kswapd1:383]
Modules linked in: ipv6 nfs lockd nfs_acl auth_rpcgss sunrpc cachefiles
fscache dm_mirror dm_region_hash dm_log dm_multipath scsi_dh dm_mod
video output sbs sbshc battery acpi_memhotplug ac parport_pc lp parport
ipmi_devintf serio_raw bnx2 button k8temp hwmon i2c_piix4 ipmi_si
i2c_core shpchp ipmi_msghandler hpilo rtc_cmos rtc_core pcspkr rtc_lib
usb_storage cciss sd_mod scsi_mod ext3 jbd uhci_hcd ohci_hcd ehci_hcd
CPU 1:
Modules linked in: ipv6 nfs lockd nfs_acl auth_rpcgss sunrpc cachefiles
fscache dm_mirror dm_region_hash dm_log dm_multipath scsi_dh dm_mod
video output sbs sbshc battery acpi_memhotplug ac parport_pc lp parport
ipmi_devintf serio_raw bnx2 button k8temp hwmon i2c_piix4 ipmi_si
i2c_core shpchp ipmi_msghandler hpilo rtc_cmos rtc_core pcspkr rtc_lib
usb_storage cciss sd_mod scsi_mod ext3 jbd uhci_hcd ohci_hcd ehci_hcd
Pid: 383, comm: kswapd1 Not tainted 2.6.30-dh #3 ProLiant DL385 G2
RIP: 0010:[<ffffffff8028078e>] [<ffffffff8028078e>]
find_get_pages+0x5c/0xbf
RSP: 0018:ffff88007ed33c70 EFLAGS: 00000293
RAX: ffff8800425dab30 RBX: 0000000000000000 RCX: 0000000000000000
RDX: 0000000000000002 RSI: ffffe200010ba7c0 RDI: ffffe200010ba7b8
RBP: ffffffff8020c44e R08: 0000000000000003 R09: 0000000000000040
R10: 0000000000000002 R11: 0000000000000040 R12: ffffe200010a4478
R13: ffffffff802a64d4 R14: 0000000000000000 R15: ffff8800426db198
FS: 00007fb0b47db6e0(0000) GS:ffffc20000013000(0000) knlGS:0000000000000000
CS: 0010 DS: 0018 ES: 0018 CR0: 000000008005003b
CR2: 00007f6a44b28000 CR3: 000000012c478000 CR4: 00000000000006e0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
Call Trace:
[<ffffffff80287294>] ? pagevec_lookup+0x17/0x1f
[<ffffffff802875e6>] ? __invalidate_mapping_pages+0xfc/0x119
[<ffffffff802bc8f5>] ? shrink_icache_memory+0xed/0x20a
[<ffffffff802894bb>] ? shrink_slab+0xd8/0x150
[<ffffffff8028a156>] ? kswapd+0x37c/0x54c
[<ffffffff80287ad7>] ? isolate_pages_global+0x0/0x1f8
[<ffffffff8024a422>] ? autoremove_wake_function+0x0/0x2e
[<ffffffff8022bb4b>] ? __wake_up_common+0x3f/0x71
[<ffffffff80289dda>] ? kswapd+0x0/0x54c
[<ffffffff80289dda>] ? kswapd+0x0/0x54c
[<ffffffff8024a2f3>] ? kthread+0x54/0x81
[<ffffffff8020c93a>] ? child_rip+0xa/0x20
[<ffffffff8024a29f>] ? kthread+0x0/0x81
[<ffffffff8020c930>] ? child_rip+0x0/0x20
INFO: task kswapd0:382 blocked for more than 120 seconds.
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
kswapd0 D ffffc200000106c0 0 382 2
ffff88007ffc4080 0000000000000046 ffffffff8064d740 0000000000000001
0000000000000000 ffff88007ed1d840 ffff88007ed1dbc8 ffff88007ed31fd8
ffffc200000236c0 0000000000000001 ffff88007ed32000 ffffffff8064d740
Call Trace:
[<ffffffff804bcdb3>] ? __mutex_lock_slowpath+0xbf/0x109
[<ffffffff804bcc67>] ? mutex_lock+0x1a/0x31
[<ffffffff802bc848>] ? shrink_icache_memory+0x40/0x20a
[<ffffffff802894bb>] ? shrink_slab+0xd8/0x150
[<ffffffff8028a156>] ? kswapd+0x37c/0x54c
[<ffffffff80287ad7>] ? isolate_pages_global+0x0/0x1f8
[<ffffffff8024a422>] ? autoremove_wake_function+0x0/0x2e
[<ffffffff8022bb4b>] ? __wake_up_common+0x3f/0x71
[<ffffffff80289dda>] ? kswapd+0x0/0x54c
[<ffffffff80289dda>] ? kswapd+0x0/0x54c
[<ffffffff8024a2f3>] ? kthread+0x54/0x81
[<ffffffff8020c93a>] ? child_rip+0xa/0x20
[<ffffffff8024a29f>] ? kthread+0x0/0x81
[<ffffffff8020c930>] ? child_rip+0x0/0x20
INFO: task kjournald:644 blocked for more than 120 seconds.
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
kjournald D ffffc200000496c0 0 644 2
ffff88007ffc4780 0000000000000046 0000000000000008 0000000000000000
ffffffff80339cb1 ffff88007ed7a780 ffff88007ed7ab08 000000010016dcdf
ffff88012c09ed48 ffff88007edd89f0 ffff88012c036080 ffffffff803377b5
Call Trace:
[<ffffffff80339cb1>] ? blk_recount_segments+0x17/0x27
[<ffffffff803377b5>] ? __make_request+0x310/0x40b
[<ffffffff802c89b5>] ? sync_buffer+0x0/0x40
[<ffffffff804bc473>] ? schedule+0x9/0x1d
[<ffffffff804bc6ea>] ? io_schedule+0x5d/0x9e
[<ffffffff802c89f0>] ? sync_buffer+0x3b/0x40
[<ffffffff804bca0d>] ? __wait_on_bit+0x40/0x6f
[<ffffffff802c89b5>] ? sync_buffer+0x0/0x40
[<ffffffff804bcaa8>] ? out_of_line_wait_on_bit+0x6c/0x78
[<ffffffff8024a450>] ? wake_bit_function+0x0/0x23
[<ffffffffa00263a1>] ? journal_commit_transaction+0x841/0xd0c [jbd]
[<ffffffff80240ff2>] ? lock_timer_base+0x26/0x4c
[<ffffffffa002900b>] ? kjournald+0xc5/0x1ff [jbd]
[<ffffffff8024a422>] ? autoremove_wake_function+0x0/0x2e
[<ffffffffa0028f46>] ? kjournald+0x0/0x1ff [jbd]
[<ffffffffa0028f46>] ? kjournald+0x0/0x1ff [jbd]
[<ffffffff8024a2f3>] ? kthread+0x54/0x81
[<ffffffff8020c93a>] ? child_rip+0xa/0x20
[<ffffffff8024a29f>] ? kthread+0x0/0x81
[<ffffffff8020c930>] ? child_rip+0x0/0x20
INFO: task syslogd:2832 blocked for more than 120 seconds.
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
syslogd D ffffc200000496c0 0 2832 1
ffff88007ed7a780 0000000000000082 0000000000000000 0000000000000000
ffff8800c8ce4f00 ffff88007e9fb880 ffff88007e9fbc08 ffff8800c8ce4f00
0000000300000409 ffff88007e875cc8 ffff880126406738 0000000000000000
Call Trace:
[<ffffffff804bc473>] ? schedule+0x9/0x1d
[<ffffffffa0028892>] ? log_wait_commit+0x9f/0xed [jbd]
[<ffffffff8024a422>] ? autoremove_wake_function+0x0/0x2e
[<ffffffff8022cbc2>] ? __wake_up+0x30/0x44
[<ffffffffa002456b>] ? journal_stop+0x1d9/0x209 [jbd]
[<ffffffffa0024d61>] ? journal_start+0x9b/0xd2 [jbd]
[<ffffffff802c4096>] ? __writeback_single_inode+0x19b/0x2b9
[<ffffffff802c49c1>] ? sync_inode+0x24/0x33
[<ffffffffa003755a>] ? ext3_sync_file+0x9e/0xb0 [ext3]
[<ffffffff802c6d58>] ? vfs_fsync+0x6d/0xc5
[<ffffffff802c6dd7>] ? do_fsync+0x27/0x3a
[<ffffffff802c6e08>] ? sys_fsync+0xb/0x10
[<ffffffff8020b96b>] ? system_call_fastpath+0x16/0x1b
INFO: task collectd:3149 blocked for more than 120 seconds.
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
collectd D ffffc200000366c0 0 3149 1
ffff88007ffc08c0 0000000000000086 ffff88012f1b4bc8 0000000100177570
0000000000000282 ffff88012f1b4840 ffff88012f1b4bc8 0000000100179c84
0000000000000282 ffffffff8024c7ea 0000000000000001 ffff88012c135f58
Call Trace:
[<ffffffff8024c7ea>] ? hrtimer_try_to_cancel+0x5f/0x68
[<ffffffff804bc473>] ? schedule+0x9/0x1d
[<ffffffff804bdb77>] ? __down_read+0x71/0x8b
[<ffffffff804bfcb8>] ? do_page_fault+0x166/0x282
[<ffffffff804bdf8f>] ? page_fault+0x1f/0x30
INFO: task collectd:3150 blocked for more than 120 seconds.
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
collectd D ffffc200000106c0 0 3150 1
ffffffff805ea360 0000000000000086 0000000000000000 0000000000000000
0000000000000000 ffff88007d131080 ffff88007d131408 000000010017756e
000000001bebcede 000000004a3fe1f3 000000001bebcede 000000004a3fe1f3
Call Trace:
[<ffffffff804bc473>] ? schedule+0x9/0x1d
[<ffffffff804bdae5>] ? __down_write_nested+0x71/0x8b
[<ffffffff8020f663>] ? sys_mmap+0xca/0x110
[<ffffffff8020b96b>] ? system_call_fastpath+0x16/0x1b
INFO: task collectd:3151 blocked for more than 120 seconds.
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
collectd D ffffc200000366c0 0 3151 1
ffff88007ffc08c0 0000000000000086 ffffe200013fe1f0 ffffffff802cf16a
0000000000000000 ffff88007e9fb180 ffff88007e9fb508 0000000100177570
ffff880000011440 ffff8801264a9e70 0000000000000000 00000000001201d2
Call Trace:
[<ffffffff802cf16a>] ? mpage_bio_submit+0x22/0x26
[<ffffffff8027eeeb>] ? sync_page+0x0/0x48
[<ffffffff804bc473>] ? schedule+0x9/0x1d
[<ffffffff804bc6ea>] ? io_schedule+0x5d/0x9e
[<ffffffff8027ef2f>] ? sync_page+0x44/0x48
[<ffffffff804bc90f>] ? __wait_on_bit_lock+0x3e/0x84
[<ffffffff8027eed7>] ? __lock_page+0x5e/0x64
[<ffffffff8024a450>] ? wake_bit_function+0x0/0x23
[<ffffffff8027ef83>] ? find_lock_page+0x35/0x55
[<ffffffff80280b6e>] ? filemap_fault+0x16c/0x336
[<ffffffff8028fcd4>] ? __do_fault+0x51/0x3e5
[<ffffffff80291cfa>] ? handle_mm_fault+0x32f/0x6f1
[<ffffffff804bfd68>] ? do_page_fault+0x216/0x282
[<ffffffff804bdf8f>] ? page_fault+0x1f/0x30
INFO: task collectd:3152 blocked for more than 120 seconds.
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
collectd D ffffc200000496c0 0 3152 1
ffff88007ffc4780 0000000000000086 0000000000000000 0000000000000000
0000000000000000 ffff88007ec9c080 ffff88007ec9c408 000000010017756c
0000000018c68b18 000000004a3fdbfd 0000000018c68b18 000000004a3fdbfd
Call Trace:
[<ffffffff804bc473>] ? schedule+0x9/0x1d
[<ffffffff804bdae5>] ? __down_write_nested+0x71/0x8b
[<ffffffff8020f663>] ? sys_mmap+0xca/0x110
[<ffffffff8020b96b>] ? system_call_fastpath+0x16/0x1b
[konetzed at kerneltest ~]$
> In your statement above, are you comparing NFS with a cache to NFS without? If
> so, that might well be true: the cache has to eat some of your client machine's
> performance in order to give something back, so it is not an automatic win.
>
On 2.6.29-rc3 it added about 30 seconds to a 8 min copy, which is about
what I expected. Using the 2.6.30 kernel with fscache I get the dmesg
errors as before and initial copy is 5 mins and every copy once cache is
primed takes about 30 mins.
Any ideas why dmesg is spitting out those errors, I dont get that error
if I use the same kernel only no fscache.
Thanks
Edward
More information about the Linux-cachefs
mailing list