ws28xx: no backfill of values when contact to console is lost and regained

[Michi Kaa]

Hi,

with the ws28xx driver I've encountered the following:

Jul 10 21:01:00 weewxPi weewx[1381]: ftpgenerator: ftp'd 46 files in 9.28 seconds
Jul 10 21:10:12 weewxPi weewx[1381]: ws28xx: MainThread: no new weather data after 609 seconds
Jul 10 21:10:12 weewxPi weewx[1381]: ws28xx: MainThread: no contact with console after 609 seconds: press [SET] to sync
Jul 10 21:20:43 weewxPi weewx[1381]: ws28xx: MainThread: no new weather data after 1239 seconds
Jul 10 21:20:43 weewxPi weewx[1381]: ws28xx: MainThread: no contact with console after 1239 seconds: press [SET] to sync
Jul 10 21:30:43 weewxPi weewx[1381]: ws28xx: MainThread: no new weather data after 1840 seconds
Jul 10 21:30:43 weewxPi weewx[1381]: ws28xx: MainThread: no contact with console after 1840 seconds: press [SET] to sync
Jul 10 21:41:14 weewxPi weewx[1381]: ws28xx: MainThread: no new weather data after 2470 seconds
Jul 10 21:41:14 weewxPi weewx[1381]: ws28xx: MainThread: no contact with console after 2470 seconds: press [SET] to sync
Jul 10 21:51:14 weewxPi weewx[1381]: ws28xx: MainThread: no new weather data after 3071 seconds
Jul 10 21:51:14 weewxPi weewx[1381]: ws28xx: MainThread: no contact with console after 3071 seconds: press [SET] to sync
Jul 10 22:00:20 weewxPi weewx[1381]: manager: Added record 2019-07-10 21:05:00 CEST (1562785500) to database 'weewx.sdb'
Jul 10 22:00:20 weewxPi weewx[1381]: manager: Added record 2019-07-10 21:05:00 CEST (1562785500) to daily summary in 'weewx.sdb'
Jul 10 22:00:20 weewxPi weewx[1381]: engine: Garbage collected 10889 objects
Jul 10 22:00:27 weewxPi weewx[1381]: cheetahgenerator: Generated 14 files for report StandardReport in 6.78 seconds
Jul 10 22:00:45 weewxPi weewx[1381]: imagegenerator: Generated 36 images for StandardReport in 18.05 seconds
Jul 10 22:00:45 weewxPi weewx[1381]: copygenerator: copied 0 files to /var/www/weewx
Jul 10 22:00:47 weewxPi weewx[1381]: GaugeGenerator: Generated 7 images for HTMLPages in 1.90 seconds
Jul 10 22:00:47 weewxPi weewx[1381]: translategenerator.pyc: Language is german
Jul 10 22:00:51 weewxPi weewx[1381]: historygenerator.pyc: Generated 12 tables in 3.90 seconds
Jul 10 22:00:57 weewxPi weewx[1381]: cheetahgenerator: Generated 11 files for report HTMLPages in 9.90 seconds
Jul 10 22:00:57 weewxPi weewx[1381]: copygenerator: copied 0 files to /var/www/weewx/Bootstrap
Jul 10 22:00:57 weewxPi weewx[1381]: translategenerator.pyc: Language is german
Jul 10 22:01:30 weewxPi weewx[1381]: imagegenerator: Generated 28 images for BigImages in 32.66 seconds
Jul 10 22:01:30 weewxPi weewx[1381]: translategenerator.pyc: Language is german
Jul 10 22:01:52 weewxPi weewx[1381]: imagegenerator: Generated 28 images for SmallImages in 22.25 seconds
Jul 10 22:02:04 weewxPi weewx[1381]: ftpgenerator: ftp'd 74 files in 11.68 seconds
Jul 10 22:02:20 weewxPi weewx[1381]: ftpgenerator: ftp'd 74 files in 15.58 seconds
Jul 10 22:10:21 weewxPi weewx[1381]: ws28xx: MainThread: no new weather data after 617 seconds
Jul 10 22:10:21 weewxPi weewx[1381]: ws28xx: MainThread: no contact with console after 617 seconds: press [SET] to sync
Jul 10 22:20:21 weewxPi weewx[1381]: ws28xx: MainThread: no new weather data after 1218 seconds
Jul 10 22:20:21 weewxPi weewx[1381]: ws28xx: MainThread: no contact with console after 1218 seconds: press [SET] to sync
Jul 10 22:30:52 weewxPi weewx[1381]: ws28xx: MainThread: no new weather data after 1848 seconds
Jul 10 22:30:52 weewxPi weewx[1381]: ws28xx: MainThread: no contact with console after 1848 seconds: press [SET] to sync
Jul 10 22:41:22 weewxPi weewx[1381]: ws28xx: MainThread: no new weather data after 2479 seconds
Jul 10 22:41:22 weewxPi weewx[1381]: ws28xx: MainThread: no contact with console after 2479 seconds: press [SET] to sync
Jul 10 22:51:53 weewxPi weewx[1381]: ws28xx: MainThread: no new weather data after 3109 seconds
Jul 10 22:51:53 weewxPi weewx[1381]: ws28xx: MainThread: no contact with console after 3109 seconds: press [SET] to sync
Jul 10 23:00:27 weewxPi weewx[1381]: manager: Added record 2019-07-10 22:05:00 CEST (1562789100) to database 'weewx.sdb'
Jul 10 23:00:28 weewxPi weewx[1381]: manager: Added record 2019-07-10 22:05:00 CEST (1562789100) to daily summary in 'weewx.sdb'

Contact to console was lost and the regaind, but the missing archive values are not beeing backfilled. What is the reason for this? The only solution I know for backfilling values is to restore a backup of the database file (which I save on a daily basis) from a time before the contact was lost, and restart weewx. The missing archive values are then read from the console and stored. Should'nt weewx try to get these values from console when conatct is regained?

Is there another workaround without restoing a database backup which means loosing all loop-data? (which means possible data loss of min/max values, winddir and wind)

[Michi Kaa]

[Michi Kaa]

Nothing?

[Andrew Milner]

are you certain it has reconnected??

the archive records are only being generated at 1 hr intervals - is this correct??

there does not appear to be any communication between archive events - very strange.

The log message instructs you to resynch by pressing SET - did you do that??

I am far from convinced this is running as you intend - generating updates only once per hour??

On Monday, 29 July 2019 14:01:30 UTC+3, Michi Kaa wrote:

Nothing?

[Michi Kaa]

Am Montag, 29. Juli 2019 13:19:05 UTC+2 schrieb Andrew Milner:

are you certain it has reconnected??

Yes. The log portion above is copied "as is" from weewx.log and I didn't touch anything before or after.

 

the archive records are only being generated at 1 hr intervals - is this correct??

No, records are beeing generated every 5 mins. But since the connection to the console was interrupted, there was no data available hence no records being generated in the affected time window.

 

there does not appear to be any communication between archive events - very strange.

No connection - no communication. It is a 868MHz USB dongle which connects the Raspi to the console OTA. Y

 

The log message instructs you to resynch by pressing SET - did you do that??

No, I didn't, I didn't touch anything. Connection was regained without resynch.

 

I am far from convinced this is running as you intend - generating updates only once per hour??

It is running as intendend for over four years now with > 99,9% data completeness every 5 mins. I observed connection losses like this maybe once or twice before and backfilled the missing data as described above. I'd expect weewx to backfill data after connection loss and connection regain without any interaction. But something in the database prevents weewx from getting the missing data from the console. It acts like there is no data, When you restore the database to a point before the connection loss happened, weewx reads console data from the affected time windows without any problem.

 

[Andrew Milner]

do you have a rogue dateTime in the database?

The log you posted ONLY has database records added at 22:00, 23:00, 24:00 and a message every 10 minutes saying there is no new data - press SET to resynch.  I repeat - how do you know that it has reconnected?? No new data implies that it has NOT connected.  I see no evidence of a record being generated every 5 minutes.

I believe you have not, despite what you think, actually regained normal communication - either that or there is  a record with an 'in the future' dateTime in the database.  The fact that you can recover by restoring an old backup implies that your problem is probably caused by the wrong dateTime associated with a record, and no data can be found with a dateTime greater than what is in the database - so no backfill is performed.  

You could try running with debug = 1 set to see if more information can be found or you can keep a backup of the database which will not backfill and investigate what the last record contains for dateTime.

[Michi Kaa]

Am Mittwoch, 7. August 2019 09:20:27 UTC+2 schrieb Andrew Milner:

do you have a rogue dateTime in the database?

Not that I'm aware of.

 

The log you posted ONLY has database records added at 22:00, 23:00, 24:00 and a message every 10 minutes saying there is no new data - press SET to resynch.  I repeat - how do you know that it has reconnected??

Well, the log tells me so, if I understand it correctly. At 22:00 it tells me it added the 21:05 record. After that (22:10:21) it tells me it didn't have contact with console for 617 seconds. Before that (21:51:14) it didn't have contact to console for 3071 seconds so it was connected in between because it resetted the "no contact since" value. After 01:00 there where records added every 5min again and the problem hasn't shon up again since.

 

No new data implies that it has NOT connected.  I see no evidence of a record being generated every 5 minutes.

This part of the log I didn't consider relevant. But take a look at the graph in post #2: you can see that there are beiing records up unti 20:00, the three single values between 20:00 and 01:00 and after 01:00 everythings looks normal again.

 

I believe you have not, despite what you think, actually regained normal communication - either that or there is  a record with an 'in the future' dateTime in the database.  The fact that you can recover by restoring an old backup implies that your problem is probably caused by the wrong dateTime associated with a record, and no data can be found with a dateTime greater than what is in the database - so no backfill is performed.

I believe, better: I know normal connection was regained at 01:00 - this part of the log I didn't consider relevant.

 

You could try running with debug = 1 set to see if more information can be found or you can keep a backup of the database which will not backfill and investigate what the last record contains for dateTime.

I think I'd be better off reproducing a connection loss by moving console out of range of the USB dongle but in range of the outside unit which transmitts wheather data to console.

[Andrew Milner]

You never said that it recovered by itself after 0100 - in fact you gave the impression that it only started working again after you stopped weewx, restored an old database and restarted weew and that then it did the backfill and recovered.  Well that is how I understood your posts anyway.

[Michi Kaa]

Am Mittwoch, 7. August 2019 13:49:00 UTC+2 schrieb Andrew Milner:

You never said that it recovered by itself after 0100 - in fact you gave the impression that it only started working again after you stopped weewx, restored an old database and restarted weew and that then it did the backfill and recovered.  Well that is how I understood your posts anyway.

I see. How did you get the impression? I am not a native english speaker and thought I pointed out that the only solution I know for backfilling ist to restore a backup, but I didn't say, I did in this particular case.

In short again: Connection was lost, regained, lost, regained, lost... then regained and up until now, never lost again. I wanted to know if the fact, that backfilling archive values, which are undoubtfully stored in the console, isn't working as I'd expect it, is considered a bug or is considered expected behaviour.

[gjr80]

Hi,

The backfill behaviour you are seeing is expected behaviour for the current codebase, in a nutshell WeeWX only attempts to download historical records when WeeWX starts.

Explanation. Drivers for stations that have the ability to store archive records may implement a genStartupRecords method. When called this method emits any records held in the station memory that are newer than the last record held in the WeeWX archive. WeeWX calls the genStartupMethod (if it exists) once during WeeWX startup, once WeeWX has started genStartupRecords is not called again unless WeeWX is restarted. The ws28xx driver has a a genStartupRecords method, which is called during WeeWX startup; however, the loss of communications you are experiencing does not cause WeeWX to restart so hence the archive records stored in the station are not downloaded when the connection returns to normal.

Looking at the ws28xx driver, the comments in the driver state:

“The station console sends a broadcast on the hour. If the transceiver responds, the station console may continue to broadcast data, depending on the transceiver response and the timing of the transceiver response.”

This may explain why you are seeing activity on the hour and nothing in between. For some unknown reason communication is eventually properly restored and normal 5 minute archive operation returns.

In short, given the current way stored records are backfilled by WeeWX and the operation of the ws28xx driver, I don’t think you have any other option for backfilling stored records. You may find that resynchronising with the station helps return normal operation earlier, but it won’t cause historical records to be downloaded.

Matthew or a ws28xx guru may have better advice.

Gary

[Andrew Milner]

Gary - thanks for that good description of when backfilling occurs although I have a feeling that the original poster had to restore an old copy of the database in order for backfilling to occur - hence my suspicion about a rogue dateTime in the database which would not backfill.

[gjr80]

If you call the ‘top of the hour’ archive records rogue records then yes they had a hand in preventing backfill, provided a restart occurred only those archive records stored in the station after the most recent ‘top of the hour’ archive record would be downloaded. Arguably though the reason the backfill did not occur when proper comms were restored is because the driver never caused a WeeWX restart so hence WeeWX never asks for the backfill from the driver.

Gary

[Michi Kaa]

Thank you for the explanation, Gary, everything now seems perfectly logical to me. Being a software developer myself I have a feeling that it probably isn't an easy change task to let weewx backfill values under such circumstances, nevertheless I'll write that on my christmas wishlist ;)

Maybe someone can anwser this question: lets pretend it is Jul 11, 01:30 and I discover the above issue. Yes, I have a weewx.sdb backup from Jul 10 00:01. I now could stop weewx, restore weewx.sdb to its state at Jul 10 00:01 and start weewx again. All the missing archive values are now read from console which is OK with a tiny flaw: all loop data is lost so the wind plot looks ugly because ws28xx only knows 16 directions and possibly minimum and maximum values for the day are slighty off. Question: in which way do I have to manipulate the database to get weewx to read - more or less only - the missing values? I once tried to delete the most current archive entries (in the case we discuss here that would be archive values Jul 10 20:00 and newer) which didn't help. If I had to guess this is linked to all the archive_day tables and their state...

[gjr80]

Not sure the WeeWX engine behaviour (backfill only requested during WeeWX startup/restart) will change, you probably have more chance of changing the driver behaviour.

Regarding your loop data question. Unfortunately there is little that can be done if the station does not maintain the same level of ‘precision’ in its stored archive records as it emits in its loop data. For the ws28xx stations in normal operation WeeWX synthesises an archive record from accumulated loop data, so you get all the highs and lows and ‘precision’ of the loop data. When you backfill records from the station you take what the station gives you, if that is one of 16 discrete wind directions that is what you are stuck with, the ‘precision’ of the loop data is not available for that period. In terms of highs and lows some time detail will be lost as highs and lows will now be seen on archive record timestamps rather than loop packet time stamps. The loss or otherwise of high and low values details will depend on how the station constructs the archive record it stores in memory.

If it’s any consolation a similar issue exists with the Davis stations, hardware generated archive records provide one of 16 discrete wind directions but loop packets provide wind direction as an integer in the range 1 to 360 degrees.

Remember that an archive record value is an average over a period of say 5 minutes so the need for 1 degree precision in the case of wind direction seems somewhat less important.

Gary

[Thomas Keffer]

Just a clarification: on startup, weewx does indeed call the genStartRecords() method on the driver. However, the default implementation is to just call genArchiveRecords() with the last good timestamp in the database as an argument. If the driver supports it, this effectively means  a "catch up" is done on every archive record. 

For example, this is what the Vantage driver does. I'm not familiar with the ws28xx driver, but the author may have had his/her reasons for overriding genStartupRecords(), which could mean losing this feature.

-tk

--
You received this message because you are subscribed to the Google Groups "weewx-user" group.
To unsubscribe from this group and stop receiving emails from it, send an email to weewx-user+...@googlegroups.com.
To view this discussion on the web visit https://groups.google.com/d/msgid/weewx-user/d9018181-e22f-4dbc-9213-5383a4617863%40googlegroups.com.

[gjr80]

Didn’t pickup on that. The ws28xx driver has no genArchiveRecords method, there is a comment in the driver to the effect that hardware record generation should not be implemented until archive records can be read at a faster rate than they are currently.

Gary

[Michi Kaa]

Am Mittwoch, 7. August 2019 21:11:04 UTC+2 schrieb gjr80:

Remember that an archive record value is an average over a period of say 5 minutes so the need for 1 degree precision in the case of wind direction seems somewhat less important.

Gary

I wouldn't consider it important in a statistics point of view, but the (especially) 24h wind direction plot looks somehow "ugly" if you only have 16 (or, on other stations maybe less) possible directions. On the other hand it depends on the plot as well, I use a crosshair for every value, maybe it doesn't look that ugly using a line graph or any other representaion.

Other than that I am really courious what a ws28xx guru has to say about the specific behaviour shown in case of a signal loss as described here and if there is a chance to improve data completeness in such cases without a manual intervention.