[Mar 2 14:47:14] Asterisk Ready. ]1;Asterisk]2;Asterisk Console on 'vcch120' (pid 20518)*CLI> sip debuget verbose 4debug 4ip debuget debug 4 Core debug was 5 and is now 4 *CLI> set debug 4ip debuget verbose 4 Verbosity was 5 and is now 4 *CLI> set verbose 4debug 4ip debug SIP Debugging enabled *CLI> [Mar 2 14:47:23] <-- SIP read from 192.168.98.162:2051: INVITE sip:700@192.168.98.120 SIP/2.0 Via: SIP/2.0/UDP 192.168.98.162:2051;branch=z9hG4bK-76hcclli8oti;rport From: ;tag=kjpbj07q55 To: Call-ID: 3c3becb9222e-0cu1xn1bcocp@snom320-0004132475DA CSeq: 1 INVITE Max-Forwards: 70 Contact: ;flow-id=1 P-Key-Flags: keys="3" User-Agent: snom320/6.5.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;refresher=uas Min-SE: 90 Content-Type: application/sdp Content-Length: 479 v=0 o=root 1222033344 1222033344 IN IP4 192.168.98.162 s=call c=IN IP4 192.168.98.162 t=0 0 m=audio 58582 RTP/AVP 0 8 9 2 3 18 4 101 a=crypto:1 AES_CM_128_HMAC_SHA1_32 inline:2v0WNLaIsWO2Uaqvy+MVpWGWa6mCE63cQsU2TpqB 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 [Mar 2 14:47:23] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 0: INVITE sip:700@192.168.98.120 SIP/2.0 (37) [Mar 2 14:47:23] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.98.162:2051;branch=z9hG4bK-76hcclli8oti;rport (70) [Mar 2 14:47:23] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 2: From: ;tag=kjpbj07q55 (46) [Mar 2 14:47:23] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 3: To: (28) [Mar 2 14:47:23] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 4: Call-ID: 3c3becb9222e-0cu1xn1bcocp@snom320-0004132475DA (55) [Mar 2 14:47:23] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 5: CSeq: 1 INVITE (14) [Mar 2 14:47:23] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 6: Max-Forwards: 70 (16) [Mar 2 14:47:23] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 7: Contact: ;flow-id=1 (63) [Mar 2 14:47:23] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 8: P-Key-Flags: keys="3" (21) [Mar 2 14:47:23] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 9: User-Agent: snom320/6.5.1 (25) [Mar 2 14:47:23] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 10: Accept: application/sdp (23) [Mar 2 14:47:23] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 11: Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO (88) [Mar 2 14:47:23] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 12: Allow-Events: talk, hold, refer (31) [Mar 2 14:47:23] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 13: Supported: timer, 100rel, replaces, callerid (44) [Mar 2 14:47:23] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 14: Session-Expires: 3600;refresher=uas (35) [Mar 2 14:47:23] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 15: Min-SE: 90 (10) [Mar 2 14:47:23] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 16: Content-Type: application/sdp (29) [Mar 2 14:47:23] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 17: Content-Length: 479 (19) [Mar 2 14:47:23] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 18: (0) [Mar 2 14:47:23] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: v=0 (3) [Mar 2 14:47:23] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: o=root 1222033344 1222033344 IN IP4 192.168.98.162 (50) [Mar 2 14:47:23] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: s=call (6) [Mar 2 14:47:23] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: c=IN IP4 192.168.98.162 (23) [Mar 2 14:47:23] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: t=0 0 (5) [Mar 2 14:47:23] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: m=audio 58582 RTP/AVP 0 8 9 2 3 18 4 101 (40) [Mar 2 14:47:23] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: a=crypto:1 AES_CM_128_HMAC_SHA1_32 inline:2v0WNLaIsWO2Uaqvy+MVpWGWa6mCE63cQsU2TpqB (82) [Mar 2 14:47:23] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: a=rtpmap:0 pcmu/8000 (20) [Mar 2 14:47:23] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: a=rtpmap:8 pcma/8000 (20) [Mar 2 14:47:23] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: a=rtpmap:9 g722/8000 (20) [Mar 2 14:47:23] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: a=rtpmap:2 g726-32/8000 (23) [Mar 2 14:47:23] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: a=rtpmap:3 gsm/8000 (19) [Mar 2 14:47:23] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: a=rtpmap:18 g729/8000 (21) [Mar 2 14:47:23] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: a=rtpmap:4 g723/8000 (20) [Mar 2 14:47:23] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [Mar 2 14:47:23] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: a=fmtp:101 0-16 (15) [Mar 2 14:47:23] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: a=ptime:20 (10) [Mar 2 14:47:23] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: a=encryption:optional (21) [Mar 2 14:47:23] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: a=sendrecv (10) [Mar 2 14:47:23] --- (18 headers 19 lines) --- [Mar 2 14:47:23] DEBUG[20529]: chan_sip.c:3191 sip_alloc: Allocating new SIP dialog for 3c3becb9222e-0cu1xn1bcocp@snom320-0004132475DA - INVITE (With RTP) [Mar 2 14:47:23] DEBUG[20529]: chan_sip.c:11296 handle_request: **** Received INVITE (5) - Command in SIP INVITE [Mar 2 14:47:23] DEBUG[20529]: chan_sip.c:1015 parse_sip_options: Begin: parsing SIP "Supported: timer, 100rel, replaces, callerid" [Mar 2 14:47:23] DEBUG[20529]: chan_sip.c:1027 parse_sip_options: Found SIP option: -timer- [Mar 2 14:47:23] DEBUG[20529]: chan_sip.c:1033 parse_sip_options: Matched SIP option: timer [Mar 2 14:47:23] DEBUG[20529]: chan_sip.c:1027 parse_sip_options: Found SIP option: -100rel- [Mar 2 14:47:23] DEBUG[20529]: chan_sip.c:1033 parse_sip_options: Matched SIP option: 100rel [Mar 2 14:47:23] DEBUG[20529]: chan_sip.c:1027 parse_sip_options: Found SIP option: -replaces- [Mar 2 14:47:23] DEBUG[20529]: chan_sip.c:1033 parse_sip_options: Matched SIP option: replaces [Mar 2 14:47:23] DEBUG[20529]: chan_sip.c:1027 parse_sip_options: Found SIP option: -callerid- [Mar 2 14:47:23] DEBUG[20529]: chan_sip.c:1038 parse_sip_options: Found no match for SIP option: callerid (Please file bug report!) [Mar 2 14:47:23] DEBUG[20529]: chan_sip.c:1044 parse_sip_options: * SIP extension value: 7 for call 3c3becb9222e-0cu1xn1bcocp@snom320-0004132475DA [Mar 2 14:47:23] Using INVITE request as basis request - 3c3becb9222e-0cu1xn1bcocp@snom320-0004132475DA [Mar 2 14:47:23] Sending to 192.168.98.162 : 2051 (NAT) [Mar 2 14:47:23] DEBUG[20529]: chan_sip.c:7282 check_user_full: Setting NAT on RTP to 0 [Mar 2 14:47:23] Reliably Transmitting (no NAT) to 192.168.98.162:2051: SIP/2.0 407 Proxy Authentication Required Via: SIP/2.0/UDP 192.168.98.162:2051;branch=z9hG4bK-76hcclli8oti;received=192.168.98.162;rport=2051 From: ;tag=kjpbj07q55 To: ;tag=as36006236 Call-ID: 3c3becb9222e-0cu1xn1bcocp@snom320-0004132475DA CSeq: 1 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Proxy-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="3c05c719" Content-Length: 0 --- [Mar 2 14:47:23] DEBUG[20529]: chan_sip.c:1307 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #3 [Mar 2 14:47:23] Scheduling destruction of call '3c3becb9222e-0cu1xn1bcocp@snom320-0004132475DA' in 15000 ms [Mar 2 14:47:23] Found user '1000' [Mar 2 14:47:23] <-- SIP read from 192.168.98.162:2051: ACK sip:700@192.168.98.120 SIP/2.0 Via: SIP/2.0/UDP 192.168.98.162:2051;branch=z9hG4bK-76hcclli8oti;rport From: ;tag=kjpbj07q55 To: ;tag=as36006236 Call-ID: 3c3becb9222e-0cu1xn1bcocp@snom320-0004132475DA CSeq: 1 ACK Max-Forwards: 70 Contact: ;flow-id=1 Content-Length: 0 [Mar 2 14:47:23] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 0: ACK sip:700@192.168.98.120 SIP/2.0 (34) [Mar 2 14:47:23] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.98.162:2051;branch=z9hG4bK-76hcclli8oti;rport (70) [Mar 2 14:47:23] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 2: From: ;tag=kjpbj07q55 (46) [Mar 2 14:47:23] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 3: To: ;tag=as36006236 (43) [Mar 2 14:47:23] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 4: Call-ID: 3c3becb9222e-0cu1xn1bcocp@snom320-0004132475DA (55) [Mar 2 14:47:23] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 5: CSeq: 1 ACK (11) [Mar 2 14:47:23] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 6: Max-Forwards: 70 (16) [Mar 2 14:47:23] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 7: Contact: ;flow-id=1 (63) [Mar 2 14:47:23] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 8: Content-Length: 0 (17) [Mar 2 14:47:23] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 9: (0) [Mar 2 14:47:23] --- (9 headers 0 lines) --- [Mar 2 14:47:23] DEBUG[20529]: chan_sip.c:11296 handle_request: **** Received ACK (6) - Command in SIP ACK [Mar 2 14:47:23] DEBUG[20529]: chan_sip.c:1403 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #3 [Mar 2 14:47:23] DEBUG[20529]: chan_sip.c:1415 __sip_ack: Stopping retransmission on '3c3becb9222e-0cu1xn1bcocp@snom320-0004132475DA' of Response 1: Match Found [Mar 2 14:47:23] <-- SIP read from 192.168.98.162:2051: INVITE sip:700@192.168.98.120 SIP/2.0 Via: SIP/2.0/UDP 192.168.98.162:2051;branch=z9hG4bK-13y3j4szpc66;rport From: ;tag=kjpbj07q55 To: Call-ID: 3c3becb9222e-0cu1xn1bcocp@snom320-0004132475DA CSeq: 2 INVITE Max-Forwards: 70 Contact: ;flow-id=1 P-Key-Flags: keys="3" User-Agent: snom320/6.5.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;refresher=uas Min-SE: 90 Proxy-Authorization: Digest username="1000",realm="asterisk",nonce="3c05c719",uri="sip:700@192.168.98.120",response="ed5b9a6bd377ebc3e1ed1f29e469dd6a",algorithm=md5 Content-Type: application/sdp Content-Length: 479 v=0 o=root 1222033344 1222033344 IN IP4 192.168.98.162 s=call c=IN IP4 192.168.98.162 t=0 0 m=audio 58582 RTP/AVP 0 8 9 2 3 18 4 101 a=crypto:1 AES_CM_128_HMAC_SHA1_32 inline:2v0WNLaIsWO2Uaqvy+MVpWGWa6mCE63cQsU2TpqB 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 [Mar 2 14:47:23] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 0: INVITE sip:700@192.168.98.120 SIP/2.0 (37) [Mar 2 14:47:23] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.98.162:2051;branch=z9hG4bK-13y3j4szpc66;rport (70) [Mar 2 14:47:23] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 2: From: ;tag=kjpbj07q55 (46) [Mar 2 14:47:23] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 3: To: (28) [Mar 2 14:47:23] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 4: Call-ID: 3c3becb9222e-0cu1xn1bcocp@snom320-0004132475DA (55) [Mar 2 14:47:23] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 5: CSeq: 2 INVITE (14) [Mar 2 14:47:23] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 6: Max-Forwards: 70 (16) [Mar 2 14:47:23] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 7: Contact: ;flow-id=1 (63) [Mar 2 14:47:23] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 8: P-Key-Flags: keys="3" (21) [Mar 2 14:47:23] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 9: User-Agent: snom320/6.5.1 (25) [Mar 2 14:47:23] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 10: Accept: application/sdp (23) [Mar 2 14:47:23] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 11: Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO (88) [Mar 2 14:47:23] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 12: Allow-Events: talk, hold, refer (31) [Mar 2 14:47:23] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 13: Supported: timer, 100rel, replaces, callerid (44) [Mar 2 14:47:23] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 14: Session-Expires: 3600;refresher=uas (35) [Mar 2 14:47:23] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 15: Min-SE: 90 (10) [Mar 2 14:47:23] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 16: Proxy-Authorization: Digest username="1000",realm="asterisk",nonce="3c05c719",uri="sip:700@192.168.98.120",response="ed5b9a6bd377ebc3e1ed1f29e469dd6a",algorithm=md5 (164) [Mar 2 14:47:23] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 17: Content-Type: application/sdp (29) [Mar 2 14:47:23] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 18: Content-Length: 479 (19) [Mar 2 14:47:23] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 19: (0) [Mar 2 14:47:23] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: v=0 (3) [Mar 2 14:47:23] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: o=root 1222033344 1222033344 IN IP4 192.168.98.162 (50) [Mar 2 14:47:23] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: s=call (6) [Mar 2 14:47:23] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: c=IN IP4 192.168.98.162 (23) [Mar 2 14:47:23] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: t=0 0 (5) [Mar 2 14:47:23] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: m=audio 58582 RTP/AVP 0 8 9 2 3 18 4 101 (40) [Mar 2 14:47:23] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: a=crypto:1 AES_CM_128_HMAC_SHA1_32 inline:2v0WNLaIsWO2Uaqvy+MVpWGWa6mCE63cQsU2TpqB (82) [Mar 2 14:47:23] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: a=rtpmap:0 pcmu/8000 (20) [Mar 2 14:47:23] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: a=rtpmap:8 pcma/8000 (20) [Mar 2 14:47:23] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: a=rtpmap:9 g722/8000 (20) [Mar 2 14:47:23] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: a=rtpmap:2 g726-32/8000 (23) [Mar 2 14:47:23] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: a=rtpmap:3 gsm/8000 (19) [Mar 2 14:47:23] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: a=rtpmap:18 g729/8000 (21) [Mar 2 14:47:23] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: a=rtpmap:4 g723/8000 (20) [Mar 2 14:47:23] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [Mar 2 14:47:23] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: a=fmtp:101 0-16 (15) [Mar 2 14:47:23] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: a=ptime:20 (10) [Mar 2 14:47:23] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: a=encryption:optional (21) [Mar 2 14:47:23] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: a=sendrecv (10) [Mar 2 14:47:23] --- (19 headers 19 lines) --- [Mar 2 14:47:23] DEBUG[20529]: chan_sip.c:11296 handle_request: **** Received INVITE (5) - Command in SIP INVITE [Mar 2 14:47:23] Using INVITE request as basis request - 3c3becb9222e-0cu1xn1bcocp@snom320-0004132475DA [Mar 2 14:47:23] Sending to 192.168.98.162 : 2051 (NAT) [Mar 2 14:47:23] DEBUG[20529]: chan_sip.c:7282 check_user_full: Setting NAT on RTP to 0 [Mar 2 14:47:23] Found user '1000' [Mar 2 14:47:23] Found RTP audio format 0 [Mar 2 14:47:23] Found RTP audio format 8 [Mar 2 14:47:23] Found RTP audio format 9 [Mar 2 14:47:23] Found RTP audio format 2 [Mar 2 14:47:23] Found RTP audio format 3 [Mar 2 14:47:23] Found RTP audio format 18 [Mar 2 14:47:23] Found RTP audio format 4 [Mar 2 14:47:23] Found RTP audio format 101 [Mar 2 14:47:23] Peer audio RTP is at port 192.168.98.162:58582 [Mar 2 14:47:23] DEBUG[20529]: chan_sip.c:3683 process_sdp: Peer audio RTP is at port 192.168.98.162:58582 [Mar 2 14:47:23] Found description format pcmu [Mar 2 14:47:23] Found description format pcma [Mar 2 14:47:23] Found description format g722 [Mar 2 14:47:23] Found description format g726-32 [Mar 2 14:47:23] Found description format gsm [Mar 2 14:47:23] Found description format g729 [Mar 2 14:47:23] Found description format g723 [Mar 2 14:47:23] Found description format telephone-event [Mar 2 14:47:23] Capabilities: us - 0x8000e (gsm|ulaw|alaw|h263), peer - audio=0x11f (g723|gsm|ulaw|alaw|g726|g729)/video=0x0 (nothing), combined - 0xe (gsm|ulaw|alaw) [Mar 2 14:47:23] Non-codec capabilities: us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) [Mar 2 14:47:23] DEBUG[20529]: chan_sip.c:10660 handle_request_invite: Checking SIP call limits for device 1000 [Mar 2 14:47:23] DEBUG[20529]: chan_sip.c:2228 update_call_counter: Updating call counter for incoming call [Mar 2 14:47:23] Looking for 700 in local (domain 192.168.98.120) [Mar 2 14:47:23] DEBUG[20529]: chan_sip.c:6258 build_route: build_route: Contact hop: ;flow-id=1 [Mar 2 14:47:23] list_route: hop: [Mar 2 14:47:23] Transmitting (no NAT) to 192.168.98.162:2051: SIP/2.0 100 Trying Via: SIP/2.0/UDP 192.168.98.162:2051;branch=z9hG4bK-13y3j4szpc66;received=192.168.98.162;rport=2051 From: ;tag=kjpbj07q55 To: Call-ID: 3c3becb9222e-0cu1xn1bcocp@snom320-0004132475DA CSeq: 2 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Contact: Content-Length: 0 --- [Mar 2 14:47:23] DEBUG[20522]: chan_sip.c:11844 sip_devicestate: Checking device state for peer 1000 [Mar 2 14:47:23] DEBUG[20522]: devicestate.c:187 do_state_change: Changing state for SIP/1000 - state 2 (In use) [Mar 2 14:47:23] DEBUG[20558]: pbx.c:1697 pbx_extension_helper: Launching 'Park' [Mar 2 14:47:23] -- Executing Park("SIP/1000-081cfd00", "") in new stack [Mar 2 14:47:23] DEBUG[20522]: chan_sip.c:11844 sip_devicestate: Checking device state for peer 1000 [Mar 2 14:47:23] DEBUG[20522]: channel.c:775 channel_find_locked: Avoiding initial deadlock for 'SIP/1000-081cfd00' [Mar 2 14:47:23] DEBUG[20558]: chan_sip.c:2570 sip_answer: sip_answer(SIP/1000-081cfd00) [Mar 2 14:47:23] We're at 192.168.98.120 port 18808 [Mar 2 14:47:23] Adding codec 0x2 (gsm) to SDP [Mar 2 14:47:23] Adding codec 0x4 (ulaw) to SDP [Mar 2 14:47:23] Adding codec 0x8 (alaw) to SDP [Mar 2 14:47:23] Adding non-codec 0x1 (telephone-event) to SDP [Mar 2 14:47:23] Reliably Transmitting (no NAT) to 192.168.98.162:2051: SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.98.162:2051;branch=z9hG4bK-13y3j4szpc66;received=192.168.98.162;rport=2051 From: ;tag=kjpbj07q55 To: ;tag=as6f172031 Call-ID: 3c3becb9222e-0cu1xn1bcocp@snom320-0004132475DA CSeq: 2 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Contact: Content-Type: application/sdp Content-Length: 267 v=0 o=root 20518 20518 IN IP4 192.168.98.120 s=session c=IN IP4 192.168.98.120 t=0 0 m=audio 18808 RTP/AVP 3 0 8 101 a=rtpmap:3 GSM/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - --- [Mar 2 14:47:23] DEBUG[20558]: chan_sip.c:1307 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #5 [Mar 2 14:47:23] DEBUG[20559]: app_queue.c:500 changethread: Device 'SIP/1000' changed to state '2' (In use) but we don't care because they're not a member of any queue. [Mar 2 14:47:23] DEBUG[20522]: devicestate.c:187 do_state_change: Changing state for SIP/1000 - state 2 (In use) [Mar 2 14:47:23] DEBUG[20560]: app_queue.c:500 changethread: Device 'SIP/1000' changed to state '2' (In use) but we don't care because they're not a member of any queue. [Mar 2 14:47:23] <-- SIP read from 192.168.98.162:2051: ACK sip:700@192.168.98.120 SIP/2.0 Via: SIP/2.0/UDP 192.168.98.162:2051;branch=z9hG4bK-mybkfobm57ia;rport From: ;tag=kjpbj07q55 To: ;tag=as6f172031 Call-ID: 3c3becb9222e-0cu1xn1bcocp@snom320-0004132475DA CSeq: 2 ACK Max-Forwards: 70 Contact: ;flow-id=1 Content-Length: 0 [Mar 2 14:47:23] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 0: ACK sip:700@192.168.98.120 SIP/2.0 (34) [Mar 2 14:47:23] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.98.162:2051;branch=z9hG4bK-mybkfobm57ia;rport (70) [Mar 2 14:47:23] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 2: From: ;tag=kjpbj07q55 (46) [Mar 2 14:47:23] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 3: To: ;tag=as6f172031 (43) [Mar 2 14:47:23] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 4: Call-ID: 3c3becb9222e-0cu1xn1bcocp@snom320-0004132475DA (55) [Mar 2 14:47:23] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 5: CSeq: 2 ACK (11) [Mar 2 14:47:23] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 6: Max-Forwards: 70 (16) [Mar 2 14:47:23] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 7: Contact: ;flow-id=1 (63) [Mar 2 14:47:23] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 8: Content-Length: 0 (17) [Mar 2 14:47:23] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 9: (0) [Mar 2 14:47:23] --- (9 headers 0 lines) --- [Mar 2 14:47:23] DEBUG[20529]: chan_sip.c:11296 handle_request: **** Received ACK (6) - Command in SIP ACK [Mar 2 14:47:23] DEBUG[20529]: chan_sip.c:1403 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #5 [Mar 2 14:47:23] DEBUG[20529]: chan_sip.c:1415 __sip_ack: Stopping retransmission on '3c3becb9222e-0cu1xn1bcocp@snom320-0004132475DA' of Response 2: Match Found [Mar 2 14:47:23] DEBUG[20558]: rtp.c:411 ast_rtcp_read: Got RTCP report of 52 bytes [Mar 2 14:47:24] DEBUG[20558]: chan_sip.c:3051 sip_rtp_read: Oooh, format changed to 2 [Mar 2 14:47:24] DEBUG[20558]: channel.c:2414 set_format: Set channel SIP/1000-081cfd00 to read format ulaw [Mar 2 14:47:24] DEBUG[20558]: channel.c:2414 set_format: Set channel SIP/1000-081cfd00 to write format ulaw [Mar 2 14:47:24] == Parked SIP/1000-081cfd00 on 701. Will timeout back to extension [local] s, 1 in 45 seconds [Mar 2 14:47:24] DEBUG[20558]: pbx.c:4898 ast_add_extension2: Added extension '701' priority 1 to parkedcalls [Mar 2 14:47:24] -- Added extension '701' priority 1 to parkedcalls [Mar 2 14:47:24] DEBUG[20558]: channel.c:2414 set_format: Set channel SIP/1000-081cfd00 to write format gsm [Mar 2 14:47:24] DEBUG[20558]: rtp.c:1361 ast_rtp_write: Ooh, format changed from unknown to gsm [Mar 2 14:47:24] DEBUG[20558]: channel.c:1759 ast_settimeout: Scheduling timer at 160 sample intervals [Mar 2 14:47:24] -- Playing 'digits/7' (language 'en') [Mar 2 14:47:26] <-- SIP read from 192.168.98.162:2051: INVITE sip:700@192.168.98.120 SIP/2.0 Via: SIP/2.0/UDP 192.168.98.162:2051;branch=z9hG4bK-dv4ozkwuqm18;rport From: ;tag=kjpbj07q55 To: ;tag=as6f172031 Call-ID: 3c3becb9222e-0cu1xn1bcocp@snom320-0004132475DA CSeq: 3 INVITE Max-Forwards: 70 Contact: ;flow-id=1 P-Key-Flags: keys="3" User-Agent: snom320/6.5.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;refresher=uas Min-SE: 90 Content-Type: application/sdp Content-Length: 472 v=0 o=root 1222033344 1222033345 IN IP4 192.168.98.162 s=call c=IN IP4 0.0.0.0 t=0 0 m=audio 58582 RTP/AVP 0 8 9 2 3 18 4 101 a=crypto:1 AES_CM_128_HMAC_SHA1_32 inline:2v0WNLaIsWO2Uaqvy+MVpWGWa6mCE63cQsU2TpqB 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 [Mar 2 14:47:26] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 0: INVITE sip:700@192.168.98.120 SIP/2.0 (37) [Mar 2 14:47:26] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.98.162:2051;branch=z9hG4bK-dv4ozkwuqm18;rport (70) [Mar 2 14:47:26] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 2: From: ;tag=kjpbj07q55 (46) [Mar 2 14:47:26] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 3: To: ;tag=as6f172031 (43) [Mar 2 14:47:26] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 4: Call-ID: 3c3becb9222e-0cu1xn1bcocp@snom320-0004132475DA (55) [Mar 2 14:47:26] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 5: CSeq: 3 INVITE (14) [Mar 2 14:47:26] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 6: Max-Forwards: 70 (16) [Mar 2 14:47:26] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 7: Contact: ;flow-id=1 (63) [Mar 2 14:47:26] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 8: P-Key-Flags: keys="3" (21) [Mar 2 14:47:26] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 9: User-Agent: snom320/6.5.1 (25) [Mar 2 14:47:26] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 10: Accept: application/sdp (23) [Mar 2 14:47:26] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 11: Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO (88) [Mar 2 14:47:26] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 12: Allow-Events: talk, hold, refer (31) [Mar 2 14:47:26] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 13: Supported: timer, 100rel, replaces, callerid (44) [Mar 2 14:47:26] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 14: Session-Expires: 3600;refresher=uas (35) [Mar 2 14:47:26] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 15: Min-SE: 90 (10) [Mar 2 14:47:26] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 16: Content-Type: application/sdp (29) [Mar 2 14:47:26] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 17: Content-Length: 472 (19) [Mar 2 14:47:26] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 18: (0) [Mar 2 14:47:26] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: v=0 (3) [Mar 2 14:47:26] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: o=root 1222033344 1222033345 IN IP4 192.168.98.162 (50) [Mar 2 14:47:26] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: s=call (6) [Mar 2 14:47:26] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: c=IN IP4 0.0.0.0 (16) [Mar 2 14:47:26] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: t=0 0 (5) [Mar 2 14:47:26] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: m=audio 58582 RTP/AVP 0 8 9 2 3 18 4 101 (40) [Mar 2 14:47:26] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: a=crypto:1 AES_CM_128_HMAC_SHA1_32 inline:2v0WNLaIsWO2Uaqvy+MVpWGWa6mCE63cQsU2TpqB (82) [Mar 2 14:47:26] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: a=rtpmap:0 pcmu/8000 (20) [Mar 2 14:47:26] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: a=rtpmap:8 pcma/8000 (20) [Mar 2 14:47:26] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: a=rtpmap:9 g722/8000 (20) [Mar 2 14:47:26] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: a=rtpmap:2 g726-32/8000 (23) [Mar 2 14:47:26] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: a=rtpmap:3 gsm/8000 (19) [Mar 2 14:47:26] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: a=rtpmap:18 g729/8000 (21) [Mar 2 14:47:26] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: a=rtpmap:4 g723/8000 (20) [Mar 2 14:47:26] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [Mar 2 14:47:26] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: a=fmtp:101 0-16 (15) [Mar 2 14:47:26] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: a=ptime:20 (10) [Mar 2 14:47:26] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: a=encryption:optional (21) [Mar 2 14:47:26] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: a=sendonly (10) [Mar 2 14:47:26] --- (18 headers 19 lines) --- [Mar 2 14:47:26] DEBUG[20529]: chan_sip.c:11296 handle_request: **** Received INVITE (5) - Command in SIP INVITE [Mar 2 14:47:26] Using INVITE request as basis request - 3c3becb9222e-0cu1xn1bcocp@snom320-0004132475DA [Mar 2 14:47:26] Sending to 192.168.98.162 : 2051 (NAT) [Mar 2 14:47:26] Found RTP audio format 0 [Mar 2 14:47:26] Found RTP audio format 8 [Mar 2 14:47:26] Found RTP audio format 9 [Mar 2 14:47:26] Found RTP audio format 2 [Mar 2 14:47:26] Found RTP audio format 3 [Mar 2 14:47:26] Found RTP audio format 18 [Mar 2 14:47:26] Found RTP audio format 4 [Mar 2 14:47:26] Found RTP audio format 101 [Mar 2 14:47:26] Peer audio RTP is at port 0.0.0.0:58582 [Mar 2 14:47:26] DEBUG[20529]: chan_sip.c:3683 process_sdp: Peer audio RTP is at port 0.0.0.0:58582 [Mar 2 14:47:26] Found description format pcmu [Mar 2 14:47:26] Found description format pcma [Mar 2 14:47:26] Found description format g722 [Mar 2 14:47:26] Found description format g726-32 [Mar 2 14:47:26] Found description format gsm [Mar 2 14:47:26] Found description format g729 [Mar 2 14:47:26] Found description format g723 [Mar 2 14:47:26] Found description format telephone-event [Mar 2 14:47:26] Capabilities: us - 0x8000e (gsm|ulaw|alaw|h263), peer - audio=0x11f (g723|gsm|ulaw|alaw|g726|g729)/video=0x0 (nothing), combined - 0xe (gsm|ulaw|alaw) [Mar 2 14:47:26] Non-codec capabilities: us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) [Mar 2 14:47:26] DEBUG[20529]: chan_sip.c:10704 handle_request_invite: Got a SIP re-invite for call 3c3becb9222e-0cu1xn1bcocp@snom320-0004132475DA [Mar 2 14:47:26] We're at 192.168.98.120 port 18808 [Mar 2 14:47:26] Adding codec 0x2 (gsm) to SDP [Mar 2 14:47:26] Adding codec 0x4 (ulaw) to SDP [Mar 2 14:47:26] Adding codec 0x8 (alaw) to SDP [Mar 2 14:47:26] Adding non-codec 0x1 (telephone-event) to SDP [Mar 2 14:47:26] Reliably Transmitting (NAT) to 192.168.98.162:2051: SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.98.162:2051;branch=z9hG4bK-dv4ozkwuqm18;received=192.168.98.162;rport=2051 From: ;tag=kjpbj07q55 To: ;tag=as6f172031 Call-ID: 3c3becb9222e-0cu1xn1bcocp@snom320-0004132475DA CSeq: 3 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Contact: Content-Type: application/sdp Content-Length: 267 v=0 o=root 20518 20519 IN IP4 192.168.98.120 s=session c=IN IP4 192.168.98.120 t=0 0 m=audio 18808 RTP/AVP 3 0 8 101 a=rtpmap:3 GSM/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - --- [Mar 2 14:47:26] DEBUG[20529]: chan_sip.c:1307 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #6 [Mar 2 14:47:26] <-- SIP read from 192.168.98.162:2051: ACK sip:700@192.168.98.120 SIP/2.0 Via: SIP/2.0/UDP 192.168.98.162:2051;branch=z9hG4bK-weszepk057po;rport From: ;tag=kjpbj07q55 To: ;tag=as6f172031 Call-ID: 3c3becb9222e-0cu1xn1bcocp@snom320-0004132475DA CSeq: 3 ACK Max-Forwards: 70 Contact: ;flow-id=1 Content-Length: 0 [Mar 2 14:47:26] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 0: ACK sip:700@192.168.98.120 SIP/2.0 (34) [Mar 2 14:47:26] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.98.162:2051;branch=z9hG4bK-weszepk057po;rport (70) [Mar 2 14:47:26] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 2: From: ;tag=kjpbj07q55 (46) [Mar 2 14:47:26] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 3: To: ;tag=as6f172031 (43) [Mar 2 14:47:26] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 4: Call-ID: 3c3becb9222e-0cu1xn1bcocp@snom320-0004132475DA (55) [Mar 2 14:47:26] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 5: CSeq: 3 ACK (11) [Mar 2 14:47:26] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 6: Max-Forwards: 70 (16) [Mar 2 14:47:26] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 7: Contact: ;flow-id=1 (63) [Mar 2 14:47:26] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 8: Content-Length: 0 (17) [Mar 2 14:47:26] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 9: (0) [Mar 2 14:47:26] --- (9 headers 0 lines) --- [Mar 2 14:47:26] DEBUG[20529]: chan_sip.c:11296 handle_request: **** Received ACK (6) - Command in SIP ACK [Mar 2 14:47:26] DEBUG[20529]: chan_sip.c:1403 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #6 [Mar 2 14:47:26] DEBUG[20529]: chan_sip.c:1415 __sip_ack: Stopping retransmission on '3c3becb9222e-0cu1xn1bcocp@snom320-0004132475DA' of Response 3: Match Found [Mar 2 14:47:28] <-- SIP read from 192.168.98.162:2051: INVITE sip:701@192.168.98.120 SIP/2.0 Via: SIP/2.0/UDP 192.168.98.162:2051;branch=z9hG4bK-y4bjjhsgfbok;rport From: ;tag=qzdpvzvvp7 To: Call-ID: 3c3becbd7530-2g3pz7higtpm@snom320-0004132475DA CSeq: 1 INVITE Max-Forwards: 70 Contact: ;flow-id=1 P-Key-Flags: keys="3" User-Agent: snom320/6.5.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;refresher=uas Min-SE: 90 Content-Type: application/sdp Content-Length: 477 v=0 o=root 401972089 401972089 IN IP4 192.168.98.162 s=call c=IN IP4 192.168.98.162 t=0 0 m=audio 65330 RTP/AVP 0 8 9 2 3 18 4 101 a=crypto:1 AES_CM_128_HMAC_SHA1_32 inline:HoxmeMXUcT3hKzt5p+7cJSmHbuKjyU7Z77mpLPes 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 [Mar 2 14:47:28] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 0: INVITE sip:701@192.168.98.120 SIP/2.0 (37) [Mar 2 14:47:28] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.98.162:2051;branch=z9hG4bK-y4bjjhsgfbok;rport (70) [Mar 2 14:47:28] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 2: From: ;tag=qzdpvzvvp7 (46) [Mar 2 14:47:28] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 3: To: (28) [Mar 2 14:47:28] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 4: Call-ID: 3c3becbd7530-2g3pz7higtpm@snom320-0004132475DA (55) [Mar 2 14:47:28] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 5: CSeq: 1 INVITE (14) [Mar 2 14:47:28] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 6: Max-Forwards: 70 (16) [Mar 2 14:47:28] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 7: Contact: ;flow-id=1 (63) [Mar 2 14:47:28] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 8: P-Key-Flags: keys="3" (21) [Mar 2 14:47:28] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 9: User-Agent: snom320/6.5.1 (25) [Mar 2 14:47:28] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 10: Accept: application/sdp (23) [Mar 2 14:47:28] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 11: Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO (88) [Mar 2 14:47:28] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 12: Allow-Events: talk, hold, refer (31) [Mar 2 14:47:28] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 13: Supported: timer, 100rel, replaces, callerid (44) [Mar 2 14:47:28] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 14: Session-Expires: 3600;refresher=uas (35) [Mar 2 14:47:28] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 15: Min-SE: 90 (10) [Mar 2 14:47:28] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 16: Content-Type: application/sdp (29) [Mar 2 14:47:28] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 17: Content-Length: 477 (19) [Mar 2 14:47:28] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 18: (0) [Mar 2 14:47:28] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: v=0 (3) [Mar 2 14:47:28] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: o=root 401972089 401972089 IN IP4 192.168.98.162 (48) [Mar 2 14:47:28] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: s=call (6) [Mar 2 14:47:28] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: c=IN IP4 192.168.98.162 (23) [Mar 2 14:47:28] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: t=0 0 (5) [Mar 2 14:47:28] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: m=audio 65330 RTP/AVP 0 8 9 2 3 18 4 101 (40) [Mar 2 14:47:28] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: a=crypto:1 AES_CM_128_HMAC_SHA1_32 inline:HoxmeMXUcT3hKzt5p+7cJSmHbuKjyU7Z77mpLPes (82) [Mar 2 14:47:28] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: a=rtpmap:0 pcmu/8000 (20) [Mar 2 14:47:28] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: a=rtpmap:8 pcma/8000 (20) [Mar 2 14:47:28] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: a=rtpmap:9 g722/8000 (20) [Mar 2 14:47:28] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: a=rtpmap:2 g726-32/8000 (23) [Mar 2 14:47:28] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: a=rtpmap:3 gsm/8000 (19) [Mar 2 14:47:28] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: a=rtpmap:18 g729/8000 (21) [Mar 2 14:47:28] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: a=rtpmap:4 g723/8000 (20) [Mar 2 14:47:28] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [Mar 2 14:47:28] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: a=fmtp:101 0-16 (15) [Mar 2 14:47:28] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: a=ptime:20 (10) [Mar 2 14:47:28] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: a=encryption:optional (21) [Mar 2 14:47:28] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: a=sendrecv (10) [Mar 2 14:47:28] --- (18 headers 19 lines) --- [Mar 2 14:47:28] DEBUG[20529]: chan_sip.c:3191 sip_alloc: Allocating new SIP dialog for 3c3becbd7530-2g3pz7higtpm@snom320-0004132475DA - INVITE (With RTP) [Mar 2 14:47:28] DEBUG[20529]: chan_sip.c:11296 handle_request: **** Received INVITE (5) - Command in SIP INVITE [Mar 2 14:47:28] DEBUG[20529]: chan_sip.c:1015 parse_sip_options: Begin: parsing SIP "Supported: timer, 100rel, replaces, callerid" [Mar 2 14:47:28] DEBUG[20529]: chan_sip.c:1027 parse_sip_options: Found SIP option: -timer- [Mar 2 14:47:28] DEBUG[20529]: chan_sip.c:1033 parse_sip_options: Matched SIP option: timer [Mar 2 14:47:28] DEBUG[20529]: chan_sip.c:1027 parse_sip_options: Found SIP option: -100rel- [Mar 2 14:47:28] DEBUG[20529]: chan_sip.c:1033 parse_sip_options: Matched SIP option: 100rel [Mar 2 14:47:28] DEBUG[20529]: chan_sip.c:1027 parse_sip_options: Found SIP option: -replaces- [Mar 2 14:47:28] DEBUG[20529]: chan_sip.c:1033 parse_sip_options: Matched SIP option: replaces [Mar 2 14:47:28] DEBUG[20529]: chan_sip.c:1027 parse_sip_options: Found SIP option: -callerid- [Mar 2 14:47:28] DEBUG[20529]: chan_sip.c:1038 parse_sip_options: Found no match for SIP option: callerid (Please file bug report!) [Mar 2 14:47:28] DEBUG[20529]: chan_sip.c:1044 parse_sip_options: * SIP extension value: 7 for call 3c3becbd7530-2g3pz7higtpm@snom320-0004132475DA [Mar 2 14:47:28] Using INVITE request as basis request - 3c3becbd7530-2g3pz7higtpm@snom320-0004132475DA [Mar 2 14:47:28] Sending to 192.168.98.162 : 2051 (NAT) [Mar 2 14:47:28] DEBUG[20529]: chan_sip.c:7282 check_user_full: Setting NAT on RTP to 0 [Mar 2 14:47:28] Reliably Transmitting (no NAT) to 192.168.98.162:2051: SIP/2.0 407 Proxy Authentication Required Via: SIP/2.0/UDP 192.168.98.162:2051;branch=z9hG4bK-y4bjjhsgfbok;received=192.168.98.162;rport=2051 From: ;tag=qzdpvzvvp7 To: ;tag=as4f3e126d Call-ID: 3c3becbd7530-2g3pz7higtpm@snom320-0004132475DA CSeq: 1 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Proxy-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="6ef5f38f" Content-Length: 0 --- [Mar 2 14:47:28] DEBUG[20529]: chan_sip.c:1307 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #7 [Mar 2 14:47:28] Scheduling destruction of call '3c3becbd7530-2g3pz7higtpm@snom320-0004132475DA' in 15000 ms [Mar 2 14:47:28] Found user '1000' [Mar 2 14:47:28] <-- SIP read from 192.168.98.162:2051: ACK sip:701@192.168.98.120 SIP/2.0 Via: SIP/2.0/UDP 192.168.98.162:2051;branch=z9hG4bK-y4bjjhsgfbok;rport From: ;tag=qzdpvzvvp7 To: ;tag=as4f3e126d Call-ID: 3c3becbd7530-2g3pz7higtpm@snom320-0004132475DA CSeq: 1 ACK Max-Forwards: 70 Contact: ;flow-id=1 Content-Length: 0 [Mar 2 14:47:28] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 0: ACK sip:701@192.168.98.120 SIP/2.0 (34) [Mar 2 14:47:28] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.98.162:2051;branch=z9hG4bK-y4bjjhsgfbok;rport (70) [Mar 2 14:47:28] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 2: From: ;tag=qzdpvzvvp7 (46) [Mar 2 14:47:28] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 3: To: ;tag=as4f3e126d (43) [Mar 2 14:47:28] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 4: Call-ID: 3c3becbd7530-2g3pz7higtpm@snom320-0004132475DA (55) [Mar 2 14:47:28] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 5: CSeq: 1 ACK (11) [Mar 2 14:47:28] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 6: Max-Forwards: 70 (16) [Mar 2 14:47:28] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 7: Contact: ;flow-id=1 (63) [Mar 2 14:47:28] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 8: Content-Length: 0 (17) [Mar 2 14:47:28] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 9: (0) [Mar 2 14:47:28] --- (9 headers 0 lines) --- [Mar 2 14:47:28] DEBUG[20529]: chan_sip.c:11296 handle_request: **** Received ACK (6) - Command in SIP ACK [Mar 2 14:47:28] DEBUG[20529]: chan_sip.c:1403 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #7 [Mar 2 14:47:28] DEBUG[20529]: chan_sip.c:1415 __sip_ack: Stopping retransmission on '3c3becbd7530-2g3pz7higtpm@snom320-0004132475DA' of Response 1: Match Found [Mar 2 14:47:28] <-- SIP read from 192.168.98.162:2051: INVITE sip:701@192.168.98.120 SIP/2.0 Via: SIP/2.0/UDP 192.168.98.162:2051;branch=z9hG4bK-hjxtp47ve2b3;rport From: ;tag=qzdpvzvvp7 To: Call-ID: 3c3becbd7530-2g3pz7higtpm@snom320-0004132475DA CSeq: 2 INVITE Max-Forwards: 70 Contact: ;flow-id=1 P-Key-Flags: keys="3" User-Agent: snom320/6.5.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;refresher=uas Min-SE: 90 Proxy-Authorization: Digest username="1000",realm="asterisk",nonce="6ef5f38f",uri="sip:701@192.168.98.120",response="f342fd151d92107b609c2897a58d233a",algorithm=md5 Content-Type: application/sdp Content-Length: 477 v=0 o=root 401972089 401972089 IN IP4 192.168.98.162 s=call c=IN IP4 192.168.98.162 t=0 0 m=audio 65330 RTP/AVP 0 8 9 2 3 18 4 101 a=crypto:1 AES_CM_128_HMAC_SHA1_32 inline:HoxmeMXUcT3hKzt5p+7cJSmHbuKjyU7Z77mpLPes 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 [Mar 2 14:47:28] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 0: INVITE sip:701@192.168.98.120 SIP/2.0 (37) [Mar 2 14:47:28] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.98.162:2051;branch=z9hG4bK-hjxtp47ve2b3;rport (70) [Mar 2 14:47:28] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 2: From: ;tag=qzdpvzvvp7 (46) [Mar 2 14:47:28] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 3: To: (28) [Mar 2 14:47:28] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 4: Call-ID: 3c3becbd7530-2g3pz7higtpm@snom320-0004132475DA (55) [Mar 2 14:47:28] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 5: CSeq: 2 INVITE (14) [Mar 2 14:47:28] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 6: Max-Forwards: 70 (16) [Mar 2 14:47:28] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 7: Contact: ;flow-id=1 (63) [Mar 2 14:47:28] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 8: P-Key-Flags: keys="3" (21) [Mar 2 14:47:28] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 9: User-Agent: snom320/6.5.1 (25) [Mar 2 14:47:28] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 10: Accept: application/sdp (23) [Mar 2 14:47:28] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 11: Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO (88) [Mar 2 14:47:28] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 12: Allow-Events: talk, hold, refer (31) [Mar 2 14:47:28] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 13: Supported: timer, 100rel, replaces, callerid (44) [Mar 2 14:47:28] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 14: Session-Expires: 3600;refresher=uas (35) [Mar 2 14:47:28] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 15: Min-SE: 90 (10) [Mar 2 14:47:28] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 16: Proxy-Authorization: Digest username="1000",realm="asterisk",nonce="6ef5f38f",uri="sip:701@192.168.98.120",response="f342fd151d92107b609c2897a58d233a",algorithm=md5 (164) [Mar 2 14:47:28] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 17: Content-Type: application/sdp (29) [Mar 2 14:47:28] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 18: Content-Length: 477 (19) [Mar 2 14:47:28] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 19: (0) [Mar 2 14:47:28] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: v=0 (3) [Mar 2 14:47:28] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: o=root 401972089 401972089 IN IP4 192.168.98.162 (48) [Mar 2 14:47:28] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: s=call (6) [Mar 2 14:47:28] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: c=IN IP4 192.168.98.162 (23) [Mar 2 14:47:28] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: t=0 0 (5) [Mar 2 14:47:28] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: m=audio 65330 RTP/AVP 0 8 9 2 3 18 4 101 (40) [Mar 2 14:47:28] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: a=crypto:1 AES_CM_128_HMAC_SHA1_32 inline:HoxmeMXUcT3hKzt5p+7cJSmHbuKjyU7Z77mpLPes (82) [Mar 2 14:47:28] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: a=rtpmap:0 pcmu/8000 (20) [Mar 2 14:47:28] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: a=rtpmap:8 pcma/8000 (20) [Mar 2 14:47:28] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: a=rtpmap:9 g722/8000 (20) [Mar 2 14:47:28] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: a=rtpmap:2 g726-32/8000 (23) [Mar 2 14:47:28] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: a=rtpmap:3 gsm/8000 (19) [Mar 2 14:47:28] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: a=rtpmap:18 g729/8000 (21) [Mar 2 14:47:28] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: a=rtpmap:4 g723/8000 (20) [Mar 2 14:47:28] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [Mar 2 14:47:28] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: a=fmtp:101 0-16 (15) [Mar 2 14:47:28] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: a=ptime:20 (10) [Mar 2 14:47:28] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: a=encryption:optional (21) [Mar 2 14:47:28] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: a=sendrecv (10) [Mar 2 14:47:28] --- (19 headers 19 lines) --- [Mar 2 14:47:28] DEBUG[20529]: chan_sip.c:11296 handle_request: **** Received INVITE (5) - Command in SIP INVITE [Mar 2 14:47:28] Using INVITE request as basis request - 3c3becbd7530-2g3pz7higtpm@snom320-0004132475DA [Mar 2 14:47:28] Sending to 192.168.98.162 : 2051 (NAT) [Mar 2 14:47:28] DEBUG[20529]: chan_sip.c:7282 check_user_full: Setting NAT on RTP to 0 [Mar 2 14:47:28] Found user '1000' [Mar 2 14:47:28] Found RTP audio format 0 [Mar 2 14:47:28] Found RTP audio format 8 [Mar 2 14:47:28] Found RTP audio format 9 [Mar 2 14:47:28] Found RTP audio format 2 [Mar 2 14:47:28] Found RTP audio format 3 [Mar 2 14:47:28] Found RTP audio format 18 [Mar 2 14:47:28] Found RTP audio format 4 [Mar 2 14:47:28] Found RTP audio format 101 [Mar 2 14:47:28] Peer audio RTP is at port 192.168.98.162:65330 [Mar 2 14:47:28] DEBUG[20529]: chan_sip.c:3683 process_sdp: Peer audio RTP is at port 192.168.98.162:65330 [Mar 2 14:47:28] Found description format pcmu [Mar 2 14:47:28] Found description format pcma [Mar 2 14:47:28] Found description format g722 [Mar 2 14:47:28] Found description format g726-32 [Mar 2 14:47:28] Found description format gsm [Mar 2 14:47:28] Found description format g729 [Mar 2 14:47:28] Found description format g723 [Mar 2 14:47:28] Found description format telephone-event [Mar 2 14:47:28] Capabilities: us - 0x8000e (gsm|ulaw|alaw|h263), peer - audio=0x11f (g723|gsm|ulaw|alaw|g726|g729)/video=0x0 (nothing), combined - 0xe (gsm|ulaw|alaw) [Mar 2 14:47:28] Non-codec capabilities: us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) [Mar 2 14:47:28] DEBUG[20529]: chan_sip.c:10660 handle_request_invite: Checking SIP call limits for device 1000 [Mar 2 14:47:28] DEBUG[20529]: chan_sip.c:2228 update_call_counter: Updating call counter for incoming call [Mar 2 14:47:28] Looking for 701 in local (domain 192.168.98.120) [Mar 2 14:47:28] DEBUG[20529]: chan_sip.c:6258 build_route: build_route: Contact hop: ;flow-id=1 [Mar 2 14:47:28] list_route: hop: [Mar 2 14:47:28] Transmitting (no NAT) to 192.168.98.162:2051: SIP/2.0 100 Trying Via: SIP/2.0/UDP 192.168.98.162:2051;branch=z9hG4bK-hjxtp47ve2b3;received=192.168.98.162;rport=2051 From: ;tag=qzdpvzvvp7 To: Call-ID: 3c3becbd7530-2g3pz7higtpm@snom320-0004132475DA CSeq: 2 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Contact: Content-Length: 0 --- [Mar 2 14:47:28] DEBUG[20522]: chan_sip.c:11844 sip_devicestate: Checking device state for peer 1000 [Mar 2 14:47:28] DEBUG[20522]: devicestate.c:187 do_state_change: Changing state for SIP/1000 - state 2 (In use) [Mar 2 14:47:28] DEBUG[20571]: pbx.c:1697 pbx_extension_helper: Launching 'ParkedCall' [Mar 2 14:47:28] -- Executing ParkedCall("SIP/1000-081e5908", "701") in new stack [Mar 2 14:47:28] DEBUG[20571]: chan_sip.c:2570 sip_answer: sip_answer(SIP/1000-081e5908) [Mar 2 14:47:28] We're at 192.168.98.120 port 16392 [Mar 2 14:47:28] Adding codec 0x2 (gsm) to SDP [Mar 2 14:47:28] Adding codec 0x4 (ulaw) to SDP [Mar 2 14:47:28] Adding codec 0x8 (alaw) to SDP [Mar 2 14:47:28] Adding non-codec 0x1 (telephone-event) to SDP [Mar 2 14:47:28] Reliably Transmitting (no NAT) to 192.168.98.162:2051: SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.98.162:2051;branch=z9hG4bK-hjxtp47ve2b3;received=192.168.98.162;rport=2051 From: ;tag=qzdpvzvvp7 To: ;tag=as4e509c0c Call-ID: 3c3becbd7530-2g3pz7higtpm@snom320-0004132475DA CSeq: 2 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Contact: Content-Type: application/sdp Content-Length: 267 v=0 o=root 20518 20518 IN IP4 192.168.98.120 s=session c=IN IP4 192.168.98.120 t=0 0 m=audio 16392 RTP/AVP 3 0 8 101 a=rtpmap:3 GSM/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - --- [Mar 2 14:47:28] DEBUG[20571]: chan_sip.c:1307 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #9 [Mar 2 14:47:28] DEBUG[20571]: chan_sip.c:2755 sip_indicate: Bridged channel is back from hold, let's talk! : 3c3becb9222e-0cu1xn1bcocp@snom320-0004132475DA [Mar 2 14:47:28] DEBUG[20571]: channel.c:2414 set_format: Set channel SIP/1000-081e5908 to read format slin [Mar 2 14:47:28] DEBUG[20571]: channel.c:2414 set_format: Set channel SIP/1000-081cfd00 to write format slin [Mar 2 14:47:28] DEBUG[20571]: channel.c:2414 set_format: Set channel SIP/1000-081cfd00 to read format slin [Mar 2 14:47:28] DEBUG[20571]: channel.c:2414 set_format: Set channel SIP/1000-081e5908 to write format slin [Mar 2 14:47:28] -- Channel SIP/1000-081e5908 connected to parked call 701 [Mar 2 14:47:28] WARNING[20571]: channel.c:1608 ast_waitfor_nandfds: Thread -1225049184 Blocking 'SIP/1000-081cfd00', already blocked by thread -1224782944 in procedure ast_waitfor_nandfds [Mar 2 14:47:28] DEBUG[20522]: chan_sip.c:11844 sip_devicestate: Checking device state for peer 1000 [Mar 2 14:47:28] DEBUG[20522]: devicestate.c:187 do_state_change: Changing state for SIP/1000 - state 2 (In use) [Mar 2 14:47:28] DEBUG[20572]: app_queue.c:500 changethread: Device 'SIP/1000' changed to state '2' (In use) but we don't care because they're not a member of any queue. [Mar 2 14:47:28] DEBUG[20573]: app_queue.c:500 changethread: Device 'SIP/1000' changed to state '2' (In use) but we don't care because they're not a member of any queue. [Mar 2 14:47:28] <-- SIP read from 192.168.98.162:2051: ACK sip:701@192.168.98.120 SIP/2.0 Via: SIP/2.0/UDP 192.168.98.162:2051;branch=z9hG4bK-m76e81wwx0fy;rport From: ;tag=qzdpvzvvp7 To: ;tag=as4e509c0c Call-ID: 3c3becbd7530-2g3pz7higtpm@snom320-0004132475DA CSeq: 2 ACK Max-Forwards: 70 Contact: ;flow-id=1 Content-Length: 0 [Mar 2 14:47:28] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 0: ACK sip:701@192.168.98.120 SIP/2.0 (34) [Mar 2 14:47:28] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.98.162:2051;branch=z9hG4bK-m76e81wwx0fy;rport (70) [Mar 2 14:47:28] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 2: From: ;tag=qzdpvzvvp7 (46) [Mar 2 14:47:28] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 3: To: ;tag=as4e509c0c (43) [Mar 2 14:47:28] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 4: Call-ID: 3c3becbd7530-2g3pz7higtpm@snom320-0004132475DA (55) [Mar 2 14:47:28] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 5: CSeq: 2 ACK (11) [Mar 2 14:47:28] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 6: Max-Forwards: 70 (16) [Mar 2 14:47:28] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 7: Contact: ;flow-id=1 (63) [Mar 2 14:47:28] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 8: Content-Length: 0 (17) [Mar 2 14:47:28] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 9: (0) [Mar 2 14:47:28] --- (9 headers 0 lines) --- [Mar 2 14:47:28] DEBUG[20529]: chan_sip.c:11296 handle_request: **** Received ACK (6) - Command in SIP ACK [Mar 2 14:47:28] DEBUG[20529]: chan_sip.c:1403 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #9 [Mar 2 14:47:28] DEBUG[20529]: chan_sip.c:1415 __sip_ack: Stopping retransmission on '3c3becbd7530-2g3pz7higtpm@snom320-0004132475DA' of Response 2: Match Found [Mar 2 14:47:28] DEBUG[20571]: rtp.c:411 ast_rtcp_read: Got RTCP report of 52 bytes [Mar 2 14:47:28] DEBUG[20571]: chan_sip.c:3051 sip_rtp_read: Oooh, format changed to 2 [Mar 2 14:47:28] DEBUG[20571]: channel.c:2414 set_format: Set channel SIP/1000-081e5908 to read format slin [Mar 2 14:47:28] DEBUG[20571]: channel.c:2414 set_format: Set channel SIP/1000-081e5908 to write format slin [Mar 2 14:47:28] DEBUG[20571]: channel.c:2414 set_format: Set channel SIP/1000-081e5908 to read format gsm [Mar 2 14:47:28] DEBUG[20571]: channel.c:2414 set_format: Set channel SIP/1000-081cfd00 to write format gsm [Mar 2 14:47:28] DEBUG[20571]: channel.c:2414 set_format: Set channel SIP/1000-081cfd00 to read format gsm [Mar 2 14:47:28] DEBUG[20571]: channel.c:2414 set_format: Set channel SIP/1000-081e5908 to write format gsm [Mar 2 14:47:33] DEBUG[20571]: rtp.c:411 ast_rtcp_read: Got RTCP report of 52 bytes [Mar 2 14:47:38] DEBUG[20571]: rtp.c:411 ast_rtcp_read: Got RTCP report of 52 bytes [Mar 2 14:47:39] <-- SIP read from 192.168.98.162:2051: INVITE sip:701@192.168.98.120 SIP/2.0 Via: SIP/2.0/UDP 192.168.98.162:2051;branch=z9hG4bK-p7my3k36r4rt;rport From: ;tag=qzdpvzvvp7 To: ;tag=as4e509c0c Call-ID: 3c3becbd7530-2g3pz7higtpm@snom320-0004132475DA CSeq: 3 INVITE Max-Forwards: 70 Contact: ;flow-id=1 P-Key-Flags: keys="3" User-Agent: snom320/6.5.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;refresher=uas Min-SE: 90 Content-Type: application/sdp Content-Length: 470 v=0 o=root 401972089 401972090 IN IP4 192.168.98.162 s=call c=IN IP4 0.0.0.0 t=0 0 m=audio 65330 RTP/AVP 0 8 9 2 3 18 4 101 a=crypto:1 AES_CM_128_HMAC_SHA1_32 inline:HoxmeMXUcT3hKzt5p+7cJSmHbuKjyU7Z77mpLPes 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 [Mar 2 14:47:39] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 0: INVITE sip:701@192.168.98.120 SIP/2.0 (37) [Mar 2 14:47:39] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.98.162:2051;branch=z9hG4bK-p7my3k36r4rt;rport (70) [Mar 2 14:47:39] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 2: From: ;tag=qzdpvzvvp7 (46) [Mar 2 14:47:39] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 3: To: ;tag=as4e509c0c (43) [Mar 2 14:47:39] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 4: Call-ID: 3c3becbd7530-2g3pz7higtpm@snom320-0004132475DA (55) [Mar 2 14:47:39] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 5: CSeq: 3 INVITE (14) [Mar 2 14:47:39] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 6: Max-Forwards: 70 (16) [Mar 2 14:47:39] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 7: Contact: ;flow-id=1 (63) [Mar 2 14:47:39] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 8: P-Key-Flags: keys="3" (21) [Mar 2 14:47:39] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 9: User-Agent: snom320/6.5.1 (25) [Mar 2 14:47:39] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 10: Accept: application/sdp (23) [Mar 2 14:47:39] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 11: Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO (88) [Mar 2 14:47:39] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 12: Allow-Events: talk, hold, refer (31) [Mar 2 14:47:39] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 13: Supported: timer, 100rel, replaces, callerid (44) [Mar 2 14:47:39] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 14: Session-Expires: 3600;refresher=uas (35) [Mar 2 14:47:39] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 15: Min-SE: 90 (10) [Mar 2 14:47:39] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 16: Content-Type: application/sdp (29) [Mar 2 14:47:39] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 17: Content-Length: 470 (19) [Mar 2 14:47:39] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 18: (0) [Mar 2 14:47:39] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: v=0 (3) [Mar 2 14:47:39] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: o=root 401972089 401972090 IN IP4 192.168.98.162 (48) [Mar 2 14:47:39] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: s=call (6) [Mar 2 14:47:39] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: c=IN IP4 0.0.0.0 (16) [Mar 2 14:47:39] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: t=0 0 (5) [Mar 2 14:47:39] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: m=audio 65330 RTP/AVP 0 8 9 2 3 18 4 101 (40) [Mar 2 14:47:39] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: a=crypto:1 AES_CM_128_HMAC_SHA1_32 inline:HoxmeMXUcT3hKzt5p+7cJSmHbuKjyU7Z77mpLPes (82) [Mar 2 14:47:39] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: a=rtpmap:0 pcmu/8000 (20) [Mar 2 14:47:39] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: a=rtpmap:8 pcma/8000 (20) [Mar 2 14:47:39] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: a=rtpmap:9 g722/8000 (20) [Mar 2 14:47:39] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: a=rtpmap:2 g726-32/8000 (23) [Mar 2 14:47:39] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: a=rtpmap:3 gsm/8000 (19) [Mar 2 14:47:39] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: a=rtpmap:18 g729/8000 (21) [Mar 2 14:47:39] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: a=rtpmap:4 g723/8000 (20) [Mar 2 14:47:39] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [Mar 2 14:47:39] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: a=fmtp:101 0-16 (15) [Mar 2 14:47:39] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: a=ptime:20 (10) [Mar 2 14:47:39] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: a=encryption:optional (21) [Mar 2 14:47:39] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: a=sendonly (10) [Mar 2 14:47:39] --- (18 headers 19 lines) --- [Mar 2 14:47:39] DEBUG[20529]: chan_sip.c:11296 handle_request: **** Received INVITE (5) - Command in SIP INVITE [Mar 2 14:47:39] Using INVITE request as basis request - 3c3becbd7530-2g3pz7higtpm@snom320-0004132475DA [Mar 2 14:47:39] Sending to 192.168.98.162 : 2051 (NAT) [Mar 2 14:47:39] Found RTP audio format 0 [Mar 2 14:47:39] Found RTP audio format 8 [Mar 2 14:47:39] Found RTP audio format 9 [Mar 2 14:47:39] Found RTP audio format 2 [Mar 2 14:47:39] Found RTP audio format 3 [Mar 2 14:47:39] Found RTP audio format 18 [Mar 2 14:47:39] Found RTP audio format 4 [Mar 2 14:47:39] Found RTP audio format 101 [Mar 2 14:47:39] Peer audio RTP is at port 0.0.0.0:65330 [Mar 2 14:47:39] DEBUG[20529]: chan_sip.c:3683 process_sdp: Peer audio RTP is at port 0.0.0.0:65330 [Mar 2 14:47:39] Found description format pcmu [Mar 2 14:47:39] Found description format pcma [Mar 2 14:47:39] Found description format g722 [Mar 2 14:47:39] Found description format g726-32 [Mar 2 14:47:39] Found description format gsm [Mar 2 14:47:39] Found description format g729 [Mar 2 14:47:39] Found description format g723 [Mar 2 14:47:39] Found description format telephone-event [Mar 2 14:47:39] Capabilities: us - 0x8000e (gsm|ulaw|alaw|h263), peer - audio=0x11f (g723|gsm|ulaw|alaw|g726|g729)/video=0x0 (nothing), combined - 0xe (gsm|ulaw|alaw) [Mar 2 14:47:39] Non-codec capabilities: us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) [Mar 2 14:47:39] DEBUG[20529]: channel.c:2414 set_format: Set channel SIP/1000-081cfd00 to write format slin [Mar 2 14:47:39] -- Started music on hold, class 'default', on channel 'SIP/1000-081cfd00' [Mar 2 14:47:39] DEBUG[20529]: channel.c:1759 ast_settimeout: Scheduling timer at 160 sample intervals [Mar 2 14:47:39] DEBUG[20529]: chan_sip.c:10704 handle_request_invite: Got a SIP re-invite for call 3c3becbd7530-2g3pz7higtpm@snom320-0004132475DA [Mar 2 14:47:39] We're at 192.168.98.120 port 16392 [Mar 2 14:47:39] Adding codec 0x2 (gsm) to SDP [Mar 2 14:47:39] Adding codec 0x4 (ulaw) to SDP [Mar 2 14:47:39] Adding codec 0x8 (alaw) to SDP [Mar 2 14:47:39] Adding non-codec 0x1 (telephone-event) to SDP [Mar 2 14:47:39] Reliably Transmitting (NAT) to 192.168.98.162:2051: SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.98.162:2051;branch=z9hG4bK-p7my3k36r4rt;received=192.168.98.162;rport=2051 From: ;tag=qzdpvzvvp7 To: ;tag=as4e509c0c Call-ID: 3c3becbd7530-2g3pz7higtpm@snom320-0004132475DA CSeq: 3 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Contact: Content-Type: application/sdp Content-Length: 267 v=0 o=root 20518 20519 IN IP4 192.168.98.120 s=session c=IN IP4 192.168.98.120 t=0 0 m=audio 16392 RTP/AVP 3 0 8 101 a=rtpmap:3 GSM/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - --- [Mar 2 14:47:39] DEBUG[20529]: chan_sip.c:1307 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #10 [Mar 2 14:47:40] <-- SIP read from 192.168.98.162:2051: ACK sip:701@192.168.98.120 SIP/2.0 Via: SIP/2.0/UDP 192.168.98.162:2051;branch=z9hG4bK-sh9pjpyacb11;rport From: ;tag=qzdpvzvvp7 To: ;tag=as4e509c0c Call-ID: 3c3becbd7530-2g3pz7higtpm@snom320-0004132475DA CSeq: 3 ACK Max-Forwards: 70 Contact: ;flow-id=1 Content-Length: 0 [Mar 2 14:47:40] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 0: ACK sip:701@192.168.98.120 SIP/2.0 (34) [Mar 2 14:47:40] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.98.162:2051;branch=z9hG4bK-sh9pjpyacb11;rport (70) [Mar 2 14:47:40] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 2: From: ;tag=qzdpvzvvp7 (46) [Mar 2 14:47:40] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 3: To: ;tag=as4e509c0c (43) [Mar 2 14:47:40] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 4: Call-ID: 3c3becbd7530-2g3pz7higtpm@snom320-0004132475DA (55) [Mar 2 14:47:40] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 5: CSeq: 3 ACK (11) [Mar 2 14:47:40] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 6: Max-Forwards: 70 (16) [Mar 2 14:47:40] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 7: Contact: ;flow-id=1 (63) [Mar 2 14:47:40] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 8: Content-Length: 0 (17) [Mar 2 14:47:40] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 9: (0) [Mar 2 14:47:40] --- (9 headers 0 lines) --- [Mar 2 14:47:40] DEBUG[20529]: chan_sip.c:11296 handle_request: **** Received ACK (6) - Command in SIP ACK [Mar 2 14:47:40] DEBUG[20529]: chan_sip.c:1403 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #10 [Mar 2 14:47:40] DEBUG[20529]: chan_sip.c:1415 __sip_ack: Stopping retransmission on '3c3becbd7530-2g3pz7higtpm@snom320-0004132475DA' of Response 3: Match Found [Mar 2 14:47:40] DEBUG[20571]: rtp.c:411 ast_rtcp_read: Got RTCP report of 52 bytes [Mar 2 14:47:40] <-- SIP read from 192.168.98.162:2051: INVITE sip:701@192.168.98.120 SIP/2.0 Via: SIP/2.0/UDP 192.168.98.162:2051;branch=z9hG4bK-w9cyy27n9tlw;rport From: ;tag=qzdpvzvvp7 To: ;tag=as4e509c0c Call-ID: 3c3becbd7530-2g3pz7higtpm@snom320-0004132475DA CSeq: 4 INVITE Max-Forwards: 70 Contact: ;flow-id=1 P-Key-Flags: keys="3" User-Agent: snom320/6.5.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;refresher=uas Min-SE: 90 Content-Type: application/sdp Content-Length: 477 v=0 o=root 401972089 401972091 IN IP4 192.168.98.162 s=call c=IN IP4 192.168.98.162 t=0 0 m=audio 65330 RTP/AVP 0 8 9 2 3 18 4 101 a=crypto:1 AES_CM_128_HMAC_SHA1_32 inline:HoxmeMXUcT3hKzt5p+7cJSmHbuKjyU7Z77mpLPes 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 [Mar 2 14:47:40] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 0: INVITE sip:701@192.168.98.120 SIP/2.0 (37) [Mar 2 14:47:40] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.98.162:2051;branch=z9hG4bK-w9cyy27n9tlw;rport (70) [Mar 2 14:47:40] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 2: From: ;tag=qzdpvzvvp7 (46) [Mar 2 14:47:40] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 3: To: ;tag=as4e509c0c (43) [Mar 2 14:47:40] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 4: Call-ID: 3c3becbd7530-2g3pz7higtpm@snom320-0004132475DA (55) [Mar 2 14:47:40] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 5: CSeq: 4 INVITE (14) [Mar 2 14:47:40] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 6: Max-Forwards: 70 (16) [Mar 2 14:47:40] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 7: Contact: ;flow-id=1 (63) [Mar 2 14:47:40] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 8: P-Key-Flags: keys="3" (21) [Mar 2 14:47:40] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 9: User-Agent: snom320/6.5.1 (25) [Mar 2 14:47:40] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 10: Accept: application/sdp (23) [Mar 2 14:47:40] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 11: Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO (88) [Mar 2 14:47:40] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 12: Allow-Events: talk, hold, refer (31) [Mar 2 14:47:40] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 13: Supported: timer, 100rel, replaces, callerid (44) [Mar 2 14:47:40] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 14: Session-Expires: 3600;refresher=uas (35) [Mar 2 14:47:40] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 15: Min-SE: 90 (10) [Mar 2 14:47:40] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 16: Content-Type: application/sdp (29) [Mar 2 14:47:40] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 17: Content-Length: 477 (19) [Mar 2 14:47:40] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 18: (0) [Mar 2 14:47:40] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: v=0 (3) [Mar 2 14:47:40] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: o=root 401972089 401972091 IN IP4 192.168.98.162 (48) [Mar 2 14:47:40] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: s=call (6) [Mar 2 14:47:40] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: c=IN IP4 192.168.98.162 (23) [Mar 2 14:47:40] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: t=0 0 (5) [Mar 2 14:47:40] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: m=audio 65330 RTP/AVP 0 8 9 2 3 18 4 101 (40) [Mar 2 14:47:40] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: a=crypto:1 AES_CM_128_HMAC_SHA1_32 inline:HoxmeMXUcT3hKzt5p+7cJSmHbuKjyU7Z77mpLPes (82) [Mar 2 14:47:40] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: a=rtpmap:0 pcmu/8000 (20) [Mar 2 14:47:40] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: a=rtpmap:8 pcma/8000 (20) [Mar 2 14:47:40] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: a=rtpmap:9 g722/8000 (20) [Mar 2 14:47:40] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: a=rtpmap:2 g726-32/8000 (23) [Mar 2 14:47:40] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: a=rtpmap:3 gsm/8000 (19) [Mar 2 14:47:40] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: a=rtpmap:18 g729/8000 (21) [Mar 2 14:47:40] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: a=rtpmap:4 g723/8000 (20) [Mar 2 14:47:40] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [Mar 2 14:47:40] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: a=fmtp:101 0-16 (15) [Mar 2 14:47:40] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: a=ptime:20 (10) [Mar 2 14:47:40] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: a=encryption:optional (21) [Mar 2 14:47:40] DEBUG[20529]: chan_sip.c:3474 parse_request: Line: a=sendrecv (10) [Mar 2 14:47:40] --- (18 headers 19 lines) --- [Mar 2 14:47:40] DEBUG[20529]: chan_sip.c:11296 handle_request: **** Received INVITE (5) - Command in SIP INVITE [Mar 2 14:47:40] Using INVITE request as basis request - 3c3becbd7530-2g3pz7higtpm@snom320-0004132475DA [Mar 2 14:47:40] Sending to 192.168.98.162 : 2051 (NAT) [Mar 2 14:47:40] Found RTP audio format 0 [Mar 2 14:47:40] Found RTP audio format 8 [Mar 2 14:47:40] Found RTP audio format 9 [Mar 2 14:47:40] Found RTP audio format 2 [Mar 2 14:47:40] Found RTP audio format 3 [Mar 2 14:47:40] Found RTP audio format 18 [Mar 2 14:47:40] Found RTP audio format 4 [Mar 2 14:47:40] Found RTP audio format 101 [Mar 2 14:47:40] Peer audio RTP is at port 192.168.98.162:65330 [Mar 2 14:47:40] DEBUG[20529]: chan_sip.c:3683 process_sdp: Peer audio RTP is at port 192.168.98.162:65330 [Mar 2 14:47:40] Found description format pcmu [Mar 2 14:47:40] Found description format pcma [Mar 2 14:47:40] Found description format g722 [Mar 2 14:47:40] Found description format g726-32 [Mar 2 14:47:40] Found description format gsm [Mar 2 14:47:40] Found description format g729 [Mar 2 14:47:40] Found description format g723 [Mar 2 14:47:40] Found description format telephone-event [Mar 2 14:47:40] Capabilities: us - 0x8000e (gsm|ulaw|alaw|h263), peer - audio=0x11f (g723|gsm|ulaw|alaw|g726|g729)/video=0x0 (nothing), combined - 0xe (gsm|ulaw|alaw) [Mar 2 14:47:40] Non-codec capabilities: us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) [Mar 2 14:47:40] DEBUG[20529]: channel.c:2414 set_format: Set channel SIP/1000-081cfd00 to write format gsm [Mar 2 14:47:40] -- Stopped music on hold on SIP/1000-081cfd00 [Mar 2 14:47:40] DEBUG[20529]: channel.c:1759 ast_settimeout: Scheduling timer at 0 sample intervals [Mar 2 14:47:40] DEBUG[20529]: chan_sip.c:10704 handle_request_invite: Got a SIP re-invite for call 3c3becbd7530-2g3pz7higtpm@snom320-0004132475DA [Mar 2 14:47:40] We're at 192.168.98.120 port 16392 [Mar 2 14:47:40] Adding codec 0x2 (gsm) to SDP [Mar 2 14:47:40] Adding codec 0x4 (ulaw) to SDP [Mar 2 14:47:40] Adding codec 0x8 (alaw) to SDP [Mar 2 14:47:40] Adding non-codec 0x1 (telephone-event) to SDP [Mar 2 14:47:40] Reliably Transmitting (NAT) to 192.168.98.162:2051: SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.98.162:2051;branch=z9hG4bK-w9cyy27n9tlw;received=192.168.98.162;rport=2051 From: ;tag=qzdpvzvvp7 To: ;tag=as4e509c0c Call-ID: 3c3becbd7530-2g3pz7higtpm@snom320-0004132475DA CSeq: 4 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Contact: Content-Type: application/sdp Content-Length: 267 v=0 o=root 20518 20520 IN IP4 192.168.98.120 s=session c=IN IP4 192.168.98.120 t=0 0 m=audio 16392 RTP/AVP 3 0 8 101 a=rtpmap:3 GSM/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - --- [Mar 2 14:47:40] DEBUG[20529]: chan_sip.c:1307 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #11 [Mar 2 14:47:40] <-- SIP read from 192.168.98.162:2051: ACK sip:701@192.168.98.120 SIP/2.0 Via: SIP/2.0/UDP 192.168.98.162:2051;branch=z9hG4bK-d83oceh4wqef;rport From: ;tag=qzdpvzvvp7 To: ;tag=as4e509c0c Call-ID: 3c3becbd7530-2g3pz7higtpm@snom320-0004132475DA CSeq: 4 ACK Max-Forwards: 70 Contact: ;flow-id=1 Content-Length: 0 [Mar 2 14:47:40] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 0: ACK sip:701@192.168.98.120 SIP/2.0 (34) [Mar 2 14:47:40] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.98.162:2051;branch=z9hG4bK-d83oceh4wqef;rport (70) [Mar 2 14:47:40] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 2: From: ;tag=qzdpvzvvp7 (46) [Mar 2 14:47:40] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 3: To: ;tag=as4e509c0c (43) [Mar 2 14:47:40] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 4: Call-ID: 3c3becbd7530-2g3pz7higtpm@snom320-0004132475DA (55) [Mar 2 14:47:40] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 5: CSeq: 4 ACK (11) [Mar 2 14:47:40] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 6: Max-Forwards: 70 (16) [Mar 2 14:47:40] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 7: Contact: ;flow-id=1 (63) [Mar 2 14:47:40] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 8: Content-Length: 0 (17) [Mar 2 14:47:40] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 9: (0) [Mar 2 14:47:40] --- (9 headers 0 lines) --- [Mar 2 14:47:40] DEBUG[20529]: chan_sip.c:11296 handle_request: **** Received ACK (6) - Command in SIP ACK [Mar 2 14:47:40] DEBUG[20529]: chan_sip.c:1403 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #11 [Mar 2 14:47:40] DEBUG[20529]: chan_sip.c:1415 __sip_ack: Stopping retransmission on '3c3becbd7530-2g3pz7higtpm@snom320-0004132475DA' of Response 4: Match Found [Mar 2 14:47:40] DEBUG[20571]: rtp.c:411 ast_rtcp_read: Got RTCP report of 52 bytes [Mar 2 14:47:41] DEBUG[20558]: channel.c:1759 ast_settimeout: Scheduling timer at 0 sample intervals [Mar 2 14:47:41] DEBUG[20558]: channel.c:2414 set_format: Set channel SIP/1000-081cfd00 to write format ulaw [Mar 2 14:47:41] DEBUG[20558]: channel.c:2414 set_format: Set channel SIP/1000-081cfd00 to write format gsm [Mar 2 14:47:41] DEBUG[20558]: channel.c:1759 ast_settimeout: Scheduling timer at 160 sample intervals [Mar 2 14:47:41] -- Playing 'digits/0' (language 'en') [Mar 2 14:47:42] <-- SIP read from 192.168.98.162:2051: BYE sip:701@192.168.98.120 SIP/2.0 Via: SIP/2.0/UDP 192.168.98.162:2051;branch=z9hG4bK-7fq5odtksb9o;rport From: ;tag=qzdpvzvvp7 To: ;tag=as4e509c0c Call-ID: 3c3becbd7530-2g3pz7higtpm@snom320-0004132475DA CSeq: 5 BYE Max-Forwards: 70 Contact: ;flow-id=1 User-Agent: snom320/6.5.1 RTP-RxStat: Total_Rx_Pkts=0,Rx_Pkts=0,Rx_Pkts_Lost=1,Remote_Rx_Pkts_Lost=0 RTP-TxStat: Total_Tx_Pkts=588,Tx_Pkts=41,Remote_Tx_Pkts=0 Content-Length: 0 [Mar 2 14:47:42] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 0: BYE sip:701@192.168.98.120 SIP/2.0 (34) [Mar 2 14:47:42] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.98.162:2051;branch=z9hG4bK-7fq5odtksb9o;rport (70) [Mar 2 14:47:42] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 2: From: ;tag=qzdpvzvvp7 (46) [Mar 2 14:47:42] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 3: To: ;tag=as4e509c0c (43) [Mar 2 14:47:42] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 4: Call-ID: 3c3becbd7530-2g3pz7higtpm@snom320-0004132475DA (55) [Mar 2 14:47:42] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 5: CSeq: 5 BYE (11) [Mar 2 14:47:42] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 6: Max-Forwards: 70 (16) [Mar 2 14:47:42] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 7: Contact: ;flow-id=1 (63) [Mar 2 14:47:42] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 8: User-Agent: snom320/6.5.1 (25) [Mar 2 14:47:42] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 9: RTP-RxStat: Total_Rx_Pkts=0,Rx_Pkts=0,Rx_Pkts_Lost=1,Remote_Rx_Pkts_Lost=0 (74) [Mar 2 14:47:42] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 10: RTP-TxStat: Total_Tx_Pkts=588,Tx_Pkts=41,Remote_Tx_Pkts=0 (57) [Mar 2 14:47:42] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 11: Content-Length: 0 (17) [Mar 2 14:47:42] DEBUG[20529]: chan_sip.c:3442 parse_request: Header 12: (0) [Mar 2 14:47:42] --- (12 headers 0 lines) --- [Mar 2 14:47:42] DEBUG[20529]: chan_sip.c:11296 handle_request: **** Received BYE (8) - Command in SIP BYE [Mar 2 14:47:42] Sending to 192.168.98.162 : 2051 (NAT) [Mar 2 14:47:42] DEBUG[20529]: chan_sip.c:10949 handle_request_bye: Received bye, issuing owner hangup [Mar 2 14:47:42] Transmitting (NAT) to 192.168.98.162:2051: SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.98.162:2051;branch=z9hG4bK-7fq5odtksb9o;received=192.168.98.162;rport=2051 From: ;tag=qzdpvzvvp7 To: ;tag=as4e509c0c Call-ID: 3c3becbd7530-2g3pz7higtpm@snom320-0004132475DA CSeq: 5 BYE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Contact: Content-Length: 0 --- [Mar 2 14:47:42] DEBUG[20571]: channel.c:3386 ast_generic_bridge: Didn't get a frame from channel: SIP/1000-081e5908 [Mar 2 14:47:42] DEBUG[20571]: channel.c:3675 ast_channel_bridge: Bridge stops bridging channels SIP/1000-081e5908 and SIP/1000-081cfd00 [Mar 2 14:47:42] DEBUG[20571]: channel.c:1759 ast_settimeout: Scheduling timer at 0 sample intervals [Mar 2 14:47:42] DEBUG[20571]: pbx.c:1542 pbx_substitute_variables_helper_full: Function result is '1000' [Mar 2 14:47:42] DEBUG[20571]: pbx.c:1542 pbx_substitute_variables_helper_full: Function result is '1000' [Mar 2 14:47:42] DEBUG[20571]: pbx.c:1542 pbx_substitute_variables_helper_full: Function result is '700' [Mar 2 14:47:42] DEBUG[20571]: pbx.c:1542 pbx_substitute_variables_helper_full: Function result is 'local' [Mar 2 14:47:42] DEBUG[20571]: pbx.c:1542 pbx_substitute_variables_helper_full: Function result is 'SIP/1000-081cfd00' [Mar 2 14:47:42] DEBUG[20571]: pbx.c:1542 pbx_substitute_variables_helper_full: Function result is '(null)' [Mar 2 14:47:42] DEBUG[20571]: pbx.c:1542 pbx_substitute_variables_helper_full: Function result is 'Park' [Mar 2 14:47:42] DEBUG[20571]: pbx.c:1542 pbx_substitute_variables_helper_full: Function result is '(null)' [Mar 2 14:47:42] DEBUG[20571]: pbx.c:1542 pbx_substitute_variables_helper_full: Function result is '2007-03-02 14:47:23' [Mar 2 14:47:42] DEBUG[20571]: pbx.c:1542 pbx_substitute_variables_helper_full: Function result is '2007-03-02 14:47:23' [Mar 2 14:47:42] DEBUG[20571]: pbx.c:1542 pbx_substitute_variables_helper_full: Function result is '2007-03-02 14:47:42' [Mar 2 14:47:42] DEBUG[20571]: pbx.c:1542 pbx_substitute_variables_helper_full: Function result is '19' [Mar 2 14:47:42] DEBUG[20571]: pbx.c:1542 pbx_substitute_variables_helper_full: Function result is '19' [Mar 2 14:47:42] DEBUG[20571]: pbx.c:1542 pbx_substitute_variables_helper_full: Function result is 'ANSWERED' [Mar 2 14:47:42] DEBUG[20571]: pbx.c:1542 pbx_substitute_variables_helper_full: Function result is 'DOCUMENTATION' [Mar 2 14:47:42] DEBUG[20571]: pbx.c:1542 pbx_substitute_variables_helper_full: Function result is '(null)' [Mar 2 14:47:42] DEBUG[20571]: pbx.c:1542 pbx_substitute_variables_helper_full: Function result is '1172868443.0' [Mar 2 14:47:42] DEBUG[20571]: pbx.c:1542 pbx_substitute_variables_helper_full: Function result is '(null)' [Mar 2 14:47:42] DEBUG[20571]: channel.c:1371 ast_hangup: Hanging up channel 'SIP/1000-081cfd00' [Mar 2 14:47:42] DEBUG[20571]: chan_sip.c:2440 sip_hangup: Hangup call SIP/1000-081cfd00, SIP callid 3c3becb9222e-0cu1xn1bcocp@snom320-0004132475DA) [Mar 2 14:47:42] DEBUG[20571]: chan_sip.c:2448 sip_hangup: update_call_counter(1000) - decrement call limit counter [Mar 2 14:47:42] DEBUG[20571]: chan_sip.c:2228 update_call_counter: Updating call counter for incoming call [Mar 2 14:47:42] Scheduling destruction of call '3c3becb9222e-0cu1xn1bcocp@snom320-0004132475DA' in 32000 ms [Mar 2 14:47:42] set_destination: Parsing for address/port to send to [Mar 2 14:47:42] set_destination: set destination to 192.168.98.162, port 2051 [Mar 2 14:47:42] Reliably Transmitting (NAT) to 192.168.98.162:2051: BYE sip:1000@192.168.98.162:2051 SIP/2.0 Via: SIP/2.0/UDP 192.168.98.120:5060;branch=z9hG4bK37e43e41;rport From: ;tag=as6f172031 To: ;tag=kjpbj07q55 Call-ID: 3c3becb9222e-0cu1xn1bcocp@snom320-0004132475DA CSeq: 102 BYE User-Agent: Asterisk PBX Max-Forwards: 70 Content-Length: 0 --- [Mar 2 14:47:42] DEBUG[20571]: chan_sip.c:1307 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #13 [Mar 2 14:47:42] WARNING[20571]: channel.c:933 ast_channel_free: PBX may not have been terminated properly on 'SIP/1000-081cfd00' [Mar 2 14:47:42] DEBUG[20571]: pbx.c:2336 __ast_pbx_run: Spawn extension (local,701,1) exited non-zero on 'SIP/1000-081e5908' [Mar 2 14:47:42] == Spawn extension (local, 701, 1) exited non-zero on 'SIP/1000-081e5908' [Mar 2 14:47:42] DEBUG[20571]: pbx.c:1542 pbx_substitute_variables_helper_full: Function result is '1000' [Mar 2 14:47:42] DEBUG[20571]: pbx.c:1542 pbx_substitute_variables_helper_full: Function result is '1000' [Mar 2 14:47:42] DEBUG[20571]: pbx.c:1542 pbx_substitute_variables_helper_full: Function result is '701' [Mar 2 14:47:42] DEBUG[20571]: pbx.c:1542 pbx_substitute_variables_helper_full: Function result is 'local' [Mar 2 14:47:42] DEBUG[20571]: pbx.c:1542 pbx_substitute_variables_helper_full: Function result is 'SIP/1000-081e5908' [Mar 2 14:47:42] DEBUG[20571]: pbx.c:1542 pbx_substitute_variables_helper_full: Function result is '(null)' [Mar 2 14:47:42] DEBUG[20571]: pbx.c:1542 pbx_substitute_variables_helper_full: Function result is 'ParkedCall' [Mar 2 14:47:42] DEBUG[20571]: pbx.c:1542 pbx_substitute_variables_helper_full: Function result is '701' [Mar 2 14:47:42] DEBUG[20571]: pbx.c:1542 pbx_substitute_variables_helper_full: Function result is '2007-03-02 14:47:28' [Mar 2 14:47:42] DEBUG[20571]: pbx.c:1542 pbx_substitute_variables_helper_full: Function result is '2007-03-02 14:47:28' [Mar 2 14:47:42] DEBUG[20571]: pbx.c:1542 pbx_substitute_variables_helper_full: Function result is '2007-03-02 14:47:42' [Mar 2 14:47:42] DEBUG[20571]: pbx.c:1542 pbx_substitute_variables_helper_full: Function result is '14' [Mar 2 14:47:42] DEBUG[20571]: pbx.c:1542 pbx_substitute_variables_helper_full: Function result is '14' [Mar 2 14:47:42] DEBUG[20571]: pbx.c:1542 pbx_substitute_variables_helper_full: Function result is 'ANSWERED' [Mar 2 14:47:42] DEBUG[20571]: pbx.c:1542 pbx_substitute_variables_helper_full: Function result is 'DOCUMENTATION' [Mar 2 14:47:42] DEBUG[20571]: pbx.c:1542 pbx_substitute_variables_helper_full: Function result is '(null)' [Mar 2 14:47:42] DEBUG[20571]: pbx.c:1542 pbx_substitute_variables_helper_full: Function result is '1172868448.1' [Mar 2 14:47:42] DEBUG[20571]: pbx.c:1542 pbx_substitute_variables_helper_full: Function result is '(null)' [Mar 2 14:47:42] DEBUG[20571]: channel.c:1371 ast_hangup: Hanging up channel 'SIP/1000-081e5908' [Mar 2 14:47:42] DEBUG[20571]: chan_sip.c:2440 sip_hangup: Hangup call SIP/1000-081e5908, SIP callid 3c3becbd7530-2g3pz7higtpm@snom320-0004132475DA) [Mar 2 14:47:42] DEBUG[20571]: chan_sip.c:2448 sip_hangup: update_call_counter(1000) - decrement call limit counter [Mar 2 14:47:42] DEBUG[20571]: chan_sip.c:2228 update_call_counter: Updating call counter for incoming call [Mar 2 14:47:42] DEBUG[20522]: chan_sip.c:11844 sip_devicestate: Checking device state for peer 1000 [Mar 2 14:47:42] DEBUG[20522]: devicestate.c:187 do_state_change: Changing state for SIP/1000 - state 1 (Not in use) [Mar 2 14:47:42] DEBUG[20522]: chan_sip.c:11844 sip_devicestate: Checking device state for peer 1000 [Mar 2 14:47:42] DEBUG[20522]: devicestate.c:187 do_state_change: Changing state for SIP/1000 - state 1 (Not in use) [Mar 2 14:47:42] DEBUG[20604]: app_queue.c:500 changethread: Device 'SIP/1000' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Mar 2 14:47:42] DEBUG[20605]: app_queue.c:500 changethread: Device 'SIP/1000' changed to state '1' (Not in use) but we don't care because they're not a member of any queue.