Jun 21 11:16:52 VERBOSE[4944] logger.c: -- Remote UNIX connection Jun 21 11:16:58 VERBOSE[4963] logger.c: <-- SIP read from 10.2.200.150:2063: INVITE sip:7910@10.253.0.176;user=phone SIP/2.0 Via: SIP/2.0/UDP 10.2.200.150:2063;branch=z9hG4bK-yhdp4xsyggp3;rport From: "7914" ;tag=bck9fswnc8 To: Call-ID: 3c376d536419-hh9gc75x74cz@snom320-000413242B7A CSeq: 1 INVITE Max-Forwards: 70 Contact: ;flow-id=1 P-Key-Flags: keys="3" User-Agent: snom320/5.5 Accept: application/sdp Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO Allow-Events: talk, hold, refer Supported: timer, 100rel, replaces, callerid Session-Expires: 3600;refresher=uas Content-Type: application/sdp Content-Length: 473 v=0 o=root 616753668 616753668 IN IP4 10.2.200.150 s=call c=IN IP4 10.2.200.150 t=0 0 m=audio 57714 RTP/AVP 0 8 9 2 3 18 4 101 a=crypto:1 AES_CM_128_HMAC_SHA1_32 inline:bcrnXBM3o5Mhl5QTdCHb4nu2EUIka1y2xsR8XObK a=rtpmap:0 pcmu/8000 a=rtpmap:8 pcma/8000 a=rtpmap:9 g722/8000 a=rtpmap:2 g726-32/8000 a=rtpmap:3 gsm/8000 a=rtpmap:18 g729/8000 a=rtpmap:4 g723/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 a=encryption:optional a=sendrecv Jun 21 11:16:58 DEBUG[4963] chan_sip.c: Header 0: INVITE sip:7910@10.253.0.176;user=phone SIP/2.0 (47) Jun 21 11:16:58 DEBUG[4963] chan_sip.c: Header 1: Via: SIP/2.0/UDP 10.2.200.150:2063;branch=z9hG4bK-yhdp4xsyggp3;rport (68) Jun 21 11:16:58 DEBUG[4963] chan_sip.c: Header 2: From: "7914" ;tag=bck9fswnc8 (51) Jun 21 11:16:58 DEBUG[4963] chan_sip.c: Header 3: To: (38) Jun 21 11:16:58 DEBUG[4963] chan_sip.c: Header 4: Call-ID: 3c376d536419-hh9gc75x74cz@snom320-000413242B7A (55) Jun 21 11:16:58 DEBUG[4963] chan_sip.c: Header 5: CSeq: 1 INVITE (14) Jun 21 11:16:58 DEBUG[4963] chan_sip.c: Header 6: Max-Forwards: 70 (16) Jun 21 11:16:58 DEBUG[4963] chan_sip.c: Header 7: Contact: ;flow-id=1 (61) Jun 21 11:16:58 DEBUG[4963] chan_sip.c: Header 8: P-Key-Flags: keys="3" (21) Jun 21 11:16:58 DEBUG[4963] chan_sip.c: Header 9: User-Agent: snom320/5.5 (23) Jun 21 11:16:58 DEBUG[4963] chan_sip.c: Header 10: Accept: application/sdp (23) Jun 21 11:16:58 DEBUG[4963] chan_sip.c: Header 11: Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO (88) Jun 21 11:16:58 DEBUG[4963] chan_sip.c: Header 12: Allow-Events: talk, hold, refer (31) Jun 21 11:16:58 DEBUG[4963] chan_sip.c: Header 13: Supported: timer, 100rel, replaces, callerid (44) Jun 21 11:16:58 DEBUG[4963] chan_sip.c: Header 14: Session-Expires: 3600;refresher=uas (35) Jun 21 11:16:58 DEBUG[4963] chan_sip.c: Header 15: Content-Type: application/sdp (29) Jun 21 11:16:58 DEBUG[4963] chan_sip.c: Header 16: Content-Length: 473 (19) Jun 21 11:16:58 DEBUG[4963] chan_sip.c: Header 17: (0) Jun 21 11:16:58 DEBUG[4963] chan_sip.c: Line: v=0 (3) Jun 21 11:16:58 DEBUG[4963] chan_sip.c: Line: o=root 616753668 616753668 IN IP4 10.2.200.150 (46) Jun 21 11:16:58 DEBUG[4963] chan_sip.c: Line: s=call (6) Jun 21 11:16:58 DEBUG[4963] chan_sip.c: Line: c=IN IP4 10.2.200.150 (21) Jun 21 11:16:58 DEBUG[4963] chan_sip.c: Line: t=0 0 (5) Jun 21 11:16:58 DEBUG[4963] chan_sip.c: Line: m=audio 57714 RTP/AVP 0 8 9 2 3 18 4 101 (40) Jun 21 11:16:58 DEBUG[4963] chan_sip.c: Line: a=crypto:1 AES_CM_128_HMAC_SHA1_32 inline:bcrnXBM3o5Mhl5QTdCHb4nu2EUIka1y2xsR8XObK (82) Jun 21 11:16:58 DEBUG[4963] chan_sip.c: Line: a=rtpmap:0 pcmu/8000 (20) Jun 21 11:16:58 DEBUG[4963] chan_sip.c: Line: a=rtpmap:8 pcma/8000 (20) Jun 21 11:16:58 DEBUG[4963] chan_sip.c: Line: a=rtpmap:9 g722/8000 (20) Jun 21 11:16:58 DEBUG[4963] chan_sip.c: Line: a=rtpmap:2 g726-32/8000 (23) Jun 21 11:16:58 DEBUG[4963] chan_sip.c: Line: a=rtpmap:3 gsm/8000 (19) Jun 21 11:16:58 DEBUG[4963] chan_sip.c: Line: a=rtpmap:18 g729/8000 (21) Jun 21 11:16:58 DEBUG[4963] chan_sip.c: Line: a=rtpmap:4 g723/8000 (20) Jun 21 11:16:58 DEBUG[4963] chan_sip.c: Line: a=rtpmap:101 telephone-event/8000 (33) Jun 21 11:16:58 DEBUG[4963] chan_sip.c: Line: a=fmtp:101 0-16 (15) Jun 21 11:16:58 DEBUG[4963] chan_sip.c: Line: a=ptime:20 (10) Jun 21 11:16:58 DEBUG[4963] chan_sip.c: Line: a=encryption:optional (21) Jun 21 11:16:58 DEBUG[4963] chan_sip.c: Line: a=sendrecv (10) Jun 21 11:16:58 VERBOSE[4963] logger.c: --- (17 headers 19 lines)Jun 21 11:16:58 VERBOSE[4963] logger.c: --- (17 headers 19 lines)--- Jun 21 11:16:58 DEBUG[4963] chan_sip.c: Allocating new SIP dialog for 3c376d536419-hh9gc75x74cz@snom320-000413242B7A - INVITE (With RTP) Jun 21 11:16:58 DEBUG[4963] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE Jun 21 11:16:58 DEBUG[4963] chan_sip.c: Begin: parsing SIP "Supported: timer, 100rel, replaces, callerid" Jun 21 11:16:58 DEBUG[4963] chan_sip.c: Found SIP option: -timer- Jun 21 11:16:58 DEBUG[4963] chan_sip.c: Matched SIP option: timer Jun 21 11:16:58 DEBUG[4963] chan_sip.c: Found SIP option: -100rel- Jun 21 11:16:58 DEBUG[4963] chan_sip.c: Matched SIP option: 100rel Jun 21 11:16:58 DEBUG[4963] chan_sip.c: Found SIP option: -replaces- Jun 21 11:16:58 DEBUG[4963] chan_sip.c: Matched SIP option: replaces Jun 21 11:16:58 DEBUG[4963] chan_sip.c: Found SIP option: -callerid- Jun 21 11:16:58 DEBUG[4963] chan_sip.c: Found no match for SIP option: callerid (Please file bug report!) Jun 21 11:16:58 DEBUG[4963] chan_sip.c: * SIP extension value: 7 for call 3c376d536419-hh9gc75x74cz@snom320-000413242B7A Jun 21 11:16:58 VERBOSE[4963] logger.c: Using INVITE request as basis request - 3c376d536419-hh9gc75x74cz@snom320-000413242B7A Jun 21 11:16:58 VERBOSE[4963] logger.c: Sending to 10.2.200.150 : 2063 (NAT) Jun 21 11:16:58 DEBUG[4963] chan_sip.c: Setting NAT on RTP to 0 Jun 21 11:16:58 VERBOSE[4963] logger.c: Reliably Transmitting (no NAT) to 10.2.200.150:2063: SIP/2.0 407 Proxy Authentication Required Via: SIP/2.0/UDP 10.2.200.150:2063;branch=z9hG4bK-yhdp4xsyggp3;rport;received=10.2.200.150 From: "7914" ;tag=bck9fswnc8 To: ;tag=as75e3676f Call-ID: 3c376d536419-hh9gc75x74cz@snom320-000413242B7A CSeq: 1 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Contact: Proxy-Authenticate: Digest realm="asterisk", nonce="2af161ec" Content-Length: 0 --- Jun 21 11:16:58 DEBUG[4963] chan_sip.c: *** SIP TIMER: Initalizing retransmit timer on packet: Id #21 Jun 21 11:16:58 VERBOSE[4963] logger.c: Scheduling destruction of call '3c376d536419-hh9gc75x74cz@snom320-000413242B7A' in 15000 ms Jun 21 11:16:58 VERBOSE[4963] logger.c: Found user '7914' Jun 21 11:16:59 VERBOSE[4963] logger.c: <-- SIP read from 10.2.200.150:2063: ACK sip:7910@10.253.0.176;user=phone SIP/2.0 Via: SIP/2.0/UDP 10.2.200.150:2063;branch=z9hG4bK-yhdp4xsyggp3;rport From: "7914" ;tag=bck9fswnc8 To: ;tag=as75e3676f Call-ID: 3c376d536419-hh9gc75x74cz@snom320-000413242B7A CSeq: 1 ACK Max-Forwards: 70 Contact: ;flow-id=1 Content-Length: 0 Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Header 0: ACK sip:7910@10.253.0.176;user=phone SIP/2.0 (44) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Header 1: Via: SIP/2.0/UDP 10.2.200.150:2063;branch=z9hG4bK-yhdp4xsyggp3;rport (68) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Header 2: From: "7914" ;tag=bck9fswnc8 (51) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Header 3: To: ;tag=as75e3676f (53) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Header 4: Call-ID: 3c376d536419-hh9gc75x74cz@snom320-000413242B7A (55) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Header 5: CSeq: 1 ACK (11) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Header 6: Max-Forwards: 70 (16) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Header 7: Contact: ;flow-id=1 (61) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Header 8: Content-Length: 0 (17) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Header 9: (0) Jun 21 11:16:59 VERBOSE[4963] logger.c: --- (9 headers 0 lines)Jun 21 11:16:59 VERBOSE[4963] logger.c: --- (9 headers 0 lines)--- Jun 21 11:16:59 DEBUG[4963] chan_sip.c: **** Received ACK (6) - Command in SIP ACK Jun 21 11:16:59 DEBUG[4963] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #21 Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Stopping retransmission on '3c376d536419-hh9gc75x74cz@snom320-000413242B7A' of Response 1: Match Found Jun 21 11:16:59 VERBOSE[4963] logger.c: <-- SIP read from 10.2.200.150:2063: INVITE sip:7910@10.253.0.176;user=phone SIP/2.0 Via: SIP/2.0/UDP 10.2.200.150:2063;branch=z9hG4bK-9mrhvk5s7kc3;rport From: "7914" ;tag=bck9fswnc8 To: Call-ID: 3c376d536419-hh9gc75x74cz@snom320-000413242B7A CSeq: 2 INVITE Max-Forwards: 70 Contact: ;flow-id=1 P-Key-Flags: keys="3" User-Agent: snom320/5.5 Accept: application/sdp Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO Allow-Events: talk, hold, refer Supported: timer, 100rel, replaces, callerid Session-Expires: 3600;refresher=uas Proxy-Authorization: Digest username="7914",realm="asterisk",nonce="2af161ec",uri="sip:7910@10.253.0.176;user=phone",response="77dda90845ba8c694fc82a877aeb9b57",algorithm=md5 Content-Type: application/sdp Content-Length: 473 v=0 o=root 616753668 616753668 IN IP4 10.2.200.150 s=call c=IN IP4 10.2.200.150 t=0 0 m=audio 57714 RTP/AVP 0 8 9 2 3 18 4 101 a=crypto:1 AES_CM_128_HMAC_SHA1_32 inline:bcrnXBM3o5Mhl5QTdCHb4nu2EUIka1y2xsR8XObK a=rtpmap:0 pcmu/8000 a=rtpmap:8 pcma/8000 a=rtpmap:9 g722/8000 a=rtpmap:2 g726-32/8000 a=rtpmap:3 gsm/8000 a=rtpmap:18 g729/8000 a=rtpmap:4 g723/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 a=encryption:optional a=sendrecv Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Header 0: INVITE sip:7910@10.253.0.176;user=phone SIP/2.0 (47) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Header 1: Via: SIP/2.0/UDP 10.2.200.150:2063;branch=z9hG4bK-9mrhvk5s7kc3;rport (68) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Header 2: From: "7914" ;tag=bck9fswnc8 (51) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Header 3: To: (38) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Header 4: Call-ID: 3c376d536419-hh9gc75x74cz@snom320-000413242B7A (55) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Header 5: CSeq: 2 INVITE (14) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Header 6: Max-Forwards: 70 (16) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Header 7: Contact: ;flow-id=1 (61) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Header 8: P-Key-Flags: keys="3" (21) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Header 9: User-Agent: snom320/5.5 (23) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Header 10: Accept: application/sdp (23) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Header 11: Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO (88) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Header 12: Allow-Events: talk, hold, refer (31) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Header 13: Supported: timer, 100rel, replaces, callerid (44) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Header 14: Session-Expires: 3600;refresher=uas (35) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Header 15: Proxy-Authorization: Digest username="7914",realm="asterisk",nonce="2af161ec",uri="sip:7910@10.253.0.176;user=phone",response="77dda90845ba8c694fc82a877aeb9b57",algorithm=md5 (174) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Header 16: Content-Type: application/sdp (29) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Header 17: Content-Length: 473 (19) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Header 18: (0) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Line: v=0 (3) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Line: o=root 616753668 616753668 IN IP4 10.2.200.150 (46) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Line: s=call (6) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Line: c=IN IP4 10.2.200.150 (21) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Line: t=0 0 (5) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Line: m=audio 57714 RTP/AVP 0 8 9 2 3 18 4 101 (40) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Line: a=crypto:1 AES_CM_128_HMAC_SHA1_32 inline:bcrnXBM3o5Mhl5QTdCHb4nu2EUIka1y2xsR8XObK (82) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Line: a=rtpmap:0 pcmu/8000 (20) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Line: a=rtpmap:8 pcma/8000 (20) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Line: a=rtpmap:9 g722/8000 (20) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Line: a=rtpmap:2 g726-32/8000 (23) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Line: a=rtpmap:3 gsm/8000 (19) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Line: a=rtpmap:18 g729/8000 (21) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Line: a=rtpmap:4 g723/8000 (20) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Line: a=rtpmap:101 telephone-event/8000 (33) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Line: a=fmtp:101 0-16 (15) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Line: a=ptime:20 (10) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Line: a=encryption:optional (21) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Line: a=sendrecv (10) Jun 21 11:16:59 VERBOSE[4963] logger.c: --- (18 headers 19 lines)Jun 21 11:16:59 VERBOSE[4963] logger.c: --- (18 headers 19 lines)--- Jun 21 11:16:59 DEBUG[4963] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE Jun 21 11:16:59 VERBOSE[4963] logger.c: Using INVITE request as basis request - 3c376d536419-hh9gc75x74cz@snom320-000413242B7A Jun 21 11:16:59 VERBOSE[4963] logger.c: Sending to 10.2.200.150 : 2063 (NAT) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Setting NAT on RTP to 0 Jun 21 11:16:59 VERBOSE[4963] logger.c: Found user '7914' Jun 21 11:16:59 VERBOSE[4963] logger.c: Found RTP audio format 0 Jun 21 11:16:59 VERBOSE[4963] logger.c: Found RTP audio format 8 Jun 21 11:16:59 VERBOSE[4963] logger.c: Found RTP audio format 9 Jun 21 11:16:59 VERBOSE[4963] logger.c: Found RTP audio format 2 Jun 21 11:16:59 VERBOSE[4963] logger.c: Found RTP audio format 3 Jun 21 11:16:59 VERBOSE[4963] logger.c: Found RTP audio format 18 Jun 21 11:16:59 VERBOSE[4963] logger.c: Found RTP audio format 4 Jun 21 11:16:59 VERBOSE[4963] logger.c: Found RTP audio format 101 Jun 21 11:16:59 VERBOSE[4963] logger.c: Peer audio RTP is at port 10.2.200.150:57714 Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Peer audio RTP is at port 10.2.200.150:57714 Jun 21 11:16:59 VERBOSE[4963] logger.c: Found description format pcmu Jun 21 11:16:59 VERBOSE[4963] logger.c: Found description format pcma Jun 21 11:16:59 VERBOSE[4963] logger.c: Found description format g722 Jun 21 11:16:59 VERBOSE[4963] logger.c: Found description format g726-32 Jun 21 11:16:59 VERBOSE[4963] logger.c: Found description format gsm Jun 21 11:16:59 VERBOSE[4963] logger.c: Found description format g729 Jun 21 11:16:59 VERBOSE[4963] logger.c: Found description format g723 Jun 21 11:16:59 VERBOSE[4963] logger.c: Found description format telephone-event Jun 21 11:16:59 VERBOSE[4963] logger.c: Capabilities: us - 0xe (gsm|ulaw|alaw), peer - audio=0x11f (g723|gsm|ulaw|alaw|g726|g729)/video=0x0 (nothing), combined - 0xe (gsm|ulaw|alaw) Jun 21 11:16:59 VERBOSE[4963] logger.c: Non-codec capabilities: us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Checking SIP call limits for device 7914 Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Updating call counter for incoming call Jun 21 11:16:59 VERBOSE[4963] logger.c: Looking for 7910 in internal (domain 10.253.0.176) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: build_route: Contact hop: ;flow-id=1 Jun 21 11:16:59 VERBOSE[4963] logger.c: list_route: hop: Jun 21 11:16:59 VERBOSE[4963] logger.c: Transmitting (no NAT) to 10.2.200.150:2063: SIP/2.0 100 Trying Via: SIP/2.0/UDP 10.2.200.150:2063;branch=z9hG4bK-9mrhvk5s7kc3;rport;received=10.2.200.150 From: "7914" ;tag=bck9fswnc8 To: Call-ID: 3c376d536419-hh9gc75x74cz@snom320-000413242B7A CSeq: 2 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Contact: Content-Length: 0 --- Jun 21 11:16:59 DEBUG[4946] chan_sip.c: Checking device state for peer 7914 Jun 21 11:16:59 DEBUG[4946] devicestate.c: Changing state for SIP/7914 - state 2 (In use) Jun 21 11:16:59 DEBUG[5009] pbx.c: Launching 'Dial' Jun 21 11:16:59 DEBUG[5010] app_queue.c: Device 'SIP/7914' changed to state '2' (In use) Jun 21 11:16:59 VERBOSE[5009] logger.c: -- Executing Dial("SIP/7914-9313287", "SIP/7910") in new stack Jun 21 11:16:59 DEBUG[5009] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - INVITE (With RTP) Jun 21 11:16:59 DEBUG[5009] chan_sip.c: Setting NAT on RTP to 0 Jun 21 11:16:59 DEBUG[5009] channel.c: Not copying variable STACK-internal-7910-1. Jun 21 11:16:59 DEBUG[5009] channel.c: Not copying variable SIPCALLID. Jun 21 11:16:59 DEBUG[5009] channel.c: Not copying variable SIPUSERAGENT. Jun 21 11:16:59 DEBUG[5009] channel.c: Not copying variable SIPDOMAIN. Jun 21 11:16:59 DEBUG[5009] channel.c: Not copying variable SIPURI. Jun 21 11:16:59 DEBUG[5009] chan_sip.c: Outgoing Call for 7910 Jun 21 11:16:59 DEBUG[5009] chan_sip.c: Updating call counter for outgoing call Jun 21 11:16:59 VERBOSE[5009] logger.c: We're at 10.253.0.176 port 12712 Jun 21 11:16:59 VERBOSE[5009] logger.c: Adding codec 0x4 (ulaw) to SDP Jun 21 11:16:59 VERBOSE[5009] logger.c: Adding codec 0x8 (alaw) to SDP Jun 21 11:16:59 VERBOSE[5009] logger.c: Adding codec 0x2 (gsm) to SDP Jun 21 11:16:59 VERBOSE[5009] logger.c: Adding non-codec 0x1 (telephone-event) to SDP Jun 21 11:16:59 DEBUG[5009] chan_sip.c: Header 0: INVITE sip:7910@10.2.200.189:5060 SIP/2.0 (41) Jun 21 11:16:59 DEBUG[5009] chan_sip.c: Header 1: Via: SIP/2.0/UDP 10.253.0.176:5060;branch=z9hG4bK1a182db4;rport (63) Jun 21 11:16:59 DEBUG[5009] chan_sip.c: Header 2: From: "7914" ;tag=as0c84e840 (51) Jun 21 11:16:59 DEBUG[5009] chan_sip.c: Header 3: To: (32) Jun 21 11:16:59 DEBUG[5009] chan_sip.c: Header 4: Contact: (32) Jun 21 11:16:59 DEBUG[5009] chan_sip.c: Header 5: Call-ID: 608ac29152d9128975c39ad555cc00a4@10.253.0.176 (54) Jun 21 11:16:59 DEBUG[5009] chan_sip.c: Header 6: CSeq: 102 INVITE (16) Jun 21 11:16:59 DEBUG[5009] chan_sip.c: Header 7: User-Agent: Asterisk PBX (24) Jun 21 11:16:59 DEBUG[5009] chan_sip.c: Header 8: Max-Forwards: 70 (16) Jun 21 11:16:59 DEBUG[5009] chan_sip.c: Header 9: Date: Wed, 21 Jun 2006 10:16:59 GMT (35) Jun 21 11:16:59 DEBUG[5009] chan_sip.c: Header 10: Alert-Info: Answer (18) Jun 21 11:16:59 DEBUG[5009] chan_sip.c: Header 11: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) Jun 21 11:16:59 DEBUG[5009] chan_sip.c: Header 12: Content-Type: application/sdp (29) Jun 21 11:16:59 DEBUG[5009] chan_sip.c: Header 13: Content-Length: 261 (19) Jun 21 11:16:59 DEBUG[5009] chan_sip.c: Header 14: (0) Jun 21 11:16:59 DEBUG[5009] chan_sip.c: Line: v=0 (3) Jun 21 11:16:59 DEBUG[5009] chan_sip.c: Line: o=root 4942 4942 IN IP4 10.253.0.176 (36) Jun 21 11:16:59 DEBUG[5009] chan_sip.c: Line: s=session (9) Jun 21 11:16:59 DEBUG[5009] chan_sip.c: Line: c=IN IP4 10.253.0.176 (21) Jun 21 11:16:59 DEBUG[5009] chan_sip.c: Line: t=0 0 (5) Jun 21 11:16:59 DEBUG[5009] chan_sip.c: Line: m=audio 12712 RTP/AVP 0 8 3 101 (31) Jun 21 11:16:59 DEBUG[5009] chan_sip.c: Line: a=rtpmap:0 PCMU/8000 (20) Jun 21 11:16:59 DEBUG[5009] chan_sip.c: Line: a=rtpmap:8 PCMA/8000 (20) Jun 21 11:16:59 DEBUG[5009] chan_sip.c: Line: a=rtpmap:3 GSM/8000 (19) Jun 21 11:16:59 DEBUG[5009] chan_sip.c: Line: a=rtpmap:101 telephone-event/8000 (33) Jun 21 11:16:59 DEBUG[5009] chan_sip.c: Line: a=fmtp:101 0-16 (15) Jun 21 11:16:59 DEBUG[5009] chan_sip.c: Line: a=silenceSupp:off - - - - (25) Jun 21 11:16:59 VERBOSE[5009] logger.c: 14 headers, 12 lines Jun 21 11:16:59 VERBOSE[5009] logger.c: Reliably Transmitting (no NAT) to 10.2.200.189:5060: INVITE sip:7910@10.2.200.189:5060 SIP/2.0 Via: SIP/2.0/UDP 10.253.0.176:5060;branch=z9hG4bK1a182db4;rport From: "7914" ;tag=as0c84e840 To: Contact: Call-ID: 608ac29152d9128975c39ad555cc00a4@10.253.0.176 CSeq: 102 INVITE User-Agent: Asterisk PBX Max-Forwards: 70 Date: Wed, 21 Jun 2006 10:16:59 GMT Alert-Info: Answer Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Content-Type: application/sdp Content-Length: 261 v=0 o=root 4942 4942 IN IP4 10.253.0.176 s=session c=IN IP4 10.253.0.176 t=0 0 m=audio 12712 RTP/AVP 0 8 3 101 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:3 GSM/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - --- Jun 21 11:16:59 DEBUG[5009] chan_sip.c: *** SIP TIMER: Initalizing retransmit timer on packet: Id #23 Jun 21 11:16:59 VERBOSE[5009] logger.c: -- Called 7910 Jun 21 11:16:59 DEBUG[5009] channel.c: Set channel SIP/7910-9318a67 to read format ulaw Jun 21 11:16:59 DEBUG[5009] channel.c: Set channel SIP/7914-9313287 to write format ulaw Jun 21 11:16:59 DEBUG[5009] channel.c: Set channel SIP/7914-9313287 to read format ulaw Jun 21 11:16:59 DEBUG[5009] channel.c: Set channel SIP/7910-9318a67 to write format ulaw Jun 21 11:16:59 VERBOSE[4963] logger.c: <-- SIP read from 10.2.200.189:52932: SIP/2.0 100 Trying Via: SIP/2.0/UDP 10.253.0.176:5060;branch=z9hG4bK1a182db4;rport From: "7914" ;tag=as0c84e840 To: Call-ID: 608ac29152d9128975c39ad555cc00a4@10.253.0.176 Date: Wed, 21 Jun 2006 10:22:31 GMT CSeq: 102 INVITE Server: CSCO/7 Contact: Content-Length: 0 Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Header 0: SIP/2.0 100 Trying (18) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Header 1: Via: SIP/2.0/UDP 10.253.0.176:5060;branch=z9hG4bK1a182db4;rport (63) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Header 2: From: "7914" ;tag=as0c84e840 (51) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Header 3: To: (32) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Header 4: Call-ID: 608ac29152d9128975c39ad555cc00a4@10.253.0.176 (54) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Header 5: Date: Wed, 21 Jun 2006 10:22:31 GMT (35) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Header 6: CSeq: 102 INVITE (16) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Header 7: Server: CSCO/7 (14) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Header 8: Contact: (37) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Header 9: Content-Length: 0 (17) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Header 10: (0) Jun 21 11:16:59 VERBOSE[4963] logger.c: --- (10 headers 0 lines)Jun 21 11:16:59 VERBOSE[4963] logger.c: --- (10 headers 0 lines)--- Jun 21 11:16:59 DEBUG[4963] chan_sip.c: *** SIP TIMER: Cancelling retransmission #23 - INVITE (got response) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '608ac29152d9128975c39ad555cc00a4@10.253.0.176' Request 102: Found Jun 21 11:16:59 DEBUG[4963] chan_sip.c: SIP response 100 to standard invite Jun 21 11:16:59 VERBOSE[4963] logger.c: <-- SIP read from 10.2.200.189:52932: SIP/2.0 180 Ringing Via: SIP/2.0/UDP 10.253.0.176:5060;branch=z9hG4bK1a182db4;rport From: "7914" ;tag=as0c84e840 To: ;tag=00036bc97a290a9b435c8321-74ee3d98 Call-ID: 608ac29152d9128975c39ad555cc00a4@10.253.0.176 Date: Wed, 21 Jun 2006 10:22:31 GMT CSeq: 102 INVITE Server: CSCO/7 Contact: Content-Length: 0 Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Header 0: SIP/2.0 180 Ringing (19) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Header 1: Via: SIP/2.0/UDP 10.253.0.176:5060;branch=z9hG4bK1a182db4;rport (63) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Header 2: From: "7914" ;tag=as0c84e840 (51) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Header 3: To: ;tag=00036bc97a290a9b435c8321-74ee3d98 (70) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Header 4: Call-ID: 608ac29152d9128975c39ad555cc00a4@10.253.0.176 (54) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Header 5: Date: Wed, 21 Jun 2006 10:22:31 GMT (35) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Header 6: CSeq: 102 INVITE (16) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Header 7: Server: CSCO/7 (14) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Header 8: Contact: (37) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Header 9: Content-Length: 0 (17) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Header 10: (0) Jun 21 11:16:59 VERBOSE[4963] logger.c: --- (10 headers 0 lines)Jun 21 11:16:59 VERBOSE[4963] logger.c: --- (10 headers 0 lines)--- Jun 21 11:16:59 DEBUG[4963] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '608ac29152d9128975c39ad555cc00a4@10.253.0.176' Request 102: Found Jun 21 11:16:59 DEBUG[4963] chan_sip.c: SIP response 180 to standard invite Jun 21 11:16:59 DEBUG[4946] chan_sip.c: Checking device state for peer 7910 Jun 21 11:16:59 DEBUG[4946] devicestate.c: Changing state for SIP/7910 - state 6 (Ringing) Jun 21 11:16:59 VERBOSE[5009] logger.c: -- SIP/7910-9318a67 is ringing Jun 21 11:16:59 VERBOSE[5009] logger.c: Transmitting (no NAT) to 10.2.200.150:2063: SIP/2.0 180 Ringing Via: SIP/2.0/UDP 10.2.200.150:2063;branch=z9hG4bK-9mrhvk5s7kc3;rport;received=10.2.200.150 From: "7914" ;tag=bck9fswnc8 To: ;tag=as57f41a66 Call-ID: 3c376d536419-hh9gc75x74cz@snom320-000413242B7A CSeq: 2 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Contact: Content-Length: 0 --- Jun 21 11:16:59 DEBUG[5011] app_queue.c: Device 'SIP/7910' changed to state '6' (Ringing) Jun 21 11:16:59 VERBOSE[4963] logger.c: <-- SIP read from 10.2.200.189:52932: SIP/2.0 200 OK Via: SIP/2.0/UDP 10.253.0.176:5060;branch=z9hG4bK1a182db4;rport From: "7914" ;tag=as0c84e840 To: ;tag=00036bc97a290a9b435c8321-74ee3d98 Call-ID: 608ac29152d9128975c39ad555cc00a4@10.253.0.176 Date: Wed, 21 Jun 2006 10:22:31 GMT CSeq: 102 INVITE Server: CSCO/7 Contact: Content-Type: application/sdp Content-Length: 194 v=0 o=Cisco-SIPUA 25759 83 IN IP4 10.2.200.189 s=SIP Call c=IN IP4 10.2.200.189 t=0 0 m=audio 22512 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Header 0: SIP/2.0 200 OK (14) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Header 1: Via: SIP/2.0/UDP 10.253.0.176:5060;branch=z9hG4bK1a182db4;rport (63) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Header 2: From: "7914" ;tag=as0c84e840 (51) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Header 3: To: ;tag=00036bc97a290a9b435c8321-74ee3d98 (70) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Header 4: Call-ID: 608ac29152d9128975c39ad555cc00a4@10.253.0.176 (54) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Header 5: Date: Wed, 21 Jun 2006 10:22:31 GMT (35) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Header 6: CSeq: 102 INVITE (16) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Header 7: Server: CSCO/7 (14) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Header 8: Contact: (37) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Header 9: Content-Type: application/sdp (29) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Header 10: Content-Length: 194 (19) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Header 11: (0) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Line: v=0 (3) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Line: o=Cisco-SIPUA 25759 83 IN IP4 10.2.200.189 (42) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Line: s=SIP Call (10) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Line: c=IN IP4 10.2.200.189 (21) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Line: t=0 0 (5) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Line: m=audio 22512 RTP/AVP 0 101 (27) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Line: a=rtpmap:0 PCMU/8000 (20) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Line: a=rtpmap:101 telephone-event/8000 (33) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Line: a=fmtp:101 0-15 (15) Jun 21 11:16:59 VERBOSE[4963] logger.c: --- (11 headers 9 lines)Jun 21 11:16:59 VERBOSE[4963] logger.c: --- (11 headers 9 lines)--- Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Acked pending invite 102 Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Stopping retransmission on '608ac29152d9128975c39ad555cc00a4@10.253.0.176' of Request 102: Match Found Jun 21 11:16:59 DEBUG[4963] chan_sip.c: SIP response 200 to standard invite Jun 21 11:16:59 VERBOSE[4963] logger.c: Found RTP audio format 0 Jun 21 11:16:59 VERBOSE[4963] logger.c: Found RTP audio format 101 Jun 21 11:16:59 VERBOSE[4963] logger.c: Peer audio RTP is at port 10.2.200.189:22512 Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Peer audio RTP is at port 10.2.200.189:22512 Jun 21 11:16:59 VERBOSE[4963] logger.c: Found description format PCMU Jun 21 11:16:59 VERBOSE[4963] logger.c: Found description format telephone-event Jun 21 11:16:59 VERBOSE[4963] logger.c: Capabilities: us - 0xe (gsm|ulaw|alaw), peer - audio=0x4 (ulaw)/video=0x0 (nothing), combined - 0x4 (ulaw) Jun 21 11:16:59 VERBOSE[4963] logger.c: Non-codec capabilities: us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: build_route: Contact hop: Jun 21 11:16:59 VERBOSE[4963] logger.c: list_route: hop: Jun 21 11:16:59 VERBOSE[4963] logger.c: set_destination: Parsing for address/port to send to Jun 21 11:16:59 VERBOSE[4963] logger.c: set_destination: set destination to 10.2.200.189, port 5060 Jun 21 11:16:59 VERBOSE[4963] logger.c: Transmitting (no NAT) to 10.2.200.189:5060: ACK sip:7910@10.2.200.189:5060 SIP/2.0 Via: SIP/2.0/UDP 10.253.0.176:5060;branch=z9hG4bK5d626b8e;rport From: "7914" ;tag=as0c84e840 To: ;tag=00036bc97a290a9b435c8321-74ee3d98 Contact: Call-ID: 608ac29152d9128975c39ad555cc00a4@10.253.0.176 CSeq: 102 ACK User-Agent: Asterisk PBX Max-Forwards: 70 Content-Length: 0 --- Jun 21 11:16:59 DEBUG[4946] chan_sip.c: Checking device state for peer 7910 Jun 21 11:16:59 VERBOSE[5009] logger.c: -- SIP/7910-9318a67 answered SIP/7914-9313287 Jun 21 11:16:59 DEBUG[4946] devicestate.c: Changing state for SIP/7910 - state 2 (In use) Jun 21 11:16:59 DEBUG[5009] channel.c: Set channel SIP/7914-9313287 to read format ulaw Jun 21 11:16:59 DEBUG[5009] channel.c: Set channel SIP/7910-9318a67 to write format ulaw Jun 21 11:16:59 DEBUG[5009] channel.c: Set channel SIP/7910-9318a67 to read format ulaw Jun 21 11:16:59 DEBUG[5009] channel.c: Set channel SIP/7914-9313287 to write format ulaw Jun 21 11:16:59 DEBUG[5012] app_queue.c: Device 'SIP/7910' changed to state '2' (In use) Jun 21 11:16:59 DEBUG[4946] chan_sip.c: Checking device state for peer 7914 Jun 21 11:16:59 DEBUG[5009] chan_sip.c: sip_answer(SIP/7914-9313287) Jun 21 11:16:59 DEBUG[4946] channel.c: Avoiding initial deadlock for 'SIP/7914-9313287' Jun 21 11:16:59 VERBOSE[5009] logger.c: We're at 10.253.0.176 port 17966 Jun 21 11:16:59 VERBOSE[5009] logger.c: Adding codec 0x4 (ulaw) to SDP Jun 21 11:16:59 VERBOSE[5009] logger.c: Adding codec 0x8 (alaw) to SDP Jun 21 11:16:59 VERBOSE[5009] logger.c: Adding codec 0x2 (gsm) to SDP Jun 21 11:16:59 VERBOSE[5009] logger.c: Adding non-codec 0x1 (telephone-event) to SDP Jun 21 11:16:59 VERBOSE[5009] logger.c: Reliably Transmitting (no NAT) to 10.2.200.150:2063: SIP/2.0 200 OK Via: SIP/2.0/UDP 10.2.200.150:2063;branch=z9hG4bK-9mrhvk5s7kc3;rport;received=10.2.200.150 From: "7914" ;tag=bck9fswnc8 To: ;tag=as57f41a66 Call-ID: 3c376d536419-hh9gc75x74cz@snom320-000413242B7A CSeq: 2 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Contact: Content-Type: application/sdp Content-Length: 261 v=0 o=root 4942 4942 IN IP4 10.253.0.176 s=session c=IN IP4 10.253.0.176 t=0 0 m=audio 17966 RTP/AVP 0 8 3 101 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:3 GSM/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - --- Jun 21 11:16:59 DEBUG[5009] chan_sip.c: *** SIP TIMER: Initalizing retransmit timer on packet: Id #24 Jun 21 11:16:59 VERBOSE[5009] logger.c: -- Attempting native bridge of SIP/7914-9313287 and SIP/7910-9318a67 Jun 21 11:16:59 DEBUG[5009] chan_sip.c: Deferring reinvite on SIP '3c376d536419-hh9gc75x74cz@snom320-000413242B7A' - It's audio will be redirected to IP 10.2.200.189 Jun 21 11:16:59 DEBUG[5009] chan_sip.c: Sending reinvite on SIP '608ac29152d9128975c39ad555cc00a4@10.253.0.176' - It's audio soon redirected to IP 10.2.200.150 Jun 21 11:16:59 VERBOSE[5009] logger.c: set_destination: Parsing for address/port to send to Jun 21 11:16:59 VERBOSE[5009] logger.c: set_destination: set destination to 10.2.200.189, port 5060 Jun 21 11:16:59 VERBOSE[5009] logger.c: We're at 10.253.0.176 port 12712 Jun 21 11:16:59 VERBOSE[5009] logger.c: Adding codec 0x4 (ulaw) to SDP Jun 21 11:16:59 VERBOSE[5009] logger.c: Adding codec 0x8 (alaw) to SDP Jun 21 11:16:59 VERBOSE[5009] logger.c: Adding codec 0x2 (gsm) to SDP Jun 21 11:16:59 VERBOSE[5009] logger.c: Adding codec 0x1 (g723) to SDP Jun 21 11:16:59 VERBOSE[5009] logger.c: Adding codec 0x10 (g726) to SDP Jun 21 11:16:59 VERBOSE[5009] logger.c: Adding codec 0x100 (g729) to SDP Jun 21 11:16:59 VERBOSE[5009] logger.c: Adding non-codec 0x1 (telephone-event) to SDP Jun 21 11:16:59 DEBUG[5009] chan_sip.c: Header 0: INVITE sip:7910@10.2.200.189:5060 SIP/2.0 (41) Jun 21 11:16:59 DEBUG[5009] chan_sip.c: Header 1: Via: SIP/2.0/UDP 10.253.0.176:5060;branch=z9hG4bK5b55cc01;rport (63) Jun 21 11:16:59 DEBUG[5009] chan_sip.c: Header 2: From: "7914" ;tag=as0c84e840 (51) Jun 21 11:16:59 DEBUG[5009] chan_sip.c: Header 3: To: ;tag=00036bc97a290a9b435c8321-74ee3d98 (70) Jun 21 11:16:59 DEBUG[5009] chan_sip.c: Header 4: Contact: (32) Jun 21 11:16:59 DEBUG[5009] chan_sip.c: Header 5: Call-ID: 608ac29152d9128975c39ad555cc00a4@10.253.0.176 (54) Jun 21 11:16:59 DEBUG[5009] chan_sip.c: Header 6: CSeq: 103 INVITE (16) Jun 21 11:16:59 DEBUG[5009] chan_sip.c: Header 7: User-Agent: Asterisk PBX (24) Jun 21 11:16:59 DEBUG[5009] chan_sip.c: Header 8: Max-Forwards: 70 (16) Jun 21 11:16:59 DEBUG[5009] chan_sip.c: Header 9: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) Jun 21 11:16:59 DEBUG[5009] chan_sip.c: Header 10: X-asterisk-info: SIP re-invite (RTP bridge) (43) Jun 21 11:16:59 DEBUG[5009] chan_sip.c: Header 11: Content-Type: application/sdp (29) Jun 21 11:16:59 DEBUG[5009] chan_sip.c: Header 12: Content-Length: 363 (19) Jun 21 11:16:59 DEBUG[5009] chan_sip.c: Header 13: (0) Jun 21 11:16:59 DEBUG[5009] chan_sip.c: Line: v=0 (3) Jun 21 11:16:59 DEBUG[5009] chan_sip.c: Line: o=root 4942 4943 IN IP4 10.2.200.150 (36) Jun 21 11:16:59 DEBUG[5009] chan_sip.c: Line: s=session (9) Jun 21 11:16:59 DEBUG[5009] chan_sip.c: Line: c=IN IP4 10.2.200.150 (21) Jun 21 11:16:59 DEBUG[5009] chan_sip.c: Line: t=0 0 (5) Jun 21 11:16:59 DEBUG[5009] chan_sip.c: Line: m=audio 57714 RTP/AVP 0 8 3 4 111 18 101 (40) Jun 21 11:16:59 DEBUG[5009] chan_sip.c: Line: a=rtpmap:0 PCMU/8000 (20) Jun 21 11:16:59 DEBUG[5009] chan_sip.c: Line: a=rtpmap:8 PCMA/8000 (20) Jun 21 11:16:59 DEBUG[5009] chan_sip.c: Line: a=rtpmap:3 GSM/8000 (19) Jun 21 11:16:59 DEBUG[5009] chan_sip.c: Line: a=rtpmap:4 G723/8000 (20) Jun 21 11:16:59 DEBUG[5009] chan_sip.c: Line: a=rtpmap:111 G726-32/8000 (25) Jun 21 11:16:59 DEBUG[5009] chan_sip.c: Line: a=rtpmap:18 G729/8000 (21) Jun 21 11:16:59 DEBUG[5009] chan_sip.c: Line: a=fmtp:18 annexb=no (19) Jun 21 11:16:59 DEBUG[5009] chan_sip.c: Line: a=rtpmap:101 telephone-event/8000 (33) Jun 21 11:16:59 DEBUG[5009] chan_sip.c: Line: a=fmtp:101 0-16 (15) Jun 21 11:16:59 DEBUG[5009] chan_sip.c: Line: a=silenceSupp:off - - - - (25) Jun 21 11:16:59 VERBOSE[5009] logger.c: 13 headers, 16 lines Jun 21 11:16:59 VERBOSE[5009] logger.c: Reliably Transmitting (no NAT) to 10.2.200.189:5060: INVITE sip:7910@10.2.200.189:5060 SIP/2.0 Via: SIP/2.0/UDP 10.253.0.176:5060;branch=z9hG4bK5b55cc01;rport From: "7914" ;tag=as0c84e840 To: ;tag=00036bc97a290a9b435c8321-74ee3d98 Contact: Call-ID: 608ac29152d9128975c39ad555cc00a4@10.253.0.176 CSeq: 103 INVITE User-Agent: Asterisk PBX Max-Forwards: 70 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY X-asterisk-info: SIP re-invite (RTP bridge) Content-Type: application/sdp Content-Length: 363 v=0 o=root 4942 4943 IN IP4 10.2.200.150 s=session c=IN IP4 10.2.200.150 t=0 0 m=audio 57714 RTP/AVP 0 8 3 4 111 18 101 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:3 GSM/8000 a=rtpmap:4 G723/8000 a=rtpmap:111 G726-32/8000 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - --- Jun 21 11:16:59 DEBUG[5009] chan_sip.c: *** SIP TIMER: Initalizing retransmit timer on packet: Id #25 Jun 21 11:16:59 DEBUG[4946] devicestate.c: Changing state for SIP/7914 - state 2 (In use) Jun 21 11:16:59 DEBUG[5013] app_queue.c: Device 'SIP/7914' changed to state '2' (In use) Jun 21 11:16:59 VERBOSE[4963] logger.c: <-- SIP read from 10.2.200.150:2063: ACK sip:7910@10.253.0.176 SIP/2.0 Via: SIP/2.0/UDP 10.2.200.150:2063;branch=z9hG4bK-rr3nvz5xcvla;rport From: "7914" ;tag=bck9fswnc8 To: ;tag=as57f41a66 Call-ID: 3c376d536419-hh9gc75x74cz@snom320-000413242B7A CSeq: 2 ACK Max-Forwards: 70 Contact: ;flow-id=1 Content-Length: 0 Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Header 0: ACK sip:7910@10.253.0.176 SIP/2.0 (33) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Header 1: Via: SIP/2.0/UDP 10.2.200.150:2063;branch=z9hG4bK-rr3nvz5xcvla;rport (68) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Header 2: From: "7914" ;tag=bck9fswnc8 (51) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Header 3: To: ;tag=as57f41a66 (53) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Header 4: Call-ID: 3c376d536419-hh9gc75x74cz@snom320-000413242B7A (55) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Header 5: CSeq: 2 ACK (11) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Header 6: Max-Forwards: 70 (16) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Header 7: Contact: ;flow-id=1 (61) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Header 8: Content-Length: 0 (17) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Header 9: (0) Jun 21 11:16:59 VERBOSE[4963] logger.c: --- (9 headers 0 lines)Jun 21 11:16:59 VERBOSE[4963] logger.c: --- (9 headers 0 lines)--- Jun 21 11:16:59 DEBUG[4963] chan_sip.c: **** Received ACK (6) - Command in SIP ACK Jun 21 11:16:59 DEBUG[4963] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #24 Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Stopping retransmission on '3c376d536419-hh9gc75x74cz@snom320-000413242B7A' of Response 2: Match Found Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Sending pending reinvite on '3c376d536419-hh9gc75x74cz@snom320-000413242B7A' Jun 21 11:16:59 VERBOSE[4963] logger.c: set_destination: Parsing for address/port to send to Jun 21 11:16:59 VERBOSE[4963] logger.c: set_destination: set destination to 10.2.200.150, port 2063 Jun 21 11:16:59 VERBOSE[4963] logger.c: We're at 10.253.0.176 port 17966 Jun 21 11:16:59 VERBOSE[4963] logger.c: Adding codec 0x4 (ulaw) to SDP Jun 21 11:16:59 VERBOSE[4963] logger.c: Adding non-codec 0x1 (telephone-event) to SDP Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Header 0: INVITE sip:7914@10.2.200.150:2063 SIP/2.0 (41) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Header 1: Via: SIP/2.0/UDP 10.253.0.176:5060;branch=z9hG4bK6e970ae0;rport (63) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Header 2: From: ;tag=as57f41a66 (55) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Header 3: To: "7914" ;tag=bck9fswnc8 (49) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Header 4: Contact: (32) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Header 5: Call-ID: 3c376d536419-hh9gc75x74cz@snom320-000413242B7A (55) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Header 6: CSeq: 102 INVITE (16) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Header 7: User-Agent: Asterisk PBX (24) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Header 8: Max-Forwards: 70 (16) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Header 9: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Header 10: X-asterisk-info: SIP re-invite (RTP bridge) (43) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Header 11: Content-Type: application/sdp (29) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Header 12: Content-Length: 214 (19) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Header 13: (0) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Line: v=0 (3) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Line: o=root 4942 4943 IN IP4 10.2.200.189 (36) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Line: s=session (9) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Line: c=IN IP4 10.2.200.189 (21) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Line: t=0 0 (5) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Line: m=audio 22512 RTP/AVP 0 101 (27) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Line: a=rtpmap:0 PCMU/8000 (20) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Line: a=rtpmap:101 telephone-event/8000 (33) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Line: a=fmtp:101 0-16 (15) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Line: a=silenceSupp:off - - - - (25) Jun 21 11:16:59 VERBOSE[4963] logger.c: 13 headers, 10 lines Jun 21 11:16:59 VERBOSE[4963] logger.c: Reliably Transmitting (no NAT) to 10.2.200.150:2063: INVITE sip:7914@10.2.200.150:2063 SIP/2.0 Via: SIP/2.0/UDP 10.253.0.176:5060;branch=z9hG4bK6e970ae0;rport From: ;tag=as57f41a66 To: "7914" ;tag=bck9fswnc8 Contact: Call-ID: 3c376d536419-hh9gc75x74cz@snom320-000413242B7A CSeq: 102 INVITE User-Agent: Asterisk PBX Max-Forwards: 70 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY X-asterisk-info: SIP re-invite (RTP bridge) Content-Type: application/sdp Content-Length: 214 v=0 o=root 4942 4943 IN IP4 10.2.200.189 s=session c=IN IP4 10.2.200.189 t=0 0 m=audio 22512 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - --- Jun 21 11:16:59 DEBUG[4963] chan_sip.c: *** SIP TIMER: Initalizing retransmit timer on packet: Id #26 Jun 21 11:16:59 DEBUG[5009] rtp.c: Got RTCP report of 52 bytes Jun 21 11:16:59 DEBUG[5009] rtp.c: Ooh, format changed from unknown to ulaw Jun 21 11:16:59 VERBOSE[4963] logger.c: <-- SIP read from 10.2.200.189:52932: SIP/2.0 200 OK Via: SIP/2.0/UDP 10.253.0.176:5060;branch=z9hG4bK5b55cc01;rport From: "7914" ;tag=as0c84e840 To: ;tag=00036bc97a290a9b435c8321-74ee3d98 Call-ID: 608ac29152d9128975c39ad555cc00a4@10.253.0.176 Date: Wed, 21 Jun 2006 10:22:31 GMT CSeq: 103 INVITE Server: CSCO/7 Contact: Content-Type: application/sdp Content-Length: 196 v=0 o=Cisco-SIPUA 22418 6589 IN IP4 10.2.200.189 s=SIP Call c=IN IP4 10.2.200.189 t=0 0 m=audio 22512 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Header 0: SIP/2.0 200 OK (14) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Header 1: Via: SIP/2.0/UDP 10.253.0.176:5060;branch=z9hG4bK5b55cc01;rport (63) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Header 2: From: "7914" ;tag=as0c84e840 (51) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Header 3: To: ;tag=00036bc97a290a9b435c8321-74ee3d98 (70) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Header 4: Call-ID: 608ac29152d9128975c39ad555cc00a4@10.253.0.176 (54) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Header 5: Date: Wed, 21 Jun 2006 10:22:31 GMT (35) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Header 6: CSeq: 103 INVITE (16) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Header 7: Server: CSCO/7 (14) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Header 8: Contact: (37) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Header 9: Content-Type: application/sdp (29) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Header 10: Content-Length: 196 (19) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Header 11: (0) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Line: v=0 (3) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Line: o=Cisco-SIPUA 22418 6589 IN IP4 10.2.200.189 (44) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Line: s=SIP Call (10) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Line: c=IN IP4 10.2.200.189 (21) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Line: t=0 0 (5) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Line: m=audio 22512 RTP/AVP 0 101 (27) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Line: a=rtpmap:0 PCMU/8000 (20) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Line: a=rtpmap:101 telephone-event/8000 (33) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Line: a=fmtp:101 0-15 (15) Jun 21 11:16:59 VERBOSE[4963] logger.c: --- (11 headers 9 lines)Jun 21 11:16:59 VERBOSE[4963] logger.c: --- (11 headers 9 lines)--- Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Acked pending invite 103 Jun 21 11:16:59 DEBUG[4963] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #25 Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Stopping retransmission on '608ac29152d9128975c39ad555cc00a4@10.253.0.176' of Request 103: Match Found Jun 21 11:16:59 DEBUG[4963] chan_sip.c: SIP response 200 to RE-invite on outgoing call 608ac29152d9128975c39ad555cc00a4@10.253.0.176 Jun 21 11:16:59 VERBOSE[4963] logger.c: Found RTP audio format 0 Jun 21 11:16:59 VERBOSE[4963] logger.c: Found RTP audio format 101 Jun 21 11:16:59 VERBOSE[4963] logger.c: Peer audio RTP is at port 10.2.200.189:22512 Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Peer audio RTP is at port 10.2.200.189:22512 Jun 21 11:16:59 VERBOSE[4963] logger.c: Found description format PCMU Jun 21 11:16:59 VERBOSE[4963] logger.c: Found description format telephone-event Jun 21 11:16:59 VERBOSE[4963] logger.c: Capabilities: us - 0xe (gsm|ulaw|alaw), peer - audio=0x4 (ulaw)/video=0x0 (nothing), combined - 0x4 (ulaw) Jun 21 11:16:59 VERBOSE[4963] logger.c: Non-codec capabilities: us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: build_route: Retaining previous route: Jun 21 11:16:59 VERBOSE[4963] logger.c: set_destination: Parsing for address/port to send to Jun 21 11:16:59 VERBOSE[4963] logger.c: set_destination: set destination to 10.2.200.189, port 5060 Jun 21 11:16:59 VERBOSE[4963] logger.c: Transmitting (no NAT) to 10.2.200.189:5060: ACK sip:7910@10.2.200.189:5060 SIP/2.0 Via: SIP/2.0/UDP 10.253.0.176:5060;branch=z9hG4bK1b7b3616;rport From: "7914" ;tag=as0c84e840 To: ;tag=00036bc97a290a9b435c8321-74ee3d98 Contact: Call-ID: 608ac29152d9128975c39ad555cc00a4@10.253.0.176 CSeq: 103 ACK User-Agent: Asterisk PBX Max-Forwards: 70 Content-Length: 0 --- Jun 21 11:16:59 VERBOSE[4963] logger.c: <-- SIP read from 10.2.200.150:2063: SIP/2.0 200 Ok Via: SIP/2.0/UDP 10.253.0.176:5060;branch=z9hG4bK6e970ae0;rport=5060 From: ;tag=as57f41a66 To: "7914" ;tag=bck9fswnc8 Call-ID: 3c376d536419-hh9gc75x74cz@snom320-000413242B7A CSeq: 102 INVITE Contact: ;flow-id=1 User-Agent: snom320/5.5 Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO Allow-Events: talk, hold, refer Supported: timer, 100rel, replaces, callerid Content-Type: application/sdp Content-Length: 325 v=0 o=root 616753668 616753669 IN IP4 10.2.200.150 s=call c=IN IP4 10.2.200.150 t=0 0 m=audio 57714 RTP/AVP 0 101 a=crypto:1 AES_CM_128_HMAC_SHA1_32 inline:bcrnXBM3o5Mhl5QTdCHb4nu2EUIka1y2xsR8XObK a=rtpmap:0 pcmu/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 a=encryption:optional a=sendrecv Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Header 0: SIP/2.0 200 Ok (14) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Header 1: Via: SIP/2.0/UDP 10.253.0.176:5060;branch=z9hG4bK6e970ae0;rport=5060 (68) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Header 2: From: ;tag=as57f41a66 (55) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Header 3: To: "7914" ;tag=bck9fswnc8 (49) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Header 4: Call-ID: 3c376d536419-hh9gc75x74cz@snom320-000413242B7A (55) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Header 5: CSeq: 102 INVITE (16) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Header 6: Contact: ;flow-id=1 (61) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Header 7: User-Agent: snom320/5.5 (23) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Header 8: Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO (88) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Header 9: Allow-Events: talk, hold, refer (31) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Header 10: Supported: timer, 100rel, replaces, callerid (44) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Header 11: Content-Type: application/sdp (29) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Header 12: Content-Length: 325 (19) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Header 13: (0) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Line: v=0 (3) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Line: o=root 616753668 616753669 IN IP4 10.2.200.150 (46) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Line: s=call (6) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Line: c=IN IP4 10.2.200.150 (21) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Line: t=0 0 (5) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Line: m=audio 57714 RTP/AVP 0 101 (27) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Line: a=crypto:1 AES_CM_128_HMAC_SHA1_32 inline:bcrnXBM3o5Mhl5QTdCHb4nu2EUIka1y2xsR8XObK (82) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Line: a=rtpmap:0 pcmu/8000 (20) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Line: a=rtpmap:101 telephone-event/8000 (33) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Line: a=fmtp:101 0-16 (15) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Line: a=ptime:20 (10) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Line: a=encryption:optional (21) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Line: a=sendrecv (10) Jun 21 11:16:59 VERBOSE[4963] logger.c: --- (13 headers 13 lines)Jun 21 11:16:59 VERBOSE[4963] logger.c: --- (13 headers 13 lines)--- Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Acked pending invite 102 Jun 21 11:16:59 DEBUG[4963] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #26 Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Stopping retransmission on '3c376d536419-hh9gc75x74cz@snom320-000413242B7A' of Request 102: Match Found Jun 21 11:16:59 DEBUG[4963] chan_sip.c: SIP response 200 to RE-invite on outgoing call 3c376d536419-hh9gc75x74cz@snom320-000413242B7A Jun 21 11:16:59 VERBOSE[4963] logger.c: Found RTP audio format 0 Jun 21 11:16:59 VERBOSE[4963] logger.c: Found RTP audio format 101 Jun 21 11:16:59 VERBOSE[4963] logger.c: Peer audio RTP is at port 10.2.200.150:57714 Jun 21 11:16:59 DEBUG[4963] chan_sip.c: Peer audio RTP is at port 10.2.200.150:57714 Jun 21 11:16:59 VERBOSE[4963] logger.c: Found description format pcmu Jun 21 11:16:59 VERBOSE[4963] logger.c: Found description format telephone-event Jun 21 11:16:59 VERBOSE[4963] logger.c: Capabilities: us - 0xe (gsm|ulaw|alaw), peer - audio=0x4 (ulaw)/video=0x0 (nothing), combined - 0x4 (ulaw) Jun 21 11:16:59 VERBOSE[4963] logger.c: Non-codec capabilities: us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) Jun 21 11:16:59 DEBUG[4963] chan_sip.c: build_route: Contact hop: ;flow-id=1 Jun 21 11:16:59 VERBOSE[4963] logger.c: list_route: hop: Jun 21 11:16:59 VERBOSE[4963] logger.c: set_destination: Parsing for address/port to send to Jun 21 11:16:59 VERBOSE[4963] logger.c: set_destination: set destination to 10.2.200.150, port 2063 Jun 21 11:16:59 VERBOSE[4963] logger.c: Transmitting (no NAT) to 10.2.200.150:2063: ACK sip:7914@10.2.200.150:2063;line=v62iicjq SIP/2.0 Via: SIP/2.0/UDP 10.253.0.176:5060;branch=z9hG4bK3e3a6045;rport From: ;tag=as57f41a66 To: "7914" ;tag=bck9fswnc8 Contact: Call-ID: 3c376d536419-hh9gc75x74cz@snom320-000413242B7A CSeq: 102 ACK User-Agent: Asterisk PBX Max-Forwards: 70 Content-Length: 0 --- Jun 21 11:17:04 DEBUG[4967] manager.c: Manager received command 'Redirect' Jun 21 11:17:04 DEBUG[4967] channel.c: Soft-Hanging up channel 'SIP/7914-9313287' Jun 21 11:17:04 DEBUG[5009] rtp.c: Oooh, got a hangup Jun 21 11:17:04 DEBUG[5009] chan_sip.c: Sending reinvite on SIP '608ac29152d9128975c39ad555cc00a4@10.253.0.176' - It's audio soon redirected to IP 10.253.0.176 Jun 21 11:17:04 VERBOSE[5009] logger.c: set_destination: Parsing for address/port to send to Jun 21 11:17:04 VERBOSE[5009] logger.c: set_destination: set destination to 10.2.200.189, port 5060 Jun 21 11:17:04 VERBOSE[5009] logger.c: We're at 10.253.0.176 port 12712 Jun 21 11:17:04 VERBOSE[5009] logger.c: Adding codec 0x4 (ulaw) to SDP Jun 21 11:17:04 VERBOSE[5009] logger.c: Adding codec 0x8 (alaw) to SDP Jun 21 11:17:04 VERBOSE[5009] logger.c: Adding codec 0x2 (gsm) to SDP Jun 21 11:17:04 VERBOSE[5009] logger.c: Adding non-codec 0x1 (telephone-event) to SDP Jun 21 11:17:04 DEBUG[5009] chan_sip.c: Header 0: INVITE sip:7910@10.2.200.189:5060 SIP/2.0 (41) Jun 21 11:17:04 DEBUG[5009] chan_sip.c: Header 1: Via: SIP/2.0/UDP 10.253.0.176:5060;branch=z9hG4bK198039b0;rport (63) Jun 21 11:17:04 DEBUG[5009] chan_sip.c: Header 2: From: "7914" ;tag=as0c84e840 (51) Jun 21 11:17:04 DEBUG[5009] chan_sip.c: Header 3: To: ;tag=00036bc97a290a9b435c8321-74ee3d98 (70) Jun 21 11:17:04 DEBUG[5009] chan_sip.c: Header 4: Contact: (32) Jun 21 11:17:04 DEBUG[5009] chan_sip.c: Header 5: Call-ID: 608ac29152d9128975c39ad555cc00a4@10.253.0.176 (54) Jun 21 11:17:04 DEBUG[5009] chan_sip.c: Header 6: CSeq: 104 INVITE (16) Jun 21 11:17:04 DEBUG[5009] chan_sip.c: Header 7: User-Agent: Asterisk PBX (24) Jun 21 11:17:04 DEBUG[5009] chan_sip.c: Header 8: Max-Forwards: 70 (16) Jun 21 11:17:04 DEBUG[5009] chan_sip.c: Header 9: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) Jun 21 11:17:04 DEBUG[5009] chan_sip.c: Header 10: X-asterisk-info: SIP re-invite (RTP bridge) (43) Jun 21 11:17:04 DEBUG[5009] chan_sip.c: Header 11: Content-Type: application/sdp (29) Jun 21 11:17:04 DEBUG[5009] chan_sip.c: Header 12: Content-Length: 261 (19) Jun 21 11:17:04 DEBUG[5009] chan_sip.c: Header 13: (0) Jun 21 11:17:04 DEBUG[5009] chan_sip.c: Line: v=0 (3) Jun 21 11:17:04 DEBUG[5009] chan_sip.c: Line: o=root 4942 4944 IN IP4 10.253.0.176 (36) Jun 21 11:17:04 DEBUG[5009] chan_sip.c: Line: s=session (9) Jun 21 11:17:04 DEBUG[5009] chan_sip.c: Line: c=IN IP4 10.253.0.176 (21) Jun 21 11:17:04 DEBUG[5009] chan_sip.c: Line: t=0 0 (5) Jun 21 11:17:04 DEBUG[5009] chan_sip.c: Line: m=audio 12712 RTP/AVP 0 8 3 101 (31) Jun 21 11:17:04 DEBUG[5009] chan_sip.c: Line: a=rtpmap:0 PCMU/8000 (20) Jun 21 11:17:04 DEBUG[5009] chan_sip.c: Line: a=rtpmap:8 PCMA/8000 (20) Jun 21 11:17:04 DEBUG[5009] chan_sip.c: Line: a=rtpmap:3 GSM/8000 (19) Jun 21 11:17:04 DEBUG[5009] chan_sip.c: Line: a=rtpmap:101 telephone-event/8000 (33) Jun 21 11:17:04 DEBUG[5009] chan_sip.c: Line: a=fmtp:101 0-16 (15) Jun 21 11:17:04 DEBUG[5009] chan_sip.c: Line: a=silenceSupp:off - - - - (25) Jun 21 11:17:04 VERBOSE[5009] logger.c: 13 headers, 12 lines Jun 21 11:17:04 VERBOSE[5009] logger.c: Reliably Transmitting (no NAT) to 10.2.200.189:5060: INVITE sip:7910@10.2.200.189:5060 SIP/2.0 Via: SIP/2.0/UDP 10.253.0.176:5060;branch=z9hG4bK198039b0;rport From: "7914" ;tag=as0c84e840 To: ;tag=00036bc97a290a9b435c8321-74ee3d98 Contact: Call-ID: 608ac29152d9128975c39ad555cc00a4@10.253.0.176 CSeq: 104 INVITE User-Agent: Asterisk PBX Max-Forwards: 70 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY X-asterisk-info: SIP re-invite (RTP bridge) Content-Type: application/sdp Content-Length: 261 v=0 o=root 4942 4944 IN IP4 10.253.0.176 s=session c=IN IP4 10.253.0.176 t=0 0 m=audio 12712 RTP/AVP 0 8 3 101 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:3 GSM/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - --- Jun 21 11:17:04 DEBUG[5009] chan_sip.c: *** SIP TIMER: Initalizing retransmit timer on packet: Id #27 Jun 21 11:17:04 DEBUG[5009] channel.c: Returning from native bridge, channels: SIP/7914-9313287, SIP/7910-9318a67 Jun 21 11:17:04 DEBUG[5009] channel.c: Hanging up channel 'SIP/7910-9318a67' Jun 21 11:17:04 DEBUG[5009] chan_sip.c: Hangup call SIP/7910-9318a67, SIP callid 608ac29152d9128975c39ad555cc00a4@10.253.0.176) Jun 21 11:17:04 DEBUG[5009] chan_sip.c: update_call_counter(7910) - decrement call limit counter Jun 21 11:17:04 DEBUG[5009] chan_sip.c: Updating call counter for outgoing call Jun 21 11:17:04 DEBUG[5009] app_dial.c: Exiting with DIALSTATUS=ANSWER. Jun 21 11:17:04 DEBUG[4946] chan_sip.c: Checking device state for peer 7910 Jun 21 11:17:04 DEBUG[5009] pbx.c: Spawn extension (internal,7200,0) exited non-zero on 'SIP/7914-9313287' Jun 21 11:17:04 DEBUG[4946] devicestate.c: Changing state for SIP/7910 - state 1 (Not in use) Jun 21 11:17:04 DEBUG[5009] pbx.c: Launching 'Dial' Jun 21 11:17:04 DEBUG[5014] app_queue.c: Device 'SIP/7910' changed to state '1' (Not in use) Jun 21 11:17:04 VERBOSE[5009] logger.c: -- Executing Dial("SIP/7914-9313287", "IAX2/7200") in new stack Jun 21 11:17:04 DEBUG[5009] channel.c: Not copying variable STACK-internal-7200-1. Jun 21 11:17:04 DEBUG[5009] channel.c: Not copying variable DIALSTATUS. Jun 21 11:17:04 DEBUG[5009] channel.c: Not copying variable DIALEDTIME. Jun 21 11:17:04 DEBUG[5009] channel.c: Not copying variable ANSWEREDTIME. Jun 21 11:17:04 DEBUG[5009] channel.c: Not copying variable BRIDGEPEER. Jun 21 11:17:04 DEBUG[5009] channel.c: Not copying variable DIALEDPEERNUMBER. Jun 21 11:17:04 DEBUG[5009] channel.c: Not copying variable DIALEDPEERNAME. Jun 21 11:17:04 DEBUG[5009] channel.c: Not copying variable STACK-internal-7910-1. Jun 21 11:17:04 DEBUG[5009] channel.c: Not copying variable SIPCALLID. Jun 21 11:17:04 DEBUG[5009] channel.c: Not copying variable SIPUSERAGENT. Jun 21 11:17:04 DEBUG[5009] channel.c: Not copying variable SIPDOMAIN. Jun 21 11:17:04 DEBUG[5009] channel.c: Not copying variable SIPURI. Jun 21 11:17:04 DEBUG[4946] chan_iax2.c: Checking device state for device 7200 Jun 21 11:17:04 DEBUG[4946] chan_iax2.c: iax2_devicestate(7200): Found peer. What's device state of 7200? addr=2009596426, defaddr=0 maxms=0, lastms=0 Jun 21 11:17:04 DEBUG[4946] channel.c: Avoiding initial deadlock for 'IAX2/7200-3' Jun 21 11:17:04 VERBOSE[5009] logger.c: -- Called 7200 Jun 21 11:17:04 DEBUG[5009] channel.c: Set channel IAX2/7200-3 to read format ulaw Jun 21 11:17:04 DEBUG[5009] channel.c: Set channel SIP/7914-9313287 to write format ulaw Jun 21 11:17:04 DEBUG[5009] channel.c: Set channel SIP/7914-9313287 to read format ulaw Jun 21 11:17:04 DEBUG[5009] channel.c: Set channel IAX2/7200-3 to write format ulaw Jun 21 11:17:04 DEBUG[4946] devicestate.c: Changing state for IAX2/7200 - state 6 (Ringing) Jun 21 11:17:04 DEBUG[5015] app_queue.c: Device 'IAX2/7200' changed to state '6' (Ringing) Jun 21 11:17:04 VERBOSE[4954] logger.c: -- Call accepted by 10.2.200.119 (format ulaw) Jun 21 11:17:04 VERBOSE[4954] logger.c: -- Format for call is ulaw Jun 21 11:17:04 DEBUG[4954] channel.c: Set channel IAX2/7200-3 to write format ulaw Jun 21 11:17:04 DEBUG[4954] channel.c: Set channel IAX2/7200-3 to read format ulaw Jun 21 11:17:04 VERBOSE[5009] logger.c: -- IAX2/7200-3 is ringing Jun 21 11:17:04 DEBUG[5009] channel.c: Driver for channel 'SIP/7914-9313287' does not support indication 3, emulating it Jun 21 11:17:04 DEBUG[5009] channel.c: Set channel SIP/7914-9313287 to write format slin Jun 21 11:17:04 DEBUG[5009] channel.c: Scheduling timer at 160 sample intervals Jun 21 11:17:04 DEBUG[5009] rtp.c: Difference is 42608, ms is 5346 Jun 21 11:17:05 VERBOSE[4963] logger.c: <-- SIP read from 10.2.200.189:52932: SIP/2.0 200 OK Via: SIP/2.0/UDP 10.253.0.176:5060;branch=z9hG4bK198039b0;rport From: "7914" ;tag=as0c84e840 To: ;tag=00036bc97a290a9b435c8321-74ee3d98 Call-ID: 608ac29152d9128975c39ad555cc00a4@10.253.0.176 Date: Wed, 21 Jun 2006 10:22:36 GMT CSeq: 104 INVITE Server: CSCO/7 Contact: Content-Type: application/sdp Content-Length: 197 v=0 o=Cisco-SIPUA 10784 26473 IN IP4 10.2.200.189 s=SIP Call c=IN IP4 10.2.200.189 t=0 0 m=audio 22512 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 Jun 21 11:17:05 DEBUG[4963] chan_sip.c: Header 0: SIP/2.0 200 OK (14) Jun 21 11:17:05 DEBUG[4963] chan_sip.c: Header 1: Via: SIP/2.0/UDP 10.253.0.176:5060;branch=z9hG4bK198039b0;rport (63) Jun 21 11:17:05 DEBUG[4963] chan_sip.c: Header 2: From: "7914" ;tag=as0c84e840 (51) Jun 21 11:17:05 DEBUG[4963] chan_sip.c: Header 3: To: ;tag=00036bc97a290a9b435c8321-74ee3d98 (70) Jun 21 11:17:05 DEBUG[4963] chan_sip.c: Header 4: Call-ID: 608ac29152d9128975c39ad555cc00a4@10.253.0.176 (54) Jun 21 11:17:05 DEBUG[4963] chan_sip.c: Header 5: Date: Wed, 21 Jun 2006 10:22:36 GMT (35) Jun 21 11:17:05 DEBUG[4963] chan_sip.c: Header 6: CSeq: 104 INVITE (16) Jun 21 11:17:05 DEBUG[4963] chan_sip.c: Header 7: Server: CSCO/7 (14) Jun 21 11:17:05 DEBUG[4963] chan_sip.c: Header 8: Contact: (37) Jun 21 11:17:05 DEBUG[4963] chan_sip.c: Header 9: Content-Type: application/sdp (29) Jun 21 11:17:05 DEBUG[4963] chan_sip.c: Header 10: Content-Length: 197 (19) Jun 21 11:17:05 DEBUG[4963] chan_sip.c: Header 11: (0) Jun 21 11:17:05 DEBUG[4963] chan_sip.c: Line: v=0 (3) Jun 21 11:17:05 DEBUG[4963] chan_sip.c: Line: o=Cisco-SIPUA 10784 26473 IN IP4 10.2.200.189 (45) Jun 21 11:17:05 DEBUG[4963] chan_sip.c: Line: s=SIP Call (10) Jun 21 11:17:05 DEBUG[4963] chan_sip.c: Line: c=IN IP4 10.2.200.189 (21) Jun 21 11:17:05 DEBUG[4963] chan_sip.c: Line: t=0 0 (5) Jun 21 11:17:05 DEBUG[4963] chan_sip.c: Line: m=audio 22512 RTP/AVP 0 101 (27) Jun 21 11:17:05 DEBUG[4963] chan_sip.c: Line: a=rtpmap:0 PCMU/8000 (20) Jun 21 11:17:05 DEBUG[4963] chan_sip.c: Line: a=rtpmap:101 telephone-event/8000 (33) Jun 21 11:17:05 DEBUG[4963] chan_sip.c: Line: a=fmtp:101 0-15 (15) Jun 21 11:17:05 VERBOSE[4963] logger.c: --- (11 headers 9 lines)Jun 21 11:17:05 VERBOSE[4963] logger.c: --- (11 headers 9 lines)--- Jun 21 11:17:05 DEBUG[4963] chan_sip.c: Acked pending invite 104 Jun 21 11:17:05 DEBUG[4963] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #27 Jun 21 11:17:05 DEBUG[4963] chan_sip.c: Stopping retransmission on '608ac29152d9128975c39ad555cc00a4@10.253.0.176' of Request 104: Match Found Jun 21 11:17:05 DEBUG[4963] chan_sip.c: SIP response 200 to standard invite Jun 21 11:17:05 VERBOSE[4963] logger.c: Found RTP audio format 0 Jun 21 11:17:05 VERBOSE[4963] logger.c: Found RTP audio format 101 Jun 21 11:17:05 VERBOSE[4963] logger.c: Peer audio RTP is at port 10.2.200.189:22512 Jun 21 11:17:05 DEBUG[4963] chan_sip.c: Peer audio RTP is at port 10.2.200.189:22512 Jun 21 11:17:05 VERBOSE[4963] logger.c: Found description format PCMU Jun 21 11:17:05 VERBOSE[4963] logger.c: Found description format telephone-event Jun 21 11:17:05 VERBOSE[4963] logger.c: Capabilities: us - 0xe (gsm|ulaw|alaw), peer - audio=0x4 (ulaw)/video=0x0 (nothing), combined - 0x4 (ulaw) Jun 21 11:17:05 VERBOSE[4963] logger.c: Non-codec capabilities: us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) Jun 21 11:17:05 DEBUG[4963] chan_sip.c: build_route: Retaining previous route: Jun 21 11:17:05 VERBOSE[4963] logger.c: set_destination: Parsing for address/port to send to Jun 21 11:17:05 VERBOSE[4963] logger.c: set_destination: set destination to 10.2.200.189, port 5060 Jun 21 11:17:05 VERBOSE[4963] logger.c: Transmitting (no NAT) to 10.2.200.189:5060: ACK sip:7910@10.2.200.189:5060 SIP/2.0 Via: SIP/2.0/UDP 10.253.0.176:5060;branch=z9hG4bK23d54fdf;rport From: "7914" ;tag=as0c84e840 To: ;tag=00036bc97a290a9b435c8321-74ee3d98 Contact: Call-ID: 608ac29152d9128975c39ad555cc00a4@10.253.0.176 CSeq: 104 ACK User-Agent: Asterisk PBX Max-Forwards: 70 Content-Length: 0 --- Jun 21 11:17:05 VERBOSE[4963] logger.c: set_destination: Parsing for address/port to send to Jun 21 11:17:05 VERBOSE[4963] logger.c: set_destination: set destination to 10.2.200.189, port 5060 Jun 21 11:17:05 VERBOSE[4963] logger.c: Reliably Transmitting (no NAT) to 10.2.200.189:5060: BYE sip:7910@10.2.200.189:5060 SIP/2.0 Via: SIP/2.0/UDP 10.253.0.176:5060;branch=z9hG4bK56c1c61c;rport From: "7914" ;tag=as0c84e840 To: ;tag=00036bc97a290a9b435c8321-74ee3d98 Contact: Call-ID: 608ac29152d9128975c39ad555cc00a4@10.253.0.176 CSeq: 105 BYE User-Agent: Asterisk PBX Max-Forwards: 70 Content-Length: 0 --- Jun 21 11:17:05 DEBUG[4963] chan_sip.c: *** SIP TIMER: Initalizing retransmit timer on packet: Id #28 Jun 21 11:17:05 VERBOSE[4963] logger.c: <-- SIP read from 10.2.200.189:52932: SIP/2.0 200 OK Via: SIP/2.0/UDP 10.253.0.176:5060;branch=z9hG4bK56c1c61c;rport From: "7914" ;tag=as0c84e840 To: ;tag=00036bc97a290a9b435c8321-74ee3d98 Call-ID: 608ac29152d9128975c39ad555cc00a4@10.253.0.176 Date: Wed, 21 Jun 2006 10:22:36 GMT CSeq: 105 BYE Server: CSCO/7 Content-Length: 0 Jun 21 11:17:05 DEBUG[4963] chan_sip.c: Header 0: SIP/2.0 200 OK (14) Jun 21 11:17:05 DEBUG[4963] chan_sip.c: Header 1: Via: SIP/2.0/UDP 10.253.0.176:5060;branch=z9hG4bK56c1c61c;rport (63) Jun 21 11:17:05 DEBUG[4963] chan_sip.c: Header 2: From: "7914" ;tag=as0c84e840 (51) Jun 21 11:17:05 DEBUG[4963] chan_sip.c: Header 3: To: ;tag=00036bc97a290a9b435c8321-74ee3d98 (70) Jun 21 11:17:05 DEBUG[4963] chan_sip.c: Header 4: Call-ID: 608ac29152d9128975c39ad555cc00a4@10.253.0.176 (54) Jun 21 11:17:05 DEBUG[4963] chan_sip.c: Header 5: Date: Wed, 21 Jun 2006 10:22:36 GMT (35) Jun 21 11:17:05 DEBUG[4963] chan_sip.c: Header 6: CSeq: 105 BYE (13) Jun 21 11:17:05 DEBUG[4963] chan_sip.c: Header 7: Server: CSCO/7 (14) Jun 21 11:17:05 DEBUG[4963] chan_sip.c: Header 8: Content-Length: 0 (17) Jun 21 11:17:05 DEBUG[4963] chan_sip.c: Header 9: (0) Jun 21 11:17:05 VERBOSE[4963] logger.c: --- (9 headers 0 lines)Jun 21 11:17:05 VERBOSE[4963] logger.c: --- (9 headers 0 lines)--- Jun 21 11:17:05 DEBUG[4963] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #28 Jun 21 11:17:05 DEBUG[4963] chan_sip.c: Stopping retransmission on '608ac29152d9128975c39ad555cc00a4@10.253.0.176' of Request 105: Match Found Jun 21 11:17:05 VERBOSE[4963] logger.c: Destroying call '608ac29152d9128975c39ad555cc00a4@10.253.0.176' Jun 21 11:17:07 DEBUG[4946] chan_iax2.c: Checking device state for device 7200 Jun 21 11:17:07 DEBUG[4946] chan_iax2.c: iax2_devicestate(7200): Found peer. What's device state of 7200? addr=2009596426, defaddr=0 maxms=0, lastms=0 Jun 21 11:17:07 DEBUG[4946] devicestate.c: Changing state for IAX2/7200 - state 2 (In use) Jun 21 11:17:07 VERBOSE[5009] logger.c: -- IAX2/7200-3 answered SIP/7914-9313287 Jun 21 11:17:07 DEBUG[5016] app_queue.c: Device 'IAX2/7200' changed to state '2' (In use) Jun 21 11:17:07 DEBUG[5009] channel.c: Set channel SIP/7914-9313287 to write format ulaw Jun 21 11:17:07 DEBUG[5009] channel.c: Scheduling timer at 0 sample intervals Jun 21 11:17:07 DEBUG[5009] channel.c: Set channel SIP/7914-9313287 to read format ulaw Jun 21 11:17:07 DEBUG[5009] channel.c: Set channel IAX2/7200-3 to write format ulaw Jun 21 11:17:07 DEBUG[5009] channel.c: Set channel IAX2/7200-3 to read format ulaw Jun 21 11:17:07 DEBUG[5009] channel.c: Set channel SIP/7914-9313287 to write format ulaw Jun 21 11:17:07 DEBUG[4954] chan_iax2.c: Ooh, voice format changed to 4 Jun 21 11:17:07 DEBUG[4954] channel.c: Set channel IAX2/7200-3 to read format ulaw Jun 21 11:17:16 VERBOSE[4963] logger.c: <-- SIP read from 10.2.200.150:2063: BYE sip:7910@10.253.0.176 SIP/2.0 Via: SIP/2.0/UDP 10.2.200.150:2063;branch=z9hG4bK-7ja7tehfpya9;rport From: "7914" ;tag=bck9fswnc8 To: ;tag=as57f41a66 Call-ID: 3c376d536419-hh9gc75x74cz@snom320-000413242B7A CSeq: 3 BYE Max-Forwards: 70 Contact: ;flow-id=1 User-Agent: snom320/5.5 RTP-RxStat: Total_Rx_Pkts=788,Rx_Pkts=788,Rx_Pkts_Lost=65299,Remote_Rx_Pkts_Lost=0 RTP-TxStat: Total_Tx_Pkts=373,Tx_Pkts=373,Remote_Tx_Pkts=0 Content-Length: 0 Jun 21 11:17:16 DEBUG[4963] chan_sip.c: Header 0: BYE sip:7910@10.253.0.176 SIP/2.0 (33) Jun 21 11:17:16 DEBUG[4963] chan_sip.c: Header 1: Via: SIP/2.0/UDP 10.2.200.150:2063;branch=z9hG4bK-7ja7tehfpya9;rport (68) Jun 21 11:17:16 DEBUG[4963] chan_sip.c: Header 2: From: "7914" ;tag=bck9fswnc8 (51) Jun 21 11:17:16 DEBUG[4963] chan_sip.c: Header 3: To: ;tag=as57f41a66 (53) Jun 21 11:17:16 DEBUG[4963] chan_sip.c: Header 4: Call-ID: 3c376d536419-hh9gc75x74cz@snom320-000413242B7A (55) Jun 21 11:17:16 DEBUG[4963] chan_sip.c: Header 5: CSeq: 3 BYE (11) Jun 21 11:17:16 DEBUG[4963] chan_sip.c: Header 6: Max-Forwards: 70 (16) Jun 21 11:17:16 DEBUG[4963] chan_sip.c: Header 7: Contact: ;flow-id=1 (61) Jun 21 11:17:16 DEBUG[4963] chan_sip.c: Header 8: User-Agent: snom320/5.5 (23) Jun 21 11:17:16 DEBUG[4963] chan_sip.c: Header 9: RTP-RxStat: Total_Rx_Pkts=788,Rx_Pkts=788,Rx_Pkts_Lost=65299,Remote_Rx_Pkts_Lost=0 (82) Jun 21 11:17:16 DEBUG[4963] chan_sip.c: Header 10: RTP-TxStat: Total_Tx_Pkts=373,Tx_Pkts=373,Remote_Tx_Pkts=0 (58) Jun 21 11:17:16 DEBUG[4963] chan_sip.c: Header 11: Content-Length: 0 (17) Jun 21 11:17:16 DEBUG[4963] chan_sip.c: Header 12: (0) Jun 21 11:17:16 VERBOSE[4963] logger.c: --- (12 headers 0 lines)Jun 21 11:17:16 VERBOSE[4963] logger.c: --- (12 headers 0 lines)--- Jun 21 11:17:16 DEBUG[4963] chan_sip.c: **** Received BYE (8) - Command in SIP BYE Jun 21 11:17:16 VERBOSE[4963] logger.c: Sending to 10.2.200.150 : 2063 (NAT) Jun 21 11:17:16 VERBOSE[4963] logger.c: Transmitting (NAT) to 10.2.200.150:2063: SIP/2.0 200 OK Via: SIP/2.0/UDP 10.2.200.150:2063;branch=z9hG4bK-7ja7tehfpya9;received=10.2.200.150;rport=2063 From: "7914" ;tag=bck9fswnc8 To: ;tag=as57f41a66 Call-ID: 3c376d536419-hh9gc75x74cz@snom320-000413242B7A CSeq: 3 BYE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Contact: Content-Length: 0 X-Asterisk-HangupCause: Normal Clearing --- Jun 21 11:17:16 DEBUG[5009] channel.c: Didn't get a frame from channel: SIP/7914-9313287 Jun 21 11:17:16 DEBUG[5009] channel.c: Bridge stops bridging channels SIP/7914-9313287 and IAX2/7200-3 Jun 21 11:17:16 DEBUG[5009] channel.c: Hanging up channel 'IAX2/7200-3' Jun 21 11:17:16 DEBUG[5009] chan_iax2.c: We're hanging up IAX2/7200-3 now... Jun 21 11:17:16 VERBOSE[5009] logger.c: -- Hungup 'IAX2/7200-3' Jun 21 11:17:16 DEBUG[5009] app_dial.c: Exiting with DIALSTATUS=ANSWER. Jun 21 11:17:16 DEBUG[4946] chan_iax2.c: Checking device state for device 7200 Jun 21 11:17:16 DEBUG[4946] chan_iax2.c: iax2_devicestate(7200): Found peer. What's device state of 7200? addr=2009596426, defaddr=0 maxms=0, lastms=0 Jun 21 11:17:16 DEBUG[5009] pbx.c: Spawn extension (internal,7200,1) exited non-zero on 'SIP/7914-9313287' Jun 21 11:17:16 DEBUG[4946] devicestate.c: Changing state for IAX2/7200 - state 1 (Not in use) Jun 21 11:17:16 DEBUG[5009] pbx.c: Launching 'Hangup' Jun 21 11:17:16 DEBUG[5017] app_queue.c: Device 'IAX2/7200' changed to state '1' (Not in use) Jun 21 11:17:16 VERBOSE[5009] logger.c: -- Executing Hangup("SIP/7914-9313287", "") in new stack Jun 21 11:17:16 DEBUG[5009] pbx.c: Spawn extension (internal,h,1) exited non-zero on 'SIP/7914-9313287' Jun 21 11:17:16 DEBUG[5009] cdr.c: Dropping CDR ! Jun 21 11:17:16 DEBUG[5009] channel.c: Hanging up channel 'SIP/7914-9313287' Jun 21 11:17:16 DEBUG[5009] chan_sip.c: Hangup call SIP/7914-9313287, SIP callid 3c376d536419-hh9gc75x74cz@snom320-000413242B7A) Jun 21 11:17:16 DEBUG[5009] chan_sip.c: update_call_counter(7914) - decrement call limit counter Jun 21 11:17:16 DEBUG[5009] chan_sip.c: Updating call counter for outgoing call Jun 21 11:17:16 DEBUG[4946] chan_sip.c: Checking device state for peer 7914 Jun 21 11:17:16 DEBUG[4946] devicestate.c: Changing state for SIP/7914 - state 1 (Not in use) Jun 21 11:17:16 DEBUG[5018] app_queue.c: Device 'SIP/7914' changed to state '1' (Not in use) Jun 21 11:17:17 VERBOSE[4963] logger.c: Destroying call '3c376d536419-hh9gc75x74cz@snom320-000413242B7A' Jun 21 11:17:19 VERBOSE[5008] logger.c: -- Remote UNIX connection disconnected Jun 21 11:17:37 DEBUG[4946] chan_iax2.c: Checking device state for device 7200 Jun 21 11:17:37 DEBUG[4946] chan_iax2.c: iax2_devicestate(7200): Found peer. What's device state of 7200? addr=2009596426, defaddr=0 maxms=0, lastms=0 Jun 21 11:17:37 DEBUG[4946] devicestate.c: Changing state for IAX2/7200 - state 1 (Not in use) Jun 21 11:17:37 DEBUG[5020] app_queue.c: Device 'IAX2/7200' changed to state '1' (Not in use) Jun 21 11:17:37 NOTICE[4954] chan_iax2.c: Restricting registration for peer '7200' to 60 seconds (requested 240) Jun 21 11:17:37 DEBUG[4946] chan_iax2.c: Checking device state for device 7200 Jun 21 11:17:37 DEBUG[4946] chan_iax2.c: iax2_devicestate(7200): Found peer. What's device state of 7200? addr=2009596426, defaddr=0 maxms=0, lastms=0 Jun 21 11:17:37 DEBUG[4946] devicestate.c: Changing state for IAX2/7200 - state 1 (Not in use) Jun 21 11:17:37 DEBUG[5021] app_queue.c: Device 'IAX2/7200' changed to state '1' (Not in use) Jun 21 11:18:23 DEBUG[4946] chan_iax2.c: Checking device state for device 7200 Jun 21 11:18:23 DEBUG[4946] chan_iax2.c: iax2_devicestate(7200): Found peer. What's device state of 7200? addr=2009596426, defaddr=0 maxms=0, lastms=0 Jun 21 11:18:23 DEBUG[4946] devicestate.c: Changing state for IAX2/7200 - state 1 (Not in use) Jun 21 11:18:23 DEBUG[5022] app_queue.c: Device 'IAX2/7200' changed to state '1' (Not in use) Jun 21 11:18:23 NOTICE[4954] chan_iax2.c: Restricting registration for peer '7200' to 60 seconds (requested 240) Jun 21 11:18:23 DEBUG[4946] chan_iax2.c: Checking device state for device 7200 Jun 21 11:18:23 DEBUG[4946] chan_iax2.c: iax2_devicestate(7200): Found peer. What's device state of 7200? addr=2009596426, defaddr=0 maxms=0, lastms=0 Jun 21 11:18:23 DEBUG[4946] devicestate.c: Changing state for IAX2/7200 - state 1 (Not in use) Jun 21 11:18:23 DEBUG[5023] app_queue.c: Device 'IAX2/7200' changed to state '1' (Not in use) Jun 21 11:19:09 DEBUG[4946] chan_iax2.c: Checking device state for device 7200 Jun 21 11:19:09 DEBUG[4946] chan_iax2.c: iax2_devicestate(7200): Found peer. What's device state of 7200? addr=2009596426, defaddr=0 maxms=0, lastms=0 Jun 21 11:19:09 DEBUG[4946] devicestate.c: Changing state for IAX2/7200 - state 1 (Not in use) Jun 21 11:19:09 DEBUG[5024] app_queue.c: Device 'IAX2/7200' changed to state '1' (Not in use) Jun 21 11:19:09 NOTICE[4954] chan_iax2.c: Restricting registration for peer '7200' to 60 seconds (requested 240) Jun 21 11:19:09 DEBUG[4946] chan_iax2.c: Checking device state for device 7200 Jun 21 11:19:09 DEBUG[4946] chan_iax2.c: iax2_devicestate(7200): Found peer. What's device state of 7200? addr=2009596426, defaddr=0 maxms=0, lastms=0 Jun 21 11:19:09 DEBUG[4946] devicestate.c: Changing state for IAX2/7200 - state 1 (Not in use) Jun 21 11:19:09 DEBUG[5025] app_queue.c: Device 'IAX2/7200' changed to state '1' (Not in use)