Sep 1 15:48:22 DEBUG[17601] chan_iax2.c: Peer lastms 18, historicms 18, maxms 120 Sep 1 15:48:26 DEBUG[17596] channel.c: Scheduling timer at 160 sample intervals Sep 1 15:48:26 DEBUG[30653] channel.c: Generator got voice, switching to phase locked mode Sep 1 15:48:26 DEBUG[30653] channel.c: Scheduling timer at 0 sample intervals Sep 1 15:48:26 DEBUG[17596] chan_sip.c: Stopping retransmission on '0a7bb27003cb8f19576a453d66a31981@10.1.20.3' of Response 1: Match Found Sep 1 15:48:29 DEBUG[17596] acl.c: ##### Testing 10.1.20.69 with 10.1.20.0 Sep 1 15:48:29 DEBUG[17596] acl.c: ##### Testing 10.1.20.69 with 172.28.1.0 Sep 1 15:48:29 DEBUG[17596] chan_sip.c: Setting NAT on RTP to 0 Sep 1 15:48:29 DEBUG[17596] chan_sip.c: Stopping retransmission on 'b5f527fb-1e4ed5d9-bfd1c530@10.1.20.69' of Response 1: Match Found Sep 1 15:48:29 DEBUG[17596] chan_sip.c: Setting NAT on RTP to 0 Sep 1 15:48:29 DEBUG[17596] chan_sip.c: Checking SIP call limits for device 1029 Sep 1 15:48:29 DEBUG[17596] chan_sip.c: build_route: Contact hop: Sep 1 15:48:29 DEBUG[17585] channel.c: Avoiding initial deadlock for 'SIP/1029-093aa288' Sep 1 15:48:29 DEBUG[30768] pbx.c: Expression result is '1' Sep 1 15:48:29 DEBUG[30768] pbx.c: Function result is 'Jane Bell' Sep 1 15:48:29 DEBUG[30768] pbx.c: Function result is '1010@local' Sep 1 15:48:29 DEBUG[30768] chan_sip.c: Setting NAT on RTP to 0 Sep 1 15:48:29 DEBUG[30768] acl.c: ##### Testing 10.1.20.50 with 10.1.20.0 Sep 1 15:48:29 DEBUG[30768] acl.c: ##### Testing 10.1.20.50 with 172.28.1.0 Sep 1 15:48:29 DEBUG[30768] chan_sip.c: Outgoing Call for 1010 Sep 1 15:48:29 DEBUG[17596] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '00576cf01d0f2ce35c818f625d8f2bbf@10.1.20.3' Request 102: Found Sep 1 15:48:29 DEBUG[17596] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '00576cf01d0f2ce35c818f625d8f2bbf@10.1.20.3' Request 102: Found Sep 1 15:48:31 DEBUG[17596] chan_sip.c: Acked pending invite 102 Sep 1 15:48:31 DEBUG[17596] chan_sip.c: Stopping retransmission on '00576cf01d0f2ce35c818f625d8f2bbf@10.1.20.3' of Request 102: Match Found Sep 1 15:48:31 DEBUG[17596] chan_sip.c: build_route: Contact hop: Sep 1 15:48:31 DEBUG[17585] channel.c: Avoiding initial deadlock for 'SIP/1029-093aa288' Sep 1 15:48:31 DEBUG[17596] chan_sip.c: Stopping retransmission on 'b5f527fb-1e4ed5d9-bfd1c530@10.1.20.69' of Response 2: Match Found Sep 1 15:48:39 DEBUG[30718] chan_agent.c: Bridge on 'SIP/1026-09382bc8' being cleared (2) Sep 1 15:48:39 DEBUG[30718] chan_sip.c: update_call_counter(1026) - decrement call limit counter Sep 1 15:48:39 DEBUG[30718] channel.c: Didn't get a frame from channel: Agent/2073 Sep 1 15:48:39 DEBUG[30718] channel.c: Bridge stops bridging channels Agent/2073 and SIP/mags-093620a0 Sep 1 15:48:39 DEBUG[30718] chan_sip.c: update_call_counter(441616826222) - decrement call limit counter Sep 1 15:48:39 DEBUG[30718] app_dial.c: Exiting with DIALSTATUS=ANSWER. Sep 1 15:48:39 DEBUG[30718] channel.c: Spy MixMonitor removed from channel Agent/2073 Sep 1 15:48:39 DEBUG[30718] cdr_pgsql.c: cdr_pgsql: inserting a CDR record. Sep 1 15:48:39 DEBUG[30718] cdr_pgsql.c: cdr_pgsql: SQL command executed: INSERT INTO cdr (calldate,clid,src,dst,dcontext,channel,dstchannel,lastapp,lastdata,duration,billsec,disposition,amaflags,accountcode,uniqueid,userfield) VALUES ('2006-09-01 15:47:06','"->Austin Waldron junior" <01616826222>','01616826222','01616826222','auto_dial', 'Agent/2073','SIP/mags-093620a0','Dial','SIP/441616826222@mags',93,89,'ANSWERED',3,'Evision-BIT','1157122026.2454','000/agent-2073-o227637c123907-20060901-154706.729') Sep 1 15:48:39 DEBUG[30718] chan_agent.c: Hangup called for state Up Sep 1 15:48:39 NOTICE[30718] pbx_spool.c: Call completed to AGENT/2073 Sep 1 15:48:39 DEBUG[17596] chan_sip.c: Stopping retransmission on '6b494f0e16f5fdcc09323009702401d4@gk.magrathea.net' of Request 104: Match Found Sep 1 15:48:45 DEBUG[30665] chan_agent.c: Bridge on 'SIP/1024-09350e68' being cleared (2) Sep 1 15:48:45 DEBUG[30665] chan_sip.c: update_call_counter(1024) - decrement call limit counter Sep 1 15:48:45 DEBUG[30665] channel.c: Didn't get a frame from channel: Agent/2074 Sep 1 15:48:45 DEBUG[30665] channel.c: Bridge stops bridging channels Agent/2074 and SIP/mags-093a3710 Sep 1 15:48:45 DEBUG[30665] chan_sip.c: update_call_counter(442075800515) - decrement call limit counter Sep 1 15:48:45 DEBUG[30665] app_dial.c: Exiting with DIALSTATUS=ANSWER. Sep 1 15:48:45 DEBUG[30665] channel.c: Spy MixMonitor removed from channel Agent/2074 Sep 1 15:48:45 DEBUG[30665] cdr_pgsql.c: cdr_pgsql: inserting a CDR record. Sep 1 15:48:45 DEBUG[30665] cdr_pgsql.c: cdr_pgsql: SQL command executed: INSERT INTO cdr (calldate,clid,src,dst,dcontext,channel,dstchannel,lastapp,lastdata,duration,billsec,disposition,amaflags,accountcode,uniqueid,userfield) VALUES ('2006-09-01 15:45:52','"->Hilary S Riva" <02075800515>','02075800515','02075800515','auto_dial', 'Agent/2074','SIP/mags-093a3710','Dial','SIP/442075800515@mags',173,170,'ANSWERED',3,'Blue Martini','1157121951.2437','000/agent-2074-o90007254c263755-20060901-154552.729') Sep 1 15:48:45 DEBUG[30665] chan_agent.c: Hangup called for state Up Sep 1 15:48:45 NOTICE[30665] pbx_spool.c: Call completed to AGENT/2074 Sep 1 15:48:45 DEBUG[17596] chan_sip.c: Stopping retransmission on '01f749ed1034abb51a14ab4320f9a680@gk.magrathea.net' of Request 104: Match Found Sep 1 15:49:12 DEBUG[17596] acl.c: ##### Testing 213.166.5.135 with 10.1.20.0 Sep 1 15:49:12 DEBUG[17596] acl.c: ##### Testing 213.166.5.135 with 172.28.1.0 Sep 1 15:49:12 DEBUG[17596] chan_sip.c: Target address 213.166.5.135 is not local, substituting externip Sep 1 15:49:12 DEBUG[17596] chan_sip.c: Stopping retransmission on '538c54df67fa491d0ffbd8f034277706@89.105.104.74' of Request 102: Match Found Sep 1 15:49:22 DEBUG[17601] chan_iax2.c: Peer lastms 19, historicms 19, maxms 120 Sep 1 15:49:30 DEBUG[30740] chan_agent.c: Bridge on 'SIP/1023-09319be8' being cleared (2) Sep 1 15:49:30 DEBUG[30740] chan_sip.c: update_call_counter(1023) - decrement call limit counter Sep 1 15:49:30 DEBUG[30740] channel.c: Didn't get a frame from channel: Agent/2071 Sep 1 15:49:30 DEBUG[30740] channel.c: Bridge stops bridging channels Agent/2071 and SIP/mags-09373ce8 Sep 1 15:49:30 DEBUG[30740] chan_sip.c: update_call_counter(19086048686) - decrement call limit counter Sep 1 15:49:30 DEBUG[30740] app_dial.c: Exiting with DIALSTATUS=ANSWER. Sep 1 15:49:30 DEBUG[30740] channel.c: Spy MixMonitor removed from channel Agent/2071 Sep 1 15:49:30 DEBUG[30740] cdr_pgsql.c: cdr_pgsql: inserting a CDR record. Sep 1 15:49:30 DEBUG[30740] cdr_pgsql.c: cdr_pgsql: SQL command executed: INSERT INTO cdr (calldate,clid,src,dst,dcontext,channel,dstchannel,lastapp,lastdata,duration,billsec,disposition,amaflags,accountcode,uniqueid,userfield) VALUES ('2006-09-01 15:47:31','"->SAL GIORDANO" <0019086048686>','0019086048686','0019086048686','auto_dial', 'Agent/2071','SIP/mags-09373ce8','Dial','SIP/19086048686@mags',119,114,'ANSWERED',3,'Perot Systems TSI (USA)','1157122051.2459','000/agent-2071-o722253c261087-20060901-154731.729') Sep 1 15:49:30 DEBUG[30740] chan_agent.c: Hangup called for state Up Sep 1 15:49:30 NOTICE[30740] pbx_spool.c: Call completed to AGENT/2071 Sep 1 15:49:30 DEBUG[17596] chan_sip.c: Stopping retransmission on '6615dcf366004734136b2e506ddbd86c@gk.magrathea.net' of Request 104: Match Found Sep 1 15:50:12 DEBUG[17596] acl.c: ##### Testing 213.166.5.135 with 10.1.20.0 Sep 1 15:50:12 DEBUG[17596] acl.c: ##### Testing 213.166.5.135 with 172.28.1.0 Sep 1 15:50:12 DEBUG[17596] chan_sip.c: Target address 213.166.5.135 is not local, substituting externip Sep 1 15:50:12 DEBUG[17596] chan_sip.c: Stopping retransmission on '2d22dd33528d6a842c33d82852f7f339@89.105.104.74' of Request 102: Match Found Sep 1 15:50:22 DEBUG[17601] chan_iax2.c: Peer lastms 18, historicms 18, maxms 120 Sep 1 15:50:25 DEBUG[30752] chan_agent.c: Bridge on 'SIP/1016-09329b30' being cleared (2) Sep 1 15:50:25 DEBUG[30752] chan_sip.c: update_call_counter(1016) - decrement call limit counter Sep 1 15:50:25 DEBUG[30752] channel.c: Didn't get a frame from channel: Agent/2033 Sep 1 15:50:25 DEBUG[30752] channel.c: Bridge stops bridging channels Agent/2033 and SIP/mags-093b79c0 Sep 1 15:50:25 DEBUG[30752] chan_sip.c: update_call_counter(19083515400) - decrement call limit counter Sep 1 15:50:25 DEBUG[30752] app_dial.c: Exiting with DIALSTATUS=ANSWER. Sep 1 15:50:25 DEBUG[30752] channel.c: Spy MixMonitor removed from channel Agent/2033 Sep 1 15:50:25 DEBUG[30752] cdr_pgsql.c: cdr_pgsql: inserting a CDR record. Sep 1 15:50:25 DEBUG[30752] cdr_pgsql.c: cdr_pgsql: SQL command executed: INSERT INTO cdr (calldate,clid,src,dst,dcontext,channel,dstchannel,lastapp,lastdata,duration,billsec,disposition,amaflags,accountcode,uniqueid,userfield) VALUES ('2006-09-01 15:47:38','"->ROBERT DAVIS" <0019083515400>','0019083515400','0019083515400','auto_dial', 'Agent/2033','SIP/mags-093b79c0','Dial','SIP/19083515400@mags',167,159,'ANSWERED',3,'Perot Systems TSI (USA)','1157122058.2464','000/agent-2033-o722374c261208-20060901-154738.729') Sep 1 15:50:25 DEBUG[30752] chan_agent.c: Hangup called for state Up Sep 1 15:50:25 NOTICE[30752] pbx_spool.c: Call completed to AGENT/2033 Sep 1 15:50:25 DEBUG[17596] chan_sip.c: Stopping retransmission on '7849b1395b30537c42742595256a8d51@gk.magrathea.net' of Request 104: Match Found Sep 1 15:50:45 DEBUG[30562] chan_agent.c: Bridge on 'SIP/1021-0934c678' being cleared (2) Sep 1 15:50:45 DEBUG[30562] chan_sip.c: update_call_counter(1021) - decrement call limit counter Sep 1 15:50:45 DEBUG[30562] channel.c: Didn't get a frame from channel: Agent/2076 Sep 1 15:50:45 DEBUG[30562] channel.c: Bridge stops bridging channels Agent/2076 and SIP/mags-b751b5c0 Sep 1 15:50:45 DEBUG[30562] chan_sip.c: update_call_counter(442089695511) - decrement call limit counter Sep 1 15:50:45 DEBUG[30562] app_dial.c: Exiting with DIALSTATUS=ANSWER. Sep 1 15:50:45 DEBUG[30562] channel.c: Spy MixMonitor removed from channel Agent/2076 Sep 1 15:50:45 DEBUG[30562] cdr_pgsql.c: cdr_pgsql: inserting a CDR record. Sep 1 15:50:45 DEBUG[30562] cdr_pgsql.c: cdr_pgsql: SQL command executed: INSERT INTO cdr (calldate,clid,src,dst,dcontext,channel,dstchannel,lastapp,lastdata,duration,billsec,disposition,amaflags,accountcode,uniqueid,userfield) VALUES ('2006-09-01 15:44:04','"->Tara McBride" <02089695511>','02089695511','02089695511','auto_dial', 'Agent/2076','SIP/mags-b751b5c0','Dial','SIP/442089695511@mags',401,387,'ANSWERED',3,'Zensar','1157121843.2404','000/agent-2076-o920596c215705-20060901-154404.729') Sep 1 15:50:45 DEBUG[30562] chan_agent.c: Hangup called for state Up Sep 1 15:50:45 NOTICE[30562] pbx_spool.c: Call completed to AGENT/2076 Sep 1 15:50:45 DEBUG[17596] chan_sip.c: Stopping retransmission on '24afea7d36057c4b598dc8a836fe909d@gk.magrathea.net' of Request 104: Match Found Sep 1 15:50:45 DEBUG[17596] chan_sip.c: Stopping retransmission on '24afea7d36057c4b598dc8a836fe909d@gk.magrathea.net' of Request 105: Match Found Sep 1 15:51:12 DEBUG[17596] acl.c: ##### Testing 213.166.5.135 with 10.1.20.0 Sep 1 15:51:12 DEBUG[17596] acl.c: ##### Testing 213.166.5.135 with 172.28.1.0 Sep 1 15:51:12 DEBUG[17596] chan_sip.c: Target address 213.166.5.135 is not local, substituting externip Sep 1 15:51:12 DEBUG[17596] chan_sip.c: Stopping retransmission on '46b0786b01fe47712499c4185afbc53b@89.105.104.74' of Request 102: Match Found Sep 1 15:51:22 DEBUG[17601] chan_iax2.c: Peer lastms 18, historicms 18, maxms 120 Sep 1 15:51:23 DEBUG[17596] chan_sip.c: Assigning Replace-Call-ID Info b5f527fb-1e4ed5d9-bfd1c530@10.1.20.69 to REPLACE_CALL_ID Sep 1 15:51:23 DEBUG[17596] chan_sip.c: 202 Accepted (supervised) Sep 1 15:51:23 DEBUG[17596] channel.c: Scheduling timer at 0 sample intervals Sep 1 15:51:23 DEBUG[17596] channel.c: Planning to masquerade channel Zap/1-1 into the structure of SIP/1029-093aa288 Sep 1 15:51:23 DEBUG[17596] channel.c: Done planning to masquerade channel Zap/1-1 into the structure of SIP/1029-093aa288 Sep 1 15:51:23 DEBUG[30768] channel.c: Got clone lock for masquerade on 'Zap/1-1' at 0x931e05c Sep 1 15:51:23 DEBUG[30768] chan_sip.c: update_call_counter(1029) - decrement call limit counter Sep 1 15:51:23 DEBUG[30768] channel.c: Putting channel Zap/1-1 in 8/8 formats Sep 1 15:51:23 DEBUG[30768] chan_zap.c: New owner for channel 1 is Zap/1-1 Sep 1 15:51:23 DEBUG[30768] chan_zap.c: Updated conferencing on 1, with 0 conference users Sep 1 15:51:23 DEBUG[30768] chan_zap.c: Updated conferencing on 1, with 0 conference users Sep 1 15:51:23 DEBUG[30768] channel.c: Released clone lock on 'SIP/1029-093aa288' Sep 1 15:51:23 DEBUG[30768] channel.c: Done Masquerading Zap/1-1 (6) Sep 1 15:51:23 DEBUG[30653] channel.c: Didn't get a frame from channel: SIP/1029-093aa288 Sep 1 15:51:23 DEBUG[30653] channel.c: Bridge stops bridging channels SIP/1029-093aa288 and SIP/1029-09323790 Sep 1 15:51:23 DEBUG[30653] chan_sip.c: update_call_counter(1029) - decrement call limit counter Sep 1 15:51:23 DEBUG[30653] app_dial.c: Exiting with DIALSTATUS=ANSWER. Sep 1 15:51:23 DEBUG[17596] chan_sip.c: Stopping retransmission on '0a7bb27003cb8f19576a453d66a31981@10.1.20.3' of Request 103: Match Found Sep 1 15:51:23 DEBUG[17596] chan_sip.c: Stopping retransmission on '0a7bb27003cb8f19576a453d66a31981@10.1.20.3' of Request 104: Match Found Sep 1 15:51:23 DEBUG[17596] chan_sip.c: Stopping retransmission on 'b5f527fb-1e4ed5d9-bfd1c530@10.1.20.69' of Request 102: Match Found Sep 1 15:51:35 DEBUG[17596] acl.c: ##### Testing 10.1.20.71 with 10.1.20.0 Sep 1 15:51:35 DEBUG[17596] acl.c: ##### Testing 10.1.20.71 with 172.28.1.0 Sep 1 15:51:39 DEBUG[17596] acl.c: ##### Testing 10.1.20.67 with 10.1.20.0 Sep 1 15:51:39 DEBUG[17596] acl.c: ##### Testing 10.1.20.67 with 172.28.1.0 Sep 1 15:51:43 DEBUG[17596] acl.c: ##### Testing 10.1.20.62 with 10.1.20.0 Sep 1 15:51:43 DEBUG[17596] acl.c: ##### Testing 10.1.20.62 with 172.28.1.0 Sep 1 15:51:46 DEBUG[17596] acl.c: ##### Testing 10.1.20.68 with 10.1.20.0 Sep 1 15:51:46 DEBUG[17596] acl.c: ##### Testing 10.1.20.68 with 172.28.1.0 Sep 1 15:51:47 DEBUG[17596] acl.c: ##### Testing 10.1.20.55 with 10.1.20.0 Sep 1 15:51:47 DEBUG[17596] acl.c: ##### Testing 10.1.20.55 with 172.28.1.0 Sep 1 15:51:47 DEBUG[17596] acl.c: ##### Testing 10.1.20.58 with 10.1.20.0 Sep 1 15:51:47 DEBUG[17596] acl.c: ##### Testing 10.1.20.58 with 172.28.1.0 Sep 1 15:51:47 DEBUG[17596] acl.c: ##### Testing 10.1.20.53 with 10.1.20.0 Sep 1 15:51:47 DEBUG[17596] acl.c: ##### Testing 10.1.20.53 with 172.28.1.0 Sep 1 15:51:47 DEBUG[17596] acl.c: ##### Testing 10.1.20.57 with 10.1.20.0 Sep 1 15:51:47 DEBUG[17596] acl.c: ##### Testing 10.1.20.57 with 172.28.1.0 Sep 1 15:51:48 DEBUG[17596] acl.c: ##### Testing 10.1.20.51 with 10.1.20.0 Sep 1 15:51:48 DEBUG[17596] acl.c: ##### Testing 10.1.20.51 with 172.28.1.0 Sep 1 15:51:49 DEBUG[17596] acl.c: ##### Testing 10.1.20.70 with 10.1.20.0 Sep 1 15:51:49 DEBUG[17596] acl.c: ##### Testing 10.1.20.70 with 172.28.1.0 Sep 1 15:51:49 DEBUG[17596] acl.c: ##### Testing 10.1.20.50 with 10.1.20.0 Sep 1 15:51:49 DEBUG[17596] acl.c: ##### Testing 10.1.20.50 with 172.28.1.0 Sep 1 15:51:50 DEBUG[17596] chan_sip.c: Auto destroying call '669cd020-7cf3e576-48757c83@10.1.20.71' Sep 1 15:51:51 DEBUG[17596] acl.c: ##### Testing 10.1.20.54 with 10.1.20.0 Sep 1 15:51:51 DEBUG[17596] acl.c: ##### Testing 10.1.20.54 with 172.28.1.0 Sep 1 15:51:51 DEBUG[17596] acl.c: ##### Testing 10.1.20.56 with 10.1.20.0 Sep 1 15:51:51 DEBUG[17596] acl.c: ##### Testing 10.1.20.56 with 172.28.1.0 Sep 1 15:51:53 DEBUG[17596] acl.c: ##### Testing 10.1.20.65 with 10.1.20.0 Sep 1 15:51:53 DEBUG[17596] acl.c: ##### Testing 10.1.20.65 with 172.28.1.0 Sep 1 15:51:54 DEBUG[17596] chan_sip.c: Auto destroying call 'c786b8a4-fdb023e-c51227b7@10.1.20.67' Sep 1 15:51:55 DEBUG[17596] acl.c: ##### Testing 10.1.20.69 with 10.1.20.0 Sep 1 15:51:55 DEBUG[17596] acl.c: ##### Testing 10.1.20.69 with 172.28.1.0 Sep 1 15:51:56 DEBUG[17596] acl.c: ##### Testing 10.1.20.61 with 10.1.20.0 Sep 1 15:51:56 DEBUG[17596] acl.c: ##### Testing 10.1.20.61 with 172.28.1.0 Sep 1 15:51:56 DEBUG[17596] acl.c: ##### Testing 10.1.20.59 with 10.1.20.0 Sep 1 15:51:56 DEBUG[17596] acl.c: ##### Testing 10.1.20.59 with 172.28.1.0 Sep 1 15:51:58 DEBUG[17596] chan_sip.c: Auto destroying call '7ff70378-42423b2e-41eaa59b@10.1.20.62' Sep 1 15:52:01 DEBUG[17596] chan_sip.c: Auto destroying call '2aab3d43-4baebd09-eb7cce0@10.1.20.68' Sep 1 15:52:02 DEBUG[17596] chan_sip.c: Auto destroying call 'bad2318f-3f2669ad-4ddf6ce8@10.1.20.55' Sep 1 15:52:02 DEBUG[17596] chan_sip.c: Auto destroying call '867ad7d9-21e2ac13-114c0e9c@10.1.20.58' Sep 1 15:52:02 DEBUG[17596] chan_sip.c: Auto destroying call 'bad2318f-3f2669ad-4ddf6ce8@10.1.20.53' Sep 1 15:52:03 DEBUG[17596] chan_sip.c: Auto destroying call 'f1cc1761-af70f9df-36157a78@10.1.20.57' Sep 1 15:52:03 DEBUG[17596] acl.c: ##### Testing 10.1.20.60 with 10.1.20.0 Sep 1 15:52:03 DEBUG[17596] acl.c: ##### Testing 10.1.20.60 with 172.28.1.0 Sep 1 15:52:03 DEBUG[17596] chan_sip.c: Auto destroying call '12a7986b-a93697ad-ab4ccf84@10.1.20.51' Sep 1 15:52:03 DEBUG[17596] acl.c: ##### Testing 10.1.20.49 with 10.1.20.0 Sep 1 15:52:03 DEBUG[17596] acl.c: ##### Testing 10.1.20.49 with 172.28.1.0 Sep 1 15:52:04 DEBUG[17596] acl.c: ##### Testing 10.1.20.64 with 10.1.20.0 Sep 1 15:52:04 DEBUG[17596] acl.c: ##### Testing 10.1.20.64 with 172.28.1.0 Sep 1 15:52:04 DEBUG[17596] chan_sip.c: Auto destroying call '9d7fb839-353259ef-81a355c4@10.1.20.70' Sep 1 15:52:04 DEBUG[17596] chan_sip.c: Auto destroying call '9d7fb839-353259ef-81a355c4@10.1.20.50' Sep 1 15:52:05 WARNING[30823] cdr.c: CDR on channel 'Local/1022@local-6893,2' not posted Sep 1 15:52:05 WARNING[30823] cdr.c: CDR on channel 'Local/1022@local-6893,2' lacks end Sep 1 15:52:05 DEBUG[30823] pbx.c: Expression result is '1' Sep 1 15:52:05 DEBUG[30823] chan_sip.c: Setting NAT on RTP to 0 Sep 1 15:52:05 DEBUG[30823] acl.c: ##### Testing 10.1.20.62 with 10.1.20.0 Sep 1 15:52:05 DEBUG[30823] acl.c: ##### Testing 10.1.20.62 with 172.28.1.0 Sep 1 15:52:05 DEBUG[30823] chan_sip.c: Outgoing Call for 1022 Sep 1 15:52:05 DEBUG[17596] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '6e99a96672a8f2f7770fa97818858cdd@10.1.20.3' Request 102: Found Sep 1 15:52:05 DEBUG[17596] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '6e99a96672a8f2f7770fa97818858cdd@10.1.20.3' Request 102: Found Sep 1 15:52:05 DEBUG[17596] chan_sip.c: Acked pending invite 102 Sep 1 15:52:05 DEBUG[17596] chan_sip.c: Stopping retransmission on '6e99a96672a8f2f7770fa97818858cdd@10.1.20.3' of Request 102: Match Found Sep 1 15:52:05 DEBUG[17596] chan_sip.c: build_route: Contact hop: Sep 1 15:52:05 DEBUG[30821] channel.c: Spy MixMonitor added to channel Agent/2057 Sep 1 15:52:05 DEBUG[30821] pbx.c: Expression result is '0' Sep 1 15:52:05 DEBUG[30821] pbx.c: Function result is '1' Sep 1 15:52:05 DEBUG[30821] pbx.c: Expression result is '0' Sep 1 15:52:05 DEBUG[30821] pbx.c: Not taking any branch Sep 1 15:52:05 DEBUG[30821] chan_sip.c: Setting NAT on RTP to 524288 Sep 1 15:52:05 DEBUG[30821] acl.c: ##### Testing 213.166.5.135 with 10.1.20.0 Sep 1 15:52:05 DEBUG[30821] acl.c: ##### Testing 213.166.5.135 with 172.28.1.0 Sep 1 15:52:05 DEBUG[30821] chan_sip.c: Target address 213.166.5.135 is not local, substituting externip Sep 1 15:52:05 DEBUG[30821] chan_sip.c: Outgoing Call for 441707422397 Sep 1 15:52:05 DEBUG[17596] chan_sip.c: Acked pending invite 102 Sep 1 15:52:05 DEBUG[17596] chan_sip.c: Stopping retransmission on '422375eb61dcc2f17bb47902691883f2@gk.magrathea.net' of Request 102: Match Found Sep 1 15:52:05 DEBUG[17596] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '422375eb61dcc2f17bb47902691883f2@gk.magrathea.net' Request 103: Found Sep 1 15:52:06 DEBUG[30823] channel.c: Planning to masquerade channel SIP/1022-09347090 into the structure of Local/1022@local-6893,1 Sep 1 15:52:06 DEBUG[30823] channel.c: Done planning to masquerade channel SIP/1022-09347090 into the structure of Local/1022@local-6893,1 Sep 1 15:52:06 DEBUG[30823] chan_local.c: Not posting to queue since already masked on 'Local/1022@local-6893,2' Sep 1 15:52:06 DEBUG[30821] channel.c: Got clone lock for masquerade on 'SIP/1022-09347090' at 0x9357474 Sep 1 15:52:06 DEBUG[30821] channel.c: Putting channel SIP/1022-09347090 in 64/64 formats Sep 1 15:52:06 DEBUG[30821] channel.c: Released clone lock on 'Local/1022@local-6893,1' Sep 1 15:52:06 DEBUG[30821] channel.c: Done Masquerading SIP/1022-09347090 (6) Sep 1 15:52:06 DEBUG[30823] channel.c: Didn't get a frame from channel: Local/1022@local-6893,2 Sep 1 15:52:06 DEBUG[30821] chan_agent.c: Bridge on 'SIP/1022-09347090' being set to 'Agent/2057' (3) Sep 1 15:52:06 DEBUG[30823] channel.c: Bridge stops bridging channels Local/1022@local-6893,2 and Local/1022@local-6893,1 Sep 1 15:52:06 DEBUG[30821] chan_agent.c: Native formats changing from 64 to 8 Sep 1 15:52:06 DEBUG[30821] chan_agent.c: Resetting read to 64 and write to 64 Sep 1 15:52:06 DEBUG[30823] app_dial.c: Exiting with DIALSTATUS=ANSWER. Sep 1 15:52:06 DEBUG[30821] channel.c: Building translator from alaw to SLINEAR for spies on channel Agent/2057 Sep 1 15:52:06 DEBUG[17596] chan_sip.c: Auto destroying call '33d9ba99-6a288fa3-3fafead8@10.1.20.54' Sep 1 15:52:06 DEBUG[17596] chan_sip.c: Auto destroying call '12a7986b-a93697ad-ab4ccf84@10.1.20.56' Sep 1 15:52:07 DEBUG[17596] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '422375eb61dcc2f17bb47902691883f2@gk.magrathea.net' Request 103: Found Sep 1 15:52:07 DEBUG[30821] channel.c: Building translator from alaw to SLINEAR for spies on channel Agent/2057 Sep 1 15:52:08 DEBUG[17596] chan_sip.c: Auto destroying call '6ae98ad8-a7cbd07a-cb02ba85@10.1.20.65' Sep 1 15:52:10 DEBUG[17596] chan_sip.c: Auto destroying call '924b2e93-2dd898b1-30ebf928@10.1.20.69' Sep 1 15:52:11 DEBUG[17596] chan_sip.c: Auto destroying call '924b2e93-2dd898b1-30ebf928@10.1.20.61' Sep 1 15:52:11 DEBUG[17596] chan_sip.c: Auto destroying call '2806998b-d2da87d5-9dfbf768@10.1.20.59' Sep 1 15:52:12 DEBUG[17596] acl.c: ##### Testing 213.166.5.135 with 10.1.20.0 Sep 1 15:52:12 DEBUG[17596] acl.c: ##### Testing 213.166.5.135 with 172.28.1.0 Sep 1 15:52:12 DEBUG[17596] chan_sip.c: Target address 213.166.5.135 is not local, substituting externip Sep 1 15:52:12 DEBUG[17596] chan_sip.c: Stopping retransmission on '59c00a760a4ab7b767f8422b18333724@89.105.104.74' of Request 102: Match Found Sep 1 15:52:18 DEBUG[17596] chan_sip.c: Auto destroying call '2ed490fe-87a93a80-ed6ab355@10.1.20.60' Sep 1 15:52:18 DEBUG[17596] chan_sip.c: Auto destroying call '7a5a9636-66330659-18c0a398@10.1.20.49' Sep 1 15:52:19 DEBUG[17596] chan_sip.c: Auto destroying call 'f5928c0c-827e1c36-608128f9@10.1.20.64' Sep 1 15:52:20 DEBUG[17596] chan_sip.c: Acked pending invite 103 Sep 1 15:52:20 DEBUG[17596] chan_sip.c: Stopping retransmission on '422375eb61dcc2f17bb47902691883f2@gk.magrathea.net' of Request 103: Match Found Sep 1 15:52:20 DEBUG[17596] chan_sip.c: build_route: Contact hop: Sep 1 15:52:22 DEBUG[17601] chan_iax2.c: Peer lastms 19, historicms 19, maxms 120 Sep 1 15:52:25 DEBUG[17596] acl.c: ##### Testing 10.1.20.63 with 10.1.20.0 Sep 1 15:52:25 DEBUG[17596] acl.c: ##### Testing 10.1.20.63 with 172.28.1.0 Sep 1 15:52:29 WARNING[30836] cdr.c: CDR on channel 'Local/1021@local-8c0a,2' not posted Sep 1 15:52:29 WARNING[30836] cdr.c: CDR on channel 'Local/1021@local-8c0a,2' lacks end Sep 1 15:52:29 DEBUG[30836] pbx.c: Expression result is '1' Sep 1 15:52:29 DEBUG[30836] chan_sip.c: Setting NAT on RTP to 0 Sep 1 15:52:29 DEBUG[30836] acl.c: ##### Testing 10.1.20.61 with 10.1.20.0 Sep 1 15:52:29 DEBUG[30836] acl.c: ##### Testing 10.1.20.61 with 172.28.1.0 Sep 1 15:52:29 DEBUG[30836] chan_sip.c: Outgoing Call for 1021 Sep 1 15:52:29 DEBUG[17596] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '7355c8f078aa81832298fe2f27834016@10.1.20.3' Request 102: Found Sep 1 15:52:29 DEBUG[17596] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '7355c8f078aa81832298fe2f27834016@10.1.20.3' Request 102: Found Sep 1 15:52:29 DEBUG[17596] chan_sip.c: Acked pending invite 102 Sep 1 15:52:29 DEBUG[17596] chan_sip.c: Stopping retransmission on '7355c8f078aa81832298fe2f27834016@10.1.20.3' of Request 102: Match Found Sep 1 15:52:29 DEBUG[17596] chan_sip.c: build_route: Contact hop: Sep 1 15:52:29 DEBUG[30834] channel.c: Spy MixMonitor added to channel Agent/2076 Sep 1 15:52:29 DEBUG[30834] pbx.c: Expression result is '0' Sep 1 15:52:29 DEBUG[30834] pbx.c: Function result is '2' Sep 1 15:52:29 DEBUG[30834] pbx.c: Expression result is '0' Sep 1 15:52:29 DEBUG[30834] pbx.c: Not taking any branch Sep 1 15:52:29 DEBUG[30834] chan_sip.c: Setting NAT on RTP to 524288 Sep 1 15:52:29 DEBUG[30834] acl.c: ##### Testing 213.166.5.135 with 10.1.20.0 Sep 1 15:52:29 DEBUG[30834] acl.c: ##### Testing 213.166.5.135 with 172.28.1.0 Sep 1 15:52:29 DEBUG[30834] chan_sip.c: Target address 213.166.5.135 is not local, substituting externip Sep 1 15:52:29 DEBUG[30834] chan_sip.c: Outgoing Call for 441515237566 Sep 1 15:52:29 DEBUG[17596] chan_sip.c: Acked pending invite 102 Sep 1 15:52:29 DEBUG[17596] chan_sip.c: Stopping retransmission on '6fecb1276295a41e59a54d96722ada74@gk.magrathea.net' of Request 102: Match Found Sep 1 15:52:30 DEBUG[17596] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '6fecb1276295a41e59a54d96722ada74@gk.magrathea.net' Request 103: Found Sep 1 15:52:30 DEBUG[30836] channel.c: Planning to masquerade channel SIP/1021-0934c678 into the structure of Local/1021@local-8c0a,1 Sep 1 15:52:30 DEBUG[30836] channel.c: Done planning to masquerade channel SIP/1021-0934c678 into the structure of Local/1021@local-8c0a,1 Sep 1 15:52:30 DEBUG[30836] chan_local.c: Not posting to queue since already masked on 'Local/1021@local-8c0a,2' Sep 1 15:52:30 DEBUG[30834] channel.c: Got clone lock for masquerade on 'SIP/1021-0934c678' at 0x939e014 Sep 1 15:52:30 DEBUG[30834] channel.c: Putting channel SIP/1021-0934c678 in 64/64 formats Sep 1 15:52:30 DEBUG[30834] channel.c: Released clone lock on 'Local/1021@local-8c0a,1' Sep 1 15:52:30 DEBUG[30834] channel.c: Done Masquerading SIP/1021-0934c678 (6) Sep 1 15:52:30 DEBUG[30836] channel.c: Didn't get a frame from channel: Local/1021@local-8c0a,2 Sep 1 15:52:30 DEBUG[30834] chan_agent.c: Bridge on 'SIP/1021-0934c678' being set to 'Agent/2076' (3) Sep 1 15:52:30 DEBUG[30836] channel.c: Bridge stops bridging channels Local/1021@local-8c0a,2 and Local/1021@local-8c0a,1 Sep 1 15:52:30 DEBUG[30834] chan_agent.c: Native formats changing from 64 to 8 Sep 1 15:52:30 DEBUG[30834] chan_agent.c: Resetting read to 64 and write to 64 Sep 1 15:52:30 DEBUG[30836] app_dial.c: Exiting with DIALSTATUS=ANSWER. Sep 1 15:52:30 DEBUG[30834] channel.c: Building translator from alaw to SLINEAR for spies on channel Agent/2076 Sep 1 15:52:32 DEBUG[17596] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '6fecb1276295a41e59a54d96722ada74@gk.magrathea.net' Request 103: Found Sep 1 15:52:32 DEBUG[30834] channel.c: Building translator from alaw to SLINEAR for spies on channel Agent/2076 Sep 1 15:52:40 DEBUG[17596] chan_sip.c: Auto destroying call '57c1914c-c029e9a-11f9c343@10.1.20.63' Sep 1 15:52:50 DEBUG[17596] acl.c: ##### Testing 10.1.20.66 with 10.1.20.0 Sep 1 15:52:50 DEBUG[17596] acl.c: ##### Testing 10.1.20.66 with 172.28.1.0 Sep 1 15:52:53 DEBUG[30821] chan_agent.c: Bridge on 'SIP/1022-09347090' being cleared (2) Sep 1 15:52:53 DEBUG[30821] chan_sip.c: update_call_counter(1022) - decrement call limit counter Sep 1 15:52:53 DEBUG[30821] channel.c: Didn't get a frame from channel: Agent/2057 Sep 1 15:52:53 DEBUG[30821] channel.c: Bridge stops bridging channels Agent/2057 and SIP/mags-09319be8 Sep 1 15:52:53 DEBUG[30821] chan_sip.c: update_call_counter(441707422397) - decrement call limit counter Sep 1 15:52:53 DEBUG[30821] app_dial.c: Exiting with DIALSTATUS=ANSWER. Sep 1 15:52:53 DEBUG[30821] channel.c: Spy MixMonitor removed from channel Agent/2057 Sep 1 15:52:53 DEBUG[30821] cdr_pgsql.c: cdr_pgsql: inserting a CDR record. Sep 1 15:52:53 DEBUG[30821] cdr_pgsql.c: cdr_pgsql: SQL command executed: INSERT INTO cdr (calldate,clid,src,dst,dcontext,channel,dstchannel,lastapp,lastdata,duration,billsec,disposition,amaflags,accountcode,uniqueid,userfield) VALUES ('2006-09-01 15:52:05','"->Braham Amiri" <01707422397>','01707422397','01707422397','auto_dial', 'Agent/2057','SIP/mags-09319be8','Dial','SIP/441707422397@mags',48,33,'ANSWERED',3,'Strategic Systems Solutions','1157122325.2471','000/agent-2057-o898835c266622-20060901-155205.729') Sep 1 15:52:53 DEBUG[30821] chan_agent.c: Hangup called for state Up Sep 1 15:52:53 NOTICE[30821] pbx_spool.c: Call completed to AGENT/2057 Sep 1 15:52:53 DEBUG[17596] chan_sip.c: Stopping retransmission on '422375eb61dcc2f17bb47902691883f2@gk.magrathea.net' of Request 104: Match Found Sep 1 15:52:54 WARNING[30852] cdr.c: CDR on channel 'Local/1016@local-f40f,2' not posted Sep 1 15:52:54 WARNING[30852] cdr.c: CDR on channel 'Local/1016@local-f40f,2' lacks end Sep 1 15:52:54 DEBUG[30852] pbx.c: Expression result is '1' Sep 1 15:52:54 DEBUG[30852] chan_sip.c: Setting NAT on RTP to 0 Sep 1 15:52:54 DEBUG[30852] acl.c: ##### Testing 10.1.20.56 with 10.1.20.0 Sep 1 15:52:54 DEBUG[30852] acl.c: ##### Testing 10.1.20.56 with 172.28.1.0 Sep 1 15:52:54 DEBUG[30852] chan_sip.c: Outgoing Call for 1016 Sep 1 15:52:54 DEBUG[17596] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '51fff28b1b53f30e01f9d99d40577e5a@10.1.20.3' Request 102: Found Sep 1 15:52:54 DEBUG[17596] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '51fff28b1b53f30e01f9d99d40577e5a@10.1.20.3' Request 102: Found Sep 1 15:52:55 DEBUG[17596] chan_sip.c: Acked pending invite 102 Sep 1 15:52:55 DEBUG[17596] chan_sip.c: Stopping retransmission on '51fff28b1b53f30e01f9d99d40577e5a@10.1.20.3' of Request 102: Match Found Sep 1 15:52:55 DEBUG[17596] chan_sip.c: build_route: Contact hop: Sep 1 15:52:55 DEBUG[30850] channel.c: Spy MixMonitor added to channel Agent/2033 Sep 1 15:52:55 DEBUG[30850] pbx.c: Expression result is '0' Sep 1 15:52:55 DEBUG[30850] pbx.c: Function result is '2' Sep 1 15:52:55 DEBUG[30850] pbx.c: Expression result is '0' Sep 1 15:52:55 DEBUG[30850] pbx.c: Not taking any branch Sep 1 15:52:55 DEBUG[30850] chan_sip.c: Setting NAT on RTP to 524288 Sep 1 15:52:55 DEBUG[30850] acl.c: ##### Testing 213.166.5.135 with 10.1.20.0 Sep 1 15:52:55 DEBUG[30850] acl.c: ##### Testing 213.166.5.135 with 172.28.1.0 Sep 1 15:52:55 DEBUG[30850] chan_sip.c: Target address 213.166.5.135 is not local, substituting externip Sep 1 15:52:55 DEBUG[30850] chan_sip.c: Outgoing Call for 12126793600 Sep 1 15:52:55 DEBUG[17596] chan_sip.c: Acked pending invite 102 Sep 1 15:52:55 DEBUG[17596] chan_sip.c: Stopping retransmission on '226e59580d72abc8614974154cd36db1@gk.magrathea.net' of Request 102: Match Found Sep 1 15:52:55 DEBUG[17596] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '226e59580d72abc8614974154cd36db1@gk.magrathea.net' Request 103: Found Sep 1 15:52:55 DEBUG[30852] channel.c: Planning to masquerade channel SIP/1016-093232d8 into the structure of Local/1016@local-f40f,1 Sep 1 15:52:55 DEBUG[30852] channel.c: Done planning to masquerade channel SIP/1016-093232d8 into the structure of Local/1016@local-f40f,1 Sep 1 15:52:55 DEBUG[30852] chan_local.c: Not posting to queue since already masked on 'Local/1016@local-f40f,2' Sep 1 15:52:55 DEBUG[30850] channel.c: Got clone lock for masquerade on 'SIP/1016-093232d8' at 0x9357474 Sep 1 15:52:55 DEBUG[30850] channel.c: Putting channel SIP/1016-093232d8 in 64/64 formats Sep 1 15:52:55 DEBUG[30850] channel.c: Released clone lock on 'Local/1016@local-f40f,1' Sep 1 15:52:55 DEBUG[30850] channel.c: Done Masquerading SIP/1016-093232d8 (6) Sep 1 15:52:55 DEBUG[30850] chan_agent.c: Bridge on 'SIP/1016-093232d8' being set to 'Agent/2033' (3) Sep 1 15:52:55 DEBUG[30850] chan_agent.c: Native formats changing from 64 to 8 Sep 1 15:52:55 DEBUG[30850] chan_agent.c: Resetting read to 64 and write to 64 Sep 1 15:52:55 DEBUG[30852] channel.c: Didn't get a frame from channel: Local/1016@local-f40f,2 Sep 1 15:52:55 DEBUG[30852] channel.c: Bridge stops bridging channels Local/1016@local-f40f,2 and Local/1016@local-f40f,1 Sep 1 15:52:55 DEBUG[30852] app_dial.c: Exiting with DIALSTATUS=ANSWER. Sep 1 15:52:55 DEBUG[30850] channel.c: Building translator from alaw to SLINEAR for spies on channel Agent/2033 Sep 1 15:52:57 DEBUG[17596] chan_sip.c: Acked pending invite 103 Sep 1 15:52:57 DEBUG[17596] chan_sip.c: Stopping retransmission on '6fecb1276295a41e59a54d96722ada74@gk.magrathea.net' of Request 103: Match Found Sep 1 15:52:57 DEBUG[17596] chan_sip.c: build_route: Contact hop: Sep 1 15:52:59 DEBUG[17596] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '226e59580d72abc8614974154cd36db1@gk.magrathea.net' Request 103: Found Sep 1 15:52:59 DEBUG[30850] channel.c: Building translator from alaw to SLINEAR for spies on channel Agent/2033 Sep 1 15:53:00 DEBUG[17596] chan_sip.c: Acked pending invite 103 Sep 1 15:53:00 DEBUG[17596] chan_sip.c: Stopping retransmission on '226e59580d72abc8614974154cd36db1@gk.magrathea.net' of Request 103: Match Found Sep 1 15:53:00 DEBUG[17596] chan_sip.c: build_route: Record-Route hop: Sep 1 15:53:03 WARNING[30865] cdr.c: CDR on channel 'Local/1023@local-204a,2' not posted Sep 1 15:53:03 WARNING[30865] cdr.c: CDR on channel 'Local/1023@local-204a,2' lacks end Sep 1 15:53:03 DEBUG[30865] pbx.c: Expression result is '1' Sep 1 15:53:03 DEBUG[30865] chan_sip.c: Setting NAT on RTP to 0 Sep 1 15:53:03 DEBUG[30865] acl.c: ##### Testing 10.1.20.63 with 10.1.20.0 Sep 1 15:53:03 DEBUG[30865] acl.c: ##### Testing 10.1.20.63 with 172.28.1.0 Sep 1 15:53:03 DEBUG[30865] chan_sip.c: Outgoing Call for 1023 Sep 1 15:53:03 DEBUG[17596] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '763b9f425a7c4be13101ded96c8debe6@10.1.20.3' Request 102: Found Sep 1 15:53:03 DEBUG[17596] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '763b9f425a7c4be13101ded96c8debe6@10.1.20.3' Request 102: Found Sep 1 15:53:04 DEBUG[17596] chan_sip.c: Acked pending invite 102 Sep 1 15:53:04 DEBUG[17596] chan_sip.c: Stopping retransmission on '763b9f425a7c4be13101ded96c8debe6@10.1.20.3' of Request 102: Match Found Sep 1 15:53:04 DEBUG[17596] chan_sip.c: build_route: Contact hop: Sep 1 15:53:04 DEBUG[30863] channel.c: Spy MixMonitor added to channel Agent/2071 Sep 1 15:53:04 DEBUG[30863] pbx.c: Expression result is '0' Sep 1 15:53:04 DEBUG[30863] pbx.c: Function result is '3' Sep 1 15:53:04 DEBUG[30863] pbx.c: Expression result is '0' Sep 1 15:53:04 DEBUG[30863] pbx.c: Not taking any branch Sep 1 15:53:04 DEBUG[30863] chan_sip.c: Setting NAT on RTP to 524288 Sep 1 15:53:04 DEBUG[30863] acl.c: ##### Testing 213.166.5.135 with 10.1.20.0 Sep 1 15:53:04 DEBUG[30863] acl.c: ##### Testing 213.166.5.135 with 172.28.1.0 Sep 1 15:53:04 DEBUG[30863] chan_sip.c: Target address 213.166.5.135 is not local, substituting externip Sep 1 15:53:04 DEBUG[30863] chan_sip.c: Outgoing Call for 12122374000 Sep 1 15:53:04 DEBUG[17596] chan_sip.c: Acked pending invite 102 Sep 1 15:53:04 DEBUG[17596] chan_sip.c: Stopping retransmission on '437e04b009d5b2504e19de9f399dd2ae@gk.magrathea.net' of Request 102: Match Found Sep 1 15:53:04 DEBUG[17596] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '437e04b009d5b2504e19de9f399dd2ae@gk.magrathea.net' Request 103: Found Sep 1 15:53:04 DEBUG[30865] channel.c: Planning to masquerade channel SIP/1023-09347090 into the structure of Local/1023@local-204a,1 Sep 1 15:53:04 DEBUG[30865] channel.c: Done planning to masquerade channel SIP/1023-09347090 into the structure of Local/1023@local-204a,1 Sep 1 15:53:04 DEBUG[30865] chan_local.c: Not posting to queue since already masked on 'Local/1023@local-204a,2' Sep 1 15:53:04 DEBUG[30863] channel.c: Got clone lock for masquerade on 'SIP/1023-09347090' at 0x9349db4 Sep 1 15:53:04 DEBUG[30863] channel.c: Putting channel SIP/1023-09347090 in 64/64 formats Sep 1 15:53:04 DEBUG[30863] channel.c: Released clone lock on 'Local/1023@local-204a,1' Sep 1 15:53:04 DEBUG[30863] channel.c: Done Masquerading SIP/1023-09347090 (6) Sep 1 15:53:04 DEBUG[30865] channel.c: Didn't get a frame from channel: Local/1023@local-204a,2 Sep 1 15:53:04 DEBUG[30863] chan_agent.c: Bridge on 'SIP/1023-09347090' being set to 'Agent/2071' (3) Sep 1 15:53:04 DEBUG[30865] channel.c: Bridge stops bridging channels Local/1023@local-204a,2 and Local/1023@local-204a,1 Sep 1 15:53:04 DEBUG[30863] chan_agent.c: Native formats changing from 64 to 8 Sep 1 15:53:04 DEBUG[30863] chan_agent.c: Resetting read to 64 and write to 64 Sep 1 15:53:04 DEBUG[30865] app_dial.c: Exiting with DIALSTATUS=ANSWER. Sep 1 15:53:04 DEBUG[30863] channel.c: Building translator from alaw to SLINEAR for spies on channel Agent/2071 Sep 1 15:53:05 DEBUG[17596] chan_sip.c: Auto destroying call 'bbf5e670-de56a7b6-dfc86ead@10.1.20.66' Sep 1 15:53:06 DEBUG[17596] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '437e04b009d5b2504e19de9f399dd2ae@gk.magrathea.net' Request 103: Found Sep 1 15:53:06 DEBUG[30863] channel.c: Building translator from alaw to SLINEAR for spies on channel Agent/2071 Sep 1 15:53:09 DEBUG[17596] chan_sip.c: Acked pending invite 103 Sep 1 15:53:09 DEBUG[17596] chan_sip.c: Stopping retransmission on '437e04b009d5b2504e19de9f399dd2ae@gk.magrathea.net' of Request 103: Match Found Sep 1 15:53:09 DEBUG[17596] chan_sip.c: build_route: Record-Route hop: Sep 1 15:53:12 DEBUG[17596] acl.c: ##### Testing 213.166.5.135 with 10.1.20.0 Sep 1 15:53:12 DEBUG[17596] acl.c: ##### Testing 213.166.5.135 with 172.28.1.0 Sep 1 15:53:12 DEBUG[17596] chan_sip.c: Target address 213.166.5.135 is not local, substituting externip Sep 1 15:53:12 DEBUG[17596] chan_sip.c: Stopping retransmission on '5c08942b1c6012853a3e14326c002ab3@89.105.104.74' of Request 102: Match Found Sep 1 15:53:22 DEBUG[17601] chan_iax2.c: Peer lastms 19, historicms 19, maxms 120 Sep 1 15:53:44 WARNING[30877] cdr.c: CDR on channel 'Local/1029@local-2458,2' not posted Sep 1 15:53:44 WARNING[30877] cdr.c: CDR on channel 'Local/1029@local-2458,2' lacks end Sep 1 15:53:44 DEBUG[30877] pbx.c: Expression result is '1' Sep 1 15:53:44 DEBUG[30877] chan_sip.c: Setting NAT on RTP to 0 Sep 1 15:53:44 DEBUG[30877] acl.c: ##### Testing 10.1.20.69 with 10.1.20.0 Sep 1 15:53:44 DEBUG[30877] acl.c: ##### Testing 10.1.20.69 with 172.28.1.0 Sep 1 15:53:44 DEBUG[30877] chan_sip.c: Outgoing Call for 1029 Sep 1 15:53:44 DEBUG[17596] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '5a4ea64e2722140035debe63688ac115@10.1.20.3' Request 102: Found Sep 1 15:53:44 DEBUG[17596] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '5a4ea64e2722140035debe63688ac115@10.1.20.3' Request 102: Found Sep 1 15:53:45 DEBUG[17596] chan_sip.c: Acked pending invite 102 Sep 1 15:53:45 DEBUG[17596] chan_sip.c: Stopping retransmission on '5a4ea64e2722140035debe63688ac115@10.1.20.3' of Request 102: Match Found Sep 1 15:53:45 DEBUG[17596] chan_sip.c: build_route: Contact hop: Sep 1 15:53:45 DEBUG[30875] channel.c: Spy MixMonitor added to channel Agent/2030 Sep 1 15:53:45 DEBUG[30875] pbx.c: Expression result is '0' Sep 1 15:53:45 DEBUG[30875] pbx.c: Function result is '4' Sep 1 15:53:45 DEBUG[30875] pbx.c: Expression result is '0' Sep 1 15:53:45 DEBUG[30875] pbx.c: Not taking any branch Sep 1 15:53:45 DEBUG[30875] chan_sip.c: Setting NAT on RTP to 524288 Sep 1 15:53:45 DEBUG[30875] acl.c: ##### Testing 213.166.5.135 with 10.1.20.0 Sep 1 15:53:45 DEBUG[30875] acl.c: ##### Testing 213.166.5.135 with 172.28.1.0 Sep 1 15:53:45 DEBUG[30875] chan_sip.c: Target address 213.166.5.135 is not local, substituting externip Sep 1 15:53:45 DEBUG[30875] chan_sip.c: Outgoing Call for 448702416181 Sep 1 15:53:45 DEBUG[17596] chan_sip.c: Acked pending invite 102 Sep 1 15:53:45 DEBUG[17596] chan_sip.c: Stopping retransmission on '0cd74fbf3bd641722dffc04c243b5f8e@gk.magrathea.net' of Request 102: Match Found Sep 1 15:53:45 DEBUG[17596] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '0cd74fbf3bd641722dffc04c243b5f8e@gk.magrathea.net' Request 103: Found Sep 1 15:53:45 DEBUG[30877] channel.c: Planning to masquerade channel SIP/1029-09350e68 into the structure of Local/1029@local-2458,1 Sep 1 15:53:45 DEBUG[30877] channel.c: Done planning to masquerade channel SIP/1029-09350e68 into the structure of Local/1029@local-2458,1 Sep 1 15:53:45 DEBUG[30877] chan_local.c: Not posting to queue since already masked on 'Local/1029@local-2458,2' Sep 1 15:53:45 DEBUG[30875] channel.c: Got clone lock for masquerade on 'SIP/1029-09350e68' at 0x934a4dc Sep 1 15:53:45 DEBUG[30875] channel.c: Putting channel SIP/1029-09350e68 in 64/64 formats Sep 1 15:53:45 DEBUG[30875] channel.c: Released clone lock on 'Local/1029@local-2458,1' Sep 1 15:53:45 DEBUG[30875] channel.c: Done Masquerading SIP/1029-09350e68 (6) Sep 1 15:53:45 DEBUG[30875] chan_agent.c: Bridge on 'SIP/1029-09350e68' being set to 'Agent/2030' (3) Sep 1 15:53:45 DEBUG[30877] channel.c: Didn't get a frame from channel: Local/1029@local-2458,1 Sep 1 15:53:45 DEBUG[30875] chan_agent.c: Native formats changing from 64 to 8 Sep 1 15:53:45 DEBUG[30875] chan_agent.c: Resetting read to 64 and write to 64 Sep 1 15:53:45 DEBUG[30877] channel.c: Bridge stops bridging channels Local/1029@local-2458,2 and Local/1029@local-2458,1 Sep 1 15:53:45 DEBUG[30877] app_dial.c: Exiting with DIALSTATUS=ANSWER. Sep 1 15:53:45 DEBUG[30875] channel.c: Building translator from alaw to SLINEAR for spies on channel Agent/2030 Sep 1 15:53:47 DEBUG[17596] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '0cd74fbf3bd641722dffc04c243b5f8e@gk.magrathea.net' Request 103: Found Sep 1 15:53:47 DEBUG[30875] channel.c: Building translator from alaw to SLINEAR for spies on channel Agent/2030 Sep 1 15:53:48 DEBUG[17596] chan_sip.c: Acked pending invite 103 Sep 1 15:53:48 DEBUG[17596] chan_sip.c: Stopping retransmission on '0cd74fbf3bd641722dffc04c243b5f8e@gk.magrathea.net' of Request 103: Match Found Sep 1 15:53:48 DEBUG[17596] chan_sip.c: build_route: Record-Route hop: Sep 1 15:54:02 WARNING[30889] cdr.c: CDR on channel 'Local/1024@local-5792,2' not posted Sep 1 15:54:02 WARNING[30889] cdr.c: CDR on channel 'Local/1024@local-5792,2' lacks end Sep 1 15:54:02 DEBUG[30889] pbx.c: Expression result is '1' Sep 1 15:54:02 DEBUG[30889] chan_sip.c: Setting NAT on RTP to 0 Sep 1 15:54:02 DEBUG[30889] acl.c: ##### Testing 10.1.20.64 with 10.1.20.0 Sep 1 15:54:02 DEBUG[30889] acl.c: ##### Testing 10.1.20.64 with 172.28.1.0 Sep 1 15:54:02 DEBUG[30889] chan_sip.c: Outgoing Call for 1024 Sep 1 15:54:02 DEBUG[17596] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '40ec70120f064eb248a421604be59dc7@10.1.20.3' Request 102: Found Sep 1 15:54:03 DEBUG[17596] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '40ec70120f064eb248a421604be59dc7@10.1.20.3' Request 102: Found Sep 1 15:54:03 DEBUG[17596] chan_sip.c: Acked pending invite 102 Sep 1 15:54:03 DEBUG[17596] chan_sip.c: Stopping retransmission on '40ec70120f064eb248a421604be59dc7@10.1.20.3' of Request 102: Match Found Sep 1 15:54:03 DEBUG[17596] chan_sip.c: build_route: Contact hop: Sep 1 15:54:03 DEBUG[30887] channel.c: Spy MixMonitor added to channel Agent/2074 Sep 1 15:54:03 DEBUG[30887] pbx.c: Expression result is '0' Sep 1 15:54:03 DEBUG[30887] pbx.c: Function result is '5' Sep 1 15:54:03 DEBUG[30887] pbx.c: Expression result is '0' Sep 1 15:54:03 DEBUG[30887] pbx.c: Not taking any branch Sep 1 15:54:03 DEBUG[30887] chan_sip.c: Setting NAT on RTP to 524288 Sep 1 15:54:03 DEBUG[30887] acl.c: ##### Testing 213.166.5.135 with 10.1.20.0 Sep 1 15:54:03 DEBUG[30887] acl.c: ##### Testing 213.166.5.135 with 172.28.1.0 Sep 1 15:54:03 DEBUG[30887] chan_sip.c: Target address 213.166.5.135 is not local, substituting externip Sep 1 15:54:03 DEBUG[30887] chan_sip.c: Outgoing Call for 442086009700 Sep 1 15:54:03 DEBUG[17596] chan_sip.c: Acked pending invite 102 Sep 1 15:54:03 DEBUG[17596] chan_sip.c: Stopping retransmission on '2b977c8565d590b851d5bb6b49580716@gk.magrathea.net' of Request 102: Match Found Sep 1 15:54:03 DEBUG[17596] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '2b977c8565d590b851d5bb6b49580716@gk.magrathea.net' Request 103: Found Sep 1 15:54:03 DEBUG[30889] channel.c: Planning to masquerade channel SIP/1024-093d9c78 into the structure of Local/1024@local-5792,1 Sep 1 15:54:03 DEBUG[30889] channel.c: Done planning to masquerade channel SIP/1024-093d9c78 into the structure of Local/1024@local-5792,1 Sep 1 15:54:03 DEBUG[30889] chan_local.c: Not posting to queue since already masked on 'Local/1024@local-5792,2' Sep 1 15:54:03 DEBUG[30887] channel.c: Got clone lock for masquerade on 'SIP/1024-093d9c78' at 0x93dc99c Sep 1 15:54:03 DEBUG[30887] channel.c: Putting channel SIP/1024-093d9c78 in 64/64 formats Sep 1 15:54:03 DEBUG[30887] channel.c: Released clone lock on 'Local/1024@local-5792,1' Sep 1 15:54:03 DEBUG[30887] channel.c: Done Masquerading SIP/1024-093d9c78 (6) Sep 1 15:54:03 DEBUG[30887] chan_agent.c: Bridge on 'SIP/1024-093d9c78' being set to 'Agent/2074' (3) Sep 1 15:54:03 DEBUG[30889] channel.c: Didn't get a frame from channel: Local/1024@local-5792,2 Sep 1 15:54:03 DEBUG[30887] chan_agent.c: Native formats changing from 64 to 8 Sep 1 15:54:03 DEBUG[30887] chan_agent.c: Resetting read to 64 and write to 64 Sep 1 15:54:03 DEBUG[30889] channel.c: Bridge stops bridging channels Local/1024@local-5792,2 and Local/1024@local-5792,1 Sep 1 15:54:03 DEBUG[30889] app_dial.c: Exiting with DIALSTATUS=ANSWER. Sep 1 15:54:03 DEBUG[30887] channel.c: Building translator from alaw to SLINEAR for spies on channel Agent/2074 Sep 1 15:54:03 DEBUG[30834] chan_agent.c: Bridge on 'SIP/1021-0934c678' being cleared (2) Sep 1 15:54:03 DEBUG[30834] chan_sip.c: update_call_counter(1021) - decrement call limit counter Sep 1 15:54:03 DEBUG[30834] channel.c: Didn't get a frame from channel: Agent/2076 Sep 1 15:54:03 DEBUG[30834] channel.c: Bridge stops bridging channels Agent/2076 and SIP/mags-0939a990 Sep 1 15:54:03 DEBUG[30834] chan_sip.c: update_call_counter(441515237566) - decrement call limit counter Sep 1 15:54:03 DEBUG[30834] app_dial.c: Exiting with DIALSTATUS=ANSWER. Sep 1 15:54:03 DEBUG[30834] channel.c: Spy MixMonitor removed from channel Agent/2076 Sep 1 15:54:03 DEBUG[30834] cdr_pgsql.c: cdr_pgsql: inserting a CDR record. Sep 1 15:54:03 DEBUG[30834] cdr_pgsql.c: cdr_pgsql: SQL command executed: INSERT INTO cdr (calldate,clid,src,dst,dcontext,channel,dstchannel,lastapp,lastdata,duration,billsec,disposition,amaflags,accountcode,uniqueid,userfield) VALUES ('2006-09-01 15:52:29','"->Rob Jones" <01515237566>','01515237566','01515237566','auto_dial', 'Agent/2076','SIP/mags-0939a990','Dial','SIP/441515237566@mags',94,66,'ANSWERED',3,'Zensar','1157122349.2476','000/agent-2076-o919443c215422-20060901-155229.729') Sep 1 15:54:03 DEBUG[30834] chan_agent.c: Hangup called for state Up Sep 1 15:54:03 NOTICE[30834] pbx_spool.c: Call completed to AGENT/2076 Sep 1 15:54:03 DEBUG[17596] chan_sip.c: Stopping retransmission on '6fecb1276295a41e59a54d96722ada74@gk.magrathea.net' of Request 104: Match Found Sep 1 15:54:07 DEBUG[17596] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '2b977c8565d590b851d5bb6b49580716@gk.magrathea.net' Request 103: Found Sep 1 15:54:08 DEBUG[30887] channel.c: Building translator from alaw to SLINEAR for spies on channel Agent/2074 Sep 1 15:54:12 DEBUG[30850] channel.c: Didn't get a frame from channel: SIP/mags-0932df08 Sep 1 15:54:12 DEBUG[30850] channel.c: Bridge stops bridging channels Agent/2033 and SIP/mags-0932df08 Sep 1 15:54:12 DEBUG[30850] chan_sip.c: update_call_counter(12126793600) - decrement call limit counter Sep 1 15:54:12 DEBUG[30850] app_dial.c: Exiting with DIALSTATUS=ANSWER. Sep 1 15:54:12 DEBUG[30850] channel.c: Spy MixMonitor removed from channel Agent/2033 Sep 1 15:54:12 DEBUG[30850] cdr_pgsql.c: cdr_pgsql: inserting a CDR record. Sep 1 15:54:12 DEBUG[30850] cdr_pgsql.c: cdr_pgsql: SQL command executed: INSERT INTO cdr (calldate,clid,src,dst,dcontext,channel,dstchannel,lastapp,lastdata,duration,billsec,disposition,amaflags,accountcode,uniqueid,userfield) VALUES ('2006-09-01 15:52:55','"->LEONA HELMSLEY" <0012126793600>','0012126793600','0012126793600','auto_dial', 'Agent/2033','SIP/mags-0932df08','Dial','SIP/12126793600@mags',77,72,'ANSWERED',3,'Perot Systems TSI (USA)','1157122374.2481','000/agent-2033-o722378c261212-20060901-155255.729') Sep 1 15:54:12 DEBUG[30850] chan_agent.c: Hangup called for state Up Sep 1 15:54:12 DEBUG[30850] chan_sip.c: update_call_counter(1016) - decrement call limit counter Sep 1 15:54:12 DEBUG[30850] chan_agent.c: Hungup, howlong is 0, autologoff is 0 Sep 1 15:54:12 NOTICE[30850] pbx_spool.c: Call completed to AGENT/2033 Sep 1 15:54:12 DEBUG[17596] acl.c: ##### Testing 213.166.5.135 with 10.1.20.0 Sep 1 15:54:12 DEBUG[17596] acl.c: ##### Testing 213.166.5.135 with 172.28.1.0 Sep 1 15:54:12 DEBUG[17596] chan_sip.c: Target address 213.166.5.135 is not local, substituting externip Sep 1 15:54:12 DEBUG[17596] chan_sip.c: Stopping retransmission on '51fff28b1b53f30e01f9d99d40577e5a@10.1.20.3' of Request 103: Match Found Sep 1 15:54:12 DEBUG[17596] chan_sip.c: Stopping retransmission on '1a1a09f87b60b1401e2bf8fc35d54043@89.105.104.74' of Request 102: Match Found Sep 1 15:54:16 DEBUG[17596] chan_sip.c: Acked pending invite 103 Sep 1 15:54:16 DEBUG[17596] chan_sip.c: Stopping retransmission on '2b977c8565d590b851d5bb6b49580716@gk.magrathea.net' of Request 103: Match Found Sep 1 15:54:16 DEBUG[17596] chan_sip.c: build_route: Contact hop: Sep 1 15:54:22 DEBUG[17601] chan_iax2.c: Peer lastms 20, historicms 20, maxms 120 Sep 1 15:54:39 DEBUG[30887] chan_agent.c: Bridge on 'SIP/1024-093d9c78' being cleared (2) Sep 1 15:54:39 DEBUG[30887] chan_sip.c: update_call_counter(1024) - decrement call limit counter Sep 1 15:54:39 DEBUG[30887] channel.c: Didn't get a frame from channel: Agent/2074 Sep 1 15:54:39 DEBUG[30887] channel.c: Bridge stops bridging channels Agent/2074 and SIP/mags-0936ae30 Sep 1 15:54:39 DEBUG[30887] chan_sip.c: update_call_counter(442086009700) - decrement call limit counter Sep 1 15:54:39 DEBUG[30887] app_dial.c: Exiting with DIALSTATUS=ANSWER. Sep 1 15:54:39 DEBUG[30887] channel.c: Spy MixMonitor removed from channel Agent/2074 Sep 1 15:54:39 DEBUG[30887] cdr_pgsql.c: cdr_pgsql: inserting a CDR record. Sep 1 15:54:39 DEBUG[30887] cdr_pgsql.c: cdr_pgsql: SQL command executed: INSERT INTO cdr (calldate,clid,src,dst,dcontext,channel,dstchannel,lastapp,lastdata,duration,billsec,disposition,amaflags,accountcode,uniqueid,userfield) VALUES ('2006-09-01 15:54:03','"->Christopher J Manson" <02086009700>','02086009700','02086009700','auto_dial', 'Agent/2074','SIP/mags-0936ae30','Dial','SIP/442086009700@mags',36,23,'ANSWERED',3,'Blue Martini','1157122442.2496','000/agent-2074-o90007328c263829-20060901-155403.729') Sep 1 15:54:39 DEBUG[30887] chan_agent.c: Hangup called for state Up Sep 1 15:54:39 NOTICE[30887] pbx_spool.c: Call completed to AGENT/2074 Sep 1 15:54:39 DEBUG[17596] chan_sip.c: Stopping retransmission on '2b977c8565d590b851d5bb6b49580716@gk.magrathea.net' of Request 104: Match Found Sep 1 15:55:00 WARNING[30913] cdr.c: CDR on channel 'Local/1027@local-e009,2' not posted Sep 1 15:55:00 WARNING[30913] cdr.c: CDR on channel 'Local/1027@local-e009,2' lacks end Sep 1 15:55:00 DEBUG[30913] pbx.c: Expression result is '1' Sep 1 15:55:00 DEBUG[30913] chan_sip.c: Setting NAT on RTP to 0 Sep 1 15:55:00 DEBUG[30913] acl.c: ##### Testing 10.1.20.67 with 10.1.20.0 Sep 1 15:55:00 DEBUG[30913] acl.c: ##### Testing 10.1.20.67 with 172.28.1.0 Sep 1 15:55:00 DEBUG[30913] chan_sip.c: Outgoing Call for 1027 Sep 1 15:55:01 DEBUG[17596] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '0ffd10421a257a19021b88be2a74e050@10.1.20.3' Request 102: Found Sep 1 15:55:01 DEBUG[17596] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '0ffd10421a257a19021b88be2a74e050@10.1.20.3' Request 102: Found Sep 1 15:55:01 DEBUG[17596] chan_sip.c: Acked pending invite 102 Sep 1 15:55:01 DEBUG[17596] chan_sip.c: Stopping retransmission on '0ffd10421a257a19021b88be2a74e050@10.1.20.3' of Request 102: Match Found Sep 1 15:55:01 DEBUG[17596] chan_sip.c: build_route: Contact hop: Sep 1 15:55:01 DEBUG[30911] channel.c: Spy MixMonitor added to channel Agent/2069 Sep 1 15:55:01 DEBUG[30911] pbx.c: Expression result is '0' Sep 1 15:55:01 DEBUG[30911] pbx.c: Function result is '3' Sep 1 15:55:01 DEBUG[30911] pbx.c: Expression result is '0' Sep 1 15:55:01 DEBUG[30911] pbx.c: Not taking any branch Sep 1 15:55:01 DEBUG[30911] chan_sip.c: Setting NAT on RTP to 524288 Sep 1 15:55:01 DEBUG[30911] acl.c: ##### Testing 213.166.5.135 with 10.1.20.0 Sep 1 15:55:01 DEBUG[30911] acl.c: ##### Testing 213.166.5.135 with 172.28.1.0 Sep 1 15:55:01 DEBUG[30911] chan_sip.c: Target address 213.166.5.135 is not local, substituting externip Sep 1 15:55:01 DEBUG[30911] chan_sip.c: Outgoing Call for 441592778330 Sep 1 15:55:01 DEBUG[17596] chan_sip.c: Acked pending invite 102 Sep 1 15:55:01 DEBUG[17596] chan_sip.c: Stopping retransmission on '59673017254ccddf003b07b157d5c024@gk.magrathea.net' of Request 102: Match Found Sep 1 15:55:01 DEBUG[17596] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '59673017254ccddf003b07b157d5c024@gk.magrathea.net' Request 103: Found Sep 1 15:55:01 DEBUG[30913] channel.c: Planning to masquerade channel SIP/1027-0934c678 into the structure of Local/1027@local-e009,1 Sep 1 15:55:01 DEBUG[30913] channel.c: Done planning to masquerade channel SIP/1027-0934c678 into the structure of Local/1027@local-e009,1 Sep 1 15:55:01 DEBUG[30913] chan_local.c: Not posting to queue since already masked on 'Local/1027@local-e009,2' Sep 1 15:55:01 DEBUG[30911] channel.c: Got clone lock for masquerade on 'SIP/1027-0934c678' at 0x9326efc Sep 1 15:55:01 DEBUG[30911] channel.c: Putting channel SIP/1027-0934c678 in 64/64 formats Sep 1 15:55:01 DEBUG[30911] channel.c: Released clone lock on 'Local/1027@local-e009,1' Sep 1 15:55:01 DEBUG[30911] channel.c: Done Masquerading SIP/1027-0934c678 (6) Sep 1 15:55:01 DEBUG[30913] channel.c: Didn't get a frame from channel: Local/1027@local-e009,2 Sep 1 15:55:01 DEBUG[30911] chan_agent.c: Bridge on 'SIP/1027-0934c678' being set to 'Agent/2069' (3) Sep 1 15:55:01 DEBUG[30913] channel.c: Bridge stops bridging channels Local/1027@local-e009,2 and Local/1027@local-e009,1 Sep 1 15:55:01 DEBUG[30911] chan_agent.c: Native formats changing from 64 to 8 Sep 1 15:55:01 DEBUG[30913] app_dial.c: Exiting with DIALSTATUS=ANSWER. Sep 1 15:55:01 DEBUG[30911] chan_agent.c: Resetting read to 64 and write to 64 Sep 1 15:55:01 DEBUG[30911] channel.c: Building translator from alaw to SLINEAR for spies on channel Agent/2069 Sep 1 15:55:02 WARNING[30924] cdr.c: CDR on channel 'Local/1026@local-c73d,2' not posted Sep 1 15:55:02 WARNING[30924] cdr.c: CDR on channel 'Local/1026@local-c73d,2' lacks end Sep 1 15:55:02 DEBUG[30924] pbx.c: Expression result is '1' Sep 1 15:55:02 DEBUG[30924] chan_sip.c: Setting NAT on RTP to 0 Sep 1 15:55:02 DEBUG[30924] acl.c: ##### Testing 10.1.20.66 with 10.1.20.0 Sep 1 15:55:02 DEBUG[30924] acl.c: ##### Testing 10.1.20.66 with 172.28.1.0 Sep 1 15:55:02 DEBUG[30924] chan_sip.c: Outgoing Call for 1026 Sep 1 15:55:03 DEBUG[17596] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '5119dbf153e1d7c20250bb060b09a0a0@10.1.20.3' Request 102: Found Sep 1 15:55:03 DEBUG[17596] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '5119dbf153e1d7c20250bb060b09a0a0@10.1.20.3' Request 102: Found Sep 1 15:55:03 DEBUG[17596] chan_sip.c: Acked pending invite 102 Sep 1 15:55:03 DEBUG[17596] chan_sip.c: Stopping retransmission on '5119dbf153e1d7c20250bb060b09a0a0@10.1.20.3' of Request 102: Match Found Sep 1 15:55:03 DEBUG[17596] chan_sip.c: build_route: Contact hop: Sep 1 15:55:03 DEBUG[30922] channel.c: Spy MixMonitor added to channel Agent/2073 Sep 1 15:55:03 DEBUG[30922] pbx.c: Expression result is '0' Sep 1 15:55:03 DEBUG[30922] pbx.c: Function result is '4' Sep 1 15:55:03 DEBUG[30922] pbx.c: Expression result is '0' Sep 1 15:55:03 DEBUG[30922] pbx.c: Not taking any branch Sep 1 15:55:03 DEBUG[30922] chan_sip.c: Setting NAT on RTP to 524288 Sep 1 15:55:03 DEBUG[30922] acl.c: ##### Testing 213.166.5.135 with 10.1.20.0 Sep 1 15:55:03 DEBUG[30922] acl.c: ##### Testing 213.166.5.135 with 172.28.1.0 Sep 1 15:55:03 DEBUG[30922] chan_sip.c: Target address 213.166.5.135 is not local, substituting externip Sep 1 15:55:03 DEBUG[30922] chan_sip.c: Outgoing Call for 441418838629 Sep 1 15:55:03 DEBUG[17596] chan_sip.c: Acked pending invite 102 Sep 1 15:55:03 DEBUG[17596] chan_sip.c: Stopping retransmission on '320dd9c06469b8a46b7f5674182c54fd@gk.magrathea.net' of Request 102: Match Found Sep 1 15:55:03 DEBUG[17596] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '320dd9c06469b8a46b7f5674182c54fd@gk.magrathea.net' Request 103: Found Sep 1 15:55:03 DEBUG[30924] channel.c: Planning to masquerade channel SIP/1026-093d9c78 into the structure of Local/1026@local-c73d,1 Sep 1 15:55:03 DEBUG[30924] channel.c: Done planning to masquerade channel SIP/1026-093d9c78 into the structure of Local/1026@local-c73d,1 Sep 1 15:55:03 DEBUG[30924] chan_local.c: Not posting to queue since already masked on 'Local/1026@local-c73d,2' Sep 1 15:55:03 DEBUG[30922] channel.c: Got clone lock for masquerade on 'SIP/1026-093d9c78' at 0x93bd47c Sep 1 15:55:03 DEBUG[30922] channel.c: Putting channel SIP/1026-093d9c78 in 64/64 formats Sep 1 15:55:03 DEBUG[30922] channel.c: Released clone lock on 'Local/1026@local-c73d,1' Sep 1 15:55:03 DEBUG[30922] channel.c: Done Masquerading SIP/1026-093d9c78 (6) Sep 1 15:55:03 DEBUG[30924] channel.c: Didn't get a frame from channel: Local/1026@local-c73d,2 Sep 1 15:55:03 DEBUG[30922] chan_agent.c: Bridge on 'SIP/1026-093d9c78' being set to 'Agent/2073' (3) Sep 1 15:55:03 DEBUG[30924] channel.c: Bridge stops bridging channels Local/1026@local-c73d,2 and Local/1026@local-c73d,1 Sep 1 15:55:03 DEBUG[30924] app_dial.c: Exiting with DIALSTATUS=ANSWER. Sep 1 15:55:03 DEBUG[30922] chan_agent.c: Native formats changing from 64 to 8 Sep 1 15:55:03 DEBUG[30922] chan_agent.c: Resetting read to 64 and write to 64 Sep 1 15:55:03 DEBUG[30922] channel.c: Building translator from alaw to SLINEAR for spies on channel Agent/2073 Sep 1 15:55:04 DEBUG[17596] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '320dd9c06469b8a46b7f5674182c54fd@gk.magrathea.net' Request 103: Found Sep 1 15:55:04 DEBUG[30922] channel.c: Building translator from alaw to SLINEAR for spies on channel Agent/2073 Sep 1 15:55:06 DEBUG[17596] chan_sip.c: Acked pending invite 103 Sep 1 15:55:06 DEBUG[17596] chan_sip.c: Stopping retransmission on '320dd9c06469b8a46b7f5674182c54fd@gk.magrathea.net' of Request 103: Match Found Sep 1 15:55:06 DEBUG[17596] chan_sip.c: build_route: Contact hop: Sep 1 15:55:07 DEBUG[17596] chan_sip.c: Acked pending invite 103 Sep 1 15:55:07 DEBUG[17596] chan_sip.c: Stopping retransmission on '59673017254ccddf003b07b157d5c024@gk.magrathea.net' of Request 103: Match Found Sep 1 15:55:07 DEBUG[30911] chan_sip.c: update_call_counter(441592778330) - decrement call limit counter Sep 1 15:55:07 DEBUG[30911] app_dial.c: Exiting with DIALSTATUS=BUSY. Sep 1 15:55:12 DEBUG[17596] acl.c: ##### Testing 213.166.5.135 with 10.1.20.0 Sep 1 15:55:12 DEBUG[17596] acl.c: ##### Testing 213.166.5.135 with 172.28.1.0 Sep 1 15:55:12 DEBUG[17596] chan_sip.c: Target address 213.166.5.135 is not local, substituting externip Sep 1 15:55:12 DEBUG[17596] chan_sip.c: Stopping retransmission on '3434c33d4e5a3d565075c6157aeaa665@89.105.104.74' of Request 102: Match Found Sep 1 15:55:12 DEBUG[30911] chan_iax2.c: We're hanging up IAX2/magsiax-1 now... Sep 1 15:55:12 DEBUG[30911] app_dial.c: Exiting with DIALSTATUS=CONGESTION. Sep 1 15:55:12 DEBUG[17585] channel.c: Avoiding initial deadlock for 'Zap/2-1' Sep 1 15:55:12 DEBUG[30911] channel.c: Building translator from alaw to SLINEAR for spies on channel Agent/2069 Sep 1 15:55:12 DEBUG[30911] chan_agent.c: Bridge on 'SIP/1027-0934c678' being cleared (2) Sep 1 15:55:12 DEBUG[30911] chan_sip.c: update_call_counter(1027) - decrement call limit counter Sep 1 15:55:12 DEBUG[30911] chan_zap.c: Set option AUDIO MODE, value: ON(1) on Zap/2-1 Sep 1 15:55:12 DEBUG[30911] chan_zap.c: Hangup: channel: 2 index = 0, normal = 19, callwait = -1, thirdcall = -1 Sep 1 15:55:12 DEBUG[30911] chan_zap.c: Not yet hungup... Calling hangup once with icause, and clearing call Sep 1 15:55:12 DEBUG[30911] chan_zap.c: disabled echo cancellation on channel 2 Sep 1 15:55:12 DEBUG[30911] chan_zap.c: Set option TDD MODE, value: OFF(0) on Zap/2-1 Sep 1 15:55:12 DEBUG[30911] chan_zap.c: Updated conferencing on 2, with 0 conference users Sep 1 15:55:12 DEBUG[30911] chan_zap.c: Set option AUDIO MODE, value: OFF(0) on Zap/2-1 Sep 1 15:55:12 DEBUG[30911] chan_zap.c: disabled echo cancellation on channel 2 Sep 1 15:55:12 DEBUG[30911] app_dial.c: Exiting with DIALSTATUS=CANCEL. Sep 1 15:55:12 DEBUG[30911] channel.c: Spy MixMonitor removed from channel Agent/2069 Sep 1 15:55:12 DEBUG[30911] cdr_pgsql.c: cdr_pgsql: inserting a CDR record. Sep 1 15:55:12 DEBUG[30911] cdr_pgsql.c: cdr_pgsql: SQL command executed: INSERT INTO cdr (calldate,clid,src,dst,dcontext,channel,dstchannel,lastapp,lastdata,duration,billsec,disposition,amaflags,accountcode,uniqueid,userfield) VALUES ('2006-09-01 15:55:01','"->Stacey Spence" <01592778330>','01592778330','01592778330','auto_dial', 'Agent/2069','Zap/2-1','Dial','Zap/g1d/01592778330',11,0,'ANSWERED',3,'Evision-BIT','1157122500.2501','000/agent-2069-o283643c165154-20060901-155501.729') Sep 1 15:55:12 DEBUG[30911] chan_agent.c: Hangup called for state Up Sep 1 15:55:12 NOTICE[30911] pbx_spool.c: Call completed to AGENT/2069 Sep 1 15:55:15 WARNING[30945] cdr.c: CDR on channel 'Local/1027@local-a23c,2' not posted Sep 1 15:55:15 WARNING[30945] cdr.c: CDR on channel 'Local/1027@local-a23c,2' lacks end Sep 1 15:55:15 DEBUG[30945] pbx.c: Expression result is '1' Sep 1 15:55:15 DEBUG[30945] chan_sip.c: Setting NAT on RTP to 0 Sep 1 15:55:15 DEBUG[30945] acl.c: ##### Testing 10.1.20.67 with 10.1.20.0 Sep 1 15:55:15 DEBUG[30945] acl.c: ##### Testing 10.1.20.67 with 172.28.1.0 Sep 1 15:55:15 DEBUG[30945] chan_sip.c: Outgoing Call for 1027 Sep 1 15:55:16 DEBUG[17596] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '0e92899333df5772341a5f240bf01f48@10.1.20.3' Request 102: Found Sep 1 15:55:16 DEBUG[17596] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '0e92899333df5772341a5f240bf01f48@10.1.20.3' Request 102: Found Sep 1 15:55:16 DEBUG[17596] chan_sip.c: Acked pending invite 102 Sep 1 15:55:16 DEBUG[17596] chan_sip.c: Stopping retransmission on '0e92899333df5772341a5f240bf01f48@10.1.20.3' of Request 102: Match Found Sep 1 15:55:16 DEBUG[17596] chan_sip.c: build_route: Contact hop: Sep 1 15:55:16 DEBUG[30943] channel.c: Spy MixMonitor added to channel Agent/2069 Sep 1 15:55:16 DEBUG[30943] pbx.c: Expression result is '0' Sep 1 15:55:16 DEBUG[30943] pbx.c: Function result is '4' Sep 1 15:55:16 DEBUG[30943] pbx.c: Expression result is '0' Sep 1 15:55:16 DEBUG[30943] pbx.c: Not taking any branch Sep 1 15:55:16 DEBUG[30943] chan_sip.c: Setting NAT on RTP to 524288 Sep 1 15:55:16 DEBUG[30943] acl.c: ##### Testing 213.166.5.135 with 10.1.20.0 Sep 1 15:55:16 DEBUG[30943] acl.c: ##### Testing 213.166.5.135 with 172.28.1.0 Sep 1 15:55:16 DEBUG[30943] chan_sip.c: Target address 213.166.5.135 is not local, substituting externip Sep 1 15:55:16 DEBUG[30943] chan_sip.c: Outgoing Call for 441592778330 Sep 1 15:55:16 DEBUG[17596] chan_sip.c: Acked pending invite 102 Sep 1 15:55:16 DEBUG[17596] chan_sip.c: Stopping retransmission on '5e8f064b77464c2e66a4bd7f37be9970@gk.magrathea.net' of Request 102: Match Found Sep 1 15:55:16 DEBUG[17596] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '5e8f064b77464c2e66a4bd7f37be9970@gk.magrathea.net' Request 103: Found Sep 1 15:55:16 DEBUG[30945] channel.c: Planning to masquerade channel SIP/1027-0939a990 into the structure of Local/1027@local-a23c,1 Sep 1 15:55:16 DEBUG[30945] channel.c: Done planning to masquerade channel SIP/1027-0939a990 into the structure of Local/1027@local-a23c,1 Sep 1 15:55:16 DEBUG[30945] chan_local.c: Not posting to queue since already masked on 'Local/1027@local-a23c,2' Sep 1 15:55:16 DEBUG[30943] channel.c: Got clone lock for masquerade on 'SIP/1027-0939a990' at 0x933f984 Sep 1 15:55:16 DEBUG[30943] channel.c: Putting channel SIP/1027-0939a990 in 64/64 formats Sep 1 15:55:16 DEBUG[30943] channel.c: Released clone lock on 'Local/1027@local-a23c,1' Sep 1 15:55:16 DEBUG[30943] channel.c: Done Masquerading SIP/1027-0939a990 (6) Sep 1 15:55:16 DEBUG[30945] channel.c: Didn't get a frame from channel: Local/1027@local-a23c,2 Sep 1 15:55:16 DEBUG[30943] chan_agent.c: Bridge on 'SIP/1027-0939a990' being set to 'Agent/2069' (3) Sep 1 15:55:16 DEBUG[30945] channel.c: Bridge stops bridging channels Local/1027@local-a23c,2 and Local/1027@local-a23c,1 Sep 1 15:55:16 DEBUG[30943] chan_agent.c: Native formats changing from 64 to 8 Sep 1 15:55:16 DEBUG[30945] app_dial.c: Exiting with DIALSTATUS=ANSWER. Sep 1 15:55:16 DEBUG[30943] chan_agent.c: Resetting read to 64 and write to 64 Sep 1 15:55:16 DEBUG[30943] channel.c: Building translator from alaw to SLINEAR for spies on channel Agent/2069 Sep 1 15:55:22 DEBUG[17601] chan_iax2.c: Peer lastms 19, historicms 19, maxms 120 Sep 1 15:55:22 DEBUG[17596] chan_sip.c: Acked pending invite 103 Sep 1 15:55:22 DEBUG[17596] chan_sip.c: Stopping retransmission on '5e8f064b77464c2e66a4bd7f37be9970@gk.magrathea.net' of Request 103: Match Found Sep 1 15:55:22 DEBUG[30943] chan_sip.c: update_call_counter(441592778330) - decrement call limit counter Sep 1 15:55:22 DEBUG[30943] app_dial.c: Exiting with DIALSTATUS=BUSY. Sep 1 15:55:23 WARNING[30957] cdr.c: CDR on channel 'Local/1021@local-0dd2,2' not posted Sep 1 15:55:23 WARNING[30957] cdr.c: CDR on channel 'Local/1021@local-0dd2,2' lacks end Sep 1 15:55:23 DEBUG[30957] pbx.c: Expression result is '1' Sep 1 15:55:23 DEBUG[30957] chan_sip.c: Setting NAT on RTP to 0 Sep 1 15:55:23 DEBUG[30957] acl.c: ##### Testing 10.1.20.61 with 10.1.20.0 Sep 1 15:55:23 DEBUG[30957] acl.c: ##### Testing 10.1.20.61 with 172.28.1.0 Sep 1 15:55:23 DEBUG[30957] chan_sip.c: Outgoing Call for 1021 Sep 1 15:55:24 DEBUG[17596] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '002f383b6498f0df5018475368449c50@10.1.20.3' Request 102: Found Sep 1 15:55:24 DEBUG[17596] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '002f383b6498f0df5018475368449c50@10.1.20.3' Request 102: Found Sep 1 15:55:24 DEBUG[17596] chan_sip.c: Acked pending invite 102 Sep 1 15:55:24 DEBUG[17596] chan_sip.c: Stopping retransmission on '002f383b6498f0df5018475368449c50@10.1.20.3' of Request 102: Match Found Sep 1 15:55:24 DEBUG[17596] chan_sip.c: build_route: Contact hop: Sep 1 15:55:24 DEBUG[30956] channel.c: Spy MixMonitor added to channel Agent/2076 Sep 1 15:55:24 DEBUG[30956] pbx.c: Expression result is '0' Sep 1 15:55:24 DEBUG[30956] channel.c: Avoiding deadlock for 'Zap/1-1' Sep 1 15:55:24 DEBUG[30956] pbx.c: Function result is '5' Sep 1 15:55:24 DEBUG[30956] pbx.c: Expression result is '0' Sep 1 15:55:24 DEBUG[30956] pbx.c: Not taking any branch Sep 1 15:55:24 DEBUG[30956] chan_sip.c: Setting NAT on RTP to 524288 Sep 1 15:55:24 DEBUG[30956] acl.c: ##### Testing 213.166.5.135 with 10.1.20.0 Sep 1 15:55:24 DEBUG[30956] acl.c: ##### Testing 213.166.5.135 with 172.28.1.0 Sep 1 15:55:24 DEBUG[30956] chan_sip.c: Target address 213.166.5.135 is not local, substituting externip Sep 1 15:55:24 DEBUG[30956] chan_sip.c: Outgoing Call for 441279680068 Sep 1 15:55:24 DEBUG[17596] chan_sip.c: Acked pending invite 102 Sep 1 15:55:24 DEBUG[17596] chan_sip.c: Stopping retransmission on '08d46abf572ea81627a46e2b228f1490@gk.magrathea.net' of Request 102: Match Found Sep 1 15:55:24 DEBUG[17596] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '08d46abf572ea81627a46e2b228f1490@gk.magrathea.net' Request 103: Found Sep 1 15:55:24 DEBUG[30957] channel.c: Planning to masquerade channel SIP/1021-0934c678 into the structure of Local/1021@local-0dd2,1 Sep 1 15:55:24 DEBUG[30957] channel.c: Done planning to masquerade channel SIP/1021-0934c678 into the structure of Local/1021@local-0dd2,1 Sep 1 15:55:24 DEBUG[30957] chan_local.c: Not posting to queue since already masked on 'Local/1021@local-0dd2,2' Sep 1 15:55:24 DEBUG[30956] channel.c: Got clone lock for masquerade on 'SIP/1021-0934c678' at 0x931cf4c Sep 1 15:55:24 DEBUG[30956] channel.c: Putting channel SIP/1021-0934c678 in 64/64 formats Sep 1 15:55:24 DEBUG[30956] channel.c: Released clone lock on 'Local/1021@local-0dd2,1' Sep 1 15:55:24 DEBUG[30957] channel.c: Didn't get a frame from channel: Local/1021@local-0dd2,2 Sep 1 15:55:24 DEBUG[30956] channel.c: Done Masquerading SIP/1021-0934c678 (6) Sep 1 15:55:24 DEBUG[30956] chan_agent.c: Bridge on 'SIP/1021-0934c678' being set to 'Agent/2076' (3) Sep 1 15:55:24 DEBUG[30957] channel.c: Bridge stops bridging channels Local/1021@local-0dd2,2 and Local/1021@local-0dd2,1 Sep 1 15:55:24 DEBUG[30956] chan_agent.c: Native formats changing from 64 to 8 Sep 1 15:55:24 DEBUG[30956] chan_agent.c: Resetting read to 64 and write to 64 Sep 1 15:55:24 DEBUG[30957] app_dial.c: Exiting with DIALSTATUS=ANSWER. Sep 1 15:55:24 DEBUG[30956] channel.c: Building translator from alaw to SLINEAR for spies on channel Agent/2076 Sep 1 15:55:25 DEBUG[17596] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '08d46abf572ea81627a46e2b228f1490@gk.magrathea.net' Request 103: Found Sep 1 15:55:25 DEBUG[30956] channel.c: Building translator from alaw to SLINEAR for spies on channel Agent/2076 Sep 1 15:55:27 DEBUG[17596] chan_sip.c: Acked pending invite 103 Sep 1 15:55:27 DEBUG[17596] chan_sip.c: Stopping retransmission on '08d46abf572ea81627a46e2b228f1490@gk.magrathea.net' of Request 103: Match Found Sep 1 15:55:27 DEBUG[17596] chan_sip.c: build_route: Contact hop: Sep 1 15:55:28 DEBUG[30943] chan_iax2.c: We're hanging up IAX2/magsiax-4 now... Sep 1 15:55:28 DEBUG[30943] app_dial.c: Exiting with DIALSTATUS=CONGESTION. Sep 1 15:55:28 DEBUG[30943] channel.c: Building translator from alaw to SLINEAR for spies on channel Agent/2069 Sep 1 15:55:28 DEBUG[17598] chan_zap.c: Queuing frame from PRI_EVENT_PROCEEDING on channel 0/2 span 1 Sep 1 15:55:29 DEBUG[30943] chan_agent.c: Bridge on 'SIP/1027-0939a990' being cleared (2) Sep 1 15:55:29 DEBUG[30943] chan_sip.c: update_call_counter(1027) - decrement call limit counter Sep 1 15:55:29 DEBUG[30943] chan_zap.c: Set option AUDIO MODE, value: ON(1) on Zap/2-1 Sep 1 15:55:29 DEBUG[30943] chan_zap.c: Hangup: channel: 2 index = 0, normal = 19, callwait = -1, thirdcall = -1 Sep 1 15:55:29 DEBUG[30943] chan_zap.c: Not yet hungup... Calling hangup once with icause, and clearing call Sep 1 15:55:29 DEBUG[30943] chan_zap.c: disabled echo cancellation on channel 2 Sep 1 15:55:29 DEBUG[30943] chan_zap.c: Set option TDD MODE, value: OFF(0) on Zap/2-1 Sep 1 15:55:29 DEBUG[30943] chan_zap.c: Updated conferencing on 2, with 0 conference users Sep 1 15:55:29 DEBUG[30943] chan_zap.c: Set option AUDIO MODE, value: OFF(0) on Zap/2-1 Sep 1 15:55:29 DEBUG[30943] chan_zap.c: disabled echo cancellation on channel 2 Sep 1 15:55:29 DEBUG[30943] app_dial.c: Exiting with DIALSTATUS=CANCEL. Sep 1 15:55:29 DEBUG[30943] channel.c: Spy MixMonitor removed from channel Agent/2069 Sep 1 15:55:29 DEBUG[30943] cdr_pgsql.c: cdr_pgsql: inserting a CDR record. Sep 1 15:55:29 DEBUG[30943] cdr_pgsql.c: cdr_pgsql: SQL command executed: INSERT INTO cdr (calldate,clid,src,dst,dcontext,channel,dstchannel,lastapp,lastdata,duration,billsec,disposition,amaflags,accountcode,uniqueid,userfield) VALUES ('2006-09-01 15:55:16','"->Stacey Spence" <01592778330>','01592778330','01592778330','auto_dial', 'Agent/2069','Zap/2-1','Dial','Zap/g1d/01592778330',13,0,'ANSWERED',3,'Evision-BIT','1157122515.2513','000/agent-2069-o283643c165154-20060901-155516.729') Sep 1 15:55:29 DEBUG[30943] chan_agent.c: Hangup called for state Up Sep 1 15:55:29 NOTICE[30943] pbx_spool.c: Call completed to AGENT/2069 Sep 1 15:55:33 WARNING[30977] cdr.c: CDR on channel 'Local/1027@local-f719,2' not posted Sep 1 15:55:33 WARNING[30977] cdr.c: CDR on channel 'Local/1027@local-f719,2' lacks end Sep 1 15:55:33 DEBUG[30977] pbx.c: Expression result is '1' Sep 1 15:55:33 DEBUG[30977] chan_sip.c: Setting NAT on RTP to 0 Sep 1 15:55:33 DEBUG[30977] acl.c: ##### Testing 10.1.20.67 with 10.1.20.0 Sep 1 15:55:33 DEBUG[30977] acl.c: ##### Testing 10.1.20.67 with 172.28.1.0 Sep 1 15:55:33 DEBUG[30977] chan_sip.c: Outgoing Call for 1027 Sep 1 15:55:33 DEBUG[17596] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '4afedb0c77eeec596fdc5a8e7050112d@10.1.20.3' Request 102: Found Sep 1 15:55:33 DEBUG[17596] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '4afedb0c77eeec596fdc5a8e7050112d@10.1.20.3' Request 102: Found Sep 1 15:55:33 DEBUG[17596] chan_sip.c: Acked pending invite 102 Sep 1 15:55:33 DEBUG[17596] chan_sip.c: Stopping retransmission on '4afedb0c77eeec596fdc5a8e7050112d@10.1.20.3' of Request 102: Match Found Sep 1 15:55:33 DEBUG[17596] chan_sip.c: build_route: Contact hop: Sep 1 15:55:33 DEBUG[30975] channel.c: Spy MixMonitor added to channel Agent/2069 Sep 1 15:55:33 DEBUG[30975] pbx.c: Expression result is '0' Sep 1 15:55:33 DEBUG[30975] pbx.c: Function result is '5' Sep 1 15:55:33 DEBUG[30975] pbx.c: Expression result is '0' Sep 1 15:55:33 DEBUG[30975] pbx.c: Not taking any branch Sep 1 15:55:33 DEBUG[30975] chan_sip.c: Setting NAT on RTP to 524288 Sep 1 15:55:33 DEBUG[30975] acl.c: ##### Testing 213.166.5.135 with 10.1.20.0 Sep 1 15:55:33 DEBUG[30975] acl.c: ##### Testing 213.166.5.135 with 172.28.1.0 Sep 1 15:55:33 DEBUG[30975] chan_sip.c: Target address 213.166.5.135 is not local, substituting externip Sep 1 15:55:33 DEBUG[30975] chan_sip.c: Outgoing Call for 441592778330 Sep 1 15:55:33 DEBUG[17596] chan_sip.c: Acked pending invite 102 Sep 1 15:55:33 DEBUG[17596] chan_sip.c: Stopping retransmission on '07974a171588764f2e834328309b3b46@gk.magrathea.net' of Request 102: Match Found Sep 1 15:55:33 DEBUG[17596] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '07974a171588764f2e834328309b3b46@gk.magrathea.net' Request 103: Found Sep 1 15:55:33 DEBUG[30977] channel.c: Planning to masquerade channel SIP/1027-0932df08 into the structure of Local/1027@local-f719,1 Sep 1 15:55:33 DEBUG[30977] channel.c: Done planning to masquerade channel SIP/1027-0932df08 into the structure of Local/1027@local-f719,1 Sep 1 15:55:33 DEBUG[30977] chan_local.c: Not posting to queue since already masked on 'Local/1027@local-f719,2' Sep 1 15:55:33 DEBUG[30975] channel.c: Got clone lock for masquerade on 'SIP/1027-0932df08' at 0x935a684 Sep 1 15:55:33 DEBUG[30975] channel.c: Putting channel SIP/1027-0932df08 in 64/64 formats Sep 1 15:55:33 DEBUG[30975] channel.c: Released clone lock on 'Local/1027@local-f719,1' Sep 1 15:55:33 DEBUG[30975] channel.c: Done Masquerading SIP/1027-0932df08 (6) Sep 1 15:55:33 DEBUG[30977] channel.c: Didn't get a frame from channel: Local/1027@local-f719,2 Sep 1 15:55:33 DEBUG[30975] chan_agent.c: Bridge on 'SIP/1027-0932df08' being set to 'Agent/2069' (3) Sep 1 15:55:33 DEBUG[30977] channel.c: Bridge stops bridging channels Local/1027@local-f719,2 and Local/1027@local-f719,1 Sep 1 15:55:33 DEBUG[30975] chan_agent.c: Native formats changing from 64 to 8 Sep 1 15:55:33 DEBUG[30975] chan_agent.c: Resetting read to 64 and write to 64 Sep 1 15:55:33 DEBUG[30977] app_dial.c: Exiting with DIALSTATUS=ANSWER. Sep 1 15:55:33 DEBUG[30975] channel.c: Building translator from alaw to SLINEAR for spies on channel Agent/2069 Sep 1 15:55:39 DEBUG[17596] chan_sip.c: Acked pending invite 103 Sep 1 15:55:39 DEBUG[17596] chan_sip.c: Stopping retransmission on '07974a171588764f2e834328309b3b46@gk.magrathea.net' of Request 103: Match Found Sep 1 15:55:39 DEBUG[30975] chan_sip.c: update_call_counter(441592778330) - decrement call limit counter Sep 1 15:55:39 DEBUG[30975] app_dial.c: Exiting with DIALSTATUS=BUSY. Sep 1 15:55:42 WARNING[30990] cdr.c: CDR on channel 'Local/1024@local-df9b,2' not posted Sep 1 15:55:42 WARNING[30990] cdr.c: CDR on channel 'Local/1024@local-df9b,2' lacks end Sep 1 15:55:42 DEBUG[30990] pbx.c: Expression result is '1' Sep 1 15:55:42 DEBUG[30990] chan_sip.c: Setting NAT on RTP to 0 Sep 1 15:55:42 DEBUG[30990] acl.c: ##### Testing 10.1.20.64 with 10.1.20.0 Sep 1 15:55:42 DEBUG[30990] acl.c: ##### Testing 10.1.20.64 with 172.28.1.0 Sep 1 15:55:42 DEBUG[30990] chan_sip.c: Outgoing Call for 1024 Sep 1 15:55:42 DEBUG[17596] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '53c7aa06719dced836b7038c2d70dd61@10.1.20.3' Request 102: Found Sep 1 15:55:42 DEBUG[17596] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '53c7aa06719dced836b7038c2d70dd61@10.1.20.3' Request 102: Found Sep 1 15:55:42 DEBUG[17596] chan_sip.c: Acked pending invite 102 Sep 1 15:55:42 DEBUG[17596] chan_sip.c: Stopping retransmission on '53c7aa06719dced836b7038c2d70dd61@10.1.20.3' of Request 102: Match Found Sep 1 15:55:42 DEBUG[17596] chan_sip.c: build_route: Contact hop: Sep 1 15:55:42 DEBUG[30988] channel.c: Spy MixMonitor added to channel Agent/2074 Sep 1 15:55:42 DEBUG[30988] pbx.c: Expression result is '0' Sep 1 15:55:42 DEBUG[30988] pbx.c: Function result is '6' Sep 1 15:55:42 DEBUG[30988] pbx.c: Expression result is '0' Sep 1 15:55:42 DEBUG[30988] pbx.c: Not taking any branch Sep 1 15:55:42 DEBUG[30988] chan_sip.c: Setting NAT on RTP to 524288 Sep 1 15:55:42 DEBUG[30988] acl.c: ##### Testing 213.166.5.135 with 10.1.20.0 Sep 1 15:55:42 DEBUG[30988] acl.c: ##### Testing 213.166.5.135 with 172.28.1.0 Sep 1 15:55:42 DEBUG[30988] chan_sip.c: Target address 213.166.5.135 is not local, substituting externip Sep 1 15:55:42 DEBUG[30988] chan_sip.c: Outgoing Call for 442074990077 Sep 1 15:55:42 DEBUG[17596] chan_sip.c: Acked pending invite 102 Sep 1 15:55:42 DEBUG[17596] chan_sip.c: Stopping retransmission on '1eff342c4c7d5fc43c0605257f6d694c@gk.magrathea.net' of Request 102: Match Found Sep 1 15:55:42 DEBUG[17596] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '1eff342c4c7d5fc43c0605257f6d694c@gk.magrathea.net' Request 103: Found Sep 1 15:55:42 DEBUG[30990] channel.c: Planning to masquerade channel SIP/1024-0939a990 into the structure of Local/1024@local-df9b,1 Sep 1 15:55:42 DEBUG[30990] channel.c: Done planning to masquerade channel SIP/1024-0939a990 into the structure of Local/1024@local-df9b,1 Sep 1 15:55:42 DEBUG[30990] chan_local.c: Not posting to queue since already masked on 'Local/1024@local-df9b,2' Sep 1 15:55:42 DEBUG[30988] channel.c: Got clone lock for masquerade on 'SIP/1024-0939a990' at 0x9385f2c Sep 1 15:55:42 DEBUG[30988] channel.c: Putting channel SIP/1024-0939a990 in 64/64 formats Sep 1 15:55:42 DEBUG[30988] channel.c: Released clone lock on 'Local/1024@local-df9b,1' Sep 1 15:55:42 DEBUG[30988] channel.c: Done Masquerading SIP/1024-0939a990 (6) Sep 1 15:55:42 DEBUG[30988] chan_agent.c: Bridge on 'SIP/1024-0939a990' being set to 'Agent/2074' (3) Sep 1 15:55:42 DEBUG[30990] channel.c: Didn't get a frame from channel: Local/1024@local-df9b,2 Sep 1 15:55:42 DEBUG[30988] chan_agent.c: Native formats changing from 64 to 8 Sep 1 15:55:42 DEBUG[30988] chan_agent.c: Resetting read to 64 and write to 64 Sep 1 15:55:42 DEBUG[30990] channel.c: Bridge stops bridging channels Local/1024@local-df9b,2 and Local/1024@local-df9b,1 Sep 1 15:55:42 DEBUG[30990] app_dial.c: Exiting with DIALSTATUS=ANSWER. Sep 1 15:55:42 DEBUG[30988] channel.c: Building translator from alaw to SLINEAR for spies on channel Agent/2074 Sep 1 15:55:42 DEBUG[30956] chan_agent.c: Bridge on 'SIP/1021-0934c678' being cleared (2) Sep 1 15:55:42 DEBUG[30956] chan_sip.c: update_call_counter(1021) - decrement call limit counter Sep 1 15:55:42 DEBUG[30956] channel.c: Didn't get a frame from channel: Agent/2076 Sep 1 15:55:42 DEBUG[30956] channel.c: Bridge stops bridging channels Agent/2076 and SIP/mags-0938c1b8 Sep 1 15:55:42 DEBUG[30956] chan_sip.c: update_call_counter(441279680068) - decrement call limit counter Sep 1 15:55:42 DEBUG[30956] app_dial.c: Exiting with DIALSTATUS=ANSWER. Sep 1 15:55:42 DEBUG[30956] channel.c: Spy MixMonitor removed from channel Agent/2076 Sep 1 15:55:42 DEBUG[30956] cdr_pgsql.c: cdr_pgsql: inserting a CDR record. Sep 1 15:55:42 DEBUG[30956] cdr_pgsql.c: cdr_pgsql: SQL command executed: INSERT INTO cdr (calldate,clid,src,dst,dcontext,channel,dstchannel,lastapp,lastdata,duration,billsec,disposition,amaflags,accountcode,uniqueid,userfield) VALUES ('2006-09-01 15:55:24','"->Paul Lucas" <01279680068>','01279680068','01279680068','auto_dial', 'Agent/2076','SIP/mags-0938c1b8','Dial','SIP/441279680068@mags',18,15,'ANSWERED',3,'Zensar','1157122523.2519','000/agent-2076-o919854c215065-20060901-155524.729') Sep 1 15:55:42 DEBUG[30956] chan_agent.c: Hangup called for state Up Sep 1 15:55:42 NOTICE[30956] pbx_spool.c: Call completed to AGENT/2076 Sep 1 15:55:42 DEBUG[17596] chan_sip.c: Stopping retransmission on '08d46abf572ea81627a46e2b228f1490@gk.magrathea.net' of Request 104: Match Found Sep 1 15:55:43 DEBUG[17596] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '1eff342c4c7d5fc43c0605257f6d694c@gk.magrathea.net' Request 103: Found Sep 1 15:55:43 DEBUG[30988] channel.c: Building translator from alaw to SLINEAR for spies on channel Agent/2074 Sep 1 15:55:45 DEBUG[30975] chan_iax2.c: We're hanging up IAX2/magsiax-2 now... Sep 1 15:55:45 DEBUG[30975] app_dial.c: Exiting with DIALSTATUS=CONGESTION. Sep 1 15:55:45 DEBUG[17585] channel.c: Avoiding initial deadlock for 'Zap/2-1' Sep 1 15:55:45 DEBUG[30975] channel.c: Building translator from alaw to SLINEAR for spies on channel Agent/2069 Sep 1 15:55:45 DEBUG[30988] chan_agent.c: Bridge on 'SIP/1024-0939a990' being cleared (2) Sep 1 15:55:45 DEBUG[30988] chan_sip.c: update_call_counter(1024) - decrement call limit counter Sep 1 15:55:45 DEBUG[30988] chan_sip.c: update_call_counter(442074990077) - decrement call limit counter Sep 1 15:55:45 DEBUG[30988] chan_sip.c: Acked pending invite 103 Sep 1 15:55:45 DEBUG[30988] chan_sip.c: Stopping retransmission on '1eff342c4c7d5fc43c0605257f6d694c@gk.magrathea.net' of Request 103: Match Found Sep 1 15:55:45 DEBUG[30988] app_dial.c: Exiting with DIALSTATUS=CANCEL. Sep 1 15:55:45 DEBUG[30988] channel.c: Spy MixMonitor removed from channel Agent/2074 Sep 1 15:55:45 DEBUG[30988] cdr_pgsql.c: cdr_pgsql: inserting a CDR record. Sep 1 15:55:45 DEBUG[30988] cdr_pgsql.c: cdr_pgsql: SQL command executed: INSERT INTO cdr (calldate,clid,src,dst,dcontext,channel,dstchannel,lastapp,lastdata,duration,billsec,disposition,amaflags,accountcode,uniqueid,userfield) VALUES ('2006-09-01 15:55:42','"->Stuart Lawson" <02074990077>','02074990077','02074990077','auto_dial', 'Agent/2074','SIP/mags-09394e50','Dial','SIP/442074990077@mags',3,0,'ANSWERED',3,'Blue Martini','1157122542.2531','000/agent-2074-o90007332c263833-20060901-155542.729') Sep 1 15:55:45 DEBUG[30988] chan_agent.c: Hangup called for state Up Sep 1 15:55:45 NOTICE[30988] pbx_spool.c: Call completed to AGENT/2074 Sep 1 15:55:45 DEBUG[17596] chan_sip.c: Stopping retransmission on '1eff342c4c7d5fc43c0605257f6d694c@gk.magrathea.net' of Request 103: Match Found Sep 1 15:55:45 DEBUG[17596] chan_sip.c: Stopping retransmission on '1eff342c4c7d5fc43c0605257f6d694c@gk.magrathea.net' of Request 103: Match Not Found Sep 1 15:55:45 DEBUG[17598] chan_zap.c: Queuing frame from PRI_EVENT_PROCEEDING on channel 0/2 span 1 Sep 1 15:55:48 DEBUG[30975] chan_agent.c: Bridge on 'SIP/1027-0932df08' being cleared (2) Sep 1 15:55:48 DEBUG[30975] chan_sip.c: update_call_counter(1027) - decrement call limit counter Sep 1 15:55:48 DEBUG[30975] chan_zap.c: Set option AUDIO MODE, value: ON(1) on Zap/2-1 Sep 1 15:55:48 DEBUG[30975] chan_zap.c: Hangup: channel: 2 index = 0, normal = 19, callwait = -1, thirdcall = -1 Sep 1 15:55:48 DEBUG[30975] chan_zap.c: Not yet hungup... Calling hangup once with icause, and clearing call Sep 1 15:55:48 DEBUG[30975] chan_zap.c: disabled echo cancellation on channel 2 Sep 1 15:55:48 DEBUG[30975] chan_zap.c: Set option TDD MODE, value: OFF(0) on Zap/2-1 Sep 1 15:55:48 DEBUG[30975] chan_zap.c: Updated conferencing on 2, with 0 conference users Sep 1 15:55:48 DEBUG[30975] chan_zap.c: Set option AUDIO MODE, value: OFF(0) on Zap/2-1 Sep 1 15:55:48 DEBUG[30975] chan_zap.c: disabled echo cancellation on channel 2 Sep 1 15:55:48 DEBUG[30975] app_dial.c: Exiting with DIALSTATUS=CANCEL. Sep 1 15:55:48 DEBUG[30975] channel.c: Spy MixMonitor removed from channel Agent/2069 Sep 1 15:55:48 DEBUG[30975] cdr_pgsql.c: cdr_pgsql: inserting a CDR record. Sep 1 15:55:48 DEBUG[30975] cdr_pgsql.c: cdr_pgsql: SQL command executed: INSERT INTO cdr (calldate,clid,src,dst,dcontext,channel,dstchannel,lastapp,lastdata,duration,billsec,disposition,amaflags,accountcode,uniqueid,userfield) VALUES ('2006-09-01 15:55:33','"->Stacey Spence" <01592778330>','01592778330','01592778330','auto_dial', 'Agent/2069','Zap/2-1','Dial','Zap/g1d/01592778330',15,0,'ANSWERED',3,'Evision-BIT','1157122533.2525','000/agent-2069-o283643c165154-20060901-155533.729') Sep 1 15:55:48 DEBUG[30975] chan_agent.c: Hangup called for state Up Sep 1 15:55:48 NOTICE[30975] pbx_spool.c: Call completed to AGENT/2069 Sep 1 15:55:50 DEBUG[17596] acl.c: ##### Testing 10.1.20.67 with 10.1.20.0 Sep 1 15:55:50 DEBUG[17596] acl.c: ##### Testing 10.1.20.67 with 172.28.1.0 Sep 1 15:55:50 DEBUG[17596] chan_sip.c: Setting NAT on RTP to 0 Sep 1 15:55:51 DEBUG[17596] chan_sip.c: Stopping retransmission on '5d936b4f-e9397c1-e1be3576@10.1.20.67' of Response 1: Match Found Sep 1 15:55:51 DEBUG[17596] chan_sip.c: Setting NAT on RTP to 0 Sep 1 15:55:51 DEBUG[17596] chan_sip.c: Checking SIP call limits for device 1027 Sep 1 15:55:51 DEBUG[17596] chan_sip.c: build_route: Contact hop: Sep 1 15:55:51 DEBUG[17585] channel.c: Avoiding initial deadlock for 'SIP/1027-0939a990' Sep 1 15:55:51 WARNING[31014] cdr.c: CDR on channel 'SIP/1027-0939a990' not posted Sep 1 15:55:51 WARNING[31014] cdr.c: CDR on channel 'SIP/1027-0939a990' lacks end Sep 1 15:55:51 DEBUG[31014] pbx.c: Expression result is '1' Sep 1 15:55:51 DEBUG[31014] pbx.c: Function result is '1842' Sep 1 15:55:51 WARNING[31015] cdr.c: CDR on channel 'Local/8604@default-8475,2' not posted Sep 1 15:55:51 WARNING[31015] cdr.c: CDR on channel 'Local/8604@default-8475,2' lacks end Sep 1 15:55:51 DEBUG[31015] channel.c: Scheduling timer at 160 sample intervals Sep 1 15:55:51 DEBUG[31015] channel.c: Scheduling timer at 0 sample intervals Sep 1 15:55:52 DEBUG[31015] channel.c: Scheduling timer at 160 sample intervals Sep 1 15:55:52 DEBUG[31015] channel.c: Scheduling timer at 0 sample intervals Sep 1 15:55:53 DEBUG[31015] channel.c: Scheduling timer at 160 sample intervals Sep 1 15:55:53 DEBUG[31015] channel.c: Scheduling timer at 0 sample intervals Sep 1 15:55:53 DEBUG[17596] chan_sip.c: Stopping retransmission on '5d936b4f-e9397c1-e1be3576@10.1.20.67' of Response 2: Match Found Sep 1 15:55:54 DEBUG[31015] channel.c: Scheduling timer at 160 sample intervals Sep 1 15:55:55 DEBUG[31015] channel.c: Scheduling timer at 0 sample intervals Sep 1 15:55:56 DEBUG[31015] channel.c: Scheduling timer at 160 sample intervals Sep 1 15:55:57 DEBUG[31015] channel.c: Scheduling timer at 0 sample intervals Sep 1 15:56:00 DEBUG[31015] channel.c: Scheduling timer at 160 sample intervals Sep 1 15:56:03 DEBUG[31015] channel.c: Scheduling timer at 0 sample intervals Sep 1 15:56:04 DEBUG[31015] channel.c: Scheduling timer at 160 sample intervals Sep 1 15:56:05 DEBUG[31015] channel.c: Scheduling timer at 0 sample intervals Sep 1 15:56:06 DEBUG[31015] channel.c: Scheduling timer at 160 sample intervals Sep 1 15:56:07 DEBUG[31015] channel.c: Scheduling timer at 0 sample intervals Sep 1 15:56:07 DEBUG[31015] channel.c: Scheduling timer at 0 sample intervals Sep 1 15:56:08 DEBUG[31014] channel.c: Didn't get a frame from channel: Local/8604@default-8475,1 Sep 1 15:56:08 DEBUG[31014] channel.c: Bridge stops bridging channels SIP/1027-0939a990 and Local/8604@default-8475,1 Sep 1 15:56:08 DEBUG[31014] app_dial.c: Exiting with DIALSTATUS=ANSWER. Sep 1 15:56:08 DEBUG[31014] chan_sip.c: update_call_counter(1027) - decrement call limit counter Sep 1 15:56:08 DEBUG[17596] chan_sip.c: Stopping retransmission on '5d936b4f-e9397c1-e1be3576@10.1.20.67' of Request 102: Match Found Sep 1 15:56:11 WARNING[31028] cdr.c: CDR on channel 'Local/1027@local-3b67,2' not posted Sep 1 15:56:11 WARNING[31028] cdr.c: CDR on channel 'Local/1027@local-3b67,2' lacks end Sep 1 15:56:11 DEBUG[31028] pbx.c: Expression result is '1' Sep 1 15:56:11 DEBUG[31028] chan_sip.c: Setting NAT on RTP to 0 Sep 1 15:56:11 DEBUG[31028] acl.c: ##### Testing 10.1.20.67 with 10.1.20.0 Sep 1 15:56:11 DEBUG[31028] acl.c: ##### Testing 10.1.20.67 with 172.28.1.0 Sep 1 15:56:11 DEBUG[31028] chan_sip.c: Outgoing Call for 1027 Sep 1 15:56:11 DEBUG[17596] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '1757da6b2ce050ba5b6393e30bfecf29@10.1.20.3' Request 102: Found Sep 1 15:56:11 DEBUG[17596] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '1757da6b2ce050ba5b6393e30bfecf29@10.1.20.3' Request 102: Found Sep 1 15:56:11 DEBUG[17596] chan_sip.c: Acked pending invite 102 Sep 1 15:56:11 DEBUG[17596] chan_sip.c: Stopping retransmission on '1757da6b2ce050ba5b6393e30bfecf29@10.1.20.3' of Request 102: Match Found Sep 1 15:56:11 DEBUG[17596] chan_sip.c: build_route: Contact hop: Sep 1 15:56:11 DEBUG[31026] channel.c: Spy MixMonitor added to channel Agent/2069 Sep 1 15:56:11 DEBUG[31026] pbx.c: Expression result is '0' Sep 1 15:56:11 DEBUG[31026] pbx.c: Function result is '4' Sep 1 15:56:11 DEBUG[31026] pbx.c: Expression result is '0' Sep 1 15:56:11 DEBUG[31026] pbx.c: Not taking any branch Sep 1 15:56:11 DEBUG[31026] chan_sip.c: Setting NAT on RTP to 524288 Sep 1 15:56:11 DEBUG[31026] acl.c: ##### Testing 213.166.5.135 with 10.1.20.0 Sep 1 15:56:11 DEBUG[31026] acl.c: ##### Testing 213.166.5.135 with 172.28.1.0 Sep 1 15:56:11 DEBUG[31026] chan_sip.c: Target address 213.166.5.135 is not local, substituting externip Sep 1 15:56:11 DEBUG[31026] chan_sip.c: Outgoing Call for 441592778330 Sep 1 15:56:11 DEBUG[17596] chan_sip.c: Acked pending invite 102 Sep 1 15:56:11 DEBUG[17596] chan_sip.c: Stopping retransmission on '3f7c05d564d322fe726edc774636867d@gk.magrathea.net' of Request 102: Match Found Sep 1 15:56:11 DEBUG[17596] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '3f7c05d564d322fe726edc774636867d@gk.magrathea.net' Request 103: Found Sep 1 15:56:11 DEBUG[31028] channel.c: Planning to masquerade channel SIP/1027-0939a990 into the structure of Local/1027@local-3b67,1 Sep 1 15:56:11 DEBUG[31028] channel.c: Done planning to masquerade channel SIP/1027-0939a990 into the structure of Local/1027@local-3b67,1 Sep 1 15:56:11 DEBUG[31028] chan_local.c: Not posting to queue since already masked on 'Local/1027@local-3b67,2' Sep 1 15:56:11 DEBUG[31026] channel.c: Got clone lock for masquerade on 'SIP/1027-0939a990' at 0x935a684 Sep 1 15:56:11 DEBUG[31026] channel.c: Putting channel SIP/1027-0939a990 in 64/64 formats Sep 1 15:56:11 DEBUG[31026] channel.c: Released clone lock on 'Local/1027@local-3b67,1' Sep 1 15:56:11 DEBUG[31026] channel.c: Done Masquerading SIP/1027-0939a990 (6) Sep 1 15:56:11 DEBUG[31028] channel.c: Didn't get a frame from channel: Local/1027@local-3b67,2 Sep 1 15:56:11 DEBUG[31026] chan_agent.c: Bridge on 'SIP/1027-0939a990' being set to 'Agent/2069' (3) Sep 1 15:56:11 DEBUG[31028] channel.c: Bridge stops bridging channels Local/1027@local-3b67,2 and Local/1027@local-3b67,1 Sep 1 15:56:11 DEBUG[31026] chan_agent.c: Native formats changing from 64 to 8 Sep 1 15:56:11 DEBUG[31026] chan_agent.c: Resetting read to 64 and write to 64 Sep 1 15:56:11 DEBUG[31028] app_dial.c: Exiting with DIALSTATUS=ANSWER. Sep 1 15:56:11 DEBUG[31026] channel.c: Building translator from alaw to SLINEAR for spies on channel Agent/2069 Sep 1 15:56:12 DEBUG[17596] acl.c: ##### Testing 213.166.5.135 with 10.1.20.0 Sep 1 15:56:12 DEBUG[17596] acl.c: ##### Testing 213.166.5.135 with 172.28.1.0 Sep 1 15:56:12 DEBUG[17596] chan_sip.c: Target address 213.166.5.135 is not local, substituting externip Sep 1 15:56:12 DEBUG[17596] chan_sip.c: Stopping retransmission on '12f2c8325d6df0474f8d8687643c3157@89.105.104.74' of Request 102: Match Found Sep 1 15:56:17 DEBUG[17596] chan_sip.c: Acked pending invite 103 Sep 1 15:56:17 DEBUG[17596] chan_sip.c: Stopping retransmission on '3f7c05d564d322fe726edc774636867d@gk.magrathea.net' of Request 103: Match Found Sep 1 15:56:17 DEBUG[31026] chan_sip.c: update_call_counter(441592778330) - decrement call limit counter Sep 1 15:56:17 DEBUG[31026] app_dial.c: Exiting with DIALSTATUS=BUSY. Sep 1 15:56:22 DEBUG[17601] chan_iax2.c: Peer lastms 18, historicms 18, maxms 120 Sep 1 15:56:23 DEBUG[31026] chan_iax2.c: We're hanging up IAX2/magsiax-1 now... Sep 1 15:56:23 DEBUG[31026] app_dial.c: Exiting with DIALSTATUS=CONGESTION. Sep 1 15:56:23 DEBUG[17585] channel.c: Avoiding initial deadlock for 'Zap/2-1' Sep 1 15:56:23 DEBUG[31026] channel.c: Building translator from alaw to SLINEAR for spies on channel Agent/2069 Sep 1 15:56:23 DEBUG[17598] chan_zap.c: Queuing frame from PRI_EVENT_PROCEEDING on channel 0/2 span 1 Sep 1 15:56:27 DEBUG[31026] chan_zap.c: Set option AUDIO MODE, value: ON(1) on Zap/2-1 Sep 1 15:56:27 DEBUG[31026] chan_zap.c: Hangup: channel: 2 index = 0, normal = 19, callwait = -1, thirdcall = -1 Sep 1 15:56:27 DEBUG[31026] chan_zap.c: Not yet hungup... Calling hangup once with icause, and clearing call Sep 1 15:56:27 DEBUG[31026] chan_zap.c: disabled echo cancellation on channel 2 Sep 1 15:56:27 DEBUG[31026] chan_zap.c: Set option TDD MODE, value: OFF(0) on Zap/2-1 Sep 1 15:56:27 DEBUG[31026] chan_zap.c: Updated conferencing on 2, with 0 conference users Sep 1 15:56:27 DEBUG[31026] chan_zap.c: Set option AUDIO MODE, value: OFF(0) on Zap/2-1 Sep 1 15:56:27 DEBUG[31026] chan_zap.c: disabled echo cancellation on channel 2 Sep 1 15:56:27 DEBUG[31026] app_dial.c: Exiting with DIALSTATUS=BUSY. Sep 1 15:56:27 DEBUG[31026] channel.c: Scheduling timer at 160 sample intervals Sep 1 15:56:27 DEBUG[31026] channel.c: Generator got voice, switching to phase locked mode Sep 1 15:56:27 DEBUG[31026] channel.c: Scheduling timer at 0 sample intervals Sep 1 15:56:30 DEBUG[31026] chan_agent.c: Bridge on 'SIP/1027-0939a990' being cleared (2) Sep 1 15:56:30 DEBUG[31026] chan_sip.c: update_call_counter(1027) - decrement call limit counter Sep 1 15:56:30 DEBUG[31026] channel.c: Scheduling timer at 0 sample intervals Sep 1 15:56:30 DEBUG[31026] channel.c: Spy MixMonitor removed from channel Agent/2069 Sep 1 15:56:30 DEBUG[31026] cdr_pgsql.c: cdr_pgsql: inserting a CDR record. Sep 1 15:56:30 DEBUG[31026] cdr_pgsql.c: cdr_pgsql: SQL command executed: INSERT INTO cdr (calldate,clid,src,dst,dcontext,channel,dstchannel,lastapp,lastdata,duration,billsec,disposition,amaflags,accountcode,uniqueid,userfield) VALUES ('2006-09-01 15:56:11','"->Stacey Spence" <01592778330>','01592778330','s-BUSY','auto_dial', 'Agent/2069','Zap/2-1','PlayTones','400/375|0/375|400/375|0/375|400/375|0/375|400/375|0/375|400/375|0/375',19,0,'ANSWERED',3,'Evision-BIT','1157122571.2540','000/agent-2069-o283643c165154-20060901-155611.729') Sep 1 15:56:30 DEBUG[31026] chan_agent.c: Hangup called for state Up Sep 1 15:56:30 NOTICE[31026] pbx_spool.c: Call completed to AGENT/2069 Sep 1 15:56:34 WARNING[31048] cdr.c: CDR on channel 'Local/1027@local-c547,2' not posted Sep 1 15:56:34 WARNING[31048] cdr.c: CDR on channel 'Local/1027@local-c547,2' lacks end Sep 1 15:56:34 DEBUG[31048] pbx.c: Expression result is '1' Sep 1 15:56:34 DEBUG[31048] chan_sip.c: Setting NAT on RTP to 0 Sep 1 15:56:34 DEBUG[31048] acl.c: ##### Testing 10.1.20.67 with 10.1.20.0 Sep 1 15:56:34 DEBUG[31048] acl.c: ##### Testing 10.1.20.67 with 172.28.1.0 Sep 1 15:56:34 DEBUG[31048] chan_sip.c: Outgoing Call for 1027 Sep 1 15:56:34 DEBUG[17596] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '3008cabc48ee696b7f7d51c85fa5a31d@10.1.20.3' Request 102: Found Sep 1 15:56:34 DEBUG[17596] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '3008cabc48ee696b7f7d51c85fa5a31d@10.1.20.3' Request 102: Found Sep 1 15:56:34 DEBUG[17596] chan_sip.c: Acked pending invite 102 Sep 1 15:56:34 DEBUG[17596] chan_sip.c: Stopping retransmission on '3008cabc48ee696b7f7d51c85fa5a31d@10.1.20.3' of Request 102: Match Found Sep 1 15:56:34 DEBUG[17596] chan_sip.c: build_route: Contact hop: Sep 1 15:56:34 DEBUG[31046] channel.c: Spy MixMonitor added to channel Agent/2069 Sep 1 15:56:34 DEBUG[31046] pbx.c: Expression result is '0' Sep 1 15:56:34 DEBUG[31046] pbx.c: Function result is '4' Sep 1 15:56:34 DEBUG[31046] pbx.c: Expression result is '0' Sep 1 15:56:34 DEBUG[31046] pbx.c: Not taking any branch Sep 1 15:56:34 DEBUG[31046] chan_sip.c: Setting NAT on RTP to 524288 Sep 1 15:56:34 DEBUG[31046] acl.c: ##### Testing 213.166.5.135 with 10.1.20.0 Sep 1 15:56:34 DEBUG[31046] acl.c: ##### Testing 213.166.5.135 with 172.28.1.0 Sep 1 15:56:34 DEBUG[31046] chan_sip.c: Target address 213.166.5.135 is not local, substituting externip Sep 1 15:56:34 DEBUG[31046] chan_sip.c: Outgoing Call for 441592778330 Sep 1 15:56:34 DEBUG[17596] chan_sip.c: Acked pending invite 102 Sep 1 15:56:34 DEBUG[17596] chan_sip.c: Stopping retransmission on '2fbcd6157f4e4e111318058022d895d4@gk.magrathea.net' of Request 102: Match Found Sep 1 15:56:34 DEBUG[17596] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '2fbcd6157f4e4e111318058022d895d4@gk.magrathea.net' Request 103: Found Sep 1 15:56:34 DEBUG[17596] acl.c: ##### Testing 10.1.20.52 with 10.1.20.0 Sep 1 15:56:34 DEBUG[17596] acl.c: ##### Testing 10.1.20.52 with 172.28.1.0 Sep 1 15:56:34 DEBUG[17596] chan_sip.c: Setting NAT on RTP to 0 Sep 1 15:56:34 DEBUG[31048] channel.c: Planning to masquerade channel SIP/1027-0939a990 into the structure of Local/1027@local-c547,1 Sep 1 15:56:34 DEBUG[31048] channel.c: Done planning to masquerade channel SIP/1027-0939a990 into the structure of Local/1027@local-c547,1 Sep 1 15:56:34 DEBUG[31048] chan_local.c: Not posting to queue since already masked on 'Local/1027@local-c547,2' Sep 1 15:56:34 DEBUG[31046] channel.c: Got clone lock for masquerade on 'SIP/1027-0939a990' at 0x93aeb34 Sep 1 15:56:34 DEBUG[31046] channel.c: Putting channel SIP/1027-0939a990 in 64/64 formats Sep 1 15:56:34 DEBUG[31046] channel.c: Released clone lock on 'Local/1027@local-c547,1' Sep 1 15:56:34 DEBUG[31046] channel.c: Done Masquerading SIP/1027-0939a990 (6) Sep 1 15:56:34 DEBUG[31048] channel.c: Didn't get a frame from channel: Local/1027@local-c547,2 Sep 1 15:56:34 DEBUG[31046] chan_agent.c: Bridge on 'SIP/1027-0939a990' being set to 'Agent/2069' (3) Sep 1 15:56:34 DEBUG[31046] chan_agent.c: Native formats changing from 64 to 8 Sep 1 15:56:34 DEBUG[31046] chan_agent.c: Resetting read to 64 and write to 64 Sep 1 15:56:34 DEBUG[31048] channel.c: Bridge stops bridging channels Local/1027@local-c547,2 and Local/1027@local-c547,1 Sep 1 15:56:34 DEBUG[31048] app_dial.c: Exiting with DIALSTATUS=ANSWER. Sep 1 15:56:34 DEBUG[31046] channel.c: Building translator from alaw to SLINEAR for spies on channel Agent/2069 Sep 1 15:56:34 DEBUG[17596] chan_sip.c: Stopping retransmission on '000af434-e131069e-51423c37-69268311@10.1.20.52' of Response 101: Match Found Sep 1 15:56:34 DEBUG[17596] chan_sip.c: Setting NAT on RTP to 0 Sep 1 15:56:34 DEBUG[17596] chan_sip.c: Checking SIP call limits for device 1012 Sep 1 15:56:34 DEBUG[17596] chan_sip.c: build_route: Contact hop: Sep 1 15:56:34 DEBUG[17585] channel.c: Avoiding initial deadlock for 'SIP/1012-0938c1b8' Sep 1 15:56:34 DEBUG[31057] pbx.c: Expression result is '1' Sep 1 15:56:34 DEBUG[31057] pbx.c: Function result is 'Walter McDonald' Sep 1 15:56:34 DEBUG[31057] pbx.c: Function result is '1031@local' Sep 1 15:56:34 DEBUG[31057] chan_sip.c: Setting NAT on RTP to 0 Sep 1 15:56:34 DEBUG[31057] acl.c: ##### Testing 10.1.20.71 with 10.1.20.0 Sep 1 15:56:34 DEBUG[31057] acl.c: ##### Testing 10.1.20.71 with 172.28.1.0 Sep 1 15:56:34 DEBUG[31057] chan_sip.c: Outgoing Call for 1031 Sep 1 15:56:34 DEBUG[17596] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '3e5251155a4e87587671cd3f78a1b089@10.1.20.3' Request 102: Found Sep 1 15:56:34 DEBUG[17596] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '3e5251155a4e87587671cd3f78a1b089@10.1.20.3' Request 102: Found Sep 1 15:56:36 DEBUG[17596] chan_sip.c: Acked pending invite 102 Sep 1 15:56:36 DEBUG[17596] chan_sip.c: Stopping retransmission on '3e5251155a4e87587671cd3f78a1b089@10.1.20.3' of Request 102: Match Found Sep 1 15:56:36 DEBUG[17596] chan_sip.c: build_route: Contact hop: Sep 1 15:56:36 DEBUG[17585] channel.c: Avoiding initial deadlock for 'SIP/1012-0938c1b8' Sep 1 15:56:36 DEBUG[17596] chan_sip.c: Stopping retransmission on '000af434-e131069e-51423c37-69268311@10.1.20.52' of Response 102: Match Found Sep 1 15:56:40 DEBUG[17596] chan_sip.c: Acked pending invite 103 Sep 1 15:56:40 DEBUG[17596] chan_sip.c: Stopping retransmission on '2fbcd6157f4e4e111318058022d895d4@gk.magrathea.net' of Request 103: Match Found Sep 1 15:56:40 DEBUG[31046] chan_sip.c: update_call_counter(441592778330) - decrement call limit counter Sep 1 15:56:40 DEBUG[31046] app_dial.c: Exiting with DIALSTATUS=BUSY. Sep 1 15:56:46 DEBUG[31046] chan_iax2.c: We're hanging up IAX2/magsiax-3 now... Sep 1 15:56:46 DEBUG[31046] app_dial.c: Exiting with DIALSTATUS=CONGESTION. Sep 1 15:56:46 DEBUG[17585] channel.c: Avoiding initial deadlock for 'Zap/2-1' Sep 1 15:56:46 DEBUG[31046] channel.c: Building translator from alaw to SLINEAR for spies on channel Agent/2069 Sep 1 15:56:46 DEBUG[17598] chan_zap.c: Queuing frame from PRI_EVENT_PROCEEDING on channel 0/2 span 1 Sep 1 15:56:50 DEBUG[31046] chan_zap.c: Set option AUDIO MODE, value: ON(1) on Zap/2-1 Sep 1 15:56:50 DEBUG[31046] chan_zap.c: Hangup: channel: 2 index = 0, normal = 19, callwait = -1, thirdcall = -1 Sep 1 15:56:50 DEBUG[31046] chan_zap.c: Not yet hungup... Calling hangup once with icause, and clearing call Sep 1 15:56:50 DEBUG[31046] chan_zap.c: disabled echo cancellation on channel 2 Sep 1 15:56:50 DEBUG[31046] chan_zap.c: Set option TDD MODE, value: OFF(0) on Zap/2-1 Sep 1 15:56:50 DEBUG[31046] chan_zap.c: Updated conferencing on 2, with 0 conference users Sep 1 15:56:50 DEBUG[31046] chan_zap.c: Set option AUDIO MODE, value: OFF(0) on Zap/2-1 Sep 1 15:56:50 DEBUG[31046] chan_zap.c: disabled echo cancellation on channel 2 Sep 1 15:56:50 DEBUG[31046] app_dial.c: Exiting with DIALSTATUS=BUSY. Sep 1 15:56:50 DEBUG[31046] channel.c: Scheduling timer at 160 sample intervals Sep 1 15:56:50 DEBUG[31046] channel.c: Generator got voice, switching to phase locked mode Sep 1 15:56:50 DEBUG[31046] channel.c: Scheduling timer at 0 sample intervals Sep 1 15:56:52 DEBUG[30768] channel.c: Didn't get a frame from channel: SIP/1010-0938fbe0 Sep 1 15:56:52 DEBUG[30768] channel.c: Bridge stops bridging channels Zap/1-1 and SIP/1010-0938fbe0 Sep 1 15:56:52 DEBUG[30768] chan_sip.c: update_call_counter(1010) - decrement call limit counter Sep 1 15:56:52 DEBUG[30768] app_dial.c: Exiting with DIALSTATUS=ANSWER. Sep 1 15:56:52 DEBUG[30768] cdr_pgsql.c: cdr_pgsql: inserting a CDR record. Sep 1 15:56:52 DEBUG[30768] cdr_pgsql.c: cdr_pgsql: SQL command executed: INSERT INTO cdr (calldate,clid,src,dst,dcontext,channel,dstchannel,lastapp,lastdata,duration,billsec,disposition,amaflags,accountcode,uniqueid,userfield) VALUES ('2006-09-01 15:48:29','"EXTERNAL CALL" <7795548805>','7795548805','2026','demo', 'SIP/1029-093aa288','SIP/1010-0938fbe0','Dial','SIP/1010|500',503,501,'ANSWERED',3,'','1157122109.2467','') Sep 1 15:56:52 DEBUG[30768] cdr_pgsql.c: cdr_pgsql: inserting a CDR record. Sep 1 15:56:52 DEBUG[30768] cdr_pgsql.c: cdr_pgsql: SQL command executed: INSERT INTO cdr (calldate,clid,src,dst,dcontext,channel,dstchannel,lastapp,lastdata,duration,billsec,disposition,amaflags,accountcode,uniqueid,userfield) VALUES ('2006-09-01 15:45:38','"EXTERNAL CALL" <7795548805>','7795548805','2026','demo', 'SIP/1010-09373ad8','SIP/1029-09323790','Dial','SIP/1029|500',674,670,'ANSWERED',3,'','1157121938.2433','') Sep 1 15:56:52 DEBUG[30768] cdr_pgsql.c: cdr_pgsql: inserting a CDR record. Sep 1 15:56:52 DEBUG[30768] cdr_pgsql.c: cdr_pgsql: SQL command executed: INSERT INTO cdr (calldate,clid,src,dst,dcontext,channel,dstchannel,lastapp,lastdata,duration,billsec,disposition,amaflags,accountcode,uniqueid,userfield) VALUES ('2006-09-01 15:45:22','"EXTERNAL CALL" <7795548805>','7795548805','2026','demo', 'Zap/1-1','SIP/1010-09350e68','Queue','fci-inbound2|r',690,690,'ANSWERED',3,'','1157121922.2419','inb/Zap-1-1-20060901-154523.729') Sep 1 15:56:52 DEBUG[30768] chan_zap.c: Set option AUDIO MODE, value: ON(1) on Zap/1-1 Sep 1 15:56:52 DEBUG[30768] chan_zap.c: Hangup: channel: 1 index = 0, normal = 18, callwait = -1, thirdcall = -1 Sep 1 15:56:52 DEBUG[30768] chan_zap.c: Not yet hungup... Calling hangup once with icause, and clearing call Sep 1 15:56:52 DEBUG[30768] chan_zap.c: disabled echo cancellation on channel 1 Sep 1 15:56:52 DEBUG[30768] chan_zap.c: Set option TDD MODE, value: OFF(0) on Zap/1-1 Sep 1 15:56:52 DEBUG[30768] chan_zap.c: Updated conferencing on 1, with 0 conference users Sep 1 15:56:52 DEBUG[30768] chan_zap.c: Set option AUDIO MODE, value: OFF(0) on Zap/1-1 Sep 1 15:56:52 DEBUG[30768] chan_zap.c: disabled echo cancellation on channel 1 Sep 1 15:56:53 DEBUG[31046] chan_agent.c: Bridge on 'SIP/1027-0939a990' being cleared (2) Sep 1 15:56:53 DEBUG[31046] chan_sip.c: update_call_counter(1027) - decrement call limit counter Sep 1 15:56:53 DEBUG[31046] channel.c: Scheduling timer at 0 sample intervals Sep 1 15:56:57 NOTICE[31137] cdr.c: CDR simple logging enabled. Sep 1 15:56:57 DEBUG[31137] pbx_dundi.c: Seeding global EID '00:04:23:9f:23:16' from 'eth0' Sep 1 15:56:57 DEBUG[31137] acl.c: 10.1.20.0/255.255.255.0/255.255.255.0 appended to acl for peer Sep 1 15:56:57 DEBUG[31137] acl.c: 172.28.1.0/255.255.255.0/255.255.255.0 appended to acl for peer Sep 1 15:56:57 DEBUG[31137] acl.c: ##### Testing 213.166.5.135 with 10.1.20.0 Sep 1 15:56:57 DEBUG[31137] acl.c: ##### Testing 213.166.5.135 with 172.28.1.0 Sep 1 15:56:57 DEBUG[31137] chan_sip.c: Target address 213.166.5.135 is not local, substituting externip Sep 1 15:56:57 DEBUG[31137] chan_zap.c: Failed to read gains: Invalid argument Sep 1 15:56:57 DEBUG[31137] chan_zap.c: Failed to read gains: Invalid argument Sep 1 15:56:57 DEBUG[31137] chan_zap.c: Updated conferencing on 1, with 0 conference users Sep 1 15:56:57 DEBUG[31137] chan_zap.c: Failed to read gains: Invalid argument Sep 1 15:56:57 DEBUG[31137] chan_zap.c: Failed to read gains: Invalid argument Sep 1 15:56:57 DEBUG[31137] chan_zap.c: Updated conferencing on 2, with 0 conference users Sep 1 15:56:57 DEBUG[31137] chan_zap.c: Failed to read gains: Invalid argument Sep 1 15:56:57 DEBUG[31137] chan_zap.c: Failed to read gains: Invalid argument Sep 1 15:56:57 DEBUG[31137] chan_zap.c: Updated conferencing on 3, with 0 conference users Sep 1 15:56:57 DEBUG[31137] chan_zap.c: Failed to read gains: Invalid argument Sep 1 15:56:57 DEBUG[31137] chan_zap.c: Failed to read gains: Invalid argument Sep 1 15:56:57 DEBUG[31137] chan_zap.c: Updated conferencing on 4, with 0 conference users Sep 1 15:56:57 DEBUG[31137] chan_zap.c: Failed to read gains: Invalid argument Sep 1 15:56:57 DEBUG[31137] chan_zap.c: Failed to read gains: Invalid argument Sep 1 15:56:57 DEBUG[31137] chan_zap.c: Updated conferencing on 5, with 0 conference users Sep 1 15:56:57 DEBUG[31137] chan_zap.c: Failed to read gains: Invalid argument Sep 1 15:56:57 DEBUG[31137] chan_zap.c: Failed to read gains: Invalid argument Sep 1 15:56:57 DEBUG[31137] chan_zap.c: Updated conferencing on 6, with 0 conference users Sep 1 15:56:57 DEBUG[31137] chan_zap.c: Failed to read gains: Invalid argument Sep 1 15:56:57 DEBUG[31137] chan_zap.c: Failed to read gains: Invalid argument Sep 1 15:56:57 DEBUG[31137] chan_zap.c: Updated conferencing on 7, with 0 conference users Sep 1 15:56:57 DEBUG[31137] chan_zap.c: Failed to read gains: Invalid argument Sep 1 15:56:57 DEBUG[31137] chan_zap.c: Failed to read gains: Invalid argument Sep 1 15:56:57 DEBUG[31137] chan_zap.c: Updated conferencing on 8, with 0 conference users Sep 1 15:56:57 DEBUG[31137] chan_zap.c: Failed to read gains: Invalid argument Sep 1 15:56:57 DEBUG[31137] chan_zap.c: Failed to read gains: Invalid argument Sep 1 15:56:57 DEBUG[31137] chan_zap.c: Updated conferencing on 9, with 0 conference users Sep 1 15:56:57 DEBUG[31137] chan_zap.c: Failed to read gains: Invalid argument Sep 1 15:56:57 DEBUG[31137] chan_zap.c: Failed to read gains: Invalid argument Sep 1 15:56:57 DEBUG[31137] chan_zap.c: Updated conferencing on 10, with 0 conference users Sep 1 15:56:57 DEBUG[31137] chan_zap.c: Failed to read gains: Invalid argument Sep 1 15:56:57 DEBUG[31137] chan_zap.c: Failed to read gains: Invalid argument Sep 1 15:56:57 DEBUG[31137] chan_zap.c: Updated conferencing on 11, with 0 conference users Sep 1 15:56:57 DEBUG[31137] chan_zap.c: Failed to read gains: Invalid argument Sep 1 15:56:57 DEBUG[31137] chan_zap.c: Failed to read gains: Invalid argument Sep 1 15:56:57 DEBUG[31137] chan_zap.c: Updated conferencing on 12, with 0 conference users Sep 1 15:56:57 DEBUG[31137] chan_zap.c: Failed to read gains: Invalid argument Sep 1 15:56:57 DEBUG[31137] chan_zap.c: Failed to read gains: Invalid argument Sep 1 15:56:57 DEBUG[31137] chan_zap.c: Updated conferencing on 13, with 0 conference users Sep 1 15:56:57 DEBUG[31137] chan_zap.c: Failed to read gains: Invalid argument Sep 1 15:56:57 DEBUG[31137] chan_zap.c: Failed to read gains: Invalid argument Sep 1 15:56:57 DEBUG[31137] chan_zap.c: Updated conferencing on 14, with 0 conference users Sep 1 15:56:57 DEBUG[31137] chan_zap.c: Failed to read gains: Invalid argument Sep 1 15:56:57 DEBUG[31137] chan_zap.c: Failed to read gains: Invalid argument Sep 1 15:56:57 DEBUG[31137] chan_zap.c: Updated conferencing on 15, with 0 conference users Sep 1 15:56:57 DEBUG[31178] chan_sip.c: Stopping retransmission on '3425bb6d2870d1e665708cf0342de3b5@89.105.104.74' of Request 102: Match Found Sep 1 15:56:57 DEBUG[31137] app_voicemail.c: VM Operator break disabled globally Sep 1 15:56:57 DEBUG[31137] app_voicemail.c: VM CID Info before msg disabled globally Sep 1 15:56:57 DEBUG[31137] app_voicemail.c: ENVELOPE before msg enabled globally Sep 1 15:56:57 DEBUG[31137] app_voicemail.c: Duration info before msg enabled globally Sep 1 15:56:57 DEBUG[31137] app_voicemail.c: We are not going to skip to the next msg after save/delete Sep 1 15:56:57 DEBUG[31183] chan_iax2.c: Peer lastms 55, historicms 55, maxms 120 Sep 1 15:56:57 DEBUG[31137] cdr_pgsql.c: cdr_pgsql: got hostname of 172.28.1.52 Sep 1 15:56:57 DEBUG[31137] cdr_pgsql.c: cdr_pgsql: got port of 5432 Sep 1 15:56:57 DEBUG[31137] cdr_pgsql.c: cdr_pgsql: got user of asterisk Sep 1 15:56:57 DEBUG[31137] cdr_pgsql.c: cdr_pgsql: got dbname of callrecords_asterisk Sep 1 15:56:57 DEBUG[31137] cdr_pgsql.c: cdr_pgsql: got password of retlaw Sep 1 15:56:57 DEBUG[31137] cdr_pgsql.c: cdr_pgsql: got sql table name of cdr Sep 1 15:56:57 DEBUG[31137] cdr_pgsql.c: Successfully connected to PostgreSQL database. Sep 1 15:56:57 NOTICE[31137] codec_g729.c: G.729 transcoding module Copyright (C) 1999-2005 Digium, Inc. Sep 1 15:56:57 NOTICE[31137] codec_g729.c: This module is supplied under a commercial license granted by Digium, Inc. Sep 1 15:56:57 NOTICE[31137] codec_g729.c: Please see the full license text supplied by the accompanying Sep 1 15:56:57 NOTICE[31137] codec_g729.c: "register" utility, or ask for a copy from Digium. Sep 1 15:56:57 DEBUG[31178] acl.c: ##### Testing 213.166.5.135 with 10.1.20.0 Sep 1 15:56:57 DEBUG[31178] acl.c: ##### Testing 213.166.5.135 with 172.28.1.0 Sep 1 15:56:57 DEBUG[31178] chan_sip.c: Target address 213.166.5.135 is not local, substituting externip Sep 1 15:56:57 DEBUG[31178] chan_sip.c: Scheduled a registration timeout for gk.magrathea.net id #51 Sep 1 15:56:57 DEBUG[31178] chan_sip.c: Stopping retransmission on '68ecf6614ad2dbca2ee210e96a7b956f@127.0.0.1' of Request 102: Match Found Sep 1 15:56:57 DEBUG[31178] chan_sip.c: Stopping retransmission on '68ecf6614ad2dbca2ee210e96a7b956f@127.0.0.1' of Request 103: Match Found Sep 1 15:56:57 DEBUG[31178] chan_sip.c: Registration successful Sep 1 15:56:57 DEBUG[31178] chan_sip.c: Cancelling timeout 51 Sep 1 15:56:58 DEBUG[31178] acl.c: ##### Testing 10.1.20.71 with 10.1.20.0 Sep 1 15:56:58 DEBUG[31178] acl.c: ##### Testing 10.1.20.71 with 172.28.1.0 Sep 1 15:56:58 DEBUG[31178] acl.c: ##### Testing 10.1.20.69 with 10.1.20.0 Sep 1 15:56:58 DEBUG[31178] acl.c: ##### Testing 10.1.20.69 with 172.28.1.0 Sep 1 15:57:02 DEBUG[31178] acl.c: ##### Testing 213.166.5.135 with 10.1.20.0 Sep 1 15:57:02 DEBUG[31178] acl.c: ##### Testing 213.166.5.135 with 172.28.1.0 Sep 1 15:57:02 DEBUG[31178] chan_sip.c: Target address 213.166.5.135 is not local, substituting externip Sep 1 15:57:05 DEBUG[31178] acl.c: ##### Testing 10.1.20.67 with 10.1.20.0 Sep 1 15:57:05 DEBUG[31178] acl.c: ##### Testing 10.1.20.67 with 172.28.1.0 Sep 1 15:57:05 DEBUG[31178] chan_sip.c: Setting NAT on RTP to 0 Sep 1 15:57:05 DEBUG[31178] chan_sip.c: Stopping retransmission on 'c4b5d7c7-fd1c63f9-e013060e@10.1.20.67' of Response 1: Match Found Sep 1 15:57:05 DEBUG[31178] chan_sip.c: Setting NAT on RTP to 0 Sep 1 15:57:05 DEBUG[31178] chan_sip.c: Checking SIP call limits for device 1027 Sep 1 15:57:05 DEBUG[31178] chan_sip.c: build_route: Contact hop: Sep 1 15:57:05 DEBUG[31164] channel.c: Avoiding initial deadlock for 'SIP/1027-08e2fa48' Sep 1 15:57:05 WARNING[31188] cdr.c: CDR on channel 'SIP/1027-08e2fa48' not posted Sep 1 15:57:05 WARNING[31188] cdr.c: CDR on channel 'SIP/1027-08e2fa48' lacks end Sep 1 15:57:05 DEBUG[31188] pbx.c: Expression result is '0' Sep 1 15:57:05 DEBUG[31188] channel.c: Scheduling timer at 160 sample intervals Sep 1 15:57:05 DEBUG[31178] chan_sip.c: Stopping retransmission on 'c4b5d7c7-fd1c63f9-e013060e@10.1.20.67' of Response 2: Match Found Sep 1 15:57:06 DEBUG[31188] channel.c: Scheduling timer at 0 sample intervals Sep 1 15:57:07 DEBUG[31188] channel.c: Scheduling timer at 160 sample intervals Sep 1 15:57:07 DEBUG[31188] channel.c: Scheduling timer at 0 sample intervals Sep 1 15:57:08 DEBUG[31188] channel.c: Scheduling timer at 160 sample intervals Sep 1 15:57:09 DEBUG[31188] channel.c: Scheduling timer at 0 sample intervals Sep 1 15:57:09 DEBUG[31188] channel.c: Scheduling timer at 0 sample intervals Sep 1 15:57:09 DEBUG[31178] acl.c: ##### Testing 10.1.20.66 with 10.1.20.0 Sep 1 15:57:09 DEBUG[31178] acl.c: ##### Testing 10.1.20.66 with 172.28.1.0 Sep 1 15:57:10 DEBUG[31188] chan_sip.c: update_call_counter(1027) - decrement call limit counter Sep 1 15:57:10 DEBUG[31178] chan_sip.c: Stopping retransmission on 'c4b5d7c7-fd1c63f9-e013060e@10.1.20.67' of Request 102: Match Found Sep 1 15:57:11 DEBUG[31178] acl.c: ##### Testing 10.1.20.61 with 10.1.20.0 Sep 1 15:57:11 DEBUG[31178] acl.c: ##### Testing 10.1.20.61 with 172.28.1.0 Sep 1 15:57:11 DEBUG[31178] chan_sip.c: Setting NAT on RTP to 0 Sep 1 15:57:11 DEBUG[31178] chan_sip.c: Stopping retransmission on 'a7eae096-a9889abc-fe4c9b97@10.1.20.61' of Response 1: Match Found Sep 1 15:57:11 DEBUG[31178] chan_sip.c: Setting NAT on RTP to 0 Sep 1 15:57:11 DEBUG[31178] chan_sip.c: Checking SIP call limits for device 1021 Sep 1 15:57:11 DEBUG[31178] chan_sip.c: build_route: Contact hop: Sep 1 15:57:11 DEBUG[31164] channel.c: Avoiding initial deadlock for 'SIP/1021-08e2fa48' Sep 1 15:57:11 WARNING[31193] cdr.c: CDR on channel 'SIP/1021-08e2fa48' not posted Sep 1 15:57:11 WARNING[31193] cdr.c: CDR on channel 'SIP/1021-08e2fa48' lacks end Sep 1 15:57:11 DEBUG[31193] pbx.c: Expression result is '0' Sep 1 15:57:11 DEBUG[31193] channel.c: Scheduling timer at 160 sample intervals Sep 1 15:57:11 DEBUG[31178] chan_sip.c: Stopping retransmission on 'a7eae096-a9889abc-fe4c9b97@10.1.20.61' of Response 2: Match Found Sep 1 15:57:13 DEBUG[31178] acl.c: ##### Testing 213.166.5.135 with 10.1.20.0 Sep 1 15:57:13 DEBUG[31178] acl.c: ##### Testing 213.166.5.135 with 172.28.1.0 Sep 1 15:57:13 DEBUG[31178] chan_sip.c: Target address 213.166.5.135 is not local, substituting externip Sep 1 15:57:14 DEBUG[31178] acl.c: ##### Testing 213.166.5.135 with 10.1.20.0 Sep 1 15:57:14 DEBUG[31178] acl.c: ##### Testing 213.166.5.135 with 172.28.1.0 Sep 1 15:57:14 DEBUG[31178] chan_sip.c: Target address 213.166.5.135 is not local, substituting externip Sep 1 15:57:14 DEBUG[31178] acl.c: ##### Testing 10.1.20.66 with 10.1.20.0 Sep 1 15:57:14 DEBUG[31178] acl.c: ##### Testing 10.1.20.66 with 172.28.1.0 Sep 1 15:57:14 DEBUG[31178] chan_sip.c: Setting NAT on RTP to 0 Sep 1 15:57:14 DEBUG[31178] chan_sip.c: Stopping retransmission on 'dfd9a2fe-314999b4-f932fb83@10.1.20.66' of Response 1: Match Found Sep 1 15:57:14 DEBUG[31178] chan_sip.c: Setting NAT on RTP to 0 Sep 1 15:57:14 DEBUG[31178] chan_sip.c: Checking SIP call limits for device 1026 Sep 1 15:57:14 DEBUG[31178] chan_sip.c: build_route: Contact hop: Sep 1 15:57:14 DEBUG[31164] channel.c: Avoiding initial deadlock for 'SIP/1026-08e3f680' Sep 1 15:57:14 WARNING[31196] cdr.c: CDR on channel 'SIP/1026-08e3f680' not posted Sep 1 15:57:14 WARNING[31196] cdr.c: CDR on channel 'SIP/1026-08e3f680' lacks end Sep 1 15:57:14 DEBUG[31196] pbx.c: Expression result is '0' Sep 1 15:57:14 DEBUG[31196] channel.c: Scheduling timer at 160 sample intervals Sep 1 15:57:14 DEBUG[31178] chan_sip.c: Stopping retransmission on 'dfd9a2fe-314999b4-f932fb83@10.1.20.66' of Response 2: Match Found Sep 1 15:57:15 DEBUG[31193] channel.c: Scheduling timer at 0 sample intervals Sep 1 15:57:15 DEBUG[31193] channel.c: Scheduling timer at 0 sample intervals Sep 1 15:57:15 DEBUG[31196] channel.c: Scheduling timer at 0 sample intervals Sep 1 15:57:16 DEBUG[31196] channel.c: Scheduling timer at 160 sample intervals Sep 1 15:57:16 DEBUG[31196] channel.c: Scheduling timer at 0 sample intervals Sep 1 15:57:17 DEBUG[31193] channel.c: Scheduling timer at 160 sample intervals Sep 1 15:57:18 DEBUG[31196] channel.c: Scheduling timer at 160 sample intervals Sep 1 15:57:19 DEBUG[31196] channel.c: Scheduling timer at 0 sample intervals Sep 1 15:57:19 DEBUG[31196] pbx.c: Extension 8600, priority 4 returned normally even though call was hung up Sep 1 15:57:19 DEBUG[31196] chan_sip.c: update_call_counter(1026) - decrement call limit counter Sep 1 15:57:20 DEBUG[31193] channel.c: Scheduling timer at 0 sample intervals Sep 1 15:57:20 DEBUG[31193] channel.c: Scheduling timer at 0 sample intervals Sep 1 15:57:20 DEBUG[31178] acl.c: ##### Testing 10.1.20.66 with 10.1.20.0 Sep 1 15:57:20 DEBUG[31178] acl.c: ##### Testing 10.1.20.66 with 172.28.1.0 Sep 1 15:57:20 DEBUG[31178] chan_sip.c: Setting NAT on RTP to 0 Sep 1 15:57:20 DEBUG[31178] chan_sip.c: Stopping retransmission on '45a5dfee-58a00624-ed58b8b3@10.1.20.66' of Response 1: Match Found Sep 1 15:57:20 DEBUG[31178] chan_sip.c: Setting NAT on RTP to 0 Sep 1 15:57:20 DEBUG[31178] chan_sip.c: Checking SIP call limits for device 1026 Sep 1 15:57:20 DEBUG[31178] chan_sip.c: build_route: Contact hop: Sep 1 15:57:20 DEBUG[31164] channel.c: Avoiding initial deadlock for 'SIP/1026-08e34fc0' Sep 1 15:57:20 WARNING[31200] cdr.c: CDR on channel 'SIP/1026-08e34fc0' not posted Sep 1 15:57:20 WARNING[31200] cdr.c: CDR on channel 'SIP/1026-08e34fc0' lacks end Sep 1 15:57:20 DEBUG[31200] pbx.c: Expression result is '0' Sep 1 15:57:20 DEBUG[31200] channel.c: Scheduling timer at 160 sample intervals Sep 1 15:57:21 DEBUG[31178] chan_sip.c: Stopping retransmission on '45a5dfee-58a00624-ed58b8b3@10.1.20.66' of Response 2: Match Found Sep 1 15:57:21 DEBUG[31193] channel.c: Scheduling timer at 160 sample intervals Sep 1 15:57:21 DEBUG[31200] channel.c: Scheduling timer at 0 sample intervals Sep 1 15:57:22 DEBUG[31193] channel.c: Scheduling timer at 0 sample intervals Sep 1 15:57:22 DEBUG[31193] channel.c: Scheduling timer at 0 sample intervals Sep 1 15:57:23 DEBUG[31193] chan_sip.c: update_call_counter(1021) - decrement call limit counter Sep 1 15:57:23 DEBUG[31200] channel.c: Scheduling timer at 160 sample intervals Sep 1 15:57:23 DEBUG[31200] channel.c: Scheduling timer at 0 sample intervals Sep 1 15:57:23 DEBUG[31178] chan_sip.c: Stopping retransmission on 'a7eae096-a9889abc-fe4c9b97@10.1.20.61' of Request 102: Match Found Sep 1 15:57:23 DEBUG[31200] channel.c: Scheduling timer at 160 sample intervals Sep 1 15:57:25 DEBUG[31200] channel.c: Scheduling timer at 0 sample intervals Sep 1 15:57:25 DEBUG[31200] channel.c: Scheduling timer at 0 sample intervals Sep 1 15:57:25 DEBUG[31200] chan_sip.c: update_call_counter(1026) - decrement call limit counter Sep 1 15:57:25 DEBUG[31178] chan_sip.c: Stopping retransmission on '45a5dfee-58a00624-ed58b8b3@10.1.20.66' of Request 102: Match Found Sep 1 15:57:28 WARNING[31209] cdr.c: CDR on channel 'Local/1026@local-dfed,2' not posted Sep 1 15:57:28 WARNING[31209] cdr.c: CDR on channel 'Local/1026@local-dfed,2' lacks end Sep 1 15:57:28 DEBUG[31209] pbx.c: Expression result is '1' Sep 1 15:57:28 DEBUG[31209] chan_sip.c: Setting NAT on RTP to 0 Sep 1 15:57:28 DEBUG[31209] acl.c: ##### Testing 10.1.20.66 with 10.1.20.0 Sep 1 15:57:28 DEBUG[31209] acl.c: ##### Testing 10.1.20.66 with 172.28.1.0 Sep 1 15:57:28 DEBUG[31209] chan_sip.c: Outgoing Call for 1026 Sep 1 15:57:28 DEBUG[31178] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '033cab104e0f86da7cf197c4676d2d33@10.1.20.3' Request 102: Found Sep 1 15:57:28 DEBUG[31178] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '033cab104e0f86da7cf197c4676d2d33@10.1.20.3' Request 102: Found Sep 1 15:57:28 DEBUG[31178] chan_sip.c: Acked pending invite 102 Sep 1 15:57:28 DEBUG[31178] chan_sip.c: Stopping retransmission on '033cab104e0f86da7cf197c4676d2d33@10.1.20.3' of Request 102: Match Found Sep 1 15:57:28 DEBUG[31178] chan_sip.c: build_route: Contact hop: Sep 1 15:57:28 DEBUG[31207] pbx.c: Expression result is '0' Sep 1 15:57:28 DEBUG[31207] pbx.c: Function result is '1' Sep 1 15:57:28 DEBUG[31207] pbx.c: Expression result is '0' Sep 1 15:57:28 DEBUG[31207] pbx.c: Not taking any branch Sep 1 15:57:28 DEBUG[31207] chan_sip.c: Setting NAT on RTP to 524288 Sep 1 15:57:28 DEBUG[31207] acl.c: ##### Testing 213.166.5.135 with 10.1.20.0 Sep 1 15:57:28 DEBUG[31207] acl.c: ##### Testing 213.166.5.135 with 172.28.1.0 Sep 1 15:57:28 DEBUG[31207] chan_sip.c: Target address 213.166.5.135 is not local, substituting externip Sep 1 15:57:28 DEBUG[31207] chan_sip.c: Outgoing Call for 441418838629 Sep 1 15:57:28 DEBUG[31178] chan_sip.c: Acked pending invite 102 Sep 1 15:57:28 DEBUG[31178] chan_sip.c: Stopping retransmission on '5f5c953030dc9d692997aa3b089f9851@gk.magrathea.net' of Request 102: Match Found Sep 1 15:57:28 DEBUG[31178] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '5f5c953030dc9d692997aa3b089f9851@gk.magrathea.net' Request 103: Found Sep 1 15:57:28 DEBUG[31209] channel.c: Planning to masquerade channel SIP/1026-08e313e0 into the structure of Local/1026@local-dfed,1 Sep 1 15:57:28 DEBUG[31209] channel.c: Done planning to masquerade channel SIP/1026-08e313e0 into the structure of Local/1026@local-dfed,1 Sep 1 15:57:28 DEBUG[31209] chan_local.c: Not posting to queue since already masked on 'Local/1026@local-dfed,2' Sep 1 15:57:28 DEBUG[31207] channel.c: Got clone lock for masquerade on 'SIP/1026-08e313e0' at 0x8e303a4 Sep 1 15:57:28 DEBUG[31207] channel.c: Putting channel SIP/1026-08e313e0 in 64/64 formats Sep 1 15:57:28 DEBUG[31207] channel.c: Released clone lock on 'Local/1026@local-dfed,1' Sep 1 15:57:28 DEBUG[31207] channel.c: Done Masquerading SIP/1026-08e313e0 (6) Sep 1 15:57:28 DEBUG[31209] channel.c: Didn't get a frame from channel: Local/1026@local-dfed,2 Sep 1 15:57:28 DEBUG[31207] chan_agent.c: Bridge on 'SIP/1026-08e313e0' being set to 'Agent/2073' (3) Sep 1 15:57:28 DEBUG[31209] channel.c: Bridge stops bridging channels Local/1026@local-dfed,2 and Local/1026@local-dfed,1 Sep 1 15:57:28 DEBUG[31207] chan_agent.c: Native formats changing from 64 to 8 Sep 1 15:57:28 DEBUG[31207] chan_agent.c: Resetting read to 64 and write to 64 Sep 1 15:57:28 DEBUG[31209] app_dial.c: Exiting with DIALSTATUS=ANSWER. Sep 1 15:57:29 DEBUG[31178] chan_sip.c: Auto destroying call '68ecf6614ad2dbca2ee210e96a7b956f@127.0.0.1' Sep 1 15:57:30 DEBUG[31178] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '5f5c953030dc9d692997aa3b089f9851@gk.magrathea.net' Request 103: Found Sep 1 15:57:33 WARNING[31221] cdr.c: CDR on channel 'Local/1027@local-3a89,2' not posted Sep 1 15:57:33 WARNING[31221] cdr.c: CDR on channel 'Local/1027@local-3a89,2' lacks end Sep 1 15:57:33 DEBUG[31221] pbx.c: Expression result is '1' Sep 1 15:57:33 DEBUG[31221] chan_sip.c: Setting NAT on RTP to 0 Sep 1 15:57:33 DEBUG[31221] acl.c: ##### Testing 10.1.20.67 with 10.1.20.0 Sep 1 15:57:33 DEBUG[31221] acl.c: ##### Testing 10.1.20.67 with 172.28.1.0 Sep 1 15:57:33 DEBUG[31221] chan_sip.c: Outgoing Call for 1027 Sep 1 15:57:33 DEBUG[31178] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '3b12906c568e912d4d10414e0ef3937d@10.1.20.3' Request 102: Found Sep 1 15:57:33 DEBUG[31178] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '3b12906c568e912d4d10414e0ef3937d@10.1.20.3' Request 102: Found Sep 1 15:57:33 DEBUG[31178] chan_sip.c: Acked pending invite 102 Sep 1 15:57:33 DEBUG[31178] chan_sip.c: Stopping retransmission on '3b12906c568e912d4d10414e0ef3937d@10.1.20.3' of Request 102: Match Found Sep 1 15:57:33 DEBUG[31178] chan_sip.c: build_route: Contact hop: Sep 1 15:57:33 DEBUG[31219] pbx.c: Expression result is '0' Sep 1 15:57:33 DEBUG[31219] pbx.c: Function result is '2' Sep 1 15:57:33 DEBUG[31219] pbx.c: Expression result is '0' Sep 1 15:57:33 DEBUG[31219] pbx.c: Not taking any branch Sep 1 15:57:33 DEBUG[31219] chan_sip.c: Setting NAT on RTP to 524288 Sep 1 15:57:33 DEBUG[31219] acl.c: ##### Testing 213.166.5.135 with 10.1.20.0 Sep 1 15:57:33 DEBUG[31219] acl.c: ##### Testing 213.166.5.135 with 172.28.1.0 Sep 1 15:57:33 DEBUG[31219] chan_sip.c: Target address 213.166.5.135 is not local, substituting externip Sep 1 15:57:33 DEBUG[31219] chan_sip.c: Outgoing Call for 441592778330 Sep 1 15:57:33 DEBUG[31178] chan_sip.c: Acked pending invite 102 Sep 1 15:57:33 DEBUG[31178] chan_sip.c: Stopping retransmission on '6bcb35b3257083c952c3671145026b0f@gk.magrathea.net' of Request 102: Match Found Sep 1 15:57:33 DEBUG[31178] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '6bcb35b3257083c952c3671145026b0f@gk.magrathea.net' Request 103: Found Sep 1 15:57:33 DEBUG[31221] channel.c: Planning to masquerade channel SIP/1027-08e2cdf0 into the structure of Local/1027@local-3a89,1 Sep 1 15:57:33 DEBUG[31221] channel.c: Done planning to masquerade channel SIP/1027-08e2cdf0 into the structure of Local/1027@local-3a89,1 Sep 1 15:57:33 DEBUG[31221] chan_local.c: Not posting to queue since already masked on 'Local/1027@local-3a89,2' Sep 1 15:57:33 DEBUG[31219] channel.c: Got clone lock for masquerade on 'SIP/1027-08e2cdf0' at 0x8e72834 Sep 1 15:57:33 DEBUG[31219] channel.c: Putting channel SIP/1027-08e2cdf0 in 64/64 formats Sep 1 15:57:33 DEBUG[31219] channel.c: Released clone lock on 'Local/1027@local-3a89,1' Sep 1 15:57:33 DEBUG[31221] channel.c: Didn't get a frame from channel: Local/1027@local-3a89,2 Sep 1 15:57:33 DEBUG[31219] channel.c: Done Masquerading SIP/1027-08e2cdf0 (6) Sep 1 15:57:33 DEBUG[31219] chan_agent.c: Bridge on 'SIP/1027-08e2cdf0' being set to 'Agent/2069' (3) Sep 1 15:57:33 DEBUG[31221] channel.c: Bridge stops bridging channels Local/1027@local-3a89,2 and Local/1027@local-3a89,1 Sep 1 15:57:33 DEBUG[31219] chan_agent.c: Native formats changing from 64 to 8 Sep 1 15:57:33 DEBUG[31219] chan_agent.c: Resetting read to 64 and write to 64 Sep 1 15:57:33 DEBUG[31221] app_dial.c: Exiting with DIALSTATUS=ANSWER. Sep 1 15:57:34 DEBUG[31178] chan_sip.c: Acked pending invite 103 Sep 1 15:57:34 DEBUG[31178] chan_sip.c: Stopping retransmission on '5f5c953030dc9d692997aa3b089f9851@gk.magrathea.net' of Request 103: Match Found Sep 1 15:57:34 DEBUG[31178] chan_sip.c: build_route: Contact hop: Sep 1 15:57:39 DEBUG[31178] chan_sip.c: Acked pending invite 103 Sep 1 15:57:39 DEBUG[31178] chan_sip.c: Stopping retransmission on '6bcb35b3257083c952c3671145026b0f@gk.magrathea.net' of Request 103: Match Found Sep 1 15:57:39 DEBUG[31219] chan_sip.c: update_call_counter(441592778330) - decrement call limit counter Sep 1 15:57:39 DEBUG[31219] app_dial.c: Exiting with DIALSTATUS=BUSY.