GUI date/time and current conditions frozen

[Zsolt Máté]

My current conditions are "frozen".

Date is waaay in the future. I'm located in NZ, local time/date is 4:47PM, the 21st of May.

Since we're UTC-12, nobody passed the dateline yet.

I've checkt the date/time and timezone and these are correct on my server.

The graphs are correct.

What could cause this?

I'm running weewx 4.0.0 and capturing my data using interceptor.

[gjr80]

Hi,

Could be any one of a number of causes, should be easily diagnosed with a debug log extract from WeeWX startup.

Gary

[Zsolt Máté]

Thanks for the fast reply Gary.

Here's the log -> https://pastebin.com/4zNJEJea

[gjr80]

Thanks, that is bizarre, I expectedt to see something in the log about record timestamps being less than the last, but no everything is normal. Archive records are bing generated with the correct timestamps, reports are being generated without issue. I can't see it being a browser cache issue, it would be stuck in the past not the future. A few (random) things to check:

1. does the time change or is it always 22 May 00:00 (guessing it stays put).

2. is the Seasons skin index.html file being generated every 5 minutes (ie does its timestamp change) (again guessing it does as Seasons should generate eight report files each report cycle and that is what it is doing)

3. do the current observations on the Seasons page change and are they correct.

4. do the timestamps below the plots on the Seasons 'Day' tab show the correct current time.

Gary

[Zsolt Máté]

I've ruled out browser cache. Tested on multiple devices within my network and even asked friends abroad to test. You can give it a try, as well. https://weather.zmate.nz

1. 22nd of May, 12:00:00 is not changing.

2. I've deleted the contents of the www and it has been automatically regenerated, without forcing it.
3. plots are being generated correctly, and the hour/minute looks correct.

4. the timestamp below the plots is showing 05/22/2020 12:00:00 AM - good that you asked.

[gjr80]

Aha, look at your wind direction and wind vector plots, you have a wind direction dot at midnight and likewise a vector. Are you using SQLite? If so try the following (you may have to install the sqlite3 package first if sqlite3 is not found - just use sudo apt-get install sqlite3):

$ sqlite /var/lib/weewx/weewx.sdb
> SELECT MAX(datetime(dateTime,'unixepoch','localtime')) FROM archive;

(.q to exit the sqlite3 command prompt)

What does that show?

Gary

I suspect There will be a data point in your archive for direction

[Zsolt Máté]

Nice catch.

I'm using mysql as database. Via phpmyadmin I've managed to sort the database to date, max is 1590084000, converted:

GMT: Thursday, 21 May 2020 6:00:00 PM

Your time zone: Friday, 22 May 2020 6:00:00 AM GMT+12:00

Relative: In 10 hours

[gjr80]

Brain fade on my part, I should have tweaked earlier. I would go in and delete the future records from the archive then rebuild the daily summaries. You could just let it be and it will (seemingly) fix itself come 6am tomorrow (albeit with a couple of duplicate index errors in the log) but those bogus records will remain.

Gary

[Zsolt Máté]

It looks like I messed up something. I've deleted the two rows from the "future", but now weewx wont start.

root@weewx:~# service weewx restart

root@weewx:~# tail -f /var/log/syslog

May 21 20:30:32 weewx weewx[8599] CRITICAL __main__:     ****    File "/usr/share/weewx/weewx/engine.py", line 158, in run

May 21 20:30:32 weewx weewx[8599] CRITICAL __main__:     ****      self.dispatchEvent(weewx.Event(weewx.STARTUP))

May 21 20:30:32 weewx weewx[8599] CRITICAL __main__:     ****    File "/usr/share/weewx/weewx/engine.py", line 224, in dispatchEvent

May 21 20:30:32 weewx weewx[8599] CRITICAL __main__:     ****      callback(event)

May 21 20:30:32 weewx weewx[8599] CRITICAL __main__:     ****    File "/usr/share/weewx/weewx/engine.py", line 522, in startup

May 21 20:30:32 weewx weewx[8599] CRITICAL __main__:     ****      _nrecs, _ndays = dbmanager.backfill_day_summary()

May 21 20:30:32 weewx weewx[8599] CRITICAL __main__:     ****    File "/usr/share/weewx/weewx/manager.py", line 1012, in backfill_day_summary

May 21 20:30:32 weewx weewx[8599] CRITICAL __main__:     ****      timestamp_to_string(lastRecord)))

May 21 20:30:32 weewx weewx[8599] CRITICAL __main__:     ****  ViolatedPrecondition: lastUpdate(2020-05-22 06:00:00 NZST (1590084000)) > lastRecord(2020-05-21 19:00:00 NZST (1590044400))

May 21 20:30:32 weewx weewx[8599] CRITICAL __main__:     ****  Exiting.

[gjr80]

Did you use wee_database to rebuild the daily summaries? Probably safest to drop them first then rebuild.

Gary

[Zsolt Máté]

wee_database --check runs OK (I assume), but --rebuild-daily return an error

root@weewx:~# wee_database --check

Using configuration file /etc/weewx/weewx.conf

Using database binding 'wx_binding', which is bound to database 'archive_mysql'

Checking daily summary tables version...

Daily summary tables are at version 2.0

Interval Weighting Fix is not required.

Daily summary tables version check completed in 0.02 seconds.

Preparing Null String Fix, this may take a while...

 Checking record: 135849; Timestamp: 2020-05-21 19:00:00 NZST (1590044400)

No null strings found.

Completed Null String Check in 12.25 seconds.

root@weewx:~# ^C

root@weewx:~# wee_database --rebuild-daily

Using configuration file /etc/weewx/weewx.conf

Using database binding 'wx_binding', which is bound to database 'archive_mysql'

All daily summaries will be rebuilt.

Proceed (y/n)? y

Rebuilding daily summaries in database 'weewx' ...

Traceback (most recent call last):

  File "/usr/share/weewx/wee_database", line 974, in <module>

    main()

  File "/usr/share/weewx/wee_database", line 169, in main

    rebuildDaily(config_dict, db_binding, options)

  File "/usr/share/weewx/wee_database", line 275, in rebuildDaily

    trans_days=20)

  File "/usr/share/weewx/weewx/manager.py", line 1012, in backfill_day_summary

    timestamp_to_string(lastRecord)))

weewx.ViolatedPrecondition: lastUpdate(2020-05-22 06:00:00 NZST (1590084000)) > lastRecord(2020-05-21 19:00:00 NZST (1590044400))

[gjr80]

No, —check just checks a couple of unrelated things, will not help you at all. You need to use —drop-daily before —rebuild-daily.

Gary

[Zsolt Máté]

Thank you, it worked. Interestingly that rogue spike is still showing up at the wind vector plot.

[gjr80]

Just force all your plots to be regenerated by deleting them from your WeeWX machine.

Gary

[Zsolt Máté]

Tried, twice.

[Jacques Terrettaz]

Hi,

You said on your top message that  your timezone is UTC - 12

But below I see UTC + 12

Could it be the problem ?

[Zsolt Máté]

Sorry, my bad. New Zealand is UTC+12.

My issue didn't disappear. Now is showing the time is showing 2PM and not updating, but local time is 07:15AM.

Data in the plots is scattered.

I've double checked the date/time on my PWS and is correct.

[Zsolt Máté]

Update, without any intervention time jumped to 6PM. 10hrs ahead.

[gjr80]

Just looked at your sire and you are now showing 0300 23 May so it has jumped again. If you look at the wind direction and wind vector plots you can clearly see individual points at around 0100 and 0300. It is hard to see but I believe all of the other plots have individual points at the same times (interestingly your plots only seem to have points every one hour, hence the lack of jointing lines, I am sure yesterday there were many more data points being shown, I would expect there to be points every archive interval, in your case 5 minutes). So for some reason you are picking up at least one bogus future dated loop packet every so often. I had a quick look at the interceptor driver last night and it protects you against receiving a packet that is earlier than the last packet in the database but there is no protection for packets that are timestamped later than the current system clock, so a future dated packet could quite conceivably be emitted by the driver and accepted by WeeWX.

Before we look at how to fix the problem it would be good to understand the exact circumstances when future data records are received. Could I suggest:

1. stop WeeWX

2. delete all future dated records from the archive

3. optional step, delete all plot files on the WeeWX machine. Aware you had an issue with this yesterday, note these must be the plots generated by WeeWX and not copies that have been uploaded to a web server or elsewhere on the WeeWX machine otherwise the old, incorrect plots are copied next time rather than all being regnerated

4. optional step, using the wee_database utility drop the daily summary tables using --drop-daily then rebuild the daily summaries using --rebuild-daily

5. ensure debug = 1 in weewx.conf

6. restart WeeWX

7. confirm the date-time in the top left hand corner of the main page returns to the current date-time

I say 3. and 4. are optional, they will tidy up your incorrect data but since we know it will happen again it is up to you whether you want to bother going through those steps now. You will have to do the same steps later anyway.

Let WeeWX run and when you next notice the current date-time in the top left corner has jumped forward look through the log since the restart to find the future dated record, if your time jumped to 0300 23 May 2020 then you would be looking for something like:

May 21 17:10:29 weewx weewx[7776] INFO weewx.manager: Added record 2020-05-23 03:00:00 NZST (1590159600) to database 'weewx'
May 21 17:10:29 weewx weewx[7776] INFO weewx.manager: Added record 2020-05-23 03:00:00 NZST (1590159600) to daily summary in 'weewx'

Once you find that entry it would be worthwhile seeing the log for say 10 minutes either side of that entry.

You could also go through your current logs looking for bogus future dated records that are timstamped with the same (future dated) date-time that you have been seeing in the top left hand corner of your main page (I think you mentioned 10pm and 6am?), up to you which way you go, we just want to see what is going on around those times.

One final thing, could you post a wee_debug report. This will give us a succinct picture of your WeeWX config. Just be careful to check the wee_debug report for sensitive info before posting; wee_debug should obfuscate passords, user names, api keys etc but it is not perfect.

Gary

[Zsolt Máté]

Weird, I really don't know what's happening. This morning, I've deleted everything related to the past day from the database.

1. done

2. deleted two records, see attached image 

3. I've deleted all the files from /var/www/html/weewx/

4. ran wee_database --drop-daily and --rebuild-daily

5. debug is set to 1

6. restart WeeWX

7. as soon as the web pages are generated, the date and time is correct.

I've started weewx right now, let's see what's happening.

What I've noticed today, the www data wasn't updated every 5 minutes, sometimes the website got updated only after 10-15 or even 30 minutes.

debug info here -> https://pastebin.com/k519Squx

Thanks for trying to help me.

PS, now that I've finished writing this reply, I noticed that the date and time below the plots is already wrong. Date and time in the top left corner is still OK.

[Zsolt Máté]

It stopped updating the html at local 08:00PM, and in the log I see an MQTT message dated tomorrow.

It's MQTT related: May 22 20:00:20 weewx weewx[5569] INFO weewx.restx: MQTT: Published record 2020-05-23 07:00:00 NZST (1590174000)

Log from 10 minutes before until 10 minutes after 8PM -> https://pastebin.com/K7s8e60V

[gjr80]

Thanks. I am trying to get my head around what is going on here. There seems to be a lot of double handling (posting) of records, for example the 22 May 19:50:20 record is published by the MQTT uploader six times:

May 22 19:50:28 weewx weewx[5569] INFO weewx.restx: MQTT: Published record 2020-05-22 19:50:20 NZST (1590133820)
...
May 22 19:50:29 weewx weewx[5569] INFO weewx.restx: MQTT: Published record 2020-05-22 19:50:20 NZST (1590133820)
...
May 22 19:50:44 weewx weewx[5569] INFO weewx.restx: MQTT: Published record 2020-05-22 19:50:20 NZST (1590133820)
...
May 22 19:50:50 weewx weewx[5569] INFO weewx.restx: MQTT: Published record 2020-05-22 19:50:20 NZST (1590133820)
...
May 22 19:51:00 weewx weewx[5569] INFO weewx.restx: MQTT: Published record 2020-05-22 19:50:20 NZST (1590133820)
...
May 22 19:51:16 weewx weewx[5569] INFO weewx.restx: MQTT: Published record 2020-05-22 19:50:20 NZST (1590133820)

I also see the interceptor is picking up a lot of what appears to be duplicate records some of which are HTTP POST and others HTTP GET. Can you clarrify your configuration? From the wee_debug report you have WeeWX uploading to WU both normal (every archive record) updates and rapid fire and you have WeeWX uploading to a MQTT broker every archive record and loop packet. Do you have your weather station uploading to WU? I am thinking it might be time to pare back to a bare bones setup by turning off a few services.

Gary

[Zsolt Máté]

Right now I've disabled MQTT in weewx.conf, cleaned the future records from the database, dropped and rebuild the daily stats. Last HTML generated is more than 30 minutes old.

To paint a picture of my setup:

I'm running this weather station -> https://www.jaycar.co.nz/7-inch-colour-wireless-weather-station/p/XC0370 - IP address 192.168.2.60 that sends data to WU (intercepted)

weewx is running in a proxmox container with the IP's 192.168.2.40 and 192.168.2.41, 41 being the interceptor.

On my router (openwrt), I've set up a rule, that the traffic from my PWS should be forwarded to 192.168.2.41.

iptables -t nat -A PREROUTING -s 192.168.2.60 -p tcp --dport 80 -j DNAT --to-destination 192.168.2.41:80

iptables -t nat -A POSTROUTING -j MASQUERADE

Weewx is forwarding the intercepted data to WU.

MQTT is used for the Belchertown skin (right now uninstalled) and to integrate my weather data into Home Assistant.

[Zsolt Máté]

Update, disabling MQTT didn't help. My time just jumped 10 hours in advance. From 12PM to 10PM.

Log 10 minutes +/- 12PM -> https://pastebin.com/FjkM7Mg8

Problem occurs here

May 23 12:00:19 weewx weewx[9805] DEBUG user.interceptor: raw packet: {'wind_speed': 1.8, 'humidity_in': 46.0, 'temperature_in': 71.2, 'solar_radiation': 296.66, 'windchill': 55.8, 'dewpoint': 48.6, 'humidity_out': 77.0, 'uv': 3.0, 'rain': 0.0, 'dateTime': 1590231600, 'pressure': 30.207, 'temperature_out': 55.8, 'wind_dir': 74.0, 'barometer': 30.169, 'rain_total': 0.0, 'usUnits': 1, 'wind_gust': 2.2}

Right now I've disabled WU in my weewx.conf, deleted html and cleaned the database.

Let's see.

[gjr80]

OK, starting to test the limits of my networking knowledge. One last thing to try, let's make sure the interceptor is listening to the correct IP address (and only the correct IP address). In weewx.conf under [Interceptor] can you add and the address = 192,168.2.41, ie:

[Interceptor]
    ....
    device_type = observer
    address = 192.168.2.41
    ....

Save and restart WeeWX.

I see you have now disabled WeeWX posting to WU, that may well fix the issue of the multiple duplicate packets but of course you have now lost the ability of posting to WU. If disabling WU in WeeWX settles things down you might want to try the adding the address setting above and enabling WU (but lets leave RF aside for now).

Taking a log extract from startup for a couple of archive periods should soon show if we are on track or not.

Gary

[Zsolt Máté]

Disabling WU didn't help.

May 23 15:00:19 weewx weewx[10289] DEBUG user.interceptor: raw packet: {'wind_speed': 2.0, 'humidity_in': 46.0, 'temperature_in': 72.9, 'solar_radiation': 134.81, 'windchill': 54.9, 'dewpoint': 47.8, 'humidity_out': 77.0, 'uv': 1.0, 'rain': 0.0, 'dateTime': 1590242400, 'pressure': 30.11, 'temperature_out': 54.9, 'wind_dir': 61.0, 'barometer': 30.071, 'rain_total': 0.0, 'usUnits': 1, 'wind_gust': 3.4}

I thought using pcap filter is better than in my case.

Switched to "address = 192.168.2.41", cleaned the database, deleted the html and started weewx.

[gjr80]

How about a log from startup for about 30 minutes, we should be able to see if those duplicate packets are gone.

Gary

[Zsolt Máté]

We have 8:22PM, it stopped at last report wast generated at 8PM.

Here's the log of the first 30 minutes, of the actual run

https://pastebin.com/uhyCkPvX

[gjr80]

Ok, the multiple duplicate timestamped packets are still there as are the POST and GET. Your system stuck at 8pm but you log extract went to 7:59pm, would be useful seeing 7:55 to say 8:15.

Gary

[Zsolt Máté]

Here's the log -> https://pastebin.com/B2zFhnje

[gjr80]

Well I am stumped.

The repeat packets seem to be in a reasonably regular routine, a few HTTP GETs followed by a HTTP POST. I can accept that since you are fooling your station into thinking the interceptor driver is WU your weather station may not be seeing the exact response it expects and that causes it to resend the data or try HTTP POST.

Looking at that last log extract I can see the 8pm archive record being saved, so that accounts for 8pm appearing on your page. The interceptor started deeming some of those duplicate packets as out of order and discarding them (interceptor accepts packets if the timestamp is greater than or equal to the last packets timestamp, anything else is dropped). I can’t see why it suddenly started dropping packets. Since no packets are getting through (after 8pm) no archive records are generated and hence no report cycle and the generated Seasons page doesn’t change. I expect that later some packets will be accepted and things will seem to work for a while. Noteworthy that this is a different symptom to yesterday where the page date-time was jumping ahead.

Would be good to get Matthew’s view (interceptor author) but I know he is busy with other things.

Only other suggestion I have is to maybe reconfigure your network to have your weather station update WU and have WeeWX use the interceptor driver to sniff the packets being sent to WU. Haven’t done that myself so I am not sure how feasible it is.

Gary

[Zsolt Máté]

I'm confident that the date/time will jump. I'm going to leave it run for the night.

I went through Matthew's wiki/how to/issues multiple times, and this is the best what I was able to do. I wasn't able to make interceptor listen to my network traffic and sniff out the communication between my PWS and WU.

If nothing helps, I'm going to clean up my database, export it, set up another virtual machine and install weewx.

[Zsolt Máté]

As an update, I didn't restart or modified anything since my last message, and it just started working.

I really don't understand what happened, now I'm afraid now to stop/restart it.

[Zsolt Máté]

After a month of trial and error, I'm still struggling with this issue.

I've changed my VM from turnkey linux to a full ubuntu server, didn't help. Tried minimal installations, mysql vs sqlite, no joy. My date is being messed up somehow.