Here is the full log. I dialed out on two extensions with the max channels set to 1
[Oct 23 08:24:31] VERBOSE[9052] logger.c: – Executing [818003473288@from-internal:1] Macro(“SIP/525-097d9d70”, “pinsets|1|1”) in new stack
[Oct 23 08:24:31] VERBOSE[9052] logger.c: – Executing [s@macro-pinsets:1] GotoIf(“SIP/525-097d9d70”, “1 = 1?cdr|1”) in new stack
[Oct 23 08:24:31] VERBOSE[9052] logger.c: – Goto (macro-pinsets,cdr,1)
[Oct 23 08:24:31] DEBUG[9052] app_macro.c: Executed application: GotoIf
[Oct 23 08:24:31] VERBOSE[9052] logger.c: – Executing [cdr@macro-pinsets:1] Authenticate(“SIP/525-097d9d70”, “/etc/asterisk/pinset_1|a”) in new stack
[Oct 23 08:24:31] VERBOSE[9052] logger.c: – <SIP/525-097d9d70> Playing ‘agent-pass’ (language ‘en’)
[Oct 23 08:24:35] VERBOSE[9052] logger.c: – <SIP/525-097d9d70> Playing ‘auth-thankyou’ (language ‘en’)
[Oct 23 08:24:36] DEBUG[9052] app_macro.c: Executed application: Authenticate
[Oct 23 08:24:36] VERBOSE[9052] logger.c: – Executing [818003473288@from-internal:2] Macro(“SIP/525-097d9d70”, “dialout-trunk|1|18003473288||”) in new stack
[Oct 23 08:24:36] VERBOSE[9052] logger.c: – Executing [s@macro-dialout-trunk:1] Set(“SIP/525-097d9d70”, “DIAL_TRUNK=1”) in new stack
[Oct 23 08:24:36] DEBUG[9052] app_macro.c: Executed application: Set
[Oct 23 08:24:36] VERBOSE[9052] logger.c: – Executing [s@macro-dialout-trunk:2] Set(“SIP/525-097d9d70”, “DIAL_NUMBER=18003473288”) in new stack
[Oct 23 08:24:36] DEBUG[9052] app_macro.c: Executed application: Set
[Oct 23 08:24:36] VERBOSE[9052] logger.c: – Executing [s@macro-dialout-trunk:3] Set(“SIP/525-097d9d70”, “ROUTE_PASSWD=”) in new stack
[Oct 23 08:24:36] DEBUG[9052] app_macro.c: Executed application: Set
[Oct 23 08:24:36] VERBOSE[9052] logger.c: – Executing [s@macro-dialout-trunk:4] GotoIf(“SIP/525-097d9d70”, “1?noauth”) in new stack
[Oct 23 08:24:36] VERBOSE[9052] logger.c: – Goto (macro-dialout-trunk,s,6)
[Oct 23 08:24:36] DEBUG[9052] app_macro.c: Executed application: GotoIf
[Oct 23 08:24:36] VERBOSE[9052] logger.c: – Executing [s@macro-dialout-trunk:6] GotoIf(“SIP/525-097d9d70”, “0?disabletrunk|1”) in new stack
[Oct 23 08:24:36] DEBUG[9052] app_macro.c: Executed application: GotoIf
[Oct 23 08:24:36] VERBOSE[9052] logger.c: – Executing [s@macro-dialout-trunk:7] Set(“SIP/525-097d9d70”, “_NODEST=”) in new stack
[Oct 23 08:24:36] DEBUG[9052] app_macro.c: Executed application: Set
[Oct 23 08:24:36] VERBOSE[9052] logger.c: – Executing [s@macro-dialout-trunk:8] Set(“SIP/525-097d9d70”, “DIAL_TRUNK_OPTIONS=tr”) in new stack
[Oct 23 08:24:36] DEBUG[9052] app_macro.c: Executed application: Set
[Oct 23 08:24:36] VERBOSE[9052] logger.c: – Executing [s@macro-dialout-trunk:9] Set(“SIP/525-097d9d70”, “GROUP()=OUT_1”) in new stack
[Oct 23 08:24:36] DEBUG[9052] app_macro.c: Executed application: Set
[Oct 23 08:24:36] VERBOSE[9052] logger.c: – Executing [s@macro-dialout-trunk:10] Macro(“SIP/525-097d9d70”, “user-callerid|SKIPTTL”) in new stack
[Oct 23 08:24:36] VERBOSE[9052] logger.c: – Executing [s@macro-user-callerid:1] NoOp(“SIP/525-097d9d70”, “user-callerid: device 525”) in new stack
[Oct 23 08:24:36] DEBUG[9052] app_macro.c: Executed application: Noop
[Oct 23 08:24:36] VERBOSE[9052] logger.c: – Executing [s@macro-user-callerid:2] Set(“SIP/525-097d9d70”, “AMPUSER=525”) in new stack
[Oct 23 08:24:36] DEBUG[9052] app_macro.c: Executed application: Set
[Oct 23 08:24:36] VERBOSE[9052] logger.c: – Executing [s@macro-user-callerid:3] GotoIf(“SIP/525-097d9d70”, “0?report”) in new stack
[Oct 23 08:24:36] DEBUG[9052] app_macro.c: Executed application: GotoIf
[Oct 23 08:24:36] VERBOSE[9052] logger.c: – Executing [s@macro-user-callerid:4] GotoIf(“SIP/525-097d9d70”, “0?start”) in new stack
[Oct 23 08:24:36] DEBUG[9052] app_macro.c: Executed application: GotoIf
[Oct 23 08:24:36] VERBOSE[9052] logger.c: – Executing [s@macro-user-callerid:5] Set(“SIP/525-097d9d70”, “REALCALLERIDNUM=525”) in new stack
[Oct 23 08:24:36] DEBUG[9052] app_macro.c: Executed application: Set
[Oct 23 08:24:36] VERBOSE[9052] logger.c: – Executing [s@macro-user-callerid:6] NoOp(“SIP/525-097d9d70”, “REALCALLERIDNUM is 525”) in new stack
[Oct 23 08:24:36] DEBUG[9052] app_macro.c: Executed application: NoOp
[Oct 23 08:24:36] VERBOSE[9052] logger.c: – Executing [s@macro-user-callerid:7] Set(“SIP/525-097d9d70”, “AMPUSER=525”) in new stack
[Oct 23 08:24:36] DEBUG[9052] app_macro.c: Executed application: Set
[Oct 23 08:24:36] VERBOSE[9052] logger.c: – Executing [s@macro-user-callerid:8] Set(“SIP/525-097d9d70”, “AMPUSERCIDNAME=525 Kenton”) in new stack
[Oct 23 08:24:36] DEBUG[9052] app_macro.c: Executed application: Set
[Oct 23 08:24:36] VERBOSE[9052] logger.c: – Executing [s@macro-user-callerid:9] GotoIf(“SIP/525-097d9d70”, “0?report”) in new stack
[Oct 23 08:24:36] DEBUG[9052] app_macro.c: Executed application: GotoIf
[Oct 23 08:24:36] VERBOSE[9052] logger.c: – Executing [s@macro-user-callerid:10] Set(“SIP/525-097d9d70”, “AMPUSERCID=525”) in new stack
[Oct 23 08:24:36] DEBUG[9052] app_macro.c: Executed application: Set
[Oct 23 08:24:36] VERBOSE[9052] logger.c: – Executing [s@macro-user-callerid:11] Set(“SIP/525-097d9d70”, “CALLERID(all)=“525 Kenton” <525>”) in new stack
[Oct 23 08:24:36] DEBUG[9052] app_macro.c: Executed application: Set
[Oct 23 08:24:36] VERBOSE[9052] logger.c: – Executing [s@macro-user-callerid:12] Set(“SIP/525-097d9d70”, “REALCALLERIDNUM=525”) in new stack
[Oct 23 08:24:36] DEBUG[9052] app_macro.c: Executed application: Set
[Oct 23 08:24:36] VERBOSE[9052] logger.c: – Executing [s@macro-user-callerid:13] NoOp(“SIP/525-097d9d70”, “TTL: ARG1: SKIPTTL”) in new stack
[Oct 23 08:24:36] DEBUG[9052] app_macro.c: Executed application: Noop
[Oct 23 08:24:36] VERBOSE[9052] logger.c: – Executing [s@macro-user-callerid:14] GotoIf(“SIP/525-097d9d70”, “1?continue”) in new stack
[Oct 23 08:24:36] VERBOSE[9052] logger.c: – Goto (macro-user-callerid,s,23)
[Oct 23 08:24:36] DEBUG[9052] app_macro.c: Executed application: GotoIf
[Oct 23 08:24:36] VERBOSE[9052] logger.c: – Executing [s@macro-user-callerid:23] NoOp(“SIP/525-097d9d70”, “Using CallerID “525 Kenton” <525>”) in new stack
[Oct 23 08:24:36] DEBUG[9052] app_macro.c: Executed application: NoOp
[Oct 23 08:24:36] DEBUG[9052] app_macro.c: Executed application: Macro
[Oct 23 08:24:36] VERBOSE[9052] logger.c: – Executing [s@macro-dialout-trunk:11] Macro(“SIP/525-097d9d70”, “record-enable|525|OUT”) in new stack
[Oct 23 08:24:36] VERBOSE[9052] logger.c: – Executing [s@macro-record-enable:1] GotoIf(“SIP/525-097d9d70”, “0?2:4”) in new stack
[Oct 23 08:24:36] VERBOSE[9052] logger.c: – Goto (macro-record-enable,s,4)
[Oct 23 08:24:36] DEBUG[9052] app_macro.c: Executed application: GotoIf
[Oct 23 08:24:36] VERBOSE[9052] logger.c: – Executing [s@macro-record-enable:4] AGI(“SIP/525-097d9d70”, “recordingcheck|20071023-082436|1193149471.13”) in new stack
[Oct 23 08:24:36] VERBOSE[9052] logger.c: – Launched AGI Script /var/lib/asterisk/agi-bin/recordingcheck
[Oct 23 08:24:36] VERBOSE[9052] logger.c: recordingcheck|20071023-082436|1193149471.13: Outbound recording not enabled
[Oct 23 08:24:36] VERBOSE[9052] logger.c: – AGI Script recordingcheck completed, returning 0
[Oct 23 08:24:36] DEBUG[9052] app_macro.c: Executed application: AGI
[Oct 23 08:24:36] VERBOSE[9052] logger.c: – Executing [s@macro-record-enable:5] NoOp(“SIP/525-097d9d70”, “No recording needed”) in new stack
[Oct 23 08:24:36] DEBUG[9052] app_macro.c: Executed application: Noop
[Oct 23 08:24:36] DEBUG[9052] app_macro.c: Executed application: Macro
[Oct 23 08:24:36] VERBOSE[9052] logger.c: – Executing [s@macro-dialout-trunk:12] GotoIf(“SIP/525-097d9d70”, “0?skipoutcid”) in new stack
[Oct 23 08:24:36] DEBUG[9052] app_macro.c: Executed application: GotoIf
[Oct 23 08:24:36] VERBOSE[9052] logger.c: – Executing [s@macro-dialout-trunk:13] Set(“SIP/525-097d9d70”, “DIAL_TRUNK_OPTIONS=”) in new stack
[Oct 23 08:24:36] DEBUG[9052] app_macro.c: Executed application: Set
[Oct 23 08:24:36] VERBOSE[9052] logger.c: – Executing [s@macro-dialout-trunk:14] Macro(“SIP/525-097d9d70”, “outbound-callerid|1”) in new stack
[Oct 23 08:24:36] VERBOSE[9052] logger.c: – Executing [s@macro-outbound-callerid:1] GotoIf(“SIP/525-097d9d70”, “1?start”) in new stack
[Oct 23 08:24:36] VERBOSE[9052] logger.c: – Goto (macro-outbound-callerid,s,3)
[Oct 23 08:24:36] DEBUG[9052] app_macro.c: Executed application: GotoIf
[Oct 23 08:24:36] VERBOSE[9052] logger.c: – Executing [s@macro-outbound-callerid:3] NoOp(“SIP/525-097d9d70”, “REALCALLERIDNUM is 525”) in new stack
[Oct 23 08:24:36] DEBUG[9052] app_macro.c: Executed application: NoOp
[Oct 23 08:24:36] VERBOSE[9052] logger.c: – Executing [s@macro-outbound-callerid:4] GotoIf(“SIP/525-097d9d70”, “1?normcid”) in new stack
[Oct 23 08:24:36] VERBOSE[9052] logger.c: – Goto (macro-outbound-callerid,s,9)
[Oct 23 08:24:36] DEBUG[9052] app_macro.c: Executed application: GotoIf
[Oct 23 08:24:36] VERBOSE[9052] logger.c: – Executing [s@macro-outbound-callerid:9] Set(“SIP/525-097d9d70”, “USEROUTCID=”) in new stack
[Oct 23 08:24:36] DEBUG[9052] app_macro.c: Executed application: Set
[Oct 23 08:24:36] DEBUG[9052] db.c: Unable to find key ‘525/emergency_cid’ in family ‘DEVICE’
[Oct 23 08:24:36] DEBUG[9052] func_db.c: DB: DEVICE/525/emergency_cid not found in database.
[Oct 23 08:24:36] VERBOSE[9052] logger.c: – Executing [s@macro-outbound-callerid:10] Set(“SIP/525-097d9d70”, “EMERGENCYCID=”) in new stack
[Oct 23 08:24:36] DEBUG[9052] app_macro.c: Executed application: Set
[Oct 23 08:24:36] VERBOSE[9052] logger.c: – Executing [s@macro-outbound-callerid:11] Set(“SIP/525-097d9d70”, “TRUNKOUTCID=2282064501”) in new stack
[Oct 23 08:24:36] DEBUG[9052] app_macro.c: Executed application: Set
[Oct 23 08:24:36] VERBOSE[9052] logger.c: – Executing [s@macro-outbound-callerid:12] GotoIf(“SIP/525-097d9d70”, “1?trunkcid”) in new stack
[Oct 23 08:24:36] VERBOSE[9052] logger.c: – Goto (macro-outbound-callerid,s,16)
[Oct 23 08:24:36] DEBUG[9052] app_macro.c: Executed application: GotoIf
[Oct 23 08:24:36] VERBOSE[9052] logger.c: – Executing [s@macro-outbound-callerid:16] GotoIf(“SIP/525-097d9d70”, “0?usercid”) in new stack
[Oct 23 08:24:36] DEBUG[9052] app_macro.c: Executed application: GotoIf
[Oct 23 08:24:36] VERBOSE[9052] logger.c: – Executing [s@macro-outbound-callerid:17] Set(“SIP/525-097d9d70”, “CALLERID(all)=2282064501”) in new stack
[Oct 23 08:24:36] DEBUG[9052] app_macro.c: Executed application: Set
[Oct 23 08:24:36] VERBOSE[9052] logger.c: – Executing [s@macro-outbound-callerid:18] GotoIf(“SIP/525-097d9d70”, “1?report”) in new stack
[Oct 23 08:24:36] VERBOSE[9052] logger.c: – Goto (macro-outbound-callerid,s,22)
[Oct 23 08:24:36] DEBUG[9052] app_macro.c: Executed application: GotoIf
[Oct 23 08:24:36] VERBOSE[9052] logger.c: – Executing [s@macro-outbound-callerid:22] NoOp(“SIP/525-097d9d70”, "CallerID set to “2282064501” ") in new stack
[Oct 23 08:24:36] DEBUG[9052] app_macro.c: Executed application: NoOp
[Oct 23 08:24:36] DEBUG[9052] app_macro.c: Executed application: Macro
[Oct 23 08:24:36] VERBOSE[9052] logger.c: – Executing [s@macro-dialout-trunk:15] GotoIf(“SIP/525-097d9d70”, “0?nomax”) in new stack
[Oct 23 08:24:36] DEBUG[9052] app_macro.c: Executed application: GotoIf
[Oct 23 08:24:36] VERBOSE[9052] logger.c: – Executing [s@macro-dialout-trunk:16] GotoIf(“SIP/525-097d9d70”, “0?chanfull”) in new stack
[Oct 23 08:24:36] DEBUG[9052] app_macro.c: Executed application: GotoIf
[Oct 23 08:24:36] VERBOSE[9052] logger.c: – Executing [s@macro-dialout-trunk:17] AGI(“SIP/525-097d9d70”, “fixlocalprefix”) in new stack
[Oct 23 08:24:36] VERBOSE[9052] logger.c: – Launched AGI Script /var/lib/asterisk/agi-bin/fixlocalprefix
[Oct 23 08:24:36] VERBOSE[9052] logger.c: > fixlocalprefix: Using pattern 81NXXNXXXXXX
[Oct 23 08:24:36] VERBOSE[9052] logger.c: – AGI Script fixlocalprefix completed, returning 0
[Oct 23 08:24:36] DEBUG[9052] app_macro.c: Executed application: AGI
[Oct 23 08:24:36] VERBOSE[9052] logger.c: – Executing [s@macro-dialout-trunk:18] Set(“SIP/525-097d9d70”, “OUTNUM=18003473288”) in new stack
[Oct 23 08:24:36] DEBUG[9052] app_macro.c: Executed application: Set
[Oct 23 08:24:36] VERBOSE[9052] logger.c: – Executing [s@macro-dialout-trunk:19] Set(“SIP/525-097d9d70”, “custom=SIP/vitel-outbound”) in new stack
[Oct 23 08:24:36] DEBUG[9052] app_macro.c: Executed application: Set
[Oct 23 08:24:36] VERBOSE[9052] logger.c: – Executing [s@macro-dialout-trunk:20] GotoIf(“SIP/525-097d9d70”, “1?gocall”) in new stack
[Oct 23 08:24:36] VERBOSE[9052] logger.c: – Goto (macro-dialout-trunk,s,24)
[Oct 23 08:24:36] DEBUG[9052] app_macro.c: Executed application: GotoIf
[Oct 23 08:24:36] VERBOSE[9052] logger.c: – Executing [s@macro-dialout-trunk:24] GotoIf(“SIP/525-097d9d70”, “0?customtrunk”) in new stack
[Oct 23 08:24:36] DEBUG[9052] app_macro.c: Executed application: GotoIf
[Oct 23 08:24:36] VERBOSE[9052] logger.c: – Executing [s@macro-dialout-trunk:25] Dial(“SIP/525-097d9d70”, “SIP/vitel-outbound/18003473288|300|”) in new stack
[Oct 23 08:24:36] VERBOSE[9052] logger.c: – Called vitel-outbound/18003473288
[Oct 23 08:24:38] VERBOSE[9052] logger.c: – SIP/vitel-outbound-097bc0a0 answered SIP/525-097d9d70
[Oct 23 08:24:38] VERBOSE[9052] logger.c: – Packet2Packet bridging SIP/525-097d9d70 and SIP/vitel-outbound-097bc0a0
[Oct 23 08:24:40] VERBOSE[9061] logger.c: – Executing [818003473288@from-internal:1] Macro(“SIP/203-097c9f50”, “pinsets|1|1”) in new stack
[Oct 23 08:24:40] VERBOSE[9061] logger.c: – Executing [s@macro-pinsets:1] GotoIf(“SIP/203-097c9f50”, “1 = 1?cdr|1”) in new stack
[Oct 23 08:24:40] VERBOSE[9061] logger.c: – Goto (macro-pinsets,cdr,1)
[Oct 23 08:24:40] DEBUG[9061] app_macro.c: Executed application: GotoIf
[Oct 23 08:24:40] VERBOSE[9061] logger.c: – Executing [cdr@macro-pinsets:1] Authenticate(“SIP/203-097c9f50”, “/etc/asterisk/pinset_1|a”) in new stack
[Oct 23 08:24:40] VERBOSE[9061] logger.c: – <SIP/203-097c9f50> Playing ‘agent-pass’ (language ‘en’)
[Oct 23 08:24:46] VERBOSE[9061] logger.c: – <SIP/203-097c9f50> Playing ‘auth-thankyou’ (language ‘en’)
[Oct 23 08:24:47] DEBUG[9061] app_macro.c: Executed application: Authenticate
[Oct 23 08:24:47] VERBOSE[9061] logger.c: – Executing [818003473288@from-internal:2] Macro(“SIP/203-097c9f50”, “dialout-trunk|1|18003473288||”) in new stack
[Oct 23 08:24:47] VERBOSE[9061] logger.c: – Executing [s@macro-dialout-trunk:1] Set(“SIP/203-097c9f50”, “DIAL_TRUNK=1”) in new stack
[Oct 23 08:24:47] DEBUG[9061] app_macro.c: Executed application: Set
[Oct 23 08:24:47] VERBOSE[9061] logger.c: – Executing [s@macro-dialout-trunk:2] Set(“SIP/203-097c9f50”, “DIAL_NUMBER=18003473288”) in new stack
[Oct 23 08:24:47] DEBUG[9061] app_macro.c: Executed application: Set
[Oct 23 08:24:47] VERBOSE[9061] logger.c: – Executing [s@macro-dialout-trunk:3] Set(“SIP/203-097c9f50”, “ROUTE_PASSWD=”) in new stack
[Oct 23 08:24:47] DEBUG[9061] app_macro.c: Executed application: Set
[Oct 23 08:24:47] VERBOSE[9061] logger.c: – Executing [s@macro-dialout-trunk:4] GotoIf(“SIP/203-097c9f50”, “1?noauth”) in new stack
[Oct 23 08:24:47] VERBOSE[9061] logger.c: – Goto (macro-dialout-trunk,s,6)
[Oct 23 08:24:47] DEBUG[9061] app_macro.c: Executed application: GotoIf
[Oct 23 08:24:47] VERBOSE[9061] logger.c: – Executing [s@macro-dialout-trunk:6] GotoIf(“SIP/203-097c9f50”, “0?disabletrunk|1”) in new stack
[Oct 23 08:24:47] DEBUG[9061] app_macro.c: Executed application: GotoIf
[Oct 23 08:24:47] VERBOSE[9061] logger.c: – Executing [s@macro-dialout-trunk:7] Set(“SIP/203-097c9f50”, “_NODEST=”) in new stack
[Oct 23 08:24:47] DEBUG[9061] app_macro.c: Executed application: Set
[Oct 23 08:24:47] VERBOSE[9061] logger.c: – Executing [s@macro-dialout-trunk:8] Set(“SIP/203-097c9f50”, “DIAL_TRUNK_OPTIONS=tr”) in new stack
[Oct 23 08:24:47] DEBUG[9061] app_macro.c: Executed application: Set
[Oct 23 08:24:47] VERBOSE[9061] logger.c: – Executing [s@macro-dialout-trunk:9] Set(“SIP/203-097c9f50”, “GROUP()=OUT_1”) in new stack
[Oct 23 08:24:47] DEBUG[9061] app_macro.c: Executed application: Set
[Oct 23 08:24:47] VERBOSE[9061] logger.c: – Executing [s@macro-dialout-trunk:10] Macro(“SIP/203-097c9f50”, “user-callerid|SKIPTTL”) in new stack
[Oct 23 08:24:47] VERBOSE[9061] logger.c: – Executing [s@macro-user-callerid:1] NoOp(“SIP/203-097c9f50”, “user-callerid: device 203”) in new stack
[Oct 23 08:24:47] DEBUG[9061] app_macro.c: Executed application: Noop
[Oct 23 08:24:47] VERBOSE[9061] logger.c: – Executing [s@macro-user-callerid:2] Set(“SIP/203-097c9f50”, “AMPUSER=203”) in new stack
[Oct 23 08:24:47] DEBUG[9061] app_macro.c: Executed application: Set
[Oct 23 08:24:47] VERBOSE[9061] logger.c: – Executing [s@macro-user-callerid:3] GotoIf(“SIP/203-097c9f50”, “0?report”) in new stack
[Oct 23 08:24:47] DEBUG[9061] app_macro.c: Executed application: GotoIf
[Oct 23 08:24:47] VERBOSE[9061] logger.c: – Executing [s@macro-user-callerid:4] GotoIf(“SIP/203-097c9f50”, “0?start”) in new stack
[Oct 23 08:24:47] DEBUG[9061] app_macro.c: Executed application: GotoIf
[Oct 23 08:24:47] VERBOSE[9061] logger.c: – Executing [s@macro-user-callerid:5] Set(“SIP/203-097c9f50”, “REALCALLERIDNUM=203”) in new stack
[Oct 23 08:24:47] DEBUG[9061] app_macro.c: Executed application: Set
[Oct 23 08:24:47] VERBOSE[9061] logger.c: – Executing [s@macro-user-callerid:6] NoOp(“SIP/203-097c9f50”, “REALCALLERIDNUM is 203”) in new stack
[Oct 23 08:24:47] DEBUG[9061] app_macro.c: Executed application: NoOp
[Oct 23 08:24:47] VERBOSE[9061] logger.c: – Executing [s@macro-user-callerid:7] Set(“SIP/203-097c9f50”, “AMPUSER=203”) in new stack
[Oct 23 08:24:47] DEBUG[9061] app_macro.c: Executed application: Set
[Oct 23 08:24:47] VERBOSE[9061] logger.c: – Executing [s@macro-user-callerid:8] Set(“SIP/203-097c9f50”, “AMPUSERCIDNAME=Kenton Softphone”) in new stack
[Oct 23 08:24:47] DEBUG[9061] app_macro.c: Executed application: Set
[Oct 23 08:24:47] VERBOSE[9061] logger.c: – Executing [s@macro-user-callerid:9] GotoIf(“SIP/203-097c9f50”, “0?report”) in new stack
[Oct 23 08:24:47] DEBUG[9061] app_macro.c: Executed application: GotoIf
[Oct 23 08:24:47] VERBOSE[9061] logger.c: – Executing [s@macro-user-callerid:10] Set(“SIP/203-097c9f50”, “AMPUSERCID=203”) in new stack
[Oct 23 08:24:47] DEBUG[9061] app_macro.c: Executed application: Set
[Oct 23 08:24:47] VERBOSE[9061] logger.c: – Executing [s@macro-user-callerid:11] Set(“SIP/203-097c9f50”, “CALLERID(all)=“Kenton Softphone” <203>”) in new stack
[Oct 23 08:24:47] DEBUG[9061] app_macro.c: Executed application: Set
[Oct 23 08:24:47] VERBOSE[9061] logger.c: – Executing [s@macro-user-callerid:12] Set(“SIP/203-097c9f50”, “REALCALLERIDNUM=203”) in new stack
[Oct 23 08:24:47] DEBUG[9061] app_macro.c: Executed application: Set
[Oct 23 08:24:47] VERBOSE[9061] logger.c: – Executing [s@macro-user-callerid:13] NoOp(“SIP/203-097c9f50”, “TTL: ARG1: SKIPTTL”) in new stack
[Oct 23 08:24:47] DEBUG[9061] app_macro.c: Executed application: Noop
[Oct 23 08:24:47] VERBOSE[9061] logger.c: – Executing [s@macro-user-callerid:14] GotoIf(“SIP/203-097c9f50”, “1?continue”) in new stack
[Oct 23 08:24:47] VERBOSE[9061] logger.c: – Goto (macro-user-callerid,s,23)
[Oct 23 08:24:47] DEBUG[9061] app_macro.c: Executed application: GotoIf
[Oct 23 08:24:47] VERBOSE[9061] logger.c: – Executing [s@macro-user-callerid:23] NoOp(“SIP/203-097c9f50”, “Using CallerID “Kenton Softphone” <203>”) in new stack
[Oct 23 08:24:47] DEBUG[9061] app_macro.c: Executed application: NoOp
[Oct 23 08:24:47] DEBUG[9061] app_macro.c: Executed application: Macro
[Oct 23 08:24:47] VERBOSE[9061] logger.c: – Executing [s@macro-dialout-trunk:11] Macro(“SIP/203-097c9f50”, “record-enable|203|OUT”) in new stack
[Oct 23 08:24:47] VERBOSE[9061] logger.c: – Executing [s@macro-record-enable:1] GotoIf(“SIP/203-097c9f50”, “0?2:4”) in new stack
[Oct 23 08:24:47] VERBOSE[9061] logger.c: – Goto (macro-record-enable,s,4)
[Oct 23 08:24:47] DEBUG[9061] app_macro.c: Executed application: GotoIf
[Oct 23 08:24:47] VERBOSE[9061] logger.c: – Executing [s@macro-record-enable:4] AGI(“SIP/203-097c9f50”, “recordingcheck|20071023-082447|1193149480.15”) in new stack
[Oct 23 08:24:47] VERBOSE[9061] logger.c: – Launched AGI Script /var/lib/asterisk/agi-bin/recordingcheck
[Oct 23 08:24:47] VERBOSE[9061] logger.c: recordingcheck|20071023-082447|1193149480.15: Outbound recording not enabled
[Oct 23 08:24:47] VERBOSE[9061] logger.c: – AGI Script recordingcheck completed, returning 0
[Oct 23 08:24:47] DEBUG[9061] app_macro.c: Executed application: AGI
[Oct 23 08:24:47] VERBOSE[9061] logger.c: – Executing [s@macro-record-enable:5] NoOp(“SIP/203-097c9f50”, “No recording needed”) in new stack
[Oct 23 08:24:47] DEBUG[9061] app_macro.c: Executed application: Noop
[Oct 23 08:24:47] DEBUG[9061] app_macro.c: Executed application: Macro
[Oct 23 08:24:47] VERBOSE[9061] logger.c: – Executing [s@macro-dialout-trunk:12] GotoIf(“SIP/203-097c9f50”, “0?skipoutcid”) in new stack
[Oct 23 08:24:47] DEBUG[9061] app_macro.c: Executed application: GotoIf
[Oct 23 08:24:47] VERBOSE[9061] logger.c: – Executing [s@macro-dialout-trunk:13] Set(“SIP/203-097c9f50”, “DIAL_TRUNK_OPTIONS=”) in new stack
[Oct 23 08:24:47] DEBUG[9061] app_macro.c: Executed application: Set
[Oct 23 08:24:47] VERBOSE[9061] logger.c: – Executing [s@macro-dialout-trunk:14] Macro(“SIP/203-097c9f50”, “outbound-callerid|1”) in new stack
[Oct 23 08:24:47] VERBOSE[9061] logger.c: – Executing [s@macro-outbound-callerid:1] GotoIf(“SIP/203-097c9f50”, “1?start”) in new stack
[Oct 23 08:24:47] VERBOSE[9061] logger.c: – Goto (macro-outbound-callerid,s,3)
[Oct 23 08:24:47] DEBUG[9061] app_macro.c: Executed application: GotoIf
[Oct 23 08:24:47] VERBOSE[9061] logger.c: – Executing [s@macro-outbound-callerid:3] NoOp(“SIP/203-097c9f50”, “REALCALLERIDNUM is 203”) in new stack
[Oct 23 08:24:47] DEBUG[9061] app_macro.c: Executed application: NoOp
[Oct 23 08:24:47] VERBOSE[9061] logger.c: – Executing [s@macro-outbound-callerid:4] GotoIf(“SIP/203-097c9f50”, “1?normcid”) in new stack
[Oct 23 08:24:47] VERBOSE[9061] logger.c: – Goto (macro-outbound-callerid,s,9)
[Oct 23 08:24:47] DEBUG[9061] app_macro.c: Executed application: GotoIf
[Oct 23 08:24:47] VERBOSE[9061] logger.c: – Executing [s@macro-outbound-callerid:9] Set(“SIP/203-097c9f50”, “USEROUTCID=”) in new stack
[Oct 23 08:24:47] DEBUG[9061] app_macro.c: Executed application: Set
[Oct 23 08:24:47] DEBUG[9061] db.c: Unable to find key ‘203/emergency_cid’ in family ‘DEVICE’
[Oct 23 08:24:47] DEBUG[9061] func_db.c: DB: DEVICE/203/emergency_cid not found in database.
[Oct 23 08:24:47] VERBOSE[9061] logger.c: – Executing [s@macro-outbound-callerid:10] Set(“SIP/203-097c9f50”, “EMERGENCYCID=”) in new stack
[Oct 23 08:24:47] DEBUG[9061] app_macro.c: Executed application: Set
[Oct 23 08:24:47] VERBOSE[9061] logger.c: – Executing [s@macro-outbound-callerid:11] Set(“SIP/203-097c9f50”, “TRUNKOUTCID=2282064501”) in new stack
[Oct 23 08:24:47] DEBUG[9061] app_macro.c: Executed application: Set
[Oct 23 08:24:47] VERBOSE[9061] logger.c: – Executing [s@macro-outbound-callerid:12] GotoIf(“SIP/203-097c9f50”, “1?trunkcid”) in new stack
[Oct 23 08:24:47] VERBOSE[9061] logger.c: – Goto (macro-outbound-callerid,s,16)
[Oct 23 08:24:47] DEBUG[9061] app_macro.c: Executed application: GotoIf
[Oct 23 08:24:47] VERBOSE[9061] logger.c: – Executing [s@macro-outbound-callerid:16] GotoIf(“SIP/203-097c9f50”, “0?usercid”) in new stack
[Oct 23 08:24:47] DEBUG[9061] app_macro.c: Executed application: GotoIf
[Oct 23 08:24:47] VERBOSE[9061] logger.c: – Executing [s@macro-outbound-callerid:17] Set(“SIP/203-097c9f50”, “CALLERID(all)=2282064501”) in new stack
[Oct 23 08:24:47] DEBUG[9061] app_macro.c: Executed application: Set
[Oct 23 08:24:47] VERBOSE[9061] logger.c: – Executing [s@macro-outbound-callerid:18] GotoIf(“SIP/203-097c9f50”, “1?report”) in new stack
[Oct 23 08:24:47] VERBOSE[9061] logger.c: – Goto (macro-outbound-callerid,s,22)
[Oct 23 08:24:47] DEBUG[9061] app_macro.c: Executed application: GotoIf
[Oct 23 08:24:47] VERBOSE[9061] logger.c: – Executing [s@macro-outbound-callerid:22] NoOp(“SIP/203-097c9f50”, "CallerID set to “2282064501” ") in new stack
[Oct 23 08:24:47] DEBUG[9061] app_macro.c: Executed application: NoOp
[Oct 23 08:24:47] DEBUG[9061] app_macro.c: Executed application: Macro
[Oct 23 08:24:47] VERBOSE[9061] logger.c: – Executing [s@macro-dialout-trunk:15] GotoIf(“SIP/203-097c9f50”, “0?nomax”) in new stack
[Oct 23 08:24:47] DEBUG[9061] app_macro.c: Executed application: GotoIf
[Oct 23 08:24:47] VERBOSE[9061] logger.c: – Executing [s@macro-dialout-trunk:16] GotoIf(“SIP/203-097c9f50”, “0?chanfull”) in new stack
[Oct 23 08:24:47] DEBUG[9061] app_macro.c: Executed application: GotoIf
[Oct 23 08:24:47] VERBOSE[9061] logger.c: – Executing [s@macro-dialout-trunk:17] AGI(“SIP/203-097c9f50”, “fixlocalprefix”) in new stack
[Oct 23 08:24:47] VERBOSE[9061] logger.c: – Launched AGI Script /var/lib/asterisk/agi-bin/fixlocalprefix
[Oct 23 08:24:47] VERBOSE[9061] logger.c: > fixlocalprefix: Using pattern 81NXXNXXXXXX
[Oct 23 08:24:47] VERBOSE[9061] logger.c: – AGI Script fixlocalprefix completed, returning 0
[Oct 23 08:24:47] DEBUG[9061] app_macro.c: Executed application: AGI
[Oct 23 08:24:47] VERBOSE[9061] logger.c: – Executing [s@macro-dialout-trunk:18] Set(“SIP/203-097c9f50”, “OUTNUM=18003473288”) in new stack
[Oct 23 08:24:47] DEBUG[9061] app_macro.c: Executed application: Set
[Oct 23 08:24:47] VERBOSE[9061] logger.c: – Executing [s@macro-dialout-trunk:19] Set(“SIP/203-097c9f50”, “custom=SIP/vitel-outbound”) in new stack
[Oct 23 08:24:47] DEBUG[9061] app_macro.c: Executed application: Set
[Oct 23 08:24:47] VERBOSE[9061] logger.c: – Executing [s@macro-dialout-trunk:20] GotoIf(“SIP/203-097c9f50”, “1?gocall”) in new stack
[Oct 23 08:24:47] VERBOSE[9061] logger.c: – Goto (macro-dialout-trunk,s,24)
[Oct 23 08:24:47] DEBUG[9061] app_macro.c: Executed application: GotoIf
[Oct 23 08:24:47] VERBOSE[9061] logger.c: – Executing [s@macro-dialout-trunk:24] GotoIf(“SIP/203-097c9f50”, “0?customtrunk”) in new stack
[Oct 23 08:24:47] DEBUG[9061] app_macro.c: Executed application: GotoIf
[Oct 23 08:24:47] VERBOSE[9061] logger.c: – Executing [s@macro-dialout-trunk:25] Dial(“SIP/203-097c9f50”, “SIP/vitel-outbound/18003473288|300|”) in new stack
[Oct 23 08:24:47] VERBOSE[9061] logger.c: – Called vitel-outbound/18003473288
[Oct 23 08:24:49] VERBOSE[9061] logger.c: – SIP/vitel-outbound-0976add8 answered SIP/203-097c9f50
[Oct 23 08:24:49] VERBOSE[9061] logger.c: – Packet2Packet bridging SIP/203-097c9f50 and SIP/vitel-outbound-0976add8
[Oct 23 08:24:56] VERBOSE[8959] logger.c: – Remote UNIX connection disconnected
[Oct 23 08:25:08] VERBOSE[9052] logger.c: == Spawn extension (macro-dialout-trunk, s, 25) exited non-zero on ‘SIP/525-097d9d70’ in macro ‘dialout-trunk’
[Oct 23 08:25:08] VERBOSE[9052] logger.c: == Spawn extension (macro-dialout-trunk, s, 25) exited non-zero on ‘SIP/525-097d9d70’
[Oct 23 08:25:08] VERBOSE[9052] logger.c: – Executing [h@macro-dialout-trunk:1] Macro(“SIP/525-097d9d70”, “hangupcall”) in new stack
[Oct 23 08:25:08] VERBOSE[9052] logger.c: – Executing [s@macro-hangupcall:1] ResetCDR(“SIP/525-097d9d70”, “w”) in new stack
[Oct 23 08:25:08] ERROR[9052] cdr_addon_mysql.c: cdr_mysql: cannot connect to database server localhost. CDR will not be spooled.
[Oct 23 08:25:08] DEBUG[9052] cdr_addon_mysql.c: cdr_mysql: inserting a CDR record.
[Oct 23 08:25:08] DEBUG[9052] cdr_addon_mysql.c: cdr_mysql: SQL command as follows: INSERT INTO cdr (calldate,clid,src,dst,dcontext,channel,dstchannel,lastapp,lastdata,duration,billsec,disposition,amaflags,accountcode,uniqueid) VALUES (‘2007-10-23 08:24:31’,’“2282064501” ‘,‘HospitalLomadeLuz’,‘818003473288’,‘from-internal’, ‘SIP/525-097d9d70’,‘SIP/vitel-outbound-097bc0a0’,‘Dial’,‘SIP/vitel-outbound/18003473288|300|’,37,37,‘ANSWERED’,3,‘1234’,‘1193149471.13’)
[Oct 23 08:25:08] DEBUG[9052] app_macro.c: Executed application: ResetCDR
[Oct 23 08:25:08] VERBOSE[9052] logger.c: – Executing [s@macro-hangupcall:2] NoCDR(“SIP/525-097d9d70”, “”) in new stack
[Oct 23 08:25:08] DEBUG[9052] app_macro.c: Executed application: NoCDR
[Oct 23 08:25:08] VERBOSE[9052] logger.c: – Executing [s@macro-hangupcall:3] GotoIf(“SIP/525-097d9d70”, “1?skiprg”) in new stack
[Oct 23 08:25:08] VERBOSE[9052] logger.c: – Goto (macro-hangupcall,s,6)
[Oct 23 08:25:08] DEBUG[9052] app_macro.c: Executed application: GotoIf
[Oct 23 08:25:08] VERBOSE[9052] logger.c: – Executing [s@macro-hangupcall:6] GotoIf(“SIP/525-097d9d70”, “1?skipblkvm”) in new stack
[Oct 23 08:25:08] VERBOSE[9052] logger.c: – Goto (macro-hangupcall,s,9)
[Oct 23 08:25:08] DEBUG[9052] app_macro.c: Executed application: GotoIf
[Oct 23 08:25:08] VERBOSE[9052] logger.c: – Executing [s@macro-hangupcall:9] GotoIf(“SIP/525-097d9d70”, “1?theend”) in new stack
[Oct 23 08:25:08] VERBOSE[9052] logger.c: – Goto (macro-hangupcall,s,11)
[Oct 23 08:25:08] DEBUG[9052] app_macro.c: Executed application: GotoIf
[Oct 23 08:25:08] VERBOSE[9052] logger.c: – Executing [s@macro-hangupcall:11] Hangup(“SIP/525-097d9d70”, “”) in new stack
[Oct 23 08:25:08] VERBOSE[9052] logger.c: == Spawn extension (macro-hangupcall, s, 11) exited non-zero on ‘SIP/525-097d9d70’ in macro ‘hangupcall’
[Oct 23 08:25:08] VERBOSE[9052] logger.c: == Spawn extension (macro-hangupcall, s, 11) exited non-zero on ‘SIP/525-097d9d70’
[Oct 23 08:25:09] VERBOSE[9061] logger.c: == Spawn extension (macro-dialout-trunk, s, 25) exited non-zero on ‘SIP/203-097c9f50’ in macro ‘dialout-trunk’
[Oct 23 08:25:09] VERBOSE[9061] logger.c: == Spawn extension (macro-dialout-trunk, s, 25) exited non-zero on ‘SIP/203-097c9f50’
[Oct 23 08:25:09] VERBOSE[9061] logger.c: – Executing [h@macro-dialout-trunk:1] Macro(“SIP/203-097c9f50”, “hangupcall”) in new stack
[Oct 23 08:25:09] VERBOSE[9061] logger.c: – Executing [s@macro-hangupcall:1] ResetCDR(“SIP/203-097c9f50”, “w”) in new stack
[Oct 23 08:25:09] ERROR[9061] cdr_addon_mysql.c: cdr_mysql: cannot connect to database server localhost. CDR will not be spooled.
[Oct 23 08:25:09] DEBUG[9061] cdr_addon_mysql.c: cdr_mysql: inserting a CDR record.
[Oct 23 08:25:09] DEBUG[9061] cdr_addon_mysql.c: cdr_mysql: SQL command as follows: INSERT INTO cdr (calldate,clid,src,dst,dcontext,channel,dstchannel,lastapp,lastdata,duration,billsec,disposition,amaflags,accountcode,uniqueid) VALUES (‘2007-10-23 08:24:40’,’“2282064501” ',‘HospitalLomadeLuz’,‘818003473288’,‘from-internal’, ‘SIP/203-097c9f50’,‘SIP/vitel-outbound-0976add8’,‘Dial’,‘SIP/vitel-outbound/18003473288|300|’,29,29,‘ANSWERED’,3,‘1234’,‘1193149480.15’)
[Oct 23 08:25:09] DEBUG[9061] app_macro.c: Executed application: ResetCDR
[Oct 23 08:25:09] VERBOSE[9061] logger.c: – Executing [s@macro-hangupcall:2] NoCDR(“SIP/203-097c9f50”, “”) in new stack
[Oct 23 08:25:09] DEBUG[9061] app_macro.c: Executed application: NoCDR
[Oct 23 08:25:09] VERBOSE[9061] logger.c: – Executing [s@macro-hangupcall:3] GotoIf(“SIP/203-097c9f50”, “1?skiprg”) in new stack
[Oct 23 08:25:09] VERBOSE[9061] logger.c: – Goto (macro-hangupcall,s,6)
[Oct 23 08:25:09] DEBUG[9061] app_macro.c: Executed application: GotoIf
[Oct 23 08:25:09] VERBOSE[9061] logger.c: – Executing [s@macro-hangupcall:6] GotoIf(“SIP/203-097c9f50”, “1?skipblkvm”) in new stack
[Oct 23 08:25:09] VERBOSE[9061] logger.c: – Goto (macro-hangupcall,s,9)
[Oct 23 08:25:09] DEBUG[9061] app_macro.c: Executed application: GotoIf
[Oct 23 08:25:09] VERBOSE[9061] logger.c: – Executing [s@macro-hangupcall:9] GotoIf(“SIP/203-097c9f50”, “1?theend”) in new stack
[Oct 23 08:25:09] VERBOSE[9061] logger.c: – Goto (macro-hangupcall,s,11)
[Oct 23 08:25:09] DEBUG[9061] app_macro.c: Executed application: GotoIf
[Oct 23 08:25:09] VERBOSE[9061] logger.c: – Executing [s@macro-hangupcall:11] Hangup(“SIP/203-097c9f50”, “”) in new stack
[Oct 23 08:25:09] VERBOSE[9061] logger.c: == Spawn extension (macro-hangupcall, s, 11) exited non-zero on ‘SIP/203-097c9f50’ in macro ‘hangupcall’
[Oct 23 08:25:09] VERBOSE[9061] logger.c: == Spawn extension (macro-hangupcall, s, 11) exited non-zero on ‘SIP/203-097c9f50’