October 22, 2017

Theo Arends' replacement firmware for the Sonoff WiFi switch logs error and information messages to the serial port and to its webserver by default. It can also log debug messages. More importantly, it can send all these messages to a syslog host 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.

The configuration of the firmware on the switch must be changed but this is quite simple to do. 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. Changing the settings of rsyslog
  2. Enabling Error Logs on Sonoff
  3. More about rsyslog

  1. Changing the settings of rsyslog
  2. Theo Arends' Sonoff 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.

    pi@domo:~ $ sudo nano /etc/rsyslog.conf
    # provides UDP syslog reception $ModLoad imudp $UDPServerRun 514

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

    pi@domo:~ $ sudo systemctl restart rsyslog

    Just for the fun of it, I listed the files in the log directory /var/log ordered from the oldest to the last modified and then I looked at the content of deamon.log.

    pi@domo:~ $ cd /var/log pi@domo:/var/log $ ls -ltr ... -rw-r----- 1 root adm 76859 Oct 23 02:28 daemon.log -rw-r----- 1 root adm 8332 Oct 23 02:35 user.log -rw-r----- 1 root adm 292271 Oct 23 02:37 syslog -rw-r----- 1 root adm 258443 Oct 23 02:37 messages -rw-r----- 1 root adm 179161 Oct 23 02:37 kern.log pi@domo:/var/log $ cat daemon.log Oct 23 02:24:03 domo systemd[1]: Stopping System Logging Service... Oct 23 02:24:03 domo systemd[1]: Starting System Logging Service... Oct 23 02:24:03 domo systemd[1]: Started System Logging Service.

    This confirms that the daemon was restarted and it should now receive UDP messages over the network.

  3. Enabling Error Logs on Sonoff
  4. The web interface of a Sonoff device running Theo Arends' replacement firmware (1) firmware can be used to enable logging messages to syslog. As usual, the interface is reached by entering the device IP address in a web browser. Once the main page is reached, click on the Configuration button (left panel on the figure below) and then on the Configure Logging button (middle panel below).

    In the Logging parameters page (right panel) enter the IP address of the syslog host or its name if it can be resolved on the local area network. That means replacing the default dumus1 value shown above in the right panel.

    Normally, I would suggest setting the Syslog level to 1 Error. However, 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 Sonoff 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, let look at the user log on the server.

    pi@domo:$ cat /var/log/user.log ... Oct 23 02:32:23 sonoff-5511 ESP-MQTT: stat/sonoff/RESULT = {"POWER":"OFF"} Oct 23 02:32:23 sonoff-5511 ESP-MQTT: stat/sonoff/POWER = OFF

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

    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.

  5. Changing the settings of rsyslog
  6. When I looked up information about syslog on the Raspberry Pi it was surprising how little there was about the installed rsyslog and how most seem to prefer to install 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.

    Naturally, I wanted to get the proper documentation for the daemon but it was not clear to me which version was installed on Raspian Jessie Lite. It is a bit complicated to find out.

    Start two ssh sessions. In the first, use the tail command to get the latest additions to the syslog log.

    pi@domo:~ $ tail -f /var/log/syslog
    ... Oct 23 01:32:43 sonoff-5511 ESP-mDNS: Service found on domo ip 192.168.1.22 port 1883 Oct 23 01:33:00 sonoff-5511 ESP-MQTT: Attempting connection... Oct 23 01:33:01 sonoff-5511 ESP-mDNS: Query done with 1 mqtt services found

    Then restart the rsyslog daemon in the second ssh terminal.

    pi@domo:~ $ sudo systemctl restart rsyslog

    Additional information should now be displayed in the first terminal

    Oct 23 01:34:40 domo systemd[1]: Stopping System Logging Service... Oct 23 01:34:40 domo rsyslogd: [origin software="rsyslogd" swVersion="8.4.2" x-pid="401" x-info="http://www.rsyslog.com"] exiting on signal 15. Oct 23 01:34:40 domo rsyslogd: [origin software="rsyslogd" swVersion="8.4.2" x-pid="1042" x-info="http://www.rsyslog.com"] start

    This confirms that Raspian has the latest version of rsyslog: version 8.4.2.

    (Source for this is a post on Dec 02, 2011 by teifler entitled What version do I have?)

    The home site of The rocket-fast system for log processing is http://www.rsyslog.com/. Interestingly there is a configuration wizard on that site. Try just adding the UDP input module. You will see that the configuration file it suggests is quite different from the model found in Debian.

    # This configuration has been generated by using the 
    # rsyslog Configuration Builder which can be found at: 
    # http://www.rsyslog.com/rsyslog-configuration-builder/
    #
    # Default Settings
    
    # Load Modules
    module(load="imudp")
    module(load="imuxsock")
    
    # rsyslog Templates
    
    # rsyslog Input Modules
    input(type="imudp" 
    	 port="")

    This is, most likely, because rsyslog is being used as a "drop in" replacement for syslogd. The latter's syntax is being used.

    Some worry about rsyslog memory usage. It is a multi-threaded application with each thread taking up considerable memory for its runtime stack; 8MB per thread on the Raspberry Pi (source: Reducing memory usage. I tried following advice from Jesse Johnson on how to reduce the stack size of each thread but without success. Apparently, /etc/default/rsyslog is not read by rsyslogd in Debian Jessie.

    Checking on actual memory usage seems to put this problem in perspective.

    pi@domo:~ $ sudo cat /proc/`pidof rsyslogd`/smaps ... be9ca000-be9eb000 rwxp 00000000 00:00 0 [stack] Size: 132 kB Rss: 16 kB Pss: 16 kB Shared_Clean: 0 kB Shared_Dirty: 0 kB Private_Clean: 0 kB Private_Dirty: 16 kB Referenced: 16 kB Anonymous: 16 kB AnonHugePages: 0 kB ShmemPmdMapped: 0 kB Shared_Hugetlb: 0 kB Private_Hugetlb: 0 kB Swap: 0 kB SwapPss: 0 kB KernelPageSize: 4 kB MMUPageSize: 4 kB Locked: 0 kB VmFlags: rd wr ex mr mw me gd ac

    The actual stack size of a thread is considerably less than 8 MB if I interpret correctly the printout and the documentation T H E /proc F I L E S Y S T E M.

    Another often mentioned problem with the log files is related to the limited number of write cycles that can be performed on an SD card. 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 negligeable, 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.


    Note

    (1) I know, that Sonoff-MQTT-OTA-Arduino is end of life firmware and that Theo Arends has moved on to Sonof-Tasmota. I will be receiving a few more Itead devices and perhaps at that time I will try that newer version. (Back)