From 5918cff18c87cb0d43d6c19484770006e22eaf4c Mon Sep 17 00:00:00 2001 From: Aleksander Wennersteen Date: Mon, 13 Jul 2026 16:27:16 +0200 Subject: [PATCH 1/3] Add QRMI log callback --- plugins/spank_qrmi/CMakeLists.txt | 8 +- plugins/spank_qrmi/README.md | 41 ++++++- plugins/spank_qrmi/spank_qrmi.c | 194 ++++++++++++++++++++---------- 3 files changed, 177 insertions(+), 66 deletions(-) diff --git a/plugins/spank_qrmi/CMakeLists.txt b/plugins/spank_qrmi/CMakeLists.txt index be71243..541187a 100644 --- a/plugins/spank_qrmi/CMakeLists.txt +++ b/plugins/spank_qrmi/CMakeLists.txt @@ -128,6 +128,12 @@ target_link_libraries(spank_qrmi target_include_directories(spank_qrmi PRIVATE ${QRMI_SOURCE_DIR} ) +if(EXISTS "${QRMI_SOURCE_DIR}/qrmi.h") + file(READ "${QRMI_SOURCE_DIR}/qrmi.h" QRMI_HEADER_CONTENTS) + if(QRMI_HEADER_CONTENTS MATCHES "qrmi_log_callback_set") + target_compile_definitions(spank_qrmi PRIVATE QRMI_HAS_LOG_CALLBACK=1) + endif() +endif() target_compile_options(spank_qrmi PRIVATE -Wall -Wextra -Werror -O2 -pedantic -Wconversion -Wwrite-strings -Wfloat-equal -) \ No newline at end of file +) diff --git a/plugins/spank_qrmi/README.md b/plugins/spank_qrmi/README.md index 66481cb..0a47ba6 100644 --- a/plugins/spank_qrmi/README.md +++ b/plugins/spank_qrmi/README.md @@ -129,6 +129,12 @@ required /usr/lib64/slurm/spank_qrmi.so /etc/slurm/qrmi_config.json > ```bash > required /usr/lib64/slurm/spank_qrmi.so /etc/slurm/qrmi_config.json --env:http_proxy=http://192.168.1.128:3128 --env:https_proxy=http://192.168.1.128:3128 > ``` +> +> The same mechanism can be used to control QRMI runtime logging for the Slurm daemon process, for example: +> ```bash +> required /usr/lib64/slurm/spank_qrmi.so /etc/slurm/qrmi_config.json --env:RUST_LOG=qrmi=debug,reqwest=warn +> ``` +> For allocator node, your don't need to specify the path to qrmi_config.json like below. @@ -174,7 +180,17 @@ This plugin uses Slurm logger for logging. Log messages from this plugin can be [2025-07-31T09:43:34.020] [21.batch] debug: spank_qrmi_c: name(ibm_sherbrooke), type(1) found in qrmi_config ``` -You can enable QRMI runtime log by specifying the following `srun` arguments. +The plugin also routes QRMI runtime logs from the daemon-side acquire/release +path through Slurm logging. These records are emitted with a `spank_qrmi QRMI` +prefix in the Slurm daemon logs, for example: + +```bash +[2026-06-22T12:21:24.012] [17.batch] debug: spank_qrmi QRMI reqwest::connect: starting new connection: http://c1:4207/ +``` + +By default, QRMI itself logs at `warn`. For QPU jobs, this plugin sets +`RUST_LOG` from Slurm's `SRUN_DEBUG` level when `RUST_LOG` has not already been +set: | sbatch/srun option | Slurm log level (SRUN_DEBUG) | QRMI log level (RUST_LOG) | | ---- | ---- | ---- | @@ -183,6 +199,29 @@ You can enable QRMI runtime log by specifying the following `srun` arguments. | --verbose | 4 | debug | | -vv or more | 5 | trace | +You can override QRMI logging independently of Slurm logging by setting +`RUST_LOG` in `plugstack.conf` with `--env:RUST_LOG=...`. The plugin applies +`--env:` arguments before QRMI is initialized, so the setting applies to both +daemon-side acquire/release calls and the job environment. + +Examples: + +```bash +# Slurm debug logs, but keep QRMI less verbose. +required /usr/lib64/slurm/spank_qrmi.so /etc/slurm/qrmi_config.json --env:RUST_LOG=warn + +# QRMI debug logs without increasing Slurm's requested job verbosity. +required /usr/lib64/slurm/spank_qrmi.so /etc/slurm/qrmi_config.json --env:RUST_LOG=debug + +# Target QRMI while keeping HTTP client logs quieter. +required /usr/lib64/slurm/spank_qrmi.so /etc/slurm/qrmi_config.json --env:RUST_LOG=qrmi=debug,reqwest=warn + +``` + +QRMI records still pass through Slurm's logging APIs. QRMI `debug` records are +written with `slurm_debug()`, so Slurm's daemon log level must allow debug logs +for them to appear in `slurmd.log`. QRMI `info`, `warn`, and `error` records are +sent through Slurm info/error logging. Example: diff --git a/plugins/spank_qrmi/spank_qrmi.c b/plugins/spank_qrmi/spank_qrmi.c index 528b450..f3cce42 100644 --- a/plugins/spank_qrmi/spank_qrmi.c +++ b/plugins/spank_qrmi/spank_qrmi.c @@ -70,8 +70,13 @@ static qpu_resource_t *_acquired_resource_create(char *name, QrmiResourceType ty static void _acquired_resource_destroy(void *object); static qpu_resource_t *_acquire_qpu(spank_t spank_ctxt, char *name, QrmiResourceType type); static void _release_qpu(qpu_resource_t *res); +static void slurm_qrmi_error(const char *format, ...); static qrmi_error_t *_qrmi_error_create(char* message); static void _qrmi_error_destroy(void *object); +#if defined(QRMI_HAS_LOG_CALLBACK) +static void _qrmi_log_to_slurm(const char *level, const char *target, const char *message); +#endif +static bool _configure_qrmi_logging(spank_t spank_ctxt); /* * @function _dump_environ @@ -98,6 +103,9 @@ static bool _starts_with(const char *str, const char *prefix) { return strncmp(prefix, str, strlen(prefix)) == 0; } + return true; +} + /* * @function _qpu_names_opt_cb * @@ -231,6 +239,59 @@ int slurm_spank_init_post_opt(spank_t spank_ctxt, int argc, char **argv) { return SLURM_SUCCESS; } + for (int i = 0; i < argc; i++) { + slurm_debug("%s: argv[%d] = [%s]", plugin_name, i, argv[i]); + } + + if (argc == 0) { + slurm_qrmi_error("%s, QRMI config file not specified to plugin args", plugin_name); + g_init_post_opt_failed = true; + return SLURM_SUCCESS; + } + + /* + * Parses optional plugin arguments. + * + * Environment settings use --env:{variable name}={value}. + */ + for (int i = 1; i < argc; i++) { + if (!_starts_with(argv[i], "--env:")) { + /* ignored. */ + continue; + } + const char *input = &argv[i][strlen("--env:")]; + const char *delimiter = strchr(input, '='); + if (delimiter == NULL) { + slurm_qrmi_error("%s, Invalid --env: argument. '=' delimiter not found in %s", plugin_name, argv[i]); + g_init_post_opt_failed = true; + return SLURM_SUCCESS; + } + size_t env_name_len = (size_t)(delimiter - input); + char *env_name = strndup(input, env_name_len); + if (env_name == NULL) { + slurm_qrmi_error("%s, Failed to allocate buffer with length = %ld", plugin_name, env_name_len); + g_init_post_opt_failed = true; + return SLURM_SUCCESS; + } + const char *env_value = delimiter + 1; + if (setenv(env_name, env_value, OVERWRITE) != 0) { + slurm_qrmi_error("%s, Failed to set environment variable %s", plugin_name, env_name); + g_init_post_opt_failed = true; + free(env_name); + return SLURM_SUCCESS; + } + if (spank_setenv(spank_ctxt, env_name, env_value, OVERWRITE) != ESPANK_SUCCESS) { + slurm_debug("%s, unable to set SPANK environment variable %s", plugin_name, + env_name); + } + free(env_name); + } + + if (!_configure_qrmi_logging(spank_ctxt)) { + g_init_post_opt_failed = true; + return SLURM_SUCCESS; + } + /* * Set environment variable for slurm job ID and UID. */ @@ -261,16 +322,6 @@ int slurm_spank_init_post_opt(spank_t spank_ctxt, int argc, char **argv) { spank_setenv(spank_ctxt, "SLURM_JOB_QPU_RESOURCES", "", OVERWRITE); spank_setenv(spank_ctxt, "SLURM_JOB_QPU_TYPES", "", OVERWRITE); - for (int i = 0; i < argc; i++) { - slurm_debug("%s: argv[%d] = [%s]", plugin_name, i, argv[i]); - } - - if (argc == 0) { - slurm_qrmi_error("%s, QRMI config file not specified to plugin args", plugin_name); - g_init_post_opt_failed = true; - return SLURM_SUCCESS; - } - QrmiConfig *cnf = qrmi_config_load(argv[0]); if (cnf == NULL) { slurm_qrmi_error("%s, Failed to load QRMI config file(%s). %s", @@ -280,37 +331,6 @@ int slurm_spank_init_post_opt(spank_t spank_ctxt, int argc, char **argv) { } slurm_debug("%s, config: %p", plugin_name, (void *)cnf); - /* - * Parses optional plugin arguments. - * - * Currently, only environment variable settings prefixed with - * --env:{variable name}={value} are supported. - */ - for (int i = 1; i < argc; i++) { - if (!_starts_with(argv[i], "--env:")) { - /* ignored. */ - continue; - } - const char *input = &argv[i][strlen("--env:")]; - const char *delimiter = strchr(input, '='); - if (delimiter == NULL) { - slurm_qrmi_error("%s, Invalid --env: argument. '=' delimiter not found in %s", plugin_name, argv[i]); - g_init_post_opt_failed = true; - return SLURM_SUCCESS; - } - size_t env_name_len = (size_t)(delimiter - input); - char *env_name = strndup(input, env_name_len); - if (env_name == NULL) { - slurm_qrmi_error("%s, Failed to allocate buffer with length = %ld", plugin_name, env_name_len); - g_init_post_opt_failed = true; - return SLURM_SUCCESS; - } - const char *env_value = delimiter + 1; - setenv(env_name, env_value, OVERWRITE); - spank_setenv(spank_ctxt, env_name, env_value, OVERWRITE); - free(env_name); - } - char *bufp = strdup(g_qpu_names_opt); if (bufp == NULL) { slurm_qrmi_error("%s, Failed to allocate buffer with length = %ld", @@ -474,46 +494,90 @@ static void _report_deferred_errors(void) { * * Set environment variables for QRMI runtime logging, based on SRUN_DEBUG. */ -static void _set_rust_loglevel(spank_t spank_ctxt) { - buffer buf; - qrmi_buf_init(&buf, MAX_INT_STRLEN + 1); - if (spank_getenv(spank_ctxt, "SRUN_DEBUG", buf.buffer, MAX_INT_STRLEN + 1) != - ESPANK_SUCCESS) { - qrmi_buf_free(&buf); - return; +static const char *_rust_loglevel_from_srun_debug(const char *srun_debug) { + if (srun_debug == NULL) { + return "info"; } /* if failed, level=0 --> default level(info) */ - int level = atoi(buf.buffer); - const char *level_str = NULL; + int level = atoi(srun_debug); switch (level) { case 2: /* --quiet */ - level_str = "error"; - break; + return "error"; case 3: /* default */ - level_str = "info"; - break; + return "info"; case 4: /* --verbose */ - level_str = "debug"; - break; + return "debug"; default: if (level >= 5) { /* -vv or more */ - level_str = "trace"; - } else { - /* default is Info as same as srun */ - level_str = "info"; + return "trace"; } - break; + /* default is Info as same as srun */ + return "info"; + } +} + +static bool _set_rust_loglevel(spank_t spank_ctxt) { + buffer buf; + const char *level_str = NULL; + qrmi_buf_init(&buf, MAX_INT_STRLEN + 1); + if (spank_getenv(spank_ctxt, "SRUN_DEBUG", buf.buffer, MAX_INT_STRLEN + 1) != + ESPANK_SUCCESS) { + level_str = _rust_loglevel_from_srun_debug(NULL); + } else { + level_str = _rust_loglevel_from_srun_debug(buf.buffer); } if (level_str != NULL) { - spank_setenv(spank_ctxt, "RUST_LOG", level_str, KEEP_IF_EXISTS); - slurm_debug("%s: setenv(%s, %s)", plugin_name, "RUST_LOG", level_str); + if (setenv("RUST_LOG", level_str, KEEP_IF_EXISTS) != 0) { + slurm_qrmi_error("%s, Failed to set environment variable %s", plugin_name, + "RUST_LOG"); + qrmi_buf_free(&buf); + return false; + } + if (spank_setenv(spank_ctxt, "RUST_LOG", level_str, KEEP_IF_EXISTS) != + ESPANK_SUCCESS) { + slurm_debug("%s, unable to set SPANK environment variable %s", plugin_name, + "RUST_LOG"); + } + slurm_debug("%s: setenv(%s, %s)", plugin_name, "RUST_LOG", getenv("RUST_LOG")); } qrmi_buf_free(&buf); + return true; +} + +#if defined(QRMI_HAS_LOG_CALLBACK) +static void _qrmi_log_to_slurm(const char *level, const char *target, const char *message) { + const char *log_target = target != NULL ? target : "qrmi"; + const char *log_message = message != NULL ? message : ""; + + if (level == NULL) { + slurm_info("%s QRMI %s: %s", plugin_name, log_target, log_message); + } else if (strcmp(level, "ERROR") == 0) { + slurm_error("%s QRMI %s: %s", plugin_name, log_target, log_message); + } else if (strcmp(level, "WARN") == 0) { + slurm_info("%s QRMI WARN %s: %s", plugin_name, log_target, log_message); + } else if (strcmp(level, "INFO") == 0) { + slurm_info("%s QRMI %s: %s", plugin_name, log_target, log_message); + } else if (strcmp(level, "DEBUG") == 0) { + slurm_debug("%s QRMI %s: %s", plugin_name, log_target, log_message); + } else { + slurm_debug2("%s QRMI %s %s: %s", plugin_name, level, log_target, log_message); + } +} +#endif + +static bool _configure_qrmi_logging(spank_t spank_ctxt) { + if (!_set_rust_loglevel(spank_ctxt)) { + return false; + } +#if defined(QRMI_HAS_LOG_CALLBACK) + qrmi_log_callback_set(_qrmi_log_to_slurm); +#endif + return true; } @@ -604,7 +668,9 @@ int slurm_spank_task_init(spank_t spank_ctxt, int argc, char **argv) { /* * Set environment variables for QRMI runtime logging. */ - _set_rust_loglevel(spank_ctxt); + if (!_set_rust_loglevel(spank_ctxt)) { + return SLURM_ERROR; + } SPANK_DEBUG_LEAVE(); From 892bd9a3fa0694ac5b86ee88d64eb0377d095673 Mon Sep 17 00:00:00 2001 From: Aleksander Wennersteen Date: Tue, 14 Jul 2026 11:00:53 +0200 Subject: [PATCH 2/3] fix --- plugins/spank_qrmi/spank_qrmi.c | 3 --- 1 file changed, 3 deletions(-) diff --git a/plugins/spank_qrmi/spank_qrmi.c b/plugins/spank_qrmi/spank_qrmi.c index f3cce42..1f6ad2c 100644 --- a/plugins/spank_qrmi/spank_qrmi.c +++ b/plugins/spank_qrmi/spank_qrmi.c @@ -103,9 +103,6 @@ static bool _starts_with(const char *str, const char *prefix) { return strncmp(prefix, str, strlen(prefix)) == 0; } - return true; -} - /* * @function _qpu_names_opt_cb * From 74154f10fd683c5370444f2f91f5e248c499aa2f Mon Sep 17 00:00:00 2001 From: Aleksander Wennersteen Date: Tue, 14 Jul 2026 11:13:20 +0200 Subject: [PATCH 3/3] Remove tokens from logs. with new logging, this will leak credentials to system logs --- plugins/spank_qrmi/spank_qrmi.c | 19 +++++++------------ 1 file changed, 7 insertions(+), 12 deletions(-) diff --git a/plugins/spank_qrmi/spank_qrmi.c b/plugins/spank_qrmi/spank_qrmi.c index 1f6ad2c..9407bcb 100644 --- a/plugins/spank_qrmi/spank_qrmi.c +++ b/plugins/spank_qrmi/spank_qrmi.c @@ -408,8 +408,7 @@ int slurm_spank_init_post_opt(spank_t spank_ctxt, int argc, char **argv) { slurm_list_append(g_acquired_resources, acquired); qrmi_buf_envvarname_for_res_create(&keybuf, res->name, "QRMI_JOB_ACQUISITION_TOKEN"); - slurm_debug("%s: setenv(%s, %s)", plugin_name, keybuf.buffer, - acquired->acquisition_token); + slurm_debug("%s: setenv(%s)", plugin_name, keybuf.buffer); setenv(keybuf.buffer, acquired->acquisition_token, KEEP_IF_EXISTS); spank_setenv(spank_ctxt, keybuf.buffer, acquired->acquisition_token, KEEP_IF_EXISTS); @@ -440,8 +439,7 @@ int slurm_spank_init_post_opt(spank_t spank_ctxt, int argc, char **argv) { void *x = NULL; while ((x = slurm_list_next(sessions_iter)) != NULL) { qpu_resource_t *item = (qpu_resource_t *)x; - slurm_debug("%s: name(%s), type(%d), token(%s)", plugin_name, item->name, item->type, - item->acquisition_token); + slurm_debug("%s: name(%s), type(%d)", plugin_name, item->name, item->type); strbuf_append_str(&qpu_resources_envvar, item->name); const char *type_as_str = qrmi_config_resource_type_to_str(item->type); slurm_debug("%s: type_as_str(%s)", plugin_name, type_as_str); @@ -828,7 +826,7 @@ static qpu_resource_t *_acquire_qpu(spank_t spank_ctxt, char *name, QrmiResource return NULL; } - slurm_debug("%s, acquisition_token: %s(%s)", plugin_name, acquisition_token, name); + slurm_debug("%s, acquired resource: %s", plugin_name, name); qpu_resource_t *res = _acquired_resource_create(name, type, acquisition_token); qrmi_string_free(acquisition_token); return res; @@ -848,8 +846,7 @@ static void _release_qpu(qpu_resource_t *res) { if (res == NULL) { return; } - slurm_debug("%s: releasing name(%s), type(%d), token(%s)", plugin_name, res->name, res->type, - res->acquisition_token); + slurm_debug("%s: releasing name(%s), type(%d)", plugin_name, res->name, res->type); void *qrmi = qrmi_resource_new(res->name, res->type); if (qrmi == NULL) { slurm_error("%s, Failed to create a QRMI instance, %s", @@ -858,14 +855,12 @@ static void _release_qpu(qpu_resource_t *res) { } rc = qrmi_resource_release(qrmi, res->acquisition_token); if (rc != QRMI_RETURN_CODE_SUCCESS) { - slurm_error("%s, Failed to release acquired resource: name(%s), type(%d), token(%s), %s", - plugin_name, res->name, res->type, res->acquisition_token, - qrmi_get_last_error()); + slurm_error("%s, Failed to release acquired resource: name(%s), type(%d), %s", plugin_name, + res->name, res->type, qrmi_get_last_error()); } rc = qrmi_string_free(res->acquisition_token); if (rc != QRMI_RETURN_CODE_SUCCESS) { - slurm_error("%s, Failed to free acquisition token string: (%s)", plugin_name, - res->acquisition_token); + slurm_error("%s, Failed to free acquisition token string", plugin_name); } rc = qrmi_resource_free(qrmi); if (rc != QRMI_RETURN_CODE_SUCCESS) {