unnamedplayer ~ # asterisk -r Asterisk 1.2.10, Copyright (C) 1999 - 2006 Digium, Inc. and others. Created by Mark Spencer Asterisk comes with ABSOLUTELY NO WARRANTY; type 'show warranty' for details. This is free software, with components licensed under the GNU General Public License version 2 and other licenses; you are welcome to redistribute it under certain conditions. Type 'show license' for details. ========================================================================= Connected to Asterisk 1.2.10 currently running on unnamedplayer (pid = 29792) Verbosity is at least 10 unnamedplayer*CLI> Terminated unnamedplayer ~ # asterisk -r Asterisk 1.2.10, Copyright (C) 1999 - 2006 Digium, Inc. and others. Created by Mark Spencer Asterisk comes with ABSOLUTELY NO WARRANTY; type 'show warranty' for details. This is free software, with components licensed under the GNU General Public License version 2 and other licenses; you are welcome to redistribute it under certain conditions. Type 'show license' for details. ========================================================================= Connected to Asterisk 1.2.10 currently running on unnamedplayer (pid = 9977) unnamedplayer*CLI> unnamedplayer*CLI> unnamedplayer*CLI> set debug 4 Core debug was 0 and is now 4 unnamedplayer*CLI> se send set unnamedplayer*CLI> set verbose 4 Verbosity was 0 and is now 4 unnamedplayer*CLI> sip debug SIP Debugging enabled unnamedplayer*CLI> <-- SIP read from 172.16.8.125:7120: Aug 9 09:21:56 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 0: (0) --- (0 headers 0 lines) Nat keepalive --- unnamedplayer*CLI> <-- SIP read from 172.16.8.125:7120: Aug 9 09:22:05 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 0: (0) --- (0 headers 0 lines) Nat keepalive --- unnamedplayer*CLI> <-- SIP read from 172.16.8.125:7120: Aug 9 09:22:14 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 0: (0) --- (0 headers 0 lines) Nat keepalive --- unnamedplayer*CLI> <-- SIP read from 172.16.8.125:7120: Aug 9 09:22:23 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 0: (0) --- (0 headers 0 lines) Nat keepalive --- unnamedplayer*CLI> <-- SIP read from 172.16.8.125:7120: Aug 9 09:22:32 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 0: (0) --- (0 headers 0 lines) Nat keepalive --- unnamedplayer*CLI> <-- SIP read from 172.16.8.125:7120: Aug 9 09:22:41 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 0: (0) --- (0 headers 0 lines) Nat keepalive --- unnamedplayer*CLI> <-- SIP read from 172.16.8.125:7120: Aug 9 09:22:50 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 0: (0) --- (0 headers 0 lines) Nat keepalive --- unnamedplayer*CLI> <-- SIP read from 172.16.8.125:7120: Aug 9 09:22:59 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 0: (0) --- (0 headers 0 lines) Nat keepalive --- unnamedplayer*CLI> <-- SIP read from 1.1.1.10:5060: INVITE sip:1601@10.1.2.10;user=phone SIP/2.0 Via: SIP/2.0/UDP 1.1.1.10:5060;branch=z9hG4bKf52375844af8bf15 From: 6003-steve ;tag=3764155442 To: Call-ID: 139264295@1.1.1.10 CSeq: 1 INVITE Contact: 6003-steve User-Agent: Cisco ATA 188 v3.2.1 atasip (050616A) Expires: 300 Allow: ACK, BYE, CANCEL, INVITE, NOTIFY, OPTIONS, REFER, REGISTER, PRACK, UPDATE Supported: 100rel,replaces Content-Length: 226 Content-Type: application/sdp v=0 o=6003 216456 216456 IN IP4 1.1.1.10 s=ATA186 Call c=IN IP4 1.1.1.10 t=0 0 m=audio 16386 RTP/AVP 8 0 101 a=rtpmap:8 PCMA/8000/1 a=rtpmap:0 PCMU/8000/1 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 Aug 9 09:23:00 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 0: INVITE sip:1601@10.1.2.10;user=phone SIP/2.0 (51) Aug 9 09:23:00 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 1: Via: SIP/2.0/UDP 1.1.1.10:5060;branch=z9hG4bKf52375844af8bf15 (64) Aug 9 09:23:00 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 2: From: 6003-steve ;tag=3764155442 (69) Aug 9 09:23:00 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 3: To: (42) Aug 9 09:23:00 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 4: Call-ID: 139264295@1.1.1.10 (30) Aug 9 09:23:00 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 5: CSeq: 1 INVITE (14) Aug 9 09:23:00 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 6: Contact: 6003-steve (77) Aug 9 09:23:00 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 7: User-Agent: Cisco ATA 188 v3.2.1 atasip (050616A) (50) Aug 9 09:23:00 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 8: Expires: 300 (12) Aug 9 09:23:00 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 9: Allow: ACK, BYE, CANCEL, INVITE, NOTIFY, OPTIONS, REFER, REGISTER, PRACK, UPDATE (80) Aug 9 09:23:00 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 10: Supported: 100rel,replaces (26) Aug 9 09:23:00 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 11: Content-Length: 226 (19) Aug 9 09:23:00 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 12: Content-Type: application/sdp (29) Aug 9 09:23:00 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 13: (0) Aug 9 09:23:00 DEBUG[9996]: chan_sip.c:3389 parse_request: Line: v=0 (3) Aug 9 09:23:00 DEBUG[9996]: chan_sip.c:3389 parse_request: Line: o=6003 216456 216456 IN IP4 1.1.1.10 (44) Aug 9 09:23:00 DEBUG[9996]: chan_sip.c:3389 parse_request: Line: s=ATA186 Call (13) Aug 9 09:23:00 DEBUG[9996]: chan_sip.c:3389 parse_request: Line: c=IN IP4 1.1.1.10 (20) Aug 9 09:23:00 DEBUG[9996]: chan_sip.c:3389 parse_request: Line: t=0 0 (5) Aug 9 09:23:00 DEBUG[9996]: chan_sip.c:3389 parse_request: Line: m=audio 16386 RTP/AVP 8 0 101 (29) Aug 9 09:23:00 DEBUG[9996]: chan_sip.c:3389 parse_request: Line: a=rtpmap:8 PCMA/8000/1 (22) Aug 9 09:23:00 DEBUG[9996]: chan_sip.c:3389 parse_request: Line: a=rtpmap:0 PCMU/8000/1 (22) Aug 9 09:23:00 DEBUG[9996]: chan_sip.c:3389 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) Aug 9 09:23:00 DEBUG[9996]: chan_sip.c:3389 parse_request: Line: a=fmtp:101 0-15 (15) --- (13 headers 10 lines)--- Aug 9 09:23:00 DEBUG[9996]: chan_sip.c:3141 sip_alloc: Allocating new SIP dialog for 139264295@1.1.1.10 - INVITE (With RTP) Aug 9 09:23:00 DEBUG[9996]: chan_sip.c:11139 handle_request: **** Received INVITE (5) - Command in SIP INVITE Aug 9 09:23:00 DEBUG[9996]: chan_sip.c:1004 parse_sip_options: Begin: parsing SIP "Supported: 100rel,replaces" Aug 9 09:23:00 DEBUG[9996]: chan_sip.c:1016 parse_sip_options: Found SIP option: -100rel- Aug 9 09:23:00 DEBUG[9996]: chan_sip.c:1022 parse_sip_options: Matched SIP option: 100rel Aug 9 09:23:00 DEBUG[9996]: chan_sip.c:1016 parse_sip_options: Found SIP option: -replaces- Aug 9 09:23:00 DEBUG[9996]: chan_sip.c:1022 parse_sip_options: Matched SIP option: replaces Aug 9 09:23:00 DEBUG[9996]: chan_sip.c:1033 parse_sip_options: * SIP extension value: 3 for call 139264295@1.1.1.10 Using INVITE request as basis request - 139264295@1.1.1.10 Sending to 1.1.1.10 : 5060 (non-NAT) Aug 9 09:23:00 DEBUG[9996]: chan_sip.c:7149 check_user_full: Setting NAT on RTP to 524288 Aug 9 09:23:00 DEBUG[9996]: chan_sip.c:7153 check_user_full: Setting NAT on VRTP to 524288 Reliably Transmitting (NAT) to 1.1.1.10:5060: SIP/2.0 407 Proxy Authentication Required Via: SIP/2.0/UDP 1.1.1.10:5060;branch=z9hG4bKf52375844af8bf15;received=1.1.1.10 From: 6003-steve ;tag=3764155442 To: ;tag=as2a6044f3 Call-ID: 139264295@1.1.1.10 CSeq: 1 INVITE User-Agent: tull.ch PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Contact: Proxy-Authenticate: Digest algorithm=MD5, realm="tull.ch", nonce="20cf7ca1" Content-Length: 0 --- Aug 9 09:23:00 DEBUG[9996]: chan_sip.c:1293 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #47 Scheduling destruction of call '139264295@1.1.1.10' in 15000 ms Found user '6003' unnamedplayer*CLI> <-- SIP read from 1.1.1.10:5060: ACK sip:1601@10.1.2.10;user=phone SIP/2.0 Via: SIP/2.0/UDP 1.1.1.10:5060;branch=z9hG4bKf52375844af8bf15 From: 6003-steve ;tag=3764155442 To: ;tag=as2a6044f3 Call-ID: 139264295@1.1.1.10 CSeq: 1 ACK User-Agent: Cisco ATA 188 v3.2.1 atasip (050616A) Content-Length: 0 Aug 9 09:23:00 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 0: ACK sip:1601@10.1.2.10;user=phone SIP/2.0 (48) Aug 9 09:23:00 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 1: Via: SIP/2.0/UDP 1.1.1.10:5060;branch=z9hG4bKf52375844af8bf15 (64) Aug 9 09:23:00 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 2: From: 6003-steve ;tag=3764155442 (69) Aug 9 09:23:00 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 3: To: ;tag=as2a6044f3 (57) Aug 9 09:23:00 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 4: Call-ID: 139264295@1.1.1.10 (30) Aug 9 09:23:00 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 5: CSeq: 1 ACK (11) Aug 9 09:23:00 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 6: User-Agent: Cisco ATA 188 v3.2.1 atasip (050616A) (50) Aug 9 09:23:00 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 7: Content-Length: 0 (17) Aug 9 09:23:00 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 8: (0) --- (8 headers 0 lines)--- Aug 9 09:23:00 DEBUG[9996]: chan_sip.c:11139 handle_request: **** Received ACK (6) - Command in SIP ACK Aug 9 09:23:00 DEBUG[9996]: chan_sip.c:1390 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #47 Aug 9 09:23:00 DEBUG[9996]: chan_sip.c:1401 __sip_ack: Stopping retransmission on '139264295@1.1.1.10' of Response 1: Match Found unnamedplayer*CLI> <-- SIP read from 1.1.1.10:5060: INVITE sip:1601@10.1.2.10;user=phone SIP/2.0 Via: SIP/2.0/UDP 1.1.1.10:5060;branch=z9hG4bK40460f93951806c2 From: 6003-steve ;tag=3764155442 To: Call-ID: 139264295@1.1.1.10 CSeq: 2 INVITE Contact: 6003-steve User-Agent: Cisco ATA 188 v3.2.1 atasip (050616A) Proxy-Authorization: Digest username="6003",realm="tull.ch",nonce="20cf7ca1",uri="sip:1601@10.1.2.10",response="a1831309dfdcc9c219bdbd37c053b9bc" Expires: 300 Allow: ACK, BYE, CANCEL, INVITE, NOTIFY, OPTIONS, REFER, REGISTER, PRACK, UPDATE Supported: 100rel,replaces Content-Length: 226 Content-Type: application/sdp v=0 o=6003 216456 216456 IN IP4 1.1.1.10 s=ATA186 Call c=IN IP4 1.1.1.10 t=0 0 m=audio 16386 RTP/AVP 8 0 101 a=rtpmap:8 PCMA/8000/1 a=rtpmap:0 PCMU/8000/1 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 Aug 9 09:23:00 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 0: INVITE sip:1601@10.1.2.10;user=phone SIP/2.0 (51) Aug 9 09:23:00 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 1: Via: SIP/2.0/UDP 1.1.1.10:5060;branch=z9hG4bK40460f93951806c2 (64) Aug 9 09:23:00 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 2: From: 6003-steve ;tag=3764155442 (69) Aug 9 09:23:00 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 3: To: (42) Aug 9 09:23:00 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 4: Call-ID: 139264295@1.1.1.10 (30) Aug 9 09:23:00 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 5: CSeq: 2 INVITE (14) Aug 9 09:23:00 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 6: Contact: 6003-steve (77) Aug 9 09:23:00 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 7: User-Agent: Cisco ATA 188 v3.2.1 atasip (050616A) (50) Aug 9 09:23:00 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 8: Proxy-Authorization: Digest username="6003",realm="tull.ch",nonce="20cf7ca1",uri="sip:1601@10.1.2.10",response="a1831309dfdcc9c219bdbd37c053b9bc" (157) Aug 9 09:23:00 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 9: Expires: 300 (12) Aug 9 09:23:00 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 10: Allow: ACK, BYE, CANCEL, INVITE, NOTIFY, OPTIONS, REFER, REGISTER, PRACK, UPDATE (80) Aug 9 09:23:00 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 11: Supported: 100rel,replaces (26) Aug 9 09:23:00 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 12: Content-Length: 226 (19) Aug 9 09:23:00 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 13: Content-Type: application/sdp (29) Aug 9 09:23:00 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 14: (0) Aug 9 09:23:00 DEBUG[9996]: chan_sip.c:3389 parse_request: Line: v=0 (3) Aug 9 09:23:00 DEBUG[9996]: chan_sip.c:3389 parse_request: Line: o=6003 216456 216456 IN IP4 1.1.1.10 (44) Aug 9 09:23:00 DEBUG[9996]: chan_sip.c:3389 parse_request: Line: s=ATA186 Call (13) Aug 9 09:23:00 DEBUG[9996]: chan_sip.c:3389 parse_request: Line: c=IN IP4 1.1.1.10 (20) Aug 9 09:23:00 DEBUG[9996]: chan_sip.c:3389 parse_request: Line: t=0 0 (5) Aug 9 09:23:00 DEBUG[9996]: chan_sip.c:3389 parse_request: Line: m=audio 16386 RTP/AVP 8 0 101 (29) Aug 9 09:23:00 DEBUG[9996]: chan_sip.c:3389 parse_request: Line: a=rtpmap:8 PCMA/8000/1 (22) Aug 9 09:23:00 DEBUG[9996]: chan_sip.c:3389 parse_request: Line: a=rtpmap:0 PCMU/8000/1 (22) Aug 9 09:23:00 DEBUG[9996]: chan_sip.c:3389 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) Aug 9 09:23:00 DEBUG[9996]: chan_sip.c:3389 parse_request: Line: a=fmtp:101 0-15 (15) --- (14 headers 10 lines)--- Aug 9 09:23:00 DEBUG[9996]: chan_sip.c:11139 handle_request: **** Received INVITE (5) - Command in SIP INVITE Using INVITE request as basis request - 139264295@1.1.1.10 Sending to 1.1.1.10 : 5060 (NAT) Aug 9 09:23:00 DEBUG[9996]: chan_sip.c:7149 check_user_full: Setting NAT on RTP to 524288 Aug 9 09:23:00 DEBUG[9996]: chan_sip.c:7153 check_user_full: Setting NAT on VRTP to 524288 Found user '6003' Found RTP audio format 8 Found RTP audio format 0 Found RTP audio format 101 Peer audio RTP is at port 1.1.1.10:16386 Aug 9 09:23:00 DEBUG[9996]: chan_sip.c:3598 process_sdp: Peer audio RTP is at port 1.1.1.10:16386 Peer video RTP is at port 1.1.1.10:65535 Aug 9 09:23:00 DEBUG[9996]: chan_sip.c:3622 process_sdp: Peer video RTP is at port 1.1.1.10:65535 Found description format PCMA Found description format PCMU Found description format telephone-event Capabilities: us - 0xa (gsm|alaw), peer - audio=0xc (ulaw|alaw)/video=0x0 (nothing), combined - 0x8 (alaw) Non-codec capabilities: us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) Aug 9 09:23:00 DEBUG[9996]: chan_sip.c:10496 handle_request_invite: Checking SIP call limits for device 6003 Aug 9 09:23:00 DEBUG[9996]: chan_sip.c:2206 update_call_counter: Updating call counter for incoming call Looking for 1601 in privileged (domain 10.1.2.10) Aug 9 09:23:00 DEBUG[9996]: chan_sip.c:6131 build_route: build_route: Contact hop: 6003-steve list_route: hop: Transmitting (NAT) to 1.1.1.10:5060: SIP/2.0 100 Trying Via: SIP/2.0/UDP 1.1.1.10:5060;branch=z9hG4bK40460f93951806c2;received=1.1.1.10 From: 6003-steve ;tag=3764155442 To: Call-ID: 139264295@1.1.1.10 CSeq: 2 INVITE User-Agent: tull.ch PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Contact: Content-Length: 0 --- Aug 9 09:23:00 DEBUG[9981]: chan_sip.c:11670 sip_devicestate: Checking device state for peer 6003 Aug 9 09:23:00 DEBUG[9981]: devicestate.c:187 do_state_change: Changing state for SIP/6003 - state 2 (In use) Aug 9 09:23:00 DEBUG[9981]: chan_sip.c:11670 sip_devicestate: Checking device state for peer 6003 Aug 9 09:23:00 DEBUG[10180]: app_queue.c:490 changethread: Device 'SIP/6003' changed to state '2' (In use) but we don't care because they're not a member of any queue. Aug 9 09:23:00 DEBUG[10179]: pbx.c:1677 pbx_extension_helper: Launching 'Dial' -- Executing Dial("SIP/6003-08171e30", "SIP/1601@10.110.30.10") in new stack Aug 9 09:23:00 DEBUG[10179]: chan_sip.c:3141 sip_alloc: Allocating new SIP dialog for (No Call-ID) - INVITE (With RTP) Aug 9 09:23:00 DEBUG[10179]: channel.c:2856 ast_channel_inherit_variables: Not copying variable STACK-privileged-1601-1. Aug 9 09:23:00 DEBUG[10179]: channel.c:2856 ast_channel_inherit_variables: Not copying variable SIPCALLID. Aug 9 09:23:00 DEBUG[10179]: channel.c:2856 ast_channel_inherit_variables: Not copying variable SIPUSERAGENT. Aug 9 09:23:00 DEBUG[10179]: channel.c:2856 ast_channel_inherit_variables: Not copying variable SIPDOMAIN. Aug 9 09:23:00 DEBUG[10179]: channel.c:2856 ast_channel_inherit_variables: Not copying variable SIPURI. Aug 9 09:23:00 DEBUG[10179]: chan_sip.c:2068 sip_call: Outgoing Call for 1601 Aug 9 09:23:00 DEBUG[10179]: chan_sip.c:2206 update_call_counter: Updating call counter for outgoing call We're at 10.1.2.10 port 16034 Video is at 10.1.2.10 port 16004 Adding codec 0x8 (alaw) to SDP Adding codec 0x2 (gsm) to SDP Adding codec 0x400 (ilbc) to SDP Adding non-codec 0x1 (telephone-event) to SDP Aug 9 09:23:00 DEBUG[10179]: chan_sip.c:3357 parse_request: Header 0: INVITE sip:1601@10.110.30.10 SIP/2.0 (40) Aug 9 09:23:00 DEBUG[10179]: chan_sip.c:3357 parse_request: Header 1: Via: SIP/2.0/UDP 10.1.2.10:5060;branch=z9hG4bK0883537b;rport (61) Aug 9 09:23:00 DEBUG[10179]: chan_sip.c:3357 parse_request: Header 2: From: "MeanFaxMachine" ;tag=as0af0b132 (65) Aug 9 09:23:00 DEBUG[10179]: chan_sip.c:3357 parse_request: Header 3: To: (31) Aug 9 09:23:00 DEBUG[10179]: chan_sip.c:3357 parse_request: Header 4: Contact: (36) Aug 9 09:23:00 DEBUG[10179]: chan_sip.c:3357 parse_request: Header 5: Call-ID: 093e8fec7af28f8d3e5ab4cb24771e72@10.1.2.10 (52) Aug 9 09:23:00 DEBUG[10179]: chan_sip.c:3357 parse_request: Header 6: CSeq: 102 INVITE (16) Aug 9 09:23:00 DEBUG[10179]: chan_sip.c:3357 parse_request: Header 7: User-Agent: tull.ch PBX (23) Aug 9 09:23:00 DEBUG[10179]: chan_sip.c:3357 parse_request: Header 8: Max-Forwards: 70 (16) Aug 9 09:23:00 DEBUG[10179]: chan_sip.c:3357 parse_request: Header 9: Date: Wed, 09 Aug 2006 07:23:00 GMT (35) Aug 9 09:23:00 DEBUG[10179]: chan_sip.c:3357 parse_request: Header 10: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) Aug 9 09:23:00 DEBUG[10179]: chan_sip.c:3357 parse_request: Header 11: Content-Type: application/sdp (29) Aug 9 09:23:00 DEBUG[10179]: chan_sip.c:3357 parse_request: Header 12: Content-Length: 259 (19) Aug 9 09:23:00 DEBUG[10179]: chan_sip.c:3357 parse_request: Header 13: (0) Aug 9 09:23:00 DEBUG[10179]: chan_sip.c:3389 parse_request: Line: v=0 (3) Aug 9 09:23:00 DEBUG[10179]: chan_sip.c:3389 parse_request: Line: o=root 9977 9977 IN IP4 10.1.2.10 (34) Aug 9 09:23:00 DEBUG[10179]: chan_sip.c:3389 parse_request: Line: s=session (9) Aug 9 09:23:00 DEBUG[10179]: chan_sip.c:3389 parse_request: Line: c=IN IP4 10.1.2.10 (19) Aug 9 09:23:00 DEBUG[10179]: chan_sip.c:3389 parse_request: Line: t=0 0 (5) Aug 9 09:23:00 DEBUG[10179]: chan_sip.c:3389 parse_request: Line: m=audio 16034 RTP/AVP 8 3 97 101 (32) Aug 9 09:23:00 DEBUG[10179]: chan_sip.c:3389 parse_request: Line: a=rtpmap:8 PCMA/8000 (20) Aug 9 09:23:00 DEBUG[10179]: chan_sip.c:3389 parse_request: Line: a=rtpmap:3 GSM/8000 (19) Aug 9 09:23:00 DEBUG[10179]: chan_sip.c:3389 parse_request: Line: a=rtpmap:97 iLBC/8000 (21) Aug 9 09:23:00 DEBUG[10179]: chan_sip.c:3389 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) Aug 9 09:23:00 DEBUG[10179]: chan_sip.c:3389 parse_request: Line: a=fmtp:101 0-16 (15) Aug 9 09:23:00 DEBUG[10179]: chan_sip.c:3389 parse_request: Line: a=silenceSupp:off - - - - (25) 13 headers, 12 lines Reliably Transmitting (no NAT) to 10.110.30.10:5060: INVITE sip:1601@10.110.30.10 SIP/2.0 Via: SIP/2.0/UDP 10.1.2.10:5060;branch=z9hG4bK0883537b;rport From: "MeanFaxMachine" ;tag=as0af0b132 To: Contact: Call-ID: 093e8fec7af28f8d3e5ab4cb24771e72@10.1.2.10 CSeq: 102 INVITE User-Agent: tull.ch PBX Max-Forwards: 70 Date: Wed, 09 Aug 2006 07:23:00 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Content-Type: application/sdp Content-Length: 259 v=0 o=root 9977 9977 IN IP4 10.1.2.10 s=session c=IN IP4 10.1.2.10 t=0 0 m=audio 16034 RTP/AVP 8 3 97 101 a=rtpmap:8 PCMA/8000 a=rtpmap:3 GSM/8000 a=rtpmap:97 iLBC/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - --- Aug 9 09:23:00 DEBUG[10179]: chan_sip.c:1293 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #49 -- Called 1601@10.110.30.10 Aug 9 09:23:00 DEBUG[10179]: channel.c:2363 set_format: Set channel SIP/10.110.30.10-0817b740 to read format alaw Aug 9 09:23:00 DEBUG[10179]: channel.c:2363 set_format: Set channel SIP/6003-08171e30 to write format alaw Aug 9 09:23:00 DEBUG[10179]: channel.c:2363 set_format: Set channel SIP/6003-08171e30 to read format alaw Aug 9 09:23:00 DEBUG[10179]: channel.c:2363 set_format: Set channel SIP/10.110.30.10-0817b740 to write format alaw unnamedplayer*CLI> <-- SIP read from 10.110.30.10:5060: SIP/2.0 100 Trying Via: SIP/2.0/UDP 10.1.2.10:5060;received=10.1.2.10;branch=z9hG4bK0883537b;rport=5060 From: "MeanFaxMachine" ;tag=as0af0b132 To: Call-ID: 093e8fec7af28f8d3e5ab4cb24771e72@10.1.2.10 CSeq: 102 INVITE Aug 9 09:23:00 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 0: SIP/2.0 100 Trying (18) Aug 9 09:23:00 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 1: Via: SIP/2.0/UDP 10.1.2.10:5060;received=10.1.2.10;branch=z9hG4bK0883537b;rport=5060 (86) Aug 9 09:23:00 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 2: From: "MeanFaxMachine" ;tag=as0af0b132 (65) Aug 9 09:23:00 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 3: To: (31) Aug 9 09:23:00 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 4: Call-ID: 093e8fec7af28f8d3e5ab4cb24771e72@10.1.2.10 (52) Aug 9 09:23:00 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 5: CSeq: 102 INVITE (16) Aug 9 09:23:00 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 6: (0) --- (6 headers 0 lines)--- Aug 9 09:23:00 DEBUG[9996]: chan_sip.c:1445 __sip_semi_ack: *** SIP TIMER: Cancelling retransmission #49 - INVITE (got response) Aug 9 09:23:00 DEBUG[9996]: chan_sip.c:1454 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '093e8fec7af28f8d3e5ab4cb24771e72@10.1.2.10' Request 102: Found Aug 9 09:23:00 DEBUG[9996]: chan_sip.c:9578 handle_response_invite: SIP response 100 to standard invite unnamedplayer*CLI> <-- SIP read from 10.110.30.10:5060: SIP/2.0 180 Ringing Via: SIP/2.0/UDP 10.1.2.10:5060;received=10.1.2.10;branch=z9hG4bK0883537b;rport=5060 From: "MeanFaxMachine" ;tag=as0af0b132 To: ;tag=1937808815 Call-ID: 093e8fec7af28f8d3e5ab4cb24771e72@10.1.2.10 CSeq: 102 INVITE Contact: Content-Length: 0 Aug 9 09:23:02 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 0: SIP/2.0 180 Ringing (19) Aug 9 09:23:02 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 1: Via: SIP/2.0/UDP 10.1.2.10:5060;received=10.1.2.10;branch=z9hG4bK0883537b;rport=5060 (86) Aug 9 09:23:02 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 2: From: "MeanFaxMachine" ;tag=as0af0b132 (65) Aug 9 09:23:02 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 3: To: ;tag=1937808815 (46) Aug 9 09:23:02 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 4: Call-ID: 093e8fec7af28f8d3e5ab4cb24771e72@10.1.2.10 (52) Aug 9 09:23:02 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 5: CSeq: 102 INVITE (16) Aug 9 09:23:02 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 6: Contact: (55) Aug 9 09:23:02 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 7: Content-Length: 0 (17) Aug 9 09:23:02 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 8: (0) --- (8 headers 0 lines)--- Aug 9 09:23:02 DEBUG[9996]: chan_sip.c:1454 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '093e8fec7af28f8d3e5ab4cb24771e72@10.1.2.10' Request 102: Found Aug 9 09:23:02 DEBUG[9996]: chan_sip.c:9578 handle_response_invite: SIP response 180 to standard invite -- SIP/10.110.30.10-0817b740 is ringing Aug 9 09:23:02 DEBUG[9981]: chan_sip.c:11670 sip_devicestate: Transmitting (NAT) to 1.1.1.10:5060: SIP/2.0 180 Ringing Via: SIP/2.0/UDP 1.1.1.10:5060;branch=z9hG4bK40460f93951806c2;received=1.1.1.10 From: 6003-steve ;tag=3764155442 To: ;tag=as1d6b437e Call-ID: 139264295@1.1.1.10 CSeq: 2 INVITE User-Agent: tull.ch PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Contact: Content-Length: 0 --- Checking device state for peer 10.110.30.10 Aug 9 09:23:02 DEBUG[9981]: devicestate.c:187 do_state_change: Changing state for SIP/10.110.30.10 - state 6 (Ringing) Aug 9 09:23:02 DEBUG[10185]: app_queue.c:490 changethread: Device 'SIP/10.110.30.10' changed to state '6' (Ringing) but we don't care because they're not a member of any queue. Aug 9 09:23:03 DEBUG[10179]: rtp.c:411 ast_rtcp_read: Got RTCP report of 88 bytes Aug 9 09:23:05 DEBUG[10179]: rtp.c:411 ast_rtcp_read: Got RTCP report of 88 bytes unnamedplayer*CLI> <-- SIP read from 10.110.30.10:5060: SIP/2.0 200 Ok Via: SIP/2.0/UDP 10.1.2.10:5060;received=10.1.2.10;branch=z9hG4bK0883537b;rport=5060 From: "MeanFaxMachine" ;tag=as0af0b132 To: ;tag=1937808815 Call-ID: 093e8fec7af28f8d3e5ab4cb24771e72@10.1.2.10 CSeq: 102 INVITE Contact: Allow: INVITE,ACK,PRACK,SUBSCRIBE,BYE,CANCEL,NOTIFY,INFO,REFER,UPDATE Supported: timer Content-Type: application/sdp Content-Length: 340 v=0 o=- 89 0 IN IP4 10.110.30.10 s=Cisco SDP 0 c=IN IP4 10.110.30.10 t=0 0 m=audio 16002 RTP/AVP 8 101 100 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=rtpmap:100 X-NSE/8000 a=fmtp:100 200-202 a=X-sqn:0 a=X-cap: 1 audio RTP/AVP 100 a=X-cpar: a=rtpmap:100 X-NSE/8000 a=X-cpar: a=fmtp:100 200-202 a=X-cap: 2 image udptl t38 Aug 9 09:23:07 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 0: SIP/2.0 200 Ok (14) Aug 9 09:23:07 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 1: Via: SIP/2.0/UDP 10.1.2.10:5060;received=10.1.2.10;branch=z9hG4bK0883537b;rport=5060 (86) Aug 9 09:23:07 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 2: From: "MeanFaxMachine" ;tag=as0af0b132 (65) Aug 9 09:23:07 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 3: To: ;tag=1937808815 (46) Aug 9 09:23:07 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 4: Call-ID: 093e8fec7af28f8d3e5ab4cb24771e72@10.1.2.10 (52) Aug 9 09:23:07 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 5: CSeq: 102 INVITE (16) Aug 9 09:23:07 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 6: Contact: (55) Aug 9 09:23:07 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 7: Allow: INVITE,ACK,PRACK,SUBSCRIBE,BYE,CANCEL,NOTIFY,INFO,REFER,UPDATE (69) Aug 9 09:23:07 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 8: Supported: timer (16) Aug 9 09:23:07 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 9: Content-Type: application/sdp (29) Aug 9 09:23:07 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 10: Content-Length: 340 (19) Aug 9 09:23:07 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 11: (0) Aug 9 09:23:07 DEBUG[9996]: chan_sip.c:3389 parse_request: Line: v=0 (3) Aug 9 09:23:07 DEBUG[9996]: chan_sip.c:3389 parse_request: Line: o=- 89 0 IN IP4 10.110.30.10 (26) Aug 9 09:23:07 DEBUG[9996]: chan_sip.c:3389 parse_request: Line: s=Cisco SDP 0 (13) Aug 9 09:23:07 DEBUG[9996]: chan_sip.c:3389 parse_request: Line: c=IN IP4 10.110.30.10 (19) Aug 9 09:23:07 DEBUG[9996]: chan_sip.c:3389 parse_request: Line: t=0 0 (5) Aug 9 09:23:07 DEBUG[9996]: chan_sip.c:3389 parse_request: Line: m=audio 16002 RTP/AVP 8 101 100 (31) Aug 9 09:23:07 DEBUG[9996]: chan_sip.c:3389 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) Aug 9 09:23:07 DEBUG[9996]: chan_sip.c:3389 parse_request: Line: a=fmtp:101 0-15 (15) Aug 9 09:23:07 DEBUG[9996]: chan_sip.c:3389 parse_request: Line: a=rtpmap:100 X-NSE/8000 (23) Aug 9 09:23:07 DEBUG[9996]: chan_sip.c:3389 parse_request: Line: a=fmtp:100 200-202 (18) Aug 9 09:23:07 DEBUG[9996]: chan_sip.c:3389 parse_request: Line: a=X-sqn:0 (9) Aug 9 09:23:07 DEBUG[9996]: chan_sip.c:3389 parse_request: Line: a=X-cap: 1 audio RTP/AVP 100 (28) Aug 9 09:23:07 DEBUG[9996]: chan_sip.c:3389 parse_request: Line: a=X-cpar: a=rtpmap:100 X-NSE/8000 (33) Aug 9 09:23:07 DEBUG[9996]: chan_sip.c:3389 parse_request: Line: a=X-cpar: a=fmtp:100 200-202 (28) Aug 9 09:23:07 DEBUG[9996]: chan_sip.c:3389 parse_request: Line: a=X-cap: 2 image udptl t38 (26) --- (11 headers 15 lines)--- Aug 9 09:23:07 DEBUG[9996]: chan_sip.c:1379 __sip_ack: Acked pending invite 102 Aug 9 09:23:07 DEBUG[9996]: chan_sip.c:1401 __sip_ack: Stopping retransmission on '093e8fec7af28f8d3e5ab4cb24771e72@10.1.2.10' of Request 102: Match Found Aug 9 09:23:07 DEBUG[9996]: chan_sip.c:9578 handle_response_invite: SIP response 200 to standard invite Found RTP audio format 8 Found RTP audio format 101 Found RTP audio format 100 Peer audio RTP is at port 10.110.30.10:16002 Aug 9 09:23:07 DEBUG[9996]: chan_sip.c:3598 process_sdp: Peer audio RTP is at port 10.110.30.10:16002 Peer video RTP is at port 10.110.30.10:65535 Aug 9 09:23:07 DEBUG[9996]: chan_sip.c:3622 process_sdp: Peer video RTP is at port 10.110.30.10:65535 Found description format telephone-event Found description format X-NSE Capabilities: us - 0x40a (gsm|alaw|ilbc), peer - audio=0x8 (alaw)/video=0x0 (nothing), combined - 0x8 (alaw) Non-codec capabilities: us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) Aug 9 09:23:07 DEBUG[9996]: chan_sip.c:6131 build_route: build_route: Contact hop: list_route: hop: set_destination: Parsing for address/port to send to set_destination: set destination to 10.110.30.10, port 5060 Transmitting (no NAT) to 10.110.30.10:5060: ACK sip:1601@10.110.30.10:5060;transport=udp SIP/2.0 Via: SIP/2.0/UDP 10.1.2.10:5060;branch=z9hG4bK1c54a3d3;rport From: "MeanFaxMachine" ;tag=as0af0b132 To: ;tag=1937808815 Contact: Call-ID: 093e8fec7af28f8d3e5ab4cb24771e72@10.1.2.10 CSeq: 102 ACK User-Agent: tull.ch PBX Max-Forwards: 70 Content-Length: 0 --- -- SIP/10.110.30.10-0817b740 answered SIP/6003-08171e30 Aug 9 09:23:07 DEBUG[10179]: channel.c:2363 set_format: Set channel SIP/6003-08171e30 to read format alaw Aug 9 09:23:07 DEBUG[10179]: channel.c:2363 set_format: Set channel SIP/10.110.30.10-0817b740 to write format alaw Aug 9 09:23:07 DEBUG[10179]: channel.c:2363 set_format: Set channel SIP/10.110.30.10-0817b740 to read format alaw Aug 9 09:23:07 DEBUG[10179]: channel.c:2363 set_format: Set channel SIP/6003-08171e30 to write format alaw Aug 9 09:23:07 DEBUG[10179]: chan_sip.c:2537 sip_answer: sip_answer(SIP/6003-08171e30) We're at 10.1.2.10 port 16048 Video is at 10.1.2.10 port 16040 Adding codec 0x8 (alaw) to SDP Adding non-codec 0x1 (telephone-event) to SDP Reliably Transmitting (NAT) to 1.1.1.10:5060: SIP/2.0 200 OK Via: SIP/2.0/UDP 1.1.1.10:5060;branch=z9hG4bK40460f93951806c2;received=1.1.1.10 From: 6003-steve ;tag=3764155442 To: ;tag=as1d6b437e Call-ID: 139264295@1.1.1.10 CSeq: 2 INVITE User-Agent: tull.ch PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Contact: Content-Type: application/sdp Content-Length: 210 v=0 o=root 9977 9977 IN IP4 10.1.2.10 s=session c=IN IP4 10.1.2.10 t=0 0 m=audio 16048 RTP/AVP 8 101 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - --- Aug 9 09:23:07 DEBUG[10179]: chan_sip.c:1293 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #50 -- Attempting native bridge of SIP/6003-08171e30 and SIP/10.110.30.10-0817b740 Aug 9 09:23:07 DEBUG[10179]: chan_sip.c:12926 sip_set_rtp_peer: Deferring reinvite on SIP '139264295@1.1.1.10' - It's audio will be redirected to IP 10.110.30.10 Aug 9 09:23:07 DEBUG[10179]: chan_sip.c:12920 sip_set_rtp_peer: Sending reinvite on SIP '093e8fec7af28f8d3e5ab4cb24771e72@10.1.2.10' - It's audio soon redirected to IP 1.1.1.10 set_destination: Parsing for address/port to send to set_destination: set destination to 10.110.30.10, port 5060 We're at 10.1.2.10 port 16034 Video is at 10.1.2.10 port 16004 Adding codec 0x8 (alaw) to SDP Adding codec 0x4 (ulaw) to SDP Adding non-codec 0x1 (telephone-event) to SDP Aug 9 09:23:07 DEBUG[10179]: chan_sip.c:3357 parse_request: Header 0: INVITE sip:1601@10.110.30.10:5060;transport=udp SIP/2.0 (59) Aug 9 09:23:07 DEBUG[10179]: chan_sip.c:3357 parse_request: Header 1: Via: SIP/2.0/UDP 10.1.2.10:5060;branch=z9hG4bK311c341c;rport (61) Aug 9 09:23:07 DEBUG[10179]: chan_sip.c:3357 parse_request: Header 2: From: "MeanFaxMachine" ;tag=as0af0b132 (65) Aug 9 09:23:07 DEBUG[10179]: chan_sip.c:3357 parse_request: Header 3: To: ;tag=1937808815 (46) Aug 9 09:23:07 DEBUG[10179]: chan_sip.c:3357 parse_request: Header 4: Contact: (36) Aug 9 09:23:07 DEBUG[10179]: chan_sip.c:3357 parse_request: Header 5: Call-ID: 093e8fec7af28f8d3e5ab4cb24771e72@10.1.2.10 (52) Aug 9 09:23:07 DEBUG[10179]: chan_sip.c:3357 parse_request: Header 6: CSeq: 103 INVITE (16) Aug 9 09:23:07 DEBUG[10179]: chan_sip.c:3357 parse_request: Header 7: User-Agent: tull.ch PBX (23) Aug 9 09:23:07 DEBUG[10179]: chan_sip.c:3357 parse_request: Header 8: Max-Forwards: 70 (16) Aug 9 09:23:07 DEBUG[10179]: chan_sip.c:3357 parse_request: Header 9: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) Aug 9 09:23:07 DEBUG[10179]: chan_sip.c:3357 parse_request: Header 10: X-asterisk-info: SIP re-invite (RTP bridge) (43) Aug 9 09:23:07 DEBUG[10179]: chan_sip.c:3357 parse_request: Header 11: Content-Type: application/sdp (29) Aug 9 09:23:07 DEBUG[10179]: chan_sip.c:3357 parse_request: Header 12: Content-Length: 236 (19) Aug 9 09:23:07 DEBUG[10179]: chan_sip.c:3357 parse_request: Header 13: (0) Aug 9 09:23:07 DEBUG[10179]: chan_sip.c:3389 parse_request: Line: v=0 (3) Aug 9 09:23:07 DEBUG[10179]: chan_sip.c:3389 parse_request: Line: o=root 9977 9978 IN IP4 1.1.1.10 (35) Aug 9 09:23:07 DEBUG[10179]: chan_sip.c:3389 parse_request: Line: s=session (9) Aug 9 09:23:07 DEBUG[10179]: chan_sip.c:3389 parse_request: Line: c=IN IP4 1.1.1.10 (20) Aug 9 09:23:07 DEBUG[10179]: chan_sip.c:3389 parse_request: Line: t=0 0 (5) Aug 9 09:23:07 DEBUG[10179]: chan_sip.c:3389 parse_request: Line: m=audio 16386 RTP/AVP 8 0 101 (29) Aug 9 09:23:07 DEBUG[10179]: chan_sip.c:3389 parse_request: Line: a=rtpmap:8 PCMA/8000 (20) Aug 9 09:23:07 DEBUG[10179]: chan_sip.c:3389 parse_request: Line: a=rtpmap:0 PCMU/8000 (20) Aug 9 09:23:07 DEBUG[10179]: chan_sip.c:3389 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) Aug 9 09:23:07 DEBUG[10179]: chan_sip.c:3389 parse_request: Line: a=fmtp:101 0-16 (15) Aug 9 09:23:07 DEBUG[10179]: chan_sip.c:3389 parse_request: Line: a=silenceSupp:off - - - - (25) 13 headers, 11 lines Reliably Transmitting (no NAT) to 10.110.30.10:5060: INVITE sip:1601@10.110.30.10:5060;transport=udp SIP/2.0 Via: SIP/2.0/UDP 10.1.2.10:5060;branch=z9hG4bK311c341c;rport From: "MeanFaxMachine" ;tag=as0af0b132 To: ;tag=1937808815 Contact: Call-ID: 093e8fec7af28f8d3e5ab4cb24771e72@10.1.2.10 CSeq: 103 INVITE User-Agent: tull.ch 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: 236 v=0 o=root 9977 9978 IN IP4 1.1.1.10 s=session c=IN IP4 1.1.1.10 t=0 0 m=audio 16386 RTP/AVP 8 0 101 a=rtpmap:8 PCMA/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - --- Aug 9 09:23:07 DEBUG[9981]: chan_sip.c:11670 sip_devicestate: Checking device state for peer 10.110.30.10 Aug 9 09:23:07 DEBUG[10179]: chan_sip.c:1293 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #51 Aug 9 09:23:07 DEBUG[9981]: channel.c:777 channel_find_locked: Avoiding initial deadlock for 'SIP/10.110.30.10-0817b740' Aug 9 09:23:07 DEBUG[9981]: devicestate.c:187 do_state_change: Changing state for SIP/10.110.30.10 - state 2 (In use) Aug 9 09:23:07 DEBUG[9981]: chan_sip.c:11670 sip_devicestate: Checking device state for peer 6003 Aug 9 09:23:07 DEBUG[9981]: devicestate.c:187 do_state_change: Changing state for SIP/6003 - state 2 (In use) Aug 9 09:23:07 DEBUG[9981]: chan_sip.c:11670 sip_devicestate: Checking device state for peer 6003 Aug 9 09:23:07 DEBUG[10192]: app_queue.c:490 changethread: Device 'SIP/10.110.30.10' changed to state '2' (In use) but we don't care because they're not a member of any queue. Aug 9 09:23:07 DEBUG[10193]: app_queue.c:490 changethread: Device 'SIP/6003' changed to state '2' (In use) but we don't care because they're not a member of any queue. Aug 9 09:23:07 DEBUG[10179]: rtp.c:1353 ast_rtp_write: Ooh, format changed from unknown to alaw unnamedplayer*CLI> <-- SIP read from 1.1.1.10:5060: ACK sip:1601@10.1.2.10 SIP/2.0 Via: SIP/2.0/UDP 1.1.1.10:5060;branch=z9hG4bK7b15f7e7e9e6f8a3 From: 6003-steve ;tag=3764155442 To: ;tag=as1d6b437e Call-ID: 139264295@1.1.1.10 CSeq: 2 ACK User-Agent: Cisco ATA 188 v3.2.1 atasip (050616A) Proxy-Authorization: Digest username="6003",realm="tull.ch",nonce="20cf7ca1",uri="sip:1601@10.1.2.10",response="a1831309dfdcc9c219bdbd37c053b9bc" Content-Length: 0 Aug 9 09:23:08 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 0: ACK sip:1601@10.1.2.10 SIP/2.0 (37) Aug 9 09:23:08 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 1: Via: SIP/2.0/UDP 1.1.1.10:5060;branch=z9hG4bK7b15f7e7e9e6f8a3 (64) Aug 9 09:23:08 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 2: From: 6003-steve ;tag=3764155442 (69) Aug 9 09:23:08 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 3: To: ;tag=as1d6b437e (57) Aug 9 09:23:08 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 4: Call-ID: 139264295@1.1.1.10 (30) Aug 9 09:23:08 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 5: CSeq: 2 ACK (11) Aug 9 09:23:08 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 6: User-Agent: Cisco ATA 188 v3.2.1 atasip (050616A) (50) Aug 9 09:23:08 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 7: Proxy-Authorization: Digest username="6003",realm="tull.ch",nonce="20cf7ca1",uri="sip:1601@10.1.2.10",response="a1831309dfdcc9c219bdbd37c053b9bc" (157) Aug 9 09:23:08 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 8: Content-Length: 0 (17) Aug 9 09:23:08 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 9: (0) --- (9 headers 0 lines)--- Aug 9 09:23:08 DEBUG[9996]: chan_sip.c:11139 handle_request: **** Received ACK (6) - Command in SIP ACK Aug 9 09:23:08 DEBUG[9996]: chan_sip.c:1390 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #50 Aug 9 09:23:08 DEBUG[9996]: chan_sip.c:1401 __sip_ack: Stopping retransmission on '139264295@1.1.1.10' of Response 2: Match Found Aug 9 09:23:08 DEBUG[9996]: chan_sip.c:9561 check_pendings: Sending pending reinvite on '139264295@1.1.1.10' set_destination: Parsing for address/port to send to set_destination: set destination to 1.1.1.10, port 5060 We're at 10.1.2.10 port 16048 Video is at 10.1.2.10 port 16040 Adding codec 0x8 (alaw) to SDP Adding non-codec 0x1 (telephone-event) to SDP Aug 9 09:23:08 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 0: INVITE sip:6003@1.1.1.10:5060 SIP/2.0 (45) Aug 9 09:23:08 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 1: Via: SIP/2.0/UDP 10.1.2.10:5060;branch=z9hG4bK7a79778b;rport (61) Aug 9 09:23:08 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 2: From: ;tag=as1d6b437e (59) Aug 9 09:23:08 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 3: To: 6003-steve ;tag=3764155442 (67) Aug 9 09:23:08 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 4: Contact: (36) Aug 9 09:23:08 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 5: Call-ID: 139264295@1.1.1.10 (30) Aug 9 09:23:08 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 6: CSeq: 102 INVITE (16) Aug 9 09:23:08 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 7: User-Agent: tull.ch PBX (23) Aug 9 09:23:08 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 8: Max-Forwards: 70 (16) Aug 9 09:23:08 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 9: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) Aug 9 09:23:08 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 10: X-asterisk-info: SIP re-invite (RTP bridge) (43) Aug 9 09:23:08 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 11: Content-Type: application/sdp (29) Aug 9 09:23:08 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 12: Content-Length: 210 (19) Aug 9 09:23:08 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 13: (0) Aug 9 09:23:08 DEBUG[9996]: chan_sip.c:3389 parse_request: Line: v=0 (3) Aug 9 09:23:08 DEBUG[9996]: chan_sip.c:3389 parse_request: Line: o=root 9977 9978 IN IP4 10.110.30.10 (34) Aug 9 09:23:08 DEBUG[9996]: chan_sip.c:3389 parse_request: Line: s=session (9) Aug 9 09:23:08 DEBUG[9996]: chan_sip.c:3389 parse_request: Line: c=IN IP4 10.110.30.10 (19) Aug 9 09:23:08 DEBUG[9996]: chan_sip.c:3389 parse_request: Line: t=0 0 (5) Aug 9 09:23:08 DEBUG[9996]: chan_sip.c:3389 parse_request: Line: m=audio 16002 RTP/AVP 8 101 (27) Aug 9 09:23:08 DEBUG[9996]: chan_sip.c:3389 parse_request: Line: a=rtpmap:8 PCMA/8000 (20) Aug 9 09:23:08 DEBUG[9996]: chan_sip.c:3389 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) Aug 9 09:23:08 DEBUG[9996]: chan_sip.c:3389 parse_request: Line: a=fmtp:101 0-16 (15) Aug 9 09:23:08 DEBUG[9996]: chan_sip.c:3389 parse_request: Line: a=silenceSupp:off - - - - (25) 13 headers, 10 lines Reliably Transmitting (NAT) to 1.1.1.10:5060: INVITE sip:6003@1.1.1.10:5060 SIP/2.0 Via: SIP/2.0/UDP 10.1.2.10:5060;branch=z9hG4bK7a79778b;rport From: ;tag=as1d6b437e To: 6003-steve ;tag=3764155442 Contact: Call-ID: 139264295@1.1.1.10 CSeq: 102 INVITE User-Agent: tull.ch PBX ax-Forwards: 70LI> Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY X-asterisk-info: SIP re-invite (RTP bridge) Content-Type: application/sdp Content-Length: 210 v=0 o=root 9977 9978 IN IP4 10.110.30.10 s=session c=IN IP4 10.110.30.10 t=0 0 m=audio 16002 RTP/AVP 8 101 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - --- Aug 9 09:23:08 DEBUG[9996]: chan_sip.c:1293 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #52 Aug 9 09:23:08 DEBUG[10179]: rtp.c:1353 ast_rtp_write: Ooh, format changed from unknown to alaw unnamedplayer*CLI> <-- SIP read from 1.1.1.10:5060: SIP/2.0 200 OK Via: SIP/2.0/UDP 10.1.2.10:5060;branch=z9hG4bK7a79778b;rport From: ;tag=as1d6b437e To: 6003-steve ;tag=3764155442 Call-ID: 139264295@1.1.1.10 CSeq: 102 INVITE Contact: 6003-steve Server: Cisco ATA 188 v3.2.1 atasip (050616A) Allow: ACK, BYE, CANCEL, INVITE, NOTIFY, OPTIONS, REFER, REGISTER, PRACK, UPDATE Supported: replaces Content-Length: 200 Content-Type: application/sdp v=0 o=6003 217243 217243 IN IP4 1.1.1.10 s=ATA186 Call c=IN IP4 1.1.1.10 t=0 0 m=audio 16386 RTP/AVP 8 101 a=rtpmap:8 PCMA/8000/1 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 Aug 9 09:23:08 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 0: SIP/2.0 200 OK (14) Aug 9 09:23:08 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 1: Via: SIP/2.0/UDP 10.1.2.10:5060;branch=z9hG4bK7a79778b;rport (61) Aug 9 09:23:08 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 2: From: ;tag=as1d6b437e (59) Aug 9 09:23:08 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 3: To: 6003-steve ;tag=3764155442 (67) Aug 9 09:23:08 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 4: Call-ID: 139264295@1.1.1.10 (30) Aug 9 09:23:08 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 5: CSeq: 102 INVITE (16) Aug 9 09:23:08 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 6: Contact: 6003-steve (77) Aug 9 09:23:08 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 7: Server: Cisco ATA 188 v3.2.1 atasip (050616A) (46) Aug 9 09:23:08 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 8: Allow: ACK, BYE, CANCEL, INVITE, NOTIFY, OPTIONS, REFER, REGISTER, PRACK, UPDATE (80) Aug 9 09:23:08 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 9: Supported: replaces (19) Aug 9 09:23:08 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 10: Content-Length: 200 (19) Aug 9 09:23:08 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 11: Content-Type: application/sdp (29) Aug 9 09:23:08 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 12: (0) Aug 9 09:23:08 DEBUG[9996]: chan_sip.c:3389 parse_request: Line: v=0 (3) Aug 9 09:23:08 DEBUG[9996]: chan_sip.c:3389 parse_request: Line: o=6003 217243 217243 IN IP4 1.1.1.10 (44) Aug 9 09:23:08 DEBUG[9996]: chan_sip.c:3389 parse_request: Line: s=ATA186 Call (13) Aug 9 09:23:08 DEBUG[9996]: chan_sip.c:3389 parse_request: Line: c=IN IP4 1.1.1.10 (20) Aug 9 09:23:08 DEBUG[9996]: chan_sip.c:3389 parse_request: Line: t=0 0 (5) Aug 9 09:23:08 DEBUG[9996]: chan_sip.c:3389 parse_request: Line: m=audio 16386 RTP/AVP 8 101 (27) Aug 9 09:23:08 DEBUG[9996]: chan_sip.c:3389 parse_request: Line: a=rtpmap:8 PCMA/8000/1 (22) Aug 9 09:23:08 DEBUG[9996]: chan_sip.c:3389 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) Aug 9 09:23:08 DEBUG[9996]: chan_sip.c:3389 parse_request: Line: a=fmtp:101 0-15 (15) --- (12 headers 9 lines)--- Aug 9 09:23:08 DEBUG[9996]: chan_sip.c:1379 __sip_ack: Acked pending invite 102 Aug 9 09:23:08 DEBUG[9996]: chan_sip.c:1390 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #52 Aug 9 09:23:08 DEBUG[9996]: chan_sip.c:1401 __sip_ack: Stopping retransmission on '139264295@1.1.1.10' of Request 102: Match Found Aug 9 09:23:08 DEBUG[9996]: chan_sip.c:9576 handle_response_invite: SIP response 200 to RE-invite on outgoing call 139264295@1.1.1.10 Found RTP audio format 8 Found RTP audio format 101 Peer audio RTP is at port 1.1.1.10:16386 Aug 9 09:23:08 DEBUG[9996]: chan_sip.c:3598 process_sdp: Peer audio RTP is at port 1.1.1.10:16386 Peer video RTP is at port 1.1.1.10:65535 Aug 9 09:23:08 DEBUG[9996]: chan_sip.c:3622 process_sdp: Peer video RTP is at port 1.1.1.10:65535 Found description format PCMA Found description format telephone-event Capabilities: us - 0xa (gsm|alaw), peer - audio=0x8 (alaw)/video=0x0 (nothing), combined - 0x8 (alaw) Non-codec capabilities: us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) Aug 9 09:23:08 DEBUG[9996]: chan_sip.c:6131 build_route: build_route: Contact hop: 6003-steve list_route: hop: set_destination: Parsing for address/port to send to set_destination: set destination to 1.1.1.10, port 5060 Transmitting (NAT) to 1.1.1.10:5060: ACK sip:6003@1.1.1.10:5060;user=phone;transport=udp SIP/2.0 Via: SIP/2.0/UDP 10.1.2.10:5060;branch=z9hG4bK0e9df56e;rport From: ;tag=as1d6b437e To: 6003-steve ;tag=3764155442 Contact: Call-ID: 139264295@1.1.1.10 CSeq: 102 ACK User-Agent: tull.ch PBX Max-Forwards: 70 Content-Length: 0 --- unnamedplayer*CLI> <-- SIP read from 10.110.30.10:5060: SIP/2.0 200 Ok Via: SIP/2.0/UDP 10.1.2.10:5060;received=10.1.2.10;branch=z9hG4bK311c341c;rport=5060 From: "MeanFaxMachine" ;tag=as0af0b132 To: ;tag=1937808815 Call-ID: 093e8fec7af28f8d3e5ab4cb24771e72@10.1.2.10 CSeq: 103 INVITE Contact: Allow: INVITE,ACK,PRACK,SUBSCRIBE,BYE,CANCEL,NOTIFY,INFO,REFER,UPDATE Supported: timer Content-Type: application/sdp Content-Length: 340 v=0 o=- 89 1 IN IP4 10.110.30.10 s=Cisco SDP 0 c=IN IP4 10.110.30.10 t=0 0 m=audio 16002 RTP/AVP 8 101 100 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=rtpmap:100 X-NSE/8000 a=fmtp:100 200-202 a=X-sqn:0 a=X-cap: 1 audio RTP/AVP 100 a=X-cpar: a=rtpmap:100 X-NSE/8000 a=X-cpar: a=fmtp:100 200-202 a=X-cap: 2 image udptl t38 Aug 9 09:23:08 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 0: SIP/2.0 200 Ok (14) Aug 9 09:23:08 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 1: Via: SIP/2.0/UDP 10.1.2.10:5060;received=10.1.2.10;branch=z9hG4bK311c341c;rport=5060 (86) Aug 9 09:23:08 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 2: From: "MeanFaxMachine" ;tag=as0af0b132 (65) Aug 9 09:23:08 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 3: To: ;tag=1937808815 (46) Aug 9 09:23:08 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 4: Call-ID: 093e8fec7af28f8d3e5ab4cb24771e72@10.1.2.10 (52) Aug 9 09:23:08 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 5: CSeq: 103 INVITE (16) Aug 9 09:23:08 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 6: Contact: (55) Aug 9 09:23:08 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 7: Allow: INVITE,ACK,PRACK,SUBSCRIBE,BYE,CANCEL,NOTIFY,INFO,REFER,UPDATE (69) Aug 9 09:23:08 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 8: Supported: timer (16) Aug 9 09:23:08 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 9: Content-Type: application/sdp (29) Aug 9 09:23:08 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 10: Content-Length: 340 (19) Aug 9 09:23:08 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 11: (0) Aug 9 09:23:08 DEBUG[9996]: chan_sip.c:3389 parse_request: Line: v=0 (3) Aug 9 09:23:08 DEBUG[9996]: chan_sip.c:3389 parse_request: Line: o=- 89 1 IN IP4 10.110.30.10 (26) Aug 9 09:23:08 DEBUG[9996]: chan_sip.c:3389 parse_request: Line: s=Cisco SDP 0 (13) Aug 9 09:23:08 DEBUG[9996]: chan_sip.c:3389 parse_request: Line: c=IN IP4 10.110.30.10 (19) Aug 9 09:23:08 DEBUG[9996]: chan_sip.c:3389 parse_request: Line: t=0 0 (5) Aug 9 09:23:08 DEBUG[9996]: chan_sip.c:3389 parse_request: Line: m=audio 16002 RTP/AVP 8 101 100 (31) Aug 9 09:23:08 DEBUG[9996]: chan_sip.c:3389 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) Aug 9 09:23:08 DEBUG[9996]: chan_sip.c:3389 parse_request: Line: a=fmtp:101 0-15 (15) Aug 9 09:23:08 DEBUG[9996]: chan_sip.c:3389 parse_request: Line: a=rtpmap:100 X-NSE/8000 (23) Aug 9 09:23:08 DEBUG[9996]: chan_sip.c:3389 parse_request: Line: a=fmtp:100 200-202 (18) Aug 9 09:23:08 DEBUG[9996]: chan_sip.c:3389 parse_request: Line: a=X-sqn:0 (9) Aug 9 09:23:08 DEBUG[9996]: chan_sip.c:3389 parse_request: Line: a=X-cap: 1 audio RTP/AVP 100 (28) Aug 9 09:23:08 DEBUG[9996]: chan_sip.c:3389 parse_request: Line: a=X-cpar: a=rtpmap:100 X-NSE/8000 (33) Aug 9 09:23:08 DEBUG[9996]: chan_sip.c:3389 parse_request: Line: a=X-cpar: a=fmtp:100 200-202 (28) Aug 9 09:23:08 DEBUG[9996]: chan_sip.c:3389 parse_request: Line: a=X-cap: 2 image udptl t38 (26) --- (11 headers 15 lines)--- Aug 9 09:23:08 DEBUG[9996]: chan_sip.c:1379 __sip_ack: Acked pending invite 103 Aug 9 09:23:08 DEBUG[9996]: chan_sip.c:1390 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #51 Aug 9 09:23:08 DEBUG[9996]: chan_sip.c:1401 __sip_ack: Stopping retransmission on '093e8fec7af28f8d3e5ab4cb24771e72@10.1.2.10' of Request 103: Match Found Aug 9 09:23:08 DEBUG[9996]: chan_sip.c:9576 handle_response_invite: SIP response 200 to RE-invite on outgoing call 093e8fec7af28f8d3e5ab4cb24771e72@10.1.2.10 Found RTP audio format 8 Found RTP audio format 101 Found RTP audio format 100 Peer audio RTP is at port 10.110.30.10:16002 Aug 9 09:23:08 DEBUG[9996]: chan_sip.c:3598 process_sdp: Peer audio RTP is at port 10.110.30.10:16002 Peer video RTP is at port 10.110.30.10:65535 Aug 9 09:23:08 DEBUG[9996]: chan_sip.c:3622 process_sdp: Peer video RTP is at port 10.110.30.10:65535 Found description format telephone-event Found description format X-NSE Capabilities: us - 0x40a (gsm|alaw|ilbc), peer - audio=0x8 (alaw)/video=0x0 (nothing), combined - 0x8 (alaw) Non-codec capabilities: us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) Aug 9 09:23:08 DEBUG[9996]: chan_sip.c:6074 build_route: build_route: Retaining previous route: set_destination: Parsing for address/port to send to set_destination: set destination to 10.110.30.10, port 5060 Transmitting (no NAT) to 10.110.30.10:5060: ACK sip:1601@10.110.30.10:5060;transport=udp SIP/2.0 Via: SIP/2.0/UDP 10.1.2.10:5060;branch=z9hG4bK4df8d5ed;rport From: "MeanFaxMachine" ;tag=as0af0b132 To: ;tag=1937808815 Contact: Call-ID: 093e8fec7af28f8d3e5ab4cb24771e72@10.1.2.10 CSeq: 103 ACK User-Agent: tull.ch PBX Max-Forwards: 70 Content-Length: 0 --- unnamedplayer*CLI> <-- SIP read from 172.16.8.125:7120: Aug 9 09:23:08 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 0: (0) --- (0 headers 0 lines) Nat keepalive --- unnamedplayer*CLI> <-- SIP read from 10.110.30.10:5060: INVITE sip:06003@10.1.2.10 SIP/2.0 Via: SIP/2.0/UDP 10.110.30.10:5060;branch=z9hG4bK000muu2030agpa8og541sb0000g00.1 From: ;tag=1937808815 To: "MeanFaxMachine" ;tag=as0af0b132 Call-ID: 093e8fec7af28f8d3e5ab4cb24771e72@10.1.2.10 CSeq: 1 INVITE Supported: timer Contact: Allow: INVITE,ACK,PRACK,SUBSCRIBE,BYE,CANCEL,NOTIFY,INFO,REFER,UPDATE Max-Forwards: 69 Content-Type: application/sdp Content-Length: 235 v=0 o=- 89 2 IN IP4 10.110.30.10 s=Cisco SDP 0 c=IN IP4 10.110.30.10 t=0 0 m=image 16002 udptl t38 a=X-sqn:0 a=X-cap: 1 audio RTP/AVP 100 a=X-cpar: a=rtpmap:100 X-NSE/8000 a=X-cpar: a=fmtp:100 200-202 a=X-cap: 2 image udptl t38 Aug 9 09:23:15 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 0: INVITE sip:06003@10.1.2.10 SIP/2.0 (40) Aug 9 09:23:15 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 1: Via: SIP/2.0/UDP 10.110.30.10:5060;branch=z9hG4bK000muu2030agpa8og541sb0000g00.1 (78) Aug 9 09:23:15 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 2: From: ;tag=1937808815 (48) Aug 9 09:23:15 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 3: To: "MeanFaxMachine" ;tag=as0af0b132 (63) Aug 9 09:23:15 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 4: Call-ID: 093e8fec7af28f8d3e5ab4cb24771e72@10.1.2.10 (52) Aug 9 09:23:15 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 5: CSeq: 1 INVITE (14) Aug 9 09:23:15 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 6: Supported: timer (16) Aug 9 09:23:15 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 7: Contact: (55) Aug 9 09:23:15 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 8: Allow: INVITE,ACK,PRACK,SUBSCRIBE,BYE,CANCEL,NOTIFY,INFO,REFER,UPDATE (69) Aug 9 09:23:15 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 9: Max-Forwards: 69 (16) Aug 9 09:23:15 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 10: Content-Type: application/sdp (29) Aug 9 09:23:15 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 11: Content-Length: 235 (19) Aug 9 09:23:15 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 12: (0) Aug 9 09:23:15 DEBUG[9996]: chan_sip.c:3389 parse_request: Line: v=0 (3) Aug 9 09:23:15 DEBUG[9996]: chan_sip.c:3389 parse_request: Line: o=- 89 2 IN IP4 10.110.30.10 (26) Aug 9 09:23:15 DEBUG[9996]: chan_sip.c:3389 parse_request: Line: s=Cisco SDP 0 (13) Aug 9 09:23:15 DEBUG[9996]: chan_sip.c:3389 parse_request: Line: c=IN IP4 10.110.30.10 (19) Aug 9 09:23:15 DEBUG[9996]: chan_sip.c:3389 parse_request: Line: t=0 0 (5) Aug 9 09:23:15 DEBUG[9996]: chan_sip.c:3389 parse_request: Line: m=image 16002 udptl t38 (23) Aug 9 09:23:15 DEBUG[9996]: chan_sip.c:3389 parse_request: Line: a=X-sqn:0 (9) Aug 9 09:23:15 DEBUG[9996]: chan_sip.c:3389 parse_request: Line: a=X-cap: 1 audio RTP/AVP 100 (28) Aug 9 09:23:15 DEBUG[9996]: chan_sip.c:3389 parse_request: Line: a=X-cpar: a=rtpmap:100 X-NSE/8000 (33) Aug 9 09:23:15 DEBUG[9996]: chan_sip.c:3389 parse_request: Line: a=X-cpar: a=fmtp:100 200-202 (28) Aug 9 09:23:15 DEBUG[9996]: chan_sip.c:3389 parse_request: Line: a=X-cap: 2 image udptl t38 (26) --- (12 headers 11 lines)--- Aug 9 09:23:15 DEBUG[9996]: chan_sip.c:11139 handle_request: **** Received INVITE (5) - Command in SIP INVITE Aug 9 09:23:15 DEBUG[9996]: chan_sip.c:1004 parse_sip_options: Begin: parsing SIP "Supported: timer" Aug 9 09:23:15 DEBUG[9996]: chan_sip.c:1016 parse_sip_options: Found SIP option: -timer- Aug 9 09:23:15 DEBUG[9996]: chan_sip.c:1022 parse_sip_options: Matched SIP option: timer Aug 9 09:23:15 DEBUG[9996]: chan_sip.c:1033 parse_sip_options: * SIP extension value: 4 for call 093e8fec7af28f8d3e5ab4cb24771e72@10.1.2.10 Using INVITE request as basis request - 093e8fec7af28f8d3e5ab4cb24771e72@10.1.2.10 Sending to 10.110.30.10 : 5060 (non-NAT) Aug 9 09:23:15 WARNING[9996]: chan_sip.c:3567 process_sdp: Unknown SDP media type in offer: image 16002 udptl t38 Transmitting (no NAT) to 10.110.30.10:5060: SIP/2.0 488 Not acceptable here Via: SIP/2.0/UDP 10.110.30.10:5060;branch=z9hG4bK000muu2030agpa8og541sb0000g00.1;received=10.110.30.10 From: ;tag=1937808815 To: "MeanFaxMachine" ;tag=as0af0b132 Call-ID: 093e8fec7af28f8d3e5ab4cb24771e72@10.1.2.10 CSeq: 1 INVITE User-Agent: tull.ch PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Contact: Content-Length: 0 X-Asterisk-HangupCause: Normal Clearing --- Aug 9 09:23:15 DEBUG[9996]: chan_sip.c:11340 sipsock_read: SIP message could not be handled, bad request: 093e8fec7af28f8d3e5ab4cb24771e72@10.1.2.10 unnamedplayer*CLI> <-- SIP read from 10.110.30.10:5060: ACK sip:06003@10.1.2.10 SIP/2.0 Via: SIP/2.0/UDP 10.110.30.10:5060;branch=z9hG4bK000muu2030agpa8og541sb0000g00.1 CSeq: 1 ACK From: ;tag=1937808815 To: "MeanFaxMachine" ;tag=as0af0b132 Call-ID: 093e8fec7af28f8d3e5ab4cb24771e72@10.1.2.10 Max-Forwards: 69 Content-Length: 0 Aug 9 09:23:15 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 0: ACK sip:06003@10.1.2.10 SIP/2.0 (37) Aug 9 09:23:15 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 1: Via: SIP/2.0/UDP 10.110.30.10:5060;branch=z9hG4bK000muu2030agpa8og541sb0000g00.1 (78) Aug 9 09:23:15 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 2: CSeq: 1 ACK (11) Aug 9 09:23:15 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 3: From: ;tag=1937808815 (48) Aug 9 09:23:15 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 4: To: "MeanFaxMachine" ;tag=as0af0b132 (63) Aug 9 09:23:15 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 5: Call-ID: 093e8fec7af28f8d3e5ab4cb24771e72@10.1.2.10 (52) Aug 9 09:23:15 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 6: Max-Forwards: 69 (16) Aug 9 09:23:15 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 7: Content-Length: 0 (17) Aug 9 09:23:15 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 8: (0) --- (8 headers 0 lines)--- Aug 9 09:23:15 DEBUG[9996]: chan_sip.c:11139 handle_request: **** Received ACK (6) - Command in SIP ACK Aug 9 09:23:15 DEBUG[9996]: chan_sip.c:1401 __sip_ack: Stopping retransmission on '093e8fec7af28f8d3e5ab4cb24771e72@10.1.2.10' of Response 1: Match Not Found unnamedplayer*CLI> <-- SIP read from 172.22.23.26:5060: INVITE sip:06003@10.1.2.10:5060;user=phone SIP/2.0 Via: SIP/2.0/UDP pgw-sip.cablecom.lab:5060 ;branch=z9hG4bKorig-7b-06003-1601-93151 From: ;tag=1937808815 To: "MeanFaxMachine" ;tag=as0af0b132 Call-ID: 093e8fec7af28f8d3e5ab4cb24771e72@10.1.2.10 CSeq: 2 INVITE Supported: timer Contact: Allow: INVITE,ACK,PRACK,SUBSCRIBE,BYE,CANCEL,NOTIFY,INFO,REFER,UPDATE Max-Forwards: 70 Content-Type: application/sdp Content-Length: 295 v=0 o=- 89 3 IN IP4 172.17.14.12 s=Cisco SDP 0 c=IN IP4 172.17.14.12 t=0 0 m=audio 16864 RTP/AVP 8 101 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=X-sqn:0 a=X-cap: 1 audio RTP/AVP 100 a=X-cpar: a=rtpmap:100 X-NSE/8000 a=X-cpar: a=fmtp:100 200-202 a=X-cap: 2 image udptl t38 Aug 9 09:23:16 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 0: INVITE sip:06003@10.1.2.10:5060;user=phone SIP/2.0 (56) Aug 9 09:23:16 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 1: Via: SIP/2.0/UDP pgw-sip.cablecom.lab:5060 ;branch=z9hG4bKorig-7b-06003-1601-93151 (93) Aug 9 09:23:16 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 2: From: ;tag=1937808815 (48) Aug 9 09:23:16 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 3: To: "MeanFaxMachine" ;tag=as0af0b132 (63) Aug 9 09:23:16 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 4: Call-ID: 093e8fec7af28f8d3e5ab4cb24771e72@10.1.2.10 (52) Aug 9 09:23:16 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 5: CSeq: 2 INVITE (14) Aug 9 09:23:16 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 6: Supported: timer (16) Aug 9 09:23:16 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 7: Contact: (52) Aug 9 09:23:16 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 8: Allow: INVITE,ACK,PRACK,SUBSCRIBE,BYE,CANCEL,NOTIFY,INFO,REFER,UPDATE (69) Aug 9 09:23:16 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 9: Max-Forwards: 70 (16) Aug 9 09:23:16 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 10: Content-Type: application/sdp (29) Aug 9 09:23:16 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 11: Content-Length: 295 (19) Aug 9 09:23:16 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 12: (0) Aug 9 09:23:16 DEBUG[9996]: chan_sip.c:3389 parse_request: Line: v=0 (3) Aug 9 09:23:16 DEBUG[9996]: chan_sip.c:3389 parse_request: Line: o=- 89 3 IN IP4 172.17.14.12 (28) Aug 9 09:23:16 DEBUG[9996]: chan_sip.c:3389 parse_request: Line: s=Cisco SDP 0 (13) Aug 9 09:23:16 DEBUG[9996]: chan_sip.c:3389 parse_request: Line: c=IN IP4 172.17.14.12 (21) Aug 9 09:23:16 DEBUG[9996]: chan_sip.c:3389 parse_request: Line: t=0 0 (5) Aug 9 09:23:16 DEBUG[9996]: chan_sip.c:3389 parse_request: Line: m=audio 16864 RTP/AVP 8 101 (27) Aug 9 09:23:16 DEBUG[9996]: chan_sip.c:3389 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) Aug 9 09:23:16 DEBUG[9996]: chan_sip.c:3389 parse_request: Line: a=fmtp:101 0-15 (15) Aug 9 09:23:16 DEBUG[9996]: chan_sip.c:3389 parse_request: Line: a=X-sqn:0 (9) Aug 9 09:23:16 DEBUG[9996]: chan_sip.c:3389 parse_request: Line: a=X-cap: 1 audio RTP/AVP 100 (28) Aug 9 09:23:16 DEBUG[9996]: chan_sip.c:3389 parse_request: Line: a=X-cpar: a=rtpmap:100 X-NSE/8000 (33) Aug 9 09:23:16 DEBUG[9996]: chan_sip.c:3389 parse_request: Line: a=X-cpar: a=fmtp:100 200-202 (28) Aug 9 09:23:16 DEBUG[9996]: chan_sip.c:3389 parse_request: Line: a=X-cap: 2 image udptl t38 (26) --- (12 headers 13 lines)--- Aug 9 09:23:16 DEBUG[9996]: chan_sip.c:11139 handle_request: **** Received INVITE (5) - Command in SIP INVITE Using INVITE request as basis request - 093e8fec7af28f8d3e5ab4cb24771e72@10.1.2.10 Sending to 172.22.23.26 : 5060 (non-NAT) Found RTP audio format 8 Found RTP audio format 101 Peer audio RTP is at port 172.17.14.12:16864 Aug 9 09:23:16 DEBUG[9996]: chan_sip.c:3598 process_sdp: Peer audio RTP is at port 172.17.14.12:16864 Peer video RTP is at port 172.17.14.12:65535 Aug 9 09:23:16 DEBUG[9996]: chan_sip.c:3622 process_sdp: Peer video RTP is at port 172.17.14.12:65535 Found description format telephone-event Capabilities: us - 0x40a (gsm|alaw|ilbc), peer - audio=0x8 (alaw)/video=0x0 (nothing), combined - 0x8 (alaw) Non-codec capabilities: us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) Aug 9 09:23:16 DEBUG[9996]: chan_sip.c:10550 handle_request_invite: Got a SIP re-invite for call 093e8fec7af28f8d3e5ab4cb24771e72@10.1.2.10 We're at 10.1.2.10 port 16034 Video is at 10.1.2.10 port 16004 Adding codec 0x8 (alaw) to SDP Adding codec 0x4 (ulaw) to SDP Adding non-codec 0x1 (telephone-event) to SDP Reliably Transmitting (no NAT) to 172.22.23.26:5060: SIP/2.0 200 OK Via: SIP/2.0/UDP pgw-sip.cablecom.lab:5060 ;branch=z9hG4bKorig-7b-06003-1601-93151;received=172.22.23.26 From: ;tag=1937808815 To: "MeanFaxMachine" ;tag=as0af0b132 Call-ID: 093e8fec7af28f8d3e5ab4cb24771e72@10.1.2.10 CSeq: 2 INVITE User-Agent: tull.ch PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Contact: Content-Type: application/sdp Content-Length: 236 v=0 o=root 9977 9979 IN IP4 1.1.1.10 s=session c=IN IP4 1.1.1.10 t=0 0 m=audio 16386 RTP/AVP 8 0 101 a=rtpmap:8 PCMA/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - --- Aug 9 09:23:16 DEBUG[9996]: chan_sip.c:1293 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #53 Aug 9 09:23:16 DEBUG[10179]: rtp.c:1666 ast_rtp_bridge: Oooh, 'SIP/10.110.30.10-0817b740' changed end address to 172.17.14.12:16864 (format 8) Aug 9 09:23:16 DEBUG[10179]: rtp.c:1668 ast_rtp_bridge: Oooh, 'SIP/10.110.30.10-0817b740' changed end vaddress to 172.17.14.12:65535 (format 8) Aug 9 09:23:16 DEBUG[10179]: rtp.c:1670 ast_rtp_bridge: Oooh, 'SIP/10.110.30.10-0817b740' was 10.110.30.10:16002/(format 8) Aug 9 09:23:16 DEBUG[10179]: rtp.c:1672 ast_rtp_bridge: Oooh, 'SIP/10.110.30.10-0817b740' was 10.110.30.10:65535/(format 8) Aug 9 09:23:16 DEBUG[10179]: chan_sip.c:12920 sip_set_rtp_peer: Sending reinvite on SIP '139264295@1.1.1.10' - It's audio soon redirected to IP 172.17.14.12 set_destination: Parsing for address/port to send to set_destination: set destination to 1.1.1.10, port 5060 We're at 10.1.2.10 port 16048 Video is at 10.1.2.10 port 16040 Adding codec 0x8 (alaw) to SDP Adding non-codec 0x1 (telephone-event) to SDP Aug 9 09:23:16 DEBUG[10179]: chan_sip.c:3357 parse_request: Header 0: INVITE sip:6003@1.1.1.10:5060;user=phone;transport=udp SIP/2.0 (70) Aug 9 09:23:16 DEBUG[10179]: chan_sip.c:3357 parse_request: Header 1: Via: SIP/2.0/UDP 10.1.2.10:5060;branch=z9hG4bK03616cc8;rport (61) Aug 9 09:23:16 DEBUG[10179]: chan_sip.c:3357 parse_request: Header 2: From: ;tag=as1d6b437e (59) Aug 9 09:23:16 DEBUG[10179]: chan_sip.c:3357 parse_request: Header 3: To: 6003-steve ;tag=3764155442 (67) Aug 9 09:23:16 DEBUG[10179]: chan_sip.c:3357 parse_request: Header 4: Contact: (36) Aug 9 09:23:16 DEBUG[10179]: chan_sip.c:3357 parse_request: Header 5: Call-ID: 139264295@1.1.1.10 (30) Aug 9 09:23:16 DEBUG[10179]: chan_sip.c:3357 parse_request: Header 6: CSeq: 103 INVITE (16) Aug 9 09:23:16 DEBUG[10179]: chan_sip.c:3357 parse_request: Header 7: User-Agent: tull.ch PBX (23) Aug 9 09:23:16 DEBUG[10179]: chan_sip.c:3357 parse_request: Header 8: Max-Forwards: 70 (16) Aug 9 09:23:16 DEBUG[10179]: chan_sip.c:3357 parse_request: Header 9: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) Aug 9 09:23:16 DEBUG[10179]: chan_sip.c:3357 parse_request: Header 10: X-asterisk-info: SIP re-invite (RTP bridge) (43) Aug 9 09:23:16 DEBUG[10179]: chan_sip.c:3357 parse_request: Header 11: Content-Type: application/sdp (29) Aug 9 09:23:16 DEBUG[10179]: chan_sip.c:3357 parse_request: Header 12: Content-Length: 214 (19) Aug 9 09:23:16 DEBUG[10179]: chan_sip.c:3357 parse_request: Header 13: (0) Aug 9 09:23:16 DEBUG[10179]: chan_sip.c:3389 parse_request: Line: v=0 (3) Aug 9 09:23:16 DEBUG[10179]: chan_sip.c:3389 parse_request: Line: o=root 9977 9979 IN IP4 172.17.14.12 (36) Aug 9 09:23:16 DEBUG[10179]: chan_sip.c:3389 parse_request: Line: s=session (9) Aug 9 09:23:16 DEBUG[10179]: chan_sip.c:3389 parse_request: Line: c=IN IP4 172.17.14.12 (21) Aug 9 09:23:16 DEBUG[10179]: chan_sip.c:3389 parse_request: Line: t=0 0 (5) Aug 9 09:23:16 DEBUG[10179]: chan_sip.c:3389 parse_request: Line: m=audio 16864 RTP/AVP 8 101 (27) Aug 9 09:23:16 DEBUG[10179]: chan_sip.c:3389 parse_request: Line: a=rtpmap:8 PCMA/8000 (20) Aug 9 09:23:16 DEBUG[10179]: chan_sip.c:3389 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) Aug 9 09:23:16 DEBUG[10179]: chan_sip.c:3389 parse_request: Line: a=fmtp:101 0-16 (15) Aug 9 09:23:16 DEBUG[10179]: chan_sip.c:3389 parse_request: Line: a=silenceSupp:off - - - - (25) 13 headers, 10 lines Reliably Transmitting (NAT) to 1.1.1.10:5060: INVITE sip:6003@1.1.1.10:5060;user=phone;transport=udp SIP/2.0 Via: SIP/2.0/UDP 10.1.2.10:5060;branch=z9hG4bK03616cc8;rport From: ;tag=as1d6b437e To: 6003-steve ;tag=3764155442 Contact: Call-ID: 139264295@1.1.1.10 CSeq: 103 INVITE User-Agent: tull.ch 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 9977 9979 IN IP4 172.17.14.12 s=session c=IN IP4 172.17.14.12 t=0 0 m=audio 16864 RTP/AVP 8 101 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - --- Aug 9 09:23:16 DEBUG[10179]: chan_sip.c:1293 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #54 unnamedplayer*CLI> <-- SIP read from 172.22.23.26:5060: ACK sip:06003@10.1.2.10:5060;user=phone SIP/2.0 Via: SIP/2.0/UDP pgw-sip.cablecom.lab:5060 ;branch=z9hG4bKorig-7b-06003-1601-93151 From: ;tag=1937808815 To: "MeanFaxMachine" ;tag=as0af0b132 Call-ID: 093e8fec7af28f8d3e5ab4cb24771e72@10.1.2.10 CSeq: 2 ACK Content-Length: 0 Aug 9 09:23:16 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 0: ACK sip:06003@10.1.2.10:5060;user=phone SIP/2.0 (53) Aug 9 09:23:16 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 1: Via: SIP/2.0/UDP pgw-sip.cablecom.lab:5060 ;branch=z9hG4bKorig-7b-06003-1601-93151 (93) Aug 9 09:23:16 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 2: From: ;tag=1937808815 (48) Aug 9 09:23:16 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 3: To: "MeanFaxMachine" ;tag=as0af0b132 (63) Aug 9 09:23:16 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 4: Call-ID: 093e8fec7af28f8d3e5ab4cb24771e72@10.1.2.10 (52) Aug 9 09:23:16 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 5: CSeq: 2 ACK (11) Aug 9 09:23:16 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 6: Content-Length: 0 (17) Aug 9 09:23:16 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 7: (0) --- (7 headers 0 lines)--- Aug 9 09:23:16 DEBUG[9996]: chan_sip.c:11139 handle_request: **** Received ACK (6) - Command in SIP ACK Aug 9 09:23:16 DEBUG[9996]: chan_sip.c:1390 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #53 Aug 9 09:23:16 DEBUG[9996]: chan_sip.c:1401 __sip_ack: Stopping retransmission on '093e8fec7af28f8d3e5ab4cb24771e72@10.1.2.10' of Response 2: Match Found unnamedplayer*CLI> <-- SIP read from 1.1.1.10:5060: SIP/2.0 200 OK Via: SIP/2.0/UDP 10.1.2.10:5060;branch=z9hG4bK03616cc8;rport From: ;tag=as1d6b437e To: 6003-steve ;tag=3764155442 Call-ID: 139264295@1.1.1.10 CSeq: 103 INVITE Contact: 6003-steve Server: Cisco ATA 188 v3.2.1 atasip (050616A) Allow: ACK, BYE, CANCEL, INVITE, NOTIFY, OPTIONS, REFER, REGISTER, PRACK, UPDATE Supported: replaces Content-Length: 200 Content-Type: application/sdp v=0 o=6003 218119 218119 IN IP4 1.1.1.10 s=ATA186 Call c=IN IP4 1.1.1.10 t=0 0 m=audio 16386 RTP/AVP 8 101 a=rtpmap:8 PCMA/8000/1 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 Aug 9 09:23:16 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 0: SIP/2.0 200 OK (14) Aug 9 09:23:16 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 1: Via: SIP/2.0/UDP 10.1.2.10:5060;branch=z9hG4bK03616cc8;rport (61) Aug 9 09:23:16 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 2: From: ;tag=as1d6b437e (59) Aug 9 09:23:16 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 3: To: 6003-steve ;tag=3764155442 (67) Aug 9 09:23:16 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 4: Call-ID: 139264295@1.1.1.10 (30) Aug 9 09:23:16 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 5: CSeq: 103 INVITE (16) Aug 9 09:23:16 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 6: Contact: 6003-steve (77) Aug 9 09:23:16 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 7: Server: Cisco ATA 188 v3.2.1 atasip (050616A) (46) Aug 9 09:23:16 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 8: Allow: ACK, BYE, CANCEL, INVITE, NOTIFY, OPTIONS, REFER, REGISTER, PRACK, UPDATE (80) Aug 9 09:23:16 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 9: Supported: replaces (19) Aug 9 09:23:16 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 10: Content-Length: 200 (19) Aug 9 09:23:16 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 11: Content-Type: application/sdp (29) Aug 9 09:23:16 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 12: (0) Aug 9 09:23:16 DEBUG[9996]: chan_sip.c:3389 parse_request: Line: v=0 (3) Aug 9 09:23:16 DEBUG[9996]: chan_sip.c:3389 parse_request: Line: o=6003 218119 218119 IN IP4 1.1.1.10 (44) Aug 9 09:23:16 DEBUG[9996]: chan_sip.c:3389 parse_request: Line: s=ATA186 Call (13) Aug 9 09:23:16 DEBUG[9996]: chan_sip.c:3389 parse_request: Line: c=IN IP4 1.1.1.10 (20) Aug 9 09:23:16 DEBUG[9996]: chan_sip.c:3389 parse_request: Line: t=0 0 (5) Aug 9 09:23:16 DEBUG[9996]: chan_sip.c:3389 parse_request: Line: m=audio 16386 RTP/AVP 8 101 (27) Aug 9 09:23:16 DEBUG[9996]: chan_sip.c:3389 parse_request: Line: a=rtpmap:8 PCMA/8000/1 (22) Aug 9 09:23:16 DEBUG[9996]: chan_sip.c:3389 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) Aug 9 09:23:16 DEBUG[9996]: chan_sip.c:3389 parse_request: Line: a=fmtp:101 0-15 (15) --- (12 headers 9 lines)--- Aug 9 09:23:16 DEBUG[9996]: chan_sip.c:1379 __sip_ack: Acked pending invite 103 Aug 9 09:23:16 DEBUG[9996]: chan_sip.c:1390 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #54 Aug 9 09:23:16 DEBUG[9996]: chan_sip.c:1401 __sip_ack: Stopping retransmission on '139264295@1.1.1.10' of Request 103: Match Found Aug 9 09:23:16 DEBUG[9996]: chan_sip.c:9576 handle_response_invite: SIP response 200 to RE-invite on outgoing call 139264295@1.1.1.10 Found RTP audio format 8 Found RTP audio format 101 Peer audio RTP is at port 1.1.1.10:16386 Aug 9 09:23:16 DEBUG[9996]: chan_sip.c:3598 process_sdp: Peer audio RTP is at port 1.1.1.10:16386 Peer video RTP is at port 1.1.1.10:65535 Aug 9 09:23:16 DEBUG[9996]: chan_sip.c:3622 process_sdp: Peer video RTP is at port 1.1.1.10:65535 Found description format PCMA Found description format telephone-event Capabilities: us - 0xa (gsm|alaw), peer - audio=0x8 (alaw)/video=0x0 (nothing), combined - 0x8 (alaw) Non-codec capabilities: us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) Aug 9 09:23:16 DEBUG[9996]: chan_sip.c:6074 build_route: build_route: Retaining previous route: set_destination: Parsing for address/port to send to set_destination: set destination to 1.1.1.10, port 5060 Transmitting (NAT) to 1.1.1.10:5060: ACK sip:6003@1.1.1.10:5060;user=phone;transport=udp SIP/2.0 Via: SIP/2.0/UDP 10.1.2.10:5060;branch=z9hG4bK131e937f;rport From: ;tag=as1d6b437e To: 6003-steve ;tag=3764155442 Contact: Call-ID: 139264295@1.1.1.10 CSeq: 103 ACK User-Agent: tull.ch PBX Max-Forwards: 70 Content-Length: 0 --- unnamedplayer*CLI> <-- SIP read from 172.16.8.125:7120: Aug 9 09:23:17 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 0: (0) --- (0 headers 0 lines) Nat keepalive --- unnamedplayer*CLI> <-- SIP read from 172.16.8.125:7120: Aug 9 09:23:26 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 0: (0) --- (0 headers 0 lines) Nat keepalive --- unnamedplayer*CLI> <-- SIP read from 172.16.8.125:7120: Aug 9 09:23:35 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 0: (0) --- (0 headers 0 lines) Nat keepalive --- unnamedplayer*CLI> <-- SIP read from 172.16.8.125:7120: Aug 9 09:23:44 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 0: (0) --- (0 headers 0 lines) Nat keepalive --- unnamedplayer*CLI> <-- SIP read from 1.1.1.10:5060: BYE sip:1601@10.1.2.10 SIP/2.0 Via: SIP/2.0/UDP 1.1.1.10:5060;branch=z9hG4bK8f8820d050515d66 From: 6003-steve ;tag=3764155442 To: ;tag=as1d6b437e Call-ID: 139264295@1.1.1.10 CSeq: 3 BYE User-Agent: Cisco ATA 188 v3.2.1 atasip (050616A) Proxy-Authorization: Digest username="6003",realm="tull.ch",nonce="20cf7ca1",uri="sip:1601@10.1.2.10",response="46b1a95618a7c5cb3884d6301037997f" Content-Length: 0 Aug 9 09:23:44 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 0: BYE sip:1601@10.1.2.10 SIP/2.0 (37) Aug 9 09:23:44 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 1: Via: SIP/2.0/UDP 1.1.1.10:5060;branch=z9hG4bK8f8820d050515d66 (64) Aug 9 09:23:44 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 2: From: 6003-steve ;tag=3764155442 (69) Aug 9 09:23:44 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 3: To: ;tag=as1d6b437e (57) Aug 9 09:23:44 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 4: Call-ID: 139264295@1.1.1.10 (30) Aug 9 09:23:44 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 5: CSeq: 3 BYE (11) Aug 9 09:23:44 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 6: User-Agent: Cisco ATA 188 v3.2.1 atasip (050616A) (50) Aug 9 09:23:44 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 7: Proxy-Authorization: Digest username="6003",realm="tull.ch",nonce="20cf7ca1",uri="sip:1601@10.1.2.10",response="46b1a95618a7c5cb3884d6301037997f" (157) Aug 9 09:23:44 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 8: Content-Length: 0 (17) Aug 9 09:23:44 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 9: (0) --- (9 headers 0 lines)--- Aug 9 09:23:44 DEBUG[9996]: chan_sip.c:11139 handle_request: **** Received BYE (8) - Command in SIP BYE Sending to 1.1.1.10 : 5060 (NAT) Transmitting (NAT) to 1.1.1.10:5060: SIP/2.0 200 OK Via: SIP/2.0/UDP 1.1.1.10:5060;branch=z9hG4bK8f8820d050515d66;received=1.1.1.10 From: 6003-steve ;tag=3764155442 To: ;tag=as1d6b437e Call-ID: 139264295@1.1.1.10 CSeq: 3 BYE User-Agent: tull.ch PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Contact: Content-Length: 0 X-Asterisk-HangupCause: Normal Clearing unnamedplayer*CLI> --- Aug 9 09:23:44 DEBUG[10179]: rtp.c:1712 ast_rtp_bridge: Oooh, got a hangup Aug 9 09:23:44 DEBUG[10179]: channel.c:3522 ast_channel_bridge: Returning from native bridge, channels: SIP/6003-08171e30, SIP/10.110.30.10-0817b740 Aug 9 09:23:44 DEBUG[10179]: channel.c:1336 ast_hangup: Hanging up channel 'SIP/10.110.30.10-0817b740' Aug 9 09:23:44 DEBUG[10179]: chan_sip.c:2415 sip_hangup: Hangup call SIP/10.110.30.10-0817b740, SIP callid 093e8fec7af28f8d3e5ab4cb24771e72@10.1.2.10) Aug 9 09:23:44 DEBUG[10179]: chan_sip.c:2423 sip_hangup: update_call_counter(1601) - decrement call limit counter Aug 9 09:23:44 DEBUG[10179]: chan_sip.c:2206 update_call_counter: Updating call counter for incoming call set_destination: Parsing for address/port to send to set_destination: set destination to 10.110.30.10, port 5060 Reliably Transmitting (no NAT) to 10.110.30.10:5060: BYE sip:1601@10.110.30.10:5060;transport=udp SIP/2.0 Via: SIP/2.0/UDP 10.1.2.10:5060;branch=z9hG4bK59fc85f6;rport From: "MeanFaxMachine" ;tag=as0af0b132 To: ;tag=1937808815 Contact: Call-ID: 093e8fec7af28f8d3e5ab4cb24771e72@10.1.2.10 CSeq: 104 BYE User-Agent: tull.ch PBX Max-Forwards: 70 Content-Length: 0 --- Aug 9 09:23:44 DEBUG[10179]: chan_sip.c:1293 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #55 Aug 9 09:23:44 DEBUG[10179]: app_dial.c:1628 dial_exec_full: Exiting with DIALSTATUS=ANSWER. Aug 9 09:23:44 DEBUG[10179]: pbx.c:2316 __ast_pbx_run: Spawn extension (privileged,1601,1) exited non-zero on 'SIP/6003-08171e30' Aug 9 09:23:44 DEBUG[9981]: chan_sip.c:11670 sip_devicestate: Checking device state for peer 10.110.30.10 Aug 9 09:23:44 DEBUG[9981]: devicestate.c:187 do_state_change: Changing state for SIP/10.110.30.10 - state 1 (Not in use) Aug 9 09:23:44 DEBUG[10179]: cdr_addon_mysql.c:206 mysql_log: cdr_mysql: inserting a CDR record. Aug 9 09:23:44 DEBUG[10179]: cdr_addon_mysql.c:222 mysql_log: cdr_mysql: SQL command as follows: INSERT INTO cdr (calldate,clid,src,dst,dcontext,channel,dstchannel,lastapp,lastdata,duration,billsec,disposition,amaflags,accountcode) VALUES ('2006-08-09 09:23:00','\"MeanFaxMachine\" <06003>','06003','1601','privileged', 'SIP/6003-08171e30','SIP/10.110.30.10-0817b740','Dial','SIP/1601@10.110.30.10',44,37,'ANSWERED',3,'') Aug 9 09:23:44 DEBUG[10264]: app_queue.c:490 changethread: Device 'SIP/10.110.30.10' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. Aug 9 09:23:44 DEBUG[10179]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '"MeanFaxMachine" <06003>' Aug 9 09:23:44 DEBUG[10179]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '06003' Aug 9 09:23:44 DEBUG[10179]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '1601' Aug 9 09:23:44 DEBUG[10179]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is 'privileged' Aug 9 09:23:44 DEBUG[10179]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is 'SIP/6003-08171e30' Aug 9 09:23:44 DEBUG[10179]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is 'SIP/10.110.30.10-0817b740' Aug 9 09:23:44 DEBUG[10179]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is 'Dial' Aug 9 09:23:44 DEBUG[10179]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is 'SIP/1601@10.110.30.10' Aug 9 09:23:44 DEBUG[10179]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '2006-08-09 09:23:00' Aug 9 09:23:44 DEBUG[10179]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '2006-08-09 09:23:07' Aug 9 09:23:44 DEBUG[10179]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '2006-08-09 09:23:44' Aug 9 09:23:44 DEBUG[10179]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '44' Aug 9 09:23:44 DEBUG[10179]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '37' Aug 9 09:23:44 DEBUG[10179]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is 'ANSWERED' Aug 9 09:23:44 DEBUG[10179]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is 'DOCUMENTATION' Aug 9 09:23:44 DEBUG[10179]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '(null)' Aug 9 09:23:44 DEBUG[10179]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '1155108180.0' Aug 9 09:23:44 DEBUG[10179]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '(null)' Aug 9 09:23:44 DEBUG[10179]: channel.c:1336 ast_hangup: Hanging up channel 'SIP/6003-08171e30' Aug 9 09:23:44 DEBUG[10179]: chan_sip.c:2415 sip_hangup: Hangup call SIP/6003-08171e30, SIP callid 139264295@1.1.1.10) Aug 9 09:23:44 DEBUG[10179]: chan_sip.c:2423 sip_hangup: update_call_counter(6003) - decrement call limit counter Aug 9 09:23:44 DEBUG[10179]: chan_sip.c:2206 update_call_counter: Updating call counter for outgoing call Aug 9 09:23:44 DEBUG[9981]: chan_sip.c:11670 sip_devicestate: Checking device state for peer 6003 Aug 9 09:23:44 DEBUG[9981]: devicestate.c:187 do_state_change: Changing state for SIP/6003 - state 1 (Not in use) Aug 9 09:23:44 DEBUG[9981]: chan_sip.c:11670 sip_devicestate: Checking device state for peer 6003 Aug 9 09:23:44 DEBUG[10265]: app_queue.c:490 changethread: Device 'SIP/6003' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. unnamedplayer*CLI> <-- SIP read from 10.110.30.10:5060: SIP/2.0 200 Ok Via: SIP/2.0/UDP 10.1.2.10:5060;received=10.1.2.10;branch=z9hG4bK59fc85f6;rport=5060 From: "MeanFaxMachine" ;tag=as0af0b132 To: ;tag=1937808815 Call-ID: 093e8fec7af28f8d3e5ab4cb24771e72@10.1.2.10 CSeq: 104 BYE Content-Length: 0 Aug 9 09:23:44 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 0: SIP/2.0 200 Ok (14) Aug 9 09:23:44 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 1: Via: SIP/2.0/UDP 10.1.2.10:5060;received=10.1.2.10;branch=z9hG4bK59fc85f6;rport=5060 (86) Aug 9 09:23:44 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 2: From: "MeanFaxMachine" ;tag=as0af0b132 (65) Aug 9 09:23:44 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 3: To: ;tag=1937808815 (46) Aug 9 09:23:44 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 4: Call-ID: 093e8fec7af28f8d3e5ab4cb24771e72@10.1.2.10 (52) Aug 9 09:23:44 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 5: CSeq: 104 BYE (13) Aug 9 09:23:44 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 6: Content-Length: 0 (17) Aug 9 09:23:44 DEBUG[9996]: chan_sip.c:3357 parse_request: Header 7: (0) --- (7 headers 0 lines)--- Aug 9 09:23:44 DEBUG[9996]: chan_sip.c:1390 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #55 Aug 9 09:23:44 DEBUG[9996]: chan_sip.c:1401 __sip_ack: Stopping retransmission on '093e8fec7af28f8d3e5ab4cb24771e72@10.1.2.10' of Request 104: Match Found Destroying call '093e8fec7af28f8d3e5ab4cb24771e72@10.1.2.10' Destroying call '139264295@1.1.1.10' unnamedplayer*CLI> <-- SIP read from 172.16.8.125:7120: