devast*CLI> core set debug 5 Core debug was OFF and is now 5. [Nov 11 16:34:50] DEBUG[18040]: threadpool.c:1137 worker_idle: Worker thread idle timeout reached. Dying. [Nov 11 16:34:50] DEBUG[18028]: threadpool.c:996 worker_thread_destroy: Destroying worker thread 2 [Nov 11 16:34:53] DEBUG[18038]: threadpool.c:1137 worker_idle: Worker thread idle timeout reached. Dying. [Nov 11 16:34:53] DEBUG[18039]: threadpool.c:1137 worker_idle: Worker thread idle timeout reached. Dying. [Nov 11 16:34:53] DEBUG[18028]: threadpool.c:996 worker_thread_destroy: Destroying worker thread 0 [Nov 11 16:34:53] DEBUG[18028]: threadpool.c:996 worker_thread_destroy: Destroying worker thread 1 devast*CLI> pjsip set logger on PJSIP Logging enabled [Nov 11 16:35:00] DEBUG[18092]: res_pjsip_registrar_expire.c:78 check_expiration_thread: Woke up at 1478882100 Interval: 30 [Nov 11 16:35:00] DEBUG[18092]: res_pjsip_registrar_expire.c:85 check_expiration_thread: Expiring 0 contacts [Nov 11 16:35:19] DEBUG[18090]: res_timing_timerfd.c:167 timerfd_timer_ack: Expected to acknowledge 1 ticks but got 3 instead [Nov 11 16:35:23] DEBUG[18090]: res_timing_timerfd.c:167 timerfd_timer_ack: Expected to acknowledge 1 ticks but got 3 instead [Nov 11 16:35:30] DEBUG[18057]: threadpool.c:1137 worker_idle: Worker thread idle timeout reached. Dying. [Nov 11 16:35:30] DEBUG[18058]: threadpool.c:1137 worker_idle: Worker thread idle timeout reached. Dying. [Nov 11 16:35:30] DEBUG[18051]: threadpool.c:996 worker_thread_destroy: Destroying worker thread 8 [Nov 11 16:35:30] DEBUG[18051]: threadpool.c:996 worker_thread_destroy: Destroying worker thread 9 [Nov 11 16:35:30] DEBUG[18060]: threadpool.c:1137 worker_idle: Worker thread idle timeout reached. Dying. [Nov 11 16:35:30] DEBUG[18061]: threadpool.c:1137 worker_idle: Worker thread idle timeout reached. Dying. [Nov 11 16:35:30] DEBUG[18062]: threadpool.c:1137 worker_idle: Worker thread idle timeout reached. Dying. [Nov 11 16:35:30] DEBUG[18027]: threadpool.c:996 worker_thread_destroy: Destroying worker thread 11 [Nov 11 16:35:30] DEBUG[18027]: threadpool.c:996 worker_thread_destroy: Destroying worker thread 12 [Nov 11 16:35:30] DEBUG[18027]: threadpool.c:996 worker_thread_destroy: Destroying worker thread 13 [Nov 11 16:35:30] DEBUG[18092]: res_pjsip_registrar_expire.c:78 check_expiration_thread: Woke up at 1478882130 Interval: 30 [Nov 11 16:35:30] DEBUG[18092]: res_pjsip_registrar_expire.c:85 check_expiration_thread: Expiring 0 contacts [Nov 11 16:35:30] DEBUG[18059]: threadpool.c:1137 worker_idle: Worker thread idle timeout reached. Dying. [Nov 11 16:35:30] DEBUG[18027]: threadpool.c:996 worker_thread_destroy: Destroying worker thread 10 [Nov 11 16:35:33] DEBUG[18055]: threadpool.c:1137 worker_idle: Worker thread idle timeout reached. Dying. [Nov 11 16:35:33] DEBUG[18056]: threadpool.c:1137 worker_idle: Worker thread idle timeout reached. Dying. [Nov 11 16:35:33] DEBUG[18051]: threadpool.c:996 worker_thread_destroy: Destroying worker thread 6 [Nov 11 16:35:33] DEBUG[18051]: threadpool.c:996 worker_thread_destroy: Destroying worker thread 7 [Nov 11 16:35:33] DEBUG[18054]: threadpool.c:1137 worker_idle: Worker thread idle timeout reached. Dying. [Nov 11 16:35:33] DEBUG[18051]: threadpool.c:996 worker_thread_destroy: Destroying worker thread 5 <--- Received SIP request (525 bytes) from UDP:12.49.160.131:58781 ---> REGISTER sip:104.197.69.7 SIP/2.0 Via: SIP/2.0/UDP 10.200.101.116:58781;branch=z9hG4bK-524287-1---510c701eed52f364;rport Max-Forwards: 70 Contact: To: From: ;tag=bc201339 Call-ID: 82162MjA5NTE0YjkyZTE4MjA3ZGUzNzZhYjQxNDc2MTllMzI CSeq: 1 REGISTER Expires: 3600 Allow: SUBSCRIBE, NOTIFY, INVITE, ACK, CANCEL, BYE, REFER, INFO, OPTIONS, MESSAGE User-Agent: Bria 4 release 4.6.0 stamp 82162 Content-Length: 0 [Nov 11 16:35:47] DEBUG[18053]: netsock2.c:172 ast_sockaddr_split_hostport: Splitting '12.49.160.131:58781' into... [Nov 11 16:35:47] DEBUG[18053]: netsock2.c:226 ast_sockaddr_split_hostport: ...host '12.49.160.131' and port '58781'. [Nov 11 16:35:47] DEBUG[18053]: netsock2.c:172 ast_sockaddr_split_hostport: Splitting '10.128.0.3:5060' into... [Nov 11 16:35:47] DEBUG[18053]: netsock2.c:226 ast_sockaddr_split_hostport: ...host '10.128.0.3' and port '5060'. [Nov 11 16:35:47] DEBUG[18053]: res_pjsip/pjsip_distributor.c:267 find_dialog: Could not find matching transaction for Request msg REGISTER/cseq=1 (rdata0x1d09188) [Nov 11 16:35:47] DEBUG[18053]: res_pjsip/pjsip_distributor.c:359 ast_sip_get_distributor_serializer: Calculated serializer pjsip/distributor-0000002a to use for Request msg REGISTER/cseq=1 (rdata0x1d09188) [Nov 11 16:35:47] DEBUG[18051]: threadpool.c:517 grow: Increasing threadpool SIP's size by 5 [Nov 11 16:35:47] DEBUG[18116]: res_odbc.c:869 _ast_odbc_request_obj2: Reusing ODBC handle 0x253ae80 from class 'asterisk' [Nov 11 16:35:47] DEBUG[18116]: res_config_odbc.c:116 custom_prepare: Skip: 0; SQL: SELECT * FROM ps_endpoint_id_ips WHERE id LIKE ? ORDER BY id [Nov 11 16:35:47] DEBUG[18116]: res_config_odbc.c:132 custom_prepare: Parameter 1 ('id LIKE') = '%' [Nov 11 16:35:47] DEBUG[18116]: res_odbc.c:718 ast_odbc_release_obj: Releasing ODBC handle 0x253ae80 into pool [Nov 11 16:35:47] DEBUG[18116]: res_pjsip_endpoint_identifier_ip.c:128 ip_identify: No identify sections to match against [Nov 11 16:35:47] DEBUG[18116]: res_pjsip_endpoint_identifier_user.c:133 username_identify: Attempting identify by From username '1506' domain '104.197.69.7' [Nov 11 16:35:47] DEBUG[18116]: res_odbc.c:869 _ast_odbc_request_obj2: Reusing ODBC handle 0x253ae80 from class 'asterisk' [Nov 11 16:35:47] DEBUG[18116]: res_config_odbc.c:116 custom_prepare: Skip: 0; SQL: SELECT * FROM ps_endpoints WHERE id = ? [Nov 11 16:35:47] DEBUG[18116]: res_config_odbc.c:132 custom_prepare: Parameter 1 ('id') = '1506@104.197.69.7' [Nov 11 16:35:47] DEBUG[18116]: res_odbc.c:718 ast_odbc_release_obj: Releasing ODBC handle 0x253ae80 into pool [Nov 11 16:35:47] DEBUG[18116]: res_odbc.c:869 _ast_odbc_request_obj2: Reusing ODBC handle 0x253ae80 from class 'asterisk' [Nov 11 16:35:47] DEBUG[18116]: res_config_odbc.c:116 custom_prepare: Skip: 0; SQL: SELECT * FROM ps_domain_aliases WHERE id = ? [Nov 11 16:35:47] DEBUG[18116]: res_config_odbc.c:132 custom_prepare: Parameter 1 ('id') = '104.197.69.7' [Nov 11 16:35:47] DEBUG[18116]: res_odbc.c:718 ast_odbc_release_obj: Releasing ODBC handle 0x253ae80 into pool [Nov 11 16:35:47] DEBUG[18116]: res_odbc.c:869 _ast_odbc_request_obj2: Reusing ODBC handle 0x253ae80 from class 'asterisk' [Nov 11 16:35:47] DEBUG[18116]: res_config_odbc.c:116 custom_prepare: Skip: 0; SQL: SELECT * FROM ps_transports WHERE id = ? [Nov 11 16:35:47] DEBUG[18116]: res_config_odbc.c:132 custom_prepare: Parameter 1 ('id') = 'nat_udp' [Nov 11 16:35:47] DEBUG[18116]: res_odbc.c:718 ast_odbc_release_obj: Releasing ODBC handle 0x253ae80 into pool [Nov 11 16:35:47] DEBUG[18116]: config.c:3742 ast_parse_arg: extract uint from [0] in [0, 65535] gives [0](0) [Nov 11 16:35:47] DEBUG[18116]: config.c:3689 ast_parse_arg: extract int from [100] in [1, 2147483647] gives [100](0) [Nov 11 16:35:47] DEBUG[18116]: config.c:3742 ast_parse_arg: extract uint from [1] in [0, 4294967295] gives [1](0) [Nov 11 16:35:47] DEBUG[18116]: config.c:3742 ast_parse_arg: extract uint from [0] in [0, 4294967295] gives [0](0) [Nov 11 16:35:47] DEBUG[18116]: netsock2.c:172 ast_sockaddr_split_hostport: Splitting '10.128.0.0' into... [Nov 11 16:35:47] DEBUG[18116]: netsock2.c:226 ast_sockaddr_split_hostport: ...host '10.128.0.0' and port ''. [Nov 11 16:35:47] DEBUG[18116]: acl.c:661 ast_append_ha: 10.128.0.0:0/255.255.240.0:0 sense 0 appended to ACL [Nov 11 16:35:47] DEBUG[18116]: netsock2.c:172 ast_sockaddr_split_hostport: Splitting '104.197.69.7' into... [Nov 11 16:35:47] DEBUG[18116]: netsock2.c:226 ast_sockaddr_split_hostport: ...host '104.197.69.7' and port ''. [Nov 11 16:35:47] DEBUG[18116]: res_odbc.c:869 _ast_odbc_request_obj2: Reusing ODBC handle 0x253ae80 from class 'asterisk' [Nov 11 16:35:47] DEBUG[18116]: res_config_odbc.c:116 custom_prepare: Skip: 0; SQL: SELECT * FROM ps_endpoints WHERE id = ? [Nov 11 16:35:47] DEBUG[18116]: res_config_odbc.c:132 custom_prepare: Parameter 1 ('id') = '1506' [Nov 11 16:35:47] DEBUG[18116]: res_odbc.c:718 ast_odbc_release_obj: Releasing ODBC handle 0x253ae80 into pool [Nov 11 16:35:47] DEBUG[18116]: res_sorcery_realtime.c:131 sorcery_realtime_filter_objectset: Filtering out realtime field 'disallow' from retrieval [Nov 11 16:35:47] DEBUG[18116]: config.c:3742 ast_parse_arg: extract uint from [0] in [0, 4294967295] gives [0](0) [Nov 11 16:35:47] DEBUG[18116]: config.c:3742 ast_parse_arg: extract uint from [0] in [0, 4294967295] gives [0](0) [Nov 11 16:35:47] DEBUG[18116]: config.c:3742 ast_parse_arg: extract uint from [0] in [0, 4294967295] gives [0](0) [Nov 11 16:35:47] DEBUG[18116]: config.c:3742 ast_parse_arg: extract uint from [0] in [0, 4294967295] gives [0](0) [Nov 11 16:35:47] DEBUG[18116]: config.c:3742 ast_parse_arg: extract uint from [0] in [0, 4294967295] gives [0](0) [Nov 11 16:35:47] DEBUG[18116]: config.c:3742 ast_parse_arg: extract uint from [1800] in [0, 4294967295] gives [1800](0) [Nov 11 16:35:47] DEBUG[18116]: config.c:3742 ast_parse_arg: extract uint from [0] in [0, 4294967295] gives [0](0) [Nov 11 16:35:47] DEBUG[18116]: config.c:3742 ast_parse_arg: extract uint from [0] in [0, 4294967295] gives [0](0) [Nov 11 16:35:47] DEBUG[18116]: config.c:3742 ast_parse_arg: extract uint from [90] in [0, 4294967295] gives [90](0) [Nov 11 16:35:47] DEBUG[18116]: config.c:3742 ast_parse_arg: extract uint from [0] in [0, 4294967295] gives [0](0) [Nov 11 16:35:47] DEBUG[18116]: config.c:3742 ast_parse_arg: extract uint from [0] in [0, 4294967295] gives [0](0) [Nov 11 16:35:47] DEBUG[18116]: res_pjsip_endpoint_identifier_user.c:145 username_identify: Identified by From username '1506' domain '104.197.69.7' [Nov 11 16:35:47] DEBUG[18116]: res_odbc.c:869 _ast_odbc_request_obj2: Reusing ODBC handle 0x253ae80 from class 'asterisk' [Nov 11 16:35:47] DEBUG[18116]: res_config_odbc.c:116 custom_prepare: Skip: 0; SQL: SELECT * FROM ps_auths WHERE id = ? [Nov 11 16:35:47] DEBUG[18116]: res_config_odbc.c:132 custom_prepare: Parameter 1 ('id') = 'phone' [Nov 11 16:35:47] DEBUG[18116]: res_odbc.c:718 ast_odbc_release_obj: Releasing ODBC handle 0x253ae80 into pool [Nov 11 16:35:47] DEBUG[18116]: config.c:3742 ast_parse_arg: extract uint from [32] in [0, 4294967295] gives [32](0) [Nov 11 16:35:47] DEBUG[18116]: netsock2.c:172 ast_sockaddr_split_hostport: Splitting '10.128.0.3' into... [Nov 11 16:35:47] DEBUG[18116]: netsock2.c:226 ast_sockaddr_split_hostport: ...host '10.128.0.3' and port ''. [Nov 11 16:35:47] DEBUG[18116]: netsock2.c:172 ast_sockaddr_split_hostport: Splitting '12.49.160.131' into... [Nov 11 16:35:47] DEBUG[18116]: netsock2.c:226 ast_sockaddr_split_hostport: ...host '12.49.160.131' and port ''. [Nov 11 16:35:47] DEBUG[18116]: netsock2.c:172 ast_sockaddr_split_hostport: Splitting '10.128.0.3:5060' into... [Nov 11 16:35:47] DEBUG[18116]: netsock2.c:226 ast_sockaddr_split_hostport: ...host '10.128.0.3' and port '5060'. [Nov 11 16:35:47] DEBUG[18116]: netsock2.c:172 ast_sockaddr_split_hostport: Splitting '12.49.160.131:58781' into... [Nov 11 16:35:47] DEBUG[18116]: netsock2.c:226 ast_sockaddr_split_hostport: ...host '12.49.160.131' and port '58781'. <--- Transmitting SIP response (531 bytes) to UDP:12.49.160.131:58781 ---> SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 10.200.101.116:58781;rport=58781;received=12.49.160.131;branch=z9hG4bK-524287-1---510c701eed52f364 Call-ID: 82162MjA5NTE0YjkyZTE4MjA3ZGUzNzZhYjQxNDc2MTllMzI From: ;tag=bc201339 To: ;tag=z9hG4bK-524287-1---510c701eed52f364 CSeq: 1 REGISTER WWW-Authenticate: Digest realm="asterisk",nonce="1478882147/8b845d8c881a2d5056e3cfeab5623a50",opaque="38df36b365ce5435",algorithm=md5,qop="auth" Server: Asterisk PBX 14.1.1 Content-Length: 0 <--- Received SIP request (525 bytes) from UDP:12.49.160.131:58781 ---> REGISTER sip:104.197.69.7 SIP/2.0 Via: SIP/2.0/UDP 10.200.101.116:58781;branch=z9hG4bK-524287-1---510c701eed52f364;rport Max-Forwards: 70 Contact: To: From: ;tag=bc201339 Call-ID: 82162MjA5NTE0YjkyZTE4MjA3ZGUzNzZhYjQxNDc2MTllMzI CSeq: 1 REGISTER Expires: 3600 Allow: SUBSCRIBE, NOTIFY, INVITE, ACK, CANCEL, BYE, REFER, INFO, OPTIONS, MESSAGE User-Agent: Bria 4 release 4.6.0 stamp 82162 Content-Length: 0 [Nov 11 16:35:47] DEBUG[18053]: netsock2.c:172 ast_sockaddr_split_hostport: Splitting '12.49.160.131:58781' into... [Nov 11 16:35:47] DEBUG[18053]: netsock2.c:226 ast_sockaddr_split_hostport: ...host '12.49.160.131' and port '58781'. [Nov 11 16:35:47] DEBUG[18053]: netsock2.c:172 ast_sockaddr_split_hostport: Splitting '10.128.0.3:5060' into... [Nov 11 16:35:47] DEBUG[18053]: netsock2.c:226 ast_sockaddr_split_hostport: ...host '10.128.0.3' and port '5060'. [Nov 11 16:35:47] DEBUG[18053]: res_pjsip/pjsip_distributor.c:267 find_dialog: Could not find matching transaction for Request msg REGISTER/cseq=1 (rdata0x7f34940095b8) [Nov 11 16:35:47] DEBUG[18053]: res_pjsip/pjsip_distributor.c:359 ast_sip_get_distributor_serializer: Calculated serializer pjsip/distributor-0000002a to use for Request msg REGISTER/cseq=1 (rdata0x7f34940095b8) [Nov 11 16:35:47] DEBUG[18116]: res_odbc.c:869 _ast_odbc_request_obj2: Reusing ODBC handle 0x253ae80 from class 'asterisk' [Nov 11 16:35:47] DEBUG[18116]: res_config_odbc.c:116 custom_prepare: Skip: 0; SQL: SELECT * FROM ps_endpoint_id_ips WHERE id LIKE ? ORDER BY id [Nov 11 16:35:47] DEBUG[18116]: res_config_odbc.c:132 custom_prepare: Parameter 1 ('id LIKE') = '%' [Nov 11 16:35:47] DEBUG[18116]: res_odbc.c:718 ast_odbc_release_obj: Releasing ODBC handle 0x253ae80 into pool [Nov 11 16:35:47] DEBUG[18116]: res_pjsip_endpoint_identifier_ip.c:128 ip_identify: No identify sections to match against [Nov 11 16:35:47] DEBUG[18116]: res_pjsip_endpoint_identifier_user.c:133 username_identify: Attempting identify by From username '1506' domain '104.197.69.7' [Nov 11 16:35:47] DEBUG[18116]: res_odbc.c:869 _ast_odbc_request_obj2: Reusing ODBC handle 0x253ae80 from class 'asterisk' [Nov 11 16:35:47] DEBUG[18116]: res_config_odbc.c:116 custom_prepare: Skip: 0; SQL: SELECT * FROM ps_endpoints WHERE id = ? [Nov 11 16:35:47] DEBUG[18116]: res_config_odbc.c:132 custom_prepare: Parameter 1 ('id') = '1506@104.197.69.7' [Nov 11 16:35:47] DEBUG[18116]: res_odbc.c:718 ast_odbc_release_obj: Releasing ODBC handle 0x253ae80 into pool [Nov 11 16:35:47] DEBUG[18116]: res_odbc.c:869 _ast_odbc_request_obj2: Reusing ODBC handle 0x253ae80 from class 'asterisk' [Nov 11 16:35:47] DEBUG[18116]: res_config_odbc.c:116 custom_prepare: Skip: 0; SQL: SELECT * FROM ps_domain_aliases WHERE id = ? [Nov 11 16:35:47] DEBUG[18116]: res_config_odbc.c:132 custom_prepare: Parameter 1 ('id') = '104.197.69.7' [Nov 11 16:35:47] DEBUG[18116]: res_odbc.c:718 ast_odbc_release_obj: Releasing ODBC handle 0x253ae80 into pool [Nov 11 16:35:47] DEBUG[18116]: res_odbc.c:869 _ast_odbc_request_obj2: Reusing ODBC handle 0x253ae80 from class 'asterisk' [Nov 11 16:35:47] DEBUG[18116]: res_config_odbc.c:116 custom_prepare: Skip: 0; SQL: SELECT * FROM ps_transports WHERE id = ? [Nov 11 16:35:47] DEBUG[18116]: res_config_odbc.c:132 custom_prepare: Parameter 1 ('id') = 'nat_udp' [Nov 11 16:35:47] DEBUG[18116]: res_odbc.c:718 ast_odbc_release_obj: Releasing ODBC handle 0x253ae80 into pool [Nov 11 16:35:47] DEBUG[18116]: config.c:3742 ast_parse_arg: extract uint from [0] in [0, 65535] gives [0](0) [Nov 11 16:35:47] DEBUG[18116]: config.c:3689 ast_parse_arg: extract int from [100] in [1, 2147483647] gives [100](0) [Nov 11 16:35:47] DEBUG[18116]: config.c:3742 ast_parse_arg: extract uint from [1] in [0, 4294967295] gives [1](0) [Nov 11 16:35:47] DEBUG[18116]: config.c:3742 ast_parse_arg: extract uint from [0] in [0, 4294967295] gives [0](0) [Nov 11 16:35:47] DEBUG[18116]: netsock2.c:172 ast_sockaddr_split_hostport: Splitting '10.128.0.0' into... [Nov 11 16:35:47] DEBUG[18116]: netsock2.c:226 ast_sockaddr_split_hostport: ...host '10.128.0.0' and port ''. [Nov 11 16:35:47] DEBUG[18116]: acl.c:661 ast_append_ha: 10.128.0.0:0/255.255.240.0:0 sense 0 appended to ACL [Nov 11 16:35:47] DEBUG[18116]: netsock2.c:172 ast_sockaddr_split_hostport: Splitting '104.197.69.7' into... [Nov 11 16:35:47] DEBUG[18116]: netsock2.c:226 ast_sockaddr_split_hostport: ...host '104.197.69.7' and port ''. [Nov 11 16:35:47] DEBUG[18116]: res_odbc.c:869 _ast_odbc_request_obj2: Reusing ODBC handle 0x253ae80 from class 'asterisk' [Nov 11 16:35:47] DEBUG[18116]: res_config_odbc.c:116 custom_prepare: Skip: 0; SQL: SELECT * FROM ps_endpoints WHERE id = ? [Nov 11 16:35:47] DEBUG[18116]: res_config_odbc.c:132 custom_prepare: Parameter 1 ('id') = '1506' [Nov 11 16:35:47] DEBUG[18116]: res_odbc.c:718 ast_odbc_release_obj: Releasing ODBC handle 0x253ae80 into pool [Nov 11 16:35:47] DEBUG[18116]: res_sorcery_realtime.c:131 sorcery_realtime_filter_objectset: Filtering out realtime field 'disallow' from retrieval [Nov 11 16:35:47] DEBUG[18116]: config.c:3742 ast_parse_arg: extract uint from [0] in [0, 4294967295] gives [0](0) [Nov 11 16:35:47] DEBUG[18116]: config.c:3742 ast_parse_arg: extract uint from [0] in [0, 4294967295] gives [0](0) [Nov 11 16:35:47] DEBUG[18116]: config.c:3742 ast_parse_arg: extract uint from [0] in [0, 4294967295] gives [0](0) [Nov 11 16:35:47] DEBUG[18116]: config.c:3742 ast_parse_arg: extract uint from [0] in [0, 4294967295] gives [0](0) [Nov 11 16:35:47] DEBUG[18116]: config.c:3742 ast_parse_arg: extract uint from [0] in [0, 4294967295] gives [0](0) [Nov 11 16:35:47] DEBUG[18116]: config.c:3742 ast_parse_arg: extract uint from [1800] in [0, 4294967295] gives [1800](0) [Nov 11 16:35:47] DEBUG[18116]: config.c:3742 ast_parse_arg: extract uint from [0] in [0, 4294967295] gives [0](0) [Nov 11 16:35:47] DEBUG[18116]: config.c:3742 ast_parse_arg: extract uint from [0] in [0, 4294967295] gives [0](0) [Nov 11 16:35:47] DEBUG[18116]: config.c:3742 ast_parse_arg: extract uint from [90] in [0, 4294967295] gives [90](0) [Nov 11 16:35:47] DEBUG[18116]: config.c:3742 ast_parse_arg: extract uint from [0] in [0, 4294967295] gives [0](0) [Nov 11 16:35:47] DEBUG[18116]: config.c:3742 ast_parse_arg: extract uint from [0] in [0, 4294967295] gives [0](0) [Nov 11 16:35:47] DEBUG[18116]: res_pjsip_endpoint_identifier_user.c:145 username_identify: Identified by From username '1506' domain '104.197.69.7' [Nov 11 16:35:47] DEBUG[18116]: res_odbc.c:869 _ast_odbc_request_obj2: Reusing ODBC handle 0x253ae80 from class 'asterisk' [Nov 11 16:35:47] DEBUG[18116]: res_config_odbc.c:116 custom_prepare: Skip: 0; SQL: SELECT * FROM ps_auths WHERE id = ? [Nov 11 16:35:47] DEBUG[18116]: res_config_odbc.c:132 custom_prepare: Parameter 1 ('id') = 'phone' [Nov 11 16:35:47] DEBUG[18116]: res_odbc.c:718 ast_odbc_release_obj: Releasing ODBC handle 0x253ae80 into pool [Nov 11 16:35:47] DEBUG[18116]: config.c:3742 ast_parse_arg: extract uint from [32] in [0, 4294967295] gives [32](0) [Nov 11 16:35:47] DEBUG[18116]: netsock2.c:172 ast_sockaddr_split_hostport: Splitting '10.128.0.3' into... [Nov 11 16:35:47] DEBUG[18116]: netsock2.c:226 ast_sockaddr_split_hostport: ...host '10.128.0.3' and port ''. [Nov 11 16:35:47] DEBUG[18116]: netsock2.c:172 ast_sockaddr_split_hostport: Splitting '12.49.160.131' into... [Nov 11 16:35:47] DEBUG[18116]: netsock2.c:226 ast_sockaddr_split_hostport: ...host '12.49.160.131' and port ''. [Nov 11 16:35:47] DEBUG[18116]: netsock2.c:172 ast_sockaddr_split_hostport: Splitting '10.128.0.3:5060' into... [Nov 11 16:35:47] DEBUG[18116]: netsock2.c:226 ast_sockaddr_split_hostport: ...host '10.128.0.3' and port '5060'. [Nov 11 16:35:47] DEBUG[18116]: netsock2.c:172 ast_sockaddr_split_hostport: Splitting '12.49.160.131:58781' into... [Nov 11 16:35:47] DEBUG[18116]: netsock2.c:226 ast_sockaddr_split_hostport: ...host '12.49.160.131' and port '58781'. <--- Transmitting SIP response (531 bytes) to UDP:12.49.160.131:58781 ---> SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 10.200.101.116:58781;rport=58781;received=12.49.160.131;branch=z9hG4bK-524287-1---510c701eed52f364 Call-ID: 82162MjA5NTE0YjkyZTE4MjA3ZGUzNzZhYjQxNDc2MTllMzI From: ;tag=bc201339 To: ;tag=z9hG4bK-524287-1---510c701eed52f364 CSeq: 1 REGISTER WWW-Authenticate: Digest realm="asterisk",nonce="1478882147/8b845d8c881a2d5056e3cfeab5623a50",opaque="611806151c5b8d57",algorithm=md5,qop="auth" Server: Asterisk PBX 14.1.1 Content-Length: 0 <--- Received SIP request (525 bytes) from UDP:12.49.160.131:58781 ---> REGISTER sip:104.197.69.7 SIP/2.0 Via: SIP/2.0/UDP 10.200.101.116:58781;branch=z9hG4bK-524287-1---510c701eed52f364;rport Max-Forwards: 70 Contact: To: From: ;tag=bc201339 Call-ID: 82162MjA5NTE0YjkyZTE4MjA3ZGUzNzZhYjQxNDc2MTllMzI CSeq: 1 REGISTER Expires: 3600 Allow: SUBSCRIBE, NOTIFY, INVITE, ACK, CANCEL, BYE, REFER, INFO, OPTIONS, MESSAGE User-Agent: Bria 4 release 4.6.0 stamp 82162 Content-Length: 0 [Nov 11 16:35:48] DEBUG[18053]: netsock2.c:172 ast_sockaddr_split_hostport: Splitting '12.49.160.131:58781' into... [Nov 11 16:35:48] DEBUG[18053]: netsock2.c:226 ast_sockaddr_split_hostport: ...host '12.49.160.131' and port '58781'. [Nov 11 16:35:48] DEBUG[18053]: netsock2.c:172 ast_sockaddr_split_hostport: Splitting '10.128.0.3:5060' into... [Nov 11 16:35:48] DEBUG[18053]: netsock2.c:226 ast_sockaddr_split_hostport: ...host '10.128.0.3' and port '5060'. [Nov 11 16:35:48] DEBUG[18053]: res_pjsip/pjsip_distributor.c:267 find_dialog: Could not find matching transaction for Request msg REGISTER/cseq=1 (rdata0x7f34940095b8) [Nov 11 16:35:48] DEBUG[18053]: res_pjsip/pjsip_distributor.c:359 ast_sip_get_distributor_serializer: Calculated serializer pjsip/distributor-0000002a to use for Request msg REGISTER/cseq=1 (rdata0x7f34940095b8) [Nov 11 16:35:48] DEBUG[18116]: res_odbc.c:869 _ast_odbc_request_obj2: Reusing ODBC handle 0x253ae80 from class 'asterisk' [Nov 11 16:35:48] DEBUG[18116]: res_config_odbc.c:116 custom_prepare: Skip: 0; SQL: SELECT * FROM ps_endpoint_id_ips WHERE id LIKE ? ORDER BY id [Nov 11 16:35:48] DEBUG[18116]: res_config_odbc.c:132 custom_prepare: Parameter 1 ('id LIKE') = '%' [Nov 11 16:35:48] DEBUG[18116]: res_odbc.c:718 ast_odbc_release_obj: Releasing ODBC handle 0x253ae80 into pool [Nov 11 16:35:48] DEBUG[18116]: res_pjsip_endpoint_identifier_ip.c:128 ip_identify: No identify sections to match against [Nov 11 16:35:48] DEBUG[18116]: res_pjsip_endpoint_identifier_user.c:133 username_identify: Attempting identify by From username '1506' domain '104.197.69.7' [Nov 11 16:35:48] DEBUG[18116]: res_odbc.c:869 _ast_odbc_request_obj2: Reusing ODBC handle 0x253ae80 from class 'asterisk' [Nov 11 16:35:48] DEBUG[18116]: res_config_odbc.c:116 custom_prepare: Skip: 0; SQL: SELECT * FROM ps_endpoints WHERE id = ? [Nov 11 16:35:48] DEBUG[18116]: res_config_odbc.c:132 custom_prepare: Parameter 1 ('id') = '1506@104.197.69.7' [Nov 11 16:35:48] DEBUG[18116]: res_odbc.c:718 ast_odbc_release_obj: Releasing ODBC handle 0x253ae80 into pool [Nov 11 16:35:48] DEBUG[18116]: res_odbc.c:869 _ast_odbc_request_obj2: Reusing ODBC handle 0x253ae80 from class 'asterisk' [Nov 11 16:35:48] DEBUG[18116]: res_config_odbc.c:116 custom_prepare: Skip: 0; SQL: SELECT * FROM ps_domain_aliases WHERE id = ? [Nov 11 16:35:48] DEBUG[18116]: res_config_odbc.c:132 custom_prepare: Parameter 1 ('id') = '104.197.69.7' [Nov 11 16:35:48] DEBUG[18116]: res_odbc.c:718 ast_odbc_release_obj: Releasing ODBC handle 0x253ae80 into pool [Nov 11 16:35:48] DEBUG[18116]: res_odbc.c:869 _ast_odbc_request_obj2: Reusing ODBC handle 0x253ae80 from class 'asterisk' [Nov 11 16:35:48] DEBUG[18116]: res_config_odbc.c:116 custom_prepare: Skip: 0; SQL: SELECT * FROM ps_transports WHERE id = ? [Nov 11 16:35:48] DEBUG[18116]: res_config_odbc.c:132 custom_prepare: Parameter 1 ('id') = 'nat_udp' [Nov 11 16:35:48] DEBUG[18116]: res_odbc.c:718 ast_odbc_release_obj: Releasing ODBC handle 0x253ae80 into pool [Nov 11 16:35:48] DEBUG[18116]: config.c:3742 ast_parse_arg: extract uint from [0] in [0, 65535] gives [0](0) [Nov 11 16:35:48] DEBUG[18116]: config.c:3689 ast_parse_arg: extract int from [100] in [1, 2147483647] gives [100](0) [Nov 11 16:35:48] DEBUG[18116]: config.c:3742 ast_parse_arg: extract uint from [1] in [0, 4294967295] gives [1](0) [Nov 11 16:35:48] DEBUG[18116]: config.c:3742 ast_parse_arg: extract uint from [0] in [0, 4294967295] gives [0](0) [Nov 11 16:35:48] DEBUG[18116]: netsock2.c:172 ast_sockaddr_split_hostport: Splitting '10.128.0.0' into... [Nov 11 16:35:48] DEBUG[18116]: netsock2.c:226 ast_sockaddr_split_hostport: ...host '10.128.0.0' and port ''. [Nov 11 16:35:48] DEBUG[18116]: acl.c:661 ast_append_ha: 10.128.0.0:0/255.255.240.0:0 sense 0 appended to ACL [Nov 11 16:35:48] DEBUG[18116]: netsock2.c:172 ast_sockaddr_split_hostport: Splitting '104.197.69.7' into... [Nov 11 16:35:48] DEBUG[18116]: netsock2.c:226 ast_sockaddr_split_hostport: ...host '104.197.69.7' and port ''. [Nov 11 16:35:48] DEBUG[18116]: res_odbc.c:869 _ast_odbc_request_obj2: Reusing ODBC handle 0x253ae80 from class 'asterisk' [Nov 11 16:35:48] DEBUG[18116]: res_config_odbc.c:116 custom_prepare: Skip: 0; SQL: SELECT * FROM ps_endpoints WHERE id = ? [Nov 11 16:35:48] DEBUG[18116]: res_config_odbc.c:132 custom_prepare: Parameter 1 ('id') = '1506' [Nov 11 16:35:48] DEBUG[18116]: res_odbc.c:718 ast_odbc_release_obj: Releasing ODBC handle 0x253ae80 into pool [Nov 11 16:35:48] DEBUG[18116]: res_sorcery_realtime.c:131 sorcery_realtime_filter_objectset: Filtering out realtime field 'disallow' from retrieval [Nov 11 16:35:48] DEBUG[18116]: config.c:3742 ast_parse_arg: extract uint from [0] in [0, 4294967295] gives [0](0) [Nov 11 16:35:48] DEBUG[18116]: config.c:3742 ast_parse_arg: extract uint from [0] in [0, 4294967295] gives [0](0) [Nov 11 16:35:48] DEBUG[18116]: config.c:3742 ast_parse_arg: extract uint from [0] in [0, 4294967295] gives [0](0) [Nov 11 16:35:48] DEBUG[18116]: config.c:3742 ast_parse_arg: extract uint from [0] in [0, 4294967295] gives [0](0) [Nov 11 16:35:48] DEBUG[18116]: config.c:3742 ast_parse_arg: extract uint from [0] in [0, 4294967295] gives [0](0) [Nov 11 16:35:48] DEBUG[18116]: config.c:3742 ast_parse_arg: extract uint from [1800] in [0, 4294967295] gives [1800](0) [Nov 11 16:35:48] DEBUG[18116]: config.c:3742 ast_parse_arg: extract uint from [0] in [0, 4294967295] gives [0](0) [Nov 11 16:35:48] DEBUG[18116]: config.c:3742 ast_parse_arg: extract uint from [0] in [0, 4294967295] gives [0](0) [Nov 11 16:35:48] DEBUG[18116]: config.c:3742 ast_parse_arg: extract uint from [90] in [0, 4294967295] gives [90](0) [Nov 11 16:35:48] DEBUG[18116]: config.c:3742 ast_parse_arg: extract uint from [0] in [0, 4294967295] gives [0](0) [Nov 11 16:35:48] DEBUG[18116]: config.c:3742 ast_parse_arg: extract uint from [0] in [0, 4294967295] gives [0](0) [Nov 11 16:35:48] DEBUG[18116]: res_pjsip_endpoint_identifier_user.c:145 username_identify: Identified by From username '1506' domain '104.197.69.7' [Nov 11 16:35:48] DEBUG[18116]: res_odbc.c:869 _ast_odbc_request_obj2: Reusing ODBC handle 0x253ae80 from class 'asterisk' [Nov 11 16:35:48] DEBUG[18116]: res_config_odbc.c:116 custom_prepare: Skip: 0; SQL: SELECT * FROM ps_auths WHERE id = ? [Nov 11 16:35:48] DEBUG[18116]: res_config_odbc.c:132 custom_prepare: Parameter 1 ('id') = 'phone' [Nov 11 16:35:48] DEBUG[18116]: res_odbc.c:718 ast_odbc_release_obj: Releasing ODBC handle 0x253ae80 into pool [Nov 11 16:35:48] DEBUG[18116]: config.c:3742 ast_parse_arg: extract uint from [32] in [0, 4294967295] gives [32](0) [Nov 11 16:35:48] DEBUG[18116]: netsock2.c:172 ast_sockaddr_split_hostport: Splitting '10.128.0.3' into... [Nov 11 16:35:48] DEBUG[18116]: netsock2.c:226 ast_sockaddr_split_hostport: ...host '10.128.0.3' and port ''. [Nov 11 16:35:48] DEBUG[18116]: netsock2.c:172 ast_sockaddr_split_hostport: Splitting '12.49.160.131' into... [Nov 11 16:35:48] DEBUG[18116]: netsock2.c:226 ast_sockaddr_split_hostport: ...host '12.49.160.131' and port ''. [Nov 11 16:35:48] DEBUG[18116]: netsock2.c:172 ast_sockaddr_split_hostport: Splitting '10.128.0.3:5060' into... [Nov 11 16:35:48] DEBUG[18116]: netsock2.c:226 ast_sockaddr_split_hostport: ...host '10.128.0.3' and port '5060'. [Nov 11 16:35:48] DEBUG[18116]: netsock2.c:172 ast_sockaddr_split_hostport: Splitting '12.49.160.131:58781' into... [Nov 11 16:35:48] DEBUG[18116]: netsock2.c:226 ast_sockaddr_split_hostport: ...host '12.49.160.131' and port '58781'. <--- Transmitting SIP response (531 bytes) to UDP:12.49.160.131:58781 ---> SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 10.200.101.116:58781;rport=58781;received=12.49.160.131;branch=z9hG4bK-524287-1---510c701eed52f364 Call-ID: 82162MjA5NTE0YjkyZTE4MjA3ZGUzNzZhYjQxNDc2MTllMzI From: ;tag=bc201339 To: ;tag=z9hG4bK-524287-1---510c701eed52f364 CSeq: 1 REGISTER WWW-Authenticate: Digest realm="asterisk",nonce="1478882148/653fbe68f2075d95afa47c426cc5968e",opaque="332b66cd0eb86fdf",algorithm=md5,qop="auth" Server: Asterisk PBX 14.1.1 Content-Length: 0 <--- Received SIP request (525 bytes) from UDP:12.49.160.131:58781 ---> REGISTER sip:104.197.69.7 SIP/2.0 Via: SIP/2.0/UDP 10.200.101.116:58781;branch=z9hG4bK-524287-1---510c701eed52f364;rport Max-Forwards: 70 Contact: To: From: ;tag=bc201339 Call-ID: 82162MjA5NTE0YjkyZTE4MjA3ZGUzNzZhYjQxNDc2MTllMzI CSeq: 1 REGISTER Expires: 3600 Allow: SUBSCRIBE, NOTIFY, INVITE, ACK, CANCEL, BYE, REFER, INFO, OPTIONS, MESSAGE User-Agent: Bria 4 release 4.6.0 stamp 82162 Content-Length: 0 [Nov 11 16:35:50] DEBUG[18053]: netsock2.c:172 ast_sockaddr_split_hostport: Splitting '12.49.160.131:58781' into... [Nov 11 16:35:50] DEBUG[18053]: netsock2.c:226 ast_sockaddr_split_hostport: ...host '12.49.160.131' and port '58781'. [Nov 11 16:35:50] DEBUG[18053]: netsock2.c:172 ast_sockaddr_split_hostport: Splitting '10.128.0.3:5060' into... [Nov 11 16:35:50] DEBUG[18053]: netsock2.c:226 ast_sockaddr_split_hostport: ...host '10.128.0.3' and port '5060'. [Nov 11 16:35:50] DEBUG[18053]: res_pjsip/pjsip_distributor.c:267 find_dialog: Could not find matching transaction for Request msg REGISTER/cseq=1 (rdata0x7f34940095b8) [Nov 11 16:35:50] DEBUG[18053]: res_pjsip/pjsip_distributor.c:359 ast_sip_get_distributor_serializer: Calculated serializer pjsip/distributor-0000002a to use for Request msg REGISTER/cseq=1 (rdata0x7f34940095b8) [Nov 11 16:35:50] DEBUG[18116]: res_odbc.c:869 _ast_odbc_request_obj2: Reusing ODBC handle 0x253ae80 from class 'asterisk' [Nov 11 16:35:50] DEBUG[18116]: res_config_odbc.c:116 custom_prepare: Skip: 0; SQL: SELECT * FROM ps_endpoint_id_ips WHERE id LIKE ? ORDER BY id [Nov 11 16:35:50] DEBUG[18116]: res_config_odbc.c:132 custom_prepare: Parameter 1 ('id LIKE') = '%' [Nov 11 16:35:50] DEBUG[18116]: res_odbc.c:718 ast_odbc_release_obj: Releasing ODBC handle 0x253ae80 into pool [Nov 11 16:35:50] DEBUG[18116]: res_pjsip_endpoint_identifier_ip.c:128 ip_identify: No identify sections to match against [Nov 11 16:35:50] DEBUG[18116]: res_pjsip_endpoint_identifier_user.c:133 username_identify: Attempting identify by From username '1506' domain '104.197.69.7' [Nov 11 16:35:50] DEBUG[18116]: res_odbc.c:869 _ast_odbc_request_obj2: Reusing ODBC handle 0x253ae80 from class 'asterisk' [Nov 11 16:35:50] DEBUG[18116]: res_config_odbc.c:116 custom_prepare: Skip: 0; SQL: SELECT * FROM ps_endpoints WHERE id = ? [Nov 11 16:35:50] DEBUG[18116]: res_config_odbc.c:132 custom_prepare: Parameter 1 ('id') = '1506@104.197.69.7' [Nov 11 16:35:50] DEBUG[18116]: res_odbc.c:718 ast_odbc_release_obj: Releasing ODBC handle 0x253ae80 into pool [Nov 11 16:35:50] DEBUG[18116]: res_odbc.c:869 _ast_odbc_request_obj2: Reusing ODBC handle 0x253ae80 from class 'asterisk' [Nov 11 16:35:50] DEBUG[18116]: res_config_odbc.c:116 custom_prepare: Skip: 0; SQL: SELECT * FROM ps_domain_aliases WHERE id = ? [Nov 11 16:35:50] DEBUG[18116]: res_config_odbc.c:132 custom_prepare: Parameter 1 ('id') = '104.197.69.7' [Nov 11 16:35:50] DEBUG[18116]: res_odbc.c:718 ast_odbc_release_obj: Releasing ODBC handle 0x253ae80 into pool [Nov 11 16:35:50] DEBUG[18116]: res_odbc.c:869 _ast_odbc_request_obj2: Reusing ODBC handle 0x253ae80 from class 'asterisk' [Nov 11 16:35:50] DEBUG[18116]: res_config_odbc.c:116 custom_prepare: Skip: 0; SQL: SELECT * FROM ps_transports WHERE id = ? [Nov 11 16:35:50] DEBUG[18116]: res_config_odbc.c:132 custom_prepare: Parameter 1 ('id') = 'nat_udp' [Nov 11 16:35:50] DEBUG[18116]: res_odbc.c:718 ast_odbc_release_obj: Releasing ODBC handle 0x253ae80 into pool [Nov 11 16:35:50] DEBUG[18116]: config.c:3742 ast_parse_arg: extract uint from [0] in [0, 65535] gives [0](0) [Nov 11 16:35:50] DEBUG[18116]: config.c:3689 ast_parse_arg: extract int from [100] in [1, 2147483647] gives [100](0) [Nov 11 16:35:50] DEBUG[18116]: config.c:3742 ast_parse_arg: extract uint from [1] in [0, 4294967295] gives [1](0) [Nov 11 16:35:50] DEBUG[18116]: config.c:3742 ast_parse_arg: extract uint from [0] in [0, 4294967295] gives [0](0) [Nov 11 16:35:50] DEBUG[18116]: netsock2.c:172 ast_sockaddr_split_hostport: Splitting '10.128.0.0' into... [Nov 11 16:35:50] DEBUG[18116]: netsock2.c:226 ast_sockaddr_split_hostport: ...host '10.128.0.0' and port ''. [Nov 11 16:35:50] DEBUG[18116]: acl.c:661 ast_append_ha: 10.128.0.0:0/255.255.240.0:0 sense 0 appended to ACL [Nov 11 16:35:50] DEBUG[18116]: netsock2.c:172 ast_sockaddr_split_hostport: Splitting '104.197.69.7' into... [Nov 11 16:35:50] DEBUG[18116]: netsock2.c:226 ast_sockaddr_split_hostport: ...host '104.197.69.7' and port ''. [Nov 11 16:35:50] DEBUG[18116]: res_odbc.c:869 _ast_odbc_request_obj2: Reusing ODBC handle 0x253ae80 from class 'asterisk' [Nov 11 16:35:50] DEBUG[18116]: res_config_odbc.c:116 custom_prepare: Skip: 0; SQL: SELECT * FROM ps_endpoints WHERE id = ? [Nov 11 16:35:50] DEBUG[18116]: res_config_odbc.c:132 custom_prepare: Parameter 1 ('id') = '1506' [Nov 11 16:35:50] DEBUG[18116]: res_odbc.c:718 ast_odbc_release_obj: Releasing ODBC handle 0x253ae80 into pool [Nov 11 16:35:50] DEBUG[18116]: res_sorcery_realtime.c:131 sorcery_realtime_filter_objectset: Filtering out realtime field 'disallow' from retrieval [Nov 11 16:35:50] DEBUG[18116]: config.c:3742 ast_parse_arg: extract uint from [0] in [0, 4294967295] gives [0](0) [Nov 11 16:35:50] DEBUG[18116]: config.c:3742 ast_parse_arg: extract uint from [0] in [0, 4294967295] gives [0](0) [Nov 11 16:35:50] DEBUG[18116]: config.c:3742 ast_parse_arg: extract uint from [0] in [0, 4294967295] gives [0](0) [Nov 11 16:35:50] DEBUG[18116]: config.c:3742 ast_parse_arg: extract uint from [0] in [0, 4294967295] gives [0](0) [Nov 11 16:35:50] DEBUG[18116]: config.c:3742 ast_parse_arg: extract uint from [0] in [0, 4294967295] gives [0](0) [Nov 11 16:35:50] DEBUG[18116]: config.c:3742 ast_parse_arg: extract uint from [1800] in [0, 4294967295] gives [1800](0) [Nov 11 16:35:50] DEBUG[18116]: config.c:3742 ast_parse_arg: extract uint from [0] in [0, 4294967295] gives [0](0) [Nov 11 16:35:50] DEBUG[18116]: config.c:3742 ast_parse_arg: extract uint from [0] in [0, 4294967295] gives [0](0) [Nov 11 16:35:50] DEBUG[18116]: config.c:3742 ast_parse_arg: extract uint from [90] in [0, 4294967295] gives [90](0) [Nov 11 16:35:50] DEBUG[18116]: config.c:3742 ast_parse_arg: extract uint from [0] in [0, 4294967295] gives [0](0) [Nov 11 16:35:50] DEBUG[18116]: config.c:3742 ast_parse_arg: extract uint from [0] in [0, 4294967295] gives [0](0) [Nov 11 16:35:50] DEBUG[18116]: res_pjsip_endpoint_identifier_user.c:145 username_identify: Identified by From username '1506' domain '104.197.69.7' [Nov 11 16:35:50] DEBUG[18116]: res_odbc.c:869 _ast_odbc_request_obj2: Reusing ODBC handle 0x253ae80 from class 'asterisk' [Nov 11 16:35:50] DEBUG[18116]: res_config_odbc.c:116 custom_prepare: Skip: 0; SQL: SELECT * FROM ps_auths WHERE id = ? [Nov 11 16:35:50] DEBUG[18116]: res_config_odbc.c:132 custom_prepare: Parameter 1 ('id') = 'phone' [Nov 11 16:35:50] DEBUG[18116]: res_odbc.c:718 ast_odbc_release_obj: Releasing ODBC handle 0x253ae80 into pool [Nov 11 16:35:50] DEBUG[18116]: config.c:3742 ast_parse_arg: extract uint from [32] in [0, 4294967295] gives [32](0) [Nov 11 16:35:50] DEBUG[18116]: netsock2.c:172 ast_sockaddr_split_hostport: Splitting '10.128.0.3' into... [Nov 11 16:35:50] DEBUG[18116]: netsock2.c:226 ast_sockaddr_split_hostport: ...host '10.128.0.3' and port ''. [Nov 11 16:35:50] DEBUG[18116]: netsock2.c:172 ast_sockaddr_split_hostport: Splitting '12.49.160.131' into... [Nov 11 16:35:50] DEBUG[18116]: netsock2.c:226 ast_sockaddr_split_hostport: ...host '12.49.160.131' and port ''. [Nov 11 16:35:50] DEBUG[18116]: netsock2.c:172 ast_sockaddr_split_hostport: Splitting '10.128.0.3:5060' into... [Nov 11 16:35:50] DEBUG[18116]: netsock2.c:226 ast_sockaddr_split_hostport: ...host '10.128.0.3' and port '5060'. [Nov 11 16:35:50] DEBUG[18116]: netsock2.c:172 ast_sockaddr_split_hostport: Splitting '12.49.160.131:58781' into... [Nov 11 16:35:50] DEBUG[18116]: netsock2.c:226 ast_sockaddr_split_hostport: ...host '12.49.160.131' and port '58781'. <--- Transmitting SIP response (531 bytes) to UDP:12.49.160.131:58781 ---> SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 10.200.101.116:58781;rport=58781;received=12.49.160.131;branch=z9hG4bK-524287-1---510c701eed52f364 Call-ID: 82162MjA5NTE0YjkyZTE4MjA3ZGUzNzZhYjQxNDc2MTllMzI From: ;tag=bc201339 To: ;tag=z9hG4bK-524287-1---510c701eed52f364 CSeq: 1 REGISTER WWW-Authenticate: Digest realm="asterisk",nonce="1478882150/cc54c3c70bf899a0db1ec63be86a0597",opaque="0f7b7b9136d9bd05",algorithm=md5,qop="auth" Server: Asterisk PBX 14.1.1 Content-Length: 0 devast*CLI> pjsip set logger off PJSIP Logging disabled [Nov 11 16:36:00] DEBUG[18092]: res_pjsip_registrar_expire.c:78 check_expiration_thread: Woke up at 1478882160 Interval: 30 [Nov 11 16:36:00] DEBUG[18092]: res_pjsip_registrar_expire.c:85 check_expiration_thread: Expiring 0 contacts devast*CLI> core set debug off Core debug was 5 and is now OFF. devast*CLI>