[Oct 27 08:23:31] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [1000@from-node:1] NoOp("SIP/asterisk-asteriskdev1-00000028", " - From Node - ") in new stack
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [1000@from-node:2] Set("SIP/asterisk-asteriskdev1-00000028", "FROMSOURCE=node") in new stack
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [1000@from-node:3] Set("SIP/asterisk-asteriskdev1-00000028", "_CALLER=2201") in new stack
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [1000@from-node:4] Set("SIP/asterisk-asteriskdev1-00000028", "CALLEDNUMBER=1000") in new stack
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [1000@from-node:5] GotoIf("SIP/asterisk-asteriskdev1-00000028", "1?diallocaluser") in new stack
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] pbx.c:     -- Goto (from-node,1000,7)
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [1000@from-node:7] Goto("SIP/asterisk-asteriskdev1-00000028", "to-node-users,1000,1") in new stack
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] pbx.c:     -- Goto (to-node-users,1000,1)
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [1000@to-node-users:1] Gosub("SIP/asterisk-asteriskdev1-00000028", "macro-dial-localext,1000,1(SIP/1000&SIP/soft1000&SIP/web1000,1000)") in new stack
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [1000@macro-dial-localext:1] NoOp("SIP/asterisk-asteriskdev1-00000028", "Calling internal extension SIP/1000&SIP/soft1000&SIP/web1000") in new stack
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [1000@macro-dial-localext:2] Set("SIP/asterisk-asteriskdev1-00000028", "TIMEOUT=") in new stack
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [1000@macro-dial-localext:3] Macro("SIP/asterisk-asteriskdev1-00000028", "executeagi,callerid.agi?user=1000") in new stack
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [s@macro-executeagi:1] NoOp("SIP/asterisk-asteriskdev1-00000028", "Execute AGI") in new stack
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [s@macro-executeagi:2] GotoIf("SIP/asterisk-asteriskdev1-00000028", "0?agihost0failed") in new stack
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [s@macro-executeagi:3] AGI("SIP/asterisk-asteriskdev1-00000028", "agi://130.10.14.249/callerid.agi?user=1000") in new stack
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] res_agi.c:     -- <SIP/asterisk-asteriskdev1-00000028>AGI Script agi://130.10.14.249/callerid.agi?user=1000 completed, returning 0
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [s@macro-executeagi:4] GotoIf("SIP/asterisk-asteriskdev1-00000028", "1?agisuccess") in new stack
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] pbx.c:     -- Goto (macro-executeagi,s,7)
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [s@macro-executeagi:7] NoOp("SIP/asterisk-asteriskdev1-00000028", "AGI SUCCESS") in new stack
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [1000@macro-dial-localext:4] GotoIf("SIP/asterisk-asteriskdev1-00000028", "1?clstraight:setuserid") in new stack
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] pbx.c:     -- Goto (macro-dial-localext,1000,5)
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [1000@macro-dial-localext:5] Set("SIP/asterisk-asteriskdev1-00000028", "CONNECTEDLINE(num,i)=1000") in new stack
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [1000@macro-dial-localext:6] Set("SIP/asterisk-asteriskdev1-00000028", "CONNECTEDLINE(name,i)=Tony Stark") in new stack
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [1000@macro-dial-localext:7] Set("SIP/asterisk-asteriskdev1-00000028", "CONNECTEDLINE(pres)=allowed") in new stack
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [1000@macro-dial-localext:8] Set("SIP/asterisk-asteriskdev1-00000028", "USERID=1000") in new stack
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [1000@macro-dial-localext:9] Set("SIP/asterisk-asteriskdev1-00000028", "DIALEXTENSION=SIP/1000&SIP/soft1000&SIP/web1000") in new stack
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [1000@macro-dial-localext:10] Set("SIP/asterisk-asteriskdev1-00000028", "CLIPNUMBER=2201") in new stack
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [1000@macro-dial-localext:11] Macro("SIP/asterisk-asteriskdev1-00000028", "executeagi,clip.agi?type=local") in new stack
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [s@macro-executeagi:1] NoOp("SIP/asterisk-asteriskdev1-00000028", "Execute AGI") in new stack
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [s@macro-executeagi:2] GotoIf("SIP/asterisk-asteriskdev1-00000028", "0?agihost0failed") in new stack
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [s@macro-executeagi:3] AGI("SIP/asterisk-asteriskdev1-00000028", "agi://130.10.14.249/clip.agi?type=local") in new stack
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] res_agi.c:     -- <SIP/asterisk-asteriskdev1-00000028>AGI Script agi://130.10.14.249/clip.agi?type=local completed, returning 0
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [s@macro-executeagi:4] GotoIf("SIP/asterisk-asteriskdev1-00000028", "1?agisuccess") in new stack
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] pbx.c:     -- Goto (macro-executeagi,s,7)
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [s@macro-executeagi:7] NoOp("SIP/asterisk-asteriskdev1-00000028", "AGI SUCCESS") in new stack
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [1000@macro-dial-localext:12] Set("SIP/asterisk-asteriskdev1-00000028", "CALLERID(num)=2201") in new stack
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [1000@macro-dial-localext:13] Macro("SIP/asterisk-asteriskdev1-00000028", "executeagi,defaultrules.agi?user=1000") in new stack
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [s@macro-executeagi:1] NoOp("SIP/asterisk-asteriskdev1-00000028", "Execute AGI") in new stack
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [s@macro-executeagi:2] GotoIf("SIP/asterisk-asteriskdev1-00000028", "0?agihost0failed") in new stack
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [s@macro-executeagi:3] AGI("SIP/asterisk-asteriskdev1-00000028", "agi://130.10.14.249/defaultrules.agi?user=1000") in new stack
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] res_agi.c:     -- <SIP/asterisk-asteriskdev1-00000028>AGI Script agi://130.10.14.249/defaultrules.agi?user=1000 completed, returning 0
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [s@macro-executeagi:4] GotoIf("SIP/asterisk-asteriskdev1-00000028", "1?agisuccess") in new stack
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] pbx.c:     -- Goto (macro-executeagi,s,7)
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [s@macro-executeagi:7] NoOp("SIP/asterisk-asteriskdev1-00000028", "AGI SUCCESS") in new stack
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [1000@macro-dial-localext:14] NoOp("SIP/asterisk-asteriskdev1-00000028", "VOICEMAIL: false") in new stack
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [1000@macro-dial-localext:15] NoOp("SIP/asterisk-asteriskdev1-00000028", "VOICEMAILTIMEOUT: ") in new stack
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [1000@macro-dial-localext:16] NoOp("SIP/asterisk-asteriskdev1-00000028", "FORWARDCONTEXT: ") in new stack
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [1000@macro-dial-localext:17] NoOp("SIP/asterisk-asteriskdev1-00000028", "ISFORWARDED: false") in new stack
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [1000@macro-dial-localext:18] GotoIf("SIP/asterisk-asteriskdev1-00000028", "0?dial") in new stack
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [1000@macro-dial-localext:19] GotoIf("SIP/asterisk-asteriskdev1-00000028", "1?dial") in new stack
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] pbx.c:     -- Goto (macro-dial-localext,1000,34)
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [1000@macro-dial-localext:34] Macro("SIP/asterisk-asteriskdev1-00000028", "executeagi,personal.agi?dialstatus=DIRECT&user=1000") in new stack
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [s@macro-executeagi:1] NoOp("SIP/asterisk-asteriskdev1-00000028", "Execute AGI") in new stack
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [s@macro-executeagi:2] GotoIf("SIP/asterisk-asteriskdev1-00000028", "0?agihost0failed") in new stack
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [s@macro-executeagi:3] AGI("SIP/asterisk-asteriskdev1-00000028", "agi://130.10.14.249/personal.agi?dialstatus=DIRECT&user=1000") in new stack
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] res_agi.c:     -- <SIP/asterisk-asteriskdev1-00000028>AGI Script agi://130.10.14.249/personal.agi?dialstatus=DIRECT&user=1000 completed, returning 0
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [s@macro-executeagi:4] GotoIf("SIP/asterisk-asteriskdev1-00000028", "1?agisuccess") in new stack
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] pbx.c:     -- Goto (macro-executeagi,s,7)
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [s@macro-executeagi:7] NoOp("SIP/asterisk-asteriskdev1-00000028", "AGI SUCCESS") in new stack
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [1000@macro-dial-localext:35] Macro("SIP/asterisk-asteriskdev1-00000028", "executeagi,lookup.agi?user=1000&serverid=1") in new stack
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [s@macro-executeagi:1] NoOp("SIP/asterisk-asteriskdev1-00000028", "Execute AGI") in new stack
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [s@macro-executeagi:2] GotoIf("SIP/asterisk-asteriskdev1-00000028", "0?agihost0failed") in new stack
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [s@macro-executeagi:3] AGI("SIP/asterisk-asteriskdev1-00000028", "agi://130.10.14.249/lookup.agi?user=1000&serverid=1") in new stack
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] res_agi.c:     -- <SIP/asterisk-asteriskdev1-00000028>AGI Script agi://130.10.14.249/lookup.agi?user=1000&serverid=1 completed, returning 0
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [s@macro-executeagi:4] GotoIf("SIP/asterisk-asteriskdev1-00000028", "1?agisuccess") in new stack
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] pbx.c:     -- Goto (macro-executeagi,s,7)
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [s@macro-executeagi:7] NoOp("SIP/asterisk-asteriskdev1-00000028", "AGI SUCCESS") in new stack
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [1000@macro-dial-localext:36] Set("SIP/asterisk-asteriskdev1-00000028", "CALLS=0") in new stack
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [1000@macro-dial-localext:37] Set("SIP/asterisk-asteriskdev1-00000028", "SOFTCALLS=0") in new stack
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [1000@macro-dial-localext:38] Set("SIP/asterisk-asteriskdev1-00000028", "WEBCALLS=0") in new stack
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [1000@macro-dial-localext:39] Set("SIP/asterisk-asteriskdev1-00000028", "DECTCALLS=") in new stack
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [1000@macro-dial-localext:40] Set("SIP/asterisk-asteriskdev1-00000028", "PHONEIP=10.0.0.100") in new stack
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [1000@macro-dial-localext:41] Set("SIP/asterisk-asteriskdev1-00000028", "SOFTIP=(null)") in new stack
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [1000@macro-dial-localext:42] Set("SIP/asterisk-asteriskdev1-00000028", "WEBIP=(null)") in new stack
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [1000@macro-dial-localext:43] Set("SIP/asterisk-asteriskdev1-00000028", "DECTIP=") in new stack
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [1000@macro-dial-localext:44] Gosub("SIP/asterisk-asteriskdev1-00000028", "lookup-called-party,s,1(1000)") in new stack
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [s@lookup-called-party:1] Set("SIP/asterisk-asteriskdev1-00000028", "LOGGEDINSERVERID=") in new stack
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [s@lookup-called-party:2] Set("SIP/asterisk-asteriskdev1-00000028", "LOGGEDINSERVERIP=") in new stack
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [s@lookup-called-party:3] Set("SIP/asterisk-asteriskdev1-00000028", "LOGGEDINSERVERNAME=") in new stack
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [s@lookup-called-party:4] Macro("SIP/asterisk-asteriskdev1-00000028", "executeagi,lookup.agi?user=1000") in new stack
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [s@macro-executeagi:1] NoOp("SIP/asterisk-asteriskdev1-00000028", "Execute AGI") in new stack
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [s@macro-executeagi:2] GotoIf("SIP/asterisk-asteriskdev1-00000028", "0?agihost0failed") in new stack
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [s@macro-executeagi:3] AGI("SIP/asterisk-asteriskdev1-00000028", "agi://130.10.14.249/lookup.agi?user=1000") in new stack
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] res_agi.c:     -- <SIP/asterisk-asteriskdev1-00000028>AGI Script agi://130.10.14.249/lookup.agi?user=1000 completed, returning 0
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [s@macro-executeagi:4] GotoIf("SIP/asterisk-asteriskdev1-00000028", "1?agisuccess") in new stack
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] pbx.c:     -- Goto (macro-executeagi,s,7)
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [s@macro-executeagi:7] NoOp("SIP/asterisk-asteriskdev1-00000028", "AGI SUCCESS") in new stack
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [s@lookup-called-party:5] Set("SIP/asterisk-asteriskdev1-00000028", "CALLEDPARTYLOGGEDINSERVERID=") in new stack
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [s@lookup-called-party:6] Set("SIP/asterisk-asteriskdev1-00000028", "CALLEDPARTYLOGGEDINSERVERIP=") in new stack
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [s@lookup-called-party:7] Set("SIP/asterisk-asteriskdev1-00000028", "CALLEDPARTYLOGGEDINSERVERNAME=") in new stack
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [s@lookup-called-party:8] GotoIf("SIP/asterisk-asteriskdev1-00000028", "1?lookupfailed") in new stack
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] pbx.c:     -- Goto (lookup-called-party,s,10)
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [s@lookup-called-party:10] Return("SIP/asterisk-asteriskdev1-00000028", "-1") in new stack
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [1000@macro-dial-localext:45] GosubIf("SIP/asterisk-asteriskdev1-00000028", "0?lookup-called-user,s,1(2201,1000)") in new stack
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [1000@macro-dial-localext:46] Macro("SIP/asterisk-asteriskdev1-00000028", "executeagi,mobileservice.agi?user=1000") in new stack
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [s@macro-executeagi:1] NoOp("SIP/asterisk-asteriskdev1-00000028", "Execute AGI") in new stack
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [s@macro-executeagi:2] GotoIf("SIP/asterisk-asteriskdev1-00000028", "0?agihost0failed") in new stack
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [s@macro-executeagi:3] AGI("SIP/asterisk-asteriskdev1-00000028", "agi://130.10.14.249/mobileservice.agi?user=1000") in new stack
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] res_agi.c:     -- <SIP/asterisk-asteriskdev1-00000028>AGI Script agi://130.10.14.249/mobileservice.agi?user=1000 completed, returning 0
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [s@macro-executeagi:4] GotoIf("SIP/asterisk-asteriskdev1-00000028", "1?agisuccess") in new stack
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] pbx.c:     -- Goto (macro-executeagi,s,7)
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [s@macro-executeagi:7] NoOp("SIP/asterisk-asteriskdev1-00000028", "AGI SUCCESS") in new stack
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [1000@macro-dial-localext:47] GotoIf("SIP/asterisk-asteriskdev1-00000028", "1?callwaitingcheck") in new stack
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] pbx.c:     -- Goto (macro-dial-localext,1000,56)
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [1000@macro-dial-localext:56] GotoIf("SIP/asterisk-asteriskdev1-00000028", "0?callwaiting") in new stack
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [1000@macro-dial-localext:57] GotoIf("SIP/asterisk-asteriskdev1-00000028", "0?callwaiting") in new stack
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [1000@macro-dial-localext:58] GotoIf("SIP/asterisk-asteriskdev1-00000028", "0?callwaiting") in new stack
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [1000@macro-dial-localext:59] GotoIf("SIP/asterisk-asteriskdev1-00000028", "0?callwaiting:execdial") in new stack
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] pbx.c:     -- Goto (macro-dial-localext,1000,64)
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [1000@macro-dial-localext:64] Macro("SIP/asterisk-asteriskdev1-00000028", "executeagi,ringtone.agi?user=1000") in new stack
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [s@macro-executeagi:1] NoOp("SIP/asterisk-asteriskdev1-00000028", "Execute AGI") in new stack
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [s@macro-executeagi:2] GotoIf("SIP/asterisk-asteriskdev1-00000028", "0?agihost0failed") in new stack
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [s@macro-executeagi:3] AGI("SIP/asterisk-asteriskdev1-00000028", "agi://130.10.14.249/ringtone.agi?user=1000") in new stack
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] res_agi.c:     -- AGI Script Executing Application: (SipAddHeader) Options: (Alert-Info: <http://130.10.14.249:8080/provisioning/ringtone/default?user=1000&id=0>)
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] res_agi.c:     -- <SIP/asterisk-asteriskdev1-00000028>AGI Script agi://130.10.14.249/ringtone.agi?user=1000 completed, returning 0
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [s@macro-executeagi:4] GotoIf("SIP/asterisk-asteriskdev1-00000028", "1?agisuccess") in new stack
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] pbx.c:     -- Goto (macro-executeagi,s,7)
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [s@macro-executeagi:7] NoOp("SIP/asterisk-asteriskdev1-00000028", "AGI SUCCESS") in new stack
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [1000@macro-dial-localext:65] GotoIf("SIP/asterisk-asteriskdev1-00000028", "0?setDialOptionExtern") in new stack
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [1000@macro-dial-localext:66] Set("SIP/asterisk-asteriskdev1-00000028", "DIALOPTIONS=tT") in new stack
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [1000@macro-dial-localext:67] Goto("SIP/asterisk-asteriskdev1-00000028", "skipDialOptionsExtern") in new stack
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] pbx.c:     -- Goto (macro-dial-localext,1000,69)
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [1000@macro-dial-localext:69] NoOp("SIP/asterisk-asteriskdev1-00000028", "Transferoptions: tT") in new stack
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [1000@macro-dial-localext:70] GotoIf("SIP/asterisk-asteriskdev1-00000028", "1?noblindtransfer") in new stack
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] pbx.c:     -- Goto (macro-dial-localext,1000,75)
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [1000@macro-dial-localext:75] NoOp("SIP/asterisk-asteriskdev1-00000028", "Transfer failed for ") in new stack
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [1000@macro-dial-localext:76] ExecIf("SIP/asterisk-asteriskdev1-00000028", "0?Set(CALLERID(all)="Tf(Clark Kent (2201)) <2201>")") in new stack
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [1000@macro-dial-localext:77] Dial("SIP/asterisk-asteriskdev1-00000028", "SIP/1000&SIP/soft1000&SIP/web1000,,ItT") in new stack
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] netsock2.c:   == Using SIP VIDEO TOS bits 136
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] netsock2.c:   == Using SIP VIDEO CoS mark 6
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] netsock2.c:   == Using SIP RTP TOS bits 184
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] netsock2.c:   == Using SIP RTP CoS mark 5
[Oct 27 08:23:31] WARNING[26744][C-00000011] channel.c: Don't know any of (h261|h263|h263p|h264) formats
[Oct 27 08:23:31] WARNING[26744][C-00000011] app_dial.c: Unable to create channel of type 'SIP' (cause 20 - Subscriber absent)
[Oct 27 08:23:31] WARNING[26744][C-00000011] app_dial.c: Unable to create channel of type 'SIP' (cause 20 - Subscriber absent)
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] app_dial.c:     -- Called SIP/1000
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] app_dial.c:     -- Connected line update to SIP/asterisk-asteriskdev1-00000028 prevented.
[Oct 27 08:23:31] VERBOSE[26744][C-00000011] app_dial.c:     -- SIP/1000-00000029 is ringing
[Oct 27 08:23:33] WARNING[825][C-00000011] chan_sip.c: Ignoring video stream offer because port number is zero
[Oct 27 08:23:33] WARNING[825][C-00000011] channel.c: Don't know any of (nothing) formats
[Oct 27 08:23:33] WARNING[825][C-00000011] channel.c: Unable to find a codec translation path from (alaw) to (nothing)
[Oct 27 08:23:33] WARNING[825][C-00000011] channel.c: Don't know any of (nothing) formats
[Oct 27 08:23:33] WARNING[825][C-00000011] channel.c: Unable to find a codec translation path from (alaw) to (nothing)
[Oct 27 08:23:33] VERBOSE[26744][C-00000011] app_dial.c:     -- Connected line update to SIP/asterisk-asteriskdev1-00000028 prevented.
[Oct 27 08:23:33] VERBOSE[26744][C-00000011] app_dial.c:     -- SIP/1000-00000029 answered SIP/asterisk-asteriskdev1-00000028
[Oct 27 08:23:36] VERBOSE[26744][C-00000011] res_musiconhold.c:     -- Started music on hold, class 'default', on SIP/asterisk-asteriskdev1-00000028
[Oct 27 08:23:37] VERBOSE[22633] pbx.c:   == Setting global variable '130_10_14_249_is' to 'alive'
[Oct 27 08:23:40] VERBOSE[26744][C-00000011] res_musiconhold.c:     -- Stopped music on hold on SIP/asterisk-asteriskdev1-00000028
[Oct 27 08:23:40] VERBOSE[26744][C-00000011] pbx.c:   == Spawn extension (blindtransfer, 2203, 1) exited non-zero on 'SIP/asterisk-asteriskdev1-00000028'
[Oct 27 08:23:40] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [2203@blindtransfer:1] GotoIf("SIP/asterisk-asteriskdev1-00000028", "0?attendedtransfer-dtmf,2203,1") in new stack
[Oct 27 08:23:40] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [2203@blindtransfer:2] GotoIf("SIP/asterisk-asteriskdev1-00000028", "0?setcallerid:setblindtransferer") in new stack
[Oct 27 08:23:40] VERBOSE[26744][C-00000011] pbx.c:     -- Goto (blindtransfer,2203,4)
[Oct 27 08:23:40] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [2203@blindtransfer:4] Set("SIP/asterisk-asteriskdev1-00000028", "BLINDTRANSFERER=1000") in new stack
[Oct 27 08:23:40] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [2203@blindtransfer:5] Set("SIP/asterisk-asteriskdev1-00000028", "BLINDTRANSFERERUSER=1000") in new stack
[Oct 27 08:23:40] ERROR[26744][C-00000011] func_global.c: Channel 'SIP/1000-00000029' not found!  Variable 'inboundcall' will be blank.
[Oct 27 08:23:40] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [2203@blindtransfer:6] GotoIf("SIP/asterisk-asteriskdev1-00000028", "0?replaceuser:aclcheck") in new stack
[Oct 27 08:23:40] VERBOSE[26744][C-00000011] pbx.c:     -- Goto (blindtransfer,2203,8)
[Oct 27 08:23:40] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [2203@blindtransfer:8] Macro("SIP/asterisk-asteriskdev1-00000028", "executeagi,acl.agi?user=1000&callednum=2203") in new stack
[Oct 27 08:23:40] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [s@macro-executeagi:1] NoOp("SIP/asterisk-asteriskdev1-00000028", "Execute AGI") in new stack
[Oct 27 08:23:40] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [s@macro-executeagi:2] GotoIf("SIP/asterisk-asteriskdev1-00000028", "0?agihost0failed") in new stack
[Oct 27 08:23:40] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [s@macro-executeagi:3] AGI("SIP/asterisk-asteriskdev1-00000028", "agi://130.10.14.249/acl.agi?user=1000&callednum=2203") in new stack
[Oct 27 08:23:40] VERBOSE[26744][C-00000011] res_agi.c:     -- <SIP/asterisk-asteriskdev1-00000028>AGI Script agi://130.10.14.249/acl.agi?user=1000&callednum=2203 completed, returning 0
[Oct 27 08:23:40] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [s@macro-executeagi:4] GotoIf("SIP/asterisk-asteriskdev1-00000028", "1?agisuccess") in new stack
[Oct 27 08:23:40] VERBOSE[26744][C-00000011] pbx.c:     -- Goto (macro-executeagi,s,7)
[Oct 27 08:23:40] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [s@macro-executeagi:7] NoOp("SIP/asterisk-asteriskdev1-00000028", "AGI SUCCESS") in new stack
[Oct 27 08:23:40] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [2203@blindtransfer:9] Set("SIP/asterisk-asteriskdev1-00000028", "BLINDTRANSFERERCONTEXT=from-internal-6000-acl") in new stack
[Oct 27 08:23:40] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [2203@blindtransfer:10] Goto("SIP/asterisk-asteriskdev1-00000028", "from-internal-6000-acl,2203,1") in new stack
[Oct 27 08:23:40] VERBOSE[26744][C-00000011] pbx.c:     -- Goto (from-internal-6000-acl,2203,1)
[Oct 27 08:23:40] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [2203@from-internal-6000-acl:1] Goto("SIP/asterisk-asteriskdev1-00000028", "acl2203,1") in new stack
[Oct 27 08:23:40] VERBOSE[26744][C-00000011] pbx.c:     -- Goto (from-internal-6000-acl,acl2203,1)
[Oct 27 08:23:40] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [acl2203@from-internal-6000-acl:1] NoOp("SIP/asterisk-asteriskdev1-00000028", "ACL check for 2201 - destination 2203") in new stack
[Oct 27 08:23:40] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [acl2203@from-internal-6000-acl:2] Set("SIP/asterisk-asteriskdev1-00000028", "_CALLER=2201") in new stack
[Oct 27 08:23:40] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [acl2203@from-internal-6000-acl:3] Set("SIP/asterisk-asteriskdev1-00000028", "CALLEDNUMBER=2203") in new stack
[Oct 27 08:23:40] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [acl2203@from-internal-6000-acl:4] Macro("SIP/asterisk-asteriskdev1-00000028", "executeagi,set-callerid.agi") in new stack
[Oct 27 08:23:40] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [s@macro-executeagi:1] NoOp("SIP/asterisk-asteriskdev1-00000028", "Execute AGI") in new stack
[Oct 27 08:23:40] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [s@macro-executeagi:2] GotoIf("SIP/asterisk-asteriskdev1-00000028", "0?agihost0failed") in new stack
[Oct 27 08:23:40] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [s@macro-executeagi:3] AGI("SIP/asterisk-asteriskdev1-00000028", "agi://130.10.14.249/set-callerid.agi") in new stack
[Oct 27 08:23:40] VERBOSE[26744][C-00000011] res_agi.c:     -- <SIP/asterisk-asteriskdev1-00000028>AGI Script agi://130.10.14.249/set-callerid.agi completed, returning 0
[Oct 27 08:23:40] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [s@macro-executeagi:4] GotoIf("SIP/asterisk-asteriskdev1-00000028", "1?agisuccess") in new stack
[Oct 27 08:23:40] VERBOSE[26744][C-00000011] pbx.c:     -- Goto (macro-executeagi,s,7)
[Oct 27 08:23:40] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [s@macro-executeagi:7] NoOp("SIP/asterisk-asteriskdev1-00000028", "AGI SUCCESS") in new stack
[Oct 27 08:23:40] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [acl2203@from-internal-6000-acl:5] SIPAddHeader("SIP/asterisk-asteriskdev1-00000028", "Call-Info: <http://130.10.14.249:8080/xmlphone/picture?userid=2201>;purpose=icon") in new stack
[Oct 27 08:23:40] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [acl2203@from-internal-6000-acl:6] NoOp("SIP/asterisk-asteriskdev1-00000028", "REDIRECTINGCOUNT = 0") in new stack
[Oct 27 08:23:40] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [acl2203@from-internal-6000-acl:7] NoOp("SIP/asterisk-asteriskdev1-00000028", "FORWARDARRAY     = ") in new stack
[Oct 27 08:23:40] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [acl2203@from-internal-6000-acl:8] GotoIf("SIP/asterisk-asteriskdev1-00000028", "1?acl") in new stack
[Oct 27 08:23:40] VERBOSE[26744][C-00000011] pbx.c:     -- Goto (from-internal-6000-acl,acl2203,14)
[Oct 27 08:23:40] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [acl2203@from-internal-6000-acl:14] Macro("SIP/asterisk-asteriskdev1-00000028", "executeagi,acl.agi?user=2201&callednum=2203") in new stack
[Oct 27 08:23:40] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [s@macro-executeagi:1] NoOp("SIP/asterisk-asteriskdev1-00000028", "Execute AGI") in new stack
[Oct 27 08:23:40] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [s@macro-executeagi:2] GotoIf("SIP/asterisk-asteriskdev1-00000028", "0?agihost0failed") in new stack
[Oct 27 08:23:40] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [s@macro-executeagi:3] AGI("SIP/asterisk-asteriskdev1-00000028", "agi://130.10.14.249/acl.agi?user=2201&callednum=2203") in new stack
[Oct 27 08:23:40] VERBOSE[26744][C-00000011] res_agi.c:     -- <SIP/asterisk-asteriskdev1-00000028>AGI Script agi://130.10.14.249/acl.agi?user=2201&callednum=2203 completed, returning 0
[Oct 27 08:23:40] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [s@macro-executeagi:4] GotoIf("SIP/asterisk-asteriskdev1-00000028", "1?agisuccess") in new stack
[Oct 27 08:23:40] VERBOSE[26744][C-00000011] pbx.c:     -- Goto (macro-executeagi,s,7)
[Oct 27 08:23:40] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [s@macro-executeagi:7] NoOp("SIP/asterisk-asteriskdev1-00000028", "AGI SUCCESS") in new stack
[Oct 27 08:23:40] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [acl2203@from-internal-6000-acl:15] GosubIf("SIP/asterisk-asteriskdev1-00000028", "0?macro-dialout-clir,s,1(2203,2201)") in new stack
[Oct 27 08:23:40] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [acl2203@from-internal-6000-acl:16] Goto("SIP/asterisk-asteriskdev1-00000028", "from-internal-6000,2203,1") in new stack
[Oct 27 08:23:40] VERBOSE[26744][C-00000011] pbx.c:     -- Goto (from-internal-6000,2203,1)
[Oct 27 08:23:40] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [2203@from-internal-6000:1] Goto("SIP/asterisk-asteriskdev1-00000028", "ltl2203,1") in new stack
[Oct 27 08:23:40] VERBOSE[26744][C-00000011] pbx.c:     -- Goto (from-internal-6000,ltl2203,1)
[Oct 27 08:23:40] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [ltl2203@from-internal-6000:1] NoOp("SIP/asterisk-asteriskdev1-00000028", "local-to-localext 2203") in new stack
[Oct 27 08:23:40] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [ltl2203@from-internal-6000:2] Dial("SIP/asterisk-asteriskdev1-00000028", "SIP/asterisk-asteriskdev1/2203,120,eo") in new stack
[Oct 27 08:23:40] VERBOSE[26744][C-00000011] netsock2.c:   == Using SIP VIDEO TOS bits 136
[Oct 27 08:23:40] VERBOSE[26744][C-00000011] netsock2.c:   == Using SIP VIDEO CoS mark 6
[Oct 27 08:23:40] VERBOSE[26744][C-00000011] netsock2.c:   == Using SIP RTP TOS bits 184
[Oct 27 08:23:40] VERBOSE[26744][C-00000011] netsock2.c:   == Using SIP RTP CoS mark 5
[Oct 27 08:23:40] VERBOSE[26744][C-00000011] app_dial.c:     -- Called SIP/asterisk-asteriskdev1/2203
[Oct 27 08:23:47] VERBOSE[26744][C-00000011] app_dial.c:   == Everyone is busy/congested at this time (1:0/0/1)
[Oct 27 08:23:47] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [ltl2203@from-internal-6000:3] GotoIf("SIP/asterisk-asteriskdev1-00000028", "1?backtotransferer") in new stack
[Oct 27 08:23:47] VERBOSE[26744][C-00000011] pbx.c:     -- Goto (from-internal-6000,ltl2203,5)
[Oct 27 08:23:47] VERBOSE[26744][C-00000011] pbx.c:     -- Executing [ltl2203@from-internal-6000:5] Wait("SIP/asterisk-asteriskdev1-00000028", "1") in new stack
[Oct 27 08:23:47] VERBOSE[26744][C-00000011] pbx.c:   == Spawn extension (from-internal-6000, ltl2203, 5) exited non-zero on 'SIP/asterisk-asteriskdev1-00000028'
[Oct 27 08:33:43] VERBOSE[26751][C-00000018] pbx.c:     -- Executing [ltl2203@from-internal-6000:3] GotoIf("SIP/1000-00000036", "0?backtotransferer") in new stack
[Oct 27 08:33:43] VERBOSE[26751][C-00000018] pbx.c:     -- Executing [ltl2203@from-internal-6000:4] Hangup("SIP/1000-00000036", "") in new stack
[Oct 27 08:33:43] VERBOSE[26751][C-00000018] pbx.c:   == Spawn extension (from-internal-6000, ltl2203, 4) exited non-zero on 'SIP/1000-00000036'
[Oct 27 08:33:51] VERBOSE[22633] pbx.c:   == Setting global variable '130_10_14_249_is' to 'alive'
[Oct 27 08:33:53] VERBOSE[26748][C-00000015] pbx.c:   == Spawn extension (from-internal-6000, ltl2203, 2) exited non-zero on 'SIP/asterisk-asteriskdev1-0000002f'
[Oct 27 08:34:06] VERBOSE[22633] pbx.c:   == Setting global variable '130_10_14_249_is' to 'alive'
[Oct 27 08:34:21] VERBOSE[22633] pbx.c:   == Setting global variable '130_10_14_249_is' to 'alive'
[Oct 27 08:34:36] VERBOSE[22633] pbx.c:   == Setting global variable '130_10_14_249_is' to 'alive'
[Oct 27 08:34:51] VERBOSE[22633] pbx.c:   == Setting global variable '130_10_14_249_is' to 'alive'
[Oct 27 08:35:06] VERBOSE[22633] pbx.c:   == Setting global variable '130_10_14_249_is' to 'alive'
[Oct 27 08:35:21] VERBOSE[22633] pbx.c:   == Setting global variable '130_10_14_249_is' to 'alive'
[Oct 27 08:35:36] VERBOSE[22633] pbx.c:   == Setting global variable '130_10_14_249_is' to 'alive'
[Oct 27 08:35:51] VERBOSE[22633] pbx.c:   == Setting global variable '130_10_14_249_is' to 'alive'
[Oct 27 08:36:06] VERBOSE[22633] pbx.c:   == Setting global variable '130_10_14_249_is' to 'alive'
[Oct 27 08:36:21] VERBOSE[22633] pbx.c:   == Setting global variable '130_10_14_249_is' to 'alive'
[Oct 27 08:36:36] VERBOSE[22633] pbx.c:   == Setting global variable '130_10_14_249_is' to 'alive'
[Oct 27 08:36:51] VERBOSE[22633] pbx.c:   == Setting global variable '130_10_14_249_is' to 'alive'
[Oct 27 08:37:06] VERBOSE[22633] pbx.c:   == Setting global variable '130_10_14_249_is' to 'alive'
[Oct 27 08:37:21] VERBOSE[22633] pbx.c:   == Setting global variable '130_10_14_249_is' to 'alive'
[Oct 27 08:37:36] VERBOSE[22633] pbx.c:   == Setting global variable '130_10_14_249_is' to 'alive'
[Oct 27 08:37:51] VERBOSE[22633] pbx.c:   == Setting global variable '130_10_14_249_is' to 'alive'
[Oct 27 08:38:06] VERBOSE[22633] pbx.c:   == Setting global variable '130_10_14_249_is' to 'alive'
[Oct 27 08:38:21] VERBOSE[22633] pbx.c:   == Setting global variable '130_10_14_249_is' to 'alive'
[Oct 27 08:38:36] VERBOSE[22633] pbx.c:   == Setting global variable '130_10_14_249_is' to 'alive'
[Oct 27 08:38:51] VERBOSE[22633] pbx.c:   == Setting global variable '130_10_14_249_is' to 'alive'
[Oct 27 08:39:06] VERBOSE[22633] pbx.c:   == Setting global variable '130_10_14_249_is' to 'alive'
[Oct 27 08:39:21] VERBOSE[22633] pbx.c:   == Setting global variable '130_10_14_249_is' to 'alive'
[Oct 27 08:39:36] VERBOSE[22633] pbx.c:   == Setting global variable '130_10_14_249_is' to 'alive'
[Oct 27 08:39:51] VERBOSE[22633] pbx.c:   == Setting global variable '130_10_14_249_is' to 'alive'
[Oct 27 08:40:06] VERBOSE[22633] pbx.c:   == Setting global variable '130_10_14_249_is' to 'alive'
[Oct 27 08:40:21] VERBOSE[22633] pbx.c:   == Setting global variable '130_10_14_249_is' to 'alive'
[Oct 27 08:40:36] VERBOSE[22633] pbx.c:   == Setting global variable '130_10_14_249_is' to 'alive'
[Oct 27 08:40:40] VERBOSE[26752] manager.c:   == Manager 'obelisk' logged on from 130.10.15.15
[Oct 27 08:40:51] VERBOSE[22633] pbx.c:   == Setting global variable '130_10_14_249_is' to 'alive'
[Oct 27 08:40:55] VERBOSE[26752] pbx.c:   == Setting global variable '130_10_15_15_is' to 'alive'
[Oct 27 08:41:06] VERBOSE[22633] pbx.c:   == Setting global variable '130_10_14_249_is' to 'alive'
[Oct 27 08:41:10] VERBOSE[26752] pbx.c:   == Setting global variable '130_10_15_15_is' to 'alive'
[Oct 27 08:41:11] VERBOSE[825][C-00000019] netsock2.c:   == Using SIP VIDEO TOS bits 136
[Oct 27 08:41:11] VERBOSE[825][C-00000019] netsock2.c:   == Using SIP VIDEO CoS mark 6
[Oct 27 08:41:11] VERBOSE[825][C-00000019] netsock2.c:   == Using SIP RTP TOS bits 184
[Oct 27 08:41:11] VERBOSE[825][C-00000019] netsock2.c:   == Using SIP RTP CoS mark 5
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [1000@from-node:1] NoOp("SIP/asterisk-asteriskdev1-00000038", " - From Node - ") in new stack
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [1000@from-node:2] Set("SIP/asterisk-asteriskdev1-00000038", "FROMSOURCE=node") in new stack
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [1000@from-node:3] Set("SIP/asterisk-asteriskdev1-00000038", "_CALLER=2201") in new stack
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [1000@from-node:4] Set("SIP/asterisk-asteriskdev1-00000038", "CALLEDNUMBER=1000") in new stack
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [1000@from-node:5] GotoIf("SIP/asterisk-asteriskdev1-00000038", "1?diallocaluser") in new stack
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] pbx.c:     -- Goto (from-node,1000,7)
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [1000@from-node:7] Goto("SIP/asterisk-asteriskdev1-00000038", "to-node-users,1000,1") in new stack
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] pbx.c:     -- Goto (to-node-users,1000,1)
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [1000@to-node-users:1] Gosub("SIP/asterisk-asteriskdev1-00000038", "macro-dial-localext,1000,1(SIP/1000&SIP/soft1000&SIP/web1000,1000)") in new stack
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [1000@macro-dial-localext:1] NoOp("SIP/asterisk-asteriskdev1-00000038", "Calling internal extension SIP/1000&SIP/soft1000&SIP/web1000") in new stack
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [1000@macro-dial-localext:2] Set("SIP/asterisk-asteriskdev1-00000038", "TIMEOUT=") in new stack
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [1000@macro-dial-localext:3] Macro("SIP/asterisk-asteriskdev1-00000038", "executeagi,callerid.agi?user=1000") in new stack
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [s@macro-executeagi:1] NoOp("SIP/asterisk-asteriskdev1-00000038", "Execute AGI") in new stack
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [s@macro-executeagi:2] GotoIf("SIP/asterisk-asteriskdev1-00000038", "0?agihost0failed") in new stack
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [s@macro-executeagi:3] AGI("SIP/asterisk-asteriskdev1-00000038", "agi://130.10.14.249/callerid.agi?user=1000") in new stack
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] res_agi.c:     -- <SIP/asterisk-asteriskdev1-00000038>AGI Script agi://130.10.14.249/callerid.agi?user=1000 completed, returning 0
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [s@macro-executeagi:4] GotoIf("SIP/asterisk-asteriskdev1-00000038", "1?agisuccess") in new stack
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] pbx.c:     -- Goto (macro-executeagi,s,7)
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [s@macro-executeagi:7] NoOp("SIP/asterisk-asteriskdev1-00000038", "AGI SUCCESS") in new stack
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [1000@macro-dial-localext:4] GotoIf("SIP/asterisk-asteriskdev1-00000038", "1?clstraight:setuserid") in new stack
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] pbx.c:     -- Goto (macro-dial-localext,1000,5)
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [1000@macro-dial-localext:5] Set("SIP/asterisk-asteriskdev1-00000038", "CONNECTEDLINE(num,i)=1000") in new stack
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [1000@macro-dial-localext:6] Set("SIP/asterisk-asteriskdev1-00000038", "CONNECTEDLINE(name,i)=Tony Stark") in new stack
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [1000@macro-dial-localext:7] Set("SIP/asterisk-asteriskdev1-00000038", "CONNECTEDLINE(pres)=allowed") in new stack
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [1000@macro-dial-localext:8] Set("SIP/asterisk-asteriskdev1-00000038", "USERID=1000") in new stack
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [1000@macro-dial-localext:9] Set("SIP/asterisk-asteriskdev1-00000038", "DIALEXTENSION=SIP/1000&SIP/soft1000&SIP/web1000") in new stack
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [1000@macro-dial-localext:10] Set("SIP/asterisk-asteriskdev1-00000038", "CLIPNUMBER=2201") in new stack
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [1000@macro-dial-localext:11] Macro("SIP/asterisk-asteriskdev1-00000038", "executeagi,clip.agi?type=local") in new stack
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [s@macro-executeagi:1] NoOp("SIP/asterisk-asteriskdev1-00000038", "Execute AGI") in new stack
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [s@macro-executeagi:2] GotoIf("SIP/asterisk-asteriskdev1-00000038", "0?agihost0failed") in new stack
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [s@macro-executeagi:3] AGI("SIP/asterisk-asteriskdev1-00000038", "agi://130.10.14.249/clip.agi?type=local") in new stack
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] res_agi.c:     -- <SIP/asterisk-asteriskdev1-00000038>AGI Script agi://130.10.14.249/clip.agi?type=local completed, returning 0
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [s@macro-executeagi:4] GotoIf("SIP/asterisk-asteriskdev1-00000038", "1?agisuccess") in new stack
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] pbx.c:     -- Goto (macro-executeagi,s,7)
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [s@macro-executeagi:7] NoOp("SIP/asterisk-asteriskdev1-00000038", "AGI SUCCESS") in new stack
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [1000@macro-dial-localext:12] Set("SIP/asterisk-asteriskdev1-00000038", "CALLERID(num)=2201") in new stack
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [1000@macro-dial-localext:13] Macro("SIP/asterisk-asteriskdev1-00000038", "executeagi,defaultrules.agi?user=1000") in new stack
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [s@macro-executeagi:1] NoOp("SIP/asterisk-asteriskdev1-00000038", "Execute AGI") in new stack
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [s@macro-executeagi:2] GotoIf("SIP/asterisk-asteriskdev1-00000038", "0?agihost0failed") in new stack
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [s@macro-executeagi:3] AGI("SIP/asterisk-asteriskdev1-00000038", "agi://130.10.14.249/defaultrules.agi?user=1000") in new stack
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] res_agi.c:     -- <SIP/asterisk-asteriskdev1-00000038>AGI Script agi://130.10.14.249/defaultrules.agi?user=1000 completed, returning 0
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [s@macro-executeagi:4] GotoIf("SIP/asterisk-asteriskdev1-00000038", "1?agisuccess") in new stack
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] pbx.c:     -- Goto (macro-executeagi,s,7)
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [s@macro-executeagi:7] NoOp("SIP/asterisk-asteriskdev1-00000038", "AGI SUCCESS") in new stack
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [1000@macro-dial-localext:14] NoOp("SIP/asterisk-asteriskdev1-00000038", "VOICEMAIL: false") in new stack
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [1000@macro-dial-localext:15] NoOp("SIP/asterisk-asteriskdev1-00000038", "VOICEMAILTIMEOUT: ") in new stack
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [1000@macro-dial-localext:16] NoOp("SIP/asterisk-asteriskdev1-00000038", "FORWARDCONTEXT: ") in new stack
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [1000@macro-dial-localext:17] NoOp("SIP/asterisk-asteriskdev1-00000038", "ISFORWARDED: false") in new stack
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [1000@macro-dial-localext:18] GotoIf("SIP/asterisk-asteriskdev1-00000038", "0?dial") in new stack
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [1000@macro-dial-localext:19] GotoIf("SIP/asterisk-asteriskdev1-00000038", "1?dial") in new stack
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] pbx.c:     -- Goto (macro-dial-localext,1000,34)
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [1000@macro-dial-localext:34] Macro("SIP/asterisk-asteriskdev1-00000038", "executeagi,personal.agi?dialstatus=DIRECT&user=1000") in new stack
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [s@macro-executeagi:1] NoOp("SIP/asterisk-asteriskdev1-00000038", "Execute AGI") in new stack
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [s@macro-executeagi:2] GotoIf("SIP/asterisk-asteriskdev1-00000038", "0?agihost0failed") in new stack
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [s@macro-executeagi:3] AGI("SIP/asterisk-asteriskdev1-00000038", "agi://130.10.14.249/personal.agi?dialstatus=DIRECT&user=1000") in new stack
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] res_agi.c:     -- <SIP/asterisk-asteriskdev1-00000038>AGI Script agi://130.10.14.249/personal.agi?dialstatus=DIRECT&user=1000 completed, returning 0
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [s@macro-executeagi:4] GotoIf("SIP/asterisk-asteriskdev1-00000038", "1?agisuccess") in new stack
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] pbx.c:     -- Goto (macro-executeagi,s,7)
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [s@macro-executeagi:7] NoOp("SIP/asterisk-asteriskdev1-00000038", "AGI SUCCESS") in new stack
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [1000@macro-dial-localext:35] Macro("SIP/asterisk-asteriskdev1-00000038", "executeagi,lookup.agi?user=1000&serverid=1") in new stack
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [s@macro-executeagi:1] NoOp("SIP/asterisk-asteriskdev1-00000038", "Execute AGI") in new stack
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [s@macro-executeagi:2] GotoIf("SIP/asterisk-asteriskdev1-00000038", "0?agihost0failed") in new stack
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [s@macro-executeagi:3] AGI("SIP/asterisk-asteriskdev1-00000038", "agi://130.10.14.249/lookup.agi?user=1000&serverid=1") in new stack
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] res_agi.c:     -- <SIP/asterisk-asteriskdev1-00000038>AGI Script agi://130.10.14.249/lookup.agi?user=1000&serverid=1 completed, returning 0
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [s@macro-executeagi:4] GotoIf("SIP/asterisk-asteriskdev1-00000038", "1?agisuccess") in new stack
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] pbx.c:     -- Goto (macro-executeagi,s,7)
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [s@macro-executeagi:7] NoOp("SIP/asterisk-asteriskdev1-00000038", "AGI SUCCESS") in new stack
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [1000@macro-dial-localext:36] Set("SIP/asterisk-asteriskdev1-00000038", "CALLS=0") in new stack
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [1000@macro-dial-localext:37] Set("SIP/asterisk-asteriskdev1-00000038", "SOFTCALLS=0") in new stack
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [1000@macro-dial-localext:38] Set("SIP/asterisk-asteriskdev1-00000038", "WEBCALLS=0") in new stack
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [1000@macro-dial-localext:39] Set("SIP/asterisk-asteriskdev1-00000038", "DECTCALLS=") in new stack
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [1000@macro-dial-localext:40] Set("SIP/asterisk-asteriskdev1-00000038", "PHONEIP=10.0.0.100") in new stack
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [1000@macro-dial-localext:41] Set("SIP/asterisk-asteriskdev1-00000038", "SOFTIP=(null)") in new stack
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [1000@macro-dial-localext:42] Set("SIP/asterisk-asteriskdev1-00000038", "WEBIP=(null)") in new stack
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [1000@macro-dial-localext:43] Set("SIP/asterisk-asteriskdev1-00000038", "DECTIP=") in new stack
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [1000@macro-dial-localext:44] Gosub("SIP/asterisk-asteriskdev1-00000038", "lookup-called-party,s,1(1000)") in new stack
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [s@lookup-called-party:1] Set("SIP/asterisk-asteriskdev1-00000038", "LOGGEDINSERVERID=") in new stack
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [s@lookup-called-party:2] Set("SIP/asterisk-asteriskdev1-00000038", "LOGGEDINSERVERIP=") in new stack
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [s@lookup-called-party:3] Set("SIP/asterisk-asteriskdev1-00000038", "LOGGEDINSERVERNAME=") in new stack
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [s@lookup-called-party:4] Macro("SIP/asterisk-asteriskdev1-00000038", "executeagi,lookup.agi?user=1000") in new stack
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [s@macro-executeagi:1] NoOp("SIP/asterisk-asteriskdev1-00000038", "Execute AGI") in new stack
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [s@macro-executeagi:2] GotoIf("SIP/asterisk-asteriskdev1-00000038", "0?agihost0failed") in new stack
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [s@macro-executeagi:3] AGI("SIP/asterisk-asteriskdev1-00000038", "agi://130.10.14.249/lookup.agi?user=1000") in new stack
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] res_agi.c:     -- <SIP/asterisk-asteriskdev1-00000038>AGI Script agi://130.10.14.249/lookup.agi?user=1000 completed, returning 0
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [s@macro-executeagi:4] GotoIf("SIP/asterisk-asteriskdev1-00000038", "1?agisuccess") in new stack
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] pbx.c:     -- Goto (macro-executeagi,s,7)
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [s@macro-executeagi:7] NoOp("SIP/asterisk-asteriskdev1-00000038", "AGI SUCCESS") in new stack
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [s@lookup-called-party:5] Set("SIP/asterisk-asteriskdev1-00000038", "CALLEDPARTYLOGGEDINSERVERID=") in new stack
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [s@lookup-called-party:6] Set("SIP/asterisk-asteriskdev1-00000038", "CALLEDPARTYLOGGEDINSERVERIP=") in new stack
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [s@lookup-called-party:7] Set("SIP/asterisk-asteriskdev1-00000038", "CALLEDPARTYLOGGEDINSERVERNAME=") in new stack
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [s@lookup-called-party:8] GotoIf("SIP/asterisk-asteriskdev1-00000038", "1?lookupfailed") in new stack
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] pbx.c:     -- Goto (lookup-called-party,s,10)
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [s@lookup-called-party:10] Return("SIP/asterisk-asteriskdev1-00000038", "-1") in new stack
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [1000@macro-dial-localext:45] GosubIf("SIP/asterisk-asteriskdev1-00000038", "0?lookup-called-user,s,1(2201,1000)") in new stack
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [1000@macro-dial-localext:46] Macro("SIP/asterisk-asteriskdev1-00000038", "executeagi,mobileservice.agi?user=1000") in new stack
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [s@macro-executeagi:1] NoOp("SIP/asterisk-asteriskdev1-00000038", "Execute AGI") in new stack
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [s@macro-executeagi:2] GotoIf("SIP/asterisk-asteriskdev1-00000038", "0?agihost0failed") in new stack
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [s@macro-executeagi:3] AGI("SIP/asterisk-asteriskdev1-00000038", "agi://130.10.14.249/mobileservice.agi?user=1000") in new stack
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] res_agi.c:     -- <SIP/asterisk-asteriskdev1-00000038>AGI Script agi://130.10.14.249/mobileservice.agi?user=1000 completed, returning 0
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [s@macro-executeagi:4] GotoIf("SIP/asterisk-asteriskdev1-00000038", "1?agisuccess") in new stack
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] pbx.c:     -- Goto (macro-executeagi,s,7)
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [s@macro-executeagi:7] NoOp("SIP/asterisk-asteriskdev1-00000038", "AGI SUCCESS") in new stack
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [1000@macro-dial-localext:47] GotoIf("SIP/asterisk-asteriskdev1-00000038", "1?callwaitingcheck") in new stack
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] pbx.c:     -- Goto (macro-dial-localext,1000,56)
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [1000@macro-dial-localext:56] GotoIf("SIP/asterisk-asteriskdev1-00000038", "0?callwaiting") in new stack
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [1000@macro-dial-localext:57] GotoIf("SIP/asterisk-asteriskdev1-00000038", "0?callwaiting") in new stack
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [1000@macro-dial-localext:58] GotoIf("SIP/asterisk-asteriskdev1-00000038", "0?callwaiting") in new stack
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [1000@macro-dial-localext:59] GotoIf("SIP/asterisk-asteriskdev1-00000038", "0?callwaiting:execdial") in new stack
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] pbx.c:     -- Goto (macro-dial-localext,1000,64)
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [1000@macro-dial-localext:64] Macro("SIP/asterisk-asteriskdev1-00000038", "executeagi,ringtone.agi?user=1000") in new stack
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [s@macro-executeagi:1] NoOp("SIP/asterisk-asteriskdev1-00000038", "Execute AGI") in new stack
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [s@macro-executeagi:2] GotoIf("SIP/asterisk-asteriskdev1-00000038", "0?agihost0failed") in new stack
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [s@macro-executeagi:3] AGI("SIP/asterisk-asteriskdev1-00000038", "agi://130.10.14.249/ringtone.agi?user=1000") in new stack
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] res_agi.c:     -- AGI Script Executing Application: (SipAddHeader) Options: (Alert-Info: <http://130.10.14.249:8080/provisioning/ringtone/default?user=1000&id=0>)
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] res_agi.c:     -- <SIP/asterisk-asteriskdev1-00000038>AGI Script agi://130.10.14.249/ringtone.agi?user=1000 completed, returning 0
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [s@macro-executeagi:4] GotoIf("SIP/asterisk-asteriskdev1-00000038", "1?agisuccess") in new stack
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] pbx.c:     -- Goto (macro-executeagi,s,7)
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [s@macro-executeagi:7] NoOp("SIP/asterisk-asteriskdev1-00000038", "AGI SUCCESS") in new stack
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [1000@macro-dial-localext:65] GotoIf("SIP/asterisk-asteriskdev1-00000038", "0?setDialOptionExtern") in new stack
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [1000@macro-dial-localext:66] Set("SIP/asterisk-asteriskdev1-00000038", "DIALOPTIONS=tT") in new stack
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [1000@macro-dial-localext:67] Goto("SIP/asterisk-asteriskdev1-00000038", "skipDialOptionsExtern") in new stack
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] pbx.c:     -- Goto (macro-dial-localext,1000,69)
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [1000@macro-dial-localext:69] NoOp("SIP/asterisk-asteriskdev1-00000038", "Transferoptions: tT") in new stack
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [1000@macro-dial-localext:70] GotoIf("SIP/asterisk-asteriskdev1-00000038", "1?noblindtransfer") in new stack
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] pbx.c:     -- Goto (macro-dial-localext,1000,75)
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [1000@macro-dial-localext:75] NoOp("SIP/asterisk-asteriskdev1-00000038", "Transfer failed for ") in new stack
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [1000@macro-dial-localext:76] ExecIf("SIP/asterisk-asteriskdev1-00000038", "0?Set(CALLERID(all)="Tf(Clark Kent (2201)) <2201>")") in new stack
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [1000@macro-dial-localext:77] Dial("SIP/asterisk-asteriskdev1-00000038", "SIP/1000&SIP/soft1000&SIP/web1000,,ItT") in new stack
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] netsock2.c:   == Using SIP VIDEO TOS bits 136
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] netsock2.c:   == Using SIP VIDEO CoS mark 6
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] netsock2.c:   == Using SIP RTP TOS bits 184
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] netsock2.c:   == Using SIP RTP CoS mark 5
[Oct 27 08:41:11] WARNING[26753][C-00000019] channel.c: Don't know any of (h261|h263|h263p|h264) formats
[Oct 27 08:41:11] WARNING[26753][C-00000019] app_dial.c: Unable to create channel of type 'SIP' (cause 20 - Subscriber absent)
[Oct 27 08:41:11] WARNING[26753][C-00000019] app_dial.c: Unable to create channel of type 'SIP' (cause 20 - Subscriber absent)
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] app_dial.c:     -- Called SIP/1000
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] app_dial.c:     -- Connected line update to SIP/asterisk-asteriskdev1-00000038 prevented.
[Oct 27 08:41:11] VERBOSE[26753][C-00000019] app_dial.c:     -- SIP/1000-00000039 is ringing
[Oct 27 08:41:14] WARNING[825][C-00000019] chan_sip.c: Ignoring video stream offer because port number is zero
[Oct 27 08:41:14] WARNING[825][C-00000019] channel.c: Don't know any of (nothing) formats
[Oct 27 08:41:14] WARNING[825][C-00000019] channel.c: Unable to find a codec translation path from (alaw) to (nothing)
[Oct 27 08:41:14] WARNING[825][C-00000019] channel.c: Don't know any of (nothing) formats
[Oct 27 08:41:14] WARNING[825][C-00000019] channel.c: Unable to find a codec translation path from (alaw) to (nothing)
[Oct 27 08:41:14] VERBOSE[26753][C-00000019] app_dial.c:     -- Connected line update to SIP/asterisk-asteriskdev1-00000038 prevented.
[Oct 27 08:41:14] VERBOSE[26753][C-00000019] app_dial.c:     -- SIP/1000-00000039 answered SIP/asterisk-asteriskdev1-00000038
[Oct 27 08:41:21] VERBOSE[22633] pbx.c:   == Setting global variable '130_10_14_249_is' to 'alive'
[Oct 27 08:41:25] VERBOSE[26752] pbx.c:   == Setting global variable '130_10_15_15_is' to 'alive'
[Oct 27 08:41:36] VERBOSE[22633] pbx.c:   == Setting global variable '130_10_14_249_is' to 'alive'
[Oct 27 08:41:37] VERBOSE[26753][C-00000019] res_musiconhold.c:     -- Started music on hold, class 'default', on SIP/asterisk-asteriskdev1-00000038
[Oct 27 08:41:40] VERBOSE[26752] pbx.c:   == Setting global variable '130_10_15_15_is' to 'alive'
[Oct 27 08:41:42] VERBOSE[26753][C-00000019] res_musiconhold.c:     -- Stopped music on hold on SIP/asterisk-asteriskdev1-00000038
[Oct 27 08:41:42] VERBOSE[26753][C-00000019] pbx.c:   == Spawn extension (blindtransfer, 2203, 1) exited non-zero on 'SIP/asterisk-asteriskdev1-00000038'
[Oct 27 08:41:42] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [2203@blindtransfer:1] GotoIf("SIP/asterisk-asteriskdev1-00000038", "0?attendedtransfer-dtmf,2203,1") in new stack
[Oct 27 08:41:42] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [2203@blindtransfer:2] GotoIf("SIP/asterisk-asteriskdev1-00000038", "0?setcallerid:setblindtransferer") in new stack
[Oct 27 08:41:42] VERBOSE[26753][C-00000019] pbx.c:     -- Goto (blindtransfer,2203,4)
[Oct 27 08:41:42] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [2203@blindtransfer:4] Set("SIP/asterisk-asteriskdev1-00000038", "BLINDTRANSFERER=1000") in new stack
[Oct 27 08:41:42] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [2203@blindtransfer:5] Set("SIP/asterisk-asteriskdev1-00000038", "BLINDTRANSFERERUSER=1000") in new stack
[Oct 27 08:41:42] ERROR[26753][C-00000019] func_global.c: Channel 'SIP/1000-00000039' not found!  Variable 'inboundcall' will be blank.
[Oct 27 08:41:42] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [2203@blindtransfer:6] GotoIf("SIP/asterisk-asteriskdev1-00000038", "0?replaceuser:aclcheck") in new stack
[Oct 27 08:41:42] VERBOSE[26753][C-00000019] pbx.c:     -- Goto (blindtransfer,2203,8)
[Oct 27 08:41:42] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [2203@blindtransfer:8] Macro("SIP/asterisk-asteriskdev1-00000038", "executeagi,acl.agi?user=1000&callednum=2203") in new stack
[Oct 27 08:41:42] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [s@macro-executeagi:1] NoOp("SIP/asterisk-asteriskdev1-00000038", "Execute AGI") in new stack
[Oct 27 08:41:42] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [s@macro-executeagi:2] GotoIf("SIP/asterisk-asteriskdev1-00000038", "0?agihost0failed") in new stack
[Oct 27 08:41:42] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [s@macro-executeagi:3] AGI("SIP/asterisk-asteriskdev1-00000038", "agi://130.10.14.249/acl.agi?user=1000&callednum=2203") in new stack
[Oct 27 08:41:42] VERBOSE[26753][C-00000019] res_agi.c:     -- <SIP/asterisk-asteriskdev1-00000038>AGI Script agi://130.10.14.249/acl.agi?user=1000&callednum=2203 completed, returning 0
[Oct 27 08:41:42] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [s@macro-executeagi:4] GotoIf("SIP/asterisk-asteriskdev1-00000038", "1?agisuccess") in new stack
[Oct 27 08:41:42] VERBOSE[26753][C-00000019] pbx.c:     -- Goto (macro-executeagi,s,7)
[Oct 27 08:41:42] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [s@macro-executeagi:7] NoOp("SIP/asterisk-asteriskdev1-00000038", "AGI SUCCESS") in new stack
[Oct 27 08:41:42] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [2203@blindtransfer:9] Set("SIP/asterisk-asteriskdev1-00000038", "BLINDTRANSFERERCONTEXT=from-internal-6000-acl") in new stack
[Oct 27 08:41:42] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [2203@blindtransfer:10] Goto("SIP/asterisk-asteriskdev1-00000038", "from-internal-6000-acl,2203,1") in new stack
[Oct 27 08:41:42] VERBOSE[26753][C-00000019] pbx.c:     -- Goto (from-internal-6000-acl,2203,1)
[Oct 27 08:41:42] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [2203@from-internal-6000-acl:1] Goto("SIP/asterisk-asteriskdev1-00000038", "acl2203,1") in new stack
[Oct 27 08:41:42] VERBOSE[26753][C-00000019] pbx.c:     -- Goto (from-internal-6000-acl,acl2203,1)
[Oct 27 08:41:42] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [acl2203@from-internal-6000-acl:1] NoOp("SIP/asterisk-asteriskdev1-00000038", "ACL check for 2201 - destination 2203") in new stack
[Oct 27 08:41:42] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [acl2203@from-internal-6000-acl:2] Set("SIP/asterisk-asteriskdev1-00000038", "_CALLER=2201") in new stack
[Oct 27 08:41:42] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [acl2203@from-internal-6000-acl:3] Set("SIP/asterisk-asteriskdev1-00000038", "CALLEDNUMBER=2203") in new stack
[Oct 27 08:41:42] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [acl2203@from-internal-6000-acl:4] Macro("SIP/asterisk-asteriskdev1-00000038", "executeagi,set-callerid.agi") in new stack
[Oct 27 08:41:42] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [s@macro-executeagi:1] NoOp("SIP/asterisk-asteriskdev1-00000038", "Execute AGI") in new stack
[Oct 27 08:41:42] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [s@macro-executeagi:2] GotoIf("SIP/asterisk-asteriskdev1-00000038", "0?agihost0failed") in new stack
[Oct 27 08:41:42] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [s@macro-executeagi:3] AGI("SIP/asterisk-asteriskdev1-00000038", "agi://130.10.14.249/set-callerid.agi") in new stack
[Oct 27 08:41:42] VERBOSE[26753][C-00000019] res_agi.c:     -- <SIP/asterisk-asteriskdev1-00000038>AGI Script agi://130.10.14.249/set-callerid.agi completed, returning 0
[Oct 27 08:41:42] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [s@macro-executeagi:4] GotoIf("SIP/asterisk-asteriskdev1-00000038", "1?agisuccess") in new stack
[Oct 27 08:41:42] VERBOSE[26753][C-00000019] pbx.c:     -- Goto (macro-executeagi,s,7)
[Oct 27 08:41:42] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [s@macro-executeagi:7] NoOp("SIP/asterisk-asteriskdev1-00000038", "AGI SUCCESS") in new stack
[Oct 27 08:41:42] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [acl2203@from-internal-6000-acl:5] SIPAddHeader("SIP/asterisk-asteriskdev1-00000038", "Call-Info: <http://130.10.14.249:8080/xmlphone/picture?userid=2201>;purpose=icon") in new stack
[Oct 27 08:41:42] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [acl2203@from-internal-6000-acl:6] NoOp("SIP/asterisk-asteriskdev1-00000038", "REDIRECTINGCOUNT = 0") in new stack
[Oct 27 08:41:42] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [acl2203@from-internal-6000-acl:7] NoOp("SIP/asterisk-asteriskdev1-00000038", "FORWARDARRAY     = ") in new stack
[Oct 27 08:41:42] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [acl2203@from-internal-6000-acl:8] GotoIf("SIP/asterisk-asteriskdev1-00000038", "1?acl") in new stack
[Oct 27 08:41:42] VERBOSE[26753][C-00000019] pbx.c:     -- Goto (from-internal-6000-acl,acl2203,14)
[Oct 27 08:41:42] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [acl2203@from-internal-6000-acl:14] Macro("SIP/asterisk-asteriskdev1-00000038", "executeagi,acl.agi?user=2201&callednum=2203") in new stack
[Oct 27 08:41:42] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [s@macro-executeagi:1] NoOp("SIP/asterisk-asteriskdev1-00000038", "Execute AGI") in new stack
[Oct 27 08:41:42] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [s@macro-executeagi:2] GotoIf("SIP/asterisk-asteriskdev1-00000038", "0?agihost0failed") in new stack
[Oct 27 08:41:42] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [s@macro-executeagi:3] AGI("SIP/asterisk-asteriskdev1-00000038", "agi://130.10.14.249/acl.agi?user=2201&callednum=2203") in new stack
[Oct 27 08:41:42] VERBOSE[26753][C-00000019] res_agi.c:     -- <SIP/asterisk-asteriskdev1-00000038>AGI Script agi://130.10.14.249/acl.agi?user=2201&callednum=2203 completed, returning 0
[Oct 27 08:41:42] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [s@macro-executeagi:4] GotoIf("SIP/asterisk-asteriskdev1-00000038", "1?agisuccess") in new stack
[Oct 27 08:41:42] VERBOSE[26753][C-00000019] pbx.c:     -- Goto (macro-executeagi,s,7)
[Oct 27 08:41:42] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [s@macro-executeagi:7] NoOp("SIP/asterisk-asteriskdev1-00000038", "AGI SUCCESS") in new stack
[Oct 27 08:41:42] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [acl2203@from-internal-6000-acl:15] GosubIf("SIP/asterisk-asteriskdev1-00000038", "0?macro-dialout-clir,s,1(2203,2201)") in new stack
[Oct 27 08:41:42] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [acl2203@from-internal-6000-acl:16] Goto("SIP/asterisk-asteriskdev1-00000038", "from-internal-6000,2203,1") in new stack
[Oct 27 08:41:42] VERBOSE[26753][C-00000019] pbx.c:     -- Goto (from-internal-6000,2203,1)
[Oct 27 08:41:42] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [2203@from-internal-6000:1] Goto("SIP/asterisk-asteriskdev1-00000038", "ltl2203,1") in new stack
[Oct 27 08:41:42] VERBOSE[26753][C-00000019] pbx.c:     -- Goto (from-internal-6000,ltl2203,1)
[Oct 27 08:41:42] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [ltl2203@from-internal-6000:1] NoOp("SIP/asterisk-asteriskdev1-00000038", "local-to-localext 2203") in new stack
[Oct 27 08:41:42] VERBOSE[26753][C-00000019] pbx.c:     -- Executing [ltl2203@from-internal-6000:2] Dial("SIP/asterisk-asteriskdev1-00000038", "SIP/asterisk-asteriskdev1/2203,120,eo") in new stack
[Oct 27 08:41:42] VERBOSE[26753][C-00000019] netsock2.c:   == Using SIP VIDEO TOS bits 136
[Oct 27 08:41:42] VERBOSE[26753][C-00000019] netsock2.c:   == Using SIP VIDEO CoS mark 6
[Oct 27 08:41:42] VERBOSE[26753][C-00000019] netsock2.c:   == Using SIP RTP TOS bits 184
[Oct 27 08:41:42] VERBOSE[26753][C-00000019] netsock2.c:   == Using SIP RTP CoS mark 5
[Oct 27 08:41:42] VERBOSE[26753][C-00000019] app_dial.c:     -- Called SIP/asterisk-asteriskdev1/2203
[Oct 27 08:41:48] VERBOSE[26753][C-00000019] app_dial.c:   == Everyone is busy/congested at this time (1:0/0/1)