Nov 11 17:17:40 DEBUG[13249] pbx.c: Launching 'Dial' Nov 11 17:17:40 VERBOSE[13249] logger.c: -- Executing Dial("SIP/ext2006-4cdd", "SIP/613@fwd|60|twW") in new stack Nov 11 17:17:40 DEBUG[13249] app_dial.c: SIMPLE DIAL (NO URL) Nov 11 17:17:40 DEBUG[13249] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - INVITE (With RTP) Nov 11 17:17:40 DEBUG[13249] chan_sip.c: Setting NAT on RTP to 0 Nov 11 17:17:40 DEBUG[13249] chan_sip.c: Setting NAT on VRTP to 0 Nov 11 17:17:40 DEBUG[13249] acl.c: ##### Testing 69.90.155.70 with 192.168.254.0 Nov 11 17:17:40 DEBUG[13249] chan_sip.c: Target address 69.90.155.70 is not local, substituting externip Nov 11 17:17:40 DEBUG[13249] channel.c: Not copying variable STACK-macro-dialfwd-s-3. Nov 11 17:17:40 DEBUG[13249] channel.c: Not copying variable MACRO_DEPTH. Nov 11 17:17:40 DEBUG[13249] channel.c: Not copying variable STACK-macro-dialfwd-s-2. Nov 11 17:17:40 DEBUG[13249] channel.c: Not copying variable STACK-macro-dialfwd-s-1. Nov 11 17:17:40 DEBUG[13249] channel.c: Not copying variable ARG2. Nov 11 17:17:40 DEBUG[13249] channel.c: Not copying variable ARG1. Nov 11 17:17:40 DEBUG[13249] channel.c: Not copying variable MACRO_PRIORITY. Nov 11 17:17:40 DEBUG[13249] channel.c: Not copying variable MACRO_CONTEXT. Nov 11 17:17:40 DEBUG[13249] channel.c: Not copying variable MACRO_EXTEN. Nov 11 17:17:40 DEBUG[13249] channel.c: Not copying variable STACK-home-*393613-1. Nov 11 17:17:40 DEBUG[13249] channel.c: Not copying variable SIPCALLID. Nov 11 17:17:40 DEBUG[13249] channel.c: Not copying variable SIPUSERAGENT. Nov 11 17:17:40 DEBUG[13249] channel.c: Not copying variable SIPDOMAIN. Nov 11 17:17:40 DEBUG[13249] channel.c: Not copying variable SIPURI. Nov 11 17:17:40 DEBUG[13249] chan_sip.c: Outgoing Call for 613 Nov 11 17:17:40 DEBUG[13249] chan_sip.c: Updating call counter for outgoing call Nov 11 17:17:40 VERBOSE[13249] logger.c: -- Called 613@fwd Nov 11 17:17:40 DEBUG[13249] channel.c: Set channel SIP/fwd-a9a8 to read format ulaw Nov 11 17:17:40 DEBUG[13249] channel.c: Set channel SIP/ext2006-4cdd to write format ulaw Nov 11 17:17:40 DEBUG[13249] channel.c: Set channel SIP/ext2006-4cdd to read format ulaw Nov 11 17:17:40 DEBUG[13249] channel.c: Set channel SIP/fwd-a9a8 to write format ulaw Nov 11 17:17:40 DEBUG[13243] chan_sip.c: = Found Their Call ID: 32c2a16c64b83632060941ed460927c2@fwd.pulver.com Their Tag Our tag: as4ab37e23 Nov 11 17:17:40 DEBUG[13243] chan_sip.c: Acked pending invite 102 Nov 11 17:17:40 DEBUG[13243] chan_sip.c: Stopping retransmission on '32c2a16c64b83632060941ed460927c2@fwd.pulver.com' of Request 102: Match Found Nov 11 17:17:40 DEBUG[13243] chan_sip.c: SIP response 407 to standard invite Nov 11 17:17:40 DEBUG[13243] chan_sip.c: Auth attempt 1 on INVITE Nov 11 17:17:40 DEBUG[13243] chan_sip.c: = Found Their Call ID: 32c2a16c64b83632060941ed460927c2@fwd.pulver.com Their Tag Our tag: as4ab37e23 Nov 11 17:17:40 DEBUG[13243] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '32c2a16c64b83632060941ed460927c2@fwd.pulver.com' Request 103: Found Nov 11 17:17:40 DEBUG[13243] chan_sip.c: SIP response 100 to standard invite Nov 11 17:17:40 DEBUG[13243] chan_sip.c: = Found Their Call ID: 32c2a16c64b83632060941ed460927c2@fwd.pulver.com Their Tag Our tag: as4ab37e23 Nov 11 17:17:40 DEBUG[13243] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '32c2a16c64b83632060941ed460927c2@fwd.pulver.com' Request 103: Found Nov 11 17:17:40 DEBUG[13243] chan_sip.c: SIP response 180 to standard invite Nov 11 17:17:40 VERBOSE[13249] logger.c: -- SIP/fwd-a9a8 is ringing Nov 11 17:17:40 DEBUG[13249] channel.c: Driver for channel 'SIP/ext2006-4cdd' does not support indication 3, emulating it Nov 11 17:17:40 DEBUG[13249] channel.c: Set channel SIP/ext2006-4cdd to write format slin Nov 11 17:17:40 DEBUG[13249] channel.c: Scheduling timer at 160 sample intervals Nov 11 17:17:40 DEBUG[13240] chan_sip.c: Checking device state for peer fwd Nov 11 17:17:40 DEBUG[13240] devicestate.c: Changing state for SIP/fwd - state 6 (Ringing) Nov 11 17:17:40 DEBUG[13252] app_queue.c: Device 'SIP/fwd' changed to state '6' (Ringing) Nov 11 17:17:41 DEBUG[13249] channel.c: Generator got voice, switching to phase locked mode Nov 11 17:17:41 DEBUG[13249] channel.c: Scheduling timer at 0 sample intervals Nov 11 17:17:41 DEBUG[13249] rtp.c: Difference is 1096, ms is 157 Nov 11 17:17:43 DEBUG[13247] chan_iax2.c: Allocate call number Nov 11 17:17:43 DEBUG[13247] chan_iax2.c: Registration created on call 2 Nov 11 17:17:47 DEBUG[13243] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP) Nov 11 17:17:47 DEBUG[13243] acl.c: ##### Testing 192.168.254.251 with 192.168.254.0 Nov 11 17:17:47 DEBUG[13243] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP) Nov 11 17:17:47 DEBUG[13243] acl.c: ##### Testing 192.168.254.251 with 192.168.254.0 Nov 11 17:17:47 DEBUG[13243] chan_sip.c: = No match Their Call ID: 2021908137777d562812f721485c9460@192.168.254.250 Their Tag Our tag: as3738c1a8 Nov 11 17:17:47 DEBUG[13243] chan_sip.c: = Found Their Call ID: 37ba9d8d6ac06fcc50101a934a90ea6a@192.168.254.250 Their Tag Our tag: as52315c9e Nov 11 17:17:47 DEBUG[13243] chan_sip.c: Stopping retransmission on '37ba9d8d6ac06fcc50101a934a90ea6a@192.168.254.250' of Request 102: Match Found Nov 11 17:17:47 DEBUG[13243] chan_sip.c: = Found Their Call ID: 2021908137777d562812f721485c9460@192.168.254.250 Their Tag Our tag: as3738c1a8 Nov 11 17:17:47 DEBUG[13243] chan_sip.c: Stopping retransmission on '2021908137777d562812f721485c9460@192.168.254.250' of Request 102: Match Found Nov 11 17:17:47 DEBUG[13243] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP) Nov 11 17:17:47 DEBUG[13243] acl.c: ##### Testing 192.168.254.252 with 192.168.254.0 Nov 11 17:17:47 DEBUG[13243] chan_sip.c: = Found Their Call ID: 5904c20c4ef7ac8406e8ded022ded1d4@192.168.254.250 Their Tag Our tag: as2d14ca92 Nov 11 17:17:47 DEBUG[13243] chan_sip.c: Stopping retransmission on '5904c20c4ef7ac8406e8ded022ded1d4@192.168.254.250' of Request 102: Match Found Nov 11 17:17:47 DEBUG[13243] chan_sip.c: = Found Their Call ID: 32c2a16c64b83632060941ed460927c2@fwd.pulver.com Their Tag as546a4403 Our tag: as4ab37e23 Nov 11 17:17:47 DEBUG[13243] chan_sip.c: Acked pending invite 103 Nov 11 17:17:47 DEBUG[13243] chan_sip.c: Stopping retransmission on '32c2a16c64b83632060941ed460927c2@fwd.pulver.com' of Request 103: Match Found Nov 11 17:17:47 DEBUG[13243] chan_sip.c: SIP response 200 to standard invite Nov 11 17:17:47 DEBUG[13243] chan_sip.c: build_route: Record-Route hop: Nov 11 17:17:47 VERBOSE[13249] logger.c: -- SIP/fwd-a9a8 answered SIP/ext2006-4cdd Nov 11 17:17:47 DEBUG[13249] channel.c: Set channel SIP/ext2006-4cdd to write format ulaw Nov 11 17:17:47 DEBUG[13249] channel.c: Scheduling timer at 0 sample intervals Nov 11 17:17:47 DEBUG[13249] channel.c: Set channel SIP/ext2006-4cdd to read format ulaw Nov 11 17:17:47 DEBUG[13249] channel.c: Set channel SIP/fwd-a9a8 to write format ulaw Nov 11 17:17:47 DEBUG[13249] channel.c: Set channel SIP/fwd-a9a8 to read format ulaw Nov 11 17:17:47 DEBUG[13249] channel.c: Set channel SIP/ext2006-4cdd to write format ulaw Nov 11 17:17:47 VERBOSE[13249] logger.c: -- Attempting native bridge of SIP/ext2006-4cdd and SIP/fwd-a9a8 Nov 11 17:17:47 DEBUG[13240] chan_sip.c: Checking device state for peer fwd Nov 11 17:17:47 DEBUG[13240] devicestate.c: Changing state for SIP/fwd - state 2 (In use) Nov 11 17:17:47 DEBUG[13253] app_queue.c: Device 'SIP/fwd' changed to state '2' (In use) Nov 11 17:17:47 DEBUG[13249] rtp.c: Ooh, format changed from unknown to ulaw Nov 11 17:17:50 DEBUG[13243] chan_sip.c: = No match Their Call ID: 32c2a16c64b83632060941ed460927c2@fwd.pulver.com Their Tag as546a4403 Our tag: as4ab37e23 Nov 11 17:17:50 DEBUG[13243] chan_sip.c: = No match Their Call ID: ff39f085-3b47c5ef-6bb20c3e@192.168.254.252 Their Tag 5416FA39-1624DFD8 Our tag: as2155b391 Nov 11 17:17:50 DEBUG[13243] acl.c: ##### Testing 192.168.254.252 with 192.168.254.0 Nov 11 17:17:50 DEBUG[13243] chan_sip.c: Allocating new SIP dialog for b378558e-a3c4c028-9c5d90bf@192.168.254.252 - SUBSCRIBE (No RTP) Nov 11 17:17:50 DEBUG[13243] chan_sip.c: **** Received SUBSCRIBE (10) - Command in SIP SUBSCRIBE Nov 11 17:17:50 DEBUG[13243] chan_sip.c: = Found Their Call ID: b378558e-a3c4c028-9c5d90bf@192.168.254.252 Their Tag B6176AA2-7C89E409 Our tag: as51c4acae Nov 11 17:17:50 DEBUG[13243] chan_sip.c: **** Received SUBSCRIBE (10) - Command in SIP SUBSCRIBE Nov 11 17:17:50 DEBUG[13249] rtp.c: Got RTCP report of 92 bytes Nov 11 17:17:55 DEBUG[13249] rtp.c: Sending dtmf: 42 (*), at 192.168.254.252 Nov 11 17:17:55 DEBUG[13249] channel.c: Got DTMF on channel (SIP/ext2006-4cdd) Nov 11 17:17:55 DEBUG[13249] channel.c: Bridge stops bridging channels SIP/ext2006-4cdd and SIP/fwd-a9a8 Nov 11 17:17:55 DEBUG[13249] res_features.c: Feature interpret: chan=SIP/ext2006-4cdd, peer=SIP/fwd-a9a8, sense=1, features=16 Nov 11 17:17:55 DEBUG[13249] res_features.c: Set time limit to 500 Nov 11 17:17:55 VERBOSE[13249] logger.c: -- Attempting native bridge of SIP/ext2006-4cdd and SIP/fwd-a9a8 Nov 11 17:17:55 DEBUG[13249] rtp.c: Sending dtmf: 49 (1), at 192.168.254.252 Nov 11 17:17:55 DEBUG[13249] channel.c: Got DTMF on channel (SIP/ext2006-4cdd) Nov 11 17:17:55 DEBUG[13249] channel.c: Bridge stops bridging channels SIP/ext2006-4cdd and SIP/fwd-a9a8 Nov 11 17:17:55 DEBUG[13249] res_features.c: Feature interpret: chan=SIP/ext2006-4cdd, peer=SIP/fwd-a9a8, sense=1, features=16 Nov 11 17:17:55 VERBOSE[13249] logger.c: -- User hit '*1' to record call. filename: wav|auto-1131754675-3607171717-*393613|m Nov 11 17:18:00 DEBUG[13249] rtp.c: Sending dtmf: 42 (*), at 192.168.254.252 Nov 11 17:18:00 DEBUG[13249] channel.c: Got DTMF on channel (SIP/ext2006-4cdd) Nov 11 17:18:00 DEBUG[13249] channel.c: Bridge stops bridging channels SIP/ext2006-4cdd and SIP/fwd-a9a8 Nov 11 17:18:00 DEBUG[13249] res_features.c: Feature interpret: chan=SIP/ext2006-4cdd, peer=SIP/fwd-a9a8, sense=1, features=16 Nov 11 17:18:00 DEBUG[13249] res_features.c: Set time limit to 500 Nov 11 17:18:00 DEBUG[13249] rtp.c: Got RTCP report of 92 bytes Nov 11 17:18:10 DEBUG[13249] rtp.c: Got RTCP report of 92 bytes Nov 11 17:18:11 DEBUG[13249] rtp.c: Sending dtmf: 42 (*), at 192.168.254.252 Nov 11 17:18:11 DEBUG[13249] channel.c: Got DTMF on channel (SIP/ext2006-4cdd) Nov 11 17:18:11 DEBUG[13249] channel.c: Bridge stops bridging channels SIP/ext2006-4cdd and SIP/fwd-a9a8 Nov 11 17:18:11 DEBUG[13249] res_features.c: Timed out for feature! Nov 11 17:18:11 DEBUG[13249] rtp.c: Ignore potential DTMF echo from '69.90.168.13' Nov 11 17:18:11 DEBUG[13254] rtp.c: Sending dtmf: 49 (1), at 192.168.254.252 Nov 11 17:18:16 DEBUG[13249] rtp.c: Sending dtmf: 42 (*), at 192.168.254.252 Nov 11 17:18:16 DEBUG[13249] channel.c: Got DTMF on channel (SIP/ext2006-4cdd) Nov 11 17:18:16 DEBUG[13249] channel.c: Bridge stops bridging channels SIP/ext2006-4cdd and SIP/fwd-a9a8 Nov 11 17:18:16 DEBUG[13249] res_features.c: Feature interpret: chan=SIP/ext2006-4cdd, peer=SIP/fwd-a9a8, sense=1, features=16 Nov 11 17:18:16 DEBUG[13249] res_features.c: Set time limit to 500 Nov 11 17:18:16 DEBUG[13249] rtp.c: Sending dtmf: 49 (1), at 192.168.254.252 Nov 11 17:18:16 DEBUG[13249] channel.c: Got DTMF on channel (SIP/ext2006-4cdd) Nov 11 17:18:16 DEBUG[13249] channel.c: Bridge stops bridging channels SIP/ext2006-4cdd and SIP/fwd-a9a8 Nov 11 17:18:16 DEBUG[13249] res_features.c: Feature interpret: chan=SIP/ext2006-4cdd, peer=SIP/fwd-a9a8, sense=1, features=16 Nov 11 17:18:16 VERBOSE[13249] logger.c: -- User hit '*1' to stop recording call. Nov 11 17:18:16 DEBUG[13249] res_monitor.c: monitor executing ( nice -n 19 soxmix "/var/spool/asterisk/monitor/auto-1131754675-3607171717-*393613-in.wav" "/var/spool/asterisk/monitor/auto-1131754675-3607171717-*393613-out.wav" "/var/spool/asterisk/monitor/auto-1131754675-3607171717-*393613.wav" && rm -f "/var/spool/asterisk/monitor/auto-1131754675-3607171717-*393613-"* ) & Nov 11 17:18:16 VERBOSE[13249] logger.c: -- Attempting native bridge of SIP/ext2006-4cdd and SIP/fwd-a9a8 Nov 11 17:18:19 DEBUG[13243] chan_sip.c: = No match Their Call ID: 32c2a16c64b83632060941ed460927c2@fwd.pulver.com Their Tag as546a4403 Our tag: as4ab37e23 Nov 11 17:18:19 DEBUG[13243] chan_sip.c: = Found Their Call ID: ff39f085-3b47c5ef-6bb20c3e@192.168.254.252 Their Tag 5416FA39-1624DFD8 Our tag: as2155b391 Nov 11 17:18:19 DEBUG[13243] chan_sip.c: **** Received BYE (8) - Command in SIP BYE