Archiving not happening when using SDR

[bdf0506]

I just rebuilt a WeeWX system, running 4.1.1 and I'm facing an odd issue where I find that archiving is NOT happening when I use the SDR driver.

If I use the Simulator, archiving works at the testing interval of 30 seconds as planned. While using the SDR driver, it is able to parse the RTL_433 packets just fine in loop mode, but archive never happens.

Grepped out the sdr packets as they are super noisy:

[root@weewx ~]$ tail -1000f /var/log/weewx.log | grep -v sdr

Oct 5 22:51:48 weewx weewx[1137]: * Starting weewx weather system weewx
Oct 5 22:51:54 weewx weewx[1361] INFO __main__: Initializing weewx version 4.1.1
Oct 5 22:51:54 weewx weewx[1361] INFO __main__: Using Python 3.6.9 (default, Jul 17 2020, 12:50:27) #012[GCC 8.4.0]Oct 5 22:51:54 weewx weewx[1361] INFO __main__: Platform Linux-4.15.0-118-generic-x86_64-with-Ubuntu-18.04-bionic
Oct 5 22:51:54 weewx weewx[1361] INFO __main__: Locale is 'en_US.UTF-8'
Oct 5 22:51:54 weewx weewx[1361] INFO __main__: PID file is /var/run/weewx.pid
Oct 5 22:51:54 weewx weewx[1137]: ...done.
Oct 5 22:51:55 weewx weewx[1537] INFO __main__: Using configuration file /opt/weewx/weewx.conf
Oct 5 22:51:55 weewx weewx[1537] INFO __main__: Debug is 5
Oct 5 22:51:55 weewx weewx[1537] DEBUG __main__: Initializing engine
Oct 5 22:51:57 weewx weewx[1537] DEBUG weewx.engine: Loading service weewx.engine.StdTimeSynch
Oct 5 22:51:57 weewx weewx[1537] DEBUG weewx.engine: Finished loading service weewx.engine.StdTimeSynch
Oct 5 22:51:57 weewx weewx[1537] DEBUG weewx.engine: Loading service weewx.engine.StdConvert
Oct 5 22:51:57 weewx weewx[1537] INFO weewx.engine: StdConvert target unit is 0x1
Oct 5 22:51:57 weewx weewx[1537] DEBUG weewx.engine: Finished loading service weewx.engine.StdConvert
Oct 5 22:51:57 weewx weewx[1537] DEBUG weewx.engine: Loading service weewx.engine.StdCalibrate
Oct 5 22:51:57 weewx weewx[1537] DEBUG weewx.engine: Finished loading service weewx.engine.StdCalibrate
Oct 5 22:51:57 weewx weewx[1537] DEBUG weewx.engine: Loading service weewx.engine.StdQC
Oct 5 22:51:57 weewx weewx[1537] DEBUG weewx.engine: Finished loading service weewx.engine.StdQC
Oct 5 22:51:57 weewx weewx[1537] DEBUG weewx.engine: Loading service weewx.wxservices.StdWXCalculate
Oct 5 22:52:06 weewx weewx[1537] DEBUG weewx.manager: Daily summary version is 2.0
Oct 5 22:52:06 weewx weewx[1537] INFO weewx.wxservices: The following values will be calculated: pressure=prefer_hardware, altimeter=prefer_hardware, appTemp=prefer_hardware, barometer=prefer_hardware, beaufort=prefer_hardware, cloudbase=prefer_hardware, dewpoint=prefer_hardware, ET=prefer_hardware, heatindex=prefer_hardware, humidex=prefer_hardware, inDewpoint=prefer_hardware, maxSolarRad=prefer_hardware, rainRate=prefer_hardware, windchill=prefer_hardware, windrun=prefer_hardware
Oct 5 22:52:06 weewx weewx[1537] INFO weewx.wxservices: The following algorithms will be used for calculations: altimeter=aaASOS, maxSolarRad=RS
Oct 5 22:52:06 weewx weewx[1537] DEBUG weewx.engine: Finished loading service weewx.wxservices.StdWXCalculate
Oct 5 22:52:06 weewx weewx[1537] DEBUG weewx.engine: Loading service weewx.engine.StdArchive
Oct 5 22:52:06 weewx weewx[1537] INFO weewx.engine: Archive will use data binding wx_binding
Oct 5 22:52:06 weewx weewx[1537] INFO weewx.engine: Record generation will be attempted in 'software'
Oct 5 22:52:06 weewx weewx[1537] INFO weewx.engine: Using archive interval of 30 seconds (software record generation)
Oct 5 22:52:06 weewx weewx[1537] WARNING weewx.engine: Archive delay (15) is unusually long
Oct 5 22:52:06 weewx weewx[1537] DEBUG weewx.engine: Use LOOP data in hi/low calculations: 1
Oct 5 22:52:06 weewx weewx[1537] DEBUG weewx.engine: Finished loading service weewx.engine.StdArchive
Oct 5 22:52:06 weewx weewx[1537] DEBUG weewx.engine: Loading service weewx.restx.StdStationRegistry
Oct 5 22:52:07 weewx weewx[1537] INFO weewx.restx: StationRegistry: Registration not requested.
Oct 5 22:52:07 weewx weewx[1537] DEBUG weewx.engine: Finished loading service weewx.restx.StdStationRegistry
Oct 5 22:52:07 weewx weewx[1537] DEBUG weewx.engine: Loading service weewx.restx.StdWunderground
Oct 5 22:52:07 weewx weewx[1537] INFO weewx.restx: Wunderground: Posting not enabled.
Oct 5 22:52:07 weewx weewx[1537] DEBUG weewx.engine: Finished loading service weewx.restx.StdWunderground
Oct 5 22:52:07 weewx weewx[1537] DEBUG weewx.engine: Loading service weewx.restx.StdPWSweather
Oct 5 22:52:07 weewx weewx[1537] INFO weewx.restx: PWSweather: Posting not enabled.
Oct 5 22:52:07 weewx weewx[1537] DEBUG weewx.engine: Finished loading service weewx.restx.StdPWSweather
Oct 5 22:52:07 weewx weewx[1537] DEBUG weewx.engine: Loading service weewx.restx.StdCWOP
Oct 5 22:52:07 weewx weewx[1537] INFO weewx.restx: CWOP: Posting not enabled.
Oct 5 22:52:07 weewx weewx[1537] DEBUG weewx.engine: Finished loading service weewx.restx.StdCWOP
Oct 5 22:52:07 weewx weewx[1537] DEBUG weewx.engine: Loading service weewx.restx.StdWOW
Oct 5 22:52:07 weewx weewx[1537] INFO weewx.restx: WOW: Posting not enabled.
Oct 5 22:52:07 weewx weewx[1537] DEBUG weewx.engine: Finished loading service weewx.restx.StdWOW
Oct 5 22:52:07 weewx weewx[1537] DEBUG weewx.engine: Loading service weewx.restx.StdAWEKAS
Oct 5 22:52:07 weewx weewx[1537] INFO weewx.restx: AWEKAS: Posting not enabled.
Oct 5 22:52:07 weewx weewx[1537] DEBUG weewx.engine: Finished loading service weewx.restx.StdAWEKAS
Oct 5 22:52:07 weewx weewx[1537] DEBUG weewx.engine: Loading service weewx.engine.StdPrint
Oct 5 22:52:07 weewx weewx[1537] DEBUG weewx.engine: Finished loading service weewx.engine.StdPrint
Oct 5 22:52:07 weewx weewx[1537] DEBUG weewx.engine: Loading service weewx.engine.StdReport
Oct 5 22:52:07 weewx weewx[1537] DEBUG weewx.engine: Finished loading service weewx.engine.StdReport
Oct 5 22:52:07 weewx weewx[1537] INFO __main__: Starting up weewx version 4.1.1
Oct 5 22:52:07 weewx weewx[1537] DEBUG weewx.engine: Station does not support reading the time
Oct 5 22:52:07 weewx weewx[1537] INFO weewx.engine: Using binding 'wx_binding' to database 'weewx'
Oct 5 22:52:07 weewx weewx[1537] INFO weewx.manager: Starting backfill of daily summaries
Oct 5 22:52:07 weewx weewx[1537] INFO weewx.engine: Starting main packet loop.

[root@weewx ~]$ date

Mon Oct  5 22:57:51 EDT 2020

Relevant config file sections:

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

# This section is for general configuration information.

# Set to 1 for extra debug info, otherwise comment it out or set to zero

debug = 5

# Root directory of the weewx data file hierarchy for this station

WEEWX_ROOT = /opt/weewx

# Whether to log successful operations

log_success = True

# Whether to log unsuccessful operations

log_failure = True

# How long to wait before timing out a socket (FTP, HTTP) connection

socket_timeout = 20

# Do not modify this. It is used when installing and updating weewx.

version = 4.1.1

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

[SDR]

   # This section is for the software-defined radio driver.

   # The driver to use

   driver = user.sdr

   log_unknown_sensors = True

   log_unmapped_sensors = False

   path = /usr/local/bin/

   cmd = rtl_433 -C customary -F json

   [[sensor_map]]

      outHumidity = humidity.0D5C.Acurite5n1PacketV2

      outTemp = temperature.0D5C.Acurite5n1PacketV2

      windSpeed = wind_speed.0D5C.Acurite5n1PacketV2

      windDir = wind_dir.0D5C.Acurite5n1PacketV2

      rain_total = rain_total.0D5C.Acurite5n1PacketV2

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

#   This section is for configuring the archive service.

[StdArchive]

    # If the station hardware supports data logging then the archive interval

    # will be downloaded from the station. Otherwise, specify it (in seconds).

    archive_interval = 30

    # If possible, new archive records are downloaded from the station

    # hardware. If the hardware does not support this, then new archive

    # records will be generated in software.

    # Set the following to "software" to force software record generation.

    record_generation = software

    # Whether to include LOOP data in hi/low statistics

    loop_hilo = True

    # The data binding used to save archive records

    data_binding = wx_binding

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

#   This section is for configuring the archive service.

[StdArchive]

    # If the station hardware supports data logging then the archive interval

    # will be downloaded from the station. Otherwise, specify it (in seconds).

    archive_interval = 30

    # If possible, new archive records are downloaded from the station

    # hardware. If the hardware does not support this, then new archive

    # records will be generated in software.

    # Set the following to "software" to force software record generation.

    record_generation = software

    # Whether to include LOOP data in hi/low statistics

    loop_hilo = True

    # The data binding used to save archive records

    data_binding = wx_binding

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

Any ideas of why this isn't working with SDR?

[bdf0506]

Here's the wx_bindings section too.

Full output including the sdr packets: https://pastebin.com/FFU0JGN7

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

 

#   This section binds a data store to a database.

[DataBindings]

    [[wx_binding]]

        # The database must match one of the sections in [Databases].

        # This is likely to be the only option you would want to change.

        database = archive_mysql

        # The name of the table within the database

        table_name = archive

        # The manager handles aggregation of data for historical summaries

        manager = weewx.manager.DaySummaryManager

        # The schema defines the structure of the database.

        # It is *only* used when the database is created.

        schema = schemas.wview.schema

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

[gjr80]

Hi,

A few suggestions. An archive interval of 30 seconds is exceptionally small and is asking for trouble. Officially the archive interval should be a multiple of 60 seconds (though there was a relatively recent change introduced in v4.0.0 that now permits 'oddball' archive intervals. I am not sure what 'oddball' means exactly but the issue that the change addressed was a problem that occurred when the archive interval did not evenly divide into 24 hours). Best not to push the boundaries until you get SDR working properly.

Can you provide a non-filtered debug log extract from startup. Appreciate you were filtering out the SDR chatter but that makes it very hard to see what SDR is doing. The debug setting in weewx.conf is what you use to quieten the log, in this case debug=1 will be sufficient to start with. Also, have you run WeeWX directly to see if you are getting loop packets from the SDR driver?

Gary

[gjr80]

OK, just saw the pastebin link. Disregard the log comment.

Gary

[bdf0506]

I figured it out. It was a nasty little bug/race condition which is probably works as designed.

I noticed that when I would run WeeWx directly (thanks for the pointer to try that) it was showing my loop packets were off by 5 hours, which happens to be my offset from UTC. My guess is that since the time of the loop packets didn't match the time that the system was running, after the archive period expired, no data was found, so there was nothing to do. This likely should have been printed in a log message or something, but it wasn't.

So, I went into the SDR help docs, and realized that I needed to tell SDR to use UTC time, so I had to change this property:

cmd = rtl_433 -C customary -F json

to

cmd = rtl_433 -M utc -C customary -F json

I guess this really boils down to RTFM since it clearly states that in the configuration section of https://github.com/matthewwall/weewx-sdr !