[Oct 12 16:13:54] Asterisk 13.17.2 built by root @ lord.nyrd.ru on a amd64 running FreeBSD on 2017-10-09 05:31:32 UTC [Oct 12 16:14:15] VERBOSE[102118] res_pjsip_logger.c: <--- Received SIP request (679 bytes) from UDP:192.168.51.136:5060 ---> REGISTER sip:10.124.1.1 SIP/2.0 Via: SIP/2.0/UDP 192.168.51.136:5060;branch=z9hG4bK6f00f100a448077 From: ;tag=6f00f100a4 To: sip:700@10.124.1.1 Call-ID: 6f010000-e91e-f167-8000-0002a404d88e@192.168.51.136 CSeq: 48077 REGISTER Date: Thu, 15 Jan 2011 16:35:02 GMT User-Agent: AddPac SIP Gateway Authorization: Digest username="700", realm="asterisk", nonce="1507806807/6b8aacba6823a3f91caf4af81f3eef4d", opaque="47cef1fa6370ba90", uri="sip:10.124.1.1", qop=auth, nc=0000a4d6, cnonce="b3a8aa4e", response="4053e38a0cfbfee6e80a11d51f799a0c", algorithm=MD5 Contact: ;expires=59 Expires: 59 Content-Length: 0 Max-Forwards: 70 [Oct 12 16:14:15] DEBUG[102118] netsock2.c: Splitting '192.168.51.136:5060' into... [Oct 12 16:14:15] DEBUG[102118] netsock2.c: ...host '192.168.51.136' and port '5060'. [Oct 12 16:14:15] DEBUG[102118] netsock2.c: Splitting '192.168.51.50:5060' into... [Oct 12 16:14:15] DEBUG[102118] netsock2.c: ...host '192.168.51.50' and port '5060'. [Oct 12 16:14:15] DEBUG[102118] res_pjsip/pjsip_distributor.c: Could not find matching transaction for Request msg REGISTER/cseq=48077 (rdata0x804830028) [Oct 12 16:14:15] DEBUG[102118] res_pjsip/pjsip_distributor.c: Calculated serializer pjsip/distributor-00000035 to use for Request msg REGISTER/cseq=48077 (rdata0x804830028) [Oct 12 16:14:15] DEBUG[100631] netsock2.c: Splitting '192.168.51.136' into... [Oct 12 16:14:15] DEBUG[100631] netsock2.c: ...host '192.168.51.136' and port ''. [Oct 12 16:14:15] DEBUG[100631] res_pjsip_endpoint_identifier_ip.c: Source address 192.168.51.136:5060 does not match identify 'rc_identify' [Oct 12 16:14:15] DEBUG[100631] res_pjsip_endpoint_identifier_ip.c: Source address 192.168.51.136:5060 does not match identify 'zadarma' [Oct 12 16:14:15] DEBUG[100631] res_pjsip_endpoint_identifier_ip.c: Identify checks by IP address failed to find match: '192.168.51.136:5060' did not match any identify section rules [Oct 12 16:14:15] DEBUG[100631] res_pjsip_endpoint_identifier_user.c: Attempting identify by From username '700' domain '10.124.1.1' [Oct 12 16:14:15] DEBUG[100631] res_pjsip_endpoint_identifier_user.c: Identified by From username '700' domain '10.124.1.1' [Oct 12 16:14:15] DEBUG[100631] res_pjsip_authenticator_digest.c: Using default realm 'asterisk' on incoming auth '700'. [Oct 12 16:14:15] DEBUG[100631] netsock2.c: Splitting '10.124.1.1' into... [Oct 12 16:14:15] DEBUG[100631] netsock2.c: ...host '10.124.1.1' and port ''. [Oct 12 16:14:15] DEBUG[100631] netsock2.c: Splitting '192.168.51.136' into... [Oct 12 16:14:15] DEBUG[100631] netsock2.c: ...host '192.168.51.136' and port ''. [Oct 12 16:14:15] DEBUG[100631] netsock2.c: Splitting '192.168.51.50:5060' into... [Oct 12 16:14:15] DEBUG[100631] netsock2.c: ...host '192.168.51.50' and port '5060'. [Oct 12 16:14:15] DEBUG[100631] netsock2.c: Splitting '192.168.51.136:5060' into... [Oct 12 16:14:15] DEBUG[100631] netsock2.c: ...host '192.168.51.136' and port '5060'. [Oct 12 16:14:15] VERBOSE[100631] res_pjsip_logger.c: <--- Transmitting SIP response (511 bytes) to UDP:192.168.51.136:5060 ---> SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 192.168.51.136:5060;rport=5060;received=192.168.51.136;branch=z9hG4bK6f00f100a448077 Call-ID: 6f010000-e91e-f167-8000-0002a404d88e@192.168.51.136 From: ;tag=6f00f100a4 To: ;tag=z9hG4bK6f00f100a448077 CSeq: 48077 REGISTER WWW-Authenticate: Digest realm="asterisk",nonce="1507806855/8982ed2e9a314d4a247d5aca0ea4f05b",opaque="7de8b89639af0214",stale=true,algorithm=md5,qop="auth" Server: lord.nyrd.ru Content-Length: 0 [Oct 12 16:14:15] VERBOSE[102118] res_pjsip_logger.c: <--- Received SIP request (679 bytes) from UDP:192.168.51.136:5060 ---> REGISTER sip:10.124.1.1 SIP/2.0 Via: SIP/2.0/UDP 192.168.51.136:5060;branch=z9hG4bK6f00f100a448078 From: ;tag=6f00f100a4 To: sip:700@10.124.1.1 Call-ID: 6f010000-e91e-f167-8000-0002a404d88e@192.168.51.136 CSeq: 48078 REGISTER Date: Thu, 15 Jan 2011 16:35:02 GMT User-Agent: AddPac SIP Gateway Authorization: Digest username="700", realm="asterisk", nonce="1507806855/8982ed2e9a314d4a247d5aca0ea4f05b", opaque="7de8b89639af0214", uri="sip:10.124.1.1", qop=auth, nc=0000a4d7, cnonce="201d53bf", response="918014ae83afe8fd0d734e748bd74e95", algorithm=MD5 Contact: ;expires=59 Expires: 59 Content-Length: 0 Max-Forwards: 70 [Oct 12 16:14:15] DEBUG[102118] netsock2.c: Splitting '192.168.51.136:5060' into... [Oct 12 16:14:15] DEBUG[102118] netsock2.c: ...host '192.168.51.136' and port '5060'. [Oct 12 16:14:15] DEBUG[102118] netsock2.c: Splitting '192.168.51.50:5060' into... [Oct 12 16:14:15] DEBUG[102118] netsock2.c: ...host '192.168.51.50' and port '5060'. [Oct 12 16:14:15] DEBUG[102118] res_pjsip/pjsip_distributor.c: Could not find matching transaction for Request msg REGISTER/cseq=48078 (rdata0x804830028) [Oct 12 16:14:15] DEBUG[102118] res_pjsip/pjsip_distributor.c: Calculated serializer pjsip/distributor-00000035 to use for Request msg REGISTER/cseq=48078 (rdata0x804830028) [Oct 12 16:14:15] DEBUG[102381] netsock2.c: Splitting '192.168.51.136' into... [Oct 12 16:14:15] DEBUG[102381] netsock2.c: ...host '192.168.51.136' and port ''. [Oct 12 16:14:15] DEBUG[102381] res_pjsip_endpoint_identifier_ip.c: Source address 192.168.51.136:5060 does not match identify 'rc_identify' [Oct 12 16:14:15] DEBUG[102381] res_pjsip_endpoint_identifier_ip.c: Source address 192.168.51.136:5060 does not match identify 'zadarma' [Oct 12 16:14:15] DEBUG[102381] res_pjsip_endpoint_identifier_ip.c: Identify checks by IP address failed to find match: '192.168.51.136:5060' did not match any identify section rules [Oct 12 16:14:15] DEBUG[102381] res_pjsip_endpoint_identifier_user.c: Attempting identify by From username '700' domain '10.124.1.1' [Oct 12 16:14:15] DEBUG[102381] res_pjsip_endpoint_identifier_user.c: Identified by From username '700' domain '10.124.1.1' [Oct 12 16:14:15] DEBUG[102381] res_pjsip_authenticator_digest.c: Using default realm 'asterisk' on incoming auth '700'. [Oct 12 16:14:15] DEBUG[102381] res_pjsip_authenticator_digest.c: Calculated nonce 1507806855/8982ed2e9a314d4a247d5aca0ea4f05b. Actual nonce is 1507806855/8982ed2e9a314d4a247d5aca0ea4f05b [Oct 12 16:14:15] DEBUG[102381] netsock2.c: Splitting '10.124.1.1' into... [Oct 12 16:14:15] DEBUG[102381] netsock2.c: ...host '10.124.1.1' and port ''. [Oct 12 16:14:15] DEBUG[102381] netsock2.c: Splitting '192.168.51.136' into... [Oct 12 16:14:15] DEBUG[102381] netsock2.c: ...host '192.168.51.136' and port ''. [Oct 12 16:14:15] DEBUG[102381] res_pjsip_registrar.c: Matched id '700' to aor '700' [Oct 12 16:14:15] DEBUG[102381] res_pjsip_registrar.c: Matched aor '700' by To username [Oct 12 16:14:15] DEBUG[102381] config.c: extract double from [3.0] in [-inf, inf] gives [3.000000](0) [Oct 12 16:14:15] DEBUG[102381] config.c: extract uint from [0] in [0, 4294967295] gives [0](0) [Oct 12 16:14:15] DEBUG[102381] config.c: extract double from [3.000000] in [-inf, inf] gives [3.000000](0) [Oct 12 16:14:15] DEBUG[102381] config.c: extract uint from [5060] in [0, 4294967295] gives [5060](0) [Oct 12 16:14:15] DEBUG[102381] config.c: extract uint from [0] in [0, 86400] gives [0](0) [Oct 12 16:14:15] DEBUG[102381] config.c: extract double from [3.0] in [-inf, inf] gives [3.000000](0) [Oct 12 16:14:15] DEBUG[102381] config.c: extract uint from [0] in [0, 4294967295] gives [0](0) [Oct 12 16:14:15] DEBUG[102381] config.c: extract double from [3.000000] in [-inf, inf] gives [3.000000](0) [Oct 12 16:14:15] DEBUG[102381] config.c: extract uint from [5060] in [0, 4294967295] gives [5060](0) [Oct 12 16:14:15] DEBUG[102381] config.c: extract uint from [0] in [0, 86400] gives [0](0) [Oct 12 16:14:15] DEBUG[102381] res_pjsip_registrar.c: Refreshed contact 'sip:700@192.168.51.136' on AOR '700' with new expiration of 60 seconds [Oct 12 16:14:15] DEBUG[102124] config.c: extract uint from [3] in [0, 4294967295] gives [3](0) [Oct 12 16:14:15] DEBUG[102124] config.c: extract uint from [0] in [0, 4294967295] gives [0](0) [Oct 12 16:14:15] DEBUG[102124] config.c: extract uint from [2] in [0, 4294967295] gives [2](0) [Oct 12 16:14:15] DEBUG[102096] threadpool.c: Increasing threadpool stasis-core's size by 1 [Oct 12 16:14:15] DEBUG[102381] config.c: extract double from [3.0] in [-inf, inf] gives [3.000000](0) [Oct 12 16:14:15] DEBUG[102381] config.c: extract uint from [0] in [0, 4294967295] gives [0](0) [Oct 12 16:14:15] DEBUG[102381] config.c: extract double from [3.000000] in [-inf, inf] gives [3.000000](0) [Oct 12 16:14:15] DEBUG[102381] config.c: extract uint from [5060] in [0, 4294967295] gives [5060](0) [Oct 12 16:14:15] DEBUG[102381] config.c: extract uint from [0] in [0, 86400] gives [0](0) [Oct 12 16:14:15] DEBUG[102381] netsock2.c: Splitting '192.168.51.50:5060' into... [Oct 12 16:14:15] DEBUG[102381] netsock2.c: ...host '192.168.51.50' and port '5060'. [Oct 12 16:14:15] DEBUG[102381] netsock2.c: Splitting '192.168.51.136:5060' into... [Oct 12 16:14:15] DEBUG[102381] netsock2.c: ...host '192.168.51.136' and port '5060'. [Oct 12 16:14:15] VERBOSE[102381] res_pjsip_logger.c: <--- Transmitting SIP response (439 bytes) to UDP:192.168.51.136:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.51.136:5060;rport=5060;received=192.168.51.136;branch=z9hG4bK6f00f100a448078 Call-ID: 6f010000-e91e-f167-8000-0002a404d88e@192.168.51.136 From: ;tag=6f00f100a4 To: ;tag=z9hG4bK6f00f100a448078 CSeq: 48078 REGISTER Date: Thu, 12 Oct 2017 11:14:15 GMT Contact: ;expires=59 Expires: 60 Server: lord.nyrd.ru Content-Length: 0 [Oct 12 16:14:34] DEBUG[102156] res_pjsip_registrar_expire.c: Woke up at 1507806874 Interval: 30 [Oct 12 16:14:34] DEBUG[102156] res_pjsip_registrar_expire.c: Expiring 0 contacts [Oct 12 16:14:35] DEBUG[102663] threadpool.c: Worker thread idle timeout reached. Dying. [Oct 12 16:14:35] DEBUG[102096] threadpool.c: Destroying worker thread 6006 [Oct 12 16:14:40] VERBOSE[102118] res_pjsip_logger.c: <--- Received SIP request (561 bytes) from UDP:193.254.248.22:5060 ---> OPTIONS sip:000340@37.60.19.38:5060 SIP/2.0 Via: SIP/2.0/UDP 193.254.248.22:5060;branch=z9hG4bK3de27528 Max-Forwards: 70 From: "asterisk" ;tag=as6bddc611 To: Contact: Call-ID: 3a9e2cba1815d8a76769a78d427bbe2e@193.254.248.22:5060 CSeq: 102 OPTIONS User-Agent: Asterisk PBX 13.13.0 Date: Thu, 12 Oct 2017 11:14:40 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE Supported: replaces, timer Content-Length: 0 [Oct 12 16:14:40] DEBUG[102118] netsock2.c: Splitting '193.254.248.22:5060' into... [Oct 12 16:14:40] DEBUG[102118] netsock2.c: ...host '193.254.248.22' and port '5060'. [Oct 12 16:14:40] DEBUG[102118] netsock2.c: Splitting '37.60.19.38:5060' into... [Oct 12 16:14:40] DEBUG[102118] netsock2.c: ...host '37.60.19.38' and port '5060'. [Oct 12 16:14:40] DEBUG[102118] res_pjsip/pjsip_distributor.c: Could not find matching transaction for Request msg OPTIONS/cseq=102 (rdata0x80482e028) [Oct 12 16:14:40] DEBUG[102118] res_pjsip/pjsip_distributor.c: Calculated serializer pjsip/distributor-00000034 to use for Request msg OPTIONS/cseq=102 (rdata0x80482e028) [Oct 12 16:14:40] DEBUG[100631] netsock2.c: Splitting '193.254.248.22' into... [Oct 12 16:14:40] DEBUG[100631] netsock2.c: ...host '193.254.248.22' and port ''. [Oct 12 16:14:40] DEBUG[100631] res_pjsip_endpoint_identifier_ip.c: Source address 193.254.248.22:5060 matches identify 'rc_identify' [Oct 12 16:14:40] DEBUG[100631] res_pjsip_endpoint_identifier_ip.c: Retrieved endpoint rc_endpoint [Oct 12 16:14:40] DEBUG[100631] netsock2.c: Splitting '37.60.19.38:5060' into... [Oct 12 16:14:40] DEBUG[100631] netsock2.c: ...host '37.60.19.38' and port '5060'. [Oct 12 16:14:40] DEBUG[100631] netsock2.c: Splitting '193.254.248.22:5060' into... [Oct 12 16:14:40] DEBUG[100631] netsock2.c: ...host '193.254.248.22' and port '5060'. [Oct 12 16:14:40] VERBOSE[100631] res_pjsip_logger.c: <--- Transmitting SIP response (838 bytes) to UDP:193.254.248.22:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 193.254.248.22:5060;rport=5060;received=193.254.248.22;branch=z9hG4bK3de27528 Call-ID: 3a9e2cba1815d8a76769a78d427bbe2e@193.254.248.22:5060 From: "asterisk" ;tag=as6bddc611 To: ;tag=z9hG4bK3de27528 CSeq: 102 OPTIONS Accept: application/sdp, application/dialog-info+xml, application/pidf+xml, application/simple-message-summary, application/xpidf+xml, application/cpim-pidf+xml, application/pidf+xml, application/dialog-info+xml, application/simple-message-summary, message/sipfrag;version=2.0 Allow: OPTIONS, SUBSCRIBE, NOTIFY, PUBLISH, INVITE, ACK, BYE, CANCEL, UPDATE, PRACK, REGISTER, MESSAGE, REFER Supported: 100rel, timer, replaces, norefersub Accept-Encoding: text/plain Accept-Language: en Server: lord.nyrd.ru Content-Length: 0 [Oct 12 16:14:53] VERBOSE[102118] res_pjsip_logger.c: <--- Received SIP request (877 bytes) from UDP:193.254.248.22:5060 ---> INVITE sip:000340@37.60.19.38:5060 SIP/2.0 Via: SIP/2.0/UDP 193.254.248.22:5060;branch=z9hG4bK64f347ae Max-Forwards: 70 From: "320968" ;tag=as50c67fb2 To: Contact: Call-ID: 23f0fd773a26754935326966632e5e50@193.254.248.22:5060 CSeq: 102 INVITE User-Agent: Asterisk PBX 13.13.0 Date: Thu, 12 Oct 2017 11:14:53 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE Supported: replaces, timer Content-Type: application/sdp Content-Length: 291 v=0 o=root 1050155685 1050155685 IN IP4 193.254.248.22 s=Asterisk PBX 13.13.0 c=IN IP4 193.254.248.22 t=0 0 m=audio 17458 RTP/AVP 8 18 101 a=rtpmap:8 PCMA/8000 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=maxptime:150 a=sendrecv [Oct 12 16:14:53] DEBUG[102118] netsock2.c: Splitting '193.254.248.22:5060' into... [Oct 12 16:14:53] DEBUG[102118] netsock2.c: ...host '193.254.248.22' and port '5060'. [Oct 12 16:14:53] DEBUG[102118] netsock2.c: Splitting '37.60.19.38:5060' into... [Oct 12 16:14:53] DEBUG[102118] netsock2.c: ...host '37.60.19.38' and port '5060'. [Oct 12 16:14:53] DEBUG[102118] res_pjsip/pjsip_distributor.c: Could not find matching transaction for Request msg INVITE/cseq=102 (rdata0x80482e028) [Oct 12 16:14:53] DEBUG[102118] res_pjsip/pjsip_distributor.c: Calculated serializer pjsip/distributor-0000002e to use for Request msg INVITE/cseq=102 (rdata0x80482e028) [Oct 12 16:14:53] DEBUG[102381] netsock2.c: Splitting '193.254.248.22' into... [Oct 12 16:14:53] DEBUG[102381] netsock2.c: ...host '193.254.248.22' and port ''. [Oct 12 16:14:53] DEBUG[102381] res_pjsip_endpoint_identifier_ip.c: Source address 193.254.248.22:5060 matches identify 'rc_identify' [Oct 12 16:14:53] DEBUG[102381] res_pjsip_endpoint_identifier_ip.c: Retrieved endpoint rc_endpoint [Oct 12 16:14:53] DEBUG[102381] dsp.c: Setup tone 1100 Hz, 500 ms, block_size=160, hits_required=21 [Oct 12 16:14:53] DEBUG[102381] dsp.c: Setup tone 2100 Hz, 2600 ms, block_size=160, hits_required=116 [Oct 12 16:14:53] DEBUG[102381] res_pjsip/pjsip_distributor.c: Calculated serializer pjsip/distributor-0000002e to use for Request msg INVITE/cseq=102 (rdata0x806c37028) [Oct 12 16:14:53] DEBUG[102381] res_pjsip_session.c: Method is INVITE, Response is 100 Trying [Oct 12 16:14:53] DEBUG[102381] netsock2.c: Splitting '37.60.19.38:5060' into... [Oct 12 16:14:53] DEBUG[102381] netsock2.c: ...host '37.60.19.38' and port '5060'. [Oct 12 16:14:53] DEBUG[102381] netsock2.c: Splitting '193.254.248.22:5060' into... [Oct 12 16:14:53] DEBUG[102381] netsock2.c: ...host '193.254.248.22' and port '5060'. [Oct 12 16:14:53] VERBOSE[102381] res_pjsip_logger.c: <--- Transmitting SIP response (330 bytes) to UDP:193.254.248.22:5060 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 193.254.248.22:5060;rport=5060;received=193.254.248.22;branch=z9hG4bK64f347ae Call-ID: 23f0fd773a26754935326966632e5e50@193.254.248.22:5060 From: "320968" ;tag=as50c67fb2 To: CSeq: 102 INVITE Server: lord.nyrd.ru Content-Length: 0 [Oct 12 16:14:53] DEBUG[102381] res_pjsip_session.c: Function void session_inv_on_state_changed(pjsip_inv_session *, pjsip_event *) called on event TSX_STATE [Oct 12 16:14:53] DEBUG[102381] res_pjsip_session.c: The state change pertains to the endpoint 'rc_endpoint()' [Oct 12 16:14:53] DEBUG[102381] res_pjsip_session.c: The inv session still has an invite_tsx (0x81064d0a8) [Oct 12 16:14:53] DEBUG[102381] res_pjsip_session.c: There is no transaction involved in this state change [Oct 12 16:14:53] DEBUG[102381] res_pjsip_session.c: The current inv state is INCOMING [Oct 12 16:14:53] DEBUG[102381] res_pjsip_session.c: Source of transaction state change is TX_MSG [Oct 12 16:14:53] DEBUG[102381] res_pjsip_session.c: Function void session_inv_on_tsx_state_changed(pjsip_inv_session *, pjsip_transaction *, pjsip_event *) called on event TSX_STATE [Oct 12 16:14:53] DEBUG[102381] res_pjsip_session.c: The state change pertains to the endpoint 'rc_endpoint()' [Oct 12 16:14:53] DEBUG[102381] res_pjsip_session.c: The inv session still has an invite_tsx (0x81064d0a8) [Oct 12 16:14:53] DEBUG[102381] res_pjsip_session.c: The UAS INVITE transaction involved in this state change is 0x81064d0a8 [Oct 12 16:14:53] DEBUG[102381] res_pjsip_session.c: The current transaction state is Proceeding [Oct 12 16:14:53] DEBUG[102381] res_pjsip_session.c: The transaction state change event is TX_MSG [Oct 12 16:14:53] DEBUG[102381] res_pjsip_session.c: The current inv state is INCOMING [Oct 12 16:14:53] DEBUG[102381] res_pjsip_session.c: Negotiating incoming SDP media stream 'audio' using audio SDP handler [Oct 12 16:14:53] DEBUG[102381] netsock2.c: Splitting '193.254.248.22' into... [Oct 12 16:14:53] DEBUG[102381] netsock2.c: ...host '193.254.248.22' and port ''. [Oct 12 16:14:53] DEBUG[102381] netsock2.c: Splitting '37.60.19.38' into... [Oct 12 16:14:53] DEBUG[102381] netsock2.c: ...host '37.60.19.38' and port ''. [Oct 12 16:14:53] DEBUG[102381] res_pjsip_sdp_rtp.c: Endpoint rc_endpoint: Binding RTP media to 37.60.19.38 [Oct 12 16:14:53] DEBUG[102381] rtp_engine.c: Using engine 'asterisk' for RTP instance '0x806ea6030' [Oct 12 16:14:53] DEBUG[102381] res_rtp_asterisk.c: Allocated port 10468 for RTP instance '0x806ea6030' [Oct 12 16:14:53] DEBUG[102381] res_rtp_asterisk.c: Creating ICE session 37.60.19.38:10468 (10468) for RTP instance '0x806ea6030' [Oct 12 16:14:53] DEBUG[102381] netsock2.c: Splitting '192.168.124.1' into... [Oct 12 16:14:53] DEBUG[102381] netsock2.c: ...host '192.168.124.1' and port ''. [Oct 12 16:14:53] DEBUG[102381] netsock2.c: Splitting '192.168.124.1' into... [Oct 12 16:14:53] DEBUG[102381] netsock2.c: ...host '192.168.124.1' and port ''. [Oct 12 16:14:53] DEBUG[102381] netsock2.c: Splitting '37.60.19.38' into... [Oct 12 16:14:53] DEBUG[102381] netsock2.c: ...host '37.60.19.38' and port ''. [Oct 12 16:14:53] DEBUG[102381] netsock2.c: Splitting '37.60.19.38' into... [Oct 12 16:14:53] DEBUG[102381] netsock2.c: ...host '37.60.19.38' and port ''. [Oct 12 16:14:53] DEBUG[102381] netsock2.c: Splitting '192.168.51.50' into... [Oct 12 16:14:53] DEBUG[102381] netsock2.c: ...host '192.168.51.50' and port ''. [Oct 12 16:14:53] DEBUG[102381] netsock2.c: Splitting '192.168.51.50' into... [Oct 12 16:14:53] DEBUG[102381] netsock2.c: ...host '192.168.51.50' and port ''. [Oct 12 16:14:53] DEBUG[102381] netsock2.c: Splitting '10.229.10.10' into... [Oct 12 16:14:53] DEBUG[102381] netsock2.c: ...host '10.229.10.10' and port ''. [Oct 12 16:14:53] DEBUG[102381] netsock2.c: Splitting '10.229.10.10' into... [Oct 12 16:14:53] DEBUG[102381] netsock2.c: ...host '10.229.10.10' and port ''. [Oct 12 16:14:53] DEBUG[102381] rtp_engine.c: RTP instance '0x806ea6030' is setup and ready to go [Oct 12 16:14:53] DEBUG[102381] acl.c: Attached to given IP address [Oct 12 16:14:53] DEBUG[102381] res_rtp_asterisk.c: Setup RTCP on RTP instance '0x806ea6030' [Oct 12 16:14:53] DEBUG[102381] rtp_engine.c: Setting tx payload type 8 based on m type on 0x7fffdfb983d0 [Oct 12 16:14:53] DEBUG[102381] rtp_engine.c: Setting tx payload type 18 based on m type on 0x7fffdfb983d0 [Oct 12 16:14:53] DEBUG[102381] rtp_engine.c: Setting tx payload type 101 based on m type on 0x7fffdfb983d0 [Oct 12 16:14:53] DEBUG[102381] rtp_engine.c: Copying payload 8 (0x806eab528) from 0x7fffdfb983d0 to 0x806ea61f8 [Oct 12 16:14:53] DEBUG[102381] rtp_engine.c: Copying payload 18 (0x806eab618) from 0x7fffdfb983d0 to 0x806ea61f8 [Oct 12 16:14:53] DEBUG[102381] rtp_engine.c: Copying payload 101 (0x806eaba68) from 0x7fffdfb983d0 to 0x806ea61f8 [Oct 12 16:14:53] DEBUG[102381] res_pjsip_session.c: Media stream 'audio' handled by audio [Oct 12 16:14:53] DEBUG[102381] res_rtp_asterisk.c: Ignoring duplicate RTCP property on RTP instance '0x806ea6030' [Oct 12 16:14:53] DEBUG[102381] res_pjsip_t38.c: Not creating outgoing SDP stream: T.38 not enabled [Oct 12 16:14:53] DEBUG[102381] res_pjsip_session.c: Method is INVITE [Oct 12 16:14:53] DEBUG[102381] channel.c: Channel 0x806f1a030 'PJSIP/rc_endpoint-0000001d' allocated [Oct 12 16:14:53] DEBUG[102096] threadpool.c: Increasing threadpool stasis-core's size by 1 [Oct 12 16:14:53] DEBUG[102381] chan_pjsip.c: Started PBX on new PJSIP channel PJSIP/rc_endpoint-0000001d [Oct 12 16:14:53] DEBUG[102666][C-00000016] pbx.c: Launching 'NoOp' [Oct 12 16:14:53] DEBUG[102666][C-00000016] pbx.c: Launching 'ReceiveFAX' [Oct 12 16:14:53] DEBUG[102666][C-00000016] res_fax.c: Reserving a FAX session from 'Spandsp FAX Driver'. [Oct 12 16:14:53] DEBUG[102666][C-00000016] res_fax.c: Selected FAX technology module (Spandsp FAX Driver) does not support reserving sessions. [Oct 12 16:14:53] DEBUG[102107] devicestate.c: No provider found, checking channel drivers for PJSIP - rc_endpoint [Oct 12 16:14:53] DEBUG[102107] devicestate.c: Changing state for PJSIP/rc_endpoint - state 2 (In use) [Oct 12 16:14:53] DEBUG[100631] res_pjsip_session.c: Applying negotiated SDP media stream 'audio' using audio SDP handler [Oct 12 16:14:53] DEBUG[100631] res_rtp_asterisk.c: Ignoring duplicate RTCP property on RTP instance '0x806ea6030' [Oct 12 16:14:53] DEBUG[102169] app_queue.c: Device 'PJSIP/rc_endpoint' changed to state '2' (In use) but we don't care because they're not a member of any queue. [Oct 12 16:14:53] DEBUG[100631] netsock2.c: Splitting '193.254.248.22' into... [Oct 12 16:14:53] DEBUG[100631] netsock2.c: ...host '193.254.248.22' and port ''. [Oct 12 16:14:53] DEBUG[100631] acl.c: For destination '193.254.248.22', our source address is '37.60.19.38'. [Oct 12 16:14:53] DEBUG[100631] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x806ea6030' [Oct 12 16:14:53] DEBUG[100631] rtp_engine.c: Setting tx payload type 8 based on m type on 0x7fffdd6def20 [Oct 12 16:14:53] DEBUG[100631] rtp_engine.c: Setting tx payload type 18 based on m type on 0x7fffdd6def20 [Oct 12 16:14:53] DEBUG[100631] rtp_engine.c: Setting tx payload type 101 based on m type on 0x7fffdd6def20 [Oct 12 16:14:53] DEBUG[100631] rtp_engine.c: Copying payload 8 (0x81061d6f8) from 0x7fffdd6def20 to 0x806ea61f8 [Oct 12 16:14:53] DEBUG[100631] rtp_engine.c: Copying payload 18 (0x81061d8d8) from 0x7fffdd6def20 to 0x806ea61f8 [Oct 12 16:14:53] DEBUG[100631] rtp_engine.c: Copying payload 101 (0x81061d9c8) from 0x7fffdd6def20 to 0x806ea61f8 [Oct 12 16:14:53] DEBUG[100631] res_pjsip_session.c: Applied negotiated SDP media stream 'audio' using audio SDP handler [Oct 12 16:14:53] DEBUG[100631] res_pjsip_session.c: Method is INVITE, Response is 200 OK [Oct 12 16:14:53] DEBUG[100631] res_pjsip/pjsip_message_ip_updater.c: Re-wrote Contact URI host/port to 37.60.19.38:5060 [Oct 12 16:14:53] DEBUG[100631] netsock2.c: Splitting '37.60.19.38:5060' into... [Oct 12 16:14:53] DEBUG[100631] netsock2.c: ...host '37.60.19.38' and port '5060'. [Oct 12 16:14:53] DEBUG[100631] netsock2.c: Splitting '193.254.248.22:5060' into... [Oct 12 16:14:53] DEBUG[100631] netsock2.c: ...host '193.254.248.22' and port '5060'. [Oct 12 16:14:53] VERBOSE[100631] res_pjsip_logger.c: <--- Transmitting SIP response (772 bytes) to UDP:193.254.248.22:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 193.254.248.22:5060;rport=5060;received=193.254.248.22;branch=z9hG4bK64f347ae Call-ID: 23f0fd773a26754935326966632e5e50@193.254.248.22:5060 From: "320968" ;tag=as50c67fb2 To: ;tag=5db618d3-8f4f-44f0-bc88-f54c92a8751a CSeq: 102 INVITE Server: lord.nyrd.ru Contact: Allow: OPTIONS, SUBSCRIBE, NOTIFY, PUBLISH, INVITE, ACK, BYE, CANCEL, UPDATE, PRACK, REGISTER, MESSAGE, REFER Supported: 100rel, timer, replaces, norefersub Content-Type: application/sdp Content-Length: 179 v=0 o=- 1050155685 1050155687 IN IP4 37.60.19.38 s=Asterisk c=IN IP4 37.60.19.38 t=0 0 m=audio 10468 RTP/AVP 8 a=rtpmap:8 PCMA/8000 a=ptime:20 a=maxptime:150 a=sendrecv [Oct 12 16:14:53] DEBUG[100631] res_pjsip_session.c: Function void session_inv_on_state_changed(pjsip_inv_session *, pjsip_event *) called on event TSX_STATE [Oct 12 16:14:53] DEBUG[100631] res_pjsip_session.c: The state change pertains to the endpoint 'rc_endpoint(PJSIP/rc_endpoint-0000001d)' [Oct 12 16:14:53] DEBUG[100631] res_pjsip_session.c: The inv session still has an invite_tsx (0x81064d0a8) [Oct 12 16:14:53] DEBUG[100631] res_pjsip_session.c: There is no transaction involved in this state change [Oct 12 16:14:53] DEBUG[100631] res_pjsip_session.c: The current inv state is CONNECTING [Oct 12 16:14:53] DEBUG[100631] res_pjsip_session.c: Source of transaction state change is TX_MSG [Oct 12 16:14:53] DEBUG[100631] res_pjsip_session.c: Function void session_inv_on_tsx_state_changed(pjsip_inv_session *, pjsip_transaction *, pjsip_event *) called on event TSX_STATE [Oct 12 16:14:53] DEBUG[100631] res_pjsip_session.c: The state change pertains to the endpoint 'rc_endpoint(PJSIP/rc_endpoint-0000001d)' [Oct 12 16:14:53] DEBUG[100631] res_pjsip_session.c: The inv session still has an invite_tsx (0x81064d0a8) [Oct 12 16:14:53] DEBUG[100631] res_pjsip_session.c: The UAS INVITE transaction involved in this state change is 0x81064d0a8 [Oct 12 16:14:53] DEBUG[100631] res_pjsip_session.c: The current transaction state is Completed [Oct 12 16:14:53] DEBUG[100631] res_pjsip_session.c: The transaction state change event is TX_MSG [Oct 12 16:14:53] DEBUG[100631] res_pjsip_session.c: The current inv state is CONNECTING [Oct 12 16:14:53] VERBOSE[102118] res_pjsip_logger.c: <--- Received SIP request (424 bytes) from UDP:193.254.248.22:5060 ---> ACK sip:37.60.19.38:5060 SIP/2.0 Via: SIP/2.0/UDP 193.254.248.22:5060;branch=z9hG4bK6bc533c5 Max-Forwards: 70 From: "320968" ;tag=as50c67fb2 To: ;tag=5db618d3-8f4f-44f0-bc88-f54c92a8751a Contact: Call-ID: 23f0fd773a26754935326966632e5e50@193.254.248.22:5060 CSeq: 102 ACK User-Agent: Asterisk PBX 13.13.0 Content-Length: 0 [Oct 12 16:14:53] DEBUG[102118] netsock2.c: Splitting '193.254.248.22:5060' into... [Oct 12 16:14:53] DEBUG[102118] netsock2.c: ...host '193.254.248.22' and port '5060'. [Oct 12 16:14:53] DEBUG[102118] netsock2.c: Splitting '37.60.19.38:5060' into... [Oct 12 16:14:53] DEBUG[102118] netsock2.c: ...host '37.60.19.38' and port '5060'. [Oct 12 16:14:53] DEBUG[102118] res_pjsip/pjsip_distributor.c: Searching for serializer associated with dialog dlg0x81064e8a8 for Request msg ACK/cseq=102 (rdata0x80482e028) [Oct 12 16:14:53] DEBUG[102118] res_pjsip/pjsip_distributor.c: Found serializer pjsip/distributor-0000002e associated with dialog dlg0x81064e8a8 [Oct 12 16:14:53] DEBUG[102381] res_pjsip_session.c: Function void session_inv_on_tsx_state_changed(pjsip_inv_session *, pjsip_transaction *, pjsip_event *) called on event TSX_STATE [Oct 12 16:14:53] DEBUG[102381] res_pjsip_session.c: The state change pertains to the endpoint 'rc_endpoint(PJSIP/rc_endpoint-0000001d)' [Oct 12 16:14:53] DEBUG[102381] res_pjsip_session.c: The inv session does NOT have an invite_tsx [Oct 12 16:14:53] DEBUG[102381] res_pjsip_session.c: The UAS INVITE transaction involved in this state change is 0x81064d0a8 [Oct 12 16:14:53] DEBUG[102381] res_pjsip_session.c: The current transaction state is Terminated [Oct 12 16:14:53] DEBUG[102381] res_pjsip_session.c: The transaction state change event is USER [Oct 12 16:14:53] DEBUG[102381] res_pjsip_session.c: The current inv state is CONNECTING [Oct 12 16:14:53] DEBUG[102381] res_pjsip_session.c: Function void session_inv_on_state_changed(pjsip_inv_session *, pjsip_event *) called on event RX_MSG [Oct 12 16:14:53] DEBUG[102381] res_pjsip_session.c: The state change pertains to the endpoint 'rc_endpoint(PJSIP/rc_endpoint-0000001d)' [Oct 12 16:14:53] DEBUG[102381] res_pjsip_session.c: The inv session does NOT have an invite_tsx [Oct 12 16:14:53] DEBUG[102381] res_pjsip_session.c: There is no transaction involved in this state change [Oct 12 16:14:53] DEBUG[102381] res_pjsip_session.c: The current inv state is CONFIRMED [Oct 12 16:14:53] DEBUG[102381] res_pjsip_session.c: Received request [Oct 12 16:14:53] DEBUG[102381] res_pjsip_session.c: Method is ACK [Oct 12 16:14:53] DEBUG[102666][C-00000016] channel.c: Channel PJSIP/rc_endpoint-0000001d setting write format path: slin -> alaw [Oct 12 16:14:53] DEBUG[102666][C-00000016] channel.c: Scheduling timer at (50 requested / 50 actual) timer ticks per second [Oct 12 16:14:53] DEBUG[102666][C-00000016] res_rtp_asterisk.c: Ooh, format changed from none to alaw [Oct 12 16:14:56] VERBOSE[102118] res_pjsip_logger.c: <--- Received SIP request (858 bytes) from UDP:193.254.248.22:5060 ---> INVITE sip:37.60.19.38:5060 SIP/2.0 Via: SIP/2.0/UDP 193.254.248.22:5060;branch=z9hG4bK11cca2a0 Max-Forwards: 70 From: "320968" ;tag=as50c67fb2 To: ;tag=5db618d3-8f4f-44f0-bc88-f54c92a8751a Contact: Call-ID: 23f0fd773a26754935326966632e5e50@193.254.248.22:5060 CSeq: 103 INVITE User-Agent: Asterisk PBX 13.13.0 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE Supported: replaces, timer Content-Type: application/sdp Content-Length: 275 v=0 o=root 1050155685 1050155686 IN IP4 193.254.248.22 s=Asterisk PBX 13.13.0 c=IN IP4 193.254.248.22 t=0 0 m=image 4804 udptl t38 a=T38FaxVersion:0 a=T38MaxBitRate:14400 a=T38FaxRateManagement:transferredTCF a=T38FaxMaxDatagram:397 a=T38FaxUdpEC:t38UDPRedundancy [Oct 12 16:14:56] DEBUG[102118] netsock2.c: Splitting '193.254.248.22:5060' into... [Oct 12 16:14:56] DEBUG[102118] netsock2.c: ...host '193.254.248.22' and port '5060'. [Oct 12 16:14:56] DEBUG[102118] netsock2.c: Splitting '37.60.19.38:5060' into... [Oct 12 16:14:56] DEBUG[102118] netsock2.c: ...host '37.60.19.38' and port '5060'. [Oct 12 16:14:56] DEBUG[102118] res_pjsip/pjsip_distributor.c: Searching for serializer associated with dialog dlg0x81064e8a8 for Request msg INVITE/cseq=103 (rdata0x80482e028) [Oct 12 16:14:56] DEBUG[102118] res_pjsip/pjsip_distributor.c: Found serializer pjsip/distributor-0000002e associated with dialog dlg0x81064e8a8 [Oct 12 16:14:56] DEBUG[100631] res_pjsip_t38.c: UDPTL initialized on session for PJSIP/rc_endpoint-0000001d [Oct 12 16:14:56] DEBUG[100631] res_pjsip_t38.c: T.38 state changed to '2' from '0' on channel 'PJSIP/rc_endpoint-0000001d' [Oct 12 16:14:56] DEBUG[100631] res_pjsip_t38.c: Deferring incoming SDP stream on PJSIP/rc_endpoint-0000001d for peer re-invite [Oct 12 16:14:56] DEBUG[100631] res_pjsip_t38.c: T.38 state changed to '3' from '2' on channel 'PJSIP/rc_endpoint-0000001d' [Oct 12 16:14:56] DEBUG[100631] res_pjsip_t38.c: Automatic T.38 rejection on channel 'PJSIP/rc_endpoint-0000001d' terminated [Oct 12 16:14:56] DEBUG[102666][C-00000016] channel.c: Channel PJSIP/rc_endpoint-0000001d setting write format path: alaw -> alaw [Oct 12 16:14:56] DEBUG[102666][C-00000016] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second [Oct 12 16:14:56] DEBUG[102666][C-00000016] res_fax.c: Negotiated T.38 for receive on PJSIP/rc_endpoint-0000001d [Oct 12 16:14:56] VERBOSE[100631] res_pjsip_logger.c: <--- Received SIP request (858 bytes) from UDP:193.254.248.22:5060 ---> INVITE sip:37.60.19.38:5060 SIP/2.0 Via: SIP/2.0/UDP 193.254.248.22:5060;branch=z9hG4bK11cca2a0 Max-Forwards: 70 From: "320968" ;tag=as50c67fb2 To: ;tag=5db618d3-8f4f-44f0-bc88-f54c92a8751a Contact: Call-ID: 23f0fd773a26754935326966632e5e50@193.254.248.22:5060 CSeq: 103 INVITE User-Agent: Asterisk PBX 13.13.0 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE Supported: replaces, timer Content-Type: application/sdp Content-Length: 275 v=0 o=root 1050155685 1050155686 IN IP4 193.254.248.22 s=Asterisk PBX 13.13.0 c=IN IP4 193.254.248.22 t=0 0 m=image 4804 udptl t38 a=T38FaxVersion:0 a=T38MaxBitRate:14400 a=T38FaxRateManagement:transferredTCF a=T38FaxMaxDatagram:397 a=T38FaxUdpEC:t38UDPRedundancy [Oct 12 16:14:56] DEBUG[100631] netsock2.c: Splitting '193.254.248.22:5060' into... [Oct 12 16:14:56] DEBUG[100631] netsock2.c: ...host '193.254.248.22' and port '5060'. [Oct 12 16:14:56] DEBUG[100631] netsock2.c: Splitting '37.60.19.38:5060' into... [Oct 12 16:14:56] DEBUG[100631] netsock2.c: ...host '37.60.19.38' and port '5060'. [Oct 12 16:14:56] DEBUG[100631] res_pjsip/pjsip_distributor.c: Searching for serializer associated with dialog dlg0x81064e8a8 for Request msg INVITE/cseq=103 (rdata0x806c49028) [Oct 12 16:14:56] DEBUG[100631] res_pjsip/pjsip_distributor.c: Found serializer pjsip/distributor-0000002e associated with dialog dlg0x81064e8a8 [Oct 12 16:14:56] DEBUG[100631] res_pjsip_session.c: Negotiating incoming SDP media stream 'image' using image SDP handler [Oct 12 16:14:56] DEBUG[100631] netsock2.c: Splitting '193.254.248.22' into... [Oct 12 16:14:56] DEBUG[100631] netsock2.c: ...host '193.254.248.22' and port ''. [Oct 12 16:14:56] DEBUG[100631] res_pjsip_session.c: Media stream 'image' handled by image [Oct 12 16:14:56] DEBUG[100631] res_rtp_asterisk.c: Ignoring duplicate RTCP property on RTP instance '0x806ea6030' [Oct 12 16:14:56] DEBUG[100631] res_pjsip_session.c: Stopping SDP media stream 'audio' as it is not currently negotiated [Oct 12 16:14:56] DEBUG[100631] res_pjsip_session.c: Applying negotiated SDP media stream 'image' using image SDP handler [Oct 12 16:14:56] DEBUG[100631] netsock2.c: Splitting '193.254.248.22' into... [Oct 12 16:14:56] DEBUG[100631] netsock2.c: ...host '193.254.248.22' and port ''. [Oct 12 16:14:56] DEBUG[100631] res_pjsip_session.c: Applied negotiated SDP media stream 'image' using image SDP handler [Oct 12 16:14:56] DEBUG[100631] res_pjsip/pjsip_message_ip_updater.c: Re-wrote Contact URI host/port to 37.60.19.38:5060 [Oct 12 16:14:56] DEBUG[100631] netsock2.c: Splitting '37.60.19.38:5060' into... [Oct 12 16:14:56] DEBUG[100631] netsock2.c: ...host '37.60.19.38' and port '5060'. [Oct 12 16:14:56] DEBUG[100631] netsock2.c: Splitting '193.254.248.22:5060' into... [Oct 12 16:14:56] DEBUG[100631] netsock2.c: ...host '193.254.248.22' and port '5060'. [Oct 12 16:14:56] VERBOSE[100631] res_pjsip_logger.c: <--- Transmitting SIP response (848 bytes) to UDP:193.254.248.22:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 193.254.248.22:5060;rport=5060;received=193.254.248.22;branch=z9hG4bK11cca2a0 Call-ID: 23f0fd773a26754935326966632e5e50@193.254.248.22:5060 From: "320968" ;tag=as50c67fb2 To: ;tag=5db618d3-8f4f-44f0-bc88-f54c92a8751a CSeq: 103 INVITE Contact: Allow: OPTIONS, SUBSCRIBE, NOTIFY, PUBLISH, INVITE, ACK, BYE, CANCEL, UPDATE, PRACK, REGISTER, MESSAGE, REFER Supported: 100rel, timer, replaces, norefersub Server: lord.nyrd.ru Content-Type: application/sdp Content-Length: 255 v=0 o=- 1050155685 1050155688 IN IP4 37.60.19.38 s=Asterisk c=IN IP4 37.60.19.38 t=0 0 m=image 4666 udptl t38 a=T38FaxVersion:0 a=T38MaxBitRate:14400 a=T38FaxRateManagement:transferredTCF a=T38FaxMaxDatagram:1400 a=T38FaxUdpEC:t38UDPRedundancy [Oct 12 16:14:56] DEBUG[100631] res_pjsip_session.c: Function void session_inv_on_tsx_state_changed(pjsip_inv_session *, pjsip_transaction *, pjsip_event *) called on event TSX_STATE [Oct 12 16:14:56] DEBUG[100631] res_pjsip_session.c: The state change pertains to the endpoint 'rc_endpoint(PJSIP/rc_endpoint-0000001d)' [Oct 12 16:14:56] DEBUG[100631] res_pjsip_session.c: The inv session still has an invite_tsx (0x81064d0a8) [Oct 12 16:14:56] DEBUG[100631] res_pjsip_session.c: The UAS INVITE transaction involved in this state change is 0x81064d0a8 [Oct 12 16:14:56] DEBUG[100631] res_pjsip_session.c: The current transaction state is Completed [Oct 12 16:14:56] DEBUG[100631] res_pjsip_session.c: The transaction state change event is TX_MSG [Oct 12 16:14:56] DEBUG[100631] res_pjsip_session.c: The current inv state is CONFIRMED [Oct 12 16:14:56] DEBUG[100631] res_pjsip_session.c: Function void session_inv_on_tsx_state_changed(pjsip_inv_session *, pjsip_transaction *, pjsip_event *) called on event TSX_STATE [Oct 12 16:14:56] DEBUG[100631] res_pjsip_session.c: The state change pertains to the endpoint 'rc_endpoint(PJSIP/rc_endpoint-0000001d)' [Oct 12 16:14:56] DEBUG[100631] res_pjsip_session.c: The inv session still has an invite_tsx (0x81064d0a8) [Oct 12 16:14:56] DEBUG[100631] res_pjsip_session.c: The UAS INVITE transaction involved in this state change is 0x81064d0a8 [Oct 12 16:14:56] DEBUG[100631] res_pjsip_session.c: The current transaction state is Completed [Oct 12 16:14:56] DEBUG[100631] res_pjsip_session.c: The transaction state change event is RX_MSG [Oct 12 16:14:56] DEBUG[100631] res_pjsip_session.c: The current inv state is CONFIRMED [Oct 12 16:14:56] DEBUG[100631] res_pjsip_session.c: Received request [Oct 12 16:14:56] DEBUG[100631] res_pjsip_session.c: Method is INVITE [Oct 12 16:14:56] VERBOSE[102118] res_pjsip_logger.c: <--- Received SIP request (424 bytes) from UDP:193.254.248.22:5060 ---> ACK sip:37.60.19.38:5060 SIP/2.0 Via: SIP/2.0/UDP 193.254.248.22:5060;branch=z9hG4bK70574f95 Max-Forwards: 70 From: "320968" ;tag=as50c67fb2 To: ;tag=5db618d3-8f4f-44f0-bc88-f54c92a8751a Contact: Call-ID: 23f0fd773a26754935326966632e5e50@193.254.248.22:5060 CSeq: 103 ACK User-Agent: Asterisk PBX 13.13.0 Content-Length: 0 [Oct 12 16:14:56] DEBUG[102118] netsock2.c: Splitting '193.254.248.22:5060' into... [Oct 12 16:14:56] DEBUG[102118] netsock2.c: ...host '193.254.248.22' and port '5060'. [Oct 12 16:14:56] DEBUG[102118] netsock2.c: Splitting '37.60.19.38:5060' into... [Oct 12 16:14:56] DEBUG[102118] netsock2.c: ...host '37.60.19.38' and port '5060'. [Oct 12 16:14:56] DEBUG[102118] res_pjsip/pjsip_distributor.c: Searching for serializer associated with dialog dlg0x81064e8a8 for Request msg ACK/cseq=103 (rdata0x80482e028) [Oct 12 16:14:56] DEBUG[102118] res_pjsip/pjsip_distributor.c: Found serializer pjsip/distributor-0000002e associated with dialog dlg0x81064e8a8 [Oct 12 16:14:56] DEBUG[102381] res_pjsip_session.c: Function void session_inv_on_tsx_state_changed(pjsip_inv_session *, pjsip_transaction *, pjsip_event *) called on event TSX_STATE [Oct 12 16:14:56] DEBUG[102381] res_pjsip_session.c: The state change pertains to the endpoint 'rc_endpoint(PJSIP/rc_endpoint-0000001d)' [Oct 12 16:14:56] DEBUG[102381] res_pjsip_session.c: The inv session does NOT have an invite_tsx [Oct 12 16:14:56] DEBUG[102381] res_pjsip_session.c: The UAS INVITE transaction involved in this state change is 0x81064d0a8 [Oct 12 16:14:56] DEBUG[102381] res_pjsip_session.c: The current transaction state is Terminated [Oct 12 16:14:56] DEBUG[102381] res_pjsip_session.c: The transaction state change event is USER [Oct 12 16:14:56] DEBUG[102381] res_pjsip_session.c: The current inv state is CONFIRMED [Oct 12 16:14:56] DEBUG[102666][C-00000016] res_fax.c: Requesting a new FAX session from 'Spandsp FAX Driver'. [Oct 12 16:14:56] DEBUG[102666][C-00000016] res_fax.c: channel 'PJSIP/rc_endpoint-0000001d' using FAX session '12' [Oct 12 16:14:56] DEBUG[102666][C-00000016] res_fax.c: channel PJSIP/rc_endpoint-0000001d will wait on FAX fd 39 [Oct 12 16:14:56] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:14:56] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:14:59] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:00] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:01] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:01] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:01] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:01] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:01] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:01] DEBUG[102168] netsock2.c: Splitting '37.60.19.38:10469' into... [Oct 12 16:15:01] DEBUG[102168] netsock2.c: ...host '37.60.19.38' and port '10469'. [Oct 12 16:15:01] DEBUG[102168] netsock2.c: Splitting '193.254.248.22:17459' into... [Oct 12 16:15:01] DEBUG[102168] netsock2.c: ...host '193.254.248.22' and port '17459'. [Oct 12 16:15:01] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:01] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:01] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:01] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:01] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:01] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:01] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:01] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:01] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:01] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:01] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:01] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:01] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:01] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:01] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:01] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:01] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:01] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:01] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:01] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:01] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:01] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:01] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:01] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:01] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:01] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:01] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:01] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:01] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:02] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:02] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:02] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:02] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:02] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:03] VERBOSE[102118] res_pjsip_logger.c: <--- Received SIP request (679 bytes) from UDP:192.168.51.136:5060 ---> REGISTER sip:10.124.1.1 SIP/2.0 Via: SIP/2.0/UDP 192.168.51.136:5060;branch=z9hG4bK6f00f100a448079 From: ;tag=6f00f100a4 To: sip:700@10.124.1.1 Call-ID: 6f010000-e91e-f167-8000-0002a404d88e@192.168.51.136 CSeq: 48079 REGISTER Date: Thu, 15 Jan 2011 16:35:50 GMT User-Agent: AddPac SIP Gateway Authorization: Digest username="700", realm="asterisk", nonce="1507806855/8982ed2e9a314d4a247d5aca0ea4f05b", opaque="7de8b89639af0214", uri="sip:10.124.1.1", qop=auth, nc=0000a4d8, cnonce="201d53bf", response="f0a1d730d8c07ceb405492dc86d38c84", algorithm=MD5 Contact: ;expires=59 Expires: 59 Content-Length: 0 Max-Forwards: 70 [Oct 12 16:15:03] DEBUG[102118] netsock2.c: Splitting '192.168.51.136:5060' into... [Oct 12 16:15:03] DEBUG[102118] netsock2.c: ...host '192.168.51.136' and port '5060'. [Oct 12 16:15:03] DEBUG[102118] netsock2.c: Splitting '192.168.51.50:5060' into... [Oct 12 16:15:03] DEBUG[102118] netsock2.c: ...host '192.168.51.50' and port '5060'. [Oct 12 16:15:03] DEBUG[102118] res_pjsip/pjsip_distributor.c: Could not find matching transaction for Request msg REGISTER/cseq=48079 (rdata0x804830028) [Oct 12 16:15:03] DEBUG[102118] res_pjsip/pjsip_distributor.c: Calculated serializer pjsip/distributor-00000035 to use for Request msg REGISTER/cseq=48079 (rdata0x804830028) [Oct 12 16:15:03] DEBUG[102381] netsock2.c: Splitting '192.168.51.136' into... [Oct 12 16:15:03] DEBUG[102381] netsock2.c: ...host '192.168.51.136' and port ''. [Oct 12 16:15:03] DEBUG[102381] res_pjsip_endpoint_identifier_ip.c: Source address 192.168.51.136:5060 does not match identify 'rc_identify' [Oct 12 16:15:03] DEBUG[102381] res_pjsip_endpoint_identifier_ip.c: Source address 192.168.51.136:5060 does not match identify 'zadarma' [Oct 12 16:15:03] DEBUG[102381] res_pjsip_endpoint_identifier_ip.c: Identify checks by IP address failed to find match: '192.168.51.136:5060' did not match any identify section rules [Oct 12 16:15:03] DEBUG[102381] res_pjsip_endpoint_identifier_user.c: Attempting identify by From username '700' domain '10.124.1.1' [Oct 12 16:15:03] DEBUG[102381] res_pjsip_endpoint_identifier_user.c: Identified by From username '700' domain '10.124.1.1' [Oct 12 16:15:03] DEBUG[102381] res_pjsip_authenticator_digest.c: Using default realm 'asterisk' on incoming auth '700'. [Oct 12 16:15:03] DEBUG[102381] netsock2.c: Splitting '10.124.1.1' into... [Oct 12 16:15:03] DEBUG[102381] netsock2.c: ...host '10.124.1.1' and port ''. [Oct 12 16:15:03] DEBUG[102381] netsock2.c: Splitting '192.168.51.136' into... [Oct 12 16:15:03] DEBUG[102381] netsock2.c: ...host '192.168.51.136' and port ''. [Oct 12 16:15:03] DEBUG[102381] netsock2.c: Splitting '192.168.51.50:5060' into... [Oct 12 16:15:03] DEBUG[102381] netsock2.c: ...host '192.168.51.50' and port '5060'. [Oct 12 16:15:03] DEBUG[102381] netsock2.c: Splitting '192.168.51.136:5060' into... [Oct 12 16:15:03] DEBUG[102381] netsock2.c: ...host '192.168.51.136' and port '5060'. [Oct 12 16:15:03] VERBOSE[102381] res_pjsip_logger.c: <--- Transmitting SIP response (511 bytes) to UDP:192.168.51.136:5060 ---> SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 192.168.51.136:5060;rport=5060;received=192.168.51.136;branch=z9hG4bK6f00f100a448079 Call-ID: 6f010000-e91e-f167-8000-0002a404d88e@192.168.51.136 From: ;tag=6f00f100a4 To: ;tag=z9hG4bK6f00f100a448079 CSeq: 48079 REGISTER WWW-Authenticate: Digest realm="asterisk",nonce="1507806903/3fc0ef80c075dbbbf6bb1a99303c230f",opaque="001d37577e1c7275",stale=true,algorithm=md5,qop="auth" Server: lord.nyrd.ru Content-Length: 0 [Oct 12 16:15:03] VERBOSE[102118] res_pjsip_logger.c: <--- Received SIP request (679 bytes) from UDP:192.168.51.136:5060 ---> REGISTER sip:10.124.1.1 SIP/2.0 Via: SIP/2.0/UDP 192.168.51.136:5060;branch=z9hG4bK6f00f100a448080 From: ;tag=6f00f100a4 To: sip:700@10.124.1.1 Call-ID: 6f010000-e91e-f167-8000-0002a404d88e@192.168.51.136 CSeq: 48080 REGISTER Date: Thu, 15 Jan 2011 16:35:50 GMT User-Agent: AddPac SIP Gateway Authorization: Digest username="700", realm="asterisk", nonce="1507806903/3fc0ef80c075dbbbf6bb1a99303c230f", opaque="001d37577e1c7275", uri="sip:10.124.1.1", qop=auth, nc=0000a4d9, cnonce="abf4b1e6", response="e5e19cf7e75c7b03e6ece8feb4315677", algorithm=MD5 Contact: ;expires=59 Expires: 59 Content-Length: 0 Max-Forwards: 70 [Oct 12 16:15:03] DEBUG[102118] netsock2.c: Splitting '192.168.51.136:5060' into... [Oct 12 16:15:03] DEBUG[102118] netsock2.c: ...host '192.168.51.136' and port '5060'. [Oct 12 16:15:03] DEBUG[102118] netsock2.c: Splitting '192.168.51.50:5060' into... [Oct 12 16:15:03] DEBUG[102118] netsock2.c: ...host '192.168.51.50' and port '5060'. [Oct 12 16:15:03] DEBUG[102118] res_pjsip/pjsip_distributor.c: Could not find matching transaction for Request msg REGISTER/cseq=48080 (rdata0x804830028) [Oct 12 16:15:03] DEBUG[102118] res_pjsip/pjsip_distributor.c: Calculated serializer pjsip/distributor-00000035 to use for Request msg REGISTER/cseq=48080 (rdata0x804830028) [Oct 12 16:15:03] DEBUG[100631] netsock2.c: Splitting '192.168.51.136' into... [Oct 12 16:15:03] DEBUG[100631] netsock2.c: ...host '192.168.51.136' and port ''. [Oct 12 16:15:03] DEBUG[100631] res_pjsip_endpoint_identifier_ip.c: Source address 192.168.51.136:5060 does not match identify 'rc_identify' [Oct 12 16:15:03] DEBUG[100631] res_pjsip_endpoint_identifier_ip.c: Source address 192.168.51.136:5060 does not match identify 'zadarma' [Oct 12 16:15:03] DEBUG[100631] res_pjsip_endpoint_identifier_ip.c: Identify checks by IP address failed to find match: '192.168.51.136:5060' did not match any identify section rules [Oct 12 16:15:03] DEBUG[100631] res_pjsip_endpoint_identifier_user.c: Attempting identify by From username '700' domain '10.124.1.1' [Oct 12 16:15:03] DEBUG[100631] res_pjsip_endpoint_identifier_user.c: Identified by From username '700' domain '10.124.1.1' [Oct 12 16:15:03] DEBUG[100631] res_pjsip_authenticator_digest.c: Using default realm 'asterisk' on incoming auth '700'. [Oct 12 16:15:03] DEBUG[100631] res_pjsip_authenticator_digest.c: Calculated nonce 1507806903/3fc0ef80c075dbbbf6bb1a99303c230f. Actual nonce is 1507806903/3fc0ef80c075dbbbf6bb1a99303c230f [Oct 12 16:15:03] DEBUG[100631] netsock2.c: Splitting '10.124.1.1' into... [Oct 12 16:15:03] DEBUG[100631] netsock2.c: ...host '10.124.1.1' and port ''. [Oct 12 16:15:03] DEBUG[100631] netsock2.c: Splitting '192.168.51.136' into... [Oct 12 16:15:03] DEBUG[100631] netsock2.c: ...host '192.168.51.136' and port ''. [Oct 12 16:15:03] DEBUG[100631] res_pjsip_registrar.c: Matched id '700' to aor '700' [Oct 12 16:15:03] DEBUG[100631] res_pjsip_registrar.c: Matched aor '700' by To username [Oct 12 16:15:03] DEBUG[100631] config.c: extract double from [3.0] in [-inf, inf] gives [3.000000](0) [Oct 12 16:15:03] DEBUG[100631] config.c: extract uint from [0] in [0, 4294967295] gives [0](0) [Oct 12 16:15:03] DEBUG[100631] config.c: extract double from [3.000000] in [-inf, inf] gives [3.000000](0) [Oct 12 16:15:03] DEBUG[100631] config.c: extract uint from [5060] in [0, 4294967295] gives [5060](0) [Oct 12 16:15:03] DEBUG[100631] config.c: extract uint from [0] in [0, 86400] gives [0](0) [Oct 12 16:15:03] DEBUG[100631] config.c: extract double from [3.0] in [-inf, inf] gives [3.000000](0) [Oct 12 16:15:03] DEBUG[100631] config.c: extract uint from [0] in [0, 4294967295] gives [0](0) [Oct 12 16:15:03] DEBUG[100631] config.c: extract double from [3.000000] in [-inf, inf] gives [3.000000](0) [Oct 12 16:15:03] DEBUG[100631] config.c: extract uint from [5060] in [0, 4294967295] gives [5060](0) [Oct 12 16:15:03] DEBUG[100631] config.c: extract uint from [0] in [0, 86400] gives [0](0) [Oct 12 16:15:03] DEBUG[100631] res_pjsip_registrar.c: Refreshed contact 'sip:700@192.168.51.136' on AOR '700' with new expiration of 60 seconds [Oct 12 16:15:03] DEBUG[102124] config.c: extract uint from [3] in [0, 4294967295] gives [3](0) [Oct 12 16:15:03] DEBUG[102124] config.c: extract uint from [0] in [0, 4294967295] gives [0](0) [Oct 12 16:15:03] DEBUG[102124] config.c: extract uint from [2] in [0, 4294967295] gives [2](0) [Oct 12 16:15:03] DEBUG[100631] config.c: extract double from [3.0] in [-inf, inf] gives [3.000000](0) [Oct 12 16:15:03] DEBUG[100631] config.c: extract uint from [0] in [0, 4294967295] gives [0](0) [Oct 12 16:15:03] DEBUG[100631] config.c: extract double from [3.000000] in [-inf, inf] gives [3.000000](0) [Oct 12 16:15:03] DEBUG[100631] config.c: extract uint from [5060] in [0, 4294967295] gives [5060](0) [Oct 12 16:15:03] DEBUG[100631] config.c: extract uint from [0] in [0, 86400] gives [0](0) [Oct 12 16:15:03] DEBUG[100631] netsock2.c: Splitting '192.168.51.50:5060' into... [Oct 12 16:15:03] DEBUG[100631] netsock2.c: ...host '192.168.51.50' and port '5060'. [Oct 12 16:15:03] DEBUG[100631] netsock2.c: Splitting '192.168.51.136:5060' into... [Oct 12 16:15:03] DEBUG[100631] netsock2.c: ...host '192.168.51.136' and port '5060'. [Oct 12 16:15:03] VERBOSE[100631] res_pjsip_logger.c: <--- Transmitting SIP response (439 bytes) to UDP:192.168.51.136:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.51.136:5060;rport=5060;received=192.168.51.136;branch=z9hG4bK6f00f100a448080 Call-ID: 6f010000-e91e-f167-8000-0002a404d88e@192.168.51.136 From: ;tag=6f00f100a4 To: ;tag=z9hG4bK6f00f100a448080 CSeq: 48080 REGISTER Date: Thu, 12 Oct 2017 11:15:03 GMT Contact: ;expires=59 Expires: 60 Server: lord.nyrd.ru Content-Length: 0 [Oct 12 16:15:04] DEBUG[102156] res_pjsip_registrar_expire.c: Woke up at 1507806904 Interval: 30 [Oct 12 16:15:04] DEBUG[102156] res_pjsip_registrar_expire.c: Expiring 0 contacts [Oct 12 16:15:05] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:06] DEBUG[102168] netsock2.c: Splitting '37.60.19.38:10469' into... [Oct 12 16:15:06] DEBUG[102168] netsock2.c: ...host '37.60.19.38' and port '10469'. [Oct 12 16:15:06] DEBUG[102168] netsock2.c: Splitting '193.254.248.22:17459' into... [Oct 12 16:15:06] DEBUG[102168] netsock2.c: ...host '193.254.248.22' and port '17459'. [Oct 12 16:15:06] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:06] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:06] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:06] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:06] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:06] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:06] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:06] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:06] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:06] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:06] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:06] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:06] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:07] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:07] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:07] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:07] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:07] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:07] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:07] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:07] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:07] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:07] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:07] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:07] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:07] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:07] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:07] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:07] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:07] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:07] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:07] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:07] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:07] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:07] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:07] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:07] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:07] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:07] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:11] DEBUG[102168] netsock2.c: Splitting '37.60.19.38:10469' into... [Oct 12 16:15:11] DEBUG[102168] netsock2.c: ...host '37.60.19.38' and port '10469'. [Oct 12 16:15:11] DEBUG[102168] netsock2.c: Splitting '193.254.248.22:17459' into... [Oct 12 16:15:11] DEBUG[102168] netsock2.c: ...host '193.254.248.22' and port '17459'. [Oct 12 16:15:11] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:12] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:12] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:12] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:12] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:12] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:12] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:12] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:12] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:12] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:12] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:12] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:12] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:12] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:12] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:12] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:12] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:12] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:12] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:12] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:12] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:12] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:12] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:12] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:12] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:13] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:13] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:13] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:13] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:13] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:13] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:13] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:13] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:13] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:13] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:13] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:13] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:13] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:13] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:13] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:16] DEBUG[102168] netsock2.c: Splitting '37.60.19.38:10469' into... [Oct 12 16:15:16] DEBUG[102168] netsock2.c: ...host '37.60.19.38' and port '10469'. [Oct 12 16:15:16] DEBUG[102168] netsock2.c: Splitting '193.254.248.22:17459' into... [Oct 12 16:15:16] DEBUG[102168] netsock2.c: ...host '193.254.248.22' and port '17459'. [Oct 12 16:15:16] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:17] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:17] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:17] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:18] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:19] NOTICE[102666][C-00000016] udptl.c: UDPTL (PJSIP/rc_endpoint-0000001d): Transmission error to 193.254.248.22:4804: Invalid argument [Oct 12 16:15:19] DEBUG[102666][C-00000016] res_fax_spandsp.c: FAX session '12' entering phase E [Oct 12 16:15:19] DEBUG[102666][C-00000016] res_fax_spandsp.c: FAX session '12' completed with result: FAILED (Disconnected after permitted retries) [Oct 12 16:15:19] DEBUG[102666][C-00000016] res_fax_spandsp.c: FAX session '12' is complete. [Oct 12 16:15:19] DEBUG[102666][C-00000016] res_fax.c: channel 'PJSIP/rc_endpoint-0000001d' - event loop stopped { timeout: 10000, remaining_time: 10000 } [Oct 12 16:15:19] DEBUG[102666][C-00000016] res_fax.c: Shutting down T.38 on PJSIP/rc_endpoint-0000001d [Oct 12 16:15:19] DEBUG[100631] res_pjsip_t38.c: T.38 state changed to '0' from '3' on channel 'PJSIP/rc_endpoint-0000001d' [Oct 12 16:15:19] DEBUG[102666][C-00000016] res_fax.c: Shut down T.38 on PJSIP/rc_endpoint-0000001d [Oct 12 16:15:19] DEBUG[100631] res_rtp_asterisk.c: Ignoring duplicate RTCP property on RTP instance '0x806ea6030' [Oct 12 16:15:19] DEBUG[100631] res_pjsip_t38.c: Not creating outgoing SDP stream: T.38 not enabled [Oct 12 16:15:19] DEBUG[102666][C-00000016] pbx.c: Launching 'Hangup' [Oct 12 16:15:19] DEBUG[100631] res_pjsip_session.c: Sending session refresh SDP via re-INVITE to rc_endpoint [Oct 12 16:15:19] DEBUG[100631] res_pjsip_session.c: Method is INVITE [Oct 12 16:15:19] DEBUG[102666][C-00000016] channel.c: Soft-Hanging (0x20) up channel 'PJSIP/rc_endpoint-0000001d' [Oct 12 16:15:19] DEBUG[102666][C-00000016] pbx.c: Spawn extension (from-trunk,000340,3) exited non-zero on 'PJSIP/rc_endpoint-0000001d' [Oct 12 16:15:19] DEBUG[102666][C-00000016] channel.c: Soft-Hanging (0x10) up channel 'PJSIP/rc_endpoint-0000001d' [Oct 12 16:15:19] DEBUG[102666][C-00000016] channel.c: Channel 0x806f1a030 'PJSIP/rc_endpoint-0000001d' hanging up. Refs: 2 [Oct 12 16:15:19] DEBUG[102666][C-00000016] chan_pjsip.c: AST hangup cause 16 (no match found in PJSIP) [Oct 12 16:15:19] DEBUG[100631] res_pjsip/pjsip_message_ip_updater.c: Re-wrote Contact URI host/port to 37.60.19.38:5060 [Oct 12 16:15:19] DEBUG[100631] netsock2.c: Splitting '37.60.19.38:5060' into... [Oct 12 16:15:19] DEBUG[100631] netsock2.c: ...host '37.60.19.38' and port '5060'. [Oct 12 16:15:19] DEBUG[100631] netsock2.c: Splitting '193.254.248.22:5060' into... [Oct 12 16:15:19] DEBUG[100631] netsock2.c: ...host '193.254.248.22' and port '5060'. [Oct 12 16:15:19] VERBOSE[100631] res_pjsip_logger.c: <--- Transmitting SIP request (860 bytes) to UDP:193.254.248.22:5060 ---> INVITE sip:320968@193.254.248.22:5060 SIP/2.0 Via: SIP/2.0/UDP 37.60.19.38:5060;rport;branch=z9hG4bKPj007a534d-7b57-4c9b-b454-e494feaf67f1 From: ;tag=5db618d3-8f4f-44f0-bc88-f54c92a8751a To: "320968" ;tag=as50c67fb2 Contact: Call-ID: 23f0fd773a26754935326966632e5e50@193.254.248.22:5060 CSeq: 20040 INVITE Allow: OPTIONS, SUBSCRIBE, NOTIFY, PUBLISH, INVITE, ACK, BYE, CANCEL, UPDATE, PRACK, REGISTER, MESSAGE, REFER Supported: 100rel, timer, replaces, norefersub Session-Expires: 1800 Min-SE: 90 Max-Forwards: 70 User-Agent: lord.nyrd.ru Content-Type: application/sdp Content-Length: 179 v=0 o=- 1050155685 1050155689 IN IP4 37.60.19.38 s=Asterisk c=IN IP4 37.60.19.38 t=0 0 m=audio 10468 RTP/AVP 8 a=rtpmap:8 PCMA/8000 a=ptime:20 a=maxptime:150 a=sendrecv [Oct 12 16:15:19] DEBUG[100631] res_pjsip_session.c: Function void session_inv_on_tsx_state_changed(pjsip_inv_session *, pjsip_transaction *, pjsip_event *) called on event TSX_STATE [Oct 12 16:15:19] DEBUG[100631] res_pjsip_session.c: The state change pertains to the endpoint 'rc_endpoint(PJSIP/rc_endpoint-0000001d)' [Oct 12 16:15:19] DEBUG[100631] res_pjsip_session.c: The inv session still has an invite_tsx (0x81064d8a8) [Oct 12 16:15:19] DEBUG[100631] res_pjsip_session.c: The UAC INVITE transaction involved in this state change is 0x81064d8a8 [Oct 12 16:15:19] DEBUG[100631] res_pjsip_session.c: The current transaction state is Calling [Oct 12 16:15:19] DEBUG[100631] res_pjsip_session.c: The transaction state change event is TX_MSG [Oct 12 16:15:19] DEBUG[100631] res_pjsip_session.c: The current inv state is CONFIRMED [Oct 12 16:15:19] DEBUG[100631] res_pjsip_session.c: Delay sending BYE to rc_endpoint because of outstanding transaction... [Oct 12 16:15:19] DEBUG[100631] channel.c: Channel 0x806f1a030 'PJSIP/rc_endpoint-0000001d' destroying [Oct 12 16:15:19] DEBUG[102109] cdr.c: Finalized CDR for PJSIP/rc_endpoint-0000001d - start 1507806893.531938 answer 1507806893.533116 end 1507806919.350451 dispo ANSWERED [Oct 12 16:15:19] DEBUG[102107] devicestate.c: No provider found, checking channel drivers for PJSIP - rc_endpoint [Oct 12 16:15:19] DEBUG[102109] cdr_pgsql.c: Inserting a CDR record: [INSERT INTO cdr ("calldate","clid","src","dst","dcontext","channel","dstchannel","lastapp","lastdata","duration","billsec","disposition","amaflags","accountcode","uniqueid","userfield","peeraccount","linkedid","sequence") VALUES ('2017-10-12 16:14:53','"320968" <320968>','320968','000340','from-trunk','PJSIP/rc_endpoint-0000001d','','Hangup','',25,25,'ANSWERED',3,'','1507806893.51','','','1507806893.51',29)] [Oct 12 16:15:19] DEBUG[102107] devicestate.c: Changing state for PJSIP/rc_endpoint - state 1 (Not in use) [Oct 12 16:15:19] DEBUG[102169] app_queue.c: Device 'PJSIP/rc_endpoint' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Oct 12 16:15:19] VERBOSE[102118] res_pjsip_logger.c: <--- Received SIP response (567 bytes) from UDP:193.254.248.22:5060 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 37.60.19.38:5060;branch=z9hG4bKPj007a534d-7b57-4c9b-b454-e494feaf67f1;received=37.60.19.38;rport=5060 From: ;tag=5db618d3-8f4f-44f0-bc88-f54c92a8751a To: "320968" ;tag=as50c67fb2 Call-ID: 23f0fd773a26754935326966632e5e50@193.254.248.22:5060 CSeq: 20040 INVITE Server: Asterisk PBX 13.13.0 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE Supported: replaces, timer Contact: Content-Length: 0 [Oct 12 16:15:19] DEBUG[102118] netsock2.c: Splitting '193.254.248.22:5060' into... [Oct 12 16:15:19] DEBUG[102118] netsock2.c: ...host '193.254.248.22' and port '5060'. [Oct 12 16:15:19] DEBUG[102118] netsock2.c: Splitting '37.60.19.38:5060' into... [Oct 12 16:15:19] DEBUG[102118] netsock2.c: ...host '37.60.19.38' and port '5060'. [Oct 12 16:15:19] DEBUG[102118] res_pjsip/pjsip_distributor.c: Searching for serializer associated with dialog dlg0x81064e8a8 for Response msg 100/INVITE/cseq=20040 (rdata0x80482e028) [Oct 12 16:15:19] DEBUG[102118] res_pjsip/pjsip_distributor.c: Found serializer pjsip/distributor-0000002e associated with dialog dlg0x81064e8a8 [Oct 12 16:15:19] VERBOSE[102118] res_pjsip_logger.c: <--- Received SIP response (831 bytes) from UDP:193.254.248.22:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 37.60.19.38:5060;branch=z9hG4bKPj007a534d-7b57-4c9b-b454-e494feaf67f1;received=37.60.19.38;rport=5060 From: ;tag=5db618d3-8f4f-44f0-bc88-f54c92a8751a To: "320968" ;tag=as50c67fb2 Call-ID: 23f0fd773a26754935326966632e5e50@193.254.248.22:5060 CSeq: 20040 INVITE Server: Asterisk PBX 13.13.0 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE Supported: replaces, timer Contact: Content-Type: application/sdp Content-Length: 235 v=0 o=root 1050155685 1050155687 IN IP4 193.254.248.22 s=Asterisk PBX 13.13.0 c=IN IP4 193.254.248.22 t=0 0 m=audio 17458 RTP/AVP 8 18 a=rtpmap:8 PCMA/8000 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=maxptime:150 a=sendrecv [Oct 12 16:15:19] DEBUG[102381] res_pjsip_session.c: Function void session_inv_on_tsx_state_changed(pjsip_inv_session *, pjsip_transaction *, pjsip_event *) called on event TSX_STATE [Oct 12 16:15:19] DEBUG[102381] res_pjsip_session.c: The state change pertains to the endpoint 'rc_endpoint()' [Oct 12 16:15:19] DEBUG[102381] res_pjsip_session.c: The inv session still has an invite_tsx (0x81064d8a8) [Oct 12 16:15:19] DEBUG[102381] res_pjsip_session.c: The UAC INVITE transaction involved in this state change is 0x81064d8a8 [Oct 12 16:15:19] DEBUG[102381] res_pjsip_session.c: The current transaction state is Proceeding [Oct 12 16:15:19] DEBUG[102118] netsock2.c: Splitting '193.254.248.22:5060' into... [Oct 12 16:15:19] DEBUG[102381] res_pjsip_session.c: The transaction state change event is RX_MSG [Oct 12 16:15:19] DEBUG[102118] netsock2.c: ...host '193.254.248.22' and port '5060'. [Oct 12 16:15:19] DEBUG[102381] res_pjsip_session.c: The current inv state is CONFIRMED [Oct 12 16:15:19] DEBUG[102118] netsock2.c: Splitting '37.60.19.38:5060' into... [Oct 12 16:15:19] DEBUG[102381] res_pjsip_session.c: Received response [Oct 12 16:15:19] DEBUG[102118] netsock2.c: ...host '37.60.19.38' and port '5060'. [Oct 12 16:15:19] DEBUG[102381] res_pjsip_session.c: Response is 100 Trying [Oct 12 16:15:19] DEBUG[102381] res_pjsip_session.c: Endpoint 'rc_endpoint()' INVITE delay check. tsx-state:Proceeding [Oct 12 16:15:19] DEBUG[102118] res_pjsip/pjsip_distributor.c: Searching for serializer associated with dialog dlg0x81064e8a8 for Response msg 200/INVITE/cseq=20040 (rdata0x80482e028) [Oct 12 16:15:19] DEBUG[102118] res_pjsip/pjsip_distributor.c: Found serializer pjsip/distributor-0000002e associated with dialog dlg0x81064e8a8 [Oct 12 16:15:19] DEBUG[100631] netsock2.c: Splitting '37.60.19.38:5060' into... [Oct 12 16:15:19] DEBUG[100631] netsock2.c: ...host '37.60.19.38' and port '5060'. [Oct 12 16:15:19] DEBUG[100631] netsock2.c: Splitting '193.254.248.22:5060' into... [Oct 12 16:15:19] DEBUG[100631] netsock2.c: ...host '193.254.248.22' and port '5060'. [Oct 12 16:15:19] VERBOSE[100631] res_pjsip_logger.c: <--- Transmitting SIP request (414 bytes) to UDP:193.254.248.22:5060 ---> ACK sip:320968@193.254.248.22:5060 SIP/2.0 Via: SIP/2.0/UDP 37.60.19.38:5060;rport;branch=z9hG4bKPjbe63a748-3710-480d-8c38-6fe9792b2bc1 From: ;tag=5db618d3-8f4f-44f0-bc88-f54c92a8751a To: "320968" ;tag=as50c67fb2 Call-ID: 23f0fd773a26754935326966632e5e50@193.254.248.22:5060 CSeq: 20040 ACK Max-Forwards: 70 User-Agent: lord.nyrd.ru Content-Length: 0 [Oct 12 16:15:19] DEBUG[100631] res_pjsip_session.c: Function void session_inv_on_tsx_state_changed(pjsip_inv_session *, pjsip_transaction *, pjsip_event *) called on event TSX_STATE [Oct 12 16:15:19] DEBUG[100631] res_pjsip_session.c: The state change pertains to the endpoint 'rc_endpoint()' [Oct 12 16:15:19] DEBUG[100631] res_pjsip_session.c: The inv session does NOT have an invite_tsx [Oct 12 16:15:19] DEBUG[100631] res_pjsip_session.c: The UAC INVITE transaction involved in this state change is 0x81064d8a8 [Oct 12 16:15:19] DEBUG[100631] res_pjsip_session.c: The current transaction state is Terminated [Oct 12 16:15:19] DEBUG[100631] res_pjsip_session.c: The transaction state change event is RX_MSG [Oct 12 16:15:19] DEBUG[100631] res_pjsip_session.c: The current inv state is CONFIRMED [Oct 12 16:15:19] DEBUG[100631] res_pjsip_session.c: Received response [Oct 12 16:15:19] DEBUG[100631] res_pjsip_session.c: Response is 200 OK [Oct 12 16:15:19] DEBUG[100631] res_pjsip_session.c: Endpoint 'rc_endpoint()' INVITE delay check. tsx-state:Terminated [Oct 12 16:15:19] DEBUG[100631] res_pjsip_session.c: Endpoint 'rc_endpoint()' sending delayed BYE request. [Oct 12 16:15:19] DEBUG[100631] res_pjsip_session.c: Method is BYE [Oct 12 16:15:19] DEBUG[100631] netsock2.c: Splitting '37.60.19.38:5060' into... [Oct 12 16:15:19] DEBUG[100631] netsock2.c: ...host '37.60.19.38' and port '5060'. [Oct 12 16:15:19] DEBUG[100631] netsock2.c: Splitting '193.254.248.22:5060' into... [Oct 12 16:15:19] DEBUG[100631] netsock2.c: ...host '193.254.248.22' and port '5060'. [Oct 12 16:15:19] VERBOSE[100631] res_pjsip_logger.c: <--- Transmitting SIP request (414 bytes) to UDP:193.254.248.22:5060 ---> BYE sip:320968@193.254.248.22:5060 SIP/2.0 Via: SIP/2.0/UDP 37.60.19.38:5060;rport;branch=z9hG4bKPjf701df75-5430-43c0-ba93-3ca2180288c5 From: ;tag=5db618d3-8f4f-44f0-bc88-f54c92a8751a To: "320968" ;tag=as50c67fb2 Call-ID: 23f0fd773a26754935326966632e5e50@193.254.248.22:5060 CSeq: 20041 BYE Max-Forwards: 70 User-Agent: lord.nyrd.ru Content-Length: 0 [Oct 12 16:15:19] DEBUG[100631] res_pjsip_session.c: Function void session_inv_on_tsx_state_changed(pjsip_inv_session *, pjsip_transaction *, pjsip_event *) called on event TSX_STATE [Oct 12 16:15:19] DEBUG[100631] res_pjsip_session.c: The state change pertains to the endpoint 'rc_endpoint()' [Oct 12 16:15:19] DEBUG[100631] res_pjsip_session.c: The inv session does NOT have an invite_tsx [Oct 12 16:15:19] DEBUG[100631] res_pjsip_session.c: The UAC BYE transaction involved in this state change is 0x81064c0a8 [Oct 12 16:15:19] DEBUG[100631] res_pjsip_session.c: The current transaction state is Calling [Oct 12 16:15:19] DEBUG[100631] res_pjsip_session.c: The transaction state change event is TX_MSG [Oct 12 16:15:19] DEBUG[100631] res_pjsip_session.c: The current inv state is CONFIRMED [Oct 12 16:15:19] VERBOSE[102118] res_pjsip_logger.c: <--- Received SIP response (517 bytes) from UDP:193.254.248.22:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 37.60.19.38:5060;branch=z9hG4bKPjf701df75-5430-43c0-ba93-3ca2180288c5;received=37.60.19.38;rport=5060 From: ;tag=5db618d3-8f4f-44f0-bc88-f54c92a8751a To: "320968" ;tag=as50c67fb2 Call-ID: 23f0fd773a26754935326966632e5e50@193.254.248.22:5060 CSeq: 20041 BYE Server: Asterisk PBX 13.13.0 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE Supported: replaces, timer Content-Length: 0 [Oct 12 16:15:19] DEBUG[102118] netsock2.c: Splitting '193.254.248.22:5060' into... [Oct 12 16:15:19] DEBUG[102118] netsock2.c: ...host '193.254.248.22' and port '5060'. [Oct 12 16:15:19] DEBUG[102118] netsock2.c: Splitting '37.60.19.38:5060' into... [Oct 12 16:15:19] DEBUG[102118] netsock2.c: ...host '37.60.19.38' and port '5060'. [Oct 12 16:15:19] DEBUG[102118] res_pjsip/pjsip_distributor.c: Searching for serializer associated with dialog dlg0x81064e8a8 for Response msg 200/BYE/cseq=20041 (rdata0x80482e028) [Oct 12 16:15:19] DEBUG[102118] res_pjsip/pjsip_distributor.c: Found serializer pjsip/distributor-0000002e associated with dialog dlg0x81064e8a8 [Oct 12 16:15:19] DEBUG[102381] res_pjsip_session.c: Function void session_inv_on_state_changed(pjsip_inv_session *, pjsip_event *) called on event TSX_STATE [Oct 12 16:15:19] DEBUG[102381] res_pjsip_session.c: The state change pertains to the endpoint 'rc_endpoint()' [Oct 12 16:15:19] DEBUG[102381] res_pjsip_session.c: The inv session does NOT have an invite_tsx [Oct 12 16:15:19] DEBUG[102381] res_pjsip_session.c: There is no transaction involved in this state change [Oct 12 16:15:19] DEBUG[102381] res_pjsip_session.c: The current inv state is DISCONNCTD [Oct 12 16:15:19] DEBUG[102381] res_pjsip_session.c: Source of transaction state change is RX_MSG [Oct 12 16:15:19] DEBUG[102381] res_pjsip_session.c: Received response [Oct 12 16:15:19] DEBUG[102381] res_pjsip_session.c: Response is 200 OK [Oct 12 16:15:19] DEBUG[102381] res_pjsip_session.c: Function void session_inv_on_tsx_state_changed(pjsip_inv_session *, pjsip_transaction *, pjsip_event *) called on event TSX_STATE [Oct 12 16:15:19] DEBUG[102381] res_pjsip_session.c: The state change pertains to the endpoint 'rc_endpoint()' [Oct 12 16:15:19] DEBUG[102381] res_pjsip_session.c: The inv session does NOT have an invite_tsx [Oct 12 16:15:19] DEBUG[102381] res_pjsip_session.c: The UAC BYE transaction involved in this state change is 0x81064c0a8 [Oct 12 16:15:19] DEBUG[102381] res_pjsip_session.c: The current transaction state is Completed [Oct 12 16:15:19] DEBUG[102381] res_pjsip_session.c: The transaction state change event is RX_MSG [Oct 12 16:15:19] DEBUG[102381] res_pjsip_session.c: The current inv state is DISCONNCTD [Oct 12 16:15:19] DEBUG[102381] res_pjsip_session.c: Received response [Oct 12 16:15:19] DEBUG[102381] res_pjsip_session.c: Response is 200 OK [Oct 12 16:15:19] DEBUG[102381] res_pjsip_session.c: BYE received final response code 200 [Oct 12 16:15:21] DEBUG[102168] netsock2.c: Splitting '37.60.19.38:10469' into... [Oct 12 16:15:21] DEBUG[102168] netsock2.c: ...host '37.60.19.38' and port '10469'. [Oct 12 16:15:21] DEBUG[102168] netsock2.c: Splitting '193.254.248.22:17459' into... [Oct 12 16:15:21] DEBUG[102168] netsock2.c: ...host '193.254.248.22' and port '17459'. [Oct 12 16:15:24] DEBUG[102118] res_pjsip_session.c: Function void session_inv_on_tsx_state_changed(pjsip_inv_session *, pjsip_transaction *, pjsip_event *) called on event TSX_STATE [Oct 12 16:15:24] DEBUG[102118] res_pjsip_session.c: The state change pertains to the endpoint 'rc_endpoint()' [Oct 12 16:15:24] DEBUG[102118] res_pjsip_session.c: The inv session does NOT have an invite_tsx [Oct 12 16:15:24] DEBUG[102118] res_pjsip_session.c: The UAC BYE transaction involved in this state change is 0x81064c0a8 [Oct 12 16:15:24] DEBUG[102118] res_pjsip_session.c: The current transaction state is Terminated [Oct 12 16:15:24] DEBUG[102118] res_pjsip_session.c: The transaction state change event is TIMER [Oct 12 16:15:24] DEBUG[102118] res_pjsip_session.c: The current inv state is DISCONNCTD [Oct 12 16:15:24] DEBUG[100631] res_pjsip_session.c: Destroying SIP session with endpoint rc_endpoint [Oct 12 16:15:24] DEBUG[100631] rtp_engine.c: Destroyed RTP instance '0x806ea6030' [Oct 12 16:15:34] DEBUG[102156] res_pjsip_registrar_expire.c: Woke up at 1507806934 Interval: 30 [Oct 12 16:15:34] DEBUG[102156] res_pjsip_registrar_expire.c: Expiring 0 contacts [Oct 12 16:15:39] DEBUG[102665] threadpool.c: Worker thread idle timeout reached. Dying. [Oct 12 16:15:39] DEBUG[102096] threadpool.c: Destroying worker thread 6007 [Oct 12 16:15:40] VERBOSE[102118] res_pjsip_logger.c: <--- Received SIP request (561 bytes) from UDP:193.254.248.22:5060 ---> OPTIONS sip:000340@37.60.19.38:5060 SIP/2.0 Via: SIP/2.0/UDP 193.254.248.22:5060;branch=z9hG4bK2a662e22 Max-Forwards: 70 From: "asterisk" ;tag=as561b7aac To: Contact: Call-ID: 1bb173627e2662aa1aae2ebd4ac75f7e@193.254.248.22:5060 CSeq: 102 OPTIONS User-Agent: Asterisk PBX 13.13.0 Date: Thu, 12 Oct 2017 11:15:40 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE Supported: replaces, timer Content-Length: 0 [Oct 12 16:15:40] DEBUG[102118] netsock2.c: Splitting '193.254.248.22:5060' into... [Oct 12 16:15:40] DEBUG[102118] netsock2.c: ...host '193.254.248.22' and port '5060'. [Oct 12 16:15:40] DEBUG[102118] netsock2.c: Splitting '37.60.19.38:5060' into... [Oct 12 16:15:40] DEBUG[102118] netsock2.c: ...host '37.60.19.38' and port '5060'. [Oct 12 16:15:40] DEBUG[102118] res_pjsip/pjsip_distributor.c: Could not find matching transaction for Request msg OPTIONS/cseq=102 (rdata0x80482e028) [Oct 12 16:15:40] DEBUG[102118] res_pjsip/pjsip_distributor.c: Calculated serializer pjsip/distributor-00000030 to use for Request msg OPTIONS/cseq=102 (rdata0x80482e028) [Oct 12 16:15:40] DEBUG[102381] netsock2.c: Splitting '193.254.248.22' into... [Oct 12 16:15:40] DEBUG[102381] netsock2.c: ...host '193.254.248.22' and port ''. [Oct 12 16:15:40] DEBUG[102381] res_pjsip_endpoint_identifier_ip.c: Source address 193.254.248.22:5060 matches identify 'rc_identify' [Oct 12 16:15:40] DEBUG[102381] res_pjsip_endpoint_identifier_ip.c: Retrieved endpoint rc_endpoint [Oct 12 16:15:40] DEBUG[102381] netsock2.c: Splitting '37.60.19.38:5060' into... [Oct 12 16:15:40] DEBUG[102381] netsock2.c: ...host '37.60.19.38' and port '5060'. [Oct 12 16:15:40] DEBUG[102381] netsock2.c: Splitting '193.254.248.22:5060' into... [Oct 12 16:15:40] DEBUG[102381] netsock2.c: ...host '193.254.248.22' and port '5060'. [Oct 12 16:15:40] VERBOSE[102381] res_pjsip_logger.c: <--- Transmitting SIP response (838 bytes) to UDP:193.254.248.22:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 193.254.248.22:5060;rport=5060;received=193.254.248.22;branch=z9hG4bK2a662e22 Call-ID: 1bb173627e2662aa1aae2ebd4ac75f7e@193.254.248.22:5060 From: "asterisk" ;tag=as561b7aac To: ;tag=z9hG4bK2a662e22 CSeq: 102 OPTIONS Accept: application/sdp, application/dialog-info+xml, application/pidf+xml, application/simple-message-summary, application/xpidf+xml, application/cpim-pidf+xml, application/pidf+xml, application/dialog-info+xml, application/simple-message-summary, message/sipfrag;version=2.0 Allow: OPTIONS, SUBSCRIBE, NOTIFY, PUBLISH, INVITE, ACK, BYE, CANCEL, UPDATE, PRACK, REGISTER, MESSAGE, REFER Supported: 100rel, timer, replaces, norefersub Accept-Encoding: text/plain Accept-Language: en Server: lord.nyrd.ru Content-Length: 0 [Oct 12 16:15:50] VERBOSE[102118] res_pjsip_logger.c: <--- Received SIP request (679 bytes) from UDP:192.168.51.136:5060 ---> REGISTER sip:10.124.1.1 SIP/2.0 Via: SIP/2.0/UDP 192.168.51.136:5060;branch=z9hG4bK6f00f100a448081 From: ;tag=6f00f100a4 To: sip:700@10.124.1.1 Call-ID: 6f010000-e91e-f167-8000-0002a404d88e@192.168.51.136 CSeq: 48081 REGISTER Date: Thu, 15 Jan 2011 16:36:38 GMT User-Agent: AddPac SIP Gateway Authorization: Digest username="700", realm="asterisk", nonce="1507806903/3fc0ef80c075dbbbf6bb1a99303c230f", opaque="001d37577e1c7275", uri="sip:10.124.1.1", qop=auth, nc=0000a4da, cnonce="abf4b1e6", response="b15be97b26c5f484a4d8a83ece9b31bb", algorithm=MD5 Contact: ;expires=59 Expires: 59 Content-Length: 0 Max-Forwards: 70 [Oct 12 16:15:50] DEBUG[102118] netsock2.c: Splitting '192.168.51.136:5060' into... [Oct 12 16:15:50] DEBUG[102118] netsock2.c: ...host '192.168.51.136' and port '5060'. [Oct 12 16:15:50] DEBUG[102118] netsock2.c: Splitting '192.168.51.50:5060' into... [Oct 12 16:15:50] DEBUG[102118] netsock2.c: ...host '192.168.51.50' and port '5060'. [Oct 12 16:15:50] DEBUG[102118] res_pjsip/pjsip_distributor.c: Could not find matching transaction for Request msg REGISTER/cseq=48081 (rdata0x804830028) [Oct 12 16:15:50] DEBUG[102118] res_pjsip/pjsip_distributor.c: Calculated serializer pjsip/distributor-00000035 to use for Request msg REGISTER/cseq=48081 (rdata0x804830028) [Oct 12 16:15:50] DEBUG[100631] netsock2.c: Splitting '192.168.51.136' into... [Oct 12 16:15:50] DEBUG[100631] netsock2.c: ...host '192.168.51.136' and port ''. [Oct 12 16:15:50] DEBUG[100631] res_pjsip_endpoint_identifier_ip.c: Source address 192.168.51.136:5060 does not match identify 'rc_identify' [Oct 12 16:15:50] DEBUG[100631] res_pjsip_endpoint_identifier_ip.c: Source address 192.168.51.136:5060 does not match identify 'zadarma' [Oct 12 16:15:50] DEBUG[100631] res_pjsip_endpoint_identifier_ip.c: Identify checks by IP address failed to find match: '192.168.51.136:5060' did not match any identify section rules [Oct 12 16:15:50] DEBUG[100631] res_pjsip_endpoint_identifier_user.c: Attempting identify by From username '700' domain '10.124.1.1' [Oct 12 16:15:50] DEBUG[100631] res_pjsip_endpoint_identifier_user.c: Identified by From username '700' domain '10.124.1.1' [Oct 12 16:15:50] DEBUG[100631] res_pjsip_authenticator_digest.c: Using default realm 'asterisk' on incoming auth '700'. [Oct 12 16:15:50] DEBUG[100631] netsock2.c: Splitting '10.124.1.1' into... [Oct 12 16:15:50] DEBUG[100631] netsock2.c: ...host '10.124.1.1' and port ''. [Oct 12 16:15:50] DEBUG[100631] netsock2.c: Splitting '192.168.51.136' into... [Oct 12 16:15:50] DEBUG[100631] netsock2.c: ...host '192.168.51.136' and port ''. [Oct 12 16:15:50] DEBUG[100631] netsock2.c: Splitting '192.168.51.50:5060' into... [Oct 12 16:15:50] DEBUG[100631] netsock2.c: ...host '192.168.51.50' and port '5060'. [Oct 12 16:15:50] DEBUG[100631] netsock2.c: Splitting '192.168.51.136:5060' into... [Oct 12 16:15:50] DEBUG[100631] netsock2.c: ...host '192.168.51.136' and port '5060'. [Oct 12 16:15:50] VERBOSE[100631] res_pjsip_logger.c: <--- Transmitting SIP response (511 bytes) to UDP:192.168.51.136:5060 ---> SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 192.168.51.136:5060;rport=5060;received=192.168.51.136;branch=z9hG4bK6f00f100a448081 Call-ID: 6f010000-e91e-f167-8000-0002a404d88e@192.168.51.136 From: ;tag=6f00f100a4 To: ;tag=z9hG4bK6f00f100a448081 CSeq: 48081 REGISTER WWW-Authenticate: Digest realm="asterisk",nonce="1507806950/70d50270b66f2bffbe290c8769a37ab9",opaque="7d9ee1a749f11d05",stale=true,algorithm=md5,qop="auth" Server: lord.nyrd.ru Content-Length: 0 [Oct 12 16:15:50] VERBOSE[102118] res_pjsip_logger.c: <--- Received SIP request (679 bytes) from UDP:192.168.51.136:5060 ---> REGISTER sip:10.124.1.1 SIP/2.0 Via: SIP/2.0/UDP 192.168.51.136:5060;branch=z9hG4bK6f00f100a448082 From: ;tag=6f00f100a4 To: sip:700@10.124.1.1 Call-ID: 6f010000-e91e-f167-8000-0002a404d88e@192.168.51.136 CSeq: 48082 REGISTER Date: Thu, 15 Jan 2011 16:36:38 GMT User-Agent: AddPac SIP Gateway Authorization: Digest username="700", realm="asterisk", nonce="1507806950/70d50270b66f2bffbe290c8769a37ab9", opaque="7d9ee1a749f11d05", uri="sip:10.124.1.1", qop=auth, nc=0000a4db, cnonce="8ecd0bbb", response="fa59c68b761f0b67c48e035bbd381cd8", algorithm=MD5 Contact: ;expires=59 Expires: 59 Content-Length: 0 Max-Forwards: 70 [Oct 12 16:15:50] DEBUG[102118] netsock2.c: Splitting '192.168.51.136:5060' into... [Oct 12 16:15:50] DEBUG[102118] netsock2.c: ...host '192.168.51.136' and port '5060'. [Oct 12 16:15:50] DEBUG[102118] netsock2.c: Splitting '192.168.51.50:5060' into... [Oct 12 16:15:50] DEBUG[102118] netsock2.c: ...host '192.168.51.50' and port '5060'. [Oct 12 16:15:50] DEBUG[102118] res_pjsip/pjsip_distributor.c: Could not find matching transaction for Request msg REGISTER/cseq=48082 (rdata0x804830028) [Oct 12 16:15:50] DEBUG[102118] res_pjsip/pjsip_distributor.c: Calculated serializer pjsip/distributor-00000035 to use for Request msg REGISTER/cseq=48082 (rdata0x804830028) [Oct 12 16:15:50] DEBUG[102381] netsock2.c: Splitting '192.168.51.136' into... [Oct 12 16:15:50] DEBUG[102381] netsock2.c: ...host '192.168.51.136' and port ''. [Oct 12 16:15:50] DEBUG[102381] res_pjsip_endpoint_identifier_ip.c: Source address 192.168.51.136:5060 does not match identify 'rc_identify' [Oct 12 16:15:50] DEBUG[102381] res_pjsip_endpoint_identifier_ip.c: Source address 192.168.51.136:5060 does not match identify 'zadarma' [Oct 12 16:15:50] DEBUG[102381] res_pjsip_endpoint_identifier_ip.c: Identify checks by IP address failed to find match: '192.168.51.136:5060' did not match any identify section rules [Oct 12 16:15:50] DEBUG[102381] res_pjsip_endpoint_identifier_user.c: Attempting identify by From username '700' domain '10.124.1.1' [Oct 12 16:15:50] DEBUG[102381] res_pjsip_endpoint_identifier_user.c: Identified by From username '700' domain '10.124.1.1' [Oct 12 16:15:50] DEBUG[102381] res_pjsip_authenticator_digest.c: Using default realm 'asterisk' on incoming auth '700'. [Oct 12 16:15:50] DEBUG[102381] res_pjsip_authenticator_digest.c: Calculated nonce 1507806950/70d50270b66f2bffbe290c8769a37ab9. Actual nonce is 1507806950/70d50270b66f2bffbe290c8769a37ab9 [Oct 12 16:15:50] DEBUG[102381] netsock2.c: Splitting '10.124.1.1' into... [Oct 12 16:15:50] DEBUG[102381] netsock2.c: ...host '10.124.1.1' and port ''. [Oct 12 16:15:50] DEBUG[102381] netsock2.c: Splitting '192.168.51.136' into... [Oct 12 16:15:50] DEBUG[102381] netsock2.c: ...host '192.168.51.136' and port ''. [Oct 12 16:15:50] DEBUG[102381] res_pjsip_registrar.c: Matched id '700' to aor '700' [Oct 12 16:15:50] DEBUG[102381] res_pjsip_registrar.c: Matched aor '700' by To username [Oct 12 16:15:50] DEBUG[102381] config.c: extract double from [3.0] in [-inf, inf] gives [3.000000](0) [Oct 12 16:15:50] DEBUG[102381] config.c: extract uint from [0] in [0, 4294967295] gives [0](0) [Oct 12 16:15:50] DEBUG[102381] config.c: extract double from [3.000000] in [-inf, inf] gives [3.000000](0) [Oct 12 16:15:50] DEBUG[102381] config.c: extract uint from [5060] in [0, 4294967295] gives [5060](0) [Oct 12 16:15:50] DEBUG[102381] config.c: extract uint from [0] in [0, 86400] gives [0](0) [Oct 12 16:15:50] DEBUG[102381] config.c: extract double from [3.0] in [-inf, inf] gives [3.000000](0) [Oct 12 16:15:50] DEBUG[102381] config.c: extract uint from [0] in [0, 4294967295] gives [0](0) [Oct 12 16:15:50] DEBUG[102381] config.c: extract double from [3.000000] in [-inf, inf] gives [3.000000](0) [Oct 12 16:15:50] DEBUG[102381] config.c: extract uint from [5060] in [0, 4294967295] gives [5060](0) [Oct 12 16:15:50] DEBUG[102381] config.c: extract uint from [0] in [0, 86400] gives [0](0) [Oct 12 16:15:50] DEBUG[102381] res_pjsip_registrar.c: Refreshed contact 'sip:700@192.168.51.136' on AOR '700' with new expiration of 60 seconds [Oct 12 16:15:50] DEBUG[102124] config.c: extract uint from [3] in [0, 4294967295] gives [3](0) [Oct 12 16:15:50] DEBUG[102124] config.c: extract uint from [0] in [0, 4294967295] gives [0](0) [Oct 12 16:15:50] DEBUG[102124] config.c: extract uint from [2] in [0, 4294967295] gives [2](0) [Oct 12 16:15:50] DEBUG[102096] threadpool.c: Increasing threadpool stasis-core's size by 1 [Oct 12 16:15:50] DEBUG[102381] config.c: extract double from [3.0] in [-inf, inf] gives [3.000000](0) [Oct 12 16:15:50] DEBUG[102381] config.c: extract uint from [0] in [0, 4294967295] gives [0](0) [Oct 12 16:15:50] DEBUG[102381] config.c: extract double from [3.000000] in [-inf, inf] gives [3.000000](0) [Oct 12 16:15:50] DEBUG[102381] config.c: extract uint from [5060] in [0, 4294967295] gives [5060](0) [Oct 12 16:15:50] DEBUG[102381] config.c: extract uint from [0] in [0, 86400] gives [0](0) [Oct 12 16:15:50] DEBUG[102381] netsock2.c: Splitting '192.168.51.50:5060' into... [Oct 12 16:15:50] DEBUG[102381] netsock2.c: ...host '192.168.51.50' and port '5060'. [Oct 12 16:15:50] DEBUG[102381] netsock2.c: Splitting '192.168.51.136:5060' into... [Oct 12 16:15:50] DEBUG[102381] netsock2.c: ...host '192.168.51.136' and port '5060'. [Oct 12 16:15:50] VERBOSE[102381] res_pjsip_logger.c: <--- Transmitting SIP response (439 bytes) to UDP:192.168.51.136:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.51.136:5060;rport=5060;received=192.168.51.136;branch=z9hG4bK6f00f100a448082 Call-ID: 6f010000-e91e-f167-8000-0002a404d88e@192.168.51.136 From: ;tag=6f00f100a4 To: ;tag=z9hG4bK6f00f100a448082 CSeq: 48082 REGISTER Date: Thu, 12 Oct 2017 11:15:50 GMT Contact: ;expires=59 Expires: 60 Server: lord.nyrd.ru Content-Length: 0