Device state doesn't change only for new accounts

Sonono · February 11, 2023, 7:12am

We have problem about device status.
We use realtime database (mariadb).
When I send register from existing account, device state change from unavailable to not in use. (see log 1)
However, when I add new account to my ps_endpoints table and send register from new account, device state doesn’t change. (see log 2. devicestate.c doesn’t appear.)
After I execute “module reload res_pjsip.so”, the device state of new account become changeable.

Actually, we are in the process of migrating the version from 13 to 18.15 and this problem doesn’t occar in 13.

We are in so much trouble…
Can anyone help us?
Please let us know even if it is a small notice.

log 1

[Feb 11 15:47:13] <--- Received SIP request (811 bytes) from TLS:180.60.8.7:35820 --->
[Feb 11 15:47:13] REGISTER sips:example.com SIP/2.0
[Feb 11 15:47:13] Via: SIP/2.0/TLS 192.168.0.145:60206;branch=z9hG4bKPjHNTO--QKSYL1k8COiDer6XaMHPqe1Ifh;alias
[Feb 11 15:47:13] Max-Forwards: 70
[Feb 11 15:47:13] From: <sips:xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx_7070@example.com>;tag=9eY4RmDls6V.RgoMg1a3JRldNTlAHMve
[Feb 11 15:47:13] To: <sips:xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx_7070@example.com>
[Feb 11 15:47:13] Call-ID: Wg7199W2nSSHzzybQB8gzLb8YCG2uFM5
[Feb 11 15:47:13] CSeq: 29160 REGISTER
[Feb 11 15:47:13] User-Agent: Phone iOS 16.0.3 94 iPhone12,8 68SV-Q8IN-JMBF
[Feb 11 15:47:13] Contact: <sips:xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx_7070@192.168.0.145:60206;transport=TLS;ob>;reg-id=1;+sip.instance="<urn:uuid:00000000-0000-0000-0000-00008bc8000b>"
[Feb 11 15:47:13] Expires: 600
[Feb 11 15:47:13] Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS
[Feb 11 15:47:13] Supported: outbound, path
[Feb 11 15:47:13] Content-Length:  0
[Feb 11 15:47:13]
[Feb 11 15:47:13]
[Feb 11 15:47:13] DEBUG[3990440]: res_pjsip/pjsip_distributor.c:393 find_dialog: Could not find matching transaction for Request msg REGISTER/cseq=29160 (rdata0x7f5ef01a4568)
[Feb 11 15:47:13] DEBUG[3990440]: res_pjsip/pjsip_distributor.c:471 ast_sip_get_distributor_serializer: Calculated serializer pjsip/distributor-000000a7 to use for Request msg REGISTER/cseq=29160 (rdata0x7f5ef01a4568)
[Feb 11 15:47:13] DEBUG[1515547]: netsock2.c:170 ast_sockaddr_split_hostport: Splitting '180.60.8.7' into...
[Feb 11 15:47:13] DEBUG[1515547]: netsock2.c:224 ast_sockaddr_split_hostport: ...host '180.60.8.7' and port ''.
[Feb 11 15:47:13] DEBUG[1515547]: res_pjsip_endpoint_identifier_ip.c:320 ip_identify_match_check: Source address 180.60.8.7:35820 does not match identify 'sbc-01'
[Feb 11 15:47:13] DEBUG[1515547]: res_pjsip_endpoint_identifier_ip.c:320 ip_identify_match_check: Source address 180.60.8.7:35820 does not match identify 'sbc-02'
[Feb 11 15:47:13] DEBUG[1515547]: res_pjsip_endpoint_identifier_ip.c:320 ip_identify_match_check: Source address 180.60.8.7:35820 does not match identify 'nobody'
[Feb 11 15:47:13] DEBUG[1515547]: res_pjsip_endpoint_identifier_ip.c:320 ip_identify_match_check: Source address 180.60.8.7:35820 does not match identify 'ipvoice-03-01'
[Feb 11 15:47:13] DEBUG[1515547]: res_pjsip_endpoint_identifier_user.c:148 username_identify: Attempting identify by From username 'xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx_7070' domain 'example.com'
[Feb 11 15:47:13] DEBUG[1515547]: res_odbc.c:965 _ast_odbc_request_obj2: Reusing ODBC handle 0x55f88ceae670 from class 'config'
[Feb 11 15:47:13] DEBUG[1515547]: res_config_odbc.c:115 custom_prepare: Skip: 0; SQL: SELECT * FROM view_ps_endpoints WHERE id = ?
[Feb 11 15:47:13] DEBUG[1515547]: res_config_odbc.c:134 custom_prepare: Parameter 1 ('id') = 'xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx_7070@example.com'
[Feb 11 15:47:13] DEBUG[1515547]: res_odbc.c:808 ast_odbc_release_obj: Releasing ODBC handle 0x55f88ceae670 into pool
[Feb 11 15:47:13] DEBUG[1515547]: res_odbc.c:965 _ast_odbc_request_obj2: Reusing ODBC handle 0x55f88ceae670 from class 'config'
[Feb 11 15:47:13] DEBUG[1515547]: res_config_odbc.c:115 custom_prepare: Skip: 0; SQL: SELECT * FROM view_ps_endpoints WHERE id = ?
[Feb 11 15:47:13] DEBUG[1515547]: res_config_odbc.c:134 custom_prepare: Parameter 1 ('id') = 'xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx_7070'
[Feb 11 15:47:13] DEBUG[1515547]: res_odbc.c:808 ast_odbc_release_obj: Releasing ODBC handle 0x55f88ceae670 into pool
[Feb 11 15:47:13] DEBUG[1515547]: res_sorcery_realtime.c:132 sorcery_realtime_filter_objectset: Filtering out realtime field 'disallow' from retrieval
[Feb 11 15:47:13] DEBUG[1515547]: res_sorcery_realtime.c:132 sorcery_realtime_filter_objectset: Filtering out realtime field 'external_media_address' from retrieval
[Feb 11 15:47:13] DEBUG[1515547]: config.c:3877 ast_parse_arg: extract uint from [0] in [0, 4294967295] gives [0](0)
[Feb 11 15:47:13] DEBUG[1515547]: config.c:3877 ast_parse_arg: extract uint from [1800] in [0, 4294967295] gives [1800](0)
[Feb 11 15:47:13] DEBUG[1515547]: config.c:3877 ast_parse_arg: extract uint from [0] in [0, 4294967295] gives [0](0)
[Feb 11 15:47:13] DEBUG[1515547]: config.c:3877 ast_parse_arg: extract uint from [0] in [0, 4294967295] gives [0](0)
[Feb 11 15:47:13] DEBUG[1515547]: config.c:3877 ast_parse_arg: extract uint from [0] in [0, 4294967295] gives [0](0)
[Feb 11 15:47:13] DEBUG[1515547]: config.c:3877 ast_parse_arg: extract uint from [1] in [0, 4294967295] gives [1](0)
[Feb 11 15:47:13] DEBUG[1515547]: config.c:3877 ast_parse_arg: extract uint from [1] in [0, 4294967295] gives [1](0)
[Feb 11 15:47:13] DEBUG[1515547]: config.c:3877 ast_parse_arg: extract uint from [0] in [0, 4294967295] gives [0](0)
[Feb 11 15:47:13] DEBUG[1515547]: config.c:3877 ast_parse_arg: extract uint from [0] in [0, 4294967295] gives [0](0)
[Feb 11 15:47:13] DEBUG[1515547]: config.c:3877 ast_parse_arg: extract uint from [0] in [0, 4294967295] gives [0](0)
[Feb 11 15:47:13] DEBUG[1515547]: config.c:3877 ast_parse_arg: extract uint from [90] in [0, 4294967295] gives [90](0)
[Feb 11 15:47:13] DEBUG[1515547]: config.c:3877 ast_parse_arg: extract uint from [0] in [0, 4294967295] gives [0](0)
[Feb 11 15:47:13] DEBUG[1515547]: config.c:3877 ast_parse_arg: extract uint from [0] in [0, 4294967295] gives [0](0)
[Feb 11 15:47:13] DEBUG[1515547]: config.c:3877 ast_parse_arg: extract uint from [90] in [0, 4294967295] gives [90](0)
[Feb 11 15:47:13] DEBUG[1515547]: config.c:3877 ast_parse_arg: extract uint from [7300] in [0, 4294967295] gives [7300](0)
[Feb 11 15:47:13] DEBUG[1515547]: config.c:3877 ast_parse_arg: extract uint from [30] in [0, 4294967295] gives [30](0)
[Feb 11 15:47:13] DEBUG[1515547]: config.c:3877 ast_parse_arg: extract uint from [600] in [0, 4294967295] gives [600](0)
[Feb 11 15:47:13] DEBUG[1515547]: res_pjsip_endpoint_identifier_user.c:160 username_identify: Identified by From username 'xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx_7070' domain 'example.com'
[Feb 11 15:47:13] DEBUG[1515547]: res_pjsip_nat.c:55 save_orig_contact_host: Saving contact '192.168.0.145:60206'
[Feb 11 15:47:13] DEBUG[1515547]: res_odbc.c:965 _ast_odbc_request_obj2: Reusing ODBC handle 0x55f88ceae670 from class 'config'
[Feb 11 15:47:13] DEBUG[1515547]: res_config_odbc.c:115 custom_prepare: Skip: 0; SQL: SELECT * FROM view_ps_auths WHERE id = ?
[Feb 11 15:47:13] DEBUG[1515547]: res_config_odbc.c:134 custom_prepare: Parameter 1 ('id') = 'xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx_7070'
[Feb 11 15:47:13] DEBUG[1515547]: res_odbc.c:808 ast_odbc_release_obj: Releasing ODBC handle 0x55f88ceae670 into pool
[Feb 11 15:47:13] DEBUG[1515547]: config.c:3877 ast_parse_arg: extract uint from [32] in [0, 4294967295] gives [32](0)
[Feb 11 15:47:13] DEBUG[1515547]: res_pjsip_authenticator_digest.c:358 verify: Realm: example.com  Username: xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx_7070  Result: NOAUTH
[Feb 11 15:47:13] DEBUG[1515547]: netsock2.c:170 ast_sockaddr_split_hostport: Splitting '10.0.2.193' into...
[Feb 11 15:47:13] DEBUG[1515547]: netsock2.c:224 ast_sockaddr_split_hostport: ...host '10.0.2.193' and port ''.
[Feb 11 15:47:13] DEBUG[1515547]: netsock2.c:170 ast_sockaddr_split_hostport: Splitting '180.60.8.7' into...
[Feb 11 15:47:13] DEBUG[1515547]: netsock2.c:224 ast_sockaddr_split_hostport: ...host '180.60.8.7' and port ''.
[Feb 11 15:47:13] <--- Transmitting SIP response (632 bytes) to TLS:180.60.8.7:35820 --->
[Feb 11 15:47:13] SIP/2.0 401 Unauthorized
[Feb 11 15:47:13] Via: SIP/2.0/TLS 192.168.0.145:60206;branch=z9hG4bKPjHNTO--QKSYL1k8COiDer6XaMHPqe1Ifh;alias
[Feb 11 15:47:13] Call-ID: Wg7199W2nSSHzzybQB8gzLb8YCG2uFM5
[Feb 11 15:47:13] From: <sips:xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx_7070@example.com>;tag=9eY4RmDls6V.RgoMg1a3JRldNTlAHMve
[Feb 11 15:47:13] To: <sips:xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx_7070@example.com>;tag=z9hG4bKPjHNTO--QKSYL1k8COiDer6XaMHPqe1Ifh
[Feb 11 15:47:13] CSeq: 29160 REGISTER
[Feb 11 15:47:13] WWW-Authenticate: Digest realm="example.com",nonce="1676098033/25030be1cadb875b09b11c686e9386dd",opaque="32dd4a7260495fd1",algorithm=MD5,qop="auth"
[Feb 11 15:47:13] Server: Biz Cloud PBX/18.15
[Feb 11 15:47:13] Content-Length:  0
[Feb 11 15:47:13]
[Feb 11 15:47:13]
[Feb 11 15:47:13] <--- Received SIP request (1160 bytes) from TLS:180.60.8.7:35820 --->
[Feb 11 15:47:13] REGISTER sips:example.com SIP/2.0
[Feb 11 15:47:13] Via: SIP/2.0/TLS 192.168.0.145:60206;branch=z9hG4bKPjZgVLVXGLLV7KfGK0-mWGsqB5iuZwZ5cX;alias
[Feb 11 15:47:13] Max-Forwards: 70
[Feb 11 15:47:13] From: <sips:xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx_7070@example.com>;tag=9eY4RmDls6V.RgoMg1a3JRldNTlAHMve
[Feb 11 15:47:13] To: <sips:xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx_7070@example.com>
[Feb 11 15:47:13] Call-ID: Wg7199W2nSSHzzybQB8gzLb8YCG2uFM5
[Feb 11 15:47:13] CSeq: 29161 REGISTER
[Feb 11 15:47:13] User-Agent: Phone iOS 16.0.3 94 iPhone12,8 68SV-Q8IN-JMBF
[Feb 11 15:47:13] Contact: <sips:xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx_7070@192.168.0.145:60206;transport=TLS;ob>;reg-id=1;+sip.instance="<urn:uuid:00000000-0000-0000-0000-00008bc8000b>"
[Feb 11 15:47:13] Expires: 600
[Feb 11 15:47:13] Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS
[Feb 11 15:47:13] Authorization: Digest username="xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx_7070", realm="example.com", nonce="1676098033/25030be1cadb875b09b11c686e9386dd", uri="sips:example.com", response="91e25d995a08680704ed41a758c2b934", algorithm=MD5, cnonce="2-HMd4y2PFCUNSDTBPpS0B9Hh5NvJd.h", opaque="32dd4a7260495fd1", qop=auth, nc=00000001
[Feb 11 15:47:13] Supported: outbound, path
[Feb 11 15:47:13] Content-Length:  0
[Feb 11 15:47:13]
[Feb 11 15:47:13]
[Feb 11 15:47:13] DEBUG[3990440]: res_pjsip/pjsip_distributor.c:393 find_dialog: Could not find matching transaction for Request msg REGISTER/cseq=29161 (rdata0x7f5ef01a4568)
[Feb 11 15:47:13] DEBUG[3990440]: res_pjsip/pjsip_distributor.c:471 ast_sip_get_distributor_serializer: Calculated serializer pjsip/distributor-000000a7 to use for Request msg REGISTER/cseq=29161 (rdata0x7f5ef01a4568)
[Feb 11 15:47:13] DEBUG[495160]: netsock2.c:170 ast_sockaddr_split_hostport: Splitting '180.60.8.7' into...
[Feb 11 15:47:13] DEBUG[495160]: netsock2.c:224 ast_sockaddr_split_hostport: ...host '180.60.8.7' and port ''.
[Feb 11 15:47:13] DEBUG[495160]: res_pjsip_endpoint_identifier_ip.c:320 ip_identify_match_check: Source address 180.60.8.7:35820 does not match identify 'sbc-01'
[Feb 11 15:47:13] DEBUG[495160]: res_pjsip_endpoint_identifier_ip.c:320 ip_identify_match_check: Source address 180.60.8.7:35820 does not match identify 'sbc-02'
[Feb 11 15:47:13] DEBUG[495160]: res_pjsip_endpoint_identifier_ip.c:320 ip_identify_match_check: Source address 180.60.8.7:35820 does not match identify 'nobody'
[Feb 11 15:47:13] DEBUG[495160]: res_pjsip_endpoint_identifier_ip.c:320 ip_identify_match_check: Source address 180.60.8.7:35820 does not match identify 'ipvoice-03-01'
[Feb 11 15:47:13] DEBUG[495160]: res_pjsip_endpoint_identifier_user.c:148 username_identify: Attempting identify by From username 'xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx_7070' domain 'example.com'
[Feb 11 15:47:13] DEBUG[495160]: res_odbc.c:965 _ast_odbc_request_obj2: Reusing ODBC handle 0x55f88ceae670 from class 'config'
[Feb 11 15:47:13] DEBUG[495160]: res_config_odbc.c:115 custom_prepare: Skip: 0; SQL: SELECT * FROM view_ps_endpoints WHERE id = ?
[Feb 11 15:47:13] DEBUG[495160]: res_config_odbc.c:134 custom_prepare: Parameter 1 ('id') = 'xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx_7070@example.com'
[Feb 11 15:47:13] DEBUG[495160]: res_odbc.c:808 ast_odbc_release_obj: Releasing ODBC handle 0x55f88ceae670 into pool
[Feb 11 15:47:13] DEBUG[495160]: res_pjsip_endpoint_identifier_user.c:160 username_identify: Identified by From username 'xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx_7070' domain 'example.com'
[Feb 11 15:47:13] DEBUG[495160]: res_pjsip_nat.c:55 save_orig_contact_host: Saving contact '192.168.0.145:60206'
[Feb 11 15:47:13] DEBUG[495160]: res_pjsip_authenticator_digest.c:261 check_nonce: Calculated nonce 1676098033/25030be1cadb875b09b11c686e9386dd. Actual nonce is 1676098033/25030be1cadb875b09b11c686e9386dd
[Feb 11 15:47:13] DEBUG[495160]: res_pjsip_authenticator_digest.c:358 verify: Realm: example.com  Username: xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx_7070  Result: SUCCESS
[Feb 11 15:47:13] DEBUG[495160]: netsock2.c:170 ast_sockaddr_split_hostport: Splitting '10.0.2.193' into...
[Feb 11 15:47:13] DEBUG[495160]: netsock2.c:224 ast_sockaddr_split_hostport: ...host '10.0.2.193' and port ''.
[Feb 11 15:47:13] DEBUG[495160]: netsock2.c:170 ast_sockaddr_split_hostport: Splitting '180.60.8.7' into...
[Feb 11 15:47:13] DEBUG[495160]: netsock2.c:224 ast_sockaddr_split_hostport: ...host '180.60.8.7' and port ''.
[Feb 11 15:47:13] DEBUG[495160]: res_pjsip_registrar.c:1038 match_aor: Matched id 'xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx_7070' to aor 'xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx_7070'
[Feb 11 15:47:13] DEBUG[495160]: res_pjsip_registrar.c:1137 find_registrar_aor: Matched aor 'xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx_7070' by To username
[Feb 11 15:47:13] DEBUG[495160]: res_odbc.c:965 _ast_odbc_request_obj2: Reusing ODBC handle 0x55f88ceae670 from class 'config'
[Feb 11 15:47:13] DEBUG[495160]: res_config_odbc.c:115 custom_prepare: Skip: 0; SQL: SELECT * FROM view_ps_aors WHERE id = ?
[Feb 11 15:47:13] DEBUG[495160]: res_config_odbc.c:134 custom_prepare: Parameter 1 ('id') = 'xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx_7070'
[Feb 11 15:47:13] DEBUG[495160]: res_odbc.c:808 ast_odbc_release_obj: Releasing ODBC handle 0x55f88ceae670 into pool
[Feb 11 15:47:13] DEBUG[495160]: config.c:3964 ast_parse_arg: extract double from [3.0] in [-inf, inf] gives [3.000000](0)
[Feb 11 15:47:13] DEBUG[495160]: config.c:3877 ast_parse_arg: extract uint from [7200] in [0, 4294967295] gives [7200](0)
[Feb 11 15:47:13] DEBUG[495160]: config.c:3877 ast_parse_arg: extract uint from [3600] in [0, 4294967295] gives [3600](0)
[Feb 11 15:47:13] DEBUG[495160]: config.c:3877 ast_parse_arg: extract uint from [60] in [0, 4294967295] gives [60](0)
[Feb 11 15:47:13] DEBUG[495160]: config.c:3877 ast_parse_arg: extract uint from [0] in [0, 4294967295] gives [0](0)
[Feb 11 15:47:13] DEBUG[495160]: config.c:3877 ast_parse_arg: extract uint from [300] in [0, 4294967295] gives [300](0)
[Feb 11 15:47:13] DEBUG[495160]: config.c:3877 ast_parse_arg: extract uint from [1] in [0, 4294967295] gives [1](0)
[Feb 11 15:47:13] DEBUG[495160]: config.c:3877 ast_parse_arg: extract uint from [300] in [0, 4294967295] gives [300](0)
[Feb 11 15:47:13] DEBUG[495160]: config.c:3877 ast_parse_arg: extract uint from [300] in [0, 4294967295] gives [300](0)
[Feb 11 15:47:13] DEBUG[495160]: config.c:3964 ast_parse_arg: extract double from [3.0] in [-inf, inf] gives [3.000000](0)
[Feb 11 15:47:13] DEBUG[495160]: config.c:3877 ast_parse_arg: extract uint from [0] in [0, 4294967295] gives [0](0)
[Feb 11 15:47:13] DEBUG[495160]: res_pjsip/pjsip_transport_events.c:468 ast_sip_transport_monitor_register_replace: Registered monitor 0x7f5f74107f30(0x7f5fb4024dc0) to transport tlss0x7f5ef01a4278
[Feb 11 15:47:13]     -- Added contact 'sips:xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx_7070@180.60.8.7:35820;transport=TLS;ob;x-ast-orig-host=192.168.0.145:60206' to AOR 'xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx_7070' with expiration of 300 seconds
[Feb 11 15:47:13] DEBUG[495160]: res_pjsip_nat.c:345 restore_orig_contact_host: Restoring contact 180.60.8.7:35820  to 192.168.0.145:60206
[Feb 11 15:47:13] <--- Transmitting SIP response (615 bytes) to TLS:180.60.8.7:35820 --->
[Feb 11 15:47:13] SIP/2.0 200 OK
[Feb 11 15:47:13] Via: SIP/2.0/TLS 192.168.0.145:60206;branch=z9hG4bKPjZgVLVXGLLV7KfGK0-mWGsqB5iuZwZ5cX;alias
[Feb 11 15:47:13] Call-ID: Wg7199W2nSSHzzybQB8gzLb8YCG2uFM5
[Feb 11 15:47:13] From: <sips:xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx_7070@example.com>;tag=9eY4RmDls6V.RgoMg1a3JRldNTlAHMve
[Feb 11 15:47:13] To: <sips:xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx_7070@example.com>;tag=z9hG4bKPjZgVLVXGLLV7KfGK0-mWGsqB5iuZwZ5cX
[Feb 11 15:47:13] CSeq: 29161 REGISTER
[Feb 11 15:47:13] Date: Sat, 11 Feb 2023 06:47:13 GMT
[Feb 11 15:47:13] Contact: <sips:xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx_7070@192.168.0.145:60206;transport=TLS;ob>;expires=299
[Feb 11 15:47:13] Expires: 300
[Feb 11 15:47:13] Server: Biz Cloud PBX/18.15
[Feb 11 15:47:13] Content-Length:  0
[Feb 11 15:47:13]
[Feb 11 15:47:13]
[Feb 11 15:47:13] DEBUG[495160]: res_pjsip/pjsip_options.c:2138 sip_options_contact_add_task: An unqualified contact has been added to AOR 'xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx_7070' so it is now available
[Feb 11 15:47:13] DEBUG[495160]: res_pjsip/pjsip_options.c:620 sip_options_update_endpoint_state_compositor_aor: Endpoint state compositor 'xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx_7070' is online as AOR 'xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx_7070' is available
[Feb 11 15:47:13]   == Endpoint xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx_7070 is now Reachable
[Feb 11 15:47:13] DEBUG[3990403]: devicestate.c:361 _ast_device_state: No provider found, checking channel drivers for PJSIP - xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx_7070
[Feb 11 15:47:13] DEBUG[3990403]: devicestate.c:466 do_state_change: Changing state for PJSIP/xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx_7070 - state 1 (Not in use)
[Feb 11 15:47:13] DEBUG[3990478]: app_queue.c:2720 device_state_cb: Device 'PJSIP/xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx_7070' changed to state '1' (Not in use) but we don't care because they're not a member of any queue.

Sonono · February 11, 2023, 7:12am

log2

[Feb 11 16:02:22] DEBUG[3990440]: res_pjsip/pjsip_transport_events.c:272 transport_state_callback: Reliable transport 'tlss0x7f5ef01a4278' state:CONNECTED
[Feb 11 16:02:22] <--- Received SIP request (811 bytes) from TLS:180.60.8.7:37866 --->
[Feb 11 16:02:22] REGISTER sips:example.com SIP/2.0
[Feb 11 16:02:22] Via: SIP/2.0/TLS 192.168.0.145:60208;branch=z9hG4bKPjUvbrZ07.KhF5FT3.isgcT7BNiuGho9xK;alias
[Feb 11 16:02:22] Max-Forwards: 70
[Feb 11 16:02:22] From: <sips:xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx_7092@example.com>;tag=19fwnzhcxdcZH..76SG98F-rPf5DsXhk
[Feb 11 16:02:22] To: <sips:xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx_7092@example.com>
[Feb 11 16:02:22] Call-ID: 6QBcuz8MQPDFJn3kDCgNthWAdySk0aiU
[Feb 11 16:02:22] CSeq: 35872 REGISTER
[Feb 11 16:02:22] User-Agent: Phone iOS 16.0.3 94 iPhone12,8 68SV-Q8IN-JMBF
[Feb 11 16:02:22] Contact: <sips:xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx_7092@192.168.0.145:60208;transport=TLS;ob>;reg-id=1;+sip.instance="<urn:uuid:00000000-0000-0000-0000-00008bc8000b>"
[Feb 11 16:02:22] Expires: 600
[Feb 11 16:02:22] Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS
[Feb 11 16:02:22] Supported: outbound, path
[Feb 11 16:02:22] Content-Length:  0
[Feb 11 16:02:22]
[Feb 11 16:02:22]
[Feb 11 16:02:22] DEBUG[3990440]: res_pjsip/pjsip_distributor.c:393 find_dialog: Could not find matching transaction for Request msg REGISTER/cseq=35872 (rdata0x7f5ef01a4568)
[Feb 11 16:02:22] DEBUG[3990440]: res_pjsip/pjsip_distributor.c:471 ast_sip_get_distributor_serializer: Calculated serializer pjsip/distributor-000000a9 to use for Request msg REGISTER/cseq=35872 (rdata0x7f5ef01a4568)
[Feb 11 16:02:22] DEBUG[495160]: netsock2.c:170 ast_sockaddr_split_hostport: Splitting '180.60.8.7' into...
[Feb 11 16:02:22] DEBUG[495160]: netsock2.c:224 ast_sockaddr_split_hostport: ...host '180.60.8.7' and port ''.
[Feb 11 16:02:22] DEBUG[495160]: res_pjsip_endpoint_identifier_ip.c:320 ip_identify_match_check: Source address 180.60.8.7:37866 does not match identify 'sbc-01'
[Feb 11 16:02:22] DEBUG[495160]: res_pjsip_endpoint_identifier_ip.c:320 ip_identify_match_check: Source address 180.60.8.7:37866 does not match identify 'sbc-02'
[Feb 11 16:02:22] DEBUG[495160]: res_pjsip_endpoint_identifier_ip.c:320 ip_identify_match_check: Source address 180.60.8.7:37866 does not match identify 'nobody'
[Feb 11 16:02:22] DEBUG[495160]: res_pjsip_endpoint_identifier_ip.c:320 ip_identify_match_check: Source address 180.60.8.7:37866 does not match identify 'ipvoice-03-01'
[Feb 11 16:02:22] DEBUG[495160]: res_pjsip_endpoint_identifier_user.c:148 username_identify: Attempting identify by From username 'xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx_7092' domain 'example.com'
[Feb 11 16:02:22] DEBUG[495160]: res_odbc.c:965 _ast_odbc_request_obj2: Reusing ODBC handle 0x55f88ceae670 from class 'config'
[Feb 11 16:02:22] DEBUG[495160]: res_config_odbc.c:115 custom_prepare: Skip: 0; SQL: SELECT * FROM view_ps_endpoints WHERE id = ?
[Feb 11 16:02:22] DEBUG[495160]: res_config_odbc.c:134 custom_prepare: Parameter 1 ('id') = 'xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx_7092@example.com'
[Feb 11 16:02:22] DEBUG[495160]: res_odbc.c:808 ast_odbc_release_obj: Releasing ODBC handle 0x55f88ceae670 into pool
[Feb 11 16:02:22] DEBUG[495160]: res_odbc.c:965 _ast_odbc_request_obj2: Reusing ODBC handle 0x55f88ceae670 from class 'config'
[Feb 11 16:02:22] DEBUG[495160]: res_config_odbc.c:115 custom_prepare: Skip: 0; SQL: SELECT * FROM view_ps_endpoints WHERE id = ?
[Feb 11 16:02:22] DEBUG[495160]: res_config_odbc.c:134 custom_prepare: Parameter 1 ('id') = 'xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx_7092'
[Feb 11 16:02:22] DEBUG[495160]: res_odbc.c:808 ast_odbc_release_obj: Releasing ODBC handle 0x55f88ceae670 into pool
[Feb 11 16:02:22] DEBUG[495160]: res_sorcery_realtime.c:132 sorcery_realtime_filter_objectset: Filtering out realtime field 'disallow' from retrieval
[Feb 11 16:02:22] DEBUG[495160]: res_sorcery_realtime.c:132 sorcery_realtime_filter_objectset: Filtering out realtime field 'external_media_address' from retrieval
[Feb 11 16:02:22] DEBUG[495160]: config.c:3877 ast_parse_arg: extract uint from [0] in [0, 4294967295] gives [0](0)
[Feb 11 16:02:22] DEBUG[495160]: config.c:3877 ast_parse_arg: extract uint from [1800] in [0, 4294967295] gives [1800](0)
[Feb 11 16:02:22] DEBUG[495160]: config.c:3877 ast_parse_arg: extract uint from [0] in [0, 4294967295] gives [0](0)
[Feb 11 16:02:22] DEBUG[495160]: config.c:3877 ast_parse_arg: extract uint from [0] in [0, 4294967295] gives [0](0)
[Feb 11 16:02:22] DEBUG[495160]: config.c:3877 ast_parse_arg: extract uint from [0] in [0, 4294967295] gives [0](0)
[Feb 11 16:02:22] DEBUG[495160]: config.c:3877 ast_parse_arg: extract uint from [1] in [0, 4294967295] gives [1](0)
[Feb 11 16:02:22] DEBUG[495160]: config.c:3877 ast_parse_arg: extract uint from [1] in [0, 4294967295] gives [1](0)
[Feb 11 16:02:22] DEBUG[495160]: config.c:3877 ast_parse_arg: extract uint from [0] in [0, 4294967295] gives [0](0)
[Feb 11 16:02:22] DEBUG[495160]: config.c:3877 ast_parse_arg: extract uint from [0] in [0, 4294967295] gives [0](0)
[Feb 11 16:02:22] DEBUG[495160]: config.c:3877 ast_parse_arg: extract uint from [0] in [0, 4294967295] gives [0](0)
[Feb 11 16:02:22] DEBUG[495160]: config.c:3877 ast_parse_arg: extract uint from [90] in [0, 4294967295] gives [90](0)
[Feb 11 16:02:22] DEBUG[495160]: config.c:3877 ast_parse_arg: extract uint from [0] in [0, 4294967295] gives [0](0)
[Feb 11 16:02:22] DEBUG[495160]: config.c:3877 ast_parse_arg: extract uint from [0] in [0, 4294967295] gives [0](0)
[Feb 11 16:02:22] DEBUG[495160]: config.c:3877 ast_parse_arg: extract uint from [90] in [0, 4294967295] gives [90](0)
[Feb 11 16:02:22] DEBUG[495160]: config.c:3877 ast_parse_arg: extract uint from [7300] in [0, 4294967295] gives [7300](0)
[Feb 11 16:02:22] DEBUG[495160]: config.c:3877 ast_parse_arg: extract uint from [30] in [0, 4294967295] gives [30](0)
[Feb 11 16:02:22] DEBUG[495160]: config.c:3877 ast_parse_arg: extract uint from [600] in [0, 4294967295] gives [600](0)
[Feb 11 16:02:22] DEBUG[495160]: stasis.c:580 stasis_topic_create_with_detail: Creating topic. name: endpoint:PJSIP/xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx_7092, detail:
[Feb 11 16:02:22] DEBUG[495160]: stasis.c:614 stasis_topic_create_with_detail: Topic 'endpoint:PJSIP/xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx_7092': 0x7f5fb4012df0 created
[Feb 11 16:02:22] DEBUG[495160]: stasis.c:580 stasis_topic_create_with_detail: Creating topic. name: cache:122/endpoint:PJSIP/xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx_7092, detail:
[Feb 11 16:02:22] DEBUG[495160]: stasis.c:614 stasis_topic_create_with_detail: Topic 'cache:122/endpoint:PJSIP/xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx_7092': 0x7f5fb4054900 created
[Feb 11 16:02:22] DEBUG[495160]: res_pjsip_endpoint_identifier_user.c:160 username_identify: Identified by From username 'xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx_7092' domain 'example.com'
[Feb 11 16:02:22] DEBUG[3990382]: threadpool.c:536 grow: Increasing threadpool stasis/pool's size by 1
[Feb 11 16:02:22] DEBUG[495160]: res_pjsip_nat.c:55 save_orig_contact_host: Saving contact '192.168.0.145:60208'
[Feb 11 16:02:22] DEBUG[495160]: res_odbc.c:965 _ast_odbc_request_obj2: Reusing ODBC handle 0x55f88ceae670 from class 'config'
[Feb 11 16:02:22] DEBUG[495160]: res_config_odbc.c:115 custom_prepare: Skip: 0; SQL: SELECT * FROM view_ps_auths WHERE id = ?
[Feb 11 16:02:22] DEBUG[495160]: res_config_odbc.c:134 custom_prepare: Parameter 1 ('id') = 'xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx_7092'
[Feb 11 16:02:22] DEBUG[495160]: res_odbc.c:808 ast_odbc_release_obj: Releasing ODBC handle 0x55f88ceae670 into pool
[Feb 11 16:02:22] DEBUG[495160]: config.c:3877 ast_parse_arg: extract uint from [32] in [0, 4294967295] gives [32](0)
[Feb 11 16:02:22] DEBUG[495160]: res_pjsip_authenticator_digest.c:358 verify: Realm: example.com  Username: xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx_7092  Result: NOAUTH
[Feb 11 16:02:22] DEBUG[495160]: netsock2.c:170 ast_sockaddr_split_hostport: Splitting '10.0.2.193' into...
[Feb 11 16:02:22] DEBUG[495160]: netsock2.c:224 ast_sockaddr_split_hostport: ...host '10.0.2.193' and port ''.
[Feb 11 16:02:22] DEBUG[495160]: netsock2.c:170 ast_sockaddr_split_hostport: Splitting '180.60.8.7' into...
[Feb 11 16:02:22] DEBUG[495160]: netsock2.c:224 ast_sockaddr_split_hostport: ...host '180.60.8.7' and port ''.
[Feb 11 16:02:22] <--- Transmitting SIP response (632 bytes) to TLS:180.60.8.7:37866 --->
[Feb 11 16:02:22] SIP/2.0 401 Unauthorized
[Feb 11 16:02:22] Via: SIP/2.0/TLS 192.168.0.145:60208;branch=z9hG4bKPjUvbrZ07.KhF5FT3.isgcT7BNiuGho9xK;alias
[Feb 11 16:02:22] Call-ID: 6QBcuz8MQPDFJn3kDCgNthWAdySk0aiU
[Feb 11 16:02:22] From: <sips:xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx_7092@example.com>;tag=19fwnzhcxdcZH..76SG98F-rPf5DsXhk
[Feb 11 16:02:22] To: <sips:xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx_7092@example.com>;tag=z9hG4bKPjUvbrZ07.KhF5FT3.isgcT7BNiuGho9xK
[Feb 11 16:02:22] CSeq: 35872 REGISTER
[Feb 11 16:02:22] WWW-Authenticate: Digest realm="example.com",nonce="1676098942/eae74de4ad6902c218e6440f9fa05f83",opaque="677c1dfc3fb260fb",algorithm=MD5,qop="auth"
[Feb 11 16:02:22] Server: Biz Cloud PBX/18.15
[Feb 11 16:02:22] Content-Length:  0

[Feb 11 16:02:22] <--- Received SIP request (1160 bytes) from TLS:180.60.8.7:37866 --->
[Feb 11 16:02:22] REGISTER sips:example.com SIP/2.0
[Feb 11 16:02:22] Via: SIP/2.0/TLS 192.168.0.145:60208;branch=z9hG4bKPj6PVhaaX7sYQQj0WDR1ww-QxOCT2XjWt3;alias
[Feb 11 16:02:22] Max-Forwards: 70
[Feb 11 16:02:22] From: <sips:xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx_7092@example.com>;tag=19fwnzhcxdcZH..76SG98F-rPf5DsXhk
[Feb 11 16:02:22] To: <sips:xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx_7092@example.com>
[Feb 11 16:02:22] Call-ID: 6QBcuz8MQPDFJn3kDCgNthWAdySk0aiU
[Feb 11 16:02:22] CSeq: 35873 REGISTER
[Feb 11 16:02:22] User-Agent: Phone iOS 16.0.3 94 iPhone12,8 68SV-Q8IN-JMBF
[Feb 11 16:02:22] Contact: <sips:xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx_7092@192.168.0.145:60208;transport=TLS;ob>;reg-id=1;+sip.instance="<urn:uuid:00000000-0000-0000-0000-00008bc8000b>"
[Feb 11 16:02:22] Expires: 600
[Feb 11 16:02:22] Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS
[Feb 11 16:02:22] Authorization: Digest username="xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx_7092", realm="example.com", nonce="1676098942/eae74de4ad6902c218e6440f9fa05f83", uri="sips:example.com", response="7856959b7c561c7a630d4736d7bbb4a3", algorithm=MD5, cnonce="mbNbJUEkysDY4q2msOcwjgUNcztyyrQF", opaque="677c1dfc3fb260fb", qop=auth, nc=00000001
[Feb 11 16:02:22] Supported: outbound, path
[Feb 11 16:02:22] Content-Length:  0
[Feb 11 16:02:22]
[Feb 11 16:02:22]
[Feb 11 16:02:22] DEBUG[3990440]: res_pjsip/pjsip_distributor.c:393 find_dialog: Could not find matching transaction for Request msg REGISTER/cseq=35873 (rdata0x7f5ef01a4568)
[Feb 11 16:02:22] DEBUG[3990440]: res_pjsip/pjsip_distributor.c:471 ast_sip_get_distributor_serializer: Calculated serializer pjsip/distributor-000000a9 to use for Request msg REGISTER/cseq=35873 (rdata0x7f5ef01a4568)
[Feb 11 16:02:22] DEBUG[1515547]: netsock2.c:170 ast_sockaddr_split_hostport: Splitting '180.60.8.7' into...
[Feb 11 16:02:22] DEBUG[1515547]: netsock2.c:224 ast_sockaddr_split_hostport: ...host '180.60.8.7' and port ''.
[Feb 11 16:02:22] DEBUG[1515547]: res_pjsip_endpoint_identifier_ip.c:320 ip_identify_match_check: Source address 180.60.8.7:37866 does not match identify 'sbc-01'
[Feb 11 16:02:22] DEBUG[1515547]: res_pjsip_endpoint_identifier_ip.c:320 ip_identify_match_check: Source address 180.60.8.7:37866 does not match identify 'sbc-02'
[Feb 11 16:02:22] DEBUG[1515547]: res_pjsip_endpoint_identifier_ip.c:320 ip_identify_match_check: Source address 180.60.8.7:37866 does not match identify 'nobody'
[Feb 11 16:02:22] DEBUG[1515547]: res_pjsip_endpoint_identifier_ip.c:320 ip_identify_match_check: Source address 180.60.8.7:37866 does not match identify 'ipvoice-03-01'
[Feb 11 16:02:22] DEBUG[1515547]: res_pjsip_endpoint_identifier_user.c:148 username_identify: Attempting identify by From username 'xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx_7092' domain 'example.com'
[Feb 11 16:02:22] DEBUG[1515547]: res_odbc.c:965 _ast_odbc_request_obj2: Reusing ODBC handle 0x55f88ceae670 from class 'config'
[Feb 11 16:02:22] DEBUG[1515547]: res_config_odbc.c:115 custom_prepare: Skip: 0; SQL: SELECT * FROM view_ps_endpoints WHERE id = ?
[Feb 11 16:02:22] DEBUG[1515547]: res_config_odbc.c:134 custom_prepare: Parameter 1 ('id') = 'xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx_7092@example.com'
[Feb 11 16:02:22] DEBUG[1515547]: res_odbc.c:808 ast_odbc_release_obj: Releasing ODBC handle 0x55f88ceae670 into pool
[Feb 11 16:02:22] DEBUG[1515547]: res_pjsip_endpoint_identifier_user.c:160 username_identify: Identified by From username 'xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx_7092' domain 'example.com'
[Feb 11 16:02:22] DEBUG[1515547]: res_pjsip_nat.c:55 save_orig_contact_host: Saving contact '192.168.0.145:60208'
[Feb 11 16:02:22] DEBUG[1515547]: res_pjsip_authenticator_digest.c:261 check_nonce: Calculated nonce 1676098942/eae74de4ad6902c218e6440f9fa05f83. Actual nonce is 1676098942/eae74de4ad6902c218e6440f9fa05f83
[Feb 11 16:02:22] DEBUG[1515547]: res_pjsip_authenticator_digest.c:358 verify: Realm: example.com  Username: xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx_7092  Result: SUCCESS
[Feb 11 16:02:22] DEBUG[1515547]: netsock2.c:170 ast_sockaddr_split_hostport: Splitting '10.0.2.193' into...
[Feb 11 16:02:22] DEBUG[1515547]: netsock2.c:224 ast_sockaddr_split_hostport: ...host '10.0.2.193' and port ''.
[Feb 11 16:02:22] DEBUG[1515547]: netsock2.c:170 ast_sockaddr_split_hostport: Splitting '180.60.8.7' into...
[Feb 11 16:02:22] DEBUG[1515547]: netsock2.c:224 ast_sockaddr_split_hostport: ...host '180.60.8.7' and port ''.
[Feb 11 16:02:22] DEBUG[1515547]: res_pjsip_registrar.c:1038 match_aor: Matched id 'xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx_7092' to aor 'xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx_7092'
[Feb 11 16:02:22] DEBUG[1515547]: res_pjsip_registrar.c:1137 find_registrar_aor: Matched aor 'xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx_7092' by To username
[Feb 11 16:02:22] DEBUG[1515547]: res_odbc.c:965 _ast_odbc_request_obj2: Reusing ODBC handle 0x55f88ceae670 from class 'config'
[Feb 11 16:02:22] DEBUG[1515547]: res_config_odbc.c:115 custom_prepare: Skip: 0; SQL: SELECT * FROM view_ps_aors WHERE id = ?
[Feb 11 16:02:22] DEBUG[1515547]: res_config_odbc.c:134 custom_prepare: Parameter 1 ('id') = 'xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx_7092'
[Feb 11 16:02:22] DEBUG[1515547]: res_odbc.c:808 ast_odbc_release_obj: Releasing ODBC handle 0x55f88ceae670 into pool
[Feb 11 16:02:22] DEBUG[1515547]: config.c:3964 ast_parse_arg: extract double from [3.0] in [-inf, inf] gives [3.000000](0)
[Feb 11 16:02:22] DEBUG[1515547]: config.c:3877 ast_parse_arg: extract uint from [7200] in [0, 4294967295] gives [7200](0)
[Feb 11 16:02:22] DEBUG[1515547]: config.c:3877 ast_parse_arg: extract uint from [3600] in [0, 4294967295] gives [3600](0)
[Feb 11 16:02:22] DEBUG[1515547]: config.c:3877 ast_parse_arg: extract uint from [60] in [0, 4294967295] gives [60](0)
[Feb 11 16:02:22] DEBUG[1515547]: config.c:3877 ast_parse_arg: extract uint from [0] in [0, 4294967295] gives [0](0)
[Feb 11 16:02:22] DEBUG[1515547]: config.c:3877 ast_parse_arg: extract uint from [300] in [0, 4294967295] gives [300](0)
[Feb 11 16:02:22] DEBUG[1515547]: config.c:3877 ast_parse_arg: extract uint from [1] in [0, 4294967295] gives [1](0)
[Feb 11 16:02:22] DEBUG[1515547]: config.c:3877 ast_parse_arg: extract uint from [300] in [0, 4294967295] gives [300](0)
[Feb 11 16:02:22] DEBUG[1515547]: config.c:3877 ast_parse_arg: extract uint from [300] in [0, 4294967295] gives [300](0)
[Feb 11 16:02:22] DEBUG[1515547]: config.c:3964 ast_parse_arg: extract double from [3.0] in [-inf, inf] gives [3.000000](0)
[Feb 11 16:02:22] DEBUG[1515547]: config.c:3877 ast_parse_arg: extract uint from [0] in [0, 4294967295] gives [0](0)
[Feb 11 16:02:22] DEBUG[1515547]: res_pjsip/pjsip_transport_events.c:468 ast_sip_transport_monitor_register_replace: Registered monitor 0x7f5f74107f30(0x7f5f400ab8c0) to transport tlss0x7f5ef01a4278
[Feb 11 16:02:22]     -- Added contact 'sips:xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx_7092@180.60.8.7:37866;transport=TLS;ob;x-ast-orig-host=192.168.0.145:60208' to AOR 'xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx_7092' with expiration of 300 seconds
[Feb 11 16:02:22] DEBUG[1515547]: res_pjsip_nat.c:345 restore_orig_contact_host: Restoring contact 180.60.8.7:37866  to 192.168.0.145:60208
[Feb 11 16:02:22] <--- Transmitting SIP response (615 bytes) to TLS:180.60.8.7:37866 --->
[Feb 11 16:02:22] SIP/2.0 200 OK
[Feb 11 16:02:22] Via: SIP/2.0/TLS 192.168.0.145:60208;branch=z9hG4bKPj6PVhaaX7sYQQj0WDR1ww-QxOCT2XjWt3;alias
[Feb 11 16:02:22] Call-ID: 6QBcuz8MQPDFJn3kDCgNthWAdySk0aiU
[Feb 11 16:02:22] From: <sips:xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx_7092@example.com>;tag=19fwnzhcxdcZH..76SG98F-rPf5DsXhk
[Feb 11 16:02:22] To: <sips:xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx_7092@example.com>;tag=z9hG4bKPj6PVhaaX7sYQQj0WDR1ww-QxOCT2XjWt3
[Feb 11 16:02:22] CSeq: 35873 REGISTER
[Feb 11 16:02:22] Date: Sat, 11 Feb 2023 07:02:22 GMT
[Feb 11 16:02:22] Contact: <sips:xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx_7092@192.168.0.145:60208;transport=TLS;ob>;expires=299
[Feb 11 16:02:22] Expires: 300
[Feb 11 16:02:22] Server: Biz Cloud PBX/18.15
[Feb 11 16:02:22] Content-Length:  0

jcolp · February 11, 2023, 10:52am

Qualify support was rewritten in PJSIP, because of poor performance. Trying to have it be dynamic had disastrous performance consequences, to the degree that Asterisk would hang at startup for awhile loading things under .conf file usage - which is the vast majority of usage. Therefore you have to inform Asterisk you’ve added things to the database to have them monitored using the “pjsip reload qualify aor” or “pjsip reload qualify endpoint” CLI commands.

Sonono · February 12, 2023, 8:37am

Thank you for your detailed explanation!
I understand the process and the consequences and “pjsip reload qualify aor xxx” works!!!
Thanks a lot.
Have a nice day!

system · March 14, 2023, 8:38am

This topic was automatically closed 30 days after the last reply. New replies are no longer allowed.