fix: resolve LIBCUDA_LOG_LEVEL on first use so early messages honour it

[krim404]

I spent most of a day chasing this before reading the source, so I figured I should write it up
properly rather than just work around it.

Every process in our HAMi containers prints these to stderr, no matter what I set
LIBCUDA_LOG_LEVEL to:

[HAMI-core Warn(556:140497071547584:libvgpu.c:115)]: recursive dlsym : open64
[HAMI-core Warn(556:140497071547584:libvgpu.c:115)]: recursive dlsym : openat64
[HAMI-core Msg(9255:140295499897728:libvgpu.c:870)]: Initializing.....

What eventually made it click is that the device plugin already sets LIBCUDA_LOG_LEVEL=1 in the
container environment. The container is asking for warn level to be quiet, and it isn't, so
something was off rather than me holding it wrong.

The reason is just ordering. g_log_level starts at 2 in log_utils.c, and both LOG_WARN and
LOG_MSG fire at >= 2. But the variable is only read by log_utils_init(), and in libvgpu.c
that call sits at line 872, while the dlsym hook lives at 74 with its warning at 115 and the
"Initializing" message at 870. Both messages happen while g_log_level is still the compile time
default, which is exactly the threshold. Setting the variable to 0 in the pod environment changes
nothing for the warnings, and the Msg lines are identical for every value from 0 to 5.

One thing that might help reproducing: we only see the recursive dlsym warnings in containers
that ask for graphics in NVIDIA_DRIVER_CAPABILITIES. Compute only pods on the same node and
the same card have never shown them, presumably because far fewer libraries get resolved on the
way up.

Why I care enough to send a patch rather than pipe it to /dev/null: we run KDE desktops on HAMi
GPUs through Coder, which collects a few workspace metrics by running a small script per metric
and storing whatever comes back. The shell it spawns emits the warning while it is still being
linked, before the script's first line runs, so the warning ends up as the metric value. I tried
to filter it and could not, and the thing that finally convinced me was setting one metric's
entire script to echo ok. It came back as a HAMi warning. There is no point in the script that
is early enough, so there is nothing a consumer can do about it.

I did look for a way to patch around it on our side first. /etc/ld.so.preload and
/usr/local/vgpu/libvgpu.so are read only bind mounts, so nothing inside the container can
redirect them, and patching the library on the node gets overwritten on the next upgrade.

The change

log_level() resolves LIBCUDA_LOG_LEVEL on first use via pthread_once instead of depending
on log_utils_init() having run, and the four threshold checks in the macros go through it.
log_utils_init() keeps working and stays the thing pthread_once calls, so the existing call
site in preInit() is harmless either way. LOG_ERROR is untouched, it has no threshold.

Behaviour is unchanged when the variable is unset, and the levels now apply from the very first
message:

$ ./t                       # env unset, default 2
[HAMI-core Warn(...)]: recursive dlsym : open64
[HAMI-core Msg(...)]: Initializing.....
[HAMI-core ERROR (...)]: boom 1

$ LIBCUDA_LOG_LEVEL=1 ./t
[HAMI-core ERROR (...)]: boom 1

$ LIBCUDA_LOG_LEVEL=0 ./t
[HAMI-core ERROR (...)]: boom 1

In case it comes up in review: calling getenv() from inside the dlsym hook is fine, it does not
route through dlsym itself, so this does not feed the recursion the hook exists to catch.

If you would rather keep log_utils_init() as the single entry point and call it from a
constructor instead, that works for me too. I went with the accessor because it does not depend
on constructor ordering, which is the part that broke here in the first place.

Tested against HAMi v2.9.0 on an RTX PRO 6000 Blackwell, driver 610.43.02, Debian 13 on kernel
6.12, k3s v1.35.1 with containerd.

Summary by CodeRabbit

• Bug Fixes
  • Improved logging behavior when messages are emitted before logging initialization.
  • Log-level settings are now resolved consistently on first use, preventing initialization-order issues.
  • Logging configuration is safely handled when accessed concurrently.
  • Existing default behavior and output destinations remain unchanged.

[hami-robot]

[APPROVALNOTIFIER] This PR is NOT APPROVED

This pull-request has been approved by: krim404
Once this PR has been reviewed and has the lgtm label, please assign archlitchi for approval. For more information see the Kubernetes Code Review Process.

The full list of commands accepted by this bot can be found here.

Details

Needs approval from an approver in each of these files:

• OWNERS

Approvers can indicate their approval by writing /approve in a comment
Approvers can cancel approval by writing /approve cancel in a comment

[hami-robot]

Welcome @krim404! It looks like this is your first PR to Project-HAMi/HAMi-core 🎉

[coderabbitai]

No actionable comments were generated in the recent review. 🎉

ℹ️ Recent review info

⚙️ Run configuration

Configuration used: Organization UI

Review profile: CHILL

Plan: Pro Plus

Run ID: 47b375e2-4a8c-437c-9bdb-04e01321d456

📥 Commits

Reviewing files that changed from the base of the PR and between 52f33fc and e044eb9.

📒 Files selected for processing (2)

• src/include/log_utils.h
• src/log_utils.c

---

📝 Walkthrough

Walkthrough

Logging macros now use a public log_level() accessor. The accessor lazily and thread-safely initializes the cached level from LIBCUDA_LOG_LEVEL, allowing messages emitted before explicit logging initialization to resolve the configured threshold.

Changes

Logging level initialization and macro integration

Layer / File(s)	Summary
Thread-safe lazy accessor src/log_utils.c	Adds pthread_once initialization so log_level() invokes log_utils_init() once before returning g_log_level.
Logging macro threshold integration src/include/log_utils.h	Updates FILEDEBUG and non-FILEDEBUG macros to use log_level() while preserving existing file and stderr output behavior.

Estimated code review effort: 3 (Moderate) | ~20 minutes

Sequence Diagram(s)

sequenceDiagram
  participant LoggingMacro
  participant log_level
  participant pthread_once
  participant log_utils_init
  participant Environment
  LoggingMacro->>log_level: request threshold level
  log_level->>pthread_once: initialize once
  pthread_once->>log_utils_init: resolve cached level
  log_utils_init->>Environment: read LIBCUDA_LOG_LEVEL
  log_level-->>LoggingMacro: return g_log_level

Loading

Suggested labels: enhancement

Poem

A rabbit logs beneath the moon,
“The level wakes up none too soon!”
Once through the gate, the settings flow,
To file or stderr, on they go.
Thread-safe whispers, neat and bright—
Hop, hop, logs now choose their light!

🚥 Pre-merge checks | ✅ 5

✅ Passed checks (5 passed)

Check name	Status	Explanation
Description Check	✅ Passed	Check skipped - CodeRabbit’s high-level summary is enabled.
Title check	✅ Passed	The title clearly summarizes the main change: resolving LIBCUDA_LOG_LEVEL on first use so early log messages honor it.
Docstring Coverage	✅ Passed	No functions found in the changed files to evaluate docstring coverage. Skipping docstring coverage check.
Linked Issues check	✅ Passed	Check skipped because no linked issues were found for this pull request.
Out of Scope Changes check	✅ Passed	Check skipped because no linked issues were found for this pull request.

✨ Finishing Touches

🧪 Generate unit tests (beta)

• Create PR with unit tests

---

Thanks for using CodeRabbit! It's free for OSS, and your support helps us grow. If you like it, consider giving us a shout-out.

❤️ Share

• X
• Mastodon
• Reddit
• LinkedIn

_{Comment @coderabbitai help to get the list of available commands.}