12 Feb
2009
12 Feb
'09
10:29 p.m.
Hi All,
Is this something I should worry about?
Feb 12 20:27:22 sw1 kernel: [3273100.087148] INFO: task kamailio:1845
blocked for more than 120 seconds.
Feb 12 20:27:22 sw1 kernel: [3273100.087206] "echo 0 > /proc/sys/
kernel/hung_task_timeout_secs" disables this message.
Feb 12 20:27:22 sw1 kernel: [3273100.087291] kamailio D
8ce9265a 0 1845 1829
Feb 12 20:27:22 sw1 kernel: [3273100.087346] f6a98da0 00000082
23f7e426 8ce9265a 000701ae f6a98f2c c302bfa0 00000002
Feb 12 20:27:22 sw1 kernel: [3273100.087427] c01344f6 001e17ce
00000001 00000000 c01190e6 f6a98da0 f6a98da0 c02c4dc0
Feb 12 20:27:22 sw1 kernel: [3273100.087538] f74eea84 f74eea8c
f74eea88 f6a98da0 c02b8846 f68c3d68 f74eea8c f6a98da0
Feb 12 20:27:22 sw1 kernel: [3273100.087648] Call Trace:
Feb 12 20:27:22 sw1 kernel: [3273100.087730] [<c01344f6>] ktime_get
+0xd/0x21
Feb 12 20:27:22 sw1 kernel: [3273100.087784] [<c01190e6>]
hrtick_start_fair+0xeb/0x12c
Feb 12 20:27:22 sw1 kernel: [3273100.087840] [<c02b8846>]
__mutex_lock_slowpath+0x50/0x7b
Feb 12 20:27:22 sw1 kernel: [3273100.087896] [<c02b86dc>] mutex_lock
+0xa/0xb
Feb 12 20:27:22 sw1 kernel: [3273100.087945] [<c02a7ea9>]
unix_dgram_recvmsg+0x3e/0x245
Feb 12 20:27:22 sw1 kernel: [3273100.087998] [<c01318e9>]
autoremove_wake_function+0xd/0x2d
Feb 12 20:27:22 sw1 kernel: [3273100.088055] [<c011845d>]
__wake_up_common+0x2e/0x58
Feb 12 20:27:22 sw1 kernel: [3273100.088109] [<c024ef76>] sock_recvmsg
+0xde/0xf9
Feb 12 20:27:22 sw1 kernel: [3273100.088165] [<c01318dc>]
autoremove_wake_function+0x0/0x2d
Feb 12 20:27:22 sw1 kernel: [3273100.088223] [<c0117c67>]
kunmap_atomic+0x55/0x8a
Feb 12 20:27:22 sw1 kernel: [3273100.088273] [<c0117c79>]
kunmap_atomic+0x67/0x8a
Feb 12 20:27:22 sw1 kernel: [3273100.088327] [<c015ae91>]
get_page_from_freelist+0x34f/0x3e3
Feb 12 20:27:22 sw1 kernel: [3273100.088387] [<c024fd9a>] sys_recvfrom
+0xb4/0x116
Feb 12 20:27:22 sw1 kernel: [3273100.088438] [<c015b0fb>]
__alloc_pages_internal+0xb5/0x34e
Feb 12 20:27:22 sw1 kernel: [3273100.088497] [<c0163cd3>]
handle_mm_fault+0x257/0x690
Feb 12 20:27:22 sw1 kernel: [3273100.088554] [<c025024d>]
sys_socketcall+0x135/0x19e
Feb 12 20:27:22 sw1 kernel: [3273100.088610] [<c0103853>]
sysenter_past_esp+0x78/0xb1
Feb 12 20:27:22 sw1 kernel: [3273100.091119] [<c02b0000>]
acpi_pci_root_add+0x165/0x296
Feb 12 20:27:22 sw1 kernel: [3273100.091174] =======================
Feb 12 20:27:22 sw1 kernel: [3273100.091218] INFO: task kamailio:1846
blocked for more than 120 seconds.
Feb 12 20:27:22 sw1 kernel: [3273100.091274] "echo 0 > /proc/sys/
kernel/hung_task_timeout_secs" disables this message.
Feb 12 20:27:22 sw1 kernel: [3273100.091358] kamailio D
00000002 0 1846 1829
Feb 12 20:27:22 sw1 kernel: [3273100.091413] f6a995e0 00000086
00000000 00000002 00000000 f6a9976c c3017fa0 00000000
Feb 12 20:27:22 sw1 kernel: [3273100.091495] ffffffff 1d621a39
00000000 00000000 00000000 00000000 00000000 000000ff
Feb 12 20:27:22 sw1 kernel: [3273100.091605] f74eea84 f74eea8c
f74eea88 f6a995e0 c02b8846 f74eea8c f6b21d68 f6a995e0
Feb 12 20:27:22 sw1 kernel: [3273100.091715] Call Trace:
Feb 12 20:27:22 sw1 kernel: [3273100.091790] [<c02b8846>]
__mutex_lock_slowpath+0x50/0x7b
Feb 12 20:27:22 sw1 kernel: [3273100.091847] [<c02b86dc>] mutex_lock
+0xa/0xb
Feb 12 20:27:22 sw1 kernel: [3273100.091895] [<c02a7ea9>]
unix_dgram_recvmsg+0x3e/0x245
Feb 12 20:27:22 sw1 kernel: [3273100.091949] [<c0129ab0>]
lock_timer_base+0x19/0x35
Feb 12 20:27:22 sw1 kernel: [3273100.092002] [<c0129b10>]
try_to_del_timer_sync+0x44/0x4a
Feb 12 20:27:22 sw1 kernel: [3273100.092057] [<c024ef76>] sock_recvmsg
+0xde/0xf9
Feb 12 20:27:22 sw1 kernel: [3273100.092108] [<c01297ec>]
process_timeout+0x0/0x5
Feb 12 20:27:22 sw1 kernel: [3273100.092163] [<c01318dc>]
autoremove_wake_function+0x0/0x2d
Feb 12 20:27:22 sw1 kernel: [3273100.092219] [<c015a0d0>] __rmqueue
+0x13/0x174
Feb 12 20:27:22 sw1 kernel: [3273100.092221] [<c0117c67>]
kunmap_atomic+0x55/0x8a
Feb 12 20:27:22 sw1 kernel: [3273100.092221] [<c0117c79>]
kunmap_atomic+0x67/0x8a
Feb 12 20:27:22 sw1 kernel: [3273100.092221] [<c015ae91>]
get_page_from_freelist+0x34f/0x3e3
Feb 12 20:27:22 sw1 kernel: [3273100.092221] [<c024fd9a>] sys_recvfrom
+0xb4/0x116
Feb 12 20:27:22 sw1 kernel: [3273100.092221] [<c015b0fb>]
__alloc_pages_internal+0xb5/0x34e
Feb 12 20:27:22 sw1 kernel: [3273100.092221] [<c0163cd3>]
handle_mm_fault+0x257/0x690
Feb 12 20:27:22 sw1 kernel: [3273100.092221] [<c025024d>]
sys_socketcall+0x135/0x19e
Feb 12 20:27:22 sw1 kernel: [3273100.092221] [<c0103853>]
sysenter_past_esp+0x78/0xb1
Feb 12 20:27:22 sw1 kernel: [3273100.092221] [<c02b0000>]
acpi_pci_root_add+0x165/0x296
Feb 12 20:27:22 sw1 kernel: [3273100.092221] =======================
Feb 12 20:27:22 sw1 kernel: [3273100.092221] INFO: task kamailio:22820
blocked for more than 120 seconds.
Feb 12 20:27:22 sw1 kernel: [3273100.092221] "echo 0 > /proc/sys/
kernel/hung_task_timeout_secs" disables this message.
Feb 12 20:27:22 sw1 kernel: [3273100.092221] kamailio D
854aa937 0 22820 22803
Feb 12 20:27:22 sw1 kernel: [3273100.092221] f762fa40 00000086
2603ada4 854aa937 000767a5 f762fbcc c3021fa0 00000001
Feb 12 20:27:22 sw1 kernel: [3273100.092221] c01344f6 001fcdbd
00000001 00000000 c01190e6 f762fa40 f762fa40 c02c4dc0
Feb 12 20:27:22 sw1 kernel: [3273100.092221] f6b38544 f6b3854c
f6b38548 f762fa40 c02b8846 f68a3d68 f6b3854c f762fa40
Feb 12 20:27:22 sw1 kernel: [3273100.092221] Call Trace:
Feb 12 20:27:22 sw1 kernel: [3273100.092221] [<c01344f6>] ktime_get
+0xd/0x21
Feb 12 20:27:22 sw1 kernel: [3273100.092221] [<c01190e6>]
hrtick_start_fair+0xeb/0x12c
Feb 12 20:27:22 sw1 kernel: [3273100.092221] [<c02b8846>]
__mutex_lock_slowpath+0x50/0x7b
Feb 12 20:27:22 sw1 kernel: [3273100.092221] [<c02b86dc>] mutex_lock
+0xa/0xb
Feb 12 20:27:22 sw1 kernel: [3273100.092274] [<c02a7ea9>]
unix_dgram_recvmsg+0x3e/0x245
Feb 12 20:27:22 sw1 kernel: [3273100.092328] [<c01318e9>]
autoremove_wake_function+0xd/0x2d
Feb 12 20:27:22 sw1 kernel: [3273100.092383] [<c015a05d>]
__rmqueue_smallest+0x83/0xe3
Feb 12 20:27:22 sw1 kernel: [3273100.092438] [<c024ef76>] sock_recvmsg
+0xde/0xf9
Feb 12 20:27:22 sw1 kernel: [3273100.092493] [<c01318dc>]
autoremove_wake_function+0x0/0x2d
Feb 12 20:27:22 sw1 kernel: [3273100.092551] [<c0117c67>]
kunmap_atomic+0x55/0x8a
Feb 12 20:27:22 sw1 kernel: [3273100.092601] [<c0117c79>]
kunmap_atomic+0x67/0x8a
Feb 12 20:27:22 sw1 kernel: [3273100.092653] [<c015ae91>]
get_page_from_freelist+0x34f/0x3e3
Feb 12 20:27:22 sw1 kernel: [3273100.092712] [<c024fd9a>] sys_recvfrom
+0xb4/0x116
Feb 12 20:27:22 sw1 kernel: [3273100.092764] [<c015b0fb>]
__alloc_pages_internal+0xb5/0x34e
Feb 12 20:27:22 sw1 kernel: [3273100.092822] [<c0163cd3>]
handle_mm_fault+0x257/0x690
Feb 12 20:27:22 sw1 kernel: [3273100.092881] [<c025024d>]
sys_socketcall+0x135/0x19e
Feb 12 20:27:22 sw1 kernel: [3273100.092937] [<c0103853>]
sysenter_past_esp+0x78/0xb1
Feb 12 20:27:22 sw1 kernel: [3273100.092991] [<c02b0000>]
acpi_pci_root_add+0x165/0x296
Feb 12 20:27:22 sw1 kernel: [3273100.093046] =======================
Feb 12 20:27:22 sw1 kernel: [3273100.093090] INFO: task kamailio:22821
blocked for more than 120 seconds.
Feb 12 20:27:22 sw1 kernel: [3273100.093146] "echo 0 > /proc/sys/
kernel/hung_task_timeout_secs" disables this message.
Feb 12 20:27:22 sw1 kernel: [3273100.093230] kamailio D
8543066c 0 22821 22803
Feb 12 20:27:22 sw1 kernel: [3273100.110119] f762ede0 00000082
2603ada4 8543066c 000767a5 f762ef6c c3017fa0 00000000
Feb 12 20:27:22 sw1 kernel: [3273100.110201] c01344f6 001fcdbd
00000002 00000000 c01190e6 f762ede0 f762ede0 c02c4dc0
Feb 12 20:27:22 sw1 kernel: [3273100.110312] f6b38544 f6b3854c
f6b38548 f762ede0 c02b8846 f6b3854c f6bfdd68 f762ede0
Feb 12 20:27:22 sw1 kernel: [3273100.110422] Call Trace:
Feb 12 20:27:22 sw1 kernel: [3273100.110493] [<c01344f6>] ktime_get
+0xd/0x21
Feb 12 20:27:22 sw1 kernel: [3273100.110543] [<c01190e6>]
hrtick_start_fair+0xeb/0x12c
Feb 12 20:27:22 sw1 kernel: [3273100.110598] [<c02b8846>]
__mutex_lock_slowpath+0x50/0x7b
Feb 12 20:27:22 sw1 kernel: [3273100.110653] [<c02b86dc>] mutex_lock
+0xa/0xb
Feb 12 20:27:22 sw1 kernel: [3273100.110702] [<c02a7ea9>]
unix_dgram_recvmsg+0x3e/0x245
Feb 12 20:27:22 sw1 kernel: [3273100.110755] [<c01318e9>]
autoremove_wake_function+0xd/0x2d
Feb 12 20:27:22 sw1 kernel: [3273100.110810] [<c011845d>]
__wake_up_common+0x2e/0x58
Feb 12 20:27:22 sw1 kernel: [3273100.110864] [<c024ef76>] sock_recvmsg
+0xde/0xf9
Feb 12 20:27:22 sw1 kernel: [3273100.110919] [<c01318dc>]
autoremove_wake_function+0x0/0x2d
Feb 12 20:27:22 sw1 kernel: [3273100.110976] [<c0117c67>]
kunmap_atomic+0x55/0x8a
Feb 12 20:27:22 sw1 kernel: [3273100.111027] [<c0117c79>]
kunmap_atomic+0x67/0x8a
Feb 12 20:27:22 sw1 kernel: [3273100.111079] [<c015ae91>]
get_page_from_freelist+0x34f/0x3e3
Feb 12 20:27:22 sw1 kernel: [3273100.111138] [<c024fd9a>] sys_recvfrom
+0xb4/0x116
Feb 12 20:27:22 sw1 kernel: [3273100.111189] [<c015b0fb>]
__alloc_pages_internal+0xb5/0x34e
Feb 12 20:27:22 sw1 kernel: [3273100.111248] [<c0163cd3>]
handle_mm_fault+0x257/0x690
Feb 12 20:27:22 sw1 kernel: [3273100.111307] [<c025024d>]
sys_socketcall+0x135/0x19e
Feb 12 20:27:22 sw1 kernel: [3273100.111362] [<c0103853>]
sysenter_past_esp+0x78/0xb1
Feb 12 20:27:22 sw1 kernel: [3273100.111417] [<c02b0000>]
acpi_pci_root_add+0x165/0x296
Feb 12 20:27:22 sw1 kernel: [3273100.111471] =======================
12 Feb
12 Feb
10:40 p.m.
Hello,
yes, there is something to worry until you discovered the cause and
might be something not to worry :-) ...
can you get the type of that process? Do:
kamctl ps
and you will see the list of kamailio processes. If it is a SIP worker,
then either is a dns block, tcp block (looks like due to timeout) or
lock block.
Cheers,
Daniel
On 02/12/2009 10:29 PM, Brian Chamberlain wrote:
Hi All,
Is this something I should worry about?
Feb 12 20:27:22 sw1 kernel: [3273100.087148] INFO: task kamailio:1845
blocked for more than 120 seconds.
Feb 12 20:27:22 sw1 kernel: [3273100.087206] "echo 0 >
/proc/sys/kernel/hung_task_timeout_secs" disables this message.
Feb 12 20:27:22 sw1 kernel: [3273100.087291] kamailio D 8ce9265a
0 1845 1829
Feb 12 20:27:22 sw1 kernel: [3273100.087346] f6a98da0 00000082
23f7e426 8ce9265a 000701ae f6a98f2c c302bfa0 00000002
Feb 12 20:27:22 sw1 kernel: [3273100.087427] c01344f6 001e17ce
00000001 00000000 c01190e6 f6a98da0 f6a98da0 c02c4dc0
Feb 12 20:27:22 sw1 kernel: [3273100.087538] f74eea84 f74eea8c
f74eea88 f6a98da0 c02b8846 f68c3d68 f74eea8c f6a98da0
Feb 12 20:27:22 sw1 kernel: [3273100.087648] Call Trace:
Feb 12 20:27:22 sw1 kernel: [3273100.087730] [<c01344f6>]
ktime_get+0xd/0x21
Feb 12 20:27:22 sw1 kernel: [3273100.087784] [<c01190e6>]
hrtick_start_fair+0xeb/0x12c
Feb 12 20:27:22 sw1 kernel: [3273100.087840] [<c02b8846>]
__mutex_lock_slowpath+0x50/0x7b
Feb 12 20:27:22 sw1 kernel: [3273100.087896] [<c02b86dc>]
mutex_lock+0xa/0xb
Feb 12 20:27:22 sw1 kernel: [3273100.087945] [<c02a7ea9>]
unix_dgram_recvmsg+0x3e/0x245
Feb 12 20:27:22 sw1 kernel: [3273100.087998] [<c01318e9>]
autoremove_wake_function+0xd/0x2d
Feb 12 20:27:22 sw1 kernel: [3273100.088055] [<c011845d>]
__wake_up_common+0x2e/0x58
Feb 12 20:27:22 sw1 kernel: [3273100.088109] [<c024ef76>]
sock_recvmsg+0xde/0xf9
Feb 12 20:27:22 sw1 kernel: [3273100.088165] [<c01318dc>]
autoremove_wake_function+0x0/0x2d
Feb 12 20:27:22 sw1 kernel: [3273100.088223] [<c0117c67>]
kunmap_atomic+0x55/0x8a
Feb 12 20:27:22 sw1 kernel: [3273100.088273] [<c0117c79>]
kunmap_atomic+0x67/0x8a
Feb 12 20:27:22 sw1 kernel: [3273100.088327] [<c015ae91>]
get_page_from_freelist+0x34f/0x3e3
Feb 12 20:27:22 sw1 kernel: [3273100.088387] [<c024fd9a>]
sys_recvfrom+0xb4/0x116
Feb 12 20:27:22 sw1 kernel: [3273100.088438] [<c015b0fb>]
__alloc_pages_internal+0xb5/0x34e
Feb 12 20:27:22 sw1 kernel: [3273100.088497] [<c0163cd3>]
handle_mm_fault+0x257/0x690
Feb 12 20:27:22 sw1 kernel: [3273100.088554] [<c025024d>]
sys_socketcall+0x135/0x19e
Feb 12 20:27:22 sw1 kernel: [3273100.088610] [<c0103853>]
sysenter_past_esp+0x78/0xb1
Feb 12 20:27:22 sw1 kernel: [3273100.091119] [<c02b0000>]
acpi_pci_root_add+0x165/0x296
Feb 12 20:27:22 sw1 kernel: [3273100.091174] =======================
Feb 12 20:27:22 sw1 kernel: [3273100.091218] INFO: task kamailio:1846
blocked for more than 120 seconds.
Feb 12 20:27:22 sw1 kernel: [3273100.091274] "echo 0 >
/proc/sys/kernel/hung_task_timeout_secs" disables this message.
Feb 12 20:27:22 sw1 kernel: [3273100.091358] kamailio D 00000002
0 1846 1829
Feb 12 20:27:22 sw1 kernel: [3273100.091413] f6a995e0 00000086
00000000 00000002 00000000 f6a9976c c3017fa0 00000000
Feb 12 20:27:22 sw1 kernel: [3273100.091495] ffffffff 1d621a39
00000000 00000000 00000000 00000000 00000000 000000ff
Feb 12 20:27:22 sw1 kernel: [3273100.091605] f74eea84 f74eea8c
f74eea88 f6a995e0 c02b8846 f74eea8c f6b21d68 f6a995e0
Feb 12 20:27:22 sw1 kernel: [3273100.091715] Call Trace:
Feb 12 20:27:22 sw1 kernel: [3273100.091790] [<c02b8846>]
__mutex_lock_slowpath+0x50/0x7b
Feb 12 20:27:22 sw1 kernel: [3273100.091847] [<c02b86dc>]
mutex_lock+0xa/0xb
Feb 12 20:27:22 sw1 kernel: [3273100.091895] [<c02a7ea9>]
unix_dgram_recvmsg+0x3e/0x245
Feb 12 20:27:22 sw1 kernel: [3273100.091949] [<c0129ab0>]
lock_timer_base+0x19/0x35
Feb 12 20:27:22 sw1 kernel: [3273100.092002] [<c0129b10>]
try_to_del_timer_sync+0x44/0x4a
Feb 12 20:27:22 sw1 kernel: [3273100.092057] [<c024ef76>]
sock_recvmsg+0xde/0xf9
Feb 12 20:27:22 sw1 kernel: [3273100.092108] [<c01297ec>]
process_timeout+0x0/0x5
Feb 12 20:27:22 sw1 kernel: [3273100.092163] [<c01318dc>]
autoremove_wake_function+0x0/0x2d
Feb 12 20:27:22 sw1 kernel: [3273100.092219] [<c015a0d0>]
__rmqueue+0x13/0x174
Feb 12 20:27:22 sw1 kernel: [3273100.092221] [<c0117c67>]
kunmap_atomic+0x55/0x8a
Feb 12 20:27:22 sw1 kernel: [3273100.092221] [<c0117c79>]
kunmap_atomic+0x67/0x8a
Feb 12 20:27:22 sw1 kernel: [3273100.092221] [<c015ae91>]
get_page_from_freelist+0x34f/0x3e3
Feb 12 20:27:22 sw1 kernel: [3273100.092221] [<c024fd9a>]
sys_recvfrom+0xb4/0x116
Feb 12 20:27:22 sw1 kernel: [3273100.092221] [<c015b0fb>]
__alloc_pages_internal+0xb5/0x34e
Feb 12 20:27:22 sw1 kernel: [3273100.092221] [<c0163cd3>]
handle_mm_fault+0x257/0x690
Feb 12 20:27:22 sw1 kernel: [3273100.092221] [<c025024d>]
sys_socketcall+0x135/0x19e
Feb 12 20:27:22 sw1 kernel: [3273100.092221] [<c0103853>]
sysenter_past_esp+0x78/0xb1
Feb 12 20:27:22 sw1 kernel: [3273100.092221] [<c02b0000>]
acpi_pci_root_add+0x165/0x296
Feb 12 20:27:22 sw1 kernel: [3273100.092221] =======================
Feb 12 20:27:22 sw1 kernel: [3273100.092221] INFO: task kamailio:22820
blocked for more than 120 seconds.
Feb 12 20:27:22 sw1 kernel: [3273100.092221] "echo 0 >
/proc/sys/kernel/hung_task_timeout_secs" disables this message.
Feb 12 20:27:22 sw1 kernel: [3273100.092221] kamailio D 854aa937
0 22820 22803
Feb 12 20:27:22 sw1 kernel: [3273100.092221] f762fa40 00000086
2603ada4 854aa937 000767a5 f762fbcc c3021fa0 00000001
Feb 12 20:27:22 sw1 kernel: [3273100.092221] c01344f6 001fcdbd
00000001 00000000 c01190e6 f762fa40 f762fa40 c02c4dc0
Feb 12 20:27:22 sw1 kernel: [3273100.092221] f6b38544 f6b3854c
f6b38548 f762fa40 c02b8846 f68a3d68 f6b3854c f762fa40
Feb 12 20:27:22 sw1 kernel: [3273100.092221] Call Trace:
Feb 12 20:27:22 sw1 kernel: [3273100.092221] [<c01344f6>]
ktime_get+0xd/0x21
Feb 12 20:27:22 sw1 kernel: [3273100.092221] [<c01190e6>]
hrtick_start_fair+0xeb/0x12c
Feb 12 20:27:22 sw1 kernel: [3273100.092221] [<c02b8846>]
__mutex_lock_slowpath+0x50/0x7b
Feb 12 20:27:22 sw1 kernel: [3273100.092221] [<c02b86dc>]
mutex_lock+0xa/0xb
Feb 12 20:27:22 sw1 kernel: [3273100.092274] [<c02a7ea9>]
unix_dgram_recvmsg+0x3e/0x245
Feb 12 20:27:22 sw1 kernel: [3273100.092328] [<c01318e9>]
autoremove_wake_function+0xd/0x2d
Feb 12 20:27:22 sw1 kernel: [3273100.092383] [<c015a05d>]
__rmqueue_smallest+0x83/0xe3
Feb 12 20:27:22 sw1 kernel: [3273100.092438] [<c024ef76>]
sock_recvmsg+0xde/0xf9
Feb 12 20:27:22 sw1 kernel: [3273100.092493] [<c01318dc>]
autoremove_wake_function+0x0/0x2d
Feb 12 20:27:22 sw1 kernel: [3273100.092551] [<c0117c67>]
kunmap_atomic+0x55/0x8a
Feb 12 20:27:22 sw1 kernel: [3273100.092601] [<c0117c79>]
kunmap_atomic+0x67/0x8a
Feb 12 20:27:22 sw1 kernel: [3273100.092653] [<c015ae91>]
get_page_from_freelist+0x34f/0x3e3
Feb 12 20:27:22 sw1 kernel: [3273100.092712] [<c024fd9a>]
sys_recvfrom+0xb4/0x116
Feb 12 20:27:22 sw1 kernel: [3273100.092764] [<c015b0fb>]
__alloc_pages_internal+0xb5/0x34e
Feb 12 20:27:22 sw1 kernel: [3273100.092822] [<c0163cd3>]
handle_mm_fault+0x257/0x690
Feb 12 20:27:22 sw1 kernel: [3273100.092881] [<c025024d>]
sys_socketcall+0x135/0x19e
Feb 12 20:27:22 sw1 kernel: [3273100.092937] [<c0103853>]
sysenter_past_esp+0x78/0xb1
Feb 12 20:27:22 sw1 kernel: [3273100.092991] [<c02b0000>]
acpi_pci_root_add+0x165/0x296
Feb 12 20:27:22 sw1 kernel: [3273100.093046] =======================
Feb 12 20:27:22 sw1 kernel: [3273100.093090] INFO: task kamailio:22821
blocked for more than 120 seconds.
Feb 12 20:27:22 sw1 kernel: [3273100.093146] "echo 0 >
/proc/sys/kernel/hung_task_timeout_secs" disables this message.
Feb 12 20:27:22 sw1 kernel: [3273100.093230] kamailio D 8543066c
0 22821 22803
Feb 12 20:27:22 sw1 kernel: [3273100.110119] f762ede0 00000082
2603ada4 8543066c 000767a5 f762ef6c c3017fa0 00000000
Feb 12 20:27:22 sw1 kernel: [3273100.110201] c01344f6 001fcdbd
00000002 00000000 c01190e6 f762ede0 f762ede0 c02c4dc0
Feb 12 20:27:22 sw1 kernel: [3273100.110312] f6b38544 f6b3854c
f6b38548 f762ede0 c02b8846 f6b3854c f6bfdd68 f762ede0
Feb 12 20:27:22 sw1 kernel: [3273100.110422] Call Trace:
Feb 12 20:27:22 sw1 kernel: [3273100.110493] [<c01344f6>]
ktime_get+0xd/0x21
Feb 12 20:27:22 sw1 kernel: [3273100.110543] [<c01190e6>]
hrtick_start_fair+0xeb/0x12c
Feb 12 20:27:22 sw1 kernel: [3273100.110598] [<c02b8846>]
__mutex_lock_slowpath+0x50/0x7b
Feb 12 20:27:22 sw1 kernel: [3273100.110653] [<c02b86dc>]
mutex_lock+0xa/0xb
Feb 12 20:27:22 sw1 kernel: [3273100.110702] [<c02a7ea9>]
unix_dgram_recvmsg+0x3e/0x245
Feb 12 20:27:22 sw1 kernel: [3273100.110755] [<c01318e9>]
autoremove_wake_function+0xd/0x2d
Feb 12 20:27:22 sw1 kernel: [3273100.110810] [<c011845d>]
__wake_up_common+0x2e/0x58
Feb 12 20:27:22 sw1 kernel: [3273100.110864] [<c024ef76>]
sock_recvmsg+0xde/0xf9
Feb 12 20:27:22 sw1 kernel: [3273100.110919] [<c01318dc>]
autoremove_wake_function+0x0/0x2d
Feb 12 20:27:22 sw1 kernel: [3273100.110976] [<c0117c67>]
kunmap_atomic+0x55/0x8a
Feb 12 20:27:22 sw1 kernel: [3273100.111027] [<c0117c79>]
kunmap_atomic+0x67/0x8a
Feb 12 20:27:22 sw1 kernel: [3273100.111079] [<c015ae91>]
get_page_from_freelist+0x34f/0x3e3
Feb 12 20:27:22 sw1 kernel: [3273100.111138] [<c024fd9a>]
sys_recvfrom+0xb4/0x116
Feb 12 20:27:22 sw1 kernel: [3273100.111189] [<c015b0fb>]
__alloc_pages_internal+0xb5/0x34e
Feb 12 20:27:22 sw1 kernel: [3273100.111248] [<c0163cd3>]
handle_mm_fault+0x257/0x690
Feb 12 20:27:22 sw1 kernel: [3273100.111307] [<c025024d>]
sys_socketcall+0x135/0x19e
Feb 12 20:27:22 sw1 kernel: [3273100.111362] [<c0103853>]
sysenter_past_esp+0x78/0xb1
Feb 12 20:27:22 sw1 kernel: [3273100.111417] [<c02b0000>]
acpi_pci_root_add+0x165/0x296
Feb 12 20:27:22 sw1 kernel: [3273100.111471] =======================
------------------------------------------------------------------------
_______________________________________________
Kamailio (OpenSER) - Users mailing list
Users(a)lists.kamailio.org
http://lists.kamailio.org/cgi-bin/mailman/listinfo/users
http://lists.openser-project.org/cgi-bin/mailman/listinfo/users
--
Daniel-Constantin Mierla
http://www.asipto.com
10:44 p.m.
Daniel-Constantin Mierla wrote:
kamctl ps
Hey, that's pretty neat. Didn't know about that.
So, when you add "children" in the config, are these additional SIP
worker threads, or something else, or some combination?
--
Alex Balashov
Evariste Systems
Web : http://www.evaristesys.com/
Tel : (+1) (678) 954-0670
Direct : (+1) (678) 954-0671
Mobile : (+1) (678) 237-1775
10:50 p.m.
Hello Alex,
On 02/12/2009 10:44 PM, Alex Balashov wrote:
Daniel-Constantin Mierla wrote:
another hint, try this one:
kamctl fifo which
Did you know about it :-) ?
kamctl ps
Hey, that's pretty neat. Didn't know about that.
So, when you add "children" in the config,
are these additional SIP
worker threads, or something else, or some combination?
here is the output of my kamailio running with children=2
Process:: ID=0 PID=24128 Type=attendant
Process:: ID=1 PID=24129 Type=SIP receiver udp:192.168.1.23:5060
Process:: ID=2 PID=24130 Type=SIP receiver udp:192.168.1.23:5060
Process:: ID=3 PID=24131 Type=timer
Process:: ID=4 PID=24132 Type=MI FIFO
Process:: ID=5 PID=24133 Type=TCP receiver
Process:: ID=6 PID=24134 Type=TCP receiver
Process:: ID=7 PID=24135 Type=TCP main
The receivers are reflected by the children value, and they are the sip
workers. You can have different TCP children number using tcp_children
in config file.
Cheers,
Daniel
--
Daniel-Constantin Mierla
http://www.asipto.com
11 p.m.
Hi Daniel
Process:: ID=0 PID=22803 Type=attendant
Process:: ID=1 PID=22804 Type=SIP receiver udp:x.x.x.x:5060
Process:: ID=2 PID=22805 Type=SIP receiver udp:x.x.x.x:5060
Process:: ID=3 PID=22806 Type=SIP receiver udp:x.x.x.x:5060
Process:: ID=4 PID=22807 Type=SIP receiver udp:x.x.x.x:5060
Process:: ID=5 PID=22808 Type=SIP receiver udp:x.x.x.x:5060
Process:: ID=6 PID=22809 Type=SIP receiver udp:x.x.x.x:5060
Process:: ID=7 PID=22810 Type=SIP receiver udp:x.x.x.x:5060
Process:: ID=8 PID=22811 Type=SIP receiver udp:x.x.x.x:5060
Process:: ID=9 PID=22812 Type=SIP receiver udp:x.x.x.x:5060
Process:: ID=10 PID=22813 Type=SIP receiver udp:x.x.x.x:5060
Process:: ID=11 PID=22814 Type=timer
Process:: ID=12 PID=22816 Type=MI Datagram
Process:: ID=13 PID=22820 Type=MI Datagram
Process:: ID=14 PID=22821 Type=MI Datagram
Process:: ID=15 PID=22824 Type=MI FIFO
Thanks,
Brian
On 12 Feb 2009, at 20:40, Daniel-Constantin Mierla wrote:
Hello,
yes, there is something to worry until you discovered the cause and
might be something not to worry :-) ...
can you get the type of that process? Do:
kamctl ps
and you will see the list of kamailio processes. If it is a SIP
worker, then either is a dns block, tcp block (looks like due to
timeout) or lock block.
Cheers,
Daniel
On 02/12/2009 10:29 PM, Brian Chamberlain wrote:
Hi All,
Is this something I should worry about?
Feb 12 20:27:22 sw1 kernel: [3273100.087148] INFO: task kamailio:
1845 blocked for more than 120 seconds.
Feb 12 20:27:22 sw1 kernel: [3273100.087206] "echo 0 > /proc/sys/
kernel/hung_task_timeout_secs" disables this message.
Feb 12 20:27:22 sw1 kernel: [3273100.087291] kamailio D
8ce9265a 0 1845 1829
Feb 12 20:27:22 sw1 kernel: [3273100.087346] f6a98da0
00000082 23f7e426 8ce9265a 000701ae f6a98f2c c302bfa0 00000002
Feb 12 20:27:22 sw1 kernel: [3273100.087427] c01344f6
001e17ce 00000001 00000000 c01190e6 f6a98da0 f6a98da0 c02c4dc0
Feb 12 20:27:22 sw1 kernel: [3273100.087538] f74eea84
f74eea8c f74eea88 f6a98da0 c02b8846 f68c3d68 f74eea8c f6a98da0
Feb 12 20:27:22 sw1 kernel: [3273100.087648] Call Trace:
Feb 12 20:27:22 sw1 kernel: [3273100.087730] [<c01344f6>] ktime_get
+0xd/0x21
Feb 12 20:27:22 sw1 kernel: [3273100.087784] [<c01190e6>]
hrtick_start_fair+0xeb/0x12c
Feb 12 20:27:22 sw1 kernel: [3273100.087840] [<c02b8846>]
__mutex_lock_slowpath+0x50/0x7b
Feb 12 20:27:22 sw1 kernel: [3273100.087896] [<c02b86dc>]
mutex_lock+0xa/0xb
Feb 12 20:27:22 sw1 kernel: [3273100.087945] [<c02a7ea9>]
unix_dgram_recvmsg+0x3e/0x245
Feb 12 20:27:22 sw1 kernel: [3273100.087998] [<c01318e9>]
autoremove_wake_function+0xd/0x2d
Feb 12 20:27:22 sw1 kernel: [3273100.088055] [<c011845d>]
__wake_up_common+0x2e/0x58
Feb 12 20:27:22 sw1 kernel: [3273100.088109] [<c024ef76>]
sock_recvmsg+0xde/0xf9
Feb 12 20:27:22 sw1 kernel: [3273100.088165] [<c01318dc>]
autoremove_wake_function+0x0/0x2d
Feb 12 20:27:22 sw1 kernel: [3273100.088223] [<c0117c67>]
kunmap_atomic+0x55/0x8a
Feb 12 20:27:22 sw1 kernel: [3273100.088273] [<c0117c79>]
kunmap_atomic+0x67/0x8a
Feb 12 20:27:22 sw1 kernel: [3273100.088327] [<c015ae91>]
get_page_from_freelist+0x34f/0x3e3
Feb 12 20:27:22 sw1 kernel: [3273100.088387] [<c024fd9a>]
sys_recvfrom+0xb4/0x116
Feb 12 20:27:22 sw1 kernel: [3273100.088438] [<c015b0fb>]
__alloc_pages_internal+0xb5/0x34e
Feb 12 20:27:22 sw1 kernel: [3273100.088497] [<c0163cd3>]
handle_mm_fault+0x257/0x690
Feb 12 20:27:22 sw1 kernel: [3273100.088554] [<c025024d>]
sys_socketcall+0x135/0x19e
Feb 12 20:27:22 sw1 kernel: [3273100.088610] [<c0103853>]
sysenter_past_esp+0x78/0xb1
Feb 12 20:27:22 sw1 kernel: [3273100.091119] [<c02b0000>]
acpi_pci_root_add+0x165/0x296
Feb 12 20:27:22 sw1 kernel: [3273100.091174] =======================
Feb 12 20:27:22 sw1 kernel: [3273100.091218] INFO: task kamailio:
1846 blocked for more than 120 seconds.
Feb 12 20:27:22 sw1 kernel: [3273100.091274] "echo 0 > /proc/sys/
kernel/hung_task_timeout_secs" disables this message.
Feb 12 20:27:22 sw1 kernel: [3273100.091358] kamailio D
00000002 0 1846 1829
Feb 12 20:27:22 sw1 kernel: [3273100.091413] f6a995e0
00000086 00000000 00000002 00000000 f6a9976c c3017fa0 00000000
Feb 12 20:27:22 sw1 kernel: [3273100.091495] ffffffff
1d621a39 00000000 00000000 00000000 00000000 00000000 000000ff
Feb 12 20:27:22 sw1 kernel: [3273100.091605] f74eea84
f74eea8c f74eea88 f6a995e0 c02b8846 f74eea8c f6b21d68 f6a995e0
Feb 12 20:27:22 sw1 kernel: [3273100.091715] Call Trace:
Feb 12 20:27:22 sw1 kernel: [3273100.091790] [<c02b8846>]
__mutex_lock_slowpath+0x50/0x7b
Feb 12 20:27:22 sw1 kernel: [3273100.091847] [<c02b86dc>]
mutex_lock+0xa/0xb
Feb 12 20:27:22 sw1 kernel: [3273100.091895] [<c02a7ea9>]
unix_dgram_recvmsg+0x3e/0x245
Feb 12 20:27:22 sw1 kernel: [3273100.091949] [<c0129ab0>]
lock_timer_base+0x19/0x35
Feb 12 20:27:22 sw1 kernel: [3273100.092002] [<c0129b10>]
try_to_del_timer_sync+0x44/0x4a
Feb 12 20:27:22 sw1 kernel: [3273100.092057] [<c024ef76>]
sock_recvmsg+0xde/0xf9
Feb 12 20:27:22 sw1 kernel: [3273100.092108] [<c01297ec>]
process_timeout+0x0/0x5
Feb 12 20:27:22 sw1 kernel: [3273100.092163] [<c01318dc>]
autoremove_wake_function+0x0/0x2d
Feb 12 20:27:22 sw1 kernel: [3273100.092219] [<c015a0d0>] __rmqueue
+0x13/0x174
Feb 12 20:27:22 sw1 kernel: [3273100.092221] [<c0117c67>]
kunmap_atomic+0x55/0x8a
Feb 12 20:27:22 sw1 kernel: [3273100.092221] [<c0117c79>]
kunmap_atomic+0x67/0x8a
Feb 12 20:27:22 sw1 kernel: [3273100.092221] [<c015ae91>]
get_page_from_freelist+0x34f/0x3e3
Feb 12 20:27:22 sw1 kernel: [3273100.092221] [<c024fd9a>]
sys_recvfrom+0xb4/0x116
Feb 12 20:27:22 sw1 kernel: [3273100.092221] [<c015b0fb>]
__alloc_pages_internal+0xb5/0x34e
Feb 12 20:27:22 sw1 kernel: [3273100.092221] [<c0163cd3>]
handle_mm_fault+0x257/0x690
Feb 12 20:27:22 sw1 kernel: [3273100.092221] [<c025024d>]
sys_socketcall+0x135/0x19e
Feb 12 20:27:22 sw1 kernel: [3273100.092221] [<c0103853>]
sysenter_past_esp+0x78/0xb1
Feb 12 20:27:22 sw1 kernel: [3273100.092221] [<c02b0000>]
acpi_pci_root_add+0x165/0x296
Feb 12 20:27:22 sw1 kernel: [3273100.092221] =======================
Feb 12 20:27:22 sw1 kernel: [3273100.092221] INFO: task kamailio:
22820 blocked for more than 120 seconds.
Feb 12 20:27:22 sw1 kernel: [3273100.092221] "echo 0 > /proc/sys/
kernel/hung_task_timeout_secs" disables this message.
Feb 12 20:27:22 sw1 kernel: [3273100.092221] kamailio D
854aa937 0 22820 22803
Feb 12 20:27:22 sw1 kernel: [3273100.092221] f762fa40
00000086 2603ada4 854aa937 000767a5 f762fbcc c3021fa0 00000001
Feb 12 20:27:22 sw1 kernel: [3273100.092221] c01344f6
001fcdbd 00000001 00000000 c01190e6 f762fa40 f762fa40 c02c4dc0
Feb 12 20:27:22 sw1 kernel: [3273100.092221] f6b38544
f6b3854c f6b38548 f762fa40 c02b8846 f68a3d68 f6b3854c f762fa40
Feb 12 20:27:22 sw1 kernel: [3273100.092221] Call Trace:
Feb 12 20:27:22 sw1 kernel: [3273100.092221] [<c01344f6>] ktime_get
+0xd/0x21
Feb 12 20:27:22 sw1 kernel: [3273100.092221] [<c01190e6>]
hrtick_start_fair+0xeb/0x12c
Feb 12 20:27:22 sw1 kernel: [3273100.092221] [<c02b8846>]
__mutex_lock_slowpath+0x50/0x7b
Feb 12 20:27:22 sw1 kernel: [3273100.092221] [<c02b86dc>]
mutex_lock+0xa/0xb
Feb 12 20:27:22 sw1 kernel: [3273100.092274] [<c02a7ea9>]
unix_dgram_recvmsg+0x3e/0x245
Feb 12 20:27:22 sw1 kernel: [3273100.092328] [<c01318e9>]
autoremove_wake_function+0xd/0x2d
Feb 12 20:27:22 sw1 kernel: [3273100.092383] [<c015a05d>]
__rmqueue_smallest+0x83/0xe3
Feb 12 20:27:22 sw1 kernel: [3273100.092438] [<c024ef76>]
sock_recvmsg+0xde/0xf9
Feb 12 20:27:22 sw1 kernel: [3273100.092493] [<c01318dc>]
autoremove_wake_function+0x0/0x2d
Feb 12 20:27:22 sw1 kernel: [3273100.092551] [<c0117c67>]
kunmap_atomic+0x55/0x8a
Feb 12 20:27:22 sw1 kernel: [3273100.092601] [<c0117c79>]
kunmap_atomic+0x67/0x8a
Feb 12 20:27:22 sw1 kernel: [3273100.092653] [<c015ae91>]
get_page_from_freelist+0x34f/0x3e3
Feb 12 20:27:22 sw1 kernel: [3273100.092712] [<c024fd9a>]
sys_recvfrom+0xb4/0x116
Feb 12 20:27:22 sw1 kernel: [3273100.092764] [<c015b0fb>]
__alloc_pages_internal+0xb5/0x34e
Feb 12 20:27:22 sw1 kernel: [3273100.092822] [<c0163cd3>]
handle_mm_fault+0x257/0x690
Feb 12 20:27:22 sw1 kernel: [3273100.092881] [<c025024d>]
sys_socketcall+0x135/0x19e
Feb 12 20:27:22 sw1 kernel: [3273100.092937] [<c0103853>]
sysenter_past_esp+0x78/0xb1
Feb 12 20:27:22 sw1 kernel: [3273100.092991] [<c02b0000>]
acpi_pci_root_add+0x165/0x296
Feb 12 20:27:22 sw1 kernel: [3273100.093046] =======================
Feb 12 20:27:22 sw1 kernel: [3273100.093090] INFO: task kamailio:
22821 blocked for more than 120 seconds.
Feb 12 20:27:22 sw1 kernel: [3273100.093146] "echo 0 > /proc/sys/
kernel/hung_task_timeout_secs" disables this message.
Feb 12 20:27:22 sw1 kernel: [3273100.093230] kamailio D
8543066c 0 22821 22803
Feb 12 20:27:22 sw1 kernel: [3273100.110119] f762ede0
00000082 2603ada4 8543066c 000767a5 f762ef6c c3017fa0 00000000
Feb 12 20:27:22 sw1 kernel: [3273100.110201] c01344f6
001fcdbd 00000002 00000000 c01190e6 f762ede0 f762ede0 c02c4dc0
Feb 12 20:27:22 sw1 kernel: [3273100.110312] f6b38544
f6b3854c f6b38548 f762ede0 c02b8846 f6b3854c f6bfdd68 f762ede0
Feb 12 20:27:22 sw1 kernel: [3273100.110422] Call Trace:
Feb 12 20:27:22 sw1 kernel: [3273100.110493] [<c01344f6>] ktime_get
+0xd/0x21
Feb 12 20:27:22 sw1 kernel: [3273100.110543] [<c01190e6>]
hrtick_start_fair+0xeb/0x12c
Feb 12 20:27:22 sw1 kernel: [3273100.110598] [<c02b8846>]
__mutex_lock_slowpath+0x50/0x7b
Feb 12 20:27:22 sw1 kernel: [3273100.110653] [<c02b86dc>]
mutex_lock+0xa/0xb
Feb 12 20:27:22 sw1 kernel: [3273100.110702] [<c02a7ea9>]
unix_dgram_recvmsg+0x3e/0x245
Feb 12 20:27:22 sw1 kernel: [3273100.110755] [<c01318e9>]
autoremove_wake_function+0xd/0x2d
Feb 12 20:27:22 sw1 kernel: [3273100.110810] [<c011845d>]
__wake_up_common+0x2e/0x58
Feb 12 20:27:22 sw1 kernel: [3273100.110864] [<c024ef76>]
sock_recvmsg+0xde/0xf9
Feb 12 20:27:22 sw1 kernel: [3273100.110919] [<c01318dc>]
autoremove_wake_function+0x0/0x2d
Feb 12 20:27:22 sw1 kernel: [3273100.110976] [<c0117c67>]
kunmap_atomic+0x55/0x8a
Feb 12 20:27:22 sw1 kernel: [3273100.111027] [<c0117c79>]
kunmap_atomic+0x67/0x8a
Feb 12 20:27:22 sw1 kernel: [3273100.111079] [<c015ae91>]
get_page_from_freelist+0x34f/0x3e3
Feb 12 20:27:22 sw1 kernel: [3273100.111138] [<c024fd9a>]
sys_recvfrom+0xb4/0x116
Feb 12 20:27:22 sw1 kernel: [3273100.111189] [<c015b0fb>]
__alloc_pages_internal+0xb5/0x34e
Feb 12 20:27:22 sw1 kernel: [3273100.111248] [<c0163cd3>]
handle_mm_fault+0x257/0x690
Feb 12 20:27:22 sw1 kernel: [3273100.111307] [<c025024d>]
sys_socketcall+0x135/0x19e
Feb 12 20:27:22 sw1 kernel: [3273100.111362] [<c0103853>]
sysenter_past_esp+0x78/0xb1
Feb 12 20:27:22 sw1 kernel: [3273100.111417] [<c02b0000>]
acpi_pci_root_add+0x165/0x296
Feb 12 20:27:22 sw1 kernel: [3273100.111471] =======================
------------------------------------------------------------------------
_______________________________________________
Kamailio (OpenSER) - Users mailing list
Users(a)lists.kamailio.org
http://lists.kamailio.org/cgi-bin/mailman/listinfo/users
http://lists.openser-project.org/cgi-bin/mailman/listinfo/users
--
Daniel-Constantin Mierla
http://www.asipto.com
11:04 p.m.
Hello,
correlating messages:
Feb 12 20:27:22 sw1 kernel: [3273100.093090] INFO: task kamailio:22821
blocked for more than 120 seconds.
and
Process:: ID=14 PID=22821 Type=MI Datagram
seems that one of your MI datagram was blocked for some time. Are you
using MI datagram commands often? What are they?
Cheers,
Daniel
On 02/12/2009 11:00 PM, Brian Chamberlain wrote:
Hi Daniel
Process:: ID=0 PID=22803 Type=attendant
Process:: ID=1 PID=22804 Type=SIP receiver udp:x.x.x.x:5060
Process:: ID=2 PID=22805 Type=SIP receiver udp:x.x.x.x:5060
Process:: ID=3 PID=22806 Type=SIP receiver udp:x.x.x.x:5060
Process:: ID=4 PID=22807 Type=SIP receiver udp:x.x.x.x:5060
Process:: ID=5 PID=22808 Type=SIP receiver udp:x.x.x.x:5060
Process:: ID=6 PID=22809 Type=SIP receiver udp:x.x.x.x:5060
Process:: ID=7 PID=22810 Type=SIP receiver udp:x.x.x.x:5060
Process:: ID=8 PID=22811 Type=SIP receiver udp:x.x.x.x:5060
Process:: ID=9 PID=22812 Type=SIP receiver udp:x.x.x.x:5060
Process:: ID=10 PID=22813 Type=SIP receiver udp:x.x.x.x:5060
Process:: ID=11 PID=22814 Type=timer
Process:: ID=12 PID=22816 Type=MI Datagram
Process:: ID=13 PID=22820 Type=MI Datagram
Process:: ID=14 PID=22821 Type=MI Datagram
Process:: ID=15 PID=22824 Type=MI FIFO
Thanks,
Brian
On 12 Feb 2009, at 20:40, Daniel-Constantin Mierla wrote:
--
Daniel-Constantin Mierla
http://www.asipto.com
Hello,
yes, there is something to worry until you discovered the cause and
might be something not to worry :-) ...
can you get the type of that process? Do:
kamctl ps
and you will see the list of kamailio processes. If it is a SIP
worker, then either is a dns block, tcp block (looks like due to
timeout) or lock block.
Cheers,
Daniel
On 02/12/2009 10:29 PM, Brian Chamberlain wrote:
Hi All,
Is this something I should worry about?
Feb 12 20:27:22 sw1 kernel: [3273100.087148] INFO: task
kamailio:1845 blocked for more than 120 seconds.
Feb 12 20:27:22 sw1 kernel: [3273100.087206] "echo 0 >
/proc/sys/kernel/hung_task_timeout_secs" disables this message.
Feb 12 20:27:22 sw1 kernel: [3273100.087291] kamailio D
8ce9265a 0 1845 1829
Feb 12 20:27:22 sw1 kernel: [3273100.087346] f6a98da0
00000082 23f7e426 8ce9265a 000701ae f6a98f2c c302bfa0 00000002
Feb 12 20:27:22 sw1 kernel: [3273100.087427] c01344f6
001e17ce 00000001 00000000 c01190e6 f6a98da0 f6a98da0 c02c4dc0
Feb 12 20:27:22 sw1 kernel: [3273100.087538] f74eea84
f74eea8c f74eea88 f6a98da0 c02b8846 f68c3d68 f74eea8c f6a98da0
Feb 12 20:27:22 sw1 kernel: [3273100.087648] Call Trace:
Feb 12 20:27:22 sw1 kernel: [3273100.087730] [<c01344f6>]
ktime_get+0xd/0x21
Feb 12 20:27:22 sw1 kernel: [3273100.087784] [<c01190e6>]
hrtick_start_fair+0xeb/0x12c
Feb 12 20:27:22 sw1 kernel: [3273100.087840] [<c02b8846>]
__mutex_lock_slowpath+0x50/0x7b
Feb 12 20:27:22 sw1 kernel: [3273100.087896] [<c02b86dc>]
mutex_lock+0xa/0xb
Feb 12 20:27:22 sw1 kernel: [3273100.087945] [<c02a7ea9>]
unix_dgram_recvmsg+0x3e/0x245
Feb 12 20:27:22 sw1 kernel: [3273100.087998] [<c01318e9>]
autoremove_wake_function+0xd/0x2d
Feb 12 20:27:22 sw1 kernel: [3273100.088055] [<c011845d>]
__wake_up_common+0x2e/0x58
Feb 12 20:27:22 sw1 kernel: [3273100.088109] [<c024ef76>]
sock_recvmsg+0xde/0xf9
Feb 12 20:27:22 sw1 kernel: [3273100.088165] [<c01318dc>]
autoremove_wake_function+0x0/0x2d
Feb 12 20:27:22 sw1 kernel: [3273100.088223] [<c0117c67>]
kunmap_atomic+0x55/0x8a
Feb 12 20:27:22 sw1 kernel: [3273100.088273] [<c0117c79>]
kunmap_atomic+0x67/0x8a
Feb 12 20:27:22 sw1 kernel: [3273100.088327] [<c015ae91>]
get_page_from_freelist+0x34f/0x3e3
Feb 12 20:27:22 sw1 kernel: [3273100.088387] [<c024fd9a>]
sys_recvfrom+0xb4/0x116
Feb 12 20:27:22 sw1 kernel: [3273100.088438] [<c015b0fb>]
__alloc_pages_internal+0xb5/0x34e
Feb 12 20:27:22 sw1 kernel: [3273100.088497] [<c0163cd3>]
handle_mm_fault+0x257/0x690
Feb 12 20:27:22 sw1 kernel: [3273100.088554] [<c025024d>]
sys_socketcall+0x135/0x19e
Feb 12 20:27:22 sw1 kernel: [3273100.088610] [<c0103853>]
sysenter_past_esp+0x78/0xb1
Feb 12 20:27:22 sw1 kernel: [3273100.091119] [<c02b0000>]
acpi_pci_root_add+0x165/0x296
Feb 12 20:27:22 sw1 kernel: [3273100.091174] =======================
Feb 12 20:27:22 sw1 kernel: [3273100.091218] INFO: task
kamailio:1846 blocked for more than 120 seconds.
Feb 12 20:27:22 sw1 kernel: [3273100.091274] "echo 0 >
/proc/sys/kernel/hung_task_timeout_secs" disables this message.
Feb 12 20:27:22 sw1 kernel: [3273100.091358] kamailio D
00000002 0 1846 1829
Feb 12 20:27:22 sw1 kernel: [3273100.091413] f6a995e0
00000086 00000000 00000002 00000000 f6a9976c c3017fa0 00000000
Feb 12 20:27:22 sw1 kernel: [3273100.091495] ffffffff
1d621a39 00000000 00000000 00000000 00000000 00000000 000000ff
Feb 12 20:27:22 sw1 kernel: [3273100.091605] f74eea84
f74eea8c f74eea88 f6a995e0 c02b8846 f74eea8c f6b21d68 f6a995e0
Feb 12 20:27:22 sw1 kernel: [3273100.091715] Call Trace:
Feb 12 20:27:22 sw1 kernel: [3273100.091790] [<c02b8846>]
__mutex_lock_slowpath+0x50/0x7b
Feb 12 20:27:22 sw1 kernel: [3273100.091847] [<c02b86dc>]
mutex_lock+0xa/0xb
Feb 12 20:27:22 sw1 kernel: [3273100.091895] [<c02a7ea9>]
unix_dgram_recvmsg+0x3e/0x245
Feb 12 20:27:22 sw1 kernel: [3273100.091949] [<c0129ab0>]
lock_timer_base+0x19/0x35
Feb 12 20:27:22 sw1 kernel: [3273100.092002] [<c0129b10>]
try_to_del_timer_sync+0x44/0x4a
Feb 12 20:27:22 sw1 kernel: [3273100.092057] [<c024ef76>]
sock_recvmsg+0xde/0xf9
Feb 12 20:27:22 sw1 kernel: [3273100.092108] [<c01297ec>]
process_timeout+0x0/0x5
Feb 12 20:27:22 sw1 kernel: [3273100.092163] [<c01318dc>]
autoremove_wake_function+0x0/0x2d
Feb 12 20:27:22 sw1 kernel: [3273100.092219] [<c015a0d0>]
__rmqueue+0x13/0x174
Feb 12 20:27:22 sw1 kernel: [3273100.092221] [<c0117c67>]
kunmap_atomic+0x55/0x8a
Feb 12 20:27:22 sw1 kernel: [3273100.092221] [<c0117c79>]
kunmap_atomic+0x67/0x8a
Feb 12 20:27:22 sw1 kernel: [3273100.092221] [<c015ae91>]
get_page_from_freelist+0x34f/0x3e3
Feb 12 20:27:22 sw1 kernel: [3273100.092221] [<c024fd9a>]
sys_recvfrom+0xb4/0x116
Feb 12 20:27:22 sw1 kernel: [3273100.092221] [<c015b0fb>]
__alloc_pages_internal+0xb5/0x34e
Feb 12 20:27:22 sw1 kernel: [3273100.092221] [<c0163cd3>]
handle_mm_fault+0x257/0x690
Feb 12 20:27:22 sw1 kernel: [3273100.092221] [<c025024d>]
sys_socketcall+0x135/0x19e
Feb 12 20:27:22 sw1 kernel: [3273100.092221] [<c0103853>]
sysenter_past_esp+0x78/0xb1
Feb 12 20:27:22 sw1 kernel: [3273100.092221] [<c02b0000>]
acpi_pci_root_add+0x165/0x296
Feb 12 20:27:22 sw1 kernel: [3273100.092221] =======================
Feb 12 20:27:22 sw1 kernel: [3273100.092221] INFO: task
kamailio:22820 blocked for more than 120 seconds.
Feb 12 20:27:22 sw1 kernel: [3273100.092221] "echo 0 >
/proc/sys/kernel/hung_task_timeout_secs" disables this message.
Feb 12 20:27:22 sw1 kernel: [3273100.092221] kamailio D
854aa937 0 22820 22803
Feb 12 20:27:22 sw1 kernel: [3273100.092221] f762fa40
00000086 2603ada4 854aa937 000767a5 f762fbcc c3021fa0 00000001
Feb 12 20:27:22 sw1 kernel: [3273100.092221] c01344f6
001fcdbd 00000001 00000000 c01190e6 f762fa40 f762fa40 c02c4dc0
Feb 12 20:27:22 sw1 kernel: [3273100.092221] f6b38544
f6b3854c f6b38548 f762fa40 c02b8846 f68a3d68 f6b3854c f762fa40
Feb 12 20:27:22 sw1 kernel: [3273100.092221] Call Trace:
Feb 12 20:27:22 sw1 kernel: [3273100.092221] [<c01344f6>]
ktime_get+0xd/0x21
Feb 12 20:27:22 sw1 kernel: [3273100.092221] [<c01190e6>]
hrtick_start_fair+0xeb/0x12c
Feb 12 20:27:22 sw1 kernel: [3273100.092221] [<c02b8846>]
__mutex_lock_slowpath+0x50/0x7b
Feb 12 20:27:22 sw1 kernel: [3273100.092221] [<c02b86dc>]
mutex_lock+0xa/0xb
Feb 12 20:27:22 sw1 kernel: [3273100.092274] [<c02a7ea9>]
unix_dgram_recvmsg+0x3e/0x245
Feb 12 20:27:22 sw1 kernel: [3273100.092328] [<c01318e9>]
autoremove_wake_function+0xd/0x2d
Feb 12 20:27:22 sw1 kernel: [3273100.092383] [<c015a05d>]
__rmqueue_smallest+0x83/0xe3
Feb 12 20:27:22 sw1 kernel: [3273100.092438] [<c024ef76>]
sock_recvmsg+0xde/0xf9
Feb 12 20:27:22 sw1 kernel: [3273100.092493] [<c01318dc>]
autoremove_wake_function+0x0/0x2d
Feb 12 20:27:22 sw1 kernel: [3273100.092551] [<c0117c67>]
kunmap_atomic+0x55/0x8a
Feb 12 20:27:22 sw1 kernel: [3273100.092601] [<c0117c79>]
kunmap_atomic+0x67/0x8a
Feb 12 20:27:22 sw1 kernel: [3273100.092653] [<c015ae91>]
get_page_from_freelist+0x34f/0x3e3
Feb 12 20:27:22 sw1 kernel: [3273100.092712] [<c024fd9a>]
sys_recvfrom+0xb4/0x116
Feb 12 20:27:22 sw1 kernel: [3273100.092764] [<c015b0fb>]
__alloc_pages_internal+0xb5/0x34e
Feb 12 20:27:22 sw1 kernel: [3273100.092822] [<c0163cd3>]
handle_mm_fault+0x257/0x690
Feb 12 20:27:22 sw1 kernel: [3273100.092881] [<c025024d>]
sys_socketcall+0x135/0x19e
Feb 12 20:27:22 sw1 kernel: [3273100.092937] [<c0103853>]
sysenter_past_esp+0x78/0xb1
Feb 12 20:27:22 sw1 kernel: [3273100.092991] [<c02b0000>]
acpi_pci_root_add+0x165/0x296
Feb 12 20:27:22 sw1 kernel: [3273100.093046] =======================
Feb 12 20:27:22 sw1 kernel: [3273100.093090] INFO: task
kamailio:22821 blocked for more than 120 seconds.
Feb 12 20:27:22 sw1 kernel: [3273100.093146] "echo 0 >
/proc/sys/kernel/hung_task_timeout_secs" disables this message.
Feb 12 20:27:22 sw1 kernel: [3273100.093230] kamailio D
8543066c 0 22821 22803
Feb 12 20:27:22 sw1 kernel: [3273100.110119] f762ede0
00000082 2603ada4 8543066c 000767a5 f762ef6c c3017fa0 00000000
Feb 12 20:27:22 sw1 kernel: [3273100.110201] c01344f6
001fcdbd 00000002 00000000 c01190e6 f762ede0 f762ede0 c02c4dc0
Feb 12 20:27:22 sw1 kernel: [3273100.110312] f6b38544
f6b3854c f6b38548 f762ede0 c02b8846 f6b3854c f6bfdd68 f762ede0
Feb 12 20:27:22 sw1 kernel: [3273100.110422] Call Trace:
Feb 12 20:27:22 sw1 kernel: [3273100.110493] [<c01344f6>]
ktime_get+0xd/0x21
Feb 12 20:27:22 sw1 kernel: [3273100.110543] [<c01190e6>]
hrtick_start_fair+0xeb/0x12c
Feb 12 20:27:22 sw1 kernel: [3273100.110598] [<c02b8846>]
__mutex_lock_slowpath+0x50/0x7b
Feb 12 20:27:22 sw1 kernel: [3273100.110653] [<c02b86dc>]
mutex_lock+0xa/0xb
Feb 12 20:27:22 sw1 kernel: [3273100.110702] [<c02a7ea9>]
unix_dgram_recvmsg+0x3e/0x245
Feb 12 20:27:22 sw1 kernel: [3273100.110755] [<c01318e9>]
autoremove_wake_function+0xd/0x2d
Feb 12 20:27:22 sw1 kernel: [3273100.110810] [<c011845d>]
__wake_up_common+0x2e/0x58
Feb 12 20:27:22 sw1 kernel: [3273100.110864] [<c024ef76>]
sock_recvmsg+0xde/0xf9
Feb 12 20:27:22 sw1 kernel: [3273100.110919] [<c01318dc>]
autoremove_wake_function+0x0/0x2d
Feb 12 20:27:22 sw1 kernel: [3273100.110976] [<c0117c67>]
kunmap_atomic+0x55/0x8a
Feb 12 20:27:22 sw1 kernel: [3273100.111027] [<c0117c79>]
kunmap_atomic+0x67/0x8a
Feb 12 20:27:22 sw1 kernel: [3273100.111079] [<c015ae91>]
get_page_from_freelist+0x34f/0x3e3
Feb 12 20:27:22 sw1 kernel: [3273100.111138] [<c024fd9a>]
sys_recvfrom+0xb4/0x116
Feb 12 20:27:22 sw1 kernel: [3273100.111189] [<c015b0fb>]
__alloc_pages_internal+0xb5/0x34e
Feb 12 20:27:22 sw1 kernel: [3273100.111248] [<c0163cd3>]
handle_mm_fault+0x257/0x690
Feb 12 20:27:22 sw1 kernel: [3273100.111307] [<c025024d>]
sys_socketcall+0x135/0x19e
Feb 12 20:27:22 sw1 kernel: [3273100.111362] [<c0103853>]
sysenter_past_esp+0x78/0xb1
Feb 12 20:27:22 sw1 kernel: [3273100.111417] [<c02b0000>]
acpi_pci_root_add+0x165/0x296
Feb 12 20:27:22 sw1 kernel: [3273100.111471] =======================
------------------------------------------------------------------------
_______________________________________________
Kamailio (OpenSER) - Users mailing list
Users(a)lists.kamailio.org
http://lists.kamailio.org/cgi-bin/mailman/listinfo/users
http://lists.openser-project.org/cgi-bin/mailman/listinfo/users
--
Daniel-Constantin Mierla
http://www.asipto.com
11:06 p.m.
Daniel-Constantin Mierla wrote:
Hello,
correlating messages:
Feb 12 20:27:22 sw1 kernel: [3273100.093090] INFO: task kamailio:22821
blocked for more than 120 seconds.
and
Process:: ID=14 PID=22821 Type=MI Datagram
seems that one of your MI datagram was blocked for some time. Are you
using MI datagram commands often? What are they?
Brian, I would guess CDRtool and its rating engine use a lot of MI
commands as part of its interface with the proxy. Daniel, can you
corroborate that?
--
Alex Balashov
Evariste Systems
Web : http://www.evaristesys.com/
Tel : (+1) (678) 954-0670
Direct : (+1) (678) 954-0671
Mobile : (+1) (678) 237-1775
11:09 p.m.
On 12 Feb 2009, at 21:06, Alex Balashov wrote:
Daniel-Constantin Mierla wrote:
I've been doing a lot of rerating today as it goes..
Hello,
correlating messages:
Feb 12 20:27:22 sw1 kernel: [3273100.093090] INFO: task kamailio:
22821 blocked for more than 120 seconds.
and
Process:: ID=14 PID=22821 Type=MI Datagram
seems that one of your MI datagram was blocked for some time. Are
you using MI datagram commands often? What are they?
Brian, I would guess CDRtool and its rating engine use a lot of MI
commands as part of its interface with the proxy. Daniel, can you
corroborate that?
11:11 p.m.
Brian Chamberlain wrote:
On 12 Feb 2009, at 21:06, Alex Balashov wrote:
I don't know that this results in a lot of MI commands. I think CDRtool
and its processes use a lot of MI for managing session timers and stuff
like that, or maybe that's Call Control. I'm not really familiar with
AG Projects' technology stack.
--
Alex Balashov
Evariste Systems
Web : http://www.evaristesys.com/
Tel : (+1) (678) 954-0670
Direct : (+1) (678) 954-0671
Mobile : (+1) (678) 237-1775
Daniel-Constantin Mierla wrote:
I've been doing a lot of rerating today as it goes.. Hello,
correlating messages:
Feb 12 20:27:22 sw1 kernel: [3273100.093090] INFO: task
kamailio:22821 blocked for more than 120 seconds.
and
Process:: ID=14 PID=22821 Type=MI Datagram
seems that one of your MI datagram was blocked for some time. Are you
using MI datagram commands often? What are they?
Brian, I would guess CDRtool and its rating engine use a lot of MI
commands as part of its interface with the proxy. Daniel, can you
corroborate that?
11:17 p.m.
On 02/12/2009 11:11 PM, Alex Balashov wrote:
Brian Chamberlain wrote:
OK, so we identified the source. Thanks a lot Alex!
Brian, you could sniff the UDP traffic for MI datagram, are you using
UDP sockets or unix sockets?
Anyhow, I wonder what the cdrtool would need for rating from kamailio...
so if you can get the commands send by cdrtool, I can tell you where is
the possible lock.
Cheers,
Daniel
--
Daniel-Constantin Mierla
http://www.asipto.com
On 12 Feb 2009, at 21:06, Alex Balashov wrote:
I don't know that this results in a lot of MI commands. I think CDRtool
and its processes use a lot of MI for managing session timers and stuff
like that, or maybe that's Call Control. I'm not really familiar with
AG Projects' technology stack.
Daniel-Constantin Mierla wrote:
I've been doing a lot of rerating today as it goes..
Hello,
correlating messages:
Feb 12 20:27:22 sw1 kernel: [3273100.093090] INFO: task
kamailio:22821 blocked for more than 120 seconds.
and
Process:: ID=14 PID=22821 Type=MI Datagram
seems that one of your MI datagram was blocked for some time. Are you
using MI datagram commands often? What are they?
Brian, I would guess CDRtool and its rating engine use a lot of MI
commands as part of its interface with the proxy. Daniel, can you
corroborate that?
11:23 p.m.
Daniel-Constantin Mierla wrote:
On 02/12/2009 11:11 PM, Alex Balashov wrote:
UNIX domain sockets. I am not aware of a good way to "sniff" those. Is
there one?
I suppose one could switch to UDP sockets...
Brian Chamberlain wrote:
OK, so we identified the source. Thanks a lot Alex!
Brian, you could sniff the UDP traffic for MI datagram, are you using
UDP sockets or unix sockets? On 12 Feb 2009, at 21:06, Alex Balashov wrote:
I don't know that this results in a lot of MI commands. I think
CDRtool and its processes use a lot of MI for managing session timers
and stuff like that, or maybe that's Call Control. I'm not really
familiar with AG Projects' technology stack.
Daniel-Constantin Mierla wrote:
> Hello,
> correlating messages:
> Feb 12 20:27:22 sw1 kernel: [3273100.093090] INFO: task
> kamailio:22821 blocked for more than 120 seconds.
> and
> Process:: ID=14 PID=22821 Type=MI Datagram
> seems that one of your MI datagram was blocked for some time. Are
> you using MI datagram commands often? What are they?
>
Brian, I would guess CDRtool and its rating engine use a lot of MI
commands as part of its interface with the proxy. Daniel, can you
corroborate that?
I've been doing a lot of rerating today as it goes..
Anyhow, I wonder what the cdrtool would need for
rating from kamailio...
so if you can get the commands send by cdrtool, I can tell you where is
the possible lock.
I do not know.
I've been trying to help Brian with this, but I just don't know enough
about the AG Projects end of things.
--
Alex Balashov
Evariste Systems
Web : http://www.evaristesys.com/
Tel : (+1) (678) 954-0670
Direct : (+1) (678) 954-0671
Mobile : (+1) (678) 237-1775
11:32 p.m.
On 02/12/2009 11:23 PM, Alex Balashov wrote:
Neither do I, but we can do reverse
engineering if you learn the
commands send.
The problem could become critical, if it blocks access to some
hash/location in memory for modules (e.g., usrloc).
Cheers,
Daniel
--
Daniel-Constantin Mierla
http://www.asipto.com
Daniel-Constantin Mierla wrote:
Never did it, but I found this after a quick googling:
http://graag.blogspot.com/2007/10/unix-socket-sniffer.html
On 02/12/2009 11:11 PM, Alex Balashov wrote:
UNIX domain sockets. I am not aware of a good way to "sniff" those.
Is there one? Brian Chamberlain wrote:
OK, so we identified the source. Thanks a lot Alex!
Brian, you could sniff the UDP traffic for MI datagram, are you using
UDP sockets or unix sockets? On 12 Feb 2009, at 21:06, Alex Balashov wrote:
> Daniel-Constantin Mierla wrote:
>
>> Hello,
>> correlating messages:
>> Feb 12 20:27:22 sw1 kernel: [3273100.093090] INFO: task
>> kamailio:22821 blocked for more than 120 seconds.
>> and
>> Process:: ID=14 PID=22821 Type=MI Datagram
>> seems that one of your MI datagram was blocked for some time. Are
>> you using MI datagram commands often? What are they?
>>
> Brian, I would guess CDRtool and its rating engine use a lot of MI
> commands as part of its interface with the proxy. Daniel, can you
> corroborate that?
>
I've been doing a lot of rerating today as it goes..
I don't know that this results in a lot of MI commands. I think
CDRtool and its processes use a lot of MI for managing session
timers and stuff like that, or maybe that's Call Control. I'm not
really familiar with AG Projects' technology stack.
I suppose one could switch to UDP sockets...
This is the way I would do, then use
ngrep/wiresharck/.... Hopefully the
cdrtool supports UDP sockets.
Anyhow, I wonder what the cdrtool would need for
rating from
kamailio... so if you can get the commands send by cdrtool, I can
tell you where is the possible lock.
I do not know.
I've been trying to help Brian with this, but I just don't know enough
about the AG Projects end of things.
11:11 p.m.
Hello,
On 02/12/2009 11:06 PM, Alex Balashov wrote:
Daniel-Constantin Mierla wrote:
Never used CDRTool, do not want to elaborate on that why I
didn't...
But yes, if it is doing heavy MI work, then it can block the MI processes.
Cheers,
Daniel
--
Daniel-Constantin Mierla
http://www.asipto.com
Hello,
correlating messages:
Feb 12 20:27:22 sw1 kernel: [3273100.093090] INFO: task
kamailio:22821 blocked for more than 120 seconds.
and
Process:: ID=14 PID=22821 Type=MI Datagram
seems that one of your MI datagram was blocked for some time. Are you
using MI datagram commands often? What are they?
Brian, I would guess CDRtool and its rating engine use a lot of MI
commands as part of its interface with the proxy. Daniel, can you
corroborate that?
5764
days inactive
5764
days old
12 comments
3 participants
participants (3)
-
Alex Balashov -
Brian Chamberlain -
Daniel-Constantin Mierla