[Home]

Summary:ASTERISK-00065: queue app seems to crash regularly
Reporter:jfriedeck (jfriedeck)Labels:
Date Opened:2003-08-08 11:49:17Date Closed:2004-09-25 02:14:15
Priority:CriticalRegression?No
Status:Closed/CompleteComponents:Applications/app_queue
Versions:Frequency of
Occurrence
Related
Issues:
Environment:Attachments:( 0) bt
( 1) newbt
Description:When using queue app, asterisk dies if no extension is available or extension dials outside line. If extension is available, call goes through but then receiving channel hangs. Worked yesterday. Doesn't today. Have new CVS on updated Mandrake 9.1 on celeron 2.2GHz 384MB.
Comments:By: jfriedeck (jfriedeck) 2003-08-08 12:45:45

I think this is the same issue that 68 is having.

Jim
By: Mark Spencer (markster) 2003-08-08 14:32:59

Should be fixed in CVS.  Sorry for introducing the problem.
By: jfriedeck (jfriedeck) 2003-08-08 14:39:08

Still crashing in slightly different place. After call goes through.
By: jfriedeck (jfriedeck) 2003-08-08 14:39:56

#0  local_hangup (ast=0x812bc50) at chan_local.c:247
#1  0x08056c88 in ast_hangup (chan=0x4663a58c) at channel.c:668
#2  0x47a96f90 in dial_exec (chan=0x81269f0, data=0x0) at app_dial.c:663
#3  0x0806101a in pbx_exec (c=0x81269f0, app=0x80dcab8, data=0x4885774c,
   newstack=1) at pbx.c:388
#4  0x08068071 in pbx_extension_helper (c=0x81269f0, context=0x8126b40 "c_in_1",
   exten=0x812bc50 "Zap/73-1<MASQ>", priority=1, callerid=0x0, action=1180935564)
   at pbx.c:1135
ASTERISK-1  0x08062e9c in ast_pbx_run (c=0x4663a58c) at pbx.c:1619
ASTERISK-2  0x08068731 in pbx_thread (data=0x812b780) at pbx.c:1835
ASTERISK-3  0x4002d811 in pthread_start_thread () from /lib/i686/libpthread.so.0




Aug  8 14:21:02 DEBUG[360467]: File chan_zap.c, Line 3285 (zt_read): DTMF digit: 1 on Zap/74-1
Aug  8 14:21:03 DEBUG[360467]: File chan_zap.c, Line 3285 (zt_read): DTMF digit: 0 on Zap/74-1
Aug  8 14:21:03 DEBUG[360467]: File chan_zap.c, Line 3285 (zt_read): DTMF digit: 3 on Zap/74-1
Aug  8 14:21:03 DEBUG[360467]: File chan_zap.c, Line 934 (zt_enable_ec): Enabled echo cancellation on channel 74
Aug  8 14:21:03 DEBUG[360467]: File channel.c, Line 1290 (ast_prod): Prodding channel 'Zap/74-1'
Aug  8 14:21:03 DEBUG[360467]: File app_queue.c, Line 723 (try_calling): Simple queue (no URL)
Aug  8 14:21:03 DEBUG[360467]: File app_queue.c, Line 723 (try_calling): Simple queue (no URL)
Aug  8 14:21:03 DEBUG[360467]: File app_queue.c, Line 723 (try_calling): Simple queue (no URL)
Aug  8 14:21:03 DEBUG[360467]: File app_queue.c, Line 723 (try_calling): Simple queue (no URL)
Aug  8 14:21:03 DEBUG[360467]: File app_queue.c, Line 723 (try_calling): Simple queue (no URL)
Aug  8 14:21:03 DEBUG[360467]: File app_queue.c, Line 403 (ring_one): Trying 'Agent/1025' with metric 0
Aug  8 14:21:03 DEBUG[360467]: File app_queue.c, Line 403 (ring_one): Trying 'Agent/1024' with metric 0
Aug  8 14:21:03 DEBUG[360467]: File app_queue.c, Line 403 (ring_one): Trying 'Agent/1023' with metric 0
Aug  8 14:21:03 DEBUG[360467]: File app_queue.c, Line 403 (ring_one): Trying 'Agent/1021' with metric 0
Aug  8 14:21:05 DEBUG[376852]: File chan_zap.c, Line 3061 (zt_exception): Exception on 25, channel 73
Aug  8 14:21:05 DEBUG[376852]: File chan_zap.c, Line 2517 (zt_handle_event): Got event Ringer Off(11) on channel 73 (index 0)
Aug  8 14:21:07 DEBUG[376852]: File chan_zap.c, Line 3061 (zt_exception): Exception on 25, channel 73
Aug  8 14:21:07 DEBUG[376852]: File chan_zap.c, Line 2517 (zt_handle_event): Got event Ring/Answered(2) on channel 73 (index 0)
Aug  8 14:21:07 DEBUG[376852]: File chan_zap.c, Line 934 (zt_enable_ec): Enabled echo cancellation on channel 73
Aug  8 14:21:07 DEBUG[376852]: File chan_zap.c, Line 2670 (zt_handle_event): channel 73 answered
Aug  8 14:21:07 DEBUG[360467]: File app_queue.c, Line 539 (wait_for_answer): Dunno what to do with control type -1
Aug  8 14:21:07 DEBUG[376852]: File chan_zap.c, Line 1866 (zt_setoption): Set option TONE VERIFY, mode: MUTECONF/MAX(2) on Zap/73-1
Aug  8 14:21:07 DEBUG[360467]: File chan_zap.c, Line 1866 (zt_setoption): Set option TONE VERIFY, mode: MUTECONF/MAX(2) on Zap/74-1
Aug  8 14:21:07 DEBUG[360467]: File chan_zap.c, Line 1793 (zt_answer): Took Zap/74-1 off hook
Aug  8 14:21:07 DEBUG[376852]: File channel.c, Line 1810 (ast_channel_masquerade): Planning to masquerade Zap/73-1 into the structure of Local/201@c_in_1-52e9.1
Aug  8 14:21:07 DEBUG[360467]: File channel.c, Line 1856 (ast_do_masquerade): Actually Masquerading Zap/73-1(6) into the structure of Local/201@c_in_1-52e9.1(6)
Aug  8 14:21:07 DEBUG[376852]: File channel.c, Line 1828 (ast_channel_masquerade): Done planning to masquerade Zap/73-1 into the structure of Zap/73-1<MASQ>
Aug  8 14:21:07 DEBUG[376852]: File channel.c, Line 2100 (ast_channel_bridge): Bridge stops because we're zombie or need a soft hangup: c0=Local/201@c_in_1-52e9,2, c1=Zap/73-1<MASQ>, flags: No,No,No,Yes
Aug  8 14:21:07 DEBUG[376852]: File channel.c, Line 2215 (ast_channel_bridge): Bridge stops bridging channels Local/201@c_in_1-52e9,2 and Zap/73-1<MASQ>
By: jfriedeck (jfriedeck) 2003-08-08 16:59:37

If I make the second step in the agent's extension voicemail(agentid), the pbx will dial the channel forever - even after I hang up the calling channel. When I then dialed the queue again fom another channel I got 'Junk at the beginning 49443303.' All the channels are on-hook ahd the PBX is still dialing the single agent over and over. Very strange.

Jim
By: tclark (tclark) 2003-08-08 17:31:22

I can confirm the crash as well using the agentcallbacklogon on a local Zap channel

#0  local_hangup (ast=0x81402b8) at chan_local.c:247
#1  0x08056bf8 in ast_hangup (chan=0x46b7a550) at channel.c:668
#2  0x41f95f70 in dial_exec (chan=0x81bc860, data=0x0) at app_dial.c:663
#3  0x08061089 in pbx_exec (c=0x81bc860, app=0x80d38e8, data=0x4900374c, newstack=1) at pbx.c:388
#4  0x08068090 in pbx_extension_helper (c=0x81402b8, context=0x81bc9b0 "dispatchlogin", exten=0x81bcaa4 "100",
   priority=1, callerid=0x0, action=1186440528) at pbx.c:1135
ASTERISK-1  0x08062f2c in ast_pbx_run (c=0x46b7a550) at pbx.c:1619
ASTERISK-2  0x08068761 in pbx_thread (data=0x81199b8) at pbx.c:1835
ASTERISK-3  0x4002d941 in pthread_start_thread () from /lib/i686/libpthread.so.0
By: Mark Spencer (markster) 2003-08-08 20:22:57

My chan_local does not suggest this crash is at a line of code that can crash.  Are you positive you're running on latest CVS?
By: Adam Goryachev (adamg) 2003-08-09 05:56:12

Using current CVS I am still getting a crash, though it looks a little bit different to before. The same usage scenario as before though in bug 70 (i think)

backtrace is:

#0  local_hangup (ast=0x8116328) at chan_local.c:247
247 int isoutbound = IS_OUTBOUND(ast, p);
(gdb)
(gdb)
(gdb)
(gdb) bt
#0  local_hangup (ast=0x8116328) at chan_local.c:247
#1  0x080562fc in ast_hangup (chan=0x8116328) at channel.c:668
#2  0x41f12ca3 in dial_exec (chan=0x81089a8, data=0x456b373c) at app_dial.c:663
#3  0x0805efc6 in pbx_exec (c=0x81089a8, app=0x80d6948, data=0x456b373c, newstack=1) at pbx.c:388
#4  0x08060b5a in pbx_extension_helper (c=0x81089a8, context=0x8108af8 "dispatchlogin", exten=0x8108bec "1001", priority=1, callerid=0x0,
   action=1) at pbx.c:1135
ASTERISK-1  0x080617fe in ast_pbx_run (c=0x81089a8) at pbx.c:1619
ASTERISK-2  0x0806753f in pbx_thread (data=0x81089a8) at pbx.c:1835
ASTERISK-3  0x40024fef in pthread_start_thread () from /lib/i686/libpthread.so.0
By: Mark Spencer (markster) 2003-08-09 13:23:32

I will need to ssh in to look at this and do further debugging.  Someone find me on IRC.
By: Adam Goryachev (adamg) 2003-08-11 04:17:32

I won't be awake at the times you seem to be around on IRC... (I'm in Australia +1000 hours)...

If there is some other way that you can let me know what you need to try, and I can get those results to you. Failing that, you may need to find someone else who can re-produce this bug.

If it helps, I can provide a copy of my configs etc...

Regards,
Adam
By: Adam Goryachev (adamg) 2003-08-11 04:28:17

Another bt if this helps at all? This one was produced with both the calling channel and target agent extensions being Zap channels (on a TDM40B card). One channel dialled, added to the queue, heard MoH, the other zap channel was ringing, as soon as I pickup, asterisk core dumps (even before pressing #).

Surely this should be very easily re-produced?
Possibly relevant configs:
extensions.conf
[dispatchlogin]
exten => *1,1,AgentCallbackLogin(1001|@dispatchlogin) ; to logout use empty ext like # then hangup
exten => 1001,1,Dial,Zap/5      ; Dial extension...
[remote]
; Call comes in, blah, and dropped into queue
exten => s,1,Answer
exten => s,2,DigitTimeout,5
exten => s,3,ResponseTimeout,10
exten => s,4,SetMusicOnHold,default
exten => s,5,Background,local/Thanks_for_calling
exten => s,6,Queue(queue,t)

queues.conf:
[general]

[queue]
music = default
strategy = ringall
timeout = 15
retry = 5
maxlen = 0
member => Agent/1001

I hope this makes some difference in assisting to resolve this issue.

Regards,
Adam

(gdb) bt
#0  local_hangup (ast=0x810c580) at chan_local.c:247
#1  0x080562fc in ast_hangup (chan=0x810c580) at channel.c:668
#2  0x41f12ca3 in dial_exec (chan=0x81092b8, data=0x456b373c) at app_dial.c:663
#3  0x0805efc6 in pbx_exec (c=0x81092b8, app=0x80e1ff8, data=0x456b373c, newstack=1) at pbx.c:388
#4  0x08060b5a in pbx_extension_helper (c=0x81092b8, context=0x8109408 "dispatchlogin", exten=0x81094fc "1001", priority=1,
   callerid=0x0, action=1) at pbx.c:1135
ASTERISK-1  0x080617fe in ast_pbx_run (c=0x81092b8) at pbx.c:1619
ASTERISK-2  0x0806753f in pbx_thread (data=0x81092b8) at pbx.c:1835
ASTERISK-3  0x40024fef in pthread_start_thread () from /lib/i686/libpthread.so.0
By: jfriedeck (jfriedeck) 2003-08-11 09:40:12

Mark, Jim here. Email me (asterisk@carhil.com) and you can ssh to our machine. Still exibiting same problem. After problem occured typing 'Show Agents' hung asterisk. Never seen that before. CVS as of this morning. Thanks.

Jim
By: jfriedeck (jfriedeck) 2003-08-12 09:48:04

Mark graciously spent 1.5 hrs on phone with me and hammered out a fix for this bug. Thanks Mark! Enjoy Florida.

Jim
By: Mark Spencer (markster) 2003-08-12 09:53:04

Looks like we really got it this time.
By: jfriedeck (jfriedeck) 2003-08-12 10:42:06

No longer a crash but stilll broken. I hate to do this to Mark. Using AgentCallbackLogin, I log 4 phones in to queue. First few calls are routed correctly. After the 3rd call, the target channel rings forever and * never acks the off-hook condition. It keeps dialing the target channel regardless of hook condition. Then the queue locks up and is non-responsive and no longer routes calls. Condition can only be remedied by asterisk restart.
By: jfriedeck (jfriedeck) 2003-08-12 11:06:33

Last lines of output....

DEBUG[606230]: File chan_zap.c, Line 950 (zt_disable_ec): disabled echo cancellation on channel 76
   -- Stopped music on hold on Zap/76-1
   -- User disconnected while waiting their turn
 == Spawn extension (c_in_1, 103, 1) exited non-zero on 'Zap/76-1'
DEBUG[606230]: File cdr_mysql.c, Line 84 (mysql_log): cdr_mysql: inserting a CDR record.
DEBUG[606230]: File cdr_mysql.c, Line 90 (mysql_log): cdr_mysql: SQL command as follows:  INSERT INTO cdr (calldate,clid,src,dst,dcontext,channel,dstchannel,lastapp,lastdata,duration,billsec,disposition,amaflags,accountcode) VALUES ('2003-08-12 10:24:45','CHANZ076-A04<204>','204','103','c_in_1', 'Zap/76-1','','Queue','q_lo_1',7,0,'NO ANSWER',3,'')
DEBUG[606230]: File chan_zap.c, Line 1510 (zt_hangup): Hangup: channel: 76 index = 0, normal = 28, callwait = -1, thirdcall = -1
DEBUG[606230]: File chan_zap.c, Line 950 (zt_disable_ec): disabled echo cancellation on channel 76
DEBUG[606230]: File chan_zap.c, Line 1877 (zt_setoption): Set option TDD MODE, value: OFF(0) on Zap/76-1
DEBUG[606230]: File chan_zap.c, Line 909 (update_conf): Updated conferencing on 76, with 0 conference users
   -- Hungup 'Zap/76-1'
Warning, flexibel rate not heavily tested!
DEBUG[65541]: File res_musiconhold.c, Line 283 (monmp3thread): Read 96 bytes of audio while expecting 640
Warning, flexibel rate not heavily tested!
Junk at the beginning 49443303
Warning, flexibel rate not heavily tested!
DEBUG[65541]: File res_musiconhold.c, Line 283 (monmp3thread): Read 338 bytes of audio while expecting 640
Warning, flexibel rate not heavily tested!
DEBUG[65541]: File res_musiconhold.c, Line 283 (monmp3thread): Read 614 bytes of audio while expecting 640
Junk at the beginning 49443303
Warning, flexibel rate not heavily tested!
DEBUG[65541]: File res_musiconhold.c, Line 283 (monmp3thread): Read 368 bytes of audio while expecting 640
stop now
By: jfriedeck (jfriedeck) 2003-08-12 11:14:39

Seems to occur when target channel is busy. Asterisk may not route call correctly if first target is busy. After a while of routing calls, one phone will ring forever and off-hook is not recognized.
By: Brian West (bkw918) 2003-08-12 11:37:01

what strategy do you use for queues?
By: jfriedeck (jfriedeck) 2003-08-12 11:56:56

We use the 'leastrecent' strategy.
By: Brian West (bkw918) 2003-08-12 12:01:49

leastrecent and fewest calls strategy are somewhat broken.  They only ring the leastrecent or fewestcalls agent over and over never trying any other agents in queue.  FYI check my posting on the mailing list for input needed for mark to work on the logic.
By: jfriedeck (jfriedeck) 2003-08-12 13:25:17

Roundrobin does the same thing. If channel is busy, * locks up the target channel until * is reloaded. Will try rebooting the machine and let you know.
By: Mark Spencer (markster) 2003-08-12 14:19:39

Find me on irc.  I'm out of town and this will be the only way for me to login and figure out what the deadlock is.  I will need ssh access.
By: jfriedeck (jfriedeck) 2003-08-12 15:48:01

What's your nickname? How do I find someone on IRC? First time using it.

Jim
By: Mark Spencer (markster) 2003-08-12 15:52:27

#asterisk on irc.freenode.net, nick is kram
By: Mark Spencer (markster) 2003-08-14 14:25:12

I believe this bug is finally dead.  The details of fixes include:
* Races in chan_local and chan_agent
* Masquerade fixes
* Locking fixes in channel.c