setting debug_level to trace crashes your RIOT

[mfrey]

Hi,

I probably should find a job where the main task is to break things. Anyway, enabling logging by setting debug_level to TRACE crashes RIOT. I'm using RIOTs ccn-lite-relay example and simply added a line which enables the log messages. While this seem to be a silly endeavour, it should work. Right? I'm trying to get more details, but my tmux session was flooded with "ISR stack overflowed by at least 16 bytes." at some point.

Originally, I wanted to understand why the RIOT example works using tapsetup, but fails every time in a single hop scenario in our testbed. The following looks "suspicious"

At some point the stdout seems to be redirect to stdin (?) which is something I noticed before in other cases using RIOTs pyterm.

Can somebody confirm this behaviour?

TIA Michael

[mfrey]

The issue is triggered by

236     DEBUGMSG_CFWD(INFO, "  incoming interest=<%s>%s nonce=%"PRIi32" from=%s\n",
237                   ccnl_prefix_to_str((*pkt)->pfx,s,CCNL_MAX_PREFIX_SIZE),
238                   ccnl_suite2str((*pkt)->suite), nonce,
239                   ccnl_addr2ascii(from ? &from->peer : NULL));

in file ccnl_fwd.c.

[mfrey]

The problem is quite simple. RIOT maps the logging macros to "printf" (see ./core/include/log.h in RIOT and ccnl-riot-logging.h in ccn-lite). Passing NULL to %s in printf is undefined behaviour and this is apparently messing up the output of the shell.

I'll open a dedicated issue for the printf/logging problem.

[mfrey]

The function ccnl_addr2ascii is called with a loopback face, i.e.

122 static struct ccnl_face_s *loopback_face;

which was initialised as a local face

467 loopback_face = ccnl_get_face_or_create(&ccnl_relay, -1, NULL, 0);

Hence, the call of

239                   ccnl_addr2ascii(from ? &from->peer : NULL));

is

239                   ccnl_addr2ascii(0);

since sock->peer is 0 and since it is none of the socket types in the switch statement (AF_*) it returns NULL.