Asterisk 1.2.9.1, Copyright (C) 1999 - 2006 Digium, Inc. and others. Created by Mark Spencer Asterisk comes with ABSOLUTELY NO WARRANTY; type 'show warranty' for details. This is free software, with components licensed under the GNU General Public License version 2 and other licenses; you are welcome to redistribute it under certain conditions. Type 'show license' for details. ========================================================================= Connected to Asterisk 1.2.9.1 currently running on ultravoX (pid = 2555) Verbosity is at least 4 Core debug is at least 4 ultravoX*CLI> <-- SIP read from 192.168.0.163:2051: INVITE sip:11@192.168.0.25;user=phone SIP/2.0 Via: SIP/2.0/UDP 192.168.0.163:2051;branch=z9hG4bK-p0tgza6b90oe;rport From: "snom" ;tag=ls79hgc0bt To: Call-ID: 3c2bc9a7afc8-us5jzg0io0z5@snom360 CSeq: 1 INVITE Max-Forwards: 70 Contact: P-Key-Flags: resolution="31x13", keys="4" User-Agent: snom360/4.1 Accept: application/sdp Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO Allow-Events: talk, hold, refer Supported: timer, 100rel, replaces, callerid Session-Expires: 3600 Content-Type: application/sdp Content-Length: 368 v=0 o=root 622177470 622177470 IN IP4 192.168.0.163 s=call c=IN IP4 192.168.0.163 t=0 0 m=audio 63408 RTP/AVP 0 8 9 2 3 18 4 101 a=rtpmap:0 pcmu/8000 a=rtpmap:8 pcma/8000 a=rtpmap:9 g722/8000 a=rtpmap:2 g726-32/8000 a=rtpmap:3 gsm/8000 a=rtpmap:18 g729/8000 a=rtpmap:4 g723/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=ptime:20 a=sendrecv Jul 24 11:54:05 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 0: INVITE sip:11@192.168.0.25;user=phone SIP/2.0 (45) Jul 24 11:54:05 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.0.163:2051;branch=z9hG4bK-p0tgza6b90oe;rport (69) Jul 24 11:54:05 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 2: From: "snom" ;tag=ls79hgc0bt (49) Jul 24 11:54:05 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 3: To: (36) Jul 24 11:54:05 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 4: Call-ID: 3c2bc9a7afc8-us5jzg0io0z5@snom360 (42) Jul 24 11:54:05 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 5: CSeq: 1 INVITE (14) Jul 24 11:54:05 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 6: Max-Forwards: 70 (16) Jul 24 11:54:05 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 7: Contact: (50) Jul 24 11:54:05 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 8: P-Key-Flags: resolution="31x13", keys="4" (41) Jul 24 11:54:05 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 9: User-Agent: snom360/4.1 (23) Jul 24 11:54:05 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 10: Accept: application/sdp (23) Jul 24 11:54:05 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 11: Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO (88) Jul 24 11:54:05 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 12: Allow-Events: talk, hold, refer (31) Jul 24 11:54:05 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 13: Supported: timer, 100rel, replaces, callerid (44) Jul 24 11:54:05 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 14: Session-Expires: 3600 (21) Jul 24 11:54:05 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 15: Content-Type: application/sdp (29) Jul 24 11:54:05 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 16: Content-Length: 368 (19) Jul 24 11:54:05 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 17: (0) Jul 24 11:54:05 DEBUG[3885]: chan_sip.c:3404 parse_request: Line: v=0 (3) Jul 24 11:54:05 DEBUG[3885]: chan_sip.c:3404 parse_request: Line: o=root 622177470 622177470 IN IP4 192.168.0.163 (47) Jul 24 11:54:05 DEBUG[3885]: chan_sip.c:3404 parse_request: Line: s=call (6) Jul 24 11:54:05 DEBUG[3885]: chan_sip.c:3404 parse_request: Line: c=IN IP4 192.168.0.163 (22) Jul 24 11:54:05 DEBUG[3885]: chan_sip.c:3404 parse_request: Line: t=0 0 (5) Jul 24 11:54:05 DEBUG[3885]: chan_sip.c:3404 parse_request: Line: m=audio 63408 RTP/AVP 0 8 9 2 3 18 4 101 (40) Jul 24 11:54:05 DEBUG[3885]: chan_sip.c:3404 parse_request: Line: a=rtpmap:0 pcmu/8000 (20) Jul 24 11:54:05 DEBUG[3885]: chan_sip.c:3404 parse_request: Line: a=rtpmap:8 pcma/8000 (20) Jul 24 11:54:05 DEBUG[3885]: chan_sip.c:3404 parse_request: Line: a=rtpmap:9 g722/8000 (20) Jul 24 11:54:05 DEBUG[3885]: chan_sip.c:3404 parse_request: Line: a=rtpmap:2 g726-32/8000 (23) Jul 24 11:54:05 DEBUG[3885]: chan_sip.c:3404 parse_request: Line: a=rtpmap:3 gsm/8000 (19) Jul 24 11:54:05 DEBUG[3885]: chan_sip.c:3404 parse_request: Line: a=rtpmap:18 g729/8000 (21) Jul 24 11:54:05 DEBUG[3885]: chan_sip.c:3404 parse_request: Line: a=rtpmap:4 g723/8000 (20) Jul 24 11:54:05 DEBUG[3885]: chan_sip.c:3404 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) Jul 24 11:54:05 DEBUG[3885]: chan_sip.c:3404 parse_request: Line: a=fmtp:101 0-15 (15) Jul 24 11:54:05 DEBUG[3885]: chan_sip.c:3404 parse_request: Line: a=ptime:20 (10) Jul 24 11:54:05 DEBUG[3885]: chan_sip.c:3404 parse_request: Line: a=sendrecv (10) --- (17 headers 17 lines)--- Jul 24 11:54:05 DEBUG[3885]: chan_sip.c:3156 sip_alloc: Allocating new SIP dialog for 3c2bc9a7afc8-us5jzg0io0z5@snom360 - INVITE (With RTP) Jul 24 11:54:05 DEBUG[3885]: chan_sip.c:11246 handle_request: **** Received INVITE (5) - Command in SIP INVITE Jul 24 11:54:05 DEBUG[3885]: chan_sip.c:1007 parse_sip_options: Begin: parsing SIP "Supported: timer, 100rel, replaces, callerid" Jul 24 11:54:05 DEBUG[3885]: chan_sip.c:1019 parse_sip_options: Found SIP option: -timer- Jul 24 11:54:05 DEBUG[3885]: chan_sip.c:1025 parse_sip_options: Matched SIP option: timer Jul 24 11:54:05 DEBUG[3885]: chan_sip.c:1019 parse_sip_options: Found SIP option: -100rel- Jul 24 11:54:05 DEBUG[3885]: chan_sip.c:1025 parse_sip_options: Matched SIP option: 100rel Jul 24 11:54:05 DEBUG[3885]: chan_sip.c:1019 parse_sip_options: Found SIP option: -replaces- Jul 24 11:54:05 DEBUG[3885]: chan_sip.c:1025 parse_sip_options: Matched SIP option: replaces Jul 24 11:54:05 DEBUG[3885]: chan_sip.c:1019 parse_sip_options: Found SIP option: -callerid- Jul 24 11:54:05 DEBUG[3885]: chan_sip.c:1030 parse_sip_options: Found no match for SIP option: callerid (Please file bug report!) Jul 24 11:54:05 DEBUG[3885]: chan_sip.c:1036 parse_sip_options: * SIP extension value: 7 for call 3c2bc9a7afc8-us5jzg0io0z5@snom360 Using INVITE request as basis request - 3c2bc9a7afc8-us5jzg0io0z5@snom360 Sending to 192.168.0.163 : 2051 (NAT) Jul 24 11:54:05 DEBUG[3885]: chan_sip.c:7213 check_user_full: Setting NAT on RTP to 0 Reliably Transmitting (no NAT) to 192.168.0.163:2051: SIP/2.0 407 Proxy Authentication Required Via: SIP/2.0/UDP 192.168.0.163:2051;branch=z9hG4bK-p0tgza6b90oe;rport;received=192.168.0.163 From: "snom" ;tag=ls79hgc0bt To: ;tag=as0fe11ac3 Call-ID: 3c2bc9a7afc8-us5jzg0io0z5@snom360 CSeq: 1 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Contact: Proxy-Authenticate: Digest realm="mydomain.tld", nonce="28e29cdd" Content-Length: 0 --- Jul 24 11:54:05 DEBUG[3885]: chan_sip.c:1296 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #85 Scheduling destruction of call '3c2bc9a7afc8-us5jzg0io0z5@snom360' in 15000 ms Found user '10' ultravoX*CLI> <-- SIP read from 192.168.0.163:2051: ACK sip:11@192.168.0.25;user=phone SIP/2.0 Via: SIP/2.0/UDP 192.168.0.163:2051;branch=z9hG4bK-p0tgza6b90oe;rport From: "snom" ;tag=ls79hgc0bt To: ;tag=as0fe11ac3 Call-ID: 3c2bc9a7afc8-us5jzg0io0z5@snom360 CSeq: 1 ACK Max-Forwards: 70 Contact: Content-Length: 0 Jul 24 11:54:05 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 0: ACK sip:11@192.168.0.25;user=phone SIP/2.0 (42) Jul 24 11:54:05 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.0.163:2051;branch=z9hG4bK-p0tgza6b90oe;rport (69) Jul 24 11:54:05 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 2: From: "snom" ;tag=ls79hgc0bt (49) Jul 24 11:54:05 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 3: To: ;tag=as0fe11ac3 (51) Jul 24 11:54:05 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 4: Call-ID: 3c2bc9a7afc8-us5jzg0io0z5@snom360 (42) Jul 24 11:54:05 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 5: CSeq: 1 ACK (11) Jul 24 11:54:05 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 6: Max-Forwards: 70 (16) Jul 24 11:54:05 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 7: Contact: (50) Jul 24 11:54:05 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 8: Content-Length: 0 (17) Jul 24 11:54:05 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 9: (0) --- (9 headers 0 lines)--- Jul 24 11:54:05 DEBUG[3885]: chan_sip.c:11246 handle_request: **** Received ACK (6) - Command in SIP ACK Jul 24 11:54:05 DEBUG[3885]: chan_sip.c:1393 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #85 Jul 24 11:54:05 DEBUG[3885]: chan_sip.c:1404 __sip_ack: Stopping retransmission on '3c2bc9a7afc8-us5jzg0io0z5@snom360' of Response 1: Match Found <-- SIP read from 192.168.0.163:2051: INVITE sip:11@192.168.0.25;user=phone SIP/2.0 Via: SIP/2.0/UDP 192.168.0.163:2051;branch=z9hG4bK-j7u3pi4981dj;rport From: "snom" ;tag=ls79hgc0bt To: Call-ID: 3c2bc9a7afc8-us5jzg0io0z5@snom360 CSeq: 2 INVITE Max-Forwards: 70 Contact: P-Key-Flags: resolution="31x13", keys="4" User-Agent: snom360/4.1 Accept: application/sdp Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO Allow-Events: talk, hold, refer Supported: timer, 100rel, replaces, callerid Session-Expires: 3600 Proxy-Authorization: Digest username="10",realm="mydomain.tld",nonce="28e29cdd",uri="sip:11@192.168.0.25;user=phone",response="b123f08e52e408514aa7f3ac396a7bf6",algorithm=md5 Content-Type: application/sdp Content-Length: 368 v=0 o=root 622177470 622177470 IN IP4 192.168.0.163 s=call c=IN IP4 192.168.0.163 t=0 0 m=audio 63408 RTP/AVP 0 8 9 2 3 18 4 101 a=rtpmap:0 pcmu/8000 a=rtpmap:8 pcma/8000 a=rtpmap:9 g722/8000 =rtpmap:2 g726-32/8000 a=rtpmap:3 gsm/8000 a=rtpmap:18 g729/8000 a=rtpmap:4 g723/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=ptime:20 a=sendrecv Jul 24 11:54:05 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 0: INVITE sip:11@192.168.0.25;user=phone SIP/2.0 (45) Jul 24 11:54:05 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.0.163:2051;branch=z9hG4bK-j7u3pi4981dj;rport (69) Jul 24 11:54:05 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 2: From: "snom" ;tag=ls79hgc0bt (49) Jul 24 11:54:05 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 3: To: (36) Jul 24 11:54:05 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 4: Call-ID: 3c2bc9a7afc8-us5jzg0io0z5@snom360 (42) Jul 24 11:54:05 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 5: CSeq: 2 INVITE (14) Jul 24 11:54:05 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 6: Max-Forwards: 70 (16) Jul 24 11:54:05 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 7: Contact: (50) Jul 24 11:54:05 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 8: P-Key-Flags: resolution="31x13", keys="4" (41) Jul 24 11:54:05 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 9: User-Agent: snom360/4.1 (23) Jul 24 11:54:05 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 10: Accept: application/sdp (23) Jul 24 11:54:05 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 11: Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO (88) Jul 24 11:54:05 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 12: Allow-Events: talk, hold, refer (31) Jul 24 11:54:05 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 13: Supported: timer, 100rel, replaces, callerid (44) Jul 24 11:54:05 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 14: Session-Expires: 3600 (21) Jul 24 11:54:05 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 15: Proxy-Authorization: Digest username="10",realm="mydomain.tld",nonce="28e29cdd",uri="sip:11@192.168.0.25;user=phone",response="b123f08e52e408514aa7f3ac396a7bf6",algorithm=md5 (174) Jul 24 11:54:05 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 16: Content-Type: application/sdp (29) Jul 24 11:54:05 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 17: Content-Length: 368 (19) Jul 24 11:54:05 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 18: (0) Jul 24 11:54:05 DEBUG[3885]: chan_sip.c:3404 parse_request: Line: v=0 (3) Jul 24 11:54:05 DEBUG[3885]: chan_sip.c:3404 parse_request: Line: o=root 622177470 622177470 IN IP4 192.168.0.163 (47) Jul 24 11:54:05 DEBUG[3885]: chan_sip.c:3404 parse_request: Line: s=call (6) Jul 24 11:54:05 DEBUG[3885]: chan_sip.c:3404 parse_request: Line: c=IN IP4 192.168.0.163 (22) Jul 24 11:54:05 DEBUG[3885]: chan_sip.c:3404 parse_request: Line: t=0 0 (5) Jul 24 11:54:05 DEBUG[3885]: chan_sip.c:3404 parse_request: Line: m=audio 63408 RTP/AVP 0 8 9 2 3 18 4 101 (40) Jul 24 11:54:05 DEBUG[3885]: chan_sip.c:3404 parse_request: Line: a=rtpmap:0 pcmu/8000 (20) Jul 24 11:54:05 DEBUG[3885]: chan_sip.c:3404 parse_request: Line: a=rtpmap:8 pcma/8000 (20) Jul 24 11:54:05 DEBUG[3885]: chan_sip.c:3404 parse_request: Line: a=rtpmap:9 g722/8000 (20) Jul 24 11:54:05 DEBUG[3885]: chan_sip.c:3404 parse_request: Line: a=rtpmap:2 g726-32/8000 (23) Jul 24 11:54:05 DEBUG[3885]: chan_sip.c:3404 parse_request: Line: a=rtpmap:3 gsm/8000 (19) Jul 24 11:54:05 DEBUG[3885]: chan_sip.c:3404 parse_request: Line: a=rtpmap:18 g729/8000 (21) Jul 24 11:54:05 DEBUG[3885]: chan_sip.c:3404 parse_request: Line: a=rtpmap:4 g723/8000 (20) Jul 24 11:54:05 DEBUG[3885]: chan_sip.c:3404 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) Jul 24 11:54:05 DEBUG[3885]: chan_sip.c:3404 parse_request: Line: a=fmtp:101 0-15 (15) Jul 24 11:54:05 DEBUG[3885]: chan_sip.c:3404 parse_request: Line: a=ptime:20 (10) Jul 24 11:54:05 DEBUG[3885]: chan_sip.c:3404 parse_request: Line: a=sendrecv (10) --- (18 headers 17 lines)--- Jul 24 11:54:05 DEBUG[3885]: chan_sip.c:11246 handle_request: **** Received INVITE (5) - Command in SIP INVITE Using INVITE request as basis request - 3c2bc9a7afc8-us5jzg0io0z5@snom360 Sending to 192.168.0.163 : 2051 (NAT) Jul 24 11:54:05 DEBUG[3885]: chan_sip.c:7213 check_user_full: Setting NAT on RTP to 0 Found user '10' Found RTP audio format 0 Found RTP audio format 8 Found RTP audio format 9 Found RTP audio format 2 Found RTP audio format 3 Found RTP audio format 18 Found RTP audio format 4 Found RTP audio format 101 Peer audio RTP is at port 192.168.0.163:63408 Jul 24 11:54:05 DEBUG[3885]: chan_sip.c:3613 process_sdp: Peer audio RTP is at port 192.168.0.163:63408 Found description format pcmu Found description format pcma Found description format g722 Found description format g726-32 Found description format gsm Found description format g729 Found description format g723 Found description format telephone-event Capabilities: us - 0x1f07ff (g723|gsm|ulaw|alaw|g726|adpcm|slin|lpc10|g729|speex|ilbc|jpeg|png|h261|h263|h263p), peer - audio=0x11f (g723|gsm|ulaw|alaw|g726|g729)/video=0x0 (nothing), combined - 0x11f (g723|gsm|ulaw|alaw|g726|g729) Non-codec capabilities: us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) Jul 24 11:54:05 DEBUG[3885]: chan_sip.c:10573 handle_request_invite: Checking SIP call limits for device 10 Jul 24 11:54:05 DEBUG[3885]: chan_sip.c:2218 update_call_counter: Updating call counter for incoming call Looking for 11 in DefaultOutgoingRule (domain 192.168.0.25) Jul 24 11:54:05 DEBUG[3885]: chan_sip.c:6172 build_route: build_route: Contact hop: list_route: hop: Transmitting (no NAT) to 192.168.0.163:2051: SIP/2.0 100 Trying Via: SIP/2.0/UDP 192.168.0.163:2051;branch=z9hG4bK-j7u3pi4981dj;rport;received=192.168.0.163 From: "snom" ;tag=ls79hgc0bt To: Call-ID: 3c2bc9a7afc8-us5jzg0io0z5@snom360 CSeq: 2 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Contact: Content-Length: 0 --- Jul 24 11:54:05 DEBUG[3872]: chan_sip.c:11781 sip_devicestate: Checking device state for peer 10 Jul 24 11:54:05 DEBUG[3872]: devicestate.c:187 do_state_change: Changing state for SIP/10 - state 2 (In use) Jul 24 11:54:05 DEBUG[3872]: chan_sip.c:11781 sip_devicestate: Checking device state for peer 10 Jul 24 11:54:05 DEBUG[3976]: pbx.c:1677 pbx_extension_helper: Launching 'AGI' -- Executing AGI("SIP/10-15f3", "dial.php|entity=37&group=2&extension=11") in new stack -- Launched AGI Script /var/lib/asterisk/agi-bin/dial.php Jul 24 11:54:05 DEBUG[3977]: app_queue.c:523 changethread: Device 'SIP/10' changed to state '2' (In use) but we don't care because they're not a member of any queue. -- AGI Script Executing Application: (macro) Options: (stdexten|SIP/11) Jul 24 11:54:06 DEBUG[3976]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '11' Jul 24 11:54:06 DEBUG[3976]: pbx.c:1677 pbx_extension_helper: Launching 'Set' -- Executing Set("SIP/10-15f3", "EXTENSION=11") in new stack Jul 24 11:54:06 DEBUG[3976]: db.c:200 ast_db_get: Unable to find key '11' in family 'DND' Jul 24 11:54:06 DEBUG[3976]: func_db.c:69 function_db_read: DB: DND/11 not found in database. Jul 24 11:54:06 DEBUG[3976]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '' Jul 24 11:54:06 DEBUG[3976]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '0' Jul 24 11:54:06 DEBUG[3976]: pbx.c:1677 pbx_extension_helper: Launching 'GotoIf' -- Executing GotoIf("SIP/10-15f3", "0?s-BUSY|1") in new stack Jul 24 11:54:06 DEBUG[3976]: pbx.c:6175 pbx_builtin_gotoif: Not taking any branch Jul 24 11:54:06 DEBUG[3976]: db.c:200 ast_db_get: Unable to find key '11' in family 'CFU' Jul 24 11:54:06 DEBUG[3976]: func_db.c:69 function_db_read: DB: CFU/11 not found in database. Jul 24 11:54:06 DEBUG[3976]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '' Jul 24 11:54:06 DEBUG[3976]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '0' Jul 24 11:54:06 DEBUG[3976]: db.c:200 ast_db_get: Unable to find key 'SIP/11' in family 'CFU' Jul 24 11:54:06 DEBUG[3976]: func_db.c:69 function_db_read: DB: CFU/SIP/11 not found in database. Jul 24 11:54:06 DEBUG[3976]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '' Jul 24 11:54:06 DEBUG[3976]: pbx.c:1677 pbx_extension_helper: Launching 'GotoIf' -- Executing GotoIf("SIP/10-15f3", "0?DefaultOutgoingRule||1") in new stack Jul 24 11:54:06 DEBUG[3976]: pbx.c:6175 pbx_builtin_gotoif: Not taking any branch Jul 24 11:54:06 DEBUG[3976]: pbx.c:1677 pbx_extension_helper: Launching 'Dial' -- Executing Dial("SIP/10-15f3", "SIP/11|20|tTwW") in new stack Jul 24 11:54:06 DEBUG[3976]: chan_sip.c:3156 sip_alloc: Allocating new SIP dialog for (No Call-ID) - INVITE (With RTP) Jul 24 11:54:06 DEBUG[3976]: chan_sip.c:1877 create_addr_from_peer: Setting NAT on RTP to 0 Jul 24 11:54:06 DEBUG[3976]: channel.c:2823 ast_channel_inherit_variables: Not copying variable STACK-macro-stdexten-s-4. Jul 24 11:54:06 DEBUG[3976]: channel.c:2823 ast_channel_inherit_variables: Not copying variable MACRO_DEPTH. Jul 24 11:54:06 DEBUG[3976]: channel.c:2823 ast_channel_inherit_variables: Not copying variable STACK-macro-stdexten-s-3. Jul 24 11:54:06 DEBUG[3976]: channel.c:2823 ast_channel_inherit_variables: Not copying variable STACK-macro-stdexten-s-2. Jul 24 11:54:06 DEBUG[3976]: channel.c:2823 ast_channel_inherit_variables: Not copying variable EXTENSION. Jul 24 11:54:06 DEBUG[3976]: channel.c:2823 ast_channel_inherit_variables: Not copying variable STACK-macro-stdexten-s-1. Jul 24 11:54:06 DEBUG[3976]: channel.c:2823 ast_channel_inherit_variables: Not copying variable ARG1. Jul 24 11:54:06 DEBUG[3976]: channel.c:2823 ast_channel_inherit_variables: Not copying variable MACRO_PRIORITY. Jul 24 11:54:06 DEBUG[3976]: channel.c:2823 ast_channel_inherit_variables: Not copying variable MACRO_CONTEXT. Jul 24 11:54:06 DEBUG[3976]: channel.c:2823 ast_channel_inherit_variables: Not copying variable MACRO_EXTEN. Jul 24 11:54:06 DEBUG[3976]: channel.c:2823 ast_channel_inherit_variables: Not copying variable STACK-DefaultOutgoingRule-11-1. Jul 24 11:54:06 DEBUG[3976]: channel.c:2823 ast_channel_inherit_variables: Not copying variable SIPCALLID. Jul 24 11:54:06 DEBUG[3976]: channel.c:2823 ast_channel_inherit_variables: Not copying variable SIPUSERAGENT. Jul 24 11:54:06 DEBUG[3976]: channel.c:2823 ast_channel_inherit_variables: Not copying variable SIPDOMAIN. Jul 24 11:54:06 DEBUG[3976]: channel.c:2823 ast_channel_inherit_variables: Not copying variable SIPURI. Jul 24 11:54:06 DEBUG[3976]: chan_sip.c:2077 sip_call: Outgoing Call for 11 Jul 24 11:54:06 DEBUG[3976]: chan_sip.c:2218 update_call_counter: Updating call counter for outgoing call We're at 192.168.0.25 port 17146 Adding codec 0x8 (alaw) to SDP Adding codec 0x4 (ulaw) to SDP Adding codec 0x2 (gsm) to SDP Adding codec 0x400 (ilbc) to SDP Adding codec 0x100 (g729) to SDP Adding codec 0x1 (g723) to SDP Adding codec 0x10 (g726) to SDP Adding codec 0x20 (adpcm) to SDP Adding codec 0x40 (slin) to SDP Adding codec 0x80 (lpc10) to SDP Adding codec 0x200 (speex) to SDP Adding non-codec 0x1 (telephone-event) to SDP Jul 24 11:54:06 DEBUG[3976]: chan_sip.c:3372 parse_request: Header 0: INVITE sip:11@192.168.0.189:2054;line=sczhjqwm SIP/2.0 (54) Jul 24 11:54:06 DEBUG[3976]: chan_sip.c:3372 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.0.25:5060;branch=z9hG4bK7418798c;rport (63) Jul 24 11:54:06 DEBUG[3976]: chan_sip.c:3372 parse_request: Header 2: From: "snom" ;tag=as165ec945 (49) Jul 24 11:54:06 DEBUG[3976]: chan_sip.c:3372 parse_request: Header 3: To: (45) Jul 24 11:54:06 DEBUG[3976]: chan_sip.c:3372 parse_request: Header 4: Contact: (30) Jul 24 11:54:06 DEBUG[3976]: chan_sip.c:3372 parse_request: Header 5: Call-ID: 3b4811ad1530aa5674197392245961fa@192.168.0.25 (54) Jul 24 11:54:06 DEBUG[3976]: chan_sip.c:3372 parse_request: Header 6: CSeq: 102 INVITE (16) Jul 24 11:54:06 DEBUG[3976]: chan_sip.c:3372 parse_request: Header 7: User-Agent: Asterisk PBX (24) Jul 24 11:54:06 DEBUG[3976]: chan_sip.c:3372 parse_request: Header 8: Max-Forwards: 70 (16) Jul 24 11:54:06 DEBUG[3976]: chan_sip.c:3372 parse_request: Header 9: Date: Mon, 24 Jul 2006 09:54:06 GMT (35) Jul 24 11:54:06 DEBUG[3976]: chan_sip.c:3372 parse_request: Header 10: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) Jul 24 11:54:06 DEBUG[3976]: chan_sip.c:3372 parse_request: Header 11: Content-Type: application/sdp (29) Jul 24 11:54:06 DEBUG[3976]: chan_sip.c:3372 parse_request: Header 12: Content-Length: 490 (19) Jul 24 11:54:06 DEBUG[3976]: chan_sip.c:3372 parse_request: Header 13: (0) Jul 24 11:54:06 DEBUG[3976]: chan_sip.c:3404 parse_request: Line: v=0 (3) Jul 24 11:54:06 DEBUG[3976]: chan_sip.c:3404 parse_request: Line: o=root 2555 2555 IN IP4 192.168.0.25 (36) Jul 24 11:54:06 DEBUG[3976]: chan_sip.c:3404 parse_request: Line: s=session (9) Jul 24 11:54:06 DEBUG[3976]: chan_sip.c:3404 parse_request: Line: c=IN IP4 192.168.0.25 (21) Jul 24 11:54:06 DEBUG[3976]: chan_sip.c:3404 parse_request: Line: t=0 0 (5) Jul 24 11:54:06 DEBUG[3976]: chan_sip.c:3404 parse_request: Line: m=audio 17146 RTP/AVP 8 0 3 97 18 4 111 5 10 7 110 101 (54) Jul 24 11:54:06 DEBUG[3976]: chan_sip.c:3404 parse_request: Line: a=rtpmap:8 PCMA/8000 (20) Jul 24 11:54:06 DEBUG[3976]: chan_sip.c:3404 parse_request: Line: a=rtpmap:0 PCMU/8000 (20) Jul 24 11:54:06 DEBUG[3976]: chan_sip.c:3404 parse_request: Line: a=rtpmap:3 GSM/8000 (19) Jul 24 11:54:06 DEBUG[3976]: chan_sip.c:3404 parse_request: Line: a=rtpmap:97 iLBC/8000 (21) Jul 24 11:54:06 DEBUG[3976]: chan_sip.c:3404 parse_request: Line: a=rtpmap:18 G729/8000 (21) Jul 24 11:54:06 DEBUG[3976]: chan_sip.c:3404 parse_request: Line: a=fmtp:18 annexb=no (19) Jul 24 11:54:06 DEBUG[3976]: chan_sip.c:3404 parse_request: Line: a=rtpmap:4 G723/8000 (20) Jul 24 11:54:06 DEBUG[3976]: chan_sip.c:3404 parse_request: Line: a=rtpmap:111 G726-32/8000 (25) Jul 24 11:54:06 DEBUG[3976]: chan_sip.c:3404 parse_request: Line: a=rtpmap:5 DVI4/8000 (20) Jul 24 11:54:06 DEBUG[3976]: chan_sip.c:3404 parse_request: Line: a=rtpmap:10 L16/8000 (20) Jul 24 11:54:06 DEBUG[3976]: chan_sip.c:3404 parse_request: Line: a=rtpmap:7 LPC/8000 (19) Jul 24 11:54:06 DEBUG[3976]: chan_sip.c:3404 parse_request: Line: a=rtpmap:110 speex/8000 (23) Jul 24 11:54:06 DEBUG[3976]: chan_sip.c:3404 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) Jul 24 11:54:06 DEBUG[3976]: chan_sip.c:3404 parse_request: Line: a=fmtp:101 0-16 (15) Jul 24 11:54:06 DEBUG[3976]: chan_sip.c:3404 parse_request: Line: a=silenceSupp:off - - - - (25) 13 headers, 21 lines Reliably Transmitting (no NAT) to 192.168.0.189:2054: INVITE sip:11@192.168.0.189:2054;line=sczhjqwm SIP/2.0 Via: SIP/2.0/UDP 192.168.0.25:5060;branch=z9hG4bK7418798c;rport From: "snom" ;tag=as165ec945 To: Contact: Call-ID: 3b4811ad1530aa5674197392245961fa@192.168.0.25 CSeq: 102 INVITE User-Agent: Asterisk PBX Max-Forwards: 70 Date: Mon, 24 Jul 2006 09:54:06 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Content-Type: application/sdp Content-Length: 490 v=0 o=root 2555 2555 IN IP4 192.168.0.25 s=session c=IN IP4 192.168.0.25 t=0 0 m=audio 17146 RTP/AVP 8 0 3 97 18 4 111 5 10 7 110 101 a=rtpmap:8 PCMA/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:3 GSM/8000 a=rtpmap:97 iLBC/8000 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:4 G723/8000 a=rtpmap:111 G726-32/8000 a=rtpmap:5 DVI4/8000 a=rtpmap:10 L16/8000 a=rtpmap:7 LPC/8000 a=rtpmap:110 speex/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - --- Jul 24 11:54:06 DEBUG[3976]: chan_sip.c:1296 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #87 -- Called 11 Jul 24 11:54:06 DEBUG[3976]: channel.c:2350 set_format: Set channel SIP/11-47ac to read format alaw Jul 24 11:54:06 DEBUG[3976]: channel.c:2350 set_format: Set channel SIP/10-15f3 to write format alaw Jul 24 11:54:06 DEBUG[3976]: channel.c:2350 set_format: Set channel SIP/10-15f3 to read format alaw Jul 24 11:54:06 DEBUG[3976]: channel.c:2350 set_format: Set channel SIP/11-47ac to write format alaw ultravoX*CLI> <-- SIP read from 192.168.0.189:2054: SIP/2.0 180 Ringing Via: SIP/2.0/UDP 192.168.0.25:5060;branch=z9hG4bK7418798c;rport=5060 From: "snom" ;tag=as165ec945 To: ;tag=oe3qaheqd7 Call-ID: 3b4811ad1530aa5674197392245961fa@192.168.0.25 CSeq: 102 INVITE Contact: ;flow-id=1 Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO Allow-Events: talk, hold, refer Content-Length: 0 Jul 24 11:54:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 0: SIP/2.0 180 Ringing (19) Jul 24 11:54:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.0.25:5060;branch=z9hG4bK7418798c;rport=5060 (68) Jul 24 11:54:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 2: From: "snom" ;tag=as165ec945 (49) Jul 24 11:54:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 3: To: ;tag=oe3qaheqd7 (60) Jul 24 11:54:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 4: Call-ID: 3b4811ad1530aa5674197392245961fa@192.168.0.25 (54) Jul 24 11:54:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 5: CSeq: 102 INVITE (16) Jul 24 11:54:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 6: Contact: ;flow-id=1 (60) Jul 24 11:54:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 7: Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO (88) Jul 24 11:54:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 8: Allow-Events: talk, hold, refer (31) Jul 24 11:54:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 9: Content-Length: 0 (17) Jul 24 11:54:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 10: (0) --- (10 headers 0 lines)--- Jul 24 11:54:06 DEBUG[3885]: chan_sip.c:1448 __sip_semi_ack: *** SIP TIMER: Cancelling retransmission #87 - INVITE (got response) Jul 24 11:54:06 DEBUG[3885]: chan_sip.c:1457 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '3b4811ad1530aa5674197392245961fa@192.168.0.25' Request 102: Found Jul 24 11:54:06 DEBUG[3885]: chan_sip.c:9646 handle_response_invite: SIP response 180 to standard invite -- SIP/11-47ac is ringing Transmitting (no NAT) to 192.168.0.163:2051: SIP/2.0 180 Ringing Via: SIP/2.0/UDP 192.168.0.163:2051;branch=z9hG4bK-j7u3pi4981dj;rport;received=192.168.0.163 From: "snom" ;tag=ls79hgc0bt To: ;tag=as349f01f5 Call-ID: 3c2bc9a7afc8-us5jzg0io0z5@snom360 CSeq: 2 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Contact: Content-Length: 0 --- Jul 24 11:54:06 DEBUG[3872]: chan_sip.c:11781 sip_devicestate: Checking device state for peer 11 Jul 24 11:54:06 DEBUG[3872]: devicestate.c:187 do_state_change: Changing state for SIP/11 - state 6 (Ringing) Jul 24 11:54:06 DEBUG[3872]: chan_sip.c:11781 sip_devicestate: Checking device state for peer 11 Jul 24 11:54:06 DEBUG[3980]: app_queue.c:523 changethread: Device 'SIP/11' changed to state '6' (Ringing) but we don't care because they're not a member of any queue. Jul 24 11:54:06 DEBUG[3885]: chan_sip.c:3156 sip_alloc: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP) Jul 24 11:54:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 0: OPTIONS sip:13@192.168.0.190:2051;line=no7rb4d3 SIP/2.0 (55) Jul 24 11:54:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.0.25:5060;branch=z9hG4bK54a1d25b;rport (63) Jul 24 11:54:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 2: From: "asterisk" ;tag=as5c985432 (59) Jul 24 11:54:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 3: To: (45) Jul 24 11:54:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 4: Contact: (36) Jul 24 11:54:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 5: Call-ID: 58f8952c3b2ddf415ac03f2c15e1c648@192.168.0.25 (54) Jul 24 11:54:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 6: CSeq: 102 OPTIONS (17) Jul 24 11:54:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 7: User-Agent: Asterisk PBX (24) Jul 24 11:54:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 8: Max-Forwards: 70 (16) Jul 24 11:54:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 9: Date: Mon, 24 Jul 2006 09:54:06 GMT (35) Jul 24 11:54:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 10: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) Jul 24 11:54:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 11: Content-Length: 0 (17) Jul 24 11:54:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 12: (0) 12 headers, 0 lines Reliably Transmitting (no NAT) to 192.168.0.190:2051: OPTIONS sip:13@192.168.0.190:2051;line=no7rb4d3 SIP/2.0 Via: SIP/2.0/UDP 192.168.0.25:5060;branch=z9hG4bK54a1d25b;rport From: "asterisk" ;tag=as5c985432 To: Contact: Call-ID: 58f8952c3b2ddf415ac03f2c15e1c648@192.168.0.25 CSeq: 102 OPTIONS User-Agent: Asterisk PBX Max-Forwards: 70 Date: Mon, 24 Jul 2006 09:54:06 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Content-Length: 0 --- Jul 24 11:54:06 DEBUG[3885]: chan_sip.c:1296 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #89 ultravoX*CLI> <-- SIP read from 192.168.0.190:2051: SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.0.25:5060;branch=z9hG4bK54a1d25b;rport=5060 From: "asterisk" ;tag=as5c985432 To: Call-ID: 58f8952c3b2ddf415ac03f2c15e1c648@192.168.0.25 CSeq: 102 OPTIONS Contact: User-Agent: snom320/4.1 Accept-Language: en Accept: application/sdp Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO Allow-Events: talk, hold, refer Supported: timer, 100rel, replaces, callerid Content-Length: 0 Jul 24 11:54:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 0: SIP/2.0 200 OK (14) Jul 24 11:54:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.0.25:5060;branch=z9hG4bK54a1d25b;rport=5060 (68) Jul 24 11:54:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 2: From: "asterisk" ;tag=as5c985432 (59) Jul 24 11:54:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 3: To: (45) Jul 24 11:54:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 4: Call-ID: 58f8952c3b2ddf415ac03f2c15e1c648@192.168.0.25 (54) Jul 24 11:54:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 5: CSeq: 102 OPTIONS (17) Jul 24 11:54:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 6: Contact: (50) Jul 24 11:54:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 7: User-Agent: snom320/4.1 (23) Jul 24 11:54:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 8: Accept-Language: en (19) Jul 24 11:54:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 9: Accept: application/sdp (23) Jul 24 11:54:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 10: Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO (88) Jul 24 11:54:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 11: Allow-Events: talk, hold, refer (31) Jul 24 11:54:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 12: Supported: timer, 100rel, replaces, callerid (44) Jul 24 11:54:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 13: Content-Length: 0 (17) Jul 24 11:54:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 14: (0) --- (14 headers 0 lines)--- Jul 24 11:54:06 DEBUG[3885]: chan_sip.c:1393 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #89 Jul 24 11:54:06 DEBUG[3885]: chan_sip.c:1404 __sip_ack: Stopping retransmission on '58f8952c3b2ddf415ac03f2c15e1c648@192.168.0.25' of Request 102: Match Found Destroying call '58f8952c3b2ddf415ac03f2c15e1c648@192.168.0.25' Jul 24 11:54:06 DEBUG[3885]: chan_sip.c:3156 sip_alloc: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP) Jul 24 11:54:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 0: OPTIONS sip:11@192.168.0.189:2054;line=sczhjqwm SIP/2.0 (55) Jul 24 11:54:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.0.25:5060;branch=z9hG4bK6e2adc87;rport (63) Jul 24 11:54:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 2: From: "asterisk" ;tag=as35ccfa64 (59) Jul 24 11:54:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 3: To: (45) Jul 24 11:54:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 4: Contact: (36) Jul 24 11:54:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 5: Call-ID: 7fce744805c597c718a5463731747542@192.168.0.25 (54) Jul 24 11:54:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 6: CSeq: 102 OPTIONS (17) Jul 24 11:54:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 7: User-Agent: Asterisk PBX (24) Jul 24 11:54:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 8: Max-Forwards: 70 (16) Jul 24 11:54:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 9: Date: Mon, 24 Jul 2006 09:54:06 GMT (35) Jul 24 11:54:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 10: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) Jul 24 11:54:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 11: Content-Length: 0 (17) Jul 24 11:54:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 12: (0) 12 headers, 0 lines Reliably Transmitting (no NAT) to 192.168.0.189:2054: OPTIONS sip:11@192.168.0.189:2054;line=sczhjqwm SIP/2.0 Via: SIP/2.0/UDP 192.168.0.25:5060;branch=z9hG4bK6e2adc87;rport From: "asterisk" ;tag=as35ccfa64 To: Contact: Call-ID: 7fce744805c597c718a5463731747542@192.168.0.25 CSeq: 102 OPTIONS User-Agent: Asterisk PBX Max-Forwards: 70 Date: Mon, 24 Jul 2006 09:54:06 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Content-Length: 0 --- Jul 24 11:54:06 DEBUG[3885]: chan_sip.c:1296 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #92 ultravoX*CLI> <-- SIP read from 192.168.0.189:2054: SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.0.25:5060;branch=z9hG4bK6e2adc87;rport=5060 From: "asterisk" ;tag=as35ccfa64 To: Call-ID: 7fce744805c597c718a5463731747542@192.168.0.25 CSeq: 102 OPTIONS Contact: ;flow-id=1 User-Agent: snom320/6.2 Accept-Language: en Accept: application/sdp Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO Allow-Events: talk, hold, refer Supported: timer, 100rel, replaces, callerid Content-Length: 0 Jul 24 11:54:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 0: SIP/2.0 200 OK (14) Jul 24 11:54:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.0.25:5060;branch=z9hG4bK6e2adc87;rport=5060 (68) Jul 24 11:54:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 2: From: "asterisk" ;tag=as35ccfa64 (59) Jul 24 11:54:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 3: To: (45) Jul 24 11:54:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 4: Call-ID: 7fce744805c597c718a5463731747542@192.168.0.25 (54) Jul 24 11:54:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 5: CSeq: 102 OPTIONS (17) Jul 24 11:54:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 6: Contact: ;flow-id=1 (60) Jul 24 11:54:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 7: User-Agent: snom320/6.2 (23) Jul 24 11:54:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 8: Accept-Language: en (19) Jul 24 11:54:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 9: Accept: application/sdp (23) Jul 24 11:54:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 10: Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO (88) Jul 24 11:54:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 11: Allow-Events: talk, hold, refer (31) Jul 24 11:54:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 12: Supported: timer, 100rel, replaces, callerid (44) Jul 24 11:54:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 13: Content-Length: 0 (17) Jul 24 11:54:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 14: (0) --- (14 headers 0 lines)--- Jul 24 11:54:06 DEBUG[3885]: chan_sip.c:1393 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #92 Jul 24 11:54:06 DEBUG[3885]: chan_sip.c:1404 __sip_ack: Stopping retransmission on '7fce744805c597c718a5463731747542@192.168.0.25' of Request 102: Match Found Destroying call '7fce744805c597c718a5463731747542@192.168.0.25' ultravoX*CLI> <-- SIP read from 192.168.0.189:2054: SIP/2.0 180 Ringing Via: SIP/2.0/UDP 192.168.0.25:5060;branch=z9hG4bK7418798c;rport=5060 From: "snom" ;tag=as165ec945 To: ;tag=oe3qaheqd7 Call-ID: 3b4811ad1530aa5674197392245961fa@192.168.0.25 CSeq: 102 INVITE Contact: ;flow-id=1 Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO Allow-Events: talk, hold, refer Content-Length: 0 Jul 24 11:54:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 0: SIP/2.0 180 Ringing (19) Jul 24 11:54:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.0.25:5060;branch=z9hG4bK7418798c;rport=5060 (68) Jul 24 11:54:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 2: From: "snom" ;tag=as165ec945 (49) Jul 24 11:54:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 3: To: ;tag=oe3qaheqd7 (60) Jul 24 11:54:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 4: Call-ID: 3b4811ad1530aa5674197392245961fa@192.168.0.25 (54) Jul 24 11:54:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 5: CSeq: 102 INVITE (16) Jul 24 11:54:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 6: Contact: ;flow-id=1 (60) Jul 24 11:54:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 7: Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO (88) Jul 24 11:54:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 8: Allow-Events: talk, hold, refer (31) Jul 24 11:54:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 9: Content-Length: 0 (17) Jul 24 11:54:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 10: (0) --- (10 headers 0 lines)--- Jul 24 11:54:06 DEBUG[3885]: chan_sip.c:1457 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '3b4811ad1530aa5674197392245961fa@192.168.0.25' Request 102: Found Jul 24 11:54:06 DEBUG[3885]: chan_sip.c:9646 handle_response_invite: SIP response 180 to standard invite -- SIP/11-47ac is ringing ultravoX*CLI> <-- SIP read from 192.168.0.189:2054: SIP/2.0 180 Ringing Via: SIP/2.0/UDP 192.168.0.25:5060;branch=z9hG4bK7418798c;rport=5060 From: "snom" ;tag=as165ec945 To: ;tag=oe3qaheqd7 Call-ID: 3b4811ad1530aa5674197392245961fa@192.168.0.25 CSeq: 102 INVITE Contact: ;flow-id=1 Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO Allow-Events: talk, hold, refer Content-Length: 0 Jul 24 11:54:07 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 0: SIP/2.0 180 Ringing (19) Jul 24 11:54:07 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.0.25:5060;branch=z9hG4bK7418798c;rport=5060 (68) Jul 24 11:54:07 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 2: From: "snom" ;tag=as165ec945 (49) Jul 24 11:54:07 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 3: To: ;tag=oe3qaheqd7 (60) Jul 24 11:54:07 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 4: Call-ID: 3b4811ad1530aa5674197392245961fa@192.168.0.25 (54) Jul 24 11:54:07 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 5: CSeq: 102 INVITE (16) Jul 24 11:54:07 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 6: Contact: ;flow-id=1 (60) Jul 24 11:54:07 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 7: Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO (88) Jul 24 11:54:07 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 8: Allow-Events: talk, hold, refer (31) Jul 24 11:54:07 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 9: Content-Length: 0 (17) Jul 24 11:54:07 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 10: (0) --- (10 headers 0 lines)--- Jul 24 11:54:07 DEBUG[3885]: chan_sip.c:1457 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '3b4811ad1530aa5674197392245961fa@192.168.0.25' Request 102: Found Jul 24 11:54:07 DEBUG[3885]: chan_sip.c:9646 handle_response_invite: SIP response 180 to standard invite -- SIP/11-47ac is ringing ultravoX*CLI> <-- SIP read from 192.168.0.189:2054: SIP/2.0 180 Ringing Via: SIP/2.0/UDP 192.168.0.25:5060;branch=z9hG4bK7418798c;rport=5060 From: "snom" ;tag=as165ec945 To: ;tag=oe3qaheqd7 Call-ID: 3b4811ad1530aa5674197392245961fa@192.168.0.25 CSeq: 102 INVITE Contact: ;flow-id=1 Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO Allow-Events: talk, hold, refer Content-Length: 0 Jul 24 11:54:09 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 0: SIP/2.0 180 Ringing (19) Jul 24 11:54:09 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.0.25:5060;branch=z9hG4bK7418798c;rport=5060 (68) Jul 24 11:54:09 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 2: From: "snom" ;tag=as165ec945 (49) Jul 24 11:54:09 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 3: To: ;tag=oe3qaheqd7 (60) Jul 24 11:54:09 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 4: Call-ID: 3b4811ad1530aa5674197392245961fa@192.168.0.25 (54) Jul 24 11:54:09 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 5: CSeq: 102 INVITE (16) Jul 24 11:54:09 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 6: Contact: ;flow-id=1 (60) Jul 24 11:54:09 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 7: Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO (88) Jul 24 11:54:09 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 8: Allow-Events: talk, hold, refer (31) Jul 24 11:54:09 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 9: Content-Length: 0 (17) Jul 24 11:54:09 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 10: (0) --- (10 headers 0 lines)--- Jul 24 11:54:09 DEBUG[3885]: chan_sip.c:1457 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '3b4811ad1530aa5674197392245961fa@192.168.0.25' Request 102: Found Jul 24 11:54:09 DEBUG[3885]: chan_sip.c:9646 handle_response_invite: SIP response 180 to standard invite -- SIP/11-47ac is ringing Jul 24 11:54:13 DEBUG[3976]: rtp.c:411 ast_rtcp_read: Got RTCP report of 52 bytes ultravoX*CLI> <-- SIP read from 192.168.0.189:2054: SIP/2.0 200 Ok Via: SIP/2.0/UDP 192.168.0.25:5060;branch=z9hG4bK7418798c;rport=5060 From: "snom" ;tag=as165ec945 To: ;tag=oe3qaheqd7 Call-ID: 3b4811ad1530aa5674197392245961fa@192.168.0.25 CSeq: 102 INVITE Contact: ;flow-id=1 User-Agent: snom320/6.2 Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO Allow-Events: talk, hold, refer Supported: timer, 100rel, replaces, callerid Content-Type: application/sdp Content-Length: 317 v=0 o=root 1547310099 1547310100 IN IP4 192.168.0.189 s=call c=IN IP4 192.168.0.189 t=0 0 m=audio 10710 RTP/AVP 8 101 a=crypto:1 AES_CM_128_HMAC_SHA1_32 inline:aPKYs7WbjhdElVlLZS1X422+Vo+iKXnyyGiSNtsz a=rtpmap:8 pcma/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=encryption:optional a=sendrecv Jul 24 11:54:13 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 0: SIP/2.0 200 Ok (14) Jul 24 11:54:13 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.0.25:5060;branch=z9hG4bK7418798c;rport=5060 (68) Jul 24 11:54:13 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 2: From: "snom" ;tag=as165ec945 (49) Jul 24 11:54:13 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 3: To: ;tag=oe3qaheqd7 (60) Jul 24 11:54:13 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 4: Call-ID: 3b4811ad1530aa5674197392245961fa@192.168.0.25 (54) Jul 24 11:54:13 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 5: CSeq: 102 INVITE (16) Jul 24 11:54:13 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 6: Contact: ;flow-id=1 (60) Jul 24 11:54:13 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 7: User-Agent: snom320/6.2 (23) Jul 24 11:54:13 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 8: Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO (88) Jul 24 11:54:13 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 9: Allow-Events: talk, hold, refer (31) Jul 24 11:54:13 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 10: Supported: timer, 100rel, replaces, callerid (44) Jul 24 11:54:13 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 11: Content-Type: application/sdp (29) Jul 24 11:54:13 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 12: Content-Length: 317 (19) Jul 24 11:54:13 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 13: (0) Jul 24 11:54:13 DEBUG[3885]: chan_sip.c:3404 parse_request: Line: v=0 (3) Jul 24 11:54:13 DEBUG[3885]: chan_sip.c:3404 parse_request: Line: o=root 1547310099 1547310100 IN IP4 192.168.0.189 (49) Jul 24 11:54:13 DEBUG[3885]: chan_sip.c:3404 parse_request: Line: s=call (6) Jul 24 11:54:13 DEBUG[3885]: chan_sip.c:3404 parse_request: Line: c=IN IP4 192.168.0.189 (22) Jul 24 11:54:13 DEBUG[3885]: chan_sip.c:3404 parse_request: Line: t=0 0 (5) Jul 24 11:54:13 DEBUG[3885]: chan_sip.c:3404 parse_request: Line: m=audio 10710 RTP/AVP 8 101 (27) Jul 24 11:54:13 DEBUG[3885]: chan_sip.c:3404 parse_request: Line: a=crypto:1 AES_CM_128_HMAC_SHA1_32 inline:aPKYs7WbjhdElVlLZS1X422+Vo+iKXnyyGiSNtsz (82) Jul 24 11:54:13 DEBUG[3885]: chan_sip.c:3404 parse_request: Line: a=rtpmap:8 pcma/8000 (20) Jul 24 11:54:13 DEBUG[3885]: chan_sip.c:3404 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) Jul 24 11:54:13 DEBUG[3885]: chan_sip.c:3404 parse_request: Line: a=fmtp:101 0-16 (15) Jul 24 11:54:13 DEBUG[3885]: chan_sip.c:3404 parse_request: Line: a=encryption:optional (21) Jul 24 11:54:13 DEBUG[3885]: chan_sip.c:3404 parse_request: Line: a=sendrecv (10) --- (13 headers 12 lines)--- Jul 24 11:54:13 DEBUG[3885]: chan_sip.c:1382 __sip_ack: Acked pending invite 102 Jul 24 11:54:13 DEBUG[3885]: chan_sip.c:1404 __sip_ack: Stopping retransmission on '3b4811ad1530aa5674197392245961fa@192.168.0.25' of Request 102: Match Found Jul 24 11:54:13 DEBUG[3885]: chan_sip.c:9646 handle_response_invite: SIP response 200 to standard invite Found RTP audio format 8 Found RTP audio format 101 Peer audio RTP is at port 192.168.0.189:10710 Jul 24 11:54:13 DEBUG[3885]: chan_sip.c:3613 process_sdp: Peer audio RTP is at port 192.168.0.189:10710 Found description format pcma Found description format telephone-event Capabilities: us - 0x1f07ff (g723|gsm|ulaw|alaw|g726|adpcm|slin|lpc10|g729|speex|ilbc|jpeg|png|h261|h263|h263p), peer - audio=0x8 (alaw)/video=0x0 (nothing), combined - 0x8 (alaw) Non-codec capabilities: us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) Jul 24 11:54:13 DEBUG[3885]: chan_sip.c:6172 build_route: build_route: Contact hop: ;flow-id=1 list_route: hop: set_destination: Parsing for address/port to send to set_destination: set destination to 192.168.0.189, port 2054 Transmitting (no NAT) to 192.168.0.189:2054: ACK sip:11@192.168.0.189:2054;line=sczhjqwm SIP/2.0 Via: SIP/2.0/UDP 192.168.0.25:5060;branch=z9hG4bK6ee3670f;rport From: "snom" ;tag=as165ec945 To: ;tag=oe3qaheqd7 Contact: Call-ID: 3b4811ad1530aa5674197392245961fa@192.168.0.25 CSeq: 102 ACK User-Agent: Asterisk PBX Max-Forwards: 70 Content-Length: 0 --- -- SIP/11-47ac answered SIP/10-15f3 Jul 24 11:54:13 DEBUG[3976]: channel.c:2350 set_format: Set channel SIP/10-15f3 to read format alaw Jul 24 11:54:13 DEBUG[3976]: channel.c:2350 set_format: Set channel SIP/11-47ac to write format alaw Jul 24 11:54:13 DEBUG[3976]: channel.c:2350 set_format: Set channel SIP/11-47ac to read format alaw Jul 24 11:54:13 DEBUG[3976]: channel.c:2350 set_format: Set channel SIP/10-15f3 to write format alaw Jul 24 11:54:13 DEBUG[3976]: chan_sip.c:2549 sip_answer: sip_answer(SIP/10-15f3) We're at 192.168.0.25 port 12802 Adding codec 0x8 (alaw) to SDP Adding codec 0x4 (ulaw) to SDP Adding codec 0x2 (gsm) to SDP Adding codec 0x100 (g729) to SDP Adding codec 0x1 (g723) to SDP Adding codec 0x10 (g726) to SDP Adding non-codec 0x1 (telephone-event) to SDP Reliably Transmitting (no NAT) to 192.168.0.163:2051: SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.0.163:2051;branch=z9hG4bK-j7u3pi4981dj;rport;received=192.168.0.163 From: "snom" ;tag=ls79hgc0bt To: ;tag=as349f01f5 Call-ID: 3c2bc9a7afc8-us5jzg0io0z5@snom360 CSeq: 2 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Contact: Content-Type: application/sdp Content-Length: 359 v=0 o=root 2555 2555 IN IP4 192.168.0.25 s=session c=IN IP4 192.168.0.25 t=0 0 m=audio 12802 RTP/AVP 8 0 3 18 4 2 101 a=rtpmap:8 PCMA/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:3 GSM/8000 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:4 G723/8000 a=rtpmap:2 G726-32/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - --- Jul 24 11:54:13 DEBUG[3976]: chan_sip.c:1296 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #95 -- Attempting native bridge of SIP/10-15f3 and SIP/11-47ac Jul 24 11:54:13 DEBUG[3872]: chan_sip.c:11781 sip_devicestate: Checking device state for peer 11 Jul 24 11:54:13 DEBUG[3872]: devicestate.c:187 do_state_change: Changing state for SIP/11 - state 2 (In use) Jul 24 11:54:13 DEBUG[3872]: chan_sip.c:11781 sip_devicestate: Checking device state for peer 11 Jul 24 11:54:13 DEBUG[3872]: chan_sip.c:11781 sip_devicestate: Checking device state for peer 10 Jul 24 11:54:13 DEBUG[3872]: devicestate.c:187 do_state_change: Changing state for SIP/10 - state 2 (In use) Jul 24 11:54:13 DEBUG[3872]: chan_sip.c:11781 sip_devicestate: Checking device state for peer 10 Jul 24 11:54:13 DEBUG[3981]: app_queue.c:523 changethread: Device 'SIP/11' changed to state '2' (In use) but we don't care because they're not a member of any queue. Jul 24 11:54:13 DEBUG[3982]: app_queue.c:523 changethread: Device 'SIP/10' changed to state '2' (In use) but we don't care because they're not a member of any queue. Jul 24 11:54:13 DEBUG[3976]: chan_sip.c:3016 sip_rtp_read: Oooh, format changed to 4 Jul 24 11:54:13 DEBUG[3976]: channel.c:2350 set_format: Set channel SIP/11-47ac to read format alaw Jul 24 11:54:13 DEBUG[3976]: channel.c:2350 set_format: Set channel SIP/11-47ac to write format alaw Jul 24 11:54:13 DEBUG[3976]: rtp.c:1352 ast_rtp_write: Ooh, format changed from unknown to alaw Jul 24 11:54:13 DEBUG[3976]: channel.c:2350 set_format: Set channel SIP/10-15f3 to read format slin Jul 24 11:54:13 DEBUG[3976]: channel.c:2350 set_format: Set channel SIP/11-47ac to write format slin Jul 24 11:54:13 DEBUG[3976]: channel.c:2350 set_format: Set channel SIP/11-47ac to read format slin Jul 24 11:54:13 DEBUG[3976]: channel.c:2350 set_format: Set channel SIP/10-15f3 to write format slin ultravoX*CLI> <-- SIP read from 192.168.0.163:2051: ACK sip:11@192.168.0.25 SIP/2.0 Via: SIP/2.0/UDP 192.168.0.163:2051;branch=z9hG4bK-7rbfuxoua5dl;rport From: "snom" ;tag=ls79hgc0bt To: ;tag=as349f01f5 Call-ID: 3c2bc9a7afc8-us5jzg0io0z5@snom360 CSeq: 2 ACK Max-Forwards: 70 Contact: Content-Length: 0 Jul 24 11:54:13 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 0: ACK sip:11@192.168.0.25 SIP/2.0 (31) Jul 24 11:54:13 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.0.163:2051;branch=z9hG4bK-7rbfuxoua5dl;rport (69) Jul 24 11:54:13 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 2: From: "snom" ;tag=ls79hgc0bt (49) Jul 24 11:54:13 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 3: To: ;tag=as349f01f5 (51) Jul 24 11:54:13 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 4: Call-ID: 3c2bc9a7afc8-us5jzg0io0z5@snom360 (42) Jul 24 11:54:13 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 5: CSeq: 2 ACK (11) Jul 24 11:54:13 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 6: Max-Forwards: 70 (16) Jul 24 11:54:13 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 7: Contact: (50) Jul 24 11:54:13 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 8: Content-Length: 0 (17) Jul 24 11:54:13 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 9: (0) --- (9 headers 0 lines)--- Jul 24 11:54:13 DEBUG[3885]: chan_sip.c:11246 handle_request: **** Received ACK (6) - Command in SIP ACK Jul 24 11:54:13 DEBUG[3885]: chan_sip.c:1393 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #95 Jul 24 11:54:13 DEBUG[3885]: chan_sip.c:1404 __sip_ack: Stopping retransmission on '3c2bc9a7afc8-us5jzg0io0z5@snom360' of Response 2: Match Found Jul 24 11:54:13 DEBUG[3976]: chan_sip.c:3016 sip_rtp_read: Oooh, format changed to 8 Jul 24 11:54:13 DEBUG[3976]: channel.c:2350 set_format: Set channel SIP/11-47ac to read format slin Jul 24 11:54:13 DEBUG[3976]: channel.c:2350 set_format: Set channel SIP/11-47ac to write format slin Jul 24 11:54:13 DEBUG[3976]: channel.c:2350 set_format: Set channel SIP/10-15f3 to read format alaw Jul 24 11:54:13 DEBUG[3976]: channel.c:2350 set_format: Set channel SIP/11-47ac to write format alaw Jul 24 11:54:13 DEBUG[3976]: channel.c:2350 set_format: Set channel SIP/11-47ac to read format alaw Jul 24 11:54:13 DEBUG[3976]: channel.c:2350 set_format: Set channel SIP/10-15f3 to write format alaw Jul 24 11:54:13 DEBUG[3976]: rtp.c:1352 ast_rtp_write: Ooh, format changed from unknown to alaw Jul 24 11:54:18 DEBUG[3976]: rtp.c:411 ast_rtcp_read: Got RTCP report of 52 bytes ultravoX*CLI> <-- SIP read from 192.168.0.189:2054: INVITE sip:10@192.168.0.25 SIP/2.0 Via: SIP/2.0/UDP 192.168.0.189:2054;branch=z9hG4bK-m4lpov8rhhfk;rport From: ;tag=oe3qaheqd7 To: "snom" ;tag=as165ec945 Call-ID: 3b4811ad1530aa5674197392245961fa@192.168.0.25 CSeq: 1 INVITE Max-Forwards: 70 Contact: ;flow-id=1 P-Key-Flags: keys="3" User-Agent: snom320/6.2 Accept: application/sdp Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO Allow-Events: talk, hold, refer Supported: timer, 100rel, replaces, callerid Session-Expires: 3600;refresher=uas Min-SE: 90 Content-Type: application/sdp Content-Length: 471 v=0 o=root 1547310099 1547310101 IN IP4 192.168.0.189 s=call c=IN IP4 0.0.0.0 t=0 0 m=audio 10710 RTP/AVP 0 8 9 2 3 18 4 101 a=crypto:1 AES_CM_128_HMAC_SHA1_32 inline:aPKYs7WbjhdElVlLZS1X422+Vo+iKXnyyGiSNtsz a=rtpmap:0 pcmu/8000 a=rtpmap:8 pcma/8000 a=rtpmap:9 g722/8000 a=rtpmap:2 g726-32/8000 a=rtpmap:3 gsm/8000 a=rtpmap:18 g729/8000 a=rtpmap:4 g723/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 a=encryption:optional a=sendonly Jul 24 11:54:18 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 0: INVITE sip:10@192.168.0.25 SIP/2.0 (34) Jul 24 11:54:18 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.0.189:2054;branch=z9hG4bK-m4lpov8rhhfk;rport (69) Jul 24 11:54:18 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 2: From: ;tag=oe3qaheqd7 (62) Jul 24 11:54:18 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 3: To: "snom" ;tag=as165ec945 (47) Jul 24 11:54:18 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 4: Call-ID: 3b4811ad1530aa5674197392245961fa@192.168.0.25 (54) Jul 24 11:54:18 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 5: CSeq: 1 INVITE (14) Jul 24 11:54:18 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 6: Max-Forwards: 70 (16) Jul 24 11:54:18 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 7: Contact: ;flow-id=1 (60) Jul 24 11:54:18 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 8: P-Key-Flags: keys="3" (21) Jul 24 11:54:18 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 9: User-Agent: snom320/6.2 (23) Jul 24 11:54:18 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 10: Accept: application/sdp (23) Jul 24 11:54:18 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 11: Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO (88) Jul 24 11:54:18 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 12: Allow-Events: talk, hold, refer (31) Jul 24 11:54:18 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 13: Supported: timer, 100rel, replaces, callerid (44) Jul 24 11:54:18 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 14: Session-Expires: 3600;refresher=uas (35) Jul 24 11:54:18 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 15: Min-SE: 90 (10) Jul 24 11:54:18 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 16: Content-Type: application/sdp (29) Jul 24 11:54:18 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 17: Content-Length: 471 (19) Jul 24 11:54:18 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 18: (0) Jul 24 11:54:18 DEBUG[3885]: chan_sip.c:3404 parse_request: Line: v=0 (3) Jul 24 11:54:18 DEBUG[3885]: chan_sip.c:3404 parse_request: Line: o=root 1547310099 1547310101 IN IP4 192.168.0.189 (49) Jul 24 11:54:18 DEBUG[3885]: chan_sip.c:3404 parse_request: Line: s=call (6) Jul 24 11:54:18 DEBUG[3885]: chan_sip.c:3404 parse_request: Line: c=IN IP4 0.0.0.0 (16) Jul 24 11:54:18 DEBUG[3885]: chan_sip.c:3404 parse_request: Line: t=0 0 (5) Jul 24 11:54:18 DEBUG[3885]: chan_sip.c:3404 parse_request: Line: m=audio 10710 RTP/AVP 0 8 9 2 3 18 4 101 (40) Jul 24 11:54:18 DEBUG[3885]: chan_sip.c:3404 parse_request: Line: a=crypto:1 AES_CM_128_HMAC_SHA1_32 inline:aPKYs7WbjhdElVlLZS1X422+Vo+iKXnyyGiSNtsz (82) Jul 24 11:54:18 DEBUG[3885]: chan_sip.c:3404 parse_request: Line: a=rtpmap:0 pcmu/8000 (20) Jul 24 11:54:18 DEBUG[3885]: chan_sip.c:3404 parse_request: Line: a=rtpmap:8 pcma/8000 (20) Jul 24 11:54:18 DEBUG[3885]: chan_sip.c:3404 parse_request: Line: a=rtpmap:9 g722/8000 (20) Jul 24 11:54:18 DEBUG[3885]: chan_sip.c:3404 parse_request: Line: a=rtpmap:2 g726-32/8000 (23) Jul 24 11:54:18 DEBUG[3885]: chan_sip.c:3404 parse_request: Line: a=rtpmap:3 gsm/8000 (19) Jul 24 11:54:18 DEBUG[3885]: chan_sip.c:3404 parse_request: Line: a=rtpmap:18 g729/8000 (21) Jul 24 11:54:18 DEBUG[3885]: chan_sip.c:3404 parse_request: Line: a=rtpmap:4 g723/8000 (20) Jul 24 11:54:18 DEBUG[3885]: chan_sip.c:3404 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) Jul 24 11:54:18 DEBUG[3885]: chan_sip.c:3404 parse_request: Line: a=fmtp:101 0-16 (15) Jul 24 11:54:18 DEBUG[3885]: chan_sip.c:3404 parse_request: Line: a=ptime:20 (10) Jul 24 11:54:18 DEBUG[3885]: chan_sip.c:3404 parse_request: Line: a=encryption:optional (21) Jul 24 11:54:18 DEBUG[3885]: chan_sip.c:3404 parse_request: Line: a=sendonly (10) --- (18 headers 19 lines)--- Jul 24 11:54:18 DEBUG[3885]: chan_sip.c:11246 handle_request: **** Received INVITE (5) - Command in SIP INVITE Jul 24 11:54:18 DEBUG[3885]: chan_sip.c:1007 parse_sip_options: Begin: parsing SIP "Supported: timer, 100rel, replaces, callerid" Jul 24 11:54:18 DEBUG[3885]: chan_sip.c:1019 parse_sip_options: Found SIP option: -timer- Jul 24 11:54:18 DEBUG[3885]: chan_sip.c:1025 parse_sip_options: Matched SIP option: timer Jul 24 11:54:18 DEBUG[3885]: chan_sip.c:1019 parse_sip_options: Found SIP option: -100rel- Jul 24 11:54:18 DEBUG[3885]: chan_sip.c:1025 parse_sip_options: Matched SIP option: 100rel Jul 24 11:54:18 DEBUG[3885]: chan_sip.c:1019 parse_sip_options: Found SIP option: -replaces- Jul 24 11:54:18 DEBUG[3885]: chan_sip.c:1025 parse_sip_options: Matched SIP option: replaces Jul 24 11:54:18 DEBUG[3885]: chan_sip.c:1019 parse_sip_options: Found SIP option: -callerid- Jul 24 11:54:18 DEBUG[3885]: chan_sip.c:1030 parse_sip_options: Found no match for SIP option: callerid (Please file bug report!) Jul 24 11:54:18 DEBUG[3885]: chan_sip.c:1036 parse_sip_options: * SIP extension value: 7 for call 3b4811ad1530aa5674197392245961fa@192.168.0.25 Using INVITE request as basis request - 3b4811ad1530aa5674197392245961fa@192.168.0.25 Sending to 192.168.0.189 : 2054 (NAT) Found RTP audio format 0 Found RTP audio format 8 Found RTP audio format 9 Found RTP audio format 2 Found RTP audio format 3 Found RTP audio format 18 Found RTP audio format 4 Found RTP audio format 101 Peer audio RTP is at port 0.0.0.0:10710 Jul 24 11:54:18 DEBUG[3885]: chan_sip.c:3613 process_sdp: Peer audio RTP is at port 0.0.0.0:10710 Found description format pcmu Found description format pcma Found description format g722 Found description format g726-32 Found description format gsm Found description format g729 Found description format g723 Found description format telephone-event Capabilities: us - 0x1f07ff (g723|gsm|ulaw|alaw|g726|adpcm|slin|lpc10|g729|speex|ilbc|jpeg|png|h261|h263|h263p), peer - audio=0x11f (g723|gsm|ulaw|alaw|g726|g729)/video=0x0 (nothing), combined - 0x11f (g723|gsm|ulaw|alaw|g726|g729) Non-codec capabilities: us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) Jul 24 11:54:18 DEBUG[3885]: channel.c:2350 set_format: Set channel SIP/10-15f3 to write format slin -- Started music on hold, class 'default', on channel 'SIP/10-15f3' Jul 24 11:54:18 DEBUG[3885]: channel.c:1711 ast_settimeout: Scheduling timer at 160 sample intervals Jul 24 11:54:18 DEBUG[3885]: chan_sip.c:10660 handle_request_invite: Got a SIP re-invite for call 3b4811ad1530aa5674197392245961fa@192.168.0.25 We're at 192.168.0.25 port 17146 Adding codec 0x8 (alaw) to SDP Adding codec 0x4 (ulaw) to SDP Adding codec 0x2 (gsm) to SDP Adding codec 0x100 (g729) to SDP Adding codec 0x1 (g723) to SDP Adding codec 0x10 (g726) to SDP Adding non-codec 0x1 (telephone-event) to SDP Reliably Transmitting (NAT) to 192.168.0.189:2054: SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.0.189:2054;branch=z9hG4bK-m4lpov8rhhfk;received=192.168.0.189;rport=2054 From: ;tag=oe3qaheqd7 To: "snom" ;tag=as165ec945 Call-ID: 3b4811ad1530aa5674197392245961fa@192.168.0.25 CSeq: 1 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Contact: Content-Type: application/sdp Content-Length: 359 v=0 o=root 2555 2556 IN IP4 192.168.0.25 s=session c=IN IP4 192.168.0.25 t=0 0 m=audio 17146 RTP/AVP 8 0 3 18 4 2 101 a=rtpmap:8 PCMA/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:3 GSM/8000 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:4 G723/8000 a=rtpmap:2 G726-32/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - --- Jul 24 11:54:18 DEBUG[3885]: chan_sip.c:1296 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #96 Jul 24 11:54:18 DEBUG[3976]: channel.c:1975 ast_read: Generator got voice, switching to phase locked mode Jul 24 11:54:18 DEBUG[3976]: channel.c:1711 ast_settimeout: Scheduling timer at 0 sample intervals ultravoX*CLI> <-- SIP read from 192.168.0.189:2054: ACK sip:10@192.168.0.25 SIP/2.0 Via: SIP/2.0/UDP 192.168.0.189:2054;branch=z9hG4bK-7ynay1e8y86j;rport From: ;tag=oe3qaheqd7 To: "snom" ;tag=as165ec945 Call-ID: 3b4811ad1530aa5674197392245961fa@192.168.0.25 CSeq: 1 ACK Max-Forwards: 70 Contact: ;flow-id=1 Content-Length: 0 Jul 24 11:54:18 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 0: ACK sip:10@192.168.0.25 SIP/2.0 (31) Jul 24 11:54:18 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.0.189:2054;branch=z9hG4bK-7ynay1e8y86j;rport (69) Jul 24 11:54:18 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 2: From: ;tag=oe3qaheqd7 (62) Jul 24 11:54:18 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 3: To: "snom" ;tag=as165ec945 (47) Jul 24 11:54:18 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 4: Call-ID: 3b4811ad1530aa5674197392245961fa@192.168.0.25 (54) Jul 24 11:54:18 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 5: CSeq: 1 ACK (11) Jul 24 11:54:18 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 6: Max-Forwards: 70 (16) Jul 24 11:54:18 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 7: Contact: ;flow-id=1 (60) Jul 24 11:54:18 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 8: Content-Length: 0 (17) Jul 24 11:54:18 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 9: (0) --- (9 headers 0 lines)--- Jul 24 11:54:18 DEBUG[3885]: chan_sip.c:11246 handle_request: **** Received ACK (6) - Command in SIP ACK Jul 24 11:54:18 DEBUG[3885]: chan_sip.c:1393 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #96 Jul 24 11:54:18 DEBUG[3885]: chan_sip.c:1404 __sip_ack: Stopping retransmission on '3b4811ad1530aa5674197392245961fa@192.168.0.25' of Response 1: Match Found ultravoX*CLI> <-- SIP read from 192.168.0.189:2054: INVITE sip:13@192.168.0.25 SIP/2.0 Via: SIP/2.0/UDP 192.168.0.189:2054;branch=z9hG4bK-6hlgvon911fr;rport From: "test" ;tag=ha8sklk5y5 To: Call-ID: 3c26d02c15f9-59hhmt9sgje0@snom320-000413240554 CSeq: 1 INVITE Max-Forwards: 70 Contact: ;flow-id=1 P-Key-Flags: keys="3" User-Agent: snom320/6.2 Accept: application/sdp Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO Allow-Events: talk, hold, refer Supported: timer, 100rel, replaces, callerid Session-Expires: 3600;refresher=uas Min-SE: 90 Content-Type: application/sdp Content-Length: 477 v=0 o=root 1364337492 1364337492 IN IP4 192.168.0.189 s=call c=IN IP4 192.168.0.189 t=0 0 m=audio 10868 RTP/AVP 0 8 9 2 3 18 4 101 a=crypto:1 AES_CM_128_HMAC_SHA1_32 inline:xkrbdbjDfnVVnLufJ/zG/zuf0cj4vmkyW99t/kan a=rtpmap:0 pcmu/8000 a=rtpmap:8 pcma/8000 a=rtpmap:9 g722/8000 a=rtpmap:2 g726-32/8000 a=rtpmap:3 gsm/8000 a=rtpmap:18 g729/8000 a=rtpmap:4 g723/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 a=encryption:optional a=sendrecv Jul 24 11:54:26 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 0: INVITE sip:13@192.168.0.25 SIP/2.0 (34) Jul 24 11:54:26 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.0.189:2054;branch=z9hG4bK-6hlgvon911fr;rport (69) Jul 24 11:54:26 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 2: From: "test" ;tag=ha8sklk5y5 (49) Jul 24 11:54:26 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 3: To: (25) Jul 24 11:54:26 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 4: Call-ID: 3c26d02c15f9-59hhmt9sgje0@snom320-000413240554 (55) Jul 24 11:54:26 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 5: CSeq: 1 INVITE (14) Jul 24 11:54:26 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 6: Max-Forwards: 70 (16) Jul 24 11:54:26 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 7: Contact: ;flow-id=1 (60) Jul 24 11:54:26 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 8: P-Key-Flags: keys="3" (21) Jul 24 11:54:26 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 9: User-Agent: snom320/6.2 (23) Jul 24 11:54:26 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 10: Accept: application/sdp (23) Jul 24 11:54:26 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 11: Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO (88) Jul 24 11:54:26 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 12: Allow-Events: talk, hold, refer (31) Jul 24 11:54:26 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 13: Supported: timer, 100rel, replaces, callerid (44) Jul 24 11:54:26 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 14: Session-Expires: 3600;refresher=uas (35) Jul 24 11:54:26 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 15: Min-SE: 90 (10) Jul 24 11:54:26 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 16: Content-Type: application/sdp (29) Jul 24 11:54:26 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 17: Content-Length: 477 (19) Jul 24 11:54:26 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 18: (0) Jul 24 11:54:26 DEBUG[3885]: chan_sip.c:3404 parse_request: Line: v=0 (3) Jul 24 11:54:26 DEBUG[3885]: chan_sip.c:3404 parse_request: Line: o=root 1364337492 1364337492 IN IP4 192.168.0.189 (49) Jul 24 11:54:26 DEBUG[3885]: chan_sip.c:3404 parse_request: Line: s=call (6) Jul 24 11:54:26 DEBUG[3885]: chan_sip.c:3404 parse_request: Line: c=IN IP4 192.168.0.189 (22) Jul 24 11:54:26 DEBUG[3885]: chan_sip.c:3404 parse_request: Line: t=0 0 (5) Jul 24 11:54:26 DEBUG[3885]: chan_sip.c:3404 parse_request: Line: m=audio 10868 RTP/AVP 0 8 9 2 3 18 4 101 (40) Jul 24 11:54:26 DEBUG[3885]: chan_sip.c:3404 parse_request: Line: a=crypto:1 AES_CM_128_HMAC_SHA1_32 inline:xkrbdbjDfnVVnLufJ/zG/zuf0cj4vmkyW99t/kan (82) Jul 24 11:54:26 DEBUG[3885]: chan_sip.c:3404 parse_request: Line: a=rtpmap:0 pcmu/8000 (20) Jul 24 11:54:26 DEBUG[3885]: chan_sip.c:3404 parse_request: Line: a=rtpmap:8 pcma/8000 (20) Jul 24 11:54:26 DEBUG[3885]: chan_sip.c:3404 parse_request: Line: a=rtpmap:9 g722/8000 (20) Jul 24 11:54:26 DEBUG[3885]: chan_sip.c:3404 parse_request: Line: a=rtpmap:2 g726-32/8000 (23) Jul 24 11:54:26 DEBUG[3885]: chan_sip.c:3404 parse_request: Line: a=rtpmap:3 gsm/8000 (19) Jul 24 11:54:26 DEBUG[3885]: chan_sip.c:3404 parse_request: Line: a=rtpmap:18 g729/8000 (21) Jul 24 11:54:26 DEBUG[3885]: chan_sip.c:3404 parse_request: Line: a=rtpmap:4 g723/8000 (20) Jul 24 11:54:26 DEBUG[3885]: chan_sip.c:3404 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) Jul 24 11:54:26 DEBUG[3885]: chan_sip.c:3404 parse_request: Line: a=fmtp:101 0-16 (15) Jul 24 11:54:26 DEBUG[3885]: chan_sip.c:3404 parse_request: Line: a=ptime:20 (10) Jul 24 11:54:26 DEBUG[3885]: chan_sip.c:3404 parse_request: Line: a=encryption:optional (21) Jul 24 11:54:26 DEBUG[3885]: chan_sip.c:3404 parse_request: Line: a=sendrecv (10) --- (18 headers 19 lines)--- Jul 24 11:54:26 DEBUG[3885]: chan_sip.c:3156 sip_alloc: Allocating new SIP dialog for 3c26d02c15f9-59hhmt9sgje0@snom320-000413240554 - INVITE (With RTP) Jul 24 11:54:26 DEBUG[3885]: chan_sip.c:11246 handle_request: **** Received INVITE (5) - Command in SIP INVITE Jul 24 11:54:26 DEBUG[3885]: chan_sip.c:1007 parse_sip_options: Begin: parsing SIP "Supported: timer, 100rel, replaces, callerid" Jul 24 11:54:26 DEBUG[3885]: chan_sip.c:1019 parse_sip_options: Found SIP option: -timer- Jul 24 11:54:26 DEBUG[3885]: chan_sip.c:1025 parse_sip_options: Matched SIP option: timer Jul 24 11:54:26 DEBUG[3885]: chan_sip.c:1019 parse_sip_options: Found SIP option: -100rel- Jul 24 11:54:26 DEBUG[3885]: chan_sip.c:1025 parse_sip_options: Matched SIP option: 100rel Jul 24 11:54:26 DEBUG[3885]: chan_sip.c:1019 parse_sip_options: Found SIP option: -replaces- Jul 24 11:54:26 DEBUG[3885]: chan_sip.c:1025 parse_sip_options: Matched SIP option: replaces Jul 24 11:54:26 DEBUG[3885]: chan_sip.c:1019 parse_sip_options: Found SIP option: -callerid- Jul 24 11:54:26 DEBUG[3885]: chan_sip.c:1030 parse_sip_options: Found no match for SIP option: callerid (Please file bug report!) Jul 24 11:54:26 DEBUG[3885]: chan_sip.c:1036 parse_sip_options: * SIP extension value: 7 for call 3c26d02c15f9-59hhmt9sgje0@snom320-000413240554 Using INVITE request as basis request - 3c26d02c15f9-59hhmt9sgje0@snom320-000413240554 Sending to 192.168.0.189 : 2054 (NAT) Jul 24 11:54:26 DEBUG[3885]: chan_sip.c:7213 check_user_full: Setting NAT on RTP to 0 Reliably Transmitting (no NAT) to 192.168.0.189:2054: SIP/2.0 407 Proxy Authentication Required Via: SIP/2.0/UDP 192.168.0.189:2054;branch=z9hG4bK-6hlgvon911fr;rport;received=192.168.0.189 From: "test" ;tag=ha8sklk5y5 To: ;tag=as7293b874 Call-ID: 3c26d02c15f9-59hhmt9sgje0@snom320-000413240554 CSeq: 1 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Contact: Proxy-Authenticate: Digest realm="mydomain.tld", nonce="2e820dd8" Content-Length: 0 --- Jul 24 11:54:26 DEBUG[3885]: chan_sip.c:1296 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #97 Scheduling destruction of call '3c26d02c15f9-59hhmt9sgje0@snom320-000413240554' in 15000 ms Found user '11' ultravoX*CLI> <-- SIP read from 192.168.0.189:2054: ACK sip:13@192.168.0.25 SIP/2.0 Via: SIP/2.0/UDP 192.168.0.189:2054;branch=z9hG4bK-6hlgvon911fr;rport From: "test" ;tag=ha8sklk5y5 To: ;tag=as7293b874 Call-ID: 3c26d02c15f9-59hhmt9sgje0@snom320-000413240554 CSeq: 1 ACK Max-Forwards: 70 Contact: ;flow-id=1 Content-Length: 0 Jul 24 11:54:26 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 0: ACK sip:13@192.168.0.25 SIP/2.0 (31) Jul 24 11:54:26 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.0.189:2054;branch=z9hG4bK-6hlgvon911fr;rport (69) Jul 24 11:54:26 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 2: From: "test" ;tag=ha8sklk5y5 (49) Jul 24 11:54:26 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 3: To: ;tag=as7293b874 (40) Jul 24 11:54:26 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 4: Call-ID: 3c26d02c15f9-59hhmt9sgje0@snom320-000413240554 (55) Jul 24 11:54:26 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 5: CSeq: 1 ACK (11) Jul 24 11:54:26 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 6: Max-Forwards: 70 (16) Jul 24 11:54:26 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 7: Contact: ;flow-id=1 (60) Jul 24 11:54:26 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 8: Content-Length: 0 (17) Jul 24 11:54:26 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 9: (0) --- (9 headers 0 lines)--- Jul 24 11:54:26 DEBUG[3885]: chan_sip.c:11246 handle_request: **** Received ACK (6) - Command in SIP ACK Jul 24 11:54:26 DEBUG[3885]: chan_sip.c:1393 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #97 Jul 24 11:54:26 DEBUG[3885]: chan_sip.c:1404 __sip_ack: Stopping retransmission on '3c26d02c15f9-59hhmt9sgje0@snom320-000413240554' of Response 1: Match Found <-- SIP read from 192.168.0.189:2054: INVITE sip:13@192.168.0.25 SIP/2.0 Via: SIP/2.0/UDP 192.168.0.189:2054;branch=z9hG4bK-duhsbunfz8l7;rport From: "test" ;tag=ha8sklk5y5 To: Call-ID: 3c26d02c15f9-59hhmt9sgje0@snom320-000413240554 CSeq: 2 INVITE Max-Forwards: 70 Contact: ;flow-id=1 P-Key-Flags: keys="3" User-Agent: snom320/6.2 Accept: application/sdp Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO Allow-Events: talk, hold, refer Supported: timer, 100rel, replaces, callerid Session-Expires: 3600;refresher=uas Min-SE: 90 Proxy-Authorization: Digest username="11",realm="mydomain.tld",nonce="2e820dd8",uri="sip:13@192.168.0.25",response="2756d98e37422de94f86046bafbe056d",algorithm=md5 Content-Type: application/sdp Content-Length: 477 v=0 o=root 1364337492 1364337492 IN IP4 192.168.0.189 s=call c=IN IP4 192.168.0.189 t=0 0 m=audio 10868 RTP/AVP 0 8 9 2 3 18 4 101 a=crypto:1 AES_CM_128_HMAC_SHA1_32 inline:xkrbdbjDfnVVnLufJ/zG/zuf0cj4vmkyW99t/kan a=rtpmap:0 pcmu/8000 a=rtpmap:8 pcma/8000 a=rtpmap:9 g722/8000 a=rtpmap:2 g726-32/8000 a=rtpmap:3 gsm/8000 a=rtpmap:18 g729/8000 a=rtpmap:4 g723/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 a=encryption:optional a=sendrecv Jul 24 11:54:26 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 0: INVITE sip:13@192.168.0.25 SIP/2.0 (34) Jul 24 11:54:26 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.0.189:2054;branch=z9hG4bK-duhsbunfz8l7;rport (69) Jul 24 11:54:26 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 2: From: "test" ;tag=ha8sklk5y5 (49) Jul 24 11:54:26 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 3: To: (25) Jul 24 11:54:26 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 4: Call-ID: 3c26d02c15f9-59hhmt9sgje0@snom320-000413240554 (55) Jul 24 11:54:26 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 5: CSeq: 2 INVITE (14) Jul 24 11:54:26 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 6: Max-Forwards: 70 (16) Jul 24 11:54:26 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 7: Contact: ;flow-id=1 (60) Jul 24 11:54:26 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 8: P-Key-Flags: keys="3" (21) Jul 24 11:54:26 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 9: User-Agent: snom320/6.2 (23) Jul 24 11:54:26 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 10: Accept: application/sdp (23) Jul 24 11:54:26 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 11: Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO (88) Jul 24 11:54:26 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 12: Allow-Events: talk, hold, refer (31) Jul 24 11:54:26 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 13: Supported: timer, 100rel, replaces, callerid (44) Jul 24 11:54:26 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 14: Session-Expires: 3600;refresher=uas (35) Jul 24 11:54:26 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 15: Min-SE: 90 (10) Jul 24 11:54:26 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 16: Proxy-Authorization: Digest username="11",realm="mydomain.tld",nonce="2e820dd8",uri="sip:13@192.168.0.25",response="2756d98e37422de94f86046bafbe056d",algorithm=md5 (163) Jul 24 11:54:26 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 17: Content-Type: application/sdp (29) Jul 24 11:54:26 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 18: Content-Length: 477 (19) Jul 24 11:54:26 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 19: (0) Jul 24 11:54:26 DEBUG[3885]: chan_sip.c:3404 parse_request: Line: v=0 (3) Jul 24 11:54:26 DEBUG[3885]: chan_sip.c:3404 parse_request: Line: o=root 1364337492 1364337492 IN IP4 192.168.0.189 (49) Jul 24 11:54:26 DEBUG[3885]: chan_sip.c:3404 parse_request: Line: s=call (6) Jul 24 11:54:26 DEBUG[3885]: chan_sip.c:3404 parse_request: Line: c=IN IP4 192.168.0.189 (22) Jul 24 11:54:26 DEBUG[3885]: chan_sip.c:3404 parse_request: Line: t=0 0 (5) Jul 24 11:54:26 DEBUG[3885]: chan_sip.c:3404 parse_request: Line: m=audio 10868 RTP/AVP 0 8 9 2 3 18 4 101 (40) Jul 24 11:54:26 DEBUG[3885]: chan_sip.c:3404 parse_request: Line: a=crypto:1 AES_CM_128_HMAC_SHA1_32 inline:xkrbdbjDfnVVnLufJ/zG/zuf0cj4vmkyW99t/kan (82) Jul 24 11:54:26 DEBUG[3885]: chan_sip.c:3404 parse_request: Line: a=rtpmap:0 pcmu/8000 (20) Jul 24 11:54:26 DEBUG[3885]: chan_sip.c:3404 parse_request: Line: a=rtpmap:8 pcma/8000 (20) Jul 24 11:54:26 DEBUG[3885]: chan_sip.c:3404 parse_request: Line: a=rtpmap:9 g722/8000 (20) Jul 24 11:54:26 DEBUG[3885]: chan_sip.c:3404 parse_request: Line: a=rtpmap:2 g726-32/8000 (23) Jul 24 11:54:26 DEBUG[3885]: chan_sip.c:3404 parse_request: Line: a=rtpmap:3 gsm/8000 (19) Jul 24 11:54:26 DEBUG[3885]: chan_sip.c:3404 parse_request: Line: a=rtpmap:18 g729/8000 (21) Jul 24 11:54:26 DEBUG[3885]: chan_sip.c:3404 parse_request: Line: a=rtpmap:4 g723/8000 (20) Jul 24 11:54:26 DEBUG[3885]: chan_sip.c:3404 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) Jul 24 11:54:26 DEBUG[3885]: chan_sip.c:3404 parse_request: Line: a=fmtp:101 0-16 (15) Jul 24 11:54:26 DEBUG[3885]: chan_sip.c:3404 parse_request: Line: a=ptime:20 (10) Jul 24 11:54:26 DEBUG[3885]: chan_sip.c:3404 parse_request: Line: a=encryption:optional (21) Jul 24 11:54:26 DEBUG[3885]: chan_sip.c:3404 parse_request: Line: a=sendrecv (10) --- (19 headers 19 lines)--- Jul 24 11:54:26 DEBUG[3885]: chan_sip.c:11246 handle_request: **** Received INVITE (5) - Command in SIP INVITE Using INVITE request as basis request - 3c26d02c15f9-59hhmt9sgje0@snom320-000413240554 Sending to 192.168.0.189 : 2054 (NAT) Jul 24 11:54:26 DEBUG[3885]: chan_sip.c:7213 check_user_full: Setting NAT on RTP to 0 Found user '11' Found RTP audio format 0 Found RTP audio format 8 Found RTP audio format 9 Found RTP audio format 2 Found RTP audio format 3 Found RTP audio format 18 Found RTP audio format 4 Found RTP audio format 101 Peer audio RTP is at port 192.168.0.189:10868 Jul 24 11:54:26 DEBUG[3885]: chan_sip.c:3613 process_sdp: Peer audio RTP is at port 192.168.0.189:10868 Found description format pcmu Found description format pcma Found description format g722 Found description format g726-32 Found description format gsm Found description format g729 Found description format g723 Found description format telephone-event Capabilities: us - 0x1f07ff (g723|gsm|ulaw|alaw|g726|adpcm|slin|lpc10|g729|speex|ilbc|jpeg|png|h261|h263|h263p), peer - audio=0x11f (g723|gsm|ulaw|alaw|g726|g729)/video=0x0 (nothing), combined - 0x11f (g723|gsm|ulaw|alaw|g726|g729) Non-codec capabilities: us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) Jul 24 11:54:26 DEBUG[3885]: chan_sip.c:10573 handle_request_invite: Checking SIP call limits for device 11 Jul 24 11:54:26 DEBUG[3885]: chan_sip.c:2218 update_call_counter: Updating call counter for incoming call Looking for 13 in DefaultOutgoingRule (domain 192.168.0.25) Jul 24 11:54:26 DEBUG[3885]: chan_sip.c:6172 build_route: build_route: Contact hop: ;flow-id=1 list_route: hop: Transmitting (no NAT) to 192.168.0.189:2054: SIP/2.0 100 Trying Via: SIP/2.0/UDP 192.168.0.189:2054;branch=z9hG4bK-duhsbunfz8l7;rport;received=192.168.0.189 From: "test" ;tag=ha8sklk5y5 To: Call-ID: 3c26d02c15f9-59hhmt9sgje0@snom320-000413240554 CSeq: 2 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Contact: Content-Length: 0 --- Jul 24 11:54:26 DEBUG[3872]: chan_sip.c:11781 sip_devicestate: Checking device state for peer 11 Jul 24 11:54:26 DEBUG[3872]: devicestate.c:187 do_state_change: Changing state for SIP/11 - state 2 (In use) Jul 24 11:54:26 DEBUG[3872]: chan_sip.c:11781 sip_devicestate: Checking device state for peer 11 Jul 24 11:54:26 DEBUG[3983]: pbx.c:1677 pbx_extension_helper: Launching 'AGI' -- Executing AGI("SIP/11-f85f", "dial.php|entity=43&group=2&extension=13") in new stack -- Launched AGI Script /var/lib/asterisk/agi-bin/dial.php Jul 24 11:54:26 DEBUG[3984]: app_queue.c:523 changethread: Device 'SIP/11' changed to state '2' (In use) but we don't care because they're not a member of any queue. -- AGI Script Executing Application: (macro) Options: (stdexten|SIP/13) Jul 24 11:54:26 DEBUG[3983]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '13' Jul 24 11:54:26 DEBUG[3983]: pbx.c:1677 pbx_extension_helper: Launching 'Set' -- Executing Set("SIP/11-f85f", "EXTENSION=13") in new stack Jul 24 11:54:26 DEBUG[3983]: db.c:200 ast_db_get: Unable to find key '13' in family 'DND' Jul 24 11:54:26 DEBUG[3983]: func_db.c:69 function_db_read: DB: DND/13 not found in database. Jul 24 11:54:26 DEBUG[3983]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '' Jul 24 11:54:26 DEBUG[3983]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '0' Jul 24 11:54:26 DEBUG[3983]: pbx.c:1677 pbx_extension_helper: Launching 'GotoIf' -- Executing GotoIf("SIP/11-f85f", "0?s-BUSY|1") in new stack Jul 24 11:54:26 DEBUG[3983]: pbx.c:6175 pbx_builtin_gotoif: Not taking any branch Jul 24 11:54:26 DEBUG[3983]: db.c:200 ast_db_get: Unable to find key '13' in family 'CFU' Jul 24 11:54:26 DEBUG[3983]: func_db.c:69 function_db_read: DB: CFU/13 not found in database. Jul 24 11:54:26 DEBUG[3983]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '' Jul 24 11:54:26 DEBUG[3983]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '0' Jul 24 11:54:26 DEBUG[3983]: db.c:200 ast_db_get: Unable to find key 'SIP/13' in family 'CFU' Jul 24 11:54:26 DEBUG[3983]: func_db.c:69 function_db_read: DB: CFU/SIP/13 not found in database. Jul 24 11:54:26 DEBUG[3983]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '' Jul 24 11:54:26 DEBUG[3983]: pbx.c:1677 pbx_extension_helper: Launching 'GotoIf' -- Executing GotoIf("SIP/11-f85f", "0?DefaultOutgoingRule||1") in new stack Jul 24 11:54:26 DEBUG[3983]: pbx.c:6175 pbx_builtin_gotoif: Not taking any branch Jul 24 11:54:26 DEBUG[3983]: pbx.c:1677 pbx_extension_helper: Launching 'Dial' -- Executing Dial("SIP/11-f85f", "SIP/13|20|tTwW") in new stack Jul 24 11:54:26 DEBUG[3983]: chan_sip.c:3156 sip_alloc: Allocating new SIP dialog for (No Call-ID) - INVITE (With RTP) Jul 24 11:54:26 DEBUG[3983]: chan_sip.c:1877 create_addr_from_peer: Setting NAT on RTP to 0 Jul 24 11:54:26 DEBUG[3983]: channel.c:2823 ast_channel_inherit_variables: Not copying variable STACK-macro-stdexten-s-4. Jul 24 11:54:26 DEBUG[3983]: channel.c:2823 ast_channel_inherit_variables: Not copying variable MACRO_DEPTH. Jul 24 11:54:26 DEBUG[3983]: channel.c:2823 ast_channel_inherit_variables: Not copying variable STACK-macro-stdexten-s-3. Jul 24 11:54:26 DEBUG[3983]: channel.c:2823 ast_channel_inherit_variables: Not copying variable STACK-macro-stdexten-s-2. Jul 24 11:54:26 DEBUG[3983]: channel.c:2823 ast_channel_inherit_variables: Not copying variable EXTENSION. Jul 24 11:54:26 DEBUG[3983]: channel.c:2823 ast_channel_inherit_variables: Not copying variable STACK-macro-stdexten-s-1. Jul 24 11:54:26 DEBUG[3983]: channel.c:2823 ast_channel_inherit_variables: Not copying variable ARG1. Jul 24 11:54:26 DEBUG[3983]: channel.c:2823 ast_channel_inherit_variables: Not copying variable MACRO_PRIORITY. Jul 24 11:54:26 DEBUG[3983]: channel.c:2823 ast_channel_inherit_variables: Not copying variable MACRO_CONTEXT. Jul 24 11:54:26 DEBUG[3983]: channel.c:2823 ast_channel_inherit_variables: Not copying variable MACRO_EXTEN. Jul 24 11:54:26 DEBUG[3983]: channel.c:2823 ast_channel_inherit_variables: Not copying variable STACK-DefaultOutgoingRule-13-1. Jul 24 11:54:26 DEBUG[3983]: channel.c:2823 ast_channel_inherit_variables: Not copying variable SIPCALLID. Jul 24 11:54:26 DEBUG[3983]: channel.c:2823 ast_channel_inherit_variables: Not copying variable SIPUSERAGENT. Jul 24 11:54:26 DEBUG[3983]: channel.c:2823 ast_channel_inherit_variables: Not copying variable SIPDOMAIN. Jul 24 11:54:26 DEBUG[3983]: channel.c:2823 ast_channel_inherit_variables: Not copying variable SIPURI. Jul 24 11:54:26 DEBUG[3983]: chan_sip.c:2077 sip_call: Outgoing Call for 13 Jul 24 11:54:26 DEBUG[3983]: chan_sip.c:2218 update_call_counter: Updating call counter for outgoing call We're at 192.168.0.25 port 13508 Adding codec 0x8 (alaw) to SDP Adding codec 0x4 (ulaw) to SDP Adding codec 0x2 (gsm) to SDP Adding codec 0x400 (ilbc) to SDP Adding codec 0x100 (g729) to SDP Adding codec 0x1 (g723) to SDP Adding codec 0x10 (g726) to SDP Adding codec 0x20 (adpcm) to SDP Adding codec 0x40 (slin) to SDP Adding codec 0x80 (lpc10) to SDP Adding codec 0x200 (speex) to SDP Adding non-codec 0x1 (telephone-event) to SDP Jul 24 11:54:26 DEBUG[3983]: chan_sip.c:3372 parse_request: Header 0: INVITE sip:13@192.168.0.190:2051;line=no7rb4d3 SIP/2.0 (54) Jul 24 11:54:26 DEBUG[3983]: chan_sip.c:3372 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.0.25:5060;branch=z9hG4bK42235889;rport (63) Jul 24 11:54:26 DEBUG[3983]: chan_sip.c:3372 parse_request: Header 2: From: "snom2" ;tag=as536cf13e (50) Jul 24 11:54:26 DEBUG[3983]: chan_sip.c:3372 parse_request: Header 3: To: (45) Jul 24 11:54:26 DEBUG[3983]: chan_sip.c:3372 parse_request: Header 4: Contact: (30) Jul 24 11:54:26 DEBUG[3983]: chan_sip.c:3372 parse_request: Header 5: Call-ID: 1bdd7cc92bbe978c07c94d4d2c5daefb@192.168.0.25 (54) Jul 24 11:54:26 DEBUG[3983]: chan_sip.c:3372 parse_request: Header 6: CSeq: 102 INVITE (16) Jul 24 11:54:26 DEBUG[3983]: chan_sip.c:3372 parse_request: Header 7: User-Agent: Asterisk PBX (24) Jul 24 11:54:26 DEBUG[3983]: chan_sip.c:3372 parse_request: Header 8: Max-Forwards: 70 (16) Jul 24 11:54:26 DEBUG[3983]: chan_sip.c:3372 parse_request: Header 9: Date: Mon, 24 Jul 2006 09:54:26 GMT (35) Jul 24 11:54:26 DEBUG[3983]: chan_sip.c:3372 parse_request: Header 10: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) Jul 24 11:54:26 DEBUG[3983]: chan_sip.c:3372 parse_request: Header 11: Content-Type: application/sdp (29) Jul 24 11:54:26 DEBUG[3983]: chan_sip.c:3372 parse_request: Header 12: Content-Length: 490 (19) Jul 24 11:54:26 DEBUG[3983]: chan_sip.c:3372 parse_request: Header 13: (0) Jul 24 11:54:26 DEBUG[3983]: chan_sip.c:3404 parse_request: Line: v=0 (3) Jul 24 11:54:26 DEBUG[3983]: chan_sip.c:3404 parse_request: Line: o=root 2555 2555 IN IP4 192.168.0.25 (36) Jul 24 11:54:26 DEBUG[3983]: chan_sip.c:3404 parse_request: Line: s=session (9) Jul 24 11:54:26 DEBUG[3983]: chan_sip.c:3404 parse_request: Line: c=IN IP4 192.168.0.25 (21) Jul 24 11:54:26 DEBUG[3983]: chan_sip.c:3404 parse_request: Line: t=0 0 (5) Jul 24 11:54:26 DEBUG[3983]: chan_sip.c:3404 parse_request: Line: m=audio 13508 RTP/AVP 8 0 3 97 18 4 111 5 10 7 110 101 (54) Jul 24 11:54:26 DEBUG[3983]: chan_sip.c:3404 parse_request: Line: a=rtpmap:8 PCMA/8000 (20) Jul 24 11:54:26 DEBUG[3983]: chan_sip.c:3404 parse_request: Line: a=rtpmap:0 PCMU/8000 (20) Jul 24 11:54:26 DEBUG[3983]: chan_sip.c:3404 parse_request: Line: a=rtpmap:3 GSM/8000 (19) Jul 24 11:54:26 DEBUG[3983]: chan_sip.c:3404 parse_request: Line: a=rtpmap:97 iLBC/8000 (21) Jul 24 11:54:26 DEBUG[3983]: chan_sip.c:3404 parse_request: Line: a=rtpmap:18 G729/8000 (21) Jul 24 11:54:26 DEBUG[3983]: chan_sip.c:3404 parse_request: Line: a=fmtp:18 annexb=no (19) Jul 24 11:54:26 DEBUG[3983]: chan_sip.c:3404 parse_request: Line: a=rtpmap:4 G723/8000 (20) Jul 24 11:54:26 DEBUG[3983]: chan_sip.c:3404 parse_request: Line: a=rtpmap:111 G726-32/8000 (25) Jul 24 11:54:26 DEBUG[3983]: chan_sip.c:3404 parse_request: Line: a=rtpmap:5 DVI4/8000 (20) Jul 24 11:54:26 DEBUG[3983]: chan_sip.c:3404 parse_request: Line: a=rtpmap:10 L16/8000 (20) Jul 24 11:54:26 DEBUG[3983]: chan_sip.c:3404 parse_request: Line: a=rtpmap:7 LPC/8000 (19) Jul 24 11:54:26 DEBUG[3983]: chan_sip.c:3404 parse_request: Line: a=rtpmap:110 speex/8000 (23) Jul 24 11:54:26 DEBUG[3983]: chan_sip.c:3404 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) Jul 24 11:54:26 DEBUG[3983]: chan_sip.c:3404 parse_request: Line: a=fmtp:101 0-16 (15) Jul 24 11:54:26 DEBUG[3983]: chan_sip.c:3404 parse_request: Line: a=silenceSupp:off - - - - (25) 13 headers, 21 lines Reliably Transmitting (no NAT) to 192.168.0.190:2051: INVITE sip:13@192.168.0.190:2051;line=no7rb4d3 SIP/2.0 Via: SIP/2.0/UDP 192.168.0.25:5060;branch=z9hG4bK42235889;rport From: "snom2" ;tag=as536cf13e To: Contact: Call-ID: 1bdd7cc92bbe978c07c94d4d2c5daefb@192.168.0.25 CSeq: 102 INVITE User-Agent: Asterisk PBX Max-Forwards: 70 Date: Mon, 24 Jul 2006 09:54:26 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Content-Type: application/sdp Content-Length: 490 v=0 o=root 2555 2555 IN IP4 192.168.0.25 s=session c=IN IP4 192.168.0.25 t=0 0 m=audio 13508 RTP/AVP 8 0 3 97 18 4 111 5 10 7 110 101 a=rtpmap:8 PCMA/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:3 GSM/8000 a=rtpmap:97 iLBC/8000 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:4 G723/8000 a=rtpmap:111 G726-32/8000 a=rtpmap:5 DVI4/8000 a=rtpmap:10 L16/8000 a=rtpmap:7 LPC/8000 a=rtpmap:110 speex/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - --- Jul 24 11:54:26 DEBUG[3983]: chan_sip.c:1296 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #99 -- Called 13 Jul 24 11:54:26 DEBUG[3983]: channel.c:2350 set_format: Set channel SIP/13-031d to read format alaw Jul 24 11:54:26 DEBUG[3983]: channel.c:2350 set_format: Set channel SIP/11-f85f to write format alaw Jul 24 11:54:26 DEBUG[3983]: channel.c:2350 set_format: Set channel SIP/11-f85f to read format alaw Jul 24 11:54:26 DEBUG[3983]: channel.c:2350 set_format: Set channel SIP/13-031d to write format alaw ultravoX*CLI> <-- SIP read from 192.168.0.190:2051: SIP/2.0 180 Ringing Via: SIP/2.0/UDP 192.168.0.25:5060;branch=z9hG4bK42235889;rport=5060 From: "snom2" ;tag=as536cf13e To: ;tag=1rwoq1h92u Call-ID: 1bdd7cc92bbe978c07c94d4d2c5daefb@192.168.0.25 CSeq: 102 INVITE Contact: Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO Allow-Events: talk, hold, refer Content-Length: 0 Jul 24 11:54:27 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 0: SIP/2.0 180 Ringing (19) Jul 24 11:54:27 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.0.25:5060;branch=z9hG4bK42235889;rport=5060 (68) Jul 24 11:54:27 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 2: From: "snom2" ;tag=as536cf13e (50) Jul 24 11:54:27 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 3: To: ;tag=1rwoq1h92u (60) Jul 24 11:54:27 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 4: Call-ID: 1bdd7cc92bbe978c07c94d4d2c5daefb@192.168.0.25 (54) Jul 24 11:54:27 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 5: CSeq: 102 INVITE (16) Jul 24 11:54:27 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 6: Contact: (50) Jul 24 11:54:27 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 7: Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO (88) Jul 24 11:54:27 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 8: Allow-Events: talk, hold, refer (31) Jul 24 11:54:27 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 9: Content-Length: 0 (17) Jul 24 11:54:27 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 10: (0) --- (10 headers 0 lines)--- Jul 24 11:54:27 DEBUG[3885]: chan_sip.c:1448 __sip_semi_ack: *** SIP TIMER: Cancelling retransmission #99 - INVITE (got response) Jul 24 11:54:27 DEBUG[3885]: chan_sip.c:1457 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '1bdd7cc92bbe978c07c94d4d2c5daefb@192.168.0.25' Request 102: Found Jul 24 11:54:27 DEBUG[3885]: chan_sip.c:9646 handle_response_invite: SIP response 180 to standard invite Jul 24 11:54:27 DEBUG[3872]: chan_sip.c:11781 sip_devicestate: Checking device state for peer 13 Jul 24 11:54:27 DEBUG[3872]: devicestate.c:187 do_state_change: Changing state for SIP/13 - state 6 (Ringing) Jul 24 11:54:27 DEBUG[3872]: chan_sip.c:11781 sip_devicestate: Checking device state for peer 13 Jul 24 11:54:27 DEBUG[3987]: app_queue.c:523 changethread: Device 'SIP/13' changed to state '6' (Ringing) but we don't care because they're not a member of any queue. -- SIP/13-031d is ringing Transmitting (no NAT) to 192.168.0.189:2054: SIP/2.0 180 Ringing Via: SIP/2.0/UDP 192.168.0.189:2054;branch=z9hG4bK-duhsbunfz8l7;rport;received=192.168.0.189 From: "test" ;tag=ha8sklk5y5 To: ;tag=as4c90e870 Call-ID: 3c26d02c15f9-59hhmt9sgje0@snom320-000413240554 CSeq: 2 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Contact: Content-Length: 0 --- ultravoX*CLI> <-- SIP read from 192.168.0.190:2051: SIP/2.0 180 Ringing Via: SIP/2.0/UDP 192.168.0.25:5060;branch=z9hG4bK42235889;rport=5060 From: "snom2" ;tag=as536cf13e To: ;tag=1rwoq1h92u Call-ID: 1bdd7cc92bbe978c07c94d4d2c5daefb@192.168.0.25 CSeq: 102 INVITE Contact: Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO Allow-Events: talk, hold, refer Content-Length: 0 Jul 24 11:54:27 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 0: SIP/2.0 180 Ringing (19) Jul 24 11:54:27 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.0.25:5060;branch=z9hG4bK42235889;rport=5060 (68) Jul 24 11:54:27 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 2: From: "snom2" ;tag=as536cf13e (50) Jul 24 11:54:27 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 3: To: ;tag=1rwoq1h92u (60) Jul 24 11:54:27 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 4: Call-ID: 1bdd7cc92bbe978c07c94d4d2c5daefb@192.168.0.25 (54) Jul 24 11:54:27 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 5: CSeq: 102 INVITE (16) Jul 24 11:54:27 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 6: Contact: (50) Jul 24 11:54:27 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 7: Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO (88) Jul 24 11:54:27 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 8: Allow-Events: talk, hold, refer (31) Jul 24 11:54:27 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 9: Content-Length: 0 (17) Jul 24 11:54:27 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 10: (0) --- (10 headers 0 lines)--- Jul 24 11:54:27 DEBUG[3885]: chan_sip.c:1457 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '1bdd7cc92bbe978c07c94d4d2c5daefb@192.168.0.25' Request 102: Found Jul 24 11:54:27 DEBUG[3885]: chan_sip.c:9646 handle_response_invite: SIP response 180 to standard invite -- SIP/13-031d is ringing ultravoX*CLI> <-- SIP read from 192.168.0.190:2051: SIP/2.0 180 Ringing Via: SIP/2.0/UDP 192.168.0.25:5060;branch=z9hG4bK42235889;rport=5060 From: "snom2" ;tag=as536cf13e To: ;tag=1rwoq1h92u Call-ID: 1bdd7cc92bbe978c07c94d4d2c5daefb@192.168.0.25 CSeq: 102 INVITE Contact: Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO Allow-Events: talk, hold, refer Content-Length: 0 Jul 24 11:54:28 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 0: SIP/2.0 180 Ringing (19) Jul 24 11:54:28 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.0.25:5060;branch=z9hG4bK42235889;rport=5060 (68) Jul 24 11:54:28 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 2: From: "snom2" ;tag=as536cf13e (50) Jul 24 11:54:28 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 3: To: ;tag=1rwoq1h92u (60) Jul 24 11:54:28 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 4: Call-ID: 1bdd7cc92bbe978c07c94d4d2c5daefb@192.168.0.25 (54) Jul 24 11:54:28 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 5: CSeq: 102 INVITE (16) Jul 24 11:54:28 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 6: Contact: (50) Jul 24 11:54:28 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 7: Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO (88) Jul 24 11:54:28 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 8: Allow-Events: talk, hold, refer (31) Jul 24 11:54:28 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 9: Content-Length: 0 (17) Jul 24 11:54:28 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 10: (0) --- (10 headers 0 lines)--- Jul 24 11:54:28 DEBUG[3885]: chan_sip.c:1457 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '1bdd7cc92bbe978c07c94d4d2c5daefb@192.168.0.25' Request 102: Found Jul 24 11:54:28 DEBUG[3885]: chan_sip.c:9646 handle_response_invite: SIP response 180 to standard invite -- SIP/13-031d is ringing ultravoX*CLI> <-- SIP read from 192.168.0.190:2051: SIP/2.0 200 Ok Via: SIP/2.0/UDP 192.168.0.25:5060;branch=z9hG4bK42235889;rport=5060 From: "snom2" ;tag=as536cf13e To: ;tag=1rwoq1h92u Call-ID: 1bdd7cc92bbe978c07c94d4d2c5daefb@192.168.0.25 CSeq: 102 INVITE Contact: User-Agent: snom320/4.1 Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO Allow-Events: talk, hold, refer Supported: timer, 100rel, replaces, callerid Content-Type: application/sdp Content-Length: 210 v=0 o=root 1202216702 1202216703 IN IP4 192.168.0.190 s=call c=IN IP4 192.168.0.190 t=0 0 m=audio 53866 RTP/AVP 8 101 a=rtpmap:8 pcma/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=sendrecv Jul 24 11:54:30 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 0: SIP/2.0 200 Ok (14) Jul 24 11:54:30 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.0.25:5060;branch=z9hG4bK42235889;rport=5060 (68) Jul 24 11:54:30 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 2: From: "snom2" ;tag=as536cf13e (50) Jul 24 11:54:30 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 3: To: ;tag=1rwoq1h92u (60) Jul 24 11:54:30 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 4: Call-ID: 1bdd7cc92bbe978c07c94d4d2c5daefb@192.168.0.25 (54) Jul 24 11:54:30 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 5: CSeq: 102 INVITE (16) Jul 24 11:54:30 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 6: Contact: (50) Jul 24 11:54:30 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 7: User-Agent: snom320/4.1 (23) Jul 24 11:54:30 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 8: Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO (88) Jul 24 11:54:30 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 9: Allow-Events: talk, hold, refer (31) Jul 24 11:54:30 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 10: Supported: timer, 100rel, replaces, callerid (44) Jul 24 11:54:30 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 11: Content-Type: application/sdp (29) Jul 24 11:54:30 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 12: Content-Length: 210 (19) Jul 24 11:54:30 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 13: (0) Jul 24 11:54:30 DEBUG[3885]: chan_sip.c:3404 parse_request: Line: v=0 (3) Jul 24 11:54:30 DEBUG[3885]: chan_sip.c:3404 parse_request: Line: o=root 1202216702 1202216703 IN IP4 192.168.0.190 (49) Jul 24 11:54:30 DEBUG[3885]: chan_sip.c:3404 parse_request: Line: s=call (6) Jul 24 11:54:30 DEBUG[3885]: chan_sip.c:3404 parse_request: Line: c=IN IP4 192.168.0.190 (22) Jul 24 11:54:30 DEBUG[3885]: chan_sip.c:3404 parse_request: Line: t=0 0 (5) Jul 24 11:54:30 DEBUG[3885]: chan_sip.c:3404 parse_request: Line: m=audio 53866 RTP/AVP 8 101 (27) Jul 24 11:54:30 DEBUG[3885]: chan_sip.c:3404 parse_request: Line: a=rtpmap:8 pcma/8000 (20) Jul 24 11:54:30 DEBUG[3885]: chan_sip.c:3404 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) Jul 24 11:54:30 DEBUG[3885]: chan_sip.c:3404 parse_request: Line: a=fmtp:101 0-15 (15) Jul 24 11:54:30 DEBUG[3885]: chan_sip.c:3404 parse_request: Line: a=sendrecv (10) --- (13 headers 10 lines)--- Jul 24 11:54:30 DEBUG[3885]: chan_sip.c:1382 __sip_ack: Acked pending invite 102 Jul 24 11:54:30 DEBUG[3885]: chan_sip.c:1404 __sip_ack: Stopping retransmission on '1bdd7cc92bbe978c07c94d4d2c5daefb@192.168.0.25' of Request 102: Match Found Jul 24 11:54:30 DEBUG[3885]: chan_sip.c:9646 handle_response_invite: SIP response 200 to standard invite Found RTP audio format 8 Found RTP audio format 101 Peer audio RTP is at port 192.168.0.190:53866 Jul 24 11:54:30 DEBUG[3885]: chan_sip.c:3613 process_sdp: Peer audio RTP is at port 192.168.0.190:53866 Found description format pcma Found description format telephone-event Capabilities: us - 0x1f07ff (g723|gsm|ulaw|alaw|g726|adpcm|slin|lpc10|g729|speex|ilbc|jpeg|png|h261|h263|h263p), peer - audio=0x8 (alaw)/video=0x0 (nothing), combined - 0x8 (alaw) Non-codec capabilities: us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) Jul 24 11:54:30 DEBUG[3885]: chan_sip.c:6172 build_route: build_route: Contact hop: list_route: hop: set_destination: Parsing for address/port to send to set_destination: set destination to 192.168.0.190, port 2051 Transmitting (no NAT) to 192.168.0.190:2051: ACK sip:13@192.168.0.190:2051;line=no7rb4d3 SIP/2.0 Via: SIP/2.0/UDP 192.168.0.25:5060;branch=z9hG4bK5fbbf966;rport From: "snom2" ;tag=as536cf13e To: ;tag=1rwoq1h92u Contact: Call-ID: 1bdd7cc92bbe978c07c94d4d2c5daefb@192.168.0.25 CSeq: 102 ACK User-Agent: Asterisk PBX Max-Forwards: 70 Content-Length: 0 --- -- SIP/13-031d answered SIP/11-f85f Jul 24 11:54:30 DEBUG[3983]: channel.c:2350 set_format: Set channel SIP/11-f85f to read format alaw Jul 24 11:54:30 DEBUG[3983]: channel.c:2350 set_format: Set channel SIP/13-031d to write format alaw Jul 24 11:54:30 DEBUG[3983]: channel.c:2350 set_format: Set channel SIP/13-031d to read format alaw Jul 24 11:54:30 DEBUG[3983]: channel.c:2350 set_format: Set channel SIP/11-f85f to write format alaw Jul 24 11:54:30 DEBUG[3983]: chan_sip.c:2549 sip_answer: sip_answer(SIP/11-f85f) We're at 192.168.0.25 port 19272 Adding codec 0x8 (alaw) to SDP Adding codec 0x4 (ulaw) to SDP Adding codec 0x2 (gsm) to SDP Adding codec 0x100 (g729) to SDP Adding codec 0x1 (g723) to SDP Adding codec 0x10 (g726) to SDP Adding non-codec 0x1 (telephone-event) to SDP Reliably Transmitting (no NAT) to 192.168.0.189:2054: SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.0.189:2054;branch=z9hG4bK-duhsbunfz8l7;rport;received=192.168.0.189 From: "test" ;tag=ha8sklk5y5 To: ;tag=as4c90e870 Call-ID: 3c26d02c15f9-59hhmt9sgje0@snom320-000413240554 CSeq: 2 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Contact: Content-Type: application/sdp Content-Length: 359 v=0 o=root 2555 2555 IN IP4 192.168.0.25 s=session c=IN IP4 192.168.0.25 t=0 0 m=audio 19272 RTP/AVP 8 0 3 18 4 2 101 a=rtpmap:8 PCMA/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:3 GSM/8000 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:4 G723/8000 a=rtpmap:2 G726-32/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - --- Jul 24 11:54:30 DEBUG[3983]: chan_sip.c:1296 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #101 -- Attempting native bridge of SIP/11-f85f and SIP/13-031d Jul 24 11:54:30 DEBUG[3872]: chan_sip.c:11781 sip_devicestate: Checking device state for peer 13 Jul 24 11:54:30 DEBUG[3872]: devicestate.c:187 do_state_change: Changing state for SIP/13 - state 2 (In use) Jul 24 11:54:30 DEBUG[3872]: chan_sip.c:11781 sip_devicestate: Checking device state for peer 13 Jul 24 11:54:30 DEBUG[3872]: chan_sip.c:11781 sip_devicestate: Checking device state for peer 11 Jul 24 11:54:30 DEBUG[3872]: devicestate.c:187 do_state_change: Changing state for SIP/11 - state 2 (In use) Jul 24 11:54:30 DEBUG[3872]: chan_sip.c:11781 sip_devicestate: Checking device state for peer 11 Jul 24 11:54:30 DEBUG[3988]: app_queue.c:523 changethread: Device 'SIP/13' changed to state '2' (In use) but we don't care because they're not a member of any queue. Jul 24 11:54:30 DEBUG[3989]: app_queue.c:523 changethread: Device 'SIP/11' changed to state '2' (In use) but we don't care because they're not a member of any queue. ultravoX*CLI> <-- SIP read from 192.168.0.189:2054: ACK sip:13@192.168.0.25 SIP/2.0 Via: SIP/2.0/UDP 192.168.0.189:2054;branch=z9hG4bK-0rifsuqnhp69;rport From: "test" ;tag=ha8sklk5y5 To: ;tag=as4c90e870 Call-ID: 3c26d02c15f9-59hhmt9sgje0@snom320-000413240554 CSeq: 2 ACK Max-Forwards: 70 Contact: ;flow-id=1 Content-Length: 0 Jul 24 11:54:30 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 0: ACK sip:13@192.168.0.25 SIP/2.0 (31) Jul 24 11:54:30 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.0.189:2054;branch=z9hG4bK-0rifsuqnhp69;rport (69) Jul 24 11:54:30 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 2: From: "test" ;tag=ha8sklk5y5 (49) Jul 24 11:54:30 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 3: To: ;tag=as4c90e870 (40) Jul 24 11:54:30 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 4: Call-ID: 3c26d02c15f9-59hhmt9sgje0@snom320-000413240554 (55) Jul 24 11:54:30 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 5: CSeq: 2 ACK (11) Jul 24 11:54:30 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 6: Max-Forwards: 70 (16) Jul 24 11:54:30 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 7: Contact: ;flow-id=1 (60) Jul 24 11:54:30 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 8: Content-Length: 0 (17) Jul 24 11:54:30 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 9: (0) --- (9 headers 0 lines)--- Jul 24 11:54:30 DEBUG[3885]: chan_sip.c:11246 handle_request: **** Received ACK (6) - Command in SIP ACK Jul 24 11:54:30 DEBUG[3885]: chan_sip.c:1393 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #101 Jul 24 11:54:30 DEBUG[3885]: chan_sip.c:1404 __sip_ack: Stopping retransmission on '3c26d02c15f9-59hhmt9sgje0@snom320-000413240554' of Response 2: Match Found Jul 24 11:54:30 DEBUG[3983]: rtp.c:411 ast_rtcp_read: Got RTCP report of 52 bytes Jul 24 11:54:30 DEBUG[3983]: rtp.c:1352 ast_rtp_write: Ooh, format changed from unknown to alaw Jul 24 11:54:30 DEBUG[3983]: rtp.c:1352 ast_rtp_write: Ooh, format changed from unknown to alaw Jul 24 11:54:35 DEBUG[3983]: rtp.c:411 ast_rtcp_read: Got RTCP report of 52 bytes ultravoX*CLI> <-- SIP read from 192.168.0.189:2054: REFER sip:10@192.168.0.25 SIP/2.0 Via: SIP/2.0/UDP 192.168.0.189:2054;branch=z9hG4bK-51zpc1o5vfcw;rport From: ;tag=oe3qaheqd7 To: "snom" ;tag=as165ec945 Call-ID: 3b4811ad1530aa5674197392245961fa@192.168.0.25 CSeq: 2 REFER Max-Forwards: 70 Contact: ;flow-id=1 Refer-To: sip:13@192.168.0.25?Replaces=3c26d02c15f9-59hhmt9sgje0%40snom320-000413240554%3Bto-tag%3Das4c90e870%3Bfrom-tag%3Dha8sklk5y5 Referred-By: sip:11@192.168.0.25 User-Agent: snom320/6.2 Content-Length: 0 Jul 24 11:54:35 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 0: REFER sip:10@192.168.0.25 SIP/2.0 (33) Jul 24 11:54:35 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.0.189:2054;branch=z9hG4bK-51zpc1o5vfcw;rport (69) Jul 24 11:54:35 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 2: From: ;tag=oe3qaheqd7 (62) Jul 24 11:54:35 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 3: To: "snom" ;tag=as165ec945 (47) Jul 24 11:54:35 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 4: Call-ID: 3b4811ad1530aa5674197392245961fa@192.168.0.25 (54) Jul 24 11:54:35 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 5: CSeq: 2 REFER (13) Jul 24 11:54:35 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 6: Max-Forwards: 70 (16) Jul 24 11:54:35 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 7: Contact: ;flow-id=1 (60) Jul 24 11:54:35 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 8: Refer-To: sip:13@192.168.0.25?Replaces=3c26d02c15f9-59hhmt9sgje0%40snom320-000413240554%3Bto-tag%3Das4c90e870%3Bfrom-tag%3Dha8sklk5y5 (133) Jul 24 11:54:35 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 9: Referred-By: sip:11@192.168.0.25 (32) Jul 24 11:54:35 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 10: User-Agent: snom320/6.2 (23) Jul 24 11:54:35 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 11: Content-Length: 0 (17) Jul 24 11:54:35 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 12: (0) --- (12 headers 0 lines)--- Jul 24 11:54:35 DEBUG[3885]: chan_sip.c:11246 handle_request: **** Received REFER (9) - Command in SIP REFER Jul 24 11:54:35 DEBUG[3885]: chan_sip.c:10772 handle_request_refer: SIP call transfer received for call 3b4811ad1530aa5674197392245961fa@192.168.0.25 (REFER)! Transfer to 13 in DefaultOutgoingRule Transfer from 11 in DefaultOutgoingRule Jul 24 11:54:35 DEBUG[3885]: chan_sip.c:6914 get_refer_info: Assigning Replace-Call-ID Info 3c26d02c15f9-59hhmt9sgje0@snom320-000413240554 to REPLACE_CALL_ID Jul 24 11:54:35 DEBUG[3885]: chan_sip.c:10784 handle_request_refer: 202 Accepted (supervised) Jul 24 11:54:35 DEBUG[3885]: channel.c:2350 set_format: Set channel SIP/10-15f3 to write format alaw -- Stopped music on hold on SIP/10-15f3 Jul 24 11:54:35 DEBUG[3885]: channel.c:1711 ast_settimeout: Scheduling timer at 0 sample intervals Jul 24 11:54:35 DEBUG[3885]: chan_sip.c:10390 attempt_transfer: Trying to masquerade SIP/11-f85f and SIP/10-15f3 Jul 24 11:54:35 DEBUG[3885]: channel.c:2757 ast_channel_masquerade: Planning to masquerade channel SIP/10-15f3 into the structure of SIP/11-f85f Jul 24 11:54:35 DEBUG[3885]: channel.c:2770 ast_channel_masquerade: Done planning to masquerade channel SIP/10-15f3 into the structure of SIP/11-f85f Transmitting (NAT) to 192.168.0.189:2054: SIP/2.0 202 Accepted Via: SIP/2.0/UDP 192.168.0.189:2054;branch=z9hG4bK-51zpc1o5vfcw;received=192.168.0.189;rport=2054 From: ;tag=oe3qaheqd7 To: "snom" ;tag=as165ec945 Call-ID: 3b4811ad1530aa5674197392245961fa@192.168.0.25 CSeq: 2 REFER User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Contact: Content-Length: 0 X-Asterisk-HangupCause: Normal Clearing --- set_destination: Parsing for address/port to send to set_destination: set destination to 192.168.0.189, port 2054 Reliably Transmitting (NAT) to 192.168.0.189:2054: NOTIFY sip:11@192.168.0.189:2054;line=sczhjqwm SIP/2.0 Via: SIP/2.0/UDP 192.168.0.25:5060;branch=z9hG4bK56c4d0ec;rport From: "snom" ;tag=as165ec945 To: ;tag=oe3qaheqd7 Contact: Call-ID: 3b4811ad1530aa5674197392245961fa@192.168.0.25 CSeq: 103 NOTIFY User-Agent: Asterisk PBX Max-Forwards: 70 Event: refer;id=2 Subscription-state: terminated;reason=noresource Content-Type: message/sipfrag;version=2.0 Content-Length: 14 SIP/2.0 200 OK --- Jul 24 11:54:35 DEBUG[3885]: chan_sip.c:1296 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #102 set_destination: Parsing for address/port to send to set_destination: set destination to 192.168.0.189, port 2054 Reliably Transmitting (NAT) to 192.168.0.189:2054: BYE sip:11@192.168.0.189:2054;line=sczhjqwm SIP/2.0 Via: SIP/2.0/UDP 192.168.0.25:5060;branch=z9hG4bK1cc08979;rport From: "snom" ;tag=as165ec945 To: ;tag=oe3qaheqd7 Contact: Call-ID: 3b4811ad1530aa5674197392245961fa@192.168.0.25 CSeq: 104 BYE User-Agent: Asterisk PBX Max-Forwards: 70 X-Asterisk-HangupCause: Normal Clearing Content-Length: 0 --- Jul 24 11:54:35 DEBUG[3885]: chan_sip.c:1296 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #103 Jul 24 11:54:35 DEBUG[3983]: channel.c:2880 ast_do_masquerade: Actually Masquerading SIP/10-15f3(6) into the structure of SIP/11-f85f(6) Jul 24 11:54:35 DEBUG[3983]: channel.c:2891 ast_do_masquerade: Got clone lock for masquerade on 'SIP/10-15f3' at 0x86ead3c Jul 24 11:54:35 DEBUG[3983]: chan_sip.c:2427 sip_hangup: Hangup call SIP/10-15f3, SIP callid 3c26d02c15f9-59hhmt9sgje0@snom320-000413240554) Jul 24 11:54:35 DEBUG[3983]: chan_sip.c:2435 sip_hangup: update_call_counter(11) - decrement call limit counter Jul 24 11:54:35 DEBUG[3983]: chan_sip.c:2218 update_call_counter: Updating call counter for incoming call set_destination: Parsing for address/port to send to set_destination: set destination to 192.168.0.189, port 2054 Reliably Transmitting (no NAT) to 192.168.0.189:2054: BYE sip:11@192.168.0.189:2054 SIP/2.0 Via: SIP/2.0/UDP 192.168.0.25:5060;branch=z9hG4bK634f5ebc;rport From: ;tag=as4c90e870 To: "test" ;tag=ha8sklk5y5 Contact: Call-ID: 3c26d02c15f9-59hhmt9sgje0@snom320-000413240554 CSeq: 102 BYE User-Agent: Asterisk PBX Max-Forwards: 70 Content-Length: 0 --- Jul 24 11:54:35 DEBUG[3983]: chan_sip.c:1296 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #104 Jul 24 11:54:35 DEBUG[3983]: channel.c:2350 set_format: Set channel SIP/10-15f3 to write format alaw Jul 24 11:54:35 DEBUG[3983]: channel.c:2350 set_format: Set channel SIP/10-15f3 to read format alaw Jul 24 11:54:35 DEBUG[3983]: channel.c:3052 ast_do_masquerade: Putting channel SIP/10-15f3 in 8/8 formats Jul 24 11:54:35 DEBUG[3983]: channel.c:3087 ast_do_masquerade: Released clone lock on 'SIP/11-f85f' Jul 24 11:54:35 DEBUG[3983]: channel.c:3096 ast_do_masquerade: Done Masquerading SIP/10-15f3 (6) Jul 24 11:54:35 DEBUG[3976]: channel.c:3275 ast_generic_bridge: Didn't get a frame from channel: SIP/11-f85f Jul 24 11:54:35 DEBUG[3976]: channel.c:3550 ast_channel_bridge: Bridge stops bridging channels SIP/11-f85f and SIP/11-47ac Jul 24 11:54:35 DEBUG[3976]: channel.c:1323 ast_hangup: Hanging up channel 'SIP/11-47ac' Jul 24 11:54:35 DEBUG[3976]: chan_sip.c:2427 sip_hangup: Hangup call SIP/11-47ac, SIP callid 3b4811ad1530aa5674197392245961fa@192.168.0.25) Jul 24 11:54:35 DEBUG[3976]: chan_sip.c:2435 sip_hangup: update_call_counter(11) - decrement call limit counter Jul 24 11:54:35 DEBUG[3976]: chan_sip.c:2218 update_call_counter: Updating call counter for incoming call Jul 24 11:54:35 DEBUG[3976]: app_dial.c:1619 dial_exec_full: Exiting with DIALSTATUS=ANSWER. Jul 24 11:54:35 DEBUG[3976]: app_macro.c:231 macro_exec: Spawn extension (macro-stdexten,s,4) exited non-zero on 'SIP/11-f85f' in macro 'stdexten' Jul 24 11:54:35 DEBUG[3976]: res_agi.c:1886 run_agi: SIP/11-f85f hungup Jul 24 11:54:35 DEBUG[3976]: pbx.c:2316 __ast_pbx_run: Spawn extension (macro-stdexten,s,4) exited non-zero on 'SIP/11-f85f' Jul 24 11:54:35 DEBUG[3976]: channel.c:1328 ast_hangup: Hanging up zombie 'SIP/11-f85f' Jul 24 11:54:35 DEBUG[3872]: chan_sip.c:11781 sip_devicestate: Checking device state for peer 11 Jul 24 11:54:35 DEBUG[3872]: devicestate.c:187 do_state_change: Changing state for SIP/11 - state 1 (Not in use) Jul 24 11:54:35 DEBUG[3872]: chan_sip.c:11781 sip_devicestate: Checking device state for peer 11 Jul 24 11:54:35 DEBUG[3872]: chan_sip.c:11781 sip_devicestate: Checking device state for peer 11 Jul 24 11:54:35 DEBUG[3872]: devicestate.c:187 do_state_change: Changing state for SIP/11 - state 1 (Not in use) Jul 24 11:54:35 DEBUG[3872]: chan_sip.c:11781 sip_devicestate: Checking device state for peer 11 Jul 24 11:54:35 DEBUG[3983]: channel.c:3259 ast_generic_bridge: Nobody there, continuing... Jul 24 11:54:35 DEBUG[3990]: app_queue.c:523 changethread: Device 'SIP/11' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. Jul 24 11:54:35 DEBUG[3991]: app_queue.c:523 changethread: Device 'SIP/11' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. ultravoX*CLI> <-- SIP read from 192.168.0.189:2054: SIP/2.0 200 Ok Via: SIP/2.0/UDP 192.168.0.25:5060;branch=z9hG4bK56c4d0ec;rport=5060 From: "snom" ;tag=as165ec945 To: ;tag=oe3qaheqd7 Call-ID: 3b4811ad1530aa5674197392245961fa@192.168.0.25 CSeq: 103 NOTIFY Contact: ;flow-id=1 Content-Length: 0 Jul 24 11:54:35 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 0: SIP/2.0 200 Ok (14) Jul 24 11:54:35 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.0.25:5060;branch=z9hG4bK56c4d0ec;rport=5060 (68) Jul 24 11:54:35 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 2: From: "snom" ;tag=as165ec945 (49) Jul 24 11:54:35 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 3: To: ;tag=oe3qaheqd7 (60) Jul 24 11:54:35 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 4: Call-ID: 3b4811ad1530aa5674197392245961fa@192.168.0.25 (54) Jul 24 11:54:35 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 5: CSeq: 103 NOTIFY (16) Jul 24 11:54:35 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 6: Contact: ;flow-id=1 (60) Jul 24 11:54:35 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 7: Content-Length: 0 (17) Jul 24 11:54:35 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 8: (0) --- (8 headers 0 lines)--- Jul 24 11:54:35 DEBUG[3885]: chan_sip.c:1393 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #102 Jul 24 11:54:35 DEBUG[3885]: chan_sip.c:1404 __sip_ack: Stopping retransmission on '3b4811ad1530aa5674197392245961fa@192.168.0.25' of Request 103: Match Found ultravoX*CLI> <-- SIP read from 192.168.0.189:2054: SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.0.25:5060;branch=z9hG4bK1cc08979;rport=5060 From: "snom" ;tag=as165ec945 To: ;tag=oe3qaheqd7 Call-ID: 3b4811ad1530aa5674197392245961fa@192.168.0.25 CSeq: 104 BYE Contact: ;flow-id=1 User-Agent: snom320/6.2 Content-Length: 0 Jul 24 11:54:35 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 0: SIP/2.0 200 OK (14) Jul 24 11:54:35 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.0.25:5060;branch=z9hG4bK1cc08979;rport=5060 (68) Jul 24 11:54:35 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 2: From: "snom" ;tag=as165ec945 (49) Jul 24 11:54:35 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 3: To: ;tag=oe3qaheqd7 (60) Jul 24 11:54:35 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 4: Call-ID: 3b4811ad1530aa5674197392245961fa@192.168.0.25 (54) Jul 24 11:54:35 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 5: CSeq: 104 BYE (13) Jul 24 11:54:35 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 6: Contact: ;flow-id=1 (60) Jul 24 11:54:35 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 7: User-Agent: snom320/6.2 (23) Jul 24 11:54:35 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 8: Content-Length: 0 (17) Jul 24 11:54:35 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 9: (0) --- (9 headers 0 lines)--- Jul 24 11:54:35 DEBUG[3885]: chan_sip.c:1393 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #103 Jul 24 11:54:35 DEBUG[3885]: chan_sip.c:1404 __sip_ack: Stopping retransmission on '3b4811ad1530aa5674197392245961fa@192.168.0.25' of Request 104: Match Found Destroying call '3b4811ad1530aa5674197392245961fa@192.168.0.25' ultravoX*CLI> <-- SIP read from 192.168.0.189:2054: SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.0.25:5060;branch=z9hG4bK634f5ebc;rport=5060 From: ;tag=as4c90e870 To: "test" ;tag=ha8sklk5y5 Call-ID: 3c26d02c15f9-59hhmt9sgje0@snom320-000413240554 CSeq: 102 BYE Contact: ;flow-id=1 User-Agent: snom320/6.2 Content-Length: 0 Jul 24 11:54:35 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 0: SIP/2.0 200 OK (14) Jul 24 11:54:35 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.0.25:5060;branch=z9hG4bK634f5ebc;rport=5060 (68) Jul 24 11:54:35 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 2: From: ;tag=as4c90e870 (42) Jul 24 11:54:35 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 3: To: "test" ;tag=ha8sklk5y5 (47) Jul 24 11:54:35 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 4: Call-ID: 3c26d02c15f9-59hhmt9sgje0@snom320-000413240554 (55) Jul 24 11:54:35 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 5: CSeq: 102 BYE (13) Jul 24 11:54:35 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 6: Contact: ;flow-id=1 (60) Jul 24 11:54:35 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 7: User-Agent: snom320/6.2 (23) Jul 24 11:54:35 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 8: Content-Length: 0 (17) Jul 24 11:54:35 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 9: (0) --- (9 headers 0 lines)--- Jul 24 11:54:35 DEBUG[3885]: chan_sip.c:1393 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #104 Jul 24 11:54:35 DEBUG[3885]: chan_sip.c:1404 __sip_ack: Stopping retransmission on '3c26d02c15f9-59hhmt9sgje0@snom320-000413240554' of Request 102: Match Found Destroying call '3c26d02c15f9-59hhmt9sgje0@snom320-000413240554' ultravoX*CLI> <-- SIP read from 192.168.0.190:2051: BYE sip:11@192.168.0.25 SIP/2.0 Via: SIP/2.0/UDP 192.168.0.190:2051;branch=z9hG4bK-zf57bab8vnbf;rport From: ;tag=1rwoq1h92u To: "snom2" ;tag=as536cf13e Call-ID: 1bdd7cc92bbe978c07c94d4d2c5daefb@192.168.0.25 CSeq: 1 BYE Max-Forwards: 70 Contact: User-Agent: snom320/4.1 Content-Length: 0 Jul 24 11:54:40 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 0: BYE sip:11@192.168.0.25 SIP/2.0 (31) Jul 24 11:54:40 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.0.190:2051;branch=z9hG4bK-zf57bab8vnbf;rport (69) Jul 24 11:54:40 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 2: From: ;tag=1rwoq1h92u (62) Jul 24 11:54:40 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 3: To: "snom2" ;tag=as536cf13e (48) Jul 24 11:54:40 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 4: Call-ID: 1bdd7cc92bbe978c07c94d4d2c5daefb@192.168.0.25 (54) Jul 24 11:54:40 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 5: CSeq: 1 BYE (11) Jul 24 11:54:40 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 6: Max-Forwards: 70 (16) Jul 24 11:54:40 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 7: Contact: (50) Jul 24 11:54:40 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 8: User-Agent: snom320/4.1 (23) Jul 24 11:54:40 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 9: Content-Length: 0 (17) Jul 24 11:54:40 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 10: (0) --- (10 headers 0 lines)--- Jul 24 11:54:40 DEBUG[3885]: chan_sip.c:11246 handle_request: **** Received BYE (8) - Command in SIP BYE Sending to 192.168.0.190 : 2051 (NAT) Transmitting (NAT) to 192.168.0.190:2051: SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.0.190:2051;branch=z9hG4bK-zf57bab8vnbf;received=192.168.0.190;rport=2051 From: ;tag=1rwoq1h92u To: "snom2" ;tag=as536cf13e Call-ID: 1bdd7cc92bbe978c07c94d4d2c5daefb@192.168.0.25 CSeq: 1 BYE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Contact: Content-Length: 0 X-Asterisk-HangupCause: Normal Clearing --- Jul 24 11:54:40 DEBUG[3983]: channel.c:3275 ast_generic_bridge: Didn't get a frame from channel: SIP/13-031d Jul 24 11:54:40 DEBUG[3983]: channel.c:3550 ast_channel_bridge: Bridge stops bridging channels SIP/10-15f3 and SIP/13-031d Jul 24 11:54:40 DEBUG[3983]: channel.c:1323 ast_hangup: Hanging up channel 'SIP/13-031d' Jul 24 11:54:40 DEBUG[3983]: chan_sip.c:2427 sip_hangup: Hangup call SIP/13-031d, SIP callid 1bdd7cc92bbe978c07c94d4d2c5daefb@192.168.0.25) Jul 24 11:54:40 DEBUG[3983]: chan_sip.c:2435 sip_hangup: update_call_counter(13) - decrement call limit counter Jul 24 11:54:40 DEBUG[3983]: chan_sip.c:2218 update_call_counter: Updating call counter for outgoing call Jul 24 11:54:40 DEBUG[3983]: app_dial.c:1619 dial_exec_full: Exiting with DIALSTATUS=ANSWER. Jul 24 11:54:40 DEBUG[3983]: app_macro.c:231 macro_exec: Spawn extension (macro-stdexten,s,4) exited non-zero on 'SIP/10-15f3' in macro 'stdexten' Jul 24 11:54:40 DEBUG[3872]: chan_sip.c:11781 sip_devicestate: Checking device state for peer 13 Jul 24 11:54:40 DEBUG[3872]: devicestate.c:187 do_state_change: Changing state for SIP/13 - state 1 (Not in use) Jul 24 11:54:40 DEBUG[3872]: chan_sip.c:11781 sip_devicestate: Checking device state for peer 13 -- AGI Script dial.php completed, returning 0 Jul 24 11:54:40 DEBUG[3983]: pbx.c:1677 pbx_extension_helper: Launching 'Goto' -- Executing Goto("SIP/10-15f3", "s-ANSWER|1") in new stack -- Goto (macro-stdexten,s-ANSWER,1) Jul 24 11:54:40 DEBUG[3983]: pbx.c:1677 pbx_extension_helper: Launching 'PlayTones' -- Executing PlayTones("SIP/10-15f3", "congestion") in new stack Jul 24 11:54:40 DEBUG[3983]: channel.c:2350 set_format: Set channel SIP/10-15f3 to write format slin Jul 24 11:54:40 DEBUG[3983]: channel.c:1711 ast_settimeout: Scheduling timer at 160 sample intervals Jul 24 11:54:40 DEBUG[3992]: app_queue.c:523 changethread: Device 'SIP/13' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. Jul 24 11:54:40 DEBUG[3983]: channel.c:1975 ast_read: Generator got voice, switching to phase locked mode Jul 24 11:54:40 DEBUG[3983]: channel.c:1711 ast_settimeout: Scheduling timer at 0 sample intervals Destroying call '1bdd7cc92bbe978c07c94d4d2c5daefb@192.168.0.25' ultravoX*CLI> <-- SIP read from 192.168.0.163:2051: BYE sip:11@192.168.0.25 SIP/2.0 Via: SIP/2.0/UDP 192.168.0.163:2051;branch=z9hG4bK-b9uvxse4n2ep;rport From: "snom" ;tag=ls79hgc0bt To: ;tag=as349f01f5 Call-ID: 3c2bc9a7afc8-us5jzg0io0z5@snom360 CSeq: 3 BYE Max-Forwards: 70 Contact: User-Agent: snom360/4.1 Content-Length: 0 Jul 24 11:54:43 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 0: BYE sip:11@192.168.0.25 SIP/2.0 (31) Jul 24 11:54:43 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.0.163:2051;branch=z9hG4bK-b9uvxse4n2ep;rport (69) Jul 24 11:54:43 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 2: From: "snom" ;tag=ls79hgc0bt (49) Jul 24 11:54:43 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 3: To: ;tag=as349f01f5 (51) Jul 24 11:54:43 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 4: Call-ID: 3c2bc9a7afc8-us5jzg0io0z5@snom360 (42) Jul 24 11:54:43 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 5: CSeq: 3 BYE (11) Jul 24 11:54:43 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 6: Max-Forwards: 70 (16) Jul 24 11:54:43 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 7: Contact: (50) Jul 24 11:54:43 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 8: User-Agent: snom360/4.1 (23) Jul 24 11:54:43 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 9: Content-Length: 0 (17) Jul 24 11:54:43 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 10: (0) --- (10 headers 0 lines)--- Jul 24 11:54:43 DEBUG[3885]: chan_sip.c:11246 handle_request: **** Received BYE (8) - Command in SIP BYE Sending to 192.168.0.163 : 2051 (NAT) Transmitting (NAT) to 192.168.0.163:2051: SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.0.163:2051;branch=z9hG4bK-b9uvxse4n2ep;received=192.168.0.163;rport=2051 From: "snom" ;tag=ls79hgc0bt To: ;tag=as349f01f5 Call-ID: 3c2bc9a7afc8-us5jzg0io0z5@snom360 CSeq: 3 BYE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Contact: Content-Length: 0 X-Asterisk-HangupCause: Normal Clearing --- Jul 24 11:54:43 DEBUG[3983]: channel.c:2350 set_format: Set channel SIP/10-15f3 to write format alaw Jul 24 11:54:43 DEBUG[3983]: channel.c:1711 ast_settimeout: Scheduling timer at 0 sample intervals Jul 24 11:54:43 DEBUG[3983]: cdr_addon_mysql.c:206 mysql_log: cdr_mysql: inserting a CDR record. Jul 24 11:54:43 DEBUG[3983]: cdr_addon_mysql.c:222 mysql_log: cdr_mysql: SQL command as follows: INSERT INTO cdr (calldate,clid,src,dst,dcontext,channel,dstchannel,lastapp,lastdata,duration,billsec,disposition,amaflags,accountcode,uniqueid,userfield) VALUES ('2006-07-24 11:54:26','\"snom\" <10>','10','13','DefaultOutgoingRule', 'SIP/11-f85f','SIP/13-031d','PlayTones','congestion',17,13,'ANSWERED',3,'','1153734866.12','') Jul 24 11:54:43 DEBUG[3983]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '"snom" <10>' Jul 24 11:54:43 DEBUG[3983]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '10' Jul 24 11:54:43 DEBUG[3983]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '13' Jul 24 11:54:43 DEBUG[3983]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is 'DefaultOutgoingRule' Jul 24 11:54:43 DEBUG[3983]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is 'SIP/11-f85f' Jul 24 11:54:43 DEBUG[3983]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is 'SIP/13-031d' Jul 24 11:54:43 DEBUG[3983]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is 'PlayTones' Jul 24 11:54:43 DEBUG[3983]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is 'congestion' Jul 24 11:54:43 DEBUG[3983]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '2006-07-24 11:54:26' Jul 24 11:54:43 DEBUG[3983]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '2006-07-24 11:54:30' Jul 24 11:54:43 DEBUG[3983]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '2006-07-24 11:54:43' Jul 24 11:54:43 DEBUG[3983]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '17' Jul 24 11:54:43 DEBUG[3983]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '13' Jul 24 11:54:43 DEBUG[3983]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is 'ANSWERED' Jul 24 11:54:43 DEBUG[3983]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is 'DOCUMENTATION' Jul 24 11:54:43 DEBUG[3983]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '(null)' Jul 24 11:54:43 DEBUG[3983]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '1153734866.12' Jul 24 11:54:43 DEBUG[3983]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '(null)' Jul 24 11:54:43 DEBUG[3983]: cdr_addon_mysql.c:206 mysql_log: cdr_mysql: inserting a CDR record. Jul 24 11:54:43 DEBUG[3983]: cdr_addon_mysql.c:222 mysql_log: cdr_mysql: SQL command as follows: INSERT INTO cdr (calldate,clid,src,dst,dcontext,channel,dstchannel,lastapp,lastdata,duration,billsec,disposition,amaflags,accountcode,uniqueid,userfield) VALUES ('2006-07-24 11:54:05','\"snom\" <10>','10','13','DefaultOutgoingRule', 'SIP/10-15f3','SIP/11-47ac','PlayTones','congestion',38,30,'ANSWERED',3,'','1153734845.10','') Jul 24 11:54:43 DEBUG[3983]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '"snom" <10>' Jul 24 11:54:43 DEBUG[3983]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '10' Jul 24 11:54:43 DEBUG[3983]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '13' Jul 24 11:54:43 DEBUG[3983]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is 'DefaultOutgoingRule' Jul 24 11:54:43 DEBUG[3983]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is 'SIP/10-15f3' Jul 24 11:54:43 DEBUG[3983]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is 'SIP/11-47ac' Jul 24 11:54:43 DEBUG[3983]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is 'PlayTones' Jul 24 11:54:43 DEBUG[3983]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is 'congestion' Jul 24 11:54:43 DEBUG[3983]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '2006-07-24 11:54:05' Jul 24 11:54:43 DEBUG[3983]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '2006-07-24 11:54:13' Jul 24 11:54:43 DEBUG[3983]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '2006-07-24 11:54:43' Jul 24 11:54:43 DEBUG[3983]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '38' Jul 24 11:54:43 DEBUG[3983]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '30' Jul 24 11:54:43 DEBUG[3983]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is 'ANSWERED' Jul 24 11:54:43 DEBUG[3983]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is 'DOCUMENTATION' Jul 24 11:54:43 DEBUG[3983]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '(null)' Jul 24 11:54:43 DEBUG[3983]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '1153734845.10' Jul 24 11:54:43 DEBUG[3983]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '(null)' Jul 24 11:54:43 DEBUG[3983]: channel.c:1323 ast_hangup: Hanging up channel 'SIP/10-15f3' Jul 24 11:54:43 DEBUG[3983]: chan_sip.c:2427 sip_hangup: Hangup call SIP/10-15f3, SIP callid 3c2bc9a7afc8-us5jzg0io0z5@snom360) Jul 24 11:54:43 DEBUG[3983]: chan_sip.c:2435 sip_hangup: update_call_counter(10) - decrement call limit counter Jul 24 11:54:43 DEBUG[3983]: chan_sip.c:2218 update_call_counter: Updating call counter for incoming call Jul 24 11:54:43 DEBUG[3872]: chan_sip.c:11781 sip_devicestate: Checking device state for peer 10 Jul 24 11:54:43 DEBUG[3872]: devicestate.c:187 do_state_change: Changing state for SIP/10 - state 1 (Not in use) Jul 24 11:54:43 DEBUG[3872]: chan_sip.c:11781 sip_devicestate: Checking device state for peer 10 Jul 24 11:54:43 DEBUG[3993]: app_queue.c:523 changethread: Device 'SIP/10' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. Destroying call '3c2bc9a7afc8-us5jzg0io0z5@snom360' Jul 24 11:54:54 DEBUG[3885]: chan_sip.c:3156 sip_alloc: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP) Jul 24 11:54:54 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 0: OPTIONS sip:10@192.168.0.163:2051;line=upjd371q SIP/2.0 (55) Jul 24 11:54:54 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.0.25:5060;branch=z9hG4bK63f04986;rport (63) Jul 24 11:54:54 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 2: From: "asterisk" ;tag=as3b85aa08 (59) Jul 24 11:54:54 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 3: To: (45) Jul 24 11:54:54 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 4: Contact: (36) Jul 24 11:54:54 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 5: Call-ID: 1c4b4a7c57935c296cc4067f60dd7a11@192.168.0.25 (54) Jul 24 11:54:54 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 6: CSeq: 102 OPTIONS (17) Jul 24 11:54:54 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 7: User-Agent: Asterisk PBX (24) Jul 24 11:54:54 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 8: Max-Forwards: 70 (16) Jul 24 11:54:54 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 9: Date: Mon, 24 Jul 2006 09:54:54 GMT (35) Jul 24 11:54:54 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 10: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) Jul 24 11:54:54 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 11: Content-Length: 0 (17) Jul 24 11:54:54 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 12: (0) 12 headers, 0 lines Reliably Transmitting (no NAT) to 192.168.0.163:2051: OPTIONS sip:10@192.168.0.163:2051;line=upjd371q SIP/2.0 Via: SIP/2.0/UDP 192.168.0.25:5060;branch=z9hG4bK63f04986;rport From: "asterisk" ;tag=as3b85aa08 To: Contact: Call-ID: 1c4b4a7c57935c296cc4067f60dd7a11@192.168.0.25 CSeq: 102 OPTIONS User-Agent: Asterisk PBX Max-Forwards: 70 Date: Mon, 24 Jul 2006 09:54:54 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Content-Length: 0 --- Jul 24 11:54:54 DEBUG[3885]: chan_sip.c:1296 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #105 ultravoX*CLI> <-- SIP read from 192.168.0.163:2051: SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.0.25:5060;branch=z9hG4bK63f04986;rport=5060 From: "asterisk" ;tag=as3b85aa08 To: Call-ID: 1c4b4a7c57935c296cc4067f60dd7a11@192.168.0.25 CSeq: 102 OPTIONS Contact: User-Agent: snom360/4.1 Accept-Language: en Accept: application/sdp Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO Allow-Events: talk, hold, refer Supported: timer, 100rel, replaces, callerid Content-Length: 0 Jul 24 11:54:54 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 0: SIP/2.0 200 OK (14) Jul 24 11:54:54 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.0.25:5060;branch=z9hG4bK63f04986;rport=5060 (68) Jul 24 11:54:54 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 2: From: "asterisk" ;tag=as3b85aa08 (59) Jul 24 11:54:54 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 3: To: (45) Jul 24 11:54:54 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 4: Call-ID: 1c4b4a7c57935c296cc4067f60dd7a11@192.168.0.25 (54) Jul 24 11:54:54 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 5: CSeq: 102 OPTIONS (17) Jul 24 11:54:54 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 6: Contact: (50) Jul 24 11:54:54 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 7: User-Agent: snom360/4.1 (23) Jul 24 11:54:54 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 8: Accept-Language: en (19) Jul 24 11:54:54 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 9: Accept: application/sdp (23) Jul 24 11:54:54 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 10: Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO (88) Jul 24 11:54:54 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 11: Allow-Events: talk, hold, refer (31) Jul 24 11:54:54 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 12: Supported: timer, 100rel, replaces, callerid (44) Jul 24 11:54:54 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 13: Content-Length: 0 (17) Jul 24 11:54:54 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 14: (0) --- (14 headers 0 lines)--- Jul 24 11:54:54 DEBUG[3885]: chan_sip.c:1393 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #105 Jul 24 11:54:54 DEBUG[3885]: chan_sip.c:1404 __sip_ack: Stopping retransmission on '1c4b4a7c57935c296cc4067f60dd7a11@192.168.0.25' of Request 102: Match Found Destroying call '1c4b4a7c57935c296cc4067f60dd7a11@192.168.0.25' Jul 24 11:55:06 DEBUG[3885]: chan_sip.c:3156 sip_alloc: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP) Jul 24 11:55:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 0: OPTIONS sip:13@192.168.0.190:2051;line=no7rb4d3 SIP/2.0 (55) Jul 24 11:55:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.0.25:5060;branch=z9hG4bK038c49ff;rport (63) Jul 24 11:55:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 2: From: "asterisk" ;tag=as66e0fbf6 (59) Jul 24 11:55:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 3: To: (45) Jul 24 11:55:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 4: Contact: (36) Jul 24 11:55:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 5: Call-ID: 3088f2fd13a9b6ad6ca24bda27d02b1b@192.168.0.25 (54) Jul 24 11:55:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 6: CSeq: 102 OPTIONS (17) Jul 24 11:55:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 7: User-Agent: Asterisk PBX (24) Jul 24 11:55:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 8: Max-Forwards: 70 (16) Jul 24 11:55:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 9: Date: Mon, 24 Jul 2006 09:55:06 GMT (35) Jul 24 11:55:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 10: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) Jul 24 11:55:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 11: Content-Length: 0 (17) Jul 24 11:55:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 12: (0) 12 headers, 0 lines Reliably Transmitting (no NAT) to 192.168.0.190:2051: OPTIONS sip:13@192.168.0.190:2051;line=no7rb4d3 SIP/2.0 Via: SIP/2.0/UDP 192.168.0.25:5060;branch=z9hG4bK038c49ff;rport From: "asterisk" ;tag=as66e0fbf6 To: Contact: Call-ID: 3088f2fd13a9b6ad6ca24bda27d02b1b@192.168.0.25 CSeq: 102 OPTIONS User-Agent: Asterisk PBX Max-Forwards: 70 Date: Mon, 24 Jul 2006 09:55:06 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Content-Length: 0 --- Jul 24 11:55:06 DEBUG[3885]: chan_sip.c:1296 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #108 ultravoX*CLI> <-- SIP read from 192.168.0.190:2051: SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.0.25:5060;branch=z9hG4bK038c49ff;rport=5060 From: "asterisk" ;tag=as66e0fbf6 To: Call-ID: 3088f2fd13a9b6ad6ca24bda27d02b1b@192.168.0.25 CSeq: 102 OPTIONS Contact: User-Agent: snom320/4.1 Accept-Language: en Accept: application/sdp Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO Allow-Events: talk, hold, refer Supported: timer, 100rel, replaces, callerid Content-Length: 0 Jul 24 11:55:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 0: SIP/2.0 200 OK (14) Jul 24 11:55:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.0.25:5060;branch=z9hG4bK038c49ff;rport=5060 (68) Jul 24 11:55:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 2: From: "asterisk" ;tag=as66e0fbf6 (59) Jul 24 11:55:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 3: To: (45) Jul 24 11:55:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 4: Call-ID: 3088f2fd13a9b6ad6ca24bda27d02b1b@192.168.0.25 (54) Jul 24 11:55:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 5: CSeq: 102 OPTIONS (17) Jul 24 11:55:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 6: Contact: (50) Jul 24 11:55:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 7: User-Agent: snom320/4.1 (23) Jul 24 11:55:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 8: Accept-Language: en (19) Jul 24 11:55:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 9: Accept: application/sdp (23) Jul 24 11:55:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 10: Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO (88) Jul 24 11:55:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 11: Allow-Events: talk, hold, refer (31) Jul 24 11:55:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 12: Supported: timer, 100rel, replaces, callerid (44) Jul 24 11:55:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 13: Content-Length: 0 (17) Jul 24 11:55:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 14: (0) --- (14 headers 0 lines)--- Jul 24 11:55:06 DEBUG[3885]: chan_sip.c:1393 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #108 Jul 24 11:55:06 DEBUG[3885]: chan_sip.c:1404 __sip_ack: Stopping retransmission on '3088f2fd13a9b6ad6ca24bda27d02b1b@192.168.0.25' of Request 102: Match Found Destroying call '3088f2fd13a9b6ad6ca24bda27d02b1b@192.168.0.25' Jul 24 11:55:06 DEBUG[3885]: chan_sip.c:3156 sip_alloc: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP) Jul 24 11:55:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 0: OPTIONS sip:11@192.168.0.189:2054;line=sczhjqwm SIP/2.0 (55) Jul 24 11:55:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.0.25:5060;branch=z9hG4bK16780cdd;rport (63) Jul 24 11:55:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 2: From: "asterisk" ;tag=as2081c200 (59) Jul 24 11:55:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 3: To: (45) Jul 24 11:55:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 4: Contact: (36) Jul 24 11:55:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 5: Call-ID: 33cf42df6fd0ea0b6f9f5e537564f61a@192.168.0.25 (54) Jul 24 11:55:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 6: CSeq: 102 OPTIONS (17) Jul 24 11:55:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 7: User-Agent: Asterisk PBX (24) Jul 24 11:55:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 8: Max-Forwards: 70 (16) Jul 24 11:55:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 9: Date: Mon, 24 Jul 2006 09:55:06 GMT (35) Jul 24 11:55:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 10: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) Jul 24 11:55:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 11: Content-Length: 0 (17) Jul 24 11:55:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 12: (0) 12 headers, 0 lines Reliably Transmitting (no NAT) to 192.168.0.189:2054: OPTIONS sip:11@192.168.0.189:2054;line=sczhjqwm SIP/2.0 Via: SIP/2.0/UDP 192.168.0.25:5060;branch=z9hG4bK16780cdd;rport From: "asterisk" ;tag=as2081c200 To: Contact: Call-ID: 33cf42df6fd0ea0b6f9f5e537564f61a@192.168.0.25 CSeq: 102 OPTIONS User-Agent: Asterisk PBX Max-Forwards: 70 Date: Mon, 24 Jul 2006 09:55:06 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Content-Length: 0 --- Jul 24 11:55:06 DEBUG[3885]: chan_sip.c:1296 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #111 ultravoX*CLI> <-- SIP read from 192.168.0.189:2054: SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.0.25:5060;branch=z9hG4bK16780cdd;rport=5060 From: "asterisk" ;tag=as2081c200 To: Call-ID: 33cf42df6fd0ea0b6f9f5e537564f61a@192.168.0.25 CSeq: 102 OPTIONS Contact: ;flow-id=1 User-Agent: snom320/6.2 Accept-Language: en Accept: application/sdp Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO Allow-Events: talk, hold, refer Supported: timer, 100rel, replaces, callerid Content-Length: 0 Jul 24 11:55:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 0: SIP/2.0 200 OK (14) Jul 24 11:55:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.0.25:5060;branch=z9hG4bK16780cdd;rport=5060 (68) Jul 24 11:55:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 2: From: "asterisk" ;tag=as2081c200 (59) Jul 24 11:55:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 3: To: (45) Jul 24 11:55:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 4: Call-ID: 33cf42df6fd0ea0b6f9f5e537564f61a@192.168.0.25 (54) Jul 24 11:55:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 5: CSeq: 102 OPTIONS (17) Jul 24 11:55:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 6: Contact: ;flow-id=1 (60) Jul 24 11:55:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 7: User-Agent: snom320/6.2 (23) Jul 24 11:55:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 8: Accept-Language: en (19) Jul 24 11:55:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 9: Accept: application/sdp (23) Jul 24 11:55:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 10: Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO (88) Jul 24 11:55:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 11: Allow-Events: talk, hold, refer (31) Jul 24 11:55:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 12: Supported: timer, 100rel, replaces, callerid (44) Jul 24 11:55:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 13: Content-Length: 0 (17) Jul 24 11:55:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 14: (0) --- (14 headers 0 lines)--- Jul 24 11:55:06 DEBUG[3885]: chan_sip.c:1393 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #111 Jul 24 11:55:06 DEBUG[3885]: chan_sip.c:1404 __sip_ack: Stopping retransmission on '33cf42df6fd0ea0b6f9f5e537564f61a@192.168.0.25' of Request 102: Match Found Destroying call '33cf42df6fd0ea0b6f9f5e537564f61a@192.168.0.25' Jul 24 11:55:54 DEBUG[3885]: chan_sip.c:3156 sip_alloc: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP) Jul 24 11:55:54 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 0: OPTIONS sip:10@192.168.0.163:2051;line=upjd371q SIP/2.0 (55) Jul 24 11:55:54 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.0.25:5060;branch=z9hG4bK196bfe28;rport (63) Jul 24 11:55:54 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 2: From: "asterisk" ;tag=as66052e1f (59) Jul 24 11:55:54 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 3: To: (45) Jul 24 11:55:54 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 4: Contact: (36) Jul 24 11:55:54 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 5: Call-ID: 2d93199c77f4611426766eec7307575c@192.168.0.25 (54) Jul 24 11:55:54 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 6: CSeq: 102 OPTIONS (17) Jul 24 11:55:54 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 7: User-Agent: Asterisk PBX (24) Jul 24 11:55:54 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 8: Max-Forwards: 70 (16) Jul 24 11:55:54 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 9: Date: Mon, 24 Jul 2006 09:55:54 GMT (35) Jul 24 11:55:54 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 10: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) Jul 24 11:55:54 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 11: Content-Length: 0 (17) Jul 24 11:55:54 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 12: (0) 12 headers, 0 lines Reliably Transmitting (no NAT) to 192.168.0.163:2051: OPTIONS sip:10@192.168.0.163:2051;line=upjd371q SIP/2.0 Via: SIP/2.0/UDP 192.168.0.25:5060;branch=z9hG4bK196bfe28;rport From: "asterisk" ;tag=as66052e1f To: Contact: Call-ID: 2d93199c77f4611426766eec7307575c@192.168.0.25 CSeq: 102 OPTIONS User-Agent: Asterisk PBX Max-Forwards: 70 Date: Mon, 24 Jul 2006 09:55:54 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Content-Length: 0 --- Jul 24 11:55:54 DEBUG[3885]: chan_sip.c:1296 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #114 ultravoX*CLI> <-- SIP read from 192.168.0.163:2051: SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.0.25:5060;branch=z9hG4bK196bfe28;rport=5060 From: "asterisk" ;tag=as66052e1f To: Call-ID: 2d93199c77f4611426766eec7307575c@192.168.0.25 CSeq: 102 OPTIONS Contact: User-Agent: snom360/4.1 Accept-Language: en Accept: application/sdp Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO Allow-Events: talk, hold, refer Supported: timer, 100rel, replaces, callerid Content-Length: 0 Jul 24 11:55:54 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 0: SIP/2.0 200 OK (14) Jul 24 11:55:54 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.0.25:5060;branch=z9hG4bK196bfe28;rport=5060 (68) Jul 24 11:55:54 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 2: From: "asterisk" ;tag=as66052e1f (59) Jul 24 11:55:54 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 3: To: (45) Jul 24 11:55:54 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 4: Call-ID: 2d93199c77f4611426766eec7307575c@192.168.0.25 (54) Jul 24 11:55:54 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 5: CSeq: 102 OPTIONS (17) Jul 24 11:55:54 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 6: Contact: (50) Jul 24 11:55:54 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 7: User-Agent: snom360/4.1 (23) Jul 24 11:55:54 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 8: Accept-Language: en (19) Jul 24 11:55:54 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 9: Accept: application/sdp (23) Jul 24 11:55:54 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 10: Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO (88) Jul 24 11:55:54 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 11: Allow-Events: talk, hold, refer (31) Jul 24 11:55:54 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 12: Supported: timer, 100rel, replaces, callerid (44) Jul 24 11:55:54 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 13: Content-Length: 0 (17) Jul 24 11:55:54 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 14: (0) --- (14 headers 0 lines)--- Jul 24 11:55:54 DEBUG[3885]: chan_sip.c:1393 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #114 Jul 24 11:55:54 DEBUG[3885]: chan_sip.c:1404 __sip_ack: Stopping retransmission on '2d93199c77f4611426766eec7307575c@192.168.0.25' of Request 102: Match Found Destroying call '2d93199c77f4611426766eec7307575c@192.168.0.25' Jul 24 11:56:06 DEBUG[3885]: chan_sip.c:3156 sip_alloc: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP) Jul 24 11:56:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 0: OPTIONS sip:13@192.168.0.190:2051;line=no7rb4d3 SIP/2.0 (55) Jul 24 11:56:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.0.25:5060;branch=z9hG4bK6dcaa88b;rport (63) Jul 24 11:56:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 2: From: "asterisk" ;tag=as245d086d (59) Jul 24 11:56:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 3: To: (45) Jul 24 11:56:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 4: Contact: (36) Jul 24 11:56:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 5: Call-ID: 587c40a259e3377f759eab4f117c2818@192.168.0.25 (54) Jul 24 11:56:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 6: CSeq: 102 OPTIONS (17) Jul 24 11:56:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 7: User-Agent: Asterisk PBX (24) Jul 24 11:56:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 8: Max-Forwards: 70 (16) Jul 24 11:56:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 9: Date: Mon, 24 Jul 2006 09:56:06 GMT (35) Jul 24 11:56:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 10: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) Jul 24 11:56:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 11: Content-Length: 0 (17) Jul 24 11:56:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 12: (0) 12 headers, 0 lines Reliably Transmitting (no NAT) to 192.168.0.190:2051: OPTIONS sip:13@192.168.0.190:2051;line=no7rb4d3 SIP/2.0 Via: SIP/2.0/UDP 192.168.0.25:5060;branch=z9hG4bK6dcaa88b;rport From: "asterisk" ;tag=as245d086d To: Contact: Call-ID: 587c40a259e3377f759eab4f117c2818@192.168.0.25 CSeq: 102 OPTIONS User-Agent: Asterisk PBX Max-Forwards: 70 Date: Mon, 24 Jul 2006 09:56:06 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Content-Length: 0 --- Jul 24 11:56:06 DEBUG[3885]: chan_sip.c:1296 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #117 ultravoX*CLI> <-- SIP read from 192.168.0.190:2051: SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.0.25:5060;branch=z9hG4bK6dcaa88b;rport=5060 From: "asterisk" ;tag=as245d086d To: Call-ID: 587c40a259e3377f759eab4f117c2818@192.168.0.25 CSeq: 102 OPTIONS Contact: User-Agent: snom320/4.1 Accept-Language: en Accept: application/sdp Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO Allow-Events: talk, hold, refer Supported: timer, 100rel, replaces, callerid Content-Length: 0 Jul 24 11:56:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 0: SIP/2.0 200 OK (14) Jul 24 11:56:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.0.25:5060;branch=z9hG4bK6dcaa88b;rport=5060 (68) Jul 24 11:56:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 2: From: "asterisk" ;tag=as245d086d (59) Jul 24 11:56:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 3: To: (45) Jul 24 11:56:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 4: Call-ID: 587c40a259e3377f759eab4f117c2818@192.168.0.25 (54) Jul 24 11:56:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 5: CSeq: 102 OPTIONS (17) Jul 24 11:56:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 6: Contact: (50) Jul 24 11:56:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 7: User-Agent: snom320/4.1 (23) Jul 24 11:56:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 8: Accept-Language: en (19) Jul 24 11:56:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 9: Accept: application/sdp (23) Jul 24 11:56:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 10: Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO (88) Jul 24 11:56:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 11: Allow-Events: talk, hold, refer (31) Jul 24 11:56:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 12: Supported: timer, 100rel, replaces, callerid (44) Jul 24 11:56:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 13: Content-Length: 0 (17) Jul 24 11:56:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 14: (0) --- (14 headers 0 lines)--- Jul 24 11:56:06 DEBUG[3885]: chan_sip.c:1393 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #117 Jul 24 11:56:06 DEBUG[3885]: chan_sip.c:1404 __sip_ack: Stopping retransmission on '587c40a259e3377f759eab4f117c2818@192.168.0.25' of Request 102: Match Found Destroying call '587c40a259e3377f759eab4f117c2818@192.168.0.25' Jul 24 11:56:06 DEBUG[3885]: chan_sip.c:3156 sip_alloc: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP) Jul 24 11:56:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 0: OPTIONS sip:11@192.168.0.189:2054;line=sczhjqwm SIP/2.0 (55) Jul 24 11:56:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.0.25:5060;branch=z9hG4bK318b826e;rport (63) Jul 24 11:56:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 2: From: "asterisk" ;tag=as7161bbed (59) Jul 24 11:56:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 3: To: (45) Jul 24 11:56:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 4: Contact: (36) Jul 24 11:56:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 5: Call-ID: 3a37126b1a9a35460160cad03ce674d9@192.168.0.25 (54) Jul 24 11:56:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 6: CSeq: 102 OPTIONS (17) Jul 24 11:56:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 7: User-Agent: Asterisk PBX (24) Jul 24 11:56:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 8: Max-Forwards: 70 (16) Jul 24 11:56:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 9: Date: Mon, 24 Jul 2006 09:56:06 GMT (35) Jul 24 11:56:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 10: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) Jul 24 11:56:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 11: Content-Length: 0 (17) Jul 24 11:56:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 12: (0) 12 headers, 0 lines Reliably Transmitting (no NAT) to 192.168.0.189:2054: OPTIONS sip:11@192.168.0.189:2054;line=sczhjqwm SIP/2.0 Via: SIP/2.0/UDP 192.168.0.25:5060;branch=z9hG4bK318b826e;rport From: "asterisk" ;tag=as7161bbed To: Contact: Call-ID: 3a37126b1a9a35460160cad03ce674d9@192.168.0.25 CSeq: 102 OPTIONS User-Agent: Asterisk PBX Max-Forwards: 70 Date: Mon, 24 Jul 2006 09:56:06 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Content-Length: 0 --- Jul 24 11:56:06 DEBUG[3885]: chan_sip.c:1296 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #120 ultravoX*CLI> <-- SIP read from 192.168.0.189:2054: SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.0.25:5060;branch=z9hG4bK318b826e;rport=5060 From: "asterisk" ;tag=as7161bbed To: Call-ID: 3a37126b1a9a35460160cad03ce674d9@192.168.0.25 CSeq: 102 OPTIONS Contact: ;flow-id=1 User-Agent: snom320/6.2 Accept-Language: en Accept: application/sdp Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO Allow-Events: talk, hold, refer Supported: timer, 100rel, replaces, callerid Content-Length: 0 Jul 24 11:56:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 0: SIP/2.0 200 OK (14) Jul 24 11:56:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.0.25:5060;branch=z9hG4bK318b826e;rport=5060 (68) Jul 24 11:56:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 2: From: "asterisk" ;tag=as7161bbed (59) Jul 24 11:56:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 3: To: (45) Jul 24 11:56:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 4: Call-ID: 3a37126b1a9a35460160cad03ce674d9@192.168.0.25 (54) Jul 24 11:56:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 5: CSeq: 102 OPTIONS (17) Jul 24 11:56:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 6: Contact: ;flow-id=1 (60) Jul 24 11:56:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 7: User-Agent: snom320/6.2 (23) Jul 24 11:56:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 8: Accept-Language: en (19) Jul 24 11:56:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 9: Accept: application/sdp (23) Jul 24 11:56:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 10: Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO (88) Jul 24 11:56:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 11: Allow-Events: talk, hold, refer (31) Jul 24 11:56:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 12: Supported: timer, 100rel, replaces, callerid (44) Jul 24 11:56:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 13: Content-Length: 0 (17) Jul 24 11:56:06 DEBUG[3885]: chan_sip.c:3372 parse_request: Header 14: (0) --- (14 headers 0 lines)--- Jul 24 11:56:06 DEBUG[3885]: chan_sip.c:1393 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #120 Jul 24 11:56:06 DEBUG[3885]: chan_sip.c:1404 __sip_ack: Stopping retransmission on '3a37126b1a9a35460160cad03ce674d9@192.168.0.25' of Request 102: Match Found Destroying call '3a37126b1a9a35460160cad03ce674d9@192.168.0.25'