Dirty shutdown of my Fitlet, can't pull records from VantagePro2 data logger

[John Canfield]

We lost power a week ago and my UPS the Fitlet was on ran out of battery so we had a "pull the plug" situation on my weewx Linux Mint Fitlet (it's been running for two or three years fine). When power was restored I kept getting errors when weewx tried to read the data logger in the VantagePro2. It could wake up the console and then maybe pull a few records or lately zero records and it gives up:

May  1 08:59:01 beecreek weewx[20103]: engine: Initializing weewx version 3.6.2
May  1 08:59:01 beecreek weewx[20103]: engine: Using Python 2.7.12 (default, Nov 12 2018, 14:                      36:49) #012[GCC 5.4.0 20160609]
May  1 08:59:01 beecreek weewx[20103]: engine: Platform Linux-4.4.6-generic.fitlet-x86_64-wit                      h-LinuxMint-18-sarah
May  1 08:59:01 beecreek weewx[20103]: engine: pid file is /var/run/weewx.pid
May  1 08:59:01 beecreek weewx[20107]: engine: Using configuration file /etc/weewx/weewx.conf
May  1 08:59:01 beecreek weewx[20107]: engine: Initializing engine
May  1 08:59:01 beecreek weewx[20107]: engine: Loading station type Vantage (weewx.drivers.va                      ntage)
May  1 08:59:01 beecreek weewx[20107]: vantage: driver version is 3.0.9
May  1 08:59:01 beecreek weewx[20090]:    ...done.
May  1 08:59:01 beecreek systemd[1]: Started LSB: weewx weather system.
May  1 08:59:01 beecreek weewx[20107]: vantage: Opened up serial port /dev/ttyUSB0; baud 1920                      0; timeout 5.00
May  1 08:59:01 beecreek weewx[20107]: vantage: gentle wake up of console successful
May  1 08:59:01 beecreek weewx[20107]: vantage: _setup; hardware type is 16
May  1 08:59:01 beecreek weewx[20107]: engine: Loading service weewx.engine.StdTimeSynch
May  1 08:59:01 beecreek weewx[20107]: engine: Finished loading service weewx.engine.StdTimeS                      ynch
May  1 08:59:01 beecreek weewx[20107]: engine: Loading service weewx.engine.StdConvert
May  1 08:59:01 beecreek weewx[20107]: engine: StdConvert target unit is 0x1
May  1 08:59:01 beecreek weewx[20107]: engine: Finished loading service weewx.engine.StdConve                      rt
May  1 08:59:01 beecreek weewx[20107]: engine: Loading service weewx.engine.StdCalibrate
May  1 08:59:01 beecreek weewx[20107]: engine: Finished loading service weewx.engine.StdCalib                      rate
May  1 08:59:01 beecreek weewx[20107]: engine: Loading service weewx.engine.StdQC
May  1 08:59:01 beecreek weewx[20107]: engine: Finished loading service weewx.engine.StdQC
May  1 08:59:01 beecreek weewx[20107]: engine: Loading service weewx.wxservices.StdWXCalculat                      e
May  1 08:59:01 beecreek weewx[20107]: wxcalculate: The following values will be calculated:                       barometer=prefer_hardware, windchill=prefer_hardware, dewpoint=prefer_hardware, appTemp=prefe                      r_hardware, rainRate=prefer_hardware, windrun=prefer_hardware, heatindex=prefer_hardware, max                      SolarRad=prefer_hardware, humidex=prefer_hardware, pressure=prefer_hardware, inDewpoint=prefe                      r_hardware, ET=prefer_hardware, altimeter=prefer_hardware, cloudbase=prefer_hardware
May  1 08:59:01 beecreek weewx[20107]: wxcalculate: The following algorithms will be used for                       calculations: altimeter=aaNOAA, maxSolarRad=RS
May  1 08:59:01 beecreek weewx[20107]: engine: Finished loading service weewx.wxservices.StdW                      XCalculate
May  1 08:59:01 beecreek weewx[20107]: engine: Loading service weewx.engine.StdArchive
May  1 08:59:01 beecreek weewx[20107]: engine: Archive will use data binding wx_binding
May  1 08:59:01 beecreek weewx[20107]: engine: Record generation will be attempted in 'hardwa                      re'
May  1 08:59:01 beecreek weewx[20107]: engine: The archive interval in the configuration file                       (300) does not match the station hardware interval (600).
May  1 08:59:01 beecreek weewx[20107]: engine: Using archive interval of 600 seconds (specifi                      ed by hardware)
May  1 08:59:01 beecreek weewx[20107]: engine: Use LOOP data in hi/low calculations: 1
May  1 08:59:01 beecreek weewx[20107]: engine: Using binding 'wx_binding' to database 'weewx.                      sdb'
May  1 08:59:01 beecreek weewx[20107]: manager: Starting backfill of daily summaries
May  1 08:59:01 beecreek weewx[20107]: manager: Daily summaries up to date
May  1 08:59:01 beecreek weewx[20107]: engine: Finished loading service weewx.engine.StdArchi                      ve
May  1 08:59:01 beecreek weewx[20107]: engine: Loading service weewx.restx.StdStationRegistry
May  1 08:59:01 beecreek weewx[20107]: restx: StationRegistry: Station will be registered.
May  1 08:59:01 beecreek weewx[20107]: engine: Finished loading service weewx.restx.StdStatio                      nRegistry
May  1 08:59:01 beecreek weewx[20107]: engine: Loading service weewx.restx.StdWunderground
May  1 08:59:01 beecreek weewx[20107]: restx: Wunderground-PWS: Data for station KTXHARPE2 wi                      ll be posted
May  1 08:59:01 beecreek weewx[20107]: engine: Finished loading service weewx.restx.StdWunder                      ground
May  1 08:59:01 beecreek weewx[20107]: engine: Loading service weewx.restx.StdPWSweather
May  1 08:59:01 beecreek weewx[20107]: restx: PWSweather: Posting not enabled.
May  1 08:59:01 beecreek weewx[20107]: engine: Finished loading service weewx.restx.StdPWSwea                      ther
May  1 08:59:01 beecreek weewx[20107]: engine: Loading service weewx.restx.StdCWOP
May  1 08:59:01 beecreek weewx[20107]: restx: CWOP: Data for station EW0158 will be posted
May  1 08:59:01 beecreek weewx[20107]: engine: Finished loading service weewx.restx.StdCWOP
May  1 08:59:01 beecreek weewx[20107]: engine: Loading service weewx.restx.StdWOW
May  1 08:59:01 beecreek weewx[20107]: restx: WOW: Posting not enabled.
May  1 08:59:01 beecreek weewx[20107]: engine: Finished loading service weewx.restx.StdWOW
May  1 08:59:01 beecreek weewx[20107]: engine: Loading service weewx.restx.StdAWEKAS
May  1 08:59:01 beecreek weewx[20107]: restx: AWEKAS: Posting not enabled.
May  1 08:59:01 beecreek weewx[20107]: engine: Finished loading service weewx.restx.StdAWEKAS
May  1 08:59:01 beecreek weewx[20107]: engine: Loading service weewx.engine.StdPrint
May  1 08:59:01 beecreek weewx[20107]: engine: Finished loading service weewx.engine.StdPrint
May  1 08:59:01 beecreek weewx[20107]: engine: Loading service weewx.engine.StdReport
May  1 08:59:01 beecreek weewx[20107]: engine: Finished loading service weewx.engine.StdRepor                      t
May  1 08:59:01 beecreek weewx[20107]: engine: Starting up weewx version 3.6.2
May  1 08:59:01 beecreek weewx[20107]: vantage: gentle wake up of console successful
May  1 08:59:01 beecreek weewx[20107]: engine: Clock error is 4.14 seconds (positive is fast)
May  1 08:59:01 beecreek weewx[20107]: vantage: Getting archive packets since 2019-04-25 09:2                      0:00 CDT (1556202000)
May  1 08:59:01 beecreek weewx[20107]: vantage: gentle wake up of console successful
May  1 08:59:01 beecreek weewx[20107]: vantage: Retrieving 93 page(s); starting index= 0
May  1 08:59:02 beecreek weewx[20107]: vantage: empty record page 0; index 0
May  1 08:59:02 beecreek weewx[20107]: engine: Starting main packet loop.
May  1 08:59:02 beecreek weewx[20107]: vantage: gentle wake up of console successful
May  1 08:59:02 beecreek weewx[20107]: vantage: Requesting 200 LOOP packets.
May  1 08:59:02 beecreek weewx[20107]: vantage: gentle wake up of console successful
May  1 08:59:07 beecreek weewx[20107]: vantage: LOOP try #1; error: Expected to read 99 chars                      ; got 0 instead
May  1 08:59:07 beecreek weewx[20107]: vantage: Requesting 200 LOOP packets.
May  1 08:59:12 beecreek weewx[20107]: vantage: retry  #0 failed
May  1 08:59:15 beecreek weewx[20107]: vantage: retry  #1 failed
May  1 08:59:17 beecreek weewx[20107]: vantage: retry  #2 failed
May  1 08:59:19 beecreek weewx[20107]: vantage: retry  #3 failed
May  1 08:59:19 beecreek weewx[20107]: vantage: Unable to wake up console
May  1 08:59:19 beecreek weewx[20107]: vantage: LOOP try #2; error: Unable to wake up Vantage                       console
May  1 08:59:19 beecreek weewx[20107]: vantage: Requesting 200 LOOP packets.
May  1 08:59:21 beecreek weewx[20107]: vantage: retry  #0 failed
May  1 08:59:23 beecreek weewx[20107]: vantage: retry  #1 failed

And here's part of the lsusb -v response:

Bus 003 Device 003: ID 10c4:ea60 Cygnal Integrated Products, Inc. CP210x UART Bridge / myAVR mySmartUSB light
Couldn't open device, some information will be missing (same message on all USB ports)
Device Descriptor:
  bLength                18
  bDescriptorType         1
  bcdUSB               1.10
  bDeviceClass            0 (Defined at Interface level)
  bDeviceSubClass         0
  bDeviceProtocol         0
  bMaxPacketSize0        64
  idVendor           0x10c4 Cygnal Integrated Products, Inc.
  idProduct          0xea60 CP210x UART Bridge / myAVR mySmartUSB light
  bcdDevice            1.00
  iManufacturer           1
  iProduct                2
  iSerial                 3
  bNumConfigurations      1
  Configuration Descriptor:
    bLength                 9
    bDescriptorType         2
    wTotalLength           32
    bNumInterfaces          1
    bConfigurationValue     1
    iConfiguration          0
    bmAttributes         0x80
      (Bus Powered)
    MaxPower              100mA
    Interface Descriptor:
      bLength                 9
      bDescriptorType         4
      bInterfaceNumber        0
      bAlternateSetting       0
      bNumEndpoints           2
      bInterfaceClass       255 Vendor Specific Class
      bInterfaceSubClass      0
      bInterfaceProtocol      0
      iInterface              2
      Endpoint Descriptor:
        bLength                 7
        bDescriptorType         5
        bEndpointAddress     0x81  EP 1 IN
        bmAttributes            2
          Transfer Type            Bulk
          Synch Type               None
          Usage Type               Data
        wMaxPacketSize     0x0040  1x 64 bytes
        bInterval               0
      Endpoint Descriptor:
        bLength                 7
        bDescriptorType         5
        bEndpointAddress     0x01  EP 1 OUT
        bmAttributes            2
          Transfer Type            Bulk
          Synch Type               None
          Usage Type               Data
        wMaxPacketSize     0x0040  1x 64 bytes
        bInterval               0

Troubleshooting results with no joy so far. I'm pretty much out of ideas at this moment.

Restarted weewx, reboot server, unplugged data logger from the Davis console, switched to another fairly new Davis VantagePro2 console, tried different USB ports on the Fitlet (I think ttyUSB0 is following the port change), tried new Davis Logger and new USB cable between the Fitlet and the data logger. I've tried various combinations of the previous activities.

[John Canfield]

Just checked the kernel log and ttyUSB0 is reacting to me changing the ports:

Apr 30 13:46:19 beecreek kernel: [16655.212235] usb 3-2: new full-speed USB device number 2 using xhci_hcd
Apr 30 13:46:19 beecreek kernel: [16655.361518] usb 3-2: New USB device found, idVendor=10c4, idProduct=ea61
Apr 30 13:46:19 beecreek kernel: [16655.361532] usb 3-2: New USB device strings: Mfr=1, Product=2, SerialNumber=3
Apr 30 13:46:19 beecreek kernel: [16655.361540] usb 3-2: Product: CP2102 USB to UART Bridge Controller
Apr 30 13:46:19 beecreek kernel: [16655.361546] usb 3-2: Manufacturer: Silicon Labs
Apr 30 13:46:19 beecreek kernel: [16655.361552] usb 3-2: SerialNumber: 1255369079
Apr 30 13:46:19 beecreek kernel: [16655.367734] cp210x 3-2:1.0: cp210x converter detected
Apr 30 13:46:19 beecreek kernel: [16655.368025] usb 3-2: cp210x converter now attached to ttyUSB0
Apr 30 13:47:39 beecreek kernel: [16735.264504] usb 3-2: USB disconnect, device number 2
Apr 30 13:47:39 beecreek kernel: [16735.266937] cp210x ttyUSB0: cp210x converter now disconnected from ttyUSB0
Apr 30 13:47:39 beecreek kernel: [16735.266962] cp210x 3-2:1.0: device disconnected
Apr 30 13:47:54 beecreek kernel: [16750.500795] usb 3-2: new full-speed USB device number 3 using xhci_hcd
Apr 30 13:47:54 beecreek kernel: [16750.650118] usb 3-2: New USB device found, idVendor=10c4, idProduct=ea60
Apr 30 13:47:54 beecreek kernel: [16750.650131] usb 3-2: New USB device strings: Mfr=1, Product=2, SerialNumber=3
Apr 30 13:47:54 beecreek kernel: [16750.650139] usb 3-2: Product: CP2102 USB to UART Bridge Controller
Apr 30 13:47:54 beecreek kernel: [16750.650145] usb 3-2: Manufacturer: Silicon Labs
Apr 30 13:47:54 beecreek kernel: [16750.650151] usb 3-2: SerialNumber: 0001
Apr 30 13:47:54 beecreek kernel: [16750.656328] cp210x 3-2:1.0: cp210x converter detected
Apr 30 13:47:54 beecreek kernel: [16750.657233] usb 3-2: cp210x converter now attached to ttyUSB0
May  1 08:53:08 beecreek kernel: [85470.262589] ip_tables: (C) 2000-2006 Netfilter Core Team

[Thomas Keffer]

Hi, John

It looks like you have two problems.

1. The message "vantage: Retrieving 93 page(s); starting index= 0", followed by no pages retrieved, suggests that the logger is corrupt. Try clearing it. 

2. Some sort of (possibly intermittent) USB problem. I can't help you much on this one. It looks like you're using a serial-to-usb adapter. If you have another one around, try swapping.

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

[John Canfield]

Hi Tom,

Well that was no joy and I can't talk to the Davis console with minicom. I'm using the USB version of the logger, should have mentioned that before (and I did try a new USB logger). I'm thinking something in the file system got corrupted with the unexpected shutdown. Maybe the next course of action is to completely rebuild the Fitlet. Ugh.

John

john@beecreek ~ $ sudo wee_device --clear-memory

[sudo] password for john:
Using configuration file /etc/weewx/weewx.conf
Using Vantage driver version 3.0.9 (weewx.drivers.vantage)
Proceeding will erase old archive records.
Are you sure you wish to proceed (y/n)? y
Clearing the archive memory ...
Traceback (most recent call last):
  File "/usr/bin/wee_device", line 54, in <module>
    main()
  File "/usr/bin/wee_device", line 51, in main
    device.configure(config_dict)
  File "/usr/share/weewx/weewx/drivers/__init__.py", line 69, in configure
    self.do_options(options, parser, config_dict, prompt)
  File "/usr/share/weewx/weewx/drivers/vantage.py", line 1831, in do_options
    self.clear_memory(station)
  File "/usr/share/weewx/weewx/drivers/vantage.py", line 2092, in clear_memory
    station.clearLog()
  File "/usr/share/weewx/weewx/drivers/vantage.py", line 1006, in clearLog
    raise weewx.RetriesExceeded("While clearing log")
weewx.RetriesExceeded: While clearing log

To unsubscribe from this group and stop receiving emails from it, send an email to weewx...@googlegroups.com.

[vince]

On Wednesday, May 1, 2019 at 10:02:33 AM UTC-7, John Canfield wrote:

Well that was no joy and I can't talk to the Davis console with minicom. I'm using the USB version of the logger, should have mentioned that before (and I did try a new USB logger).

Still sounds more like your usb device name changed or something along those lines.

[John Canfield]

The enigma for me then is why does weewx report the console woke up? A USB problem is the first thing I thought of as well but the Fitlet does report when ttyUSB0 is attached to a new port. Grrrr.

Thanks Vince, I need all of the help I can get even though I'm not a weewx newbie - I was one of Tom's beta testers with one of his first releases.

[vince]

On Wednesday, May 1, 2019 at 10:21:15 AM UTC-7, John Canfield wrote:

The enigma for me then is why does weewx report the console woke up? A USB problem is the first thing I thought of as well but the Fitlet does report when ttyUSB0 is attached to a new port. Grrrr.

Thanks Vince, I need all of the help I can get even though I'm not a weewx newbie - I was one of Tom's beta testers with one of his first releases.

I think the minicom approach of trying to connect to the console 'without' weewx is a good one, it's just that the device might not match the one you're trying to use.

Try disconnecting the usb then reconnecting it, then use 'dmesg' to see what device it allocated.

[John Canfield]

This is driving me CRAZY!

I thought I found the problem with a UPS monitor daemon running (I had unplugged the USB cable from the CyberPower box) - I stopped the process and set it to not start at boot. Then it looked like weewx was talking to the console but we had some kind of database problem since I've been down for several days. It was updating my web page with old data. Now I'm getting errors like it can't talk to the logger. I did manage to do a logger text dump but after fiddling around that won't work now. I'm really frustrated and it's time to leave it alone and come back later.

Sigh.

[John Canfield]

Finally. I've fiddled around so much with this my head is spinning. weather.janeandjohn.org is current again. Hooray!

The short story:

- the original Davis VP2 console is good

- the original Davis USB logger is good

- did an upgrade to the latest weewx release

- I performed a sudo wee_database --update which caught my webpage up to April 30, 2019

- restarted weewx and rebooted several times while trying database commands (wee_database --drop-daily, sudo wee_database --to=2019-05-02, sudo wee_device --set-interval=1)

- the magic seemed to be sudo wee_device --set-interval=1 which Tom said in another thread cleared the data logger (and I rebooted again)

So apparently if the database gets screwed up as in not current with the logger, you (at least me) can go off on a tangent chasing an interface problem

John (WB5THT)

[John]

I think I chased the same ghost a couple times.  What I believe the underlying problem is has to do with weewx incorrectly changing the console's clock to an earlier time.  The result is that the console eventually appends a record to the datalogger with an earlier timestamp than the previous record.   Weewx aborts reading the datalogger when it comes across the out of order timestamp.  Clearing the logger's memory, changing the recording interval, etc ... gets around the problem, until it happens again. 

[John Canfield]

Yes, it does have something to do with timestamps. Boy was I chasing my tail for several days - bought a new Davis logger and even bought the WiFi logger to try. I was on the verge of rebuilding the entire Fitlet and then stumbled on a solution (a blind chicken finds a piece of corn once in a while <grin>.)

My permanent (hopefully) 'fix' is I now have significantly more UPS reserve minutes that should take me from about 60 minutes to 120-180 minutes.

John
WB5THT

--
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/-aw7xfmK7_4/unsubscribe.
To unsubscribe from this group and all its topics, send an email to weewx-user+...@googlegroups.com.
To view this discussion on the web visit https://groups.google.com/d/msgid/weewx-user/7469e457-d7df-4b4e-bdb5-7fc11de81f7f%40googlegroups.com.

[John]

I seem to have found another solution, just disable weewx from updating the console's clock. It is a setting in the weewx configuration file.

To unsubscribe from this group and all its topics, send an email to weewx...@googlegroups.com.

[John Canfield]

Ah, now that's interesting. Thanks.

John
WB5THT

To unsubscribe from this group and all its topics, send an email to weewx-user+...@googlegroups.com.
To view this discussion on the web visit https://groups.google.com/d/msgid/weewx-user/cd5188c9-06b3-4a85-a9ab-93a7e9f9b62f%40googlegroups.com.