search

gphoto / libgphoto2

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

sporadic error -7 with a5100 / a6300 and possibly other (sony) cameras #376

Open notnot opened 5 years ago

notnot commented 5 years ago

I am capturing images and downloading them in a loop, using libgphoto2. Occasionally gp_camera_capture() returns error -7 (Generic I/O error). Rarely can the camera take more than a few hundred photos in a row. When i add a sleep of 1 second after gp_camera_capture() and also after gp_camera_file_get(), this error doesn't seem to occur, at least i haven't seen it happen yet. I wonder if i am doing something wrong. Are the above functions not blocking, and should i somehow use the event system to know when it is safe to initiate the next capture?

Note that both these cameras can capture and download previews at 25 Hz without any such errors. I have let them run for more than a week continuously to test reliability. I am building a machine vision system that should run 24/7 for several months without human intervention, so this error really is an obstacle. I am not sure yet that i can trust the workaround with the added pauses.

I have seen this behavior with both the Sony a5100 and a6300 cameras. I use libgphoto version 2.5.19.

notnot commented 5 years ago

I am running a long test tonight with my own application, trying to capture 10000 photos in a row. Once that test has finished, i will do a test with gphoto2 on the command line, with a minimal interval between captures. If gphoto2 has the same error, i know that the fault is not in my application but in libgphoto2.

Sija commented 5 years ago

@notnot Since there were more than a couple of improvements in the last versions, I'd advise to update gphoto2 to the newest version before running the tests.

msmeissn commented 5 years ago

it is likely a protocol / libgphoto2 issue. As Sija writes, perhaps the newer current git helps, but without having debuginfo its hard to say what the issue is. If you can get a debug trace of this failure it would be good to see.

notnot commented 5 years ago

By the way, the test to capture and download 10000 photos, with 1 second pauses went well, so this might be a practical plan B.

loop:
    gp_camera_capture()
    sleep 1 second
    gp_camera_file_get()
    sleep 1 second

I also tried pauses of half a second, or just single pauses of 1 second in one location. I got the -7 error eventually in all these cases.

notnot commented 5 years ago

How to get the debug trace? It is easy to reproduce the issue.

msmeissn commented 5 years ago

with gphoto2 use options --debug --debug-logfile=xx.log

with C code something around this kind of code:

static void errordumper(GPLogLevel level, const char domain, const char str, void *data) { fprintf(stdout, "%s\n", str); }

    gp_log_add_func(GP_LOG_DATA, errordumper, NULL);

(or GP_LOG_DEBUG as data will log also all data traffic)

Use of debug logging might change the timing again though.

notnot commented 5 years ago

Thanks msmeissn, i will incorporate that kind of error printing into my code. Today i did a few more tests:

gphoto2 -I 2 -F 10000 --capture-image-and-download

This completed without any issues, even though the capture rate was faster than the earlier test with an interval of 3 seconds.

In my own application i reduced the complexity to a minimum and only do 

loop:
    go_camera_capture()
    sleep ? milliseconds

I am still trying out various amounts of pause times, but i do have the impression that the issue doesn't occur that frequently as when combined with the downloading. I have seen several perfect runs of 1000 captures with no pausing at all.

I hope to report back to you with a detailed error log!

notnot commented 5 years ago

Ok, here is the tail of typical debug trace:

LOG: level 2, domain 'camera_sony_capture', data 'DEBUG== 0xd215 after capture = 0'
LOG: level 2, domain 'ptp_usb_sendreq', data 'Sending PTP_OC 0x9209 (PTP_OC_SONY_GetAllDevicePropData) request...'
LOG: level 2, domain 'ptp_usb_getdata', data 'Reading PTP_OC 0x9209 (PTP_OC_SONY_GetAllDevicePropData) data...'
LOG: level 2, domain 'ptp_usb_getresp', data 'Reading PTP_OC 0x9209 (PTP_OC_SONY_GetAllDevicePropData) response...'
LOG: level 2, domain 'camera_sony_capture', data 'DEBUG== 0xd215 after capture = 0'
LOG: level 2, domain 'ptp_usb_sendreq', data 'Sending PTP_OC 0x9209 (PTP_OC_SONY_GetAllDevicePropData) request...'
LOG: level 2, domain 'ptp_usb_getdata', data 'Reading PTP_OC 0x9209 (PTP_OC_SONY_GetAllDevicePropData) data...'
LOG: level 2, domain 'ptp_usb_getresp', data 'Reading PTP_OC 0x9209 (PTP_OC_SONY_GetAllDevicePropData) response...'
LOG: level 2, domain 'camera_sony_capture', data 'DEBUG== 0xd215 after capture = 0'
LOG: level 2, domain 'ptp_usb_sendreq', data 'Sending PTP_OC 0x9209 (PTP_OC_SONY_GetAllDevicePropData) request...'
LOG: level 2, domain 'ptp_usb_getdata', data 'Reading PTP_OC 0x9209 (PTP_OC_SONY_GetAllDevicePropData) data...'
LOG: level 2, domain 'ptp_usb_getresp', data 'Reading PTP_OC 0x9209 (PTP_OC_SONY_GetAllDevicePropData) response...'
LOG: level 2, domain 'camera_sony_capture', data 'DEBUG== 0xd215 after capture = 0'
LOG: level 2, domain 'camera_sony_capture', data 'ending image availability'
LOG: level 0, domain 'camera_sony_capture [library.c:4150]', data 'no object found during event polling. try the 0xffffc001 object id'
LOG: level 2, domain 'ptp_usb_sendreq', data 'Sending PTP_OC 0x1008 (Get object info) (0xffffc001) request...'
LOG: level 2, domain 'ptp_usb_getdata', data 'Reading PTP_OC 0x1008 (Get object info) data...'
LOG: level 2, domain '_cb_irq', data '0x1172758 with status 5'
LOG: level 2, domain '_cb_irq', data 'Transfer 0x1172758 should be in LIBUSB_TRANSFER_COMPLETED, but is 5!'
LOG: level 2, domain '_cb_irq', data '0x1172658 with status 5'
LOG: level 2, domain '_cb_irq', data 'Transfer 0x1172658 should be in LIBUSB_TRANSFER_COMPLETED, but is 5!'
LOG: level 2, domain '_cb_irq', data '0x1176118 with status 5'
LOG: level 2, domain '_cb_irq', data 'Transfer 0x1176118 should be in LIBUSB_TRANSFER_COMPLETED, but is 5!'
LOG: level 2, domain '_cb_irq', data '0x11a8478 with status 5'
LOG: level 2, domain '_cb_irq', data 'Transfer 0x11a8478 should be in LIBUSB_TRANSFER_COMPLETED, but is 5!'
LOG: level 2, domain '_cb_irq', data '0x11a8228 with status 5'
LOG: level 2, domain '_cb_irq', data 'Transfer 0x11a8228 should be in LIBUSB_TRANSFER_COMPLETED, but is 5!'
LOG: level 2, domain '_cb_irq', data '0x11894d8 with status 5'
LOG: level 2, domain '_cb_irq', data 'Transfer 0x11894d8 should be in LIBUSB_TRANSFER_COMPLETED, but is 5!'
LOG: level 2, domain '_cb_irq', data '0x1189288 with status 5'
LOG: level 2, domain '_cb_irq', data 'Transfer 0x1189288 should be in LIBUSB_TRANSFER_COMPLETED, but is 5!'
LOG: level 2, domain '_cb_irq', data '0x1187ec8 with status 5'
LOG: level 2, domain '_cb_irq', data 'Transfer 0x1187ec8 should be in LIBUSB_TRANSFER_COMPLETED, but is 5!'
LOG: level 2, domain '_cb_irq', data '0x1187c78 with status 5'
LOG: level 2, domain '_cb_irq', data 'Transfer 0x1187c78 should be in LIBUSB_TRANSFER_COMPLETED, but is 5!'
LOG: level 2, domain '_cb_irq', data '0x1172c28 with status 5'
LOG: level 2, domain '_cb_irq', data 'Transfer 0x1172c28 should be in LIBUSB_TRANSFER_COMPLETED, but is 5!'
LOG: level 0, domain 'gp_libusb1_read [libusb1.c:603]', data ''libusb_bulk_transfer (port->pl->dh, port->settings.usb.inep, (unsigned char*)bytes, size, &curread, port->timeout)' failed: Input/Output error (-1)'
LOG: level 0, domain 'gp_port_read [gphoto2-port.c:441]', data 'Reading 1024 = 0x400 bytes from port failed: Error reading from the port (-34)'
LOG: level 2, domain 'ptp_usb_getpacket', data 'Clearing halt on IN EP and retrying once.'
LOG: level 2, domain 'gp_port_usb_clear_halt', data 'Clear USB halt...'
LOG: level 0, domain 'gp_libusb1_clear_halt_lib [libusb1.c:575]', data ''libusb_clear_halt(port->pl->dh, internal_ep)' failed: No such device (it may have been disconnected) (-4)'
LOG: level 0, domain 'gp_libusb1_read [libusb1.c:603]', data ''libusb_bulk_transfer (port->pl->dh, port->settings.usb.inep, (unsigned char*)bytes, size, &curread, port->timeout)' failed: No such device (it may have been disconnected) (-4)'
LOG: level 0, domain 'gp_port_read [gphoto2-port.c:441]', data 'Reading 1024 = 0x400 bytes from port failed: Could not find the requested device on the USB port (-52)'
LOG: level 0, domain 'ptp_usb_getdata [usb.c:447]', data 'PTP_OC 0x1008 receiving data failed: PTP No Device (0x02f9)'
LOG: level 0, domain 'camera_sony_capture [library.c:4154]', data ''ptp_getobjectinfo (params, newobject, &oi)' failed: PTP I/O Error (0x02ff)'
LOG: level 0, domain 'gp_camera_capture [gphoto2-camera.c:1340]', data ''camera->functions->capture (camera, type, path, context)' failed: -7'
--- FAIL: TestCaptureImageAndDownload (38.39s)
    gphoto_test.go:76: CaptureImage(): gp_camera_capture(): error -7

I hope this sheds some light on things! If you need a longer trace, let me know. The output became too long for my terminal to scroll all the way back, but i could try writing it to a file.

Note: i am still using libgphoto2 version 2.5.19. I'll be upgrading to 2.5.22 tonight.

notnot commented 5 years ago

Here is an edited debug trace that also shows some of the output when capturing and downloading were still going well. When the trouble happens, a great number of repeated lines are printed, which i cut out and replaced with ..., followed with the tail of the trace.

...
lengthy init stuff omitted here...
...

LOG level 2: domain 'ptp'
  data 'event: nparams=0x1, code=0xC202, trans_id=0xFFFFFFFF, p1=0xFFFFC001, p2=0x0, p3=0x0'
LOG level 2: domain 'camera_sony_capture'
  data 'during event.code=c202 Param1=ffffc001'
LOG level 2: domain 'ptp_usb_sendreq'
  data 'Sending PTP_OC 0x9209 (PTP_OC_SONY_GetAllDevicePropData) request...'
LOG level 2: domain 'ptp_usb_getdata'
  data 'Reading PTP_OC 0x9209 (PTP_OC_SONY_GetAllDevicePropData) data...'
LOG level 2: domain 'ptp_usb_getresp'
  data 'Reading PTP_OC 0x9209 (PTP_OC_SONY_GetAllDevicePropData) response...'
LOG level 2: domain 'camera_sony_capture'
  data 'DEBUG== 0xd213 after shutter press = 1'
LOG level 2: domain 'gp_port_get_timeout'
  data 'Current port timeout is 20000 milliseconds.'
LOG level 2: domain 'gp_port_set_timeout'
  data 'Setting port timeout to 150 milliseconds.'
LOG level 2: domain 'gp_port_set_timeout'
  data 'Setting port timeout to 20000 milliseconds.'
LOG level 2: domain 'ptp'
  data 'event: nparams=0x1, code=0xC203, trans_id=0xFFFFFFFF, p1=0xD21D, p2=0x0, p3=0x0'
LOG level 2: domain 'camera_sony_capture'
  data 'during event.code=c203 Param1=0000d21d'
LOG level 2: domain 'ptp_usb_sendreq'
  data 'Sending PTP_OC 0x9209 (PTP_OC_SONY_GetAllDevicePropData) request...'
LOG level 2: domain 'ptp_usb_getdata'
  data 'Reading PTP_OC 0x9209 (PTP_OC_SONY_GetAllDevicePropData) data...'
LOG level 2: domain 'ptp_usb_getresp'
  data 'Reading PTP_OC 0x9209 (PTP_OC_SONY_GetAllDevicePropData) response...'
LOG level 2: domain 'camera_sony_capture'
  data 'DEBUG== 0xd213 after shutter press = 1'
LOG level 2: domain 'gp_port_get_timeout'
  data 'Current port timeout is 20000 milliseconds.'
LOG level 2: domain 'gp_port_set_timeout'
  data 'Setting port timeout to 150 milliseconds.'
LOG level 2: domain 'gp_port_set_timeout'
  data 'Setting port timeout to 20000 milliseconds.'
LOG level 2: domain 'ptp'
  data 'event: nparams=0x1, code=0xC201, trans_id=0xFFFFFFFF, p1=0xFFFFC001, p2=0x0, p3=0x0'
LOG level 2: domain 'camera_sony_capture'
  data 'during event.code=c201 Param1=ffffc001'
LOG level 2: domain 'ptp_usb_sendreq'
  data 'Sending PTP_OC 0x9209 (PTP_OC_SONY_GetAllDevicePropData) request...'
LOG level 2: domain 'ptp_usb_getdata'
  data 'Reading PTP_OC 0x9209 (PTP_OC_SONY_GetAllDevicePropData) data...'
LOG level 2: domain 'ptp_usb_getresp'
  data 'Reading PTP_OC 0x9209 (PTP_OC_SONY_GetAllDevicePropData) response...'
LOG level 2: domain 'camera_sony_capture'
  data 'DEBUG== 0xd213 after shutter press = 1'
LOG level 2: domain 'gp_port_get_timeout'
  data 'Current port timeout is 20000 milliseconds.'
LOG level 2: domain 'gp_port_set_timeout'
  data 'Setting port timeout to 150 milliseconds.'
LOG level 2: domain 'gp_port_set_timeout'
  data 'Setting port timeout to 20000 milliseconds.'
LOG level 2: domain 'ptp'
  data 'event: nparams=0x1, code=0xC203, trans_id=0xFFFFFFFF, p1=0x5005, p2=0x0, p3=0x0'
LOG level 2: domain 'camera_sony_capture'
  data 'during event.code=c203 Param1=00005005'
LOG level 2: domain 'ptp_usb_sendreq'
  data 'Sending PTP_OC 0x9209 (PTP_OC_SONY_GetAllDevicePropData) request...'
LOG level 2: domain 'ptp_usb_getdata'
  data 'Reading PTP_OC 0x9209 (PTP_OC_SONY_GetAllDevicePropData) data...'
LOG level 2: domain 'ptp_usb_getresp'
  data 'Reading PTP_OC 0x9209 (PTP_OC_SONY_GetAllDevicePropData) response...'
LOG level 2: domain 'camera_sony_capture'
  data 'DEBUG== 0xd213 after shutter press = 1'
LOG level 2: domain 'gp_port_get_timeout'
  data 'Current port timeout is 20000 milliseconds.'
LOG level 2: domain 'gp_port_set_timeout'
  data 'Setting port timeout to 150 milliseconds.'
LOG level 2: domain 'gp_port_set_timeout'
  data 'Setting port timeout to 20000 milliseconds.'
LOG level 2: domain 'ptp'
  data 'event: nparams=0x1, code=0xC202, trans_id=0xFFFFFFFF, p1=0xFFFFC001, p2=0x0, p3=0x0'
LOG level 2: domain 'camera_sony_capture'
  data 'during event.code=c202 Param1=ffffc001'
LOG level 2: domain 'ptp_usb_sendreq'
  data 'Sending PTP_OC 0x9209 (PTP_OC_SONY_GetAllDevicePropData) request...'
LOG level 2: domain 'ptp_usb_getdata'
  data 'Reading PTP_OC 0x9209 (PTP_OC_SONY_GetAllDevicePropData) data...'
LOG level 2: domain 'ptp_usb_getresp'
  data 'Reading PTP_OC 0x9209 (PTP_OC_SONY_GetAllDevicePropData) response...'
LOG level 2: domain 'camera_sony_capture'
  data 'DEBUG== 0xd213 after shutter press = 1'
LOG level 2: domain 'gp_port_get_timeout'
  data 'Current port timeout is 20000 milliseconds.'
LOG level 2: domain 'gp_port_set_timeout'
  data 'Setting port timeout to 150 milliseconds.'
LOG level 2: domain 'gp_port_set_timeout'
  data 'Setting port timeout to 20000 milliseconds.'
LOG level 2: domain 'ptp_usb_sendreq'
  data 'Sending PTP_OC 0x9209 (PTP_OC_SONY_GetAllDevicePropData) request...'
LOG level 2: domain 'ptp_usb_getdata'
  data 'Reading PTP_OC 0x9209 (PTP_OC_SONY_GetAllDevicePropData) data...'
LOG level 2: domain 'ptp_usb_getresp'
  data 'Reading PTP_OC 0x9209 (PTP_OC_SONY_GetAllDevicePropData) response...'
LOG level 2: domain 'ptp_usb_sendreq'
  data 'Sending PTP_OC 0x9209 (PTP_OC_SONY_GetAllDevicePropData) request...'
LOG level 2: domain 'ptp_usb_getdata'
  data 'Reading PTP_OC 0x9209 (PTP_OC_SONY_GetAllDevicePropData) data...'
LOG level 2: domain 'ptp_usb_getresp'
  data 'Reading PTP_OC 0x9209 (PTP_OC_SONY_GetAllDevicePropData) response...'
LOG level 2: domain 'camera_sony_capture'
  data 'DEBUG== 0xd213 after shutter press = 1'
LOG level 2: domain 'gp_port_get_timeout'
  data 'Current port timeout is 20000 milliseconds.'
LOG level 2: domain 'gp_port_set_timeout'
  data 'Setting port timeout to 150 milliseconds.'
LOG level 2: domain '_cb_irq'
  data '0x1d1b078 with status 0'
LOG level 2: domain '_cb_irq'
  data 'Requeuing completed transfer 0x1d1b078'
LOG level 2: domain 'gp_port_set_timeout'
  data 'Setting port timeout to 20000 milliseconds.'
LOG level 2: domain 'ptp'
  data 'event: nparams=0x1, code=0xC203, trans_id=0xFFFFFFFF, p1=0xD21D, p2=0x0, p3=0x0'
LOG level 2: domain 'camera_sony_capture'
  data 'during event.code=c203 Param1=0000d21d'
LOG level 2: domain 'ptp_usb_sendreq'
  data 'Sending PTP_OC 0x9209 (PTP_OC_SONY_GetAllDevicePropData) request...'
LOG level 2: domain 'ptp_usb_getdata'
  data 'Reading PTP_OC 0x9209 (PTP_OC_SONY_GetAllDevicePropData) data...'
LOG level 2: domain 'ptp_usb_getresp'
  data 'Reading PTP_OC 0x9209 (PTP_OC_SONY_GetAllDevicePropData) response...'
LOG level 2: domain 'camera_sony_capture'
  data 'DEBUG== 0xd213 after shutter press = 1'
LOG level 2: domain 'gp_port_get_timeout'
  data 'Current port timeout is 20000 milliseconds.'
LOG level 2: domain 'gp_port_set_timeout'
  data 'Setting port timeout to 150 milliseconds.'
LOG level 2: domain '_cb_irq'
  data '0x1d2f478 with status 0'
LOG level 2: domain '_cb_irq'
  data 'Requeuing completed transfer 0x1d2f478'
LOG level 2: domain 'gp_port_set_timeout'
  data 'Setting port timeout to 20000 milliseconds.'
LOG level 2: domain 'ptp'
  data 'event: nparams=0x1, code=0xC203, trans_id=0xFFFFFFFF, p1=0x5005, p2=0x0, p3=0x0'
LOG level 2: domain 'camera_sony_capture'
  data 'during event.code=c203 Param1=00005005'
LOG level 2: domain 'ptp_usb_sendreq'
  data 'Sending PTP_OC 0x9209 (PTP_OC_SONY_GetAllDevicePropData) request...'
LOG level 2: domain 'ptp_usb_getdata'
  data 'Reading PTP_OC 0x9209 (PTP_OC_SONY_GetAllDevicePropData) data...'
LOG level 2: domain 'ptp_usb_getresp'
  data 'Reading PTP_OC 0x9209 (PTP_OC_SONY_GetAllDevicePropData) response...'
LOG level 2: domain 'ptp'
  data 'ptp_sony_getalldevicepropdesc: d215: value 0 -> 1'
LOG level 2: domain 'camera_sony_capture'
  data 'DEBUG== 0xd213 after shutter press = 1'
LOG level 2: domain 'gp_port_get_timeout'
  data 'Current port timeout is 20000 milliseconds.'
LOG level 2: domain 'gp_port_set_timeout'
  data 'Setting port timeout to 150 milliseconds.'
LOG level 2: domain '_cb_irq'
  data '0x1d2c7a8 with status 0'
LOG level 2: domain '_cb_irq'
  data 'Requeuing completed transfer 0x1d2c7a8'
LOG level 2: domain 'gp_port_set_timeout'
  data 'Setting port timeout to 20000 milliseconds.'
LOG level 2: domain 'ptp'
  data 'event: nparams=0x1, code=0xC203, trans_id=0xFFFFFFFF, p1=0xD21D, p2=0x0, p3=0x0'
LOG level 2: domain 'camera_sony_capture'
  data 'during event.code=c203 Param1=0000d21d'
LOG level 2: domain 'ptp_usb_sendreq'
  data 'Sending PTP_OC 0x9209 (PTP_OC_SONY_GetAllDevicePropData) request...'
LOG level 2: domain 'ptp_usb_getdata'
  data 'Reading PTP_OC 0x9209 (PTP_OC_SONY_GetAllDevicePropData) data...'
LOG level 2: domain 'ptp_usb_getresp'
  data 'Reading PTP_OC 0x9209 (PTP_OC_SONY_GetAllDevicePropData) response...'
LOG level 2: domain 'camera_sony_capture'
  data 'DEBUG== 0xd213 after shutter press = 1'
LOG level 2: domain 'gp_port_get_timeout'
  data 'Current port timeout is 20000 milliseconds.'
LOG level 2: domain 'gp_port_set_timeout'
  data 'Setting port timeout to 150 milliseconds.'
LOG level 2: domain 'gp_port_set_timeout'
  data 'Setting port timeout to 20000 milliseconds.'
LOG level 2: domain 'ptp_usb_sendreq'
  data 'Sending PTP_OC 0x9209 (PTP_OC_SONY_GetAllDevicePropData) request...'
LOG level 2: domain 'ptp_usb_getdata'
  data 'Reading PTP_OC 0x9209 (PTP_OC_SONY_GetAllDevicePropData) data...'
LOG level 2: domain 'ptp_usb_getresp'
  data 'Reading PTP_OC 0x9209 (PTP_OC_SONY_GetAllDevicePropData) response...'
LOG level 2: domain 'camera_sony_capture'
  data 'DEBUG== 0xd213 after shutter press = 1'
LOG level 2: domain 'camera_sony_capture'
  data 'releasing shutterbutton'
LOG level 2: domain 'ptp_usb_sendreq'
  data 'Sending PTP_OC 0x9207 (PTP_OC_SONY_SetControlDeviceB) (0xd2c2) request...'
LOG level 2: domain 'ptp_usb_senddata'
  data 'Sending PTP_OC 0x9207 (PTP_OC_SONY_SetControlDeviceB) data...'
LOG level 2: domain 'ptp_usb_getresp'
  data 'Reading PTP_OC 0x9207 (PTP_OC_SONY_SetControlDeviceB) response...'
LOG level 2: domain 'ptp_usb_sendreq'
  data 'Sending PTP_OC 0x9207 (PTP_OC_SONY_SetControlDeviceB) (0xd2c1) request...'
LOG level 2: domain 'ptp_usb_senddata'
  data 'Sending PTP_OC 0x9207 (PTP_OC_SONY_SetControlDeviceB) data...'
LOG level 2: domain 'ptp_usb_getresp'
  data 'Reading PTP_OC 0x9207 (PTP_OC_SONY_SetControlDeviceB) response...'
LOG level 2: domain 'camera_sony_capture'
  data 'waiting for image availability'
LOG level 2: domain 'ptp_usb_sendreq'
  data 'Sending PTP_OC 0x9209 (PTP_OC_SONY_GetAllDevicePropData) request...'
LOG level 2: domain 'ptp_usb_getdata'
  data 'Reading PTP_OC 0x9209 (PTP_OC_SONY_GetAllDevicePropData) data...'
LOG level 2: domain 'ptp_usb_getresp'
  data 'Reading PTP_OC 0x9209 (PTP_OC_SONY_GetAllDevicePropData) response...'
LOG level 2: domain 'camera_sony_capture'
  data 'DEBUG== 0xd215 after capture = 1'
LOG level 2: domain 'ptp_usb_sendreq'
  data 'Sending PTP_OC 0x9209 (PTP_OC_SONY_GetAllDevicePropData) request...'
LOG level 2: domain 'ptp_usb_getdata'
  data 'Reading PTP_OC 0x9209 (PTP_OC_SONY_GetAllDevicePropData) data...'
LOG level 2: domain 'ptp_usb_getresp'
  data 'Reading PTP_OC 0x9209 (PTP_OC_SONY_GetAllDevicePropData) response...'
LOG level 2: domain 'camera_sony_capture'
  data 'DEBUG== 0xd215 after capture = 1'
LOG level 2: domain 'ptp_usb_sendreq'
  data 'Sending PTP_OC 0x9209 (PTP_OC_SONY_GetAllDevicePropData) request...'
LOG level 2: domain 'ptp_usb_getdata'
  data 'Reading PTP_OC 0x9209 (PTP_OC_SONY_GetAllDevicePropData) data...'
LOG level 2: domain 'ptp_usb_getresp'
  data 'Reading PTP_OC 0x9209 (PTP_OC_SONY_GetAllDevicePropData) response...'
LOG level 2: domain 'camera_sony_capture'
  data 'DEBUG== 0xd215 after capture = 1'
LOG level 2: domain 'ptp_usb_sendreq'
  data 'Sending PTP_OC 0x9209 (PTP_OC_SONY_GetAllDevicePropData) request...'
LOG level 2: domain 'ptp_usb_getdata'
  data 'Reading PTP_OC 0x9209 (PTP_OC_SONY_GetAllDevicePropData) data...'
LOG level 2: domain 'ptp_usb_getresp'
  data 'Reading PTP_OC 0x9209 (PTP_OC_SONY_GetAllDevicePropData) response...'
LOG level 2: domain 'camera_sony_capture'
  data 'DEBUG== 0xd215 after capture = 1'
LOG level 2: domain 'ptp_usb_sendreq'
  data 'Sending PTP_OC 0x9209 (PTP_OC_SONY_GetAllDevicePropData) request...'
LOG level 2: domain 'ptp_usb_getdata'
  data 'Reading PTP_OC 0x9209 (PTP_OC_SONY_GetAllDevicePropData) data...'
LOG level 2: domain 'ptp_usb_getresp'
  data 'Reading PTP_OC 0x9209 (PTP_OC_SONY_GetAllDevicePropData) response...'
LOG level 2: domain 'camera_sony_capture'
  data 'DEBUG== 0xd215 after capture = 1'
LOG level 2: domain 'ptp_usb_sendreq'
  data 'Sending PTP_OC 0x9209 (PTP_OC_SONY_GetAllDevicePropData) request...'
LOG level 2: domain 'ptp_usb_getdata'
  data 'Reading PTP_OC 0x9209 (PTP_OC_SONY_GetAllDevicePropData) data...'
LOG level 2: domain 'ptp_usb_getresp'
  data 'Reading PTP_OC 0x9209 (PTP_OC_SONY_GetAllDevicePropData) response...'
LOG level 2: domain 'camera_sony_capture'
  data 'DEBUG== 0xd215 after capture = 1'
LOG level 2: domain 'ptp_usb_sendreq'
  data 'Sending PTP_OC 0x9209 (PTP_OC_SONY_GetAllDevicePropData) request...'
LOG level 2: domain 'ptp_usb_getdata'
  data 'Reading PTP_OC 0x9209 (PTP_OC_SONY_GetAllDevicePropData) data...'
LOG level 2: domain '_cb_irq'
  data '0x1d2c9f8 with status 0'
LOG level 2: domain '_cb_irq'
  data 'Requeuing completed transfer 0x1d2c9f8'
LOG level 2: domain '_cb_irq'
  data '0x1d3df68 with status 0'
LOG level 2: domain '_cb_irq'
  data 'Requeuing completed transfer 0x1d3df68'
LOG level 2: domain 'ptp_usb_getresp'
  data 'Reading PTP_OC 0x9209 (PTP_OC_SONY_GetAllDevicePropData) response...'
LOG level 2: domain 'ptp'
  data 'ptp_sony_getalldevicepropdesc: d215: value 1 -> 32769'
LOG level 2: domain 'camera_sony_capture'
  data 'DEBUG== 0xd215 after capture = 32769'
LOG level 2: domain 'camera_sony_capture'
  data 'SONY ObjectInMemory count change seen, ending wait'
LOG level 2: domain 'camera_sony_capture'
  data 'ending image availability'
LOG level 0: domain 'camera_sony_capture [library.c:4150]'
  data 'no object found during event polling. try the 0xffffc001 object id'
LOG level 2: domain 'ptp_usb_sendreq'
  data 'Sending PTP_OC 0x1008 (Get object info) (0xffffc001) request...'
LOG level 2: domain 'ptp_usb_getdata'
  data 'Reading PTP_OC 0x1008 (Get object info) data...'
LOG level 2: domain 'ptp_usb_getresp'
  data 'Reading PTP_OC 0x1008 (Get object info) response...'
LOG level 2: domain '_cb_irq'
  data '0x1d2c278 with status 0'
LOG level 2: domain '_cb_irq'
  data 'Requeuing completed transfer 0x1d2c278'
LOG level 2: domain 'ptp_usb_sendreq'
  data 'Sending PTP_OC 0x1009 (Get object) (0xffffc001) request...'
LOG level 2: domain 'ptp_usb_getdata'
  data 'Reading PTP_OC 0x1009 (Get object) data...'
LOG level 2: domain 'ptp_usb_getresp'
  data 'Reading PTP_OC 0x1009 (Get object) response...'
LOG level 2: domain 'add_objectid_and_upload'
  data 'setting size'
LOG level 2: domain 'add_objectid_and_upload'
  data 'append to fs'
LOG level 2: domain 'gp_filesystem_append'
  data 'Append //capt0163.jpg to filesystem'
LOG level 2: domain 'lookup_folder'
  data 'Lookup folder '/'...'
LOG level 2: domain 'lookup_folder'
  data 'Found! / is 0x1d15010'
LOG level 2: domain 'internal_append'
  data 'Internal append capt0163.jpg to folder /'
LOG level 2: domain 'add_objectid_and_upload'
  data 'adding filedata to fs'
LOG level 2: domain 'gp_filesystem_set_file_noop'
  data 'Adding file 'capt0163.jpg' to folder '/' (type 1)...'
LOG level 2: domain 'lookup_folder_file'
  data 'Lookup folder / file capt0163.jpg'
LOG level 2: domain 'lookup_folder'
  data 'Lookup folder '/'...'
LOG level 2: domain 'lookup_folder'
  data 'Found! / is 0x1d15010'
LOG level 2: domain 'gp_filesystem_lru_update'
  data 'Adding file 'capt0163.jpg' from folder '/' to the fscache LRU list (type 1)...'
LOG level 2: domain 'lookup_folder_file'
  data 'Lookup folder / file capt0163.jpg'
LOG level 2: domain 'lookup_folder'
  data 'Lookup folder '/'...'
LOG level 2: domain 'lookup_folder'
  data 'Found! / is 0x1d15010'
LOG level 2: domain 'gp_filesystem_lru_update'
  data 'File 'capt0163.jpg' from folder '/' added in fscache LRU list.'
LOG level 2: domain 'gp_filesystem_lru_check'
  data 'Checking fscache LRU list integrity...'
LOG level 2: domain 'gp_filesystem_lru_check'
  data 'fscache LRU list ok with 1 items (287802193 bytes)'
LOG level 2: domain 'strcpy_mime'
  data 'Failed to find mime type for 0000'
LOG level 2: domain 'add_objectid_and_upload'
  data 'setting fileinfo in fs'
LOG level 2: domain 'lookup_folder_file'
  data 'Lookup folder / file capt0163.jpg'
LOG level 2: domain 'lookup_folder'
  data 'Lookup folder '/'...'
LOG level 2: domain 'lookup_folder'
  data 'Found! / is 0x1d15010'
LOG level 2: domain 'gp_camera_file_get'
  data 'Getting file 'capt0163.jpg' in folder '/'...'
LOG level 2: domain 'gp_filesystem_get_file_impl'
  data 'Getting file 'capt0163.jpg' from folder '/' (type 1)...'
LOG level 2: domain 'lookup_folder_file'
  data 'Lookup folder / file capt0163.jpg'
LOG level 2: domain 'lookup_folder'
  data 'Lookup folder '/'...'
LOG level 2: domain 'lookup_folder'
  data 'Found! / is 0x1d15010'
LOG level 2: domain 'gp_file_copy'
  data 'Copying '' onto 'capt0163.jpg'...'
LOG level 2: domain 'gp_filesystem_get_file_impl'
  data 'LRU cache used for type 1!'
LOG level 2: domain 'gp_camera_file_delete'
  data 'Deleting file 'capt0163.jpg' in folder '/'...'
LOG level 2: domain 'lookup_folder_file'
  data 'Lookup folder / file capt0163.jpg'
LOG level 2: domain 'lookup_folder'
  data 'Lookup folder '/'...'
LOG level 2: domain 'lookup_folder'
  data 'Found! / is 0x1d15010'
LOG level 2: domain 'gp_filesystem_delete_file'
  data 'Deleting 'capt0163.jpg' from folder '/'...'
LOG level 2: domain 'ptp_usb_sendreq'
  data 'Sending PTP_OC 0x9209 (PTP_OC_SONY_GetAllDevicePropData) request...'
LOG level 2: domain 'ptp_usb_getdata'
  data 'Reading PTP_OC 0x9209 (PTP_OC_SONY_GetAllDevicePropData) data...'
LOG level 2: domain '_cb_irq'
  data '0x1d178b8 with status 0'
LOG level 2: domain '_cb_irq'
  data 'Requeuing completed transfer 0x1d178b8'
LOG level 2: domain '_cb_irq'
  data '0x1d2cf88 with status 0'
LOG level 2: domain '_cb_irq'
  data 'Requeuing completed transfer 0x1d2cf88'
LOG level 2: domain '_cb_irq'
  data '0x1d17c28 with status 0'
LOG level 2: domain '_cb_irq'
  data 'Requeuing completed transfer 0x1d17c28'
LOG level 2: domain 'ptp_usb_getresp'
  data 'Reading PTP_OC 0x9209 (PTP_OC_SONY_GetAllDevicePropData) response...'
LOG level 2: domain 'ptp'
  data 'ptp_sony_getalldevicepropdesc: d215: value 32769 -> 0'
LOG level 2: domain 'camera_sony_capture'
  data 'dpd.CurrentValue.u8 = 3'
LOG level 2: domain 'camera_sony_capture'
  data 'dpd.FactoryDefaultValue.u8 = 2'
LOG level 2: domain 'ptp_usb_sendreq'
  data 'Sending PTP_OC 0x9207 (PTP_OC_SONY_SetControlDeviceB) (0xd2c1) request...'
LOG level 2: domain 'ptp_usb_senddata'
  data 'Sending PTP_OC 0x9207 (PTP_OC_SONY_SetControlDeviceB) data...'
LOG level 2: domain 'ptp_usb_getresp'
  data 'Reading PTP_OC 0x9207 (PTP_OC_SONY_SetControlDeviceB) response...'
LOG level 2: domain 'ptp_usb_sendreq'
  data 'Sending PTP_OC 0x9207 (PTP_OC_SONY_SetControlDeviceB) (0xd2c2) request...'
LOG level 2: domain 'ptp_usb_senddata'
  data 'Sending PTP_OC 0x9207 (PTP_OC_SONY_SetControlDeviceB) data...'
LOG level 2: domain 'ptp_usb_getresp'
  data 'Reading PTP_OC 0x9207 (PTP_OC_SONY_SetControlDeviceB) response...'
LOG level 2: domain 'camera_sony_capture'
  data 'holding down shutterbutton'
LOG level 2: domain 'gp_port_get_timeout'
  data 'Current port timeout is 20000 milliseconds.'
LOG level 2: domain 'gp_port_set_timeout'
  data 'Setting port timeout to 150 milliseconds.'
LOG level 2: domain 'gp_port_set_timeout'
  data 'Setting port timeout to 20000 milliseconds.'
LOG level 2: domain 'ptp'
  data 'event: nparams=0x1, code=0xC201, trans_id=0xFFFFFFFF, p1=0xFFFFC001, p2=0x0, p3=0x0'
LOG level 2: domain 'camera_sony_capture'
  data 'during event.code=c201 Param1=ffffc001'
LOG level 2: domain 'ptp_usb_sendreq'
  data 'Sending PTP_OC 0x9209 (PTP_OC_SONY_GetAllDevicePropData) request...'
LOG level 2: domain 'ptp_usb_getdata'
  data 'Reading PTP_OC 0x9209 (PTP_OC_SONY_GetAllDevicePropData) data...'
LOG level 2: domain 'ptp_usb_getresp'
  data 'Reading PTP_OC 0x9209 (PTP_OC_SONY_GetAllDevicePropData) response...'
LOG level 2: domain 'camera_sony_capture'
  data 'DEBUG== 0xd213 after shutter press = 1'
LOG level 2: domain 'gp_port_get_timeout'
  data 'Current port timeout is 20000 milliseconds.'
LOG level 2: domain 'gp_port_set_timeout'
  data 'Setting port timeout to 150 milliseconds.'
LOG level 2: domain 'gp_port_set_timeout'
  data 'Setting port timeout to 20000 milliseconds.'
LOG level 2: domain 'ptp'
  data 'event: nparams=0x1, code=0xC203, trans_id=0xFFFFFFFF, p1=0xD21D, p2=0x0, p3=0x0'
LOG level 2: domain 'camera_sony_capture'
  data 'during event.code=c203 Param1=0000d21d'
LOG level 2: domain 'ptp_usb_sendreq'
  data 'Sending PTP_OC 0x9209 (PTP_OC_SONY_GetAllDevicePropData) request...'
LOG level 2: domain 'ptp_usb_getdata'
  data 'Reading PTP_OC 0x9209 (PTP_OC_SONY_GetAllDevicePropData) data...'
LOG level 2: domain 'ptp_usb_getresp'
  data 'Reading PTP_OC 0x9209 (PTP_OC_SONY_GetAllDevicePropData) response...'
LOG level 2: domain 'camera_sony_capture'
  data 'DEBUG== 0xd213 after shutter press = 1'
LOG level 2: domain 'gp_port_get_timeout'
  data 'Current port timeout is 20000 milliseconds.'
LOG level 2: domain 'gp_port_set_timeout'
  data 'Setting port timeout to 150 milliseconds.'
LOG level 2: domain 'gp_port_set_timeout'
  data 'Setting port timeout to 20000 milliseconds.'
LOG level 2: domain 'ptp'
  data 'event: nparams=0x1, code=0xC203, trans_id=0xFFFFFFFF, p1=0x5005, p2=0x0, p3=0x0'
LOG level 2: domain 'camera_sony_capture'
  data 'during event.code=c203 Param1=00005005'
LOG level 2: domain 'ptp_usb_sendreq'
  data 'Sending PTP_OC 0x9209 (PTP_OC_SONY_GetAllDevicePropData) request...'
LOG level 2: domain 'ptp_usb_getdata'
  data 'Reading PTP_OC 0x9209 (PTP_OC_SONY_GetAllDevicePropData) data...'
LOG level 2: domain 'ptp_usb_getresp'
  data 'Reading PTP_OC 0x9209 (PTP_OC_SONY_GetAllDevicePropData) response...'
LOG level 2: domain 'camera_sony_capture'
  data 'DEBUG== 0xd213 after shutter press = 1'
LOG level 2: domain 'gp_port_get_timeout'
  data 'Current port timeout is 20000 milliseconds.'
LOG level 2: domain 'gp_port_set_timeout'
  data 'Setting port timeout to 150 milliseconds.'
LOG level 2: domain 'gp_port_set_timeout'
  data 'Setting port timeout to 20000 milliseconds.'
LOG level 2: domain 'ptp'
  data 'event: nparams=0x1, code=0xC202, trans_id=0xFFFFFFFF, p1=0xFFFFC001, p2=0x0, p3=0x0'
LOG level 2: domain 'camera_sony_capture'
  data 'during event.code=c202 Param1=ffffc001'
LOG level 2: domain 'ptp_usb_sendreq'
  data 'Sending PTP_OC 0x9209 (PTP_OC_SONY_GetAllDevicePropData) request...'
LOG level 2: domain 'ptp_usb_getdata'
  data 'Reading PTP_OC 0x9209 (PTP_OC_SONY_GetAllDevicePropData) data...'
LOG level 2: domain 'ptp_usb_getresp'
  data 'Reading PTP_OC 0x9209 (PTP_OC_SONY_GetAllDevicePropData) response...'
LOG level 2: domain 'camera_sony_capture'
  data 'DEBUG== 0xd213 after shutter press = 1'
LOG level 2: domain 'gp_port_get_timeout'
  data 'Current port timeout is 20000 milliseconds.'
LOG level 2: domain 'gp_port_set_timeout'
  data 'Setting port timeout to 150 milliseconds.'
LOG level 2: domain 'gp_port_set_timeout'
  data 'Setting port timeout to 20000 milliseconds.'
LOG level 2: domain 'ptp'
  data 'event: nparams=0x1, code=0xC203, trans_id=0xFFFFFFFF, p1=0x5005, p2=0x0, p3=0x0'
LOG level 2: domain 'camera_sony_capture'
  data 'during event.code=c203 Param1=00005005'
LOG level 2: domain 'ptp_usb_sendreq'
  data 'Sending PTP_OC 0x9209 (PTP_OC_SONY_GetAllDevicePropData) request...'
LOG level 2: domain 'ptp_usb_getdata'
  data 'Reading PTP_OC 0x9209 (PTP_OC_SONY_GetAllDevicePropData) data...'
LOG level 2: domain 'ptp_usb_getresp'
  data 'Reading PTP_OC 0x9209 (PTP_OC_SONY_GetAllDevicePropData) response...'
LOG level 2: domain 'camera_sony_capture'
  data 'DEBUG== 0xd213 after shutter press = 1'
LOG level 2: domain 'gp_port_get_timeout'
  data 'Current port timeout is 20000 milliseconds.'
LOG level 2: domain 'gp_port_set_timeout'
  data 'Setting port timeout to 150 milliseconds.'
LOG level 2: domain 'gp_port_set_timeout'
  data 'Setting port timeout to 20000 milliseconds.'
LOG level 2: domain 'ptp'
  data 'event: nparams=0x1, code=0xC203, trans_id=0xFFFFFFFF, p1=0xD213, p2=0x0, p3=0x0'
LOG level 2: domain 'camera_sony_capture'
  data 'during event.code=c203 Param1=0000d213'
LOG level 2: domain 'camera_sony_capture'
  data 'SONY FocusFound change received, 0xd213... ending press'
LOG level 2: domain 'camera_sony_capture'
  data 'releasing shutterbutton'
LOG level 2: domain 'ptp_usb_sendreq'
  data 'Sending PTP_OC 0x9207 (PTP_OC_SONY_SetControlDeviceB) (0xd2c2) request...'
LOG level 2: domain 'ptp_usb_senddata'
  data 'Sending PTP_OC 0x9207 (PTP_OC_SONY_SetControlDeviceB) data...'
LOG level 2: domain 'ptp_usb_getresp'
  data 'Reading PTP_OC 0x9207 (PTP_OC_SONY_SetControlDeviceB) response...'
LOG level 2: domain 'ptp_usb_sendreq'
  data 'Sending PTP_OC 0x9207 (PTP_OC_SONY_SetControlDeviceB) (0xd2c1) request...'
LOG level 2: domain 'ptp_usb_senddata'
  data 'Sending PTP_OC 0x9207 (PTP_OC_SONY_SetControlDeviceB) data...'
LOG level 2: domain 'ptp_usb_getresp'
  data 'Reading PTP_OC 0x9207 (PTP_OC_SONY_SetControlDeviceB) response...'
LOG level 2: domain 'camera_sony_capture'
  data 'waiting for image availability'
LOG level 2: domain 'ptp_usb_sendreq'
  data 'Sending PTP_OC 0x9209 (PTP_OC_SONY_GetAllDevicePropData) request...'
LOG level 2: domain 'ptp_usb_getdata'
  data 'Reading PTP_OC 0x9209 (PTP_OC_SONY_GetAllDevicePropData) data...'
LOG level 2: domain 'ptp_usb_getresp'
  data 'Reading PTP_OC 0x9209 (PTP_OC_SONY_GetAllDevicePropData) response...'
LOG level 2: domain 'ptp_usb_sendreq'
  data 'Sending PTP_OC 0x9209 (PTP_OC_SONY_GetAllDevicePropData) request...'
LOG level 2: domain 'ptp_usb_getdata'
  data 'Reading PTP_OC 0x9209 (PTP_OC_SONY_GetAllDevicePropData) data...'
LOG level 2: domain 'ptp_usb_getresp'
  data 'Reading PTP_OC 0x9209 (PTP_OC_SONY_GetAllDevicePropData) response...'
LOG level 2: domain 'camera_sony_capture'
  data 'DEBUG== 0xd215 after capture = 0'

...
many repetitive sequences omitted here... 
...

LOG level 2: domain 'ptp_usb_sendreq'
  data 'Sending PTP_OC 0x9209 (PTP_OC_SONY_GetAllDevicePropData) request...'
LOG level 2: domain 'ptp_usb_getdata'
  data 'Reading PTP_OC 0x9209 (PTP_OC_SONY_GetAllDevicePropData) data...'
LOG level 2: domain 'ptp_usb_getresp'
  data 'Reading PTP_OC 0x9209 (PTP_OC_SONY_GetAllDevicePropData) response...'
LOG level 2: domain 'camera_sony_capture'
  data 'DEBUG== 0xd215 after capture = 0'
LOG level 2: domain 'ptp_usb_sendreq'
  data 'Sending PTP_OC 0x9209 (PTP_OC_SONY_GetAllDevicePropData) request...'
LOG level 2: domain 'ptp_usb_getdata'
  data 'Reading PTP_OC 0x9209 (PTP_OC_SONY_GetAllDevicePropData) data...'
LOG level 2: domain 'ptp_usb_getresp'
  data 'Reading PTP_OC 0x9209 (PTP_OC_SONY_GetAllDevicePropData) response...'
LOG level 2: domain 'camera_sony_capture'
  data 'DEBUG== 0xd215 after capture = 0'
LOG level 2: domain 'ptp_usb_sendreq'
  data 'Sending PTP_OC 0x9209 (PTP_OC_SONY_GetAllDevicePropData) request...'
LOG level 2: domain 'ptp_usb_getdata'
  data 'Reading PTP_OC 0x9209 (PTP_OC_SONY_GetAllDevicePropData) data...'
LOG level 2: domain 'ptp_usb_getresp'
  data 'Reading PTP_OC 0x9209 (PTP_OC_SONY_GetAllDevicePropData) response...'
LOG level 2: domain 'camera_sony_capture'
  data 'DEBUG== 0xd215 after capture = 0'
LOG level 2: domain 'ptp_usb_sendreq'
  data 'Sending PTP_OC 0x9209 (PTP_OC_SONY_GetAllDevicePropData) request...'
LOG level 2: domain 'ptp_usb_getdata'
  data 'Reading PTP_OC 0x9209 (PTP_OC_SONY_GetAllDevicePropData) data...'
LOG level 2: domain 'ptp_usb_getresp'
  data 'Reading PTP_OC 0x9209 (PTP_OC_SONY_GetAllDevicePropData) response...'
LOG level 2: domain 'camera_sony_capture'
  data 'DEBUG== 0xd215 after capture = 0'
LOG level 2: domain 'camera_sony_capture'
  data 'ending image availability'
LOG level 0: domain 'camera_sony_capture [library.c:4150]'
  data 'no object found during event polling. try the 0xffffc001 object id'
LOG level 2: domain 'ptp_usb_sendreq'
  data 'Sending PTP_OC 0x1008 (Get object info) (0xffffc001) request...'
LOG level 2: domain 'ptp_usb_getdata'
  data 'Reading PTP_OC 0x1008 (Get object info) data...'
LOG level 2: domain '_cb_irq'
  data '0x1d2f478 with status 5'
LOG level 2: domain '_cb_irq'
  data 'Transfer 0x1d2f478 should be in LIBUSB_TRANSFER_COMPLETED, but is 5!'
LOG level 2: domain '_cb_irq'
  data '0x1d1b078 with status 5'
LOG level 2: domain '_cb_irq'
  data 'Transfer 0x1d1b078 should be in LIBUSB_TRANSFER_COMPLETED, but is 5!'
LOG level 2: domain '_cb_irq'
  data '0x1d3ead8 with status 5'
LOG level 2: domain '_cb_irq'
  data 'Transfer 0x1d3ead8 should be in LIBUSB_TRANSFER_COMPLETED, but is 5!'
LOG level 2: domain '_cb_irq'
  data '0x1d17c28 with status 5'
LOG level 2: domain '_cb_irq'
  data 'Transfer 0x1d17c28 should be in LIBUSB_TRANSFER_COMPLETED, but is 5!'
LOG level 2: domain '_cb_irq'
  data '0x1d2cf88 with status 5'
LOG level 2: domain '_cb_irq'
  data 'Transfer 0x1d2cf88 should be in LIBUSB_TRANSFER_COMPLETED, but is 5!'
LOG level 2: domain '_cb_irq'
  data '0x1d178b8 with status 5'
LOG level 2: domain '_cb_irq'
  data 'Transfer 0x1d178b8 should be in LIBUSB_TRANSFER_COMPLETED, but is 5!'
LOG level 2: domain '_cb_irq'
  data '0x1d2c278 with status 5'
LOG level 2: domain '_cb_irq'
  data 'Transfer 0x1d2c278 should be in LIBUSB_TRANSFER_COMPLETED, but is 5!'
LOG level 2: domain '_cb_irq'
  data '0x1d3df68 with status 5'
LOG level 2: domain '_cb_irq'
  data 'Transfer 0x1d3df68 should be in LIBUSB_TRANSFER_COMPLETED, but is 5!'
LOG level 2: domain '_cb_irq'
  data '0x1d2c9f8 with status 5'
LOG level 2: domain '_cb_irq'
  data 'Transfer 0x1d2c9f8 should be in LIBUSB_TRANSFER_COMPLETED, but is 5!'
LOG level 2: domain '_cb_irq'
  data '0x1d2c7a8 with status 5'
LOG level 2: domain '_cb_irq'
  data 'Transfer 0x1d2c7a8 should be in LIBUSB_TRANSFER_COMPLETED, but is 5!'
LOG level 0: domain 'gp_libusb1_read [libusb1.c:603]'
  data ''libusb_bulk_transfer (port->pl->dh, port->settings.usb.inep, (unsigned char*)bytes, size, &curread, port->timeout)' failed: Input/Output error (-1)'
LOG level 0: domain 'gp_port_read [gphoto2-port.c:441]'
  data 'Reading 1024 = 0x400 bytes from port failed: Error reading from the port (-34)'
LOG level 2: domain 'ptp_usb_getpacket'
  data 'Clearing halt on IN EP and retrying once.'
LOG level 2: domain 'gp_port_usb_clear_halt'
  data 'Clear USB halt...'
LOG level 0: domain 'gp_libusb1_clear_halt_lib [libusb1.c:575]'
  data ''libusb_clear_halt(port->pl->dh, internal_ep)' failed: No such device (it may have been disconnected) (-4)'
LOG level 0: domain 'gp_libusb1_read [libusb1.c:603]'
  data ''libusb_bulk_transfer (port->pl->dh, port->settings.usb.inep, (unsigned char*)bytes, size, &curread, port->timeout)' failed: No such device (it may have been disconnected) (-4)'
LOG level 0: domain 'gp_port_read [gphoto2-port.c:441]'
  data 'Reading 1024 = 0x400 bytes from port failed: Could not find the requested device on the USB port (-52)'
LOG level 0: domain 'ptp_usb_getdata [usb.c:447]'
  data 'PTP_OC 0x1008 receiving data failed: PTP No Device (0x02f9)'
LOG level 0: domain 'camera_sony_capture [library.c:4154]'
  data ''ptp_getobjectinfo (params, newobject, &oi)' failed: PTP I/O Error (0x02ff)'
LOG level 0: domain 'gp_camera_capture [gphoto2-camera.c:1340]'
  data ''camera->functions->capture (camera, type, path, context)' failed: -7'
notnot commented 5 years ago

After upgrading to libgphoto2 2.5.22, error -7 still arises :(

notnot commented 5 years ago

Some more updates:

I did a longer test: 25000 captures with the sleep of 1 second between gp_camera_capture() and gp_camera_file_get() and a sleep of 1 second before the next capture. This test succeeded, so it seems a reliable workaround (although one can never be sure, the error -7 appears to arrive at random).

I tried to re-initialize the context and camera after getting error -7. This fails with error -105 (camera model not found). When i exit my test program and run it again, the context and camera can be initialized without a problem. I don't have to switch the camera off and back on. It would be nice if there would be a way to 'reset' libgphoto2 state without exiting the application. For now, i solved this by splitting my application in two processes, a supervisor and a worker. The worker controls the camera, and if something goes wrong, it exits, and the supervisor will launch it again.

msmeissn commented 5 years ago

that -105 error might mean that the camera crashed and reconnected, so it needs a quick redetect. (freeing the camera and starting with fresh detection + init new?) this might have happened at this line:time data 'Sending PTP_OC 0x1008 (Get object info) (0xffffc001) request...'

i made some additional checks in current git (not yet released) for this problem.

notnot commented 5 years ago

Thanks for looking into this Marcus. I will try the release when its available and test it for you. For the time being, my supervisor/worker process approach works well. The camera has taken about a million photos now, restarting the capture process goes so quickly that you hardly even notice it. Of course it would be great to fix this error -7 at the root. Do you have any idea why gphoto2 doesn't exhibit it?

ahaugedk commented 5 years ago

Just FYI. I am seeing the same behavior with my a6000 (and my a6300). I implemented the supervisor/worker process approach and it works.

But +1 for finding the root cause :)

ahaugedk commented 5 years ago

By the way I am running on a raspberry pi: gphoto2 2.5.20.1
libgphoto2 2.5.22.1 libgphoto2_port 0.12.0

Installed using https://github.com/gonzalo/gphoto2-updater

msmeissn commented 5 years ago

for resetting the camera state, I would just free the Camera (gp_camera_unref(cameraptr); and allocate a new one). This should clear dangling state (likely a port pointing to the old USB entry) effectively.

notnot commented 5 years ago

How is that better than freeing the camera (using gp_camera_exit()) and context (using gp_context_unref() and then setting everything back up? Which is what i have been trying, but won't work, at least not after getting the -7 error.

msmeissn commented 5 years ago

the context does not need to be freed necessarily on reconnect.

gp_camera_exit() does not remove the port there, if you would reopen the camera it might take the old port which is now pointing to a non existant device.

But if it really is just spurious, it is probably some other problem :/

notnot commented 4 years ago

It is sad to have to revive an old issue but now that time has come... The error -7 has become a real show-stopper when i use libgphoto2 2.5.25. Usually my software can only capture a single image, after that it fails with error -7. One time i have seen it capture 3 images, after which it it failed with the dreaded error -7. It doesn't matter how much time has elapsed between captures.

The interesting fact is that 'gphoto2 --capture-image-and-download --frames=10 --interval=5' always works, also with libgphoto2 2.5.25. This begs the question: is gphoto2 doing something that my application isn't doing? I am under some time pressure now, so i can't dive into the gphoto2 source. Instead, i downgraded to libgphoto 2.5.20, and my machine vision system is usable again.

When i have some more time i would love to write a minimal C program that demonstrates the problem. I am using Sony alpha 5100 and 6300 cameras. The issue might be related to those. Marcus, do you have access to one of there cameras to test?

msmeissn commented 4 years ago

the "gphoto2 --capture-image-and-download --frames=10 --interval=5" is continously polling the camera for events and draining the event queue, using gp_camera_wait_for_event ... this might have an effect in this case

notnot commented 4 years ago

Good to know. I will try and implement that, plus your suggested way of resetting the camera state, once i can find some time. It doesn't feel good to be stuck on a certain version of libgphoto.

starlord1980 commented 4 years ago

Is this the same as the issue I'm having on my Sony a6300. I'm able to take around 3-7 pictures via Octolapse script and then I get a timeout. I've just posted my debug log and setup information on this link: https://github.com/gphoto/gphoto2/issues/30

notnot commented 3 years ago

I have finally had some time to work on this further. I have implemented event queue draining (using gp_camera_wait_for_event()) as Marcus suggested, and i can report that this improves the reliability of continuous capturing in a loop. Without adding any pauses after capture, nor after downloading, i have run several successful tests of capturing 10K images in a sequence, as fast as possible. Sadly I have seen an unsuccessful test run too, where the 7924th capture failed. I will add some pauses and repeat the testing, in the hope that a capture failure becomes even more rare.

Still using
gphoto2 2.5.20 gcc, popt(m), exif, no cdk, no aa, jpeg, no readline libgphoto2 2.5.20 all camlibs, gcc, ltdl, EXIF libgphoto2_port 0.12.0 iolibs: disk ptpip serial usb1 usbdiskdirect usbscsi, gcc, ltdl, USB, serial without locking

I am currently running the tests on a desktop machine. I will soon run these tests on a nVidia Jetson Nano (a small controller computer).