[May 18 08:37:33] Asterisk 13.9.1 built by root @ sip1.voztovoice.net on a x86_64 running Linux on 2016-05-17 17:50:13 UTC [May 18 08:37:38] ERROR[5661] res_pjsip.c: Unable to create outbound OPTIONS request to endpoint 1000@sip1.voztovoice.net [May 18 08:37:38] ERROR[5661] res_pjsip/pjsip_options.c: Unable to create request to qualify contact sip:1000@95.250.29.3:63830;rinstance=0148f41ce0e64c22 [May 18 08:37:45] DEBUG[5664] threadpool.c: Worker thread idle timeout reached. Dying. [May 18 08:37:45] DEBUG[5665] threadpool.c: Worker thread idle timeout reached. Dying. [May 18 08:37:45] DEBUG[5659] threadpool.c: Destroying worker thread 8 [May 18 08:37:45] DEBUG[5659] threadpool.c: Destroying worker thread 9 [May 18 08:37:45] DEBUG[5667] threadpool.c: Worker thread idle timeout reached. Dying. [May 18 08:37:45] DEBUG[5668] threadpool.c: Worker thread idle timeout reached. Dying. [May 18 08:37:45] DEBUG[5669] threadpool.c: Worker thread idle timeout reached. Dying. [May 18 08:37:45] DEBUG[5638] threadpool.c: Destroying worker thread 11 [May 18 08:37:45] DEBUG[5638] threadpool.c: Destroying worker thread 12 [May 18 08:37:45] DEBUG[5638] threadpool.c: Destroying worker thread 13 [May 18 08:37:46] DEBUG[5683] chan_sip.c: Allocating new SIP dialog for 4aab073e3e920dad57c798be013830e5@[::1]:5060 - OPTIONS (No RTP) [May 18 08:37:46] DEBUG[5683] acl.c: For destination '45.79.0.96', our source address is '104.131.62.231'. [May 18 08:37:46] DEBUG[5683] chan_sip.c: Target address 45.79.0.96:5060 is not local, substituting externaddr [May 18 08:37:46] DEBUG[5683] chan_sip.c: Setting AST_TRANSPORT_UDP with address 104.131.62.231:5060 [May 18 08:37:46] DEBUG[5683] chan_sip.c: SIP call-id changed from '4aab073e3e920dad57c798be013830e5@[::1]:5060' to '3daf9c75606541ff3fbdff8703539ae0@104.131.62.231:5060' [May 18 08:37:46] DEBUG[5683] chan_sip.c: Initializing initreq for method OPTIONS - callid 3daf9c75606541ff3fbdff8703539ae0@104.131.62.231:5060 [May 18 08:37:46] DEBUG[5683] chan_sip.c: Trying to put 'OPTIONS sip' onto UDP socket destined for 45.79.0.96:5060 [May 18 08:37:46] DEBUG[5683] chan_sip.c: = Looking for Call ID: 3daf9c75606541ff3fbdff8703539ae0@104.131.62.231:5060 (Checking To) --From tag as72248b17 --To-tag 35c3bda49c13da092cc089e13e0de35f.8834 [May 18 08:37:46] DEBUG[5683] chan_sip.c: Stopping retransmission on '3daf9c75606541ff3fbdff8703539ae0@104.131.62.231:5060' of Request 102: Match Found [May 18 08:37:46] DEBUG[5683] chan_sip.c: Destroying SIP dialog 3daf9c75606541ff3fbdff8703539ae0@104.131.62.231:5060 [May 18 08:37:47] DEBUG[5701] res_pjsip_registrar_expire.c: Woke up at 1463578667 Interval: 30 [May 18 08:37:47] DEBUG[5701] res_pjsip_registrar_expire.c: Expiring 0 contacts [May 18 08:37:48] DEBUG[5662] threadpool.c: Worker thread idle timeout reached. Dying. [May 18 08:37:48] DEBUG[5663] threadpool.c: Worker thread idle timeout reached. Dying. [May 18 08:37:48] DEBUG[5659] threadpool.c: Destroying worker thread 6 [May 18 08:37:48] DEBUG[5659] threadpool.c: Destroying worker thread 7 [May 18 08:37:53] DEBUG[5661] config.c: extract uint from [3] in [0, 4294967295] gives [3](0) [May 18 08:37:53] DEBUG[5661] config.c: extract uint from [0] in [0, 4294967295] gives [0](0) [May 18 08:37:53] DEBUG[5661] config.c: extract uint from [2] in [0, 4294967295] gives [2](0) [May 18 08:37:53] DEBUG[5661] res_pjsip.c: 0x7faf2c00ad78: Wrapper created [May 18 08:37:53] DEBUG[5661] res_pjsip.c: 0x7faf2c00ad78: Set timer to 3000 msec [May 18 08:37:53] DEBUG[5661] res_pjsip_multihomed.c: Re-wrote Contact URI host/port to 104.131.62.231:5080 [May 18 08:37:53] DEBUG[5661] netsock2.c: Splitting '0.0.0.0:5080' into... [May 18 08:37:53] DEBUG[5661] netsock2.c: ...host '0.0.0.0' and port '5080'. [May 18 08:37:53] DEBUG[5661] netsock2.c: Splitting '45.79.0.96:5060' into... [May 18 08:37:53] DEBUG[5661] netsock2.c: ...host '45.79.0.96' and port '5060'. [May 18 08:37:53] VERBOSE[5661] res_pjsip_logger.c: <--- Transmitting SIP request (437 bytes) to UDP:45.79.0.96:5060 ---> OPTIONS sip:sip.voztovoice.eu:5060 SIP/2.0 Via: SIP/2.0/UDP 104.131.62.231:5080;rport;branch=z9hG4bKPj60f5d775-54d4-47d0-9c4f-3e7c9c72de91 From: ;tag=38649881-5865-4927-9646-c11aa6fa7e9f To: Contact: Call-ID: ef2d1288-25a8-4658-bb32-09fed652ce31 CSeq: 22328 OPTIONS Max-Forwards: 70 User-Agent: Curso Asterisk PBX Content-Length: 0 [May 18 08:37:54] VERBOSE[5660] res_pjsip_logger.c: <--- Received SIP response (449 bytes) from UDP:45.79.0.96:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 104.131.62.231:5080;received=104.131.62.231;rport=5080;branch=z9hG4bKPj60f5d775-54d4-47d0-9c4f-3e7c9c72de91 From: ;tag=38649881-5865-4927-9646-c11aa6fa7e9f To: ;tag=35c3bda49c13da092cc089e13e0de35f.5b28 Call-ID: ef2d1288-25a8-4658-bb32-09fed652ce31 CSeq: 22328 OPTIONS Accept: */* Accept-Language: en Server: VozToVoice Proxy Server Content-Length: 0 [May 18 08:37:54] DEBUG[5660] netsock2.c: Splitting '45.79.0.96:5060' into... [May 18 08:37:54] DEBUG[5660] netsock2.c: ...host '45.79.0.96' and port '5060'. [May 18 08:37:54] DEBUG[5660] netsock2.c: Splitting '0.0.0.0:5080' into... [May 18 08:37:54] DEBUG[5660] netsock2.c: ...host '0.0.0.0' and port '5080'. [May 18 08:37:54] DEBUG[5660] res_pjsip/pjsip_distributor.c: No dialog serializer for response (null). Using request transaction as basis [May 18 08:37:54] DEBUG[5660] res_pjsip/pjsip_distributor.c: Found serializer pjsip/default-00000009 on transaction tsx0x7faf2c0109a8 [May 18 08:37:54] DEBUG[5661] res_pjsip.c: 0x7faf2c00ad78: PJSIP tsx response received [May 18 08:37:54] DEBUG[5661] res_pjsip.c: 0x7faf2c00ad78: Cancelling timer [May 18 08:37:54] DEBUG[5661] res_pjsip.c: 0x7faf2c00ad78: Timer cancelled [May 18 08:37:54] DEBUG[5661] config.c: extract uint from [3] in [0, 4294967295] gives [3](0) [May 18 08:37:54] DEBUG[5661] config.c: extract uint from [0] in [0, 4294967295] gives [0](0) [May 18 08:37:54] DEBUG[5661] config.c: extract uint from [2] in [0, 4294967295] gives [2](0) [May 18 08:37:54] DEBUG[5661] res_pjsip.c: 0x7faf2c00ad78: Callbacks executed [May 18 08:37:54] DEBUG[5661] res_pjsip.c: 0x7faf2c00ad78: wrapper destroyed [May 18 08:37:54] DEBUG[5666] res_pjsip/pjsip_configuration.c: Contact voztovoice/sip:sip.voztovoice.eu:5060 status didn't change: Reachable, RTT: 45.665 msec [May 18 08:37:59] VERBOSE[5660] res_pjsip_logger.c: <--- Received SIP request (612 bytes) from UDP:95.250.29.3:51606 ---> SUBSCRIBE sip:1000@sip1.voztovoice.net:5080 SIP/2.0 Via: SIP/2.0/UDP 192.168.1.108:51606;branch=z9hG4bK-524287-1---5bf5645acb88ea5d;rport Max-Forwards: 70 Contact: To: From: "1000";tag=98b5f544 Call-ID: 79961MjBhM2I1MDM1Y2Y5MGQ5YmQ4MTRjODBhM2NjN2M5NGE CSeq: 1 SUBSCRIBE Expires: 300 Accept: application/simple-message-summary Allow: SUBSCRIBE, NOTIFY, INVITE, ACK, CANCEL, BYE, REFER, INFO, OPTIONS, MESSAGE User-Agent: X-Lite release 4.9.3 stamp 79961 Event: message-summary Content-Length: 0 [May 18 08:37:59] DEBUG[5660] netsock2.c: Splitting '95.250.29.3:51606' into... [May 18 08:37:59] DEBUG[5660] netsock2.c: ...host '95.250.29.3' and port '51606'. [May 18 08:37:59] DEBUG[5660] netsock2.c: Splitting '0.0.0.0:5080' into... [May 18 08:37:59] DEBUG[5660] netsock2.c: ...host '0.0.0.0' and port '5080'. [May 18 08:37:59] DEBUG[5661] netsock2.c: Splitting '95.250.29.3' into... [May 18 08:37:59] DEBUG[5661] netsock2.c: ...host '95.250.29.3' and port ''. [May 18 08:37:59] DEBUG[5661] res_pjsip_endpoint_identifier_ip.c: Source address 95.250.29.3:51606 does not match identify 'voztovoice' [May 18 08:37:59] DEBUG[5661] res_pjsip_endpoint_identifier_ip.c: '95.250.29.3:51606' did not match any identify section rules [May 18 08:37:59] DEBUG[5661] res_pjsip_endpoint_identifier_user.c: Retrieved endpoint 1000@sip1.voztovoice.net [May 18 08:37:59] DEBUG[5661] netsock2.c: Splitting '104.131.62.231' into... [May 18 08:37:59] DEBUG[5661] netsock2.c: ...host '104.131.62.231' and port ''. [May 18 08:37:59] DEBUG[5661] netsock2.c: Splitting '95.250.29.3' into... [May 18 08:37:59] DEBUG[5661] netsock2.c: ...host '95.250.29.3' and port ''. [May 18 08:37:59] DEBUG[5661] netsock2.c: Splitting '0.0.0.0:5080' into... [May 18 08:37:59] DEBUG[5661] netsock2.c: ...host '0.0.0.0' and port '5080'. [May 18 08:37:59] DEBUG[5661] netsock2.c: Splitting '95.250.29.3:51606' into... [May 18 08:37:59] DEBUG[5661] netsock2.c: ...host '95.250.29.3' and port '51606'. [May 18 08:37:59] VERBOSE[5661] res_pjsip_logger.c: <--- Transmitting SIP response (549 bytes) to UDP:95.250.29.3:51606 ---> SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 192.168.1.108:51606;rport=51606;received=95.250.29.3;branch=z9hG4bK-524287-1---5bf5645acb88ea5d Call-ID: 79961MjBhM2I1MDM1Y2Y5MGQ5YmQ4MTRjODBhM2NjN2M5NGE From: "1000" ;tag=98b5f544 To: ;tag=z9hG4bK-524287-1---5bf5645acb88ea5d CSeq: 1 SUBSCRIBE WWW-Authenticate: Digest realm="asterisk",nonce="1463578679/667f153de353c1a62593b13bffe71513",opaque="4000bc0e1e734135",algorithm=md5,qop="auth" Server: Curso Asterisk PBX Content-Length: 0 [May 18 08:38:00] VERBOSE[5660] res_pjsip_logger.c: <--- Received SIP request (907 bytes) from UDP:95.250.29.3:51606 ---> SUBSCRIBE sip:1000@sip1.voztovoice.net:5080 SIP/2.0 Via: SIP/2.0/UDP 192.168.1.108:51606;branch=z9hG4bK-524287-1---88432329f83c7347;rport Max-Forwards: 70 Contact: To: From: "1000";tag=98b5f544 Call-ID: 79961MjBhM2I1MDM1Y2Y5MGQ5YmQ4MTRjODBhM2NjN2M5NGE CSeq: 2 SUBSCRIBE Expires: 300 Accept: application/simple-message-summary Allow: SUBSCRIBE, NOTIFY, INVITE, ACK, CANCEL, BYE, REFER, INFO, OPTIONS, MESSAGE User-Agent: X-Lite release 4.9.3 stamp 79961 Authorization: Digest username="1000",realm="asterisk",nonce="1463578679/667f153de353c1a62593b13bffe71513",uri="sip:1000@sip1.voztovoice.net:5080",response="2479d4cc3410da0127eee8c7ce6b1d23",cnonce="b842238fc4ca46a2bc32f9ff499a8e7b",nc=00000001,qop=auth,algorithm=md5,opaque="4000bc0e1e734135" Event: message-summary Content-Length: 0 [May 18 08:38:00] DEBUG[5660] netsock2.c: Splitting '95.250.29.3:51606' into... [May 18 08:38:00] DEBUG[5660] netsock2.c: ...host '95.250.29.3' and port '51606'. [May 18 08:38:00] DEBUG[5660] netsock2.c: Splitting '0.0.0.0:5080' into... [May 18 08:38:00] DEBUG[5660] netsock2.c: ...host '0.0.0.0' and port '5080'. [May 18 08:38:00] DEBUG[5661] netsock2.c: Splitting '95.250.29.3' into... [May 18 08:38:00] DEBUG[5661] netsock2.c: ...host '95.250.29.3' and port ''. [May 18 08:38:00] DEBUG[5661] res_pjsip_endpoint_identifier_ip.c: Source address 95.250.29.3:51606 does not match identify 'voztovoice' [May 18 08:38:00] DEBUG[5661] res_pjsip_endpoint_identifier_ip.c: '95.250.29.3:51606' did not match any identify section rules [May 18 08:38:00] DEBUG[5661] res_pjsip_endpoint_identifier_user.c: Retrieved endpoint 1000@sip1.voztovoice.net [May 18 08:38:00] DEBUG[5661] res_pjsip_authenticator_digest.c: Calculated nonce 1463578679/667f153de353c1a62593b13bffe71513. Actual nonce is 1463578679/667f153de353c1a62593b13bffe71513 [May 18 08:38:00] DEBUG[5661] netsock2.c: Splitting '104.131.62.231' into... [May 18 08:38:00] DEBUG[5661] netsock2.c: ...host '104.131.62.231' and port ''. [May 18 08:38:00] DEBUG[5661] netsock2.c: Splitting '95.250.29.3' into... [May 18 08:38:00] DEBUG[5661] netsock2.c: ...host '95.250.29.3' and port ''. [May 18 08:38:00] DEBUG[5661] res_pjsip_pubsub.c: Body generator 0x7faef617a120 found for accept type application/simple-message-summary [May 18 08:38:00] DEBUG[5661] res_pjsip_pubsub.c: Subscription to resource 1000 is not to a list [May 18 08:38:00] DEBUG[5661] res_pjsip_mwi.c: AOR 1000 has no configured mailboxes. MWI subscription failed. [May 18 08:38:00] DEBUG[5661] netsock2.c: Splitting '0.0.0.0:5080' into... [May 18 08:38:00] DEBUG[5661] netsock2.c: ...host '0.0.0.0' and port '5080'. [May 18 08:38:00] DEBUG[5661] netsock2.c: Splitting '95.250.29.3:51606' into... [May 18 08:38:00] DEBUG[5661] netsock2.c: ...host '95.250.29.3' and port '51606'. [May 18 08:38:00] VERBOSE[5661] res_pjsip_logger.c: <--- Transmitting SIP response (399 bytes) to UDP:95.250.29.3:51606 ---> SIP/2.0 404 Not Found Via: SIP/2.0/UDP 192.168.1.108:51606;rport=51606;received=95.250.29.3;branch=z9hG4bK-524287-1---88432329f83c7347 Call-ID: 79961MjBhM2I1MDM1Y2Y5MGQ5YmQ4MTRjODBhM2NjN2M5NGE From: "1000" ;tag=98b5f544 To: ;tag=z9hG4bK-524287-1---88432329f83c7347 CSeq: 2 SUBSCRIBE Server: Curso Asterisk PBX Content-Length: 0 [May 18 08:38:08] ERROR[5661] res_pjsip.c: Unable to create outbound OPTIONS request to endpoint 1000@sip1.voztovoice.net [May 18 08:38:08] ERROR[5661] res_pjsip/pjsip_options.c: Unable to create request to qualify contact sip:1000@95.250.29.3:63830;rinstance=0148f41ce0e64c22 [May 18 08:38:13] VERBOSE[5660] res_pjsip_logger.c: <--- Received SIP request (571 bytes) from UDP:95.250.29.3:51621 ---> REGISTER sip:sip1.voztovoice.net:5080 SIP/2.0 Via: SIP/2.0/UDP 192.168.1.108:51621;branch=z9hG4bK-524287-1---8887234a12d2aa4c;rport Max-Forwards: 70 Contact: To: "1000" From: "1000";tag=22cf657f Call-ID: 79961Yjc1YWQyMGNhZDA3MmZmZTJiMDdlZGRhMzJmNjJkN2U CSeq: 1 REGISTER Expires: 3600 Allow: SUBSCRIBE, NOTIFY, INVITE, ACK, CANCEL, BYE, REFER, INFO, OPTIONS, MESSAGE User-Agent: X-Lite release 4.9.3 stamp 79961 Content-Length: 0 [May 18 08:38:13] DEBUG[5660] netsock2.c: Splitting '95.250.29.3:51621' into... [May 18 08:38:13] DEBUG[5660] netsock2.c: ...host '95.250.29.3' and port '51621'. [May 18 08:38:13] DEBUG[5660] netsock2.c: Splitting '0.0.0.0:5080' into... [May 18 08:38:13] DEBUG[5660] netsock2.c: ...host '0.0.0.0' and port '5080'. [May 18 08:38:13] DEBUG[5661] netsock2.c: Splitting '95.250.29.3' into... [May 18 08:38:13] DEBUG[5661] netsock2.c: ...host '95.250.29.3' and port ''. [May 18 08:38:13] DEBUG[5661] res_pjsip_endpoint_identifier_ip.c: Source address 95.250.29.3:51621 does not match identify 'voztovoice' [May 18 08:38:13] DEBUG[5661] res_pjsip_endpoint_identifier_ip.c: '95.250.29.3:51621' did not match any identify section rules [May 18 08:38:13] DEBUG[5661] res_pjsip_endpoint_identifier_user.c: Retrieved endpoint 1000@sip1.voztovoice.net [May 18 08:38:13] DEBUG[5661] netsock2.c: Splitting '104.131.62.231' into... [May 18 08:38:13] DEBUG[5661] netsock2.c: ...host '104.131.62.231' and port ''. [May 18 08:38:13] DEBUG[5661] netsock2.c: Splitting '95.250.29.3' into... [May 18 08:38:13] DEBUG[5661] netsock2.c: ...host '95.250.29.3' and port ''. [May 18 08:38:13] DEBUG[5661] netsock2.c: Splitting '0.0.0.0:5080' into... [May 18 08:38:13] DEBUG[5661] netsock2.c: ...host '0.0.0.0' and port '5080'. [May 18 08:38:13] DEBUG[5661] netsock2.c: Splitting '95.250.29.3:51621' into... [May 18 08:38:13] DEBUG[5661] netsock2.c: ...host '95.250.29.3' and port '51621'. [May 18 08:38:13] VERBOSE[5661] res_pjsip_logger.c: <--- Transmitting SIP response (555 bytes) to UDP:95.250.29.3:51621 ---> SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 192.168.1.108:51621;rport=51621;received=95.250.29.3;branch=z9hG4bK-524287-1---8887234a12d2aa4c Call-ID: 79961Yjc1YWQyMGNhZDA3MmZmZTJiMDdlZGRhMzJmNjJkN2U From: "1000" ;tag=22cf657f To: "1000" ;tag=z9hG4bK-524287-1---8887234a12d2aa4c CSeq: 1 REGISTER WWW-Authenticate: Digest realm="asterisk",nonce="1463578693/fb10ef5e4c6809fd3baa7348c91ad749",opaque="5bd48773667d5b9a",algorithm=md5,qop="auth" Server: Curso Asterisk PBX Content-Length: 0 [May 18 08:38:13] VERBOSE[5660] res_pjsip_logger.c: <--- Received SIP request (861 bytes) from UDP:95.250.29.3:51621 ---> REGISTER sip:sip1.voztovoice.net:5080 SIP/2.0 Via: SIP/2.0/UDP 192.168.1.108:51621;branch=z9hG4bK-524287-1---900b9f30c65d431d;rport Max-Forwards: 70 Contact: To: "1000" From: "1000";tag=22cf657f Call-ID: 79961Yjc1YWQyMGNhZDA3MmZmZTJiMDdlZGRhMzJmNjJkN2U CSeq: 2 REGISTER Expires: 3600 Allow: SUBSCRIBE, NOTIFY, INVITE, ACK, CANCEL, BYE, REFER, INFO, OPTIONS, MESSAGE User-Agent: X-Lite release 4.9.3 stamp 79961 Authorization: Digest username="1000",realm="asterisk",nonce="1463578693/fb10ef5e4c6809fd3baa7348c91ad749",uri="sip:sip1.voztovoice.net:5080",response="d26f736bde1301c9f6de2ea5b377181b",cnonce="a782d7ed500ce14c3b2daa370a0bb5aa",nc=00000001,qop=auth,algorithm=md5,opaque="5bd48773667d5b9a" Content-Length: 0 [May 18 08:38:13] DEBUG[5660] netsock2.c: Splitting '95.250.29.3:51621' into... [May 18 08:38:13] DEBUG[5660] netsock2.c: ...host '95.250.29.3' and port '51621'. [May 18 08:38:13] DEBUG[5660] netsock2.c: Splitting '0.0.0.0:5080' into... [May 18 08:38:13] DEBUG[5660] netsock2.c: ...host '0.0.0.0' and port '5080'. [May 18 08:38:13] DEBUG[5661] netsock2.c: Splitting '95.250.29.3' into... [May 18 08:38:13] DEBUG[5661] netsock2.c: ...host '95.250.29.3' and port ''. [May 18 08:38:13] DEBUG[5661] res_pjsip_endpoint_identifier_ip.c: Source address 95.250.29.3:51621 does not match identify 'voztovoice' [May 18 08:38:13] DEBUG[5661] res_pjsip_endpoint_identifier_ip.c: '95.250.29.3:51621' did not match any identify section rules [May 18 08:38:13] DEBUG[5661] res_pjsip_endpoint_identifier_user.c: Retrieved endpoint 1000@sip1.voztovoice.net [May 18 08:38:13] DEBUG[5661] res_pjsip_authenticator_digest.c: Calculated nonce 1463578693/fb10ef5e4c6809fd3baa7348c91ad749. Actual nonce is 1463578693/fb10ef5e4c6809fd3baa7348c91ad749 [May 18 08:38:13] DEBUG[5661] netsock2.c: Splitting '104.131.62.231' into... [May 18 08:38:13] DEBUG[5661] netsock2.c: ...host '104.131.62.231' and port ''. [May 18 08:38:13] DEBUG[5661] netsock2.c: Splitting '95.250.29.3' into... [May 18 08:38:13] DEBUG[5661] netsock2.c: ...host '95.250.29.3' and port ''. [May 18 08:38:13] DEBUG[5661] config.c: extract double from [3.0] in [-inf, inf] gives [3.000000](0) [May 18 08:38:13] DEBUG[5661] config.c: extract double from [3.000000] in [-inf, inf] gives [3.000000](0) [May 18 08:38:13] DEBUG[5661] config.c: extract uint from [30] in [0, 86400] gives [30](0) [May 18 08:38:13] DEBUG[5661] config.c: extract double from [3.0] in [-inf, inf] gives [3.000000](0) [May 18 08:38:13] VERBOSE[5661] res_pjsip_registrar.c: Added contact 'sip:1000@95.250.29.3:51621;rinstance=d952013009ce781f' to AOR '1000' with expiration of 3600 seconds [May 18 08:38:13] DEBUG[5661] config.c: extract double from [3.0] in [-inf, inf] gives [3.000000](0) [May 18 08:38:13] DEBUG[5661] config.c: extract double from [3.000000] in [-inf, inf] gives [3.000000](0) [May 18 08:38:13] DEBUG[5661] config.c: extract uint from [30] in [0, 86400] gives [30](0) [May 18 08:38:13] DEBUG[5661] config.c: extract uint from [3] in [0, 4294967295] gives [3](0) [May 18 08:38:13] DEBUG[5661] config.c: extract uint from [0] in [0, 4294967295] gives [0](0) [May 18 08:38:13] DEBUG[5661] config.c: extract uint from [2] in [0, 4294967295] gives [2](0) [May 18 08:38:13] DEBUG[5661] netsock2.c: Splitting '0.0.0.0:5080' into... [May 18 08:38:13] DEBUG[5661] netsock2.c: ...host '0.0.0.0' and port '5080'. [May 18 08:38:13] DEBUG[5661] netsock2.c: Splitting '95.250.29.3:51621' into... [May 18 08:38:13] DEBUG[5661] netsock2.c: ...host '95.250.29.3' and port '51621'. [May 18 08:38:13] VERBOSE[5661] res_pjsip_logger.c: <--- Transmitting SIP response (529 bytes) to UDP:95.250.29.3:51621 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.1.108:51621;rport=51621;received=95.250.29.3;branch=z9hG4bK-524287-1---900b9f30c65d431d Call-ID: 79961Yjc1YWQyMGNhZDA3MmZmZTJiMDdlZGRhMzJmNjJkN2U From: "1000" ;tag=22cf657f To: "1000" ;tag=z9hG4bK-524287-1---900b9f30c65d431d CSeq: 2 REGISTER Date: Wed, 18 May 2016 13:38:13 GMT Contact: ;expires=3599 Expires: 3600 Server: Curso Asterisk PBX Content-Length: 0 [May 18 08:38:13] DEBUG[5638] threadpool.c: Increasing threadpool Sorcery's size by 1 [May 18 08:38:13] DEBUG[5666] config.c: extract uint from [3] in [0, 4294967295] gives [3](0) [May 18 08:38:13] DEBUG[5666] config.c: extract uint from [0] in [0, 4294967295] gives [0](0) [May 18 08:38:13] DEBUG[5666] config.c: extract uint from [2] in [0, 4294967295] gives [2](0) [May 18 08:38:13] VERBOSE[5666] res_pjsip/pjsip_configuration.c: Contact 1000/sip:1000@95.250.29.3:51621;rinstance=d952013009ce781f has been created [May 18 08:38:13] DEBUG[5639] threadpool.c: Increasing threadpool stasis-core's size by 1 [May 18 08:38:13] DEBUG[5659] threadpool.c: Increasing threadpool SIP's size by 5 [May 18 08:38:13] DEBUG[5666] config.c: extract double from [3.0] in [-inf, inf] gives [3.000000](0) [May 18 08:38:13] DEBUG[5666] config.c: extract double from [3.000000] in [-inf, inf] gives [3.000000](0) [May 18 08:38:13] DEBUG[5666] config.c: extract uint from [30] in [0, 86400] gives [30](0) [May 18 08:38:13] DEBUG[5666] res_pjsip_mwi.c: Removing stasis subscription to mailbox 1000@default [May 18 08:38:13] DEBUG[5639] threadpool.c: Increasing threadpool stasis-core's size by 1 [May 18 08:38:13] ERROR[5661] res_pjsip.c: Unable to create outbound OPTIONS request to endpoint 1000@sip1.voztovoice.net [May 18 08:38:13] ERROR[5661] res_pjsip/pjsip_options.c: Unable to create request to qualify contact sip:1000@95.250.29.3:51621;rinstance=d952013009ce781f [May 18 08:38:13] DEBUG[5666] taskprocessor.c: destroying taskprocessor 'subp:1000@default-00000025' [May 18 08:38:13] DEBUG[5666] config.c: extract double from [3.0] in [-inf, inf] gives [3.000000](0) [May 18 08:38:13] DEBUG[5666] config.c: extract double from [3.000000] in [-inf, inf] gives [3.000000](0) [May 18 08:38:13] DEBUG[5666] config.c: extract uint from [30] in [0, 86400] gives [30](0) [May 18 08:38:13] DEBUG[5666] res_pjsip_mwi.c: Created unsolicited MWI subscription for endpoint 1000@sip1.voztovoice.net [May 18 08:38:13] DEBUG[5666] res_pjsip_mwi.c: Creating stasis MWI subscription to mailbox 1000@default for endpoint 1000@sip1.voztovoice.net [May 18 08:38:13] VERBOSE[5666] res_pjsip/pjsip_configuration.c: Contact 1000/sip:1000@95.250.29.3:63830;rinstance=0148f41ce0e64c22 has been deleted [May 18 08:38:13] DEBUG[5666] config.c: extract double from [3.0] in [-inf, inf] gives [3.000000](0) [May 18 08:38:13] DEBUG[5666] config.c: extract double from [3.000000] in [-inf, inf] gives [3.000000](0) [May 18 08:38:13] DEBUG[5666] config.c: extract uint from [30] in [0, 86400] gives [30](0) [May 18 08:38:13] DEBUG[5733] res_pjsip_mwi.c: Destroying MWI subscription for endpoint 1000@sip1.voztovoice.net [May 18 08:38:13] DEBUG[5733] res_pjsip_mwi.c: Sending unsolicited MWI NOTIFY to endpoint 1000@sip1.voztovoice.net, new messages: 0, old messages: 0 [May 18 08:38:13] DEBUG[5733] config.c: extract double from [3.0] in [-inf, inf] gives [3.000000](0) [May 18 08:38:13] DEBUG[5733] config.c: extract double from [3.000000] in [-inf, inf] gives [3.000000](0) [May 18 08:38:13] DEBUG[5733] config.c: extract uint from [30] in [0, 86400] gives [30](0) [May 18 08:38:13] ERROR[5733] res_pjsip.c: Unable to create outbound NOTIFY request to endpoint 1000@sip1.voztovoice.net [May 18 08:38:13] WARNING[5733] res_pjsip_mwi.c: Unable to create unsolicited NOTIFY request to endpoint 1000@sip1.voztovoice.net URI sip:1000@95.250.29.3:51621;rinstance=d952013009ce781f [May 18 08:38:13] DEBUG[5639] threadpool.c: Increasing threadpool stasis-core's size by 1 [May 18 08:38:13] DEBUG[5639] threadpool.c: Increasing threadpool stasis-core's size by 1 [May 18 08:38:14] VERBOSE[5660] res_pjsip_logger.c: <--- Received SIP request (637 bytes) from UDP:95.250.29.3:51621 ---> SUBSCRIBE sip:1000@sip1.voztovoice.net:5080 SIP/2.0 Via: SIP/2.0/UDP 192.168.1.108:51621;branch=z9hG4bK-524287-1---b6fbda566c1a9a0a;rport Max-Forwards: 70 Contact: To: From: "1000";tag=289e2f60 Call-ID: 79961MWU5MzM2NjQwMTY1ODdiMGEyZjZhNjExNzFmMGNhZDc CSeq: 1 SUBSCRIBE Expires: 300 Accept: application/simple-message-summary Allow: SUBSCRIBE, NOTIFY, INVITE, ACK, CANCEL, BYE, REFER, INFO, OPTIONS, MESSAGE User-Agent: X-Lite release 4.9.3 stamp 79961 Event: message-summary Content-Length: 0 [May 18 08:38:14] DEBUG[5660] netsock2.c: Splitting '95.250.29.3:51621' into... [May 18 08:38:14] DEBUG[5660] netsock2.c: ...host '95.250.29.3' and port '51621'. [May 18 08:38:14] DEBUG[5660] netsock2.c: Splitting '0.0.0.0:5080' into... [May 18 08:38:14] DEBUG[5660] netsock2.c: ...host '0.0.0.0' and port '5080'. [May 18 08:38:14] DEBUG[5661] netsock2.c: Splitting '95.250.29.3' into... [May 18 08:38:14] DEBUG[5661] netsock2.c: ...host '95.250.29.3' and port ''. [May 18 08:38:14] DEBUG[5661] res_pjsip_endpoint_identifier_ip.c: Source address 95.250.29.3:51621 does not match identify 'voztovoice' [May 18 08:38:14] DEBUG[5661] res_pjsip_endpoint_identifier_ip.c: '95.250.29.3:51621' did not match any identify section rules [May 18 08:38:14] DEBUG[5661] res_pjsip_endpoint_identifier_user.c: Retrieved endpoint 1000@sip1.voztovoice.net [May 18 08:38:14] DEBUG[5661] netsock2.c: Splitting '104.131.62.231' into... [May 18 08:38:14] DEBUG[5661] netsock2.c: ...host '104.131.62.231' and port ''. [May 18 08:38:14] DEBUG[5661] netsock2.c: Splitting '95.250.29.3' into... [May 18 08:38:14] DEBUG[5661] netsock2.c: ...host '95.250.29.3' and port ''. [May 18 08:38:14] DEBUG[5661] netsock2.c: Splitting '0.0.0.0:5080' into... [May 18 08:38:14] DEBUG[5661] netsock2.c: ...host '0.0.0.0' and port '5080'. [May 18 08:38:14] DEBUG[5661] netsock2.c: Splitting '95.250.29.3:51621' into... [May 18 08:38:14] DEBUG[5661] netsock2.c: ...host '95.250.29.3' and port '51621'. [May 18 08:38:14] VERBOSE[5661] res_pjsip_logger.c: <--- Transmitting SIP response (549 bytes) to UDP:95.250.29.3:51621 ---> SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 192.168.1.108:51621;rport=51621;received=95.250.29.3;branch=z9hG4bK-524287-1---b6fbda566c1a9a0a Call-ID: 79961MWU5MzM2NjQwMTY1ODdiMGEyZjZhNjExNzFmMGNhZDc From: "1000" ;tag=289e2f60 To: ;tag=z9hG4bK-524287-1---b6fbda566c1a9a0a CSeq: 1 SUBSCRIBE WWW-Authenticate: Digest realm="asterisk",nonce="1463578694/4be8237959dd339a39aca36f47345496",opaque="265d863b6fecade4",algorithm=md5,qop="auth" Server: Curso Asterisk PBX Content-Length: 0 [May 18 08:38:14] VERBOSE[5660] res_pjsip_logger.c: <--- Received SIP request (932 bytes) from UDP:95.250.29.3:51621 ---> SUBSCRIBE sip:1000@sip1.voztovoice.net:5080 SIP/2.0 Via: SIP/2.0/UDP 192.168.1.108:51621;branch=z9hG4bK-524287-1---3a3346740fb4d165;rport Max-Forwards: 70 Contact: To: From: "1000";tag=289e2f60 Call-ID: 79961MWU5MzM2NjQwMTY1ODdiMGEyZjZhNjExNzFmMGNhZDc CSeq: 2 SUBSCRIBE Expires: 300 Accept: application/simple-message-summary Allow: SUBSCRIBE, NOTIFY, INVITE, ACK, CANCEL, BYE, REFER, INFO, OPTIONS, MESSAGE User-Agent: X-Lite release 4.9.3 stamp 79961 Authorization: Digest username="1000",realm="asterisk",nonce="1463578694/4be8237959dd339a39aca36f47345496",uri="sip:1000@sip1.voztovoice.net:5080",response="7665e19c2c979ee32e9ccfcb8636f2ed",cnonce="e53216aead976e739644baee6c808afe",nc=00000001,qop=auth,algorithm=md5,opaque="265d863b6fecade4" Event: message-summary Content-Length: 0 [May 18 08:38:14] DEBUG[5660] netsock2.c: Splitting '95.250.29.3:51621' into... [May 18 08:38:14] DEBUG[5660] netsock2.c: ...host '95.250.29.3' and port '51621'. [May 18 08:38:14] DEBUG[5660] netsock2.c: Splitting '0.0.0.0:5080' into... [May 18 08:38:14] DEBUG[5660] netsock2.c: ...host '0.0.0.0' and port '5080'. [May 18 08:38:14] DEBUG[5661] netsock2.c: Splitting '95.250.29.3' into... [May 18 08:38:14] DEBUG[5661] netsock2.c: ...host '95.250.29.3' and port ''. [May 18 08:38:14] DEBUG[5661] res_pjsip_endpoint_identifier_ip.c: Source address 95.250.29.3:51621 does not match identify 'voztovoice' [May 18 08:38:14] DEBUG[5661] res_pjsip_endpoint_identifier_ip.c: '95.250.29.3:51621' did not match any identify section rules [May 18 08:38:14] DEBUG[5661] res_pjsip_endpoint_identifier_user.c: Retrieved endpoint 1000@sip1.voztovoice.net [May 18 08:38:14] DEBUG[5661] res_pjsip_authenticator_digest.c: Calculated nonce 1463578694/4be8237959dd339a39aca36f47345496. Actual nonce is 1463578694/4be8237959dd339a39aca36f47345496 [May 18 08:38:14] DEBUG[5661] netsock2.c: Splitting '104.131.62.231' into... [May 18 08:38:14] DEBUG[5661] netsock2.c: ...host '104.131.62.231' and port ''. [May 18 08:38:14] DEBUG[5661] netsock2.c: Splitting '95.250.29.3' into... [May 18 08:38:14] DEBUG[5661] netsock2.c: ...host '95.250.29.3' and port ''. [May 18 08:38:14] DEBUG[5661] res_pjsip_pubsub.c: Body generator 0x7faef617a120 found for accept type application/simple-message-summary [May 18 08:38:14] DEBUG[5661] res_pjsip_pubsub.c: Subscription to resource 1000 is not to a list [May 18 08:38:14] DEBUG[5661] res_pjsip_mwi.c: AOR 1000 has no configured mailboxes. MWI subscription failed. [May 18 08:38:14] DEBUG[5661] netsock2.c: Splitting '0.0.0.0:5080' into... [May 18 08:38:14] DEBUG[5661] netsock2.c: ...host '0.0.0.0' and port '5080'. [May 18 08:38:14] DEBUG[5661] netsock2.c: Splitting '95.250.29.3:51621' into... [May 18 08:38:14] DEBUG[5661] netsock2.c: ...host '95.250.29.3' and port '51621'. [May 18 08:38:14] VERBOSE[5661] res_pjsip_logger.c: <--- Transmitting SIP response (399 bytes) to UDP:95.250.29.3:51621 ---> SIP/2.0 404 Not Found Via: SIP/2.0/UDP 192.168.1.108:51621;rport=51621;received=95.250.29.3;branch=z9hG4bK-524287-1---3a3346740fb4d165 Call-ID: 79961MWU5MzM2NjQwMTY1ODdiMGEyZjZhNjExNzFmMGNhZDc From: "1000" ;tag=289e2f60 To: ;tag=z9hG4bK-524287-1---3a3346740fb4d165 CSeq: 2 SUBSCRIBE Server: Curso Asterisk PBX Content-Length: 0 [May 18 08:38:17] DEBUG[5701] res_pjsip_registrar_expire.c: Woke up at 1463578697 Interval: 30 [May 18 08:38:17] DEBUG[5701] res_pjsip_registrar_expire.c: Expiring 0 contacts [May 18 08:38:23] DEBUG[5661] config.c: extract uint from [3] in [0, 4294967295] gives [3](0) [May 18 08:38:23] DEBUG[5661] config.c: extract uint from [0] in [0, 4294967295] gives [0](0) [May 18 08:38:23] DEBUG[5661] config.c: extract uint from [2] in [0, 4294967295] gives [2](0) [May 18 08:38:23] DEBUG[5661] res_pjsip.c: 0x7faf2c014ff8: Wrapper created [May 18 08:38:23] DEBUG[5661] res_pjsip.c: 0x7faf2c014ff8: Set timer to 3000 msec [May 18 08:38:23] DEBUG[5661] res_pjsip_multihomed.c: Re-wrote Contact URI host/port to 104.131.62.231:5080 [May 18 08:38:23] DEBUG[5661] netsock2.c: Splitting '0.0.0.0:5080' into... [May 18 08:38:23] DEBUG[5661] netsock2.c: ...host '0.0.0.0' and port '5080'. [May 18 08:38:23] DEBUG[5661] netsock2.c: Splitting '45.79.0.96:5060' into... [May 18 08:38:23] DEBUG[5661] netsock2.c: ...host '45.79.0.96' and port '5060'. [May 18 08:38:23] VERBOSE[5661] res_pjsip_logger.c: <--- Transmitting SIP request (437 bytes) to UDP:45.79.0.96:5060 ---> OPTIONS sip:sip.voztovoice.eu:5060 SIP/2.0 Via: SIP/2.0/UDP 104.131.62.231:5080;rport;branch=z9hG4bKPj50743f57-c86f-4c78-9bb0-4ff9c03806c7 From: ;tag=f976940b-f0f5-424f-b169-5a8290a388e7 To: Contact: Call-ID: 2589cd4a-0a9f-40ea-98bf-3e7de3a9dc98 CSeq: 47873 OPTIONS Max-Forwards: 70 User-Agent: Curso Asterisk PBX Content-Length: 0 [May 18 08:38:24] VERBOSE[5660] res_pjsip_logger.c: <--- Received SIP response (449 bytes) from UDP:45.79.0.96:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 104.131.62.231:5080;received=104.131.62.231;rport=5080;branch=z9hG4bKPj50743f57-c86f-4c78-9bb0-4ff9c03806c7 From: ;tag=f976940b-f0f5-424f-b169-5a8290a388e7 To: ;tag=35c3bda49c13da092cc089e13e0de35f.61e0 Call-ID: 2589cd4a-0a9f-40ea-98bf-3e7de3a9dc98 CSeq: 47873 OPTIONS Accept: */* Accept-Language: en Server: VozToVoice Proxy Server Content-Length: 0 [May 18 08:38:24] DEBUG[5660] netsock2.c: Splitting '45.79.0.96:5060' into... [May 18 08:38:24] DEBUG[5660] netsock2.c: ...host '45.79.0.96' and port '5060'. [May 18 08:38:24] DEBUG[5660] netsock2.c: Splitting '0.0.0.0:5080' into... [May 18 08:38:24] DEBUG[5660] netsock2.c: ...host '0.0.0.0' and port '5080'. [May 18 08:38:24] DEBUG[5660] res_pjsip/pjsip_distributor.c: No dialog serializer for response (null). Using request transaction as basis [May 18 08:38:24] DEBUG[5660] res_pjsip/pjsip_distributor.c: Found serializer pjsip/default-0000000c on transaction tsx0x7faf2c00ae58 [May 18 08:38:24] DEBUG[5661] res_pjsip.c: 0x7faf2c014ff8: PJSIP tsx response received [May 18 08:38:24] DEBUG[5661] res_pjsip.c: 0x7faf2c014ff8: Cancelling timer [May 18 08:38:24] DEBUG[5661] res_pjsip.c: 0x7faf2c014ff8: Timer cancelled [May 18 08:38:24] DEBUG[5661] config.c: extract uint from [3] in [0, 4294967295] gives [3](0) [May 18 08:38:24] DEBUG[5661] config.c: extract uint from [0] in [0, 4294967295] gives [0](0) [May 18 08:38:24] DEBUG[5661] config.c: extract uint from [2] in [0, 4294967295] gives [2](0) [May 18 08:38:24] DEBUG[5661] res_pjsip.c: 0x7faf2c014ff8: Callbacks executed [May 18 08:38:24] DEBUG[5661] res_pjsip.c: 0x7faf2c014ff8: wrapper destroyed [May 18 08:38:24] DEBUG[5666] res_pjsip/pjsip_configuration.c: Contact voztovoice/sip:sip.voztovoice.eu:5060 status didn't change: Reachable, RTT: 44.492 msec [May 18 08:38:33] DEBUG[5732] threadpool.c: Worker thread idle timeout reached. Dying. [May 18 08:38:33] DEBUG[5639] threadpool.c: Destroying worker thread 18 [May 18 08:38:33] DEBUG[5738] threadpool.c: Worker thread idle timeout reached. Dying. [May 18 08:38:33] DEBUG[5739] threadpool.c: Worker thread idle timeout reached. Dying. [May 18 08:38:33] DEBUG[5740] threadpool.c: Worker thread idle timeout reached. Dying. [May 18 08:38:33] DEBUG[5639] threadpool.c: Destroying worker thread 24 [May 18 08:38:33] DEBUG[5639] threadpool.c: Destroying worker thread 25 [May 18 08:38:33] DEBUG[5639] threadpool.c: Destroying worker thread 26 [May 18 08:38:36] VERBOSE[5660] res_pjsip_logger.c: <--- Received SIP request (856 bytes) from UDP:95.250.29.3:51621 ---> REGISTER sip:sip1.voztovoice.net:5080 SIP/2.0 Via: SIP/2.0/UDP 192.168.1.108:51621;branch=z9hG4bK-524287-1---79b32209e8dfcd4f;rport Max-Forwards: 70 Contact: ;expires=0 To: "1000" From: "1000";tag=22cf657f Call-ID: 79961Yjc1YWQyMGNhZDA3MmZmZTJiMDdlZGRhMzJmNjJkN2U CSeq: 3 REGISTER Allow: SUBSCRIBE, NOTIFY, INVITE, ACK, CANCEL, BYE, REFER, INFO, OPTIONS, MESSAGE User-Agent: X-Lite release 4.9.3 stamp 79961 Authorization: Digest username="1000",realm="asterisk",nonce="1463578693/fb10ef5e4c6809fd3baa7348c91ad749",uri="sip:sip1.voztovoice.net:5080",response="8a569e6833e1200d9ec8c9a3bddd544a",cnonce="2c845a44d2af20fe499f1407d7195166",nc=00000002,qop=auth,algorithm=md5,opaque="5bd48773667d5b9a" Content-Length: 0 [May 18 08:38:36] DEBUG[5660] netsock2.c: Splitting '95.250.29.3:51621' into... [May 18 08:38:36] DEBUG[5660] netsock2.c: ...host '95.250.29.3' and port '51621'. [May 18 08:38:36] DEBUG[5660] netsock2.c: Splitting '0.0.0.0:5080' into... [May 18 08:38:36] DEBUG[5660] netsock2.c: ...host '0.0.0.0' and port '5080'. [May 18 08:38:36] DEBUG[5661] netsock2.c: Splitting '95.250.29.3' into... [May 18 08:38:36] DEBUG[5661] netsock2.c: ...host '95.250.29.3' and port ''. [May 18 08:38:36] DEBUG[5661] res_pjsip_endpoint_identifier_ip.c: Source address 95.250.29.3:51621 does not match identify 'voztovoice' [May 18 08:38:36] DEBUG[5661] res_pjsip_endpoint_identifier_ip.c: '95.250.29.3:51621' did not match any identify section rules [May 18 08:38:36] DEBUG[5661] res_pjsip_endpoint_identifier_user.c: Retrieved endpoint 1000@sip1.voztovoice.net [May 18 08:38:36] DEBUG[5661] res_pjsip_authenticator_digest.c: Calculated nonce 1463578693/fb10ef5e4c6809fd3baa7348c91ad749. Actual nonce is 1463578693/fb10ef5e4c6809fd3baa7348c91ad749 [May 18 08:38:36] DEBUG[5661] netsock2.c: Splitting '104.131.62.231' into... [May 18 08:38:36] DEBUG[5661] netsock2.c: ...host '104.131.62.231' and port ''. [May 18 08:38:36] DEBUG[5661] netsock2.c: Splitting '95.250.29.3' into... [May 18 08:38:36] DEBUG[5661] netsock2.c: ...host '95.250.29.3' and port ''. [May 18 08:38:36] DEBUG[5661] config.c: extract double from [3.0] in [-inf, inf] gives [3.000000](0) [May 18 08:38:36] DEBUG[5661] config.c: extract double from [3.000000] in [-inf, inf] gives [3.000000](0) [May 18 08:38:36] DEBUG[5661] config.c: extract uint from [30] in [0, 86400] gives [30](0) [May 18 08:38:36] VERBOSE[5661] res_pjsip_registrar.c: Removed contact 'sip:1000@95.250.29.3:51621;rinstance=d952013009ce781f' from AOR '1000' due to request [May 18 08:38:36] DEBUG[5661] netsock2.c: Splitting '0.0.0.0:5080' into... [May 18 08:38:36] DEBUG[5661] netsock2.c: ...host '0.0.0.0' and port '5080'. [May 18 08:38:36] DEBUG[5661] netsock2.c: Splitting '95.250.29.3:51621' into... [May 18 08:38:36] DEBUG[5661] netsock2.c: ...host '95.250.29.3' and port '51621'. [May 18 08:38:36] VERBOSE[5661] res_pjsip_logger.c: <--- Transmitting SIP response (435 bytes) to UDP:95.250.29.3:51621 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.1.108:51621;rport=51621;received=95.250.29.3;branch=z9hG4bK-524287-1---79b32209e8dfcd4f Call-ID: 79961Yjc1YWQyMGNhZDA3MmZmZTJiMDdlZGRhMzJmNjJkN2U From: "1000" ;tag=22cf657f To: "1000" ;tag=z9hG4bK-524287-1---79b32209e8dfcd4f CSeq: 3 REGISTER Date: Wed, 18 May 2016 13:38:36 GMT Server: Curso Asterisk PBX Content-Length: 0 [May 18 08:38:36] VERBOSE[5666] res_pjsip/pjsip_configuration.c: Contact 1000/sip:1000@95.250.29.3:51621;rinstance=d952013009ce781f has been deleted [May 18 08:38:36] DEBUG[5639] threadpool.c: Increasing threadpool stasis-core's size by 1 [May 18 08:38:36] VERBOSE[5666] res_pjsip/pjsip_configuration.c: Endpoint 1000@sip1.voztovoice.net is now Unreachable [May 18 08:38:36] DEBUG[5651] devicestate.c: No provider found, checking channel drivers for PJSIP - 1000@sip1.voztovoice.net [May 18 08:38:36] DEBUG[5651] devicestate.c: Changing state for PJSIP/1000@sip1.voztovoice.net - state 5 (Unavailable) [May 18 08:38:36] DEBUG[5718] app_queue.c: Device 'PJSIP/1000@sip1.voztovoice.net' changed to state '5' (Unavailable) but we don't care because they're not a member of any queue. [May 18 08:38:38] VERBOSE[5728] asterisk.c: Remote UNIX connection disconnected [May 18 08:38:46] DEBUG[5683] chan_sip.c: Allocating new SIP dialog for 6b017c43429b3cab47159fe032083957@[::1]:5060 - OPTIONS (No RTP) [May 18 08:38:46] DEBUG[5683] acl.c: For destination '45.79.0.96', our source address is '104.131.62.231'. [May 18 08:38:46] DEBUG[5683] chan_sip.c: Target address 45.79.0.96:5060 is not local, substituting externaddr [May 18 08:38:46] DEBUG[5683] chan_sip.c: Setting AST_TRANSPORT_UDP with address 104.131.62.231:5060 [May 18 08:38:46] DEBUG[5683] chan_sip.c: SIP call-id changed from '6b017c43429b3cab47159fe032083957@[::1]:5060' to '2d0787a629c062785e3adf2108cf565a@104.131.62.231:5060' [May 18 08:38:46] DEBUG[5683] chan_sip.c: Initializing initreq for method OPTIONS - callid 2d0787a629c062785e3adf2108cf565a@104.131.62.231:5060 [May 18 08:38:46] DEBUG[5683] chan_sip.c: Trying to put 'OPTIONS sip' onto UDP socket destined for 45.79.0.96:5060 [May 18 08:38:46] DEBUG[5683] chan_sip.c: = Looking for Call ID: 2d0787a629c062785e3adf2108cf565a@104.131.62.231:5060 (Checking To) --From tag as6091c230 --To-tag 35c3bda49c13da092cc089e13e0de35f.cbaa [May 18 08:38:46] DEBUG[5683] chan_sip.c: Stopping retransmission on '2d0787a629c062785e3adf2108cf565a@104.131.62.231:5060' of Request 102: Match Found [May 18 08:38:46] DEBUG[5683] chan_sip.c: Destroying SIP dialog 2d0787a629c062785e3adf2108cf565a@104.131.62.231:5060 [May 18 08:38:47] DEBUG[5701] res_pjsip_registrar_expire.c: Woke up at 1463578727 Interval: 30 [May 18 08:38:47] DEBUG[5701] res_pjsip_registrar_expire.c: Expiring 0 contacts [May 18 08:38:53] DEBUG[5661] config.c: extract uint from [3] in [0, 4294967295] gives [3](0) [May 18 08:38:53] DEBUG[5661] config.c: extract uint from [0] in [0, 4294967295] gives [0](0) [May 18 08:38:53] DEBUG[5661] config.c: extract uint from [2] in [0, 4294967295] gives [2](0) [May 18 08:38:53] DEBUG[5661] res_pjsip.c: 0x7faf2c00cbf8: Wrapper created [May 18 08:38:53] DEBUG[5661] res_pjsip.c: 0x7faf2c00cbf8: Set timer to 3000 msec [May 18 08:38:53] DEBUG[5661] res_pjsip_multihomed.c: Re-wrote Contact URI host/port to 104.131.62.231:5080 [May 18 08:38:53] DEBUG[5661] netsock2.c: Splitting '0.0.0.0:5080' into... [May 18 08:38:53] DEBUG[5661] netsock2.c: ...host '0.0.0.0' and port '5080'. [May 18 08:38:53] DEBUG[5661] netsock2.c: Splitting '45.79.0.96:5060' into... [May 18 08:38:53] DEBUG[5661] netsock2.c: ...host '45.79.0.96' and port '5060'. [May 18 08:38:53] VERBOSE[5661] res_pjsip_logger.c: <--- Transmitting SIP request (437 bytes) to UDP:45.79.0.96:5060 ---> OPTIONS sip:sip.voztovoice.eu:5060 SIP/2.0 Via: SIP/2.0/UDP 104.131.62.231:5080;rport;branch=z9hG4bKPj0d6ce4dc-cf07-4aff-9ffb-7bf32e37d909 From: ;tag=c7b28baa-29e7-4f29-910f-12aba63e8368 To: Contact: Call-ID: b1124cc6-e452-4541-93ee-62ca8a68c7e7 CSeq: 16359 OPTIONS Max-Forwards: 70 User-Agent: Curso Asterisk PBX Content-Length: 0 [May 18 08:38:54] VERBOSE[5660] res_pjsip_logger.c: <--- Received SIP response (449 bytes) from UDP:45.79.0.96:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 104.131.62.231:5080;received=104.131.62.231;rport=5080;branch=z9hG4bKPj0d6ce4dc-cf07-4aff-9ffb-7bf32e37d909 From: ;tag=c7b28baa-29e7-4f29-910f-12aba63e8368 To: ;tag=35c3bda49c13da092cc089e13e0de35f.c6c9 Call-ID: b1124cc6-e452-4541-93ee-62ca8a68c7e7 CSeq: 16359 OPTIONS Accept: */* Accept-Language: en Server: VozToVoice Proxy Server Content-Length: 0 [May 18 08:38:54] DEBUG[5660] netsock2.c: Splitting '45.79.0.96:5060' into... [May 18 08:38:54] DEBUG[5660] netsock2.c: ...host '45.79.0.96' and port '5060'. [May 18 08:38:54] DEBUG[5660] netsock2.c: Splitting '0.0.0.0:5080' into... [May 18 08:38:54] DEBUG[5660] netsock2.c: ...host '0.0.0.0' and port '5080'. [May 18 08:38:54] DEBUG[5660] res_pjsip/pjsip_distributor.c: No dialog serializer for response (null). Using request transaction as basis [May 18 08:38:54] DEBUG[5660] res_pjsip/pjsip_distributor.c: Found serializer pjsip/default-0000000e on transaction tsx0x7faf2c0109a8 [May 18 08:38:54] DEBUG[5661] res_pjsip.c: 0x7faf2c00cbf8: PJSIP tsx response received [May 18 08:38:54] DEBUG[5661] res_pjsip.c: 0x7faf2c00cbf8: Cancelling timer [May 18 08:38:54] DEBUG[5661] res_pjsip.c: 0x7faf2c00cbf8: Timer cancelled [May 18 08:38:54] DEBUG[5661] config.c: extract uint from [3] in [0, 4294967295] gives [3](0) [May 18 08:38:54] DEBUG[5661] config.c: extract uint from [0] in [0, 4294967295] gives [0](0) [May 18 08:38:54] DEBUG[5661] config.c: extract uint from [2] in [0, 4294967295] gives [2](0) [May 18 08:38:54] DEBUG[5661] res_pjsip.c: 0x7faf2c00cbf8: Callbacks executed [May 18 08:38:54] DEBUG[5661] res_pjsip.c: 0x7faf2c00cbf8: wrapper destroyed [May 18 08:38:54] DEBUG[5666] res_pjsip/pjsip_configuration.c: Contact voztovoice/sip:sip.voztovoice.eu:5060 status didn't change: Reachable, RTT: 44.472 msec [May 18 08:38:56] DEBUG[5741] threadpool.c: Worker thread idle timeout reached. Dying. [May 18 08:38:56] DEBUG[5639] threadpool.c: Destroying worker thread 27 [May 18 08:38:56] VERBOSE[5640] asterisk.c: Remote UNIX connection [May 18 08:39:00] VERBOSE[5744] loader.c: Reloading module 'res_pjsip.so' (Basic SIP resource) [May 18 08:39:00] DEBUG[5661] config.c: Parsing /etc/asterisk/pjsip.conf [May 18 08:39:00] VERBOSE[5661] config.c: Parsing '/etc/asterisk/pjsip.conf': Found [May 18 08:39:00] DEBUG[5661] res_sorcery_config.c: Using bucket size of '3' for objects of type 'auth' from 'pjsip.conf' [May 18 08:39:00] DEBUG[5661] config.c: extract uint from [32] in [0, 4294967295] gives [32](0) [May 18 08:39:00] DEBUG[5661] config.c: extract uint from [32] in [0, 4294967295] gives [32](0) [May 18 08:39:00] DEBUG[5661] config.c: extract uint from [32] in [0, 4294967295] gives [32](0) [May 18 08:39:00] DEBUG[5661] config.c: extract uint from [32] in [0, 4294967295] gives [32](0) [May 18 08:39:00] DEBUG[5661] res_pjsip_config_wizard.c: Config file 'pjsip_wizard.conf' was unchanged for 'auth'. [May 18 08:39:00] DEBUG[5661] config.c: Parsing /etc/asterisk/pjsip.conf [May 18 08:39:00] VERBOSE[5661] config.c: Parsing '/etc/asterisk/pjsip.conf': Found [May 18 08:39:00] DEBUG[5661] res_sorcery_config.c: Using bucket size of '1' for objects of type 'phoneprov' from 'pjsip.conf' [May 18 08:39:00] DEBUG[5661] res_pjsip_config_wizard.c: Config file 'pjsip_wizard.conf' was unchanged for 'phoneprov'. [May 18 08:39:00] DEBUG[5661] config.c: Parsing /etc/asterisk/pjsip.conf [May 18 08:39:00] VERBOSE[5661] config.c: Parsing '/etc/asterisk/pjsip.conf': Found [May 18 08:39:00] DEBUG[5661] res_sorcery_config.c: Using bucket size of '3' for objects of type 'aor' from 'pjsip.conf' [May 18 08:39:00] DEBUG[5661] config.c: extract double from [3.0] in [-inf, inf] gives [3.000000](0) [May 18 08:39:00] DEBUG[5661] config.c: extract uint from [60] in [0, 4294967295] gives [60](0) [May 18 08:39:00] DEBUG[5661] config.c: extract uint from [3600] in [0, 4294967295] gives [3600](0) [May 18 08:39:00] DEBUG[5661] config.c: extract uint from [0] in [0, 4294967295] gives [0](0) [May 18 08:39:00] DEBUG[5661] config.c: extract uint from [7200] in [0, 4294967295] gives [7200](0) [May 18 08:39:00] DEBUG[5661] config.c: extract uint from [1] in [0, 4294967295] gives [1](0) [May 18 08:39:00] DEBUG[5661] config.c: extract uint from [30] in [0, 86400] gives [30](0) [May 18 08:39:00] DEBUG[5661] config.c: extract double from [3.0] in [-inf, inf] gives [3.000000](0) [May 18 08:39:00] DEBUG[5661] config.c: extract uint from [60] in [0, 4294967295] gives [60](0) [May 18 08:39:00] DEBUG[5661] config.c: extract uint from [3600] in [0, 4294967295] gives [3600](0) [May 18 08:39:00] DEBUG[5661] config.c: extract uint from [0] in [0, 4294967295] gives [0](0) [May 18 08:39:00] DEBUG[5661] config.c: extract uint from [7200] in [0, 4294967295] gives [7200](0) [May 18 08:39:00] DEBUG[5661] config.c: extract uint from [1] in [0, 4294967295] gives [1](0) [May 18 08:39:00] DEBUG[5661] config.c: extract uint from [30] in [0, 86400] gives [30](0) [May 18 08:39:00] DEBUG[5661] config.c: extract double from [3.0] in [-inf, inf] gives [3.000000](0) [May 18 08:39:00] DEBUG[5661] config.c: extract uint from [60] in [0, 4294967295] gives [60](0) [May 18 08:39:00] DEBUG[5661] config.c: extract uint from [3600] in [0, 4294967295] gives [3600](0) [May 18 08:39:00] DEBUG[5661] config.c: extract uint from [0] in [0, 4294967295] gives [0](0) [May 18 08:39:00] DEBUG[5661] config.c: extract uint from [7200] in [0, 4294967295] gives [7200](0) [May 18 08:39:00] DEBUG[5661] config.c: extract uint from [1] in [0, 4294967295] gives [1](0) [May 18 08:39:00] DEBUG[5661] config.c: extract uint from [30] in [0, 86400] gives [30](0) [May 18 08:39:00] DEBUG[5661] config.c: extract double from [3.0] in [-inf, inf] gives [3.000000](0) [May 18 08:39:00] DEBUG[5661] config.c: extract uint from [60] in [0, 4294967295] gives [60](0) [May 18 08:39:00] DEBUG[5661] config.c: extract uint from [3600] in [0, 4294967295] gives [3600](0) [May 18 08:39:00] DEBUG[5661] config.c: extract uint from [0] in [0, 4294967295] gives [0](0) [May 18 08:39:00] DEBUG[5661] config.c: extract uint from [7200] in [0, 4294967295] gives [7200](0) [May 18 08:39:00] DEBUG[5661] config.c: extract double from [3.0] in [-inf, inf] gives [3.000000](0) [May 18 08:39:00] DEBUG[5661] res_pjsip_config_wizard.c: Config file 'pjsip_wizard.conf' was unchanged for 'aor'. [May 18 08:39:00] DEBUG[5661] config.c: Parsing /etc/asterisk/pjsip.conf [May 18 08:39:00] VERBOSE[5661] config.c: Parsing '/etc/asterisk/pjsip.conf': Found [May 18 08:39:00] DEBUG[5661] res_sorcery_config.c: Using bucket size of '1' for objects of type 'transport' from 'pjsip.conf' [May 18 08:39:00] DEBUG[5661] config.c: extract uint from [0] in [0, 65535] gives [0](0) [May 18 08:39:00] DEBUG[5661] config.c: extract int from [100] in [1, 2147483647] gives [100](0) [May 18 08:39:00] DEBUG[5661] config.c: extract uint from [1] in [0, 4294967295] gives [1](0) [May 18 08:39:00] DEBUG[5661] config.c: extract uint from [0] in [0, 4294967295] gives [0](0) [May 18 08:39:00] DEBUG[5661] config.c: Parsing /etc/asterisk/pjsip.conf [May 18 08:39:00] VERBOSE[5661] config.c: Parsing '/etc/asterisk/pjsip.conf': Found [May 18 08:39:00] DEBUG[5661] res_sorcery_config.c: Using bucket size of '3' for objects of type 'endpoint' from 'pjsip.conf' [May 18 08:39:00] DEBUG[5661] config.c: extract uint from [0] in [0, 4294967295] gives [0](0) [May 18 08:39:00] DEBUG[5661] config.c: extract uint from [0] in [0, 4294967295] gives [0](0) [May 18 08:39:00] DEBUG[5661] config.c: extract uint from [0] in [0, 4294967295] gives [0](0) [May 18 08:39:00] DEBUG[5661] config.c: extract uint from [0] in [0, 4294967295] gives [0](0) [May 18 08:39:00] DEBUG[5661] config.c: extract uint from [0] in [0, 4294967295] gives [0](0) [May 18 08:39:00] DEBUG[5661] config.c: extract uint from [1800] in [0, 4294967295] gives [1800](0) [May 18 08:39:00] DEBUG[5661] config.c: extract uint from [0] in [0, 4294967295] gives [0](0) [May 18 08:39:00] DEBUG[5661] config.c: extract uint from [0] in [0, 4294967295] gives [0](0) [May 18 08:39:00] DEBUG[5661] config.c: extract uint from [90] in [0, 4294967295] gives [90](0) [May 18 08:39:00] DEBUG[5661] config.c: extract uint from [0] in [0, 4294967295] gives [0](0) [May 18 08:39:00] DEBUG[5661] config.c: extract uint from [0] in [0, 4294967295] gives [0](0) [May 18 08:39:00] DEBUG[5661] config.c: extract uint from [0] in [0, 4294967295] gives [0](0) [May 18 08:39:00] DEBUG[5661] config.c: extract uint from [0] in [0, 4294967295] gives [0](0) [May 18 08:39:00] DEBUG[5661] config.c: extract uint from [0] in [0, 4294967295] gives [0](0) [May 18 08:39:00] DEBUG[5661] config.c: extract uint from [0] in [0, 4294967295] gives [0](0) [May 18 08:39:00] DEBUG[5661] config.c: extract uint from [1800] in [0, 4294967295] gives [1800](0) [May 18 08:39:00] DEBUG[5661] config.c: extract uint from [0] in [0, 4294967295] gives [0](0) [May 18 08:39:00] DEBUG[5661] config.c: extract uint from [0] in [0, 4294967295] gives [0](0) [May 18 08:39:00] DEBUG[5661] config.c: extract uint from [90] in [0, 4294967295] gives [90](0) [May 18 08:39:00] DEBUG[5661] config.c: extract uint from [0] in [0, 4294967295] gives [0](0) [May 18 08:39:00] DEBUG[5661] config.c: extract uint from [0] in [0, 4294967295] gives [0](0) [May 18 08:39:00] DEBUG[5661] config.c: extract uint from [0] in [0, 4294967295] gives [0](0) [May 18 08:39:00] DEBUG[5661] config.c: extract uint from [0] in [0, 4294967295] gives [0](0) [May 18 08:39:00] DEBUG[5661] config.c: extract uint from [0] in [0, 4294967295] gives [0](0) [May 18 08:39:00] DEBUG[5661] config.c: extract uint from [0] in [0, 4294967295] gives [0](0) [May 18 08:39:00] DEBUG[5661] config.c: extract uint from [1800] in [0, 4294967295] gives [1800](0) [May 18 08:39:00] DEBUG[5661] config.c: extract uint from [0] in [0, 4294967295] gives [0](0) [May 18 08:39:00] DEBUG[5661] config.c: extract uint from [0] in [0, 4294967295] gives [0](0) [May 18 08:39:00] DEBUG[5661] config.c: extract uint from [90] in [0, 4294967295] gives [90](0) [May 18 08:39:00] DEBUG[5661] config.c: extract uint from [0] in [0, 4294967295] gives [0](0) [May 18 08:39:00] DEBUG[5661] config.c: extract uint from [0] in [0, 4294967295] gives [0](0) [May 18 08:39:00] DEBUG[5661] config.c: extract uint from [0] in [0, 4294967295] gives [0](0) [May 18 08:39:00] DEBUG[5661] config.c: extract uint from [0] in [0, 4294967295] gives [0](0) [May 18 08:39:00] DEBUG[5661] config.c: extract uint from [0] in [0, 4294967295] gives [0](0) [May 18 08:39:00] DEBUG[5661] config.c: extract uint from [0] in [0, 4294967295] gives [0](0) [May 18 08:39:00] DEBUG[5661] config.c: extract uint from [1800] in [0, 4294967295] gives [1800](0) [May 18 08:39:00] DEBUG[5661] config.c: extract uint from [0] in [0, 4294967295] gives [0](0) [May 18 08:39:00] DEBUG[5661] config.c: extract uint from [0] in [0, 4294967295] gives [0](0) [May 18 08:39:00] DEBUG[5661] config.c: extract uint from [90] in [0, 4294967295] gives [90](0) [May 18 08:39:00] DEBUG[5661] config.c: extract uint from [0] in [0, 4294967295] gives [0](0) [May 18 08:39:00] DEBUG[5661] res_pjsip_config_wizard.c: Config file 'pjsip_wizard.conf' was unchanged for 'endpoint'. [May 18 08:39:00] DEBUG[5661] config.c: Parsing /etc/asterisk/pjsip.conf [May 18 08:39:00] VERBOSE[5661] config.c: Parsing '/etc/asterisk/pjsip.conf': Found [May 18 08:39:00] DEBUG[5661] res_sorcery_config.c: Using bucket size of '1' for objects of type 'acl' from 'pjsip.conf' [May 18 08:39:00] DEBUG[5661] config.c: Parsing /etc/asterisk/pjsip.conf [May 18 08:39:00] VERBOSE[5661] config.c: Parsing '/etc/asterisk/pjsip.conf': Found [May 18 08:39:00] DEBUG[5661] res_sorcery_config.c: Using bucket size of '1' for objects of type 'registration' from 'pjsip.conf' [May 18 08:39:00] DEBUG[5661] config.c: extract uint from [10] in [0, 4294967295] gives [10](0) [May 18 08:39:00] DEBUG[5661] config.c: extract uint from [0] in [0, 4294967295] gives [0](0) [May 18 08:39:00] DEBUG[5661] config.c: extract uint from [60] in [0, 4294967295] gives [60](0) [May 18 08:39:00] DEBUG[5661] config.c: extract uint from [3600] in [0, 4294967295] gives [3600](0) [May 18 08:39:00] DEBUG[5661] config.c: extract uint from [0] in [0, 4294967295] gives [0](0) [May 18 08:39:00] DEBUG[5661] config.c: extract uint from [600] in [0, 4294967295] gives [600](0) [May 18 08:39:00] DEBUG[5661] config.c: extract uint from [10] in [0, 4294967295] gives [10](0) [May 18 08:39:00] DEBUG[5661] config.c: extract uint from [60] in [0, 4294967295] gives [60](0) [May 18 08:39:00] DEBUG[5661] res_pjsip_outbound_registration.c: Applying configuration to outbound registration 'voztovoice' [May 18 08:39:00] DEBUG[5661] res_pjsip_outbound_registration.c: Registration 'voztovoice' didn't change. Can re-use [May 18 08:39:00] DEBUG[5661] res_pjsip_outbound_registration.c: No change between old configuration and new configuration on outbound registration 'voztovoice'. Using previous state [May 18 08:39:00] DEBUG[5661] res_pjsip_config_wizard.c: Config file 'pjsip_wizard.conf' was unchanged for 'registration'. [May 18 08:39:00] DEBUG[5661] config.c: Parsing /etc/asterisk/pjsip.conf [May 18 08:39:00] VERBOSE[5661] config.c: Parsing '/etc/asterisk/pjsip.conf': Found [May 18 08:39:00] DEBUG[5661] res_sorcery_config.c: Using bucket size of '1' for objects of type 'inbound-publication' from 'pjsip.conf' [May 18 08:39:00] DEBUG[5661] config.c: Parsing /etc/asterisk/pjsip.conf [May 18 08:39:00] VERBOSE[5661] config.c: Parsing '/etc/asterisk/pjsip.conf': Found [May 18 08:39:00] DEBUG[5661] res_sorcery_config.c: Using bucket size of '1' for objects of type 'outbound-publish' from 'pjsip.conf' [May 18 08:39:00] NOTICE[5661] sorcery.c: Type 'system' is not reloadable, maintaining previous values [May 18 08:39:00] DEBUG[5661] config.c: Parsing /etc/asterisk/pjsip.conf [May 18 08:39:00] VERBOSE[5661] config.c: Parsing '/etc/asterisk/pjsip.conf': Found [May 18 08:39:00] DEBUG[5661] res_sorcery_config.c: Using bucket size of '1' for objects of type 'global' from 'pjsip.conf' [May 18 08:39:00] DEBUG[5661] config.c: extract uint from [0] in [0, 4294967295] gives [0](0) [May 18 08:39:00] DEBUG[5661] config.c: extract uint from [0] in [0, 4294967295] gives [0](0) [May 18 08:39:00] DEBUG[5661] config.c: extract uint from [30] in [0, 4294967295] gives [30](0) [May 18 08:39:00] DEBUG[5661] config.c: extract uint from [70] in [0, 4294967295] gives [70](0) [May 18 08:39:00] DEBUG[5661] config.c: Parsing /etc/asterisk/pjsip.conf [May 18 08:39:00] VERBOSE[5661] config.c: Parsing '/etc/asterisk/pjsip.conf': Found [May 18 08:39:00] DEBUG[5661] res_sorcery_config.c: Using bucket size of '1' for objects of type 'identify' from 'pjsip.conf' [May 18 08:39:00] DEBUG[5661] netsock2.c: Splitting 'sip.voztovoice.eu' into... [May 18 08:39:00] DEBUG[5661] netsock2.c: ...host 'sip.voztovoice.eu' and port ''. [May 18 08:39:00] DEBUG[5638] threadpool.c: Increasing threadpool Sorcery's size by 1 [May 18 08:39:00] DEBUG[5638] threadpool.c: Increasing threadpool Sorcery's size by 1 [May 18 08:39:00] DEBUG[5638] threadpool.c: Increasing threadpool Sorcery's size by 1 [May 18 08:39:00] DEBUG[5638] threadpool.c: Increasing threadpool Sorcery's size by 1 [May 18 08:39:00] DEBUG[5666] res_pjsip_outbound_registration.c: Auths updated. Checking for any outbound registrations that are in permanent rejected state so they can be retried [May 18 08:39:00] DEBUG[5661] netsock2.c: Splitting '45.79.0.96' into... [May 18 08:39:00] DEBUG[5661] netsock2.c: ...host '45.79.0.96' and port ''. [May 18 08:39:00] DEBUG[5661] acl.c: 45.79.0.96:0/255.255.255.255:0 sense 0 appended to ACL [May 18 08:39:00] DEBUG[5661] res_pjsip_config_wizard.c: Config file 'pjsip_wizard.conf' was unchanged for 'identify'. [May 18 08:39:00] DEBUG[5661] config.c: Parsing /etc/asterisk/pjsip.conf [May 18 08:39:00] VERBOSE[5661] config.c: Parsing '/etc/asterisk/pjsip.conf': Found [May 18 08:39:00] DEBUG[5661] res_sorcery_config.c: Using bucket size of '1' for objects of type 'asterisk-publication' from 'pjsip.conf' [May 18 08:39:00] DEBUG[5661] config.c: Parsing /etc/asterisk/pjsip.conf [May 18 08:39:00] VERBOSE[5661] config.c: Parsing '/etc/asterisk/pjsip.conf': Found [May 18 08:39:00] DEBUG[5661] res_sorcery_config.c: Using bucket size of '1' for objects of type 'resource_list' from 'pjsip.conf' [May 18 08:39:00] DEBUG[5661] config.c: Parsing /etc/asterisk/pjsip.conf [May 18 08:39:00] VERBOSE[5661] config.c: Parsing '/etc/asterisk/pjsip.conf': Found [May 18 08:39:00] DEBUG[5661] res_sorcery_config.c: Using bucket size of '1' for objects of type 'domain_alias' from 'pjsip.conf' [May 18 08:39:00] VERBOSE[5744] loader.c: Reloading module 'res_pjsip_authenticator_digest.so' (PJSIP authentication resource) [May 18 08:39:00] VERBOSE[5744] loader.c: Reloading module 'res_pjsip_endpoint_identifier_ip.so' (PJSIP IP endpoint identifier) [May 18 08:39:00] DEBUG[5744] res_sorcery_config.c: Config file 'pjsip.conf' was unchanged [May 18 08:39:00] DEBUG[5744] res_pjsip_config_wizard.c: Config file 'pjsip_wizard.conf' was unchanged for 'identify'. [May 18 08:39:00] VERBOSE[5744] loader.c: Reloading module 'res_pjsip_mwi.so' (PJSIP MWI resource) [May 18 08:39:00] DEBUG[5744] res_pjsip_mwi.c: Removing stasis subscription to mailbox 1000@default [May 18 08:39:00] DEBUG[5639] threadpool.c: Increasing threadpool stasis-core's size by 1 [May 18 08:39:00] DEBUG[5639] threadpool.c: Increasing threadpool stasis-core's size by 1 [May 18 08:39:00] DEBUG[5744] taskprocessor.c: destroying taskprocessor 'subp:1000@default-0000003e' [May 18 08:39:00] VERBOSE[5744] loader.c: Reloading module 'res_pjsip_notify.so' (CLI/AMI PJSIP NOTIFY Support) [May 18 08:39:00] DEBUG[5744] config_options.c: pjsip_notify.conf was unchanged [May 18 08:39:00] VERBOSE[5744] loader.c: Reloading module 'res_pjsip_outbound_publish.so' (PJSIP Outbound Publish Support) [May 18 08:39:00] DEBUG[5744] res_sorcery_config.c: Config file 'pjsip.conf' was unchanged [May 18 08:39:00] VERBOSE[5744] loader.c: Reloading module 'res_pjsip_publish_asterisk.so' (PJSIP Asterisk Event PUBLISH Support) [May 18 08:39:00] DEBUG[5744] res_sorcery_config.c: Config file 'pjsip.conf' was unchanged [May 18 08:39:00] VERBOSE[5744] loader.c: Reloading module 'res_pjsip_outbound_registration.so' (PJSIP Outbound Registration Support) [May 18 08:39:00] DEBUG[5744] res_sorcery_config.c: Config file 'pjsip.conf' was unchanged [May 18 08:39:00] DEBUG[5744] res_pjsip_config_wizard.c: Config file 'pjsip_wizard.conf' was unchanged for 'registration'. [May 18 08:39:00] DEBUG[5661] res_pjsip_mwi.c: Destroying MWI subscription for endpoint 1000@sip1.voztovoice.net [May 18 08:39:13] DEBUG[5737] threadpool.c: Worker thread idle timeout reached. Dying. [May 18 08:39:13] DEBUG[5659] threadpool.c: Destroying worker thread 23 [May 18 08:39:13] DEBUG[5735] threadpool.c: Worker thread idle timeout reached. Dying. [May 18 08:39:13] DEBUG[5736] threadpool.c: Worker thread idle timeout reached. Dying. [May 18 08:39:13] DEBUG[5659] threadpool.c: Destroying worker thread 21 [May 18 08:39:13] DEBUG[5659] threadpool.c: Destroying worker thread 22 [May 18 08:39:13] DEBUG[5734] threadpool.c: Worker thread idle timeout reached. Dying. [May 18 08:39:13] DEBUG[5659] threadpool.c: Destroying worker thread 20 [May 18 08:39:17] DEBUG[5701] res_pjsip_registrar_expire.c: Woke up at 1463578757 Interval: 30 [May 18 08:39:17] DEBUG[5701] res_pjsip_registrar_expire.c: Expiring 0 contacts [May 18 08:39:20] DEBUG[5749] threadpool.c: Worker thread idle timeout reached. Dying. [May 18 08:39:20] DEBUG[5639] threadpool.c: Destroying worker thread 32 [May 18 08:39:20] DEBUG[5750] threadpool.c: Worker thread idle timeout reached. Dying. [May 18 08:39:20] DEBUG[5639] threadpool.c: Destroying worker thread 33 [May 18 08:39:25] VERBOSE[5660] res_pjsip_logger.c: <--- Received SIP request (571 bytes) from UDP:95.250.29.3:50963 ---> REGISTER sip:sip1.voztovoice.net:5080 SIP/2.0 Via: SIP/2.0/UDP 192.168.1.108:50963;branch=z9hG4bK-524287-1---e1eaa7644c54f371;rport Max-Forwards: 70 Contact: To: "1000" From: "1000";tag=8fd27b3b Call-ID: 79961OGMxMzdlNTE4YzAzNGJjNmI0ZjUyOGY3MDM3OWNiZWI CSeq: 1 REGISTER Expires: 3600 Allow: SUBSCRIBE, NOTIFY, INVITE, ACK, CANCEL, BYE, REFER, INFO, OPTIONS, MESSAGE User-Agent: X-Lite release 4.9.3 stamp 79961 Content-Length: 0 [May 18 08:39:25] DEBUG[5660] netsock2.c: Splitting '95.250.29.3:50963' into... [May 18 08:39:25] DEBUG[5660] netsock2.c: ...host '95.250.29.3' and port '50963'. [May 18 08:39:25] DEBUG[5660] netsock2.c: Splitting '0.0.0.0:5080' into... [May 18 08:39:25] DEBUG[5660] netsock2.c: ...host '0.0.0.0' and port '5080'. [May 18 08:39:25] DEBUG[5661] netsock2.c: Splitting '95.250.29.3' into... [May 18 08:39:25] DEBUG[5661] netsock2.c: ...host '95.250.29.3' and port ''. [May 18 08:39:25] DEBUG[5661] res_pjsip_endpoint_identifier_ip.c: Source address 95.250.29.3:50963 does not match identify 'voztovoice' [May 18 08:39:25] DEBUG[5661] res_pjsip_endpoint_identifier_ip.c: '95.250.29.3:50963' did not match any identify section rules [May 18 08:39:25] DEBUG[5661] res_pjsip_endpoint_identifier_user.c: Retrieved endpoint 1000@sip1.voztovoice.net [May 18 08:39:25] DEBUG[5661] netsock2.c: Splitting '104.131.62.231' into... [May 18 08:39:25] DEBUG[5661] netsock2.c: ...host '104.131.62.231' and port ''. [May 18 08:39:25] DEBUG[5661] netsock2.c: Splitting '95.250.29.3' into... [May 18 08:39:25] DEBUG[5661] netsock2.c: ...host '95.250.29.3' and port ''. [May 18 08:39:25] DEBUG[5661] netsock2.c: Splitting '0.0.0.0:5080' into... [May 18 08:39:25] DEBUG[5661] netsock2.c: ...host '0.0.0.0' and port '5080'. [May 18 08:39:25] DEBUG[5661] netsock2.c: Splitting '95.250.29.3:50963' into... [May 18 08:39:25] DEBUG[5661] netsock2.c: ...host '95.250.29.3' and port '50963'. [May 18 08:39:25] VERBOSE[5661] res_pjsip_logger.c: <--- Transmitting SIP response (555 bytes) to UDP:95.250.29.3:50963 ---> SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 192.168.1.108:50963;rport=50963;received=95.250.29.3;branch=z9hG4bK-524287-1---e1eaa7644c54f371 Call-ID: 79961OGMxMzdlNTE4YzAzNGJjNmI0ZjUyOGY3MDM3OWNiZWI From: "1000" ;tag=8fd27b3b To: "1000" ;tag=z9hG4bK-524287-1---e1eaa7644c54f371 CSeq: 1 REGISTER WWW-Authenticate: Digest realm="asterisk",nonce="1463578765/0d45bccb564213b9af790ab607fa140a",opaque="58bb2d255226070e",algorithm=md5,qop="auth" Server: Curso Asterisk PBX Content-Length: 0 [May 18 08:39:25] VERBOSE[5660] res_pjsip_logger.c: <--- Received SIP request (861 bytes) from UDP:95.250.29.3:50963 ---> REGISTER sip:sip1.voztovoice.net:5080 SIP/2.0 Via: SIP/2.0/UDP 192.168.1.108:50963;branch=z9hG4bK-524287-1---a220c479b915fd51;rport Max-Forwards: 70 Contact: To: "1000" From: "1000";tag=8fd27b3b Call-ID: 79961OGMxMzdlNTE4YzAzNGJjNmI0ZjUyOGY3MDM3OWNiZWI CSeq: 2 REGISTER Expires: 3600 Allow: SUBSCRIBE, NOTIFY, INVITE, ACK, CANCEL, BYE, REFER, INFO, OPTIONS, MESSAGE User-Agent: X-Lite release 4.9.3 stamp 79961 Authorization: Digest username="1000",realm="asterisk",nonce="1463578765/0d45bccb564213b9af790ab607fa140a",uri="sip:sip1.voztovoice.net:5080",response="1f8ae885e04e8076d25abc0238c96237",cnonce="b6b9f44a0f105d2ea6feba252f64d783",nc=00000001,qop=auth,algorithm=md5,opaque="58bb2d255226070e" Content-Length: 0 [May 18 08:39:25] DEBUG[5660] netsock2.c: Splitting '95.250.29.3:50963' into... [May 18 08:39:25] DEBUG[5660] netsock2.c: ...host '95.250.29.3' and port '50963'. [May 18 08:39:25] DEBUG[5660] netsock2.c: Splitting '0.0.0.0:5080' into... [May 18 08:39:25] DEBUG[5660] netsock2.c: ...host '0.0.0.0' and port '5080'. [May 18 08:39:25] DEBUG[5661] netsock2.c: Splitting '95.250.29.3' into... [May 18 08:39:25] DEBUG[5661] netsock2.c: ...host '95.250.29.3' and port ''. [May 18 08:39:25] DEBUG[5661] res_pjsip_endpoint_identifier_ip.c: Source address 95.250.29.3:50963 does not match identify 'voztovoice' [May 18 08:39:25] DEBUG[5661] res_pjsip_endpoint_identifier_ip.c: '95.250.29.3:50963' did not match any identify section rules [May 18 08:39:25] DEBUG[5661] res_pjsip_endpoint_identifier_user.c: Retrieved endpoint 1000@sip1.voztovoice.net [May 18 08:39:25] DEBUG[5661] res_pjsip_authenticator_digest.c: Calculated nonce 1463578765/0d45bccb564213b9af790ab607fa140a. Actual nonce is 1463578765/0d45bccb564213b9af790ab607fa140a [May 18 08:39:25] DEBUG[5661] netsock2.c: Splitting '104.131.62.231' into... [May 18 08:39:25] DEBUG[5661] netsock2.c: ...host '104.131.62.231' and port ''. [May 18 08:39:25] DEBUG[5661] netsock2.c: Splitting '95.250.29.3' into... [May 18 08:39:25] DEBUG[5661] netsock2.c: ...host '95.250.29.3' and port ''. [May 18 08:39:25] DEBUG[5661] config.c: extract double from [3.0] in [-inf, inf] gives [3.000000](0) [May 18 08:39:25] VERBOSE[5661] res_pjsip_registrar.c: Added contact 'sip:1000@95.250.29.3:50963;rinstance=263cb96fbd9d0789' to AOR '1000' with expiration of 3600 seconds [May 18 08:39:25] DEBUG[5661] config.c: extract double from [3.0] in [-inf, inf] gives [3.000000](0) [May 18 08:39:25] DEBUG[5661] config.c: extract double from [3.000000] in [-inf, inf] gives [3.000000](0) [May 18 08:39:25] DEBUG[5661] config.c: extract uint from [30] in [0, 86400] gives [30](0) [May 18 08:39:25] DEBUG[5661] config.c: extract uint from [3] in [0, 4294967295] gives [3](0) [May 18 08:39:25] DEBUG[5661] config.c: extract uint from [0] in [0, 4294967295] gives [0](0) [May 18 08:39:25] DEBUG[5661] config.c: extract uint from [2] in [0, 4294967295] gives [2](0) [May 18 08:39:25] DEBUG[5661] netsock2.c: Splitting '0.0.0.0:5080' into... [May 18 08:39:25] DEBUG[5661] netsock2.c: ...host '0.0.0.0' and port '5080'. [May 18 08:39:25] DEBUG[5661] netsock2.c: Splitting '95.250.29.3:50963' into... [May 18 08:39:25] DEBUG[5661] netsock2.c: ...host '95.250.29.3' and port '50963'. [May 18 08:39:25] VERBOSE[5661] res_pjsip_logger.c: <--- Transmitting SIP response (529 bytes) to UDP:95.250.29.3:50963 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.1.108:50963;rport=50963;received=95.250.29.3;branch=z9hG4bK-524287-1---a220c479b915fd51 Call-ID: 79961OGMxMzdlNTE4YzAzNGJjNmI0ZjUyOGY3MDM3OWNiZWI From: "1000" ;tag=8fd27b3b To: "1000" ;tag=z9hG4bK-524287-1---a220c479b915fd51 CSeq: 2 REGISTER Date: Wed, 18 May 2016 13:39:25 GMT Contact: ;expires=3599 Expires: 3600 Server: Curso Asterisk PBX Content-Length: 0 [May 18 08:39:25] DEBUG[5666] config.c: extract uint from [3] in [0, 4294967295] gives [3](0) [May 18 08:39:25] DEBUG[5666] config.c: extract uint from [0] in [0, 4294967295] gives [0](0) [May 18 08:39:25] DEBUG[5666] config.c: extract uint from [2] in [0, 4294967295] gives [2](0) [May 18 08:39:25] VERBOSE[5666] res_pjsip/pjsip_configuration.c: Contact 1000/sip:1000@95.250.29.3:50963;rinstance=263cb96fbd9d0789 has been created [May 18 08:39:25] DEBUG[5639] threadpool.c: Increasing threadpool stasis-core's size by 1 [May 18 08:39:25] DEBUG[5666] config.c: extract double from [3.0] in [-inf, inf] gives [3.000000](0) [May 18 08:39:25] DEBUG[5666] config.c: extract double from [3.000000] in [-inf, inf] gives [3.000000](0) [May 18 08:39:25] DEBUG[5666] config.c: extract uint from [30] in [0, 86400] gives [30](0) [May 18 08:39:25] VERBOSE[5666] res_pjsip/pjsip_configuration.c: Endpoint 1000@sip1.voztovoice.net is now Reachable [May 18 08:39:25] DEBUG[5666] config.c: extract double from [3.0] in [-inf, inf] gives [3.000000](0) [May 18 08:39:25] DEBUG[5666] config.c: extract double from [3.000000] in [-inf, inf] gives [3.000000](0) [May 18 08:39:25] DEBUG[5666] config.c: extract uint from [30] in [0, 86400] gives [30](0) [May 18 08:39:25] DEBUG[5666] res_pjsip_mwi.c: Created unsolicited MWI subscription for endpoint 1000@sip1.voztovoice.net [May 18 08:39:25] DEBUG[5666] res_pjsip_mwi.c: Creating stasis MWI subscription to mailbox 1000@default for endpoint 1000@sip1.voztovoice.net [May 18 08:39:25] DEBUG[5651] devicestate.c: No provider found, checking channel drivers for PJSIP - 1000@sip1.voztovoice.net [May 18 08:39:25] DEBUG[5651] devicestate.c: Changing state for PJSIP/1000@sip1.voztovoice.net - state 1 (Not in use) [May 18 08:39:25] DEBUG[5718] app_queue.c: Device 'PJSIP/1000@sip1.voztovoice.net' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [May 18 08:39:25] ERROR[5661] res_pjsip.c: Unable to create outbound OPTIONS request to endpoint 1000@sip1.voztovoice.net [May 18 08:39:25] ERROR[5661] res_pjsip/pjsip_options.c: Unable to create request to qualify contact sip:1000@95.250.29.3:50963;rinstance=263cb96fbd9d0789 [May 18 08:39:25] DEBUG[5661] res_pjsip_mwi.c: Sending unsolicited MWI NOTIFY to endpoint 1000@sip1.voztovoice.net, new messages: 0, old messages: 0 [May 18 08:39:25] DEBUG[5661] config.c: extract double from [3.0] in [-inf, inf] gives [3.000000](0) [May 18 08:39:25] DEBUG[5661] config.c: extract double from [3.000000] in [-inf, inf] gives [3.000000](0) [May 18 08:39:25] DEBUG[5661] config.c: extract uint from [30] in [0, 86400] gives [30](0) [May 18 08:39:25] ERROR[5661] res_pjsip.c: Unable to create outbound NOTIFY request to endpoint 1000@sip1.voztovoice.net [May 18 08:39:25] WARNING[5661] res_pjsip_mwi.c: Unable to create unsolicited NOTIFY request to endpoint 1000@sip1.voztovoice.net URI sip:1000@95.250.29.3:50963;rinstance=263cb96fbd9d0789 [May 18 08:39:25] DEBUG[5639] threadpool.c: Increasing threadpool stasis-core's size by 1 [May 18 08:39:25] DEBUG[5639] threadpool.c: Increasing threadpool stasis-core's size by 1 [May 18 08:39:27] VERBOSE[5660] res_pjsip_logger.c: <--- Received SIP request (637 bytes) from UDP:95.250.29.3:50963 ---> SUBSCRIBE sip:1000@sip1.voztovoice.net:5080 SIP/2.0 Via: SIP/2.0/UDP 192.168.1.108:50963;branch=z9hG4bK-524287-1---92334a24620e7347;rport Max-Forwards: 70 Contact: To: From: "1000";tag=6038c67f Call-ID: 79961ZTUwZjhkMjk3N2VhYWRjYzc4NmE5OTI5NmY2MTZlNjU CSeq: 1 SUBSCRIBE Expires: 300 Accept: application/simple-message-summary Allow: SUBSCRIBE, NOTIFY, INVITE, ACK, CANCEL, BYE, REFER, INFO, OPTIONS, MESSAGE User-Agent: X-Lite release 4.9.3 stamp 79961 Event: message-summary Content-Length: 0 [May 18 08:39:27] DEBUG[5660] netsock2.c: Splitting '95.250.29.3:50963' into... [May 18 08:39:27] DEBUG[5660] netsock2.c: ...host '95.250.29.3' and port '50963'. [May 18 08:39:27] DEBUG[5660] netsock2.c: Splitting '0.0.0.0:5080' into... [May 18 08:39:27] DEBUG[5660] netsock2.c: ...host '0.0.0.0' and port '5080'. [May 18 08:39:27] DEBUG[5661] netsock2.c: Splitting '95.250.29.3' into... [May 18 08:39:27] DEBUG[5661] netsock2.c: ...host '95.250.29.3' and port ''. [May 18 08:39:27] DEBUG[5661] res_pjsip_endpoint_identifier_ip.c: Source address 95.250.29.3:50963 does not match identify 'voztovoice' [May 18 08:39:27] DEBUG[5661] res_pjsip_endpoint_identifier_ip.c: '95.250.29.3:50963' did not match any identify section rules [May 18 08:39:27] DEBUG[5661] res_pjsip_endpoint_identifier_user.c: Retrieved endpoint 1000@sip1.voztovoice.net [May 18 08:39:27] DEBUG[5661] netsock2.c: Splitting '104.131.62.231' into... [May 18 08:39:27] DEBUG[5661] netsock2.c: ...host '104.131.62.231' and port ''. [May 18 08:39:27] DEBUG[5661] netsock2.c: Splitting '95.250.29.3' into... [May 18 08:39:27] DEBUG[5661] netsock2.c: ...host '95.250.29.3' and port ''. [May 18 08:39:27] DEBUG[5661] netsock2.c: Splitting '0.0.0.0:5080' into... [May 18 08:39:27] DEBUG[5661] netsock2.c: ...host '0.0.0.0' and port '5080'. [May 18 08:39:27] DEBUG[5661] netsock2.c: Splitting '95.250.29.3:50963' into... [May 18 08:39:27] DEBUG[5661] netsock2.c: ...host '95.250.29.3' and port '50963'. [May 18 08:39:27] VERBOSE[5661] res_pjsip_logger.c: <--- Transmitting SIP response (549 bytes) to UDP:95.250.29.3:50963 ---> SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 192.168.1.108:50963;rport=50963;received=95.250.29.3;branch=z9hG4bK-524287-1---92334a24620e7347 Call-ID: 79961ZTUwZjhkMjk3N2VhYWRjYzc4NmE5OTI5NmY2MTZlNjU From: "1000" ;tag=6038c67f To: ;tag=z9hG4bK-524287-1---92334a24620e7347 CSeq: 1 SUBSCRIBE WWW-Authenticate: Digest realm="asterisk",nonce="1463578767/6c051626ab1bb59902ea87d0c24af72d",opaque="7e2599f949c0ab4e",algorithm=md5,qop="auth" Server: Curso Asterisk PBX Content-Length: 0 [May 18 08:39:28] VERBOSE[5660] res_pjsip_logger.c: <--- Received SIP request (932 bytes) from UDP:95.250.29.3:50963 ---> SUBSCRIBE sip:1000@sip1.voztovoice.net:5080 SIP/2.0 Via: SIP/2.0/UDP 192.168.1.108:50963;branch=z9hG4bK-524287-1---31f10b33ee329575;rport Max-Forwards: 70 Contact: To: From: "1000";tag=6038c67f Call-ID: 79961ZTUwZjhkMjk3N2VhYWRjYzc4NmE5OTI5NmY2MTZlNjU CSeq: 2 SUBSCRIBE Expires: 300 Accept: application/simple-message-summary Allow: SUBSCRIBE, NOTIFY, INVITE, ACK, CANCEL, BYE, REFER, INFO, OPTIONS, MESSAGE User-Agent: X-Lite release 4.9.3 stamp 79961 Authorization: Digest username="1000",realm="asterisk",nonce="1463578767/6c051626ab1bb59902ea87d0c24af72d",uri="sip:1000@sip1.voztovoice.net:5080",response="d75d4e6184e19cce4e5ab297655cb538",cnonce="6cce7c51b688b7fb817693469c4dddf5",nc=00000001,qop=auth,algorithm=md5,opaque="7e2599f949c0ab4e" Event: message-summary Content-Length: 0 [May 18 08:39:28] DEBUG[5660] netsock2.c: Splitting '95.250.29.3:50963' into... [May 18 08:39:28] DEBUG[5660] netsock2.c: ...host '95.250.29.3' and port '50963'. [May 18 08:39:28] DEBUG[5660] netsock2.c: Splitting '0.0.0.0:5080' into... [May 18 08:39:28] DEBUG[5660] netsock2.c: ...host '0.0.0.0' and port '5080'. [May 18 08:39:28] DEBUG[5661] netsock2.c: Splitting '95.250.29.3' into... [May 18 08:39:28] DEBUG[5661] netsock2.c: ...host '95.250.29.3' and port ''. [May 18 08:39:28] DEBUG[5661] res_pjsip_endpoint_identifier_ip.c: Source address 95.250.29.3:50963 does not match identify 'voztovoice' [May 18 08:39:28] DEBUG[5661] res_pjsip_endpoint_identifier_ip.c: '95.250.29.3:50963' did not match any identify section rules [May 18 08:39:28] DEBUG[5661] res_pjsip_endpoint_identifier_user.c: Retrieved endpoint 1000@sip1.voztovoice.net [May 18 08:39:28] DEBUG[5661] res_pjsip_authenticator_digest.c: Calculated nonce 1463578767/6c051626ab1bb59902ea87d0c24af72d. Actual nonce is 1463578767/6c051626ab1bb59902ea87d0c24af72d [May 18 08:39:28] DEBUG[5661] netsock2.c: Splitting '104.131.62.231' into... [May 18 08:39:28] DEBUG[5661] netsock2.c: ...host '104.131.62.231' and port ''. [May 18 08:39:28] DEBUG[5661] netsock2.c: Splitting '95.250.29.3' into... [May 18 08:39:28] DEBUG[5661] netsock2.c: ...host '95.250.29.3' and port ''. [May 18 08:39:28] DEBUG[5661] res_pjsip_pubsub.c: Body generator 0x7faef617a120 found for accept type application/simple-message-summary [May 18 08:39:28] DEBUG[5661] res_pjsip_pubsub.c: Subscription to resource 1000 is not to a list [May 18 08:39:28] DEBUG[5661] res_pjsip_mwi.c: AOR 1000 has no configured mailboxes. MWI subscription failed. [May 18 08:39:28] DEBUG[5661] netsock2.c: Splitting '0.0.0.0:5080' into... [May 18 08:39:28] DEBUG[5661] netsock2.c: ...host '0.0.0.0' and port '5080'. [May 18 08:39:28] DEBUG[5661] netsock2.c: Splitting '95.250.29.3:50963' into... [May 18 08:39:28] DEBUG[5661] netsock2.c: ...host '95.250.29.3' and port '50963'. [May 18 08:39:28] VERBOSE[5661] res_pjsip_logger.c: <--- Transmitting SIP response (399 bytes) to UDP:95.250.29.3:50963 ---> SIP/2.0 404 Not Found Via: SIP/2.0/UDP 192.168.1.108:50963;rport=50963;received=95.250.29.3;branch=z9hG4bK-524287-1---31f10b33ee329575 Call-ID: 79961ZTUwZjhkMjk3N2VhYWRjYzc4NmE5OTI5NmY2MTZlNjU From: "1000" ;tag=6038c67f To: ;tag=z9hG4bK-524287-1---31f10b33ee329575 CSeq: 2 SUBSCRIBE Server: Curso Asterisk PBX Content-Length: 0 [May 18 08:39:50] VERBOSE[5744] asterisk.c: Remote UNIX connection disconnected [May 18 08:39:55] ERROR[5661] res_pjsip.c: Unable to create outbound OPTIONS request to endpoint 1000@sip1.voztovoice.net [May 18 08:39:55] ERROR[5661] res_pjsip/pjsip_options.c: Unable to create request to qualify contact sip:1000@95.250.29.3:50963;rinstance=263cb96fbd9d0789 [May 18 08:40:25] ERROR[5661] res_pjsip.c: Unable to create outbound OPTIONS request to endpoint 1000@sip1.voztovoice.net [May 18 08:40:25] ERROR[5661] res_pjsip/pjsip_options.c: Unable to create request to qualify contact sip:1000@95.250.29.3:50963;rinstance=263cb96fbd9d0789 [May 18 08:40:55] ERROR[5661] res_pjsip.c: Unable to create outbound OPTIONS request to endpoint 1000@sip1.voztovoice.net [May 18 08:40:55] ERROR[5661] res_pjsip/pjsip_options.c: Unable to create request to qualify contact sip:1000@95.250.29.3:50963;rinstance=263cb96fbd9d0789 [May 18 08:41:25] ERROR[5661] res_pjsip.c: Unable to create outbound OPTIONS request to endpoint 1000@sip1.voztovoice.net [May 18 08:41:25] ERROR[5661] res_pjsip/pjsip_options.c: Unable to create request to qualify contact sip:1000@95.250.29.3:50963;rinstance=263cb96fbd9d0789 [May 18 08:41:55] ERROR[5661] res_pjsip.c: Unable to create outbound OPTIONS request to endpoint 1000@sip1.voztovoice.net [May 18 08:41:55] ERROR[5661] res_pjsip/pjsip_options.c: Unable to create request to qualify contact sip:1000@95.250.29.3:50963;rinstance=263cb96fbd9d0789 [May 18 08:42:25] ERROR[5661] res_pjsip.c: Unable to create outbound OPTIONS request to endpoint 1000@sip1.voztovoice.net [May 18 08:42:25] ERROR[5661] res_pjsip/pjsip_options.c: Unable to create request to qualify contact sip:1000@95.250.29.3:50963;rinstance=263cb96fbd9d0789 [May 18 08:42:55] ERROR[5661] res_pjsip.c: Unable to create outbound OPTIONS request to endpoint 1000@sip1.voztovoice.net [May 18 08:42:55] ERROR[5661] res_pjsip/pjsip_options.c: Unable to create request to qualify contact sip:1000@95.250.29.3:50963;rinstance=263cb96fbd9d0789 ParameterName : ParameterValue ========================================================= 100rel : yes accountcode : 1000 aggregate_mwi : true allow : (ulaw|g722) allow_subscribe : true allow_transfer : true aors : 1000 auth : aut1000 bind_rtp_to_media_address : false call_group : 1 callerid : "Fulano" <1000> callerid_privacy : allowed_not_screened callerid_tag : connected_line_method : invite context : externas-pjsip cos_audio : 0 cos_video : 0 device_state_busy_at : 0 direct_media : false direct_media_glare_mitigation : none direct_media_method : invite disable_direct_media_on_nat : false dtls_ca_file : dtls_ca_path : dtls_cert_file : dtls_cipher : dtls_fingerprint : SHA-256 dtls_private_key : dtls_rekey : 0 dtls_setup : active dtls_verify : No dtmf_mode : rfc4733 fax_detect : false force_avp : false force_rport : true from_domain : from_user : g726_non_standard : false ice_support : false identify_by : username inband_progress : false language : es mailboxes : 1000@default media_address : media_encryption : no media_encryption_optimistic : false media_use_received_transport : false message_context : moh_suggest : default mwi_from_user : mwi_subscribe_replaces_unsolicited : false named_call_group : named_pickup_group : one_touch_recording : false outbound_auth : outbound_proxy : pickup_group : 1 record_off_feature : automixmon record_on_feature : automixmon rewrite_contact : true rpid_immediate : false rtp_engine : asterisk rtp_ipv6 : false rtp_keepalive : 0 rtp_symmetric : true rtp_timeout : 0 rtp_timeout_hold : 0 sdp_owner : - sdp_session : Asterisk send_diversion : true send_pai : false send_rpid : false set_var : srtp_tag_32 : false sub_min_expiry : 0 t38_udptl : false t38_udptl_ec : none t38_udptl_ipv6 : false t38_udptl_maxdatagram : 0 t38_udptl_nat : false timers : yes timers_min_se : 90 timers_sess_expires : 1800 tone_zone : tos_audio : 0 tos_video : 0 transport : no-nat trust_id_inbound : false trust_id_outbound : false use_avpf : false use_ptime : false user_eq_phone : false voicemail_extension : [1000@sip1.voztovoice.net] type=endpoint context=externas-pjsip disallow=all allow=ulaw,g722 accountcode=1000 language=es mailboxes=1000@default dtmf_mode=rfc4733 callerid=Fulano <1000> direct_media=no force_rport=yes rtp_symmetric=yes rewrite_contact=yes call_group=1 pickup_group=1 transport=no-nat auth=aut1000 aors=1000 [aut1000] type=auth auth_type=userpass password=secret username=1000 [1000] type=aor max_contacts=1 remove_existing=yes qualify_frequency=30