Power outage without RTC module

[Andrea Di Saverio]

Today I had a power outage, from the 06:01 CEST to the 07:51 CEST.
So the last record added by weewx before the outage was at 06:01 CEST. From logs (reporting here only last two lines):

    pi@raspberrypi:~ $ journalctl -b -1
    Aug 20 06:01:14 raspberrypi python3[16243]: weewx[16243] INFO weewx.manager: Added record 2022-08-20 06:01:00 CEST (1660968060) to database 'weewx.sdb'
    Aug 20 06:01:14 raspberrypi python3[16243]: weewx[16243] INFO weewx.manager: Added record 2022-08-20 06:01:00 CEST (1660968060) to daily summary in 'weewx.s>

When the power came back, the wifi was not available, so the raspberry's time (I have no RTC module) was automatically set to a previously recorded timestamp: 05:53:32 CEST (118 mins before real time).
So when weewx re-started recording, it discarded first 8 samples and then started going. From logs:

    Aug 20 06:01:19 raspberrypi python3[600]: weewx[600] ERROR weewx.manager: Unable to add record 2022-08-20 05:54:00 CEST (1660967640) to database 'weewx.sdb': UNIQUE constraint failed: archive.dateTime
    Aug 20 06:01:19 raspberrypi python3[600]: weewx[600] ERROR weewx.manager: Unable to add record 2022-08-20 05:55:00 CEST (1660967700) to database 'weewx.sdb': UNIQUE constraint failed: archive.dateTime
    Aug 20 06:01:19 raspberrypi python3[600]: weewx[600] ERROR weewx.manager: Unable to add record 2022-08-20 05:56:00 CEST (1660967760) to database 'weewx.sdb': UNIQUE constraint failed: archive.dateTime
    Aug 20 06:01:19 raspberrypi python3[600]: weewx[600] ERROR weewx.manager: Unable to add record 2022-08-20 05:57:00 CEST (1660967820) to database 'weewx.sdb': UNIQUE constraint failed: archive.dateTime
    Aug 20 06:01:19 raspberrypi python3[600]: weewx[600] ERROR weewx.manager: Unable to add record 2022-08-20 05:58:00 CEST (1660967880) to database 'weewx.sdb': UNIQUE constraint failed: archive.dateTime
    Aug 20 06:01:19 raspberrypi python3[600]: weewx[600] ERROR weewx.manager: Unable to add record 2022-08-20 05:59:00 CEST (1660967940) to database 'weewx.sdb': UNIQUE constraint failed: archive.dateTime
    Aug 20 06:01:19 raspberrypi python3[600]: weewx[600] ERROR weewx.manager: Unable to add record 2022-08-20 06:00:00 CEST (1660968000) to database 'weewx.sdb': UNIQUE constraint failed: archive.dateTime
    Aug 20 06:01:19 raspberrypi python3[600]: weewx[600] ERROR weewx.manager: Unable to add record 2022-08-20 06:01:00 CEST (1660968060) to database 'weewx.sdb': UNIQUE constraint failed: archive.dateTime
    Aug 20 06:02:16 raspberrypi python3[600]: weewx[600] INFO weewx.manager: Added record 2022-08-20 06:02:00 CEST (1660968120) to database 'weewx.sdb'
    Aug 20 06:02:16 raspberrypi python3[600]: weewx[600] INFO weewx.manager: Added record 2022-08-20 06:02:00 CEST (1660968120) to daily summary in 'weewx.sdb'

But, and this is a bit surprising, it also discarded records collected in the davis datalogger.
They are 110 lines, from 1660968120 (06:02:00 CEST) and 1660974660 (07:51:00 CEST) (The power outage didn't affect the davis station: it is battery powered).
From logs (reporting only the first and the last one):

    Aug 20 05:53:35 raspberrypi python3[600]: weewx[600] WARNING weewx.engine: Ignore historical record: {'dateTime': 1660968120, 'usUnits': 1, 'interval': 1, 'rxCheckPercent': 89.6875, 'outTemp': 68.8>
    ...
    Aug 20 05:53:35 raspberrypi python3[600]: weewx[600] WARNING weewx.engine: Ignore historical record: {'dateTime': 1660974660, 'usUnits': 1, 'interval': 1, 'rxCheckPercent': 100.0, 'outTemp': 69.5, >

Why were they discarded? Because the weewx time was before the record's time?

Then, few hours later I restored the wifi network, and the rasp automatically changed his time, and so weewx. From logs:

    Aug 20 12:09:33 raspberrypi systemd[1]: Started Network Time Synchronization.
    Aug 20 14:07:04 raspberrypi systemd-timesyncd[2057]: Initial synchronization to time server 93.94.88.51:123 (0.debian.pool.ntp.org).
    Aug 20 14:07:05 raspberrypi python3[600]: weewx[600] INFO weewx.engine: Clock error is -7050.52 seconds (positive is fast)
    Aug 20 14:07:05 raspberrypi python3[600]: weewx[600] INFO weewx.drivers.vantage: Clock set to 2022-08-20 14:07:06 CEST (1660997226)

After this, it started to store data correctly, starting from 1660997280 (14:08:00 CEST).

Now the situation is:
- I have a hole from the 1660990140 (12:09:00 CEST) to 1660997280 (14:08:00 CEST) (excluded). (When I restored the network connection, and rasp fixed its time).
- All the database records with dateTime from 1660968120 (06:02:00 CEST) to 1660990140 (12:09:00 CEST) (included) are backshifted of 118 minutes
- Real records from 1660968120 (06:02:00 CEST) to 1660974660 (07:51:00 CEST) are in the datalogger so I can restore them.
- The only records I lost, are the first 8 samples weewx took after restart (from 07:52:00 CEST to 07:59:00 CEST, included)

My plan to fix data:
1. drop (but preserving for later use) all the records starting from 1660968120 (06:02:00 CEST) (included) from the `archive` table in the database
2. start weewx with datalogger activated to download records from 1660968120 (06:02:00 CEST) to 1660974660 (07:51:00 CEST)
3. re-insert records I removed at step 1. insert only from 1660968120 (06:02:00 CEST) to 1660990140 (12:09:00 CEST), adding 118*60 to dateTime
4. re-insert all the following records (so starting from 1660997280 (14:08:00 CEST)) keeping them as they are
5. fix other table running `wee_database --drop-daily` and then `wee_database --rebuild-daily` (maybe scoped to the single day of today)

Any suggestion, or comment?

Thanks


[But at the end, I have a question: Why in the datalogger, records starting from 07:52:00 CEST, have the same wrong values present in the weewx database? Is the datalogger written by weewx?
I mean: It looks like the datalogger has been written by weewx when (i) no data were present AND (ii) weewx was connected to him (so, starting from 07:52:00 CEST. before data are present, collected by the station itself)]

[MikeQ]

I have had a similar issue twice but not since January 2021.  I have my Davis console on wall power plus batteries, assuming the batteries would work like a UPS but that might not be reliable.

Look at the weewx wiki:

https://github.com/weewx/weewx/wiki/Troubleshooting-the-Davis-Vantage-station#weewx-generates-html-pages-but-it-does-not-update-them

I shut down weewx and inspected my database using DB Browser for SQLite on a desktop and there are no issues in the DB so clock slew was not my issue.

If I follow the instructions in 'Corrupt station memory' using debug mode i see exactly the same results as the wiki shows with the DMPACT command indicating the download is complete while I still have 197 pages in the datalogger.

Rebooting the console did not work for me and I had to use the dump & clear commands.  That resulted in the loss of records for a 25 minute period the last time around. 

[Andrea Di Saverio]

I was able to restore all the data, doing as I planned: (i) the records collected during the power outage have been recovered from davis data logger, (ii) the subsequent records were already in the database but with wrong dateTime, so I just fixed its value shifting it 118m in the future.

Then, as solid definitive solution for the future, I have also bought an RTC module for the rasp.

What is still puzzling me, is how is possible that the same wrong data (the wrong time value) was in the davis datalogger as well, for all the records in the period from after the power outage to the restoration of the correct time.

[Paul R Anderson]

For hardware that supports WeeWx can set the onboard clock of the hardware.

In your case the davis data logger supports setting of its onboard clock.

This is controlled in the  [StdTimeSynch] section of weewx.config

I believe WeeWx ships with this as default:

##############################################################################

#   For hardware that supports it, this section controls how often the
#   onboard clock gets updated.

[StdTimeSynch]

    # How often to check the weather station clock for drift (in seconds)
    clock_check = 14400

    # How much it can drift before we will correct it (in seconds)
    max_drift = 5

##############################################################################

So unless you changed it most likely WeeWx set the davis datalogger onboard clock, while your OS was running with the incorrect time. 

--
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/222c7edc-6798-4514-bbcd-44a33155d9dcn%40googlegroups.com.

[Paul R Anderson]

By the way there is an easy solution to stop this whole calamity of events from occurring.

In the case that for some reason you can not install a RTC, which is very desirable, and highly recommended.

You can enable the systemd-time-wait-sync service on your system.

sudo systemctl status systemd-time-wait-sync

sudo systemctl start systemd-time-wait-sync

The systemd service for weewx located at  /util/systemd/weewx.service

Has this in it:

Requires=time-sync.target After=time-sync.target

The problem is that time-sync.target starts thes ynchronization process , but doesn't wait for it to complete, so WeeWx starts before the OS clock gets synchronized .

Once you enable systemd-time-wait-sync Service 

systemd-time-wait-sync will wait infinitely till it can synchronize time.

Now services that depend on time-sync target , such as WeeWx ,will not start until the OS time is synchronized.

Which all means that now when the power comes back on the system starts, It tries to synchronize system OS time,

It might need to wait for a Wi-Fi connection, a router to start, an internet connection or something else.

Until the OS time get's synchronized WeeWx won't start.

Meanwhile your davis logger , if running on batteries during the whole power outage , will continue to log data.

Once WeeWx starts it will get all the data from the logger for the period of the power outage to present .

All should be well and looking at the WeeWx data, you would never know there was a power outage.

Hope this helps, and is't to confusing to follow.

Paul

[vince]

Easier yet - just install ntp and use that instead, and systemd won't do anything time related. 

FWIW - I've found ntp handles drift better by far, and I've been using it happily everywhere for well over 20 years across all unixy platforms of all vintages so I know what I'm getting.  You never know what systemd is going to do or change os to os and version to version.  You gotta fight the systemd borg whenever possible :-)

Here's the logs from a pi4 using ntp that I am running the simulator on which was powered down overnight.  Note how the system boots up initial with a Mar-26 date and weewx waits gracefully for the system to get the correct date+time before proceeding.  You'll see the syslog show the system switch to today's date when ntpd updates things and weewx starts up pretty much immediately after.

Mar 26 22:42:16 pi4 kernel: [    0.000000] Booting Linux on physical CPU 0x0
Mar 26 22:42:16 pi4 kernel: [    0.000000] Linux version 5.15.56-v7l+ (dom@buildbot) (arm-linux-gnueabihf-gcc-8 (Ubuntu/Linaro 8.4.0-3ubuntu1) 8.4.0, GNU ld (GNU Binutils for Ubuntu) 2.34) #1575 SMP Fri Jul 22 20:29:46 BST 2022
Mar 26 22:42:16 pi4 kernel: [    0.000000] CPU: ARMv7 Processor [410fd083] revision 3 (ARMv7), cr=30c5383d
Mar 26 22:42:16 pi4 kernel: [    0.000000] CPU: div instructions available: patching division code
Mar 26 22:42:16 pi4 kernel: [    0.000000] CPU: PIPT / VIPT nonaliasing data cache, PIPT instruction cache
Mar 26 22:42:16 pi4 kernel: [    0.000000] OF: fdt: Machine model: Raspberry Pi 4 Model B Rev 1.1

[...]

Mar 26 22:42:16 pi4 kernel: [    7.491386] uart-pl011 fe201000.serial: no DMA platform data
Mar 26 22:42:16 pi4 kernel: [    7.806915] Adding 102396k swap on /var/swap.  Priority:-2 extents:1 across:102396k SSFS
Mar 26 22:42:17 pi4 kernel: [    8.223906] brcmfmac: brcmf_cfg80211_set_power_mgmt: power save enabled
Mar 26 22:42:17 pi4 kernel: [    8.590674] bcmgenet fd580000.ethernet: configuring instance for external RGMII (RX delay)
Mar 26 22:42:17 pi4 kernel: [    8.592910] bcmgenet fd580000.ethernet eth0: Link is Down
Mar 26 22:42:17 pi4 weewx[415] INFO __main__: Initializing weewx version 4.8.0
Mar 26 22:42:17 pi4 weewx[415] INFO __main__: Using Python 3.9.2 (default, Mar 12 2021, 04:06:34) #012[GCC 10.2.1 20210110]
Mar 26 22:42:17 pi4 weewx[415] INFO __main__: Platform Linux-5.15.56-v7l+-armv7l-with-glibc2.31
Mar 26 22:42:17 pi4 weewx[415] INFO __main__: Locale is 'en_US.UTF-8'
Mar 26 22:42:17 pi4 weewx[415] INFO __main__: Using configuration file /home/weewx/weewx.conf
Mar 26 22:42:17 pi4 weewx[415] INFO __main__: Debug is 0
Mar 26 22:42:17 pi4 weewx[415] INFO __main__: Waiting for sane time. Current time is 2022-03-26 22:42:17 PDT (1648359737)
Mar 26 22:42:23 pi4 kernel: [   14.316585] IPv6: ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready
Mar 26 22:42:23 pi4 kernel: [   14.383527] Bluetooth: Core ver 2.22
Mar 26 22:42:23 pi4 kernel: [   14.383597] NET: Registered PF_BLUETOOTH protocol family
[...]
Mar 26 22:42:23 pi4 kernel: [   14.700205] Bluetooth: BNEP socket layer initialized
Mar 26 22:42:23 pi4 kernel: [   14.714801] NET: Registered PF_ALG protocol family
Mar 26 22:42:23 pi4 kernel: [   14.735599] cryptd: max_cpu_qlen set to 1000
Aug 22 08:34:37 pi4 kernel: [   31.832505] cam-dummy-reg: disabling
Aug 22 08:34:37 pi4 weewx[415] INFO weewx.engine: Loading station type Simulator (weewx.drivers.simulator)
Aug 22 08:34:37 pi4 weewx[415] INFO user.MQTTSubscribe: (Service) Version is 2.1.0
Aug 22 08:34:37 pi4 weewx[415] INFO user.MQTTSubscribe: (Service) Log level: 0
Aug 22 08:34:37 pi4 weewx[415] INFO user.MQTTSubscribe: (Service) Log debug setting: 0
Aug 22 08:34:37 pi4 weewx[415] INFO user.MQTTSubscribe: (Service) Log console: False
Aug 22 08:34:37 pi4 weewx[415] INFO user.MQTTSubscribe: (Service) Log file: None

[Paul R Anderson]

Problem I've seen in the past was that on a Rasberry Pi installrd NTP , like I have on every system I've installed since 2004, yet after a power outage weeWx started with a bad Os Time. Investigated and found that if I removed purged fake-hwclock the expected wait for ntp worked. Now on some systems I install ntp others I don't, if it's a PI remove fake-hwclock and even if the machine has a RTC I enable systemd-time-wait-sync.

Also change weewx.service to:

Requires=systemd-time-wait-sync.service
After=systemd-time-wait-sync.service

Many ways to get there

--
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/0d091386-1e68-4f64-9c7b-44e67de544afn%40googlegroups.com.

[vince]

On Monday, August 22, 2022 at 10:12:59 AM UTC-7 pa...@pauland.net wrote:

Problem I've seen in the past was that on a Rasberry Pi installrd NTP , like I have on every system I've installed since 2004, yet after a power outage weeWx started with a bad Os Time. Investigated and found that if I removed purged fake-hwclock the expected wait for ntp worked. Now on some systems I install ntp others I don't, if it's a PI remove fake-hwclock and even if the machine has a RTC I enable systemd-time-wait-sync.

Yes - but be careful there.  Lots of os now have that blasted fake-hwclock kludge.

I remove fake-hwclock and install/enable ntpd everywhere and it's nice and simple and reliable.  No need to edit anything in weewx at all, which is an added plus.

The pi time-related details are in the FAQ and wiki.

[Paul R Anderson]

fake-hwclock is just plain silly, by design it sets the OS time to a known wrong state with the premise that it's a better than nothing choice.

Funny the further down the rabbit hole I go the more I see that I don't like.  Such as debian setting NTPD or timesyncd to use debian.pool.ntp.org ntp servers.

I certainly don't trust their list of rotating servers to all be accurate. Always set systems to use known highly available servers I trust.

It's a jungle out there a minimum you need, Belt, Suspenders, and of course a good quality Tin Foil Hat.

Paul

so strange that a simple thing lige starting

--
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/221eacc6-2833-420d-ad00-0d6cb4d56c00n%40googlegroups.com.

[cric...@pobox.com]

My solution was to install ntp, plus add a wait routine in bin/user/extensions that waits for ntpq -pn to
report sync'd time.  I use that code on the rest of my Rpi's as well.  Can send if interested.  FWIW, the RPi that

runs my weather station does have a RTC stacked on the serial port (pre-dates said code block).

[gary....@gmail.com]

Though I have an RTC on both Pi, I install always install chrony

On my primary server, I have chrony running using NTS servers as its time source. I allow clients from the LAN on this machine.

I have all other machines that can run it use chrony with my LAN server as the only source. If a device only has a time source (NTP) field, I use the LAN address of the main server.

Though the load is low, it keeps additional traffic off my WAN and has proven to be accurate over the years. More so that NTPD in my location.

I too have come to look for fake-hwclock and remove it.