This thread has been locked.

If you have a related question, please click the "Ask a related question" button in the top right corner. The newly created question will be automatically linked to this question.

AM4378: c_can error/overrun when high bus load

Part Number: AM4378

Hi,

I have a cusomt board based board on am4378HS and I'm performing some can tests. I discovered that when set bitrate to 500k during replaying can file from PC to board it detect 4-5 error/overrun frames. When comparing the original file with received one few lines in candump are missing.


When decreased can speed to 125KB replaying the same file no error/overruns are detected and files are the same. I'm not can expert thus I'm asking for some advice on how to debug such phenomena. 

Thanks and BR,

marek

  • Hi Marek,

    What OS do you use? TI Processor SDK Linux or RTOS?

  • TI Processor SDK

  • Can this be an issue. I spotted it in bootlog.

    net can0: c_can_hw_raminit_wait_syscon: time out

  • Specifically I'm using: ​am437x-evm-linux-sdk-src-06.03.00.106.tar.xz SDK release

  • Hi Marek,

    Thanks for the update. I am routing your query to the Linux CAN expert.

  • Hi,

    Could you please attach the full log showing the boot, the CAN configuration and this command after you are experiencing the errors? (I assume you are using CAN0 here)

     ip -d -s link show can0

    Also please tell us the response to this command:

    uname -a

    What speed are you running the processor at?

    Best Regards,

    Schuyler

  • Hi,

    On host PC I'm using peakcan usb dongle. I run following commands:

    sudo ifconfig can0 txqueuelen 1000
    sudo ip link set can0 type can bitrate 5000000; sudo ifconfig can0 up

    Similar command are run on am437x board.

    Then on PC I run: cangen can0 -g0 and on target candump can0 -L > /tmp/can.txt

    On board I check command and after some time I see error/overrun frames:

    ip -d -s link show can0
    4: can0: <NOARP,UP,LOWER_UP,ECHO> mtu 16 qdisc pfifo_fast state UP mode DEFAULT group default qlen 10
        link/can  promiscuity 0 
        can state ERROR-ACTIVE (berr-counter tx 0 rx 0) restart-ms 0 
              bitrate 500000 sample-point 0.875 
              tq 125 prop-seg 6 phase-seg1 7 phase-seg2 2 sjw 1
              c_can: tseg1 2..16 tseg2 1..8 sjw 1..4 brp 1..1024 brp-inc 1
              clock 24000000
              re-started bus-errors arbit-lost error-warn error-pass bus-off
              0          0          0          0          0          0         numtxqueues 1 numrxqueues 1 gso_max_size 65536 gso_max_segs 65535 
        RX: bytes  packets  errors  dropped overrun mcast   
        373965     65075    3       0       3       0       
        TX: bytes  packets  errors  dropped carrier collsns 
        0          0        0       0       0       0   

    Bootlog is here:

    7571.am437x_bootlog.txt
    [    0.000000] Booting Linux on physical CPU 0x0
    [    0.000000] Linux version 4.19.94-gbe5389fd85 (marek@dnb) (gcc version 7.3.1 20180425 [linaro-7.3-2018.05 revision d29120a424ecfbc167ef90065c0eeb7f91977701] (Linaro GCC 7.3-2018.05)) #2 SMP Tue Mar 30 14:07:00 CEST 2021
    [    0.000000] CPU: ARMv7 Processor [412fc09a] revision 10 (ARMv7), cr=10c5387d
    [    0.000000] CPU: PIPT / VIPT nonaliasing data cache, VIPT aliasing instruction cache
    [    0.000000] OF: fdt: Machine model: TI AM437x TEST
    [    0.000000] Memory policy: Data cache writeback
    [    0.000000] cma: Reserved 16 MiB at 0xbf000000
    [    0.000000] On node 0 totalpages: 262144
    [    0.000000]   Normal zone: 1728 pages used for memmap
    [    0.000000]   Normal zone: 0 pages reserved
    [    0.000000]   Normal zone: 196608 pages, LIFO batch:63
    [    0.000000]   HighMem zone: 65536 pages, LIFO batch:15
    [    0.000000] CPU: All CPU(s) started in SVC mode.
    [    0.000000] AM437x ES1.2 (neon)
    [    0.000000] random: get_random_bytes called from start_kernel+0x8c/0x4a0 with crng_init=0
    [    0.000000] percpu: Embedded 17 pages/cpu s38056 r8192 d23384 u69632
    [    0.000000] pcpu-alloc: s38056 r8192 d23384 u69632 alloc=17*4096
    [    0.000000] pcpu-alloc: [0] 0 
    [    0.000000] Built 1 zonelists, mobility grouping on.  Total pages: 260416
    [    0.000000] Kernel command line: console=ttyS0,115200n8 root=/dev/mmcblk1p2 rootfstype=ext4 rootwait ip=none omap_wdt.early_enable=1
    [    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: 1000316K/1048576K available (9216K kernel code, 804K rwdata, 2644K rodata, 1024K init, 7477K bss, 31876K reserved, 16384K cma-reserved, 245760K highmem)
    [    0.000000] Virtual kernel memory layout:
                       vector  : 0xffff0000 - 0xffff1000   (   4 kB)
                       fixmap  : 0xffc00000 - 0xfff00000   (3072 kB)
                       vmalloc : 0xf0800000 - 0xff800000   ( 240 MB)
                       lowmem  : 0xc0000000 - 0xf0000000   ( 768 MB)
                       pkmap   : 0xbfe00000 - 0xc0000000   (   2 MB)
                       modules : 0xbf000000 - 0xbfe00000   (  14 MB)
                         .text : 0x(ptrval) - 0x(ptrval)   (10208 kB)
                         .init : 0x(ptrval) - 0x(ptrval)   (1024 kB)
                         .data : 0x(ptrval) - 0x(ptrval)   ( 805 kB)
                          .bss : 0x(ptrval) - 0x(ptrval)   (7478 kB)
    [    0.000000] Running RCU self tests
    [    0.000000] rcu: Hierarchical RCU implementation.
    [    0.000000] rcu:     RCU event tracing is enabled.
    [    0.000000] rcu:     RCU lockdep checking is enabled.
    [    0.000000] rcu:     RCU restricting CPUs from NR_CPUS=2 to nr_cpu_ids=1.
    [    0.000000] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=1
    [    0.000000] NR_IRQS: 16, nr_irqs: 16, preallocated irqs: 16
    [    0.000000] L2C: platform modifies aux control register: 0x0e030000 -> 0x3e430000
    [    0.000000] L2C: DT/platform modifies aux control register: 0x0e030000 -> 0x3e430000
    [    0.000000] L2C-310 enabling early BRESP for Cortex-A9
    [    0.000000] OMAP L2C310: ROM does not support power control setting
    [    0.000000] L2C-310 dynamic clock gating disabled, standby mode disabled
    [    0.000000] L2C-310 cache controller enabled, 16 ways, 256 kB
    [    0.000000] L2C-310: CACHE_ID 0x410000c9, AUX_CTRL 0x4e430000
    [    0.000000] OMAP clockevent source: timer2 at 24000000 Hz
    [    0.000020] sched_clock: 32 bits at 24MHz, resolution 41ns, wraps every 89478484971ns
    [    0.000055] clocksource: timer1: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 79635851949 ns
    [    0.000129] OMAP clocksource: timer1 at 24000000 Hz
    [    0.000865] clocksource: 32k_counter: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 58327039986419 ns
    [    0.000890] OMAP clocksource: 32k_counter at 32768 Hz
    [    0.002265] Console: colour dummy device 80x30
    [    0.002340] Lock dependency validator: Copyright (c) 2006 Red Hat, Inc., Ingo Molnar
    [    0.002359] ... MAX_LOCKDEP_SUBCLASSES:  8
    [    0.002375] ... MAX_LOCK_DEPTH:          48
    [    0.002390] ... MAX_LOCKDEP_KEYS:        8191
    [    0.002406] ... CLASSHASH_SIZE:          4096
    [    0.002421] ... MAX_LOCKDEP_ENTRIES:     32768
    [    0.002437] ... MAX_LOCKDEP_CHAINS:      65536
    [    0.002452] ... CHAINHASH_SIZE:          32768
    [    0.002467]  memory used by lock dependency info: 4655 kB
    [    0.002483]  per task-struct memory footprint: 1536 bytes
    [    0.002587] Calibrating delay loop... 1594.16 BogoMIPS (lpj=7970816)
    [    0.160470] pid_max: default: 32768 minimum: 301
    [    0.160939] Security Framework initialized
    [    0.161107] Mount-cache hash table entries: 2048 (order: 1, 8192 bytes)
    [    0.161146] Mountpoint-cache hash table entries: 2048 (order: 1, 8192 bytes)
    [    0.165073] CPU: Testing write buffer coherency: ok
    [    0.165278] CPU0: Spectre v2: using BPIALL workaround
    [    0.167014] CPU0: thread -1, cpu 0, socket 0, mpidr 80000000
    [    0.169792] Setting up static identity map for 0x80100000 - 0x80100078
    [    0.170708] rcu: Hierarchical SRCU implementation.
    [    0.172946] smp: Bringing up secondary CPUs ...
    [    0.172979] smp: Brought up 1 node, 1 CPU
    [    0.173002] SMP: Total of 1 processors activated (1594.16 BogoMIPS).
    [    0.173022] CPU: All CPU(s) started in SVC mode.
    [    0.176940] devtmpfs: initialized
    [    0.211582] VFP support v0.3: implementor 41 architecture 3 part 30 variant 9 rev 4
    [    0.212624] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 ns
    [    0.212710] futex hash table entries: 256 (order: 2, 16384 bytes)
    [    0.215010] pinctrl core: initialized pinctrl subsystem
    [    0.220838] NET: Registered protocol family 16
    [    0.228601] DMA: preallocated 256 KiB pool for atomic coherent allocations
    [    0.363896] audit: initializing netlink subsys (disabled)
    [    0.367061] cpuidle: using governor menu
    [    0.391625] audit: type=2000 audit(0.360:1): state=initialized audit_enabled=0 res=1
    [    0.392525] gpio gpiochip0: (gpio-0-31): added GPIO chardev (254:0)
    [    0.393036] gpiochip_setup_dev: registered GPIOs 0 to 31 on device: gpiochip0 (gpio-0-31)
    [    0.393194] OMAP GPIO hardware version 0.1
    [    0.395803] gpio gpiochip1: (gpio-32-63): added GPIO chardev (254:1)
    [    0.396105] gpiochip_setup_dev: registered GPIOs 32 to 63 on device: gpiochip1 (gpio-32-63)
    [    0.398550] gpio gpiochip2: (gpio-64-95): added GPIO chardev (254:2)
    [    0.398788] gpiochip_setup_dev: registered GPIOs 64 to 95 on device: gpiochip2 (gpio-64-95)
    [    0.401235] gpio gpiochip3: (gpio-96-127): added GPIO chardev (254:3)
    [    0.401477] gpiochip_setup_dev: registered GPIOs 96 to 127 on device: gpiochip3 (gpio-96-127)
    [    0.420568] No ATAGs?
    [    0.421015] hw-breakpoint: found 5 (+1 reserved) breakpoint and 1 watchpoint registers.
    [    0.421128] hw-breakpoint: maximum watchpoint size is 4 bytes.
    [    0.465822] edma 49000000.edma: TI EDMA DMA engine driver
    [    0.467166] of_get_named_gpiod_flags: can't parse 'gpio' property of node '/fixedregulator@1[0]'
    [    0.467972] of_get_named_gpiod_flags: can't parse 'gpio' property of node '/fixedregulator@0[0]'
    [    0.474756] vgaarb: loaded
    [    0.475989] SCSI subsystem initialized
    [    0.476950] libata version 3.00 loaded.
    [    0.478074] pps_core: LinuxPPS API ver. 1 registered
    [    0.478103] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti <giometti@linux.it>
    [    0.478169] PTP clock support registered
    [    0.483640] clocksource: Switched to clocksource timer1
    [    0.646395] VFS: Disk quotas dquot_6.6.0
    [    0.646619] VFS: Dquot-cache hash table entries: 1024 (order 0, 4096 bytes)
    [    0.676299] NET: Registered protocol family 2
    [    0.678994] tcp_listen_portaddr_hash hash table entries: 512 (order: 2, 20480 bytes)
    [    0.679132] TCP established hash table entries: 8192 (order: 3, 32768 bytes)
    [    0.679311] TCP bind hash table entries: 8192 (order: 6, 294912 bytes)
    [    0.680316] TCP: Hash tables configured (established 8192 bind 8192)
    [    0.680908] UDP hash table entries: 512 (order: 3, 40960 bytes)
    [    0.681091] UDP-Lite hash table entries: 512 (order: 3, 40960 bytes)
    [    0.681662] NET: Registered protocol family 1
    [    0.685263] RPC: Registered named UNIX socket transport module.
    [    0.685358] RPC: Registered udp transport module.
    [    0.685378] RPC: Registered tcp transport module.
    [    0.685397] RPC: Registered tcp NFSv4.1 backchannel transport module.
    [    0.685429] PCI: CLS 0 bytes, default 64
    [    0.692927] Initialise system trusted keyrings
    [    0.694445] workingset: timestamp_bits=14 max_order=18 bucket_order=4
    [    0.698032] NFS: Registering the id_resolver key type
    [    0.698234] Key type id_resolver registered
    [    0.698318] Key type id_legacy registered
    [    0.698518] jffs2: version 2.2. (NAND) (SUMMARY)  \xffffffc2\xffffffa9 2001-2006 Red Hat, Inc.
    [    0.707580] Key type asymmetric registered
    [    0.707891] Asymmetric key parser 'x509' registered
    [    0.708189] bounce: pool size: 64 pages
    [    0.708367] io scheduler noop registered
    [    0.708393] io scheduler deadline registered
    [    0.708628] io scheduler cfq registered (default)
    [    0.708656] io scheduler mq-deadline registered
    [    0.708678] io scheduler kyber registered
    [    0.714649] pinctrl-single 44e10800.pinmux: 199 pins, size 796
    [    0.722797] Serial: 8250/16550 driver, 6 ports, IRQ sharing enabled
    [    0.732196] omap8250 44e09000.serial: No clock speed specified: using default: 48000000
    [    0.738623] console [ttyS0] disabled
    [    0.739208] 44e09000.serial: ttyS0 at MMIO 0x44e09000 (irq = 31, base_baud = 3000000) is a 8250
    [    1.479376] console [ttyS0] enabled
    [    1.485181] omap8250 48022000.serial: No clock speed specified: using default: 48000000
    [    1.494753] 48022000.serial: ttyS1 at MMIO 0x48022000 (irq = 32, base_baud = 3000000) is a 8250
    [    1.505340] omap8250 48024000.serial: No clock speed specified: using default: 48000000
    [    1.514954] 48024000.serial: ttyS2 at MMIO 0x48024000 (irq = 33, base_baud = 3000000) is a 8250
    [    1.561150] brd: module loaded
    [    1.596966] loop: module loaded
    [    1.603298] mtdoops: mtd device (mtddev=name/number) must be supplied
    [    1.620086] mdio_bus fixed-0: GPIO lookup for consumer reset
    [    1.620111] mdio_bus fixed-0: using lookup tables for GPIO lookup
    [    1.620235] mdio_bus fixed-0: No GPIO consumer reset found
    [    1.620499] libphy: Fixed MDIO Bus: probed
    [    1.643902] mdio_bus 4a101000.mdio: GPIO lookup for consumer reset
    [    1.643931] mdio_bus 4a101000.mdio: using device tree for GPIO lookup
    [    1.643976] of_get_named_gpiod_flags: can't parse 'reset-gpios' property of node '/ocp@44000000/ethernet@4a100000/mdio@4a101000[0]'
    [    1.644012] of_get_named_gpiod_flags: can't parse 'reset-gpio' property of node '/ocp@44000000/ethernet@4a100000/mdio@4a101000[0]'
    [    1.644031] mdio_bus 4a101000.mdio: using lookup tables for GPIO lookup
    [    1.644049] mdio_bus 4a101000.mdio: No GPIO consumer reset found
    [    1.703587] davinci_mdio 4a101000.mdio: davinci mdio revision 1.6, bus freq 1000000
    [    1.711362] davinci_mdio 4a101000.mdio: detected phy mask fffffffa
    [    1.725186] libphy: 4a101000.mdio: probed
    [    1.729274] davinci_mdio 4a101000.mdio: phy[0]: device 4a101000.mdio:00, driver Micrel KSZ9031 Gigabit PHY
    [    1.739765] davinci_mdio 4a101000.mdio: phy[2]: device 4a101000.mdio:02, driver Micrel KSZ9031 Gigabit PHY
    [    1.751054] cpsw 4a100000.ethernet: No slave[0] phy_id, phy-handle, or fixed-link property
    [    1.759819] cpsw 4a100000.ethernet: Detected MACID = 50:65:83:e3:20:3e
    [    1.767472] cpsw 4a100000.ethernet: initialized cpsw ale version 1.4
    [    1.774123] cpsw 4a100000.ethernet: ALE Table size 1024
    [    1.779500] cpsw 4a100000.ethernet: cpts: overflow check period 500 (jiffies)
    [    1.790716] i2c /dev entries driver
    [    1.798856] sdhci: Secure Digital Host Controller Interface driver
    [    1.805245] sdhci: Copyright(c) Pierre Ossman
    [    1.811079] omap_hsmmc 48060000.mmc: GPIO lookup for consumer cd
    [    1.811099] omap_hsmmc 48060000.mmc: using device tree for GPIO lookup
    [    1.811145] of_get_named_gpiod_flags: can't parse 'cd-gpios' property of node '/ocp@44000000/mmc@48060000[0]'
    [    1.811179] of_get_named_gpiod_flags: can't parse 'cd-gpio' property of node '/ocp@44000000/mmc@48060000[0]'
    [    1.811196] omap_hsmmc 48060000.mmc: using lookup tables for GPIO lookup
    [    1.811216] omap_hsmmc 48060000.mmc: No GPIO consumer cd found
    [    1.811237] omap_hsmmc 48060000.mmc: GPIO lookup for consumer wp
    [    1.811250] omap_hsmmc 48060000.mmc: using device tree for GPIO lookup
    [    1.811281] of_get_named_gpiod_flags: can't parse 'wp-gpios' property of node '/ocp@44000000/mmc@48060000[0]'
    [    1.811312] of_get_named_gpiod_flags: can't parse 'wp-gpio' property of node '/ocp@44000000/mmc@48060000[0]'
    [    1.811328] omap_hsmmc 48060000.mmc: using lookup tables for GPIO lookup
    [    1.811344] omap_hsmmc 48060000.mmc: No GPIO consumer wp found
    [    1.812957] omap_hsmmc 48060000.mmc: Linked as a consumer to regulator.2
    [    1.847345] omap_hsmmc 481d8000.mmc: GPIO lookup for consumer cd
    [    1.847369] omap_hsmmc 481d8000.mmc: using device tree for GPIO lookup
    [    1.847413] of_get_named_gpiod_flags: can't parse 'cd-gpios' property of node '/ocp@44000000/mmc@481d8000[0]'
    [    1.847447] of_get_named_gpiod_flags: can't parse 'cd-gpio' property of node '/ocp@44000000/mmc@481d8000[0]'
    [    1.847465] omap_hsmmc 481d8000.mmc: using lookup tables for GPIO lookup
    [    1.847484] omap_hsmmc 481d8000.mmc: No GPIO consumer cd found
    [    1.847505] omap_hsmmc 481d8000.mmc: GPIO lookup for consumer wp
    [    1.847517] omap_hsmmc 481d8000.mmc: using device tree for GPIO lookup
    [    1.847548] of_get_named_gpiod_flags: can't parse 'wp-gpios' property of node '/ocp@44000000/mmc@481d8000[0]'
    [    1.847579] of_get_named_gpiod_flags: can't parse 'wp-gpio' property of node '/ocp@44000000/mmc@481d8000[0]'
    [    1.847594] omap_hsmmc 481d8000.mmc: using lookup tables for GPIO lookup
    [    1.847608] omap_hsmmc 481d8000.mmc: No GPIO consumer wp found
    [    1.852878] sdhci-pltfm: SDHCI platform and OF driver helper
    [    1.859665] ledtrig-cpu: registered to indicate activity on CPUs
    [    1.867727] oprofile: no performance counters
    [    1.873058] oprofile: using timer interrupt.
    [    1.878383] Initializing XFRM netlink socket
    [    1.883314] NET: Registered protocol family 10
    [    1.892228] Segment Routing with IPv6
    [    1.896327] sit: IPv6, IPv4 and MPLS over IPv4 tunneling driver
    [    1.904668] NET: Registered protocol family 17
    [    1.909238] NET: Registered protocol family 15
    [    1.914246] Key type dns_resolver registered
    [    1.918801] ThumbEE CPU extension supported.
    [    1.923128] Registering SWP/SWPB emulation handler
    [    1.928060] omap_voltage_late_init: Voltage driver support not added
    [    1.934543] sr_dev_init: Unknown instance smartreflex0
    [    1.940290] SmartReflex Class3 initialized
    [    1.948279] Loading compiled-in X.509 certificates
    [    2.015360] gpio gpiochip4: Persistence not supported for GPIO 4
    [    2.015409] GPIO line 132 (GPRS_SEL) hogged as output/high
    [    2.022246] gpio gpiochip4: (gpio-128-159): added GPIO chardev (254:4)
    [    2.022799] gpiochip_setup_dev: registered GPIOs 128 to 159 on device: gpiochip4 (gpio-128-159)
    [    2.024082] of_get_named_gpiod_flags: parsed 'gpio' property of node '/fixedregulator@2[0]' - status (0)
    [    2.032669] omap_i2c 44e0b000.i2c: bus 0 rev0.12 at 400 kHz
    [    2.040048] omap_hsmmc 481d8000.mmc: GPIO lookup for consumer cd
    [    2.040071] omap_hsmmc 481d8000.mmc: using device tree for GPIO lookup
    [    2.040118] of_get_named_gpiod_flags: can't parse 'cd-gpios' property of node '/ocp@44000000/mmc@481d8000[0]'
    [    2.040155] of_get_named_gpiod_flags: can't parse 'cd-gpio' property of node '/ocp@44000000/mmc@481d8000[0]'
    [    2.040175] omap_hsmmc 481d8000.mmc: using lookup tables for GPIO lookup
    [    2.040262] omap_hsmmc 481d8000.mmc: No GPIO consumer cd found
    [    2.040288] omap_hsmmc 481d8000.mmc: GPIO lookup for consumer wp
    [    2.040302] omap_hsmmc 481d8000.mmc: using device tree for GPIO lookup
    [    2.040338] of_get_named_gpiod_flags: can't parse 'wp-gpios' property of node '/ocp@44000000/mmc@481d8000[0]'
    [    2.040371] of_get_named_gpiod_flags: can't parse 'wp-gpio' property of node '/ocp@44000000/mmc@481d8000[0]'
    [    2.040389] omap_hsmmc 481d8000.mmc: using lookup tables for GPIO lookup
    [    2.040404] omap_hsmmc 481d8000.mmc: No GPIO consumer wp found
    [    2.041806] omap_hsmmc 481d8000.mmc: Linked as a consumer to regulator.3
    [    2.103763] mmc0: switch to bus width 8 failed
    [    2.113398] mmc0: new high speed MMC card at address 0001
    [    2.125869] mmcblk0: mmc0:0001 DG4008 7.28 GiB 
    [    2.132789] mmcblk0boot0: mmc0:0001 DG4008 partition 1 4.00 MiB
    [    2.140869] mmcblk0boot1: mmc0:0001 DG4008 partition 2 4.00 MiB
    [    2.148644] mmcblk0rpmb: mmc0:0001 DG4008 partition 3 4.00 MiB, chardev (248:0)
    [    2.191334] hctosys: unable to open rtc device (rtc0)
    [    2.196668] sr_init: No PMIC hook to init smartreflex
    [    2.208354] Waiting for root device /dev/mmcblk1p2...
    [    2.275353] mmc1: host does not support reading read-only switch, assuming write-enable
    [    2.289338] mmc1: new high speed SDHC card at address aaaa
    [    2.298550] mmcblk1: mmc1:aaaa SL16G 14.8 GiB 
    [    2.312730]  mmcblk1: p1 p2 p3 p4 < p5 p6 >
    [    2.343004] EXT4-fs (mmcblk1p2): INFO: recovery required on readonly filesystem
    [    2.350822] EXT4-fs (mmcblk1p2): write access will be enabled during recovery
    [    2.394860] EXT4-fs (mmcblk1p2): recovery complete
    [    2.408371] EXT4-fs (mmcblk1p2): mounted filesystem with ordered data mode. Opts: (null)
    [    2.416870] VFS: Mounted root (ext4 filesystem) readonly on device 179:26.
    [    2.438908] devtmpfs: mounted
    [    2.444945] Freeing unused kernel memory: 1024K
    [    2.450301] Run /sbin/init as init process
    [    2.539331] random: fast init done
    [    2.831005] systemd[1]: System time before build time, advancing clock.
    [    2.974985] systemd[1]: systemd 234 running in system mode. (-PAM -AUDIT -SELINUX +IMA -APPARMOR +SMACK +SYSVINIT +UTMP -LIBCRYPTSETUP -GCRYPT -GNUTLS +ACL +XZ -LZ4 -SECCOMP +BLKID -ELFUTILS +KMOD -IDN2 -IDN default-hierarchy=hybrid)
    [    2.997774] systemd[1]: Detected architecture arm.
    [    3.049290] systemd[1]: Set hostname to <am43xx-test>.
    [    3.700738] systemd[1]: multi-user.target: Wants dependency dropin /etc/systemd/system/multi-user.target.wants/wpa_supplicant@eth0.service target /lib/systemd/system/wpa_supplicant-wired@.service has different name
    [    3.975160] random: systemd: uninitialized urandom read (16 bytes read)
    [    3.982663] systemd[1]: Listening on Syslog Socket.
    [    4.014100] random: systemd: uninitialized urandom read (16 bytes read)
    [    4.030075] systemd[1]: Created slice System Slice.
    [    4.064364] random: systemd: uninitialized urandom read (16 bytes read)
    [    4.075276] systemd[1]: Created slice system-serial\x2dgetty.slice.
    [    4.114926] systemd[1]: Listening on Journal Socket.
    [    4.155685] systemd[1]: Listening on udev Control Socket.
    [    4.195479] systemd[1]: Listening on /dev/initctl Compatibility Named Pipe.
    [    5.372069] EXT4-fs (mmcblk1p2): re-mounted. Opts: (null)
    [    6.069870] systemd-journald[75]: Received request to flush runtime journal from PID 1
    [    8.802250] remoteproc remoteproc0: wkup_m3 is available
    [    8.895143] wkup_m3_ipc 44e11324.wkup_m3_ipc: IPC Request for A8->M3 Channel failed! -517
    [    8.999480] wkup_m3_ipc 44e11324.wkup_m3_ipc: IPC Request for A8->M3 Channel failed! -517
    [    9.091544] omap_wdt: OMAP Watchdog Timer Rev 0x01: initial timeout 60 sec
    [    9.106151] wkup_m3_ipc 44e11324.wkup_m3_ipc: IPC Request for A8->M3 Channel failed! -517
    [    9.224507] omap-mailbox 480c8000.mailbox: omap mailbox rev 0x400
    [    9.255284] remoteproc remoteproc0: powering up wkup_m3
    [    9.334432] remoteproc remoteproc0: Direct firmware load for am335x-pm-firmware.elf failed with error -2
    [    9.344810] remoteproc remoteproc0: request_firmware failed: -2
    [    9.350794] wkup_m3_ipc 44e11324.wkup_m3_ipc: rproc_boot failed
    [    9.389639] CAN device driver interface
    [    9.521688] omap_rng 48310000.rng: Random Number Generator ver. 20
    [    9.530169] random: crng init done
    [    9.533784] random: 7 urandom warning(s) missed due to ratelimiting
    [    9.569274] c_can_platform 481cc000.can: c_can_platform device registered (regs=6ebb0fe3, irq=57)
    [   10.852248] of_get_named_gpiod_flags: parsed 'gpios' property of node '/leds/led0[0]' - status (0)
    [   10.852306] gpio gpiochip4: Persistence not supported for GPIO 8
    [   10.852318] no flags found for gpios
    [   10.855364] of_get_named_gpiod_flags: parsed 'gpios' property of node '/leds/led1[0]' - status (0)
    [   10.855415] gpio gpiochip4: Persistence not supported for GPIO 9
    [   10.855427] no flags found for gpios
    [   10.856096] of_get_named_gpiod_flags: parsed 'gpios' property of node '/leds/led2[0]' - status (0)
    [   10.856133] gpio gpiochip4: Persistence not supported for GPIO 13
    [   10.856144] no flags found for gpios
    [   10.856514] of_get_named_gpiod_flags: parsed 'gpios' property of node '/leds/led3[0]' - status (0)
    [   10.856652] gpio gpiochip2: Persistence not supported for GPIO 21
    [   10.856665] no flags found for gpios
    [   10.857071] of_get_named_gpiod_flags: parsed 'gpios' property of node '/leds/led4[0]' - status (0)
    [   10.857102] gpio gpiochip4: Persistence not supported for GPIO 1
    [   10.857114] no flags found for gpios
    [   10.857447] of_get_named_gpiod_flags: parsed 'gpios' property of node '/leds/led5[0]' - status (0)
    [   10.857476] gpio gpiochip2: Persistence not supported for GPIO 20
    [   10.857487] no flags found for gpios
    [   10.881150] PM: Cannot get wkup_m3_ipc handle
    [   13.183023] PM: Cannot get wkup_m3_ipc handle
    [   13.750732] dwc3 48390000.usb: Failed to get clk 'ref': -2
    [   14.005372] dwc3 483d0000.usb: Failed to get clk 'ref': -2
    [   14.014944] PM: Cannot get wkup_m3_ipc handle
    [   14.121556] net eth0: initializing cpsw version 1.15 (0)
    [   14.128497] libphy: PHY  not found
    [   14.131942] net eth0: phy "" not found on slave 0, err -19
    [   14.201757] PM: Cannot get wkup_m3_ipc handle
    [   14.363088] usbcore: registered new interface driver usbfs
    [   14.369749] usbcore: registered new interface driver hub
    [   14.375527] usbcore: registered new device driver usb
    [   14.464406] Micrel KSZ9031 Gigabit PHY 4a101000.mdio:02: attached PHY driver [Micrel KSZ9031 Gigabit PHY] (mii_bus:phy_addr=4a101000.mdio:02, irq=POLL)
    [   14.617384] IPv6: ADDRCONF(NETDEV_UP): eth0: link is not ready
    [   14.744418] xhci-hcd xhci-hcd.1.auto: xHCI Host Controller
    [   14.751298] xhci-hcd xhci-hcd.1.auto: new USB bus registered, assigned bus number 1
    [   14.856976] xhci-hcd xhci-hcd.1.auto: hcc params 0x0238f06d hci version 0x100 quirks 0x0000000002010010
    [   14.866952] xhci-hcd xhci-hcd.1.auto: irq 91, io mem 0x483d0000
    [   14.973182] usb usb1: New USB device found, idVendor=1d6b, idProduct=0002, bcdDevice= 4.19
    [   14.982060] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
    [   14.989482] usb usb1: Product: xHCI Host Controller
    [   14.994467] usb usb1: Manufacturer: Linux 4.19.94-gbe5389fd85 xhci-hcd
    [   15.001043] usb usb1: SerialNumber: xhci-hcd.1.auto
    [   15.274970] hub 1-0:1.0: USB hub found
    [   15.302008] hub 1-0:1.0: 1 port detected
    [   15.377382] xhci-hcd xhci-hcd.1.auto: xHCI Host Controller
    [   15.382985] xhci-hcd xhci-hcd.1.auto: new USB bus registered, assigned bus number 2
    [   15.390898] xhci-hcd xhci-hcd.1.auto: Host supports USB 3.0 SuperSpeed
    [   15.398210] PM: Cannot get wkup_m3_ipc handle
    [   15.539409] usb usb2: We don't know the algorithms for LPM for this host, disabling LPM.
    [   15.591796] usb usb2: New USB device found, idVendor=1d6b, idProduct=0003, bcdDevice= 4.19
    [   15.600460] usb usb2: New USB device strings: Mfr=3, Product=2, SerialNumber=1
    [   15.607987] usb usb2: Product: xHCI Host Controller
    [   15.612908] usb usb2: Manufacturer: Linux 4.19.94-gbe5389fd85 xhci-hcd
    [   15.619552] usb usb2: SerialNumber: xhci-hcd.1.auto
    [   15.763004] hub 2-0:1.0: USB hub found
    [   15.787624] hub 2-0:1.0: 1 port detected
    [   15.833957] PM: Cannot get wkup_m3_ipc handle
    [   18.647111] cpsw 4a100000.ethernet eth0: Link is Up - 1Gbps/Full - flow control off
    [   18.712981] IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
    [   19.432894] net can0: c_can_hw_raminit_wait_syscon: time out
    [   19.439745] c_can_platform 481cc000.can can0: setting BTR=1c02 BRPE=0000
    [   19.448059] IPv6: ADDRCONF(NETDEV_UP): can0: link is not ready
    [   19.715031] IPv6: ADDRCONF(NETDEV_CHANGE): can0: link becomes ready
    [   21.090653] c_can_platform 481cc000.can can0: setting BTR=1c02 BRPE=0000
    
    

    uname -a : Linux am43xx-test 4.19.94-gbe5389fd85 #2 SMP Tue Mar 30 14:07:00 CEST 2021 armv7l GNU/Linux

    We're running at full speed.

    Thanks and BR,

    marek

  • Hi,

    one more comment. I tried n am437x EVM with SDK. Also message: 

    [ 1169.150530] net can0: c_can_hw_raminit_wait_syscon: time out

    happens only if bitrate is > 250kb. 

    Thanks and BR,

    marek

  • Hi,

    I will assume this is a copy error or something from the setup command; bitrate 5000000;  This has one extra 0 in it this saying the bitrate is set to 5M.

    It is possible to overrun the CAN interface, there are several contributing factors that could cause this.  I would recommend using a canbus analyzer to see what the CAN messages are coming from the Ubuntu to determine what the actual message rate is.

    I would recommend increasing the time between messages in the cangen command to see if that eliminates the overruns and the errors.

    Best Regards,

    Schuyler

  • Hi,

    well maybe it is typo or something but I constantly see and issue and from above you see that bitrate was properly set: bitrate 500000 (ip command output).

    I used canlyzer and it can receive all frames properly while am437x board cannot. I checked canbusload at it is ~53%. Do you have some other ideas what we can try to resolve this issue? As said with bitrates <= 250kB everything works perfectly fine.

    This error indicate that RAMINIT timeouts. Strange thing is that it happens also only at 500kB and above not below. As I understand from TRM there is some internal RAM which is initialized by setting some bit and then wait for done bit in same register. Do you have an idea on that?

    [ 1169.150530] net can0: c_can_hw_raminit_wait_syscon: time out

    Thanks and BR,

    marek

  • Hi,

    What version of the TI kernel or TI Linux SDK are you using?

    Best Regards,

    Schuyler

  • Hi,

    it's written above in thread: Specifically I'm using: ​am437x-evm-linux-sdk-src-06.03.00.106.tar.xz SDK release (kernel 4.19.64). 

    Thanks.

  • Hi,

    I am un-familiar with cangen. Looking at the manpage could you please try adding -I to the command line? Does the CANBUS analyzer show the same identifier with each CAN message?

    Best Regards,

    Schuyler

  • Hi,

    cangen basically can generate can frames. Without any values it generated random can frames (different length and can ID). Canbus analyzer properly capture all frames while our board/am437x EVM miss some of them as described above. 

    BR,

    marek

  • Hi, 

    I will review this issue with other teams to see if there are some suggestions that can be offered.

    Best Regards,

    Schuyler

  • Hi,

    Could you please attach the boot log the entire console log? We would like to see when the timeout message is occurring in context to the CAN traffic. Does the analyzer you are using have a text file output? Does it output pcap files so we could use wireshark to look at the data? If so please attach the pcap file.

    Best Regards,

    Schuyler

  • Hi,

    Could also try increasing the gap length? Most likely the dropped messages are coming in to fast and causing an overwrite in the CAN message memory. I am not sure if cangen implements any kind of flow control. 

    One option would be to try the RT kernel version.

    Do you require a burst or a stream? How are you planning to use the CANBUS?

    Best Regards,

    Schuyler