meaning of debug_level

[basilkohler]

Meaning of debug_level not documented or defined.

suggestion:

• 1 fatal
• 2 error
• 3 warning
• 4 info
• 5 debug
• 6 verbose

[tschudin]

On Wed, 29 Oct 2014, Basil Kohler wrote:

Meaning of debug_level not documented or defined.

suggestion:

• 1 fatal
• 2 error
• 3 warning
• 4 info
• 5 debug
• 6 verbose

I would strongly support such a review of levels, it is badly needed.

The huge range (up to 99 and more) was mostly for level 6 (verbose)
which needs some finer granularity I think.

[basilkohler]

Final agreement:
1 [F] FATAL
2 [E] ERROR
3 [W] WARNING
4 [I] IFNO
^^^ production ^^^
5 [D] DEBUG
6 [T] TRACE
7 [V] VERBOSE

DEBUGMSG should print character in brackets to the log.

[basilkohler]

I started implementing the new debug_level and output.
I found out that one can print the name of the current function (__func__ variable), making it possible to print the trace automatically (at least as long as there is one DEBUGMSG in the current function).

I'm not sure if we should go that route or add a manual TRACE statement into every function:

• + Always up-to-date trace
• + Toggle trace with debug_level >= TRACE
• + Automatic trace for every debugmsg
• - Exists only for c99 (kernel module would lose the possibility to print traces...)
• - can only be printed before the actual message (because of new-line message of the printed message), cluttering the output.
• - would sometimes need both, a TRACE message as well as an actual info message (e.g.
  DEBUGMSG(TRACE, "ccnl_populate_cache\n") and DEBUGMSG(INFO, "populating cache from directory %s\n", path)

Checkout branch dev-basil to see it in action. (run ccn-lite-relay with -v 1005 and -v 1006).

Any other feedback before I continue adopting it further?

[tschudin]

good points. Considering them, why not treat TRACE as something
different from DEBUGMSG?

The code

 ccnl_core_init();

 TRACEIN();

 DEBUGMSG(INFO, "This is ccn-lite-relay, starting at %s",
          ctime(&theRelay.startup_time) + 4);
 DEBUGMSG(INFO, "  ccnl-core: %s\n", CCNL_VERSION);
 DEBUGMSG(INFO, "using suite %s\n", ccnl_suite2str(suite));

 TRACEOUT();

will produce

[T] 0.0000> main() // ccn-lite-relay.c:753
[I] 0.0001: This is ccn-lite-relay, starting at Nov 10 17:32:07 2014
[I] 0.0004: ccnl-core: 2014-11-07
[I] 0.0004: using suite ndn2013
[T] 0.0004< main() // ccn-lite-relay.c:762

I wrote the TRACEIN() such that optionally you can give it a string.
This allows kernel developpers to add a function name where they need
that info (i.e., where source file name and line number is too awkward
to look up). For example:

 TRACEIN("ccnl_populate_cache");

Outside the kernel (and assuming C99 or later), this argument is
discarded and the true function name is inserted.

Point-by-point:

• Always up-to-date trace

yes

• Toggle trace with debug_level >= TRACE

yes

• Automatic trace for every debugmsg

no, explicit TRACEIN() and TRACEOUT()

• Exists only for c99 (kernel module would lose the possibility to print
  traces...)

true, applies here too

• can only be printed before the actual message (because of new-line
  message of the printed message), cluttering the output.

not a problem anymore

• would sometimes need both, a TRACE message as well as an actual info
  message (e.g. DEBUGMSG(TRACE, "ccnl_populate_cache\n") and
  DEBUGMSG(INFO, "populating cache from directory %s\n", path)

which is why it seems good to me to have both. Example for printing
arg values:

TRACEIN("ccnl_populate_cache");
DEBUGMSG(VERBOSE, "  path=%s\n", path);

I have forked a branch called dev-trace with these changes. Note that I
have not written the stubs in case USE_DEBUG is not set.

c

On Mon, 10 Nov 2014, Basil Kohler wrote:

I started implementing the new debug_level and output.
I found out that one can print the name of the current function (func
variable), making it possible to print the trace automatically (at least as
long as there is one DEBUGMSG in the current function).

I'm not sure if we should go that route or add a manual TRACE statement into
every function:

• Always up-to-date trace
• Toggle trace with debug_level >= TRACE
• Automatic trace for every debugmsg
• Exists only for c99 (kernel module would lose the possibility to print
  traces...)
• can only be printed before the actual message (because of new-line
  message of the printed message), cluttering the output.
• would sometimes need both, a TRACE message as well as an actual info
  message (e.g. DEBUGMSG(TRACE, "ccnl_populate_cache\n") and
  DEBUGMSG(INFO, "populating cache from directory %s\n", path)

Checkout branch dev-basil to see it in action. (run ccn-lite-relay with -v
1005 and -v 1006).

Any other feedback before I continue adopting it further?

—
Reply to this email directly or view it on
GitHub.[ADxFAk7FL6LCmFOgdJBDNpZvVA5QHN0Fks5nML-QgaJpZM4C0U0y.gif]

[basilkohler]

I have thought about an explicit TRACE command as well. As you showed, it is more flexible that way.

The main disadvantage is that you don't get the trace for free for every DEBUGMSG (and most methods will have at least a DEBUGMSG(DEBUG, ...)), this means an explicit TRACE will be more (very easy) work.

This means we should add a TRACEIN at the beginning and a TRACEOUT at the end of all important methods?

[tschudin]

On Tue, 11 Nov 2014, Basil Kohler wrote:

The main disadvantage is that you don't get the trace for free for
every DEBUGMSG (and most methods will have at least a DEBUGMSG(DEBUG,
...)), this means an explicit TRACE will be more (very easy) work.

This means we should add a TRACEIN at the beginning and a TRACEOUT at
the end of all important methods?

I don't think so: it's an option, not a mandate. For example, almost no
function so far generates a log when it exits. IMHO trace is for
debugging error cases you don't understand, these "beeps" should be
added by-need.

One thought: having "TRACE" as a flag, like in

DEBUGMSG(INFO|TRACE, ...

which will also print the function name (if available via func)

Opinions?

[basilkohler]

I kept the TRACEIN/TRACEOUT command (for manual use), but added the function name, file name and line number to the output (printed for TRACE and above).
I set the value of TRACE to 99 to make sure that all the scripts still work for now.
I also read that it is possible to compile a kernel module in c99, therefore it should not be an issue if we actually need the output of func in the kernel module.