From mboxrd@z Thu Jan 1 00:00:00 1970 Received: from eggs.gnu.org ([2001:4830:134:3::10]:47924) by lists.gnu.org with esmtp (Exim 4.71) (envelope-from ) id 1Zn67e-0006ZZ-EW for qemu-devel@nongnu.org; Fri, 16 Oct 2015 10:36:48 -0400 Received: from Debian-exim by eggs.gnu.org with spam-scanned (Exim 4.71) (envelope-from ) id 1Zn67a-0002xy-8J for qemu-devel@nongnu.org; Fri, 16 Oct 2015 10:36:42 -0400 Received: from mail-wi0-f170.google.com ([209.85.212.170]:33524) by eggs.gnu.org with esmtp (Exim 4.71) (envelope-from ) id 1Zn67Z-0002xn-W6 for qemu-devel@nongnu.org; Fri, 16 Oct 2015 10:36:38 -0400 Received: by wijp11 with SMTP id p11so13596708wij.0 for ; Fri, 16 Oct 2015 07:36:37 -0700 (PDT) References: <1444894224-9542-1-git-send-email-den@openvz.org> <1444894224-9542-3-git-send-email-den@openvz.org> <87oafzdmck.fsf_-_@blackfin.pond.sub.org> From: Alex =?utf-8?Q?Benn=C3=A9e?= In-reply-to: <87oafzdmck.fsf_-_@blackfin.pond.sub.org> Date: Fri, 16 Oct 2015 15:36:35 +0100 Message-ID: <87wpum6ft8.fsf@linaro.org> MIME-Version: 1.0 Content-Type: text/plain; charset=utf-8 Content-Transfer-Encoding: 8bit Subject: Re: [Qemu-devel] What's the intended use of log.h logging? (was: [PATCH 2/3] log: report hmp/qmp command and qmp event) List-Id: List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , To: Markus Armbruster Cc: Peter Maydell , Pavel Butsykin , qemu-devel@nongnu.org, Luiz Capitulino , Stefan Hajnoczi , "Denis V. Lunev" Markus Armbruster writes: > We have a couple of related features, and I'd like to get some clarity > on how exactly they should be used. FWIW this is how I view them. > > 1. Tracing > > Documented in docs/tracing.txt. > > Each trace event can be individually controlled with -trace and with > monitor command trace-event. Wildcards work. Monitor command "info > trace-event" shows their status. > > Supports a wealth of tracing backends: nop (compiles out tracing > completely), stderr (prints trace to stderr), "simple", "ftrace", > "dtrace", ... Range from "trivially easy" to "complex power tool". While not enabled by default this is the sort of thing that can be enabled by distros to enable non-invasive tracing of complex behaviour and performance bottle-necks. Ignoring nop/stderr backends the others can be used when your looking as system-wide behaviour and interactions between QEMU, KVM and the kernel. > > 2. Ad hoc printing > > We have 108 files with some #define DPRINTF(), and probably some more > sailing under different flags. The ones that aren't useless should > probably be tracepoints. These are basically debug crutches for individual files that are currently in development or particularly tricky bits of code that the relevant developer would enable when debugging. > > 3. "qemu/log.h" logging > > Sports a "mask", where each bit enables a certain set of log > messages. Control the mask with "-d item,..." Try "-d help" to see > acceptable items. > > Logs to stderr by default, can be redirected with "-D ". > > Odd for a log file: no timestamp, but proposed "[PATCH 3/3] log: adds > a timestamp to each log entry" adds one. > > Log message format is unclear. > > There are no locks beyond the one provided by stdio, and log entries > appear to be build with multiple calls in places. I suspect logging > from more than one thread can mess up the log. As you note bellow most of these are TCG related and currently unlikely to race with each other due to TCG being single threaded (for now ;-) > Currently defined items are: > > const QEMULogItem qemu_log_items[] = { > { CPU_LOG_TB_OUT_ASM, "out_asm", > "show generated host assembly code for each compiled TB" }, > { CPU_LOG_TB_IN_ASM, "in_asm", > "show target assembly code for each compiled TB" }, > { CPU_LOG_TB_OP, "op", > "show micro ops for each compiled TB" }, > { CPU_LOG_TB_OP_OPT, "op_opt", > "show micro ops (x86 only: before eflags optimization) and\n" > "after liveness analysis" }, > { CPU_LOG_INT, "int", > "show interrupts/exceptions in short format" }, > { CPU_LOG_EXEC, "exec", > "show trace before each executed TB (lots of logs)" }, > { CPU_LOG_TB_CPU, "cpu", > "show CPU state before block translation" }, > { CPU_LOG_MMU, "mmu", > "log MMU-related activities" }, > { CPU_LOG_PCALL, "pcall", > "x86 only: show protected mode far calls/returns/exceptions" }, > { CPU_LOG_RESET, "cpu_reset", > "show CPU state before CPU resets" }, > { CPU_LOG_IOPORT, "ioport", > "show all i/o ports accesses" }, > { LOG_UNIMP, "unimp", > "log unimplemented functionality" }, > { LOG_GUEST_ERROR, "guest_errors", > "log when the guest OS does something invalid (eg accessing a\n" > "non-existent register)" }, > { 0, NULL, NULL }, > }; > > Looks like this is basically TCG with a couple of random LOG_UNIMP > and LOG_GUEST_ERROR thrown in. It's definitely not a general purpose > QEMU log in its current state. However it is useful when users find broken TCG stuff and you want a log of what happened. Having said that I'm not sure how often that happens because any non-trivial stuff generates huge logs. It is the logging I use the most though. > Should some of these items be tracepoints instead? IMHO no because stitching together tracepoints with the log file would be a pain. > Do we want a general purpose QEMU log? It depends. If you are talking about a standardised log style thing then maybe but all the current TCG reporting is very specialised and often over multiple lines. To my mind a general purpose log should be fairly quiet and just log extraordinary events (maybe via syslog). The sort of stuff that would be useful for a user to report when tailing a log before something went wrong. > > If yes, should this TCG-ish log become the general purpose QEMU log? > > I'm asking because "[PATCH 2/3] log: report hmp/qmp command and qmp > event" proposes to log QMP traffic here. I understand the need for > logging QMP traffic, but I'm not sure it fits here. Yeah I'm unsure about this as well. To my mind as the QMP is a whole separate API I'd be tempted to log it separately. > 4. Error messages with timestamps > > "-msg timestamp" adds timestamps to the error messages that use the > proper error reporting interfaces. > > I suspect this is basically a poor work-around for not having a log > file. Aren't these meant to be user visible errors? "I died because of X"? -- Alex Bennée