Experiences with vantage driver on a raspberry pi

[Luc Heijst]

On my raspberry pi model 2b I run two instances of weewx simultanious for my ws28xx weather station and klimalogg thermo-hygro logger respectively. 

No problems with these and rxCheckPercentages of nearly 100% each.

Last week I got my Davis Vantage Pro2 weather station and I hooked it up on this RPI.

To be honest: I was a bit disappointed first!

I got mainly three errors:

1. No <ACK> received (but always 'a') after startup

2. CRC error with read of WRD command

3. Zero bytes received when reading 267 bytes of loop data

Error 1 I could cure most of the time by adding a wait of 0.5 s after the console was wake up-ped.

Error 2 I cured by adding a wait of 1.0 s just before the WRD command

Error 3 was cured by increasing variable 'timeout' in the Vantage section of weewx.conf from 5 s to 30 s

(I also set max_tries to 1, because retrying seemed to solve nothing.)

Now my vantage driver runs without errors and the rxCheckPercentages are between 90 and 100 %.

Any of you have similar experiences?

Cheers,

Luc

[Luc Heijst]

Update: Error 3 was referring to reading 267 bytes of the archive data, not the loop data.

Luc

[Thomas Keffer]

I have not had any of these problems.

When people have problems communicating with the Vantage it is almost always a serial-to-USB converter problem. Are you using one? Or, does your VPro have a USB connector?

Also, most of the communication problems seem to involve LOOP data, not the archive data. The latter seems to download without problems most of the time.

-tk

On Tue, Nov 10, 2015 at 1:33 PM, Luc Heijst <ljm.h...@gmail.com> wrote:

Update: Error 3 was referring to reading 267 bytes of the archive data, not the loop data.

Luc

--
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.
For more options, visit https://groups.google.com/d/optout.

[L.J.M. Heijst]

Hi Tom,

Thanks for your message about our cat Smurf.

I have a USB device. Tried three different USB cables (one with a ferrite coil) all same results, also with lower baud rates. The problems are with reading the archive data (after group 4 follows a new read which result sometimes in 0 bytes received). Today I had problems with my Raspberry PI, so I wanted to swich back to my Synology NAS. But not today, as my dear (almost 19 years) old cat passed away...

Luc

Verstuurd vanaf mijn iPad

You received this message because you are subscribed to a topic in the Google Groups "weewx-user" group.
To unsubscribe from this topic, visit https://groups.google.com/d/topic/weewx-user/nW-vZsXIeJk/unsubscribe.
To unsubscribe from this group and all its topics, send an email to weewx-user+...@googlegroups.com.

[Nate Bargmann]

Luc, I'm chiming in a bit late. Do you have the logger that plugs into
the back of the VP2 console? If so, I had problems early on with the
console sitting on a shelf and strain on the USB cable unseating the
logger slightly which caused LOOP read errors. I resolved that but
putting a bit of antistatic foam between the logger body and the cover.
So far no more errors even when I move the console a bit.

- Nate

--

"The optimist proclaims that we live in the best of all
possible worlds. The pessimist fears this is true."

Ham radio, Linux, bikes, and more: http://www.n0nb.us

[Luc Heijst]

Thanks Nate,

I checked the logger; it was pre-installed by the supplier so I had not inspected it in detail. 

Tonight I removed the logger and needed so much power that I doubt that a slight movement of the cable would tresult in contact errors.

But it was worth checking; thanks for your advice.

Tom,

i might have found the cause of the problems; I'll have to wait till daylight to check more precise.

The line between the antennas of the iss and the console go through a window. 

Our windows happen to have on both sides iron grates to keep out burglars (and Vantage radio signals)

Half way the windows there are larger openings in both grates. So I will look by daylight from the antenna of the console to the antenna of the iss en position this line-of-sight through this opening.

The line between the console and the anemometer transmitter kit may go through another window (with grates) or just outside that window.

The longest streak of consecutive good packets received is increased from about 60 for both iss and atk to 230 (iss) and 320 (atk).

As a test, I deleted the 200 most recent archive records from the database and reread them again. Now I only had one error (still 1 error to much!).

Cheers,

Luc

[Thomas Keffer]

Not following here.

If the RF signal was blocked, that would affect the quality of the link between the ISS (or wind anemometer), not between the logger and the RPi.

Or, am I missing something?

-tk

--

[Thomas Keffer]

Oops. That got garbled. Let me try again:

If the RF signal was blocked, that would affect the quality of the link between the ISS (or wind anemometer) and the console, not between the logger and the RPi.

Or, am I missing something?

-tk

[Luc Heijst]

Tom,

If I understood it right the console can do one transmission at a time:

a. or it is receiving signals frpm the iss and anemometer

b. or it is receiving/sending data to the RPI.

If the above is true, a disturbance in channel 'a' may influence (delay?) channel 'b'.

I wonder how long channe 'b' will be reserved for sending/receiving after the console is waked up before channel 'a' will get control again. I will check the documentation.on this.

Luc

[Thomas Keffer]

I don't know. That would be a question for Davis. 

A bit of evidence that you might be right: if one downloads a lot of archive records, the display on the console freezes. Makes me think it cannot do two things at once.

But, it does not follow that a lot of RF link failures can cause USB failures.

-tk

[Luc Heijst]

Tom,

We don't have to ask Davis: it's in the manual.(Vantage ProTM, Vantage Pro2TM and Vantage VueTM Serial Communication Reference Manual Rev 2.6.1 )

VI. Blackout Periods

The console will not process commands when it is in any of the Setup screens (except the first: "Receiving From…"). It will also not process commands when the console is in a number entry mode (e.g. setting an alarm value).

Similarly, when a Download is in progress, the console will not respond to key presses and will not receive data packets from remote sensors.

The only error I stil get is a timeout error where 0 bytes are received.whetr 267 were expected. BTW. the vantage driver does not wait between two read command. I had expect it should wait 'wait_before_retry' seconds.. 

Futhermore I wonder if it has any use to retry a read which has a timeout.Unfortunately there is no timeout exeption on a read command, but you may concliude that if less characters are received than expected a timeout has occurred, especial when zero bytes were received.

Luc

[Thomas Keffer]

Yes, that's pretty much what I said. 

NB: it does not say the opposite: that if the RF link is disturbed, then this can cause problems with the serial protocol.

-tk

[Luc Heijst]

Tom,

You are right, the opposite is not true.

During a dump the console keeps awake for a minimum of two minutes, so that will not be any problem.

Something else.

On my console the elevation is set to 4 meters, but the vantage driver says Altitude: 3 (meter).

Davis Vantage EEPROM settings:

    

    CONSOLE TYPE:                   VantagePro2

    

    CONSOLE FIRMWARE:

      Date:                         Jun  3 2013

      Version:                      3.15

    

    CONSOLE SETTINGS:

      Archive interval:             300 (seconds)

      Altitude:                     3 (meter)

      Wind cup type:                large

      Rain bucket type:             0.2 MM

      Rain year start:              1

      Onboard time:                 2015-11-13 23:34:55 

Luc

[Luc Heijst]

Tom,

When i get a timeout on a read of 267 archive bytes a retry doesn't help. The next messages also get a timeout. i'd like to try to send an Esc to abort the DMPAFT followed by a wakeup of the console and a new DMPAFT command. I will keep you informed.

Cheers, Luc

[Thomas Keffer]

OK. Feel free to fork the repository and make any changes.

-tk

[Luc Heijst]

Status update

I modified the vantage driver (tested with serial/USB) to get a better communication.

- wake up console gently (just a wtite \n and a read, no flush, no sleep)

- when this fails wake up console the traditional way (i.e thorough; so far no need for it)

- reinvoke DMPAFT when zero bytes are received (i.e. timeout)

- reinvoke LOOP 200 when zero bytes are received (i.e timeout)

- driver has no sleep commands anymore (serial/USB only)

- current throughput: 150 loop packets in 300 s

Luc

[Luc Heijst]

Status update

In addition to the modifications reported on 22 Nov:

- pause 2.5 s and reinvoke DMPAFT after each 50th received historical record to let the console read the sensors data

Explanation

-----------

A 'traditional' catchup of all vantage archive records took 25 minutes on my Raspberry PI 2B.

During the catchup of in total 2563 records no communication is possible between the console (read: the data logger) and the sensors resulting in a data gap of 25 minutes.

See the Vantage ProTM, Vantage Pro2TM and Vantage VueTM Serial Communication Reference Manual:

VI. Blackout Periods

The console will not process commands when it is in any of the Setup screens (except the first: "Receiving From…"). It will also not process commands when the console is in a number entry mode (e.g. setting an alarm value).

Similarly, when a Download is in progress, the console will not respond to key presses and will not receive data packets from remote sensors.

In the modified driver after each received 50th historical record the DMPAFT command is ended with a sent escape character.

Then the driver pauses 2.5 s to let the console communicate with the sensors. In general this will result in one bad packet followed by one good packet (with the data of the sensors).

After the pause the driver reinvokes the DMPAFT command to get the number of outstanding pages with historical records.

In the attached graphs you will noticed the effects of:

a. a 'traditional' catchup between 10:25 and 10:50; notice the wind data is zero during that period.

b. a 'modified' catchup between 11:06 and 11:21; the graphs show the received sensor data during the catchup.

For those interested in how it is done I've included my modified driver. Be aware this is a test version and contain numerous debug statements which show the progress of the driver.

Below an example of the debug log. 

Luc

Example of vantage debug log

----------------------------

START 'TRADITIONAL' DRIVER

Dec 13 10:25:22 pi2 vant[24397]: engine: Initializing engine

Dec 13 10:25:22 pi2 vant[24397]: vantage: Opened up serial port /dev/ttyUSB0; baud 19200; timeout 4.00

Dec 13 10:25:23 pi2 vant[24397]: vantage: hardware type is 16

Dec 13 10:25:23 pi2 vant[24397]: engine: Loading service weewx.engine.StdTimeSynch

Dec 13 10:25:23 pi2 vant[24397]: engine: Finished loading service weewx.engine.StdTimeSynch

Dec 13 10:25:23 pi2 vant[24397]: engine: Loading service weewx.engine.StdConvert

Dec 13 10:25:23 pi2 vant[24397]: engine: Finished loading service weewx.engine.StdConvert

Dec 13 10:25:23 pi2 vant[24397]: engine: Loading service weewx.engine.StdCalibrate

Dec 13 10:25:23 pi2 vant[24397]: engine: Finished loading service weewx.engine.StdCalibrate

Dec 13 10:25:23 pi2 vant[24397]: engine: Loading service weewx.engine.StdQC

Dec 13 10:25:23 pi2 vant[24397]: engine: Finished loading service weewx.engine.StdQC

Dec 13 10:25:23 pi2 vant[24397]: engine: Loading service weewx.wxservices.StdWXCalculate

Dec 13 10:25:23 pi2 vant[24397]: engine: Finished loading service weewx.wxservices.StdWXCalculate

Dec 13 10:25:23 pi2 vant[24397]: engine: Loading service user.cmon.ComputerMonitor

Dec 13 10:25:24 pi2 vant[24397]: engine: Finished loading service user.cmon.ComputerMonitor

Dec 13 10:25:24 pi2 vant[24397]: engine: Loading service user.weewxwd3.WdWXCalculate

Dec 13 10:25:24 pi2 vant[24397]: engine: Finished loading service user.weewxwd3.WdWXCalculate

Dec 13 10:25:24 pi2 vant[24397]: engine: Loading service weewx.engine.StdArchive

Dec 13 10:25:24 pi2 vant[24397]: engine: Use LOOP data in hi/low calculations: 1

Dec 13 10:25:24 pi2 vant[24397]: engine: Finished loading service weewx.engine.StdArchive

Dec 13 10:25:24 pi2 vant[24397]: engine: Loading service user.forecast.WUForecast

Dec 13 10:25:25 pi2 vant[24397]: forecast: MainThread: WU: last forecast issued 2015-12-13 09:25:21 SRT (1450009521), requested 2015-12-13 09:25:21 SRT (1450009521)

Dec 13 10:25:25 pi2 vant[24397]: engine: Finished loading service user.forecast.WUForecast

Dec 13 10:25:25 pi2 vant[24397]: engine: Loading service user.retain.RetainLoopValues

Dec 13 10:25:25 pi2 vant[24397]: engine: Finished loading service user.retain.RetainLoopValues

Dec 13 10:25:25 pi2 vant[24397]: engine: Loading service user.weewxwd3.WdArchive

Dec 13 10:25:25 pi2 vant[24397]: engine: Finished loading service user.weewxwd3.WdArchive

Dec 13 10:25:25 pi2 vant[24397]: engine: Loading service weewx.restx.StdStationRegistry

Dec 13 10:25:25 pi2 vant[24397]: engine: Finished loading service weewx.restx.StdStationRegistry

Dec 13 10:25:25 pi2 vant[24397]: engine: Loading service weewx.restx.StdWOW

Dec 13 10:25:25 pi2 vant[24397]: engine: Finished loading service weewx.restx.StdWOW

Dec 13 10:25:25 pi2 vant[24397]: engine: Loading service weewx.restx.StdWunderground

Dec 13 10:25:25 pi2 vant[24397]: engine: Finished loading service weewx.restx.StdWunderground

Dec 13 10:25:25 pi2 vant[24397]: engine: Loading service weewx.restx.StdPWSweather

Dec 13 10:25:25 pi2 vant[24397]: engine: Finished loading service weewx.restx.StdPWSweather

Dec 13 10:25:25 pi2 vant[24397]: engine: Loading service weewx.restx.StdCWOP

Dec 13 10:25:25 pi2 vant[24397]: engine: Finished loading service weewx.restx.StdCWOP

Dec 13 10:25:25 pi2 vant[24397]: engine: Loading service user.sync.SyncService

Dec 13 10:25:25 pi2 vant[24397]: sync archive: requesting latest dateTime from http://www.lucdesign.nl/web/meso/data.php

Dec 13 10:25:25 pi2 vant[24397]: sync archive: 0 records to sync since last synced record with dateTime: 2015-12-13 10:20:00 SRT (1450012800)

Dec 13 10:25:25 pi2 vant[24397]: sync archive: will sync archive records

Dec 13 10:25:25 pi2 vant[24397]: sync archive: waiting for new records

Dec 13 10:25:25 pi2 vant[24397]: sync raw: waiting for new records

Dec 13 10:25:25 pi2 vant[24397]: sync raw: will sync raw records

Dec 13 10:25:25 pi2 vant[24397]: engine: Finished loading service user.sync.SyncService

Dec 13 10:25:25 pi2 vant[24397]: engine: Loading service weewx.engine.StdPrint

Dec 13 10:25:25 pi2 vant[24397]: engine: Finished loading service weewx.engine.StdPrint

Dec 13 10:25:25 pi2 vant[24397]: engine: Loading service weewx.engine.StdReport

Dec 13 10:25:25 pi2 vant[24397]: engine: Finished loading service weewx.engine.StdReport

Dec 13 10:25:25 pi2 vant[24397]: vantage: successfully woke up console gently

Dec 13 10:25:25 pi2 vant[24397]: vantage: Getting all archive packets

Dec 13 10:25:25 pi2 vant[24397]: vantage: successfully woke up console gently

START OF 'TRADITIONAL' CATCHUP

Dec 13 10:25:25 pi2 vant[24397]: vantage: Retrieving 513 page(s); starting index= 0

Dec 13 10:25:25 pi2 vant[24397]: vantage: number_of_wind_samples: 111; rxCheckPercent: 97.125

Dec 13 10:25:25 pi2 vant[24397]: vantage: received record in page 0; index 0; dateTime 2015-12-04 13:00:00 SRT (1449244800)

Dec 13 10:25:25 pi2 vant[24397]: vantage: yield3 archive record no 1; time_outs: 0

Dec 13 10:25:25 pi2 vant[24397]: cmon: Skipping record: time difference 768326 too big

Dec 13 10:25:25 pi2 vant[24397]: forecast: MainThread: WU: not yet time to do the forecast

Dec 13 10:25:26 pi2 vant[24397]: restx: CWOP: record 2015-12-04 13:00:00 SRT (1449244800) is stale (768326 > 1800).

Dec 13 10:25:26 pi2 vant[24397]: sync archive: put record in queue 2015-12-04 13:00:00 SRT (1449244800)

Dec 13 10:25:26 pi2 vant[24397]: sync archive: get record 2015-12-04 13:00:00 SRT (1449244800); last synced 2015-12-13 10:20:00 SRT (1450012800)

Dec 13 10:25:26 pi2 vant[24397]: vantage: number_of_wind_samples: 109; rxCheckPercent: 95.375

Dec 13 10:25:26 pi2 vant[24397]: vantage: received record in page 0; index 1; dateTime 2015-12-04 13:05:00 SRT (1449245100)

Dec 13 10:25:26 pi2 vant[24397]: vantage: yield3 archive record no 2; time_outs: 0

Dec 13 10:25:26 pi2 vant[24397]: sync archive: skip already synced record 2015-12-04 13:00:00 SRT (1449244800)

Dec 13 10:25:26 pi2 vant[24397]: cmon: Skipping record: time difference 768026 too big

Dec 13 10:25:26 pi2 vant[24397]: forecast: MainThread: WU: not yet time to do the forecast

Dec 13 10:25:26 pi2 vant[24397]: sync archive: put record in queue 2015-12-04 13:05:00 SRT (1449245100)

Dec 13 10:25:26 pi2 vant[24397]: restx: CWOP: record 2015-12-04 13:05:00 SRT (1449245100) is stale (768026 > 1800).

Dec 13 10:25:26 pi2 vant[24397]: vantage: number_of_wind_samples: 110; rxCheckPercent: 96.25

Dec 13 10:25:26 pi2 vant[24397]: vantage: received record in page 0; index 2; dateTime 2015-12-04 13:10:00 SRT (1449245400)

Dec 13 10:25:26 pi2 vant[24397]: vantage: yield3 archive record no 3; time_outs: 0

Dec 13 10:25:26 pi2 vant[24397]: sync archive: get record 2015-12-04 13:05:00 SRT (1449245100); last synced 2015-12-13 10:20:00 SRT (1450012800)

Dec 13 10:25:26 pi2 vant[24397]: cmon: Skipping record: time difference 767727 too big

Dec 13 10:25:26 pi2 vant[24397]: sync archive: skip already synced record 2015-12-04 13:05:00 SRT (1449245100)

Dec 13 10:25:27 pi2 vant[24397]: forecast: MainThread: WU: not yet time to do the forecast

Dec 13 10:25:27 pi2 vant[24397]: sync archive: get record 2015-12-04 13:10:00 SRT (1449245400); last synced 2015-12-13 10:20:00 SRT (1450012800)

Dec 13 10:25:27 pi2 vant[24397]: sync archive: skip already synced record 2015-12-04 13:10:00 SRT (1449245400)

Dec 13 10:25:27 pi2 vant[24397]: restx: CWOP: record 2015-12-04 13:10:00 SRT (1449245400) is stale (767727 > 1800).

Dec 13 10:25:27 pi2 vant[24397]: sync archive: put record in queue 2015-12-04 13:10:00 SRT (1449245400)

Dec 13 10:25:27 pi2 vant[24397]: vantage: number_of_wind_samples: 108; rxCheckPercent: 94.5

Dec 13 10:25:27 pi2 vant[24397]: vantage: received record in page 0; index 3; dateTime 2015-12-04 13:15:00 SRT (1449245700)

Dec 13 10:25:27 pi2 vant[24397]: vantage: yield3 archive record no 4; time_outs: 0

Dec 13 10:25:27 pi2 vant[24397]: cmon: Skipping record: time difference 767427 too big

Dec 13 10:25:27 pi2 vant[24397]: forecast: MainThread: WU: not yet time to do the forecast

Dec 13 10:25:27 pi2 vant[24397]: sync archive: put record in queue 2015-12-04 13:15:00 SRT (1449245700)

Dec 13 10:25:27 pi2 vant[24397]: sync archive: get record 2015-12-04 13:15:00 SRT (1449245700); last synced 2015-12-13 10:20:00 SRT (1450012800)

Dec 13 10:25:27 pi2 vant[24397]: vantage: number_of_wind_samples: 109; rxCheckPercent: 95.375

Dec 13 10:25:27 pi2 vant[24397]: vantage: received record in page 0; index 4; dateTime 2015-12-04 13:20:00 SRT (1449246000)

Dec 13 10:25:27 pi2 vant[24397]: sync archive: skip already synced record 2015-12-04 13:15:00 SRT (1449245700)

Dec 13 10:25:27 pi2 vant[24397]: restx: CWOP: record 2015-12-04 13:15:00 SRT (1449245700) is stale (767427 > 1800).

Dec 13 10:25:27 pi2 vant[24397]: vantage: yield3 archive record no 5; time_outs: 0

...

Dec 13 10:50:28 pi2 vant[24397]: vantage: yield3 archive record no 2561; time_outs: 2

Dec 13 10:50:28 pi2 vant[24397]: cmon: Skipping record: time difference 989 too big

Dec 13 10:50:28 pi2 vant[24397]: forecast: MainThread: WU: not yet time to do the forecast

Dec 13 10:50:28 pi2 vant[24397]: restx: StationRegistry: wait interval (164040 < 604800) has not passed for record 2015-12-13 10:34:00 SRT (1450013640)

Dec 13 10:50:28 pi2 vant[24397]: sync archive: put record in queue 2015-12-13 10:34:00 SRT (1450013640)

Dec 13 10:50:28 pi2 vant[24397]: vantage: number_of_wind_samples: 0; rxCheckPercent: 0.0

Dec 13 10:50:28 pi2 vant[24397]: vantage: received record in page 190; index 1; dateTime 2015-12-13 10:35:00 SRT (1450013700)

Dec 13 10:50:28 pi2 vant[24397]: vantage: yield3 archive record no 2562; time_outs: 2

Dec 13 10:50:28 pi2 vant[24397]: cmon: Skipping record: time difference 929 too big

Dec 13 10:50:29 pi2 vant[24397]: restx: CWOP: Connected to server cwop.aprs.net:14580

Dec 13 10:50:29 pi2 vant[24397]: restx: CWOP: wait interval (540 < 600) has not passed for record 2015-12-13 10:34:00 SRT (1450013640)

Dec 13 10:50:29 pi2 vant[24397]: forecast: MainThread: WU: not yet time to do the forecast

Dec 13 10:50:29 pi2 vant[24397]: restx: StationRegistry: wait interval (164100 < 604800) has not passed for record 2015-12-13 10:35:00 SRT (1450013700)

Dec 13 10:50:29 pi2 vant[24397]: sync archive: put record in queue 2015-12-13 10:35:00 SRT (1450013700)

Dec 13 10:50:29 pi2 vant[24397]: vantage: number_of_wind_samples: 0; rxCheckPercent: 0.0

Dec 13 10:50:29 pi2 vant[24397]: vantage: received record in page 190; index 2; dateTime 2015-12-13 10:41:00 SRT (1450014060)

Dec 13 10:50:29 pi2 vant[24397]: vantage: yield3 archive record no 2563; time_outs: 2

Dec 13 10:50:29 pi2 vant[24397]: cmon: Skipping record: time difference 570 too big

Dec 13 10:50:29 pi2 vant[24397]: restx: CWOP: Connected to server cwop.aprs.net:14580

Dec 13 10:50:30 pi2 vant[24397]: sync archive: get record 2015-12-13 10:34:00 SRT (1450013640); last synced 2015-12-13 10:20:00 SRT (1450012800)

Dec 13 10:50:30 pi2 vant[24397]: sync archive: send record 2015-12-13 10:34:00 SRT (1450013640)

Dec 13 10:50:30 pi2 vant[24397]: forecast: MainThread: WU: not yet time to do the forecast

Dec 13 10:50:30 pi2 vant[24397]: restx: StationRegistry: wait interval (164460 < 604800) has not passed for record 2015-12-13 10:41:00 SRT (1450014060)

Dec 13 10:50:30 pi2 vant[24397]: restx: CWOP: wait interval (360 < 600) has not passed for record 2015-12-13 10:41:00 SRT (1450014060)

Dec 13 10:50:30 pi2 vant[24397]: sync archive: put record in queue 2015-12-13 10:41:00 SRT (1450014060)

Dec 13 10:50:30 pi2 vant[24397]: vantage: number_of_wind_samples: 108; rxCheckPercent: 94.5

Dec 13 10:50:30 pi2 vant[24397]: vantage: received record in page 190; index 3; dateTime 2015-12-04 13:15:00 SRT (1449245700)

Dec 13 10:50:30 pi2 vant[24397]: vantage: DMPAFT complete: page timestamp 2015-12-04 13:15:00 SRT (1449245700) less than final timestamp 2015-12-13 10:41:00 SRT (1450014060)

END OF 'TRADIIONAL' CATCHUP

Dec 13 10:50:30 pi2 vant[24397]: vantage: successfully woke up console gently

Dec 13 10:50:30 pi2 vant[24397]: vantage: Requesting 200 LOOP packets.

Dec 13 10:50:30 pi2 vant[24397]: vantage: successfully woke up console gently

Dec 13 10:50:30 pi2 vant[24397]: vantage: yield2 loop_packet no 1; dateTime 1450014631

Dec 13 10:50:30 pi2 vant[24397]: sync raw: send record 2015-12-13 10:50:31 SRT (1450014631)

Dec 13 10:50:31 pi2 vant[24397]: sync archive: get record 2015-12-13 10:35:00 SRT (1450013700); last synced 2015-12-13 10:20:00 SRT (1450012800)

Dec 13 10:50:31 pi2 vant[24397]: sync archive: send record 2015-12-13 10:35:00 SRT (1450013700)

Dec 13 10:50:32 pi2 vant[24397]: sync archive: get record 2015-12-13 10:41:00 SRT (1450014060); last synced 2015-12-13 10:20:00 SRT (1450012800)

Dec 13 10:50:32 pi2 vant[24397]: sync archive: send record 2015-12-13 10:41:00 SRT (1450014060)

Dec 13 10:50:32 pi2 vant[24397]: vantage: yield2 loop_packet no 2; dateTime 1450014632

Dec 13 10:50:32 pi2 vant[24397]: sync raw: send record 2015-12-13 10:50:32 SRT (1450014632)

Dec 13 10:50:36 pi2 vant[24397]: vantage: yield2 loop_packet no 3; dateTime 1450014636

START 'MODIFIED' DRIVER

Dec 13 11:07:03 pi2 vant[24701]: engine: Initializing engine

Dec 13 11:07:04 pi2 vant[24701]: vantage: Opened up serial port /dev/ttyUSB0; baud 19200; timeout 4.00

Dec 13 11:07:04 pi2 vant[24701]: vantage: hardware type is 16

Dec 13 11:07:04 pi2 vant[24701]: engine: Loading service weewx.engine.StdTimeSynch

Dec 13 11:07:04 pi2 vant[24701]: engine: Finished loading service weewx.engine.StdTimeSynch

Dec 13 11:07:04 pi2 vant[24701]: engine: Loading service weewx.engine.StdConvert

Dec 13 11:07:04 pi2 vant[24701]: engine: Finished loading service weewx.engine.StdConvert

Dec 13 11:07:04 pi2 vant[24701]: engine: Loading service weewx.engine.StdCalibrate

Dec 13 11:07:04 pi2 vant[24701]: engine: Finished loading service weewx.engine.StdCalibrate

Dec 13 11:07:04 pi2 vant[24701]: engine: Loading service weewx.engine.StdQC

Dec 13 11:07:04 pi2 vant[24701]: engine: Finished loading service weewx.engine.StdQC

Dec 13 11:07:04 pi2 vant[24701]: engine: Loading service weewx.wxservices.StdWXCalculate

Dec 13 11:07:04 pi2 vant[24701]: engine: Finished loading service weewx.wxservices.StdWXCalculate

Dec 13 11:07:04 pi2 vant[24701]: engine: Loading service user.cmon.ComputerMonitor

Dec 13 11:07:04 pi2 vant[24701]: engine: Finished loading service user.cmon.ComputerMonitor

Dec 13 11:07:04 pi2 vant[24701]: engine: Loading service user.weewxwd3.WdWXCalculate

Dec 13 11:07:04 pi2 vant[24701]: engine: Finished loading service user.weewxwd3.WdWXCalculate

Dec 13 11:07:04 pi2 vant[24701]: engine: Loading service weewx.engine.StdArchive

Dec 13 11:07:04 pi2 vant[24701]: engine: Use LOOP data in hi/low calculations: 1

Dec 13 11:07:08 pi2 vant[24701]: engine: Finished loading service weewx.engine.StdArchive

Dec 13 11:07:08 pi2 vant[24701]: engine: Loading service user.forecast.WUForecast

Dec 13 11:07:08 pi2 vant[24701]: forecast: MainThread: WU: last forecast issued 2015-12-13 09:25:21 SRT (1450009521), requested 2015-12-13 09:25:21 SRT (1450009521)

Dec 13 11:07:08 pi2 vant[24701]: engine: Finished loading service user.forecast.WUForecast

Dec 13 11:07:08 pi2 vant[24701]: engine: Loading service user.retain.RetainLoopValues

Dec 13 11:07:08 pi2 vant[24701]: engine: Finished loading service user.retain.RetainLoopValues

Dec 13 11:07:08 pi2 vant[24701]: engine: Loading service user.weewxwd3.WdArchive

Dec 13 11:07:08 pi2 vant[24701]: engine: Finished loading service user.weewxwd3.WdArchive

Dec 13 11:07:08 pi2 vant[24701]: engine: Loading service weewx.restx.StdStationRegistry

Dec 13 11:07:08 pi2 vant[24701]: engine: Finished loading service weewx.restx.StdStationRegistry

Dec 13 11:07:08 pi2 vant[24701]: engine: Loading service weewx.restx.StdWOW

Dec 13 11:07:08 pi2 vant[24701]: engine: Finished loading service weewx.restx.StdWOW

Dec 13 11:07:08 pi2 vant[24701]: engine: Loading service weewx.restx.StdWunderground

Dec 13 11:07:08 pi2 vant[24701]: engine: Finished loading service weewx.restx.StdWunderground

Dec 13 11:07:08 pi2 vant[24701]: engine: Loading service weewx.restx.StdPWSweather

Dec 13 11:07:08 pi2 vant[24701]: engine: Finished loading service weewx.restx.StdPWSweather

Dec 13 11:07:08 pi2 vant[24701]: engine: Loading service weewx.restx.StdCWOP

Dec 13 11:07:08 pi2 vant[24701]: engine: Finished loading service weewx.restx.StdCWOP

Dec 13 11:07:08 pi2 vant[24701]: engine: Loading service user.sync.SyncService

Dec 13 11:07:08 pi2 vant[24701]: sync archive: requesting latest dateTime from http://www.lucdesign.nl/web/meso/data.php

Dec 13 11:07:09 pi2 vant[24701]: sync archive: 0 records to sync since last synced record with dateTime: 2015-12-13 11:05:00 SRT (1450015500)

Dec 13 11:07:09 pi2 vant[24701]: sync archive: waiting for new records

Dec 13 11:07:09 pi2 vant[24701]: sync archive: will sync archive records

Dec 13 11:07:09 pi2 vant[24701]: sync raw: waiting for new records

Dec 13 11:07:09 pi2 vant[24701]: sync raw: will sync raw records

Dec 13 11:07:09 pi2 vant[24701]: engine: Finished loading service user.sync.SyncService

Dec 13 11:07:09 pi2 vant[24701]: engine: Loading service weewx.engine.StdPrint

Dec 13 11:07:09 pi2 vant[24701]: engine: Finished loading service weewx.engine.StdPrint

Dec 13 11:07:09 pi2 vant[24701]: engine: Loading service weewx.engine.StdReport

Dec 13 11:07:09 pi2 vant[24701]: engine: Finished loading service weewx.engine.StdReport

Dec 13 11:07:09 pi2 vant[24701]: vantage: successfully woke up console gently

Dec 13 11:07:09 pi2 vant[24701]: vantage: Getting all archive packets

Dec 13 11:07:09 pi2 vant[24701]: vantage: successfully woke up console gently

START OF 'MODIFIED' CATCHUP

Dec 13 11:07:09 pi2 vant[24701]: vantage: Retrieving 513 page(s); starting index= 2

Dec 13 11:07:09 pi2 vant[24701]: vantage: number_of_wind_samples: 108; rxCheckPercent: 94.5

Dec 13 11:07:09 pi2 vant[24701]: vantage: received record in page 0; index 2; dateTime 2015-12-04 13:35:00 SRT (1449246900)

Dec 13 11:07:09 pi2 vant[24701]: vantage: yield3 archive record no 1; time_outs: 0

Dec 13 11:07:09 pi2 vant[24701]: cmon: Skipping record: time difference 768729 too big

Dec 13 11:07:09 pi2 vant[24701]: forecast: MainThread: WU: not yet time to do the forecast

Dec 13 11:07:09 pi2 vant[24701]: sync archive: put record in queue 2015-12-04 13:35:00 SRT (1449246900)

Dec 13 11:07:09 pi2 vant[24701]: restx: CWOP: record 2015-12-04 13:35:00 SRT (1449246900) is stale (768729 > 1800).

Dec 13 11:07:09 pi2 vant[24701]: sync archive: get record 2015-12-04 13:35:00 SRT (1449246900); last synced 2015-12-13 11:05:00 SRT (1450015500)

Dec 13 11:07:09 pi2 vant[24701]: sync archive: skip already synced record 2015-12-04 13:35:00 SRT (1449246900)

Dec 13 11:07:09 pi2 vant[24701]: vantage: number_of_wind_samples: 111; rxCheckPercent: 97.125

Dec 13 11:07:09 pi2 vant[24701]: vantage: received record in page 0; index 3; dateTime 2015-12-04 13:40:00 SRT (1449247200)

Dec 13 11:07:09 pi2 vant[24701]: vantage: yield3 archive record no 2; time_outs: 0

Dec 13 11:07:09 pi2 vant[24701]: cmon: Skipping record: time difference 768430 too big

Dec 13 11:07:09 pi2 vant[24701]: forecast: MainThread: WU: not yet time to do the forecast

Dec 13 11:07:09 pi2 vant[24701]: sync archive: put record in queue 2015-12-04 13:40:00 SRT (1449247200)

Dec 13 11:07:09 pi2 vant[24701]: restx: CWOP: record 2015-12-04 13:40:00 SRT (1449247200) is stale (768429 > 1800).

Dec 13 11:07:09 pi2 vant[24701]: vantage: number_of_wind_samples: 110; rxCheckPercent: 96.25

Dec 13 11:07:09 pi2 vant[24701]: vantage: received record in page 0; index 4; dateTime 2015-12-04 13:45:00 SRT (1449247500)

Dec 13 11:07:09 pi2 vant[24701]: vantage: yield3 archive record no 3; time_outs: 0

Dec 13 11:07:09 pi2 vant[24701]: sync archive: get record 2015-12-04 13:40:00 SRT (1449247200); last synced 2015-12-13 11:05:00 SRT (1450015500)

Dec 13 11:07:09 pi2 vant[24701]: sync archive: skip already synced record 2015-12-04 13:40:00 SRT (1449247200)

Dec 13 11:07:09 pi2 vant[24701]: cmon: Skipping record: time difference 768130 too big

Dec 13 11:07:09 pi2 vant[24701]: forecast: MainThread: WU: not yet time to do the forecast

Dec 13 11:07:09 pi2 vant[24701]: sync archive: put record in queue 2015-12-04 13:45:00 SRT (1449247500)

Dec 13 11:07:09 pi2 vant[24701]: sync archive: get record 2015-12-04 13:45:00 SRT (1449247500); last synced 2015-12-13 11:05:00 SRT (1450015500)

Dec 13 11:07:09 pi2 vant[24701]: restx: CWOP: record 2015-12-04 13:45:00 SRT (1449247500) is stale (768129 > 1800).

Dec 13 11:07:09 pi2 vant[24701]: sync archive: skip already synced record 2015-12-04 13:45:00 SRT (1449247500)

Dec 13 11:07:09 pi2 vant[24701]: vantage: number_of_wind_samples: 112; rxCheckPercent: 98.0

Dec 13 11:07:09 pi2 vant[24701]: vantage: received record in page 1; index 0; dateTime 2015-12-04 13:50:00 SRT (1449247800)

Dec 13 11:07:09 pi2 vant[24701]: vantage: yield3 archive record no 4; time_outs: 0

Dec 13 11:07:10 pi2 vant[24701]: cmon: Skipping record: time difference 767830 too big

Dec 13 11:07:10 pi2 vant[24701]: forecast: MainThread: WU: not yet time to do the forecast

Dec 13 11:07:10 pi2 vant[24701]: sync archive: put record in queue 2015-12-04 13:50:00 SRT (1449247800)

Dec 13 11:07:10 pi2 vant[24701]: restx: CWOP: record 2015-12-04 13:50:00 SRT (1449247800) is stale (767830 > 1800).

Dec 13 11:07:10 pi2 vant[24701]: sync archive: get record 2015-12-04 13:50:00 SRT (1449247800); last synced 2015-12-13 11:05:00 SRT (1450015500)

Dec 13 11:07:10 pi2 vant[24701]: vantage: number_of_wind_samples: 115; rxCheckPercent: 100.0

Dec 13 11:07:10 pi2 vant[24701]: sync archive: skip already synced record 2015-12-04 13:50:00 SRT (1449247800)

Dec 13 11:07:10 pi2 vant[24701]: vantage: received record in page 1; index 1; dateTime 2015-12-04 13:55:00 SRT (1449248100)

Dec 13 11:07:10 pi2 vant[24701]: vantage: yield3 archive record no 5; time_outs: 0

...

AFTER EACH 50TH RECORD WAIT 2.5 S

Dec 13 11:07:21 pi2 vant[24701]: vantage: yield3 archive record no 50; time_outs: 0

Dec 13 11:07:21 pi2 vant[24701]: cmon: Skipping record: time difference 754041 too big

Dec 13 11:07:21 pi2 vant[24701]: forecast: MainThread: WU: not yet time to do the forecast

Dec 13 11:07:21 pi2 vant[24701]: restx: StationRegistry: wait interval (14700 < 604800) has not passed for record 2015-12-04 17:40:00 SRT (1449261600)

Dec 13 11:07:21 pi2 vant[24701]: restx: CWOP: record 2015-12-04 17:40:00 SRT (1449261600) is stale (754041 > 1800).

Dec 13 11:07:21 pi2 vant[24701]: sync archive: get record 2015-12-04 17:40:00 SRT (1449261600); last synced 2015-12-13 11:05:00 SRT (1450015500)

Dec 13 11:07:21 pi2 vant[24701]: sync archive: skip already synced record 2015-12-04 17:40:00 SRT (1449261600)

Dec 13 11:07:21 pi2 vant[24701]: sync archive: put record in queue 2015-12-04 17:40:00 SRT (1449261600)

Dec 13 11:07:21 pi2 vant[24701]: vantage: restart DMPAFT after 50 read records

Dec 13 11:07:24 pi2 vant[24701]: vantage: Getting archive packets since 2015-12-04 17:40:00 SRT (1449261600)

Dec 13 11:07:24 pi2 vant[24701]: vantage: successfully woke up console gently

Dec 13 11:07:26 pi2 vant[24701]: vantage: Retrieving 503 page(s); starting index= 2

Dec 13 11:07:26 pi2 vant[24701]: vantage: number_of_wind_samples: 109; rxCheckPercent: 95.375

Dec 13 11:07:26 pi2 vant[24701]: vantage: received record in page 0; index 2; dateTime 2015-12-04 17:45:00 SRT (1449261900)

Dec 13 11:07:26 pi2 vant[24701]: vantage: yield3 archive record no 51; time_outs: 0

...

Dec 13 11:21:16 pi2 vant[24701]: vantage: yield3 archive record no 2561; time_outs: 0

Dec 13 11:21:16 pi2 vant[24701]: cmon: Skipping record: time difference 677 too big

Dec 13 11:21:16 pi2 vant[24701]: forecast: MainThread: WU: not yet time to do the forecast

Dec 13 11:21:16 pi2 vant[24701]: restx: CWOP: wait interval (300 < 600) has not passed for record 2015-12-13 11:00:00 SRT (1450015200)

Dec 13 11:21:16 pi2 vant[24701]: restx: CWOP: Connected to server cwop.aprs.net:14580

Dec 13 11:21:17 pi2 vant[24701]: sync archive: put record in queue 2015-12-13 11:10:00 SRT (1450015800)

Dec 13 11:21:17 pi2 vant[24701]: restx: StationRegistry: wait interval (164100 < 604800) has not passed for record 2015-12-13 11:10:00 SRT (1450015800)

Dec 13 11:21:17 pi2 vant[24701]: vantage: number_of_wind_samples: 16; rxCheckPercent: 14.0

Dec 13 11:21:17 pi2 vant[24701]: restx: CWOP: wait interval (300 < 600) has not passed for record 2015-12-13 11:10:00 SRT (1450015800)

Dec 13 11:21:17 pi2 vant[24701]: sync archive: get record 2015-12-13 11:10:00 SRT (1450015800); last synced 2015-12-13 11:05:00 SRT (1450015500)

Dec 13 11:21:17 pi2 vant[24701]: sync archive: send record 2015-12-13 11:10:00 SRT (1450015800)

Dec 13 11:21:17 pi2 vant[24701]: vantage: received record in page 2; index 3; dateTime 2015-12-13 11:15:00 SRT (1450016100)

Dec 13 11:21:17 pi2 vant[24701]: vantage: yield3 archive record no 2562; time_outs: 0

Dec 13 11:21:17 pi2 vant[24701]: cmon: Skipping record: time difference 377 too big

Dec 13 11:21:17 pi2 vant[24701]: forecast: MainThread: WU: not yet time to do the forecast

Dec 13 11:21:17 pi2 vant[24701]: restx: StationRegistry: wait interval (164400 < 604800) has not passed for record 2015-12-13 11:15:00 SRT (1450016100)

Dec 13 11:21:17 pi2 vant[24701]: sync archive: put record in queue 2015-12-13 11:15:00 SRT (1450016100)

Dec 13 11:21:17 pi2 vant[24701]: vantage: number_of_wind_samples: 18; rxCheckPercent: 15.75

Dec 13 11:21:17 pi2 vant[24701]: vantage: received record in page 2; index 4; dateTime 2015-12-13 11:20:00 SRT (1450016400)

Dec 13 11:21:17 pi2 vant[24701]: vantage: yield3 archive record no 2563; time_outs: 0

Dec 13 11:21:17 pi2 vant[24701]: restx: CWOP: Connected to server cwop.aprs.net:14580

Dec 13 11:21:17 pi2 vant[24701]: forecast: MainThread: WU: not yet time to do the forecast

Dec 13 11:21:17 pi2 vant[24701]: restx: StationRegistry: wait interval (164700 < 604800) has not passed for record 2015-12-13 11:20:00 SRT (1450016400)

Dec 13 11:21:17 pi2 vant[24701]: sync archive: put record in queue 2015-12-13 11:20:00 SRT (1450016400)

Dec 13 11:21:17 pi2 vant[24701]: vantage: DMPAFT complete: no more pages to read

END OF 'MODIFIED' CATCHUP

Dec 13 11:21:17 pi2 vant[24701]: vantage: successfully woke up console gently

Dec 13 11:21:18 pi2 vant[24701]: restx: CWOP: wait interval (300 < 600) has not passed for record 2015-12-13 11:20:00 SRT (1450016400)

Dec 13 11:21:18 pi2 vant[24701]: vantage: Requesting 200 LOOP packets.

Dec 13 11:21:18 pi2 vant[24701]: vantage: successfully woke up console gently

Dec 13 11:21:18 pi2 vant[24701]: sync archive: get record 2015-12-13 11:15:00 SRT (1450016100); last synced 2015-12-13 11:05:00 SRT (1450015500)

Dec 13 11:21:18 pi2 vant[24701]: sync archive: send record 2015-12-13 11:15:00 SRT (1450016100)

Dec 13 11:21:18 pi2 vant[24701]: vantage: yield2 loop_packet no 1; dateTime 1450016478

Dec 13 11:21:18 pi2 vant[24701]: sync raw: send record 2015-12-13 11:21:18 SRT (1450016478)

Dec 13 11:21:18 pi2 vant[24701]: vantage: yield2 loop_packet no 2; dateTime 1450016479

Dec 13 11:21:19 pi2 vant[24701]: sync archive: get record 2015-12-13 11:20:00 SRT (1450016400); last synced 2015-12-13 11:05:00 SRT (1450015500)

Dec 13 11:21:19 pi2 vant[24701]: sync archive: send record 2015-12-13 11:20:00 SRT (1450016400)

Dec 13 11:21:19 pi2 vant[24701]: sync raw: send record 2015-12-13 11:21:19 SRT (1450016479)

Dec 13 11:21:20 pi2 vant[24701]: vantage: yield2 loop_packet no 3; dateTime 1450016481

[Kenneth Baker]

Hi Luc,

I have seen something similar with one of my weewx installations.  I'm running 3.4.0.  Vantage Pro 2, with a serial data logger running console firmware 1.60 from Dec 12 2006.  It is connected to my beaglebone black with a serial<->usb adapter. 

The computer running weewx had been offline for ~2 days (I reinstalled the system but saved my weewx database), but the logger had been online.  It had about 2 days of archive data (archived every 5 minutes) to catch up on.

Weewx would download and archive 5 records (1 DMPAFT page) and then fail with a "vantage: Unable to pass CRC16 check while getting data". This would fall back to the engine "engine: Caught WeeWxIOError: Unable to pass CRC16 check while getting data Feb 23 11:29:01 beagle weewx[2032]: **** Waiting 60 seconds then retrying...". Upon retry it would download 5 more records, fail and the cycle would continue. Note: the very first time it only reads 4 records out of the DMPAFT page.

I instrumented vantage.py and noticed that the actual error being thrown was WeeWxIOError of "Expected to read 267 chars; got 0 instead". Which is being ignored inside get_data_with_crc16() which is called inside genArchiveRecords().

So every time through the cycle my data logger would immediately return one page which would be processed, and subsequent reads (even when a retry would be requested) would return zero.

I did not get to try out your changes as I found them after my system finally caught up. But I think your direction to have zero reads in this scenario fall back to retry the DMPAFT make a lot of sense.

In the short term it might make sense to change vantage.py to differentiate between get_data_with_crc16() failing due to CRC errors and errors in reading the proper number of bytes...

-- Ken

(attached are two files during the period prior to my instrumentation. one is the full log file weewx.log; the other weewx_filtered.log has a bunch of messages filtered out one can more readily view the failure).

[Thomas Keffer]

Thanks for your detailed analysis, Ken!

You have a very old firmware version, which tickled a memory in my brain. If you look at the Davis firmware update page, you'll see they fixed a communications problem in 2010 (firmware v1.82). Their explanation:

Fixed a communication problem where the console output an extra "\n\r" if it received binary data containing a 10 (x0A) or a 13 (x0D). Note: This issue only affects third-party software developers

It's quite possible that the encoded date in the DMPAFT command contained a 0x0A or 0x0D, triggering the unexpected \n\r.

-tk

[Luc Heijst]

Hi Ken,

My modified vantage driver sees the difference between crc errors and number of received bytes other than expected. In the latter retries don't help so the DMPAFT call is restarted.

To let the sensors communicate with the console during the catchup period, after each 50th received archive record a wait of 2.5 seconds is invoked.

You can try my driver youself. Copy file vantage_mod4_debug.py to the user directory.

In the Vantage section of weewx.conf change line:

    driver = weewx.drivers.vantage

into:

    driver = user.vantage_mod4_debug

You can do a test with retrieving all historical records as follows:

• Stop weewx
  
• temporary change line:
  

    [[archive_sqlite]]

        database_type = SQLite

        database_name = weewx.sdb

into

    [[archive_sqlite]]

        database_type = SQLite

        database_name = weewx_test.sdb

• Start weewx
  Now a new database weewx_test.sdb is created ans all Vantage historical records are read

To go back to the original database:

• Stop weewx
  
• change line:
  

    [[archive_sqlite]]

        database_type = SQLite

        database_name = weewx_test.sdb

back to the original content:

    [[archive_sqlite]]

        database_type = SQLite

        database_name = weewx.sdb

• Start weewx
  Now weewx continues with the original database and starts with a catchup of the missed historical records during the test.

Succes!

Luc

[Luc Heijst]

Tom,

The symptoms Kenneth described in his last mail are exactly the same as I experienced with the Vantage driver of last November (is the current version if I'm correct). 

For those reasons I started this thread (and modified the driver).

The wake-up fix is one part I've changed, but the "Expected to read 267 chars; got 0 instead" error I fixed too (also for loop records with zero bytes received) .

Luc

[Thomas Keffer]

Luc, out of curiosity, what firmware version are you using in your VP2?

-tk

--

[Luc Heijst]

CONSOLE TYPE: VantagePro2

CONSOLE FIRMWARE:

Date: Jun 3 2013

Version: 3.15

[Thomas Keffer]

Pretty recent. Thanks.

-tk

--

[fraban]

Hi all

I have had similiar problems here with the DAVIS Logger USB and  the IP-WeatherLink from Davis. 

The USB logger was running on the Vantage PRO 2 Console and I observed every day one or two, sometimes 3 peeks with rxCheckPercentages going down to 10 or less, then back to nearly 100. With Envoy and the DAVIS IP-Logger same peeks, but not at the same time (Funny). Both Vantage Pro2 Console and envoy was receiving the same ISS station. With envoy and IP-Davis logger I recognized peeks down to 0% - then no <ACK> and this causes the weewxd on raspberry hanging up itself. So I have to restart weewx on the rasp manually, this happens daily. 

I tried several settings of the transmitter 1,2 ... 7 ... always the same. 

Same loggers and Consoles I tried with now with a Davis Vantage VUE. I observed the same. Twice a day I found rxCheckPercentages lower then 10 with the Console and USB-Logger and with envoy together with the IP-Logger sometimes 0%. Always when going to 0% weewx stopped not getting <ACK>. This only happens withe the DAVIS IP-Logger.  

Both vantage Pro2 and VUE shows the same scenario with the loggers. 

I came to the conclusion that something in combination Console <-> Logger ( USB or IP) must be responsible for this sparkles.  

Actually I can see - Luc knows, we are running tests with Meteostick. Here I have no such problems from the same stations - all running well since a few days now. IMHO the stations outside are OK, the problem looks like to be with the combination -Console<->Logger or envoy<->Logger. 

Now next try is a VANTAGE VUE Console with VUE Station outside  the DAVIS IP-Logger and weewx. Testing will start this weekend. I´ll keep you updated. 

- Luc, our actual meteostick driver (0.5)  seems to be good. Results can be confirmed with meteo-tower. 

-frank 

[Luc Heijst]

Frank,

The frequency of the received packets -in special those received from the station which has the anemometer connected- depend on the transmitter-ID of that station, see table.

Transmitter ID Loop time (s)

1               2,5625

2               2,625

3               2,6875

4               2,75

5               2,8125

6               2,875

7               2,9375

8               3

Weewx will calculate the right rxCheckPercent with the information of the parameter  below in the vantage section of weewx.conf

    # The id of your ISS station with anemometer wired (usually 1)

    # or -if present- the id of the Anemometer Transmitter Kit

    iss_id = 2

In my situation I have the wind meter connected to a Anemometer Transmission Kit on channel 2.

There are actually two rxCheckPercentages.

1. Calculated on base of the received value of number_of_wind_samples in the vantage archive record
   This is the one the default vantage driver uses.
2. Calculated on base of the number of received loop packets in my modified vantage driver.
   This percentage is much higher When the same formula is used it will be most of the time 100% (or more!).
   This percentage is only reported as debug message by driver vantage_mod4_debug.py. 

Each console or envoy hs its own counter for received wind samples. A communication problem between the console and the ISS -which will result in a lower rxCheckpercent- doesn't imply the envoy has to have the same communication problem. Probably the strengths of the received signals are not the same same on both devices (at the same time). That explains why the dips in reception don't match.
I think the main cause of the reception go to zero is that weewx is trying to read the archive records from the console or envoy and keeping that channel busy for a while due to a problem. During that period the ISS can't talk with the console or envoy.

A problem what more than once happened on my station -depending on the place where my console was situated- is a call to read the (5) archive records timed out because zero bytes were received. I experienced that epeating thi call (over and over again) always has the same result, thus time out.

The standard vantage driver would in this case pause 'timeout' * 'max_tries' seconds before giving up, resulting in giving the wrong error message "CRC error" (instead of "zero bytes treceived" and stopping itself to be started later.

During the 'timeout' * 'max_tries' period the driver keeps the channel occupied thus preventing the console talking to the ISS with as result lower or none received wind samples.

Now my modified driver...

It recognizes that less than expected number of bytes were received and gives that information back to the routine(s) they call. On two places I changed the coding:

1. Routine DMPAFT
   This routine reads all (not yet present in weewx) archive records from the USB or IP-datalogger.
   When a time-out occurred (in my case set to 4 seconds), the DMPAFT call is ended in a correct way and restarted again immediately.
   This results in a continuation of the archive read after only one time-out and in 99,99% of the cases no time-out follows direct after.
   When all 2000 or so packets are to be read, utmost 15 time-outs were seen.
   
   
2. Routine LOOP 200
   This routine requests 200 loop records and then waits for them coming in.
   Same story here: when a time-out occurred the LOOP call is ended and right again requested again.

This new approach has also a disadvantage. Football trainer Johan Cruyff used to say: "elk voordeel HEB zijn nadeel" (free translated: each advantage HAVE it's disadvantage).

When all 2000+ archive records are to be retrieved from the data logger the communication would last several minutes (20 ore more I thought) and during that period there is no communication possible with the ISS, resulting in a real data-gap because this data is not on the datalogger too. 

No more crashes mean: no more time for the console to talk to the ISS during thise 'pauses' between stop and start weewx.

For that reason my drivver stops the DMPAFT call after each received 50th archive package, waits 2.5 seconds to let the console or envoy talk with the station(s) and then restarts DMPAFT to read the next 50 archive records.

Frank, I will contact you by mail about your situation and trying to get a solution.

Luc

[Luc Heijst]

Frank,

I forgot to mention one more thing...

Many times when the original vantage driver was started (due to time-out problems described in my last mail or other reasons), the console wasn't be able to wake-up the console.
In that situation the driver stopped itself (without starting again) with a message 'no <ACK> received'.

I have an automatic start of weewx when my Raspberry PI boots, but noticed many times a stopped weewx instance with the vantage driver due to this problem. My other two weewx instances for my ws28xx and kklimalogg drivers kept active.

This problem is also solved in my driver and Tom included this solution in the official Vantage driver (not yet present in weewx 3.4.0).

Luc 

On Friday, 26 February 2016 07:10:15 UTC-3, fraban wrote:

[Frank Bandle]

Luc,

thanks for explanation. But exactly the hangup problems of the weewx with DAVIS Systems was the reason going forward with Meteostick. And as I see it looks working well. 

-frank

-- 
Frank Bandle
Sent with Airmail

--
You received this message because you are subscribed to a topic in the Google Groups "weewx-user" group.
To unsubscribe from this topic, visit https://groups.google.com/d/topic/weewx-user/nW-vZsXIeJk/unsubscribe.
To unsubscribe from this group and all its topics, send an email to weewx-user+...@googlegroups.com.

[Luc Heijst]

Frank,

The big advantage of the console or envoy with a data logger is... the data logger!

When you experiment a lot like me with weewx and the computer on which weewx runs -in my case a Raspberry PI- you would loss a lot of weather data of the vantage station during these periods when you had no data logger.

I had problems with a corrupted MySQL database on my USB stick after a lightning strike in the neigbourhood, problems with a very slow USB stick I used as replacement, problems with setting up myRaspberry PI with the latest raspbian version and MariaDB and so on.

If this was not enough allready, once in two month or so the power at my home is disrupted for a period of 2 to 5 hours. 

Where would I be If I hadn't battery driven devices with local memory like my KlimaLogg Pro (51.200 records), TFA Opus (1794 records) and vantage Pro2 with USB datalogger (2560 records).

BTW. I was involved for all three drivers in improving the communication. Especially the combination of the wx28xx and klimalogg drivers because they both use the same make and model of the USB transceiver resulting in receiving each others signals in both drivers!

Luc

[Frank Bandle]

Luc,

yes I know the advantages of the data logger. We are here doing experiments with battery-puffered raspberrys - approx 5V battery-packages and solar powered ones.  This will provide us from power-problems and we can use the stations in the outback. 

All things are in early beta status, but it looks good. So we have both - Data loggers in different kinds from DAVIS and 3rd Party - Meteostick ….    

-frank

-- 
Frank Bandle
Sent with Airmail

--

[Luc Heijst]

This would be a great feature! What do you (plan to) use for internet comunication between the RPI and the 'outside world'?

Luc

[Frank Bandle]

For live data we use - UMTS / LTE sticks.

long time recording is done by the raspberries with big SD Card and USB Sticks . Power consumption is low - nor problems with it.

-frank

-- 
Frank Bandle
Sent with Airmail

--

[Luc Heijst]

And, uh, the regular database backups? :-)

Luc

[Frank Bandle]

A simple mysqldump by cron …  hourly ….

quick and fast

and a parallel php program writing the data to a 2nd DB 

totally simple - all with Linux basics 

-frank

-- 
Frank Bandle
Sent with Airmail

[Luc Heijst]

To all,

Frank was so kind to gave access to his Rapberry PI where an instance of the vantage driver runs for a Davis Vue with IP data logger on a Davis Envoy.

This gave me the opportunity to test the behaviour of my modified vantage driver for an ip data logger.

Today I made a big step forwards in avoiding the dreadfull 'no ACK received' messages. I need some more time to know for sure.

Luc

[Luc Heijst]

To all,

The behaviour of weewx on errors is different in the initial stage,

When a WeeWxIOError error is detected in the initial stage, weewx exists without restarting.

When in a later stage this error is detected the driver will exit, but will restart after one minute.

To overcome the driver exits without restarting, you have to specify option '--loop-on-init' on the weewxd command line. 

Personally I like this setting be part of the weewx.conf file, but I'm not sure if this is technically possible.

Luc

[mwall]

On Wednesday, March 9, 2016 at 5:53:38 PM UTC-5, Luc Heijst wrote:

Personally I like this setting be part of the weewx.conf file, but I'm not sure if this is technically possible.

as of 61ee948..c92bfe6, loop_on_init can be specified in weewx.conf at the root level (same location as debug).

m

[Luc Heijst]

Matthew,

61ee948..c92bfe6: I dialed this number but nobody picked up the phone!  :-) You mean: the next release?

Luc

[vince]

On Thursday, March 10, 2016 at 6:52:50 AM UTC-8, Luc Heijst wrote:

61ee948..c92bfe6: I dialed this number but nobody picked up the phone!  :-) You mean: the next release?

Huh ? Can't tell if you're serious or not.
If you choose to go get the files from that change, you can do it now.

Change is at https://github.com/weewx/weewx/commit/c92bfe6b48c168861a7b220f786a6236fb4c0291

Otherwise yes of course, whenever there's a next release it'll come in there...
 

[L.J.M. Heijst]

Vince,

Your answer suggests that I should understand Matthew's message 'number' and should know what to do with it. But I am THAT STUPID: I don't !

It's up to you to make up if i'm serious or not.

Most of the time a got a commit link which I could follow.
Now I got two sets of alphabetic characters seperated with two dots. I (seriously) had no idea what I could do with these numbers.
You are refering to a commit with a very long string which seem to have no correlation to the given numbers.

So forgive me not understanding how it works.

Cheers, Luc 

--  You received this message because you are subscribed to a topic in the Google Groups "weewx-user" group. To unsubscribe from this topic, visit

https://groups.google.com/d/topic/weewx-user/nW-vZsXIeJk/unsubscribe.

To unsubscribe from this group and all its topics, send an email to

weewx-user+...@googlegroups.com. For more options, visit https://groups.google.com/d/optout.

Dit e-mailbericht is verzonden vanaf een virusvrije computer die wordt beschermd door Avast. www.avast.com

[Andrew Milner]

Don't worry Luc - I didn't understand Matthew's reference either!!

Something in the back of my memory seems to recall that this was included in one of Tom's responses recently, but I don't recall which version it was included in.

Andrew

[L.J.M. Heijst]

Andrew,

Do not worry: I don't worry that fast!

We're both getting old, I think. Our memories let us down! 

I was not interested in applying the referenced patch right now. I rather try to improve my code in such a way the patch is not needed...
But when needed, it's nice to know that it can be handled in weewx.conf instead of a parameter in the start command file of weewx.

Luc

[vince]

On Thursday, March 10, 2016 at 10:00:25 AM UTC-8, Luc Heijst wrote:

Your answer suggests that I should understand Matthew's message 'number' and should know what to do with it. But I am THAT STUPID: I don't !

Not in the least.
And I didn't use the word 'stupid'.
 

It's up to you to make up if i'm serious or not.

FWIW, it's up to you to make sure people know if you're serious or not.
I certainly couldn't figure it out from your wording.
 

Most of the time a got a commit link which I could follow.
Now I got two sets of alphabetic characters seperated with two dots. I (seriously) had no idea what I could do with these numbers.
You are refering to a commit with a very long string which seem to have no correlation to the given numbers.

Fair enough, I hope you'd said it originally that clearly (which I would have agreed with).

Basically I looked up the two numbers in the github repo and saw a recent change with the driver you mentioned, so I sent you the link to the patch.

Typically when you see 61ee948..c92bfe6 you can interpret that as being either 'from change X to change Y'.   The bug existed in 61ee948 and he fixed it in c92bf36 if you look through the committed changes at https://github.com/weewx/weewx/commits/master for yesterday.

That said, it would probably have been less stressful if Matthew's answer had been worded differently, perhaps the lines of "fixed in change nnnnnn or later in github if you want it now, and in the content for the next update of weewx whenever that happens if you want to wait for an official release", but so it goes.
 

So forgive me not understanding how it works.

Not understanding is fine.
Not remembering is fine.
Being decaffeinated is fine.

But....

If you're reporting something, please be clearer.
If you're asking something, please be clearer.
It'll help.  Really.

[Luc Heijst]

Vince,

I thought the symbol :-) is general accepted as "I 'm laughing, don't take my words too serious" but of course I can be wrong (I'm almost 65 years old and don't understand the nowadays talk).

Stupid is the word I gave to myself, but I understood your message as 'why don't you understand how it works, XXXXXX? '  

As an autist I know that not everyone understands my type of humor. It's like saying: "If you don't come to my funeral, I won't go to yours too!".

And thanks, Vince, for your explanation. I think I would have found it myself when I wanted to. (I'm learning Github and try to publish something myself in the near future).

So sorry if I set you at work. It was not my intention.

Luc

[Pete Helgren]

Luc,

I am not sure where in this lengthy thread to post this but I want to thank you for the patch.  Weewx would stop reporting and have to be restarted about every other day since I installed it in January.  Since I installed the patch last week Weewx has run without a hitch.

Much appreciated!

Pete

[Luc Heijst]

Pete,

You are welcome!

I'm currently testing the modified vantage driver for IP data loggers. The results are promising...

Luc 

[Pete Helgren]

Hmmm.  I AM using the IP data logger and the Vantage driver.  Was the patch specific to the USB version? (if so, I missed it....)

I am seeing the "gentle wake up successful" messages in the log.  I just assumed that the patch was "generic" (knowing next to nothing about the internals of weewx).....

In any case, even if it is dumb luck, I'll take it.  It has been nice not to get "offline" emails from WeatherUnderground......

[Luc Heijst]

Hi Pete,

The patch you mention is generic for both types of data loggers.

I'm currently working on time outs that occur in the IP section of the driver during a catchup of many historical records.

With the original driver weewx is stopped after a time out and continues after 2 minutes. In the modified driver we are 'up and running again' within a few seconds...

Luc

[Luc Heijst]

At last I understand how all puzzle pieces come together!

I studied the syslogs of the vantage driver reading from an IP data logger more carefully and discovered the cause of the time outs in reading historical records.

To explain, I will globally describe the used protocol.

The vantage driver starts with telling the console logic it wants to get one or more records with historical data starting from a given date and time.

When everything is ok the driver will answer back the number of pages it will send. Each page contain the data of 5 historical records.

When the driver sends an ACK character, the console logic will send the first page containing 5 records.

When this page is handled ok by the weewx driver it will send another ACK to receive the next page with data until all pages are read.

The vantage driver has to do the following to handle each of the five records within the page:

• read a record within the page and check the data with the crc16 mechanism.
• parse the data (translate it to weewx usable data format)
• check the end condition
• if not ready yet, yield this record to the archive program
• the archive program will store a record in the weewx database and also update the record in the daily summary database

When all is done and OK, the vantage driver will send an ACK character to tell the console logic it wants to get the next page.

A typical system will read and handle these 5 records in one or two seconds.

It appears the vantage console logic allow handling a page for a maximum period of 10 seconds. After that period the console logic will end the DMPAFT protocol (learned from the syslog data).

When the ACK is sent after a period of 10 seconds, the console no longer responds, resulting in a time out on the read section of the vantage driver.

The current vantage driver (in weewx 3.0.5) will now repeat the complete DMPAFT logic after a time out is detected, so the data collection is up and running within a few seconds.

Thanks to Frank Bandle who let me test on his RPI with an IP data logger and also thanks to Tom Keffer who had the patience with my 'endless nagging' and transformed my bad coding into this new version of the driver.

Luc

[Luc Heijst]

Just thinking...

When knowing this, we can avoid these console time outs by checking in the vantage driver how long it took to process a page. 

When this period is more than 10 seconds, don't send a reply to the console, but repeat the complete DMPAFT sequence including the wake up of the console.

What do you thinkTom?

Luc

[Thomas Keffer]

The present driver is robust, covers 99% of the use cases, and is reasonably simple.

The "1%" left is systems where:

• Weewx needs to download a lot of archive records (perhaps on the first startup?)
• Is on a very slow system that can only one record every 2 seconds (it takes about 0.2s on my RPi)
• Is an IP logger

The intersection of all these cases is a true "corner case," and I don't think worth adding any additional complexity. The present driver still works, it's just a little slow.

-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.

[Luc Heijst]

Tom, 

Totally agreed.

I just wanted to report that my modification 'an sich' worked ok, see logging below, but it is totally nonsense in a situation like this -where we had to wait 45.3 seconds to proces some records- to insert extra code to gain as little as 5 seconds !

It's good to know that we covered 99%. Thanks again!

Luc

Mar 15 16:11:05 raspberrypi weewx[20258]: vantage: gentle wake up of console successful

Mar 15 16:11:09 raspberrypi weewx[20258]: vantage: Retrieving 479 page(s); starting index= 2

...

Mar 15 16:11:54 raspberrypi weewx[20258]: vantage: handling page took too long (45.3 s); restart DMPAFT

Mar 15 16:11:54 raspberrypi weewx[20258]: vantage: DMPAFT try #1; error: Handling page took too long (45.3 s)

Mar 15 16:11:54 raspberrypi weewx[20258]: vantage: Getting archive packets since 2016-03-07 08:00:00 CET (1457334000)

Mar 15 16:11:54 raspberrypi weewx[20258]: vantage: gentle wake up of console successful

Mar 15 16:11:57 raspberrypi weewx[20258]: vantage: Retrieving 478 page(s); starting index= 0

[Luc Heijst]

Update

I optimized the (wakeup logic of the) vantage driver of weewx 3.5.0 a bit more. Now running vantage driver version 3.0.12. 

On our test system, a RPI with a Vantage Envoy and IP logger, the number of time-outs dropped from an average of 180 a day to zero the last five days!

Luc