[OpenSIPS-Users] LDAP Authentication
Alan Rubin
Alan.Rubin at nt.gov.au
Fri Jun 19 03:35:39 CEST 2009
(reposting to fit the list size limits)
Bogdan,
2) I removed the "!" from the REGISTER section. This seems to have at
least pushed me on to the next stage of actually doing an LDAP query:
Jun 19 10:58:18 dcshub1 /usr/local/opensips/sbin/opensips[31159]:
DBG:ldap:ldap_url_search: LDAP URL parsed into session_name
[sipaccounts], base [o=ntg], scope [2], filter
[(&(cn=oh5)(departmentNumber=66)(ntguserstatus=Active))]
Jun 19 10:58:18 dcshub1 /usr/local/opensips/sbin/opensips[31159]:
DBG:ldap:lds_search: [sipaccounts]: performing LDAP search: dn [o=ntg],
scope [2], filter
[(&(cn=oh5)(departmentNumber=66)(ntguserstatus=Active))], client_timeout
[5000000] usecs
Jun 19 10:58:18 dcshub1 /usr/local/opensips/sbin/opensips[31159]:
DBG:ldap:ldap_params_search: [sipaccounts]: [1] LDAP entries found
Jun 19 10:58:18 dcshub1 /usr/local/opensips/sbin/opensips[31159]:
DBG:auth:check_nonce: comparing
[4a3ae9d000000001b43a57f1ad95192b98ace5030eb50d1a] and
[4a3ae9d000000001b43a57f1ad95192b98ace5030eb50d1a]
Jun 19 10:58:18 dcshub1 /usr/local/opensips/sbin/opensips[31159]:
DBG:auth:reserve_nonce_index: second= 12, sec_monit= -1, index= 2
Jun 19 10:58:18 dcshub1 /usr/local/opensips/sbin/opensips[31159]:
DBG:auth:build_auth_hf: nonce index= 2
Jun 19 10:58:18 dcshub1 /usr/local/opensips/sbin/opensips[31159]:
DBG:auth:build_auth_hf: 'Proxy-Authenticate: Digest
realm="155.205.69.126",
nonce="4a3ae9d000000002c65c88df6909b9e945bdbaaa5e495b3a" '
Jun 19 10:58:18 dcshub1 /usr/local/opensips/sbin/opensips[31159]:
DBG:core:parse_headers: flags=ffffffffffffffff
Jun 19 10:58:18 dcshub1 /usr/local/opensips/sbin/opensips[31159]:
DBG:core:check_via_address: params 155.205.26.124, 155.205.26.124, 0
Jun 19 10:58:18 dcshub1 /usr/local/opensips/sbin/opensips[31159]:
DBG:core:destroy_avp_list: destroying list (nil)
Jun 19 10:58:18 dcshub1 /usr/local/opensips/sbin/opensips[31159]:
DBG:core:receive_msg: cleaning up
...
Still failing, but this time it is code 407: Proxy Authentication
Required. Getting closer?
1) Perhaps I mean "encoded" and am just using the wrong term. An
example return from our LDAP search:
userPassword: {SSHA}twmolvRuvt11fr4GVJOxIasfcGi6yci9LIEfaUQ==
Regards,
Alan Rubin
-----Original Message-----
From: Bogdan-Andrei Iancu [mailto:bogdan at voice-system.ro]
Sent: Friday, 19 June 2009 10:52 AM
To: Alan Rubin
Cc: users at lists.opensips.org
Subject: Re: [OpenSIPS-Users] LDAP Authentication
Alan,
2 points:
1) what you mean by "encrypted" ? the module supports only ha1 encoded
passwords.
2) I see you deal with a REGISTER request, but in your script you
changed the auth (from DB to LDAP) only for INVITES - check in the
script the second auth block (for REGISTERS) and change it in the same
time as we did for the INVITEs.
Regards,
Bogdan
Alan Rubin wrote:
> Bogdan,
>
> Thanks for your help. I reset the configuration for calculate_ha1 to
0
> (it was set to 1), but I am still getting a "401 - Unauthorized"
error.
> The password returning from the LDAP server should be an encrypted
> string.
>
> # ----- auth_db params -----
> /* uncomment the following lines if you want to enable the DB based
> authentication */
> #modparam("auth_db", "calculate_ha1", yes)
> #modparam("auth_db", "password_column", "password")
> #modparam("auth_db", "db_url",
> # "mysql://opensips:<redacted>@localhost/opensips")
> #modparam("auth_db", "load_credentials", "")
>
> # ------ auth params -----
> #modparam("auth", "username_spec", "$var(username)")
> #modparam("auth", "password_spec", "$avp(s:password)")
> modparam("auth", "nonce_expire", 30)
> modparam("auth", "secret", "<redacted>")
> modparam("auth", "disable_nonce_check", 0)
> modparam("auth", "username_spec", "$var(username)")
> modparam("auth", "password_spec", "$avp(s:password)")
> modparam("auth", "calculate_ha1", 0)
>
> Here are the relevant logs from the connection (I think):
>
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27778]:
> DBG:core:parse_msg: SIP Request:
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27778]:
> DBG:core:parse_msg: method: <REGISTER>
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27778]:
> DBG:core:parse_msg: uri: <sip:155.205.69.126>
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27778]:
> DBG:core:parse_msg: version: <SIP/2.0>
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27778]:
> DBG:core:parse_headers: flags=2
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27778]:
> DBG:core:parse_via_param: found param type 232, <branch> =
> <z9hG4bK-d8754z-f2755c5f5d1c3201-1---d8754z->; state=6
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27778]:
> DBG:core:parse_via_param: found param type 235, <rport> = <n/a>;
> state=17
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27778]:
> DBG:core:parse_via: end of header reached, state=5
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27778]:
> DBG:core:parse_headers: via found, flags=2
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27778]:
> DBG:core:parse_headers: this is the first via
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27778]:
> DBG:core:receive_msg: After parse_msg...
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27778]:
> DBG:core:receive_msg: preparing to run routing scripts...
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27778]:
> DBG:core:parse_headers: flags=100
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27778]:
> DBG:maxfwd:is_maxfwd_present: value = 70
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27778]:
> DBG:core:parse_headers: flags=8
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27778]:
> DBG:core:parse_to: end of header reached, state=10
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27778]:
> DBG:core:parse_to: display={"alan"}, ruri={sip:oh5 at 155.205.69.126}
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27778]:
> DBG:core:get_hdr_field: <To> [32]; uri=[sip:oh5 at 155.205.69.126]
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27778]:
> DBG:core:get_hdr_field: to body ["alan"<sip:oh5 at 155.205.69.126> ]
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27778]:
> DBG:uri:has_totag: no totag
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27778]:
> DBG:core:parse_headers: flags=78
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27778]:
> DBG:core:get_hdr_field: cseq <CSeq>: <1> <REGISTER>
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27778]:
> DBG:tm:t_lookup_request: start searching: hash=57545, isACK=0
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27778]:
> DBG:tm:matching_3261: RFC3261 transaction matching failed
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27778]:
> DBG:tm:t_lookup_request: no transaction found
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27778]:
> DBG:core:parse_headers: flags=200
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27778]:
> DBG:core:get_hdr_field: content_length=0
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27778]:
> DBG:core:get_hdr_field: found end of header
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27778]:
> DBG:rr:find_first_route: No Route headers found
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27778]:
> DBG:rr:loose_route: There is no Route HF
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27778]:
> DBG:core:grep_sock_info: checking if host==us: 14==9 &&
> [155.205.69.126] == [127.0.0.1]
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27778]:
> DBG:core:grep_sock_info: checking if port 5060 matches port 5060
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27778]:
> DBG:core:grep_sock_info: checking if host==us: 14==14 &&
> [155.205.69.126] == [155.205.69.126]
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27778]:
> DBG:core:grep_sock_info: checking if port 5060 matches port 5060
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27778]:
> DBG:core:parse_headers: flags=4000
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27778]:
> DBG:auth:pre_auth: credentials with given realm not found
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27778]:
> DBG:auth:reserve_nonce_index: second= 3, sec_monit= -1, index= 0
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27778]:
> DBG:auth:build_auth_hf: nonce index= 0
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27778]:
> DBG:auth:build_auth_hf: 'WWW-Authenticate: Digest
> realm="155.205.69.126",
> nonce="4a3ad9b90000000032ce5a6488ce3120fce3ebb88c23cd79" '
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27778]:
> DBG:core:parse_headers: flags=ffffffffffffffff
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27778]:
> DBG:core:check_via_address: params 155.205.26.124, 155.205.26.124, 0
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27778]:
> DBG:core:destroy_avp_list: destroying list (nil)
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27778]:
> DBG:core:receive_msg: cleaning up
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27784]:
> DBG:core:parse_msg: SIP Request:
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27784]:
> DBG:core:parse_msg: method: <REGISTER>
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27784]:
> DBG:core:parse_msg: uri: <sip:155.205.69.126>
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27784]:
> DBG:core:parse_msg: version: <SIP/2.0>
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27784]:
> DBG:core:parse_headers: flags=2
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27784]:
> DBG:core:parse_via_param: found param type 232, <branch> =
> <z9hG4bK-d8754z-9520b61e7123e11e-1---d8754z->; state=6
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27784]:
> DBG:core:parse_via_param: found param type 235, <rport> = <n/a>;
> state=17
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27784]:
> DBG:core:parse_via: end of header reached, state=5
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27784]:
> DBG:core:parse_headers: via found, flags=2
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27784]:
> DBG:core:parse_headers: this is the first via
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27784]:
> DBG:core:receive_msg: After parse_msg...
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27784]:
> DBG:core:receive_msg: preparing to run routing scripts...
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27784]:
> DBG:core:parse_headers: flags=100
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27784]:
> DBG:maxfwd:is_maxfwd_present: value = 70
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27784]:
> DBG:core:parse_headers: flags=8
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27784]:
> DBG:core:parse_to: end of header reached, state=10
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27784]:
> DBG:core:parse_to: display={"alan"}, ruri={sip:oh5 at 155.205.69.126}
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27784]:
> DBG:core:get_hdr_field: <To> [32]; uri=[sip:oh5 at 155.205.69.126]
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27784]:
> DBG:core:get_hdr_field: to body ["alan"<sip:oh5 at 155.205.69.126> ]
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27784]:
> DBG:uri:has_totag: no totag
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27784]:
> DBG:core:parse_headers: flags=78
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27784]:
> DBG:core:get_hdr_field: cseq <CSeq>: <2> <REGISTER>
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27784]:
> DBG:tm:t_lookup_request: start searching: hash=57542, isACK=0
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27784]:
> DBG:tm:matching_3261: RFC3261 transaction matching failed
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27784]:
> DBG:tm:t_lookup_request: no transaction found
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27784]:
> DBG:core:parse_headers: flags=200
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27784]:
> DBG:core:get_hdr_field: content_length=0
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27784]:
> DBG:core:get_hdr_field: found end of header
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27784]:
> DBG:rr:find_first_route: No Route headers found
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27784]:
> DBG:rr:loose_route: There is no Route HF
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27784]:
> DBG:core:grep_sock_info: checking if host==us: 14==9 &&
> [155.205.69.126] == [127.0.0.1]
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27784]:
> DBG:core:grep_sock_info: checking if port 5060 matches port 5060
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27784]:
> DBG:core:grep_sock_info: checking if host==us: 14==14 &&
> [155.205.69.126] == [155.205.69.126]
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27784]:
> DBG:core:grep_sock_info: checking if port 5060 matches port 5060
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27784]:
> DBG:auth:check_nonce: comparing
> [4a3ad9b90000000032ce5a6488ce3120fce3ebb88c23cd79] and
> [4a3ad9b90000000032ce5a6488ce3120fce3ebb88c23cd79]
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27784]:
> DBG:core:db_do_query: SYNC-DBG - SELECT successfully executed!
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27784]:
> DBG:db_mysql:db_mysql_do_prepared_query: conn=0x81b2c68
(tail=135989560)
> MC=0x81b4338
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27784]:
> DBG:db_mysql:db_mysql_do_prepared_query: new query=|select ha1,rpid
from
> subscriber where username=?|
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27784]:
> DBG:db_mysql:db_mysql_do_prepared_query: prepared statement
successfully
> set...
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27784]:
> DBG:db_mysql:db_mysql_do_prepared_query: discon is 0 for 135989560
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27784]:
> DBG:db_mysql:db_mysql_do_prepared_query: set values for the statement
> run
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27784]:
> DBG:db_mysql:db_mysql_val2bind: added val (0): len=3; type=254;
> is_null=0
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27784]:
> DBG:db_mysql:db_mysql_do_prepared_query: doing BIND_PARAM in...
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27784]:
> DBG:db_mysql:db_mysql_do_prepared_query: discon reset for 135989560
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27784]:
> DBG:db_mysql:db_mysql_do_prepared_query: prepared statement has 2
> columns in result
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27784]:
> DBG:db_mysql:db_mysql_do_prepared_query: doing to BIND_PARAM out ...
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27784]:
> DBG:db_mysql:db_mysql_query: SYNC-DBG - SELECT-STMT successfully
> executed!!
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27784]:
> DBG:core:db_new_result: allocate 28 bytes for result set at 0x81b7ee0
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27784]:
> DBG:db_mysql:db_mysql_store_result: SYNC-DBG - SELECT result was
stored!
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27784]:
> DBG:db_mysql:db_mysql_get_columns: 2 columns returned from the query
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27784]:
> DBG:core:db_allocate_columns: allocate 32 bytes for result columns at
> 0x81b7f08
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27784]:
> DBG:db_mysql:db_mysql_get_columns: RES_NAMES(0x81b7f10)[0]=[ha1]
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27784]:
> DBG:db_mysql:db_mysql_get_columns: use DB_STRING result type
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27784]:
> DBG:db_mysql:db_mysql_get_columns: RES_NAMES(0x81b7f18)[1]=[rpid]
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27784]:
> DBG:db_mysql:db_mysql_get_columns: use DB_STRING result type
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27784]:
> DBG:db_mysql:db_mysql_convert_rows: no rows returned from the query
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27784]:
> DBG:auth_db:get_ha1: no result for user 'oh5@'
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27784]:
> DBG:core:db_free_columns: freeing result columns at 0x81b7f08
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27784]:
> DBG:core:db_free_rows: freeing 0 rows
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27784]:
> DBG:core:db_free_result: freeing result set at 0x81b7ee0
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27784]:
> DBG:core:db_free_result: SYNC-DBG - freeing result!
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27784]:
> DBG:auth:reserve_nonce_index: second= 4, sec_monit= -1, index= 1
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27784]:
> DBG:auth:build_auth_hf: nonce index= 1
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27784]:
> DBG:auth:build_auth_hf: 'WWW-Authenticate: Digest
> realm="155.205.69.126",
> nonce="4a3ad9b9000000012a548105ca3e174701a4abc4ca9ebe65" '
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27784]:
> DBG:core:parse_headers: flags=ffffffffffffffff
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27784]:
> DBG:core:check_via_address: params 155.205.26.124, 155.205.26.124, 0
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27784]:
> DBG:core:destroy_avp_list: destroying list (nil)
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27784]:
> DBG:core:receive_msg: cleaning up
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27781]:
> DBG:core:parse_msg: SIP Request:
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27781]:
> DBG:core:parse_msg: method: <REGISTER>
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27781]:
> DBG:core:parse_msg: uri: <sip:155.205.69.126>
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27781]:
> DBG:core:parse_msg: version: <SIP/2.0>
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27781]:
> DBG:core:parse_headers: flags=2
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27781]:
> DBG:core:parse_via_param: found param type 232, <branch> =
> <z9hG4bK-d8754z-9d36227c7e326926-1---d8754z->; state=6
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27781]:
> DBG:core:parse_via_param: found param type 235, <rport> = <n/a>;
> state=17
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27781]:
> DBG:core:parse_via: end of header reached, state=5
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27781]:
> DBG:core:parse_headers: via found, flags=2
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27781]:
> DBG:core:parse_headers: this is the first via
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27781]:
> DBG:core:receive_msg: After parse_msg...
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27781]:
> DBG:core:receive_msg: preparing to run routing scripts...
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27781]:
> DBG:core:parse_headers: flags=100
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27781]:
> DBG:maxfwd:is_maxfwd_present: value = 70
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27781]:
> DBG:core:parse_headers: flags=8
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27781]:
> DBG:core:parse_to: end of header reached, state=10
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27781]:
> DBG:core:parse_to: display={"alan"}, ruri={sip:oh5 at 155.205.69.126}
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27781]:
> DBG:core:get_hdr_field: <To> [32]; uri=[sip:oh5 at 155.205.69.126]
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27781]:
> DBG:core:get_hdr_field: to body ["alan"<sip:oh5 at 155.205.69.126> ]
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27781]:
> DBG:uri:has_totag: no totag
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27781]:
> DBG:core:parse_headers: flags=78
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27781]:
> DBG:core:get_hdr_field: cseq <CSeq>: <3> <REGISTER>
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27781]:
> DBG:tm:t_lookup_request: start searching: hash=57543, isACK=0
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27781]:
> DBG:tm:matching_3261: RFC3261 transaction matching failed
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27781]:
> DBG:tm:t_lookup_request: no transaction found
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27781]:
> DBG:core:parse_headers: flags=200
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27781]:
> DBG:core:get_hdr_field: content_length=0
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27781]:
> DBG:core:get_hdr_field: found end of header
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27781]:
> DBG:rr:find_first_route: No Route headers found
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27781]:
> DBG:rr:loose_route: There is no Route HF
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27781]:
> DBG:core:grep_sock_info: checking if host==us: 14==9 &&
> [155.205.69.126] == [127.0.0.1]
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27781]:
> DBG:core:grep_sock_info: checking if port 5060 matches port 5060
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27781]:
> DBG:core:grep_sock_info: checking if host==us: 14==14 &&
> [155.205.69.126] == [155.205.69.126]
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27781]:
> DBG:core:grep_sock_info: checking if port 5060 matches port 5060
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27781]:
> DBG:auth:check_nonce: comparing
> [4a3ad9b9000000012a548105ca3e174701a4abc4ca9ebe65] and
> [4a3ad9b9000000012a548105ca3e174701a4abc4ca9ebe65]
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27781]:
> DBG:core:db_do_query: SYNC-DBG - SELECT successfully executed!
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27781]:
> DBG:db_mysql:db_mysql_do_prepared_query: conn=0x81b2c68
(tail=135989560)
> MC=0x81b4338
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27781]:
> DBG:db_mysql:db_mysql_do_prepared_query: new query=|select ha1,rpid
from
> subscriber where username=?|
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27781]:
> DBG:db_mysql:db_mysql_do_prepared_query: prepared statement
successfully
> set...
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27781]:
> DBG:db_mysql:db_mysql_do_prepared_query: discon is 0 for 135989560
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27781]:
> DBG:db_mysql:db_mysql_do_prepared_query: set values for the statement
> run
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27781]:
> DBG:db_mysql:db_mysql_val2bind: added val (0): len=3; type=254;
> is_null=0
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27781]:
> DBG:db_mysql:db_mysql_do_prepared_query: doing BIND_PARAM in...
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27781]:
> DBG:db_mysql:db_mysql_do_prepared_query: discon reset for 135989560
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27781]:
> DBG:db_mysql:db_mysql_do_prepared_query: prepared statement has 2
> columns in result
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27781]:
> DBG:db_mysql:db_mysql_do_prepared_query: doing to BIND_PARAM out ...
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27781]:
> DBG:db_mysql:db_mysql_query: SYNC-DBG - SELECT-STMT successfully
> executed!!
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27781]:
> DBG:core:db_new_result: allocate 28 bytes for result set at 0x81b7ee0
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27781]:
> DBG:db_mysql:db_mysql_store_result: SYNC-DBG - SELECT result was
stored!
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27781]:
> DBG:db_mysql:db_mysql_get_columns: 2 columns returned from the query
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27781]:
> DBG:core:db_allocate_columns: allocate 32 bytes for result columns at
> 0x81b7f08
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27781]:
> DBG:db_mysql:db_mysql_get_columns: RES_NAMES(0x81b7f10)[0]=[ha1]
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27781]:
> DBG:db_mysql:db_mysql_get_columns: use DB_STRING result type
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27781]:
> DBG:db_mysql:db_mysql_get_columns: RES_NAMES(0x81b7f18)[1]=[rpid]
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27781]:
> DBG:db_mysql:db_mysql_get_columns: use DB_STRING result type
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27781]:
> DBG:db_mysql:db_mysql_convert_rows: no rows returned from the query
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27781]:
> DBG:auth_db:get_ha1: no result for user 'oh5@'
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27781]:
> DBG:core:db_free_columns: freeing result columns at 0x81b7f08
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27781]:
> DBG:core:db_free_rows: freeing 0 rows
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27781]:
> DBG:core:db_free_result: freeing result set at 0x81b7ee0
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27781]:
> DBG:core:db_free_result: SYNC-DBG - freeing result!
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27781]:
> DBG:auth:reserve_nonce_index: second= 4, sec_monit= -1, index= 2
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27781]:
> DBG:auth:build_auth_hf: nonce index= 2
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27781]:
> DBG:auth:build_auth_hf: 'WWW-Authenticate: Digest
> realm="155.205.69.126",
> nonce="4a3ad9b900000002b64f5ef190966742551aa9531e9165f3" '
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27781]:
> DBG:core:parse_headers: flags=ffffffffffffffff
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27781]:
> DBG:core:check_via_address: params 155.205.26.124, 155.205.26.124, 0
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27781]:
> DBG:core:destroy_avp_list: destroying list (nil)
> Jun 19 09:49:39 dcshub1 /usr/local/opensips/sbin/opensips[27781]:
> DBG:core:receive_msg: cleaning up
> ...
>
>
> And here are the changes I made to the main route, for the benefit of
> anyone else who might have an idea for me:
>
> if (!(method=="REGISTER") && from_uri==myself) { /*no
> multidomain version*/
> # are any credentials available in the request ?
> if (!is_present_hf("Proxy-Authorization")) {
> proxy_challenge("", "0");
> exit;
> }
>
> # run the ldap_query() and load the passwd into
> $avp(s:password)
> # TODO
> $var(username)=$fU;
>
>
ldap_search("ldap://sipaccounts/o=ntg??sub?(&(cn=$fU)(departmentNumber=6
> 6)(ntguserstatus=Active))");
> ldap_result("userPassword/$avp(s:password)");
>
> # username to authenticate
> #$var(username) = $fU;
>
> # do the authentication
> if(!pv_proxy_authorize("")){
> proxy_challenge("", "0");
> exit;
> }
>
> Regards,
>
> Alan Rubin
>
> -----Original Message-----
> From: Bogdan-Andrei Iancu [mailto:bogdan at voice-system.ro]
> Sent: Friday, 19 June 2009 9:42 AM
> To: Alan Rubin; users at lists.opensips.org
> Subject: Re: [OpenSIPS-Users] LDAP Authentication
>
> HI Alan,
>
> sorry for the late reply - this week we have the OpenSIPS bootcamp and
> I'm getting my hands on the emails only from time to time..
>
> So, Are you loading the passwd in raw format (plain text) ? If so, you
> need the calulcate_ha1 param to be set to 1
> (http://www.opensips.org/html/docs/modules/1.5.x/auth.html#id228275) -
> by default it is set to 0.... (see prev email)
>
> Regards,
> Bogdan
>
> Alan Rubin wrote:
>
>> Bogdan,
>>
>> I've attached a log from a test this morning. I restarted opensips,
>> tried connecting from my PC using LDAP credentials and failed. Then
I
>> made sure that the local account was removed and tried again with
LDAP
>> credentials and it failed. Hopefully that's all apparent in the
>> logfile. I am using the X-lite client to connect.
>>
>> Regards,
>>
>> Alan Rubin
>>
>> -----Original Message-----
>> From: Bogdan-Andrei Iancu [mailto:bogdan at voice-system.ro]
>> Sent: Wednesday, 17 June 2009 1:29 AM
>> To: Alan Rubin
>> Subject: Re: [OpenSIPS-Users] LDAP Authentication
>>
>> Hi Alan,
>>
>> the script looks ok - you can 1) use xlog just before the pv_auth()
to
>>
>
>
>> see if the user and passwd are properly filled in, or 2) use debug=6
>>
> to
>
>> get the logs and post them here.
>>
>> Regards,
>> Bogdan
>>
>> Alan Rubin wrote:
>>
>>
>>> Bogdan,
>>>
>>> If you have a minute, could you take a look at my opensips.cfg file?
>>>
>>>
>> It
>>
>>
>>> is still authorizing against the users that were added by hand. I
>>>
>>>
>> have
>>
>>
>>> probably put the LDAP authentication in the wrong place, but I seem
>>>
> to
>
>>> be going in circles.
>>>
>>> Also, I used some of the template from Tristan Mahe for readability
>>>
> (I
>
>>> adapted his LDAP search examples and used his variable names). I
>>>
>>>
>> don't
>>
>>
>>> think this is my issue, but it could be.
>>>
>>> Thanks for your time,
>>>
>>>
>>> Alan Rubin
More information about the Users
mailing list