[Mar 6 22:12:46] <--- SIP read from 192.168.1.209:2051 ---> INVITE sip:asterisk@192.168.1.101 SIP/2.0 Via: SIP/2.0/UDP 192.168.1.209:2051;branch=z9hG4bK-lh5h1j43l0v3;rport From: ;tag=pqlju95znl To: "BNET-" ;tag=as6200e764 Call-ID: 0bdd2305080dc8592e5ef52d01eebafe@192.168.1.101 CSeq: 1 INVITE Max-Forwards: 70 Contact: ;flow-id=1 P-Key-Flags: keys="3" User-Agent: snom300/6.5.2 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 Min-SE: 90 Content-Type: application/sdp Content-Length: 453 v=0 o=root 1853686946 1853686948 IN IP4 192.168.1.209 s=call c=IN IP4 192.168.1.209 t=0 0 m=audio 63056 RTP/AVP 18 0 9 2 3 4 101 a=crypto:1 AES_CM_128_HMAC_SHA1_32 inline:scZOxywvXmhtxhtmb8Ry0jHt+lh9i7WpJuob/juZ a=rtpmap:18 g729/8000 a=rtpmap:0 pcmu/8000 a=rtpmap:9 g722/8000 a=rtpmap:2 g726-32/8000 a=rtpmap:3 gsm/8000 a=rtpmap:4 g723/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 a=encryption:optional a=sendonly <-------------> [Mar 6 22:12:46] DEBUG[28809]: chan_sip.c:4571 parse_request: Header 0: INVITE sip:asterisk@192.168.1.101 SIP/2.0 (41) [Mar 6 22:12:46] DEBUG[28809]: chan_sip.c:4571 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.1.209:2051;branch=z9hG4bK-lh5h1j43l0v3;rport (69) [Mar 6 22:12:46] DEBUG[28809]: chan_sip.c:4571 parse_request: Header 2: From: ;tag=pqlju95znl (63) [Mar 6 22:12:46] DEBUG[28809]: chan_sip.c:4571 parse_request: Header 3: To: "BNET-" ;tag=as6200e764 (55) [Mar 6 22:12:46] DEBUG[28809]: chan_sip.c:4571 parse_request: Header 4: Call-ID: 0bdd2305080dc8592e5ef52d01eebafe@192.168.1.101 (55) [Mar 6 22:12:46] DEBUG[28809]: chan_sip.c:4571 parse_request: Header 5: CSeq: 1 INVITE (14) [Mar 6 22:12:46] DEBUG[28809]: chan_sip.c:4571 parse_request: Header 6: Max-Forwards: 70 (16) [Mar 6 22:12:46] DEBUG[28809]: chan_sip.c:4571 parse_request: Header 7: Contact: ;flow-id=1 (61) [Mar 6 22:12:46] DEBUG[28809]: chan_sip.c:4571 parse_request: Header 8: P-Key-Flags: keys="3" (21) [Mar 6 22:12:46] DEBUG[28809]: chan_sip.c:4571 parse_request: Header 9: User-Agent: snom300/6.5.2 (25) [Mar 6 22:12:46] DEBUG[28809]: chan_sip.c:4571 parse_request: Header 10: Accept: application/sdp (23) [Mar 6 22:12:46] DEBUG[28809]: chan_sip.c:4571 parse_request: Header 11: Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO (88) [Mar 6 22:12:46] DEBUG[28809]: chan_sip.c:4571 parse_request: Header 12: Allow-Events: talk, hold, refer (31) [Mar 6 22:12:46] DEBUG[28809]: chan_sip.c:4571 parse_request: Header 13: Supported: timer, 100rel, replaces, callerid (44) [Mar 6 22:12:46] DEBUG[28809]: chan_sip.c:4571 parse_request: Header 14: Session-Expires: 3600;refresher=uas (35) [Mar 6 22:12:46] DEBUG[28809]: chan_sip.c:4571 parse_request: Header 15: Min-SE: 90 (10) [Mar 6 22:12:46] DEBUG[28809]: chan_sip.c:4571 parse_request: Header 16: Content-Type: application/sdp (29) [Mar 6 22:12:46] DEBUG[28809]: chan_sip.c:4571 parse_request: Header 17: Content-Length: 453 (19) [Mar 6 22:12:46] DEBUG[28809]: chan_sip.c:4571 parse_request: Header 18: (0) [Mar 6 22:12:46] DEBUG[28809]: chan_sip.c:4603 parse_request: Line: v=0 (3) [Mar 6 22:12:46] DEBUG[28809]: chan_sip.c:4603 parse_request: Line: o=root 1853686946 1853686948 IN IP4 192.168.1.209 (49) [Mar 6 22:12:46] DEBUG[28809]: chan_sip.c:4603 parse_request: Line: s=call (6) [Mar 6 22:12:46] DEBUG[28809]: chan_sip.c:4603 parse_request: Line: c=IN IP4 192.168.1.209 (22) [Mar 6 22:12:46] DEBUG[28809]: chan_sip.c:4603 parse_request: Line: t=0 0 (5) [Mar 6 22:12:46] DEBUG[28809]: chan_sip.c:4603 parse_request: Line: m=audio 63056 RTP/AVP 18 0 9 2 3 4 101 (38) [Mar 6 22:12:46] DEBUG[28809]: chan_sip.c:4603 parse_request: Line: a=crypto:1 AES_CM_128_HMAC_SHA1_32 inline:scZOxywvXmhtxhtmb8Ry0jHt+lh9i7WpJuob/juZ (82) [Mar 6 22:12:46] DEBUG[28809]: chan_sip.c:4603 parse_request: Line: a=rtpmap:18 g729/8000 (21) [Mar 6 22:12:46] DEBUG[28809]: chan_sip.c:4603 parse_request: Line: a=rtpmap:0 pcmu/8000 (20) [Mar 6 22:12:46] DEBUG[28809]: chan_sip.c:4603 parse_request: Line: a=rtpmap:9 g722/8000 (20) [Mar 6 22:12:46] DEBUG[28809]: chan_sip.c:4603 parse_request: Line: a=rtpmap:2 g726-32/8000 (23) [Mar 6 22:12:46] DEBUG[28809]: chan_sip.c:4603 parse_request: Line: a=rtpmap:3 gsm/8000 (19) [Mar 6 22:12:46] DEBUG[28809]: chan_sip.c:4603 parse_request: Line: a=rtpmap:4 g723/8000 (20) [Mar 6 22:12:46] DEBUG[28809]: chan_sip.c:4603 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [Mar 6 22:12:46] DEBUG[28809]: chan_sip.c:4603 parse_request: Line: a=fmtp:101 0-16 (15) [Mar 6 22:12:46] DEBUG[28809]: chan_sip.c:4603 parse_request: Line: a=ptime:20 (10) [Mar 6 22:12:46] DEBUG[28809]: chan_sip.c:4603 parse_request: Line: a=encryption:optional (21) [Mar 6 22:12:46] DEBUG[28809]: chan_sip.c:4603 parse_request: Line: a=sendonly (10) [Mar 6 22:12:46] --- (18 headers 18 lines) --- [Mar 6 22:12:46] DEBUG[28809]: chan_sip.c:14590 handle_request: **** Received INVITE (5) - Command in SIP INVITE [Mar 6 22:12:46] DEBUG[28809]: chan_sip.c:1678 parse_sip_options: Begin: parsing SIP "Supported: timer, 100rel, replaces, callerid" [Mar 6 22:12:46] DEBUG[28809]: chan_sip.c:1686 parse_sip_options: Found SIP option: -timer- [Mar 6 22:12:46] DEBUG[28809]: chan_sip.c:1692 parse_sip_options: Matched SIP option: timer [Mar 6 22:12:46] DEBUG[28809]: chan_sip.c:1686 parse_sip_options: Found SIP option: -100rel- [Mar 6 22:12:46] DEBUG[28809]: chan_sip.c:1692 parse_sip_options: Matched SIP option: 100rel [Mar 6 22:12:46] DEBUG[28809]: chan_sip.c:1686 parse_sip_options: Found SIP option: -replaces- [Mar 6 22:12:46] DEBUG[28809]: chan_sip.c:1692 parse_sip_options: Matched SIP option: replaces [Mar 6 22:12:46] DEBUG[28809]: chan_sip.c:1686 parse_sip_options: Found SIP option: -callerid- [Mar 6 22:12:46] DEBUG[28809]: chan_sip.c:1700 parse_sip_options: Found no match for SIP option: callerid (Please file bug report!) [Mar 6 22:12:46] Sending to 192.168.1.209 : 2051 (NAT) [Mar 6 22:12:46] Found RTP audio format 18 [Mar 6 22:12:46] Found RTP audio format 0 [Mar 6 22:12:46] Found RTP audio format 9 [Mar 6 22:12:46] Found RTP audio format 2 [Mar 6 22:12:46] Found RTP audio format 3 [Mar 6 22:12:46] Found RTP audio format 4 [Mar 6 22:12:46] Found RTP audio format 101 [Mar 6 22:12:46] Peer audio RTP is at port 192.168.1.209:63056 [Mar 6 22:12:46] Got unsupported a:crypto in SDP offer [Mar 6 22:12:46] Found description format g729 for ID 18 [Mar 6 22:12:46] Found description format pcmu for ID 0 [Mar 6 22:12:46] Found description format g722 for ID 9 [Mar 6 22:12:46] Found description format g726-32 for ID 2 [Mar 6 22:12:46] Found description format gsm for ID 3 [Mar 6 22:12:46] Found description format g723 for ID 4 [Mar 6 22:12:46] Found description format telephone-event for ID 101 [Mar 6 22:12:46] Got unsupported a:fmtp in SDP offer [Mar 6 22:12:46] DEBUG[28809]: chan_sip.c:5123 process_sdp: T38 state changed to 0 on channel SIP/217-083f5750 [Mar 6 22:12:46] Capabilities: us - 0x10e (gsm|ulaw|alaw|g729), peer - audio=0x1907 (g723|gsm|ulaw|g726|g729|g722)/video=0x0 (nothing), combined - 0x106 (gsm|ulaw|g729) [Mar 6 22:12:46] Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) [Mar 6 22:12:46] Peer audio RTP is at port 192.168.1.209:63056 [Mar 6 22:12:46] DEBUG[28809]: chan_sip.c:5203 process_sdp: We're settling with these formats: 0x106 (gsm|ulaw|g729) [Mar 6 22:12:46] DEBUG[28809]: chan_sip.c:5210 process_sdp: We have an owner, now see if we need to change this call [Mar 6 22:12:46] DEBUG[28809]: chan_sip.c:13431 handle_request_invite: Got a SIP re-invite for call 0bdd2305080dc8592e5ef52d01eebafe@192.168.1.101 [Mar 6 22:12:46] DEBUG[28809]: chan_sip.c:13526 handle_request_invite: SIP/217-083f5750: This call is UP.... [Mar 6 22:12:46] DEBUG[28809]: chan_sip.c:6414 transmit_response_with_sdp: Setting framing from config on incoming call [Mar 6 22:12:46] DEBUG[28809]: chan_sip.c:6182 add_sdp: ** Our capability: 0x106 (gsm|ulaw|g729) Video flag: True [Mar 6 22:12:46] DEBUG[28809]: chan_sip.c:6183 add_sdp: ** Our prefcodec: 0x100 (g729) [Mar 6 22:12:46] Audio is at 192.168.1.101 port 11656 [Mar 6 22:12:46] Adding codec 0x100 (g729) to SDP [Mar 6 22:12:46] Adding codec 0x2 (gsm) to SDP [Mar 6 22:12:46] Adding codec 0x4 (ulaw) to SDP [Mar 6 22:12:46] Adding non-codec 0x1 (telephone-event) to SDP [Mar 6 22:12:46] DEBUG[28809]: chan_sip.c:6314 add_sdp: -- Done with adding codecs to SDP [Mar 6 22:12:46] DEBUG[28809]: chan_sip.c:6359 add_sdp: Done building SDP. Settling with this capability: 0x106 (gsm|ulaw|g729) [Mar 6 22:12:46] <--- Reliably Transmitting (NAT) to 192.168.1.209:2051 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.1.209:2051;branch=z9hG4bK-lh5h1j43l0v3;received=192.168.1.209;rport=2051 From: ;tag=pqlju95znl To: "BNET-" ;tag=as6200e764 Call-ID: 0bdd2305080dc8592e5ef52d01eebafe@192.168.1.101 CSeq: 1 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Type: application/sdp Content-Length: 312 v=0 o=root 28803 28804 IN IP4 192.168.1.101 s=session c=IN IP4 192.168.1.101 t=0 0 m=audio 11656 RTP/AVP 18 3 0 101 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:3 GSM/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=recvonly <------------> [Mar 6 22:12:46] DEBUG[28809]: chan_sip.c:1973 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #645 [Mar 6 22:12:46] -- Started music on hold, class 'default', on SIP/192.168.1.101-084df348 [Mar 6 22:12:46] DEBUG[28845]: res_musiconhold.c:254 ast_moh_files_next: SIP/192.168.1.101-084df348 Opened file 1 '/var/lib/asterisk/moh/fpm-sunshine' [Mar 6 22:12:46] <--- SIP read from 192.168.1.209:2051 ---> ACK sip:asterisk@192.168.1.101 SIP/2.0 Via: SIP/2.0/UDP 192.168.1.209:2051;branch=z9hG4bK-mk621n7mmzqe;rport From: ;tag=pqlju95znl To: "BNET-" ;tag=as6200e764 Call-ID: 0bdd2305080dc8592e5ef52d01eebafe@192.168.1.101 CSeq: 1 ACK Max-Forwards: 70 Contact: ;flow-id=1 Content-Length: 0 <-------------> [Mar 6 22:12:46] DEBUG[28809]: chan_sip.c:4571 parse_request: Header 0: ACK sip:asterisk@192.168.1.101 SIP/2.0 (38) [Mar 6 22:12:46] DEBUG[28809]: chan_sip.c:4571 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.1.209:2051;branch=z9hG4bK-mk621n7mmzqe;rport (69) [Mar 6 22:12:46] DEBUG[28809]: chan_sip.c:4571 parse_request: Header 2: From: ;tag=pqlju95znl (63) [Mar 6 22:12:46] DEBUG[28809]: chan_sip.c:4571 parse_request: Header 3: To: "BNET-" ;tag=as6200e764 (55) [Mar 6 22:12:46] DEBUG[28809]: chan_sip.c:4571 parse_request: Header 4: Call-ID: 0bdd2305080dc8592e5ef52d01eebafe@192.168.1.101 (55) [Mar 6 22:12:46] DEBUG[28809]: chan_sip.c:4571 parse_request: Header 5: CSeq: 1 ACK (11) [Mar 6 22:12:46] DEBUG[28809]: chan_sip.c:4571 parse_request: Header 6: Max-Forwards: 70 (16) [Mar 6 22:12:46] DEBUG[28809]: chan_sip.c:4571 parse_request: Header 7: Contact: ;flow-id=1 (61) [Mar 6 22:12:46] DEBUG[28809]: chan_sip.c:4571 parse_request: Header 8: Content-Length: 0 (17) [Mar 6 22:12:46] DEBUG[28809]: chan_sip.c:4571 parse_request: Header 9: (0) [Mar 6 22:12:46] --- (9 headers 0 lines) --- [Mar 6 22:12:46] DEBUG[28809]: chan_sip.c:14590 handle_request: **** Received ACK (6) - Command in SIP ACK [Mar 6 22:12:46] DEBUG[28809]: chan_sip.c:2077 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #645 [Mar 6 22:12:46] DEBUG[28809]: chan_sip.c:2087 __sip_ack: Stopping retransmission on '0bdd2305080dc8592e5ef52d01eebafe@192.168.1.101' of Response 1: Match Not Found [Mar 6 22:12:46] DEBUG[28809]: chan_sip.c:2008 __sip_autodestruct: Auto destroying SIP dialog '4d884666-2c401540-f43e95a1@192.168.1.105' [Mar 6 22:12:46] DEBUG[28809]: chan_sip.c:3107 sip_destroy: Destroying SIP dialog 4d884666-2c401540-f43e95a1@192.168.1.105 [Mar 6 22:12:46] Really destroying SIP dialog '4d884666-2c401540-f43e95a1@192.168.1.105' Method: REGISTER [Mar 6 22:12:48] DEBUG[28809]: chan_sip.c:2008 __sip_autodestruct: Auto destroying SIP dialog 'f1b5116e-3e26a2de@192.168.1.24' [Mar 6 22:12:48] DEBUG[28809]: chan_sip.c:3107 sip_destroy: Destroying SIP dialog f1b5116e-3e26a2de@192.168.1.24 [Mar 6 22:12:48] Really destroying SIP dialog 'f1b5116e-3e26a2de@192.168.1.24' Method: REGISTER [Mar 6 22:12:51] DEBUG[28845]: rtp.c:2687 ast_rtp_write: Created smoother: format: 256 ms: 20 len: 20 [Mar 6 22:12:51] <--- SIP read from 192.168.1.209:2051 ---> REFER sip:asterisk@192.168.1.101 SIP/2.0 Via: SIP/2.0/UDP 192.168.1.209:2051;branch=z9hG4bK-2ac8e2bfp22v;rport From: ;tag=pqlju95znl To: "BNET-" ;tag=as6200e764 Call-ID: 0bdd2305080dc8592e5ef52d01eebafe@192.168.1.101 CSeq: 2 REFER Max-Forwards: 70 Contact: ;flow-id=1 Refer-To: sip:221@192.168.1.101;user=phone Referred-By: sip:217@192.168.1.101 User-Agent: snom300/6.5.2 Content-Length: 0 <-------------> [Mar 6 22:12:51] DEBUG[28809]: chan_sip.c:4571 parse_request: Header 0: REFER sip:asterisk@192.168.1.101 SIP/2.0 (40) [Mar 6 22:12:51] DEBUG[28809]: chan_sip.c:4571 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.1.209:2051;branch=z9hG4bK-2ac8e2bfp22v;rport (69) [Mar 6 22:12:51] DEBUG[28809]: chan_sip.c:4571 parse_request: Header 2: From: ;tag=pqlju95znl (63) [Mar 6 22:12:51] DEBUG[28809]: chan_sip.c:4571 parse_request: Header 3: To: "BNET-" ;tag=as6200e764 (55) [Mar 6 22:12:51] DEBUG[28809]: chan_sip.c:4571 parse_request: Header 4: Call-ID: 0bdd2305080dc8592e5ef52d01eebafe@192.168.1.101 (55) [Mar 6 22:12:51] DEBUG[28809]: chan_sip.c:4571 parse_request: Header 5: CSeq: 2 REFER (13) [Mar 6 22:12:51] DEBUG[28809]: chan_sip.c:4571 parse_request: Header 6: Max-Forwards: 70 (16) [Mar 6 22:12:51] DEBUG[28809]: chan_sip.c:4571 parse_request: Header 7: Contact: ;flow-id=1 (61) [Mar 6 22:12:51] DEBUG[28809]: chan_sip.c:4571 parse_request: Header 8: Refer-To: sip:221@192.168.1.101;user=phone (42) [Mar 6 22:12:51] DEBUG[28809]: chan_sip.c:4571 parse_request: Header 9: Referred-By: sip:217@192.168.1.101 (34) [Mar 6 22:12:51] DEBUG[28809]: chan_sip.c:4571 parse_request: Header 10: User-Agent: snom300/6.5.2 (25) [Mar 6 22:12:51] DEBUG[28809]: chan_sip.c:4571 parse_request: Header 11: Content-Length: 0 (17) [Mar 6 22:12:51] DEBUG[28809]: chan_sip.c:4571 parse_request: Header 12: (0) [Mar 6 22:12:51] --- (12 headers 0 lines) --- [Mar 6 22:12:51] DEBUG[28809]: chan_sip.c:14590 handle_request: **** Received REFER (9) - Command in SIP REFER [Mar 6 22:12:51] Call 0bdd2305080dc8592e5ef52d01eebafe@192.168.1.101 got a SIP call transfer from caller: (REFER)! [Mar 6 22:12:51] SIP transfer to extension 221@internal by 217@192.168.1.101 [Mar 6 22:12:51] DEBUG[28809]: chan_sip.c:13931 handle_request_refer: SIP blind transfer: Transferer channel SIP/217-083f5750, transferee channel SIP/192.168.1.101-084df348 [Mar 6 22:12:51] DEBUG[28809]: chan_sip.c:13947 handle_request_refer: Got SIP transfer, applying to bridged peer 'SIP/192.168.1.101-084df348' [Mar 6 22:12:51] <--- Transmitting (NAT) to 192.168.1.209:2051 ---> SIP/2.0 202 Accepted Via: SIP/2.0/UDP 192.168.1.209:2051;branch=z9hG4bK-2ac8e2bfp22v;received=192.168.1.209;rport=2051 From: ;tag=pqlju95znl To: "BNET-" ;tag=as6200e764 Call-ID: 0bdd2305080dc8592e5ef52d01eebafe@192.168.1.101 CSeq: 2 REFER User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Length: 0 <------------> [Mar 6 22:12:51] DEBUG[28809]: chan_sip.c:13985 handle_request_refer: chan1->name: SIP/217-083f5750