live data never sent to services

[3v1n0]

I had an old installation of pywws (around 16.12), and I decided to finally upgrade it.

My pywws was down for a couple of days. So I've upgraded pywws, lanunched pywws.reprocess but now the live data is correctly read but never sent.

I've added some debugging bits, but basically datalogger.log_data() called and never returns... Continuously processing live data:

2019-03-29 03:49:14:pywws.logger:pywws version 19.3.0, build 1650 (17131d2)
2019-03-29 03:49:14:pywws.logger:Python version 2.7.9 (default, Aug 13 2016, 17:33:18) 
[GCC 4.9.2]
2019-03-29 03:49:14:pywws.weatherstation:using pywws.device_pyusb
2019-03-29 03:49:16:pywws.weatherstation:avoid 5.34576821327
2019-03-29 03:49:23:pywws.calib:Using default calibration
2019-03-29 03:49:25:pywws.livelog:Logging data...
2019-03-29 03:49:25:pywws.logdata:Synchronising to weather station
2019-03-29 03:49:26:pywws.weatherstation:read period 218
2019-03-29 03:49:26:pywws.weatherstation:delay 158, pause 37.4444
2019-03-29 03:50:03:pywws.weatherstation:status {'rain_overflow': False, 'lost_connection': False}
2019-03-29 03:50:03:pywws.weatherstation:delay 158, pause 0.5
2019-03-29 03:50:04:pywws.weatherstation:avoid 5.74577116966
2019-03-29 03:50:10:pywws.weatherstation:live_data new data
2019-03-29 03:50:10:pywws.logdata:Reading time 29/03 02:50:07
2019-03-29 03:50:10:pywws.logdata:Is logged False, 2019-03-29 02:50:07, 1, None
2019-03-29 03:50:10:pywws.weatherstation:delay 159, pause 41.2913
2019-03-29 03:50:51:pywws.weatherstation:delay 159, pause 0.5
2019-03-29 03:50:52:pywws.weatherstation:avoid 5.77075910568
2019-03-29 03:50:58:pywws.weatherstation:live_data new data
2019-03-29 03:50:58:pywws.logdata:Reading time 29/03 02:50:55
2019-03-29 03:50:58:pywws.logdata:Is logged False, 2019-03-29 02:50:55, 1, None
2019-03-29 03:50:58:pywws.weatherstation:delay 159, pause 41.2907
2019-03-29 03:51:39:pywws.weatherstation:delay 159, pause 0.5
2019-03-29 03:51:40:pywws.weatherstation:avoid 5.77075719833
2019-03-29 03:51:46:pywws.weatherstation:live_data new data
2019-03-29 03:51:46:pywws.logdata:Reading time 29/03 02:51:43
...
2019-03-29 04:38:10:pywws.weatherstation:live_data new data
2019-03-29 04:38:10:pywws.logdata:Reading time 29/03 03:38:07
2019-03-29 04:38:10:pywws.logdata:Is logged False, 2019-03-29 03:38:07, 1, None
2019-03-29 04:38:10:pywws.weatherstation:delay 207, pause 41.2651
2019-03-29 04:38:51:pywws.weatherstation:delay 207, pause 0.5
2019-03-29 04:38:52:pywws.weatherstation:avoid 5.75576305389
2019-03-29 04:38:58:pywws.weatherstation:live_data new data
2019-03-29 04:38:58:pywws.logdata:Reading time 29/03 03:38:55
2019-03-29 04:38:58:pywws.logdata:Is logged False, 2019-03-29 03:38:55, 1, None
2019-03-29 04:38:58:pywws.weatherstation:delay 207, pause 41.2719

And so continues... No service is called.

If I set logdata sync = 0, the function does exit but it never enters into this cycle: for data, logged in datalogger.live_data(logged_only=(not tasks.has_live_tasks())):

Any way I can help in debugging this? [not that should change, but I've tried running in python3 but no change]

[jim-easterbrook]

Note the delay 207 lines - these mean that your station is not correctly logging data as it's 207 + (n * 256) minutes since it last logged any. Resetting the base station (by removing the batteries and unplugging USB) might fix this.

As for the missing services, one possibility is that your weather.ini file didn't get correctly updated automatically. Check you have suitable services entries in [live] and [logged] sections of weather.ini. https://pywws.readthedocs.io/en/latest/guides/livelogging.html#configuring-periodic-tasks

Another possibility is that the service uploaders are waiting for some data to be logged before they send anything. This is usually a good idea, but obviously causes problems if the base station stops logging.

[3v1n0]

Soo... After few hours of doing this dance, the station started reporting data.

Not sure if this is caused by the fact that it had to read unpublished stuff from memory yet, but log wasn't mentioning it.

For sure there's something weird going on in case pywws is off for some time before it goes back to report live data.

As for the missing services, one possibility is that your weather.ini file didn't get correctly updated automatically. Check you have suitable services entries in [live] and [logged] sections of weather.ini.

No this wasn't the case, I didn't post the full detailed log here, but the services were properly initiated.

So, while the problem is fixed now, I guess that is weird that although some live data is recorded by the station, and I've live services on, the pywws still wait for the first logged bit before starting reporting logged bits. Isn't it?

[jim-easterbrook]

It's important to some services to send data in the correct order. To send "catchup" data before live data we need to fetch the logged data from the station first, then process and send it, then start "live" logging.

There are many ways in which the weather station can fail. It would be hard to design pywws to be able to cope with all of them.

[3v1n0]

It's important to some services to send data in the correct order. To send "catchup" data before live data we need to fetch the logged data from the station first, then process and send it, then start "live" logging.

So in theory services might expose this and thus if they need catchup first, then we can wait, otherwise we can send live data as soon as available and catchup one once we log?

Or otherwise can't we just send catchup on startup and waiting to send logged data until the catchup phase is done?

[jim-easterbrook]

In theory, but this isn't currently done by the service uploaders but by the live or hourly program. It's not a problem when the weather station is working normally.

[jim-easterbrook]

Commit d36d35b should help with the synchronisation problem.