[Sep 7 15:48:54] VERBOSE[26796] res_pjsip_logger.c: <--- Received SIP request (597 bytes) from TLS:10.0.0.132:1180 ---> REGISTER sip:sip0.srv.local:5061;transport=tls SIP/2.0 Via: SIP/2.0/TLS 10.0.0.132:1180;rport;branch=z9hG4bKPj06m7qQPk.Lda4TNRoeomcxQ1kl0iPKdu;alias Max-Forwards: 70 From: "1003316" ;tag=vIiOtDf1T4NbUtnGWnbPDgQaMjKwH3fp To: "1003316" Call-ID: ylM7K0aZIt.IhkXVF-vE2ZuhbY0CHwPX CSeq: 42316 REGISTER User-Agent: sip client Supported: outbound, path Contact: ;reg-id=1;+sip.instance="" Expires: 0 Content-Length: 0 [Sep 7 15:48:54] DEBUG[26796] res_pjsip/pjsip_distributor.c: Could not find matching transaction for Request msg REGISTER/cseq=42316 (rdata0x7f8a1804e698) [Sep 7 15:48:54] DEBUG[26796] res_pjsip/pjsip_distributor.c: Calculated serializer pjsip/distributor-0000004c to use for Request msg REGISTER/cseq=42316 (rdata0x7f8a1804e698) [Sep 7 15:48:54] DEBUG[27428] netsock2.c: Splitting '10.0.0.132' into... [Sep 7 15:48:54] DEBUG[27428] netsock2.c: ...host '10.0.0.132' and port ''. [Sep 7 15:48:54] DEBUG[27428] res_pjsip_endpoint_identifier_ip.c: No identify sections to match against [Sep 7 15:48:54] DEBUG[27428] res_pjsip_endpoint_identifier_user.c: Attempting identify by From username '1003316' domain 'sip0.srv.local' [Sep 7 15:48:54] DEBUG[27428] res_odbc.c: Reusing ODBC handle 0x3000fe0 from class 'asterisk' [Sep 7 15:48:54] DEBUG[27428] res_config_odbc.c: Skip: 0; SQL: SELECT * FROM ps_endpoints WHERE id = ? [Sep 7 15:48:54] DEBUG[27428] res_config_odbc.c: Parameter 1 ('id') = '1003316@sip0.srv.local' [Sep 7 15:48:54] DEBUG[27428] res_odbc.c: Releasing ODBC handle 0x3000fe0 into pool [Sep 7 15:48:54] DEBUG[27428] res_odbc.c: Reusing ODBC handle 0x3000fe0 from class 'asterisk' [Sep 7 15:48:54] DEBUG[27428] res_config_odbc.c: Skip: 0; SQL: SELECT * FROM ps_endpoints WHERE id = ? [Sep 7 15:48:54] DEBUG[27428] res_config_odbc.c: Parameter 1 ('id') = '1003316' [Sep 7 15:48:54] DEBUG[27428] res_odbc.c: Releasing ODBC handle 0x3000fe0 into pool [Sep 7 15:48:54] DEBUG[27428] res_sorcery_realtime.c: Filtering out realtime field 'disallow' from retrieval [Sep 7 15:48:54] DEBUG[27428] config.c: extract uint from [0] in [0, 4294967295] gives [0](0) [Sep 7 15:48:54] DEBUG[27428] config.c: extract uint from [1800] in [0, 4294967295] gives [1800](0) [Sep 7 15:48:54] DEBUG[27428] config.c: extract uint from [0] in [0, 4294967295] gives [0](0) [Sep 7 15:48:54] DEBUG[27428] config.c: extract uint from [0] in [0, 4294967295] gives [0](0) [Sep 7 15:48:54] DEBUG[27428] config.c: extract uint from [0] in [0, 4294967295] gives [0](0) [Sep 7 15:48:54] DEBUG[27428] config.c: extract uint from [1] in [0, 4294967295] gives [1](0) [Sep 7 15:48:54] DEBUG[27428] config.c: extract uint from [1] in [0, 4294967295] gives [1](0) [Sep 7 15:48:54] DEBUG[27428] config.c: extract uint from [0] in [0, 4294967295] gives [0](0) [Sep 7 15:48:54] DEBUG[27428] config.c: extract uint from [0] in [0, 4294967295] gives [0](0) [Sep 7 15:48:54] DEBUG[27428] config.c: extract uint from [0] in [0, 4294967295] gives [0](0) [Sep 7 15:48:54] DEBUG[27428] config.c: extract uint from [90] in [0, 4294967295] gives [90](0) [Sep 7 15:48:54] DEBUG[27428] config.c: extract uint from [0] in [0, 4294967295] gives [0](0) [Sep 7 15:48:54] DEBUG[27428] config.c: extract uint from [0] in [0, 4294967295] gives [0](0) [Sep 7 15:48:54] DEBUG[27428] config.c: extract uint from [1] in [0, 4294967295] gives [1](0) [Sep 7 15:48:54] DEBUG[27428] config.c: extract uint from [15] in [0, 4294967295] gives [15](0) [Sep 7 15:48:54] DEBUG[27428] res_pjsip_endpoint_identifier_user.c: Identified by From username '1003316' domain 'sip0.srv.local' [Sep 7 15:48:54] DEBUG[27428] res_odbc.c: Reusing ODBC handle 0x3000fe0 from class 'asterisk' [Sep 7 15:48:54] DEBUG[27428] res_config_odbc.c: Skip: 0; SQL: SELECT * FROM ps_auths WHERE id = ? [Sep 7 15:48:54] DEBUG[27428] res_config_odbc.c: Parameter 1 ('id') = '1003316' [Sep 7 15:48:54] DEBUG[27428] res_odbc.c: Releasing ODBC handle 0x3000fe0 into pool [Sep 7 15:48:54] DEBUG[27428] config.c: extract uint from [32] in [0, 4294967295] gives [32](0) [Sep 7 15:48:54] DEBUG[27428] res_pjsip_authenticator_digest.c: Using default realm 'asterisk' on incoming auth '1003316'. [Sep 7 15:48:54] DEBUG[27428] netsock2.c: Splitting '172.31.26.174' into... [Sep 7 15:48:54] DEBUG[27428] netsock2.c: ...host '172.31.26.174' and port ''. [Sep 7 15:48:54] DEBUG[27428] netsock2.c: Splitting '10.0.0.132' into... [Sep 7 15:48:54] DEBUG[27428] netsock2.c: ...host '10.0.0.132' and port ''. [Sep 7 15:48:54] DEBUG[27391] manager.c: Examining AMI event: Event: ChallengeSent Privilege: security,all EventTV: 2020-09-07T15:48:54.632+0900 Severity: Informational Service: PJSIP EventVersion: 1 AccountID: 1003316 SessionID: ylM7K0aZIt.IhkXVF-vE2ZuhbY0CHwPX LocalAddress: IPV4/TLS/172.31.26.174/5061 RemoteAddress: IPV4/TLS/10.0.0.132/1180 Challenge: [Sep 7 15:48:54] VERBOSE[27428] res_pjsip_logger.c: <--- Transmitting SIP response (584 bytes) to TLS:10.0.0.132:1180 ---> SIP/2.0 401 Unauthorized Via: SIP/2.0/TLS 10.0.0.132:1180;rport=1180;received=10.0.0.132;branch=z9hG4bKPj06m7qQPk.Lda4TNRoeomcxQ1kl0iPKdu;alias Call-ID: ylM7K0aZIt.IhkXVF-vE2ZuhbY0CHwPX From: "1003316" ;tag=vIiOtDf1T4NbUtnGWnbPDgQaMjKwH3fp To: "1003316" ;tag=z9hG4bKPj06m7qQPk.Lda4TNRoeomcxQ1kl0iPKdu CSeq: 42316 REGISTER WWW-Authenticate: Digest realm="asterisk",nonce="1599461334/44800e597e585da3144ce93cfb0d216a",opaque="34baead116144388",algorithm=md5,qop="auth" Server: Asterisk PBX Content-Length: 0 [Sep 7 15:48:54] VERBOSE[26796] res_pjsip_logger.c: <--- Received SIP request (909 bytes) from TLS:10.0.0.132:1180 ---> REGISTER sip:sip0.srv.local:5061;transport=tls SIP/2.0 Via: SIP/2.0/TLS 10.0.0.132:1180;rport;branch=z9hG4bKPj1WREULfrlTXR8LMEaThAQQrA83EuOSaS;alias Max-Forwards: 70 From: "1003316" ;tag=vIiOtDf1T4NbUtnGWnbPDgQaMjKwH3fp To: "1003316" Call-ID: ylM7K0aZIt.IhkXVF-vE2ZuhbY0CHwPX CSeq: 42317 REGISTER User-Agent: sip client Supported: outbound, path Contact: ;reg-id=1;+sip.instance="" Expires: 0 Authorization: Digest username="1003316", realm="asterisk", nonce="1599461334/44800e597e585da3144ce93cfb0d216a", uri="sip:sip0.srv.local:5061;transport=tls", response="4d6e24a0912d39dc925274fba46de941", algorithm=md5, cnonce="HKqD.pyujRjPi8XHOtgM53JPIoYEz00F", opaque="34baead116144388", qop=auth, nc=00000001 Content-Length: 0 [Sep 7 15:48:54] DEBUG[26796] res_pjsip/pjsip_distributor.c: Could not find matching transaction for Request msg REGISTER/cseq=42317 (rdata0x7f8a1804e698) [Sep 7 15:48:54] DEBUG[26796] res_pjsip/pjsip_distributor.c: Calculated serializer pjsip/distributor-0000004c to use for Request msg REGISTER/cseq=42317 (rdata0x7f8a1804e698) [Sep 7 15:48:54] DEBUG[27428] netsock2.c: Splitting '10.0.0.132' into... [Sep 7 15:48:54] DEBUG[27428] netsock2.c: ...host '10.0.0.132' and port ''. [Sep 7 15:48:54] DEBUG[27428] res_pjsip_endpoint_identifier_ip.c: No identify sections to match against [Sep 7 15:48:54] DEBUG[27428] res_pjsip_endpoint_identifier_user.c: Attempting identify by From username '1003316' domain 'sip0.srv.local' [Sep 7 15:48:54] DEBUG[27428] res_odbc.c: Reusing ODBC handle 0x3000fe0 from class 'asterisk' [Sep 7 15:48:54] DEBUG[27428] res_config_odbc.c: Skip: 0; SQL: SELECT * FROM ps_endpoints WHERE id = ? [Sep 7 15:48:54] DEBUG[27428] res_config_odbc.c: Parameter 1 ('id') = '1003316@sip0.srv.local' [Sep 7 15:48:54] DEBUG[27428] res_odbc.c: Releasing ODBC handle 0x3000fe0 into pool [Sep 7 15:48:54] DEBUG[27428] res_odbc.c: Reusing ODBC handle 0x3000fe0 from class 'asterisk' [Sep 7 15:48:54] DEBUG[27428] res_config_odbc.c: Skip: 0; SQL: SELECT * FROM ps_endpoints WHERE id = ? [Sep 7 15:48:54] DEBUG[27428] res_config_odbc.c: Parameter 1 ('id') = '1003316' [Sep 7 15:48:54] DEBUG[27428] res_odbc.c: Releasing ODBC handle 0x3000fe0 into pool [Sep 7 15:48:54] DEBUG[27428] res_sorcery_realtime.c: Filtering out realtime field 'disallow' from retrieval [Sep 7 15:48:54] DEBUG[27428] config.c: extract uint from [0] in [0, 4294967295] gives [0](0) [Sep 7 15:48:54] DEBUG[27428] config.c: extract uint from [1800] in [0, 4294967295] gives [1800](0) [Sep 7 15:48:54] DEBUG[27428] config.c: extract uint from [0] in [0, 4294967295] gives [0](0) [Sep 7 15:48:54] DEBUG[27428] config.c: extract uint from [0] in [0, 4294967295] gives [0](0) [Sep 7 15:48:54] DEBUG[27428] config.c: extract uint from [0] in [0, 4294967295] gives [0](0) [Sep 7 15:48:54] DEBUG[27428] config.c: extract uint from [1] in [0, 4294967295] gives [1](0) [Sep 7 15:48:54] DEBUG[27428] config.c: extract uint from [1] in [0, 4294967295] gives [1](0) [Sep 7 15:48:54] DEBUG[27428] config.c: extract uint from [0] in [0, 4294967295] gives [0](0) [Sep 7 15:48:54] DEBUG[27428] config.c: extract uint from [0] in [0, 4294967295] gives [0](0) [Sep 7 15:48:54] DEBUG[27428] config.c: extract uint from [0] in [0, 4294967295] gives [0](0) [Sep 7 15:48:54] DEBUG[27428] config.c: extract uint from [90] in [0, 4294967295] gives [90](0) [Sep 7 15:48:54] DEBUG[27428] config.c: extract uint from [0] in [0, 4294967295] gives [0](0) [Sep 7 15:48:54] DEBUG[27428] config.c: extract uint from [0] in [0, 4294967295] gives [0](0) [Sep 7 15:48:54] DEBUG[27428] config.c: extract uint from [1] in [0, 4294967295] gives [1](0) [Sep 7 15:48:54] DEBUG[27428] config.c: extract uint from [15] in [0, 4294967295] gives [15](0) [Sep 7 15:48:54] DEBUG[27428] res_pjsip_endpoint_identifier_user.c: Identified by From username '1003316' domain 'sip0.srv.local' [Sep 7 15:48:54] DEBUG[27428] res_odbc.c: Reusing ODBC handle 0x3000fe0 from class 'asterisk' [Sep 7 15:48:54] DEBUG[27428] res_config_odbc.c: Skip: 0; SQL: SELECT * FROM ps_auths WHERE id = ? [Sep 7 15:48:54] DEBUG[27428] res_config_odbc.c: Parameter 1 ('id') = '1003316' [Sep 7 15:48:54] DEBUG[27428] res_odbc.c: Releasing ODBC handle 0x3000fe0 into pool [Sep 7 15:48:54] DEBUG[27428] config.c: extract uint from [32] in [0, 4294967295] gives [32](0) [Sep 7 15:48:54] DEBUG[27428] res_pjsip_authenticator_digest.c: Using default realm 'asterisk' on incoming auth '1003316'. [Sep 7 15:48:54] DEBUG[27428] res_pjsip_authenticator_digest.c: Calculated nonce 1599461334/44800e597e585da3144ce93cfb0d216a. Actual nonce is 1599461334/44800e597e585da3144ce93cfb0d216a [Sep 7 15:48:54] DEBUG[27428] netsock2.c: Splitting '172.31.26.174' into... [Sep 7 15:48:54] DEBUG[27428] netsock2.c: ...host '172.31.26.174' and port ''. [Sep 7 15:48:54] DEBUG[27428] netsock2.c: Splitting '10.0.0.132' into... [Sep 7 15:48:54] DEBUG[27428] netsock2.c: ...host '10.0.0.132' and port ''. [Sep 7 15:48:54] DEBUG[27391] manager.c: Examining AMI event: Event: SuccessfulAuth Privilege: security,all EventTV: 2020-09-07T15:48:54.654+0900 Severity: Informational Service: PJSIP EventVersion: 1 AccountID: 1003316 SessionID: ylM7K0aZIt.IhkXVF-vE2ZuhbY0CHwPX LocalAddress: IPV4/TLS/172.31.26.174/5061 RemoteAddress: IPV4/TLS/10.0.0.132/1180 UsingPassword: 1 [Sep 7 15:48:54] DEBUG[27428] res_pjsip_registrar.c: Matched id '1003316' to aor '1003316' [Sep 7 15:48:54] DEBUG[27428] res_pjsip_registrar.c: Matched aor '1003316' by To username [Sep 7 15:48:54] DEBUG[27428] res_odbc.c: Reusing ODBC handle 0x3000fe0 from class 'asterisk' [Sep 7 15:48:54] DEBUG[27428] res_config_odbc.c: Skip: 0; SQL: SELECT * FROM ps_aors WHERE id = ? [Sep 7 15:48:54] DEBUG[27428] res_config_odbc.c: Parameter 1 ('id') = '1003316' [Sep 7 15:48:54] DEBUG[27428] res_odbc.c: Releasing ODBC handle 0x3000fe0 into pool [Sep 7 15:48:54] DEBUG[27428] config.c: extract double from [3.0] in [-inf, inf] gives [3.000000](0) [Sep 7 15:48:54] DEBUG[27428] config.c: extract uint from [7200] in [0, 4294967295] gives [7200](0) [Sep 7 15:48:54] DEBUG[27428] config.c: extract uint from [3600] in [0, 4294967295] gives [3600](0) [Sep 7 15:48:54] DEBUG[27428] config.c: extract uint from [60] in [0, 4294967295] gives [60](0) [Sep 7 15:48:54] DEBUG[27428] config.c: extract uint from [0] in [0, 4294967295] gives [0](0) [Sep 7 15:48:54] DEBUG[27428] config.c: extract uint from [1] in [0, 4294967295] gives [1](0) [Sep 7 15:48:54] DEBUG[27428] res_odbc.c: Reusing ODBC handle 0x3000fe0 from class 'asterisk' [Sep 7 15:48:54] DEBUG[27428] res_config_odbc.c: Skip: 0; SQL: SELECT * FROM ps_contacts WHERE id LIKE ? ORDER BY id [Sep 7 15:48:54] DEBUG[27428] res_config_odbc.c: Parameter 1 ('id LIKE') = '1003316;@%' [Sep 7 15:48:54] DEBUG[27428] res_odbc.c: Releasing ODBC handle 0x3000fe0 into pool [Sep 7 15:48:54] DEBUG[27428] config.c: extract double from [3.0] in [-inf, inf] gives [3.000000](0) [Sep 7 15:48:54] DEBUG[27428] config.c: extract uint from [0] in [0, 4294967295] gives [0](0) [Sep 7 15:48:54] DEBUG[27428] config.c: extract uint from [0] in [0, 86400] gives [0](0) [Sep 7 15:48:54] DEBUG[27428] config.c: extract double from [3.000000] in [-inf, inf] gives [3.000000](0) [Sep 7 15:48:54] DEBUG[27428] config.c: extract uint from [1180] in [0, 4294967295] gives [1180](0) [Sep 7 15:48:54] DEBUG[27428] res_odbc.c: Reusing ODBC handle 0x3000fe0 from class 'asterisk' [Sep 7 15:48:54] DEBUG[27428] res_config_odbc.c: Skip: 0; SQL: DELETE FROM ps_contacts WHERE id=? [Sep 7 15:48:54] DEBUG[27428] res_config_odbc.c: Parameter 1 = '1003316;@d46d1ff6c4d83c2c654e05df07e3aff2' [Sep 7 15:48:54] DEBUG[27428] res_odbc.c: Releasing ODBC handle 0x3000fe0 into pool [Sep 7 15:48:54] DEBUG[27430] res_pjsip/pjsip_options.c: An unqualified contact has been removed from AOR '1003316' leaving no remaining contacts [Sep 7 15:48:54] DEBUG[26779] devicestate.c: No provider found, checking channel drivers for PJSIP - 1003316 [Sep 7 15:48:54] VERBOSE[27428] res_pjsip_logger.c: <--- Transmitting SIP response (477 bytes) to TLS:10.0.0.132:1180 ---> SIP/2.0 200 OK Via: SIP/2.0/TLS 10.0.0.132:1180;rport=1180;received=10.0.0.132;branch=z9hG4bKPj1WREULfrlTXR8LMEaThAQQrA83EuOSaS;alias Call-ID: ylM7K0aZIt.IhkXVF-vE2ZuhbY0CHwPX From: "1003316" ;tag=vIiOtDf1T4NbUtnGWnbPDgQaMjKwH3fp To: "1003316" ;tag=z9hG4bKPj1WREULfrlTXR8LMEaThAQQrA83EuOSaS CSeq: 42317 REGISTER Date: Mon, 07 Sep 2020 06:48:54 GMT Expires: 0 Server: Asterisk PBX Content-Length: 0 [Sep 7 15:48:54] DEBUG[27391] manager.c: Examining AMI event: Event: PeerStatus Privilege: system,all ChannelType: PJSIP Peer: PJSIP/1003316 PeerStatus: Unreachable [Sep 7 15:48:54] DEBUG[27391] manager.c: Examining AMI event: Event: ContactStatus Privilege: system,all URI: sip:1003316@10.0.0.132:1180;transport=TLS;ob ContactStatus: Removed AOR: 1003316 EndpointName: 1003316 RoundtripUsec: 0 [Sep 7 15:48:54] DEBUG[26779] res_odbc.c: Reusing ODBC handle 0x3000fe0 from class 'asterisk' [Sep 7 15:48:54] DEBUG[26779] res_config_odbc.c: Skip: 0; SQL: SELECT * FROM ps_endpoints WHERE id = ? [Sep 7 15:48:54] DEBUG[26779] res_config_odbc.c: Parameter 1 ('id') = '1003316' [Sep 7 15:48:54] DEBUG[26779] res_odbc.c: Releasing ODBC handle 0x3000fe0 into pool [Sep 7 15:48:54] DEBUG[26779] res_sorcery_realtime.c: Filtering out realtime field 'disallow' from retrieval [Sep 7 15:48:54] DEBUG[26779] config.c: extract uint from [0] in [0, 4294967295] gives [0](0) [Sep 7 15:48:54] DEBUG[26779] config.c: extract uint from [1800] in [0, 4294967295] gives [1800](0) [Sep 7 15:48:54] DEBUG[26779] config.c: extract uint from [0] in [0, 4294967295] gives [0](0) [Sep 7 15:48:54] DEBUG[26779] config.c: extract uint from [0] in [0, 4294967295] gives [0](0) [Sep 7 15:48:54] DEBUG[26779] config.c: extract uint from [0] in [0, 4294967295] gives [0](0) [Sep 7 15:48:54] DEBUG[26779] config.c: extract uint from [1] in [0, 4294967295] gives [1](0) [Sep 7 15:48:54] DEBUG[26779] config.c: extract uint from [1] in [0, 4294967295] gives [1](0) [Sep 7 15:48:54] DEBUG[26779] config.c: extract uint from [0] in [0, 4294967295] gives [0](0) [Sep 7 15:48:54] DEBUG[26779] config.c: extract uint from [0] in [0, 4294967295] gives [0](0) [Sep 7 15:48:54] DEBUG[26779] config.c: extract uint from [0] in [0, 4294967295] gives [0](0) [Sep 7 15:48:54] DEBUG[26779] config.c: extract uint from [90] in [0, 4294967295] gives [90](0) [Sep 7 15:48:54] DEBUG[26779] config.c: extract uint from [0] in [0, 4294967295] gives [0](0) [Sep 7 15:48:54] DEBUG[26779] config.c: extract uint from [0] in [0, 4294967295] gives [0](0) [Sep 7 15:48:54] DEBUG[26779] config.c: extract uint from [1] in [0, 4294967295] gives [1](0) [Sep 7 15:48:54] DEBUG[26779] config.c: extract uint from [15] in [0, 4294967295] gives [15](0) [Sep 7 15:48:54] DEBUG[26779] devicestate.c: Changing state for PJSIP/1003316 - state 5 (Unavailable) [Sep 7 15:48:54] DEBUG[27391] manager.c: Examining AMI event: Event: DeviceStateChange Privilege: call,all Device: PJSIP/1003316 State: UNAVAILABLE [Sep 7 15:48:54] DEBUG[27433] res_odbc.c: Reusing ODBC handle 0x3000fe0 from class 'asterisk' [Sep 7 15:48:54] DEBUG[27433] res_config_odbc.c: Skip: 0; SQL: SELECT * FROM ps_endpoints WHERE id = ? [Sep 7 15:48:54] DEBUG[27433] res_config_odbc.c: Parameter 1 ('id') = '1003316' [Sep 7 15:48:54] DEBUG[27433] res_odbc.c: Releasing ODBC handle 0x3000fe0 into pool [Sep 7 15:48:54] DEBUG[27433] res_sorcery_realtime.c: Filtering out realtime field 'disallow' from retrieval