openpaperwork / paperwork

Personal document manager (Linux/Windows) -- Moved to Gnome's Gitlab
https://gitlab.gnome.org/World/OpenPaperwork/paperwork
2.43k stars 149 forks source link

UI become unusable after "Device is busy" exception from pyinsane. #155

Closed matclab closed 11 years ago

matclab commented 11 years ago

The scanning failed with the following stack trace and the UI become unresponsive (no button is working).

Action: [Scan a single page]
Worker Scanning page: 0 ; False
Workers: Queueing [Scanning page]
Workers: [Scanning page] started
Workers: [Progress bar updater: main window progress bar] started
Scanner mode set to 'Color'
Warning: Unable to set scanner source to 'Auto': <class 'pyinsane.rawapi.SaneStatus'> : Data is invalid (4)
Workers: [Scanning page] ended
Worker [Scanning page] raised an exception: <class 'pyinsane.rawapi.SaneStatus'> : Device is busy. Try again later (3)
Traceback (most recent call last):
  File "/usr/lib/python2.7/site-packages/paperwork/frontend/workers.py", line 47, in run
    worker._wrapper(**kwargs)
  File "/usr/lib/python2.7/site-packages/paperwork/frontend/workers.py", line 154, in _wrapper
    self.__last_ret_value = BasicWorker._wrapper(self, **kwargs)
  File "/usr/lib/python2.7/site-packages/paperwork/frontend/workers.py", line 105, in _wrapper
    return self.do(**kwargs)
  File "/usr/lib/python2.7/site-packages/paperwork/frontend/mainwindow.py", line 657, in do
    doc.scan_single_page(scan_src, scanner.options['resolution'].value,
  File "/usr/lib/python2.7/site-packages/pyinsane/abstract_th.py", line 108, in _get_value
    return SaneAction(self._abstract_opt._get_value).wait()
  File "/usr/lib/python2.7/site-packages/pyinsane/abstract_th.py", line 34, in wait
    raise self.exception
SaneException: <class 'pyinsane.rawapi.SaneStatus'> : Device is busy. Try again later (3)
matclab commented 11 years ago

In fact I got this exception every time with a Canon Lide 30 scanner

Device found: [Canon LiDE 35/40/50] -> [genesys:libusb:004:013]
Got value [['Canon LiDE 35/40/50', 'genesys:libusb:004:013']]
 Workers: [Device finder] endedSelect scanner: 0
jaesivsm commented 11 years ago

I also get this exception with a Canon LiDE 110.

The test scan in the option menu works fine though.

jflesch commented 11 years ago

Note to myself: I can probably reproduce this issue by starting a scan with simple-scan and then try to start a scan with Paperwork at the same time.

jflesch commented 11 years ago

Hmmm. Do you get this exception every time, or just the second time you scan something in Paperwork ? (calibration scan in the settings window included)

jaesivsm commented 11 years ago

I get it every time. Even after a successful scan done in the settings window.

In both case I get an error tough :

ERROR  paperwork.frontend.settingswindow Warning: Unable to set scanner source to 'Auto': <class 'pyinsane.rawapi.SaneStatus'> : Data is invalid (4)
jaesivsm commented 11 years ago

Hi again. I tried again with a more recent version of both paperwork and pyinsane and I got a more verbose output. I thought it might be useful to paste it here :

ERROR  paperwork.frontend.mainwindow  Warning: Unable to set scanner source to 'Auto': <class 'pyinsane.rawapi.SaneStatus'> : Data is invalid (4)
ERROR  paperwork.frontend.jobs        ===> Job SingleScan:0 raised an exception: <class 'pyinsane.rawapi.SaneException'>: <class 'pyinsane.rawapi.SaneStatus'> : Device is busy. Try again later (3)
ERROR  paperwork.frontend.mainwindow  Error while scanning: <class 'pyinsane.rawapi.SaneStatus'> : Device is busy. Try again later (3)
ERROR  paperwork.frontend.jobs         0:              jobs.py: L  155: _run
ERROR  paperwork.frontend.jobs         1:        mainwindow.py: L 1136: do
ERROR  paperwork.frontend.jobs         2:       abstract_th.py: L  108: _get_value
ERROR  paperwork.frontend.jobs         3:       abstract_th.py: L   34: wait
ERROR  paperwork.frontend.jobs        ---> Job SingleScan:0 was started by:
ERROR  paperwork.frontend.jobs         0:          launcher.py: L   27: <module>
ERROR  paperwork.frontend.jobs         1:         paperwork.py: L   98: main
ERROR  paperwork.frontend.jobs         2:             types.py: L   43: function
ERROR  paperwork.frontend.jobs         3:           actions.py: L   59: on_menuitem_activate_cb
ERROR  paperwork.frontend.jobs         4:           actions.py: L   53: __do
ERROR  paperwork.frontend.jobs         5:        mainwindow.py: L 1738: do
ERROR  paperwork.frontend.jobs         6:              jobs.py: L  235: schedule
WARNING paperwork.frontend.jobs        Job SingleScan:0 took 33356ms and is unstoppable ! (maximum allowed: 500ms)

Sorry for the spam if it wasn't useful and congratulations on the good work !

jflesch commented 11 years ago

That's weird, the error "Device is busy" happened while trying to read the option 'resolution' of your scanner.

jaesivsm commented 11 years ago

Well if I can perform some more test I'd be happy to. On the plus side, it is to be noted that the UI isn't blocked anymore, I don't have to kill the process once the error occurred.

jflesch commented 11 years ago

Sorry, I haven't had time to work on this issue yet. Up to now, I was working on #188. I'll see if I can have a look at it this week-end.

jflesch commented 11 years ago

Hm, by the way, I forgot to ask you something : I assume other scanning tools (like simple-scan for instance) work fine ?

jaesivsm commented 11 years ago

Yeah, I did the test without mentioning it, but indeed, simple-scan works fine.

jflesch commented 11 years ago

Also, if it's ok with you, I would be curious to know the output of the following scripts:

$ git clone http://github.com/jflesch/pyinsane.git
$ cd pyinsane
# turn your scanner on
$ ./list_all.py  # should give various informations regarding your scanner
$ ./scan.py /dev/null  # will do a test scan and throw away the output image

Thanks in advance,

jaesivsm commented 11 years ago

list_all.py actually raises an exception.

$ ./list_all.py 

Scanner 'genesys:libusb:001:004' (Canon, LiDE 110, flatbed scanner)
  Option: threshold-curve
    Title: Threshold curve
    Desc: Dynamic threshold curve, from light to dark, normally 50-65
    Type: <class 'src.rawapi.SaneValueType'> : Integer (1)
    Unit: <class 'src.rawapi.SaneUnit'> : None (0)
    Size: 4
    Capabilities: <class 'src.rawapi.SaneCapabilities'> :[ Soft_select, Soft_detect,]
    Constraint type: <class 'src.rawapi.SaneConstraintType'> : Range (1)
    Constraint: (0, 127, 1)
    Value: 50
  Option: disable-dynamic-lineart
    Title: Disable dynamic lineart
    Desc: Disable use of a software adaptive algorithm to generate lineart relying instead on hardware lineart.
    Type: <class 'src.rawapi.SaneValueType'> : Boolean (0)
    Unit: <class 'src.rawapi.SaneUnit'> : None (0)
    Size: 4
    Capabilities: <class 'src.rawapi.SaneCapabilities'> :[ Soft_select, Soft_detect,]
    Constraint type: <class 'src.rawapi.SaneConstraintType'> : None (0)
    Constraint: None
    Value: 0
  Option: disable-interpolation
    Title: Disable interpolation
    Desc: When using high resolutions where the horizontal resolution is smaller than the vertical resolution this disables horizontal interpolation.
    Type: <class 'src.rawapi.SaneValueType'> : Boolean (0)
    Unit: <class 'src.rawapi.SaneUnit'> : None (0)
    Size: 4
    Capabilities: <class 'src.rawapi.SaneCapabilities'> :[ Soft_select, Soft_detect,]
    Constraint type: <class 'src.rawapi.SaneConstraintType'> : None (0)
    Constraint: None
    Value: 0
  Option: scan
    Title: Scan button
    Desc: Scan button
    Type: <class 'src.rawapi.SaneValueType'> : Boolean (0)
    Unit: <class 'src.rawapi.SaneUnit'> : None (0)
    Size: 4
    Capabilities: <class 'src.rawapi.SaneCapabilities'> :[ Hard_select, Soft_detect, Advanced,]
    Constraint type: <class 'src.rawapi.SaneConstraintType'> : None (0)
    Constraint: None
    Value: 0
  Option: tl-y
    Title: Top-left y
    Desc: Top-left y position of scan area.
    Type: <class 'src.rawapi.SaneValueType'> : Fixed (2)
    Unit: <class 'src.rawapi.SaneUnit'> : Mm (3)
    Size: 4
    Capabilities: <class 'src.rawapi.SaneCapabilities'> :[ Soft_select, Soft_detect,]
    Constraint type: <class 'src.rawapi.SaneConstraintType'> : Range (1)
    Constraint: (0, 19660800, 0)
    Value: 0
  Option: tl-x
    Title: Top-left x
    Desc: Top-left x position of scan area.
    Type: <class 'src.rawapi.SaneValueType'> : Fixed (2)
    Unit: <class 'src.rawapi.SaneUnit'> : Mm (3)
    Size: 4
    Capabilities: <class 'src.rawapi.SaneCapabilities'> :[ Soft_select, Soft_detect,]
    Constraint type: <class 'src.rawapi.SaneConstraintType'> : Range (1)
    Constraint: (0, 14011596, 0)
    Value: 0
  Option: ocr
    Title: OCR button
    Desc: OCR button
    Type: <class 'src.rawapi.SaneValueType'> : Boolean (0)
    Unit: <class 'src.rawapi.SaneUnit'> : None (0)
    Size: 4
    Capabilities: <class 'src.rawapi.SaneCapabilities'> :[ Inactive,]
    Constraint type: <class 'src.rawapi.SaneConstraintType'> : None (0)
    Constraint: None
Traceback (most recent call last):
  File "./list_all.py", line 19, in <module>
    print "    Value: %s" % (str(opt.value))
  File "/tmp/pyinsane/src/abstract.py", line 73, in _get_value
    return rawapi.sane_get_option_value(sane_dev_handle[1], self.idx)
  File "/tmp/pyinsane/src/rawapi.py", line 586, in sane_get_option_value
    raise SaneException(SaneStatus(status))
src.rawapi.SaneException: <class 'src.rawapi.SaneStatus'> : Data is invalid (4)

scan.py on the other hand works fine.

$ ./scan.py /dev/null

Output file: /dev/null
Looking for scanners ...
Devices detected:
- Scanner 'genesys:libusb:001:004' (Canon, LiDE 110, flatbed scanner)

Will use: Scanner 'genesys:libusb:001:004' (Canon, LiDE 110, flatbed scanner)

Setting resolution to 300
Setting source to Auto
Failed to set source to Auto: <class 'src.rawapi.SaneStatus'> : Data is invalid (4)
Setting mode to Color

Scanning ...  

Writing output file ...
Done
jflesch commented 11 years ago

Hm, that's weird. It seems the only problem here is that it's not possible to read back the resolution set on your scanner. In this case, it's actually not really a problem, since Paperwork can simply use the resolution defined in its configuration. (it's slightly less reliable, since the scanner may have rejected this resolution previsously, but I assume it will be a good-enough fix).

I've pushed a fix on the branch testing : c007dfe4925818a1d65704c220d644f4ff75718c . Can you test it please ?

jaesivsm commented 11 years ago

I think I get the same error :

ERROR  paperwork.frontend.mainwindow  Warning: Unable to set scanner source to 'Auto': <class 'pyinsane.rawapi.SaneStatus'> : Data is invalid (4)
ERROR  paperwork.frontend.jobs        ===> Job SingleScan:0 raised an exception: <type 'exceptions.TypeError'>: not enough arguments for format string
ERROR  paperwork.frontend.mainwindow  Error while scanning: not enough arguments for format string
ERROR  paperwork.frontend.jobs         0:              jobs.py: L  155: _run
ERROR  paperwork.frontend.jobs         1:        mainwindow.py: L 1142: do
ERROR  paperwork.frontend.jobs        ---> Job SingleScan:0 was started by:
ERROR  paperwork.frontend.jobs         0:          launcher.py: L   27: <module>
ERROR  paperwork.frontend.jobs         1:         paperwork.py: L   98: main
ERROR  paperwork.frontend.jobs         2:             types.py: L   43: function
ERROR  paperwork.frontend.jobs         3:           actions.py: L   59: on_menuitem_activate_cb
ERROR  paperwork.frontend.jobs         4:           actions.py: L   53: __do
ERROR  paperwork.frontend.jobs         5:        mainwindow.py: L 1745: do
ERROR  paperwork.frontend.jobs         6:              jobs.py: L  235: schedule
WARNING paperwork.frontend.jobs        Job SingleScan:0 took 33447ms and is unstoppable ! (maximum allowed: 500ms)
jflesch commented 11 years ago

Oops, my bad. Fixed by 19c3aead7243f0b6384a7e130ff7dbae043f1200 Can you try again please ? (I'm sorry but I can hardly test this piece of code since I don't have the same scanner than you, so it may require a few more tests)

jaesivsm commented 11 years ago

I don't mind doing the testing. This time I got this and it froze.

INFO   paperwork.frontend.actions     Action: [Scan a single page]
INFO   paperwork.backend.config       Scanner mode set to 'Color'
ERROR  paperwork.frontend.mainwindow  Warning: Unable to set scanner source to 'Auto': <class 'pyinsane.rawapi.SaneStatus'> : Data is invalid (4)
WARNING paperwork.frontend.mainwindow  Failed to read the resolution set on the scanner: <class 'pyinsane.rawapi.SaneStatus'> : Device is busy. Try again later (3). Assuming 2400
jflesch commented 11 years ago

You scan with a resolution of 2400 ?! Is it really the resolution you want to use or is it a bug ? Anyway, I won't have time to do more this evening. We will see this week-end if I can do anything else. In the meantime, try scanning with a lower resolution ;) (like 300 dpi for instance)

jaesivsm commented 11 years ago

Woops, actually I remember having set this resolution a while ago but I didn't try to change it back.

Trying with a 300 one works fine. Congrats for fixing the bug and good night :)

jflesch commented 11 years ago

K, I'm going to close this issue. Please reopen if you still have problems.

jaesivsm commented 11 years ago

Hi again, I'm still having issue with my scans,

I didn't took time to look at the scan with my last tests but I just noticed that they are cut almost in half vertically. Paper work raises no serious error in the logs but I get this though :

INFO   paperwork.backend.img.page     Scanner resolution: 300
INFO   paperwork.backend.img.page     Scanner calibration: ((0, 0), (1257, 1770))
INFO   paperwork.backend.img.page     Calibration resolution: 200
INFO   root                           Cropping: (0, 0, 1885, 2655)

NB: my scans are done correctly when using simple-scan or something else.

jflesch commented 11 years ago

Looks like the calibration of your scanner is wrong. Have you tried recalibrating it in the settings dialog ?

jaesivsm commented 11 years ago

For recalibration, I need to go to the settings dialog, do a scan, adjust the blue box over the scanned file an click "Ok", right ?

If so, I did that and it didn't help, after clicking "OK", paperwork says Writing /home/jaes/.config/paperwork.conf ... and the file contains :

[Scanner]
device = genesys:libusb:001:003
resolution = 300
scantimecalibration = 16.4924499989
calibration_pt_a_x = 0
calibration_pt_a_y = 0
calibration_pt_b_x = 1258
calibration_pt_b_y = 1770
scantime = 27.2765829563

but the scans are still weirdly cropped.

jflesch commented 11 years ago

For recalibration, I need to go to the settings dialog, do a scan, adjust the blue box over the scanned file an click "Ok", right ?

Yep.

Hm, I'm wondering: Paperwork tries to do the calibration scan with a resolution of 200dpi. Is this resolution available with your scanner ? Also, can you send me again the output of the script ./list_all.py (from pyinsane) ? Because last time, there was an exception so the output was incomplete.

jaesivsm commented 11 years ago

Here you go the for the output of the list_all.py command : https://gist.github.com/jaesivsm/5896009

About the 200dpi resolution, it doesn't appear in the list in the settings window (nor in the simple-scan settings window) so I'd say no.

jflesch commented 11 years ago

Yep, I think it's the problem.

/me get his coke out of the fridge ... let's roll ...

jflesch commented 11 years ago

I've pushed a fix in the testing branch. You'll have to redo a calibration scan in order for it to work. Please tell me if it works for you.

jaesivsm commented 11 years ago

Works fine now. Thanks !

jflesch commented 11 years ago

Awesome. I'm going to close this ticket. Please reopen if you still have problems with your scanner.