[Home]

Summary:ASTERISK-17871: Asterisk always deadlocks in queue after upgrading to 1.8.3&1.8.4
Reporter:mervent (mervent)Labels:
Date Opened:2011-05-17 11:20:24Date Closed:2011-05-25 06:32:43
Priority:MajorRegression?No
Status:Closed/CompleteComponents:Applications/app_queue
Versions:1.8.3 Frequency of
Occurrence
Related
Issues:
Environment:Attachments:
Description:Hello,

We using asterisk with lua dialplan rules, after upgrading our asterisk box - every time when we receiving incoming call to our queue we got deadlock.
Extension 1150 exists in lua dialplan and working. Asterisk <1.8.3 aslo working ok. If i replace
member => Local/1150@phones_and_peers/n
to
member => SIP/1150,1
all working ok. It just happens with local channels.


****** ADDITIONAL INFORMATION ******

extensions.lua:
["1150"] = function()
local t = { "SIP/1152", "SIP/1154" }
dial_group(t, "ringall");
end;
(extension content doesnt matter, it can be just app.Dial("SIP/1152") )

queue.conf:

[pribor_queue]
music = default
strategy = ringall
timeoutpriority=conf
context = phones ; Here we go when the caller presses a single digit, while in the queue
timeout = 600
wrapuptime=0
announce-frequency = 30
announce-holdtime = yes
joinempty = yes
member => Local/1150@phones_and_peers/n


/usr/sbin/asterisk -vvvvvv -g  -dddddd -c
  -- Executing [t@ivr_pribor:1] goto("DAHDI/i1/4956519180-2", "74956519180,1")
   -- Goto (ivr_pribor,74956519180,1)
[May 17 19:59:20] DEBUG[7354]: pbx_lua.c:1283 lua_find_extension: Looking up 74956519180@ivr_pribor:1
[May 17 19:59:20] DEBUG[7353]: audiohook.c:227 audiohook_read_frame_both: Read factory 0x1a7c540 and write factory 0x1a7cf80 both fail to provide 160 samples
[May 17 19:59:20] DEBUG[7354]: pbx_lua.c:1283 lua_find_extension: Looking up 74956519180@ivr_pribor:1
   -- Executing [74956519180@ivr_pribor:1] Answer("DAHDI/i1/4956519180-2", "")
[May 17 19:59:20] DEBUG[7354]: chan_dahdi.c:9115 dahdi_indicate: Requested indication -1 on channel DAHDI/i1/4956519180-2
[May 17 19:59:20] DEBUG[7354]: pbx.c:3095 ast_str_retrieve_variable: Result of 'UNIQUEID' is '1305647942.2'
[May 17 19:59:20] DEBUG[7354]: pbx.c:3095 ast_str_retrieve_variable: Result of 'UNIQUEID' is '1305647942.2'
   -- Executing [74956519180@ivr_pribor:1] NoOp("DAHDI/i1/4956519180-2", "Starting recording /var/spool/asterisk/monitor/QUEUE-4956519180-1305647942.2.wav")
[May 17 19:59:20] DEBUG[7354]: pbx.c:3095 ast_str_retrieve_variable: Result of 'UNIQUEID' is '1305647942.2'
[May 17 19:59:20] DEBUG[7354]: pbx.c:3095 ast_str_retrieve_variable: Result of 'UNIQUEID' is '1305647942.2'
   -- Executing [74956519180@ivr_pribor:1] MixMonitor("DAHDI/i1/4956519180-2", "/var/spool/asterisk/monitor/QUEUE-4956519180-1305647942.2.wav")
[May 17 19:59:20] DEBUG[7354]: autochan.c:54 ast_autochan_setup: Created autochan 0x171acd0 to hold channel DAHDI/i1/4956519180-2 (0x1aaa108)
   -- Executing [74956519180@ivr_pribor:1] queue("DAHDI/i1/4956519180-2", "pribor_queue,t")
[May 17 19:59:20] DEBUG[7354]: app_queue.c:5848 queue_exec: NO QUEUE_PRIO variable found. Using default.
[May 17 19:59:20] DEBUG[7354]: app_queue.c:5898 queue_exec: queue: pribor_queue, options: t, url: (null), announce: (null), expires: 0, priority: 0
[May 17 19:59:20] DEBUG[7354]: app_queue.c:2412 update_realtime_members: Queue pribor_queue has no realtime members defined. No need for update
[May 17 19:59:20] DEBUG[7354]: app_queue.c:2523 join_queue: Queue 'pribor_queue' Join, Channel 'DAHDI/i1/4956519180-2', Position '1'
   -- Started music on hold, class 'default', on DAHDI/i1/4956519180-2
[May 17 19:59:20] DEBUG[7354]: channel.c:3427 ast_settimeout: Scheduling timer at (50 requested / 50 actual) timer ticks per second
[May 17 19:59:20] DEBUG[7354]: app_queue.c:3855 is_our_turn: There is 1 available member.
[May 17 19:59:20] DEBUG[7354]: app_queue.c:3869 is_our_turn: It's our turn (DAHDI/i1/4956519180-2).
[May 17 19:59:20] DEBUG[7354]: app_queue.c:4430 try_calling: DAHDI/i1/4956519180-2 is trying to call a queue member.
[May 17 19:59:20] DEBUG[7354]: app_queue.c:3215 ring_one: (Parallel) Trying 'Local/1150@phones_and_peers/n' with metric 0
[May 17 19:59:20] DEBUG[7354]: channel.c:5930 ast_channel_inherit_variables: Not copying variable MIXMONITOR_FILENAME.
[May 17 19:59:20] DEBUG[7354]: channel.c:5930 ast_channel_inherit_variables: Not copying variable BACKGROUNDSTATUS.
[May 17 19:59:20] DEBUG[7354]: channel.c:5930 ast_channel_inherit_variables: Not copying variable CALLEDTON.
[May 17 19:59:20] DEBUG[7354]: channel.c:5930 ast_channel_inherit_variables: Not copying variable PRIREDIRECTREASON.
[May 17 19:59:20] DEBUG[7354]: channel.c:5930 ast_channel_inherit_variables: Not copying variable ANI2.
[May 17 19:59:20] DEBUG[7354]: channel.c:5930 ast_channel_inherit_variables: Not copying variable TRANSFERCAPABILITY.
 == Begin MixMonitor Recording DAHDI/i1/4956519180-2
[May 17 19:59:20] DEBUG[7379]: audiohook.c:227 audiohook_read_frame_both: Read factory 0x1a7a490 and write factory 0x1a7aed0 both fail to provide 160 samples
[May 17 19:59:20] DEBUG[7354]: pbx_lua.c:1283 lua_find_extension: Looking up 1150@phones_and_peers:1
[May 17 19:59:20] DEBUG[7354]: pbx_lua.c:1283 lua_find_extension: Looking up 1150@phones:1
[May 17 19:59:20] DEBUG[7353]: audiohook.c:233 audiohook_read_frame_both: Write factory 0x1a7cf80 was pretty quick last time, waiting for them.
[May 17 19:59:20] DEBUG[7353]: audiohook.c:227 audiohook_read_frame_both: Read factory 0x1a7c540 and write factory 0x1a7cf80 both fail to provide 160 samples
[May 17 19:59:20] DEBUG[7353]: audiohook.c:233 audiohook_read_frame_both: Write factory 0x1a7cf80 was pretty quick last time, waiting for them.
[May 17 19:59:20] DEBUG[7353]: audiohook.c:227 audiohook_read_frame_both: Read factory 0x1a7c540 and write factory 0x1a7cf80 both fail to provide 160 samples
[May 17 19:59:20] DEBUG[7353]: audiohook.c:233 audiohook_read_frame_both: Write factory 0x1a7cf80 was pretty quick last time, waiting for them.
[May 17 19:59:20] DEBUG[7353]: audiohook.c:227 audiohook_read_frame_both: Read factory 0x1a7c540 and write factory 0x1a7cf80 both fail to provide 160 samples
[May 17 19:59:20] DEBUG[7353]: audiohook.c:233 audiohook_read_frame_both: Write factory 0x1a7cf80 was pretty quick last time, waiting for them.
[May 17 19:59:20] DEBUG[7353]: audiohook.c:227 audiohook_read_frame_both: Read factory 0x1a7c540 and write factory 0x1a7cf80 both fail to provide 160 samples
[May 17 19:59:20] DEBUG[7353]: audiohook.c:233 audiohook_read_frame_both: Write factory 0x1a7cf80 was pretty quick last time, waiting for them.

And so on. It's locked now.

GDB

Thread 6 (Thread 0x7f24ef2e6700 (LWP 8909)):
#0  0x00007f2514df0d34 in __lll_lock_wait () from /lib64/libpthread.so.0
#1  0x00007f2514dec244 in _L_lock_547 () from /lib64/libpthread.so.0
#2  0x00007f2514dec0a6 in pthread_mutex_lock () from /lib64/libpthread.so.0
#3  0x0000000000472a3c in ast_waitfor_nandfds ()
#4  0x00000000004734a7 in ast_waitfor_n ()
ASTERISK-1  0x0000000000443e7e in ?? ()
ASTERISK-2  0x000000000053a81a in ?? ()
ASTERISK-3  0x00007f2514de9914 in start_thread () from /lib64/libpthread.so.0
ASTERISK-4  0x00007f25144734bd in clone () from /lib64/libc.so.6

Thread 5 (Thread 0x7f24ef362700 (LWP 8927)):
#0  0x00007f251446a903 in poll () from /lib64/libc.so.6
#1  0x0000000000472ee5 in ast_waitfor_nandfds ()
#2  0x00000000004781bc in ?? ()
#3  0x0000000000478c95 in ast_channel_bridge ()
#4  0x00000000004a8546 in ast_bridge_call ()
ASTERISK-1  0x00007f25010ba47b in ?? () from /usr/lib64/asterisk/modules/app_dial.so
ASTERISK-2  0x00007f25010bbd86 in ?? () from /usr/lib64/asterisk/modules/app_dial.so
ASTERISK-3  0x00000000004ee9cb in pbx_exec ()
ASTERISK-4  0x00007f2511f38f9d in ?? () from /usr/lib64/asterisk/modules/pbx_lua.so
ASTERISK-5  0x00007f2511d16051 in ?? () from /usr/lib64/liblua.so.5
ASTERISK-6 0x00007f2511d20c88 in ?? () from /usr/lib64/liblua.so.5
ASTERISK-7 0x00007f2511d1650d in ?? () from /usr/lib64/liblua.so.5
ASTERISK-8 0x00007f2511d15bc7 in ?? () from /usr/lib64/liblua.so.5
ASTERISK-9 0x00007f2511d15c40 in ?? () from /usr/lib64/liblua.so.5
ASTERISK-10 0x00007f2511d116c1 in lua_pcall () from /usr/lib64/liblua.so.5
ASTERISK-11 0x00007f2511f39a96 in ?? () from /usr/lib64/asterisk/modules/pbx_lua.so
ASTERISK-12 0x00000000004fb647 in ?? ()
ASTERISK-13 0x0000000000500e4d in ?? ()
ASTERISK-14 0x00000000005024a9 in ?? ()
ASTERISK-15 0x000000000053a81a in ?? ()
ASTERISK-16 0x00007f2514de9914 in start_thread () from /lib64/libpthread.so.0
ASTERISK-17 0x00007f25144734bd in clone () from /lib64/libc.so.6

Thread 4 (Thread 0x7f24eefe9700 (LWP 8928)):
#0  0x00007f2514dee5d9 in pthread_cond_timedwait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0
#1  0x0000000000440d2f in ast_audiohook_trigger_wait ()
#2  0x00007f24f7731c58 in ?? () from /usr/lib64/asterisk/modules/app_mixmonitor.so
#3  0x000000000053a81a in ?? ()
#4  0x00007f2514de9914 in start_thread () from /lib64/libpthread.so.0
ASTERISK-1  0x00007f25144734bd in clone () from /lib64/libc.so.6
---Type <return> to continue, or q <return> to quit---

Thread 3 (Thread 0x7f24eef6d700 (LWP 8929)):
#0  0x00007f251444347d in nanosleep () from /lib64/libc.so.6
#1  0x00007f251446d524 in usleep () from /lib64/libc.so.6
#2  0x000000000044392a in ast_autoservice_stop ()
#3  0x00000000004f64f4 in pbx_find_extension ()
#4  0x00000000004fb145 in ?? ()
ASTERISK-1  0x00000000004fba44 in ast_exists_extension ()
ASTERISK-2  0x00007f24f5ed1953 in ?? () from /usr/lib64/asterisk/modules/chan_local.so
ASTERISK-3  0x00000000004656c6 in ast_call ()
ASTERISK-4  0x00007f250906dae5 in ?? () from /usr/lib64/asterisk/modules/app_queue.so
ASTERISK-5  0x00007f250906edb1 in ?? () from /usr/lib64/asterisk/modules/app_queue.so
ASTERISK-6 0x00007f2509072598 in ?? () from /usr/lib64/asterisk/modules/app_queue.so
ASTERISK-7 0x00007f25090769dd in ?? () from /usr/lib64/asterisk/modules/app_queue.so
ASTERISK-8 0x00000000004ee9cb in pbx_exec ()
ASTERISK-9 0x00007f2511f38f9d in ?? () from /usr/lib64/asterisk/modules/pbx_lua.so
ASTERISK-10 0x00007f2511d16051 in ?? () from /usr/lib64/liblua.so.5
ASTERISK-11 0x00007f2511d20c88 in ?? () from /usr/lib64/liblua.so.5
ASTERISK-12 0x00007f2511d1650d in ?? () from /usr/lib64/liblua.so.5
ASTERISK-13 0x00007f2511d15bc7 in ?? () from /usr/lib64/liblua.so.5
ASTERISK-14 0x00007f2511d15c40 in ?? () from /usr/lib64/liblua.so.5
ASTERISK-15 0x00007f2511d116c1 in lua_pcall () from /usr/lib64/liblua.so.5
ASTERISK-16 0x00007f2511f39a96 in ?? () from /usr/lib64/asterisk/modules/pbx_lua.so
ASTERISK-17 0x00000000004fb647 in ?? ()
ASTERISK-18 0x0000000000500e4d in ?? ()
ASTERISK-19 0x00000000005024a9 in ?? ()
ASTERISK-20 0x000000000053a81a in ?? ()
ASTERISK-21 0x00007f2514de9914 in start_thread () from /lib64/libpthread.so.0
ASTERISK-22 0x00007f25144734bd in clone () from /lib64/libc.so.6

Thread 2 (Thread 0x7f24eeef1700 (LWP 8968)):
#0  0x00007f2514dee5d9 in pthread_cond_timedwait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0
#1  0x0000000000440d2f in ast_audiohook_trigger_wait ()
#2  0x00007f24f7731c58 in ?? () from /usr/lib64/asterisk/modules/app_mixmonitor.so
#3  0x000000000053a81a in ?? ()
#4  0x00007f2514de9914 in start_thread () from /lib64/libpthread.so.0
ASTERISK-1  0x00007f25144734bd in clone () from /lib64/libc.so.6
Comments:By: Sébastien Couture (sysreq) 2011-05-17 11:44:10

Have you taken a look at issue ASTERISK-17414? It could very well be related.. plus, even though that patch was merged into the 1.8 branch on April 26th, it didn't seem to make it into 1.8.4 (which was released May 9th).
By: Leif Madsen (lmadsen) 2011-05-17 16:56:34

Yes please test the latest 1.8 branch directly.
By: Leif Madsen (lmadsen) 2011-05-25 06:32:43

Closing this with the presumption that the change in ASTERISK-17414 also fixes this. If this is not the case, please reopen. If you can't, please find a bug marshal on the IRC channel #asterisk-bugs on irc.freenode.net.