DEBUG messages show when only INFO was asked for
| Affects | Status | Importance | Assigned to | Milestone | |
|---|---|---|---|---|---|
| | juju-core |
High
|
Tim Penhey | ||
Bug Description
As seen here:
http://
We issue "juju --show-log bootstrap -e azure-upgrade-
This is a security issue because DEBUG messages often contain credentials. It is a regression because we used to only get INFO messages, and our credentials used to be safe.
| Changed in juju-core: | |
| milestone: | none → 1.23 |
| Dimiter Naydenov (dimitern) wrote : | #2 |
As for the security side of things - absolutely! We shouldn't be logging sensitive info like keys or credentials even at DEBUG level. We might need a dedicated feature flag like "full on debug" though, in case developers want to see all.
| Aaron Bentley (abentley) wrote : | #3 |
Normally, we don't see DEBUG messages when we do --show-log
Here are some examples from http://
http://
http://
http://
http://
http://
http://
http://
http://
http://
Note: this isn't just bootstrap, this is a whole lifecycle from bootstrap to destroy-
So this appears to be a change in behaviour. It may be that the POLICY is old, but no DEBUG messages were actually emitted until recently.
If it is not, it is at least surprising behaviour. If the messages are valuable for more than debugging, then they should be logged at the INFO level. If the info is only useful for debugging, then it should not be shown by default.
| Dimiter Naydenov (dimitern) wrote : | #4 |
Is this azure-specific or other substrates seem affected as well?
| Aaron Bentley (abentley) wrote : | #5 |
Other substrates are affected:
http://
http://
http://
http://
| Dimiter Naydenov (dimitern) wrote : | #6 |
http://
Ign http://
Ign http://
Ign http://
Ign http://
Hit http://
Hit http://
Hit http://
Hit http://
Hit http://
...
are coming from juju (even with --debug we don't print these directly on stderr but with log prefixes). Maybe ppc64 lxc/kvm tests are poorly isolated from the host? I've seen the recent commits in ~juju-qa repos, some of these look like possible causes (e.g. added --debug to all tests jobs, adding/removing set +x in some bash scripts, implementing async bootstrap - i.e. if something else is dumping to stderr while bootstrap does not).
In any case - going through all recent jobs in the past 2 weeks or so (way before version-2328 quoted as the first time this started happening) I can see a mixture of DEBUG logs being present or not in different job types, and combined with a detailed analysis of recent commits across all the main branches of juju/juju and anything related to logging, I'd say this is not a juju issue but a CI setup one.
| Tim Penhey (thumper) wrote : | #7 |
I'm confused, because I checked the 1.20 source tree, and found this:
c.AddScripts(
// The bootstrapping is always run with debug on.
cfg.jujuTools() + "/jujud bootstrap-state" +
" --data-dir " + shquote(
" --env-config " + shquote(
" --instance-id " + shquote(
hardware +
cons +
" --debug",
)
Which clearly shows that bootstrap-state is called with --debug.
| Aaron Bentley (abentley) wrote : | #8 |
Tim, you're probably right about the internal state. But I am reporting this bug from a user perspective. DEBUG appears in unit test runs, but it doesn't appear in any other logs for:
http://
http://
Those are the only builds of 1.20.x that we still have console logs for. Can you give us a counterexample where DEBUG messages were emitted in the 1.20 series?
| Changed in juju-core: | |
| status: | Incomplete → Triaged |
| Tim Penhey (thumper) wrote : | #9 |
Aaron, I'm guessing it is environmental.
The JUJU_LOGGING_CONFIG environment variable is the default if '--logging-config' is not specified.
Can you please try adding "--logging-
| Changed in juju-core: | |
| status: | Triaged → Incomplete |
| Aaron Bentley (abentley) wrote : | #10 |
We do not set JUJU_LOGGING_
| Changed in juju-core: | |
| status: | Incomplete → Triaged |
| Changed in juju-core: | |
| importance: | Critical → High |
| assignee: | nobody → Tim Penhey (thumper) |
| status: | Triaged → In Progress |
| tags: | removed: regression |
| Changed in juju-core: | |
| status: | In Progress → Fix Committed |
| Changed in juju-core: | |
| milestone: | 1.23 → 1.23-beta1 |
| Changed in juju-core: | |
| status: | Fix Committed → Fix Released |
No I disagree. This has been the behaviour since it was implemented.
All agents, machine and unit are started with logging set to the debug level. This is until the logging worker starts and gets told what the logging level should be.
This was a design decision at the time and most certainly isn't a regression.
Can you please show old and new logs? This behaviour hasn't changed, so I'm curious as to what has changed.