Re: [PATCH v2 2/2] util/log: Always send errors to logfile when daemonized

[Greg Kurz <groug@kaod.org>]

On Thu, 20 Oct 2022 12:21:27 +1000
Richard Henderson <richard.henderson@linaro.org> wrote:

> On 10/20/22 01:16, Greg Kurz wrote:
> > When QEMU is started with `-daemonize`, all stdio descriptors get
> > redirected to `/dev/null`. This basically means that anything
> > printed with error_report() and friends is lost.
> > 
> > One could hope that passing `-D ${logfile}` would cause the messages
> > to go to `${logfile}`, as the documentation tends to suggest:
> > 
> >        -D logfile
> >                Output log in logfile instead of to stderr
> > 
> > Unfortunately, `-D` belongs to the logging framework and it only
> > does this redirection if some log item is also enabled with `-d`
> > or if QEMU was configured with `--enable-trace-backend=log`. A
> > typical production setup doesn't do tracing or fine-grain
> > debugging but it certainly needs to collect errors.
> > 
> > Ignore the check on enabled log items when QEMU is daemonized. Previous
> > behaviour is retained for the non-daemonized case. The logic is unrolled
> > as an `if` for better readability. Since qemu_set_log_internal() caches
> > the final log level and the per-thread property in global variables, it
> > seems more correct to check these instead of intermediary local variables.
> > 
> > Special care is needed for the `-D ${logfile} -d tid` case : `${logfile}`
> > is expected to be a template that contains exactly one `%d` that should be
> > expanded to a PID or TID. The logic in qemu_log_trylock() already takes
> > care of that for per-thread logs. Do it as well for the QEMU main thread
> > when opening the file.
> 
> I don't understand why daemonize changes -d tid at all.
> If there's a bug there, please separate it out.
> 
> I don't understand the is_main_log_thread checks.
> Why is the main thread special?
> 

The current code base either opens a per-thread file in
qemu_log_trylock() when -d tid is enabled, or only a
single global file in qemu_log_set_internal() in the
opposite case.

The goal of this patch is to go through the `In case we
are a daemon redirect stderr to logfile` logic, so that
other users of stderr, aka. error_report(), can benefit
from it as well. Since this is only done for the global
file, the logic was changed to : _main_ thread to always
use the global file and other threads to use the per-thread
file.

I now realize how terrible a choice this is. It violates
the current logic too much and brings new problems like
"how to identify the main thread"...

> > -    /*
> > -     * In all cases we only log if qemu_loglevel is set.
> > -     * Also:
> > -     *   If per-thread, open the file for each thread in qemu_log_lock.
> > -     *   If not daemonized we will always log either to stderr
> > -     *     or to a file (if there is a filename).
> > -     *   If we are daemonized, we will only log if there is a filename.
> > -     */
> >       daemonized = is_daemonized();
> > -    need_to_open_file = log_flags && !per_thread && (!daemonized || filename);
> > +    need_to_open_file = false;
> > +    if (!daemonized) {
> > +        /*
> > +         * If not daemonized we only log if qemu_loglevel is set, either to
> > +         * stderr or to a file (if there is a filename).
> > +         * If per-thread, open the file for each thread in qemu_log_trylock().
> > +         */
> > +        need_to_open_file = qemu_loglevel && !log_per_thread;
> > +    } else {
> > +        /*
> > +         * If we are daemonized, we will only log if there is a filename.
> > +         */
> > +        need_to_open_file = filename != NULL;
> > +    }
> 
> I would have thought that this was the only change required -- ignoring qemu_loglevel when 
> daemonized.
> 

I was thinking the same at first, but this ended up in the
global file being open with a filename containing a '%d'...
I chose the direction of doing the g_strdup_printf() trick
for the global file as well but then I had to make sure
that qemu_log_trylock() wouldn't try later to open the same
file, hence the _main_ thread check...

The question is actually : where stderr should point to in
the '-daemonize -D foo%d.log -d tid` case ?

> 

> r~