*CLI> [Apr 5 17:35:09] DEBUG[3742]: chan_sip.c:4310 sip_alloc: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP) [Apr 5 17:35:09] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 0: OPTIONS sip:103@192.168.4.109:2051;line=0cl0sm4g SIP/2.0 (56) [Apr 5 17:35:09] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.4.14:5060;branch=z9hG4bK5f77ed2a;rport (63) [Apr 5 17:35:09] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 2: From: "asterisk" ;tag=as3bdf7f28 (59) [Apr 5 17:35:09] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 3: To: (46) [Apr 5 17:35:09] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 4: Contact: (36) [Apr 5 17:35:09] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 5: Call-ID: 47a101ad52b1336125a7a2b225f54d2b@192.168.4.14 (54) [Apr 5 17:35:09] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 6: CSeq: 102 OPTIONS (17) [Apr 5 17:35:09] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 7: User-Agent: Asterisk PBX (24) [Apr 5 17:35:09] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 8: Max-Forwards: 70 (16) [Apr 5 17:35:09] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 9: Date: Thu, 05 Apr 2007 15:35:09 GMT (35) [Apr 5 17:35:09] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 10: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) [Apr 5 17:35:09] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 11: Supported: replaces (19) [Apr 5 17:35:09] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 12: Content-Length: 0 (17) [Apr 5 17:35:09] Reliably Transmitting (NAT) to 192.168.4.109:2051: OPTIONS sip:103@192.168.4.109:2051;line=0cl0sm4g SIP/2.0 Via: SIP/2.0/UDP 192.168.4.14:5060;branch=z9hG4bK5f77ed2a;rport From: "asterisk" ;tag=as3bdf7f28 To: Contact: Call-ID: 47a101ad52b1336125a7a2b225f54d2b@192.168.4.14 CSeq: 102 OPTIONS User-Agent: Asterisk PBX Max-Forwards: 70 Date: Thu, 05 Apr 2007 15:35:09 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Content-Length: 0 --- [Apr 5 17:35:09] DEBUG[3742]: chan_sip.c:1975 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #24 [Apr 5 17:35:09] <--- SIP read from 192.168.4.109:2051 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.4.14:5060;branch=z9hG4bK5f77ed2a;rport=5060 From: "asterisk" ;tag=as3bdf7f28 To: Call-ID: 47a101ad52b1336125a7a2b225f54d2b@192.168.4.14 CSeq: 102 OPTIONS Contact: ;flow-id=1 User-Agent: snom360/6.5.8 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 <-------------> [Apr 5 17:35:09] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 0: SIP/2.0 200 OK (14) [Apr 5 17:35:09] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.4.14:5060;branch=z9hG4bK5f77ed2a;rport=5060 (68) [Apr 5 17:35:09] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 2: From: "asterisk" ;tag=as3bdf7f28 (59) [Apr 5 17:35:09] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 3: To: (46) [Apr 5 17:35:09] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 4: Call-ID: 47a101ad52b1336125a7a2b225f54d2b@192.168.4.14 (54) [Apr 5 17:35:09] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 5: CSeq: 102 OPTIONS (17) [Apr 5 17:35:09] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 6: Contact: ;flow-id=1 (69) [Apr 5 17:35:09] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 7: User-Agent: snom360/6.5.8 (25) [Apr 5 17:35:09] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 8: Accept-Language: en (19) [Apr 5 17:35:09] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 9: Accept: application/sdp (23) [Apr 5 17:35:09] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 10: Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO (88) [Apr 5 17:35:09] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 11: Allow-Events: talk, hold, refer (31) [Apr 5 17:35:09] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 12: Supported: timer, 100rel, replaces, callerid (44) [Apr 5 17:35:09] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 13: Content-Length: 0 (17) [Apr 5 17:35:09] --- (14 headers 0 lines) --- [Apr 5 17:35:09] DEBUG[3742]: chan_sip.c:2079 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #24 [Apr 5 17:35:09] DEBUG[3742]: chan_sip.c:2089 __sip_ack: Stopping retransmission on '47a101ad52b1336125a7a2b225f54d2b@192.168.4.14' of Request 102: Match Not Found [Apr 5 17:35:09] Really destroying SIP dialog '47a101ad52b1336125a7a2b225f54d2b@192.168.4.14' Method: OPTIONS [Apr 5 17:35:09] DEBUG[3742]: chan_sip.c:4310 sip_alloc: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP) [Apr 5 17:35:09] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 0: OPTIONS sip:101@192.168.4.11:5060 SIP/2.0 (41) [Apr 5 17:35:09] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.4.14:5060;branch=z9hG4bK4242b263;rport (63) [Apr 5 17:35:09] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 2: From: "asterisk" ;tag=as19cf852f (59) [Apr 5 17:35:09] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 3: To: (31) [Apr 5 17:35:09] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 4: Contact: (36) [Apr 5 17:35:09] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 5: Call-ID: 5caee6373e80c41601b1dd1050880340@192.168.4.14 (54) [Apr 5 17:35:09] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 6: CSeq: 102 OPTIONS (17) [Apr 5 17:35:09] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 7: User-Agent: Asterisk PBX (24) [Apr 5 17:35:09] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 8: Max-Forwards: 70 (16) [Apr 5 17:35:09] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 9: Date: Thu, 05 Apr 2007 15:35:09 GMT (35) [Apr 5 17:35:09] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 10: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) [Apr 5 17:35:09] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 11: Supported: replaces (19) [Apr 5 17:35:09] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 12: Content-Length: 0 (17) [Apr 5 17:35:09] Reliably Transmitting (NAT) to 192.168.4.11:5060: OPTIONS sip:101@192.168.4.11:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.4.14:5060;branch=z9hG4bK4242b263;rport From: "asterisk" ;tag=as19cf852f To: Contact: Call-ID: 5caee6373e80c41601b1dd1050880340@192.168.4.14 CSeq: 102 OPTIONS User-Agent: Asterisk PBX Max-Forwards: 70 Date: Thu, 05 Apr 2007 15:35:09 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Content-Length: 0 --- [Apr 5 17:35:09] DEBUG[3742]: chan_sip.c:1975 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #27 [Apr 5 17:35:09] <--- SIP read from 192.168.4.11:5060 ---> SIP/2.0 405 Method Not Allowed Via: SIP/2.0/UDP 192.168.4.14:5060;rport=5060;received=192.168.4.14;branch=z9hG4bK4242b263 Content-Length: 0 Allow: INVITE, ACK, CANCEL, BYE, REFER, NOTIFY Call-ID: 5caee6373e80c41601b1dd1050880340@192.168.4.14 CSeq: 102 OPTIONS From: "asterisk";tag=as19cf852f Server: SJphone/1.60.289a (SJ Labs) To: "unknown" <-------------> [Apr 5 17:35:09] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 0: SIP/2.0 405 Method Not Allowed (30) [Apr 5 17:35:09] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.4.14:5060;rport=5060;received=192.168.4.14;branch=z9hG4bK4242b263 (90) [Apr 5 17:35:09] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 2: Content-Length: 0 (17) [Apr 5 17:35:09] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 3: Allow: INVITE, ACK, CANCEL, BYE, REFER, NOTIFY (46) [Apr 5 17:35:09] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 4: Call-ID: 5caee6373e80c41601b1dd1050880340@192.168.4.14 (54) [Apr 5 17:35:09] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 5: CSeq: 102 OPTIONS (17) [Apr 5 17:35:09] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 6: From: "asterisk";tag=as19cf852f (58) [Apr 5 17:35:09] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 7: Server: SJphone/1.60.289a (SJ Labs) (35) [Apr 5 17:35:09] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 8: To: "unknown" (40) [Apr 5 17:35:09] --- (9 headers 0 lines) --- [Apr 5 17:35:09] DEBUG[3742]: chan_sip.c:2079 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #27 [Apr 5 17:35:09] DEBUG[3742]: chan_sip.c:2089 __sip_ack: Stopping retransmission on '5caee6373e80c41601b1dd1050880340@192.168.4.14' of Request 102: Match Not Found [Apr 5 17:35:09] Really destroying SIP dialog '5caee6373e80c41601b1dd1050880340@192.168.4.14' Method: OPTIONS [Apr 5 17:35:09] DEBUG[3742]: chan_sip.c:4310 sip_alloc: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP) [Apr 5 17:35:09] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 0: OPTIONS sip:102@192.168.4.104:5060;line=9l1gd4rz SIP/2.0 (56) [Apr 5 17:35:09] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.4.14:5060;branch=z9hG4bK70ed5668;rport (63) [Apr 5 17:35:09] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 2: From: "asterisk" ;tag=as4a66e83e (59) [Apr 5 17:35:09] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 3: To: (46) [Apr 5 17:35:09] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 4: Contact: (36) [Apr 5 17:35:09] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 5: Call-ID: 7a4423b03125b6c770c80c3f3328ad32@192.168.4.14 (54) [Apr 5 17:35:09] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 6: CSeq: 102 OPTIONS (17) [Apr 5 17:35:09] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 7: User-Agent: Asterisk PBX (24) [Apr 5 17:35:09] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 8: Max-Forwards: 70 (16) [Apr 5 17:35:09] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 9: Date: Thu, 05 Apr 2007 15:35:09 GMT (35) [Apr 5 17:35:09] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 10: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) [Apr 5 17:35:09] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 11: Supported: replaces (19) [Apr 5 17:35:09] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 12: Content-Length: 0 (17) [Apr 5 17:35:09] Reliably Transmitting (NAT) to 192.168.4.104:5060: OPTIONS sip:102@192.168.4.104:5060;line=9l1gd4rz SIP/2.0 Via: SIP/2.0/UDP 192.168.4.14:5060;branch=z9hG4bK70ed5668;rport From: "asterisk" ;tag=as4a66e83e To: Contact: Call-ID: 7a4423b03125b6c770c80c3f3328ad32@192.168.4.14 CSeq: 102 OPTIONS User-Agent: Asterisk PBX Max-Forwards: 70 Date: Thu, 05 Apr 2007 15:35:09 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Content-Length: 0 --- [Apr 5 17:35:09] DEBUG[3742]: chan_sip.c:1975 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #30 [Apr 5 17:35:09] <--- SIP read from 192.168.4.104:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.4.14:5060;branch=z9hG4bK70ed5668;rport=5060 From: "asterisk" ;tag=as4a66e83e To: Call-ID: 7a4423b03125b6c770c80c3f3328ad32@192.168.4.14 CSeq: 102 OPTIONS Contact: User-Agent: snom220-3.56z 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 Content-Length: 0 <-------------> [Apr 5 17:35:09] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 0: SIP/2.0 200 OK (14) [Apr 5 17:35:09] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.4.14:5060;branch=z9hG4bK70ed5668;rport=5060 (68) [Apr 5 17:35:09] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 2: From: "asterisk" ;tag=as4a66e83e (59) [Apr 5 17:35:09] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 3: To: (46) [Apr 5 17:35:09] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 4: Call-ID: 7a4423b03125b6c770c80c3f3328ad32@192.168.4.14 (54) [Apr 5 17:35:09] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 5: CSeq: 102 OPTIONS (17) [Apr 5 17:35:09] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 6: Contact: (51) [Apr 5 17:35:09] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 7: User-Agent: snom220-3.56z (25) [Apr 5 17:35:09] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 8: Accept-Language: en (19) [Apr 5 17:35:09] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 9: Accept: application/sdp (23) [Apr 5 17:35:09] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 10: Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO (88) [Apr 5 17:35:09] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 11: Allow-Events: talk, hold, refer (31) [Apr 5 17:35:09] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 12: Supported: timer, 100rel, replaces (34) [Apr 5 17:35:09] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 13: Content-Length: 0 (17) [Apr 5 17:35:09] --- (14 headers 0 lines) --- [Apr 5 17:35:09] DEBUG[3742]: chan_sip.c:2079 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #30 [Apr 5 17:35:09] DEBUG[3742]: chan_sip.c:2089 __sip_ack: Stopping retransmission on '7a4423b03125b6c770c80c3f3328ad32@192.168.4.14' of Request 102: Match Not Found [Apr 5 17:35:09] Really destroying SIP dialog '7a4423b03125b6c770c80c3f3328ad32@192.168.4.14' Method: OPTIONS [Apr 5 17:35:10] DEBUG[3742]: chan_sip.c:2010 __sip_autodestruct: Auto destroying SIP dialog 'CE64C4D1-4737-4E96-B31D-48FB8E6FBC49@192.168.4.11' [Apr 5 17:35:10] DEBUG[3742]: chan_sip.c:3109 sip_destroy: Destroying SIP dialog CE64C4D1-4737-4E96-B31D-48FB8E6FBC49@192.168.4.11 [Apr 5 17:35:10] Really destroying SIP dialog 'CE64C4D1-4737-4E96-B31D-48FB8E6FBC49@192.168.4.11' Method: OPTIONS [Apr 5 17:35:11] <--- SIP read from 192.168.4.11:5060 ---> INVITE sip:103@192.168.4.14:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.4.11;rport;branch=z9hG4bKc0a8040b0000001a4615172100006b8d00000008 Content-Length: 337 Contact: Call-ID: E481A37A-80BD-45DC-90AB-A3A3450A476F@192.168.4.11 Content-Type: application/sdp CSeq: 1 INVITE From: "unknown";tag=3492175015678 Max-Forwards: 70 To: User-Agent: SJphone/1.60.289a (SJ Labs) v=0 o=- 3384776097 3384776097 IN IP4 192.168.4.11 s=SJphone c=IN IP4 192.168.4.11 t=0 0 a=direction:active m=audio 49152 RTP/AVP 3 97 98 8 0 101 a=rtpmap:3 GSM/8000 a=rtpmap:97 iLBC/8000 a=rtpmap:98 iLBC/8000 a=fmtp:98 mode=20 a=rtpmap:8 PCMA/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-11,16 <-------------> [Apr 5 17:35:11] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 0: INVITE sip:103@192.168.4.14:5060 SIP/2.0 (40) [Apr 5 17:35:11] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.4.11;rport;branch=z9hG4bKc0a8040b0000001a4615172100006b8d00000008 (90) [Apr 5 17:35:11] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 2: Content-Length: 337 (19) [Apr 5 17:35:11] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 3: Contact: (36) [Apr 5 17:35:11] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 4: Call-ID: E481A37A-80BD-45DC-90AB-A3A3450A476F@192.168.4.11 (58) [Apr 5 17:35:11] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 5: Content-Type: application/sdp (29) [Apr 5 17:35:11] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 6: CSeq: 1 INVITE (14) [Apr 5 17:35:11] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 7: From: "unknown";tag=3492175015678 (60) [Apr 5 17:35:11] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 8: Max-Forwards: 70 (16) [Apr 5 17:35:11] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 9: To: (31) [Apr 5 17:35:11] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 10: User-Agent: SJphone/1.60.289a (SJ Labs) (39) [Apr 5 17:35:11] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 11: (0) [Apr 5 17:35:11] DEBUG[3742]: chan_sip.c:4605 parse_request: Line: v=0 (3) [Apr 5 17:35:11] DEBUG[3742]: chan_sip.c:4605 parse_request: Line: o=- 3384776097 3384776097 IN IP4 192.168.4.11 (45) [Apr 5 17:35:11] DEBUG[3742]: chan_sip.c:4605 parse_request: Line: s=SJphone (9) [Apr 5 17:35:11] DEBUG[3742]: chan_sip.c:4605 parse_request: Line: c=IN IP4 192.168.4.11 (21) [Apr 5 17:35:11] DEBUG[3742]: chan_sip.c:4605 parse_request: Line: t=0 0 (5) [Apr 5 17:35:11] DEBUG[3742]: chan_sip.c:4605 parse_request: Line: a=direction:active (18) [Apr 5 17:35:11] DEBUG[3742]: chan_sip.c:4605 parse_request: Line: m=audio 49152 RTP/AVP 3 97 98 8 0 101 (37) [Apr 5 17:35:11] DEBUG[3742]: chan_sip.c:4605 parse_request: Line: a=rtpmap:3 GSM/8000 (19) [Apr 5 17:35:11] DEBUG[3742]: chan_sip.c:4605 parse_request: Line: a=rtpmap:97 iLBC/8000 (21) [Apr 5 17:35:11] DEBUG[3742]: chan_sip.c:4605 parse_request: Line: a=rtpmap:98 iLBC/8000 (21) [Apr 5 17:35:11] DEBUG[3742]: chan_sip.c:4605 parse_request: Line: a=fmtp:98 mode=20 (17) [Apr 5 17:35:11] DEBUG[3742]: chan_sip.c:4605 parse_request: Line: a=rtpmap:8 PCMA/8000 (20) [Apr 5 17:35:11] DEBUG[3742]: chan_sip.c:4605 parse_request: Line: a=rtpmap:0 PCMU/8000 (20) [Apr 5 17:35:11] DEBUG[3742]: chan_sip.c:4605 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [Apr 5 17:35:11] --- (11 headers 15 lines) --- [Apr 5 17:35:11] DEBUG[3742]: chan_sip.c:2575 do_setnat: Setting NAT on RTP to Off [Apr 5 17:35:11] DEBUG[3742]: chan_sip.c:2580 do_setnat: Setting NAT on VRTP to Off [Apr 5 17:35:11] DEBUG[3742]: chan_sip.c:2585 do_setnat: Setting NAT on UDPTL to Off [Apr 5 17:35:11] DEBUG[3742]: chan_sip.c:4310 sip_alloc: Allocating new SIP dialog for E481A37A-80BD-45DC-90AB-A3A3450A476F@192.168.4.11 - INVITE (With RTP) [Apr 5 17:35:11] DEBUG[3742]: chan_sip.c:14633 handle_request: **** Received INVITE (5) - Command in SIP INVITE [Apr 5 17:35:11] Sending to 192.168.4.11 : 5060 (NAT) [Apr 5 17:35:11] Using INVITE request as basis request - E481A37A-80BD-45DC-90AB-A3A3450A476F@192.168.4.11 [Apr 5 17:35:11] Found peer '101' [Apr 5 17:35:11] DEBUG[3742]: chan_sip.c:2575 do_setnat: Setting NAT on RTP to On [Apr 5 17:35:11] DEBUG[3742]: chan_sip.c:2580 do_setnat: Setting NAT on VRTP to On [Apr 5 17:35:11] DEBUG[3742]: chan_sip.c:2585 do_setnat: Setting NAT on UDPTL to On [Apr 5 17:35:11] <--- Reliably Transmitting (NAT) to 192.168.4.11:5060 ---> SIP/2.0 407 Proxy Authentication Required Via: SIP/2.0/UDP 192.168.4.11;branch=z9hG4bKc0a8040b0000001a4615172100006b8d00000008;received=192.168.4.11;rport=5060 From: "unknown";tag=3492175015678 To: ;tag=as3f26c88b Call-ID: E481A37A-80BD-45DC-90AB-A3A3450A476F@192.168.4.11 CSeq: 1 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Proxy-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="76e9b130" Content-Length: 0 <------------> [Apr 5 17:35:11] DEBUG[3742]: chan_sip.c:1975 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #33 [Apr 5 17:35:11] Scheduling destruction of SIP dialog 'E481A37A-80BD-45DC-90AB-A3A3450A476F@192.168.4.11' in 320 ms (Method: INVITE) [Apr 5 17:35:11] <--- SIP read from 192.168.4.11:5060 ---> ACK sip:103@192.168.4.14:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.4.11;rport;branch=z9hG4bKc0a8040b0000001a4615172100006b8d00000008 Content-Length: 0 Call-ID: E481A37A-80BD-45DC-90AB-A3A3450A476F@192.168.4.11 CSeq: 1 ACK From: "unknown";tag=3492175015678 Max-Forwards: 70 To: ;tag=as3f26c88b User-Agent: SJphone/1.60.289a (SJ Labs) <-------------> [Apr 5 17:35:11] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 0: ACK sip:103@192.168.4.14:5060 SIP/2.0 (37) [Apr 5 17:35:11] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.4.11;rport;branch=z9hG4bKc0a8040b0000001a4615172100006b8d00000008 (90) [Apr 5 17:35:11] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 2: Content-Length: 0 (17) [Apr 5 17:35:11] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 3: Call-ID: E481A37A-80BD-45DC-90AB-A3A3450A476F@192.168.4.11 (58) [Apr 5 17:35:11] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 4: CSeq: 1 ACK (11) [Apr 5 17:35:11] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 5: From: "unknown";tag=3492175015678 (60) [Apr 5 17:35:11] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 6: Max-Forwards: 70 (16) [Apr 5 17:35:11] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 7: To: ;tag=as3f26c88b (46) [Apr 5 17:35:11] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 8: User-Agent: SJphone/1.60.289a (SJ Labs) (39) [Apr 5 17:35:11] --- (9 headers 0 lines) --- [Apr 5 17:35:11] DEBUG[3742]: chan_sip.c:14633 handle_request: **** Received ACK (6) - Command in SIP ACK [Apr 5 17:35:11] DEBUG[3742]: chan_sip.c:2079 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #33 [Apr 5 17:35:11] DEBUG[3742]: chan_sip.c:2089 __sip_ack: Stopping retransmission on 'E481A37A-80BD-45DC-90AB-A3A3450A476F@192.168.4.11' of Response 1: Match Not Found [Apr 5 17:35:11] <--- SIP read from 192.168.4.11:5060 ---> INVITE sip:103@192.168.4.14:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.4.11;rport;branch=z9hG4bKc0a8040b0000001a461517210000174d00000009 Content-Length: 337 Contact: Call-ID: E481A37A-80BD-45DC-90AB-A3A3450A476F@192.168.4.11 Content-Type: application/sdp CSeq: 2 INVITE From: "unknown";tag=3492175015678 Max-Forwards: 70 To: User-Agent: SJphone/1.60.289a (SJ Labs) Proxy-Authorization: Digest username="101",realm="asterisk",nonce="76e9b130",uri="sip:103@192.168.4.14:5060",response="41e1999ffbb5de0e32cbe47b29e4032c",algorithm="MD5" v=0 o=- 3384776097 3384776097 IN IP4 192.168.4.11 s=SJphone c=IN IP4 192.168.4.11 t=0 0 a=direction:active m=audio 49152 RTP/AVP 3 97 98 8 0 101 a=rtpmap:3 GSM/8000 a=rtpmap:97 iLBC/8000 a=rtpmap:98 iLBC/8000 a=fmtp:98 mode=20 a=rtpmap:8 PCMA/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-11,16 <-------------> [Apr 5 17:35:11] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 0: INVITE sip:103@192.168.4.14:5060 SIP/2.0 (40) [Apr 5 17:35:11] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.4.11;rport;branch=z9hG4bKc0a8040b0000001a461517210000174d00000009 (90) [Apr 5 17:35:11] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 2: Content-Length: 337 (19) [Apr 5 17:35:11] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 3: Contact: (36) [Apr 5 17:35:11] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 4: Call-ID: E481A37A-80BD-45DC-90AB-A3A3450A476F@192.168.4.11 (58) [Apr 5 17:35:11] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 5: Content-Type: application/sdp (29) [Apr 5 17:35:11] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 6: CSeq: 2 INVITE (14) [Apr 5 17:35:11] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 7: From: "unknown";tag=3492175015678 (60) [Apr 5 17:35:11] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 8: Max-Forwards: 70 (16) [Apr 5 17:35:11] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 9: To: (31) [Apr 5 17:35:11] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 10: User-Agent: SJphone/1.60.289a (SJ Labs) (39) [Apr 5 17:35:11] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 11: Proxy-Authorization: Digest username="101",realm="asterisk",nonce="76e9b130",uri="sip:103@192.168.4.14:5060",response="41e1999ffbb5de0e32cbe47b29e4032c",algorithm="MD5" (168) [Apr 5 17:35:11] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 12: (0) [Apr 5 17:35:11] DEBUG[3742]: chan_sip.c:4605 parse_request: Line: v=0 (3) [Apr 5 17:35:11] DEBUG[3742]: chan_sip.c:4605 parse_request: Line: o=- 3384776097 3384776097 IN IP4 192.168.4.11 (45) [Apr 5 17:35:11] DEBUG[3742]: chan_sip.c:4605 parse_request: Line: s=SJphone (9) [Apr 5 17:35:11] DEBUG[3742]: chan_sip.c:4605 parse_request: Line: c=IN IP4 192.168.4.11 (21) [Apr 5 17:35:11] DEBUG[3742]: chan_sip.c:4605 parse_request: Line: t=0 0 (5) [Apr 5 17:35:11] DEBUG[3742]: chan_sip.c:4605 parse_request: Line: a=direction:active (18) [Apr 5 17:35:11] DEBUG[3742]: chan_sip.c:4605 parse_request: Line: m=audio 49152 RTP/AVP 3 97 98 8 0 101 (37) [Apr 5 17:35:11] DEBUG[3742]: chan_sip.c:4605 parse_request: Line: a=rtpmap:3 GSM/8000 (19) [Apr 5 17:35:11] DEBUG[3742]: chan_sip.c:4605 parse_request: Line: a=rtpmap:97 iLBC/8000 (21) [Apr 5 17:35:11] DEBUG[3742]: chan_sip.c:4605 parse_request: Line: a=rtpmap:98 iLBC/8000 (21) [Apr 5 17:35:11] DEBUG[3742]: chan_sip.c:4605 parse_request: Line: a=fmtp:98 mode=20 (17) [Apr 5 17:35:11] DEBUG[3742]: chan_sip.c:4605 parse_request: Line: a=rtpmap:8 PCMA/8000 (20) [Apr 5 17:35:11] DEBUG[3742]: chan_sip.c:4605 parse_request: Line: a=rtpmap:0 PCMU/8000 (20) [Apr 5 17:35:11] DEBUG[3742]: chan_sip.c:4605 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [Apr 5 17:35:11] --- (12 headers 15 lines) --- [Apr 5 17:35:11] DEBUG[3742]: chan_sip.c:14633 handle_request: **** Received INVITE (5) - Command in SIP INVITE [Apr 5 17:35:11] Sending to 192.168.4.11 : 5060 (NAT) [Apr 5 17:35:11] Using INVITE request as basis request - E481A37A-80BD-45DC-90AB-A3A3450A476F@192.168.4.11 [Apr 5 17:35:11] Found peer '101' [Apr 5 17:35:11] DEBUG[3742]: chan_sip.c:2575 do_setnat: Setting NAT on RTP to On [Apr 5 17:35:11] DEBUG[3742]: chan_sip.c:2580 do_setnat: Setting NAT on VRTP to On [Apr 5 17:35:11] DEBUG[3742]: chan_sip.c:2585 do_setnat: Setting NAT on UDPTL to On [Apr 5 17:35:11] Found RTP audio format 3 [Apr 5 17:35:11] Found RTP audio format 97 [Apr 5 17:35:11] Found RTP audio format 98 [Apr 5 17:35:11] Found RTP audio format 8 [Apr 5 17:35:11] Found RTP audio format 0 [Apr 5 17:35:11] Found RTP audio format 101 [Apr 5 17:35:11] DEBUG[3742]: chan_sip.c:4899 process_sdp: Peer doesn't provide T.38 UDPTL [Apr 5 17:35:11] Peer audio RTP is at port 192.168.4.11:49152 [Apr 5 17:35:11] Found description format GSM for ID 3 [Apr 5 17:35:11] Found description format iLBC for ID 97 [Apr 5 17:35:11] Found description format iLBC for ID 98 [Apr 5 17:35:11] Got unsupported a:fmtp in SDP offer [Apr 5 17:35:11] Found description format PCMA for ID 8 [Apr 5 17:35:11] Found description format PCMU for ID 0 [Apr 5 17:35:11] Found description format telephone-event for ID 101 [Apr 5 17:35:11] Got unsupported a:fmtp in SDP offer [Apr 5 17:35:11] DEBUG[3742]: chan_sip.c:5129 process_sdp: T38 state changed to 0 on channel [Apr 5 17:35:11] Capabilities: us - 0x4 (ulaw), peer - audio=0x40e (gsm|ulaw|alaw|ilbc)/video=0x0 (nothing), combined - 0x4 (ulaw) [Apr 5 17:35:11] Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) [Apr 5 17:35:11] Peer audio RTP is at port 192.168.4.11:49152 [Apr 5 17:35:11] DEBUG[3742]: chan_sip.c:5209 process_sdp: We're settling with these formats: 0x4 (ulaw) [Apr 5 17:35:11] DEBUG[3742]: chan_sip.c:13401 handle_request_invite: Checking SIP call limits for device 101 [Apr 5 17:35:11] DEBUG[3742]: chan_sip.c:3003 update_call_counter: Updating call counter for incoming call [Apr 5 17:35:11] DEBUG[3742]: chan_sip.c:3077 update_call_counter: Call from peer '101' is 1 out of 2 [Apr 5 17:35:11] DEBUG[3742]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/101 [Apr 5 17:35:11] Looking for 103 in from-sip (domain 192.168.4.14) [Apr 5 17:35:11] DEBUG[3742]: chan_sip.c:3805 sip_new: *** Our native formats are 0x4 (ulaw) [Apr 5 17:35:11] DEBUG[3742]: chan_sip.c:3806 sip_new: *** Joint capabilities are 0x4 (ulaw) [Apr 5 17:35:11] DEBUG[3742]: chan_sip.c:3807 sip_new: *** Our capabilities are 0x4 (ulaw) [Apr 5 17:35:11] DEBUG[3742]: chan_sip.c:3808 sip_new: *** AST_CODEC_CHOOSE formats are 0x4 (ulaw) [Apr 5 17:35:11] DEBUG[3742]: chan_sip.c:3831 sip_new: This channel will not be able to handle video. [Apr 5 17:35:11] DEBUG[3742]: chan_sip.c:7980 build_route: build_route: Contact hop: [Apr 5 17:35:11] list_route: hop: [Apr 5 17:35:11] DEBUG[3742]: chan_sip.c:13476 handle_request_invite: SIP/101-081df580: New call is still down.... Trying... [Apr 5 17:35:11] <--- Transmitting (NAT) to 192.168.4.11:5060 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 192.168.4.11;branch=z9hG4bKc0a8040b0000001a461517210000174d00000009;received=192.168.4.11;rport=5060 From: "unknown";tag=3492175015678 To: Call-ID: E481A37A-80BD-45DC-90AB-A3A3450A476F@192.168.4.11 CSeq: 2 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Length: 0 <------------> [Apr 5 17:35:11] DEBUG[3742]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/101-081df580 [Apr 5 17:35:11] DEBUG[3725]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 101 [Apr 5 17:35:11] DEBUG[3725]: chan_sip.c:15244 sip_devicestate: Checking device state for peer 101 [Apr 5 17:35:11] DEBUG[3725]: devicestate.c:287 do_state_change: Changing state for SIP/101 - state 2 (In use) [Apr 5 17:35:11] DEBUG[3725]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 101 [Apr 5 17:35:11] DEBUG[3725]: chan_sip.c:15244 sip_devicestate: Checking device state for peer 101 [Apr 5 17:35:11] DEBUG[3725]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 101 [Apr 5 17:35:11] DEBUG[3725]: chan_sip.c:15244 sip_devicestate: Checking device state for peer 101 [Apr 5 17:35:11] DEBUG[3725]: devicestate.c:287 do_state_change: Changing state for SIP/101 - state 2 (In use) [Apr 5 17:35:11] DEBUG[3725]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 101 [Apr 5 17:35:11] DEBUG[3725]: chan_sip.c:15244 sip_devicestate: Checking device state for peer 101 [Apr 5 17:35:11] DEBUG[3755]: app_queue.c:546 changethread: Device 'SIP/101' changed to state '2' (In use) but we don't care because they're not a member of any queue. [Apr 5 17:35:11] DEBUG[3756]: app_queue.c:546 changethread: Device 'SIP/101' changed to state '2' (In use) but we don't care because they're not a member of any queue. [Apr 5 17:35:11] ERROR[3754]: pbx.c:1523 ast_func_read: Function DEVSTATE not registered [Apr 5 17:35:11] DEBUG[3754]: pbx.c:1648 pbx_substitute_variables_helper_full: Function result is '(null)' [Apr 5 17:35:11] DEBUG[3754]: pbx.c:1795 pbx_extension_helper: Launching 'NoOp' [Apr 5 17:35:11] -- Executing [103@from-sip:1] NoOp("SIP/101-081df580", "SIP/103 has state ") in new stack [Apr 5 17:35:11] DEBUG[3754]: pbx.c:1648 pbx_substitute_variables_helper_full: Function result is '0' [Apr 5 17:35:11] DEBUG[3754]: pbx.c:1795 pbx_extension_helper: Launching 'NoOp' [Apr 5 17:35:11] -- Executing [103@from-sip:2] NoOp("SIP/101-081df580", "SIPPEER(103:curcalls) is 0") in new stack [Apr 5 17:35:11] DEBUG[3754]: pbx.c:1795 pbx_extension_helper: Launching 'Dial' [Apr 5 17:35:11] -- Executing [103@from-sip:3] Dial("SIP/101-081df580", "SIP/103") in new stack [Apr 5 17:35:11] DEBUG[3754]: chan_sip.c:15310 sip_request_call: Asked to create a SIP channel with formats: 0x4 (ulaw) [Apr 5 17:35:11] DEBUG[3754]: chan_sip.c:4310 sip_alloc: Allocating new SIP dialog for (No Call-ID) - INVITE (With RTP) [Apr 5 17:35:11] DEBUG[3754]: chan_sip.c:2621 create_addr_from_peer: Our T38 capability (3856) [Apr 5 17:35:11] DEBUG[3754]: chan_sip.c:2575 do_setnat: Setting NAT on RTP to On [Apr 5 17:35:11] DEBUG[3754]: chan_sip.c:2585 do_setnat: Setting NAT on UDPTL to On [Apr 5 17:35:11] DEBUG[3754]: chan_sip.c:3805 sip_new: *** Our native formats are 0x4 (ulaw) [Apr 5 17:35:11] DEBUG[3754]: chan_sip.c:3806 sip_new: *** Joint capabilities are 0x0 (nothing) [Apr 5 17:35:11] DEBUG[3754]: chan_sip.c:3807 sip_new: *** Our capabilities are 0x4 (ulaw) [Apr 5 17:35:11] DEBUG[3754]: chan_sip.c:3808 sip_new: *** AST_CODEC_CHOOSE formats are 0x4 (ulaw) [Apr 5 17:35:11] DEBUG[3754]: chan_sip.c:3810 sip_new: *** Our preferred formats from the incoming channel are 0x4 (ulaw) [Apr 5 17:35:11] DEBUG[3754]: chan_sip.c:3831 sip_new: This channel will not be able to handle video. [Apr 5 17:35:11] DEBUG[3754]: channel.c:3301 ast_channel_inherit_variables: Not copying variable STACK-from-sip-103-3. [Apr 5 17:35:11] DEBUG[3754]: channel.c:3301 ast_channel_inherit_variables: Not copying variable STACK-from-sip-103-2. [Apr 5 17:35:11] DEBUG[3754]: channel.c:3301 ast_channel_inherit_variables: Not copying variable STACK-from-sip-103-1. [Apr 5 17:35:11] DEBUG[3754]: channel.c:3301 ast_channel_inherit_variables: Not copying variable SIPCALLID. [Apr 5 17:35:11] DEBUG[3754]: channel.c:3301 ast_channel_inherit_variables: Not copying variable SIPUSERAGENT. [Apr 5 17:35:11] DEBUG[3754]: channel.c:3301 ast_channel_inherit_variables: Not copying variable SIPDOMAIN. [Apr 5 17:35:11] DEBUG[3754]: channel.c:3301 ast_channel_inherit_variables: Not copying variable SIPURI. [Apr 5 17:35:11] DEBUG[3754]: chan_sip.c:2830 sip_call: Outgoing Call for 103 [Apr 5 17:35:11] DEBUG[3754]: chan_sip.c:3003 update_call_counter: Updating call counter for outgoing call [Apr 5 17:35:11] DEBUG[3754]: chan_sip.c:3077 update_call_counter: Call to peer '103' is 1 out of 2 [Apr 5 17:35:11] DEBUG[3754]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/103 [Apr 5 17:35:11] DEBUG[3725]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 103 [Apr 5 17:35:11] DEBUG[3725]: chan_sip.c:15244 sip_devicestate: Checking device state for peer 103 [Apr 5 17:35:11] DEBUG[3725]: devicestate.c:287 do_state_change: Changing state for SIP/103 - state 6 (Ringing) [Apr 5 17:35:11] DEBUG[3725]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 103 [Apr 5 17:35:11] DEBUG[3725]: chan_sip.c:15244 sip_devicestate: Checking device state for peer 103 [Apr 5 17:35:11] DEBUG[3757]: app_queue.c:546 changethread: Device 'SIP/103' changed to state '6' (Ringing) but we don't care because they're not a member of any queue. [Apr 5 17:35:11] DEBUG[3754]: chan_sip.c:2845 sip_call: Our T38 capability (3856), joint T38 capability (3856) [Apr 5 17:35:11] DEBUG[3754]: chan_sip.c:6188 add_sdp: ** Our capability: 0x4 (ulaw) Video flag: False [Apr 5 17:35:11] DEBUG[3754]: chan_sip.c:6189 add_sdp: ** Our prefcodec: 0x4 (ulaw) [Apr 5 17:35:11] Audio is at 192.168.4.14 port 18062 [Apr 5 17:35:11] Adding codec 0x4 (ulaw) to SDP [Apr 5 17:35:11] Adding non-codec 0x1 (telephone-event) to SDP [Apr 5 17:35:11] DEBUG[3754]: chan_sip.c:6320 add_sdp: -- Done with adding codecs to SDP [Apr 5 17:35:11] DEBUG[3754]: chan_sip.c:6365 add_sdp: Done building SDP. Settling with this capability: 0x4 (ulaw) [Apr 5 17:35:11] DEBUG[3754]: chan_sip.c:4573 parse_request: Header 0: INVITE sip:103@192.168.4.109:2051;line=0cl0sm4g SIP/2.0 (55) [Apr 5 17:35:11] DEBUG[3754]: chan_sip.c:4573 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.4.14:5060;branch=z9hG4bK7ae33b17;rport (63) [Apr 5 17:35:11] DEBUG[3754]: chan_sip.c:4573 parse_request: Header 2: From: "unknown" ;tag=as67a477eb (53) [Apr 5 17:35:11] DEBUG[3754]: chan_sip.c:4573 parse_request: Header 3: To: (46) [Apr 5 17:35:11] DEBUG[3754]: chan_sip.c:4573 parse_request: Header 4: Contact: (31) [Apr 5 17:35:11] DEBUG[3754]: chan_sip.c:4573 parse_request: Header 5: Call-ID: 7dab6c18398aeb4169270c7f2093dafd@192.168.4.14 (54) [Apr 5 17:35:11] DEBUG[3754]: chan_sip.c:4573 parse_request: Header 6: CSeq: 102 INVITE (16) [Apr 5 17:35:11] DEBUG[3754]: chan_sip.c:4573 parse_request: Header 7: User-Agent: Asterisk PBX (24) [Apr 5 17:35:11] DEBUG[3754]: chan_sip.c:4573 parse_request: Header 8: Max-Forwards: 70 (16) [Apr 5 17:35:11] DEBUG[3754]: chan_sip.c:4573 parse_request: Header 9: Date: Thu, 05 Apr 2007 15:35:11 GMT (35) [Apr 5 17:35:11] DEBUG[3754]: chan_sip.c:4573 parse_request: Header 10: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) [Apr 5 17:35:11] DEBUG[3754]: chan_sip.c:4573 parse_request: Header 11: Supported: replaces (19) [Apr 5 17:35:11] DEBUG[3754]: chan_sip.c:4573 parse_request: Header 12: Content-Type: application/sdp (29) [Apr 5 17:35:11] DEBUG[3754]: chan_sip.c:4573 parse_request: Header 13: Content-Length: 238 (19) [Apr 5 17:35:11] DEBUG[3754]: chan_sip.c:4573 parse_request: Header 14: (0) [Apr 5 17:35:11] DEBUG[3754]: chan_sip.c:4605 parse_request: Line: v=0 (3) [Apr 5 17:35:11] DEBUG[3754]: chan_sip.c:4605 parse_request: Line: o=root 3720 3720 IN IP4 192.168.4.14 (36) [Apr 5 17:35:11] DEBUG[3754]: chan_sip.c:4605 parse_request: Line: s=session (9) [Apr 5 17:35:11] DEBUG[3754]: chan_sip.c:4605 parse_request: Line: c=IN IP4 192.168.4.14 (21) [Apr 5 17:35:11] DEBUG[3754]: chan_sip.c:4605 parse_request: Line: t=0 0 (5) [Apr 5 17:35:11] DEBUG[3754]: chan_sip.c:4605 parse_request: Line: m=audio 18062 RTP/AVP 0 101 (27) [Apr 5 17:35:11] DEBUG[3754]: chan_sip.c:4605 parse_request: Line: a=rtpmap:0 PCMU/8000 (20) [Apr 5 17:35:11] DEBUG[3754]: chan_sip.c:4605 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [Apr 5 17:35:11] DEBUG[3754]: chan_sip.c:4605 parse_request: Line: a=fmtp:101 0-16 (15) [Apr 5 17:35:11] DEBUG[3754]: chan_sip.c:4605 parse_request: Line: a=silenceSupp:off - - - - (25) [Apr 5 17:35:11] DEBUG[3754]: chan_sip.c:4605 parse_request: Line: a=ptime:20 (10) [Apr 5 17:35:11] DEBUG[3754]: chan_sip.c:4605 parse_request: Line: a=sendrecv (10) [Apr 5 17:35:11] Reliably Transmitting (NAT) to 192.168.4.109:2051: INVITE sip:103@192.168.4.109:2051;line=0cl0sm4g SIP/2.0 Via: SIP/2.0/UDP 192.168.4.14:5060;branch=z9hG4bK7ae33b17;rport From: "unknown" ;tag=as67a477eb To: Contact: Call-ID: 7dab6c18398aeb4169270c7f2093dafd@192.168.4.14 CSeq: 102 INVITE User-Agent: Asterisk PBX Max-Forwards: 70 Date: Thu, 05 Apr 2007 15:35:11 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Content-Type: application/sdp Content-Length: 238 v=0 o=root 3720 3720 IN IP4 192.168.4.14 s=session c=IN IP4 192.168.4.14 t=0 0 m=audio 18062 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv --- [Apr 5 17:35:11] DEBUG[3754]: chan_sip.c:1975 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #35 [Apr 5 17:35:11] -- Called 103 [Apr 5 17:35:11] <--- SIP read from 192.168.4.109:2051 ---> SIP/2.0 180 Ringing Via: SIP/2.0/UDP 192.168.4.14:5060;branch=z9hG4bK7ae33b17;rport=5060 From: "unknown" ;tag=as67a477eb To: ;tag=b0vl6ge5e3 Call-ID: 7dab6c18398aeb4169270c7f2093dafd@192.168.4.14 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 <-------------> [Apr 5 17:35:11] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 0: SIP/2.0 180 Ringing (19) [Apr 5 17:35:11] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.4.14:5060;branch=z9hG4bK7ae33b17;rport=5060 (68) [Apr 5 17:35:11] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 2: From: "unknown" ;tag=as67a477eb (53) [Apr 5 17:35:11] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 3: To: ;tag=b0vl6ge5e3 (61) [Apr 5 17:35:11] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 4: Call-ID: 7dab6c18398aeb4169270c7f2093dafd@192.168.4.14 (54) [Apr 5 17:35:11] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 5: CSeq: 102 INVITE (16) [Apr 5 17:35:11] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 6: Contact: ;flow-id=1 (61) [Apr 5 17:35:11] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 7: Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO (88) [Apr 5 17:35:11] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 8: Allow-Events: talk, hold, refer (31) [Apr 5 17:35:11] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 9: Content-Length: 0 (17) [Apr 5 17:35:11] --- (10 headers 0 lines) --- [Apr 5 17:35:11] DEBUG[3742]: chan_sip.c:2122 __sip_semi_ack: *** SIP TIMER: Cancelling retransmission #35 - INVITE (got response) [Apr 5 17:35:11] DEBUG[3742]: chan_sip.c:2131 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '7dab6c18398aeb4169270c7f2093dafd@192.168.4.14' Request 102: Found [Apr 5 17:35:11] DEBUG[3742]: chan_sip.c:11641 handle_response_invite: SIP response 180 to standard invite [Apr 5 17:35:11] DEBUG[3742]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/103-081e3c90 [Apr 5 17:35:11] DEBUG[3725]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 103 [Apr 5 17:35:11] DEBUG[3725]: chan_sip.c:15244 sip_devicestate: Checking device state for peer 103 [Apr 5 17:35:11] DEBUG[3725]: devicestate.c:287 do_state_change: Changing state for SIP/103 - state 6 (Ringing) [Apr 5 17:35:11] DEBUG[3725]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 103 [Apr 5 17:35:11] DEBUG[3725]: chan_sip.c:15244 sip_devicestate: Checking device state for peer 103 [Apr 5 17:35:11] -- SIP/103-081e3c90 is ringing [Apr 5 17:35:11] <--- Transmitting (NAT) to 192.168.4.11:5060 ---> SIP/2.0 180 Ringing Via: SIP/2.0/UDP 192.168.4.11;branch=z9hG4bKc0a8040b0000001a461517210000174d00000009;received=192.168.4.11;rport=5060 From: "unknown";tag=3492175015678 To: ;tag=as453198ae Call-ID: E481A37A-80BD-45DC-90AB-A3A3450A476F@192.168.4.11 CSeq: 2 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Length: 0 <------------> [Apr 5 17:35:11] DEBUG[3758]: app_queue.c:546 changethread: Device 'SIP/103' changed to state '6' (Ringing) but we don't care because they're not a member of any queue. [Apr 5 17:35:12] <--- SIP read from 192.168.4.109:2051 ---> SIP/2.0 180 Ringing Via: SIP/2.0/UDP 192.168.4.14:5060;branch=z9hG4bK7ae33b17;rport=5060 From: "unknown" ;tag=as67a477eb To: ;tag=b0vl6ge5e3 Call-ID: 7dab6c18398aeb4169270c7f2093dafd@192.168.4.14 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 <-------------> [Apr 5 17:35:12] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 0: SIP/2.0 180 Ringing (19) [Apr 5 17:35:12] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.4.14:5060;branch=z9hG4bK7ae33b17;rport=5060 (68) [Apr 5 17:35:12] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 2: From: "unknown" ;tag=as67a477eb (53) [Apr 5 17:35:12] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 3: To: ;tag=b0vl6ge5e3 (61) [Apr 5 17:35:12] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 4: Call-ID: 7dab6c18398aeb4169270c7f2093dafd@192.168.4.14 (54) [Apr 5 17:35:12] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 5: CSeq: 102 INVITE (16) [Apr 5 17:35:12] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 6: Contact: ;flow-id=1 (61) [Apr 5 17:35:12] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 7: Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO (88) [Apr 5 17:35:12] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 8: Allow-Events: talk, hold, refer (31) [Apr 5 17:35:12] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 9: Content-Length: 0 (17) [Apr 5 17:35:12] --- (10 headers 0 lines) --- [Apr 5 17:35:12] DEBUG[3742]: chan_sip.c:2131 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '7dab6c18398aeb4169270c7f2093dafd@192.168.4.14' Request 102: Found [Apr 5 17:35:12] DEBUG[3742]: chan_sip.c:11641 handle_response_invite: SIP response 180 to standard invite [Apr 5 17:35:12] -- SIP/103-081e3c90 is ringing [Apr 5 17:35:13] <--- SIP read from 192.168.4.109:2051 ---> SIP/2.0 180 Ringing Via: SIP/2.0/UDP 192.168.4.14:5060;branch=z9hG4bK7ae33b17;rport=5060 From: "unknown" ;tag=as67a477eb To: ;tag=b0vl6ge5e3 Call-ID: 7dab6c18398aeb4169270c7f2093dafd@192.168.4.14 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 <-------------> [Apr 5 17:35:13] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 0: SIP/2.0 180 Ringing (19) [Apr 5 17:35:13] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.4.14:5060;branch=z9hG4bK7ae33b17;rport=5060 (68) [Apr 5 17:35:13] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 2: From: "unknown" ;tag=as67a477eb (53) [Apr 5 17:35:13] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 3: To: ;tag=b0vl6ge5e3 (61) [Apr 5 17:35:13] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 4: Call-ID: 7dab6c18398aeb4169270c7f2093dafd@192.168.4.14 (54) [Apr 5 17:35:13] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 5: CSeq: 102 INVITE (16) [Apr 5 17:35:13] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 6: Contact: ;flow-id=1 (61) [Apr 5 17:35:13] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 7: Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO (88) [Apr 5 17:35:13] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 8: Allow-Events: talk, hold, refer (31) [Apr 5 17:35:13] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 9: Content-Length: 0 (17) [Apr 5 17:35:13] --- (10 headers 0 lines) --- [Apr 5 17:35:13] DEBUG[3742]: chan_sip.c:2131 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '7dab6c18398aeb4169270c7f2093dafd@192.168.4.14' Request 102: Found [Apr 5 17:35:13] DEBUG[3742]: chan_sip.c:11641 handle_response_invite: SIP response 180 to standard invite [Apr 5 17:35:13] -- SIP/103-081e3c90 is ringing [Apr 5 17:35:15] <--- SIP read from 192.168.4.109:2051 ---> SIP/2.0 180 Ringing Via: SIP/2.0/UDP 192.168.4.14:5060;branch=z9hG4bK7ae33b17;rport=5060 From: "unknown" ;tag=as67a477eb To: ;tag=b0vl6ge5e3 Call-ID: 7dab6c18398aeb4169270c7f2093dafd@192.168.4.14 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 <-------------> [Apr 5 17:35:15] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 0: SIP/2.0 180 Ringing (19) [Apr 5 17:35:15] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.4.14:5060;branch=z9hG4bK7ae33b17;rport=5060 (68) [Apr 5 17:35:15] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 2: From: "unknown" ;tag=as67a477eb (53) [Apr 5 17:35:15] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 3: To: ;tag=b0vl6ge5e3 (61) [Apr 5 17:35:15] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 4: Call-ID: 7dab6c18398aeb4169270c7f2093dafd@192.168.4.14 (54) [Apr 5 17:35:15] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 5: CSeq: 102 INVITE (16) [Apr 5 17:35:15] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 6: Contact: ;flow-id=1 (61) [Apr 5 17:35:15] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 7: Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO (88) [Apr 5 17:35:15] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 8: Allow-Events: talk, hold, refer (31) [Apr 5 17:35:15] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 9: Content-Length: 0 (17) [Apr 5 17:35:15] --- (10 headers 0 lines) --- [Apr 5 17:35:15] DEBUG[3742]: chan_sip.c:2131 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '7dab6c18398aeb4169270c7f2093dafd@192.168.4.14' Request 102: Found [Apr 5 17:35:15] DEBUG[3742]: chan_sip.c:11641 handle_response_invite: SIP response 180 to standard invite [Apr 5 17:35:15] -- SIP/103-081e3c90 is ringing [Apr 5 17:35:15] DEBUG[3754]: rtp.c:868 ast_rtcp_read: RTCP NAT: Got RTCP from other end. Now sending to address 192.168.4.109:11123 [Apr 5 17:35:15] DEBUG[3754]: rtp.c:873 ast_rtcp_read: Got RTCP report of 52 bytes [Apr 5 17:35:15] <--- SIP read from 192.168.4.109:2051 ---> SIP/2.0 200 Ok Via: SIP/2.0/UDP 192.168.4.14:5060;branch=z9hG4bK7ae33b17;rport=5060 From: "unknown" ;tag=as67a477eb To: ;tag=b0vl6ge5e3 Call-ID: 7dab6c18398aeb4169270c7f2093dafd@192.168.4.14 CSeq: 102 INVITE Contact: ;flow-id=1 User-Agent: snom360/6.5.8 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: 329 v=0 o=root 1859181628 1859181629 IN IP4 192.168.4.109 s=call c=IN IP4 192.168.4.109 t=0 0 m=audio 11122 RTP/AVP 0 101 a=crypto:1 AES_CM_128_HMAC_SHA1_32 inline:Pnx6rrLRgebm371hdmd56XzObUjxF47Nsc3j1fM2 a=rtpmap:0 pcmu/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 a=encryption:optional a=sendrecv <-------------> [Apr 5 17:35:15] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 0: SIP/2.0 200 Ok (14) [Apr 5 17:35:15] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.4.14:5060;branch=z9hG4bK7ae33b17;rport=5060 (68) [Apr 5 17:35:15] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 2: From: "unknown" ;tag=as67a477eb (53) [Apr 5 17:35:15] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 3: To: ;tag=b0vl6ge5e3 (61) [Apr 5 17:35:15] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 4: Call-ID: 7dab6c18398aeb4169270c7f2093dafd@192.168.4.14 (54) [Apr 5 17:35:15] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 5: CSeq: 102 INVITE (16) [Apr 5 17:35:15] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 6: Contact: ;flow-id=1 (61) [Apr 5 17:35:15] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 7: User-Agent: snom360/6.5.8 (25) [Apr 5 17:35:15] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 8: Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO (88) [Apr 5 17:35:15] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 9: Allow-Events: talk, hold, refer (31) [Apr 5 17:35:15] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 10: Supported: timer, 100rel, replaces, callerid (44) [Apr 5 17:35:15] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 11: Content-Type: application/sdp (29) [Apr 5 17:35:15] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 12: Content-Length: 329 (19) [Apr 5 17:35:15] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 13: (0) [Apr 5 17:35:15] DEBUG[3742]: chan_sip.c:4605 parse_request: Line: v=0 (3) [Apr 5 17:35:15] DEBUG[3742]: chan_sip.c:4605 parse_request: Line: o=root 1859181628 1859181629 IN IP4 192.168.4.109 (49) [Apr 5 17:35:15] DEBUG[3742]: chan_sip.c:4605 parse_request: Line: s=call (6) [Apr 5 17:35:15] DEBUG[3742]: chan_sip.c:4605 parse_request: Line: c=IN IP4 192.168.4.109 (22) [Apr 5 17:35:15] DEBUG[3742]: chan_sip.c:4605 parse_request: Line: t=0 0 (5) [Apr 5 17:35:15] DEBUG[3742]: chan_sip.c:4605 parse_request: Line: m=audio 11122 RTP/AVP 0 101 (27) [Apr 5 17:35:15] DEBUG[3742]: chan_sip.c:4605 parse_request: Line: a=crypto:1 AES_CM_128_HMAC_SHA1_32 inline:Pnx6rrLRgebm371hdmd56XzObUjxF47Nsc3j1fM2 (82) [Apr 5 17:35:15] DEBUG[3742]: chan_sip.c:4605 parse_request: Line: a=rtpmap:0 pcmu/8000 (20) [Apr 5 17:35:15] DEBUG[3742]: chan_sip.c:4605 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [Apr 5 17:35:15] DEBUG[3742]: chan_sip.c:4605 parse_request: Line: a=fmtp:101 0-16 (15) [Apr 5 17:35:15] DEBUG[3742]: chan_sip.c:4605 parse_request: Line: a=ptime:20 (10) [Apr 5 17:35:15] DEBUG[3742]: chan_sip.c:4605 parse_request: Line: a=encryption:optional (21) [Apr 5 17:35:15] --- (13 headers 13 lines) --- [Apr 5 17:35:15] DEBUG[3742]: chan_sip.c:2071 __sip_ack: Acked pending invite 102 [Apr 5 17:35:15] DEBUG[3742]: chan_sip.c:2089 __sip_ack: Stopping retransmission on '7dab6c18398aeb4169270c7f2093dafd@192.168.4.14' of Request 102: Match Not Found [Apr 5 17:35:15] DEBUG[3742]: chan_sip.c:11641 handle_response_invite: SIP response 200 to standard invite [Apr 5 17:35:15] Found RTP audio format 0 [Apr 5 17:35:15] Found RTP audio format 101 [Apr 5 17:35:15] DEBUG[3742]: chan_sip.c:4899 process_sdp: Peer doesn't provide T.38 UDPTL [Apr 5 17:35:15] Peer audio RTP is at port 192.168.4.109:11122 [Apr 5 17:35:15] Got unsupported a:crypto in SDP offer [Apr 5 17:35:15] Found description format pcmu for ID 0 [Apr 5 17:35:15] Found description format telephone-event for ID 101 [Apr 5 17:35:15] Got unsupported a:fmtp in SDP offer [Apr 5 17:35:15] DEBUG[3742]: chan_sip.c:5129 process_sdp: T38 state changed to 0 on channel SIP/103-081e3c90 [Apr 5 17:35:15] Capabilities: us - 0x4 (ulaw), peer - audio=0x4 (ulaw)/video=0x0 (nothing), combined - 0x4 (ulaw) [Apr 5 17:35:15] Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) [Apr 5 17:35:15] Peer audio RTP is at port 192.168.4.109:11122 [Apr 5 17:35:15] DEBUG[3742]: chan_sip.c:5209 process_sdp: We're settling with these formats: 0x4 (ulaw) [Apr 5 17:35:15] DEBUG[3742]: chan_sip.c:5216 process_sdp: We have an owner, now see if we need to change this call [Apr 5 17:35:15] DEBUG[3742]: chan_sip.c:3003 update_call_counter: Updating call counter for outgoing call [Apr 5 17:35:15] DEBUG[3742]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/103 [Apr 5 17:35:15] DEBUG[3742]: chan_sip.c:7980 build_route: build_route: Contact hop: ;flow-id=1 [Apr 5 17:35:15] list_route: hop: [Apr 5 17:35:15] DEBUG[3742]: chan_sip.c:5643 reqprep: Strict routing enforced for session 7dab6c18398aeb4169270c7f2093dafd@192.168.4.14 [Apr 5 17:35:15] set_destination: Parsing for address/port to send to [Apr 5 17:35:15] set_destination: set destination to 192.168.4.109, port 2051 [Apr 5 17:35:15] Transmitting (NAT) to 192.168.4.109:2051: ACK sip:103@192.168.4.109:2051;line=0cl0sm4g SIP/2.0 Via: SIP/2.0/UDP 192.168.4.14:5060;branch=z9hG4bK3a7bc817;rport From: "unknown" ;tag=as67a477eb To: ;tag=b0vl6ge5e3 Contact: Call-ID: 7dab6c18398aeb4169270c7f2093dafd@192.168.4.14 CSeq: 102 ACK User-Agent: Asterisk PBX Max-Forwards: 70 Content-Length: 0 --- [Apr 5 17:35:15] -- Call on SIP/103-081e3c90 left from hold [Apr 5 17:35:15] DEBUG[3754]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/103-081e3c90 [Apr 5 17:35:15] -- SIP/103-081e3c90 answered SIP/101-081df580 [Apr 5 17:35:15] DEBUG[3754]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/101-081df580 [Apr 5 17:35:15] DEBUG[3754]: chan_sip.c:3463 sip_answer: SIP answering channel: SIP/101-081df580 [Apr 5 17:35:15] DEBUG[3754]: chan_sip.c:6420 transmit_response_with_sdp: Setting framing from config on incoming call [Apr 5 17:35:15] DEBUG[3754]: chan_sip.c:6188 add_sdp: ** Our capability: 0x4 (ulaw) Video flag: True [Apr 5 17:35:15] DEBUG[3754]: chan_sip.c:6189 add_sdp: ** Our prefcodec: 0x0 (nothing) [Apr 5 17:35:15] Audio is at 192.168.4.14 port 12294 [Apr 5 17:35:15] Adding codec 0x4 (ulaw) to SDP [Apr 5 17:35:15] Adding non-codec 0x1 (telephone-event) to SDP [Apr 5 17:35:15] DEBUG[3754]: chan_sip.c:6320 add_sdp: -- Done with adding codecs to SDP [Apr 5 17:35:15] DEBUG[3754]: chan_sip.c:6365 add_sdp: Done building SDP. Settling with this capability: 0x4 (ulaw) [Apr 5 17:35:15] <--- Reliably Transmitting (NAT) to 192.168.4.11:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.4.11;branch=z9hG4bKc0a8040b0000001a461517210000174d00000009;received=192.168.4.11;rport=5060 From: "unknown";tag=3492175015678 To: ;tag=as453198ae Call-ID: E481A37A-80BD-45DC-90AB-A3A3450A476F@192.168.4.11 CSeq: 2 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Type: application/sdp Content-Length: 238 v=0 o=root 3720 3720 IN IP4 192.168.4.14 s=session c=IN IP4 192.168.4.14 t=0 0 m=audio 12294 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv <------------> [Apr 5 17:35:15] DEBUG[3754]: chan_sip.c:1975 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #37 [Apr 5 17:35:15] -- Packet2Packet bridging SIP/101-081df580 and SIP/103-081e3c90 [Apr 5 17:35:15] DEBUG[3725]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 103 [Apr 5 17:35:15] DEBUG[3725]: chan_sip.c:15244 sip_devicestate: Checking device state for peer 103 [Apr 5 17:35:15] DEBUG[3725]: devicestate.c:287 do_state_change: Changing state for SIP/103 - state 2 (In use) [Apr 5 17:35:15] DEBUG[3725]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 103 [Apr 5 17:35:15] DEBUG[3725]: chan_sip.c:15244 sip_devicestate: Checking device state for peer 103 [Apr 5 17:35:15] DEBUG[3725]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 103 [Apr 5 17:35:15] DEBUG[3725]: chan_sip.c:15244 sip_devicestate: Checking device state for peer 103 [Apr 5 17:35:15] DEBUG[3725]: devicestate.c:287 do_state_change: Changing state for SIP/103 - state 2 (In use) [Apr 5 17:35:15] DEBUG[3725]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 103 [Apr 5 17:35:15] DEBUG[3725]: chan_sip.c:15244 sip_devicestate: Checking device state for peer 103 [Apr 5 17:35:15] DEBUG[3725]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 101 [Apr 5 17:35:15] DEBUG[3725]: chan_sip.c:15244 sip_devicestate: Checking device state for peer 101 [Apr 5 17:35:15] DEBUG[3725]: devicestate.c:287 do_state_change: Changing state for SIP/101 - state 2 (In use) [Apr 5 17:35:15] DEBUG[3725]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 101 [Apr 5 17:35:15] DEBUG[3725]: chan_sip.c:15244 sip_devicestate: Checking device state for peer 101 [Apr 5 17:35:15] <--- SIP read from 192.168.4.11:5060 ---> ACK sip:103@192.168.4.14 SIP/2.0 Via: SIP/2.0/UDP 192.168.4.11;rport;branch=z9hG4bKc0a8040b0000001a46151726000047390000000d Content-Length: 0 Call-ID: E481A37A-80BD-45DC-90AB-A3A3450A476F@192.168.4.11 CSeq: 2 ACK From: "unknown";tag=3492175015678 Max-Forwards: 70 To: ;tag=as453198ae User-Agent: SJphone/1.60.289a (SJ Labs) <-------------> [Apr 5 17:35:15] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 0: ACK sip:103@192.168.4.14 SIP/2.0 (32) [Apr 5 17:35:15] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.4.11;rport;branch=z9hG4bKc0a8040b0000001a46151726000047390000000d (90) [Apr 5 17:35:15] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 2: Content-Length: 0 (17) [Apr 5 17:35:15] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 3: Call-ID: E481A37A-80BD-45DC-90AB-A3A3450A476F@192.168.4.11 (58) [Apr 5 17:35:15] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 4: CSeq: 2 ACK (11) [Apr 5 17:35:15] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 5: From: "unknown";tag=3492175015678 (60) [Apr 5 17:35:15] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 6: Max-Forwards: 70 (16) [Apr 5 17:35:15] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 7: To: ;tag=as453198ae (46) [Apr 5 17:35:15] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 8: User-Agent: SJphone/1.60.289a (SJ Labs) (39) [Apr 5 17:35:15] --- (9 headers 0 lines) --- [Apr 5 17:35:15] DEBUG[3742]: chan_sip.c:14633 handle_request: **** Received ACK (6) - Command in SIP ACK [Apr 5 17:35:15] DEBUG[3742]: chan_sip.c:2079 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #37 [Apr 5 17:35:15] DEBUG[3742]: chan_sip.c:2089 __sip_ack: Stopping retransmission on 'E481A37A-80BD-45DC-90AB-A3A3450A476F@192.168.4.11' of Response 2: Match Not Found [Apr 5 17:35:15] DEBUG[3759]: app_queue.c:546 changethread: Device 'SIP/103' changed to state '2' (In use) but we don't care because they're not a member of any queue. [Apr 5 17:35:15] DEBUG[3760]: app_queue.c:546 changethread: Device 'SIP/103' changed to state '2' (In use) but we don't care because they're not a member of any queue. [Apr 5 17:35:15] DEBUG[3761]: app_queue.c:546 changethread: Device 'SIP/101' changed to state '2' (In use) but we don't care because they're not a member of any queue. [Apr 5 17:35:20] DEBUG[3754]: rtp.c:873 ast_rtcp_read: Got RTCP report of 52 bytes *CLI> sip show in[Apr 5 17:35:25] DEBUG[3754]: rtp.c:873 ast_rtcp_read: Got RTCP report of 52 bytes use * User name In use Limit * Peer name In use Limit 103 1/0 2 102 0/0 2 101 1/0 2 *CLI> orcore s[Apr 5 17:35:30] DEBUG[3754]: rtp.c:873 ast_rtcp_read: Got RTCP report of 52 bytes how hints -= Registered Asterisk Dial Plan Hints =- 103@from-sip : SIP/103 State:InUse Watchers 0 102@from-sip : SIP/102 State:Idle Watchers 0 101@from-sip : SIP/101 State:InUse Watchers 0 ---------------- - 3 hints registered *CLI> [Apr 5 17:35:32] DEBUG[3742]: chan_sip.c:2010 __sip_autodestruct: Auto destroying SIP dialog 'CC0970E7-403A-408C-A913-EB6A577F10DB@192.168.4.11' [Apr 5 17:35:32] DEBUG[3742]: chan_sip.c:3109 sip_destroy: Destroying SIP dialog CC0970E7-403A-408C-A913-EB6A577F10DB@192.168.4.11 [Apr 5 17:35:32] Really destroying SIP dialog 'CC0970E7-403A-408C-A913-EB6A577F10DB@192.168.4.11' Method: REGISTER [Apr 5 17:35:34] <--- SIP read from 192.168.4.109:2051 ---> INVITE sip:101@192.168.4.14 SIP/2.0 Via: SIP/2.0/UDP 192.168.4.109:2051;branch=z9hG4bK-xp9zx1phof6f;rport From: ;tag=b0vl6ge5e3 To: "unknown" ;tag=as67a477eb Call-ID: 7dab6c18398aeb4169270c7f2093dafd@192.168.4.14 CSeq: 1 INVITE Max-Forwards: 70 Contact: ;flow-id=1 P-Key-Flags: resolution="31x13", keys="4" User-Agent: snom360/6.5.8 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 1859181628 1859181630 IN IP4 192.168.4.109 s=call c=IN IP4 192.168.4.109 t=0 0 m=audio 11122 RTP/AVP 0 8 9 2 3 18 4 101 a=crypto:1 AES_CM_128_HMAC_SHA1_32 inline:Pnx6rrLRgebm371hdmd56XzObUjxF47Nsc3j1fM2 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 <-------------> [Apr 5 17:35:34] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 0: INVITE sip:101@192.168.4.14 SIP/2.0 (35) [Apr 5 17:35:34] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.4.109:2051;branch=z9hG4bK-xp9zx1phof6f;rport (69) [Apr 5 17:35:34] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 2: From: ;tag=b0vl6ge5e3 (63) [Apr 5 17:35:34] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 3: To: "unknown" ;tag=as67a477eb (51) [Apr 5 17:35:34] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 4: Call-ID: 7dab6c18398aeb4169270c7f2093dafd@192.168.4.14 (54) [Apr 5 17:35:34] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 5: CSeq: 1 INVITE (14) [Apr 5 17:35:34] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 6: Max-Forwards: 70 (16) [Apr 5 17:35:34] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 7: Contact: ;flow-id=1 (61) [Apr 5 17:35:34] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 8: P-Key-Flags: resolution="31x13", keys="4" (41) [Apr 5 17:35:34] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 9: User-Agent: snom360/6.5.8 (25) [Apr 5 17:35:34] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 10: Accept: application/sdp (23) [Apr 5 17:35:34] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 11: Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO (88) [Apr 5 17:35:34] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 12: Allow-Events: talk, hold, refer (31) [Apr 5 17:35:34] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 13: Supported: timer, 100rel, replaces, callerid (44) [Apr 5 17:35:34] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 14: Session-Expires: 3600;refresher=uas (35) [Apr 5 17:35:34] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 15: Min-SE: 90 (10) [Apr 5 17:35:34] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 16: Content-Type: application/sdp (29) [Apr 5 17:35:34] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 17: Content-Length: 477 (19) [Apr 5 17:35:34] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 18: (0) [Apr 5 17:35:34] DEBUG[3742]: chan_sip.c:4605 parse_request: Line: v=0 (3) [Apr 5 17:35:34] DEBUG[3742]: chan_sip.c:4605 parse_request: Line: o=root 1859181628 1859181630 IN IP4 192.168.4.109 (49) [Apr 5 17:35:34] DEBUG[3742]: chan_sip.c:4605 parse_request: Line: s=call (6) [Apr 5 17:35:34] DEBUG[3742]: chan_sip.c:4605 parse_request: Line: c=IN IP4 192.168.4.109 (22) [Apr 5 17:35:34] DEBUG[3742]: chan_sip.c:4605 parse_request: Line: t=0 0 (5) [Apr 5 17:35:34] DEBUG[3742]: chan_sip.c:4605 parse_request: Line: m=audio 11122 RTP/AVP 0 8 9 2 3 18 4 101 (40) [Apr 5 17:35:34] DEBUG[3742]: chan_sip.c:4605 parse_request: Line: a=crypto:1 AES_CM_128_HMAC_SHA1_32 inline:Pnx6rrLRgebm371hdmd56XzObUjxF47Nsc3j1fM2 (82) [Apr 5 17:35:34] DEBUG[3742]: chan_sip.c:4605 parse_request: Line: a=rtpmap:0 pcmu/8000 (20) [Apr 5 17:35:34] DEBUG[3742]: chan_sip.c:4605 parse_request: Line: a=rtpmap:8 pcma/8000 (20) [Apr 5 17:35:34] DEBUG[3742]: chan_sip.c:4605 parse_request: Line: a=rtpmap:9 g722/8000 (20) [Apr 5 17:35:34] DEBUG[3742]: chan_sip.c:4605 parse_request: Line: a=rtpmap:2 g726-32/8000 (23) [Apr 5 17:35:34] DEBUG[3742]: chan_sip.c:4605 parse_request: Line: a=rtpmap:3 gsm/8000 (19) [Apr 5 17:35:34] DEBUG[3742]: chan_sip.c:4605 parse_request: Line: a=rtpmap:18 g729/8000 (21) [Apr 5 17:35:34] DEBUG[3742]: chan_sip.c:4605 parse_request: Line: a=rtpmap:4 g723/8000 (20) [Apr 5 17:35:34] DEBUG[3742]: chan_sip.c:4605 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [Apr 5 17:35:34] DEBUG[3742]: chan_sip.c:4605 parse_request: Line: a=fmtp:101 0-16 (15) [Apr 5 17:35:34] DEBUG[3742]: chan_sip.c:4605 parse_request: Line: a=ptime:20 (10) [Apr 5 17:35:34] DEBUG[3742]: chan_sip.c:4605 parse_request: Line: a=encryption:optional (21) [Apr 5 17:35:34] --- (18 headers 19 lines) --- [Apr 5 17:35:34] DEBUG[3742]: chan_sip.c:14633 handle_request: **** Received INVITE (5) - Command in SIP INVITE [Apr 5 17:35:34] DEBUG[3742]: chan_sip.c:1680 parse_sip_options: Begin: parsing SIP "Supported: timer, 100rel, replaces, callerid" [Apr 5 17:35:34] DEBUG[3742]: chan_sip.c:1688 parse_sip_options: Found SIP option: -timer- [Apr 5 17:35:34] DEBUG[3742]: chan_sip.c:1694 parse_sip_options: Matched SIP option: timer [Apr 5 17:35:34] DEBUG[3742]: chan_sip.c:1688 parse_sip_options: Found SIP option: -100rel- [Apr 5 17:35:34] DEBUG[3742]: chan_sip.c:1694 parse_sip_options: Matched SIP option: 100rel [Apr 5 17:35:34] DEBUG[3742]: chan_sip.c:1688 parse_sip_options: Found SIP option: -replaces- [Apr 5 17:35:34] DEBUG[3742]: chan_sip.c:1694 parse_sip_options: Matched SIP option: replaces [Apr 5 17:35:34] DEBUG[3742]: chan_sip.c:1688 parse_sip_options: Found SIP option: -callerid- [Apr 5 17:35:34] DEBUG[3742]: chan_sip.c:1702 parse_sip_options: Found no match for SIP option: callerid (Please file bug report!) [Apr 5 17:35:34] Sending to 192.168.4.109 : 2051 (NAT) [Apr 5 17:35:34] Found RTP audio format 0 [Apr 5 17:35:34] Found RTP audio format 8 [Apr 5 17:35:34] Found RTP audio format 9 [Apr 5 17:35:34] Found RTP audio format 2 [Apr 5 17:35:34] Found RTP audio format 3 [Apr 5 17:35:34] Found RTP audio format 18 [Apr 5 17:35:34] Found RTP audio format 4 [Apr 5 17:35:34] Found RTP audio format 101 [Apr 5 17:35:34] DEBUG[3742]: chan_sip.c:4899 process_sdp: Peer doesn't provide T.38 UDPTL [Apr 5 17:35:34] Peer audio RTP is at port 192.168.4.109:11122 [Apr 5 17:35:34] Got unsupported a:crypto in SDP offer [Apr 5 17:35:34] Found description format pcmu for ID 0 [Apr 5 17:35:34] Found description format pcma for ID 8 [Apr 5 17:35:34] Found description format g722 for ID 9 [Apr 5 17:35:34] Found description format g726-32 for ID 2 [Apr 5 17:35:34] Found description format gsm for ID 3 [Apr 5 17:35:34] Found description format g729 for ID 18 [Apr 5 17:35:34] Found description format g723 for ID 4 [Apr 5 17:35:34] Found description format telephone-event for ID 101 [Apr 5 17:35:34] Got unsupported a:fmtp in SDP offer [Apr 5 17:35:34] DEBUG[3742]: chan_sip.c:5129 process_sdp: T38 state changed to 0 on channel SIP/103-081e3c90 [Apr 5 17:35:34] Capabilities: us - 0x4 (ulaw), peer - audio=0x190f (g723|gsm|ulaw|alaw|g726|g729|g722)/video=0x0 (nothing), combined - 0x4 (ulaw) [Apr 5 17:35:34] Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) [Apr 5 17:35:34] Peer audio RTP is at port 192.168.4.109:11122 [Apr 5 17:35:34] DEBUG[3742]: chan_sip.c:5209 process_sdp: We're settling with these formats: 0x4 (ulaw) [Apr 5 17:35:34] DEBUG[3742]: chan_sip.c:5216 process_sdp: We have an owner, now see if we need to change this call [Apr 5 17:35:34] DEBUG[3742]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/103 [Apr 5 17:35:34] DEBUG[3742]: chan_sip.c:13454 handle_request_invite: Got a SIP re-invite for call 7dab6c18398aeb4169270c7f2093dafd@192.168.4.14 [Apr 5 17:35:34] DEBUG[3742]: chan_sip.c:13549 handle_request_invite: SIP/103-081e3c90: This call is UP.... [Apr 5 17:35:34] DEBUG[3742]: chan_sip.c:6420 transmit_response_with_sdp: Setting framing from config on incoming call [Apr 5 17:35:34] DEBUG[3742]: chan_sip.c:6188 add_sdp: ** Our capability: 0x4 (ulaw) Video flag: True [Apr 5 17:35:34] DEBUG[3742]: chan_sip.c:6189 add_sdp: ** Our prefcodec: 0x4 (ulaw) [Apr 5 17:35:34] Audio is at 192.168.4.14 port 18062 [Apr 5 17:35:34] Adding codec 0x4 (ulaw) to SDP [Apr 5 17:35:34] Adding non-codec 0x1 (telephone-event) to SDP [Apr 5 17:35:34] DEBUG[3742]: chan_sip.c:6320 add_sdp: -- Done with adding codecs to SDP [Apr 5 17:35:34] DEBUG[3742]: chan_sip.c:6365 add_sdp: Done building SDP. Settling with this capability: 0x4 (ulaw) [Apr 5 17:35:34] <--- Reliably Transmitting (NAT) to 192.168.4.109:2051 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.4.109:2051;branch=z9hG4bK-xp9zx1phof6f;received=192.168.4.109;rport=2051 From: ;tag=b0vl6ge5e3 To: "unknown" ;tag=as67a477eb Call-ID: 7dab6c18398aeb4169270c7f2093dafd@192.168.4.14 CSeq: 1 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Type: application/sdp Content-Length: 238 v=0 o=root 3720 3721 IN IP4 192.168.4.14 s=session c=IN IP4 192.168.4.14 t=0 0 m=audio 18062 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=recvonly <------------> [Apr 5 17:35:34] DEBUG[3742]: chan_sip.c:1975 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #38 [Apr 5 17:35:34] -- Started music on hold, class 'default', on SIP/101-081df580 [Apr 5 17:35:34] DEBUG[3754]: channel.c:1997 ast_settimeout: Scheduling timer at 160 sample intervals [Apr 5 17:35:34] DEBUG[3725]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 103 [Apr 5 17:35:34] DEBUG[3725]: chan_sip.c:15244 sip_devicestate: Checking device state for peer 103 [Apr 5 17:35:34] DEBUG[3725]: devicestate.c:287 do_state_change: Changing state for SIP/103 - state 8 (On Hold) [Apr 5 17:35:34] DEBUG[3725]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 103 [Apr 5 17:35:34] DEBUG[3725]: chan_sip.c:15244 sip_devicestate: Checking device state for peer 103 [Apr 5 17:35:34] DEBUG[3762]: app_queue.c:546 changethread: Device 'SIP/103' changed to state '8' (On Hold) but we don't care because they're not a member of any queue. [Apr 5 17:35:34] DEBUG[3754]: channel.c:2845 set_format: Set channel SIP/101-081df580 to write format slin [Apr 5 17:35:34] DEBUG[3754]: res_musiconhold.c:254 ast_moh_files_next: SIP/101-081df580 Opened file 1 '/var/lib/asterisk/moh/fpm-sunshine' [Apr 5 17:35:34] DEBUG[3754]: rtp.c:2689 ast_rtp_write: Ooh, format changed from unknown to ulaw [Apr 5 17:35:34] DEBUG[3754]: rtp.c:2706 ast_rtp_write: Created smoother: format: 4 ms: 20 len: 160 [Apr 5 17:35:34] <--- SIP read from 192.168.4.109:2051 ---> ACK sip:101@192.168.4.14 SIP/2.0 Via: SIP/2.0/UDP 192.168.4.109:2051;branch=z9hG4bK-fseqm6a7393b;rport From: ;tag=b0vl6ge5e3 To: "unknown" ;tag=as67a477eb Call-ID: 7dab6c18398aeb4169270c7f2093dafd@192.168.4.14 CSeq: 1 ACK Max-Forwards: 70 Contact: ;flow-id=1 Content-Length: 0 <-------------> [Apr 5 17:35:34] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 0: ACK sip:101@192.168.4.14 SIP/2.0 (32) [Apr 5 17:35:34] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.4.109:2051;branch=z9hG4bK-fseqm6a7393b;rport (69) [Apr 5 17:35:34] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 2: From: ;tag=b0vl6ge5e3 (63) [Apr 5 17:35:34] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 3: To: "unknown" ;tag=as67a477eb (51) [Apr 5 17:35:34] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 4: Call-ID: 7dab6c18398aeb4169270c7f2093dafd@192.168.4.14 (54) [Apr 5 17:35:34] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 5: CSeq: 1 ACK (11) [Apr 5 17:35:34] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 6: Max-Forwards: 70 (16) [Apr 5 17:35:34] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 7: Contact: ;flow-id=1 (61) [Apr 5 17:35:34] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 8: Content-Length: 0 (17) [Apr 5 17:35:34] --- (9 headers 0 lines) --- [Apr 5 17:35:34] DEBUG[3742]: chan_sip.c:14633 handle_request: **** Received ACK (6) - Command in SIP ACK [Apr 5 17:35:34] DEBUG[3742]: chan_sip.c:2079 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #38 [Apr 5 17:35:34] DEBUG[3742]: chan_sip.c:2089 __sip_ack: Stopping retransmission on '7dab6c18398aeb4169270c7f2093dafd@192.168.4.14' of Response 1: Match Not Found core show hintssip show inuse * User name In use Limit * Peer name In use Limit 103 1/0 2 102 0/0 2 101 1/0 2 *CLI> [Apr 5 17:35:40] <--- SIP read from 192.168.4.11:5060 ---> OPTIONS sip:192.168.4.14:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.4.11;rport;branch=z9hG4bKc0a8040b000000104615173f000052d70000000e Content-Length: 0 Call-ID: 2EF9B8A4-663E-4346-9FB3-0460AAC4AB1C@192.168.4.11 CSeq: 1 OPTIONS From: ;tag=3495095322624 Max-Forwards: 70 To: <-------------> [Apr 5 17:35:40] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 0: OPTIONS sip:192.168.4.14:5060 SIP/2.0 (37) [Apr 5 17:35:40] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.4.11;rport;branch=z9hG4bKc0a8040b000000104615173f000052d70000000e (90) [Apr 5 17:35:40] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 2: Content-Length: 0 (17) [Apr 5 17:35:40] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 3: Call-ID: 2EF9B8A4-663E-4346-9FB3-0460AAC4AB1C@192.168.4.11 (58) [Apr 5 17:35:40] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 4: CSeq: 1 OPTIONS (15) [Apr 5 17:35:40] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 5: From: ;tag=3495095322624 (51) [Apr 5 17:35:40] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 6: Max-Forwards: 70 (16) [Apr 5 17:35:40] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 7: To: (27) [Apr 5 17:35:40] --- (8 headers 0 lines) --- [Apr 5 17:35:40] DEBUG[3742]: chan_sip.c:4310 sip_alloc: Allocating new SIP dialog for 2EF9B8A4-663E-4346-9FB3-0460AAC4AB1C@192.168.4.11 - OPTIONS (No RTP) [Apr 5 17:35:40] DEBUG[3742]: chan_sip.c:14633 handle_request: **** Received OPTIONS (3) - Command in SIP OPTIONS [Apr 5 17:35:40] Looking for s in default (domain 192.168.4.14) [Apr 5 17:35:40] <--- Transmitting (no NAT) to 192.168.4.11:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.4.11;branch=z9hG4bKc0a8040b000000104615173f000052d70000000e;received=192.168.4.11;rport=5060 From: ;tag=3495095322624 To: ;tag=as093a42b1 Call-ID: 2EF9B8A4-663E-4346-9FB3-0460AAC4AB1C@192.168.4.11 CSeq: 1 OPTIONS User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Accept: application/sdp Content-Length: 0 <------------> [Apr 5 17:35:40] Scheduling destruction of SIP dialog '2EF9B8A4-663E-4346-9FB3-0460AAC4AB1C@192.168.4.11' in 32000 ms (Method: OPTIONS) sip show inusecore show hints -= Registered Asterisk Dial Plan Hints =- 103@from-sip : SIP/103 State:Hold Watchers 0 102@from-sip : SIP/102 State:Idle Watchers 0 101@from-sip : SIP/101 State:InUse Watchers 0 ---------------- - 3 hints registered *CLI> [Apr 5 17:35:44] DEBUG[3754]: rtp.c:868 ast_rtcp_read: RTCP NAT: Got RTCP from other end. Now sending to address 192.168.4.109:11123 [Apr 5 17:35:44] DEBUG[3754]: rtp.c:873 ast_rtcp_read: Got RTCP report of 52 bytes [Apr 5 17:35:44] <--- SIP read from 192.168.4.109:2051 ---> INVITE sip:101@192.168.4.14 SIP/2.0 Via: SIP/2.0/UDP 192.168.4.109:2051;branch=z9hG4bK-yk0nn3azfwtx;rport From: ;tag=b0vl6ge5e3 To: "unknown" ;tag=as67a477eb Call-ID: 7dab6c18398aeb4169270c7f2093dafd@192.168.4.14 CSeq: 2 INVITE Max-Forwards: 70 Contact: ;flow-id=1 P-Key-Flags: resolution="31x13", keys="4" User-Agent: snom360/6.5.8 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 1859181628 1859181631 IN IP4 192.168.4.109 s=call c=IN IP4 192.168.4.109 t=0 0 m=audio 11122 RTP/AVP 0 8 9 2 3 18 4 101 a=crypto:1 AES_CM_128_HMAC_SHA1_32 inline:Pnx6rrLRgebm371hdmd56XzObUjxF47Nsc3j1fM2 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 <-------------> [Apr 5 17:35:44] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 0: INVITE sip:101@192.168.4.14 SIP/2.0 (35) [Apr 5 17:35:44] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.4.109:2051;branch=z9hG4bK-yk0nn3azfwtx;rport (69) [Apr 5 17:35:44] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 2: From: ;tag=b0vl6ge5e3 (63) [Apr 5 17:35:44] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 3: To: "unknown" ;tag=as67a477eb (51) [Apr 5 17:35:44] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 4: Call-ID: 7dab6c18398aeb4169270c7f2093dafd@192.168.4.14 (54) [Apr 5 17:35:44] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 5: CSeq: 2 INVITE (14) [Apr 5 17:35:44] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 6: Max-Forwards: 70 (16) [Apr 5 17:35:44] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 7: Contact: ;flow-id=1 (61) [Apr 5 17:35:44] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 8: P-Key-Flags: resolution="31x13", keys="4" (41) [Apr 5 17:35:44] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 9: User-Agent: snom360/6.5.8 (25) [Apr 5 17:35:44] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 10: Accept: application/sdp (23) [Apr 5 17:35:44] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 11: Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO (88) [Apr 5 17:35:44] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 12: Allow-Events: talk, hold, refer (31) [Apr 5 17:35:44] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 13: Supported: timer, 100rel, replaces, callerid (44) [Apr 5 17:35:44] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 14: Session-Expires: 3600;refresher=uas (35) [Apr 5 17:35:44] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 15: Min-SE: 90 (10) [Apr 5 17:35:44] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 16: Content-Type: application/sdp (29) [Apr 5 17:35:44] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 17: Content-Length: 477 (19) [Apr 5 17:35:44] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 18: (0) [Apr 5 17:35:44] DEBUG[3742]: chan_sip.c:4605 parse_request: Line: v=0 (3) [Apr 5 17:35:44] DEBUG[3742]: chan_sip.c:4605 parse_request: Line: o=root 1859181628 1859181631 IN IP4 192.168.4.109 (49) [Apr 5 17:35:44] DEBUG[3742]: chan_sip.c:4605 parse_request: Line: s=call (6) [Apr 5 17:35:44] DEBUG[3742]: chan_sip.c:4605 parse_request: Line: c=IN IP4 192.168.4.109 (22) [Apr 5 17:35:44] DEBUG[3742]: chan_sip.c:4605 parse_request: Line: t=0 0 (5) [Apr 5 17:35:44] DEBUG[3742]: chan_sip.c:4605 parse_request: Line: m=audio 11122 RTP/AVP 0 8 9 2 3 18 4 101 (40) [Apr 5 17:35:44] DEBUG[3742]: chan_sip.c:4605 parse_request: Line: a=crypto:1 AES_CM_128_HMAC_SHA1_32 inline:Pnx6rrLRgebm371hdmd56XzObUjxF47Nsc3j1fM2 (82) [Apr 5 17:35:44] DEBUG[3742]: chan_sip.c:4605 parse_request: Line: a=rtpmap:0 pcmu/8000 (20) [Apr 5 17:35:44] DEBUG[3742]: chan_sip.c:4605 parse_request: Line: a=rtpmap:8 pcma/8000 (20) [Apr 5 17:35:44] DEBUG[3742]: chan_sip.c:4605 parse_request: Line: a=rtpmap:9 g722/8000 (20) [Apr 5 17:35:44] DEBUG[3742]: chan_sip.c:4605 parse_request: Line: a=rtpmap:2 g726-32/8000 (23) [Apr 5 17:35:44] DEBUG[3742]: chan_sip.c:4605 parse_request: Line: a=rtpmap:3 gsm/8000 (19) [Apr 5 17:35:44] DEBUG[3742]: chan_sip.c:4605 parse_request: Line: a=rtpmap:18 g729/8000 (21) [Apr 5 17:35:44] DEBUG[3742]: chan_sip.c:4605 parse_request: Line: a=rtpmap:4 g723/8000 (20) [Apr 5 17:35:44] DEBUG[3742]: chan_sip.c:4605 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [Apr 5 17:35:44] DEBUG[3742]: chan_sip.c:4605 parse_request: Line: a=fmtp:101 0-16 (15) [Apr 5 17:35:44] DEBUG[3742]: chan_sip.c:4605 parse_request: Line: a=ptime:20 (10) [Apr 5 17:35:44] DEBUG[3742]: chan_sip.c:4605 parse_request: Line: a=encryption:optional (21) [Apr 5 17:35:44] --- (18 headers 19 lines) --- [Apr 5 17:35:44] DEBUG[3742]: chan_sip.c:14633 handle_request: **** Received INVITE (5) - Command in SIP INVITE [Apr 5 17:35:44] Sending to 192.168.4.109 : 2051 (NAT) [Apr 5 17:35:44] Found RTP audio format 0 [Apr 5 17:35:44] Found RTP audio format 8 [Apr 5 17:35:44] Found RTP audio format 9 [Apr 5 17:35:44] Found RTP audio format 2 [Apr 5 17:35:44] Found RTP audio format 3 [Apr 5 17:35:44] Found RTP audio format 18 [Apr 5 17:35:44] Found RTP audio format 4 [Apr 5 17:35:44] Found RTP audio format 101 [Apr 5 17:35:44] DEBUG[3742]: chan_sip.c:4899 process_sdp: Peer doesn't provide T.38 UDPTL [Apr 5 17:35:44] Peer audio RTP is at port 192.168.4.109:11122 [Apr 5 17:35:44] Got unsupported a:crypto in SDP offer [Apr 5 17:35:44] Found description format pcmu for ID 0 [Apr 5 17:35:44] Found description format pcma for ID 8 [Apr 5 17:35:44] Found description format g722 for ID 9 [Apr 5 17:35:44] Found description format g726-32 for ID 2 [Apr 5 17:35:44] Found description format gsm for ID 3 [Apr 5 17:35:44] Found description format g729 for ID 18 [Apr 5 17:35:44] Found description format g723 for ID 4 [Apr 5 17:35:44] Found description format telephone-event for ID 101 [Apr 5 17:35:44] Got unsupported a:fmtp in SDP offer [Apr 5 17:35:44] DEBUG[3742]: chan_sip.c:5129 process_sdp: T38 state changed to 0 on channel SIP/103-081e3c90 [Apr 5 17:35:44] Capabilities: us - 0x4 (ulaw), peer - audio=0x190f (g723|gsm|ulaw|alaw|g726|g729|g722)/video=0x0 (nothing), combined - 0x4 (ulaw) [Apr 5 17:35:44] Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) [Apr 5 17:35:44] Peer audio RTP is at port 192.168.4.109:11122 [Apr 5 17:35:44] DEBUG[3742]: chan_sip.c:5209 process_sdp: We're settling with these formats: 0x4 (ulaw) [Apr 5 17:35:44] DEBUG[3742]: chan_sip.c:5216 process_sdp: We have an owner, now see if we need to change this call [Apr 5 17:35:44] DEBUG[3742]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/103 [Apr 5 17:35:44] DEBUG[3742]: chan_sip.c:13454 handle_request_invite: Got a SIP re-invite for call 7dab6c18398aeb4169270c7f2093dafd@192.168.4.14 [Apr 5 17:35:44] DEBUG[3742]: chan_sip.c:13549 handle_request_invite: SIP/103-081e3c90: This call is UP.... [Apr 5 17:35:44] DEBUG[3742]: chan_sip.c:6420 transmit_response_with_sdp: Setting framing from config on incoming call [Apr 5 17:35:44] DEBUG[3742]: chan_sip.c:6188 add_sdp: ** Our capability: 0x4 (ulaw) Video flag: True [Apr 5 17:35:44] DEBUG[3742]: chan_sip.c:6189 add_sdp: ** Our prefcodec: 0x4 (ulaw) [Apr 5 17:35:45] Audio is at 192.168.4.14 port 18062 [Apr 5 17:35:45] Adding codec 0x4 (ulaw) to SDP [Apr 5 17:35:45] Adding non-codec 0x1 (telephone-event) to SDP [Apr 5 17:35:45] DEBUG[3742]: chan_sip.c:6320 add_sdp: -- Done with adding codecs to SDP [Apr 5 17:35:45] DEBUG[3742]: chan_sip.c:6365 add_sdp: Done building SDP. Settling with this capability: 0x4 (ulaw) [Apr 5 17:35:45] <--- Reliably Transmitting (NAT) to 192.168.4.109:2051 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.4.109:2051;branch=z9hG4bK-yk0nn3azfwtx;received=192.168.4.109;rport=2051 From: ;tag=b0vl6ge5e3 To: "unknown" ;tag=as67a477eb Call-ID: 7dab6c18398aeb4169270c7f2093dafd@192.168.4.14 CSeq: 2 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Type: application/sdp Content-Length: 238 v=0 o=root 3720 3722 IN IP4 192.168.4.14 s=session c=IN IP4 192.168.4.14 t=0 0 m=audio 18062 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv <------------> [Apr 5 17:35:45] DEBUG[3742]: chan_sip.c:1975 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #41 [Apr 5 17:35:45] -- Stopped music on hold on SIP/101-081df580 [Apr 5 17:35:45] DEBUG[3754]: channel.c:2845 set_format: Set channel SIP/101-081df580 to write format ulaw [Apr 5 17:35:45] DEBUG[3754]: channel.c:1997 ast_settimeout: Scheduling timer at 0 sample intervals [Apr 5 17:35:45] DEBUG[3725]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 103 [Apr 5 17:35:45] DEBUG[3725]: chan_sip.c:15244 sip_devicestate: Checking device state for peer 103 [Apr 5 17:35:45] DEBUG[3725]: devicestate.c:287 do_state_change: Changing state for SIP/103 - state 2 (In use) [Apr 5 17:35:45] DEBUG[3725]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 103 [Apr 5 17:35:45] DEBUG[3725]: chan_sip.c:15244 sip_devicestate: Checking device state for peer 103 [Apr 5 17:35:45] DEBUG[3763]: app_queue.c:546 changethread: Device 'SIP/103' changed to state '2' (In use) but we don't care because they're not a member of any queue. [Apr 5 17:35:45] <--- SIP read from 192.168.4.109:2051 ---> ACK sip:101@192.168.4.14 SIP/2.0 Via: SIP/2.0/UDP 192.168.4.109:2051;branch=z9hG4bK-bkjll4ue4xtv;rport From: ;tag=b0vl6ge5e3 To: "unknown" ;tag=as67a477eb Call-ID: 7dab6c18398aeb4169270c7f2093dafd@192.168.4.14 CSeq: 2 ACK Max-Forwards: 70 Contact: ;flow-id=1 Content-Length: 0 <-------------> [Apr 5 17:35:45] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 0: ACK sip:101@192.168.4.14 SIP/2.0 (32) [Apr 5 17:35:45] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.4.109:2051;branch=z9hG4bK-bkjll4ue4xtv;rport (69) [Apr 5 17:35:45] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 2: From: ;tag=b0vl6ge5e3 (63) [Apr 5 17:35:45] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 3: To: "unknown" ;tag=as67a477eb (51) [Apr 5 17:35:45] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 4: Call-ID: 7dab6c18398aeb4169270c7f2093dafd@192.168.4.14 (54) [Apr 5 17:35:45] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 5: CSeq: 2 ACK (11) [Apr 5 17:35:45] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 6: Max-Forwards: 70 (16) [Apr 5 17:35:45] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 7: Contact: ;flow-id=1 (61) [Apr 5 17:35:45] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 8: Content-Length: 0 (17) [Apr 5 17:35:45] --- (9 headers 0 lines) --- [Apr 5 17:35:45] DEBUG[3742]: chan_sip.c:14633 handle_request: **** Received ACK (6) - Command in SIP ACK [Apr 5 17:35:45] DEBUG[3742]: chan_sip.c:2079 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #41 [Apr 5 17:35:45] DEBUG[3742]: chan_sip.c:2089 __sip_ack: Stopping retransmission on '7dab6c18398aeb4169270c7f2093dafd@192.168.4.14' of Response 2: Match Not Found [Apr 5 17:35:45] DEBUG[3754]: rtp.c:873 ast_rtcp_read: Got RTCP report of 52 bytes core show hintssip show inuse * User name In use Limit * Peer name In use Limit 103 1/0 2 102 0/0 2 101 1/0 2 *CLI> sip show inusecore show hints[Apr 5 17:35:50] DEBUG[3754]: rtp.c:873 ast_rtcp_read: Got RTCP report of 52 bytes -= Registered Asterisk Dial Plan Hints =- 103@from-sip : SIP/103 State:InUse Watchers 0 102@from-sip : SIP/102 State:Idle Watchers 0 101@from-sip : SIP/101 State:InUse Watchers 0 ---------------- - 3 hints registered *CLI> [Apr 5 17:35:55] <--- SIP read from 192.168.4.109:2051 ---> BYE sip:101@192.168.4.14 SIP/2.0 Via: SIP/2.0/UDP 192.168.4.109:2051;branch=z9hG4bK-rz8d8xuqhudo;rport From: ;tag=b0vl6ge5e3 To: "unknown" ;tag=as67a477eb Call-ID: 7dab6c18398aeb4169270c7f2093dafd@192.168.4.14 CSeq: 3 BYE Max-Forwards: 70 Contact: ;flow-id=1 User-Agent: snom360/6.5.8 RTP-RxStat: Total_Rx_Pkts=0,Rx_Pkts=0,Rx_Pkts_Lost=1,Remote_Rx_Pkts_Lost=0 RTP-TxStat: Total_Tx_Pkts=1388,Tx_Pkts=466,Remote_Tx_Pkts=0 Content-Length: 0 <-------------> [Apr 5 17:35:55] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 0: BYE sip:101@192.168.4.14 SIP/2.0 (32) [Apr 5 17:35:55] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.4.109:2051;branch=z9hG4bK-rz8d8xuqhudo;rport (69) [Apr 5 17:35:55] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 2: From: ;tag=b0vl6ge5e3 (63) [Apr 5 17:35:55] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 3: To: "unknown" ;tag=as67a477eb (51) [Apr 5 17:35:55] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 4: Call-ID: 7dab6c18398aeb4169270c7f2093dafd@192.168.4.14 (54) [Apr 5 17:35:55] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 5: CSeq: 3 BYE (11) [Apr 5 17:35:55] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 6: Max-Forwards: 70 (16) [Apr 5 17:35:55] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 7: Contact: ;flow-id=1 (61) [Apr 5 17:35:55] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 8: User-Agent: snom360/6.5.8 (25) [Apr 5 17:35:55] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 9: RTP-RxStat: Total_Rx_Pkts=0,Rx_Pkts=0,Rx_Pkts_Lost=1,Remote_Rx_Pkts_Lost=0 (74) [Apr 5 17:35:55] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 10: RTP-TxStat: Total_Tx_Pkts=1388,Tx_Pkts=466,Remote_Tx_Pkts=0 (59) [Apr 5 17:35:55] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 11: Content-Length: 0 (17) [Apr 5 17:35:55] --- (12 headers 0 lines) --- [Apr 5 17:35:55] DEBUG[3742]: chan_sip.c:14633 handle_request: **** Received BYE (8) - Command in SIP BYE [Apr 5 17:35:55] Sending to 192.168.4.109 : 2051 (NAT) [Apr 5 17:35:55] DEBUG[3742]: chan_sip.c:1633 sip_alreadygone: Setting SIP_ALREADYGONE on dialog 7dab6c18398aeb4169270c7f2093dafd@192.168.4.14 [Apr 5 17:35:55] DEBUG[3742]: chan_sip.c:14190 handle_request_bye: Received bye, issuing owner hangup [Apr 5 17:35:55] <--- Transmitting (NAT) to 192.168.4.109:2051 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.4.109:2051;branch=z9hG4bK-rz8d8xuqhudo;received=192.168.4.109;rport=2051 From: ;tag=b0vl6ge5e3 To: "unknown" ;tag=as67a477eb Call-ID: 7dab6c18398aeb4169270c7f2093dafd@192.168.4.14 CSeq: 3 BYE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Length: 0 <------------> [Apr 5 17:35:55] DEBUG[3754]: rtp.c:3088 bridge_p2p_loop: Oooh, got a hangup [Apr 5 17:35:55] DEBUG[3754]: channel.c:4048 ast_channel_bridge: Returning from native bridge, channels: SIP/101-081df580, SIP/103-081e3c90 [Apr 5 17:35:55] DEBUG[3754]: channel.c:1693 ast_hangup: Hanging up channel 'SIP/103-081e3c90' [Apr 5 17:35:55] DEBUG[3754]: chan_sip.c:3312 sip_hangup: Hangup call SIP/103-081e3c90, SIP callid 7dab6c18398aeb4169270c7f2093dafd@192.168.4.14) [Apr 5 17:35:55] DEBUG[3754]: chan_sip.c:3321 sip_hangup: update_call_counter(103) - decrement call limit counter on hangup [Apr 5 17:35:55] DEBUG[3754]: chan_sip.c:3003 update_call_counter: Updating call counter for outgoing call [Apr 5 17:35:55] DEBUG[3754]: chan_sip.c:3051 update_call_counter: Call to peer '103' removed from call limit 2 [Apr 5 17:35:55] DEBUG[3754]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/103 [Apr 5 17:35:55] DEBUG[3754]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/103-081e3c90 [Apr 5 17:35:55] DEBUG[3754]: rtp.c:1476 ast_rtp_early_bridge: Channel '' has no RTP, not doing anything [Apr 5 17:35:55] DEBUG[3754]: app_dial.c:1670 dial_exec_full: Exiting with DIALSTATUS=ANSWER. [Apr 5 17:35:55] DEBUG[3754]: pbx.c:2393 __ast_pbx_run: Spawn extension (from-sip,103,3) exited non-zero on 'SIP/101-081df580' [Apr 5 17:35:55] == Spawn extension (from-sip, 103, 3) exited non-zero on 'SIP/101-081df580' [Apr 5 17:35:55] DEBUG[3754]: pbx.c:1648 pbx_substitute_variables_helper_full: Function result is '"unknown" <101>' [Apr 5 17:35:55] DEBUG[3754]: pbx.c:1648 pbx_substitute_variables_helper_full: Function result is '101' [Apr 5 17:35:55] DEBUG[3754]: pbx.c:1648 pbx_substitute_variables_helper_full: Function result is '103' [Apr 5 17:35:55] DEBUG[3754]: pbx.c:1648 pbx_substitute_variables_helper_full: Function result is 'from-sip' [Apr 5 17:35:55] DEBUG[3754]: pbx.c:1648 pbx_substitute_variables_helper_full: Function result is 'SIP/101-081df580' [Apr 5 17:35:55] DEBUG[3754]: pbx.c:1648 pbx_substitute_variables_helper_full: Function result is 'SIP/103-081e3c90' [Apr 5 17:35:55] DEBUG[3754]: pbx.c:1648 pbx_substitute_variables_helper_full: Function result is 'Dial' [Apr 5 17:35:55] DEBUG[3754]: pbx.c:1648 pbx_substitute_variables_helper_full: Function result is 'SIP/103' [Apr 5 17:35:55] DEBUG[3754]: pbx.c:1648 pbx_substitute_variables_helper_full: Function result is '2007-04-05 17:35:11' [Apr 5 17:35:55] DEBUG[3754]: pbx.c:1648 pbx_substitute_variables_helper_full: Function result is '2007-04-05 17:35:15' [Apr 5 17:35:55] DEBUG[3754]: pbx.c:1648 pbx_substitute_variables_helper_full: Function result is '2007-04-05 17:35:55' [Apr 5 17:35:55] DEBUG[3754]: pbx.c:1648 pbx_substitute_variables_helper_full: Function result is '44' [Apr 5 17:35:55] DEBUG[3754]: pbx.c:1648 pbx_substitute_variables_helper_full: Function result is '40' [Apr 5 17:35:55] DEBUG[3754]: pbx.c:1648 pbx_substitute_variables_helper_full: Function result is 'ANSWERED' [Apr 5 17:35:55] DEBUG[3754]: pbx.c:1648 pbx_substitute_variables_helper_full: Function result is 'DOCUMENTATION' [Apr 5 17:35:55] DEBUG[3754]: pbx.c:1648 pbx_substitute_variables_helper_full: Function result is '' [Apr 5 17:35:55] DEBUG[3754]: pbx.c:1648 pbx_substitute_variables_helper_full: Function result is '1175787311.0' [Apr 5 17:35:55] DEBUG[3754]: pbx.c:1648 pbx_substitute_variables_helper_full: Function result is '' [Apr 5 17:35:55] DEBUG[3754]: channel.c:1693 ast_hangup: Hanging up channel 'SIP/101-081df580' [Apr 5 17:35:55] DEBUG[3754]: chan_sip.c:3312 sip_hangup: Hangup call SIP/101-081df580, SIP callid E481A37A-80BD-45DC-90AB-A3A3450A476F@192.168.4.11) [Apr 5 17:35:55] DEBUG[3754]: chan_sip.c:3321 sip_hangup: update_call_counter(101) - decrement call limit counter on hangup [Apr 5 17:35:55] DEBUG[3754]: chan_sip.c:3003 update_call_counter: Updating call counter for incoming call [Apr 5 17:35:55] DEBUG[3754]: chan_sip.c:3051 update_call_counter: Call from peer '101' removed from call limit 2 [Apr 5 17:35:55] DEBUG[3754]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/101 [Apr 5 17:35:55] Scheduling destruction of SIP dialog 'E481A37A-80BD-45DC-90AB-A3A3450A476F@192.168.4.11' in 320 ms (Method: ACK) [Apr 5 17:35:55] DEBUG[3754]: chan_sip.c:5643 reqprep: Strict routing enforced for session E481A37A-80BD-45DC-90AB-A3A3450A476F@192.168.4.11 [Apr 5 17:35:55] set_destination: Parsing for address/port to send to [Apr 5 17:35:55] set_destination: set destination to 192.168.4.11, port 5060 [Apr 5 17:35:55] Reliably Transmitting (NAT) to 192.168.4.11:5060: BYE sip:101@192.168.4.11:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.4.14:5060;branch=z9hG4bK060037e2;rport From: ;tag=as453198ae To: "unknown";tag=3492175015678 Call-ID: E481A37A-80BD-45DC-90AB-A3A3450A476F@192.168.4.11 CSeq: 102 BYE User-Agent: Asterisk PBX Max-Forwards: 70 Content-Length: 0 --- [Apr 5 17:35:55] DEBUG[3754]: chan_sip.c:1975 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #43 [Apr 5 17:35:55] DEBUG[3754]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/101-081df580 [Apr 5 17:35:55] DEBUG[3725]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 103 [Apr 5 17:35:55] DEBUG[3725]: chan_sip.c:15244 sip_devicestate: Checking device state for peer 103 [Apr 5 17:35:55] <--- SIP read from 192.168.4.11:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.4.14:5060;rport=5060;received=192.168.4.14;branch=z9hG4bK060037e2 Content-Length: 0 Call-ID: E481A37A-80BD-45DC-90AB-A3A3450A476F@192.168.4.11 CSeq: 102 BYE From: ;tag=as453198ae Server: SJphone/1.60.289a (SJ Labs) To: "unknown";tag=3492175015678 <-------------> [Apr 5 17:35:55] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 0: SIP/2.0 200 OK (14) [Apr 5 17:35:55] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.4.14:5060;rport=5060;received=192.168.4.14;branch=z9hG4bK060037e2 (90) [Apr 5 17:35:55] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 2: Content-Length: 0 (17) [Apr 5 17:35:55] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 3: Call-ID: E481A37A-80BD-45DC-90AB-A3A3450A476F@192.168.4.11 (58) [Apr 5 17:35:55] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 4: CSeq: 102 BYE (13) [Apr 5 17:35:55] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 5: From: ;tag=as453198ae (48) [Apr 5 17:35:55] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 6: Server: SJphone/1.60.289a (SJ Labs) (35) [Apr 5 17:35:55] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 7: To: "unknown";tag=3492175015678 (58) [Apr 5 17:35:55] --- (8 headers 0 lines) --- [Apr 5 17:35:55] DEBUG[3742]: chan_sip.c:2079 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #43 [Apr 5 17:35:55] DEBUG[3742]: chan_sip.c:2089 __sip_ack: Stopping retransmission on 'E481A37A-80BD-45DC-90AB-A3A3450A476F@192.168.4.11' of Request 102: Match Not Found [Apr 5 17:35:55] SIP Response message for INCOMING dialog BYE arrived [Apr 5 17:35:55] Really destroying SIP dialog '7dab6c18398aeb4169270c7f2093dafd@192.168.4.14' Method: BYE [Apr 5 17:35:55] Really destroying SIP dialog 'E481A37A-80BD-45DC-90AB-A3A3450A476F@192.168.4.11' Method: ACK [Apr 5 17:35:55] DEBUG[3725]: devicestate.c:287 do_state_change: Changing state for SIP/103 - state 1 (Not in use) [Apr 5 17:35:55] DEBUG[3725]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 103 [Apr 5 17:35:55] DEBUG[3725]: chan_sip.c:15244 sip_devicestate: Checking device state for peer 103 [Apr 5 17:35:55] DEBUG[3725]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 103 [Apr 5 17:35:55] DEBUG[3725]: chan_sip.c:15244 sip_devicestate: Checking device state for peer 103 [Apr 5 17:35:55] DEBUG[3725]: devicestate.c:287 do_state_change: Changing state for SIP/103 - state 1 (Not in use) [Apr 5 17:35:55] DEBUG[3725]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 103 [Apr 5 17:35:55] DEBUG[3725]: chan_sip.c:15244 sip_devicestate: Checking device state for peer 103 [Apr 5 17:35:55] DEBUG[3725]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 101 [Apr 5 17:35:55] DEBUG[3725]: chan_sip.c:15244 sip_devicestate: Checking device state for peer 101 [Apr 5 17:35:55] DEBUG[3725]: devicestate.c:287 do_state_change: Changing state for SIP/101 - state 1 (Not in use) [Apr 5 17:35:55] DEBUG[3725]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 101 [Apr 5 17:35:55] DEBUG[3725]: chan_sip.c:15244 sip_devicestate: Checking device state for peer 101 [Apr 5 17:35:55] DEBUG[3725]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 101 [Apr 5 17:35:55] DEBUG[3725]: chan_sip.c:15244 sip_devicestate: Checking device state for peer 101 [Apr 5 17:35:55] DEBUG[3725]: devicestate.c:287 do_state_change: Changing state for SIP/101 - state 1 (Not in use) [Apr 5 17:35:55] DEBUG[3725]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 101 [Apr 5 17:35:55] DEBUG[3725]: chan_sip.c:15244 sip_devicestate: Checking device state for peer 101 [Apr 5 17:35:55] DEBUG[3764]: app_queue.c:546 changethread: Device 'SIP/103' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Apr 5 17:35:55] DEBUG[3765]: app_queue.c:546 changethread: Device 'SIP/103' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Apr 5 17:35:55] DEBUG[3766]: app_queue.c:546 changethread: Device 'SIP/101' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Apr 5 17:35:55] DEBUG[3767]: app_queue.c:546 changethread: Device 'SIP/101' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. stopcore show hints[Apr 5 17:36:01] <--- SIP read from 192.168.4.11:5060 ---> OPTIONS sip:192.168.4.14:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.4.11;rport;branch=z9hG4bKc0a8040b0000001046151753000032e100000011 Content-Length: 0 Call-ID: 2EF9B8A4-663E-4346-9FB3-0460AAC4AB1C@192.168.4.11 CSeq: 2 OPTIONS From: ;tag=3497095326530 Max-Forwards: 70 To: <-------------> [Apr 5 17:36:01] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 0: OPTIONS sip:192.168.4.14:5060 SIP/2.0 (37) [Apr 5 17:36:01] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.4.11;rport;branch=z9hG4bKc0a8040b0000001046151753000032e100000011 (90) [Apr 5 17:36:01] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 2: Content-Length: 0 (17) [Apr 5 17:36:01] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 3: Call-ID: 2EF9B8A4-663E-4346-9FB3-0460AAC4AB1C@192.168.4.11 (58) [Apr 5 17:36:01] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 4: CSeq: 2 OPTIONS (15) [Apr 5 17:36:01] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 5: From: ;tag=3497095326530 (51) [Apr 5 17:36:01] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 6: Max-Forwards: 70 (16) [Apr 5 17:36:01] DEBUG[3742]: chan_sip.c:4573 parse_request: Header 7: To: (27) [Apr 5 17:36:01] --- (8 headers 0 lines) --- [Apr 5 17:36:01] DEBUG[3742]: chan_sip.c:4310 sip_alloc: Allocating new SIP dialog for 2EF9B8A4-663E-4346-9FB3-0460AAC4AB1C@192.168.4.11 - OPTIONS (No RTP) [Apr 5 17:36:01] DEBUG[3742]: chan_sip.c:14633 handle_request: **** Received OPTIONS (3) - Command in SIP OPTIONS [Apr 5 17:36:01] Looking for s in default (domain 192.168.4.14) [Apr 5 17:36:01] <--- Transmitting (no NAT) to 192.168.4.11:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.4.11;branch=z9hG4bKc0a8040b0000001046151753000032e100000011;received=192.168.4.11;rport=5060 From: ;tag=3497095326530 To: ;tag=as77869c06 Call-ID: 2EF9B8A4-663E-4346-9FB3-0460AAC4AB1C@192.168.4.11 CSeq: 2 OPTIONS User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Accept: application/sdp Content-Length: 0 <------------> [Apr 5 17:36:01] Scheduling destruction of SIP dialog '2EF9B8A4-663E-4346-9FB3-0460AAC4AB1C@192.168.4.11' in 32000 ms (Method: OPTIONS) sip show inuse * User name In use Limit * Peer name In use Limit 103 0/0 2 102 0/0 2 101 0/0 2 *CLI> sip show inusecore show hints -= Registered Asterisk Dial Plan Hints =- 103@from-sip : SIP/103 State:Idle Watchers 0 102@from-sip : SIP/102 State:Idle Watchers 0 101@from-sip : SIP/101 State:Idle Watchers 0 ---------------- - 3 hints registered *CLI> stop now [Apr 5 17:36:05] Beginning asterisk shutdown.... [Apr 5 17:36:05] Executing last minute cleanups [Apr 5 17:36:05] == Destroying musiconhold processes [Apr 5 17:36:05] Asterisk cleanly ending (0). [Apr 5 17:36:05] DEBUG[3720]: asterisk.c:1276 quit_handler: Asterisk ending (0).