Canon EOS 2000D appears to reject commands sent too soon after PTP/IP connection is established

[BCMM]

Describe the bug

When using a network connection as opposed to USB, the Canon EOS 2000D appears to reject commands sent too soon after the connection is established, causing the gphoto2 command-line to fail.

Name the camera

If this is camera specific, include the camera name as shown by gphoto2 --auto-detect or USB IDs

I can't use --auto-detect because the camera is not connected by USB, but it's a Canon EOS 2000D.

libgphoto2 and gphoto2 version

gphoto2 2.5.26

Copyright (c) 2000-2020 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.26         gcc, popt(m), exif, cdk, aa, jpeg, readline
libgphoto2      2.5.26         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

$ gphoto2 --debug --debug-logfile=debug.log --capture-image                

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

debug.log

Using gphoto --shell, this can be worked around by including a delay between the establishment of the connection and the attempt to capture an image.

This command almost always fails:

$ (sleep 1; echo capture-image) | gphoto2 --shell
gphoto2: {/tmp} /> capture-image                                               
capture-image

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

This command always succeeds:

$ (sleep 5; echo capture-image) | gphoto2 --shell
gphoto2: {/tmp} /> capture-image                                               
capture-image
New file is in location /capt0000.jpg on the camera
gphoto2: {/tmp} />

(gphoto2 --wait-event=5s --capture-photo can also be used to produce a similar effect.)

This may just be a coincidence, but the period during which capture will fail appears to correspond to the period during which the following message is displayed on the camera's screen. So far, the camera appears to operate reliably as long the screen is black before commands are sent.

[msmeissn]

It seems we need to wait for some tgrigger condition (or just a specified time)

can you also take a logfile with wait-event where it works? perhaps an event is visible which we can use.

[BCMM]

As far as I can tell, there is no obvious event which indicates readiness. However, it appears to reliably sends the first FocusInfo around half a second after it is ready to begin capture.

Here are two logs, one which shows capture succeeding, and one in which it appears to fail at exactly the same point. (The camera was still set on a two second self-timer from a previous experiment, so if the capture appears slow, that's not a mistake).

$ gphoto2 --debug --debug-logfile=early-sucess.log --wait-event=34 --capture-image
Waiting for 34 events from camera. Press Ctrl-C to abort.                      
UNKNOWN PTP Property d11b changed
UNKNOWN PTP Property d11c changed
UNKNOWN PTP Property d1b0 changed
UNKNOWN PTP Property d1b0 changed
UNKNOWN PTP Property d105 changed
UNKNOWN PTP Property d108 changed
UNKNOWN PTP Property d106 changed
UNKNOWN PTP Property d107 changed
UNKNOWN PTP Property d109 changed
UNKNOWN PTP Property d10b changed
UNKNOWN PTP Property d10c changed
UNKNOWN PTP Property d10d changed
UNKNOWN PTP Property d10e changed
UNKNOWN PTP Property d10f changed
UNKNOWN PTP Property d11b changed
UNKNOWN PTP Property d114 changed
UNKNOWN PTP Property d116 changed
UNKNOWN PTP Property d119 changed
UNKNOWN PTP Property d110 changed
UNKNOWN PTP Property d101 changed
UNKNOWN PTP Property d102 changed
UNKNOWN PTP Property d103 changed
UNKNOWN PTP Property d104 changed
UNKNOWN PTP Property d11d changed
UNKNOWN PTP Property d111 changed
UNKNOWN PTP Property d112 changed
UNKNOWN PTP Property d113 changed
UNKNOWN PTP Property d120 changed
UNKNOWN PTP Property d122 changed
UNKNOWN PTP Property d156 changed
UNKNOWN PTP Property d150 changed
UNKNOWN PTP Property d151 changed
UNKNOWN PTP Property d152 changed
UNKNOWN PTP Property d153 changed
New file is in location /capt0000.jpg on the camera
New file is in location /capt0001.cr2 on the camera

I have edited this log file, since the original was over 100 MB early-success-edited.log

$ gphoto2 --debug --debug-logfile=early-failure.log --wait-event=34 --capture-image
Waiting for 34 events from camera. Press Ctrl-C to abort.                      
UNKNOWN PTP Property d11b changed
UNKNOWN PTP Property d11c changed
UNKNOWN PTP Property d1b0 changed
UNKNOWN PTP Property d1b0 changed
UNKNOWN PTP Property d105 changed
UNKNOWN PTP Property d108 changed
UNKNOWN PTP Property d106 changed
UNKNOWN PTP Property d107 changed
UNKNOWN PTP Property d109 changed
UNKNOWN PTP Property d10b changed
UNKNOWN PTP Property d10c changed
UNKNOWN PTP Property d10d changed
UNKNOWN PTP Property d10e changed
UNKNOWN PTP Property d10f changed
UNKNOWN PTP Property d11b changed
UNKNOWN PTP Property d114 changed
UNKNOWN PTP Property d116 changed
UNKNOWN PTP Property d119 changed
UNKNOWN PTP Property d110 changed
UNKNOWN PTP Property d101 changed
UNKNOWN PTP Property d102 changed
UNKNOWN PTP Property d103 changed
UNKNOWN PTP Property d104 changed
UNKNOWN PTP Property d11d changed
UNKNOWN PTP Property d111 changed
UNKNOWN PTP Property d112 changed
UNKNOWN PTP Property d113 changed
UNKNOWN PTP Property d120 changed
UNKNOWN PTP Property d122 changed
UNKNOWN PTP Property d156 changed
UNKNOWN PTP Property d150 changed
UNKNOWN PTP Property d151 changed
UNKNOWN PTP Property d152 changed
UNKNOWN PTP Property d153 changed

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

early-failure.log

Here is the first 6 seconds after connection, uninterrupted:

$ gphoto2 --debug --debug-logfile=6-seconds.log --wait-event=6s
Waiting for 6 seconds for events from camera. Press Ctrl-C to abort.           
UNKNOWN PTP Property d11b changed
UNKNOWN PTP Property d11c changed
UNKNOWN PTP Property d1b0 changed
UNKNOWN PTP Property d1b0 changed
UNKNOWN PTP Property d105 changed
UNKNOWN PTP Property d108 changed
UNKNOWN PTP Property d106 changed
UNKNOWN PTP Property d107 changed
UNKNOWN PTP Property d109 changed
UNKNOWN PTP Property d10b changed
UNKNOWN PTP Property d10c changed
UNKNOWN PTP Property d10d changed
UNKNOWN PTP Property d10e changed
UNKNOWN PTP Property d10f changed
UNKNOWN PTP Property d11b changed
UNKNOWN PTP Property d114 changed
UNKNOWN PTP Property d116 changed
UNKNOWN PTP Property d119 changed
UNKNOWN PTP Property d110 changed
UNKNOWN PTP Property d101 changed
UNKNOWN PTP Property d102 changed
UNKNOWN PTP Property d103 changed
UNKNOWN PTP Property d104 changed
UNKNOWN PTP Property d11d changed
UNKNOWN PTP Property d111 changed
UNKNOWN PTP Property d112 changed
UNKNOWN PTP Property d113 changed
UNKNOWN PTP Property d120 changed
UNKNOWN PTP Property d122 changed
UNKNOWN PTP Property d156 changed
UNKNOWN PTP Property d150 changed
UNKNOWN PTP Property d151 changed
UNKNOWN PTP Property d152 changed
UNKNOWN PTP Property d153 changed
UNKNOWN PTP Property d154 changed
UNKNOWN PTP Property d155 changed
UNKNOWN PTP Property d160 changed
UNKNOWN PTP Property d161 changed
UNKNOWN PTP Property d162 changed
UNKNOWN PTP Property d11c changed
UNKNOWN PTP Property d1a0 changed
UNKNOWN PTP Property d1a1 changed
UNKNOWN PTP Property d1a8 changed
UNKNOWN PTP Property d1ab changed
UNKNOWN PTP Property d1b0 changed
UNKNOWN PTP Property d1b1 changed
UNKNOWN PTP Property d1b2 changed
UNKNOWN PTP Property d1b3 changed
UNKNOWN PTP Property d1b4 changed
UNKNOWN PTP Property d1b5 changed
UNKNOWN PTP Property d1a9 changed
UNKNOWN PTP Property d146 changed
UNKNOWN PTP Property d1ac changed
UNKNOWN PTP Property d11e changed
UNKNOWN PTP Property d11f changed
UNKNOWN PTP Property d1d9 changed
UNKNOWN PTP Property d1ba changed
UNKNOWN PTP Property d1ca changed
UNKNOWN PTP Property d1bc changed
UNKNOWN PTP Property d1b8 changed
UNKNOWN FocusInfo eosversion=0,size=6000x4000,size2=6000x4000,points={{0,860,136,210},{-972,456,200,150},{972,456,200,150},{-1614,0,200,150},{0,0,260,258},{1614,0,200,150},{-972,-456,200,150},{972,-456,200,150},{0,-860,136,210}},select={},unknown={10000000ffff}
UNKNOWN PTP Property d1d8 changed
UNKNOWN PTP Property d1b7 changed
UNKNOWN PTP Property d1b9 changed
UNKNOWN PTP Property d1db changed
UNKNOWN PTP Property d1dc changed
UNKNOWN PTP Property d1df changed
UNKNOWN PTP Property d1bd changed
UNKNOWN PTP Property d1c1 changed
UNKNOWN PTP Property d1c0 changed
UNKNOWN PTP Property d1bf changed
UNKNOWN PTP Property d1c4 changed
UNKNOWN PTP Property d1c2 changed
UNKNOWN PTP Property d1c5 changed
UNKNOWN PTP Property d194 changed
UNKNOWN PTP Property d195 changed
UNKNOWN PTP Property d196 changed
UNKNOWN PTP Property d197 changed
UNKNOWN PTP Property d198 changed
UNKNOWN PTP Property d1c6 changed
UNKNOWN PTP Property d1c8 changed
UNKNOWN PTP Property d17c changed
UNKNOWN PTP Property d17d changed
UNKNOWN PTP Property d17e changed
UNKNOWN PTP Property d14d changed
UNKNOWN PTP Property d138 changed
UNKNOWN PTP Property d177 changed
UNKNOWN PTP Property d175 changed
UNKNOWN PTP Property d14a changed
UNKNOWN PTP Property d1dd changed
UNKNOWN unhandled EOS event CTGInfoCheckComplete (size 12)
UNKNOWN Button 21
UNKNOWN PTP Property d102 changed
UNKNOWN PTP Property d101 changed
UNKNOWN PTP Property d103 changed
UNKNOWN OLCInfo event 0x0010 content 00000000
UNKNOWN OLCInfo event 0x0020 content 000000000000
UNKNOWN OLCInfo exposure indicator 1,0,0.0 (00000000)
UNKNOWN OLCInfo event 0x0080 content 00000000
UNKNOWN Focus Info 000000000000
UNKNOWN Focus Mask 00000000000000
UNKNOWN OLCInfo event 0x0400 content 00000000000000
UNKNOWN OLCInfo event 0x0800 content 0000000008000000
UNKNOWN OLCInfo event 0x1000 content 00
UNKNOWN OLCInfo event mask=1fff
UNKNOWN PTP Property d115 changed
UNKNOWN PTP Property d1d0 changed
UNKNOWN PTP Property d1d1 changed
UNKNOWN PTP Property d1af changed
UNKNOWN PTP Property d105 changed
UNKNOWN PTP Property d108 changed
UNKNOWN PTP Property d106 changed
UNKNOWN PTP Property d107 changed
UNKNOWN PTP Property d109 changed
UNKNOWN PTP Property d10b changed
UNKNOWN PTP Property d10c changed
UNKNOWN PTP Property d10d changed
UNKNOWN PTP Property d10e changed
UNKNOWN PTP Property d10f changed
UNKNOWN PTP Property d11b changed
UNKNOWN PTP Property d114 changed
UNKNOWN PTP Property d116 changed
UNKNOWN PTP Property d119 changed
UNKNOWN PTP Property d110 changed
UNKNOWN PTP Property d101 changed
UNKNOWN PTP Property d102 changed
UNKNOWN PTP Property d103 changed
UNKNOWN PTP Property d104 changed
UNKNOWN PTP Property d11d changed
UNKNOWN PTP Property d111 changed
UNKNOWN PTP Property d112 changed
UNKNOWN PTP Property d113 changed
UNKNOWN PTP Property d120 changed
UNKNOWN PTP Property d122 changed
UNKNOWN PTP Property d156 changed
UNKNOWN PTP Property d150 changed
UNKNOWN PTP Property d151 changed
UNKNOWN PTP Property d152 changed
UNKNOWN PTP Property d153 changed
UNKNOWN PTP Property d154 changed
UNKNOWN PTP Property d155 changed
UNKNOWN PTP Property d160 changed
UNKNOWN PTP Property d161 changed
UNKNOWN PTP Property d162 changed
UNKNOWN PTP Property d11c changed
UNKNOWN PTP Property d1a0 changed
UNKNOWN PTP Property d1a1 changed
UNKNOWN PTP Property d1a8 changed
UNKNOWN PTP Property d1ab changed
UNKNOWN PTP Property d1b0 changed
UNKNOWN PTP Property d1b1 changed
UNKNOWN PTP Property d1b2 changed
UNKNOWN PTP Property d1b3 changed
UNKNOWN PTP Property d1b4 changed
UNKNOWN PTP Property d1b5 changed
UNKNOWN PTP Property d1a9 changed
UNKNOWN PTP Property d146 changed
UNKNOWN PTP Property d1ac changed
UNKNOWN PTP Property d11e changed
UNKNOWN PTP Property d11f changed
UNKNOWN PTP Property d1d9 changed
UNKNOWN PTP Property d1ba changed
UNKNOWN PTP Property d1ca changed
UNKNOWN PTP Property d1bc changed
UNKNOWN PTP Property d1b8 changed
UNKNOWN FocusInfo eosversion=0,size=6000x4000,size2=6000x4000,points={{0,860,136,210},{-972,456,200,150},{972,456,200,150},{-1614,0,200,150},{0,0,260,258},{1614,0,200,150},{-972,-456,200,150},{972,-456,200,150},{0,-860,136,210}},select={},unknown={10000000ffff}
UNKNOWN PTP Property d1d8 changed
UNKNOWN PTP Property d1b7 changed
UNKNOWN PTP Property d1b9 changed
UNKNOWN PTP Property d1db changed
UNKNOWN PTP Property d1dc changed
UNKNOWN PTP Property d1df changed
UNKNOWN PTP Property d1bd changed
UNKNOWN PTP Property d1c1 changed
UNKNOWN PTP Property d1c0 changed
UNKNOWN PTP Property d1bf changed
UNKNOWN PTP Property d1c4 changed
UNKNOWN PTP Property d1c2 changed
UNKNOWN PTP Property d1c5 changed
UNKNOWN PTP Property d194 changed
UNKNOWN PTP Property d195 changed
UNKNOWN PTP Property d196 changed
UNKNOWN PTP Property d197 changed
UNKNOWN PTP Property d198 changed
UNKNOWN PTP Property d1c6 changed
UNKNOWN PTP Property d1c8 changed
UNKNOWN PTP Property d17c changed
UNKNOWN PTP Property d17d changed
UNKNOWN PTP Property d17e changed
UNKNOWN PTP Property d14d changed
UNKNOWN PTP Property d138 changed
UNKNOWN PTP Property d177 changed
UNKNOWN PTP Property d175 changed
UNKNOWN PTP Property d14a changed
UNKNOWN PTP Property d1dd changed
UNKNOWN unhandled EOS event CTGInfoCheckComplete (size 12)
UNKNOWN Button 21
UNKNOWN PTP Property d102 changed
UNKNOWN PTP Property d101 changed
UNKNOWN PTP Property d103 changed
UNKNOWN OLCInfo event 0x0010 content 00000000
UNKNOWN OLCInfo event 0x0020 content 000000000000
UNKNOWN OLCInfo exposure indicator 1,0,0.0 (00000000)
UNKNOWN OLCInfo event 0x0080 content 00000000
UNKNOWN Focus Info 000000000000
UNKNOWN Focus Mask 00000000000000
UNKNOWN OLCInfo event 0x0400 content 00000000000000
UNKNOWN OLCInfo event 0x0800 content 0000000008000000
UNKNOWN OLCInfo event 0x1000 content 00
UNKNOWN OLCInfo event mask=1fff
UNKNOWN PTP Property d115 changed
UNKNOWN PTP Property d1d0 changed
UNKNOWN PTP Property d1d1 changed
UNKNOWN PTP Property d1af changed
UNKNOWN PTP Property d105 changed
UNKNOWN PTP Property d108 changed
UNKNOWN PTP Property d106 changed
UNKNOWN PTP Property d107 changed
UNKNOWN PTP Property d109 changed
UNKNOWN PTP Property d10b changed
UNKNOWN PTP Property d10c changed
UNKNOWN PTP Property d10d changed
UNKNOWN PTP Property d10e changed
UNKNOWN PTP Property d10f changed
UNKNOWN PTP Property d11b changed
UNKNOWN PTP Property d114 changed
UNKNOWN PTP Property d116 changed
UNKNOWN PTP Property d119 changed
UNKNOWN PTP Property d110 changed
UNKNOWN PTP Property d101 changed
UNKNOWN PTP Property d102 changed
UNKNOWN PTP Property d103 changed
UNKNOWN PTP Property d104 changed
UNKNOWN PTP Property d11d changed
UNKNOWN PTP Property d111 changed
UNKNOWN PTP Property d112 changed
UNKNOWN PTP Property d113 changed
UNKNOWN PTP Property d120 changed
UNKNOWN PTP Property d122 changed
UNKNOWN PTP Property d156 changed
UNKNOWN PTP Property d150 changed
UNKNOWN PTP Property d151 changed
UNKNOWN PTP Property d152 changed
UNKNOWN PTP Property d153 changed
UNKNOWN PTP Property d154 changed
UNKNOWN PTP Property d155 changed
UNKNOWN PTP Property d160 changed
UNKNOWN PTP Property d161 changed
UNKNOWN PTP Property d162 changed
UNKNOWN PTP Property d11c changed
UNKNOWN PTP Property d1a0 changed
UNKNOWN PTP Property d1a1 changed
UNKNOWN PTP Property d1a8 changed
UNKNOWN PTP Property d1ab changed
UNKNOWN PTP Property d1b0 changed
UNKNOWN PTP Property d1b1 changed
UNKNOWN PTP Property d1b2 changed
UNKNOWN PTP Property d1b3 changed
UNKNOWN PTP Property d1b4 changed
UNKNOWN PTP Property d1b5 changed
UNKNOWN PTP Property d1a9 changed
UNKNOWN PTP Property d146 changed
UNKNOWN PTP Property d1ac changed
UNKNOWN PTP Property d11e changed
UNKNOWN PTP Property d11f changed
UNKNOWN PTP Property d1d9 changed
UNKNOWN PTP Property d1ba changed
UNKNOWN PTP Property d1ca changed
UNKNOWN PTP Property d1bc changed
UNKNOWN PTP Property d1b8 changed
UNKNOWN FocusInfo eosversion=0,size=6000x4000,size2=6000x4000,points={{0,860,136,210},{-972,456,200,150},{972,456,200,150},{-1614,0,200,150},{0,0,260,258},{1614,0,200,150},{-972,-456,200,150},{972,-456,200,150},{0,-860,136,210}},select={},unknown={10000000ffff}
UNKNOWN PTP Property d1d8 changed
UNKNOWN PTP Property d1b7 changed
UNKNOWN PTP Property d1b9 changed
UNKNOWN PTP Property d1db changed
UNKNOWN PTP Property d1dc changed
UNKNOWN PTP Property d1df changed
UNKNOWN PTP Property d1bd changed
UNKNOWN PTP Property d1c1 changed
UNKNOWN PTP Property d1c0 changed
UNKNOWN PTP Property d1bf changed
UNKNOWN PTP Property d1c4 changed
UNKNOWN PTP Property d1c2 changed
UNKNOWN PTP Property d1c5 changed
UNKNOWN PTP Property d194 changed
UNKNOWN PTP Property d195 changed

6-seconds.log

[thovdamm]

I'm having the same problem.. Is it still an ongoing issue ?

[thovdamm]

I managed to make my Canon EOS 2000D work with libgphoto2<=2.5.23 (seems like gphoto2 itself works with any version). I suspect the change introduced with version 2.5.24 to have broken PTP communications for some Canon Cameras, maybe something worth looking into ?

I suggest installing these versions using gphoto2-updater, adapting the .env file with the desired versions.

It is a shame there isn't a better installation utility.

[hfiguiere]

The thing is that libgphoto2 is at 2.5.30.

[thovdamm]

It is, but libgphoto2 versions from 2.5.24 yield the issue at hand.

[hfiguiere]

Did you reproduce with 2.5.30?

2.5.27 and 2.5.28 have some canon fixes.

There is no point of tracking a regression if it was fixed already.

[thovdamm]

Yes, I did. I actually tested every combination of gphoto2 and libgphoto2 versions; with the conclusion above (libgphoto 2.5.24 broke some PTP communication functions for at least my camera)

[msmeissn]

if you want to try something,

camlibs/ptp2/config.c::camera_prepare_canon_eos_capture

add:

        if (strcmp(params->deviceinfo.Model,"Canon EOS 2000D") != 0)
                usleep(100*1000); /* 0.1 second */

before these lines near the end of the function:

       if (    is_canon_eos_m (params) &&
                (strcmp(params->deviceinfo.Model,"Canon EOS M6 Mark II") != 0)
        ) {

and fiddle a bit with the usleep() delays?

[msmeissn]

the primary difference between 2.5.23 and 2.5.24 is the uilocking on/off method being added :/

[thovdamm]

I tried your suggestion for different delays, but could not make the camera work reliably.

It seems the issue occurs after failing to acquire focus information (camlibs/ptp2/library.c:5924), so during the half-way pressing ? The issue is similar when the focus is manually set on the camera.

Here are four log files; if that helps you narrow down the issue. debug_autofocus_success.log debug_autofocus_failure.log debug_manualfocus_success.log debug_manualfocus_failure.log

Please tell me if I can try anything else, thanks !

[msmeissn]

i bought a eos2000d and am trying to reproduce this.

Autofocus mode: Currently i get the busy error only when the camera does not get focus within 2 seconds during capture. I do not get 10 seconds wait from your logfile, the command returns immediately busy.

I think there some reporting is needed

[thovdamm]

Do you have an idea where this difference might be coming from ?

What do you mean by reporting is needed ? Can I help in any way?

[msmeissn]

as i have it available i can try stuff here, thanks!

So far I also see issues when i do capture the second time after plugin (first time works great, second and third times work not well)

[flomi14]

Hey i have the same problem. Did you find something? or do you have a solution for that? Greetigs

[thovdamm]

I just used version 2.5.23 (of libgphoto) which works.. I haven't tried newer versions since my original post, so I don't know if the bug was fixed recently (but I guess it wasn't)

For an easy install, I pulled https://raw.githubusercontent.com/gonzalo/gphoto2-updater/master/gphoto2-updater.sh and changed the version number in the .env file.

Hope that helps.

[flomi14]

Thank you so much thats great