PJSIP incoming call won't authenticate

Asterisk Asterisk SIP
#1

I’m using Asterisk 14.2.1 and PJSIP with realtime configuration
registration and outgoing calls to OVH work correctly.
Incoming calls refuse to authenticate.
Incoming calls appear to be anonymous and I have created an “anonymous” endpoint as stated in various configuration documents. res_pjsip_endpoint_identifier_anonymous.so is loaded

[Apr 4 17:55:27] <— Received SIP request (1304 bytes) from UDP:91.121.129.20:5060 —>
[Apr 4 17:55:27] INVITE sip:KFONE-default@192.168.1.34:5060;transport=udp SIP/2.0
[Apr 4 17:55:27] Authorization: Digest username=“anonymous”,realm=“sip.ovh.fr”,nonce=“1491321327/b311d2c643bcecd6bbccaf12db0a68cb”,uri=“sip:KFONE-default@192.168.1.34:5060”,response=“390e4af98661593b8ea7e7d0f7671ca9”,algorithm=MD5,opaque=“086f1ecd45870cf0”
[Apr 4 17:55:27] Call-ID: 16309-NQ-2c5ef558-76a11a521@sip.ovh.fr
[Apr 4 17:55:27] Contact: sip:10.7.1.60:5060
[Apr 4 17:55:27] Content-Type: application/sdp
[Apr 4 17:55:27] CSeq: 734518015 INVITE
[Apr 4 17:55:27] From: “0680123456” sip:0680123456@sip.ovh.fr;user=phone;tag=16309-GH-2c5ef559-2988e1f17
[Apr 4 17:55:27] Max-Forwards: 0
[Apr 4 17:55:27] Record-Route: sip:91.121.129.20:5060;lr
[Apr 4 17:55:27] To: sip:0972306227@10.7.1.60;user=phone
[Apr 4 17:55:27] Via: SIP/2.0/UDP 91.121.129.20:5060;branch=z9hG4bK-CJON-00616fdf-0125fbb2
[Apr 4 17:55:27] Allow: REFER,INVITE,NOTIFY,ACK,UPDATE,OPTIONS,REGISTER,SUBSCRIBE,NOTIFY,CANCEL,BYE,PRACK
[Apr 4 17:55:27] User-Agent: Cirpack/v4.70 (gw_sip)
[Apr 4 17:55:27] Content-Length: 444
[Apr 4 17:55:27]
[Apr 4 17:55:27] v=0
[Apr 4 17:55:27] o=cp10 149132132790 149132132790 IN IP4 10.7.1.45
[Apr 4 17:55:27] s=SIP Call
[Apr 4 17:55:27] c=IN IP4 91.121.129.142
[Apr 4 17:55:27] t=0 0
[Apr 4 17:55:27] m=audio 36532 RTP/AVP 18 4 8 0 125 111 101
[Apr 4 17:55:27] b=AS:26
[Apr 4 17:55:27] a=rtpmap:18 G729/8000/1
[Apr 4 17:55:27] a=fmtp:18 annexb=no
[Apr 4 17:55:27] a=rtpmap:4 G723/8000/1
[Apr 4 17:55:27] a=fmtp:4 annexa=no
[Apr 4 17:55:27] a=rtpmap:8 PCMA/8000/1
[Apr 4 17:55:27] a=rtpmap:0 PCMU/8000/1
[Apr 4 17:55:27] a=rtpmap:125 CLEARMODE/8000/1
[Apr 4 17:55:27] a=rtpmap:111 iLBC/8000/1
[Apr 4 17:55:27] a=fmtp:111 mode=20
[Apr 4 17:55:27] a=rtpmap:101 telephone-event/8000
[Apr 4 17:55:27] a=fmtp:101 0-15
[Apr 4 17:55:27] a=ptime:20
[Apr 4 17:55:27] a=sendrecv
[Apr 4 17:55:27]
[Apr 4 17:55:27] DEBUG[24765]: res_pjsip/pjsip_distributor.c:267 find_dialog: Could not find matching transaction for Request msg INVITE/cseq=734518015 (rdata0xb4f018c4)
[Apr 4 17:55:27] DEBUG[24765]: res_pjsip/pjsip_distributor.c:359 ast_sip_get_distributor_serializer: Calculated serializer pjsip/distributor-0000003f to use for Request msg INVITE/cseq=734518015 (rdata0xb4f018c4)
[Apr 4 17:55:27] DEBUG[24766]: acl.c:661 ast_append_ha: 169.132.196.11:0/255.255.255.255:0 sense 0 appended to ACL
[Apr 4 17:55:27] DEBUG[24766]: acl.c:661 ast_append_ha: 66.33.146.52:0/255.255.255.255:0 sense 0 appended to ACL
[Apr 4 17:55:27] DEBUG[24766]: acl.c:661 ast_append_ha: 91.121.129.20:0/255.255.255.255:0 sense 0 appended to ACL
[Apr 4 17:55:27] DEBUG[24766]: res_pjsip_endpoint_identifier_ip.c:113 ip_identify_match_check: Source address 91.121.129.20:5060 does not match identify ‘net2phone’
[Apr 4 17:55:27] DEBUG[24766]: res_pjsip_endpoint_identifier_ip.c:108 ip_identify_match_check: Source address 91.121.129.20:5060 matches identify ‘ovh’
[Apr 4 17:55:27] DEBUG[24766]: res_odbc.c:869 _ast_odbc_request_obj2: Reusing ODBC handle 0x9119cc4 from class ‘asterisk’
[Apr 4 17:55:27] DEBUG[24766]: res_config_odbc.c:116 custom_prepare: Skip: 0; SQL: SELECT * FROM ps_endpoints WHERE id = ?
[Apr 4 17:55:27] DEBUG[24766]: res_config_odbc.c:132 custom_prepare: Parameter 1 (‘id’) = ‘ovh’
[Apr 4 17:55:27] DEBUG[24766]: res_odbc.c:718 ast_odbc_release_obj: Releasing ODBC handle 0x9119cc4 into pool
[Apr 4 17:55:27] DEBUG[24766]: res_sorcery_realtime.c:131 sorcery_realtime_filter_objectset: Filtering out realtime field ‘disallow’ from retrieval
[Apr 4 17:55:27] DEBUG[24766]: config.c:3742 ast_parse_arg: extract uint from [0] in [0, 4294967295] gives 0
[Apr 4 17:55:27] DEBUG[24766]: config.c:3742 ast_parse_arg: extract uint from [0] in [0, 4294967295] gives 0
[Apr 4 17:55:27] DEBUG[24766]: config.c:3742 ast_parse_arg: extract uint from [0] in [0, 4294967295] gives 0
[Apr 4 17:55:27] DEBUG[24766]: config.c:3742 ast_parse_arg: extract uint from [0] in [0, 4294967295] gives 0
[Apr 4 17:55:27] DEBUG[24766]: config.c:3742 ast_parse_arg: extract uint from [0] in [0, 4294967295] gives 0
[Apr 4 17:55:27] DEBUG[24766]: config.c:3742 ast_parse_arg: extract uint from [1800] in [0, 4294967295] gives 1800
[Apr 4 17:55:27] DEBUG[24766]: config.c:3742 ast_parse_arg: extract uint from [0] in [0, 4294967295] gives 0
[Apr 4 17:55:27] DEBUG[24766]: config.c:3742 ast_parse_arg: extract uint from [0] in [0, 4294967295] gives 0
[Apr 4 17:55:27] DEBUG[24766]: config.c:3742 ast_parse_arg: extract uint from [90] in [0, 4294967295] gives 90
[Apr 4 17:55:27] DEBUG[24766]: config.c:3742 ast_parse_arg: extract uint from [0] in [0, 4294967295] gives 0
[Apr 4 17:55:27] DEBUG[24766]: config.c:3742 ast_parse_arg: extract uint from [0] in [0, 4294967295] gives 0
[Apr 4 17:55:27] DEBUG[24766]: config.c:3742 ast_parse_arg: extract uint from [1] in [0, 4294967295] gives 1
[Apr 4 17:55:27] DEBUG[24766]: res_pjsip_endpoint_identifier_ip.c:143 ip_identify: Retrieved endpoint ovh
[Apr 4 17:55:27] DEBUG[24766]: res_odbc.c:869 _ast_odbc_request_obj2: Reusing ODBC handle 0x9119cc4 from class ‘asterisk’
[Apr 4 17:55:27] DEBUG[24766]: res_config_odbc.c:116 custom_prepare: Skip: 0; SQL: SELECT * FROM ps_endpoint_id_ips WHERE id LIKE ? ORDER BY id
[Apr 4 17:55:27] DEBUG[24766]: res_config_odbc.c:132 custom_prepare: Parameter 1 (‘id LIKE’) = ‘%’
[Apr 4 17:55:27] DEBUG[24766]: res_odbc.c:718 ast_odbc_release_obj: Releasing ODBC handle 0x9119cc4 into pool
[Apr 4 17:55:27] DEBUG[24766]: acl.c:661 ast_append_ha: 66.33.146.52:0/255.255.255.255:0 sense 0 appended to ACL
[Apr 4 17:55:27] DEBUG[24766]: acl.c:661 ast_append_ha: 169.132.196.11:0/255.255.255.255:0 sense 0 appended to ACL
[Apr 4 17:55:27] DEBUG[24766]: acl.c:661 ast_append_ha: 91.121.129.20:0/255.255.255.255:0 sense 0 appended to ACL
[Apr 4 17:55:27] DEBUG[24766]: res_pjsip_endpoint_identifier_ip.c:113 ip_identify_match_check: Source address 91.121.129.20:5060 does not match identify ‘net2phone’
[Apr 4 17:55:27] DEBUG[24766]: res_pjsip_endpoint_identifier_ip.c:108 ip_identify_match_check: Source address 91.121.129.20:5060 matches identify ‘ovh’
[Apr 4 17:55:27] DEBUG[24766]: res_odbc.c:869 _ast_odbc_request_obj2: Reusing ODBC handle 0x9119cc4 from class ‘asterisk’
[Apr 4 17:55:27] DEBUG[24766]: res_config_odbc.c:116 custom_prepare: Skip: 0; SQL: SELECT * FROM ps_endpoints WHERE id = ?
[Apr 4 17:55:27] DEBUG[24766]: res_config_odbc.c:132 custom_prepare: Parameter 1 (‘id’) = ‘ovh’
[Apr 4 17:55:27] DEBUG[24766]: res_odbc.c:718 ast_odbc_release_obj: Releasing ODBC handle 0x9119cc4 into pool
[Apr 4 17:55:27] DEBUG[24766]: res_sorcery_realtime.c:131 sorcery_realtime_filter_objectset: Filtering out realtime field ‘disallow’ from retrieval
[Apr 4 17:55:27] DEBUG[24766]: config.c:3742 ast_parse_arg: extract uint from [0] in [0, 4294967295] gives 0
[Apr 4 17:55:27] DEBUG[24766]: config.c:3742 ast_parse_arg: extract uint from [0] in [0, 4294967295] gives 0
[Apr 4 17:55:27] DEBUG[24766]: config.c:3742 ast_parse_arg: extract uint from [0] in [0, 4294967295] gives 0
[Apr 4 17:55:27] DEBUG[24766]: config.c:3742 ast_parse_arg: extract uint from [0] in [0, 4294967295] gives 0
[Apr 4 17:55:27] DEBUG[24766]: config.c:3742 ast_parse_arg: extract uint from [0] in [0, 4294967295] gives 0
[Apr 4 17:55:27] DEBUG[24766]: config.c:3742 ast_parse_arg: extract uint from [1800] in [0, 4294967295] gives 1800
[Apr 4 17:55:27] DEBUG[24766]: config.c:3742 ast_parse_arg: extract uint from [0] in [0, 4294967295] gives 0
[Apr 4 17:55:27] DEBUG[24766]: config.c:3742 ast_parse_arg: extract uint from [0] in [0, 4294967295] gives 0
[Apr 4 17:55:27] DEBUG[24766]: config.c:3742 ast_parse_arg: extract uint from [90] in [0, 4294967295] gives 90
[Apr 4 17:55:27] DEBUG[24766]: config.c:3742 ast_parse_arg: extract uint from [0] in [0, 4294967295] gives 0
[Apr 4 17:55:27] DEBUG[24766]: config.c:3742 ast_parse_arg: extract uint from [0] in [0, 4294967295] gives 0
[Apr 4 17:55:27] DEBUG[24766]: config.c:3742 ast_parse_arg: extract uint from [1] in [0, 4294967295] gives 1
[Apr 4 17:55:27] DEBUG[24766]: res_pjsip_endpoint_identifier_ip.c:143 ip_identify: Retrieved endpoint ovh
[Apr 4 17:55:27] DEBUG[24766]: res_odbc.c:869 _ast_odbc_request_obj2: Reusing ODBC handle 0x9119cc4 from class ‘asterisk’
[Apr 4 17:55:27] DEBUG[24766]: res_config_odbc.c:116 custom_prepare: Skip: 0; SQL: SELECT * FROM ps_auths WHERE id = ?
[Apr 4 17:55:27] DEBUG[24766]: res_config_odbc.c:132 custom_prepare: Parameter 1 (‘id’) = ‘ovh’
[Apr 4 17:55:27] DEBUG[24766]: res_odbc.c:718 ast_odbc_release_obj: Releasing ODBC handle 0x9119cc4 into pool
[Apr 4 17:55:27] DEBUG[24766]: config.c:3742 ast_parse_arg: extract uint from [32] in [0, 4294967295] gives 32
[Apr 4 17:55:27] DEBUG[24766]: res_pjsip_authenticator_digest.c:257 check_nonce: Calculated nonce 1491321327/b311d2c643bcecd6bbccaf12db0a68cb. Actual nonce is 1491321327/b311d2c643bcecd6bbccaf12db0a68cb
[Apr 4 17:55:27] NOTICE[24766]: res_pjsip/pjsip_distributor.c:525 log_failed_request: Request ‘INVITE’ from ‘“0680123456” sip:0680123456@sip.ovh.fr;user=phone’ failed for ‘91.121.129.20:5060’ (callid: 16309-NQ-2c5ef558-76a11a521@sip.ovh.fr) - Failed to authenticate

Any suggestions?

#2

The request is matching an endpoint named ‘ovh’. What is the configuration of it?

#3

Hi,

            I’ve extracted the definition from the database in the attached file.

            I hope its readable.

            Best regards,

            Pete
#4

There is no attachment on this post. You can also post the output of “pjsip show endpoint ovh”

#5

Endpoint: ovh Unavailable 0 of 1

OutAuth:  ovh/0033972306227

 InAuth:  ovh/0033972306227

    Aor:  ovh                                                2

  Contact:  ovh/sip:0033972306227@sip.ovh.fr           5c91c115fa Unknown         nan

Transport: transport-udp udp 0 0 0.0.0.0:5060

Identify: ovh/ovh

    Match: 91.121.129.20/32

ParameterName : ParameterValue

#6

You have an “auth” option set. This means we are challenging for authentication inbound calls. They do not appear to want to authenticate. If you remove it does it then work?

#7

Thanks. That seems to have made a significant difference which I’ll test some more tomorrow morning since its now 10 :43pm !

#8

I’m back here again having updated to Asterisk 16.1.1

The authentication appears to be refused because the nonces don’t match but they do at least as far as the debug trace shows:
[Feb 14 16:41:01] DEBUG[24527]: res_pjsip_authenticator_digest.c:259 check_nonce: Calculated nonce 1550158861/71f346d2836ebba6d06c186ae5744731. Actual nonce is
1550158861/71f346d2836ebba6d06c186ae5744731
[Feb 14 16:41:01] NOTICE[24527]: res_pjsip/pjsip_distributor.c:672 log_failed_request: Request ‘INVITE’ from ‘"+33680963546" sip:0680963546@sip.ovh.fr;user=phone’ failed for ‘91.121.129.20:5060’ (callid: 20445-VX-8386e99f-0fdf8b673@sip.ovh.fr) - Failed to authenticate

So what’s going on? The code is just doing a strcmp so I don’t see why it isn’t giving the right result.

#9

Are you sure they will authenticate your challenge? Many providers don’t expect the receiving side to challenge them.

#10

Hi Joshua,

I’m back to the case which I talked about in 2017.

I can make outgoing calls on this SIP trunk to an outside provider to which I registered.

However when I receive a call from them, Asterisk rejects the call because it is unable to authenticate it.

In the pjsip authenticator digest module, this rejection seems to be caused by the nonces: calculated vs candidate being considered to be different when they appear to be identical. That’s what I don’t understand.

Best regards,

Pete

#11

I’d suggest providing new traces and current configuration again then. Generally though as I stated earlier - upstream providers don’t authenticate to you. As for not matching - the nonce is only part of the calculation. It includes other aspects of the message and the password. So the question isn’t “why does the authentication fail?” it’s “why are you challenging for authentication and does the provider support it?”.

#12

Here’s the trace:
[Feb 14 20:49:53] <— Received SIP request (1176 bytes) from UDP:91.121.129.20:5060 —>
[Feb 14 20:49:53] INVITE sip:ovh_incoming@192.168.1.31:5060;transport=udp SIP/2.0
[Feb 14 20:49:53] Authorization: Digest username=“anonymous”,realm=“sip.ovh.fr”,nonce=“1550173793/925afcb0884ea6487bdec75087a170d4”,uri=“sip:ovh_incoming@192.168.1.31:5060”,response=“6d9a24a6acbe30c38e6440d9aae0aeb6”,algorithm=MD5,opaque=“0c462da4288e3aa3”
[Feb 14 20:49:53] Call-ID: 25736-UV-83d4f84a-3f89ef801@sip.ovh.fr
[Feb 14 20:49:53] Contact: sip:10.7.1.60:5060
[Feb 14 20:49:53] Content-Type: application/sdp
[Feb 14 20:49:53] CSeq: 60161807 INVITE
[Feb 14 20:49:53] From: “+33680963546” sip:0680963546@sip.ovh.fr;user=phone;tag=25736-VP-83d4f84b-3c59cbd77
[Feb 14 20:49:53] Max-Forwards: 29
[Feb 14 20:49:53] Record-Route: sip:91.121.129.20:5060;lr
[Feb 14 20:49:53] To: sip:0972306227@10.7.1.60;user=phone
[Feb 14 20:49:53] Via: SIP/2.0/UDP 91.121.129.20:5060;branch=z9hG4bK-ZYHW-003e70c7-57452e91
[Feb 14 20:49:53] Allow: REFER,INVITE,NOTIFY,ACK,UPDATE,OPTIONS,REGISTER,SUBSCRIBE,NOTIFY,CANCEL,BYE,PRACK
[Feb 14 20:49:53] User-Agent: Cirpack/v4.76 (gw_sip)
[Feb 14 20:49:53] Content-Length: 316
[Feb 14 20:49:53]
[Feb 14 20:49:53] v=0
[Feb 14 20:49:53] o=cp10 155017379362 155017379362 IN IP4 193.251.120.125
[Feb 14 20:49:53] s=SIP Call
[Feb 14 20:49:53] c=IN IP4 91.121.129.143
[Feb 14 20:49:53] t=0 0
[Feb 14 20:49:53] m=audio 33314 RTP/AVP 8 18 0 97
[Feb 14 20:49:53] b=AS:82
[Feb 14 20:49:53] a=rtpmap:8 PCMA/8000/1
[Feb 14 20:49:53] a=rtpmap:18 G729/8000/1
[Feb 14 20:49:53] a=fmtp:18 annexb=no
[Feb 14 20:49:53] a=rtpmap:0 PCMU/8000/1
[Feb 14 20:49:53] a=rtpmap:97 telephone-event/8000
[Feb 14 20:49:53] a=fmtp:97 0-15
[Feb 14 20:49:53] a=ptime:20
[Feb 14 20:49:53] a=sendrecv
[Feb 14 20:49:53]
[Feb 14 20:49:53] DEBUG[3752]: res_odbc.c:848 _ast_odbc_request_obj2: Reusing ODBC handle 0x560ddd0a88e0 from class ‘asterisk’
[Feb 14 20:49:53] DEBUG[3752]: res_config_odbc.c:115 custom_prepare: Skip: 0; SQL: SELECT * FROM ps_transports WHERE id = ?
[Feb 14 20:49:53] DEBUG[3752]: res_config_odbc.c:134 custom_prepare: Parameter 1 (‘id’) = ‘transport-udp’
[Feb 14 20:49:53] DEBUG[3752]: res_odbc.c:697 ast_odbc_release_obj: Releasing ODBC handle 0x560ddd0a88e0 into pool
[Feb 14 20:49:53] DEBUG[3752]: config.c:3730 ast_parse_arg: extract uint from [1] in [0, 4294967295] gives 1
[Feb 14 20:49:53] DEBUG[3752]: config.c:3730 ast_parse_arg: extract uint from [0] in [0, 65535] gives 0
[Feb 14 20:49:53] DEBUG[3752]: config.c:3677 ast_parse_arg: extract int from [100] in [1, 2147483647] gives 100
[Feb 14 20:49:53] DEBUG[3752]: config.c:3730 ast_parse_arg: extract uint from [0] in [0, 4294967295] gives 0
[Feb 14 20:49:53] DEBUG[3752]: res_pjsip/pjsip_distributor.c:393 find_dialog: Could not find matching transaction for Request msg INVITE/cseq=60161807 (rdata0x7fabb8003ee8)
[Feb 14 20:49:53] DEBUG[3752]: res_pjsip/pjsip_distributor.c:471 ast_sip_get_distributor_serializer: Calculated serializer pjsip/distributor-0000003a to use for Request msg INVITE/cseq=60161807 (rdata0x7fabb8003ee8)
[Feb 14 20:49:53] DEBUG[3753]: netsock2.c:170 ast_sockaddr_split_hostport: Splitting ‘91.121.129.20’ into…
[Feb 14 20:49:53] DEBUG[3753]: netsock2.c:224 ast_sockaddr_split_hostport: …host ‘91.121.129.20’ and port ‘’.
[Feb 14 20:49:53] DEBUG[3753]: acl.c:569 debug_ha_sense_appended: 91.121.129.20:0/255.255.255.255:0 sense 0 appended to ACL
[Feb 14 20:49:53] DEBUG[3753]: res_pjsip_endpoint_identifier_ip.c:245 ip_identify_match_check: Source address 91.121.129.20:5060 does not match identify ‘net2phone’
[Feb 14 20:49:53] DEBUG[3753]: res_pjsip_endpoint_identifier_ip.c:240 ip_identify_match_check: Source address 91.121.129.20:5060 matches identify ‘ovh’
[Feb 14 20:49:53] DEBUG[3753]: res_odbc.c:848 _ast_odbc_request_obj2: Reusing ODBC handle 0x560ddd0a88e0 from class ‘asterisk’
[Feb 14 20:49:53] DEBUG[3753]: res_config_odbc.c:115 custom_prepare: Skip: 0; SQL: SELECT * FROM ps_endpoints WHERE id = ?
[Feb 14 20:49:53] DEBUG[3753]: res_config_odbc.c:134 custom_prepare: Parameter 1 (‘id’) = ‘ovh’
[Feb 14 20:49:53] DEBUG[3753]: res_odbc.c:697 ast_odbc_release_obj: Releasing ODBC handle 0x560ddd0a88e0 into pool
[Feb 14 20:49:53] DEBUG[3753]: res_sorcery_realtime.c:132 sorcery_realtime_filter_objectset: Filtering out realtime field ‘disallow’ from retrieval
[Feb 14 20:49:53] DEBUG[3753]: config.c:3730 ast_parse_arg: extract uint from [0] in [0, 4294967295] gives 0
[Feb 14 20:49:53] DEBUG[3753]: config.c:3730 ast_parse_arg: extract uint from [1800] in [0, 4294967295] gives 1800
[Feb 14 20:49:53] DEBUG[3753]: config.c:3730 ast_parse_arg: extract uint from [0] in [0, 4294967295] gives 0
[Feb 14 20:49:53] DEBUG[3753]: config.c:3730 ast_parse_arg: extract uint from [0] in [0, 4294967295] gives 0
[Feb 14 20:49:53] DEBUG[3753]: config.c:3730 ast_parse_arg: extract uint from [0] in [0, 4294967295] gives 0
[Feb 14 20:49:53] DEBUG[3753]: config.c:3730 ast_parse_arg: extract uint from [1] in [0, 4294967295] gives 1
[Feb 14 20:49:53] DEBUG[3753]: config.c:3730 ast_parse_arg: extract uint from [1] in [0, 4294967295] gives 1
[Feb 14 20:49:53] DEBUG[3753]: config.c:3730 ast_parse_arg: extract uint from [0] in [0, 4294967295] gives 0
[Feb 14 20:49:53] DEBUG[3753]: config.c:3730 ast_parse_arg: extract uint from [0] in [0, 4294967295] gives 0
[Feb 14 20:49:53] DEBUG[3753]: config.c:3730 ast_parse_arg: extract uint from [0] in [0, 4294967295] gives 0
[Feb 14 20:49:53] DEBUG[3753]: config.c:3730 ast_parse_arg: extract uint from [90] in [0, 4294967295] gives 90
[Feb 14 20:49:53] DEBUG[3753]: config.c:3730 ast_parse_arg: extract uint from [0] in [0, 4294967295] gives 0
[Feb 14 20:49:53] DEBUG[3753]: config.c:3730 ast_parse_arg: extract uint from [0] in [0, 4294967295] gives 0
[Feb 14 20:49:53] DEBUG[3753]: config.c:3730 ast_parse_arg: extract uint from [1] in [0, 4294967295] gives 1
[Feb 14 20:49:53] DEBUG[3753]: res_pjsip_endpoint_identifier_ip.c:273 common_identify: Identify ‘ovh’ SIP message matched to endpoint ovh
[Feb 14 20:49:53] DEBUG[3753]: netsock2.c:170 ast_sockaddr_split_hostport: Splitting ‘91.121.129.20’ into…
[Feb 14 20:49:53] DEBUG[3753]: netsock2.c:224 ast_sockaddr_split_hostport: …host ‘91.121.129.20’ and port ‘’.
[Feb 14 20:49:53] DEBUG[3753]: res_odbc.c:848 _ast_odbc_request_obj2: Reusing ODBC handle 0x560ddd0a88e0 from class ‘asterisk’
[Feb 14 20:49:53] DEBUG[3753]: res_config_odbc.c:115 custom_prepare: Skip: 0; SQL: SELECT * FROM ps_endpoint_id_ips WHERE id LIKE ? ORDER BY id
[Feb 14 20:49:53] DEBUG[3753]: res_config_odbc.c:134 custom_prepare: Parameter 1 (‘id LIKE’) = ‘%’
[Feb 14 20:49:53] DEBUG[3753]: res_odbc.c:697 ast_odbc_release_obj: Releasing ODBC handle 0x560ddd0a88e0 into pool
[Feb 14 20:49:53] DEBUG[3753]: netsock2.c:170 ast_sockaddr_split_hostport: Splitting ‘ippbx.net2phone.com’ into…
[Feb 14 20:49:53] DEBUG[3753]: netsock2.c:224 ast_sockaddr_split_hostport: …host ‘ippbx.net2phone.com’ and port ‘’.
[Feb 14 20:49:53] DEBUG[3753]: netsock2.c:170 ast_sockaddr_split_hostport: Splitting ‘ippbx.net2phone.com’ into…
[Feb 14 20:49:53] DEBUG[3753]: netsock2.c:224 ast_sockaddr_split_hostport: …host ‘ippbx.net2phone.com’ and port ‘’.
[Feb 14 20:49:53] DEBUG[3753]: netsock2.c:170 ast_sockaddr_split_hostport: Splitting ‘169.132.196.11’ into…
[Feb 14 20:49:53] DEBUG[3753]: netsock2.c:224 ast_sockaddr_split_hostport: …host ‘169.132.196.11’ and port ‘’.
[Feb 14 20:49:53] DEBUG[3753]: acl.c:569 debug_ha_sense_appended: 169.132.196.11:0/255.255.255.255:0 sense 0 appended to ACL
[Feb 14 20:49:53] DEBUG[3753]: netsock2.c:170 ast_sockaddr_split_hostport: Splitting ‘66.33.146.52’ into…
[Feb 14 20:49:53] DEBUG[3753]: netsock2.c:224 ast_sockaddr_split_hostport: …host ‘66.33.146.52’ and port ‘’.
[Feb 14 20:49:53] DEBUG[3753]: acl.c:569 debug_ha_sense_appended: 66.33.146.52:0/255.255.255.255:0 sense 0 appended to ACL
[Feb 14 20:49:53] DEBUG[3753]: netsock2.c:170 ast_sockaddr_split_hostport: Splitting ‘sip.ovh.fr’ into…
[Feb 14 20:49:53] DEBUG[3753]: netsock2.c:224 ast_sockaddr_split_hostport: …host ‘sip.ovh.fr’ and port ‘’.
[Feb 14 20:49:53] DEBUG[3753]: netsock2.c:170 ast_sockaddr_split_hostport: Splitting ‘sip.ovh.fr’ into…
[Feb 14 20:49:53] DEBUG[3753]: netsock2.c:224 ast_sockaddr_split_hostport: …host ‘sip.ovh.fr’ and port ‘’.
[Feb 14 20:49:53] DEBUG[3753]: netsock2.c:170 ast_sockaddr_split_hostport: Splitting ‘91.121.129.20’ into…
[Feb 14 20:49:53] DEBUG[3753]: netsock2.c:224 ast_sockaddr_split_hostport: …host ‘91.121.129.20’ and port ‘’.
[Feb 14 20:49:53] DEBUG[3753]: acl.c:569 debug_ha_sense_appended: 91.121.129.20:0/255.255.255.255:0 sense 0 appended to ACL
[Feb 14 20:49:53] DEBUG[3753]: res_pjsip_endpoint_identifier_ip.c:245 ip_identify_match_check: Source address 91.121.129.20:5060 does not match identify ‘net2phone’
[Feb 14 20:49:53] DEBUG[3753]: res_pjsip_endpoint_identifier_ip.c:240 ip_identify_match_check: Source address 91.121.129.20:5060 matches identify ‘ovh’
[Feb 14 20:49:53] DEBUG[3753]: res_odbc.c:848 _ast_odbc_request_obj2: Reusing ODBC handle 0x560ddd0a88e0 from class ‘asterisk’
[Feb 14 20:49:53] DEBUG[3753]: res_config_odbc.c:115 custom_prepare: Skip: 0; SQL: SELECT * FROM ps_endpoints WHERE id = ?
[Feb 14 20:49:53] DEBUG[3753]: res_config_odbc.c:134 custom_prepare: Parameter 1 (‘id’) = ‘ovh’
[Feb 14 20:49:53] DEBUG[3753]: res_odbc.c:697 ast_odbc_release_obj: Releasing ODBC handle 0x560ddd0a88e0 into pool
[Feb 14 20:49:53] DEBUG[3753]: res_sorcery_realtime.c:132 sorcery_realtime_filter_objectset: Filtering out realtime field ‘disallow’ from retrieval
[Feb 14 20:49:53] DEBUG[3753]: config.c:3730 ast_parse_arg: extract uint from [0] in [0, 4294967295] gives 0
[Feb 14 20:49:53] DEBUG[3753]: config.c:3730 ast_parse_arg: extract uint from [1800] in [0, 4294967295] gives 1800
[Feb 14 20:49:53] DEBUG[3753]: config.c:3730 ast_parse_arg: extract uint from [0] in [0, 4294967295] gives 0
[Feb 14 20:49:53] DEBUG[3753]: config.c:3730 ast_parse_arg: extract uint from [0] in [0, 4294967295] gives 0
[Feb 14 20:49:53] DEBUG[3753]: config.c:3730 ast_parse_arg: extract uint from [0] in [0, 4294967295] gives 0
[Feb 14 20:49:53] DEBUG[3753]: config.c:3730 ast_parse_arg: extract uint from [1] in [0, 4294967295] gives 1
[Feb 14 20:49:53] DEBUG[3753]: config.c:3730 ast_parse_arg: extract uint from [1] in [0, 4294967295] gives 1
[Feb 14 20:49:53] DEBUG[3753]: config.c:3730 ast_parse_arg: extract uint from [0] in [0, 4294967295] gives 0
[Feb 14 20:49:53] DEBUG[3753]: config.c:3730 ast_parse_arg: extract uint from [0] in [0, 4294967295] gives 0
[Feb 14 20:49:53] DEBUG[3753]: config.c:3730 ast_parse_arg: extract uint from [0] in [0, 4294967295] gives 0
[Feb 14 20:49:53] DEBUG[3753]: config.c:3730 ast_parse_arg: extract uint from [90] in [0, 4294967295] gives 90
[Feb 14 20:49:53] DEBUG[3753]: config.c:3730 ast_parse_arg: extract uint from [0] in [0, 4294967295] gives 0
[Feb 14 20:49:53] DEBUG[3753]: config.c:3730 ast_parse_arg: extract uint from [0] in [0, 4294967295] gives 0
[Feb 14 20:49:53] DEBUG[3753]: config.c:3730 ast_parse_arg: extract uint from [1] in [0, 4294967295] gives 1
[Feb 14 20:49:53] DEBUG[3753]: res_pjsip_endpoint_identifier_ip.c:273 common_identify: Identify ‘ovh’ SIP message matched to endpoint ovh
[Feb 14 20:49:53] DEBUG[3753]: res_odbc.c:848 _ast_odbc_request_obj2: Reusing ODBC handle 0x560ddd0a88e0 from class ‘asterisk’
[Feb 14 20:49:53] DEBUG[3753]: res_config_odbc.c:115 custom_prepare: Skip: 0; SQL: SELECT * FROM ps_auths WHERE id = ?
[Feb 14 20:49:53] DEBUG[3753]: res_config_odbc.c:134 custom_prepare: Parameter 1 (‘id’) = ‘ovh’
[Feb 14 20:49:53] DEBUG[3753]: res_odbc.c:697 ast_odbc_release_obj: Releasing ODBC handle 0x560ddd0a88e0 into pool
[Feb 14 20:49:53] DEBUG[3753]: config.c:3730 ast_parse_arg: extract uint from [32] in [0, 4294967295] gives 32
[Feb 14 20:49:53] DEBUG[3753]: res_pjsip_authenticator_digest.c:259 check_nonce: Calculated nonce |1550173793/925afcb0884ea6487bdec75087a170d4| Actual nonce is |1550173793/925afcb0884ea6487bdec75087a170d4|
[Feb 14 20:49:53] NOTICE[3753]: res_pjsip/pjsip_distributor.c:672 log_failed_request: Request ‘INVITE’ from ‘"+33680963546" sip:0680963546@sip.ovh.fr;user=phone’ failed for ‘91.121.129.20:5060’ (callid: 25736-UV-83d4f84a-3f89ef801@sip.ovh.fr) - Failed to authenticate

I’ve inserted the || around the nonces in the debug message to ensure there are no leading or training spaces having been bitten by that in an earlier life. I can give you the configs if you insist but you can see from the trace that the authentication works fine until it compares the nonces where it fails despite the fact that they seem to be identical.

#13

The configuration for “ovh” is needed. Authentication isn’t even yet computed or compared yet at that point, and I don’t believe the nonce is the problem. It’s only part of the process and occurs before the authentication calculation and comparison is actually done. It’s not your problem.

#14

In res_pjsip_authenticator.c as indicated in the trace above we have the following:
build_nonce(&calculated, timestamp, rdata, auth->realm);
ast_debug(3, “Calculated nonce |%s| Actual nonce is |%s|\n”, ast_str_buffer(calculated), candidate);
if (strcmp(ast_str_buffer(calculated), candidate)) {
return 0;
}
return 1;

the ast_debug call is on line 259 as the trace says.
So you may not believe that the trace is the problem but this code sure does!

There may be other problems since we only get to solve them one at a time but this is certainly one of them.

Please don’t insult me. I have tried to investigate this on my own but there are limits.

Best regards.

#15

I was not trying to insult you so I’ll take leave of this thread and let others chime in.

#16

I believe you were asked a direct question in regards to OVH. Do they support inbound authentication? Will they use a user/password that either they give you or you give them to send calls to you? Because 99.99% of providers don’t do that. You are either registering to them or using IP auth to deal with calls between you.

Also there is nothing wrong with what you have shown. When OVH sends the initial INVITE and you challenge them for auth, YOU (as in Asterisk) is generating that nonce for that specific request. OVH then needs to use that nonce, user, password, domain and generate an md5 hash to reply. They will send back both the nonce you sent them and that hash.

What you are showing (and what’s been explained) is PJSIP looking at the generated nonce it made for that specific transaction and it’s comparing it to what OVH sent back in their INVITE auth section.

So as it was explained, in order for OVH to properly authenticate inbound calls to you they need 1) the nonce you generated and sent back to them and 2) username, password and domain/realm for the account. With #2 then #1 doesn’t matter. The nonce could be completely correct but because they don’t have a user, password, domain/realm combo to work along with the nonce the auth is going to fail.

You need to answer the very simple question “Does OVH support inbound authentication?”

1 Like
#17

Here’s the inbound (to me from OVH) call attempt:
[Feb 15 11:01:04] <— Received SIP request (1180 bytes) from UDP:91.121.129.20:5060 —>
[Feb 15 11:01:04] INVITE sip:ovh_incoming@192.168.1.31:5060;transport=udp SIP/2.0
[Feb 15 11:01:04] Authorization: Digest username=“anonymous”,realm=“sip.ovh.fr”,nonce=“1550224864/d9720bbd0c766b3b956b0d228089acbf”,uri=“sip:ovh_incoming@192.168.1.31:5060”,response=“5a02ebfaa8661b7aef199c0891ac747e”,algorithm=MD5,opaque=“55fda9c7150dadf0”
[Feb 15 11:01:04] Call-ID: 12672-IU-84b8fe63-6b3b9c4f6@sip.ovh.fr
[Feb 15 11:01:04] Contact: sip:10.7.1.60:5060
[Feb 15 11:01:04] Content-Type: application/sdp
[Feb 15 11:01:04] CSeq: 75456641 INVITE
[Feb 15 11:01:04] From: “De 0478754157” sip:0478754157@sip.ovh.fr;user=phone;tag=12672-AH-84b8fe64-584eb7154
[Feb 15 11:01:04] Max-Forwards: 29
[Feb 15 11:01:04] Record-Route: sip:91.121.129.20:5060;lr
[Feb 15 11:01:04] To: sip:0972306227@10.7.1.60;user=phone
[Feb 15 11:01:04] Via: SIP/2.0/UDP 91.121.129.20:5060;branch=z9hG4bK-OOIB-027651cb-48de146a
[Feb 15 11:01:04] Allow: REFER,INVITE,NOTIFY,ACK,UPDATE,OPTIONS,REGISTER,SUBSCRIBE,NOTIFY,CANCEL,BYE,PRACK
[Feb 15 11:01:04] User-Agent: Cirpack/v4.76 (gw_sip)
[Feb 15 11:01:04] Content-Length: 319
[Feb 15 11:01:04]
[Feb 15 11:01:04] v=0
[Feb 15 11:01:04] o=cp10 155022486480 155022486480 IN IP4 193.251.121.115
[Feb 15 11:01:04] s=SIP Call
[Feb 15 11:01:04] c=IN IP4 91.121.129.141
[Feb 15 11:01:04] t=0 0
[Feb 15 11:01:04] m=audio 31806 RTP/AVP 8 18 0 101
[Feb 15 11:01:04] b=AS:82
[Feb 15 11:01:04] a=rtpmap:8 PCMA/8000/1
[Feb 15 11:01:04] a=rtpmap:18 G729/8000/1
[Feb 15 11:01:04] a=fmtp:18 annexb=no
[Feb 15 11:01:04] a=rtpmap:0 PCMU/8000/1
[Feb 15 11:01:04] a=rtpmap:101 telephone-event/8000
[Feb 15 11:01:04] a=fmtp:101 0-15
[Feb 15 11:01:04] a=ptime:20
[Feb 15 11:01:04] a=sendrecv
[Feb 15 11:01:04]
[Feb 15 11:01:04] NOTICE[2713]: res_pjsip/pjsip_distributor.c:672 log_failed_request: Request ‘INVITE’ from ‘“De 0478754157” sip:0478754157@sip.ovh.fr;user=phone’ failed for ‘91.121.129.20:5060’ (callid: 12672-IU-84b8fe63-6b3b9c4f6@sip.ovh.fr) - Failed to authenticate
[Feb 15 11:01:04] <— Transmitting SIP response (621 bytes) to UDP:91.121.129.20:5060 —>
[Feb 15 11:01:04] SIP/2.0 401 Unauthorized
[Feb 15 11:01:04] Via: SIP/2.0/UDP 91.121.129.20:5060;rport=5060;received=91.121.129.20;branch=z9hG4bK-OOIB-027651cb-48de146a
[Feb 15 11:01:04] Record-Route: sip:91.121.129.20:5060;lr
[Feb 15 11:01:04] Call-ID: 12672-IU-84b8fe63-6b3b9c4f6@sip.ovh.fr
[Feb 15 11:01:04] From: “De 0478754157” sip:0478754157@sip.ovh.fr;user=phone;tag=12672-AH-84b8fe64-584eb7154
[Feb 15 11:01:04] To: sip:0972306227@10.7.1.60;user=phone;tag=z9hG4bK-OOIB-027651cb-48de146a
[Feb 15 11:01:04] CSeq: 75456641 INVITE
[Feb 15 11:01:04] WWW-Authenticate: Digest realm=“sip.ovh.fr”,nonce=“1550224864/d9720bbd0c766b3b956b0d228089acbf”,opaque=“67b344ab3c4bc7c3”,algorithm=md5,qop=“auth”
[Feb 15 11:01:04] Server: Asterisk PBX 16.1.1
[Feb 15 11:01:04] Content-Length: 0
[Feb 15 11:01:04]
[Feb 15 11:01:04]
[Feb 15 11:01:04] <— Received SIP request (417 bytes) from UDP:91.121.129.20:5060 —>
[Feb 15 11:01:04] ACK sip:ovh_incoming@192.168.1.31:5060;transport=udp SIP/2.0
[Feb 15 11:01:04] Call-ID: 12672-IU-84b8fe63-6b3b9c4f6@sip.ovh.fr
[Feb 15 11:01:04] CSeq: 75456641 ACK
[Feb 15 11:01:04] From: “De 0478754157” sip:0478754157@sip.ovh.fr;user=phone;tag=12672-AH-84b8fe64-584eb7154
[Feb 15 11:01:04] Max-Forwards: 29
[Feb 15 11:01:04] To: sip:0972306227@10.7.1.60;user=phone;tag=z9hG4bK-OOIB-027651cb-48de146a
[Feb 15 11:01:04] Via: SIP/2.0/UDP 91.121.129.20:5060;branch=z9hG4bK-OOIB-027651cb-48de146a
[Feb 15 11:01:04] Content-Length: 0

#18

You’re still not answering the BASIC question that has been posed. Does OVH support this? Until you actually answer this question posting these debugs is pointless. We see what is happening, proper authentication transactions based on your forcing auth on inbound calls. So does OVH have the right details to respond to your challenge? Because if they don’t it’s going to continue to fail unless they have the right creds or you stop authing inbound calls.

The latter should be the right option.