Troubleshooting some issues when running the Terkin Datalogger on the LoPy4

Over at Unlocking LoRaWAN / TTN on the LoPy4, @Thias is starting with the LoPy4. We are handling some issues about this guy here.

LoPy4 Log ohne angeschlossene Sensoren mit Sandbox Firmware nach Refactoring vom 31.10.2019 [1] und Pycom Firmware (pybytes per pybytes_config.json deaktiviert)

vorab:

rm -rf dist-packages
make setup
make install

bringt mich zu:

Pycom MicroPython 1.20.1.r1 [v1.11-3138a13] on 2019-10-08; LoPy4 with ESP32
Pybytes Version: 1.1.3
Type "help()" for more information.
>>> 
>>> import machine ; machine.reset()
ets Jun  8 2016 00:22:57

rst:0x7 (TG0WDT_SYS_RESET),boot:0x12 (SPI_FAST_FLASH_BOOT)
configsip: 0, SPIWP:0xee
clk_drv:0x00,q_drv:0x00,d_drv:0x00,cs0_drv:0x00,hd_drv:0x00,wp_drv:0x00
mode:DIO, clock div:1
load:0x3fff8020,len:8
load:0x3fff8028,len:2136
load:0x4009fa00,len:19880
entry 0x400a05d0
[boot.py] INFO: Python module search path is: ['', '/flash', '/flash/lib']
[boot.py] INFO: Starting "mboot" bootloader
[mboot]   INFO: Python module search path is: ['/flash/lib-mpy-1.11-pycom', '', '/flash', '/flash/lib', '/flash/dist-packages', '/flash/terkin']
Pybytes configuration read from /flash/pybytes_config.json
Not starting Pybytes as auto-start is disabled
[main.py] INFO: Loading settings
[main.py] INFO: Starting logging
[main.py] INFO: Loading Terkin Datalogger
[main.py] INFO: Loading modules
   14.8634 [terkin.datalogger        ] INFO   : Starting Terkin datalogger
   14.8813 [terkin.configuration     ] INFO   : Starting TerkinConfiguration on path "/flash"
   14.8995 [terkin.configuration     ] INFO   : Ensuring existence of backup directory at "/flash/backup"
   15.0199 [terkin.configuration     ] INFO   : Reading configuration file /flash/settings-user.json
   15.0426 [terkin.configuration     ] INFO   : User settings: {}
   15.5960 [terkin.device            ] WARNING: Could not determine reset cause
   15.6105 [terkin.watchdog          ] INFO   : Skipping watchdog timer (WDT)
   16.1655 [terkin.device            ] INFO   : Start curating the garbage collector
   16.4703 [terkin.device            ] INFO   : Curating the garbage collector finished. Free memory: 2392384
   16.4969 [terkin.device            ] INFO   : Turning off Bluetooth
   17.1289 [terkin.watchdog          ] INFO   : Resuming watchdog
   17.1499 [terkin.datalogger        ] INFO   : Starting Terkin MicroPython Datalogger 0.6.0
   17.1769 [terkin.configuration     ] INFO   : Configuration settings:
   17.2163 [terkin.configuration     ] INFO   : Section "telemetry": {"targets": [{"enabled": true, "topology": "mqttkit", "endpoint": "mqtt://swarm.hiveeyes.org", "address": {"network": "testdrive", "gateway": "thias", "node": "lopy4-mqtt-json", "realm": "hiveeyes"}}, {"enabled": false, "topology": "mqttkit", "endpoint": "https://daq.example.org/api", "address": {"network": "testdrive", "gateway": "area-42", "node": "node-01-http-json", "realm": "workbench"}}, {"enabled": false, "data": {"key": "## redacted ##"}, "endpoint": "https://test.free.beeceptor.com/api/sensors"}, {"encode": "base64", "format": "lpp", "address": {"network": "testdrive", "gateway": "area-42", "node": "node-01-mqtt-lpp", "realm": "workbench"}, "enabled": false, "endpoint": "mqtt://daq.example.org"}]}
   17.2992 [terkin.configuration     ] INFO   : Section "interfaces": {"uart0": {"terminal": true}}
   17.3310 [terkin.configuration     ] INFO   : Section "networking": {"wifi": {"phy": {"antenna_external": false, "antenna_pin": "P12"}, "stations": [{"ssid": "WerNet", "password": "## redacted ##"}]}, "lora": {"otaa": {"application_eui": "## redacted ##", "datarate": 0, "frequency": 868100000, "region": "LoRa.EU868", "application_key": "## redacted ##", "device_eui": "007A2C890789A9B3"}, "antenna_attached": true}}
   17.3867 [terkin.configuration     ] INFO   : Section "main": {"rgb_led": {"terkin": true, "heartbeat": false}, "watchdog": {"enabled": false, "timeout": 60000}, "interval": {"maintenance": 15.0, "field": 60.0}, "fastboot": true, "backup": {"file_count": 7}, "deepsleep": false, "logging": {"enabled": true, "configuration": true}}
   17.4658 [terkin.configuration     ] INFO   : Section "sensors": {"system": [{"type": "system.memfree"}, {"type": "system.temperature"}, {"type": "system.uptime"}, {"type": "system.wifi"}, {"enabled": false, "type": "system.touch-buttons"}, {"pin": "P16", "resistor_r2": 1000, "resistor_r1": 1000, "enabled": true, "type": "system.battery-voltage"}], "environment": [{"pin_dout": "P22", "scale": 4.424242, "offset": -73000, "enabled": false, "name": "scale", "description": "Waage 1", "id": "scale-1", "number": 0, "pin_pdsck": "P21", "type": "HX711"}, {"enabled": false, "bus": "onewire:0", "name": "temperature", "description": "Wabengasse 1", "id": "ds18b20-1", "type": "DS18B20", "devices": [{"id": "ds18b20-r1c1", "enabled": false, "address": "1111111111111111", "description": "Reihe 1, Spalte 1"}, {"id": "ds18b20-r1c2", "enabled": false, "address": "2222222222222222", "description": "Reihe 1, Spalte 2"}]}, {"id": "bme280-1", "description": "Temperatur und Feuchte außen", "type": "BME280", "address": 119, "enabled": false, "bus": "i2c:0"}], "busses": [{"id": "bus-i2c-0", "family": "i2c", "number": 0, "pin_sda": "P9", "enabled": false, "pin_scl": "P10"}, {"id": "bus-i2c-1", "family": "i2c", "number": 1, "pin_sda": "P22", "enabled": false, "pin_scl": "P21"}, {"enabled": true, "family": "onewire", "pin_data": "P11", "id": "bus-onewire-0", "number": 0}], "prettify_log": true}
   17.6095 [terkin.configuration     ] INFO   : Section "services": {"api": {"modeserver": {"enabled": true}, "http": {"enabled": true}}}
---------------------------------------------
System memory info (in bytes)
---------------------------------------------
MPTask stack water mark: 5016
ServersTask stack water mark: 3628
LoRaTask stack water mark: 3516
SigfoxTask stack water mark: 2752
TimerTask stack water mark: 2136
IdleTask stack water mark: 612
System free heap: 383064
---------------------------------------------
   17.7417 [terkin.device            ] INFO   : 

===================================
Terkin MicroPython Datalogger 0.6.0
===================================
CPU freq     160.0 MHz
Device id    807d3a936500


Python  : 3.4.0
lorawan : 1.0.2
machine : LoPy4 with ESP32
nodename: LoPy4
pybytes : 1.1.3
release : 1.20.1.r1
sigfox  : 1.0.1
sysname : LoPy4
version : v1.11-3138a13 on 2019-10-08



   17.7816 [terkin.device            ] INFO   : Starting networking
   17.8194 [terkin.network.wifi      ] INFO   : Starting stopwatch
   17.9271 [terkin.network.wifi      ] INFO   : Started stopwatch successfully
   18.0288 [terkin.network.wifi      ] INFO   : WiFi STA: Networking address (MAC): {'ap_mac': '00:00:00:00:00:00', 'sta_mac': '80:7d:3a:93:65:00'}
   18.0440 [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')
   18.0591 [terkin.network.wifi      ] INFO   : WiFi: Starting interface
   18.0736 [terkin.network.wifi      ] INFO   : WiFi: Using internal antenna
   18.1091 [terkin.device            ] INFO   : Start curating the garbage collector
   18.4141 [terkin.device            ] INFO   : Curating the garbage collector finished. Free memory: 2392064
   18.5238 [terkin.network.core      ] INFO   : Waiting for the network stack to come up within 5 seconds
   18.5885 [terkin.network.core      ] INFO   : Network stack ready
   18.6216 [terkin.network.core      ] INFO   : Starting mode server on 0.0.0.0:666
   24.5066 [terkin.api.http          ] INFO   : Setting up HTTP API
   24.7909 [terkin.api.http          ] INFO   : Starting HTTP server
   24.8190 [terkin.network.core      ] ERROR  : Starting HTTP server failed
Traceback (most recent call last):
  File "/flash/lib/terkin/network/core.py", line 126, in start_services
  File "/flash/lib/terkin/network/core.py", line 144, in start_httpserver
  File "/flash/lib/terkin/api/http.py", line 72, in start
  File "/flash/dist-packages/microWebSrv.py", line 219, in Start
OSError: Network card not available

   25.6287 [terkin.network.wifi      ] INFO   : WiFi STA: Connecting to configured networks: ['WerNet']. Attempt: #1
   25.6544 [terkin.network.wifi      ] INFO   : WiFi STA: Preparing connection to network "WerNet"
   25.6747 [terkin.network.wifi      ] INFO   : WiFi STA: Getting auth mode
   25.7561 [terkin.network.wifi      ] INFO   : WiFi STA: Auth mode from NVRAM with key=wa.9d66b1d414d4, value=3
   25.7803 [terkin.network.wifi      ] INFO   : WiFi STA: Auth mode is "3"
   25.8077 [terkin.network.wifi      ] INFO   : WiFi STA: Starting connection to "WerNet" with timeout of 15.0 seconds
   25.9372 [terkin.network.wifi      ] INFO   : WiFi STA: Waiting for network to come up within 14.997 seconds
Unhandled exception in thread started by <bound_method>
Traceback (most recent call last):
  File "/flash/lib/terkin/network/ip.py", line 31, in start_real
OSError: Network card not available
   28.2280 [terkin.network.lora      ] INFO   : [LoRA] Not joined yet...
   28.9669 [terkin.network.wifi      ] INFO   : WiFi STA: Waiting for network to come up within 11.967 seconds
   30.8810 [terkin.network.lora      ] INFO   : [LoRA] Not joined yet...
   31.9800 [terkin.network.wifi      ] INFO   : WiFi STA: Waiting for network to come up within 8.953 seconds
   33.5002 [terkin.network.lora      ] INFO   : [LoRA] Not joined yet...
   34.9862 [terkin.network.wifi      ] INFO   : WiFi STA: Waiting for network to come up within 5.947 seconds
   36.1194 [terkin.network.lora      ] INFO   : [LoRA] Not joined yet...
   37.9933 [terkin.network.wifi      ] INFO   : WiFi STA: Waiting for network to come up within 2.94 seconds
   38.7396 [terkin.network.lora      ] INFO   : [LoRA] Not joined yet...
   40.9576 [terkin.network.wifi      ] ERROR  : Invoking "is_connected" failed
Traceback (most recent call last):
  File "/flash/lib/terkin/network/wifi.py", line 192, in is_connected
TimeoutError: Connection to AP Timeout!

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

   41.0986 [terkin.network.wifi      ] INFO   : WiFi STA: Forgetting NVRAM data for network "WerNet"
   41.2004 [terkin.network.wifi      ] ERROR  : WiFi STA: Connecting to any network candidate failed. Please check your WiFi configuration for one of the 1 station candidates.
   41.2258 [terkin.network.wifi      ] WARNING: Todo: We might want to buffer telemetry data to flash memory to be scheduled for transmission later.
   41.2660 [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 176, in stay_connected
  File "/flash/lib/terkin/network/wifi.py", line 257, in connect_stations
WiFiException: WiFi STA: Connecting to any network candidate failed

   41.3621 [terkin.network.wifi      ] INFO   : WiFi STA: Retrying in 1.962988 seconds
   41.4828 [terkin.network.lora      ] INFO   : [LoRA] Not joined yet...
   41.5048 [terkin.network.lora      ] INFO   : [LoRA] joined...
   43.3453 [terkin.network.wifi      ] INFO   : WiFi STA: Connecting to configured networks: ['WerNet']. Attempt: #2
   43.3732 [terkin.network.wifi      ] INFO   : WiFi STA: Preparing connection to network "WerNet"
   43.3948 [terkin.network.wifi      ] INFO   : WiFi STA: Getting auth mode
   43.4763 [terkin.network.wifi      ] INFO   : WiFi STA: Unknown auth mode for network "WerNet", invoking WiFi scan
   43.4991 [terkin.network.wifi      ] INFO   : WiFi STA: Scanning for networks
   44.0264 [terkin.network.lora      ] INFO   : [LoRa] socket created
   45.6930 [terkin.network.wifi      ] INFO   : WiFi STA: Networks available: ['DIRECT-6C-HP OfficeJet Pro 6970', 'KDG-60B0A', 'TC-9BB6D', 'KabelBox-A0C8', 'WerNet', 'SprinterBoxGast', 'o2-WLAN35', 'NETGEAR85', 'SprinterBox', 'WLAN-209719', 'Kuschelnetz', 'FRITZ!Box 7430 SW', 'Ourhome_24', 'Mesh23', 'Siemensstr Home 2,4', 'DIRECT-277310A9', 'Minionelch', 'ShadowyPlanet', 'WLAN-728781', 'Telekom_FON', 'KDG-029D0', 'FRITZ!Box 7490', 'DIRECT-hqC48x Series', 'freifunk-potsdam.de', 'Powers-Box']
   45.7501 [terkin.network.wifi      ] INFO   : WiFi STA: Storing auth mode into NVRAM with key=wa.9d66b1d414d4, value=3
   45.7764 [terkin.network.wifi      ] INFO   : WiFi STA: Auth mode is "3"
   45.8047 [terkin.network.wifi      ] INFO   : WiFi STA: Starting connection to "WerNet" with timeout of 15.0 seconds
   45.9322 [terkin.network.wifi      ] INFO   : WiFi STA: Waiting for network to come up within 14.998 seconds
   46.2573 [terkin.network.wifi      ] INFO   : WiFi STA: Connected to "WerNet" with IP address "192.168.188.40"
   46.3493 [terkin.network.wifi      ] INFO   : WiFi STA: Networking address (MAC): {'ap_mac': '00:00:00:00:00:00', 'sta_mac': '80:7d:3a:93:65:00'}
   46.3736 [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')
   48.2523 [terkin.device            ] INFO   : Starting telemetry
   48.2938 [terkin.telemetry         ] INFO   : Telemetry channel topology: MqttKitTopology
   48.3358 [terkin.telemetry         ] INFO   : Telemetry channel URI: mqtt://swarm.hiveeyes.org/hiveeyes/testdrive/thias/lopy4-mqtt-json
   48.3587 [terkin.telemetry         ] INFO   : Starting Terkin TelemetryClient
   48.4193 [terkin.sensor.core       ] INFO   : Starting all busses [{'enabled': False, 'family': 'i2c', 'pin_scl': 'P10', 'pin_sda': 'P9', 'id': 'bus-i2c-0', 'number': 0}, {'enabled': False, 'family': 'i2c', 'pin_scl': 'P21', 'pin_sda': 'P22', 'id': 'bus-i2c-1', 'number': 1}, {'pin_data': 'P11', 'id': 'bus-onewire-0', 'number': 0, 'family': 'onewire', 'enabled': True}]
   48.4695 [terkin.sensor.core       ] INFO   : Bus with id "bus-i2c-0" and family "i2c" is disabled, skipping registration
   48.4978 [terkin.sensor.core       ] INFO   : Bus with id "bus-i2c-1" and family "i2c" is disabled, skipping registration
   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'

   48.6878 [terkin.sensor.core       ] INFO   : Registering bus "onewire:0"
   48.7096 [terkin.datalogger        ] INFO   : Registering sensors
   48.7767 [terkin.datalogger        ] INFO   : Setting up sensor with with id=system.memfree and type=system.memfree on bus=None with address=None described as "None"
   48.8343 [terkin.datalogger        ] INFO   : Setting up sensor with with id=system.temperature and type=system.temperature on bus=None with address=None described as "None"
   48.8774 [terkin.datalogger        ] INFO   : Setting up sensor with with id=system.uptime and type=system.uptime on bus=None with address=None described as "None"
   48.9199 [terkin.datalogger        ] INFO   : Setting up sensor with with id=system.wifi and type=system.wifi on bus=None with address=None described as "None"
   48.9632 [terkin.datalogger        ] INFO   : Setting up sensor with with id=system.touch-buttons and type=system.touch-buttons on bus=None with address=None described as "None"
   48.9953 [terkin.datalogger        ] INFO   : Sensor with id=system.touch-buttons is disabled, skipping registration
   49.0359 [terkin.datalogger        ] INFO   : Setting up sensor with with id=system.battery-voltage and type=system.battery-voltage on bus=None with address=None described as "None"
SystemVoltage settings: {'resistor_r2': 1000, 'resistor_r1': 1000, 'enabled': True, 'pin': 'P16', 'type': 'system.battery-voltage'}
   49.1348 [terkin.datalogger        ] INFO   : Setting up sensor with with id=scale-1 and type=hx711 on bus=None with address=None described as "Waage 1"
   49.1623 [terkin.datalogger        ] INFO   : Sensor with id=scale-1 is disabled, skipping registration
   49.1849 [terkin.sensor.core       ] INFO   : Trying to find bus by name "onewire:0"
   49.2059 [terkin.sensor.core       ] INFO   : Found bus by name "onewire:0": <OneWireBus object at 3f97f480>
   49.2461 [terkin.datalogger        ] INFO   : Setting up sensor with with id=ds18b20-1 and type=ds18b20 on bus=onewire:0 with address=None described as "Wabengasse 1"
   49.2754 [terkin.datalogger        ] INFO   : Sensor with id=ds18b20-1 is disabled, skipping registration
   49.2981 [terkin.sensor.core       ] INFO   : Trying to find bus by name "i2c:0"
   49.3192 [terkin.sensor.core       ] INFO   : Found bus by name "i2c:0": None
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'
Pycom MicroPython 1.20.1.r1 [v1.11-3138a13] on 2019-10-08; LoPy4 with ESP32
Pybytes Version: 1.1.3
Type "help()" for more information.
>>> 

[1] Large refactoring · hiveeyes/hiveeyes-micropython-firmware@2a835be · GitHub

Thanks for writing in and also thanks for

We are already doing some network-related investigations over at Troubleshooting the recent Pycom Firmware Release 1.20.1.r1.

While we see pybytes has been disabled successfully through pybytes_config.json

we still feel that the error message

might be related to that.

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.

This is a complete firmware image which can be flashed to the device through the Pycom Firmware Updater, as outlined on Installing the recent Pycom Firmware 1.20.1.r1 requires erasing the flash memory completely. Please make sure to use the erase_all command first.

On Linux, the appropriate procedure might be

wget https://packages.hiveeyes.org/hiveeyes/foss/pycom/LoPy4-1.20.1.r1-vanilla-0.1.0.tar.gz
pycom-fwtool-cli --verbose --port /dev/ttyS0 erase_all
pycom-fwtool-cli --verbose --port /dev/ttyS0 flash --tar LoPy4-1.20.1.r1-vanilla-0.1.0.tar.gz

We will be happy to hear about the outcome for you.

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?

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.

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.

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!

1 Like

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

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

This also sounds familiar, see

Which means success or does the software just freeze afterwards?

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

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

'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?

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 > section Hiveeyes-Software

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…


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.


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

Please also enjoy

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.

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.

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

2 Likes

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",
1 Like

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 ↩︎

1 Like

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.

1 Like