From patchwork Tue Nov 8 14:00:31 2022 Content-Type: text/plain; charset="utf-8" MIME-Version: 1.0 Content-Transfer-Encoding: 8bit X-Patchwork-Submitter: Greg Kurz X-Patchwork-Id: 13036333 Return-Path: X-Spam-Checker-Version: SpamAssassin 3.4.0 (2014-02-07) on aws-us-west-2-korg-lkml-1.web.codeaurora.org Received: from lists.gnu.org (lists.gnu.org [209.51.188.17]) (using TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)) (No client certificate requested) by smtp.lore.kernel.org (Postfix) with ESMTPS id D1733C4332F for ; Tue, 8 Nov 2022 14:01:55 +0000 (UTC) Received: from localhost ([::1] helo=lists1p.gnu.org) by lists.gnu.org with esmtp (Exim 4.90_1) (envelope-from ) id 1osPAC-0006gv-9z; Tue, 08 Nov 2022 09:01:16 -0500 Received: from eggs.gnu.org ([2001:470:142:3::10]) by lists.gnu.org with esmtps (TLS1.2:ECDHE_RSA_AES_256_GCM_SHA384:256) (Exim 4.90_1) (envelope-from ) id 1osP9z-0006aW-Vt for qemu-devel@nongnu.org; Tue, 08 Nov 2022 09:01:06 -0500 Received: from us-smtp-delivery-44.mimecast.com ([205.139.111.44]) by eggs.gnu.org with esmtps (TLS1.2:ECDHE_RSA_AES_256_GCM_SHA384:256) (Exim 4.90_1) (envelope-from ) id 1osP9s-0005vR-AD for qemu-devel@nongnu.org; Tue, 08 Nov 2022 09:01:03 -0500 Received: from mimecast-mx02.redhat.com (mimecast-mx02.redhat.com [66.187.233.88]) by relay.mimecast.com with ESMTP with STARTTLS (version=TLSv1.2, cipher=TLS_ECDHE_RSA_WITH_AES_256_GCM_SHA384) id us-mta-222-iuuI-F7fNY2sVvr4Cow39g-1; Tue, 08 Nov 2022 09:00:43 -0500 X-MC-Unique: iuuI-F7fNY2sVvr4Cow39g-1 Received: from smtp.corp.redhat.com (int-mx08.intmail.prod.int.rdu2.redhat.com [10.11.54.8]) (using TLSv1.2 with cipher AECDH-AES256-SHA (256/256 bits)) (No client certificate requested) by mimecast-mx02.redhat.com (Postfix) with ESMTPS id 33108101A528; Tue, 8 Nov 2022 14:00:43 +0000 (UTC) Received: from bahia.redhat.com (unknown [10.39.192.123]) by smtp.corp.redhat.com (Postfix) with ESMTP id C3286C15BB5; Tue, 8 Nov 2022 14:00:41 +0000 (UTC) From: Greg Kurz To: qemu-devel@nongnu.org Cc: =?utf-8?q?Daniel_P_=2E_Berrang=C3=A9?= , =?utf-8?q?Alex_Benn=C3=A9e?= , Paolo Bonzini , Richard Henderson , Greg Kurz Subject: [PATCH v3 1/2] util/log: do not close and reopen log files when flags are turned off Date: Tue, 8 Nov 2022 15:00:31 +0100 Message-Id: <20221108140032.1460307-2-groug@kaod.org> In-Reply-To: <20221108140032.1460307-1-groug@kaod.org> References: <20221108140032.1460307-1-groug@kaod.org> MIME-Version: 1.0 X-Scanned-By: MIMEDefang 3.1 on 10.11.54.8 Received-SPF: softfail client-ip=205.139.111.44; envelope-from=groug@kaod.org; helo=us-smtp-delivery-44.mimecast.com X-Spam_score_int: -18 X-Spam_score: -1.9 X-Spam_bar: - X-Spam_report: (-1.9 / 5.0 requ) BAYES_00=-1.9, RCVD_IN_DNSWL_LOW=-0.7, SPF_HELO_NONE=0.001, SPF_SOFTFAIL=0.665 autolearn=no autolearn_force=no X-Spam_action: no action X-BeenThere: qemu-devel@nongnu.org X-Mailman-Version: 2.1.29 Precedence: list List-Id: List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , Errors-To: qemu-devel-bounces+qemu-devel=archiver.kernel.org@nongnu.org Sender: qemu-devel-bounces+qemu-devel=archiver.kernel.org@nongnu.org From: Paolo Bonzini log_append makes sure that if you turn off the logging (which clears log_flags and makes need_to_open_file false) the old log is not overwritten. The usecase is that if you remove or move the file QEMU will not keep writing to the old file. However, this is not always the desited behavior, in particular having log_append==1 after changing the file name makes little sense. When qemu_set_log_internal is called from the logfile monitor command, filename must be non-NULL and therefore changed_name must be true. Therefore, the only case where the file is closed and need_to_open_file == false is indeed when log_flags becomes zero. In this case, just flush the file and do not bother closing it, thus faking the same append behavior as previously. The behavioral change is that changing the logfile twice, for example log1 -> log2 -> log1, will cause log1 to be overwritten. This can simply be documented, since it is not a particularly surprising behavior. Suggested-by: Alex Bennée Signed-off-by: Paolo Bonzini Reviewed-by: Richard Henderson Reviewed-by: Greg Kurz Message-Id: <20221025092119.236224-1-pbonzini@redhat.com> [groug: nullify global_file before actually closing the file] Signed-off-by: Greg Kurz --- util/log.c | 14 ++++++-------- 1 file changed, 6 insertions(+), 8 deletions(-) diff --git a/util/log.c b/util/log.c index c2198badf240..fb843453dd49 100644 --- a/util/log.c +++ b/util/log.c @@ -45,7 +45,6 @@ static __thread FILE *thread_file; static __thread Notifier qemu_log_thread_cleanup_notifier; int qemu_loglevel; -static bool log_append; static bool log_per_thread; static GArray *debug_regions; @@ -277,19 +276,20 @@ static bool qemu_set_log_internal(const char *filename, bool changed_name, daemonized = is_daemonized(); need_to_open_file = log_flags && !per_thread && (!daemonized || filename); - if (logfile && (!need_to_open_file || changed_name)) { - qatomic_rcu_set(&global_file, NULL); - if (logfile != stderr) { + if (logfile) { + fflush(logfile); + if (changed_name && logfile != stderr) { RCUCloseFILE *r = g_new0(RCUCloseFILE, 1); r->fd = logfile; + qatomic_rcu_set(&global_file, NULL); call_rcu(r, rcu_close_file, rcu); + logfile = NULL; } - logfile = NULL; } if (!logfile && need_to_open_file) { if (filename) { - logfile = fopen(filename, log_append ? "a" : "w"); + logfile = fopen(filename, "w"); if (!logfile) { error_setg_errno(errp, errno, "Error opening logfile %s", filename); @@ -308,8 +308,6 @@ static bool qemu_set_log_internal(const char *filename, bool changed_name, logfile = stderr; } - log_append = 1; - qatomic_rcu_set(&global_file, logfile); } return true; From patchwork Tue Nov 8 14:00:32 2022 Content-Type: text/plain; charset="utf-8" MIME-Version: 1.0 Content-Transfer-Encoding: 7bit X-Patchwork-Submitter: Greg Kurz X-Patchwork-Id: 13036334 Return-Path: X-Spam-Checker-Version: SpamAssassin 3.4.0 (2014-02-07) on aws-us-west-2-korg-lkml-1.web.codeaurora.org Received: from lists.gnu.org (lists.gnu.org [209.51.188.17]) (using TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)) (No client certificate requested) by smtp.lore.kernel.org (Postfix) with ESMTPS id B2AC9C4332F for ; Tue, 8 Nov 2022 14:02:07 +0000 (UTC) Received: from localhost ([::1] helo=lists1p.gnu.org) by lists.gnu.org with esmtp (Exim 4.90_1) (envelope-from ) id 1osPAD-0006is-QF; Tue, 08 Nov 2022 09:01:17 -0500 Received: from eggs.gnu.org ([2001:470:142:3::10]) by lists.gnu.org with esmtps (TLS1.2:ECDHE_RSA_AES_256_GCM_SHA384:256) (Exim 4.90_1) (envelope-from ) id 1osP9x-0006ZA-EI for qemu-devel@nongnu.org; Tue, 08 Nov 2022 09:01:05 -0500 Received: from us-smtp-delivery-44.mimecast.com ([205.139.111.44]) by eggs.gnu.org with esmtps (TLS1.2:ECDHE_RSA_AES_256_GCM_SHA384:256) (Exim 4.90_1) (envelope-from ) id 1osP9u-0005Rk-5S for qemu-devel@nongnu.org; Tue, 08 Nov 2022 09:01:00 -0500 Received: from mimecast-mx02.redhat.com (mimecast-mx02.redhat.com [66.187.233.88]) by relay.mimecast.com with ESMTP with STARTTLS (version=TLSv1.2, cipher=TLS_ECDHE_RSA_WITH_AES_256_GCM_SHA384) id us-mta-346-8SA2lIVQML2qMxQiNpheQg-1; Tue, 08 Nov 2022 09:00:45 -0500 X-MC-Unique: 8SA2lIVQML2qMxQiNpheQg-1 Received: from smtp.corp.redhat.com (int-mx08.intmail.prod.int.rdu2.redhat.com [10.11.54.8]) (using TLSv1.2 with cipher AECDH-AES256-SHA (256/256 bits)) (No client certificate requested) by mimecast-mx02.redhat.com (Postfix) with ESMTPS id CE0EE811E81; Tue, 8 Nov 2022 14:00:44 +0000 (UTC) Received: from bahia.redhat.com (unknown [10.39.192.123]) by smtp.corp.redhat.com (Postfix) with ESMTP id 831CAC15BB5; Tue, 8 Nov 2022 14:00:43 +0000 (UTC) From: Greg Kurz To: qemu-devel@nongnu.org Cc: =?utf-8?q?Daniel_P_=2E_Berrang=C3=A9?= , =?utf-8?q?Alex_Benn=C3=A9e?= , Paolo Bonzini , Richard Henderson , Greg Kurz Subject: [PATCH v3 2/2] util/log: Always send errors to logfile when daemonized Date: Tue, 8 Nov 2022 15:00:32 +0100 Message-Id: <20221108140032.1460307-3-groug@kaod.org> In-Reply-To: <20221108140032.1460307-1-groug@kaod.org> References: <20221108140032.1460307-1-groug@kaod.org> MIME-Version: 1.0 X-Scanned-By: MIMEDefang 3.1 on 10.11.54.8 Received-SPF: softfail client-ip=205.139.111.44; envelope-from=groug@kaod.org; helo=us-smtp-delivery-44.mimecast.com X-Spam_score_int: -18 X-Spam_score: -1.9 X-Spam_bar: - X-Spam_report: (-1.9 / 5.0 requ) BAYES_00=-1.9, RCVD_IN_DNSWL_LOW=-0.7, SPF_HELO_NONE=0.001, SPF_SOFTFAIL=0.665 autolearn=no autolearn_force=no X-Spam_action: no action X-BeenThere: qemu-devel@nongnu.org X-Mailman-Version: 2.1.29 Precedence: list List-Id: List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , Errors-To: qemu-devel-bounces+qemu-devel=archiver.kernel.org@nongnu.org Sender: qemu-devel-bounces+qemu-devel=archiver.kernel.org@nongnu.org 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. Current logging code allows to redirect to a file with `-D` but this requires to enable some logging item with `-d` as well to be functional. Relax the check on the log flags when QEMU is daemonized, so that other users of stderr can benefit from the redirection, without the need to enable unwanted debug logs. Previous behaviour is retained for the non-daemonized case. The logic is unrolled as an `if` for better readability. The qemu_log_level and log_per_thread globals reflect the state we want to transition to at this point : use them instead of the intermediary locals for correctness. qemu_set_log_internal() is adapted to open a per-thread log file when '-d tid' is passed. This is done by hijacking qemu_try_lock() which seems simpler that refactoring the code. Signed-off-by: Greg Kurz Reviewed-by: Richard Henderson --- util/log.c | 72 ++++++++++++++++++++++++++++++++++++++++-------------- 1 file changed, 53 insertions(+), 19 deletions(-) diff --git a/util/log.c b/util/log.c index fb843453dd49..7837ff991769 100644 --- a/util/log.c +++ b/util/log.c @@ -79,13 +79,15 @@ static int log_thread_id(void) static void qemu_log_thread_cleanup(Notifier *n, void *unused) { - fclose(thread_file); - thread_file = NULL; + if (thread_file != stderr) { + fclose(thread_file); + thread_file = NULL; + } } /* Lock/unlock output. */ -FILE *qemu_log_trylock(void) +static FILE *qemu_log_trylock_with_err(Error **errp) { FILE *logfile; @@ -96,6 +98,9 @@ FILE *qemu_log_trylock(void) = g_strdup_printf(global_filename, log_thread_id()); logfile = fopen(filename, "w"); if (!logfile) { + error_setg_errno(errp, errno, + "Error opening logfile %s for thread %d", + filename, log_thread_id()); return NULL; } thread_file = logfile; @@ -122,6 +127,11 @@ FILE *qemu_log_trylock(void) return logfile; } +FILE *qemu_log_trylock(void) +{ + return qemu_log_trylock_with_err(NULL); +} + void qemu_log_unlock(FILE *logfile) { if (logfile) { @@ -265,16 +275,21 @@ static bool qemu_set_log_internal(const char *filename, bool changed_name, #endif qemu_loglevel = log_flags; - /* - * 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; + } if (logfile) { fflush(logfile); @@ -287,19 +302,34 @@ static bool qemu_set_log_internal(const char *filename, bool changed_name, } } + if (log_per_thread && daemonized) { + logfile = thread_file; + } + if (!logfile && need_to_open_file) { if (filename) { - logfile = fopen(filename, "w"); - if (!logfile) { - error_setg_errno(errp, errno, "Error opening logfile %s", - filename); - return false; + if (log_per_thread) { + logfile = qemu_log_trylock_with_err(errp); + if (!logfile) { + return false; + } + qemu_log_unlock(logfile); + } else { + logfile = fopen(filename, "w"); + if (!logfile) { + error_setg_errno(errp, errno, "Error opening logfile %s", + filename); + return false; + } } /* In case we are a daemon redirect stderr to logfile */ if (daemonized) { dup2(fileno(logfile), STDERR_FILENO); fclose(logfile); - /* This will skip closing logfile in rcu_close_file. */ + /* + * This will skip closing logfile in rcu_close_file() + * or qemu_log_thread_cleanup(). + */ logfile = stderr; } } else { @@ -308,7 +338,11 @@ static bool qemu_set_log_internal(const char *filename, bool changed_name, logfile = stderr; } - qatomic_rcu_set(&global_file, logfile); + if (log_per_thread && daemonized) { + thread_file = logfile; + } else { + qatomic_rcu_set(&global_file, logfile); + } } return true; }