AttributeError when starting wfrog (wmr200, raspberrypi, raspberian wheezy)

[Greg Vickers]

Hi,

I've purchased a raspberrypi and would like to use this to run wfrog.  I have a wmr200 weather station and have plugged it directly into the pi, i.e. no USB hub.  I'm using a spare iPhone power supply, which doesn't seem to have any problems providing power.

I have installed all the package dependencies and wfrog installed and configured successfully with 'wfrog -S'.  When I run wfrog, I get the following error:
$ sudo wfrog -d
Traceback (most recent call last):
  File "/usr/bin/wfrog", line 138, in <module>
    component.run(config_file, settings)
  File "/usr/lib/wfrog/wflogger/wflogger.py", line 132, in run
    self.configure(config_file, settings_file)
  File "/usr/lib/wfrog/wflogger/wflogger.py", line 94, in configure
    (config, self.context) = self.configurer.configure(options, self, config_file, settings_file)
  File "/usr/lib/wfrog/wfcommon/config.py", line 123, in configure
    self.logger.info("Starting wfrog " + wfrog_version)
  File "/usr/lib/python2.7/logging/__init__.py", line 1140, in info
    self._log(INFO, msg, args, **kwargs)
  File "/usr/lib/python2.7/logging/__init__.py", line 1258, in _log
    self.handle(record)
  File "/usr/lib/python2.7/logging/__init__.py", line 1268, in handle
    self.callHandlers(record)
  File "/usr/lib/python2.7/logging/__init__.py", line 1308, in callHandlers
    hdlr.handle(record)
  File "/usr/lib/python2.7/logging/__init__.py", line 744, in handle
    rv = self.filter(record)
  File "/usr/lib/python2.7/logging/__init__.py", line 607, in filter
    for f in self.filters:
AttributeError: 'RotatingFileHandler' object has no attribute 'filters'
$

And the process exits.  If I run 'wfrog -v':
$ sudo wfrog -v
Exception in thread Thread-3:
Traceback (most recent call last):
  File "/usr/lib/python2.7/threading.py", line 551, in __bootstrap_inner
    self.run()
  File "/usr/lib/python2.7/threading.py", line 504, in run
    self.__target(*self.__args, **self.__kwargs)
  File "/usr/lib/wfrog/wfdriver/wfdriver.py", line 117, in run
    self.station.run(gen, self.enqueue_event)
  File "/usr/lib/wfrog/wfdriver/station/wmr200.py", line 348, in run
    self.connectDevice()
  File "/usr/lib/wfrog/wfdriver/station/wmr200.py", line 305, in connectDevice
    self.logger.exception("WMR200 connect failed: %s" % str(e))
  File "/usr/lib/python2.7/logging/__init__.py", line 1172, in exception
    self.error(msg, exc_info=1, *args)
  File "/usr/lib/python2.7/logging/__init__.py", line 1166, in error
    self._log(ERROR, msg, args, **kwargs)
  File "/usr/lib/python2.7/logging/__init__.py", line 1258, in _log
    self.handle(record)
  File "/usr/lib/python2.7/logging/__init__.py", line 1268, in handle
    self.callHandlers(record)
  File "/usr/lib/python2.7/logging/__init__.py", line 1308, in callHandlers
    hdlr.handle(record)
  File "/usr/lib/python2.7/logging/__init__.py", line 744, in handle
    rv = self.filter(record)
  File "/usr/lib/python2.7/logging/__init__.py", line 607, in filter
    for f in self.filters:
AttributeError: 'RotatingFileHandler' object has no attribute 'filters'

And the process keeps running!  If I do a wget to localhost:7680, I get the following:
----------------------------------------
Exception happened during processing of request from ('127.0.0.1', 54255)
Traceback (most recent call last):
  File "/usr/lib/wfrog/wfrender/renderer/http.py", line 257, in _handle_request_noblock
    self.process_request(request, client_address)
  File "/usr/lib/python2.7/SocketServer.py", line 310, in process_request
    self.finish_request(request, client_address)
  File "/usr/lib/python2.7/SocketServer.py", line 323, in finish_request
    self.RequestHandlerClass(request, client_address, self)
  File "/usr/lib/python2.7/SocketServer.py", line 638, in __init__
    self.handle()
  File "/usr/lib/python2.7/BaseHTTPServer.py", line 340, in handle
    self.handle_one_request()
  File "/usr/lib/python2.7/BaseHTTPServer.py", line 328, in handle_one_request
    method()
  File "/usr/lib/wfrog/wfrender/renderer/http.py", line 193, in do_GET
    _HttpRendererSingleton.logger.exception(e)
  File "/usr/lib/python2.7/logging/__init__.py", line 1172, in exception
    self.error(msg, exc_info=1, *args)
  File "/usr/lib/python2.7/logging/__init__.py", line 1166, in error
    self._log(ERROR, msg, args, **kwargs)
  File "/usr/lib/python2.7/logging/__init__.py", line 1258, in _log
    self.handle(record)
  File "/usr/lib/python2.7/logging/__init__.py", line 1268, in handle
    self.callHandlers(record)
  File "/usr/lib/python2.7/logging/__init__.py", line 1308, in callHandlers
    hdlr.handle(record)
  File "/usr/lib/python2.7/logging/__init__.py", line 744, in handle
    rv = self.filter(record)
  File "/usr/lib/python2.7/logging/__init__.py", line 607, in filter
    for f in self.filters:
AttributeError: 'RotatingFileHandler' object has no attribute 'filters'
----------------------------------------

I'm not a python programmer, so I don't know what the above errors mean, if I grep for RotatingFileHandler, in the config files, I get one hit:
$ cat fileloghandler.yaml
handler: !!python/object/new:logging.handlers.RotatingFileHandler
    kwds:
        filename: ${filename}
        maxBytes: 262144
        backupCount: 3

And this is the same as the config file on my previous computer used with wfrog.  Any ideas why I am getting this error?

Thanks,
Greg

[Jordi Puigsegur Figueras]

This is related to your python version. You've probably switched to 2.7 and there was a known problem (http://code.google.com/p/wfrog/issues/detail?id=85). Fortunately there is a workaround implemented. You just need to download the latest source from svn and it should work.

Jordi.

2012/11/18 Greg Vickers <daeh...@gmail.com>

[Greg Vickers]

Cool, thanks!  I've pulled down the current version from svn and ran it and wound up with this result:

~/wfrog-read-only/bin $ sudo ./wfrog -v
2012-11-18 19:59:11,744 ERROR [station.wmr200] WMR200 connect failed: error sending control message: Device or resource busy

Traceback (most recent call last):

  File "/home/daehenoc/wfrog-read-only/wfdriver/station/wmr200.py", line 259, in connectDevice
    0xA, [], 0, 0, int(usbTimeout * 1000))
USBError: error sending control message: Device or resource busy
2012-11-18 19:59:11,759 ERROR [station.wmr200] Can't write request record: error sending control message: Device or resource busy

Traceback (most recent call last):

  File "/home/daehenoc/wfrog-read-only/wfdriver/station/wmr200.py", line 198, in sendPacket
    timeout = int(usbTimeout * 1000))
USBError: error sending control message: Device or resource busy
2012-11-18 19:59:11,767 ERROR [station.wmr200] WMR200 disconnect failed: could not release intf 0: Invalid argument

Traceback (most recent call last):

  File "/home/daehenoc/wfrog-read-only/wfdriver/station/wmr200.py", line 319, in disconnectDevice
    self.devh.releaseInterface()
USBError: could not release intf 0: Invalid argument

Exception in thread Thread-3:
Traceback (most recent call last):
  File "/usr/lib/python2.7/threading.py", line 551, in __bootstrap_inner
    self.run()
  File "/usr/lib/python2.7/threading.py", line 504, in run
    self.__target(*self.__args, **self.__kwargs)

  File "/home/daehenoc/wfrog-read-only/wfdriver/wfdriver.py", line 117, in run
    self.station.run(gen, self.enqueue_event)
  File "/home/daehenoc/wfrog-read-only/wfdriver/station/wmr200.py", line 349, in run
    self.logData()
  File "/home/daehenoc/wfrog-read-only/wfdriver/station/wmr200.py", line 443, in logData
    self.sendCommand(0xD0)
  File "/home/daehenoc/wfrog-read-only/wfdriver/station/wmr200.py", line 210, in sendCommand
    self.sendPacket([0x01, command, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00])
  File "/home/daehenoc/wfrog-read-only/wfdriver/station/wmr200.py", line 196, in sendPacket
    self.devh.controlMsg(usb.TYPE_CLASS + usb.RECIP_INTERFACE,
AttributeError: 'NoneType' object has no attribute 'controlMsg'

Um.  The bottle of Sangiovese (The Little Wine Company) isn't helping me here at all!  It's a lovely 2007 drop :)  I'll try putting python 2.6 on and see if that helps with the 0.8.2 version.

Cheers,
Greg

[Chris Schlaeger]

Please post the complete log file.

Chris

[Greg Vickers]

Here is the /var/log/wfrog.log rile:

/var/log $ cat wfrog.log

2012-11-18 19:59:11,744 ERROR [station.wmr200] WMR200 connect failed: error sending control message: Device or resource busy
Traceback (most recent call last):
  File "/home/daehenoc/wfrog-read-only/wfdriver/station/wmr200.py", line 259, in connectDevice
    0xA, [], 0, 0, int(usbTimeout * 1000))
USBError: error sending control message: Device or resource busy
2012-11-18 19:59:11,759 ERROR [station.wmr200] Can't write request record: error sending control message: Device or resource busy
Traceback (most recent call last):
  File "/home/daehenoc/wfrog-read-only/wfdriver/station/wmr200.py", line 198, in sendPacket
    timeout = int(usbTimeout * 1000))
USBError: error sending control message: Device or resource busy
2012-11-18 19:59:11,767 ERROR [station.wmr200] WMR200 disconnect failed: could not release intf 0: Invalid argument
Traceback (most recent call last):
  File "/home/daehenoc/wfrog-read-only/wfdriver/station/wmr200.py", line 319, in disconnectDevice
    self.devh.releaseInterface()
USBError: could not release intf 0: Invalid argument

I found that python2.6 was already installed, so I configured update-alternatives according to the instructions here:
http://codeghar.wordpress.com/2009/01/27/update-alternatives-in-debian/

And configured python2.6 as the default python and wfrog works a treat, thanks!

Cheers,
Greg

[Greg Vickers]

Hmm, nope, I spoke too soon!  wfrog runs and I can browse to the page, and I was waiting for data to appear on the page.  However, no data was being displayed after an hour.  So I stopped wflogger and wfrender, and ran sudo wfrog -v:

$ sudo wfrog  -v
2012-11-19 14:32:53,279 ERROR [station.wmr200] WMR200 connect failed: error sending control message: Device or resource busy

Traceback (most recent call last):

  File "/usr/lib/wfrog/wfdriver/station/wmr200.py", line 259, in connectDevice

    0xA, [], 0, 0, int(usbTimeout * 1000))
USBError: error sending control message: Device or resource busy

2012-11-19 14:32:53,295 ERROR [station.wmr200] Can't write request record: error sending control message: Device or resource busy

Traceback (most recent call last):

  File "/usr/lib/wfrog/wfdriver/station/wmr200.py", line 198, in sendPacket

    timeout = int(usbTimeout * 1000))
USBError: error sending control message: Device or resource busy

2012-11-19 14:32:53,307 ERROR [station.wmr200] WMR200 disconnect failed: could not release intf 0: Invalid argument

Traceback (most recent call last):

  File "/usr/lib/wfrog/wfdriver/station/wmr200.py", line 319, in disconnectDevice

    self.devh.releaseInterface()
USBError: could not release intf 0: Invalid argument
Exception in thread Thread-3:
Traceback (most recent call last):

  File "/usr/lib/python2.6/threading.py", line 532, in __bootstrap_inner
    self.run()
  File "/usr/lib/python2.6/threading.py", line 484, in run

    self.__target(*self.__args, **self.__kwargs)
  File "/usr/lib/wfrog/wfdriver/wfdriver.py", line 117, in run
    self.station.run(gen, self.enqueue_event)

  File "/usr/lib/wfrog/wfdriver/station/wmr200.py", line 349, in run
    self.logData()
  File "/usr/lib/wfrog/wfdriver/station/wmr200.py", line 439, in logData
    self.sendCommand(0xD0)
  File "/usr/lib/wfrog/wfdriver/station/wmr200.py", line 210, in sendCommand

    self.sendPacket([0x01, command, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00])

  File "/usr/lib/wfrog/wfdriver/station/wmr200.py", line 196, in sendPacket

    self.devh.controlMsg(usb.TYPE_CLASS + usb.RECIP_INTERFACE,
AttributeError: 'NoneType' object has no attribute 'controlMsg'

So I'm still getting this AttributeError, albeit a different error :p

Here's the list of python versions installed on the system:
$ dpkg -l python2.6
Desired=Unknown/Install/Remove/Purge/Hold
| Status=Not/Inst/Conf-files/Unpacked/halF-conf/Half-inst/trig-aWait/Trig-pend
|/ Err?=(none)/Reinst-required (Status,Err: uppercase=bad)
||/ Name                          Version             Architecture        Description
+++-=============================-===================-===================-================================================================
ii  python2.6                     2.6.8-0.2           armhf               An interactive high-level object-oriented language (version 2.6)
$ dpkg -l python2.7
Desired=Unknown/Install/Remove/Purge/Hold
| Status=Not/Inst/Conf-files/Unpacked/halF-conf/Half-inst/trig-aWait/Trig-pend
|/ Err?=(none)/Reinst-required (Status,Err: uppercase=bad)
||/ Name                          Version             Architecture        Description
+++-=============================-===================-===================-================================================================
ii  python2.7                     2.7.3~rc2-2.1       armhf               Interactive high-level object-oriented language (version 2.7)

I did try removing python2.7, but there were a few dependencies which I didn't try to resolve, and just updated the default for python.  Should I go ahead and try to remove python2.7?

Thanks,
Greg

[Chris Schlaeger]

The output of 'wfrog -v' is not the log file. I need the content of your wfrog.log file.

Chris

[mik79]

Hi,

i  tried the same and i made the python 2.6 workaround:

Here ist the log file. I think the interesting part is at 2012-11-26 00:51:03,623

2012-11-26 00:31:24,740 ERROR [station.wmr200] WMR200 connect failed: error sending control message: Device or resource busy

Traceback (most recent call last):

  File "/usr/lib/wfrog/wfdriver/station/wmr200.py", line 259, in connectDevice
    0xA, [], 0, 0, int(usbTimeout * 1000))
USBError: error sending control message: Device or resource busy

2012-11-26 00:31:24,756 ERROR [station.wmr200] Can't write request record: error sending control message: Device or resource busy

Traceback (most recent call last):

  File "/usr/lib/wfrog/wfdriver/station/wmr200.py", line 198, in sendPacket
    timeout = int(usbTimeout * 1000))
USBError: error sending control message: Device or resource busy

2012-11-26 00:31:24,767 ERROR [station.wmr200] WMR200 disconnect failed: could not release intf 0: Invalid argument

Traceback (most recent call last):

  File "/usr/lib/wfrog/wfdriver/station/wmr200.py", line 319, in disconnectDevice
    self.devh.releaseInterface()
USBError: could not release intf 0: Invalid argument

2012-11-26 00:33:54,215 ERROR [data.currentxml] Could not parse /var/lib/wfrog/wfrog-current.xml

Traceback (most recent call last):

  File "/usr/lib/wfrog/wfrender/datasource/xmlquery.py", line 68, in execute
    dom = xml.dom.minidom.parse(self.path)
  File "/usr/lib/python2.6/xml/dom/minidom.py", line 1918, in parse
    return expatbuilder.parse(file)
  File "/usr/lib/python2.6/xml/dom/expatbuilder.py", line 922, in parse
    fp = open(file, 'rb')
IOError: [Errno 2] No such file or directory: '/var/lib/wfrog/wfrog-current.xml'
2012-11-26 00:33:59,244 ERROR [data.currentxml] Could not parse /var/lib/wfrog/wfrog-current.xml

Traceback (most recent call last):

  File "/usr/lib/wfrog/wfrender/datasource/xmlquery.py", line 68, in execute
    dom = xml.dom.minidom.parse(self.path)
  File "/usr/lib/python2.6/xml/dom/minidom.py", line 1918, in parse
    return expatbuilder.parse(file)
  File "/usr/lib/python2.6/xml/dom/expatbuilder.py", line 922, in parse
    fp = open(file, 'rb')
IOError: [Errno 2] No such file or directory: '/var/lib/wfrog/wfrog-current.xml'
2012-11-26 00:51:03,623 INFO [config] Starting wfrog 0.8.2
2012-11-26 00:51:03,628 INFO [config] Loaded settings file /etc/wfrog/settings.yaml
2012-11-26 00:51:09,562 INFO [config] Starting wfrog 0.8.2
2012-11-26 00:51:09,565 INFO [config] Loaded settings file /etc/wfrog/settings.yaml
2012-11-26 00:51:09,591 INFO [station.wmr200] Thread started
2012-11-26 00:51:09,608 INFO [station.wmr200] USB initialization
2012-11-26 00:51:09,624 INFO [station.wmr200] Oregon Scientific weather station found
2012-11-26 00:51:09,627 INFO [station.wmr200] Manufacturer: 0
2012-11-26 00:51:09,640 INFO [station.wmr200] Product: 1
2012-11-26 00:51:09,643 INFO [station.wmr200] Device version: 03.02
2012-11-26 00:51:09,645 INFO [station.wmr200] USB version: 01.10
2012-11-26 00:51:09,665 INFO [station.wmr200] Unloaded other driver from interface 0
2012-11-26 00:51:10,371 INFO [config] Starting wfrog 0.8.2
2012-11-26 00:51:10,374 INFO [config] Loaded settings file /etc/wfrog/settings.yaml
2012-11-26 00:51:10,391 INFO [renderer.http] Started server on port 7680
2012-11-26 00:51:10,761 ERROR [station.wmr200] WMR200 connect failed: error sending control message: Device or resource busy

Traceback (most recent call last):

  File "/usr/lib/wfrog/wfdriver/station/wmr200.py", line 259, in connectDevice
    0xA, [], 0, 0, int(usbTimeout * 1000))
USBError: error sending control message: Device or resource busy

2012-11-26 00:51:10,772 ERROR [station.wmr200] Can't write request record: error sending control message: Device or resource busy

Traceback (most recent call last):

  File "/usr/lib/wfrog/wfdriver/station/wmr200.py", line 198, in sendPacket
    timeout = int(usbTimeout * 1000))
USBError: error sending control message: Device or resource busy

2012-11-26 00:51:10,777 ERROR [station.wmr200] WMR200 disconnect failed: could not release intf 0: Invalid argument

Traceback (most recent call last):

[Chris Schlaeger]

There is nothing in this log snippet that would help me diagnose the problem.

Chris

[mik79]

Hi,

we had to delete row 253 from the wmr200.py:

self.devh.reset()

and now IT WORKS!!!!!

Thank you very much for the cool programm!!!!

Michael

[Greg Vickers]

Hi,

This has not worked for me - I've had intermittent success with the daemons, the logger does sometimes record information from my wmr200, but I don't know why.

Chris, where do I find the wfrog.log file?  Just asking because the information that I've posted before has not been the correct information you require.

Thanks,
Greg

[Chris Schlaeger]

On Mon, Dec 24, 2012 at 3:30 AM, Greg Vickers <daeh...@gmail.com> wrote:

Chris, where do I find the wfrog.log file?  Just asking because the information that I've posted before has not been the correct information you require.

The log file is usually saved as /var/log/wfrog.log.

Chris

[Greg Vickers]

Thanks Chris - here is the last information in the wfrog.log file in /var/log:

$ tail -n 20 wfrog.log
2012-12-24 12:28:00,359 INFO [station.wmr200] Device version: 03.02
2012-12-24 12:28:00,362 INFO [station.wmr200] USB version: 01.10
2012-12-24 12:28:00,926 INFO [config] Starting wfrog 0.8.2
2012-12-24 12:28:00,929 INFO [config] Loaded settings file /etc/wfrog/settings.yaml
2012-12-24 12:28:00,968 INFO [renderer.http] Started server on port 80
2012-12-24 12:28:01,455 ERROR [station.wmr200] WMR200 connect failed: error sending control message: Device or resource busy

Traceback (most recent call last):
  File "/usr/lib/wfrog/wfdriver/station/wmr200.py", line 259, in connectDevice
    0xA, [], 0, 0, int(usbTimeout * 1000))
USBError: error sending control message: Device or resource busy

2012-12-24 12:28:01,463 ERROR [station.wmr200] Can't write request record: error sending control message: Device or resource busy

Traceback (most recent call last):
  File "/usr/lib/wfrog/wfdriver/station/wmr200.py", line 198, in sendPacket
    timeout = int(usbTimeout * 1000))
USBError: error sending control message: Device or resource busy

2012-12-24 12:28:01,469 ERROR [station.wmr200] WMR200 disconnect failed: could not release intf 0: Invalid argument

Traceback (most recent call last):
  File "/usr/lib/wfrog/wfdriver/station/wmr200.py", line 319, in disconnectDevice
    self.devh.releaseInterface()
USBError: could not release intf 0: Invalid argument

I've stopped and restarted both the logger and renderer, and they stay running, but the wflogger.log file has this information in it:
/var/log $ tail -n 20 wflogger.log
2012-12-29 15:49:47,012 INFO [station.wmr200] Manufacturer: 0
2012-12-29 15:49:47,015 INFO [station.wmr200] Product: 1
2012-12-29 15:49:47,028 INFO [station.wmr200] Device version: 03.02
2012-12-29 15:49:47,030 INFO [station.wmr200] USB version: 01.10
2012-12-29 15:49:47,050 INFO [station.wmr200] Unloaded other driver from interface 0
2012-12-29 15:49:48,117 ERROR [station.wmr200] WMR200 connect failed: error sending control message: Device or resource busy

Traceback (most recent call last):
  File "/usr/lib/wfrog/wfdriver/station/wmr200.py", line 259, in connectDevice
    0xA, [], 0, 0, int(usbTimeout * 1000))
USBError: error sending control message: Device or resource busy

2012-12-29 15:49:48,124 ERROR [station.wmr200] Can't write request record: error sending control message: Device or resource busy

Traceback (most recent call last):
  File "/usr/lib/wfrog/wfdriver/station/wmr200.py", line 198, in sendPacket
    timeout = int(usbTimeout * 1000))
USBError: error sending control message: Device or resource busy

2012-12-29 15:49:48,138 ERROR [station.wmr200] WMR200 disconnect failed: could not release intf 0: Invalid argument

Traceback (most recent call last):
  File "/usr/lib/wfrog/wfdriver/station/wmr200.py", line 319, in disconnectDevice
    self.devh.releaseInterface()
USBError: could not release intf 0: Invalid argument

Is this helpful, or is there another log file I can pull out for you?

Thanks,
Greg

[janc]

Hi

I've got also this error with lubuntu 12.10 python 2.5.6 installed, wfrog_0.8.2-1_all.deb, pywws-12.10_r547.tar.gz my station is an wh1080 from Alecto (ws4000) .

Maybe is here a solution "Concurrent logging handler (drop-in replacement for RotatingFileHandler)"
on this site
http://pypi.python.org/pypi/ConcurrentLogHandler

janc


Op zondag 18 november 2012 05:50:02 UTC+1 schreef Greg Vickers het volgende:

Op zondag 18 november 2012 05:50:02 UTC+1 schreef Greg Vickers het volgende:

[Greg Vickers]

I've tossed this in and have gotten a standard Core2Duo system to install wfrog to - so I won't come back to this problem, good luck to others, I hope a solution is found!

[Greg Vickers]

Hi,

This issue has occured again for me on a recent Debian install with python 2.7, and I've resolved this issue by following the fix detailed in post #18 on the bug page:
https://code.google.com/p/wfrog/issues/detail?id=85

Cheers,
Greg