air and sky timestamps out of order

[pmendiuk]

I have been using weatherflow-udp for a few months and I have seen some gaps in the data in weewx during that time. A couple of days ago I installed MQTTSubscribe to add an interior sensor. That new service has caused weewx to exit occasionally due to the weatherflow data time stamps being out of order as it tried to append the data.

Jun 20 11:05:35 MITX-6930 weewx[16315]: weatherflowudp: MainThread: raw packet: {'serial_number': 'SK-00015052', 'type': 'rapid_wind', 'ob': [1561053931, 0.98, 342], 'hub_sn': 'HB-00011764'}
Jun 20 11:05:35 MITX-6930 weewx[16315]: weatherflowudp: MainThread: parsed packet: {'serial_number.SK_00015052.rapid_wind': 'SK-00015052', 'type.SK_00015052.rapid_wind': 'rapid_wind', 'hub_sn.SK_00015052.rapid_wind': 'HB-00011764', 'time_epoch.SK_00015052.rapid_wind': 1561053931, 'ob.SK_00015052.rapid_wind': [1561053931, 0.98, 342], 'wind_speed.SK_00015052.rapid_wind': 0.98, 'wind_direction.SK_00015052.rapid_wind': 342, 'time_epoch': 1561053931}
Jun 20 11:05:35 MITX-6930 weewx[16315]: weatherflowudp: MainThread: Loop packet: {'windDir': 342, 'windSpeed': 0.98, 'usUnits': 17, 'dateTime': 1561053931}
Jun 20 11:05:35 MITX-6930 weewx[16315]: MQTTSubscribeService: Packet prior to update is: 2019-06-20 11:05:31 PDT (1561053931) dateTime: 1561053931, usUnits: 17, windDir: 342, windSpeed: 0.98
Jun 20 11:05:35 MITX-6930 weewx[16315]: MQTTSubscribeService: Processing interval: 1561053928.000000 1561053931.000000
Jun 20 11:05:35 MITX-6930 weewx[16315]: MQTTSubscribe: TopicManager queue size is: 0
Jun 20 11:05:35 MITX-6930 weewx[16315]: MQTTSubscribeService: Queue was empty
Jun 20 11:05:35 MITX-6930 weewx[16315]: MQTTSubscribeService: Packet after update is: 2019-06-20 11:05:31 PDT (1561053931) dateTime: 1561053931, usUnits: 17, windDir: 342, windSpeed: 0.98
Jun 20 11:05:35 MITX-6930 weewx[16315]: restx: MQTT: Published record 2019-06-20 11:05:31 PDT (1561053931)
Jun 20 11:05:37 MITX-6930 weewx[16315]: weatherflowudp: MainThread: raw packet: {'firmware_revision': 43, 'serial_number': 'SK-00015052', 'type': 'obs_sky', 'obs': [[1561053914, 29168, 3.06, 0.0, 0.0, 0.68, 1.52, 7, 3.39, 1, 243, None, 0, 3]], 'hub_sn': 'HB-00011764'}
Jun 20 11:05:37 MITX-6930 weewx[16315]: weatherflowudp: MainThread: parsed packet: {'wind_avg.SK_00015052.obs_sky': 0.68, 'type.SK_00015052.obs_sky': 'obs_sky', 'rain_accumulated.SK_00015052.obs_sky': 0.0, 'hub_sn.SK_00015052.obs_sky': 'HB-00011764', 'precipitation_type.SK_00015052.obs_sky': 0, 'uv.SK_00015052.obs_sky': 3.06, 'firmware_revision.SK_00015052.obs_sky': 43, 'wind_gust.SK_00015052.obs_sky': 1.52, 'wind_direction.SK_00015052.obs_sky': 7, 'local_day_rain_accumulation.SK_00015052.obs_sky': None, 'obs.SK_00015052.obs_sky': [[1561053914, 29168, 3.06, 0.0, 0.0, 0.68, 1.52, 7, 3.39, 1, 243, None, 0, 3]], 'wind_sample_interval.SK_00015052.obs_sky': 3, 'illuminance.SK_00015052.obs_sky': 29168, 'report_interval.SK_00015052.obs_sky': 1, 'time_epoch.SK_00015052.obs_sky': 1561053914, 'solar_radiation.SK_00015052.obs_sky': 243, 'time_epoch': 1561053914, 'wind_lull.SK_00015052.obs_sky': 0.0, 'battery.SK_00015052.obs_sky': 3.39, 'serial_number.SK_00015052.obs_sky': 'SK-00015052'}
Jun 20 11:05:37 MITX-6930 weewx[16315]: weatherflowudp: MainThread: Loop packet: {'skyBatteryVoltage': 3.39, 'precipitationType': 0, 'windBatteryStatus': 3.39, 'UV': 3.06, 'radiation': 243, 'rain': 0.0, 'dateTime': 1561053914, 'illuminance': 29168, 'windLull': 0.0, 'usUnits': 17}
Jun 20 11:05:37 MITX-6930 weewx[16315]: MQTTSubscribeService: Packet prior to update is: 2019-06-20 11:05:14 PDT (1561053914) dateTime: 1561053914, illuminance: 29168, precipitationType: 0, radiation: 243, rain: 0.0, skyBatteryVoltage: 3.39, usUnits: 17, UV: 3.06, windBatteryStatus: 3.39, windLull: 0.0
Jun 20 11:05:37 MITX-6930 weewx[16315]: MQTTSubscribeService: Processing interval: 1561053931.000000 1561053914.000000
Jun 20 11:05:37 MITX-6930 weewx[16315]: engine: Main loop exiting. Shutting engine down.
Jun 20 11:05:37 MITX-6930 weewx[16315]: engine: Shutting down StdReport thread
Jun 20 11:05:37 MITX-6930 weewx[16315]: engine: StdReport thread has been terminated
Jun 20 11:05:37 MITX-6930 weewx[16315]: restx: Shut down MQTT thread.
Jun 20 11:05:37 MITX-6930 weewx[16315]: restx: Shut down Wunderground-RF thread.
Jun 20 11:05:37 MITX-6930 weewx[16315]: MQTTSubscribe: Disconnected with result code 0
Jun 20 11:05:37 MITX-6930 weewx[16315]: engine: Caught unrecoverable exception in engine:
Jun 20 11:05:37 MITX-6930 weewx[16315]:     ****  start time (1561053931) is greater than stop time (1561053914)
Jun 20 11:05:37 MITX-6930 weewx[16315]:     ****  Traceback (most recent call last):
Jun 20 11:05:37 MITX-6930 weewx[16315]:     ****    File "/usr/share/weewx/weewx/engine.py", line 890, in main
Jun 20 11:05:37 MITX-6930 weewx[16315]:     ****      engine.run()
Jun 20 11:05:37 MITX-6930 weewx[16315]:     ****    File "/usr/share/weewx/weewx/engine.py", line 191, in run
Jun 20 11:05:37 MITX-6930 weewx[16315]:     ****      self.dispatchEvent(weewx.Event(weewx.NEW_LOOP_PACKET, packet=packet))
Jun 20 11:05:37 MITX-6930 weewx[16315]:     ****    File "/usr/share/weewx/weewx/engine.py", line 224, in dispatchEvent
Jun 20 11:05:37 MITX-6930 weewx[16315]:     ****      callback(event)
Jun 20 11:05:37 MITX-6930 weewx[16315]:     ****    File "/usr/share/weewx/user/MQTTSubscribe.py", line 609, in new_loop_packet
Jun 20 11:05:37 MITX-6930 weewx[16315]:     ****      target_data = self.subscriber.get_accumulated_data(topic, start_ts, self.end_ts, event.packet['usUnits'])
Jun 20 11:05:37 MITX-6930 weewx[16315]:     ****    File "/usr/share/weewx/user/MQTTSubscribe.py", line 529, in get_accumulated_data
Jun 20 11:05:37 MITX-6930 weewx[16315]:     ****      return self.manager.get_accumulated_data(topic, start_ts, end_ts, units)
Jun 20 11:05:37 MITX-6930 weewx[16315]:     ****    File "/usr/share/weewx/user/MQTTSubscribe.py", line 277, in get_accumulated_data
Jun 20 11:05:37 MITX-6930 weewx[16315]:     ****      accumulator = weewx.accum.Accum(weeutil.weeutil.TimeSpan(start_ts, end_ts))
Jun 20 11:05:37 MITX-6930 weewx[16315]:     ****    File "/usr/share/weewx/weeutil/weeutil.py", line 256, in __new__
Jun 20 11:05:37 MITX-6930 weewx[16315]:     ****      raise ValueError("start time (%d) is greater than stop time (%d)" % (args[0], args[1]))
Jun 20 11:05:37 MITX-6930 weewx[16315]:     ****  ValueError: start time (1561053931) is greater than stop time (1561053914)
Jun 20 11:05:37 MITX-6930 weewx[16315]:     ****  Exiting.

The RSSI value for both the sky and air sensors is good so I don't understand why there would be a gap in the timestamps unless there is something else going on.