Log publication specified by the convention

[nicola-lunghi]

Log channel

define a log channel for getting debugging information from the device

homie/[device-id]/logs/fatal
homie/[device-id]/logs/error
homie/[device-id]/logs/warn
homie/[device-id]/logs/info
homie/[device-id]/logs/debug
homie/[device-id]/logs/trace

[nicola-lunghi]

This could also be implemented using the broadcast channel?

homie/$broadcast/logs/error

[fermuch]

Doesn't it make more sense to implement logs outside of homie, but instead as a node?

I'd implement it as:

homie/someid/logs/$name → "ESP32 Logs"
homie/someid/logs/$type → "log"
homie/someid/logs/$properties → "level,fatal,error,warn,info,debug,trace"

Where with the property level you could set the current level (e.g. "info"), so you can switch to enable/disable more verbosity.

The downsides I see are: MQTT doesn't guarantee the order of the messages is the same on both sides, and once there's a new line (or whatever you use as buffer) you'll end up rewriting the old message. In case of a crash, you'll still have the last message though, because of the retain property.

[ingoogni]

$logs messages should be part of the device state.

sensor states/logs should be dealt with on sensor level. The device (ESPxxxx) may be running fine but the attached sensor may be in a non responsive state. My CO2 sensors for example take a while befor they start measuring data that make sense.

[timpur]

I like the idea, just not sure if this should be part of the convention or not... maybe something that isnt required for implementations but is optional. It does make sense to have it at device and node level. Lets keep discussing :)

[euphi]

I already did something like this for Homie-ESP8266: https://github.com/euphi/HomieLoggerNode

It uses a Log/$function/$level topic, so you can subscribe or filter the loglevel per function.

[nicola-lunghi]

so could be accepted?

[ThomDietrich]

The idea in general is not bad. It would help if you could write down a solid proposal to discuss about 😉

[nicola-lunghi]

Implement a log feature for homie

homie/[device-id]/$logs/[level]

where level could be
error
warn
info
debug
trace

[jamesmyatt]

It would be great if more of these special channels were really just specialised types of Node, like @euphi 's example.

[nicola-lunghi]

or (for implementing masquerading) (but a bit verbose
(t=trace d=debug i=info e=error)
for an error message
homie/[device-id]/$logs/t/d/i/w/e "error"

warning
homie/[device-id]/$logs/t/d/i/w "error"
info
homie/[device-id]/$logs/t/d/i "error"
debug
homie/[device-id]/$logs/t/d "error"
trace
homie/[device-id]/$logs/t "error"

this could permit to subscribe for example to (only info messages):
homie/+/$logs/t/d/i

or (info warn error)
homie/+/$logs/t/d/#

[lorenwest]

I'm not a fan of this $logs convention. The problem is the firmware doesn't know if anyone is subscribed, so it has to place every log message at all levels onto the MQTT bus, just in case someone happens to be interested.

I wouldn't put any device that implements this onto my MQTT bus because of the sheer chatter.

If logging were available, I'd want to instruct the device to send them, vs. having the device send every log at every level. We'd need a settable attribute for this.

[jamesmyatt]

@lorenwest , that's how MQTT works. If you don't want your device broadcasting when no-one's listening, then MQTT is the wrong protocol. What would happen when your consumer disconnects? However, I agree with your sentiment about the amount of chatter.

You might want a settable parameter that determines what level of messages end up in the logs channel.

I think I'd prefer a single logs topic, i.e. homie/+/$logs and have the level name at the start of the payload, e.g.: ERROR:BME280 unreachable

[ThomDietrich]

To be honest I am still unsure about the special purpose of the log idea.

I use a normal node to publish debugging data. I am also able to enable/disable it at will. Why? Because debugging info is for troubleshooting!... The same goes for log data.

Why do we need log topics? Why do we need them as fixed part of the convention? If correctly configured, your device offers the right set of nodes and properties to publish all relevant data that you'd otherwise dump to a log. A well implemented node doesn't need a log.

@jamesmyatt gave a good example. The described case should be solved like so:
homie/mydevice/mysensor/reachable <- "false".

[lorenwest]

You might want a settable parameter that determines what level of messages end up in the logs channel.

Good idea @jamesmyatt. In fact, I would suggest making this parameter required if you implement logging messages.

My day job is corporate software deployment, and to @ThomDietrich comment, logs are valuable beyond debugging for production deployments. We deal with tens of millions of log entries each day, which triggered my sensitivity to the chatter on an MQTT network purpose-designed for small devices and low bandwidth.

[ThomDietrich]

I am also a proud owner of an elasticsearch (ELK) instance to manage server logs. Neat if you need to deal with complex systems and the verbosity of logs.

The homie convention is primarily oriented at simple sensor/actor-nodes interacting with a controller entity, and the discoverability of the former by the latter.

I am not convinced a well configured node needs any kind of additional log for productive use. Every relevant property of the device can be published as property.
For debugging purposes a regular node/property can be used.

Please discuss

[lorenwest]

While I agree with @ThomDietrich on the general value of logs in this context, the one thing that could be valuable is defining the settable parameter for targeting the logs to output. A well designed node would do that, and I could see value in having it part of the Homie convention so general purpose logging receivers could be written to configure any node that supports homie logging.

[lorenwest]

On the other hand, MQTT (especially when coupled with the discoverability of Homie) is itself a logging framework, and shouldn't need an additional logging layer on top of it. The only thing about this whole discussion I see valuable is differentiating sensor data from sensor meta-data in a way to control meta-data chatter.

[timpur]

IMHO, we should also keep in mind homie is ment to be a light weight convention. We can't accept every feature and nor should we. There is nothing stopping this feature being implemented as a node and I still think it should be.

Maybe what the convention can to do is define some recommendations for nodes and node layouts, maybe in the FAQ or something? Another thing that we could do is also alow for creation of some special system type nodes that start with a $node-id?

[euphi]

I'm also unsure if a logging mechanism should be part of the convention. Maybe there could be a appendix to the convention with informal "best practices"?

But even if we do, what would be the proposal?

homie/{$device}/Log/{$function}/{$level} or homie/{$device}/Log/{$level}/{$function} ?

And Log or $log ?

@lorenwest Logging is very important for debugging. On some of my device I test new software by OTA-update, so I have no serial connection. Logging on MQTT is then just convenient.
Furthermore there is not always a "normal" channel to publish errors. A temperature node would just stop publishing values in case of reading errors, but you can give an error message (e.g. I2C failure) on a logging channel.

Of course it is good practice to don't enable DEBUG or INFO log levels by default.

[jamesmyatt]

I'm certainly in favour of implementing logging by "best practice", rather than an explicit rigid feature. The regular Homie nodes already provide the necessary features, and messages are essentially already logs.

[lorenwest]

Absolutely @euphi - I didn't mean to suggest it wasn't valuable for debugging, just that it does have value beyond debugging. In fact, debugging may be the primary use case.

In the context of debugging, it absolutely is necessary to set output levels and have DEBUG and INFO disabled by default. If a device supports this optional homie logging convention, here's my recommendation:

homie/{$device}/$log/{$level}/{$function}

$log vs. Log because it's metadata, not primary sensor data.

Then for configuring logs, I would recommend

homie/{$device}/$log_level/set (DEBUG | INFO | ...)

That would set the logging level for all {$functions} within a {$device}. Once you've set the chattiness based on $log_level, you can use standard MQTT subscription to filter the {$function} you want to view.

[euphi]

homie/{$device}/$log_level/set (DEBUG | INFO | ...)

would be not-compliant to a regular Node.

So
homie/{$device}/$log/level/set (DEBUG | INFO | ...) is better.

My implementation for homie-esp8266 already does this (but with "..Log/Level/..), see the source

[ThomDietrich]

I'd also suggest a "best-practice" documentation. As chance has it I recently added the first entry of that kind: https://github.com/homieiot/convention#faq - feel free to add a section for logging!

@euphi @lorenwest So far $-IDs are reserved for attributes in the convention. @lorenwest you called log data metadata but in the existing context I'd argue that this is not the case.

[davidgraeff]

There seem to be an agreement of not adding logging to the spec, but to the FAQ section instead.
Please head over to the website repository and make a pull request for adding this best-practice section.

https://github.com/homieiot/convention-website/tree/master/docs/FAQ