Datalog WDT restart, some services don't start

Hi Bob!

I’m configuring a newish unit (Model W14 v5). It connects and runs ok (i.e. I see the http interface), but I see two problems:

  1. Message logs about “dataLog: datalog WDT - restarting”.
  2. More importantly, startup messages stop after “HTTP server started”.

For problem #1, I tried and “deletelog” command.
For problem #2, I note that, as expected, some services are not started: no data uploader and no MDNS.

Other info: Release is set to MINOR. I had an identical problem with another unit I’m configuring.

How should I proceed? Your help is appreciated! Cheers, Brett

11/22/21 19:39:35z timeSync: service started.
11/22/21 19:39:35z statService: started.
11/22/21 19:39:35z Updater: service started. Auto-update class is MINOR
11/22/21 19:39:35z dataLog: service started.
11/22/21 19:39:35z dataLog: Last log entry 11/22/21 18:23:00
11/22/21 19:39:35z historyLog: service started.
11/22/21 19:39:35z historyLog: Last log entry 11/22/21 18:23:00
11/22/21 19:39:37z Updater: Auto-update is current for class MINOR.
11/22/21 20:56:10z dataLog: datalog WDT - restarting

** Restart **

SD initialized.
11/22/21 20:56:11z Real Time Clock is running. Unix time 1637614571
11/22/21 20:56:11z Reset reason: Software/System restart
11/22/21 20:56:11z Trace: 9:0, 9:0, 8:2, 8:2, 1:2, 1:3, 1:3, 1:1, 1:2, 9:0, 9:0, 8:2, 8:2, 1:2, 1:3, 1:3, 1:1, 1:2, 9:0, 9:0, 8:2, 8:2, 1:2, 1:3, 1:3, 1:1, 1:2, 9:0, 9:0, 8:2, 8:2, 1:2
11/22/21 20:56:11z ESP8266 ID: 4307075, RTC PCF8523
11/22/21 20:56:11z IoTaWatt 5.0, Firmware version 02_06_06
11/22/21 20:56:11z SPIFFS mounted.
11/22/21 20:56:11z Local time zone: +0:00
11/22/21 20:56:11z device name: IotaWatt
11/22/21 20:56:11z HTTP server started
11/22/21 22:07:45z WiFi connected. SSID=NetComm 0405, IP=192.168.0.21, channel=11, RSSI -62db
11/22/21 22:07:45z MDNS responder started for hostname IotaWatt
11/22/21 22:07:45z LLMNR responder started for hostname IotaWatt
11/22/21 22:07:45z timeSync: service started.
11/22/21 22:07:45z statService: started.
11/22/21 22:07:45z Updater: service started. Auto-update class is MINOR
11/22/21 22:07:45z dataLog: service started.
11/22/21 22:07:45z dataLog: Last log entry 11/22/21 20:51:10
11/22/21 22:07:45z historyLog: service started.
11/22/21 22:07:45z historyLog: Last log entry 11/22/21 20:51:00
11/22/21 23:24:22z dataLog: datalog WDT - restarting

** Restart **

SD initialized.
11/22/21 23:24:24z Real Time Clock is running. Unix time 1637623464
11/22/21 23:24:24z Reset reason: Software/System restart
11/22/21 23:24:24z Trace: 9:0, 9:0, 8:4, 8:6, 8:8, 8:9, 1:2, 1:3, 1:3, 1:1, 1:2, 9:0, 9:0, 8:4, 8:6, 8:8, 8:9, 1:2, 1:3, 1:3, 1:1, 1:2, 9:0, 9:0, 8:4, 8:6, 8:8, 8:9, 8:4, 8:2, 8:2, 1:2
11/22/21 23:24:24z ESP8266 ID: 4307075, RTC PCF8523
11/22/21 23:24:24z IoTaWatt 5.0, Firmware version 02_06_06
11/22/21 23:24:24z SPIFFS mounted.
11/22/21 23:24:24z Local time zone: +0:00
11/22/21 23:24:24z device name: IotaWatt
11/22/21 23:24:24z HTTP server started
11/22/21 23:24:24z timeSync: service started.
11/23/21 00:35:58z statService: started.
11/23/21 00:35:58z Updater: service started. Auto-update class is MINOR
11/23/21 00:35:58z dataLog: service started.
11/23/21 00:35:58z dataLog: Last log entry 11/22/21 22:19:05
11/23/21 00:35:58z historyLog: service started.
11/23/21 00:35:58z historyLog: Last log entry 11/22/21 20:51:00
11/23/21 00:35:58z WiFi connected. SSID=NetComm 0405, IP=192.168.0.21, channel=11, RSSI -58db
11/23/21 00:35:58z MDNS responder started for hostname IotaWatt
11/23/21 00:35:58z LLMNR responder started for hostname IotaWatt
11/23/21 00:41:00z dataLog: datalog WDT - restarting

** Restart **

SD initialized.
11/23/21 00:41:01z Real Time Clock is running. Unix time 1637628061
11/23/21 00:41:01z Reset reason: Software/System restart
11/23/21 00:41:01z Trace: 9:0, 9:0, 8:2, 8:2, 1:2, 1:3, 1:3, 1:1, 1:2, 9:0, 9:0, 8:2, 8:2, 1:2, 1:3, 1:3, 1:1, 1:2, 9:0, 9:0, 8:2, 8:2, 1:2, 1:3, 1:3, 1:1, 1:2, 9:0, 9:0, 8:2, 8:2, 1:2
11/23/21 00:41:01z ESP8266 ID: 4307075, RTC PCF8523
11/23/21 00:41:01z IoTaWatt 5.0, Firmware version 02_06_06
11/23/21 00:41:01z SPIFFS mounted.
11/23/21 00:41:01z Local time zone: +0:00
11/23/21 00:41:01z device name: IotaWatt
11/23/21 00:41:01z HTTP server started
11/23/21 01:52:35z WiFi connected. SSID=NetComm 0405, IP=192.168.0.21, channel=11, RSSI -58db
11/23/21 01:52:35z MDNS responder started for hostname IotaWatt
11/23/21 01:52:35z LLMNR responder started for hostname IotaWatt
11/23/21 01:52:35z timeSync: service started.
11/23/21 01:52:35z statService: started.
11/23/21 01:52:35z Updater: service started. Auto-update class is MINOR
11/23/21 01:52:35z dataLog: service started.
11/23/21 01:52:36z dataLog: Last log entry 11/23/21 00:36:00
11/23/21 01:52:36z historyLog: service started.
11/23/21 01:52:36z historyLog: Last log entry 11/23/21 00:36:00
11/23/21 03:09:12z dataLog: datalog WDT - restarting

** Restart **

SD initialized.
11/23/21 03:09:13z Real Time Clock is running. Unix time 1637636953
11/23/21 03:09:13z Reset reason: Software/System restart
11/23/21 03:09:13z Trace: 1:3, 1:3, 1:1, 1:2, 9:0, 9:0, 8:4, 8:6, 8:8, 8:9, 1:2, 1:3, 1:3, 1:1, 1:2, 9:0, 9:0, 8:4, 8:6, 8:8, 8:9, 1:2, 1:3, 1:3, 1:1, 1:2, 9:0, 9:0, 8:4, 8:2, 8:2, 1:2
11/23/21 03:09:13z ESP8266 ID: 4307075, RTC PCF8523
11/23/21 03:09:13z IoTaWatt 5.0, Firmware version 02_06_06
11/23/21 03:09:13z SPIFFS mounted.
11/23/21 03:09:13z Local time zone: +0:00
11/23/21 03:09:13z device name: IotaWatt
11/23/21 03:09:13z HTTP server started
11/23/21 03:09:13z timeSync: service started.
11/23/21 04:20:47z statService: started.
11/23/21 04:20:47z Updater: service started. Auto-update class is MINOR
11/23/21 04:20:47z dataLog: service started.
11/23/21 04:20:47z dataLog: Last log entry 11/23/21 02:00:05
11/23/21 04:20:47z historyLog: service started.
11/23/21 04:20:47z historyLog: Last log entry 11/23/21 00:36:00
11/23/21 04:20:47z WiFi connected. SSID=NetComm 0405, IP=192.168.0.21, channel=11, RSSI -59db
11/23/21 04:20:47z MDNS responder started for hostname IotaWatt
11/23/21 04:20:47z LLMNR responder started for hostname IotaWatt
11/23/21 05:37:22z dataLog: datalog WDT - restarting

** Restart **

SD initialized.
11/23/21 05:37:23z Real Time Clock is running. Unix time 1637645843
11/23/21 05:37:23z Reset reason: Software/System restart
11/23/21 05:37:23z Trace: 8:6, 8:8, 8:9, 1:2, 1:3, 1:3, 1:1, 1:2, 9:0, 9:0, 8:4, 8:6, 8:8, 8:9, 1:2, 1:3, 1:3, 1:1, 1:2, 9:0, 9:0, 8:4, 8:6, 8:8, 8:9, 8:4, 8:6, 8:8, 8:9, 1:2, 1:3, 1:3
11/23/21 05:37:23z ESP8266 ID: 4307075, RTC PCF8523
11/23/21 05:37:23z IoTaWatt 5.0, Firmware version 02_06_06
11/23/21 05:37:23z SPIFFS mounted.
11/23/21 05:37:23z Local time zone: +0:00
11/23/21 05:37:23z device name: IotaWatt
11/23/21 05:37:23z HTTP server started
11/23/21 06:48:57z timeSync: service started.
11/23/21 06:48:57z statService: started.
11/23/21 06:48:57z Updater: service started. Auto-update class is MINOR
11/23/21 06:48:57z dataLog: service started.
11/23/21 06:48:57z dataLog: Last log entry 11/23/21 04:21:25
11/23/21 06:48:57z historyLog: service started.
11/23/21 06:48:58z historyLog: Last log entry 11/23/21 02:00:00
11/23/21 06:48:58z WiFi connected. SSID=NetComm 0405, IP=192.168.0.21, channel=11, RSSI -60db
11/23/21 06:48:58z MDNS responder started for hostname IotaWatt
11/23/21 06:48:58z LLMNR responder started for hostname IotaWatt
11/23/21 06:49:00z Updater: Auto-update is current for class MINOR.
11/23/21 06:54:00z dataLog: datalog WDT - restarting

** Restart **

SD initialized.
11/23/21 06:54:01z Real Time Clock is running. Unix time 1637650441
11/23/21 06:54:01z Reset reason: Software/System restart
11/23/21 06:54:01z Trace: 9:0, 9:0, 8:2, 8:2, 1:2, 1:3, 1:3, 1:1, 1:2, 9:0, 9:0, 8:2, 8:2, 1:2, 1:3, 1:3, 1:1, 1:2, 9:0, 9:0, 8:2, 8:2, 1:2, 1:3, 1:3, 1:1, 1:2, 9:0, 9:0, 8:2, 8:2, 1:2
11/23/21 06:54:01z ESP8266 ID: 4307075, RTC PCF8523
11/23/21 06:54:01z IoTaWatt 5.0, Firmware version 02_06_06
11/23/21 06:54:01z SPIFFS mounted.
11/23/21 06:54:01z Local time zone: +0:00
11/23/21 06:54:01z device name: IotaWatt
11/23/21 06:54:01z HTTP server started
11/23/21 08:05:35z WiFi connected. SSID=NetComm 0405, IP=192.168.0.21, channel=11, RSSI -65db
11/23/21 08:05:35z MDNS responder started for hostname IotaWatt
11/23/21 08:05:35z LLMNR responder started for hostname IotaWatt
11/23/21 08:05:35z timeSync: service started.
11/23/21 08:05:35z statService: started.
11/23/21 08:05:35z Updater: service started. Auto-update class is MINOR
11/23/21 08:05:36z dataLog: service started.
11/23/21 08:05:36z dataLog: Last log entry 11/23/21 06:49:00
11/23/21 08:05:36z historyLog: service started.
11/23/21 08:05:36z historyLog: Last log entry 11/23/21 06:49:00
11/23/21 10:33:44z dataLog: datalog WDT - restarting

** Restart **

SD initialized.
11/23/21 10:33:45z Real Time Clock is running. Unix time 1637663625
11/23/21 10:33:45z Reset reason: Software/System restart
11/23/21 10:33:45z Trace: 1:2, 9:0, 9:0, 8:2, 8:2, 1:2, 1:3, 1:3, 1:1, 1:2, 9:0, 9:0, 8:4, 8:6, 8:8, 8:9, 1:2, 1:3, 1:3, 1:1, 1:2, 9:0, 9:0, 8:4, 8:6, 8:8, 8:9, 8:4, 8:6, 8:8, 8:9, 1:2
11/23/21 10:33:45z ESP8266 ID: 4307075, RTC PCF8523
11/23/21 10:33:45z IoTaWatt 5.0, Firmware version 02_06_06
11/23/21 10:33:45z SPIFFS mounted.
11/23/21 10:33:45z Local time zone: +0:00
11/23/21 10:33:45z device name: IotaWatt
11/23/21 10:33:45z HTTP server started
11/23/21 10:33:45z timeSync: service started.
11/23/21 10:33:46z statService: started.

** Restart **

SD initialized.
1/13/22 21:41:39z Real Time Clock is running. Unix time 1642110099
1/13/22 21:41:39z Reset Reason: Power-fail restart.
1/13/22 21:41:39z ESP8266 ID: 4307075, RTC PCF8523
1/13/22 21:41:39z IoTaWatt 5.0, Firmware version 02_06_06
1/13/22 21:41:39z SPIFFS mounted.
1/13/22 21:41:39z Local time zone: +0:00
1/13/22 21:41:39z device name: IotaWatt
1/13/22 21:41:42z Connecting with WiFiManager.
1/13/22 21:41:45z HTTP server started

** Restart **

SD initialized.
1/13/22 21:47:57z Real Time Clock is running. Unix time 1642110477
1/13/22 21:47:57z Reset Reason: Power-fail restart.
1/13/22 21:47:57z ESP8266 ID: 4307075, RTC PCF8523
1/13/22 21:47:57z IoTaWatt 5.0, Firmware version 02_06_06
1/13/22 21:47:57z SPIFFS mounted.
1/13/22 21:47:57z Local time zone: +0:00
1/13/22 21:47:57z device name: IotaWatt
1/13/22 21:48:00z Connecting with WiFiManager.
1/13/22 21:48:03z HTTP server started

It’s the OP here. I tried yet another unit and got problem #2. Here is the annotated log:

** Restart **

SD initialized.
1/13/22 22:14:48z Real Time Clock is running. Unix time 1642112088
1/13/22 22:14:48z Reset Reason: Power-fail restart.
1/13/22 22:14:48z ESP8266 ID: 16274376, RTC PCF8523 (68)
1/13/22 22:14:48z IoTaWatt 5.0, Firmware version 02_07_05
1/13/22 22:14:48z SPIFFS mounted.
1/13/22 22:14:48z Local time zone: +0:00
1/13/22 22:14:48z device name: IotaWatt
1/13/22 22:14:51z Connecting with WiFiManager.
1/13/22 22:14:54z HTTP server started

Hangs, so I disconnect and reconnect to a different wifi network…

1/13/22 22:18:26z Disconnect command received.

** Restart **

SD initialized.
1/13/22 22:18:45z Real Time Clock is running. Unix time 1642112325
1/13/22 22:18:45z Reset Reason: Power-fail restart.
1/13/22 22:18:45z ESP8266 ID: 16274376, RTC PCF8523 (68)
1/13/22 22:18:45z IoTaWatt 5.0, Firmware version 02_07_05
1/13/22 22:18:45z SPIFFS mounted.
1/13/22 22:18:45z Local time zone: +0:00
1/13/22 22:18:45z device name: IotaWatt
1/13/22 22:18:48z Connecting with WiFiManager.
1/13/22 22:19:44z HTTP server started
1/13/22 22:19:44z WiFi connected. SSID=condorman, IP=192.168.43.20, channel=11, RSSI -48db
1/13/22 22:19:44z MDNS responder started for hostname IotaWatt
1/13/22 22:19:44z LLMNR responder started for hostname IotaWatt

Now it starts MDNS ok and assumedly is fine. This is on a different network: a mobile phone hotspot wifi.

So maybe it’s hanging waiting for something (e.g. time server) my network is blocked to? I post these units to customers and rely on reliable startup to connect and configure, so I’m keen to get to the bottom of this.

You say there is an uploader that doesn’t start. Can you pm the config.txt file for that?

I let it run for another hour and get a successful start of mDNS, etc. (This is a “raw” config file with only the name changed. Timezone unchanged.)

I haven’t setup an uploader on this unit yet. I’ll leave it alone until I hear your feedback, then configure with uploader, etc.

** Restart **

SD initialized.
1/13/22 22:42:07z Real Time Clock is running. Unix time 1642113727
1/13/22 22:42:07z Reset reason: Software/System restart
1/13/22 22:42:07z Trace: 11:31[1], 11:31[2], 11:31[3], 11:30[3], 11:35, 11:36, 11:35, 11:40, 11:45, 11:50, 11:55, 11:70, 1:4, 1:1, 1:2, 9:0, 9:0, 8:2, 8:2, 1:2, 1:3, 1:3, 1:1, 1:2, 9:0, 9:0, 8:2, 8:2, 1:2, 1:3, 10:2, 10:3
1/13/22 22:42:07z ESP8266 ID: 16274376, RTC PCF8523 (68)
1/13/22 22:42:07z IoTaWatt 5.0, Firmware version 02_07_05
1/13/22 22:42:07z SPIFFS mounted.
1/13/22 22:42:07z Local time zone: +0:00
1/13/22 22:42:07z device name: nogo
1/13/22 22:42:07z HTTP server started
1/13/22 23:53:41z timeSync: service started.
1/13/22 23:53:41z statService: started.
1/13/22 23:53:41z Updater: service started. Auto-update class is MINOR
1/13/22 23:53:41z dataLog: service started.
1/13/22 23:53:41z dataLog: New current log created.
1/13/22 23:53:41z WiFi connected. SSID=NetComm 0405, IP=192.168.0.246, channel=1, RSSI -67db
1/13/22 23:53:41z MDNS responder started for hostname nogo
1/13/22 23:53:41z LLMNR responder started for hostname nogo

I have to say I don’t see exactly what’s going on. I don’t think it’s anything to do with a time server.

When you say “newish” do you mean a unit that was previously deployed and is now being recommissioned? If so how long since last used?

When you delete the old log, deletelog=both or just current?

The ‘newish’ unit was purchased mid last year. It was not previously deployed. It hasn’t been plugged in for about 2 months. I deleted both logs.

I’m mention the time server as I have to leave new iotawatts connected for 24 hours to obtain a time for the RTC.

I’m curious about the 1 hour delay before “timeSync: service started.”

Can I see the config file? Is there a VT configured and connected?

I’m configuring a new unit and will document what happens below.

Nothing is connected physically.

You’ll see it connects okay once the new config file is loaded. So, for me, there is really no problem. I just have to lookup it’s IP address. However, for others looking for “iotawatt.local” there might be an issue as mDNS service doesn’t start with default config.txt?

Step 1
Plug in and connect to WiFi. See attached log1 and config1.
config.txt (569 Bytes)
log1.txt (113.4 KB)
I have to go to IP address as mDNS is not started.

Step 2
Upload custom config to config+1.txt.
It is ‘accepted’ and saved as config.txt
(I previously used code to automatically upload to iotawatt.local/edit and restart via the API, but this doesn’t work not without mDNS)
Restart iotawatt
Log and config (redacted) is attached.
config2.txt (5.4 KB)
log2.txt (9.7 KB)

So there is no VT connected?

Actually the last connection I see logged was on 11/23/21 at 08:05:35z.

I have not researched the behavior of an IoTaWatt without a VT connected. Essentially, all of the core functions are performed in between samples defined by one complete AC cycle.

This older unit was apparently left powered up for a couple of days in November without a VT or meaningful config. I can imagine a potential issue here with trying to sort out the datalogs upon restart more than a month later. It should be no problem with a VT to regulate the cadence of the internal Services, but without that, I can’t say what would happen.

IoTaWatt’s raison d’être is to measure electric energy. Voltage is a fundamental metric needed to do that, so it makes no sense to compromise the efficiency of the voltage signal synchronization to facilitate operating without a VT.

Only if there is no VT. I’d encourage you to insure that your units always have a VT connected when powered up.

Current I config the units in the “office” with no VT, no CTs. Out on site I then plug VTs, CTs in and boot up.

Knowing this info above I’ll plug in a VT in the office too.

Thanks for the info.