Iancu,Thank you!! You identified the problem. Turns out that I had failed to add the IP for the OpenSIPS proxy to a firewall that was blocking the response from this new sip server (facepalm) to the device :-(
So, once I fixed the firewall I thought that would be it... Not my luck.Now it is challenging and /_*rejecting!*_/ The HA1 is failing to compare! But the passwords are correct! Now I am really mystified.
I created identical DB entries for this unit in both the original OpenSER system and the OpenSIPS system.
Registration to the OpenSER system works perfectly - HA1 validates. When I change the sip server to the new system, to OpenSIPS system fails due to mismatched HA1. Whaaa.... ?!?!
Mismatched HA1 would imply a password failure but I have absolutely, positively verified the passwords in both database entries and the /_*only*_/ thing I change on the device is the sip server. It should just register on the new system. I have attached packet capture of the transaction between the device and teh OpenSIPSs system.
I have absolutely, positively copied and pasted (no trailing nl or spaces) and verified that the passwords are the same in both databases and also the same on the device.
OpenSER DB subscriber entery
phplib_id username domain password first_name last_name phone
email_address datetime_created datetime_modified confirmation flag
sendnotification greeting ha1 ha1b allow_find timezone rpid domn
uuid customerID customerName
3105738133 3105738133 digilink.net XXXXXXXX PPC Home
Fax 3105738133
7/5/2012 16:36 11/7/2021 13:58
o
0 \N \N \N \N 72 DigiLink Internet
Services
OpenSIPS DB subscriber entry
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 digidial XXXXXXXX \N PPC Home Fax 3105738133
[email protected] 7/5/2012 16:36 11/7/2021 13:58
0
72 DigiLink Internet Services \N
Registration code:
OpenSER system:
modparam("auth_db", "calculate_ha1", yes)
modparam("auth_db", "password_column", "password")
if (method=="REGISTER") {
#xlog("L_INFO","[$rm][$ft][$tt] Processing
registration");
if (!www_authorize("digilink.net", "subscriber")) {
#xlog("L_INFO","[$rm][$ft][$tt]
Challenging peer");
www_challenge("digilink.net", "0");
exit;
};
xlog("L_INFO","[$rm][$ft][$tt] Registered $fu from
$si");
save("location");
exit;
};
==============
OpenSIPS system
#### AUTH Db module
loadmodule "auth.so"
loadmodule "auth_db.so"
modparam("auth_db", "calculate_ha1", 1)
modparam("auth_db", "use_domain", 1)
modparam("auth_db", "user_column", "username")
modparam("auth_db", "password_column", "password")
modparam("auth_db", "load_credentials", "")
if (is_method("REGISTER")) {
xlog("L_INFO", "REGISTER: [$tu] request from [$si]");
xlog("L_INFO","[$ft][$au]@[$ad] - Processing registration");
xlog("L_INFO", "REGISTER: www_authorize returned [$var(x)]
to authenticate with [$rU]$ru credential");
if (!www_authorize("digilink.net", "subscriber")) {
xlog("L_INFO","CHALLENGE: [$ft][$tt]");
www_challenge("digilink.net","auth","MD5");
exit;
} else {
xlog("L_ALERT", "REGISTER: URI [$tu][$rU]$ru credential
from [$si] - FAILED!");
sl_send_reply(403, "Not Authorized!"); exit; }xlog("L_INFO", "REGISTER: URI [$tu] - [$rm][$ft][$tt] Registered $fu from $si");
save("location");
exit;
}
Debug output:
Sep 7 09:42:09 [5640] DBG:core:parse_msg: SIP Request:
Sep 7 09:42:09 [5640] DBG:core:parse_msg: method: <REGISTER>
Sep 7 09:42:09 [5640] DBG:core:parse_msg: uri: <sip:sip.rs.digidial.net>
Sep 7 09:42:09 [5640] DBG:core:parse_msg: version: <SIP/2.0>
Sep 7 09:42:09 [5640] DBG:core:parse_headers: flags=ffffffffffffffff
Sep 7 09:42:09 [5640] DBG:core:parse_via_param: found param type 232,
<branch> = <z9hG4bK-b316ab8b>; state=16
Sep 7 09:42:09 [5640] DBG:core:parse_via: end of header reached, state=5Sep 7 09:42:09 [5640] DBG:core:parse_headers: via found, flags=ffffffffffffffff
Sep 7 09:42:09 [5640] DBG:core:parse_headers: this is the first via Sep 7 09:42:09 [5640] DBG:core:_parse_to: end of header reached, state=10Sep 7 09:42:09 [5640] DBG:core:_parse_to: display={"PPC Fax"}, ruri={sip:[email protected]} Sep 7 09:42:09 [5640] DBG:core:get_hdr_field: <To> [48]; uri=[sip:[email protected]] Sep 7 09:42:09 [5640] DBG:core:get_hdr_field: to body ["PPC Fax" <sip:[email protected]>
]Sep 7 09:42:09 [5640] DBG:core:get_hdr_field: cseq <CSeq>: <86966> <REGISTER>
Sep 7 09:42:09 [5640] DBG:core:get_hdr_field: content_length=0 Sep 7 09:42:09 [5640] DBG:core:get_hdr_field: found end of header Sep 7 09:42:09 [5640] DBG:core:receive_msg: After parse_msg...Sep 7 09:42:09 [5640] DBG:core:receive_msg: preparing to run routing scripts... Sep 7 09:42:09 [5640] DBG:pike:mark_node: search on branch 205 (top=0x7f90f8b40bd8)
Sep 7 09:42:09 [5640] DBG:pike:mark_node: only first 1 were matched!Sep 7 09:42:09 [5640] DBG:pike:pike_check_req: src IP [205.147.62.19],node=0x7f90f8b40bd8; hits=[0,3],[0,0] node_flags=2 func_flags=8
Sep 7 09:42:09 [5640] DBG:maxfwd:is_maxfwd_present: value = 70 Sep 7 09:42:09 [5640] DBG:core:comp_scriptvar: int 27: 833 / 2048 Sep 7 09:42:09 [5640] DBG:core:parse_to_param: tag=30079e2fdf731b79o1Sep 7 09:42:09 [5640] DBG:core:parse_to_param: end of header reached, state=11
Sep 7 09:42:09 [5640] DBG:core:_parse_to: end of header reached, state=29Sep 7 09:42:09 [5640] DBG:core:_parse_to: display={"PPC Fax"}, ruri={sip:[email protected]}
Sep 7 09:42:09 [5640] DBG:core:parse_headers: flags=78 Sep 7 09:42:09 [5640] DBG:core:parse_headers: flags=200 Sep 7 09:42:09 [5640] DBG:rr:find_first_route: No Route headers found Sep 7 09:42:09 [5640] DBG:rr:loose_route: There is no Route HF ... [snip]Sep 7 09:42:09 [5640] Unknown source [205.147.62.19]: [sip:[email protected]] request
Sep 7 09:42:09 [5640] DBG:core:parse_headers: flags=ffffffffffffffffSep 7 09:42:09 [5640] DBG:core:parse_params: Parsing params for:[expires=300] Sep 7 09:42:09 [5640] REGISTER: [sip:[email protected]] request from [205.147.62.19]
Sep 7 09:42:09 [5640] DBG:core:parse_headers: flags=14000 Sep 7 09:42:09 [5640] DBG:core:parse_headers: flags=14000Sep 7 09:42:09 [5640] [30079e2fdf731b79o1][3105738133]@[<null>] - Processing registration Sep 7 09:42:09 [5640] REGISTER: www_authorize returned [<null>] to authenticate with [<null>]sip:sip.rs.digidial.net credentialSep 7 09:42:09 [5640] DBG:auth:pre_auth: nonce index= 1
Sep 7 09:42:09 [5640] DBG:db_mysql:has_stmt_ctx: ctx found for subscriberSep 7 09:42:09 [5640] DBG:db_mysql:db_mysql_do_prepared_query: conn=0x7f90fa86ac90 (tail=140260655146496) MC=0x7f90fa86a698 Sep 7 09:42:09 [5640] DBG:db_mysql:db_mysql_do_prepared_query: set values for the statement run Sep 7 09:42:09 [5640] DBG:db_mysql:db_mysql_val2bind: added val (0): len=10; type=254; is_null=0 Sep 7 09:42:09 [5640] DBG:db_mysql:db_mysql_val2bind: added val (1): len=12; type=254; is_null=0 Sep 7 09:42:09 [5640] DBG:db_mysql:db_mysql_do_prepared_query: doing BIND_PARAM in... Sep 7 09:42:09 [5640] DBG:db_mysql:mysql_raise_event: MySQL status has not changed: connected Sep 7 09:42:09 [5640] DBG:db_mysql:db_mysql_do_prepared_query: prepared statement has 1 columns in result Sep 7 09:42:09 [5640] DBG:core:db_new_result: allocate 48 bytes for result set at 0x7f90fa86cb98 Sep 7 09:42:09 [5640] DBG:db_mysql:db_mysql_get_columns: 1 columns returned from the query Sep 7 09:42:09 [5640] DBG:core:db_allocate_columns: allocate 28 bytes for result columns at 0x7f90fa86d480 Sep 7 09:42:09 [5640] DBG:db_mysql:db_mysql_get_columns: RES_NAMES(0x7f90fa86d488)[0]=[ha1] Sep 7 09:42:09 [5640] DBG:db_mysql:db_mysql_get_columns: use DB_STRING result type Sep 7 09:42:09 [5640] DBG:core:db_allocate_rows: allocate 48 bytes for result rows and values at 0x7f90fa86c170
Sep 7 09:42:09 [5640] DBG:db_mysql:db_mysql_str2val: converting STRING []Sep 7 09:42:09 [5640] DBG:auth_db:get_ha1: _*HA1 string calculated: 115137ac8cc974c418c92e51dfb4fffb*_ Sep 7 09:42:09 [5640] DBG:auth:check_response: *_our result = '841dc25d395e34bab3c0251e200b38f9'_*
Sep 7 09:42:09 [5640] DBG:auth:check_response: _*authorization failed*_Sep 7 09:42:09 [5640] DBG:core:db_free_columns: freeing result columns at 0x7f90fa86d480
Sep 7 09:42:09 [5640] DBG:core:db_free_rows: freeing 1 rowsSep 7 09:42:09 [5640] DBG:core:db_free_row: freeing row values at 0x7f90fa86c180
Sep 7 09:42:09 [5640] DBG:core:db_free_rows: freeing rows at 0x7f90fa86c170Sep 7 09:42:09 [5640] DBG:core:db_free_result: freeing result set at 0x7f90fa86cb98
Sep 7 09:42:09 [5640] DBG:core:pv_get_xto_attr: no Tag parameterSep 7 09:42:09 [5640] CHALLENGE: [30079e2fdf731b79o1][<null>]Sep 7 09:42:09 [5640] DBG:auth:reserve_nonce_index: second= 13, sec_monit= -1, index= 2
Sep 7 09:42:09 [5640] DBG:auth:challenge: nonce index= 2Sep 7 09:42:09 [5640] DBG:auth:build_auth_hf: 'WWW-Authenticate: Digest realm="digilink.net", nonce="jc2ceYLP1dzX+qS8Erm1zKIihYg6b953YdAZIa38dj4A", qop="auth", algorithm=MD5' Sep 7 09:42:09 [5640] DBG:core:MD5StringArray: MD5 calculated: a7216245b8ac903b73694b3c3949959b
Sep 7 09:42:09 [5640] DBG:core:parse_headers: flags=ffffffffffffffff Sep 7 09:42:09 [5640] DBG:core:destroy_avp_list: destroying list (nil) Sep 7 09:42:09 [5640] DBG:core:receive_msg: cleaning up -- *Bob Atkins * /President/CEO/ *DigiLink, Inc. <http://www.digilink.net>* Business Inter-net-working */The Cure for the Common ISP!/* Phone: (310) 577-9450 Fax: (310) 577-3360 eMail: [email protected] On 9/6/2022 11:16 PM, Bogdan-Andrei Iancu wrote:
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= 36Sep 6 11:34:42 [4299] DBG:auth:challenge: nonce index= 36Sep 6 11:34:42 [4299] DBG:auth:build_auth_hf: 'WWW-Authenticate: Digest realm="23.253.166.155", nonce="945VEH4DrBNkbwzJOMTyiEbNih+ChrtOdEF1sn9J0QAA", qop="auth", algorithm=MD5But 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/
ATA-OpenSIPS-reg-failure.pkt.pcap
Description: Binary data
_______________________________________________ Users mailing list [email protected] http://lists.opensips.org/cgi-bin/mailman/listinfo/users
