From: Arran Cudbard-Bell Date: Sat, 23 Feb 2019 14:01:34 +0000 (+0800) Subject: Switch most calls to RDEBUG to REDBUG2 X-Git-Url: http://git.ipfire.org/cgi-bin/gitweb.cgi?a=commitdiff_plain;h=f30a2ed2ca65e3af2be259cae0629089ccde9849;p=thirdparty%2Ffreeradius-server.git Switch most calls to RDEBUG to REDBUG2 Frontend modules left using RDEBUG, module return codes changed to RDEBUG, this should hopefully produce more consistent debug output, and make radiusd -x more useful --- diff --git a/src/lib/eap/chbind.c b/src/lib/eap/chbind.c index ee276eea472..3fe3bed5223 100644 --- a/src/lib/eap/chbind.c +++ b/src/lib/eap/chbind.c @@ -78,7 +78,7 @@ static bool chbind_build_response(REQUEST *request, CHBIND_REQ *chbind) ptr[2] = total & 0xff; ptr[3] = CHBIND_NSID_RADIUS; - RDEBUG("Sending chbind response: code %i", (int )(ptr[0])); + RDEBUG2("Sending chbind response: code %i", (int )(ptr[0])); log_request_pair_list(L_DBG_LVL_1, request, request->reply->vps, NULL); /* Encode the chbind attributes into the response */ diff --git a/src/lib/eap/tls.c b/src/lib/eap/tls.c index f69432dea61..f5cf1bb2d3c 100644 --- a/src/lib/eap/tls.c +++ b/src/lib/eap/tls.c @@ -503,7 +503,7 @@ static eap_tls_status_t eap_tls_session_status(eap_session_t *eap_session) return EAP_TLS_INVALID; } if (!tls_session->info.initialized) { - RDEBUG("No SSL info available. Waiting for more SSL data"); + RDEBUG2("No SSL info available. Waiting for more SSL data"); return EAP_TLS_RECORD_SEND; } @@ -593,7 +593,7 @@ static eap_tls_status_t eap_tls_verify(eap_session_t *eap_session) */ eap_tls_data = (eap_tls_data_t *)this_round->response->type.data; if (!eap_tls_data) { - RDEBUG("Invalid EAP-TLS packet; no data"); + REDEBUG("Invalid EAP-TLS packet; no data"); return EAP_TLS_INVALID; } diff --git a/src/lib/ldap/map.c b/src/lib/ldap/map.c index 95e04b39415..4f815a8bd24 100644 --- a/src/lib/ldap/map.c +++ b/src/lib/ldap/map.c @@ -266,7 +266,7 @@ int fr_ldap_map_expand(fr_ldap_map_exp_t *expanded, REQUEST *request, vp_map_t c for (map = maps; map != NULL; map = map->next) { if (tmpl_expand(&attr, attr_buff, sizeof(attr_buff), request, map->rhs, NULL, NULL) < 0) { - RDEBUG("Expansion of LDAP attribute \"%s\" failed", map->rhs->name); + REDEBUG("Expansion of LDAP attribute \"%s\" failed", map->rhs->name); TALLOC_FREE(ctx); return -1; } diff --git a/src/lib/redis/cluster.c b/src/lib/redis/cluster.c index db5b34940ed..a80a2a8288a 100644 --- a/src/lib/redis/cluster.c +++ b/src/lib/redis/cluster.c @@ -1004,14 +1004,14 @@ static cluster_rcode_t cluster_remap(REQUEST *request, fr_redis_cluster_t *clust */ if (cluster->remapping) { in_progress: - RDEBUG("Cluster remapping in progress, ignoring remap request"); + RDEBUG2("Cluster remapping in progress, ignoring remap request"); return CLUSTER_OP_IGNORED; } now = time(NULL); if (now == cluster->last_updated) { too_soon: - RDEBUG("Cluster was updated less than a second ago, ignoring remap request"); + RWARN("Cluster was updated less than a second ago, ignoring remap request"); return CLUSTER_OP_IGNORED; } @@ -1903,7 +1903,7 @@ fr_redis_rcode_t fr_redis_cluster_state_next(fr_redis_cluster_state_t *state, fr if (!fr_cond_assert(*reply)) return REDIS_RCODE_ERROR; - RDEBUG("[%i] Processing redirect \"%s\"", state->node->id, (*reply)->str); + RDEBUG2("[%i] Processing redirect \"%s\"", state->node->id, (*reply)->str); if (state->redirects++ >= cluster->conf->max_redirects) { REDEBUG("[%i] Reached max_redirects (%i)", state->node->id, state->redirects); return REDIS_RCODE_ERROR; @@ -1917,8 +1917,8 @@ fr_redis_rcode_t fr_redis_cluster_state_next(fr_redis_cluster_state_t *state, fr return REDIS_RCODE_ERROR; } - RDEBUG("[%i] Redirected from %s:%i to [%i] %s:%i", state->node->id, state->node->name, - state->node->addr.port, new->id, new->name, new->addr.port); + RDEBUG2("[%i] Redirected from %s:%i to [%i] %s:%i", state->node->id, state->node->name, + state->node->addr.port, new->id, new->name, new->addr.port); state->node = new; *conn = fr_pool_connection_get(state->node->pool, request); diff --git a/src/lib/server/log.h b/src/lib/server/log.h index 87ff1a63241..9b76cb40555 100644 --- a/src/lib/server/log.h +++ b/src/lib/server/log.h @@ -251,8 +251,8 @@ void log_global_free(void); * **Debug levels** * Level | Debug arguments | Macro(s) enabled | When to use * -------- | ----------------------- | --------------------- | ----------- - * 1 | ``-x`` | R*DEBUG | Never - Deprecated - * 2 | ``-xx`` or ``-X`` | R*DEBUG, R*DEBUG2 | Normal request flow. Operations, Results of queries, or execs, etc... + * 1 | ``-x`` | R*DEBUG | Packet processing, entering/exiting virtual servers, results of module calls + * 2 | ``-xx`` or ``-X`` | R*DEBUG, R*DEBUG2 | Unlang keyword evaluation. Module debug output, results of queries, or execs, etc... * 3 | ``-xxx`` or ``-Xx`` | R*DEBUG, R*DEBUG[2-3] | Internal server state or packet input. State machine changes, extra attribute info, etc... * 4 | ``-xxxx`` or ``-Xxx`` | R*DEBUG, R*DEBUG[2-4] | Verbose internal server state messages or packet input. Hex dumps, structure dumps, pointer values. * 5 | ``-xxxxx`` or ``-Xxxx`` | R*DEBUG, R*DEBUG[2-5] | Low level internal server state messages. diff --git a/src/lib/server/map.c b/src/lib/server/map.c index 56218bbccc0..e0b369528ce 100644 --- a/src/lib/server/map.c +++ b/src/lib/server/map.c @@ -44,12 +44,12 @@ RCSID("$Id$") #ifdef DEBUG_MAP static void map_dump(REQUEST *request, vp_map_t const *map) { - RDEBUG(">>> MAP TYPES LHS: %s, RHS: %s", - fr_int2str(tmpl_type_table, map->lhs->type, "???"), - fr_int2str(tmpl_type_table, map->rhs->type, "???")); + RDEBUG2(">>> MAP TYPES LHS: %s, RHS: %s", + fr_int2str(tmpl_type_table, map->lhs->type, "???"), + fr_int2str(tmpl_type_table, map->rhs->type, "???")); if (map->rhs) { - RDEBUG(">>> MAP NAMES %s %s", map->lhs->name, map->rhs->name); + RDEBUG2(">>> MAP NAMES %s %s", map->lhs->name, map->rhs->name); } } #endif @@ -1594,8 +1594,8 @@ static inline void map_list_mod_debug(REQUEST *request, * If it's an exec, ignore the list */ if (map->rhs->type == TMPL_TYPE_EXEC) { - RDEBUG("%s %s %s%pV%s", mod->lhs->name, fr_int2str(fr_tokens_table, mod->op, ""), - quote, vb, quote); + RDEBUG2("%s %s %s%pV%s", mod->lhs->name, fr_int2str(fr_tokens_table, mod->op, ""), + quote, vb, quote); return; } @@ -1637,7 +1637,7 @@ static inline void map_list_mod_debug(REQUEST *request, switch (map->lhs->type) { case TMPL_TYPE_ATTR: case TMPL_TYPE_LIST: - RDEBUG("%s %s %s", map->lhs->name, fr_int2str(fr_tokens_table, mod->op, ""), rhs); + RDEBUG2("%s %s %s", map->lhs->name, fr_int2str(fr_tokens_table, mod->op, ""), rhs); break; default: @@ -2922,14 +2922,14 @@ void map_debug_log(REQUEST *request, vp_map_t const *map, VALUE_PAIR const *vp) */ if (vp) { tmpl_snprint(buffer, sizeof(buffer), map->lhs); - RDEBUG("%s%s %s %s", buffer, vp->da->name, fr_int2str(fr_tokens_table, vp->op, ""), rhs); + RDEBUG2("%s%s %s %s", buffer, vp->da->name, fr_int2str(fr_tokens_table, vp->op, ""), rhs); break; } /* FALL-THROUGH */ case TMPL_TYPE_ATTR: tmpl_snprint(buffer, sizeof(buffer), map->lhs); - RDEBUG("%s %s %s", buffer, fr_int2str(fr_tokens_table, vp ? vp->op : map->op, ""), rhs); + RDEBUG2("%s %s %s", buffer, fr_int2str(fr_tokens_table, vp ? vp->op : map->op, ""), rhs); break; default: diff --git a/src/lib/server/module.c b/src/lib/server/module.c index 783629c0632..ed3eb40ecdc 100644 --- a/src/lib/server/module.c +++ b/src/lib/server/module.c @@ -341,7 +341,7 @@ bool module_section_type_set(REQUEST *request, fr_dict_attr_t const *type_da, fr case 0: fr_value_box_copy(vp, &vp->data, enumv->value); vp->data.enumv = vp->da; /* So we get the correct string alias */ - RDEBUG("Setting &control:%pP", vp); + RDEBUG2("Setting &control:%pP", vp); return true; case 1: diff --git a/src/lib/server/xlat_func.c b/src/lib/server/xlat_func.c index 030b6c12f5b..130c28f90ba 100644 --- a/src/lib/server/xlat_func.c +++ b/src/lib/server/xlat_func.c @@ -1852,7 +1852,7 @@ static ssize_t parse_pad(vp_tmpl_t **vpt_p, size_t *pad_len_p, char *pad_char_p, while (isspace((int) *p)) p++; if (*p != '&') { - RDEBUG("First argument must be an attribute reference"); + REDEBUG("First argument must be an attribute reference"); return 0; } @@ -1869,7 +1869,7 @@ static ssize_t parse_pad(vp_tmpl_t **vpt_p, size_t *pad_len_p, char *pad_char_p, pad_len = strtoul(p, &end, 10); if ((pad_len == ULONG_MAX) || (pad_len > 8192)) { talloc_free(vpt); - RDEBUG("Invalid pad_len found at: %s", p); + REDEBUG("Invalid pad_len found at: %s", p); return fmt - p; } @@ -1884,7 +1884,7 @@ static ssize_t parse_pad(vp_tmpl_t **vpt_p, size_t *pad_len_p, char *pad_char_p, if (*p) { if (!isspace(*p)) { talloc_free(vpt); - RDEBUG("Invalid text found at: %s", p); + REDEBUG("Invalid text found at: %s", p); return fmt - p; } @@ -1892,7 +1892,7 @@ static ssize_t parse_pad(vp_tmpl_t **vpt_p, size_t *pad_len_p, char *pad_char_p, if (p[1] != '\0') { talloc_free(vpt); - RDEBUG("Invalid text found at: %s", p); + REDEBUG("Invalid text found at: %s", p); return fmt - p; } diff --git a/src/lib/soh/soh.c b/src/lib/soh/soh.c index 543fac057f7..c6ec828e3e4 100644 --- a/src/lib/soh/soh.c +++ b/src/lib/soh/soh.c @@ -199,7 +199,7 @@ static int eap_peap_soh_mstlv(REQUEST *request, uint8_t const *p, unsigned int d */ case 1: if (data_len < 18) { - RDEBUG("insufficient data for MS-Machine-Inventory-Packet"); + RDEBUG2("insufficient data for MS-Machine-Inventory-Packet"); return 0; } data_len -= 18; @@ -339,7 +339,7 @@ static int eap_peap_soh_mstlv(REQUEST *request, uint8_t const *p, unsigned int d break; default: - RDEBUG("SoH Unknown MS TV %i stopping", c); + RDEBUG2("SoH Unknown MS TV %i stopping", c); return 0; } } @@ -437,14 +437,14 @@ int soh_verify(REQUEST *request, uint8_t const *data, unsigned int data_len) { hdr.tlv_vendor = soh_pull_be_32(data); data += 4; if (hdr.tlv_type != 7 || hdr.tlv_vendor != 0x137) { - RDEBUG("SoH payload is %i %08x not a ms-vendor packet", hdr.tlv_type, hdr.tlv_vendor); + RDEBUG2("SoH payload is %i %08x not a ms-vendor packet", hdr.tlv_type, hdr.tlv_vendor); return -1; } hdr.soh_type = soh_pull_be_16(data); data += 2; hdr.soh_len = soh_pull_be_16(data); data += 2; if (hdr.soh_type != 1) { - RDEBUG("SoH tlv %04x is not a response", hdr.soh_type); + RDEBUG2("SoH tlv %04x is not a response", hdr.soh_type); return -1; } @@ -457,13 +457,13 @@ int soh_verify(REQUEST *request, uint8_t const *data, unsigned int data_len) { if ((resp.outer_type != 7) || (resp.vendor != 0x137)) { - RDEBUG("SoH response outer type %i/vendor %08x not recognised", resp.outer_type, resp.vendor); + RDEBUG2("SoH response outer type %i/vendor %08x not recognised", resp.outer_type, resp.vendor); return -1; } switch (resp.inner_type) { case 1: /* no mode sub-header */ - RDEBUG("SoH without mode subheader"); + RDEBUG2("SoH without mode subheader"); break; case 2: @@ -484,7 +484,7 @@ int soh_verify(REQUEST *request, uint8_t const *data, unsigned int data_len) { break; default: - RDEBUG("SoH invalid inner type %i", resp.inner_type); + RDEBUG2("SoH invalid inner type %i", resp.inner_type); return -1; } @@ -703,7 +703,7 @@ int soh_verify(REQUEST *request, uint8_t const *data, unsigned int data_len) { break; default: - RDEBUG("SoH Unknown TLV %i len=%i", tlv.tlv_type, tlv.tlv_len); + RDEBUG2("SoH Unknown TLV %i len=%i", tlv.tlv_type, tlv.tlv_len); break; } diff --git a/src/lib/tls/ocsp.c b/src/lib/tls/ocsp.c index 74e4aabe009..f62034891bd 100644 --- a/src/lib/tls/ocsp.c +++ b/src/lib/tls/ocsp.c @@ -137,7 +137,7 @@ static int ocsp_staple_to_pair(VALUE_PAIR **out, REQUEST *request, OCSP_RESPONSE uint8_t *buff, *p; if (!resp) { - RDEBUG("No response available"); + REDEBUG("No OCSP response available"); return -1; } diff --git a/src/lib/tls/validate.c b/src/lib/tls/validate.c index a22cb2c0f7b..25721e6ff31 100644 --- a/src/lib/tls/validate.c +++ b/src/lib/tls/validate.c @@ -284,21 +284,21 @@ int tls_validate_cert_cb(int ok, X509_STORE_CTX *x509_ctx) #endif fd = mkstemp(filename); if (fd < 0) { - RDEBUG("Failed creating file in %s: %s", - conf->verify_tmp_dir, fr_syserror(errno)); + RDEBUG2("Failed creating file in %s: %s", + conf->verify_tmp_dir, fr_syserror(errno)); break; } fp = fdopen(fd, "w"); if (!fp) { close(fd); - RDEBUG("Failed opening file \"%s\": %s", filename, fr_syserror(errno)); + REDEBUG("Failed opening file \"%s\": %s", filename, fr_syserror(errno)); break; } if (!PEM_write_X509(fp, cert)) { fclose(fp); - RDEBUG("Failed writing certificate to file"); + REDEBUG("Failed writing certificate to file"); goto do_unlink; } fclose(fp); @@ -312,7 +312,7 @@ int tls_validate_cert_cb(int ok, X509_STORE_CTX *x509_ctx) REDEBUG("Client certificate CN \"%s\" failed external verification", common_name); my_ok = 0; } else { - RDEBUG("Client certificate CN \"%s\" passed external validation", common_name); + RDEBUG2("Client certificate CN \"%s\" passed external validation", common_name); } do_unlink: diff --git a/src/lib/unlang/interpret.c b/src/lib/unlang/interpret.c index 622ea575c26..0612018a724 100644 --- a/src/lib/unlang/interpret.c +++ b/src/lib/unlang/interpret.c @@ -47,13 +47,13 @@ static void unlang_dump_instruction(REQUEST *request, unlang_t *instruction) { RINDENT(); if (!instruction) { - RDEBUG("instruction = NULL"); + RDEBUG2("instruction = NULL"); REXDENT(); return; } - RDEBUG("type %s", unlang_ops[instruction->type].name); - RDEBUG("name %s", instruction->name); - RDEBUG("debug_name %s", instruction->debug_name); + RDEBUG2("type %s", unlang_ops[instruction->type].name); + RDEBUG2("name %s", instruction->name); + RDEBUG2("debug_name %s", instruction->debug_name); REXDENT(); } @@ -63,15 +63,15 @@ static void unlang_dump_frame(REQUEST *request, unlang_stack_frame_t *frame) RINDENT(); if (frame->next) { - RDEBUG("next %s", frame->next->debug_name); + RDEBUG2("next %s", frame->next->debug_name); } else { - RDEBUG("next "); + RDEBUG2("next "); } - RDEBUG("top_frame %s", frame->top_frame ? "yes" : "no"); - RDEBUG("result %s", fr_int2str(mod_rcode_table, frame->result, "")); - RDEBUG("priority %d", frame->priority); - RDEBUG("unwind %d", frame->unwind); - RDEBUG("repeat %s", frame->repeat ? "yes" : "no"); + RDEBUG2("top_frame %s", frame->top_frame ? "yes" : "no"); + RDEBUG2("result %s", fr_int2str(mod_rcode_table, frame->result, "")); + RDEBUG2("priority %d", frame->priority); + RDEBUG2("unwind %d", frame->unwind); + RDEBUG2("repeat %s", frame->repeat ? "yes" : "no"); REXDENT(); } @@ -81,15 +81,15 @@ static void unlang_dump_stack(REQUEST *request) int i; unlang_stack_t *stack = request->stack; - RDEBUG("----- Begin stack debug [depth %i] -----", stack->depth); + RDEBUG2("----- Begin stack debug [depth %i] -----", stack->depth); for (i = stack->depth; i >= 0; i--) { unlang_stack_frame_t *frame = &stack->frame[i]; - RDEBUG("[%d] Frame contents", i); + RDEBUG2("[%d] Frame contents", i); unlang_dump_frame(request, frame); } - RDEBUG("----- End stack debug [depth %i] -------", stack->depth); + RDEBUG2("----- End stack debug [depth %i] -------", stack->depth); } #define DUMP_STACK if (DEBUG_ENABLED5) unlang_dump_stack(request) #else diff --git a/src/lib/unlang/module.c b/src/lib/unlang/module.c index 2771af5267d..d64b6a3725a 100644 --- a/src/lib/unlang/module.c +++ b/src/lib/unlang/module.c @@ -127,8 +127,11 @@ static unlang_action_t unlang_module(REQUEST *request, request->rcode = *presult; done: - RDEBUG2("%s (%s)", instruction->name ? instruction->name : "", - fr_int2str(mod_rcode_table, *presult, "")); + /* + * Must be left at RDEBUG() level otherwise RDEBUG becomes pointless + */ + RDEBUG("%s (%s)", instruction->name ? instruction->name : "", + fr_int2str(mod_rcode_table, *presult, "")); switch (*presult) { case RLM_MODULE_YIELD: diff --git a/src/lib/unlang/op.c b/src/lib/unlang/op.c index 33ae38859af..30269fd2f49 100644 --- a/src/lib/unlang/op.c +++ b/src/lib/unlang/op.c @@ -747,7 +747,7 @@ static unlang_action_t unlang_call(REQUEST *request, * on the caller to look at request->reply->code. */ if (final == FR_IO_YIELD) { - RDEBUG("Noo yield for you!"); + RDEBUG2("Noo yield for you!"); } /* @@ -966,7 +966,7 @@ static rlm_rcode_t unlang_parallel_run(REQUEST *request, unlang_parallel_t *stat * Run this entry. */ case CHILD_RUNNABLE: - RDEBUG("parallel - running entry %d/%d", i + 1, state->num_children); + RDEBUG2("parallel - running entry %d/%d", i + 1, state->num_children); result = unlang_run(state->children[i].child); if (result == RLM_MODULE_YIELD) { state->children[i].state = CHILD_YIELDED; @@ -995,8 +995,8 @@ static rlm_rcode_t unlang_parallel_run(REQUEST *request, unlang_parallel_t *stat * parallel section". */ if (priority == MOD_ACTION_RETURN) { - RDEBUG("child %d/%d says 'return' - skipping the remaining children", - i + 1, state->num_children); + RDEBUG2("child %d/%d says 'return' - skipping the remaining children", + i + 1, state->num_children); /* * Fall through to processing the diff --git a/src/lib/unlang/xlat.c b/src/lib/unlang/xlat.c index b461c8c05b5..f4540c159ad 100644 --- a/src/lib/unlang/xlat.c +++ b/src/lib/unlang/xlat.c @@ -380,7 +380,7 @@ static unlang_action_t unlang_xlat_inline(REQUEST *request, unlang_xlat_push(pool, &state->result, request, mx->exp, false); return UNLANG_ACTION_PUSHED_CHILD; } else { - RDEBUG("`%s`", mx->xlat_name); + RDEBUG2("`%s`", mx->xlat_name); radius_exec_program(request, NULL, 0, NULL, request, mx->xlat_name, request->packet->vps, false, true, EXEC_TIMEOUT); return UNLANG_ACTION_CONTINUE; diff --git a/src/modules/proto_dhcpv4/proto_dhcpv4.c b/src/modules/proto_dhcpv4/proto_dhcpv4.c index 73347f31e0c..f647481cc2b 100644 --- a/src/modules/proto_dhcpv4/proto_dhcpv4.c +++ b/src/modules/proto_dhcpv4/proto_dhcpv4.c @@ -263,10 +263,7 @@ static int mod_decode(void const *instance, REQUEST *request, uint8_t *const dat */ request->dict = dict_dhcpv4; - if (DEBUG_ENABLED3) { - RDEBUG("proto_dhcpv4 decode packet"); - fr_dhcpv4_print_hex(fr_log_fp, data, data_len); - } + RHEXDUMP(L_DBG_LVL_3, data, data_len, "proto_dhcpv4 decode packet"); client = address->radclient; @@ -407,10 +404,7 @@ static ssize_t mod_encode(void const *instance, REQUEST *request, uint8_t *buffe return -1; } - if (DEBUG_ENABLED3) { - RDEBUG("proto_dhcpv4 encode packet"); - fr_dhcpv4_print_hex(fr_log_fp, buffer, data_len); - } + RHEXDUMP(L_DBG_LVL_3, buffer, data_len, "proto_dhcpv4 encode packet"); request->reply->data_len = data_len; return data_len; diff --git a/src/modules/proto_vmps/proto_vmps.c b/src/modules/proto_vmps/proto_vmps.c index 47fbd784f8c..c8550927305 100644 --- a/src/modules/proto_vmps/proto_vmps.c +++ b/src/modules/proto_vmps/proto_vmps.c @@ -221,10 +221,7 @@ static int mod_decode(void const *instance, REQUEST *request, uint8_t *const dat rad_assert(data[0] < FR_MAX_PACKET_CODE); - if (DEBUG_ENABLED3) { - RDEBUG("proto_vmps decode packet"); - fr_vmps_print_hex(fr_log_fp, data, data_len); - } + RHEXDUMP(L_DBG_LVL_3, data, data_len, "proto_vmps decode packet"); /* * Set the request dictionary so that we can do @@ -369,10 +366,7 @@ static ssize_t mod_encode(void const *instance, REQUEST *request, uint8_t *buffe return -1; } - if (DEBUG_ENABLED3) { - RDEBUG("proto_vmps encode packet"); - fr_vmps_print_hex(fr_log_fp, buffer, data_len); - } + RHEXDUMP(L_DBG_LVL_3, buffer, data_len, "proto_vmps encode packet"); return data_len; } diff --git a/src/modules/rlm_cache/rlm_cache.c b/src/modules/rlm_cache/rlm_cache.c index a40d201e573..57d8acc30e8 100644 --- a/src/modules/rlm_cache/rlm_cache.c +++ b/src/modules/rlm_cache/rlm_cache.c @@ -173,7 +173,7 @@ static rlm_rcode_t cache_merge(rlm_cache_t const *inst, REQUEST *request, rlm_ca map_snprint(buffer, sizeof(buffer), map); REXDENT(); - RDEBUG("Skipping %s", buffer); + RDEBUG2("Skipping %s", buffer); RINDENT(); continue; } @@ -212,7 +212,7 @@ static rlm_rcode_t cache_find(rlm_cache_entry_t **out, rlm_cache_t const *inst, ret = inst->driver->find(&c, &inst->config, inst->driver_inst->data, request, *handle, key, key_len); switch (ret) { case CACHE_RECONNECT: - RDEBUG("Reconnecting..."); + RDEBUG2("Reconnecting..."); if (cache_reconnect(handle, inst, request) == 0) continue; return RLM_MODULE_FAIL; @@ -264,7 +264,7 @@ static rlm_rcode_t cache_find(rlm_cache_entry_t **out, rlm_cache_t const *inst, static rlm_rcode_t cache_expire(rlm_cache_t const *inst, REQUEST *request, rlm_cache_handle_t **handle, uint8_t const *key, size_t key_len) { - RDEBUG("Expiring cache entry"); + RDEBUG2("Expiring cache entry"); for (;;) switch (inst->driver->expire(&inst->config, inst->driver_inst->data, request, *handle, key, key_len)) { case CACHE_RECONNECT: @@ -318,7 +318,7 @@ static rlm_rcode_t cache_insert(rlm_cache_t const *inst, REQUEST *request, rlm_c last = &c->maps; - RDEBUG("Creating new cache entry"); + RDEBUG2("Creating new cache entry"); /* * Alloc a pool so we don't have excessive allocs when @@ -336,7 +336,7 @@ static rlm_rcode_t cache_insert(rlm_cache_t const *inst, REQUEST *request, rlm_c * as if this were an update section. */ if (map_to_vp(pool, &to_cache, request, map, NULL) < 0) { - RDEBUG("Skipping %s", map->rhs->name); + RDEBUG2("Skipping %s", map->rhs->name); continue; } @@ -457,7 +457,7 @@ static rlm_rcode_t cache_insert(rlm_cache_t const *inst, REQUEST *request, rlm_c return RLM_MODULE_FAIL; case CACHE_OK: - RDEBUG("Committed entry, TTL %d seconds", ttl); + RDEBUG2("Committed entry, TTL %d seconds", ttl); cache_free(inst, &c); return merge ? RLM_MODULE_UPDATED : RLM_MODULE_OK; @@ -491,7 +491,7 @@ static rlm_rcode_t cache_set_ttl(rlm_cache_t const *inst, REQUEST *request, return RLM_MODULE_FAIL; case CACHE_OK: - RDEBUG("Updated entry TTL"); + RDEBUG2("Updated entry TTL"); return RLM_MODULE_OK; default: @@ -513,7 +513,7 @@ static rlm_rcode_t cache_set_ttl(rlm_cache_t const *inst, REQUEST *request, return RLM_MODULE_FAIL; case CACHE_OK: - RDEBUG("Updated entry TTL"); + RDEBUG2("Updated entry TTL"); return RLM_MODULE_OK; default: diff --git a/src/modules/rlm_chap/rlm_chap.c b/src/modules/rlm_chap/rlm_chap.c index 069a730518b..986e5edc664 100644 --- a/src/modules/rlm_chap/rlm_chap.c +++ b/src/modules/rlm_chap/rlm_chap.c @@ -76,7 +76,7 @@ static rlm_rcode_t CC_HINT(nonnull) mod_authorize(void *instance, UNUSED void *t vp = fr_pair_find_by_da(request->packet->vps, attr_chap_challenge, TAG_ANY); if (!vp) { - RDEBUG("creating CHAP-Challenge from the request authenticator"); + RDEBUG2("Creating CHAP-Challenge from the request authenticator"); MEM(vp = fr_pair_afrom_da(request->packet, attr_chap_challenge)); fr_pair_value_memcpy(vp, request->packet->vector, sizeof(request->packet->vector)); @@ -173,7 +173,7 @@ static rlm_rcode_t CC_HINT(nonnull) mod_authenticate(UNUSED void *instance, UNUS return RLM_MODULE_REJECT; } - RDEBUG("CHAP user \"%pV\" authenticated successfully", &request->username->data); + RDEBUG2("CHAP user \"%pV\" authenticated successfully", &request->username->data); return RLM_MODULE_OK; } diff --git a/src/modules/rlm_client/rlm_client.c b/src/modules/rlm_client/rlm_client.c index 5f8924fcf35..7c197d3df5f 100644 --- a/src/modules/rlm_client/rlm_client.c +++ b/src/modules/rlm_client/rlm_client.c @@ -143,7 +143,8 @@ static rlm_rcode_t map_proc_client(UNUSED void *mod_inst, UNUSED void *proc_inst client = client_find(NULL, &ip, IPPROTO_IP); if (!client) { RDEBUG("No client found with IP \"%s\"", client_str); - return 0; + rcode = RLM_MODULE_NOTFOUND; + goto finish; } if (client->cs) { @@ -172,7 +173,7 @@ static rlm_rcode_t map_proc_client(UNUSED void *mod_inst, UNUSED void *proc_inst char *field = NULL; if (tmpl_aexpand(request, &field, request, map->rhs, NULL, NULL) < 0) { - RDEBUG("Failed expanding RHS at %s", map->lhs->name); + REDEBUG("Failed expanding RHS at %s", map->lhs->name); rcode = RLM_MODULE_FAIL; talloc_free(field); break; @@ -277,30 +278,30 @@ static rlm_rcode_t CC_HINT(nonnull) mod_authorize(UNUSED void *instance, UNUSED */ if ((request->packet->src_port != 0) || (request->packet->vps != NULL) || (request->parent != NULL)) { - RDEBUG("Improper configuration"); + REDEBUG("Improper configuration"); return RLM_MODULE_NOOP; } if (!request->client || !request->client->cs) { - RDEBUG("Unknown client definition"); + REDEBUG("Unknown client definition"); return RLM_MODULE_NOOP; } cp = cf_pair_find(request->client->cs, "directory"); if (!cp) { - RDEBUG("No directory configuration in the client"); + REDEBUG("No directory configuration in the client"); return RLM_MODULE_NOOP; } value = cf_pair_value(cp); if (!value) { - RDEBUG("No value given for the directory entry in the client"); + REDEBUG("No value given for the directory entry in the client"); return RLM_MODULE_NOOP; } length = strlen(value); if (length > (sizeof(buffer) - 256)) { - RDEBUG("Directory name too long"); + REDEBUG("Directory name too long"); return RLM_MODULE_NOOP; } diff --git a/src/modules/rlm_couchbase/rlm_couchbase.c b/src/modules/rlm_couchbase/rlm_couchbase.c index 818764c059d..a720d0172a9 100644 --- a/src/modules/rlm_couchbase/rlm_couchbase.c +++ b/src/modules/rlm_couchbase/rlm_couchbase.c @@ -257,7 +257,7 @@ static rlm_rcode_t mod_accounting(void *instance, UNUSED void *thread, REQUEST * /* sanity check */ if ((vp = fr_pair_find_by_da(request->packet->vps, attr_acct_status_type, TAG_ANY)) == NULL) { /* log debug */ - RDEBUG("could not find status type in packet"); + RDEBUG2("could not find status type in packet"); /* return */ return RLM_MODULE_NOOP; } @@ -268,7 +268,7 @@ static rlm_rcode_t mod_accounting(void *instance, UNUSED void *thread, REQUEST * /* acknowledge the request but take no action */ if (status == FR_STATUS_ACCOUNTING_ON || status == FR_STATUS_ACCOUNTING_OFF) { /* log debug */ - RDEBUG("handling accounting on/off request without action"); + RDEBUG2("handling accounting on/off request without action"); /* return */ return RLM_MODULE_OK; } @@ -321,7 +321,7 @@ static rlm_rcode_t mod_accounting(void *instance, UNUSED void *thread, REQUEST * /* start json document if needed */ if (docfound != 1) { /* debugging */ - RDEBUG("no existing document found - creating new json document"); + RDEBUG2("no existing document found - creating new json document"); /* create new json object */ cookie->jobj = json_object_new_object(); /* set 'docType' element for new document */ diff --git a/src/modules/rlm_csv/rlm_csv.c b/src/modules/rlm_csv/rlm_csv.c index 1037abfdf52..902677b2b26 100644 --- a/src/modules/rlm_csv/rlm_csv.c +++ b/src/modules/rlm_csv/rlm_csv.c @@ -505,7 +505,7 @@ static rlm_rcode_t mod_map_proc(void *mod_inst, UNUSED void *proc_inst, REQUEST if (map->rhs->type != TMPL_TYPE_UNPARSED) { if (tmpl_aexpand(request, &field_name, request, map->rhs, NULL, NULL) < 0) { REXDENT(); - RDEBUG("Failed expanding RHS at %s", map->lhs->name); + REDEBUG("Failed expanding RHS at %s", map->lhs->name); rcode = RLM_MODULE_FAIL; goto finish; } @@ -519,7 +519,7 @@ static rlm_rcode_t mod_map_proc(void *mod_inst, UNUSED void *proc_inst, REQUEST if (field < 0) { REXDENT(); - RDEBUG("No such field name %s", map->rhs->name); + REDEBUG("No such field name %s", map->rhs->name); rcode = RLM_MODULE_FAIL; goto finish; } diff --git a/src/modules/rlm_digest/rlm_digest.c b/src/modules/rlm_digest/rlm_digest.c index 0d383e58be9..1415e0207f4 100644 --- a/src/modules/rlm_digest/rlm_digest.c +++ b/src/modules/rlm_digest/rlm_digest.c @@ -105,7 +105,7 @@ static int digest_fix(REQUEST *request) /* * Check for proper format of the Digest-Attributes */ - RDEBUG("Checking for correctly formatted Digest-Attributes"); + RDEBUG2("Checking for correctly formatted Digest-Attributes"); rad_assert(attr_digest_attributes); first = fr_cursor_iter_by_da_init(&cursor, &request->packet->vps, attr_digest_attributes); @@ -127,7 +127,7 @@ static int digest_fix(REQUEST *request) * The attribute type must be valid */ if ((p[0] == 0) || (p[0] > 10)) { - RDEBUG("Not formatted as Digest-Attributes: subtlv (%u) invalid", (unsigned int) p[0]); + RDEBUG2("Not formatted as Digest-Attributes: subtlv (%u) invalid", (unsigned int) p[0]); return RLM_MODULE_NOOP; } @@ -137,7 +137,7 @@ static int digest_fix(REQUEST *request) * Too short. */ if (attr_len < 3) { - RDEBUG("Not formatted as Digest-Attributes: TLV too short"); + RDEBUG2("Not formatted as Digest-Attributes: TLV too short"); return RLM_MODULE_NOOP; } @@ -145,7 +145,7 @@ static int digest_fix(REQUEST *request) * Too long. */ if (p + attr_len > end) { - RDEBUG("Not formatted as Digest-Attributes: TLV too long)"); + RDEBUG2("Not formatted as Digest-Attributes: TLV too long)"); return RLM_MODULE_NOOP; } @@ -159,7 +159,7 @@ static int digest_fix(REQUEST *request) /* * Convert them to something sane. */ - RDEBUG("Digest-Attributes validated, unpacking into interal attributes"); + RDEBUG2("Digest-Attributes validated, unpacking into interal attributes"); fr_cursor_head(&cursor); for (i = fr_cursor_head(&cursor); i; diff --git a/src/modules/rlm_eap/eap.c b/src/modules/rlm_eap/eap.c index 475b6584805..cbc609bf575 100644 --- a/src/modules/rlm_eap/eap.c +++ b/src/modules/rlm_eap/eap.c @@ -866,7 +866,7 @@ eap_session_t *eap_session_continue(eap_packet_raw_t **eap_packet_p, rlm_eap_t c case FR_EAP_IDENTITY: eap_session->identity = eap_identity(request, eap_session, eap_packet); if (!eap_session->identity) { - RDEBUG("Invalid identity response"); + REDEBUG("Invalid identity response"); goto error_session; } @@ -891,7 +891,7 @@ eap_session_t *eap_session_continue(eap_packet_raw_t **eap_packet_p, rlm_eap_t c case FR_EAP_INVALID: case FR_EAP_NOTIFICATION: case FR_EAP_NAK: - RDEBUG("Initial EAP method (%u) invalid", eap_packet->data[0]); + REDEBUG("Initial EAP method (%u) invalid", eap_packet->data[0]); goto error_session; /* diff --git a/src/modules/rlm_eap/rlm_eap.c b/src/modules/rlm_eap/rlm_eap.c index cca29de296c..eddd15dbeb8 100644 --- a/src/modules/rlm_eap/rlm_eap.c +++ b/src/modules/rlm_eap/rlm_eap.c @@ -284,7 +284,7 @@ static eap_type_t eap_process_nak(rlm_eap_t *inst, REQUEST *request, * common choices. */ if (nak->data[i] == 0) { - RDEBUG("Peer NAK'd indicating it is not willing to continue "); + REDEBUG("Peer NAK'd indicating it is not willing to continue "); return FR_EAP_INVALID; } @@ -339,7 +339,7 @@ static eap_type_t eap_process_nak(rlm_eap_t *inst, REQUEST *request, continue; } - RDEBUG("Found mutually acceptable type %s (%d)", eap_type2name(nak->data[i]), nak->data[i]); + RDEBUG2("Found mutually acceptable type %s (%d)", eap_type2name(nak->data[i]), nak->data[i]); method = nak->data[i]; diff --git a/src/modules/rlm_eap/types/rlm_eap_aka/rlm_eap_aka.c b/src/modules/rlm_eap/types/rlm_eap_aka/rlm_eap_aka.c index 009ccea02d3..2d1f5863782 100644 --- a/src/modules/rlm_eap/types/rlm_eap_aka/rlm_eap_aka.c +++ b/src/modules/rlm_eap/types/rlm_eap_aka/rlm_eap_aka.c @@ -814,7 +814,7 @@ static int process_eap_aka_challenge(eap_session_t *eap_session, VALUE_PAIR *vps } if (memcmp(checkcode->vp_octets, eap_aka_session->checkcode, eap_aka_session->checkcode_len) == 0) { - RDEBUG("EAP-AKA-Checkcode matches calculated checkcode"); + RDEBUG2("EAP-AKA-Checkcode matches calculated checkcode"); } else { REDEBUG("EAP-AKA-Checkcode does not match calculated checkcode"); RHEXDUMP_INLINE(L_DBG_LVL_2, checkcode->vp_octets, checkcode->vp_length, "Received"); diff --git a/src/modules/rlm_eap/types/rlm_eap_fast/eap_fast.c b/src/modules/rlm_eap/types/rlm_eap_fast/eap_fast.c index dfb28d71201..be1910c1c55 100644 --- a/src/modules/rlm_eap/types/rlm_eap_fast/eap_fast.c +++ b/src/modules/rlm_eap/types/rlm_eap_fast/eap_fast.c @@ -139,7 +139,7 @@ static void eap_fast_send_identity_request(REQUEST *request, tls_session_t *tls_ { eap_packet_raw_t eap_packet; - RDEBUG("Sending EAP-Identity"); + RDEBUG2("Sending EAP-Identity"); eap_packet.code = FR_EAP_CODE_REQUEST; eap_packet.id = eap_session->this_round->response->id + 1; @@ -160,7 +160,7 @@ static void eap_fast_send_pac_tunnel(REQUEST *request, tls_session_t *tls_sessio memset(&pac, 0, sizeof(pac)); memset(&opaque_plaintext, 0, sizeof(opaque_plaintext)); - RDEBUG("Sending Tunnel PAC"); + RDEBUG2("Sending Tunnel PAC"); pac.key.hdr.type = htons(EAP_FAST_TLV_MANDATORY | attr_eap_fast_pac_key->attr); pac.key.hdr.length = htons(sizeof(pac.key.data)); @@ -218,7 +218,7 @@ static void eap_fast_append_crypto_binding(REQUEST *request, tls_session_t *tls_ eap_tlv_crypto_binding_tlv_t binding = {0}; int const len = sizeof(binding) - (&binding.reserved - (uint8_t *)&binding); - RDEBUG("Sending Cryptobinding"); + RDEBUG2("Sending Cryptobinding"); binding.tlv_type = htons(EAP_FAST_TLV_MANDATORY | attr_eap_fast_crypto_binding->attr); binding.length = htons(len); @@ -274,22 +274,22 @@ static int eap_fast_verify(REQUEST *request, tls_session_t *tls_session, uint8_t present |= 1 << attr; if (num[attr_eap_fast_eap_payload->attr] > 1) { - RDEBUG("Too many EAP-Payload TLVs"); + REDEBUG("Too many EAP-Payload TLVs"); unexpected: for (int i = 0; i < EAP_FAST_TLV_MAX; i++) { - if (present & (1 << i)) RDEBUG(" - attribute %d is present", i); + if (present & (1 << i)) RDEBUG2(" - attribute %d is present", i); } eap_fast_send_error(tls_session, EAP_FAST_ERR_UNEXPECTED_TLV); return 0; } if (num[attr_eap_fast_intermediate_result->attr] > 1) { - RDEBUG("Too many Intermediate-Result TLVs"); + REDEBUG("Too many Intermediate-Result TLVs"); goto unexpected; } } else { if ((data[0] & 0x80) != 0) { - RDEBUG("Unknown mandatory TLV %02x", attr); + REDEBUG("Unknown mandatory TLV %02x", attr); goto unexpected; } @@ -331,7 +331,7 @@ unexpected: uint16_t status; if (length < 2) { - RDEBUG("EAP-FAST TLV %u is too short. Expected 2, got %d.", attr, length); + REDEBUG("EAP-FAST TLV %u is too short. Expected 2, got %d", attr, length); return 0; } @@ -339,12 +339,12 @@ unexpected: status = ntohs(status); if (status == EAP_FAST_TLV_RESULT_FAILURE) { - RDEBUG("EAP-FAST TLV %u indicates failure. Rejecting request.", attr); + REDEBUG("EAP-FAST TLV %u indicates failure. Rejecting request", attr); return 0; } if (status != EAP_FAST_TLV_RESULT_SUCCESS) { - RDEBUG("EAP-FAST TLV %u contains unknown value. Rejecting request.", attr); + REDEBUG("EAP-FAST TLV %u contains unknown value. Rejecting request", attr); goto unexpected; } } @@ -360,12 +360,12 @@ unexpected: * Check if the peer mixed & matched TLVs. */ if ((num[attr_eap_fast_nak->attr] > 0) && (num[attr_eap_fast_nak->attr] != total)) { - RDEBUG("NAK TLV sent with non-NAK TLVs. Rejecting request."); + REDEBUG("NAK TLV sent with non-NAK TLVs. Rejecting request"); goto unexpected; } if (num[attr_eap_fast_intermediate_result->attr] > 0) { - RDEBUG("NAK TLV sent with non-NAK TLVs. Rejecting request."); + REDEBUG("NAK TLV sent with non-NAK TLVs. Rejecting request"); goto unexpected; } @@ -375,13 +375,13 @@ unexpected: switch (t->stage) { case EAP_FAST_TLS_SESSION_HANDSHAKE: if (present) { - RDEBUG("Unexpected TLVs in TLS Session Handshake stage"); + REDEBUG("Unexpected TLVs in TLS Session Handshake stage"); goto unexpected; } break; case EAP_FAST_AUTHENTICATION: if (present != (uint32_t)(1 << attr_eap_fast_eap_payload->attr)) { - RDEBUG("Unexpected TLVs in authentication stage"); + REDEBUG("Unexpected TLVs in authentication stage"); goto unexpected; } break; @@ -391,25 +391,25 @@ unexpected: ? 1 << attr_eap_fast_result->attr : 1 << attr_eap_fast_intermediate_result->attr; if (present & ~(bits | (1 << attr_eap_fast_crypto_binding->attr) | (1 << attr_eap_fast_pac_tlv->attr))) { - RDEBUG("Unexpected TLVs in cryptobind checking stage"); + REDEBUG("Unexpected TLVs in cryptobind checking stage"); goto unexpected; } break; } case EAP_FAST_PROVISIONING: if (present & ~((1 << attr_eap_fast_pac_tlv->attr) | (1 << attr_eap_fast_result->attr))) { - RDEBUG("Unexpected TLVs in provisioning stage"); + REDEBUG("Unexpected TLVs in provisioning stage"); goto unexpected; } break; case EAP_FAST_COMPLETE: if (present) { - RDEBUG("Unexpected TLVs in complete stage"); + REDEBUG("Unexpected TLVs in complete stage"); goto unexpected; } break; default: - RDEBUG("Unexpected stage %d", t->stage); + REDEBUG("Unexpected stage %d", t->stage); return 0; } @@ -493,7 +493,7 @@ static rlm_rcode_t CC_HINT(nonnull) process_reply(NDEBUG_UNUSED eap_session_t *e */ switch (reply->code) { case FR_CODE_ACCESS_ACCEPT: - RDEBUG("Got tunneled Access-Accept"); + RDEBUG2("Got tunneled Access-Accept"); rcode = RLM_MODULE_OK; @@ -522,7 +522,7 @@ static rlm_rcode_t CC_HINT(nonnull) process_reply(NDEBUG_UNUSED eap_session_t *e break; case FR_MSCHAP2_SUCCESS: - RDEBUG("Got %s, tunneling it to the client in a challenge", vp->da->name); + RDEBUG2("Got %s, tunneling it to the client in a challenge", vp->da->name); rcode = RLM_MODULE_HANDLED; t->authenticated = true; break; @@ -536,12 +536,12 @@ static rlm_rcode_t CC_HINT(nonnull) process_reply(NDEBUG_UNUSED eap_session_t *e break; case FR_CODE_ACCESS_REJECT: - RDEBUG("Got tunneled Access-Reject"); + REDEBUG("Got tunneled Access-Reject"); rcode = RLM_MODULE_REJECT; break; case FR_CODE_ACCESS_CHALLENGE: - RDEBUG("Got tunneled Access-Challenge"); + RDEBUG2("Got tunneled Access-Challenge"); /* * Copy the EAP-Message back to the tunnel. @@ -558,7 +558,7 @@ static rlm_rcode_t CC_HINT(nonnull) process_reply(NDEBUG_UNUSED eap_session_t *e break; default: - RDEBUG("Unknown RADIUS packet type %d: rejecting tunneled user", reply->code); + REDEBUG("Unknown RADIUS packet type %d: rejecting tunneled user", reply->code); rcode = RLM_MODULE_INVALID; break; } @@ -575,7 +575,7 @@ static FR_CODE eap_fast_eap_payload(REQUEST *request, eap_session_t *eap_session eap_fast_tunnel_t *t; REQUEST *fake; - RDEBUG("Processing received EAP Payload"); + RDEBUG2("Processing received EAP Payload"); /* * Allocate a fake REQUEST structure. @@ -592,7 +592,7 @@ static FR_CODE eap_fast_eap_payload(REQUEST *request, eap_session_t *eap_session fake->packet->vps = fr_pair_afrom_da(fake->packet, attr_eap_message); fr_pair_value_memcpy(fake->packet->vps, tlv_eap_payload->vp_octets, tlv_eap_payload->vp_length); - RDEBUG("Got tunneled request"); + RDEBUG2("Got tunneled request"); log_request_pair_list(L_DBG_LVL_1, request, fake->packet->vps, NULL); /* @@ -629,7 +629,7 @@ static FR_CODE eap_fast_eap_payload(REQUEST *request, eap_session_t *eap_session t->username->vp_tainted = true; fr_pair_value_bstrncpy(t->username, vp->vp_octets + 5, vp->vp_length - 5); - RDEBUG("Got tunneled identity of %pV", &t->username->data); + RDEBUG2("Got tunneled identity of %pV", &t->username->data); } else { /* * Don't reject the request outright, @@ -687,7 +687,7 @@ static FR_CODE eap_fast_eap_payload(REQUEST *request, eap_session_t *eap_session int ret; eap_tunnel_data_t *tunnel; - RDEBUG("Tunneled authentication will be proxied to %pV", &vp->data); + RDEBUG2("Tunneled authentication will be proxied to %pV", &vp->data); /* * Tell the original request that it's going to be proxied. @@ -745,7 +745,7 @@ static FR_CODE eap_fast_eap_payload(REQUEST *request, eap_session_t *eap_session } else #endif /* WITH_PROXY */ { - RDEBUG("No tunneled reply was found, and the request was not proxied: rejecting the user."); + REDEBUG("No tunneled reply was found, and the request was not proxied: rejecting the user"); code = FR_CODE_ACCESS_REJECT; } break; @@ -874,7 +874,7 @@ static FR_CODE eap_fast_process_tlvs(REQUEST *request, eap_session_t *eap_sessio } } else if (vp->da == attr_eap_fast_pac_info_pac_type) { if (vp->vp_uint32 != PAC_TYPE_TUNNEL) { - RDEBUG("only able to serve Tunnel PAC's, ignoring request"); + RDEBUG2("only able to serve Tunnel PAC's, ignoring request"); continue; } t->pac.send = true; @@ -947,7 +947,7 @@ FR_CODE eap_fast_process(eap_session_t *eap_session, tls_session_t *tls_session) t->pac.send = true; } else { if (SSL_session_reused(tls_session->ssl)) { - RDEBUG("Session Resumed from PAC"); + RDEBUG2("Session Resumed from PAC"); t->mode = EAP_FAST_NORMAL_AUTH; } else { RDEBUG2("Using authenticated provisioning"); @@ -971,7 +971,7 @@ FR_CODE eap_fast_process(eap_session_t *eap_session, tls_session_t *tls_session) if (eap_fast_decode_pair(request, &cursor, attr_eap_fast_tlv, data, data_len, NULL) < 0) return FR_CODE_ACCESS_REJECT; - RDEBUG("Got Tunneled FAST TLVs"); + RDEBUG2("Got Tunneled FAST TLVs"); log_request_pair_list(L_DBG_LVL_1, request, fast_vps, NULL); code = eap_fast_process_tlvs(request, eap_session, tls_session, fast_vps); fr_pair_list_free(&fast_vps); @@ -1002,7 +1002,7 @@ FR_CODE eap_fast_process(eap_session_t *eap_session, tls_session_t *tls_session) eap_fast_append_result(tls_session, code); if (t->pac.send) { - RDEBUG("Peer requires new PAC"); + RDEBUG2("Peer requires new PAC"); eap_fast_send_pac_tunnel(request, tls_session); code = FR_CODE_ACCESS_CHALLENGE; break; diff --git a/src/modules/rlm_eap/types/rlm_eap_fast/rlm_eap_fast.c b/src/modules/rlm_eap/types/rlm_eap_fast/rlm_eap_fast.c index 996dd3fd4ac..dcf15fb8ad3 100644 --- a/src/modules/rlm_eap/types/rlm_eap_fast/rlm_eap_fast.c +++ b/src/modules/rlm_eap/types/rlm_eap_fast/rlm_eap_fast.c @@ -295,7 +295,7 @@ static int _session_secret(SSL *s, void *secret, int *secret_len, if (!t->pac.key) return 0; - RDEBUG("processing PAC-Opaque"); + RDEBUG2("processing PAC-Opaque"); eap_fast_session_ticket(tls_session, s, secret, secret_len); @@ -330,7 +330,7 @@ static int _session_ticket(SSL *s, uint8_t const *data, int len, void *arg) t = talloc_get_type_abort(tls_session->opaque, eap_fast_tunnel_t); - RDEBUG("PAC provided via ClientHello SessionTicket extension"); + RDEBUG2("PAC provided via ClientHello SessionTicket extension"); RHEXDUMP(L_DBG_LVL_MAX, data, len, "PAC-Opaque"); if ((ntohs(opaque->hdr.type) & EAP_FAST_TLV_TYPE) != attr_eap_fast_pac_opaque_tlv->attr) { @@ -602,7 +602,7 @@ static rlm_rcode_t mod_session_init(void *type_arg, eap_session_t *eap_session) tls_session = eap_tls_session->tls_session; if (inst->cipher_list) { - RDEBUG("Over-riding main cipher list with '%s'", inst->cipher_list); + RDEBUG2("Over-riding main cipher list with '%s'", inst->cipher_list); if (!SSL_set_cipher_list(tls_session->ssl, inst->cipher_list)) { REDEBUG("Failed over-riding cipher list to '%s'. EAP-FAST will likely not work", diff --git a/src/modules/rlm_eap/types/rlm_eap_leap/rlm_eap_leap.c b/src/modules/rlm_eap/types/rlm_eap_leap/rlm_eap_leap.c index 362070b817f..5536de907e0 100644 --- a/src/modules/rlm_eap/types/rlm_eap_leap/rlm_eap_leap.c +++ b/src/modules/rlm_eap/types/rlm_eap_leap/rlm_eap_leap.c @@ -133,7 +133,7 @@ static rlm_rcode_t mod_process(UNUSED void *instance, eap_session_t *eap_session * Stage 2 is handled by initiate() */ default: - RDEBUG("Internal sanity check failed on stage"); + REDEBUG("Internal sanity check failed on stage"); break; } diff --git a/src/modules/rlm_eap/types/rlm_eap_peap/peap.c b/src/modules/rlm_eap/types/rlm_eap_peap/peap.c index e61ae41843b..29a23e05edf 100644 --- a/src/modules/rlm_eap/types/rlm_eap_peap/peap.c +++ b/src/modules/rlm_eap/types/rlm_eap_peap/peap.c @@ -169,37 +169,36 @@ static void eap_peap_soh_verify(REQUEST *request, RADIUS_PACKET *packet, fr_pair_add(&packet->vps, vp); if (data && data[0] == FR_EAP_NAK) { - RDEBUG("SoH - client NAKed"); + REDEBUG("SoH - client NAKed"); return; } if (!data || data_len < 8) { - RDEBUG("SoH - eap payload too short"); + REDEBUG("SoH - eap payload too short"); return; } eap_method_base = *data++; if (eap_method_base != 254) { - RDEBUG("SoH - response is not extended EAP: %i", eap_method_base); + REDEBUG("SoH - response is not extended EAP: %i", eap_method_base); return; } eap_vendor = soh_pull_be_24(data); data += 3; if (eap_vendor != 0x137) { - RDEBUG("SoH - extended eap vendor %08x is not Microsoft", eap_vendor); + REDEBUG("SoH - extended eap vendor %08x is not Microsoft", eap_vendor); return; } eap_method = soh_pull_be_32(data); data += 4; if (eap_method != 0x21) { - RDEBUG("SoH - response eap type %08x is not EAP-SoH", eap_method); + REDEBUG("SoH - response eap type %08x is not EAP-SoH", eap_method); return; } - rv = soh_verify(request, data, data_len - 8); - if (rv<0) { - RDEBUG("SoH - error decoding payload: %s", fr_strerror()); + if (rv < 0) { + REDEBUG("SoH - error decoding payload: %s", fr_strerror()); } else { vp->vp_uint32 = 1; } @@ -370,7 +369,7 @@ static int eap_peap_check_tlv(REQUEST *request, uint8_t const *data, size_t data } } - RDEBUG("Unknown TLV %02x", data[10]); + RDEBUG2("Unknown TLV %02x", data[10]); return 0; } @@ -553,7 +552,7 @@ rlm_rcode_t eap_peap_process(eap_session_t *eap_session, tls_session_t *tls_sess fr_pair_value_bstrncpy(t->username, data + 1, data_len - 1); - RDEBUG("Got inner identity \"%pV\"", &t->username->data); + RDEBUG2("Got inner identity \"%pV\"", &t->username->data); if (t->soh) { t->status = PEAP_STATUS_WAIT_FOR_SOH_RESPONSE; RDEBUG2("Requesting SoH from client"); @@ -572,7 +571,7 @@ rlm_rcode_t eap_peap_process(eap_session_t *eap_session, tls_session_t *tls_sess if (t->soh_virtual_server) fake->server_cs = virtual_server_find(t->soh_virtual_server); - RDEBUG("Sending SoH request to server %s", + RDEBUG2("Sending SoH request to server %s", fake->server_cs ? cf_section_name2(fake->server_cs) : "NULL"); rad_virtual_server(fake); @@ -654,7 +653,7 @@ rlm_rcode_t eap_peap_process(eap_session_t *eap_session, tls_session_t *tls_sess return RLM_MODULE_REJECT; case PEAP_STATUS_PHASE2_INIT: - RDEBUG("In state machine in phase2 init?"); + RDEBUG2("In state machine in phase2 init?"); case PEAP_STATUS_PHASE2: break; diff --git a/src/modules/rlm_eap/types/rlm_eap_ttls/rlm_eap_ttls.c b/src/modules/rlm_eap/types/rlm_eap_ttls/rlm_eap_ttls.c index e99db55e0cd..ba574cfa171 100644 --- a/src/modules/rlm_eap/types/rlm_eap_ttls/rlm_eap_ttls.c +++ b/src/modules/rlm_eap/types/rlm_eap_ttls/rlm_eap_ttls.c @@ -165,7 +165,7 @@ static rlm_rcode_t mod_process(void *arg, eap_session_t *eap_session) */ case EAP_TLS_ESTABLISHED: if (SSL_session_reused(tls_session->ssl)) { - RDEBUG("Skipping Phase2 due to session resumption"); + RDEBUG2("Skipping Phase2 due to session resumption"); goto do_keys; } diff --git a/src/modules/rlm_eap/types/rlm_eap_ttls/ttls.c b/src/modules/rlm_eap/types/rlm_eap_ttls/ttls.c index 241ee320dee..69363c7ca3d 100644 --- a/src/modules/rlm_eap/types/rlm_eap_ttls/ttls.c +++ b/src/modules/rlm_eap/types/rlm_eap_ttls/ttls.c @@ -481,7 +481,7 @@ static rlm_rcode_t CC_HINT(nonnull) process_reply(NDEBUG_UNUSED eap_session_t *e switch (reply->code) { case FR_CODE_ACCESS_ACCEPT: { - RDEBUG("Got tunneled Access-Accept"); + RDEBUG2("Got tunneled Access-Accept"); fr_cursor_init(&to_tunnel, &tunnel_vps); rcode = RLM_MODULE_OK; @@ -494,7 +494,7 @@ static rlm_rcode_t CC_HINT(nonnull) process_reply(NDEBUG_UNUSED eap_session_t *e vp; vp = fr_cursor_next(&cursor)) { if (vp->da == attr_ms_chap2_success) { - RDEBUG("Got MS-CHAP2-Success, tunneling it to the client in a challenge"); + RDEBUG2("Got MS-CHAP2-Success, tunneling it to the client in a challenge"); rcode = RLM_MODULE_HANDLED; t->authenticated = true; @@ -509,7 +509,7 @@ static rlm_rcode_t CC_HINT(nonnull) process_reply(NDEBUG_UNUSED eap_session_t *e break; case FR_CODE_ACCESS_REJECT: - RDEBUG("Got tunneled Access-Reject"); + REDEBUG("Got tunneled Access-Reject"); rcode = RLM_MODULE_REJECT; break; @@ -520,7 +520,7 @@ static rlm_rcode_t CC_HINT(nonnull) process_reply(NDEBUG_UNUSED eap_session_t *e * a Reply-Message to the client. */ case FR_CODE_ACCESS_CHALLENGE: - RDEBUG("Got tunneled Access-Challenge"); + RDEBUG2("Got tunneled Access-Challenge"); fr_cursor_init(&to_tunnel, &tunnel_vps); @@ -541,7 +541,7 @@ static rlm_rcode_t CC_HINT(nonnull) process_reply(NDEBUG_UNUSED eap_session_t *e break; default: - RDEBUG("Unknown RADIUS packet type %d: rejecting tunneled user", reply->code); + REDEBUG("Unknown RADIUS packet type %d: rejecting tunneled user", reply->code); rcode = RLM_MODULE_INVALID; break; } @@ -552,7 +552,7 @@ static rlm_rcode_t CC_HINT(nonnull) process_reply(NDEBUG_UNUSED eap_session_t *e * to the supplicant. */ if (tunnel_vps) { - RDEBUG("Sending tunneled reply attributes"); + RDEBUG2("Sending tunneled reply attributes"); log_request_pair_list(L_DBG_LVL_2, request, tunnel_vps, NULL); vp2diameter(request, tls_session, tunnel_vps); @@ -595,7 +595,7 @@ FR_CODE eap_ttls_process(eap_session_t *eap_session, tls_session_t *tls_session) */ if (data_len == 0) { if (t->authenticated) { - RDEBUG("Got ACK, and the user was already authenticated"); + RDEBUG2("Got ACK, and the user was already authenticated"); code = FR_CODE_ACCESS_ACCEPT; goto finish; } /* else no session, no data, die. */ @@ -638,7 +638,7 @@ FR_CODE eap_ttls_process(eap_session_t *eap_session, tls_session_t *tls_session) MEM(fr_pair_add_by_da(fake->packet, &vp, &fake->packet->vps, attr_freeradius_proxied_to) >= 0); fr_pair_value_from_str(vp, "127.0.0.1", sizeof("127.0.0.1"), '\0', false); - RDEBUG("Got tunneled request"); + RDEBUG2("Got tunneled request"); log_request_pair_list(L_DBG_LVL_1, request, fake->packet->vps, NULL); /* @@ -671,7 +671,7 @@ FR_CODE eap_ttls_process(eap_session_t *eap_session, tls_session_t *tls_session) fr_pair_value_bstrncpy(t->username, vp->vp_octets + 5, vp->vp_length - 5); - RDEBUG("Got tunneled identity of %pV", &t->username->data); + RDEBUG2("Got tunneled identity of %pV", &t->username->data); } else { /* * Don't reject the request outright, @@ -697,7 +697,7 @@ FR_CODE eap_ttls_process(eap_session_t *eap_session, tls_session_t *tls_session) FR_CODE chbind_code; CHBIND_REQ *req = talloc_zero(fake, CHBIND_REQ); - RDEBUG("received chbind request"); + RDEBUG2("received chbind request"); req->request = chbind; if (fake->username) { req->username = fake->username; @@ -708,11 +708,11 @@ FR_CODE eap_ttls_process(eap_session_t *eap_session, tls_session_t *tls_session) /* encapsulate response here */ if (req->response) { - RDEBUG("sending chbind response"); + RDEBUG2("sending chbind response"); fr_pair_add(&fake->reply->vps, eap_chbind_packet2vp(fake->reply, req->response)); } else { - RDEBUG("no chbind response"); + RDEBUG2("no chbind response"); } /* clean up chbind req */ @@ -734,7 +734,7 @@ FR_CODE eap_ttls_process(eap_session_t *eap_session, tls_session_t *tls_session) * Decide what to do with the reply. */ if (!fake->reply->code) { - RDEBUG("No tunneled reply was found for request %" PRIu64 ", and the request was not " + RDEBUG2("No tunneled reply was found for request %" PRIu64 ", and the request was not " "proxied: rejecting the user", request->number); code = FR_CODE_ACCESS_REJECT; } else { diff --git a/src/modules/rlm_example/rlm_example.c b/src/modules/rlm_example/rlm_example.c index 16059ebb5b8..22dd96ead79 100644 --- a/src/modules/rlm_example/rlm_example.c +++ b/src/modules/rlm_example/rlm_example.c @@ -125,7 +125,7 @@ static rlm_rcode_t CC_HINT(nonnull) mod_authorize(UNUSED void *instance, UNUSED */ vp = fr_pair_find_by_da(request->packet->vps, attr_state, TAG_ANY); if (vp != NULL) { - RDEBUG("Found reply to access challenge"); + RDEBUG2("Found reply to access challenge"); return RLM_MODULE_OK; } @@ -141,7 +141,7 @@ static rlm_rcode_t CC_HINT(nonnull) mod_authorize(UNUSED void *instance, UNUSED * The server will take care of sending it to the user. */ request->reply->code = FR_CODE_ACCESS_CHALLENGE; - RDEBUG("Sending Access-Challenge"); + RDEBUG2("Sending Access-Challenge"); return RLM_MODULE_HANDLED; } diff --git a/src/modules/rlm_exec/rlm_exec.c b/src/modules/rlm_exec/rlm_exec.c index 3b051ea56e9..cc48facb39d 100644 --- a/src/modules/rlm_exec/rlm_exec.c +++ b/src/modules/rlm_exec/rlm_exec.c @@ -105,7 +105,7 @@ static rlm_rcode_t rlm_exec_status2rcode(REQUEST *request, char *answer, size_t * This frees up 0, for success where it'd normally be reject. */ if (status == 0) { - RDEBUG("Program executed successfully"); + RDEBUG2("Program executed successfully"); return RLM_MODULE_OK; } diff --git a/src/modules/rlm_expiration/rlm_expiration.c b/src/modules/rlm_expiration/rlm_expiration.c index ffdabf908fa..a142c7bed41 100644 --- a/src/modules/rlm_expiration/rlm_expiration.c +++ b/src/modules/rlm_expiration/rlm_expiration.c @@ -75,7 +75,7 @@ static rlm_rcode_t CC_HINT(nonnull) mod_authorize(UNUSED void *instance, UNUSED return RLM_MODULE_USERLOCK; } - RDEBUG("Account will expire at '%pV'", &check_item->data); + RDEBUG2("Account will expire at '%pV'", &check_item->data); left = (uint32_t)(((time_t) check_item->vp_date) - request->packet->timestamp.tv_sec); @@ -88,13 +88,13 @@ static rlm_rcode_t CC_HINT(nonnull) mod_authorize(UNUSED void *instance, UNUSED /* just update... */ if (vp->vp_uint32 > (uint32_t)left) { vp->vp_uint32 = (uint32_t)left; - RDEBUG("&reply:Session-Timeout := %pV", &vp->data); + RDEBUG2("&reply:Session-Timeout := %pV", &vp->data); } break; case 0: /* no pre-existing */ vp->vp_uint32 = (uint32_t)left; - RDEBUG("&reply:Session-Timeout := %pV", &vp->data); + RDEBUG2("&reply:Session-Timeout := %pV", &vp->data); break; default: /* malloc failure */ diff --git a/src/modules/rlm_expr/rlm_expr.c b/src/modules/rlm_expr/rlm_expr.c index db9a05c2d5d..0c0efc6529f 100644 --- a/src/modules/rlm_expr/rlm_expr.c +++ b/src/modules/rlm_expr/rlm_expr.c @@ -287,7 +287,7 @@ static bool get_number(REQUEST *request, char const **string, int64_t *answer) if (!get_expression(request, &p, &x, TOKEN_NONE)) return false; if (*p != ')') { - RDEBUG("No trailing ')'"); + REDEBUG("No trailing ')'"); return false; } p++; @@ -295,7 +295,7 @@ static bool get_number(REQUEST *request, char const **string, int64_t *answer) } if ((*p < '0') || (*p > '9')) { - RDEBUG2("Not a number at \"%s\"", p); + REDEBUG("Not a number at \"%s\"", p); return false; } @@ -353,7 +353,7 @@ static bool calc_result(REQUEST *request, int64_t lhs, expr_token_t op, int64_t case TOKEN_REMAINDER: if (rhs == 0) { - RDEBUG("Division by zero!"); + REDEBUG("Division by zero!"); return false; } @@ -366,7 +366,7 @@ static bool calc_result(REQUEST *request, int64_t lhs, expr_token_t op, int64_t case TOKEN_LSHIFT: if (rhs > 62) { - RDEBUG("Shift must be less than 62 (was %lld)", (long long int) rhs); + REDEBUG("Shift must be less than 62 (was %lld)", (long long int) rhs); return false; } @@ -375,7 +375,7 @@ static bool calc_result(REQUEST *request, int64_t lhs, expr_token_t op, int64_t case TOKEN_RSHIFT: if (rhs > 62) { - RDEBUG("Shift must be less than 62 (was %lld)", (long long int) rhs); + REDEBUG("Shift must be less than 62 (was %lld)", (long long int) rhs); return false; } @@ -519,7 +519,7 @@ static ssize_t expr_xlat(UNUSED TALLOC_CTX *ctx, char **out, size_t outlen, } if (*p) { - RDEBUG("Invalid text after expression: %s", p); + REDEBUG("Invalid text after expression: %s", p); return -1; } diff --git a/src/modules/rlm_krb5/rlm_krb5.c b/src/modules/rlm_krb5/rlm_krb5.c index 192e3702c52..9ae580be48b 100644 --- a/src/modules/rlm_krb5/rlm_krb5.c +++ b/src/modules/rlm_krb5/rlm_krb5.c @@ -270,7 +270,7 @@ static rlm_rcode_t krb5_parse_user(krb5_principal *client, rlm_krb5_t const *ins } krb5_unparse_name(context, *client, &princ_name); - RDEBUG("Using client principal \"%s\"", princ_name); + RDEBUG2("Using client principal \"%s\"", princ_name); #ifdef HEIMDAL_KRB5 free(princ_name); #else @@ -307,7 +307,7 @@ static rlm_rcode_t krb5_process_error(rlm_krb5_t const *inst, REQUEST *request, return RLM_MODULE_USERLOCK; case KRB5KDC_ERR_C_PRINCIPAL_UNKNOWN: - RDEBUG("User not found (%i): %s", ret, rlm_krb5_error(inst, conn->context, ret)); + RDEBUG2("User not found (%i): %s", ret, rlm_krb5_error(inst, conn->context, ret)); return RLM_MODULE_NOTFOUND; default: @@ -426,7 +426,7 @@ static rlm_rcode_t CC_HINT(nonnull) mod_authenticate(void *instance, UNUSED void * Retrieve the TGT from the TGS/KDC and check we can decrypt it. */ memcpy(&password, &request->password->vp_strvalue, sizeof(password)); - RDEBUG("Retrieving and decrypting TGT"); + RDEBUG2("Retrieving and decrypting TGT"); ret = krb5_get_init_creds_password(conn->context, &init_creds, client, password, NULL, NULL, 0, NULL, inst->gic_options); if (ret) { @@ -434,7 +434,7 @@ static rlm_rcode_t CC_HINT(nonnull) mod_authenticate(void *instance, UNUSED void goto cleanup; } - RDEBUG("Attempting to authenticate against service principal"); + RDEBUG2("Attempting to authenticate against service principal"); ret = krb5_verify_init_creds(conn->context, &init_creds, inst->server, conn->keytab, NULL, inst->vic_options); if (ret) rcode = krb5_process_error(inst, request, conn, ret); diff --git a/src/modules/rlm_ldap/groups.c b/src/modules/rlm_ldap/groups.c index d2b88f57cac..7c3a280d031 100644 --- a/src/modules/rlm_ldap/groups.c +++ b/src/modules/rlm_ldap/groups.c @@ -80,7 +80,7 @@ static rlm_rcode_t rlm_ldap_group_name2dn(rlm_ldap_t const *inst, REQUEST *reque return RLM_MODULE_INVALID; } - RDEBUG("Converting group name(s) to group DN(s)"); + RDEBUG2("Converting group name(s) to group DN(s)"); /* * It'll probably only save a few ms in network latency, but it means we can send a query @@ -114,7 +114,7 @@ static rlm_rcode_t rlm_ldap_group_name2dn(rlm_ldap_t const *inst, REQUEST *reque break; case LDAP_PROC_NO_RESULT: - RDEBUG("Tried to resolve group name(s) to DNs but got no results"); + RDEBUG2("Tried to resolve group name(s) to DNs but got no results"); goto finish; default: @@ -162,7 +162,7 @@ static rlm_rcode_t rlm_ldap_group_name2dn(rlm_ldap_t const *inst, REQUEST *reque } fr_ldap_util_normalise_dn(*dn, *dn); - RDEBUG("Got group DN \"%s\"", *dn); + RDEBUG2("Got group DN \"%s\"", *dn); dn++; } while((entry = ldap_next_entry((*pconn)->handle, entry))); @@ -215,7 +215,7 @@ static rlm_rcode_t rlm_ldap_group_dn2name(rlm_ldap_t const *inst, REQUEST *reque return RLM_MODULE_INVALID; } - RDEBUG("Resolving group DN \"%s\" to group name", dn); + RDEBUG2("Resolving group DN \"%s\" to group name", dn); status = fr_ldap_search(&result, request, pconn, dn, LDAP_SCOPE_BASE, NULL, attrs, NULL, NULL); switch (status) { @@ -249,7 +249,7 @@ static rlm_rcode_t rlm_ldap_group_dn2name(rlm_ldap_t const *inst, REQUEST *reque } *out = fr_ldap_berval_to_string(request, values[0]); - RDEBUG("Group DN \"%s\" resolves to name \"%s\"", dn, *out); + RDEBUG2("Group DN \"%s\" resolves to name \"%s\"", dn, *out); finish: if (result) ldap_msgfree(result); @@ -383,13 +383,13 @@ rlm_rcode_t rlm_ldap_cacheable_userobj(rlm_ldap_t const *inst, REQUEST *request, fr_cursor_init(&list_cursor, list); - RDEBUG("Adding cacheable user object memberships"); + RDEBUG2("Adding cacheable user object memberships"); RINDENT(); if (RDEBUG_ENABLED) { for (vp = fr_cursor_head(&groups_cursor); vp; vp = fr_cursor_next(&groups_cursor)) { - RDEBUG("&control:%s += \"%pV\"", inst->cache_da->name, &vp->data); + RDEBUG2("&control:%s += \"%pV\"", inst->cache_da->name, &vp->data); } } @@ -401,7 +401,7 @@ rlm_rcode_t rlm_ldap_cacheable_userobj(rlm_ldap_t const *inst, REQUEST *request, fr_pair_value_strcpy(vp, *dn_p); fr_cursor_append(&list_cursor, vp); - RDEBUG("&control:%s += \"%pV\"", inst->cache_da->name, &vp->data); + RDEBUG2("&control:%s += \"%pV\"", inst->cache_da->name, &vp->data); ldap_memfree(*dn_p); } REXDENT(); @@ -480,7 +480,7 @@ rlm_rcode_t rlm_ldap_cacheable_groupobj(rlm_ldap_t const *inst, REQUEST *request goto finish; } - RDEBUG("Adding cacheable group object memberships"); + RDEBUG2("Adding cacheable group object memberships"); do { if (inst->cacheable_group_dn) { dn = ldap_get_dn((*pconn)->handle, entry); @@ -496,7 +496,7 @@ rlm_rcode_t rlm_ldap_cacheable_groupobj(rlm_ldap_t const *inst, REQUEST *request fr_pair_value_strcpy(vp, dn); RINDENT(); - RDEBUG("&control:%pP", vp); + RDEBUG2("&control:%pP", vp); REXDENT(); ldap_memfree(dn); } @@ -511,7 +511,7 @@ rlm_rcode_t rlm_ldap_cacheable_groupobj(rlm_ldap_t const *inst, REQUEST *request fr_pair_value_bstrncpy(vp, values[0]->bv_val, values[0]->bv_len); RINDENT(); - RDEBUG("&control:%pP", vp); + RDEBUG2("&control:%pP", vp); REXDENT(); ldap_value_free_len(values); @@ -612,7 +612,7 @@ rlm_rcode_t rlm_ldap_check_groupobj_dynamic(rlm_ldap_t const *inst, REQUEST *req REXDENT(); switch (status) { case LDAP_PROC_SUCCESS: - RDEBUG("User found in group object \"%s\"", base_dn); + RDEBUG2("User found in group object \"%s\"", base_dn); break; case LDAP_PROC_NO_RESULT: @@ -657,7 +657,7 @@ rlm_rcode_t rlm_ldap_check_userobj_dynamic(rlm_ldap_t const *inst, REQUEST *requ break; case LDAP_PROC_NO_RESULT: - RDEBUG("Can't check membership attributes, user object not found"); + RDEBUG2("Can't check membership attributes, user object not found"); rcode = RLM_MODULE_NOTFOUND; @@ -678,7 +678,7 @@ rlm_rcode_t rlm_ldap_check_userobj_dynamic(rlm_ldap_t const *inst, REQUEST *requ values = ldap_get_values_len((*pconn)->handle, entry, inst->userobj_membership_attr); if (!values) { - RDEBUG("No group membership attribute(s) found in user object"); + RDEBUG2("No group membership attribute(s) found in user object"); goto finish; } @@ -702,7 +702,7 @@ rlm_rcode_t rlm_ldap_check_userobj_dynamic(rlm_ldap_t const *inst, REQUEST *requ if (!name_is_dn && !value_is_dn) { if ((check->vp_length == values[i]->bv_len) && (memcmp(values[i]->bv_val, check->vp_strvalue, values[i]->bv_len) == 0)) { - RDEBUG("User found in group \"%s\". Comparison between membership: name, check: name", + RDEBUG2("User found in group \"%s\". Comparison between membership: name, check: name", check->vp_strvalue); rcode = RLM_MODULE_OK; @@ -723,7 +723,7 @@ rlm_rcode_t rlm_ldap_check_userobj_dynamic(rlm_ldap_t const *inst, REQUEST *requ if (tolower(values[i]->bv_val[j]) != tolower(check->vp_strvalue[j])) break; } if (j == (int)values[i]->bv_len) { - RDEBUG("User found in group DN \"%s\". " + RDEBUG2("User found in group DN \"%s\". " "Comparison between membership: dn, check: dn", check->vp_strvalue); rcode = RLM_MODULE_OK; @@ -754,7 +754,7 @@ rlm_rcode_t rlm_ldap_check_userobj_dynamic(rlm_ldap_t const *inst, REQUEST *requ (memcmp(values[i]->bv_val, resolved, values[i]->bv_len) == 0)) eq = true; talloc_free(resolved); if (eq) { - RDEBUG("User found in group \"%pV\". Comparison between membership: name, check: name " + RDEBUG2("User found in group \"%pV\". Comparison between membership: name, check: name " "(resolved from DN \"%s\")", fr_box_strvalue_len(values[i]->bv_val, values[i]->bv_len), check->vp_strvalue); rcode = RLM_MODULE_OK; @@ -788,7 +788,7 @@ rlm_rcode_t rlm_ldap_check_userobj_dynamic(rlm_ldap_t const *inst, REQUEST *requ (memcmp(check->vp_strvalue, resolved, check->vp_length) == 0)) eq = true; talloc_free(resolved); if (eq) { - RDEBUG("User found in group \"%s\". Comparison between membership: name " + RDEBUG2("User found in group \"%s\". Comparison between membership: name " "(resolved from DN \"%s\"), check: name", check->vp_strvalue, value); rcode = RLM_MODULE_OK; diff --git a/src/modules/rlm_ldap/rlm_ldap.c b/src/modules/rlm_ldap/rlm_ldap.c index 717dac5c024..17cca26c44e 100644 --- a/src/modules/rlm_ldap/rlm_ldap.c +++ b/src/modules/rlm_ldap/rlm_ldap.c @@ -356,7 +356,7 @@ static ssize_t ldap_xlat(UNUSED TALLOC_CTX *ctx, char **out, size_t outlen, values = ldap_get_values_len(conn->handle, entry, ldap_url->lud_attrs[0]); if (!values) { - RDEBUG("No \"%s\" attributes found in specified object", ldap_url->lud_attrs[0]); + RDEBUG2("No \"%s\" attributes found in specified object", ldap_url->lud_attrs[0]); goto free_result; } @@ -593,7 +593,7 @@ static int rlm_ldap_groupcmp(void *instance, REQUEST *request, UNUSED VALUE_PAIR rad_assert(inst->groupobj_base_dn); - RDEBUG("Searching for user in group \"%pV\"", &check->data); + RDEBUG2("Searching for user in group \"%pV\"", &check->data); if (check->vp_length == 0) { REDEBUG("Cannot do comparison (group name is empty)"); @@ -684,7 +684,7 @@ finish: if (conn) mod_conn_release(inst, request, conn); if (!found) { - RDEBUG("User is not a member of \"%pV\"", &check->data); + RDEBUG2("User is not a member of \"%pV\"", &check->data); return 1; } @@ -772,7 +772,7 @@ static rlm_rcode_t CC_HINT(nonnull) mod_authenticate(void *instance, UNUSED void } } - RDEBUG("Login attempt by \"%pV\"", &request->username->data); + RDEBUG2("Login attempt by \"%pV\"", &request->username->data); /* * Get the DN by doing a search. @@ -793,7 +793,7 @@ static rlm_rcode_t CC_HINT(nonnull) mod_authenticate(void *instance, UNUSED void switch (status) { case LDAP_PROC_SUCCESS: rcode = RLM_MODULE_OK; - RDEBUG("Bind as user \"%s\" was successful", dn); + RDEBUG2("Bind as user \"%s\" was successful", dn); break; case LDAP_PROC_NOT_PERMITTED: @@ -866,7 +866,7 @@ static rlm_rcode_t rlm_ldap_map_profile(rlm_ldap_t const *inst, REQUEST *request case LDAP_PROC_BAD_DN: case LDAP_PROC_NO_RESULT: - RDEBUG("Profile object \"%s\" not found", dn); + RDEBUG2("Profile object \"%s\" not found", dn); return RLM_MODULE_NOTFOUND; default: @@ -886,7 +886,7 @@ static rlm_rcode_t rlm_ldap_map_profile(rlm_ldap_t const *inst, REQUEST *request goto free_result; } - RDEBUG("Processing profile attributes"); + RDEBUG2("Processing profile attributes"); RINDENT(); if (fr_ldap_map_do(request, *pconn, inst->valuepair_attr, expanded, entry) > 0) rcode = RLM_MODULE_UPDATED; REXDENT(); @@ -1033,7 +1033,7 @@ static rlm_rcode_t mod_authorize(void *instance, UNUSED void *thread, REQUEST *r switch (status) { case LDAP_PROC_SUCCESS: rcode = RLM_MODULE_OK; - RDEBUG("Bind as user '%s' was successful", dn); + RDEBUG2("Bind as user '%s' was successful", dn); break; case LDAP_PROC_NOT_PERMITTED: @@ -1119,7 +1119,7 @@ skip_edir: } if (inst->user_map || inst->valuepair_attr) { - RDEBUG("Processing user attributes"); + RDEBUG2("Processing user attributes"); RINDENT(); if (fr_ldap_map_do(request, conn, inst->valuepair_attr, &expanded, entry) > 0) rcode = RLM_MODULE_UPDATED; @@ -1234,7 +1234,7 @@ static rlm_rcode_t user_modify(rlm_ldap_t const *inst, REQUEST *request, ldap_ac op = cf_pair_operator(cp); if (!value || (*value == '\0')) { - RDEBUG("Empty value string, skipping attribute \"%s\"", attr); + RDEBUG2("Empty value string, skipping attribute \"%s\"", attr); continue; } @@ -1260,7 +1260,7 @@ static rlm_rcode_t user_modify(rlm_ldap_t const *inst, REQUEST *request, ldap_ac char *exp = NULL; if (xlat_aeval(request, &exp, request, value, NULL, NULL) <= 0) { - RDEBUG("Skipping attribute \"%s\"", attr); + RDEBUG2("Skipping attribute \"%s\"", attr); talloc_free(exp); diff --git a/src/modules/rlm_ldap/user.c b/src/modules/rlm_ldap/user.c index ce9bb897b91..6b81ffcd429 100644 --- a/src/modules/rlm_ldap/user.c +++ b/src/modules/rlm_ldap/user.c @@ -92,7 +92,7 @@ char const *rlm_ldap_find_user(rlm_ldap_t const *inst, REQUEST *request, fr_ldap if (!force) { vp = fr_pair_find_by_da(request->control, attr_ldap_userdn, TAG_ANY); if (vp) { - RDEBUG("Using user DN from request \"%pV\"", &vp->data); + RDEBUG2("Using user DN from request \"%pV\"", &vp->data); *rcode = RLM_MODULE_OK; return vp->vp_strvalue; } @@ -194,7 +194,7 @@ char const *rlm_ldap_find_user(rlm_ldap_t const *inst, REQUEST *request, fr_ldap } fr_ldap_util_normalise_dn(dn, dn); - RDEBUG("User object found at DN \"%s\"", dn); + RDEBUG2("User object found at DN \"%s\"", dn); MEM(pair_update_control(&vp, attr_ldap_userdn) >= 0); fr_pair_value_strcpy(vp, dn); @@ -231,18 +231,18 @@ rlm_rcode_t rlm_ldap_check_access(rlm_ldap_t const *inst, REQUEST *request, if (values) { if (inst->access_positive) { if ((values[0]->bv_len >= 5) && (strncasecmp(values[0]->bv_val, "false", 5) == 0)) { - RDEBUG("\"%s\" attribute exists but is set to 'false' - user locked out", - inst->userobj_access_attr); + REDEBUG("\"%s\" attribute exists but is set to 'false' - user locked out", + inst->userobj_access_attr); rcode = RLM_MODULE_USERLOCK; } /* RLM_MODULE_OK set above... */ } else if ((values[0]->bv_len < 5) || (strncasecmp(values[0]->bv_val, "false", 5) != 0)) { - RDEBUG("\"%s\" attribute exists - user locked out", inst->userobj_access_attr); + REDEBUG("\"%s\" attribute exists - user locked out", inst->userobj_access_attr); rcode = RLM_MODULE_USERLOCK; } ldap_value_free_len(values); } else if (inst->access_positive) { - RDEBUG("No \"%s\" attribute - user locked out", inst->userobj_access_attr); + REDEBUG("No \"%s\" attribute - user locked out", inst->userobj_access_attr); rcode = RLM_MODULE_USERLOCK; } diff --git a/src/modules/rlm_linelog/rlm_linelog.c b/src/modules/rlm_linelog/rlm_linelog.c index 6ad97705671..a2b8cc8a333 100644 --- a/src/modules/rlm_linelog/rlm_linelog.c +++ b/src/modules/rlm_linelog/rlm_linelog.c @@ -626,7 +626,7 @@ build_vector: } if (vector_len == 0) { - RDEBUG("No data to write"); + RDEBUG2("No data to write"); rcode = RLM_MODULE_NOOP; goto finish; } diff --git a/src/modules/rlm_logintime/rlm_logintime.c b/src/modules/rlm_logintime/rlm_logintime.c index 8198cb6d883..7819c40fd76 100644 --- a/src/modules/rlm_logintime/rlm_logintime.c +++ b/src/modules/rlm_logintime/rlm_logintime.c @@ -161,7 +161,7 @@ static rlm_rcode_t CC_HINT(nonnull) mod_authorize(void *instance, UNUSED void *t /* * Authentication is OK. Now see if this user may login at this time of the day. */ - RDEBUG("Checking Login-Time"); + RDEBUG2("Checking Login-Time"); /* * Compare the time the request was received with the current Login-Time value @@ -193,20 +193,20 @@ static rlm_rcode_t CC_HINT(nonnull) mod_authorize(void *instance, UNUSED void *t * There's time left in the users session, inform the NAS by including a Session-vp * attribute in the reply, or modifying the existing one. */ - RDEBUG("Login within allowed time-slot, %d seconds left in this session", left); + RDEBUG2("Login within allowed time-slot, %d seconds left in this session", left); switch (pair_update_reply(&vp, attr_session_timeout)) { case 1: /* just update... */ if (vp->vp_uint32 > (uint32_t)left) { vp->vp_uint32 = (uint32_t)left; - RDEBUG("&reply:Session-Timeout := %pV", &vp->data); + RDEBUG2("&reply:Session-Timeout := %pV", &vp->data); } break; case 0: /* no pre-existing */ vp->vp_uint32 = (uint32_t)left; - RDEBUG("&reply:Session-Timeout := %pV", &vp->data); + RDEBUG2("&reply:Session-Timeout := %pV", &vp->data); break; case -1: /* malloc failure */ diff --git a/src/modules/rlm_lua/lua.c b/src/modules/rlm_lua/lua.c index 86e14810892..88a4ebeb64d 100644 --- a/src/modules/rlm_lua/lua.c +++ b/src/modules/rlm_lua/lua.c @@ -262,7 +262,7 @@ static int rlm_lua_unmarshall(VALUE_PAIR **out, REQUEST *request, lua_State *L, p = (uint8_t const *) lua_tolstring(L, -1, &len); if (!p) { - RDEBUG("Unmarshalling failed: Lua bstring was NULL"); + REDEBUG("Unmarshalling failed: Lua bstring was NULL"); return -1; } fr_pair_value_memcpy(vp, p, len); @@ -763,7 +763,7 @@ static int rlm_lua_get_field(lua_State *L, REQUEST *request, char const *field) while ((q = strchr(field, '.'))) { if ((size_t) (p - q) >= sizeof(buffer)) { - RDEBUG("Field name too long, maximum is %zu", sizeof(buffer)); + REDEBUG("Field name too long, maximum is %zu", sizeof(buffer)); return -1; } @@ -774,7 +774,7 @@ static int rlm_lua_get_field(lua_State *L, REQUEST *request, char const *field) lua_getfield(L, -1, buffer); } if (lua_isnil(L, -1)) { - RDEBUG("Field '%s' does not exist", p); + REDEBUG("Field '%s' does not exist", p); return -1; } } diff --git a/src/modules/rlm_mschap/rlm_mschap.c b/src/modules/rlm_mschap/rlm_mschap.c index db57e2a72fe..cdaa36d5a3a 100644 --- a/src/modules/rlm_mschap/rlm_mschap.c +++ b/src/modules/rlm_mschap/rlm_mschap.c @@ -570,7 +570,7 @@ static ssize_t mschap_xlat(UNUSED TALLOC_CTX *ctx, char **out, size_t outlen, fr_bin2hex(*out, buffer, NT_DIGEST_LENGTH); (*out)[32] = '\0'; - RDEBUG("NT-Hash of \"known-good\" password: %s", *out); + RDEBUG2("NT-Hash of \"known-good\" password: %s", *out); return 32; /* @@ -588,7 +588,7 @@ static ssize_t mschap_xlat(UNUSED TALLOC_CTX *ctx, char **out, size_t outlen, smbdes_lmpwdhash(p, buffer); fr_bin2hex(*out, buffer, LM_DIGEST_LENGTH); (*out)[32] = '\0'; - RDEBUG("LM-Hash of %s = %s", p, *out); + RDEBUG2("LM-Hash of %s = %s", p, *out); return 32; } else { REDEBUG("Unknown expansion string '%s'", fmt); @@ -755,7 +755,7 @@ static int CC_HINT(nonnull (1, 2, 4, 5)) do_mschap_cpw(rlm_mschap_t const *inst, char *pmsg; char const *emsg; - RDEBUG("Doing MS-CHAPv2 password change via ntlm_auth helper"); + RDEBUG2("Doing MS-CHAPv2 password change via ntlm_auth helper"); /* * Start up ntlm_auth with a pipe on stdin and stdout @@ -919,10 +919,10 @@ ntlm_auth_err: size_t len = 0; if (!nt_password) { - RDEBUG("Local MS-CHAPv2 password change requires NT-Password attribute"); + RDEBUG2("Local MS-CHAPv2 password change requires NT-Password attribute"); return -1; } else { - RDEBUG("Doing MS-CHAPv2 password change locally"); + RDEBUG2("Doing MS-CHAPv2 password change locally"); } /* @@ -1047,7 +1047,7 @@ ntlm_auth_err: return -1; } - RDEBUG("MS-CHAPv2 password change succeeded: %s", result); + RDEBUG2("MS-CHAPv2 password change succeeded: %s", result); /* * Update the NT-Password attribute with the new hash this lets us @@ -1651,7 +1651,7 @@ static rlm_rcode_t CC_HINT(nonnull) process_cpw_request(rlm_mschap_t const *inst * and then jump into mschap2 auth with the challenge/ * response. */ - RDEBUG("MS-CHAPv2 password change request received"); + RDEBUG2("MS-CHAPv2 password change request received"); if (cpw->vp_length != 68) { REDEBUG("MS-CHAP2-CPW has the wrong format: length %zu != 68", cpw->vp_length); @@ -1751,7 +1751,7 @@ static rlm_rcode_t CC_HINT(nonnull) process_cpw_request(rlm_mschap_t const *inst return RLM_MODULE_REJECT; } - RDEBUG("Password change successful"); + RDEBUG2("Password change successful"); return RLM_MODULE_OK; } @@ -1869,7 +1869,7 @@ static rlm_rcode_t CC_HINT(nonnull) mod_authenticate(void *instance, UNUSED void * to have cleared this bit in the config/SQL/wherever. */ if (smb_ctrl && smb_ctrl->vp_uint32 & ACB_FR_EXPIRED) { - RDEBUG("Clearing expiry bit in SMB-Acct-Ctrl to allow authentication"); + RDEBUG2("Clearing expiry bit in SMB-Acct-Ctrl to allow authentication"); smb_ctrl->vp_uint32 &= ~ACB_FR_EXPIRED; } diff --git a/src/modules/rlm_opendirectory/rlm_opendirectory.c b/src/modules/rlm_opendirectory/rlm_opendirectory.c index be55dea77f2..9146b374ec2 100644 --- a/src/modules/rlm_opendirectory/rlm_opendirectory.c +++ b/src/modules/rlm_opendirectory/rlm_opendirectory.c @@ -222,7 +222,7 @@ static long od_check_passwd(REQUEST *request, char const *uname, char const *pas uiCurr = 0; if (!pUserName) { - RDEBUG("Failed to find user name"); + RDEBUG2("Failed to find user name"); break; } @@ -351,7 +351,7 @@ static rlm_rcode_t CC_HINT(nonnull) mod_authenticate(UNUSED void *instance, UNUS } if (ret != RLM_MODULE_OK) { - RDEBUG("Invalid password: %pV", &request->username->data); + RDEBUG2("Invalid password: %pV", &request->username->data); return ret; } @@ -376,7 +376,7 @@ static rlm_rcode_t CC_HINT(nonnull) mod_authorize(void *instance, UNUSED void *t gid_t gid; if (!request->username) { - RDEBUG("OpenDirectory requires a User-Name attribute"); + RDEBUG2("OpenDirectory requires a User-Name attribute"); return RLM_MODULE_NOOP; } @@ -384,7 +384,7 @@ static rlm_rcode_t CC_HINT(nonnull) mod_authorize(void *instance, UNUSED void *t uuid_clear(guid_sacl); if (rad_getgid(request, &gid, kRadiusSACLName) < 0) { - RDEBUG("The SACL group \"%s\" does not exist on this system", kRadiusSACLName); + RDEBUG2("The SACL group \"%s\" does not exist on this system", kRadiusSACLName); } else { err = mbr_gid_to_uuid(gid, guid_sacl); if (err != 0) { @@ -421,16 +421,16 @@ static rlm_rcode_t CC_HINT(nonnull) mod_authorize(void *instance, UNUSED void *t #endif { if (!rad_client) { - RDEBUG("The client record could not be found for host %s", + RDEBUG2("The client record could not be found for host %s", fr_inet_ntoh(&request->packet->src_ipaddr, host_ipaddr, sizeof(host_ipaddr))); } else { - RDEBUG("The host %s does not have an access group", + RDEBUG2("The host %s does not have an access group", fr_inet_ntoh(&request->packet->src_ipaddr, host_ipaddr, sizeof(host_ipaddr))); } } if (uuid_is_null(guid_sacl) && uuid_is_null(guid_nasgroup)) { - RDEBUG("No access control groups, all users allowed"); + RDEBUG2("No access control groups, all users allowed"); if (!module_section_type_set(request, attr_auth_type, inst->auth_type)) return RLM_MODULE_NOOP; diff --git a/src/modules/rlm_pap/rlm_pap.c b/src/modules/rlm_pap/rlm_pap.c index 8fcf3e128de..67d63e84246 100644 --- a/src/modules/rlm_pap/rlm_pap.c +++ b/src/modules/rlm_pap/rlm_pap.c @@ -410,7 +410,7 @@ redo: RDEBUG3("Unknown header {%s} in Password-With-Header = \"%s\", re-writing to " "Cleartext-Password", buffer, vp->vp_strvalue); } else { - RDEBUG("Unknown header {%s} in Password-With-Header, re-writing to " + RDEBUG2("Unknown header {%s} in Password-With-Header, re-writing to " "Cleartext-Password", buffer); } goto unknown_header; @@ -463,7 +463,7 @@ redo: RDEBUG3("No {...} in &Password-With-Header = \"%s\", re-writing to Cleartext-Password", vp->vp_strvalue); } else { - RDEBUG("No {...} in &Password-With-Header, re-writing to Cleartext-Password"); + RDEBUG2("No {...} in &Password-With-Header, re-writing to Cleartext-Password"); } unknown_header: new = fr_pair_afrom_da(request, attr_cleartext_password); @@ -619,7 +619,7 @@ static rlm_rcode_t CC_HINT(nonnull) pap_auth_clear(UNUSED rlm_pap_t const *inst, if (RDEBUG_ENABLED3) { RDEBUG3("Comparing with \"known good\" Cleartext-Password \"%s\" (%zd)", vp->vp_strvalue, vp->vp_length); } else { - RDEBUG("Comparing with \"known good\" Cleartext-Password"); + RDEBUG2("Comparing with \"known good\" Cleartext-Password"); } if ((vp->vp_length != request->password->vp_length) || @@ -638,7 +638,7 @@ static rlm_rcode_t CC_HINT(nonnull) pap_auth_crypt(UNUSED rlm_pap_t const *inst, if (RDEBUG_ENABLED3) { RDEBUG3("Comparing with \"known good\" Crypt-Password \"%s\"", vp->vp_strvalue); } else { - RDEBUG("Comparing with \"known-good\" Crypt-password"); + RDEBUG2("Comparing with \"known-good\" Crypt-password"); } if (fr_crypt_check(request->password->vp_strvalue, vp->vp_strvalue) != 0) { @@ -653,7 +653,7 @@ static rlm_rcode_t CC_HINT(nonnull) pap_auth_md5(rlm_pap_t const *inst, REQUEST { uint8_t digest[128]; - RDEBUG("Comparing with \"known-good\" MD5-Password"); + RDEBUG2("Comparing with \"known-good\" MD5-Password"); if (inst->normify) { normify(request, vp, MD5_DIGEST_LENGTH); @@ -682,7 +682,7 @@ static rlm_rcode_t CC_HINT(nonnull) pap_auth_smd5(rlm_pap_t const *inst, REQUEST fr_md5_ctx_t *md5_ctx; uint8_t digest[128]; - RDEBUG("Comparing with \"known-good\" SMD5-Password"); + RDEBUG2("Comparing with \"known-good\" SMD5-Password"); if (inst->normify) normify(request, vp, MD5_DIGEST_LENGTH); if (vp->vp_length <= MD5_DIGEST_LENGTH) { @@ -715,7 +715,7 @@ static rlm_rcode_t CC_HINT(nonnull) pap_auth_sha(rlm_pap_t const *inst, REQUEST fr_sha1_ctx sha1_context; uint8_t digest[128]; - RDEBUG("Comparing with \"known-good\" SHA-Password"); + RDEBUG2("Comparing with \"known-good\" SHA-Password"); if (inst->normify) normify(request, vp, SHA1_DIGEST_LENGTH); @@ -744,7 +744,7 @@ static rlm_rcode_t CC_HINT(nonnull) pap_auth_ssha(rlm_pap_t const *inst, REQUEST fr_sha1_ctx sha1_context; uint8_t digest[128]; - RDEBUG("Comparing with \"known-good\" SSHA-Password"); + RDEBUG2("Comparing with \"known-good\" SSHA-Password"); if (inst->normify) normify(request, vp, SHA1_DIGEST_LENGTH); @@ -784,7 +784,7 @@ static rlm_rcode_t CC_HINT(nonnull) pap_auth_sha_evp(rlm_pap_t const *inst, REQU if (inst->normify) normify(request, vp, SHA224_DIGEST_LENGTH); if (vp->da == attr_sha2_password) { - RDEBUG("Comparing with \"known-good\" SHA2-Password"); + RDEBUG2("Comparing with \"known-good\" SHA2-Password"); /* * All the SHA-2 algorithms produce digests of different lengths, @@ -823,7 +823,7 @@ static rlm_rcode_t CC_HINT(nonnull) pap_auth_sha_evp(rlm_pap_t const *inst, REQU } # ifdef HAVE_EVP_SHA3_512 else if (vp->da == attr_sha3_password) { - RDEBUG("Comparing with \"known-good\" SHA3-Password"); + RDEBUG2("Comparing with \"known-good\" SHA3-Password"); /* * All the SHA-3 algorithms produce digests of different lengths, * so it's trivial to determine which EVP_MD to use. @@ -933,7 +933,7 @@ static rlm_rcode_t CC_HINT(nonnull) pap_auth_ssha_evp(rlm_pap_t const *inst, REQ return RLM_MODULE_INVALID; } - RDEBUG("Comparing with \"known-good\" %s-Password", name); + RDEBUG2("Comparing with \"known-good\" %s-Password", name); /* * Unlike plain SHA2/3 we already know what length @@ -1002,7 +1002,7 @@ static inline rlm_rcode_t CC_HINT(nonnull) pap_auth_pbkdf2_parse(REQUEST *reques uint8_t hash[EVP_MAX_MD_SIZE]; uint8_t digest[EVP_MAX_MD_SIZE]; - RDEBUG("Comparing with \"known-good\" PBKDF2-Password"); + RDEBUG2("Comparing with \"known-good\" PBKDF2-Password"); if (len <= 1) { REDEBUG("PBKDF2-Password is too short"); @@ -1259,7 +1259,7 @@ static rlm_rcode_t CC_HINT(nonnull) pap_auth_nt(rlm_pap_t const *inst, REQUEST * uint8_t digest[MD4_DIGEST_LENGTH]; uint8_t ucs2_password[512]; - RDEBUG("Comparing with \"known-good\" NT-Password"); + RDEBUG2("Comparing with \"known-good\" NT-Password"); rad_assert(request->password != NULL); rad_assert(request->password->da == attr_user_password); @@ -1296,7 +1296,7 @@ static rlm_rcode_t CC_HINT(nonnull) pap_auth_lm(rlm_pap_t const *inst, REQUEST * char charbuf[32 + 1]; ssize_t len; - RDEBUG("Comparing with \"known-good\" LM-Password"); + RDEBUG2("Comparing with \"known-good\" LM-Password"); if (inst->normify) normify(request, vp, MD4_DIGEST_LENGTH); @@ -1325,7 +1325,7 @@ static rlm_rcode_t CC_HINT(nonnull) pap_auth_ns_mta_md5(UNUSED rlm_pap_t const * uint8_t buff[FR_MAX_STRING_LEN]; uint8_t buff2[FR_MAX_STRING_LEN + 50]; - RDEBUG("Using NT-MTA-MD5-Password"); + RDEBUG2("Using NT-MTA-MD5-Password"); if (vp->vp_length != 64) { REDEBUG("\"known good\" NS-MTA-MD5-Password has incorrect length, expected 64 got %zu", vp->vp_length); @@ -1406,7 +1406,7 @@ static rlm_rcode_t CC_HINT(nonnull) mod_authenticate(void *instance, UNUSED void RDEBUG3("Login attempt with password \"%s\" (%zd)", request->password->vp_strvalue, request->password->vp_length); } else { - RDEBUG("Login attempt with password"); + RDEBUG2("Login attempt with password"); } /* @@ -1483,7 +1483,7 @@ static rlm_rcode_t CC_HINT(nonnull) mod_authenticate(void *instance, UNUSED void if (rc == RLM_MODULE_REJECT) REDEBUG("Passwords don't match"); - if (rc == RLM_MODULE_OK) RDEBUG("User authenticated successfully"); + if (rc == RLM_MODULE_OK) RDEBUG2("User authenticated successfully"); return rc; } diff --git a/src/modules/rlm_passwd/rlm_passwd.c b/src/modules/rlm_passwd/rlm_passwd.c index c8e76814a5b..d8309d99bde 100644 --- a/src/modules/rlm_passwd/rlm_passwd.c +++ b/src/modules/rlm_passwd/rlm_passwd.c @@ -524,10 +524,10 @@ static void result_add(TALLOC_CTX *ctx, rlm_passwd_t const *inst, REQUEST *reque vp = fr_pair_make(ctx, request->dict, vps, inst->pwd_fmt->field[i], pw->field[i], T_OP_EQ); if (vp) { - RDEBUG("Added %s: '%s' to %s ", inst->pwd_fmt->field[i], pw->field[i], listname); + RDEBUG2("Added %s: '%s' to %s ", inst->pwd_fmt->field[i], pw->field[i], listname); } } else - RDEBUG("NOOP %s: '%s' to %s ", inst->pwd_fmt->field[i], pw->field[i], listname); + RDEBUG2("NOOP %s: '%s' to %s ", inst->pwd_fmt->field[i], pw->field[i], listname); } } } diff --git a/src/modules/rlm_perl/rlm_perl.c b/src/modules/rlm_perl/rlm_perl.c index 7177c5a1816..f5ab85779ba 100644 --- a/src/modules/rlm_perl/rlm_perl.c +++ b/src/modules/rlm_perl/rlm_perl.c @@ -436,7 +436,7 @@ static ssize_t perl_xlat(UNUSED TALLOC_CTX *ctx, char **out, size_t outlen, strlcpy(*out, tmp, outlen); ret = strlen(*out); - RDEBUG("Len is %zu , out is %s freespace is %zu", ret, *out, outlen); + RDEBUG2("Len is %zu , out is %s freespace is %zu", ret, *out, outlen); } PUTBACK ; @@ -645,14 +645,14 @@ static void perl_vp_to_svpvn_element(REQUEST *request, AV *av, VALUE_PAIR const switch (vp->vp_type) { case FR_TYPE_STRING: - RDEBUG("$%s{'%s'}[%i] = &%s:%s -> '%s'", hash_name, vp->da->name, *i, - list_name, vp->da->name, vp->vp_strvalue); + RDEBUG2("$%s{'%s'}[%i] = &%s:%s -> '%s'", hash_name, vp->da->name, *i, + list_name, vp->da->name, vp->vp_strvalue); sv = newSVpvn(vp->vp_strvalue, vp->vp_length); break; case FR_TYPE_OCTETS: - RDEBUG("$%s{'%s'}[%i] = &%s:%s -> 0x%pH", hash_name, vp->da->name, *i, - list_name, vp->da->name, &vp->data); + RDEBUG2("$%s{'%s'}[%i] = &%s:%s -> 0x%pH", hash_name, vp->da->name, *i, + list_name, vp->da->name, &vp->data); sv = newSVpvn((char const *)vp->vp_octets, vp->vp_length); break; @@ -662,8 +662,8 @@ static void perl_vp_to_svpvn_element(REQUEST *request, AV *av, VALUE_PAIR const size_t len; len = fr_pair_value_snprint(buffer, sizeof(buffer), vp, '\0'); - RDEBUG("$%s{'%s'}[%i] = &%s:%s -> '%s'", hash_name, vp->da->name, *i, - list_name, vp->da->name, buffer); + RDEBUG2("$%s{'%s'}[%i] = &%s:%s -> '%s'", hash_name, vp->da->name, *i, + list_name, vp->da->name, buffer); sv = newSVpvn(buffer, truncate_len(len, sizeof(buffer))); } break; @@ -736,13 +736,13 @@ static void perl_store_vps(UNUSED TALLOC_CTX *ctx, REQUEST *request, VALUE_PAIR */ switch (vp->vp_type) { case FR_TYPE_STRING: - RDEBUG("$%s{'%s'} = &%s:%s -> '%pV'", hash_name, vp->da->name, list_name, + RDEBUG2("$%s{'%s'} = &%s:%s -> '%pV'", hash_name, vp->da->name, list_name, vp->da->name, &vp->data); (void)hv_store(rad_hv, name, strlen(name), newSVpvn(vp->vp_strvalue, vp->vp_length), 0); break; case FR_TYPE_OCTETS: - RDEBUG("$%s{'%s'} = &%s:%s -> %pV", hash_name, vp->da->name, list_name, + RDEBUG2("$%s{'%s'} = &%s:%s -> %pV", hash_name, vp->da->name, list_name, vp->da->name, &vp->data); (void)hv_store(rad_hv, name, strlen(name), newSVpvn((char const *)vp->vp_octets, vp->vp_length), 0); @@ -754,7 +754,7 @@ static void perl_store_vps(UNUSED TALLOC_CTX *ctx, REQUEST *request, VALUE_PAIR size_t len; len = fr_pair_value_snprint(buffer, sizeof(buffer), vp, '\0'); - RDEBUG("$%s{'%s'} = &%s:%s -> '%s'", hash_name, vp->da->name, + RDEBUG2("$%s{'%s'} = &%s:%s -> '%s'", hash_name, vp->da->name, list_name, vp->da->name, buffer); (void)hv_store(rad_hv, name, strlen(name), newSVpvn(buffer, truncate_len(len, sizeof(buffer))), 0); @@ -804,8 +804,8 @@ static int pairadd_sv(TALLOC_CTX *ctx, REQUEST *request, VALUE_PAIR **vps, char VP_VERIFY(vp); - RDEBUG("&%s:%s %s $%s{'%s'} -> '%s'", list_name, key, fr_int2str(fr_tokens_table, op, ""), - hash_name, key, val); + RDEBUG2("&%s:%s %s $%s{'%s'} -> '%s'", list_name, key, fr_int2str(fr_tokens_table, op, ""), + hash_name, key, val); return 0; } @@ -937,8 +937,8 @@ static int do_perl(void *instance, REQUEST *request, char const *function_name) SPAGAIN; if (SvTRUE(ERRSV)) { - RDEBUG("perl_embed:: module = %s , func = %s exit status= %s\n", - inst->module, function_name, SvPV(ERRSV,n_a)); + REDEBUG("perl_embed:: module = %s , func = %s exit status= %s\n", + inst->module, function_name, SvPV(ERRSV,n_a)); (void)POPs; exitstatus = RLM_MODULE_FAIL; } else if (count == 1) { @@ -1043,7 +1043,7 @@ static rlm_rcode_t CC_HINT(nonnull) mod_accounting(void *instance, UNUSED void * if (pair != NULL) { acct_status_type = pair->vp_uint32; } else { - RDEBUG("Invalid Accounting Packet"); + REDEBUG("Invalid Accounting Packet"); return RLM_MODULE_INVALID; } diff --git a/src/modules/rlm_radius/rlm_radius.c b/src/modules/rlm_radius/rlm_radius.c index 0f265ccbdea..3290e6e3ec0 100644 --- a/src/modules/rlm_radius/rlm_radius.c +++ b/src/modules/rlm_radius/rlm_radius.c @@ -466,7 +466,7 @@ static rlm_rcode_t CC_HINT(nonnull) mod_process(void *instance, void *thread, RE void *request_io_ctx; if (!request->packet->code) { - RDEBUG("You MUST specify a packet code"); + REDEBUG("You MUST specify a packet code"); return RLM_MODULE_FAIL; } diff --git a/src/modules/rlm_radius/rlm_radius_udp.c b/src/modules/rlm_radius/rlm_radius_udp.c index 64041bd4639..8bc53a208fc 100644 --- a/src/modules/rlm_radius/rlm_radius_udp.c +++ b/src/modules/rlm_radius/rlm_radius_udp.c @@ -882,7 +882,7 @@ static void status_check_timeout(fr_event_list_t *el, struct timeval *now, void * Insert the next retransmission timer. */ if (fr_event_timer_insert(u, el, &u->timer.ev, &u->timer.next, status_check_timeout, u) < 0) { - RDEBUG("Failed inserting retransmission timer for status check - closing connection %s", c->name); + REDEBUG("Failed inserting retransmission timer for status check - closing connection %s", c->name); talloc_free(c); return; } diff --git a/src/modules/rlm_rediswho/rlm_rediswho.c b/src/modules/rlm_rediswho/rlm_rediswho.c index a0cac60e327..a64a8a41595 100644 --- a/src/modules/rlm_rediswho/rlm_rediswho.c +++ b/src/modules/rlm_rediswho/rlm_rediswho.c @@ -207,19 +207,19 @@ static rlm_rcode_t CC_HINT(nonnull) mod_accounting(void *instance, UNUSED void * vp = fr_pair_find_by_da(request->packet->vps, attr_acct_status_type, TAG_ANY); if (!vp) { - RDEBUG("Could not find account status type in packet"); + RDEBUG2("Could not find account status type in packet"); return RLM_MODULE_NOOP; } dv = fr_dict_enum_by_value(vp->da, &vp->data); if (!dv) { - RDEBUG("Unknown Acct-Status-Type %u", vp->vp_uint32); + RDEBUG2("Unknown Acct-Status-Type %u", vp->vp_uint32); return RLM_MODULE_NOOP; } cs = cf_section_find(inst->cs, dv->alias, NULL); if (!cs) { - RDEBUG("No subsection %s", dv->alias); + RDEBUG2("No subsection %s", dv->alias); return RLM_MODULE_NOOP; } diff --git a/src/modules/rlm_rest/io.c b/src/modules/rlm_rest/io.c index c653a6dd0a0..4586fd9ac3e 100644 --- a/src/modules/rlm_rest/io.c +++ b/src/modules/rlm_rest/io.c @@ -351,7 +351,7 @@ void rest_io_module_action(REQUEST *request, void *instance, void *thread, void if (action != FR_SIGNAL_CANCEL) return; - RDEBUG("Forcefully cancelling pending REST request"); + RDEBUG2("Forcefully cancelling pending REST request"); ret = curl_multi_remove_handle(t->mandle, randle->candle); /* Gracefully terminate the request */ if (ret != CURLM_OK) { diff --git a/src/modules/rlm_rest/rest.c b/src/modules/rlm_rest/rest.c index 5cc270316b7..eb62811fd36 100644 --- a/src/modules/rlm_rest/rest.c +++ b/src/modules/rlm_rest/rest.c @@ -1328,7 +1328,7 @@ static size_t rest_response_header(void *in, size_t size, size_t nmemb, void *us */ q = memchr(p, ' ', s); if (!q) { - RDEBUG("Malformed HTTP header: Missing reason code"); + REDEBUG("Malformed HTTP header: Missing reason code"); goto malformed; } diff --git a/src/modules/rlm_rest/rlm_rest.c b/src/modules/rlm_rest/rlm_rest.c index 9318602f6a4..2c64e444cd7 100644 --- a/src/modules/rlm_rest/rlm_rest.c +++ b/src/modules/rlm_rest/rlm_rest.c @@ -181,7 +181,7 @@ static int rlm_rest_perform(rlm_rest_t const *instance, rlm_rest_thread_t *threa char *uri = NULL; int ret; - RDEBUG("Expanding URI components"); + RDEBUG2("Expanding URI components"); /* * Build xlat'd URI, this allows REST servers to be specified by @@ -190,7 +190,7 @@ static int rlm_rest_perform(rlm_rest_t const *instance, rlm_rest_thread_t *threa uri_len = rest_uri_build(&uri, instance, request, section->uri); if (uri_len <= 0) return -1; - RDEBUG("Sending HTTP %s to \"%s\"", fr_int2str(http_method_table, section->method, NULL), uri); + RDEBUG2("Sending HTTP %s to \"%s\"", fr_int2str(http_method_table, section->method, NULL), uri); /* * Configure various CURL options, and initialise the read/write @@ -325,7 +325,7 @@ static xlat_action_t rest_xlat(TALLOC_CTX *ctx, UNUSED fr_cursor_t *out, */ memcpy(&rctx->section, &mod_inst->xlat, sizeof(*section)); - RDEBUG("Expanding URI components"); + RDEBUG2("Expanding URI components"); /* * Extract the method from the start of the format string (if there is one) @@ -384,7 +384,7 @@ static xlat_action_t rest_xlat(TALLOC_CTX *ctx, UNUSED fr_cursor_t *out, section->data = q; } - RDEBUG("Sending HTTP %s to \"%s\"", + RDEBUG2("Sending HTTP %s to \"%s\"", (section->method == HTTP_METHOD_CUSTOM) ? section->method_str : fr_int2str(http_method_table, section->method, NULL), uri); diff --git a/src/modules/rlm_securid/rlm_securid.c b/src/modules/rlm_securid/rlm_securid.c index a1fa53af7dc..80a55b68aea 100644 --- a/src/modules/rlm_securid/rlm_securid.c +++ b/src/modules/rlm_securid/rlm_securid.c @@ -127,13 +127,13 @@ static SECURID_AUTH_RC securidAuth(void *instance, REQUEST *request, acm_ret = SD_Init(&sdiHandle); if (acm_ret != ACM_OK) { - ERROR("Cannot communicate with the ACE/Server"); + RERROR("Cannot communicate with the ACE/Server"); return -1; } acm_ret = SD_Lock(sdiHandle, securid_user); if (acm_ret != ACM_OK) { - ERROR("SecurID: Access denied. Name [%s] lock failed", username); + REDEBUG("SecurID: Access denied. Name [%s] lock failed", username); return -2; } @@ -141,19 +141,19 @@ static SECURID_AUTH_RC securidAuth(void *instance, REQUEST *request, switch (acm_ret) { case ACM_OK: /* we are in now */ - RDEBUG("SecurID authentication successful for %s", username); + RDEBUG2("SecurID authentication successful for %s", username); SD_Close(sdiHandle); return RC_SECURID_AUTH_SUCCESS; case ACM_ACCESS_DENIED: /* not this time */ - RDEBUG("SecurID Access denied for %s", username); + RDEBUG2("SecurID Access denied for %s", username); SD_Close(sdiHandle); return RC_SECURID_AUTH_ACCESS_DENIED_FAILURE; case ACM_INVALID_SERVER: - ERROR("SecurID: Invalid ACE server"); + RERROR("SecurID: Invalid ACE server"); return RC_SECURID_AUTH_INVALID_SERVER_FAILURE; case ACM_NEW_PIN_REQUIRED: @@ -221,7 +221,7 @@ static SECURID_AUTH_RC securidAuth(void *instance, REQUEST *request, } } else { /* existing session found */ - RDEBUG("Continuing previous session found for user [%s]", username); + RDEBUG2("Continuing previous session found for user [%s]", username); /* continue previous session */ switch (securid_session->securidSessionState) { @@ -290,7 +290,7 @@ static SECURID_AUTH_RC securidAuth(void *instance, REQUEST *request, RDEBUG2("Pin confirmation succeeded. Pins match"); acm_ret = SD_Pin(securid_session->sdiHandle, securid_pass); if (acm_ret == ACM_NEW_PIN_ACCEPTED) { - RDEBUG("New SecurID pin accepted for %s.", securid_session->identity); + RDEBUG2("New SecurID pin accepted for %s.", securid_session->identity); securid_session->securidSessionState = NEW_PIN_AUTH_VALIDATE_STATE; @@ -300,7 +300,7 @@ static SECURID_AUTH_RC securidAuth(void *instance, REQUEST *request, rc = RC_SECURID_AUTH_CHALLENGE; strlcpy(replyMsgBuffer, " \r\n\r\nWait for the code on your card to change, then enter new PIN and TokenCode\r\n\r\nEnter PASSCODE:", replyMsgBufferSize); } else { - RDEBUG("SecurID: New SecurID pin rejected for %s.", securid_session->identity); + RDEBUG2("SecurID: New SecurID pin rejected for %s.", securid_session->identity); SD_Pin(securid_session->sdiHandle, &empty_pin[0]); /* cancel PIN */ @@ -314,7 +314,7 @@ static SECURID_AUTH_RC securidAuth(void *instance, REQUEST *request, case NEW_PIN_AUTH_VALIDATE_STATE: acm_ret = SD_Check(securid_session->sdiHandle, securid_pass, securid_user); if (acm_ret == ACM_OK) { - RDEBUG("New SecurID passcode accepted for %s", securid_session->identity); + RDEBUG2("New SecurID passcode accepted for %s", securid_session->identity); rc = RC_SECURID_AUTH_SUCCESS; } else { @@ -511,7 +511,7 @@ static rlm_rcode_t CC_HINT(nonnull) mod_authenticate(void *instance, UNUSED void if (RDEBUG_ENABLED3) { RDEBUG3("Login attempt with password \"%s\"", password); } else { - RDEBUG("Login attempt with password"); + RDEBUG2("Login attempt with password"); } rcode = securidAuth(inst, request, username, password, @@ -531,7 +531,7 @@ static rlm_rcode_t CC_HINT(nonnull) mod_authenticate(void *instance, UNUSED void /* Mark the packet as a Acceess-Challenge Packet */ request->reply->code = FR_CODE_ACCESS_CHALLENGE; - RDEBUG("Sending Access-Challenge"); + RDEBUG2("Sending Access-Challenge"); rcode = RLM_MODULE_HANDLED; break; diff --git a/src/modules/rlm_soh/rlm_soh.c b/src/modules/rlm_soh/rlm_soh.c index e7f1e5e58be..7736ba8ed68 100644 --- a/src/modules/rlm_soh/rlm_soh.c +++ b/src/modules/rlm_soh/rlm_soh.c @@ -170,7 +170,7 @@ static rlm_rcode_t CC_HINT(nonnull) mod_post_auth(void *instance, UNUSED void *t if (vlen <= 1) { uint8_t *p; - RDEBUG("SoH adding NAP marker to DHCP reply"); + RDEBUG2("SoH adding NAP marker to DHCP reply"); /* client probe; send "NAP" in the reply */ vp = fr_pair_afrom_da(request->reply, attr_dhcp_vendor); p = talloc_array(vp, uint8_t, 5); @@ -183,7 +183,7 @@ static rlm_rcode_t CC_HINT(nonnull) mod_post_auth(void *instance, UNUSED void *t fr_pair_add(&request->reply->vps, vp); } else { - RDEBUG("SoH decoding NAP from DHCP request"); + RDEBUG2("SoH decoding NAP from DHCP request"); /* SoH payload */ rcode = soh_verify(request, data, vlen); if (rcode < 0) { @@ -212,11 +212,11 @@ static rlm_rcode_t CC_HINT(nonnull) mod_authorize(UNUSED void *instance, UNUSED /* try to find the MS-SoH payload */ vp = fr_pair_find_by_da(request->packet->vps, attr_ms_quarantine_soh, TAG_ANY); if (!vp) { - RDEBUG("SoH radius VP not found"); + RDEBUG2("SoH radius VP not found"); return RLM_MODULE_NOOP; } - RDEBUG("SoH radius VP found"); + RDEBUG2("SoH radius VP found"); /* decode it */ rv = soh_verify(request, vp->vp_octets, vp->vp_length); if (rv < 0) { diff --git a/src/modules/rlm_sql/rlm_sql.c b/src/modules/rlm_sql/rlm_sql.c index d5fe05a9c85..b8899041f8c 100644 --- a/src/modules/rlm_sql/rlm_sql.c +++ b/src/modules/rlm_sql/rlm_sql.c @@ -205,7 +205,7 @@ static ssize_t sql_xlat(UNUSED TALLOC_CTX *ctx, char **out, UNUSED size_t outlen numaffected = (inst->driver->sql_affected_rows)(handle, inst->config); if (numaffected < 1) { - RDEBUG("SQL query affected no rows"); + RDEBUG2("SQL query affected no rows"); (inst->driver->sql_finish_query)(handle, inst->config); goto finish; @@ -227,14 +227,14 @@ static ssize_t sql_xlat(UNUSED TALLOC_CTX *ctx, char **out, UNUSED size_t outlen case RLM_SQL_OK: if (row[0]) break; - RDEBUG("NULL value in first column of result"); + RDEBUG2("NULL value in first column of result"); (inst->driver->sql_finish_select_query)(handle, inst->config); ret = -1; goto finish; case RLM_SQL_NO_MORE_ROWS: - RDEBUG("SQL query returned no results"); + RDEBUG2("SQL query returned no results"); (inst->driver->sql_finish_select_query)(handle, inst->config); ret = -1; @@ -448,7 +448,7 @@ static rlm_rcode_t mod_map_proc(void *mod_inst, UNUSED void *proc_inst, REQUEST * in the result set. */ if (!found_field) { - RDEBUG("No fields matching map found in query result"); + RDEBUG2("No fields matching map found in query result"); rcode = RLM_MODULE_NOOP; (inst->driver->sql_finish_select_query)(handle, inst->config); goto finish; @@ -474,7 +474,7 @@ static rlm_rcode_t mod_map_proc(void *mod_inst, UNUSED void *proc_inst, REQUEST if (ret == RLM_SQL_ERROR) goto error; if (rows == 0) { - RDEBUG("SQL query returned no results"); + RDEBUG2("SQL query returned no results"); rcode = RLM_MODULE_NOOP; } @@ -687,7 +687,7 @@ static int sql_get_grouplist(rlm_sql_t const *inst, rlm_sql_handle_t **handle, R while (rlm_sql_fetch_row(&row, inst, request, handle) == RLM_SQL_OK) { if (!row[0]){ - RDEBUG("row[0] returned NULL"); + RDEBUG2("row[0] returned NULL"); (inst->driver->sql_finish_select_query)(*handle, inst->config); talloc_free(entry); return -1; @@ -738,10 +738,10 @@ static int sql_groupcmp(void *instance, REQUEST *request, UNUSED VALUE_PAIR *req return 1; } - RDEBUG("sql_groupcmp"); + RDEBUG2("sql_groupcmp"); if (check->vp_length == 0){ - RDEBUG("sql_groupcmp: Illegal group name"); + RDEBUG2("sql_groupcmp: Illegal group name"); return 1; } @@ -770,7 +770,7 @@ static int sql_groupcmp(void *instance, REQUEST *request, UNUSED VALUE_PAIR *req for (entry = head; entry != NULL; entry = entry->next) { if (strcmp(entry->name, check->vp_strvalue) == 0){ - RDEBUG("sql_groupcmp finished: User is a member of group %s", + RDEBUG2("sql_groupcmp finished: User is a member of group %s", check->vp_strvalue); talloc_free(head); fr_pool_connection_release(inst->pool, request, handle); @@ -782,7 +782,7 @@ static int sql_groupcmp(void *instance, REQUEST *request, UNUSED VALUE_PAIR *req talloc_free(head); fr_pool_connection_release(inst->pool, request, handle); - RDEBUG("sql_groupcmp finished: User is NOT a member of group %pV", &check->data); + RDEBUG2("sql_groupcmp finished: User is NOT a member of group %pV", &check->data); return 1; } @@ -1488,7 +1488,7 @@ static int acct_redundant(rlm_sql_t const *inst, REQUEST *request, sql_acct_sect while (true) { value = cf_pair_value(pair); if (!value) { - RDEBUG("Ignoring null query"); + RDEBUG2("Ignoring null query"); rcode = RLM_MODULE_NOOP; goto finish; @@ -1501,7 +1501,7 @@ static int acct_redundant(rlm_sql_t const *inst, REQUEST *request, sql_acct_sect } if (!*expanded) { - RDEBUG("Ignoring null query"); + RDEBUG2("Ignoring null query"); rcode = RLM_MODULE_NOOP; goto finish; @@ -1511,7 +1511,7 @@ static int acct_redundant(rlm_sql_t const *inst, REQUEST *request, sql_acct_sect sql_ret = rlm_sql_query(inst, request, &handle, expanded); TALLOC_FREE(expanded); - RDEBUG("SQL query returned: %s", fr_int2str(sql_rcode_table, sql_ret, "")); + RDEBUG2("SQL query returned: %s", fr_int2str(sql_rcode_table, sql_ret, "")); switch (sql_ret) { /* @@ -1556,7 +1556,7 @@ static int acct_redundant(rlm_sql_t const *inst, REQUEST *request, sql_acct_sect */ numaffected = (inst->driver->sql_affected_rows)(handle, inst->config); (inst->driver->sql_finish_query)(handle, inst->config); - RDEBUG("%i record(s) updated", numaffected); + RDEBUG2("%i record(s) updated", numaffected); if (numaffected > 0) break; /* A query succeeded, were done! */ next: @@ -1567,13 +1567,13 @@ static int acct_redundant(rlm_sql_t const *inst, REQUEST *request, sql_acct_sect pair = cf_pair_find_next(section->cs, pair, attr); if (!pair) { - RDEBUG("No additional queries configured"); + RDEBUG2("No additional queries configured"); rcode = RLM_MODULE_NOOP; goto finish; } - RDEBUG("Trying next query..."); + RDEBUG2("Trying next query..."); } diff --git a/src/modules/rlm_sqlippool/rlm_sqlippool.c b/src/modules/rlm_sqlippool/rlm_sqlippool.c index e368a2a5c21..3f321f77884 100644 --- a/src/modules/rlm_sqlippool/rlm_sqlippool.c +++ b/src/modules/rlm_sqlippool/rlm_sqlippool.c @@ -379,7 +379,7 @@ static int CC_HINT(nonnull (1, 3, 4, 5)) sqlippool_query1(char *out, int outlen, rlen = strlen(row[0]); if (rlen >= outlen) { - RDEBUG("insufficient string space"); + RDEBUG2("insufficient string space"); goto finish; } @@ -486,13 +486,13 @@ static rlm_rcode_t CC_HINT(nonnull) mod_post_auth(void *instance, UNUSED void *t * If there is a Framed-IP-Address attribute in the reply do nothing */ if (fr_pair_find_by_da(request->reply->vps, inst->framed_ip_address, TAG_ANY) != NULL) { - RDEBUG("Framed-IP-Address already exists"); + RDEBUG2("Framed-IP-Address already exists"); return do_logging(inst, request, inst->log_exists, RLM_MODULE_NOOP); } if (fr_pair_find_by_da(request->control, attr_pool_name, TAG_ANY) == NULL) { - RDEBUG("No Pool-Name defined"); + RDEBUG2("No Pool-Name defined"); return do_logging(inst, request, inst->log_nopool, RLM_MODULE_NOOP); } @@ -560,7 +560,7 @@ static rlm_rcode_t CC_HINT(nonnull) mod_post_auth(void *instance, UNUSED void *t * that case, we should return * NOTFOUND */ - RDEBUG("pool appears to be full"); + RDEBUG2("pool appears to be full"); return do_logging(inst, request, inst->log_failed, RLM_MODULE_NOTFOUND); } @@ -571,14 +571,14 @@ static rlm_rcode_t CC_HINT(nonnull) mod_post_auth(void *instance, UNUSED void *t * sqlippool, so we should just ignore this * allocation failure and return NOOP */ - RDEBUG("IP address could not be allocated as no pool exists with that name"); + RDEBUG2("IP address could not be allocated as no pool exists with that name"); return RLM_MODULE_NOOP; } fr_pool_connection_release(inst->sql_inst->pool, request, handle); - RDEBUG("IP address could not be allocated"); + RDEBUG2("IP address could not be allocated"); return do_logging(inst, request, inst->log_failed, RLM_MODULE_NOOP); } @@ -590,12 +590,12 @@ static rlm_rcode_t CC_HINT(nonnull) mod_post_auth(void *instance, UNUSED void *t if (fr_pair_value_from_str(vp, allocation, allocation_len, '\0', true) < 0) { DO_PART(allocate_commit); - RDEBUG("Invalid IP number [%s] returned from instbase query.", allocation); + RDEBUG2("Invalid IP number [%s] returned from instbase query.", allocation); fr_pool_connection_release(inst->sql_inst->pool, request, handle); return do_logging(inst, request, inst->log_failed, RLM_MODULE_NOOP); } - RDEBUG("Allocated IP %s", allocation); + RDEBUG2("Allocated IP %s", allocation); fr_pair_add(&request->reply->vps, vp); /* @@ -677,7 +677,7 @@ static rlm_rcode_t CC_HINT(nonnull) mod_accounting(void *instance, UNUSED void * vp = fr_pair_find_by_da(request->packet->vps, attr_acct_status_type, TAG_ANY); if (!vp) { - RDEBUG("Could not find account status type in packet"); + RDEBUG2("Could not find account status type in packet"); return RLM_MODULE_NOOP; } acct_status_type = vp->vp_uint32; @@ -697,7 +697,7 @@ static rlm_rcode_t CC_HINT(nonnull) mod_accounting(void *instance, UNUSED void * handle = fr_pool_connection_get(inst->sql_inst->pool, request); if (!handle) { - RDEBUG("Failed reserving SQL connection"); + RDEBUG2("Failed reserving SQL connection"); return RLM_MODULE_FAIL; } diff --git a/src/modules/rlm_unbound/rlm_unbound.c b/src/modules/rlm_unbound/rlm_unbound.c index 7b5c61c0b9b..0a59c221b3d 100644 --- a/src/modules/rlm_unbound/rlm_unbound.c +++ b/src/modules/rlm_unbound/rlm_unbound.c @@ -180,7 +180,7 @@ static int ub_common_wait(rlm_unbound_t const *inst, REQUEST *request, if ((void const *)*ub == (void const *)inst) { int res; - RDEBUG("%s - DNS took too long", name); + REDEBUG2("%s - DNS took too long", name); res = ub_cancel(inst->ub, async_id); if (res) { @@ -200,12 +200,12 @@ static int ub_common_fail(REQUEST *request, char const *name, struct ub_result * } if (ub->nxdomain) { - RDEBUG("%s - NXDOMAIN", name); + RDEBUG2("%s - NXDOMAIN", name); return -1; } if (!ub->havedata) { - RDEBUG("%s - Empty result", name); + RDEBUG2("%s - Empty result", name); return -1; } diff --git a/src/modules/rlm_unix/rlm_unix.c b/src/modules/rlm_unix/rlm_unix.c index 33b9b851e71..5d476916788 100644 --- a/src/modules/rlm_unix/rlm_unix.c +++ b/src/modules/rlm_unix/rlm_unix.c @@ -372,7 +372,7 @@ static rlm_rcode_t CC_HINT(nonnull) mod_accounting(void *instance, UNUSED void * * Which type is this. */ if ((vp = fr_pair_find_by_da(request->packet->vps, attr_acct_status_type, TAG_ANY)) == NULL) { - RDEBUG("no Accounting-Status-Type attribute in request"); + RDEBUG2("no Accounting-Status-Type attribute in request"); return RLM_MODULE_NOOP; } status = vp->vp_uint32; diff --git a/src/modules/rlm_unpack/rlm_unpack.c b/src/modules/rlm_unpack/rlm_unpack.c index c1f0e38129b..11576c460e1 100644 --- a/src/modules/rlm_unpack/rlm_unpack.c +++ b/src/modules/rlm_unpack/rlm_unpack.c @@ -122,7 +122,7 @@ static ssize_t unpack_xlat(UNUSED TALLOC_CTX *ctx, char **out, size_t outlen, */ len = strlen(data_name + 2); if ((len & 0x01) != 0) { - RDEBUG("Invalid hex string in '%s'", data_name); + REDEBUG("Invalid hex string in '%s'", data_name); goto nothing; } input = blob; diff --git a/src/modules/rlm_wimax/rlm_wimax.c b/src/modules/rlm_wimax/rlm_wimax.c index d821c8f8f99..77428938de2 100644 --- a/src/modules/rlm_wimax/rlm_wimax.c +++ b/src/modules/rlm_wimax/rlm_wimax.c @@ -177,7 +177,7 @@ static rlm_rcode_t CC_HINT(nonnull) mod_post_auth(void *instance, UNUSED void *t msk = fr_pair_find_by_da(request->reply->vps, attr_eap_msk, TAG_ANY); emsk = fr_pair_find_by_da(request->reply->vps, attr_eap_emsk, TAG_ANY); if (!msk || !emsk) { - RDEBUG("No EAP-MSK or EAP-EMSK. Cannot create WiMAX keys"); + REDEBUG2("No EAP-MSK or EAP-EMSK. Cannot create WiMAX keys"); return RLM_MODULE_NOOP; } @@ -239,8 +239,8 @@ static rlm_rcode_t CC_HINT(nonnull) mod_post_auth(void *instance, UNUSED void *t (mip_rk_1[2] << 8) | mip_rk_1[3]); if (mip_spi < 256) mip_spi += 256; - RDEBUG("MIP-RK = 0x%pH", fr_box_octets(mip_rk, rk_len)); - RDEBUG("MIP-SPI = %08x", ntohl(mip_spi)); + REDEBUG2("MIP-RK = 0x%pH", fr_box_octets(mip_rk, rk_len)); + REDEBUG2("MIP-SPI = %08x", ntohl(mip_spi)); /* * FIXME: Perform SPI collision prevention @@ -405,7 +405,7 @@ static rlm_rcode_t CC_HINT(nonnull) mod_post_auth(void *instance, UNUSED void *t */ vp = fr_pair_find_by_da(request->packet->vps, attr_wimax_rrq_mn_ha_spi, TAG_ANY); if (vp) { - RDEBUG("Client requested MN-HA key: Should use SPI to look up key from storage"); + REDEBUG2("Client requested MN-HA key: Should use SPI to look up key from storage"); if (!mn_nai) { RWDEBUG("MN-NAI was not found!"); } @@ -422,7 +422,7 @@ static rlm_rcode_t CC_HINT(nonnull) mod_post_auth(void *instance, UNUSED void *t */ vp = fr_pair_find_by_da(request->packet->vps, attr_wimax_ha_rk_key_requested, TAG_ANY); if (vp && (vp->vp_uint32 == 1)) { - RDEBUG("Client requested HA-RK: Should use IP to look it up from storage"); + REDEBUG2("Client requested HA-RK: Should use IP to look it up from storage"); } } diff --git a/src/modules/rlm_winbind/rlm_winbind.c b/src/modules/rlm_winbind/rlm_winbind.c index 11fca9d9db0..2ed95a597db 100644 --- a/src/modules/rlm_winbind/rlm_winbind.c +++ b/src/modules/rlm_winbind/rlm_winbind.c @@ -169,13 +169,13 @@ static int winbind_group_cmp(void *instance, REQUEST *request, UNUSED VALUE_PAIR goto error; } - RDEBUG2("Trying to find user \"%s\" in group \"%s\"", username, check->vp_strvalue); + REDEBUG2("Trying to find user \"%s\" in group \"%s\"", username, check->vp_strvalue); err = wbcCtxGetGroups(wb_ctx, username, &num_groups, &wb_groups); switch (err) { case WBC_ERR_SUCCESS: rcode = 0; - RDEBUG2("Successfully retrieved user's groups"); + REDEBUG2("Successfully retrieved user's groups"); break; case WBC_ERR_WINBIND_NOT_AVAILABLE: @@ -196,7 +196,7 @@ static int winbind_group_cmp(void *instance, REQUEST *request, UNUSED VALUE_PAIR break; } - if (!num_groups) RDEBUG("No groups returned"); + if (!num_groups) REDEBUG2("No groups returned"); if (rcode) goto finish; rcode = 1; @@ -232,7 +232,7 @@ static int winbind_group_cmp(void *instance, REQUEST *request, UNUSED VALUE_PAIR continue; } - RDEBUG3("Resolved GID %i to name \"%s\"", wb_groups[i], group->gr_name); + REDEBUG2("Resolved GID %i to name \"%s\"", wb_groups[i], group->gr_name); /* Find the backslash in the returned group name */ if ((backslash < strlen(group->gr_name)) && (group->gr_name[backslash] == '\\')) { @@ -245,9 +245,9 @@ static int winbind_group_cmp(void *instance, REQUEST *request, UNUSED VALUE_PAIR } /* See if the group matches */ - RDEBUG3("Checking plain group name \"%s\"", group_name); + REDEBUG2("Checking plain group name \"%s\"", group_name); if (!strcasecmp(group_name, check->vp_strvalue)) { - RDEBUG("Found matching group: %s", group_name); + REDEBUG2("Found matching group: %s", group_name); found = true; rcode = 0; } @@ -257,7 +257,7 @@ static int winbind_group_cmp(void *instance, REQUEST *request, UNUSED VALUE_PAIR if (found) break; } - if (rcode) RDEBUG2("No groups found that match"); + if (rcode) REDEBUG2("No groups found that match"); finish: wbcFreeMemory(wb_groups); @@ -464,7 +464,7 @@ static rlm_rcode_t CC_HINT(nonnull) mod_authorize(void *instance, UNUSED void *t rlm_winbind_t const *inst = instance; if (!request->password || (request->password->da != attr_user_password)) { - RDEBUG("No User-Password found in the request; not doing winbind authentication."); + REDEBUG2("No User-Password found in the request; not doing winbind authentication."); return RLM_MODULE_NOOP; } @@ -507,10 +507,10 @@ static rlm_rcode_t CC_HINT(nonnull) mod_authenticate(void *instance, UNUSED void * Log the password */ if (RDEBUG_ENABLED3) { - RDEBUG3("Login attempt with password \"%s\" (%zd)", request->password->vp_strvalue, + REDEBUG("Login attempt with password \"%s\" (%zd)", request->password->vp_strvalue, request->password->vp_length); } else { - RDEBUG("Login attempt with password"); + REDEBUG2("Login attempt with password"); } /* @@ -519,7 +519,7 @@ static rlm_rcode_t CC_HINT(nonnull) mod_authenticate(void *instance, UNUSED void * chatty enough. */ if (do_auth_wbclient_pap(inst, request) == 0) { - RDEBUG("User authenticated successfully using winbind"); + REDEBUG2("User authenticated successfully using winbind"); return RLM_MODULE_OK; } diff --git a/src/modules/rlm_yubikey/decrypt.c b/src/modules/rlm_yubikey/decrypt.c index 0a6957faeee..d66f2fedc24 100644 --- a/src/modules/rlm_yubikey/decrypt.c +++ b/src/modules/rlm_yubikey/decrypt.c @@ -51,7 +51,7 @@ rlm_rcode_t rlm_yubikey_decrypt(rlm_yubikey_t const *inst, REQUEST *request, cha return RLM_MODULE_REJECT; } - RDEBUG("Token data decrypted successfully"); + RDEBUG2("Token data decrypted successfully"); counter = (yubikey_counter(token.ctr) << 8) | token.use; timestamp = (token.tstph << 16) | token.tstpl; diff --git a/src/modules/rlm_yubikey/rlm_yubikey.c b/src/modules/rlm_yubikey/rlm_yubikey.c index 300ede7e8a4..80843c35b91 100644 --- a/src/modules/rlm_yubikey/rlm_yubikey.c +++ b/src/modules/rlm_yubikey/rlm_yubikey.c @@ -290,7 +290,7 @@ static rlm_rcode_t CC_HINT(nonnull) mod_authorize(void *instance, UNUSED void *t if (RDEBUG_ENABLED3) { RDMARKER(otp, -ret, "User-Password (aes-block) value contains non modhex chars"); } else { - RDEBUG("User-Password (aes-block) value contains non modhex chars"); + RDEBUG2("User-Password (aes-block) value contains non modhex chars"); } return RLM_MODULE_NOOP; }