victronenergy / venus

Victron Energy Unix/Linux OS
https://github.com/victronenergy/venus/wiki
589 stars 75 forks source link

Cerbo: ftdi usb issue at power up (?) and not recovered #621

Closed mpvader closed 4 years ago

mpvader commented 4 years ago

On Lucian his system: https://vrm.victronenergy.com/installation/47448/overview

the grid meter is connected to the missing ftdi usb.

Venus OS v2.53

and there is another ftdi usb rs485 interface, connected to the IMT meteorological sensor - which díd survive the boot and was working properly.

dmesg output below. At [168309.247999], the ftdi cable was unplugged and replugged by lucian. Before, and after, that, the leds on it were blinking.

[    0.000000] Booting Linux on physical CPU 0x0
[    0.000000] Linux version 4.19.87 (oe-user@oe-host) (gcc version 7.3.0 (GCC)) #1 SMP Sun Apr 5 13:37:21 UTC 2020
[    0.000000] CPU: ARMv7 Processor [410fc074] revision 4 (ARMv7), cr=10c5387d
[    0.000000] CPU: div instructions available: patching division code
[    0.000000] CPU: PIPT / VIPT nonaliasing data cache, VIPT aliasing instruction cache
[    0.000000] OF: fdt: Machine model: Cerbo GX
[    0.000000] Memory policy: Data cache writealloc
[    0.000000] Reserved memory: created CMA memory pool at 0x4a000000, size 96 MiB
[    0.000000] OF: reserved mem: initialized node cma@4a000000, compatible id shared-dma-pool
[    0.000000] On node 0 totalpages: 261376
[    0.000000]   Normal zone: 1536 pages used for memmap
[    0.000000]   Normal zone: 0 pages reserved
[    0.000000]   Normal zone: 196608 pages, LIFO batch:63
[    0.000000]   HighMem zone: 64768 pages, LIFO batch:15
[    0.000000] psci: probing for conduit method from DT.
[    0.000000] psci: Using PSCI v0.1 Function IDs from DT
[    0.000000] random: get_random_bytes called from start_kernel+0x9c/0x3f4 with crng_init=0
[    0.000000] percpu: Embedded 15 pages/cpu s31116 r8192 d22132 u61440
[    0.000000] pcpu-alloc: s31116 r8192 d22132 u61440 alloc=15*4096
[    0.000000] pcpu-alloc: [0] 0 [0] 1 
[    0.000000] Built 1 zonelists, mobility grouping on.  Total pages: 259840
[    0.000000] Kernel command line: console=ttyS0,115200 root=/dev/mmcblk1p2 rootwait ro rootfstype=ext4 5
[    0.000000] Dentry cache hash table entries: 131072 (order: 7, 524288 bytes)
[    0.000000] Inode-cache hash table entries: 65536 (order: 6, 262144 bytes)
[    0.000000] Memory: 928048K/1045504K available (6144K kernel code, 264K rwdata, 1880K rodata, 1024K init, 241K bss, 19152K reserved, 98304K cma-reserved, 259072K highmem)
[    0.000000] Virtual kernel memory layout:
[    0.000000]     vector  : 0xffff0000 - 0xffff1000   (   4 kB)
[    0.000000]     fixmap  : 0xffc00000 - 0xfff00000   (3072 kB)
[    0.000000]     vmalloc : 0xf0800000 - 0xff800000   ( 240 MB)
[    0.000000]     lowmem  : 0xc0000000 - 0xf0000000   ( 768 MB)
[    0.000000]     pkmap   : 0xbfe00000 - 0xc0000000   (   2 MB)
[    0.000000]     modules : 0xbf000000 - 0xbfe00000   (  14 MB)
[    0.000000]       .text : 0x(ptrval) - 0x(ptrval)   (7136 kB)
[    0.000000]       .init : 0x(ptrval) - 0x(ptrval)   (1024 kB)
[    0.000000]       .data : 0x(ptrval) - 0x(ptrval)   ( 265 kB)
[    0.000000]        .bss : 0x(ptrval) - 0x(ptrval)   ( 242 kB)
[    0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=2, Nodes=1
[    0.000000] rcu: Hierarchical RCU implementation.
[    0.000000] rcu:     RCU restricting CPUs from NR_CPUS=4 to nr_cpu_ids=2.
[    0.000000] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=2
[    0.000000] NR_IRQS: 16, nr_irqs: 16, preallocated irqs: 16
[    0.000000] GIC: Using split EOI/Deactivate mode
[    0.000000] arch_timer: cp15 timer(s) running at 24.00MHz (phys).
[    0.000000] clocksource: arch_sys_counter: mask: 0xffffffffffffff max_cycles: 0x588fe9dc0, max_idle_ns: 440795202592 ns
[    0.000008] sched_clock: 56 bits at 24MHz, resolution 41ns, wraps every 4398046511097ns
[    0.000020] Switching to timer-based delay loop, resolution 41ns
[    0.000349] clocksource: timer: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 79635851949 ns
[    0.000608] clocksource: hstimer: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 6370868154 ns
[    0.000860] Console: colour dummy device 80x30
[    0.000928] Calibrating delay loop (skipped), value calculated using timer frequency.. 48.00 BogoMIPS (lpj=240000)
[    0.000943] pid_max: default: 32768 minimum: 301
[    0.001161] Mount-cache hash table entries: 2048 (order: 1, 8192 bytes)
[    0.001177] Mountpoint-cache hash table entries: 2048 (order: 1, 8192 bytes)
[    0.001847] CPU: Testing write buffer coherency: ok
[    0.002246] /cpus/cpu@0 missing clock-frequency property
[    0.002267] /cpus/cpu@1 missing clock-frequency property
[    0.002281] CPU0: thread -1, cpu 0, socket 0, mpidr 80000000
[    0.002894] Setting up static identity map for 0x40100000 - 0x40100060
[    0.003063] rcu: Hierarchical SRCU implementation.
[    0.004045] smp: Bringing up secondary CPUs ...
[    0.014831] CPU1: thread -1, cpu 1, socket 0, mpidr 80000001
[    0.015002] smp: Brought up 1 node, 2 CPUs
[    0.015020] SMP: Total of 2 processors activated (96.00 BogoMIPS).
[    0.015027] CPU: All CPU(s) started in HYP mode.
[    0.015032] CPU: Virtualization extensions available.
[    0.016173] devtmpfs: initialized
[    0.022470] VFP support v0.3: implementor 41 architecture 2 part 30 variant 7 rev 4
[    0.022726] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 ns
[    0.022759] futex hash table entries: 512 (order: 3, 32768 bytes)
[    0.026320] pinctrl core: initialized pinctrl subsystem
[    0.027271] NET: Registered protocol family 16
[    0.028627] DMA: preallocated 256 KiB pool for atomic coherent allocations
[    0.029641] cpuidle: using governor ladder
[    0.029693] cpuidle: using governor menu
[    0.029912] hw-breakpoint: found 5 (+1 reserved) breakpoint and 4 watchpoint registers.
[    0.029923] hw-breakpoint: maximum watchpoint size is 8 bytes.
[    0.044437] cryptd: max_cpu_qlen set to 1000
[    0.046678] SCSI subsystem initialized
[    0.046925] usbcore: registered new interface driver usbfs
[    0.046975] usbcore: registered new interface driver hub
[    0.047073] usbcore: registered new device driver usb
[    0.048646] clocksource: Switched to clocksource arch_sys_counter
[    0.056802] NET: Registered protocol family 2
[    0.057441] tcp_listen_portaddr_hash hash table entries: 512 (order: 0, 6144 bytes)
[    0.057476] TCP established hash table entries: 8192 (order: 3, 32768 bytes)
[    0.057564] TCP bind hash table entries: 8192 (order: 4, 65536 bytes)
[    0.057690] TCP: Hash tables configured (established 8192 bind 8192)
[    0.057824] UDP hash table entries: 512 (order: 2, 16384 bytes)
[    0.057890] UDP-Lite hash table entries: 512 (order: 2, 16384 bytes)
[    0.058110] NET: Registered protocol family 1
[    0.058815] hw perfevents: no interrupt-affinity property for /pmu, guessing.
[    0.059083] hw perfevents: enabled with armv7_cortex_a7 PMU driver, 5 counters available
[    0.061817] Initialise system trusted keyrings
[    0.062075] workingset: timestamp_bits=30 max_order=18 bucket_order=0
[    0.072486] Key type asymmetric registered
[    0.072512] Asymmetric key parser 'x509' registered
[    0.072583] bounce: pool size: 64 pages
[    0.072604] io scheduler noop registered
[    0.072613] io scheduler deadline registered (default)
[    0.074071] sun4i-usb-phy 1c13400.phy: Couldn't get regulator usb0_vbus... Deferring probe
[    0.077742] sun4i-pinctrl 1c20800.pinctrl: initialized sunXi PIO driver
[    0.132697] Serial: 8250/16550 driver, 8 ports, IRQ sharing disabled
[    0.135583] console [ttyS0] disabled
[    0.155904] 1c28000.serial: ttyS0 at MMIO 0x1c28000 (irq = 48, base_baud = 1500000) is a U6_16550A
[    0.751786] console [ttyS0] enabled
[    0.778334] 1c28400.serial: ttyS1 at MMIO 0x1c28400 (irq = 49, base_baud = 1500000) is a U6_16550A
[    0.808490] 1c28800.serial: ttyS2 at MMIO 0x1c28800 (irq = 50, base_baud = 1500000) is a U6_16550A
[    0.817643] serial serial0: tty port ttyS2 registered
[    0.843601] 1c28c00.serial: ttyS3 at MMIO 0x1c28c00 (irq = 51, base_baud = 1500000) is a U6_16550A
[    0.873677] 1c29000.serial: ttyS4 at MMIO 0x1c29000 (irq = 52, base_baud = 1500000) is a U6_16550A
[    0.903759] 1c29400.serial: ttyS5 at MMIO 0x1c29400 (irq = 53, base_baud = 1500000) is a U6_16550A
[    0.933799] 1c29800.serial: ttyS6 at MMIO 0x1c29800 (irq = 54, base_baud = 1500000) is a U6_16550A
[    0.963852] 1c29c00.serial: ttyS7 at MMIO 0x1c29c00 (irq = 55, base_baud = 1500000) is a U6_16550A
[    0.977387] sun4i-backend 1e60000.display-backend: Couldn't find matching frontend, frontend features disabled
[    0.987776] sun4i-drm display-engine: bound 1e60000.display-backend (ops sun4i_backend_ops)
[    0.996174] sun4i-backend 1e40000.display-backend: Couldn't find matching frontend, frontend features disabled
[    1.006473] sun4i-drm display-engine: bound 1e40000.display-backend (ops sun4i_backend_ops)
[    1.015286] sun4i-drm display-engine: No panel or bridge found... RGB output disabled
[    1.023154] sun4i-drm display-engine: bound 1c0c000.lcd-controller (ops sun4i_tcon_ops)
[    1.031518] sun4i-drm display-engine: No panel or bridge found... RGB output disabled
[    1.039383] sun4i-drm display-engine: bound 1c0d000.lcd-controller (ops sun4i_tcon_ops)
[    1.047847] clk_unregister: unregistering prepared clock: hdmi-ddc
[    1.054072] clk_unregister: unregistering prepared clock: hdmi-tmds
[    1.060447] sun4i-drm display-engine: failed to bind 1c16000.hdmi (ops sun4i_hdmi_ops): -517
[    1.069152] sun4i-drm display-engine: Couldn't bind all pipelines components
[    1.076351] sun4i-drm display-engine: master bind failed: -517
[    1.085151] brd: module loaded
[    1.089163] libphy: Fixed MDIO Bus: probed
[    1.094188] ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver
[    1.100741] ehci-platform: EHCI generic platform driver
[    1.106440] ohci_hcd: USB 1.1 'Open' Host Controller (OHCI) Driver
[    1.112664] ohci-platform: OHCI generic platform driver
[    1.119151] sunxi-rtc 1c20d00.rtc: registered as rtc1
[    1.124206] sunxi-rtc 1c20d00.rtc: RTC enabled
[    1.128849] i2c /dev entries driver
[    1.133388] axp20x-i2c 0-0034: AXP20x variant AXP209 found
[    1.145605] ldo1: supplied by regulator-dummy
[    1.150378] ldo2: supplied by regulator-dummy
[    1.155808] ldo3: supplied by regulator-dummy
[    1.161195] ldo4: supplied by regulator-dummy
[    1.165733] ldo5: supplied by regulator-dummy
[    1.171184] dcdc2: supplied by regulator-dummy
[    1.176277] dcdc3: supplied by regulator-dummy
[    1.181220] vdd-sys: Bringing 1250000uV into 1400000-1400000uV
[    1.188439] axp20x-i2c 0-0034: AXP20X driver loaded
[    1.194971] at24 1-0050: 256 byte 24c02 EEPROM, read-only, 0 bytes/write
[    1.204947] rtc-pcf8523 1-0068: rtc core: registered rtc-pcf8523 as rtc0
[    1.213173] at24 2-0050: 256 byte 24c02 EEPROM, read-only, 0 bytes/write
[    1.221547] sunxi-wdt 1c20c90.watchdog: Watchdog enabled (timeout=16 sec, nowayout=1)
[    1.229970] watchdog: watchdog0 running and kernel based pre-userspace handler disabled
[    1.238689] cpu cpu0: Linked as a consumer to regulator.9
[    1.244154] cpu cpu0: Dropping the link to regulator.9
[    1.249570] cpu cpu0: Linked as a consumer to regulator.9
[    1.257330] sunxi-mmc 1c0f000.mmc: Linked as a consumer to regulator.2
[    1.264636] sunxi-mmc 1c0f000.mmc: Got CD GPIO
[    1.294700] sunxi-mmc 1c0f000.mmc: initialized, max. request size: 16384 KB
[    1.302102] sunxi-mmc 1c11000.mmc: Linked as a consumer to regulator.2
[    1.334554] sunxi-mmc 1c11000.mmc: initialized, max. request size: 16384 KB
[    1.342016] sunxi-mmc 1c12000.mmc: Linked as a consumer to regulator.2
[    1.349183] sunxi-mmc 1c12000.mmc: allocated mmc-pwrseq
[    1.363771] random: fast init done
[    1.379794] sunxi-mmc 1c12000.mmc: initialized, max. request size: 16384 KB
[    1.388068] sun4i-ss 1c15000.crypto-engine: Die ID 0
[    1.395859] NET: Registered protocol family 10
[    1.401415] Segment Routing with IPv6
[    1.405200] NET: Registered protocol family 17
[    1.409794] Registering SWP/SWPB emulation handler
[    1.416298] registered taskstats version 1
[    1.420517] Loading compiled-in X.509 certificates
[    1.427767] mmc2: queuing unknown CIS tuple 0x80 (2 bytes)
[    1.434094] mmc1: new DDR MMC card at address 0001
[    1.435748] sun4i-usb-phy 1c13400.phy: Linked as a consumer to regulator.11
[    1.446137] sun4i-usb-phy 1c13400.phy: Linked as a consumer to regulator.12
[    1.447125] mmc2: queuing unknown CIS tuple 0x80 (3 bytes)
[    1.453366] sun4i-usb-phy 1c13400.phy: Linked as a consumer to regulator.13
[    1.460136] mmc2: queuing unknown CIS tuple 0x80 (3 bytes)
[    1.466420] sun4i-backend 1e60000.display-backend: Couldn't find matching frontend, frontend features disabled
[    1.471743] mmcblk1: mmc1:0001 SEM04G 3.69 GiB 
[    1.481634] sun4i-drm display-engine: bound 1e60000.display-backend (ops sun4i_backend_ops)
[    1.486176] mmcblk1boot0: mmc1:0001 SEM04G partition 1 2.00 MiB
[    1.494175] sun4i-backend 1e40000.display-backend: Couldn't find matching frontend, frontend features disabled
[    1.500499] mmcblk1boot1: mmc1:0001 SEM04G partition 2 2.00 MiB
[    1.510438] sun4i-drm display-engine: bound 1e40000.display-backend (ops sun4i_backend_ops)
[    1.518344]  mmcblk1: p1 p2 p3 p4 < p5 p6 >
[    1.524950] sun4i-drm display-engine: No panel or bridge found... RGB output disabled
[    1.529716] mmc2: queuing unknown CIS tuple 0x80 (7 bytes)
[    1.536499] sun4i-drm display-engine: bound 1c0c000.lcd-controller (ops sun4i_tcon_ops)
[    1.546087] mmc2: queuing unknown CIS tuple 0x81 (9 bytes)
[    1.550415] sun4i-drm display-engine: No panel or bridge found... RGB output disabled
[    1.563299] sun4i-drm display-engine: bound 1c0d000.lcd-controller (ops sun4i_tcon_ops)
[    1.566810] mmc2: new high speed SDIO card at address 0001
[    1.572167] sun4i-drm display-engine: bound 1c16000.hdmi (ops sun4i_hdmi_ops)
[    1.584016] [drm] Supports vblank timestamp caching Rev 2 (21.10.2013).
[    1.590643] [drm] No driver support for vblank timestamp query.
[    1.611865] fbcon: Deferring console take-over
[    1.616326] sun4i-drm display-engine: fb0: DRM emulated frame buffer device
[    1.623802] [drm] Initialized sun4i-drm 1.0.0 20150629 for display-engine on minor 0
[    1.632083] ehci-platform 1c14000.usb: EHCI Host Controller
[    1.637687] ehci-platform 1c14000.usb: new USB bus registered, assigned bus number 1
[    1.645842] ehci-platform 1c14000.usb: irq 35, io mem 0x01c14000
[    1.678661] ehci-platform 1c14000.usb: USB 2.0 started, EHCI 1.00
[    1.684981] usb usb1: New USB device found, idVendor=1d6b, idProduct=0002, bcdDevice= 4.19
[    1.693266] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[    1.700492] usb usb1: Product: EHCI Host Controller
[    1.705366] usb usb1: Manufacturer: Linux 4.19.87 ehci_hcd
[    1.710857] usb usb1: SerialNumber: 1c14000.usb
[    1.716000] hub 1-0:1.0: USB hub found
[    1.719834] hub 1-0:1.0: 1 port detected
[    1.724547] ehci-platform 1c1c000.usb: EHCI Host Controller
[    1.730208] ehci-platform 1c1c000.usb: new USB bus registered, assigned bus number 2
[    1.738294] ehci-platform 1c1c000.usb: irq 39, io mem 0x01c1c000
[    1.768664] ehci-platform 1c1c000.usb: USB 2.0 started, EHCI 1.00
[    1.774972] usb usb2: New USB device found, idVendor=1d6b, idProduct=0002, bcdDevice= 4.19
[    1.783260] usb usb2: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[    1.790488] usb usb2: Product: EHCI Host Controller
[    1.795362] usb usb2: Manufacturer: Linux 4.19.87 ehci_hcd
[    1.800855] usb usb2: SerialNumber: 1c1c000.usb
[    1.805954] hub 2-0:1.0: USB hub found
[    1.809774] hub 2-0:1.0: 1 port detected
[    1.814491] ohci-platform 1c14400.usb: Generic Platform OHCI controller
[    1.821180] ohci-platform 1c14400.usb: new USB bus registered, assigned bus number 3
[    1.829307] ohci-platform 1c14400.usb: irq 36, io mem 0x01c14400
[    1.902877] usb usb3: New USB device found, idVendor=1d6b, idProduct=0001, bcdDevice= 4.19
[    1.911161] usb usb3: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[    1.918374] usb usb3: Product: Generic Platform OHCI controller
[    1.924315] usb usb3: Manufacturer: Linux 4.19.87 ohci_hcd
[    1.929813] usb usb3: SerialNumber: 1c14400.usb
[    1.934914] hub 3-0:1.0: USB hub found
[    1.938747] hub 3-0:1.0: 1 port detected
[    1.943481] ohci-platform 1c1c400.usb: Generic Platform OHCI controller
[    1.950173] ohci-platform 1c1c400.usb: new USB bus registered, assigned bus number 4
[    1.958221] ohci-platform 1c1c400.usb: irq 40, io mem 0x01c1c400
[    2.032854] usb usb4: New USB device found, idVendor=1d6b, idProduct=0001, bcdDevice= 4.19
[    2.041143] usb usb4: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[    2.048356] usb usb4: Product: Generic Platform OHCI controller
[    2.054296] usb usb4: Manufacturer: Linux 4.19.87 ohci_hcd
[    2.059793] usb usb4: SerialNumber: 1c1c400.usb
[    2.064911] hub 4-0:1.0: USB hub found
[    2.068731] hub 4-0:1.0: 1 port detected
[    2.073521] usb_phy_generic usb_phy_generic.0.auto: usb_phy_generic.0.auto supply vcc not found, using dummy regulator
[    2.084345] usb_phy_generic usb_phy_generic.0.auto: Linked as a consumer to regulator.0
[    2.092709] musb-hdrc musb-hdrc.1.auto: DMA mask not set
[    2.098271] musb-hdrc musb-hdrc.1.auto: MUSB HDRC host driver
[    2.104053] musb-hdrc musb-hdrc.1.auto: new USB bus registered, assigned bus number 5
[    2.112125] usb usb5: New USB device found, idVendor=1d6b, idProduct=0002, bcdDevice= 4.19
[    2.120419] usb usb5: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[    2.127634] usb usb5: Product: MUSB HDRC host driver
[    2.132607] usb usb5: Manufacturer: Linux 4.19.87 musb-hcd
[    2.138087] usb usb5: SerialNumber: musb-hdrc.1.auto
[    2.143660] hub 5-0:1.0: USB hub found
[    2.147488] hub 5-0:1.0: 1 port detected
[    2.152663] input: button as /devices/platform/button/input/input0
[    2.160490] rtc-pcf8523 1-0068: setting system clock to 2020-04-10 10:59:22 UTC (1586516362)
[    2.171933] EXT4-fs (mmcblk1p2): INFO: recovery required on readonly filesystem
[    2.178719] usb 2-1: new high-speed USB device number 2 using ehci-platform
[    2.179299] EXT4-fs (mmcblk1p2): write access will be enabled during recovery
[    2.380506] usb 2-1: New USB device found, idVendor=05e3, idProduct=0608, bcdDevice=32.98
[    2.388738] usb 2-1: New USB device strings: Mfr=0, Product=1, SerialNumber=0
[    2.395882] usb 2-1: Product: USB2.0 Hub
[    2.400749] hub 2-1:1.0: USB hub found
[    2.404865] hub 2-1:1.0: 4 ports detected
[    2.588717] usb 5-1: new high-speed USB device number 2 using musb-hdrc
[    2.728695] usb 2-1.2: new high-speed USB device number 3 using ehci-platform
[    2.768856] usb 5-1: New USB device found, idVendor=0424, idProduct=2422, bcdDevice= 0.a0
[    2.777063] usb 5-1: New USB device strings: Mfr=0, Product=0, SerialNumber=0
[    2.785204] hub 5-1:1.0: USB hub found
[    2.789094] hub 5-1:1.0: 2 ports detected
[    2.855966] random: crng init done
[    2.880540] usb 2-1.2: New USB device found, idVendor=05e3, idProduct=0608, bcdDevice=32.98
[    2.888961] usb 2-1.2: New USB device strings: Mfr=0, Product=1, SerialNumber=0
[    2.896279] usb 2-1.2: Product: USB2.0 Hub
[    2.901644] hub 2-1.2:1.0: USB hub found
[    2.906023] hub 2-1.2:1.0: 4 ports detected
[    2.940784] EXT4-fs (mmcblk1p2): recovery complete
[    2.947529] EXT4-fs (mmcblk1p2): mounted filesystem with ordered data mode. Opts: (null)
[    2.955701] VFS: Mounted root (ext4 filesystem) readonly on device 179:2.
[    2.962638] devtmpfs: mounted
[    2.966780] Freeing unused kernel memory: 1024K
[    2.971495] Run /sbin/init as init process
[    3.108758] usb 5-1.1: new high-speed USB device number 3 using musb-hdrc
[    3.228792] usb 2-1.2.1: new full-speed USB device number 4 using ehci-platform
[    3.239020] usb 5-1.1: config 1 interface 1 altsetting 0 endpoint 0x3 has wMaxPacketSize 0, skipping
[    3.248157] usb 5-1.1: config 1 interface 1 altsetting 0 endpoint 0x83 has wMaxPacketSize 0, skipping
[    3.257641] usb 5-1.1: New USB device found, idVendor=0bda, idProduct=b720, bcdDevice= 2.00
[    3.266047] usb 5-1.1: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[    3.273408] usb 5-1.1: Product: 802.11n WLAN Adapter
[    3.278370] usb 5-1.1: Manufacturer: Realtek
[    3.282660] usb 5-1.1: SerialNumber: 00e04c000001
[    3.288021] usb 5-1.1: skipping disabled interface 0
[    3.293057] usb 5-1.1: skipping disabled interface 1
[    3.333585] EXT4-fs (mmcblk1p5): recovery complete
[    3.339483] EXT4-fs (mmcblk1p5): mounted filesystem with ordered data mode. Opts: (null)
[    3.426366] usb 2-1.2.1: New USB device found, idVendor=0403, idProduct=6001, bcdDevice= 6.00
[    3.435100] usb 2-1.2.1: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[    3.442679] usb 2-1.2.1: Product: FT232R USB UART
[    3.447426] usb 2-1.2.1: Manufacturer: FTDI
[    3.451695] usb 2-1.2.1: SerialNumber: AK08M9PN
[    3.496103] udevd[149]: starting version 3.2.2
[    3.558742] usb 2-1.2.4: new full-speed USB device number 5 using ehci-platform
[    3.568498] udevd[150]: starting eudev-3.2.2
[    3.726366] usb 2-1.2.4: New USB device found, idVendor=0403, idProduct=6001, bcdDevice= 6.00
[    3.735024] usb 2-1.2.4: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[    3.742564] usb 2-1.2.4: Product: FT232R USB UART
[    3.747273] usb 2-1.2.4: Manufacturer: FTDI
[    3.751503] usb 2-1.2.4: SerialNumber: A600NE6Z
[    3.825821] sun4i-emac 1c0b000.ethernet: eth0: at 50c3b723, IRQ 27 MAC: 02:d7:05:40:b0:e7
[    3.839667] sun4i-mdio 1c0b080.mdio: 1c0b080.mdio supply phy not found, using dummy regulator
[    3.848403] sun4i-mdio 1c0b080.mdio: Linked as a consumer to regulator.0
[    3.857604] libphy: sun4i_mii_bus: probed
[    3.938829] pwm-beeper buzzer: buzzer supply amp not found, using dummy regulator
[    3.943831] cfg80211: Loading compiled-in X.509 certificates for regulatory database
[    3.946539] pwm-beeper buzzer: Linked as a consumer to regulator.0
[    3.960696] input: pwm-beeper as /devices/platform/buzzer/input/input1
[    3.981382] usbcore: registered new interface driver usbserial_generic
[    3.988065] usbserial: USB Serial support registered for generic
[    4.013745] cfg80211: Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7'
[    4.027695] usbcore: registered new interface driver ftdi_sio
[    4.030831] Bluetooth: Core ver 2.22
[    4.033631] usbserial: USB Serial support registered for FTDI USB Serial Device
[    4.037159] NET: Registered protocol family 31
[    4.044801] ftdi_sio 2-1.2.1:1.0: FTDI USB Serial Device converter detected
[    4.048954] Bluetooth: HCI device and connection manager initialized
[    4.056047] usb 2-1.2.1: Detected FT232RL
[    4.062285] Bluetooth: HCI socket layer initialized
[    4.071385] Bluetooth: L2CAP socket layer initialized
[    4.072731] platform regulatory.0: Direct firmware load for regulatory.db failed with error -2
[    4.085218] platform regulatory.0: Falling back to syfs fallback for: regulatory.db
[    4.089249] Bluetooth: HCI UART driver ver 2.3
[    4.097458] Bluetooth: HCI UART protocol H4 registered
[    4.103137] Bluetooth: HCI UART protocol Broadcom registered
[    4.109635] hci_uart_bcm serial0-0: serial0-0 supply vbat not found, using dummy regulator
[    4.118239] hci_uart_bcm serial0-0: Linked as a consumer to regulator.0
[    4.125044] hci_uart_bcm serial0-0: serial0-0 supply vddio not found, using dummy regulator
[    4.136226] cerbo-gx-adc 3-0012: Cerbo GX ADC hw 2, fw 4
[    4.142092] backlight gxdisp-2-0051: GX Display backlight rev 2
[    4.152705] 8723bu: loading out-of-tree module taints kernel.
[    4.161196] CAN device driver interface
[    4.171972] Allwinner sunXi mali glue initialized
[    4.177858] input: generic ft5x06 (79) as /devices/platform/soc@1c00000/1c2b400.i2c/i2c-2/2-0038/input/input2
[    4.188908] usb 2-1.2.1: FTDI USB Serial Device converter now attached to ttyUSB0
[    4.195323] sun4i_can 1c2bc00.can: device registered (base=989d2a66, irq=60)
[    4.196575] ftdi_sio 2-1.2.4:1.0: FTDI USB Serial Device converter detected
[    4.205508] Mali: 
[    4.205514] Found Mali GPU Mali-400 MP r1p1
[    4.210752] usb 2-1.2.4: Detected FT232RL
[    4.229849] Mali: 
[    4.229857] 2+0 PP cores initialized
[    4.237778] Mali: 
[    4.237784] Mali device driver loaded
[    4.244104] usb 2-1.2.4: FTDI USB Serial Device converter now attached to ttyUSB1
[    4.263457] brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac43362-sdio for chip BCM43362/1
[    4.319610] usbcore: registered new interface driver rtl8723bu
[    4.394241] Bluetooth: hci0: BCM: chip id 63
[    4.401381] Bluetooth: hci0: BCM: features 0x07
[    4.429765] Bluetooth: hci0: BCM20702A
[    4.433548] Bluetooth: hci0: BCM20702A1 (001.002.014) build 0000
[    4.579698] brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac43362-sdio for chip BCM43362/1
[    5.376134] cfg80211: failed to load regulatory.db
[    5.422019] brcmfmac: brcmf_c_process_clm_blob: no clm_blob available (err=-11), device may have limited channels available
[    5.446812] brcmfmac: brcmf_c_preinit_dcmds: Firmware: BCM43362/1 wl0: May 16 2018 23:42:49 version 5.90.244 FWID 01-0
[    5.572133] rtl8723bu 5-1.1:1.2 disabled-wlan0: renamed from wlan0
[    5.619176] rtl8723bu 5-1.1:1.2 ap0: renamed from wlan1
[    5.659181] brcmfmac mmc2:0001:1 wifi0: renamed from wlan2
[    7.411105] Bluetooth: hci0: BCM20702A1 (001.002.014) build 0000
[    7.419352] Bluetooth: hci0: BCM: Using default device address (20:70:02:a0:00:00)
[    7.805497] EXT4-fs (mmcblk1p2): re-mounted. Opts: (null)
[    8.726054] watchdog: watchdog0: watchdog did not stop!
[   10.434020] IPv6: ADDRCONF(NETDEV_UP): ap0: link is not ready
[   11.779029] IPv6: ADDRCONF(NETDEV_UP): ll-eth0: link is not ready
[   12.107378] EXT4-fs (mmcblk1p3): mounted filesystem with ordered data mode. Opts: (null)
[   12.178794] device eth0 entered promiscuous mode
[   12.183651] IPv6: ADDRCONF(NETDEV_UP): eth0: link is not ready
[   14.688909] sun4i-emac 1c0b000.ethernet eth0: Link is Up - 100Mbps/Full - flow control off
[   14.698158] IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
[   14.718824] IPv6: ADDRCONF(NETDEV_CHANGE): ll-eth0: link becomes ready
[   19.345278] IPv6: ADDRCONF(NETDEV_UP): can0: link is not ready
[   19.358821] IPv6: ADDRCONF(NETDEV_CHANGE): can0: link becomes ready
[   19.580026] can: controller area network core (rev 20170425 abi 9)
[   19.586357] NET: Registered protocol family 29
[   19.634342] can: raw protocol (rev 20170425)
[   19.922087] IPv6: ADDRCONF(NETDEV_UP): wifi0: link is not ready
[   20.133193] slcan: serial line CAN interface driver
[   20.138100] slcan: 10 dynamic interface channels.
[   22.067560] IPv6: ADDRCONF(NETDEV_UP): ap0: link is not ready
[   22.077031] can1: renamed from slcan0
[   22.489117] IPv6: ADDRCONF(NETDEV_CHANGE): ap0: link becomes ready
[   23.558170] potentially unexpected fatal signal 6.
[   23.563218] CPU: 0 PID: 1547 Comm: nc Tainted: G           O      4.19.87 #1
[   23.570671] Hardware name: Allwinner sun7i (A20) Family
[   23.576006] PC is at 0xb6e4aa1c
[   23.579207] LR is at 0xbeb0db10
[   23.582373] pc : [<b6e4aa1c>]    lr : [<beb0db10>]    psr: 00070010
[   23.588709] sp : beb0db10  ip : 00000000  fp : 00000010
[   23.593974] r10: 00016458  r9 : 0000023d  r8 : 0001609c
[   23.599299] r7 : 000000af  r6 : b6f39748  r5 : b6f590d8  r4 : 00000006
[   23.605883] r3 : 00000008  r2 : 00000000  r1 : beb0db10  r0 : 00000000
[   23.612572] Flags: nzcv  IRQs on  FIQs on  Mode USER_32  ISA ARM  Segment user
[   23.619919] Control: 10c5387d  Table: 6dbf406a  DAC: 00000055
[   23.625705] CPU: 0 PID: 1547 Comm: nc Tainted: G           O      4.19.87 #1
[   23.632752] Hardware name: Allwinner sun7i (A20) Family
[   23.638007] [<c010ee34>] (unwind_backtrace) from [<c010bba4>] (show_stack+0x10/0x14)
[   23.645796] [<c010bba4>] (show_stack) from [<c062168c>] (dump_stack+0x94/0xa8)
[   23.653062] [<c062168c>] (dump_stack) from [<c0137a5c>] (get_signal+0x60c/0x72c)
[   23.660503] [<c0137a5c>] (get_signal) from [<c010af7c>] (do_signal+0x1f4/0x4bc)
[   23.667862] [<c010af7c>] (do_signal) from [<c010b40c>] (do_work_pending+0xb8/0xdc)
[   23.675441] [<c010b40c>] (do_work_pending) from [<c010106c>] (slow_work_pending+0xc/0x20)
[   23.683614] Exception stack(0xed80bfb0 to 0xed80bff8)
[   23.688668] bfa0:                                     00000000 beb0db10 00000000 00000008
[   23.696839] bfc0: 00000006 b6f590d8 b6f39748 000000af 0001609c 0000023d 00016458 00000010
[   23.705009] bfe0: 00000000 beb0db10 beb0db10 b6e4aa1c 00070010 00000002
[   32.488748] vcc3v0: disabling
[   32.491747] vcc5v0: disabling
[  515.550920] potentially unexpected fatal signal 6.
[  515.555749] CPU: 1 PID: 7854 Comm: nc Tainted: G           O      4.19.87 #1
[  515.562964] Hardware name: Allwinner sun7i (A20) Family
[  515.568212] PC is at 0xb6e60a1c
[  515.571426] LR is at 0xbef14b10
[  515.574570] pc : [<b6e60a1c>]    lr : [<bef14b10>]    psr: 00070010
[  515.580882] sp : bef14b10  ip : 00000000  fp : 00000010
[  515.586109] r10: 00016458  r9 : 0000023d  r8 : 0001609c
[  515.591398] r7 : 000000af  r6 : b6f4f748  r5 : b6f6f0d8  r4 : 00000006
[  515.597940] r3 : 00000008  r2 : 00000000  r1 : bef14b10  r0 : 00000000
[  515.604534] Flags: nzcv  IRQs on  FIQs on  Mode USER_32  ISA ARM  Segment user
[  515.611808] Control: 10c5387d  Table: 6d7f006a  DAC: 00000055
[  515.617563] CPU: 1 PID: 7854 Comm: nc Tainted: G           O      4.19.87 #1
[  515.624607] Hardware name: Allwinner sun7i (A20) Family
[  515.629861] [<c010ee34>] (unwind_backtrace) from [<c010bba4>] (show_stack+0x10/0x14)
[  515.637614] [<c010bba4>] (show_stack) from [<c062168c>] (dump_stack+0x94/0xa8)
[  515.644840] [<c062168c>] (dump_stack) from [<c0137a5c>] (get_signal+0x60c/0x72c)
[  515.652233] [<c0137a5c>] (get_signal) from [<c010af7c>] (do_signal+0x1f4/0x4bc)
[  515.659538] [<c010af7c>] (do_signal) from [<c010b40c>] (do_work_pending+0xb8/0xdc)
[  515.667106] [<c010b40c>] (do_work_pending) from [<c010106c>] (slow_work_pending+0xc/0x20)
[  515.675277] Exception stack(0xec891fb0 to 0xec891ff8)
[  515.680329] 1fa0:                                     00000000 bef14b10 00000000 00000008
[  515.688503] 1fc0: 00000006 b6f6f0d8 b6f4f748 000000af 0001609c 0000023d 00016458 00000010
[  515.696675] 1fe0: 00000000 bef14b10 bef14b10 b6e60a1c 00070010 00000002
[ 1892.479621] ftdi_sio ttyUSB0: usb_serial_generic_read_bulk_callback - urb stopped: -32
[ 1892.490633] ftdi_sio ttyUSB0: usb_serial_generic_read_bulk_callback - urb stopped: -32
[ 1892.564927] usb 2-1.2.1: USB disconnect, device number 4
[ 1892.579553] ftdi_sio ttyUSB0: FTDI USB Serial Device converter now disconnected from ttyUSB0
[ 1892.588313] ftdi_sio 2-1.2.1:1.0: device disconnected
[ 1893.378715] usb 2-1.2.1: new full-speed USB device number 6 using ehci-platform
[ 1893.535499] usb 2-1.2.1: New USB device found, idVendor=0403, idProduct=6001, bcdDevice= 6.00
[ 1893.544107] usb 2-1.2.1: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[ 1893.551634] usb 2-1.2.1: Product: FT232R USB UART
[ 1893.556359] usb 2-1.2.1: Manufacturer: FTDI
[ 1893.560638] usb 2-1.2.1: SerialNumber: AK08M9PN
[ 1893.569405] ftdi_sio 2-1.2.1:1.0: FTDI USB Serial Device converter detected
[ 1893.576580] usb 2-1.2.1: Detected FT232RL
[ 1893.581405] usb 2-1.2.1: FTDI USB Serial Device converter now attached to ttyUSB0
[ 1900.524993] IPv6: ADDRCONF(NETDEV_CHANGE): can0: link becomes ready
[ 1901.064197] can1: renamed from slcan0
[ 1902.549080] usb 2-1.2.1: USB disconnect, device number 6
[ 1902.558067] ftdi_sio ttyUSB0: FTDI USB Serial Device converter now disconnected from ttyUSB0
[ 1902.566867] ftdi_sio 2-1.2.1:1.0: device disconnected
[ 1902.938746] usb 2-1.2.1: new full-speed USB device number 7 using ehci-platform
[ 1903.108832] usb 2-1.2.1: device descriptor read/64, error -32
[ 1903.358768] usb 2-1.2.1: device descriptor read/64, error -32
[ 1903.598751] usb 2-1.2.1: new full-speed USB device number 8 using ehci-platform
[ 1903.818764] usb 2-1.2.1: device descriptor read/64, error -32
[ 1904.038766] usb 2-1.2.1: device descriptor read/64, error -32
[ 1904.159214] usb 2-1.2-port1: attempt power cycle
[ 1904.828922] usb 2-1.2.1: new full-speed USB device number 9 using ehci-platform
[ 1905.278814] usb 2-1.2.1: device not accepting address 9, error -32
[ 1905.408742] usb 2-1.2.1: new full-speed USB device number 10 using ehci-platform
[ 1905.988758] usb 2-1.2.1: device not accepting address 10, error -32
[ 1905.997820] usb 2-1.2-port1: unable to enumerate USB device
[ 1907.708757] usb 2-1.2.1: new full-speed USB device number 11 using ehci-platform
[ 1907.868755] usb 2-1.2.1: device descriptor read/64, error -32
[ 1908.098819] usb 2-1.2.1: device descriptor read/64, error -32
[ 1908.318766] usb 2-1.2.1: new full-speed USB device number 12 using ehci-platform
[ 1908.508726] usb 2-1.2.1: device descriptor read/64, error -32
[ 1908.728968] usb 2-1.2.1: device descriptor read/64, error -32
[ 1908.849194] usb 2-1.2-port1: attempt power cycle
[ 1909.518799] usb 2-1.2.1: new full-speed USB device number 13 using ehci-platform
[ 1910.008754] usb 2-1.2.1: device not accepting address 13, error -32
[ 1910.148744] usb 2-1.2.1: new full-speed USB device number 14 using ehci-platform
[ 1910.608907] usb 2-1.2.1: device not accepting address 14, error -32
[ 1910.617113] usb 2-1.2-port1: unable to enumerate USB device
[ 1919.900011] input: generic ft5x06 (18) as /devices/platform/soc@1c00000/1c2b400.i2c/i2c-2/2-0038/input/input3
[ 1919.913394] at24 2-0050: 256 byte 24c02 EEPROM, read-only, 0 bytes/write
[ 1919.924565] backlight gxdisp-2-0051: GX Display backlight rev 5
[ 1921.796409] IPv6: ADDRCONF(NETDEV_CHANGE): can0: link becomes ready
[ 1922.275119] can1: renamed from slcan0
[11779.318644] usb 2-1.2.1: new full-speed USB device number 15 using ehci-platform
[11780.178642] usb 2-1.3: new low-speed USB device number 16 using ehci-platform
[11780.341907] usb 2-1.3: New USB device found, idVendor=413c, idProduct=3010, bcdDevice= 2.20
[11780.350312] usb 2-1.3: New USB device strings: Mfr=0, Product=0, SerialNumber=0
[11780.396278] usbcore: registered new interface driver usbhid
[11780.402092] usbhid: USB HID core driver
[11780.414794] input: HID 413c:3010 as /devices/platform/soc@1c00000/1c1c000.usb/usb2/2-1/2-1.3/2-1.3:1.0/0003:413C:3010.0001/input/input4
[11780.427747] hid-generic 0003:413C:3010.0001: input: USB HID v1.00 Mouse [HID 413c:3010] on usb-1c1c000.usb-1.3/input0
[11955.922870] usb 2-1.3: USB disconnect, device number 16
[20145.922896] potentially unexpected fatal signal 6.
[20145.927782] CPU: 1 PID: 11975 Comm: nc Tainted: G           O      4.19.87 #1
[20145.935054] Hardware name: Allwinner sun7i (A20) Family
[20145.940380] PC is at 0xb6e10a1c
[20145.943580] LR is at 0xbe848b10
[20145.946727] pc : [<b6e10a1c>]    lr : [<be848b10>]    psr: 00070010
[20145.953078] sp : be848b10  ip : 00000000  fp : 00000010
[20145.958337] r10: 00016458  r9 : 0000023d  r8 : 0001609c
[20145.963645] r7 : 000000af  r6 : b6eff748  r5 : b6f1f0d8  r4 : 00000006
[20145.970222] r3 : 00000008  r2 : 00000000  r1 : be848b10  r0 : 00000000
[20145.976754] Flags: nzcv  IRQs on  FIQs on  Mode USER_32  ISA ARM  Segment user
[20145.984034] Control: 10c5387d  Table: 6d6fc06a  DAC: 00000055
[20145.989829] CPU: 1 PID: 11975 Comm: nc Tainted: G           O      4.19.87 #1
[20145.996962] Hardware name: Allwinner sun7i (A20) Family
[20146.002216] [<c010ee34>] (unwind_backtrace) from [<c010bba4>] (show_stack+0x10/0x14)
[20146.009971] [<c010bba4>] (show_stack) from [<c062168c>] (dump_stack+0x94/0xa8)
[20146.017203] [<c062168c>] (dump_stack) from [<c0137a5c>] (get_signal+0x60c/0x72c)
[20146.024602] [<c0137a5c>] (get_signal) from [<c010af7c>] (do_signal+0x1f4/0x4bc)
[20146.031914] [<c010af7c>] (do_signal) from [<c010b40c>] (do_work_pending+0xb8/0xdc)
[20146.039485] [<c010b40c>] (do_work_pending) from [<c010106c>] (slow_work_pending+0xc/0x20)
[20146.047658] Exception stack(0xed7f1fb0 to 0xed7f1ff8)
[20146.052710] 1fa0:                                     00000000 be848b10 00000000 00000008
[20146.060882] 1fc0: 00000006 b6f1f0d8 b6eff748 000000af 0001609c 0000023d 00016458 00000010
[20146.069053] 1fe0: 00000000 be848b10 be848b10 b6e10a1c 00070010 00000002
[168309.247999] usb 2-1.2.1: new full-speed USB device number 17 using ehci-platform
[168309.405370] usb 2-1.2.1: New USB device found, idVendor=0403, idProduct=6001, bcdDevice= 6.00
[168309.414076] usb 2-1.2.1: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[168309.421714] usb 2-1.2.1: Product: FT232R USB UART
[168309.426563] usb 2-1.2.1: Manufacturer: FTDI
[168309.430931] usb 2-1.2.1: SerialNumber: AK08M9PN
[168309.440136] ftdi_sio 2-1.2.1:1.0: FTDI USB Serial Device converter detected
[168309.447471] usb 2-1.2.1: Detected FT232RL
[168309.452654] usb 2-1.2.1: FTDI USB Serial Device converter now attached to ttyUSB0
mpvader commented 4 years ago

Mans looked into it.

Looks like the FTDI converter got itself into some weird state. the kernel was trying and failing to reconnect; it tried all, including power cycling the usb port (see the logs). Note that the FTDI was connected to an external hub, so might be that that doesn't support power cycling its ports.

The ports on the Cerbo should support that as per schematics and hardware, but we never verified that.

The one other thing the Cerbo cq 'we' could have done is power cycle the complete Venus OS.

Anyway, for now closing this - we'll continue when this happens more.

Two other things we could do:

mpvader commented 4 years ago

another suggestion, making usb issues visible. either for us, on vrm, or even for the customer.

mpvader commented 4 years ago

closing this for now, we can always dig it back up if more instances are reported.