[OpenSIPS-Users] Cannot get registration to work with v3.2.8??

Bogdan-Andrei Iancu bogdan at opensips.org
Wed Sep 7 06:16:12 UTC 2022


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;bob at 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 at 23.253.166.155}
> Sep  6 11:34:42 [4299] DBG:core:get_hdr_field: <To> [27]; 
> uri=[sip:3970 at 23.253.166.155]
> Sep  6 11:34:42 [4299] DBG:core:get_hdr_field: to body 
> [<sip:3970 at 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 at 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 at 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 at 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.

-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.opensips.org/pipermail/users/attachments/20220907/95b1c0bc/attachment-0001.html>


More information about the Users mailing list