tinyos/tinyos-main — pull request #261 by mcerveny (2014-04-05 12:27:49+00:00)
Title: RFE: printfsyslog - per file conditional printing macros 

Hello.

I had problem with some sort of flexible debugging outputs. I present here my solution (new 3 defines - prinfsyslog(), prinfsyslog_inline() and prinfsyslog_flush()). I use Tinyos printf() (the alternative DiagMsg seems to be complicated).

_Problem1_ ) The "format" strings from printf() uses many of RAM.
_Solution1_ ) There is some well known solution (for example printf_P() from avrlib). Tinyos prinf() may be reprogrammed this way. I used on avr platform flag to store string only in flash PSTR() and do flash-to-ram copy to shared buffer just before Tinyos printf() call. There is unresolved problem with usage inside interrupt (I do not use printf() in interrupt handling).

_Problem2_ ) Flexible filtering of debug output based on file base with global disable.
_Solution2_ ) Manually add/delete/comment-out printf() section is not best solution. I used new defines (eg. c-preprocessor based) that add/delete debug output before compilation. The filtering is inspired by 2-dimensional filtering (facility+severity level) form un*x syslog infrastructure. The facility defines type of debug and the severity defines hierarchical importance. You can set minimum severity (eg. >=) to debug output per facility (*_SEVERITY). You can filer active facilities to debug (eg. binary "or" in *_FACILITY_MASK). (for definition facility-severity - see begin of printfsyslog.h) (for example - see https://github.com/mcerveny/tinyos-main/blob/multi-hop-forwarding-with-babel-routing/tos/lib/net/mh/babel/BabelRoutingM.nc#L48 or https://github.com/mcerveny/tinyos-main/blob/multi-hop-forwarding-with-babel-routing/tos/lib/net/mh/MultiHopM.nc#L49 ). This infrastructure can be used with "#if"/"#endif" to disable more debugging code.
Global enable - define symbol "PRINTFSYSLOG" (PFLAGS+=-DPRINTFSYSLOG)
Global add line-number - define symbol "PRINTFSYSLOG_LINE" (PFLAGS+=-DPRINTFSYSLOG_LINE)

Some example output:
BABEL/S/D/334: txbegin == hello h_seq=0000 - upd all - upd - upd: dest=E3BF seq=0000 metr=0000 - == FFFF
BABEL/S/D/499: txdone
BABEL/R/D/531: rxbegin 1616 == HELLO - hello: h_seq=0182 - hello: new - (node rssi 60)
BABEL/R/D/1201: route query: ROUTE to 1616 through 1616
MH/SL4/D/290: sent type 198
MH//D/355: subsend done
MH/SL4/D/365: signaling upper sendDone
MH//D/412: receive from 1616
BABEL/R/D/1201: route query: RECEIVE
MH/RL4/D/455: signaling upper receive type 198

Format "T/F/S/L: some text" - can be easily filtered with grep/sed.

Example interpretation:
"BABEL" - unique tag
"R" - defined for routing part of code
"D" - debug level (lowest level)
"1201" - optional line nuber
"route query: ROUTE to 1616 through 1616" - text with data

There were previous similar discussions:
https://www.millennium.berkeley.edu/pipermail/tinyos-devel/2011-March/004829.html
https://github.com/tinyos/tinyos-main/blob/master/tos/lib/net/blip/blip_printf.h

TODO: It can be compatible with dbg() in simulator.

Your opinion ?
I suppose that many of you are using similar solution, can you share your solutions ?

Thanks, Martin Ceveny