indi-gphoto indi_sony_ccd Sony a5000 subsequent exposures not captured

m-kostrzewa commented 4 years ago

Describe the bug

I have Sony Alpha A5000 (ILCE-5000).

Only about every 3rd exposure done by Ekos using indi_sony_ccd driver actually moves the shutter and captures new data. Other exposures don't cause the shutter to open or close, and stale data is downloaded as preview (from the successful exposure).

I have investigated this issue and provide a hack/patch that works for me.

Additional keywords: freeze, frozen, stuck,

To Reproduce

Reproduce it using Kstars+Ekos.

In profile editor, add Sony DSLR device. I have Sony Alpha a5000 (ILCE-5000) connected via USB in PC direct mode. Run the profile.

Go to CCD tab.
Grab preview exposure. Preview should appear.
Move the camera so that it points to a different object (to compare previews).
Grab preview exposure. You will notice there's no shutter sound, and the preview is the same as in step 2.
Repeat steps 3-4 until a "fresh, real" preview appears (around 3 times).

Note, that no error is reported here.

This may or may not be relevant, but I also disabled LENR via telnet like so: https://github.com/ma1co/OpenMemories-Tweak/issues/205 This requires installing OpenMemories Tweak app on the camera itself. I initially suspected it to be the problem, but even though this hack works (LENR is disabled), it didn't solve this issue. I'm not sure if it is required for my patch to work.

During the investigationI ran some gphoto2 commands to try to replicate the issue manually:

astroberry@astroberry:~/codez/indi-3rdparty/indi-gphoto/build $ gphoto2 -v --set-config bulb=1
gphoto2 2.5.23

Copyright (c) 2000-2019 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.23         gcc, popt(m), exif, no cdk, no aa, no jpeg, no readline
libgphoto2      2.5.24.1       standard camlibs, gcc, ltdl, EXIF
libgphoto2_port 0.12.0         iolibs: disk ptpip serial usb1 usbdiskdirect usbscsi, gcc, ltdl, EXIF, USB, serial without locking

astroberry@astroberry:~/codez/indi-3rdparty/indi-gphoto/build $ gphoto2 -v --set-config bulb=0 --wait-event-and-download=5s --force-overwrite
gphoto2 2.5.23

Copyright (c) 2000-2019 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.23         gcc, popt(m), exif, no cdk, no aa, no jpeg, no readline
libgphoto2      2.5.24.1       standard camlibs, gcc, ltdl, EXIF
libgphoto2_port 0.12.0         iolibs: disk ptpip serial usb1 usbdiskdirect usbscsi, gcc, ltdl, EXIF, USB, serial without locking
Waiting for 5 seconds for events from camera. Press Ctrl-C to abort.           
UNKNOWN PTP Property 5004 changed
UNKNOWN PTP Property 5004 changed
UNKNOWN PTP Event c201, Param1 ffffc001
Saving file as capt0000.arw                                                    
Saving file as capt0001.arw

You may notice, that even though I grab only one image, two files are downloaded (capt0000.arw and capt0001.arw). Sometimes it is1 file, sometimes 3, depending on the sequence of actions before. I can also run another pair of commands like above (bulb=1/bulb=0) immediately after without it getting stuck. This made me suspect that the issue is not withing libgphoto2, but with the indi driver. I thought that maybe the indi driver doesn't handle the situation where there are multiple files to be downloaded.

I have no idea why multiple files are generated to begin with. If someone could enlighten me, I'd appreciate it.

Expected behavior

Each preview should match the exposure. Each exposure should actually open/close the shutter and grab new data.

The following patch fixes the issue.

diff --git a/indi-gphoto/gphoto_driver.cpp b/indi-gphoto/gphoto_driver.cpp
index 9823d77..81a73f3 100644
--- a/indi-gphoto/gphoto_driver.cpp
+++ b/indi-gphoto/gphoto_driver.cpp
@@ -1358,7 +1358,9 @@ int gphoto_read_exposure_fd(gphoto_driver *gphoto, int fd)
         {
             case GP_EVENT_CAPTURE_COMPLETE:
                 DEBUGDEVICE(device, INDI::Logger::DBG_DEBUG, "Capture event completed.");
-                break;
+               pthread_mutex_unlock(&gphoto->mutex);
+               return GP_OK;
+                // break;
             case GP_EVENT_FILE_ADDED:
                 DEBUGDEVICE(device, INDI::Logger::DBG_DEBUG, "File added event completed.");
                 fn     = static_cast<CameraFilePath *>(data);
@@ -1368,8 +1370,8 @@ int gphoto_read_exposure_fd(gphoto_driver *gphoto, int fd)
                 // JM 2018-08-06: Why do we really need to reset values here?
                 //reset_settings(gphoto);

-                pthread_mutex_unlock(&gphoto->mutex);
-                return result;
+                //pthread_mutex_unlock(&gphoto->mutex);
+                //return result;
             case GP_EVENT_UNKNOWN:
                 //DEBUGDEVICE(device, INDI::Logger::DBG_DEBUG, "Unknown event.");
                 break;
@@ -1380,6 +1382,7 @@ int gphoto_read_exposure_fd(gphoto_driver *gphoto, int fd)
                 {
                     pthread_mutex_unlock(&gphoto->mutex);
                     return -1;
+               //      return GP_OK;
                 }
                 break;

Desktop (please complete the following information):

OS: Linux astroberry 4.19.118-v7l+ #1311 SMP Mon Apr 27 14:26:42 BST 2020 armv7l GNU/Linux
Version

$ gphoto2 -v
gphoto2 2.5.23

Copyright (c) 2000-2019 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.23         gcc, popt(m), exif, no cdk, no aa, no jpeg, no readline
libgphoto2      2.5.24.1       standard camlibs, gcc, ltdl, EXIF
libgphoto2_port 0.12.0         iolibs: disk ptpip serial usb1 usbdiskdirect usbscsi, gcc, ltdl, EXIF, USB, serial without locking

$ apt list --installed | grep indi

WARNING: apt does not have a stable CLI interface. Use with caution in scripts.

indi-aagcloudwatcher-ng/unknown,now 1.5-2 armhf [installed,automatic]
indi-aagcloudwatcher/unknown,now 1.4-3 armhf [installed,automatic]
indi-aok/unknown,now 1.0 armhf [installed,automatic]
indi-apogee/unknown,now 1.9-3 armhf [installed,automatic]
indi-armadillo-platypus/unknown,now 1.0-3 armhf [installed,automatic]
indi-asi/unknown,now 1.7 armhf [installed]
indi-astroberry-amh/unknown,now 0.3-1 armhf [installed,automatic]
indi-astroberry-diy/unknown,now 2.6.4 armhf [installed,automatic]
indi-astroberry-piface/unknown,now 2.2-1 armhf [installed,automatic]
indi-astromechfoc/unknown,now 0.1-3 armhf [installed,automatic]
indi-atik/unknown,now 2.6 armhf [installed,automatic]
indi-avalon/unknown,now 1.10 armhf [installed,automatic]
indi-bin/unknown,now 1.8.5 armhf [installed,automatic]
indi-dreamfocuser/unknown,now 2.1-3 armhf [installed,automatic]
indi-dsi/unknown,now 0.2-3 armhf [installed,automatic]
indi-duino/unknown,now 1.3 armhf [installed,automatic]
indi-eqmod/unknown,now 1.0 armhf [installed,automatic]
indi-ffmv/unknown,now 0.2-3 armhf [installed,automatic]
indi-fishcamp/unknown,now 1.1-3 armhf [installed,automatic]
indi-fli/unknown,now 1.5-1 armhf [installed,automatic]
indi-full/unknown,now 1.8.6 armhf [installed,automatic]
indi-gphoto/unknown,now 2.9-4 armhf [installed]
indi-gpsd/unknown,now 0.5-3 armhf [installed,automatic]
indi-gpsnmea/unknown,now 0.2-3 armhf [installed,automatic]
indi-maxdomeii/unknown,now 1.3-3 armhf [installed,automatic]
indi-mgen/unknown,now 0.1-3 armhf [installed,automatic]
indi-mi/unknown,now 1.8-1 armhf [installed,automatic]
indi-nexdome/unknown,now 1.4-3 armhf [installed,automatic]
indi-nexstarevo/unknown,now 0.4-3 armhf [installed,automatic]
indi-nightscape/unknown,now 1.0-3 armhf [installed,automatic]
indi-pentax/unknown,now 1.0 armhf [installed,automatic]
indi-qhy/unknown,now 2.6-4 armhf [installed,automatic]
indi-qsi/unknown,now 0.9-3 armhf [installed,automatic]
indi-sbig/unknown,now 2.1-3 armhf [installed,automatic]
indi-shelyak/unknown,now 1.0-3 armhf [installed,automatic]
indi-starbook/unknown,now 0.8-3 armhf [installed,automatic]
indi-sx/unknown,now 1.15-2 armhf [installed,automatic]
indi-talon6/unknown,now 2.0-3 armhf [installed,automatic]
indi-toupbase/unknown,now 0.2-3 armhf [installed,automatic]
indiwebmanagerapp/unknown,now 6:1.5 armhf [installed,automatic]
libayatana-appindicator3-1/stable,now 0.5.3-4 armhf [installed,automatic]
libayatana-indicator3-7/stable,now 0.6.2-3 armhf [installed,automatic]
libindi-data/unknown,now 1.8.5 all [installed,automatic]
libindi-dev/unknown,now 1.8.5 armhf [installed,automatic]
libindi1/unknown,now 1.8.5 armhf [installed,automatic]
libindicator3-7/stable,now 0.5.0-4 armhf [installed,automatic]

Log Files

original logs

log_bugged.txt.

One of many original logs. I may have done some aborts in this log file so you may encounter some junk, however it's not the cause of the problem :) Here's the important bit: you will notice that only one GP_EVENT_FILE_ADDED event is handled per exposure. After it's handled, the control is returned to the caller. This means, that only one file can be downloaded per exposure. So the case of multiple files per exposure is not handled correctly.

For some reason, until all queued up files are downloaded, the shutter doesn't work.

Sometimes when I pressed some button on the camera at this moment, I would get the error message "writing to memory card unable to operate". I disabled saving to SD card via Ekos interface but it didn't help. So I suspect what the error message really means is "Waiting for client to handle all GP_EVENT_FILE_ADDED events".

To drain the queue, I have to schedule multiple exposures. Note, that even though "Starting exposure" log is produced, there's no shutter sound in most cases.

Excerpts:

DEBUG   5.596671 sec    : Exposure complete.
DEBUG   7.456848 sec    : File added event completed.
DEBUG   7.457044 sec    : Deleting aborted image... Name: (capt0000.arw) Folder: (/)
DEBUG   7.565348 sec    : Could not determine image size (Unspecified error)
DEBUG   14.444694 sec   : Requested CCD Frame is (0,0) (5456 x 3632)
INFO    14.444989 sec   : Starting 6 seconds exposure.
DEBUG   14.445069 sec   : Starting exposure (exptime: 6 secs, mirror lock: 0, force bulb: true, exposure index: 0)
...

DEBUG   30.351691 sec   : Exposure complete.
DEBUG   32.238162 sec   : File added event completed.
DEBUG   32.238307 sec   : Downloading image... Name: (capt0001.arw) Folder: (/) Delete from SD card? (false)
DEBUG   32.404074 sec   : Could not determine image size (Unspecified error)
INFO    32.571951 sec   : Exposure done, downloading image...
DEBUG   34.932984 sec   : read_libraw: raw_width: 5504 top_margin 0 left_margin 0 first_visible_pixel 0
DEBUG   34.933235 sec   : read_libraw: rawdata.sizes.width: 5472 rawdata.sizes.height 3656 memsize 40011264 bayer_pattern RGGB
DEBUG   35.202770 sec   : read_libraw: memsize (40011264) naxis (2) w (5472) h (3656) bpp (16) bayer pattern (RGGB)
DEBUG   35.247405 sec   : Subframing... subFrameSize: 39632384 - oneFrameSize: 39632384 - subX: 0 - subY: 0 - subW: 5456 - subH: 3632
DEBUG   35.740931 sec   : Uploading file. Ext: fits, Size: 39637440, sendImage? Yes, saveImage? No
DEBUG   36.790822 sec   : BLOB transfer took 1.04969 seconds
DEBUG   36.790981 sec   : Upload complete
INFO    46.274509 sec   : Starting 6 seconds exposure.

...

DEBUG   54.153053 sec   : File added event completed.
DEBUG   54.158079 sec   : Downloading image... Name: (capt0002.arw) Folder: (/) Delete from SD card? (false)
DEBUG   54.320478 sec   : Could not determine image size (Unspecified error)
INFO    54.492608 sec   : Exposure done, downloading image...
DEBUG   56.850036 sec   : read_libraw: raw_width: 5504 top_margin 0 left_margin 0 first_visible_pixel 0
DEBUG   56.850207 sec   : read_libraw: rawdata.sizes.width: 5472 rawdata.sizes.height 3656 memsize 40011264 bayer_pattern RGGB
DEBUG   56.928127 sec   : read_libraw: memsize (40011264) naxis (2) w (5472) h (3656) bpp (16) bayer pattern (RGGB)
DEBUG   56.972947 sec   : Subframing... subFrameSize: 39632384 - oneFrameSize: 39632384 - subX: 0 - subY: 0 - subW: 5456 - subH: 3632
DEBUG   57.444006 sec   : Uploading file. Ext: fits, Size: 39637440, sendImage? Yes, saveImage? No
DEBUG   58.508581 sec   : BLOB transfer took 1.06396 seconds
DEBUG   58.508714 sec   : Upload complete
INFO    125.834484 sec  : Starting 6 seconds exposure.

...

logs after patch

log_patched.txt

After applying the aforementioned patch: all the files to be downloaded (GP_EVENT_FILE_ADDED events) are 'drained' until GP_EVENT_CAPTURE_COMPLETE. The last file's data is the one passed to the caller. Driver works as expected.

I was inspired by this comment: https://github.com/gphoto/gphoto2/issues/48#issuecomment-294225211

Excerpt:

DEBUG   9.271595 sec    : Exposure complete.
DEBUG   10.450409 sec   : Event timed out #1, retrying...
DEBUG   12.417993 sec   : File added event completed.
DEBUG   12.418198 sec   : Deleting aborted image... Name: (capt0000.arw) Folder: (/)
DEBUG   12.530922 sec   : Could not determine image size (Unspecified error)
DEBUG   14.373861 sec   : File added event completed.
DEBUG   14.374023 sec   : Deleting aborted image... Name: (capt0001.arw) Folder: (/)
DEBUG   14.483128 sec   : Could not determine image size (Unspecified error)
DEBUG   16.224815 sec   : File added event completed.
DEBUG   16.224969 sec   : Deleting aborted image... Name: (capt0002.arw) Folder: (/)
DEBUG   16.334314 sec   : Could not determine image size (Unspecified error)
DEBUG   16.344237 sec   : Capture event completed.
DEBUG   72.498099 sec   : Requested CCD Frame is (0,0) (5456 x 3632)
INFO    72.498755 sec   : Starting 1 seconds exposure.

msmeissn commented 4 years ago

I think the event handling in indi should cope with 1 or more images being added, which can happen if you do triggering outside of the usb protocol, (or even if someone presses the shutter button).

knro commented 4 years ago

@m-kostrzewa Thank you for the detailed report!

@msmeissn I'm trying to do that now, but it appears that some cameras (e.g. my Canon 600D) the event GP_EVENT_CAPTURE_COMPLETE is never received while it is triggered for Nikon 3500D. Can you please check gphoto_read_exposure_fd and see what we're doing wrong? Right now the function returns after GP_EVENT_FILE_ADDED which works for the majority of cameras.

knro commented 4 years ago

@m-kostrzewa Can you please apply this patch and see if it works in your case?

gphoto.zip

msmeissn commented 4 years ago

CAPTURE_COMPLETE is not reliable sadly. I would poll events with a short timeout and see if I get a GP_EVENT_TIMEOUT timeout back if I not expecting more pictures.

knro commented 4 years ago

@msmeissn This is exactly what I did in the patch above! Will wait for @m-kostrzewa to test it out. Thank you for the feedback.

m-kostrzewa commented 4 years ago

@knro thanks for swift reply. I tested your patch on sequences of 1sec and 15sec exposures. Works great.

knro commented 4 years ago

@m-kostrzewa does it work for 30+ sec exposures as well?

msmeissn commented 4 years ago

@msmeissn This is exactly what I did in the patch above! Will wait for @m-kostrzewa to test it out. Thank you for the feedback.

Ah yes, looks good. :)

m-kostrzewa commented 4 years ago

@knro tested on sequence of 60 sec exposures, it works

m-kostrzewa commented 4 years ago

@k-ross tested it tonight on sequences of 180, 300, 600sec exposures. I've encountered some hiccups. Good news is that the happy path works great, and I think this bug is resolved.

The hiccups I encountered were mostly "sad path" edge cases. Some were encountered because I prefer to focus the camera using mobile phone WiFi app. When I'm done I turn the app off and reconnect INDI driver. There were also instances where Ekos sequence aborts/pauses made the camera "stuck". I haven't debugged it too much nor marked the logs in any way though... When I encounter these issues again I will report them properly. Here's my memory dump:

Disconnecting/connecting the camera via Ekos sometimes works, sometimes doesn't with error message to check the cable. May be user error on my part.
Sometimes the first preview exposure after reconnecting to INDI driver from Ekos is stuck in "Downloading", even though it appears in the preview. Maybe this suggests the event handling routine can be made more resilient? (I will need to capture better logs for this as I don't know how to reproduce).
one time, I had error where driver couldn't connect to the camera at all, I had to restart everything (kstars+ekos, indi drivers, camera power cycle).
This was encountered also before patching, but almost always when connecting INDI sony driver via Ekos, an exposure is immediately started. There's an easy workaround - just abort it once after connection is estabilished via Ekos GUI. I've no idea why this happens though.

But as I said, I think this bug is mostly resolved. Thanks.

kleb0nas12 commented 3 years ago

Hi guys , If someone would be able to explain how to 'patch' this problem that would be great! Because I am facing exact the same problem (with sony alpha a5000) and the only thread I found on internet is here. The problem is the same: ekos only donwloads every second photo and sometime , on start hangs with the first one.

glundby commented 3 years ago

Long time since I did the hack but here is the links I used then: https://github.com/ma1co/Sony-PMCA-RE/releases/tag/v0.17 https://github.com/ma1co/OpenMemories-Tweak/issues/169 Happy hacking :-)

m-kostrzewa commented 3 years ago

@kleb0nas12

I built it manually months ago and can't remember the details, but the overall structure of what needs to be done is as follows

Download .zip file uploaded by @knro
Need to clone (using git) some indi repositories in order to build indi drivers (can't remember which, sorry)
Use git apply to apply code patch from the .zip file
Download indi build dependencies (need to go through relevant README files in some repo)
Build relevant indi driver (can't remember which, but filename in .zip should help) using make asdfasfasdf command. This is also described in some README file in some repo.
Find the old driver binary, back it up, replace with the one you've built.

It's kinda cumbersome. If you have software development/IT experience it should help. Even then, building such big project for the first time is often frustrating :) and takes some time. If you hit any road blockers, don't be afraid to ask

Ideally, @knro merges his patch and it is released officially in newer version soon. But I imagine it's a breaking change for some other camera models. @knro what is stopping you from merging your patch?

m-kostrzewa commented 3 years ago

Actually, as https://github.com/indilib/indi-3rdparty/issues/230 noticed, this patch is already merged to main branch.

So just needs to download the newest version of indi driver, @kleb0nas12

@knro may I close this issue?

kleb0nas12 commented 3 years ago

I am using up-to-date indi drivers (sudo apt update doens't update/upgrade indi drivers?)

knro commented 3 years ago

Right INDI packages already have this in. Check that you have INDI v1.8.7 installed.

peppuccio commented 3 years ago

Hello, I have the same problem with my Sony A7S. I'm new to open solutions and run an astroberry version on PI 4 under Raspberry OS. How can I be sure that my Indi version is the good one?

Thanks J. Ferraro Paris

m-kostrzewa commented 3 years ago

Show apt list --installed, look for indi

If version is too low, try

sudo apt-get update && apt-get upgrade

If version is still too low, report back. I haven't tried this yet :)

peppuccio commented 3 years ago

Thanks for you response... the first one since I try to solve this problem ! here is a capture for apt list --installed indi-version

And the same command after apt-get update && apt-get upgrade indi-version2 It's sounds to me that I don't have 1.8.7 version in both case

G. Ferraro

m-kostrzewa commented 3 years ago

Hmm.. maybe newest version is not in apt repository yet...

In this case, you must build the software yourself.

Try following https://github.com/indilib/indi-3rdparty#building-individual-3rd-party-drivers-typically-recommended. However, instead of indi-eqmod, use indi-gphoto everywhere.

Remember, to

git clone --depth=1 https://github.com/indilib/indi-3rdparty
sudo apt-get install libnova-dev libcfitsio-dev libusb-1.0-0-dev zlib1g-dev libgsl-dev build-essential cmake git libjpeg-dev libcurl4-gnutls-dev libtiff-dev libftdi-dev libgps-dev libraw-dev libdc1394-22-dev libgphoto2-dev libboost-dev libboost-regex-dev librtlsdr-dev liblimesuite-dev libftdi1-dev

first

If you encounter problems let me know, I'll try to help

peppuccio commented 3 years ago

Thanks a lot. I put a request in the Astroberry section of the Indi Forum. I would prefer an official package... We have a forecast of 10 days raining here in Paris... and If needed I can use an ascom driver under widows!

G. Ferraro

kleb0nas12 commented 3 years ago

Yes indeed. I reinstalled INDI on my raspberry pi , and it still 1.8.6

peppuccio commented 3 years ago

I open an issue in the astroberry section of the INDI forum, but I receive no reply. Perhaps it is due to the new year vacations?

G. Ferraro

kleb0nas12 commented 3 years ago

I don't know, but there is still the same 1.8.6 version.

indilib / indi-3rdparty

indi-gphoto indi_sony_ccd Sony a5000 subsequent exposures not captured #151