When tracebacks are sent to a log file or stderr using the default
configurations, it can be difficult to work with those logs. Using
"grep" to search for messages or time periods will typically only
produce a single line of the error.
Further, on a busy system the error may be interleaved with other
log lines making extraction even harder.
To address both of these issues, add a formatter which formats every
line of a multi-line log message using the same format specifier.
This is quite readable when streaming or viewing a standard log file,
and it should cause all log lines to automatically appear in
ELK/splunk setups since they will all have the same message format.
(Though, those setups are probably better served with a native
logging configuration that sends the entire record together.)
It may be somewhat difficult if a multi-line log entry is recorded
on a busy system with multiple threads. However, some judicious
grepping should help with that since all related lineswill have the
exact same timestamp (including microseconds). Advanced users/devs
could specify a logging format with the thread id if necessary, though
I don't think we should do that by default.
Since this is implemented as a standard logging formatter, it can
be opted-out via logging config files. This enables it by default,
which I think is reasonable for new users, but if we decide that we
would prefer opt-in, that is a simple change.
Sample output (from Zuul):
2021-01-29 10:59:02,004 DEBUG zuul.Scheduler: Run handler awake
2021-01-29 10:59:02,004 ERROR zuul.Scheduler: Exception in run handler:
2021-01-29 10:59:02,004 ERROR zuul.Scheduler: Traceback (most recent call last):
2021-01-29 10:59:02,004 ERROR zuul.Scheduler: File "/home/corvus/git/zuul/zuul/zuul/scheduler.py", line 1254, in run
2021-01-29 10:59:02,004 ERROR zuul.Scheduler: raise Exception("Test")
2021-01-29 10:59:02,004 ERROR zuul.Scheduler: Exception: Test
2021-01-29 10:59:02,005 DEBUG zuul.Scheduler: Run handler sleeping
Change-Id: I6d7e7e7a9e19d46a744f9ffac8d532fc6b4bba01
In the default logging config, create a NullHandler logging handler
and connect the root logger to that.
Starting in python 3.2[1], a logging handler of last resort will output
exceptions to stderr if no handlers are configured. Currently, our
default logging configuration has no handlers configured for the
root logger, and therefore libraries which log errors or exceptions
on loggers that do not appear in our configuration will use the logger
of last resort.
This is the case for paramiko. During our key scanning, we now expect
paramiko to raise some exceptions about some host keys being invalid.
We have an exception handler to avoid logging the exception when it is
raised to us, however, paramiko also logs the exception under its own
namespace before raising it. In order to suppress the output of these
exceptions, we need to ensure that paramiko logs have a handler. The
easiest way to do that for paramiko and other libraries is by routing
the root logger to null, which was our original intent.
[1] https://docs.python.org/3/howto/logging.html#what-happens-if-no-configuration-is-provided
Change-Id: Iaa57ed0f0452eefd376a68ac21f49f3141cdaa25
Logging adapters were already in use for the NodeLauncher. In order to
expand logging of Zuul's event id to nodepool, we will first centralize
the existing adapters and refactor them simliar to how this is already
done in Zuul.
This will allow us to correlate node request with other log messages
from Zuul via the event id to allow for faster and easier debugging.
Change-Id: Idc7468239a055c75074e876ea8c445b49c791131
os-client-config is now just a wrapper around openstacksdk. The shade
code has been imported into openstacksdk. To reduce complexity, just use
openstacksdk directly.
openstacksdk's TaskManager has had to grow some features to deal with
SwiftService. Making nodepool's TaskManager a subclass of openstacksdk's
TaskManager ensures that we get the thread pool set up properly.
Change-Id: I3a01eb18ae31cc3b61509984f3817378db832b47
Add a default logging configuration based on what was recently
added to Zuul. This will use sane defaults for system logging,
though it does not yet address image build logging.
Change-Id: Ie86fc6d6839e2eb199c27515346b57b2ebede703