May 3 17:02:21 VERBOSE[11730] logger.c: -- Zap/1-1 answered SIP/227-083aa418 May 3 17:02:21 DEBUG[3529] chan_sip.c: Stopping retransmission on '8f0589b49d2620f00590b70c59499dd1@192.168.5.107' of Response 1247784216: Match Found May 3 17:02:22 DEBUG[11730] chan_zap.c: Exception on 17, channel 1 May 3 17:02:22 DEBUG[11730] chan_zap.c: Got event Dial Complete(9) on channel 1 (index 0) May 3 17:02:22 DEBUG[11730] chan_zap.c: Echo cancellation already on May 3 17:02:27 DEBUG[11730] channel.c: Didn't get a frame from channel: SIP/227-083aa418 May 3 17:02:27 DEBUG[11730] channel.c: Bridge stops bridging channels SIP/227-083aa418 and Zap/1-1 May 3 17:02:27 DEBUG[11730] chan_zap.c: Hangup: channel: 1 index = 0, normal = 17, callwait = -1, thirdcall = -1 May 3 17:02:27 DEBUG[11730] chan_zap.c: disabled echo cancellation on channel 1 May 3 17:02:27 DEBUG[11730] chan_zap.c: Set option TDD MODE, value: OFF(0) on Zap/1-1 May 3 17:02:27 DEBUG[11730] chan_zap.c: Updated conferencing on 1, with 0 conference users May 3 17:02:27 VERBOSE[11730] logger.c: -- Hungup 'Zap/1-1' May 3 17:02:27 DEBUG[11730] app_dial.c: Exiting with DIALSTATUS=ANSWER. May 3 17:02:27 VERBOSE[11730] logger.c: == Spawn extension (macro-dialout-trunk, s, 20) exited non-zero on 'SIP/227-083aa418' in macro 'dialout-trunk' May 3 17:02:27 VERBOSE[11730] logger.c: == Spawn extension (macro-dialout-trunk, s, 20) exited non-zero on 'SIP/227-083aa418' May 3 17:02:27 VERBOSE[11730] logger.c: -- Executing Macro("SIP/227-083aa418", "hangupcall") in new stack May 3 17:02:27 VERBOSE[11730] logger.c: -- Executing ResetCDR("SIP/227-083aa418", "w") in new stack May 3 17:02:27 DEBUG[11730] cdr_addon_mysql.c: cdr_mysql: inserting a CDR record. May 3 17:02:27 DEBUG[11730] cdr_addon_mysql.c: cdr_mysql: SQL command as follows: INSERT INTO cdr (calldate,clid,src,dst,dcontext,channel,dstchannel,lastapp,lastdata,duration,b$ May 3 17:02:27 VERBOSE[11730] logger.c: -- Executing NoCDR("SIP/227-083aa418", "") in new stack May 3 17:02:27 WARNING[11730] cdr.c: CDR on channel 'SIP/227-083aa418' not posted May 3 17:02:27 WARNING[11730] cdr.c: CDR on channel 'SIP/227-083aa418' lacks end May 3 17:02:27 DEBUG[11730] pbx.c: Expression result is '1' May 3 17:02:27 VERBOSE[11730] logger.c: -- Executing GotoIf("SIP/227-083aa418", "1?skiprg") in new stack May 3 17:02:27 VERBOSE[11730] logger.c: -- Goto (macro-hangupcall,s,6) May 3 17:02:27 DEBUG[11730] pbx.c: Expression result is '1' May 3 17:02:27 VERBOSE[11730] logger.c: -- Executing GotoIf("SIP/227-083aa418", "1?theend") in new stack May 3 17:02:27 VERBOSE[11730] logger.c: -- Goto (macro-hangupcall,s,9) May 3 17:02:27 VERBOSE[11730] logger.c: -- Executing Wait("SIP/227-083aa418", "5") in new stack May 3 17:02:27 VERBOSE[11730] logger.c: == Spawn extension (macro-hangupcall, s, 9) exited non-zero on 'SIP/227-083aa418' in macro 'hangupcall' May 3 17:02:27 VERBOSE[11730] logger.c: == Spawn extension (macro-hangupcall, s, 9) exited non-zero on 'SIP/227-083aa418' May 3 17:02:27 DEBUG[11730] chan_sip.c: update_call_counter(227) - decrement call limit counter May 3 17:02:27 DEBUG[3531] chan_zap.c: disabled echo cancellation on channel 1 May 3 17:02:34 DEBUG[3529] chan_sip.c: Stopping retransmission on '13b2d9d659fa143469d7617a0c370d6b@192.168.5.6' of Request 102: Match Found May 3 17:02:42 DEBUG[3529] chan_sip.c: Auto destroying call 'e6ef375afa4faa802d4aa017312f2be0@192.168.5.104' May 3 17:02:45 DEBUG[3529] chan_sip.c: Setting NAT on RTP to 524288 May 3 17:02:45 DEBUG[3529] chan_sip.c: Stopping retransmission on 'ebdf2c11eeb2f7db68d0d359571e19e9@192.168.5.107' of Response 252914452: Match Found May 3 17:02:45 DEBUG[3529] chan_sip.c: Setting NAT on RTP to 524288 May 3 17:02:45 DEBUG[3529] chan_sip.c: Checking SIP call limits for device 227 May 3 17:02:45 DEBUG[3529] chan_sip.c: build_route: Contact hop: Bread May 3 17:02:45 VERBOSE[11742] logger.c: -- Executing Macro("SIP/227-08371dd0", "dialout-trunk|1|13012310140||") in new stack May 3 17:02:45 VERBOSE[11742] logger.c: -- Executing Set("SIP/227-08371dd0", "DIAL_TRUNK=1") in new stack May 3 17:02:45 VERBOSE[11742] logger.c: -- Executing Set("SIP/227-08371dd0", "_NODEST=") in new stack May 3 17:02:45 VERBOSE[11742] logger.c: -- Executing Set("SIP/227-08371dd0", "DIAL_NUMBER=13012310140") in new stack May 3 17:02:45 VERBOSE[11742] logger.c: -- Executing Set("SIP/227-08371dd0", "ROUTE_PASSWD=") in new stack May 3 17:02:45 VERBOSE[11742] logger.c: -- Executing Set("SIP/227-08371dd0", "DIAL_TRUNK_OPTIONS=tr") in new stack May 3 17:02:45 DEBUG[11742] pbx.c: Expression result is '1' May 3 17:02:45 VERBOSE[11742] logger.c: -- Executing GotoIf("SIP/227-08371dd0", "1?noauth") in new stack May 3 17:02:45 VERBOSE[11742] logger.c: -- Goto (macro-dialout-trunk,s,8) May 3 17:02:45 VERBOSE[11742] logger.c: -- Executing Set("SIP/227-08371dd0", "GROUP()=OUT_1") in new stack May 3 17:02:45 VERBOSE[11742] logger.c: -- Executing Macro("SIP/227-08371dd0", "user-callerid|SKIPTTL") in new stack May 3 17:02:45 DEBUG[11742] pbx.c: Function result is 'device' May 3 17:02:45 DEBUG[11742] pbx.c: Function result is '227' May 3 17:02:45 VERBOSE[11742] logger.c: -- Executing NoOp("SIP/227-08371dd0", "user-callerid: device 227") in new stack May 3 17:02:45 DEBUG[11742] pbx.c: Function result is '227' May 3 17:02:45 VERBOSE[11742] logger.c: -- Executing NoOp("SIP/227-08371dd0", "user-callerid: device 227") in new stack May 3 17:02:45 DEBUG[11742] pbx.c: Expression result is '0' May 3 17:02:45 VERBOSE[11742] logger.c: -- Executing GotoIf("SIP/227-08371dd0", "0?report") in new stack May 3 17:02:45 DEBUG[11742] pbx.c: Not taking any branch May 3 17:02:45 DEBUG[11742] pbx.c: Expression result is '0' May 3 17:02:45 VERBOSE[11742] logger.c: -- Executing GotoIf("SIP/227-08371dd0", "0?start") in new stack May 3 17:02:45 DEBUG[11742] pbx.c: Not taking any branch May 3 17:02:45 DEBUG[11742] pbx.c: Function result is '227' May 3 17:02:45 VERBOSE[11742] logger.c: -- Executing Set("SIP/227-08371dd0", "REALCALLERIDNUM=227") in new stack May 3 17:02:45 VERBOSE[11742] logger.c: -- Executing NoOp("SIP/227-08371dd0", "REALCALLERIDNUM is 227") in new stack May 3 17:02:45 DEBUG[11742] pbx.c: Function result is '227' May 3 17:02:45 VERBOSE[11742] logger.c: -- Executing Set("SIP/227-08371dd0", "AMPUSER=227") in new stack May 3 17:02:45 DEBUG[11742] pbx.c: Function result is 'Bread' May 3 17:02:45 VERBOSE[11742] logger.c: -- Executing Set("SIP/227-08371dd0", "AMPUSERCIDNAME=Bread") in new stack May 3 17:02:45 DEBUG[11742] pbx.c: Expression result is '0' May 3 17:02:45 VERBOSE[11742] logger.c: -- Executing GotoIf("SIP/227-08371dd0", "0?report") in new stack May 3 17:02:45 DEBUG[11742] pbx.c: Not taking any branch May 3 17:02:45 VERBOSE[11742] logger.c: -- Executing Set("SIP/227-08371dd0", "CALLERID(all)=Bread <227>") in new stack May 3 17:02:45 DEBUG[11742] pbx.c: Function result is '227' May 3 17:02:45 VERBOSE[11742] logger.c: -- Executing Set("SIP/227-08371dd0", "REALCALLERIDNUM=227") in new stack May 3 17:02:45 VERBOSE[11742] logger.c: -- Executing NoOp("SIP/227-08371dd0", "TTL: ARG1: SKIPTTL") in new stack May 3 17:02:45 DEBUG[11742] pbx.c: Expression result is '1' May 3 17:02:45 VERBOSE[11742] logger.c: -- Executing GotoIf("SIP/227-08371dd0", "1?continue") in new stack May 3 17:02:45 VERBOSE[11742] logger.c: -- Goto (macro-user-callerid,s,21) May 3 17:02:45 DEBUG[11742] pbx.c: Function result is '"Bread" <227>' May 3 17:02:45 VERBOSE[11742] logger.c: -- Executing NoOp("SIP/227-08371dd0", "Using CallerID "Bread" <227>") in new stack May 3 17:02:45 DEBUG[11742] pbx.c: Function result is '227' May 3 17:02:45 VERBOSE[11742] logger.c: -- Executing Macro("SIP/227-08371dd0", "record-enable|227|OUT") in new stack May 3 17:02:45 DEBUG[11742] pbx.c: Function result is '0' May 3 17:02:45 DEBUG[11742] pbx.c: Expression result is '0' May 3 17:02:45 VERBOSE[11742] logger.c: -- Executing GotoIf("SIP/227-08371dd0", "0?2:4") in new stack May 3 17:02:45 VERBOSE[11742] logger.c: -- Goto (macro-record-enable,s,4) May 3 17:02:45 VERBOSE[11742] logger.c: -- Executing DeadAGI("SIP/227-08371dd0", "recordingcheck|20070503-170245|1178226165.205") in new stack May 3 17:02:45 VERBOSE[11742] logger.c: -- Launched AGI Script /var/lib/asterisk/agi-bin/recordingcheck May 3 17:02:45 VERBOSE[11742] logger.c: recordingcheck|20070503-170245|1178226165.205: Outbound recording not enabled May 3 17:02:45 VERBOSE[11742] logger.c: -- AGI Script recordingcheck completed, returning 0 May 3 17:02:45 VERBOSE[11742] logger.c: -- Executing NoOp("SIP/227-08371dd0", "No recording needed") in new stack May 3 17:02:45 DEBUG[11742] pbx.c: Expression result is '0' May 3 17:02:45 VERBOSE[11742] logger.c: -- Executing GotoIf("SIP/227-08371dd0", "0?skipoutcid") in new stack May 3 17:02:45 DEBUG[11742] pbx.c: Not taking any branch May 3 17:02:45 VERBOSE[11742] logger.c: -- Executing Set("SIP/227-08371dd0", "DIAL_TRUNK_OPTIONS=r") in new stack May 3 17:02:45 VERBOSE[11742] logger.c: -- Executing Macro("SIP/227-08371dd0", "outbound-callerid|1") in new stack May 3 17:02:45 DEBUG[11742] pbx.c: Expression result is '1' May 3 17:02:45 VERBOSE[11742] logger.c: -- Executing GotoIf("SIP/227-08371dd0", "1?start") in new stack May 3 17:02:45 VERBOSE[11742] logger.c: -- Goto (macro-outbound-callerid,s,3) May 3 17:02:45 VERBOSE[11742] logger.c: -- Executing NoOp("SIP/227-08371dd0", "REALCALLERIDNUM is 227") in new stack May 3 17:02:45 DEBUG[11742] pbx.c: Expression result is '1' May 3 17:02:45 VERBOSE[11742] logger.c: -- Executing GotoIf("SIP/227-08371dd0", "1?normcid") in new stack May 3 17:02:45 VERBOSE[11742] logger.c: -- Goto (macro-outbound-callerid,s,9) May 3 17:02:45 DEBUG[11742] pbx.c: Function result is '' May 3 17:02:45 VERBOSE[11742] logger.c: -- Executing Set("SIP/227-08371dd0", "USEROUTCID=") in new stack May 3 17:02:45 DEBUG[11742] db.c: Unable to find key '227/emergency_cid' in family 'DEVICE' May 3 17:02:45 DEBUG[11742] func_db.c: DB: DEVICE/227/emergency_cid not found in database. May 3 17:02:45 DEBUG[11742] db.c: Unable to find key '227/emergency_cid' in family 'DEVICE' May 3 17:02:45 DEBUG[11742] func_db.c: DB: DEVICE/227/emergency_cid not found in database. May 3 17:02:45 DEBUG[11742] pbx.c: Function result is '' May 3 17:02:45 VERBOSE[11742] logger.c: -- Executing Set("SIP/227-08371dd0", "EMERGENCYCID=") in new stack May 3 17:02:45 VERBOSE[11742] logger.c: -- Executing Set("SIP/227-08371dd0", "TRUNKOUTCID=") in new stack May 3 17:02:45 DEBUG[11742] pbx.c: Expression result is '1' May 3 17:02:45 VERBOSE[11742] logger.c: -- Executing GotoIf("SIP/227-08371dd0", "1?trunkcid") in new stack May 3 17:02:45 VERBOSE[11742] logger.c: -- Goto (macro-outbound-callerid,s,16) May 3 17:02:45 DEBUG[11742] pbx.c: Expression result is '1' May 3 17:02:45 VERBOSE[11742] logger.c: -- Executing GotoIf("SIP/227-08371dd0", "1?usercid") in new stack May 3 17:02:45 VERBOSE[11742] logger.c: -- Goto (macro-outbound-callerid,s,18) May 3 17:02:45 DEBUG[11742] pbx.c: Expression result is '1' May 3 17:02:45 VERBOSE[11742] logger.c: -- Executing GotoIf("SIP/227-08371dd0", "1?report") in new stack May 3 17:02:45 VERBOSE[11742] logger.c: -- Goto (macro-outbound-callerid,s,22) May 3 17:02:45 DEBUG[11742] pbx.c: Function result is '"Bread" <227>' May 3 17:02:45 VERBOSE[11742] logger.c: -- Executing NoOp("SIP/227-08371dd0", "CallerID set to "Bread" <227>") in new stack May 3 17:02:45 DEBUG[11742] pbx.c: Expression result is '1' May 3 17:02:45 VERBOSE[11742] logger.c: -- Executing GotoIf("SIP/227-08371dd0", "1?nomax") in new stack May 3 17:02:45 VERBOSE[11742] logger.c: -- Goto (macro-dialout-trunk,s,16) May 3 17:02:45 VERBOSE[11742] logger.c: -- Executing DeadAGI("SIP/227-08371dd0", "fixlocalprefix") in new stack May 3 17:02:45 VERBOSE[11742] logger.c: -- Launched AGI Script /var/lib/asterisk/agi-bin/fixlocalprefix May 3 17:02:45 VERBOSE[11742] logger.c: > fixlocalprefix: Using pattern 1+NXXNXXXXXX May 3 17:02:45 VERBOSE[11742] logger.c: -- AGI Script fixlocalprefix completed, returning 0 May 3 17:02:45 VERBOSE[11742] logger.c: -- Executing Set("SIP/227-08371dd0", "OUTNUM=13012310140") in new stack May 3 17:02:45 DEBUG[11742] pbx.c: Function result is 'ZAP/g1' May 3 17:02:45 VERBOSE[11742] logger.c: -- Executing Set("SIP/227-08371dd0", "custom=ZAP/g1") in new stack May 3 17:02:45 DEBUG[11742] pbx.c: Expression result is '0' May 3 17:02:45 VERBOSE[11742] logger.c: -- Executing GotoIf("SIP/227-08371dd0", "0?customtrunk") in new stack May 3 17:02:45 DEBUG[11742] pbx.c: Not taking any branch May 3 17:02:45 VERBOSE[11742] logger.c: -- Executing Dial("SIP/227-08371dd0", "ZAP/g1/13012310140|300|r") in new stack May 3 17:02:45 DEBUG[11742] chan_zap.c: Dialing '13012310140' May 3 17:02:45 DEBUG[11742] chan_zap.c: Deferring dialing... May 3 17:02:45 VERBOSE[11742] logger.c: -- Called g1/13012310140 May 3 17:02:45 DEBUG[11742] chan_zap.c: Exception on 17, channel 1 May 3 17:02:45 DEBUG[11742] chan_zap.c: Got event Wink/Flash(3) on channel 1 (index 0) May 3 17:02:45 DEBUG[11742] chan_zap.c: Ignoring wink on channel 1 May 3 17:02:46 DEBUG[11742] chan_zap.c: Exception on 17, channel 1 May 3 17:02:46 DEBUG[11742] chan_zap.c: Got event Hook Transition Complete(12) on channel 1 (index 0) May 3 17:02:47 DEBUG[3529] chan_sip.c: Stopping retransmission on '19782c8647ba972d30cac3112b1b96f2@192.168.5.6' of Request 102: Match Found May 3 17:02:47 DEBUG[3529] chan_sip.c: Stopping retransmission on '07b990ef009acdb802e704e800ffa877@192.168.5.6' of Request 102: Match Found May 3 17:02:47 DEBUG[3529] chan_sip.c: Stopping retransmission on '77d09c0e06d213f7501656957576fbb5@192.168.5.6' of Request 102: Match Found May 3 17:02:47 DEBUG[3529] chan_sip.c: Stopping retransmission on '3ba1638d29cb716679204b8c759dfe92@192.168.5.6' of Request 102: Match Found May 3 17:02:48 DEBUG[11742] chan_zap.c: Exception on 17, channel 1 May 3 17:02:48 DEBUG[11742] chan_zap.c: Got event Dial Complete(9) on channel 1 (index 0) May 3 17:02:48 DEBUG[11742] chan_zap.c: Enabled echo cancellation on channel 1 May 3 17:02:48 DEBUG[11742] chan_zap.c: Engaged echo training on channel 1 May 3 17:02:50 DEBUG[11742] chan_zap.c: Exception on 17, channel 1 May 3 17:02:50 DEBUG[11742] chan_zap.c: Got event Dial Complete(9) on channel 1 (index 0) May 3 17:02:50 DEBUG[11742] chan_zap.c: Echo cancellation already on May 3 17:02:50 DEBUG[3527] chan_iax2.c: Peer lastms 21, historicms 21, maxms 2000 May 3 17:02:53 DEBUG[3529] chan_sip.c: Auto destroying call 'e396ac71d52f151af04957448a6890c4@192.168.5.107' May 3 17:02:56 DEBUG[3529] chan_sip.c: Stopping retransmission on '09f6c3c620fb221679a6990618b81907@192.168.5.6' of Request 102: Match Found May 3 17:02:57 DEBUG[3529] chan_sip.c: Stopping retransmission on '190b87797ae7b5f018677e0d31dfaa93@192.168.5.6' of Request 102: Match Found May 3 17:02:59 DEBUG[11742] chan_zap.c: Exception on 17, channel 1 May 3 17:02:57 DEBUG[3529] chan_sip.c: Stopping retransmission on '190b87797ae7b5f018677e0d31dfaa93@192.168.5.6' of Request 102: Match Found May 3 17:02:59 DEBUG[11742] chan_zap.c: Exception on 17, channel 1 May 3 17:02:59 DEBUG[11742] chan_zap.c: Got event Ring/Answered(2) on channel 1 (index 0) May 3 17:02:59 VERBOSE[11742] logger.c: -- Zap/1-1 answered SIP/227-08371dd0 May 3 17:02:59 DEBUG[3529] chan_sip.c: Stopping retransmission on 'ebdf2c11eeb2f7db68d0d359571e19e9@192.168.5.107' of Response 252914453: Match Found May 3 17:03:06 DEBUG[3529] chan_sip.c: Setting NAT on RTP to 0 May 3 17:03:07 DEBUG[3529] chan_sip.c: Stopping retransmission on 'e74b5ecff21355c28241e5124c2fe15b@192.168.5.101' of Response 1327830202: Match Found May 3 17:03:07 DEBUG[3529] chan_sip.c: Setting NAT on RTP to 0 May 3 17:03:07 DEBUG[3529] chan_sip.c: Checking SIP call limits for device 221 May 3 17:03:07 DEBUG[3529] chan_sip.c: build_route: Contact hop: General Manager May 3 17:03:07 VERBOSE[11755] logger.c: -- Executing Macro("SIP/221-083f11d0", "dialout-trunk|1|13017680028||") in new stack May 3 17:03:07 VERBOSE[11755] logger.c: -- Executing Set("SIP/221-083f11d0", "DIAL_TRUNK=1") in new stack May 3 17:03:07 VERBOSE[11755] logger.c: -- Executing Set("SIP/221-083f11d0", "_NODEST=") in new stack May 3 17:03:07 VERBOSE[11755] logger.c: -- Executing Set("SIP/221-083f11d0", "DIAL_NUMBER=13017680028") in new stack May 3 17:03:07 VERBOSE[11755] logger.c: -- Executing Set("SIP/221-083f11d0", "ROUTE_PASSWD=") in new stack May 3 17:03:07 VERBOSE[11755] logger.c: -- Executing Set("SIP/221-083f11d0", "DIAL_TRUNK_OPTIONS=tr") in new stack May 3 17:03:07 DEBUG[11755] pbx.c: Expression result is '1' May 3 17:03:07 VERBOSE[11755] logger.c: -- Executing GotoIf("SIP/221-083f11d0", "1?noauth") in new stack May 3 17:03:07 VERBOSE[11755] logger.c: -- Goto (macro-dialout-trunk,s,8) May 3 17:03:07 VERBOSE[11755] logger.c: -- Executing Set("SIP/221-083f11d0", "GROUP()=OUT_1") in new stack May 3 17:03:07 VERBOSE[11755] logger.c: -- Executing Macro("SIP/221-083f11d0", "user-callerid|SKIPTTL") in new stack May 3 17:03:07 DEBUG[11755] pbx.c: Function result is 'General Manager' May 3 17:03:07 DEBUG[11755] pbx.c: Function result is '221' May 3 17:03:07 VERBOSE[11755] logger.c: -- Executing NoOp("SIP/221-083f11d0", "user-callerid: General Manager 221") in new stack May 3 17:03:07 DEBUG[11755] pbx.c: Expression result is '0' May 3 17:03:07 VERBOSE[11755] logger.c: -- Executing GotoIf("SIP/221-083f11d0", "0?report") in new stack May 3 17:03:07 DEBUG[11755] pbx.c: Not taking any branch May 3 17:03:07 DEBUG[11755] pbx.c: Expression result is '0' May 3 17:03:07 VERBOSE[11755] logger.c: -- Executing GotoIf("SIP/221-083f11d0", "0?start") in new stack May 3 17:03:07 DEBUG[11755] pbx.c: Not taking any branch May 3 17:03:07 DEBUG[11755] pbx.c: Function result is '221' May 3 17:03:07 VERBOSE[11755] logger.c: -- Executing Set("SIP/221-083f11d0", "REALCALLERIDNUM=221") in new stack May 3 17:03:07 VERBOSE[11755] logger.c: -- Executing NoOp("SIP/221-083f11d0", "REALCALLERIDNUM is 221") in new stack May 3 17:03:07 DEBUG[11755] pbx.c: Function result is '221' May 3 17:03:07 VERBOSE[11755] logger.c: -- Executing Set("SIP/221-083f11d0", "AMPUSER=221") in new stack May 3 17:03:07 DEBUG[11755] pbx.c: Function result is 'General Manager' May 3 17:03:07 VERBOSE[11755] logger.c: -- Executing Set("SIP/221-083f11d0", "AMPUSERCIDNAME=General Manager") in new stack May 3 17:03:07 DEBUG[11755] pbx.c: Expression result is '0' May 3 17:03:07 VERBOSE[11755] logger.c: -- Executing GotoIf("SIP/221-083f11d0", "0?report") in new stack May 3 17:03:07 DEBUG[11755] pbx.c: Not taking any branch May 3 17:03:07 VERBOSE[11755] logger.c: -- Executing Set("SIP/221-083f11d0", "CALLERID(all)=General Manager <221>") in new stack May 3 17:03:07 DEBUG[11755] pbx.c: Function result is '221' May 3 17:03:07 VERBOSE[11755] logger.c: -- Executing Set("SIP/221-083f11d0", "REALCALLERIDNUM=221") in new stack May 3 17:03:07 VERBOSE[11755] logger.c: -- Executing NoOp("SIP/221-083f11d0", "TTL: ARG1: SKIPTTL") in new stack May 3 17:03:07 DEBUG[11755] pbx.c: Expression result is '1' May 3 17:03:07 VERBOSE[11755] logger.c: -- Executing GotoIf("SIP/221-083f11d0", "1?continue") in new stack May 3 17:03:07 VERBOSE[11755] logger.c: -- Goto (macro-user-callerid,s,21) May 3 17:03:07 DEBUG[11755] pbx.c: Function result is '"General Manager" <221>' May 3 17:03:07 VERBOSE[11755] logger.c: -- Executing NoOp("SIP/221-083f11d0", "Using CallerID "General Manager" <221>") in new stack May 3 17:03:07 DEBUG[11755] pbx.c: Function result is '221' May 3 17:03:07 VERBOSE[11755] logger.c: -- Executing Macro("SIP/221-083f11d0", "record-enable|221|OUT") in new stack May 3 17:03:07 DEBUG[11755] pbx.c: Function result is '0' May 3 17:03:07 DEBUG[11755] pbx.c: Expression result is '0' May 3 17:03:07 VERBOSE[11755] logger.c: -- Executing GotoIf("SIP/221-083f11d0", "0?2:4") in new stack May 3 17:03:07 DEBUG[11755] pbx.c: Expression result is '0' May 3 17:03:07 VERBOSE[11755] logger.c: -- Executing GotoIf("SIP/221-083f11d0", "0?2:4") in new stack May 3 17:03:07 VERBOSE[11755] logger.c: -- Goto (macro-record-enable,s,4) May 3 17:03:07 VERBOSE[11755] logger.c: -- Executing DeadAGI("SIP/221-083f11d0", "recordingcheck|20070503-170307|1178226187.207") in new stack May 3 17:03:07 VERBOSE[11755] logger.c: -- Launched AGI Script /var/lib/asterisk/agi-bin/recordingcheck May 3 17:03:07 VERBOSE[11755] logger.c: recordingcheck|20070503-170307|1178226187.207: Outbound recording not enabled May 3 17:03:07 VERBOSE[11755] logger.c: -- AGI Script recordingcheck completed, returning 0 May 3 17:03:07 VERBOSE[11755] logger.c: -- Executing NoOp("SIP/221-083f11d0", "No recording needed") in new stack May 3 17:03:07 DEBUG[11755] pbx.c: Expression result is '0' May 3 17:03:07 VERBOSE[11755] logger.c: -- Executing GotoIf("SIP/221-083f11d0", "0?skipoutcid") in new stack May 3 17:03:07 DEBUG[11755] pbx.c: Not taking any branch May 3 17:03:07 VERBOSE[11755] logger.c: -- Executing Set("SIP/221-083f11d0", "DIAL_TRUNK_OPTIONS=r") in new stack May 3 17:03:07 VERBOSE[11755] logger.c: -- Executing Macro("SIP/221-083f11d0", "outbound-callerid|1") in new stack May 3 17:03:07 DEBUG[11755] pbx.c: Expression result is '1' May 3 17:03:07 VERBOSE[11755] logger.c: -- Executing GotoIf("SIP/221-083f11d0", "1?start") in new stack May 3 17:03:07 VERBOSE[11755] logger.c: -- Goto (macro-outbound-callerid,s,3) May 3 17:03:07 VERBOSE[11755] logger.c: -- Executing NoOp("SIP/221-083f11d0", "REALCALLERIDNUM is 221") in new stack May 3 17:03:07 DEBUG[11755] pbx.c: Expression result is '1' May 3 17:03:07 VERBOSE[11755] logger.c: -- Executing GotoIf("SIP/221-083f11d0", "1?normcid") in new stack May 3 17:03:07 VERBOSE[11755] logger.c: -- Goto (macro-outbound-callerid,s,9) May 3 17:03:07 DEBUG[11755] pbx.c: Function result is '' May 3 17:03:07 VERBOSE[11755] logger.c: -- Executing Set("SIP/221-083f11d0", "USEROUTCID=") in new stack May 3 17:03:07 DEBUG[11755] db.c: Unable to find key '221/emergency_cid' in family 'DEVICE' May 3 17:03:07 DEBUG[11755] func_db.c: DB: DEVICE/221/emergency_cid not found in database. May 3 17:03:07 DEBUG[11755] pbx.c: Function result is '' May 3 17:03:07 VERBOSE[11755] logger.c: -- Executing Set("SIP/221-083f11d0", "EMERGENCYCID=") in new stack May 3 17:03:07 VERBOSE[11755] logger.c: -- Executing Set("SIP/221-083f11d0", "TRUNKOUTCID=") in new stack May 3 17:03:07 DEBUG[11755] pbx.c: Expression result is '1' May 3 17:03:07 VERBOSE[11755] logger.c: -- Executing GotoIf("SIP/221-083f11d0", "1?trunkcid") in new stack May 3 17:03:07 VERBOSE[11755] logger.c: -- Goto (macro-outbound-callerid,s,16) May 3 17:03:07 DEBUG[11755] pbx.c: Expression result is '1' May 3 17:03:07 VERBOSE[11755] logger.c: -- Executing GotoIf("SIP/221-083f11d0", "1?usercid") in new stack May 3 17:03:07 VERBOSE[11755] logger.c: -- Goto (macro-outbound-callerid,s,18) May 3 17:03:07 DEBUG[11755] pbx.c: Expression result is '1' May 3 17:03:07 VERBOSE[11755] logger.c: -- Executing GotoIf("SIP/221-083f11d0", "1?report") in new stack May 3 17:03:07 VERBOSE[11755] logger.c: -- Goto (macro-outbound-callerid,s,22) May 3 17:03:07 DEBUG[11755] pbx.c: Function result is '"General Manager" <221>' May 3 17:03:07 VERBOSE[11755] logger.c: -- Executing NoOp("SIP/221-083f11d0", "CallerID set to "General Manager" <221>") in new stack May 3 17:03:07 DEBUG[11755] pbx.c: Expression result is '1' May 3 17:03:07 VERBOSE[11755] logger.c: -- Executing GotoIf("SIP/221-083f11d0", "1?nomax") in new stack May 3 17:03:07 VERBOSE[11755] logger.c: -- Goto (macro-dialout-trunk,s,16) May 3 17:03:07 VERBOSE[11755] logger.c: -- Executing DeadAGI("SIP/221-083f11d0", "fixlocalprefix") in new stack May 3 17:03:07 VERBOSE[11755] logger.c: -- Launched AGI Script /var/lib/asterisk/agi-bin/fixlocalprefix May 3 17:03:07 VERBOSE[11755] logger.c: > fixlocalprefix: Using pattern 1+NXXNXXXXXX May 3 17:03:07 VERBOSE[11755] logger.c: -- AGI Script fixlocalprefix completed, returning 0 May 3 17:03:07 VERBOSE[11755] logger.c: -- Executing Set("SIP/221-083f11d0", "OUTNUM=13017680028") in new stack May 3 17:03:07 DEBUG[11755] pbx.c: Function result is 'ZAP/g1' May 3 17:03:07 VERBOSE[11755] logger.c: -- Executing Set("SIP/221-083f11d0", "custom=ZAP/g1") in new stack May 3 17:03:07 DEBUG[11755] pbx.c: Expression result is '0' May 3 17:03:07 VERBOSE[11755] logger.c: -- Executing GotoIf("SIP/221-083f11d0", "0?customtrunk") in new stack May 3 17:03:07 DEBUG[11755] pbx.c: Not taking any branch May 3 17:03:07 VERBOSE[11755] logger.c: -- Executing Dial("SIP/221-083f11d0", "ZAP/g1/13017680028|300|r") in new stack May 3 17:03:07 DEBUG[11755] chan_zap.c: Dialing '13017680028' May 3 17:03:07 DEBUG[11755] chan_zap.c: Deferring dialing... May 3 17:03:07 DEBUG[11755] chan_zap.c: Dialing '13017680028' May 3 17:03:07 DEBUG[11755] chan_zap.c: Deferring dialing... May 3 17:03:07 VERBOSE[11755] logger.c: -- Called g1/13017680028 May 3 17:03:07 DEBUG[11755] chan_zap.c: Exception on 18, channel 2 May 3 17:03:07 DEBUG[11755] chan_zap.c: Got event Wink/Flash(3) on channel 2 (index 0) May 3 17:03:07 DEBUG[11755] chan_zap.c: Ignoring wink on channel 2 May 3 17:03:07 DEBUG[11755] chan_zap.c: Exception on 18, channel 2 May 3 17:03:07 DEBUG[11755] chan_zap.c: Got event Hook Transition Complete(12) on channel 2 (index 0) May 3 17:03:09 DEBUG[3529] chan_sip.c: Auto destroying call '61669fcac95ab19ab105ee7e63922e9a@192.168.5.105' May 3 17:03:09 DEBUG[11755] chan_zap.c: Exception on 18, channel 2 May 3 17:03:09 DEBUG[11755] chan_zap.c: Got event Dial Complete(9) on channel 2 (index 0) May 3 17:03:09 DEBUG[11755] chan_zap.c: Enabled echo cancellation on channel 2 May 3 17:03:09 DEBUG[11755] chan_zap.c: Engaged echo training on channel 2 May 3 17:03:10 DEBUG[3529] chan_sip.c: Auto destroying call '600af6880e0db18abf25d83f85eded06@192.168.5.102' May 3 17:03:11 DEBUG[11755] chan_zap.c: Exception on 18, channel 2 May 3 17:03:11 DEBUG[11755] chan_zap.c: Got event Dial Complete(9) on channel 2 (index 0) May 3 17:03:11 DEBUG[11755] chan_zap.c: Echo cancellation already on May 3 17:03:18 DEBUG[3529] chan_sip.c: Auto destroying call 'c9623ed39367b200e204aaff2dbefa6c@192.168.5.108' May 3 17:03:19 DEBUG[3529] chan_sip.c: Auto destroying call 'bcaad64bf319fdb077f8cb2056ce90b5@192.168.5.110' May 3 17:03:38 DEBUG[3529] chan_sip.c: Stopping retransmission on '405a978a1070ee1f05e7e9d476f7ef34@192.168.5.6' of Request 102: Match Found May 3 17:03:40 DEBUG[11755] chan_zap.c: Exception on 18, channel 2 May 3 17:03:40 DEBUG[11755] chan_zap.c: Got event Ring/Answered(2) on channel 2 (index 0) May 3 17:03:40 VERBOSE[11755] logger.c: -- Zap/2-1 answered SIP/221-083f11d0 May 3 17:03:40 DEBUG[3529] chan_sip.c: Stopping retransmission on 'e74b5ecff21355c28241e5124c2fe15b@192.168.5.101' of Response 1327830203: Match Found May 3 17:03:47 DEBUG[3529] chan_sip.c: Stopping retransmission on '6e096f810f04919808ab2a9e216343a5@192.168.5.6' of Request 102: Match Found May 3 17:03:47 DEBUG[3529] chan_sip.c: Stopping retransmission on '167203c9099cbbae0bdb203c3f4e286a@192.168.5.6' of Request 102: Match Found May 3 17:03:47 DEBUG[3529] chan_sip.c: Stopping retransmission on '7a44612e12abdf3b448b89cf3e25cb90@192.168.5.6' of Request 102: Match Found May 3 17:03:48 DEBUG[3529] chan_sip.c: Stopping retransmission on '5fdda98546124b4834007dfa22897e64@192.168.5.6' of Request 102: Match Found May 3 17:03:48 DEBUG[3583] manager.c: Manager received command 'Command' May 3 17:03:48 DEBUG[3583] manager.c: Manager received command 'Command' May 3 17:03:48 DEBUG[3583] manager.c: Manager received command 'Command' May 3 17:03:48 DEBUG[3529] chan_sip.c: Auto destroying call '36855d7e8ba36442b38fb429d85c2500@192.168.5.109' May 3 17:03:50 DEBUG[3529] chan_sip.c: Stopping retransmission on '56df943c6750825b6d386c3064305b64@192.168.5.6' of Request 102: Match Found May 3 17:03:51 DEBUG[3527] chan_iax2.c: Peer lastms 218, historicms 218, maxms 2000 May 3 17:03:52 DEBUG[3529] chan_sip.c: Stopping retransmission on '0f587c6e5410169311e7fc44455de088@192.168.5.6' of Request 102: Match Found May 3 17:03:52 DEBUG[3529] chan_sip.c: Stopping retransmission on '7715a8b91ea9a960513501ba1aeebf33@192.168.5.6' of Request 102: Match Found May 3 17:03:53 DEBUG[11742] channel.c: Didn't get a frame from channel: SIP/227-08371dd0 May 3 17:03:53 DEBUG[11742] channel.c: Bridge stops bridging channels SIP/227-08371dd0 and Zap/1-1 May 3 17:03:53 DEBUG[11742] chan_zap.c: Hangup: channel: 1 index = 0, normal = 17, callwait = -1, thirdcall = -1 May 3 17:03:53 DEBUG[11742] chan_zap.c: disabled echo cancellation on channel 1 May 3 17:03:53 DEBUG[11742] chan_zap.c: Set option TDD MODE, value: OFF(0) on Zap/1-1 May 3 17:03:53 DEBUG[11742] chan_zap.c: Updated conferencing on 1, with 0 conference users May 3 17:03:53 VERBOSE[11742] logger.c: -- Hungup 'Zap/1-1' May 3 17:03:53 DEBUG[11742] app_dial.c: Exiting with DIALSTATUS=ANSWER. May 3 17:03:53 VERBOSE[11742] logger.c: == Spawn extension (macro-dialout-trunk, s, 20) exited non-zero on 'SIP/227-08371dd0' in macro 'dialout-trunk' May 3 17:03:53 VERBOSE[11742] logger.c: == Spawn extension (macro-dialout-trunk, s, 20) exited non-zero on 'SIP/227-08371dd0' May 3 17:03:53 VERBOSE[11742] logger.c: -- Executing Macro("SIP/227-08371dd0", "hangupcall") in new stack May 3 17:03:53 VERBOSE[11742] logger.c: -- Executing ResetCDR("SIP/227-08371dd0", "w") in new stack May 3 17:03:53 DEBUG[11742] cdr_addon_mysql.c: cdr_mysql: inserting a CDR record. May 3 17:03:53 DEBUG[11742] cdr_addon_mysql.c: cdr_mysql: SQL command as follows: INSERT INTO cdr (calldate,clid,src,dst,dcontext,channel,dstchannel,lastapp,lastdata,duration,b$ May 3 17:03:53 VERBOSE[11742] logger.c: -- Executing NoCDR("SIP/227-08371dd0", "") in new stack May 3 17:03:53 WARNING[11742] cdr.c: CDR on channel 'SIP/227-08371dd0' not posted May 3 17:03:53 WARNING[11742] cdr.c: CDR on channel 'SIP/227-08371dd0' lacks end May 3 17:03:53 DEBUG[11742] pbx.c: Expression result is '1' May 3 17:03:53 WARNING[11742] cdr.c: CDR on channel 'SIP/227-08371dd0' lacks end May 3 17:03:53 DEBUG[11742] pbx.c: Expression result is '1' May 3 17:03:53 VERBOSE[11742] logger.c: -- Executing GotoIf("SIP/227-08371dd0", "1?skiprg") in new stack May 3 17:03:53 VERBOSE[11742] logger.c: -- Goto (macro-hangupcall,s,6) May 3 17:03:53 DEBUG[11742] pbx.c: Expression result is '1' May 3 17:03:53 VERBOSE[11742] logger.c: -- Executing GotoIf("SIP/227-08371dd0", "1?theend") in new stack May 3 17:03:53 VERBOSE[11742] logger.c: -- Goto (macro-hangupcall,s,9) May 3 17:03:53 VERBOSE[11742] logger.c: -- Executing Wait("SIP/227-08371dd0", "5") in new stack May 3 17:03:53 VERBOSE[11742] logger.c: == Spawn extension (macro-hangupcall, s, 9) exited non-zero on 'SIP/227-08371dd0' in macro 'hangupcall' May 3 17:03:53 VERBOSE[11742] logger.c: == Spawn extension (macro-hangupcall, s, 9) exited non-zero on 'SIP/227-08371dd0' May 3 17:03:53 DEBUG[11742] chan_sip.c: update_call_counter(227) - decrement call limit counter May 3 17:03:53 DEBUG[3531] chan_zap.c: disabled echo cancellation on channel 1 May 3 17:03:55 DEBUG[3529] chan_sip.c: Auto destroying call '3e246df849c7fd6c33960d3572b44f90@192.168.5.106' May 3 17:03:57 DEBUG[3529] chan_sip.c: Auto destroying call 'ff5101665f9273f9b7d935233d3fec51@192.168.5.101' May 3 17:04:03 DEBUG[3529] chan_sip.c: Auto destroying call 'c5bbe19d7c981e4a6b4067cdfd663f95@192.168.5.103' May 3 17:04:13 DEBUG[3529] chan_sip.c: Stopping retransmission on '3399152f5098c9e46cd06b1f53218ee4@192.168.5.6' of Request 102: Match Found May 3 17:04:27 DEBUG[3529] chan_sip.c: Auto destroying call 'e6ef375afa4faa802d4aa017312f2be0@192.168.5.104' May 3 17:04:38 DEBUG[3529] chan_sip.c: Auto destroying call 'e396ac71d52f151af04957448a6890c4@192.168.5.107' May 3 17:04:46 DEBUG[3529] chan_sip.c: Stopping retransmission on '3e70c040526a43f758d37579006a8483@192.168.5.6' of Request 102: Match Found May 3 17:04:47 DEBUG[3529] chan_sip.c: Stopping retransmission on '2190767478700ab05fc08d0c4cf8f93c@192.168.5.6' of Request 102: Match Found May 3 17:04:47 DEBUG[3529] chan_sip.c: Stopping retransmission on '763134bc0589b12a5999c7bd6b81c401@192.168.5.6' of Request 102: Match Found May 3 17:04:47 DEBUG[3529] chan_sip.c: Stopping retransmission on '0fa16b9b2e4b14fb7f8016b61a6ed5e9@192.168.5.6' of Request 102: Match Found May 3 17:04:48 DEBUG[3529] chan_sip.c: Stopping retransmission on '6bc8f99b323d553065d66a5f366f3444@192.168.5.6' of Request 102: Match Found May 3 17:04:48 DEBUG[3529] chan_sip.c: Stopping retransmission on '45d4f2d94e8aff4e20d3819339c3425a@192.168.5.6' of Request 102: Match Found May 3 17:04:51 DEBUG[3527] chan_iax2.c: Peer lastms 16, historicms 16, maxms 2000 May 3 17:04:54 DEBUG[3529] chan_sip.c: Auto destroying call '61669fcac95ab19ab105ee7e63922e9a@192.168.5.105' May 3 17:04:55 DEBUG[3529] chan_sip.c: Auto destroying call '600af6880e0db18abf25d83f85eded06@192.168.5.102' May 3 17:05:02 DEBUG[11755] chan_zap.c: Exception on 18, channel 2 May 3 17:05:02 DEBUG[11755] chan_zap.c: Got event On hook(1) on channel 2 (index 0) May 3 17:05:02 DEBUG[11755] chan_zap.c: disabled echo cancellation on channel 2 May 3 17:05:02 DEBUG[11755] channel.c: Didn't get a frame from channel: Zap/2-1 May 3 17:05:02 DEBUG[11755] channel.c: Bridge stops bridging channels SIP/221-083f11d0 and Zap/2-1 May 3 17:05:02 DEBUG[11755] chan_zap.c: Hangup: channel: 2 index = 0, normal = 18, callwait = -1, thirdcall = -1 May 3 17:05:02 DEBUG[11755] chan_zap.c: disabled echo cancellation on channel 2 May 3 17:05:02 DEBUG[11755] chan_zap.c: Set option TDD MODE, value: OFF(0) on Zap/2-1 May 3 17:05:02 DEBUG[11755] chan_zap.c: Updated conferencing on 2, with 0 conference users May 3 17:05:02 VERBOSE[11755] logger.c: -- Hungup 'Zap/2-1' May 3 17:05:02 DEBUG[11755] app_dial.c: Exiting with DIALSTATUS=ANSWER. May 3 17:05:02 VERBOSE[11755] logger.c: == Spawn extension (macro-dialout-trunk, s, 20) exited non-zero on 'SIP/221-083f11d0' in macro 'dialout-trunk' May 3 17:05:02 VERBOSE[11755] logger.c: == Spawn extension (macro-dialout-trunk, s, 20) exited non-zero on 'SIP/221-083f11d0' May 3 17:05:02 VERBOSE[11755] logger.c: -- Executing Macro("SIP/221-083f11d0", "hangupcall") in new stack May 3 17:05:02 VERBOSE[11755] logger.c: -- Executing ResetCDR("SIP/221-083f11d0", "w") in new stack May 3 17:05:02 DEBUG[11755] cdr_addon_mysql.c: cdr_mysql: inserting a CDR record. May 3 17:05:02 DEBUG[11755] cdr_addon_mysql.c: cdr_mysql: SQL command as follows: INSERT INTO cdr (calldate,clid,src,dst,dcontext,channel,dstchannel,lastapp,lastdata,duration,b$ May 3 17:05:02 VERBOSE[11755] logger.c: -- Executing NoCDR("SIP/221-083f11d0", "") in new stack May 3 17:05:02 WARNING[11755] cdr.c: CDR on channel 'SIP/221-083f11d0' not posted May 3 17:05:02 WARNING[11755] cdr.c: CDR on channel 'SIP/221-083f11d0' lacks end May 3 17:05:02 DEBUG[11755] pbx.c: Expression result is '1' May 3 17:05:02 VERBOSE[11755] logger.c: -- Executing GotoIf("SIP/221-083f11d0", "1?skiprg") in new stack May 3 17:05:02 VERBOSE[11755] logger.c: -- Goto (macro-hangupcall,s,6) May 3 17:05:02 DEBUG[11755] pbx.c: Expression result is '1' May 3 17:05:02 VERBOSE[11755] logger.c: -- Executing GotoIf("SIP/221-083f11d0", "1?theend") in new stack May 3 17:05:02 VERBOSE[11755] logger.c: -- Goto (macro-hangupcall,s,9) May 3 17:05:02 VERBOSE[11755] logger.c: -- Executing Wait("SIP/221-083f11d0", "5") in new stack May 3 17:05:02 VERBOSE[11755] logger.c: -- Goto (macro-hangupcall,s,9) May 3 17:05:02 VERBOSE[11755] logger.c: -- Executing Wait("SIP/221-083f11d0", "5") in new stack May 3 17:05:03 DEBUG[3529] chan_sip.c: Auto destroying call 'c9623ed39367b200e204aaff2dbefa6c@192.168.5.108' May 3 17:05:04 DEBUG[3529] chan_sip.c: Auto destroying call 'bcaad64bf319fdb077f8cb2056ce90b5@192.168.5.110' May 3 17:05:07 VERBOSE[11755] logger.c: -- Executing Hangup("SIP/221-083f11d0", "") in new stack May 3 17:05:07 VERBOSE[11755] logger.c: == Spawn extension (macro-hangupcall, s, 10) exited non-zero on 'SIP/221-083f11d0' in macro 'hangupcall' May 3 17:05:07 VERBOSE[11755] logger.c: == Spawn extension (macro-hangupcall, s, 10) exited non-zero on 'SIP/221-083f11d0' May 3 17:05:07 DEBUG[11755] chan_sip.c: update_call_counter(221) - decrement call limit counter May 3 17:05:07 DEBUG[3529] chan_sip.c: Stopping retransmission on 'e74b5ecff21355c28241e5124c2fe15b@192.168.5.101' of Request 102: Match Found May 3 17:05:28 DEBUG[3529] chan_sip.c: Stopping retransmission on '2aba7af7175dcd861922ae920f53e34e@192.168.5.6' of Request 102: Match Found May 3 17:05:29 DEBUG[3529] chan_sip.c: Stopping retransmission on '411305d837a9b48d5f93d924781f9c05@192.168.5.6' of Request 102: Match Found May 3 17:05:31 DEBUG[3529] chan_sip.c: Stopping retransmission on '4b9d0732352356172ade32be3578c7c5@192.168.5.6' of Request 102: Match Found May 3 17:05:33 DEBUG[3529] chan_sip.c: Auto destroying call '36855d7e8ba36442b38fb429d85c2500@192.168.5.109' May 3 17:05:40 DEBUG[3529] chan_sip.c: Auto destroying call '3e246df849c7fd6c33960d3572b44f90@192.168.5.106' May 3 17:05:42 DEBUG[3529] chan_sip.c: Auto destroying call 'ff5101665f9273f9b7d935233d3fec51@192.168.5.101' May 3 17:05:42 DEBUG[3529] chan_sip.c: Stopping retransmission on '1dd4fe5536df80f63209d38277dec65c@192.168.5.6' of Request 102: Match Found May 3 17:05:47 DEBUG[3529] chan_sip.c: Stopping retransmission on '0c9f84467c4fb0cc07e71f2d51ef4dce@192.168.5.6' of Request 102: Match Found May 3 17:05:47 DEBUG[3529] chan_sip.c: Stopping retransmission on '3a01ef7b18451b6b1818bdd0105c6ae5@192.168.5.6' of Request 102: Match Found May 3 17:05:48 DEBUG[3529] chan_sip.c: Stopping retransmission on '1e278f6d2d7b72bb4259073430d06369@192.168.5.6' of Request 102: Match Found May 3 17:05:48 DEBUG[3529] chan_sip.c: Stopping retransmission on '10b91265187a1a054e8636a1041269f3@192.168.5.6' of Request 102: Match Found May 3 17:05:48 DEBUG[3583] manager.c: Manager received command 'Command' May 3 17:05:48 DEBUG[3583] manager.c: Manager received command 'Command' May 3 17:05:48 DEBUG[3583] manager.c: Manager received command 'Command' May 3 17:05:48 DEBUG[3529] chan_sip.c: Auto destroying call 'c5bbe19d7c981e4a6b4067cdfd663f95@192.168.5.103' May 3 17:05:51 DEBUG[3527] chan_iax2.c: Peer lastms 17, historicms 17, maxms 2000 May 3 17:05:58 VERBOSE[12045] logger.c: -- Starting simple switch on 'Zap/1-1' May 3 17:06:00 DEBUG[12045] chan_zap.c: DTMF digit: 4 on Zap/1-1 May 3 17:06:00 DEBUG[12045] chan_zap.c: DTMF digit: 4 on Zap/1-1 May 3 17:06:00 DEBUG[12045] chan_zap.c: DTMF digit: 0 on Zap/1-1 May 3 17:06:03 DEBUG[3529] chan_sip.c: Stopping retransmission on '7d87d2ae2e2a18ef020bfe934c4f127f@192.168.5.6' of Request 102: Match Found May 3 17:06:03 DEBUG[12045] chan_zap.c: Enabled echo cancellation on channel 1 May 3 17:06:03 VERBOSE[12045] logger.c: -- Executing NoOp("Zap/1-1", "Catch-All DID Match - Found 440 - You probably want a DID for this.") in new stack May 3 17:06:03 VERBOSE[12045] logger.c: -- Executing Goto("Zap/1-1", "ext-did|s|1") in new stack May 3 17:06:03 VERBOSE[12045] logger.c: -- Goto (ext-did,s,1) May 3 17:06:03 VERBOSE[12045] logger.c: -- Executing Set("Zap/1-1", "FROM_DID=s") in new stack May 3 17:06:03 VERBOSE[12045] logger.c: -- Executing Gosub("Zap/1-1", "app-blacklist-check|s|1") in new stack May 3 17:06:03 VERBOSE[12045] logger.c: -- Executing LookupBlacklist("Zap/1-1", "") in new stack May 3 17:06:03 DEBUG[12045] pbx.c: Expression result is '0' May 3 17:06:03 VERBOSE[12045] logger.c: -- Executing GotoIf("Zap/1-1", "0?blacklisted") in new stack May 3 17:06:03 DEBUG[12045] pbx.c: Not taking any branch May 3 17:06:03 VERBOSE[12045] logger.c: -- Executing Return("Zap/1-1", "") in new stack May 3 17:06:03 VERBOSE[12045] logger.c: -- Executing Goto("Zap/1-1", "ext-group|1|1") in new stack May 3 17:06:03 VERBOSE[12045] logger.c: -- Goto (ext-group,1,1) May 3 17:06:03 VERBOSE[12045] logger.c: -- Executing Macro("Zap/1-1", "user-callerid|") in new stack May 3 17:06:03 DEBUG[12045] pbx.c: Function result is '' May 3 17:06:03 DEBUG[12045] pbx.c: Function result is '' May 3 17:06:03 VERBOSE[12045] logger.c: -- Executing NoOp("Zap/1-1", "user-callerid: ") in new stack May 3 17:06:03 DEBUG[12045] pbx.c: Expression result is '0' May 3 17:06:03 VERBOSE[12045] logger.c: -- Executing GotoIf("Zap/1-1", "0?report") in new stack May 3 17:06:03 DEBUG[12045] pbx.c: Not taking any branch May 3 17:06:03 DEBUG[12045] pbx.c: Expression result is '0' May 3 17:06:03 VERBOSE[12045] logger.c: -- Executing GotoIf("Zap/1-1", "0?start") in new stack May 3 17:06:03 DEBUG[12045] pbx.c: Not taking any branch May 3 17:06:03 DEBUG[12045] pbx.c: Function result is '' May 3 17:06:03 DEBUG[12045] pbx.c: Not taking any branch May 3 17:06:03 DEBUG[12045] pbx.c: Function result is '' May 3 17:06:03 VERBOSE[12045] logger.c: -- Executing Set("Zap/1-1", "REALCALLERIDNUM=") in new stack May 3 17:06:03 VERBOSE[12045] logger.c: -- Executing NoOp("Zap/1-1", "REALCALLERIDNUM is ") in new stack May 3 17:06:03 DEBUG[12045] db.c: Unable to find key '/user' in family 'DEVICE' May 3 17:06:03 DEBUG[12045] func_db.c: DB: DEVICE//user not found in database. May 3 17:06:03 DEBUG[12045] pbx.c: Function result is '' May 3 17:06:03 VERBOSE[12045] logger.c: -- Executing Set("Zap/1-1", "AMPUSER=") in new stack May 3 17:06:03 DEBUG[12045] db.c: Unable to find key '/cidname' in family 'AMPUSER' May 3 17:06:03 DEBUG[12045] func_db.c: DB: AMPUSER//cidname not found in database. May 3 17:06:03 DEBUG[12045] pbx.c: Function result is '' May 3 17:06:03 VERBOSE[12045] logger.c: -- Executing Set("Zap/1-1", "AMPUSERCIDNAME=") in new stack May 3 17:06:03 DEBUG[12045] pbx.c: Expression result is '1' May 3 17:06:03 VERBOSE[12045] logger.c: -- Executing GotoIf("Zap/1-1", "1?report") in new stack May 3 17:06:03 VERBOSE[12045] logger.c: -- Goto (macro-user-callerid,s,11) May 3 17:06:03 VERBOSE[12045] logger.c: -- Executing NoOp("Zap/1-1", "TTL: ARG1: ") in new stack May 3 17:06:03 DEBUG[12045] pbx.c: Expression result is '0' May 3 17:06:03 VERBOSE[12045] logger.c: -- Executing GotoIf("Zap/1-1", "0?continue") in new stack May 3 17:06:03 DEBUG[12045] pbx.c: Not taking any branch May 3 17:06:03 DEBUG[12045] pbx.c: Expression result is '1' May 3 17:06:03 DEBUG[12045] pbx.c: Expression result is '-1' May 3 17:06:03 DEBUG[12045] pbx.c: Function result is '64' May 3 17:06:03 VERBOSE[12045] logger.c: -- Executing Set("Zap/1-1", "_TTL=64") in new stack May 3 17:06:03 DEBUG[12045] pbx.c: Expression result is '1' May 3 17:06:03 VERBOSE[12045] logger.c: -- Executing GotoIf("Zap/1-1", "1?continue") in new stack May 3 17:06:03 VERBOSE[12045] logger.c: -- Goto (macro-user-callerid,s,21) May 3 17:06:03 DEBUG[12045] pbx.c: Function result is '"" <>' May 3 17:06:03 VERBOSE[12045] logger.c: -- Executing NoOp("Zap/1-1", "Using CallerID "" <>") in new stack May 3 17:06:03 DEBUG[12045] pbx.c: Expression result is '1' May 3 17:06:03 VERBOSE[12045] logger.c: -- Executing GotoIf("Zap/1-1", "1?skipdb") in new stack May 3 17:06:03 VERBOSE[12045] logger.c: -- Goto (ext-group,1,4) May 3 17:06:03 VERBOSE[12045] logger.c: -- Executing Set("Zap/1-1", "__NODEST=") in new stack May 3 17:06:03 VERBOSE[12045] logger.c: -- Executing Set("Zap/1-1", "__BLKVM_OVERRIDE=BLKVM/1/Zap/1-1") in new stack May 3 17:06:03 VERBOSE[12045] logger.c: -- Executing Set("Zap/1-1", "__BLKVM_BASE=1") in new stack May 3 17:06:03 VERBOSE[12045] logger.c: -- Executing Set("Zap/1-1", "DB(BLKVM/1/Zap/1-1)=TRUE") in new stack May 3 17:06:03 VERBOSE[12045] logger.c: -- Executing Set("Zap/1-1", "RRNODEST=") in new stack May 3 17:06:03 VERBOSE[12045] logger.c: -- Executing Set("Zap/1-1", "__NODEST=1") in new stack May 3 17:06:03 DEBUG[12045] pbx.c: Expression result is '1' May 3 17:06:03 VERBOSE[12045] logger.c: -- Executing GotoIf("Zap/1-1", "1?REPCID") in new stack May 3 17:06:03 VERBOSE[12045] logger.c: -- Goto (ext-group,1,14) May 3 17:06:03 DEBUG[12045] pbx.c: Function result is '' May 3 17:06:03 VERBOSE[12045] logger.c: -- Executing NoOp("Zap/1-1", "CALLERID(name) is ") in new stack May 3 17:06:03 VERBOSE[12045] logger.c: -- Executing Set("Zap/1-1", "RecordMethod=Group") in new stack May 3 17:06:03 VERBOSE[12045] logger.c: -- Executing Macro("Zap/1-1", "record-enable|221-222-223-224-225-226-227-228-229-230|Group") in new stack May 3 17:06:03 DEBUG[12045] pbx.c: Function result is '0' May 3 17:06:03 DEBUG[12045] pbx.c: Expression result is '0' May 3 17:06:03 VERBOSE[12045] logger.c: -- Executing GotoIf("Zap/1-1", "0?2:4") in new stack May 3 17:06:03 VERBOSE[12045] logger.c: -- Goto (macro-record-enable,s,4) May 3 17:06:03 VERBOSE[12045] logger.c: -- Executing DeadAGI("Zap/1-1", "recordingcheck|20070503-170603|1178226358.209") in new stack May 3 17:06:03 VERBOSE[12045] logger.c: -- Launched AGI Script /var/lib/asterisk/agi-bin/recordingcheck May 3 17:06:03 VERBOSE[12045] logger.c: -- AGI Script recordingcheck completed, returning 0 May 3 17:06:03 VERBOSE[12045] logger.c: -- Executing NoOp("Zap/1-1", "No recording needed") in new stack May 3 17:06:03 VERBOSE[12045] logger.c: -- Executing Set("Zap/1-1", "RingGroupMethod=ringall") in new stack May 3 17:06:03 VERBOSE[12045] logger.c: -- Executing Macro("Zap/1-1", "dial|25|tr|221-222-223-224-225-226-227-228-229-230") in new stack May 3 17:06:03 VERBOSE[12045] logger.c: -- Executing Set("Zap/1-1", "RingGroupMethod=ringall") in new stack May 3 17:06:03 VERBOSE[12045] logger.c: -- Executing Macro("Zap/1-1", "dial|25|tr|221-222-223-224-225-226-227-228-229-230") in new stack May 3 17:06:03 VERBOSE[12045] logger.c: -- Executing DeadAGI("Zap/1-1", "dialparties.agi") in new stack May 3 17:06:03 VERBOSE[12045] logger.c: -- Launched AGI Script /var/lib/asterisk/agi-bin/dialparties.agi May 3 17:06:03 VERBOSE[12045] logger.c: dialparties.agi: Starting New Dialparties.agi May 3 17:06:03 VERBOSE[12045] logger.c: dialparties.agi: priority is 1 May 3 17:06:03 VERBOSE[12045] logger.c: dialparties.agi: Caller ID name is 'unknown' number is 'unknown' May 3 17:06:03 VERBOSE[12045] logger.c: dialparties.agi: Methodology of ring is 'ringall' May 3 17:06:03 VERBOSE[12045] logger.c: > dialparties.agi: USE_CONFIRMATION: 'FALSE' May 3 17:06:03 VERBOSE[12045] logger.c: > dialparties.agi: RINGGROUP_INDEX: '' May 3 17:06:03 VERBOSE[12045] logger.c: -- dialparties.agi: Added extension 221 to extension map May 3 17:06:03 VERBOSE[12045] logger.c: -- dialparties.agi: Added extension 222 to extension map May 3 17:06:03 VERBOSE[12045] logger.c: -- dialparties.agi: Added extension 223 to extension map May 3 17:06:03 VERBOSE[12045] logger.c: -- dialparties.agi: Added extension 224 to extension map May 3 17:06:03 VERBOSE[12045] logger.c: -- dialparties.agi: Added extension 225 to extension map May 3 17:06:03 VERBOSE[12045] logger.c: -- dialparties.agi: Added extension 226 to extension map May 3 17:06:03 VERBOSE[12045] logger.c: -- dialparties.agi: Added extension 227 to extension map May 3 17:06:03 VERBOSE[12045] logger.c: -- dialparties.agi: Added extension 228 to extension map May 3 17:06:03 VERBOSE[12045] logger.c: -- dialparties.agi: Added extension 229 to extension map May 3 17:06:03 VERBOSE[12045] logger.c: -- dialparties.agi: Added extension 230 to extension map May 3 17:06:03 DEBUG[12045] db.c: Unable to find key '221' in family 'CF' May 3 17:06:03 VERBOSE[12045] logger.c: -- dialparties.agi: Extension 221 cf is disabled May 3 17:06:03 DEBUG[12045] db.c: Unable to find key '222' in family 'CF' May 3 17:06:03 VERBOSE[12045] logger.c: -- dialparties.agi: Extension 222 cf is disabled May 3 17:06:03 DEBUG[12045] db.c: Unable to find key '223' in family 'CF' May 3 17:06:03 VERBOSE[12045] logger.c: -- dialparties.agi: Extension 223 cf is disabled May 3 17:06:03 DEBUG[12045] db.c: Unable to find key '224' in family 'CF' May 3 17:06:03 VERBOSE[12045] logger.c: -- dialparties.agi: Extension 224 cf is disabled May 3 17:06:03 DEBUG[12045] db.c: Unable to find key '225' in family 'CF' May 3 17:06:03 VERBOSE[12045] logger.c: -- dialparties.agi: Extension 225 cf is disabled May 3 17:06:03 DEBUG[12045] db.c: Unable to find key '226' in family 'CF' May 3 17:06:03 VERBOSE[12045] logger.c: -- dialparties.agi: Extension 226 cf is disabled May 3 17:06:03 DEBUG[12045] db.c: Unable to find key '227' in family 'CF' May 3 17:06:03 VERBOSE[12045] logger.c: -- dialparties.agi: Extension 227 cf is disabled May 3 17:06:03 DEBUG[12045] db.c: Unable to find key '228' in family 'CF' May 3 17:06:03 VERBOSE[12045] logger.c: -- dialparties.agi: Extension 228 cf is disabled May 3 17:06:03 DEBUG[12045] db.c: Unable to find key '229' in family 'CF' May 3 17:06:03 VERBOSE[12045] logger.c: -- dialparties.agi: Extension 229 cf is disabled May 3 17:06:03 DEBUG[12045] db.c: Unable to find key '230' in family 'CF' May 3 17:06:03 VERBOSE[12045] logger.c: -- dialparties.agi: Extension 230 cf is disabled May 3 17:06:03 DEBUG[12045] db.c: Unable to find key '221' in family 'DND' May 3 17:06:03 VERBOSE[12045] logger.c: -- dialparties.agi: Extension 221 do not disturb is disabled May 3 17:06:03 DEBUG[12045] db.c: Unable to find key '222' in family 'DND' May 3 17:06:03 VERBOSE[12045] logger.c: -- dialparties.agi: Extension 222 do not disturb is disabled May 3 17:06:03 DEBUG[12045] db.c: Unable to find key '223' in family 'DND' May 3 17:06:03 VERBOSE[12045] logger.c: -- dialparties.agi: Extension 223 do not disturb is disabled May 3 17:06:03 DEBUG[12045] db.c: Unable to find key '224' in family 'DND' May 3 17:06:03 VERBOSE[12045] logger.c: -- dialparties.agi: Extension 224 do not disturb is disabled May 3 17:06:03 DEBUG[12045] db.c: Unable to find key '225' in family 'DND' May 3 17:06:03 VERBOSE[12045] logger.c: -- dialparties.agi: Extension 225 do not disturb is disabled May 3 17:06:03 DEBUG[12045] db.c: Unable to find key '226' in family 'DND' May 3 17:06:03 VERBOSE[12045] logger.c: -- dialparties.agi: Extension 226 do not disturb is disabled May 3 17:06:03 DEBUG[12045] db.c: Unable to find key '227' in family 'DND' May 3 17:06:03 VERBOSE[12045] logger.c: -- dialparties.agi: Extension 227 do not disturb is disabled May 3 17:06:03 DEBUG[12045] db.c: Unable to find key '227' in family 'DND' May 3 17:06:03 VERBOSE[12045] logger.c: -- dialparties.agi: Extension 227 do not disturb is disabled May 3 17:06:03 DEBUG[12045] db.c: Unable to find key '228' in family 'DND' May 3 17:06:03 VERBOSE[12045] logger.c: -- dialparties.agi: Extension 228 do not disturb is disabled May 3 17:06:03 DEBUG[12045] db.c: Unable to find key '229' in family 'DND' May 3 17:06:03 VERBOSE[12045] logger.c: -- dialparties.agi: Extension 229 do not disturb is disabled May 3 17:06:03 DEBUG[12045] db.c: Unable to find key '230' in family 'DND' May 3 17:06:03 VERBOSE[12045] logger.c: -- dialparties.agi: Extension 230 do not disturb is disabled May 3 17:06:03 DEBUG[12045] db.c: Unable to find key '221' in family 'CW' May 3 17:06:03 DEBUG[12045] db.c: Unable to find key '221' in family 'CFB' May 3 17:06:03 DEBUG[12045] db.c: Unable to find key '221' in family 'CFU' May 3 17:06:03 VERBOSE[12045] logger.c: > dialparties.agi: extnum: 221 May 3 17:06:03 VERBOSE[12045] logger.c: > dialparties.agi: exthascw: 0 May 3 17:06:03 VERBOSE[12045] logger.c: > dialparties.agi: exthascfb: 0 May 3 17:06:03 VERBOSE[12045] logger.c: > dialparties.agi: extcfb: May 3 17:06:03 VERBOSE[12045] logger.c: > dialparties.agi: exthascfu: 0 May 3 17:06:03 VERBOSE[12045] logger.c: > dialparties.agi: extcfu: May 3 17:06:03 DEBUG[12049] manager.c: Manager received command 'login' May 3 17:06:03 VERBOSE[12049] logger.c: == Parsing '/etc/asterisk/manager.conf': May 3 17:06:03 VERBOSE[12049] logger.c: == Parsing '/etc/asterisk/manager.conf': Found May 3 17:06:03 VERBOSE[12049] logger.c: == Parsing '/etc/asterisk/manager_custom.conf': May 3 17:06:03 VERBOSE[12049] logger.c: == Parsing '/etc/asterisk/manager_custom.co$ May 3 17:06:03 WARNING[12049] config.c: Unknown directive 'permit=192.168.1.0/255.255.255.0' at line 18 of manager_custom.conf May 3 17:06:03 DEBUG[12049] acl.c: 0.0.0.0/0.0.0.0/0.0.0.0 appended to acl for peer May 3 17:06:03 DEBUG[12049] acl.c: 127.0.0.1/255.255.255.0/255.255.255.0 appended to acl for peer May 3 17:06:03 DEBUG[12049] acl.c: ##### Testing 127.0.0.1 with 0.0.0.0 May 3 17:06:03 DEBUG[12049] acl.c: ##### Testing 127.0.0.1 with 127.0.0.0 May 3 17:06:03 VERBOSE[12049] logger.c: == Manager 'admin' logged on from 127.0.0.1 May 3 17:06:03 DEBUG[12049] manager.c: Manager received command 'ExtensionState' May 3 17:06:03 DEBUG[12049] manager.c: Manager received command 'Logoff' May 3 17:06:03 VERBOSE[12049] logger.c: == Manager 'admin' logged off from 127.0.0.1 May 3 17:06:03 VERBOSE[12045] logger.c: > dialparties.agi: ExtensionState: 0 May 3 17:06:03 VERBOSE[12045] logger.c: dialparties.agi: Extension 221 has ExtensionState: 0 May 3 17:06:03 VERBOSE[12045] logger.c: -- dialparties.agi: Checking CW and CFB status for extension 221 May 3 17:06:03 DEBUG[12045] db.c: Unable to find key '221' in family 'CALLTRACE' May 3 17:06:03 VERBOSE[12045] logger.c: -- dialparties.agi: DbDel CALLTRACE/221 - Caller ID is not defined May 3 17:06:03 DEBUG[12045] db.c: Unable to find key '222' in family 'CW' May 3 17:06:03 DEBUG[12045] db.c: Unable to find key '222' in family 'CFB' May 3 17:06:03 DEBUG[12045] db.c: Unable to find key '222' in family 'CFU' May 3 17:06:03 VERBOSE[12045] logger.c: > dialparties.agi: extnum: 222 May 3 17:06:03 VERBOSE[12045] logger.c: > dialparties.agi: exthascw: 0 May 3 17:06:03 VERBOSE[12045] logger.c: > dialparties.agi: exthascfb: 0 May 3 17:06:03 VERBOSE[12045] logger.c: > dialparties.agi: extcfb: May 3 17:06:03 VERBOSE[12045] logger.c: > dialparties.agi: exthascfu: 0 May 3 17:06:03 VERBOSE[12045] logger.c: > dialparties.agi: extcfu: May 3 17:06:03 DEBUG[12050] manager.c: Manager received command 'login' May 3 17:06:03 VERBOSE[12050] logger.c: == Parsing '/etc/asterisk/manager.conf': May 3 17:06:03 VERBOSE[12050] logger.c: == Parsing '/etc/asterisk/manager.conf': Found May 3 17:06:03 VERBOSE[12050] logger.c: == Parsing '/etc/asterisk/manager_custom.conf': May 3 17:06:03 VERBOSE[12050] logger.c: == Parsing '/etc/asterisk/manager_custom.co$ May 3 17:06:03 WARNING[12050] config.c: Unknown directive 'permit=192.168.1.0/255.255.255.0' at line 18 of manager_custom.conf May 3 17:06:03 DEBUG[12050] acl.c: 0.0.0.0/0.0.0.0/0.0.0.0 appended to acl for peer May 3 17:06:03 DEBUG[12050] acl.c: 127.0.0.1/255.255.255.0/255.255.255.0 appended to acl for peer May 3 17:06:03 DEBUG[12050] acl.c: ##### Testing 127.0.0.1 with 0.0.0.0 May 3 17:06:03 DEBUG[12050] acl.c: ##### Testing 127.0.0.1 with 127.0.0.0 May 3 17:06:03 VERBOSE[12050] logger.c: == Manager 'admin' logged on from 127.0.0.1 May 3 17:06:03 DEBUG[12050] manager.c: Manager received command 'ExtensionState' May 3 17:06:03 DEBUG[12050] manager.c: Manager received command 'Logoff' May 3 17:06:03 DEBUG[12050] manager.c: Manager received command 'ExtensionState' May 3 17:06:03 DEBUG[12050] manager.c: Manager received command 'Logoff' May 3 17:06:03 VERBOSE[12050] logger.c: == Manager 'admin' logged off from 127.0.0.1 May 3 17:06:03 VERBOSE[12045] logger.c: > dialparties.agi: ExtensionState: 0 May 3 17:06:03 VERBOSE[12045] logger.c: dialparties.agi: Extension 222 has ExtensionState: 0 May 3 17:06:03 VERBOSE[12045] logger.c: -- dialparties.agi: Checking CW and CFB status for extension 222 May 3 17:06:03 DEBUG[12045] db.c: Unable to find key '222' in family 'CALLTRACE' May 3 17:06:03 VERBOSE[12045] logger.c: -- dialparties.agi: DbDel CALLTRACE/222 - Caller ID is not defined May 3 17:06:03 DEBUG[12045] db.c: Unable to find key '223' in family 'CW' May 3 17:06:03 DEBUG[12045] db.c: Unable to find key '223' in family 'CFB' May 3 17:06:03 DEBUG[12045] db.c: Unable to find key '223' in family 'CFU' May 3 17:06:03 VERBOSE[12045] logger.c: > dialparties.agi: extnum: 223 May 3 17:06:03 VERBOSE[12045] logger.c: > dialparties.agi: exthascw: 0 May 3 17:06:03 VERBOSE[12045] logger.c: > dialparties.agi: exthascfb: 0 May 3 17:06:03 VERBOSE[12045] logger.c: > dialparties.agi: extcfb: May 3 17:06:03 VERBOSE[12045] logger.c: > dialparties.agi: exthascfu: 0 May 3 17:06:03 VERBOSE[12045] logger.c: > dialparties.agi: extcfu: May 3 17:06:03 DEBUG[12051] manager.c: Manager received command 'login' May 3 17:06:03 VERBOSE[12051] logger.c: == Parsing '/etc/asterisk/manager.conf': May 3 17:06:03 VERBOSE[12051] logger.c: == Parsing '/etc/asterisk/manager.conf': Found May 3 17:06:03 VERBOSE[12051] logger.c: == Parsing '/etc/asterisk/manager_custom.conf': May 3 17:06:03 VERBOSE[12051] logger.c: == Parsing '/etc/asterisk/manager_custom.co$ May 3 17:06:03 WARNING[12051] config.c: Unknown directive 'permit=192.168.1.0/255.255.255.0' at line 18 of manager_custom.conf May 3 17:06:03 DEBUG[12051] acl.c: 0.0.0.0/0.0.0.0/0.0.0.0 appended to acl for peer May 3 17:06:03 DEBUG[12051] acl.c: 127.0.0.1/255.255.255.0/255.255.255.0 appended to acl for peer May 3 17:06:03 DEBUG[12051] acl.c: ##### Testing 127.0.0.1 with 0.0.0.0 May 3 17:06:03 DEBUG[12051] acl.c: ##### Testing 127.0.0.1 with 127.0.0.0 May 3 17:06:03 VERBOSE[12051] logger.c: == Manager 'admin' logged on from 127.0.0.1 May 3 17:06:03 DEBUG[12051] manager.c: Manager received command 'ExtensionState' May 3 17:06:03 DEBUG[12051] manager.c: Manager received command 'Logoff' May 3 17:06:03 VERBOSE[12051] logger.c: == Manager 'admin' logged off from 127.0.0.1 May 3 17:06:03 VERBOSE[12045] logger.c: > dialparties.agi: ExtensionState: 0 May 3 17:06:03 VERBOSE[12045] logger.c: dialparties.agi: Extension 223 has ExtensionState: 0 May 3 17:06:03 VERBOSE[12045] logger.c: -- dialparties.agi: Checking CW and CFB status for extension 223 May 3 17:06:03 DEBUG[12045] db.c: Unable to find key '223' in family 'CALLTRACE' May 3 17:06:03 VERBOSE[12045] logger.c: -- dialparties.agi: DbDel CALLTRACE/223 - Caller ID is not defined May 3 17:06:03 DEBUG[12045] db.c: Unable to find key '224' in family 'CW' May 3 17:06:03 DEBUG[12045] db.c: Unable to find key '224' in family 'CFB' May 3 17:06:03 DEBUG[12045] db.c: Unable to find key '224' in family 'CFU' May 3 17:06:03 VERBOSE[12045] logger.c: > dialparties.agi: extnum: 224 May 3 17:06:03 VERBOSE[12045] logger.c: > dialparties.agi: exthascw: 0 May 3 17:06:03 VERBOSE[12045] logger.c: > dialparties.agi: exthascfb: 0 May 3 17:06:03 VERBOSE[12045] logger.c: > dialparties.agi: extcfb: May 3 17:06:03 VERBOSE[12045] logger.c: > dialparties.agi: exthascfu: 0 May 3 17:06:03 VERBOSE[12045] logger.c: > dialparties.agi: extcfu: May 3 17:06:03 DEBUG[12052] manager.c: Manager received command 'login' May 3 17:06:03 VERBOSE[12052] logger.c: == Parsing '/etc/asterisk/manager.conf': May 3 17:06:03 VERBOSE[12052] logger.c: == Parsing '/etc/asterisk/manager.conf': Found May 3 17:06:03 VERBOSE[12052] logger.c: == Parsing '/etc/asterisk/manager_custom.conf': May 3 17:06:03 VERBOSE[12052] logger.c: == Parsing '/etc/asterisk/manager_custom.co$ May 3 17:06:03 WARNING[12052] config.c: Unknown directive 'permit=192.168.1.0/255.255.255.0' at line 18 of manager_custom.conf May 3 17:06:03 DEBUG[12052] acl.c: 0.0.0.0/0.0.0.0/0.0.0.0 appended to acl for peer May 3 17:06:03 DEBUG[12052] acl.c: 127.0.0.1/255.255.255.0/255.255.255.0 appended to acl for peer May 3 17:06:03 DEBUG[12052] acl.c: ##### Testing 127.0.0.1 with 0.0.0.0 May 3 17:06:03 DEBUG[12052] acl.c: ##### Testing 127.0.0.1 with 127.0.0.0 May 3 17:06:03 VERBOSE[12052] logger.c: == Manager 'admin' logged on from 127.0.0.1 May 3 17:06:03 DEBUG[12052] manager.c: Manager received command 'ExtensionState' May 3 17:06:03 DEBUG[12052] manager.c: Manager received command 'Logoff' May 3 17:06:03 DEBUG[12052] manager.c: Manager received command 'ExtensionState' May 3 17:06:03 DEBUG[12052] manager.c: Manager received command 'Logoff' May 3 17:06:03 VERBOSE[12052] logger.c: == Manager 'admin' logged off from 127.0.0.1 May 3 17:06:03 VERBOSE[12045] logger.c: > dialparties.agi: ExtensionState: 0 May 3 17:06:03 VERBOSE[12045] logger.c: dialparties.agi: Extension 224 has ExtensionState: 0 May 3 17:06:03 VERBOSE[12045] logger.c: -- dialparties.agi: Checking CW and CFB status for extension 224 May 3 17:06:03 DEBUG[12045] db.c: Unable to find key '224' in family 'CALLTRACE' May 3 17:06:03 VERBOSE[12045] logger.c: -- dialparties.agi: DbDel CALLTRACE/224 - Caller ID is not defined May 3 17:06:03 DEBUG[12045] db.c: Unable to find key '225' in family 'CW' May 3 17:06:03 DEBUG[12045] db.c: Unable to find key '225' in family 'CFB' May 3 17:06:03 DEBUG[12045] db.c: Unable to find key '225' in family 'CFU' May 3 17:06:03 VERBOSE[12045] logger.c: > dialparties.agi: extnum: 225 May 3 17:06:03 VERBOSE[12045] logger.c: > dialparties.agi: exthascw: 0 May 3 17:06:03 VERBOSE[12045] logger.c: > dialparties.agi: exthascfb: 0 May 3 17:06:03 VERBOSE[12045] logger.c: > dialparties.agi: extcfb: May 3 17:06:03 VERBOSE[12045] logger.c: > dialparties.agi: exthascfu: 0 May 3 17:06:03 VERBOSE[12045] logger.c: > dialparties.agi: extcfu: May 3 17:06:03 DEBUG[12053] manager.c: Manager received command 'login' May 3 17:06:03 VERBOSE[12053] logger.c: == Parsing '/etc/asterisk/manager.conf': May 3 17:06:03 VERBOSE[12053] logger.c: == Parsing '/etc/asterisk/manager.conf': Found May 3 17:06:03 VERBOSE[12053] logger.c: == Parsing '/etc/asterisk/manager_custom.conf': May 3 17:06:03 VERBOSE[12053] logger.c: == Parsing '/etc/asterisk/manager_custom.co$ May 3 17:06:03 WARNING[12053] config.c: Unknown directive 'permit=192.168.1.0/255.255.255.0' at line 18 of manager_custom.conf May 3 17:06:03 DEBUG[12053] acl.c: 0.0.0.0/0.0.0.0/0.0.0.0 appended to acl for peer May 3 17:06:03 DEBUG[12053] acl.c: 127.0.0.1/255.255.255.0/255.255.255.0 appended to acl for peer May 3 17:06:03 DEBUG[12053] acl.c: ##### Testing 127.0.0.1 with 0.0.0.0 May 3 17:06:03 DEBUG[12053] acl.c: ##### Testing 127.0.0.1 with 127.0.0.0 May 3 17:06:03 VERBOSE[12053] logger.c: == Manager 'admin' logged on from 127.0.0.1 May 3 17:06:03 DEBUG[12053] manager.c: Manager received command 'ExtensionState' May 3 17:06:03 DEBUG[12053] manager.c: Manager received command 'Logoff' May 3 17:06:03 VERBOSE[12053] logger.c: == Manager 'admin' logged off from 127.0.0.1 May 3 17:06:03 VERBOSE[12045] logger.c: > dialparties.agi: ExtensionState: 0 May 3 17:06:03 VERBOSE[12045] logger.c: dialparties.agi: Extension 225 has ExtensionState: 0 May 3 17:06:03 VERBOSE[12045] logger.c: -- dialparties.agi: Checking CW and CFB status for extension 225 May 3 17:06:03 VERBOSE[12045] logger.c: -- dialparties.agi: DbDel CALLTRACE/225 - Caller ID is not defined May 3 17:06:03 DEBUG[12045] db.c: Unable to find key '226' in family 'CW' May 3 17:06:03 DEBUG[12045] db.c: Unable to find key '226' in family 'CFB' May 3 17:06:03 DEBUG[12045] db.c: Unable to find key '226' in family 'CFU' May 3 17:06:03 VERBOSE[12045] logger.c: > dialparties.agi: extnum: 226 May 3 17:06:03 VERBOSE[12045] logger.c: > dialparties.agi: exthascw: 0 May 3 17:06:03 VERBOSE[12045] logger.c: > dialparties.agi: exthascfb: 0 May 3 17:06:03 VERBOSE[12045] logger.c: > dialparties.agi: extcfb: May 3 17:06:03 VERBOSE[12045] logger.c: > dialparties.agi: exthascfu: 0 May 3 17:06:03 VERBOSE[12045] logger.c: > dialparties.agi: extcfu: May 3 17:06:03 DEBUG[12054] manager.c: Manager received command 'login' May 3 17:06:03 VERBOSE[12054] logger.c: == Parsing '/etc/asterisk/manager.conf': May 3 17:06:03 VERBOSE[12054] logger.c: == Parsing '/etc/asterisk/manager.conf': Found May 3 17:06:03 VERBOSE[12054] logger.c: == Parsing '/etc/asterisk/manager_custom.conf': May 3 17:06:03 VERBOSE[12054] logger.c: == Parsing '/etc/asterisk/manager_custom.co$ May 3 17:06:03 WARNING[12054] config.c: Unknown directive 'permit=192.168.1.0/255.255.255.0' at line 18 of manager_custom.conf May 3 17:06:03 DEBUG[12054] acl.c: 0.0.0.0/0.0.0.0/0.0.0.0 appended to acl for peer May 3 17:06:03 DEBUG[12054] acl.c: 127.0.0.1/255.255.255.0/255.255.255.0 appended to acl for peer May 3 17:06:03 DEBUG[12054] acl.c: ##### Testing 127.0.0.1 with 0.0.0.0 May 3 17:06:03 DEBUG[12054] acl.c: ##### Testing 127.0.0.1 with 127.0.0.0 May 3 17:06:03 VERBOSE[12054] logger.c: == Manager 'admin' logged on from 127.0.0.1 May 3 17:06:03 DEBUG[12054] manager.c: Manager received command 'ExtensionState' May 3 17:06:03 DEBUG[12054] manager.c: Manager received command 'Logoff' May 3 17:06:03 VERBOSE[12054] logger.c: == Manager 'admin' logged off from 127.0.0.1 May 3 17:06:03 DEBUG[12054] manager.c: Manager received command 'Logoff' May 3 17:06:03 VERBOSE[12054] logger.c: == Manager 'admin' logged off from 127.0.0.1 May 3 17:06:03 VERBOSE[12045] logger.c: > dialparties.agi: ExtensionState: 0 May 3 17:06:03 VERBOSE[12045] logger.c: dialparties.agi: Extension 226 has ExtensionState: 0 May 3 17:06:03 VERBOSE[12045] logger.c: -- dialparties.agi: Checking CW and CFB status for extension 226 May 3 17:06:03 DEBUG[12045] db.c: Unable to find key '226' in family 'CALLTRACE' May 3 17:06:03 VERBOSE[12045] logger.c: -- dialparties.agi: DbDel CALLTRACE/226 - Caller ID is not defined May 3 17:06:03 DEBUG[12045] db.c: Unable to find key '227' in family 'CW' May 3 17:06:03 DEBUG[12045] db.c: Unable to find key '227' in family 'CFB' May 3 17:06:03 DEBUG[12045] db.c: Unable to find key '227' in family 'CFU' May 3 17:06:03 VERBOSE[12045] logger.c: > dialparties.agi: extnum: 227 May 3 17:06:03 VERBOSE[12045] logger.c: > dialparties.agi: exthascw: 0 May 3 17:06:03 VERBOSE[12045] logger.c: > dialparties.agi: exthascfb: 0 May 3 17:06:03 VERBOSE[12045] logger.c: > dialparties.agi: extcfb: May 3 17:06:03 VERBOSE[12045] logger.c: > dialparties.agi: exthascfu: 0 May 3 17:06:03 VERBOSE[12045] logger.c: > dialparties.agi: extcfu: May 3 17:06:03 DEBUG[12055] manager.c: Manager received command 'login' May 3 17:06:03 VERBOSE[12055] logger.c: == Parsing '/etc/asterisk/manager.conf': May 3 17:06:03 VERBOSE[12055] logger.c: == Parsing '/etc/asterisk/manager.conf': Found May 3 17:06:03 VERBOSE[12055] logger.c: == Parsing '/etc/asterisk/manager_custom.conf': May 3 17:06:03 VERBOSE[12055] logger.c: == Parsing '/etc/asterisk/manager_custom.co$ May 3 17:06:03 WARNING[12055] config.c: Unknown directive 'permit=192.168.1.0/255.255.255.0' at line 18 of manager_custom.conf May 3 17:06:03 DEBUG[12055] acl.c: 0.0.0.0/0.0.0.0/0.0.0.0 appended to acl for peer May 3 17:06:03 DEBUG[12055] acl.c: 127.0.0.1/255.255.255.0/255.255.255.0 appended to acl for peer May 3 17:06:03 DEBUG[12055] acl.c: ##### Testing 127.0.0.1 with 0.0.0.0 May 3 17:06:03 DEBUG[12055] acl.c: ##### Testing 127.0.0.1 with 127.0.0.0 May 3 17:06:03 VERBOSE[12055] logger.c: == Manager 'admin' logged on from 127.0.0.1 May 3 17:06:03 DEBUG[12055] manager.c: Manager received command 'ExtensionState' May 3 17:06:03 DEBUG[12055] manager.c: Manager received command 'Logoff' May 3 17:06:03 VERBOSE[12055] logger.c: == Manager 'admin' logged off from 127.0.0.1 May 3 17:06:03 VERBOSE[12045] logger.c: > dialparties.agi: ExtensionState: 0 May 3 17:06:03 VERBOSE[12045] logger.c: dialparties.agi: Extension 227 has ExtensionState: 0 May 3 17:06:03 VERBOSE[12045] logger.c: -- dialparties.agi: Checking CW and CFB status for extension 227 May 3 17:06:03 DEBUG[12045] db.c: Unable to find key '227' in family 'CALLTRACE' May 3 17:06:03 VERBOSE[12045] logger.c: -- dialparties.agi: DbDel CALLTRACE/227 - Caller ID is not defined May 3 17:06:03 DEBUG[12045] db.c: Unable to find key '228' in family 'CW' May 3 17:06:03 DEBUG[12045] db.c: Unable to find key '228' in family 'CFB' May 3 17:06:03 DEBUG[12045] db.c: Unable to find key '228' in family 'CFU' May 3 17:06:03 VERBOSE[12045] logger.c: > dialparties.agi: extnum: 228 May 3 17:06:03 VERBOSE[12045] logger.c: > dialparties.agi: exthascw: 0 May 3 17:06:03 VERBOSE[12045] logger.c: > dialparties.agi: exthascfb: 0 May 3 17:06:03 VERBOSE[12045] logger.c: > dialparties.agi: extcfb: May 3 17:06:03 VERBOSE[12045] logger.c: > dialparties.agi: exthascfu: 0 May 3 17:06:03 VERBOSE[12045] logger.c: > dialparties.agi: extcfu: May 3 17:06:03 DEBUG[12056] manager.c: Manager received command 'login' May 3 17:06:03 VERBOSE[12056] logger.c: == Parsing '/etc/asterisk/manager.conf': May 3 17:06:03 VERBOSE[12056] logger.c: == Parsing '/etc/asterisk/manager.conf': Found May 3 17:06:03 VERBOSE[12056] logger.c: == Parsing '/etc/asterisk/manager_custom.conf': May 3 17:06:03 VERBOSE[12056] logger.c: == Parsing '/etc/asterisk/manager_custom.co$ May 3 17:06:03 WARNING[12056] config.c: Unknown directive 'permit=192.168.1.0/255.255.255.0' at line 18 of manager_custom.conf May 3 17:06:03 DEBUG[12056] acl.c: 0.0.0.0/0.0.0.0/0.0.0.0 appended to acl for peer May 3 17:06:03 DEBUG[12056] acl.c: 127.0.0.1/255.255.255.0/255.255.255.0 appended to acl for peer May 3 17:06:03 DEBUG[12056] acl.c: ##### Testing 127.0.0.1 with 0.0.0.0 May 3 17:06:03 DEBUG[12056] acl.c: ##### Testing 127.0.0.1 with 127.0.0.0 May 3 17:06:03 VERBOSE[12056] logger.c: == Manager 'admin' logged on from 127.0.0.1 May 3 17:06:03 DEBUG[12056] manager.c: Manager received command 'ExtensionState' May 3 17:06:03 DEBUG[12056] manager.c: Manager received command 'Logoff' May 3 17:06:03 VERBOSE[12056] logger.c: == Manager 'admin' logged off from 127.0.0.1 May 3 17:06:03 DEBUG[12056] manager.c: Manager received command 'Logoff' May 3 17:06:03 VERBOSE[12056] logger.c: == Manager 'admin' logged off from 127.0.0.1 May 3 17:06:03 VERBOSE[12045] logger.c: > dialparties.agi: ExtensionState: 0 May 3 17:06:03 VERBOSE[12045] logger.c: dialparties.agi: Extension 228 has ExtensionState: 0 May 3 17:06:03 VERBOSE[12045] logger.c: -- dialparties.agi: Checking CW and CFB status for extension 228 May 3 17:06:03 DEBUG[12045] db.c: Unable to find key '228' in family 'CALLTRACE' May 3 17:06:03 VERBOSE[12045] logger.c: -- dialparties.agi: DbDel CALLTRACE/228 - Caller ID is not defined May 3 17:06:03 DEBUG[12045] db.c: Unable to find key '229' in family 'CW' May 3 17:06:03 DEBUG[12045] db.c: Unable to find key '229' in family 'CFB' May 3 17:06:03 DEBUG[12045] db.c: Unable to find key '229' in family 'CFU' May 3 17:06:03 VERBOSE[12045] logger.c: > dialparties.agi: extnum: 229 May 3 17:06:03 VERBOSE[12045] logger.c: > dialparties.agi: exthascw: 0 May 3 17:06:03 VERBOSE[12045] logger.c: > dialparties.agi: exthascfb: 0 May 3 17:06:03 VERBOSE[12045] logger.c: > dialparties.agi: extcfb: May 3 17:06:03 VERBOSE[12045] logger.c: > dialparties.agi: exthascfu: 0 May 3 17:06:03 VERBOSE[12045] logger.c: > dialparties.agi: extcfu: May 3 17:06:03 DEBUG[12057] manager.c: Manager received command 'login' May 3 17:06:03 VERBOSE[12057] logger.c: == Parsing '/etc/asterisk/manager.conf': May 3 17:06:03 VERBOSE[12057] logger.c: == Parsing '/etc/asterisk/manager.conf': Found May 3 17:06:03 VERBOSE[12057] logger.c: == Parsing '/etc/asterisk/manager_custom.conf': May 3 17:06:03 VERBOSE[12057] logger.c: == Parsing '/etc/asterisk/manager_custom.co$ May 3 17:06:03 WARNING[12057] config.c: Unknown directive 'permit=192.168.1.0/255.255.255.0' at line 18 of manager_custom.conf May 3 17:06:03 DEBUG[12057] acl.c: 0.0.0.0/0.0.0.0/0.0.0.0 appended to acl for peer May 3 17:06:03 DEBUG[12057] acl.c: 127.0.0.1/255.255.255.0/255.255.255.0 appended to acl for peer May 3 17:06:03 DEBUG[12057] acl.c: ##### Testing 127.0.0.1 with 0.0.0.0 May 3 17:06:03 DEBUG[12057] acl.c: ##### Testing 127.0.0.1 with 127.0.0.0 May 3 17:06:03 VERBOSE[12057] logger.c: == Manager 'admin' logged on from 127.0.0.1 May 3 17:06:03 DEBUG[12057] manager.c: Manager received command 'ExtensionState' May 3 17:06:03 DEBUG[12057] manager.c: Manager received command 'Logoff' May 3 17:06:03 VERBOSE[12057] logger.c: == Manager 'admin' logged off from 127.0.0.1 May 3 17:06:03 VERBOSE[12045] logger.c: > dialparties.agi: ExtensionState: 0 May 3 17:06:03 VERBOSE[12045] logger.c: dialparties.agi: Extension 229 has ExtensionState: 0 May 3 17:06:03 VERBOSE[12045] logger.c: -- dialparties.agi: Checking CW and CFB status for extension 229 May 3 17:06:03 DEBUG[12045] db.c: Unable to find key '229' in family 'CALLTRACE' May 3 17:06:03 VERBOSE[12045] logger.c: -- dialparties.agi: DbDel CALLTRACE/229 - Caller ID is not defined May 3 17:06:03 DEBUG[12045] db.c: Unable to find key '230' in family 'CW' May 3 17:06:03 DEBUG[12045] db.c: Unable to find key '230' in family 'CFB' May 3 17:06:03 DEBUG[12045] db.c: Unable to find key '230' in family 'CFU' May 3 17:06:03 VERBOSE[12045] logger.c: > dialparties.agi: extnum: 230 May 3 17:06:03 VERBOSE[12045] logger.c: > dialparties.agi: exthascw: 0 May 3 17:06:03 VERBOSE[12045] logger.c: > dialparties.agi: exthascfb: 0 May 3 17:06:03 VERBOSE[12045] logger.c: > dialparties.agi: extcfb: May 3 17:06:03 VERBOSE[12045] logger.c: > dialparties.agi: exthascfu: 0 May 3 17:06:03 VERBOSE[12045] logger.c: > dialparties.agi: extcfu: May 3 17:06:03 DEBUG[12058] manager.c: Manager received command 'login' May 3 17:06:03 VERBOSE[12058] logger.c: == Parsing '/etc/asterisk/manager.conf': May 3 17:06:03 VERBOSE[12058] logger.c: == Parsing '/etc/asterisk/manager.conf': Found May 3 17:06:03 VERBOSE[12058] logger.c: == Parsing '/etc/asterisk/manager_custom.conf': May 3 17:06:03 VERBOSE[12058] logger.c: == Parsing '/etc/asterisk/manager_custom.co$ May 3 17:06:03 WARNING[12058] config.c: Unknown directive 'permit=192.168.1.0/255.255.255.0' at line 18 of manager_custom.conf May 3 17:06:03 DEBUG[12058] acl.c: 0.0.0.0/0.0.0.0/0.0.0.0 appended to acl for peer May 3 17:06:03 DEBUG[12058] acl.c: 127.0.0.1/255.255.255.0/255.255.255.0 appended to acl for peer May 3 17:06:03 DEBUG[12058] acl.c: ##### Testing 127.0.0.1 with 0.0.0.0 May 3 17:06:03 DEBUG[12058] acl.c: ##### Testing 127.0.0.1 with 127.0.0.0 May 3 17:06:03 VERBOSE[12058] logger.c: == Manager 'admin' logged on from 127.0.0.1 May 3 17:06:03 DEBUG[12058] manager.c: Manager received command 'ExtensionState' May 3 17:06:03 DEBUG[12058] manager.c: Manager received command 'Logoff' May 3 17:06:03 VERBOSE[12058] logger.c: == Manager 'admin' logged off from 127.0.0.1 May 3 17:06:03 DEBUG[12058] manager.c: Manager received command 'Logoff' May 3 17:06:03 VERBOSE[12058] logger.c: == Manager 'admin' logged off from 127.0.0.1 May 3 17:06:03 VERBOSE[12045] logger.c: > dialparties.agi: ExtensionState: 0 May 3 17:06:03 VERBOSE[12045] logger.c: dialparties.agi: Extension 230 has ExtensionState: 0 May 3 17:06:03 VERBOSE[12045] logger.c: -- dialparties.agi: Checking CW and CFB status for extension 230 May 3 17:06:03 DEBUG[12045] db.c: Unable to find key '230' in family 'CALLTRACE' May 3 17:06:03 VERBOSE[12045] logger.c: -- dialparties.agi: DbDel CALLTRACE/230 - Caller ID is not defined May 3 17:06:03 VERBOSE[12045] logger.c: > dialparties.agi: NODEST: 1 adding M(auto-blkvm) to dialopts: trM(auto-blkvm) May 3 17:06:03 VERBOSE[12045] logger.c: -- AGI Script dialparties.agi completed, returning 0 May 3 17:06:03 VERBOSE[12045] logger.c: -- Executing Dial("Zap/1-1", "SIP/221&SIP/222&SIP/223&SIP/224&SIP/225&SIP/226&SIP/227&SIP/228&SIP/229&SIP/230|25|trM(auto-blkvm)") i$ May 3 17:06:03 DEBUG[12045] chan_sip.c: Setting NAT on RTP to 0 May 3 17:06:03 DEBUG[12045] chan_sip.c: Outgoing Call for 221 May 3 17:06:03 VERBOSE[12045] logger.c: -- Called 221 May 3 17:06:03 DEBUG[12045] chan_sip.c: Setting NAT on RTP to 0 May 3 17:06:03 DEBUG[12045] chan_sip.c: Outgoing Call for 222 May 3 17:06:03 VERBOSE[12045] logger.c: -- Called 222 May 3 17:06:03 DEBUG[12045] chan_sip.c: Setting NAT on RTP to 0 May 3 17:06:03 DEBUG[12045] chan_sip.c: Outgoing Call for 223 May 3 17:06:03 VERBOSE[12045] logger.c: -- Called 223 May 3 17:06:03 DEBUG[12045] chan_sip.c: Setting NAT on RTP to 0 May 3 17:06:03 DEBUG[12045] chan_sip.c: Outgoing Call for 224 May 3 17:06:03 VERBOSE[12045] logger.c: -- Called 224 May 3 17:06:03 DEBUG[12045] chan_sip.c: Setting NAT on RTP to 0 May 3 17:06:03 DEBUG[12045] chan_sip.c: Outgoing Call for 225 May 3 17:06:03 VERBOSE[12045] logger.c: -- Called 225 May 3 17:06:03 DEBUG[12045] chan_sip.c: Setting NAT on RTP to 0 May 3 17:06:03 DEBUG[12045] chan_sip.c: Outgoing Call for 226 May 3 17:06:03 VERBOSE[12045] logger.c: -- Called 226 May 3 17:06:03 DEBUG[12045] chan_sip.c: Setting NAT on RTP to 524288 May 3 17:06:03 DEBUG[12045] chan_sip.c: Outgoing Call for 227 May 3 17:06:03 VERBOSE[12045] logger.c: -- Called 227 May 3 17:06:03 DEBUG[12045] chan_sip.c: Setting NAT on RTP to 524288 May 3 17:06:03 DEBUG[12045] chan_sip.c: Outgoing Call for 228 May 3 17:06:03 VERBOSE[12045] logger.c: -- Called 228 May 3 17:06:03 DEBUG[12045] chan_sip.c: Setting NAT on RTP to 524288 May 3 17:06:03 DEBUG[12045] chan_sip.c: Outgoing Call for 229 May 3 17:06:03 VERBOSE[12045] logger.c: -- Called 229 May 3 17:06:03 DEBUG[12045] chan_sip.c: Setting NAT on RTP to 524288 May 3 17:06:03 DEBUG[12045] chan_sip.c: Outgoing Call for 230 May 3 17:06:03 VERBOSE[12045] logger.c: -- Called 230 May 3 17:06:03 DEBUG[12045] chan_zap.c: Requested indication 3 on channel Zap/1-1 May 3 17:06:04 DEBUG[3529] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '394dc5c35a8cfa906fe13fc705ea19b0@192.168.5.6' Request 102: Found May 3 17:06:04 DEBUG[3529] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '02acf8370d767bd82318c439736cfa47@192.168.5.6' Request 102: Found May 3 17:06:04 DEBUG[3529] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '17be7da474a90bd5039d6d880a709597@192.168.5.6' Request 102: Found May 3 17:06:04 DEBUG[3529] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '340fa9665cf3c4bc5f2ff51f09022e49@192.168.5.6' Request 102: Found May 3 17:06:04 DEBUG[3529] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '6219912b6321ae64194d21b47a56c7c2@192.168.5.6' Request 102: Found May 3 17:06:04 DEBUG[3529] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '4baec8416318b40d12fcb9de1166f650@192.168.5.6' Request 102: Found May 3 17:06:04 DEBUG[3529] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '301cabc90151430c402ceda3040d7914@192.168.5.6' Request 102: Found May 3 17:06:04 DEBUG[3529] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '17be7da474a90bd5039d6d880a709597@192.168.5.6' Request 102: Found May 3 17:06:04 VERBOSE[12045] logger.c: -- SIP/225-083f5f48 is ringing May 3 17:06:04 DEBUG[3529] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '340fa9665cf3c4bc5f2ff51f09022e49@192.168.5.6' Request 102: Found May 3 17:06:04 VERBOSE[12045] logger.c: -- SIP/226-083fbba0 is ringing May 3 17:06:04 DEBUG[3529] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '6219912b6321ae64194d21b47a56c7c2@192.168.5.6' Request 102: Found May 3 17:06:04 VERBOSE[12045] logger.c: -- SIP/224-083f02f0 is ringing May 3 17:06:04 DEBUG[3529] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '6219912b6321ae64194d21b47a56c7c2@192.168.5.6' Request 102: Found May 3 17:06:04 VERBOSE[12045] logger.c: -- SIP/224-083f02f0 is ringing May 3 17:06:04 DEBUG[3529] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '02acf8370d767bd82318c439736cfa47@192.168.5.6' Request 102: Found May 3 17:06:04 VERBOSE[12045] logger.c: -- SIP/223-083ea698 is ringing May 3 17:06:04 DEBUG[3529] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '3b833b0153c8566d6be1143d7c3d7f22@192.168.5.6' Request 102: Found May 3 17:06:04 DEBUG[3529] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '3b2f779a48b620490466e1e74223a218@192.168.5.6' Request 102: Found May 3 17:06:04 DEBUG[3529] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '3b833b0153c8566d6be1143d7c3d7f22@192.168.5.6' Request 102: Found May 3 17:06:04 VERBOSE[12045] logger.c: -- SIP/222-083e4e50 is ringing May 3 17:06:04 DEBUG[3529] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '505dc9306f3ef4c87415106a00b494b1@192.168.5.6' Request 102: Found May 3 17:06:04 DEBUG[3529] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '4baec8416318b40d12fcb9de1166f650@192.168.5.6' Request 102: Found May 3 17:06:04 VERBOSE[12045] logger.c: -- SIP/221-083aa418 is ringing May 3 17:06:04 DEBUG[3529] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '394dc5c35a8cfa906fe13fc705ea19b0@192.168.5.6' Request 102: Found May 3 17:06:04 DEBUG[3529] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '301cabc90151430c402ceda3040d7914@192.168.5.6' Request 102: Found May 3 17:06:04 DEBUG[3529] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '4baec8416318b40d12fcb9de1166f650@192.168.5.6' Request 102: Found May 3 17:06:04 VERBOSE[12045] logger.c: -- SIP/228-08407458 is ringing May 3 17:06:04 DEBUG[3529] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '3b2f779a48b620490466e1e74223a218@192.168.5.6' Request 102: Found May 3 17:06:04 DEBUG[3529] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '3b2f779a48b620490466e1e74223a218@192.168.5.6' Request 102: Found May 3 17:06:04 DEBUG[3529] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '394dc5c35a8cfa906fe13fc705ea19b0@192.168.5.6' Request 102: Found May 3 17:06:04 VERBOSE[12045] logger.c: -- SIP/229-0840d0b8 is ringing May 3 17:06:04 VERBOSE[12045] logger.c: -- SIP/230-08412d18 is ringing May 3 17:06:04 DEBUG[3529] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '301cabc90151430c402ceda3040d7914@192.168.5.6' Request 102: Found May 3 17:06:04 VERBOSE[12045] logger.c: -- SIP/227-084017f8 is ringing May 3 17:06:06 DEBUG[3529] chan_sip.c: Acked pending invite 102 May 3 17:06:06 DEBUG[3529] chan_sip.c: Stopping retransmission on '17be7da474a90bd5039d6d880a709597@192.168.5.6' of Request 102: Match Found May 3 17:06:06 DEBUG[3529] chan_sip.c: build_route: Contact hop: May 3 17:06:06 VERBOSE[12045] logger.c: -- SIP/225-083f5f48 answered Zap/1-1 May 3 17:06:06 DEBUG[12045] chan_sip.c: update_call_counter(230) - decrement call limit counter May 3 17:06:06 DEBUG[12045] chan_sip.c: Acked pending invite 102 May 3 17:06:06 DEBUG[12045] chan_sip.c: Stopping retransmission on '394dc5c35a8cfa906fe13fc705ea19b0@192.168.5.6' of Request 102: Match Found May 3 17:06:06 DEBUG[12045] chan_sip.c: update_call_counter(229) - decrement call limit counter May 3 17:06:06 DEBUG[12045] chan_sip.c: Acked pending invite 102 May 3 17:06:06 DEBUG[12045] chan_sip.c: Stopping retransmission on '3b2f779a48b620490466e1e74223a218@192.168.5.6' of Request 102: Match Found May 3 17:06:06 DEBUG[12045] chan_sip.c: update_call_counter(228) - decrement call limit counter May 3 17:06:06 DEBUG[12045] chan_sip.c: Acked pending invite 102 May 3 17:06:06 DEBUG[12045] chan_sip.c: Stopping retransmission on '4baec8416318b40d12fcb9de1166f650@192.168.5.6' of Request 102: Match Found May 3 17:06:06 DEBUG[12045] chan_sip.c: update_call_counter(227) - decrement call limit counter May 3 17:06:06 DEBUG[12045] chan_sip.c: Acked pending invite 102 May 3 17:06:06 DEBUG[12045] chan_sip.c: Stopping retransmission on '301cabc90151430c402ceda3040d7914@192.168.5.6' of Request 102: Match Found May 3 17:06:06 DEBUG[12045] chan_sip.c: update_call_counter(226) - decrement call limit counter May 3 17:06:06 DEBUG[12045] chan_sip.c: Acked pending invite 102 May 3 17:06:06 DEBUG[12045] chan_sip.c: Stopping retransmission on '340fa9665cf3c4bc5f2ff51f09022e49@192.168.5.6' of Request 102: Match Found May 3 17:06:06 DEBUG[12045] chan_sip.c: update_call_counter(224) - decrement call limit counter May 3 17:06:06 DEBUG[12045] chan_sip.c: Acked pending invite 102 May 3 17:06:06 DEBUG[12045] chan_sip.c: Stopping retransmission on '6219912b6321ae64194d21b47a56c7c2@192.168.5.6' of Request 102: Match Found May 3 17:06:06 DEBUG[12045] chan_sip.c: update_call_counter(223) - decrement call limit counter May 3 17:06:06 DEBUG[12045] chan_sip.c: Acked pending invite 102 May 3 17:06:06 DEBUG[12045] chan_sip.c: Stopping retransmission on '02acf8370d767bd82318c439736cfa47@192.168.5.6' of Request 102: Match Found May 3 17:06:06 DEBUG[12045] chan_sip.c: update_call_counter(222) - decrement call limit counter May 3 17:06:06 DEBUG[12045] chan_sip.c: Acked pending invite 102 May 3 17:06:06 DEBUG[12045] chan_sip.c: Stopping retransmission on '3b833b0153c8566d6be1143d7c3d7f22@192.168.5.6' of Request 102: Match Found May 3 17:06:06 DEBUG[12045] chan_sip.c: update_call_counter(221) - decrement call limit counter May 3 17:06:06 DEBUG[12045] chan_sip.c: Acked pending invite 102 May 3 17:06:06 DEBUG[12045] chan_sip.c: Stopping retransmission on '505dc9306f3ef4c87415106a00b494b1@192.168.5.6' of Request 102: Match Found May 3 17:06:06 VERBOSE[12045] logger.c: -- Executing Set("SIP/225-083f5f48", "__MACRO_RESULT=") in new stack May 3 17:06:06 DEBUG[12045] chan_sip.c: Stopping retransmission on '505dc9306f3ef4c87415106a00b494b1@192.168.5.6' of Request 102: Match Found May 3 17:06:06 VERBOSE[12045] logger.c: -- Executing Set("SIP/225-083f5f48", "__MACRO_RESULT=") in new stack May 3 17:06:06 VERBOSE[12045] logger.c: -- Executing DBdel("SIP/225-083f5f48", "BLKVM/1/Zap/1-1") in new stack May 3 17:06:06 VERBOSE[12045] logger.c: -- DBdel: family=BLKVM, key=1/Zap/1-1 May 3 17:06:06 DEBUG[12045] app_dial.c: Macro exited with status 0 May 3 17:06:06 DEBUG[12045] chan_zap.c: Requested indication -1 on channel Zap/1-1 May 3 17:06:06 DEBUG[12045] chan_zap.c: Took Zap/1-1 off hook May 3 17:06:06 DEBUG[3529] chan_sip.c: Stopping retransmission on '3b833b0153c8566d6be1143d7c3d7f22@192.168.5.6' of Request 102: Match Found May 3 17:06:06 DEBUG[3529] chan_sip.c: Stopping retransmission on '301cabc90151430c402ceda3040d7914@192.168.5.6' of Request 102: Match Found May 3 17:06:06 DEBUG[3529] chan_sip.c: Stopping retransmission on '394dc5c35a8cfa906fe13fc705ea19b0@192.168.5.6' of Request 102: Match Found May 3 17:06:06 DEBUG[3529] chan_sip.c: Stopping retransmission on '3b2f779a48b620490466e1e74223a218@192.168.5.6' of Request 102: Match Found May 3 17:06:06 DEBUG[3529] chan_sip.c: Stopping retransmission on '02acf8370d767bd82318c439736cfa47@192.168.5.6' of Request 102: Match Found May 3 17:06:06 DEBUG[3529] chan_sip.c: Stopping retransmission on '340fa9665cf3c4bc5f2ff51f09022e49@192.168.5.6' of Request 102: Match Found May 3 17:06:06 DEBUG[3529] chan_sip.c: Stopping retransmission on '6219912b6321ae64194d21b47a56c7c2@192.168.5.6' of Request 102: Match Found May 3 17:06:06 DEBUG[3529] chan_sip.c: Stopping retransmission on '4baec8416318b40d12fcb9de1166f650@192.168.5.6' of Request 102: Match Found May 3 17:06:06 DEBUG[3529] chan_sip.c: Stopping retransmission on '301cabc90151430c402ceda3040d7914@192.168.5.6' of Request 102: Match Not Found May 3 17:06:06 DEBUG[3529] chan_sip.c: Stopping retransmission on '3b833b0153c8566d6be1143d7c3d7f22@192.168.5.6' of Request 102: Match Not Found May 3 17:06:06 DEBUG[3529] chan_sip.c: Stopping retransmission on '02acf8370d767bd82318c439736cfa47@192.168.5.6' of Request 102: Match Not Found May 3 17:06:06 DEBUG[3529] chan_sip.c: Stopping retransmission on '394dc5c35a8cfa906fe13fc705ea19b0@192.168.5.6' of Request 102: Match Not Found May 3 17:06:06 DEBUG[3529] chan_sip.c: Stopping retransmission on '3b2f779a48b620490466e1e74223a218@192.168.5.6' of Request 102: Match Not Found May 3 17:06:06 DEBUG[3529] chan_sip.c: Stopping retransmission on '340fa9665cf3c4bc5f2ff51f09022e49@192.168.5.6' of Request 102: Match Not Found May 3 17:06:06 DEBUG[3529] chan_sip.c: Stopping retransmission on '6219912b6321ae64194d21b47a56c7c2@192.168.5.6' of Request 102: Match Not Found May 3 17:06:06 DEBUG[3529] chan_sip.c: Stopping retransmission on '4baec8416318b40d12fcb9de1166f650@192.168.5.6' of Request 102: Match Not Found May 3 17:06:06 DEBUG[3529] chan_sip.c: That's odd... Got a response on a call we dont know about. Cseq 102 Cmd SIP/2.0 May 3 17:06:06 DEBUG[3529] chan_sip.c: That's odd... Got a response on a call we dont know about. Cseq 102 Cmd SIP/2.0 May 3 17:06:06 DEBUG[3529] chan_sip.c: That's odd... Got a response on a call we dont know about. Cseq 102 Cmd SIP/2.0 May 3 17:06:06 DEBUG[3529] chan_sip.c: That's odd... Got a response on a call we dont know about. Cseq 102 Cmd SIP/2.0 May 3 17:06:06 DEBUG[3529] chan_sip.c: Stopping retransmission on '505dc9306f3ef4c87415106a00b494b1@192.168.5.6' of Request 102: Match Not Found May 3 17:06:06 DEBUG[3529] chan_sip.c: Stopping retransmission on '505dc9306f3ef4c87415106a00b494b1@192.168.5.6' of Request 102: Match Found May 3 17:06:12 DEBUG[3529] chan_sip.c: Auto destroying call 'e6ef375afa4faa802d4aa017312f2be0@192.168.5.104'