gphoto / libgphoto2

The libgphoto2 camera access and control library.
GNU Lesser General Public License v2.1
1.06k stars 325 forks source link

Bad handling of unhandled events in camera_nikon_capture #846

Closed omrisarig13 closed 2 years ago

omrisarig13 commented 2 years ago

Bug Description There is a very long (unnecessary) delay when taking pictures with a Nikon (Z9) camera when there are a lot of events in the queue.

I am taking pictures with my Nikon camera, after changing some camera properties. In that case, after sending the capture event, there are always more events that are being sent from the camera to the device right after asking for capture (in my case, a lot of events of 0x4006 (DevicePropChanged)). In my case, it can be up to additional 10 seconds of delay after changing a property in the device.

Code Investigation I've investigated the relevant code to understand how can this delay be minimized. The relevant function in the code is camera_nikon_capture in camlibs/ptp2/library.c.

The loop that takes a long time is the one waiting for the finishing events (0x4002 and 0x400D). The full loop is here: https://github.com/gphoto/libgphoto2/blob/e0e4da2d5c87d7406c644f419a5ca58be0a90d4d/camlibs/ptp2/library.c#L4168-L4243 This loop has an internal loop, that runs over the current events in the system. This loop breaks whenever it reaches an event that is not handled, to avoid an endless loop (by changing the value of checkevt): https://github.com/gphoto/libgphoto2/blob/e0e4da2d5c87d7406c644f419a5ca58be0a90d4d/camlibs/ptp2/library.c#L4224-L4229

The camera does not remove the unhandled event, but adds it back to the end of the queue, meaning that the next time, it'll start again from the start of the queue, and have this event again at the end.

When the internal loop ends, the function goes back to the external loop, which runs again after checking for a timeout (which also includes sleeping for some time): https://github.com/gphoto/libgphoto2/blob/e0e4da2d5c87d7406c644f419a5ca58be0a90d4d/camlibs/ptp2/library.c#L4243

The timeout waiting function (waiting_for_timeout), has a delay inside it (of up to 200ms, gradually increasing in every call). This means that the loop will run again, and keep looking at the events in the queue, after a 200ms delay.

When I'm looking at the event queue in my system, it has about 50 events of 0x4006, followed by an event of 0x4002 and an event of 0x400D (which are the needed ones). In the current implementation, the loop will handle only one unexpected event every time (0x4006 is the unexpected event, in my case), which introduces a delay of about 10 seconds (50 events * 0.2 seconds of delay between every two events).

Patch I've created a patch that solves the issue for me, but I don't think it is up to standards in the code. The patch is attached to this issue.

With this patch, the internal loop runs according to the number of events in the loop, instead of running as long as there are still events. This change makes it unnecessary to break the loop every time an unhandled event is encountered.

The issue with this patch is that it directly references the value of params->nrofevents in library.c, which always happens through helper functions in the other parts of the library. There wasn't any helper function to get this value, so I wasn't sure if one should be added or if any other solution is preferred.

I'd be happy to create a pull request in case this solution is acceptable, or modify it according to any wanted standards.

Camera Nikon Z9

libgphoto2 version The library was compiled from the sources of the latest master: e0e4da2d5c87d7406c644f419a5ca58be0a90d4d

Output of: gphoto2 --version:

gphoto2 2.5.28.1

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.1       gcc, popt(m), exif, no cdk, no aa, jpeg, readline
libgphoto2      2.5.30.1       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

Reproducing I encountered this issue after changing a property value in the camera and then calling the capture function.

In my case, the code looks something like this (pseudo-code):

// Init
GPContext *context = = sample_create_context();
Camera *camera;
gp_camera_new(camera);
gp_camera_init(camera, context);
[log.txt](https://github.com/gphoto/libgphoto2/files/9704431/log.txt)

// Change property
PTPParams *params = &camera->pl->params;
PTPPropertyValue propval;
ropval.u8 = selector_value;
ptp_setdevicepropvalue(params, PTP_DPC_NIKON_LiveViewSelector, &propval, PTP_DTC_UINT8);
// It is possible (and probably necessary) to clear the events sent from the camera here as well. When doing so, the delay is lower (as there are fewer events in the queue), but it is still much longer than actually required.

// Capture a picture
CameraFilePath camera_file_path;
gp_camera_capture(camera, GP_CAPTURE_IMAGE, &camera_file_path, context);

A log is attached to the project. The log messages from the library are indented 1 level in. The program is doing more than just changing the property and taking a picture. The relevant lines are 831-2882 for the whole picture-taking operation or 941-1331 for only the loop which waits for events.

msmeissn commented 2 years ago

needs a bit thinking and testing about the requeuing technology.

msmeissn commented 2 years ago

i added a local event queue to avoid these repeated checks.

can you check current git?

omrisarig13 commented 2 years ago

Hi @msmeissn

The solution looks quite elegant, but had some pointer issues - it took the wrong pointers in two locations in the code, that caused the code to fail with Seg-fault.
I fixed these issues and opened a pull request (#849).


I believe the memory allocated by the function ptp_add_event_queue is never freed in the current implementation. Currently, this function allocates memory for the storedevents queue from camera_nikon_capture: https://github.com/gphoto/libgphoto2/blob/540762d91f62019d05cbb29fd60adae17fbf9c9f/camlibs/ptp2/library.c#L4064

I did not add any freeing of this memory. I don't think I have a good enough understanding of the current allocation/freeing mechanism to know where this should be added.

omrisarig13 commented 2 years ago

Also, just to mention, I ran the code and made sure that it was working with my camera for my current needs. I did not run any extensive tests on the code (did not make sure that all the events are available after the re-queueing, for example).

msmeissn commented 2 years ago

yeah, i need to add freeing, true. will keep it open until i get to it in the next days.

msmeissn commented 2 years ago

i added freeing