search

gphoto / gphoto2

The gphoto2 commandline tool for accessing and controlling digital cameras.
GNU General Public License v2.0
720 stars 116 forks source link

Canon camera only takes picture first time #538

Closed michilehr closed 1 year ago

michilehr commented 2 years ago

Describe the bug

I am not able to take a picture after the first one. When I try to take a second picture by running gphoto2 --capture-image, I get following error:

*** Error ***
Canon EOS Full-Press failed (0x2019: PTP Device Busy)
ERROR: Could not capture image.
ERROR: Could not capture.
*** Error (-110: 'I/O in progress') ***

Name the camera

Model                          Port
----------------------------------------------------------
Canon EOS 1500D                usb:001,006

libgphoto2 and gphoto2 version

gphoto2 2.5.27

Copyright (c) 2000-2021 Marcus Meissner and others

gphoto2 comes with NO WARRANTY, to the extent permitted by law. You may
redistribute copies of gphoto2 under the terms of the GNU General Public
License. For more information about these matters, see the files named COPYING.

This version of gphoto2 is using the following software versions and options:
gphoto2         2.5.27         gcc, popt(m), exif, cdk, aa, jpeg, readline
libgphoto2      2.5.27         standard camlibs, gcc, ltdl, EXIF
libgphoto2_port 0.12.0         iolibs: disk ptpip serial usb1 usbdiskdirect usbscsi, gcc, ltdl, EXIF, USB, serial without locking

To Reproduce Please see description

michilehr commented 2 years ago

Now I have following error:

*** Error ***
Canon EOS Full-Press failed (0x2019: PTP Device Busy)
ERROR: Could not capture image.
ERROR: Could not capture.
*** Error (-110: 'I/O in progress') ***

When I run --debug, I have following error in the log:

2.698714 camera_trigger_canon_eos_capture [library.c:5924](0): no focus info?

I have updated gphoto2 to the lastest version:

gphoto2 2.5.28

Copyright (c) 2000-2021 Marcus Meissner and others

gphoto2 comes with NO WARRANTY, to the extent permitted by law. You may
redistribute copies of gphoto2 under the terms of the GNU General Public
License. For more information about these matters, see the files named COPYING.

This version of gphoto2 is using the following software versions and options:
gphoto2         2.5.28         gcc, popt(m), exif, no cdk, no aa, jpeg, no readline
libgphoto2      2.5.30         standard camlibs (SKIPPING docupen lumix), gcc, no ltdl, EXIF
libgphoto2_port 0.12.1         iolibs: disk ptpip serial usb1 usbdiskdirect usbscsi, gcc, no ltdl, EXIF, USB, serial without locking
jesswhyte commented 2 years ago

I also have this issue, Ubuntu 20.04 gphoto2 2.5.28 gcc, popt(m), exif, no cdk, no aa, jpeg, readline libgphoto2 2.5.30 standard camlibs (SKIPPING docupen), gcc, no ltdl, EXIF libgphoto2_port 0.12.1 iolibs: disk ptpip serial usb1 usbdiskdirect usbscsi, gcc, no ltdl, EXIF, USB, serial without locking

Canon EOS 1500D

Happens after first photo, even when using --debug:

Error
PTP Timeout

Error
An error occurred in the io-library ('Timeout reading from or writing to the port'): No error description available ERROR: Could not capture image. ERROR: Could not capture.

Error
PTP Timeout

Error
An error occurred in the io-library ('Timeout reading from or writing to the port'): No error description available

msmeissn commented 2 years ago

This might be a timing / delay issue :/

@michilehr can you capture a debug trace of this success full run and attach it here?

Does it also happen when you save to logfile directly via --debug --debug-logfile=debug.log ?

michilehr commented 1 year ago

Hello @msmeissn, sorry for the delay.

Please find attached a debug-success-logand a debug-error.log. I have removed some binary date - otherwise the log would be to hugh to be uploaded (38MB).

I am running gphoto2 with the following command:

gphoto2 --reset; gphoto2 -D && gphoto2 --wait-event=1 --capture-image-and-download --force-overwrite --port "usb:001" --camera "USB PTP Class Camera" --filename="lala.jpg" --no-keep --debug --debug-logfile=debug.log

Versions:

gphoto2 2.5.28

Copyright (c) 2000-2021 Marcus Meissner and others

gphoto2 comes with NO WARRANTY, to the extent permitted by law. You may
redistribute copies of gphoto2 under the terms of the GNU General Public
License. For more information about these matters, see the files named COPYING.

This version of gphoto2 is using the following software versions and options:
gphoto2         2.5.28         gcc, popt(m), exif, no cdk, no aa, jpeg, no readline
libgphoto2      2.5.30         standard camlibs (SKIPPING docupen lumix), gcc, no ltdl, EXIF
libgphoto2_port 0.12.1         iolibs: disk ptpip serial usb1 usbdiskdirect usbscsi, gcc, no ltdl, EXIF, USB, serial without locking

Please let me know if you need further information and thanks again for having a look!

debug-success.log debug-error.log

michilehr commented 1 year ago

@msmeissn any chance to get any help on the issue soon? I also wrote you an email before Christmas if you were open to help us in another way. Please let me know.

msmeissn commented 1 year ago

SO the difference is that the first logfile has successful focusing, the second logfile does not focus within 2 seconds and so the full release fails.

I assume afterwards the camera always reports busy?

I added a fix to current libgphoto2 GIT that does undoes the half-press on error for the full press.

Can you try building it and see if it helps?

michilehr commented 1 year ago

Thank you for your help @msmeissn !

Yes. Afterwards the camera reports always busy and only a restart of the camera fixes the issue.

I did build it and tried. Now the camera fails to take a photo after some tests.

Debug log:

0.000031 main                        (2): ALWAYS INCLUDE THE FOLLOWING LINES WHEN SENDING DEBUG MESSAGES TO THE MAILING LIST:
0.000107 main                        (2): gphoto2 2.5.28.1
0.000119 main                        (2): gphoto2 has been compiled with the following options:
0.000128 main                        (2):  + gcc (C compiler used)
0.000137 main                        (2):  + popt (mandatory, for handling command-line parameters)
0.000145 main                        (2):  + exif (for displaying EXIF information)
0.000153 main                        (2):  + no cdk (for accessing configuration options)
0.000161 main                        (2):  + no aa (for displaying live previews)
0.000169 main                        (2):  + jpeg (for displaying live previews in JPEG format)
0.000198 main                        (2):  + no readline (for easy navigation in the shell)
0.000210 main                        (2): libgphoto2 2.5.30.1
0.000225 main                        (2): libgphoto2 has been compiled with the following options:
0.000246 main                        (2):  + standard camlib set SKIPPING SOME (ax203 canon digigr8 dimagev directory jl2005a jl2005c kodak_dc240 mars pentax ptp2 ricoh_g3 sierra sonix sq905 st2205 topfield tp6801 SKIPPING docupen lumix)
0.000257 main                        (2):  + gcc (C compiler used)
0.000265 main                        (2):  + no ltdl (for portable loading of camlibs)
0.000273 main                        (2):  + EXIF (for special handling of EXIF files)
0.000282 main                        (2): libgphoto2_port 0.12.2
0.000310 main                        (2): libgphoto2_port has been compiled with the following options:
0.000319 main                        (2):  + iolibs: disk ptpip serial usb1 usbdiskdirect usbscsi
0.000327 main                        (2):  + gcc (C compiler used)
0.000334 main                        (2):  + no ltdl (for portable loading of iolibs)
0.000341 main                        (2):  + EXIF (for vusb)
0.000349 main                        (2):  + USB (libusb1, for USB cameras)
0.000357 main                        (2):  + serial (for serial cameras)
0.000364 main                        (2):  + no resmgr (serial port access and locking)
0.000372 main                        (2):  + no ttylock (serial port locking)
0.000379 main                        (2):  + no lockdev (serial port locking)
0.000388 main                        (2): CAMLIBS env var not set, using compile-time default instead
0.000396 main                        (2): IOLIBS env var not set, using compile-time default instead
0.000404 main                        (2): invoked with following arguments:
0.000412 main                        (2):   --wait-event=10
0.000420 main                        (2):   --capture-image-and-download
0.000427 main                        (2):   --force-overwrite
0.000435 main                        (2):   --filename=temp.jpg
0.000442 main                        (2):   --no-keep
0.000449 main                        (2):   --debug
0.000536 load_settings               (2): Creating gphoto config directory ('/home/pi/.gphoto')
0.000658 load_settings               (2): Loading settings from file '/home/pi/.gphoto/settings'.
0.000804 main                        (2): The user has not specified both a model and a port. Try to figure them out.
0.000823 gp_port_init_localedir      (2): localedir has been set to /usr/local/share/locale (compile-time default)
0.000836 gp_port_info_list_load      (2): Using ltdl to load io-drivers from '/usr/local/lib/libgphoto2_port/0.12.2'...
0.001009 foreach_func                (2): Called for filename '/usr/local/lib/libgphoto2_port/0.12.2/disk'.
0.001392 gp_port_library_list        (2): found fstab fstype ext4
0.001447 gp_port_library_list        (2): found fstab fstype vfat
0.001607 gp_port_library_list        (2): found mtab fstype sysfs
0.001631 gp_port_library_list        (2): found mtab fstype proc
0.001644 gp_port_library_list        (2): found mtab fstype devtmpfs
0.001677 gp_port_library_list        (2): found mtab fstype devpts
0.001691 gp_port_library_list        (2): found mtab fstype tmpfs
0.001721 gp_port_library_list        (2): found mtab fstype ext4
0.001749 gp_port_library_list        (2): found mtab fstype securityfs
0.001763 gp_port_library_list        (2): found mtab fstype tmpfs
0.001801 gp_port_library_list        (2): found mtab fstype tmpfs
0.001837 gp_port_library_list        (2): found mtab fstype cgroup2
0.001851 gp_port_library_list        (2): found mtab fstype pstore
0.001890 gp_port_library_list        (2): found mtab fstype autofs
0.001903 gp_port_library_list        (2): found mtab fstype debugfs
0.001933 gp_port_library_list        (2): found mtab fstype tracefs
0.002005 gp_port_library_list        (2): found mtab fstype mqueue
0.002025 gp_port_library_list        (2): found mtab fstype fusectl
0.002037 gp_port_library_list        (2): found mtab fstype configfs
0.002078 gp_port_library_list        (2): found mtab fstype autofs
0.002091 gp_port_library_list        (2): found mtab fstype tmpfs
0.002114 gp_port_library_list        (2): found mtab fstype tmpfs
0.002245 foreach_func                (2): Loaded '' ('^disk:') from '/usr/local/lib/libgphoto2_port/0.12.2/disk'.
0.002259 foreach_func                (2): Called for filename '/usr/local/lib/libgphoto2_port/0.12.2/ptpip'.
0.002501 foreach_func                (2): Loaded 'PTP/IP Connection' ('ptpip:') from '/usr/local/lib/libgphoto2_port/0.12.2/ptpip'.
0.002535 foreach_func                (2): Loaded '' ('^ptpip:') from '/usr/local/lib/libgphoto2_port/0.12.2/ptpip'.
0.002545 foreach_func                (2): Loaded 'IP Connection' ('ip:') from '/usr/local/lib/libgphoto2_port/0.12.2/ptpip'.
0.002555 foreach_func                (2): Loaded '' ('^ip:') from '/usr/local/lib/libgphoto2_port/0.12.2/ptpip'.
0.002563 foreach_func                (2): Called for filename '/usr/local/lib/libgphoto2_port/0.12.2/serial'.
0.003009 foreach_func                (2): Loaded 'Serial Port 0' ('serial:/dev/ttyS0') from '/usr/local/lib/libgphoto2_port/0.12.2/serial'.
0.003038 foreach_func                (2): Loaded 'Serial Port Device' ('serial:') from '/usr/local/lib/libgphoto2_port/0.12.2/serial'.
0.003049 foreach_func                (2): Loaded '' ('^serial:') from '/usr/local/lib/libgphoto2_port/0.12.2/serial'.
0.003058 foreach_func                (2): Called for filename '/usr/local/lib/libgphoto2_port/0.12.2/usb1'.
0.016901 foreach_func                (2): Loaded '' ('^usb:') from '/usr/local/lib/libgphoto2_port/0.12.2/usb1'.
0.016934 foreach_func                (2): Loaded 'Universal Serial Bus' ('usb:007,006') from '/usr/local/lib/libgphoto2_port/0.12.2/usb1'.
0.016945 foreach_func                (2): Loaded 'Universal Serial Bus' ('usb:007,005') from '/usr/local/lib/libgphoto2_port/0.12.2/usb1'.
0.016954 foreach_func                (2): Loaded 'Universal Serial Bus' ('usb:007,004') from '/usr/local/lib/libgphoto2_port/0.12.2/usb1'.
0.016968 foreach_func                (2): Loaded 'Universal Serial Bus' ('usb:007,003') from '/usr/local/lib/libgphoto2_port/0.12.2/usb1'.
0.016978 foreach_func                (2): Called for filename '/usr/local/lib/libgphoto2_port/0.12.2/usbdiskdirect'.
0.017438 foreach_func                (2): Called for filename '/usr/local/lib/libgphoto2_port/0.12.2/usbscsi'.
0.017694 gp_port_info_list_count     (2): Counting entries (13 available)...
0.017713 gp_port_info_list_count     (2): 8 regular entries available.
0.017731 gp_port_init_localedir      (2): ignoring late call (localedir value NULL)
0.017744 gp_init_localedir           (2): localedir has been set to /usr/local/share/locale (compile-time default)
0.017767 unlocked_gp_abilities_list_load_dir(2): Using ltdl to load camera libraries from '/usr/local/lib/libgphoto2/2.5.30.1'...
0.017910 foreach_func                (2): Found '/usr/local/lib/libgphoto2/2.5.30.1/ax203'.
0.017932 foreach_func                (2): Found '/usr/local/lib/libgphoto2/2.5.30.1/canon'.
0.017941 foreach_func                (2): Found '/usr/local/lib/libgphoto2/2.5.30.1/digigr8'.
0.017948 foreach_func                (2): Found '/usr/local/lib/libgphoto2/2.5.30.1/dimagev'.
0.017955 foreach_func                (2): Found '/usr/local/lib/libgphoto2/2.5.30.1/directory'.
0.017967 foreach_func                (2): Found '/usr/local/lib/libgphoto2/2.5.30.1/jl2005a'.
0.017975 foreach_func                (2): Found '/usr/local/lib/libgphoto2/2.5.30.1/jl2005c'.
0.017982 foreach_func                (2): Found '/usr/local/lib/libgphoto2/2.5.30.1/kodak_dc240'.
0.017990 foreach_func                (2): Found '/usr/local/lib/libgphoto2/2.5.30.1/mars'.
0.017997 foreach_func                (2): Found '/usr/local/lib/libgphoto2/2.5.30.1/pentax'.
0.018004 foreach_func                (2): Found '/usr/local/lib/libgphoto2/2.5.30.1/ptp2'.
0.018013 foreach_func                (2): Found '/usr/local/lib/libgphoto2/2.5.30.1/ricoh_g3'.
0.018033 foreach_func                (2): Found '/usr/local/lib/libgphoto2/2.5.30.1/sierra'.
0.018042 foreach_func                (2): Found '/usr/local/lib/libgphoto2/2.5.30.1/sonix'.
0.018051 foreach_func                (2): Found '/usr/local/lib/libgphoto2/2.5.30.1/sq905'.
0.018069 foreach_func                (2): Found '/usr/local/lib/libgphoto2/2.5.30.1/st2205'.
0.018079 foreach_func                (2): Found '/usr/local/lib/libgphoto2/2.5.30.1/topfield'.
0.018088 foreach_func                (2): Found '/usr/local/lib/libgphoto2/2.5.30.1/tp6801'.
0.018111 unlocked_gp_abilities_list_load_dir(2): Found 18 camera drivers.
0.044377 gp_port_info_list_count     (2): Counting entries (13 available)...
0.044435 gp_port_info_list_count     (2): 8 regular entries available.
0.044442 gp_port_new                 (2): Creating new device...
0.044458 gp_port_info_list_get_info  (2): Getting info of entry 0 (13 available)...
0.044792 gp_port_set_settings        (2): Setting settings...
0.044820 gp_port_info_list_get_info  (2): Getting info of entry 1 (13 available)...
0.044986 gp_port_set_settings        (2): Setting settings...
0.045007 gp_port_info_list_get_info  (2): Getting info of entry 2 (13 available)...
0.045171 gp_port_set_timeout         (2): Setting port timeout to 500 milliseconds.
0.045222 gp_port_set_settings        (2): Setting settings...
0.045232 gp_port_info_list_get_info  (2): Getting info of entry 3 (13 available)...
0.045375 gp_port_set_timeout         (2): Setting port timeout to 500 milliseconds.
0.045392 gp_port_set_settings        (2): Setting settings...
0.045399 gp_port_info_list_get_info  (2): Getting info of entry 4 (13 available)...
0.055970 gp_port_set_timeout         (2): Setting port timeout to 5000 milliseconds.
0.056008 gp_port_set_settings        (2): Setting settings...
0.056022 gp_libusb1_update           (2): (old int=0, conf=-1, alt=-1) port usb:007,006, (new int=0, conf=-1, alt=-1) port usb:007,006
0.056029 gp_libusb1_update           (2): lowlevel libusb1 port not yet opened, no need for libusb changes
0.056038 gp_abilities_list_detect_usb(2): Auto-detecting USB cameras...
0.057288 gp_libusb1_find_device_by_class_lib(2): Looking for USB device (class 0x29a, subclass, 0xffffffff, protocol 0xffffffff)...
0.058215 gp_libusb1_find_device_by_class_lib(2): Looking for USB device (class 0x6, subclass, 0x1, protocol 0x1)...
0.058356 gp_port_info_list_get_info  (2): Getting info of entry 5 (13 available)...
0.069729 gp_port_set_timeout         (2): Setting port timeout to 5000 milliseconds.
0.069763 gp_port_set_settings        (2): Setting settings...
0.069779 gp_libusb1_update           (2): (old int=0, conf=-1, alt=-1) port usb:007,005, (new int=0, conf=-1, alt=-1) port usb:007,005
0.069786 gp_libusb1_update           (2): lowlevel libusb1 port not yet opened, no need for libusb changes
0.069795 gp_abilities_list_detect_usb(2): Auto-detecting USB cameras...
0.071030 gp_libusb1_find_device_by_class_lib(2): Looking for USB device (class 0x29a, subclass, 0xffffffff, protocol 0xffffffff)...
0.072098 gp_libusb1_find_device_by_class_lib(2): Looking for USB device (class 0x6, subclass, 0x1, protocol 0x1)...
0.072244 gp_port_info_list_get_info  (2): Getting info of entry 6 (13 available)...
0.083309 gp_port_set_timeout         (2): Setting port timeout to 5000 milliseconds.
0.083342 gp_port_set_settings        (2): Setting settings...
0.083358 gp_libusb1_update           (2): (old int=0, conf=-1, alt=-1) port usb:007,004, (new int=0, conf=-1, alt=-1) port usb:007,004
0.083365 gp_libusb1_update           (2): lowlevel libusb1 port not yet opened, no need for libusb changes
0.083374 gp_abilities_list_detect_usb(2): Auto-detecting USB cameras...
0.083724 gp_libusb1_find_device_lib  (2): Looking for USB device (vendor 0x4a9, product 0x32e1)... found.
0.083863 gp_libusb1_find_device_lib  (2): Detected defaults: config 1, interface 0, altsetting 0, inep 81, outep 02, intep 83, class 06, subclass 01
0.083879 gp_abilities_list_detect_usb(2): Found 'Canon EOS 1500D' (0x4a9,0x32e1)
0.083998 gp_port_info_list_get_info  (2): Getting info of entry 7 (13 available)...
0.094873 gp_port_set_timeout         (2): Setting port timeout to 5000 milliseconds.
0.094906 gp_port_set_settings        (2): Setting settings...
0.094921 gp_libusb1_update           (2): (old int=0, conf=-1, alt=-1) port usb:007,003, (new int=0, conf=-1, alt=-1) port usb:007,003
0.094928 gp_libusb1_update           (2): lowlevel libusb1 port not yet opened, no need for libusb changes
0.094937 gp_abilities_list_detect_usb(2): Auto-detecting USB cameras...
0.096266 gp_libusb1_find_device_by_class_lib(2): Looking for USB device (class 0x29a, subclass, 0xffffffff, protocol 0xffffffff)...
0.097216 gp_libusb1_find_device_by_class_lib(2): Looking for USB device (class 0x6, subclass, 0x1, protocol 0x1)...
0.097334 gp_port_free                (2): Freeing port...
0.097349 gp_port_close               (2): Closing port...
0.097738 gp_camera_set_abilities     (2): Setting abilities ('Canon EOS 1500D')...
0.097764 gp_setting_set              (2): Setting key 'model' to value 'Canon EOS 1500D' (gphoto2)
0.097781 save_settings               (2): Saving 3 setting(s) to file "/home/pi/.gphoto/settings"
0.098244 gp_port_info_list_lookup_path(2): Looking for path 'usb:007,004' (13 entries available)...
0.098272 gp_port_info_list_get_info  (2): Getting info of entry 6 (13 available)...
0.098288 gp_camera_set_port_info     (2): Setting port info for port 'Universal Serial Bus' at 'usb:007,004'...
0.109265 gp_port_set_timeout         (2): Setting port timeout to 5000 milliseconds.
0.109295 gp_port_set_settings        (2): Setting settings...
0.109314 gp_libusb1_update           (2): (old int=0, conf=-1, alt=-1) port usb:007,004, (new int=0, conf=-1, alt=-1) port usb:007,004
0.109326 gp_libusb1_update           (2): lowlevel libusb1 port not yet opened, no need for libusb changes
0.109341 gp_setting_set              (2): Setting key 'port' to value 'usb:007,004' (gphoto2)
0.109353 save_settings               (2): Saving 3 setting(s) to file "/home/pi/.gphoto/settings"
Waiting for 10 events from camera. Press Ctrl-C to abort.
0.109902 gp_camera_init              (2): Initializing camera...
0.109979 gp_libusb1_find_device_lib  (2): Looking for USB device (vendor 0x4a9, product 0x32e1)... found.
0.110171 gp_libusb1_find_device_lib  (2): Detected defaults: config 1, interface 0, altsetting 0, inep 81, outep 02, intep 83, class 06, subclass 01
0.110284 gp_camera_init              (2): Loading '/usr/local/lib/libgphoto2/2.5.30.1/ptp2'...
0.111902 gp_port_open                (2): Opening USB port...
0.111937 gp_libusb1_open             (2): ()
0.112029 gp_libusb1_open             (2): claiming interface 0
0.112297 camera_init                 (2): maxpacketsize 512
0.112330 gp_port_set_timeout         (2): Setting port timeout to 1500 milliseconds.
0.112363 ptp                         (2): PTP: Opening session
0.112383 ptp_usb_sendreq             (2): Sending PTP_OC 0x1002 (Open session) (0x1) request...
0.112392 gp_port_write               (3): Writing 16 = 0x10 bytes to port...
0.112624 gp_port_write               (3): Wrote   16 = 0x10 bytes to port: (hexdump of 16 bytes)
0000  10 00 00 00 01 00 02 10-00 00 00 00 01 00 00 00  ................

0.112645 ptp_usb_getresp             (2): Reading PTP_OC 0x1002 (Open session) response...
0.112661 gp_port_read                (3): Reading 1024 = 0x400 bytes from port...
1.613825 gp_libusb1_read [libusb1.c:592](0): 'libusb_bulk_transfer (port->pl->dh, port->settings.usb.inep, (unsigned char*)bytes, size, &curread, port->timeout)' failed: Operation timed out (-7)
1.613977 gp_port_read [gphoto2-port.c:440](0): Reading 1024 = 0x400 bytes from port failed: Timeout reading from or writing to the port (-10)
1.614069 ptp_usb_getresp [usb.c:516] (0): PTP_OC 0x1002 receiving resp failed: PTP I/O Error (0x02ff)
1.614136 camera_init [library.c:9807](0): 'ptp_opensession (params, sessionid)' failed: PTP I/O Error (0x02ff)
1.614161 ptp_usb_control_device_reset_request(2): Sending usb device reset request.
1.614351 gp_port_usb_msg_class_write (3): Writing message (request=0x66 value=0x0 index=0x0 size=0=0x0): (no hexdump, NULL buffer)
1.615602 ptp                         (2): PTP: Opening session
1.615787 ptp_usb_sendreq             (2): Sending PTP_OC 0x1002 (Open session) (0x1) request...
1.615929 gp_port_write               (3): Writing 16 = 0x10 bytes to port...
1.616267 gp_port_write               (3): Wrote   16 = 0x10 bytes to port: (hexdump of 16 bytes)
0000  10 00 00 00 01 00 02 10-00 00 00 00 01 00 00 00  ................

1.616324 ptp_usb_getresp             (2): Reading PTP_OC 0x1002 (Open session) response...
1.616361 gp_port_read                (3): Reading 1024 = 0x400 bytes from port...
3.116922 gp_libusb1_read [libusb1.c:592](0): 'libusb_bulk_transfer (port->pl->dh, port->settings.usb.inep, (unsigned char*)bytes, size, &curread, port->timeout)' failed: Operation timed out (-7)
3.117046 gp_port_read [gphoto2-port.c:440](0): Reading 1024 = 0x400 bytes from port failed: Timeout reading from or writing to the port (-10)
3.117100 ptp_usb_getresp [usb.c:516] (0): PTP_OC 0x1002 receiving resp failed: PTP I/O Error (0x02ff)
3.117145 camera_init [library.c:9807](0): 'ptp_opensession (params, sessionid)' failed: PTP I/O Error (0x02ff)
3.117276 ptp_usb_control_device_reset_request(2): Sending usb device reset request.
3.117329 gp_port_usb_msg_class_write (3): Writing message (request=0x66 value=0x0 index=0x0 size=0=0x0): (no hexdump, NULL buffer)
3.118337 ptp                         (2): PTP: Opening session
3.118421 ptp_usb_sendreq             (2): Sending PTP_OC 0x1002 (Open session) (0x1) request...
3.118459 gp_port_write               (3): Writing 16 = 0x10 bytes to port...
4.618912 gp_libusb1_write [libusb1.c:578](0): 'libusb_bulk_transfer (port->pl->dh, port->settings.usb.outep, (unsigned char*)bytes, size, &curwritten, port->timeout)' failed: Operation timed out (-7)
4.619037 gp_port_write [gphoto2-port.c:405](0): Writing 16 = 0x10 bytes to port failed: Timeout reading from or writing to the port (-10)
4.619108 ptp_usb_sendreq [usb.c:109] (0): PTP_OC 0x1002 sending req failed: Timeout reading from or writing to the port (-10)
4.619160 camera_init [library.c:9807](0): 'ptp_opensession (params, sessionid)' failed: PTP Timeout (0x02fa)
4.619280 camera_init [library.c:9835](0): 'ret' failed: 'PTP Timeout' (0x02fa)
4.619378 gp_context_error            (0): PTP Timeout

*** Error ***
PTP Timeout
4.619479 gp_port_close               (2): Closing port...
4.620705 _close_async_interrupts     (2): canceling transfer 0:0x55a1e57460 (status 0)
4.621345 _close_async_interrupts     (2): canceling transfer 1:0x55a1e5a700 (status 0)
4.621783 _close_async_interrupts     (2): canceling transfer 2:0x55a1e58730 (status 0)
4.622408 _close_async_interrupts     (2): canceling transfer 3:0x55a1e581e0 (status 0)
4.622814 _close_async_interrupts     (2): canceling transfer 4:0x55a1e4efb0 (status 0)
4.623246 _close_async_interrupts     (2): canceling transfer 5:0x55a1e5b6d0 (status 0)
4.623700 _close_async_interrupts     (2): canceling transfer 6:0x55a1e4c1e0 (status 0)
4.624094 _close_async_interrupts     (2): canceling transfer 7:0x55a1e4dd10 (status 0)
4.624337 _close_async_interrupts     (2): canceling transfer 8:0x55a1e49ea0 (status 0)
4.624712 _close_async_interrupts     (2): canceling transfer 9:0x55a1e69720 (status 0)
4.625137 _cb_irq                     (2): 0x55a1e57460 with status 3
4.625242 _cb_irq                     (2): Transfer 0x55a1e57460 should be in LIBUSB_TRANSFER_COMPLETED, but is 3!
4.625356 _cb_irq                     (2): 0x55a1e5a700 with status 3
4.625392 _cb_irq                     (2): Transfer 0x55a1e5a700 should be in LIBUSB_TRANSFER_COMPLETED, but is 3!
4.625441 _cb_irq                     (2): 0x55a1e58730 with status 3
4.625473 _cb_irq                     (2): Transfer 0x55a1e58730 should be in LIBUSB_TRANSFER_COMPLETED, but is 3!
4.625519 _cb_irq                     (2): 0x55a1e581e0 with status 3
4.625552 _cb_irq                     (2): Transfer 0x55a1e581e0 should be in LIBUSB_TRANSFER_COMPLETED, but is 3!
4.625596 _cb_irq                     (2): 0x55a1e4efb0 with status 3
4.625628 _cb_irq                     (2): Transfer 0x55a1e4efb0 should be in LIBUSB_TRANSFER_COMPLETED, but is 3!
4.625714 _cb_irq                     (2): 0x55a1e5b6d0 with status 3
4.625750 _cb_irq                     (2): Transfer 0x55a1e5b6d0 should be in LIBUSB_TRANSFER_COMPLETED, but is 3!
4.625841 _cb_irq                     (2): 0x55a1e4c1e0 with status 3
4.625875 _cb_irq                     (2): Transfer 0x55a1e4c1e0 should be in LIBUSB_TRANSFER_COMPLETED, but is 3!
4.625920 _cb_irq                     (2): 0x55a1e4dd10 with status 3
4.625952 _cb_irq                     (2): Transfer 0x55a1e4dd10 should be in LIBUSB_TRANSFER_COMPLETED, but is 3!
4.625999 _cb_irq                     (2): 0x55a1e49ea0 with status 3
4.626031 _cb_irq                     (2): Transfer 0x55a1e49ea0 should be in LIBUSB_TRANSFER_COMPLETED, but is 3!
4.626077 _cb_irq                     (2): 0x55a1e69720 with status 3
4.626109 _cb_irq                     (2): Transfer 0x55a1e69720 should be in LIBUSB_TRANSFER_COMPLETED, but is 3!
4.627021 gp_context_error            (0): An error occurred in the io-library ('Timeout reading from or writing to the port'): No error description available

*** Error ***
An error occurred in the io-library ('Timeout reading from or writing to the port'): No error description available
4.627176 gp_camera_init              (2): Initializing camera...
4.627474 gp_libusb1_find_device_lib  (2): Looking for USB device (vendor 0x4a9, product 0x32e1)... found.
4.627918 gp_libusb1_find_device_lib  (2): Detected defaults: config 1, interface 0, altsetting 0, inep 81, outep 02, intep 83, class 06, subclass 01
4.627965 gp_camera_init              (2): Loading '/usr/local/lib/libgphoto2/2.5.30.1/ptp2'...
4.631542 gp_port_open                (2): Opening USB port...
4.631612 gp_libusb1_open             (2): ()
4.631792 gp_libusb1_open             (2): claiming interface 0
4.632501 camera_init                 (2): maxpacketsize 512
4.632590 gp_port_set_timeout         (2): Setting port timeout to 1500 milliseconds.
4.632694 ptp                         (2): PTP: Opening session
4.632749 ptp_usb_sendreq             (2): Sending PTP_OC 0x1002 (Open session) (0x1) request...
4.632789 gp_port_write               (3): Writing 16 = 0x10 bytes to port...
6.133533 gp_libusb1_write [libusb1.c:578](0): 'libusb_bulk_transfer (port->pl->dh, port->settings.usb.outep, (unsigned char*)bytes, size, &curwritten, port->timeout)' failed: Operation timed out (-7)
6.133660 gp_port_write [gphoto2-port.c:405](0): Writing 16 = 0x10 bytes to port failed: Timeout reading from or writing to the port (-10)
6.133738 ptp_usb_sendreq [usb.c:109] (0): PTP_OC 0x1002 sending req failed: Timeout reading from or writing to the port (-10)
6.133841 camera_init [library.c:9807](0): 'ptp_opensession (params, sessionid)' failed: PTP Timeout (0x02fa)
6.133874 ptp                         (2): PTP: Opening session
6.133916 ptp_usb_sendreq             (2): Sending PTP_OC 0x1002 (Open session) (0x1) request...
6.133950 gp_port_write               (3): Writing 16 = 0x10 bytes to port...
7.634505 gp_libusb1_write [libusb1.c:578](0): 'libusb_bulk_transfer (port->pl->dh, port->settings.usb.outep, (unsigned char*)bytes, size, &curwritten, port->timeout)' failed: Operation timed out (-7)
7.634632 gp_port_write [gphoto2-port.c:405](0): Writing 16 = 0x10 bytes to port failed: Timeout reading from or writing to the port (-10)
7.634684 ptp_usb_sendreq [usb.c:109] (0): PTP_OC 0x1002 sending req failed: Timeout reading from or writing to the port (-10)
7.634735 camera_init [library.c:9807](0): 'ptp_opensession (params, sessionid)' failed: PTP Timeout (0x02fa)
7.634767 ptp                         (2): PTP: Opening session
7.634808 ptp_usb_sendreq             (2): Sending PTP_OC 0x1002 (Open session) (0x1) request...
7.634842 gp_port_write               (3): Writing 16 = 0x10 bytes to port...
9.135466 gp_libusb1_write [libusb1.c:578](0): 'libusb_bulk_transfer (port->pl->dh, port->settings.usb.outep, (unsigned char*)bytes, size, &curwritten, port->timeout)' failed: Operation timed out (-7)
9.135590 gp_port_write [gphoto2-port.c:405](0): Writing 16 = 0x10 bytes to port failed: Timeout reading from or writing to the port (-10)
9.135642 ptp_usb_sendreq [usb.c:109] (0): PTP_OC 0x1002 sending req failed: Timeout reading from or writing to the port (-10)
9.135693 camera_init [library.c:9807](0): 'ptp_opensession (params, sessionid)' failed: PTP Timeout (0x02fa)
9.135735 camera_init [library.c:9835](0): 'ret' failed: 'PTP Timeout' (0x02fa)
9.135840 gp_context_error            (0): PTP Timeout

*** Error ***
PTP Timeout
9.135917 gp_port_close               (2): Closing port...
9.137071 _close_async_interrupts     (2): canceling transfer 0:0x55a1e57460 (status 0)
9.137599 _close_async_interrupts     (2): canceling transfer 1:0x55a1e5a700 (status 0)
9.138000 _close_async_interrupts     (2): canceling transfer 2:0x55a1e58730 (status 0)
9.138427 _close_async_interrupts     (2): canceling transfer 3:0x55a1e4c1e0 (status 0)
9.138913 _close_async_interrupts     (2): canceling transfer 4:0x55a1e4dd10 (status 0)
9.139347 _close_async_interrupts     (2): canceling transfer 5:0x55a1e60ac0 (status 0)
9.139741 _close_async_interrupts     (2): canceling transfer 6:0x55a1e61200 (status 0)
9.140132 _close_async_interrupts     (2): canceling transfer 7:0x55a1e54fe0 (status 0)
9.140376 _close_async_interrupts     (2): canceling transfer 8:0x55a1e55d70 (status 0)
9.140808 _close_async_interrupts     (2): canceling transfer 9:0x55a1e639c0 (status 0)
9.141048 _cb_irq                     (2): 0x55a1e57460 with status 3
9.141109 _cb_irq                     (2): Transfer 0x55a1e57460 should be in LIBUSB_TRANSFER_COMPLETED, but is 3!
9.141221 _cb_irq                     (2): 0x55a1e5a700 with status 3
9.141258 _cb_irq                     (2): Transfer 0x55a1e5a700 should be in LIBUSB_TRANSFER_COMPLETED, but is 3!
9.141307 _cb_irq                     (2): 0x55a1e58730 with status 3
9.141340 _cb_irq                     (2): Transfer 0x55a1e58730 should be in LIBUSB_TRANSFER_COMPLETED, but is 3!
9.141386 _cb_irq                     (2): 0x55a1e4c1e0 with status 3
9.141419 _cb_irq                     (2): Transfer 0x55a1e4c1e0 should be in LIBUSB_TRANSFER_COMPLETED, but is 3!
9.141464 _cb_irq                     (2): 0x55a1e4dd10 with status 3
9.141496 _cb_irq                     (2): Transfer 0x55a1e4dd10 should be in LIBUSB_TRANSFER_COMPLETED, but is 3!
9.141541 _cb_irq                     (2): 0x55a1e60ac0 with status 3
9.141590 _cb_irq                     (2): Transfer 0x55a1e60ac0 should be in LIBUSB_TRANSFER_COMPLETED, but is 3!
9.141638 _cb_irq                     (2): 0x55a1e61200 with status 3
9.141670 _cb_irq                     (2): Transfer 0x55a1e61200 should be in LIBUSB_TRANSFER_COMPLETED, but is 3!
9.141715 _cb_irq                     (2): 0x55a1e54fe0 with status 3
9.141747 _cb_irq                     (2): Transfer 0x55a1e54fe0 should be in LIBUSB_TRANSFER_COMPLETED, but is 3!
9.141792 _cb_irq                     (2): 0x55a1e55d70 with status 3
9.141824 _cb_irq                     (2): Transfer 0x55a1e55d70 should be in LIBUSB_TRANSFER_COMPLETED, but is 3!
9.141871 _cb_irq                     (2): 0x55a1e639c0 with status 3
9.141902 _cb_irq                     (2): Transfer 0x55a1e639c0 should be in LIBUSB_TRANSFER_COMPLETED, but is 3!
9.143080 gp_context_error            (0): An error occurred in the io-library ('Timeout reading from or writing to the port'): No error description available

*** Error ***
An error occurred in the io-library ('Timeout reading from or writing to the port'): No error description available
ERROR: Could not capture image.
ERROR: Could not capture.
9.143332 gp_camera_init              (2): Initializing camera...
9.143615 gp_libusb1_find_device_lib  (2): Looking for USB device (vendor 0x4a9, product 0x32e1)... found.
9.144056 gp_libusb1_find_device_lib  (2): Detected defaults: config 1, interface 0, altsetting 0, inep 81, outep 02, intep 83, class 06, subclass 01
9.144100 gp_camera_init              (2): Loading '/usr/local/lib/libgphoto2/2.5.30.1/ptp2'...
9.148972 gp_port_open                (2): Opening USB port...
9.150268 gp_libusb1_open             (2): ()
9.151145 gp_libusb1_open             (2): claiming interface 0
9.152990 camera_init                 (2): maxpacketsize 512
9.153652 gp_port_set_timeout         (2): Setting port timeout to 1500 milliseconds.
9.154289 ptp                         (2): PTP: Opening session
9.155174 ptp_usb_sendreq             (2): Sending PTP_OC 0x1002 (Open session) (0x1) request...
9.156901 gp_port_write               (3): Writing 16 = 0x10 bytes to port...
10.658343 gp_libusb1_write [libusb1.c:578](0): 'libusb_bulk_transfer (port->pl->dh, port->settings.usb.outep, (unsigned char*)bytes, size, &curwritten, port->timeout)' failed: Operation timed out (-7)
10.658470 gp_port_write [gphoto2-port.c:405](0): Writing 16 = 0x10 bytes to port failed: Timeout reading from or writing to the port (-10)
10.658547 ptp_usb_sendreq [usb.c:109] (0): PTP_OC 0x1002 sending req failed: Timeout reading from or writing to the port (-10)
10.658649 camera_init [library.c:9807](0): 'ptp_opensession (params, sessionid)' failed: PTP Timeout (0x02fa)
10.658682 ptp                         (2): PTP: Opening session
10.658724 ptp_usb_sendreq             (2): Sending PTP_OC 0x1002 (Open session) (0x1) request...
10.658759 gp_port_write               (3): Writing 16 = 0x10 bytes to port...
12.159411 gp_libusb1_write [libusb1.c:578](0): 'libusb_bulk_transfer (port->pl->dh, port->settings.usb.outep, (unsigned char*)bytes, size, &curwritten, port->timeout)' failed: Operation timed out (-7)
12.159537 gp_port_write [gphoto2-port.c:405](0): Writing 16 = 0x10 bytes to port failed: Timeout reading from or writing to the port (-10)
12.159590 ptp_usb_sendreq [usb.c:109] (0): PTP_OC 0x1002 sending req failed: Timeout reading from or writing to the port (-10)
12.159642 camera_init [library.c:9807](0): 'ptp_opensession (params, sessionid)' failed: PTP Timeout (0x02fa)
12.159674 ptp                         (2): PTP: Opening session
12.159714 ptp_usb_sendreq             (2): Sending PTP_OC 0x1002 (Open session) (0x1) request...
12.159749 gp_port_write               (3): Writing 16 = 0x10 bytes to port...
13.660402 gp_libusb1_write [libusb1.c:578](0): 'libusb_bulk_transfer (port->pl->dh, port->settings.usb.outep, (unsigned char*)bytes, size, &curwritten, port->timeout)' failed: Operation timed out (-7)
13.660527 gp_port_write [gphoto2-port.c:405](0): Writing 16 = 0x10 bytes to port failed: Timeout reading from or writing to the port (-10)
13.660580 ptp_usb_sendreq [usb.c:109] (0): PTP_OC 0x1002 sending req failed: Timeout reading from or writing to the port (-10)
13.660631 camera_init [library.c:9807](0): 'ptp_opensession (params, sessionid)' failed: PTP Timeout (0x02fa)
13.660673 camera_init [library.c:9835](0): 'ret' failed: 'PTP Timeout' (0x02fa)
13.660778 gp_context_error            (0): PTP Timeout

*** Error ***
PTP Timeout
13.660856 gp_port_close               (2): Closing port...
13.662016 _close_async_interrupts     (2): canceling transfer 0:0x55a1e57460 (status 0)
13.662513 _close_async_interrupts     (2): canceling transfer 1:0x55a1e5a700 (status 0)
13.662905 _close_async_interrupts     (2): canceling transfer 2:0x55a1e58730 (status 0)
13.663349 _close_async_interrupts     (2): canceling transfer 3:0x55a1e4c1e0 (status 0)
13.663845 _close_async_interrupts     (2): canceling transfer 4:0x55a1e4dd10 (status 0)
13.664271 _close_async_interrupts     (2): canceling transfer 5:0x55a1e60ac0 (status 0)
13.664657 _close_async_interrupts     (2): canceling transfer 6:0x55a1e61200 (status 0)
13.665026 _close_async_interrupts     (2): canceling transfer 7:0x55a1e54fe0 (status 0)
13.665289 _close_async_interrupts     (2): canceling transfer 8:0x55a1e55d70 (status 0)
13.665710 _close_async_interrupts     (2): canceling transfer 9:0x55a1e5bd50 (status 0)
13.666300 _cb_irq                     (2): 0x55a1e57460 with status 3
13.666366 _cb_irq                     (2): Transfer 0x55a1e57460 should be in LIBUSB_TRANSFER_COMPLETED, but is 3!
13.666422 _cb_irq                     (2): 0x55a1e5a700 with status 3
13.666474 _cb_irq                     (2): Transfer 0x55a1e5a700 should be in LIBUSB_TRANSFER_COMPLETED, but is 3!
13.666525 _cb_irq                     (2): 0x55a1e58730 with status 3
13.666557 _cb_irq                     (2): Transfer 0x55a1e58730 should be in LIBUSB_TRANSFER_COMPLETED, but is 3!
13.666603 _cb_irq                     (2): 0x55a1e4c1e0 with status 3
13.666636 _cb_irq                     (2): Transfer 0x55a1e4c1e0 should be in LIBUSB_TRANSFER_COMPLETED, but is 3!
13.666681 _cb_irq                     (2): 0x55a1e4dd10 with status 3
13.666714 _cb_irq                     (2): Transfer 0x55a1e4dd10 should be in LIBUSB_TRANSFER_COMPLETED, but is 3!
13.666759 _cb_irq                     (2): 0x55a1e60ac0 with status 3
13.666791 _cb_irq                     (2): Transfer 0x55a1e60ac0 should be in LIBUSB_TRANSFER_COMPLETED, but is 3!
13.666837 _cb_irq                     (2): 0x55a1e61200 with status 3
13.666885 _cb_irq                     (2): Transfer 0x55a1e61200 should be in LIBUSB_TRANSFER_COMPLETED, but is 3!
13.666932 _cb_irq                     (2): 0x55a1e54fe0 with status 3
13.666964 _cb_irq                     (2): Transfer 0x55a1e54fe0 should be in LIBUSB_TRANSFER_COMPLETED, but is 3!
13.667011 _cb_irq                     (2): 0x55a1e55d70 with status 3
13.667045 _cb_irq                     (2): Transfer 0x55a1e55d70 should be in LIBUSB_TRANSFER_COMPLETED, but is 3!
13.667090 _cb_irq                     (2): 0x55a1e5bd50 with status 3
13.667123 _cb_irq                     (2): Transfer 0x55a1e5bd50 should be in LIBUSB_TRANSFER_COMPLETED, but is 3!
13.668047 gp_context_error            (0): An error occurred in the io-library ('Timeout reading from or writing to the port'): No error description available

*** Error ***
An error occurred in the io-library ('Timeout reading from or writing to the port'): No error description available
13.672470 gp_camera_free              (2): Freeing camera...
13.672997 gp_port_free                (2): Freeing port...
13.673488 gp_port_close               (2): Closing port...
13.675342 gp_filesystem_reset         (2): resetting filesystem
13.676247 gp_filesystem_lru_clear     (2): Clearing fscache LRU list...
13.676768 gp_filesystem_lru_clear     (2): fscache LRU list already empty
13.677248 delete_all_folders          (2): Internally deleting all folders from '/'...
13.677668 lookup_folder               (2): Lookup folder '/'...
13.678076 lookup_folder               (2): Found! / is 0x55a1e41a30
13.678529 recurse_delete_folder       (2): Recurse delete folder 0x55a1e41a30//
13.678939 delete_all_files            (2): Delete all files in folder 0x55a1e41a30//
msmeissn commented 1 year ago

So it does not seem to have helped much :(

If it would be possible to get the debugtrace of the gphoto2 run before the first failing one like this? Not sure how much we can read out of that.

michilehr commented 1 year ago

Of course @msmeissn! Which version? Stable or Dev?

msmeissn commented 1 year ago

latest if possible :)

michilehr commented 1 year ago

So now I have 3 log files. I did upload the files to Dropbox because of the file limit here.

1674471530-ok.log: All good 1674471540-first-sign-of-error.log: capturing works, but first error after saving 1674471602-error.log: No more taking photos

michilehr commented 1 year ago

Hi @msmeissn, any chance to look into this? Do you need more information?

PeterZechel commented 1 year ago

Hi @msmeissn , I am facing the same issue. Is there any solution or can I support you for debugging.

msmeissn commented 1 year ago

can you please retest with 2.5.31. i think i fixed it.

dayjaby commented 1 year ago

@msmeissn 2.5.31 is not on github, right? I have a similar problem and can help with testing :)

michilehr commented 1 year ago

@msmeissn Thank you! Will test and give feedback! @dayjaby it is the libgphoto which has been updated. See https://github.com/gphoto/libgphoto2/tree/v2.5.31