Emoncms update stopped

joji · September 11, 2018, 5:12am

So I have an IotaWatt running in a remote location. i.e. don’t have handy access to it.
It stopped updating EmonCMS server. I asked a non-techie to do a powercycle on it to no avail. This went on for a month.

Then I accessed it via remote desktop software and everything seemed okay. IotaWatt has been running all this time and all the data is available onboard the sd card. The Led was glowing green, the wifi was connected. Its just that the EmonCMS server was not getting updated. It was eventually solved when I deleted the API key and pasted it again and saved the webpage that IotaWatt started updating the server again. (however the historical data was never updated).

I append some of the logs below. What I don’t understand is the entry, which happens exactly 5 hours after bootup. I have also attached a longer here: emonslog3.txt (476.6 KB)

9/11/18 07:42:50 device name: IotaWatt, version: 3
9/11/18 07:42:50 Local time zone: 5
9/11/18 07:42:53 MDNS responder started
9/11/18 07:42:53 You can now connect to http://IotaWatt.local

** Restart **

No clock yet: SD initialized.
9/11/18 01:57:20 Real Time Clock is running. Unix time: 1536631040
9/11/18 01:57:20 Version: 02_02_30
9/11/18 01:57:20 Reset reason: Software/System restart
9/11/18 01:57:20 Trace: 88,93,94,95,99,12,13,14,15,16,13,14,15,16,13,14,15,30,37,38,148,149,140,142,143,144,145,148,149,146,147,39
9/11/18 01:57:20 ESP8266 ChipID:6902565
9/11/18 06:57:20 device name: IotaWatt, version: 3
9/11/18 06:57:20 Local time zone: 5
9/11/18 06:57:23 MDNS responder started
9/11/18 06:57:23 You can now connect to http://IotaWatt.local
9/11/18 06:57:23 HTTP server started
9/11/18 06:57:23 dataLog: service started.
9/11/18 06:57:24 dataLog: Last log entry:1536631035
9/11/18 06:57:24 statService: started.
9/11/18 06:57:24 timeSync: service started.
9/11/18 06:57:24 WiFi connected. SSID: ZONG MBB-E5573-D5B9, IP: 192.168.8.100
9/11/18 06:57:24 historyLog: service started.
9/11/18 06:57:25 historyLog: Last log entry:1536631020
9/11/18 06:57:28 EmonService: started.url: emoncms.org:80, node: AlMustafa, post interval: 10, encrypted POST
9/11/18 06:57:28 EmonService: Start posting at 1534225150
9/11/18 06:57:35 EmonService: POST failed. HTTP code:read Timeout
9/11/18 06:58:35 EmonService: Resending EmonCMS data:2
9/11/18 07:00:37 EmonService: Resending EmonCMS data:3
9/11/18 07:02:31 timeSync: Failed to get NTPtime.
9/11/18 07:03:38 EmonService: Resending EmonCMS data:4
9/11/18 07:07:39 EmonService: Resending EmonCMS data:5
9/11/18 07:12:40 EmonService: Resending EmonCMS data:6
9/11/18 07:17:54 WiFi disconnected.
9/11/18 07:17:57 WiFi connected. SSID: ZONG MBB-E5573-D5B9, IP: 192.168.8.100
9/11/18 07:18:42 EmonService: Resending EmonCMS data:7
9/11/18 07:23:56 WiFi disconnected.
9/11/18 07:23:59 WiFi connected. SSID: ZONG MBB-E5573-D5B9, IP: 192.168.8.100
9/11/18 07:25:43 EmonService: Resending EmonCMS data:8
9/11/18 07:30:57 WiFi disconnected.
9/11/18 07:31:00 WiFi connected. SSID: ZONG MBB-E5573-D5B9, IP: 192.168.8.100
9/11/18 07:33:45 EmonService: Resending EmonCMS data:9
9/11/18 07:38:59 WiFi disconnected.
9/11/18 07:39:02 WiFi connected. SSID: ZONG MBB-E5573-D5B9, IP: 192.168.8.100
9/11/18 07:42:47 EmonService: Resending EmonCMS data:10
9/11/18 07:42:49 EmonService: Unable to post to Emoncms after 10 retries. Restarting ESP.

** Restart **

No clock yet: SD initialized.
9/11/18 02:42:50 Real Time Clock is running. Unix time: 1536633770
9/11/18 02:42:50 Version: 02_02_30
9/11/18 02:42:50 Reset reason: Software/System restart
9/11/18 02:42:50 Trace: 88,93,94,95,99,12,13,14,15,16,13,14,15,16,13,14,15,30,37,38,148,149,140,142,143,144,145,148,149,146,147,39
9/11/18 02:42:50 ESP8266 ChipID:6902565
9/11/18 07:42:50 device name: IotaWatt, version: 3
9/11/18 07:42:50 Local time zone: 5
9/11/18 07:42:53 MDNS responder started
9/11/18 07:42:53 You can now connect to http://IotaWatt.local
9/11/18 07:42:53 HTTP server started
9/11/18 07:42:53 dataLog: service started.
9/11/18 07:42:53 dataLog: Last log entry:1536633765
9/11/18 07:42:53 statService: started.
9/11/18 07:42:54 timeSync: service started.
9/11/18 07:42:54 WiFi connected. SSID: ZONG MBB-E5573-D5B9, IP: 192.168.8.100
9/11/18 07:42:54 historyLog: service started.
9/11/18 07:42:55 historyLog: Last log entry:1536633720
9/11/18 07:42:58 EmonService: started.url: emoncms.org:80, node: AlMustafa, post interval: 10, encrypted POST
9/11/18 07:42:58 EmonService: Start posting at 1534225150
9/11/18 07:43:05 EmonService: POST failed. HTTP code:read Timeout
9/11/18 07:44:05 EmonService: Resending EmonCMS data:2
9/11/18 07:46:06 EmonService: Resending EmonCMS data:3
9/11/18 07:49:07 EmonService: Resending EmonCMS data:4
9/11/18 07:53:08 EmonService: Resending EmonCMS data:5
9/11/18 07:58:09 EmonService: Resending EmonCMS data:6
9/11/18 08:00:41 Server: Sent less data than expected!
9/11/18 08:04:11 EmonService: started.url: emoncms.org:80, node: AlMustafa1, post interval: 10, unsecure GET
9/11/18 08:04:11 EmonService: Start posting at 1536635050
9/11/18 08:05:06 timeSync: Failed to get NTPtime.
9/11/18 08:11:18 Server: Sent less data than expected!
9/11/18 08:24:58 Server: Sent less data than expected!

overeasy · September 11, 2018, 2:32pm

That’s a red-herring. What’s going on is that when first started, the log entries are timestamped with UTC, which is what the real-time-clock is set to. A few lines later, when the configuration file is processed, the time zone is updated and the time becomes local time, which is 5 hours ahead of UTC in your case. Newer releases add a “z” to the end of the UTC times to eliminate that confusion.

But that’s not your real problem. It’s that you cannot seem to get your IoTaWatt to upload to Emoncms. As you note, it appears to be monitoring OK, so the data is there, it just doesn’t seem to be updating Emoncms.

Before I go any further, I want to note that you are still on release 02_02_30. That release was a workhorse, and there are a lot of systems still running it, but there have been a lot of improvements along the way, and a lot of things fixed. Most notably, there is a new underlying IP firmware integrated into the current release 02_03_13 which is at MINOR level and will be going to MAJOR release very soon.

What is bizarre about your system is that the WiFi seems to drop after almost exactly 20 minutes after the initial connection. It then reconnects and drops as subsequent Emoncms retries are made. You are currently trying to upload history after August 14 5:39am UTC, so this has been going on for nearly a month as you say.

Since you don’t have easy access to the IoTaWatt, I’d like you to try a simple trick to get IoTaWatt to skip ahead a little with the updating. When it starts up, it queries Emoncms for the time of the last update and picks up from there. Id like to have you send a data point for that node that is an hour past the current last update, so that IoTaWatt will try to resume there and leapfrog over any potential bad transaction that is hanging it up.

Here’s the transaction:

http://emoncms.org/input/post?time=1536640560&node=AlMustafa&json={deleteme:0}&apikey=<your write key>

You can copy and paste it as is then substitute your api key. After you send it, you should get a response “ok”. After you do that, the next time IoTaWatt restarts, Emoncms should try to start posting after 1536640560, which is an hour later. Let me know what happens after that.

joji · September 12, 2018, 12:28am

Hey,
Wow!! Many thanks for such a detailed response.
Thanks for the clarification ala 5 hours jump. Makes a lot more sense.

I have sent the command to emoncms server and it did respond back with OK. I’ll wait and see if IotaWatt now uploads the missing data.

I will also try and update to firmware version 2_03_13 once it goes MAJOR and I have access to IotaWatt and report back.

joji · September 17, 2018, 1:58pm

Hello @overeasy.
So, one thing that has happened is that I have lost about a month worth of data between 16July and 14thAug on EmonCMS server after I issued the command you suggested. But that’s not a big issue as the phase sequence was not correct so that wattage was not accurate any way. But it might be interesting to find the reason for that.
IotaWatt has been logging and uploading successfully to EmonCMS server for the past week, so I don’t wish to restart it for now as we are collecting data to size the solar panel installation for the building. I will report back on this after we have restarted IotaWatt.

If I may, I wish to get your opinion on a certain application here. All of our IotaWatt installations are in Pakistan (We are a non-profit helping hospitals, schools, orphanages fight power shortages by installing solar power plants using the donations we receive. We use IotaWatt to size the plant and then monitor plant performance).

Given the location of installation, we sometimes have very unique challenges.
For example, our next project is to install IotaWatt in a rural area where electricity and internet access is very intermittent. IotaWatt will be connected to the output of the Solar Inverter, so it shouldn’t be restart very often, but the internet is unavailable for some times days at a stretch. I trust that IotaWatt should upload all the missing data once internet access is resumed, but is there anything we can do to help ensure that the missing data is indeed uploaded? For example:

Would increasing the ‘post interval’ in the webserver config page help? Since there is theoretically less data to be uploaded? We don’t really need 10 second resolution anyway.
How about the entry bulk send? Should we keep it at default or increasing it might help?
Would increasing the post interval from 10 second to 60 second impact the kWh calculation, since the data samples are now further apart.

Many thanks for your kind support so far. We could never have achieved our goals without IotaWatt. It has helped us optimize our older installations and balance our upcoming installations. Being run on donations, it really important to stretch every dollar that we get. Thanks.

overeasy · September 17, 2018, 2:44pm

That outage predates the problem we were dealing with, so I don’t have any way to look into it. The place to start is to try to graph that period directly from IoTaWatt with the local graph utility. If the data is there, then it is an upload problem, if not, then your IoTaWatt was down for that period and could be a variety of external reasons.

It would make upload after an outage quicker, but bear in mind that when youincrease the interval, you get the average power during the interval. So the longer the interval, spikes become less obvious. That said, I would think a minute or less would be fine.

That doesn’t matter. If the IoTaWatt is bulk uploading after an outage, it will ignore that and upload maximum size packets. Bulk only reduces traffic under normal conditions.

It should not, because IoTaWatt send the time-weighted average for the period. So even if there were a huge spike for 30 seconds during the period, it would be accounted for in the average sent.

You may have some minor problems if the WiFi is disconnected for long periods. It’s OK for the internet to be down, but the local WiFi router should remain available. IoTaWatt will automatically restart after being disconnected from WiFi for an hour. That’s a failsafe feature. It comes right back up after only a few seconds, but won’t sample for up to six minutes if there is still no WiFi. It is providing a window of opportunity to connect to a new WiFi network and so is in dedicated AP mode.