I usually prints some messages on a free UART used as a debug port. They are very useful during debugging to understand the flow of execution. Most of the time, I don't compile the debug log facility in release build. I sometimes need to disable messages from some modules and enable messages from other modules under debugging. Moreover I sometimes need to enable/disable less important messages. Do you suggest some efficient implementation of debug log macros that include all the features above?
Efficient debug log
Started by ●July 20, 2017
Reply by ●July 20, 20172017-07-20
pozz <pozzugno@gmail.com> wrote:> I sometimes need to disable messages from some modules and enable > messages from other modules under debugging. > Moreover I sometimes need to enable/disable less important messages.Most logging systems use a priority parameter which can be used to mask less important messages. If you have fewer modules than bits in a word, you could also pass a module id parameter, and efficiently mask messages per-module. -a
Reply by ●July 20, 20172017-07-20
On 2017-07-20 pozz wrote in comp.arch.embedded:> I usually prints some messages on a free UART used as a debug port. > They are very useful during debugging to understand the flow of execution. > > Most of the time, I don't compile the debug log facility in release build. > > I sometimes need to disable messages from some modules and enable > messages from other modules under debugging. > Moreover I sometimes need to enable/disable less important messages. > > Do you suggest some efficient implementation of debug log macros that > include all the features above?If I have a output stream available for this purpose, I often use the following (assuming you use C): #ifdef DEBUG_ENABLE #define DEBUG_PRINTF(level, ...) ((level) <= (DebugLevel) ? fprintf(stderr, __VA_ARGS__) : (level)) #else #define DEBUG_PRINTF(level, ...) Call like a normal printf, except there is an initial parameter for the level of that paticular call. Lower the value of 'DebugLevel' to reduce the output. -- Stef (remove caps, dashes and .invalid from e-mail address to reply by mail) A wise person makes his own decisions, a weak one obeys public opinion. -- Chinese proverb
Reply by ●July 20, 20172017-07-20
On 20/07/17 19:31, pozz wrote:> I usually prints some messages on a free UART used as a debug port. They > are very useful during debugging to understand the flow of execution. > > Most of the time, I don't compile the debug log facility in release build. > > I sometimes need to disable messages from some modules and enable > messages from other modules under debugging. > Moreover I sometimes need to enable/disable less important messages. > > Do you suggest some efficient implementation of debug log macros that > include all the features above?We used to use a 32-bit trace-control word with bit-fields assigned for different subject areas. In large systems, 26 such words under letters of the alphabet, so you could enable tracing e.g. "t0-3,c6", etc. The trace function took a first argument that packed a letter and a number (0..31) into 16 bits, which made it quick to check whether that trace flag was enabled. printf-style string & varargs followed. It also returned the "enabled" boolean, so you could avoid a code path whose only purpose is to generate detailed tracing. More recently (2005) I implemented an even more powerful system, but it would only suit the largest embedded systems. It had an inlined test for the trace class being enabled (less than 2ns if disabled, after the first pass that bound the control variable), then queued the control strings and parameters into a large shared memory buffer. The buffer used lock-free synchronisation, so on normal Intel hardware could achieve >1GBps. One or more trace consumer threads could format the messages and write to a file, or send them over a TCP link. This consumer thread also listened for local connection requests so you could remotely enable and listen to tracing on a program while it was already running. So yeah, the sky is the limit as far as sophistication goes ;) Clifford Heath.
Reply by ●July 21, 20172017-07-21
Il giorno giovedì 20 luglio 2017 11:31:54 UTC+2, pozz ha scritto:> I usually prints some messages on a free UART used as a debug port. > They are very useful during debugging to understand the flow of execution. > > Most of the time, I don't compile the debug log facility in release build. > > I sometimes need to disable messages from some modules and enable > messages from other modules under debugging. > Moreover I sometimes need to enable/disable less important messages. > > Do you suggest some efficient implementation of debug log macros that > include all the features above?different #define for each module #define UART_DEBUG #define TIMER_DEBUG etc. and the in the module #ifdef UART_DEBUG printf("NO PANIC!! error on uart module") #endif You enable only the ones you want. Or instead of defining in source code, you can use the -D directive of the compiler to enable/disable the debug parts. Depending on your toolchain one could be easier than the other. Bye Jack
Reply by ●July 24, 20172017-07-24
On 20/07/17 23:14, Stef wrote:> On 2017-07-20 pozz wrote in comp.arch.embedded: >> I usually prints some messages on a free UART used as a debug port. >> They are very useful during debugging to understand the flow of execution. >> >> Most of the time, I don't compile the debug log facility in release build. >> >> I sometimes need to disable messages from some modules and enable >> messages from other modules under debugging. >> Moreover I sometimes need to enable/disable less important messages. >> >> Do you suggest some efficient implementation of debug log macros that >> include all the features above? > > If I have a output stream available for this purpose, I often use the > following (assuming you use C): > > #ifdef DEBUG_ENABLE > #define DEBUG_PRINTF(level, ...) ((level) <= (DebugLevel) ? fprintf(stderr, __VA_ARGS__) : (level)) > #else > #define DEBUG_PRINTF(level, ...) > > Call like a normal printf, except there is an initial parameter for the > level of that paticular call. > > Lower the value of 'DebugLevel' to reduce the output. >Yes, something like that is the way to do it. That means in the code itself, you avoid having any extra "#ifdef DEBUG_ENABLE" conditional compilation that /really/ messes up the readability of the code. You just use DEBUG_PRINTF, safe in the knowledge that it does nothing when debugging is disabled. The only unpleasant thing about this method is that if you have local data that is only used for debugging, you are going to get warnings about it when you disable debugging. Since I like to have most of my compiler warnings enabled, and like my code to be warning-free when compiled, this bugs me. So I have this definition: static inline int emptyFunctionX(int x, ...) { (void) x; return 0; } #define emptyFunction(...) emptyFunctionX(0, ## __VA_ARGS__) Then when disabling debugging, I have: #define debugPrintf emptyFunction (I don't like defining a function as an expression in the way you did, and I hate all-caps macro names for constants or function-like macros.) "emptyFunction" uses a gcc extension here, but that's a common compiler for many people. It swallows any arguments without generating code, and without requiring the arguments to be calculated at all (assuming you have optimisation enabled), but considers the arguments "used" as far as warnings are concerned.
Reply by ●July 26, 20172017-07-26
Il 24/07/2017 09:40, David Brown ha scritto:> On 20/07/17 23:14, Stef wrote: >> On 2017-07-20 pozz wrote in comp.arch.embedded: >>> I usually prints some messages on a free UART used as a debug port. >>> They are very useful during debugging to understand the flow of execution. >>> >>> Most of the time, I don't compile the debug log facility in release build. >>> >>> I sometimes need to disable messages from some modules and enable >>> messages from other modules under debugging. >>> Moreover I sometimes need to enable/disable less important messages. >>> >>> Do you suggest some efficient implementation of debug log macros that >>> include all the features above? >> >> If I have a output stream available for this purpose, I often use the >> following (assuming you use C): >> >> #ifdef DEBUG_ENABLE >> #define DEBUG_PRINTF(level, ...) ((level) <= (DebugLevel) ? fprintf(stderr, __VA_ARGS__) : (level)) >> #else >> #define DEBUG_PRINTF(level, ...) >> >> Call like a normal printf, except there is an initial parameter for the >> level of that paticular call. >> >> Lower the value of 'DebugLevel' to reduce the output. >> > > Yes, something like that is the way to do it. That means in the code > itself, you avoid having any extra "#ifdef DEBUG_ENABLE" conditional > compilation that /really/ messes up the readability of the code. You > just use DEBUG_PRINTF, safe in the knowledge that it does nothing when > debugging is disabled. > > The only unpleasant thing about this method is that if you have local > data that is only used for debugging, you are going to get warnings > about it when you disable debugging. Since I like to have most of my > compiler warnings enabled, and like my code to be warning-free when > compiled, this bugs me. > > So I have this definition: > > static inline int emptyFunctionX(int x, ...) { (void) x; return 0; } > #define emptyFunction(...) emptyFunctionX(0, ## __VA_ARGS__) > > Then when disabling debugging, I have: > > #define debugPrintf emptyFunction > > (I don't like defining a function as an expression in the way you did, > and I hate all-caps macro names for constants or function-like macros.) > > > "emptyFunction" uses a gcc extension here, but that's a common compiler > for many people. It swallows any arguments without generating code, and > without requiring the arguments to be calculated at all (assuming you > have optimisation enabled), but considers the arguments "used" as far as > warnings are concerned.As usual, thanks for the interesting tricks, David. If I understood correctly: #include "debug.h" // Where is debugPrintf, emptyFunction, ... static int var_used_only_in_debug; ... debug_printf(10, "The value is %d\n", var_used_only_in_debug); The compilation doesn't emit warnings (regarding unused static variables) and doesn't really allocate space for var_used_only_in_debug (thanks to optimization). This should work for functions too: #include "debug.h" static const char *fun_used_only_in_debug(int arg); ... debug_printf(10, "The name is %s\n", fun_used_only_in_debug(value)); ... static const char *fun_used_only_in_debug(int arg) { if (arg == 3) return "Three"; if (arg == 3) return "Four"; ... } In this case, the function isn't included in the output file (thanks to optimization). I have another situation. I want to include a member in a structure, but it's only used in debug. This member is used only in debug_printf calls, so it can be omitted in the Release build. If I use #ifdef DEBUG_ENABLE #endif to avoid including the member, I will have an error during build (because debug_print refers to a member that doesn't exist). If I leave the member in the structure in Release build, I will waste some space. Is there a trick to solve this problem?
Reply by ●July 26, 20172017-07-26
On 26/07/17 11:15, pozz wrote:> Il 24/07/2017 09:40, David Brown ha scritto: >> On 20/07/17 23:14, Stef wrote: >>> On 2017-07-20 pozz wrote in comp.arch.embedded: >>>> I usually prints some messages on a free UART used as a debug port. >>>> They are very useful during debugging to understand the flow of >>>> execution. >>>> >>>> Most of the time, I don't compile the debug log facility in release >>>> build. >>>> >>>> I sometimes need to disable messages from some modules and enable >>>> messages from other modules under debugging. >>>> Moreover I sometimes need to enable/disable less important messages. >>>> >>>> Do you suggest some efficient implementation of debug log macros that >>>> include all the features above? >>> >>> If I have a output stream available for this purpose, I often use the >>> following (assuming you use C): >>> >>> #ifdef DEBUG_ENABLE >>> #define DEBUG_PRINTF(level, ...) ((level) <= (DebugLevel) ? >>> fprintf(stderr, __VA_ARGS__) : (level)) >>> #else >>> #define DEBUG_PRINTF(level, ...) >>> >>> Call like a normal printf, except there is an initial parameter for the >>> level of that paticular call. >>> >>> Lower the value of 'DebugLevel' to reduce the output. >>> >> >> Yes, something like that is the way to do it. That means in the code >> itself, you avoid having any extra "#ifdef DEBUG_ENABLE" conditional >> compilation that /really/ messes up the readability of the code. You >> just use DEBUG_PRINTF, safe in the knowledge that it does nothing when >> debugging is disabled. >> >> The only unpleasant thing about this method is that if you have local >> data that is only used for debugging, you are going to get warnings >> about it when you disable debugging. Since I like to have most of my >> compiler warnings enabled, and like my code to be warning-free when >> compiled, this bugs me. >> >> So I have this definition: >> >> static inline int emptyFunctionX(int x, ...) { (void) x; return 0; } >> #define emptyFunction(...) emptyFunctionX(0, ## __VA_ARGS__) >> >> Then when disabling debugging, I have: >> >> #define debugPrintf emptyFunction >> >> (I don't like defining a function as an expression in the way you did, >> and I hate all-caps macro names for constants or function-like macros.) >> >> >> "emptyFunction" uses a gcc extension here, but that's a common compiler >> for many people. It swallows any arguments without generating code, and >> without requiring the arguments to be calculated at all (assuming you >> have optimisation enabled), but considers the arguments "used" as far as >> warnings are concerned. > > As usual, thanks for the interesting tricks, David. > > > If I understood correctly: > > #include "debug.h" // Where is debugPrintf, emptyFunction, ... > static int var_used_only_in_debug; > ... > debug_printf(10, "The value is %d\n", var_used_only_in_debug); > > The compilation doesn't emit warnings (regarding unused static > variables) and doesn't really allocate space for var_used_only_in_debug > (thanks to optimization). >Yes. In most such debug calls, you are just showing existing data, so it makes little difference. But sometimes you might want to manipulate something or make new local data before printing it.> > This should work for functions too: > > #include "debug.h" > static const char *fun_used_only_in_debug(int arg); > ... > debug_printf(10, "The name is %s\n", fun_used_only_in_debug(value)); > ... > static const char *fun_used_only_in_debug(int arg) { > if (arg == 3) return "Three"; > if (arg == 3) return "Four"; > ... > } > > In this case, the function isn't included in the output file (thanks to > optimization).Yes. Note that this will only apply if the compiler knows it is safe to skip the function call - either because it has the definition of the function on hand and can see it (such as in this case), or because you have told it is safe (such as by using the "const" or "pure" function attributes in gcc).> > > I have another situation. I want to include a member in a structure, but > it's only used in debug. This member is used only in debug_printf calls, > so it can be omitted in the Release build. If I use #ifdef DEBUG_ENABLE > #endif to avoid including the member, I will have an error during build > (because debug_print refers to a member that doesn't exist). > If I leave the member in the structure in Release build, I will waste > some space. > > Is there a trick to solve this problem?That is a very interesting question. I hadn't thought about this before, but I've got an answer for you: #define enableDebugging static inline int emptyFunctionX(int x, ...) { (void) x; return 0; } #define emptyFunction(...) emptyFunctionX(0, ## __VA_ARGS__) typedef struct {} empty_t; #ifdef enableDebugging extern int debugPrintf(const char *format, ...) __attribute__ ((format (printf, 1, 2))); #define debugField(T) T #else #define debugPrintf emptyFunction #define debugField(T) empty_t #endif typedef struct { int a; int b; debugField(int) debug; } data_t; data_t data; int sizeofData(void) { return sizeof(data_t); } int foo(void) { data.a += data.b; debugPrintf("%i %i %i", data.a, data.b, data.debug); return data.a; } I tested this using the online compiler at <https://godbolt.org>. Copy and paste it in, using whatever compiler version you like (gcc or clang, because of the __attribute__). Use "-Wall -Wextra -std=c11 -O1 -x c" as the command line options ("-x c" makes gcc compile C, rather than the default C++ for the tools used by the site). You can see the real size of the "data_t" struct from the assembly code generated for "sizeofData" - a field of type "empty_t" takes no space, but avoids the error when it is used in the disabled debugPrintf call. However, note that a struct with no members is invalid in strict ISO C. gcc is happy with it, but if you use -Wpedantic or use another compiler you may get warnings or errors. The code here also shows how to use the "format" attribute to get checking of the types in the debugPrintf call. Try changing one of the %i to %s, and look at the warnings (they will only be checked when debugging is enabled, but you can't have everything!)
Reply by ●July 27, 20172017-07-27
On 2017-07-24 David Brown wrote in comp.arch.embedded:> On 20/07/17 23:14, Stef wrote: >> On 2017-07-20 pozz wrote in comp.arch.embedded: >>> I usually prints some messages on a free UART used as a debug port. >>> They are very useful during debugging to understand the flow of execution. >>> >>> Most of the time, I don't compile the debug log facility in release build. >>> >>> I sometimes need to disable messages from some modules and enable >>> messages from other modules under debugging. >>> Moreover I sometimes need to enable/disable less important messages. >>> >>> Do you suggest some efficient implementation of debug log macros that >>> include all the features above? >> >> If I have a output stream available for this purpose, I often use the >> following (assuming you use C): >> >> #ifdef DEBUG_ENABLE >> #define DEBUG_PRINTF(level, ...) ((level) <= (DebugLevel) ? fprintf(stderr, __VA_ARGS__) : (level)) >> #else >> #define DEBUG_PRINTF(level, ...) >> >> Call like a normal printf, except there is an initial parameter for the >> level of that paticular call. >> >> Lower the value of 'DebugLevel' to reduce the output. >> > > Yes, something like that is the way to do it. That means in the code > itself, you avoid having any extra "#ifdef DEBUG_ENABLE" conditional > compilation that /really/ messes up the readability of the code. You > just use DEBUG_PRINTF, safe in the knowledge that it does nothing when > debugging is disabled. > > The only unpleasant thing about this method is that if you have local > data that is only used for debugging, you are going to get warnings > about it when you disable debugging. Since I like to have most of my > compiler warnings enabled, and like my code to be warning-free when > compiled, this bugs me.This is true, but you could also argue that data only used for debugging should be removed as well when debugging is disabled. That will require inserting some additional #ifdefs in the code in places where debug-only data is used. But mostly, i use the construct to print values of variables that are in use in normal code. And most often de DEBUG_PRINTF is not disabled at all, only the level lowered to a point where only things like startup and critical messages are emitted.> So I have this definition: > > static inline int emptyFunctionX(int x, ...) { (void) x; return 0; } > #define emptyFunction(...) emptyFunctionX(0, ## __VA_ARGS__) > > Then when disabling debugging, I have: > > #define debugPrintf emptyFunction > > (I don't like defining a function as an expression in the way you did, > and I hate all-caps macro names for constants or function-like macros.)But this requires you to write an actual debugPrintf function to handle the level comparison before calling the actual printf? But I look into it, might be a better solution is some situations. And i love all-caps macro names for constants or function-like macros ;-)> > "emptyFunction" uses a gcc extension here, but that's a common compiler > for many people. It swallows any arguments without generating code, and > without requiring the arguments to be calculated at all (assuming you > have optimisation enabled), but considers the arguments "used" as far as > warnings are concerned.Indeed a common compiler for me as well, but I have a few projects that use other compilers. -- Stef (remove caps, dashes and .invalid from e-mail address to reply by mail) Predestination was doomed from the start.
Reply by ●July 27, 20172017-07-27
On 2017-07-26 pozz wrote in comp.arch.embedded:> > I have another situation. I want to include a member in a structure, but > it's only used in debug. This member is used only in debug_printf calls, > so it can be omitted in the Release build. If I use #ifdef DEBUG_ENABLE > #endif to avoid including the member, I will have an error during build > (because debug_print refers to a member that doesn't exist). > If I leave the member in the structure in Release build, I will waste > some space. > > Is there a trick to solve this problem?I often find this "waste of space" argument a bit irrelevant. On large targets, the few extra bytes usually don't matter at all. On small targets, the space argument may seem valid. But often, you want to be able to run the debug version on the same target as the release version. This means the target must have space for this data and that this space will simply be vacant if you have a release version with the data removed. There is even a danger of expanding the code in release mode and then finding it does not fit anymore when you need to switch back to debug. But there may be situations where you have a special (larger) target for debug than is used for the release. Or situations where you have to store or transmit binaries and space is tight or expensive. So for these situations (or others, or just for the fun of it), I do find Davids exercise in the other reply very interesting. -- Stef (remove caps, dashes and .invalid from e-mail address to reply by mail) "Can you program?" "Well, I'm literate, if that's what you mean!"