DS1821+ / V1000 Troubleshooting

Hello! I have recently upgraded from DS1817+ (Avoton) to DS1821+ (V1000). Both are running DSM 7.1-42661 Update 4.

I have a Coral USB Accelerator that works fine in the DS1817+ with cp210x.ko loaded from this repo.

I follow the same steps on the DS1821+ with cp210x.ko from the V1000 folder in this repo (copy cp210x.ko to /lib/modules, insmod, copy and run rc.d script), but it will not work. Frigate cannot detect the Coral.

I have tried the drivers from Jadahl too, with the same result.

$ uname -a
Linux synbad 4.4.180+ #42661 SMP Mon Jun 27 15:11:30 CST 2022 x86_64 GNU/Linux synology_v1000_1821+

$ lsmod |grep ^usbcore
usbcore               200140  14 etxhci_hcd,usblp,uhci_hcd,usb_storage,cp210x,usbserial,ehci_hcd,ehci_pci,usbhid,ftdi_sio,cdc_acm,xhci_hcd,xhci_pci

$ lsusb -cui
|__usb1          1d6b:0002:0404 09  2.00  480MBit/s 0mA 1IF  (Linux 4.4.180+ xhci-hcd xHCI Host Controller 0000:09:00.3) hub
  |__1-1         0764:0501:0001 00  2.00   12MBit/s 2mA 1IF  (CPS CP1500PFCLCD 000000000000)
  1-1:1.0         (IF) 03:00:00 1EP  () usbfs
|__usb3          1d6b:0002:0404 09  2.00  480MBit/s 0mA 1IF  (Linux 4.4.180+ xhci-hcd xHCI Host Controller 0000:09:00.4) hub
  |__3-2         f400:f400:0100 00  2.00  480MBit/s 200mA 1IF  (Synology DiskStation 6500228E14345A35)
  3-2:1.0         (IF) 08:06:50 2EPs () usb-storage host10 (synoboot)
|__usb4          1d6b:0003:0404 09  3.00 5000MBit/s 0mA 1IF  (Linux 4.4.180+ xhci-hcd xHCI Host Controller 0000:09:00.4) hub
  |__4-1         1a6e:089a:0100 00  3.10 5000MBit/s 896mA 1IF  ( ffffffd1ffffffb2ffffffdbffffffad)
  4-1:1.0         (IF) fe:01:02 0EPs ()

$ sudo cat /dev/bus/usb/devices
T:  Bus=04 Lev=01 Prnt=01 Port=00 Cnt=01 Dev#=  4 Spd=5000 MxCh= 0
D:  Ver= 3.10 Cls=00(>ifc ) Sub=00 Prot=00 MxPS= 9 #Cfgs=  1
P:  Vendor=1a6e ProdID=089a Rev= 1.00
S:  Product=USBDevice
S:  SerialNumber=ffffffd1ffffffb2ffffffdbffffffad
C:* #Ifs= 1 Cfg#= 1 Atr=80 MxPwr=896mA
I:* If#= 0 Alt= 0 #EPs= 0 Cls=fe(app. ) Sub=01 Prot=02 Driver=(none)

I thought the Driver=(none) in /dev/bus/usb/devices indicated a problem, but it looks the same on the DS1817+ where it's working.

I also tried to build the drivers myself, but I was not able to create a suitable VM/container to do the build in. My filesystem isn't BTRFS so I can't use a VM, and I couldn't figure out how to do it in a docker container.

I tried with a powered USB hub, but the behavior was the same.

Any help is greatly appreciated.

According to lsmod, the driver is loaded. Does sudo dmesg provide any clue as to why it's not working?

When I disconnect and re-connect the Coral device, restart Frigate in docker (to change config to look for coral), then stop the docker container after it throws the error about missing coral, I see this in dmesg:

[Mon Aug 15 09:58:33 2022] usb 2-3: USB disconnect, device number 7
[Mon Aug 15 09:58:40 2022] usb 2-3: new SuperSpeed USB device number 8 using xhci_hcd
[Mon Aug 15 09:58:40 2022] Got empty serial number. Generate serial number from product.
[Mon Aug 15 09:59:43 2022] audit: type=1325 audit(1660571968.785:5615): table=nat family=2 entries=94
[Mon Aug 15 09:59:43 2022] audit: type=1325 audit(1660571968.810:5616): table=filter family=2 entries=111
[Mon Aug 15 09:59:43 2022] audit: type=1325 audit(1660571968.839:5617): table=nat family=2 entries=93
[Mon Aug 15 09:59:43 2022] audit: type=1325 audit(1660571968.859:5618): table=nat family=2 entries=92
[Mon Aug 15 09:59:43 2022] audit: type=1325 audit(1660571968.878:5619): table=filter family=2 entries=110
[Mon Aug 15 09:59:43 2022] audit: type=1325 audit(1660571968.897:5620): table=nat family=2 entries=91
[Mon Aug 15 09:59:43 2022] docker0: port 5(dockerd0daf66) entered disabled state
[Mon Aug 15 09:59:43 2022] dockerffad1b4: renamed from eth0
[Mon Aug 15 09:59:43 2022] docker0: port 5(dockerd0daf66) entered disabled state
[Mon Aug 15 09:59:43 2022] device dockerd0daf66 left promiscuous mode
[Mon Aug 15 09:59:43 2022] audit: type=1700 audit(1660571969.151:5621): dev=dockerd0daf66 prom=0 old_prom=256 auid=4294967295 uid=0 gid=0 ses=4294967295
[Mon Aug 15 09:59:43 2022] docker0: port 5(dockerd0daf66) entered disabled state
[Mon Aug 15 09:59:47 2022] device docker30e90dd entered promiscuous mode
[Mon Aug 15 09:59:47 2022] audit: type=1700 audit(1660571973.339:5622): dev=docker30e90dd prom=256 old_prom=0 auid=4294967295 uid=0 gid=0 ses=4294967295
[Mon Aug 15 09:59:47 2022] IPv6: ADDRCONF(NETDEV_UP): docker30e90dd: link is not ready
[Mon Aug 15 09:59:48 2022] audit: type=1325 audit(1660571973.597:5623): table=nat family=2 entries=90
[Mon Aug 15 09:59:48 2022] audit: type=1325 audit(1660571973.615:5624): table=filter family=2 entries=109
[Mon Aug 15 09:59:48 2022] audit_printk_skb: 12 callbacks suppressed
[Mon Aug 15 09:59:48 2022] audit: type=1325 audit(1660571974.127:5629): table=filter family=2 entries=0
[Mon Aug 15 09:59:48 2022] audit: type=1325 audit(1660571974.147:5630): table=filter family=10 entries=0
[Mon Aug 15 09:59:48 2022] audit: type=1325 audit(1660571974.158:5631): table=nat family=2 entries=0
[Mon Aug 15 09:59:48 2022] audit: type=1325 audit(1660571974.166:5632): table=mangle family=2 entries=0
[Mon Aug 15 09:59:48 2022] IPVS: Creating netns size=2096 id=54
[Mon Aug 15 09:59:49 2022] eth0: renamed from dockerca21f25
[Mon Aug 15 09:59:49 2022] IPv6: ADDRCONF(NETDEV_CHANGE): docker30e90dd: link becomes ready
[Mon Aug 15 09:59:49 2022] docker0: port 5(docker30e90dd) entered forwarding state
[Mon Aug 15 09:59:49 2022] docker0: port 5(docker30e90dd) entered forwarding state
[Mon Aug 15 10:00:04 2022] audit: type=1325 audit(1660571989.510:5633): table=nat family=2 entries=94
[Mon Aug 15 10:00:04 2022] audit: type=1325 audit(1660571989.529:5634): table=filter family=2 entries=111
[Mon Aug 15 10:00:04 2022] audit: type=1325 audit(1660571989.547:5635): table=nat family=2 entries=93
[Mon Aug 15 10:00:04 2022] audit: type=1325 audit(1660571989.567:5636): table=nat family=2 entries=92
[Mon Aug 15 10:00:04 2022] audit: type=1325 audit(1660571989.585:5637): table=filter family=2 entries=110
[Mon Aug 15 10:00:04 2022] audit: type=1325 audit(1660571989.604:5638): table=nat family=2 entries=91
[Mon Aug 15 10:00:04 2022] docker0: port 5(docker30e90dd) entered forwarding state
[Mon Aug 15 10:00:04 2022] docker0: port 5(docker30e90dd) entered disabled state
[Mon Aug 15 10:00:04 2022] dockerca21f25: renamed from eth0
[Mon Aug 15 10:00:04 2022] docker0: port 5(docker30e90dd) entered disabled state
[Mon Aug 15 10:00:04 2022] device docker30e90dd left promiscuous mode
[Mon Aug 15 10:00:04 2022] audit: type=1700 audit(1660571989.761:5639): dev=docker30e90dd prom=0 old_prom=256 auid=4294967295 uid=0 gid=0 ses=4294967295
[Mon Aug 15 10:00:04 2022] docker0: port 5(docker30e90dd) entered disabled state

I don't know what most of that means, but it seems to be related to networking and not usb.

I am going to try a coral python example script on the nas directly, to rule out docker as the issue.

I would have expected a message to show up which device entry (/dev/tty*) the device got assigned. Try rmmod cp210x then loading it again with insmod.

$ sudo rmmod cp210x
Password:
$ sudo insmod /lib/modules/cp210x.ko
$ lsmod |grep ^usbcore
usbcore               200140  14 etxhci_hcd,usblp,uhci_hcd,usb_storage,cp210x,usbserial,ehci_hcd,ehci_pci,usbhid,ftdi_sio,cdc_acm,xhci_hcd,xhci_pci

dmesg while I ran the above commands:

[Mon Aug 15 10:19:48 2022] Module [cp210x] is removed.
[Mon Aug 15 10:19:48 2022] usbserial: USB Serial deregistering driver cp210x
[Mon Aug 15 10:19:48 2022] usbcore: deregistering interface driver cp210x
[Mon Aug 15 10:20:03 2022] usbcore: registered new interface driver cp210x
[Mon Aug 15 10:20:03 2022] usbserial: USB Serial support registered for cp210x

dmesg while disconnecting/reconnecting the coral, restarting and then stopping frigate docker again:

[Mon Aug 15 10:24:33 2022] usb 2-3: USB disconnect, device number 8
[Mon Aug 15 10:24:38 2022] usb 2-3: new SuperSpeed USB device number 9 using xhci_hcd
[Mon Aug 15 10:24:38 2022] Got empty serial number. Generate serial number from product.
[Mon Aug 15 10:24:49 2022] device docker0c26e5e entered promiscuous mode
[Mon Aug 15 10:24:49 2022] audit: type=1700 audit(1660573474.853:5701): dev=docker0c26e5e prom=256 old_prom=0 auid=4294967295 uid=0 gid=0 ses=4294967295
[Mon Aug 15 10:24:49 2022] IPv6: ADDRCONF(NETDEV_UP): docker0c26e5e: link is not ready
[Mon Aug 15 10:24:49 2022] audit: type=1325 audit(1660573475.238:5702): table=nat family=2 entries=90
[Mon Aug 15 10:24:49 2022] audit: type=1325 audit(1660573475.258:5703): table=filter family=2 entries=109
[Mon Aug 15 10:24:49 2022] audit: type=1325 audit(1660573475.277:5704): table=nat family=2 entries=91
[Mon Aug 15 10:24:50 2022] audit: type=1325 audit(1660573475.299:5705): table=nat family=2 entries=92
[Mon Aug 15 10:24:50 2022] audit: type=1325 audit(1660573475.318:5706): table=filter family=2 entries=110
[Mon Aug 15 10:24:50 2022] audit: type=1325 audit(1660573475.337:5707): table=nat family=2 entries=93
[Mon Aug 15 10:24:50 2022] audit: type=1325 audit(1660573475.721:5708): table=filter family=2 entries=0
[Mon Aug 15 10:24:50 2022] audit: type=1325 audit(1660573475.729:5709): table=filter family=10 entries=0
[Mon Aug 15 10:24:50 2022] audit: type=1325 audit(1660573475.738:5710): table=nat family=2 entries=0
[Mon Aug 15 10:24:50 2022] IPVS: Creating netns size=2096 id=57
[Mon Aug 15 10:24:50 2022] eth0: renamed from docker0ec6c32
[Mon Aug 15 10:24:50 2022] IPv6: ADDRCONF(NETDEV_CHANGE): docker0c26e5e: link becomes ready
[Mon Aug 15 10:24:50 2022] docker0: port 5(docker0c26e5e) entered forwarding state
[Mon Aug 15 10:24:50 2022] docker0: port 5(docker0c26e5e) entered forwarding state
[Mon Aug 15 10:25:05 2022] docker0: port 5(docker0c26e5e) entered forwarding state
[Mon Aug 15 10:25:16 2022] audit_printk_skb: 3 callbacks suppressed
[Mon Aug 15 10:25:16 2022] audit: type=1325 audit(1660573501.463:5712): table=nat family=2 entries=94
[Mon Aug 15 10:25:16 2022] audit: type=1325 audit(1660573501.486:5713): table=filter family=2 entries=111
[Mon Aug 15 10:25:16 2022] audit: type=1325 audit(1660573501.507:5714): table=nat family=2 entries=93
[Mon Aug 15 10:25:16 2022] audit: type=1325 audit(1660573501.527:5715): table=nat family=2 entries=92
[Mon Aug 15 10:25:16 2022] audit: type=1325 audit(1660573501.547:5716): table=filter family=2 entries=110
[Mon Aug 15 10:25:16 2022] audit: type=1325 audit(1660573501.567:5717): table=nat family=2 entries=91
[Mon Aug 15 10:25:16 2022] docker0: port 5(docker0c26e5e) entered disabled state
[Mon Aug 15 10:25:16 2022] docker0ec6c32: renamed from eth0
[Mon Aug 15 10:25:16 2022] docker0: port 5(docker0c26e5e) entered disabled state
[Mon Aug 15 10:25:16 2022] device docker0c26e5e left promiscuous mode
[Mon Aug 15 10:25:16 2022] audit: type=1700 audit(1660573501.725:5718): dev=docker0c26e5e prom=0 old_prom=256 auid=4294967295 uid=0 gid=0 ses=4294967295
[Mon Aug 15 10:25:16 2022] docker0: port 5(docker0c26e5e) entered disabled state

When I connect the coral to the DS1817+ (working device), I see this in dmesg. Does this indicate cp210x is the wrong driver?

[Mon Aug 15 09:28:25 2022] usb 3-4: new SuperSpeed USB device number 7 using etxhci_hcd-170202
[Mon Aug 15 09:28:25 2022] Got empty serial number. Generate serial number from product.
[Mon Aug 15 09:28:25 2022] drivers/usb/core/ethub.c (2055) Same device found. Change serial to ffffffd1ffffffb2ffffffdbffffffa0

Does this indicate cp210x is the wrong driver?

I think so, yes. Also, given the type of device, it's actually unlikely it uses a usbserial interface at all.

I see etxhci_hcd in the usbcore driver list on both devices. Do you have any idea why one device would use xhci_hcd and the other would use etxhci_hcd, or what I can do to make it work?

I think those are USB host drivers (so for the USB chip inside the NAS).

Do you have any advice to make it work?

What's the output of lsusb -cui (with the Coral plugged in) on the NAS where it works?

Working:

$ lsusb -cui
|__usb1          1d6b:0002:0310 09  2.00  480MBit/s 0mA 1IF  (ehci_hcd 0000:00:16.0) hub
  |__1-1         8087:07db:0003 09  2.00  480MBit/s 0mA 1IF  ( ffffffd1ffffffb2ffffffdbffffffad) hub
    |__1-1.1     f400:f400:0100 00  2.00  480MBit/s 200mA 1IF  (Synology DiskStation 7F008652656DAE99)
   1-1.1:1.0      (IF) 08:06:50 2EPs () usb-storage host14 (synoboot)
|__usb3          1d6b:0003:0310 09  3.00 5000MBit/s 0mA 1IF  (Linux 3.10.108 etxhci_hcd-170202 Etron xHCI Host Controller 0000:09:00.0) hub
  |__3-4         1a6e:089a:0100 00  3.10 5000MBit/s 896mA 1IF  ( ffffffd1ffffffb2ffffffdbffffffa0)
  3-4:1.0         (IF) fe:01:02 0EPs ()

Not working:

$ lsusb -cui
|__usb1          1d6b:0002:0404 09  2.00  480MBit/s 0mA 1IF  (Linux 4.4.180+ xhci-hcd xHCI Host Controller 0000:09:00.3) hub
  |__1-1         0764:0501:0001 00  2.00   12MBit/s 2mA 1IF  (CPS CP1500PFCLCD 000000000000)
  1-1:1.0         (IF) 03:00:00 1EP  () usbfs
|__usb3          1d6b:0002:0404 09  2.00  480MBit/s 0mA 1IF  (Linux 4.4.180+ xhci-hcd xHCI Host Controller 0000:09:00.4) hub
  |__3-2         f400:f400:0100 00  2.00  480MBit/s 200mA 1IF  (Synology DiskStation 6500228E14345A35)
  3-2:1.0         (IF) 08:06:50 2EPs () usb-storage host10 (synoboot)
|__usb4          1d6b:0003:0404 09  3.00 5000MBit/s 0mA 1IF  (Linux 4.4.180+ xhci-hcd xHCI Host Controller 0000:09:00.4) hub
  |__4-1         1a6e:089a:0100 00  3.10 5000MBit/s 896mA 1IF  ( ffffffd1ffffffb2ffffffdbffffffad)
  4-1:1.0         (IF) fe:01:02 0EPs ()

I truly appreciate your time and assistance.

My guess is that the "1a6e:089a:0100" device is the Coral. It doesn't show a driver being used in both cases, which is a bit puzzling.

Are you running Frigate in a VM on your old NAS? Because that could explain why it's working there, since that wouldn't require host (DSM) support for the device.

FWIW, here's what's shown for two USB-to-serial devices connected to my NAS:

    |__1-1.3     10c4:ea60:0100 00  1.10   12MBit/s 100mA 1IF  (Silicon Labs CP2102 USB to UART Bridge Controller 0001)
   1-1.3:1.0      (IF) ff:00:00 2EPs () cp210x ttyUSB0
    |__1-1.4     0658:0200:0000 02  2.00   12MBit/s 100mA 2IFs ( ffffffd1ffffffb2ffffffdbffffffad)
   1-1.4:1.0      (IF) 02:02:01 1EP  () cdc_acm tty/ttyACM0
   1-1.4:1.1      (IF) 0a:00:00 2EPs () cdc_acm

It's showing both the driver and device entry for each device.

By the way, thanks a lot for your donation! 👍🏻

Yes, I believe "1a6e:089a" is the Coral device id as well.

No, I am running Frigate in Docker. I can't run a VM because my filesystem is not BTRFS (just learned about that requirement when I tried to spin up a VM to rebuild drivers).

Thanks for the sample of what your lsusb looks like. I see where the driver and device name should be listed now.

Do you think it's worth trying to copy the host driver from the old NAS, or since they are presumably different chips is there no way that would work?

Yeah I doubt that copying the driver will do any good (in fact, I assume that the old NAS driver is already present on your new system, just not in use because of the different hardware).

What I still don't understand is how Frigate on your old NAS accesses the Coral device, as it doesn't seem to have a device entry in /dev.

I just spun up a frigate docker container on the DS1817+ with the Coral connected, installed and ran usbutils in the container. It doesn't have cui options available, but it has -t for tree so I did that with -v for verbose.

# lsusb -tvv
/:  Bus 03.Port 1: Dev 1, Class=root_hub, Driver=etxhci_hcd-170202/4p, 5000M
    ID 1d6b:0003
    /sys/bus/usb/devices/usb3  /dev/bus/usb/003/001
    |__ Port 4: Dev 10, If 0, Class=, Driver=usbfs, 5000M
        ID 18d1:9302
        /sys/bus/usb/devices/3-4  /dev/bus/usb/003/010
/:  Bus 02.Port 1: Dev 1, Class=root_hub, Driver=etxhci_hcd-170202/4p, 480M
    ID 1d6b:0002
    /sys/bus/usb/devices/usb2  /dev/bus/usb/002/001
/:  Bus 01.Port 1: Dev 1, Class=root_hub, Driver=ehci-pci/8p, 480M
    ID 1d6b:0002
    /sys/bus/usb/devices/usb1  /dev/bus/usb/001/001
    |__ Port 1: Dev 2, If 0, Class=, Driver=hub/4p, 480M
        ID 8087:07db
        /sys/bus/usb/devices/1-1  /dev/bus/usb/001/002
        |__ Port 1: Dev 3, If 0, Class=, Driver=usb-storage, 480M
            ID f400:f400
            /sys/bus/usb/devices/1-1.1  /dev/bus/usb/001/003

Here is the output from the host with as much info included as possible:

# lsusb -ciue
|__usb1          1d6b:0002:0310 09  2.00  480MBit/s 0mA 1IF  (ehci_hcd 0000:00:16.0) hub
  |__1-1         8087:07db:0003 09  2.00  480MBit/s 0mA 1IF  ( ffffffd1ffffffb2ffffffdbffffffad) hub
    |__1-1.1     f400:f400:0100 00  2.00  480MBit/s 200mA 1IF  (Synology DiskStation 7F008652656DAE99)
                   (EP) 00: Control  attr 00 len 07 max 040
   1-1.1:1.0      (IF) 08:06:50 2EPs () usb-storage host14 (synoboot)
                   (EP) 02: Bulk  attr 02 len 07 max 200
                   (EP) 81: Bulk  attr 02 len 07 max 200
|__usb3          1d6b:0003:0310 09  3.00 5000MBit/s 0mA 1IF  (Linux 3.10.108 etxhci_hcd-170202 Etron xHCI Host Controller 0000:09:00.0) hub
  |__3-4         18d1:9302:0100 00  3.10 5000MBit/s 896mA 1IF  ( ffffffd1ffffffb2ffffffdbffffffa0)
                   (EP) 00: Control  attr 00 len 07 max 200
  3-4:1.0         (IF) ff:ff:ff 6EPs (Vendor Specific) usbfs
                   (EP) 01: Bulk  attr 02 len 07 max 400
                   (EP) 02: Bulk  attr 02 len 07 max 400
                   (EP) 03: Bulk  attr 02 len 07 max 400
                   (EP) 81: Bulk  attr 02 len 07 max 400
                   (EP) 82: Bulk  attr 02 len 07 max 400
                   (EP) 83: Interrupt (1ms) attr 03 len 07 max 040

It looks like on this NAS the Coral's ID is 18d1:9302:0100. I see it's listed as using the usbfs driver. I don't know why it said None before.

Here is the dmesg -T output from when I connected the Coral this morning and when I started and stopped the docker container just now (then moved the Coral back to the other NAS):

[Tue Aug 16 07:43:03 2022] usb 3-4: new SuperSpeed USB device number 9 using etxhci_hcd-170202
[Tue Aug 16 07:43:03 2022] Got empty serial number. Generate serial number from product.
[Tue Aug 16 07:43:03 2022] drivers/usb/core/ethub.c (2055) Same device found. Change serial to ffffffd1ffffffb2ffffffdbffffffa0
[Tue Aug 16 12:16:48 2022] aufs au_opts_verify:1570:dockerd[11799]: dirperm1 breaks the protection by the permission bits on the lower branch
[Tue Aug 16 12:16:49 2022] aufs au_opts_verify:1570:dockerd[11799]: dirperm1 breaks the protection by the permission bits on the lower branch
[Tue Aug 16 12:16:49 2022] aufs au_opts_verify:1570:dockerd[11798]: dirperm1 breaks the protection by the permission bits on the lower branch
[Tue Aug 16 12:16:49 2022] device docker307ffdf entered promiscuous mode
[Tue Aug 16 12:16:49 2022] IPv6: ADDRCONF(NETDEV_UP): docker307ffdf: link is not ready
[Tue Aug 16 12:16:50 2022] docker0: port 1(docker307ffdf) entered disabled state
[Tue Aug 16 12:16:50 2022] device docker307ffdf left promiscuous mode
[Tue Aug 16 12:16:50 2022] docker0: port 1(docker307ffdf) entered disabled state
[Tue Aug 16 12:17:15 2022] aufs au_opts_verify:1570:dockerd[11798]: dirperm1 breaks the protection by the permission bits on the lower branch
[Tue Aug 16 12:17:15 2022] aufs au_opts_verify:1570:dockerd[11798]: dirperm1 breaks the protection by the permission bits on the lower branch
[Tue Aug 16 12:17:15 2022] aufs au_opts_verify:1570:dockerd[11828]: dirperm1 breaks the protection by the permission bits on the lower branch
[Tue Aug 16 12:17:15 2022] device docker98e4ea0 entered promiscuous mode
[Tue Aug 16 12:17:15 2022] IPv6: ADDRCONF(NETDEV_UP): docker98e4ea0: link is not ready
[Tue Aug 16 12:17:16 2022] IPv6: ADDRCONF(NETDEV_CHANGE): docker98e4ea0: link becomes ready
[Tue Aug 16 12:17:17 2022] docker0: port 1(docker98e4ea0) entered forwarding state
[Tue Aug 16 12:17:17 2022] docker0: port 1(docker98e4ea0) entered forwarding state
[Tue Aug 16 12:17:28 2022] usb 3-4: reset SuperSpeed USB device number 9 using etxhci_hcd-170202
[Tue Aug 16 12:17:30 2022] etxhci_hcd-170202 0000:09:00.0: Signal while waiting for reset device command
[Tue Aug 16 12:17:30 2022] etxhci_hcd-170202 0000:09:00.0: Signal while waiting for address device command
[Tue Aug 16 12:17:30 2022] usb 3-4: reset SuperSpeed USB device number 9 using etxhci_hcd-170202
[Tue Aug 16 12:17:30 2022] usb 3-4: device firmware changed
[Tue Aug 16 12:17:30 2022] usb 3-4: USB disconnect, device number 9
[Tue Aug 16 12:17:31 2022] etxhci_hcd-170202 0000:09:00.0: ERROR: unexpected command completion code 0x0.
[Tue Aug 16 12:17:32 2022] usb 3-4: new SuperSpeed USB device number 10 using etxhci_hcd-170202
[Tue Aug 16 12:17:32 2022] docker0: port 1(docker98e4ea0) entered forwarding state
[Tue Aug 16 12:17:32 2022] Got empty serial number. Generate serial number from product.
[Tue Aug 16 12:17:32 2022] drivers/usb/core/ethub.c (2055) Same device found. Change serial to ffffffd1ffffffb2ffffffdbffffffa0
[Tue Aug 16 12:17:33 2022] docker0: port 1(docker98e4ea0) entered disabled state
[Tue Aug 16 12:17:33 2022] docker0: port 1(docker98e4ea0) entered disabled state
[Tue Aug 16 12:17:33 2022] device docker98e4ea0 left promiscuous mode
[Tue Aug 16 12:17:33 2022] docker0: port 1(docker98e4ea0) entered disabled state
[Tue Aug 16 12:17:41 2022] aufs au_opts_verify:1570:dockerd[12218]: dirperm1 breaks the protection by the permission bits on the lower branch
[Tue Aug 16 12:17:41 2022] aufs au_opts_verify:1570:dockerd[12218]: dirperm1 breaks the protection by the permission bits on the lower branch
[Tue Aug 16 12:17:41 2022] aufs au_opts_verify:1570:dockerd[11893]: dirperm1 breaks the protection by the permission bits on the lower branch
[Tue Aug 16 12:17:41 2022] device docker732b041 entered promiscuous mode
[Tue Aug 16 12:17:41 2022] IPv6: ADDRCONF(NETDEV_UP): docker732b041: link is not ready
[Tue Aug 16 12:17:42 2022] IPv6: ADDRCONF(NETDEV_CHANGE): docker732b041: link becomes ready
[Tue Aug 16 12:17:42 2022] docker0: port 1(docker732b041) entered forwarding state
[Tue Aug 16 12:17:42 2022] docker0: port 1(docker732b041) entered forwarding state
[Tue Aug 16 12:17:46 2022] etxhci_hcd-170202 0000:09:00.0: WARN Event TRB for slot 1 ep 1 with no TDs queued?
[Tue Aug 16 12:17:46 2022] etxhci_hcd-170202 0000:09:00.0: WARN Event TRB for slot 1 ep 2 with no TDs queued?
[Tue Aug 16 12:17:46 2022] etxhci_hcd-170202 0000:09:00.0: WARN Event TRB for slot 1 ep 3 with no TDs queued?
[Tue Aug 16 12:17:46 2022] etxhci_hcd-170202 0000:09:00.0: WARN Event TRB for slot 1 ep 4 with no TDs queued?
[Tue Aug 16 12:17:46 2022] etxhci_hcd-170202 0000:09:00.0: WARN Event TRB for slot 1 ep 5 with no TDs queued?
[Tue Aug 16 12:17:46 2022] etxhci_hcd-170202 0000:09:00.0: WARN Event TRB for slot 1 ep 6 with no TDs queued?
[Tue Aug 16 12:17:48 2022] usb 3-4: reset SuperSpeed USB device number 10 using etxhci_hcd-170202
[Tue Aug 16 12:17:57 2022] docker0: port 1(docker732b041) entered forwarding state
[Tue Aug 16 12:30:05 2022] docker0: port 1(docker732b041) entered disabled state
[Tue Aug 16 12:30:05 2022] docker0: port 1(docker732b041) entered disabled state
[Tue Aug 16 12:30:05 2022] device docker732b041 left promiscuous mode
[Tue Aug 16 12:30:05 2022] docker0: port 1(docker732b041) entered disabled state
[Tue Aug 16 12:30:06 2022] auplink[21635]: segfault at 7ffc841db7b8 ip 00007f0aa081f1b9 sp 00007ffc841db7c0 error 6 in libc-2.26.so[7f0aa0739000+1a8000]
[Tue Aug 16 12:30:10 2022] usb 3-4: USB disconnect, device number 10

So it seems like the older NAS is using a different driver than the new one for some reason. Do you know how the host would determine which driver to use, and if there's anything I can do to make them work the same way?

I'm sorry if this is outside the scope of this repo. It's definitely beyond my expertise, and I don't know where else to ask for help.

It looks like the driver used by the new NAS (etxhci_hcd) has known issues. This seems like a similar issue, only with a USB drive that doesn't get recognized initially: https://community.synology.com/enu/forum/1/post/125478

There's also a possible solution in there to fix it:

cd /sys/bus/pci/drivers/etxhci_hcd-170202
sudo -s
echo "0000:04:00.0" > unbind
echo "0000:04:00.0" > bind

Although, if I understand it correctly, you should replace 0000:04:00.0 with 0000:09:00.4 (from your comment here).

Something else strange... I just connected the coral to the old NAS and ran lsusb -ciue and it does not list a driver.

# lsusb -ciue
|__usb1          1d6b:0002:0310 09  2.00  480MBit/s 0mA 1IF  (ehci_hcd 0000:00:16.0) hub
  |__1-1         8087:07db:0003 09  2.00  480MBit/s 0mA 1IF  ( ffffffd1ffffffb2ffffffdbffffffad) hub
    |__1-1.1     f400:f400:0100 00  2.00  480MBit/s 200mA 1IF  (Synology DiskStation 7F008652656DAE99)
                   (EP) 00: Control  attr 00 len 07 max 040
   1-1.1:1.0      (IF) 08:06:50 2EPs () usb-storage host14 (synoboot)
                   (EP) 02: Bulk  attr 02 len 07 max 200
                   (EP) 81: Bulk  attr 02 len 07 max 200
|__usb3          1d6b:0003:0310 09  3.00 5000MBit/s 0mA 1IF  (Linux 3.10.108 etxhci_hcd-170202 Etron xHCI Host Controller 0000:09:00.0) hub
  |__3-4         1a6e:089a:0100 00  3.10 5000MBit/s 896mA 1IF  ( ffffffd1ffffffb2ffffffdbffffffa0)
                   (EP) 00: Control  attr 00 len 07 max 200
  3-4:1.0         (IF) fe:01:02 0EPs ()

This was in dmesg -T when I connected it:

[Tue Aug 16 12:53:04 2022] etxhci_hcd-170202 0000:09:00.0: ERROR: unexpected command completion code 0x0.
[Tue Aug 16 12:53:05 2022] usb 3-4: new SuperSpeed USB device number 12 using etxhci_hcd-170202
[Tue Aug 16 12:53:05 2022] Got empty serial number. Generate serial number from product.
[Tue Aug 16 12:53:05 2022] drivers/usb/core/ethub.c (2055) Same device found. Change serial to ffffffd1ffffffb2ffffffdbffffffa0

Then I started the frigate docker container, and after a few seconds the usb3 device disappeared from the lsusb output altogether. I checked the frigate log and it DID NOT detect the Coral.

I disconnected and reconnected the Coral, and started frigate again. This time it worked, but in lsusb output I dont' see a driver listed where it said usbfs before.

# lsusb -cuie
|__usb1          1d6b:0002:0310 09  2.00  480MBit/s 0mA 1IF  (ehci_hcd 0000:00:16.0) hub
  |__1-1         8087:07db:0003 09  2.00  480MBit/s 0mA 1IF  ( ffffffd1ffffffb2ffffffdbffffffad) hub
    |__1-1.1     f400:f400:0100 00  2.00  480MBit/s 200mA 1IF  (Synology DiskStation 7F008652656DAE99)
                   (EP) 00: Control  attr 00 len 07 max 040
   1-1.1:1.0      (IF) 08:06:50 2EPs () usb-storage host14 (synoboot)
                   (EP) 02: Bulk  attr 02 len 07 max 200
                   (EP) 81: Bulk  attr 02 len 07 max 200
|__usb3          1d6b:0003:0310 09  3.00 5000MBit/s 0mA 1IF  (Linux 3.10.108 etxhci_hcd-170202 Etron xHCI Host Controller 0000:09:00.0) hub
  |__3-4         18d1:9302:0100 00  3.10 5000MBit/s 896mA 1IF  ( ffffffd1ffffffb2ffffffdbffffffa0)
                   (EP) 00: Control  attr 00 len 07 max 200
  3-4:1.0         (IF) ff:ff:ff 6EPs (Vendor Specific)
                   (EP) 01: Bulk  attr 02 len 07 max 400
                   (EP) 02: Bulk  attr 02 len 07 max 400
                   (EP) 03: Bulk  attr 02 len 07 max 400
                   (EP) 81: Bulk  attr 02 len 07 max 400
                   (EP) 82: Bulk  attr 02 len 07 max 400
                   (EP) 83: Interrupt (1ms) attr 03 len 07 max 040

I ran lsusb in the container again, and it did have the driver listed in there.

# lsusb -tvvv
/:  Bus 03.Port 1: Dev 1, Class=root_hub, Driver=etxhci_hcd-170202/4p, 5000M
    ID 1d6b:0003
    /sys/bus/usb/devices/usb3  /dev/bus/usb/003/001
    |__ Port 4: Dev 15, If 0, Class=, Driver=usbfs, 5000M
        ID 18d1:9302
        /sys/bus/usb/devices/3-4  /dev/bus/usb/003/015
/:  Bus 02.Port 1: Dev 1, Class=root_hub, Driver=etxhci_hcd-170202/4p, 480M
    ID 1d6b:0002
    /sys/bus/usb/devices/usb2  /dev/bus/usb/002/001
/:  Bus 01.Port 1: Dev 1, Class=root_hub, Driver=ehci-pci/8p, 480M
    ID 1d6b:0002
    /sys/bus/usb/devices/usb1  /dev/bus/usb/001/001
    |__ Port 1: Dev 2, If 0, Class=, Driver=hub/4p, 480M
        ID 8087:07db
        /sys/bus/usb/devices/1-1  /dev/bus/usb/001/002
        |__ Port 1: Dev 3, If 0, Class=, Driver=usb-storage, 480M
            ID f400:f400
            /sys/bus/usb/devices/1-1.1  /dev/bus/usb/001/003

Then I ran lsusb outside the container again and the driver is listed.

# lsusb -cuie
|__usb1          1d6b:0002:0310 09  2.00  480MBit/s 0mA 1IF  (ehci_hcd 0000:00:16.0) hub
  |__1-1         8087:07db:0003 09  2.00  480MBit/s 0mA 1IF  ( ffffffd1ffffffb2ffffffdbffffffad) hub
    |__1-1.1     f400:f400:0100 00  2.00  480MBit/s 200mA 1IF  (Synology DiskStation 7F008652656DAE99)
                   (EP) 00: Control  attr 00 len 07 max 040
   1-1.1:1.0      (IF) 08:06:50 2EPs () usb-storage host14 (synoboot)
                   (EP) 02: Bulk  attr 02 len 07 max 200
                   (EP) 81: Bulk  attr 02 len 07 max 200
|__usb3          1d6b:0003:0310 09  3.00 5000MBit/s 0mA 1IF  (Linux 3.10.108 etxhci_hcd-170202 Etron xHCI Host Controller 0000:09:00.0) hub
  |__3-4         18d1:9302:0100 00  3.10 5000MBit/s 896mA 1IF  ( ffffffd1ffffffb2ffffffdbffffffa0)
                   (EP) 00: Control  attr 00 len 07 max 200
  3-4:1.0         (IF) ff:ff:ff 6EPs (Vendor Specific) usbfs
                   (EP) 01: Bulk  attr 02 len 07 max 400
                   (EP) 02: Bulk  attr 02 len 07 max 400
                   (EP) 03: Bulk  attr 02 len 07 max 400
                   (EP) 81: Bulk  attr 02 len 07 max 400
                   (EP) 82: Bulk  attr 02 len 07 max 400
                   (EP) 83: Interrupt (1ms) attr 03 len 07 max 040

It's like there are gremlins in there. I see your last post about a known issue and possible solution, so I will try that now. I figured I might as well send this anyway since I put it all together.

I see I mixed things up: the working NAS uses the etxhci_hcd driver, the non-working NAS uses the xhci-hcd driver. So the article may not be relevant.

I also noticed the wildly different Linux versions that each NAS is running:

New uses 4.4.180
Old uses 3.10.108

What I don't understand yet is how Docker is accessing the USB device. From what I know, you have to explicitly tell Docker which devices it's allowed to access, and/or pass /dev/bus/usb into the container and use --privileged.

Yes, I'm passing /dev/bus/usb to the docker container and using --privileged. I couldn't get it to work passing a specific device, and then there's the issue of the tty device number changing after a reboot.

Frigate inspects all usb devices to find a Coral Edge TPU. Here's the relevant config yaml:

detectors:
  coral:
    type: edgetpu
    device: usb

I checked that article and it seems to be documenting a way to disconnect/reconnect a USB device remotely. I'm not sure it's indicating there's a problem with the driver. I tried going through that unbind/bind process with the relevant xhci-hcd driver and it didn't make a difference.

frigate    | [2022-08-16 14:32:15] frigate.edgetpu                INFO    : Attempting to load TPU as usb
frigate    | [2022-08-16 14:32:16] frigate.edgetpu                ERROR   : No EdgeTPU was detected. If you do not have a Coral device yet, you must configure CPU detectors.
frigate    | Process detector:coral:
frigate    | Traceback (most recent call last):
frigate    |   File "/usr/lib/python3/dist-packages/tflite_runtime/interpreter.py", line 160, in load_delegate
frigate    |     delegate = Delegate(library, options)
frigate    |   File "/usr/lib/python3/dist-packages/tflite_runtime/interpreter.py", line 119, in __init__
frigate    |     raise ValueError(capture.message)
frigate    | ValueError
frigate    |
frigate    | During handling of the above exception, another exception occurred:
frigate    |
frigate    | Traceback (most recent call last):
frigate    |   File "/usr/lib/python3.8/multiprocessing/process.py", line 315, in _bootstrap
frigate    |     self.run()
frigate    |   File "/usr/lib/python3.8/multiprocessing/process.py", line 108, in run
frigate    |     self._target(*self._args, **self._kwargs)
frigate    |   File "/opt/frigate/frigate/edgetpu.py", line 136, in run_detector
frigate    |     object_detector = LocalObjectDetector(
frigate    |   File "/opt/frigate/frigate/edgetpu.py", line 44, in __init__
frigate    |     edge_tpu_delegate = load_delegate("libedgetpu.so.1.0", device_config)
frigate    |   File "/usr/lib/python3/dist-packages/tflite_runtime/interpreter.py", line 162, in load_delegate
frigate    |     raise ValueError('Failed to load delegate from {}\n{}'.format(
frigate    | ValueError: Failed to load delegate from libedgetpu.so.1.0

# lsusb -cuie
|__usb1          1d6b:0002:0404 09  2.00  480MBit/s 0mA 1IF  (Linux 4.4.180+ xhci-hcd xHCI Host Controller 0000:09:00.4) hub
  |__1-2         f400:f400:0100 00  2.00  480MBit/s 200mA 1IF  (Synology DiskStation 6500228E14345A35)
                   (EP) 00: Control  attr 00 len 07 max 040
  1-2:1.0         (IF) 08:06:50 2EPs () usb-storage host11 (synoboot)
                   (EP) 02: Bulk  attr 02 len 07 max 200
                   (EP) 81: Bulk  attr 02 len 07 max 200
|__usb3          1d6b:0002:0404 09  2.00  480MBit/s 0mA 1IF  (Linux 4.4.180+ xhci-hcd xHCI Host Controller 0000:09:00.3) hub
  |__3-1         0764:0501:0001 00  2.00   12MBit/s 2mA 1IF  (CPS CP1500PFCLCD 000000000000)
                   (EP) 00: Control  attr 00 len 07 max 040
  3-1:1.0         (IF) 03:00:00 1EP  () usbfs
                   (EP) 81: Interrupt (10ms) attr 03 len 07 max 040
|__usb4          1d6b:0003:0404 09  3.00 5000MBit/s 0mA 1IF  (Linux 4.4.180+ xhci-hcd xHCI Host Controller 0000:09:00.3) hub
  |__4-3         1a6e:089a:0100 00  3.10 5000MBit/s 896mA 1IF  ( ffffffd1ffffffb2ffffffdbffffffad)
                   (EP) 00: Control  attr 00 len 07 max 200
  4-3:1.0         (IF) fe:01:02 0EPs ()

Note: I moved the Coral to a back USB port because I was hopeful it was going to work, so it's in usb4 now.

How I understood the article, the device didn't get recognized initially, until it was unbound and bound again. I would try running that on the host OS, not inside the container (unbind it, bind it, then restart the container).

Looking at the Frigate docs, you can also be more specific on which USB device it should use: https://docs.frigate.video/configuration/detectors/#multiple-usb-corals

Have you tried experimenting with that configuration option?

I will continue trying the unbind/bind process a few more times to see if anything is initialized differently. I did run it at the host level before, and then restarted the docker container.

I have not tried changing the frigate config, because my understanding is the device numbers are not USB IDs, rather they reference the Nth Coral device (https://coral.ai/docs/edgetpu/multiple-edgetpu/#using-the-tensorflow-lite-python-api). So I would have to put 1 regardless of which USB port it's in, since I only have one Coral device attached.

I also tried submitting a Synology support case, even though I am sure they will just tell me the device is unsupported. It's worth a shot, I guess. I think it's crazy they think they can decide what people should use their devices for.

I'm having no luck with re-binding. It's working, as I can see the the devices and hubs disconnecting and reconnecting in dmesg. It's just not having any impact on how the device is listed in lsusb or availability in the docker container.

[Tue Aug 16 15:35:43 2022] xhci_hcd 0000:09:00.4: remove, state 1
[Tue Aug 16 15:35:43 2022] usb usb2: USB disconnect, device number 1
[Tue Aug 16 15:35:43 2022] usb 2-1: USB disconnect, device number 2
[Tue Aug 16 15:35:43 2022] xhci_hcd 0000:09:00.4: USB bus 2 deregistered
[Tue Aug 16 15:35:43 2022] xhci_hcd 0000:09:00.4: remove, state 1
[Tue Aug 16 15:35:43 2022] usb usb1: USB disconnect, device number 1
[Tue Aug 16 15:35:43 2022] usb 1-2: USB disconnect, device number 2
[Tue Aug 16 15:35:43 2022] xhci_hcd 0000:09:00.4: USB bus 1 deregistered
[Tue Aug 16 15:36:00 2022] xhci_hcd 0000:09:00.4: xHCI Host Controller
[Tue Aug 16 15:36:00 2022] xhci_hcd 0000:09:00.4: new USB bus registered, assigned bus number 1
[Tue Aug 16 15:36:00 2022] xhci_hcd 0000:09:00.4: hcc params 0x0260ffe5 hci version 0x110 quirks 0x00000410
[Tue Aug 16 15:36:00 2022] hub 1-0:1.0: USB hub found
[Tue Aug 16 15:36:00 2022] hub 1-0:1.0: 2 ports detected
[Tue Aug 16 15:36:00 2022] host 0000:09:00.4 port 1 has Vbus GPIO#91 with polarity ACTIVE_HIGH
[Tue Aug 16 15:36:00 2022] host 0000:09:00.4 port 2 has Vbus GPIO#11 with polarity ACTIVE_HIGH
[Tue Aug 16 15:36:00 2022] xhci_hcd 0000:09:00.4: xHCI Host Controller
[Tue Aug 16 15:36:00 2022] xhci_hcd 0000:09:00.4: new USB bus registered, assigned bus number 2
[Tue Aug 16 15:36:00 2022] xhci_hcd 0000:09:00.4: Host supports USB 3.1 Enhanced SuperSpeed
[Tue Aug 16 15:36:00 2022] usb usb2: We don't know the algorithms for LPM for this host, disabling LPM.
[Tue Aug 16 15:36:00 2022] hub 2-0:1.0: USB hub found
[Tue Aug 16 15:36:00 2022] hub 2-0:1.0: 1 port detected
[Tue Aug 16 15:36:00 2022] host 0000:09:00.4 port 1 has Vbus GPIO#91 with polarity ACTIVE_HIGH
[Tue Aug 16 15:36:00 2022] usb 1-2: new high-speed USB device number 2 using xhci_hcd
[Tue Aug 16 15:36:00 2022] usb-storage 1-2:1.0: USB Mass Storage device detected
[Tue Aug 16 15:36:00 2022] scsi host13: usb-storage 1-2:1.0
[Tue Aug 16 15:36:01 2022] usb 2-1: new SuperSpeed USB device number 2 using xhci_hcd
[Tue Aug 16 15:36:01 2022] Got empty serial number. Generate serial number from product.

FYI for anyone who happens to stumble across this thread...

I was able to get the Coral USB Accelerator working! It turns out the issue is with how the docker image is reading USB devices, and the image provided here works for me. "It is based on the official upstream frigate image but recompiles libusb1 without udev support."

Thank you again for all of the help, @robertklep.

robertklep / dsm7-usb-serial-drivers

DS1821+ / V1000 Troubleshooting #30