Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

segmentation fault/corrupted double-linked list on powering down camera #15

Closed
alik55 opened this issue Oct 16, 2015 · 10 comments
Closed
Assignees
Labels

Comments

@alik55
Copy link

alik55 commented Oct 16, 2015

When camera is manually powered down shortly (1-2sec) after it gets connected and while still processing queued events (cam.processEvents) the program intermittently crashes with segfault or "corrupted double-linked list".

Main:
while (1)
{
if ( !cam.isConnected() )
{
if ( !cam.connect() )
sleep(2);
}
if ( cam.isConnected() )
cam.processEvents(500);
}

cam.processEvents:
{
if ( !bConnected )
return;
CameraEventType evttype;
CameraFilePath _path;
void *evtdata = 0;
if (GP_OK != gp_camera_wait_for_event (_camera,timeout_ms, &evttype, &evtdata, context))
{
disconnect();
return;
}
switch (evttype)
{
case GP_EVENT_FILE_ADDED: // did not ask for file, discard it
path = (CameraFilePath
)evtdata;
gp_camera_file_delete(_camera, path->folder, path->name, _context);
break;
default:
break;
}
if ( evtdata )
free (evtdata);
}

cam.disconnect:
{
if ( _context && _camera )
gp_camera_exit(_camera, _context) ;
if ( _camera )
gp_camera_unref(_camera);
if ( _context )
gp_context_unref(_context);
_context = NULL;
_camera = NULL;
}

Debug log:
waiting for events timeout 500 ms
Sending PTP_OC 0x911d / PTP_OC_CANON_EOS_KeepDeviceOn request...
Reading PTP_OC 0x911d response...
Sending PTP_OC 0x9116 / PTP_OC_CANON_EOS_GetEvent request...
Reading PTP_OC 0x9116 / PTP_OC_CANON_EOS_GetEvent data...
Reading PTP_OC 0x9116 response...
entry type 0003
waiting for events timeout 500 ms
Sending PTP_OC 0x911d / PTP_OC_CANON_EOS_KeepDeviceOn request...
Reading PTP_OC 0x911d response...
'libusb_bulk_transfer (port->pl->dh, port->settings.usb.inep, (unsigned char_)bytes, size, &curread, port->timeout)' failed: Input/Output Error (-1)
Reading 1024 = 0x400 bytes from port failed: Error reading from the port (-34)
Clearing halt on IN EP and retrying once.
Clear USB halt...
'libusb_clear_halt(port->pl->dh, internal_ep)' failed: Other error (-99)
'libusb_bulk_transfer (port->pl->dh, port->settings.usb.inep, (unsigned char_)bytes, size, &curread, port->timeout)' failed: Input/Output Error (-1)
Reading 1024 = 0x400 bytes from port failed: Error reading from the port (-34)
Clearing halt on IN EP and retrying once.
Clear USB halt...
'libusb_clear_halt(port->pl->dh, internal_ep)' failed: Other error (-99)
PTP_OC 0x911d receiving resp failed: PTP I/O Error (0x02ff)
'ptp_canon_eos_keepdeviceon (params)' failed: PTP I/O Error (0x02ff)
'camera->functions->wait_for_event ( camera, timeout, eventtype, eventdata, context)' failed: -7
Exiting camera ('Canon EOS 1200D')...
Sending PTP_OC 0x9116 / PTP_OC_CANON_EOS_GetEvent request...
'libusb_bulk_transfer (port->pl->dh, port->settings.usb.outep, (unsigned char_)bytes, size, &curwritten, port->timeout)' failed: Input/Output Error (-1)
Writing 12 = 0xc bytes to port failed: Error writing to the port (-35)
PTP_OC 0x9116 sending req failed: Error writing to the port (-35)
Clearing halt on OUT EP and retrying once.
Clear USB halt...
'libusb_clear_halt(port->pl->dh, internal_ep)' failed: Other error (-99)
'libusb_bulk_transfer (port->pl->dh, port->settings.usb.outep, (unsigned char_)bytes, size, &curwritten, port->timeout)' failed: Input/Output Error (-1)
Writing 12 = 0xc bytes to port failed: Error writing to the port (-35)
PTP_OC 0x9116 sending req failed: Error writing to the port (-35)
missed EOS ptp type 3
missed EOS ptp type 3
missed EOS ptp type 3
missed EOS ptp type 3
Unprepare_capture
Sending PTP_OC 0x9160 / PTP_OC_CANON_EOS_AfCancel request...
'libusb_bulk_transfer (port->pl->dh, port->settings.usb.outep, (unsigned char_)bytes, size, &curwritten, port->timeout)' failed: Input/Output Error (-1)
Writing 12 = 0xc bytes to port failed: Error writing to the port (-35)
PTP_OC 0x9160 sending req failed: Error writing to the port (-35)
Clearing halt on OUT EP and retrying once.
Clear USB halt...
'libusb_clear_halt(port->pl->dh, internal_ep)' failed: Other error (-99)
'libusb_bulk_transfer (port->pl->dh, port->settings.usb.outep, (unsigned char_)bytes, size, &curwritten, port->timeout)' failed: Input/Output Error (-1)
Writing 12 = 0xc bytes to port failed: Error writing to the port (-35)
PTP_OC 0x9160 sending req failed: Error writing to the port (-35)
Card value is 2
Sending PTP_OC 0x9110 / PTP_OC_CANON_EOS_SetDevicePropValueEx request...
'libusb_bulk_transfer (port->pl->dh, port->settings.usb.outep, (unsigned char_)bytes, size, &curwritten, port->timeout)' failed: Input/Output Error (-1)
Writing 12 = 0xc bytes to port failed: Error writing to the port (-35)
PTP_OC 0x9110 sending req failed: Error writing to the port (-35)
Clearing halt on OUT EP and retrying once.
Clear USB halt...
'libusb_clear_halt(port->pl->dh, internal_ep)' failed: Other error (-99)
'libusb_bulk_transfer (port->pl->dh, port->settings.usb.outep, (unsigned char_)bytes, size, &curwritten, port->timeout)' failed: Input/Output Error (-1)
Writing 12 = 0xc bytes to port failed: Error writing to the port (-35)
PTP_OC 0x9110 sending req failed: Error writing to the port (-35)
'ptp_canon_eos_setdevicepropvalue (params, PTP_DPC_CANON_EOS_CaptureDestination, &ct_val, PTP_DTC_UINT32)' failed: setdevicepropvalue of capturetarget to 0x2 failed (0x02ff: PTP I/O Error)
'camera_canon_eos_update_capture_target(camera, context, 1)' failed: 'I/O problem' (-7)
Sending PTP_OC 0x1003 / Close session request...
'libusb_bulk_transfer (port->pl->dh, port->settings.usb.outep, (unsigned char_)bytes, size, &curwritten, port->timeout)' failed: Input/Output Error (-1)
Writing 12 = 0xc bytes to port failed: Error writing to the port (-35)
PTP_OC 0x1003 sending req failed: Error writing to the port (-35)
Clearing halt on OUT EP and retrying once.
Clear USB halt...
'libusb_clear_halt(port->pl->dh, internal_ep)' failed: Other error (-99)
'libusb_bulk_transfer (port->pl->dh, port->settings.usb.outep, (unsigned char_)bytes, size, &curwritten, port->timeout)' failed: Input/Output Error (-1)
Writing 12 = 0xc bytes to port failed: Error writing to the port (-35)
PTP_OC 0x1003 sending req failed: Error writing to the port (-35)
Closing port...
canceling transfer 0:0x7a20f0 (status 0)
canceling transfer 1:0x7a56f0 (status 0)
canceling transfer 2:0x7a58a8 (status 0)
canceling transfer 3:0x7a5a60 (status 0)
canceling transfer 4:0x7a5c18 (status 0)
canceling transfer 5:0x7a5dd0 (status 0)
canceling transfer 6:0x7a5f88 (status 0)
canceling transfer 7:0x7a6140 (status 0)
canceling transfer 8:0x7a62f8 (status 0)
'libusb_cancel_transfer(port->pl->transfers[i])' failed: No such device (it may have been disconnected) (-4)
canceling transfer 9:0x7a64b0 (status 0)
'libusb_cancel_transfer(port->pl->transfers[i])' failed: No such device (it may have been disconnected) (-4)
checking: transfer 0:0x7a20f0 status 0
checking: transfer 1:0x7a56f0 status 0
checking: transfer 2:0x7a58a8 status 0
checking: transfer 3:0x7a5a60 status 0
checking: transfer 4:0x7a5c18 status 0
checking: transfer 5:0x7a5dd0 status 0
checking: transfer 6:0x7a5f88 status 0
checking: transfer 7:0x7a6140 status 0
0x7a20f0 with status 5
0x7a56f0 with status 5
0x7a58a8 with status 5
0x7a5a60 with status 5
0x7a5c18 with status 5
0x7a5dd0 with status 5
0x7a5f88 with status 5
0x7a6140 with status 5
Segmentation fault (core dumped)

Backtrace:
#0 op_clear_transfer_priv (itransfer=0x7a62c0) at /usr/src/debug/libusb1/1.0.19-r0/libusb-1.0.19/libusb/os/linux_usbfs.c:2193

    transfer = 0x7a62f8
    __FUNCTION__ = "op_clear_transfer_priv"

#1 0x76a1aa38 in usbi_handle_disconnect (handle=handle@entry=0x7a3cd8) at /usr/src/debug/libusb1/1.0.19-r0/libusb-1.0.19/libusb/io.c:2614

    cur = 0x7a62c0
    to_cancel = 0x7a62c0
    __FUNCTION__ = "usbi_handle_disconnect"

#2 0x76a1de32 in op_handle_events (ctx=0x7a1ed0, fds=, nfds=4, num_ready=0)

at /usr/src/debug/libusb1/1.0.19-r0/libusb-1.0.19/libusb/os/linux_usbfs.c:2601
    pollfd = 0x7a9468
    handle = 0x7a3cd8
    hpriv = <optimized out>
    r = <optimized out>
    i = 3
    __FUNCTION__ = "op_handle_events"

#3 0x76a19c6c in handle_events (ctx=ctx@entry=0x7a1ed0, tv=tv@entry=0x7ebd4a70) at /usr/src/debug/libusb1/1.0.19-r0/libusb-1.0.19/libusb/io.c:2089

    r = <optimized out>
    ipollfd = <optimized out>
    nfds = 4
    fds = 0x7a9450
    i = <optimized out>
    timeout_ms = <optimized out>
    special_event = 1
    __FUNCTION__ = "handle_events"

#4 0x76a1a4a0 in libusb_handle_events_timeout_completed (ctx=0x7a1ed0, tv=tv@entry=0x7ebd4a98, completed=completed@entry=0x0)

at /usr/src/debug/libusb1/1.0.19-r0/libusb-1.0.19/libusb/io.c:2174
    r = 0
    poll_timeout = {tv_sec = 60, tv_usec = 0}
    __FUNCTION__ = "libusb_handle_events_timeout_completed"

#5 0x76a1a544 in libusb_handle_events (ctx=) at /usr/src/debug/libusb1/1.0.19-r0/libusb-1.0.19/libusb/io.c:2250

    tv = {tv_sec = 60, tv_usec = 0}

#6 0x76a28440 in gp_libusb1_close (port=0x7a3800) at /usr/src/debug/libgphoto2/2.5.8-r0/libgphoto2-2.5.8/libgphoto2_port/libusb1/libusb1.c:469

    i = 10
    haveone = <optimized out>
    tv = {tv_sec = 0, tv_usec = 1000}
    __func__ = "gp_libusb1_close"

#7 0x76fd6f34 in gp_port_close (port=0x7a3800) at /usr/src/debug/libgphoto2/2.5.8-r0/libgphoto2-2.5.8/libgphoto2_port/libgphoto2_port/gphoto2-port.c:301

    r = <optimized out>

#8 0x76e5e742 in gp_camera_exit (camera=0x7a0078, context=0x7a0030) at /usr/src/debug/libgphoto2/2.5.8-r0/libgphoto2-2.5.8/libgphoto2/gphoto2-camera.c:292

No locals.
#9 0x0000ff2c in Gphotocam::disconnect (this=0x14d74 ) at ../src/gphotocam.cpp:129

    bRet = true

#10 0x0001050e in Gphotocam::processEvents (this=0x14d74 , timeout_ms=500) at ../src/gphotocam.cpp:292

    evttype = GP_EVENT_TIMEOUT
    path = 0x14d74 <cam>
    evtdata = 0x0

#11 0x0000ab5a in main (argc=0, argv=0x7ebd4d98) at ../src/daemon.cpp:277

    daemon = false
    sa = {__sigaction_handler = {sa_handler = 0xa8e1 <sighup(int)>, sa_sigaction = 0xa8e1 <sighup(int)>}, sa_mask = {__val = {1, 0 <repeats 31 times>}}, 
      sa_flags = 0, sa_restorer = 0x2}
    shutterspeed = "\354)\001\000\240)\001\000\000\000\000\000\370\242\000"
    iso = "\310A\001\000\002\000\000\000\313\253\000\000\377\377\000"
    dial = "Manual\000\000\000\000\000\000\000\000\000"
    wb = "\001\000\000\000\030L\275~\337\253\000\000\001\000\000"
    batt = "tM\001\000\bL\275~\200P\271v\002\000\000"

Debug log when crash does not happen:
waiting for events timeout 500 ms
Sending PTP_OC 0x911d / PTP_OC_CANON_EOS_KeepDeviceOn request...
Reading PTP_OC 0x911d response...
Sending PTP_OC 0x9116 / PTP_OC_CANON_EOS_GetEvent request...
Reading PTP_OC 0x9116 / PTP_OC_CANON_EOS_GetEvent data...
Reading PTP_OC 0x9116 response...
'libusb_bulk_transfer (port->pl->dh, port->settings.usb.inep, (unsigned char_)bytes, size, &curread, port->timeout)' failed: Input/Output Error (-1)
Reading 1024 = 0x400 bytes from port failed: Error reading from the port (-34)
Clearing halt on IN EP and retrying once.
Clear USB halt...
'libusb_clear_halt(port->pl->dh, internal_ep)' failed: Other error (-99)
'libusb_bulk_transfer (port->pl->dh, port->settings.usb.inep, (unsigned char_)bytes, size, &curread, port->timeout)' failed: Input/Output Error (-1)
Reading 1024 = 0x400 bytes from port failed: Error reading from the port (-34)
Clearing halt on IN EP and retrying once.
Clear USB halt...
'libusb_clear_halt(port->pl->dh, internal_ep)' failed: Other error (-99)
PTP_OC 0x9116 receiving resp failed: PTP I/O Error (0x02ff)
'ptp_check_eos_events (params)' failed: Canon EOS Get Changes failed (0x02ff: PTP I/O Error)
Canon EOS Get Changes failed (0x02ff: PTP I/O Error)
'camera->functions->wait_for_event ( camera, timeout, eventtype, eventdata, context)' failed: -7
Exiting camera ('Canon EOS 1200D')...
Sending PTP_OC 0x9116 / PTP_OC_CANON_EOS_GetEvent request...
'libusb_bulk_transfer (port->pl->dh, port->settings.usb.outep, (unsigned char_)bytes, size, &curwritten, port->timeout)' failed: Input/Output Error (-1)
Writing 12 = 0xc bytes to port failed: Error writing to the port (-35)
PTP_OC 0x9116 sending req failed: Error writing to the port (-35)
Clearing halt on OUT EP and retrying once.
Clear USB halt...
'libusb_clear_halt(port->pl->dh, internal_ep)' failed: Other error (-99)
'libusb_bulk_transfer (port->pl->dh, port->settings.usb.outep, (unsigned char_)bytes, size, &curwritten, port->timeout)' failed: Input/Output Error (-1)
Writing 12 = 0xc bytes to port failed: Error writing to the port (-35)
PTP_OC 0x9116 sending req failed: Error writing to the port (-35)
missed EOS ptp type 3
...
missed EOS ptp type 3
missed EOS ptp type 0
...
missed EOS ptp type 0
missed EOS ptp type 3
...
missed EOS ptp type 3
Unprepare_capture
Sending PTP_OC 0x9160 / PTP_OC_CANON_EOS_AfCancel request...
'libusb_bulk_transfer (port->pl->dh, port->settings.usb.outep, (unsigned char_)bytes, size, &curwritten, port->timeout)' failed: Input/Output Error (-1)
Writing 12 = 0xc bytes to port failed: Error writing to the port (-35)
PTP_OC 0x9160 sending req failed: Error writing to the port (-35)
Clearing halt on OUT EP and retrying once.
Clear USB halt...
'libusb_clear_halt(port->pl->dh, internal_ep)' failed: Other error (-99)
'libusb_bulk_transfer (port->pl->dh, port->settings.usb.outep, (unsigned char_)bytes, size, &curwritten, port->timeout)' failed: Input/Output Error (-1)
Writing 12 = 0xc bytes to port failed: Error writing to the port (-35)
PTP_OC 0x9160 sending req failed: Error writing to the port (-35)
Card value is 2
Sending PTP_OC 0x9110 / PTP_OC_CANON_EOS_SetDevicePropValueEx request...
'libusb_bulk_transfer (port->pl->dh, port->settings.usb.outep, (unsigned char_)bytes, size, &curwritten, port->timeout)' failed: Input/Output Error (-1)
Writing 12 = 0xc bytes to port failed: Error writing to the port (-35)
PTP_OC 0x9110 sending req failed: Error writing to the port (-35)
Clearing halt on OUT EP and retrying once.
Clear USB halt...
'libusb_clear_halt(port->pl->dh, internal_ep)' failed: Other error (-99)
'libusb_bulk_transfer (port->pl->dh, port->settings.usb.outep, (unsigned char_)bytes, size, &curwritten, port->timeout)' failed: Input/Output Error (-1)
Writing 12 = 0xc bytes to port failed: Error writing to the port (-35)
PTP_OC 0x9110 sending req failed: Error writing to the port (-35)
'ptp_canon_eos_setdevicepropvalue (params, PTP_DPC_CANON_EOS_CaptureDestination, &ct_val, PTP_DTC_UINT32)' failed: setdevicepropvalue of capturetarget to 0x2 failed (0x02ff: PTP I/O Error)
'camera_canon_eos_update_capture_target(camera, context, 1)' failed: 'I/O problem' (-7)
Sending PTP_OC 0x1003 / Close session request...
'libusb_bulk_transfer (port->pl->dh, port->settings.usb.outep, (unsigned char_)bytes, size, &curwritten, port->timeout)' failed: Input/Output Error (-1)
Writing 12 = 0xc bytes to port failed: Error writing to the port (-35)
PTP_OC 0x1003 sending req failed: Error writing to the port (-35)
Clearing halt on OUT EP and retrying once.
Clear USB halt...
'libusb_clear_halt(port->pl->dh, internal_ep)' failed: Other error (-99)
'libusb_bulk_transfer (port->pl->dh, port->settings.usb.outep, (unsigned char_)bytes, size, &curwritten, port->timeout)' failed: Input/Output Error (-1)
Writing 12 = 0xc bytes to port failed: Error writing to the port (-35)
PTP_OC 0x1003 sending req failed: Error writing to the port (-35)
Closing port...
canceling transfer 0:0x171fd48 (status 0)
canceling transfer 1:0x172a310 (status 0)
canceling transfer 2:0x172a498 (status 0)
canceling transfer 3:0x172a620 (status 0)
canceling transfer 4:0x172a7a8 (status 0)
canceling transfer 5:0x1726e90 (status 0)
canceling transfer 6:0x1727048 (status 0)
canceling transfer 7:0x1727200 (status 0)
canceling transfer 8:0x17273b8 (status 0)
canceling transfer 9:0x1727570 (status 0)
checking: transfer 0:0x171fd48 status 0
checking: transfer 1:0x172a310 status 0
checking: transfer 2:0x172a498 status 0
checking: transfer 3:0x172a620 status 0
checking: transfer 4:0x172a7a8 status 0
checking: transfer 5:0x1726e90 status 0
checking: transfer 6:0x1727048 status 0
checking: transfer 7:0x1727200 status 0
checking: transfer 8:0x17273b8 status 0
checking: transfer 9:0x1727570 status 0
0x171fd48 with status 3
0x172a310 with status 3
0x172a498 with status 3
0x172a620 with status 3
0x172a7a8 with status 3
0x1726e90 with status 3
0x1727048 with status 3
0x1727200 with status 3
0x17273b8 with status 3
0x1727570 with status 3
resetting filesystem
Clearing fscache LRU list...
fscache LRU list already empty
Internally deleting all folders from '/'...
Lookup folder '/'...
Found! / is 0x1721a38
Recurse delete folder 0x1721a38//
disconnected from camera

@alik55
Copy link
Author

alik55 commented Oct 17, 2015

It appears there are 2 threads - one from my program and one from libusb that gets created when a camera is connected. If the camera is disconnected while there are USB transfers in progress from gp_camera_wait_for_event, the libsub thread tries to cancel transfers which involves calling handle_events in libusb/io.c and my program calls gp_camera_exit about the same time which also tries to cancel transfers from another thread. Comments before handle_events() say "do the actual event handling. assumes that no other thread is concurrently doing the same thing."

@msmeissn
Copy link
Contributor

The other libusb thread should actually only poll udev events I would hope.

@alik55
Copy link
Author

alik55 commented Oct 18, 2015

I am not in a position to debug libusb or libgphoto so I solved my problem by sleeping for a second before calling gp_camera_exit after gp_camera_wait_for_event fails just to give libusb enough time to cleanup.

@msmeissn
Copy link
Contributor

i can try itto debug it, but I fear the problem is in the libusb area, as I am using the standard api calls in the documented way I think. :/

@alik55
Copy link
Author

alik55 commented Oct 18, 2015

I am not familiar at all with what APi libusb exposes and how it is used by libgphoto_port. If libusb exposes any mutexes, those could be used. After briefly looking at libusb code it looks that it was updated quite a bit in recent years and it seemed libgphoto was using some older interface from it (eg libusb_handle_events_timeout_completed is a new one). But I may be totally wrong here.

@msmeissn msmeissn added the bug label Nov 14, 2015
@msmeissn msmeissn self-assigned this Nov 14, 2015
@msmeissn
Copy link
Contributor

could you possibly try 1.0.20 libusb? they had some async related fixes there.

@alik55
Copy link
Author

alik55 commented Nov 15, 2015

Thanks for letting me know. I will install it, but the bug was intermittent, so testing will require a large sample size, but in my release code I will want keep my workaround of sleeping for a second just in case the problem is still around.

@alik55
Copy link
Author

alik55 commented Nov 15, 2015

Well, that did not take long. It still segfaults.

@msmeissn
Copy link
Contributor

not good :( i did some related fixes for the --reset option, but this is unrelated to this issue.

i also fail to reproduce so far here

@msmeissn
Copy link
Contributor

Ok, I think I found the reason and it is as of just now fixed in GIT.

(missing clearing malloced pointers on _close which would be reused on port reopen)

Please retest :)

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

No branches or pull requests

2 participants