[Apr 13 20:35:00] DEBUG[91101] res_pjsip_outbound_registration.c: Outbound REGISTER attempt 1 to 'sip:phone.provider.example' with client 'sip:+12345678@phone.provider.example' [Apr 13 20:35:00] DEBUG[91101] res_pjsip/pjsip_resolver.c: Performing SIP DNS resolution of target 'phone.provider.example' [Apr 13 20:35:00] DEBUG[91101] res_pjsip/pjsip_resolver.c: Transport type for target 'phone.provider.example' is 'UDP' [Apr 13 20:35:00] DEBUG[91101] res_pjsip/pjsip_resolver.c: [0x7fc6e00039d8] Created resolution tracking for target 'phone.provider.example' [Apr 13 20:35:00] DEBUG[91101] res_pjsip/pjsip_resolver.c: [0x7fc6e00039d8] Added target 'phone.provider.example' with record type '35', transport 'UDP', and port '5060' [Apr 13 20:35:00] DEBUG[91101] res_pjsip/pjsip_resolver.c: [0x7fc6e00039d8] Added target '_sip._udp.phone.provider.example' with record type '33', transport 'UDP', and port '5060' [Apr 13 20:35:00] DEBUG[91101] res_pjsip/pjsip_resolver.c: [0x7fc6e00039d8] Added target 'phone.provider.example' with record type '1', transport 'UDP', and port '5060' [Apr 13 20:35:00] DEBUG[91101] res_pjsip/pjsip_resolver.c: [0x7fc6e00039d8] Starting initial resolution using parallel queries for target 'phone.provider.example' [Apr 13 20:35:00] DEBUG[89396] res_pjsip/pjsip_resolver.c: [0x7fc6e00039d8] All parallel queries completed [Apr 13 20:35:00] DEBUG[89396] res_pjsip/pjsip_resolver.c: [0x7fc6e00039d8] NAPTR record received on target 'phone.provider.example' [Apr 13 20:35:00] DEBUG[89396] res_pjsip/pjsip_resolver.c: [0x7fc6e00039d8] Added target '_sip._udp.phone.provider.example' with record type '33', transport 'UDP', and port '5060' [Apr 13 20:35:00] DEBUG[89396] res_pjsip/pjsip_resolver.c: [0x7fc6e00039d8] NAPTR record received on target 'phone.provider.example' [Apr 13 20:35:00] DEBUG[89396] res_pjsip/pjsip_resolver.c: [0x7fc6e00039d8] NAPTR record skipped because order '60' does not match strict order '50' [Apr 13 20:35:00] DEBUG[89396] res_pjsip/pjsip_resolver.c: [0x7fc6e00039d8] SRV record being skipped on target '_sip._udp.phone.provider.example' because NAPTR record exists [Apr 13 20:35:00] DEBUG[89396] res_pjsip/pjsip_resolver.c: [0x7fc6e00039d8] SRV record being skipped on target '_sip._udp.phone.provider.example' because NAPTR record exists [Apr 13 20:35:00] DEBUG[89396] res_pjsip/pjsip_resolver.c: [0x7fc6e00039d8] A record being skipped on target 'phone.provider.example' because NAPTR or SRV record exists [Apr 13 20:35:00] DEBUG[89396] res_pjsip/pjsip_resolver.c: [0x7fc6e00039d8] New queries added, performing parallel resolution again [Apr 13 20:35:00] DEBUG[89396] res_pjsip/pjsip_resolver.c: [0x7fc6e00039d8] All parallel queries completed [Apr 13 20:35:00] DEBUG[89396] res_pjsip/pjsip_resolver.c: [0x7fc6e00039d8] SRV record received on target '_sip._udp.phone.provider.example' [Apr 13 20:35:00] DEBUG[89396] res_pjsip/pjsip_resolver.c: [0x7fc6e00039d8] Added target 'phone-a.provider.example' with record type '28', transport 'UDP', and port '5060' [Apr 13 20:35:00] DEBUG[89396] res_pjsip/pjsip_resolver.c: [0x7fc6e00039d8] SRV record received on target '_sip._udp.phone.provider.example' [Apr 13 20:35:00] DEBUG[89396] res_pjsip/pjsip_resolver.c: [0x7fc6e00039d8] Added target 'phone-b.provider.example' with record type '28', transport 'UDP', and port '5060' [Apr 13 20:35:00] DEBUG[89396] res_pjsip/pjsip_resolver.c: [0x7fc6e00039d8] New queries added, performing parallel resolution again [Apr 13 20:35:00] DEBUG[89396] res_pjsip/pjsip_resolver.c: [0x7fc6e00039d8] All parallel queries completed [Apr 13 20:35:00] DEBUG[89396] res_pjsip/pjsip_resolver.c: [0x7fc6e00039d8] AAAA record received on target 'phone-a.provider.example' [Apr 13 20:35:00] DEBUG[89396] res_pjsip/pjsip_resolver.c: [0x7fc6e00039d8] AAAA record received on target 'phone-b.provider.example' [Apr 13 20:35:00] DEBUG[89396] res_pjsip/pjsip_resolver.c: [0x7fc6e00039d8] Resolution completed - 2 viable targets [Apr 13 20:35:00] DEBUG[91101] res_pjsip/pjsip_resolver.c: [0x7fc6e00039d8] Address '0' is [XXXX:8::10]:5060 with transport 'UDP' [Apr 13 20:35:00] DEBUG[91101] res_pjsip/pjsip_resolver.c: [0x7fc6e00039d8] Address '1' is [XXXX:7::10]:5060 with transport 'UDP' [Apr 13 20:35:00] DEBUG[91101] res_pjsip/pjsip_resolver.c: [0x7fc6e00039d8] Invoking user callback with '2' addresses [Apr 13 20:35:00] DEBUG[91101] res_pjsip/pjsip_message_filter.c: Re-wrote Contact URI host/port to YYYY::1:5060 (this may be re-written again later) [Apr 13 20:35:00] VERBOSE[91101] res_pjsip_logger.c: <--- Transmitting SIP request (616 bytes) to UDP:[XXXX:8::10]:5060 ---> REGISTER sip:phone.provider.example SIP/2.0 Via: SIP/2.0/UDP [YYYY::1]:5060;rport;branch=z9hG4bKPj4082ef4d-927a-4c93-ac29-0b1ccd40f49f From: ;tag=f6a935a7-8a32-4bb9-8569-97898cf92479 To: Call-ID: bf11d197-8a76-465e-b2a0-3010fd051cd2 CSeq: 52839 REGISTER Contact: Expires: 1200 Allow: OPTIONS, REGISTER, SUBSCRIBE, NOTIFY, PUBLISH, INVITE, ACK, BYE, CANCEL, UPDATE, PRACK, MESSAGE, REFER Max-Forwards: 70 User-Agent: Asterisk PBX 17.3.0 Content-Length: 0 [Apr 13 20:35:00] VERBOSE[89409] res_pjsip_logger.c: <--- Received SIP response (541 bytes) from UDP:[XXXX:8::10]:5060 ---> SIP/2.0 401 Unauthorized Call-ID: bf11d197-8a76-465e-b2a0-3010fd051cd2 CSeq: 52839 REGISTER From: ;tag=f6a935a7-8a32-4bb9-8569-97898cf92479 To: ;tag=sip+6+bb5000d+d9a4864 Via: SIP/2.0/UDP [ZZZZ::1]:5060;received=ZZZZ::1;rport=5060;branch=z9hG4bKPj4082ef4d-927a-4c93-ac29-0b1ccd40f49f Server: SIP/2.0 Content-Length: 0 WWW-Authenticate: Digest realm="phone.provider.example",nonce="1a324a17ffbe",stale=false,algorithm=MD5,qop="auth" [Apr 13 20:35:00] DEBUG[89409] res_pjsip/pjsip_distributor.c: No dialog serializer for Response msg 401/REGISTER/cseq=52839 (rdata0x7fc714004928). Using request transaction as basis. [Apr 13 20:35:00] DEBUG[89409] res_pjsip/pjsip_distributor.c: Found transaction tsx0x7fc6dc01af18 for Response msg 401/REGISTER/cseq=52839 (rdata0x7fc714004928). [Apr 13 20:35:00] DEBUG[89409] res_pjsip/pjsip_distributor.c: Found serializer pjsip/outreg/ext12345678-00000059 on transaction tsx0x7fc6dc01af18 [Apr 13 20:35:00] DEBUG[91101] res_pjsip_outbound_registration.c: Received REGISTER response 401(Unauthorized) [Apr 13 20:35:00] DEBUG[91101] res_pjsip_outbound_registration.c: Processing REGISTER response 401 from server 'sip:phone.provider.example' for client 'sip:+12345678@phone.provider.example' [Apr 13 20:35:00] DEBUG[91101] res_pjsip_outbound_registration.c: Sending authenticated REGISTER to server 'sip:phone.provider.example' from client 'sip:+12345678@phone.provider.example' [Apr 13 20:35:00] DEBUG[91101] res_pjsip/pjsip_message_filter.c: Re-wrote Contact URI host/port to YYYY::1:5060 (this may be re-written again later) [Apr 13 20:35:00] VERBOSE[91101] res_pjsip_logger.c: <--- Transmitting SIP request (870 bytes) to UDP:[XXXX:8::10]:5060 ---> REGISTER sip:phone.provider.example SIP/2.0 Via: SIP/2.0/UDP [YYYY::1]:5060;rport;branch=z9hG4bKPjee90c07b-c62d-403c-aece-dfb8583de521 From: ;tag=f6a935a7-8a32-4bb9-8569-97898cf92479 To: Call-ID: bf11d197-8a76-465e-b2a0-3010fd051cd2 CSeq: 52840 REGISTER Contact: Expires: 1200 Allow: OPTIONS, REGISTER, SUBSCRIBE, NOTIFY, PUBLISH, INVITE, ACK, BYE, CANCEL, UPDATE, PRACK, MESSAGE, REFER Max-Forwards: 70 User-Agent: Asterisk PBX 17.3.0 Authorization: Digest username="+12345678", realm="phone.provider.example", nonce="1a324a17ffbe", uri="sip:phone.provider.example", response="xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx", algorithm=MD5, cnonce="xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx", qop=auth, nc=00000001 Content-Length: 0 [Apr 13 20:35:00] VERBOSE[89409] res_pjsip_logger.c: <--- Received SIP response (520 bytes) from UDP:[XXXX:8::10]:5060 ---> SIP/2.0 200 OK Call-ID: bf11d197-8a76-465e-b2a0-3010fd051cd2 CSeq: 52840 REGISTER From: ;tag=f6a935a7-8a32-4bb9-8569-97898cf92479 To: ;tag=sip+6+bb5000d+aa2f6895 Via: SIP/2.0/UDP [ZZZZ::1]:5060;received=ZZZZ::1;rport=5060;branch=z9hG4bKPjee90c07b-c62d-403c-aece-dfb8583de521 Server: SIP/2.0 Content-Length: 0 Expires: 1200 Contact: ;Expires=1200 [Apr 13 20:35:00] DEBUG[89409] res_pjsip/pjsip_distributor.c: No dialog serializer for Response msg 200/REGISTER/cseq=52840 (rdata0x7fc714004928). Using request transaction as basis. [Apr 13 20:35:00] DEBUG[89409] res_pjsip/pjsip_distributor.c: Found transaction tsx0x7fc6dc028f38 for Response msg 200/REGISTER/cseq=52840 (rdata0x7fc714004928). [Apr 13 20:35:00] DEBUG[89409] res_pjsip/pjsip_distributor.c: Found serializer pjsip/outreg/ext12345678-00000059 on transaction tsx0x7fc6dc028f38 [Apr 13 20:35:00] DEBUG[91101] res_pjsip_outbound_registration.c: Received REGISTER response 200(OK) [Apr 13 20:35:00] DEBUG[91101] res_pjsip_outbound_registration.c: Processing REGISTER response 200 from server 'sip:phone.provider.example' for client 'sip:+12345678@phone.provider.example' [Apr 13 20:35:00] DEBUG[91101] res_pjsip_outbound_registration.c: Outbound registration to 'sip:phone.provider.example' with client 'sip:+12345678@phone.provider.example' successful [Apr 13 20:54:50] DEBUG[91580] res_pjsip_outbound_registration.c: Outbound REGISTER attempt 1 to 'sip:phone.provider.example' with client 'sip:+12345678@phone.provider.example' [Apr 13 20:54:50] DEBUG[91580] res_pjsip/pjsip_resolver.c: Performing SIP DNS resolution of target 'phone.provider.example' [Apr 13 20:54:50] DEBUG[91580] res_pjsip/pjsip_resolver.c: Transport type for target 'phone.provider.example' is 'UDP' [Apr 13 20:54:50] DEBUG[91580] res_pjsip/pjsip_resolver.c: [0x7fc6e0018a28] Created resolution tracking for target 'phone.provider.example' [Apr 13 20:54:50] DEBUG[91580] res_pjsip/pjsip_resolver.c: [0x7fc6e0018a28] Added target 'phone.provider.example' with record type '35', transport 'UDP', and port '5060' [Apr 13 20:54:50] DEBUG[91580] res_pjsip/pjsip_resolver.c: [0x7fc6e0018a28] Added target '_sip._udp.phone.provider.example' with record type '33', transport 'UDP', and port '5060' [Apr 13 20:54:50] DEBUG[91580] res_pjsip/pjsip_resolver.c: [0x7fc6e0018a28] Added target 'phone.provider.example' with record type '1', transport 'UDP', and port '5060' [Apr 13 20:54:50] DEBUG[91580] res_pjsip/pjsip_resolver.c: [0x7fc6e0018a28] Starting initial resolution using parallel queries for target 'phone.provider.example' [Apr 13 20:54:50] DEBUG[89396] res_pjsip/pjsip_resolver.c: [0x7fc6e0018a28] All parallel queries completed [Apr 13 20:54:50] DEBUG[89396] res_pjsip/pjsip_resolver.c: [0x7fc6e0018a28] NAPTR record received on target 'phone.provider.example' [Apr 13 20:54:50] DEBUG[89396] res_pjsip/pjsip_resolver.c: [0x7fc6e0018a28] Added target '_sip._udp.phone.provider.example' with record type '33', transport 'UDP', and port '5060' [Apr 13 20:54:50] DEBUG[89396] res_pjsip/pjsip_resolver.c: [0x7fc6e0018a28] NAPTR record received on target 'phone.provider.example' [Apr 13 20:54:50] DEBUG[89396] res_pjsip/pjsip_resolver.c: [0x7fc6e0018a28] NAPTR record skipped because order '60' does not match strict order '50' [Apr 13 20:54:50] DEBUG[89396] res_pjsip/pjsip_resolver.c: [0x7fc6e0018a28] SRV record being skipped on target '_sip._udp.phone.provider.example' because NAPTR record exists [Apr 13 20:54:50] DEBUG[89396] res_pjsip/pjsip_resolver.c: [0x7fc6e0018a28] SRV record being skipped on target '_sip._udp.phone.provider.example' because NAPTR record exists [Apr 13 20:54:50] DEBUG[89396] res_pjsip/pjsip_resolver.c: [0x7fc6e0018a28] A record being skipped on target 'phone.provider.example' because NAPTR or SRV record exists [Apr 13 20:54:50] DEBUG[89396] res_pjsip/pjsip_resolver.c: [0x7fc6e0018a28] New queries added, performing parallel resolution again [Apr 13 20:54:50] DEBUG[89396] res_pjsip/pjsip_resolver.c: [0x7fc6e0018a28] All parallel queries completed [Apr 13 20:54:50] DEBUG[89396] res_pjsip/pjsip_resolver.c: [0x7fc6e0018a28] SRV record received on target '_sip._udp.phone.provider.example' [Apr 13 20:54:50] DEBUG[89396] res_pjsip/pjsip_resolver.c: [0x7fc6e0018a28] Added target 'phone-b.provider.example' with record type '28', transport 'UDP', and port '5060' [Apr 13 20:54:50] DEBUG[89396] res_pjsip/pjsip_resolver.c: [0x7fc6e0018a28] SRV record received on target '_sip._udp.phone.provider.example' [Apr 13 20:54:50] DEBUG[89396] res_pjsip/pjsip_resolver.c: [0x7fc6e0018a28] Added target 'phone-a.provider.example' with record type '28', transport 'UDP', and port '5060' [Apr 13 20:54:50] DEBUG[89396] res_pjsip/pjsip_resolver.c: [0x7fc6e0018a28] New queries added, performing parallel resolution again [Apr 13 20:54:50] DEBUG[89396] res_pjsip/pjsip_resolver.c: [0x7fc6e0018a28] All parallel queries completed [Apr 13 20:54:50] DEBUG[89396] res_pjsip/pjsip_resolver.c: [0x7fc6e0018a28] AAAA record received on target 'phone-b.provider.example' [Apr 13 20:54:50] DEBUG[89396] res_pjsip/pjsip_resolver.c: [0x7fc6e0018a28] AAAA record received on target 'phone-a.provider.example' [Apr 13 20:54:50] DEBUG[89396] res_pjsip/pjsip_resolver.c: [0x7fc6e0018a28] Resolution completed - 2 viable targets [Apr 13 20:54:50] DEBUG[91580] res_pjsip/pjsip_resolver.c: [0x7fc6e0018a28] Address '0' is [XXXX:7::10]:5060 with transport 'UDP' [Apr 13 20:54:50] DEBUG[91580] res_pjsip/pjsip_resolver.c: [0x7fc6e0018a28] Address '1' is [XXXX:8::10]:5060 with transport 'UDP' [Apr 13 20:54:50] DEBUG[91580] res_pjsip/pjsip_resolver.c: [0x7fc6e0018a28] Invoking user callback with '2' addresses [Apr 13 20:54:50] DEBUG[91580] res_pjsip/pjsip_message_filter.c: Re-wrote Contact URI host/port to YYYY::1:5060 (this may be re-written again later) [Apr 13 20:54:50] VERBOSE[91580] res_pjsip_logger.c: <--- Transmitting SIP request (616 bytes) to UDP:[XXXX:7::10]:5060 ---> REGISTER sip:phone.provider.example SIP/2.0 Via: SIP/2.0/UDP [YYYY::1]:5060;rport;branch=z9hG4bKPj9037cbd3-a45c-4794-8b70-bdf77e9ddf04 From: ;tag=c0d3b65f-5c26-420f-ba1d-3cc116e488ef To: Call-ID: bf11d197-8a76-465e-b2a0-3010fd051cd2 CSeq: 52841 REGISTER Contact: Expires: 1200 Allow: OPTIONS, REGISTER, SUBSCRIBE, NOTIFY, PUBLISH, INVITE, ACK, BYE, CANCEL, UPDATE, PRACK, MESSAGE, REFER Max-Forwards: 70 User-Agent: Asterisk PBX 17.3.0 Content-Length: 0 [Apr 13 20:54:50] VERBOSE[89409] res_pjsip_logger.c: <--- Received SIP response (543 bytes) from UDP:[XXXX:7::10]:5060 ---> SIP/2.0 401 Unauthorized Call-ID: bf11d197-8a76-465e-b2a0-3010fd051cd2 CSeq: 52841 REGISTER From: ;tag=c0d3b65f-5c26-420f-ba1d-3cc116e488ef To: ;tag=sip+6+841c0002+fd88f104 Via: SIP/2.0/UDP [ZZZZ::1]:5060;received=ZZZZ::1;rport=5060;branch=z9hG4bKPj9037cbd3-a45c-4794-8b70-bdf77e9ddf04 Server: SIP/2.0 Content-Length: 0 WWW-Authenticate: Digest realm="phone.provider.example",nonce="1a325e2413cc",stale=false,algorithm=MD5,qop="auth" [Apr 13 20:54:50] DEBUG[89409] res_pjsip/pjsip_distributor.c: No dialog serializer for Response msg 401/REGISTER/cseq=52841 (rdata0x7fc714004928). Using request transaction as basis. [Apr 13 20:54:50] DEBUG[89409] res_pjsip/pjsip_distributor.c: Found transaction tsx0x7fc6dc021948 for Response msg 401/REGISTER/cseq=52841 (rdata0x7fc714004928). [Apr 13 20:54:50] DEBUG[89409] res_pjsip/pjsip_distributor.c: Found serializer pjsip/outreg/ext12345678-00000059 on transaction tsx0x7fc6dc021948 [Apr 13 20:54:50] DEBUG[91580] res_pjsip_outbound_registration.c: Received REGISTER response 401(Unauthorized) [Apr 13 20:54:50] DEBUG[91580] res_pjsip_outbound_registration.c: Processing REGISTER response 401 from server 'sip:phone.provider.example' for client 'sip:+12345678@phone.provider.example' [Apr 13 20:54:50] DEBUG[91580] res_pjsip_outbound_registration.c: Sending authenticated REGISTER to server 'sip:phone.provider.example' from client 'sip:+12345678@phone.provider.example' [Apr 13 20:54:50] DEBUG[91580] res_pjsip/pjsip_message_filter.c: Re-wrote Contact URI host/port to YYYY::1:5060 (this may be re-written again later) [Apr 13 20:54:50] VERBOSE[91580] res_pjsip_logger.c: <--- Transmitting SIP request (870 bytes) to UDP:[XXXX:7::10]:5060 ---> REGISTER sip:phone.provider.example SIP/2.0 Via: SIP/2.0/UDP [YYYY::1]:5060;rport;branch=z9hG4bKPj7e73e70b-e12e-4f00-bf1b-86c751d4b002 From: ;tag=c0d3b65f-5c26-420f-ba1d-3cc116e488ef To: Call-ID: bf11d197-8a76-465e-b2a0-3010fd051cd2 CSeq: 52842 REGISTER Contact: Expires: 1200 Allow: OPTIONS, REGISTER, SUBSCRIBE, NOTIFY, PUBLISH, INVITE, ACK, BYE, CANCEL, UPDATE, PRACK, MESSAGE, REFER Max-Forwards: 70 User-Agent: Asterisk PBX 17.3.0 Authorization: Digest username="+12345678", realm="phone.provider.example", nonce="1a325e2413cc", uri="sip:phone.provider.example", response="xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx", algorithm=MD5, cnonce="xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx", qop=auth, nc=00000001 Content-Length: 0 [Apr 13 20:54:50] VERBOSE[89409] res_pjsip_logger.c: <--- Received SIP response (521 bytes) from UDP:[XXXX:7::10]:5060 ---> SIP/2.0 200 OK Call-ID: bf11d197-8a76-465e-b2a0-3010fd051cd2 CSeq: 52842 REGISTER From: ;tag=c0d3b65f-5c26-420f-ba1d-3cc116e488ef To: ;tag=sip+6+841c0002+ab66ccba Via: SIP/2.0/UDP [ZZZZ::1]:5060;received=ZZZZ::1;rport=5060;branch=z9hG4bKPj7e73e70b-e12e-4f00-bf1b-86c751d4b002 Server: SIP/2.0 Content-Length: 0 Expires: 1200 Contact: ;Expires=1200 [Apr 13 20:54:50] DEBUG[89409] res_pjsip/pjsip_distributor.c: No dialog serializer for Response msg 200/REGISTER/cseq=52842 (rdata0x7fc714004928). Using request transaction as basis. [Apr 13 20:54:50] DEBUG[89409] res_pjsip/pjsip_distributor.c: Found transaction tsx0x7fc6e00380d8 for Response msg 200/REGISTER/cseq=52842 (rdata0x7fc714004928). [Apr 13 20:54:50] DEBUG[89409] res_pjsip/pjsip_distributor.c: Found serializer pjsip/outreg/ext12345678-00000059 on transaction tsx0x7fc6e00380d8 [Apr 13 20:54:50] DEBUG[91580] res_pjsip_outbound_registration.c: Received REGISTER response 200(OK) [Apr 13 20:54:50] DEBUG[91580] res_pjsip_outbound_registration.c: Processing REGISTER response 200 from server 'sip:phone.provider.example' for client 'sip:+12345678@phone.provider.example' [Apr 13 20:54:50] DEBUG[91580] res_pjsip_outbound_registration.c: Outbound registration to 'sip:phone.provider.example' with client 'sip:+12345678@phone.provider.example' successful