From patchwork Thu Jan 28 04:18:23 2016 Content-Type: text/plain; charset="utf-8" MIME-Version: 1.0 Content-Transfer-Encoding: 7bit X-Patchwork-Submitter: Sam Bobroff X-Patchwork-Id: 8146071 Return-Path: X-Original-To: patchwork-qemu-devel@patchwork.kernel.org Delivered-To: patchwork-parsemail@patchwork1.web.kernel.org Received: from mail.kernel.org (mail.kernel.org [198.145.29.136]) by patchwork1.web.kernel.org (Postfix) with ESMTP id 999199F818 for ; Thu, 28 Jan 2016 04:20:01 +0000 (UTC) Received: from mail.kernel.org (localhost [127.0.0.1]) by mail.kernel.org (Postfix) with ESMTP id 999AA2010B for ; Thu, 28 Jan 2016 04:20:00 +0000 (UTC) Received: from lists.gnu.org (lists.gnu.org [208.118.235.17]) (using TLSv1 with cipher AES256-SHA (256/256 bits)) (No client certificate requested) by mail.kernel.org (Postfix) with ESMTPS id 4C255200DB for ; Thu, 28 Jan 2016 04:19:59 +0000 (UTC) Received: from localhost ([::1]:53913 helo=lists.gnu.org) by lists.gnu.org with esmtp (Exim 4.71) (envelope-from ) id 1aOe3q-0000mW-MZ for patchwork-qemu-devel@patchwork.kernel.org; Wed, 27 Jan 2016 23:19:58 -0500 Received: from eggs.gnu.org ([2001:4830:134:3::10]:53157) by lists.gnu.org with esmtp (Exim 4.71) (envelope-from ) id 1aOe3g-0000iD-2j for qemu-devel@nongnu.org; Wed, 27 Jan 2016 23:19:49 -0500 Received: from Debian-exim by eggs.gnu.org with spam-scanned (Exim 4.71) (envelope-from ) id 1aOe3c-0004JR-PR for qemu-devel@nongnu.org; Wed, 27 Jan 2016 23:19:48 -0500 Received: from e23smtp01.au.ibm.com ([202.81.31.143]:56413) by eggs.gnu.org with esmtp (Exim 4.71) (envelope-from ) id 1aOe3c-0004IZ-7J for qemu-devel@nongnu.org; Wed, 27 Jan 2016 23:19:44 -0500 Received: from localhost by e23smtp01.au.ibm.com with IBM ESMTP SMTP Gateway: Authorized Use Only! Violators will be prosecuted for from ; Thu, 28 Jan 2016 14:19:40 +1000 Received: from d23dlp03.au.ibm.com (202.81.31.214) by e23smtp01.au.ibm.com (202.81.31.207) with IBM ESMTP SMTP Gateway: Authorized Use Only! Violators will be prosecuted; Thu, 28 Jan 2016 14:19:37 +1000 X-IBM-Helo: d23dlp03.au.ibm.com X-IBM-MailFrom: sam.bobroff@au1.ibm.com X-IBM-RcptTo: qemu-devel@nongnu.org Received: from d23relay06.au.ibm.com (d23relay06.au.ibm.com [9.185.63.219]) by d23dlp03.au.ibm.com (Postfix) with ESMTP id F3D2D3578055 for ; Thu, 28 Jan 2016 15:19:36 +1100 (EST) Received: from d23av01.au.ibm.com (d23av01.au.ibm.com [9.190.234.96]) by d23relay06.au.ibm.com (8.14.9/8.14.9/NCO v10.0) with ESMTP id u0S4JICA46530756 for ; Thu, 28 Jan 2016 15:19:26 +1100 Received: from d23av01.au.ibm.com (localhost [127.0.0.1]) by d23av01.au.ibm.com (8.14.4/8.14.4/NCO v10.0 AVout) with ESMTP id u0S4J4rL023030 for ; Thu, 28 Jan 2016 15:19:04 +1100 Received: from ozlabs.au.ibm.com (ozlabs.au.ibm.com [9.192.253.14]) by d23av01.au.ibm.com (8.14.4/8.14.4/NCO v10.0 AVin) with ESMTP id u0S4J4lX022431; Thu, 28 Jan 2016 15:19:04 +1100 Received: from tungsten.ozlabs.ibm.com (haven.au.ibm.com [9.192.254.114]) (using TLSv1.2 with cipher AES128-SHA256 (128/128 bits)) (No client certificate requested) by ozlabs.au.ibm.com (Postfix) with ESMTPSA id 12A51A0130; Thu, 28 Jan 2016 15:18:40 +1100 (AEDT) From: Sam Bobroff To: qemu-devel@nongnu.org Date: Thu, 28 Jan 2016 15:18:23 +1100 Message-Id: <0b88a3432f2fcfee1e57abfa9420ca6c5c386b49.1453954698.git.sam.bobroff@au1.ibm.com> X-Mailer: git-send-email 2.1.4 X-TM-AS-MML: disable X-Content-Scanned: Fidelis XPS MAILER x-cbid: 16012804-1618-0000-0000-0000039589C0 X-detected-operating-system: by eggs.gnu.org: GNU/Linux 3.x X-Received-From: 202.81.31.143 Cc: stefanha@gmail.com Subject: [Qemu-devel] [PATCH 1/1] Protect stderr from non-blocking mode X-BeenThere: qemu-devel@nongnu.org X-Mailman-Version: 2.1.14 Precedence: list List-Id: List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , Errors-To: qemu-devel-bounces+patchwork-qemu-devel=patchwork.kernel.org@nongnu.org Sender: qemu-devel-bounces+patchwork-qemu-devel=patchwork.kernel.org@nongnu.org X-Spam-Status: No, score=-6.9 required=5.0 tests=BAYES_00, RCVD_IN_DNSWL_HI, UNPARSEABLE_RELAY autolearn=unavailable version=3.3.1 X-Spam-Checker-Version: SpamAssassin 3.3.1 (2010-03-16) on mail.kernel.org X-Virus-Scanned: ClamAV using ClamSMTP On Linux, if QEMU is run from a shell with -d to enable debug logging but without directing it to a file (e.g. -D is not used, and qemu_logfile is set to stderr), and no shell redirection is used, it is possible for log messages to be lost under load. This is caused by a combination of several factors: * The shell (e.g. bash) may provide stdin, stdout and stderr as duplicates of a single open file, so they share file status flags including O_NONBLOCK. * As character devices are registered (see qemu_chr_open_stdio()), stdin and stdout are set non-blocking. * The printf() family of functions, including fprintf(), are not "non-blocking" aware: if they receive EAGAIN after partially writing their output, they immediately return EAGAIN with no way to discover how much output was written, if any. So O_NONBLOCK is set on stdin/stdout, which causes O_NONBLOCK to be set on stderr, and qemu_logfile is set to stderr. Then, under load, fprintf()s to qemu_logfile return EAGAIN, which is ignored and data is lost. This can't be fixed by handling EAGAIN because an unknown amount of data has been written. This patch works around the issue by re-opening the underlying tty file, which is available in Linux as /proc/self/fd/2, and duplicating it into fd 2 which causes stderr to refer to a new, unshared, "file description". Additionally, if we end up logging to a non-blocking file descriptor on a non-Linux platform, where no workaround has been implemented, we display a warning message. Signed-off-by: Sam Bobroff Reviewed-by: Stefan Hajnoczi --- This is somewhat of an RFC as the issue probably hasn't been noticed very often (ever?) and there are several approaches to addressing it. The discussion was a while ago, here: http://lists.nongnu.org/archive/html/qemu-devel/2015-12/msg00761.html include/sysemu/os-posix.h | 2 +- include/sysemu/os-win32.h | 2 +- os-posix.c | 30 +++++++++++++++++++++++++++++- os-win32.c | 2 +- vl.c | 2 +- 5 files changed, 33 insertions(+), 5 deletions(-) diff --git a/include/sysemu/os-posix.h b/include/sysemu/os-posix.h index f131521..7c7a36b 100644 --- a/include/sysemu/os-posix.h +++ b/include/sysemu/os-posix.h @@ -28,7 +28,7 @@ #include -void os_set_line_buffering(void); +void os_setup_stdio(void); void os_set_proc_name(const char *s); void os_setup_signal_handling(void); void os_daemonize(void); diff --git a/include/sysemu/os-win32.h b/include/sysemu/os-win32.h index 400e098..b55c5d4 100644 --- a/include/sysemu/os-win32.h +++ b/include/sysemu/os-win32.h @@ -84,7 +84,7 @@ struct tm *localtime_r(const time_t *timep, struct tm *result); static inline void os_setup_signal_handling(void) {} static inline void os_daemonize(void) {} static inline void os_setup_post(void) {} -void os_set_line_buffering(void); +void os_setup_stdio(void); static inline void os_set_proc_name(const char *dummy) {} int getpagesize(void); diff --git a/os-posix.c b/os-posix.c index e4da406..d9afa6d 100644 --- a/os-posix.c +++ b/os-posix.c @@ -40,6 +40,7 @@ #include "net/slirp.h" #include "qemu-options.h" #include "qemu/rcu.h" +#include "qemu/log.h" #ifdef CONFIG_LINUX #include @@ -256,6 +257,17 @@ void os_setup_post(void) { int fd = 0; + if (qemu_logfile == stderr) { + if (fcntl(2, F_GETFL) & O_NONBLOCK) { + /* See os_setup_stdio() for an explanation. */ + fprintf(stderr, +"Note: stderr has been set non-blocking which can cause log messages to be\n" +"lost under load. This can be avoided by directing log messages to a file\n" +"(using -D) or by redirecting stderr using your shell.\n" + ); + } + } + if (daemonize) { if (chdir("/")) { perror("not able to chdir to /"); @@ -289,8 +301,24 @@ void os_setup_post(void) } } -void os_set_line_buffering(void) +void os_setup_stdio(void) { +#if defined(__linux__) +/* In some situations (e.g. running QEMU from a bash command line and not using + * any redirection) the shell may have set up stdin, stdout and stderr as + * duplicates of a single open file (i.e. they share a "file description"). If + * this is the case then later when char drivers are registered and stdin and + * stdout are set non-blocking, stderr will also become non-blocking. Because + * printf (and variants) are not "non-blocking aware" this can cause debugging + * information to be lost (typically when using "-d" without "-D" and producing + * a lot of debug output). To avoid this, we re-open stderr to create a + * separate "file description" with it's own file status flags. */ + int fd = open("/proc/self/fd/2", O_WRONLY); + if (fd != -1) { + dup2(fd, 2); + close(fd); + } +#endif setvbuf(stdout, NULL, _IOLBF, 0); } diff --git a/os-win32.c b/os-win32.c index cc09196..2fcbc72 100644 --- a/os-win32.c +++ b/os-win32.c @@ -88,7 +88,7 @@ char *os_find_datadir(void) return qemu_get_exec_dir(); } -void os_set_line_buffering(void) +void os_setup_stdio(void) { setbuf(stdout, NULL); setbuf(stderr, NULL); diff --git a/vl.c b/vl.c index f043009..04a6893 100644 --- a/vl.c +++ b/vl.c @@ -4379,7 +4379,7 @@ int main(int argc, char **argv, char **envp) semihosting_arg_fallback(kernel_filename, kernel_cmdline); } - os_set_line_buffering(); + os_setup_stdio(); #ifdef CONFIG_SPICE /* spice needs the timers to be initialized by this point */