Walkthrough

Updates lib/log.sh to use ${LOG_FD:-} for LOG_FD checks and redirections, exports LOG_FD so child processes inherit it, and revises comments to reference subshells/child processes and preserving original STDOUT. No other files changed.

Changes

Sequence Diagram(s)

sequenceDiagram
  autonumber
  participant Shell as User Shell
  participant Script as lib/log.sh
  participant Env as Environment
  participant Child as Child Process
  participant STDOUT as Original STDOUT (preserved FD)

  Shell->>Script: source/run script
  Script->>Script: test/expand LOG_FD using ${LOG_FD:-}
  Script->>STDOUT: duplicate original STDOUT onto free fd (LOG_FD)
  Script->>Env: export LOG_FD
  Note over Script,Env: exported for inheritance

  Shell->>Child: spawn subprocess
  Child->>Env: inherits LOG_FD
  Child->>STDOUT: write logs via inherited LOG_FD
  Note over Child,STDOUT: logs routed through preserved FD

Estimated code review effort

🎯 2 (Simple) | ⏱️ ~10 minutes

Potential focus areas:

• Confirm semantics of ${LOG_FD:-} vs previous expansion in all conditional branches.
• Verify export won't unintentionally leak into environments where not desired.

Possibly related PRs

• Fix unbound variable in log initialization #173 — Also adjusts lib/log.sh LOG_FD handling and initialization behavior.
• Use parent STDOUT for logging output #172 — Related edits around preserving stdout and redirecting logs via LOG_FD.

Suggested labels

bugfix

Suggested reviewers

• frenck

Poem

I hop and tweak a tiny thread,
I tuck stdout where logs are led.
I pass the FD with gentle thump,
So child processes can all jump.
Logs safe and warm — a rabbit's thump. 🥕🐇

Pre-merge checks and finishing touches

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.

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

Specifically (as described in #172 comment), log messages and stdout could still get mixed up if one bashio script calls another bashio script as a child (not as a subshell).

Can you elaborate what exact real world use-case that fixes? Do you have an example from an add-on where that is actually necessary?

From my testing, the current approach is enough to fix function calling, which from all I know is really used in real world (see #172 (comment)).

@agners while I can't give a real-world example from the wild, I think I get what @PaulSD means. Here's a reproducer:

Sure, I understand how it could come to this situation. But do we need to support this case 🤔 🤷 ?

The move to stderr changed the contract of how any bashio script can be used, this is even true with all this changes, e.g. if the stdout of the "root" script is parsed somewhere, that will behave differently as well:

LOG_LEVEL=7 ./test.sh  | grep Hello

I'd make the point why does the root bashio script should be different than subscripts?

IMO the latter is the correct behavior, as there's indeed no mixing of the logging and stdout.

We started off to redirect logging to stdout, since stderr felt wrong. Now we kinda separate it into yet another fd, but only for sub scripts.

IMHO, we made the conscious decision that basio scripts should log to stdout, and we should stick with that. Unfortunately it also broke internal function calling. But that is fixed by #172. But no more magic needed, it's now logging to stdout.

There hasn't been any activity on this pull request recently. This pull request has been automatically marked as stale because of that and will be closed if no further activity occurs within 7 days. Thank you for your contributions.

@agners
(Sorry for the long delay. This fell off my radar, and I'm circling back to it now.)

Can you elaborate what exact real world use-case that fixes? Do you have an example from an add-on where that is actually necessary?

Scanning through a few add-ons that I am familiar with, I don't see any examples where the add-on is broken out-of-the-box and requires this PR to fix it.

However, I think it is entirely plausible that a developer or user could set up an add-on in a way that breaks things without this PR.

As a slightly contrived but plausible example:
A user of the "Advanced SSH & Web Terminal" add-on might want to add a command to the init_commands option in that add-on which uses bashio to retrieve some value from HA. Maybe something like this:

bash -c 'source /usr/lib/bashio/bashio.sh ; [ "$(bashio::services "mqtt" "ssl")" = "true" ]' && echo '--insecure' >> /root/.config/mosquitto_sub

As-is, setting log_level: trace on the SSH add-on will break this example. With the fix in this PR, this works as expected.

In addition to that example, note that you seemed to agree that this fix was worthwhile in this comment, where you said:

But yeah, with that in mind its maybe safer to not rely on that optimization, and pass down LOG_FD to bashio subshells just in case.

Note that #177 (comment) mentions running bashio scripts from other bashio scripts, which is exactly the use case that this PR tries to help with.

Note that #177 (comment) mentions running bashio scripts from other bashio scripts, which is exactly the use case that this PR tries to help with.

TLDR: If an add-on, that has some custom bashio script (in /usr/bin), and the output of this script is captured anywhere, that add-on will crash if the log level is set to debug.

I've added export LOG_FD to the beginning of each of my script to make it work (s6 services, stage2_hook, healthcheck, NetworkManager, and plain bashio scripts).

I'm really surprised, that after bashio v0.17.2 (2 month ago), nobody run into this problem.

And I've found another issue. In case of healthcheck or eg. networkmanager scripts (NM dispatcher is started as an s6 service), when bashio's exec {LOG_FD}>&1 is run at the script's start, &1 has no value (/dev/null), so LOG_FD's &10 will point to nowhere.

After &1 and &2 is "initialized" in the script, a new bashio::log.??? function would be useful (sg. like bashio::log.reinitialize_output), with sg. like this (note: eval is needed, otherwise 10 not found is the result):

if [[ "${LOG_FD:-}" =~ ^[0-9]+$ ]]; then
  eval "exec ${LOG_FD}>&1" || true
fi

Just for reference:

• Healthcheck script at the beginning:

# Redirect outputs to the log (&1 and &2 are not initialized by Docker)
exec &> /proc/1/fd/1
if [[ "${LOG_FD:-}" =~ ^[0-9]+$ ]]; then
  eval "exec ${LOG_FD}>&1" || true
fi

• NM dispatcher script at the beginning:

# Redirect outputs to the log (&2 is already set up as pipe by s6)
exec 1>&2
if [[ "${LOG_FD:-}" =~ ^[0-9]+$ ]]; then
  eval "exec ${LOG_FD}>&1" || true
fi

So a bashio::log.reinitialize_output would hide these undocumented LOG_FD details.

In addition to that example, note that you seemed to agree that this fix was worthwhile in this comment, where you said:

But yeah, with that in mind its maybe safer to not rely on that optimization, and pass down LOG_FD to bashio subshells just in case.

Right, I came around on the LOG_FD variable thing: Knowing that bash optimized these function calls to run in the same process, which had the side effect making our logging work as we intend. But it's safer to make sure even a sub-process gets the logging fd.

FYI: Created a new PR #178 to handle the STDOUT reinitialization case (mentioned in my comment #174 (comment))

There hasn't been any activity on this pull request recently. This pull request has been automatically marked as stale because of that and will be closed if no further activity occurs within 7 days. Thank you for your contributions.

not stale, this is show stopper level critical for add-ons that use scripts that return values and use bashio logging also

There hasn't been any activity on this pull request recently. This pull request has been automatically marked as stale because of that and will be closed if no further activity occurs within 7 days. Thank you for your contributions.

not stale

There hasn't been any activity on this pull request recently. This pull request has been automatically marked as stale because of that and will be closed if no further activity occurs within 7 days. Thank you for your contributions.

not stale

There hasn't been any activity on this pull request recently. This pull request has been automatically marked as stale because of that and will be closed if no further activity occurs within 7 days. Thank you for your contributions.

not stale