Can't reach by DID, but can by Extension

dwoods · April 2, 2014, 3:01pm

System running 5.211.65-9, all modules up to date as of Saturday (29-March).

We currently have a branch location in a nearby city that is tied into our PBX. Starting this week if we dial them by DID or they try us by DID, you will hear one, maybe two rings, then seems to answer with dead air, then disconnect after about 3-4 seconds. If they dial a direct extension or we try to reach them by extension, the calls goes through just fine.

Their DID is setup to ring all phones in their office through a ring group, and if no one answers after x period of time, it goes to a Misc Destination that is setup.

I assume that this occurred after I performed updates this past weekend, but cannot verify. The first it was brought to my attention was yesterday (tuesday). Prior to this past weekend, we were able to call their DID and they us without any issues.

Here is what I think is all the log output for a call from me to them. All help is appreciated.

[2014-04-02 09:24:40] VERBOSE[14683][C-000005a1] pbx.c: – Executing [95128737770@from-internal:1] Macro(“SIP/510-00000a86”, “user-callerid,LIMIT,EXTERNAL,”) in new stack
[2014-04-02 09:24:40] VERBOSE[14683][C-000005a1] pbx.c: – Executing [s@macro-user-callerid:1] Set(“SIP/510-00000a86”, “TOUCH_MONITOR=1396448680.2705”) in new stack
[2014-04-02 09:24:40] VERBOSE[14683][C-000005a1] pbx.c: – Executing [s@macro-user-callerid:2] Set(“SIP/510-00000a86”, “AMPUSER=510”) in new stack
[2014-04-02 09:24:40] VERBOSE[14683][C-000005a1] pbx.c: – Executing [s@macro-user-callerid:3] GotoIf(“SIP/510-00000a86”, “0?report”) in new stack
[2014-04-02 09:24:40] VERBOSE[14683][C-000005a1] pbx.c: – Executing [s@macro-user-callerid:4] ExecIf(“SIP/510-00000a86”, “1?Set(REALCALLERIDNUM=510)”) in new stack
[2014-04-02 09:24:40] VERBOSE[14683][C-000005a1] pbx.c: – Executing [s@macro-user-callerid:5] Set(“SIP/510-00000a86”, “AMPUSER=510”) in new stack
[2014-04-02 09:24:40] VERBOSE[14683][C-000005a1] pbx.c: – Executing [s@macro-user-callerid:6] GotoIf(“SIP/510-00000a86”, “0?limit”) in new stack
[2014-04-02 09:24:40] VERBOSE[14683][C-000005a1] pbx.c: – Executing [s@macro-user-callerid:7] Set(“SIP/510-00000a86”, “AMPUSERCIDNAME=Darrin Woods”) in new stack
[2014-04-02 09:24:40] VERBOSE[14683][C-000005a1] pbx.c: – Executing [s@macro-user-callerid:8] GotoIf(“SIP/510-00000a86”, “0?report”) in new stack
[2014-04-02 09:24:40] VERBOSE[14683][C-000005a1] pbx.c: – Executing [s@macro-user-callerid:9] Set(“SIP/510-00000a86”, “AMPUSERCID=510”) in new stack
[2014-04-02 09:24:40] VERBOSE[14683][C-000005a1] pbx.c: – Executing [s@macro-user-callerid:10] Set(“SIP/510-00000a86”, “__DIAL_OPTIONS=Ttr”) in new stack
[2014-04-02 09:24:40] VERBOSE[14683][C-000005a1] pbx.c: – Executing [s@macro-user-callerid:11] Set(“SIP/510-00000a86”, “CALLERID(all)=“Darrin Woods” <510>”) in new stack
[2014-04-02 09:24:40] VERBOSE[14683][C-000005a1] pbx.c: – Executing [s@macro-user-callerid:12] GotoIf(“SIP/510-00000a86”, “0?limit”) in new stack
[2014-04-02 09:24:40] VERBOSE[14683][C-000005a1] pbx.c: – Executing [s@macro-user-callerid:13] ExecIf(“SIP/510-00000a86”, “1?Set(GROUP(concurrency_limit)=510)”) in new stack
[2014-04-02 09:24:40] VERBOSE[14683][C-000005a1] pbx.c: – Executing [s@macro-user-callerid:14] GosubIf(“SIP/510-00000a86”, “7?sub-ccss,s,1(from-internal,95128737770)”) in new stack
[2014-04-02 09:24:40] VERBOSE[14683][C-000005a1] pbx.c: – Executing [s@sub-ccss:1] ExecIf(“SIP/510-00000a86”, “0?Return()”) in new stack
[2014-04-02 09:24:40] VERBOSE[14683][C-000005a1] pbx.c: – Executing [s@sub-ccss:2] Set(“SIP/510-00000a86”, “CCSS_SETUP=TRUE”) in new stack
[2014-04-02 09:24:40] VERBOSE[14683][C-000005a1] pbx.c: – Executing [s@sub-ccss:3] GosubIf(“SIP/510-00000a86”, “0?monitor_config,1(from-internal,95128737770):monitor_default,1(from-internal,95128737770)”) in new stack
[2014-04-02 09:24:40] VERBOSE[14683][C-000005a1] pbx.c: – Executing [monitor_default@sub-ccss:1] GotoIf(“SIP/510-00000a86”, “0?is_exten”) in new stack
[2014-04-02 09:24:40] VERBOSE[14683][C-000005a1] pbx.c: – Executing [monitor_default@sub-ccss:2] StackPop(“SIP/510-00000a86”, “”) in new stack
[2014-04-02 09:24:40] VERBOSE[14683][C-000005a1] pbx.c: – Executing [monitor_default@sub-ccss:3] Return(“SIP/510-00000a86”, “FALSE”) in new stack
[2014-04-02 09:24:40] VERBOSE[14683][C-000005a1] pbx.c: – Executing [s@macro-user-callerid:15] ExecIf(“SIP/510-00000a86”, “0?Set(CHANNEL(language)=)”) in new stack
[2014-04-02 09:24:40] VERBOSE[14683][C-000005a1] pbx.c: – Executing [s@macro-user-callerid:16] GotoIf(“SIP/510-00000a86”, “1?continue”) in new stack
[2014-04-02 09:24:40] VERBOSE[14683][C-000005a1] pbx.c: – Goto (macro-user-callerid,s,29)
[2014-04-02 09:24:40] VERBOSE[14683][C-000005a1] pbx.c: – Executing [s@macro-user-callerid:29] Set(“SIP/510-00000a86”, “CALLERID(number)=510”) in new stack
[2014-04-02 09:24:40] VERBOSE[14683][C-000005a1] pbx.c: – Executing [s@macro-user-callerid:30] Set(“SIP/510-00000a86”, “CALLERID(name)=Darrin Woods”) in new stack
[2014-04-02 09:24:40] VERBOSE[14683][C-000005a1] pbx.c: – Executing [s@macro-user-callerid:31] Set(“SIP/510-00000a86”, “CDR(cnum)=510”) in new stack
[2014-04-02 09:24:40] VERBOSE[14683][C-000005a1] pbx.c: – Executing [s@macro-user-callerid:32] Set(“SIP/510-00000a86”, “CDR(cnam)=Darrin Woods”) in new stack
[2014-04-02 09:24:40] VERBOSE[14683][C-000005a1] pbx.c: – Executing [s@macro-user-callerid:33] Set(“SIP/510-00000a86”, “CHANNEL(language)=en”) in new stack
[2014-04-02 09:24:40] VERBOSE[14683][C-000005a1] pbx.c: – Executing [95128737770@from-internal:2] Set(“SIP/510-00000a86”, “MOHCLASS=default”) in new stack
[2014-04-02 09:24:40] VERBOSE[14683][C-000005a1] pbx.c: – Executing [95128737770@from-internal:3] Set(“SIP/510-00000a86”, “_NODEST=”) in new stack
[2014-04-02 09:24:40] VERBOSE[14683][C-000005a1] pbx.c: – Executing [95128737770@from-internal:4] Gosub(“SIP/510-00000a86”, “sub-record-check,s,1(out,95128737770,)”) in new stack
[2014-04-02 09:24:40] VERBOSE[14683][C-000005a1] pbx.c: – Executing [s@sub-record-check:1] Set(“SIP/510-00000a86”, “REC_POLICY_MODE_SAVE=”) in new stack
[2014-04-02 09:24:40] VERBOSE[14683][C-000005a1] pbx.c: – Executing [s@sub-record-check:2] GotoIf(“SIP/510-00000a86”, “1?check”) in new stack
[2014-04-02 09:24:40] VERBOSE[14683][C-000005a1] pbx.c: – Goto (sub-record-check,s,7)
[2014-04-02 09:24:40] VERBOSE[14683][C-000005a1] pbx.c: – Executing [s@sub-record-check:7] Set(“SIP/510-00000a86”, “__MON_FMT=wav”) in new stack
[2014-04-02 09:24:40] VERBOSE[14683][C-000005a1] pbx.c: – Executing [s@sub-record-check:8] GotoIf(“SIP/510-00000a86”, “1?next”) in new stack
[2014-04-02 09:24:40] VERBOSE[14683][C-000005a1] pbx.c: – Goto (sub-record-check,s,11)
[2014-04-02 09:24:40] VERBOSE[14683][C-000005a1] pbx.c: – Executing [s@sub-record-check:11] ExecIf(“SIP/510-00000a86”, “0?Return()”) in new stack
[2014-04-02 09:24:40] VERBOSE[14683][C-000005a1] pbx.c: – Executing [s@sub-record-check:12] ExecIf(“SIP/510-00000a86”, “0?Set(__REC_POLICY_MODE=)”) in new stack
[2014-04-02 09:24:40] VERBOSE[14683][C-000005a1] pbx.c: – Executing [s@sub-record-check:13] GotoIf(“SIP/510-00000a86”, “0?out,1”) in new stack
[2014-04-02 09:24:40] VERBOSE[14683][C-000005a1] pbx.c: – Executing [s@sub-record-check:14] Set(“SIP/510-00000a86”, “__REC_STATUS=INITIALIZED”) in new stack
[2014-04-02 09:24:40] VERBOSE[14683][C-000005a1] pbx.c: – Executing [s@sub-record-check:15] Set(“SIP/510-00000a86”, “NOW=1396448680”) in new stack
[2014-04-02 09:24:40] VERBOSE[14683][C-000005a1] pbx.c: – Executing [s@sub-record-check:16] Set(“SIP/510-00000a86”, “__DAY=02”) in new stack
[2014-04-02 09:24:40] VERBOSE[14683][C-000005a1] pbx.c: – Executing [s@sub-record-check:17] Set(“SIP/510-00000a86”, “__MONTH=04”) in new stack
[2014-04-02 09:24:40] VERBOSE[14683][C-000005a1] pbx.c: – Executing [s@sub-record-check:18] Set(“SIP/510-00000a86”, “__YEAR=2014”) in new stack
[2014-04-02 09:24:40] VERBOSE[14683][C-000005a1] pbx.c: – Executing [s@sub-record-check:19] Set(“SIP/510-00000a86”, “__TIMESTR=20140402-092440”) in new stack
[2014-04-02 09:24:40] VERBOSE[14683][C-000005a1] pbx.c: – Executing [s@sub-record-check:20] Set(“SIP/510-00000a86”, “__FROMEXTEN=510”) in new stack
[2014-04-02 09:24:40] VERBOSE[14683][C-000005a1] pbx.c: – Executing [s@sub-record-check:21] Set(“SIP/510-00000a86”, “__CALLFILENAME=out-95128737770-510-20140402-092440-1396448680.2705”) in new stack
[2014-04-02 09:24:40] VERBOSE[14683][C-000005a1] pbx.c: – Executing [s@sub-record-check:22] Goto(“SIP/510-00000a86”, “out,1”) in new stack
[2014-04-02 09:24:40] VERBOSE[14683][C-000005a1] pbx.c: – Goto (sub-record-check,out,1)
[2014-04-02 09:24:40] VERBOSE[14683][C-000005a1] pbx.c: – Executing [out@sub-record-check:1] ExecIf(“SIP/510-00000a86”, “1?Set(__REC_POLICY_MODE=dontcare)”) in new stack
[2014-04-02 09:24:40] VERBOSE[14683][C-000005a1] pbx.c: – Executing [out@sub-record-check:2] GosubIf(“SIP/510-00000a86”, “0?record,1(exten,95128737770,510)”) in new stack
[2014-04-02 09:24:40] VERBOSE[14683][C-000005a1] pbx.c: – Executing [out@sub-record-check:3] Return(“SIP/510-00000a86”, “”) in new stack
[2014-04-02 09:24:40] VERBOSE[14683][C-000005a1] pbx.c: – Executing [95128737770@from-internal:5] Macro(“SIP/510-00000a86”, “dialout-trunk,1,5128737770,off”) in new stack
[2014-04-02 09:24:40] VERBOSE[14683][C-000005a1] pbx.c: – Executing [s@macro-dialout-trunk:1] Set(“SIP/510-00000a86”, “DIAL_TRUNK=1”) in new stack
[2014-04-02 09:24:40] VERBOSE[14683][C-000005a1] pbx.c: – Executing [s@macro-dialout-trunk:2] GosubIf(“SIP/510-00000a86”, “0?sub-pincheck,s,1()”) in new stack
[2014-04-02 09:24:40] VERBOSE[14683][C-000005a1] pbx.c: – Executing [s@macro-dialout-trunk:3] GotoIf(“SIP/510-00000a86”, “0?disabletrunk,1”) in new stack
[2014-04-02 09:24:40] VERBOSE[14683][C-000005a1] pbx.c: – Executing [s@macro-dialout-trunk:4] Set(“SIP/510-00000a86”, “DIAL_NUMBER=5128737770”) in new stack
[2014-04-02 09:24:40] VERBOSE[14683][C-000005a1] pbx.c: – Executing [s@macro-dialout-trunk:5] Set(“SIP/510-00000a86”, “DIAL_TRUNK_OPTIONS=Ttr”) in new stack
[2014-04-02 09:24:40] VERBOSE[14683][C-000005a1] pbx.c: – Executing [s@macro-dialout-trunk:6] Set(“SIP/510-00000a86”, “OUTBOUND_GROUP=OUT_1”) in new stack
[2014-04-02 09:24:40] VERBOSE[14683][C-000005a1] pbx.c: – Executing [s@macro-dialout-trunk:7] GotoIf(“SIP/510-00000a86”, “1?nomax”) in new stack
[2014-04-02 09:24:40] VERBOSE[14683][C-000005a1] pbx.c: – Goto (macro-dialout-trunk,s,9)
[2014-04-02 09:24:40] VERBOSE[14683][C-000005a1] pbx.c: – Executing [s@macro-dialout-trunk:9] GotoIf(“SIP/510-00000a86”, “0?skipoutcid”) in new stack
[2014-04-02 09:24:40] VERBOSE[14683][C-000005a1] pbx.c: – Executing [s@macro-dialout-trunk:10] Set(“SIP/510-00000a86”, “DIAL_TRUNK_OPTIONS=Tt”) in new stack
[2014-04-02 09:24:40] VERBOSE[14683][C-000005a1] pbx.c: – Executing [s@macro-dialout-trunk:11] Macro(“SIP/510-00000a86”, “outbound-callerid,1”) in new stack
[2014-04-02 09:24:40] VERBOSE[14683][C-000005a1] pbx.c: – Executing [s@macro-outbound-callerid:1] ExecIf(“SIP/510-00000a86”, “0?Set(CALLERPRES()=)”) in new stack
[2014-04-02 09:24:40] VERBOSE[14683][C-000005a1] pbx.c: – Executing [s@macro-outbound-callerid:2] ExecIf(“SIP/510-00000a86”, “0?Set(REALCALLERIDNUM=510)”) in new stack
[2014-04-02 09:24:40] VERBOSE[14683][C-000005a1] pbx.c: – Executing [s@macro-outbound-callerid:3] GotoIf(“SIP/510-00000a86”, “1?normcid”) in new stack
[2014-04-02 09:24:40] VERBOSE[14683][C-000005a1] pbx.c: – Goto (macro-outbound-callerid,s,6)
[2014-04-02 09:24:40] VERBOSE[14683][C-000005a1] pbx.c: – Executing [s@macro-outbound-callerid:6] Set(“SIP/510-00000a86”, “USEROUTCID=“Darrin Woods” <5124913510>”) in new stack
[2014-04-02 09:24:40] VERBOSE[14683][C-000005a1] pbx.c: – Executing [s@macro-outbound-callerid:7] Set(“SIP/510-00000a86”, “EMERGENCYCID=5124913500”) in new stack
[2014-04-02 09:24:40] VERBOSE[14683][C-000005a1] pbx.c: – Executing [s@macro-outbound-callerid:8] Set(“SIP/510-00000a86”, “TRUNKOUTCID=5124913500”) in new stack
[2014-04-02 09:24:40] VERBOSE[14683][C-000005a1] pbx.c: – Executing [s@macro-outbound-callerid:9] GotoIf(“SIP/510-00000a86”, “1?trunkcid”) in new stack
[2014-04-02 09:24:40] VERBOSE[14683][C-000005a1] pbx.c: – Goto (macro-outbound-callerid,s,14)
[2014-04-02 09:24:40] VERBOSE[14683][C-000005a1] pbx.c: – Executing [s@macro-outbound-callerid:14] ExecIf(“SIP/510-00000a86”, “1?Set(CALLERID(all)=5124913500)”) in new stack
[2014-04-02 09:24:40] VERBOSE[14683][C-000005a1] pbx.c: – Executing [s@macro-outbound-callerid:15] ExecIf(“SIP/510-00000a86”, “1?Set(CALLERID(all)=“Darrin Woods” <5124913510>)”) in new stack
[2014-04-02 09:24:40] VERBOSE[14683][C-000005a1] pbx.c: – Executing [s@macro-outbound-callerid:16] ExecIf(“SIP/510-00000a86”, “0?Set(CALLERID(all)=)”) in new stack
[2014-04-02 09:24:40] VERBOSE[14683][C-000005a1] pbx.c: – Executing [s@macro-outbound-callerid:17] ExecIf(“SIP/510-00000a86”, “0?Set(CALLERPRES()=prohib_passed_screen)”) in new stack
[2014-04-02 09:24:40] VERBOSE[14683][C-000005a1] pbx.c: – Executing [s@macro-outbound-callerid:18] Set(“SIP/510-00000a86”, “CDR(outbound_cnum)=5124913510”) in new stack
[2014-04-02 09:24:40] VERBOSE[14683][C-000005a1] pbx.c: – Executing [s@macro-outbound-callerid:19] Set(“SIP/510-00000a86”, “CDR(outbound_cnam)=Darrin Woods”) in new stack
[2014-04-02 09:24:40] VERBOSE[14683][C-000005a1] pbx.c: – Executing [s@macro-dialout-trunk:12] GosubIf(“SIP/510-00000a86”, “0?sub-flp-1,s,1()”) in new stack
[2014-04-02 09:24:40] VERBOSE[14683][C-000005a1] pbx.c: – Executing [s@macro-dialout-trunk:13] Set(“SIP/510-00000a86”, “OUTNUM=5128737770”) in new stack
[2014-04-02 09:24:40] VERBOSE[14683][C-000005a1] pbx.c: – Executing [s@macro-dialout-trunk:14] Set(“SIP/510-00000a86”, “custom=SIP/fpbx-1-3f3d4e15”) in new stack
[2014-04-02 09:24:40] VERBOSE[14683][C-000005a1] pbx.c: – Executing [s@macro-dialout-trunk:15] ExecIf(“SIP/510-00000a86”, “0?Set(DIAL_TRUNK_OPTIONS=M(setmusic^default)Tt)”) in new stack
[2014-04-02 09:24:40] VERBOSE[14683][C-000005a1] pbx.c: – Executing [s@macro-dialout-trunk:16] ExecIf(“SIP/510-00000a86”, “0?Set(DIAL_TRUNK_OPTIONS=TtM(confirm))”) in new stack
[2014-04-02 09:24:40] VERBOSE[14683][C-000005a1] pbx.c: – Executing [s@macro-dialout-trunk:17] Macro(“SIP/510-00000a86”, “dialout-trunk-predial-hook,”) in new stack
[2014-04-02 09:24:40] VERBOSE[14683][C-000005a1] pbx.c: – Executing [s@macro-dialout-trunk-predial-hook:1] MacroExit(“SIP/510-00000a86”, “”) in new stack
[2014-04-02 09:24:40] VERBOSE[14683][C-000005a1] pbx.c: – Executing [s@macro-dialout-trunk:18] GotoIf(“SIP/510-00000a86”, “0?bypass,1”) in new stack
[2014-04-02 09:24:40] VERBOSE[14683][C-000005a1] pbx.c: – Executing [s@macro-dialout-trunk:19] ExecIf(“SIP/510-00000a86”, “1?Set(CONNECTEDLINE(num,i)=5128737770)”) in new stack
[2014-04-02 09:24:40] VERBOSE[14683][C-000005a1] pbx.c: – Executing [s@macro-dialout-trunk:20] ExecIf(“SIP/510-00000a86”, “1?Set(CONNECTEDLINE(name,i)=CID:5124913510)”) in new stack
[2014-04-02 09:24:40] VERBOSE[14683][C-000005a1] pbx.c: – Executing [s@macro-dialout-trunk:21] GotoIf(“SIP/510-00000a86”, “0?customtrunk”) in new stack
[2014-04-02 09:24:40] VERBOSE[14683][C-000005a1] pbx.c: – Executing [s@macro-dialout-trunk:22] Dial(“SIP/510-00000a86”, “SIP/fpbx-1-3f3d4e15/5128737770,300,Tt”) in new stack
[2014-04-02 09:24:40] VERBOSE[14683][C-000005a1] netsock2.c: == Using SIP RTP TOS bits 184
[2014-04-02 09:24:40] VERBOSE[14683][C-000005a1] netsock2.c: == Using SIP RTP CoS mark 5
[2014-04-02 09:24:40] VERBOSE[14683][C-000005a1] app_dial.c: – Called SIP/fpbx-1-3f3d4e15/5128737770

[2014-04-02 09:24:43] VERBOSE[14684][C-000005a2] pbx.c: – Executing [5128737770@from-pstn:1] Set(“SIP/fpbx-1-3f3d4e15-00000a88”, “__FROM_DID=5128737770”) in new stack
[2014-04-02 09:24:43] VERBOSE[14684][C-000005a2] pbx.c: – Executing [5128737770@from-pstn:2] Gosub(“SIP/fpbx-1-3f3d4e15-00000a88”, “app-blacklist-check,s,1()”) in new stack
[2014-04-02 09:24:43] VERBOSE[14684][C-000005a2] pbx.c: – Executing [s@app-blacklist-check:1] GotoIf(“SIP/fpbx-1-3f3d4e15-00000a88”, “0?blacklisted”) in new stack
[2014-04-02 09:24:43] VERBOSE[14684][C-000005a2] pbx.c: – Executing [s@app-blacklist-check:2] Set(“SIP/fpbx-1-3f3d4e15-00000a88”, “CALLED_BLACKLIST=1”) in new stack
[2014-04-02 09:24:43] VERBOSE[14684][C-000005a2] pbx.c: – Executing [s@app-blacklist-check:3] Return(“SIP/fpbx-1-3f3d4e15-00000a88”, “”) in new stack
[2014-04-02 09:24:43] VERBOSE[14684][C-000005a2] pbx.c: – Executing [5128737770@from-pstn:3] Set(“SIP/fpbx-1-3f3d4e15-00000a88”, “CDR(did)=5128737770”) in new stack
[2014-04-02 09:24:43] VERBOSE[14684][C-000005a2] pbx.c: – Executing [5128737770@from-pstn:4] Gosub(“SIP/fpbx-1-3f3d4e15-00000a88”, “cidlookup,cidlookup_2,1()”) in new stack
[2014-04-02 09:24:43] VERBOSE[14684][C-000005a2] pbx.c: – Executing [cidlookup_2@cidlookup:1] Set(“SIP/fpbx-1-3f3d4e15-00000a88”, “CURLOPT(httptimeout)=7”) in new stack
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] pbx.c: – Executing [cidlookup_2@cidlookup:2] Set(“SIP/fpbx-1-3f3d4e15-00000a88”, “CALLERID(name)=”) in new stack
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] pbx.c: – Executing [cidlookup_2@cidlookup:3] Set(“SIP/fpbx-1-3f3d4e15-00000a88”, “current_hour=2014-04-02 09”) in new stack
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] pbx.c: – Executing [cidlookup_2@cidlookup:4] Set(“SIP/fpbx-1-3f3d4e15-00000a88”, “last_query_hour=2014-04-02 08”) in new stack
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] pbx.c: – Executing [cidlookup_2@cidlookup:5] Set(“SIP/fpbx-1-3f3d4e15-00000a88”, “total_hourly_queries=5”) in new stack
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] pbx.c: – Executing [cidlookup_2@cidlookup:6] ExecIf(“SIP/fpbx-1-3f3d4e15-00000a88”, “1?Set(DB(cidlookup/opencnam_total_hourly_queries)=0)”) in new stack
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] pbx.c: – Executing [cidlookup_2@cidlookup:7] ExecIf(“SIP/fpbx-1-3f3d4e15-00000a88”, “0?Set(DB(cidlookup/opencnam_total_hourly_queries)=0)”) in new stack
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] pbx.c: – Executing [cidlookup_2@cidlookup:8] Set(“SIP/fpbx-1-3f3d4e15-00000a88”, “DB(cidlookup/opencnam_total_hourly_queries)=1”) in new stack
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] pbx.c: – Executing [cidlookup_2@cidlookup:9] ExecIf(“SIP/fpbx-1-3f3d4e15-00000a88”, “0?System(/var/lib/asterisk/bin/opencnam-alert.php)”) in new stack
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] pbx.c: – Executing [cidlookup_2@cidlookup:10] Set(“SIP/fpbx-1-3f3d4e15-00000a88”, “DB(cidlookup/opencnam_last_query_hour)=2014-04-02 09”) in new stack
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] pbx.c: – Executing [cidlookup_2@cidlookup:11] Return(“SIP/fpbx-1-3f3d4e15-00000a88”, “”) in new stack
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] pbx.c: – Executing [5128737770@from-pstn:5] ExecIf(“SIP/fpbx-1-3f3d4e15-00000a88”, “1 ?Set(CALLERID(name)=15124913510)”) in new stack
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] pbx.c: – Executing [5128737770@from-pstn:6] Set(“SIP/fpbx-1-3f3d4e15-00000a88”, “CHANNEL(musicclass)=default”) in new stack
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] pbx.c: – Executing [5128737770@from-pstn:7] Set(“SIP/fpbx-1-3f3d4e15-00000a88”, “__MOHCLASS=default”) in new stack
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] pbx.c: – Executing [5128737770@from-pstn:8] Set(“SIP/fpbx-1-3f3d4e15-00000a88”, “__CALLINGPRES_SV=allowed_not_screened”) in new stack
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] pbx.c: – Executing [5128737770@from-pstn:9] Set(“SIP/fpbx-1-3f3d4e15-00000a88”, “CALLERPRES()=allowed_not_screened”) in new stack
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] pbx.c: – Executing [5128737770@from-pstn:10] Goto(“SIP/fpbx-1-3f3d4e15-00000a88”, “ext-group,177,1”) in new stack
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] pbx.c: – Goto (ext-group,177,1)
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] pbx.c: – Executing [177@ext-group:1] Macro(“SIP/fpbx-1-3f3d4e15-00000a88”, “user-callerid,”) in new stack
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] pbx.c: – Executing [s@macro-user-callerid:1] Set(“SIP/fpbx-1-3f3d4e15-00000a88”, “TOUCH_MONITOR=1396448683.2707”) in new stack
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] pbx.c: – Executing [s@macro-user-callerid:2] Set(“SIP/fpbx-1-3f3d4e15-00000a88”, “AMPUSER=15124913510”) in new stack
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] pbx.c: – Executing [s@macro-user-callerid:3] GotoIf(“SIP/fpbx-1-3f3d4e15-00000a88”, “0?report”) in new stack
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] pbx.c: – Executing [s@macro-user-callerid:4] ExecIf(“SIP/fpbx-1-3f3d4e15-00000a88”, “1?Set(REALCALLERIDNUM=15124913510)”) in new stack
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] pbx.c: – Executing [s@macro-user-callerid:5] Set(“SIP/fpbx-1-3f3d4e15-00000a88”, “AMPUSER=”) in new stack
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] pbx.c: – Executing [s@macro-user-callerid:6] GotoIf(“SIP/fpbx-1-3f3d4e15-00000a88”, “0?limit”) in new stack
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] pbx.c: – Executing [s@macro-user-callerid:7] Set(“SIP/fpbx-1-3f3d4e15-00000a88”, “AMPUSERCIDNAME=”) in new stack
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] pbx.c: – Executing [s@macro-user-callerid:8] GotoIf(“SIP/fpbx-1-3f3d4e15-00000a88”, “1?report”) in new stack
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] pbx.c: – Goto (macro-user-callerid,s,16)
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] pbx.c: – Executing [s@macro-user-callerid:16] GotoIf(“SIP/fpbx-1-3f3d4e15-00000a88”, “0?continue”) in new stack
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] pbx.c: – Executing [s@macro-user-callerid:17] Set(“SIP/fpbx-1-3f3d4e15-00000a88”, “__TTL=64”) in new stack
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] pbx.c: – Executing [s@macro-user-callerid:18] GotoIf(“SIP/fpbx-1-3f3d4e15-00000a88”, “1?continue”) in new stack
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] pbx.c: – Goto (macro-user-callerid,s,29)
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] pbx.c: – Executing [s@macro-user-callerid:29] Set(“SIP/fpbx-1-3f3d4e15-00000a88”, “CALLERID(number)=15124913510”) in new stack
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] pbx.c: – Executing [s@macro-user-callerid:30] Set(“SIP/fpbx-1-3f3d4e15-00000a88”, “CALLERID(name)=15124913510”) in new stack
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] pbx.c: – Executing [s@macro-user-callerid:31] Set(“SIP/fpbx-1-3f3d4e15-00000a88”, “CDR(cnum)=15124913510”) in new stack
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] pbx.c: – Executing [s@macro-user-callerid:32] Set(“SIP/fpbx-1-3f3d4e15-00000a88”, “CDR(cnam)=15124913510”) in new stack
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] pbx.c: – Executing [s@macro-user-callerid:33] Set(“SIP/fpbx-1-3f3d4e15-00000a88”, “CHANNEL(language)=en”) in new stack
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] pbx.c: – Executing [177@ext-group:2] Macro(“SIP/fpbx-1-3f3d4e15-00000a88”, “blkvm-setifempty,”) in new stack
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] pbx.c: – Executing [s@macro-blkvm-setifempty:1] GotoIf(“SIP/fpbx-1-3f3d4e15-00000a88”, “1?init”) in new stack
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] pbx.c: – Goto (macro-blkvm-setifempty,s,4)
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] pbx.c: – Executing [s@macro-blkvm-setifempty:4] Set(“SIP/fpbx-1-3f3d4e15-00000a88”, “__BLKVM_CHANNEL=SIP/fpbx-1-3f3d4e15-00000a88”) in new stack
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] pbx.c: – Executing [s@macro-blkvm-setifempty:5] Set(“SIP/fpbx-1-3f3d4e15-00000a88”, “SHARED(BLKVM,SIP/fpbx-1-3f3d4e15-00000a88)=TRUE”) in new stack
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] pbx.c: – Executing [s@macro-blkvm-setifempty:6] Set(“SIP/fpbx-1-3f3d4e15-00000a88”, “GOSUB_RETVAL=TRUE”) in new stack
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] pbx.c: – Executing [s@macro-blkvm-setifempty:7] MacroExit(“SIP/fpbx-1-3f3d4e15-00000a88”, “”) in new stack
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] pbx.c: – Executing [177@ext-group:3] GotoIf(“SIP/fpbx-1-3f3d4e15-00000a88”, “1?skipov”) in new stack
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] pbx.c: – Goto (ext-group,177,6)
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] pbx.c: – Executing [177@ext-group:6] Set(“SIP/fpbx-1-3f3d4e15-00000a88”, “RRNODEST=”) in new stack
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] pbx.c: – Executing [177@ext-group:7] Set(“SIP/fpbx-1-3f3d4e15-00000a88”, “__NODEST=177”) in new stack
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] pbx.c: – Executing [177@ext-group:8] GosubIf(“SIP/fpbx-1-3f3d4e15-00000a88”, “0?sub-rgsetcid,s,1()”) in new stack
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] pbx.c: – Executing [177@ext-group:9] Gosub(“SIP/fpbx-1-3f3d4e15-00000a88”, “sub-record-check,s,1(rg,177,dontcare)”) in new stack
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] pbx.c: – Executing [s@sub-record-check:1] Set(“SIP/fpbx-1-3f3d4e15-00000a88”, “REC_POLICY_MODE_SAVE=”) in new stack
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] pbx.c: – Executing [s@sub-record-check:2] GotoIf(“SIP/fpbx-1-3f3d4e15-00000a88”, “1?check”) in new stack
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] pbx.c: – Goto (sub-record-check,s,7)
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] pbx.c: – Executing [s@sub-record-check:7] Set(“SIP/fpbx-1-3f3d4e15-00000a88”, “__MON_FMT=wav”) in new stack
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] pbx.c: – Executing [s@sub-record-check:8] GotoIf(“SIP/fpbx-1-3f3d4e15-00000a88”, “1?next”) in new stack
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] pbx.c: – Goto (sub-record-check,s,11)
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] pbx.c: – Executing [s@sub-record-check:11] ExecIf(“SIP/fpbx-1-3f3d4e15-00000a88”, “0?Return()”) in new stack
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] pbx.c: – Executing [s@sub-record-check:12] ExecIf(“SIP/fpbx-1-3f3d4e15-00000a88”, “1?Set(__REC_POLICY_MODE=dontcare)”) in new stack
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] pbx.c: – Executing [s@sub-record-check:13] GotoIf(“SIP/fpbx-1-3f3d4e15-00000a88”, “0?rg,1”) in new stack
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] pbx.c: – Executing [s@sub-record-check:14] Set(“SIP/fpbx-1-3f3d4e15-00000a88”, “__REC_STATUS=INITIALIZED”) in new stack
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] pbx.c: – Executing [s@sub-record-check:15] Set(“SIP/fpbx-1-3f3d4e15-00000a88”, “NOW=1396448684”) in new stack
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] pbx.c: – Executing [s@sub-record-check:16] Set(“SIP/fpbx-1-3f3d4e15-00000a88”, “__DAY=02”) in new stack
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] pbx.c: – Executing [s@sub-record-check:17] Set(“SIP/fpbx-1-3f3d4e15-00000a88”, “__MONTH=04”) in new stack
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] pbx.c: – Executing [s@sub-record-check:18] Set(“SIP/fpbx-1-3f3d4e15-00000a88”, “__YEAR=2014”) in new stack
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] pbx.c: – Executing [s@sub-record-check:19] Set(“SIP/fpbx-1-3f3d4e15-00000a88”, “__TIMESTR=20140402-092444”) in new stack
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] pbx.c: – Executing [s@sub-record-check:20] Set(“SIP/fpbx-1-3f3d4e15-00000a88”, “__FROMEXTEN=15124913510”) in new stack
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] pbx.c: – Executing [s@sub-record-check:21] Set(“SIP/fpbx-1-3f3d4e15-00000a88”, “__CALLFILENAME=rg-177-15124913510-20140402-092444-1396448683.2707”) in new stack
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] pbx.c: – Executing [s@sub-record-check:22] Goto(“SIP/fpbx-1-3f3d4e15-00000a88”, “rg,1”) in new stack
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] pbx.c: – Goto (sub-record-check,rg,1)
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] pbx.c: – Executing [rg@sub-record-check:1] GosubIf(“SIP/fpbx-1-3f3d4e15-00000a88”, “0?record,1(rg,dontcare,15124913510)”) in new stack
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] pbx.c: – Executing [rg@sub-record-check:2] Return(“SIP/fpbx-1-3f3d4e15-00000a88”, “”) in new stack
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] pbx.c: – Executing [177@ext-group:10] Set(“SIP/fpbx-1-3f3d4e15-00000a88”, “RingGroupMethod=ringall”) in new stack
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] pbx.c: – Executing [177@ext-group:11] Macro(“SIP/fpbx-1-3f3d4e15-00000a88”, “dial,15,Ttr,200-201-202-203-204-205”) in new stack
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] pbx.c: – Executing [s@macro-dial:1] GotoIf(“SIP/fpbx-1-3f3d4e15-00000a88”, “0?dial”) in new stack
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] pbx.c: – Executing [s@macro-dial:2] SetMusicOnHold(“SIP/fpbx-1-3f3d4e15-00000a88”, “default”) in new stack
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] pbx.c: – Executing [s@macro-dial:3] AGI(“SIP/fpbx-1-3f3d4e15-00000a88”, “dialparties.agi”) in new stack
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] res_agi.c: – Launched AGI Script /var/lib/asterisk/agi-bin/dialparties.agi
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] res_agi.c: dialparties.agi: Starting New Dialparties.agi
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] res_agi.c: dialparties.agi: Caller ID name is ‘15124913510’ number is ‘15124913510’
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] res_agi.c: dialparties.agi: Methodology of ring is ‘ringall’
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] res_agi.c: – dialparties.agi: Added extension 200 to extension map
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] res_agi.c: – dialparties.agi: Added extension 201 to extension map
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] res_agi.c: – dialparties.agi: Added extension 202 to extension map
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] res_agi.c: – dialparties.agi: Added extension 203 to extension map
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] res_agi.c: – dialparties.agi: Added extension 204 to extension map
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] res_agi.c: – dialparties.agi: Added extension 205 to extension map
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] res_agi.c: – dialparties.agi: Extension 200 cf is disabled
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] res_agi.c: – dialparties.agi: Extension 201 cf is disabled
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] res_agi.c: – dialparties.agi: Extension 202 cf is disabled
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] res_agi.c: – dialparties.agi: Extension 203 cf is disabled
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] res_agi.c: – dialparties.agi: Extension 204 cf is disabled
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] res_agi.c: – dialparties.agi: Extension 205 cf is disabled
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] res_agi.c: – dialparties.agi: Extension 200 do not disturb is disabled
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] res_agi.c: – dialparties.agi: Extension 201 do not disturb is disabled
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] res_agi.c: – dialparties.agi: Extension 202 do not disturb is disabled
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] res_agi.c: – dialparties.agi: Extension 203 do not disturb is disabled
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] res_agi.c: – dialparties.agi: Extension 204 do not disturb is disabled
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] res_agi.c: – dialparties.agi: Extension 205 do not disturb is disabled
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] res_agi.c: – dialparties.agi: dbset CALLTRACE/200 to 15124913510
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] res_agi.c: – dialparties.agi: dbset CALLTRACE/201 to 15124913510
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] res_agi.c: – dialparties.agi: dbset CALLTRACE/202 to 15124913510
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] res_agi.c: – dialparties.agi: dbset CALLTRACE/203 to 15124913510
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] res_agi.c: – dialparties.agi: dbset CALLTRACE/204 to 15124913510
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] res_agi.c: – dialparties.agi: dbset CALLTRACE/205 to 15124913510
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] res_agi.c: – dialparties.agi: Filtered ARG3: 200-201-202-203-204-205
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] res_agi.c: – <SIP/fpbx-1-3f3d4e15-00000a88>AGI Script dialparties.agi completed, returning 0
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] pbx.c: – Executing [s@macro-dial:7] Dial(“SIP/fpbx-1-3f3d4e15-00000a88”, “SIP/200&SIP/201&SIP/202&SIP/203&SIP/204&SIP/205,15,TtrM(auto-blkvm)”) in new stack
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] netsock2.c: == Using SIP RTP TOS bits 184
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] netsock2.c: == Using SIP RTP CoS mark 5
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] netsock2.c: == Using SIP RTP TOS bits 184
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] netsock2.c: == Using SIP RTP CoS mark 5
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] netsock2.c: == Using SIP RTP TOS bits 184
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] netsock2.c: == Using SIP RTP CoS mark 5
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] netsock2.c: == Using SIP RTP TOS bits 184
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] netsock2.c: == Using SIP RTP CoS mark 5
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] netsock2.c: == Using SIP RTP TOS bits 184
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] netsock2.c: == Using SIP RTP CoS mark 5
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] netsock2.c: == Using SIP RTP TOS bits 184
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] netsock2.c: == Using SIP RTP CoS mark 5
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] app_dial.c: – Called SIP/200
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] app_dial.c: – Called SIP/201
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] app_dial.c: – Called SIP/202
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] app_dial.c: – Called SIP/203
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] app_dial.c: – Called SIP/204
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] app_dial.c: – Called SIP/205
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] app_dial.c: – SIP/205-00000a8e connected line has changed. Saving it until answer for SIP/fpbx-1-3f3d4e15-00000a88
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] app_dial.c: – SIP/204-00000a8d connected line has changed. Saving it until answer for SIP/fpbx-1-3f3d4e15-00000a88
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] app_dial.c: – SIP/203-00000a8c connected line has changed. Saving it until answer for SIP/fpbx-1-3f3d4e15-00000a88
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] app_dial.c: – SIP/202-00000a8b connected line has changed. Saving it until answer for SIP/fpbx-1-3f3d4e15-00000a88
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] app_dial.c: – SIP/201-00000a8a connected line has changed. Saving it until answer for SIP/fpbx-1-3f3d4e15-00000a88
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] app_dial.c: – SIP/200-00000a89 connected line has changed. Saving it until answer for SIP/fpbx-1-3f3d4e15-00000a88
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] app_dial.c: – SIP/202-00000a8b is ringing
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] app_dial.c: – SIP/203-00000a8c is ringing
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] app_dial.c: – SIP/200-00000a89 is ringing
[2014-04-02 09:24:44] VERBOSE[14683][C-000005a1] app_dial.c: – SIP/fpbx-1-3f3d4e15-00000a87 is ringing
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] app_dial.c: – SIP/205-00000a8e is ringing
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] app_dial.c: – SIP/204-00000a8d is ringing
[2014-04-02 09:24:44] VERBOSE[14684][C-000005a2] app_dial.c: – SIP/201-00000a8a is ringing
[2014-04-02 09:24:49] VERBOSE[14684][C-000005a2] app_dial.c: – SIP/200-00000a89 connected line has changed. Saving it until answer for SIP/fpbx-1-3f3d4e15-00000a88
[2014-04-02 09:24:49] VERBOSE[14684][C-000005a2] app_dial.c: – SIP/200-00000a89 answered SIP/fpbx-1-3f3d4e15-00000a88
[2014-04-02 09:24:49] VERBOSE[14684][C-000005a2] pbx.c: – Executing [s@macro-auto-blkvm:1] Set(“SIP/200-00000a89”, “__MACRO_RESULT=”) in new stack
[2014-04-02 09:24:49] VERBOSE[14684][C-000005a2] pbx.c: – Executing [s@macro-auto-blkvm:2] Set(“SIP/200-00000a89”, “CFIGNORE=”) in new stack
[2014-04-02 09:24:49] VERBOSE[14684][C-000005a2] pbx.c: – Executing [s@macro-auto-blkvm:3] Set(“SIP/200-00000a89”, “MASTER_CHANNEL(CFIGNORE)=”) in new stack
[2014-04-02 09:24:49] VERBOSE[14684][C-000005a2] pbx.c: – Executing [s@macro-auto-blkvm:4] Set(“SIP/200-00000a89”, “FORWARD_CONTEXT=from-internal”) in new stack
[2014-04-02 09:24:49] VERBOSE[14684][C-000005a2] pbx.c: – Executing [s@macro-auto-blkvm:5] Set(“SIP/200-00000a89”, “MASTER_CHANNEL(FORWARD_CONTEXT)=from-internal”) in new stack
[2014-04-02 09:24:49] VERBOSE[14684][C-000005a2] pbx.c: – Executing [s@macro-auto-blkvm:6] Macro(“SIP/200-00000a89”, “blkvm-clr,”) in new stack
[2014-04-02 09:24:49] VERBOSE[14684][C-000005a2] pbx.c: – Executing [s@macro-blkvm-clr:1] Set(“SIP/200-00000a89”, “SHARED(BLKVM,SIP/fpbx-1-3f3d4e15-00000a88)=”) in new stack
[2014-04-02 09:24:49] VERBOSE[14684][C-000005a2] pbx.c: – Executing [s@macro-blkvm-clr:2] Set(“SIP/200-00000a89”, “GOSUB_RETVAL=”) in new stack
[2014-04-02 09:24:49] VERBOSE[14684][C-000005a2] pbx.c: – Executing [s@macro-blkvm-clr:3] MacroExit(“SIP/200-00000a89”, “”) in new stack
[2014-04-02 09:24:49] VERBOSE[14684][C-000005a2] pbx.c: – Executing [s@macro-auto-blkvm:7] ExecIf(“SIP/200-00000a89”, “0?Set(MASTER_CHANNEL(CONNECTEDLINE(num))=200)”) in new stack
[2014-04-02 09:24:49] VERBOSE[14684][C-000005a2] pbx.c: – Executing [s@macro-auto-blkvm:8] ExecIf(“SIP/200-00000a89”, “0?Set(MASTER_CHANNEL(CONNECTEDLINE(name))=BR 177 Main)”) in new stack
[2014-04-02 09:24:49] VERBOSE[14683][C-000005a1] app_dial.c: – SIP/fpbx-1-3f3d4e15-00000a87 answered SIP/510-00000a86
[2014-04-02 09:25:00] VERBOSE[14684][C-000005a2] pbx.c: – Executing [h@macro-dial:1] Macro(“SIP/fpbx-1-3f3d4e15-00000a88”, “hangupcall”) in new stack
[2014-04-02 09:25:00] VERBOSE[14684][C-000005a2] pbx.c: – Executing [s@macro-hangupcall:1] GotoIf(“SIP/fpbx-1-3f3d4e15-00000a88”, “1?theend”) in new stack
[2014-04-02 09:25:00] VERBOSE[14684][C-000005a2] pbx.c: – Goto (macro-hangupcall,s,3)
[2014-04-02 09:25:00] VERBOSE[14684][C-000005a2] pbx.c: – Executing [s@macro-hangupcall:3] ExecIf(“SIP/fpbx-1-3f3d4e15-00000a88”, “0?Set(CDR(recordingfile)=)”) in new stack
[2014-04-02 09:25:00] VERBOSE[14684][C-000005a2] pbx.c: – Executing [s@macro-hangupcall:4] Hangup(“SIP/fpbx-1-3f3d4e15-00000a88”, “”) in new stack
[2014-04-02 09:25:00] VERBOSE[14684][C-000005a2] app_macro.c: == Spawn extension (macro-hangupcall, s, 4) exited non-zero on ‘SIP/fpbx-1-3f3d4e15-00000a88’ in macro ‘hangupcall’
[2014-04-02 09:25:00] VERBOSE[14684][C-000005a2] pbx.c: == Spawn extension (macro-dial, h, 1) exited non-zero on ‘SIP/fpbx-1-3f3d4e15-00000a88’
[2014-04-02 09:25:00] VERBOSE[14684][C-000005a2] app_macro.c: == Spawn extension (macro-dial, s, 7) exited non-zero on ‘SIP/fpbx-1-3f3d4e15-00000a88’ in macro ‘dial’
[2014-04-02 09:25:00] VERBOSE[14684][C-000005a2] pbx.c: == Spawn extension (ext-group, 177, 11) exited non-zero on ‘SIP/fpbx-1-3f3d4e15-00000a88’
[2014-04-02 09:25:00] VERBOSE[14683][C-000005a1] pbx.c: – Executing [h@macro-dialout-trunk:1] Macro(“SIP/510-00000a86”, “hangupcall,”) in new stack
[2014-04-02 09:25:00] VERBOSE[14683][C-000005a1] pbx.c: – Executing [s@macro-hangupcall:1] GotoIf(“SIP/510-00000a86”, “1?theend”) in new stack
[2014-04-02 09:25:00] VERBOSE[14683][C-000005a1] pbx.c: – Goto (macro-hangupcall,s,3)
[2014-04-02 09:25:00] VERBOSE[14683][C-000005a1] pbx.c: – Executing [s@macro-hangupcall:3] ExecIf(“SIP/510-00000a86”, “0?Set(CDR(recordingfile)=)”) in new stack
[2014-04-02 09:25:00] VERBOSE[14683][C-000005a1] pbx.c: – Executing [s@macro-hangupcall:4] Hangup(“SIP/510-00000a86”, “”) in new stack
[2014-04-02 09:25:00] VERBOSE[14683][C-000005a1] app_macro.c: == Spawn extension (macro-hangupcall, s, 4) exited non-zero on ‘SIP/510-00000a86’ in macro ‘hangupcall’
[2014-04-02 09:25:00] VERBOSE[14683][C-000005a1] pbx.c: == Spawn extension (macro-dialout-trunk, h, 1) exited non-zero on ‘SIP/510-00000a86’
[2014-04-02 09:25:00] VERBOSE[14683][C-000005a1] app_macro.c: == Spawn extension (macro-dialout-trunk, s, 22) exited non-zero on ‘SIP/510-00000a86’ in macro ‘dialout-trunk’
[2014-04-02 09:25:00] VERBOSE[14683][C-000005a1] pbx.c: == Spawn extension (from-internal, 95128737770, 5) exited non-zero on ‘SIP/510-00000a86’

dwoods · April 3, 2014, 2:55pm

So I’m now told that this issue has been going on for weeks without anyone mentioning it. After some testing it appears that anytime you dial a DID that is handled by the PBX from an extension connected to the PBX, the signaling (ring / off-hook, on-hook) all goes end to end, but there is no voice traffic that goes end to end.

I can’t say that this also isn’t some sort of firewall issue since our PBX is offsite and we’ve been doing a lot of changes to the firewall to deal with an Oracle issue, but I’m not seeing any dropped packets at either end.

I’m pretty sure this used to work, but don’t know if its a bug within Asterisk/FPBX or something that we’ve changed on the firewall.

Outbound calls and those coming in from the outside world work just fine and we have no problems dialing an extension and talking to someone, just can’t dial their DID.

Anyone have any thoughts?