Weewx crashed and now won't start

[Ron Walker]

Hi All,

I'm running weex on a raspberry pi using fileparse.  The weather station has been running for over two years.  Last night it crashed and I haven't been able to restart it.  The log output is below.  The only thing that has changed is the it was upgraded to 4.3.0 recently.  Thanks in advance for any help!

Apr 12 11:42:32 WeatherPi weewx[1399] INFO __main__: Initializing weewx version 4.3.0

Apr 12 11:42:32 WeatherPi weewx[1399] INFO __main__: Using Python 2.7.13 (default, Sep 26 2018, 18:42:22) #012[GCC 6.3.0 20170516]

Apr 12 11:42:32 WeatherPi weewx[1399] INFO __main__: Platform Linux-4.19.42-v7+-armv7l-with-debian-9.9

Apr 12 11:42:32 WeatherPi weewx[1399] INFO __main__: Locale is 'en_US.UTF-8'

Apr 12 11:42:32 WeatherPi weewx[1399] INFO __main__: Using configuration file weewx.conf

Apr 12 11:42:32 WeatherPi weewx[1399] INFO __main__: Debug is 2

Apr 12 11:42:32 WeatherPi weewx[1399] DEBUG __main__: Initializing engine

Apr 12 11:42:32 WeatherPi weewx[1399] INFO weewx.engine: Loading station type FileParse (user.fileparse)

Apr 12 11:42:32 WeatherPi weewxd: fileparse: data file is /var/tmp/data.csv

Apr 12 11:42:32 WeatherPi weewxd: fileparse: polling interval is 10.0

Apr 12 11:42:32 WeatherPi weewxd: fileparse: label map is {u'pressure': u'pressure', u'outTemp': u'outTemp', u'inTemp': u'inTemp', u'outHumidity': u'outHumidity', u'inHumidity': u'inHumidity', u'windSpeed': u'windSpeed', u'windDir': u'windDir', u'windGust': u'windGust', u'windGustDir': u'windGustDir', u'supplyVoltage': u'supplyVoltage', u'lightLevel': u'radiation', u'rain': u'rain'}

Apr 12 11:42:32 WeatherPi weewx[1399] DEBUG weewx.engine: Loading service weewx.engine.StdTimeSynch

Apr 12 11:42:32 WeatherPi weewx[1399] DEBUG weewx.engine: Finished loading service weewx.engine.StdTimeSynch

Apr 12 11:42:32 WeatherPi weewx[1399] DEBUG weewx.engine: Loading service weewx.engine.StdConvert

Apr 12 11:42:32 WeatherPi weewx[1399] INFO weewx.engine: StdConvert target unit is 0x1

Apr 12 11:42:32 WeatherPi weewx[1399] DEBUG weewx.engine: Finished loading service weewx.engine.StdConvert

Apr 12 11:42:32 WeatherPi weewx[1399] DEBUG weewx.engine: Loading service weewx.engine.StdCalibrate

Apr 12 11:42:32 WeatherPi weewx[1399] DEBUG weewx.engine: Finished loading service weewx.engine.StdCalibrate

Apr 12 11:42:32 WeatherPi weewx[1399] DEBUG weewx.engine: Loading service weewx.engine.StdQC

Apr 12 11:42:32 WeatherPi weewx[1399] DEBUG weewx.engine: Finished loading service weewx.engine.StdQC

Apr 12 11:42:32 WeatherPi weewx[1399] DEBUG weewx.engine: Loading service weewx.wxservices.StdWXCalculate

Apr 12 11:42:32 WeatherPi weewx[1399] DEBUG weewx.manager: Daily summary version is 3.0

Apr 12 11:42:32 WeatherPi weewx[1399] DEBUG weewx.engine: Finished loading service weewx.wxservices.StdWXCalculate

Apr 12 11:42:32 WeatherPi weewx[1399] DEBUG weewx.engine: Loading service weewx.wxxtypes.StdWXXTypes

Apr 12 11:42:32 WeatherPi weewx[1399] DEBUG weewx.engine: Finished loading service weewx.wxxtypes.StdWXXTypes

Apr 12 11:42:32 WeatherPi weewx[1399] DEBUG weewx.engine: Loading service weewx.wxxtypes.StdPressureCooker

Apr 12 11:42:32 WeatherPi weewx[1399] DEBUG weewx.engine: Finished loading service weewx.wxxtypes.StdPressureCooker

Apr 12 11:42:32 WeatherPi weewx[1399] DEBUG weewx.engine: Loading service weewx.wxxtypes.StdRainRater

Apr 12 11:42:32 WeatherPi weewx[1399] DEBUG weewx.engine: Finished loading service weewx.wxxtypes.StdRainRater

Apr 12 11:42:32 WeatherPi weewx[1399] DEBUG weewx.engine: Loading service weewx.wxxtypes.StdDelta

Apr 12 11:42:32 WeatherPi weewx[1399] DEBUG weewx.engine: Finished loading service weewx.wxxtypes.StdDelta

Apr 12 11:42:32 WeatherPi weewx[1399] DEBUG weewx.engine: Loading service weewx.engine.StdArchive

Apr 12 11:42:32 WeatherPi weewx[1399] INFO weewx.engine: Archive will use data binding wx_binding

Apr 12 11:42:32 WeatherPi weewx[1399] INFO weewx.engine: Record generation will be attempted in 'hardware'

Apr 12 11:42:32 WeatherPi weewx[1399] INFO weewx.engine: Using archive interval of 300 seconds (specified in weewx configuration)

Apr 12 11:42:32 WeatherPi weewx[1399] DEBUG weewx.engine: Use LOOP data in hi/low calculations: 1

Apr 12 11:42:32 WeatherPi weewx[1399] DEBUG weewx.engine: Finished loading service weewx.engine.StdArchive

Apr 12 11:42:32 WeatherPi weewx[1399] DEBUG weewx.engine: Loading service weewx.restx.StdStationRegistry

Apr 12 11:42:32 WeatherPi weewx[1399] INFO weewx.restx: StationRegistry: Registration not requested.

Apr 12 11:42:32 WeatherPi weewx[1399] DEBUG weewx.engine: Finished loading service weewx.restx.StdStationRegistry

Apr 12 11:42:32 WeatherPi weewx[1399] DEBUG weewx.engine: Loading service weewx.restx.StdWunderground

Apr 12 11:42:32 WeatherPi weewx[1399] INFO weewx.restx: Wunderground: Posting not enabled.

Apr 12 11:42:32 WeatherPi weewx[1399] DEBUG weewx.engine: Finished loading service weewx.restx.StdWunderground

Apr 12 11:42:32 WeatherPi weewx[1399] DEBUG weewx.engine: Loading service weewx.restx.StdPWSweather

Apr 12 11:42:32 WeatherPi weewx[1399] INFO weewx.restx: PWSweather: Posting not enabled.

Apr 12 11:42:32 WeatherPi weewx[1399] DEBUG weewx.engine: Finished loading service weewx.restx.StdPWSweather

Apr 12 11:42:32 WeatherPi weewx[1399] DEBUG weewx.engine: Loading service weewx.restx.StdCWOP

Apr 12 11:42:32 WeatherPi weewx[1399] INFO weewx.restx: CWOP: Posting not enabled.

Apr 12 11:42:32 WeatherPi weewx[1399] DEBUG weewx.engine: Finished loading service weewx.restx.StdCWOP

Apr 12 11:42:32 WeatherPi weewx[1399] DEBUG weewx.engine: Loading service weewx.restx.StdWOW

Apr 12 11:42:32 WeatherPi weewx[1399] INFO weewx.restx: WOW: Posting not enabled.

Apr 12 11:42:32 WeatherPi weewx[1399] DEBUG weewx.engine: Finished loading service weewx.restx.StdWOW

Apr 12 11:42:32 WeatherPi weewx[1399] DEBUG weewx.engine: Loading service weewx.restx.StdAWEKAS

Apr 12 11:42:32 WeatherPi weewx[1399] INFO weewx.restx: AWEKAS: Posting not enabled.

Apr 12 11:42:32 WeatherPi weewx[1399] DEBUG weewx.engine: Finished loading service weewx.restx.StdAWEKAS

Apr 12 11:42:32 WeatherPi weewx[1399] DEBUG weewx.engine: Loading service weewx.engine.StdPrint

Apr 12 11:42:32 WeatherPi weewx[1399] DEBUG weewx.engine: Finished loading service weewx.engine.StdPrint

Apr 12 11:42:32 WeatherPi weewx[1399] DEBUG weewx.engine: Loading service weewx.engine.StdReport

Apr 12 11:42:32 WeatherPi weewx[1399] DEBUG weewx.engine: Finished loading service weewx.engine.StdReport

Apr 12 11:42:32 WeatherPi weewx[1399] INFO __main__: Starting up weewx version 4.3.0

Apr 12 11:42:32 WeatherPi weewx[1399] DEBUG weewx.engine: Station does not support reading the time

Apr 12 11:42:32 WeatherPi weewx[1399] INFO weewx.engine: Using binding 'wx_binding' to database 'weewx.sdb'

Apr 12 11:42:32 WeatherPi weewx[1399] INFO weewx.manager: Starting backfill of daily summaries

Apr 12 11:42:32 WeatherPi weewx[1399] INFO weewx.engine: Starting main packet loop.

Apr 12 11:42:33 WeatherPi weewx[1399] INFO weewx.engine: Main loop exiting. Shutting engine down.

Apr 12 11:42:33 WeatherPi weewx[1399] CRITICAL __main__: Caught unrecoverable exception:

Apr 12 11:42:33 WeatherPi weewx[1399] CRITICAL __main__:     ****  strxfrm() argument 1 must be string without null bytes, not str

Apr 12 11:42:33 WeatherPi weewx[1399] CRITICAL __main__:     ****  Traceback (most recent call last):

Apr 12 11:42:33 WeatherPi weewx[1399] CRITICAL __main__:     ****    File "/usr/share/weewx/weewxd", line 154, in main

Apr 12 11:42:33 WeatherPi weewx[1399] CRITICAL __main__:     ****      engine.run()

Apr 12 11:42:33 WeatherPi weewx[1399] CRITICAL __main__:     ****    File "/usr/share/weewx/weewx/engine.py", line 210, in run

Apr 12 11:42:33 WeatherPi weewx[1399] CRITICAL __main__:     ****      self.dispatchEvent(weewx.Event(weewx.NEW_LOOP_PACKET, packet=packet))

Apr 12 11:42:33 WeatherPi weewx[1399] CRITICAL __main__:     ****    File "/usr/share/weewx/weewx/engine.py", line 245, in dispatchEvent

Apr 12 11:42:33 WeatherPi weewx[1399] CRITICAL __main__:     ****      callback(event)

Apr 12 11:42:33 WeatherPi weewx[1399] CRITICAL __main__:     ****    File "/usr/share/weewx/weewx/engine.py", line 781, in new_loop_packet

Apr 12 11:42:33 WeatherPi weewx[1399] CRITICAL __main__:     ****      to_sorted_string(event.packet))

Apr 12 11:42:33 WeatherPi weewx[1399] CRITICAL __main__:     ****    File "/usr/share/weewx/weeutil/weeutil.py", line 1397, in to_sorted_string

Apr 12 11:42:33 WeatherPi weewx[1399] CRITICAL __main__:     ****      return ", ".join(["%s: %s" % (k, rec.get(k)) for k in sorted(rec, key=locale.strxfrm)])

Apr 12 11:42:33 WeatherPi weewx[1399] CRITICAL __main__:     ****  TypeError: strxfrm() argument 1 must be string without null bytes, not str

Apr 12 11:42:33 WeatherPi weewx[1399] CRITICAL __main__:     ****  Exiting.

 

[Tom Keffer]

A few thoughts:

Why the upgrade to V4.3? Why not the current version, V4.7?

The error is occurring in StdPrint, which prints to the console. StdPrint sorts the keys first, so it's easier to find an observation type. You can get this error when there is an embedded null in the key used to sort a string, which, in this case, would be the keys used in the file sent to fileparse.

I'm thinking that the file that you're feeding to fileparse may have an embedded null in the key. For example, instead of 

temperature = 52.3

it has

temperature\0 = 52.3

where \0 signifies the embedded null.

Take a look at whatever is writing the file and make sure it is not accidentally adding nulls. One way it could be doing this is by converting unicode characters into utf-8, which frequently use nulls in their encoding, and which weewxd would not be expecting. If this is the case, we will probably want to change fileparse so that it can handle files with utf-8.

You didn't say what version of WeeWX you upgraded from, but the strxfrm() function was added to the sort in V4.0. If you upgraded from a version earlier than that, the embedded null would not have made a difference.

Best I can think of right now.

Incidentally, you should consider using Python 3. Python 2.7 is very old, and we may not support it much longer.

-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.
To view this discussion on the web visit https://groups.google.com/d/msgid/weewx-user/bb5afd42-911d-4962-81ee-5e9b763c91acn%40googlegroups.com.

[Ron Walker]

Hi Tom!  Thanks for your response!

I took a look at the fileparse input and I didn't see anything out of the ordinary.  I was wondering why, if the issue is something like a null label, it would work for over 12 hours before failing.  Each fileparse record is identical, in terms of the labeling.

The upgrade was an embarrassing mistake that occurred while upgrading the OS.  I went ahead and upgraded Weewx to 4.7.  Now when I start Weewx, it has an issue with trying to write to a read only database.  Log output is below.  I did change the Python default to version 3, but this output still says 2.7.  That's an issue for another day!

Apr 12 21:26:52 WeatherPi weewx[1576] INFO __main__: Initializing weewx version 4.7.0

Apr 12 21:26:52 WeatherPi weewx[1576] INFO __main__: Using Python 2.7.13 (default, Sep 26 2018, 18:42:22) #012[GCC 6.3.0 20170516]

Apr 12 21:26:52 WeatherPi weewx[1576] INFO __main__: Platform Linux-4.19.42-v7+-armv7l-with-debian-9.13

Apr 12 21:26:52 WeatherPi weewx[1576] INFO __main__: Locale is 'en_US.UTF-8'

Apr 12 21:26:52 WeatherPi weewx[1576] INFO __main__: Using configuration file weewx.conf

Apr 12 21:26:52 WeatherPi weewx[1576] INFO __main__: Debug is 2

Apr 12 21:26:52 WeatherPi weewx[1576] DEBUG __main__: Initializing engine

Apr 12 21:26:52 WeatherPi weewx[1576] INFO weewx.engine: Loading station type FileParse (user.fileparse)

Apr 12 21:26:52 WeatherPi weewxd: fileparse: data file is /var/tmp/data.csv

Apr 12 21:26:52 WeatherPi weewxd: fileparse: polling interval is 10.0

Apr 12 21:26:52 WeatherPi weewxd: fileparse: label map is {u'pressure': u'pressure', u'outTemp': u'outTemp', u'inTemp': u'inTemp', u'outHumidity': u'outHumidity', u'inHumidity': u'inHumidity', u'windSpeed': u'windSpeed', u'windDir': u'windDir', u'windGust': u'windGust', u'windGustDir': u'windGustDir', u'supplyVoltage': u'supplyVoltage', u'lightLevel': u'radiation', u'rain': u'rain'}

Apr 12 21:26:52 WeatherPi weewx[1576] DEBUG weewx.engine: Loading service weewx.engine.StdTimeSynch

Apr 12 21:26:52 WeatherPi weewx[1576] DEBUG weewx.engine: Finished loading service weewx.engine.StdTimeSynch

Apr 12 21:26:52 WeatherPi weewx[1576] DEBUG weewx.engine: Loading service weewx.engine.StdConvert

Apr 12 21:26:52 WeatherPi weewx[1576] INFO weewx.engine: StdConvert target unit is 0x1

Apr 12 21:26:52 WeatherPi weewx[1576] DEBUG weewx.engine: Finished loading service weewx.engine.StdConvert

Apr 12 21:26:52 WeatherPi weewx[1576] DEBUG weewx.engine: Loading service weewx.engine.StdCalibrate

Apr 12 21:26:52 WeatherPi weewx[1576] DEBUG weewx.engine: Finished loading service weewx.engine.StdCalibrate

Apr 12 21:26:52 WeatherPi weewx[1576] DEBUG weewx.engine: Loading service weewx.engine.StdQC

Apr 12 21:26:52 WeatherPi weewx[1576] DEBUG weewx.engine: Finished loading service weewx.engine.StdQC

Apr 12 21:26:52 WeatherPi weewx[1576] DEBUG weewx.engine: Loading service weewx.wxservices.StdWXCalculate

Apr 12 21:26:52 WeatherPi weewx[1576] DEBUG weewx.wxservices: Calculations for LOOP packets: {u'barometer': u'prefer_hardware', u'windchill': u'prefer_hardware', u'dewpoint': u'prefer_hardware', u'appTemp': u'prefer_hardware', u'rainRate': u'software', u'windrun': u'prefer_hardware', u'heatindex': u'prefer_hardware', u'maxSolarRad': u'prefer_hardware', u'humidex': u'prefer_hardware', 'windDir': 'software', u'pressure': u'prefer_hardware', u'inDewpoint': u'prefer_hardware', u'ET': u'prefer_hardware', u'altimeter': u'prefer_hardware', u'cloudbase': u'prefer_hardware', 'windGustDir': 'software'}

Apr 12 21:26:52 WeatherPi weewx[1576] DEBUG weewx.wxservices: Calculations for archive records: {u'barometer': u'prefer_hardware', u'windchill': u'prefer_hardware', u'dewpoint': u'prefer_hardware', u'appTemp': u'prefer_hardware', u'rainRate': u'software', u'windrun': u'prefer_hardware', u'heatindex': u'prefer_hardware', u'maxSolarRad': u'prefer_hardware', u'humidex': u'prefer_hardware', 'windDir': 'software', u'pressure': u'prefer_hardware', u'inDewpoint': u'prefer_hardware', u'ET': u'prefer_hardware', u'altimeter': u'prefer_hardware', u'cloudbase': u'prefer_hardware', 'windGustDir': 'software'}

Apr 12 21:26:52 WeatherPi weewx[1576] INFO weewx.wxservices: StdWXCalculate will use data binding wx_binding

Apr 12 21:26:52 WeatherPi weewx[1576] DEBUG weewx.manager: Daily summary version is 3.0

Apr 12 21:26:52 WeatherPi weewx[1576] INFO weewx.manager: Daily summaries at V3.0. Patching to V4.0

Apr 12 21:26:52 WeatherPi weewx[1576] INFO weewx.manager: recalculate_weights: Using database 'weewx.sdb'

Apr 12 21:26:52 WeatherPi weewx[1576] DEBUG weewx.manager: recalculate_weights: Tranche size 100

Apr 12 21:26:52 WeatherPi weewx[1576] CRITICAL __main__: Database OperationalError exception: attempt to write a readonly database

Apr 12 21:26:52 WeatherPi weewx[1576] CRITICAL __main__:     ****  Waiting 2 minutes then retrying...