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.

Sign up for GitHub

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

Jump to bottom

D435 intermittantly fails to appear on lsusb after boot and reboot #1615

Closed
josephduchesne opened this issue Apr 26, 2018 · 48 comments
Closed

D435 intermittantly fails to appear on lsusb after boot and reboot #1615

josephduchesne opened this issue Apr 26, 2018 · 48 comments
Assignees
@RealSense-Customer-Engineering
Labels
bug hardware question

Comments

@josephduchesne
Copy link

josephduchesne commented Apr 26, 2018 •
edited
Loading

Required Info
Camera Model D435
Firmware Version 5.9.9.2
Operating System & Version Linux (Ubuntu 16.04)
Kernel Version (Linux Only) 4.8
Platform Intel NUC 7i3BNH
SDK Version 2.10.3

Issue Description

When trying to use 2x D435 with a 7th gen i3 NUC, I found that sometimes the devices failed to show up after a reboot cycle.

I automated both a reboot test:

  1. reboot on a cron job with logging on a service that launched and monitored the D435 ROS node output
  2. powered the NUC using a relay that cycled 15 seconds off, 5 minutes on (same service+logging)

The service used the ROS pipeline with only depth enabled. One pipeline per camera. The only modificiation to the current release branch is this reset the camera whenever the driver launches: ethz-asl/realsense@148eaf9

I have experienced three issues:

  1. The device fails to show up (1 or 2 devices missing from lsusb) This is the primary issue that I am concerned about.
  2. The ros node can't talk to the camera without a reset after a 'bad' shutdown (resolved by the above patch). This issue can also be manually "fixed" by issuing the reset in the realsense-viewer each time it happens.
  3. The pipeline launches but crashes or otherwise does not emit data shortly after launch. It sometimes emits data for a second or two. (I haven't investigated this one much).

After finding a workable solution for problem 2, I set out to profile problems 1 and 3.

  • Problem 1 can be "resolved" by rebooting or power cycling the machine. This is not desirable.
  • Problem 3 can be handled by adding a watchdog that resets the entire affected pipeline (kills the process tree and relaunches the launchfile). My guess is that this is a problem in either librealsense2 stability or the ros node stability.

I profiled this a lot to try to understand the problem and work around it:

hardware kernel firmware usb config test # issue 1# issue 3# conclusion
NUC7i3BNH 4.8.0.36 5.9.2.0 usb c, usb a 211 29 13 only usb a camera experiences reset issue, maybe usb c port is immune
NUC7i3BNH 4.13.0.58 5.9.2.0 usb c, usb a 104 28 6 kernel 4.8 and 4.13 both experience this problem
NUC7i3BNH 4.8.0.36 5.9.2.0 both usb c, Kensington CH1000 hub 242 0 23 USB c hub can resolve issue 1
NUC7i3BNH 4.8.0.36 5.9.2.0 both usb c, Ankler hub 149 1 64 usb c hub does not always resolve issue
NUC7i3BNH 4.8.0.36 5.9.9.2 both usb c, Oricos hub 1 47 0 some hubs really don't work
AsRock IMB-195 i7-6700TE 4.8.0.36 5.9.9.2 both USB A 1466 733 1737 The D435s are very unreliable with this computer.

In that last case, there is a fairly reliable pattern.

  • 20 reset cycles: Cameras worked on two consecutive boots
  • 1466 reset cycles: Cameras alternated, first working, then on the next reboot did not work
@josephduchesne josephduchesne mentioned this issue Apr 26, 2018
Closed
@tedtman
Copy link

tedtman commented Apr 27, 2018

@josephduchesne thanks for all the details. I have seen issue 1 occur consistently with a 5i7 NUC and not at all on a fairly new 7i7 NUC. After updating the BIOS I have not seen issue 1 occur since. Can you confirm that you have the latest BIOS?
Regards,
Ted Tsuchiya,
Intel RealSense Support

@josephduchesne
Copy link
Author

@tedtman I made note of the current BIOS and also downloaded the newest BIOS. I can confirm that this still occurs. I plugged 2x D435 using firmware 5.9.9.2 into the rear USB A ports. On the second boot, lsusb showed:

Bus 002 Device 001: ID 1d6b:0003 Linux Foundation 3.0 root hub
Bus 001 Device 002: ID 8087:0a2b Intel Corp. 
Bus 001 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub

0/2 devices show up on Bus 002. On the next boot cycle, both appeared.

I received the following errors that seem related in syslog:

Apr 27 10:25:26 cameras kernel: [    2.143302] usb 2-3: device not accepting address 2, error -71
Apr 27 10:25:26 cameras kernel: [    2.715293] usb 2-3: device not accepting address 3, error -71
Apr 27 10:25:26 cameras kernel: [    3.539492] usb 2-3: device not accepting address 4, error -71
Apr 27 10:25:26 cameras kernel: [    4.103459] usb 2-3: device not accepting address 5, error -71
Apr 27 10:25:26 cameras kernel: [    4.695489] usb 2-4: device not accepting address 6, error -71
Apr 27 10:25:26 cameras kernel: [    5.259491] usb 2-4: device not accepting address 7, error -71
Apr 27 10:25:26 cameras kernel: [    5.823487] usb 2-4: device not accepting address 8, error -71
Apr 27 10:25:26 cameras kernel: [    6.387491] usb 2-4: device not accepting address 9, error -71

Firmware in previous tests: BNKBL357.86A.0050.2017.0816.2002
Firmware in this test: BNKBL357.86A.0063.2018.0413.1542

@josephduchesne
Copy link
Author

josephduchesne commented Apr 27, 2018 •
edited
Loading

I left the test running for a while. The computer reboots on a cron (5 min), and after boot if there are no D435s showing up.

2018-04-27 11:07:57 lsusb shows 0 D435, no address error: 8, rebooting
2018-04-27 11:08:33 lsusb shows 2 D435, starting
2018-04-27 11:10:31 lsusb shows 0 D435, no address error: 8, rebooting
2018-04-27 11:11:06 lsusb shows 2 D435, starting
2018-04-27 11:15:31 lsusb shows 0 D435, no address error: 8, rebooting
2018-04-27 11:16:07 lsusb shows 2 D435, starting
2018-04-27 11:20:34 lsusb shows 0 D435, no address error: 8, rebooting
2018-04-27 11:21:09 lsusb shows 2 D435, starting
2018-04-27 11:25:32 lsusb shows 0 D435, no address error: 8, rebooting
2018-04-27 11:26:06 lsusb shows 2 D435, starting
2018-04-27 11:30:30 lsusb shows 0 D435, no address error: 8, rebooting
2018-04-27 11:31:03 lsusb shows 2 D435, starting
2018-04-27 11:35:32 lsusb shows 0 D435, no address error: 8, rebooting
2018-04-27 11:36:08 lsusb shows 2 D435, starting
2018-04-27 11:40:31 lsusb shows 0 D435, no address error: 8, rebooting
2018-04-27 11:41:06 lsusb shows 2 D435, starting
2018-04-27 11:45:31 lsusb shows 0 D435, no address error: 8, rebooting
2018-04-27 11:46:07 lsusb shows 2 D435, starting
2018-04-27 11:50:30 lsusb shows 0 D435, no address error: 8, rebooting
2018-04-27 11:51:06 lsusb shows 2 D435, starting
2018-04-27 11:55:31 lsusb shows 0 D435, no address error: 8, rebooting
2018-04-27 11:56:05 lsusb shows 2 D435, starting
2018-04-27 12:00:32 lsusb shows 0 D435, no address error: 8, rebooting
2018-04-27 12:01:07 lsusb shows 2 D435, starting
2018-04-27 12:05:31 lsusb shows 0 D435, no address error: 8, rebooting
2018-04-27 12:06:05 lsusb shows 2 D435, starting
2018-04-27 12:10:31 lsusb shows 0 D435, no address error: 8, rebooting
2018-04-27 12:11:06 lsusb shows 2 D435, starting
2018-04-27 12:15:31 lsusb shows 0 D435, no address error: 8, rebooting
2018-04-27 12:16:06 lsusb shows 2 D435, starting
2018-04-27 12:20:31 lsusb shows 0 D435, no address error: 8, rebooting
2018-04-27 12:21:06 lsusb shows 2 D435, starting
2018-04-27 12:25:31 lsusb shows 0 D435, no address error: 8, rebooting
2018-04-27 12:26:08 lsusb shows 2 D435, starting
2018-04-27 12:30:31 lsusb shows 0 D435, no address error: 8, rebooting
2018-04-27 12:31:07 lsusb shows 2 D435, starting
2018-04-27 12:35:34 lsusb shows 0 D435, no address error: 8, rebooting
2018-04-27 12:36:10 lsusb shows 2 D435, starting
2018-04-27 12:40:31 lsusb shows 0 D435, no address error: 8, rebooting
2018-04-27 12:41:07 lsusb shows 2 D435, starting
2018-04-27 12:45:32 lsusb shows 0 D435, no address error: 8, rebooting
2018-04-27 12:46:08 lsusb shows 2 D435, starting
2018-04-27 12:50:32 lsusb shows 0 D435, no address error: 8, rebooting
2018-04-27 12:51:07 lsusb shows 2 D435, starting
2018-04-27 12:55:31 lsusb shows 0 D435, no address error: 8, rebooting
2018-04-27 12:56:06 lsusb shows 2 D435, starting
2018-04-27 13:00:32 lsusb shows 0 D435, no address error: 8, rebooting
2018-04-27 13:01:07 lsusb shows 2 D435, starting
2018-04-27 13:05:32 lsusb shows 0 D435, no address error: 8, rebooting
2018-04-27 13:06:06 lsusb shows 2 D435, starting
2018-04-27 13:10:33 lsusb shows 0 D435, no address error: 8, rebooting
2018-04-27 13:11:07 lsusb shows 2 D435, starting
2018-04-27 13:15:31 lsusb shows 0 D435, no address error: 8, rebooting
2018-04-27 13:16:04 lsusb shows 2 D435, starting

This seems suspiciously regular.

@josephduchesne
Copy link
Author

Leaving this running all weekend, it got less regular:

2018-04-30 08:50:32 lsusb shows 0 D435, no address error: 8, rebooting
2018-04-30 08:51:08 lsusb shows 2 D435, starting
2018-04-30 08:55:27 lsusb shows 2 D435, starting
2018-04-30 09:00:27 lsusb shows 2 D435, starting
2018-04-30 09:05:28 lsusb shows 2 D435, starting
2018-04-30 09:10:32 lsusb shows 0 D435, no address error: 8, rebooting
2018-04-30 09:11:08 lsusb shows 2 D435, starting
2018-04-30 09:15:32 lsusb shows 0 D435, no address error: 8, rebooting
2018-04-30 09:16:07 lsusb shows 2 D435, starting
2018-04-30 09:20:33 lsusb shows 0 D435, no address error: 8, rebooting
2018-04-30 09:21:09 lsusb shows 2 D435, starting
2018-04-30 09:25:28 lsusb shows 2 D435, starting
2018-04-30 09:30:27 lsusb shows 2 D435, starting
2018-04-30 09:35:28 lsusb shows 2 D435, starting
2018-04-30 09:40:33 lsusb shows 0 D435, no address error: 8, rebooting
2018-04-30 09:41:08 lsusb shows 2 D435, starting
2018-04-30 09:45:31 lsusb shows 0 D435, no address error: 8, rebooting
2018-04-30 09:46:08 lsusb shows 2 D435, starting
2018-04-30 09:50:33 lsusb shows 0 D435, no address error: 8, rebooting
2018-04-30 09:51:09 lsusb shows 2 D435, starting
2018-04-30 09:55:32 lsusb shows 0 D435, no address error: 8, rebooting
2018-04-30 09:56:07 lsusb shows 2 D435, starting
2018-04-30 10:00:32 lsusb shows 0 D435, no address error: 8, rebooting
2018-04-30 10:01:17 lsusb shows 2 D435, starting
2018-04-30 10:05:28 lsusb shows 2 D435, starting
2018-04-30 10:10:27 lsusb shows 2 D435, starting
2018-04-30 10:15:28 lsusb shows 2 D435, starting
2018-04-30 10:20:32 lsusb shows 0 D435, no address error: 8, rebooting
2018-04-30 10:21:07 lsusb shows 2 D435, starting
2018-04-30 10:25:27 lsusb shows 2 D435, starting
2018-04-30 10:30:27 lsusb shows 2 D435, starting
2018-04-30 10:35:33 lsusb shows 0 D435, no address error: 8, rebooting
2018-04-30 10:36:08 lsusb shows 2 D435, starting
2018-04-30 10:40:32 lsusb shows 0 D435, no address error: 8, rebooting
2018-04-30 10:41:07 lsusb shows 2 D435, starting
2018-04-30 10:45:35 lsusb shows 0 D435, no address error: 8, rebooting
2018-04-30 10:46:10 lsusb shows 2 D435, starting
2018-04-30 10:50:32 lsusb shows 0 D435, no address error: 8, rebooting
2018-04-30 10:51:07 lsusb shows 2 D435, starting

@tedtman
Copy link

tedtman commented Apr 30, 2018

Sorry @josephduchesne but can you confirm my understanding of your test?

  1. start camera and stream depth
  2. warm reboot?
  3. repeat
  4. every five minutes remove power from the NUC and restart after 15 seconds
    Thanks,
    Ted.

@josephduchesne
Copy link
Author

josephduchesne commented Apr 30, 2018 •
edited
Loading

In this particular case it's the following loop:

  • warm reboot
    • if lsusb shows both cameras
      • log "lsusb shows 2 D435, starting"
      • start camera and stream depth for 5 minutes
    • if lsusb shows 0 or 1 cameras
      • log "lsusb shows N $D435_COUNT, no address error: $NO_ADDRESS, rebooting"

I also tested an alternate configuration where every 5 minutes there was a 15 second power off cycle but the results looked similar.

The two variables D435_COUNT and NO_ADDRESS are:

D435_COUNT=$(lsusb | grep '8086:0b07' | wc -l)

NO_ADDRESS=$(journalctl -b | grep 'device not accepting address' | wc -l)

@tedtman
Copy link

tedtman commented Apr 30, 2018 •
edited
Loading

Are the cameras streaming when reboot is initiated? Is "power off cycle" a physical power off or shutdown?

@josephduchesne
Copy link
Author

They cameras may be streaming when the reboot is initiated.

Reboot is 'sudo reboot' in this case.

The cameras are running under a systemd service, but I'm not sure how the ros nodelet manager handles the signal to stop when the shutdown happens.

It is possible it's not being shut down 'properly', but since our use case involves a machine with a physical key that could turn power off without warning, this is a case that we will have to handle as gracefully as possible.

@tedtman
Copy link

tedtman commented Apr 30, 2018

Thanks, your case is understood and I just want to help provide the specifics for debugging.

If lsusb is successful, does your test know if the cameras are actually streaming? (The DSO you noted fixed 5.8.15 that succeeded with lsusb but failed to be seen by the driver on cold boot; validation for this was also performed on slightly different h/w, type-B USB boards)

@josephduchesne
Copy link
Author

josephduchesne commented Apr 30, 2018 •
edited
Loading

If lsusb is successful, I have a wrapper around the roslaunch which watches the ROS output topic, and resets the entire pipeline (roslaunch file and all nodes) if there has been no output for 10 seconds. This also logs failures. By calling reset on the cameras on initialisation (using this modification to the ROS nodelet), the camera will come up with a small number of attempts (0-3, typically 0).

This process is also logged in my logfile.

An example section of this logfile:

2018-04-30 15:55:32 lsusb shows 0 D435, no address error: 8, rebooting
2018-04-30 15:56:08 lsusb shows 2 D435, starting
2018-04-30 15:56:09 START /left_launch_monitor watching /camera_left/depth/points
2018-04-30 15:56:09 /left_launch_monitor launched /opt/ros/kinetic/bin/roslaunch /opt/ros/kinetic/share/avidbots_camera_launch/launch/single_d435.launch ns:=camera_left tf_prefix:=rs_left_ PID 1266
2018-04-30 15:56:09 START /right_launch_monitor watching /camera_right/depth/points
2018-04-30 15:56:09 /right_launch_monitor launched /opt/ros/kinetic/bin/roslaunch /opt/ros/kinetic/share/avidbots_camera_launch/launch/single_d435.launch ns:=camera_right tf_prefix:=rs_right_ PID 1267
2018-04-30 15:56:19 RESET /left_launch_monitor no message on /camera_left/depth/points in 10.02 seconds
2018-04-30 15:56:20 /left_launch_monitor launched /opt/ros/kinetic/bin/roslaunch /opt/ros/kinetic/share/avidbots_camera_launch/launch/single_d435.launch ns:=camera_left tf_prefix:=rs_left_ PID 1461
2018-04-30 15:56:27 RESET /right_launch_monitor no message on /camera_right/depth/points in 10.05 seconds
2018-04-30 15:56:27 /right_launch_monitor launched /opt/ros/kinetic/bin/roslaunch /opt/ros/kinetic/share/avidbots_camera_launch/launch/single_d435.launch ns:=camera_right tf_prefix:=rs_right_ PID 1537
2018-04-30 15:56:30 RESET /left_launch_monitor no message on /camera_left/depth/points in 10.00 seconds
2018-04-30 15:56:45 /left_launch_monitor launched /opt/ros/kinetic/bin/roslaunch /opt/ros/kinetic/share/avidbots_camera_launch/launch/single_d435.launch ns:=camera_left tf_prefix:=rs_left_ PID 1657
2018-04-30 15:57:02 RESET /left_launch_monitor no message on /camera_left/depth/points in 10.07 seconds
2018-04-30 15:57:03 /left_launch_monitor launched /opt/ros/kinetic/bin/roslaunch /opt/ros/kinetic/share/avidbots_camera_launch/launch/single_d435.launch ns:=camera_left tf_prefix:=rs_left_ PID 1792
2018-04-30 16:00:31 lsusb shows 0 D435, no address error: 8, rebooting
2018-04-30 16:01:08 lsusb shows 2 D435, starting

The sequence of events in plain english:

  • 0:32: Computer boots, but finds 0 cameras, so it reboots (Issue 1)
  • 1:08: Computer boots, finds 2 cameras and starts left/right camera managers
  • 1:19: Left camera times out, resets (Issue 2 or 3)
  • 1:27: Right camera times out, resets (after working at least partially for ~8 seconds before failing) (Issue 3)
  • 1:30: Left camera times out again (immediately after restarting, never works) (Issue 2 or 3)
  • 2:02: Left camera times out a third time (after working for ~22 seconds) (Issue 3)
  • Both cameras then happily work until 5:00 when the computer reboots on its cronjob
  • 5:31: Computer boots, but finds 0 cameras, so it reboots (Issue 1)
  • 6:08: Computer boots, finds 2 cameras and starts left/right camera managers... the cycle repeats

@josephduchesne
Copy link
Author

josephduchesne commented Apr 30, 2018 •
edited
Loading

The clarify, the launch monitor process exists to work around DSO-8665 in conjunction with the ROS node modification that resets the camera on node start.

Also, yes the fact that the launch monitor did not reset a camera after 10 seconds indicates that the camera is streaming depth data.

I have independently validated this using rostopic / rviz several times.

@RealSense-Customer-Engineering
Copy link
Collaborator

[Realsense Customer Engineering Team Comment]
@josephduchesne, can you change the BIOS setting for devices/USB to uncheck USB legacy and set xHCI mode to "Enabled" and see if this makes a difference?

@josephduchesne
Copy link
Author

The earlier tests were with USB legacy enabled, but after updating the firmware I tested first with it enabled, then with it disabled (latest tests). I didn't see a difference.

I'll check if xHCI is configured tomorrow and test whichever mode is opposite the current setting.

@josephduchesne
Copy link
Author

I can't find xHCI configuration options on the NUC7i3BNH

@tedtman
Copy link

tedtman commented May 1, 2018

Sorry, I forgot that you have a 7th gen NUC; xHCI has no optional settings. I have been working with a 4th gen i3 that has an auto / enabled mode option for xHCI.

When lsusb fails, what do you see on dmesg before reboot?

@josephduchesne
Copy link
Author

josephduchesne commented May 1, 2018 •
edited
Loading

For completeness I've attached the entire dmesg file, but the relevant section appears to be:

[    3.113989] usb 1-2: new low-speed USB device number 3 using xhci_hcd
[    3.260348] usb 1-2: New USB device found, idVendor=045e, idProduct=076c
[    3.260350] usb 1-2: New USB device strings: Mfr=1, Product=2, SerialNumber=0
[    3.260351] usb 1-2: Product: Microsoft® Comfort Mouse 4500
[    3.260352] usb 1-2: Manufacturer: Microsoft
[    3.273944] fbcon: inteldrmfb (fb0) is primary device
[    3.369764] Console: switching to colour frame buffer device 160x50
[    3.377679] usb 2-3: Device not responding to setup address.
[    3.388299] i915 0000:00:02.0: fb0: inteldrmfb frame buffer device
[    3.585676] usb 2-3: Device not responding to setup address.
[    3.790016] usb 2-3: device not accepting address 4, error -71
[    3.842309] [drm] RC6 on
[    3.937865] usb 1-8: new full-speed USB device number 4 using xhci_hcd
[    4.079871] usb 1-8: New USB device found, idVendor=8087, idProduct=0a2b
[    4.079873] usb 1-8: New USB device strings: Mfr=0, Product=0, SerialNumber=0
[    4.097433] usbcore: registered new interface driver usbhid
[    4.097434] usbhid: USB HID core driver
[    4.099091] input: Microsoft Microsoft® Comfort Mouse 4500 as /devices/pci0000:00/0000:00:14.0/usb1/1-2/1-2:1.0/0003:045E:076C.0003/input/input4
[    4.099304] input: Microsoft Wired Keyboard 600 as /devices/pci0000:00/0000:00:14.0/usb1/1-1/1-1:1.0/0003:045E:07F8.0001/input/input5
[    4.158355] microsoft 0003:045E:076C.0003: input,hidraw0: USB HID v1.11 Mouse [Microsoft Microsoft® Comfort Mouse 4500] on usb-0000:00:14.0-2/input0
[    4.201706] usb 2-3: Device not responding to setup address.
[    4.218110] hid-generic 0003:045E:07F8.0001: input,hidraw1: USB HID v1.11 Keyboard [Microsoft Wired Keyboard 600] on usb-0000:00:14.0-1/input0
[    4.219136] input: Microsoft Wired Keyboard 600 as /devices/pci0000:00/0000:00:14.0/usb1/1-1/1-1:1.1/0003:045E:07F8.0002/input/input6
[    4.278113] hid-generic 0003:045E:07F8.0002: input,hidraw2: USB HID v1.11 Device [Microsoft Wired Keyboard 600] on usb-0000:00:14.0-1/input1
[    4.409679] usb 2-3: Device not responding to setup address.
[    4.614008] usb 2-3: device not accepting address 5, error -71
[    4.642035] usb usb2-port3: unable to enumerate USB device
[    4.793679] usb 2-4: Device not responding to setup address.
[    5.001684] usb 2-4: Device not responding to setup address.
[    5.205982] usb 2-4: device not accepting address 6, error -71
[    5.357685] usb 2-4: Device not responding to setup address.
[    5.565707] usb 2-4: Device not responding to setup address.
[    5.770013] usb 2-4: device not accepting address 7, error -71
[    5.921678] usb 2-4: Device not responding to setup address.
[    6.129677] usb 2-4: Device not responding to setup address.
[    6.334007] usb 2-4: device not accepting address 8, error -71
[    6.485683] usb 2-4: Device not responding to setup address.
[    6.693686] usb 2-4: Device not responding to setup address.
[    6.898008] usb 2-4: device not accepting address 9, error -71

The Bus enumeration on the NUC7i3 is:

  • 1: Front+Back USB 2.0 host controller
  • 2: Front+Back USB 3.0 host controller
  • 3: USB C port 2.0 host controller
  • 4: USB C port 3.0 host controller

It appears that bluetooth is provided on this machine via the USB 2.0 host controller on Bus 1 as an internal USB device.

(The keyboard+mouse were not present during the tests but were plugged in for BIOS configuration)

lsusb
Bus 002 Device 001: ID 1d6b:0003 Linux Foundation 3.0 root hub
Bus 001 Device 004: ID 8087:0a2b Intel Corp. 
Bus 001 Device 003: ID 045e:076c Microsoft Corp. Comfort Mouse 4500
Bus 001 Device 002: ID 045e:07f8 Microsoft Corp. Wired Keyboard 600 (model 1576)
Bus 001 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub

d435_dmesg_errors.txt

@josephduchesne
Copy link
Author

An additional piece of debugging information:

I tried a Rosewill RC-509 PCI-E (PCI Express) to USB 3.1 (Type A +Type C) Expansion Card in the AsRock IMB-195 i7-6700TE platform listed above in the table I provided.

It does not experience issue 1. The devices always initialise correctly.

@ev-mp ev-mp mentioned this issue Jun 11, 2018
Closed
@RealSense-Customer-Engineering
Copy link
Collaborator

[Realsense Customer Engineering Team Comment]
hi @josephduchesne,

sorry for late, i am another engineer now take care this ticket, i got 2 D435 and gen7 Nuc for this issue now, but would like to confirm if latest FW5.9.13 still have same issue?
and from your last comment, using different HW seems no issue 1 now, but other issue still happen on your AsRock platform?
thanks.

@RealSense-Customer-Engineering
Copy link
Collaborator

[Realsense Customer Engineering Team Comment]
per my test for 10 reboot with latest FW v5.9.13,connect both D435 to USB port in the back, seems so far so good.

@RealSense-Customer-Engineering
Copy link
Collaborator

[Realsense Customer Engineering Team Comment]
hi @josephduchesne
would like to know if you last test is with latest FW5.9.13?
and if the new FW still fail on your Nuc?
thanks.

@RealSense-Customer-Engineering
Copy link
Collaborator

[Realsense Customer Engineering Team Comment]
hi @josephduchesne,

do you still have this issue?

@josephduchesne
Copy link
Author

I just re-ran the test on firmware 5.9.14. I set it running on Saturday with the same parameters and initially things seemed to have improved (one camera failed to show up on lsusb 8 times in 276 cycles), but then after roughly 13 hours one of the cameras stopped showing up entirely, and the system rebooted every 30sec for over a day straight without any success.

After reinstalling the hub, the issue stopped occuring again.

@RealSense-Customer-Engineering
Copy link
Collaborator

[Realsense Customer Engineering Team Comment]
hi @josephduchesne,

do you mean after reinstall the hub and it works good always?
due to our test show this issue may be related to hub power, so would like to confirm if you are the same there.
thanks.

@josephduchesne
Copy link
Author

The hub we're using is an unpowered USB hub, using USB-C to connect to the NUC and sporting USB-A ports.

With the hub (5.9.14): Two D435s started first time 128 times, required 1+ software resets 182 times

Without the hub (5.9.14): Two D435s started first time 138 times, required 1+ software resets 240 times, and one of them failed to show up as a device at boot (not visible on lsusb) 8 times in the first 13 hours. After that one device failed to show up on 3207 consecutive reboot cycles (over the weekend), but after upon unplugging and replugging the device begain to function again.

@josephduchesne
Copy link
Author

The bios version that is experiencing the issue: BNKBL357.86A.0050
Attempting overnight test using: BNKBL357.86A.0067

@RealSense-Customer-Engineering
Copy link
Collaborator

[Realsense Customer Engineering Team Comment]
hi @josephduchesne,

thanks, please let me know how it works.

@josephduchesne
Copy link
Author

@RealSense-Customer-Engineering 467 reboot cycles in, no instances of the issue. It seems that the 0067 NUC bios + 5.9.14 firmware works well.

@josephduchesne
Copy link
Author

josephduchesne commented Aug 27, 2018 •
edited
Loading

I left the test running longer and had another failure. This was on the NUC with the latest firmware, and a recent version of librealsense:

Relevant Kernel+Syslogs of failure:

Aug 25 15:25:30 camerarig3 kernel: [    4.305746] Linux video capture interface: v2.00
Aug 25 15:25:30 camerarig3 kernel: [    4.334051] uvcvideo: loading out-of-tree module taints kernel.
Aug 25 15:25:30 camerarig3 kernel: [    4.334116] uvcvideo: module verification failed: signature and/or required key missing - tainting kernel
Aug 25 15:25:30 camerarig3 kernel: [    4.334864] uvcvideo: Found UVC 1.50 device Intel(R) RealSense(TM) 435 (8086:0b07)
Aug 25 15:25:30 camerarig3 kernel: [    4.342840] uvcvideo: Unable to create debugfs 2-2 directory.
Aug 25 15:25:30 camerarig3 kernel: [    4.342895] uvcvideo 2-1:1.0: Entity type for entity Intel(R) RealSense(TM) 435 with was not initialized!
Aug 25 15:25:30 camerarig3 kernel: [    4.342897] uvcvideo 2-1:1.0: Entity type for entity Processing 2 was not initialized!
Aug 25 15:25:30 camerarig3 kernel: [    4.342899] uvcvideo 2-1:1.0: Entity type for entity Intel(R) RealSense(TM) 435 with was not initialized!
Aug 25 15:25:30 camerarig3 kernel: [    4.342900] uvcvideo 2-1:1.0: Entity type for entity Camera 1 was not initialized!
Aug 25 15:25:30 camerarig3 kernel: [    4.342978] input: Intel(R) RealSense(TM) 435 as /devices/pci0000:00/0000:00:14.0/usb2/2-1/2-1:1.0/input/input5
Aug 25 15:25:30 camerarig3 kernel: [    4.343037] uvcvideo: Found UVC 1.50 device Intel(R) RealSense(TM) 435 (8086:0b07)
Aug 25 15:25:30 camerarig3 kernel: [    4.343398] Intel(R) Wireless WiFi driver for Linux
Aug 25 15:25:30 camerarig3 kernel: [    4.343399] Copyright(c) 2003- 2015 Intel Corporation
Aug 25 15:25:30 camerarig3 kernel: [    4.344909] uvcvideo: Unable to create debugfs 2-2 directory.
Aug 25 15:25:30 camerarig3 kernel: [    4.344954] uvcvideo 2-1:1.3: Entity type for entity Processing 7 was not initialized!
Aug 25 15:25:30 camerarig3 kernel: [    4.344957] uvcvideo 2-1:1.3: Entity type for entity Extension 8 was not initialized!
Aug 25 15:25:30 camerarig3 kernel: [    4.344958] uvcvideo 2-1:1.3: Entity type for entity Camera 6 was not initialized!
Aug 25 15:25:30 camerarig3 kernel: [    4.345131] uvcvideo: Found UVC 1.50 device Intel(R) RealSense(TM) 435 (8086:0b07)
Aug 25 15:25:30 camerarig3 kernel: [    4.347199] iwlwifi 0000:3a:00.0: Direct firmware load for iwlwifi-8265-24.ucode failed with error -2
Aug 25 15:25:30 camerarig3 kernel: [    4.347215] iwlwifi 0000:3a:00.0: Direct firmware load for iwlwifi-8265-23.ucode failed with error -2
Aug 25 15:25:30 camerarig3 kernel: [    4.347490] uvcvideo: Unable to create debugfs 2-3 directory.
Aug 25 15:25:30 camerarig3 kernel: [    4.347780] uvcvideo 2-4:1.0: Entity type for entity Intel(R) RealSense(TM) 435 with was not initialized!
Aug 25 15:25:30 camerarig3 kernel: [    4.347782] uvcvideo 2-4:1.0: Entity type for entity Processing 2 was not initialized!
Aug 25 15:25:30 camerarig3 kernel: [    4.347784] uvcvideo 2-4:1.0: Entity type for entity Intel(R) RealSense(TM) 435 with was not initialized!
Aug 25 15:25:30 camerarig3 kernel: [    4.347786] uvcvideo 2-4:1.0: Entity type for entity Camera 1 was not initialized!
Aug 25 15:25:30 camerarig3 kernel: [    4.347863] input: Intel(R) RealSense(TM) 435 as /devices/pci0000:00/0000:00:14.0/usb2/2-4/2-4:1.0/input/input6
Aug 25 15:25:30 camerarig3 kernel: [    4.347924] uvcvideo: Found UVC 1.50 device Intel(R) RealSense(TM) 435 (8086:0b07)
Aug 25 15:25:30 camerarig3 kernel: [    4.349803] uvcvideo: Unable to create debugfs 2-3 directory.
Aug 25 15:25:30 camerarig3 kernel: [    4.350004] uvcvideo 2-4:1.3: Entity type for entity Processing 7 was not initialized!
Aug 25 15:25:30 camerarig3 kernel: [    4.350006] uvcvideo 2-4:1.3: Entity type for entity Extension 8 was not initialized!
Aug 25 15:25:30 camerarig3 kernel: [    4.350008] uvcvideo 2-4:1.3: Entity type for entity Camera 6 was not initialized!
Aug 25 15:25:30 camerarig3 kernel: [    4.350085] usbcore: registered new interface driver uvcvideo

... snip ...

Aug 25 15:25:40 camerarig3 kernel: [   15.251552] usb 2-1: USB disconnect, device number 2
Aug 25 15:25:41 camerarig3 kernel: [   15.515606] usb 2-1: new SuperSpeed USB device number 4 using xhci_hcd
Aug 25 15:25:41 camerarig3 kernel: [   15.536109] usb 2-1: New USB device found, idVendor=8086, idProduct=0b07
Aug 25 15:25:41 camerarig3 kernel: [   15.536112] usb 2-1: New USB device strings: Mfr=1, Product=2, SerialNumber=3
Aug 25 15:25:41 camerarig3 kernel: [   15.536114] usb 2-1: Product: Intel(R) RealSense(TM) 435
Aug 25 15:25:41 camerarig3 kernel: [   15.536115] usb 2-1: Manufacturer: Intel(R) RealSense(TM) 435
Aug 25 15:25:41 camerarig3 kernel: [   15.536116] usb 2-1: SerialNumber: 815213020930
Aug 25 15:25:41 camerarig3 kernel: [   15.538590] uvcvideo: Found UVC 1.50 device Intel(R) RealSense(TM) 435 (8086:0b07)
Aug 25 15:25:41 camerarig3 kernel: [   15.540954] uvcvideo: Unable to create debugfs 2-4 directory.
Aug 25 15:25:41 camerarig3 kernel: [   15.541019] uvcvideo 2-1:1.0: Entity type for entity Intel(R) RealSense(TM) 435 with was not initialized!
Aug 25 15:25:41 camerarig3 kernel: [   15.541021] uvcvideo 2-1:1.0: Entity type for entity Processing 2 was not initialized!
Aug 25 15:25:41 camerarig3 kernel: [   15.541023] uvcvideo 2-1:1.0: Entity type for entity Intel(R) RealSense(TM) 435 with was not initialized!
Aug 25 15:25:41 camerarig3 kernel: [   15.541024] uvcvideo 2-1:1.0: Entity type for entity Camera 1 was not initialized!
Aug 25 15:25:41 camerarig3 kernel: [   15.541106] input: Intel(R) RealSense(TM) 435 as /devices/pci0000:00/0000:00:14.0/usb2/2-1/2-1:1.0/input/input11
Aug 25 15:25:41 camerarig3 kernel: [   15.541573] uvcvideo: Found UVC 1.50 device Intel(R) RealSense(TM) 435 (8086:0b07)
Aug 25 15:25:41 camerarig3 kernel: [   15.542337] uvcvideo: Unable to create debugfs 2-4 directory.
Aug 25 15:25:41 camerarig3 kernel: [   15.542389] uvcvideo 2-1:1.3: Entity type for entity Processing 7 was not initialized!
Aug 25 15:25:41 camerarig3 kernel: [   15.542394] uvcvideo 2-1:1.3: Entity type for entity Extension 8 was not initialized!
Aug 25 15:25:41 camerarig3 kernel: [   15.542396] uvcvideo 2-1:1.3: Entity type for entity Camera 6 was not initialized!
Aug 25 15:25:44 camerarig3 kernel: [   18.927494] usb 2-4: USB disconnect, device number 3
Aug 25 15:25:44 camerarig3 kernel: [   19.199528] usb 2-4: new SuperSpeed USB device number 5 using xhci_hcd
Aug 25 15:25:44 camerarig3 kernel: [   19.223969] usb 2-4: New USB device found, idVendor=8086, idProduct=0b07
Aug 25 15:25:44 camerarig3 kernel: [   19.223971] usb 2-4: New USB device strings: Mfr=1, Product=2, SerialNumber=3
Aug 25 15:25:44 camerarig3 kernel: [   19.223973] usb 2-4: Product: Intel(R) RealSense(TM) 435
Aug 25 15:25:44 camerarig3 kernel: [   19.223974] usb 2-4: Manufacturer: Intel(R) RealSense(TM) 435
Aug 25 15:25:44 camerarig3 kernel: [   19.223975] usb 2-4: SerialNumber: 816513021577
Aug 25 15:25:44 camerarig3 kernel: [   19.225182] uvcvideo: Found UVC 1.50 device Intel(R) RealSense(TM) 435 (8086:0b07)
Aug 25 15:25:44 camerarig3 kernel: [   19.226755] uvcvideo: Unable to create debugfs 2-5 directory.
Aug 25 15:25:44 camerarig3 kernel: [   19.226809] uvcvideo 2-4:1.0: Entity type for entity Intel(R) RealSense(TM) 435 with was not initialized!
Aug 25 15:25:44 camerarig3 kernel: [   19.226811] uvcvideo 2-4:1.0: Entity type for entity Processing 2 was not initialized!
Aug 25 15:25:44 camerarig3 kernel: [   19.226813] uvcvideo 2-4:1.0: Entity type for entity Intel(R) RealSense(TM) 435 with was not initialized!
Aug 25 15:25:44 camerarig3 kernel: [   19.226815] uvcvideo 2-4:1.0: Entity type for entity Camera 1 was not initialized!
Aug 25 15:25:44 camerarig3 kernel: [   19.226900] input: Intel(R) RealSense(TM) 435 as /devices/pci0000:00/0000:00:14.0/usb2/2-4/2-4:1.0/input/input12
Aug 25 15:25:44 camerarig3 kernel: [   19.227294] uvcvideo: Found UVC 1.50 device Intel(R) RealSense(TM) 435 (8086:0b07)
Aug 25 15:25:44 camerarig3 kernel: [   19.228278] uvcvideo: Unable to create debugfs 2-5 directory.
Aug 25 15:25:44 camerarig3 kernel: [   19.228347] uvcvideo 2-4:1.3: Entity type for entity Processing 7 was not initialized!
Aug 25 15:25:44 camerarig3 kernel: [   19.228350] uvcvideo 2-4:1.3: Entity type for entity Extension 8 was not initialized!
Aug 25 15:25:44 camerarig3 kernel: [   19.228352] uvcvideo 2-4:1.3: Entity type for entity Camera 6 was not initialized!




Aug 25 15:25:49 camerarig3 kernel: [   23.816785] uvcvideo: Failed to query (SET_CUR) UVC control 3 on unit 3: -32 (exp. 4).
Aug 25 15:25:49 camerarig3 kernel: [   23.867097] uvcvideo: Failed to query (SET_CUR) UVC control 3 on unit 3: -32 (exp. 4).
Aug 25 15:25:49 camerarig3 kernel: [   23.917330] uvcvideo: Failed to query (SET_CUR) UVC control 3 on unit 3: -32 (exp. 4).
Aug 25 15:25:49 camerarig3 kernel: [   23.967502] uvcvideo: Failed to query (SET_CUR) UVC control 3 on unit 3: -32 (exp. 4).
Aug 25 15:25:49 camerarig3 kernel: [   24.017656] uvcvideo: Failed to query (SET_CUR) UVC control 3 on unit 3: -32 (exp. 4).
Aug 25 15:25:49 camerarig3 kernel: [   24.067823] uvcvideo: Failed to query (SET_CUR) UVC control 3 on unit 3: -32 (exp. 4).
Aug 25 15:25:49 camerarig3 kernel: [   24.117925] uvcvideo: Failed to query (SET_CUR) UVC control 3 on unit 3: -32 (exp. 4).
Aug 25 15:25:49 camerarig3 kernel: [   24.168054] uvcvideo: Failed to query (SET_CUR) UVC control 3 on unit 3: -32 (exp. 4).
Aug 25 15:25:49 camerarig3 kernel: [   24.218189] uvcvideo: Failed to query (SET_CUR) UVC control 3 on unit 3: -32 (exp. 4).
Aug 25 15:25:49 camerarig3 kernel: [   24.268385] uvcvideo: Failed to query (SET_CUR) UVC control 3 on unit 3: -32 (exp. 4).

.. snip ...

Aug 25 15:25:53 camerarig3 avidbots_start.sh[1578]: #033[1m[camera_#033[33m[ WARN] [1535225149.025653130]: Frame metadata isn't available! (frame_timestamp_domain = RS2_TIMESTAMP_DOMAIN_SYSTEM_TIME)#033[0m
Aug 25 15:25:53 camerarig3 avidbots_start.sh[1578]: #033[33m[ WARN] [1535225149.340844366]: Connect#033[0m

Aug 25 15:25:53 camerarig3 avidbots_start.sh[1578]:  25/08 15:25:53,731 WARNING [140074318558976] (backend-v4l2.cpp:825) Frames didn't arrived within 5 seconds
Aug 25 15:25:53 camerarig3 avidbots_start.sh[1578]:  25/08 15:25:53,737 WARNING [140074306455296] (backend-v4l2.cpp:825) Frames didn't arrived within 5 seconds
Aug 25 15:25:58 camerarig3 avidbots_start.sh[1578]:  25/08 15:25:58,735 WARNING [140074318558976] (backend-v4l2.cpp:825) Frames didn't arrived within 5 seconds
Aug 25 15:25:58 camerarig3 avidbots_start.sh[1578]:  25/08 15:25:58,741 WARNING [140074306455296] (backend-v4l2.cpp:825) Frames didn't arrived within 5 seconds

one attempt to kill+relaunch ROS driver

Aug 25 15:26:14 camerarig3 kernel: [   48.975018] xhci_hcd 0000:00:14.0: Timeout while waiting for setup device command
Aug 25 15:26:19 camerarig3 kernel: [   54.353412] xhci_hcd 0000:00:14.0: Timeout while waiting for setup device command
Aug 25 15:26:20 camerarig3 kernel: [   54.562957] usb 2-4: device not accepting address 5, error -62
Aug 25 15:26:20 camerarig3 kernel: [   54.774475] usb 2-4: Device not responding to setup address.
Aug 25 15:26:20 camerarig3 kernel: [   54.982478] usb 2-4: Device not responding to setup address.
Aug 25 15:26:20 camerarig3 kernel: [   55.186921] usb 2-4: device not accepting address 5, error -71
Aug 25 15:26:20 camerarig3 kernel: [   55.406531] usb 2-4: Device not responding to setup address.
Aug 25 15:26:21 camerarig3 kernel: [   55.614191] usb 2-4: Device not responding to setup address.
Aug 25 15:26:21 camerarig3 kernel: [   55.818920] usb 2-4: device not accepting address 5, error -71
Aug 25 15:26:21 camerarig3 kernel: [   56.038190] usb 2-4: Device not responding to setup address.
Aug 25 15:26:21 camerarig3 kernel: [   56.246189] usb 2-4: Device not responding to setup address.
Aug 25 15:26:22 camerarig3 kernel: [   56.454970] usb 2-4: device not accepting address 5, error -71
Aug 25 15:26:22 camerarig3 kernel: [   56.542999] usb 2-4: USB disconnect, device number 5
Aug 25 15:26:22 camerarig3 kernel: [   56.778445] usb 2-4: Device not responding to setup address.

After restarting the computer (and the device fails to show up on lsusb):


Aug 27 08:59:45 camerarig3 kernel: [  866.389862] usb 2-4: Device not responding to setup address.
Aug 27 08:59:45 camerarig3 kernel: [  866.597994] usb 2-4: Device not responding to setup address.
Aug 27 08:59:46 camerarig3 kernel: [  866.802450] usb 2-4: device not accepting address 7, error -71
Aug 27 08:59:46 camerarig3 kernel: [  867.013982] usb 2-4: Device not responding to setup address.
Aug 27 08:59:46 camerarig3 kernel: [  867.222581] usb 2-4: Device not responding to setup address.
Aug 27 08:59:46 camerarig3 kernel: [  867.430392] usb 2-4: device not accepting address 8, error -71
Aug 27 08:59:46 camerarig3 kernel: [  867.641842] usb 2-4: Device not responding to setup address.
Aug 27 08:59:47 camerarig3 kernel: [  867.853528] usb 2-4: Device not responding to setup address.
Aug 27 08:59:47 camerarig3 kernel: [  868.058221] usb 2-4: device not accepting address 9, error -71
Aug 27 08:59:47 camerarig3 kernel: [  868.269707] usb 2-4: Device not responding to setup address.
Aug 27 08:59:47 camerarig3 kernel: [  868.477595] usb 2-4: Device not responding to setup address.
Aug 27 08:59:47 camerarig3 kernel: [  868.682251] usb 2-4: device not accepting address 10, error -71
Aug 27 08:59:48 camerarig3 kernel: [  868.710461] usb usb2-port4: unable to enumerate USB device

This seems reminiscent of #2311, however the cables used are the supplied intel ones and although our eventual target is a mobile robot this test bench is completely static, and the test had been ongoing successfully for over 24h at this point (restarting every 5 minutes and then gathering camera data from two cameras started 3 seconds apart, logging any issues along the way).

@RealSense-Customer-Engineering
Copy link
Collaborator

[Realsense Customer Engineering Team Comment]
hi @josephduchesne,

do you have another USB certified cable for testing? the frame did arrival in time mostly cause by cable quality.

@josephduchesne
Copy link
Author

josephduchesne commented Aug 31, 2018 •
edited
Loading

I do, I have restarted the test with a different cable on both cameras.

That said, after rebooting the computer the camera still won't reconnect in this state. The system has to be either physically unpowered, or the camera unplugged. This is more than just a transient issue and appears to indicate that there is a firmware, driver or hardware bug allowing the camera to get into a non-functioning state that can't be reset from software.

@RealSense-Customer-Engineering
Copy link
Collaborator

[Realsense Customer Engineering Team Comment]
HI @josephduchesne,

Did you try the firmware 5.10.3 to see how it works?

@josephduchesne
Copy link
Author

Running with very recent BIOS on our NUC (BNKBL357.86A.0067.2018.0814.1500), and firmware 5.10.3, we experience two problems. With the USB-C hub that we were previously using without issue, the cameras fail to come up on reboot (no cameras on lsusb).

Upon downgrading the BIOS 0063 (the one we were previously using), the USB-C hub no long has the "error -71" issue on reboot (however I would expect it to revert to having problems with the USB A ports that we saw on 0063).

Boot logs containing "usb" with BIOS 0067:

Sep 18 11:04:01 camerarig1 kernel: ACPI: bus type USB registered
Sep 18 11:04:01 camerarig1 kernel: usbcore: registered new interface driver usbfs
Sep 18 11:04:01 camerarig1 kernel: usbcore: registered new interface driver hub
Sep 18 11:04:01 camerarig1 kernel: usbcore: registered new device driver usb
Sep 18 11:04:01 camerarig1 kernel: ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver
Sep 18 11:04:01 camerarig1 kernel: ohci_hcd: USB 1.1 'Open' Host Controller (OHCI) Driver
Sep 18 11:04:01 camerarig1 kernel: uhci_hcd: USB Universal Host Controller Interface driver
Sep 18 11:04:01 camerarig1 kernel: xhci_hcd 0000:00:14.0: new USB bus registered, assigned bus number 1
Sep 18 11:04:01 camerarig1 kernel: usb usb1: New USB device found, idVendor=1d6b, idProduct=0002
Sep 18 11:04:01 camerarig1 kernel: usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
Sep 18 11:04:01 camerarig1 kernel: usb usb1: Product: xHCI Host Controller
Sep 18 11:04:01 camerarig1 kernel: usb usb1: Manufacturer: Linux 4.8.0-58-generic xhci-hcd
Sep 18 11:04:01 camerarig1 kernel: usb usb1: SerialNumber: 0000:00:14.0
Sep 18 11:04:01 camerarig1 kernel: hub 1-0:1.0: USB hub found
Sep 18 11:04:01 camerarig1 kernel: xhci_hcd 0000:00:14.0: new USB bus registered, assigned bus number 2
Sep 18 11:04:01 camerarig1 kernel: usb usb2: New USB device found, idVendor=1d6b, idProduct=0003
Sep 18 11:04:01 camerarig1 kernel: usb usb2: New USB device strings: Mfr=3, Product=2, SerialNumber=1
Sep 18 11:04:01 camerarig1 kernel: usb usb2: Product: xHCI Host Controller
Sep 18 11:04:01 camerarig1 kernel: usb usb2: Manufacturer: Linux 4.8.0-58-generic xhci-hcd
Sep 18 11:04:01 camerarig1 kernel: usb usb2: SerialNumber: 0000:00:14.0
Sep 18 11:04:01 camerarig1 kernel: usb: port power management may be unreliable
Sep 18 11:04:01 camerarig1 kernel: xhci_hcd 0000:39:00.0: new USB bus registered, assigned bus number 3
Sep 18 11:04:01 camerarig1 kernel: usb usb3: New USB device found, idVendor=1d6b, idProduct=0002
Sep 18 11:04:01 camerarig1 kernel: usb usb3: New USB device strings: Mfr=3, Product=2, SerialNumber=1
Sep 18 11:04:01 camerarig1 kernel: usb usb3: Product: xHCI Host Controller
Sep 18 11:04:01 camerarig1 kernel: usb usb3: Manufacturer: Linux 4.8.0-58-generic xhci-hcd
Sep 18 11:04:01 camerarig1 kernel: usb usb3: SerialNumber: 0000:39:00.0
Sep 18 11:04:01 camerarig1 kernel: hub 3-0:1.0: USB hub found
Sep 18 11:04:01 camerarig1 kernel: xhci_hcd 0000:39:00.0: new USB bus registered, assigned bus number 4
Sep 18 11:04:01 camerarig1 kernel: usb usb4: New USB device found, idVendor=1d6b, idProduct=0003
Sep 18 11:04:01 camerarig1 kernel: usb usb4: New USB device strings: Mfr=3, Product=2, SerialNumber=1
Sep 18 11:04:01 camerarig1 kernel: usb usb4: Product: xHCI Host Controller
Sep 18 11:04:01 camerarig1 kernel: usb usb4: Manufacturer: Linux 4.8.0-58-generic xhci-hcd
Sep 18 11:04:01 camerarig1 kernel: usb usb4: SerialNumber: 0000:39:00.0
Sep 18 11:04:01 camerarig1 kernel: hub 4-0:1.0: USB hub found
Sep 18 11:04:01 camerarig1 kernel: usb 3-1: new high-speed USB device number 2 using xhci_hcd
Sep 18 11:04:01 camerarig1 kernel: usb 1-1: new low-speed USB device number 2 using xhci_hcd
Sep 18 11:04:01 camerarig1 kernel: usb 1-1: New USB device found, idVendor=046d, idProduct=c077
Sep 18 11:04:01 camerarig1 kernel: usb 1-1: New USB device strings: Mfr=1, Product=2, SerialNumber=0
Sep 18 11:04:01 camerarig1 kernel: usb 1-1: Product: USB Optical Mouse
Sep 18 11:04:01 camerarig1 kernel: usb 1-1: Manufacturer: Logitech
Sep 18 11:04:01 camerarig1 kernel: usb 1-2: new low-speed USB device number 3 using xhci_hcd
Sep 18 11:04:01 camerarig1 kernel: usb 1-2: New USB device found, idVendor=045e, idProduct=07f8
Sep 18 11:04:01 camerarig1 kernel: usb 1-2: New USB device strings: Mfr=1, Product=2, SerialNumber=0
Sep 18 11:04:01 camerarig1 kernel: usb 1-2: Product: Wired Keyboard 600
Sep 18 11:04:01 camerarig1 kernel: usb 1-2: Manufacturer: Microsoft
Sep 18 11:04:01 camerarig1 kernel: usb 3-1: New USB device found, idVendor=05e3, idProduct=0610
Sep 18 11:04:01 camerarig1 kernel: usb 3-1: New USB device strings: Mfr=1, Product=2, SerialNumber=0
Sep 18 11:04:01 camerarig1 kernel: usb 3-1: Product: USB2.0 Hub
Sep 18 11:04:01 camerarig1 kernel: usb 3-1: Manufacturer: GenesysLogic
Sep 18 11:04:01 camerarig1 kernel: hub 3-1:1.0: USB hub found
Sep 18 11:04:01 camerarig1 kernel: usb 1-3: new full-speed USB device number 4 using xhci_hcd
Sep 18 11:04:01 camerarig1 kernel: usb 4-1: Device not responding to setup address.
Sep 18 11:04:01 camerarig1 kernel: usb 1-3: New USB device found, idVendor=266e, idProduct=0102
Sep 18 11:04:01 camerarig1 kernel: usb 1-3: New USB device strings: Mfr=1, Product=2, SerialNumber=3
Sep 18 11:04:01 camerarig1 kernel: usb 1-3: Product: SiS HID Touch Controller
Sep 18 11:04:01 camerarig1 kernel: usb 1-3: Manufacturer: Silicon Integrated Systems Co.
Sep 18 11:04:01 camerarig1 kernel: usb 1-3: SerialNumber: SiS81x12345
Sep 18 11:04:01 camerarig1 kernel: usb 4-1: Device not responding to setup address.
Sep 18 11:04:01 camerarig1 kernel: usb 1-8: new full-speed USB device number 5 using xhci_hcd
Sep 18 11:04:01 camerarig1 kernel: usb 1-8: New USB device found, idVendor=8087, idProduct=0a2b
Sep 18 11:04:01 camerarig1 kernel: usb 1-8: New USB device strings: Mfr=0, Product=0, SerialNumber=0
Sep 18 11:04:01 camerarig1 kernel: usbcore: registered new interface driver usbhid
Sep 18 11:04:01 camerarig1 kernel: usbhid: USB HID core driver
Sep 18 11:04:01 camerarig1 kernel: input: Logitech USB Optical Mouse as /devices/pci0000:00/0000:00:14.0/usb1/1-1/1-1:1.0/0003:046D:C077.0001/input/input3
Sep 18 11:04:01 camerarig1 kernel: hid-generic 0003:046D:C077.0001: input,hidraw0: USB HID v1.11 Mouse [Logitech USB Optical Mouse] on usb-0000:00:14.0-1/input0
Sep 18 11:04:01 camerarig1 kernel: input: Microsoft Wired Keyboard 600 as /devices/pci0000:00/0000:00:14.0/usb1/1-2/1-2:1.0/0003:045E:07F8.0002/input/input4
Sep 18 11:04:01 camerarig1 kernel: usb 4-1: device not accepting address 2, error -71
Sep 18 11:04:01 camerarig1 kernel: hid-generic 0003:045E:07F8.0002: input,hidraw1: USB HID v1.11 Keyboard [Microsoft Wired Keyboard 600] on usb-0000:00:14.0-2/input0
Sep 18 11:04:01 camerarig1 kernel: input: Microsoft Wired Keyboard 600 as /devices/pci0000:00/0000:00:14.0/usb1/1-2/1-2:1.1/0003:045E:07F8.0003/input/input5
Sep 18 11:04:01 camerarig1 kernel: hid-generic 0003:045E:07F8.0003: input,hidraw2: USB HID v1.11 Device [Microsoft Wired Keyboard 600] on usb-0000:00:14.0-2/input1
Sep 18 11:04:01 camerarig1 kernel: usb 4-1: Device not responding to setup address.
Sep 18 11:04:01 camerarig1 kernel: usb 4-1: Device not responding to setup address.
Sep 18 11:04:01 camerarig1 kernel: usb 4-1: device not accepting address 3, error -71
Sep 18 11:04:01 camerarig1 kernel: usb 4-1: Device not responding to setup address.
Sep 18 11:04:01 camerarig1 kernel: usb 4-1: Device not responding to setup address.
Sep 18 11:04:01 camerarig1 kernel: usb 4-1: device not accepting address 4, error -71
Sep 18 11:04:01 camerarig1 kernel: usb 4-1: Device not responding to setup address.
Sep 18 11:04:01 camerarig1 kernel: usb 4-1: Device not responding to setup address.
Sep 18 11:04:01 camerarig1 kernel: usb 4-1: device not accepting address 5, error -71
Sep 18 11:04:01 camerarig1 kernel: usb usb4-port1: unable to enumerate USB device
Sep 18 11:04:01 camerarig1 kernel: usbcore: registered new interface driver btusb
Sep 18 11:04:01 camerarig1 kernel: input: Silicon Integrated Systems Co. SiS HID Touch Controller as /devices/pci0000:00/0000:00:14.0/usb1/1-3/1-3:1.0/0003:266E:0102.0004/input/input8
Sep 18 11:04:01 camerarig1 kernel: hid-multitouch 0003:266E:0102.0004: input,hiddev0,hidraw3: USB HID v1.01 Mouse [Silicon Integrated Systems Co. SiS HID Touch Controller] on usb-0000:00:14.0-3/input0

With the USB A ports, they work the vast majority of the times, but still occasionally experience the following issue where they have device descriptor errors:

Sep 17 13:40:42 cameras kernel: [    3.018659] usb 3-1.1: device descriptor read/64, error -71
Sep 17 13:40:42 cameras kernel: [    3.078080] ACPI: Video Device [GFX0] (multi-head: yes  rom: no  post: no)
Sep 17 13:40:42 cameras kernel: [    3.078653] acpi device:0f: registered as cooling_device4
Sep 17 13:40:42 cameras kernel: [    3.078734] input: Video Bus as /devices/LNXSYSTM:00/LNXSYBUS:00/PNP0A08:00/LNXVIDEO:00/input/input3
Sep 17 13:40:42 cameras kernel: [    3.078823] [drm] Initialized i915 1.6.0 20160711 for 0000:00:02.0 on minor 0
Sep 17 13:40:42 cameras kernel: [    3.106976] clocksource: Switched to clocksource tsc
Sep 17 13:40:42 cameras kernel: [    3.206755] usb 3-1.1: new high-speed USB device number 5 using xhci_hcd
Sep 17 13:40:42 cameras kernel: [    3.206919] usb 3-1.1: Device not responding to setup address.
Sep 17 13:40:42 cameras kernel: [    3.305368] i915 0000:00:02.0: No connectors reported connected with modes
Sep 17 13:40:42 cameras kernel: [    3.305373] [drm] Cannot find any crtc or sizes - going 1024x768
Sep 17 13:40:42 cameras kernel: [    3.305730] fbcon: inteldrmfb (fb0) is primary device
Sep 17 13:40:42 cameras kernel: [    3.305806] Console: switching to colour frame buffer device 128x48
Sep 17 13:40:42 cameras kernel: [    3.307290] i915 0000:00:02.0: fb0: inteldrmfb frame buffer device
Sep 17 13:40:42 cameras kernel: [    3.414909] usb 3-1.1: Device not responding to setup address.
Sep 17 13:40:42 cameras kernel: [    3.622723] usb 3-1.1: device not accepting address 5, error -71
Sep 17 13:40:42 cameras kernel: [    3.702755] usb 3-1.1: new high-speed USB device number 6 using xhci_hcd
Sep 17 13:40:42 cameras kernel: [    3.702916] usb 3-1.1: Device not responding to setup address.
Sep 17 13:40:42 cameras kernel: [    3.910906] usb 3-1.1: Device not responding to setup address.
Sep 17 13:40:42 cameras kernel: [    4.118757] usb 3-1.1: device not accepting address 6, error -71
Sep 17 13:40:42 cameras kernel: [    4.119504] usb 3-1-port1: unable to enumerate USB device
Sep 17 13:40:42 cameras kernel: [    4.198759] usb 3-1.4: new high-speed USB device number 7 using xhci_hcd
Sep 17 13:40:42 cameras kernel: [    4.278745] usb 3-1.4: device descriptor read/64, error -71
Sep 17 13:40:42 cameras kernel: [    4.466773] usb 3-1.4: device descriptor read/64, error -71
Sep 17 13:40:42 cameras kernel: [    4.654762] usb 3-1.4: new high-speed USB device number 8 using xhci_hcd
Sep 17 13:40:42 cameras kernel: [    4.734749] usb 3-1.4: device descriptor read/64, error -71
Sep 17 13:40:42 cameras kernel: [    4.835067] [drm] RC6 on
Sep 17 13:40:42 cameras kernel: [    4.922631] usb 3-1.4: device descriptor read/64, error -71
Sep 17 13:40:42 cameras kernel: [    5.110759] usb 3-1.4: new high-speed USB device number 9 using xhci_hcd
Sep 17 13:40:42 cameras kernel: [    5.110921] usb 3-1.4: Device not responding to setup address.
Sep 17 13:40:42 cameras kernel: [    5.318918] usb 3-1.4: Device not responding to setup address.
Sep 17 13:40:42 cameras kernel: [    5.526759] usb 3-1.4: device not accepting address 9, error -71
Sep 17 13:40:42 cameras kernel: [    5.606760] usb 3-1.4: new high-speed USB device number 10 using xhci_hcd
Sep 17 13:40:42 cameras kernel: [    5.606926] usb 3-1.4: Device not responding to setup address.
Sep 17 13:40:42 cameras kernel: [    5.814918] usb 3-1.4: Device not responding to setup address.
Sep 17 13:40:42 cameras kernel: [    6.022765] usb 3-1.4: device not accepting address 10, error -71
Sep 17 13:40:42 cameras kernel: [    6.023108] usb 3-1-port4: unable to enumerate USB device

@RealSense-Customer-Engineering
Copy link
Collaborator

[Realsense Customer Engineering Team Comment]
Hello @josephduchesne,

We ran the following tests on NUC7i3BNH / Ubuntu 16.04.4 / LibRealSense 2.16.1 / FW 5.10.3 / 2 D435 RealSense Cameras w/ bash script that reboots system and checks 'lsusb' for 2 D435 cameras:

BIOS 63, USB-A 2 D435 cameras connected. 41 reboots with no issues.
BIOS 63. USB-C Hub w/ power, 2 D435 cameras, 30 reboots, no issues.
BIOS 67, USB-A 2 D435 cameras, 33 reboots, no issues.
BIOS 67, USB-C hub w/ power, 2 D435 cameras, 30 reboots, no issues.
BIOS 67, USB-C hub w/ power, 2 D435 cameras, 969 reboots, no issues seeing both cameras with "lsusb" for every boot.

  • We did not see the issue with missing cameras from 'lsusb' command with either BIOS + 3 D435 RealSense Cameras.

Questions:
What does you test include other than "lsusb"? You mention running a ROS node, are you using latest wrapper and librealsense combination? Also what commands are you running at boot? We would like to have access to:

  • A copy of your script. Or commands of those scripts.
  • Brand/model of the type of hub.
  • Verification of cables being used. Are you using the cables supplied by Intel, or some other cables you purchased from another source?
    All of these items would help to try to replicate and narrow down the issue customer may be seeing.

Thank you!

@RealSense-Customer-Engineering
Copy link
Collaborator

[Realsense Customer Engineering Team Comment]
@josephduchesne,

We would like to help narrow down this issue, however; if no response we will close this issue as solved.

Thank you!

@josephduchesne
Copy link
Author

That's encouraging. We are trying without the USB hub with two cameras right now. With BIOS 69 the unpowered USB C hub we are using was not working, however without the hub it seems better. I'm trying to see if the no-hub configuration is as stable as BIOS 63 with the hub (which is what we were using previously).

@josephduchesne
Copy link
Author

We are using the intel provided cables at the moment in our tests. The ones we use in our robots are from another supplier since we want ones that screw in to the camera.

@josephduchesne
Copy link
Author

Ok, I'm currently testing the configuration. On 3/4 systems that I have tested so far NUC7i3 BIOS 0069 + Intel Realsense firmware 5.10.3 (the latest version when I started these tests two weeks ago) + a recent version of ros-kinetic-intel-realsense2 the configuration works fine and appears stable.

The cable configuration is two USB type C to Type A cables: one connected to the front blue USB port, and one connected to the back bottom USB port.

On one system though, it appears to work when cold booted (power applied to NUC), but on reboot both cameras return a USB kernel error and fail to show up under lsusb:

Oct 24 09:52:13 cameras kernel: usbcore: registered new interface driver usbfs
Oct 24 09:52:13 cameras kernel: usbcore: registered new interface driver hub
Oct 24 09:52:13 cameras kernel: usbcore: registered new device driver usb
Oct 24 09:52:13 cameras kernel: usb usb1: New USB device found, idVendor=1d6b, idProduct=0002
Oct 24 09:52:13 cameras kernel: usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
Oct 24 09:52:13 cameras kernel: usb usb1: Product: xHCI Host Controller
Oct 24 09:52:13 cameras kernel: usb usb1: Manufacturer: Linux 4.8.0-58-generic xhci-hcd
Oct 24 09:52:13 cameras kernel: usb usb1: SerialNumber: 0000:00:14.0
Oct 24 09:52:13 cameras kernel: usb usb2: New USB device found, idVendor=1d6b, idProduct=0003
Oct 24 09:52:13 cameras kernel: usb usb2: New USB device strings: Mfr=3, Product=2, SerialNumber=1
Oct 24 09:52:13 cameras kernel: usb usb2: Product: xHCI Host Controller
Oct 24 09:52:13 cameras kernel: usb usb2: Manufacturer: Linux 4.8.0-58-generic xhci-hcd
Oct 24 09:52:13 cameras kernel: usb usb2: SerialNumber: 0000:00:14.0
Oct 24 09:52:13 cameras kernel: usb: port power management may be unreliable
Oct 24 09:52:13 cameras kernel: usb 1-8: new full-speed USB device number 2 using xhci_hcd
Oct 24 09:52:13 cameras kernel: usb 1-8: New USB device found, idVendor=8087, idProduct=0a2b
Oct 24 09:52:13 cameras kernel: usb 1-8: New USB device strings: Mfr=0, Product=0, SerialNumber=0
Oct 24 09:52:13 cameras kernel: usb 2-2: Device not responding to setup address.
Oct 24 09:52:13 cameras kernel: usb 2-2: Device not responding to setup address.
Oct 24 09:52:13 cameras kernel: usb 2-2: device not accepting address 2, error -71
Oct 24 09:52:13 cameras kernel: usb 2-2: Device not responding to setup address.
Oct 24 09:52:13 cameras kernel: usb 2-2: Device not responding to setup address.
Oct 24 09:52:13 cameras kernel: usb 2-2: device not accepting address 3, error -71
Oct 24 09:52:13 cameras kernel: usb 2-2: Device not responding to setup address.
Oct 24 09:52:13 cameras kernel: usb 2-2: Device not responding to setup address.
Oct 24 09:52:13 cameras kernel: usb 2-2: device not accepting address 4, error -71
Oct 24 09:52:13 cameras kernel: usb 2-2: Device not responding to setup address.
Oct 24 09:52:13 cameras kernel: usb 2-2: Device not responding to setup address.
Oct 24 09:52:13 cameras kernel: usb 2-2: device not accepting address 5, error -71
Oct 24 09:52:13 cameras kernel: usb usb2-port2: unable to enumerate USB device
Oct 24 09:52:13 cameras kernel: usb 2-3: Device not responding to setup address.
Oct 24 09:52:13 cameras kernel: usb 2-3: Device not responding to setup address.
Oct 24 09:52:13 cameras kernel: usb 2-3: device not accepting address 6, error -71
Oct 24 09:52:13 cameras kernel: usb 2-3: Device not responding to setup address.
Oct 24 09:52:13 cameras kernel: usb 2-3: Device not responding to setup address.
Oct 24 09:52:13 cameras kernel: usb 2-3: device not accepting address 7, error -71
Oct 24 09:52:13 cameras kernel: usb 2-3: Device not responding to setup address.
Oct 24 09:52:13 cameras kernel: usb 2-3: Device not responding to setup address.
Oct 24 09:52:13 cameras kernel: usb 2-3: device not accepting address 8, error -71
Oct 24 09:52:13 cameras kernel: usb 2-3: Device not responding to setup address.
Oct 24 09:52:13 cameras kernel: usb 2-3: Device not responding to setup address.
Oct 24 09:52:13 cameras kernel: usb 2-3: device not accepting address 9, error -71
Oct 24 09:52:13 cameras kernel: usb usb2-port3: unable to enumerate USB device
Oct 24 09:52:13 cameras kernel: usbcore: registered new interface driver btusb

@RealSense-Customer-Engineering
Copy link
Collaborator

[Realsense Customer Engineering Team Comment]
Hello @josephduchesne,

I am glad to hear 3 of the 4 systems are working for you now!

Just for a quick test - can you:

  • Use the same 2 cables + 2 working cameras being used on one of the working systems and transfer them to the system displaying the lsusb errors?

  • If you are still seeing the same errors with those cables/cameras combination, can you possibly change which ports you are plugging the cameras into? Instead of the front blue, try the front yellow USB port (all ports should be USB 3.0 on this NUC), and top USB port in the back? I would like to somehow determine if one (or even all) of the ports is defective or not.

Thank you for the update! Please let us know how it goes!

@Shu1-matsumoto
Copy link

Hello, sir

I have the same issue.

Required Info
Camera Model D435
Firmware Version 5.10.3
Operating System & Version Linux (Ubuntu 18.04)
Platform Intel Atom Custom board

My SBC is recognizing D435 on USB 3.0 port, but when I reboot the SBC from command, The SBC lost the D435 after rebooting.

  1. When I take off the USB cable and insert again, it's OK. My SBC can recognize the D435.

  2. When I do shut down the SBC and push the power button, it's OK. My SBC can recognize the D435.

I need to manipulate the SBC remotely. I hope the next firmware will solve this issue.

Thank you.

@RealSense-Customer-Engineering
Copy link
Collaborator

[Realsense Customer Engineering Team Comment]
Hello @Shu1-matsumoto,

Sorry to hear you are seeing a similar issue with D435 camera.

From our testing using Intel NUCs + provided D435 USB 3.0 type C cable, this problem was proven not an issue with D435 camera itself but a cabling and / or USB port connection issue.

Since you are using a custom Intel Atom board, a few questions:

  • Where did you order system are you using? Please provide model name, #, and website so we can replicate your environment if possible.

  • Are you plugging in camera to USB 3.0 ports?

  • Have you tried different USB 3.0 type-C cables and plugging those in different ports?

  • Are you using a USB 3.0 powered hub? We suggest to use USB 3.0 powered hubs on low power devices such as Atom boards.

I am thinking the issue you are seeing is related to power consumption, could you please:

  1. Type export LRS_LOG_LEVEL=Debug.
  2. Reproduce the issue.
  3. To compare camera functionality please also post the output of rs-enumerate-devices

Thank you

@jasoncatchpole jasoncatchpole mentioned this issue Nov 19, 2018
Closed
@RealSense-Customer-Engineering
Copy link
Collaborator

[Realsense Customer Engineering Team Comment]
No responses over a month. Close this issue as solved.

@FENGZHANG123
Copy link

I met this problem as well, see issue discription ,any updates so far?

Closed
@erelson
Copy link

erelson commented Jun 11, 2019

Happened to wander in here... my own experience with these cameras and some other USB devices is that doing sudo reboot is not ideal, as it (often?) doesn't seem to cut power to the cameras, and it seems they don't re-enumerate as USB devices properly afterwards. Unclear if that's exactly what's going on in various comments, but seems similar.

Instead, a workaround I commonly do is to use the rtcwake utility which does cut power: sudo rtcwake -m off -s 30, which will wake the computer back up after it's been off for 30s (shorter times likely will work). This depends on what motherboard, etc. you're using, of course; namely how USB power is handled when powered off or rebooting varies, and not all devices (RPi) have an RTC for rtcwake to use.

@saml-dev
Copy link

@erelson - just wanted to say THANK YOU for this! The camera not being detected by the OS has been killing us in prod and although your exact answer didn't work for us, it led me to a solution that did. For others that stumble on this thread, here's what worked for us:

# must be run as sudo
echo 0 > /sys/class/rtc/rtc0/wakealarm
echo $(date '+%s' -d '+ 5 seconds') > /sys/class/rtc/rtc0/wakealarm
poweroff -f

We're still on the lookout for a solution that doesn't require a reboot, but this works for now. If anyone finds a way to properly cycle a Realsense camera (we're using a D415) without rebooting when the camera doesn't show up on lsusb, please tag me and let me know!

@MartyG-RealSense MartyG-RealSense mentioned this issue Aug 20, 2019
Closed
@MartyG-RealSense MartyG-RealSense mentioned this issue Feb 25, 2020
Closed
@MartyG-RealSense MartyG-RealSense mentioned this issue Nov 6, 2020
Closed
@MartyG-RealSense MartyG-RealSense mentioned this issue Jul 30, 2021
Closed
@MartyG-RealSense MartyG-RealSense mentioned this issue Aug 29, 2024
Open
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@RealSense-Customer-Engineering RealSense-Customer-Engineering

Labels
bug hardware question
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
9 participants
@erelson @josephduchesne @dorodnic @saml-dev @FENGZHANG123 @JasonChang13 @tedtman @RealSense-Customer-Engineering @Shu1-matsumoto