/** Print errors raised by OpenSSL I/O functions
*
* Drains the thread local OpenSSL error queue, and prints out errors
* based on the SSL handle and the return code of the I/O function.
*
* OpenSSL lists I/O functions to be:
* - SSL_connect
* - SSL_accept
* - SSL_do_handshake
* - SSL_read
* - SSL_peek
* - SSL_write
*
* @param request The current request (may be NULL).
* @param session The current tls_session.
* @param ret from the I/O operation.
* @param msg Error message describing the operation being attempted.
* @param ... Arguments for msg.
* @return
* - 0 TLS session may still be viable.
* - -1 TLS session cannot continue.
*/
int tls_log_io_error(REQUEST *request, tls_session_t *session, int ret, char const *msg, ...)
{
int error;
va_list ap;
if (ERR_peek_error()) {
va_start(ap, msg);
tls_log_error_va(request, msg, ap);
va_end(ap);
}
error = SSL_get_error(session->ssl, ret);
switch (error) {
/*
* These seem to be harmless and already "dealt
* with" by our non-blocking environment. NB:
* "ZERO_RETURN" is the clean "error"
* indicating a successfully closed SSL
* tunnel. We let this happen because our IO
* loop should not appear to have broken on
* this condition - and outside the IO loop, the
* "shutdown" state is checked.
*
* Don't print anything if we ignore the error.
*/
case SSL_ERROR_NONE:
case SSL_ERROR_WANT_READ:
case SSL_ERROR_WANT_WRITE:
case SSL_ERROR_WANT_X509_LOOKUP:
case SSL_ERROR_ZERO_RETURN:
break;
/*
* These seem to be indications of a genuine
* error that should result in the SSL tunnel
* being regarded as "dead".
*/
case SSL_ERROR_SYSCALL:
ROPTIONAL(REDEBUG, ERROR, "System call (I/O) error (%i)", ret);
return -1;
case SSL_ERROR_SSL:
ROPTIONAL(REDEBUG, ERROR, "TLS protocol error (%i)", ret);
return -1;
/*
* For any other errors that (a) exist, and (b)
* crop up - we need to interpret what to do with
* them - so "politely inform" the caller that
* the code needs updating here.
*/
default:
ROPTIONAL(REDEBUG, ERROR, "TLS session error %i (%i)", error, ret);
return -1;
}
return 0;
}
/** Call the driver's sql_select_query method, reconnecting if necessary.
*
* @note Caller must call ``(inst->module->sql_finish_select_query)(handle, inst->config);``
* after they're done with the result.
*
* @param inst #rlm_sql_t instance data.
* @param request Current request.
* @param handle to query the database with. *handle should not be NULL, as this indicates
* previous reconnection attempt has failed.
* @param query to execute. Should not be zero length.
* @return
* - #RLM_SQL_OK on success.
* - #RLM_SQL_RECONNECT if a new handle is required (also sets *handle = NULL).
* - #RLM_SQL_QUERY_INVALID, #RLM_SQL_ERROR on invalid query or connection error.
*/
sql_rcode_t rlm_sql_select_query(rlm_sql_t *inst, REQUEST *request, rlm_sql_handle_t **handle, char const *query)
{
int ret = RLM_SQL_ERROR;
int i, count;
/* Caller should check they have a valid handle */
rad_assert(*handle);
/* There's no query to run, return an error */
if (query[0] == '\0') {
if (request) REDEBUG("Zero length query");
return RLM_SQL_QUERY_INVALID;
}
/*
* inst->pool may be NULL is this function is called by mod_conn_create.
*/
count = inst->pool ? fr_connection_get_num(inst->pool) : 0;
/*
* For sanity, for when no connections are viable, and we can't make a new one
*/
for (i = 0; i < (count + 1); i++) {
ROPTIONAL(RDEBUG2, DEBUG2, "Executing select query: %s", query);
ret = (inst->module->sql_select_query)(*handle, inst->config, query);
switch (ret) {
case RLM_SQL_OK:
break;
/*
* Run through all available sockets until we exhaust all existing
* sockets in the pool and fail to establish a *new* connection.
*/
case RLM_SQL_RECONNECT:
*handle = fr_connection_reconnect(inst->pool, *handle);
/* Reconnection failed */
if (!*handle) return RLM_SQL_RECONNECT;
/* Reconnection succeeded, try again with the new handle */
continue;
case RLM_SQL_QUERY_INVALID:
case RLM_SQL_ERROR:
default:
rlm_sql_print_error(inst, request, *handle, false);
(inst->module->sql_finish_select_query)(*handle, inst->config);
break;
}
return ret;
}
ROPTIONAL(RERROR, ERROR, "Hit reconnection limit");
return RLM_SQL_ERROR;
}
ldap_rcode_t rlm_ldap_sasl_interactive(rlm_ldap_t const *inst, REQUEST *request,
ldap_handle_t *conn, char const *identity,
char const *password, ldap_sasl *sasl,
char const **error, char **extra)
{
ldap_rcode_t status;
int ret = 0;
int msgid;
char const *mech;
LDAPMessage *result = NULL;
rlm_ldap_sasl_ctx_t sasl_ctx; /* SASL defaults */
memset(&sasl_ctx, 0, sizeof(sasl_ctx));
sasl_ctx.inst = inst;
sasl_ctx.request = request;
sasl_ctx.identity = identity;
sasl_ctx.password = password;
ROPTIONAL(RDEBUG2, DEBUG2, "Starting SASL mech(s): %s", sasl->mech);
do {
ret = ldap_sasl_interactive_bind(conn->handle, NULL, sasl->mech,
NULL, NULL, LDAP_SASL_AUTOMATIC,
_sasl_interact, &sasl_ctx, result,
&mech, &msgid);
ldap_msgfree(result); /* We always need to free the old message */
if (ret >= 0) ROPTIONAL(RDEBUG3, DEBUG3, "Continuing SASL mech %s...", mech);
status = rlm_ldap_result(inst, conn, msgid, identity, &result, error, extra);
/*
* Write the servers response to the debug log
*/
if (((request && RDEBUG_ENABLED3) || DEBUG_ENABLED3) && result) {
struct berval *srv_cred;
if (ldap_parse_sasl_bind_result(conn->handle, result, &srv_cred, 0) == 0) {
char *escaped;
escaped = fr_aprints(request, srv_cred->bv_val, srv_cred->bv_len, '\0');
ROPTIONAL(RDEBUG3, DEBUG3, "SASL response : %s", escaped);
talloc_free(escaped);
ldap_memfree(srv_cred);
}
}
} while (status == LDAP_PROC_CONTINUE);
ldap_msgfree(result);
return status;
}
/** Call the driver's sql_fetch_row function
*
* Calls the driver's sql_fetch_row logging any errors. On success, will
* write row data to ``(*handle)->row``.
*
* @param out Where to write row data.
* @param inst Instance of #rlm_sql_t.
* @param request The Current request, may be NULL.
* @param handle Handle to retrieve errors for.
* @return
* - #RLM_SQL_OK on success.
* - other #sql_rcode_t constants on error.
*/
sql_rcode_t rlm_sql_fetch_row(rlm_sql_row_t *out, rlm_sql_t const *inst, REQUEST *request, rlm_sql_handle_t **handle)
{
sql_rcode_t ret;
if (!*handle || !(*handle)->conn) return RLM_SQL_ERROR;
/*
* We can't implement reconnect logic here, because the caller
* may require the original connection to free up queries or
* result sets associated with that connection.
*/
ret = (inst->driver->sql_fetch_row)(out, *handle, inst->config);
switch (ret) {
case RLM_SQL_OK:
rad_assert(*out != NULL);
return ret;
case RLM_SQL_NO_MORE_ROWS:
rad_assert(*out == NULL);
return ret;
default:
ROPTIONAL(RERROR, ERROR, "Error fetching row");
rlm_sql_print_error(inst, request, *handle, false);
return ret;
}
}
/** Modify something in the LDAP directory
*
* Binds as the administrative user and attempts to modify an LDAP object.
*
* @param[in] request Current request.
* @param[in,out] pconn to use. May change as this function calls functions which auto re-connect.
* @param[in] dn of the object to modify.
* @param[in] mods to make, see 'man ldap_modify' for more information.
* @param[in] serverctrls Search controls to pass to the server. May be NULL.
* @param[in] clientctrls Search controls for ldap_modify. May be NULL.
* @return One of the LDAP_PROC_* (#fr_ldap_rcode_t) values.
*/
fr_ldap_rcode_t fr_ldap_modify(REQUEST *request, fr_ldap_connection_t **pconn,
char const *dn, LDAPMod *mods[],
LDAPControl **serverctrls, LDAPControl **clientctrls)
{
fr_ldap_rcode_t status = LDAP_PROC_ERROR;
int msgid; // Message id returned by ldap_search_ext.
LDAPControl *our_serverctrls[LDAP_MAX_CONTROLS];
LDAPControl *our_clientctrls[LDAP_MAX_CONTROLS];
fr_ldap_control_merge(our_serverctrls, our_clientctrls,
sizeof(our_serverctrls) / sizeof(*our_serverctrls),
sizeof(our_clientctrls) / sizeof(*our_clientctrls),
*pconn, serverctrls, clientctrls);
rad_assert(*pconn && (*pconn)->handle);
if (RDEBUG_ENABLED4) fr_ldap_timeout_debug(request, *pconn, NULL, __FUNCTION__);
/*
* Perform all modifications as the admin user.
*/
if ((*pconn)->rebound) {
status = fr_ldap_bind(request, pconn,
(*pconn)->config->admin_identity, (*pconn)->config->admin_password,
&(*pconn)->config->admin_sasl,
NULL, NULL, NULL);
if (status != LDAP_PROC_SUCCESS) {
return LDAP_PROC_ERROR;
}
rad_assert(*pconn);
(*pconn)->rebound = false;
}
RDEBUG2("Modifying object with DN \"%s\"", dn);
(void) ldap_modify_ext((*pconn)->handle, dn, mods, our_serverctrls, our_clientctrls, &msgid);
RDEBUG2("Waiting for modify result...");
status = fr_ldap_result(NULL, NULL, *pconn, msgid, 0, dn, NULL);
switch (status) {
case LDAP_PROC_SUCCESS:
break;
case LDAP_PROC_BAD_CONN:
break;
/* FALL-THROUGH */
default:
ROPTIONAL(RPEDEBUG, RPERROR, "Failed modifying object");
goto finish;
}
finish:
return status;
}
/** Retrieve any errors from the SQL driver
*
* Retrieves errors from the driver from the last operation and writes them to
* to request/global log, in the ERROR, WARN, INFO and DEBUG categories.
*
* @param inst Instance of rlm_sql.
* @param request Current request, may be NULL.
* @param handle Handle to retrieve errors for.
* @param force_debug Force all errors to be logged as debug messages.
*/
void rlm_sql_print_error(rlm_sql_t *inst, REQUEST *request, rlm_sql_handle_t *handle, bool force_debug)
{
char const *driver;
sql_log_entry_t log[20];
size_t num, i;
num = (inst->module->sql_error)(handle->log_ctx, log, (sizeof(log) / sizeof(*log)), handle, inst->config);
if (num == 0) {
ROPTIONAL(RERROR, ERROR, "Unknown error");
return;
}
driver = inst->config->sql_driver_name;
for (i = 0; i < num; i++) {
if (force_debug) goto debug;
switch (log[i].type) {
case L_ERR:
ROPTIONAL(RERROR, ERROR, "%s: %s", driver, log[i].msg);
break;
case L_WARN:
ROPTIONAL(RWARN, WARN, "%s: %s", driver, log[i].msg);
break;
case L_INFO:
ROPTIONAL(RINFO, INFO, "%s: %s", driver, log[i].msg);
break;
case L_DBG:
default:
debug:
ROPTIONAL(RDEBUG, DEBUG, "%s: %s", driver, log[i].msg);
break;
}
}
talloc_free_children(handle->log_ctx);
}
static int _sasl_interact(UNUSED LDAP *handle, UNUSED unsigned flags, void *ctx, void *sasl_callbacks)
{
rlm_ldap_sasl_ctx_t *this = ctx;
REQUEST *request = this->request;
rlm_ldap_t const *inst = this->inst;
sasl_interact_t *cb = sasl_callbacks;
sasl_interact_t *cb_p;
for (cb_p = cb; cb_p->id != SASL_CB_LIST_END; cb_p++) {
ROPTIONAL(RDEBUG3, DEBUG3, "SASL challenge : %s", cb_p->challenge);
ROPTIONAL(RDEBUG3, DEBUG3, "SASL prompt : %s", cb_p->prompt);
switch (cb_p->id) {
case SASL_CB_AUTHNAME:
cb_p->result = this->identity;
break;
case SASL_CB_PASS:
cb_p->result = this->password;
break;
case SASL_CB_USER:
cb_p->result = this->extra->proxy ? this->extra->proxy : this->identity;
break;
case SASL_CB_GETREALM:
if (this->extra->realm) cb_p->result = this->extra->realm;
break;
default:
break;
}
ROPTIONAL(RDEBUG3, DEBUG3, "SASL result : %s", cb_p->result ? (char const *)cb_p->result : "");
}
return SASL_OK;
}
/** Call the driver's sql_fetch_row function
*
* Calls the driver's sql_fetch_row logging any errors. On success, will
* write row data to ``(*handle)->row``.
*
* @param out Where to write row data.
* @param inst Instance of #rlm_sql_t.
* @param request The Current request, may be NULL.
* @param handle Handle to retrieve errors for.
* @return
* - #RLM_SQL_OK on success.
* - other #sql_rcode_t constants on error.
*/
sql_rcode_t rlm_sql_fetch_row(rlm_sql_row_t *out, rlm_sql_t *inst, REQUEST *request, rlm_sql_handle_t **handle)
{
sql_rcode_t ret;
if (!*handle || !(*handle)->conn) return RLM_SQL_ERROR;
/*
* We can't implement reconnect logic here, because the caller
* may require the original connection to free up queries or
* result sets associated with that connection.
*/
ret = (inst->module->sql_fetch_row)(out, *handle, inst->config);
if (ret < 0) {
ROPTIONAL(RERROR, ERROR, "Error fetching row");
rlm_sql_print_error(inst, request, *handle, false);
}
return ret;
}
/** Search for something in the LDAP directory
*
* Binds as the administrative user and performs a search, dealing with any errors.
*
* @param[out] msgid to match response to request.
* @param[in] request Current request.
* @param[in,out] pconn to use. May change as this function calls functions which auto re-connect.
* @param[in] dn to use as base for the search.
* @param[in] scope to use (LDAP_SCOPE_BASE, LDAP_SCOPE_ONE, LDAP_SCOPE_SUB).
* @param[in] filter to use, should be pre-escaped.
* @param[in] attrs to retrieve.
* @param[in] serverctrls Search controls to pass to the server. May be NULL.
* @param[in] clientctrls Search controls for ldap_search. May be NULL.
* @return One of the LDAP_PROC_* (#fr_ldap_rcode_t) values.
*/
fr_ldap_rcode_t fr_ldap_search_async(int *msgid, REQUEST *request,
fr_ldap_connection_t **pconn,
char const *dn, int scope, char const *filter, char const * const *attrs,
LDAPControl **serverctrls, LDAPControl **clientctrls)
{
fr_ldap_rcode_t status = LDAP_PROC_ERROR;
fr_ldap_config_t const *handle_config = (*pconn)->config;
struct timeval tv; // Holds timeout values.
LDAPControl *our_serverctrls[LDAP_MAX_CONTROLS];
LDAPControl *our_clientctrls[LDAP_MAX_CONTROLS];
fr_ldap_control_merge(our_serverctrls, our_clientctrls,
sizeof(our_serverctrls) / sizeof(*our_serverctrls),
sizeof(our_clientctrls) / sizeof(*our_clientctrls),
*pconn, serverctrls, clientctrls);
rad_assert(*pconn && (*pconn)->handle);
if (DEBUG_ENABLED4 || (request && RDEBUG_ENABLED4)) fr_ldap_timeout_debug(request, *pconn, NULL, __FUNCTION__);
/*
* OpenLDAP library doesn't declare attrs array as const, but
* it really should be *sigh*.
*/
char **search_attrs;
memcpy(&search_attrs, &attrs, sizeof(attrs));
/*
* Do all searches as the admin user.
*/
if ((*pconn)->rebound) {
status = fr_ldap_bind(request, pconn,
(*pconn)->config->admin_identity, (*pconn)->config->admin_password,
&(*pconn)->config->admin_sasl, NULL,
NULL, NULL);
if (status != LDAP_PROC_SUCCESS) return LDAP_PROC_ERROR;
rad_assert(*pconn);
(*pconn)->rebound = false;
}
if (filter) {
ROPTIONAL(RDEBUG2, DEBUG2, "Performing search in \"%s\" with filter \"%s\", scope \"%s\"", dn, filter,
fr_int2str(fr_ldap_scope, scope, "<INVALID>"));
} else {
ROPTIONAL(RDEBUG2, DEBUG2, "Performing unfiltered search in \"%s\", scope \"%s\"", dn,
fr_int2str(fr_ldap_scope, scope, "<INVALID>"));
}
/*
* If LDAP search produced an error it should also be logged
* to the ld. result should pick it up without us
* having to pass it explicitly.
*/
memset(&tv, 0, sizeof(tv));
if (ldap_search_ext((*pconn)->handle, dn, scope, filter, search_attrs,
0, our_serverctrls, our_clientctrls, NULL, 0, msgid) != LDAP_SUCCESS) {
int ldap_errno;
ldap_get_option((*pconn)->handle, LDAP_OPT_ERROR_NUMBER, &ldap_errno);
ERROR("Failed performing search: %s", ldap_err2string(ldap_errno));
return LDAP_PROC_ERROR;
}
return LDAP_PROC_SUCCESS;
}
/** Search for something in the LDAP directory
*
* Binds as the administrative user and performs a search, dealing with any errors.
*
* @param[out] result Where to store the result. Must be freed with ldap_msgfree
* if LDAP_PROC_SUCCESS is returned.
* May be NULL in which case result will be automatically freed after use.
* @param[in] request Current request.
* @param[in,out] pconn to use. May change as this function calls functions which auto re-connect.
* @param[in] dn to use as base for the search.
* @param[in] scope to use (LDAP_SCOPE_BASE, LDAP_SCOPE_ONE, LDAP_SCOPE_SUB).
* @param[in] filter to use, should be pre-escaped.
* @param[in] attrs to retrieve.
* @param[in] serverctrls Search controls to pass to the server. May be NULL.
* @param[in] clientctrls Search controls for ldap_search. May be NULL.
* @return One of the LDAP_PROC_* (#fr_ldap_rcode_t) values.
*/
fr_ldap_rcode_t fr_ldap_search(LDAPMessage **result, REQUEST *request,
fr_ldap_connection_t **pconn,
char const *dn, int scope, char const *filter, char const * const *attrs,
LDAPControl **serverctrls, LDAPControl **clientctrls)
{
fr_ldap_rcode_t status = LDAP_PROC_ERROR;
LDAPMessage *our_result = NULL;
fr_ldap_config_t const *handle_config = (*pconn)->config;
int msgid; // Message id returned by
// ldap_search_ext.
int count = 0; // Number of results we got.
struct timeval tv; // Holds timeout values.
LDAPControl *our_serverctrls[LDAP_MAX_CONTROLS];
LDAPControl *our_clientctrls[LDAP_MAX_CONTROLS];
fr_ldap_control_merge(our_serverctrls, our_clientctrls,
sizeof(our_serverctrls) / sizeof(*our_serverctrls),
sizeof(our_clientctrls) / sizeof(*our_clientctrls),
*pconn, serverctrls, clientctrls);
rad_assert(*pconn && (*pconn)->handle);
if (DEBUG_ENABLED4 || (request && RDEBUG_ENABLED4)) {
fr_ldap_timeout_debug(request, *pconn, NULL, __FUNCTION__);
}
/*
* OpenLDAP library doesn't declare attrs array as const, but
* it really should be *sigh*.
*/
char **search_attrs;
memcpy(&search_attrs, &attrs, sizeof(attrs));
/*
* Do all searches as the admin user.
*/
if ((*pconn)->rebound) {
status = fr_ldap_bind(request, pconn,
(*pconn)->config->admin_identity, (*pconn)->config->admin_password,
&(*pconn)->config->admin_sasl, NULL,
NULL, NULL);
if (status != LDAP_PROC_SUCCESS) return LDAP_PROC_ERROR;
rad_assert(*pconn);
(*pconn)->rebound = false;
}
if (filter) {
ROPTIONAL(RDEBUG2, DEBUG2, "Performing search in \"%s\" with filter \"%s\", scope \"%s\"", dn, filter,
fr_int2str(fr_ldap_scope, scope, "<INVALID>"));
} else {
ROPTIONAL(RDEBUG2, DEBUG2, "Performing unfiltered search in \"%s\", scope \"%s\"", dn,
fr_int2str(fr_ldap_scope, scope, "<INVALID>"));
}
/*
* If LDAP search produced an error it should also be logged
* to the ld. result should pick it up without us
* having to pass it explicitly.
*/
memset(&tv, 0, sizeof(tv));
(void) ldap_search_ext((*pconn)->handle, dn, scope, filter, search_attrs,
0, our_serverctrls, our_clientctrls, NULL, 0, &msgid);
ROPTIONAL(RDEBUG2, DEBUG2, "Waiting for search result...");
status = fr_ldap_result(&our_result, NULL, *pconn, msgid, 1, dn, NULL);
switch (status) {
case LDAP_PROC_SUCCESS:
break;
default:
ROPTIONAL(RPEDEBUG, PERROR, "Failed performing search");
goto finish;
}
count = ldap_count_entries((*pconn)->handle, our_result);
if (count < 0) {
ROPTIONAL(REDEBUG, ERROR, "Error counting results: %s", fr_ldap_error_str(*pconn));
status = LDAP_PROC_ERROR;
ldap_msgfree(our_result);
our_result = NULL;
} else if (count == 0) {
ROPTIONAL(RDEBUG2, DEBUG2, "Search returned no results");
status = LDAP_PROC_NO_RESULT;
ldap_msgfree(our_result);
our_result = NULL;
}
finish:
/*
* We always need to get the result to count entries, but the caller
* may not of requested one. If that's the case, free it, else write
* it to where our caller said.
*/
if (!result) {
if (our_result) ldap_msgfree(our_result);
} else {
*result = our_result;
}
return status;
}
/** Bind to the LDAP directory as a user
*
* Performs a simple bind to the LDAP directory, and handles any errors that occur.
*
* @param[in] request Current request, this may be NULL, in which case all
* debug logging is done with log.
* @param[in,out] pconn to use. May change as this function calls functions
* which auto re-connect.
* @param[in] dn of the user, may be NULL to bind anonymously.
* @param[in] password of the user, may be NULL if no password is specified.
* @param[in] sasl mechanism to use for bind, and additional parameters.
* @param[in] timeout Maximum time bind is allowed to take.
* @param[in] serverctrls Only used for SASL binds. May be NULL.
* @param[in] clientctrls Search controls for sasl_bind.
* Only used for SASL binds. May be NULL.
* @return One of the LDAP_PROC_* (#fr_ldap_rcode_t) values.
*/
fr_ldap_rcode_t fr_ldap_bind(REQUEST *request,
fr_ldap_connection_t **pconn,
char const *dn, char const *password,
#ifdef WITH_SASL
fr_ldap_sasl_t const *sasl,
#else
NDEBUG_UNUSED fr_ldap_sasl_t const *sasl,
#endif
struct timeval const *timeout,
LDAPControl **serverctrls, LDAPControl **clientctrls)
{
fr_ldap_rcode_t status = LDAP_PROC_ERROR;
fr_ldap_config_t const *handle_config = (*pconn)->config;
int msgid = -1;
rad_assert(*pconn && (*pconn)->handle);
#ifndef WITH_SASL
rad_assert(!sasl || !sasl->mech);
#endif
if (DEBUG_ENABLED4 || (request && RDEBUG_ENABLED4)) {
fr_ldap_timeout_debug(request, *pconn, timeout, __FUNCTION__);
}
/*
* Bind as anonymous user
*/
if (!dn) dn = "";
#ifdef WITH_SASL
if (sasl && sasl->mech) {
status = fr_ldap_sasl_interactive(request, *pconn, dn, password, sasl,
serverctrls, clientctrls, timeout);
} else
#endif
{
int ret;
struct berval cred;
if (password) {
memcpy(&cred.bv_val, &password, sizeof(cred.bv_val));
cred.bv_len = talloc_array_length(password) - 1;
} else {
cred.bv_val = NULL;
cred.bv_len = 0;
}
/*
* Yes, confusingly named. This is the simple version
* of the SASL bind function that should always be
* available.
*/
ret = ldap_sasl_bind((*pconn)->handle, dn, LDAP_SASL_SIMPLE, &cred,
serverctrls, clientctrls, &msgid);
/* We got a valid message ID */
if ((ret == 0) && (msgid >= 0)) ROPTIONAL(RDEBUG2, DEBUG2, "Waiting for bind result...");
status = fr_ldap_result(NULL, NULL, *pconn, msgid, 0, dn, NULL);
}
switch (status) {
case LDAP_PROC_SUCCESS:
ROPTIONAL(RDEBUG2, DEBUG2, "Bind successful");
break;
case LDAP_PROC_NOT_PERMITTED:
ROPTIONAL(RPEDEBUG, PERROR, "Bind as \"%s\" to \"%s\" not permitted",
*dn ? dn : "(anonymous)", handle_config->server);
break;
default:
ROPTIONAL(RPEDEBUG, PERROR, "Bind as \"%s\" to \"%s\" failed",
*dn ? dn : "(anonymous)", handle_config->server);
break;
}
return status; /* caller closes the connection */
}
/** Prints information to the debug log on the current timeout settings
*
* There are so many different timers in LDAP it's often hard to debug
* issues with them, hence the need for this function.
*/
void fr_ldap_timeout_debug(REQUEST *request, fr_ldap_connection_t const *conn,
struct timeval const *timeout, char const *prefix)
{
struct timeval *net = NULL, *client = NULL;
int server = 0;
fr_ldap_config_t const *handle_config = conn->config;
if (request) RINDENT();
#ifdef LDAP_OPT_NETWORK_TIMEOUT
if (ldap_get_option(conn->handle, LDAP_OPT_NETWORK_TIMEOUT, &net) != LDAP_OPT_SUCCESS) {
ROPTIONAL(REDEBUG, ERROR, "Failed getting LDAP_OPT_NETWORK_TIMEOUT");
}
#endif
#ifdef LDAP_OPT_TIMEOUT
if (ldap_get_option(conn->handle, LDAP_OPT_TIMEOUT, &client) != LDAP_OPT_SUCCESS) {
ROPTIONAL(REDEBUG, ERROR, "Failed getting LDAP_OPT_TIMEOUT");
}
#endif
if (ldap_get_option(conn->handle, LDAP_OPT_TIMELIMIT, &server) != LDAP_OPT_SUCCESS) {
ROPTIONAL(REDEBUG, ERROR, "Failed getting LDAP_OPT_TIMELIMIT");
}
ROPTIONAL(RDEBUG4, DEBUG4, "%s: Timeout settings", prefix);
if (timeout) {
ROPTIONAL(RDEBUG4, DEBUG4, "Client side result timeout (ovr): %ld.%06ld",
(long)timeout->tv_sec, (long)timeout->tv_usec);
} else {
ROPTIONAL(RDEBUG4, DEBUG4, "Client side result timeout (ovr): unset");
}
#ifdef LDAP_OPT_TIMEOUT
if (client && (client->tv_sec != -1)) {
ROPTIONAL(RDEBUG4, DEBUG4, "Client side result timeout (dfl): %ld.%06ld",
(long)client->tv_sec, (long)client->tv_usec);
} else {
ROPTIONAL(RDEBUG4, DEBUG4, "Client side result timeout (dfl): unset");
}
#endif
#ifdef LDAP_OPT_NETWORK_TIMEOUT
if (net && (net->tv_sec != -1)) {
ROPTIONAL(RDEBUG4, DEBUG4, "Client side network I/O timeout : %ld.%06ld",
(long)net->tv_sec, (long)net->tv_usec);
} else {
ROPTIONAL(RDEBUG4, DEBUG4, "Client side network I/O timeout : unset");
}
#endif
ROPTIONAL(RDEBUG4, DEBUG4, "Server side result timeout : %i", server);
if (request) REXDENT();
free(net);
free(client);
}
/** Call the driver's sql_query method, reconnecting if necessary.
*
* @note Caller must call ``(inst->module->sql_finish_query)(handle, inst->config);``
* after they're done with the result.
*
* @param handle to query the database with. *handle should not be NULL, as this indicates
* previous reconnection attempt has failed.
* @param request Current request.
* @param inst #rlm_sql_t instance data.
* @param query to execute. Should not be zero length.
* @return
* - #RLM_SQL_OK on success.
* - #RLM_SQL_RECONNECT if a new handle is required (also sets *handle = NULL).
* - #RLM_SQL_QUERY_INVALID, #RLM_SQL_ERROR on invalid query or connection error.
* - #RLM_SQL_ALT_QUERY on constraints violation.
*/
sql_rcode_t rlm_sql_query(rlm_sql_t *inst, REQUEST *request, rlm_sql_handle_t **handle, char const *query)
{
int ret = RLM_SQL_ERROR;
int i, count;
/* Caller should check they have a valid handle */
rad_assert(*handle);
/* There's no query to run, return an error */
if (query[0] == '\0') {
if (request) REDEBUG("Zero length query");
return RLM_SQL_QUERY_INVALID;
}
/*
* inst->pool may be NULL is this function is called by mod_conn_create.
*/
count = inst->pool ? fr_connection_get_num(inst->pool) : 0;
/*
* Here we try with each of the existing connections, then try to create
* a new connection, then give up.
*/
for (i = 0; i < (count + 1); i++) {
ROPTIONAL(RDEBUG2, DEBUG2, "Executing query: %s", query);
ret = (inst->module->sql_query)(*handle, inst->config, query);
switch (ret) {
case RLM_SQL_OK:
break;
/*
* Run through all available sockets until we exhaust all existing
* sockets in the pool and fail to establish a *new* connection.
*/
case RLM_SQL_RECONNECT:
*handle = fr_connection_reconnect(inst->pool, *handle);
/* Reconnection failed */
if (!*handle) return RLM_SQL_RECONNECT;
/* Reconnection succeeded, try again with the new handle */
continue;
/*
* These are bad and should make rlm_sql return invalid
*/
case RLM_SQL_QUERY_INVALID:
rlm_sql_print_error(inst, request, *handle, false);
(inst->module->sql_finish_query)(*handle, inst->config);
break;
/*
* Server or client errors.
*
* If the driver claims to be able to distinguish between
* duplicate row errors and other errors, and we hit a
* general error treat it as a failure.
*
* Otherwise rewrite it to RLM_SQL_ALT_QUERY.
*/
case RLM_SQL_ERROR:
if (inst->module->flags & RLM_SQL_RCODE_FLAGS_ALT_QUERY) {
rlm_sql_print_error(inst, request, *handle, false);
(inst->module->sql_finish_query)(*handle, inst->config);
break;
}
ret = RLM_SQL_ALT_QUERY;
/* FALL-THROUGH */
/*
* Driver suggested using an alternative query
*/
case RLM_SQL_ALT_QUERY:
rlm_sql_print_error(inst, request, *handle, true);
(inst->module->sql_finish_query)(*handle, inst->config);
break;
}
return ret;
}
ROPTIONAL(RERROR, ERROR, "Hit reconnection limit");
return RLM_SQL_ERROR;
}
/** Print errors in the TLS thread local error stack
*
* Drains the thread local OpenSSL error queue, and prints out errors.
*
* @param[in] request The current request (may be NULL).
* @param[in] msg Error message describing the operation being attempted.
* @param[in] ap Arguments for msg.
* @return the number of errors drained from the stack.
*/
static int tls_log_error_va(REQUEST *request, char const *msg, va_list ap)
{
unsigned long error;
char *p;
int in_stack = 0;
char buffer[256];
int line;
char const *file;
char const *data;
int flags = 0;
/*
* Pop the first error, so ERR_peek_error()
* can be used to determine if there are
* multiple errors.
*/
error = ERR_get_error_line_data(&file, &line, &data, &flags);
if (!(flags & ERR_TXT_STRING)) data = NULL;
if (msg) {
p = talloc_vasprintf(request, msg, ap);
/*
* Single line mode (there's only one error)
*/
if (error && !ERR_peek_error()) {
ERR_error_string_n(error, buffer, sizeof(buffer));
/* Extra verbose */
if ((request && RDEBUG_ENABLED3) || DEBUG_ENABLED3) {
ROPTIONAL(REDEBUG, ERROR, "%s: %s[%i]:%s%c%s", p, file, line, buffer,
data ? ':' : '\0', data ? data : "");
} else {
ROPTIONAL(REDEBUG, ERROR, "%s: %s%c%s", p, buffer,
data ? ':' : '\0', data ? data : "");
}
talloc_free(p);
return 1;
}
/*
* Print the error we were given, irrespective
* of whether there were any OpenSSL errors.
*/
ROPTIONAL(RERROR, ERROR, "%s", p);
talloc_free(p);
}
/*
* Stack mode (there are multiple errors)
*/
if (!error) return 0;
do {
if (!(flags & ERR_TXT_STRING)) data = NULL;
ERR_error_string_n(error, buffer, sizeof(buffer));
/* Extra verbose */
if ((request && RDEBUG_ENABLED3) || DEBUG_ENABLED3) {
ROPTIONAL(REDEBUG, ERROR, "%s[%i]:%s%c%s", file, line, buffer,
data ? ':' : '\0', data ? data : "");
} else {
ROPTIONAL(REDEBUG, ERROR, "%s%c%s", buffer,
data ? ':' : '\0', data ? data : "");
}
in_stack++;
} while ((error = ERR_get_error_line_data(&file, &line, &data, &flags)));
return in_stack;
}
/** Print a message to the request or global log detailing handshake state
*
* @param[in] request The current #REQUEST.
* @param[in] tls_session The current TLS session.
*/
static void session_msg_log(REQUEST *request, tls_session_t *tls_session)
{
char const *str_write_p, *str_version, *str_content_type = "";
char const *str_details1 = "", *str_details2= "";
char buffer[32];
char content_type[64];
/*
* Don't print this out in the normal course of
* operations.
*/
if (rad_debug_lvl == 0) return;
str_write_p = tls_session->info.origin ? ">>> send" : "<<< recv";
switch (tls_session->info.version) {
case SSL2_VERSION:
str_version = "SSL 2.0 ";
break;
case SSL3_VERSION:
str_version = "SSL 3.0 ";
break;
case TLS1_VERSION:
str_version = "TLS 1.0 ";
break;
#ifdef TLS1_1_VERSION
case TLS1_1_VERSION:
str_version = "TLS 1.1 ";
break;
#endif
#ifdef TLS1_2_VERSION
case TLS1_2_VERSION:
str_version = "TLS 1.2 ";
break;
#endif
#ifdef TLS1_3_VERSON
case TLS1_3_VERSION:
str_version = "TLS 1.3 ";
break;
#endif
default:
if (tls_session->info.version) {
sprintf(buffer, "UNKNOWN TLS VERSION 0x%04x", tls_session->info.version);
str_version = buffer;
} else {
str_version = "";
}
break;
}
/*
* TLS 1.0, 1.1, 1.2 content types are the same as SSLv3
*/
switch (tls_session->info.content_type) {
case SSL3_RT_CHANGE_CIPHER_SPEC:
str_content_type = "change_cipher_spec ";
break;
case SSL3_RT_ALERT:
str_content_type = "alert ";
break;
case SSL3_RT_HANDSHAKE:
str_content_type = "handshake ";
break;
case SSL3_RT_APPLICATION_DATA:
str_content_type = "application_data ";
break;
#ifdef TLS1_RT_HEARTBEAT
case TLS1_RT_HEARTBEAT:
str_content_type = "heartbeat ";
break;
#endif
#ifdef TLS1_RT_CRYPTO
case TLS1_RT_CRYPTO:
str_content_type = "crypto ";
break;
#endif
#ifdef TLS1_RT_CRYPTO_PREMASTER
case TLS1_RT_CRYPTO_PREMASTER:
str_content_type = "crypto_premaster ";
break;
#endif
#ifdef TLS1_RT_CRYPTO_CLIENT_RANDOM
case TLS1_RT_CRYPTO_CLIENT_RANDOM:
str_content_type = "client_random ";
break;
#endif
#ifdef TLS1_RT_CRYPTO_SERVER_RANDOM
case TLS1_RT_CRYPTO_SERVER_RANDOM:
str_content_type = "server_random ";
break;
#endif
#ifdef TLS1_RT_CRYPTO_MASTER
case TLS1_RT_CRYPTO_MASTER:
str_content_type = "crypto_master ";
break;
#endif
#ifdef TLS1_RT_CRYPTO_READ
case TLS1_RT_CRYPTO_READ:
str_content_type = "crypto_read ";
break;
#endif
#ifdef TLS1_RT_CRYPTO_WRITE
case TLS1_RT_CRYPTO_WRITE:
str_content_type = "crypto_write ";
break;
#endif
#ifdef TLS1_RT_CRYPTO_MAC
case TLS1_RT_CRYPTO_MAC:
str_content_type = "crypto_mac ";
break;
#endif
#ifdef TLS1_RT_CRYPTO_KEY
case TLS1_RT_CRYPTO_KEY:
str_content_type = "crypto_key ";
break;
#endif
#ifdef TLS1_RT_CRYPTO_IV
case TLS1_RT_CRYPTO_IV:
str_content_type = "crypto_iv ";
break;
#endif
#ifdef TLS1_RT_CRYPTO_FIXED_IV
case TLS1_RT_CRYPTO_FIXED_IV:
str_content_type = "crypto_fixed_iv ";
break;
#endif
default:
snprintf(content_type, sizeof(content_type), "unknown content type %i", tls_session->info.content_type );
str_content_type = content_type;
break;
}
if (tls_session->info.content_type == SSL3_RT_ALERT) {
str_details1 = ", ???";
if (tls_session->info.record_len == 2) {
switch (tls_session->info.alert_level) {
case SSL3_AL_WARNING:
str_details1 = ", warning";
break;
case SSL3_AL_FATAL:
str_details1 = ", fatal";
break;
}
str_details2 = " ???";
switch (tls_session->info.alert_description) {
case SSL3_AD_CLOSE_NOTIFY:
str_details2 = " close_notify";
break;
case SSL3_AD_UNEXPECTED_MESSAGE:
str_details2 = " unexpected_message";
break;
case SSL3_AD_BAD_RECORD_MAC:
str_details2 = " bad_record_mac";
break;
case TLS1_AD_DECRYPTION_FAILED:
str_details2 = " decryption_failed";
break;
case TLS1_AD_RECORD_OVERFLOW:
str_details2 = " record_overflow";
break;
case SSL3_AD_DECOMPRESSION_FAILURE:
str_details2 = " decompression_failure";
break;
case SSL3_AD_HANDSHAKE_FAILURE:
str_details2 = " handshake_failure";
break;
case SSL3_AD_BAD_CERTIFICATE:
str_details2 = " bad_certificate";
break;
case SSL3_AD_UNSUPPORTED_CERTIFICATE:
str_details2 = " unsupported_certificate";
break;
case SSL3_AD_CERTIFICATE_REVOKED:
str_details2 = " certificate_revoked";
break;
case SSL3_AD_CERTIFICATE_EXPIRED:
str_details2 = " certificate_expired";
break;
case SSL3_AD_CERTIFICATE_UNKNOWN:
str_details2 = " certificate_unknown";
break;
case SSL3_AD_ILLEGAL_PARAMETER:
str_details2 = " illegal_parameter";
break;
case TLS1_AD_UNKNOWN_CA:
str_details2 = " unknown_ca";
break;
case TLS1_AD_ACCESS_DENIED:
str_details2 = " access_denied";
break;
case TLS1_AD_DECODE_ERROR:
str_details2 = " decode_error";
break;
case TLS1_AD_DECRYPT_ERROR:
str_details2 = " decrypt_error";
break;
case TLS1_AD_EXPORT_RESTRICTION:
str_details2 = " export_restriction";
break;
case TLS1_AD_PROTOCOL_VERSION:
str_details2 = " protocol_version";
break;
case TLS1_AD_INSUFFICIENT_SECURITY:
str_details2 = " insufficient_security";
break;
case TLS1_AD_INTERNAL_ERROR:
str_details2 = " internal_error";
break;
case TLS1_AD_USER_CANCELLED:
str_details2 = " user_canceled";
break;
case TLS1_AD_NO_RENEGOTIATION:
str_details2 = " no_renegotiation";
break;
}
}
}
if (tls_session->info.content_type == SSL3_RT_HANDSHAKE) {
str_details1 = "???";
if (tls_session->info.record_len > 0) switch (tls_session->info.handshake_type) {
case SSL3_MT_HELLO_REQUEST:
str_details1 = ", hello_request";
break;
case SSL3_MT_CLIENT_HELLO:
str_details1 = ", client_hello";
break;
case SSL3_MT_SERVER_HELLO:
str_details1 = ", server_hello";
break;
case SSL3_MT_CERTIFICATE:
str_details1 = ", certificate";
break;
case SSL3_MT_SERVER_KEY_EXCHANGE:
str_details1 = ", server_key_exchange";
break;
case SSL3_MT_CERTIFICATE_REQUEST:
str_details1 = ", certificate_request";
break;
case SSL3_MT_SERVER_DONE:
str_details1 = ", server_hello_done";
break;
case SSL3_MT_CERTIFICATE_VERIFY:
str_details1 = ", certificate_verify";
break;
case SSL3_MT_CLIENT_KEY_EXCHANGE:
str_details1 = ", client_key_exchange";
break;
case SSL3_MT_FINISHED:
str_details1 = ", finished";
break;
}
}
snprintf(tls_session->info.info_description,
sizeof(tls_session->info.info_description),
"%s %s%s[length %lu]%s%s\n",
str_write_p, str_version, str_content_type,
(unsigned long)tls_session->info.record_len,
str_details1, str_details2);
ROPTIONAL(RDEBUG2, DEBUG2, "%s", tls_session->info.info_description);
}
