Iotawatt not updating InfluxDB

This seems to be sort of a weird problem but I think I may have tracked it down. About 2 or 3 months ago I upgraded my laptop (which is my InfluxDB and Grafana server as well) to Windows 10. Every night, since I’ve owned this computer, it hibernates after 15 to 20 minutes of nonuse. I was having absolutely no problems with the Iotawatt/Influx interface. My monthly electric bills were within 1% of what Grafana was reporting . . . until Windows 10. Now what seems to be happening is when windows hibernates, Iotawatt seems to think InfluxDB is still running but there is no data being transfered. When I resume the computer there is a gap of data that stops when the computer went in to hibernation and restarts when the computer is turned back on. Iotawatt does not seem to be sending the data from when the computer started to sleep. The only work around I can think of at the moment is, when I’m done for the night, stop the InfluxDB update through Iotawatt, put the computer to sleep and restart the interface when I bring it back up. I already have a batch file to hibernate the computer after 10 min. Is there any command line interface for Iotawatt that I can add to the batch file to shut Iotawatt/InfluxDB interface down as well?

No.

But I don’t think that’s a good solution anyway. Can you observe the uploaded status display when the laptop apparently goes into hibernation and see if the time of last update continues to advance and/or there are any messages displayed?

Not sure how I would do that since everything is running on the same laptop. I dropped the database in InfluxDB and am currently in the process of reloading the IotaWatt data. I started that process yesterday and thought I had turned off the hibernate function, but turned it off for “on battery” and not “on power” so the notebook hibernated last night. When I restarted it this morning, sure enough, there was a gap in the Influx database. I displayed the data directly through InfludDB and you could easily see the gap. I’ve got hibernate completely turned off now and the data is in the process of uploaded again. I suppose this would be a good time to do some testing if you can tell me what to do. I can get in to the IotaWatt interface on my desktop PC and hibernate my notebook and see what happens.

Yes, I’d like to see what the IoTaWatt influx status says when the laptop is hybernating.

Here’s a screen shot right after the notebook shut down. A few seconds after this was taken the Post Failed changed to -4 but the Last Update time remained the same. I’ll leave the notebook off for an hour or so before I restart it.

Turned the laptop back on and took the following screenshots:

  1. IotaWatt right before restarting laptop.
  2. IotaWatt right after restarting laptop with with InfluxDB stopped. You can see it jumped from 5:47AM to 1:20PM.
  3. Picture of the Grafana output with the straight lines being the time the laptop was stopped.
  4. Picture of the InfluxDB database dump. You can see right in the middle of the screen where it jumps from time stamp 09:47 to 16:28.



Did you stop it or did it stop on its own? Can I see the message log for that period?

I stopped it after seeing the time jump; But it ran for probably 15 or 20 sec before I could stop it. What’s the name of the log file you want me to upload?

You can display it from the app in Tools->Message Log, then copy and paste it from your browser to the forum post.

7/06/21 15:50:05 WiFi connected. SSID=ATT6AbiV3A, IP=192.168.1.100, channel=6, RSSI -69db
7/06/21 15:50:05 MDNS responder started for hostname IotaWatt
7/06/21 15:50:05 LLMNR responder started for hostname IotaWatt
7/06/21 15:50:05 Updater: service started. Auto-update class is MINOR
7/06/21 15:50:05 influxDB_v1: Start posting at 09/30/20 21:16:30

** Restart **

SD initialized.
7/06/21 19:50:09z Real Time Clock is running. Unix time 1625601009
7/06/21 19:50:09z Reset reason: Software Watchdog
7/06/21 19:50:09z Trace: 32:35, 32:35, 32:37, 32:37, 32:37, 31:1, 1:6[6], 1:1[8], 1:2[9], 9:0[9], 9:0, 9:1, 8:4, 8:6, 8:8, 8:9, 9:3, 9:5, 9:9, 1:2, 1:3, 1:3, 1:6[1], 1:6[3], 1:5[31], 1:6[4], 31:0, 31:1, 31:2[3], 32:60, 32:60, 32:61
7/06/21 19:50:09z ESP8266 ChipID: 6195317
7/06/21 19:50:09z IoTaWatt 5.0, Firmware version 02_06_02
7/06/21 19:50:09z SPIFFS mounted.
7/06/21 15:50:09 Local time zone: -5:00
7/06/21 15:50:09 Using Daylight Saving Time (BST) when in effect.
7/06/21 15:50:09 device name: IotaWatt
7/06/21 15:50:09 HTTP server started
7/06/21 15:50:09 influxDB_v1: Starting, interval:10, url:http://192.168.1.64:8086
7/06/21 15:50:09 timeSync: service started.
7/06/21 15:50:09 statService: started.
7/06/21 15:50:09 dataLog: service started.
7/06/21 15:50:10 dataLog: Last log entry 07/06/21 15:50:05
7/06/21 15:50:13 WiFi connected. SSID=ATT6AbiV3A, IP=192.168.1.100, channel=6, RSSI -66db
7/06/21 15:50:13 MDNS responder started for hostname IotaWatt
7/06/21 15:50:13 LLMNR responder started for hostname IotaWatt
7/06/21 15:50:13 Updater: service started. Auto-update class is MINOR
7/06/21 15:50:13 influxDB_v1: Start posting at 09/30/20 21:16:30

** Restart **

SD initialized.
7/06/21 19:50:17z Real Time Clock is running. Unix time 1625601017
7/06/21 19:50:17z Reset reason: Software Watchdog
7/06/21 19:50:17z Trace: 32:35, 32:35, 32:37, 32:37, 32:37, 31:1, 1:6[6], 1:1[13], 1:2[14], 9:0[14], 9:0, 9:1, 8:4, 8:6, 8:8, 8:9, 9:3, 9:5, 9:9, 1:2, 1:3, 1:3, 1:6[1], 1:6[3], 1:5[31], 1:6[4], 31:0, 31:1, 31:2[3], 32:60, 32:60, 32:61
7/06/21 19:50:17z ESP8266 ChipID: 6195317
7/06/21 19:50:17z IoTaWatt 5.0, Firmware version 02_06_02
7/06/21 19:50:17z SPIFFS mounted.
7/06/21 15:50:17 Local time zone: -5:00
7/06/21 15:50:17 Using Daylight Saving Time (BST) when in effect.
7/06/21 15:50:17 device name: IotaWatt
7/06/21 15:50:17 HTTP server started
7/06/21 15:50:17 influxDB_v1: Starting, interval:10, url:http://192.168.1.64:8086
7/06/21 15:50:17 timeSync: service started.
7/06/21 15:50:17 statService: started.
7/06/21 15:50:17 dataLog: service started.
7/06/21 15:50:18 dataLog: Last log entry 07/06/21 15:50:10
7/06/21 15:50:21 WiFi connected. SSID=ATT6AbiV3A, IP=192.168.1.100, channel=6, RSSI -66db
7/06/21 15:50:21 MDNS responder started for hostname IotaWatt
7/06/21 15:50:21 LLMNR responder started for hostname IotaWatt
7/06/21 15:50:21 Updater: service started. Auto-update class is MINOR
7/06/21 15:50:21 influxDB_v1: Start posting at 09/30/20 21:16:30

** Restart **

SD initialized.
7/06/21 19:50:26z Real Time Clock is running. Unix time 1625601026
7/06/21 19:50:26z Reset reason: Software Watchdog
7/06/21 19:50:26z Trace: 32:35, 32:35, 32:37, 32:37, 32:37, 31:1, 1:6[6], 1:1[13], 1:2[14], 9:0[14], 9:0, 9:1, 8:4, 8:6, 8:8, 8:9, 9:3, 9:5, 9:9, 1:2, 1:3, 1:3, 1:6[1], 1:6[3], 1:5[31], 1:6[4], 31:0, 31:1, 31:2[3], 32:60, 32:60, 32:61
7/06/21 19:50:26z ESP8266 ChipID: 6195317
7/06/21 19:50:26z IoTaWatt 5.0, Firmware version 02_06_02
7/06/21 19:50:26z SPIFFS mounted.
7/06/21 15:50:26 Local time zone: -5:00
7/06/21 15:50:26 Using Daylight Saving Time (BST) when in effect.
7/06/21 15:50:26 device name: IotaWatt
7/06/21 15:50:26 HTTP server started
7/06/21 15:50:26 influxDB_v1: Starting, interval:10, url:http://192.168.1.64:8086
7/06/21 15:50:26 timeSync: service started.
7/06/21 15:50:26 statService: started.
7/06/21 15:50:26 dataLog: service started.
7/06/21 15:50:27 dataLog: Last log entry 07/06/21 15:50:20
7/06/21 15:50:30 WiFi connected. SSID=ATT6AbiV3A, IP=192.168.1.100, channel=6, RSSI -68db
7/06/21 15:50:30 MDNS responder started for hostname IotaWatt
7/06/21 15:50:30 LLMNR responder started for hostname IotaWatt
7/06/21 15:50:30 Updater: service started. Auto-update class is MINOR
7/06/21 15:50:30 influxDB_v1: Start posting at 09/30/20 21:16:30

** Restart **

SD initialized.
7/06/21 19:50:34z Real Time Clock is running. Unix time 1625601034
7/06/21 19:50:34z Reset reason: Software Watchdog
7/06/21 19:50:34z Trace: 32:35, 32:35, 32:37, 32:37, 32:37, 31:1, 1:6[6], 1:1, 1:2[1], 9:0[1], 9:0, 9:1, 8:4, 8:6, 8:8, 8:9, 9:3, 9:5, 9:9, 1:2, 1:3, 1:3, 1:6[1], 1:6[3], 1:5[31], 1:6[4], 31:0, 31:1, 31:2[3], 32:60, 32:60, 32:61
7/06/21 19:50:34z ESP8266 ChipID: 6195317
7/06/21 19:50:34z IoTaWatt 5.0, Firmware version 02_06_02
7/06/21 19:50:34z SPIFFS mounted.
7/06/21 15:50:34 Local time zone: -5:00
7/06/21 15:50:34 Using Daylight Saving Time (BST) when in effect.
7/06/21 15:50:34 device name: IotaWatt
7/06/21 15:50:34 HTTP server started
7/06/21 15:50:34 influxDB_v1: Starting, interval:10, url:http://192.168.1.64:8086
7/06/21 15:50:34 timeSync: service started.
7/06/21 15:50:34 statService: started.
7/06/21 15:50:34 dataLog: service started.
7/06/21 15:50:35 dataLog: Last log entry 07/06/21 15:50:30
7/06/21 15:50:38 Updater: service started. Auto-update class is MINOR
7/06/21 15:50:38 influxDB_v1: Start posting at 09/30/20 21:16:30

** Restart **

SD initialized.
7/06/21 19:50:42z Real Time Clock is running. Unix time 1625601042
7/06/21 19:50:42z Reset reason: Software Watchdog
7/06/21 19:50:42z Trace: 32:35, 32:35, 32:37, 32:37, 32:37, 31:1, 1:6[6], 1:1[5], 1:2[6], 9:0[6], 9:0, 9:1, 8:4, 8:6, 8:8, 8:9, 9:3, 9:5, 9:9, 1:2, 1:3, 1:3, 1:6[1], 1:6[3], 1:5[31], 1:6[4], 31:0, 31:1, 31:2[3], 32:60, 32:60, 32:61
7/06/21 19:50:42z ESP8266 ChipID: 6195317
7/06/21 19:50:42z IoTaWatt 5.0, Firmware version 02_06_02
7/06/21 19:50:42z SPIFFS mounted.
7/06/21 15:50:42 Local time zone: -5:00
7/06/21 15:50:42 Using Daylight Saving Time (BST) when in effect.
7/06/21 15:50:42 device name: IotaWatt
7/06/21 15:50:42 HTTP server started
7/06/21 15:50:42 influxDB_v1: Starting, interval:10, url:http://192.168.1.64:8086
7/06/21 15:50:42 timeSync: service started.
7/06/21 15:50:42 statService: started.
7/06/21 15:50:42 dataLog: service started.
7/06/21 15:50:43 dataLog: Last log entry 07/06/21 15:50:35
7/06/21 15:50:46 WiFi connected. SSID=ATT6AbiV3A, IP=192.168.1.100, channel=6, RSSI -66db
7/06/21 15:50:46 MDNS responder started for hostname IotaWatt
7/06/21 15:50:46 LLMNR responder started for hostname IotaWatt
7/06/21 15:50:46 Updater: service started. Auto-update class is MINOR
7/06/21 15:50:46 influxDB_v1: Start posting at 09/30/20 21:16:30

** Restart **

SD initialized.
7/06/21 19:50:50z Real Time Clock is running. Unix time 1625601050
7/06/21 19:50:50z Reset reason: Software Watchdog
7/06/21 19:50:50z Trace: 10:17, 10:18, 10:23, 10:17, 10:17, 10:17, 1:3, 1:1[10], 1:2[11], 9:0[11], 9:0, 9:1, 8:4, 8:6, 8:8, 8:9, 9:3, 9:5, 9:9, 1:2, 1:3, 1:3, 1:6[1], 1:6[3], 1:5[31], 1:6[4], 31:0, 31:1, 31:2[3], 32:60, 32:60, 32:61
7/06/21 19:50:50z ESP8266 ChipID: 6195317
7/06/21 19:50:50z IoTaWatt 5.0, Firmware version 02_06_02
7/06/21 19:50:50z SPIFFS mounted.
7/06/21 15:50:50 Local time zone: -5:00
7/06/21 15:50:50 Using Daylight Saving Time (BST) when in effect.
7/06/21 15:50:50 device name: IotaWatt
7/06/21 15:50:50 HTTP server started
7/06/21 15:50:50 influxDB_v1: Starting, interval:10, url:http://192.168.1.64:8086
7/06/21 15:50:50 timeSync: service started.
7/06/21 15:50:50 statService: started.
7/06/21 15:50:50 dataLog: service started.
7/06/21 15:50:51 dataLog: Last log entry 07/06/21 15:50:45
7/06/21 15:50:54 WiFi connected. SSID=ATT6AbiV3A, IP=192.168.1.100, channel=6, RSSI -65db
7/06/21 15:50:54 MDNS responder started for hostname IotaWatt
7/06/21 15:50:54 LLMNR responder started for hostname IotaWatt
7/06/21 15:50:54 Updater: service started. Auto-update class is MINOR
7/06/21 15:50:54 influxDB_v1: Start posting at 09/30/20 21:16:30
7/06/21 15:50:55 historyLog: service started.
7/06/21 15:50:55 historyLog: Last log entry 07/06/21 15:49:00
7/06/21 15:50:56 Updater: Auto-update is current for class MINOR.
7/06/21 18:52:20 influxDB_v1: stopped, Last post 10/10/20 13:20:20
7/06/21 20:04:15 dataLog: datalog WDT - restarting

** Restart **

SD initialized.
7/07/21 00:04:16z Real Time Clock is running. Unix time 1625616256
7/07/21 00:04:16z Reset reason: Software/System restart
7/07/21 00:04:16z Trace: 8:6, 8:8, 8:9, 9:3, 9:5, 9:9, 1:2, 1:3, 1:3, 1:6[1], 1:6[2], 1:6[2], 1:6[2], 1:6[2], 1:6[2], 1:6[3], 1:5[19], 1:6[4], 1:6[6], 1:1[4], 1:2[5], 9:0[5], 9:0, 9:1, 8:4, 8:6, 8:8, 8:9, 9:3, 9:5, 9:9, 1:2
7/07/21 00:04:16z ESP8266 ChipID: 6195317
7/07/21 00:04:16z IoTaWatt 5.0, Firmware version 02_06_02
7/07/21 00:04:16z SPIFFS mounted.
7/06/21 20:04:16 Local time zone: -5:00
7/06/21 20:04:16 Using Daylight Saving Time (BST) when in effect.
7/06/21 20:04:16 device name: IotaWatt
7/06/21 20:04:16 HTTP server started
7/06/21 20:04:16 influxDB_v1: Starting, interval:10, url:http://192.168.1.64:8086
7/06/21 20:04:16 timeSync: service started.
7/06/21 20:04:16 statService: started.
7/06/21 20:04:16 dataLog: service started.
7/06/21 20:04:17 dataLog: Last log entry 07/06/21 19:59:20
7/06/21 20:04:21 historyLog: service started.
7/06/21 20:04:21 historyLog: Last log entry 07/06/21 19:59:00
7/06/21 20:04:21 WiFi connected. SSID=ATT6AbiV3A, IP=192.168.1.100, channel=6, RSSI -70db
7/06/21 20:04:21 MDNS responder started for hostname IotaWatt
7/06/21 20:04:21 LLMNR responder started for hostname IotaWatt
7/06/21 20:04:21 Updater: service started. Auto-update class is MINOR
7/06/21 20:04:23 Updater: Auto-update is current for class MINOR.
7/06/21 20:04:23 influxDB_v1: stopped, Last post 10/10/20 13:20:20

Database has been stopped since last night and the notebook was hibernated. Just restarted the notebook and then restarted the database update and it took of from where it left off. Didn’t seem to skip any records. Last 2 lines of the log are the only thing that changed.

7/06/21 20:04:21 historyLog: Last log entry 07/06/21 19:59:00
7/06/21 20:04:21 WiFi connected. SSID=ATT6AbiV3A, IP=192.168.1.100, channel=6, RSSI -70db
7/06/21 20:04:21 MDNS responder started for hostname IotaWatt
7/06/21 20:04:21 LLMNR responder started for hostname IotaWatt
7/06/21 20:04:21 Updater: service started. Auto-update class is MINOR
7/06/21 20:04:23 Updater: Auto-update is current for class MINOR.
7/06/21 20:04:23 influxDB_v1: stopped, Last post 10/10/20 13:20:20
7/07/21 11:21:03 influxDB_v1: Start posting at 10/10/20 13:20:30
7/07/21 11:21:08 influxDB_v1: stopped, Last post 10/10/20 13:32:50

In the episode described above the PC is described as “shut-down” then “restarting”. In the initial problem description, the problem was described as being caused by “hibernating” and presumably subsequent awakening from hibernation. “Shut-down” and “sleep” are specific terms in Windows 10. While I recall hibernate being a term used in prior Windows versions, I don’t see it in Windows 10. I do think that there would be a significant difference in how influxDB works in sleep vs shut-down and essentially a restart.

The screenshot was taken at 17:07:45 on July 6. IoTaWatt had been uploading history and was at 10/10/2020 at 5:47:50 am (9:47UTC). -11 return code is a timeout, and the subsequent -4 is unable to connect.

The message log shows that the IoTaWatt was running at 17:07. As we know it thereafter experienced errors (-11 then -4) until influx restarted and the subsequent stop at 13:20:20 is logged.

The mystery here is how the time advanced without successful upload of the data. The influx data shows a gap between 5:47:50 (UTC-4) and 12:28:00. There has to be some kind of creep happening. I’ve looked at the error recovery code but will need to try to recreate to track it down.

This reinforces the idea that the posting time is advancing during error retry.

I could restart the database update, then shutdown (instead of hibernate) the notebook and restart it after 10 or 15 min and see if the time jump happens with a shutdown. Would that help the investigation any?

I’m running some tests. I think I see what’s going on.

I’ve isolated, reproduced and fixed the problem. Will integrate into a new release soon.

As an interim tip, you don’t need to stop the uploader before the laptop goes to sleep, just before it wakes up again. So if you were to miss a shutdown, stopping and then immediately restarting the uploader should change the message to “query failed”. Subsequently, when influx becomes available again, it will complete the query and pickup where it left off.

This problem will also effect influxDB2 users in the same way, but the fix will remedy that as well.

Thanks a bunch! It’s amazing nobody else apparently noticed this problem since Win10 (was it even a Win10 issue?) has been out for some time now. Or maybe I’m just weird for running all this stuff on a notebook that doesn’t stay on 24/7. How will I know when this is fixed? Just look for a new firmware version number? I’m at 02_06_02 right now and if I remember correctly this device updates automatically.

It has nothing to do with Windows 10. I reproduced it with influx running on an Rpi.

Well, yes you are off the beaten path, but it should (and will) work.

The next release will be 02_06_05. I post notices in the forum (notices Category) when auto-update changes are made.

You are on auto-update MINOR, which probably wont see this new release for a month or more. It will start out ALPHA → BETA → MINOR.

Yea, so much for the ALPHA and BETA vetting. This problem was introduced with release 02_06_00 when the uploaders were rewritten. It has been the MINOR release for two months.

Just curious, does my log look normal? Seems to be a lot of restarts. Had a few log entries in the log today that seem to be concerning:

7/06/21 20:04:15 dataLog: datalog WDT - restarting

** Restart **

SD initialized.
7/07/21 00:04:16z Real Time Clock is running. Unix time 1625616256

and

7/08/21 11:45:01 Heap memory has degraded below safe minimum, restarting.

** Restart **

SD initialized.
7/08/21 15:45:03z Real Time Clock is running. Unix time 1625759103

I saw those restarts. You mention two types, and there was a third.

datalog WDT. I only saw one of those. They are not normal and indicate that something was inhibiting normal operation to the extent that IoTaWatt was not logging to the datalog for an extended period. I would not expect to see many of these and restart does usually fix it.

Heap memory degraded. This is almost always related to HTTP error recovery. Unfortunately this could be a regular occurrence when your Emoncms goes offline and the IoTaWatt gets repeated timeout errors.

Another restart was caused by the hardware WDT. While I saw a string of these, it was before the gap that we were investigating. It seemed to disappear later as suddenly as it came on, and so I don’t believe it is an ongoing problem.