[Jul 22 14:22:47] DEBUG[27648] devicestate.c: Notification of state change to be queued on device/channel Logger/rotate [Jul 22 14:22:47] DEBUG[27648] devicestate.c: No provider found, checking channel drivers for Logger - rotate [Jul 22 14:22:47] DEBUG[27648] devicestate.c: Changing state for Logger/rotate - state 4 (Invalid) [Jul 22 14:22:47] DEBUG[27648] devicestate.c: Notification of state change to be queued on device/channel Logger/rotate [Jul 22 14:22:47] DEBUG[27648] devicestate.c: No provider found, checking channel drivers for Logger - rotate [Jul 22 14:22:47] DEBUG[27648] devicestate.c: Changing state for Logger/rotate - state 4 (Invalid) [Jul 22 14:22:47] VERBOSE[27648] logger.c: == Parsing '/etc/asterisk/logger.conf': [Jul 22 14:22:47] DEBUG[27648] config.c: Parsing /etc/asterisk/logger.conf [Jul 22 14:22:47] VERBOSE[27648] logger.c: == Found [Jul 22 14:22:47] DEBUG[27648] devicestate.c: Notification of state change to be queued on device/channel Logger/rotate [Jul 22 14:22:47] DEBUG[27648] devicestate.c: No provider found, checking channel drivers for Logger - rotate [Jul 22 14:22:47] VERBOSE[27648] logger.c: Asterisk Event Logger restarted [Jul 22 14:22:47] DEBUG[27648] devicestate.c: Changing state for Logger/rotate - state 4 (Invalid) [Jul 22 14:22:47] DEBUG[27648] devicestate.c: Notification of state change to be queued on device/channel Logger/rotate [Jul 22 14:22:47] DEBUG[27648] devicestate.c: No provider found, checking channel drivers for Logger - rotate [Jul 22 14:22:47] DEBUG[27648] devicestate.c: Changing state for Logger/rotate - state 4 (Invalid) [Jul 22 14:22:47] VERBOSE[27648] logger.c: Asterisk Queue Logger restarted [Jul 22 14:22:55] VERBOSE[27648] logger.c: -- Accepting UNAUTHENTICATED call from 209.217.98.230: > requested format = ulaw, > requested prefs = (ulaw|gsm), > actual format = ulaw, > host prefs = (ulaw), > priority = mine [Jul 22 14:22:55] DEBUG[27648] pbx.c: Launching 'Dial' [Jul 22 14:22:55] VERBOSE[27648] logger.c: -- Executing [6136274820@from-iax:1] Dial("IAX2/209.217.98.230:4569-15446", "SIP/sv0071ivr,5") in new stac k [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Asked to create a SIP channel with formats: 0x4 (ulaw) [Jul 22 14:22:55] VERBOSE[27648] logger.c: == Using SIP RTP CoS mark 5 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - INVITE (With RTP) [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Setting NAT on RTP to Off [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: OBPROXY: Not applying OBproxy to this call [Jul 22 14:22:55] DEBUG[27648] acl.c: Found IP address for this socket [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: *** Our native formats are 0x4 (ulaw) [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: *** Joint capabilities are 0x4 (ulaw) [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: *** Our capabilities are 0x6 (gsm|ulaw) [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: *** AST_CODEC_CHOOSE formats are 0x4 (ulaw) [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: *** Our preferred formats from the incoming channel are 0x4 (ulaw) [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: This channel will not be able to handle video. [Jul 22 14:22:55] DEBUG[27648] rtp.c: Channel 'IAX2/209.217.98.230:4569-15446' has no RTP, not doing anything [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Outgoing Call for [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Updating call counter for outgoing call [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Our T38 capability (0), joint T38 capability (0) [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: ** Our capability: 0x4 (ulaw) Video flag: False Text flag: False [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: ** Our prefcodec: 0x4 (ulaw) [Jul 22 14:22:55] VERBOSE[27648] logger.c: Audio is at 192.168.20.1 port 15100 [Jul 22 14:22:55] VERBOSE[27648] logger.c: Adding codec 0x4 (ulaw) to SDP [Jul 22 14:22:55] VERBOSE[27648] logger.c: Adding non-codec 0x1 (telephone-event) to SDP [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: -- Done with adding codecs to SDP [Jul 22 14:22:55] DEBUG[27648] channel.c: Internal timing is disabled (option_internal_timing=0 chan->timingfd=75) [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Done building SDP. Settling with this capability: 0x4 (ulaw) [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Initializing initreq for method INVITE - callid 53e9782a3e47a9ac34669ccd0f008cee@192.168.20.1 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 0 [ 33]: INVITE sip:sv0071iv.voice SIP/2.0 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 1 [ 63]: Via: SIP/2.0/TCP 192.168.20.1:5060;branch=z9hG4bK38e4beb6;rport [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 3 [ 65]: From: "Unknown Name" ;tag=as034aede3 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 4 [ 24]: To: [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 5 [ 57]: Contact: [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 6 [ 54]: Call-ID: 53e9782a3e47a9ac34669ccd0f008cee@192.168.20.1 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 7 [ 16]: CSeq: 102 INVITE [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 8 [ 36]: User-Agent: Asterisk PBX 1.6.0-beta9 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 9 [ 35]: Date: Tue, 22 Jul 2008 18:22:55 GMT [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 10 [ 66]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 11 [ 26]: Supported: replaces, timer [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 12 [ 29]: Content-Type: application/sdp [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 13 [ 19]: Content-Length: 267 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 14 [ 0]: [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Body 0 [ 3]: v=0 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Body 1 [ 48]: o=root 1182730262 1182730262 IN IP4 192.168.20.1 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Body 2 [ 26]: s=Asterisk PBX 1.6.0-beta9 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Body 3 [ 21]: c=IN IP4 192.168.20.1 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Body 4 [ 5]: t=0 0 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Body 5 [ 27]: m=audio 15100 RTP/AVP 0 101 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Body 6 [ 20]: a=rtpmap:0 PCMU/8000 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Body 7 [ 33]: a=rtpmap:101 telephone-event/8000 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Body 8 [ 15]: a=fmtp:101 0-16 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Body 9 [ 25]: a=silenceSupp:off - - - - [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Body 10 [ 10]: a=ptime:20 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Body 11 [ 10]: a=sendrecv [Jul 22 14:22:55] VERBOSE[27648] logger.c: Reliably Transmitting (no NAT) to 192.168.20.3:5060: INVITE sip:sv0071iv.voice SIP/2.0 Via: SIP/2.0/TCP 192.168.20.1:5060;branch=z9hG4bK38e4beb6;rport Max-Forwards: 70 From: "Unknown Name" ;tag=as034aede3 To: Contact: Call-ID: 53e9782a3e47a9ac34669ccd0f008cee@192.168.20.1 CSeq: 102 INVITE User-Agent: Asterisk PBX 1.6.0-beta9 Date: Tue, 22 Jul 2008 18:22:55 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces, timer Content-Type: application/sdp Content-Length: 267 v=0 o=root 1182730262 1182730262 IN IP4 192.168.20.1 s=Asterisk PBX 1.6.0-beta9 c=IN IP4 192.168.20.1 t=0 0 m=audio 15100 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv --- [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 0 [ 33]: INVITE sip:sv0071iv.voice SIP/2.0 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 1 [ 63]: Via: SIP/2.0/TCP 192.168.20.1:5060;branch=z9hG4bK38e4beb6;rport [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 3 [ 65]: From: "Unknown Name" ;tag=as034aede3 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 4 [ 24]: To: [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 5 [ 57]: Contact: [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 6 [ 54]: Call-ID: 53e9782a3e47a9ac34669ccd0f008cee@192.168.20.1 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 7 [ 16]: CSeq: 102 INVITE [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 8 [ 36]: User-Agent: Asterisk PBX 1.6.0-beta9 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 9 [ 35]: Date: Tue, 22 Jul 2008 18:22:55 GMT [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 10 [ 66]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 11 [ 26]: Supported: replaces, timer [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 12 [ 29]: Content-Type: application/sdp [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 13 [ 19]: Content-Length: 267 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 14 [ 0]: [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Body 0 [ 3]: v=0 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Body 1 [ 48]: o=root 1182730262 1182730262 IN IP4 192.168.20.1 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Body 2 [ 26]: s=Asterisk PBX 1.6.0-beta9 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Body 3 [ 21]: c=IN IP4 192.168.20.1 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Body 4 [ 5]: t=0 0 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Body 5 [ 27]: m=audio 15100 RTP/AVP 0 101 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Body 6 [ 20]: a=rtpmap:0 PCMU/8000 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Body 7 [ 33]: a=rtpmap:101 telephone-event/8000 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Body 8 [ 15]: a=fmtp:101 0-16 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Body 9 [ 25]: a=silenceSupp:off - - - - [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Body 10 [ 10]: a=ptime:20 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Body 11 [ 10]: a=sendrecv [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Trying to put 'INVITE sip' onto TCP socket... [Jul 22 14:22:55] VERBOSE[27648] logger.c: -- Called sv0071ivr [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 0 [ 18]: SIP/2.0 100 Trying [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 1 [ 64]: FROM: "Unknown Name";tag=as034aede3 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 2 [ 24]: TO: [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 3 [ 16]: CSEQ: 102 INVITE [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 4 [ 54]: CALL-ID: 53e9782a3e47a9ac34669ccd0f008cee@192.168.20.1 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 5 [ 63]: VIA: SIP/2.0/TCP 192.168.20.1:5060;branch=z9hG4bK38e4beb6;rport [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 6 [ 17]: CONTENT-LENGTH: 0 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 7 [ 0]: [Jul 22 14:22:55] VERBOSE[27648] logger.c: <--- SIP read from TCP://192.168.20.3:5060 ---> SIP/2.0 100 Trying FROM: "Unknown Name";tag=as034aede3 TO: CSEQ: 102 INVITE CALL-ID: 53e9782a3e47a9ac34669ccd0f008cee@192.168.20.1 VIA: SIP/2.0/TCP 192.168.20.1:5060;branch=z9hG4bK38e4beb6;rport CONTENT-LENGTH: 0 <-------------> [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 0 [ 18]: SIP/2.0 100 Trying [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 1 [ 64]: FROM: "Unknown Name";tag=as034aede3 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 2 [ 24]: TO: [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 3 [ 16]: CSEQ: 102 INVITE [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 4 [ 54]: CALL-ID: 53e9782a3e47a9ac34669ccd0f008cee@192.168.20.1 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 5 [ 63]: VIA: SIP/2.0/TCP 192.168.20.1:5060;branch=z9hG4bK38e4beb6;rport [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 6 [ 17]: CONTENT-LENGTH: 0 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 7 [ 0]: [Jul 22 14:22:55] VERBOSE[27648] logger.c: --- (7 headers 0 lines) --- [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: = Found Their Call ID: 53e9782a3e47a9ac34669ccd0f008cee@192.168.20.1 Their Tag Our tag: as034aede3 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '53e9782a3e47a9ac34669ccd0f008cee@192.168.20.1' Request 102: Not Found [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: SIP response 100 to standard invite [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 0 [ 29]: SIP/2.0 302 Moved Temporarily [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 1 [ 64]: FROM: "Unknown Name";tag=as034aede3 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 2 [ 39]: TO: ;tag=1eeb8e4ccc [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 3 [ 16]: CSEQ: 102 INVITE [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 4 [ 54]: CALL-ID: 53e9782a3e47a9ac34669ccd0f008cee@192.168.20.1 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 5 [ 63]: VIA: SIP/2.0/TCP 192.168.20.1:5060;branch=z9hG4bK38e4beb6;rport [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 6 [129]: CONTACT: [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 7 [ 17]: CONTENT-LENGTH: 0 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 8 [ 20]: SERVER: RTCC/3.0.0.0 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 9 [ 0]: [Jul 22 14:22:55] VERBOSE[27648] logger.c: <--- SIP read from TCP://192.168.20.3:5060 ---> SIP/2.0 302 Moved Temporarily FROM: "Unknown Name";tag=as034aede3 TO: ;tag=1eeb8e4ccc CSEQ: 102 INVITE CALL-ID: 53e9782a3e47a9ac34669ccd0f008cee@192.168.20.1 VIA: SIP/2.0/TCP 192.168.20.1:5060;branch=z9hG4bK38e4beb6;rport CONTACT: CONTENT-LENGTH: 0 SERVER: RTCC/3.0.0.0 <-------------> [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 0 [ 29]: SIP/2.0 302 Moved Temporarily [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 1 [ 64]: FROM: "Unknown Name";tag=as034aede3 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 2 [ 39]: TO: ;tag=1eeb8e4ccc [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 3 [ 16]: CSEQ: 102 INVITE [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 4 [ 54]: CALL-ID: 53e9782a3e47a9ac34669ccd0f008cee@192.168.20.1 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 5 [ 63]: VIA: SIP/2.0/TCP 192.168.20.1:5060;branch=z9hG4bK38e4beb6;rport [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 6 [129]: CONTACT: [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 7 [ 17]: CONTENT-LENGTH: 0 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 8 [ 20]: SERVER: RTCC/3.0.0.0 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 9 [ 0]: [Jul 22 14:22:55] VERBOSE[27648] logger.c: --- (9 headers 0 lines) --- [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: = Found Their Call ID: 53e9782a3e47a9ac34669ccd0f008cee@192.168.20.1 Their Tag Our tag: as034aede3 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Stopping retransmission on '53e9782a3e47a9ac34669ccd0f008cee@192.168.20.1' of Request 102: Match Not Found [Jul 22 14:22:55] VERBOSE[27648] logger.c: -- Got SIP response 302 "Moved Temporarily" back from 192.168.20.3 [Jul 22 14:22:55] ERROR[27648] astobj2.c: bad magic number 0xdeadbeef for 0x826d708 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Found promiscuous redirection to 'SIP/::::TCP@sv0071iv.voice:5070' [Jul 22 14:22:55] VERBOSE[27648] logger.c: Transmitting (no NAT) to 192.168.20.3:5060: ACK sip:sv0071iv.voice SIP/2.0 Via: SIP/2.0/TCP 192.168.20.1:5060;branch=z9hG4bK38e4beb6;rport Max-Forwards: 70 From: "Unknown Name" ;tag=as034aede3 To: ;tag=1eeb8e4ccc Contact: Call-ID: 53e9782a3e47a9ac34669ccd0f008cee@192.168.20.1 CSeq: 102 ACK User-Agent: Asterisk PBX 1.6.0-beta9 Content-Length: 0 --- [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 0 [ 30]: ACK sip:sv0071iv.voice SIP/2.0 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 1 [ 63]: Via: SIP/2.0/TCP 192.168.20.1:5060;branch=z9hG4bK38e4beb6;rport [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 3 [ 65]: From: "Unknown Name" ;tag=as034aede3 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 4 [ 39]: To: ;tag=1eeb8e4ccc [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 5 [ 57]: Contact: [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 6 [ 54]: Call-ID: 53e9782a3e47a9ac34669ccd0f008cee@192.168.20.1 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 7 [ 13]: CSeq: 102 ACK [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 8 [ 36]: User-Agent: Asterisk PBX 1.6.0-beta9 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 9 [ 17]: Content-Length: 0 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 10 [ 0]: [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Trying to put 'ACK sip:sv' onto TCP socket... [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Setting SIP_ALREADYGONE on dialog 53e9782a3e47a9ac34669ccd0f008cee@192.168.20.1 [Jul 22 14:22:55] VERBOSE[27648] logger.c: -- Now forwarding IAX2/209.217.98.230:4569-15446 to 'SIP/::::TCP@sv0071iv.voice:5070' (thanks to SIP/sv0071ivr-08276a88) [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Asked to create a SIP channel with formats: 0x4 (ulaw) [Jul 22 14:22:55] VERBOSE[27648] logger.c: == Using SIP RTP CoS mark 5 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - INVITE (With RTP) [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: OBPROXY: Not applying OBproxy to this call [Jul 22 14:22:55] DEBUG[27648] acl.c: Found IP address for this socket [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: *** Our native formats are 0x4 (ulaw) [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: *** Joint capabilities are 0x4 (ulaw) [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: *** Our capabilities are 0x6 (gsm|ulaw) [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: *** AST_CODEC_CHOOSE formats are 0x4 (ulaw) [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: *** Our preferred formats from the incoming channel are 0x4 (ulaw) [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: This channel will not be able to handle video. [Jul 22 14:22:55] DEBUG[27648] rtp.c: Channel 'IAX2/209.217.98.230:4569-15446' has no RTP, not doing anything [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Outgoing Call for [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Updating call counter for outgoing call [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Our T38 capability (0), joint T38 capability (0) [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: ** Our capability: 0x4 (ulaw) Video flag: False Text flag: False [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: ** Our prefcodec: 0x4 (ulaw) [Jul 22 14:22:55] VERBOSE[27648] logger.c: Audio is at 192.168.20.1 port 17494 [Jul 22 14:22:55] VERBOSE[27648] logger.c: Adding codec 0x4 (ulaw) to SDP [Jul 22 14:22:55] VERBOSE[27648] logger.c: Adding non-codec 0x1 (telephone-event) to SDP [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: -- Done with adding codecs to SDP [Jul 22 14:22:55] DEBUG[27648] channel.c: Internal timing is disabled (option_internal_timing=0 chan->timingfd=78) [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Done building SDP. Settling with this capability: 0x4 (ulaw) [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Initializing initreq for method INVITE - callid 1b76b1ba36fc18f91d8b811d68d0eb6b@192.168.20.1 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 0 [ 38]: INVITE sip:sv0071iv.voice:5070 SIP/2.0 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 1 [ 63]: Via: SIP/2.0/TCP 192.168.20.1:5060;branch=z9hG4bK0badd7d6;rport [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 3 [ 67]: From: "Unknown Name" ;tag=as22b6d950 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 4 [ 29]: To: [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 5 [ 54]: Contact: [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 6 [ 54]: Call-ID: 1b76b1ba36fc18f91d8b811d68d0eb6b@192.168.20.1 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 7 [ 16]: CSeq: 102 INVITE [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 8 [ 36]: User-Agent: Asterisk PBX 1.6.0-beta9 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 9 [ 35]: Date: Tue, 22 Jul 2008 18:22:55 GMT [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 10 [ 66]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 11 [ 26]: Supported: replaces, timer [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 12 [ 29]: Content-Type: application/sdp [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 13 [ 19]: Content-Length: 265 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 14 [ 0]: [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Body 0 [ 3]: v=0 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Body 1 [ 46]: o=root 633011042 633011042 IN IP4 192.168.20.1 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Body 2 [ 26]: s=Asterisk PBX 1.6.0-beta9 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Body 3 [ 21]: c=IN IP4 192.168.20.1 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Body 4 [ 5]: t=0 0 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Body 5 [ 27]: m=audio 17494 RTP/AVP 0 101 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Body 6 [ 20]: a=rtpmap:0 PCMU/8000 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Body 7 [ 33]: a=rtpmap:101 telephone-event/8000 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Body 8 [ 15]: a=fmtp:101 0-16 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Body 9 [ 25]: a=silenceSupp:off - - - - [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Body 10 [ 10]: a=ptime:20 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Body 11 [ 10]: a=sendrecv [Jul 22 14:22:55] VERBOSE[27648] logger.c: Reliably Transmitting (no NAT) to 192.168.20.3:5070: INVITE sip:sv0071iv.voice:5070 SIP/2.0 Via: SIP/2.0/TCP 192.168.20.1:5060;branch=z9hG4bK0badd7d6;rport Max-Forwards: 70 From: "Unknown Name" ;tag=as22b6d950 To: Contact: Call-ID: 1b76b1ba36fc18f91d8b811d68d0eb6b@192.168.20.1 CSeq: 102 INVITE User-Agent: Asterisk PBX 1.6.0-beta9 Date: Tue, 22 Jul 2008 18:22:55 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces, timer Content-Type: application/sdp Content-Length: 265 v=0 o=root 633011042 633011042 IN IP4 192.168.20.1 s=Asterisk PBX 1.6.0-beta9 c=IN IP4 192.168.20.1 t=0 0 m=audio 17494 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv --- [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 0 [ 38]: INVITE sip:sv0071iv.voice:5070 SIP/2.0 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 1 [ 63]: Via: SIP/2.0/TCP 192.168.20.1:5060;branch=z9hG4bK0badd7d6;rport [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 3 [ 67]: From: "Unknown Name" ;tag=as22b6d950 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 4 [ 29]: To: [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 5 [ 54]: Contact: [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 6 [ 54]: Call-ID: 1b76b1ba36fc18f91d8b811d68d0eb6b@192.168.20.1 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 7 [ 16]: CSeq: 102 INVITE [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 8 [ 36]: User-Agent: Asterisk PBX 1.6.0-beta9 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 9 [ 35]: Date: Tue, 22 Jul 2008 18:22:55 GMT [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 10 [ 66]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 11 [ 26]: Supported: replaces, timer [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 12 [ 29]: Content-Type: application/sdp [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 13 [ 19]: Content-Length: 265 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 14 [ 0]: [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Body 0 [ 3]: v=0 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Body 1 [ 46]: o=root 633011042 633011042 IN IP4 192.168.20.1 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Body 2 [ 26]: s=Asterisk PBX 1.6.0-beta9 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Body 3 [ 21]: c=IN IP4 192.168.20.1 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Body 4 [ 5]: t=0 0 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Body 5 [ 27]: m=audio 17494 RTP/AVP 0 101 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Body 6 [ 20]: a=rtpmap:0 PCMU/8000 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Body 7 [ 33]: a=rtpmap:101 telephone-event/8000 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Body 8 [ 15]: a=fmtp:101 0-16 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Body 9 [ 25]: a=silenceSupp:off - - - - [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Body 10 [ 10]: a=ptime:20 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Body 11 [ 10]: a=sendrecv [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Trying to put 'INVITE sip' onto TCP socket... [Jul 22 14:22:55] DEBUG[27648] channel.c: Hanging up channel 'SIP/sv0071ivr-08276a88' [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Hangup call SIP/sv0071ivr-08276a88, SIP callid 53e9782a3e47a9ac34669ccd0f008cee@192.168.20.1 [Jul 22 14:22:55] DEBUG[27648] devicestate.c: Notification of state change to be queued on device/channel SIP/sv0071ivr-08276a88 [Jul 22 14:22:55] DEBUG[27648] devicestate.c: Notification of state change to be queued on device/channel SIP/sv0071ivr [Jul 22 14:22:55] DEBUG[27648] devicestate.c: No provider found, checking channel drivers for SIP - sv0071ivr-08276a88 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Checking device state for peer sv0071ivr-08276a88 [Jul 22 14:22:55] DEBUG[27648] devicestate.c: Changing state for SIP/sv0071ivr-08276a88 - state 1 (Not in use) [Jul 22 14:22:55] DEBUG[27648] devicestate.c: No provider found, checking channel drivers for SIP - sv0071ivr [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Checking device state for peer sv0071ivr [Jul 22 14:22:55] DEBUG[27648] devicestate.c: Changing state for SIP/sv0071ivr - state 1 (Not in use) [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 0 [ 18]: SIP/2.0 100 Trying [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 1 [ 66]: FROM: "Unknown Name";tag=as22b6d950 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 2 [ 29]: TO: [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 3 [ 16]: CSEQ: 102 INVITE [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 4 [ 54]: CALL-ID: 1b76b1ba36fc18f91d8b811d68d0eb6b@192.168.20.1 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 5 [ 63]: VIA: SIP/2.0/TCP 192.168.20.1:5060;branch=z9hG4bK0badd7d6;rport [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 6 [ 17]: CONTENT-LENGTH: 0 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 7 [ 0]: [Jul 22 14:22:55] VERBOSE[27648] logger.c: <--- SIP read from TCP://192.168.20.3:5070 ---> SIP/2.0 100 Trying FROM: "Unknown Name";tag=as22b6d950 TO: CSEQ: 102 INVITE CALL-ID: 1b76b1ba36fc18f91d8b811d68d0eb6b@192.168.20.1 VIA: SIP/2.0/TCP 192.168.20.1:5060;branch=z9hG4bK0badd7d6;rport CONTENT-LENGTH: 0 <-------------> [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 0 [ 18]: SIP/2.0 100 Trying [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 1 [ 66]: FROM: "Unknown Name";tag=as22b6d950 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 2 [ 29]: TO: [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 3 [ 16]: CSEQ: 102 INVITE [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 4 [ 54]: CALL-ID: 1b76b1ba36fc18f91d8b811d68d0eb6b@192.168.20.1 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 5 [ 63]: VIA: SIP/2.0/TCP 192.168.20.1:5060;branch=z9hG4bK0badd7d6;rport [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 6 [ 17]: CONTENT-LENGTH: 0 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 7 [ 0]: [Jul 22 14:22:55] VERBOSE[27648] logger.c: --- (7 headers 0 lines) --- [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: = Found Their Call ID: 1b76b1ba36fc18f91d8b811d68d0eb6b@192.168.20.1 Their Tag Our tag: as22b6d950 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '1b76b1ba36fc18f91d8b811d68d0eb6b@192.168.20.1' Request 102: Not Found [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: SIP response 100 to standard invite [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 0 [ 19]: SIP/2.0 180 Ringing [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 1 [ 66]: FROM: "Unknown Name";tag=as22b6d950 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 2 [ 60]: TO: ;epid=21D3652D3D;tag=59ac48a8f6 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 3 [ 16]: CSEQ: 102 INVITE [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 4 [ 54]: CALL-ID: 1b76b1ba36fc18f91d8b811d68d0eb6b@192.168.20.1 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 5 [ 63]: VIA: SIP/2.0/TCP 192.168.20.1:5060;branch=z9hG4bK0badd7d6;rport [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 6 [ 17]: CONTENT-LENGTH: 0 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 7 [ 20]: SERVER: RTCC/3.0.0.0 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 8 [ 0]: [Jul 22 14:22:55] VERBOSE[27648] logger.c: <--- SIP read from TCP://192.168.20.3:5070 ---> SIP/2.0 180 Ringing FROM: "Unknown Name";tag=as22b6d950 TO: ;epid=21D3652D3D;tag=59ac48a8f6 CSEQ: 102 INVITE CALL-ID: 1b76b1ba36fc18f91d8b811d68d0eb6b@192.168.20.1 VIA: SIP/2.0/TCP 192.168.20.1:5060;branch=z9hG4bK0badd7d6;rport CONTENT-LENGTH: 0 SERVER: RTCC/3.0.0.0 <-------------> [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 0 [ 19]: SIP/2.0 180 Ringing [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 1 [ 66]: FROM: "Unknown Name";tag=as22b6d950 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 2 [ 60]: TO: ;epid=21D3652D3D;tag=59ac48a8f6 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 3 [ 16]: CSEQ: 102 INVITE [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 4 [ 54]: CALL-ID: 1b76b1ba36fc18f91d8b811d68d0eb6b@192.168.20.1 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 5 [ 63]: VIA: SIP/2.0/TCP 192.168.20.1:5060;branch=z9hG4bK0badd7d6;rport [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 6 [ 17]: CONTENT-LENGTH: 0 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 7 [ 20]: SERVER: RTCC/3.0.0.0 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 8 [ 0]: [Jul 22 14:22:55] VERBOSE[27648] logger.c: --- (8 headers 0 lines) --- [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: = Found Their Call ID: 1b76b1ba36fc18f91d8b811d68d0eb6b@192.168.20.1 Their Tag Our tag: as22b6d950 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '1b76b1ba36fc18f91d8b811d68d0eb6b@192.168.20.1' Request 102: Not Found [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: SIP response 180 to standard invite [Jul 22 14:22:55] DEBUG[27648] devicestate.c: Notification of state change to be queued on device/channel SIP/sv0071iv.voice:5070-0827c980 [Jul 22 14:22:55] DEBUG[27648] devicestate.c: Notification of state change to be queued on device/channel SIP/sv0071iv.voice:5070 [Jul 22 14:22:55] DEBUG[27648] devicestate.c: No provider found, checking channel drivers for SIP - sv0071iv.voice:5070-0827c980 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Checking device state for peer sv0071iv.voice:5070-0827c980 [Jul 22 14:22:55] VERBOSE[27648] logger.c: -- SIP/sv0071iv.voice:5070-0827c980 is ringing [Jul 22 14:22:55] DEBUG[27648] devicestate.c: Changing state for SIP/sv0071iv.voice:5070-0827c980 - state 1 (Not in use) [Jul 22 14:22:55] DEBUG[27648] devicestate.c: No provider found, checking channel drivers for SIP - sv0071iv.voice:5070 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Checking device state for peer sv0071iv.voice:5070 [Jul 22 14:22:55] DEBUG[27648] devicestate.c: Changing state for SIP/sv0071iv.voice:5070 - state 6 (Ringing) [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 0 [ 14]: SIP/2.0 200 OK [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 1 [ 66]: FROM: "Unknown Name";tag=as22b6d950 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 2 [ 60]: TO: ;epid=21D3652D3D;tag=59ac48a8f6 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 3 [ 16]: CSEQ: 102 INVITE [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 4 [ 54]: CALL-ID: 1b76b1ba36fc18f91d8b811d68d0eb6b@192.168.20.1 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 5 [ 63]: VIA: SIP/2.0/TCP 192.168.20.1:5060;branch=z9hG4bK0badd7d6;rport [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 6 [ 94]: CONTACT: ;automata [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 7 [ 19]: CONTENT-LENGTH: 192 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 8 [ 29]: CONTENT-TYPE: application/sdp [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 9 [ 13]: ALLOW: UPDATE [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 10 [ 20]: SERVER: RTCC/3.0.0.0 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 11 [ 68]: ALLOW: Ack, Cancel, Bye,Invite,Message,Info,Service,Options,BeNotify [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 12 [ 0]: [Jul 22 14:22:55] VERBOSE[27648] logger.c: <--- SIP read from TCP://192.168.20.3:5070 ---> SIP/2.0 200 OK FROM: "Unknown Name";tag=as22b6d950 TO: ;epid=21D3652D3D;tag=59ac48a8f6 CSEQ: 102 INVITE CALL-ID: 1b76b1ba36fc18f91d8b811d68d0eb6b@192.168.20.1 VIA: SIP/2.0/TCP 192.168.20.1:5060;branch=z9hG4bK0badd7d6;rport CONTACT: ;automata CONTENT-LENGTH: 192 CONTENT-TYPE: application/sdp ALLOW: UPDATE SERVER: RTCC/3.0.0.0 ALLOW: Ack, Cancel, Bye,Invite,Message,Info,Service,Options,BeNotify v=0 o=- 0 0 IN IP4 192.168.20.3 s=Microsoft Speech Server session c=IN IP4 192.168.20.3 t=0 0 m=audio 64256 RTP/AVP 0 101 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 <-------------> [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 0 [ 14]: SIP/2.0 200 OK [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 1 [ 66]: FROM: "Unknown Name";tag=as22b6d950 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 2 [ 60]: TO: ;epid=21D3652D3D;tag=59ac48a8f6 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 3 [ 16]: CSEQ: 102 INVITE [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 4 [ 54]: CALL-ID: 1b76b1ba36fc18f91d8b811d68d0eb6b@192.168.20.1 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 5 [ 63]: VIA: SIP/2.0/TCP 192.168.20.1:5060;branch=z9hG4bK0badd7d6;rport [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 6 [ 94]: CONTACT: ;automata [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 7 [ 19]: CONTENT-LENGTH: 192 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 8 [ 29]: CONTENT-TYPE: application/sdp [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 9 [ 13]: ALLOW: UPDATE [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 10 [ 20]: SERVER: RTCC/3.0.0.0 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 11 [ 68]: ALLOW: Ack, Cancel, Bye,Invite,Message,Info,Service,Options,BeNotify [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 12 [ 0]: [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Body 0 [ 3]: v=0 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Body 1 [ 27]: o=- 0 0 IN IP4 192.168.20.3 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Body 2 [ 33]: s=Microsoft Speech Server session [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Body 3 [ 21]: c=IN IP4 192.168.20.3 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Body 4 [ 5]: t=0 0 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Body 5 [ 27]: m=audio 64256 RTP/AVP 0 101 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Body 6 [ 33]: a=rtpmap:101 telephone-event/8000 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Body 7 [ 15]: a=fmtp:101 0-16 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Body 8 [ 10]: a=ptime:20 [Jul 22 14:22:55] VERBOSE[27648] logger.c: --- (12 headers 9 lines) --- [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: = Found Their Call ID: 1b76b1ba36fc18f91d8b811d68d0eb6b@192.168.20.1 Their Tag 59ac48a8f6 Our tag: as22b6d950 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Stopping retransmission on '1b76b1ba36fc18f91d8b811d68d0eb6b@192.168.20.1' of Request 102: Match Not Found [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: SIP response 200 to standard invite [Jul 22 14:22:55] VERBOSE[27648] logger.c: Found RTP audio format 0 [Jul 22 14:22:55] VERBOSE[27648] logger.c: Found RTP audio format 101 [Jul 22 14:22:55] VERBOSE[27648] logger.c: Peer audio RTP is at port 192.168.20.3:64256 [Jul 22 14:22:55] VERBOSE[27648] logger.c: Found audio description format telephone-event for ID 101 [Jul 22 14:22:55] VERBOSE[27648] logger.c: Got unsupported a:fmtp in SDP offer [Jul 22 14:22:55] VERBOSE[27648] logger.c: Capabilities: us - 0x6 (gsm|ulaw), peer - audio=0x4 (ulaw)/video=0x0 (nothing)/text=0x0 (nothing), combined - 0x4 (ulaw) [Jul 22 14:22:55] VERBOSE[27648] logger.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) [Jul 22 14:22:55] VERBOSE[27648] logger.c: Peer audio RTP is at port 192.168.20.3:64256 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: We're settling with these formats: 0x4 (ulaw) [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: We have an owner, now see if we need to change this call [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Updating call counter for outgoing call [Jul 22 14:22:55] VERBOSE[27648] logger.c: --- set_address_from_contact host 'sv0071iv.internal.veridian.on.ca' [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: build_route: Contact hop: ;automata [Jul 22 14:22:55] VERBOSE[27648] logger.c: list_route: hop: [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Strict routing enforced for session 1b76b1ba36fc18f91d8b811d68d0eb6b@192.168.20.1 [Jul 22 14:22:55] VERBOSE[27648] logger.c: set_destination: Parsing for address/port to send to [Jul 22 14:22:55] VERBOSE[27648] logger.c: set_destination: set destination to 192.168.20.3, port 5070 [Jul 22 14:22:55] VERBOSE[27648] logger.c: Transmitting (no NAT) to 192.168.20.3:5070: ACK sip:sv0071iv.internal.veridian.on.ca:5070;transport=Tcp;maddr=192.168.20.3 SIP/2.0 Via: SIP/2.0/TCP 192.168.20.1:5060;branch=z9hG4bK335573fc;rport Max-Forwards: 70 From: "Unknown Name" ;tag=as22b6d950 To: ;tag=59ac48a8f6 Contact: Call-ID: 1b76b1ba36fc18f91d8b811d68d0eb6b@192.168.20.1 CSeq: 102 ACK User-Agent: Asterisk PBX 1.6.0-beta9 Content-Length: 0 --- [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 0 [ 86]: ACK sip:sv0071iv.internal.veridian.on.ca:5070;transport=Tcp;maddr=192.168.20.3 SIP/2.0 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 1 [ 63]: Via: SIP/2.0/TCP 192.168.20.1:5060;branch=z9hG4bK335573fc;rport [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 3 [ 67]: From: "Unknown Name" ;tag=as22b6d950 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 4 [ 44]: To: ;tag=59ac48a8f6 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 5 [ 54]: Contact: [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 6 [ 54]: Call-ID: 1b76b1ba36fc18f91d8b811d68d0eb6b@192.168.20.1 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 7 [ 13]: CSeq: 102 ACK [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 8 [ 36]: User-Agent: Asterisk PBX 1.6.0-beta9 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 9 [ 17]: Content-Length: 0 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Header 10 [ 0]: [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Trying to put 'ACK sip:sv' onto TCP socket... [Jul 22 14:22:55] DEBUG[27648] devicestate.c: Notification of state change to be queued on device/channel SIP/sv0071iv.voice:5070-0827c980 [Jul 22 14:22:55] DEBUG[27648] devicestate.c: No provider found, checking channel drivers for SIP - sv0071iv.voice:5070-0827c980 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Checking device state for peer sv0071iv.voice:5070-0827c980 [Jul 22 14:22:55] DEBUG[27648] devicestate.c: Changing state for SIP/sv0071iv.voice:5070-0827c980 - state 1 (Not in use) [Jul 22 14:22:55] DEBUG[27648] devicestate.c: Notification of state change to be queued on device/channel SIP/sv0071iv.voice:5070 [Jul 22 14:22:55] DEBUG[27648] devicestate.c: No provider found, checking channel drivers for SIP - sv0071iv.voice:5070 [Jul 22 14:22:55] DEBUG[27648] chan_sip.c: Checking device state for peer sv0071iv.voice:5070 [Jul 22 14:22:55] DEBUG[27648] channel.c: Avoiding initial deadlock for channel '0x8280fe0' [Jul 22 14:22:55] VERBOSE[27648] logger.c: -- SIP/sv0071iv.voice:5070-0827c980 answered IAX2/209.217.98.230:4569-15446 [Jul 22 14:22:55] DEBUG[27648] devicestate.c: Changing state for SIP/sv0071iv.voice:5070 - state 2 (In use) [Jul 22 14:22:55] DEBUG[27648] chan_iax2.c: Answering IAX2 call [Jul 22 14:22:55] DEBUG[27648] devicestate.c: Notification of state change to be queued on device/channel IAX2/209.217.98.230:4569-15446 [Jul 22 14:22:55] DEBUG[27648] devicestate.c: Notification of state change to be queued on device/channel IAX2/209.217.98.230:4569 [Jul 22 14:22:55] DEBUG[27648] devicestate.c: No provider found, checking channel drivers for IAX2 - 209.217.98.230:4569-15446 [Jul 22 14:22:55] DEBUG[27648] chan_iax2.c: Checking device state for device 209.217.98.230 [Jul 22 14:22:55] DEBUG[27648] devicestate.c: Changing state for IAX2/209.217.98.230:4569-15446 - state 4 (Invalid) [Jul 22 14:22:55] DEBUG[27648] devicestate.c: No provider found, checking channel drivers for IAX2 - 209.217.98.230:4569 [Jul 22 14:22:55] DEBUG[27648] chan_iax2.c: Checking device state for device 209.217.98.230 [Jul 22 14:22:55] DEBUG[27648] devicestate.c: Changing state for IAX2/209.217.98.230:4569 - state 4 (Invalid) [Jul 22 14:22:55] DEBUG[27648] chan_iax2.c: Ooh, voice format changed to 4 [Jul 22 14:22:55] DEBUG[27648] channel.c: Set channel IAX2/209.217.98.230:4569-15446 to read format ulaw [Jul 22 14:22:56] DEBUG[27648] rtp.c: Ooh, format changed from unknown to ulaw [Jul 22 14:22:56] DEBUG[27648] rtp.c: Created smoother: format: 4 ms: 20 len: 160 [Jul 22 14:22:56] VERBOSE[27648] logger.c: Really destroying SIP dialog '53e9782a3e47a9ac34669ccd0f008cee@192.168.20.1' Method: INVITE [Jul 22 14:22:58] DEBUG[27648] rtp.c: Got RTCP report of 28 bytes [Jul 22 14:22:58] DEBUG[27648] rtp.c: Got RTCP report of 112 bytes [Jul 22 14:23:01] DEBUG[27648] rtp.c: Got RTCP report of 28 bytes [Jul 22 14:23:01] DEBUG[27648] rtp.c: Got RTCP report of 112 bytes [Jul 22 14:23:01] DEBUG[27648] rtp.c: Got RTCP report of 28 bytes [Jul 22 14:23:01] DEBUG[27648] rtp.c: Got RTCP report of 112 bytes [Jul 22 14:23:01] DEBUG[27648] rtp.c: Got RTCP report of 28 bytes [Jul 22 14:23:01] DEBUG[27648] rtp.c: Got RTCP report of 112 bytes [Jul 22 14:23:02] DEBUG[27648] rtp.c: Got RTCP report of 28 bytes [Jul 22 14:23:02] DEBUG[27648] rtp.c: Got RTCP report of 112 bytes [Jul 22 14:23:02] DEBUG[27648] chan_iax2.c: Immediately destroying 15446, having received hangup [Jul 22 14:23:02] DEBUG[27648] channel.c: Didn't get a frame from channel: IAX2/209.217.98.230:4569-15446 [Jul 22 14:23:02] DEBUG[27648] channel.c: Bridge stops bridging channels IAX2/209.217.98.230:4569-15446 and SIP/sv0071iv.voice:5070-0827c980 [Jul 22 14:23:02] DEBUG[27648] channel.c: Hanging up channel 'SIP/sv0071iv.voice:5070-0827c980' [Jul 22 14:23:02] DEBUG[27648] chan_sip.c: Hangup call SIP/sv0071iv.voice:5070-0827c980, SIP callid 1b76b1ba36fc18f91d8b811d68d0eb6b@192.168.20.1 [Jul 22 14:23:02] VERBOSE[27648] logger.c: Scheduling destruction of SIP dialog '1b76b1ba36fc18f91d8b811d68d0eb6b@192.168.20.1' in 32000 ms (Method: INVITE) [Jul 22 14:23:02] DEBUG[27648] chan_sip.c: Strict routing enforced for session 1b76b1ba36fc18f91d8b811d68d0eb6b@192.168.20.1 [Jul 22 14:23:02] VERBOSE[27648] logger.c: set_destination: Parsing for address/port to send to [Jul 22 14:23:02] VERBOSE[27648] logger.c: set_destination: set destination to 192.168.20.3, port 5070 [Jul 22 14:23:02] VERBOSE[27648] logger.c: Reliably Transmitting (no NAT) to 192.168.20.3:5070: BYE sip:sv0071iv.internal.veridian.on.ca:5070;transport=Tcp;maddr=192.168.20.3 SIP/2.0 Via: SIP/2.0/TCP 192.168.20.1:5060;branch=z9hG4bK6f46f39d;rport Max-Forwards: 70 From: "Unknown Name" ;tag=as22b6d950 To: ;tag=59ac48a8f6 Call-ID: 1b76b1ba36fc18f91d8b811d68d0eb6b@192.168.20.1 CSeq: 103 BYE User-Agent: Asterisk PBX 1.6.0-beta9 Content-Length: 0 --- [Jul 22 14:23:02] DEBUG[27648] chan_sip.c: Header 0 [ 86]: BYE sip:sv0071iv.internal.veridian.on.ca:5070;transport=Tcp;maddr=192.168.20.3 SIP/2.0 [Jul 22 14:23:02] DEBUG[27648] chan_sip.c: Header 1 [ 63]: Via: SIP/2.0/TCP 192.168.20.1:5060;branch=z9hG4bK6f46f39d;rport [Jul 22 14:23:02] DEBUG[27648] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [Jul 22 14:23:02] DEBUG[27648] chan_sip.c: Header 3 [ 67]: From: "Unknown Name" ;tag=as22b6d950 [Jul 22 14:23:02] DEBUG[27648] chan_sip.c: Header 4 [ 44]: To: ;tag=59ac48a8f6 [Jul 22 14:23:02] DEBUG[27648] chan_sip.c: Header 5 [ 54]: Call-ID: 1b76b1ba36fc18f91d8b811d68d0eb6b@192.168.20.1 [Jul 22 14:23:02] DEBUG[27648] chan_sip.c: Header 6 [ 13]: CSeq: 103 BYE [Jul 22 14:23:02] DEBUG[27648] chan_sip.c: Header 7 [ 36]: User-Agent: Asterisk PBX 1.6.0-beta9 [Jul 22 14:23:02] DEBUG[27648] chan_sip.c: Header 8 [ 17]: Content-Length: 0 [Jul 22 14:23:02] DEBUG[27648] chan_sip.c: Header 9 [ 0]: [Jul 22 14:23:02] DEBUG[27648] chan_sip.c: Trying to put 'BYE sip:sv' onto TCP socket... [Jul 22 14:23:02] DEBUG[27648] devicestate.c: Notification of state change to be queued on device/channel SIP/sv0071iv.voice:5070-0827c980 [Jul 22 14:23:02] DEBUG[27648] devicestate.c: Notification of state change to be queued on device/channel SIP/sv0071iv.voice:5070 [Jul 22 14:23:02] DEBUG[27648] app_dial.c: Exiting with DIALSTATUS=ANSWER. [Jul 22 14:23:02] DEBUG[27648] pbx.c: Spawn extension (from-iax,6136274820,1) exited non-zero on 'IAX2/209.217.98.230:4569-15446' [Jul 22 14:23:02] VERBOSE[27648] logger.c: == Spawn extension (from-iax, 6136274820, 1) exited non-zero on 'IAX2/209.217.98.230:4569-15446' [Jul 22 14:23:02] DEBUG[27648] channel.c: Soft-Hanging up channel 'IAX2/209.217.98.230:4569-15446' [Jul 22 14:23:02] DEBUG[27648] channel.c: Hanging up channel 'IAX2/209.217.98.230:4569-15446' [Jul 22 14:23:02] DEBUG[27648] chan_iax2.c: We're hanging up IAX2/209.217.98.230:4569-15446 now... [Jul 22 14:23:02] DEBUG[27648] chan_iax2.c: Really destroying IAX2/209.217.98.230:4569-15446 now... [Jul 22 14:23:02] VERBOSE[27648] logger.c: -- Hungup 'IAX2/209.217.98.230:4569-15446' [Jul 22 14:23:02] DEBUG[27648] devicestate.c: No provider found, checking channel drivers for SIP - sv0071iv.voice:5070-0827c980 [Jul 22 14:23:02] DEBUG[27648] devicestate.c: Notification of state change to be queued on device/channel IAX2/209.217.98.230:4569-15446 [Jul 22 14:23:02] DEBUG[27648] chan_sip.c: Checking device state for peer sv0071iv.voice:5070-0827c980 [Jul 22 14:23:02] DEBUG[27648] devicestate.c: Notification of state change to be queued on device/channel IAX2/209.217.98.230:4569 [Jul 22 14:23:02] DEBUG[27648] devicestate.c: Changing state for SIP/sv0071iv.voice:5070-0827c980 - state 1 (Not in use) [Jul 22 14:23:02] DEBUG[27648] devicestate.c: No provider found, checking channel drivers for SIP - sv0071iv.voice:5070 [Jul 22 14:23:02] DEBUG[27648] chan_sip.c: Checking device state for peer sv0071iv.voice:5070 [Jul 22 14:23:02] DEBUG[27648] devicestate.c: Changing state for SIP/sv0071iv.voice:5070 - state 1 (Not in use) [Jul 22 14:23:02] DEBUG[27648] devicestate.c: No provider found, checking channel drivers for IAX2 - 209.217.98.230:4569-15446 [Jul 22 14:23:02] DEBUG[27648] chan_iax2.c: Checking device state for device 209.217.98.230 [Jul 22 14:23:02] DEBUG[27648] devicestate.c: Changing state for IAX2/209.217.98.230:4569-15446 - state 4 (Invalid) [Jul 22 14:23:02] DEBUG[27648] devicestate.c: No provider found, checking channel drivers for IAX2 - 209.217.98.230:4569 [Jul 22 14:23:02] DEBUG[27648] chan_iax2.c: Checking device state for device 209.217.98.230 [Jul 22 14:23:02] DEBUG[27648] devicestate.c: Changing state for IAX2/209.217.98.230:4569 - state 4 (Invalid) [Jul 22 14:23:02] DEBUG[27648] chan_sip.c: Header 0 [ 14]: SIP/2.0 200 OK [Jul 22 14:23:02] DEBUG[27648] chan_sip.c: Header 1 [ 66]: FROM: "Unknown Name";tag=as22b6d950 [Jul 22 14:23:02] DEBUG[27648] chan_sip.c: Header 2 [ 60]: TO: ;tag=59ac48a8f6;epid=21D3652D3D [Jul 22 14:23:02] DEBUG[27648] chan_sip.c: Header 3 [ 13]: CSEQ: 103 BYE [Jul 22 14:23:02] DEBUG[27648] chan_sip.c: Header 4 [ 54]: CALL-ID: 1b76b1ba36fc18f91d8b811d68d0eb6b@192.168.20.1 [Jul 22 14:23:02] DEBUG[27648] chan_sip.c: Header 5 [ 63]: VIA: SIP/2.0/TCP 192.168.20.1:5060;branch=z9hG4bK6f46f39d;rport [Jul 22 14:23:02] DEBUG[27648] chan_sip.c: Header 6 [ 17]: CONTENT-LENGTH: 0 [Jul 22 14:23:02] DEBUG[27648] chan_sip.c: Header 7 [ 20]: SERVER: RTCC/3.0.0.0 [Jul 22 14:23:02] DEBUG[27648] chan_sip.c: Header 8 [ 0]: [Jul 22 14:23:02] VERBOSE[27648] logger.c: <--- SIP read from TCP://192.168.20.3:5070 ---> SIP/2.0 200 OK FROM: "Unknown Name";tag=as22b6d950 TO: ;tag=59ac48a8f6;epid=21D3652D3D CSEQ: 103 BYE CALL-ID: 1b76b1ba36fc18f91d8b811d68d0eb6b@192.168.20.1 VIA: SIP/2.0/TCP 192.168.20.1:5060;branch=z9hG4bK6f46f39d;rport CONTENT-LENGTH: 0 SERVER: RTCC/3.0.0.0 <-------------> [Jul 22 14:23:02] DEBUG[27648] chan_sip.c: Header 0 [ 14]: SIP/2.0 200 OK [Jul 22 14:23:02] DEBUG[27648] chan_sip.c: Header 1 [ 66]: FROM: "Unknown Name";tag=as22b6d950 [Jul 22 14:23:02] DEBUG[27648] chan_sip.c: Header 2 [ 60]: TO: ;tag=59ac48a8f6;epid=21D3652D3D [Jul 22 14:23:02] DEBUG[27648] chan_sip.c: Header 3 [ 13]: CSEQ: 103 BYE [Jul 22 14:23:02] DEBUG[27648] chan_sip.c: Header 4 [ 54]: CALL-ID: 1b76b1ba36fc18f91d8b811d68d0eb6b@192.168.20.1 [Jul 22 14:23:02] DEBUG[27648] chan_sip.c: Header 5 [ 63]: VIA: SIP/2.0/TCP 192.168.20.1:5060;branch=z9hG4bK6f46f39d;rport [Jul 22 14:23:02] DEBUG[27648] chan_sip.c: Header 6 [ 17]: CONTENT-LENGTH: 0 [Jul 22 14:23:02] DEBUG[27648] chan_sip.c: Header 7 [ 20]: SERVER: RTCC/3.0.0.0 [Jul 22 14:23:02] DEBUG[27648] chan_sip.c: Header 8 [ 0]: [Jul 22 14:23:02] VERBOSE[27648] logger.c: --- (8 headers 0 lines) --- [Jul 22 14:23:02] DEBUG[27648] chan_sip.c: = Found Their Call ID: 1b76b1ba36fc18f91d8b811d68d0eb6b@192.168.20.1 Their Tag 59ac48a8f6 Our tag: as22b6d950 [Jul 22 14:23:02] DEBUG[27648] chan_sip.c: Stopping retransmission on '1b76b1ba36fc18f91d8b811d68d0eb6b@192.168.20.1' of Request 103: Match Not Found [Jul 22 14:23:03] VERBOSE[27648] logger.c: Really destroying SIP dialog '1b76b1ba36fc18f91d8b811d68d0eb6b@192.168.20.1' Method: INVITE [Jul 22 14:23:16] VERBOSE[27648] logger.c: -- Remote UNIX connection disconnected [Jul 22 14:23:26] DEBUG[27648] chan_iax2.c: Allocate call number [Jul 22 14:23:26] DEBUG[27648] chan_iax2.c: Registration created on call 9536