| Message ID | 1360609282-22051-3-git-send-email-afaerber@suse.de |
|---|---|
| State | New |
| Headers | show |
CC'ing some more people from the "debug output revamp" RFC discussion. Am 11.02.2013 20:01, schrieb Andreas Färber: > From: Andreas Färber <andreas.faerber@web.de> > > Signed-off-by: Andreas Färber <andreas.faerber@web.de> > --- > hw/tmp105.c | 27 +++++++++++++++++++++++++-- > 1 Datei geändert, 25 Zeilen hinzugefügt(+), 2 Zeilen entfernt(-) > > diff --git a/hw/tmp105.c b/hw/tmp105.c > index 3ad2d2f..5dafa37 100644 > --- a/hw/tmp105.c > +++ b/hw/tmp105.c > @@ -23,6 +23,18 @@ > #include "tmp105.h" > #include "qapi/visitor.h" > > +#undef DEBUG_TMP105 > + > +static inline void GCC_FMT_ATTR(1, 2) DPRINTF(const char *fmt, ...) Being an inline function, I think it would be better to name this tmp105_dprintf() and alias via: #define DPRINTF tmp105_dprintf Assuming we want an uppercase conditional-output statement in the first place? dprintf() as used in some files (sheepdog, sPAPR, SPICE, target-{i386,ppc,s390x}/kvm.c) is already used by system headers on some platforms, so I'd rather avoid it. Any other comments or suggestions? I'm preparing to respin the above series in a similar, less-invasive style. Thanks, Andreas > +{ > +#ifdef DEBUG_TMP105 > + va_list ap; > + va_start(ap, fmt); > + vfprintf(stderr, fmt, ap); > + va_end(ap); > +#endif > +} > + > static void tmp105_interrupt_update(TMP105State *s) > { > qemu_set_irq(s->pin, s->alarm ^ ((~s->config >> 2) & 1)); /* POL */ > @@ -115,10 +127,16 @@ static void tmp105_read(TMP105State *s) > s->buf[s->len ++] = ((uint16_t) s->limit[1]) >> 0; > break; > } > + > + DPRINTF("%s: %02" PRIx8 " %02" PRIx8 "%02" PRIx8 "\n", > + __func__, s->pointer, s->buf[0], s->buf[1]); > } > > static void tmp105_write(TMP105State *s) > { > + DPRINTF("%s: %02" PRIx8 " %02" PRIx8 "%02" PRIx8 "\n", > + __func__, s->pointer, s->buf[0], s->buf[1]); > + > switch (s->pointer & 3) { > case TMP105_REG_TEMPERATURE: > break; > @@ -144,18 +162,23 @@ static void tmp105_write(TMP105State *s) > static int tmp105_rx(I2CSlave *i2c) > { > TMP105State *s = TMP105(i2c); > + int ret; > > if (s->len < 2) { > - return s->buf[s->len ++]; > + ret = s->buf[s->len++]; > } else { > - return 0xff; > + ret = 0xff; > } > + DPRINTF("%s: <- %02x\n", __func__, ret); > + return ret; > } > > static int tmp105_tx(I2CSlave *i2c, uint8_t data) > { > TMP105State *s = TMP105(i2c); > > + DPRINTF("%s: -> %02" PRIx8 "\n", __func__, data); > + > if (s->len == 0) { > s->pointer = data; > s->len++;
On Thu, Feb 14, 2013 at 04:40:29PM +0100, Andreas Färber wrote: > CC'ing some more people from the "debug output revamp" RFC discussion. > > Am 11.02.2013 20:01, schrieb Andreas Färber: > > From: Andreas Färber <andreas.faerber@web.de> > > > > Signed-off-by: Andreas Färber <andreas.faerber@web.de> > > --- > > hw/tmp105.c | 27 +++++++++++++++++++++++++-- > > 1 Datei geändert, 25 Zeilen hinzugefügt(+), 2 Zeilen entfernt(-) > > > > diff --git a/hw/tmp105.c b/hw/tmp105.c > > index 3ad2d2f..5dafa37 100644 > > --- a/hw/tmp105.c > > +++ b/hw/tmp105.c > > @@ -23,6 +23,18 @@ > > #include "tmp105.h" > > #include "qapi/visitor.h" > > > > +#undef DEBUG_TMP105 > > + > > +static inline void GCC_FMT_ATTR(1, 2) DPRINTF(const char *fmt, ...) > > Being an inline function, I think it would be better to name this > tmp105_dprintf() and alias via: #define DPRINTF tmp105_dprintf > Assuming we want an uppercase conditional-output statement in the first > place? > > dprintf() as used in some files (sheepdog, sPAPR, SPICE, > target-{i386,ppc,s390x}/kvm.c) is already used by system headers on some > platforms, so I'd rather avoid it. > > Any other comments or suggestions? I'm preparing to respin the above > series in a similar, less-invasive style. Here is a radical departure from the zoo of DPRINTF() approaches that QEMU has today. I know not everyone is comfortable using tracing, even though you can use --enable-trace-backend=stderr to get good old stderr output. In iPXE they use a clever compile-time debug macro: https://git.ipxe.org/ipxe.git/blob/HEAD:/src/include/compiler.h#l204 Basically you do DBG("hello world\n") and it gets compiled out by default using: if (DBG_LOG) { printf("hello world\n"); } Here's the really cool part, debugging can be toggled on a per-object file basis at compile-time: make DEBUG=e1000 # build QEMU with debug printfs only in e1000.o The iPXE implementation is fancier than this. It supports different log levels, hex dumping, MD5 hashing, etc. But the core idea is: 1. Debug printfs are always if (0 or 1) { printf(...); } so that the compiler syntax checks them - no more bitrot in debug printfs. 2. A single debug.h header included from qemu-common.h with Makefile support that lets you say "make DEBUG=e1000,rtl8139,net". It would be a big step up from the mess we have today. Personally, I think we should use tracing instead of debug printfs though. Tracing allows you to use not just fprintf(stderr) but also DTrace, if you like. You can mark debug trace events "disabled" in ./trace-events so they will not be compiled in by default - zero performance overhead. Stefan
Am 15.02.2013 10:06, schrieb Stefan Hajnoczi: > In iPXE they use a clever compile-time debug macro: > https://git.ipxe.org/ipxe.git/blob/HEAD:/src/include/compiler.h#l204 > > Basically you do DBG("hello world\n") and it gets compiled out by > default using: > if (DBG_LOG) { > printf("hello world\n"); > } > > Here's the really cool part, debugging can be toggled on a per-object > file basis at compile-time: > > make DEBUG=e1000 # build QEMU with debug printfs only in e1000.o > > The iPXE implementation is fancier than this. It supports different log > levels, hex dumping, MD5 hashing, etc. > > But the core idea is: > 1. Debug printfs are always if (0 or 1) { printf(...); } so that the > compiler syntax checks them - no more bitrot in debug printfs. > 2. A single debug.h header included from qemu-common.h with Makefile > support that lets you say "make DEBUG=e1000,rtl8139,net". > > It would be a big step up from the mess we have today. Thanks for that feedback. If you look at the previous discussion, that's part of what I did in my RFC, and it was rejected in favor of keeping #ifdef'able defines. Using inline functions to avoid some nasty macro-is-not-function issues, there seemed to be no need to combine both approaches due to the format string being checked one level above. > Personally, I think we should use tracing instead of debug printfs > though. Tracing allows you to use not just fprintf(stderr) but also > DTrace, if you like. You can mark debug trace events "disabled" in > ./trace-events so they will not be compiled in by default - zero > performance overhead. This series or patch is not against tracing. It might be an option to use them for tmp105. But not being the author of the targets and all of the devices my CPU refactorings potentially touch, it is infeasable for me to determine an appropriate set of tracepoints everywhere. We'd also need to decide whether we want per-target tracepoints or per-aspect tracepoints, since it's a global list. Independent of that question, some kind of include mechanism (like for the default-configs) would be nice to decouple adding tracepoints in different areas. Andreas
On Fri, Feb 15, 2013 at 10:50:16AM +0100, Andreas Färber wrote: > Am 15.02.2013 10:06, schrieb Stefan Hajnoczi: > > In iPXE they use a clever compile-time debug macro: > > https://git.ipxe.org/ipxe.git/blob/HEAD:/src/include/compiler.h#l204 > > > > Basically you do DBG("hello world\n") and it gets compiled out by > > default using: > > if (DBG_LOG) { > > printf("hello world\n"); > > } > > > > Here's the really cool part, debugging can be toggled on a per-object > > file basis at compile-time: > > > > make DEBUG=e1000 # build QEMU with debug printfs only in e1000.o > > > > The iPXE implementation is fancier than this. It supports different log > > levels, hex dumping, MD5 hashing, etc. > > > > But the core idea is: > > 1. Debug printfs are always if (0 or 1) { printf(...); } so that the > > compiler syntax checks them - no more bitrot in debug printfs. > > 2. A single debug.h header included from qemu-common.h with Makefile > > support that lets you say "make DEBUG=e1000,rtl8139,net". > > > > It would be a big step up from the mess we have today. > > Thanks for that feedback. If you look at the previous discussion, that's > part of what I did in my RFC, and it was rejected in favor of keeping > #ifdef'able defines. Using inline functions to avoid some nasty > macro-is-not-function issues, there seemed to be no need to combine both > approaches due to the format string being checked one level above. Redefining debug functions in every file is nasty. I am also not a fan of modifying a #define, it always need to be reverted before committing changes. > > Personally, I think we should use tracing instead of debug printfs > > though. Tracing allows you to use not just fprintf(stderr) but also > > DTrace, if you like. You can mark debug trace events "disabled" in > > ./trace-events so they will not be compiled in by default - zero > > performance overhead. > > This series or patch is not against tracing. It might be an option to > use them for tmp105. But not being the author of the targets and all of > the devices my CPU refactorings potentially touch, it is infeasable for > me to determine an appropriate set of tracepoints everywhere. We'd also > need to decide whether we want per-target tracepoints or per-aspect > tracepoints, since it's a global list. Independent of that question, > some kind of include mechanism (like for the default-configs) would be > nice to decouple adding tracepoints in different areas. Not sure I understand. You don't need to come up with new trace events in code you didn't write. DPRINTF() can be converted mechanically to trace_foo(arg1, arg). Then we get rid of all the DPRINTF() definitions. The ./trace-events list is informal and can change at any time. We don't need to coordinate between different subsystems or targets in QEMU. Stefan
Am 15.02.2013 13:51, schrieb Stefan Hajnoczi: > On Fri, Feb 15, 2013 at 10:50:16AM +0100, Andreas Färber wrote: >> Am 15.02.2013 10:06, schrieb Stefan Hajnoczi: >>> In iPXE they use a clever compile-time debug macro: >>> https://git.ipxe.org/ipxe.git/blob/HEAD:/src/include/compiler.h#l204 >>> >>> Basically you do DBG("hello world\n") and it gets compiled out by >>> default using: >>> if (DBG_LOG) { >>> printf("hello world\n"); >>> } >>> >>> Here's the really cool part, debugging can be toggled on a per-object >>> file basis at compile-time: >>> >>> make DEBUG=e1000 # build QEMU with debug printfs only in e1000.o >>> >>> The iPXE implementation is fancier than this. It supports different log >>> levels, hex dumping, MD5 hashing, etc. >>> >>> But the core idea is: >>> 1. Debug printfs are always if (0 or 1) { printf(...); } so that the >>> compiler syntax checks them - no more bitrot in debug printfs. >>> 2. A single debug.h header included from qemu-common.h with Makefile >>> support that lets you say "make DEBUG=e1000,rtl8139,net". >>> >>> It would be a big step up from the mess we have today. >> >> Thanks for that feedback. If you look at the previous discussion, that's >> part of what I did in my RFC, and it was rejected in favor of keeping >> #ifdef'able defines. Using inline functions to avoid some nasty >> macro-is-not-function issues, there seemed to be no need to combine both >> approaches due to the format string being checked one level above. > > Redefining debug functions in every file is nasty. I am also not a fan > of modifying a #define, it always need to be reverted before committing > changes. If you want to convert the code to tracepoints, feel free to go at it! But that hasn't been done since introducing that infrastructure, so my hopes are low. ;) >>> Personally, I think we should use tracing instead of debug printfs >>> though. Tracing allows you to use not just fprintf(stderr) but also >>> DTrace, if you like. You can mark debug trace events "disabled" in >>> ./trace-events so they will not be compiled in by default - zero >>> performance overhead. >> >> This series or patch is not against tracing. It might be an option to >> use them for tmp105. But not being the author of the targets and all of >> the devices my CPU refactorings potentially touch, it is infeasable for >> me to determine an appropriate set of tracepoints everywhere. We'd also >> need to decide whether we want per-target tracepoints or per-aspect >> tracepoints, since it's a global list. Independent of that question, >> some kind of include mechanism (like for the default-configs) would be >> nice to decouple adding tracepoints in different areas. > > Not sure I understand. You don't need to come up with new trace events > in code you didn't write. I didn't write those, but I am the one that would like them to work for my purposes. So it looks like I need to change them or nobody will. > DPRINTF() can be converted mechanically to > trace_foo(arg1, arg). Then we get rid of all the DPRINTF() definitions. What is "foo" though and what "arg1, arg"? That needs to be invented AFAIU. Following up on Anthony's original thought, the question is whether to convert a LOG_EXCP macro in target-ppc to ppc_log_excp tracepoint or whether to homogenize it as log_excp and use that across targets, to save tracepoint definitions. That's not purely mechanical. > The ./trace-events list is informal and can change at any time. We > don't need to coordinate between different subsystems or targets in > QEMU. I'm assuming that changes to ppc logging go through ppc-next, changes to sparc code go through Blue etc. All those potentially conflict since they're adding to the bottom of the same text file, thus coordination. It's a long-standing criticism of our centralistic tracing infrastructure compared to the totally decentral and inhomogeneous DPRINTFs and what-nots on the other hand. Cheers, Andreas
On 15.02.2013, at 14:04, Andreas Färber wrote: > Am 15.02.2013 13:51, schrieb Stefan Hajnoczi: >> On Fri, Feb 15, 2013 at 10:50:16AM +0100, Andreas Färber wrote: >>> Am 15.02.2013 10:06, schrieb Stefan Hajnoczi: >>>> In iPXE they use a clever compile-time debug macro: >>>> https://git.ipxe.org/ipxe.git/blob/HEAD:/src/include/compiler.h#l204 >>>> >>>> Basically you do DBG("hello world\n") and it gets compiled out by >>>> default using: >>>> if (DBG_LOG) { >>>> printf("hello world\n"); >>>> } >>>> >>>> Here's the really cool part, debugging can be toggled on a per-object >>>> file basis at compile-time: >>>> >>>> make DEBUG=e1000 # build QEMU with debug printfs only in e1000.o >>>> >>>> The iPXE implementation is fancier than this. It supports different log >>>> levels, hex dumping, MD5 hashing, etc. >>>> >>>> But the core idea is: >>>> 1. Debug printfs are always if (0 or 1) { printf(...); } so that the >>>> compiler syntax checks them - no more bitrot in debug printfs. >>>> 2. A single debug.h header included from qemu-common.h with Makefile >>>> support that lets you say "make DEBUG=e1000,rtl8139,net". >>>> >>>> It would be a big step up from the mess we have today. >>> >>> Thanks for that feedback. If you look at the previous discussion, that's >>> part of what I did in my RFC, and it was rejected in favor of keeping >>> #ifdef'able defines. Using inline functions to avoid some nasty >>> macro-is-not-function issues, there seemed to be no need to combine both >>> approaches due to the format string being checked one level above. >> >> Redefining debug functions in every file is nasty. I am also not a fan >> of modifying a #define, it always need to be reverted before committing >> changes. > > If you want to convert the code to tracepoints, feel free to go at it! > But that hasn't been done since introducing that infrastructure, so my > hopes are low. ;) > >>>> Personally, I think we should use tracing instead of debug printfs >>>> though. Tracing allows you to use not just fprintf(stderr) but also >>>> DTrace, if you like. You can mark debug trace events "disabled" in >>>> ./trace-events so they will not be compiled in by default - zero >>>> performance overhead. >>> >>> This series or patch is not against tracing. It might be an option to >>> use them for tmp105. But not being the author of the targets and all of >>> the devices my CPU refactorings potentially touch, it is infeasable for >>> me to determine an appropriate set of tracepoints everywhere. We'd also >>> need to decide whether we want per-target tracepoints or per-aspect >>> tracepoints, since it's a global list. Independent of that question, >>> some kind of include mechanism (like for the default-configs) would be >>> nice to decouple adding tracepoints in different areas. >> >> Not sure I understand. You don't need to come up with new trace events >> in code you didn't write. > > I didn't write those, but I am the one that would like them to work for > my purposes. So it looks like I need to change them or nobody will. > >> DPRINTF() can be converted mechanically to >> trace_foo(arg1, arg). Then we get rid of all the DPRINTF() definitions. > > What is "foo" though and what "arg1, arg"? That needs to be invented AFAIU. > > Following up on Anthony's original thought, the question is whether to > convert a LOG_EXCP macro in target-ppc to ppc_log_excp tracepoint or > whether to homogenize it as log_excp and use that across targets, to > save tracepoint definitions. That's not purely mechanical. > >> The ./trace-events list is informal and can change at any time. We >> don't need to coordinate between different subsystems or targets in >> QEMU. > > I'm assuming that changes to ppc logging go through ppc-next, changes to > sparc code go through Blue etc. All those potentially conflict since > they're adding to the bottom of the same text file, thus coordination. > It's a long-standing criticism of our centralistic tracing > infrastructure compared to the totally decentral and inhomogeneous > DPRINTFs and what-nots on the other hand. In parallel to the completely disastrous user experience when using trace points. Debug printfs are easy and understandable. Tracepoints are not. However, how about we take this one gradually? If all debug prints in all files do an #ifdef DEBUG static const debug_enabled = 1; #else static const debug_enabled = 0; #endif then Stefan can probably add a -DDEBUG to a specific c file through Makefile magic if he wants to do iPXE-style debugging. And if you're - like me - more happy with local #define DEBUG, then you can do that as well. I would definitely oppose moving to tracepoints. Alex
Am 15.02.2013 14:14, schrieb Alexander Graf: > In parallel to the completely disastrous user experience when using trace points. Debug printfs are easy and understandable. Tracepoints are not. > > However, how about we take this one gradually? +1, I'm looking for a minimally invasive solution that addresses my compilation-test needs. It doesn't need to be the final bells-and-whistles version. :) > If all debug prints in all files do an > > #ifdef DEBUG > static const debug_enabled = 1; > #else > static const debug_enabled = 0; > #endif > > then Stefan can probably add a -DDEBUG to a specific c file through Makefile magic if he wants to do iPXE-style debugging. And if you're - like me - more happy with local #define DEBUG, then you can do that as well. Could you please clarify: Are you suggesting to consistently use just DEBUG in place of the various FOO_DEBUGs? That would enable all debug output for --enable-debug builds, wouldn't it? (Or am I mixing that up with NDEBUG in the opposite case...?) Or just having a static const variable to avoid #ifdef FOO_DEBUG for statements as done in openpic code? Andreas > > I would definitely oppose moving to tracepoints. > > > Alex >
Il 15/02/2013 14:14, Alexander Graf ha scritto: >> > >> > I'm assuming that changes to ppc logging go through ppc-next, changes to >> > sparc code go through Blue etc. All those potentially conflict since >> > they're adding to the bottom of the same text file, thus coordination. >> > It's a long-standing criticism of our centralistic tracing >> > infrastructure compared to the totally decentral and inhomogeneous >> > DPRINTFs and what-nots on the other hand. I rarely found conflicts in trace-events, but in this case you would indeed have them. Trivial to solve, however. > In parallel to the completely disastrous user experience when using trace points. What exactly is disastrous? We could have improvements (such as having multiple trace backends compiled in an executable, e.g. simple+stderr, or having gdb magic to enable/disable them from command breakpoints). But in general, I find trace points to be quite easy to use, and unintrusive enough to let you debug performance problems. Paolo
On 16.02.2013, at 12:59, Andreas Färber wrote: > Am 15.02.2013 14:14, schrieb Alexander Graf: >> In parallel to the completely disastrous user experience when using trace points. Debug printfs are easy and understandable. Tracepoints are not. >> >> However, how about we take this one gradually? > > +1, I'm looking for a minimally invasive solution that addresses my > compilation-test needs. It doesn't need to be the final > bells-and-whistles version. :) > >> If all debug prints in all files do an >> >> #ifdef DEBUG >> static const debug_enabled = 1; >> #else >> static const debug_enabled = 0; >> #endif >> >> then Stefan can probably add a -DDEBUG to a specific c file through Makefile magic if he wants to do iPXE-style debugging. And if you're - like me - more happy with local #define DEBUG, then you can do that as well. > > Could you please clarify: Are you suggesting to consistently use just > DEBUG in place of the various FOO_DEBUGs? That would enable all debug > output for --enable-debug builds, wouldn't it? (Or am I mixing that up > with NDEBUG in the opposite case...?) Ah, DEBUG is already taken. I was thinking of some define that only applies to files you want to debug, which you can then mark the debug_enabled variable to true with. I see 2 options to do this: - Add a DEBUG_THIS_FILE define. This define is only set for files you explicitly mark to debug. I don't know how hard it would be to do this for a Makefile magician - Convert file paths into define compatible strings. hw/ppc/ppc_newworld.c would become HW_PPC_MAC_NEWWORLD_C. In that file, check for DEBUG_HW_PPC_MAC_NEWWORLD_C and set debug to enabled if it's defined. With a small script that does the above conversion you could then maybe do "make debug=hw/ppc/mac_newworld.c" to easily enable debugging for that whole file. That's iPXE style :). Alex > > Or just having a static const variable to avoid #ifdef FOO_DEBUG for > statements as done in openpic code? > > Andreas > >> >> I would definitely oppose moving to tracepoints. >> >> >> Alex >> > > > -- > SUSE LINUX Products GmbH, Maxfeldstr. 5, 90409 Nürnberg, Germany > GF: Jeff Hawn, Jennifer Guild, Felix Imendörffer; HRB 16746 AG Nürnberg
diff --git a/hw/tmp105.c b/hw/tmp105.c index 3ad2d2f..5dafa37 100644 --- a/hw/tmp105.c +++ b/hw/tmp105.c @@ -23,6 +23,18 @@ #include "tmp105.h" #include "qapi/visitor.h" +#undef DEBUG_TMP105 + +static inline void GCC_FMT_ATTR(1, 2) DPRINTF(const char *fmt, ...) +{ +#ifdef DEBUG_TMP105 + va_list ap; + va_start(ap, fmt); + vfprintf(stderr, fmt, ap); + va_end(ap); +#endif +} + static void tmp105_interrupt_update(TMP105State *s) { qemu_set_irq(s->pin, s->alarm ^ ((~s->config >> 2) & 1)); /* POL */ @@ -115,10 +127,16 @@ static void tmp105_read(TMP105State *s) s->buf[s->len ++] = ((uint16_t) s->limit[1]) >> 0; break; } + + DPRINTF("%s: %02" PRIx8 " %02" PRIx8 "%02" PRIx8 "\n", + __func__, s->pointer, s->buf[0], s->buf[1]); } static void tmp105_write(TMP105State *s) { + DPRINTF("%s: %02" PRIx8 " %02" PRIx8 "%02" PRIx8 "\n", + __func__, s->pointer, s->buf[0], s->buf[1]); + switch (s->pointer & 3) { case TMP105_REG_TEMPERATURE: break; @@ -144,18 +162,23 @@ static void tmp105_write(TMP105State *s) static int tmp105_rx(I2CSlave *i2c) { TMP105State *s = TMP105(i2c); + int ret; if (s->len < 2) { - return s->buf[s->len ++]; + ret = s->buf[s->len++]; } else { - return 0xff; + ret = 0xff; } + DPRINTF("%s: <- %02x\n", __func__, ret); + return ret; } static int tmp105_tx(I2CSlave *i2c, uint8_t data) { TMP105State *s = TMP105(i2c); + DPRINTF("%s: -> %02" PRIx8 "\n", __func__, data); + if (s->len == 0) { s->pointer = data; s->len++;