Logging to SD card using MicroPython
Debugging MicroPython after removing the serial connection can be tricky. In this article, we will explore how to write your MicroPython print statements to a log file on a SD card for a typical ESP development board.
The goal is to:
- Log to the file as soon as possible
- First, log to SOC memory
- Then, log to the SD card
- Start out with normal prints (log to serial connection)
- Give logs a meaningful name
- Start with the run count
- Change to a date-time name file when information is available
Start a logger right away
While the goal is to log to an SD card file, we still want to see logs before that over the serial connection.
Therefore, we will make the logger available as soon as possible and fall back to normal print statements until a file is available.
We will start with a very simple logger (/debug/logger.py):
class Logger:
def __init__(self) -> None:
print('logger init')
super().__init__()
def print(self, *args):
print(*args)
The Logger instance is needed throughout your app, so we'll store it as a singleton (/singletons.py):
from debug.logger import Logger
_logger = Logger()
def get_logger():
if not _logger:
raise Exception('logger not yet set')
return _logger
We can then use the logger instance (/main.py):
from singletons import get_logger # Returns singleton Logger instance
logger = get_logger()
logger.print('We are in business')
Run counter
To distinguish between subsequent logs, we can include the run count in the log name. We'll need to get that count from somewhere that can survive reset and power cycles. So let's store the run count in a file.
The BootCounter class (debug/boot_counter.py) does this as follows:
/main.py:
from singletons import get_logger # Returns singleton Logger instance
class BootCounter:
count = 1
def __init__(self, path) -> None:
super().__init__()
logger = get_logger()
logger.print('opening file: ', path)
try:
file = open(path, 'r')
try:
line = file.readline()
if not line:
logger.print('no boot count found, starting from 1')
self.count = 1
else:
try:
count = int(line)
logger.print('read count from file: ', count)
self.count = count + 1
except Exception as e:
logger.print('error reading line: ', line, e)
self.count = 1
except Exception as e:
logger.print('problem processing boot count file', e)
finally:
file.close()
except OSError as e:
logger.print('problem opening file for reading', path, e)
try:
file = open(path, 'w')
try:
file.write(str(self.count))
logger.print('boot count written: ', self.count)
except Exception as e:
logger.print('problem writing boot count', e)
finally:
file.close()
except OSError as e:
logger.print('problem opening file for writing', path, e)
There's a lot going on in the BootCounter.
The gist is to start counting on 1 if our counter file is not found or is unreadable.
And when read we increment the count and try to write it back to file.
This can be run using:
from singletons import get_logger # Returns singleton Logger instance
from debug.boot_counter import BootCounter
logger = get_logger()
logger.print('main.py called')
boot_count_path = '/boot_count'
counter = BootCounter(boot_count_path)
log_file = f'log-{counter.count}.txt'
logger.print(log_file)
On the first run the file will not exist:
MPY: soft reboot
logger init
main.py called
opening file: /boot_count
problem opening file for reading /boot_count [Errno 2] ENOENT
boot count written: 1
log-1.txt
On subsequent runs we use the counter is read and incremented:
MPY: soft reboot
logger init
main.py called
opening file: /boot_count
read count from file: 1
boot count written: 2
log-2.txt
And in case the boot_count file is unreadable (in this example it contains "abc"), we'll fall back to count 1 and start over:
MPY: soft reboot
logger init
main.py called
opening file: /boot_count
error reading line: abc invalid syntax for integer with base 10
boot count written: 1
log-1.txt
Write logs to SD card with SOC memory fallback
The Logger class will keep track of the file it is writing to and use that if available.
First, the open_log_file function should be called.
After that, the log file can be moved.
The log contents are copied over manually.
The log contents are copied over manually.
This prevented an occasional EPERM error I was having on my board.
In your case, you might get away with a simple os.rename(old_path, new_path) call.
The full Logger class code (/debug/logger.py):
import os
class Logger:
_path = None
_file = None
def __init__(self) -> None:
print('logger init')
super().__init__()
def open_log_file(self, path):
"""
Write to initial log file
"""
self._path = path
self.print('opening log file: ' + self._path)
self._file = open(self._path, 'w')
self.print('logger log file opened')
def move_file(self, new_path):
"""
Move logs to another file, manually copies over file line by line
because `os.rename` sometimes errors out with a "EPERM" exception on my chip
"""
self.print('moving log file to: ' + new_path)
try:
self._file.close()
self._file = None
old_path = self._path
self._path = None
try:
old_file = open(old_path, 'r')
new_file = open(new_path, 'w')
lines = old_file.readlines()
for line in lines:
new_file.write(line)
self._file = new_file
self.print('log file moved: ', old_path, ' -> ', new_path)
self._path = new_path
finally:
old_file.close()
os.remove(old_path)
except Exception as e:
self.print('failed to move logs: ', e)
self._file = None
self._path = None
def print(self, *args):
message = ''
for x in args:
message += str(x) + ' '
if self._file:
print(message) # Also print so can be seen when debugging using serial connection
self._file.write(message + '\n')
self._file.flush() # We want our logs to be written immediately
else:
print('No log file yet, msg: ', message)
The main limitations here are that any logs written before writing to a file are not written to the file, and your main SOC memory can fill up quickly depending on your situation. For me, those limitations are acceptable, but you should be able to remedy both quite quickly.
Now that we have the Logger, we'll write the log to the onboard memory. That way, you can catch errors in the SD card mounting process and so on. After that, we can move our log files to the SD card.
The following code uses three log files. First, a temporary file is created with the run count in the name on the SOC memory. This is then moved to a temporary file with the same name on the SD card. After that, we can get the date and time and use that in the name for another file on the SD card. Finally, we set the ESP real time clock using the internet and the NTP protocol.
Here is how it all comes together (/main.py):
import time
from config import config
from connectivity.sd import mount_sd
from connectivity.time import set_ntp_time
from connectivity.wifi import connect_ssid
from debug.boot_counter import BootCounter
from singletons import get_logger
from util.folder import mkdir_if_not_exist
logger = get_logger()
logger.print('*** Not yet written to file ***')
counter = BootCounter('/boot_count')
mkdir_if_not_exist('/log')
logger.open_log_file(f'/log/run-{counter.count}.txt')
logger.print('*** written to SOC memory temporary file ***')
sd = mount_sd('/sd')
mkdir_if_not_exist('/sd/log')
logger.move_file(f'/sd/log/run-{counter.count}.txt')
logger.print('*** written to SD temporary log file ***')
connect_ssid(config.get('SSID'), config.get('PW'))
secs = set_ntp_time()
[year, month, mday, hour, minute, second, _, _] = time.localtime(secs)
name = f'{year}-{month}-{mday}-{hour}h{minute}m{second}s-run-{counter.count}.txt'
log_dir_path = '/sd/log'
new_path = f'/sd/log/{name}'
logger.move_file(new_path)
logger.print('*** written to SD card datetime log file ***')
Running the above (for the 39th time) produced:
- temp file /log/run-39.txt
- temp file /sd/log/run-39.txt, and
- the final file
/sd/log/2022-1-6-20h19m13s-run-39.txt
The contents of the final log file
logger log file opened
*** written to SOC memory temporary file ***
setting SDCard pins
mounting
sd contents: ['.Spotlight-V100', 'config.json', 'log', '.Trashes']
Creation of the directory /sd/log failed (probably exists)
moving log file to: /sd/log/run-39.txt
log file moved: /log/run-39.txt -> /sd/log/run-39.txt
*** written to SD temporary log file ***
connecting to network...
network config: ....
setting rtc time set using ntp server...
time set, secs: 694815553 , local: (2022, 1, 6, 20, 19, 13, 3, 6)
moving log file to: /sd/log/2022-1-6-20h19m13s-run-39.txt
log file moved: /sd/log/run-39.txt -> /sd/log/2022-1-6-20h19m13s-run-39.txt
*** written to SD card datetime log file ***
With that, you should have logging in your application that can be easily checked by reading the SD card. I hope these code snippets helped you out. Please let me know if they did or let me know of problems via Twitter.
And in case you are wondering, here are some of the utility functions used:
Util functions
Here is the code used to do some common stuff. The code isn't trying to catch every exception and such, but it should get the job done.
Mount sd card
Mounting an SD card is a matter of finding out which pins you need to use. For the Wemos Lolin D32 PRO those are pins 4, 18, 19, 23:
/connectivity/sd.py:
import os, machine
from singletons import get_logger
logger = get_logger()
def mount_sd(mount_dir):
"""
SD Mounting code for Wemos Lolin D32 PRO
:param mount_dir: path string, e.g.: /sd
:return:
"""
logger.print('setting SDCard pins')
try:
sd = machine.SDCard(slot=2, sck=18, mosi=23, miso=19, cs=4)
except OSError as e:
if e.errno == -259:
logger.print('error: -259, SPI already in use') # Happens sometimes on soft reboot
logger.print('resetting')
machine.reset()
logger.print('mounting')
os.mount(sd, mount_dir, readonly=False)
logger.print('sd contents: ', os.listdir(mount_dir))
return sd
Create directory if not yet existing
/util/folder.py:
import os
from singletons import get_logger
logger = get_logger()
def mkdir_if_not_exist(path):
try:
os.mkdir(path)
except OSError:
logger.print("Creation of the directory %s failed (probably exists)" % path)
Connect to WiFi
/connectivity/wifi.py:
from singletons import get_logger
logger = get_logger()
def connect_ssid(ssid, pw):
if not ssid or not pw:
logger.print('missing ssid/pw: ', ssid, pw)
return
import network
wlan = network.WLAN(network.STA_IF)
wlan.active(True)
if not wlan.isconnected():
logger.print('connecting to network...')
wlan.config(reconnects=2)
wlan.connect(ssid, pw)
while not wlan.isconnected():
pass
logger.print('network config:', wlan.ifconfig())
Set time using NTP library
/connectivity/time.py:
import ntptime
import time
from singletons import get_logger
logger = get_logger()
def set_ntp_time():
logger.print('setting rtc time set using ntp server...')
ntptime.settime()
secs = time.time()
logger.print('time set, secs: ', secs, ', local: ', time.localtime(secs))
return secs