IotaWatt 4.0

Hardware IoTaWatt
197

*C[quote=“brotten, post:195, topic:4427”]
Everything else works ok.
[/quote]

Brian,
Could you change your auto-update class to ALPHA to get the latest release 02_02_23? This is the KRACK vulnerability release but also includes a change to check the integrity of power samples, which I think might fix your problem.

IotaWatt checks for updates every hour, and also at startup, so after changing auto-update class, you can force a restart with:
Iotawatt.local/command?restart=yes

If anyone is following this and wondering what is going on, the status response contains nan (not a number) for several Jason entries that should be numbers. When the app tries to Jason parse this Json, it fails, which causes JavaScript to stop processing the status response, leaving the status window with no content.

My MO is belt and suspenders, so I will check for nan in the IotaWatt in a later release, but right now, I think the sampling changes in 02_02_23 might give relief. I can’t reproduce this on any of my test units running that version.

198

Everything seems to be working except emoncms. I tried it with and without the userid. Without the userid, it doesn’t show an error, but no data is posted at emoncms.

** Restart **

No clock yet: SD initialized.
10/29/17 15:03:06 Real Time Clock is running. Unix time: 1509289386
10/29/17 15:03:06 Version: 02_02_23
10/29/17 15:03:06 Updater: Installing update files for version 02_02_23
10/29/17 15:03:06 Updater: Installing CNFSTYLE.CSS
10/29/17 15:03:06 Updater: Installing GRAPH.HTM
10/29/17 15:03:06 Updater: Installing GRAPH.JS
10/29/17 15:03:06 Updater: Installing INDEX.HTM
10/29/17 15:03:07 Updater: Installing TABLES.TXT
10/29/17 15:03:07 Updater: Installing EDIT.HTM
10/29/17 15:03:07 Updater: Installation complete.
10/29/17 15:03:07 Reset reason: Software/System restart
10/29/17 15:03:07 Trace: 130,131,132,133,134,135,136,137,138,139,14,17,18,13,14,17,18,13,14,17,18,11,90,91,84,86,88,93,94,95,99,12
10/29/17 15:03:07 ESP8266 ChipID:11725030
10/29/17 07:03:08 device name: IotaWatt, version: 3
10/29/17 07:03:08 Local time zone: -8
10/29/17 07:03:09 MDNS responder started
10/29/17 07:03:09 You can now connect to http://IotaWatt.local
10/29/17 07:03:09 HTTP server started
10/29/17 07:03:09 dataLog: service started.
10/29/17 07:03:09 dataLog: Last log entry:1509289345
10/29/17 07:03:09 statService: started.
10/29/17 07:03:09 timeSync: service started.
10/29/17 07:03:09 WiFi connected. SSID: CarmenLeah5, IP: 192.168.0.202
10/29/17 07:08:09 EmonService: started.url: emoncms.org, node: IotaWatt, post interval: 10, encrypted POST
10/29/17 07:08:09 EmonService: Emonlog file created.
10/29/17 07:08:09 EmonService: Start posting from 1509289685
10/29/17 07:09:10 EmonService: POST failed. HTTP code: read Timeout
10/29/17 07:09:40 Resending EmonCMS data.
10/29/17 07:10:15 EmonService: POST failed. HTTP code: connection refused
10/29/17 07:10:45 Resending EmonCMS data.
10/29/17 07:11:50 EmonService: POST failed. HTTP code: read Timeout
10/29/17 07:12:20 Resending EmonCMS data.
10/29/17 07:14:20 EmonService: started.url: emoncms.org, node: IotaWatt, post interval: 10, unsecure GET
10/29/17 07:14:20 EmonService: Start posting from 1509290050

199

I know you see those read timeouts, but it was posting and it does recover from those timeouts. Welcome to my world (I’m 4 hours ahead of you):
image

It’s not a problem with the IotaWatt or your WiFi, it’s a problem with the server not responding fast enough to posts. I’m working the issue with OEM. The good news is that your device does recover and sends the data again. Actually, it probably is getting posted the first time, but I can’t leave the IotaWatt waiting for the response because it doesn’t sample while waiting for it.

I’ll look into the unsecure not posting, but you should go back to using secure. The log shows that it did post the data for that six minute period.

You might want to set bulk-send to something like 3. That will cut the transactions by a third without any impact on interval or data integrity. The only downside is if you are running some kind of real-time reporting app that can’t tolerate data being 20 seconds old.

I’m relieved that the status display seems to be resolved. You should also find it is more stable now with respect to the samples/cycle and voltage readings. That’s not just a reporting makeover, the underlying sampling is now more stable.

EDIT: My systems seem to be doing unsecure OK, although I get timeouts there as well. Can you post the message log after you switch back to secure? It will help determine if it was actually posting. Thanks.

Edit: Can you ping emoncms.org a few times and see what the communication delay is from there?

200

could it be, when you have not been able to post for some time and it starts to send the backlog, you hit the timeout serverside ? I don’t know if it sends the backlog in one flow or if it sends it in parts to avoid the timeout ? I can image, when you have like several hours to send and your upload speed isn’t fiberspeed …
just a wild guess but I know my server has several timeouts regarding different services …

201

I was looking at the feed page instead of the inputs, my mistake.

** Restart **

No clock yet: SD initialized.
10/29/17 15:03:06 Real Time Clock is running. Unix time: 1509289386
10/29/17 15:03:06 Version: 02_02_23
10/29/17 15:03:06 Updater: Installing update files for version 02_02_23
10/29/17 15:03:06 Updater: Installing CNFSTYLE.CSS
10/29/17 15:03:06 Updater: Installing GRAPH.HTM
10/29/17 15:03:06 Updater: Installing GRAPH.JS
10/29/17 15:03:06 Updater: Installing INDEX.HTM
10/29/17 15:03:07 Updater: Installing TABLES.TXT
10/29/17 15:03:07 Updater: Installing EDIT.HTM
10/29/17 15:03:07 Updater: Installation complete.
10/29/17 15:03:07 Reset reason: Software/System restart
10/29/17 15:03:07 Trace: 130,131,132,133,134,135,136,137,138,139,14,17,18,13,14,17,18,13,14,17,18,11,90,91,84,86,88,93,94,95,99,12
10/29/17 15:03:07 ESP8266 ChipID:11725030
10/29/17 07:03:08 device name: IotaWatt, version: 3
10/29/17 07:03:08 Local time zone: -8
10/29/17 07:03:09 MDNS responder started
10/29/17 07:03:09 You can now connect to http://IotaWatt.local
10/29/17 07:03:09 HTTP server started
10/29/17 07:03:09 dataLog: service started.
10/29/17 07:03:09 dataLog: Last log entry:1509289345
10/29/17 07:03:09 statService: started.
10/29/17 07:03:09 timeSync: service started.
10/29/17 07:03:09 WiFi connected. SSID: CarmenLeah5, IP: 192.168.0.202
10/29/17 07:08:09 EmonService: started.url: emoncms.org, node: IotaWatt, post interval: 10, encrypted POST
10/29/17 07:08:09 EmonService: Emonlog file created.
10/29/17 07:08:09 EmonService: Start posting from 1509289685
10/29/17 07:09:10 EmonService: POST failed. HTTP code: read Timeout
10/29/17 07:09:40 Resending EmonCMS data.
10/29/17 07:10:15 EmonService: POST failed. HTTP code: connection refused
10/29/17 07:10:45 Resending EmonCMS data.
10/29/17 07:11:50 EmonService: POST failed. HTTP code: read Timeout
10/29/17 07:12:20 Resending EmonCMS data.
10/29/17 07:14:20 EmonService: started.url: emoncms.org, node: IotaWatt, post interval: 10, unsecure GET
10/29/17 07:14:20 EmonService: Start posting from 1509290050
10/29/17 07:27:10 EmonService: GET failed. HTTP code: read Timeout
10/29/17 07:27:40 Resending EmonCMS data.
10/29/17 07:29:10 EmonService: GET failed. HTTP code: read Timeout
10/29/17 07:29:40 Resending EmonCMS data.
10/29/17 07:30:00 EmonService: GET failed. HTTP code: read Timeout
10/29/17 07:30:30 Resending EmonCMS data.
10/29/17 07:39:10 EmonService: GET failed. HTTP code: read Timeout
10/29/17 07:39:40 Resending EmonCMS data.
10/29/17 08:10:10 EmonService: GET failed. HTTP code: read Timeout
10/29/17 08:10:40 Resending EmonCMS data.
10/29/17 08:18:20 EmonService: GET failed. HTTP code: read Timeout
10/29/17 08:18:50 Resending EmonCMS data.
10/29/17 08:18:55 EmonService: GET failed. HTTP code: connection refused
10/29/17 08:19:55 Resending EmonCMS data.
10/29/17 08:20:00 EmonService: GET failed. HTTP code: connection refused
10/29/17 08:21:00 Resending EmonCMS data.
10/29/17 08:23:10 EmonService: GET failed. HTTP code: read Timeout
10/29/17 08:23:40 Resending EmonCMS data.
10/29/17 08:24:10 EmonService: GET failed. HTTP code: read Timeout
10/29/17 08:24:40 Resending EmonCMS data.
10/29/17 08:25:12 EmonService: GET failed. HTTP code: read Timeout
10/29/17 08:25:42 Resending EmonCMS data.
10/29/17 08:25:45 EmonService: GET failed. HTTP code: read Timeout
10/29/17 08:26:15 Resending EmonCMS data.
10/29/17 08:37:30 EmonService: GET failed. HTTP code: read Timeout
10/29/17 08:38:00 Resending EmonCMS data.
10/29/17 08:48:10 EmonService: GET failed. HTTP code: read Timeout
10/29/17 08:48:40 Resending EmonCMS data.
10/29/17 08:54:10 EmonService: GET failed. HTTP code: read Timeout
10/29/17 08:54:40 Resending EmonCMS data.
10/29/17 08:56:10 EmonService: GET failed. HTTP code: read Timeout
10/29/17 08:56:40 Resending EmonCMS data.
10/29/17 09:04:10 EmonService: GET failed. HTTP code: read Timeout
10/29/17 09:04:40 Resending EmonCMS data.
10/29/17 09:10:40 EmonService: started.url: emoncms.org, node: IotaWatt, post interval: 10, encrypted POST
10/29/17 09:10:40 EmonService: Start posting from 1509297030
10/29/17 09:12:02 EmonService: POST failed. HTTP code: read Timeout
10/29/17 09:12:32 Resending EmonCMS data.
10/29/17 09:16:00 EmonService: POST failed. HTTP code: read Timeout
10/29/17 09:16:30 Resending EmonCMS data.

PING emoncms.org (80.243.190.58): 56 data bytes

64 bytes from 80.243.190.58: icmp_seq=0 ttl=32 time=165.275 ms

64 bytes from 80.243.190.58: icmp_seq=1 ttl=32 time=166.042 ms

64 bytes from 80.243.190.58: icmp_seq=2 ttl=32 time=166.471 ms

64 bytes from 80.243.190.58: icmp_seq=3 ttl=32 time=166.392 ms

64 bytes from 80.243.190.58: icmp_seq=4 ttl=32 time=161.713 ms

64 bytes from 80.243.190.58: icmp_seq=5 ttl=32 time=166.011 ms

64 bytes from 80.243.190.58: icmp_seq=6 ttl=32 time=166.238 ms

64 bytes from 80.243.190.58: icmp_seq=7 ttl=32 time=166.711 ms

64 bytes from 80.243.190.58: icmp_seq=8 ttl=32 time=167.189 ms

64 bytes from 80.243.190.58: icmp_seq=9 ttl=32 time=166.137 ms

64 bytes from 80.243.190.58: icmp_seq=10 ttl=32 time=162.178 ms

64 bytes from 80.243.190.58: icmp_seq=11 ttl=32 time=166.168 ms

64 bytes from 80.243.190.58: icmp_seq=12 ttl=32 time=163.761 ms

— 80.243.190.58 ping statistics —
13 packets transmitted, 13 received, 0.00% packet loss
round-trip min / avg / max = 161.713 / 165.407 / 167.189 ms

202

No problem, and the log does show it was up to date when you switched back to secure post. So except for the annoying timeouts, I’m under the impression you are up and running. The ping is a little longer than here. I’m at about 100ms, but still not bad for a third of the way around the world. If it turns out that the delays are unavoidable, I’ll look into resurrecting past efforts to go asynchronous. There has been some underlying improvement in the core to support that, and it would be an improvement notwithstanding these annoying timeouts. Have you tried the bulk-post?

IotaWatt uses the bulk transaction format, so when there is a backup, it aggregates the backlog into packets that are up to 1K. That will take the server a little longer to process, but my understanding of the way it works, and I’m not sure about this, but I believe the transaction is broken down and queued for handling by the input processes associated with each input included in the transaction. That process can take some time but I think the acknowledgement I get comes when the basic transaction has been decrypted and parsed.

Well, copper or fiber, it’s all the speed of light, just higher bandwidth with the fiber. Still, none of it should take anywhere near 500ms. So I’m betting that it is server side delays, especially since it all started when the server was moved on the 17th. It’s not a huge problem, and they are looking into it. Meantime, IotaWatt is robust enough to work through it.

203

@overeasy: FYI: I also had some issues with the emoncms timing out (and not being able to reconnect again). I had this issue when logging 2 Iota’s to my own EmonPi (on local network).
I tried it with a 1000ms timeout (http.setTimeout(1000); in Emonservice) and it was a little bit better but sometimes it ran into problems.
When only logging 1 Iota to my emonPi (and 1000ms timeout) it seems to be no issue anymore.

204

The pi is a whole different situation. I had one early adopter with the same problems and he loaded his Emoncms instance onto a windows machine. Problems went away. I don’t doubt that given enough time, the response will come. The problem is that IotaWatt blocks and doesn’t sample while waiting for that response. So it’s a tradeoff. Some amount of retries vs more frequent sampling. 500ms seems to work for Emoncms.org.
Maybe that’s another good reason to take another look at asynchronous posting.

205

Just to include some info.

I have a local emonpi and a new iotawatt. this morning the iotawatt was not posting data but other devices were.

I logged into the iotawatt and changed the “webserver” to “none” then saved and then back to “emoncms” and it started posting again with no other changes.

here is a snipit of the log

10/31/17 05:25:36 EmonService: GET failed. HTTP code: read Timeout
10/31/17 05:26:36 Resending EmonCMS data.
10/31/17 05:26:36 EmonService: GET failed. HTTP code: read Timeout
10/31/17 05:27:36 Resending EmonCMS data.
10/31/17 05:27:36 EmonService: GET failed. HTTP code: read Timeout
10/31/17 05:28:36 Resending EmonCMS data.
10/31/17 05:28:36 EmonService: GET failed. HTTP code: read Timeout
10/31/17 05:29:36 Resending EmonCMS data.
10/31/17 05:29:36 EmonService: GET failed. HTTP code: read Timeout
10/31/17 05:30:36 Resending EmonCMS data.
10/31/17 05:30:36 EmonService: GET failed. HTTP code: read Timeout
10/31/17 05:31:36 EmonService: stopped.
10/31/17 05:31:36 EmonService: started.url: 192.168.1.215/emoncms, node: IotaWatt, post interval: 10, unsecure GET
10/31/17 05:31:36 EmonService: Emonlog file created.
10/31/17 05:31:36 EmonService: Start posting from 1509427895

206

Thanks for the info. I’m looking into this problem. Can you verify the version of iotawatt software you are running?

207

Firmware version: 02_02_21

208

I have also noticed something similar and offer the following in the hope it may useful.

The IoTaWatt was started pm on 23rd November but during the evening of 31st the desktop PC appeared to loose connection with iotawatt.local. Checking with an Ipad (2ft away from the IoTaWatt) gave the same result. Eventually it was decided to restart the unit. Although connection with iotawatt.local was established only the voltage configuration setting was present and this indicated 120V instead of 240V! Since then, connection with iotawatt.local can only be described as erratic and variable. The Firmware version is indicated as 02_02_21. I have managed to get a copy of the log file covering the period 11/1/17 08:50:08 to 11/1/17 10:13:12. A ping check to iotawatt.local reveals: rtt min/avg/max/mdev = 78.351/158.996/260.102/61.930 ms. A previous ping result prior to the current situation provided a fairly consistent figure of 13.1 ms.

209

Do you mean the configuration app stopped updating?

I know it sounds counterintuitive, but it doesn’t matter the distance between the Ipad and the IotaWatt. The IotaWatt is communicating through your WiFi router, so when you use the Ipad, the IotaWatt communicates with the router and the Ipad communicates with the router. There is no direct link. I have an IotaWatt in an outbuilding, and I can’t access it locally when it rains, even if I am outdoors right beside it. When the rain stops, the IotaWatt connects back up.

So I’d look to see the distance between your router and the IotaWatt. All the generic advice for WiFi range applies. If your IotaWatt is having connection issues, you will see the LED turn red from time to time. Also, the message log will have disconnect and connect messages.

The solution is to relocate the WiFi router, or install a range extender.

210

Your basic problems appear to be connectivity with the router, but this is troubling. There should be no alternative config file on your device. Are you sure you are not accessing the demo app at iotawatt.com?

211

The router and iotawatt are located in adjacent rooms and about 3.5m apart. What I find puzzling is why the problem started after 8 days of successful continuous operation.

That said, I think I may have stumbled upon a solution. A search suggested that there could be channel interference especially if the router is set to AUTO. This is exactly what I found, so I changed it to Channel 1 and rebooted the router. Thankfully, Iotawatt.local now responds more like it did and seems to be reliable as well.

212

As far as I can recall iotawatt.local was being used, but I also tried the IP address for the iotawatt.

213

Glad your problem is resolved.

Me too. :exploding_head:

Very resourceful. Any idea what channel was being used when the problems were present?

So let me understand this. You had a configured the IoTaWatt with multiple inputs configured. After the communications problems started, your configuration reverted to one with only a 120V VT channel 0 configured?

If that’s the case, I would very much like to see the logfile. You can download it using image

The left column will show your SD file system:
image
In the above example I previously clicked on the + next to the iotawatt directory entry to expand it. The message log is iotamsgs.txt. If you right click it, you will be able to select “download”. If you could upload a zip of that, I can look at the whole picture.

I checked all of the recent releases and didn’t see where a config file was distributed. There is no code that I recall that produces a barebones config. So this is very curious.

Did you subsequently reconfigure your IotaWatt or did your original configuration reappear?

214

I’m still having intermittent issues with the “Input Channels Status” coming up blank. When I logged on to emoncms today, it shows it hasn’t received anything for 37 hours.
iotalog.txt (255.5 KB)

Brian

215

@overeasy The problem is probably something else, but I would suggest that the code in the emon push service be updated to have a exponentially increasing timeout or at least a configurable timeout. Currently it is set to a fixed timeout of 500msec (http.setTimeout(500)) which may not be sufficient in all cases causing POST to timeout every time where it would otherwise work if waiting for longer.

I came across this in my homebrew PVOutput push service. I found it kept timing out just because the http request had a long response time. I understand that waiting for a long time will reduce accuracy since it stops sampling during this period, but some of us living with large ping times will at least still be able to use it. It could also help remove this as a possible cause of issues.

Also as a much larger improvement later in the future, to improve accuracy with long timeouts you could move to an async http request instead of a synchronous one.

216

Brian,
There’s something else going on here that I’m following up on several fronts. But first:

Don’t change your server away from Emoncms. If you do, it won’t upload that 37 hours when you get past this.

Try going back to unsecured GET.

You can try restarting. Look closely after restart. Even though it may be logging timeouts, it may still be succeeding on retries. Check the Emoncms inputs to see if it’s posting.

Try looking at your data with the local graph app. It should all be there.

I have a diagnostic release in the oven that I want you to load. It does a little more with the reytries and increases the timeout after several retries. At this point, I don’t think that’s your issue, but it will be good to know.

Another user had similar issues and changed the default channel that his WiFi is using. I have never had trouble with that, but it might be worth a try. I’m looking into adding some WiFi statistics including channel to the status screen.

Keep me posted.