state-of-the-art / Handy3DScanner

Repository for Handy 3D Scanner
Apache License 2.0
73 stars 15 forks source link

Intel Realsense D435i support #26

Closed state-of-the-art closed 5 years ago

state-of-the-art commented 5 years ago

Right now app is tested only with D415 (camera & module version). It will be good to increase number of supported devices with D435 camera (wide range).

state-of-the-art commented 5 years ago

I finally got D435i camera (d435+inertial measurement unit) - so I can tune the application to support both cameras.

state-of-the-art commented 5 years ago

Ok, so I'm using librealsense 2.19.2, d415 and d435i with 5.11.1.100 firmware.

state-of-the-art commented 5 years ago

librealsense debug logs when connecting d415 (connected ok and showing stream):

Connect:

D Handy3DScanner: onDeviceConnected
D ViewRootImpl@9d10a3b[Handy3DScannerActivity]: MSG_WINDOW_FOCUS_CHANGED 0
D ViewRootImpl@9d10a3b[Handy3DScannerActivity]: MSG_WINDOW_FOCUS_CHANGED 1
D ViewRootImpl@9d10a3b[Handy3DScannerActivity]: mHardwareRenderer.initializeIfNeeded()#2 mSurface={isValid=true 547455611904}
D Handy3DScanner: onUsbPermission
D Handy3DScanner: inserting device with id: 2002 and file descriptor: 114
D librs   : AddUsbDevice, previous device count: 0
D librs   : AddUsbDevice, adding device: /dev/bus/usb/002/002, descriptor: 114
D librs   : Adding pipe at address 135
D librs   : Adding pipe at address 130
D librs   : Adding pipe at address 131
D librs   : Adding pipe at address 132
I librs   : Found UVC Device vid: id-
I librs   : vid- 8086
I librs   : pid- ad3
I librs   : mi- 0
I librs   : unique_id- r
I librs   : path- /dev/bus/usb/002/002
I librs   : susb specification- 320
I librs   : Found UVC Device vid: id-
I librs   : vid- 8086
I librs   : pid- ad3
I librs   : mi- 3
I librs   : unique_id- r
I librs   : path- /dev/bus/usb/002/002
I librs   : susb specification- 320
D librs   : try_fetch_usb_device(...) failed.
04-20 11:48:29.262 28081 28081 D librs   :
D librs   : Device connected:
04-20 11:48:29.262 28081 28081 D librs   :
D librs   : uvc devices:
D librs   : id-
D librs   : vid- 8086
D librs   : pid- ad3
D librs   : mi- 0
D librs   : unique_id- r
D librs   : path- /dev/bus/usb/002/002
D librs   : susb specification- 320
04-20 11:48:29.262 28081 28081 D librs   :
D librs   : id-
D librs   : vid- 8086
D librs   : pid- ad3
D librs   : mi- 3
D librs   : unique_id- r
D librs   : path- /dev/bus/usb/002/002
D librs   : susb specification- 320
04-20 11:48:29.262 28081 28081 D librs   :
D Handy 3D Scanner: Devices changed!
D Handy 3D Scanner: Removing device...
D librs   : Creating UVC Device from path: /dev/bus/usb/002/002
D librs   : Creating UVC Device from path: /dev/bus/usb/002/002
D Handy 3D Scanner: Processing found device:  "821212061876"
D Handy 3D Scanner: Connected camera:  Intel RealSense D415 :
D librs   : AddUsbDevice, current device count: 2
D Handy3DScanner: device attached: /dev/bus/usb/002/002 - UsbDevice[mName=/dev/bus/usb/002/002,mVendorId=32902,mProductId=2771,mClass=239,mSubclass=2,mProtocol=1,mManufacturerName=Intel(R) RealSense(TM) Depth Camera 415 ,mProductName=Intel(R) RealSense(TM) Depth Camera 415 ,mVersion=3.32,mSerialNumber=821413025395,mConfigurations=[
D Handy3DScanner: UsbConfiguration[mId=1,mName=null,mAttributes=192,mMaxPower=55,mInterfaces=[
D Handy3DScanner: UsbInterface[mId=0,mAlternateSetting=0,mName=Intel(R) RealSense(TM) Depth Camera 415  Depth,mClass=14,mSubclass=1,mProtocol=0,mEndpoints=[
D Handy3DScanner: UsbEndpoint[mAddress=135,mAttributes=3,mMaxPacketSize=64,mInterval=6]]
D Handy3DScanner: UsbInterface[mId=1,mAlternateSetting=0,mName=Intel(R) RealSense(TM) Depth Camera 415  Depth,mClass=14,mSubclass=2,mProtocol=0,mEndpoints=[
D Handy3DScanner: UsbEndpoint[mAddress=130,mAttributes=2,mMaxPacketSize=1024,mInterval=0]]
D Handy3DScanner: UsbInterface[mId=2,mAlternateSetting=0,mName=Intel(R) RealSense(TM) Depth Camera 415  Y,mClass=14,mSubclass=2,mProtocol=0,mEndpoints=[
D Handy3DScanner: UsbEndpoint[mAddress=131,mAttributes=2,mMaxPacketSize=1024,mInterval=0]]
D Handy3DScanner: UsbInterface[mId=3,mAlternateSetting=0,mName=Intel(R) RealSense(TM) Depth Camera 415  RGB,mClass=14,mSubclass=1,mProtocol=0,mEndpoints=[]
D Handy3DScanner: UsbInterface[mId=4,mAlternateSetting=0,mName=Intel(R) RealSense(TM) Depth Camera 415  RGB,mClass=14,mSubclass=2,mProtocol=0,mEndpoints=[
D Handy3DScanner: UsbEndpoint[mAddress=132,mAttributes=2,mMaxPacketSize=1024,mInterval=0]]]]
D Handy 3D Scanner: Connected:  "821212061876" "*"
D Handy 3D Scanner: Setting stream parameters
D Handy 3D Scanner: start streaming
D Handy 3D Scanner: start pipe
I librs   : Found UVC Device vid: id-
I librs   : vid- 8086
I librs   : pid- ad3
I librs   : mi- 0
I librs   : unique_id- r
I librs   : path- /dev/bus/usb/002/002
I librs   : susb specification- 320
I librs   : Found UVC Device vid: id-
I librs   : vid- 8086
I librs   : pid- ad3
I librs   : mi- 3
I librs   : unique_id- r
I librs   : path- /dev/bus/usb/002/002
I librs   : susb specification- 320
D librs   : try_fetch_usb_device(...) failed.
D librs   : Creating UVC Device from path: /dev/bus/usb/002/002
D librs   : Creating UVC Device from path: /dev/bus/usb/002/002
04-20 11:48:29.297 28081 28263 W librs   :
04-20 11:48:29.307 28081 28263 W librs   :
D librs   : USB pipe 130 reset successfully
D Handy 3D Scanner: get serial
D librs   : USB pipe 132 reset successfully
D librs   : Transfer thread started for endpoint address: 132
D librs   : Transfer thread started for endpoint address: 130
D librs   : Passing packet to user CB with size 1843448
D librs   : FrameAccepted,Depth,Counter,0,Index,0,BackEndTS,0.000000,SystemTime,1555786109660.638916 ,diff_ts[Sys-BE],1555786109660.638916,TS,9267.426000,TS_Domain,Hardware Clock,last_frame_number,0,last_timestamp,0.000000
D librs   : Passing packet to user CB with size 1843448
D librs   : CallbackStarted,Depth,0,DispatchedAt,1555786109702.207031
D librs   : DISPATCH (TS: )--> Depth 0 9267.426000
D librs   : DISPATCH (TS: (FN: I Depth I Infrared I Infrared ) I Color )--> Depth 0 9267.426000
D librs   : DISPATCH (FN: I Depth I Infrared I Infrared )--> Depth 0 9267.426000
D librs   : I Depth--> Depth 0, 9267.426000
D librs   : SYNC (FN: I Depth I Infrared I Infrared )--> Depth 0 9267.426000
D librs   : SYNC (TS: (FN: I Depth I Infrared I Infrared ) I Color )--> Depth 0 9267.426000
D librs   : fps 30 Depth 0 9267.426000
D librs   : (TS: (FN: I Depth I Infrared I Infrared ) I Color )Depth 0 9267.426000 fps 30 gap 33.3333 next_expected: 9300.76
D librs   : CallbackFinished,Depth,0,DispatchedAt,1.55579e+12
D librs   : Frame Callback [Depth#0] overdue. (Duration: 1.55579e+12ms, FPS: 30, Max Duration: 32ms)
D librs   : SYNC (TS: )--> Depth 0 9267.426000
D librs   : fps 30 Depth 0 9267.426000
D librs   : (TS: )Depth 0 9267.426000 fps 30 gap 33.3333 next_expected: 9300.76
D librs   : CallbackFinished,Depth,0,DispatchedAt,1.55579e+12
D librs   : Frame Callback [Depth#0] overdue. (Duration: 1.55579e+12ms, FPS: 30, Max Duration: 32ms)
04-20 11:48:29.703 28081 29143 D librs   :
D librs   : CallbackStarted,Depth,0,DispatchedAt,1555786109703.998047
D librs   : CallbackFinished,Depth,0,DispatchedAt,1.55579e+12
D librs   : FrameAccepted,Depth,Counter,1,Index,0,BackEndTS,0.000000,SystemTime,1555786109704.124023 ,diff_ts[Sys-BE],1555786109704.124023,TS,9300.747000,TS_Domain,Hardware Clock,last_frame_number,0,last_timestamp,9267.426000
D librs   : Passing packet to user CB with size 1843448
D librs   : CallbackStarted,Depth,1,DispatchedAt,1555786109738.465088
D librs   : DISPATCH (TS: )--> Depth 1 9300.747000
D librs   : DISPATCH (TS: (FN: I Depth I Infrared I Infrared ) I Color )--> Depth 1 9300.747000
D librs   : DISPATCH (FN: I Depth I Infrared I Infrared )--> Depth 1 9300.747000
D librs   : I Depth--> Depth 1, 9300.747000
D librs   : SYNC (FN: I Depth I Infrared I Infrared )--> Depth 1 9300.747000
D librs   : SYNC (TS: (FN: I Depth I Infrared I Infrared ) I Color )--> Depth 1 9300.747000
D librs   : fps 30 Depth 1 9300.747000
D librs   : (TS: (FN: I Depth I Infrared I Infrared ) I Color )Depth 1 9300.747000 fps 30 gap 33.3333 next_expected: 9334.08
D librs   : CallbackFinished,Depth,0,DispatchedAt,1.55579e+12
D librs   : Frame Callback [Depth#0] overdue. (Duration: 1.55579e+12ms, FPS: 30, Max Duration: 32ms)
D librs   : SYNC (TS: )--> Depth 1 9300.747000
D librs   : fps 30 Depth 1 9300.747000
D librs   : (TS: )Depth 1 9300.747000 fps 30 gap 33.3333 next_expected: 9334.08
D librs   : CallbackFinished,Depth,0,DispatchedAt,1.55579e+12
D librs   : Frame Callback [Depth#0] overdue. (Duration: 1.55579e+12ms, FPS: 30, Max Duration: 32ms)
04-20 11:48:29.739 28081 29143 D librs   :
D librs   : CallbackStarted,Depth,1,DispatchedAt,1555786109739.884033
D librs   : CallbackFinished,Depth,0,DispatchedAt,1.55579e+12
D librs   : Frame Callback [Depth#0] overdue. (Duration: 37.717ms, FPS: 30, Max Duration: 32ms)
D librs   : CallbackFinished,Depth,0,DispatchedAt,1.55579e+12
D librs   : FrameAccepted,Depth,Counter,2,Index,0,BackEndTS,0.000000,SystemTime,1555786109740.068115 ,diff_ts[Sys-BE],1555786109740.068115,TS,9334.068000,TS_Domain,Hardware Clock,last_frame_number,1,last_timestamp,9300.747000
D librs   : CallbackStarted,Depth,2,DispatchedAt,1555786109740.717041
D librs   : DISPATCH (TS: )--> Depth 2 9334.068000
D librs   : DISPATCH (TS: (FN: I Depth I Infrared I Infrared ) I Color )--> Depth 2 9334.068000
D librs   : DISPATCH (FN: I Depth I Infrared I Infrared )--> Depth 2 9334.068000
D librs   : I Depth--> Depth 2, 9334.068000
D librs   : SYNC (FN: I Depth I Infrared I Infrared )--> Depth 2 9334.068000
D librs   : SYNC (TS: (FN: I Depth I Infrared I Infrared ) I Color )--> Depth 2 9334.068000
D librs   : fps 30 Depth 2 9334.068000
D librs   : (TS: (FN: I Depth I Infrared I Infrared ) I Color )Depth 2 9334.068000 fps 30 gap 33.3333 next_expected: 9367.4
D librs   : CallbackFinished,Depth,0,DispatchedAt,1.55579e+12
D librs   : Frame Callback [Depth#0] overdue. (Duration: 1.55579e+12ms, FPS: 30, Max Duration: 32ms)
D librs   : SYNC (TS: )--> Depth 2 9334.068000
D librs   : fps 30 Depth 2 9334.068000
D librs   : (TS: )Depth 2 9334.068000 fps 30 gap 33.3333 next_expected: 9367.4
D librs   : CallbackFinished,Depth,0,DispatchedAt,1.55579e+12
D librs   : Frame Callback [Depth#0] overdue. (Duration: 1.55579e+12ms, FPS: 30, Max Duration: 32ms)
04-20 11:48:29.741 28081 29143 D librs   :
D librs   : CallbackStarted,Depth,2,DispatchedAt,1555786109741.840088
D librs   : CallbackFinished,Depth,1,DispatchedAt,1.55579e+12
D librs   : CallbackFinished,Depth,0,DispatchedAt,1.55579e+12
D librs   : Passing packet to user CB with size 1843448
D librs   : FrameAccepted,Depth,Counter,3,Index,0,BackEndTS,0.000000,SystemTime,1555786109759.895996 ,diff_ts[Sys-BE],1555786109759.895996,TS,9367.390000,TS_Domain,Hardware Clock,last_frame_number,2,last_timestamp,9334.068000
D librs   : CallbackStarted,Depth,3,DispatchedAt,1555786109760.669922
D librs   : DISPATCH (TS: )--> Depth 3 9367.390000
D librs   : DISPATCH (TS: (FN: I Depth I Infrared I Infrared ) I Color )--> Depth 3 9367.390000
D librs   : DISPATCH (FN: I Depth I Infrared I Infrared )--> Depth 3 9367.390000
D librs   : I Depth--> Depth 3, 9367.390000
D librs   : SYNC (FN: I Depth I Infrared I Infrared )--> Depth 3 9367.390000
D librs   : SYNC (TS: (FN: I Depth I Infrared I Infrared ) I Color )--> Depth 3 9367.390000
D librs   : fps 30 Depth 3 9367.390000
D librs   : (TS: (FN: I Depth I Infrared I Infrared ) I Color )Depth 3 9367.390000 fps 30 gap 33.3333 next_expected: 9400.72
D librs   : CallbackFinished,Depth,0,DispatchedAt,1.55579e+12
D librs   : Frame Callback [Depth#0] overdue. (Duration: 1.55579e+12ms, FPS: 30, Max Duration: 32ms)
D librs   : SYNC (TS: )--> Depth 3 9367.390000
D librs   : fps 30 Depth 3 9367.390000
D librs   : (TS: )Depth 3 9367.390000 fps 30 gap 33.3333 next_expected: 9400.72
D librs   : CallbackFinished,Depth,0,DispatchedAt,1.55579e+12
D librs   : Frame Callback [Depth#0] overdue. (Duration: 1.55579e+12ms, FPS: 30, Max Duration: 32ms)
04-20 11:48:29.762 28081 29143 D librs   :
D librs   : CallbackStarted,Depth,3,DispatchedAt,1555786109762.812012
D librs   : CallbackFinished,Depth,2,DispatchedAt,1.55579e+12
D librs   : CallbackFinished,Depth,0,DispatchedAt,1.55579e+12
D librs   : Passing packet to user CB with size 1843448
D librs   : FrameAccepted,Depth,Counter,4,Index,0,BackEndTS,0.000000,SystemTime,1555786109793.031982 ,diff_ts[Sys-BE],1555786109793.031982,TS,9400.711000,TS_Domain,Hardware Clock,last_frame_number,3,last_timestamp,9367.390000
state-of-the-art commented 5 years ago

librealsense debug logs when connecting d435i (showing connect message bug not showing stream):

state-of-the-art commented 5 years ago

That means - somewhere in the middle of Java_com_intel_realsense_librealsense_DeviceWatcher_nAddUsbDevice librealsense function we have some issue.

state-of-the-art commented 5 years ago

Added a couple of debug logs - seems the device is added and the callback is calling.

This warning is produced during the callback:

W librs   : DS5 group_devices is empty.

Something wrong with callback function on the app side...

state-of-the-art commented 5 years ago

The _callback function librealsense is calling is related to the app callback device watcher function, but it's a wrapper. When app execute set_devices_changed_callback, context set _devices_changed_callback object property with this callback, but it's started from on_device_changed context function, which is check - there was any changes between the old and new device lists.

Again seems the issue in the librealsense.

state-of-the-art commented 5 years ago

During context::on_device_changed it's executing create_devices for the both (old & curr) lists. Our device seems filtered somewhere here.

state-of-the-art commented 5 years ago

Yep, it tries to check RS2_PRODUCT_LINE_D400 and calling ds5_info::pick_ds5_devices - where we can see this warning message about DS5 group_devices.

state-of-the-art commented 5 years ago

Ok, I disabled checking of hids.capacity() >= 2 and camera started to show the stream.

state-of-the-art commented 5 years ago

Now the connection log for d435i (with additional librealsense custom debug lines) is:

D Handy3DScanner: onUsbPermission
D Handy3DScanner: inserting device with id: 2002 and file descriptor: 116
D librs   : AddUsbDevice, previous device count: 0
D librs   : AddUsbDevice, adding device: /dev/bus/usb/002/002, descriptor: 116
D librs   : AddUsbDevice, current handle: 0x7f51fc5000
D librs   : AddUsbDevice, adding device: 0x7f51fc5000
D librs   : Adding pipe at address 135
D librs   : Adding pipe at address 130
D librs   : Adding pipe at address 131
D librs   : Adding pipe at address 132
D librs   : Adding pipe at address 134
I librs   : Found UVC Device vid: id-
I librs   : vid- 8086
I librs   : pid- b3a
I librs   : mi- 0
I librs   : unique_id- t
I librs   : path- /dev/bus/usb/002/002
I librs   : susb specification- 320
I librs   : Found UVC Device vid: id-
I librs   : vid- 8086
I librs   : pid- b3a
I librs   : mi- 3
I librs   : unique_id- t
I librs   : path- /dev/bus/usb/002/002
I librs   : susb specification- 320
D librs   : AddUsbDevice, going to run callback function: 0x7f51fc5000
D librs   : AddUsbDevice, running callback function: 0x7f51fc5000
D librs   : context::on_device_changed: started
D librs   : context::create_devices: started
D librs   : context::create_devices: d400 started
D librs   : context::create_devices: d400 ended
D librs   : context::create_devices: l500 started
D librs   : context::create_devices: l500 ended
D librs   : context::create_devices: sr300 started
D librs   : context::create_devices: sr300 ended
D librs   : context::create_devices: recovery started
D librs   : context::create_devices: recovery ended
D librs   : context::create_devices: nonintel started
D librs   : context::create_devices: ended started
D librs   : context::create_devices: pushing devices...
D librs   : context::create_devices: ended
D librs   : context::create_devices: started
D librs   : context::create_devices: d400 started
D librs   : ds5_info::pick_ds5_devices: all sens present start: 1
D librs   : ds5_info::pick_ds5_devices: all sens present mul: 1
D librs   : ds5_info::pick_ds5_devices: all sens present mul: 1
D librs   : ds5_info::pick_ds5_devices: all sens present hid: 1
D librs   : ds5_info::pick_ds5_devices: all sens present hid cap: 0
D librs   : ds5_info::pick_ds5_devices: all sens present hid: 1
D librs   : ds5_info::pick_ds5_devices: devices empty: 0
D librs   : ds5_info::pick_ds5_devices: all sens present: 1
D librs   : try_fetch_usb_device(...) failed.
D librs   : context::create_devices: d400 ended
D librs   : context::create_devices: l500 started
D librs   : context::create_devices: l500 ended
D librs   : context::create_devices: sr300 started
D librs   : context::create_devices: sr300 ended
D librs   : context::create_devices: recovery started
D librs   : context::create_devices: recovery ended
D librs   : context::create_devices: nonintel started
D librs   : context::create_devices: ended started
D librs   : context::create_devices: pushing devices...
D librs   : context::create_devices: ended
D librs   : context::on_device_changed: check list changed
D librs   : context::on_device_changed: remove sets substracted
D librs   : context::on_device_changed: add sets substracted
04-20 13:08:00.493 12807 12807 D librs   :
D librs   : Device connected:
04-20 13:08:00.493 12807 12807 D librs   :
D librs   : uvc devices:
D librs   : id-
D librs   : vid- 8086
D librs   : pid- b3a
D librs   : mi- 0
D librs   : unique_id- t
D librs   : path- /dev/bus/usb/002/002
D librs   : susb specification- 320
04-20 13:08:00.493 12807 12807 D librs   :
D librs   : id-
D librs   : vid- 8086
D librs   : pid- b3a
D librs   : mi- 3
D librs   : unique_id- t
D librs   : path- /dev/bus/usb/002/002
D librs   : susb specification- 320
04-20 13:08:00.493 12807 12807 D librs   :
D librs   : context::on_device_changed: list of added devices: 1
D librs   : context::raise_devices_changed: start
D librs   : context::raise_devices_changed: running callback
D Handy 3D Scanner: Devices changed!
D Handy 3D Scanner: Removing device...
D librs   : Creating UVC Device from path: /dev/bus/usb/002/002
D librs   : Creating UVC Device from path: /dev/bus/usb/002/002
W librs   : HID device is missing!
D Handy 3D Scanner: Processing found device:  "846112070211"
D Handy 3D Scanner: Connected camera:  Intel RealSense D435I :
D librs   : context::on_device_changed: ended
D librs   : AddUsbDevice, current device count: 2
D Handy3DScanner: device attached: /dev/bus/usb/002/002 - UsbDevice[mName=/dev/bus/usb/002/002,mVendorId=32902,mProductId=2874,mClass=239,mSubclass=2,mProtocol=1,mManufacturerName=Intel(R) RealSense(TM) Depth Camera 435i,mProductName=Intel(R) RealSense(TM) Depth Camera 435i,mVersion=3.32,mSerialNumber=904523050896,mConfigurations=[
D Handy3DScanner: UsbConfiguration[mId=1,mName=null,mAttributes=192,mMaxPower=55,mInterfaces=[
D Handy3DScanner: UsbInterface[mId=0,mAlternateSetting=0,mName=Intel(R) RealSense(TM) Depth Camera 435i Depth,mClass=14,mSubclass=1,mProtocol=0,mEndpoints=[
D Handy3DScanner: UsbEndpoint[mAddress=135,mAttributes=3,mMaxPacketSize=64,mInterval=6]]
D Handy3DScanner: UsbInterface[mId=1,mAlternateSetting=0,mName=Intel(R) RealSense(TM) Depth Camera 435i Depth,mClass=14,mSubclass=2,mProtocol=0,mEndpoints=[
D Handy3DScanner: UsbEndpoint[mAddress=130,mAttributes=2,mMaxPacketSize=1024,mInterval=0]]
D Handy3DScanner: UsbInterface[mId=2,mAlternateSetting=0,mName=Intel(R) RealSense(TM) Depth Camera 435i Y,mClass=14,mSubclass=2,mProtocol=0,mEndpoints=[
D Handy3DScanner: UsbEndpoint[mAddress=131,mAttributes=2,mMaxPacketSize=1024,mInterval=0]]
D Handy3DScanner: UsbInterface[mId=3,mAlternateSetting=0,mName=Intel(R) RealSense(TM) Depth Camera 435i RGB,mClass=14,mSubclass=1,mProtocol=0,mEndpoints=[]
D Handy3DScanner: UsbInterface[mId=4,mAlternateSetting=0,mName=Intel(R) RealSense(TM) Depth Camera 435i RGB,mClass=14,mSubclass=2,mProtocol=0,mEndpoints=[
D Handy3DScanner: UsbEndpoint[mAddress=132,mAttributes=2,mMaxPacketSize=1024,mInterval=0]]
D Handy3DScanner: UsbInterface[mId=5,mAlternateSetting=0,mName=Intel(R) RealSense(TM) HID,mClass=3,mSubclass=0,mProtocol=0,mEndpoints=[
D Handy3DScanner: UsbEndpoint[mAddress=134,mAttributes=3,mMaxPacketSize=64,mInterval=2]]]]
D Handy 3D Scanner: Connected:  "846112070211" "*"
D Handy 3D Scanner: Setting stream parameters
D Handy 3D Scanner: start streaming
D Handy 3D Scanner: start pipe
I librs   : Found UVC Device vid: id-
I librs   : vid- 8086
I librs   : pid- b3a
I librs   : mi- 0
I librs   : unique_id- t
I librs   : path- /dev/bus/usb/002/002
I librs   : susb specification- 320
I librs   : Found UVC Device vid: id-
I librs   : vid- 8086
I librs   : pid- b3a
I librs   : mi- 3
I librs   : unique_id- t
I librs   : path- /dev/bus/usb/002/002
I librs   : susb specification- 320
D librs   : context::create_devices: started
D librs   : context::create_devices: d400 started
D librs   : ds5_info::pick_ds5_devices: all sens present start: 1
D librs   : ds5_info::pick_ds5_devices: all sens present mul: 1
D librs   : ds5_info::pick_ds5_devices: all sens present mul: 1
D librs   : ds5_info::pick_ds5_devices: all sens present hid: 1
D librs   : ds5_info::pick_ds5_devices: all sens present hid cap: 0
D librs   : ds5_info::pick_ds5_devices: all sens present hid: 1
D librs   : ds5_info::pick_ds5_devices: devices empty: 0
D librs   : ds5_info::pick_ds5_devices: all sens present: 1
D librs   : try_fetch_usb_device(...) failed.
D librs   : context::create_devices: d400 ended
D librs   : context::create_devices: l500 started
D librs   : context::create_devices: l500 ended
D librs   : context::create_devices: sr300 started
D librs   : context::create_devices: sr300 ended
D librs   : context::create_devices: recovery started
D librs   : context::create_devices: recovery ended
D librs   : context::create_devices: nonintel started
D librs   : context::create_devices: ended started
D librs   : context::create_devices: pushing devices...
D librs   : context::create_devices: ended
D librs   : Creating UVC Device from path: /dev/bus/usb/002/002
D librs   : Creating UVC Device from path: /dev/bus/usb/002/002
W librs   : HID device is missing!
04-20 13:08:00.521 12807 12940 W librs   :
04-20 13:08:00.524 12807 12940 W librs   :
D librs   : USB pipe 130 reset successfully
D Handy 3D Scanner: get serial
D librs   : USB pipe 132 reset successfully
D librs   : Transfer thread started for endpoint address: 130
D librs   : Transfer thread started for endpoint address: 132
D librs   : Passing packet to user CB with size 1843448
D librs   : FrameAccepted,Depth,Counter,0,Index,0,BackEndTS,0.000000,SystemTime,1555790880794.303955 ,diff_ts[Sys-BE],1555790880794.303955,TS,2324.632000,TS_Domain,Hardware Clock,last_frame_number,0,last_timestamp,0.000000
D librs   : Passing packet to user CB with size 1843448
D librs   : CallbackStarted,Depth,0,DispatchedAt,1555790880835.916992
D librs   : DISPATCH (TS: )--> Depth 0 2324.632000
W librs   : WinUSB backend is dropping a frame because librealsense wasn't fast enough
D librs   : Created default matcher
D librs   : DISPATCH (TS: (TS: (FN: I Depth I Infrared I Infrared ) I Color ) (TS: I Accel I Gyro ) )--> Depth 0 2324.632000
D librs   : DISPATCH (TS: (FN: I Depth I Infrared I Infrared ) I Color )--> Depth 0 2324.632000
D librs   : DISPATCH (FN: I Depth I Infrared I Infrared )--> Depth 0 2324.632000
D librs   : I Depth--> Depth 0, 2324.632000
D librs   : SYNC (FN: I Depth I Infrared I Infrared )--> Depth 0 2324.632000
D librs   : SYNC (TS: (FN: I Depth I Infrared I Infrared ) I Color )--> Depth 0 2324.632000
D librs   : fps 30 Depth 0 2324.632000
D librs   : (TS: (FN: I Depth I Infrared I Infrared ) I Color )Depth 0 2324.632000 fps 30 gap 33.3333 next_expected: 2357.97
D librs   : CallbackFinished,Depth,0,DispatchedAt,1.55579e+12
D librs   : Frame Callback [Depth#0] overdue. (Duration: 1.55579e+12ms, FPS: 30, Max Duration: 32ms)
D librs   : SYNC (TS: (TS: (FN: I Depth I Infrared I Infrared ) I Color ) (TS: I Accel I Gyro ) )--> Depth 0 2324.632000
D librs   : fps 30 Depth 0 2324.632000
D librs   : (TS: (TS: (FN: I Depth I Infrared I Infrared ) I Color ) (TS: I Accel I Gyro ) )Depth 0 2324.632000 fps 30 gap 33.3333 next_expected: 2357.97
D librs   : CallbackFinished,Depth,0,DispatchedAt,1.55579e+12
D librs   : Frame Callback [Depth#0] overdue. (Duration: 1.55579e+12ms, FPS: 30, Max Duration: 32ms)
D librs   : SYNC (TS: )--> Depth 0 2324.632000
D librs   : fps 30 Depth 0 2324.632000
D librs   : (TS: )Depth 0 2324.632000 fps 30 gap 33.3333 next_expected: 2357.97
D librs   : CallbackFinished,Depth,0,DispatchedAt,1.55579e+12
D librs   : Frame Callback [Depth#0] overdue. (Duration: 1.55579e+12ms, FPS: 30, Max Duration: 32ms)
04-20 13:08:00.876 12807 13638 D librs   :
D librs   : CallbackStarted,Depth,0,DispatchedAt,1555790880876.384033
D librs   : CallbackFinished,Depth,0,DispatchedAt,1.55579e+12
D librs   : FrameAccepted,Depth,Counter,1,Index,0,BackEndTS,0.000000,SystemTime,1555790880876.528076 ,diff_ts[Sys-BE],1555790880876.528076,TS,2357.969000,TS_Domain,Hardware Clock,last_frame_number,0,last_timestamp,2324.632000
D librs   : Passing packet to user CB with size 1843448
D librs   : CallbackStarted,Depth,1,DispatchedAt,1555790880913.574951
D librs   : DISPATCH (TS: )--> Depth 1 2357.969000
D librs   : DISPATCH (TS: (TS: (FN: I Depth I Infrared I Infrared ) I Color ) (TS: I Accel I Gyro ) )--> Depth 1 2357.969000
D librs   : DISPATCH (TS: (FN: I Depth I Infrared I Infrared ) I Color )--> Depth 1 2357.969000
D librs   : DISPATCH (FN: I Depth I Infrared I Infrared )--> Depth 1 2357.969000
D librs   : I Depth--> Depth 1, 2357.969000
D librs   : SYNC (FN: I Depth I Infrared I Infrared )--> Depth 1 2357.969000
D librs   : SYNC (TS: (FN: I Depth I Infrared I Infrared ) I Color )--> Depth 1 2357.969000
D librs   : fps 30 Depth 1 2357.969000
D librs   : (TS: (FN: I Depth I Infrared I Infrared ) I Color )Depth 1 2357.969000 fps 30 gap 33.3333 next_expected: 2391.3
D librs   : CallbackFinished,Depth,0,DispatchedAt,1.55579e+12
state-of-the-art commented 5 years ago

Just for reference, d415 camera connection logs with additional custom debug logs:

D Handy3DScanner: onUsbPermission
D Handy3DScanner: inserting device with id: 2002 and file descriptor: 116
D librs   : AddUsbDevice, previous device count: 0
D librs   : AddUsbDevice, adding device: /dev/bus/usb/002/002, descriptor: 116
D librs   : AddUsbDevice, current handle: 0x7f53f02000
D librs   : AddUsbDevice, adding device: 0x7f53f02000
D librs   : Adding pipe at address 135
D librs   : Adding pipe at address 130
D librs   : Adding pipe at address 131
D librs   : Adding pipe at address 132
I librs   : Found UVC Device vid: id-
I librs   : vid- 8086
I librs   : pid- ad3
I librs   : mi- 0
I librs   : unique_id- t
I librs   : path- /dev/bus/usb/002/002
I librs   : susb specification- 320
I librs   : Found UVC Device vid: id-
I librs   : vid- 8086
I librs   : pid- ad3
I librs   : mi- 3
I librs   : unique_id- t
I librs   : path- /dev/bus/usb/002/002
I librs   : susb specification- 320
D librs   : AddUsbDevice, going to run callback function: 0x7f53f02000
D librs   : AddUsbDevice, running callback function: 0x7f53f02000
D librs   : context::on_device_changed: started
D librs   : context::create_devices: started
D librs   : context::create_devices: d400 started
D librs   : context::create_devices: d400 ended
D librs   : context::create_devices: l500 started
D librs   : context::create_devices: l500 ended
D librs   : context::create_devices: sr300 started
D librs   : context::create_devices: sr300 ended
D librs   : context::create_devices: recovery started
D librs   : context::create_devices: recovery ended
D librs   : context::create_devices: nonintel started
D librs   : context::create_devices: ended started
D librs   : context::create_devices: pushing devices...
D librs   : context::create_devices: ended
D librs   : context::create_devices: started
D librs   : context::create_devices: d400 started
D librs   : ds5_info::pick_ds5_devices: all sens present start: 1
D librs   : ds5_info::pick_ds5_devices: all sens present mul: 1
D librs   : ds5_info::pick_ds5_devices: all sens present mul: 1
D librs   : ds5_info::pick_ds5_devices: devices empty: 0
D librs   : ds5_info::pick_ds5_devices: all sens present: 1
D librs   : try_fetch_usb_device(...) failed.
D librs   : context::create_devices: d400 ended
D librs   : context::create_devices: l500 started
D librs   : context::create_devices: l500 ended
D librs   : context::create_devices: sr300 started
D librs   : context::create_devices: sr300 ended
D librs   : context::create_devices: recovery started
D librs   : context::create_devices: recovery ended
D librs   : context::create_devices: nonintel started
D librs   : context::create_devices: ended started
D librs   : context::create_devices: pushing devices...
D librs   : context::create_devices: ended
D librs   : context::on_device_changed: check list changed
D librs   : context::on_device_changed: remove sets substracted
D librs   : context::on_device_changed: add sets substracted
04-20 13:17:26.079 14490 14490 D librs   :
D librs   : Device connected:
04-20 13:17:26.079 14490 14490 D librs   :
D librs   : uvc devices:
D librs   : id-
D librs   : vid- 8086
D librs   : pid- ad3
D librs   : mi- 0
D librs   : unique_id- t
D librs   : path- /dev/bus/usb/002/002
D librs   : susb specification- 320
04-20 13:17:26.079 14490 14490 D librs   :
D librs   : id-
D librs   : vid- 8086
D librs   : pid- ad3
D librs   : mi- 3
D librs   : unique_id- t
D librs   : path- /dev/bus/usb/002/002
D librs   : susb specification- 320
04-20 13:17:26.079 14490 14490 D librs   :
D librs   : context::on_device_changed: list of added devices: 1
D librs   : context::raise_devices_changed: start
D librs   : context::raise_devices_changed: running callback
D Handy 3D Scanner: Devices changed!
D Handy 3D Scanner: Removing device...
D librs   : Creating UVC Device from path: /dev/bus/usb/002/002
D librs   : Creating UVC Device from path: /dev/bus/usb/002/002
D Handy 3D Scanner: Processing found device:  "821212061876"
D Handy 3D Scanner: Connected camera:  Intel RealSense D415 :
D librs   : context::on_device_changed: ended
D librs   : AddUsbDevice, current device count: 2
D Handy3DScanner: device attached: /dev/bus/usb/002/002 - UsbDevice[mName=/dev/bus/usb/002/002,mVendorId=32902,mProductId=2771,mClass=239,mSubclass=2,mProtocol=1,mManufacturerName=Intel(R) RealSense(TM) Depth Camera 415 ,mProductName=Intel(R) RealSense(TM) Depth Camera 415 ,mVersion=3.32,mSerialNumber=821413025395,mConfigurations=[
D Handy3DScanner: UsbConfiguration[mId=1,mName=null,mAttributes=192,mMaxPower=55,mInterfaces=[
D Handy3DScanner: UsbInterface[mId=0,mAlternateSetting=0,mName=Intel(R) RealSense(TM) Depth Camera 415  Depth,mClass=14,mSubclass=1,mProtocol=0,mEndpoints=[
D Handy3DScanner: UsbEndpoint[mAddress=135,mAttributes=3,mMaxPacketSize=64,mInterval=6]]
D Handy3DScanner: UsbInterface[mId=1,mAlternateSetting=0,mName=Intel(R) RealSense(TM) Depth Camera 415  Depth,mClass=14,mSubclass=2,mProtocol=0,mEndpoints=[
D Handy3DScanner: UsbEndpoint[mAddress=130,mAttributes=2,mMaxPacketSize=1024,mInterval=0]]
D Handy3DScanner: UsbInterface[mId=2,mAlternateSetting=0,mName=Intel(R) RealSense(TM) Depth Camera 415  Y,mClass=14,mSubclass=2,mProtocol=0,mEndpoints=[
D Handy3DScanner: UsbEndpoint[mAddress=131,mAttributes=2,mMaxPacketSize=1024,mInterval=0]]
D Handy3DScanner: UsbInterface[mId=3,mAlternateSetting=0,mName=Intel(R) RealSense(TM) Depth Camera 415  RGB,mClass=14,mSubclass=1,mProtocol=0,mEndpoints=[]
D Handy3DScanner: UsbInterface[mId=4,mAlternateSetting=0,mName=Intel(R) RealSense(TM) Depth Camera 415  RGB,mClass=14,mSubclass=2,mProtocol=0,mEndpoints=[
D Handy3DScanner: UsbEndpoint[mAddress=132,mAttributes=2,mMaxPacketSize=1024,mInterval=0]]]]
D Handy 3D Scanner: Connected:  "821212061876" "*"
D Handy 3D Scanner: Setting stream parameters
D Handy 3D Scanner: start streaming
D Handy 3D Scanner: start pipe
I librs   : Found UVC Device vid: id-
I librs   : vid- 8086
I librs   : pid- ad3
I librs   : mi- 0
I librs   : unique_id- t
I librs   : path- /dev/bus/usb/002/002
I librs   : susb specification- 320
I librs   : Found UVC Device vid: id-
I librs   : vid- 8086
I librs   : pid- ad3
I librs   : mi- 3
I librs   : unique_id- t
I librs   : path- /dev/bus/usb/002/002
I librs   : susb specification- 320
D librs   : context::create_devices: started
D librs   : context::create_devices: d400 started
D librs   : ds5_info::pick_ds5_devices: all sens present start: 1
D librs   : ds5_info::pick_ds5_devices: all sens present mul: 1
D librs   : ds5_info::pick_ds5_devices: all sens present mul: 1
D librs   : ds5_info::pick_ds5_devices: devices empty: 0
D librs   : ds5_info::pick_ds5_devices: all sens present: 1
D librs   : try_fetch_usb_device(...) failed.
D librs   : context::create_devices: d400 ended
D librs   : context::create_devices: l500 started
D librs   : context::create_devices: l500 ended
D librs   : context::create_devices: sr300 started
D librs   : context::create_devices: sr300 ended
D librs   : context::create_devices: recovery started
D librs   : context::create_devices: recovery ended
D librs   : context::create_devices: nonintel started
D librs   : context::create_devices: ended started
D librs   : context::create_devices: pushing devices...
D librs   : context::create_devices: ended
D librs   : Creating UVC Device from path: /dev/bus/usb/002/002
D librs   : Creating UVC Device from path: /dev/bus/usb/002/002
04-20 13:17:26.125 14490 14653 W librs   :
04-20 13:17:26.138 14490 14653 W librs   :
D librs   : USB pipe 130 reset successfully
D Handy 3D Scanner: get serial
D librs   : USB pipe 132 reset successfully
D librs   : Transfer thread started for endpoint address: 130
D librs   : Transfer thread started for endpoint address: 132
D librs   : Passing packet to user CB with size 1843448
D librs   : FrameAccepted,Depth,Counter,0,Index,0,BackEndTS,0.000000,SystemTime,1555791446445.569092 ,diff_ts[Sys-BE],1555791446445.569092,TS,2720.426000,TS_Domain,Hardware Clock,last_frame_number,0,last_timestamp,0.000000
D librs   : Passing packet to user CB with size 1843448
D librs   : CallbackStarted,Depth,0,DispatchedAt,1555791446489.326904
D librs   : DISPATCH (TS: )--> Depth 0 2720.426000
D librs   : DISPATCH (TS: (FN: I Depth I Infrared I Infrared ) I Color )--> Depth 0 2720.426000
D librs   : DISPATCH (FN: I Depth I Infrared I Infrared )--> Depth 0 2720.426000
D librs   : I Depth--> Depth 0, 2720.426000
D librs   : SYNC (FN: I Depth I Infrared I Infrared )--> Depth 0 2720.426000
D librs   : SYNC (TS: (FN: I Depth I Infrared I Infrared ) I Color )--> Depth 0 2720.426000
D librs   : fps 30 Depth 0 2720.426000
D librs   : (TS: (FN: I Depth I Infrared I Infrared ) I Color )Depth 0 2720.426000 fps 30 gap 33.3333 next_expected: 2753.76
D librs   : CallbackFinished,Depth,0,DispatchedAt,1.55579e+12
D librs   : Frame Callback [Depth#0] overdue. (Duration: 1.55579e+12ms, FPS: 30, Max Duration: 32ms)
D librs   : SYNC (TS: )--> Depth 0 2720.426000
D librs   : fps 30 Depth 0 2720.426000
D librs   : (TS: )Depth 0 2720.426000 fps 30 gap 33.3333 next_expected: 2753.76
D librs   : CallbackFinished,Depth,0,DispatchedAt,1.55579e+12
D librs   : Frame Callback [Depth#0] overdue. (Duration: 1.55579e+12ms, FPS: 30, Max Duration: 32ms)
04-20 13:17:26.493 14490 15380 D librs   :
D librs   : CallbackStarted,Depth,0,DispatchedAt,1555791446493.625977
D librs   : CallbackFinished,Depth,0,DispatchedAt,1.55579e+12
D librs   : FrameAccepted,Depth,Counter,1,Index,0,BackEndTS,0.000000,SystemTime,1555791446493.751953 ,diff_ts[Sys-BE],1555791446493.751953,TS,2753.747000,TS_Domain,Hardware Clock,last_frame_number,0,last_timestamp,2720.426000
D librs   : Passing packet to user CB with size 1843448
D librs   : CallbackStarted,Depth,1,DispatchedAt,1555791446531.968018
D librs   : DISPATCH (TS: )--> Depth 1 2753.747000
D librs   : DISPATCH (TS: (FN: I Depth I Infrared I Infrared ) I Color )--> Depth 1 2753.747000
D librs   : DISPATCH (FN: I Depth I Infrared I Infrared )--> Depth 1 2753.747000
D librs   : I Depth--> Depth 1, 2753.747000
D librs   : SYNC (FN: I Depth I Infrared I Infrared )--> Depth 1 2753.747000
D librs   : SYNC (TS: (FN: I Depth I Infrared I Infrared ) I Color )--> Depth 1 2753.747000
D librs   : fps 30 Depth 1 2753.747000
D librs   : (TS: (FN: I Depth I Infrared I Infrared ) I Color )Depth 1 2753.747000 fps 30 gap 33.3333 next_expected: 2787.08
D librs   : CallbackFinished,Depth,0,DispatchedAt,1.55579e+12
D librs   : Frame Callback [Depth#0] overdue. (Duration: 1.55579e+12ms, FPS: 30, Max Duration: 32ms)
D librs   : SYNC (TS: )--> Depth 1 2753.747000
D librs   : fps 30 Depth 1 2753.747000
D librs   : (TS: )Depth 1 2753.747000 fps 30 gap 33.3333 next_expected: 2787.08
D librs   : CallbackFinished,Depth,0,DispatchedAt,1.55579e+12
D librs   : Frame Callback [Depth#0] overdue. (Duration: 1.55579e+12ms, FPS: 30, Max Duration: 32ms)
04-20 13:17:26.533 14490 15380 D librs   :
state-of-the-art commented 5 years ago

Created ticket in librealsense: IntelRealSense/librealsense#3803

state-of-the-art commented 5 years ago

Fixed locally for now with the same patch.