2020-10-25
md
Syslog Server on Raspbian and Tasmota Remote Logging
Removing Nuisance Messages in Raspberry Pi Syslog-> <-The original version of this post for Raspbian Jessie
Remote Logging and Email Notification->

Tasmota, Theo Arends' replacement firmware for the Sonoff Basic and many other WiFi switches, logs error and information messages to the serial port and to the console on its web server by default. It can also log messages to a syslog compatible server where they will be stored and can then be reviewed. While this would be specially valuable with error messages, it is not the default behaviour. As will be shown, it is a simple matter to change the configuration in Tasmota.

The second part of logging messages from Tasmota or any other application is to have a reachable syslog server running. As my home automation server is a Raspberry Pi running Debian, it makes sense to use its default syslog daemon rsyslog.

Table of Contents

  1. Enabling UDP in rsyslog
  2. Enabling Error Logs in Tasmota
  3. More About rsyslog

Enabling UDP in rsyslog toc

Theo Arends' Tasmota firmware uses the traditional User Datagram Protocol (UDP on port 514) when logging over the network. Accordingly, the rsyslog configuration file needs to be modified to enable reception of UDP messages. This is done by removing the comment symbol, #, in front of the UDP reception lines. I used the nano editor to change the file.

pi@raspberrypi:~ $ sudo nano /etc/rsyslog.conf

# /etc/rsyslog.conf Configuration file for rsyslog. # # For more information see # /usr/share/doc/rsyslog-doc/html/rsyslog_conf.html ################# #### MODULES #### ################# module(load="imuxsock") # provides support for local system logging module(load="imklog") # provides kernel logging support #module(load="immark") # provides --MARK-- message capability # provides UDP syslog reception module(load="imudp") <-- remove leading '#" input(type="imudp" port="514") <-- remove leading '#" ...

If the configuration file looks completely different then you may be using an older configuration file. The original version of this post, written in the days of Debian Jessie, may be helpful.

Then the daemon needs to be restarted so that the modified configuration file is used.

pi@raspberrypi:~ $ sudo systemctl restart rsyslog

Just for the fun of it, I listed the last 10 entries in the daemon log file.

pi@raspberrypi:~ $ tail /var/log/daemon.log Sep 5 23:49:41 raspberrypi systemd[813]: Reached target Basic System. Sep 5 23:49:41 raspberrypi systemd[813]: Reached target Default. Sep 5 23:49:41 raspberrypi systemd[813]: Startup finished in 273ms. Sep 5 23:49:41 raspberrypi systemd[1]: Started User Manager for UID 1000. Sep 5 23:49:41 raspberrypi systemd[1]: Started Session c1 of user pi. Sep 5 23:52:01 raspberrypi systemd[1]: Stopping System Logging Service... Sep 5 23:52:01 raspberrypi systemd[1]: rsyslog.service: Succeeded. Sep 5 23:52:01 raspberrypi systemd[1]: Stopped System Logging Service. Sep 5 23:52:01 raspberrypi systemd[1]: Starting System Logging Service... Sep 5 23:52:01 raspberrypi systemd[1]: Started System Logging Service.

This confirms that the daemon was restarted and it should now receive UDP messages over the network. This is easily verified if logger is installed on a Linux machine on the local network.

michel@hp:~$ logger -n raspberrypi.local -d "my message"

List the content of the syslog log file to verify that the message was received by the Raspberry Pi.

pi@raspberrypi:~ $ tail /var/log/syslog ... Sep 5 23:52:01 raspberrypi systemd[1]: Stopping System Logging Service... Sep 5 23:52:01 raspberrypi rsyslogd: [origin software="rsyslogd" swVersion="8.1901.0" x-pid="348" x-info="https://www.rsyslog.com"] exiting on signal 15. Sep 5 23:52:01 raspberrypi systemd[1]: rsyslog.service: Succeeded. Sep 5 23:52:01 raspberrypi systemd[1]: Stopped System Logging Service. Sep 5 23:52:01 raspberrypi systemd[1]: Starting System Logging Service... Sep 5 23:52:01 raspberrypi rsyslogd: imuxsock: Acquired UNIX socket '/run/systemd/journal/syslog' (fd 3) from systemd. [v8.1901.0] Sep 5 23:52:01 raspberrypi rsyslogd: [origin software="rsyslogd" swVersion="8.1901.0" x-pid="862" x-info="https://www.rsyslog.com"] start Sep 5 23:52:01 raspberrypi systemd[1]: Started System Logging Service. Sep 5 23:59:38 hp michel my message

It's even more fun if the --follow (or -f) command line option is specified.

pi@raspberrypi:~ $ tail -f /var/log/syslog ...

In that case, tail does not exit and instead it displays new log messages as they come in. To close tail, use the CtrlC combination.

If Windows is being used, then the Adiscon logger could be used in a similar way. First the command prompt has to be invoked (cmd) in order to use the command line utility.

C:\Users\michel\testing>logger -l 192.168.1.22 -m udp "my message" Adiscon logger V1.3 - see www.monitorware.com/logger/ for details. Logging to 192.168.1.22:0

Note the different command line switches and that the zeronconf URL rapsberrypi.local could not be resolved in a vanilla install of Windows 10 running in an Oracle Virtual Box. Nevertheless, the test worked. There may be GUI applications that perform the same task in Windows, I have not had time nor the inclination to search beyond the first utility that I found. Besides, Adiscon has close ties to the rsyslog project (the majority shareholder and president of the company is Rainer Gerhards who is the creator of the software), so its utility could be considered "official".


Enabling Error Logs in Tasmota toc

The web interface of a device running Theo Arends' Tasmota replacement firmware can be used to enable logging of messages to syslog. As usual, the interface is reached with a web browser by entering the device IP address or its zeronconf URL <hostname>.local if mDNS is enabled in the firmware.

  1. In the main page, click on the Configuration button (left panel on the figure above).
  2. In the configuration page, click on the Configure Logging button (middle panel above).
  3. In the Logging parameters page (right panel) enter the IP address of the syslog host or its name if it can be resolved.
  4. Check that the Syslog port matches the port chosen in the rsyslog configuration file. I did not change the default port which is 514.
  5. Enter the syslog priority level for messages. I suggest setting it to 1 Error to avoid flooding the journal system with messages from the device.
  6. Finally don't forget to press on the Save button.

While setting the Syslog level to 1 Error makes sense, it would be difficult to test that everything is working, so temporarily set the level to 2 Info. Then click on the Save button. To test, just toggle the device on and off. This can be done in the initial page, Main menu, or by pressing the button on the device itself or by using the home automation software. To make sure it all works, look at the user log on the server.

pi@raspberrypi:$ cat /var/log/user.log ... Sep 5 21:43:20 Test-light ESP-MQT: domoticz/in = {"idx":140,"nvalue":1,"svalue":"","Battery":95,"RSSI":6} Sep 5 21:43:20 Test-light ESP-MQT: stat/Test-light/RESULT = {"POWER":"ON"} Sep 5 21:43:20 Test-light ESP-MQT: stat/Test-light/POWER = ON Sep 5 21:43:23 Test-light ESP-MQT: domoticz/in = {"idx":140,"nvalue":0,"svalue":"","Battery":94,"RSSI":6} Sep 5 21:43:23 Test-light ESP-MQT: stat/Test-light/RESULT = {"POWER":"OFF"} Sep 5 21:43:23 Test-light ESP-MQT: stat/Test-light/POWER = OFF

The information should also appear in another log file: /var/log/syslog.

pi@raspberrypi:$ tail /var/log/user.log ... Sep 5 21:43:20 Test-light ESP-MQT: domoticz/in = {"idx":140,"nvalue":1,"svalue":"","Battery":95,"RSSI":6} Sep 5 21:43:20 Test-light ESP-MQT: stat/Test-light/RESULT = {"POWER":"ON"} Sep 5 21:43:20 Test-light ESP-MQT: stat/Test-light/POWER = ON Sep 5 21:43:23 Test-light ESP-MQT: domoticz/in = {"idx":140,"nvalue":0,"svalue":"","Battery":94,"RSSI":6} Sep 5 21:43:23 Test-light ESP-MQT: stat/Test-light/RESULT = {"POWER":"OFF"} Sep 5 21:43:23 Test-light ESP-MQT: stat/Test-light/POWER = OFF

If all is working go back to Configure Logging and set the the Syslog level to 1 Error. Do not forget to also click on the Save button.

More About rsyslog toc

It was surprising how little information could be found about rsyslog on the the Raspberry Pi. It seemed that many chose to replace it with syslog-ng. Since this was my first foray into the world of syslog, I decided to get acquainted with the default daemon before replacing it. After all, the persons looking after Debian must have a good reason for their choice. You can read rsyslog author's own take on the subject posted in July 2007: [W]hy does the world need another syslogd? (aka rsyslog vs. syslog-ng).

The version of rsyslog installed in the latest (August 8, 2020) release of Raspberry Pi OS (32-bit) Lite is 8.1901.

pi@raspberrypi:~ $ $ uname -a Linux raspberrypi 5.4.51-v7+ #1333 SMP Mon Aug 10 16:45:19 BST 2020 armv7l GNU/Linux pi@raspberrypi:~ $ rsyslogd -v rsyslogd 8.1901.0 (aka 2019.01) compiled with: PLATFORM: arm-unknown-linux-gnueabihf PLATFORM (lsb_release -d): FEATURE_REGEXP: Yes GSSAPI Kerberos 5 support: Yes FEATURE_DEBUG (debug build, slow code): No 32bit Atomic operations supported: Yes 64bit Atomic operations supported: Yes memory allocator: system default Runtime Instrumentation (slow code): No uuid support: Yes systemd support: Yes Number of Bits in RainerScript integers: 64 See https://www.rsyslog.com for more information.

This January 22, 2019 release of rsyslog is not the newest. Version v8.2010.0 was made available only five days ago. However 8.1901 is the most recent version in the Raspbian repository and it is sufficiently up to date.

pi@raspberrypi:~ $ sudo apt-cache policy rsyslog rsyslog: Installed: 8.1901.0-1 Candidate: 8.1901.0-1 Version table: *** 8.1901.0-1 500 500 http://raspbian.raspberrypi.org/raspbian buster/main armhf Packages 100 /var/lib/dpkg/status

Some were worried about memory usage in rsyslog. The project Wiki, which is no longer available, did say that the daemon is a multi-threaded application with each thread potentially taking up 8MB of memory for its stack. The huge limit on the per thread stack size remains in effect in the current version of rsyslog in Raspbian / Raspberry Pi OS.

pi@raspberrypi:~ $ cat /proc/`pidof rsyslogd`/limits Limit Soft Limit Hard Limit Units Max cpu time unlimited unlimited seconds Max file size unlimited unlimited bytes Max data size unlimited unlimited bytes Max stack size 8388608 unlimited bytes ...

I just ignored the problem over the last two and a half years, without negative consequences as far as I can tell. I tried following Jesse Johnson's instruction on limiting the thread stack size as described in his article entitled Reducing memory usage of rsyslog but failed. Apparently, the /etc/default/rsyslog file which exists is ignored by the systemd service manager. I think the proposed fix was for Linux systems using the init service manager.

In March of 2019, Reimer Prochnow, who is much more knowledgeable than myself, send an e-mail giving instruction on the correct way to set the stack limit. First, create a service override configuration file with the desired maximum stack size.

pi@raspberrypi:~ $ sudo mkdir /etc/systemd/system/rsyslog.service.d pi@raspberrypi:~ $ sudo nano /etc/systemd/system/rsyslog.service.d/override.conf
[Service] LimitSTACK=131072

Then reload the service configuration files and restart the service.

pi@raspberrypi:~ $ sudo systemctl daemon-reload pi@raspberrypi:~ $ sudo systemctl restart rsyslog

Finally, check that the lower limit is enforced.

pi@raspberrypi:~ $ cat /proc/`pidof rsyslogd`/limits Limit Soft Limit Hard Limit Units Max cpu time unlimited unlimited seconds Max file size unlimited unlimited bytes Max data size unlimited unlimited bytes Max stack size 131072 131072 bytes ...

Success! Hopefully, setting a limit on the stack size will not be detrimental; time will tell.

In a recent post, Rainer Gerhards enjoins us to [a]void overly-large in memory queues. Unfortunately, this is over my head. As before I will just ignore this, hoping that the default settings work .

Some are uneasy about log files saved to SD cards because of the limited number of write cycles that can be performed on these memory devices. There seems to be a divergence of opinion between those that calculate the theoretical impact of all those additions to the logs, which is apparently negligible, and those that insist they have lost SD cards because of too many writes. Since the latter could very well be an example of a post hoc ergo propter hoc argument, I have decided to not worry about SD card wear. Besides, I am lazy and doing nothing suits me fine.

Removing Nuisance Messages in Raspberry Pi Syslog-> <-The original version of this post for Raspbian Jessie
Remote Logging and Email Notification->