PVOutput Logging seems to have stopped

Not sure why but PVoutput logging has been stopped and won’t restart after soft reset or power cycle.

Any ideas ? Log below.

Thanks
Paul

SD initialized.
8/15/19 00:59:46z Real Time Clock is running. Unix time 1565830786
8/15/19 00:59:46z Reset reason: Software/System restart
8/15/19 00:59:46z Trace: 1:2[7], 9:0[7], 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:5[21], 1:6, 1:1[7], 1:2[8], 9:0[8], 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
8/15/19 00:59:46z ESP8266 ChipID: 2991982
8/15/19 00:59:46z IoTaWatt 4.x, Firmware version 02_04_00
8/15/19 00:59:46z SPIFFS mounted.
8/15/19 10:59:48 Local time zone: +10:00
8/15/19 10:59:48 Using Daylight Saving Time (BST) when in effect.
8/15/19 10:59:48 device name: IotaWatt
8/15/19 10:59:48 MDNS responder started for hostname IotaWatt
8/15/19 10:59:48 LLMNR responder started for hostname IotaWatt
8/15/19 10:59:49 HTTP server started
8/15/19 10:59:49 WiFi connected. SSID=Telstra82C2AA, IP=10.0.0.173, channel=1, RSSI -80db
8/15/19 10:59:49 timeSync: service started.
8/15/19 10:59:49 statService: started.
8/15/19 10:59:49 Updater: service started. Auto-update class is MINOR
8/15/19 10:59:50 dataLog: service started.
8/15/19 10:59:53 dataLog: Last log entry 08/15/19 10:59:40
8/15/19 10:59:54 historyLog: service started.
8/15/19 10:59:55 historyLog: Last log entry 08/15/19 10:59:00
8/15/19 10:59:57 Updater: Auto-update is current for class MINOR.
8/15/19 10:59:59 PVoutput: started
8/15/19 11:00:01 PVoutput: System King Creek 1, interval 5, freeload mode
8/15/19 11:00:02 PVoutput: Start status beginning 08/07/19 12:35:00
8/15/19 11:00:04 PVoutput: Fatal response
8/15/19 11:00:04 PVoutput: Stopped.

Anything unusual happen 8/7/19 at 12:35? Can you post the log from that time?

There is a new release in the works that has more robust error reporting and retry. In the meantime you can set the historyupload date to the next day and restart. You will have a half-day hole that can be backfilled up until 8/21 or November if you become a donator.

Looks like there were some internet drop outs a few days earlier but at that time it just stopped.

8/03/19 00:10:05 WiFi disconnected.
8/03/19 00:10:06 WiFi connected. SSID=Telstra82C2AA, IP=10.0.0.173, channel=9, RSSI -82db
8/03/19 00:10:15 WiFi disconnected.
8/03/19 00:10:19 WiFi connected. SSID=Telstra82C2AA, IP=10.0.0.173, channel=1, RSSI -82db
8/07/19 12:40:00 PVoutput: Fatal response
8/07/19 12:40:00 PVoutput: Stopped.
8/09/19 11:32:57 WiFi disconnected.
8/09/19 11:32:58 WiFi connected. SSID=Telstra82C2AA, IP=10.0.0.173, channel=1, RSSI -80db
8/10/19 01:00:11 WiFi disconnected.
8/10/19 01:00:15 WiFi connected. SSID=Telstra82C2AA, IP=10.0.0.173, channel=11, RSSI -81db
8/12/19 21:08:58 WiFi disconnected.
8/12/19 21:11:42 WiFi connected. SSID=Telstra82C2AA, IP=10.0.0.173, channel=11, RSSI -78db
8/12/19 21:11:52 WiFi disconnected.
8/12/19 21:11:55 WiFi connected. SSID=Telstra82C2AA, IP=10.0.0.173, channel=1, RSSI -78db
8/12/19 21:14:37 WiFi disconnected.
8/12/19 21:14:52 WiFi connected. SSID=Telstra82C2AA, IP=10.0.0.173, channel=1, RSSI -79db
8/13/19 21:03:57 timeSync: Six week routine restart.

** Restart **

SD initialized.
8/13/19 11:03:59z Real Time Clock is running. Unix time 1565694239
8/13/19 11:03:59z Reset reason: Software/System restart
8/13/19 11:03:59z 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:1[2], 1:2[3], 9:0[3], 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:5[20], 20:0, 20:1
8/13/19 11:03:59z ESP8266 ChipID: 2991982
8/13/19 11:03:59z IoTaWatt 4.x, Firmware version 02_04_00
8/13/19 11:03:59z SPIFFS mounted.
8/13/19 21:04:01 Local time zone: +10:00
8/13/19 21:04:01 Using Daylight Saving Time (BST) when in effect.
8/13/19 21:04:01 device name: IotaWatt
8/13/19 21:04:01 MDNS responder started for hostname IotaWatt
8/13/19 21:04:01 LLMNR responder started for hostname IotaWatt
8/13/19 21:04:02 HTTP server started
8/13/19 21:04:02 timeSync: service started.
8/13/19 21:04:02 statService: started.
8/13/19 21:04:02 dataLog: service started.
8/13/19 21:04:06 dataLog: Last log entry 08/13/19 21:03:55
8/13/19 21:04:06 historyLog: service started.
8/13/19 21:04:07 historyLog: Last log entry 08/13/19 21:03:00
8/13/19 21:04:12 PVoutput: started
8/13/19 22:04:03 WiFi disconnected more than 60 minutes, restarting.

** Restart **

SD initialized.
8/13/19 12:04:04z Real Time Clock is running. Unix time 1565697844
8/13/19 12:04:04z Reset reason: Software/System restart
8/13/19 12:04:04z Trace: 20:1, 20:2, 20:3, 20:4, 20:42, 1: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, 1:3, 1:4, 1:5[20], 20:0, 20:1, 20:2, 20:3, 20:4, 20:42, 1:6, 1:3, 1:4, 1:5[21]
8/13/19 12:04:04z ESP8266 ChipID: 2991982
8/13/19 12:04:04z IoTaWatt 4.x, Firmware version 02_04_00
8/13/19 12:04:04z SPIFFS mounted.
8/13/19 22:04:06 Local time zone: +10:00
8/13/19 22:04:06 Using Daylight Saving Time (BST) when in effect.
8/13/19 22:04:06 device name: IotaWatt
8/13/19 22:04:06 MDNS responder started for hostname IotaWatt
8/13/19 22:04:06 LLMNR responder started for hostname IotaWatt
8/13/19 22:04:07 HTTP server started
8/13/19 22:04:07 WiFi connected. SSID=Telstra82C2AA, IP=10.0.0.173, channel=1, RSSI -77db
8/13/19 22:04:07 timeSync: service started.
8/13/19 22:04:07 statService: started.
8/13/19 22:04:08 Updater: service started. Auto-update class is MINOR
8/13/19 22:04:08 dataLog: service started.
8/13/19 22:04:12 dataLog: Last log entry 08/13/19 22:04:00
8/13/19 22:04:12 historyLog: service started.
8/13/19 22:04:14 historyLog: Last log entry 08/13/19 22:04:00
8/13/19 22:04:15 Updater: Auto-update is current for class MINOR.
8/13/19 22:04:17 PVoutput: started
8/13/19 22:04:17 PVoutput: System King Creek 1, interval 5, freeload mode
8/13/19 22:04:18 PVoutput: Start status beginning 08/07/19 12:35:00
8/13/19 22:04:20 PVoutput: Fatal response
8/13/19 22:04:21 PVoutput: Stopped.
8/14/19 12:45:00 historyLog: primary log file read failure. Service suspended.
8/15/19 09:05:36 Restart command received.

I set the history upload date to the next day and restarted and now have all my data up to date in PVoutput.

All good now and will wait for new version but still a mystery why it stopped.

Paul

1 Like

Hopefully that should shed some light on it. There are some additional error responses now documented in the PVoutput help. There were three scheduled restarts about a month ago and I suspect there have may have been some changes, so I need to figure out if anything changed that could cause this and if the new error retry will handle it.

Had another stop on PVoutput today. We did have an internet outage at the same time and it looks like it did not recover when the internet came back u. Its still stopped, only just noticed as I was getting my Influxdb working again on the Raspberry.

8/25/19 11:29:50 WiFi disconnected.
8/25/19 11:29:53 WiFi connected. SSID=Telstra82C2AA, IP=10.0.0.173, channel=2, RSSI -80db
8/25/19 11:30:00 PVoutput: Fatal response
8/25/19 11:30:00 PVoutput: Stopped.
8/25/19 11:32:04 WiFi disconnected.
8/25/19 11:32:09 WiFi connected. SSID=Telstra82C2AA, IP=10.0.0.173, channel=2, RSSI -81db
8/25/19 11:32:20 WiFi disconnected.
8/25/19 11:32:23 WiFi connected. SSID=Telstra82C2AA, IP=10.0.0.173, channel=13, RSSI -76db
8/25/19 12:11:13 WiFi disconnected.
8/25/19 12:13:44 WiFi connected. SSID=Telstra82C2AA, IP=10.0.0.173, channel=13, RSSI -74db
8/25/19 12:16:10 WiFi disconnected.
8/25/19 12:16:45 WiFi connected. SSID=Telstra82C2AA, IP=10.0.0.173, channel=1, RSSI -80db

What I see is WiFi being lost. Recovery from that is different from having WiFi and losing internet only. It’s not clear from these log messages what is the status of the internet connection.

Has the IoTaWatt been restarted since?

I did a soft restart and PVoutput started up again.

I did lose internet (ie service outage in neighbourhood) but wifi was still working within the house. About 30min after the service outage I did a power cycle on the modem so all was down for a while.