Hi Bob,
Well, the logs cover only the challenge part, the handling of the
REGISTER without any credentials - this is the first normal step in the
digest auth process.
As per log, no Auth hdrs are found in the incoming REGISTER and a
challenge reply is built and sent back (see the last log line below):
Sep 6 11:34:42 [4299] DBG:core:pv_get_authattr: no
[Proxy-]Authorization header
Sep 6 11:34:42 [4299] [e5f4a8407663e4f7a3970][<null>]@[<null>] -
Processing registrationSep 6 11:34:42 [4299] DBG:core:parse_headers:
flags=4000
Sep 6 11:34:42 [4299] DBG:auth:pre_auth: credentials with given realm
not found
Sep 6 11:34:42 [4299] DBG:auth:reserve_nonce_index: second= 19,
sec_monit= 22, index= 36
Sep 6 11:34:42 [4299] DBG:auth:challenge: nonce index= 36
Sep 6 11:34:42 [4299] DBG:auth:build_auth_hf: 'WWW-Authenticate: Digest
realm="23.253.166.155",
nonce="945VEH4DrBNkbwzJOMTyiEbNih+ChrtOdEF1sn9J0QAA", qop="auth",
algorithm=MD5
But normally it should be a second incoming REGISTER (as response to the
challenge) with credentials this time. Do you have the logs from both
REGISTER requests and eventually the SIP capture for them?
Best regards,
Bogdan-Andrei Iancu
OpenSIPS Founder and Developer
https://www.opensips-solutions.com
OpenSIPS Summit 27-30 Sept 2022, Athens
https://www.opensips.org/events/Summit-2022Athens/
On 9/6/22 9:47 PM, Bob Atkins wrote:
Hi Iancu,
Thank you very much for your reply. Please ignore my previous message
- it got sent prematurely.
Like you, I am mystified by the fact that it says that it cannot find
the domain realm when it is actually in the table.
Keep in mind that I changed the code to specifically see the return
result from www_authorize in my earlier tests and found that
www_authorize returns [-4] which means (no credentials) - credentials
were not found in request. WHy is it returning a -4?? Why is that -4
being passing the if (!www_authorize("", "subscriber")) { statement in
the first place. It should not fall through to the challenge with a -4
return.
There is also no reason why the credentials should not be there - they
have certainly not been consumed before this point.
Here is the subscriber table entry for reference:
id;username;domain;password;cr_preferred_carrier;first_name;last_name;phone;email_address;datetime_created;datetime_modified;confirmation;flag;sendnotification;greeting;allow_find;timezone;customerID;customerName;ha1;ha1_sha256;ha1_sha512t256;rpid
1;3105738133;sip.rs.digidial.net;xxxxxxx;\N;PPC
Home;Fax;3105738133;b...@planeparts.com;2012-07-05 16:36:13;2021-11-07
13:58:34;;0;;;;;72;DigiLink Internet Services;;;;\N
I would like to point out that the /_*exact same configuration*_/
works properly in OpenSER v1.1 with exactly the same database table
and entry
I tried your suggestion (see code snipet below) and still no joy...
All that was accomplished was the realm got set to the ip server's SRV
name 'sip.rs.digidial.net' (see debug output below).
if (!www_authorize("", "subscriber")) {
#xlog("L_INFO","CHALLENGE: [$ft][$tt]");
www_challenge("", "auth,auth-int",
"MD5,MD5-sess,SHA-256,SHA-256-sess");
exit;
} else {
#xlog("L_ALERT", "REGISTER: URI [$tu] - FAILED");
xlog("L_ALERT", "REGISTER: URI [$tu][$rU]$ru
credential from [$si] - FAILED!");
sl_send_reply(403, "Not Authorized!");
exit;
}
I left the subscriber table entry as above and the test failed. I
changed the domain of the subscriber to sip.rs.digidial.net and it
still failed with exactly the same message - see below.
Debug output:
Sep 6 11:34:42 [4299] DBG:core:parse_msg: SIP Request:
Sep 6 11:34:42 [4299] DBG:core:parse_msg: method: <REGISTER>
Sep 6 11:34:42 [4299] DBG:core:parse_msg: uri: <sip:23.253.166.155:5060>
Sep 6 11:34:42 [4299] DBG:core:parse_msg: version: <SIP/2.0>
Sep 6 11:34:42 [4299] DBG:core:parse_headers: flags=ffffffffffffffff
Sep 6 11:34:42 [4299] DBG:core:_parse_to: end of header reached, state=10
Sep 6 11:34:42 [4299] DBG:core:_parse_to: display={},
ruri={sip:3970@23.253.166.155}
Sep 6 11:34:42 [4299] DBG:core:get_hdr_field: <To> [27];
uri=[sip:3970@23.253.166.155]
Sep 6 11:34:42 [4299] DBG:core:get_hdr_field: to body
[<sip:3970@23.253.166.155>
]
Sep 6 11:34:42 [4299] DBG:core:parse_via_param: found param type 232,
<branch> = <z9hG4bK-d87543-8552422463970-1--d87543->; state=6
Sep 6 11:34:42 [4299] DBG:core:parse_via_param: found param type 235,
<rport> = <n/a>; state=17
Sep 6 11:34:42 [4299] DBG:core:parse_via: end of header reached, state=5
Sep 6 11:34:42 [4299] DBG:core:parse_headers: via found,
flags=ffffffffffffffff
Sep 6 11:34:42 [4299] DBG:core:parse_headers: this is the first via
Sep 6 11:34:42 [4299] DBG:core:get_hdr_field: cseq <CSeq>: <1> <REGISTER>
Sep 6 11:34:42 [4299] DBG:core:get_hdr_field: content_length=0
Sep 6 11:34:42 [4299] DBG:core:get_hdr_field: found end of header
Sep 6 11:34:42 [4299] DBG:core:receive_msg: After parse_msg...
Sep 6 11:34:42 [4299] DBG:core:receive_msg: preparing to run routing
scripts...
Sep 6 11:34:42 [4299] DBG:pike:mark_node: search on branch 128
(top=0x7f6aba91fb08)
Sep 6 11:34:42 [4299] DBG:pike:mark_node: only first 1 were matched!
Sep 6 11:34:42 [4299] DBG:pike:pike_check_req: src IP
[128.90.81.216],node=0x7f6aba91fb08; hits=[0,1],[0,0] node_flags=2
func_flags=8
Sep 6 11:34:42 [4299] DBG:maxfwd:is_maxfwd_present: value = 70
Sep 6 11:34:42 [4299] DBG:core:comp_scriptvar: int 27: 501 / 2048
Sep 6 11:34:42 [4299] DBG:core:parse_to_param: tag=e5f4a8407663e4f7a3970
Sep 6 11:34:42 [4299] DBG:core:parse_to_param: end of header reached,
state=11
Sep 6 11:34:42 [4299] DBG:core:_parse_to: end of header reached, state=29
Sep 6 11:34:42 [4299] DBG:core:_parse_to: display={},
ruri={sip:3970@23.253.166.155}
Sep 6 11:34:42 [4299] DBG:core:parse_headers: flags=78
Sep 6 11:34:42 [4299] DBG:core:parse_headers: flags=200
Sep 6 11:34:42 [4299] DBG:rr:find_first_route: No Route headers found
Sep 6 11:34:42 [4299] DBG:rr:loose_route: There is no Route HF
Sep 6 11:34:42 [4299] DBG:core:comp_scriptvar: ip 20: 128.90.81.216
Sep 6 11:34:42 [4299] DBG:core:comp_scriptvar: ip 20: 128.90.81.216
Sep 6 11:34:42 [4299] DBG:core:comp_scriptvar: ip 20: 128.90.81.216
Sep 6 11:34:42 [4299] DBG:core:comp_scriptvar: ip 20: 128.90.81.216
Sep 6 11:34:42 [4299] DBG:core:comp_scriptvar: ip 20: 128.90.81.216
Sep 6 11:34:42 [4299] DBG:core:comp_scriptvar: ip 20: 128.90.81.216
Sep 6 11:34:42 [4299] DBG:core:comp_scriptvar: ip 20: 128.90.81.216
Sep 6 11:34:42 [4299] DBG:core:comp_scriptvar: ip 20: 128.90.81.216
Sep 6 11:34:42 [4299] DBG:core:comp_scriptvar: ip 20: 128.90.81.216
Sep 6 11:34:42 [4299] DBG:core:comp_scriptvar: ip 20: 128.90.81.216
Sep 6 11:34:42 [4299] DBG:core:comp_scriptvar: ip 20: 128.90.81.216
Sep 6 11:34:42 [4299] DBG:core:comp_scriptvar: ip 20: 128.90.81.216
Sep 6 11:34:42 [4299] DBG:core:comp_scriptvar: ip 20: 128.90.81.216
Sep 6 11:34:42 [4299] DBG:core:comp_scriptvar: ip 20: 128.90.81.216
Sep 6 11:34:42 [4299] DBG:core:comp_scriptvar: ip 20: 128.90.81.216
Sep 6 11:34:42 [4299] DBG:core:comp_scriptvar: ip 20: 128.90.81.216
Sep 6 11:34:42 [4299] DBG:core:comp_scriptvar: ip 20: 128.90.81.216
Sep 6 11:34:42 [4299] DBG:core:comp_scriptvar: ip 20: 128.90.81.216
Sep 6 11:34:42 [4299] DBG:core:comp_scriptvar: ip 20: 128.90.81.216
Sep 6 11:34:42 [4299] DBG:core:comp_scriptvar: ip 20: 128.90.81.216
Sep 6 11:34:42 [4299] DBG:core:comp_scriptvar: ip 20: 128.90.81.216
Sep 6 11:34:42 [4299] DBG:core:comp_scriptvar: ip 20: 128.90.81.216
Sep 6 11:34:42 [4299] DBG:core:comp_scriptvar: ip 20: 128.90.81.216
Sep 6 11:34:42 [4299] DBG:core:comp_scriptvar: ip 20: 128.90.81.216
Sep 6 11:34:42 [4299] DBG:core:comp_scriptvar: ip 20: 128.90.81.216
Sep 6 11:34:42 [4299] DBG:core:comp_scriptvar: ip 20: 128.90.81.216
Sep 6 11:34:42 [4299] DBG:core:comp_scriptvar: ip 20: 128.90.81.216
Sep 6 11:34:42 [4299] DBG:core:comp_scriptvar: ip 20: 128.90.81.216
Sep 6 11:34:42 [4299] DBG:core:comp_scriptvar: ip 20: 128.90.81.216
Sep 6 11:34:42 [4299] DBG:core:comp_scriptvar: ip 20: 128.90.81.216
Sep 6 11:34:42 [4299] DBG:core:comp_scriptvar: ip 20: 128.90.81.216
Sep 6 11:34:42 [4299] DBG:core:comp_scriptvar: ip 20: 128.90.81.216
Sep 6 11:34:42 [4299] DBG:core:comp_scriptvar: ip 20: 128.90.81.216
Sep 6 11:34:42 [4299] DBG:core:comp_scriptvar: ip 20: 128.90.81.216
Sep 6 11:34:42 [4299] Unknown source [128.90.81.216]:
[sip:3970@23.253.166.155] requestSep 6 11:34:42 [4299]
DBG:core:pv_get_xto_attr: no Tag parameter
Sep 6 11:34:42 [4299] REGISTER: [e5f4a8407663e4f7a3970][<null>] from
[128.90.81.216] with private IP
Sep 6 11:34:42 [4299] DBG:core:parse_headers: flags=ffffffffffffffff
Sep 6 11:34:42 [4299] REGISTER: [sip:3970@23.253.166.155] request
from [128.90.81.216]Sep 6 11:34:42 [4299] DBG:core:parse_headers:
flags=14000
Sep 6 11:34:42 [4299] DBG:core:pv_get_authattr: no
[Proxy-]Authorization header
Sep 6 11:34:42 [4299] DBG:core:parse_headers: flags=14000
Sep 6 11:34:42 [4299] DBG:core:pv_get_authattr: no
[Proxy-]Authorization header
Sep 6 11:34:42 [4299] [e5f4a8407663e4f7a3970][<null>]@[<null>] -
Processing registrationSep 6 11:34:42 [4299] DBG:core:parse_headers:
flags=4000
Sep 6 11:34:42 [4299] DBG:auth:pre_auth: credentials with given realm
not found
Sep 6 11:34:42 [4299] DBG:auth:reserve_nonce_index: second= 19,
sec_monit= 22, index= 36
Sep 6 11:34:42 [4299] DBG:auth:challenge: nonce index= 36
Sep 6 11:34:42 [4299] DBG:auth:build_auth_hf: 'WWW-Authenticate:
Digest realm="23.253.166.155",
nonce="945VEH4DrBNkbwzJOMTyiEbNih+ChrtOdEF1sn9J0QAA", qop="auth",
algorithm=MD5
'
Sep 6 11:34:42 [4299] DBG:core:MD5StringArray: MD5 calculated:
0b6da20be8b2692d9be0bd02e8c1b4c1
Sep 6 11:34:42 [4299] DBG:core:parse_headers: flags=ffffffffffffffff
Sep 6 11:34:42 [4299] DBG:core:destroy_avp_list: destroying list (nil)
Sep 6 11:34:42 [4299] DBG:core:receive_msg: cleaning up
Thank you,
Bob
On 9/6/2022 1:40 AM, Bogdan-Andrei Iancu wrote:
Hi Bob,
The key log is this one:
Aug 30 18:19:05 [17809] DBG:auth:pre_auth: credentials with given
realm not found
Basically OpenSIPS says it does not find the "digilink.net" realm in
the provided auth header in REGISTER. As a quick experiment, could
you use the empty string "" for realm (instead of "digilink.net") in
the www_authorize/challenge() functions ?
Best regards,
Bogdan-Andrei Iancu
OpenSIPS Founder and Developer
https://www.opensips-solutions.com
OpenSIPS Summit 27-30 Sept 2022, Athens
https://www.opensips.org/events/Summit-2022Athens/
On 8/31/22 4:31 AM, Bob Atkins wrote:
Hi.
Have been a long time OpenSER user in a production environment.
I managed to convert to OpenSIPS v3.2.8 on a CentOS 7 system and is
working based on IP authentication however, I just cannot get sip
registrations to work that used to work fine with OpenSER. I'm using
a SPA112 running 1.4.1(SR5) as a test device. This device registers
just fine with Asterisk and OpenSER v1.1 with exactly the same
credentials but no matter what I have tried it just won't register
with OpenSIPS v3.2.8.
I am using auth_db and mysql. I have verified that all sql data is
correct.
I have been banging my head against the screen for hours to no avail.
In reviewing the debug and log output I can clearly see that
something is wrong because the user name and domain are both <null>?
www_authorize returns [-4] which means (no credentials) -
credentials were not found in request.
There is no reason why the credentials should not be there - they
have certainly not been consumed before this point.
This same device registers just fine with /_*exactly *_/the same
credentials to both OpenSER v1.1 and asterisk servers.
Would be grateful if anyone can shed some light on this because it
seems to me that something inside auth or auth_db is broken and not
extracting the registration credentials from the REGISTER message.
_______________________________________________
Users mailing list
Users@lists.opensips.org
http://lists.opensips.org/cgi-bin/mailman/listinfo/users
