diff --git a/src/include/radiusd.h b/src/include/radiusd.h index ca4da6ca7eca..94899cc20b80 100644 --- a/src/include/radiusd.h +++ b/src/include/radiusd.h @@ -532,7 +532,8 @@ int session_zap(REQUEST *request, uint32_t nasaddr, #undef debug_pair void debug_pair(VALUE_PAIR *); void debug_pair_list(VALUE_PAIR *); -void rdebug_pair_list(int, REQUEST *, VALUE_PAIR *); +void rdebug_pair(int level, REQUEST *, VALUE_PAIR *); +void rdebug_pair_list(int level, REQUEST *, VALUE_PAIR *); int log_err (char *); /* util.c */ diff --git a/src/main/valuepair.c b/src/main/valuepair.c index 6c1079bdaf8d..d3926a81dcc2 100644 --- a/src/main/valuepair.c +++ b/src/main/valuepair.c @@ -696,6 +696,23 @@ void debug_pair_list(VALUE_PAIR *vp) fflush(fr_log_fp); } +/** Print a single valuepair to stderr or error log. + * + * @param[in] level Debug level (1-4). + * @param[in] request to read logging params from. + * @param[in] vp to print. + */ +void rdebug_pair(int level, REQUEST *request, VALUE_PAIR *vp) +{ + char buffer[256]; + if (!vp || !request || !request->log.func) return; + + if (!radlog_debug_enabled(L_DBG, level, request)) return; + + vp_prints(buffer, sizeof(buffer), vp); + RDEBUGX(level, "%s", buffer); +} + /** Print a list of valuepairs to the request list. * * @param[in] level Debug level (1-4). @@ -713,18 +730,10 @@ void rdebug_pair_list(int level, REQUEST *request, VALUE_PAIR *vp) for (vp = fr_cursor_init(&cursor, &vp); vp; vp = fr_cursor_next(&cursor)) { - /* - * Take this opportunity to verify all the VALUE_PAIRs are still valid. - */ - if (!talloc_get_type(vp, VALUE_PAIR)) { - REDEBUG("Expected VALUE_PAIR pointer got \"%s\"", talloc_get_name(vp)); - - fr_log_talloc_report(vp); - rad_assert(0); - } + VERIFY_VP(vp); vp_prints(buffer, sizeof(buffer), vp); - RDEBUGX(level, "\t%s", buffer); + RDEBUGX(level, "%s", buffer); } } diff --git a/src/modules/rlm_cache/rlm_cache.c b/src/modules/rlm_cache/rlm_cache.c index aa06d4c52bb0..24f526aca429 100644 --- a/src/modules/rlm_cache/rlm_cache.c +++ b/src/modules/rlm_cache/rlm_cache.c @@ -149,14 +149,20 @@ static void CC_HINT(nonnull) cache_merge(rlm_cache_t *inst, REQUEST *request, rl if (c->control) { RDEBUG2("Merging cached control list:"); + + RINDENT(); rdebug_pair_list(2, request, c->control); + REXDENT(); pairadd(&request->config_items, paircopy(request, c->control)); } if (c->packet && request->packet) { RDEBUG2("Merging cached request list:"); + + RINDENT(); rdebug_pair_list(2, request, c->packet); + REXDENT(); pairadd(&request->packet->vps, paircopy(request->packet, c->packet)); @@ -164,7 +170,10 @@ static void CC_HINT(nonnull) cache_merge(rlm_cache_t *inst, REQUEST *request, rl if (c->reply && request->reply) { RDEBUG2("Merging cached reply list:"); + + RINDENT(); rdebug_pair_list(2, request, c->reply); + REXDENT(); pairadd(&request->reply->vps, paircopy(request->reply, c->reply)); diff --git a/src/modules/rlm_sql/rlm_sql.c b/src/modules/rlm_sql/rlm_sql.c index f797fe27947e..a397816508aa 100644 --- a/src/modules/rlm_sql/rlm_sql.c +++ b/src/modules/rlm_sql/rlm_sql.c @@ -636,6 +636,9 @@ static rlm_rcode_t rlm_sql_process_groups(rlm_sql_t *inst, REQUEST *request, rlm } if (inst->config->authorize_group_check_query && (*inst->config->authorize_group_check_query != '\0')) { + vp_cursor_t cursor; + VALUE_PAIR *vp; + /* * Expand the group query */ @@ -665,9 +668,19 @@ static rlm_rcode_t rlm_sql_process_groups(rlm_sql_t *inst, REQUEST *request, rlm continue; } - RDEBUG2("Group \"%s\" check items matched", entry->name); + RDEBUG2("Group \"%s\": Conditional check items matched", entry->name); rcode = RLM_MODULE_OK; + RDEBUG2("Group \"%s\": Merging assignment check items", entry->name); + RINDENT(); + for (vp = fr_cursor_init(&cursor, &check_tmp); + vp; + vp = fr_cursor_next(&cursor)) { + if (!fr_assignment_op[vp->op]) continue; + + rdebug_pair(2, request, vp); + } + REXDENT(); radius_pairmove(request, &request->config_items, check_tmp, true); check_tmp = NULL; } @@ -690,12 +703,15 @@ static rlm_rcode_t rlm_sql_process_groups(rlm_sql_t *inst, REQUEST *request, rlm rcode = RLM_MODULE_FAIL; goto finish; } - *do_fall_through = fall_through(reply_tmp); - RDEBUG2("Group \"%s\" reply items processed", entry->name); + RDEBUG2("Group \"%s\": Merging reply items", entry->name); rcode = RLM_MODULE_OK; + RINDENT(); + rdebug_pair_list(2, request, reply_tmp); + REXDENT(); + radius_pairmove(request, &request->reply->vps, reply_tmp, true); reply_tmp = NULL; } @@ -966,6 +982,9 @@ static rlm_rcode_t CC_HINT(nonnull) mod_authorize(void *instance, REQUEST *reque * Query the check table to find any conditions associated with this user/realm/whatever... */ if (inst->config->authorize_check_query) { + vp_cursor_t cursor; + VALUE_PAIR *vp; + if (radius_axlat(&expanded, request, inst->config->authorize_check_query, sql_escape_func, inst) < 0) { REDEBUG("Error generating query"); @@ -994,8 +1013,18 @@ static rlm_rcode_t CC_HINT(nonnull) mod_authorize(void *instance, REQUEST *reque goto skipreply; } - RDEBUG2("Check items matched"); + RDEBUG2("Conditional check items matched, merging assignment check items"); + RINDENT(); + for (vp = fr_cursor_init(&cursor, &check_tmp); + vp; + vp = fr_cursor_next(&cursor)) { + if (!fr_assignment_op[vp->op]) continue; + + rdebug_pair(2, request, vp); + } + REXDENT(); radius_pairmove(request, &request->config_items, check_tmp, true); + rcode = RLM_MODULE_OK; check_tmp = NULL; } @@ -1023,9 +1052,15 @@ static rlm_rcode_t CC_HINT(nonnull) mod_authorize(void *instance, REQUEST *reque do_fall_through = fall_through(reply_tmp); - RDEBUG2("User found in radreply table"); + RDEBUG2("User found in radreply table, merging reply items"); user_found = true; + + RINDENT(); + rdebug_pair_list(2, request, reply_tmp); + REXDENT(); + radius_pairmove(request, &request->reply->vps, reply_tmp, true); + rcode = RLM_MODULE_OK; reply_tmp = NULL; }