[Dec 18 10:59:26] VERBOSE[26147] logger.c: <--- SIP read from 82.94.244.100:5060 ---> INVITE sip:6660@82.94.244.105 SIP/2.0 Via: SIP/2.0/UDP 82.94.244.100:5060;branch=z9hG4bK-5f52dop8 Via: SIP/2.0/UDP 192.168.100.27:5070;branch=z9hG4bK-48ffce71 Call-ID: ee172329-35a0d169@192.168.100.27 CSeq: 101 INVITE Max-Forwards: 70 Contact: "Office 1001" Expires: 240 User-Agent: Sipura/SPA941-4.1.8 Content-Length: 289 Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER Content-Type: application/sdp From: "Office 1001" ;tag=77d8f82994410069o0 To: Record-Route: v=0 o=- 84217855 84217855 IN IP4 192.168.100.27 s=- c=IN IP4 192.168.100.27 t=0 0 m=audio 16420 RTP/AVP 0 4 8 18 101 a=rtpmap:0 PCMU/8000 a=rtpmap:4 G723/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:18 G729a/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=ptime:30 a=sendrecv <-------------> [Dec 18 10:59:26] DEBUG[26147] chan_sip.c: Header 0 [ 37]: INVITE sip:6660@82.94.244.105 SIP/2.0 [Dec 18 10:59:26] DEBUG[26147] chan_sip.c: Header 1 [ 59]: Via: SIP/2.0/UDP 82.94.244.100:5060;branch=z9hG4bK-5f52dop8 [Dec 18 10:59:26] DEBUG[26147] chan_sip.c: Header 2 [ 60]: Via: SIP/2.0/UDP 192.168.100.27:5070;branch=z9hG4bK-48ffce71 [Dec 18 10:59:26] DEBUG[26147] chan_sip.c: Header 3 [ 41]: Call-ID: ee172329-35a0d169@192.168.100.27 [Dec 18 10:59:26] DEBUG[26147] chan_sip.c: Header 4 [ 16]: CSeq: 101 INVITE [Dec 18 10:59:26] DEBUG[26147] chan_sip.c: Header 5 [ 16]: Max-Forwards: 70 [Dec 18 10:59:26] DEBUG[26147] chan_sip.c: Header 6 [ 53]: Contact: "Office 1001" [Dec 18 10:59:26] DEBUG[26147] chan_sip.c: Header 7 [ 12]: Expires: 240 [Dec 18 10:59:26] DEBUG[26147] chan_sip.c: Header 8 [ 31]: User-Agent: Sipura/SPA941-4.1.8 [Dec 18 10:59:26] DEBUG[26147] chan_sip.c: Header 9 [ 19]: Content-Length: 289 [Dec 18 10:59:26] DEBUG[26147] chan_sip.c: Header 10 [ 61]: Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER [Dec 18 10:59:26] DEBUG[26147] chan_sip.c: Header 11 [ 29]: Content-Type: application/sdp [Dec 18 10:59:26] DEBUG[26147] chan_sip.c: Header 12 [ 67]: From: "Office 1001" ;tag=77d8f82994410069o0 [Dec 18 10:59:26] DEBUG[26147] chan_sip.c: Header 13 [ 29]: To: [Dec 18 10:59:26] DEBUG[26147] chan_sip.c: Header 14 [ 41]: Record-Route: [Dec 18 10:59:26] DEBUG[26147] chan_sip.c: Header 15 [ 0]: [Dec 18 10:59:26] DEBUG[26147] chan_sip.c: Body 0 [ 3]: v=0 [Dec 18 10:59:26] DEBUG[26147] chan_sip.c: Body 1 [ 43]: o=- 84217855 84217855 IN IP4 192.168.100.27 [Dec 18 10:59:26] DEBUG[26147] chan_sip.c: Body 2 [ 3]: s=- [Dec 18 10:59:26] DEBUG[26147] chan_sip.c: Body 3 [ 23]: c=IN IP4 192.168.100.27 [Dec 18 10:59:26] DEBUG[26147] chan_sip.c: Body 4 [ 5]: t=0 0 [Dec 18 10:59:26] DEBUG[26147] chan_sip.c: Body 5 [ 34]: m=audio 16420 RTP/AVP 0 4 8 18 101 [Dec 18 10:59:26] DEBUG[26147] chan_sip.c: Body 6 [ 20]: a=rtpmap:0 PCMU/8000 [Dec 18 10:59:26] DEBUG[26147] chan_sip.c: Body 7 [ 20]: a=rtpmap:4 G723/8000 [Dec 18 10:59:26] DEBUG[26147] chan_sip.c: Body 8 [ 20]: a=rtpmap:8 PCMA/8000 [Dec 18 10:59:26] DEBUG[26147] chan_sip.c: Body 9 [ 22]: a=rtpmap:18 G729a/8000 [Dec 18 10:59:26] DEBUG[26147] chan_sip.c: Body 10 [ 33]: a=rtpmap:101 telephone-event/8000 [Dec 18 10:59:26] DEBUG[26147] chan_sip.c: Body 11 [ 15]: a=fmtp:101 0-15 [Dec 18 10:59:26] DEBUG[26147] chan_sip.c: Body 12 [ 10]: a=ptime:30 [Dec 18 10:59:26] DEBUG[26147] chan_sip.c: Body 13 [ 10]: a=sendrecv [Dec 18 10:59:26] VERBOSE[26147] logger.c: --- (15 headers 14 lines) --- [Dec 18 10:59:26] DEBUG[26147] chan_sip.c: Setting NAT on RTP to Off [Dec 18 10:59:26] DEBUG[26147] chan_sip.c: Allocating new SIP dialog for ee172329-35a0d169@192.168.100.27 - INVITE (With RTP) [Dec 18 10:59:26] DEBUG[26147] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE [Dec 18 10:59:26] VERBOSE[26147] logger.c: **** Received INVITE (5) - Command in SIP INVITE [Dec 18 10:59:26] VERBOSE[26147] logger.c: Sending to 82.94.244.100 : 5060 (no NAT) [Dec 18 10:59:26] DEBUG[26147] chan_sip.c: Initializing initreq for method INVITE - callid ee172329-35a0d169@192.168.100.27 [Dec 18 10:59:26] VERBOSE[26147] logger.c: Using INVITE request as basis request - ee172329-35a0d169@192.168.100.27 [Dec 18 10:59:26] VERBOSE[26147] logger.c: No user '1001' in SIP users list [Dec 18 10:59:26] VERBOSE[26147] logger.c: Found peer '82.94.244.100' for '1001' from 82.94.244.100:5060 [Dec 18 10:59:26] DEBUG[26147] chan_sip.c: Setting NAT on RTP to Off [Dec 18 10:59:26] VERBOSE[26147] logger.c: Found RTP audio format 0 [Dec 18 10:59:26] VERBOSE[26147] logger.c: Found RTP audio format 4 [Dec 18 10:59:26] VERBOSE[26147] logger.c: Found RTP audio format 8 [Dec 18 10:59:26] VERBOSE[26147] logger.c: Found RTP audio format 18 [Dec 18 10:59:26] VERBOSE[26147] logger.c: Found RTP audio format 101 [Dec 18 10:59:26] VERBOSE[26147] logger.c: Peer audio RTP is at port 192.168.100.27:16420 [Dec 18 10:59:26] VERBOSE[26147] logger.c: Found description format PCMU for ID 0 [Dec 18 10:59:26] VERBOSE[26147] logger.c: Found description format G723 for ID 4 [Dec 18 10:59:26] VERBOSE[26147] logger.c: Found description format PCMA for ID 8 [Dec 18 10:59:26] VERBOSE[26147] logger.c: Found description format G729a for ID 18 [Dec 18 10:59:26] VERBOSE[26147] logger.c: Found description format telephone-event for ID 101 [Dec 18 10:59:26] VERBOSE[26147] logger.c: Got unsupported a:fmtp in SDP offer [Dec 18 10:59:26] DEBUG[26147] chan_sip.c: T38 state changed to 0 on channel [Dec 18 10:59:26] VERBOSE[26147] logger.c: Capabilities: us - 0x8000e (gsm|ulaw|alaw|h263), peer - audio=0x10d (g723|ulaw|alaw|g729)/video=0x0 (nothing), combined - 0xc (ulaw|alaw) [Dec 18 10:59:26] VERBOSE[26147] logger.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) [Dec 18 10:59:26] VERBOSE[26147] logger.c: Peer audio RTP is at port 192.168.100.27:16420 [Dec 18 10:59:26] DEBUG[26147] chan_sip.c: We're settling with these formats: 0xc (ulaw|alaw) [Dec 18 10:59:26] DEBUG[26147] chan_sip.c: Checking SIP call limits for device [Dec 18 10:59:26] DEBUG[26147] chan_sip.c: Updating call counter for incoming call [Dec 18 10:59:26] VERBOSE[26147] logger.c: Looking for 6660 in default (domain 82.94.244.105) [Dec 18 10:59:26] DEBUG[26147] frame.c: Could not find preferred codec - Going for the best codec [Dec 18 10:59:26] DEBUG[26147] chan_sip.c: *** Our native formats are 0x4 (ulaw) [Dec 18 10:59:26] DEBUG[26147] chan_sip.c: *** Joint capabilities are 0xc (ulaw|alaw) [Dec 18 10:59:26] DEBUG[26147] chan_sip.c: *** Our capabilities are 0x8000e (gsm|ulaw|alaw|h263) [Dec 18 10:59:26] DEBUG[26147] frame.c: Could not find preferred codec - Going for the best codec [Dec 18 10:59:26] DEBUG[26147] chan_sip.c: *** AST_CODEC_CHOOSE formats are 0x4 (ulaw) [Dec 18 10:59:26] DEBUG[26147] chan_sip.c: This channel will not be able to handle video. [Dec 18 10:59:26] DEBUG[26147] chan_sip.c: build_route: Record-Route hop: [Dec 18 10:59:26] VERBOSE[26147] logger.c: list_route: hop: [Dec 18 10:59:26] DEBUG[26147] chan_sip.c: SIP/82.94.244.100-006e6480: New call is still down.... Trying... [Dec 18 10:59:26] VERBOSE[26147] logger.c: <--- Transmitting (no NAT) to 82.94.244.100:5060 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 82.94.244.100:5060;branch=z9hG4bK-5f52dop8;received=82.94.244.100 Via: SIP/2.0/UDP 192.168.100.27:5070;branch=z9hG4bK-48ffce71 From: "Office 1001" ;tag=77d8f82994410069o0 To: Call-ID: ee172329-35a0d169@192.168.100.27 CSeq: 101 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Length: 0 <------------> [Dec 18 10:59:26] DEBUG[26147] devicestate.c: Notification of state change to be queued on device/channel SIP/82.94.244.100-006e6480 [Dec 18 10:59:26] DEBUG[26144] devicestate.c: No provider found, checking channel drivers for SIP - 82.94.244.100 [Dec 18 10:59:26] DEBUG[26144] chan_sip.c: Checking device state for peer 82.94.244.100 [Dec 18 10:59:26] DEBUG[26144] devicestate.c: Changing state for SIP/82.94.244.100 - state 1 (Not in use) [Dec 18 10:59:26] DEBUG[26149] pbx.c: Launching 'NoOp' [Dec 18 10:59:26] VERBOSE[26149] logger.c: -- Executing [6660@default:1] NoOp("SIP/82.94.244.100-006e6480", "INVALID EXTENSION from to 6660") in new stack [Dec 18 10:59:26] DEBUG[26149] pbx.c: Launching 'Playback' [Dec 18 10:59:26] VERBOSE[26149] logger.c: -- Executing [6660@default:2] Playback("SIP/82.94.244.100-006e6480", "pbx-invalid") in new stack [Dec 18 10:59:26] DEBUG[26149] devicestate.c: Notification of state change to be queued on device/channel SIP/82.94.244.100-006e6480 [Dec 18 10:59:26] DEBUG[26149] chan_sip.c: SIP answering channel: SIP/82.94.244.100-006e6480 [Dec 18 10:59:26] DEBUG[26144] devicestate.c: No provider found, checking channel drivers for SIP - 82.94.244.100 [Dec 18 10:59:26] DEBUG[26149] chan_sip.c: Setting framing from config on incoming call [Dec 18 10:59:26] DEBUG[26144] chan_sip.c: Checking device state for peer 82.94.244.100 [Dec 18 10:59:26] DEBUG[26149] chan_sip.c: ** Our capability: 0xc (ulaw|alaw) Video flag: True [Dec 18 10:59:26] DEBUG[26144] devicestate.c: Changing state for SIP/82.94.244.100 - state 1 (Not in use) [Dec 18 10:59:26] DEBUG[26149] chan_sip.c: ** Our prefcodec: 0x0 (nothing) [Dec 18 10:59:26] VERBOSE[26149] logger.c: Audio is at 82.94.244.105 port 13658 [Dec 18 10:59:26] VERBOSE[26149] logger.c: Adding codec 0x4 (ulaw) to SDP [Dec 18 10:59:26] VERBOSE[26149] logger.c: Adding codec 0x8 (alaw) to SDP [Dec 18 10:59:26] VERBOSE[26149] logger.c: Adding non-codec 0x1 (telephone-event) to SDP [Dec 18 10:59:26] DEBUG[26149] chan_sip.c: -- Done with adding codecs to SDP [Dec 18 10:59:26] DEBUG[26149] channel.c: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1) [Dec 18 10:59:26] DEBUG[26149] chan_sip.c: Done building SDP. Settling with this capability: 0xc (ulaw|alaw) [Dec 18 10:59:26] VERBOSE[26149] logger.c: <--- Reliably Transmitting (no NAT) to 82.94.244.100:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 82.94.244.100:5060;branch=z9hG4bK-5f52dop8;received=82.94.244.100 Via: SIP/2.0/UDP 192.168.100.27:5070;branch=z9hG4bK-48ffce71 Record-Route: From: "Office 1001" ;tag=77d8f82994410069o0 To: ;tag=as15de7753 Call-ID: ee172329-35a0d169@192.168.100.27 CSeq: 101 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Type: application/sdp Content-Length: 266 v=0 o=root 26141 26141 IN IP4 82.94.244.105 s=session c=IN IP4 82.94.244.105 t=0 0 m=audio 13658 RTP/AVP 0 8 101 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv <------------> [Dec 18 10:59:26] DEBUG[26149] chan_sip.c: *** SIP TIMER: Initalizing retransmit timer on packet: Id #7 [Dec 18 10:59:26] DEBUG[26149] channel.c: Set channel SIP/82.94.244.100-006e6480 to write format gsm [Dec 18 10:59:26] DEBUG[26149] rtp.c: Ooh, format changed from unknown to ulaw [Dec 18 10:59:26] DEBUG[26149] rtp.c: Created smoother: format: 4 ms: 20 len: 160 [Dec 18 10:59:26] VERBOSE[26149] logger.c: -- Playing 'pbx-invalid' (language 'en') [Dec 18 10:59:26] VERBOSE[26147] logger.c: <--- SIP read from 82.94.244.100:5060 ---> ACK sip:6660@82.94.244.105 SIP/2.0 Via: SIP/2.0/UDP 82.94.244.100:5060;branch=z9hG4bK-co8dwgm3 Via: SIP/2.0/UDP 192.168.100.27:5070;branch=z9hG4bK-fe9adefd From: "Office 1001" ;tag=77d8f82994410069o0 To: ;tag=as15de7753 Call-ID: ee172329-35a0d169@192.168.100.27 CSeq: 101 ACK Max-Forwards: 70 Contact: "Office 1001" User-Agent: Sipura/SPA941-4.1.8 Content-Length: 0 Record-Route: <-------------> [Dec 18 10:59:26] DEBUG[26147] chan_sip.c: Header 0 [ 34]: ACK sip:6660@82.94.244.105 SIP/2.0 [Dec 18 10:59:26] DEBUG[26147] chan_sip.c: Header 1 [ 59]: Via: SIP/2.0/UDP 82.94.244.100:5060;branch=z9hG4bK-co8dwgm3 [Dec 18 10:59:26] DEBUG[26147] chan_sip.c: Header 2 [ 60]: Via: SIP/2.0/UDP 192.168.100.27:5070;branch=z9hG4bK-fe9adefd [Dec 18 10:59:26] DEBUG[26147] chan_sip.c: Header 3 [ 67]: From: "Office 1001" ;tag=77d8f82994410069o0 [Dec 18 10:59:26] DEBUG[26147] chan_sip.c: Header 4 [ 43]: To: ;tag=as15de7753 [Dec 18 10:59:26] DEBUG[26147] chan_sip.c: Header 5 [ 41]: Call-ID: ee172329-35a0d169@192.168.100.27 [Dec 18 10:59:26] DEBUG[26147] chan_sip.c: Header 6 [ 13]: CSeq: 101 ACK [Dec 18 10:59:26] DEBUG[26147] chan_sip.c: Header 7 [ 16]: Max-Forwards: 70 [Dec 18 10:59:26] DEBUG[26147] chan_sip.c: Header 8 [ 53]: Contact: "Office 1001" [Dec 18 10:59:26] DEBUG[26147] chan_sip.c: Header 9 [ 31]: User-Agent: Sipura/SPA941-4.1.8 [Dec 18 10:59:26] DEBUG[26147] chan_sip.c: Header 10 [ 17]: Content-Length: 0 [Dec 18 10:59:26] DEBUG[26147] chan_sip.c: Header 11 [ 41]: Record-Route: [Dec 18 10:59:26] DEBUG[26147] chan_sip.c: Header 12 [ 0]: [Dec 18 10:59:26] VERBOSE[26147] logger.c: --- (12 headers 0 lines) --- [Dec 18 10:59:26] DEBUG[26147] chan_sip.c: = Found Their Call ID: ee172329-35a0d169@192.168.100.27 Their Tag 77d8f82994410069o0 Our tag: as15de7753 [Dec 18 10:59:26] DEBUG[26147] chan_sip.c: **** Received ACK (6) - Command in SIP ACK [Dec 18 10:59:26] VERBOSE[26147] logger.c: **** Received ACK (6) - Command in SIP ACK [Dec 18 10:59:26] VERBOSE[26147] logger.c: setting state to INV_CONFIRMED [Dec 18 10:59:26] DEBUG[26147] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #7 [Dec 18 10:59:26] DEBUG[26147] chan_sip.c: Stopping retransmission on 'ee172329-35a0d169@192.168.100.27' of Response 101: Match Found [Dec 18 10:59:28] VERBOSE[26147] logger.c: <--- SIP read from 82.94.244.100:5060 ---> INVITE sip:6660@82.94.244.105 SIP/2.0 Via: SIP/2.0/UDP 82.94.244.100:5060;branch=z9hG4bK-zdnb8chp Via: SIP/2.0/UDP 192.168.100.27:5070;branch=z9hG4bK-891228a0 From: "Office 1001" ;tag=77d8f82994410069o0 To: ;tag=as15de7753 Call-ID: ee172329-35a0d169@192.168.100.27 CSeq: 102 INVITE Max-Forwards: 70 Contact: "Office 1001" Expires: 30 User-Agent: Sipura/SPA941-4.1.8 Content-Length: 231 Content-Type: application/sdp Record-Route: v=0 o=- 84218106 84218106 IN IP4 192.168.100.27 s=- c=IN IP4 0.0.0.0 t=0 0 m=audio 16420 RTP/AVP 0 8 101 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=ptime:30 a=sendonly <-------------> [Dec 18 10:59:28] DEBUG[26147] chan_sip.c: Header 0 [ 37]: INVITE sip:6660@82.94.244.105 SIP/2.0 [Dec 18 10:59:28] DEBUG[26147] chan_sip.c: Header 1 [ 59]: Via: SIP/2.0/UDP 82.94.244.100:5060;branch=z9hG4bK-zdnb8chp [Dec 18 10:59:28] DEBUG[26147] chan_sip.c: Header 2 [ 60]: Via: SIP/2.0/UDP 192.168.100.27:5070;branch=z9hG4bK-891228a0 [Dec 18 10:59:28] DEBUG[26147] chan_sip.c: Header 3 [ 67]: From: "Office 1001" ;tag=77d8f82994410069o0 [Dec 18 10:59:28] DEBUG[26147] chan_sip.c: Header 4 [ 43]: To: ;tag=as15de7753 [Dec 18 10:59:28] DEBUG[26147] chan_sip.c: Header 5 [ 41]: Call-ID: ee172329-35a0d169@192.168.100.27 [Dec 18 10:59:28] DEBUG[26147] chan_sip.c: Header 6 [ 16]: CSeq: 102 INVITE [Dec 18 10:59:28] DEBUG[26147] chan_sip.c: Header 7 [ 16]: Max-Forwards: 70 [Dec 18 10:59:28] DEBUG[26147] chan_sip.c: Header 8 [ 53]: Contact: "Office 1001" [Dec 18 10:59:28] DEBUG[26147] chan_sip.c: Header 9 [ 11]: Expires: 30 [Dec 18 10:59:28] DEBUG[26147] chan_sip.c: Header 10 [ 31]: User-Agent: Sipura/SPA941-4.1.8 [Dec 18 10:59:28] DEBUG[26147] chan_sip.c: Header 11 [ 19]: Content-Length: 231 [Dec 18 10:59:28] DEBUG[26147] chan_sip.c: Header 12 [ 29]: Content-Type: application/sdp [Dec 18 10:59:28] DEBUG[26147] chan_sip.c: Header 13 [ 41]: Record-Route: [Dec 18 10:59:28] DEBUG[26147] chan_sip.c: Header 14 [ 0]: [Dec 18 10:59:28] DEBUG[26147] chan_sip.c: Body 0 [ 3]: v=0 [Dec 18 10:59:28] DEBUG[26147] chan_sip.c: Body 1 [ 43]: o=- 84218106 84218106 IN IP4 192.168.100.27 [Dec 18 10:59:28] DEBUG[26147] chan_sip.c: Body 2 [ 3]: s=- [Dec 18 10:59:28] DEBUG[26147] chan_sip.c: Body 3 [ 16]: c=IN IP4 0.0.0.0 [Dec 18 10:59:28] DEBUG[26147] chan_sip.c: Body 4 [ 5]: t=0 0 [Dec 18 10:59:28] DEBUG[26147] chan_sip.c: Body 5 [ 29]: m=audio 16420 RTP/AVP 0 8 101 [Dec 18 10:59:28] DEBUG[26147] chan_sip.c: Body 6 [ 20]: a=rtpmap:0 PCMU/8000 [Dec 18 10:59:28] DEBUG[26147] chan_sip.c: Body 7 [ 20]: a=rtpmap:8 PCMA/8000 [Dec 18 10:59:28] DEBUG[26147] chan_sip.c: Body 8 [ 33]: a=rtpmap:101 telephone-event/8000 [Dec 18 10:59:28] DEBUG[26147] chan_sip.c: Body 9 [ 15]: a=fmtp:101 0-15 [Dec 18 10:59:28] DEBUG[26147] chan_sip.c: Body 10 [ 10]: a=ptime:30 [Dec 18 10:59:28] DEBUG[26147] chan_sip.c: Body 11 [ 10]: a=sendonly [Dec 18 10:59:28] VERBOSE[26147] logger.c: --- (14 headers 12 lines) --- [Dec 18 10:59:28] DEBUG[26147] chan_sip.c: = Found Their Call ID: ee172329-35a0d169@192.168.100.27 Their Tag 77d8f82994410069o0 Our tag: as15de7753 [Dec 18 10:59:28] DEBUG[26147] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE [Dec 18 10:59:28] VERBOSE[26147] logger.c: **** Received INVITE (5) - Command in SIP INVITE [Dec 18 10:59:28] VERBOSE[26147] logger.c: Sending to 82.94.244.100 : 5060 (no NAT) [Dec 18 10:59:28] DEBUG[26147] chan_sip.c: Initializing initreq for method INVITE - callid ee172329-35a0d169@192.168.100.27 [Dec 18 10:59:28] VERBOSE[26147] logger.c: Found RTP audio format 0 [Dec 18 10:59:28] VERBOSE[26147] logger.c: Found RTP audio format 8 [Dec 18 10:59:28] VERBOSE[26147] logger.c: Found RTP audio format 101 [Dec 18 10:59:28] VERBOSE[26147] logger.c: Peer audio RTP is at port 0.0.0.0:16420 [Dec 18 10:59:28] VERBOSE[26147] logger.c: Found description format PCMU for ID 0 [Dec 18 10:59:28] VERBOSE[26147] logger.c: Found description format PCMA for ID 8 [Dec 18 10:59:28] VERBOSE[26147] logger.c: Found description format telephone-event for ID 101 [Dec 18 10:59:28] VERBOSE[26147] logger.c: Got unsupported a:fmtp in SDP offer [Dec 18 10:59:28] DEBUG[26147] chan_sip.c: T38 state changed to 0 on channel SIP/82.94.244.100-006e6480 [Dec 18 10:59:28] VERBOSE[26147] logger.c: Capabilities: us - 0x8000e (gsm|ulaw|alaw|h263), peer - audio=0xc (ulaw|alaw)/video=0x0 (nothing), combined - 0xc (ulaw|alaw) [Dec 18 10:59:28] VERBOSE[26147] logger.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) [Dec 18 10:59:28] VERBOSE[26147] logger.c: Peer audio RTP is at port 0.0.0.0:16420 [Dec 18 10:59:28] DEBUG[26147] chan_sip.c: We're settling with these formats: 0xc (ulaw|alaw) [Dec 18 10:59:28] DEBUG[26147] chan_sip.c: We have an owner, now see if we need to change this call [Dec 18 10:59:28] DEBUG[26147] chan_sip.c: Got a SIP re-invite for call ee172329-35a0d169@192.168.100.27 [Dec 18 10:59:28] DEBUG[26147] chan_sip.c: SIP/82.94.244.100-006e6480: This call is UP.... [Dec 18 10:59:28] DEBUG[26147] chan_sip.c: Setting framing from config on incoming call [Dec 18 10:59:28] DEBUG[26147] chan_sip.c: ** Our capability: 0xc (ulaw|alaw) Video flag: True [Dec 18 10:59:28] DEBUG[26147] chan_sip.c: ** Our prefcodec: 0x0 (nothing) [Dec 18 10:59:28] VERBOSE[26147] logger.c: Audio is at 82.94.244.105 port 13658 [Dec 18 10:59:28] VERBOSE[26147] logger.c: Adding codec 0x4 (ulaw) to SDP [Dec 18 10:59:28] VERBOSE[26147] logger.c: Adding codec 0x8 (alaw) to SDP [Dec 18 10:59:28] VERBOSE[26147] logger.c: Adding non-codec 0x1 (telephone-event) to SDP [Dec 18 10:59:28] DEBUG[26147] chan_sip.c: -- Done with adding codecs to SDP [Dec 18 10:59:28] DEBUG[26147] channel.c: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1) [Dec 18 10:59:28] DEBUG[26147] chan_sip.c: Done building SDP. Settling with this capability: 0xc (ulaw|alaw) [Dec 18 10:59:28] VERBOSE[26147] logger.c: <--- Reliably Transmitting (no NAT) to 82.94.244.100:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 82.94.244.100:5060;branch=z9hG4bK-zdnb8chp;received=82.94.244.100 Via: SIP/2.0/UDP 192.168.100.27:5070;branch=z9hG4bK-891228a0 Record-Route: From: "Office 1001" ;tag=77d8f82994410069o0 To: ;tag=as15de7753 Call-ID: ee172329-35a0d169@192.168.100.27 CSeq: 102 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Type: application/sdp Content-Length: 266 v=0 o=root 26141 26142 IN IP4 82.94.244.105 s=session c=IN IP4 82.94.244.105 t=0 0 m=audio 13658 RTP/AVP 0 8 101 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=recvonly <------------> [Dec 18 10:59:28] DEBUG[26147] chan_sip.c: *** SIP TIMER: Initalizing retransmit timer on packet: Id #9 [Dec 18 10:59:29] VERBOSE[26147] logger.c: <--- SIP read from 82.94.244.100:5060 ---> ACK sip:6660@82.94.244.105 SIP/2.0 Via: SIP/2.0/UDP 82.94.244.100:5060;branch=z9hG4bK-crhqz3j1 Via: SIP/2.0/UDP 192.168.100.27:5070;branch=z9hG4bK-ed9d3390 From: "Office 1001" ;tag=77d8f82994410069o0 To: ;tag=as15de7753 Call-ID: ee172329-35a0d169@192.168.100.27 CSeq: 102 ACK Max-Forwards: 70 Contact: "Office 1001" User-Agent: Sipura/SPA941-4.1.8 Content-Length: 0 Record-Route: <-------------> [Dec 18 10:59:29] DEBUG[26147] chan_sip.c: Header 0 [ 34]: ACK sip:6660@82.94.244.105 SIP/2.0 [Dec 18 10:59:29] DEBUG[26147] chan_sip.c: Header 1 [ 59]: Via: SIP/2.0/UDP 82.94.244.100:5060;branch=z9hG4bK-crhqz3j1 [Dec 18 10:59:29] DEBUG[26147] chan_sip.c: Header 2 [ 60]: Via: SIP/2.0/UDP 192.168.100.27:5070;branch=z9hG4bK-ed9d3390 [Dec 18 10:59:29] DEBUG[26147] chan_sip.c: Header 3 [ 67]: From: "Office 1001" ;tag=77d8f82994410069o0 [Dec 18 10:59:29] DEBUG[26147] chan_sip.c: Header 4 [ 43]: To: ;tag=as15de7753 [Dec 18 10:59:29] DEBUG[26147] chan_sip.c: Header 5 [ 41]: Call-ID: ee172329-35a0d169@192.168.100.27 [Dec 18 10:59:29] DEBUG[26147] chan_sip.c: Header 6 [ 13]: CSeq: 102 ACK [Dec 18 10:59:29] DEBUG[26147] chan_sip.c: Header 7 [ 16]: Max-Forwards: 70 [Dec 18 10:59:29] DEBUG[26147] chan_sip.c: Header 8 [ 53]: Contact: "Office 1001" [Dec 18 10:59:29] DEBUG[26147] chan_sip.c: Header 9 [ 31]: User-Agent: Sipura/SPA941-4.1.8 [Dec 18 10:59:29] DEBUG[26147] chan_sip.c: Header 10 [ 17]: Content-Length: 0 [Dec 18 10:59:29] DEBUG[26147] chan_sip.c: Header 11 [ 41]: Record-Route: [Dec 18 10:59:29] DEBUG[26147] chan_sip.c: Header 12 [ 0]: [Dec 18 10:59:29] VERBOSE[26147] logger.c: --- (12 headers 0 lines) --- [Dec 18 10:59:29] DEBUG[26147] chan_sip.c: = Found Their Call ID: ee172329-35a0d169@192.168.100.27 Their Tag 77d8f82994410069o0 Our tag: as15de7753 [Dec 18 10:59:29] DEBUG[26147] chan_sip.c: **** Received ACK (6) - Command in SIP ACK [Dec 18 10:59:29] VERBOSE[26147] logger.c: **** Received ACK (6) - Command in SIP ACK [Dec 18 10:59:29] VERBOSE[26147] logger.c: setting state to INV_CONFIRMED [Dec 18 10:59:29] DEBUG[26147] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #9 [Dec 18 10:59:29] DEBUG[26147] chan_sip.c: Stopping retransmission on 'ee172329-35a0d169@192.168.100.27' of Response 102: Match Found [Dec 18 10:59:30] DEBUG[26149] channel.c: Set channel SIP/82.94.244.100-006e6480 to write format ulaw [Dec 18 10:59:30] DEBUG[26149] pbx.c: Launching 'Goto' [Dec 18 10:59:30] VERBOSE[26149] logger.c: -- Executing [6660@default:3] Goto("SIP/82.94.244.100-006e6480", "default|6660|2") in new stack [Dec 18 10:59:30] VERBOSE[26149] logger.c: -- Goto (default,6660,2) [Dec 18 10:59:30] DEBUG[26149] pbx.c: Launching 'Playback' [Dec 18 10:59:30] VERBOSE[26149] logger.c: -- Executing [6660@default:2] Playback("SIP/82.94.244.100-006e6480", "pbx-invalid") in new stack [Dec 18 10:59:30] DEBUG[26149] channel.c: Set channel SIP/82.94.244.100-006e6480 to write format gsm [Dec 18 10:59:30] VERBOSE[26149] logger.c: -- Playing 'pbx-invalid' (language 'en') [Dec 18 10:59:31] VERBOSE[26147] logger.c: RTCP SR transmission error, rtcp halted [Dec 18 10:59:31] NOTICE[26147] sched.c: Attempted to delete nonexistent schedule entry 8! [Dec 18 10:59:34] DEBUG[26149] channel.c: Set channel SIP/82.94.244.100-006e6480 to write format ulaw [Dec 18 10:59:34] DEBUG[26149] pbx.c: Launching 'Goto' [Dec 18 10:59:34] VERBOSE[26149] logger.c: -- Executing [6660@default:3] Goto("SIP/82.94.244.100-006e6480", "default|6660|2") in new stack [Dec 18 10:59:34] VERBOSE[26149] logger.c: -- Goto (default,6660,2) [Dec 18 10:59:34] DEBUG[26149] pbx.c: Launching 'Playback' [Dec 18 10:59:34] VERBOSE[26149] logger.c: -- Executing [6660@default:2] Playback("SIP/82.94.244.100-006e6480", "pbx-invalid") in new stack [Dec 18 10:59:34] DEBUG[26149] channel.c: Set channel SIP/82.94.244.100-006e6480 to write format gsm [Dec 18 10:59:34] VERBOSE[26149] logger.c: -- Playing 'pbx-invalid' (language 'en') [Dec 18 10:59:38] VERBOSE[26147] logger.c: <--- SIP read from 82.94.244.100:5060 ---> REFER sip:6660@82.94.244.105 SIP/2.0 Via: SIP/2.0/UDP 82.94.244.100:5060;branch=z9hG4bK-rla9cxis Via: SIP/2.0/UDP 192.168.100.27:5070;branch=z9hG4bK-ae98e7e3 From: "Office 1001" ;tag=77d8f82994410069o0 To: ;tag=as15de7753 Referred-By: "Office 1001" Call-ID: ee172329-35a0d169@192.168.100.27 CSeq: 103 REFER Max-Forwards: 70 Contact: "Office 1001" User-Agent: Sipura/SPA941-4.1.8 Content-Length: 0 Record-Route: Refer-To: <-------------> [Dec 18 10:59:38] DEBUG[26147] chan_sip.c: Header 0 [ 36]: REFER sip:6660@82.94.244.105 SIP/2.0 [Dec 18 10:59:38] DEBUG[26147] chan_sip.c: Header 1 [ 59]: Via: SIP/2.0/UDP 82.94.244.100:5060;branch=z9hG4bK-rla9cxis [Dec 18 10:59:38] DEBUG[26147] chan_sip.c: Header 2 [ 60]: Via: SIP/2.0/UDP 192.168.100.27:5070;branch=z9hG4bK-ae98e7e3 [Dec 18 10:59:38] DEBUG[26147] chan_sip.c: Header 3 [ 67]: From: "Office 1001" ;tag=77d8f82994410069o0 [Dec 18 10:59:38] DEBUG[26147] chan_sip.c: Header 4 [ 43]: To: ;tag=as15de7753 [Dec 18 10:59:38] DEBUG[26147] chan_sip.c: Header 5 [ 51]: Referred-By: "Office 1001" [Dec 18 10:59:38] DEBUG[26147] chan_sip.c: Header 6 [ 41]: Call-ID: ee172329-35a0d169@192.168.100.27 [Dec 18 10:59:38] DEBUG[26147] chan_sip.c: Header 7 [ 15]: CSeq: 103 REFER [Dec 18 10:59:38] DEBUG[26147] chan_sip.c: Header 8 [ 16]: Max-Forwards: 70 [Dec 18 10:59:38] DEBUG[26147] chan_sip.c: Header 9 [ 53]: Contact: "Office 1001" [Dec 18 10:59:38] DEBUG[26147] chan_sip.c: Header 10 [ 31]: User-Agent: Sipura/SPA941-4.1.8 [Dec 18 10:59:38] DEBUG[26147] chan_sip.c: Header 11 [ 17]: Content-Length: 0 [Dec 18 10:59:38] DEBUG[26147] chan_sip.c: Header 12 [ 41]: Record-Route: [Dec 18 10:59:38] DEBUG[26147] chan_sip.c: Header 13 [151]: Refer-To: [Dec 18 10:59:38] DEBUG[26147] chan_sip.c: Header 14 [ 0]: [Dec 18 10:59:38] VERBOSE[26147] logger.c: --- (14 headers 0 lines) --- [Dec 18 10:59:38] DEBUG[26147] chan_sip.c: = Found Their Call ID: ee172329-35a0d169@192.168.100.27 Their Tag 77d8f82994410069o0 Our tag: as15de7753 [Dec 18 10:59:38] DEBUG[26147] chan_sip.c: **** Received REFER (9) - Command in SIP REFER [Dec 18 10:59:38] VERBOSE[26147] logger.c: **** Received REFER (9) - Command in SIP REFER [Dec 18 10:59:38] VERBOSE[26147] logger.c: Call ee172329-35a0d169@192.168.100.27 got a SIP call transfer from caller: (REFER)! [Dec 18 10:59:38] DEBUG[26147] chan_sip.c: Attended transfer: Will use Replace-Call-ID : e50d5432-3440af48@192.168.100.27 (No check of from/to tags) [Dec 18 10:59:38] VERBOSE[26147] logger.c: SIP transfer to extension 1002@default by 1001@82.94.244.100 [Dec 18 10:59:38] DEBUG[26147] chan_sip.c: This SIP transfer is to a remote SIP extension (remote domain 82.94.244.100:5060) [Dec 18 10:59:38] DEBUG[26147] chan_sip.c: SIP attended transfer: Transferer channel SIP/82.94.244.100-006e6480, transferee channel [Dec 18 10:59:38] DEBUG[26147] chan_sip.c: Looking for callid e50d5432-3440af48@192.168.100.27 (fromtag c66c1f2a869ba0b0o0 totag c427769b167934f3) [Dec 18 10:59:38] DEBUG[26147] chan_sip.c: Found no match for callid e50d5432-3440af48@192.168.100.27 to-tag c427769b167934f3 from-tag c66c1f2a869ba0b0o0 [Dec 18 10:59:38] DEBUG[26147] chan_sip.c: SIP attended transfer: Not our call - generating INVITE with replaces [Dec 18 10:59:38] DEBUG[26147] chan_sip.c: SIP attended transfer: Still not our call - generating INVITE with replaces [Dec 18 10:59:38] VERBOSE[26147] logger.c: <--- Transmitting (no NAT) to 82.94.244.100:5060 ---> SIP/2.0 202 Accepted Via: SIP/2.0/UDP 82.94.244.100:5060;branch=z9hG4bK-rla9cxis;received=82.94.244.100 Via: SIP/2.0/UDP 192.168.100.27:5070;branch=z9hG4bK-ae98e7e3 Record-Route: From: "Office 1001" ;tag=77d8f82994410069o0 To: ;tag=as15de7753 Call-ID: ee172329-35a0d169@192.168.100.27 CSeq: 103 REFER User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Length: 0 <------------>