indi-gphoto: Unreliable long exposures on Canon DSLR (EOS6D in particular, but also others)

[jochym]

Describe the bug
Long exposures (above 10s) on Canon DSLR are very unreliable. It is very obvious on my 6D but also 40D suffers similar problems. The capture hangs, repeats multiple times etc.

To Reproduce
Exact steps to reproduce the behavior.

1. Run driver
2. Just set exposure to 30-40s
3. The problem will show up very soon

Expected behavior
Well, reliable captures ;)

Desktop (please complete the following information):

• OS: Linux debian/raspbian
• Version bookworm, but it was like this for a long time

Analysis
It seems with long exposures the data may be available after some, sometimes long delay. In case of 6D the delay may be as long as the exposure (I suspect the camera is doing dark framing internally). I have figured out that simple constant wait suggested in gphoto docs is not correct. After long search and trial-and-error, I have figured out the correct sequence for EOS 6D in gphoto CLI (example script - captures a frame with given exposition):

#!/bin/bash

LANG=C 

gphoto2 --filename "capt_exp=${1}s_%Y-%m-%d_%H:%M:%S.%C" \
        --set-config eosremoterelease=Immediate \
        --wait-event=${1}s \
        --set-config eosremoterelease="Release Full" \
        --wait-event-and-download=CAPTURECOMPLETE

In case of gphoto2 tool, the LANG=C is crucial, but the real solution is --wait-event-and-download=CAPTURECOMPLETE which waits for the actual end of capture. This script essentially "works". Unfortunately, I do not know how to port this solution to indi-gphoto. I guess it may be easy for the person familiar with the code (just wait for this event instead of fixed timeout, although some configurable timeout on top of this may be useful).

[jochym]

Just to add some more data. The problem may be worked around for 6D with setting "Long time exposure noise reduction" to off in camera. However, I think this is still a bug. We should wait for a complete exposure, not a particular timeout. Actually, I think we should wait on complete exposure and complete file showing up in the camera. The automatic dark frame in 6D is actually a very neat feature. It makes the scope shutter unnecessary. It will be a shame not to use it.

[jochym]

I actually figured out where is the problem. In gphoto_driver.cpp

indi-3rdparty/indi-gphoto/gphoto_driver.cpp

Line 1431 in de09e79

DEBUGFDEVICE(device, INDI::Logger::DBG_DEBUG, "Event timed out #%d, retrying...", ++timeoutCounter);

we are waiting for fixed timeout - no mater what. We should wait for the complete capture and only after reasonable timeout (let us say 2*exposure + 10s) give up and decide the data is not coming. Unfortunately, I do not know how to get current exposure time to fix this properly (@knro - this will be 5 seconds for you to figure out, help ;). I will just disable the timeout in my branch and report if it fixed the problem.

For now, here is the relevant debug log:

DEBUG   508.094583 sec  : Starting exposure (exptime: 20 secs, mirror lock: 0, force bulb: true, exposure index: 1598309187)
DEBUG   508.094626 sec  : Mutex locked
DEBUG   508.094668 sec  : Setting radio/menu widget imageformat: 32 (RAW)
DEBUG   508.097011 sec  : Setting new configuration OK.
DEBUG   508.097107 sec  : Setting exposure widget bulb index: 0
DEBUG   508.097153 sec  : Setting radio/menu widget shutterspeed: 0 (bulb)
DEBUG   508.099693 sec  : Setting new configuration OK.
DEBUG   508.099789 sec  : Using internal bulb widget:eosremoterelease
DEBUG   508.099829 sec  : Setting radio/menu widget eosremoterelease: 2 (Press Full)
DEBUG   508.225102 sec  : Setting new configuration OK.
DEBUG   508.225221 sec  : Exposure started.
DEBUG   508.225355 sec  : Time left: 19999 ms
DEBUG   513.225522 sec  : Time left: 14999 ms
DEBUG   518.225755 sec  : Time left: 9999 ms
DEBUG   523.225987 sec  : Time left: 4999 ms
DEBUG   528.126121 sec  : Reading exposure...
DEBUG   528.225292 sec  : Time left: -1 ms
DEBUG   528.225387 sec  : Closing internal shutter.
DEBUG   528.225402 sec  : Using widget:eosremoterelease
DEBUG   528.225417 sec  : Setting radio/menu widget eosremoterelease: 4 (Release Full)
DEBUG   528.236484 sec  : Setting new configuration OK.
DEBUG   528.236572 sec  : Exposure complete.
DEBUG   531.503087 sec  : Event timed out #1, retrying...
DEBUG   532.505770 sec  : Event timed out #2, retrying...
DEBUG   533.508856 sec  : Event timed out #3, retrying...
DEBUG   534.511143 sec  : Event timed out #4, retrying...
DEBUG   535.514251 sec  : Event timed out #5, retrying...
DEBUG   536.516882 sec  : Event timed out #6, retrying...
DEBUG   537.519956 sec  : Event timed out #7, retrying...
DEBUG   538.522409 sec  : Event timed out #8, retrying...
DEBUG   539.524799 sec  : Event timed out #9, retrying...
DEBUG   540.527860 sec  : Event timed out #10, retrying...
ERROR   540.527935 sec  : Failed to expose.
WARNING 540.527953 sec  : If your camera mirror lock is enabled, you must set a value for the mirror locking duration.

[jochym]

And it fixed the problem. This problem. Unfortunately, there is also a problem with focusing - but that is for another day. That is - it is worked-around. It still needs proper fixing...

[knro]

Thank you for your investigation. I suppose we could wait full-exposure but perhaps not by default. Maybe can add a toggle for timeout: Default vs Max

[jochym]

Great idea! My tests last night showed that it really works over a wide range of times - so it is definitely worth it. Maybe just a switch: wait for exposure+timeout/wait for complete in-camera processing + timeout with adjustable timeout. It seems this was a problem before - the timeout used to be 5s (from the comment) now it is 10s...

Additionally, I spotted a problem with focusing in EKOS. Autofocusing leaves the camera in hang state, while executing the same steps manually with buttons in EKOS is fine - I guess something is not closed properly at the end. The focusing is problematic with canon, but eventually it works (see the attached frame). But it is a problem with DSLRs and I do not think much can be done about that.
One thing though - the canon focussing works only in viefinder mode. I had to switch it on manually in the INDI control dialog - it will be easier on the user if this was integrated into EKOS focusing page. Shall I open a separate issue somewhere for this?