IottaWatt not posting to EmonCMS

Dave · March 18, 2021, 12:49pm

Hi Guys
I’m having a bit of an issue with two out of three IotaWatts not posting to EmonCMS.
This happened both at the same time yesterday and I’m a bit stumped with the error 11 which I have no idea means what?
Can anybody throw any ideas?

Regards

Dave

** Restart **

SD initialized.
3/17/21 23:43:07z Real Time Clock is running. Unix time 1616024587 
3/17/21 23:43:07z Reset reason: Software/System restart
3/17/21 23:43:07z Trace:  8:4, 8:6, 8:8, 8:9, 1:2, 1:3, 1:4, 1:5[3], 3:0, 3:6, 3:6, 3:6, 3:6, 3:6, 3:6, 1: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, 10:2, 10:3
3/17/21 23:43:07z ESP8266 ChipID: 2518071
3/17/21 23:43:07z IoTaWatt 4.x, Firmware version 02_05_12
3/17/21 23:43:07z SPIFFS mounted.
3/17/21 23:43:07z Local time zone: +0:00
3/17/21 23:43:07z Using Daylight Saving Time (BST) when in effect.
3/17/21 23:43:07z device name: House
3/17/21 23:43:07z HTTP server started
3/17/21 23:43:07z timeSync: service started.
3/17/21 23:43:07z statService: started.
3/17/21 23:43:07z dataLog: service started.
3/17/21 23:43:08z dataLog: Last log entry 03/17/21 23:43:05
3/17/21 23:43:12z EmonService: started. url=HTTP://energy.m0nne.com/emoncms, node=House, interval=5
3/17/21 23:43:12z WiFi connected. SSID=WiFi, IP=192.168.10.133, channel=1, RSSI -56db
3/17/21 23:43:12z MDNS responder started for hostname House
3/17/21 23:43:12z LLMNR responder started for hostname House
3/17/21 23:43:12z Updater: service started. Auto-update class is BETA
3/17/21 23:43:13z EmonService: Start posting at 03/17/21 14:19:00
3/17/21 23:43:13z Updater: Auto-update is current for class BETA.
3/17/21 23:44:08z historyLog: service started.
3/17/21 23:44:08z historyLog: Last log entry 03/17/21 23:43:00
3/17/21 23:45:29z EmonService: HTTP response -11, retrying.
3/17/21 23:47:01z EmonService: Stopped.  Last post 03/17/21 14:18:55
3/17/21 23:47:46z EmonService: started. url=HTTP://energy.m0nne.com/emoncms, node=House, interval=5
3/17/21 23:47:47z EmonService: Start posting at 03/17/21 14:21:00
3/17/21 23:50:00z EmonService: HTTP response -11, retrying.
3/17/21 23:51:18z EmonService: Stopped.  Last post 03/17/21 14:20:55
3/17/21 23:51:26z EmonService: started. url=HTTP://energy.m0nne.com/emoncms, node=House, interval=5, encrypted
3/17/21 23:51:27z EmonService: Start posting at 03/17/21 14:23:00
3/17/21 23:53:05z EmonService: Stopped.  Last post 03/17/21 14:22:55
3/17/21 23:54:06z EmonService: started. url=HTTP://energy.m0nne.com/emoncms, node=House, interval=5, encrypted
3/17/21 23:54:07z EmonService: Start posting at 03/17/21 14:25:00
3/17/21 23:56:43z EmonService: HTTP response -11, retrying.
3/18/21 00:02:42z EmonService: Stopped.  Last post 03/17/21 14:24:55
3/18/21 00:02:48z EmonService: started. url=HTTP://energy.m0nne.com/emoncms, node=House, interval=5, encrypted
3/18/21 00:02:49z EmonService: Start posting at 03/17/21 14:27:05
3/18/21 00:05:09z EmonService: HTTP response -11, retrying.
3/18/21 12:28:03z Updater: Auto-update class changed to MINOR
3/18/21 12:28:04z Updater: Auto-update is current for class MINOR.
3/18/21 12:28:18z Restart command received.

** Restart **

SD initialized.
3/18/21 12:28:20z Real Time Clock is running. Unix time 1616070500 
3/18/21 12:28:20z Reset reason: Software/System restart
3/18/21 12:28:20z Trace:  1:3, 1:4, 1:3, 1:4, 1:3, 1:4, 1:3, 1:4, 1:3, 1:4, 1:3, 1:4, 1:3, 1:4, 1:3, 1:4, 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, 1:3, 10:2, 10:3
3/18/21 12:28:20z ESP8266 ChipID: 2518071
3/18/21 12:28:20z IoTaWatt 4.x, Firmware version 02_05_12
3/18/21 12:28:20z SPIFFS mounted.
3/18/21 12:28:20z Local time zone: +0:00
3/18/21 12:28:20z Using Daylight Saving Time (BST) when in effect.
3/18/21 12:28:20z device name: House
3/18/21 12:28:20z HTTP server started
3/18/21 12:28:20z timeSync: service started.
3/18/21 12:28:20z statService: started.
3/18/21 12:28:20z dataLog: service started.
3/18/21 12:28:21z dataLog: Last log entry 03/18/21 12:28:15
3/18/21 12:28:24z WiFi connected. SSID=WiFi, IP=192.168.10.133, channel=1, RSSI -58db
3/18/21 12:28:24z MDNS responder started for hostname House
3/18/21 12:28:24z LLMNR responder started for hostname House
3/18/21 12:28:24z Updater: service started. Auto-update class is MINOR
3/18/21 12:28:25z EmonService: started. url=HTTP://energy.m0nne.com/emoncms, node=House, interval=5, encrypted
3/18/21 12:28:25z Updater: Auto-update is current for class MINOR.
3/18/21 12:28:26z EmonService: Start posting at 03/17/21 14:29:15
3/18/21 12:29:21z historyLog: service started.
3/18/21 12:29:21z historyLog: Last log entry 03/18/21 12:28:00
3/18/21 12:30:46z EmonService: HTTP response -11, retrying.

overeasy · March 18, 2021, 1:15pm

-11 is timeout trying to connect. From the Emoncms url shown, I can’t determine if it’s on your LAN or an instance elsewhere. Has anything changed with the Emoncms instance, your IoTaWatt Emoncms configuration, or your LAN?

Dave · March 18, 2021, 1:42pm

Hi Bob
That’s an internal address with a private IP inside the network and a port forwarded WAN address outside.
Nothing has changed and the three units I have are configured exactly the same.
One thing I noticed was that the two units that are not working were set to BETA updates and the one that is working is set to MINOR. Did you put out a firmware update yesterday?

Regards
Dave

overeasy · March 18, 2021, 2:39pm

You may have noticed a flurry of activity with a new release, but that is only with ALPHA auto-update. BETA, MINOR and MAJOR are not updated and running on a very solid 02_05_12 release. Your log verifies that.

I see that you have the userid set to 1 in that config. Could you remove that and see what happens? Not sure what the status of the encrypted protocol status is for various releases of private instance Emoncms.

Dave · March 18, 2021, 2:46pm

Hi Bob
Ive taken the user ID out without any success.
I can create you VPN access to the IotaWatt boxes if that helps?

Regards
Dave

overeasy · March 18, 2021, 3:03pm

Can you post the message logs from the system that is uploading and one that isn’t. Just from the most recent restart is fine.

Dave · March 18, 2021, 3:18pm

Hi Bob
Please see below.

Non-working IotaWatt…

** Restart **

SD initialized.
3/18/21 14:40:54z Real Time Clock is running. Unix time 1616078454 
3/18/21 14:40:54z Reset reason: Software/System restart
3/18/21 14:40:54z Trace:  8:9, 9:3, 9:5, 9:9, 1:2, 1:3, 1:4, 1:5[3], 3:0, 3:6, 3:6, 3:6, 3:6, 3:6, 3:6, 1:6, 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, 10:2, 10:3
3/18/21 14:40:54z ESP8266 ChipID: 2518071
3/18/21 14:40:54z IoTaWatt 4.x, Firmware version 02_05_12
3/18/21 14:40:54z SPIFFS mounted.
3/18/21 14:40:54z Local time zone: +0:00
3/18/21 14:40:54z device name: House
3/18/21 14:40:54z HTTP server started
3/18/21 14:40:54z timeSync: service started.
3/18/21 14:40:54z statService: started.
3/18/21 14:40:54z dataLog: service started.
3/18/21 14:40:55z dataLog: Last log entry 03/18/21 14:40:50
3/18/21 14:40:58z WiFi connected. SSID=WiFi, IP=192.168.10.133, channel=1, RSSI -58db
3/18/21 14:40:58z MDNS responder started for hostname House
3/18/21 14:40:58z LLMNR responder started for hostname House
3/18/21 14:40:58z Updater: service started. Auto-update class is MINOR
3/18/21 14:40:59z EmonService: started. url=HTTP://energy.m0nne.com/emoncms, node=House, interval=5
3/18/21 14:40:59z Updater: Auto-update is current for class MINOR.
3/18/21 14:41:00z EmonService: Start posting at 03/18/21 00:02:10
3/18/21 14:41:55z historyLog: service started.
3/18/21 14:41:55z historyLog: Last log entry 03/18/21 14:40:00
3/18/21 14:43:10z EmonService: HTTP response -11, retrying.

Working IotaWatt…

** Restart **

SD initialized.
3/13/21 19:56:00z Real Time Clock is running. Unix time 1615665360 
3/13/21 19:56:00z Power failure detected.
3/13/21 19:56:00z Reset reason: External System
3/13/21 19:56:00z ESP8266 ChipID: 12674490
3/13/21 19:56:00z IoTaWatt 5.0, Firmware version 02_05_12
3/13/21 19:56:00z SPIFFS mounted.
3/13/21 19:56:00z Local time zone: +0:00
3/13/21 19:56:00z Using Daylight Saving Time (BST) when in effect.
3/13/21 19:56:00z device name: IotaLoft
3/13/21 19:56:03z Connecting with WiFiManager.
3/13/21 19:56:06z HTTP server started
3/13/21 19:56:06z WiFi connected. SSID=WiFi, IP=192.168.10.134, channel=6, RSSI -44db
3/13/21 19:56:06z MDNS responder started for hostname IotaLoft
3/13/21 19:56:06z LLMNR responder started for hostname IotaLoft
3/13/21 19:56:06z timeSync: service started.
3/13/21 19:56:06z statService: started.
3/13/21 19:56:06z Updater: service started. Auto-update class is MINOR
3/13/21 19:56:06z dataLog: service started.
3/13/21 19:56:06z dataLog: Last log entry 03/13/21 19:54:25
3/13/21 19:56:07z Updater: Auto-update is current for class MINOR.
3/13/21 19:56:11z EmonService: started. url=HTTP://energy.m0nne.com/emoncms, node=IotaLoft, interval=5, encrypted
3/13/21 19:56:12z EmonService: Start posting at 03/13/21 19:54:30
3/13/21 19:57:06z historyLog: service started.
3/13/21 19:57:06z historyLog: Last log entry 03/13/21 19:54:00
3/17/21 14:21:36z EmonService: HTTP response -11, retrying.
3/17/21 14:23:24z EmonService: Retry successful after 46 attempts.

overeasy · March 18, 2021, 3:37pm

I see a couple of things here:

These two machines, while on the same SSID, are using different channels. Do you have a mesh network or range extenders in your WiFi topology?

Yesterday, at 14:21, there was about a two minute lapse in communication with the Emoncms server from the “working” unit. Is that when your problems started with the other two? Can I see the log segments covering that time for the two “non-working” i.e. working fine but not uploading units?

At this point, it looks like most likely a network issue, and secondarily perhaps an Emoncms host issue.

Dave · March 18, 2021, 3:50pm

Hi Bob
Yes I have four AP’s over the house so the diffrent channels are expected.
Below is the log from both of the non working units.

3/01/21 23:25:06z Real Time Clock is running. Unix time 1614641106 
3/01/21 23:25:06z Reset reason: Software/System restart
3/01/21 23:25:06z Trace:  3:0, 3:11, 21:110, 21:110, 21:110[1], 3:11, 3:11, 3:11, 1:6, 1:3, 1:4, 1:5[3], 3:0, 3:6, 3:6, 3:6, 3:6, 3:6, 3:6, 1:6, 1:1[6], 1:2, 9:0, 9:0, 8:4, 8:6, 8:8, 8:9, 1:2, 1:3, 10:2, 10:3
3/01/21 23:25:06z ESP8266 ChipID: 2871252
3/01/21 23:25:06z IoTaWatt 4.x, Firmware version 02_05_12
3/01/21 23:25:06z SPIFFS mounted.
3/01/21 23:25:06z Local time zone: +0:00
3/01/21 23:25:06z Using Daylight Saving Time (BST) when in effect.
3/01/21 23:25:06z device name: Shed
3/01/21 23:25:07z HTTP server started
3/01/21 23:25:07z timeSync: service started.
3/01/21 23:25:07z statService: started.
3/01/21 23:25:07z dataLog: service started.
3/01/21 23:25:10z dataLog: Last log entry 03/01/21 23:25:00
3/01/21 23:25:12z EmonService: started. url=HTTP://energy.m0nne.com/emoncms, node=Shed, interval=5
3/01/21 23:25:12z Updater: service started. Auto-update class is BETA
3/01/21 23:25:12z WiFi connected. SSID=WiFi, IP=192.168.10.132, channel=6, RSSI -44db
3/01/21 23:25:12z MDNS responder started for hostname Shed
3/01/21 23:25:12z LLMNR responder started for hostname Shed
3/01/21 23:25:13z EmonService: Start posting at 11/12/19 00:34:20
3/01/21 23:25:13z Updater: Auto-update is current for class BETA.
3/01/21 23:26:08z historyLog: service started.
3/01/21 23:26:09z historyLog: Last log entry 11/21/20 05:00:00
3/01/21 23:35:51z EmonService: Stopped.  Last post 11/12/19 13:19:15
3/01/21 23:35:53z EmonService: started. url=HTTP://energy.m0nne.com/emoncms, node=Shed, interval=5
3/01/21 23:35:54z EmonService: Start posting at 11/12/19 13:19:20
3/01/21 23:41:13z EmonService: Stopped.  Last post 11/12/19 18:32:00
3/01/21 23:41:15z EmonService: started. url=HTTP://energy.m0nne.com/emoncms, node=Shed, interval=5
3/01/21 23:41:16z EmonService: Start posting at 03/01/21 00:00:05
3/02/21 00:38:47z EmonService: HTTP response -4, retrying.
3/02/21 06:28:19z EmonService: Retry successful after 439 attempts.
3/03/21 10:37:11z WiFi disconnected.
3/03/21 10:37:12z WiFi connected. SSID=WiFi, IP=192.168.10.132, channel=6, RSSI -43db
3/08/21 18:41:22z Updater: Invalid response from server. HTTPcode: -4
3/12/21 21:32:40z EmonService: Invalid response, retrying.
3/12/21 21:37:30z EmonService: Retry successful after 89 attempts.
3/17/21 14:21:37z EmonService: HTTP response -11, retrying.
3/17/21 23:43:15z Restart command received.

** Restart **

SD initialized.
3/17/21 23:43:17z Real Time Clock is running. Unix time 1616024597 
3/17/21 23:43:17z Reset reason: Software/System restart
3/17/21 23:43:17z Trace:  1:4, 1:3, 1:4, 1:3, 1:4, 1:3, 1:4, 1:3, 1:4, 1:3, 1:4, 1:3, 1:4, 1:3, 1:4, 1:3, 1:4, 1:3, 1:4, 1:3, 1:4, 1:3, 1:4, 1:3, 1:4, 1:3, 1:4, 1:3, 1:4, 1:3, 10:2, 10:3
3/17/21 23:43:17z ESP8266 ChipID: 2871252
3/17/21 23:43:17z IoTaWatt 4.x, Firmware version 02_05_12
3/17/21 23:43:17z SPIFFS mounted.
3/17/21 23:43:17z Local time zone: +0:00
3/17/21 23:43:17z Using Daylight Saving Time (BST) when in effect.
3/17/21 23:43:17z device name: Shed
3/17/21 23:43:18z HTTP server started
3/17/21 23:43:18z timeSync: service started.
3/17/21 23:43:18z statService: started.
3/17/21 23:43:18z dataLog: service started.
3/17/21 23:43:21z dataLog: Last log entry 03/17/21 23:43:15
3/17/21 23:43:23z EmonService: started. url=HTTP://energy.m0nne.com/emoncms, node=Shed, interval=5
3/17/21 23:43:23z WiFi connected. SSID=WiFi, IP=192.168.10.132, channel=6, RSSI -42db
3/17/21 23:43:23z MDNS responder started for hostname Shed
3/17/21 23:43:23z LLMNR responder started for hostname Shed
3/17/21 23:43:23z Updater: service started. Auto-update class is BETA
3/17/21 23:43:24z EmonService: Start posting at 03/17/21 14:17:10
3/17/21 23:43:24z Updater: Auto-update is current for class BETA.
3/17/21 23:44:19z historyLog: service started.
3/17/21 23:44:20z historyLog: Last log entry 03/17/21 23:43:00
3/17/21 23:45:18z EmonService: Stopped.  Last post 03/17/21 14:17:05
3/17/21 23:46:47z EmonService: started. url=HTTP://energy.m0nne.com/emoncms, node=Shed, interval=5
3/17/21 23:46:49z EmonService: Start posting at 03/17/21 14:19:15
3/17/21 23:49:05z EmonService: HTTP response -11, retrying.
3/17/21 23:51:11z EmonService: Stopped.  Last post 03/17/21 14:19:10
3/17/21 23:51:22z EmonService: started. url=HTTP://energy.m0nne.com/emoncms, node=Shed, interval=5, encrypted
3/17/21 23:51:23z EmonService: Start posting at 03/17/21 14:21:25
3/17/21 23:53:09z EmonService: Stopped.  Last post 03/17/21 14:21:20
3/17/21 23:54:10z EmonService: started. url=HTTP://energy.m0nne.com/emoncms, node=Shed, interval=5, encrypted
3/17/21 23:54:11z EmonService: Start posting at 03/17/21 14:23:35
3/17/21 23:56:41z EmonService: HTTP response -11, retrying.
3/18/21 00:02:45z EmonService: Stopped.  Last post 03/17/21 14:23:30
3/18/21 00:02:51z EmonService: started. url=HTTP://energy.m0nne.com/emoncms, node=Shed, interval=5, encrypted
3/18/21 00:02:52z EmonService: Start posting at 03/17/21 14:25:40
3/18/21 00:05:11z EmonService: HTTP response -11, retrying.
3/18/21 12:28:07z Updater: Auto-update class changed to MINOR
3/18/21 12:28:08z Updater: Auto-update is current for class MINOR.
3/18/21 12:28:14z Restart command received.

3/07/21 22:18:01z LLMNR responder started for hostname House
3/07/21 22:18:01z timeSync: service started.
3/07/21 22:18:01z statService: started.
3/07/21 22:18:01z Updater: service started. Auto-update class is BETA
3/07/21 22:18:01z dataLog: service started.
3/07/21 22:18:02z dataLog: Last log entry 03/07/21 22:17:45
3/07/21 22:18:03z Updater: Auto-update is current for class BETA.
3/07/21 22:18:06z EmonService: started. url=HTTP://energy.m0nne.com/emoncms, node=House, interval=5
3/07/21 22:18:07z EmonService: Start posting at 03/07/21 22:17:50
3/07/21 22:19:01z historyLog: service started.
3/07/21 22:19:01z historyLog: Last log entry 03/07/21 22:17:00
3/17/21 14:21:33z EmonService: HTTP response -11, retrying.
3/17/21 23:36:21z Restart command received.

** Restart **

SD initialized.
3/17/21 23:36:24z Real Time Clock is running. Unix time 1616024184 
3/17/21 23:36:24z Reset reason: Software/System restart
3/17/21 23:36:24z Trace:  1:4, 1:1[3], 1:2[4], 9:0[4], 9:0, 9:1, 8:4, 8:6, 8:8, 8:9, 9:3, 9:5, 9:9, 1:2, 1:3, 1:4, 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, 1:3, 10:2, 10:3
3/17/21 23:36:24z ESP8266 ChipID: 2518071
3/17/21 23:36:24z IoTaWatt 4.x, Firmware version 02_05_12
3/17/21 23:36:24z SPIFFS mounted.
3/17/21 23:36:24z Local time zone: +0:00
3/17/21 23:36:24z Using Daylight Saving Time (BST) when in effect.
3/17/21 23:36:24z device name: House
3/17/21 23:36:24z HTTP server started
3/17/21 23:36:24z timeSync: service started.
3/17/21 23:36:24z statService: started.
3/17/21 23:36:24z dataLog: service started.
3/17/21 23:36:25z dataLog: Last log entry 03/17/21 23:36:20
3/17/21 23:36:28z WiFi connected. SSID=WiFi, IP=192.168.10.133, channel=1, RSSI -59db
3/17/21 23:36:28z MDNS responder started for hostname House
3/17/21 23:36:28z LLMNR responder started for hostname House
3/17/21 23:36:28z Updater: service started. Auto-update class is BETA
3/17/21 23:36:29z EmonService: started. url=HTTP://energy.m0nne.com/emoncms, node=House, interval=5
3/17/21 23:36:29z Updater: Auto-update is current for class BETA.
3/17/21 23:36:30z EmonService: Start posting at 03/17/21 14:17:00
3/17/21 23:37:25z historyLog: service started.
3/17/21 23:37:25z historyLog: Last log entry 03/17/21 23:36:00
3/17/21 23:38:39z EmonService: HTTP response -11, retrying.
3/17/21 23:43:05z Restart command received.

** Restart **

SD initialized.
3/17/21 23:43:07z Real Time Clock is running. Unix time 1616024587 
3/17/21 23:43:07z Reset reason: Software/System restart
3/17/21 23:43:07z Trace:  8:4, 8:6, 8:8, 8:9, 1:2, 1:3, 1:4, 1:5[3], 3:0, 3:6, 3:6, 3:6, 3:6, 3:6, 3:6, 1: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, 10:2, 10:3
3/17/21 23:43:07z ESP8266 ChipID: 2518071
3/17/21 23:43:07z IoTaWatt 4.x, Firmware version 02_05_12
3/17/21 23:43:07z SPIFFS mounted.
3/17/21 23:43:07z Local time zone: +0:00
3/17/21 23:43:07z Using Daylight Saving Time (BST) when in effect.
3/17/21 23:43:07z device name: House
3/17/21 23:43:07z HTTP server started
3/17/21 23:43:07z timeSync: service started.
3/17/21 23:43:07z statService: started.
3/17/21 23:43:07z dataLog: service started.
3/17/21 23:43:08z dataLog: Last log entry 03/17/21 23:43:05
3/17/21 23:43:12z EmonService: started. url=HTTP://energy.m0nne.com/emoncms, node=House, interval=5
3/17/21 23:43:12z WiFi connected. SSID=WiFi, IP=192.168.10.133, channel=1, RSSI -56db
3/17/21 23:43:12z MDNS responder started for hostname House
3/17/21 23:43:12z LLMNR responder started for hostname House
3/17/21 23:43:12z Updater: service started. Auto-update class is BETA
3/17/21 23:43:13z EmonService: Start posting at 03/17/21 14:19:00
3/17/21 23:43:13z Updater: Auto-update is current for class BETA.
3/17/21 23:44:08z historyLog: service started.
3/17/21 23:44:08z historyLog: Last log entry 03/17/21 23:43:00
3/17/21 23:45:29z EmonService: HTTP response -11, retrying.
3/17/21 23:47:01z EmonService: Stopped.  Last post 03/17/21 14:18:55
3/17/21 23:47:46z EmonService: started. url=HTTP://energy.m0nne.com/emoncms, node=House, interval=5
3/17/21 23:47:47z EmonService: Start posting at 03/17/21 14:21:00
3/17/21 23:50:00z EmonService: HTTP response -11, retrying.
3/17/21 23:51:18z EmonService: Stopped.  Last post 03/17/21 14:20:55
3/17/21 23:51:26z EmonService: started. url=HTTP://energy.m0nne.com/emoncms, node=House, interval=5, encrypted
3/17/21 23:51:27z EmonService: Start posting at 03/17/21 14:23:00
3/17/21 23:53:05z EmonService: Stopped.  Last post 03/17/21 14:22:55
3/17/21 23:54:06z EmonService: started. url=HTTP://energy.m0nne.com/emoncms, node=House, interval=5, encrypted
3/17/21 23:54:07z EmonService: Start posting at 03/17/21 14:25:00
3/17/21 23:56:43z EmonService: HTTP response -11, retrying.
3/18/21 00:02:42z EmonService: Stopped.  Last post 03/17/21 14:24:55
3/18/21 00:02:48z EmonService: started. url=HTTP://energy.m0nne.com/emoncms, node=House, interval=5, encrypted
3/18/21 00:02:49z EmonService: Start posting at 03/17/21 14:27:05
3/18/21 00:05:09z EmonService: HTTP response -11, retrying.
3/18/21 12:28:03z Updater: Auto-update class changed to MINOR
3/18/21 12:28:04z Updater: Auto-update is current for class MINOR.
3/18/21 12:28:18z Restart command received.

** Restart **

SD initialized.
3/18/21 12:28:20z Real Time Clock is running. Unix time 1616070500 
3/18/21 12:28:20z Reset reason: Software/System restart
3/18/21 12:28:20z Trace:  1:3, 1:4, 1:3, 1:4, 1:3, 1:4, 1:3, 1:4, 1:3, 1:4, 1:3, 1:4, 1:3, 1:4, 1:3, 1:4, 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, 1:3, 10:2, 10:3
3/18/21 12:28:20z ESP8266 ChipID: 2518071
3/18/21 12:28:20z IoTaWatt 4.x, Firmware version 02_05_12
3/18/21 12:28:20z SPIFFS mounted.
3/18/21 12:28:20z Local time zone: +0:00
3/18/21 12:28:20z Using Daylight Saving Time (BST) when in effect.
3/18/21 12:28:20z device name: House
3/18/21 12:28:20z HTTP server started
3/18/21 12:28:20z timeSync: service started.
3/18/21 12:28:20z statService: started.
3/18/21 12:28:20z dataLog: service started.
3/18/21 12:28:21z dataLog: Last log entry 03/18/21 12:28:15
3/18/21 12:28:24z WiFi connected. SSID=WiFi, IP=192.168.10.133, channel=1, RSSI -58db
3/18/21 12:28:24z MDNS responder started for hostname House
3/18/21 12:28:24z LLMNR responder started for hostname House
3/18/21 12:28:24z Updater: service started. Auto-update class is MINOR
3/18/21 12:28:25z EmonService: started. url=HTTP://energy.m0nne.com/emoncms, node=House, interval=5, encrypted
3/18/21 12:28:25z Updater: Auto-update is current for class MINOR.
3/18/21 12:28:26z EmonService: Start posting at 03/17/21 14:29:15
3/18/21 12:29:21z historyLog: service started.
3/18/21 12:29:21z historyLog: Last log entry 03/18/21 12:28:00
3/18/21 12:30:46z EmonService: HTTP response -11, retrying.
3/18/21 13:39:18z Restart command received.

overeasy · March 18, 2021, 3:56pm

So all three units stopped communicating with Emoncms at 14:21. One recovered and was able to resume communications after two minutes. The other two not so much. At this point it seems unlikely that all three of your units would fail out-of-the-blue at exactly the same time. The common threads are your network and the Emoncms instance.

Have you looked at the Emoncms logs? Tried restarting your Emoncms instance? Tried restarting your router and APs?

Dave · March 21, 2021, 3:20am

Hi Bob
Sorry for the delay in my reply, I’ve managed to resolve the issue by issuing the command “/command?deletelog=both”, after restarting the unit started posting to the EmonCMS server again.
I haven’t done the other IotaWatt in case you would like anything from it to debug?

Regards

Dave

overeasy · March 21, 2021, 2:38pm

I believe I demonstrated conclusively that all three of your units ceased communications with your Emoncms server at exactly the same time. One of them subsequently resumed communicating with the server after several minutes and the other two remained incommunicado and were the reason for posting the problem here.

Since the introduction of release 02_05_nn there have been only a few datalog issues raised, and only three or four where deleting the logs was the recommended solution. It is an action of last resort and is prompted by specific symptoms.

The notion that all three of your units were simultaneously afflicted with datalog damage, and that such damage would cause them cease Emoncms upload but otherwise remain fully functional, is - and I do not use this word lightly - impossible.

Three days ago I suggested several areas of investigation to discover the root of the problem which evidence strongly indicates is external to IoTaWatt. There is no indication that any of those suggestions were fully explored.

I suggested restarting the Emoncms server and also the router and access points. But even after doing that, the uploads might not have resumed until then restarting the IoTaWatt. When you nuke your datalogs with that command, it forces a restart of the IoTaWatt. That was probably what made the final connection and got your Emoncms upload working again.

I would strongly recommend against using that command again. There is absolutely no indication of datalog damage. I would also strongly caution other users against using that command without first asking for support via this forum and having it recommended.

Dave · March 21, 2021, 3:23pm

Hi Bob
I did restart the EmonCMS server, the AP’s network switch and router several times without any success. I’ve even restarted the non-posting unit again without success as I have two units posting to the EmonCMS currently.
Your help and support is appreciated and followed intently as you are far more knowledgeable than me.
Would you like me to download the datalog on the last non-posting unit?

Regards
Dave

overeasy · March 21, 2021, 3:36pm

One consequence of nuking your datalog is that uploads will then restart at the time the log was wiped. So if not a communications problem, it may be an Emoncms server issue with posting to that time. There are other, much less drastic ways to get IoTaWatt to skip ahead in. The Emoncms upload.

Have you checked the Emoncms logs for any unusual conditions at the time of the original failure? Are there any problems indicated in the logs since?

What I would do if it were happening here is use wire shark to see what the response actually is to IoTaWatt communication to Emoncms.

Can you use Graph+ to view the data from the time of the failure? If you zero in on the exact time, to 5 minute intervals, is there anything unusual?

How about lookin at the data in Emoncms? What does it have from those nodes at the time of original failure?

What does Emoncms show in the inputs screen for those nodes?

Dave · March 21, 2021, 7:08pm

Hi Bob
I’ve checked the EmonCMS logs and it appears to only go as far back as the last restart, the only thing I can see is people on the internet trying URL’s as it’s accessible from the internet.
I’ve not used Wireshark before I’m afraid Bob, Ive attached some screenshots below.

overeasy · March 21, 2021, 9:52pm

It looks as if there are no real issues with the IoTaWatt datalog, although it’s not 5 second intervals.

When I look at the IoTaWatt message logs for the failure and the period right after, I see that all of the failures happened at 14:21, and that upon restart, IoTaWatt was able to successfully query the last post time and restart. This happens several times and each time the query returns a time advanced about 2 minutes, which is about the amount of data IoTaWatt would have sent during a bulk update. But each time the posting write times out, so it looks as though Emoncms did not send an acknowledgement each time. Yet there was apparently a valid response to the last post query and the inputs were apparently updated. So it looks like something with Emoncms. Potentially there could be something wrong with the data from IoTaWatt, but the possibility that all three would have had that issue, at the same time, and have the issue recur at least each 2 minutes for the 6 or 8 minutes shown in the message log is implausible.

So I think the issue is with Emoncms. Lets try something different. For the House machine, which I believe is the remaining “stuck” unit, can you change the node name to something like House1 and set the upload from date to 3/17/21 then save.

It should create a new node and begin updating. Don’t worry, if and when you get your Emoncms fixed, you can reset the node to House and it will pick up at the appropriate place. After you see the updates progressing in the status display, look at the Emoncms inputs display and you should see the new node with the values changing. Let it run until it either stops at 14:21 or blows through.

Let me know the result.

Dave · March 22, 2021, 3:43pm

Hi Bob
I’ve renamed the node and the IotaWatt has caught up posting to the EmonCMS server and is posting every 5 seconds.

overeasy · March 22, 2021, 5:17pm

OK, that pretty much proves it’s not the IoTaWatt, and that the problem is with the Emoncms instance and not the network. Next thing would be to change it back to node House and see if it’s still stuck. If so, I can give you a URL to send to Emoncms to reset the last update to a later date.

Dave · March 24, 2021, 2:40pm

Hi Bob
I’ve changed it back to House and it’s all working again, very odd as I deleted the emoncms server and recreated it.

Thank you for your help Bob

Rehgards
Dave