Parked calls disconnect after few seconds of MOH

This does not happen all the time - but it does happen regularly, at least once a week.

The person at extension 1002 receives a call, then parks it to go find the person the caller needs to talk to.

The caller hears a few seconds of music on hold then they are disconnected.

I believe I’ve grepped the relevant log entries below. I changed the PBX main number to 4809991234 and the caller’s number to 4809995678.

The asterisk version is 1.8.11-cert5, and FreePBX is 2.10.1.2. There are not analog lines only a VOIP trunk.

Any ideas or help is much appreciated.

Thank you - Richard

[2014-08-29 12:30:19] VERBOSE[1233] pbx.c:     -- Executing [3885@from-sip-external:1] NoOp("SIP/70.182.59.82-00018060", "Received incoming SIP connection from unknown peer to 3885") in new stack
[2014-08-29 12:30:19] VERBOSE[1233] pbx.c:     -- Executing [3885@from-sip-external:2] Set("SIP/70.182.59.82-00018060", "DID=3885") in new stack
[2014-08-29 12:30:19] VERBOSE[1233] pbx.c:     -- Executing [3885@from-sip-external:3] Goto("SIP/70.182.59.82-00018060", "s,1") in new stack
[2014-08-29 12:30:19] VERBOSE[1233] pbx.c:     -- Goto (from-sip-external,s,1)
[2014-08-29 12:30:19] VERBOSE[1233] pbx.c:     -- Executing [s@from-sip-external:1] GotoIf("SIP/70.182.59.82-00018060", "0?checklang:noanonymous") in new stack
[2014-08-29 12:30:19] VERBOSE[1233] pbx.c:     -- Goto (from-sip-external,s,5)
[2014-08-29 12:30:19] VERBOSE[1233] pbx.c:     -- Executing [s@from-sip-external:5] Set("SIP/70.182.59.82-00018060", "TIMEOUT(absolute)=15") in new stack
[2014-08-29 12:30:19] VERBOSE[1233] func_timeout.c: Channel will hangup at 2014-08-29 12:30:34.070 MST.
[2014-08-29 12:30:19] VERBOSE[1233] pbx.c:     -- Executing [s@from-sip-external:6] Answer("SIP/70.182.59.82-00018060", "") in new stack
[2014-08-29 12:30:19] VERBOSE[1233] pbx.c:     -- Executing [s@from-sip-external:7] Wait("SIP/70.182.59.82-00018060", "2") in new stack
[2014-08-29 12:30:21] VERBOSE[1233] pbx.c:     -- Executing [s@from-sip-external:8] Playback("SIP/70.182.59.82-00018060", "ss-noservice") in new stack
[2014-08-29 12:30:21] VERBOSE[1233] file.c:     -- <SIP/70.182.59.82-00018060> Playing 'ss-noservice.gsm' (language 'en')
[2014-08-29 12:30:26] VERBOSE[1233] pbx.c:     -- Executing [s@from-sip-external:9] PlayTones("SIP/70.182.59.82-00018060", "congestion") in new stack
[2014-08-29 12:30:26] VERBOSE[1233] pbx.c:     -- Executing [s@from-sip-external:10] Congestion("SIP/70.182.59.82-00018060", "5") in new stack
[2014-08-29 12:30:31] VERBOSE[1233] pbx.c:   == Spawn extension (from-sip-external, s, 10) exited non-zero on 'SIP/70.182.59.82-00018060'
[2014-08-29 12:30:31] VERBOSE[1233] pbx.c:     -- Executing [h@from-sip-external:1] Hangup("SIP/70.182.59.82-00018060", "") in new stack
[2014-08-29 12:30:31] VERBOSE[1233] pbx.c:   == Spawn extension (from-sip-external, h, 1) exited non-zero on 'SIP/70.182.59.82-00018060'
[2014-08-29 13:04:01] VERBOSE[1233] pbx.c:     -- Executing [35911@from-sip-external:1] NoOp("SIP/70.182.59.82-0001fcda", "Received incoming SIP connection from unknown peer to 35911") in new stack
[2014-08-29 13:04:01] VERBOSE[1233] pbx.c:     -- Executing [35911@from-sip-external:2] Set("SIP/70.182.59.82-0001fcda", "DID=35911") in new stack
[2014-08-29 13:04:01] VERBOSE[1233] pbx.c:     -- Executing [35911@from-sip-external:3] Goto("SIP/70.182.59.82-0001fcda", "s,1") in new stack
[2014-08-29 13:04:01] VERBOSE[1233] pbx.c:     -- Goto (from-sip-external,s,1)
[2014-08-29 13:04:01] VERBOSE[1233] pbx.c:     -- Executing [s@from-sip-external:1] GotoIf("SIP/70.182.59.82-0001fcda", "0?checklang:noanonymous") in new stack
[2014-08-29 13:04:01] VERBOSE[1233] pbx.c:     -- Goto (from-sip-external,s,5)
[2014-08-29 13:04:01] VERBOSE[1233] pbx.c:     -- Executing [s@from-sip-external:5] Set("SIP/70.182.59.82-0001fcda", "TIMEOUT(absolute)=15") in new stack
[2014-08-29 13:04:01] VERBOSE[1233] func_timeout.c: Channel will hangup at 2014-08-29 13:04:16.789 MST.
[2014-08-29 13:04:01] VERBOSE[1233] pbx.c:     -- Executing [s@from-sip-external:6] Answer("SIP/70.182.59.82-0001fcda", "") in new stack
[2014-08-29 13:04:02] VERBOSE[1233] pbx.c:     -- Executing [s@from-sip-external:7] Wait("SIP/70.182.59.82-0001fcda", "2") in new stack
[2014-08-29 13:04:04] VERBOSE[1233] pbx.c:     -- Executing [s@from-sip-external:8] Playback("SIP/70.182.59.82-0001fcda", "ss-noservice") in new stack
[2014-08-29 13:04:04] VERBOSE[1233] file.c:     -- <SIP/70.182.59.82-0001fcda> Playing 'ss-noservice.gsm' (language 'en')
[2014-08-29 13:04:09] VERBOSE[1233] pbx.c:     -- Executing [s@from-sip-external:9] PlayTones("SIP/70.182.59.82-0001fcda", "congestion") in new stack
[2014-08-29 13:04:09] VERBOSE[1233] pbx.c:     -- Executing [s@from-sip-external:10] Congestion("SIP/70.182.59.82-0001fcda", "5") in new stack
[2014-08-29 13:04:14] VERBOSE[1233] pbx.c:   == Spawn extension (from-sip-external, s, 10) exited non-zero on 'SIP/70.182.59.82-0001fcda'
[2014-08-29 13:04:14] VERBOSE[1233] pbx.c:     -- Executing [h@from-sip-external:1] Hangup("SIP/70.182.59.82-0001fcda", "") in new stack
[2014-08-29 13:04:14] VERBOSE[1233] pbx.c:   == Spawn extension (from-sip-external, h, 1) exited non-zero on 'SIP/70.182.59.82-0001fcda'
[2014-08-29 13:33:24] VERBOSE[1233] pbx.c:     -- Executing [67956@from-sip-external:1] NoOp("SIP/70.182.59.82-0002799e", "Received incoming SIP connection from unknown peer to 67956") in new stack
[2014-08-29 13:33:24] VERBOSE[1233] pbx.c:     -- Executing [67956@from-sip-external:2] Set("SIP/70.182.59.82-0002799e", "DID=67956") in new stack
[2014-08-29 13:33:24] VERBOSE[1233] pbx.c:     -- Executing [67956@from-sip-external:3] Goto("SIP/70.182.59.82-0002799e", "s,1") in new stack
[2014-08-29 13:33:24] VERBOSE[1233] pbx.c:     -- Goto (from-sip-external,s,1)
[2014-08-29 13:33:24] VERBOSE[1233] pbx.c:     -- Executing [s@from-sip-external:1] GotoIf("SIP/70.182.59.82-0002799e", "0?checklang:noanonymous") in new stack
[2014-08-29 13:33:24] VERBOSE[1233] pbx.c:     -- Goto (from-sip-external,s,5)
[2014-08-29 13:33:24] VERBOSE[1233] pbx.c:     -- Executing [s@from-sip-external:5] Set("SIP/70.182.59.82-0002799e", "TIMEOUT(absolute)=15") in new stack
[2014-08-29 13:33:24] VERBOSE[1233] func_timeout.c: Channel will hangup at 2014-08-29 13:33:39.894 MST.
[2014-08-29 13:33:24] VERBOSE[1233] pbx.c:     -- Executing [s@from-sip-external:6] Answer("SIP/70.182.59.82-0002799e", "") in new stack
[2014-08-29 13:33:25] VERBOSE[1233] pbx.c:     -- Executing [s@from-sip-external:7] Wait("SIP/70.182.59.82-0002799e", "2") in new stack
[2014-08-29 13:33:27] VERBOSE[1233] pbx.c:     -- Executing [s@from-sip-external:8] Playback("SIP/70.182.59.82-0002799e", "ss-noservice") in new stack
[2014-08-29 13:33:27] VERBOSE[1233] file.c:     -- <SIP/70.182.59.82-0002799e> Playing 'ss-noservice.gsm' (language 'en')
[2014-08-29 13:33:32] VERBOSE[1233] pbx.c:     -- Executing [s@from-sip-external:9] PlayTones("SIP/70.182.59.82-0002799e", "congestion") in new stack
[2014-08-29 13:33:32] VERBOSE[1233] pbx.c:     -- Executing [s@from-sip-external:10] Congestion("SIP/70.182.59.82-0002799e", "5") in new stack
[2014-08-29 13:33:37] VERBOSE[1233] pbx.c:   == Spawn extension (from-sip-external, s, 10) exited non-zero on 'SIP/70.182.59.82-0002799e'
[2014-08-29 13:33:37] VERBOSE[1233] pbx.c:     -- Executing [h@from-sip-external:1] Hangup("SIP/70.182.59.82-0002799e", "") in new stack
[2014-08-29 13:33:37] VERBOSE[1233] pbx.c:   == Spawn extension (from-sip-external, h, 1) exited non-zero on 'SIP/70.182.59.82-0002799e'
[2014-08-29 14:04:24] VERBOSE[1233] pbx.c:     -- Executing [4809991234@from-trunk:1] Set("SIP/Broadvox_LAX_OUT2-0002f653", "__FROM_DID=4809991234") in new stack
[2014-08-29 14:04:24] VERBOSE[1233] pbx.c:     -- Executing [4809991234@from-trunk:2] Gosub("SIP/Broadvox_LAX_OUT2-0002f653", "app-blacklist-check,s,1()") in new stack
[2014-08-29 14:04:24] VERBOSE[1233] pbx.c:     -- Executing [s@app-blacklist-check:1] GotoIf("SIP/Broadvox_LAX_OUT2-0002f653", "0?blacklisted") in new stack
[2014-08-29 14:04:24] VERBOSE[1233] pbx.c:     -- Executing [s@app-blacklist-check:2] Set("SIP/Broadvox_LAX_OUT2-0002f653", "CALLED_BLACKLIST=1") in new stack
[2014-08-29 14:04:24] VERBOSE[1233] pbx.c:     -- Executing [s@app-blacklist-check:3] Return("SIP/Broadvox_LAX_OUT2-0002f653", "") in new stack
[2014-08-29 14:04:24] VERBOSE[1233] pbx.c:     -- Executing [4809991234@from-trunk:3] Set("SIP/Broadvox_LAX_OUT2-0002f653", "CDR(did)=4809991234") in new stack
[2014-08-29 14:04:24] VERBOSE[1233] pbx.c:     -- Executing [4809991234@from-trunk:4] ExecIf("SIP/Broadvox_LAX_OUT2-0002f653", "0 ?Set(CALLERID(name)=4809995678)") in new stack
[2014-08-29 14:04:24] VERBOSE[1233] pbx.c:     -- Executing [4809991234@from-trunk:5] Set("SIP/Broadvox_LAX_OUT2-0002f653", "__CALLINGPRES_SV=allowed_not_screened") in new stack
[2014-08-29 14:04:24] VERBOSE[1233] pbx.c:     -- Executing [4809991234@from-trunk:6] Set("SIP/Broadvox_LAX_OUT2-0002f653", "CALLERPRES()=allowed_not_screened") in new stack
[2014-08-29 14:04:24] VERBOSE[1233] pbx.c:     -- Executing [4809991234@from-trunk:7] Macro("SIP/Broadvox_LAX_OUT2-0002f653", "prepend-cid,DP:") in new stack
[2014-08-29 14:04:24] VERBOSE[1233] pbx.c:     -- Executing [s@macro-prepend-cid:1] GotoIf("SIP/Broadvox_LAX_OUT2-0002f653", "1?REPCID") in new stack
[2014-08-29 14:04:24] VERBOSE[1233] pbx.c:     -- Goto (macro-prepend-cid,s,5)
[2014-08-29 14:04:24] VERBOSE[1233] pbx.c:     -- Executing [s@macro-prepend-cid:5] Set("SIP/Broadvox_LAX_OUT2-0002f653", "_RGPREFIX=DP:") in new stack
[2014-08-29 14:04:24] VERBOSE[1233] pbx.c:     -- Executing [s@macro-prepend-cid:6] Set("SIP/Broadvox_LAX_OUT2-0002f653", "CALLERID(name)=DP:4809995678") in new stack
[2014-08-29 14:04:24] VERBOSE[1233] pbx.c:     -- Executing [4809991234@from-trunk:8] Goto("SIP/Broadvox_LAX_OUT2-0002f653", "timeconditions,2,1") in new stack
[2014-08-29 14:04:24] VERBOSE[1233] pbx.c:     -- Goto (timeconditions,2,1)
[2014-08-29 14:04:24] VERBOSE[1233] pbx.c:     -- Executing [2@timeconditions:1] GotoIfTime("SIP/Broadvox_LAX_OUT2-0002f653", "10:00-18:00,mon-fri,*,*?truestate") in new stack
[2014-08-29 14:04:24] VERBOSE[1233] pbx.c:     -- Goto (timeconditions,2,7)
[2014-08-29 14:04:24] VERBOSE[1233] pbx.c:     -- Executing [2@timeconditions:7] GotoIf("SIP/Broadvox_LAX_OUT2-0002f653", "0?falsegoto") in new stack
[2014-08-29 14:04:24] VERBOSE[1233] pbx.c:     -- Executing [2@timeconditions:8] ExecIf("SIP/Broadvox_LAX_OUT2-0002f653", "0?Set(DB(TC/2)=)") in new stack
[2014-08-29 14:04:24] VERBOSE[1233] pbx.c:     -- Executing [2@timeconditions:9] GotoIf("SIP/Broadvox_LAX_OUT2-0002f653", "1?ext-group,620,1") in new stack
[2014-08-29 14:04:24] VERBOSE[1233] pbx.c:     -- Goto (ext-group,620,1)
[2014-08-29 14:04:24] VERBOSE[1233] pbx.c:     -- Executing [620@ext-group:1] Macro("SIP/Broadvox_LAX_OUT2-0002f653", "user-callerid,") in new stack
[2014-08-29 14:04:24] VERBOSE[1233] pbx.c:     -- Executing [s@macro-user-callerid:1] Set("SIP/Broadvox_LAX_OUT2-0002f653", "AMPUSER=4809995678") in new stack
[2014-08-29 14:04:24] VERBOSE[1233] pbx.c:     -- Executing [s@macro-user-callerid:2] GotoIf("SIP/Broadvox_LAX_OUT2-0002f653", "0?report") in new stack
[2014-08-29 14:04:24] VERBOSE[1233] pbx.c:     -- Executing [s@macro-user-callerid:3] ExecIf("SIP/Broadvox_LAX_OUT2-0002f653", "1?Set(REALCALLERIDNUM=4809995678)") in new stack
[2014-08-29 14:04:24] VERBOSE[1233] pbx.c:     -- Executing [s@macro-user-callerid:4] Set("SIP/Broadvox_LAX_OUT2-0002f653", "AMPUSER=") in new stack
[2014-08-29 14:04:24] VERBOSE[1233] pbx.c:     -- Executing [s@macro-user-callerid:5] Set("SIP/Broadvox_LAX_OUT2-0002f653", "AMPUSERCIDNAME=") in new stack
[2014-08-29 14:04:24] VERBOSE[1233] pbx.c:     -- Executing [s@macro-user-callerid:6] GotoIf("SIP/Broadvox_LAX_OUT2-0002f653", "1?report") in new stack
[2014-08-29 14:04:24] VERBOSE[1233] pbx.c:     -- Goto (macro-user-callerid,s,13)
[2014-08-29 14:04:24] VERBOSE[1233] pbx.c:     -- Executing [s@macro-user-callerid:13] GotoIf("SIP/Broadvox_LAX_OUT2-0002f653", "0?continue") in new stack
[2014-08-29 14:04:24] VERBOSE[1233] pbx.c:     -- Executing [s@macro-user-callerid:14] Set("SIP/Broadvox_LAX_OUT2-0002f653", "__TTL=64") in new stack
[2014-08-29 14:04:24] VERBOSE[1233] pbx.c:     -- Executing [s@macro-user-callerid:15] GotoIf("SIP/Broadvox_LAX_OUT2-0002f653", "1?continue") in new stack
[2014-08-29 14:04:24] VERBOSE[1233] pbx.c:     -- Goto (macro-user-callerid,s,26)
[2014-08-29 14:04:24] VERBOSE[1233] pbx.c:     -- Executing [s@macro-user-callerid:26] Set("SIP/Broadvox_LAX_OUT2-0002f653", "CALLERID(number)=4809995678") in new stack
[2014-08-29 14:04:24] VERBOSE[1233] pbx.c:     -- Executing [s@macro-user-callerid:27] Set("SIP/Broadvox_LAX_OUT2-0002f653", "CALLERID(name)=DP:4809995678") in new stack
[2014-08-29 14:04:24] VERBOSE[1233] pbx.c:     -- Executing [s@macro-user-callerid:28] Set("SIP/Broadvox_LAX_OUT2-0002f653", "CHANNEL(language)=en") in new stack
[2014-08-29 14:04:24] VERBOSE[1233] pbx.c:     -- Executing [620@ext-group:2] Macro("SIP/Broadvox_LAX_OUT2-0002f653", "blkvm-setifempty,") in new stack
[2014-08-29 14:04:24] VERBOSE[1233] pbx.c:     -- Executing [s@macro-blkvm-setifempty:1] GotoIf("SIP/Broadvox_LAX_OUT2-0002f653", "1?init") in new stack
[2014-08-29 14:04:24] VERBOSE[1233] pbx.c:     -- Goto (macro-blkvm-setifempty,s,4)
[2014-08-29 14:04:24] VERBOSE[1233] pbx.c:     -- Executing [s@macro-blkvm-setifempty:4] Set("SIP/Broadvox_LAX_OUT2-0002f653", "__BLKVM_CHANNEL=SIP/Broadvox_LAX_OUT2-0002f653") in new stack
[2014-08-29 14:04:24] VERBOSE[1233] pbx.c:     -- Executing [s@macro-blkvm-setifempty:5] Set("SIP/Broadvox_LAX_OUT2-0002f653", "SHARED(BLKVM,SIP/Broadvox_LAX_OUT2-0002f653)=TRUE") in new stack
[2014-08-29 14:04:24] VERBOSE[1233] pbx.c:     -- Executing [s@macro-blkvm-setifempty:6] Set("SIP/Broadvox_LAX_OUT2-0002f653", "GOSUB_RETVAL=TRUE") in new stack
[2014-08-29 14:04:24] VERBOSE[1233] pbx.c:     -- Executing [s@macro-blkvm-setifempty:7] MacroExit("SIP/Broadvox_LAX_OUT2-0002f653", "") in new stack
[2014-08-29 14:04:24] VERBOSE[1233] pbx.c:     -- Executing [620@ext-group:3] GotoIf("SIP/Broadvox_LAX_OUT2-0002f653", "1?skipov") in new stack
[2014-08-29 14:04:24] VERBOSE[1233] pbx.c:     -- Goto (ext-group,620,6)
[2014-08-29 14:04:24] VERBOSE[1233] pbx.c:     -- Executing [620@ext-group:6] Set("SIP/Broadvox_LAX_OUT2-0002f653", "RRNODEST=") in new stack
[2014-08-29 14:04:24] VERBOSE[1233] pbx.c:     -- Executing [620@ext-group:7] Set("SIP/Broadvox_LAX_OUT2-0002f653", "__NODEST=620") in new stack
[2014-08-29 14:04:24] VERBOSE[1233] pbx.c:     -- Executing [620@ext-group:8] GosubIf("SIP/Broadvox_LAX_OUT2-0002f653", "0?sub-rgsetcid,s,1()") in new stack
[2014-08-29 14:04:24] VERBOSE[1233] pbx.c:     -- Executing [620@ext-group:9] Gosub("SIP/Broadvox_LAX_OUT2-0002f653", "sub-record-check,s,1(rg,620,dontcare)") in new stack
[2014-08-29 14:04:24] VERBOSE[1233] pbx.c:     -- Executing [s@sub-record-check:1] GotoIf("SIP/Broadvox_LAX_OUT2-0002f653", "1?check") in new stack
[2014-08-29 14:04:24] VERBOSE[1233] pbx.c:     -- Goto (sub-record-check,s,6)
[2014-08-29 14:04:24] VERBOSE[1233] pbx.c:     -- Executing [s@sub-record-check:6] Set("SIP/Broadvox_LAX_OUT2-0002f653", "__MON_FMT=wav") in new stack
[2014-08-29 14:04:24] VERBOSE[1233] pbx.c:     -- Executing [s@sub-record-check:7] GotoIf("SIP/Broadvox_LAX_OUT2-0002f653", "1?next") in new stack
[2014-08-29 14:04:24] VERBOSE[1233] pbx.c:     -- Goto (sub-record-check,s,10)
[2014-08-29 14:04:24] VERBOSE[1233] pbx.c:     -- Executing [s@sub-record-check:10] ExecIf("SIP/Broadvox_LAX_OUT2-0002f653", "0?Return()") in new stack
[2014-08-29 14:04:24] VERBOSE[1233] pbx.c:     -- Executing [s@sub-record-check:11] GotoIf("SIP/Broadvox_LAX_OUT2-0002f653", "0?rg,1") in new stack
[2014-08-29 14:04:24] VERBOSE[1233] pbx.c:     -- Executing [s@sub-record-check:12] Set("SIP/Broadvox_LAX_OUT2-0002f653", "__REC_STATUS=INITIALIZED") in new stack
[2014-08-29 14:04:24] VERBOSE[1233] pbx.c:     -- Executing [s@sub-record-check:13] ExecIf("SIP/Broadvox_LAX_OUT2-0002f653", "1?Set(__REC_POLICY_MODE=dontcare)") in new stack
[2014-08-29 14:04:24] VERBOSE[1233] pbx.c:     -- Executing [s@sub-record-check:14] Set("SIP/Broadvox_LAX_OUT2-0002f653", "NOW=1409346264") in new stack
[2014-08-29 14:04:24] VERBOSE[1233] pbx.c:     -- Executing [s@sub-record-check:15] Set("SIP/Broadvox_LAX_OUT2-0002f653", "__DAY=29") in new stack
[2014-08-29 14:04:24] VERBOSE[1233] pbx.c:     -- Executing [s@sub-record-check:16] Set("SIP/Broadvox_LAX_OUT2-0002f653", "__MONTH=08") in new stack
[2014-08-29 14:04:24] VERBOSE[1233] pbx.c:     -- Executing [s@sub-record-check:17] Set("SIP/Broadvox_LAX_OUT2-0002f653", "__YEAR=2014") in new stack
[2014-08-29 14:04:24] VERBOSE[1233] pbx.c:     -- Executing [s@sub-record-check:18] Set("SIP/Broadvox_LAX_OUT2-0002f653", "__TIMESTR=20140829-140424") in new stack
[2014-08-29 14:04:24] VERBOSE[1233] pbx.c:     -- Executing [s@sub-record-check:19] Set("SIP/Broadvox_LAX_OUT2-0002f653", "__FROMEXTEN=4809995678") in new stack
[2014-08-29 14:04:24] VERBOSE[1233] pbx.c:     -- Executing [s@sub-record-check:20] Set("SIP/Broadvox_LAX_OUT2-0002f653", "__CALLFILENAME=rg-620-4809995678-20140829-140424-1409346264.194134") in new stack
[2014-08-29 14:04:24] VERBOSE[1233] pbx.c:     -- Executing [s@sub-record-check:21] Goto("SIP/Broadvox_LAX_OUT2-0002f653", "rg,1") in new stack
[2014-08-29 14:04:24] VERBOSE[1233] pbx.c:     -- Goto (sub-record-check,rg,1)
[2014-08-29 14:04:24] VERBOSE[1233] pbx.c:     -- Executing [rg@sub-record-check:1] GosubIf("SIP/Broadvox_LAX_OUT2-0002f653", "0?record,1(rg,dontcare,4809995678)") in new stack
[2014-08-29 14:04:24] VERBOSE[1233] pbx.c:     -- Executing [rg@sub-record-check:2] Return("SIP/Broadvox_LAX_OUT2-0002f653", "") in new stack
[2014-08-29 14:04:24] VERBOSE[1233] pbx.c:     -- Executing [620@ext-group:10] Set("SIP/Broadvox_LAX_OUT2-0002f653", "RingGroupMethod=ringall") in new stack
[2014-08-29 14:04:24] VERBOSE[1233] pbx.c:     -- Executing [620@ext-group:11] Macro("SIP/Broadvox_LAX_OUT2-0002f653", "dial,20,tr,1002-1005") in new stack
[2014-08-29 14:04:24] VERBOSE[1233] pbx.c:     -- Executing [s@macro-dial:1] GotoIf("SIP/Broadvox_LAX_OUT2-0002f653", "1?dial") in new stack
[2014-08-29 14:04:24] VERBOSE[1233] pbx.c:     -- Goto (macro-dial,s,3)
[2014-08-29 14:04:24] VERBOSE[1233] pbx.c:     -- Executing [s@macro-dial:3] AGI("SIP/Broadvox_LAX_OUT2-0002f653", "dialparties.agi") in new stack
[2014-08-29 14:04:24] VERBOSE[1233] res_agi.c:     -- Launched AGI Script /var/lib/asterisk/agi-bin/dialparties.agi
[2014-08-29 14:04:24] VERBOSE[1233] res_agi.c:  dialparties.agi: Starting New Dialparties.agi
[2014-08-29 14:04:24] VERBOSE[1233] res_agi.c:  dialparties.agi: Caller ID name is 'DP:4809995678' number is '4809995678'
[2014-08-29 14:04:24] VERBOSE[1233] res_agi.c:  dialparties.agi: Methodology of ring is  'ringall'
[2014-08-29 14:04:24] VERBOSE[1233] res_agi.c:     -- dialparties.agi: Added extension 1002 to extension map
[2014-08-29 14:04:24] VERBOSE[1233] res_agi.c:     -- dialparties.agi: Added extension 1005 to extension map
[2014-08-29 14:04:24] VERBOSE[1233] res_agi.c:     -- dialparties.agi: Extension 1002 cf is disabled
[2014-08-29 14:04:24] VERBOSE[1233] res_agi.c:     -- dialparties.agi: Extension 1005 cf is disabled
[2014-08-29 14:04:24] VERBOSE[1233] res_agi.c:     -- dialparties.agi: Extension 1002 do not disturb is disabled
[2014-08-29 14:04:24] VERBOSE[1233] res_agi.c:     -- dialparties.agi: Extension 1005 do not disturb is disabled
[2014-08-29 14:04:24] VERBOSE[1233] res_agi.c:     -- dialparties.agi: dbset CALLTRACE/1002 to 4809995678
[2014-08-29 14:04:24] VERBOSE[1233] res_agi.c:     -- dialparties.agi: dbset CALLTRACE/1005 to 4809995678
[2014-08-29 14:04:24] VERBOSE[1233] res_agi.c:     -- dialparties.agi: Filtered ARG3: 1002-1005
[2014-08-29 14:04:24] VERBOSE[1233] res_agi.c:     -- <SIP/Broadvox_LAX_OUT2-0002f653>AGI Script dialparties.agi completed, returning 0
[2014-08-29 14:04:24] VERBOSE[1233] pbx.c:     -- Executing [s@macro-dial:7] Dial("SIP/Broadvox_LAX_OUT2-0002f653", "SIP/1002&SIP/1005,20,trM(auto-blkvm)") in new stack
[2014-08-29 14:04:24] VERBOSE[1233] netsock2.c:   == Using SIP RTP TOS bits 184
[2014-08-29 14:04:24] VERBOSE[1233] netsock2.c:   == Using SIP RTP CoS mark 5
[2014-08-29 14:04:24] VERBOSE[1233] app_dial.c:     -- Called SIP/1002
[2014-08-29 14:04:24] VERBOSE[1233] netsock2.c:   == Using SIP RTP TOS bits 184
[2014-08-29 14:04:24] VERBOSE[1233] netsock2.c:   == Using SIP RTP CoS mark 5
[2014-08-29 14:04:24] VERBOSE[1233] app_dial.c:     -- Called SIP/1005
[2014-08-29 14:04:24] VERBOSE[1233] app_dial.c:     -- SIP/1002-0002f654 connected line has changed. Saving it until answer for SIP/Broadvox_LAX_OUT2-0002f653
[2014-08-29 14:04:24] VERBOSE[1233] app_dial.c:     -- SIP/1005-0002f655 connected line has changed. Saving it until answer for SIP/Broadvox_LAX_OUT2-0002f653
[2014-08-29 14:04:24] VERBOSE[1233] app_dial.c:     -- SIP/1002-0002f654 is ringing
[2014-08-29 14:04:24] VERBOSE[1233] app_dial.c:     -- SIP/1005-0002f655 is ringing
[2014-08-29 14:04:31] VERBOSE[1233] app_dial.c:     -- SIP/1002-0002f654 connected line has changed. Saving it until answer for SIP/Broadvox_LAX_OUT2-0002f653
[2014-08-29 14:04:31] VERBOSE[1233] app_dial.c:     -- SIP/1002-0002f654 answered SIP/Broadvox_LAX_OUT2-0002f653
[2014-08-29 14:04:31] VERBOSE[1233] pbx.c:     -- Executing [s@macro-auto-blkvm:1] Set("SIP/1002-0002f654", "__MACRO_RESULT=") in new stack
[2014-08-29 14:04:31] VERBOSE[1233] pbx.c:     -- Executing [s@macro-auto-blkvm:2] Macro("SIP/1002-0002f654", "blkvm-clr,") in new stack
[2014-08-29 14:04:31] VERBOSE[1233] pbx.c:     -- Executing [s@macro-blkvm-clr:1] Set("SIP/1002-0002f654", "SHARED(BLKVM,SIP/Broadvox_LAX_OUT2-0002f653)=") in new stack
[2014-08-29 14:04:31] VERBOSE[1233] pbx.c:     -- Executing [s@macro-blkvm-clr:2] Set("SIP/1002-0002f654", "GOSUB_RETVAL=") in new stack
[2014-08-29 14:04:31] VERBOSE[1233] pbx.c:     -- Executing [s@macro-blkvm-clr:3] MacroExit("SIP/1002-0002f654", "") in new stack
[2014-08-29 14:04:31] VERBOSE[1233] pbx.c:     -- Executing [s@macro-auto-blkvm:3] ExecIf("SIP/1002-0002f654", "0?Set(MASTER_CHANNEL(CONNECTEDLINE(num))=1002)") in new stack
[2014-08-29 14:04:31] VERBOSE[1233] pbx.c:     -- Executing [s@macro-auto-blkvm:4] ExecIf("SIP/1002-0002f654", "0?Set(MASTER_CHANNEL(CONNECTEDLINE(name))=Jane Doe)") in new stack
[2014-08-29 14:04:47] VERBOSE[1233] res_musiconhold.c:     -- Started music on hold, class 'default', on SIP/Broadvox_LAX_OUT2-0002f653
[2014-08-29 14:04:57] VERBOSE[1233] res_musiconhold.c:     -- Stopped music on hold on SIP/Broadvox_LAX_OUT2-0002f653
[2014-08-29 14:04:59] VERBOSE[1233] pbx.c:     -- Executing [h@macro-dial:1] Macro("Parking/SIP/Broadvox_LAX_OUT2-0002f653<ZOMBIE>", "hangupcall") in new stack
[2014-08-29 14:04:59] VERBOSE[1233] pbx.c:     -- Executing [s@macro-hangupcall:1] GotoIf("Parking/SIP/Broadvox_LAX_OUT2-0002f653<ZOMBIE>", "1?theend") in new stack
[2014-08-29 14:04:59] VERBOSE[1233] pbx.c:     -- Goto (macro-hangupcall,s,3)
[2014-08-29 14:04:59] VERBOSE[1233] pbx.c:     -- Executing [s@macro-hangupcall:3] ExecIf("Parking/SIP/Broadvox_LAX_OUT2-0002f653<ZOMBIE>", "0?Set(CDR(recordingfile)=)") in new stack
[2014-08-29 14:04:59] VERBOSE[1233] pbx.c:     -- Executing [s@macro-hangupcall:4] Hangup("Parking/SIP/Broadvox_LAX_OUT2-0002f653<ZOMBIE>", "") in new stack
[2014-08-29 14:04:59] VERBOSE[1233] app_macro.c:   == Spawn extension (macro-hangupcall, s, 4) exited non-zero on 'Parking/SIP/Broadvox_LAX_OUT2-0002f653<ZOMBIE>' in macro 'hangupcall'
[2014-08-29 14:04:59] VERBOSE[1233] features.c:   == Spawn extension (macro-dial, h, 1) exited non-zero on 'Parking/SIP/Broadvox_LAX_OUT2-0002f653<ZOMBIE>'
[2014-08-29 14:04:59] VERBOSE[1233] app_macro.c:   == Spawn extension (macro-dial, s, 7) exited non-zero on 'Parking/SIP/Broadvox_LAX_OUT2-0002f653<ZOMBIE>' in macro 'dial'
[2014-08-29 14:04:59] VERBOSE[1233] pbx.c:   == Spawn extension (ext-group, 620, 11) exited non-zero on 'Parking/SIP/Broadvox_LAX_OUT2-0002f653<ZOMBIE>'

I have yet to figure out how things ZOMBIE… I had and have the same thing happen sometimes when transferring to a queue. I can’t deliberately recreate it, but I get complaints about it.

Kinda easy
[2014-08-29 14:04:31] VERBOSE[1233] app_dial.c: – SIP/1002-0002f654 connected line has changed. Saving it until answer for SIP/Broadvox_LAX_OUT2-0002f653
[2014-08-29 14:04:31] VERBOSE[1233] app_dial.c: – SIP/1002-0002f654 answered SIP/Broadvox_LAX_OUT2-0002f653

and then

Set(MASTER_CHANNEL(CONNECTEDLINE(name))=Jane Doe)") in new stack
[2014-08-29 14:04:47] VERBOSE[1233] res_musiconhold.c: – Started music on hold, class ‘default’, on SIP/Broadvox_LAX_OUT2-0002f653
[2014-08-29 14:04:57] VERBOSE[1233] res_musiconhold.c: – Stopped music on hold on SIP/Broadvox_LAX_OUT2-0002f653
[2014-08-29 14:04:59] VERBOSE[1233] pbx.c: – Executing [h@macro-dial:1] Macro(“Parking/SIP/Broadvox_LAX_OUT2-0002f653”, “hangupcall”) in new stack
[2014-08-29 14:04:59] VERBOSE[1233] pbx.c: – Executing [s@macro-hangupcall:1] GotoIf(“Parking/SIP/Broadvox_LAX_OUT2-0002f653”, "1?

The channel (the party that called you) hungup while you had it in MOH. sometime between [2014-08-29 14:04:47] and [2014-08-29 14:04:57]

Yes, you are right - that’s easy to see. But the person that called insists they did not hang up,they were disconnected. We’ve verified this when it’s happened other times.

So, I guess short of Asterisk having gremlins inside, it’s time to look at the SIP trunk and see if that is the cause.

I has seen this topic mentioned in a couple of different places, but never saw a good answer. Just wanted to make sure there was not something simple I was missing.

Thank you