Skip to content

Conversation

@PaulSD
Copy link
Contributor

@PaulSD PaulSD commented Sep 27, 2025

This fixes another potential problem with #169 which #172 failed to fix.

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).

Summary by CodeRabbit

  • New Features

    • Logging configuration is now exported so child processes inherit consistent logging behavior.
  • Bug Fixes

    • Improved handling when the logging descriptor is unset or empty to avoid unintended redirection.
    • Preserves original standard output on the reserved descriptor to maintain prior output behavior.
  • Documentation

    • Clarified comments describing logging interactions with subshells and child processes.

@coderabbitai
Copy link

coderabbitai bot commented Sep 27, 2025

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

Cohort / File(s) Summary
Logging FD handling
lib/log.sh
Replace ${LOG_FD-} with ${LOG_FD:-} for validity checks and redirection targets, ensure original STDOUT is duplicated to a free fd via LOG_FD, export LOG_FD unconditionally for subprocess inheritance, and update comments to reflect subshell/child behavior.

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
Loading

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

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

❌ Failed checks (1 warning)
Check name Status Explanation Resolution
Docstring Coverage ⚠️ Warning Docstring coverage is 0.00% which is insufficient. The required threshold is 80.00%. You can run @coderabbitai generate docstrings to improve docstring coverage.
✅ Passed checks (2 passed)
Check name Status Explanation
Description Check ✅ Passed Check skipped - CodeRabbit’s high-level summary is enabled.
Title Check ✅ Passed The pull request title "Allow child bashio processes to access the parent LOG_FD variable" directly reflects the main objective and core change of the pull request. The primary modification is exporting the LOG_FD variable unconditionally in lib/log.sh, which is precisely what enables child processes to access it—the exact scenario described in the title. The title is concise, specific, and clearly communicates the change's purpose without unnecessary details or vague language. A developer scanning the repository history would immediately understand that this PR addresses inter-process variable accessibility for logging.
✨ Finishing touches
  • 📝 Generate docstrings
🧪 Generate unit tests (beta)
  • Create PR with unit tests
  • Post copyable unit tests in a comment

📜 Recent review details

Configuration used: CodeRabbit UI

Review profile: CHILL

Plan: Pro

📥 Commits

Reviewing files that changed from the base of the PR and between fb252ac and aacc78f.

📒 Files selected for processing (1)
  • lib/log.sh (1 hunks)
🚧 Files skipped from review as they are similar to previous changes (1)
  • lib/log.sh

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

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

Copy link

@coderabbitai coderabbitai bot left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Actionable comments posted: 1

📜 Review details

Configuration used: CodeRabbit UI

Review profile: CHILL

Plan: Pro

📥 Commits

Reviewing files that changed from the base of the PR and between d9f9ee5 and 66b6fbc.

📒 Files selected for processing (1)
  • lib/log.sh (1 hunks)
🔇 Additional comments (2)
lib/log.sh (2)

11-11: Robust fd validation check — good guard.

Using ${LOG_FD:-} with a writability probe keeps set -u safe and avoids inheriting a stale/closed fd. LGTM.


13-14: Comment clarity improved.

The note now accurately distinguishes subshell vs child process behavior. Thanks.

@agners
Copy link
Contributor

agners commented Sep 29, 2025

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)).

Copy link
Collaborator

@sairon sairon left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

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

$ cat test.sh 
#!lib/bashio
echo "PID: $$"
echo "LOG_FD: $LOG_FD"
bashio::log.info "Hello from $$, LOG_FD: $LOG_FD"
./subprocess.sh > test.out

$ cat subprocess.sh 
#!lib/bashio
echo "PID: $$"
echo "LOG_FD: $LOG_FD"
bashio::log.info "Hello from $$, LOG_FD: $LOG_FD"
if bashio::fs.file_exists $0; then
    echo "I exist"
fi
./subprocess2.sh

$ cat subprocess2.sh 
#!lib/bashio
echo "PID: $$"
echo "LOG_FD: $LOG_FD"
bashio::log.info "Hello from $$, LOG_FD: $LOG_FD"

Without the change:

$ LOG_LEVEL=7 ./test.sh 
PID: 79493
LOG_FD: 10
[12:08:38] INFO: Hello from 79493, LOG_FD: 10

$ cat test.out 
PID: 79498
LOG_FD: 11
[12:08:38] INFO: Hello from 79498, LOG_FD: 11
[12:08:38] TRACE: bashio::fs.file_exists: ./subprocess.sh
I exist
PID: 79504
LOG_FD: 12
[12:08:38] INFO: Hello from 79504, LOG_FD: 12

With the change:

$ LOG_LEVEL=7 ./test.sh 
PID: 80223
LOG_FD: 10
[12:09:43] INFO: Hello from 80223, LOG_FD: 10
[12:09:43] INFO: Hello from 80228, LOG_FD: 10
[12:09:43] TRACE: bashio::fs.file_exists: ./subprocess.sh
[12:09:43] INFO: Hello from 80234, LOG_FD: 10

$ cat test.out 
PID: 80228
LOG_FD: 10
I exist
PID: 80234
LOG_FD: 10

IMO the latter is the correct behavior, as there's indeed no mixing of the logging and stdout. Also there's difference in the behavior when the LOG_FD is set for the parent process - as the guard is applied then for all subprocesses and it essentially behaves the same way as the fixed version. While you could argue that you can explicitly export LOG_FD before you call the first bashio script from the main one, I don't think it's really intuitive.

Comment on lines 17 to 20
# Export LOG_FD for use by child bashio processes.
export LOG_FD
Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I think we can move this to the conditional block above 🤔

Copy link
Contributor Author

@PaulSD PaulSD Nov 1, 2025

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I actually did that on my first attempt, but CodeRabbit suggested making it unconditional, and the justification CodeRabbit provided makes sense (making it unconditional potentially avoids issues in an unlikely corner case), so I changed it to unconditional. See: #174 (comment)

I've added a comment to explain why it is unconditional.

@agners
Copy link
Contributor

agners commented Sep 29, 2025

@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.

@github-actions
Copy link

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.

@github-actions github-actions bot added the stale There has not been activity on this issue or PR for quite some time. label Oct 30, 2025
@PaulSD
Copy link
Contributor Author

PaulSD commented Nov 1, 2025

@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.

@github-actions github-actions bot removed the stale There has not been activity on this issue or PR for quite some time. label Nov 2, 2025
@PaulSD
Copy link
Contributor Author

PaulSD commented Nov 5, 2025

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.

@lmagyar
Copy link
Contributor

lmagyar commented Nov 5, 2025

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.

@lmagyar
Copy link
Contributor

lmagyar commented Nov 6, 2025

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.

@agners
Copy link
Contributor

agners commented Nov 6, 2025

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.

@lmagyar
Copy link
Contributor

lmagyar commented Nov 8, 2025

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

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

4 participants