Lightweight Syslog Implementation

Development archive
1

Hi everyone,

a month ago I wrote a small lightweight syslog/syslogd implementation for RIOT and added a pull request[1]. This mainly is for a private/university project and since I may got some spare time in the next weeks to continue working on this, I thought about getting some feedback from this list beforehand. First and most important is the question if this feature is still of interest for the RIOT community? It was originally mentioned in a feature request back in 2015[2] and may be obsolete by this time. Anyway, I think RIOT could benefit from a syslog implementation with udp remote logging feature and hope I can continue working on this.

A few more details about the implementation:

- I separated the syslog implementation and the syslogd implementation used for log shipping.

- I implemented the syslog implementation as described in the glibc documentation[3] for compatibility reasons.

- The implementation should be rfc5424[4] compatible.

- The syslog implementation itself is able to log to console.

- The syslogd implementation adds support for log shipping to file and via udp.

If this is still of interest i have some question about the general design and would be happy if someone could give me feedback about the following topics/design decisions

- I implemented the syslogd implementation as a RIOT pkg. The reasons are that the syslogd implementation should be easily exchangeable and is not needed for basic functionality such as logging to console. I more or less see the syslogd implementation as a proof of concept and it may need a lot more work (especially compile time configurable outputs would be cool to minimize the binary size).

- The syslogd implementation gets its input via RIOT IPC. Which is not the most generic way but way better than writing an abstraction for /dev/log which needs FS support and stuff. On the downside, any syslogd needs an implementation for RIOT IPC inputs.

- Should the syslog implementation be included into an existing logging API?

I appreciated any feedback you may have.

Regards,

Robin

[1] https://github.com/RIOT-OS/RIOT/pull/11362

[2] https://github.com/RIOT-OS/RIOT/issues/2376

[3] https://www.gnu.org/software/libc/manual/html_node/Syslog.html

[4] https://tools.ietf.org/html/rfc5424

2

Hi Robin,

First and most important is the question if this feature is still of interest for the RIOT community? It was originally mentioned in a feature request back in 2015[2] and may be obsolete by this time.

IMO the syslog API itself should not be used for new or RIOT-targeting applications. Having it available makes porting existing code easier, thus I still think it is valid to have it available.

Having the syslog-over-udp functionality available is pretty awesome, especially if it could be hooked up to the existing LOG_* framework. Have you tried that?

- Should the syslog implementation be included into an existing logging API?

See above. There's an example log backend in sys/log/log_printfnoformat showing how to create a logging backend module. It should be straigh forward to use syslog there.

Kaspar

3

Hi Kaspar,

IMO the syslog API itself should not be used for new or RIOT-targeting applications. Having it available makes porting existing code easier, thus I still think it is valid to have it available. Having the syslog-over-udp functionality available is pretty awesome, especially if it could be hooked up to the existing LOG_* framework. Have you tried that?

That's a good point. It should be fairly easy to add additional wrapper functionality to use the LOG_* Framework. I will have a look into it.

I also thinking about moving the syslogd functionality directly into RIOT (and not as a pkg). This would enable the user to only use the outputs (UDP, File, Terminal etc.) relevant for a specific application (and thus reducing binary sizes).

Maybe I can also fit the syslogd into the existing LOG_* API.

Robin

4

IMO the syslog API itself should not be used for new or RIOT-targeting applications...

Except it already is:

#define log_write(level, ...) printf(__VA_ARGS__)

and

static inline void log_write(unsigned level, const char *format, ...) {

While syslog has

void syslog(int priority, const char *format, ...);

So the existing log framework is almost the same as syslog, but with different names (it makes sense, there are not that many ways of doing logging.)

BTW, this thing can be quite useful when logging to serial: by having a backend that sends logs as messages in a queue one can prevent messages sent simultaneously from stepping over each other.

Regards,

Juan.

5

Hi Kaspar,

i just found some time to have a short look into the logging API. I tried to compile my tests with the log_printfnoformat module. As i understand the interface, I just need to add “USEMODULE += log_printfnoformat” to my application?

Sadly this leads to a compile time error: “fatal error: log_module.h: No such file or directory”. Looks like the includes not work as expected. I will have a look later and maybe create an issue/PR if it’s not a problem caused by my application.

Besides that it should be fairly easy to move the syslog implementation to the LOG API since the interfaces already are very similar as Juan mentioned. Only problem here is that syslog as implemented in gLibc expects a user to issue a call to openlog first. Maybe I can make the call to openlog implicit and thus make it compatible to both API‘s. Another solution could be to extend the log module with a bootstrap/init function which defaults to do nothing in most cases.

One problem with the generic LOG approach that comes to my mind is that it looks like a all or nothing approach. When I implement the syslog implementation as a log module it wouldn’t be possible anymore for the user to decide which logs should be shipped via syslog and which logs only should be send over serial line. Further, it would be critical to start syslog with serial logging by default to not loose any messages before the syslogd thread started. Maybe I would keep the syslog module in place as a separate module and only make a wrapper in the log API which depends on the syslog module. That way one could use both approaches.

You got any thoughts on this ?

Thanks

Robin

6

Robin,

Only problem here is that syslog as implemented in gLibc expects a user to issue a call to openlog first. Maybe I can make the call to openlog implicit and thus make it compatible to both API‘s.

The standard works in our favor here: "The use of openlog() is optional" and " The use of closelog() is optional". We can have no-ops for both functions:

#define openlog(ident, option, facility) (void)((ident), (option), (facility))

Another solution could be to extend the log module with a bootstrap/init function which defaults to do nothing in most cases.

Should not be needed if we do what unix syslog does, initialize it on the first call to syslog() if necessary.

One problem with the generic LOG approach that comes to my mind is that it looks like a all or nothing approach.

I suggest the choice should not be between serial backend and syslog backend, but rather between serial backend (used for most simple applications) and IPC/message queue backend. At the end of the quie is the logic deciding how the packet should be sent.

An advantage of this approach is that is is also useful for serial-only loggers where one wants to ensure strings don't intermingle. Also the current implementation of uart logging inherits the blocking characteristics of the UART, meanings that logging blocks until the message has been sent.

Of course, most applications are fine with just writing directly to UART backend and having the queue by default would be overkill.

When I implement the syslog implementation as a log module it wouldn’t be possible anymore for the user to decide which logs should be shipped via syslog and which logs only should be send over serial line.

With a queue, the decision can be made according to the PID of the message sender. Or, even better, according to the facility value set by that thread in openlog().

BTW, there is an option in UNIX called LOG_CONS:

> LOG_CONS Write directly to the system console if there is an error while sending to the system logger.

The more we discuss this topic, the more I'm convinced we cannot overlook it if we want RIOT to be practical for large-scale deployments.

Regards,

Juan.

7

Hi Juan,

The standard works in our favor here: "The use of openlog() is optional" and " The use of closelog() is optional". We can have no-ops for both functions:

#define openlog(ident, option, facility) (void)((ident), (option), (facility))

Should not be needed if we do what unix syslog does, initialize it on the first call to syslog() if necessary.

Looks like i missed this line. Thanks a lot for pointing out. I just pushed an update to my PR yesterday, which simply invokes openlog on demand if it wasn't done yet. I would not implement it using a noop, but rather stay with an implicit call, since we may want to let the user to have the choice to use a identity string which is not equal to the threads name. So yea, basically the unix way. I will have another look in the standard, maybe i missed some more information.

I suggest the choice should not be between serial backend and syslog backend, but rather between serial backend (used for most simple applications) and IPC/message queue backend. At the end of the quie is the logic deciding how the packet should be sent.

An advantage of this approach is that is is also useful for serial-only loggers where one wants to ensure strings don't intermingle. Also the current implementation of uart logging inherits the blocking characteristics of the UART, meanings that logging blocks until the message has been sent.

Of course, most applications are fine with just writing directly to UART backend and having the queue by default would be overkill.

I am not sure if i understand you approach correctly. I just try to describe it in my own words and you may correct me.

We got two cases:

1. Normal case as it is now: Any invocation of LOG() uses the default implementation which defaults to printf/UART

2. More sophisticated approach: Additional LOG_MQUEUE module which overwrite the LOG() function (as in log_printfnoformat) with a threaded backend implementing a message queue. If a message gets send via LOG() the message is transferred to the backend's queue and the backend writes the log request to the appropriate logger (UART or syslog for example).

The only problem i see is how the backend would distinguish between a message for serial logging and a message for something else like syslog, since both logging request would be done by invoking LOG(level,"message").

I could either extend the LOG interface, which would probably break a lot of things and would introduce additional complexity in most cases or I could treat calls to LOG as UART log request and calls to (for example) syslog() as syslog log requests. Both calls would send a message to the backend, but set a different flag depending on the target. Then a hook functionality in the backend could decide how message are dispensed.

BTW, there is an option in UNIX called LOG_CONS:

> LOG_CONS Write directly to the system console if there is an error while sending to the system logger.

I already implemented this functionality, but I think it would not help us here, since it only is aimed to allow console logging if no syslogd implementation is available.

Robin

8

The only problem i see is how the backend would distinguish between a message for serial logging and a message for something else like syslog, since both logging request would be done by invoking LOG(level,"message").

the "level" parameter of our current API is just a level. In unix, on the other hand, one has "priority". From the man page of syslog()

> The priority argument is formed by ORing together a facility value and a level value (described below).

The good news is that this ORing scheme is is compatible to what we are doing now (it is like we are currently defaulting facility to zero).

On the other side of the message queue you will have:

- The PID of the originating thread. In a way this means that "LOG_PID" is always on. - The (facility, level) selected for that message (can that live in the "type" field?)

With that information an appropriate policy can be implemented. How is that policy specified and what is the policy is a matter that if think is better to ignore for now so that we don't make too many assumptions.

Regards,

Juan.

9

Hi,

IPC/message queue backend.

RIOT's message queues are a poor choice for this, as they can only send pointers around. That means the calling thread needs to allocate memory for the log message and keep that valid until the message has been processed, which means that it has to block. Or, the calling thread allocates and the logd thread frees, which again requires allocations.

Better use a synchronised ringbuffer or pipe or tsrb.

Kaspar

10

I think i now get the idea from what you and Juan wrote. Sadly I was a little busy the last weeks and didn't find time yet to continue work on this.

As soon as I developed a concept and find time to implement it i will come back to you. Most likely in late August.

Thanks a lot for the extensive feedback. If everything works as intended we may be able to add a nice new feature to RIOT.

Regards,

Robin

11

Hi All,

As soon as I developed a concept and find time to implement it i will come back to you. Most likely in late August.

Luckily i got some spare time to continue developing this PR [1] and i am curios what you are thinking so far.

What is already implemented:

- Implemented an additional LOG backend (log_mqueue), which spawns a thread that reads from a RIOT pipe. Calls to LOG() are written into this pipe and the thread dispatches the incoming LOG requests.

For the dispatch logic I use a very basic static array with function pointers. Messages are dispatched according to their facility value. By default the array is initialized to a default handler which itself is a wrapper to printf.

- Extending the syslog implementation to overwrite the dispatch array with a syslog handler function. Every facility != 0 is dispatched to the syslog implementation if the syslog module is enabled.

- Implementing four test cases which reflects the new LOG logic:

1. tests/log: LOG as implemented right now. Calls to LOG() uses the default implementation provided by log.h.

2. tests/log_mqueue: Uses the message queue backend as described above. LOG() request are dispatched to the default handler.

3. tests/log_mqueue_syslog: Overwrites the default handler with the syslog implementation. LOG() request with a facility != 0 are dispatched to syslog. LOG() request without facility value uses the default handler (printf).

4. tests/syslog: Syslog implementation without log_mqueue backend. LOG() request with any facility value are dispatched to the default LOG() wrapper as implemented in log.h (printf). Calls to syslog() uses the syslog implementation directly. This is used for compatibility reasons. A syslogd implementation is used to ship the logs over UDP.

I am curios if this reflects whats you described in the previous discussion?

The implementation needs a little bit of rework. Obvious problems right now are:

- Priority values in log.h and priority values in syslog.h are not the same by now. This could lead to Messages being accepted by LOG() but discarded by syslog(). Maybe i could change the implementation provided by log.h without loosing backwards compatibility.

- The dispatch logic needs further rethinking. By now an auto_init function plainly overwrites the whole dispatcher array with facilities != 0. Also a linked list may be more feasible to allow more than a single module to attach onto a single facility value.

- The syslog implementation hooks itself to log_mqueue as soon as the log_mqueue module is used. This may should be more configurable.

- Configurability of queue sizes could be better.

- Missing Documentation.

[1] Add basic syslog implementation by crest42 · Pull Request #11362 · RIOT-OS/RIOT · GitHub

Robin