Hi,
We’re in the process of testing incoming calls to our FreePBX box. We have around 40 extensions, all Snom 320 models.
Calls are redirected to our temporary inbound number by our existing phone system, through two time conditions and then in to a ring group. No IVR involved during opening hours.
Everything was working normally when all of a sudden calls a being disconnected as soon as a member of the ring group answers the call. I cannot reproduce the issue on an inbound route forwarded to an extension directly.
Several moments later everything will be normal again.
Here is the log from one of the dropped calls.
Any insight gratefully received!
Thanks
John
[2011-10-11 10:03:18] VERBOSE[21118] netsock2.c: == Using SIP RTP TOS bits 184
[2011-10-11 10:03:18] VERBOSE[21118] netsock2.c: == Using SIP RTP CoS mark 5
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Executing [441158xxxxxxx@ParseDDI_from_ToHeader:1] Set(“SIP/SpitFire-000002a2”, “parseDDI=sip:[email protected]”) in new stack
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Executing [441158xxxxxxx@ParseDDI_from_ToHeader:2] Set(“SIP/SpitFire-000002a2”, “parseDDI=441158xxxxxxx”) in new stack
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Executing [441158xxxxxxx@ParseDDI_from_ToHeader:3] Goto(“SIP/SpitFire-000002a2”, “from-trunk,441158xxxxxxx,1”) in new stack
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Goto (from-trunk,441158xxxxxxx,1)
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Executing [441158xxxxxxx@from-trunk:1] Set(“SIP/SpitFire-000002a2”, “__FROM_DID=441158xxxxxxx”) in new stack
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Executing [441158xxxxxxx@from-trunk:2] Gosub(“SIP/SpitFire-000002a2”, “cidlookup,cidlookup_1,1”) in new stack
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Executing [cidlookup_1@cidlookup:1] Set(“SIP/SpitFire-000002a2”, “CURLOPT(httptimeout)=7”) in new stack
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Executing [cidlookup_1@cidlookup:2] Set(“SIP/SpitFire-000002a2”, “CALLERID(name)=01159xxxxxxx”) in new stack
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Executing [cidlookup_1@cidlookup:3] Return(“SIP/SpitFire-000002a2”, “”) in new stack
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Executing [441158xxxxxxx@from-trunk:3] Gosub(“SIP/SpitFire-000002a2”, “app-blacklist-check,s,1”) in new stack
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Executing [s@app-blacklist-check:1] GotoIf(“SIP/SpitFire-000002a2”, “0?blacklisted”) in new stack
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Executing [s@app-blacklist-check:2] Set(“SIP/SpitFire-000002a2”, “CALLED_BLACKLIST=1”) in new stack
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Executing [s@app-blacklist-check:3] Return(“SIP/SpitFire-000002a2”, “”) in new stack
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Executing [441158xxxxxxx@from-trunk:4] ExecIf(“SIP/SpitFire-000002a2”, “0 ?Set(CALLERID(name)=01159xxxxxxx)”) in new stack
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Executing [441158xxxxxxx@from-trunk:5] Set(“SIP/SpitFire-000002a2”, “__CALLINGPRES_SV=allowed_not_screened”) in new stack
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Executing [441158xxxxxxx@from-trunk:6] Set(“SIP/SpitFire-000002a2”, “CALLERPRES()=allowed_not_screened”) in new stack
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Executing [441158xxxxxxx@from-trunk:7] Set(“SIP/SpitFire-000002a2”, “__ALERT_INFO=http://nohost;info=alert-external;x-line-id=0”) in new stack
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Executing [441158xxxxxxx@from-trunk:8] Goto(“SIP/SpitFire-000002a2”, “timeconditions,1,1”) in new stack
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Goto (timeconditions,1,1)
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Executing [1@timeconditions:1] GotoIfTime(“SIP/SpitFire-000002a2”, “12:00-08:00,,23-3,dec-jan?truestate") in new stack
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Executing [1@timeconditions:2] GotoIfTime(“SIP/SpitFire-000002a2”, ",,29,aug?truestate") in new stack
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Executing [1@timeconditions:3] GotoIf(“SIP/SpitFire-000002a2”, “0?truegoto”) in new stack
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Executing [1@timeconditions:4] ExecIf(“SIP/SpitFire-000002a2”, “0?Set(DB(TC/1)=)”) in new stack
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Executing [1@timeconditions:5] Set(“SIP/SpitFire-000002a2”, “DEVICE_STATE(Custom:TC1)=INUSE”) in new stack
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Executing [1@timeconditions:6] ExecIf(“SIP/SpitFire-000002a2”, “0?Set(DEVICE_STATE(Custom:TCSTICKY)=INUSE)”) in new stack
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Executing [1@timeconditions:7] GotoIf(“SIP/SpitFire-000002a2”, “1?timeconditions,2,1”) in new stack
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Goto (timeconditions,2,1)
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Executing [2@timeconditions:1] GotoIfTime(“SIP/SpitFire-000002a2”, "08:00-16:59,mon-fri,,*?truestate”) in new stack
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Goto (timeconditions,2,9)
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Executing [2@timeconditions:9] GotoIf(“SIP/SpitFire-000002a2”, “0?falsegoto”) in new stack
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Executing [2@timeconditions:10] ExecIf(“SIP/SpitFire-000002a2”, “0?Set(DB(TC/2)=)”) in new stack
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Executing [2@timeconditions:11] Set(“SIP/SpitFire-000002a2”, “DEVICE_STATE(Custom:TC2)=NOT_INUSE”) in new stack
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Executing [2@timeconditions:12] ExecIf(“SIP/SpitFire-000002a2”, “0?Set(DEVICE_STATE(Custom:TCSTICKY)=INUSE)”) in new stack
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Executing [2@timeconditions:13] GotoIf(“SIP/SpitFire-000002a2”, “1?ext-group,1001,1”) in new stack
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Goto (ext-group,1001,1)
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Executing [1001@ext-group:1] Macro(“SIP/SpitFire-000002a2”, “user-callerid,”) in new stack
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Executing [s@macro-user-callerid:1] Set(“SIP/SpitFire-000002a2”, “AMPUSER=01159xxxxxxx”) in new stack
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Executing [s@macro-user-callerid:2] GotoIf(“SIP/SpitFire-000002a2”, “0?report”) in new stack
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Executing [s@macro-user-callerid:3] ExecIf(“SIP/SpitFire-000002a2”, “1?Set(REALCALLERIDNUM=01159xxxxxxx)”) in new stack
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Executing [s@macro-user-callerid:4] Set(“SIP/SpitFire-000002a2”, “AMPUSER=”) in new stack
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Executing [s@macro-user-callerid:5] Set(“SIP/SpitFire-000002a2”, “AMPUSERCIDNAME=”) in new stack
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Executing [s@macro-user-callerid:6] GotoIf(“SIP/SpitFire-000002a2”, “1?report”) in new stack
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Goto (macro-user-callerid,s,13)
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Executing [s@macro-user-callerid:13] GotoIf(“SIP/SpitFire-000002a2”, “0?continue”) in new stack
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Executing [s@macro-user-callerid:14] Set(“SIP/SpitFire-000002a2”, “__TTL=64”) in new stack
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Executing [s@macro-user-callerid:15] GotoIf(“SIP/SpitFire-000002a2”, “1?continue”) in new stack
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Goto (macro-user-callerid,s,26)
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Executing [s@macro-user-callerid:26] Set(“SIP/SpitFire-000002a2”, “CALLERID(number)=01159xxxxxxx”) in new stack
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Executing [s@macro-user-callerid:27] Set(“SIP/SpitFire-000002a2”, “CALLERID(name)=01159xxxxxxx”) in new stack
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Executing [s@macro-user-callerid:28] Set(“SIP/SpitFire-000002a2”, “CHANNEL(language)=en”) in new stack
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Executing [1001@ext-group:2] Macro(“SIP/SpitFire-000002a2”, “blkvm-setifempty,”) in new stack
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Executing [s@macro-blkvm-setifempty:1] GotoIf(“SIP/SpitFire-000002a2”, “1?init”) in new stack
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Goto (macro-blkvm-setifempty,s,4)
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Executing [s@macro-blkvm-setifempty:4] Set(“SIP/SpitFire-000002a2”, “__BLKVM_CHANNEL=SIP/SpitFire-000002a2”) in new stack
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Executing [s@macro-blkvm-setifempty:5] Set(“SIP/SpitFire-000002a2”, “SHARED(BLKVM,SIP/SpitFire-000002a2)=TRUE”) in new stack
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Executing [s@macro-blkvm-setifempty:6] Set(“SIP/SpitFire-000002a2”, “GOSUB_RETVAL=TRUE”) in new stack
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Executing [s@macro-blkvm-setifempty:7] MacroExit(“SIP/SpitFire-000002a2”, “”) in new stack
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Executing [1001@ext-group:3] GotoIf(“SIP/SpitFire-000002a2”, “1?skipov”) in new stack
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Goto (ext-group,1001,6)
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Executing [1001@ext-group:6] Set(“SIP/SpitFire-000002a2”, “RRNODEST=”) in new stack
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Executing [1001@ext-group:7] Set(“SIP/SpitFire-000002a2”, “__NODEST=1001”) in new stack
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Executing [1001@ext-group:8] GosubIf(“SIP/SpitFire-000002a2”, “0?sub-rgsetcid,s,1”) in new stack
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Executing [1001@ext-group:9] Set(“SIP/SpitFire-000002a2”, “__ALERT_INFO=http://nohost\;info=alert-group\;x-line-id=0”) in new stack
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Executing [1001@ext-group:10] Set(“SIP/SpitFire-000002a2”, “__PICKUPMARK=1001”) in new stack
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Executing [1001@ext-group:11] Set(“SIP/SpitFire-000002a2”, “RecordMethod=Group”) in new stack
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Executing [1001@ext-group:12] Macro(“SIP/SpitFire-000002a2”, “record-enable,6000-6010-6011-6016-6020-6021-6024-6028-6026-6037-6038,Group”) in new stack
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Executing [s@macro-record-enable:1] GotoIf(“SIP/SpitFire-000002a2”, “1?check”) in new stack
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Goto (macro-record-enable,s,4)
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Executing [s@macro-record-enable:4] ExecIf(“SIP/SpitFire-000002a2”, “0?MacroExit()”) in new stack
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Executing [s@macro-record-enable:5] GotoIf(“SIP/SpitFire-000002a2”, “1?Group:OUT”) in new stack
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Goto (macro-record-enable,s,6)
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Executing [s@macro-record-enable:6] Set(“SIP/SpitFire-000002a2”, “LOOPCNT=11”) in new stack
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Executing [s@macro-record-enable:7] Set(“SIP/SpitFire-000002a2”, “ITER=1”) in new stack
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Executing [s@macro-record-enable:8] GotoIf(“SIP/SpitFire-000002a2”, “1?continue”) in new stack
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Goto (macro-record-enable,s,12)
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Executing [s@macro-record-enable:12] Set(“SIP/SpitFire-000002a2”, “ITER=2”) in new stack
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Executing [s@macro-record-enable:13] GotoIf(“SIP/SpitFire-000002a2”, “1?begin”) in new stack
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Goto (macro-record-enable,s,8)
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Executing [s@macro-record-enable:8] GotoIf(“SIP/SpitFire-000002a2”, “1?continue”) in new stack
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Goto (macro-record-enable,s,12)
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Executing [s@macro-record-enable:12] Set(“SIP/SpitFire-000002a2”, “ITER=3”) in new stack
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Executing [s@macro-record-enable:13] GotoIf(“SIP/SpitFire-000002a2”, “1?begin”) in new stack
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Goto (macro-record-enable,s,8)
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Executing [s@macro-record-enable:8] GotoIf(“SIP/SpitFire-000002a2”, “1?continue”) in new stack
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Goto (macro-record-enable,s,12)
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Executing [s@macro-record-enable:12] Set(“SIP/SpitFire-000002a2”, “ITER=4”) in new stack
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Executing [s@macro-record-enable:13] GotoIf(“SIP/SpitFire-000002a2”, “1?begin”) in new stack
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Goto (macro-record-enable,s,8)
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Executing [s@macro-record-enable:8] GotoIf(“SIP/SpitFire-000002a2”, “1?continue”) in new stack
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Goto (macro-record-enable,s,12)
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Executing [s@macro-record-enable:12] Set(“SIP/SpitFire-000002a2”, “ITER=5”) in new stack
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Executing [s@macro-record-enable:13] GotoIf(“SIP/SpitFire-000002a2”, “1?begin”) in new stack
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Goto (macro-record-enable,s,8)
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Executing [s@macro-record-enable:8] GotoIf(“SIP/SpitFire-000002a2”, “1?continue”) in new stack
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Goto (macro-record-enable,s,12)
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Executing [s@macro-record-enable:12] Set(“SIP/SpitFire-000002a2”, “ITER=6”) in new stack
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Executing [s@macro-record-enable:13] GotoIf(“SIP/SpitFire-000002a2”, “1?begin”) in new stack
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Goto (macro-record-enable,s,8)
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Executing [s@macro-record-enable:8] GotoIf(“SIP/SpitFire-000002a2”, “1?continue”) in new stack
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Goto (macro-record-enable,s,12)
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Executing [s@macro-record-enable:12] Set(“SIP/SpitFire-000002a2”, “ITER=7”) in new stack
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Executing [s@macro-record-enable:13] GotoIf(“SIP/SpitFire-000002a2”, “1?begin”) in new stack
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Goto (macro-record-enable,s,8)
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Executing [s@macro-record-enable:8] GotoIf(“SIP/SpitFire-000002a2”, “1?continue”) in new stack
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Goto (macro-record-enable,s,12)
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Executing [s@macro-record-enable:12] Set(“SIP/SpitFire-000002a2”, “ITER=8”) in new stack
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Executing [s@macro-record-enable:13] GotoIf(“SIP/SpitFire-000002a2”, “1?begin”) in new stack
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Goto (macro-record-enable,s,8)
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Executing [s@macro-record-enable:8] GotoIf(“SIP/SpitFire-000002a2”, “1?continue”) in new stack
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Goto (macro-record-enable,s,12)
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Executing [s@macro-record-enable:12] Set(“SIP/SpitFire-000002a2”, “ITER=9”) in new stack
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Executing [s@macro-record-enable:13] GotoIf(“SIP/SpitFire-000002a2”, “1?begin”) in new stack
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Goto (macro-record-enable,s,8)
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Executing [s@macro-record-enable:8] GotoIf(“SIP/SpitFire-000002a2”, “1?continue”) in new stack
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Goto (macro-record-enable,s,12)
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Executing [s@macro-record-enable:12] Set(“SIP/SpitFire-000002a2”, “ITER=10”) in new stack
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Executing [s@macro-record-enable:13] GotoIf(“SIP/SpitFire-000002a2”, “1?begin”) in new stack
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Goto (macro-record-enable,s,8)
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Executing [s@macro-record-enable:8] GotoIf(“SIP/SpitFire-000002a2”, “1?continue”) in new stack
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Goto (macro-record-enable,s,12)
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Executing [s@macro-record-enable:12] Set(“SIP/SpitFire-000002a2”, “ITER=11”) in new stack
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Executing [s@macro-record-enable:13] GotoIf(“SIP/SpitFire-000002a2”, “1?begin”) in new stack
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Goto (macro-record-enable,s,8)
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Executing [s@macro-record-enable:8] GotoIf(“SIP/SpitFire-000002a2”, “1?continue”) in new stack
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Goto (macro-record-enable,s,12)
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Executing [s@macro-record-enable:12] Set(“SIP/SpitFire-000002a2”, “ITER=12”) in new stack
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Executing [s@macro-record-enable:13] GotoIf(“SIP/SpitFire-000002a2”, “0?begin”) in new stack
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Executing [s@macro-record-enable:14] GotoIf(“SIP/SpitFire-000002a2”, “0?IN”) in new stack
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Executing [s@macro-record-enable:15] ExecIf(“SIP/SpitFire-000002a2”, “1?MacroExit()”) in new stack
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Executing [1001@ext-group:13] Set(“SIP/SpitFire-000002a2”, “RingGroupMethod=ringall”) in new stack
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Executing [1001@ext-group:14] Macro(“SIP/SpitFire-000002a2”, “dial,20,trxw,6000-6010-6011-6016-6020-6021-6024-6028-6026-6037-6038”) in new stack
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Executing [s@macro-dial:1] GotoIf(“SIP/SpitFire-000002a2”, “1?dial”) in new stack
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Goto (macro-dial,s,3)
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Executing [s@macro-dial:3] AGI(“SIP/SpitFire-000002a2”, “dialparties.agi”) in new stack
[2011-10-11 10:03:18] VERBOSE[32472] res_agi.c: – Launched AGI Script /var/lib/asterisk/agi-bin/dialparties.agi
[2011-10-11 10:03:18] VERBOSE[32472] res_agi.c: dialparties.agi: Starting New Dialparties.agi
[2011-10-11 10:03:18] VERBOSE[32472] res_agi.c: dialparties.agi: Caller ID name is ‘01159xxxxxxx’ number is ‘01159xxxxxxx’
[2011-10-11 10:03:18] VERBOSE[32472] res_agi.c: > dialparties.agi: Setting Alert-Info: http://nohost;info=alert-group;x-line-id=0
[2011-10-11 10:03:18] VERBOSE[32472] res_agi.c: – AGI Script Executing Application: (SIPAddHeader) Options: (Alert-Info:http://nohost;info=alert-group;x-line-id=0)
[2011-10-11 10:03:18] VERBOSE[32472] res_agi.c: > dialparties.agi: USE_CONFIRMATION: ‘FALSE’
[2011-10-11 10:03:18] VERBOSE[32472] res_agi.c: > dialparties.agi: RINGGROUP_INDEX: ‘’
[2011-10-11 10:03:18] VERBOSE[32472] res_agi.c: dialparties.agi: Methodology of ring is ‘ringall’
[2011-10-11 10:03:18] VERBOSE[32472] res_agi.c: – dialparties.agi: Added extension 6000 to extension map
[2011-10-11 10:03:18] VERBOSE[32472] res_agi.c: – dialparties.agi: Added extension 6010 to extension map
[2011-10-11 10:03:18] VERBOSE[32472] res_agi.c: – dialparties.agi: Added extension 6011 to extension map
[2011-10-11 10:03:18] VERBOSE[32472] res_agi.c: – dialparties.agi: Added extension 6016 to extension map
[2011-10-11 10:03:18] VERBOSE[32472] res_agi.c: – dialparties.agi: Added extension 6020 to extension map
[2011-10-11 10:03:18] VERBOSE[32472] res_agi.c: – dialparties.agi: Added extension 6021 to extension map
[2011-10-11 10:03:18] VERBOSE[32472] res_agi.c: – dialparties.agi: Added extension 6024 to extension map
[2011-10-11 10:03:18] VERBOSE[32472] res_agi.c: – dialparties.agi: Added extension 6028 to extension map
[2011-10-11 10:03:18] VERBOSE[32472] res_agi.c: – dialparties.agi: Added extension 6026 to extension map
[2011-10-11 10:03:18] VERBOSE[32472] res_agi.c: – dialparties.agi: Added extension 6037 to extension map
[2011-10-11 10:03:18] VERBOSE[32472] res_agi.c: – dialparties.agi: Added extension 6038 to extension map
[2011-10-11 10:03:18] VERBOSE[32472] res_agi.c: – dialparties.agi: Extension 6000 cf is disabled
[2011-10-11 10:03:18] VERBOSE[32472] res_agi.c: – dialparties.agi: Extension 6010 cf is disabled
[2011-10-11 10:03:18] VERBOSE[32472] res_agi.c: – dialparties.agi: Extension 6011 cf is disabled
[2011-10-11 10:03:18] VERBOSE[32472] res_agi.c: – dialparties.agi: Extension 6016 cf is disabled
[2011-10-11 10:03:18] VERBOSE[32472] res_agi.c: – dialparties.agi: Extension 6020 cf is disabled
[2011-10-11 10:03:18] VERBOSE[32472] res_agi.c: – dialparties.agi: Extension 6021 cf is disabled
[2011-10-11 10:03:18] VERBOSE[32472] res_agi.c: – dialparties.agi: Extension 6024 cf is disabled
[2011-10-11 10:03:18] VERBOSE[32472] res_agi.c: – dialparties.agi: Extension 6028 cf is disabled
[2011-10-11 10:03:18] VERBOSE[32472] res_agi.c: – dialparties.agi: Extension 6026 cf is disabled
[2011-10-11 10:03:18] VERBOSE[32472] res_agi.c: – dialparties.agi: Extension 6037 cf is disabled
[2011-10-11 10:03:18] VERBOSE[32472] res_agi.c: – dialparties.agi: Extension 6038 cf is disabled
[2011-10-11 10:03:18] VERBOSE[32472] res_agi.c: – dialparties.agi: Extension 6000 do not disturb is disabled
[2011-10-11 10:03:18] VERBOSE[32472] res_agi.c: – dialparties.agi: Extension 6010 do not disturb is disabled
[2011-10-11 10:03:18] VERBOSE[32472] res_agi.c: – dialparties.agi: Extension 6011 do not disturb is disabled
[2011-10-11 10:03:18] VERBOSE[32472] res_agi.c: – dialparties.agi: Extension 6016 do not disturb is disabled
[2011-10-11 10:03:18] VERBOSE[32472] res_agi.c: – dialparties.agi: Extension 6020 do not disturb is disabled
[2011-10-11 10:03:18] VERBOSE[32472] res_agi.c: – dialparties.agi: Extension 6021 do not disturb is disabled
[2011-10-11 10:03:18] VERBOSE[32472] res_agi.c: – dialparties.agi: Extension 6024 do not disturb is disabled
[2011-10-11 10:03:18] VERBOSE[32472] res_agi.c: – dialparties.agi: Extension 6028 do not disturb is disabled
[2011-10-11 10:03:18] VERBOSE[32472] res_agi.c: – dialparties.agi: Extension 6026 do not disturb is disabled
[2011-10-11 10:03:18] VERBOSE[32472] res_agi.c: – dialparties.agi: Extension 6037 do not disturb is disabled
[2011-10-11 10:03:18] VERBOSE[32472] res_agi.c: – dialparties.agi: Extension 6038 do not disturb is disabled
[2011-10-11 10:03:18] VERBOSE[32472] res_agi.c: > dialparties.agi: extnum 6000 has: cw: 1; hascfb: 0 [] hascfu: 0 []
[2011-10-11 10:03:18] VERBOSE[32472] res_agi.c: – dialparties.agi: dbset CALLTRACE/6000 to 01159xxxxxxx
[2011-10-11 10:03:18] VERBOSE[32472] res_agi.c: > dialparties.agi: extnum 6010 has: cw: 1; hascfb: 0 [] hascfu: 0 []
[2011-10-11 10:03:18] VERBOSE[32472] res_agi.c: – dialparties.agi: dbset CALLTRACE/6010 to 01159xxxxxxx
[2011-10-11 10:03:18] VERBOSE[32472] res_agi.c: > dialparties.agi: extnum 6011 has: cw: 1; hascfb: 0 [] hascfu: 0 []
[2011-10-11 10:03:18] VERBOSE[32472] res_agi.c: – dialparties.agi: dbset CALLTRACE/6011 to 01159xxxxxxx
[2011-10-11 10:03:18] VERBOSE[32472] res_agi.c: > dialparties.agi: extnum 6016 has: cw: 1; hascfb: 0 [] hascfu: 0 []
[2011-10-11 10:03:18] VERBOSE[32472] res_agi.c: – dialparties.agi: dbset CALLTRACE/6016 to 01159xxxxxxx
[2011-10-11 10:03:18] VERBOSE[32472] res_agi.c: > dialparties.agi: extnum 6020 has: cw: 1; hascfb: 0 [] hascfu: 0 []
[2011-10-11 10:03:18] VERBOSE[32472] res_agi.c: – dialparties.agi: dbset CALLTRACE/6020 to 01159xxxxxxx
[2011-10-11 10:03:18] VERBOSE[32472] res_agi.c: > dialparties.agi: extnum 6021 has: cw: 1; hascfb: 0 [] hascfu: 0 []
[2011-10-11 10:03:18] VERBOSE[32472] res_agi.c: – dialparties.agi: dbset CALLTRACE/6021 to 01159xxxxxxx
[2011-10-11 10:03:18] VERBOSE[32472] res_agi.c: > dialparties.agi: extnum 6024 has: cw: 1; hascfb: 0 [] hascfu: 0 []
[2011-10-11 10:03:18] VERBOSE[32472] res_agi.c: – dialparties.agi: dbset CALLTRACE/6024 to 01159xxxxxxx
[2011-10-11 10:03:18] VERBOSE[32472] res_agi.c: > dialparties.agi: extnum 6028 has: cw: 1; hascfb: 0 [] hascfu: 0 []
[2011-10-11 10:03:18] VERBOSE[32472] res_agi.c: – dialparties.agi: dbset CALLTRACE/6028 to 01159xxxxxxx
[2011-10-11 10:03:18] VERBOSE[32472] res_agi.c: > dialparties.agi: extnum 6026 has: cw: 1; hascfb: 0 [] hascfu: 0 []
[2011-10-11 10:03:18] VERBOSE[32472] res_agi.c: – dialparties.agi: dbset CALLTRACE/6026 to 01159xxxxxxx
[2011-10-11 10:03:18] VERBOSE[32472] res_agi.c: > dialparties.agi: extnum 6037 has: cw: 1; hascfb: 0 [] hascfu: 0 []
[2011-10-11 10:03:18] VERBOSE[32472] res_agi.c: – dialparties.agi: dbset CALLTRACE/6037 to 01159xxxxxxx
[2011-10-11 10:03:18] VERBOSE[32472] res_agi.c: > dialparties.agi: extnum 6038 has: cw: 1; hascfb: 0 [] hascfu: 0 []
[2011-10-11 10:03:18] VERBOSE[32472] res_agi.c: – dialparties.agi: dbset CALLTRACE/6038 to 01159xxxxxxx
[2011-10-11 10:03:18] VERBOSE[32472] res_agi.c: – dialparties.agi: Filtered ARG3: 6000-6010-6011-6016-6020-6021-6024-6028-6026-6037-6038
[2011-10-11 10:03:18] VERBOSE[32472] res_agi.c: > dialparties.agi: NODEST: 1001 adding M(auto-blkvm) to dialopts: trxwM(auto-blkvm)
[2011-10-11 10:03:18] VERBOSE[32472] res_agi.c: > dialparties.agi: NODEST: 1001 blkvm enabled macro already in dialopts: trxwM(auto-blkvm)
[2011-10-11 10:03:18] VERBOSE[32472] res_agi.c: – <SIP/SpitFire-000002a2>AGI Script dialparties.agi completed, returning 0
[2011-10-11 10:03:18] VERBOSE[32472] pbx.c: – Executing [s@macro-dial:7] Dial(“SIP/SpitFire-000002a2”, “SIP/6000&SIP/6010&SIP/6011&SIP/6016&SIP/6020&SIP/6021&SIP/6024&SIP/6028&SIP/6026&SIP/6037&SIP/6038,20,trxwM(auto-blkvm)”) in new stack
[2011-10-11 10:03:18] VERBOSE[32472] netsock2.c: == Using SIP RTP TOS bits 184
[2011-10-11 10:03:18] VERBOSE[32472] netsock2.c: == Using SIP RTP CoS mark 5
[2011-10-11 10:03:18] VERBOSE[21112] chan_sip.c: == Extension Changed 6000[ext-local] new state Ringing for Notify User 6024
[2011-10-11 10:03:18] VERBOSE[21112] chan_sip.c: == Extension Changed 6000[ext-local] new state Ringing for Notify User 6035
[2011-10-11 10:03:18] VERBOSE[21112] chan_sip.c: == Extension Changed 6000[ext-local] new state Ringing for Notify User 6022
[2011-10-11 10:03:18] VERBOSE[21112] chan_sip.c: == Extension Changed 6000[ext-local] new state Ringing for Notify User 6025
[2011-10-11 10:03:18] VERBOSE[21112] chan_sip.c: == Extension Changed 6000[ext-local] new state Ringing for Notify User 6013
[2011-10-11 10:03:18] VERBOSE[21112] chan_sip.c: == Extension Changed 6000[ext-local] new state Ringing for Notify User 6030
[2011-10-11 10:03:18] VERBOSE[21112] chan_sip.c: == Extension Changed 6000[ext-local] new state Ringing for Notify User 6029
[2011-10-11 10:03:18] VERBOSE[21112] chan_sip.c: == Extension Changed 6000[ext-local] new state Ringing for Notify User 6036
[2011-10-11 10:03:18] VERBOSE[21112] chan_sip.c: == Extension Changed 6000[ext-local] new state Ringing for Notify User 6026
[2011-10-11 10:03:18] VERBOSE[21112] chan_sip.c: == Extension Changed 6000[ext-local] new state Ringing for Notify User 6016
[2011-10-11 10:03:18] VERBOSE[21112] chan_sip.c: == Extension Changed 6000[ext-local] new state Ringing for Notify User 6011
[2011-10-11 10:03:18] VERBOSE[21112] chan_sip.c: == Extension Changed 6000[ext-local] new state Ringing for Notify User 6021
[2011-10-11 10:03:18] VERBOSE[21112] chan_sip.c: == Extension Changed 6000[ext-local] new state Ringing for Notify User 6014
[2011-10-11 10:03:18] VERBOSE[21112] chan_sip.c: == Extension Changed 6000[ext-local] new state Ringing for Notify User 6023
[2011-10-11 10:03:18] VERBOSE[21112] chan_sip.c: == Extension Changed 6000[ext-local] new state Ringing for Notify User 6019
[2011-10-11 10:03:18] VERBOSE[21112] chan_sip.c: == Extension Changed 6000[ext-local] new state Ringing for Notify User 6041
[2011-10-11 10:03:18] VERBOSE[21112] chan_sip.c: == Extension Changed 6000[ext-local] new state Ringing for Notify User 6018
[2011-10-11 10:03:18] VERBOSE[21112] chan_sip.c: == Extension Changed 6000[ext-local] new state Ringing for Notify User 6034
[2011-10-11 10:03:18] VERBOSE[21112] chan_sip.c: == Extension Changed 6000[ext-local] new state Ringing for Notify User 6010
[2011-10-11 10:03:18] VERBOSE[21112] chan_sip.c: == Extension Changed 6000[ext-local] new state Ringing for Notify User 6038
[2011-10-11 10:03:18] VERBOSE[21112] chan_sip.c: == Extension Changed 6000[ext-local] new state Ringing for Notify User 6028
[2011-10-11 10:03:18] VERBOSE[21112] chan_sip.c: == Extension Changed 6000[ext-local] new state Ringing for Notify User 6039
[2011-10-11 10:03:18] VERBOSE[21112] chan_sip.c: == Extension Changed 6000[ext-local] new state Ringing for Notify User 6012
[2011-10-11 10:03:18] VERBOSE[21112] chan_sip.c: == Extension Changed 6000[ext-local] new state Ringing for Notify User 6017
[2011-10-11 10:03:18] VERBOSE[21112] chan_sip.c: == Extension Changed 6000[ext-local] new state Ringing for Notify User 6027
[2011-10-11 10:03:18] VERBOSE[21112] chan_sip.c: == Extension Changed 6000[ext-local] new state Ringing for Notify User 6040
[2011-10-11 10:03:18] VERBOSE[21112] chan_sip.c: == Extension Changed 6000[ext-local] new state Ringing for Notify User 6037
[2011-10-11 10:03:18] VERBOSE[21112] chan_sip.c: == Extension Changed 6000[ext-local] new state Ringing for Notify User 6020
[2011-10-11 10:03:18] VERBOSE[32472] app_dial.c: – Called SIP/6000
[2011-10-11 10:03:18] VERBOSE[32472] netsock2.c: == Using SIP RTP TOS bits 184
[2011-10-11 10:03:18] VERBOSE[32472] netsock2.c: == Using SIP RTP CoS mark 5
[2011-10-11 10:03:18] VERBOSE[21112] chan_sip.c: == Extension Changed 6010[ext-local] new state Ringing for Notify User 7001
[2011-10-11 10:03:18] VERBOSE[32472] app_dial.c: – Called SIP/6010
[2011-10-11 10:03:18] VERBOSE[32472] netsock2.c: == Using SIP RTP TOS bits 184
[2011-10-11 10:03:18] VERBOSE[32472] netsock2.c: == Using SIP RTP CoS mark 5
[2011-10-11 10:03:18] VERBOSE[21112] chan_sip.c: == Extension Changed 6011[ext-local] new state Ringing for Notify User 7001
[2011-10-11 10:03:18] VERBOSE[21112] chan_sip.c: == Extension Changed 6011[ext-local] new state Ringing for Notify User 7001
[2011-10-11 10:03:18] VERBOSE[32472] app_dial.c: – Called SIP/6011
[2011-10-11 10:03:18] VERBOSE[32472] netsock2.c: == Using SIP RTP TOS bits 184
[2011-10-11 10:03:18] VERBOSE[32472] netsock2.c: == Using SIP RTP CoS mark 5
[2011-10-11 10:03:18] VERBOSE[21112] chan_sip.c: == Extension Changed 6016[ext-local] new state Ringing for Notify User 8002
[2011-10-11 10:03:18] VERBOSE[32472] app_dial.c: – Called SIP/6016
[2011-10-11 10:03:18] VERBOSE[32472] netsock2.c: == Using SIP RTP TOS bits 184
[2011-10-11 10:03:18] VERBOSE[32472] netsock2.c: == Using SIP RTP CoS mark 5
[2011-10-11 10:03:18] VERBOSE[32472] app_dial.c: – Called SIP/6020
[2011-10-11 10:03:18] VERBOSE[32472] netsock2.c: == Using SIP RTP TOS bits 184
[2011-10-11 10:03:18] VERBOSE[32472] netsock2.c: == Using SIP RTP CoS mark 5
[2011-10-11 10:03:18] VERBOSE[21112] chan_sip.c: == Extension Changed 6021[ext-local] new state Ringing for Notify User 7001
[2011-10-11 10:03:18] VERBOSE[21112] chan_sip.c: == Extension Changed 6021[ext-local] new state Ringing for Notify User 7001
[2011-10-11 10:03:18] VERBOSE[21112] chan_sip.c: == Extension Changed 6021[ext-local] new state Ringing for Notify User 8002
[2011-10-11 10:03:18] VERBOSE[21112] chan_sip.c: == Extension Changed 6021[ext-local] new state Ringing for Notify User 60181
[2011-10-11 10:03:18] VERBOSE[32472] app_dial.c: – Called SIP/6021
[2011-10-11 10:03:18] VERBOSE[32472] netsock2.c: == Using SIP RTP TOS bits 184
[2011-10-11 10:03:18] VERBOSE[32472] netsock2.c: == Using SIP RTP CoS mark 5
[2011-10-11 10:03:18] VERBOSE[32472] app_dial.c: – Called SIP/6024
[2011-10-11 10:03:18] VERBOSE[32472] netsock2.c: == Using SIP RTP TOS bits 184
[2011-10-11 10:03:18] VERBOSE[32472] netsock2.c: == Using SIP RTP CoS mark 5
[2011-10-11 10:03:18] VERBOSE[32472] app_dial.c: – Called SIP/6028
[2011-10-11 10:03:18] VERBOSE[32472] netsock2.c: == Using SIP RTP TOS bits 184
[2011-10-11 10:03:18] VERBOSE[32472] netsock2.c: == Using SIP RTP CoS mark 5
[2011-10-11 10:03:18] VERBOSE[21112] chan_sip.c: == Extension Changed 6026[ext-local] new state Ringing for Notify User 7001
[2011-10-11 10:03:18] VERBOSE[21112] chan_sip.c: == Extension Changed 6026[ext-local] new state Ringing for Notify User 8002
[2011-10-11 10:03:18] VERBOSE[21112] chan_sip.c: == Extension Changed 6026[ext-local] new state Ringing for Notify User 8001
[2011-10-11 10:03:18] VERBOSE[32472] app_dial.c: – Called SIP/6026
[2011-10-11 10:03:18] VERBOSE[32472] netsock2.c: == Using SIP RTP TOS bits 184
[2011-10-11 10:03:18] VERBOSE[32472] netsock2.c: == Using SIP RTP CoS mark 5
[2011-10-11 10:03:18] VERBOSE[21112] chan_sip.c: == Extension Changed 6037[ext-local] new state Ringing for Notify User 7001
[2011-10-11 10:03:18] VERBOSE[21112] chan_sip.c: == Extension Changed 6037[ext-local] new state Ringing for Notify User 8002
[2011-10-11 10:03:18] VERBOSE[32472] app_dial.c: – Called SIP/6037
[2011-10-11 10:03:18] VERBOSE[32472] netsock2.c: == Using SIP RTP TOS bits 184
[2011-10-11 10:03:18] VERBOSE[32472] netsock2.c: == Using SIP RTP CoS mark 5
[2011-10-11 10:03:18] VERBOSE[21112] chan_sip.c: == Extension Changed 6038[ext-local] new state Ringing for Notify User 7001
[2011-10-11 10:03:18] VERBOSE[32472] app_dial.c: – Called SIP/6038
[2011-10-11 10:03:18] VERBOSE[32472] app_dial.c: – SIP/6000-000002a3 connected line has changed. Saving it until answer for SIP/SpitFire-000002a2
[2011-10-11 10:03:18] VERBOSE[32472] app_dial.c: – SIP/6010-000002a4 connected line has changed. Saving it until answer for SIP/SpitFire-000002a2
[2011-10-11 10:03:18] VERBOSE[32472] app_dial.c: – SIP/6011-000002a5 connected line has changed. Saving it until answer for SIP/SpitFire-000002a2
[2011-10-11 10:03:18] VERBOSE[32472] app_dial.c: – SIP/6016-000002a6 connected line has changed. Saving it until answer for SIP/SpitFire-000002a2
[2011-10-11 10:03:18] VERBOSE[32472] app_dial.c: – SIP/6020-000002a7 connected line has changed. Saving it until answer for SIP/SpitFire-000002a2
[2011-10-11 10:03:18] VERBOSE[32472] app_dial.c: – SIP/6021-000002a8 connected line has changed. Saving it until answer for SIP/SpitFire-000002a2
[2011-10-11 10:03:18] VERBOSE[32472] app_dial.c: – SIP/6024-000002a9 connected line has changed. Saving it until answer for SIP/SpitFire-000002a2
[2011-10-11 10:03:18] VERBOSE[32472] app_dial.c: – SIP/6028-000002aa connected line has changed. Saving it until answer for SIP/SpitFire-000002a2
[2011-10-11 10:03:18] VERBOSE[32472] app_dial.c: – SIP/6026-000002ab connected line has changed. Saving it until answer for SIP/SpitFire-000002a2
[2011-10-11 10:03:18] VERBOSE[32472] app_dial.c: – SIP/6037-000002ac connected line has changed. Saving it until answer for SIP/SpitFire-000002a2
[2011-10-11 10:03:18] VERBOSE[32472] app_dial.c: – SIP/6038-000002ad connected line has changed. Saving it until answer for SIP/SpitFire-000002a2
[2011-10-11 10:03:18] VERBOSE[32472] app_dial.c: – SIP/6000-000002a3 is ringing
[2011-10-11 10:03:18] VERBOSE[32472] app_dial.c: – SIP/6010-000002a4 is ringing
[2011-10-11 10:03:18] VERBOSE[32472] app_dial.c: – SIP/6011-000002a5 is ringing
[2011-10-11 10:03:18] VERBOSE[32472] app_dial.c: – SIP/6016-000002a6 is ringing
[2011-10-11 10:03:18] VERBOSE[32472] app_dial.c: – SIP/6020-000002a7 is ringing
[2011-10-11 10:03:18] VERBOSE[32472] app_dial.c: – SIP/6021-000002a8 is ringing
[2011-10-11 10:03:18] VERBOSE[32472] app_dial.c: – SIP/6024-000002a9 is ringing
[2011-10-11 10:03:18] VERBOSE[32472] app_dial.c: – SIP/6028-000002aa is ringing
[2011-10-11 10:03:18] VERBOSE[32472] app_dial.c: – SIP/6026-000002ab is ringing
[2011-10-11 10:03:18] VERBOSE[32472] app_dial.c: – SIP/6037-000002ac is ringing
[2011-10-11 10:03:18] VERBOSE[32472] app_dial.c: – SIP/6038-000002ad is ringing
[2011-10-11 10:03:19] VERBOSE[32472] app_dial.c: – SIP/6011-000002a5 is ringing
[2011-10-11 10:03:19] VERBOSE[32472] app_dial.c: – SIP/6024-000002a9 is ringing
[2011-10-11 10:03:19] VERBOSE[32472] app_dial.c: – SIP/6016-000002a6 is ringing
[2011-10-11 10:03:19] VERBOSE[32472] app_dial.c: – SIP/6038-000002ad is ringing
[2011-10-11 10:03:19] VERBOSE[32472] app_dial.c: – SIP/6021-000002a8 is ringing
[2011-10-11 10:03:19] VERBOSE[32472] app_dial.c: – SIP/6010-000002a4 is ringing
[2011-10-11 10:03:19] VERBOSE[32472] app_dial.c: – SIP/6026-000002ab is ringing
[2011-10-11 10:03:19] VERBOSE[32472] app_dial.c: – SIP/6020-000002a7 is ringing
[2011-10-11 10:03:19] VERBOSE[32472] app_dial.c: – SIP/6028-000002aa is ringing
[2011-10-11 10:03:19] VERBOSE[32472] app_dial.c: – SIP/6037-000002ac is ringing
[2011-10-11 10:03:20] VERBOSE[32472] app_dial.c: – SIP/6011-000002a5 is ringing
[2011-10-11 10:03:20] VERBOSE[32472] app_dial.c: – SIP/6038-000002ad is ringing
[2011-10-11 10:03:20] VERBOSE[32472] app_dial.c: – SIP/6016-000002a6 is ringing
[2011-10-11 10:03:20] VERBOSE[32472] app_dial.c: – SIP/6024-000002a9 is ringing
[2011-10-11 10:03:20] VERBOSE[32472] app_dial.c: – SIP/6010-000002a4 is ringing
[2011-10-11 10:03:20] VERBOSE[32472] app_dial.c: – SIP/6026-000002ab is ringing
[2011-10-11 10:03:20] VERBOSE[32472] app_dial.c: – SIP/6021-000002a8 is ringing
[2011-10-11 10:03:20] VERBOSE[32472] app_dial.c: – SIP/6028-000002aa is ringing
[2011-10-11 10:03:20] VERBOSE[32472] app_dial.c: – SIP/6037-000002ac is ringing
[2011-10-11 10:03:20] VERBOSE[32472] app_dial.c: – SIP/6020-000002a7 is ringing
[2011-10-11 10:03:20] VERBOSE[32472] app_dial.c: – SIP/6016-000002a6 connected line has changed. Saving it until answer for SIP/SpitFire-000002a2
[2011-10-11 10:03:20] VERBOSE[32472] app_dial.c: – SIP/6016-000002a6 answered SIP/SpitFire-000002a2
[2011-10-11 10:03:20] VERBOSE[32472] pbx.c: – Executing [s@macro-auto-blkvm:1] Set(“SIP/6016-000002a6”, “__MACRO_RESULT=”) in new stack
[2011-10-11 10:03:20] VERBOSE[32472] pbx.c: – Executing [s@macro-auto-blkvm:2] Macro(“SIP/6016-000002a6”, “blkvm-clr,”) in new stack
[2011-10-11 10:03:20] VERBOSE[32472] pbx.c: – Executing [s@macro-blkvm-clr:1] Set(“SIP/6016-000002a6”, “SHARED(BLKVM,SIP/SpitFire-000002a2)=”) in new stack
[2011-10-11 10:03:20] VERBOSE[32472] pbx.c: – Executing [s@macro-blkvm-clr:2] Set(“SIP/6016-000002a6”, “GOSUB_RETVAL=”) in new stack
[2011-10-11 10:03:20] VERBOSE[32472] pbx.c: – Executing [s@macro-blkvm-clr:3] MacroExit(“SIP/6016-000002a6”, “”) in new stack
[2011-10-11 10:03:20] VERBOSE[32472] pbx.c: – Executing [s@macro-auto-blkvm:3] Set(“SIP/6016-000002a6”, “MASTER_CHANNEL(CONNECTEDLINE(num))=6016”) in new stack
[2011-10-11 10:03:20] VERBOSE[32472] pbx.c: – Executing [s@macro-auto-blkvm:4] Set(“SIP/6016-000002a6”, “MASTER_CHANNEL(CONNECTEDLINE(name))=Jo Kaminski”) in new stack
[2011-10-11 10:03:20] VERBOSE[21112] chan_sip.c: == Extension Changed 6016[ext-local] new state InUse for Notify User 8002
[2011-10-11 10:03:20] VERBOSE[21112] chan_sip.c: == Extension Changed 6038[ext-local] new state Idle for Notify User 7001
[2011-10-11 10:03:20] VERBOSE[21112] chan_sip.c: == Extension Changed 6037[ext-local] new state Idle for Notify User 7001
[2011-10-11 10:03:20] VERBOSE[21112] chan_sip.c: == Extension Changed 6037[ext-local] new state Idle for Notify User 8002
[2011-10-11 10:03:20] VERBOSE[21112] chan_sip.c: == Extension Changed 6026[ext-local] new state Idle for Notify User 7001
[2011-10-11 10:03:20] VERBOSE[21112] chan_sip.c: == Extension Changed 6026[ext-local] new state Idle for Notify User 8002
[2011-10-11 10:03:20] VERBOSE[21112] chan_sip.c: == Extension Changed 6026[ext-local] new state Idle for Notify User 8001
[2011-10-11 10:03:20] VERBOSE[21112] chan_sip.c: == Extension Changed 6021[ext-local] new state Idle for Notify User 7001
[2011-10-11 10:03:20] VERBOSE[21112] chan_sip.c: == Extension Changed 6021[ext-local] new state Idle for Notify User 7001
[2011-10-11 10:03:20] VERBOSE[21112] chan_sip.c: == Extension Changed 6021[ext-local] new state Idle for Notify User 8002
[2011-10-11 10:03:20] VERBOSE[21112] chan_sip.c: == Extension Changed 6021[ext-local] new state Idle for Notify User 60181
[2011-10-11 10:03:20] VERBOSE[21112] chan_sip.c: == Extension Changed 6011[ext-local] new state Idle for Notify User 7001
[2011-10-11 10:03:20] VERBOSE[21112] chan_sip.c: == Extension Changed 6011[ext-local] new state Idle for Notify User 7001
[2011-10-11 10:03:20] VERBOSE[21112] chan_sip.c: == Extension Changed 6010[ext-local] new state Idle for Notify User 7001
[2011-10-11 10:03:20] VERBOSE[21112] chan_sip.c: == Extension Changed 6000[ext-local] new state Idle for Notify User 6024
[2011-10-11 10:03:20] VERBOSE[21112] chan_sip.c: == Extension Changed 6000[ext-local] new state Idle for Notify User 6035
[2011-10-11 10:03:20] VERBOSE[21112] chan_sip.c: == Extension Changed 6000[ext-local] new state Idle for Notify User 6022
[2011-10-11 10:03:20] VERBOSE[21112] chan_sip.c: == Extension Changed 6000[ext-local] new state Idle for Notify User 6025
[2011-10-11 10:03:20] VERBOSE[21112] chan_sip.c: == Extension Changed 6000[ext-local] new state Idle for Notify User 6013
[2011-10-11 10:03:20] VERBOSE[21112] chan_sip.c: == Extension Changed 6000[ext-local] new state Idle for Notify User 6030
[2011-10-11 10:03:20] VERBOSE[21112] chan_sip.c: == Extension Changed 6000[ext-local] new state Idle for Notify User 6029
[2011-10-11 10:03:20] VERBOSE[21112] chan_sip.c: == Extension Changed 6000[ext-local] new state Idle for Notify User 6036
[2011-10-11 10:03:20] VERBOSE[21112] chan_sip.c: == Extension Changed 6000[ext-local] new state Idle for Notify User 6026
[2011-10-11 10:03:20] VERBOSE[21112] chan_sip.c: == Extension Changed 6000[ext-local] new state Idle for Notify User 6016
[2011-10-11 10:03:20] VERBOSE[21112] chan_sip.c: == Extension Changed 6000[ext-local] new state Idle for Notify User 6011
[2011-10-11 10:03:20] VERBOSE[21112] chan_sip.c: == Extension Changed 6000[ext-local] new state Idle for Notify User 6021
[2011-10-11 10:03:20] VERBOSE[21112] chan_sip.c: == Extension Changed 6000[ext-local] new state Idle for Notify User 6014
[2011-10-11 10:03:20] VERBOSE[21112] chan_sip.c: == Extension Changed 6000[ext-local] new state Idle for Notify User 6023
[2011-10-11 10:03:20] VERBOSE[21112] chan_sip.c: == Extension Changed 6000[ext-local] new state Idle for Notify User 6019
[2011-10-11 10:03:20] VERBOSE[21112] chan_sip.c: == Extension Changed 6000[ext-local] new state Idle for Notify User 6041
[2011-10-11 10:03:20] VERBOSE[21112] chan_sip.c: == Extension Changed 6000[ext-local] new state Idle for Notify User 6018
[2011-10-11 10:03:20] VERBOSE[21112] chan_sip.c: == Extension Changed 6000[ext-local] new state Idle for Notify User 6034
[2011-10-11 10:03:20] VERBOSE[21112] chan_sip.c: == Extension Changed 6000[ext-local] new state Idle for Notify User 6010
[2011-10-11 10:03:20] VERBOSE[21112] chan_sip.c: == Extension Changed 6000[ext-local] new state Idle for Notify User 6038
[2011-10-11 10:03:20] VERBOSE[21112] chan_sip.c: == Extension Changed 6000[ext-local] new state Idle for Notify User 6028
[2011-10-11 10:03:20] VERBOSE[21112] chan_sip.c: == Extension Changed 6000[ext-local] new state Idle for Notify User 6039
[2011-10-11 10:03:20] VERBOSE[21112] chan_sip.c: == Extension Changed 6000[ext-local] new state Idle for Notify User 6012
[2011-10-11 10:03:20] VERBOSE[21112] chan_sip.c: == Extension Changed 6000[ext-local] new state Idle for Notify User 6017
[2011-10-11 10:03:20] VERBOSE[21112] chan_sip.c: == Extension Changed 6000[ext-local] new state Idle for Notify User 6027
[2011-10-11 10:03:20] VERBOSE[21112] chan_sip.c: == Extension Changed 6000[ext-local] new state Idle for Notify User 6040
[2011-10-11 10:03:20] VERBOSE[21112] chan_sip.c: == Extension Changed 6000[ext-local] new state Idle for Notify User 6037
[2011-10-11 10:03:20] VERBOSE[21112] chan_sip.c: == Extension Changed 6000[ext-local] new state Idle for Notify User 6020
[2011-10-11 10:03:20] VERBOSE[32472] pbx.c: – Executing [h@macro-dial:1] Macro(“SIP/SpitFire-000002a2”, “hangupcall”) in new stack
[2011-10-11 10:03:20] VERBOSE[32472] pbx.c: – Executing [s@macro-hangupcall:1] GotoIf(“SIP/SpitFire-000002a2”, “1?theend”) in new stack
[2011-10-11 10:03:20] VERBOSE[32472] pbx.c: – Goto (macro-hangupcall,s,3)
[2011-10-11 10:03:20] VERBOSE[32472] pbx.c: – Executing [s@macro-hangupcall:3] Hangup(“SIP/SpitFire-000002a2”, “”) in new stack
[2011-10-11 10:03:20] VERBOSE[32472] app_macro.c: == Spawn extension (macro-hangupcall, s, 3) exited non-zero on ‘SIP/SpitFire-000002a2’ in macro ‘hangupcall’
[2011-10-11 10:03:20] VERBOSE[32472] features.c: == Spawn extension (macro-dial, h, 1) exited non-zero on ‘SIP/SpitFire-000002a2’
[2011-10-11 10:03:20] VERBOSE[32472] app_macro.c: == Spawn extension (macro-dial, s, 7) exited non-zero on ‘SIP/SpitFire-000002a2’ in macro ‘dial’
[2011-10-11 10:03:20] VERBOSE[32472] pbx.c: == Spawn extension (ext-group, 1001, 14) exited non-zero on ‘SIP/SpitFire-000002a2’
[2011-10-11 10:03:20] VERBOSE[21112] chan_sip.c: == Extension Changed 6016[ext-local] new state Idle for Notify User 8002 (queued)
[2011-10-11 10:03:20] VERBOSE[21118] chan_sip.c: == Extension Changed 6016[from-internal] new state Idle for Notify User 8002