delegate messages from base handler instead from singleton

[2bndy5]

Scenario

I've been thinking about how I could use this lib to log JSON data to a file stream while using a separate logger for prompting the user or log event actions to another stream. @wmarkow this is what I really meant when I asked how the user would log to different streams - I meant logging different messages to different streams, not all messages to all streams.

Currently this cannot be done because the rf24Logging singleton is the only object that accepts packed arguments (...). The base handler requires that the packed args be initialized using stdarg.h's VA (variadic args) lists (which is currently only performed by the singleton before passing the message/data to the base handler).

Solution

If we replace RF24Logging.log() with RF24Logging.getHandler() then all the helper macros that point to rf24Logging.log() could instead point to rf24Logging.getHandler().log(). And the base handler's log() function would take the packed args instead of a pre-initialized VA list.

this way multiple streams can still be managed by the singleton:

std::ofstream fout;
OStreamLogger file_logger((ostream*)&fout);
NativePrintLogger serial_logger;

fout.open("example.JSON");
rf24Logging.sethandler(&file_logger);
RF24Log_log(0, "", "{%\n\tPurpose_of_life: \"%d\"%\n}", 42); // dump the JSON data to a file

// in the context of another lib, keeping the handler consistent would be very important
void SomeLib::func() {
    RF24BaseHandler* prev_handler = rf24Logging.getHandler(); // save the previous handler
    rf24Logging.setHandler(serial_logger);                    // set the handler to use a different stream
    RF24Log_info("JSON data dumped to file example.JSON");    // log the event on a different stream
    rf24Logging.setHandler(prev_handler);                     // restore handler for file stream
}

Side effects

This would essentially make the singleton almost obsolete since you could instantiate the handler and pass the log messages/data directly to the handler's revised log() function. Remember, there's nothing stopping the end-user from defining their own helper macros.

#define LOG_INFO(og, fmt, ...) (serial_logger.log(RF24LogLevel::INFO, og, fmt, ##__VA_ARGS__))
#define LOG_INFO_4ALL(og, fmt, ...) (RF24Log_info(og, fmt, ##__VA_ARGS__))

// in the context of another lib, independently managing a logger is possible
void SomeLib::func() {
    LOG_INFO("JSON data dumped to file example.JSON");  // log the event on a different stream
}

Alternative idea

overload the handler's log() to also accept packed args vs VA lists. This idea may cost more (depending on implementation), and still has the same side effect noted above.

[2bndy5]

Again I'm coming from a python background on this

In python's std logging lib, the module (called logging) has global functions that only get used to declare the loggers. Like our lib, the loggers themselves are used to setup logger properties like output streams, log level, header format, etc.

After the setup is all done, logging messages is done directly from the loggers that were setup. If you want all messages to go to all streams, then you have to write a custom method that forwards data to all the loggers you want.

Multiple loggers are managed by having the user assign a name in the form of a string (logging.addHandler("some.name")). Then calling logging.getHandler("some.name") returns the logger that was declared with that name (if any). Hint: the name assigned to the loggers is basically used as the equivalent to our lib's vendorId parameter, however our vendorId is less limited.

---

This issue is kind of a prelude to my linked list idea for implementing multiple loggers using a base handler extension.

[wmarkow]

I've been thinking about how I could use this lib to log JSON data to a file stream while using a separate logger for prompting the user or log event actions to another stream. @wmarkow this is what I really meant when I asked how the user would log to different streams - I meant logging different messages to different streams, not all messages to all streams.

Ok, now I understand your scenario. From the unified log library we have two cases:

• a developer of some library, like RF24 for example.
• a developer of the final application. This app gets compiled, linked and loaded to the target board. The app is using i.e. RF24 library

Both library and application may use RF24Log for logging purposes. My expectation is that library developer is only allowed to use the allowed API methods for logging purposes - other words he may only use those macros:

• RF24Log_error
• RF24Log_warn
• RF24Log_info
• RF24Log_log

He shouldn't manipulate with handlers instances, so calling rf24Logging.setHandler(serial_logger) from the library code this should be forbidden. This method should be reserved only only for the final application where the developer need/may to provide a proper implementation of RF24LogBaseHandler to handle correctly the log messages. Other words, the logging API doesn't know where the log message will be logged.

The idea of splitting log messages between two different streams (like some messages should go to file and some other should go to the screen) is quite unfamiliar to me however I understand that some developers wish to have such a solution. To support this scenario the library developer needs to give a hint to the final application about where he wishes to redirect this specific log messages. The final developer may provide a custom RF24LogBaseHandler implementation which will use those hints to redirect log messages between two (or even more) different streams. With our current API we have three possibilities of such a hint:

• by using a specific vendor id. Let's take an RF24 as an example. Normally the vendor id could be like RF24, but for messages that should be redirected to the file we could use RF24::file as a vendor id.
• by using a custom log level. This seems to be also a good way to start but at some point the library developer needs to decide which log levels to use for this purpose and after some time he may have a mess in the log levels. I think the usage of vendor id seems to be better idea.
• by using a special tag in the log message, i. e. every message that should be logged to file should start with "FILE:"

@2bndy5 , what do you say?

[2bndy5]

@wmarkow I was hoping to get your feedback before attacking this scenario...

so calling rf24Logging.setHandler(serial_logger) from the library code this should be forbidden

This whole time I've been imagining any library that offers a logging solution (via our RF24Log lib) would have to expose a new function like RF24::setLogger(). But I suppose it would be better to have the RF24 examples actually demonstrate (at least in setup()) how to setup the RF24Log lib's rf24Logging directly.

With our current API we have three possibilities of such a hint:

Of the proposed "hints" you offer, I really only like the custom log level because it would be the easiest to implement and least intensive on the CPU.

• I've said before that looking for a special FormatSpecifier (like %m) would not be trivial to implement. Additionally, the implementation would actually have to span more than 1 file (FormatSpecifier::isFmtOption() and RF24LogAbstractStream::appendFormat())
• reserving a special suffix in the vendorId seems like it would limit the arbitrary/flexible utility of the vendorId feature (I like it the way it is now). Imagine if a lib has a function named file() (as vague as it would be), and the function passes a vendorId like SomeLib::file. It would be hard to pick a suffix that wouldn't conflict with whatever the lib developer may need to use.

---

I have done some experimenting with the DualStream example on the refactor branch. Currently the example adjusts only the log level for the second handler while keeping the log level for the DualHandler consistent. This adjustment effectively can be used to control which logger outputs what. However outputing different data to different streams is still not possible. Notice also that I played with the rf24Logging.setHandler() so that the user prompts don't print twice - please review the DualStreams example.

[wmarkow]

@wmarkow I was hoping to get your feedback before attacking this scenario...

I didn't meant to attack this scenario. I just wanted to point that that setting the handler from the inside of SomeLib is a bad idea, because then SomeLib library will have knowledge about where the log massages are really redirected. In my opinion SomeLib shouldn't have a direct impact on that.

reserving a special suffix in the vendorId seems like it would limit the arbitrary/flexible utility of the vendorId feature (I like it the way it is now).

Yes, you are right. I also like the vendor id in the way as it is now. I just pointed some ideas on how we can implement your scenario with redirecting some logs to a different stream (handler).

This whole time I've been imagining any library that offers a logging solution (via our RF24Log lib) would have to expose a new function like RF24::setLogger().

I still think that the library code shouldn't manipulate with log handlers. It should just log the message. Where the message is redirected it should be configured in the final application by setting a correct (appropriate to the developer and/or end user needs) RF24LogBaseHandler implementation. Calling RF24::setLogger() should be not allowed from the libraries code. With this, the logging abstraction is decoupled from the logging handling implementation and the logging library API may be used across different platforms.

Of the proposed "hints" you offer, I really only like the custom log level because it would be the easiest to implement and least intensive on the CPU.

I think this is the way. You - as a developer of SomeLib - can pick some log level and use it to log your JSON data. In the documentation you can (or even should?) add a note that those JSON data are logged under a specific log level XYZ so the end developer can take of them in a special way. This is some kind of indirect impact to where the messages will be redirected - it is just a "hint" - but it is still an end developer decision how to handle logs entries. The end application developer (which is also you in this specific case) can implement then a custom RF24LogBaseHandler which will redirect all messages from SomeLib and log level XYZ to a different stream. If I wanted to use your SomeLib library I can decide in my own RF24LogBaseHandler what to do with those "special" messages. I can redirect them to some other stream or - if I decide that I do not need them - I will just skip them. In this way the log messages from SomeLib will work good as well for you as for me.

[2bndy5]

I didn't meant to attack this scenario.

No offense taken. I just used the word "attack" as a euphemism (as in "take on this challenge"). Sorry if I misled you (we Irish seem to love using euphemisms almost as much as British slang 😆)

I still think that the library code shouldn't manipulate with log handlers.

I was trying to agree with you, not contradict you. Maybe my thoughts didn't translate into words correctly.

Let's get back to the topic of this issue

In the documentation you can (or even should?) add a note that ...

I wouldn't add a note about this in the docs. Instead, I would like to write tutorials about how to:

• "roll-your-own logger"
• "roll-your-own handler extension"

I could then use the scenario proposed in this issue as part of the "roll-your-own logger" tutorial instead of providing (with lib distribution) an already coded solution. With that said, I think we can remove the RF24LogDualHandler.* files (and consequently the entire _handlerext folder and the DualStreams.ino example) and instead incorporate that scenario into the "roll-your-own handler extension" tutorial. BTW, I got this idea from wading through the CMake docs and it's beginner tutorial 😄

As these tutorials would be part of the docs, all source files used in the tutorials would live in the "docs" folder (not the "src" folder). I believe there is a mechanism in doxygen that allows using specific lines from a separate source file in the docs' code blocks. That way it would be really easy to maintain the tutorials and let the user just copy-n-paste the finished solution from the tutorials' source (then modify it to their liking).

those JSON data are logged under a specific log level XYZ so the end developer can take of them in a special way

Trying to apply this idea to this issue's proposed scenario. The "in a special way" would be directing the data to a different output stream. So, I'm not sure how reserving a log level in a custom handler or custom logger (handler + stream) would satisfy this issue's proposed scenario... Maybe if a single handler had access to 2 different output streams, then any message designated for a reserved level could direct the data to a file instead of whatever the other output stream is. (?? I'm just thinking out loud here)

---

@wmarkow Did you get a chance to examine/run the experimental changes I made to the DualStreams example?

[2bndy5]

I believe there is a mechanism in doxygen that allows using specific lines from a separate source file in the docs' code blocks

https://www.doxygen.nl/manual/commands.html#cmdsnippet

[2bndy5]

I took a peek at what this would look like locally. I didn't like how that turned out.

I think the intended purpose was to avoid having to change the rf24Logging handler if the dev wanted to only see a specific vendor's msgs. I'm now trying to work with the idea that vendor filtering can be done from a handler extension (like _handlerext/DualLogHandler).

I thought that namespaces might be an alternative to strcmp()-ing a given vendorID with a stored vendorID (or possibly a set of stored vendorIDs), but a bool flag from a handler extension compared to the MSB of the handler's level might better save the memory and CPU cycles.