gphoto / libgphoto2

The libgphoto2 camera access and control library.
GNU Lesser General Public License v2.1
989 stars 316 forks source link

Nikon D780 USB interaction becomes slow in shell mode #947

Open geeze123 opened 6 months ago

geeze123 commented 6 months ago

Am trying to use a Nikon D780, instead of D600/D610, with my gphoto2/libgphoto2 shell-mode setup. The D780 USB communication is, or within minutes or hours becomes, "slow". Each "get-config" or "set-config" takes multiple seconds to complete. These requests should be measured in sub-seconds, or milliseconds. Looking at the gphoto2 debug-output, there seem to be a lot of extra communication generated from libgphoto2, et al.

I started out, running with: gphoto2 2.5.28 gcc, popt(m), exif, no cdk, no aa, jpeg, no readline libgphoto2 2.5.30 standard camlibs (SKIPPING lumix), gcc, no ltdl, no EXIF libgphoto2_port 0.12.1 iolibs: disk ptpip serial usb1 usbdiskdirect usbscsi, gcc, no ltdl, no EXIF, USB, serial without locking

Have also tried this, with the same/similar "slowliness": gphoto2 2.5.28 gcc, popt(m), exif, no cdk, no aa, jpeg, no readline libgphoto2 2.5.31 standard camlibs (SKIPPING docupen lumix), gcc, no ltdl, no EXIF libgphoto2_port 0.12.2 iolibs: disk ptpip serial usb usbdiskdirect usbscsi, gcc, no ltdl, no EXIF, USB, serial without locking

The gphoto2 front end is run in "shell"-mode from a perl-script. The stdin/stdout from gphoto2 is used by the perl-script to get/set parameters and handle photo events. If nothing else is going on, the "capture-tethered 500ms" command is run. Repeated until there is time to read or write a parameter, or something else happens. Once or twice a minute, some parameters (ca 5-10) are read. With some minutes of interval, other parameters (ca 5-10) might get read and written. For the Nikon D780, these gphoto2 parameter reads or writes seem to become very slow, either immediatly, or after a (long or short) while.

Here is a gphoto2 debug file, where the "slowliness" appears to exist from the beginning or start early: gphoto2_debug_1704471442.txt

(note: in the beginning of the scenario, all parameters are read and some are written before the "shell"-mode and the first "capture-tethered 500 ms" starts)

msmeissn commented 5 months ago

currently we have a property cache , that has a 5 second timeout (currently hardcoded). After that it would refetch everything. as the nikon Dxxx series have a lot of properties this could be a bit slow.

Is the same happening with the command line options or only via shell mode?

what kind of commands are you doing in the shell mode?

I think it might need an optimzation there too.

geeze123 commented 5 months ago

The shell mode commands: 'capture-tethered 500ms' (most frequent), get_config, and a few set_config.

Every 30 s, get_config:

Every, ca 5 min, get_config:

geeze123 commented 5 months ago

After ca 2 days of continuously running with the "slow" behavior, it ended up with a situation where each "gp_port_write" would timeout and report "Error writing to the port (-35)".

See attached gphoto2 debug file. (note: back to libgphoto 2.5.30) my-logfile-timeout-errors.txt

geeze123 commented 5 months ago

After a system (and camera) restart, and running with the "--shell"-mode, I noticed it was behaving "slow", again.

I now ran a command line, with multiple parameter settings, without getting the "slow" behavior:

env LANG=C /usr/local/bin/gphoto2 --debug --debug-logfile=/root/my-logfile-set-multiple-params--date +%s.txt --no-keep --delete-all-files --force-overwrite --set-config recordingmedia=1 --set-config-value datetime=now --set-config d030=0 --set-config d033=0 --set-config-value d054=0 --set-config-value iso=400 --set-config-value f-number=f/4 --set-config-value shutterspeed2=1/1250 --set-config-value exposurecompensation=0 --set-config-value imagesize=6048x4024 --set-config-value imagequality="JPEG Basic"

See attached gphoto2 debug file. my-logfile-set-multiple-params--1705326253.txt

geeze123 commented 5 months ago

As it stands, will try to extend the hard coded (5s) cache timeout. Thanks.

geeze123 commented 5 months ago

Added the following line to my .gphoto/settings: ptp2=cachetime=20

For the past few hours, the camera communication has been running ok. Will keep an eye on it. Not sure what the side effects are in this scenario, but will likely trim the setting down a bit.

IN DEPTH: As Nikon D780 is a PTP2, I focused on that. "cachetime" seems to determine if parameter values are current. Default, "cachetime" is 2 s, but ptp2/library.c reads "cachetime" ("ptp2"-subgroup), if available, from the "settings"-file (via "gp_settings_get").

geeze123 commented 5 months ago

FYI "ptp2=cachetime=10" is also ok after ca 3 days of constant uptime