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

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

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 [h@macro-dialout-trunk: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.

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