search

DIYBookScanner / spreadpi

Raspberry Pi image for controlling a DIYBookScanner via spreads
GNU General Public License v2.0
37 stars 11 forks source link

spread.log (on spreadpi version 20140316) #17

Closed markvdb closed 10 years ago

markvdb commented 10 years ago

(OWN.TXT not yet set on any of the two attached a810 cameras)

2014-03-21 20:23:19,016 Starting scanning station server in "scanner" mode [spreadsplug.web] [DEBUG]
2014-03-21 20:23:19,057 found extension EntryPoint.parse('chdkcamera = spreadsplug.dev.chdkcamera:CHDKCameraDevice') [stevedore.extension] [DEBUG]
2014-03-21 20:23:19,064 found extension EntryPoint.parse('a2200 = spreadsplug.dev.chdkcamera:CanonA2200CameraDevice') [stevedore.extension] [DEBUG]
2014-03-21 20:23:19,067 Finding devices for driver "<stevedore.driver.DriverManager object at 0x27a7d30>" [spreads.plugin] [DEBUG]
2014-03-21 20:23:19,239 No devices could be found at startup. [spreadsplug.web] [WARNING]
2014-03-21 20:27:25,572 2606728 [spreadsplug.web.database] [DEBUG]
2014-03-21 20:27:25,576 Initializing workflow cache [spreadsplug.web.database] [INFO]
2014-03-21 20:27:25,579 Obtaining all workflows from database. [spreadsplug.web.database] [DEBUG]
2014-03-21 20:27:25,583 Initializing database. [spreadsplug.web.database] [INFO]
2014-03-21 20:27:26,859 Creating plugin manager [spreads.plugin] [DEBUG]
2014-03-21 20:27:26,869 found extension EntryPoint.parse('scantailor = spreadsplug.scantailor:ScanTailorPlugin') [stevedore] [DEBUG]
2014-03-21 20:27:26,872 found extension EntryPoint.parse('web = spreadsplug.web:WebCommands') [stevedore] [DEBUG]
2014-03-21 20:27:26,879 found extension EntryPoint.parse('tesseract = spreadsplug.tesseract:TesseractPlugin') [stevedore] [DEBUG]
2014-03-21 20:27:26,882 found extension EntryPoint.parse('djvubind = spreadsplug.djvubind:DjvuBindPlugin') [stevedore] [DEBUG]
2014-03-21 20:27:26,885 found extension EntryPoint.parse('gui = spreadsplug.gui:GuiCommand') [stevedore] [DEBUG]
2014-03-21 20:27:26,888 found extension EntryPoint.parse('autorotate = spreadsplug.autorotate:AutoRotatePlugin') [stevedore] [DEBUG]
2014-03-21 20:27:26,891 found extension EntryPoint.parse('intervaltrigger = spreadsplug.intervaltrigger:IntervalTrigger') [stevedore] [DEBUG]
2014-03-21 20:27:26,894 found extension EntryPoint.parse('hidtrigger = spreadsplug.hidtrigger:HidTrigger') [stevedore] [DEBUG]
2014-03-21 20:27:26,902 Initializing HidTrigger plugin [spreadsplug.hidtrigger] [DEBUG]
2014-03-21 20:27:26,904 found extension EntryPoint.parse('pdfbeads = spreadsplug.pdfbeads:PDFBeadsPlugin') [stevedore] [DEBUG]
2014-03-21 20:27:26,912 found extension EntryPoint.parse('chdkcamera = spreadsplug.dev.chdkcamera:CHDKCameraDevice') [stevedore.extension] [DEBUG]
2014-03-21 20:27:26,919 found extension EntryPoint.parse('a2200 = spreadsplug.dev.chdkcamera:CanonA2200CameraDevice') [stevedore.extension] [DEBUG]
2014-03-21 20:28:40,736 Initializing workflow /home/spreads/scans/Test [Workflow] [DEBUG]
2014-03-21 20:28:40,748 Creating plugin manager [spreads.plugin] [DEBUG]
2014-03-21 20:28:40,762 found extension EntryPoint.parse('scantailor = spreadsplug.scantailor:ScanTailorPlugin') [stevedore] [DEBUG]
2014-03-21 20:28:40,777 found extension EntryPoint.parse('web = spreadsplug.web:WebCommands') [stevedore] [DEBUG]
2014-03-21 20:28:40,786 found extension EntryPoint.parse('tesseract = spreadsplug.tesseract:TesseractPlugin') [stevedore] [DEBUG]
2014-03-21 20:28:40,791 found extension EntryPoint.parse('djvubind = spreadsplug.djvubind:DjvuBindPlugin') [stevedore] [DEBUG]
2014-03-21 20:28:40,794 found extension EntryPoint.parse('gui = spreadsplug.gui:GuiCommand') [stevedore] [DEBUG]
2014-03-21 20:28:40,799 found extension EntryPoint.parse('autorotate = spreadsplug.autorotate:AutoRotatePlugin') [stevedore] [DEBUG]
2014-03-21 20:28:40,803 found extension EntryPoint.parse('intervaltrigger = spreadsplug.intervaltrigger:IntervalTrigger') [stevedore] [DEBUG]
2014-03-21 20:28:40,807 found extension EntryPoint.parse('hidtrigger = spreadsplug.hidtrigger:HidTrigger') [stevedore] [DEBUG]
2014-03-21 20:28:40,815 Initializing HidTrigger plugin [spreadsplug.hidtrigger] [DEBUG]
2014-03-21 20:28:40,819 found extension EntryPoint.parse('pdfbeads = spreadsplug.pdfbeads:PDFBeadsPlugin') [stevedore] [DEBUG]
2014-03-21 20:28:40,989 Writing workflow to database:
DbWorkflow(id=None, name='Test', step=None, step_done=None, capture_start=None, config='{"device": {"shutter_speed": "1/25", "flip_target_pages": false, "focus_distance": 545, "sensitivity": 80, "shoot_raw": false, "zoom_level": 3, "chdkptp_path": "/usr/local/lib/chdkptp", "parallel_capture": true, "dpi": 300}, "web": {"debug": false, "mode": "scanner", "standalone_device": true, "database": "~/.config/spreads/workflows.db", "project_dir": "~/scans", "postprocessing_server": ""}, "verbose": false, "logfile": "/var/log/spreads/spread.log", "loglevel": "debug", "plugins": ["web", "hidtrigger"], "capture": {"capture_keys": [" ", "b"]}, "driver": "chdkcamera"}') [spreadsplug.web.database] [DEBUG]
2014-03-21 20:28:41,037 Workflow written to database with id 1 [spreadsplug.web.database] [DEBUG]
2014-03-21 20:28:41,372 Workflows updated [spreadsplub.web] [DEBUG]
2014-03-21 20:28:41,421 Finishing previous workflows [spreadsplub.web] [DEBUG]
2014-03-21 20:28:41,438 Preparing capture. [Workflow] [INFO]
2014-03-21 20:28:41,469 found extension EntryPoint.parse('chdkcamera = spreadsplug.dev.chdkcamera:CHDKCameraDevice') [stevedore.extension] [DEBUG]
2014-03-21 20:28:41,481 found extension EntryPoint.parse('a2200 = spreadsplug.dev.chdkcamera:CanonA2200CameraDevice') [stevedore.extension] [DEBUG]
2014-03-21 20:28:41,498 Finding devices for driver "<stevedore.driver.DriverManager object at 0x2831970>" [spreads.plugin] [DEBUG]
2014-03-21 20:28:41,615 Device has serial number 06458DD4B2B142D9B41D10FA7681F40C [ChdkCamera] [DEBUG]
2014-03-21 20:28:41,650 Calling chdkptp with arguments: [u'/usr/local/lib/chdkptp/chdkptp', '-c-d=006 -b=001', '-eset cli_verbose=2', '-eluar return(get_buildinfo())'] [ChdkCamera] [DEBUG]
2014-03-21 20:28:41,780 Workflows updated [spreadsplub.web] [DEBUG]
2014-03-21 20:28:42,205 Call returned:
['unexpected return code 0x2005', "ERROR: /usr/local/lib/chdkptp/lua/chdku.lua:118: attempt to index field 'apiver' (a nil value)", 'stack traceback:', "\t/usr/local/lib/chdkptp/lua/chdku.lua:118: in function 'is_ver_compatible'", '\t/usr/local/lib/chdkptp/lua/chdku.lua:627: in function </usr/local/lib/chdkptp/lua/chdku.lua:609>', '\t(tail call): ?', '\t/usr/local/lib/chdkptp/lua/cli.lua:596: in function </usr/local/lib/chdkptp/lua/cli.lua:593>', '\t(tail call): ?', '\t(tail call): ?', "\t[C]: in function 'xpcall'", "\t/usr/local/lib/chdkptp/lua/cli.lua:239: in function 'execute'", "\t/usr/local/lib/chdkptp/lua/main.lua:191: in function 'do_execute_option'", "\t/usr/local/lib/chdkptp/lua/main.lua:211: in function 'do_no_gui_startup'", '\t/usr/local/lib/chdkptp/lua/main.lua:227: in main chunk', "\t[C]: in function 'require'", '\t[string "require(\'main\')"]:1: in main chunk', 'connected: Canon PowerShot A810, max packet size 512', 'error'] [ChdkCamera] [DEBUG]
2014-03-21 20:28:42,220 Exception on /workflow/1/prepare_capture [POST] [spreadsplug.web] [ERROR]
Traceback (most recent call last):
  File "/home/spreads/virtspreads/local/lib/python2.7/site-packages/flask/app.py", line 1817, in wsgi_app
    response = self.full_dispatch_request()
  File "/home/spreads/virtspreads/local/lib/python2.7/site-packages/flask/app.py", line 1477, in full_dispatch_request
    rv = self.handle_user_exception(e)
  File "/home/spreads/virtspreads/local/lib/python2.7/site-packages/flask/app.py", line 1381, in handle_user_exception
    reraise(exc_type, exc_value, tb)
  File "/home/spreads/virtspreads/local/lib/python2.7/site-packages/flask/app.py", line 1475, in full_dispatch_request
    rv = self.dispatch_request()
  File "/home/spreads/virtspreads/local/lib/python2.7/site-packages/flask/app.py", line 1461, in dispatch_request
    return self.view_functions[rule.endpoint](**req.view_args)
  File "/home/spreads/virtspreads/local/lib/python2.7/site-packages/spreads-0.0.0-py2.7.egg/spreadsplug/web/web.py", line 408, in prepare_capture
    workflow.prepare_capture()
  File "/home/spreads/virtspreads/local/lib/python2.7/site-packages/spreads-0.0.0-py2.7.egg/spreads/workflow.py", line 153, in prepare_capture
    if any(dev.target_page is None for dev in self.devices):
  File "/home/spreads/virtspreads/local/lib/python2.7/site-packages/spreads-0.0.0-py2.7.egg/spreads/workflow.py", line 79, in devices
    self._devices = plugin.get_devices(self.config)
  File "/home/spreads/virtspreads/local/lib/python2.7/site-packages/spreads-0.0.0-py2.7.egg/spreads/plugin.py", line 359, in get_devices
    devices = list(driver_class.yield_devices(config['device']))
  File "/home/spreads/virtspreads/local/lib/python2.7/site-packages/spreads-0.0.0-py2.7.egg/spreadsplug/dev/chdkcamera.py", line 63, in yield_devices
    yield cls(config, dev)
  File "/home/spreads/virtspreads/local/lib/python2.7/site-packages/spreads-0.0.0-py2.7.egg/spreadsplug/dev/chdkcamera.py", line 94, in __init__
    get_result=True)
  File "/home/spreads/virtspreads/local/lib/python2.7/site-packages/spreads-0.0.0-py2.7.egg/spreadsplug/dev/chdkcamera.py", line 241, in _execute_lua
    output = self._run("{0} {1}".format(cmd, script))
  File "/home/spreads/virtspreads/local/lib/python2.7/site-packages/spreads-0.0.0-py2.7.egg/spreadsplug/dev/chdkcamera.py", line 234, in _run
    raise CHDKPTPException("\n".join(output))
CHDKPTPException: unexpected return code 0x2005
ERROR: /usr/local/lib/chdkptp/lua/chdku.lua:118: attempt to index field 'apiver' (a nil value)
stack traceback:
    /usr/local/lib/chdkptp/lua/chdku.lua:118: in function 'is_ver_compatible'
    /usr/local/lib/chdkptp/lua/chdku.lua:627: in function </usr/local/lib/chdkptp/lua/chdku.lua:609>
    (tail call): ?
    /usr/local/lib/chdkptp/lua/cli.lua:596: in function </usr/local/lib/chdkptp/lua/cli.lua:593>
    (tail call): ?
    (tail call): ?
    [C]: in function 'xpcall'
    /usr/local/lib/chdkptp/lua/cli.lua:239: in function 'execute'
    /usr/local/lib/chdkptp/lua/main.lua:191: in function 'do_execute_option'
    /usr/local/lib/chdkptp/lua/main.lua:211: in function 'do_no_gui_startup'
    /usr/local/lib/chdkptp/lua/main.lua:227: in main chunk
    [C]: in function 'require'
    [string "require('main')"]:1: in main chunk
error
2014-03-21 20:28:57,129 Triggering capture. [Workflow] [INFO]
2014-03-21 20:28:57,143 Sending capture command to devices [Workflow] [DEBUG]
2014-03-21 20:28:57,159 found extension EntryPoint.parse('chdkcamera = spreadsplug.dev.chdkcamera:CHDKCameraDevice') [stevedore.extension] [DEBUG]
2014-03-21 20:28:57,167 found extension EntryPoint.parse('a2200 = spreadsplug.dev.chdkcamera:CanonA2200CameraDevice') [stevedore.extension] [DEBUG]
2014-03-21 20:28:57,171 Finding devices for driver "<stevedore.driver.DriverManager object at 0x28b18d0>" [spreads.plugin] [DEBUG]
2014-03-21 20:28:57,269 Device has serial number 06458DD4B2B142D9B41D10FA7681F40C [ChdkCamera] [DEBUG]
2014-03-21 20:28:57,297 Calling chdkptp with arguments: [u'/usr/local/lib/chdkptp/chdkptp', '-c-d=006 -b=001', '-eset cli_verbose=2', '-eluar return(get_buildinfo())'] [ChdkCamera] [DEBUG]
2014-03-21 20:28:57,529 Workflows updated [spreadsplub.web] [DEBUG]
2014-03-21 20:28:57,895 Call returned:
['unexpected return code 0x2005', "ERROR: /usr/local/lib/chdkptp/lua/chdku.lua:118: attempt to index field 'apiver' (a nil value)", 'stack traceback:', "\t/usr/local/lib/chdkptp/lua/chdku.lua:118: in function 'is_ver_compatible'", '\t/usr/local/lib/chdkptp/lua/chdku.lua:627: in function </usr/local/lib/chdkptp/lua/chdku.lua:609>', '\t(tail call): ?', '\t/usr/local/lib/chdkptp/lua/cli.lua:596: in function </usr/local/lib/chdkptp/lua/cli.lua:593>', '\t(tail call): ?', '\t(tail call): ?', "\t[C]: in function 'xpcall'", "\t/usr/local/lib/chdkptp/lua/cli.lua:239: in function 'execute'", "\t/usr/local/lib/chdkptp/lua/main.lua:191: in function 'do_execute_option'", "\t/usr/local/lib/chdkptp/lua/main.lua:211: in function 'do_no_gui_startup'", '\t/usr/local/lib/chdkptp/lua/main.lua:227: in main chunk', "\t[C]: in function 'require'", '\t[string "require(\'main\')"]:1: in main chunk', 'connected: Canon PowerShot A810, max packet size 512', 'error'] [ChdkCamera] [DEBUG]
2014-03-21 20:28:57,904 Exception on /workflow/1/capture [POST] [spreadsplug.web] [ERROR]
Traceback (most recent call last):
  File "/home/spreads/virtspreads/local/lib/python2.7/site-packages/flask/app.py", line 1817, in wsgi_app
    response = self.full_dispatch_request()
  File "/home/spreads/virtspreads/local/lib/python2.7/site-packages/flask/app.py", line 1477, in full_dispatch_request
    rv = self.handle_user_exception(e)
  File "/home/spreads/virtspreads/local/lib/python2.7/site-packages/flask/app.py", line 1381, in handle_user_exception
    reraise(exc_type, exc_value, tb)
  File "/home/spreads/virtspreads/local/lib/python2.7/site-packages/flask/app.py", line 1475, in full_dispatch_request
    rv = self.dispatch_request()
  File "/home/spreads/virtspreads/local/lib/python2.7/site-packages/flask/app.py", line 1461, in dispatch_request
    return self.view_functions[rule.endpoint](**req.view_args)
  File "/home/spreads/virtspreads/local/lib/python2.7/site-packages/spreads-0.0.0-py2.7.egg/spreadsplug/web/web.py", line 426, in trigger_capture
    workflow.capture(retake=('retake' in request.args))
  File "/home/spreads/virtspreads/local/lib/python2.7/site-packages/spreads-0.0.0-py2.7.egg/spreads/workflow.py", line 191, in capture
    for dev in self.devices:
  File "/home/spreads/virtspreads/local/lib/python2.7/site-packages/spreads-0.0.0-py2.7.egg/spreads/workflow.py", line 79, in devices
    self._devices = plugin.get_devices(self.config)
  File "/home/spreads/virtspreads/local/lib/python2.7/site-packages/spreads-0.0.0-py2.7.egg/spreads/plugin.py", line 359, in get_devices
    devices = list(driver_class.yield_devices(config['device']))
  File "/home/spreads/virtspreads/local/lib/python2.7/site-packages/spreads-0.0.0-py2.7.egg/spreadsplug/dev/chdkcamera.py", line 63, in yield_devices
    yield cls(config, dev)
  File "/home/spreads/virtspreads/local/lib/python2.7/site-packages/spreads-0.0.0-py2.7.egg/spreadsplug/dev/chdkcamera.py", line 94, in __init__
    get_result=True)
  File "/home/spreads/virtspreads/local/lib/python2.7/site-packages/spreads-0.0.0-py2.7.egg/spreadsplug/dev/chdkcamera.py", line 241, in _execute_lua
    output = self._run("{0} {1}".format(cmd, script))
  File "/home/spreads/virtspreads/local/lib/python2.7/site-packages/spreads-0.0.0-py2.7.egg/spreadsplug/dev/chdkcamera.py", line 234, in _run
    raise CHDKPTPException("\n".join(output))
CHDKPTPException: unexpected return code 0x2005
ERROR: /usr/local/lib/chdkptp/lua/chdku.lua:118: attempt to index field 'apiver' (a nil value)
stack traceback:
    /usr/local/lib/chdkptp/lua/chdku.lua:118: in function 'is_ver_compatible'
    /usr/local/lib/chdkptp/lua/chdku.lua:627: in function </usr/local/lib/chdkptp/lua/chdku.lua:609>
    (tail call): ?
    /usr/local/lib/chdkptp/lua/cli.lua:596: in function </usr/local/lib/chdkptp/lua/cli.lua:593>
    (tail call): ?
    (tail call): ?
    [C]: in function 'xpcall'
    /usr/local/lib/chdkptp/lua/cli.lua:239: in function 'execute'
    /usr/local/lib/chdkptp/lua/main.lua:191: in function 'do_execute_option'
    /usr/local/lib/chdkptp/lua/main.lua:211: in function 'do_no_gui_startup'
    /usr/local/lib/chdkptp/lua/main.lua:227: in main chunk
    [C]: in function 'require'
    [string "require('main')"]:1: in main chunk
error
markvdb commented 10 years ago

00:15:55 < jbaiter> markvandenborre: did you update chdkptp or the chdk on the camera? 00:16:27 < jbaiter> looks like either the chdkptp lua code expects a newer firmware version or you have a newer firmware version that removes a field that chdkptp expects 00:16:45 < jbaiter> ERROR: /usr/local/lib/chdkptp/lua/chdku.lua:118: attempt to index field 'apiver' (a nil value) 00:16:50 < jbaiter> that's the root cause

markvdb commented 10 years ago

This was a mismatch between chdkptp 468 and a recent chdk release. Solved by updating chdkptp in the pi image to the most recent binary release.