blocked for more than 120 seconds

bert2002 · 2011-07-31 14:55:09

Hi,

after a fresh installation of Archlinux on a new SSD (dont know if this is related) on my old computer (no other hardware change) I am getting quite often a problem with firefox and other applications with following error:

[ 4921.272887] INFO: task firefox-bin:1371 blocked for more than 120 seconds.
[ 4921.272891] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 4921.272896] firefox-bin     D f2f85f2c     0  1371   1186 0x00000000
[ 4921.272903]  f2f85f3c 00200086 00000002 f2f85f2c 00000000 00000031 802c6004 00000000
[ 4921.272913]  00000000 00000001 c103d509 f2ee1ea0 f54032b8 f5403360 c1465e40 c1527480
[ 4921.272923]  f2f85edc c1527480 f5406480 f2ee1ea0 c1463fe0 2af9d067 802f4000 55315437
[ 4921.272933] Call Trace:
[ 4921.272945]  [<c103d509>] ? scheduler_tick+0xa9/0x220
[ 4921.272953]  [<c10ebf3d>] ? handle_mm_fault+0xfd/0x210
[ 4921.272959]  [<c10289f0>] ? vmalloc_sync_all+0x120/0x120
[ 4921.272965]  [<c134a0d5>] rwsem_down_failed_common+0x95/0xe0
[ 4921.272970]  [<c134a132>] rwsem_down_write_failed+0x12/0x20
[ 4921.272975]  [<c134a19a>] call_rwsem_down_write_failed+0x6/0x8
[ 4921.272981]  [<c13499ea>] ? down_write+0x1a/0x1c
[ 4921.272986]  [<c10f02a8>] sys_mmap_pgoff+0xd8/0x1c0
[ 4921.272991]  [<c134b31f>] sysenter_do_call+0x12/0x28
[ 4921.272996]  [<c1340000>] ? cpu_callback+0x3a/0x289
[ 5041.272875] INFO: task firefox-bin:1371 blocked for more than 120 seconds.
[ 5041.272880] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 5041.272884] firefox-bin     D f2f85f2c     0  1371   1186 0x00000000
[ 5041.272891]  f2f85f3c 00200086 00000002 f2f85f2c 00000000 00000031 802c6004 00000000
[ 5041.272902]  00000000 00000001 c103d509 f2ee1ea0 f54032b8 f5403360 c1465e40 c1527480
[ 5041.272911]  f2f85edc c1527480 f5406480 f2ee1ea0 c1463fe0 2af9d067 802f4000 55315437
[ 5041.272921] Call Trace:
[ 5041.272934]  [<c103d509>] ? scheduler_tick+0xa9/0x220
[ 5041.272941]  [<c10ebf3d>] ? handle_mm_fault+0xfd/0x210
[ 5041.272947]  [<c10289f0>] ? vmalloc_sync_all+0x120/0x120
[ 5041.272953]  [<c134a0d5>] rwsem_down_failed_common+0x95/0xe0
[ 5041.272958]  [<c134a132>] rwsem_down_write_failed+0x12/0x20
[ 5041.272963]  [<c134a19a>] call_rwsem_down_write_failed+0x6/0x8
[ 5041.272969]  [<c13499ea>] ? down_write+0x1a/0x1c
[ 5041.272974]  [<c10f02a8>] sys_mmap_pgoff+0xd8/0x1c0
[ 5041.272979]  [<c134b31f>] sysenter_do_call+0x12/0x28
[ 5041.272985]  [<c1340000>] ? cpu_callback+0x3a/0x289
[ 5161.272869] INFO: task firefox-bin:1371 blocked for more than 120 seconds.
[ 5161.272873] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 5161.272877] firefox-bin     D f2f85f2c     0  1371   1186 0x00000000
[ 5161.272885]  f2f85f3c 00200086 00000002 f2f85f2c 00000000 00000031 802c6004 00000000
[ 5161.272895]  00000000 00000001 c103d509 f2ee1ea0 f54032b8 f5403360 c1465e40 c1527480
[ 5161.272904]  f2f85edc c1527480 f5406480 f2ee1ea0 c1463fe0 2af9d067 802f4000 55315437
[ 5161.272914] Call Trace:
[ 5161.272927]  [<c103d509>] ? scheduler_tick+0xa9/0x220
[ 5161.272934]  [<c10ebf3d>] ? handle_mm_fault+0xfd/0x210
[ 5161.272940]  [<c10289f0>] ? vmalloc_sync_all+0x120/0x120
[ 5161.272946]  [<c134a0d5>] rwsem_down_failed_common+0x95/0xe0
[ 5161.272951]  [<c134a132>] rwsem_down_write_failed+0x12/0x20
[ 5161.272956]  [<c134a19a>] call_rwsem_down_write_failed+0x6/0x8
[ 5161.272962]  [<c13499ea>] ? down_write+0x1a/0x1c
[ 5161.272967]  [<c10f02a8>] sys_mmap_pgoff+0xd8/0x1c0
[ 5161.272973]  [<c134b31f>] sysenter_do_call+0x12/0x28
[ 5161.272978]  [<c1340000>] ? cpu_callback+0x3a/0x289
[ 5161.272995] INFO: task pkill:2886 blocked for more than 120 seconds.
[ 5161.272998] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 5161.273001] pkill           D c2201e50     0  2886      1 0x00000004
[ 5161.273007]  c2201e60 00200086 00000002 c2201e50 f3e39c00 c2201de0 c220e208 f32b9918
[ 5161.273016]  00000000 c1409b29 00000000 00000000 00000000 f32b9918 c220e208 c1527480
[ 5161.273025]  c2201e14 c1527480 f5506480 f4060d20 f4063020 c220e200 00000001 000a00d0
[ 5161.273035] Call Trace:
[ 5161.273042]  [<c112eb7a>] ? mntput_no_expire+0x2a/0xd0
[ 5161.273047]  [<c134a0d5>] rwsem_down_failed_common+0x95/0xe0
[ 5161.273052]  [<c134a152>] rwsem_down_read_failed+0x12/0x14
[ 5161.273056]  [<c134a18f>] call_rwsem_down_read_failed+0x7/0xc
[ 5161.273062]  [<c13499c2>] ? down_read+0x12/0x20
[ 5161.273066]  [<c10ec568>] __access_remote_vm+0x28/0x170
[ 5161.273072]  [<c104366e>] ? get_task_mm+0x3e/0x60
[ 5161.273076]  [<c10ec8fb>] access_process_vm+0x4b/0x70
[ 5161.273083]  [<c115d855>] proc_pid_cmdline+0x75/0xf0
[ 5161.273088]  [<c115df27>] proc_info_read+0x77/0xc0
[ 5161.273093]  [<c1114a98>] vfs_read+0x88/0x160
[ 5161.273098]  [<c115deb0>] ? proc_loginuid_read+0xc0/0xc0
[ 5161.273102]  [<c1114bad>] sys_read+0x3d/0x70
[ 5161.273107]  [<c134b31f>] sysenter_do_call+0x12/0x28

as you can see its even sometimes not possible to kill the process. I didnt used the normal kernel and didnt tried it with another yet.

Linux pc 2.6.39-ARCH #1 SMP PREEMPT Sat Jul 9 15:31:04 CEST 2011 i686 Intel(R) Pentium(R) D CPU 2.80GHz GenuineIntel GNU/Linux

Somebody knows the problem?

Thanks! && best regards bert2002

fukawi2 · 2011-07-31 23:10:18

I used to get this on several CentOS boxes, but I never got a solution...

Are you able to strace the process before it happens?

bert2002 · 2011-08-01 09:17:17

fukawi2 wrote:

I used to get this on several CentOS boxes, but I never got a solution...
Are you able to strace the process before it happens?

Not yet, but to get one it should be no problem since it occurs quite often. I will keep you updated when I got a strace.

karol · 2011-08-02 02:01:11

Sorry, I misunderstood your post, please ignore.

Last edited by karol (2011-08-02 02:03:07)

bert2002 · 2011-08-08 20:13:14

Sooo I got an strace, but cant really figure out what would be wrong except a lot of "Resource temporarily unavailable" messages.

strace -> https://rt.fm/p6v

Somehow I have the feeling that it has something to do with dbus.

Anyone else some new information?

fukawi2 · 2011-08-08 22:48:50

read(3, 0xb4749058, 4096) = -1 EAGAIN (Resource temporarily unavailable)

What is FD 3?

# ls -lh /proc/PID/fd/

Replace PID with the appropriate PID of the firefox process.

bert2002 · 2011-08-09 20:57:12

Its a socket.

ls -lh /proc/1533/fd/3
lrwx------ 1 user users 64 Aug  9 22:48 /proc/PID/fd/3 -> socket:[11299]

netstat -ae | grep 11299
unix  3      [ ]         STREAM     CONNECTED     11299

NOTE: This is from a still running instance. I will try to catch one when it stalled.

Arch Linux

#1 2011-07-31 14:55:09

blocked for more than 120 seconds

#2 2011-07-31 23:10:18

Re: blocked for more than 120 seconds

#3 2011-08-01 09:17:17

Re: blocked for more than 120 seconds

#4 2011-08-02 02:01:11

Re: blocked for more than 120 seconds

#5 2011-08-08 20:13:14

Re: blocked for more than 120 seconds

#6 2011-08-08 22:48:50

Re: blocked for more than 120 seconds

#7 2011-08-09 20:57:12

Re: blocked for more than 120 seconds

Board footer