[asterisk-bugs] Music On Hold is stopped after call in a queue is terminated

Thu May 24 18:16:08 CDT 2012

Hello all,

We have seen a problem in asterisk 1.8.11 and 1.8.12 where Music On Hold 
is stopped after call in a queue is terminated.

To reproduce the bug you have to login as an agent to wait for incoming 
calls in a queue (Music On Hold will be playing to him as normal), then 
when a call comes into the queue, the agent will get connected to the 
call and can handle it normally. The problem comes when the call is 
terminated, IN SOME OCCASIONS the MoH (that should normally be 
reproduced to him again waiting for the next call to arrive) will only 
play for half a second and then get stopped, asterisk's CLI will even 
show the line

-- Stopped music on hold on SIP/...

We have not been able to reproduce this in asterisk 1.8.7

Attached you can find the CLI output of when this bug is being reproduced

-- 
Best regards,

Eduardo Abad
QA & Certifications
PaloSanto Solutions
PBX: +593 4 2294440 ext. 221
www.palosanto.com
www.elastix.org
-------------- next part --------------

Agent Login
======================================================================
ehcp*CLI> 
  == Using SIP RTP TOS bits 184
  == Using SIP RTP CoS mark 5
  == Extension Changed 300[ext-local] new state InUse for Notify User 300 
    -- Executing [7888 at from-internal:1] Set("SIP/300-00000011", "AGENTNUMBER=") in new stack
    -- Executing [7888 at from-internal:2] NoOp("SIP/300-00000011", "AgentNumber is ") in new stack
    -- Executing [7888 at from-internal:3] AgentLogin("SIP/300-00000011", "") in new stack
    -- <SIP/300-00000011> Playing 'agent-user.gsm' (language 'en')
    -- <SIP/300-00000011> Playing 'agent-pass.gsm' (language 'en')
    -- <SIP/300-00000011> Playing 'agent-loginok.gsm' (language 'en')
    -- Started music on hold, class 'default', on SIP/300-00000011
  == Agent '101' logged in (format ulaw/ulaw)
ehcp*CLI> 
======================================================================

Call comes into queue (8000) and automatically connected to the agent
======================================================================
ehcp*CLI> 
  == Using SIP RTP TOS bits 184
  == Using SIP RTP CoS mark 5
    -- Executing [8000 at from-internal:1] Macro("SIP/290-00000012", "user-callerid,") in new stack
    -- Executing [s at macro-user-callerid:1] Set("SIP/290-00000012", "AMPUSER=290") in new stack
    -- Executing [s at macro-user-callerid:2] GotoIf("SIP/290-00000012", "0?report") in new stack
    -- Executing [s at macro-user-callerid:3] ExecIf("SIP/290-00000012", "1?Set(REALCALLERIDNUM=290)") in new stack
    -- Executing [s at macro-user-callerid:4] Set("SIP/290-00000012", "AMPUSER=290") in new stack
    -- Executing [s at macro-user-callerid:5] Set("SIP/290-00000012", "AMPUSERCIDNAME=ZoIPer") in new stack
    -- Executing [s at macro-user-callerid:6] GotoIf("SIP/290-00000012", "0?report") in new stack
    -- Executing [s at macro-user-callerid:7] Set("SIP/290-00000012", "AMPUSERCID=290") in new stack
    -- Executing [s at macro-user-callerid:8] Set("SIP/290-00000012", "CALLERID(all)="ZoIPer" <290>") in new stack
    -- Executing [s at macro-user-callerid:9] ExecIf("SIP/290-00000012", "0?Set(CHANNEL(language)=)") in new stack
    -- Executing [s at macro-user-callerid:10] GotoIf("SIP/290-00000012", "0?continue") in new stack
    -- Executing [s at macro-user-callerid:11] Set("SIP/290-00000012", "__TTL=64") in new stack
    -- Executing [s at macro-user-callerid:12] GotoIf("SIP/290-00000012", "1?continue") in new stack
    -- Goto (macro-user-callerid,s,19)
    -- Executing [s at macro-user-callerid:19] Set("SIP/290-00000012", "CALLERID(number)=290") in new stack
    -- Executing [s at macro-user-callerid:20] Set("SIP/290-00000012", "CALLERID(name)=ZoIPer") in new stack
    -- Executing [s at macro-user-callerid:21] NoOp("SIP/290-00000012", "Using CallerID "ZoIPer" <290>") in new stack
    -- Executing [8000 at from-internal:2] Answer("SIP/290-00000012", "") in new stack
    -- Executing [8000 at from-internal:3] Set("SIP/290-00000012", "__BLKVM_OVERRIDE=BLKVM/8000/SIP/290-00000012") in new stack
    -- Executing [8000 at from-internal:4] Set("SIP/290-00000012", "__BLKVM_BASE=8000") in new stack
    -- Executing [8000 at from-internal:5] Set("SIP/290-00000012", "DB(BLKVM/8000/SIP/290-00000012)=TRUE") in new stack
    -- Executing [8000 at from-internal:6] ExecIf("SIP/290-00000012", "1?Set(_DIAL_OPTIONS=trM(auto-blkvm))") in new stack
    -- Executing [8000 at from-internal:7] Set("SIP/290-00000012", "__NODEST=8000") in new stack
    -- Executing [8000 at from-internal:8] Set("SIP/290-00000012", "MONITOR_FILENAME=/var/spool/asterisk/monitor/q8000-20120524-173115-1337898675.21") in new stack
    -- Executing [8000 at from-internal:9] Queue("SIP/290-00000012", "8000,t,,") in new stack
    -- Started music on hold, class 'default', on SIP/290-00000012
    -- Stopped music on hold on SIP/300-00000011
    -- agent_call, call to agent '101' call on 'SIP/300-00000011'
    -- <SIP/300-00000011> Playing 'beep.gsm' (language 'en')
    -- Agent/101 answered SIP/290-00000012
    -- Stopped music on hold on SIP/290-00000012
ehcp*CLI> 
======================================================================

Call termination
======================================================================
ehcp*CLI> 
    -- Executing [h at from-internal:1] Macro("SIP/290-00000012", "hangupcall") in new stack
    -- Executing [s at macro-hangupcall:1] GotoIf("SIP/290-00000012", "1?endmixmoncheck") in new stack
    -- Goto (macro-hangupcall,s,9)
    -- Executing [s at macro-hangupcall:9] NoOp("SIP/290-00000012", "End of MIXMON check") in new stack
    -- Executing [s at macro-hangupcall:10] GotoIf("SIP/290-00000012", "1?nomeetmemon") in new stack
    -- Goto (macro-hangupcall,s,15)
    -- Executing [s at macro-hangupcall:15] NoOp("SIP/290-00000012", "MEETME_RECORDINGFILE=") in new stack
    -- Executing [s at macro-hangupcall:16] GotoIf("SIP/290-00000012", "1?noautomon") in new stack
    -- Goto (macro-hangupcall,s,18)
    -- Executing [s at macro-hangupcall:18] NoOp("SIP/290-00000012", "TOUCH_MONITOR_OUTPUT=") in new stack
    -- Executing [s at macro-hangupcall:19] GotoIf("SIP/290-00000012", "0?noautomon2") in new stack
    -- Executing [s at macro-hangupcall:20] System("SIP/290-00000012", "test -e /var/spool/asterisk/monitor/q8000-20120524-173115-1337898675.21*") in new stack
    -- Executing [s at macro-hangupcall:21] NoOp("SIP/290-00000012", "SYSTEMSTATUS = APPERROR") in new stack
    -- Executing [s at macro-hangupcall:22] GotoIf("SIP/290-00000012", "1?errornoautomon") in new stack
    -- Goto (macro-hangupcall,s,24)
    -- Executing [s at macro-hangupcall:24] NoOp("SIP/290-00000012", "End of MONITOR QUEUE check") in new stack
    -- Executing [s at macro-hangupcall:25] NoOp("SIP/290-00000012", "MONITOR_FILENAME=/var/spool/asterisk/monitor/q8000-20120524-173115-1337898675.21") in new stack
    -- Executing [s at macro-hangupcall:26] GotoIf("SIP/290-00000012", "1?skiprg") in new stack
    -- Goto (macro-hangupcall,s,29)
    -- Executing [s at macro-hangupcall:29] GotoIf("SIP/290-00000012", "0?skipblkvm") in new stack
    -- Executing [s at macro-hangupcall:30] NoOp("SIP/290-00000012", "Cleaning Up Block VM Flag: BLKVM/8000/SIP/290-00000012") in new stack
    -- Executing [s at macro-hangupcall:31] NoOp("SIP/290-00000012", "Deleting: BLKVM/8000/SIP/290-00000012 TRUE") in new stack
    -- Executing [s at macro-hangupcall:32] GotoIf("SIP/290-00000012", "1?theend") in new stack
    -- Goto (macro-hangupcall,s,34)
    -- Executing [s at macro-hangupcall:34] Hangup("SIP/290-00000012", "") in new stack
  == Spawn extension (macro-hangupcall, s, 34) exited non-zero on 'SIP/290-00000012' in macro 'hangupcall'
  == Spawn extension (from-internal, h, 1) exited non-zero on 'SIP/290-00000012'
    -- Started music on hold, class 'default', on SIP/300-00000011
  == Spawn extension (from-internal, 8000, 9) exited non-zero on 'SIP/290-00000012'
    -- Stopped music on hold on SIP/300-00000011
ehcp*CLI> 
ehcp*CLI> 
ehcp*CLI> agent show
101          (john) logged in on SIP/300-00000013 is idle (musiconhold is 'default')
1 agents configured [1 online , 0 offline]

ehcp*CLI> 
ehcp*CLI> 
======================================================================

Even though the output of the 'agent show' command mentions "musiconhold is 'default'" the MoH has actually been stopped as can be seen in the line    -- Stopped music on hold on SIP/300-00000011 above