Bug#517449: linux-image-2.6.26-2-vserver-amd64: still getting task task:pid blocked for more than 120 seconds. kernel log messages
Hi all, sorry if my message from yesterday was noise too, but I haven't understood yet why those kernel log messages appear anyway. Somebody in this bug report pointed out that those INFO: task xy blocked for more than 120 seconds. are only symptoms of the real problem. Could somebody explain the actual problem to me please? What I have learned from this and from other similar bug reports like this yet is, that it has something to do with the load which is on the machine. But that is not clear enough to me. TIA and kind regards, Timo -- To UNSUBSCRIBE, email to debian-bugs-dist-requ...@lists.debian.org with a subject of unsubscribe. Trouble? Contact listmas...@lists.debian.org
Bug#517449: linux-image-2.6.26-2-vserver-amd64: still getting task task:pid blocked for more than 120 seconds. kernel log messages
same to me a have different machines that have different services with this bug On Fri, Mar 26, 2010 at 4:35 AM, Timo Veith timo.ve...@gmail.com wrote: Hi all, sorry if my message from yesterday was noise too, but I haven't understood yet why those kernel log messages appear anyway. Somebody in this bug report pointed out that those INFO: task xy blocked for more than 120 seconds. are only symptoms of the real problem. Could somebody explain the actual problem to me please? What I have learned from this and from other similar bug reports like this yet is, that it has something to do with the load which is on the machine. But that is not clear enough to me. TIA and kind regards, Timo -- To unsubscribe, send mail to 517449-unsubscr...@bugs.debian.org. -- To UNSUBSCRIBE, email to debian-bugs-dist-requ...@lists.debian.org with a subject of unsubscribe. Trouble? Contact listmas...@lists.debian.org
Bug#517449: linux-image-2.6.26-2-vserver-amd64: still getting task task:pid blocked for more than 120 seconds. kernel log messages
On Fri, 2010-03-26 at 08:35 +0100, Timo Veith wrote: Hi all, sorry if my message from yesterday was noise too, but I haven't understood yet why those kernel log messages appear anyway. Somebody in this bug report pointed out that those INFO: task xy blocked for more than 120 seconds. are only symptoms of the real problem. Could somebody explain the actual problem to me please? The problem is that a task has been in uninterruptible sleep (aka IO-wait) for a long time, which probably means it is deadlocked due to a lock imbalance or incorrect lock ordering. The warning should point to which lock is involved, but that does not tell us where the buggy code is. What I have learned from this and from other similar bug reports like this yet is, that it has something to do with the load which is on the machine. But that is not clear enough to me. As the load increases there is likely to be greater lock contention and more chance of a bug in lock ordering actually causing deadlock. (There were also some bugs in tickless (aka 'NOHZ') scheduling which could also lead to this warning, but they have been fixed. Those bugs mostly affected very idle machines.) Ben. -- Ben Hutchings Once a job is fouled up, anything done to improve it makes it worse. signature.asc Description: This is a digitally signed message part
Bug#517449: linux-image-2.6.26-2-vserver-amd64: still getting task task:pid blocked for more than 120 seconds. kernel log messages
Package: linux-2.6 Version: 2.6.26-21lenny4 Followup-For: Bug #517449 -- Package-specific info: ** Version: Linux version 2.6.26-2-vserver-amd64 (Debian 2.6.26-21lenny4) (da...@debian.org) (gcc version 4.1.3 20080704 (prerelease) (Debian 4.1.2-25)) #1 SMP Tue Mar 9 23:51:13 UTC 2010 ** Command line: root=UUID=1e176c09-1de6-425a-886c-c210b2c74125 ro rootdelay=10 quiet ** Not tainted ** Kernel log: [1102456.907369] INFO: task mysqld:28528 blocked for more than 120 seconds. [1102456.907410] echo 0 /proc/sys/kernel/hung_task_timeout_secs disables this message. [1102456.907449] mysqldD 810001040ba0 0 28528 13048 [1102456.907455] 810195985da8 0086 8023d63e [1102456.907462] 0003 81019942f4d0 81019f0b14d0 81019942f758 [1102456.907467] 0296 [1102456.907472] Call Trace: [1102456.907498] [8023d63e] lock_timer_base+0x26/0x4b [1102456.907532] [a0151618] :jbd:log_wait_commit+0x9f/0xed [1102456.907540] [80246ef9] autoremove_wake_function+0x0/0x2e [1102456.907559] [a014d4f9] :jbd:journal_stop+0x165/0x18d [1102456.907571] [802c30f3] __writeback_single_inode+0x17f/0x29d [1102456.907578] [80246ef9] autoremove_wake_function+0x0/0x2e [1102456.907593] [802c3a1f] sync_inode+0x24/0x31 [1102456.907610] [a015d62a] :ext3:ext3_sync_file+0x9e/0xb0 [1102456.907622] [802c5f96] do_fsync+0x52/0xa4 [1102456.907632] [802c600b] __do_fsync+0x23/0x36 [1102456.907640] [80224f42] ia32_sysret+0x0/0x1f [1102456.907656] [1102459.052442] INFO: task mysqld:14224 blocked for more than 120 seconds. [1102459.052471] echo 0 /proc/sys/kernel/hung_task_timeout_secs disables this message. [1102459.052509] mysqldD 0 14224 13048 [1102459.052515] 8101964a7da8 0086 8023d63e [1102459.052522] 0003 810197c5d020 81019f13b550 810197c5d2a8 [1102459.052527] 0296 [1102459.052532] Call Trace: [1102459.052557] [8023d63e] lock_timer_base+0x26/0x4b [1102459.052592] [a0151618] :jbd:log_wait_commit+0x9f/0xed [1102459.052599] [80246ef9] autoremove_wake_function+0x0/0x2e [1102459.052617] [a014d4f9] :jbd:journal_stop+0x165/0x18d [1102459.052628] [802c30f3] __writeback_single_inode+0x17f/0x29d [1102459.052647] [802c3a1f] sync_inode+0x24/0x31 [1102459.052665] [a015d62a] :ext3:ext3_sync_file+0x9e/0xb0 [1102459.052679] [802c5f96] do_fsync+0x52/0xa4 [1102459.052688] [802c600b] __do_fsync+0x23/0x36 [1102459.052696] [80224f42] ia32_sysret+0x0/0x1f [1102459.052713] ** Model information sys_vendor: Dell Computer Corporation product_name: PowerEdge 1850 product_version: chassis_vendor: Dell Computer Corporation chassis_version: bios_vendor: Dell Computer Corporation bios_version: A07 board_vendor: Dell Computer Corporation board_name: 0D8266 board_version: A02 ** Loaded modules: Module Size Used by ib_iser34168 0 rdma_cm31732 1 ib_iser ib_cm 37800 1 rdma_cm iw_cm 13448 1 rdma_cm ib_sa 24704 2 rdma_cm,ib_cm ib_mad 39208 2 ib_cm,ib_sa ib_core59392 6 ib_iser,rdma_cm,ib_cm,iw_cm,ib_sa,ib_mad ib_addr10888 1 rdma_cm iscsi_tcp 21764 0 libiscsi 32384 2 ib_iser,iscsi_tcp scsi_transport_iscsi36256 4 ib_iser,iscsi_tcp,libiscsi ip6table_filter 7296 0 ip6_tables 23056 1 ip6table_filter x_tables 25224 1 ip6_tables ipmi_si43628 0 ipmi_devintf 13200 0 ipmi_msghandler38520 2 ipmi_si,ipmi_devintf loop 19596 0 snd_pcm81800 0 snd_timer 25744 1 snd_pcm snd63688 2 snd_pcm,snd_timer soundcore 12064 1 snd serio_raw 9988 0 snd_page_alloc 13072 1 snd_pcm rng_core8968 0 psmouse42268 0 video 24212 0 output 7808 1 video pcspkr 7040 0 button 11680 0 shpchp 34080 0 pci_hotplug32056 1 shpchp e752x_edac 16656 0 edac_core 49560 1 e752x_edac dcdbas 11952 0 evdev 14208 0 ext3 127632 26 jbd51240 1 ext3 mbcache12804 1 ext3 dm_mirror 20608 0 dm_log 13956 1 dm_mirror dm_snapshot19400 0 dm_mod 59376 54 dm_mirror,dm_log,dm_snapshot sg 36448 0 sd_mod 29376 4 ide_cd_mod
Bug#517449: linux-image-2.6.26-2-vserver-amd64: still getting task task:pid blocked for more than 120 seconds. kernel log messages
Happens to me yesterday with linux-image-2.6.26-2-xen-amd64_2.6.26-19lenny2_amd64.deb in differents machines. Hope this is fixed in 2.6.26-21 On Thu, Mar 25, 2010 at 6:47 AM, Timo Veith timo.ve...@gmail.com wrote: Package: linux-2.6 Version: 2.6.26-21lenny4 Followup-For: Bug #517449 -- Package-specific info: ** Version: Linux version 2.6.26-2-vserver-amd64 (Debian 2.6.26-21lenny4) (da...@debian.org) (gcc version 4.1.3 20080704 (prerelease) (Debian 4.1.2-25)) #1 SMP Tue Mar 9 23:51:13 UTC 2010 ** Command line: root=UUID=1e176c09-1de6-425a-886c-c210b2c74125 ro rootdelay=10 quiet ** Not tainted ** Kernel log: [1102456.907369] INFO: task mysqld:28528 blocked for more than 120 seconds. [1102456.907410] echo 0 /proc/sys/kernel/hung_task_timeout_secs disables this message. [1102456.907449] mysqld D 810001040ba0 0 28528 13048 [1102456.907455] 810195985da8 0086 8023d63e [1102456.907462] 0003 81019942f4d0 81019f0b14d0 81019942f758 [1102456.907467] 0296 [1102456.907472] Call Trace: [1102456.907498] [8023d63e] lock_timer_base+0x26/0x4b [1102456.907532] [a0151618] :jbd:log_wait_commit+0x9f/0xed [1102456.907540] [80246ef9] autoremove_wake_function+0x0/0x2e [1102456.907559] [a014d4f9] :jbd:journal_stop+0x165/0x18d [1102456.907571] [802c30f3] __writeback_single_inode+0x17f/0x29d [1102456.907578] [80246ef9] autoremove_wake_function+0x0/0x2e [1102456.907593] [802c3a1f] sync_inode+0x24/0x31 [1102456.907610] [a015d62a] :ext3:ext3_sync_file+0x9e/0xb0 [1102456.907622] [802c5f96] do_fsync+0x52/0xa4 [1102456.907632] [802c600b] __do_fsync+0x23/0x36 [1102456.907640] [80224f42] ia32_sysret+0x0/0x1f [1102456.907656] [1102459.052442] INFO: task mysqld:14224 blocked for more than 120 seconds. [1102459.052471] echo 0 /proc/sys/kernel/hung_task_timeout_secs disables this message. [1102459.052509] mysqld D 0 14224 13048 [1102459.052515] 8101964a7da8 0086 8023d63e [1102459.052522] 0003 810197c5d020 81019f13b550 810197c5d2a8 [1102459.052527] 0296 [1102459.052532] Call Trace: [1102459.052557] [8023d63e] lock_timer_base+0x26/0x4b [1102459.052592] [a0151618] :jbd:log_wait_commit+0x9f/0xed [1102459.052599] [80246ef9] autoremove_wake_function+0x0/0x2e [1102459.052617] [a014d4f9] :jbd:journal_stop+0x165/0x18d [1102459.052628] [802c30f3] __writeback_single_inode+0x17f/0x29d [1102459.052647] [802c3a1f] sync_inode+0x24/0x31 [1102459.052665] [a015d62a] :ext3:ext3_sync_file+0x9e/0xb0 [1102459.052679] [802c5f96] do_fsync+0x52/0xa4 [1102459.052688] [802c600b] __do_fsync+0x23/0x36 [1102459.052696] [80224f42] ia32_sysret+0x0/0x1f [1102459.052713] ** Model information sys_vendor: Dell Computer Corporation product_name: PowerEdge 1850 product_version: chassis_vendor: Dell Computer Corporation chassis_version: bios_vendor: Dell Computer Corporation bios_version: A07 board_vendor: Dell Computer Corporation board_name: 0D8266 board_version: A02 ** Loaded modules: Module Size Used by ib_iser 34168 0 rdma_cm 31732 1 ib_iser ib_cm 37800 1 rdma_cm iw_cm 13448 1 rdma_cm ib_sa 24704 2 rdma_cm,ib_cm ib_mad 39208 2 ib_cm,ib_sa ib_core 59392 6 ib_iser,rdma_cm,ib_cm,iw_cm,ib_sa,ib_mad ib_addr 10888 1 rdma_cm iscsi_tcp 21764 0 libiscsi 32384 2 ib_iser,iscsi_tcp scsi_transport_iscsi 36256 4 ib_iser,iscsi_tcp,libiscsi ip6table_filter 7296 0 ip6_tables 23056 1 ip6table_filter x_tables 25224 1 ip6_tables ipmi_si 43628 0 ipmi_devintf 13200 0 ipmi_msghandler 38520 2 ipmi_si,ipmi_devintf loop 19596 0 snd_pcm 81800 0 snd_timer 25744 1 snd_pcm snd 63688 2 snd_pcm,snd_timer soundcore 12064 1 snd serio_raw 9988 0 snd_page_alloc 13072 1 snd_pcm rng_core 8968 0 psmouse 42268 0 video 24212 0 output 7808 1 video pcspkr 7040 0 button 11680 0 shpchp 34080 0 pci_hotplug 32056 1 shpchp e752x_edac 16656 0 edac_core 49560 1 e752x_edac dcdbas 11952 0 evdev 14208 0 ext3 127632 26 jbd 51240 1
