Troubleshooting some issues when running the Terkin Datalogger on the LoPy4

[Andreas]

@Thias

48.6521 [terkin.sensor.core ] ERROR : 1-Wire hardware driver failed
Traceback (most recent call last):
  File "/flash/lib/terkin/sensor/core.py", line 277, in start
ImportError: no module named 'onewire.OneWire'

Line 277 in the current sensor/core.py looks like from onewire import OneWire for us. Can you confirm this is also true for you and matches the same thing on the device itself?

[Andreas]

@Thias

Traceback (most recent call last):
  File "main.py", line 43, in <module>
  File "main.py", line 38, in main
  File "/flash/lib/terkin/datalogger.py", line 176, in start
  File "/flash/lib/terkin/datalogger.py", line 329, in register_sensors
AttributeError: 'NoneType' object has no attribute 'name'

This indicates you might be running with an outdated settings.py. We just refactored this through Large refactoring · hiveeyes/terkin-datalogger@2a835be · GitHub and humbly ask you to adapt the sensors.system section like outlined within https://github.com/hiveeyes/hiveeyes-micropython-firmware/blob/master/settings.example.py#L205-L229.

[Andreas]

We just added another wave of refactoring through Improve multi-platform support · hiveeyes/hiveeyes-micropython-firmware@21314d9 · GitHub, so we also humbly ask you to pull the most recent thing from master.

[Thias]

@Andreas

So, we are humbly asking to use a firmware build without pybytes , which we just uploaded to https://packages.hiveeyes.org/hiveeyes/foss/pycom/LoPy4-1.20.1.r1-vanilla-0.1.0.tar.gz.

with

Board erased successfully in 20.4 seconds

and

Writing lopy4.bin at 0x00110000... (100 %)               
Hash of data verified.
Wrote 2027520 bytes (1051577 compressed) at 0x00010000 in 19.7 seconds (822.3 kbit/s)...

and

make install

I confirm the “network card not available error” is gone. Thanks for preparing the pybytesless firmware!

[Thias]

WiFi always needs two attempts to establish a connection

   13.8409 [terkin.device            ] INFO   : Starting networking
   13.8697 [terkin.network.wifi      ] INFO   : Starting stopwatch
   13.9666 [terkin.network.wifi      ] INFO   : Started stopwatch successfully
   14.0106 [terkin.network.wifi      ] INFO   : WiFi STA: Networking address (MAC): {'ap_mac': '80:7d:3a:93:65:01', 'sta_mac': '80:7d:3a:93:65:00'}
   14.0228 [terkin.network.wifi      ] INFO   : WiFi STA: Networking address (IP):  ('0.0.0.0', '0.0.0.0', '0.0.0.0', '0.0.0.0')
   14.0351 [terkin.network.wifi      ] INFO   : WiFi: Starting interface
   14.0464 [terkin.network.wifi      ] INFO   : WiFi: Using internal antenna
   14.0742 [terkin.device            ] INFO   : Start curating the garbage collector
   14.3673 [terkin.device            ] INFO   : Curating the garbage collector finished. Free memory: 2394304
   14.4658 [terkin.network.core      ] INFO   : Waiting for the network stack to come up within 5 seconds
   14.5229 [terkin.network.core      ] INFO   : Network stack ready
   14.5472 [terkin.network.core      ] INFO   : Starting mode server on 0.0.0.0:666
   19.5743 [terkin.api.http          ] INFO   : Setting up HTTP API
   19.7911 [terkin.api.http          ] INFO   : Starting HTTP server
   20.4807 [terkin.network.wifi      ] INFO   : WiFi STA: Connecting to configured networks: ['WerNet']. Attempt: #1
   20.5030 [terkin.network.wifi      ] INFO   : WiFi STA: Preparing connection to network "WerNet"
   20.5198 [terkin.network.wifi      ] INFO   : WiFi STA: Getting auth mode
   20.5913 [terkin.network.wifi      ] INFO   : WiFi STA: Auth mode from NVRAM with key=wa.9d66b1d414d4, value=3
   20.6116 [terkin.network.wifi      ] INFO   : WiFi STA: Auth mode is "3"
   20.6345 [terkin.network.wifi      ] INFO   : WiFi STA: Starting connection to "WerNet" with timeout of 30.0 seconds
   20.7520 [terkin.network.wifi      ] INFO   : WiFi STA: Waiting for network to come up within 29.997 seconds
   23.0801 [terkin.network.lora      ] INFO   : [LoRA] Not joined yet...
   24.0355 [terkin.network.wifi      ] INFO   : WiFi STA: Waiting for network to come up within 26.713 seconds
   25.6984 [terkin.network.lora      ] INFO   : [LoRA] Not joined yet...
   25.7161 [terkin.network.lora      ] INFO   : [LoRA] joined...
   27.0099 [terkin.network.wifi      ] INFO   : WiFi STA: Waiting for network to come up within 23.739 seconds
   28.2332 [terkin.network.lora      ] INFO   : [LoRa] socket created
   29.9835 [terkin.network.wifi      ] INFO   : WiFi STA: Waiting for network to come up within 20.766 seconds

...

   47.7789 [terkin.network.wifi      ] INFO   : WiFi STA: Waiting for network to come up within 2.969999 seconds
   50.7027 [terkin.network.wifi      ] ERROR  : Invoking "is_connected" failed
Traceback (most recent call last):
  File "/flash/lib/terkin/network/wifi.py", line 193, in is_connected
TimeoutError: Connection to AP Timeout!

   50.7909 [terkin.network.wifi      ] ERROR  : WiFi STA: Connecting to "WerNet" failed
Traceback (most recent call last):
  File "/flash/lib/terkin/network/wifi.py", line 241, in connect_stations
  File "/flash/lib/terkin/network/wifi.py", line 311, in connect_station
WiFiException: WiFi STA: Unable to connect to "WerNet"

   50.8319 [terkin.network.wifi      ] INFO   : WiFi STA: Forgetting NVRAM data for network "WerNet"
   50.9227 [terkin.network.wifi      ] ERROR  : WiFi STA: Connecting to any network candidate failed. Please check your WiFi configuration for one of the 1 station candidates.
   50.9454 [terkin.network.wifi      ] WARNING: Todo: We might want to buffer telemetry data to flash memory to be scheduled for transmission later.
   50.9794 [terkin.network.wifi      ] ERROR  : WiFi STA: Connecting to configured networks "['WerNet']" failed
Traceback (most recent call last):
  File "/flash/lib/terkin/network/wifi.py", line 177, in stay_connected
  File "/flash/lib/terkin/network/wifi.py", line 258, in connect_stations
WiFiException: WiFi STA: Connecting to any network candidate failed

   51.0679 [terkin.network.wifi      ] INFO   : WiFi STA: Retrying in 1.643164 seconds
   52.7294 [terkin.network.wifi      ] INFO   : WiFi STA: Connecting to configured networks: ['WerNet']. Attempt: #2
   52.7544 [terkin.network.wifi      ] INFO   : WiFi STA: Preparing connection to network "WerNet"
   52.7735 [terkin.network.wifi      ] INFO   : WiFi STA: Getting auth mode
   52.8464 [terkin.network.wifi      ] INFO   : WiFi STA: Unknown auth mode for network "WerNet", invoking WiFi scan
   52.8667 [terkin.network.wifi      ] INFO   : WiFi STA: Scanning for networks
   55.0350 [terkin.network.wifi      ] INFO   : WiFi STA: Networks available: ['NETGEAR85', 'WLAN-209719', 'Telekom_FON', 'Minionelch', 'FRITZ!Box 7560 DF', 'DIRECT-hqC48x Series', 'ShadowyPlanet', 'Mesh23', 'WerNet', 'freifunk-potsdam.de', 'devolo-f4068d8dc4d9', 'Potsdambabel', 'WLAN-728781', 'FRITZ!Box 7490 HKS', 'ARRIS-41A2', 'o2-WLAN35', 'Kuschelnetz', 'DIRECT-6C-HP OfficeJet Pro 6970', 'WLAN-EVS8XJ', 'TC-9BB6D', 'KDG-029D0', 'KabelBox-A0C8', 'o2-WLAN09']
   55.0860 [terkin.network.wifi      ] INFO   : WiFi STA: Storing auth mode into NVRAM with key=wa.9d66b1d414d4, value=3
   55.1090 [terkin.network.wifi      ] INFO   : WiFi STA: Auth mode is "3"
   55.1337 [terkin.network.wifi      ] INFO   : WiFi STA: Starting connection to "WerNet" with timeout of 30.0 seconds
   55.2497 [terkin.network.wifi      ] INFO   : WiFi STA: Waiting for network to come up within 29.998 seconds
   55.5621 [terkin.network.wifi      ] INFO   : WiFi STA: Connected to "WerNet" with IP address "192.168.188.40"
   55.6405 [terkin.network.wifi      ] INFO   : WiFi STA: Networking address (MAC): {'ap_mac': '80:7d:3a:93:65:01', 'sta_mac': '80:7d:3a:93:65:00'}
   55.6617 [terkin.network.wifi      ] INFO   : WiFi STA: Networking address (IP):  ('192.168.188.40', '255.255.255.0', '192.168.188.1', '192.168.188.189')   47.7789 [terkin.network.wifi      ] INFO   : WiFi STA: Waiting for network to come up within 2.969999 seconds
   50.7027 [terkin.network.wifi      ] ERROR  : Invoking "is_connected" failed
Traceback (most recent call last):
  File "/flash/lib/terkin/network/wifi.py", line 193, in is_connected
TimeoutError: Connection to AP Timeout!

   50.7909 [terkin.network.wifi      ] ERROR  : WiFi STA: Connecting to "WerNet" failed
Traceback (most recent call last):
  File "/flash/lib/terkin/network/wifi.py", line 241, in connect_stations
  File "/flash/lib/terkin/network/wifi.py", line 311, in connect_station
WiFiException: WiFi STA: Unable to connect to "WerNet"

   50.8319 [terkin.network.wifi      ] INFO   : WiFi STA: Forgetting NVRAM data for network "WerNet"
   50.9227 [terkin.network.wifi      ] ERROR  : WiFi STA: Connecting to any network candidate failed. Please check your WiFi configuration for one of the 1 station candidates.
   50.9454 [terkin.network.wifi      ] WARNING: Todo: We might want to buffer telemetry data to flash memory to be scheduled for transmission later.
   50.9794 [terkin.network.wifi      ] ERROR  : WiFi STA: Connecting to configured networks "['WerNet']" failed
Traceback (most recent call last):
  File "/flash/lib/terkin/network/wifi.py", line 177, in stay_connected
  File "/flash/lib/terkin/network/wifi.py", line 258, in connect_stations
WiFiException: WiFi STA: Connecting to any network candidate failed

   51.0679 [terkin.network.wifi      ] INFO   : WiFi STA: Retrying in 1.643164 seconds
   52.7294 [terkin.network.wifi      ] INFO   : WiFi STA: Connecting to configured networks: ['WerNet']. Attempt: #2
   52.7544 [terkin.network.wifi      ] INFO   : WiFi STA: Preparing connection to network "WerNet"
   52.7735 [terkin.network.wifi      ] INFO   : WiFi STA: Getting auth mode
   52.8464 [terkin.network.wifi      ] INFO   : WiFi STA: Unknown auth mode for network "WerNet", invoking WiFi scan
   52.8667 [terkin.network.wifi      ] INFO   : WiFi STA: Scanning for networks
   55.0350 [terkin.network.wifi      ] INFO   : WiFi STA: Networks available: ['NETGEAR85', 'WLAN-209719', 'Telekom_FON', 'Minionelch', 'FRITZ!Box 7560 DF', 'DIRECT-hqC48x Series', 'ShadowyPlanet', 'Mesh23', 'WerNet', 'freifunk-potsdam.de', 'devolo-f4068d8dc4d9', 'Potsdambabel', 'WLAN-728781', 'FRITZ!Box 7490 HKS', 'ARRIS-41A2', 'o2-WLAN35', 'Kuschelnetz', 'DIRECT-6C-HP OfficeJet Pro 6970', 'WLAN-EVS8XJ', 'TC-9BB6D', 'KDG-029D0', 'KabelBox-A0C8', 'o2-WLAN09']
   55.0860 [terkin.network.wifi      ] INFO   : WiFi STA: Storing auth mode into NVRAM with key=wa.9d66b1d414d4, value=3
   55.1090 [terkin.network.wifi      ] INFO   : WiFi STA: Auth mode is "3"
   55.1337 [terkin.network.wifi      ] INFO   : WiFi STA: Starting connection to "WerNet" with timeout of 30.0 seconds
   55.2497 [terkin.network.wifi      ] INFO   : WiFi STA: Waiting for network to come up within 29.998 seconds
   55.5621 [terkin.network.wifi      ] INFO   : WiFi STA: Connected to "WerNet" with IP address "192.168.188.40"
   55.6405 [terkin.network.wifi      ] INFO   : WiFi STA: Networking address (MAC): {'ap_mac': '80:7d:3a:93:65:01', 'sta_mac': '80:7d:3a:93:65:00'}
   55.6617 [terkin.network.wifi      ] INFO   : WiFi STA: Networking address (IP):  ('192.168.188.40', '255.255.255.0', '192.168.188.1', '192.168.188.189')

hereafter no more logs are being produced

[Andreas]

Just remembered that we also observed similar things like you outlined above at Stabilität und längere Testzeiträume des Terkin-Datenloggers - #64 by Andreas.

@Thias

WiFi always needs two attempts to establish a connection

This also sounds familiar, see

@Andreas

Allerdings klappt die Verbindung zum AP deterministisch nur jedes zweite Mal, also in der Hälfte aller Fälle nicht .

@Thias

hereafter no more logs are being produced

Which means success or does the software just freeze afterwards?

[Thias]

I used to see the system variables to be printed and sent to swarm.hiveeyes.org in a loop before. Looks like a freeze

[Andreas]

Seeing these weird errors again on your device, would you mind trying again with the webserver disabled?

hiveeyes/hiveeyes-micropython-firmware/blob/0.6.0/settings.example.py#L64-L66

'http': {
    'enabled': False,
},

[Thias]

@Andreas

‘http’: { ‘enabled’: False, },

did this and make sketch-and-run but log still stops after:

WiFi STA: Networking address (IP): ...

and resetting the board leads to Core 1 panic

Guru Meditation Error: Core  1 panic'ed (IllegalInstruction). Exception was unhandled.
Memory dump at 0x40200754: bad00bad bad00bad bad00bad

PS: I’ve never seen this panic before using the pybytes-less pycom firmware. Can this be related?

[clemens]

@Thias

PS: I’ve never seen this panic before using the pybytes-less pycom firmware. Can this be related?

I think it has something to do with the new 1.20.1 firmware. I saw this with pybytes activate also, see Troubleshooting the recent Pycom Firmware Release 1.20.1.r1 - #2 by clemens > section Hiveeyes-Software

[Andreas]

@Thias

resetting the board leads to Core 1 panic

Guru Meditation Error: Core  1 panic'ed (IllegalInstruction). Exception was unhandled.
Memory dump at 0x40200754: bad00bad bad00bad bad00bad

Sorry to hear that this also hits you on a LoPy4. You might alternatively check out https://packages.hiveeyes.org/hiveeyes/foss/pycom/LoPy4-1.20.1.r1-robert.tar.gz, that’s all we can offer right now. This firmware image was built and provided by robert-hh.

If this error will not go away, you might well consider going back to the official pybytes firmware…

@Thias

Pycom Firmware (pybytes per pybytes_config.json deaktiviert)

---

Sorry again, we are also just doing trial-and-error here on a regular basis. However, there are things indicating there might be something fishy under the hood.

• millis() crashes if used in irq handler called too early · Issue #2699 · espressif/arduino-esp32 · GitHub
• Cant Access EEPROM over WIFI Handler - ESP32 Forum

---

Other users are also reporting these core panics on the Pycom user forum.

t0000899 13 days ago

Wlan connection has turned to really unreliable in 1.20 version. In 1.18 connection was instant and never disconnected but in the 1.20 version wlan.connect(…) timeout most of the time and if connection is made it disconnects randomly.

– Firmware Release v1.20.1 | Pycom user forum

[Andreas]

@Andreas

something fishy under the hood

Please also enjoy

This [core dump] issue have been discussed in the forum multiple times:

• Guru Meditation Error & Magnetic Interference (EMI/RFI) | Pycom user forum
• https://forum.pycom.io/topic/3892/my-new-gpy-keeps-core-dumping
• Pycom-SSO - LogIn
• https://forum.pycom.io/topic/5177/frequency-disturbance-causing-my-pycom-modules-to-crash

This happens when in reach of some WIFI access points.

– Lopy4 unable to start WLAN.AP - Guru Meditation error: core 0 panic'ed (instrfetchprohibited) · Issue #314 · pycom/pycom-micropython-sigfox · GitHub

So, things like Soft errors caused by single-event upsets (SEUs) aka. ECC RAM absolutely matters might not be unrelated at all. Maybe some device models or revisions are more fragile than others.

[Andreas]

@Andreas

So, things like Soft errors caused by single-event upsets (SEUs) might not be unrelated at all. Maybe some device models or revisions are more fragile than others.

Saying this kiddingly, I strongly believe this issue is more likely related to Random memory corruption faults on ESP32-WROVER rev.1 and rev.2 when running in dual-core mode.

[Andreas]

@Andreas

[…] this issue is more likely related to Random memory corruption faults on ESP32-WROVER rev.1 and rev.2 when running in dual-core mode.

Coming back from there, we built firmware images for the FiPy and the LoPy4 using

#define CONFIG_FREERTOS_UNICORE 1

I can’t tell for sure whether this makes any difference at all as the FiPy on my workbench has been running pretty stable even before without that setting.

• https://packages.hiveeyes.org/hiveeyes/foss/pycom/LoPy4-1.20.1.r1-vanilla-unicore-0.1.0.tar.gz
• https://packages.hiveeyes.org/hiveeyes/foss/pycom/FiPy-1.20.1.r1-vanilla-unicore-0.1.0.tar.gz

Please also pull from our latest master as this will bring you Improve WiFi robustness on first connection attempt · hiveeyes/terkin-datalogger@d3ae518 · GitHub.

[Thias]

@Andreas

Traceback (most recent call last):
  File "main.py", line 43, in <module>
  File "main.py", line 38, in main
  File "/flash/lib/terkin/datalogger.py", line 176, in start
  File "/flash/lib/terkin/datalogger.py", line 329, in register_sensors
AttributeError: 'NoneType' object has no attribute 'name'

This indicates you might be running with an outdated settings.py . We just refactored this through Large refactoring · hiveeyes/hiveeyes-micropython-firmware@2a835be · GitHub and humbly ask you to adapt the sensors.system section like outlined within hiveeyes-micropython-firmware/settings.example.py at master · hiveeyes/hiveeyes-micropython-firmware · GitHub.

The AttributeError comes up, when bus-onewire-0 in settings.py is disabled

 "id": "bus-onewire-0",
            "family": "onewire",
            "number": 0,
            "enabled": False,
            "pin_data": "P11",

[Andreas]

Thanks for letting us know. Are you sure you are running the latest version from master or did you make some modifications locally? At line 329, we are seeing an empty line there.

However, we just added ^[1] and ^[2] to mitigate all conditions when accessing a sensor object connected to a bus object which has been disabled through the configuration settings.

---

1. Gracefully handle buses without names · hiveeyes/hiveeyes-micropython-firmware@aaae6c2 · GitHub ↩︎

2. Improve sensor registration mechanics again · hiveeyes/hiveeyes-micropython-firmware@bcaacf8 · GitHub ↩︎

[Thias]

@Andreas

Coming back from there, we built firmware images for the FiPy and the LoPy4 using

#define CONFIG_FREERTOS_UNICORE 1

Again I saw these core panics also with the unicore firmware. It starts happening after about 10 times flashing the device after PWRON. After dis/reconnecting the device from/to power the error is gone, likely until the next 10 flash procedures.

[Andreas]

@Thias

Again I saw these core panics also with the unicore firmware.

Thanks for letting us know.

@Thias

about 10 times flashing the device

Uploading raw source code through raw REPL is a rather heavy process which contributes to memory fragmentation on the device most probably leading to subsequent crashes, most probably caused by Random memory corruption faults on ESP32-WROVER rev.1 and rev.2 when running in dual-core mode.

If you are getting sick of this, we might want to go for more advanced and efficient methods bringing the source code to the device with less overhead.

---

I am using the one-stop

make recycle-ng MPY_CROSS=true MPY_TARGET=pycom MPY_VERSION=1.11

these days and would never look back. The background about why this is way more efficient is that it’s using FTP instead of raw REPL for transferring the files and that it will compile the sourcecode to bytecode before, reducing the overall size of stuff to be shipped to the device significantly.

$ du -sch dist-packages terkin
596K	total

$ du -sch lib-mpy-1.11-pycom
352K	total

How to

This currently requires a network connection over WiFi with the IP address of the device stored in .terkin/floatip like

$ cat .terkin/floatip
192.168.178.40

For automating this, I am using

make terkin-agent action=maintain macs=80:7d:3a:c2:de:44 # libero

to find the device’s IP address and

make connect-wifi ssid=GartenNetzwerk password=<redacted>

to actually get the device into the network if required.

[Thias]

@Andreas

make recycle-ng MPY_CROSS=true MPY_TARGET=pycom MPY_VERSION=1.11

this revealed the following modules missing from the environment:

• netaddr
• netifaces
• scapy

Do you mind adding these to the requirements files?

[Andreas]

These guys are listed in requirements-terkin-agent.txt already. Just run

make setup-terkin-agent

Sorry that we haven’t documented each and every bit of these details yet. You are probably one of the first people running Linux who would like to use that infrastructure.