anarki ~ # asterisk -r Asterisk 1.4.2, Copyright (C) 1999 - 2006 Digium, Inc. and others. Created by Mark Spencer Asterisk comes with ABSOLUTELY NO WARRANTY; type 'core 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 'core show license' for details. ========================================================================= Connected to Asterisk 1.4.2 currently running on anarki (pid = 2707) Verbosity is at least 5 anarki*CLI> core set verbose 5 Verbosity is at least 5 [Mar 29 13:05:20] DEBUG[2735]: chan_sip.c:14817 sipsock_read: Invalid SIP message - rejected , no callid, len 328 [Mar 29 13:05:20] DEBUG[2735]: chan_sip.c:14817 sipsock_read: Invalid SIP message - rejected , no callid, len 328 anarki*CLI> core set debug 5 Core debug is at least 5 anarki*CLI> s save say send set show sip skinny sla soft stop stun [Mar 29 13:05:35] DEBUG[2735]: chan_sip.c:14817 sipsock_read: Invalid SIP message - rejected , no callid, len 328 [Mar 29 13:05:35] DEBUG[2735]: chan_sip.c:14817 sipsock_read: Invalid SIP message - rejected , no callid, len 328 anarki*CLI> sip debug history no notify prune reload set show anarki*CLI> sip debug SIP Debugging enabled anarki*CLI> <--- SIP read from 10.10.10.23:5060 ---> NOTIFY sip:172.16.0.25 SIP/2.0 Via: SIP/2.0/UDP 10.10.10.23:5060;branch=z9hG4bK-2d1ee43a From: alx ;tag=82a91f60f0afa1ado0 To: Call-ID: edc685a6-17ad004d@10.10.10.23 CSeq: 273 NOTIFY Max-Forwards: 70 Event: keep-alive User-Agent: Linksys/SPA2102-3.3.6 Content-Length: 0 <-------------> [Mar 29 13:05:50] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 0: NOTIFY sip:172.16.0.25 SIP/2.0 (29) [Mar 29 13:05:50] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 1: Via: SIP/2.0/UDP 10.10.10.23:5060;branch=z9hG4bK-2d1ee43a (59) [Mar 29 13:05:50] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 2: From: alx ;tag=82a91f60f0afa1ado0 (59) [Mar 29 13:05:50] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 3: To: (20) [Mar 29 13:05:50] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 4: Call-ID: edc685a6-17ad004d@10.10.10.23 (40) [Mar 29 13:05:50] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 5: CSeq: 273 NOTIFY (16) [Mar 29 13:05:50] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 6: Max-Forwards: 70 (16) [Mar 29 13:05:50] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 7: Event: keep-alive (17) [Mar 29 13:05:50] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 8: User-Agent: Linksys/SPA2102-3.3.6 (33) [Mar 29 13:05:50] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 9: Content-Length: 0 (17) [Mar 29 13:05:50] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 10: (0) --- (10 headers 0 lines) --- <--- Transmitting (no NAT) to 10.10.10.23:5060 ---> SIP/2.0 489 Bad event Via: SIP/2.0/UDP 10.10.10.23:5060;branch=z9hG4bK-2d1ee43a;received=10.10.10.23 From: alx ;tag=82a91f60f0afa1ado0 To: ;tag=as3f85dfa4 Call-ID: edc685a6-17ad004d@10.10.10.23 CSeq: 273 NOTIFY User-Agent: blabla.ch 1.4PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Content-Length: 0 <------------> [Mar 29 13:05:50] DEBUG[2735]: chan_sip.c:14817 sipsock_read: Invalid SIP message - rejected , no callid, len 328 anarki*CLI> <--- SIP read from 10.10.10.23:5061 ---> NOTIFY sip:172.16.0.25 SIP/2.0 Via: SIP/2.0/UDP 10.10.10.23:5061;branch=z9hG4bK-413a54cf From: fax ;tag=d2bd39c8aad00a65o1 To: Call-ID: 3258edd2-a37bd611@10.10.10.23 CSeq: 273 NOTIFY Max-Forwards: 70 Event: keep-alive User-Agent: Linksys/SPA2102-3.3.6 Content-Length: 0 <-------------> [Mar 29 13:05:50] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 0: NOTIFY sip:172.16.0.25 SIP/2.0 (29) [Mar 29 13:05:50] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 1: Via: SIP/2.0/UDP 10.10.10.23:5061;branch=z9hG4bK-413a54cf (59) [Mar 29 13:05:50] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 2: From: fax ;tag=d2bd39c8aad00a65o1 (59) [Mar 29 13:05:50] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 3: To: (20) [Mar 29 13:05:50] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 4: Call-ID: 3258edd2-a37bd611@10.10.10.23 (40) [Mar 29 13:05:50] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 5: CSeq: 273 NOTIFY (16) [Mar 29 13:05:50] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 6: Max-Forwards: 70 (16) [Mar 29 13:05:50] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 7: Event: keep-alive (17) [Mar 29 13:05:50] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 8: User-Agent: Linksys/SPA2102-3.3.6 (33) [Mar 29 13:05:50] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 9: Content-Length: 0 (17) [Mar 29 13:05:50] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 10: (0) --- (10 headers 0 lines) --- <--- Transmitting (no NAT) to 10.10.10.23:5061 ---> SIP/2.0 489 Bad event Via: SIP/2.0/UDP 10.10.10.23:5061;branch=z9hG4bK-413a54cf;received=10.10.10.23 From: fax ;tag=d2bd39c8aad00a65o1 To: ;tag=as7539a554 Call-ID: 3258edd2-a37bd611@10.10.10.23 CSeq: 273 NOTIFY User-Agent: blabla.ch 1.4PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Content-Length: 0 <------------> [Mar 29 13:05:50] DEBUG[2735]: chan_sip.c:14817 sipsock_read: Invalid SIP message - rejected , no callid, len 328 anarki*CLI> <--- SIP read from 10.10.10.23:5060 ---> NOTIFY sip:172.16.0.25 SIP/2.0 Via: SIP/2.0/UDP 10.10.10.23:5060;branch=z9hG4bK-f9351b1c From: alx ;tag=82a91f60f0afa1ado0 To: Call-ID: edc685a6-17ad004d@10.10.10.23 CSeq: 274 NOTIFY Max-Forwards: 70 Event: keep-alive User-Agent: Linksys/SPA2102-3.3.6 Content-Length: 0 <-------------> [Mar 29 13:06:05] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 0: NOTIFY sip:172.16.0.25 SIP/2.0 (29) [Mar 29 13:06:05] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 1: Via: SIP/2.0/UDP 10.10.10.23:5060;branch=z9hG4bK-f9351b1c (59) [Mar 29 13:06:05] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 2: From: alx ;tag=82a91f60f0afa1ado0 (59) [Mar 29 13:06:05] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 3: To: (20) [Mar 29 13:06:05] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 4: Call-ID: edc685a6-17ad004d@10.10.10.23 (40) [Mar 29 13:06:05] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 5: CSeq: 274 NOTIFY (16) [Mar 29 13:06:05] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 6: Max-Forwards: 70 (16) [Mar 29 13:06:05] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 7: Event: keep-alive (17) [Mar 29 13:06:05] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 8: User-Agent: Linksys/SPA2102-3.3.6 (33) [Mar 29 13:06:05] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 9: Content-Length: 0 (17) [Mar 29 13:06:05] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 10: (0) --- (10 headers 0 lines) --- <--- Transmitting (no NAT) to 10.10.10.23:5060 ---> SIP/2.0 489 Bad event Via: SIP/2.0/UDP 10.10.10.23:5060;branch=z9hG4bK-f9351b1c;received=10.10.10.23 From: alx ;tag=82a91f60f0afa1ado0 To: ;tag=as2b9c2fd2 Call-ID: edc685a6-17ad004d@10.10.10.23 CSeq: 274 NOTIFY User-Agent: blabla.ch 1.4PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces ontent-Length: 0 <------------> [Mar 29 13:06:05] DEBUG[2735]: chan_sip.c:14817 sipsock_read: Invalid SIP message - rejected , no callid, len 328 anarki*CLI> <--- SIP read from 10.10.10.23:5061 ---> NOTIFY sip:172.16.0.25 SIP/2.0 Via: SIP/2.0/UDP 10.10.10.23:5061;branch=z9hG4bK-63a5c133 From: fax ;tag=d2bd39c8aad00a65o1 To: Call-ID: 3258edd2-a37bd611@10.10.10.23 CSeq: 274 NOTIFY Max-Forwards: 70 Event: keep-alive User-Agent: Linksys/SPA2102-3.3.6 Content-Length: 0 <-------------> [Mar 29 13:06:05] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 0: NOTIFY sip:172.16.0.25 SIP/2.0 (29) [Mar 29 13:06:05] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 1: Via: SIP/2.0/UDP 10.10.10.23:5061;branch=z9hG4bK-63a5c133 (59) [Mar 29 13:06:05] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 2: From: fax ;tag=d2bd39c8aad00a65o1 (59) [Mar 29 13:06:05] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 3: To: (20) [Mar 29 13:06:05] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 4: Call-ID: 3258edd2-a37bd611@10.10.10.23 (40) [Mar 29 13:06:05] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 5: CSeq: 274 NOTIFY (16) [Mar 29 13:06:05] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 6: Max-Forwards: 70 (16) [Mar 29 13:06:05] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 7: Event: keep-alive (17) [Mar 29 13:06:05] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 8: User-Agent: Linksys/SPA2102-3.3.6 (33) [Mar 29 13:06:05] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 9: Content-Length: 0 (17) [Mar 29 13:06:05] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 10: (0) --- (10 headers 0 lines) --- anarki*CLI> <--- Transmitting (no NAT) to 10.10.10.23:5061 ---> SIP/2.0 489 Bad event Via: SIP/2.0/UDP 10.10.10.23:5061;branch=z9hG4bK-63a5c133;received=10.10.10.23 From: fax ;tag=d2bd39c8aad00a65o1 To: ;tag=as3a27ed31 Call-ID: 3258edd2-a37bd611@10.10.10.23 CSeq: 274 NOTIFY User-Agent: blabla.ch 1.4PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Content-Length: 0 <------------> [Mar 29 13:06:05] DEBUG[2735]: chan_sip.c:14817 sipsock_read: Invalid SIP message - rejected , no callid, len 328 anarki*CLI> <--- SIP read from 10.10.10.23:5061 ---> INVITE sip:0435401601@172.16.0.25 SIP/2.0 Via: SIP/2.0/UDP 10.10.10.23:5061;branch=z9hG4bK-bfd7a813 From: fax ;tag=61ce66b1d4446863o1 To: Remote-Party-ID: fax ;screen=yes;party=calling Call-ID: 84a4e749-194220ab@10.10.10.23 CSeq: 101 INVITE Max-Forwards: 70 Contact: fax Expires: 240 User-Agent: Linksys/SPA2102-3.3.6 Content-Length: 444 Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER Supported: x-sipura Content-Type: application/sdp v=0 o=- 414945 414945 IN IP4 10.10.10.23 s=- c=IN IP4 10.10.10.23 t=0 0 m=audio 16464 RTP/AVP 8 0 2 4 18 96 97 98 100 101 a=rtpmap:8 PCMA/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:2 G726-32/8000 a=rtpmap:4 G723/8000 a=rtpmap:18 G729a/8000 a=rtpmap:96 G726-40/8000 a=rtpmap:97 G726-24/8000 a=rtpmap:98 G726-16/8000 a=rtpmap:100 NSE/8000 a=fmtp:100 192-193 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=ptime:30 a=sendrecv <-------------> [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 0: INVITE sip:0435401601@172.16.0.25 SIP/2.0 (40) [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 1: Via: SIP/2.0/UDP 10.10.10.23:5061;branch=z9hG4bK-bfd7a813 (59) [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 2: From: fax ;tag=61ce66b1d4446863o1 (59) [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 3: To: (31) [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 4: Remote-Party-ID: fax ;screen=yes;party=calling (72) [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 5: Call-ID: 84a4e749-194220ab@10.10.10.23 (40) [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 6: CSeq: 101 INVITE (16) [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 7: Max-Forwards: 70 (16) [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 8: Contact: fax (47) [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 9: Expires: 240 (12) [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 10: User-Agent: Linksys/SPA2102-3.3.6 (33) [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 11: Content-Length: 444 (19) [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 12: Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER (61) [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 13: Supported: x-sipura (19) [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 14: Content-Type: application/sdp (29) [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 15: (0) [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: v=0 (3) [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: o=- 414945 414945 IN IP4 10.10.10.23 (38) [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: s=- (3) [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: c=IN IP4 10.10.10.23 (22) [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: t=0 0 (5) [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: m=audio 16464 RTP/AVP 8 0 2 4 18 96 97 98 100 101 (49) [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: a=rtpmap:8 PCMA/8000 (20) [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: a=rtpmap:0 PCMU/8000 (20) [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: a=rtpmap:2 G726-32/8000 (23) [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: a=rtpmap:4 G723/8000 (20) [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: a=rtpmap:18 G729a/8000 (22) [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: a=rtpmap:96 G726-40/8000 (24) [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: a=rtpmap:97 G726-24/8000 (24) [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: a=rtpmap:98 G726-16/8000 (24) [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: a=rtpmap:100 NSE/8000 (21) [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: a=fmtp:100 192-193 (18) [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: a=fmtp:101 0-15 (15) [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: a=ptime:30 (10) [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: a=sendrecv (10) --- (15 headers 20 lines) --- [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:2575 do_setnat: Setting NAT on RTP to Off [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:2580 do_setnat: Setting NAT on VRTP to Off [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:2585 do_setnat: Setting NAT on UDPTL to Off [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:4310 sip_alloc: Allocating new SIP dialog for 84a4e749-194220ab@10.10.10.23 - INVITE (With RTP) [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:14633 handle_request: **** Received INVITE (5) - Command in SIP INVITE [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:1680 parse_sip_options: Begin: parsing SIP "Supported: x-sipura" [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:1688 parse_sip_options: Found SIP option: -x-sipura- [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:1700 parse_sip_options: Found private SIP option, not supported: x-sipura Sending to 10.10.10.23 : 5061 (no NAT) Using INVITE request as basis request - 84a4e749-194220ab@10.10.10.23 [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:2575 do_setnat: Setting NAT on RTP to On [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:2580 do_setnat: Setting NAT on VRTP to On [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:2585 do_setnat: Setting NAT on UDPTL to On <--- Reliably Transmitting (NAT) to 10.10.10.23:5061 ---> SIP/2.0 407 Proxy Authentication Required Via: SIP/2.0/UDP 10.10.10.23:5061;branch=z9hG4bK-bfd7a813;received=10.10.10.23 From: fax ;tag=61ce66b1d4446863o1 To: ;tag=as0e31f11b Call-ID: 84a4e749-194220ab@10.10.10.23 CSeq: 101 INVITE User-Agent: blabla.ch 1.4PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Proxy-Authenticate: Digest algorithm=MD5, realm="blabla.ch", nonce="79788763" Content-Length: 0 <------------> [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:1975 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #1290 Scheduling destruction of SIP dialog '84a4e749-194220ab@10.10.10.23' in 32000 ms (Method: INVITE) Found user '12345011' anarki*CLI> <--- SIP read from 10.10.10.23:5061 ---> ACK sip:0435401601@172.16.0.25 SIP/2.0 Via: SIP/2.0/UDP 10.10.10.23:5061;branch=z9hG4bK-bfd7a813 From: fax ;tag=61ce66b1d4446863o1 To: ;tag=as0e31f11b Call-ID: 84a4e749-194220ab@10.10.10.23 CSeq: 101 ACK Max-Forwards: 70 Contact: fax User-Agent: Linksys/SPA2102-3.3.6 Content-Length: 0 <-------------> [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 0: ACK sip:0435401601@172.16.0.25 SIP/2.0 (37) [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 1: Via: SIP/2.0/UDP 10.10.10.23:5061;branch=z9hG4bK-bfd7a813 (59) [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 2: From: fax ;tag=61ce66b1d4446863o1 (59) [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 3: To: ;tag=as0e31f11b (46) [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 4: Call-ID: 84a4e749-194220ab@10.10.10.23 (40) [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 5: CSeq: 101 ACK (13) [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 6: Max-Forwards: 70 (16) [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 7: Contact: fax (47) [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 8: User-Agent: Linksys/SPA2102-3.3.6 (33) [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 9: Content-Length: 0 (17) [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 10: (0) --- (10 headers 0 lines) --- [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:4361 find_call: = Found Their Call ID: 84a4e749-194220ab@10.10.10.23 Their Tag 61ce66b1d4446863o1 Our tag: as0e31f11b [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:14633 handle_request: **** Received ACK (6) - Command in SIP ACK [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:2079 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #1290 [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:2089 __sip_ack: Stopping retransmission on '84a4e749-194220ab@10.10.10.23' of Response 101: Match Not Found anarki*CLI> <--- SIP read from 10.10.10.23:5061 ---> INVITE sip:0435401601@172.16.0.25 SIP/2.0 Via: SIP/2.0/UDP 10.10.10.23:5061;branch=z9hG4bK-977813e7 From: fax ;tag=61ce66b1d4446863o1 To: Remote-Party-ID: fax ;screen=yes;party=calling Call-ID: 84a4e749-194220ab@10.10.10.23 CSeq: 102 INVITE Max-Forwards: 70 Proxy-Authorization: Digest username="12345011",realm="blabla.ch",nonce="79788763",uri="sip:0435401601@172.16.0.25",algorithm=MD5,response="f05d6cbded769f921ab620f4cc1b795d" Contact: fax Expires: 240 User-Agent: Linksys/SPA2102-3.3.6 Content-Length: 444 Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER Supported: x-sipura Content-Type: application/sdp v=0 o=- 414945 414945 IN IP4 10.10.10.23 s=- c=IN IP4 10.10.10.23 t=0 0 m=audio 16464 RTP/AVP 8 0 2 4 18 96 97 98 100 101 a=rtpmap:8 PCMA/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:2 G726-32/8000 a=rtpmap:4 G723/8000 a=rtpmap:18 G729a/8000 a=rtpmap:96 G726-40/8000 a=rtpmap:97 G726-24/8000 a=rtpmap:98 G726-16/8000 a=rtpmap:100 NSE/8000 a=fmtp:100 192-193 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=ptime:30 a=sendrecv <-------------> [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 0: INVITE sip:0435401601@172.16.0.25 SIP/2.0 (40) [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 1: Via: SIP/2.0/UDP 10.10.10.23:5061;branch=z9hG4bK-977813e7 (59) [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 2: From: fax ;tag=61ce66b1d4446863o1 (59) [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 3: To: (31) [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 4: Remote-Party-ID: fax ;screen=yes;party=calling (72) [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 5: Call-ID: 84a4e749-194220ab@10.10.10.23 (40) [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 6: CSeq: 102 INVITE (16) [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 7: Max-Forwards: 70 (16) [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 8: Proxy-Authorization: Digest username="12345011",realm="blabla.ch",nonce="79788763",uri="sip:0435401601@172.16.0.25",algorithm=MD5,response="f05d6cbded769f921ab620f4cc1b795d" (171) [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 9: Contact: fax (47) [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 10: Expires: 240 (12) [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 11: User-Agent: Linksys/SPA2102-3.3.6 (33) [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 12: Content-Length: 444 (19) [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 13: Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER (61) [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 14: Supported: x-sipura (19) [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 15: Content-Type: application/sdp (29) [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 16: (0) [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: v=0 (3) [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: o=- 414945 414945 IN IP4 10.10.10.23 (38) [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: s=- (3) [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: c=IN IP4 10.10.10.23 (22) [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: t=0 0 (5) [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: m=audio 16464 RTP/AVP 8 0 2 4 18 96 97 98 100 101 (49) [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: a=rtpmap:8 PCMA/8000 (20) [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: a=rtpmap:0 PCMU/8000 (20) [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: a=rtpmap:2 G726-32/8000 (23) [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: a=rtpmap:4 G723/8000 (20) [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: a=rtpmap:18 G729a/8000 (22) [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: a=rtpmap:96 G726-40/8000 (24) [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: a=rtpmap:97 G726-24/8000 (24) [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: a=rtpmap:98 G726-16/8000 (24) [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: a=rtpmap:100 NSE/8000 (21) [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: a=fmtp:100 192-193 (18) [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: a=fmtp:101 0-15 (15) [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: a=ptime:30 (10) [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: a=sendrecv (10) --- (16 headers 20 lines) --- [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:4361 find_call: = Found Their Call ID: 84a4e749-194220ab@10.10.10.23 Their Tag 61ce66b1d4446863o1 Our tag: as0e31f11b [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:14633 handle_request: **** Received INVITE (5) - Command in SIP INVITE [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:1680 parse_sip_options: Begin: parsing SIP "Supported: x-sipura" [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:1688 parse_sip_options: Found SIP option: -x-sipura- [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:1700 parse_sip_options: Found private SIP option, not supported: x-sipura Sending to 10.10.10.23 : 5061 (NAT) Using INVITE request as basis request - 84a4e749-194220ab@10.10.10.23 [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:2575 do_setnat: Setting NAT on RTP to On [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:2580 do_setnat: Setting NAT on VRTP to On [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:2585 do_setnat: Setting NAT on UDPTL to On Found user '12345011' Found RTP audio format 8 Found RTP audio format 0 Found RTP audio format 2 Found RTP audio format 4 Found RTP audio format 18 Found RTP audio format 96 Found RTP audio format 97 Found RTP audio format 98 Found RTP audio format 100 Found RTP audio format 101 [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:4899 process_sdp: Peer doesn't provide T.38 UDPTL Peer audio RTP is at port 10.10.10.23:16464 Found description format PCMA for ID 8 Found description format PCMU for ID 0 Found description format G726-32 for ID 2 Found description format G723 for ID 4 Found description format G729a for ID 18 Found description format G726-40 for ID 96 Found description format G726-24 for ID 97 Found description format G726-16 for ID 98 Found description format NSE for ID 100 Got unsupported a:fmtp in SDP offer Found description format telephone-event for ID 101 Got unsupported a:fmtp in SDP offer [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:5129 process_sdp: T38 state changed to 0 on channel Capabilities: us - 0xa (gsm|alaw), peer - audio=0xd0d (g723|ulaw|alaw|g726|g729|ilbc)/video=0x0 (nothing), combined - 0x8 (alaw) Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) Peer audio RTP is at port 10.10.10.23:16464 [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:5209 process_sdp: We're settling with these formats: 0x8 (alaw) [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:13401 handle_request_invite: Checking SIP call limits for device 12345011 [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:3003 update_call_counter: Updating call counter for incoming call Looking for 0435401601 in privileged-prod (domain 172.16.0.25) [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:3805 sip_new: *** Our native formats are 0x8 (alaw) [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:3806 sip_new: *** Joint capabilities are 0x8 (alaw) [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:3807 sip_new: *** Our capabilities are 0xa (gsm|alaw) [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:3808 sip_new: *** AST_CODEC_CHOOSE formats are 0x8 (alaw) [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:3831 sip_new: This channel will not be able to handle video. [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:7980 build_route: build_route: Contact hop: fax list_route: hop: [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:13476 handle_request_invite: SIP/12345011-081d1618: New call is still down.... Trying... <--- Transmitting (NAT) to 10.10.10.23:5061 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 10.10.10.23:5061;branch=z9hG4bK-977813e7;received=10.10.10.23 From: fax ;tag=61ce66b1d4446863o1 To: Call-ID: 84a4e749-194220ab@10.10.10.23 CSeq: 102 INVITE User-Agent: blabla.ch 1.4PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Length: 0 <------------> [Mar 29 13:06:20] DEBUG[2735]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/12345011-081d1618 [Mar 29 13:06:20] DEBUG[2711]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 12345011 [Mar 29 13:06:20] DEBUG[14946]: pbx.c:1795 pbx_extension_helper: Launching 'Dial' [Mar 29 13:06:20] DEBUG[2711]: chan_sip.c:15244 sip_devicestate: Checking device state for peer 12345011 [Mar 29 13:06:20] DEBUG[2711]: devicestate.c:287 do_state_change: Changing state for SIP/12345011 - state 1 (Not in use) [Mar 29 13:06:20] DEBUG[2711]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 12345011 [Mar 29 13:06:20] DEBUG[2711]: chan_sip.c:15244 sip_devicestate: Checking device state for peer 12345011 [Mar 29 13:06:20] DEBUG[14947]: app_queue.c:546 changethread: Device 'SIP/12345011' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. -- Executing [0435401601@privileged-prod:1] Dial("SIP/12345011-081d1618", "SIP/0435401601@172.16.0.20") in new stack [Mar 29 13:06:20] DEBUG[14946]: chan_sip.c:15310 sip_request_call: Asked to create a SIP channel with formats: 0x8 (alaw) [Mar 29 13:06:20] DEBUG[14946]: chan_sip.c:4310 sip_alloc: Allocating new SIP dialog for (No Call-ID) - INVITE (With RTP) [Mar 29 13:06:20] DEBUG[14946]: chan_sip.c:3805 sip_new: *** Our native formats are 0x8 (alaw) [Mar 29 13:06:20] DEBUG[14946]: chan_sip.c:3806 sip_new: *** Joint capabilities are 0x0 (nothing) [Mar 29 13:06:20] DEBUG[14946]: chan_sip.c:3807 sip_new: *** Our capabilities are 0x40a (gsm|alaw|ilbc) [Mar 29 13:06:20] DEBUG[14946]: chan_sip.c:3808 sip_new: *** AST_CODEC_CHOOSE formats are 0x8 (alaw) [Mar 29 13:06:20] DEBUG[14946]: chan_sip.c:3810 sip_new: *** Our preferred formats from the incoming channel are 0x8 (alaw) [Mar 29 13:06:20] DEBUG[14946]: chan_sip.c:3831 sip_new: This channel will not be able to handle video. [Mar 29 13:06:20] DEBUG[14946]: rtp.c:1598 ast_rtp_make_compatible: Seeded SDP of 'SIP/172.16.0.20-081d5580' with that of 'SIP/12345011-081d1618' [Mar 29 13:06:20] DEBUG[14946]: channel.c:3301 ast_channel_inherit_variables: Not copying variable STACK-privileged-prod-0435401601-1. [Mar 29 13:06:20] DEBUG[14946]: channel.c:3301 ast_channel_inherit_variables: Not copying variable SIPCALLID. [Mar 29 13:06:20] DEBUG[14946]: channel.c:3301 ast_channel_inherit_variables: Not copying variable SIPUSERAGENT. [Mar 29 13:06:20] DEBUG[14946]: channel.c:3301 ast_channel_inherit_variables: Not copying variable SIPDOMAIN. [Mar 29 13:06:20] DEBUG[14946]: channel.c:3301 ast_channel_inherit_variables: Not copying variable SIPURI. [Mar 29 13:06:20] DEBUG[14946]: chan_sip.c:2830 sip_call: Outgoing Call for 0435401601 [Mar 29 13:06:20] DEBUG[14946]: chan_sip.c:3003 update_call_counter: Updating call counter for outgoing call [Mar 29 13:06:20] DEBUG[14946]: chan_sip.c:2845 sip_call: Our T38 capability (3856), joint T38 capability (3856) [Mar 29 13:06:20] DEBUG[14946]: chan_sip.c:6188 add_sdp: ** Our capability: 0x40a (gsm|alaw|ilbc) Video flag: False [Mar 29 13:06:20] DEBUG[14946]: chan_sip.c:6189 add_sdp: ** Our prefcodec: 0x8 (alaw) Audio is at 172.16.0.25 port 12898 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 [Mar 29 13:06:20] DEBUG[14946]: chan_sip.c:6320 add_sdp: -- Done with adding codecs to SDP [Mar 29 13:06:20] DEBUG[14946]: channel.c:2381 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=36) [Mar 29 13:06:20] DEBUG[14946]: chan_sip.c:6365 add_sdp: Done building SDP. Settling with this capability: 0x40a (gsm|alaw|ilbc) [Mar 29 13:06:20] DEBUG[14946]: chan_sip.c:4573 parse_request: Header 0: INVITE sip:0435401601@172.16.0.20 SIP/2.0 (40) [Mar 29 13:06:20] DEBUG[14946]: chan_sip.c:4573 parse_request: Header 1: Via: SIP/2.0/UDP 172.16.0.25:5060;branch=z9hG4bK16dbae04;rport (61) [Mar 29 13:06:20] DEBUG[14946]: chan_sip.c:4573 parse_request: Header 2: From: "anon" ;tag=as297ba3fa (55) [Mar 29 13:06:20] DEBUG[14946]: chan_sip.c:4573 parse_request: Header 3: To: (31) [Mar 29 13:06:20] DEBUG[14946]: chan_sip.c:4573 parse_request: Header 4: Contact: (36) [Mar 29 13:06:20] DEBUG[14946]: chan_sip.c:4573 parse_request: Header 5: Call-ID: 7059ab55508465502ca3d05a79b1c5da@172.16.0.25 (52) [Mar 29 13:06:20] DEBUG[14946]: chan_sip.c:4573 parse_request: Header 6: CSeq: 102 INVITE (16) [Mar 29 13:06:20] DEBUG[14946]: chan_sip.c:4573 parse_request: Header 7: User-Agent: blabla.ch 1.4PBX (26) [Mar 29 13:06:20] DEBUG[14946]: chan_sip.c:4573 parse_request: Header 8: Max-Forwards: 70 (16) [Mar 29 13:06:20] DEBUG[14946]: chan_sip.c:4573 parse_request: Header 9: Date: Thu, 29 Mar 2007 11:06:20 GMT (35) [Mar 29 13:06:20] DEBUG[14946]: chan_sip.c:4573 parse_request: Header 10: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) [Mar 29 13:06:20] DEBUG[14946]: chan_sip.c:4573 parse_request: Header 11: Supported: replaces (19) [Mar 29 13:06:20] DEBUG[14946]: chan_sip.c:4573 parse_request: Header 12: Content-Type: application/sdp (29) [Mar 29 13:06:20] DEBUG[14946]: chan_sip.c:4573 parse_request: Header 13: Content-Length: 304 (19) [Mar 29 13:06:20] DEBUG[14946]: chan_sip.c:4573 parse_request: Header 14: (0) [Mar 29 13:06:20] DEBUG[14946]: chan_sip.c:4605 parse_request: Line: v=0 (3) [Mar 29 13:06:20] DEBUG[14946]: chan_sip.c:4605 parse_request: Line: o=root 14946 14946 IN IP4 172.16.0.25 (36) [Mar 29 13:06:20] DEBUG[14946]: chan_sip.c:4605 parse_request: Line: s=session (9) [Mar 29 13:06:20] DEBUG[14946]: chan_sip.c:4605 parse_request: Line: c=IN IP4 172.16.0.25 (19) [Mar 29 13:06:20] DEBUG[14946]: chan_sip.c:4605 parse_request: Line: t=0 0 (5) [Mar 29 13:06:20] DEBUG[14946]: chan_sip.c:4605 parse_request: Line: m=audio 12898 RTP/AVP 8 3 97 101 (32) [Mar 29 13:06:20] DEBUG[14946]: chan_sip.c:4605 parse_request: Line: a=rtpmap:8 PCMA/8000 (20) [Mar 29 13:06:20] DEBUG[14946]: chan_sip.c:4605 parse_request: Line: a=rtpmap:3 GSM/8000 (19) [Mar 29 13:06:20] DEBUG[14946]: chan_sip.c:4605 parse_request: Line: a=rtpmap:97 iLBC/8000 (21) [Mar 29 13:06:20] DEBUG[14946]: chan_sip.c:4605 parse_request: Line: a=fmtp:97 mode=30 (17) [Mar 29 13:06:20] DEBUG[14946]: chan_sip.c:4605 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [Mar 29 13:06:20] DEBUG[14946]: chan_sip.c:4605 parse_request: Line: a=fmtp:101 0-16 (15) [Mar 29 13:06:20] DEBUG[14946]: chan_sip.c:4605 parse_request: Line: a=silenceSupp:off - - - - (25) [Mar 29 13:06:20] DEBUG[14946]: chan_sip.c:4605 parse_request: Line: a=ptime:20 (10) [Mar 29 13:06:20] DEBUG[14946]: chan_sip.c:4605 parse_request: Line: a=sendrecv (10) Reliably Transmitting (no NAT) to 172.16.0.20:5060: INVITE sip:0435401601@172.16.0.20 SIP/2.0 Via: SIP/2.0/UDP 172.16.0.25:5060;branch=z9hG4bK16dbae04;rport From: "anon" ;tag=as297ba3fa To: Contact: Call-ID: 7059ab55508465502ca3d05a79b1c5da@172.16.0.25 CSeq: 102 INVITE User-Agent: blabla.ch 1.4PBX Max-Forwards: 70 Date: Thu, 29 Mar 2007 11:06:20 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Content-Type: application/sdp Content-Length: 304 v=0 o=root 14946 14946 IN IP4 172.16.0.25 s=session c=IN IP4 172.16.0.25 t=0 0 m=audio 12898 RTP/AVP 8 3 97 101 a=rtpmap:8 PCMA/8000 a=rtpmap:3 GSM/8000 a=rtpmap:97 iLBC/8000 a=fmtp:97 mode=30 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv --- [Mar 29 13:06:20] DEBUG[14946]: chan_sip.c:1975 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #1292 -- Called 0435401601@172.16.0.20 <--- SIP read from 172.16.0.20:5060 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 172.16.0.25:5060;received=172.16.0.25;branch=z9hG4bK16dbae04;rport=5060 From: "anon" ;tag=as297ba3fa To: Call-ID: 7059ab55508465502ca3d05a79b1c5da@172.16.0.25 CSeq: 102 INVITE <-------------> [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 0: SIP/2.0 100 Trying (18) [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 1: Via: SIP/2.0/UDP 172.16.0.25:5060;received=172.16.0.25;branch=z9hG4bK16dbae04;rport=5060 (86) [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 2: From: "anon" ;tag=as297ba3fa (55) [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 3: To: (31) [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 4: Call-ID: 7059ab55508465502ca3d05a79b1c5da@172.16.0.25 (52) [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 5: CSeq: 102 INVITE (16) [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 6: (0) --- (6 headers 0 lines) --- [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:4361 find_call: = Found Their Call ID: 7059ab55508465502ca3d05a79b1c5da@172.16.0.25 Their Tag Our tag: as297ba3fa [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:2122 __sip_semi_ack: *** SIP TIMER: Cancelling retransmission #1292 - INVITE (got response) [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:2131 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '7059ab55508465502ca3d05a79b1c5da@172.16.0.25' Request 102: Found [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:11641 handle_response_invite: SIP response 100 to standard invite anarki*CLI> <--- SIP read from 10.10.10.23:5060 ---> NOTIFY sip:172.16.0.25 SIP/2.0 Via: SIP/2.0/UDP 10.10.10.23:5060;branch=z9hG4bK-2e90acc1 From: alx ;tag=82a91f60f0afa1ado0 To: Call-ID: edc685a6-17ad004d@10.10.10.23 CSeq: 275 NOTIFY Max-Forwards: 70 Event: keep-alive User-Agent: Linksys/SPA2102-3.3.6 Content-Length: 0 <-------------> [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 0: NOTIFY sip:172.16.0.25 SIP/2.0 (29) [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 1: Via: SIP/2.0/UDP 10.10.10.23:5060;branch=z9hG4bK-2e90acc1 (59) [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 2: From: alx ;tag=82a91f60f0afa1ado0 (59) [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 3: To: (20) [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 4: Call-ID: edc685a6-17ad004d@10.10.10.23 (40) [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 5: CSeq: 275 NOTIFY (16) [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 6: Max-Forwards: 70 (16) [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 7: Event: keep-alive (17) [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 8: User-Agent: Linksys/SPA2102-3.3.6 (33) [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 9: Content-Length: 0 (17) [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 10: (0) --- (10 headers 0 lines) --- [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:4361 find_call: = No match Their Call ID: 7059ab55508465502ca3d05a79b1c5da@172.16.0.25 Their Tag Our tag: as297ba3fa [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:4361 find_call: = No match Their Call ID: 84a4e749-194220ab@10.10.10.23 Their Tag 61ce66b1d4446863o1 Our tag: as24f89e56 <--- Transmitting (no NAT) to 10.10.10.23:5060 ---> SIP/2.0 489 Bad event Via: SIP/2.0/UDP 10.10.10.23:5060;branch=z9hG4bK-2e90acc1;received=10.10.10.23 From: alx ;tag=82a91f60f0afa1ado0 To: ;tag=as7fbdd2f5 Call-ID: edc685a6-17ad004d@10.10.10.23 CSeq: 275 NOTIFY User-Agent: blabla.ch 1.4PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Content-Length: 0 <------------> [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:14817 sipsock_read: Invalid SIP message - rejected , no callid, len 328 anarki*CLI> <--- SIP read from 10.10.10.23:5061 ---> NOTIFY sip:172.16.0.25 SIP/2.0 Via: SIP/2.0/UDP 10.10.10.23:5061;branch=z9hG4bK-c4b059b0 From: fax ;tag=d2bd39c8aad00a65o1 To: Call-ID: 3258edd2-a37bd611@10.10.10.23 CSeq: 275 NOTIFY Max-Forwards: 70 Event: keep-alive User-Agent: Linksys/SPA2102-3.3.6 Content-Length: 0 <-------------> [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 0: NOTIFY sip:172.16.0.25 SIP/2.0 (29) [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 1: Via: SIP/2.0/UDP 10.10.10.23:5061;branch=z9hG4bK-c4b059b0 (59) [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 2: From: fax ;tag=d2bd39c8aad00a65o1 (59) [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 3: To: (20) [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 4: Call-ID: 3258edd2-a37bd611@10.10.10.23 (40) [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 5: CSeq: 275 NOTIFY (16) [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 6: Max-Forwards: 70 (16) [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 7: Event: keep-alive (17) [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 8: User-Agent: Linksys/SPA2102-3.3.6 (33) [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 9: Content-Length: 0 (17) [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 10: (0) --- (10 headers 0 lines) --- [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:4361 find_call: = No match Their Call ID: 7059ab55508465502ca3d05a79b1c5da@172.16.0.25 Their Tag Our tag: as297ba3fa [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:4361 find_call: = No match Their Call ID: 84a4e749-194220ab@10.10.10.23 Their Tag 61ce66b1d4446863o1 Our tag: as24f89e56 anarki*CLI> <--- Transmitting (no NAT) to 10.10.10.23:5061 ---> SIP/2.0 489 Bad event Via: SIP/2.0/UDP 10.10.10.23:5061;branch=z9hG4bK-c4b059b0;received=10.10.10.23 From: fax ;tag=d2bd39c8aad00a65o1 To: ;tag=as26a576c1 Call-ID: 3258edd2-a37bd611@10.10.10.23 CSeq: 275 NOTIFY User-Agent: blabla.ch 1.4PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Content-Length: 0 <------------> [Mar 29 13:06:20] DEBUG[2735]: chan_sip.c:14817 sipsock_read: Invalid SIP message - rejected , no callid, len 328 [Mar 29 13:06:20] DEBUG[14946]: chan_sip.c:6420 transmit_response_with_sdp: Setting framing from config on incoming call [Mar 29 13:06:20] DEBUG[14946]: chan_sip.c:6188 add_sdp: ** Our capability: 0x8 (alaw) Video flag: True [Mar 29 13:06:20] DEBUG[14946]: chan_sip.c:6189 add_sdp: ** Our prefcodec: 0x0 (nothing) Audio is at 172.16.0.25 port 19144 Adding codec 0x8 (alaw) to SDP Adding non-codec 0x1 (telephone-event) to SDP [Mar 29 13:06:20] DEBUG[14946]: chan_sip.c:6320 add_sdp: -- Done with adding codecs to SDP [Mar 29 13:06:20] DEBUG[14946]: channel.c:2381 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=29) [Mar 29 13:06:20] DEBUG[14946]: chan_sip.c:6365 add_sdp: Done building SDP. Settling with this capability: 0x8 (alaw) anarki*CLI> <--- Transmitting (NAT) to 10.10.10.23:5061 ---> SIP/2.0 183 Session Progress Via: SIP/2.0/UDP 10.10.10.23:5061;branch=z9hG4bK-977813e7;received=10.10.10.23 From: fax ;tag=61ce66b1d4446863o1 To: ;tag=as24f89e56 Call-ID: 84a4e749-194220ab@10.10.10.23 CSeq: 102 INVITE User-Agent: blabla.ch 1.4PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Type: application/sdp Content-Length: 236 v=0 o=root 14946 14946 IN IP4 172.16.0.25 s=session c=IN IP4 172.16.0.25 t=0 0 m=audio 19144 RTP/AVP 8 101 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv <------------> [Mar 29 13:06:20] DEBUG[14946]: rtp.c:2689 ast_rtp_write: Ooh, format changed from unknown to alaw [Mar 29 13:06:20] DEBUG[14946]: rtp.c:2706 ast_rtp_write: Created smoother: format: 8 ms: 20 len: 160 [Mar 29 13:06:21] NOTICE[14946]: rtp.c:1256 ast_rtp_read: Unknown RTP codec 100 received from '10.10.10.23' anarki*CLI> <--- SIP read from 172.16.0.20:5060 ---> SIP/2.0 183 Session Progress Via: SIP/2.0/UDP 172.16.0.25:5060;received=172.16.0.25;branch=z9hG4bK16dbae04;rport=5060 From: "anon" ;tag=as297ba3fa To: ;tag=1775654741 Call-ID: 7059ab55508465502ca3d05a79b1c5da@172.16.0.25 CSeq: 102 INVITE Contact: Content-Type: application/sdp Content-Length: 343 v=0 o=- 45513 1 IN IP4 172.16.0.20 s=Cisco SDP 0 c=IN IP4 172.16.0.20 t=0 0 m=audio 20058 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 <-------------> [Mar 29 13:06:21] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 0: SIP/2.0 183 Session Progress (28) [Mar 29 13:06:21] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 1: Via: SIP/2.0/UDP 172.16.0.25:5060;received=172.16.0.25;branch=z9hG4bK16dbae04;rport=5060 (86) [Mar 29 13:06:21] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 2: From: "anon" ;tag=as297ba3fa (55) [Mar 29 13:06:21] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 3: To: ;tag=1775654741 (46) [Mar 29 13:06:21] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 4: Call-ID: 7059ab55508465502ca3d05a79b1c5da@172.16.0.25 (52) [Mar 29 13:06:21] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 5: CSeq: 102 INVITE (16) [Mar 29 13:06:21] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 6: Contact: (55) [Mar 29 13:06:21] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 7: Content-Type: application/sdp (29) [Mar 29 13:06:21] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 8: Content-Length: 343 (19) [Mar 29 13:06:21] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 9: (0) [Mar 29 13:06:21] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: v=0 (3) [Mar 29 13:06:21] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: o=- 45513 1 IN IP4 172.16.0.20 (29) [Mar 29 13:06:21] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: s=Cisco SDP 0 (13) [Mar 29 13:06:21] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: c=IN IP4 172.16.0.20 (19) [Mar 29 13:06:21] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: t=0 0 (5) [Mar 29 13:06:21] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: m=audio 20058 RTP/AVP 8 101 100 (31) [Mar 29 13:06:21] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [Mar 29 13:06:21] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: a=fmtp:101 0-15 (15) [Mar 29 13:06:21] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: a=rtpmap:100 X-NSE/8000 (23) [Mar 29 13:06:21] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: a=fmtp:100 200-202 (18) [Mar 29 13:06:21] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: a=X-sqn:0 (9) [Mar 29 13:06:21] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: a=X-cap: 1 audio RTP/AVP 100 (28) [Mar 29 13:06:21] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: a=X-cpar: a=rtpmap:100 X-NSE/8000 (33) [Mar 29 13:06:21] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: a=X-cpar: a=fmtp:100 200-202 (28) [Mar 29 13:06:21] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: a=X-cap: 2 image udptl t38 (26) --- (9 headers 15 lines) --- [Mar 29 13:06:21] DEBUG[2735]: chan_sip.c:4361 find_call: = Found Their Call ID: 7059ab55508465502ca3d05a79b1c5da@172.16.0.25 Their Tag Our tag: as297ba3fa [Mar 29 13:06:21] DEBUG[2735]: chan_sip.c:2131 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '7059ab55508465502ca3d05a79b1c5da@172.16.0.25' Request 102: Found [Mar 29 13:06:21] DEBUG[2735]: chan_sip.c:11641 handle_response_invite: SIP response 183 to standard invite Found RTP audio format 8 Found RTP audio format 101 Found RTP audio format 100 [Mar 29 13:06:21] DEBUG[2735]: chan_sip.c:4899 process_sdp: Peer doesn't provide T.38 UDPTL Peer audio RTP is at port 172.16.0.20:20058 Found description format telephone-event for ID 101 Got unsupported a:fmtp in SDP offer Found description format X-NSE for ID 100 Got unsupported a:fmtp in SDP offer [Mar 29 13:06:21] DEBUG[2735]: chan_sip.c:5129 process_sdp: T38 state changed to 0 on channel SIP/172.16.0.20-081d5580 Capabilities: us - 0x40a (gsm|alaw|ilbc), peer - audio=0x8 (alaw)/video=0x0 (nothing), combined - 0x8 (alaw) Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) Peer audio RTP is at port 172.16.0.20:20058 Peer video RTP is at port 172.16.0.20:63927 [Mar 29 13:06:21] DEBUG[2735]: chan_sip.c:5209 process_sdp: We're settling with these formats: 0x8 (alaw) [Mar 29 13:06:21] DEBUG[2735]: chan_sip.c:5216 process_sdp: We have an owner, now see if we need to change this call -- Call on SIP/172.16.0.20-081d5580 left from hold -- SIP/172.16.0.20-081d5580 is making progress passing it to SIP/12345011-081d1618 [Mar 29 13:06:21] DEBUG[14946]: rtp.c:1527 ast_rtp_early_bridge: Setting early bridge SDP of 'SIP/12345011-081d1618' with that of 'SIP/172.16.0.20-081d5580' [Mar 29 13:06:21] DEBUG[14946]: rtp.c:2689 ast_rtp_write: Ooh, format changed from unknown to alaw [Mar 29 13:06:21] DEBUG[14946]: rtp.c:2706 ast_rtp_write: Created smoother: format: 8 ms: 20 len: 160 [Mar 29 13:06:22] DEBUG[14946]: rtp.c:873 ast_rtcp_read: Got RTCP report of 88 bytes anarki*CLI> <--- SIP read from 172.16.0.20:5060 ---> SIP/2.0 180 Ringing Via: SIP/2.0/UDP 172.16.0.25:5060;received=172.16.0.25;branch=z9hG4bK16dbae04;rport=5060 From: "anon" ;tag=as297ba3fa To: ;tag=1775654741 Call-ID: 7059ab55508465502ca3d05a79b1c5da@172.16.0.25 CSeq: 102 INVITE Contact: Content-Length: 0 <-------------> [Mar 29 13:06:23] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 0: SIP/2.0 180 Ringing (19) [Mar 29 13:06:23] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 1: Via: SIP/2.0/UDP 172.16.0.25:5060;received=172.16.0.25;branch=z9hG4bK16dbae04;rport=5060 (86) [Mar 29 13:06:23] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 2: From: "anon" ;tag=as297ba3fa (55) [Mar 29 13:06:23] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 3: To: ;tag=1775654741 (46) [Mar 29 13:06:23] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 4: Call-ID: 7059ab55508465502ca3d05a79b1c5da@172.16.0.25 (52) [Mar 29 13:06:23] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 5: CSeq: 102 INVITE (16) [Mar 29 13:06:23] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 6: Contact: (55) [Mar 29 13:06:23] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 7: Content-Length: 0 (17) [Mar 29 13:06:23] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 8: (0) --- (8 headers 0 lines) --- [Mar 29 13:06:23] DEBUG[2735]: chan_sip.c:4361 find_call: = Found Their Call ID: 7059ab55508465502ca3d05a79b1c5da@172.16.0.25 Their Tag 1775654741 Our tag: as297ba3fa [Mar 29 13:06:23] DEBUG[2735]: chan_sip.c:2131 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '7059ab55508465502ca3d05a79b1c5da@172.16.0.25' Request 102: Found [Mar 29 13:06:23] DEBUG[2735]: chan_sip.c:11641 handle_response_invite: SIP response 180 to standard invite [Mar 29 13:06:23] DEBUG[2735]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/172.16.0.20-081d5580 [Mar 29 13:06:23] DEBUG[2711]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 172.16.0.20 [Mar 29 13:06:23] DEBUG[2711]: chan_sip.c:15244 sip_devicestate: Checking device state for peer 172.16.0.20 [Mar 29 13:06:23] DEBUG[2711]: devicestate.c:287 do_state_change: Changing state for SIP/172.16.0.20 - state 6 (Ringing) -- SIP/172.16.0.20-081d5580 is ringing [Mar 29 13:06:23] DEBUG[14946]: rtp.c:1527 ast_rtp_early_bridge: Setting early bridge SDP of 'SIP/12345011-081d1618' with that of 'SIP/172.16.0.20-081d5580' <--- Transmitting (NAT) to 10.10.10.23:5061 ---> SIP/2.0 180 Ringing Via: SIP/2.0/UDP 10.10.10.23:5061;branch=z9hG4bK-977813e7;received=10.10.10.23 From: fax ;tag=61ce66b1d4446863o1 To: ;tag=as24f89e56 Call-ID: 84a4e749-194220ab@10.10.10.23 CSeq: 102 INVITE User-Agent: blabla.ch 1.4PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Length: 0 <------------> [Mar 29 13:06:23] DEBUG[14948]: app_queue.c:546 changethread: Device 'SIP/172.16.0.20' changed to state '6' (Ringing) but we don't care because they're not a member of any queue. [Mar 29 13:06:23] DEBUG[14946]: rtp.c:873 ast_rtcp_read: Got RTCP report of 88 bytes [Mar 29 13:06:23] DEBUG[14946]: rtp.c:873 ast_rtcp_read: Got RTCP report of 92 bytes [Mar 29 13:06:26] DEBUG[14946]: rtp.c:873 ast_rtcp_read: Got RTCP report of 108 bytes [Mar 29 13:06:26] DEBUG[14946]: rtp.c:873 ast_rtcp_read: Got RTCP report of 92 bytes anarki*CLI> <--- SIP read from 172.16.0.20:5060 ---> SIP/2.0 200 Ok Via: SIP/2.0/UDP 172.16.0.25:5060;received=172.16.0.25;branch=z9hG4bK16dbae04;rport=5060 From: "anon" ;tag=as297ba3fa To: ;tag=1775654741 Call-ID: 7059ab55508465502ca3d05a79b1c5da@172.16.0.25 CSeq: 102 INVITE Contact: Allow: INVITE,ACK,PRACK,SUBSCRIBE,BYE,CANCEL,NOTIFY,INFO,REFER,UPDATE Supported: timer Content-Type: application/sdp Content-Length: 343 v=0 o=- 45513 1 IN IP4 172.16.0.20 s=Cisco SDP 0 c=IN IP4 172.16.0.20 t=0 0 m=audio 20058 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 <-------------> [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 0: SIP/2.0 200 Ok (14) [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 1: Via: SIP/2.0/UDP 172.16.0.25:5060;received=172.16.0.25;branch=z9hG4bK16dbae04;rport=5060 (86) [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 2: From: "anon" ;tag=as297ba3fa (55) [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 3: To: ;tag=1775654741 (46) [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 4: Call-ID: 7059ab55508465502ca3d05a79b1c5da@172.16.0.25 (52) [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 5: CSeq: 102 INVITE (16) [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 6: Contact: (55) [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 7: Allow: INVITE,ACK,PRACK,SUBSCRIBE,BYE,CANCEL,NOTIFY,INFO,REFER,UPDATE (69) [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 8: Supported: timer (16) [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 9: Content-Type: application/sdp (29) [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 10: Content-Length: 343 (19) [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 11: (0) [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: v=0 (3) [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: o=- 45513 1 IN IP4 172.16.0.20 (29) [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: s=Cisco SDP 0 (13) [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: c=IN IP4 172.16.0.20 (19) [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: t=0 0 (5) [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: m=audio 20058 RTP/AVP 8 101 100 (31) [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: a=fmtp:101 0-15 (15) [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: a=rtpmap:100 X-NSE/8000 (23) [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: a=fmtp:100 200-202 (18) [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: a=X-sqn:0 (9) [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: a=X-cap: 1 audio RTP/AVP 100 (28) [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: a=X-cpar: a=rtpmap:100 X-NSE/8000 (33) [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: a=X-cpar: a=fmtp:100 200-202 (28) [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: a=X-cap: 2 image udptl t38 (26) --- (11 headers 15 lines) --- [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4361 find_call: = Found Their Call ID: 7059ab55508465502ca3d05a79b1c5da@172.16.0.25 Their Tag 1775654741 Our tag: as297ba3fa [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:2071 __sip_ack: Acked pending invite 102 [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:2089 __sip_ack: Stopping retransmission on '7059ab55508465502ca3d05a79b1c5da@172.16.0.25' of Request 102: Match Not Found [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:11641 handle_response_invite: SIP response 200 to standard invite Found RTP audio format 8 Found RTP audio format 101 Found RTP audio format 100 [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4899 process_sdp: Peer doesn't provide T.38 UDPTL Peer audio RTP is at port 172.16.0.20:20058 Found description format telephone-event for ID 101 Got unsupported a:fmtp in SDP offer Found description format X-NSE for ID 100 Got unsupported a:fmtp in SDP offer [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:5129 process_sdp: T38 state changed to 0 on channel SIP/172.16.0.20-081d5580 Capabilities: us - 0x40a (gsm|alaw|ilbc), peer - audio=0x8 (alaw)/video=0x0 (nothing), combined - 0x8 (alaw) Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) Peer audio RTP is at port 172.16.0.20:20058 Peer video RTP is at port 172.16.0.20:6664 [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:5209 process_sdp: We're settling with these formats: 0x8 (alaw) [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:5216 process_sdp: We have an owner, now see if we need to change this call [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:3003 update_call_counter: Updating call counter for outgoing call [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:7980 build_route: build_route: Contact hop: list_route: hop: [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:5643 reqprep: Strict routing enforced for session 7059ab55508465502ca3d05a79b1c5da@172.16.0.25 set_destination: Parsing for address/port to send to set_destination: set destination to 172.16.0.20, port 5060 Transmitting (no NAT) to 172.16.0.20:5060: ACK sip:0435401601@172.16.0.20:5060;transport=udp SIP/2.0 Via: SIP/2.0/UDP 172.16.0.25:5060;branch=z9hG4bK5cc14582;rport From: "anon" ;tag=as297ba3fa To: ;tag=1775654741 Contact: Call-ID: 7059ab55508465502ca3d05a79b1c5da@172.16.0.25 CSeq: 102 ACK User-Agent: blabla.ch 1.4PBX Max-Forwards: 70 Content-Length: 0 --- -- Call on SIP/172.16.0.20-081d5580 left from hold [Mar 29 13:06:28] DEBUG[14946]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/172.16.0.20-081d5580 -- SIP/172.16.0.20-081d5580 answered SIP/12345011-081d1618 [Mar 29 13:06:28] DEBUG[14946]: rtp.c:1527 ast_rtp_early_bridge: Setting early bridge SDP of 'SIP/12345011-081d1618' with that of 'SIP/172.16.0.20-081d5580' [Mar 29 13:06:28] DEBUG[14946]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/12345011-081d1618 [Mar 29 13:06:28] DEBUG[14946]: chan_sip.c:3463 sip_answer: SIP answering channel: SIP/12345011-081d1618 [Mar 29 13:06:28] DEBUG[14946]: chan_sip.c:6420 transmit_response_with_sdp: Setting framing from config on incoming call [Mar 29 13:06:28] DEBUG[14946]: chan_sip.c:6188 add_sdp: ** Our capability: 0x8 (alaw) Video flag: True [Mar 29 13:06:28] DEBUG[14946]: chan_sip.c:6189 add_sdp: ** Our prefcodec: 0x0 (nothing) Audio is at 172.16.0.25 port 19144 Adding codec 0x8 (alaw) to SDP Adding non-codec 0x1 (telephone-event) to SDP [Mar 29 13:06:28] DEBUG[14946]: chan_sip.c:6320 add_sdp: -- Done with adding codecs to SDP [Mar 29 13:06:28] DEBUG[14946]: channel.c:2381 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=29) [Mar 29 13:06:28] DEBUG[14946]: chan_sip.c:6365 add_sdp: Done building SDP. Settling with this capability: 0x8 (alaw) <--- Reliably Transmitting (NAT) to 10.10.10.23:5061 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 10.10.10.23:5061;branch=z9hG4bK-977813e7;received=10.10.10.23 From: fax ;tag=61ce66b1d4446863o1 To: ;tag=as24f89e56 Call-ID: 84a4e749-194220ab@10.10.10.23 CSeq: 102 INVITE User-Agent: blabla.ch 1.4PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Type: application/sdp Content-Length: 236 v=0 o=root 14946 14947 IN IP4 172.16.0.25 s=session c=IN IP4 172.16.0.25 t=0 0 m=audio 19144 RTP/AVP 8 101 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv <------------> [Mar 29 13:06:28] DEBUG[14946]: chan_sip.c:1975 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #1296 -- Native bridging SIP/12345011-081d1618 and SIP/172.16.0.20-081d5580 [Mar 29 13:06:28] DEBUG[14946]: chan_sip.c:16912 sip_set_rtp_peer: Deferring reinvite on SIP '84a4e749-194220ab@10.10.10.23' - It's audio will be redirected to IP 172.16.0.20 [Mar 29 13:06:28] DEBUG[14946]: chan_sip.c:16907 sip_set_rtp_peer: Sending reinvite on SIP '7059ab55508465502ca3d05a79b1c5da@172.16.0.25' - It's audio soon redirected to IP 10.10.10.23 [Mar 29 13:06:28] DEBUG[14946]: chan_sip.c:5643 reqprep: Strict routing enforced for session 7059ab55508465502ca3d05a79b1c5da@172.16.0.25 set_destination: Parsing for address/port to send to set_destination: set destination to 172.16.0.20, port 5060 [Mar 29 13:06:28] DEBUG[14946]: chan_sip.c:6188 add_sdp: ** Our capability: 0x8 (alaw) Video flag: True [Mar 29 13:06:28] DEBUG[14946]: chan_sip.c:6189 add_sdp: ** Our prefcodec: 0x8 (alaw) Audio is at 172.16.0.25 port 12898 Adding codec 0x8 (alaw) to SDP Adding non-codec 0x1 (telephone-event) to SDP [Mar 29 13:06:28] DEBUG[14946]: chan_sip.c:6320 add_sdp: -- Done with adding codecs to SDP [Mar 29 13:06:28] DEBUG[14946]: channel.c:2381 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=36) [Mar 29 13:06:28] DEBUG[14946]: chan_sip.c:6365 add_sdp: Done building SDP. Settling with this capability: 0x8 (alaw) [Mar 29 13:06:28] DEBUG[14946]: chan_sip.c:1621 initialize_initreq: Initializing already initialized SIP dialog 7059ab55508465502ca3d05a79b1c5da@172.16.0.25 (presumably reinvite) [Mar 29 13:06:28] DEBUG[14946]: chan_sip.c:4573 parse_request: Header 0: INVITE sip:0435401601@172.16.0.20:5060;transport=udp SIP/2.0 (59) [Mar 29 13:06:28] DEBUG[14946]: chan_sip.c:4573 parse_request: Header 1: Via: SIP/2.0/UDP 172.16.0.25:5060;branch=z9hG4bK131597f4;rport (61) [Mar 29 13:06:28] DEBUG[14946]: chan_sip.c:4573 parse_request: Header 2: From: "anon" ;tag=as297ba3fa (55) [Mar 29 13:06:28] DEBUG[14946]: chan_sip.c:4573 parse_request: Header 3: To: ;tag=1775654741 (46) [Mar 29 13:06:28] DEBUG[14946]: chan_sip.c:4573 parse_request: Header 4: Contact: (36) [Mar 29 13:06:28] DEBUG[14946]: chan_sip.c:4573 parse_request: Header 5: Call-ID: 7059ab55508465502ca3d05a79b1c5da@172.16.0.25 (52) [Mar 29 13:06:28] DEBUG[14946]: chan_sip.c:4573 parse_request: Header 6: CSeq: 103 INVITE (16) [Mar 29 13:06:28] DEBUG[14946]: chan_sip.c:4573 parse_request: Header 7: User-Agent: blabla.ch 1.4PBX (26) [Mar 29 13:06:28] DEBUG[14946]: chan_sip.c:4573 parse_request: Header 8: Max-Forwards: 70 (16) [Mar 29 13:06:28] DEBUG[14946]: chan_sip.c:4573 parse_request: Header 9: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) [Mar 29 13:06:28] DEBUG[14946]: chan_sip.c:4573 parse_request: Header 10: Supported: replaces (19) [Mar 29 13:06:28] DEBUG[14946]: chan_sip.c:4573 parse_request: Header 11: X-asterisk-Info: SIP re-invite (External RTP bridge) (52) [Mar 29 13:06:28] DEBUG[14946]: chan_sip.c:4573 parse_request: Header 12: Content-Type: application/sdp (29) [Mar 29 13:06:28] DEBUG[14946]: chan_sip.c:4573 parse_request: Header 13: Content-Length: 242 (19) [Mar 29 13:06:28] DEBUG[14946]: chan_sip.c:4573 parse_request: Header 14: (0) [Mar 29 13:06:28] DEBUG[14946]: chan_sip.c:4605 parse_request: Line: v=0 (3) [Mar 29 13:06:28] DEBUG[14946]: chan_sip.c:4605 parse_request: Line: o=root 14946 14947 IN IP4 10.10.10.23 (39) [Mar 29 13:06:28] DEBUG[14946]: chan_sip.c:4605 parse_request: Line: s=session (9) [Mar 29 13:06:28] DEBUG[14946]: chan_sip.c:4605 parse_request: Line: c=IN IP4 10.10.10.23 (22) [Mar 29 13:06:28] DEBUG[14946]: chan_sip.c:4605 parse_request: Line: t=0 0 (5) [Mar 29 13:06:28] DEBUG[14946]: chan_sip.c:4605 parse_request: Line: m=audio 16464 RTP/AVP 8 101 (27) [Mar 29 13:06:28] DEBUG[14946]: chan_sip.c:4605 parse_request: Line: a=rtpmap:8 PCMA/8000 (20) [Mar 29 13:06:28] DEBUG[14946]: chan_sip.c:4605 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [Mar 29 13:06:28] DEBUG[14946]: chan_sip.c:4605 parse_request: Line: a=fmtp:101 0-16 (15) [Mar 29 13:06:28] DEBUG[14946]: chan_sip.c:4605 parse_request: Line: a=silenceSupp:off - - - - (25) [Mar 29 13:06:28] DEBUG[14946]: chan_sip.c:4605 parse_request: Line: a=ptime:20 (10) [Mar 29 13:06:28] DEBUG[14946]: chan_sip.c:4605 parse_request: Line: a=sendrecv (10) Reliably Transmitting (no NAT) to 172.16.0.20:5060: INVITE sip:0435401601@172.16.0.20:5060;transport=udp SIP/2.0 Via: SIP/2.0/UDP 172.16.0.25:5060;branch=z9hG4bK131597f4;rport From: "anon" ;tag=as297ba3fa To: ;tag=1775654741 Contact: Call-ID: 7059ab55508465502ca3d05a79b1c5da@172.16.0.25 CSeq: 103 INVITE User-Agent: blabla.ch 1.4PBX Max-Forwards: 70 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces X-asterisk-Info: SIP re-invite (External RTP bridge) Content-Type: application/sdp Content-Length: 242 v=0 o=root 14946 14947 IN IP4 10.10.10.23 s=session c=IN IP4 10.10.10.23 t=0 0 m=audio 16464 RTP/AVP 8 101 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv --- [Mar 29 13:06:28] DEBUG[14946]: chan_sip.c:1975 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #1297 [Mar 29 13:06:28] DEBUG[2711]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 172.16.0.20 [Mar 29 13:06:28] DEBUG[2711]: chan_sip.c:15244 sip_devicestate: Checking device state for peer 172.16.0.20 [Mar 29 13:06:28] DEBUG[2711]: devicestate.c:287 do_state_change: Changing state for SIP/172.16.0.20 - state 2 (In use) [Mar 29 13:06:28] DEBUG[2711]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 12345011 [Mar 29 13:06:28] DEBUG[2711]: chan_sip.c:15244 sip_devicestate: Checking device state for peer 12345011 [Mar 29 13:06:28] DEBUG[2711]: devicestate.c:287 do_state_change: Changing state for SIP/12345011 - state 1 (Not in use) [Mar 29 13:06:28] DEBUG[2711]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 12345011 [Mar 29 13:06:28] DEBUG[2711]: chan_sip.c:15244 sip_devicestate: Checking device state for peer 12345011 [Mar 29 13:06:28] DEBUG[14949]: app_queue.c:546 changethread: Device 'SIP/172.16.0.20' changed to state '2' (In use) but we don't care because they're not a member of any queue. [Mar 29 13:06:28] DEBUG[14950]: app_queue.c:546 changethread: Device 'SIP/12345011' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. anarki*CLI> <--- SIP read from 10.10.10.23:5061 ---> ACK sip:0435401601@172.16.0.25 SIP/2.0 Via: SIP/2.0/UDP 10.10.10.23:5061;branch=z9hG4bK-42fe119b From: fax ;tag=61ce66b1d4446863o1 To: ;tag=as24f89e56 Call-ID: 84a4e749-194220ab@10.10.10.23 CSeq: 102 ACK Max-Forwards: 70 Proxy-Authorization: Digest username="12345011",realm="blabla.ch",nonce="79788763",uri="sip:0435401601@172.16.0.25",algorithm=MD5,response="993710b832d3a21217a42435d273f925" Contact: fax User-Agent: Linksys/SPA2102-3.3.6 Content-Length: 0 <-------------> [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 0: ACK sip:0435401601@172.16.0.25 SIP/2.0 (37) [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 1: Via: SIP/2.0/UDP 10.10.10.23:5061;branch=z9hG4bK-42fe119b (59) [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 2: From: fax ;tag=61ce66b1d4446863o1 (59) [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 3: To: ;tag=as24f89e56 (46) [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 4: Call-ID: 84a4e749-194220ab@10.10.10.23 (40) [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 5: CSeq: 102 ACK (13) [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 6: Max-Forwards: 70 (16) [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 7: Proxy-Authorization: Digest username="12345011",realm="blabla.ch",nonce="79788763",uri="sip:0435401601@172.16.0.25",algorithm=MD5,response="993710b832d3a21217a42435d273f925" (171) [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 8: Contact: fax (47) [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 9: User-Agent: Linksys/SPA2102-3.3.6 (33) [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 10: Content-Length: 0 (17) [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 11: (0) --- (11 headers 0 lines) --- [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4361 find_call: = No match Their Call ID: 7059ab55508465502ca3d05a79b1c5da@172.16.0.25 Their Tag 1775654741 Our tag: as297ba3fa [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4361 find_call: = Found Their Call ID: 84a4e749-194220ab@10.10.10.23 Their Tag 61ce66b1d4446863o1 Our tag: as24f89e56 [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:14633 handle_request: **** Received ACK (6) - Command in SIP ACK [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:2079 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #1296 [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:2089 __sip_ack: Stopping retransmission on '84a4e749-194220ab@10.10.10.23' of Response 102: Match Not Found [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:11622 check_pendings: Sending pending reinvite on '84a4e749-194220ab@10.10.10.23' [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:5643 reqprep: Strict routing enforced for session 84a4e749-194220ab@10.10.10.23 set_destination: Parsing for address/port to send to set_destination: set destination to 10.10.10.23, port 5061 [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:6188 add_sdp: ** Our capability: 0x8 (alaw) Video flag: True [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:6189 add_sdp: ** Our prefcodec: 0x0 (nothing) Audio is at 172.16.0.25 port 19144 Adding codec 0x8 (alaw) to SDP Adding non-codec 0x1 (telephone-event) to SDP [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:6320 add_sdp: -- Done with adding codecs to SDP [Mar 29 13:06:28] DEBUG[2735]: channel.c:2381 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=29) [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:6365 add_sdp: Done building SDP. Settling with this capability: 0x8 (alaw) [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:1621 initialize_initreq: Initializing already initialized SIP dialog 84a4e749-194220ab@10.10.10.23 (presumably reinvite) [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 0: INVITE sip:12345011@10.10.10.23:5061 SIP/2.0 (47) [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 1: Via: SIP/2.0/UDP 172.16.0.25:5060;branch=z9hG4bK5a16ff73;rport (61) [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 2: From: ;tag=as24f89e56 (48) [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 3: To: fax ;tag=61ce66b1d4446863o1 (57) [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 4: Contact: (36) [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 5: Call-ID: 84a4e749-194220ab@10.10.10.23 (40) [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 6: CSeq: 102 INVITE (16) [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 7: User-Agent: blabla.ch 1.4PBX (26) [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 8: Max-Forwards: 70 (16) [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 9: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 10: Supported: replaces (19) [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 11: X-asterisk-Info: SIP re-invite (External RTP bridge) (52) [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 12: Content-Type: application/sdp (29) [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 13: Content-Length: 236 (19) [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 14: (0) [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: v=0 (3) [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: o=root 14946 14948 IN IP4 172.16.0.20 (36) [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: s=session (9) [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: c=IN IP4 172.16.0.20 (19) [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: t=0 0 (5) [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: m=audio 20058 RTP/AVP 8 101 (27) [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: a=rtpmap:8 PCMA/8000 (20) [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: a=fmtp:101 0-16 (15) [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: a=silenceSupp:off - - - - (25) [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: a=ptime:20 (10) [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: a=sendrecv (10) Reliably Transmitting (NAT) to 10.10.10.23:5061: INVITE sip:12345011@10.10.10.23:5061 SIP/2.0 Via: SIP/2.0/UDP 172.16.0.25:5060;branch=z9hG4bK5a16ff73;rport From: ;tag=as24f89e56 To: fax ;tag=61ce66b1d4446863o1 Contact: Call-ID: 84a4e749-194220ab@10.10.10.23 CSeq: 102 INVITE User-Agent: blabla.ch 1.4PBX Max-Forwards: 70 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces X-asterisk-Info: SIP re-invite (External RTP bridge) Content-Type: application/sdp Content-Length: 236 v=0 o=root 14946 14948 IN IP4 172.16.0.20 s=session c=IN IP4 172.16.0.20 t=0 0 m=audio 20058 RTP/AVP 8 101 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv --- [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:1975 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #1298 anarki*CLI> <--- SIP read from 172.16.0.20:5060 ---> SIP/2.0 200 Ok Via: SIP/2.0/UDP 172.16.0.25:5060;received=172.16.0.25;branch=z9hG4bK131597f4;rport=5060 From: "anon" ;tag=as297ba3fa To: ;tag=1775654741 Call-ID: 7059ab55508465502ca3d05a79b1c5da@172.16.0.25 CSeq: 103 INVITE Contact: Allow: INVITE,ACK,PRACK,SUBSCRIBE,BYE,CANCEL,NOTIFY,INFO,REFER,UPDATE Supported: timer Content-Type: application/sdp Content-Length: 343 v=0 o=- 45513 2 IN IP4 172.16.0.20 s=Cisco SDP 0 c=IN IP4 172.16.0.20 t=0 0 m=audio 20058 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 <-------------> [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 0: SIP/2.0 200 Ok (14) [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 1: Via: SIP/2.0/UDP 172.16.0.25:5060;received=172.16.0.25;branch=z9hG4bK131597f4;rport=5060 (86) [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 2: From: "anon" ;tag=as297ba3fa (55) [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 3: To: ;tag=1775654741 (46) [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 4: Call-ID: 7059ab55508465502ca3d05a79b1c5da@172.16.0.25 (52) [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 5: CSeq: 103 INVITE (16) [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 6: Contact: (55) [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 7: Allow: INVITE,ACK,PRACK,SUBSCRIBE,BYE,CANCEL,NOTIFY,INFO,REFER,UPDATE (69) [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 8: Supported: timer (16) [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 9: Content-Type: application/sdp (29) [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 10: Content-Length: 343 (19) [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 11: (0) [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: v=0 (3) [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: o=- 45513 2 IN IP4 172.16.0.20 (29) [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: s=Cisco SDP 0 (13) [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: c=IN IP4 172.16.0.20 (19) [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: t=0 0 (5) [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: m=audio 20058 RTP/AVP 8 101 100 (31) [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: a=fmtp:101 0-15 (15) [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: a=rtpmap:100 X-NSE/8000 (23) [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: a=fmtp:100 200-202 (18) [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: a=X-sqn:0 (9) [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: a=X-cap: 1 audio RTP/AVP 100 (28) [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: a=X-cpar: a=rtpmap:100 X-NSE/8000 (33) [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: a=X-cpar: a=fmtp:100 200-202 (28) [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: a=X-cap: 2 image udptl t38 (26) --- (11 headers 15 lines) --- [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4361 find_call: = Found Their Call ID: 7059ab55508465502ca3d05a79b1c5da@172.16.0.25 Their Tag 1775654741 Our tag: as297ba3fa [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:2071 __sip_ack: Acked pending invite 103 [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:2079 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #1297 [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:2089 __sip_ack: Stopping retransmission on '7059ab55508465502ca3d05a79b1c5da@172.16.0.25' of Request 103: Match Not Found [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:11639 handle_response_invite: SIP response 200 to RE-invite on outgoing call 7059ab55508465502ca3d05a79b1c5da@172.16.0.25 Found RTP audio format 8 Found RTP audio format 101 Found RTP audio format 100 [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4899 process_sdp: Peer doesn't provide T.38 UDPTL Peer audio RTP is at port 172.16.0.20:20058 Found description format telephone-event for ID 101 Got unsupported a:fmtp in SDP offer Found description format X-NSE for ID 100 Got unsupported a:fmtp in SDP offer [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:5129 process_sdp: T38 state changed to 0 on channel SIP/172.16.0.20-081d5580 Capabilities: us - 0x40a (gsm|alaw|ilbc), peer - audio=0x8 (alaw)/video=0x0 (nothing), combined - 0x8 (alaw) Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) Peer audio RTP is at port 172.16.0.20:20058 [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:5209 process_sdp: We're settling with these formats: 0x8 (alaw) [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:5216 process_sdp: We have an owner, now see if we need to change this call [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:3003 update_call_counter: Updating call counter for outgoing call [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:7919 build_route: build_route: Retaining previous route: [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:5643 reqprep: Strict routing enforced for session 7059ab55508465502ca3d05a79b1c5da@172.16.0.25 set_destination: Parsing for address/port to send to set_destination: set destination to 172.16.0.20, port 5060 Transmitting (no NAT) to 172.16.0.20:5060: ACK sip:0435401601@172.16.0.20:5060;transport=udp SIP/2.0 Via: SIP/2.0/UDP 172.16.0.25:5060;branch=z9hG4bK4f7dacf2;rport From: "anon" ;tag=as297ba3fa To: ;tag=1775654741 Contact: Call-ID: 7059ab55508465502ca3d05a79b1c5da@172.16.0.25 CSeq: 103 ACK User-Agent: blabla.ch 1.4PBX Max-Forwards: 70 Content-Length: 0 --- anarki*CLI> <--- SIP read from 10.10.10.23:5061 ---> SIP/2.0 200 OK To: fax ;tag=61ce66b1d4446863o1 From: ;tag=as24f89e56 Call-ID: 84a4e749-194220ab@10.10.10.23 CSeq: 102 INVITE Via: SIP/2.0/UDP 172.16.0.25:5060;branch=z9hG4bK5a16ff73 Contact: fax Server: Linksys/SPA2102-3.3.6 Content-Length: 282 Content-Type: application/sdp v=0 o=- 415784 415784 IN IP4 10.10.10.23 s=- c=IN IP4 10.10.10.23 t=0 0 m=audio 16464 RTP/AVP 8 100 101 a=rtpmap:8 PCMA/8000 a=rtpmap:100 NSE/8000 a=fmtp:100 192-193 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=ptime:30 a=sendrecv a=silenceSupp:off - - - - <-------------> [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 0: SIP/2.0 200 OK (14) [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 1: To: fax ;tag=61ce66b1d4446863o1 (57) [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 2: From: ;tag=as24f89e56 (48) [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 3: Call-ID: 84a4e749-194220ab@10.10.10.23 (40) [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 4: CSeq: 102 INVITE (16) [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 5: Via: SIP/2.0/UDP 172.16.0.25:5060;branch=z9hG4bK5a16ff73 (55) [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 6: Contact: fax (47) [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 7: Server: Linksys/SPA2102-3.3.6 (29) [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 8: Content-Length: 282 (19) [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 9: Content-Type: application/sdp (29) [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 10: (0) [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: v=0 (3) [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: o=- 415784 415784 IN IP4 10.10.10.23 (38) [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: s=- (3) [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: c=IN IP4 10.10.10.23 (22) [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: t=0 0 (5) [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: m=audio 16464 RTP/AVP 8 100 101 (31) [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: a=rtpmap:8 PCMA/8000 (20) [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: a=rtpmap:100 NSE/8000 (21) [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: a=fmtp:100 192-193 (18) [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: a=fmtp:101 0-15 (15) [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: a=ptime:30 (10) [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: a=sendrecv (10) [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: a=silenceSupp:off - - - - (25) --- (10 headers 14 lines) --- [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4361 find_call: = No match Their Call ID: 7059ab55508465502ca3d05a79b1c5da@172.16.0.25 Their Tag 1775654741 Our tag: as297ba3fa [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4361 find_call: = Found Their Call ID: 84a4e749-194220ab@10.10.10.23 Their Tag 61ce66b1d4446863o1 Our tag: as24f89e56 [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:2071 __sip_ack: Acked pending invite 102 [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:2079 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #1298 [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:2089 __sip_ack: Stopping retransmission on '84a4e749-194220ab@10.10.10.23' of Request 102: Match Not Found [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:11639 handle_response_invite: SIP response 200 to RE-invite on outgoing call 84a4e749-194220ab@10.10.10.23 Found RTP audio format 8 Found RTP audio format 100 Found RTP audio format 101 [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:4899 process_sdp: Peer doesn't provide T.38 UDPTL Peer audio RTP is at port 10.10.10.23:16464 Found description format PCMA for ID 8 Found description format NSE for ID 100 Got unsupported a:fmtp in SDP offer Found description format telephone-event for ID 101 Got unsupported a:fmtp in SDP offer [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:5129 process_sdp: T38 state changed to 0 on channel SIP/12345011-081d1618 Capabilities: us - 0xa (gsm|alaw), peer - audio=0x8 (alaw)/video=0x0 (nothing), combined - 0x8 (alaw) Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) Peer audio RTP is at port 10.10.10.23:16464 [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:5209 process_sdp: We're settling with these formats: 0x8 (alaw) [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:5216 process_sdp: We have an owner, now see if we need to change this call [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:3003 update_call_counter: Updating call counter for incoming call [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:7980 build_route: build_route: Contact hop: fax list_route: hop: [Mar 29 13:06:28] DEBUG[2735]: chan_sip.c:5643 reqprep: Strict routing enforced for session 84a4e749-194220ab@10.10.10.23 set_destination: Parsing for address/port to send to set_destination: set destination to 10.10.10.23, port 5061 Transmitting (NAT) to 10.10.10.23:5061: ACK sip:12345011@10.10.10.23:5061 SIP/2.0 Via: SIP/2.0/UDP 172.16.0.25:5060;branch=z9hG4bK2945cb46;rport From: ;tag=as24f89e56 To: fax ;tag=61ce66b1d4446863o1 Contact: Call-ID: 84a4e749-194220ab@10.10.10.23 CSeq: 102 ACK User-Agent: blabla.ch 1.4PBX Max-Forwards: 70 Content-Length: 0 --- anarki*CLI> <--- SIP read from 172.16.0.20:5060 ---> INVITE sip:012345011@172.16.0.25 SIP/2.0 Via: SIP/2.0/UDP 172.16.0.20:5060;branch=z9hG4bKmuuav0100ggg6coqv681sb0000g00.1 From: ;tag=1775654741 To: "anon" ;tag=as297ba3fa Call-ID: 7059ab55508465502ca3d05a79b1c5da@172.16.0.25 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: 238 v=0 o=- 45513 3 IN IP4 172.16.0.20 s=Cisco SDP 0 c=IN IP4 172.16.0.20 t=0 0 m=image 20058 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 <-------------> [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 0: INVITE sip:012345011@172.16.0.25 SIP/2.0 (40) [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 1: Via: SIP/2.0/UDP 172.16.0.20:5060;branch=z9hG4bKmuuav0100ggg6coqv681sb0000g00.1 (78) [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 2: From: ;tag=1775654741 (48) [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 3: To: "anon" ;tag=as297ba3fa (53) [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 4: Call-ID: 7059ab55508465502ca3d05a79b1c5da@172.16.0.25 (52) [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 5: CSeq: 1 INVITE (14) [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 6: Supported: timer (16) [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 7: Contact: (59) [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 8: Allow: INVITE,ACK,PRACK,SUBSCRIBE,BYE,CANCEL,NOTIFY,INFO,REFER,UPDATE (69) [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 9: Max-Forwards: 69 (16) [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 10: Content-Type: application/sdp (29) [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 11: Content-Length: 238 (19) [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 12: (0) [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: v=0 (3) [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: o=- 45513 3 IN IP4 172.16.0.20 (29) [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: s=Cisco SDP 0 (13) [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: c=IN IP4 172.16.0.20 (19) [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: t=0 0 (5) [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: m=image 20058 udptl t38 (23) [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: a=X-sqn:0 (9) [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: a=X-cap: 1 audio RTP/AVP 100 (28) [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: a=X-cpar: a=rtpmap:100 X-NSE/8000 (33) [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: a=X-cpar: a=fmtp:100 200-202 (28) [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: a=X-cap: 2 image udptl t38 (26) --- (12 headers 11 lines) --- [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:4361 find_call: = Found Their Call ID: 7059ab55508465502ca3d05a79b1c5da@172.16.0.25 Their Tag 1775654741 Our tag: as297ba3fa [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:14633 handle_request: **** Received INVITE (5) - Command in SIP INVITE [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:1680 parse_sip_options: Begin: parsing SIP "Supported: timer" [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:1688 parse_sip_options: Found SIP option: -timer- [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:1694 parse_sip_options: Matched SIP option: timer Sending to 172.16.0.20 : 5060 (no NAT) Got T.38 offer in SDP in dialog 7059ab55508465502ca3d05a79b1c5da@172.16.0.25 [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:4841 process_sdp: T38 state changed to 4 on channel SIP/172.16.0.20-081d5580 [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:4895 process_sdp: Peer T.38 UDPTL is at port 172.16.0.20:20058 Got T.38 Re-invite without audio. Keeping RTP active during T.38 session. Callid 7059ab55508465502ca3d05a79b1c5da@172.16.0.25 [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:5122 process_sdp: Our T38 capability = (3856), peer T38 capability (0), joint T38 capability (3856) Capabilities: us - 0x40a (gsm|alaw|ilbc), peer - audio=0x0 (nothing)/video=0x0 (nothing), combined - 0x0 (nothing) Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x0 (nothing), combined - 0x0 (nothing) [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:5164 process_sdp: Have T.38 but no audio codecs, accepting offer anyway [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:13454 handle_request_invite: Got a SIP re-invite for call 7059ab55508465502ca3d05a79b1c5da@172.16.0.25 [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:13549 handle_request_invite: SIP/172.16.0.20-081d5580: This call is UP.... [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:16754 sip_handle_t38_reinvite: Sending reinvite on SIP '84a4e749-194220ab@10.10.10.23' - It's UDPTL soon redirected to IP 172.16.0.20:20058 [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:5643 reqprep: Strict routing enforced for session 84a4e749-194220ab@10.10.10.23 set_destination: Parsing for address/port to send to set_destination: set destination to 10.10.10.23, port 5061 [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:6042 add_t38_sdp: T.38 UDPTL is at 172.16.0.25 port 4881 [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:6048 add_t38_sdp: Our T38 capability (3856), peer T38 capability (3856), joint capability (3856) [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:5975 t38_get_rate: T38MaxFaxRate 9600 found [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:1621 initialize_initreq: Initializing already initialized SIP dialog 84a4e749-194220ab@10.10.10.23 (presumably reinvite) [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 0: INVITE sip:12345011@10.10.10.23:5061 SIP/2.0 (47) [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 1: Via: SIP/2.0/UDP 172.16.0.25:5060;branch=z9hG4bK157ba63c;rport (61) [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 2: From: ;tag=as24f89e56 (48) [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 3: To: fax ;tag=61ce66b1d4446863o1 (57) [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 4: Contact: (36) [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 5: Call-ID: 84a4e749-194220ab@10.10.10.23 (40) [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 6: CSeq: 103 INVITE (16) [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 7: User-Agent: blabla.ch 1.4PBX (26) [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 8: Max-Forwards: 70 (16) [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 9: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 10: Supported: replaces (19) [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 11: X-asterisk-info: SIP re-invite (T38 switchover) (47) [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 12: Content-Type: application/sdp (29) [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 13: Content-Length: 339 (19) [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 14: (0) [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: v=0 (3) [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: o=root 14946 14949 IN IP4 172.16.0.20 (36) [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: s=session (9) [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: c=IN IP4 172.16.0.20 (19) [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: t=0 0 (5) [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: m=image 20058 udptl t38 (23) [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: a=T38FaxVersion:0 (17) [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: a=T38MaxBitRate:9600 (20) [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: a=T38FaxFillBitRemoval:0 (24) [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: a=T38FaxTranscodingMMR:0 (24) [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: a=T38FaxTranscodingJBIG:0 (25) [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: a=T38FaxRateManagement:transferredTCF (37) [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: a=T38FaxMaxBuffer:400 (21) [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: a=T38FaxMaxDatagram:400 (23) [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: a=T38FaxUdpEC:t38UDPFEC (23) Reliably Transmitting (NAT) to 10.10.10.23:5061: INVITE sip:12345011@10.10.10.23:5061 SIP/2.0 Via: SIP/2.0/UDP 172.16.0.25:5060;branch=z9hG4bK157ba63c;rport From: ;tag=as24f89e56 To: fax ;tag=61ce66b1d4446863o1 Contact: Call-ID: 84a4e749-194220ab@10.10.10.23 CSeq: 103 INVITE User-Agent: blabla.ch 1.4PBX Max-Forwards: 70 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces X-asterisk-info: SIP re-invite (T38 switchover) Content-Type: application/sdp Content-Length: 339 v=0 o=root 14946 14949 IN IP4 172.16.0.20 s=session c=IN IP4 172.16.0.20 t=0 0 m=image 20058 udptl t38 a=T38FaxVersion:0 a=T38MaxBitRate:9600 a=T38FaxFillBitRemoval:0 a=T38FaxTranscodingMMR:0 a=T38FaxTranscodingJBIG:0 a=T38FaxRateManagement:transferredTCF a=T38FaxMaxBuffer:400 a=T38FaxMaxDatagram:400 a=T38FaxUdpEC:t38UDPFEC --- [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:1975 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #1299 anarki*CLI> <--- SIP read from 10.10.10.23:5061 ---> SIP/2.0 200 OK To: fax ;tag=61ce66b1d4446863o1 From: ;tag=as24f89e56 Call-ID: 84a4e749-194220ab@10.10.10.23 CSeq: 103 INVITE Via: SIP/2.0/UDP 172.16.0.25:5060;branch=z9hG4bK157ba63c Contact: fax Server: Linksys/SPA2102-3.3.6 Content-Length: 267 Content-Type: application/sdp v=0 o=- 416406 416406 IN IP4 10.10.10.23 s=- c=IN IP4 10.10.10.23 t=0 0 m=image 16464 udptl t38 a=T38FaxVersion:0 a=T38MaxBitRate:14400 a=T38FaxRateManagement:transferredTCF a=T38FaxMaxBuffer:200 a=T38FaxMaxDatagram:200 a=T38FaxUdpEC:t38UDPRedundancy <-------------> [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 0: SIP/2.0 200 OK (14) [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 1: To: fax ;tag=61ce66b1d4446863o1 (57) [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 2: From: ;tag=as24f89e56 (48) [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 3: Call-ID: 84a4e749-194220ab@10.10.10.23 (40) [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 4: CSeq: 103 INVITE (16) [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 5: Via: SIP/2.0/UDP 172.16.0.25:5060;branch=z9hG4bK157ba63c (55) [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 6: Contact: fax (47) [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 7: Server: Linksys/SPA2102-3.3.6 (29) [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 8: Content-Length: 267 (19) [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 9: Content-Type: application/sdp (29) [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 10: (0) [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: v=0 (3) [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: o=- 416406 416406 IN IP4 10.10.10.23 (38) [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: s=- (3) [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: c=IN IP4 10.10.10.23 (22) [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: t=0 0 (5) [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: m=image 16464 udptl t38 (23) [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: a=T38FaxVersion:0 (17) [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: a=T38MaxBitRate:14400 (21) [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: a=T38FaxRateManagement:transferredTCF (37) [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: a=T38FaxMaxBuffer:200 (21) [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: a=T38FaxMaxDatagram:200 (23) [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: a=T38FaxUdpEC:t38UDPRedundancy (30) --- (10 headers 12 lines) --- [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:4361 find_call: = No match Their Call ID: 7059ab55508465502ca3d05a79b1c5da@172.16.0.25 Their Tag 1775654741 Our tag: as297ba3fa [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:4361 find_call: = Found Their Call ID: 84a4e749-194220ab@10.10.10.23 Their Tag 61ce66b1d4446863o1 Our tag: as24f89e56 [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:2071 __sip_ack: Acked pending invite 103 [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:2079 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #1299 [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:2089 __sip_ack: Stopping retransmission on '84a4e749-194220ab@10.10.10.23' of Request 103: Match Not Found [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:11639 handle_response_invite: SIP response 200 to RE-invite on outgoing call 84a4e749-194220ab@10.10.10.23 Got T.38 offer in SDP in dialog 84a4e749-194220ab@10.10.10.23 [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:4841 process_sdp: T38 state changed to 4 on channel SIP/12345011-081d1618 [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:4895 process_sdp: Peer T.38 UDPTL is at port 10.10.10.23:16464 Got T.38 Re-invite without audio. Keeping RTP active during T.38 session. Callid 84a4e749-194220ab@10.10.10.23 [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:5061 process_sdp: FaxVersion: 0 [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:5037 process_sdp: T38MaxBitRate: 14400 [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:5094 process_sdp: RateMangement: transferredTCF [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:5033 process_sdp: MaxBufferSize:200 [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:5069 process_sdp: FaxMaxDatagram: 200 [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:5102 process_sdp: UDP EC: t38UDPRedundancy [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:5122 process_sdp: Our T38 capability = (3856), peer T38 capability (16160), joint T38 capability (3872) Capabilities: us - 0xa (gsm|alaw), peer - audio=0x0 (nothing)/video=0x0 (nothing), combined - 0x0 (nothing) Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x0 (nothing), combined - 0x0 (nothing) [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:5164 process_sdp: Have T.38 but no audio codecs, accepting offer anyway [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:3003 update_call_counter: Updating call counter for incoming call [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:7919 build_route: build_route: Retaining previous route: [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:16782 sip_handle_t38_reinvite: Responding 200 OK on SIP '7059ab55508465502ca3d05a79b1c5da@172.16.0.25' - It's UDPTL soon redirected to IP 10.10.10.23:16464 [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:16789 sip_handle_t38_reinvite: T38 changed state to 5 on channel SIP/12345011-081d1618 [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:16790 sip_handle_t38_reinvite: T38 changed state to 5 on channel SIP/172.16.0.20-081d5580 [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:6042 add_t38_sdp: T.38 UDPTL is at 172.16.0.25 port 4101 [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:6048 add_t38_sdp: Our T38 capability (3856), peer T38 capability (3872), joint capability (3872) [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:5975 t38_get_rate: T38MaxFaxRate 9600 found <--- Reliably Transmitting (no NAT) to 172.16.0.20:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 172.16.0.20:5060;branch=z9hG4bKmuuav0100ggg6coqv681sb0000g00.1;received=172.16.0.20 From: ;tag=1775654741 To: "anon" ;tag=as297ba3fa Call-ID: 7059ab55508465502ca3d05a79b1c5da@172.16.0.25 CSeq: 1 INVITE User-Agent: blabla.ch 1.4PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Type: application/sdp Content-Length: 352 v=0 o=root 14946 14948 IN IP4 10.10.10.23 s=session c=IN IP4 10.10.10.23 t=0 0 m=image 16464 udptl t38 a=T38FaxVersion:0 a=T38MaxBitRate:9600 a=T38FaxFillBitRemoval:0 a=T38FaxTranscodingMMR:0 a=T38FaxTranscodingJBIG:0 a=T38FaxRateManagement:transferredTCF a=T38FaxMaxBuffer:200 a=T38FaxMaxDatagram:200 a=T38FaxUdpEC:t38UDPRedundancy <------------> [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:1975 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #1300 [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:5643 reqprep: Strict routing enforced for session 84a4e749-194220ab@10.10.10.23 set_destination: Parsing for address/port to send to set_destination: set destination to 10.10.10.23, port 5061 Transmitting (NAT) to 10.10.10.23:5061: ACK sip:12345011@10.10.10.23:5061 SIP/2.0 Via: SIP/2.0/UDP 172.16.0.25:5060;branch=z9hG4bK1b2ce78d;rport From: ;tag=as24f89e56 To: fax ;tag=61ce66b1d4446863o1 Contact: Call-ID: 84a4e749-194220ab@10.10.10.23 CSeq: 103 ACK User-Agent: blabla.ch 1.4PBX Max-Forwards: 70 Content-Length: 0 --- anarki*CLI> <--- SIP read from 172.16.0.20:5060 ---> ACK sip:012345011@172.16.0.25 SIP/2.0 Via: SIP/2.0/UDP 172.16.0.20:5060;branch=z9hG4bKmuuav0100ggg6coqv681sc0000g00.1 From: ;tag=1775654741 To: "anon" ;tag=as297ba3fa Call-ID: 7059ab55508465502ca3d05a79b1c5da@172.16.0.25 CSeq: 1 ACK Content-Length: 0 Max-Forwards: 70 <-------------> [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 0: ACK sip:012345011@172.16.0.25 SIP/2.0 (37) [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 1: Via: SIP/2.0/UDP 172.16.0.20:5060;branch=z9hG4bKmuuav0100ggg6coqv681sc0000g00.1 (78) [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 2: From: ;tag=1775654741 (48) [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 3: To: "anon" ;tag=as297ba3fa (53) [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 4: Call-ID: 7059ab55508465502ca3d05a79b1c5da@172.16.0.25 (52) [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 5: CSeq: 1 ACK (11) [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 6: Content-Length: 0 (17) [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 7: Max-Forwards: 70 (16) [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 8: (0) --- (8 headers 0 lines) --- [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:4361 find_call: = Found Their Call ID: 7059ab55508465502ca3d05a79b1c5da@172.16.0.25 Their Tag 1775654741 Our tag: as297ba3fa [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:14633 handle_request: **** Received ACK (6) - Command in SIP ACK [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:2079 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #1300 [Mar 29 13:06:34] DEBUG[2735]: chan_sip.c:2089 __sip_ack: Stopping retransmission on '7059ab55508465502ca3d05a79b1c5da@172.16.0.25' of Response 1: Match Not Found anarki*CLI> <--- SIP read from 10.10.10.23:5060 ---> NOTIFY sip:172.16.0.25 SIP/2.0 Via: SIP/2.0/UDP 10.10.10.23:5060;branch=z9hG4bK-9aa1b07a From: alx ;tag=82a91f60f0afa1ado0 To: Call-ID: edc685a6-17ad004d@10.10.10.23 CSeq: 276 NOTIFY Max-Forwards: 70 Event: keep-alive User-Agent: Linksys/SPA2102-3.3.6 Content-Length: 0 <-------------> [Mar 29 13:06:35] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 0: NOTIFY sip:172.16.0.25 SIP/2.0 (29) [Mar 29 13:06:35] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 1: Via: SIP/2.0/UDP 10.10.10.23:5060;branch=z9hG4bK-9aa1b07a (59) [Mar 29 13:06:35] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 2: From: alx ;tag=82a91f60f0afa1ado0 (59) [Mar 29 13:06:35] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 3: To: (20) [Mar 29 13:06:35] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 4: Call-ID: edc685a6-17ad004d@10.10.10.23 (40) [Mar 29 13:06:35] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 5: CSeq: 276 NOTIFY (16) [Mar 29 13:06:35] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 6: Max-Forwards: 70 (16) [Mar 29 13:06:35] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 7: Event: keep-alive (17) [Mar 29 13:06:35] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 8: User-Agent: Linksys/SPA2102-3.3.6 (33) [Mar 29 13:06:35] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 9: Content-Length: 0 (17) [Mar 29 13:06:35] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 10: (0) --- (10 headers 0 lines) --- [Mar 29 13:06:35] DEBUG[2735]: chan_sip.c:4361 find_call: = No match Their Call ID: 7059ab55508465502ca3d05a79b1c5da@172.16.0.25 Their Tag 1775654741 Our tag: as297ba3fa [Mar 29 13:06:35] DEBUG[2735]: chan_sip.c:4361 find_call: = No match Their Call ID: 84a4e749-194220ab@10.10.10.23 Their Tag 61ce66b1d4446863o1 Our tag: as24f89e56 anarki*CLI> <--- Transmitting (no NAT) to 10.10.10.23:5060 ---> SIP/2.0 489 Bad event Via: SIP/2.0/UDP 10.10.10.23:5060;branch=z9hG4bK-9aa1b07a;received=10.10.10.23 From: alx ;tag=82a91f60f0afa1ado0 To: ;tag=as63df2b4c Call-ID: edc685a6-17ad004d@10.10.10.23 CSeq: 276 NOTIFY User-Agent: blabla.ch 1.4PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Content-Length: 0 <------------> [Mar 29 13:06:35] DEBUG[2735]: chan_sip.c:14817 sipsock_read: Invalid SIP message - rejected , no callid, len 328 anarki*CLI> <--- SIP read from 10.10.10.23:5061 ---> NOTIFY sip:172.16.0.25 SIP/2.0 Via: SIP/2.0/UDP 10.10.10.23:5061;branch=z9hG4bK-899c0729 From: fax ;tag=d2bd39c8aad00a65o1 To: Call-ID: 3258edd2-a37bd611@10.10.10.23 CSeq: 276 NOTIFY Max-Forwards: 70 Event: keep-alive User-Agent: Linksys/SPA2102-3.3.6 Content-Length: 0 <-------------> [Mar 29 13:06:35] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 0: NOTIFY sip:172.16.0.25 SIP/2.0 (29) [Mar 29 13:06:35] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 1: Via: SIP/2.0/UDP 10.10.10.23:5061;branch=z9hG4bK-899c0729 (59) [Mar 29 13:06:35] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 2: From: fax ;tag=d2bd39c8aad00a65o1 (59) [Mar 29 13:06:35] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 3: To: (20) [Mar 29 13:06:35] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 4: Call-ID: 3258edd2-a37bd611@10.10.10.23 (40) [Mar 29 13:06:35] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 5: CSeq: 276 NOTIFY (16) [Mar 29 13:06:35] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 6: Max-Forwards: 70 (16) [Mar 29 13:06:35] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 7: Event: keep-alive (17) [Mar 29 13:06:35] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 8: User-Agent: Linksys/SPA2102-3.3.6 (33) [Mar 29 13:06:35] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 9: Content-Length: 0 (17) [Mar 29 13:06:35] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 10: (0) --- (10 headers 0 lines) --- [Mar 29 13:06:35] DEBUG[2735]: chan_sip.c:4361 find_call: = No match Their Call ID: 7059ab55508465502ca3d05a79b1c5da@172.16.0.25 Their Tag 1775654741 Our tag: as297ba3fa [Mar 29 13:06:35] DEBUG[2735]: chan_sip.c:4361 find_call: = No match Their Call ID: 84a4e749-194220ab@10.10.10.23 Their Tag 61ce66b1d4446863o1 Our tag: as24f89e56 anarki*CLI> <--- Transmitting (no NAT) to 10.10.10.23:5061 ---> SIP/2.0 489 Bad event Via: SIP/2.0/UDP 10.10.10.23:5061;branch=z9hG4bK-899c0729;received=10.10.10.23 From: fax ;tag=d2bd39c8aad00a65o1 To: ;tag=as0fcb575b Call-ID: 3258edd2-a37bd611@10.10.10.23 CSeq: 276 NOTIFY User-Agent: blabla.ch 1.4PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Content-Length: 0 <------------> [Mar 29 13:06:35] DEBUG[2735]: chan_sip.c:14817 sipsock_read: Invalid SIP message - rejected , no callid, len 328 anarki*CLI> <--- SIP read from 10.10.10.23:5060 ---> NOTIFY sip:172.16.0.25 SIP/2.0 Via: SIP/2.0/UDP 10.10.10.23:5060;branch=z9hG4bK-7e428e22 From: alx ;tag=82a91f60f0afa1ado0 To: Call-ID: edc685a6-17ad004d@10.10.10.23 CSeq: 277 NOTIFY Max-Forwards: 70 Event: keep-alive User-Agent: Linksys/SPA2102-3.3.6 Content-Length: 0 <-------------> [Mar 29 13:06:50] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 0: NOTIFY sip:172.16.0.25 SIP/2.0 (29) [Mar 29 13:06:50] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 1: Via: SIP/2.0/UDP 10.10.10.23:5060;branch=z9hG4bK-7e428e22 (59) [Mar 29 13:06:50] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 2: From: alx ;tag=82a91f60f0afa1ado0 (59) [Mar 29 13:06:50] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 3: To: (20) [Mar 29 13:06:50] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 4: Call-ID: edc685a6-17ad004d@10.10.10.23 (40) [Mar 29 13:06:50] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 5: CSeq: 277 NOTIFY (16) [Mar 29 13:06:50] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 6: Max-Forwards: 70 (16) [Mar 29 13:06:50] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 7: Event: keep-alive (17) [Mar 29 13:06:50] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 8: User-Agent: Linksys/SPA2102-3.3.6 (33) [Mar 29 13:06:50] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 9: Content-Length: 0 (17) [Mar 29 13:06:50] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 10: (0) --- (10 headers 0 lines) --- [Mar 29 13:06:50] DEBUG[2735]: chan_sip.c:4361 find_call: = No match Their Call ID: 7059ab55508465502ca3d05a79b1c5da@172.16.0.25 Their Tag 1775654741 Our tag: as297ba3fa [Mar 29 13:06:50] DEBUG[2735]: chan_sip.c:4361 find_call: = No match Their Call ID: 84a4e749-194220ab@10.10.10.23 Their Tag 61ce66b1d4446863o1 Our tag: as24f89e56 anarki*CLI> <--- Transmitting (no NAT) to 10.10.10.23:5060 ---> SIP/2.0 489 Bad event Via: SIP/2.0/UDP 10.10.10.23:5060;branch=z9hG4bK-7e428e22;received=10.10.10.23 From: alx ;tag=82a91f60f0afa1ado0 To: ;tag=as3ebd8ed8 Call-ID: edc685a6-17ad004d@10.10.10.23 CSeq: 277 NOTIFY User-Agent: blabla.ch 1.4PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Content-Length: 0 <------------> [Mar 29 13:06:50] DEBUG[2735]: chan_sip.c:14817 sipsock_read: Invalid SIP message - rejected , no callid, len 328 anarki*CLI> <--- SIP read from 10.10.10.23:5061 ---> NOTIFY sip:172.16.0.25 SIP/2.0 Via: SIP/2.0/UDP 10.10.10.23:5061;branch=z9hG4bK-85448b7f From: fax ;tag=d2bd39c8aad00a65o1 To: Call-ID: 3258edd2-a37bd611@10.10.10.23 CSeq: 277 NOTIFY Max-Forwards: 70 Event: keep-alive User-Agent: Linksys/SPA2102-3.3.6 Content-Length: 0 <-------------> [Mar 29 13:06:50] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 0: NOTIFY sip:172.16.0.25 SIP/2.0 (29) [Mar 29 13:06:50] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 1: Via: SIP/2.0/UDP 10.10.10.23:5061;branch=z9hG4bK-85448b7f (59) [Mar 29 13:06:50] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 2: From: fax ;tag=d2bd39c8aad00a65o1 (59) [Mar 29 13:06:50] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 3: To: (20) [Mar 29 13:06:50] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 4: Call-ID: 3258edd2-a37bd611@10.10.10.23 (40) [Mar 29 13:06:50] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 5: CSeq: 277 NOTIFY (16) [Mar 29 13:06:50] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 6: Max-Forwards: 70 (16) [Mar 29 13:06:50] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 7: Event: keep-alive (17) [Mar 29 13:06:50] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 8: User-Agent: Linksys/SPA2102-3.3.6 (33) [Mar 29 13:06:50] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 9: Content-Length: 0 (17) [Mar 29 13:06:50] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 10: (0) --- (10 headers 0 lines) --- [Mar 29 13:06:50] DEBUG[2735]: chan_sip.c:4361 find_call: = No match Their Call ID: 7059ab55508465502ca3d05a79b1c5da@172.16.0.25 Their Tag 1775654741 Our tag: as297ba3fa [Mar 29 13:06:50] DEBUG[2735]: chan_sip.c:4361 find_call: = No match Their Call ID: 84a4e749-194220ab@10.10.10.23 Their Tag 61ce66b1d4446863o1 Our tag: as24f89e56 anarki*CLI> <--- Transmitting (no NAT) to 10.10.10.23:5061 ---> SIP/2.0 489 Bad event Via: SIP/2.0/UDP 10.10.10.23:5061;branch=z9hG4bK-85448b7f;received=10.10.10.23 From: fax ;tag=d2bd39c8aad00a65o1 To: ;tag=as4fc51e77 Call-ID: 3258edd2-a37bd611@10.10.10.23 CSeq: 277 NOTIFY User-Agent: blabla.ch 1.4PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Content-Length: 0 <------------> [Mar 29 13:06:50] DEBUG[2735]: chan_sip.c:14817 sipsock_read: Invalid SIP message - rejected , no callid, len 328 anarki*CLI> <--- SIP read from 10.10.10.23:5060 ---> NOTIFY sip:172.16.0.25 SIP/2.0 Via: SIP/2.0/UDP 10.10.10.23:5060;branch=z9hG4bK-2cb8eba3 From: alx ;tag=82a91f60f0afa1ado0 To: Call-ID: edc685a6-17ad004d@10.10.10.23 CSeq: 278 NOTIFY Max-Forwards: 70 Event: keep-alive User-Agent: Linksys/SPA2102-3.3.6 Content-Length: 0 <-------------> [Mar 29 13:07:05] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 0: NOTIFY sip:172.16.0.25 SIP/2.0 (29) [Mar 29 13:07:05] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 1: Via: SIP/2.0/UDP 10.10.10.23:5060;branch=z9hG4bK-2cb8eba3 (59) [Mar 29 13:07:05] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 2: From: alx ;tag=82a91f60f0afa1ado0 (59) [Mar 29 13:07:05] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 3: To: (20) [Mar 29 13:07:05] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 4: Call-ID: edc685a6-17ad004d@10.10.10.23 (40) [Mar 29 13:07:05] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 5: CSeq: 278 NOTIFY (16) [Mar 29 13:07:05] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 6: Max-Forwards: 70 (16) [Mar 29 13:07:05] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 7: Event: keep-alive (17) [Mar 29 13:07:05] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 8: User-Agent: Linksys/SPA2102-3.3.6 (33) [Mar 29 13:07:05] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 9: Content-Length: 0 (17) [Mar 29 13:07:05] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 10: (0) --- (10 headers 0 lines) --- [Mar 29 13:07:05] DEBUG[2735]: chan_sip.c:4361 find_call: = No match Their Call ID: 7059ab55508465502ca3d05a79b1c5da@172.16.0.25 Their Tag 1775654741 Our tag: as297ba3fa [Mar 29 13:07:05] DEBUG[2735]: chan_sip.c:4361 find_call: = No match Their Call ID: 84a4e749-194220ab@10.10.10.23 Their Tag 61ce66b1d4446863o1 Our tag: as24f89e56 anarki*CLI> <--- Transmitting (no NAT) to 10.10.10.23:5060 ---> SIP/2.0 489 Bad event Via: SIP/2.0/UDP 10.10.10.23:5060;branch=z9hG4bK-2cb8eba3;received=10.10.10.23 From: alx ;tag=82a91f60f0afa1ado0 To: ;tag=as25678629 Call-ID: edc685a6-17ad004d@10.10.10.23 CSeq: 278 NOTIFY User-Agent: blabla.ch 1.4PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Content-Length: 0 <------------> [Mar 29 13:07:05] DEBUG[2735]: chan_sip.c:14817 sipsock_read: Invalid SIP message - rejected , no callid, len 328 anarki*CLI> <--- SIP read from 10.10.10.23:5061 ---> NOTIFY sip:172.16.0.25 SIP/2.0 Via: SIP/2.0/UDP 10.10.10.23:5061;branch=z9hG4bK-68f169cf From: fax ;tag=d2bd39c8aad00a65o1 To: Call-ID: 3258edd2-a37bd611@10.10.10.23 CSeq: 278 NOTIFY Max-Forwards: 70 Event: keep-alive User-Agent: Linksys/SPA2102-3.3.6 Content-Length: 0 <-------------> [Mar 29 13:07:05] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 0: NOTIFY sip:172.16.0.25 SIP/2.0 (29) [Mar 29 13:07:05] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 1: Via: SIP/2.0/UDP 10.10.10.23:5061;branch=z9hG4bK-68f169cf (59) [Mar 29 13:07:05] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 2: From: fax ;tag=d2bd39c8aad00a65o1 (59) [Mar 29 13:07:05] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 3: To: (20) [Mar 29 13:07:05] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 4: Call-ID: 3258edd2-a37bd611@10.10.10.23 (40) [Mar 29 13:07:05] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 5: CSeq: 278 NOTIFY (16) [Mar 29 13:07:05] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 6: Max-Forwards: 70 (16) [Mar 29 13:07:05] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 7: Event: keep-alive (17) [Mar 29 13:07:05] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 8: User-Agent: Linksys/SPA2102-3.3.6 (33) [Mar 29 13:07:05] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 9: Content-Length: 0 (17) [Mar 29 13:07:05] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 10: (0) --- (10 headers 0 lines) --- [Mar 29 13:07:05] DEBUG[2735]: chan_sip.c:4361 find_call: = No match Their Call ID: 7059ab55508465502ca3d05a79b1c5da@172.16.0.25 Their Tag 1775654741 Our tag: as297ba3fa [Mar 29 13:07:05] DEBUG[2735]: chan_sip.c:4361 find_call: = No match Their Call ID: 84a4e749-194220ab@10.10.10.23 Their Tag 61ce66b1d4446863o1 Our tag: as24f89e56 anarki*CLI> <--- Transmitting (no NAT) to 10.10.10.23:5061 ---> SIP/2.0 489 Bad event Via: SIP/2.0/UDP 10.10.10.23:5061;branch=z9hG4bK-68f169cf;received=10.10.10.23 From: fax ;tag=d2bd39c8aad00a65o1 To: ;tag=as19b136aa Call-ID: 3258edd2-a37bd611@10.10.10.23 CSeq: 278 NOTIFY User-Agent: blabla.ch 1.4PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Content-Length: 0 <------------> [Mar 29 13:07:05] DEBUG[2735]: chan_sip.c:14817 sipsock_read: Invalid SIP message - rejected , no callid, len 328 anarki*CLI> <--- SIP read from 10.10.10.23:5060 ---> NOTIFY sip:172.16.0.25 SIP/2.0 Via: SIP/2.0/UDP 10.10.10.23:5060;branch=z9hG4bK-b0612771 From: alx ;tag=82a91f60f0afa1ado0 To: Call-ID: edc685a6-17ad004d@10.10.10.23 CSeq: 279 NOTIFY Max-Forwards: 70 Event: keep-alive User-Agent: Linksys/SPA2102-3.3.6 Content-Length: 0 <-------------> [Mar 29 13:07:20] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 0: NOTIFY sip:172.16.0.25 SIP/2.0 (29) [Mar 29 13:07:20] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 1: Via: SIP/2.0/UDP 10.10.10.23:5060;branch=z9hG4bK-b0612771 (59) [Mar 29 13:07:20] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 2: From: alx ;tag=82a91f60f0afa1ado0 (59) [Mar 29 13:07:20] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 3: To: (20) [Mar 29 13:07:20] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 4: Call-ID: edc685a6-17ad004d@10.10.10.23 (40) [Mar 29 13:07:20] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 5: CSeq: 279 NOTIFY (16) [Mar 29 13:07:20] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 6: Max-Forwards: 70 (16) [Mar 29 13:07:20] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 7: Event: keep-alive (17) [Mar 29 13:07:20] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 8: User-Agent: Linksys/SPA2102-3.3.6 (33) [Mar 29 13:07:20] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 9: Content-Length: 0 (17) [Mar 29 13:07:20] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 10: (0) --- (10 headers 0 lines) --- [Mar 29 13:07:20] DEBUG[2735]: chan_sip.c:4361 find_call: = No match Their Call ID: 7059ab55508465502ca3d05a79b1c5da@172.16.0.25 Their Tag 1775654741 Our tag: as297ba3fa [Mar 29 13:07:20] DEBUG[2735]: chan_sip.c:4361 find_call: = No match Their Call ID: 84a4e749-194220ab@10.10.10.23 Their Tag 61ce66b1d4446863o1 Our tag: as24f89e56 anarki*CLI> <--- Transmitting (no NAT) to 10.10.10.23:5060 ---> SIP/2.0 489 Bad event Via: SIP/2.0/UDP 10.10.10.23:5060;branch=z9hG4bK-b0612771;received=10.10.10.23 From: alx ;tag=82a91f60f0afa1ado0 To: ;tag=as60b7bf42 Call-ID: edc685a6-17ad004d@10.10.10.23 CSeq: 279 NOTIFY User-Agent: blabla.ch 1.4PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Content-Length: 0 <------------> [Mar 29 13:07:20] DEBUG[2735]: chan_sip.c:14817 sipsock_read: Invalid SIP message - rejected , no callid, len 328 anarki*CLI> <--- SIP read from 10.10.10.23:5061 ---> NOTIFY sip:172.16.0.25 SIP/2.0 Via: SIP/2.0/UDP 10.10.10.23:5061;branch=z9hG4bK-f982b637 From: fax ;tag=d2bd39c8aad00a65o1 To: Call-ID: 3258edd2-a37bd611@10.10.10.23 CSeq: 279 NOTIFY Max-Forwards: 70 Event: keep-alive User-Agent: Linksys/SPA2102-3.3.6 Content-Length: 0 <-------------> [Mar 29 13:07:20] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 0: NOTIFY sip:172.16.0.25 SIP/2.0 (29) [Mar 29 13:07:20] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 1: Via: SIP/2.0/UDP 10.10.10.23:5061;branch=z9hG4bK-f982b637 (59) [Mar 29 13:07:20] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 2: From: fax ;tag=d2bd39c8aad00a65o1 (59) [Mar 29 13:07:20] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 3: To: (20) [Mar 29 13:07:20] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 4: Call-ID: 3258edd2-a37bd611@10.10.10.23 (40) [Mar 29 13:07:20] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 5: CSeq: 279 NOTIFY (16) [Mar 29 13:07:20] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 6: Max-Forwards: 70 (16) [Mar 29 13:07:20] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 7: Event: keep-alive (17) [Mar 29 13:07:20] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 8: User-Agent: Linksys/SPA2102-3.3.6 (33) [Mar 29 13:07:20] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 9: Content-Length: 0 (17) [Mar 29 13:07:20] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 10: (0) --- (10 headers 0 lines) --- [Mar 29 13:07:20] DEBUG[2735]: chan_sip.c:4361 find_call: = No match Their Call ID: 7059ab55508465502ca3d05a79b1c5da@172.16.0.25 Their Tag 1775654741 Our tag: as297ba3fa [Mar 29 13:07:20] DEBUG[2735]: chan_sip.c:4361 find_call: = No match Their Call ID: 84a4e749-194220ab@10.10.10.23 Their Tag 61ce66b1d4446863o1 Our tag: as24f89e56 anarki*CLI> <--- Transmitting (no NAT) to 10.10.10.23:5061 ---> SIP/2.0 489 Bad event Via: SIP/2.0/UDP 10.10.10.23:5061;branch=z9hG4bK-f982b637;received=10.10.10.23 From: fax ;tag=d2bd39c8aad00a65o1 To: ;tag=as5b9169da Call-ID: 3258edd2-a37bd611@10.10.10.23 CSeq: 279 NOTIFY User-Agent: blabla.ch 1.4PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Content-Length: 0 <------------> [Mar 29 13:07:20] DEBUG[2735]: chan_sip.c:14817 sipsock_read: Invalid SIP message - rejected , no callid, len 328 anarki*CLI> <--- SIP read from 172.16.0.20:5060 ---> BYE sip:012345011@172.16.0.25 SIP/2.0 Via: SIP/2.0/UDP 172.16.0.20:5060;branch=z9hG4bKmuuav0100ggg6coqv681sd0000010.1 From: ;tag=1775654741 To: "anon" ;tag=as297ba3fa Call-ID: 7059ab55508465502ca3d05a79b1c5da@172.16.0.25 CSeq: 2 BYE Supported: timer Content-Length: 0 Max-Forwards: 70 <-------------> [Mar 29 13:07:24] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 0: BYE sip:012345011@172.16.0.25 SIP/2.0 (37) [Mar 29 13:07:24] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 1: Via: SIP/2.0/UDP 172.16.0.20:5060;branch=z9hG4bKmuuav0100ggg6coqv681sd0000010.1 (78) [Mar 29 13:07:24] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 2: From: ;tag=1775654741 (48) [Mar 29 13:07:24] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 3: To: "anon" ;tag=as297ba3fa (53) [Mar 29 13:07:24] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 4: Call-ID: 7059ab55508465502ca3d05a79b1c5da@172.16.0.25 (52) [Mar 29 13:07:24] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 5: CSeq: 2 BYE (11) [Mar 29 13:07:24] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 6: Supported: timer (16) [Mar 29 13:07:24] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 7: Content-Length: 0 (17) [Mar 29 13:07:24] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 8: Max-Forwards: 70 (16) [Mar 29 13:07:24] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 9: (0) --- (9 headers 0 lines) --- [Mar 29 13:07:24] DEBUG[2735]: chan_sip.c:4361 find_call: = Found Their Call ID: 7059ab55508465502ca3d05a79b1c5da@172.16.0.25 Their Tag 1775654741 Our tag: as297ba3fa [Mar 29 13:07:24] DEBUG[2735]: chan_sip.c:14633 handle_request: **** Received BYE (8) - Command in SIP BYE Sending to 172.16.0.20 : 5060 (no NAT) [Mar 29 13:07:24] DEBUG[2735]: chan_sip.c:1633 sip_alreadygone: Setting SIP_ALREADYGONE on dialog 7059ab55508465502ca3d05a79b1c5da@172.16.0.25 [Mar 29 13:07:24] DEBUG[2735]: chan_sip.c:14190 handle_request_bye: Received bye, issuing owner hangup anarki*CLI> <--- Transmitting (no NAT) to 172.16.0.20:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 172.16.0.20:5060;branch=z9hG4bKmuuav0100ggg6coqv681sd0000010.1;received=172.16.0.20 From: ;tag=1775654741 To: "anon" ;tag=as297ba3fa Call-ID: 7059ab55508465502ca3d05a79b1c5da@172.16.0.25 CSeq: 2 BYE User-Agent: blabla.ch 1.4PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Length: 0 <------------> [Mar 29 13:07:24] DEBUG[14946]: rtp.c:2874 bridge_native_loop: Oooh, got a hangup [Mar 29 13:07:24] DEBUG[14946]: chan_sip.c:16907 sip_set_rtp_peer: Sending reinvite on SIP '84a4e749-194220ab@10.10.10.23' - It's audio soon redirected to IP 172.16.0.25 [Mar 29 13:07:24] DEBUG[14946]: chan_sip.c:5643 reqprep: Strict routing enforced for session 84a4e749-194220ab@10.10.10.23 set_destination: Parsing for address/port to send to set_destination: set destination to 10.10.10.23, port 5061 [Mar 29 13:07:24] DEBUG[14946]: chan_sip.c:6188 add_sdp: ** Our capability: 0x8 (alaw) Video flag: True [Mar 29 13:07:24] DEBUG[14946]: chan_sip.c:6189 add_sdp: ** Our prefcodec: 0x0 (nothing) Audio is at 172.16.0.25 port 19144 Adding codec 0x8 (alaw) to SDP Adding non-codec 0x1 (telephone-event) to SDP [Mar 29 13:07:24] DEBUG[14946]: chan_sip.c:6320 add_sdp: -- Done with adding codecs to SDP [Mar 29 13:07:24] DEBUG[14946]: channel.c:2381 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=29) [Mar 29 13:07:24] DEBUG[14946]: chan_sip.c:6365 add_sdp: Done building SDP. Settling with this capability: 0x8 (alaw) [Mar 29 13:07:24] DEBUG[14946]: chan_sip.c:1621 initialize_initreq: Initializing already initialized SIP dialog 84a4e749-194220ab@10.10.10.23 (presumably reinvite) [Mar 29 13:07:24] DEBUG[14946]: chan_sip.c:4573 parse_request: Header 0: INVITE sip:12345011@10.10.10.23:5061 SIP/2.0 (47) [Mar 29 13:07:24] DEBUG[14946]: chan_sip.c:4573 parse_request: Header 1: Via: SIP/2.0/UDP 172.16.0.25:5060;branch=z9hG4bK5006c1cd;rport (61) [Mar 29 13:07:24] DEBUG[14946]: chan_sip.c:4573 parse_request: Header 2: From: ;tag=as24f89e56 (48) [Mar 29 13:07:24] DEBUG[14946]: chan_sip.c:4573 parse_request: Header 3: To: fax ;tag=61ce66b1d4446863o1 (57) [Mar 29 13:07:24] DEBUG[14946]: chan_sip.c:4573 parse_request: Header 4: Contact: (36) [Mar 29 13:07:24] DEBUG[14946]: chan_sip.c:4573 parse_request: Header 5: Call-ID: 84a4e749-194220ab@10.10.10.23 (40) [Mar 29 13:07:24] DEBUG[14946]: chan_sip.c:4573 parse_request: Header 6: CSeq: 104 INVITE (16) [Mar 29 13:07:24] DEBUG[14946]: chan_sip.c:4573 parse_request: Header 7: User-Agent: blabla.ch 1.4PBX (26) [Mar 29 13:07:24] DEBUG[14946]: chan_sip.c:4573 parse_request: Header 8: Max-Forwards: 70 (16) [Mar 29 13:07:24] DEBUG[14946]: chan_sip.c:4573 parse_request: Header 9: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) [Mar 29 13:07:24] DEBUG[14946]: chan_sip.c:4573 parse_request: Header 10: Supported: replaces (19) [Mar 29 13:07:24] DEBUG[14946]: chan_sip.c:4573 parse_request: Header 11: X-asterisk-Info: SIP re-invite (External RTP bridge) (52) [Mar 29 13:07:24] DEBUG[14946]: chan_sip.c:4573 parse_request: Header 12: Content-Type: application/sdp (29) [Mar 29 13:07:24] DEBUG[14946]: chan_sip.c:4573 parse_request: Header 13: Content-Length: 236 (19) [Mar 29 13:07:24] DEBUG[14946]: chan_sip.c:4573 parse_request: Header 14: (0) [Mar 29 13:07:24] DEBUG[14946]: chan_sip.c:4605 parse_request: Line: v=0 (3) [Mar 29 13:07:24] DEBUG[14946]: chan_sip.c:4605 parse_request: Line: o=root 14946 14950 IN IP4 172.16.0.25 (36) [Mar 29 13:07:24] DEBUG[14946]: chan_sip.c:4605 parse_request: Line: s=session (9) [Mar 29 13:07:24] DEBUG[14946]: chan_sip.c:4605 parse_request: Line: c=IN IP4 172.16.0.25 (19) [Mar 29 13:07:24] DEBUG[14946]: chan_sip.c:4605 parse_request: Line: t=0 0 (5) [Mar 29 13:07:24] DEBUG[14946]: chan_sip.c:4605 parse_request: Line: m=audio 19144 RTP/AVP 8 101 (27) [Mar 29 13:07:24] DEBUG[14946]: chan_sip.c:4605 parse_request: Line: a=rtpmap:8 PCMA/8000 (20) [Mar 29 13:07:24] DEBUG[14946]: chan_sip.c:4605 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [Mar 29 13:07:24] DEBUG[14946]: chan_sip.c:4605 parse_request: Line: a=fmtp:101 0-16 (15) [Mar 29 13:07:24] DEBUG[14946]: chan_sip.c:4605 parse_request: Line: a=silenceSupp:off - - - - (25) [Mar 29 13:07:24] DEBUG[14946]: chan_sip.c:4605 parse_request: Line: a=ptime:20 (10) [Mar 29 13:07:24] DEBUG[14946]: chan_sip.c:4605 parse_request: Line: a=sendrecv (10) Reliably Transmitting (NAT) to 10.10.10.23:5061: INVITE sip:12345011@10.10.10.23:5061 SIP/2.0 Via: SIP/2.0/UDP 172.16.0.25:5060;branch=z9hG4bK5006c1cd;rport From: ;tag=as24f89e56 To: fax ;tag=61ce66b1d4446863o1 Contact: Call-ID: 84a4e749-194220ab@10.10.10.23 CSeq: 104 INVITE User-Agent: blabla.ch 1.4PBX Max-Forwards: 70 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces X-asterisk-Info: SIP re-invite (External RTP bridge) Content-Type: application/sdp Content-Length: 236 v=0 o=root 14946 14950 IN IP4 172.16.0.25 s=session c=IN IP4 172.16.0.25 t=0 0 m=audio 19144 RTP/AVP 8 101 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv --- [Mar 29 13:07:24] DEBUG[14946]: chan_sip.c:1975 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #1301 [Mar 29 13:07:24] DEBUG[14946]: channel.c:4048 ast_channel_bridge: Returning from native bridge, channels: SIP/12345011-081d1618, SIP/172.16.0.20-081d5580 [Mar 29 13:07:24] DEBUG[14946]: channel.c:1693 ast_hangup: Hanging up channel 'SIP/172.16.0.20-081d5580' [Mar 29 13:07:24] DEBUG[14946]: chan_sip.c:3312 sip_hangup: Hangup call SIP/172.16.0.20-081d5580, SIP callid 7059ab55508465502ca3d05a79b1c5da@172.16.0.25) [Mar 29 13:07:24] DEBUG[14946]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/172.16.0.20-081d5580 [Mar 29 13:07:24] DEBUG[2711]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 172.16.0.20 [Mar 29 13:07:24] DEBUG[2711]: chan_sip.c:15244 sip_devicestate: Checking device state for peer 172.16.0.20 [Mar 29 13:07:24] DEBUG[2711]: devicestate.c:287 do_state_change: Changing state for SIP/172.16.0.20 - state 1 (Not in use) [Mar 29 13:07:24] DEBUG[14951]: app_queue.c:546 changethread: Device 'SIP/172.16.0.20' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Mar 29 13:07:24] DEBUG[14946]: rtp.c:1476 ast_rtp_early_bridge: Channel '' has no RTP, not doing anything [Mar 29 13:07:24] DEBUG[14946]: app_dial.c:1670 dial_exec_full: Exiting with DIALSTATUS=ANSWER. [Mar 29 13:07:24] DEBUG[14946]: pbx.c:2393 __ast_pbx_run: Spawn extension (privileged-prod,0435401601,1) exited non-zero on 'SIP/12345011-081d1618' == Spawn extension (privileged-prod, 0435401601, 1) exited non-zero on 'SIP/12345011-081d1618' [Mar 29 13:07:24] DEBUG[14946]: pbx.c:1648 pbx_substitute_variables_helper_full: Function result is '"anon" <012345011>' [Mar 29 13:07:24] DEBUG[14946]: pbx.c:1648 pbx_substitute_variables_helper_full: Function result is '012345011' [Mar 29 13:07:24] DEBUG[14946]: pbx.c:1648 pbx_substitute_variables_helper_full: Function result is '0435401601' [Mar 29 13:07:24] DEBUG[14946]: pbx.c:1648 pbx_substitute_variables_helper_full: Function result is 'privileged-prod' [Mar 29 13:07:24] DEBUG[14946]: pbx.c:1648 pbx_substitute_variables_helper_full: Function result is 'SIP/12345011-081d1618' [Mar 29 13:07:24] DEBUG[14946]: pbx.c:1648 pbx_substitute_variables_helper_full: Function result is 'SIP/172.16.0.20-081d5580' [Mar 29 13:07:24] DEBUG[14946]: pbx.c:1648 pbx_substitute_variables_helper_full: Function result is 'Dial' [Mar 29 13:07:24] DEBUG[14946]: pbx.c:1648 pbx_substitute_variables_helper_full: Function result is 'SIP/0435401601@172.16.0.20' [Mar 29 13:07:24] DEBUG[14946]: pbx.c:1648 pbx_substitute_variables_helper_full: Function result is '2007-03-29 13:06:20' [Mar 29 13:07:24] DEBUG[14946]: pbx.c:1648 pbx_substitute_variables_helper_full: Function result is '2007-03-29 13:06:28' [Mar 29 13:07:24] DEBUG[14946]: pbx.c:1648 pbx_substitute_variables_helper_full: Function result is '2007-03-29 13:07:24' [Mar 29 13:07:24] DEBUG[14946]: pbx.c:1648 pbx_substitute_variables_helper_full: Function result is '64' [Mar 29 13:07:24] DEBUG[14946]: pbx.c:1648 pbx_substitute_variables_helper_full: Function result is '56' [Mar 29 13:07:24] DEBUG[14946]: pbx.c:1648 pbx_substitute_variables_helper_full: Function result is 'ANSWERED' [Mar 29 13:07:24] DEBUG[14946]: pbx.c:1648 pbx_substitute_variables_helper_full: Function result is 'DOCUMENTATION' [Mar 29 13:07:24] DEBUG[14946]: pbx.c:1648 pbx_substitute_variables_helper_full: Function result is '' [Mar 29 13:07:24] DEBUG[14946]: pbx.c:1648 pbx_substitute_variables_helper_full: Function result is '1175166380.16' [Mar 29 13:07:24] DEBUG[14946]: pbx.c:1648 pbx_substitute_variables_helper_full: Function result is '' [Mar 29 13:07:24] DEBUG[14946]: channel.c:1693 ast_hangup: Hanging up channel 'SIP/12345011-081d1618' [Mar 29 13:07:24] DEBUG[14946]: chan_sip.c:3312 sip_hangup: Hangup call SIP/12345011-081d1618, SIP callid 84a4e749-194220ab@10.10.10.23) Scheduling destruction of SIP dialog '84a4e749-194220ab@10.10.10.23' in 32000 ms (Method: ACK) [Mar 29 13:07:24] DEBUG[14946]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/12345011-081d1618 [Mar 29 13:07:24] DEBUG[2711]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 12345011 [Mar 29 13:07:24] DEBUG[2711]: chan_sip.c:15244 sip_devicestate: Checking device state for peer 12345011 [Mar 29 13:07:24] DEBUG[2711]: devicestate.c:287 do_state_change: Changing state for SIP/12345011 - state 1 (Not in use) [Mar 29 13:07:24] DEBUG[2711]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 12345011 [Mar 29 13:07:24] DEBUG[14952]: app_queue.c:546 changethread: Device 'SIP/12345011' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Mar 29 13:07:24] DEBUG[2711]: chan_sip.c:15244 sip_devicestate: Checking device state for peer 12345011 anarki*CLI> <--- SIP read from 10.10.10.23:5061 ---> SIP/2.0 200 OK To: fax ;tag=61ce66b1d4446863o1 From: ;tag=as24f89e56 Call-ID: 84a4e749-194220ab@10.10.10.23 CSeq: 104 INVITE Via: SIP/2.0/UDP 172.16.0.25:5060;branch=z9hG4bK5006c1cd Contact: fax Server: Linksys/SPA2102-3.3.6 Content-Length: 282 Content-Type: application/sdp v=0 o=- 421396 421396 IN IP4 10.10.10.23 s=- c=IN IP4 10.10.10.23 t=0 0 m=audio 16464 RTP/AVP 8 100 101 a=rtpmap:8 PCMA/8000 a=rtpmap:100 NSE/8000 a=fmtp:100 192-193 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=ptime:30 a=sendrecv a=silenceSupp:off - - - - <-------------> [Mar 29 13:07:24] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 0: SIP/2.0 200 OK (14) [Mar 29 13:07:24] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 1: To: fax ;tag=61ce66b1d4446863o1 (57) [Mar 29 13:07:24] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 2: From: ;tag=as24f89e56 (48) [Mar 29 13:07:24] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 3: Call-ID: 84a4e749-194220ab@10.10.10.23 (40) [Mar 29 13:07:24] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 4: CSeq: 104 INVITE (16) [Mar 29 13:07:24] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 5: Via: SIP/2.0/UDP 172.16.0.25:5060;branch=z9hG4bK5006c1cd (55) [Mar 29 13:07:24] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 6: Contact: fax (47) [Mar 29 13:07:24] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 7: Server: Linksys/SPA2102-3.3.6 (29) [Mar 29 13:07:24] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 8: Content-Length: 282 (19) [Mar 29 13:07:24] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 9: Content-Type: application/sdp (29) [Mar 29 13:07:24] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 10: (0) [Mar 29 13:07:24] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: v=0 (3) [Mar 29 13:07:24] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: o=- 421396 421396 IN IP4 10.10.10.23 (38) [Mar 29 13:07:24] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: s=- (3) [Mar 29 13:07:24] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: c=IN IP4 10.10.10.23 (22) [Mar 29 13:07:24] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: t=0 0 (5) [Mar 29 13:07:24] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: m=audio 16464 RTP/AVP 8 100 101 (31) [Mar 29 13:07:24] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: a=rtpmap:8 PCMA/8000 (20) [Mar 29 13:07:24] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: a=rtpmap:100 NSE/8000 (21) [Mar 29 13:07:24] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: a=fmtp:100 192-193 (18) [Mar 29 13:07:24] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [Mar 29 13:07:24] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: a=fmtp:101 0-15 (15) [Mar 29 13:07:24] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: a=ptime:30 (10) [Mar 29 13:07:24] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: a=sendrecv (10) [Mar 29 13:07:24] DEBUG[2735]: chan_sip.c:4605 parse_request: Line: a=silenceSupp:off - - - - (25) --- (10 headers 14 lines) --- [Mar 29 13:07:24] DEBUG[2735]: chan_sip.c:4361 find_call: = No match Their Call ID: 7059ab55508465502ca3d05a79b1c5da@172.16.0.25 Their Tag 1775654741 Our tag: as297ba3fa [Mar 29 13:07:24] DEBUG[2735]: chan_sip.c:4361 find_call: = Found Their Call ID: 84a4e749-194220ab@10.10.10.23 Their Tag 61ce66b1d4446863o1 Our tag: as24f89e56 [Mar 29 13:07:24] DEBUG[2735]: chan_sip.c:2071 __sip_ack: Acked pending invite 104 [Mar 29 13:07:24] DEBUG[2735]: chan_sip.c:2079 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #1301 [Mar 29 13:07:24] DEBUG[2735]: chan_sip.c:2089 __sip_ack: Stopping retransmission on '84a4e749-194220ab@10.10.10.23' of Request 104: Match Not Found [Mar 29 13:07:24] DEBUG[2735]: chan_sip.c:11641 handle_response_invite: SIP response 200 to standard invite Found RTP audio format 8 Found RTP audio format 100 Found RTP audio format 101 [Mar 29 13:07:24] DEBUG[2735]: chan_sip.c:4899 process_sdp: Peer doesn't provide T.38 UDPTL Peer audio RTP is at port 10.10.10.23:16464 Found description format PCMA for ID 8 Found description format NSE for ID 100 Got unsupported a:fmtp in SDP offer Found description format telephone-event for ID 101 Got unsupported a:fmtp in SDP offer [Mar 29 13:07:24] DEBUG[2735]: chan_sip.c:5129 process_sdp: T38 state changed to 0 on channel Capabilities: us - 0xa (gsm|alaw), peer - audio=0x8 (alaw)/video=0x0 (nothing), combined - 0x8 (alaw) Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) Peer audio RTP is at port 10.10.10.23:16464 [Mar 29 13:07:24] DEBUG[2735]: chan_sip.c:5209 process_sdp: We're settling with these formats: 0x8 (alaw) [Mar 29 13:07:24] DEBUG[2735]: chan_sip.c:3003 update_call_counter: Updating call counter for incoming call [Mar 29 13:07:24] DEBUG[2735]: chan_sip.c:7919 build_route: build_route: Retaining previous route: [Mar 29 13:07:24] DEBUG[2735]: chan_sip.c:5643 reqprep: Strict routing enforced for session 84a4e749-194220ab@10.10.10.23 set_destination: Parsing for address/port to send to set_destination: set destination to 10.10.10.23, port 5061 Transmitting (NAT) to 10.10.10.23:5061: ACK sip:12345011@10.10.10.23:5061 SIP/2.0 Via: SIP/2.0/UDP 172.16.0.25:5060;branch=z9hG4bK09af3228;rport From: ;tag=as24f89e56 To: fax ;tag=61ce66b1d4446863o1 Contact: Call-ID: 84a4e749-194220ab@10.10.10.23 CSeq: 104 ACK User-Agent: blabla.ch 1.4PBX Max-Forwards: 70 Content-Length: 0 --- [Mar 29 13:07:24] DEBUG[2735]: chan_sip.c:5643 reqprep: Strict routing enforced for session 84a4e749-194220ab@10.10.10.23 set_destination: Parsing for address/port to send to set_destination: set destination to 10.10.10.23, port 5061 Reliably Transmitting (NAT) to 10.10.10.23:5061: BYE sip:12345011@10.10.10.23:5061 SIP/2.0 Via: SIP/2.0/UDP 172.16.0.25:5060;branch=z9hG4bK6741c97c;rport From: ;tag=as24f89e56 To: fax ;tag=61ce66b1d4446863o1 Call-ID: 84a4e749-194220ab@10.10.10.23 CSeq: 105 BYE User-Agent: blabla.ch 1.4PBX Max-Forwards: 70 Content-Length: 0 --- [Mar 29 13:07:24] DEBUG[2735]: chan_sip.c:1975 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #1303 Scheduling destruction of SIP dialog '84a4e749-194220ab@10.10.10.23' in 32000 ms (Method: ACK) Really destroying SIP dialog '7059ab55508465502ca3d05a79b1c5da@172.16.0.25' Method: BYE anarki*CLI> <--- SIP read from 10.10.10.23:5061 ---> SIP/2.0 200 OK To: fax ;tag=61ce66b1d4446863o1 From: ;tag=as24f89e56 Call-ID: 84a4e749-194220ab@10.10.10.23 CSeq: 105 BYE Via: SIP/2.0/UDP 172.16.0.25:5060;branch=z9hG4bK6741c97c Server: Linksys/SPA2102-3.3.6 P-RTP-Stat: PS=708,OS=113124,PR=386,OR=61760,PL=0,JI=1,LA=67108863,DU=56,EN=G711a,DE=G711a Content-Length: 0 <-------------> [Mar 29 13:07:24] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 0: SIP/2.0 200 OK (14) [Mar 29 13:07:24] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 1: To: fax ;tag=61ce66b1d4446863o1 (57) [Mar 29 13:07:24] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 2: From: ;tag=as24f89e56 (48) [Mar 29 13:07:24] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 3: Call-ID: 84a4e749-194220ab@10.10.10.23 (40) [Mar 29 13:07:24] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 4: CSeq: 105 BYE (13) [Mar 29 13:07:24] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 5: Via: SIP/2.0/UDP 172.16.0.25:5060;branch=z9hG4bK6741c97c (55) [Mar 29 13:07:24] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 6: Server: Linksys/SPA2102-3.3.6 (29) [Mar 29 13:07:24] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 7: P-RTP-Stat: PS=708,OS=113124,PR=386,OR=61760,PL=0,JI=1,LA=67108863,DU=56,EN=G711a,DE=G711a (90) [Mar 29 13:07:24] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 8: Content-Length: 0 (17) [Mar 29 13:07:24] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 9: (0) --- (9 headers 0 lines) --- [Mar 29 13:07:24] DEBUG[2735]: chan_sip.c:4361 find_call: = Found Their Call ID: 84a4e749-194220ab@10.10.10.23 Their Tag 61ce66b1d4446863o1 Our tag: as24f89e56 [Mar 29 13:07:24] DEBUG[2735]: chan_sip.c:2079 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #1303 [Mar 29 13:07:24] DEBUG[2735]: chan_sip.c:2089 __sip_ack: Stopping retransmission on '84a4e749-194220ab@10.10.10.23' of Request 105: Match Not Found Really destroying SIP dialog '84a4e749-194220ab@10.10.10.23' Method: ACK anarki*CLI> <--- SIP read from 10.10.10.23:5060 ---> NOTIFY sip:172.16.0.25 SIP/2.0 Via: SIP/2.0/UDP 10.10.10.23:5060;branch=z9hG4bK-dfd60c08 From: alx ;tag=82a91f60f0afa1ado0 To: Call-ID: edc685a6-17ad004d@10.10.10.23 CSeq: 280 NOTIFY Max-Forwards: 70 Event: keep-alive User-Agent: Linksys/SPA2102-3.3.6 Content-Length: 0 <-------------> [Mar 29 13:07:35] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 0: NOTIFY sip:172.16.0.25 SIP/2.0 (29) [Mar 29 13:07:35] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 1: Via: SIP/2.0/UDP 10.10.10.23:5060;branch=z9hG4bK-dfd60c08 (59) [Mar 29 13:07:35] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 2: From: alx ;tag=82a91f60f0afa1ado0 (59) [Mar 29 13:07:35] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 3: To: (20) [Mar 29 13:07:35] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 4: Call-ID: edc685a6-17ad004d@10.10.10.23 (40) [Mar 29 13:07:35] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 5: CSeq: 280 NOTIFY (16) [Mar 29 13:07:35] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 6: Max-Forwards: 70 (16) [Mar 29 13:07:35] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 7: Event: keep-alive (17) [Mar 29 13:07:35] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 8: User-Agent: Linksys/SPA2102-3.3.6 (33) [Mar 29 13:07:35] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 9: Content-Length: 0 (17) [Mar 29 13:07:35] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 10: (0) --- (10 headers 0 lines) --- <--- Transmitting (no NAT) to 10.10.10.23:5060 ---> SIP/2.0 489 Bad event Via: SIP/2.0/UDP 10.10.10.23:5060;branch=z9hG4bK-dfd60c08;received=10.10.10.23 From: alx ;tag=82a91f60f0afa1ado0 To: ;tag=as2fcd0bf9 Call-ID: edc685a6-17ad004d@10.10.10.23 CSeq: 280 NOTIFY User-Agent: blabla.ch 1.4PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces ontent-Length: 0 <------------> [Mar 29 13:07:35] DEBUG[2735]: chan_sip.c:14817 sipsock_read: Invalid SIP message - rejected , no callid, len 328 anarki*CLI> <--- SIP read from 10.10.10.23:5061 ---> NOTIFY sip:172.16.0.25 SIP/2.0 Via: SIP/2.0/UDP 10.10.10.23:5061;branch=z9hG4bK-ee29c86b From: fax ;tag=d2bd39c8aad00a65o1 To: Call-ID: 3258edd2-a37bd611@10.10.10.23 CSeq: 280 NOTIFY Max-Forwards: 70 Event: keep-alive User-Agent: Linksys/SPA2102-3.3.6 Content-Length: 0 <-------------> [Mar 29 13:07:35] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 0: NOTIFY sip:172.16.0.25 SIP/2.0 (29) [Mar 29 13:07:35] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 1: Via: SIP/2.0/UDP 10.10.10.23:5061;branch=z9hG4bK-ee29c86b (59) [Mar 29 13:07:35] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 2: From: fax ;tag=d2bd39c8aad00a65o1 (59) [Mar 29 13:07:35] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 3: To: (20) [Mar 29 13:07:35] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 4: Call-ID: 3258edd2-a37bd611@10.10.10.23 (40) [Mar 29 13:07:35] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 5: CSeq: 280 NOTIFY (16) [Mar 29 13:07:35] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 6: Max-Forwards: 70 (16) [Mar 29 13:07:35] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 7: Event: keep-alive (17) [Mar 29 13:07:35] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 8: User-Agent: Linksys/SPA2102-3.3.6 (33) [Mar 29 13:07:35] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 9: Content-Length: 0 (17) [Mar 29 13:07:35] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 10: (0) --- (10 headers 0 lines) --- <--- Transmitting (no NAT) to 10.10.10.23:5061 ---> SIP/2.0 489 Bad event Via: SIP/2.0/UDP 10.10.10.23:5061;branch=z9hG4bK-ee29c86b;received=10.10.10.23 From: fax ;tag=d2bd39c8aad00a65o1 To: ;tag=as5622a22e Call-ID: 3258edd2-a37bd611@10.10.10.23 CSeq: 280 NOTIFY User-Agent: blabla.ch 1.4PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces ontent-Length: 0 <------------> [Mar 29 13:07:35] DEBUG[2735]: chan_sip.c:14817 sipsock_read: Invalid SIP message - rejected , no callid, len 328 anarki*CLI> <--- SIP read from 10.10.10.23:5060 ---> NOTIFY sip:172.16.0.25 SIP/2.0 Via: SIP/2.0/UDP 10.10.10.23:5060;branch=z9hG4bK-6ae50542 From: alx ;tag=82a91f60f0afa1ado0 To: Call-ID: edc685a6-17ad004d@10.10.10.23 CSeq: 281 NOTIFY Max-Forwards: 70 Event: keep-alive User-Agent: Linksys/SPA2102-3.3.6 Content-Length: 0 <-------------> [Mar 29 13:07:50] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 0: NOTIFY sip:172.16.0.25 SIP/2.0 (29) [Mar 29 13:07:50] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 1: Via: SIP/2.0/UDP 10.10.10.23:5060;branch=z9hG4bK-6ae50542 (59) [Mar 29 13:07:50] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 2: From: alx ;tag=82a91f60f0afa1ado0 (59) [Mar 29 13:07:50] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 3: To: (20) [Mar 29 13:07:50] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 4: Call-ID: edc685a6-17ad004d@10.10.10.23 (40) [Mar 29 13:07:50] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 5: CSeq: 281 NOTIFY (16) [Mar 29 13:07:50] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 6: Max-Forwards: 70 (16) [Mar 29 13:07:50] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 7: Event: keep-alive (17) [Mar 29 13:07:50] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 8: User-Agent: Linksys/SPA2102-3.3.6 (33) [Mar 29 13:07:50] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 9: Content-Length: 0 (17) [Mar 29 13:07:50] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 10: (0) --- (10 headers 0 lines) --- <--- Transmitting (no NAT) to 10.10.10.23:5060 ---> SIP/2.0 489 Bad event Via: SIP/2.0/UDP 10.10.10.23:5060;branch=z9hG4bK-6ae50542;received=10.10.10.23 From: alx ;tag=82a91f60f0afa1ado0 To: ;tag=as5991a257 Call-ID: edc685a6-17ad004d@10.10.10.23 CSeq: 281 NOTIFY User-Agent: blabla.ch 1.4PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces ontent-Length: 0 <------------> [Mar 29 13:07:50] DEBUG[2735]: chan_sip.c:14817 sipsock_read: Invalid SIP message - rejected , no callid, len 328 anarki*CLI> <--- SIP read from 10.10.10.23:5061 ---> NOTIFY sip:172.16.0.25 SIP/2.0 Via: SIP/2.0/UDP 10.10.10.23:5061;branch=z9hG4bK-ea1f9657 From: fax ;tag=d2bd39c8aad00a65o1 To: Call-ID: 3258edd2-a37bd611@10.10.10.23 CSeq: 281 NOTIFY Max-Forwards: 70 Event: keep-alive User-Agent: Linksys/SPA2102-3.3.6 Content-Length: 0 <-------------> [Mar 29 13:07:50] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 0: NOTIFY sip:172.16.0.25 SIP/2.0 (29) [Mar 29 13:07:50] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 1: Via: SIP/2.0/UDP 10.10.10.23:5061;branch=z9hG4bK-ea1f9657 (59) [Mar 29 13:07:50] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 2: From: fax ;tag=d2bd39c8aad00a65o1 (59) [Mar 29 13:07:50] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 3: To: (20) [Mar 29 13:07:50] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 4: Call-ID: 3258edd2-a37bd611@10.10.10.23 (40) [Mar 29 13:07:50] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 5: CSeq: 281 NOTIFY (16) [Mar 29 13:07:50] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 6: Max-Forwards: 70 (16) [Mar 29 13:07:50] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 7: Event: keep-alive (17) [Mar 29 13:07:50] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 8: User-Agent: Linksys/SPA2102-3.3.6 (33) [Mar 29 13:07:50] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 9: Content-Length: 0 (17) [Mar 29 13:07:50] DEBUG[2735]: chan_sip.c:4573 parse_request: Header 10: (0) --- (10 headers 0 lines) --- <--- Transmitting (no NAT) to 10.10.10.23:5061 ---> SIP/2.0 489 Bad event Via: SIP/2.0/UDP 10.10.10.23:5061;branch=z9hG4bK-ea1f9657;received=10.10.10.23 From: fax ;tag=d2bd39c8aad00a65o1 To: ;tag=as11658138 Call-ID: 3258edd2-a37bd611@10.10.10.23 CSeq: 281 NOTIFY User-Agent: blabla.ch 1.4PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Content-Length: 0 <------------> [Mar 29 13:07:50] DEBUG[2735]: chan_sip.c:14817 sipsock_read: Invalid SIP message - rejected , no callid, len 328 anarki*CLI>