[Apr 13 17:40:41] <--- SIP read from UDP:192.168.1.50:5060 ---> [Apr 13 17:40:41] INVITE sip:101@192.168.1.50:5060 SIP/2.0 [Apr 13 17:40:41] Record-Route: [Apr 13 17:40:41] Via: SIP/2.0/UDP 192.168.1.50;branch=z9hG4bKa44e.dc8ec5aef25d82484e2ba84632b99261.0 [Apr 13 17:40:41] Via: SIP/2.0/UDP 192.168.1.15:45060;branch=z9hG4bK-10038-1-0 [Apr 13 17:40:41] From: ;tag=1 [Apr 13 17:40:41] To: [Apr 13 17:40:41] Call-ID: 1-10038@192.168.1.15 [Apr 13 17:40:41] CSeq: 1 INVITE [Apr 13 17:40:41] X-null1: NULL [Apr 13 17:40:41] X-null2: NULL [Apr 13 17:40:41] Contact: sip:+49211123456@192.168.1.15:45060 [Apr 13 17:40:41] Max-Forwards: 69 [Apr 13 17:40:41] User-Agent: SIPp [Apr 13 17:40:41] Content-Type: application/sdp [Apr 13 17:40:41] Content-Length: 215 [Apr 13 17:40:41] [Apr 13 17:40:41] v=0 [Apr 13 17:40:41] o=user1 53655765 2353687637 IN IP4 192.168.1.15 [Apr 13 17:40:41] s=- [Apr 13 17:40:41] c=IN IP4 192.168.1.15 [Apr 13 17:40:41] t=0 0 [Apr 13 17:40:41] m=audio 65000 RTP/AVP 8 101 [Apr 13 17:40:41] a=rtpmap:8 PCMA/8000 [Apr 13 17:40:41] a=rtpmap:101 telephone-event/8000 [Apr 13 17:40:41] a=fmtp:101 0-11,16 [Apr 13 17:40:41] a=direction:active [Apr 13 17:40:41] <-------------> [Apr 13 17:40:41] DEBUG[2493]: chan_sip.c:9622 parse_request: Header 0 [ 40]: INVITE sip:101@192.168.1.50:5060 SIP/2.0 [Apr 13 17:40:41] DEBUG[2493]: chan_sip.c:9622 parse_request: Header 1 [ 42]: Record-Route: [Apr 13 17:40:41] DEBUG[2493]: chan_sip.c:9622 parse_request: Header 2 [ 83]: Via: SIP/2.0/UDP 192.168.1.50;branch=z9hG4bKa44e.dc8ec5aef25d82484e2ba84632b99261.0 [Apr 13 17:40:41] DEBUG[2493]: chan_sip.c:9622 parse_request: Header 3 [ 60]: Via: SIP/2.0/UDP 192.168.1.15:45060;branch=z9hG4bK-10038-1-0 [Apr 13 17:40:41] DEBUG[2493]: chan_sip.c:9622 parse_request: Header 4 [ 48]: From: ;tag=1 [Apr 13 17:40:41] DEBUG[2493]: chan_sip.c:9622 parse_request: Header 5 [ 31]: To: [Apr 13 17:40:41] DEBUG[2493]: chan_sip.c:9622 parse_request: Header 6 [ 29]: Call-ID: 1-10038@192.168.1.15 [Apr 13 17:40:41] DEBUG[2493]: chan_sip.c:9622 parse_request: Header 7 [ 14]: CSeq: 1 INVITE [Apr 13 17:40:41] DEBUG[2493]: chan_sip.c:9622 parse_request: Header 8 [ 13]: X-null1: NULL [Apr 13 17:40:41] DEBUG[2493]: chan_sip.c:9622 parse_request: Header 9 [ 13]: X-null2: NULL [Apr 13 17:40:41] DEBUG[2493]: chan_sip.c:9622 parse_request: Header 10 [ 44]: Contact: sip:+49211123456@192.168.1.15:45060 [Apr 13 17:40:41] DEBUG[2493]: chan_sip.c:9622 parse_request: Header 11 [ 16]: Max-Forwards: 69 [Apr 13 17:40:41] DEBUG[2493]: chan_sip.c:9622 parse_request: Header 12 [ 16]: User-Agent: SIPp [Apr 13 17:40:41] DEBUG[2493]: chan_sip.c:9622 parse_request: Header 13 [ 29]: Content-Type: application/sdp [Apr 13 17:40:41] DEBUG[2493]: chan_sip.c:9622 parse_request: Header 14 [ 19]: Content-Length: 215 [Apr 13 17:40:41] DEBUG[2493]: chan_sip.c:9622 parse_request: Header 15 [ 0]: [Apr 13 17:40:41] DEBUG[2493]: chan_sip.c:9622 parse_request: Body 0 [ 3]: v=0 [Apr 13 17:40:41] DEBUG[2493]: chan_sip.c:9622 parse_request: Body 1 [ 47]: o=user1 53655765 2353687637 IN IP4 192.168.1.15 [Apr 13 17:40:41] DEBUG[2493]: chan_sip.c:9622 parse_request: Body 2 [ 3]: s=- [Apr 13 17:40:41] DEBUG[2493]: chan_sip.c:9622 parse_request: Body 3 [ 21]: c=IN IP4 192.168.1.15 [Apr 13 17:40:41] DEBUG[2493]: chan_sip.c:9622 parse_request: Body 4 [ 5]: t=0 0 [Apr 13 17:40:41] DEBUG[2493]: chan_sip.c:9622 parse_request: Body 5 [ 27]: m=audio 65000 RTP/AVP 8 101 [Apr 13 17:40:41] DEBUG[2493]: chan_sip.c:9622 parse_request: Body 6 [ 20]: a=rtpmap:8 PCMA/8000 [Apr 13 17:40:41] DEBUG[2493]: chan_sip.c:9622 parse_request: Body 7 [ 33]: a=rtpmap:101 telephone-event/8000 [Apr 13 17:40:41] DEBUG[2493]: chan_sip.c:9622 parse_request: Body 8 [ 18]: a=fmtp:101 0-11,16 [Apr 13 17:40:41] DEBUG[2493]: chan_sip.c:9659 parse_request: Body 9 [ 18]: a=direction:active [Apr 13 17:40:41] --- (15 headers 10 lines) --- [Apr 13 17:40:41] DEBUG[2493]: chan_sip.c:9162 __find_call: = Looking for Call ID: 1-10038@192.168.1.15 (Checking From) --From tag 1 --To-tag [Apr 13 17:40:41] DEBUG[2493]: acl.c:946 ast_ouraddrfor: For destination '192.168.1.50', our source address is '192.168.1.100'. [Apr 13 17:40:41] DEBUG[2493]: chan_sip.c:3853 ast_sip_ouraddrfor: Setting AST_TRANSPORT_UDP with address 192.168.1.100:5060 [Apr 13 17:40:41] DEBUG[2493]: netsock2.c:172 ast_sockaddr_split_hostport: Splitting '192.168.1.50' into... [Apr 13 17:40:41] DEBUG[2493]: netsock2.c:226 ast_sockaddr_split_hostport: ...host '192.168.1.50' and port ''. [Apr 13 17:40:41] Sending to 192.168.1.50:5060 (no NAT) [Apr 13 17:40:41] DEBUG[2493]: chan_sip.c:8749 __sip_alloc: Allocating new SIP dialog for 1-10038@192.168.1.15 - INVITE (No RTP) [Apr 13 17:40:41] DEBUG[2493][C-0000021b]: chan_sip.c:27991 handle_incoming: **** Received INVITE (5) - Command in SIP INVITE [Apr 13 17:40:41] DEBUG[2493][C-0000021b]: netsock2.c:172 ast_sockaddr_split_hostport: Splitting '192.168.1.50' into... [Apr 13 17:40:41] DEBUG[2493][C-0000021b]: netsock2.c:226 ast_sockaddr_split_hostport: ...host '192.168.1.50' and port ''. [Apr 13 17:40:41] Sending to 192.168.1.50:5060 (no NAT) [Apr 13 17:40:41] DEBUG[2493][C-0000021b]: chan_sip.c:25441 handle_request_invite: Initializing initreq for method INVITE - callid 1-10038@192.168.1.15 [Apr 13 17:40:41] Using INVITE request as basis request - 1-10038@192.168.1.15 [Apr 13 17:40:41] DEBUG[2493][C-0000021b]: netsock2.c:172 ast_sockaddr_split_hostport: Splitting '192.168.1.50:5060' into... [Apr 13 17:40:41] DEBUG[2493][C-0000021b]: netsock2.c:226 ast_sockaddr_split_hostport: ...host '192.168.1.50' and port ''. [Apr 13 17:40:41] DEBUG[2493][C-0000021b]: res_config_odbc.c:113 custom_prepare: Skip: 0; SQL: SELECT * FROM sipfriends WHERE name = ? AND host = ? [Apr 13 17:40:41] DEBUG[2493][C-0000021b]: res_config_odbc.c:129 custom_prepare: Parameter 1 ('name') = '+49211123456' [Apr 13 17:40:41] DEBUG[2493][C-0000021b]: res_config_odbc.c:129 custom_prepare: Parameter 2 ('host') = 'dynamic' [Apr 13 17:40:41] DEBUG[2493][C-0000021b]: res_odbc.c:1057 odbc_release_obj2: odbc_release_obj2(0x2473e44) called (obj->txf = (nil)) [Apr 13 17:40:41] DEBUG[2493][C-0000021b]: res_config_odbc.c:113 custom_prepare: Skip: 0; SQL: SELECT * FROM sipfriends WHERE name = ? [Apr 13 17:40:41] DEBUG[2493][C-0000021b]: res_config_odbc.c:129 custom_prepare: Parameter 1 ('name') = '+49211123456' [Apr 13 17:40:41] DEBUG[2493][C-0000021b]: res_odbc.c:1057 odbc_release_obj2: odbc_release_obj2(0x2473e44) called (obj->txf = (nil)) [Apr 13 17:40:41] DEBUG[2493][C-0000021b]: res_config_odbc.c:113 custom_prepare: Skip: 0; SQL: SELECT * FROM sipfriends WHERE host = ? AND callbackextension = ? AND port = ? [Apr 13 17:40:41] DEBUG[2493][C-0000021b]: res_config_odbc.c:129 custom_prepare: Parameter 1 ('host') = '192.168.1.50' [Apr 13 17:40:41] DEBUG[2493][C-0000021b]: res_config_odbc.c:129 custom_prepare: Parameter 2 ('callbackextension') = '101' [Apr 13 17:40:41] DEBUG[2493][C-0000021b]: res_config_odbc.c:129 custom_prepare: Parameter 3 ('port') = '5060' [Apr 13 17:40:41] DEBUG[2493][C-0000021b]: res_odbc.c:1057 odbc_release_obj2: odbc_release_obj2(0x2473e44) called (obj->txf = (nil)) [Apr 13 17:40:41] DEBUG[2493][C-0000021b]: res_config_odbc.c:113 custom_prepare: Skip: 0; SQL: SELECT * FROM sipfriends WHERE host = ? AND port = ? [Apr 13 17:40:41] DEBUG[2493][C-0000021b]: res_config_odbc.c:129 custom_prepare: Parameter 1 ('host') = '192.168.1.50' [Apr 13 17:40:41] DEBUG[2493][C-0000021b]: res_config_odbc.c:129 custom_prepare: Parameter 2 ('port') = '5060' [Apr 13 17:40:41] DEBUG[2493][C-0000021b]: res_odbc.c:1057 odbc_release_obj2: odbc_release_obj2(0x2473e44) called (obj->txf = (nil)) [Apr 13 17:40:41] DEBUG[2493][C-0000021b]: res_config_odbc.c:113 custom_prepare: Skip: 0; SQL: SELECT * FROM sipfriends WHERE ipaddr = ? AND port = ? [Apr 13 17:40:41] DEBUG[2493][C-0000021b]: res_config_odbc.c:129 custom_prepare: Parameter 1 ('ipaddr') = '192.168.1.50' [Apr 13 17:40:41] DEBUG[2493][C-0000021b]: res_config_odbc.c:129 custom_prepare: Parameter 2 ('port') = '5060' [Apr 13 17:40:41] DEBUG[2493][C-0000021b]: res_odbc.c:1057 odbc_release_obj2: odbc_release_obj2(0x2473e44) called (obj->txf = (nil)) [Apr 13 17:40:41] DEBUG[2493][C-0000021b]: res_config_odbc.c:113 custom_prepare: Skip: 0; SQL: SELECT * FROM sipfriends WHERE host = ? AND insecure LIKE ? ORDER BY host [Apr 13 17:40:41] DEBUG[2493][C-0000021b]: res_config_odbc.c:129 custom_prepare: Parameter 1 ('host') = '192.168.1.50' [Apr 13 17:40:41] DEBUG[2493][C-0000021b]: res_config_odbc.c:129 custom_prepare: Parameter 2 ('insecure LIKE') = '%port%' [Apr 13 17:40:41] DEBUG[2493][C-0000021b]: res_odbc.c:1057 odbc_release_obj2: odbc_release_obj2(0x2473e44) called (obj->txf = (nil)) [Apr 13 17:40:41] DEBUG[2493][C-0000021b]: res_config_odbc.c:113 custom_prepare: Skip: 0; SQL: SELECT * FROM sipfriends WHERE ipaddr = ? AND insecure LIKE ? ORDER BY ipaddr [Apr 13 17:40:41] DEBUG[2493][C-0000021b]: res_config_odbc.c:129 custom_prepare: Parameter 1 ('ipaddr') = '192.168.1.50' [Apr 13 17:40:41] DEBUG[2493][C-0000021b]: res_config_odbc.c:129 custom_prepare: Parameter 2 ('insecure LIKE') = '%port%' [Apr 13 17:40:41] DEBUG[2493][C-0000021b]: res_odbc.c:1057 odbc_release_obj2: odbc_release_obj2(0x2473e44) called (obj->txf = (nil)) [Apr 13 17:40:41] DEBUG[2493][C-0000021b]: res_config_odbc.c:113 custom_prepare: Skip: 0; SQL: SELECT * FROM sipfriends WHERE host = ? AND port = ? [Apr 13 17:40:41] DEBUG[2493][C-0000021b]: res_config_odbc.c:129 custom_prepare: Parameter 1 ('host') = '192.168.1.50' [Apr 13 17:40:41] DEBUG[2493][C-0000021b]: res_config_odbc.c:129 custom_prepare: Parameter 2 ('port') = '5060' [Apr 13 17:40:41] DEBUG[2493][C-0000021b]: res_odbc.c:1057 odbc_release_obj2: odbc_release_obj2(0x2473e44) called (obj->txf = (nil)) [Apr 13 17:40:41] DEBUG[2493][C-0000021b]: res_config_odbc.c:113 custom_prepare: Skip: 0; SQL: SELECT * FROM sipfriends WHERE ipaddr = ? AND port = ? [Apr 13 17:40:41] DEBUG[2493][C-0000021b]: res_config_odbc.c:129 custom_prepare: Parameter 1 ('ipaddr') = '192.168.1.50' [Apr 13 17:40:41] DEBUG[2493][C-0000021b]: res_config_odbc.c:129 custom_prepare: Parameter 2 ('port') = '5060' [Apr 13 17:40:41] DEBUG[2493][C-0000021b]: res_odbc.c:1057 odbc_release_obj2: odbc_release_obj2(0x2473e44) called (obj->txf = (nil)) [Apr 13 17:40:41] DEBUG[2493][C-0000021b]: res_config_odbc.c:113 custom_prepare: Skip: 0; SQL: SELECT * FROM sipfriends WHERE host = ? AND insecure LIKE ? ORDER BY host [Apr 13 17:40:41] DEBUG[2493][C-0000021b]: res_config_odbc.c:129 custom_prepare: Parameter 1 ('host') = '192.168.1.50' [Apr 13 17:40:41] DEBUG[2493][C-0000021b]: res_config_odbc.c:129 custom_prepare: Parameter 2 ('insecure LIKE') = '%port%' [Apr 13 17:40:41] DEBUG[2493][C-0000021b]: res_odbc.c:1057 odbc_release_obj2: odbc_release_obj2(0x2473e44) called (obj->txf = (nil)) [Apr 13 17:40:41] DEBUG[2493][C-0000021b]: res_config_odbc.c:113 custom_prepare: Skip: 0; SQL: SELECT * FROM sipfriends WHERE ipaddr = ? AND insecure LIKE ? ORDER BY ipaddr [Apr 13 17:40:41] DEBUG[2493][C-0000021b]: res_config_odbc.c:129 custom_prepare: Parameter 1 ('ipaddr') = '192.168.1.50' [Apr 13 17:40:41] DEBUG[2493][C-0000021b]: res_config_odbc.c:129 custom_prepare: Parameter 2 ('insecure LIKE') = '%port%' [Apr 13 17:40:41] DEBUG[2493][C-0000021b]: res_odbc.c:1057 odbc_release_obj2: odbc_release_obj2(0x2473e44) called (obj->txf = (nil)) [Apr 13 17:40:41] No matching peer for '+49211123456' from '192.168.1.50:5060' [Apr 13 17:40:41] DEBUG[2493][C-0000021b]: rtp_engine.c:421 ast_rtp_instance_new: Using engine 'asterisk' for RTP instance '0x75f0e014' [Apr 13 17:40:41] DEBUG[2493][C-0000021b]: res_rtp_asterisk.c:2437 ast_rtp_new: Allocated port 16518 for RTP instance '0x75f0e014' [Apr 13 17:40:41] DEBUG[2493][C-0000021b]: rtp_engine.c:430 ast_rtp_instance_new: RTP instance '0x75f0e014' is setup and ready to go [Apr 13 17:40:41] DEBUG[2493][C-0000021b]: res_rtp_asterisk.c:4682 ast_rtp_prop_set: Setup RTCP on RTP instance '0x75f0e014' [Apr 13 17:40:41] DEBUG[2493][C-0000021b]: chan_sip.c:5589 do_setnat: Setting NAT on RTP to Off [Apr 13 17:40:41] DEBUG[2493][C-0000021b]: chan_sip.c:10000 process_sdp: Processing session-level SDP v=0... UNSUPPORTED OR FAILED. [Apr 13 17:40:41] DEBUG[2493][C-0000021b]: chan_sip.c:10000 process_sdp: Processing session-level SDP o=user1 53655765 2353687637 IN IP4 192.168.1.15... OK. [Apr 13 17:40:41] DEBUG[2493][C-0000021b]: chan_sip.c:10000 process_sdp: Processing session-level SDP s=-... UNSUPPORTED OR FAILED. [Apr 13 17:40:41] DEBUG[2493][C-0000021b]: netsock2.c:172 ast_sockaddr_split_hostport: Splitting '192.168.1.15' into... [Apr 13 17:40:41] DEBUG[2493][C-0000021b]: netsock2.c:226 ast_sockaddr_split_hostport: ...host '192.168.1.15' and port ''. [Apr 13 17:40:41] DEBUG[2493][C-0000021b]: chan_sip.c:10000 process_sdp: Processing session-level SDP c=IN IP4 192.168.1.15... OK. [Apr 13 17:40:41] DEBUG[2493][C-0000021b]: chan_sip.c:10000 process_sdp: Processing session-level SDP t=0 0... UNSUPPORTED OR FAILED. [Apr 13 17:40:41] Found RTP audio format 8 [Apr 13 17:40:41] DEBUG[2493][C-0000021b]: rtp_engine.c:664 ast_rtp_codecs_payloads_set_m_type: Setting payload 8 (0x26c8764) based on m type on 0x74afa2c4 [Apr 13 17:40:41] Found RTP audio format 101 [Apr 13 17:40:41] DEBUG[2493][C-0000021b]: rtp_engine.c:664 ast_rtp_codecs_payloads_set_m_type: Setting payload 101 (0x246ebc4) based on m type on 0x74afa2c4 [Apr 13 17:40:41] Found audio description format PCMA for ID 8 [Apr 13 17:40:41] DEBUG[2493][C-0000021b]: chan_sip.c:10455 process_sdp: Processing media-level (audio) SDP a=rtpmap:8 PCMA/8000... OK. [Apr 13 17:40:41] Found audio description format telephone-event for ID 101 [Apr 13 17:40:41] DEBUG[2493][C-0000021b]: chan_sip.c:10455 process_sdp: Processing media-level (audio) SDP a=rtpmap:101 telephone-event/8000... OK. [Apr 13 17:40:41] DEBUG[2493][C-0000021b]: chan_sip.c:10455 process_sdp: Processing media-level (audio) SDP a=fmtp:101 0-11,16... UNSUPPORTED OR FAILED. [Apr 13 17:40:41] DEBUG[2493][C-0000021b]: chan_sip.c:10455 process_sdp: Processing media-level (audio) SDP a=direction:active... UNSUPPORTED OR FAILED. [Apr 13 17:40:41] Capabilities: us - (g722|alaw|ulaw|speex|g726|g726aal2|gsm), peer - audio=(alaw)/video=(nothing)/text=(nothing), combined - (alaw) [Apr 13 17:40:41] Non-codec capabilities (dtmf): us - 0x1 (telephone-event|), peer - 0x1 (telephone-event|), combined - 0x1 (telephone-event|) [Apr 13 17:40:41] DEBUG[2493][C-0000021b]: res_rtp_asterisk.c:4737 ast_rtp_remote_address_set: Setting RTCP address on RTP instance '0x75f0e014' [Apr 13 17:40:41] Peer audio RTP is at port 192.168.1.15:65000 [Apr 13 17:40:41] DEBUG[2493][C-0000021b]: rtp_engine.c:626 ast_rtp_codecs_payloads_copy: Copying payload 8 (0x24a43b4) from 0x74afa2c4 to 0x75f0e1c0 [Apr 13 17:40:41] DEBUG[2493][C-0000021b]: rtp_engine.c:626 ast_rtp_codecs_payloads_copy: Copying payload 101 (0x26c8764) from 0x74afa2c4 to 0x75f0e1c0 [Apr 13 17:40:41] DEBUG[2493][C-0000021b]: res_rtp_asterisk.c:4648 ast_rtp_prop_set: Ignoring duplicate RTCP property on RTP instance '0x75f0e014' [Apr 13 17:40:41] DEBUG[2493][C-0000021b]: chan_sip.c:10745 process_sdp: We're settling with these formats: (alaw) [Apr 13 17:40:41] DEBUG[2493][C-0000021b]: chan_sip.c:25570 handle_request_invite: Checking SIP call limits for device [Apr 13 17:40:41] DEBUG[2493][C-0000021b]: chan_sip.c:6546 update_call_counter: Updating call counter for incoming call [Apr 13 17:40:41] DEBUG[2493][C-0000021b]: netsock2.c:172 ast_sockaddr_split_hostport: Splitting '192.168.1.50:5060' into... [Apr 13 17:40:41] DEBUG[2493][C-0000021b]: netsock2.c:226 ast_sockaddr_split_hostport: ...host '192.168.1.50' and port ''. [Apr 13 17:40:41] DEBUG[2493][C-0000021b]: netsock2.c:172 ast_sockaddr_split_hostport: Splitting '192.168.1.50:5060' into... [Apr 13 17:40:41] DEBUG[2493][C-0000021b]: netsock2.c:226 ast_sockaddr_split_hostport: ...host '192.168.1.50' and port ''. [Apr 13 17:40:41] Looking for 101 in public (domain 192.168.1.50) [Apr 13 17:40:41] [Apr 13 17:40:41] <--- Reliably Transmitting (no NAT) to 192.168.1.50:5060 ---> [Apr 13 17:40:41] SIP/2.0 404 Not Found [Apr 13 17:40:41] Via: SIP/2.0/UDP 192.168.1.50;branch=z9hG4bKa44e.dc8ec5aef25d82484e2ba84632b99261.0;received=192.168.1.50 [Apr 13 17:40:41] Via: SIP/2.0/UDP 192.168.1.15:45060;branch=z9hG4bK-10038-1-0 [Apr 13 17:40:41] From: ;tag=1 [Apr 13 17:40:41] To: ;tag=as25024be0 [Apr 13 17:40:41] Call-ID: 1-10038@192.168.1.15 [Apr 13 17:40:41] CSeq: 1 INVITE [Apr 13 17:40:41] Server: DUS-bSBC-1 [Apr 13 17:40:41] Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE [Apr 13 17:40:41] Supported: replaces, timer [Apr 13 17:40:41] Content-Length: 0 [Apr 13 17:40:41] [Apr 13 17:40:41] [Apr 13 17:40:41] <------------> [Apr 13 17:40:41] DEBUG[2493][C-0000021b]: chan_sip.c:4161 __sip_reliable_xmit: *** SIP TIMER: Initializing retransmit timer on packet: Id #5389 [Apr 13 17:40:41] DEBUG[2493][C-0000021b]: chan_sip.c:3696 __sip_xmit: Trying to put 'SIP/2.0 404' onto UDP socket destined for 192.168.1.50:5060 [Apr 13 17:40:41] NOTICE[2493][C-0000021b]: chan_sip.c:25617 handle_request_invite: Call from '' (192.168.1.50:5060) to extension '101' rejected because extension not found in context 'public'. [Apr 13 17:40:41] DEBUG[2493][C-0000021b]: chan_sip.c:6546 update_call_counter: Updating call counter for incoming call [Apr 13 17:40:41] Scheduling destruction of SIP dialog '1-10038@192.168.1.15' in 12800 ms (Method: INVITE) [Apr 13 17:40:41] [Apr 13 17:40:41] <--- SIP read from UDP:192.168.1.50:5060 ---> [Apr 13 17:40:41] ACK sip:101@192.168.1.50:5060 SIP/2.0 [Apr 13 17:40:41] Record-Route: [Apr 13 17:40:41] Via: SIP/2.0/UDP 192.168.1.50;branch=z9hG4bKa44e.dc8ec5aef25d82484e2ba84632b99261.0 [Apr 13 17:40:41] Via: SIP/2.0/UDP 192.168.1.15:45060;branch=z9hG4bK-10038-1-0 [Apr 13 17:40:41] From: ;tag=1 [Apr 13 17:40:41] To: ;tag=as25024be0 [Apr 13 17:40:41] Call-ID: 1-10038@192.168.1.15 [Apr 13 17:40:41] CSeq: 1 ACK [Apr 13 17:40:41] Contact: [Apr 13 17:40:41] Max-Forwards: 69 [Apr 13 17:40:41] Subject: Performance Test [Apr 13 17:40:41] Content-Length: 0 [Apr 13 17:40:41] [Apr 13 17:40:41] <-------------> [Apr 13 17:40:41] DEBUG[2493]: chan_sip.c:9622 parse_request: Header 0 [ 37]: ACK sip:101@192.168.1.50:5060 SIP/2.0 [Apr 13 17:40:41] DEBUG[2493]: chan_sip.c:9622 parse_request: Header 1 [ 42]: Record-Route: [Apr 13 17:40:41] DEBUG[2493]: chan_sip.c:9622 parse_request: Header 2 [ 83]: Via: SIP/2.0/UDP 192.168.1.50;branch=z9hG4bKa44e.dc8ec5aef25d82484e2ba84632b99261.0 [Apr 13 17:40:41] DEBUG[2493]: chan_sip.c:9622 parse_request: Header 3 [ 60]: Via: SIP/2.0/UDP 192.168.1.15:45060;branch=z9hG4bK-10038-1-0 [Apr 13 17:40:41] DEBUG[2493]: chan_sip.c:9622 parse_request: Header 4 [ 48]: From: ;tag=1 [Apr 13 17:40:41] DEBUG[2493]: chan_sip.c:9622 parse_request: Header 5 [ 46]: To: ;tag=as25024be0 [Apr 13 17:40:41] DEBUG[2493]: chan_sip.c:9622 parse_request: Header 6 [ 29]: Call-ID: 1-10038@192.168.1.15 [Apr 13 17:40:41] DEBUG[2493]: chan_sip.c:9622 parse_request: Header 7 [ 11]: CSeq: 1 ACK [Apr 13 17:40:41] DEBUG[2493]: chan_sip.c:9622 parse_request: Header 8 [ 52]: Contact: [Apr 13 17:40:41] DEBUG[2493]: chan_sip.c:9622 parse_request: Header 9 [ 16]: Max-Forwards: 69 [Apr 13 17:40:41] DEBUG[2493]: chan_sip.c:9622 parse_request: Header 10 [ 25]: Subject: Performance Test [Apr 13 17:40:41] DEBUG[2493]: chan_sip.c:9622 parse_request: Header 11 [ 17]: Content-Length: 0 [Apr 13 17:40:41] --- (12 headers 0 lines) --- [Apr 13 17:40:41] DEBUG[2493]: chan_sip.c:9162 __find_call: = Looking for Call ID: 1-10038@192.168.1.15 (Checking From) --From tag 1 --To-tag as25024be0 [Apr 13 17:40:41] DEBUG[2493][C-0000021b]: chan_sip.c:27991 handle_incoming: **** Received ACK (6) - Command in SIP ACK [Apr 13 17:40:41] DEBUG[2493][C-0000021b]: chan_sip.c:4360 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #5389 [Apr 13 17:40:41] DEBUG[2493][C-0000021b]: chan_sip.c:4393 __sip_ack: Stopping retransmission on '1-10038@192.168.1.15' of Response 1: Match Found [Apr 13 17:40:41] DEBUG[2493]: chan_sip.c:6694 sip_destroy: Destroying SIP dialog 1-10038@192.168.1.15 [Apr 13 17:40:41] Really destroying SIP dialog '1-10038@192.168.1.15' Method: ACK [Apr 13 17:40:41] DEBUG[2493]: rtp_engine.c:364 instance_destructor: Destroyed RTP instance '0x75f0e014' SBC*CLI> Disconnected from Asterisk server [Apr 13 17:41:05] Asterisk cleanly ending (0). [Apr 13 17:41:05] Executing last minute cleanups