Log for debug purposes

[pozz]

I don't repeat here what is written there[1]. I found trice library and
I find it interesting to emit log messages for debug purposes, avoiding
printf execution on the target.

What I don't like is patching my code before compiling. This step delays
the build process and could mess up the repository, even if is simple to
un-patch the code before committing.

Do you apply other strategies?

I'm thinking to introduce this type of log in one of my application
where the firmware runs on an embedded platform indirectly connected to
Internet. I mean the main MCU is connected to another Internet-connected
device by a RS485 bus.

It could be very useful to receive logs from the main MCU through Internet.


[1] https://github.com/rokath/trice

[David Brown]

Post by pozz
I don't repeat here what is written there[1]. I found trice library and
I find it interesting to emit log messages for debug purposes, avoiding
printf execution on the target.
What I don't like is patching my code before compiling. This step delays
the build process and could mess up the repository, even if is simple to
un-patch the code before committing.
Do you apply other strategies?
I'm thinking to introduce this type of log in one of my application
where the firmware runs on an embedded platform indirectly connected to
Internet. I mean the main MCU is connected to another Internet-connected
device by a RS485 bus.
It could be very useful to receive logs from the main MCU through Internet.
[1] https://github.com/rokath/trice

I would not use a system that changed my source code - it's just out of
the question for me. I'm fine with /generation/ of source code files as
part of a build process, but not /changing/ code I have written. So if
I were making a system like this, I would definitely not have it change
the source code.

Suppose you want to trace calls to the "new_position" function in your
source code file "positioning.c". With trice, you'd have something like:

void new_position(uint32_t x, uint32_y, int16_t a)
{
trice("Moved to new position %lud, %lud, %d", x, y, a);
...
}

After the patching, you get a parameter "iD(1234)" added to that macro.

My way to handle this would be that you write :

trice(new_position, "Moved to new position %lud, %lud, %d", x,
y, a);


Here, I'd be using a definition of the macro "trice" to convert this to:

trice_new_position(x, y, a)

The pre-processing step, the equivalent of "trice insert", would run
through the file "positioning.c" and generate files
"positioning.trace.json" and "positioning.trace.h". The id would be
generated from a 32-bit hash (say 1234) of "positioning.c" and
"new_position", and the json file would include an entry with the hash,
the filename, function name and line number, the format string, and the
names of the parameters. The header file would contain a line:

#define trice_new_position(x, y, a) do_trice_3(1234, x, y, a)

And do_trice_3() would be an inline function that sends out the trace on
the uart (or whatever).


The file "positioning.c" would have a line #include
"positioning.trice.h". The generated files (including that header)
would be in the build directory, not the source directory, and generated
automatically by the makefile whenever the C code changed.


This would give you everything you get from the "trice" library, but
without any patching or unpatching, and with the trace generation
updated automatically as part of the "make" process.

I think it could be done a bit smarter, using _Generic macros to handle
detection of the types of the parameters so that sizes get handled
automatically.


In real work now, however, I'd use C++ to avoid any need of modifying
the source code or generating header files. (You would still need to
chew through the source code to make the json file or other input to the
PC side of the tracer. But I think if portability is not an issue, that
could be handled by having the "trice" macros put the information in a
special elf section that is then read by the tracer program.)

[pozz]

Post by David Brown

Post by pozz
I don't repeat here what is written there[1]. I found trice library
and I find it interesting to emit log messages for debug purposes,
avoiding printf execution on the target.
What I don't like is patching my code before compiling. This step
delays the build process and could mess up the repository, even if is
simple to un-patch the code before committing.
Do you apply other strategies?
I'm thinking to introduce this type of log in one of my application
where the firmware runs on an embedded platform indirectly connected
to Internet. I mean the main MCU is connected to another
Internet-connected device by a RS485 bus.
It could be very useful to receive logs from the main MCU through Internet.
[1] https://github.com/rokath/trice

I would not use a system that changed my source code - it's just out of
the question for me.  I'm fine with /generation/ of source code files as
part of a build process, but not /changing/ code I have written.  So if
I were making a system like this, I would definitely not have it change
the source code.

This is the same reason I didn't completely like that project. However
it remains interesting.

Post by David Brown
Suppose you want to trace calls to the "new_position" function in your
void new_position(uint32_t x, uint32_y, int16_t a)
{
    trice("Moved to new position %lud, %lud, %d", x, y, a);
    ...
}
After the patching, you get a parameter "iD(1234)" added to that macro.
    trice(new_position, "Moved to new position %lud, %lud, %d", x,
                y, a);
    trice_new_position(x, y, a)
The pre-processing step, the equivalent of "trice insert", would run
through the file "positioning.c" and generate files
"positioning.trace.json" and "positioning.trace.h".  The id would be
generated from a 32-bit hash (say 1234) of "positioning.c" and
"new_position", and the json file would include an entry with the hash,
the filename, function name and line number, the format string, and the
#define trice_new_position(x, y, a) do_trice_3(1234, x, y, a)
And do_trice_3() would be an inline function that sends out the trace on
the uart (or whatever).
The file "positioning.c" would have a line #include
"positioning.trice.h".  The generated files (including that header)
would be in the build directory, not the source directory, and generated
automatically by the makefile whenever the C code changed.
This would give you everything you get from the "trice" library, but
without any patching or unpatching, and with the trace generation
updated automatically as part of the "make" process.
I think it could be done a bit smarter, using _Generic macros to handle
detection of the types of the parameters so that sizes get handled
automatically.

Sure it could be an improvement.

Post by David Brown
In real work now, however, I'd use C++ to avoid any need of modifying
the source code or generating header files.  (You would still need to
chew through the source code to make the json file or other input to the
PC side of the tracer.  But I think if portability is not an issue, that
could be handled by having the "trice" macros put the information in a
special elf section that is then read by the tracer program.)

Too complex for me to follow this arguments.

[pozz]

Post by David Brown

Post by pozz
I don't repeat here what is written there[1]. I found trice library
and I find it interesting to emit log messages for debug purposes,
avoiding printf execution on the target.
What I don't like is patching my code before compiling. This step
delays the build process and could mess up the repository, even if is
simple to un-patch the code before committing.
Do you apply other strategies?
I'm thinking to introduce this type of log in one of my application
where the firmware runs on an embedded platform indirectly connected
to Internet. I mean the main MCU is connected to another
Internet-connected device by a RS485 bus.
It could be very useful to receive logs from the main MCU through Internet.
[1] https://github.com/rokath/trice

I would not use a system that changed my source code - it's just out of
the question for me.  I'm fine with /generation/ of source code files as
part of a build process, but not /changing/ code I have written.  So if
I were making a system like this, I would definitely not have it change
the source code.
Suppose you want to trace calls to the "new_position" function in your
void new_position(uint32_t x, uint32_y, int16_t a)
{
    trice("Moved to new position %lud, %lud, %d", x, y, a);
    ...
}
After the patching, you get a parameter "iD(1234)" added to that macro.
    trice(new_position, "Moved to new position %lud, %lud, %d", x,
                y, a);
    trice_new_position(x, y, a)
The pre-processing step, the equivalent of "trice insert", would run
through the file "positioning.c" and generate files
"positioning.trace.json" and "positioning.trace.h".  The id would be
generated from a 32-bit hash (say 1234) of "positioning.c" and
"new_position", and the json file would include an entry with the hash,
the filename, function name and line number, the format string, and the
#define trice_new_position(x, y, a) do_trice_3(1234, x, y, a)
And do_trice_3() would be an inline function that sends out the trace on
the uart (or whatever).
The file "positioning.c" would have a line #include
"positioning.trice.h".  The generated files (including that header)
would be in the build directory, not the source directory, and generated
automatically by the makefile whenever the C code changed.
This would give you everything you get from the "trice" library, but
without any patching or unpatching, and with the trace generation
updated automatically as part of the "make" process.
I think it could be done a bit smarter, using _Generic macros to handle
detection of the types of the parameters so that sizes get handled
automatically.

The drawback of your approach is that the developer must invent every
time a different trace name. Suppose you want to emit several trace
messages inside a function:

void new_position(uint32_t x, uint32_y, int16_t a)
{
trice(new_position_enter, "Entering new position(%lud, %lud, %d)",
x, y, a);
if (a == 0) {
trice(new_position_a0, "Hey, you pass a wrong parameter for a");
}
if ((cr_x != x) || (cr_y != y) || (cr_a != a)) {
trice(new_position_changed, "The new position really changed
(cr=%lud,%lud,%d)", cr_x, cr_y, cr_a);
cr_x = x;
cr_y = y;
cr_a = a;
}
...
}

Here the postfixs "new_position_enter", "new_position_a0",
"new_position_changed" are needed to create a different ID by
calculating the 32-bits hash of the string "position.c <postfix>".

What about using the line number instead of a custom postfix that the
developer must invent at every trace macro?

Surely the line number is not constant during developing, but I don't
think it's important. The tracer tool running on the host could reload
the json file (with IDs) when it changes.
In this case, every build is linked to a trace json file, like a symbol
file.

[David Brown]

Post by pozz

Post by David Brown

Post by pozz
I don't repeat here what is written there[1]. I found trice library
and I find it interesting to emit log messages for debug purposes,
avoiding printf execution on the target.
What I don't like is patching my code before compiling. This step
delays the build process and could mess up the repository, even if is
simple to un-patch the code before committing.
Do you apply other strategies?
I'm thinking to introduce this type of log in one of my application
where the firmware runs on an embedded platform indirectly connected
to Internet. I mean the main MCU is connected to another
Internet-connected device by a RS485 bus.
It could be very useful to receive logs from the main MCU through Internet.
[1] https://github.com/rokath/trice

I would not use a system that changed my source code - it's just out
of the question for me.  I'm fine with /generation/ of source code
files as part of a build process, but not /changing/ code I have
written.  So if I were making a system like this, I would definitely
not have it change the source code.
Suppose you want to trace calls to the "new_position" function in your
void new_position(uint32_t x, uint32_y, int16_t a)
{
     trice("Moved to new position %lud, %lud, %d", x, y, a);
     ...
}
After the patching, you get a parameter "iD(1234)" added to that macro.
     trice(new_position, "Moved to new position %lud, %lud, %d", x,
                 y, a);
     trice_new_position(x, y, a)
The pre-processing step, the equivalent of "trice insert", would run
through the file "positioning.c" and generate files
"positioning.trace.json" and "positioning.trace.h".  The id would be
generated from a 32-bit hash (say 1234) of "positioning.c" and
"new_position", and the json file would include an entry with the
hash, the filename, function name and line number, the format string,
#define trice_new_position(x, y, a) do_trice_3(1234, x, y, a)
And do_trice_3() would be an inline function that sends out the trace
on the uart (or whatever).
The file "positioning.c" would have a line #include
"positioning.trice.h".  The generated files (including that header)
would be in the build directory, not the source directory, and
generated automatically by the makefile whenever the C code changed.
This would give you everything you get from the "trice" library, but
without any patching or unpatching, and with the trace generation
updated automatically as part of the "make" process.
I think it could be done a bit smarter, using _Generic macros to
handle detection of the types of the parameters so that sizes get
handled automatically.

The drawback of your approach is that the developer must invent every
time a different trace name. Suppose you want to emit several trace

Yes.

Whether it is a drawback or an advantage (it can make it a lot easier to
cross-reference between the logs and the source code) is subjective.

Post by pozz
void new_position(uint32_t x, uint32_y, int16_t a)
{
    trice(new_position_enter, "Entering new position(%lud, %lud, %d)",
x, y, a);
    if (a == 0) {
      trice(new_position_a0, "Hey, you pass a wrong parameter for a");
    }
    if ((cr_x != x) || (cr_y != y) || (cr_a != a)) {
      trice(new_position_changed, "The new position really changed
(cr=%lud,%lud,%d)", cr_x, cr_y, cr_a);
      cr_x = x;
      cr_y = y;
      cr_a = a;
    }
    ...
}
Here the postfixs "new_position_enter", "new_position_a0",
"new_position_changed" are needed to create a different ID by
calculating the 32-bits hash of the string "position.c <postfix>".
What about using the line number instead of a custom postfix that the
developer must invent at every trace macro?

It would be possible, perhaps, to use __FILE__ and __LINE__ within the
new trice macro to generate names automatically.

Post by pozz
Surely the line number is not constant during developing, but I don't
think it's important.

Agreed.

Post by pozz
The tracer tool running on the host could reload
the json file (with IDs) when it changes.
In this case, every build is linked to a trace json file, like a symbol
file.