gphoto / gphoto2

The gphoto2 commandline tool for accessing and controlling digital cameras.
GNU General Public License v2.0
707 stars 116 forks source link

USB transfer speed #95

Open nah0y opened 7 years ago

nah0y commented 7 years ago

Hello,

I just wanted to know if there is some factor to improve the transfer speed when downloading pictures? It takes more than 7 seconds to transfer a picture of 1.4MB when I do that on a router where I installed OpenWRT, which seems odd because it takes less than 0.5 seconds when I do that on my iMac.

Thanks!

msmeissn commented 7 years ago

it might depends on the USB stack of the device.

If you want to cross check, captuyre a debugtrace of gphoto2 and look at the timestamps

nah0y commented 7 years ago

I'm sorry, I searched a little bit and haven't really found how to capture a debugtrace... could you point me to the right direction? Thanks!

nah0y commented 6 years ago

Sorry I just figured out that a debugtrace is maybe just adding --debug at the end of the command...

Anyway... It seems that what's taking a LOT of time is related to gp_port* The first time it's slow is right after detecting the camera drivers, it seems the "Counting entries available" takes more than 1sc. Look at the log:

0.090780 foreach_func (2): Found '/usr/lib/libgphoto2/2.5.10/toshiba_pdrm11'. 0.090920 foreach_func (2): Found '/usr/lib/libgphoto2/2.5.10/tp6801'. 0.091107 gp_abilities_list_load_dir (2): Found 64 camera drivers. 0.108062 gp_abilities_list_load_dir (2): Failed to load '/usr/lib/libgphoto2/2.5.10/ax203': file not found. 0.537847 gp_abilities_list_load_dir (2): Failed to load '/usr/lib/libgphoto2/2.5.10/st2205': file not found. 0.564528 gp_abilities_list_load_dir (2): Failed to load '/usr/lib/libgphoto2/2.5.10/tp6801': file not found. 1.916585 gp_port_info_list_count (2): Counting entries (10 available)...
1.925122 gp_port_info_list_count (2): 6 regular entries available. 1.926551 gp_port_new (2): Creating new device...

Same thing here, it takes 0.5s

2.019684 gp_setting_set (2): Setting key 'model' to value 'USB PTP Class Camera' (gphoto2) 2.019835 save_settings (2): Saving 2 setting(s) to file "/root/.gphoto/settings" 2.617082 gp_port_info_list_lookup_path(2): Looking for path 'usb:001,007' (10 entries available)... 2.617251 gp_port_info_list_get_info (2): Getting info of entry 5 (10 available)...

And after that, it correctly triggers the download of the picture, but it's downloading it little by little. First at the very beginning there's a timeout reading from or writing to the port.

2.640656 gp_camera_init (2): Loading '/usr/lib/libgphoto2/2.5.10/ptp2'... 2.644207 gp_port_open (2): Opening USB port... 2.644741 gp_libusb1_open (2): () 2.645369 gp_libusb1_open (2): claiming interface 0 2.647750 camera_init (2): maxpacketsize 512 2.656901 gp_port_set_timeout (2): Setting port timeout to 8000 milliseconds. 2.657485 ptp (2): PTP: Opening session 2.658105 ptp_usb_sendreq (2): Sending PTP_OC 0x1002 (Open session) request... 2.658525 gp_port_write (3): Writing 16 = 0x10 bytes to port... 10.659396 gp_libusb1_write libusb1.c:557: 'libusb_bulk_transfer (port->pl->dh, port->settings.usb.outep, (unsigned char*)bytes, size, &curwritten, port->timeout)' failed: Operation timed out (-7) 10.659571 gp_port_write gphoto2-port.c:402: Writing 16 = 0x10 bytes to port failed: Timeout reading from or writing to the port (-10) 10.659698 ptp_usb_sendreq [usb.c:98] (0): PTP_OC 0x1002 sending req failed: Timeout reading from or writing to the port (-10) 10.659829 camera_init library.c:7493: 'ptp_opensession (params, sessionid)' failed: PTP I/O Error (0x02ff) 10.659948 ptp_usb_control_device_reset_request(2): Sending usb device reset request. 10.660076 gp_port_usb_msg_class_write (3): Writing message (request=0x66 value=0x0 index=0x0 size=0=0x0): (no hexdump, NULL buffer) 10.679581 ptp (2): PTP: Opening session 10.694753 ptp_usb_sendreq (2): Sending PTP_OC 0x1002 (Open session) request... 10.697147 gp_port_write (3): Writing 16 = 0x10 bytes to port... 10.698337 gp_port_write (3): Wrote 16 = 0x10 bytes to port: (hexdump of 16 bytes) 0000 10 00 00 00 01 00 02 10-00 00 00 00 01 00 00 00 ................

10.698525 ptp_usb_getresp (2): Reading PTP_OC 0x1002 (Open session) response... 10.698675 gp_port_read (3): Reading 1024 = 0x400 bytes from port... 10.699875 gp_port_read (3): Read 12 = 0xc out of 1024 bytes from port: (hexdump of 12 bytes)

But then it continues correctly and starts downloading the picture piece by piece. In the debug we can see a message "Reading 65536..." then we see the byte array, then again "Reading 65536...", then the next byte array etc... and between each of them, there's around 1sc. (And there's a lot of them...) So it goes something like:

11.036799 gp_port_read (3): Reading 65536 = 0x10000 bytes from port... 11.084141 gp_port_read (3): Read 65536 = 0x10000 bytes from port: (hexdump of 65536 bytes) BYTE ARRAY DISPLAYED HERE 12.158934 gp_port_read (3): Reading 65536 = 0x10000 bytes from port... 12.184466 gp_port_read (3): Read 65536 = 0x10000 bytes from port: (hexdump of 65536 bytes) BYTE ARRAY DISPLAYED HERE 13.205813 gp_port_read (3): Reading 65536 = 0x10000 bytes from port... 13.224143 gp_port_read (3): Read 65536 = 0x10000 bytes from port: (hexdump of 65536 bytes)

Until it finished. Total time to download a 5.5MB picture, around 30sc.

Here's the "full" log: https://pastebin.com/yp9ptd4r I cut out some parts where it prints some byte arrays otherwise the file would be ultra huge.

Thanks for your help...

mccodesurfer commented 6 years ago

Yes, I'm using gphoto2 in Stellarmate (RPi3) observatory controller and discovered the long time (30-40 secs) to download pictures must be between the camera (Pentax K-5II) and the RPi3. Can this be improved? Is it only some DSLRs? Only Pentax?

msmeissn commented 6 years ago

The 2 -> 10 second timeout is because the device does not react on this write for some reason. Might be because something else has it open, like gvfs or so?

The other delays just seem general slowness. Wriiting the debuglog also takes a bits of these 1-2 seconds per 64k block.

nah0y commented 6 years ago

Hello.

"because the device does not react on this write for some reason" What does that mean, that is does not react?

Also, I don't think anything else has it open, this is the only thing I run on the device. And yes debugging takes some seconds, but even without debugging it's taking a lot of time.

msmeissn commented 6 years ago

it retries the the write , and succeds on the second time . nothing to worry, just the delay ins interesting. It is not visible in the pastebined trace.

robeastham commented 6 years ago

If I was buying a new mirrorless camera and I wanted to avoid slow speeds like this what would people (or Marcus) recommend? I'm assuming gphoto2 does not support WiFi or Bluetooth. But wondered if there are any newer cameras perhaps with USB C or USB 3.0 that can be used reliably?

Ideally Canon, Sony or Nikon. If not mirrorless then I would consider an SLR.

msmeissn commented 6 years ago

the usb protocol level is pretty much independend of libgphoto2, so if the camera supports usb 3 it will also just work.

for wifi we support PTP/IP but not other interfaces.