Macindy
n00b
Joined: 29 Nov 2005
Posts: 24
|
 Posted: Wed Aug 11, 2010 3:41 pm Post subject: PHP-FPM/NFS hangs |
 |
|
Hi everybody,
I just setup a new machine with nginx/php-fpm for web purposes. The filesystem is mounted via nfsv3. After 10hours of server uptime the system hangs. php-fpm is unkillable (kill -9 doesn't work). In the logfiles the following occurs:
| Quote: | Aug 11 14:31:20 paris kernel: [47870.548337] INFO: task flush-0:17:12630 blocked for more than 120 seconds.
Aug 11 14:31:20 paris kernel: [47870.548341] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Aug 11 14:31:20 paris kernel: [47870.548344] flush-0:17 D 0000000000000009 0 12630 2 0x00000000
Aug 11 14:31:20 paris kernel: [47870.548348] ffff880227d87c70 0000000000000046 ffff8803e66f4c90 ffff88022f069b00
Aug 11 14:31:20 paris kernel: [47870.548353] ffff880227d87bf0 ffffffff00000000 ffff880227d87fd8 ffff880228d92880
Aug 11 14:31:20 paris kernel: [47870.548357] 0000000000013100 ffff880227d87fd8 0000000000013100 0000000000013100
Aug 11 14:31:20 paris kernel: [47870.548361] Call Trace:
Aug 11 14:31:20 paris kernel: [47870.548370] [<ffffffff810dfa40>] ? inode_wait+0x0/0xd
Aug 11 14:31:20 paris kernel: [47870.548374] [<ffffffff810dfa49>] inode_wait+0x9/0xd
Aug 11 14:31:20 paris kernel: [47870.548380] [<ffffffff8146d165>] __wait_on_bit+0x43/0x76
Aug 11 14:31:20 paris kernel: [47870.548385] [<ffffffff810e82c7>] inode_wait_for_writeback+0x82/0xa2
Aug 11 14:31:20 paris kernel: [47870.548390] [<ffffffff81054457>] ? wake_bit_function+0x0/0x2e
Aug 11 14:31:20 paris kernel: [47870.548394] [<ffffffff810e8f3c>] wb_writeback+0x195/0x1b5
Aug 11 14:31:20 paris kernel: [47870.548400] [<ffffffff81048ae9>] ? try_to_del_timer_sync+0x6e/0x7c
Aug 11 14:31:20 paris kernel: [47870.548405] [<ffffffff810e913e>] wb_do_writeback+0x137/0x14d
Aug 11 14:31:20 paris kernel: [47870.548408] [<ffffffff81048bea>] ? process_timeout+0x0/0xb
Aug 11 14:31:20 paris kernel: [47870.548412] [<ffffffff810e918e>] bdi_writeback_task+0x3a/0xab
Aug 11 14:31:20 paris kernel: [47870.548417] [<ffffffff810ac5aa>] ? bdi_start_fn+0x0/0xc4
Aug 11 14:31:20 paris kernel: [47870.548421] [<ffffffff810ac608>] bdi_start_fn+0x5e/0xc4
Aug 11 14:31:20 paris kernel: [47870.548424] [<ffffffff810ac5aa>] ? bdi_start_fn+0x0/0xc4
Aug 11 14:31:20 paris kernel: [47870.548428] [<ffffffff81053fe7>] kthread+0x7a/0x82
Aug 11 14:31:20 paris kernel: [47870.548433] [<ffffffff81003714>] kernel_thread_helper+0x4/0x10
Aug 11 14:31:20 paris kernel: [47870.548436] [<ffffffff81053f6d>] ? kthread+0x0/0x82
Aug 11 14:31:20 paris kernel: [47870.548440] [<ffffffff81003710>] ? kernel_thread_helper+0x0/0x10
Aug 11 14:31:20 paris kernel: [47870.548445] INFO: task php-fpm:12654 blocked for more than 120 seconds.
Aug 11 14:31:20 paris kernel: [47870.548447] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Aug 11 14:31:20 paris kernel: [47870.548450] php-fpm D 0000000000000003 0 12654 4939 0x00000000
Aug 11 14:31:20 paris kernel: [47870.548454] ffff880228ce1b48 0000000000000086 ffff88022e3767c0 ffff88042ec56c00
Aug 11 14:31:20 paris kernel: [47870.548458] ffff88022e376780 ffff88041a01b5b0 ffff880228ce1fd8 ffff880228b6b600
Aug 11 14:31:20 paris kernel: [47870.548462] 0000000000013100 ffff880228ce1fd8 0000000000013100 0000000000013100
Aug 11 14:31:20 paris kernel: [47870.548465] Call Trace:
Aug 11 14:31:20 paris kernel: [47870.548470] [<ffffffff81099b36>] ? sync_page+0x0/0x45
Aug 11 14:31:20 paris kernel: [47870.548474] [<ffffffff8146ce3f>] io_schedule+0x3d/0x57
Aug 11 14:31:20 paris kernel: [47870.548478] [<ffffffff81099b77>] sync_page+0x41/0x45
Aug 11 14:31:20 paris kernel: [47870.548482] [<ffffffff8146d065>] __wait_on_bit_lock+0x41/0x8a
Aug 11 14:31:20 paris kernel: [47870.548486] [<ffffffff81099b0c>] __lock_page+0x61/0x68
Aug 11 14:31:20 paris kernel: [47870.548489] [<ffffffff81054457>] ? wake_bit_function+0x0/0x2e
Aug 11 14:31:20 paris kernel: [47870.548493] [<ffffffff810a14c0>] ? pagevec_lookup_tag+0x20/0x29
Aug 11 14:31:20 paris kernel: [47870.548497] [<ffffffff810a0062>] write_cache_pages+0x196/0x31f
Aug 11 14:31:20 paris kernel: [47870.548502] [<ffffffff8115bd00>] ? nfs_writepages_callback+0x0/0x26
Aug 11 14:31:20 paris kernel: [47870.548506] [<ffffffff8109aaa5>] ? __generic_file_aio_write+0x247/0x27c
Aug 11 14:31:20 paris kernel: [47870.548510] [<ffffffff810cdfc2>] ? do_truncate+0x78/0x82
Aug 11 14:31:20 paris kernel: [47870.548513] [<ffffffff8115bcbe>] nfs_writepages+0xb1/0xf3
Aug 11 14:31:20 paris kernel: [47870.548517] [<ffffffff8115bed7>] ? nfs_flush_one+0x0/0xda
Aug 11 14:31:20 paris kernel: [47870.548520] [<ffffffff810a0228>] do_writepages+0x1c/0x25
Aug 11 14:31:20 paris kernel: [47870.548524] [<ffffffff810e83c3>] writeback_single_inode+0xdc/0x2d1
Aug 11 14:31:20 paris kernel: [47870.548528] [<ffffffff810e85e0>] sync_inode+0x28/0x35
Aug 11 14:31:20 paris kernel: [47870.548531] [<ffffffff8115b231>] nfs_wb_all+0x3d/0x3f
Aug 11 14:31:20 paris kernel: [47870.548536] [<ffffffff8114f9eb>] nfs_do_fsync+0x1b/0x38
Aug 11 14:31:20 paris kernel: [47870.548539] [<ffffffff8114fbc1>] nfs_file_flush+0x70/0x78
Aug 11 14:31:20 paris kernel: [47870.548545] [<ffffffff810cd25e>] filp_close+0x3e/0x6d
Aug 11 14:31:20 paris kernel: [47870.548548] [<ffffffff810cf107>] ? sys_write+0x5c/0x69
Aug 11 14:31:20 paris kernel: [47870.548552] [<ffffffff810cd324>] sys_close+0x97/0xcb
Aug 11 14:31:20 paris kernel: [47870.548556] [<ffffffff8100296b>] system_call_fastpath+0x16/0x1b
Aug 11 14:31:20 paris kernel: [47870.548563] INFO: task php-fpm:12679 blocked for more than 120 seconds.
Aug 11 14:31:20 paris kernel: [47870.548565] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Aug 11 14:31:20 paris kernel: [47870.548567] php-fpm D 0000000000000004 0 12679 4939 0x00000000
Aug 11 14:31:20 paris kernel: [47870.548571] ffff8803aeb0f988 0000000000000086 ffff8803aeb0f908 ffff88042ec98d80
Aug 11 14:31:20 paris kernel: [47870.548575] 00000000000006bf ffff8804111c7808 ffff8803aeb0ffd8 ffff880429da21c0
Aug 11 14:31:20 paris kernel: [47870.548579] 0000000000013100 ffff8803aeb0ffd8 0000000000013100 0000000000013100
Aug 11 14:31:20 paris kernel: [47870.548583] Call Trace:
Aug 11 14:31:20 paris kernel: [47870.548586] [<ffffffff8105448e>] ? spin_unlock_irqrestore+0x9/0xb
Aug 11 14:31:20 paris kernel: [47870.548590] [<ffffffff810dfa40>] ? inode_wait+0x0/0xd
Aug 11 14:31:20 paris kernel: [47870.548594] [<ffffffff810dfa49>] inode_wait+0x9/0xd
Aug 11 14:31:20 paris kernel: [47870.548598] [<ffffffff8146d165>] __wait_on_bit+0x43/0x76
Aug 11 14:31:20 paris kernel: [47870.548602] [<ffffffff810e82c7>] inode_wait_for_writeback+0x82/0xa2
Aug 11 14:31:20 paris kernel: [47870.548605] [<ffffffff81054457>] ? wake_bit_function+0x0/0x2e
Aug 11 14:31:20 paris kernel: [47870.548610] [<ffffffff8115855e>] ? nfs_pageio_complete+0x9/0xb
Aug 11 14:31:20 paris kernel: [47870.548615] [<ffffffff810e8392>] writeback_single_inode+0xab/0x2d1
Aug 11 14:31:20 paris kernel: [47870.548618] [<ffffffff810e85e0>] sync_inode+0x28/0x35
Aug 11 14:31:20 paris kernel: [47870.548622] [<ffffffff8115b882>] nfs_wb_page+0x7c/0x95
Aug 11 14:31:20 paris kernel: [47870.548625] [<ffffffff8115b8f2>] nfs_flush_incompatible+0x57/0x67
Aug 11 14:31:20 paris kernel: [47870.548628] [<ffffffff8114f860>] nfs_write_begin+0xe6/0x1b1
Aug 11 14:31:20 paris kernel: [47870.548633] [<ffffffff810990de>] generic_file_buffered_write+0x100/0x24e
Aug 11 14:31:20 paris kernel: [47870.548637] [<ffffffff8109aaa5>] __generic_file_aio_write+0x247/0x27c
Aug 11 14:31:20 paris kernel: [47870.548641] [<ffffffff8146d282>] ? __mutex_unlock_slowpath+0x31/0x38
Aug 11 14:31:20 paris kernel: [47870.548645] [<ffffffff810cdfc2>] ? do_truncate+0x78/0x82
Aug 11 14:31:20 paris kernel: [47870.548649] [<ffffffff8109ab32>] generic_file_aio_write+0x58/0xa4
Aug 11 14:31:20 paris kernel: [47870.548652] [<ffffffff81150299>] nfs_file_write+0xd7/0x17f
Aug 11 14:31:20 paris kernel: [47870.548656] [<ffffffff810ceaa1>] do_sync_write+0xc6/0x103
Aug 11 14:31:20 paris kernel: [47870.548660] [<ffffffff810b0466>] ? handle_mm_fault+0x378/0x74d
Aug 11 14:31:20 paris kernel: [47870.548665] [<ffffffff811ab2d1>] ? security_file_permission+0x11/0x13
Aug 11 14:31:20 paris kernel: [47870.548668] [<ffffffff810cefdd>] vfs_write+0xa9/0x106
Aug 11 14:31:20 paris kernel: [47870.548671] [<ffffffff810cf0f0>] sys_write+0x45/0x69
Aug 11 14:31:20 paris kernel: [47870.548675] [<ffffffff8100296b>] system_call_fastpath+0x16/0x1b
Aug 11 14:32:49 paris kernel: [47959.068420] TCP: Peer 84.140.250.21:50262/80 unexpectedly shrunk window 1990483594:1990493674 (repaired)
Aug 11 14:33:20 paris kernel: [47990.218821] INFO: task flush-0:17:12630 blocked for more than 120 seconds.
Aug 11 14:33:20 paris kernel: [47990.218824] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Aug 11 14:33:20 paris kernel: [47990.218827] flush-0:17 D 0000000000000009 0 12630 2 0x00000000
Aug 11 14:33:20 paris kernel: [47990.218832] ffff880227d87c70 0000000000000046 ffff8803e66f4c90 ffff88022f069b00
Aug 11 14:33:20 paris kernel: [47990.218836] ffff880227d87bf0 ffffffff00000000 ffff880227d87fd8 ffff880228d92880
Aug 11 14:33:20 paris kernel: [47990.218840] 0000000000013100 ffff880227d87fd8 0000000000013100 0000000000013100
Aug 11 14:33:20 paris kernel: [47990.218844] Call Trace:
Aug 11 14:33:20 paris kernel: [47990.218853] [<ffffffff810dfa40>] ? inode_wait+0x0/0xd
Aug 11 14:33:20 paris kernel: [47990.218857] [<ffffffff810dfa49>] inode_wait+0x9/0xd
Aug 11 14:33:20 paris kernel: [47990.218863] [<ffffffff8146d165>] __wait_on_bit+0x43/0x76
Aug 11 14:33:20 paris kernel: [47990.218868] [<ffffffff810e82c7>] inode_wait_for_writeback+0x82/0xa2
Aug 11 14:33:20 paris kernel: [47990.218873] [<ffffffff81054457>] ? wake_bit_function+0x0/0x2e
Aug 11 14:33:20 paris kernel: [47990.218877] [<ffffffff810e8f3c>] wb_writeback+0x195/0x1b5
Aug 11 14:33:20 paris kernel: [47990.218883] [<ffffffff81048ae9>] ? try_to_del_timer_sync+0x6e/0x7c
Aug 11 14:33:20 paris kernel: [47990.218887] [<ffffffff810e913e>] wb_do_writeback+0x137/0x14d
Aug 11 14:33:20 paris kernel: [47990.218892] [<ffffffff81048bea>] ? process_timeout+0x0/0xb
Aug 11 14:33:20 paris kernel: [47990.218896] [<ffffffff810e918e>] bdi_writeback_task+0x3a/0xab
Aug 11 14:33:20 paris kernel: [47990.218901] [<ffffffff810ac5aa>] ? bdi_start_fn+0x0/0xc4
Aug 11 14:33:20 paris kernel: [47990.218904] [<ffffffff810ac608>] bdi_start_fn+0x5e/0xc4
Aug 11 14:33:20 paris kernel: [47990.218908] [<ffffffff810ac5aa>] ? bdi_start_fn+0x0/0xc4
Aug 11 14:33:20 paris kernel: [47990.218911] [<ffffffff81053fe7>] kthread+0x7a/0x82
Aug 11 14:33:20 paris kernel: [47990.218916] [<ffffffff81003714>] kernel_thread_helper+0x4/0x10
Aug 11 14:33:20 paris kernel: [47990.218919] [<ffffffff81053f6d>] ? kthread+0x0/0x82
Aug 11 14:33:20 paris kernel: [47990.218923] [<ffffffff81003710>] ? kernel_thread_helper+0x0/0x10
Aug 11 14:33:20 paris kernel: [47990.218928] INFO: task php-fpm:12654 blocked for more than 120 seconds.
Aug 11 14:33:20 paris kernel: [47990.218930] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Aug 11 14:33:20 paris kernel: [47990.218932] php-fpm D 0000000000000003 0 12654 4939 0x00000000
Aug 11 14:33:20 paris kernel: [47990.218936] ffff880228ce1b48 0000000000000086 ffff88022e3767c0 ffff88042ec56c00
Aug 11 14:33:20 paris kernel: [47990.218940] ffff88022e376780 ffff88041a01b5b0 ffff880228ce1fd8 ffff880228b6b600
Aug 11 14:33:20 paris kernel: [47990.218944] 0000000000013100 ffff880228ce1fd8 0000000000013100 0000000000013100
Aug 11 14:33:20 paris kernel: [47990.218948] Call Trace:
Aug 11 14:33:20 paris kernel: [47990.218953] [<ffffffff81099b36>] ? sync_page+0x0/0x45
Aug 11 14:33:20 paris kernel: [47990.218957] [<ffffffff8146ce3f>] io_schedule+0x3d/0x57
Aug 11 14:33:20 paris kernel: [47990.218960] [<ffffffff81099b77>] sync_page+0x41/0x45
Aug 11 14:33:20 paris kernel: [47990.218964] [<ffffffff8146d065>] __wait_on_bit_lock+0x41/0x8a
Aug 11 14:33:20 paris kernel: [47990.218968] [<ffffffff81099b0c>] __lock_page+0x61/0x68
Aug 11 14:33:20 paris kernel: [47990.218971] [<ffffffff81054457>] ? wake_bit_function+0x0/0x2e
Aug 11 14:33:20 paris kernel: [47990.218975] [<ffffffff810a14c0>] ? pagevec_lookup_tag+0x20/0x29
Aug 11 14:33:20 paris kernel: [47990.218979] [<ffffffff810a0062>] write_cache_pages+0x196/0x31f
Aug 11 14:33:20 paris kernel: [47990.218984] [<ffffffff8115bd00>] ? nfs_writepages_callback+0x0/0x26
Aug 11 14:33:20 paris kernel: [47990.218988] [<ffffffff8109aaa5>] ? __generic_file_aio_write+0x247/0x27c
Aug 11 14:33:20 paris kernel: [47990.218992] [<ffffffff810cdfc2>] ? do_truncate+0x78/0x82
Aug 11 14:33:20 paris kernel: [47990.218995] [<ffffffff8115bcbe>] nfs_writepages+0xb1/0xf3
Aug 11 14:33:20 paris kernel: [47990.218999] [<ffffffff8115bed7>] ? nfs_flush_one+0x0/0xda
Aug 11 14:33:20 paris kernel: [47990.219002] [<ffffffff810a0228>] do_writepages+0x1c/0x25
Aug 11 14:33:20 paris kernel: [47990.219006] [<ffffffff810e83c3>] writeback_single_inode+0xdc/0x2d1
Aug 11 14:33:20 paris kernel: [47990.219010] [<ffffffff810e85e0>] sync_inode+0x28/0x35
Aug 11 14:33:20 paris kernel: [47990.219013] [<ffffffff8115b231>] nfs_wb_all+0x3d/0x3f
Aug 11 14:33:20 paris kernel: [47990.219018] [<ffffffff8114f9eb>] nfs_do_fsync+0x1b/0x38
Aug 11 14:33:20 paris kernel: [47990.219021] [<ffffffff8114fbc1>] nfs_file_flush+0x70/0x78
Aug 11 14:33:20 paris kernel: [47990.219027] [<ffffffff810cd25e>] filp_close+0x3e/0x6d
Aug 11 14:33:20 paris kernel: [47990.219030] [<ffffffff810cf107>] ? sys_write+0x5c/0x69
Aug 11 14:33:20 paris kernel: [47990.219034] [<ffffffff810cd324>] sys_close+0x97/0xcb
Aug 11 14:33:20 paris kernel: [47990.219038] [<ffffffff8100296b>] system_call_fastpath+0x16/0x1b
Aug 11 14:33:20 paris kernel: [47990.219045] INFO: task php-fpm:12679 blocked for more than 120 seconds.
Aug 11 14:33:20 paris kernel: [47990.219047] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Aug 11 14:33:20 paris kernel: [47990.219049] php-fpm D 0000000000000004 0 12679 4939 0x00000000
Aug 11 14:33:20 paris kernel: [47990.219053] ffff8803aeb0f988 0000000000000086 ffff8803aeb0f908 ffff88042ec98d80
Aug 11 14:33:20 paris kernel: [47990.219057] 00000000000006bf ffff8804111c7808 ffff8803aeb0ffd8 ffff880429da21c0
Aug 11 14:33:20 paris kernel: [47990.219061] 0000000000013100 ffff8803aeb0ffd8 0000000000013100 0000000000013100
Aug 11 14:33:20 paris kernel: [47990.219065] Call Trace:
Aug 11 14:33:20 paris kernel: [47990.219068] [<ffffffff8105448e>] ? spin_unlock_irqrestore+0x9/0xb
Aug 11 14:33:20 paris kernel: [47990.219072] [<ffffffff810dfa40>] ? inode_wait+0x0/0xd
Aug 11 14:33:20 paris kernel: [47990.219076] [<ffffffff810dfa49>] inode_wait+0x9/0xd
Aug 11 14:33:20 paris kernel: [47990.219079] [<ffffffff8146d165>] __wait_on_bit+0x43/0x76
Aug 11 14:33:20 paris kernel: [47990.219084] [<ffffffff810e82c7>] inode_wait_for_writeback+0x82/0xa2
Aug 11 14:33:20 paris kernel: [47990.219087] [<ffffffff81054457>] ? wake_bit_function+0x0/0x2e
Aug 11 14:33:20 paris kernel: [47990.219092] [<ffffffff8115855e>] ? nfs_pageio_complete+0x9/0xb
Aug 11 14:33:20 paris kernel: [47990.219096] [<ffffffff810e8392>] writeback_single_inode+0xab/0x2d1
Aug 11 14:33:20 paris kernel: [47990.219100] [<ffffffff810e85e0>] sync_inode+0x28/0x35
Aug 11 14:33:20 paris kernel: [47990.219103] [<ffffffff8115b882>] nfs_wb_page+0x7c/0x95
Aug 11 14:33:20 paris kernel: [47990.219107] [<ffffffff8115b8f2>] nfs_flush_incompatible+0x57/0x67
Aug 11 14:33:20 paris kernel: [47990.219110] [<ffffffff8114f860>] nfs_write_begin+0xe6/0x1b1
Aug 11 14:33:20 paris kernel: [47990.219114] [<ffffffff810990de>] generic_file_buffered_write+0x100/0x24e
Aug 11 14:33:20 paris kernel: [47990.219119] [<ffffffff8109aaa5>] __generic_file_aio_write+0x247/0x27c
Aug 11 14:33:20 paris kernel: [47990.219123] [<ffffffff8146d282>] ? __mutex_unlock_slowpath+0x31/0x38
Aug 11 14:33:20 paris kernel: [47990.219126] [<ffffffff810cdfc2>] ? do_truncate+0x78/0x82
Aug 11 14:33:20 paris kernel: [47990.219130] [<ffffffff8109ab32>] generic_file_aio_write+0x58/0xa4
Aug 11 14:33:20 paris kernel: [47990.219134] [<ffffffff81150299>] nfs_file_write+0xd7/0x17f
Aug 11 14:33:20 paris kernel: [47990.219137] [<ffffffff810ceaa1>] do_sync_write+0xc6/0x103
Aug 11 14:33:20 paris kernel: [47990.219142] [<ffffffff810b0466>] ? handle_mm_fault+0x378/0x74d
Aug 11 14:33:20 paris kernel: [47990.219146] [<ffffffff811ab2d1>] ? security_file_permission+0x11/0x13
Aug 11 14:33:20 paris kernel: [47990.219150] [<ffffffff810cefdd>] vfs_write+0xa9/0x106
Aug 11 14:33:20 paris kernel: [47990.219153] [<ffffffff810cf0f0>] sys_write+0x45/0x69
Aug 11 14:33:20 paris kernel: [47990.219156] [<ffffffff8100296b>] system_call_fastpath+0x16/0x1b
Aug 11 14:35:20 paris kernel: [48109.889283] INFO: task flush-0:17:12630 blocked for more than 120 seconds.
Aug 11 14:35:20 paris kernel: [48109.889286] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Aug 11 14:35:20 paris kernel: [48109.889289] flush-0:17 D 0000000000000009 0 12630 2 0x00000000
Aug 11 14:35:20 paris kernel: [48109.889294] ffff880227d87c70 0000000000000046 ffff8803e66f4c90 ffff88022f069b00
Aug 11 14:35:20 paris kernel: [48109.889298] ffff880227d87bf0 ffffffff00000000 ffff880227d87fd8 ffff880228d92880
Aug 11 14:35:20 paris kernel: [48109.889302] 0000000000013100 ffff880227d87fd8 0000000000013100 0000000000013100
Aug 11 14:35:20 paris kernel: [48109.889306] Call Trace:
Aug 11 14:35:20 paris kernel: [48109.889313] [<ffffffff810dfa40>] ? inode_wait+0x0/0xd
Aug 11 14:35:20 paris kernel: [48109.889317] [<ffffffff810dfa49>] inode_wait+0x9/0xd
Aug 11 14:35:20 paris kernel: [48109.889323] [<ffffffff8146d165>] __wait_on_bit+0x43/0x76
Aug 11 14:35:20 paris kernel: [48109.889327] [<ffffffff810e82c7>] inode_wait_for_writeback+0x82/0xa2
Aug 11 14:35:20 paris kernel: [48109.889331] [<ffffffff81054457>] ? wake_bit_function+0x0/0x2e
Aug 11 14:35:20 paris kernel: [48109.889335] [<ffffffff810e8f3c>] wb_writeback+0x195/0x1b5
Aug 11 14:35:20 paris kernel: [48109.889340] [<ffffffff81048ae9>] ? try_to_del_timer_sync+0x6e/0x7c
Aug 11 14:35:20 paris kernel: [48109.889344] [<ffffffff810e913e>] wb_do_writeback+0x137/0x14d
Aug 11 14:35:20 paris kernel: [48109.889348] [<ffffffff81048bea>] ? process_timeout+0x0/0xb
Aug 11 14:35:20 paris kernel: [48109.889352] [<ffffffff810e918e>] bdi_writeback_task+0x3a/0xab
Aug 11 14:35:20 paris kernel: [48109.889356] [<ffffffff810ac5aa>] ? bdi_start_fn+0x0/0xc4
Aug 11 14:35:20 paris kernel: [48109.889360] [<ffffffff810ac608>] bdi_start_fn+0x5e/0xc4
Aug 11 14:35:20 paris kernel: [48109.889364] [<ffffffff810ac5aa>] ? bdi_start_fn+0x0/0xc4
Aug 11 14:35:20 paris kernel: [48109.889367] [<ffffffff81053fe7>] kthread+0x7a/0x82
Aug 11 14:35:20 paris kernel: [48109.889371] [<ffffffff81003714>] kernel_thread_helper+0x4/0x10
Aug 11 14:35:20 paris kernel: [48109.889374] [<ffffffff81053f6d>] ? kthread+0x0/0x82
Aug 11 14:35:20 paris kernel: [48109.889378] [<ffffffff81003710>] ? kernel_thread_helper+0x0/0x10
Aug 11 14:35:20 paris kernel: [48109.889383] INFO: task php-fpm:12654 blocked for more than 120 seconds.
Aug 11 14:35:20 paris kernel: [48109.889385] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Aug 11 14:35:20 paris kernel: [48109.889387] php-fpm D 0000000000000003 0 12654 4939 0x00000000
Aug 11 14:35:20 paris kernel: [48109.889391] ffff880228ce1b48 0000000000000086 ffff88022e3767c0 ffff88042ec56c00
Aug 11 14:35:20 paris kernel: [48109.889395] ffff88022e376780 ffff88041a01b5b0 ffff880228ce1fd8 ffff880228b6b600
Aug 11 14:35:20 paris kernel: [48109.889399] 0000000000013100 ffff880228ce1fd8 0000000000013100 0000000000013100
Aug 11 14:35:20 paris kernel: [48109.889403] Call Trace:
Aug 11 14:35:20 paris kernel: [48109.889407] [<ffffffff81099b36>] ? sync_page+0x0/0x45
Aug 11 14:35:20 paris kernel: [48109.889411] [<ffffffff8146ce3f>] io_schedule+0x3d/0x57
Aug 11 14:35:20 paris kernel: [48109.889414] [<ffffffff81099b77>] sync_page+0x41/0x45
Aug 11 14:35:20 paris kernel: [48109.889418] [<ffffffff8146d065>] __wait_on_bit_lock+0x41/0x8a
Aug 11 14:35:20 paris kernel: [48109.889422] [<ffffffff81099b0c>] __lock_page+0x61/0x68
Aug 11 14:35:20 paris kernel: [48109.889425] [<ffffffff81054457>] ? wake_bit_function+0x0/0x2e
Aug 11 14:35:20 paris kernel: [48109.889429] [<ffffffff810a14c0>] ? pagevec_lookup_tag+0x20/0x29
Aug 11 14:35:20 paris kernel: [48109.889433] [<ffffffff810a0062>] write_cache_pages+0x196/0x31f
Aug 11 14:35:20 paris kernel: [48109.889437] [<ffffffff8115bd00>] ? nfs_writepages_callback+0x0/0x26
Aug 11 14:35:20 paris kernel: [48109.889441] [<ffffffff8109aaa5>] ? __generic_file_aio_write+0x247/0x27c
Aug 11 14:35:20 paris kernel: [48109.889444] [<ffffffff810cdfc2>] ? do_truncate+0x78/0x82
Aug 11 14:35:20 paris kernel: [48109.889448] [<ffffffff8115bcbe>] nfs_writepages+0xb1/0xf3
Aug 11 14:35:20 paris kernel: [48109.889451] [<ffffffff8115bed7>] ? nfs_flush_one+0x0/0xda
Aug 11 14:35:20 paris kernel: [48109.889455] [<ffffffff810a0228>] do_writepages+0x1c/0x25
Aug 11 14:35:20 paris kernel: [48109.889459] [<ffffffff810e83c3>] writeback_single_inode+0xdc/0x2d1
Aug 11 14:35:20 paris kernel: [48109.889463] [<ffffffff810e85e0>] sync_inode+0x28/0x35
Aug 11 14:35:20 paris kernel: [48109.889466] [<ffffffff8115b231>] nfs_wb_all+0x3d/0x3f
Aug 11 14:35:20 paris kernel: [48109.889469] [<ffffffff8114f9eb>] nfs_do_fsync+0x1b/0x38
Aug 11 14:35:20 paris kernel: [48109.889473] [<ffffffff8114fbc1>] nfs_file_flush+0x70/0x78
Aug 11 14:35:20 paris kernel: [48109.889477] [<ffffffff810cd25e>] filp_close+0x3e/0x6d
Aug 11 14:35:20 paris kernel: [48109.889480] [<ffffffff810cf107>] ? sys_write+0x5c/0x69
Aug 11 14:35:20 paris kernel: [48109.889484] [<ffffffff810cd324>] sys_close+0x97/0xcb
Aug 11 14:35:20 paris kernel: [48109.889488] [<ffffffff8100296b>] system_call_fastpath+0x16/0x1b
Aug 11 14:35:20 paris kernel: [48109.889492] INFO: task php-fpm:12679 blocked for more than 120 seconds.
Aug 11 14:35:20 paris kernel: [48109.889494] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Aug 11 14:35:20 paris kernel: [48109.889496] php-fpm D 0000000000000004 0 12679 4939 0x00000000
Aug 11 14:35:20 paris kernel: [48109.889500] ffff8803aeb0f988 0000000000000086 ffff8803aeb0f908 ffff88042ec98d80
Aug 11 14:35:20 paris kernel: [48109.889504] 00000000000006bf ffff8804111c7808 ffff8803aeb0ffd8 ffff880429da21c0
Aug 11 14:35:20 paris kernel: [48109.889508] 0000000000013100 ffff8803aeb0ffd8 0000000000013100 0000000000013100
Aug 11 14:35:20 paris kernel: [48109.889511] Call Trace:
Aug 11 14:35:20 paris kernel: [48109.889515] [<ffffffff8105448e>] ? spin_unlock_irqrestore+0x9/0xb
Aug 11 14:35:20 paris kernel: [48109.889519] [<ffffffff810dfa40>] ? inode_wait+0x0/0xd
Aug 11 14:35:20 paris kernel: [48109.889522] [<ffffffff810dfa49>] inode_wait+0x9/0xd
Aug 11 14:35:20 paris kernel: [48109.889526] [<ffffffff8146d165>] __wait_on_bit+0x43/0x76
Aug 11 14:35:20 paris kernel: [48109.889530] [<ffffffff810e82c7>] inode_wait_for_writeback+0x82/0xa2
Aug 11 14:35:20 paris kernel: [48109.889534] [<ffffffff81054457>] ? wake_bit_function+0x0/0x2e
Aug 11 14:35:20 paris kernel: [48109.889538] [<ffffffff8115855e>] ? nfs_pageio_complete+0x9/0xb
Aug 11 14:35:20 paris kernel: [48109.889542] [<ffffffff810e8392>] writeback_single_inode+0xab/0x2d1
Aug 11 14:35:20 paris kernel: [48109.889546] [<ffffffff810e85e0>] sync_inode+0x28/0x35
Aug 11 14:35:20 paris kernel: [48109.889549] [<ffffffff8115b882>] nfs_wb_page+0x7c/0x95
Aug 11 14:35:20 paris kernel: [48109.889553] [<ffffffff8115b8f2>] nfs_flush_incompatible+0x57/0x67
Aug 11 14:35:20 paris kernel: [48109.889556] [<ffffffff8114f860>] nfs_write_begin+0xe6/0x1b1
Aug 11 14:35:20 paris kernel: [48109.889560] [<ffffffff810990de>] generic_file_buffered_write+0x100/0x24e
Aug 11 14:35:20 paris kernel: [48109.889564] [<ffffffff8109aaa5>] __generic_file_aio_write+0x247/0x27c
Aug 11 14:35:20 paris kernel: [48109.889569] [<ffffffff8146d282>] ? __mutex_unlock_slowpath+0x31/0x38
Aug 11 14:35:20 paris kernel: [48109.889572] [<ffffffff810cdfc2>] ? do_truncate+0x78/0x82
Aug 11 14:35:20 paris kernel: [48109.889576] [<ffffffff8109ab32>] generic_file_aio_write+0x58/0xa4
Aug 11 14:35:20 paris kernel: [48109.889579] [<ffffffff81150299>] nfs_file_write+0xd7/0x17f
Aug 11 14:35:20 paris kernel: [48109.889583] [<ffffffff810ceaa1>] do_sync_write+0xc6/0x103
Aug 11 14:35:20 paris kernel: [48109.889587] [<ffffffff810b0466>] ? handle_mm_fault+0x378/0x74d
Aug 11 14:35:20 paris kernel: [48109.889591] [<ffffffff811ab2d1>] ? security_file_permission+0x11/0x13
Aug 11 14:35:20 paris kernel: [48109.889595] [<ffffffff810cefdd>] vfs_write+0xa9/0x106
Aug 11 14:35:20 paris kernel: [48109.889598] [<ffffffff810cf0f0>] sys_write+0x45/0x69
Aug 11 14:35:20 paris kernel: [48109.889602] [<ffffffff8100296b>] system_call_fastpath+0x16/0x1b
Aug 11 14:37:20 paris kernel: [48229.559725] INFO: task flush-0:17:12630 blocked for more than 120 seconds.
Aug 11 14:37:20 paris kernel: [48229.559728] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Aug 11 14:37:20 paris kernel: [48229.559730] flush-0:17 D 0000000000000009 0 12630 2 0x00000000
Aug 11 14:37:20 paris kernel: [48229.559780] ffff880227d87c70 0000000000000046 ffff8803e66f4c90 ffff88022f069b00
Aug 11 14:37:20 paris kernel: [48229.559784] ffff880227d87bf0 ffffffff00000000 ffff880227d87fd8 ffff880228d92880
Aug 11 14:37:20 paris kernel: [48229.559788] 0000000000013100 ffff880227d87fd8 0000000000013100 0000000000013100
Aug 11 14:37:20 paris kernel: [48229.559792] Call Trace:
Aug 11 14:37:20 paris kernel: [48229.559798] [<ffffffff810dfa40>] ? inode_wait+0x0/0xd
Aug 11 14:37:20 paris kernel: [48229.559803] [<ffffffff810dfa49>] inode_wait+0x9/0xd
Aug 11 14:37:20 paris kernel: [48229.559809] [<ffffffff8146d165>] __wait_on_bit+0x43/0x76
Aug 11 14:37:20 paris kernel: [48229.559814] [<ffffffff810e82c7>] inode_wait_for_writeback+0x82/0xa2
Aug 11 14:37:20 paris kernel: [48229.559819] [<ffffffff81054457>] ? wake_bit_function+0x0/0x2e
Aug 11 14:37:20 paris kernel: [48229.559823] [<ffffffff810e8f3c>] wb_writeback+0x195/0x1b5
Aug 11 14:37:20 paris kernel: [48229.559829] [<ffffffff81048ae9>] ? try_to_del_timer_sync+0x6e/0x7c
Aug 11 14:37:20 paris kernel: [48229.559834] [<ffffffff810e913e>] wb_do_writeback+0x137/0x14d
Aug 11 14:37:20 paris kernel: [48229.559838] [<ffffffff81048bea>] ? process_timeout+0x0/0xb
Aug 11 14:37:20 paris kernel: [48229.559843] [<ffffffff810e918e>] bdi_writeback_task+0x3a/0xab
Aug 11 14:37:20 paris kernel: [48229.559848] [<ffffffff810ac5aa>] ? bdi_start_fn+0x0/0xc4
Aug 11 14:37:20 paris kernel: [48229.559852] [<ffffffff810ac608>] bdi_start_fn+0x5e/0xc4
Aug 11 14:37:20 paris kernel: [48229.559856] [<ffffffff810ac5aa>] ? bdi_start_fn+0x0/0xc4
Aug 11 14:37:20 paris kernel: [48229.559861] [<ffffffff81053fe7>] kthread+0x7a/0x82
Aug 11 14:37:20 paris kernel: [48229.559865] [<ffffffff81003714>] kernel_thread_helper+0x4/0x10
Aug 11 14:37:20 paris kernel: [48229.559870] [<ffffffff81053f6d>] ? kthread+0x0/0x82
Aug 11 14:37:20 paris kernel: [48229.559874] [<ffffffff81003710>] ? kernel_thread_helper+0x0/0x10
|
Seems nfs is hanging. nfs is running over eth1 to the fileserver. The interfaces are locked down by iptables. For eth1 the following ruleset is active
| Quote: | iptables -A INPUT -i eth1 -m state --state NEW -j ACCEPT
|
I doesn't understand why nfs gets waiting...
Any ideas are welcome, thanks! |
|
Kernel & Hardware
