Show by Label

Saturday, July 21, 2018

_HowTo: Tracing activity on a remote ESP8266 with an RPi

I have a monitoring system in my home that tracks temperatures, humidity, air particles (pollution) air pressure, my central heating system, and my not-so-smart utility meter.

All the sensors are based on ESP8266 SBC's and use the MQTT protocall to send their sensor date to a Raspi server that further manipulates the data, puts in it various RRDTOOL databases and also sends the data to a Lighttpd webserver so we can look at the results with other devices.

I recently upgraded my utility meter monitoring to include a light sensor that tracks the LED pulses that are an indication of the actual wattage used. The time between two pulses is used to calculate that number.

When I added this functionality, I also changed the ESP8266 from a WEMOS R2 mini to a WEMOS D1 mini light. This version does not have the Flash ROM on board, so I removed the code that allowed me to save error data in between reboots.

After running the system for a while, I noticed that the server did not get any MQTT client updates anymore.  When tracing the Python script on the server, I saw that no more messages were coming in. They just stopped. However, the ESP was still running, because I use the built-in LED as a visual indicater when a certain timing loop finished.

Unfortunately, the breakdown happened irregularly. Although I use Over The Air updating for the firmware, I dragged my notebook over to the utility closet and powered the ESP from a USB port. I then used the serial monitor of the Arduino IDE to see what was happening. I typically sprinkle a lot of Serial.println statements in the code to get a feel for the flow. I also collect error data and send that using the MQTT protocall to the Raspi server. I use PuTTY to sign in to the Raspi and trace the log using tail -f "log filename". I also have a MQTT test program running on another RPi to just monitor all MQTT traffic. This showed that the utility ESP continued to send it's data, but the server just didn't get it.

I made some changes to the firmware but was unlucky tracing the code on my laptop in the closet, and got frustrated when the notebook went to sleep and I lost my trace. I had to come up with another way to monitor the ESP serial statements remotely, and for longer periods.

The solution is actually quite simple.
Setup an RPi to monitor the serial activity on the TXD pin of the ESP8266 with the RXD pin located on the RPi GPIO header with a Python script, and log that data to a file. The RPi is connected to the ESP in the closet by two wires, one from the TXD pin on the ESD to the RXD on the RPi, and obviously another wire to connect the grounds together.

After monitoring everything for a while, I noticed a software watchdog problem in my code. I use a watchdog to break out of a loop if the serial communication with the IR sensor to the meter gets stuck.  The ESP tracing indicated a timing shift in the main loop that probably caused the MQTT transmissions to break. I thought that I prevented that from happening, but alas, after adding some more fail-safe pieces and checks in the main loop, things started to work again.

If you like what you see, please support me by buying me a coffee: https://www.buymeacoffee.com/M9ouLVXBdw


Here is the Python script running on the RPi to log the ESP serial transmission activity:

#!/usr/bin/python
#---------------------------------------------------------------------
# Name:        serial_monitor.py
# Purpose:     Serial port monitoring (of an ESP8266) on a RaspberryPi
#
# Author:      paulv
#
# Created:     20-07-2018
# Copyright:   (c) paulv 2018
# Licence:     <your licence>
#---------------------------------------------------------------------

# -*- coding: utf-8 -*-

from __future__ import print_function
import serial
import logging
import logging.handlers
import sys
import os
import traceback


# To enable the serial port on the GPIO connector, use raspi-config or:
# sudo nano /boot/config.txt
# enable_uart=1
# reboot

port = "/dev/ttyAMA0"
serialPort = serial.Serial(port, baudrate=115200, timeout=10.0)

# data path is on a USB stick to protect the SD card
data_path = "/mnt/my_data/"

# -- Logger definitions
LOG_FILENAME = data_path+"esp.log"
LOG_LEVEL = logging.INFO  # Could be e.g. "INFO", "DEBUG", "ERROR" or "WARNING"


class MyLogger(object):
    '''
    Replace stdout and stderr with logging to a file so we can run this script
    even as a daemon and still capture all the stdout and stderr messages in the log.

    '''
    def __init__(self, logger, level):
            """Needs a logger and a logger level."""
            self.logger = logger
            self.level = level

    def write(self, message):
            # Only log if there is a message (not just a new line)
            # typical for serial data with a cr/lf ending
            if message.rstrip() != "":
                    self.logger.log(self.level, message.rstrip())
    return


def init():
    global logger, handler

    print ("Setting up the logger functionality")
    logger = logging.getLogger(__name__)
    logger.setLevel(LOG_LEVEL)
    handler = logging.handlers.TimedRotatingFileHandler(LOG_FILENAME, when="midnight", backupCount=7)
    formatter = logging.Formatter('%(asctime)s %(levelname)-8s %(message)s')
    handler.setFormatter(formatter)
    logger.addHandler(handler)

    # pipe the stdout and stderr messages to the logger
    sys.stdout = MyLogger(logger, logging.INFO)
    sys.stderr = MyLogger(logger, logging.ERROR)
    return


def main():
    print("Serial logger for the ESP8266")

    init()

    print("Opened port", port, "for serial tracing")

    try:
        while True:
            ser_input = serialPort.readline()
            print(ser_input)

    except KeyboardInterrupt: # Ctrl-C
        print("\nCtrl-C - Terminated")
        os._exit(1)

    except Exception as e:
        sys.stderr.write("Got exception: %s" % (e))
        print(traceback.format_exc())
        os._exit(1)


if __name__ == '__main__':
    main()