Odd issue. Playing hold music for a few seconds then call drops

rubyred · October 4, 2017, 8:15pm

Periodically I am getting reports that users are getting dropped calls and the hold music is playing for a few seconds after the drop. I have reports of this happening for both inbound and outbound calls. Haven’t found a way to replicate the issue yet.

I don’t have a whole lot of experience with the logs yet but I do see where the hold music is played. Then it shows something about a transfer and then the call disconnects. Is there any way to tell which end the disconnect originated from?

Here is one of the calls.

Line 210901: [2017-10-04 12:10:55] VERBOSE[9999][C-00004015] netsock2.c: Line 210902: [2017-10-04 12:10:55] VERBOSE[9999][C-00004015] netsock2.c: Line 210903: [2017-10-04 12:10:55] VERBOSE[9648][C-00004015] pbx.c: Line 210904: [2017-10-04 12:10:55] VERBOSE[9648][C-00004015] pbx.c: Line 210905: [2017-10-04 12:10:55] VERBOSE[9648][C-00004015] pbx.c: Line 210906: [2017-10-04 12:10:55] VERBOSE[9648][C-00004015] pbx.c: Line 210907: [2017-10-04 12:10:55] VERBOSE[9648][C-00004015] pbx.c: Line 210908: [2017-10-04 12:10:55] VERBOSE[9648][C-00004015] pbx.c: Line 210909: [2017-10-04 12:10:55] VERBOSE[9648][C-00004015] pbx.c: Line 210910: [2017-10-04 12:10:55] VERBOSE[9648][C-00004015] pbx.c: Line 210911: [2017-10-04 12:10:55] VERBOSE[9648][C-00004015] pbx.c: Line 210912: [2017-10-04 12:10:55] VERBOSE[9648][C-00004015] pbx.c: Line 210913: [2017-10-04 12:10:55] VERBOSE[9648][C-00004015] pbx.c: Line 210914: [2017-10-04 12:10:55] VERBOSE[9648][C-00004015] pbx.c: Line 210915: [2017-10-04 12:10:55] VERBOSE[9648][C-00004015] pbx.c: Line 210916: [2017-10-04 12:10:55] VERBOSE[9648][C-00004015] pbx.c: Line 210917: [2017-10-04 12:10:55] VERBOSE[9648][C-00004015] pbx.c: Line 210918: [2017-10-04 12:10:55] VERBOSE[9648][C-00004015] pbx.c: Line 210919: [2017-10-04 12:10:55] VERBOSE[9648][C-00004015] pbx.c: Line 210920: [2017-10-04 12:10:55] VERBOSE[9648][C-00004015] pbx.c: Line 210921: [2017-10-04 12:10:55] VERBOSE[9648][C-00004015] pbx.c: Line 210922: [2017-10-04 12:10:55] VERBOSE[9648][C-00004015] pbx.c: Line 210923: [2017-10-04 12:10:55] VERBOSE[9648][C-00004015] pbx.c: Line 210924: [2017-10-04 12:10:55] VERBOSE[9648][C-00004015] pbx.c: Line 210925: [2017-10-04 12:10:55] VERBOSE[9648][C-00004015] pbx.c: Line 210926: [2017-10-04 12:10:55] VERBOSE[9648][C-00004015] pbx.c: Line 210927: [2017-10-04 12:10:55] VERBOSE[9648][C-00004015] pbx.c: Line 210928: [2017-10-04 12:10:55] VERBOSE[9648][C-00004015] pbx.c: Line 210929: [2017-10-04 12:10:55] VERBOSE[9648][C-00004015] pbx.c: Line 210930: [2017-10-04 12:10:55] VERBOSE[9648][C-00004015] pbx.c: Line 210931: [2017-10-04 12:10:55] VERBOSE[9648][C-00004015] pbx.c: Line 210932: [2017-10-04 12:10:55] VERBOSE[9648][C-00004015] pbx.c: Line 210933: [2017-10-04 12:10:55] VERBOSE[9648][C-00004015] pbx.c: Line 210934: [2017-10-04 12:10:55] VERBOSE[9648][C-00004015] pbx.c: Line 210935: [2017-10-04 12:10:55] VERBOSE[9648][C-00004015] pbx.c: Line 210936: [2017-10-04 12:10:55] VERBOSE[9648][C-00004015] pbx.c: Line 210937: [2017-10-04 12:10:55] VERBOSE[9648][C-00004015] pbx.c: Line 210938: [2017-10-04 12:10:55] VERBOSE[9648][C-00004015] pbx.c: Line 210939: [2017-10-04 12:10:55] VERBOSE[9648][C-00004015] pbx.c: Line 210940: [2017-10-04 12:10:55] VERBOSE[9648][C-00004015] pbx.c: Line 210941: [2017-10-04 12:10:55] VERBOSE[9648][C-00004015] pbx.c: Line 210942: [2017-10-04 12:10:55] VERBOSE[9648][C-00004015] pbx.c: Line 210943: [2017-10-04 12:10:55] VERBOSE[9648][C-00004015] pbx.c: Line 210944: [2017-10-04 12:10:55] VERBOSE[9648][C-00004015] pbx.c: Line 210945: [2017-10-04 12:10:55] VERBOSE[9648][C-00004015] pbx.c: Line 210946: [2017-10-04 12:10:55] VERBOSE[9648][C-00004015] pbx.c: Line 210947: [2017-10-04 12:10:55] VERBOSE[9648][C-00004015] pbx.c: Line 210948: [2017-10-04 12:10:55] VERBOSE[9648][C-00004015] pbx.c: Line 210949: [2017-10-04 12:10:55] VERBOSE[9648][C-00004015] pbx.c: Line 210950: [2017-10-04 12:10:55] VERBOSE[9648][C-00004015] pbx.c: Line 210951: [2017-10-04 12:10:55] VERBOSE[9648][C-00004015] pbx.c: Line 210952: [2017-10-04 12:10:55] VERBOSE[9648][C-00004015] pbx.c: Line 210953: [2017-10-04 12:10:55] VERBOSE[9648][C-00004015] pbx.c: Line 210954: [2017-10-04 12:10:55] VERBOSE[9648][C-00004015] pbx.c: Line 210955: [2017-10-04 12:10:55] VERBOSE[9648][C-00004015] pbx.c: Line 210956: [2017-10-04 12:10:55] VERBOSE[9648][C-00004015] pbx.c: Line 210957: [2017-10-04 12:10:55] VERBOSE[9648][C-00004015] pbx.c: Line 210958: [2017-10-04 12:10:55] VERBOSE[9648][C-00004015] pbx.c: Line 210959: [2017-10-04 12:10:55] VERBOSE[9648][C-00004015] pbx.c: Line 210960: [2017-10-04 12:10:55] VERBOSE[9648][C-00004015] pbx.c: Line 210961: [2017-10-04 12:10:55] VERBOSE[9648][C-00004015] pbx.c: Line 210962: [2017-10-04 12:10:55] VERBOSE[9648][C-00004015] pbx.c: Line 210963: [2017-10-04 12:10:55] VERBOSE[9648][C-00004015] pbx.c: Line 210964: [2017-10-04 12:10:55] VERBOSE[9648][C-00004015] pbx.c: Line 210965: [2017-10-04 12:10:55] VERBOSE[9648][C-00004015] pbx.c: Line 210966: [2017-10-04 12:10:55] VERBOSE[9648][C-00004015] pbx.c: Line 210967: [2017-10-04 12:10:55] VERBOSE[9648][C-00004015] pbx.c: Line 210968: [2017-10-04 12:10:55] VERBOSE[9648][C-00004015] pbx.c: Line 210969: [2017-10-04 12:10:55] VERBOSE[9648][C-00004015] pbx.c: Line 210970: [2017-10-04 12:10:55] VERBOSE[9648][C-00004015] pbx.c: Line 210971: [2017-10-04 12:10:55] VERBOSE[9648][C-00004015] pbx.c: Line 210972: [2017-10-04 12:10:55] VERBOSE[9648][C-00004015] pbx.c: Line 210973: [2017-10-04 12:10:55] VERBOSE[9648][C-00004015] pbx.c: Line 210974: [2017-10-04 12:10:55] VERBOSE[9648][C-00004015] pbx.c: Line 210975: [2017-10-04 12:10:55] VERBOSE[9648][C-00004015] pbx.c: Line 210976: [2017-10-04 12:10:55] VERBOSE[9648][C-00004015] pbx.c: Line 210977: [2017-10-04 12:10:55] VERBOSE[9648][C-00004015] pbx.c: Line 210978: [2017-10-04 12:10:55] VERBOSE[9648][C-00004015] pbx.c: Line 210979: [2017-10-04 12:10:55] VERBOSE[9648][C-00004015] pbx.c: Line 210980: [2017-10-04 12:10:55] VERBOSE[9648][C-00004015] pbx.c: Line 210981: [2017-10-04 12:10:55] VERBOSE[9648][C-00004015] pbx.c: Line 210982: [2017-10-04 12:10:55] VERBOSE[9648][C-00004015] pbx.c: Line 210983: [2017-10-04 12:10:55] VERBOSE[9648][C-00004015] pbx.c: Line 210984: [2017-10-04 12:10:55] VERBOSE[9648][C-00004015] pbx.c: Line 210985: [2017-10-04 12:10:55] VERBOSE[9648][C-00004015] pbx.c: Line 210986: [2017-10-04 12:10:55] VERBOSE[9648][C-00004015] pbx.c: Line 210987: [2017-10-04 12:10:55] VERBOSE[9648][C-00004015] pbx.c: Line 210988: [2017-10-04 12:10:55] VERBOSE[9648][C-00004015] pbx.c: Line 210989: [2017-10-04 12:10:55] VERBOSE[9648][C-00004015] pbx.c: Line 210990: [2017-10-04 12:10:55] VERBOSE[9648][C-00004015] pbx.c: Line 210991: [2017-10-04 12:10:55] VERBOSE[9648][C-00004015] pbx.c: Line 210992: [2017-10-04 12:10:55] VERBOSE[9648][C-00004015] pbx.c: Line 210993: [2017-10-04 12:10:55] VERBOSE[9648][C-00004015] pbx.c: Line 210994: [2017-10-04 12:10:55] VERBOSE[9648][C-00004015] pbx.c: Line 210995: [2017-10-04 12:10:55] VERBOSE[9648][C-00004015] pbx.c: Line 210996: [2017-10-04 12:10:55] VERBOSE[9648][C-00004015] pbx.c: Line 210997: [2017-10-04 12:10:55] VERBOSE[9648][C-00004015] pbx.c: Line 210998: [2017-10-04 12:10:55] VERBOSE[9648][C-00004015] pbx.c: Line 210999: [2017-10-04 12:10:55] VERBOSE[9648][C-00004015] netsock2.c: Line 211000: [2017-10-04 12:10:55] VERBOSE[9648][C-00004015] netsock2.c: Line 211001: [2017-10-04 12:10:55] VERBOSE[9648][C-00004015] app_dial.c: Line 211002: [2017-10-04 12:10:59] VERBOSE[9648][C-00004015] app_dial.c: Line 211003: [2017-10-04 12:10:59] VERBOSE[9648][C-00004015] app_dial.c: Line 211454: [2017-10-04 12:11:47] VERBOSE[9648][C-00004015] res_musiconhold.c: Line 211455: [2017-10-04 12:11:47] VERBOSE[9648][C-00004015] file.c: Line 211745: [2017-10-04 12:11:50] WARNING[9648][C-00004015] Line 211746: [2017-10-04 12:11:50] VERBOSE[9648][C-00004015] file.c: Line 211934: [2017-10-04 12:11:55] VERBOSE[9648][C-00004015] res_musiconhold.c: Line 212704: [2017-10-04 12:12:42] VERBOSE[9648][C-00004015] pbx.c: Line 212705: [2017-10-04 12:12:42] VERBOSE[9648][C-00004015] pbx.c: Line 212706: [2017-10-04 12:12:42] VERBOSE[9648][C-00004015] pbx.c: Line 212707: [2017-10-04 12:12:42] VERBOSE[9648][C-00004015] pbx.c: Line 212708: [2017-10-04 12:12:42] VERBOSE[9648][C-00004015] pbx.c: Line 212709: [2017-10-04 12:12:42] VERBOSE[9648][C-00004015] app_macro.c: Line 212710: [2017-10-04 12:12:42] VERBOSE[9648][C-00004015] pbx.c: Line 212711: [2017-10-04 12:12:42] VERBOSE[9648][C-00004015] app_macro.c: Line 212712: [2017-10-04 12:12:42] VERBOSE[9648][C-00004015] pbx.c: == Using SIP RTP TOS bits 184
== Using SIP RTP CoS mark 5
– Executing [DIALED#@from-internal:1] Macro(“SIP/501-00002687”, “user-callerid,LIMIT,EXTERNAL,”) in new stack
– Executing [[email protected]:1] Set(“SIP/501-00002687”, “TOUCH_MONITOR=1507133455.37472”) in new stack
– Executing [[email protected]:2] Set(“SIP/501-00002687”, “AMPUSER=501”) in new stack
– Executing [[email protected]:3] GotoIf(“SIP/501-00002687”, “0?report”) in new stack
– Executing [[email protected]:4] ExecIf(“SIP/501-00002687”, “1?Set(REALCALLERIDNUM=501)”) in new stack
– Executing [[email protected]:5] Set(“SIP/501-00002687”, “AMPUSER=501”) in new stack
– Executing [[email protected]:6] GotoIf(“SIP/501-00002687”, “0?limit”) in new stack
– Executing [[email protected]:7] Set(“SIP/501-00002687”, “AMPUSERCIDNAME=Krystian”) in new stack
– Executing [[email protected]:8] GotoIf(“SIP/501-00002687”, “0?report”) in new stack
– Executing [[email protected]:9] Set(“SIP/501-00002687”, “AMPUSERCID=501”) in new stack
– Executing [[email protected]:10] Set(“SIP/501-00002687”, “__DIAL_OPTIONS=Ttr”) in new stack
– Executing [[email protected]:11] Set(“SIP/501-00002687”, “CALLERID(all)=“Krystian” <501>”) in new stack
– Executing [[email protected]:12] GotoIf(“SIP/501-00002687”, “0?limit”) in new stack
– Executing [[email protected]:13] ExecIf(“SIP/501-00002687”, “1?Set(GROUP(concurrency_limit)=501)”) in new stack
– Executing [[email protected]:14] GosubIf(“SIP/501-00002687”, “7?sub-ccss,s,1(from-internal,DIALED#)”) in new stack
– Executing [[email protected]:1] ExecIf(“SIP/501-00002687”, “0?Return()”) in new stack
– Executing [[email protected]:2] Set(“SIP/501-00002687”, “CCSS_SETUP=TRUE”) in new stack
– Executing [[email protected]:3] GosubIf(“SIP/501-00002687”, “0?monitor_config,1(from-internal,DIALED#):monitor_default,1(from-internal,DIALED#)”) in new stack
– Executing [[email protected]:1] GotoIf(“SIP/501-00002687”, “0?is_exten”) in new stack
– Executing [[email protected]:2] StackPop(“SIP/501-00002687”, “”) in new stack
– Executing [[email protected]:3] Return(“SIP/501-00002687”, “FALSE”) in new stack
– Executing [[email protected]:15] ExecIf(“SIP/501-00002687”, “0?Set(CHANNEL(language)=)”) in new stack
– Executing [[email protected]:16] GotoIf(“SIP/501-00002687”, “1?continue”) in new stack
– Goto (macro-user-callerid,s,29)
– Executing [[email protected]:29] Set(“SIP/501-00002687”, “CALLERID(number)=501”) in new stack
– Executing [[email protected]:30] Set(“SIP/501-00002687”, “CALLERID(name)=Krystian”) in new stack
– Executing [[email protected]:31] Set(“SIP/501-00002687”, “CDR(cnum)=501”) in new stack
– Executing [[email protected]:32] Set(“SIP/501-00002687”, “CDR(cnam)=Krystian”) in new stack
– Executing [[email protected]:33] Set(“SIP/501-00002687”, “CHANNEL(language)=en”) in new stack
– Executing [DIALED#@from-internal:2] Set(“SIP/501-00002687”, “MOHCLASS=default”) in new stack
– Executing [DIALED#@from-internal:3] Set(“SIP/501-00002687”, “_NODEST=”) in new stack
– Executing [DIALED#@from-internal:4] Gosub(“SIP/501-00002687”, “sub-record-check,s,1(out,DIALED#,)”) in new stack
– Executing [[email protected]:1] Set(“SIP/501-00002687”, “REC_POLICY_MODE_SAVE=”) in new stack
– Executing [[email protected]:2] GotoIf(“SIP/501-00002687”, “1?check”) in new stack
– Goto (sub-record-check,s,7)
– Executing [[email protected]:7] Set(“SIP/501-00002687”, “__MON_FMT=wav”) in new stack
– Executing [[email protected]:8] GotoIf(“SIP/501-00002687”, “1?next”) in new stack
– Goto (sub-record-check,s,11)
– Executing [[email protected]:11] ExecIf(“SIP/501-00002687”, “0?Return()”) in new stack
– Executing [[email protected]:12] ExecIf(“SIP/501-00002687”, “0?Set(__REC_POLICY_MODE=)”) in new stack
– Executing [[email protected]:13] GotoIf(“SIP/501-00002687”, “0?out,1”) in new stack
– Executing [[email protected]:14] Set(“SIP/501-00002687”, “__REC_STATUS=INITIALIZED”) in new stack
– Executing [[email protected]:15] Set(“SIP/501-00002687”, “NOW=1507133455”) in new stack
– Executing [[email protected]:16] Set(“SIP/501-00002687”, “__DAY=04”) in new stack
– Executing [[email protected]:17] Set(“SIP/501-00002687”, “__MONTH=10”) in new stack
– Executing [[email protected]:18] Set(“SIP/501-00002687”, “__YEAR=2017”) in new stack
– Executing [[email protected]:19] Set(“SIP/501-00002687”, “__TIMESTR=20171004-121055”) in new stack
– Executing [[email protected]:20] Set(“SIP/501-00002687”, “__FROMEXTEN=501”) in new stack
– Executing [[email protected]:21] Set(“SIP/501-00002687”, “__CALLFILENAME=out-DIALED#-501-20171004-121055-1507133455.37472”) in new stack
– Executing [[email protected]:22] Goto(“SIP/501-00002687”, “out,1”) in new stack
– Goto (sub-record-check,out,1)
– Executing [[email protected]:1] ExecIf(“SIP/501-00002687”, “1?Set(__REC_POLICY_MODE=dontcare)”) in new stack
– Executing [[email protected]:2] GosubIf(“SIP/501-00002687”, “0?record,1(exten,DIALED#,501)”) in new stack
– Executing [[email protected]:3] Return(“SIP/501-00002687”, “”) in new stack
– Executing [DIALED#@from-internal:5] Macro(“SIP/501-00002687”, “dialout-trunk,6,DIALED#,off”) in new stack
– Executing [[email protected]:1] Set(“SIP/501-00002687”, “DIAL_TRUNK=6”) in new stack
– Executing [[email protected]:2] GosubIf(“SIP/501-00002687”, “0?sub-pincheck,s,1()”) in new stack
– Executing [[email protected]:3] GotoIf(“SIP/501-00002687”, “0?disabletrunk,1”) in new stack
– Executing [[email protected]:4] Set(“SIP/501-00002687”, “DIAL_NUMBER=DIALED#”) in new stack
– Executing [[email protected]:5] Set(“SIP/501-00002687”, “DIAL_TRUNK_OPTIONS=Ttr”) in new stack
– Executing [[email protected]:6] Set(“SIP/501-00002687”, “OUTBOUND_GROUP=OUT_6”) in new stack
– Executing [[email protected]:7] GotoIf(“SIP/501-00002687”, “0?nomax”) in new stack
– Executing [[email protected]:8] GotoIf(“SIP/501-00002687”, “0?chanfull”) in new stack
– Executing [[email protected]:9] GotoIf(“SIP/501-00002687”, “0?skipoutcid”) in new stack
– Executing [[email protected]:10] Set(“SIP/501-00002687”, “DIAL_TRUNK_OPTIONS=Tt”) in new stack
– Executing [[email protected]:11] Macro(“SIP/501-00002687”, “outbound-callerid,6”) in new stack
– Executing [[email protected]:1] ExecIf(“SIP/501-00002687”, “0?Set(CALLERPRES()=)”) in new stack
– Executing [[email protected]:2] ExecIf(“SIP/501-00002687”, “0?Set(REALCALLERIDNUM=501)”) in new stack
– Executing [[email protected]:3] GotoIf(“SIP/501-00002687”, “1?normcid”) in new stack
– Goto (macro-outbound-callerid,s,6)
– Executing [[email protected]:6] Set(“SIP/501-00002687”, “USEROUTCID=OUTBOUNDCID”) in new stack
– Executing [[email protected]:7] Set(“SIP/501-00002687”, “EMERGENCYCID=OUTBOUNDCID”) in new stack
– Executing [[email protected]:8] Set(“SIP/501-00002687”, “TRUNKOUTCID=”) in new stack
– Executing [[email protected]:9] GotoIf(“SIP/501-00002687”, “1?trunkcid”) in new stack
– Goto (macro-outbound-callerid,s,14)
– Executing [[email protected]:14] ExecIf(“SIP/501-00002687”, “0?Set(CALLERID(all)=)”) in new stack
– Executing [[email protected]:15] ExecIf(“SIP/501-00002687”, “1?Set(CALLERID(all)=OUTBOUNDCID)”) in new stack
– Executing [[email protected]:16] ExecIf(“SIP/501-00002687”, “0?Set(CALLERID(all)=)”) in new stack
– Executing [[email protected]:17] ExecIf(“SIP/501-00002687”, “0?Set(CALLERPRES()=prohib_passed_screen)”) in new stack
– Executing [[email protected]:18] Set(“SIP/501-00002687”, “CDR(outbound_cnum)=OUTBOUNDCID”) in new stack
– Executing [[email protected]:19] Set(“SIP/501-00002687”, “CDR(outbound_cnam)=”) in new stack
– Executing [[email protected]:12] GosubIf(“SIP/501-00002687”, “1?sub-flp-6,s,1()”) in new stack
– Executing [[email protected]:1] ExecIf(“SIP/501-00002687”, “0?Set(TARGET_FLP_6=1DIALED#)”) in new stack
– Executing [[email protected]:2] GotoIf(“SIP/501-00002687”, “0?match”) in new stack
– Executing [[email protected]:3] ExecIf(“SIP/501-00002687”, “1?Return()”) in new stack
– Executing [[email protected]:13] Set(“SIP/501-00002687”, “OUTNUM=DIALED#”) in new stack
– Executing [[email protected]:14] Set(“SIP/501-00002687”, “custom=SIP/CharterSIP”) in new stack
– Executing [[email protected]:15] ExecIf(“SIP/501-00002687”, “0?Set(DIAL_TRUNK_OPTIONS=M(setmusic^default)Tt)”) in new stack
– Executing [[email protected]:16] ExecIf(“SIP/501-00002687”, “0?Set(DIAL_TRUNK_OPTIONS=TtM(confirm))”) in new stack
– Executing [[email protected]:17] Macro(“SIP/501-00002687”, “dialout-trunk-predial-hook,”) in new stack
– Executing [[email protected]:1] MacroExit(“SIP/501-00002687”, “”) in new stack
– Executing [[email protected]:18] GotoIf(“SIP/501-00002687”, “0?bypass,1”) in new stack
– Executing [[email protected]:19] ExecIf(“SIP/501-00002687”, “1?Set(CONNECTEDLINE(num,i)=DIALED#)”) in new stack
– Executing [[email protected]:20] ExecIf(“SIP/501-00002687”, “1?Set(CONNECTEDLINE(name,i)=CID:OUTBOUNDCID)”) in new stack
– Executing [[email protected]:21] GotoIf(“SIP/501-00002687”, “0?customtrunk”) in new stack
– Executing [[email protected]:22] Dial(“SIP/501-00002687”, “SIP/CharterSIP/DIALED#,300,Tt”) in new stack
== Using SIP RTP TOS bits 184
== Using SIP RTP CoS mark 5
– Called SIP/CharterSIP/DIALED#
– SIP/CharterSIP-00002688 is making progress passing it to SIP/501-00002687
– SIP/CharterSIP-00002688 answered SIP/501-00002687
– Started music on hold, class ‘default’, on SIP/501-00002687
– <SIP/CharterSIP-00002688> Playing ‘pbx-transfer.ulaw’ (language ‘en’)
features.c: No digits dialed for atxfer.
– <SIP/CharterSIP-00002688> Playing ‘pbx-invalid.ulaw’ (language ‘en’)
– Stopped music on hold on SIP/501-00002687
– Executing [[email protected]:1] Macro(“SIP/501-00002687”, “hangupcall,”) in new stack
– Executing [[email protected]:1] GotoIf(“SIP/501-00002687”, “1?theend”) in new stack
– Goto (macro-hangupcall,s,3)
– Executing [[email protected]:3] ExecIf(“SIP/501-00002687”, “0?Set(CDR(recordingfile)=)”) in new stack
– Executing [[email protected]:4] Hangup(“SIP/501-00002687”, “”) in new stack
== Spawn extension (macro-hangupcall, s, 4) exited non-zero on ‘SIP/501-00002687’ in macro 'hangupcall’
== Spawn extension (macro-dialout-trunk, h, 1) exited non-zero on 'SIP/501-00002687’
== Spawn extension (macro-dialout-trunk, s, 22) exited non-zero on ‘SIP/501-00002687’ in macro 'dialout-trunk’
== Spawn extension (from-internal, DIALED#, 5) exited non-zero on ‘SIP/501-00002687’

rubyred · October 5, 2017, 12:38pm

This appears to be the relevant portion of the logs. Can anyone tell me what is happening here? To me it looks like the first 2 lines are the call being established. Then the user is in the call for 48 seconds and it starts playing hold music on their extension. After that it looks like its attempting a transfer of some kind that fails and plays an invalid message. Then the call is disconnected.

Line 211002: [2017-10-04 12:10:59] VERBOSE[9648][C-00004015] app_dial.c: – SIP/CharterSIP-00002688 is making progress passing it to SIP/501-00002687
Line 211003: [2017-10-04 12:10:59] VERBOSE[9648][C-00004015] app_dial.c: – SIP/CharterSIP-00002688 answered SIP/501-00002687
Line 211454: [2017-10-04 12:11:47] VERBOSE[9648][C-00004015] res_musiconhold.c: – Started music on hold, class ‘default’, on SIP/501-00002687
Line 211455: [2017-10-04 12:11:47] VERBOSE[9648][C-00004015] file.c: – <SIP/CharterSIP-00002688> Playing ‘pbx-transfer.ulaw’ (language ‘en’)
Line 211745: [2017-10-04 12:11:50] WARNING[9648][C-00004015] features.c: No digits dialed for atxfer.
Line 211746: [2017-10-04 12:11:50] VERBOSE[9648][C-00004015] file.c: – <SIP/CharterSIP-00002688> Playing ‘pbx-invalid.ulaw’ (language ‘en’)
Line 211934: [2017-10-04 12:11:55] VERBOSE[9648][C-00004015] res_musiconhold.c: – Stopped music on hold on SIP/501-00002687
Line 212704: [2017-10-04 12:12:42] VERBOSE[9648][C-00004015] pbx.c: – Executing [[email protected]:1] Macro(“SIP/501-00002687”, “hangupcall,”) in new stack

This call in particular the user said they were connected and on hold with the outside party when the hold music played and the call disconnected.

rubyred · October 20, 2017, 2:48pm

Still Experiencing this issue from time to time. Any help would be greatly appreciated.