Skip to content

mcp251xfd based dual can HAT and 5.10.95 #4902

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Closed
nmbath opened this issue Feb 21, 2022 · 83 comments
Closed

mcp251xfd based dual can HAT and 5.10.95 #4902

nmbath opened this issue Feb 21, 2022 · 83 comments

Comments

@nmbath
Copy link

nmbath commented Feb 21, 2022

Describe the bug

The HAT has a dual channel mcp251xfd can chip, running on spi0.0 and spi1.0. While the driver loads and looks like it is working a number of issues are occurring,. A dmesg | grep can shows

[ 7.661604] mcp251xfd spi0.0 can0: MCP2518FD rev0.0 (-RX_INT -MAB_NO_WARN +CRC_REG +CRC_RX +CRC_TX +ECC -HD c:40.00MHz m:20.00MHz r:17.00MHz e:16.66MHz) successfully initialized.
[ 7.724663] mcp251xfd spi1.0 can1: MCP2518FD rev0.0 (-RX_INT -MAB_NO_WARN +CRC_REG +CRC_RX +CRC_TX +ECC -HD c:40.00MHz m:20.00MHz r:17.00MHz e:16.66MHz) successfully initialized.

When trying to send and receive can messages on can0 the following dmesg messages are received for a few seconds and then stops, but traffic is sent and received on can0

[ 23.398211] NOHZ tick-stop error: Non-RCU local softirq work is pending, handler #8!!!
[ 23.501499] NOHZ tick-stop error: Non-RCU local softirq work is pending, handler #8!!!
[ 23.581290] NOHZ tick-stop error: Non-RCU local softirq work is pending, handler #8!!!
[ 23.607407] NOHZ tick-stop error: Non-RCU local softirq work is pending, handler #8!!!
[ 23.619993] NOHZ tick-stop error: Non-RCU local softirq work is pending, handler #8!!!
[ 23.629911] NOHZ tick-stop error: Non-RCU local softirq work is pending, handler #8!!!
[ 23.653014] NOHZ tick-stop error: Non-RCU local softirq work is pending, handler #8!!!
[ 23.662845] NOHZ tick-stop error: Non-RCU local softirq work is pending, handler #8!!!
[ 23.673721] NOHZ tick-stop error: Non-RCU local softirq work is pending, handler #8!!!

However I can not get can1 running at all.

ifconfig can1 up
ifconfig: SIOCSIFFLAGS: Invalid argument

dmesg has these messages
[ 394.045735] mcp251xfd spi1.0 can1: Failed to detect MCP2518FD (osc=0x00000000).
[ 394.053266] mcp251xfd spi1.0 can1: CRC read error at address 0x0e0c (length=4, data=00 00 00 00, CRC=0x0000) retrying.
[ 394.064157] mcp251xfd spi1.0 can1: CRC read error at address 0x0e0c (length=4, data=00 00 00 00, CRC=0x0000) retrying.
[ 394.075031] mcp251xfd spi1.0 can1: CRC read error at address 0x0e0c (length=4, data=00 00 00 00, CRC=0x0000) retrying.
[ 394.085798] mcp251xfd spi1.0 can1: CRC read error at address 0x0e0c (length=4, data=00 00 00 00, CRC=0x0000).
[ 394.096366] mcp251xfd spi1.0 can1: CRC read error at address 0x0000 (length=4, data=00 00 00 00, CRC=0x0000) retrying.
[ 394.107287] mcp251xfd spi1.0 can1: CRC read error at address 0x0000 (length=4, data=00 00 00 00, CRC=0x0000) retrying.
[ 394.118507] mcp251xfd spi1.0 can1: CRC read error at address 0x0000 (length=4, data=00 00 00 00, CRC=0x0000) retrying.
[ 394.129372] mcp251xfd spi1.0 can1: CRC read error at address 0x0000 (length=4, data=00 00 00 00, CRC=0x0000).
[ 394.139661] mcp251xfd spi1.0 can1: CRC read error at address 0x0e0c (length=4, data=00 00 00 00, CRC=0x0000) retrying.
[ 394.150838] mcp251xfd spi1.0 can1: CRC read error at address 0x0e0c (length=4, data=00 00 00 00, CRC=0x0000) retrying.
[ 394.161713] mcp251xfd spi1.0 can1: CRC read error at address 0x0e0c (length=4, data=00 00 00 00, CRC=0x0000) retrying.
[ 394.172492] mcp251xfd spi1.0 can1: CRC read error at address 0x0e0c (length=4, data=00 00 00 00, CRC=0x0000).
[ 394.182735] mcp251xfd spi1.0 can1: CRC read error at address 0x0000 (length=4, data=00 00 00 00, CRC=0x0000) retrying.
[ 394.193606] mcp251xfd spi1.0 can1: CRC read error at address 0x0000 (length=4, data=00 00 00 00, CRC=0x0000) retrying.
[ 394.204483] mcp251xfd spi1.0 can1: CRC read error at address 0x0000 (length=4, data=00 00 00 00, CRC=0x0000) retrying.
[ 394.215283] mcp251xfd spi1.0 can1: CRC read error at address 0x0000 (length=4, data=00 00 00 00, CRC=0x0000).

I have installed various fixes and patches as baed on https://github.com/marckleinebudde/linux-rpi/commits/v5.10-rpi/backport-performance-improvements

Steps to reproduce the behaviour

Stock 5.10.95 pulled from https://github.com/raspberrypi/linux/tree/rpi-5.10.y and the can0 interface presented some crc error, which after installing this patch 0ecb42a can: mcp251xfd: mcp251xfd_regmap_crc_read(): work around broken CRC on TBC register, stopped giving them.

Device (s)

Raspberry Pi 3 Mod. B

System

Linux raspberrypi2 5.10.95-v7 #1 SMP Fri Feb 18 07:45:17 UTC 2022 armv7l GNU/Linux

[ 0.080092] raspberrypi-firmware soc:firmware: Attached to firmware from 2022-01-20T13:58:22, variant start
[ 0.090104] raspberrypi-firmware soc:firmware: Firmware hash is bd88f66f8952d34e4e0613a85c7a6d3da49e13e2

Logs

No response

Additional context

I have a similar system using a basic mcp251x, this is also a dual can HAT. I have noticed that the mcp251xfd is also consuming far more CPU resources than the basic mcp251x, over double the resources ..

mcp251xfd:

1368 2 root SW 0 0% 10% [irq/199-spi0.0]
165 2 root RW 0 0% 6% [spi0]

compared to the mcp251x

29533 2 root SW 0 0% 4% [irq/166-mcp251x]
219 2 root SW 0 0% 2% [spi0]

@pelwell
Copy link
Contributor

pelwell commented Feb 21, 2022

I'm going to leave this open for others to contribute to, but without a dual mcp251xfd HAT and some CAN hardware it's not going to get any attention from me. Have you tried asking @marckleinebudde, whose repo you linked to?

@marckleinebudde
Copy link
Contributor

marckleinebudde commented Feb 21, 2022

Hey @nmbath,

the mcp251xfd driver in linux-v5.10 should work with your hardware, my branch is only performance improvements. If you use a newer raspi kernel, the improvements are already included.

BTW the problem:

[ 23.398211] NOHZ tick-stop error: Non-RCU local softirq work is pending, handler #8!!!

is fixed with v5.15.

Coming back to your problem:

mcp251xfd spi1.0 can1: Failed to detect MCP2518FD (osc=0x00000000).

The driver only reads 0x0, i.e. none of the bits set when reading from spi1.0. Your analysis that the chip select might not be working looks good to me. Do you have a scope to check that? Can you post here you DT overlay configuration?

The mcp251xfd driver uses more resources, as the chip is more complex, it needs more SPI transfers per received CAN message, than the mcp251x driver.

@nmbath
Copy link
Author

nmbath commented Feb 21, 2022

Hi @marckleinebudde, Thank you for your response. The HAT is a waveshare dual mcp251xfd and understand that it uses BCM pin 7 for CS. I have used their default 2xMCP2517FD.dtbo

/dts-v1/;
/plugin/;

/ {
compatible = "brcm,bcm2835", "brcm,bcm2836", "brcm,bcm2708", "brcm,bcm2709";
/* disable spi-dev for spi0.0 */

fragment@0{
target = <&spidev0>;
__overlay__ {
    status = "disabled";
};
};

fragment@1{
target = <&spidev1>;
__overlay__ {
    status = "disabled";
};
};

/* the interrupt pin of the can-controller */
fragment@2 {
    target = <&gpio>;
    __overlay__ {
        can_int_pins: can_int_pins {
            brcm,pins = <25 16>;
            brcm,function = <0>; /* input */
        };
    spi1_pins: spi1_pins {
		brcm,pins = <19 20 21>;
		brcm,function = <3>; /* alt4 */
    };

   spi1_cs_pins: spi1_cs_pins {
		brcm,pins = <26>;
		brcm,function = <1>; /* output */
    };

    };
};

/* the clock/oscillator of the can-controller */
fragment@3 {
    target-path = "/clocks";
    __overlay__ {
        /* external 40M oscillator of mcp2517fd on SPI0.0 */
        mcp2517fd_osc: mcp2517fd_osc {
            compatible = "fixed-clock";
            #clock-cells = <0>;
          clock-frequency  = <40000000>;
        };
    };
};

/* the spi config of the can-controller itself binding everything together */
fragment@4 {
    target = <&spi0>;
    __overlay__ {
        /* needed to avoid dtc warning */
        #address-cells = <1>;
        #size-cells = <0>;

      status = "okay";
        can0: can@0 {
            reg = <0>;
            pinctrl-names = "default";
     	pinctrl-0 = <&can_int_pins>;
            compatible = "microchip,mcp2517fd";
            spi-max-frequency = <20000000>;
            interrupt-parent = <&gpio>;
            interrupts = <25 8>; /* IRQ_TYPE_LEVEL_LOW */
            clocks = <&mcp2517fd_osc>;
        };

    };
};
/* the spi config of the can-controller itself binding everything together */
fragment@5 {
    target = <&spi1>;
    __overlay__ {
        /* needed to avoid dtc warning */
        #address-cells = <1>;
        #size-cells = <0>;


    cs-gpios = <&gpio 26 1>;
    status = "okay";
        can1: can@1 {
            reg = <0>;
            pinctrl-names = "default";
     	pinctrl-0 = <&spi1_pins &spi1_cs_pins>;
            compatible = "microchip,mcp2517fd";
            spi-max-frequency = <20000000>;
            interrupt-parent = <&gpio>;
            interrupts = <16 8>; /* IRQ_TYPE_LEVEL_LOW */
            clocks = <&mcp2517fd_osc>;
        };
};
};

};

Looking at this file they seem to be using GPIO26 for CS on the 2nd unit. I am now in an area I have not done much work on, and I do not have a scope to look at what is going on. GPIO26 is on pin 37, but reading their material CS_1 is physical pin 26, or BCM 7.

I tried changing the CS from 26 to 7, but then I got

[ 6.118410] pinctrl-bcm2835 3f200000.gpio: pin gpio7 already requested by 3f204000.spi; cannot claim for spi1.0
[ 6.128614] pinctrl-bcm2835 3f200000.gpio: pin-7 (spi1.0) status -22
[ 6.128647] mcp251xfd spi1.0: Error applying setting, reverse things back
[ 6.129724] mcp251xfd: probe of spi1.0 failed with error -22

It is probably something very simple, I just cant see it and don't have enough experience with GPIO's!

image

@marckleinebudde
Copy link
Contributor

Ahhh waveshare - adding @pdp7 to the loop.
Drew, long time no see, but do have you got a working Raspi DT Overlay for the waveshare mcp251xfd board?

@pelwell
Copy link
Contributor

pelwell commented Feb 21, 2022

You can release GPIO 7 by adding dtoverlay=spi0-1cs to config.txt.

@pelwell
Copy link
Contributor

pelwell commented Feb 21, 2022

Once you have something that works I can help you tidy it up and get it into the standard kernel builds.

@marckleinebudde
Copy link
Contributor

marckleinebudde commented Feb 21, 2022

Once it's working generate a "compiled" overlay with something like this (parameters have to be adjusted to the waveshare board):

ovmerge -c spi1-1cs-overlay.dts,cs0_pin=18,cs0_spidev=false mcp251xfd-overlay.dts,spi0-0,interrupt=25 mcp251xfd-overlay.dts,spi1-0,interrupt=24

See header of this file:

https://github.com/raspberrypi/linux/blob/rpi-5.15.y/arch/arm/boot/dts/overlays/seeed-can-fd-hat-v1-overlay.dts

@pelwell
Copy link
Contributor

pelwell commented Feb 21, 2022

Except with ,cs0_pin=7 and interrupt=16, i.e.

ovmerge -c spi1-1cs-overlay.dts,cs0_pin=7,cs0_spidev=false mcp251xfd-overlay.dts,spi0-0,interrupt=25 mcp251xfd-overlay.dts,spi1-0,interrupt=16

@marckleinebudde
Copy link
Contributor

ACK, that was a copy/paste from the seeed-can-fd-hat-v1-overlay.dts overlay, that needs to be adjusted. (Updated my comment for clarification).

@pelwell
Copy link
Contributor

pelwell commented Feb 21, 2022

And you can include the spi0-1cs in the same ovmerge command if you want.

@nmbath
Copy link
Author

nmbath commented Feb 21, 2022

I have tried adding spi0-1cs, but didn't seem to do anything and still have the error. Will try again in the morning.

@nmbath
Copy link
Author

nmbath commented Feb 22, 2022

I have just tried this configuration:

dtoverlay=spi0-1cs,cs0_pin=8
dtoverlay=spi1-1cs,cs0_pin=7,cs0_spidev=false
dtoverlay=mcp251xfd,spi1-0,interrupt=16
dtoverlay=mcp251xfd,spi0-0,interrupt=25

And had this..

[    5.872462] spi_master spi1: will run message pump with realtime priority
[    5.917707] mcp251xfd spi1.0 (unnamed net_device) (uninitialized): Failed to detect MCP251xFD (osc=0x00000000).
[    5.996127] spi_master spi0: will run message pump with realtime priority
[    6.014647] mcp251xfd spi0.0 can0: MCP2518FD rev0.0 (-RX_INT -MAB_NO_WARN +CRC_REG +CRC_RX +CRC_TX +ECC -HD c:40.00MHz m:20.00MHz r:17.00MHz e:16.66MHz) successfully initialized.

Digging through Waveshares details, that is correct. Reading the wiki site again, they have two modes, both sharing spi0 and one on spi0 and the other on spi1. The default mode is apparently separate SPI's. They have a different table on the wiki and that looks like when sharing an SPI the CS for can1 is 7 and when separate SPI's is 26. So changed the configuration too

dtoverlay=spi0-1cs,cs0_pin=8
dtoverlay=spi1-1cs,cs0_pin=26,cs0_spidev=false
dtoverlay=mcp251xfd,spi1-0,interrupt=16
dtoverlay=mcp251xfd,spi0-0,interrupt=25

and got this..

[    5.650436] mcp251xfd spi0.0 can0: MCP2518FD rev0.0 (-RX_INT -MAB_NO_WARN +CRC_REG +CRC_RX +CRC_TX +ECC -HD c:40.00MHz m:20.00MHz r:17.00MHz e:16.66MHz) successfully initialized.
[    5.699704] mcp251xfd spi1.0 can1: MCP2518FD rev0.0 (-RX_INT -MAB_NO_WARN +CRC_REG +CRC_RX +CRC_TX +ECC -HD c:40.00MHz m:20.00MHz r:17.00MHz e:16.66MHz) successfully initialized.
[   21.112168] can: controller area network core

ip link set can1 type can bitrate 250000
ifconfig can1 up
ifconfig: SIOCSIFFLAGS: No such device

and

[   77.044505] mcp251xfd spi1.0 can1: Failed to detect MCP2518FD (osc=0x00000000).
[   77.052125] mcp251xfd spi1.0 can1: CRC read error at address 0x0e0c (length=4, data=00 00 00 00, CRC=0x0000) retrying.
[   77.062943] mcp251xfd spi1.0 can1: CRC read error at address 0x0e0c (length=4, data=00 00 00 00, CRC=0x0000) retrying.
[   77.073793] mcp251xfd spi1.0 can1: CRC read error at address 0x0e0c (length=4, data=00 00 00 00, CRC=0x0000) retrying.
[   77.084553] mcp251xfd spi1.0 can1: CRC read error at address 0x0e0c (length=4, data=00 00 00 00, CRC=0x0000).
[   77.094659] mcp251xfd spi1.0 can1: CRC read error at address 0x0000 (length=4, data=00 00 00 00, CRC=0x0000) retrying.
[   77.105529] mcp251xfd spi1.0 can1: CRC read error at address 0x0000 (length=4, data=00 00 00 00, CRC=0x0000) retrying.
[   77.116342] mcp251xfd spi1.0 can1: CRC read error at address 0x0000 (length=4, data=00 00 00 00, CRC=0x0000) retrying.
[   77.127083] mcp251xfd spi1.0 can1: CRC read error at address 0x0000 (length=4, data=00 00 00 00, CRC=0x0000).
[   77.137193] mcp251xfd spi1.0 can1: CRC read error at address 0x0e0c (length=4, data=00 00 00 00, CRC=0x0000) retrying.
[   77.148027] mcp251xfd spi1.0 can1: CRC read error at address 0x0e0c (length=4, data=00 00 00 00, CRC=0x0000) retrying.
[   77.158840] mcp251xfd spi1.0 can1: CRC read error at address 0x0e0c (length=4, data=00 00 00 00, CRC=0x0000) retrying.
[   77.169581] mcp251xfd spi1.0 can1: CRC read error at address 0x0e0c (length=4, data=00 00 00 00, CRC=0x0000).
[   77.179617] mcp251xfd spi1.0 can1: CRC read error at address 0x0000 (length=4, data=00 00 00 00, CRC=0x0000) retrying.
[   77.190433] mcp251xfd spi1.0 can1: CRC read error at address 0x0000 (length=4, data=00 00 00 00, CRC=0x0000) retrying.
[   77.201236] mcp251xfd spi1.0 can1: CRC read error at address 0x0000 (length=4, data=00 00 00 00, CRC=0x0000) retrying.
[   77.211987] mcp251xfd spi1.0 can1: CRC read error at address 0x0000 (length=4, data=00 00 00 00, CRC=0x0000).

So maybe it's not the overlay but something else.

Just to double check, I tried this to make sure it was not on the other mode!

dtoverlay=mcp251xfd,spi0-0,interrupt=25
dtoverlay=mcp251xfd,spi0-1,interrupt=16

and got

[    5.975545] spi_master spi0: will run message pump with realtime priority
[    6.021352] mcp251xfd spi0.1 (unnamed net_device) (uninitialized): Failed to detect MCP251xFD (osc=0x00000000).
[    6.085145] mcp251xfd spi0.0 can0: MCP2518FD rev0.0 (-RX_INT -MAB_NO_WARN +CRC_REG +CRC_RX +CRC_TX +ECC -HD c:40.00MHz m:20.00MHz r:17.00MHz e:16.66MHz) successfully initialized.

Thoughts?

@marckleinebudde
Copy link
Contributor

[    5.650436] mcp251xfd spi0.0 can0: MCP2518FD rev0.0 (-RX_INT -MAB_NO_WARN +CRC_REG +CRC_RX +CRC_TX +ECC -HD c:40.00MHz m:20.00MHz r:17.00MHz e:16.66MHz) successfully initialized.
[    5.699704] mcp251xfd spi1.0 can1: MCP2518FD rev0.0 (-RX_INT -MAB_NO_WARN +CRC_REG +CRC_RX +CRC_TX +ECC -HD c:40.00MHz m:20.00MHz r:17.00MHz e:16.66MHz) successfully initialized.

This mean both mcp251xfd are properly detected. But later, during ifup you got this error messages?

[   77.044505] mcp251xfd spi1.0 can1: Failed to detect MCP2518FD (osc=0x00000000).
[   77.052125] mcp251xfd spi1.0 can1: CRC read error at address 0x0e0c (length=4, data=00 00 00 00, CRC=0x0000) retrying.

Strange. The driver only reads 0x0 from the device. Seems the mcp2518fd is not sending anymore. Can you attach a full kernel log.

@nmbath
Copy link
Author

nmbath commented Feb 22, 2022

full dmesg:

[    0.000000] Booting Linux on physical CPU 0x0
[    0.000000] Linux version 5.10.95-v7 (oe-user@oe-host) (arm-ve-linux-gnueabi-gcc (GCC) 9.3.0, GNU ld (GNU Binutils) 2.34.0.20200220) #1 SMP Fri Feb 18 07:45:17 UTC 2022
[    0.000000] CPU: ARMv7 Processor [410fd034] revision 4 (ARMv7), cr=10c5383d
[    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: Raspberry Pi 3 Model B Rev 1.2
[    0.000000] random: fast init done
[    0.000000] Memory policy: Data cache writealloc
[    0.000000] Reserved memory: created CMA memory pool at 0x37400000, size 64 MiB
[    0.000000] OF: reserved mem: initialized node linux,cma, compatible id shared-dma-pool
[    0.000000] Zone ranges:
[    0.000000]   DMA      [mem 0x0000000000000000-0x000000003b3fffff]
[    0.000000]   Normal   empty
[    0.000000] Movable zone start for each node
[    0.000000] Early memory node ranges
[    0.000000]   node   0: [mem 0x0000000000000000-0x000000003b3fffff]
[    0.000000] Initmem setup node 0 [mem 0x0000000000000000-0x000000003b3fffff]
[    0.000000] On node 0 totalpages: 242688
[    0.000000]   DMA zone: 2133 pages used for memmap
[    0.000000]   DMA zone: 0 pages reserved
[    0.000000]   DMA zone: 242688 pages, LIFO batch:63
[    0.000000] percpu: Embedded 20 pages/cpu s50828 r8192 d22900 u81920
[    0.000000] pcpu-alloc: s50828 r8192 d22900 u81920 alloc=20*4096
[    0.000000] pcpu-alloc: [0] 0 [0] 1 [0] 2 [0] 3 
[    0.000000] Built 1 zonelists, mobility grouping on.  Total pages: 240555
[    0.000000] Kernel command line: coherent_pool=1M 8250.nr_uarts=1 snd_bcm2835.enable_compat_alsa=0 snd_bcm2835.enable_hdmi=1 bcm2708_fb.fbwidth=656 bcm2708_fb.fbheight=416 bcm2708_fb.fbswap=1 vc_mem.mem_base=0x3ec00000 vc_mem.mem_size=0x40000000  dwc_otg.lpm_enable=0 console=ttyAMA0,115200 root=/dev/mmcblk0p2 rootwait
[    0.000000] Dentry cache hash table entries: 131072 (order: 7, 524288 bytes, linear)
[    0.000000] Inode-cache hash table entries: 65536 (order: 6, 262144 bytes, linear)
[    0.000000] mem auto-init: stack:off, heap alloc:off, heap free:off
[    0.000000] Memory: 878792K/970752K available (10240K kernel code, 1312K rwdata, 2980K rodata, 1024K init, 862K bss, 26424K reserved, 65536K cma-reserved)
[    0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1
[    0.000000] ftrace: allocating 32069 entries in 95 pages
[    0.000000] ftrace: allocated 94 pages with 5 groups
[    0.000000] rcu: Hierarchical RCU implementation.
[    0.000000] 	Rude variant of Tasks RCU enabled.
[    0.000000] 	Tracing variant of Tasks RCU enabled.
[    0.000000] rcu: RCU calculated value of scheduler-enlistment delay is 10 jiffies.
[    0.000000] NR_IRQS: 16, nr_irqs: 16, preallocated irqs: 16
[    0.000000] random: get_random_bytes called from start_kernel+0x3b0/0x594 with crng_init=1
[    0.000000] arch_timer: cp15 timer(s) running at 19.20MHz (phys).
[    0.000000] clocksource: arch_sys_counter: mask: 0xffffffffffffff max_cycles: 0x46d987e47, max_idle_ns: 440795202767 ns
[    0.000008] sched_clock: 56 bits at 19MHz, resolution 52ns, wraps every 4398046511078ns
[    0.000025] Switching to timer-based delay loop, resolution 52ns
[    0.000321] Console: colour dummy device 80x30
[    0.000388] Calibrating delay loop (skipped), value calculated using timer frequency.. 38.40 BogoMIPS (lpj=192000)
[    0.000424] pid_max: default: 32768 minimum: 301
[    0.000633] LSM: Security Framework initializing
[    0.000878] Mount-cache hash table entries: 2048 (order: 1, 8192 bytes, linear)
[    0.000909] Mountpoint-cache hash table entries: 2048 (order: 1, 8192 bytes, linear)
[    0.002317] cgroup: Disabling memory control group subsystem
[    0.002604] CPU: Testing write buffer coherency: ok
[    0.003106] CPU0: thread -1, cpu 0, socket 0, mpidr 80000000
[    0.004328] Setting up static identity map for 0x100000 - 0x10003c
[    0.004519] rcu: Hierarchical SRCU implementation.
[    0.005446] smp: Bringing up secondary CPUs ...
[    0.006616] CPU1: thread -1, cpu 1, socket 0, mpidr 80000001
[    0.007907] CPU2: thread -1, cpu 2, socket 0, mpidr 80000002
[    0.009096] CPU3: thread -1, cpu 3, socket 0, mpidr 80000003
[    0.009252] smp: Brought up 1 node, 4 CPUs
[    0.009296] SMP: Total of 4 processors activated (153.60 BogoMIPS).
[    0.009314] CPU: All CPU(s) started in HYP mode.
[    0.009330] CPU: Virtualization extensions available.
[    0.010429] devtmpfs: initialized
[    0.028694] VFP support v0.3: implementor 41 architecture 3 part 40 variant 3 rev 4
[    0.028947] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 ns
[    0.028984] futex hash table entries: 1024 (order: 4, 65536 bytes, linear)
[    0.031978] pinctrl core: initialized pinctrl subsystem
[    0.033194] NET: Registered protocol family 16
[    0.037174] DMA: preallocated 1024 KiB pool for atomic coherent allocations
[    0.042918] audit: initializing netlink subsys (disabled)
[    0.043815] thermal_sys: Registered thermal governor 'step_wise'
[    0.044634] audit: type=2000 audit(0.040:1): state=initialized audit_enabled=0 res=1
[    0.044827] hw-breakpoint: found 5 (+1 reserved) breakpoint and 4 watchpoint registers.
[    0.044847] hw-breakpoint: maximum watchpoint size is 8 bytes.
[    0.045164] Serial: AMBA PL011 UART driver
[    0.068373] bcm2835-mbox 3f00b880.mailbox: mailbox enabled
[    0.080086] raspberrypi-firmware soc:firmware: Attached to firmware from 2022-01-20T13:58:22, variant start
[    0.090098] raspberrypi-firmware soc:firmware: Firmware hash is bd88f66f8952d34e4e0613a85c7a6d3da49e13e2
[    0.134956] Kprobes globally optimized
[    0.140325] bcm2835-dma 3f007000.dma: DMA legacy API manager, dmachans=0x1
[    0.142552] SCSI subsystem initialized
[    0.142821] usbcore: registered new interface driver usbfs
[    0.142894] usbcore: registered new interface driver hub
[    0.142974] usbcore: registered new device driver usb
[    0.144858] clocksource: Switched to clocksource arch_sys_counter
[    1.753306] VFS: Disk quotas dquot_6.6.0
[    1.753432] VFS: Dquot-cache hash table entries: 1024 (order 0, 4096 bytes)
[    1.753647] FS-Cache: Loaded
[    1.753937] CacheFiles: Loaded
[    1.754157] simple-framebuffer 3eaf0000.framebuffer: framebuffer at 0x3eaf0000, 0x10a800 bytes, mapped to 0x(ptrval)
[    1.754184] simple-framebuffer 3eaf0000.framebuffer: format=a8r8g8b8, mode=656x416x32, linelength=2624
[    1.759216] Console: switching to colour frame buffer device 82x26
[    1.763723] simple-framebuffer 3eaf0000.framebuffer: fb0: simplefb registered!
[    1.774559] NET: Registered protocol family 2
[    1.774823] IP idents hash table entries: 16384 (order: 5, 131072 bytes, linear)
[    1.776761] tcp_listen_portaddr_hash hash table entries: 512 (order: 0, 6144 bytes, linear)
[    1.776831] TCP established hash table entries: 8192 (order: 3, 32768 bytes, linear)
[    1.776957] TCP bind hash table entries: 8192 (order: 4, 65536 bytes, linear)
[    1.777156] TCP: Hash tables configured (established 8192 bind 8192)
[    1.777346] UDP hash table entries: 512 (order: 2, 16384 bytes, linear)
[    1.777410] UDP-Lite hash table entries: 512 (order: 2, 16384 bytes, linear)
[    1.777705] NET: Registered protocol family 1
[    1.778472] RPC: Registered named UNIX socket transport module.
[    1.778493] RPC: Registered udp transport module.
[    1.778510] RPC: Registered tcp transport module.
[    1.778529] RPC: Registered tcp NFSv4.1 backchannel transport module.
[    1.780145] hw perfevents: enabled with armv7_cortex_a7 PMU driver, 7 counters available
[    1.783964] Initialise system trusted keyrings
[    1.784232] workingset: timestamp_bits=14 max_order=18 bucket_order=4
[    1.793838] zbud: loaded
[    1.796004] FS-Cache: Netfs 'nfs' registered for caching
[    1.796913] NFS: Registering the id_resolver key type
[    1.796989] Key type id_resolver registered
[    1.797008] Key type id_legacy registered
[    1.797164] nfs4filelayout_init: NFSv4 File Layout Driver Registering...
[    1.797186] nfs4flexfilelayout_init: NFSv4 Flexfile Layout Driver Registering...
[    1.798390] Key type asymmetric registered
[    1.798412] Asymmetric key parser 'x509' registered
[    1.798472] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 249)
[    1.798494] io scheduler mq-deadline registered
[    1.798512] io scheduler kyber registered
[    1.803602] bcm2708_fb soc:fb: FB found 1 display(s)
[    1.806804] bcm2708_fb soc:fb: Registered framebuffer for display 0, size 656x416
[    1.811015] Serial: 8250/16550 driver, 1 ports, IRQ sharing enabled
[    1.813867] bcm2835-rng 3f104000.rng: hwrng registered
[    1.814391] vc-mem: phys_addr:0x00000000 mem_base=0x3ec00000 mem_size:0x40000000(1024 MiB)
[    1.815667] gpiomem-bcm2835 3f200000.gpiomem: Initialised: Registers at 0x3f200000
[    1.828007] brd: module loaded
[    1.840114] loop: module loaded
[    1.841902] Loading iSCSI transport class v2.0-870.
[    1.843756] usbcore: registered new interface driver lan78xx
[    1.843834] usbcore: registered new interface driver smsc95xx
[    1.843865] dwc_otg: version 3.00a 10-AUG-2012 (platform bus)
[    2.044493] Core Release: 2.80a
[    2.044516] Setting default values for core params
[    2.044550] Finished setting default values for core params
[    2.244983] Using Buffer DMA mode
[    2.245004] Periodic Transfer Interrupt Enhancement - disabled
[    2.245021] Multiprocessor Interrupt Enhancement - disabled
[    2.245040] OTG VER PARAM: 0, OTG VER FLAG: 0
[    2.245072] Dedicated Tx FIFOs mode
[    2.245760] 
[    2.245781] WARN::dwc_otg_hcd_init:1072: FIQ DMA bounce buffers: virt = b7504000 dma = 0xf7504000 len=9024
[    2.245823] FIQ FSM acceleration enabled for :
[    2.245823] Non-periodic Split Transactions
[    2.245823] Periodic Split Transactions
[    2.245823] High-Speed Isochronous Endpoints
[    2.245823] Interrupt/Control Split Transaction hack enabled
[    2.245847] dwc_otg: Microframe scheduler enabled
[    2.245917] 
[    2.245927] WARN::hcd_init_fiq:457: FIQ on core 1
[    2.245940] 
[    2.245950] WARN::hcd_init_fiq:458: FIQ ASM at 807d8f7c length 36
[    2.245965] 
[    2.245974] WARN::hcd_init_fiq:496: MPHI regs_base at bb810000
[    2.246002] dwc_otg 3f980000.usb: DWC OTG Controller
[    2.246047] dwc_otg 3f980000.usb: new USB bus registered, assigned bus number 1
[    2.246103] dwc_otg 3f980000.usb: irq 89, io mem 0x00000000
[    2.246161] Init: Port Power? op_state=1
[    2.246179] Init: Power Port (0)
[    2.246560] usb usb1: New USB device found, idVendor=1d6b, idProduct=0002, bcdDevice= 5.10
[    2.246584] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[    2.246605] usb usb1: Product: DWC OTG Controller
[    2.246626] usb usb1: Manufacturer: Linux 5.10.95-v7 dwc_otg_hcd
[    2.246646] usb usb1: SerialNumber: 3f980000.usb
[    2.247408] hub 1-0:1.0: USB hub found
[    2.247480] hub 1-0:1.0: 1 port detected
[    2.248528] dwc_otg: FIQ enabled
[    2.248541] dwc_otg: NAK holdoff enabled
[    2.248554] dwc_otg: FIQ split-transaction FSM enabled
[    2.248572] Module dwc_common_port init
[    2.249211] usbcore: registered new interface driver usb-storage
[    2.249524] mousedev: PS/2 mouse device common for all mice
[    2.250884] bcm2835-wdt bcm2835-wdt: Broadcom BCM2835 watchdog timer
[    2.253447] sdhci: Secure Digital Host Controller Interface driver
[    2.253466] sdhci: Copyright(c) Pierre Ossman
[    2.254084] mmc-bcm2835 3f300000.mmcnr: could not get clk, deferring probe
[    2.254752] sdhost-bcm2835 3f202000.mmc: could not get clk, deferring probe
[    2.255071] sdhci-pltfm: SDHCI platform and OF driver helper
[    2.257086] ledtrig-cpu: registered to indicate activity on CPUs
[    2.257500] hid: raw HID events driver (C) Jiri Kosina
[    2.257676] usbcore: registered new interface driver usbhid
[    2.257695] usbhid: USB HID core driver
[    2.262315] Initializing XFRM netlink socket
[    2.262369] NET: Registered protocol family 17
[    2.262546] Key type dns_resolver registered
[    2.263070] Registering SWP/SWPB emulation handler
[    2.263227] registered taskstats version 1
[    2.263262] Loading compiled-in X.509 certificates
[    2.264146] Key type ._fscrypt registered
[    2.264167] Key type .fscrypt registered
[    2.264186] Key type fscrypt-provisioning registered
[    2.275994] uart-pl011 3f201000.serial: there is not valid maps for state default
[    2.276217] uart-pl011 3f201000.serial: cts_event_workaround enabled
[    2.276316] 3f201000.serial: ttyAMA0 at MMIO 0x3f201000 (irq = 114, base_baud = 0) is a PL011 rev2
[    3.352547] printk: console [ttyAMA0] enabled
[    3.357484] Indeed it is in host mode hprt0 = 00021501
[    3.425549] 3f215040.serial: ttyS0 at MMIO 0x3f215040 (irq = 86, base_baud = 50000000) is a 16550
[    3.435625] bcm2835-power bcm2835-power: Broadcom BCM2835 power domains driver
[    3.444599] mmc-bcm2835 3f300000.mmcnr: mmc_debug:0 mmc_debug2:0
[    3.450642] mmc-bcm2835 3f300000.mmcnr: DMA channel allocated
[    3.483414] sdhost: log_buf @ (ptrval) (f7507000)
[    3.524086] mmc1: queuing unknown CIS tuple 0x80 (2 bytes)
[    3.531289] mmc1: queuing unknown CIS tuple 0x80 (3 bytes)
[    3.538463] mmc1: queuing unknown CIS tuple 0x80 (3 bytes)
[    3.544008] mmc0: sdhost-bcm2835 loaded - DMA enabled (>1)
[    3.552738] of_cfs_init
[    3.555409] of_cfs_init: OK
[    3.559348] uart-pl011 3f201000.serial: no DMA platform data
[    3.565587] Waiting for root device /dev/mmcblk0p2...
[    3.572760] mmc1: queuing unknown CIS tuple 0x80 (7 bytes)
[    3.578343] usb 1-1: new high-speed USB device number 2 using dwc_otg
[    3.584968] Indeed it is in host mode hprt0 = 00001101
[    3.684896] mmc0: host does not support reading read-only switch, assuming write-enable
[    3.695952] mmc0: new high speed SDHC card at address 0007
[    3.702474] mmcblk0: mmc0:0007 SD16G 14.5 GiB
[    3.709823]  mmcblk0: p1 p2 p3 p4
[    3.759881] EXT4-fs (mmcblk0p2): mounted filesystem with ordered data mode. Opts: (null)
[    3.768099] VFS: Mounted root (ext4 filesystem) readonly on device 179:2.
[    3.772362] mmc1: new high speed SDIO card at address 0001
[    3.776109] devtmpfs: mounted
[    3.791442] Freeing unused kernel memory: 1024K
[    3.796573] Run /sbin/init as init process
[    3.800675]   with arguments:
[    3.800686]     /sbin/init
[    3.800697]   with environment:
[    3.800709]     HOME=/
[    3.800720]     TERM=linux
[    3.825270] usb 1-1: New USB device found, idVendor=0424, idProduct=9514, bcdDevice= 2.00
[    3.833477] usb 1-1: New USB device strings: Mfr=0, Product=0, SerialNumber=0
[    3.841498] hub 1-1:1.0: USB hub found
[    3.845445] hub 1-1:1.0: 5 ports detected
[    4.164918] usb 1-1.1: new high-speed USB device number 3 using dwc_otg
[    4.295387] usb 1-1.1: New USB device found, idVendor=0424, idProduct=ec00, bcdDevice= 2.00
[    4.303781] usb 1-1.1: New USB device strings: Mfr=0, Product=0, SerialNumber=0
[    4.314128] smsc95xx v2.0.0
[    4.359997] EXT4-fs (mmcblk0p4): mounted filesystem with ordered data mode. Opts: (null)
[    4.461174] smsc95xx 1-1.1:1.0 eth0: register 'smsc95xx' at usb-3f980000.usb-1.1, smsc95xx USB 2.0 Ethernet, b8:27:eb:1f:e6:f8
[    4.564952] usb 1-1.4: new high-speed USB device number 4 using dwc_otg
[    4.588713] udevd[135]: starting version 3.2.9
[    4.603406] random: udevd: uninitialized urandom read (16 bytes read)
[    4.611081] random: udevd: uninitialized urandom read (16 bytes read)
[    4.617879] random: udevd: uninitialized urandom read (16 bytes read)
[    4.678599] udevd[136]: starting eudev-3.2.9
[    4.727276] usb 1-1.4: New USB device found, idVendor=058f, idProduct=6387, bcdDevice= 1.04
[    4.735834] usb 1-1.4: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[    4.743159] usb 1-1.4: Product: Mass Storage
[    4.747469] usb 1-1.4: Manufacturer: Generic
[    4.751758] usb 1-1.4: SerialNumber: A0B041AE
[    4.757444] usb-storage 1-1.4:1.0: USB Mass Storage device detected
[    4.775056] scsi host0: usb-storage 1-1.4:1.0
[    4.816207] gpio-fan gpio-fan@0: GPIO fan initialized
[    4.947566] vc_sm_cma: module is from the staging directory, the quality is unknown, you have been warned.
[    4.960168] bcm2835_vc_sm_cma_probe: Videocore shared memory driver
[    4.966657] [vc_sm_connected_init]: start
[    4.973696] usbcore: registered new interface driver uas
[    4.980234] [vc_sm_connected_init]: installed successfully
[    4.988273] mc: Linux media interface: v0.10
[    5.064995] videodev: Linux video capture interface: v2.00
[    5.241094] bcm2835_mmal_vchiq: module is from the staging directory, the quality is unknown, you have been warned.
[    5.241102] bcm2835_mmal_vchiq: module is from the staging directory, the quality is unknown, you have been warned.
[    5.245026] bcm2835_mmal_vchiq: module is from the staging directory, the quality is unknown, you have been warned.
[    5.283324] cfg80211: Loading compiled-in X.509 certificates for regulatory database
[    5.288699] bcm2835_v4l2: module is from the staging directory, the quality is unknown, you have been warned.
[    5.303175] bcm2835_isp: module is from the staging directory, the quality is unknown, you have been warned.
[    5.354629] bcm2835_codec: module is from the staging directory, the quality is unknown, you have been warned.
[    5.378322] bcm2835-codec bcm2835-codec: Device registered as /dev/video10
[    5.382895] bcm2835-isp bcm2835-isp: Device node output[0] registered as /dev/video13
[    5.392038] bcm2835-codec bcm2835-codec: Loaded V4L2 decode
[    5.400946] bcm2835-isp bcm2835-isp: Device node capture[0] registered as /dev/video14
[    5.420807] cfg80211: Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7'
[    5.429983] bcm2835-codec bcm2835-codec: Device registered as /dev/video11
[    5.440609] bcm2835-codec bcm2835-codec: Loaded V4L2 encode
[    5.453080] bcm2835-isp bcm2835-isp: Device node capture[1] registered as /dev/video15
[    5.463259] bcm2835-codec bcm2835-codec: Device registered as /dev/video12
[    5.470484] bcm2835-codec bcm2835-codec: Loaded V4L2 isp
[    5.487264] bcm2835-codec bcm2835-codec: Device registered as /dev/video18
[    5.494415] bcm2835-codec bcm2835-codec: Loaded V4L2 image_fx
[    5.525814] bcm2835-isp bcm2835-isp: Device node stats[2] registered as /dev/video16
[    5.535377] bcm2835-isp bcm2835-isp: Register output node 0 with media controller
[    5.551177] bcm2835-isp bcm2835-isp: Register capture node 1 with media controller
[    5.608382] bcm2835-isp bcm2835-isp: Register capture node 2 with media controller
[    5.622919] bcm2835-isp bcm2835-isp: Register capture node 3 with media controller
[    5.634115] brcmfmac: F1 signature read @0x18000000=0x1541a9a6
[    5.645711] bcm2835-isp bcm2835-isp: Device node output[0] registered as /dev/video20
[    5.655991] bcm2835-isp bcm2835-isp: Device node capture[0] registered as /dev/video21
[    5.665495] bcm2835-isp bcm2835-isp: Device node capture[1] registered as /dev/video22
[    5.674746] bcm2835-isp bcm2835-isp: Device node stats[2] registered as /dev/video23
[    5.682759] bcm2835-isp bcm2835-isp: Register output node 0 with media controller
[    5.690429] bcm2835-isp bcm2835-isp: Register capture node 1 with media controller
[    5.698201] bcm2835-isp bcm2835-isp: Register capture node 2 with media controller
[    5.698531] brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac43430-sdio for chip BCM43430/1
[    5.713058] bcm2835-isp bcm2835-isp: Register capture node 3 with media controller
[    5.717916] usbcore: registered new interface driver brcmfmac
[    5.729139] bcm2835-isp bcm2835-isp: Loaded V4L2 bcm2835-isp
[    5.836796] scsi 0:0:0:0: Direct-Access     Generic  Flash Disk       8.07 PQ: 0 ANSI: 2
[    5.847542] sd 0:0:0:0: [sda] 4136192 512-byte logical blocks: (2.12 GB/1.97 GiB)
[    5.857150] sd 0:0:0:0: [sda] Write Protect is off
[    5.862291] sd 0:0:0:0: [sda] Mode Sense: 03 00 00 00
[    5.864115] sd 0:0:0:0: [sda] No Caching mode page found
[    5.869582] sd 0:0:0:0: [sda] Assuming drive cache: write through
[    5.899600] CAN device driver interface
[    5.923121] spi_master spi0: will run message pump with realtime priority
[    5.940362] mcp251xfd spi0.0 (unnamed net_device) (uninitialized): Detected MCP2518FD, but firmware specifies a MCP2517FD. Fixing up.
[    5.983905] mcp251xfd spi0.0 can0: MCP2518FD rev0.0 (-RX_INT -MAB_NO_WARN +CRC_REG +CRC_RX +CRC_TX +ECC -HD c:40.00MHz m:20.00MHz r:17.00MHz e:16.66MHz) successfully initialized.
[    6.005599] spi_master spi1: will run message pump with realtime priority
[    6.021405] mcp251xfd spi1.0 (unnamed net_device) (uninitialized): Detected MCP2518FD, but firmware specifies a MCP2517FD. Fixing up.
[    6.028834] random: crng init done
[    6.036865] random: 2 urandom warning(s) missed due to ratelimiting
[    6.049346] mcp251xfd spi1.0 can1: MCP2518FD rev0.0 (-RX_INT -MAB_NO_WARN +CRC_REG +CRC_RX +CRC_TX +ECC -HD c:40.00MHz m:20.00MHz r:17.00MHz e:16.66MHz) successfully initialized.
[    6.081218] brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac43430-sdio for chip BCM43430/1
[    6.090259] brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac43430-sdio for chip BCM43430/1
[    6.101254] brcmfmac: brcmf_c_process_clm_blob: no clm_blob available (err=-2), device may have limited channels available
[    6.101433] Bluetooth: Core ver 2.22
[    6.104377]  sda: sda1
[    6.115498] brcmfmac: brcmf_c_preinit_dcmds: Firmware: BCM43430/1 wl0: Oct 22 2019 01:59:28 version 7.45.98.94 (r723000 CY) FWID 01-3b33decd
[    6.116167] NET: Registered protocol family 31
[    6.120563] sd 0:0:0:0: [sda] Attached SCSI removable disk
[    6.131062] Bluetooth: HCI device and connection manager initialized
[    6.131101] Bluetooth: HCI socket layer initialized
[    6.131144] Bluetooth: L2CAP socket layer initialized
[    6.157607] Bluetooth: SCO socket layer initialized
[    6.190592] Bluetooth: HCI UART driver ver 2.3
[    6.195120] Bluetooth: HCI UART protocol H4 registered
[    6.200429] Bluetooth: HCI UART protocol Three-wire (H5) registered
[    6.221113] Bluetooth: HCI UART protocol Broadcom registered
[    6.418520] F2FS-fs (sda): Magic Mismatch, valid(0xf2f52010) - read(0x0)
[    6.425282] F2FS-fs (sda): Can't find valid F2FS filesystem in 1th superblock
[    6.433115] F2FS-fs (sda): Magic Mismatch, valid(0xf2f52010) - read(0x0)
[    6.439957] F2FS-fs (sda): Can't find valid F2FS filesystem in 2th superblock
[    6.773589] FAT-fs (sda1): Volume was not properly unmounted. Some data may be corrupt. Please run fsck.
[    6.886714] EXT4-fs (mmcblk0p2): re-mounted. Opts: (null)
[    8.823547] NET: Registered protocol family 10
[    8.829712] Segment Routing with IPv6
[    8.889667] watchdog: watchdog0: watchdog did not stop!
[    9.685800] NET: Registered protocol family 38
[    9.716459] cryptd: max_cpu_qlen set to 1000
[   10.927759] SMSC LAN8700 usb-001:003:01: attached PHY driver [SMSC LAN8700] (mii_bus:phy_addr=usb-001:003:01, irq=POLL)
[   10.940070] smsc95xx 1-1.1:1.0 eth0: hardware isn't capable of remote wakeup
[   10.947222] device eth0 entered promiscuous mode
[   11.106564] smsc95xx 1-1.1:1.0 eth0: Link is Down
[   11.120646] brcmfmac: brcmf_cfg80211_set_power_mgmt: power save enabled
[   13.356602] smsc95xx 1-1.1:1.0 eth0: Link is Up - 100Mbps/Full - flow control off
[   13.364178] IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
[   13.373570] IPv6: ADDRCONF(NETDEV_CHANGE): ll-eth0: link becomes ready
[   13.418123] 8021q: 802.1Q VLAN Support v1.8
[   15.263310] EXT4-fs (mmcblk0p3): mounted filesystem with ordered data mode. Opts: (null)
[   18.789915] can: controller area network core
[   18.796373] NET: Registered protocol family 29
[   18.839459] IPv6: ADDRCONF(NETDEV_CHANGE): can0: link becomes ready
[   18.967371] can: raw protocol
[   19.012973] NOHZ tick-stop error: Non-RCU local softirq work is pending, handler #08!!!
[   19.026642] NOHZ tick-stop error: Non-RCU local softirq work is pending, handler #08!!!
[   19.169767] NOHZ tick-stop error: Non-RCU local softirq work is pending, handler #08!!!
[   19.180846] NOHZ tick-stop error: Non-RCU local softirq work is pending, handler #08!!!
[   19.192669] NOHZ tick-stop error: Non-RCU local softirq work is pending, handler #08!!!
[   19.201457] NOHZ tick-stop error: Non-RCU local softirq work is pending, handler #08!!!
[   19.213719] NOHZ tick-stop error: Non-RCU local softirq work is pending, handler #08!!!
[   19.223518] NOHZ tick-stop error: Non-RCU local softirq work is pending, handler #08!!!
[   19.233351] NOHZ tick-stop error: Non-RCU local softirq work is pending, handler #08!!!
[   19.244591] NOHZ tick-stop error: Non-RCU local softirq work is pending, handler #08!!!
[   33.760686] cam1-reg: disabling
[   33.763888] cam-dummy-reg: disabling
[   62.398501] mcp251xfd spi1.0 can1: Failed to detect MCP2518FD (osc=0x00000000).
[   62.406162] mcp251xfd spi1.0 can1: CRC read error at address 0x0e0c (length=4, data=00 00 00 00, CRC=0x0000) retrying.
[   62.417409] mcp251xfd spi1.0 can1: CRC read error at address 0x0e0c (length=4, data=00 00 00 00, CRC=0x0000) retrying.
[   62.428744] mcp251xfd spi1.0 can1: CRC read error at address 0x0e0c (length=4, data=00 00 00 00, CRC=0x0000) retrying.
[   62.439521] mcp251xfd spi1.0 can1: CRC read error at address 0x0e0c (length=4, data=00 00 00 00, CRC=0x0000).
[   62.450228] mcp251xfd spi1.0 can1: CRC read error at address 0x0000 (length=4, data=00 00 00 00, CRC=0x0000) retrying.
[   62.461811] mcp251xfd spi1.0 can1: CRC read error at address 0x0000 (length=4, data=00 00 00 00, CRC=0x0000) retrying.
[   62.473109] mcp251xfd spi1.0 can1: CRC read error at address 0x0000 (length=4, data=00 00 00 00, CRC=0x0000) retrying.
[   62.483854] mcp251xfd spi1.0 can1: CRC read error at address 0x0000 (length=4, data=00 00 00 00, CRC=0x0000).
[   62.494076] mcp251xfd spi1.0 can1: CRC read error at address 0x0e0c (length=4, data=00 00 00 00, CRC=0x0000) retrying.
[   62.505333] mcp251xfd spi1.0 can1: CRC read error at address 0x0e0c (length=4, data=00 00 00 00, CRC=0x0000) retrying.
[   62.516237] mcp251xfd spi1.0 can1: CRC read error at address 0x0e0c (length=4, data=00 00 00 00, CRC=0x0000) retrying.
[   62.526978] mcp251xfd spi1.0 can1: CRC read error at address 0x0e0c (length=4, data=00 00 00 00, CRC=0x0000).
[   62.537479] mcp251xfd spi0.0 can0: RX-0: FIFO overflow.
[   62.543382] mcp251xfd spi1.0 can1: CRC read error at address 0x0000 (length=4, data=00 00 00 00, CRC=0x0000) retrying.
[   62.554691] mcp251xfd spi1.0 can1: CRC read error at address 0x0000 (length=4, data=00 00 00 00, CRC=0x0000) retrying.
[   62.566077] mcp251xfd spi1.0 can1: CRC read error at address 0x0000 (length=4, data=00 00 00 00, CRC=0x0000) retrying.
[   62.576826] mcp251xfd spi1.0 can1: CRC read error at address 0x0000 (length=4, data=00 00 00 00, CRC=0x0000).

Logged in at roughly 33.x

Issued the following command, which triggered the log messages at 62.x

root@raspberrypi2:~#  ip link set can1 type can bitrate 250000
root@raspberrypi2:~# ifconfig can1 up
ifconfig: SIOCSIFFLAGS: No such device

@marckleinebudde
Copy link
Contributor

marckleinebudde commented Feb 22, 2022

Which overlays are you using in this bootlog? This looks like the waveshare overlays? Which chips are on your waveshare hat? mcp2517fd or mcp2518fd?

The driver says the firmware (the device tree + overlays) are specifying a mcp2517fd, but the driver has detected the mcp2518fd.

[    5.940362] mcp251xfd spi0.0 (unnamed net_device) (uninitialized): Detected MCP2518FD, but firmware specifies a MCP2517FD. Fixing up.
[    5.983905] mcp251xfd spi0.0 can0: MCP2518FD rev0.0 (-RX_INT -MAB_NO_WARN +CRC_REG +CRC_RX +CRC_TX +ECC -HD c:40.00MHz m:20.00MHz r:17.00MHz e:16.66MHz) successfully initialized.
[    6.005599] spi_master spi1: will run message pump with realtime priority
[    6.021405] mcp251xfd spi1.0 (unnamed net_device) (uninitialized): Detected MCP2518FD, but firmware specifies a MCP2517FD. Fixing up.
[    6.049346] mcp251xfd spi1.0 can1: MCP2518FD rev0.0 (-RX_INT -MAB_NO_WARN +CRC_REG +CRC_RX +CRC_TX +ECC -HD c:40.00MHz m:20.00MHz r:17.00MHz e:16.66MHz) successfully initialized.

What's your config.txt?
Can you past the output of:

dtc -I fs /proc/device-tree

Later in the boot log we see these error messages:

[   19.012973] NOHZ tick-stop error: Non-RCU local softirq work is pending, handler #08!!!

This indicates that one driver instance is sending CAN messages to the Linux networking stack:

  • Is can0 attached to a CAN bus?
  • Is can1 attached to a CAN bus?
  • Is the can0 interface automatically configured and brought up?
  • Is the can1 interface automatically configured and brought up?

The question is, what happens between the interface is properly detected:

[    6.049346] mcp251xfd spi1.0 can1: MCP2518FD rev0.0 (-RX_INT -MAB_NO_WARN +CRC_REG +CRC_RX +CRC_TX +ECC -HD c:40.00MHz m:20.00MHz r:17.00MHz e:16.66MHz) successfully initialized.

and

[   62.398501] mcp251xfd spi1.0 can1: Failed to detect MCP2518FD (osc=0x00000000).

After the driver detects the chip, the chip is shut down again. When you issue a ip link set up the chip is reset the driver is polling the OSC register to show the reset defaults, but register only shows 0x0. The question is why.

@nmbath
Copy link
Author

nmbath commented Feb 22, 2022

@marckleinebudde,

Yes I am using the waveshare overlay, and this is my full config.txt

kernel=u-boot.bin

[pi2]
device_tree=bcm2709-rpi-2-b.dtb

[pi3]
device_tree=bcm2710-rpi-3-b.dtb
dtoverlay=miniuart-bt
core_freq=400
core_freq_min=400

[pi3+]
device_tree=bcm2710-rpi-3-b-plus.dtb
dtoverlay=miniuart-bt
core_freq=400
core_freq_min=400

[all]
#dtparam=spi=on
dtoverlay=gpio-fan,gpiopin=5,temp=55000

#dtoverlay=spi0-1cs,cs0_pin=8
#dtoverlay=spi1-1cs,cs0_pin=26,cs0_spidev=false
#dtoverlay=mcp251xfd,spi0-0,interrupt=25
#dtoverlay=mcp251xfd,spi0-1,interrupt=16

#dtoverlay=seeed-can-fd-hat-v1
dtoverlay=2xMCP2517FD
#dtoverlay=mcp251xfd,spi0-0,interrupt=25
#dtoverlay=mcp251xfd,spi1-0,interrupt=16

can0 is automatically configured at 250kb and starte, it is connected to a can bus, with a device running cangen can0 -g 1 -p 10 -i -x

can1 has nothing attached to it at present and no automatic configuration set. I can connect it to an active port, but had not until I actually get the device working.

dtc.txt

@marckleinebudde
Copy link
Contributor

Which chips are on your waveshare hat? mcp2517fd or mcp2518fd?

So let's recap:

  • you have two mcp2518fd (probably 18)
  • one is connected to spi0 CS0
  • one is connected to spi1 CS0

The questions are:

  • which GPIO is used for spi0 CS0
  • which GPIO is used for spi1 CS0
  • which GPIO is used for IRQ on chip attached to spi0 CS0
  • which GPIO is used for IRQ on chip attached to spi1 CS0

@nmbath
Copy link
Author

nmbath commented Feb 22, 2022

I have looked at the CHIPs on the HAT and they are labelled MCP2518FD, which aligns with their Web site

Also on their web site in the Wiki section is the attached table. This would imply that the details are

spi0 CS0 is 8
spi1 CS0 is 26
IRQ on spi0 CS0 is 25
IRQ on spi1 CS0 is 16

image

In addition their published schematic supports this as well.

When configured like this I get

[   11.628186] mcp251xfd spi0.0 (unnamed net_device) (uninitialized): Detected MCP2518FD, but firmware specifies a MCP2517FD. Fixing up.
[   11.649036] mcp251xfd spi0.0 can0: MCP2518FD rev0.0 (-RX_INT -MAB_NO_WARN +CRC_REG +CRC_RX +CRC_TX +ECC -HD c:40.00MHz m:20.00MHz r:17.00MHz e:16.66MHz) successfully initialized.
[   11.692113] mcp251xfd spi1.0 (unnamed net_device) (uninitialized): Detected MCP2518FD, but firmware specifies a MCP2517FD. Fixing up.
[   11.707525] mcp251xfd spi1.0 can1: MCP2518FD rev0.0 (-RX_INT -MAB_NO_WARN +CRC_REG +CRC_RX +CRC_TX +ECC -HD c:40.00MHz m:20.00MHz r:17.00MHz e:16.66MHz) successfully initialized.

With any other configuration of interrupt or cs0 I fail to get one or the other to initialise.

@nmbath
Copy link
Author

nmbath commented Feb 22, 2022

I have managed to compile the mcp25xxfd driver from within the source code on the waveshare wiki

Once I rmmod mcp251xfd and modprobe mcp25xxfd I managed to get both can0 and can1 working

root@raspberrypi2:~# modprobe mcp25xxfd
root@raspberrypi2:~# ip link set can1 type can bitrate 250000
root@raspberrypi2:~# ifconfig can1 up
root@raspberrypi2:~# candump can1

No traffic as the can port is not connected, I also got this in dmesg [ 1341.887415] IPv6: ADDRCONF(NETDEV_CHANGE): can1: link becomes ready

It does seem to be a code/driver issue as opposed to overlay file. I will dig through and see if I can spot where the code differs between the example waveshare has provided and the based 5.10.y code.

Also no NOHZ tick-stop error: Non-RCU local softirq work is pending, handler #08!!! errors so they may have a hybrid between 5.10 and 5.15 code bases!

@marckleinebudde
Copy link
Contributor

If you don't receive any CAN messages you'll not get the NOHZ tick-stop error error. That's a very old driver, even before it got mainline.

@marckleinebudde
Copy link
Contributor

I found something interesting:

 #define MCP25XXFD_POLL_SLEEP_US (10)
-#define MCP25XXFD_POLL_TIMEOUT_US (USEC_PER_MSEC)
+#define MCP25XXFD_POLL_TIMEOUT_US 500000
 #define MCP25XXFD_SOFTRESET_RETRIES_MAX 3
 #define MCP25XXFD_READ_CRC_RETRIES_MAX 3

Waveshare increased the timeout from 1 ms to 500ms. Can you increase the timeout and try the mainline driver?

@pelwell
Copy link
Contributor

pelwell commented Feb 22, 2022

In case I forget later, thank you for looking into this, Marc.

@marckleinebudde
Copy link
Contributor

I strongly suggest to use the mainline driver, as the waveshare driver is old and contains several bugs, that have been fixed on mainline.

@pelwell
Copy link
Contributor

pelwell commented Feb 23, 2022

It's unfortunate that in mcp251xfd_chip_clock_enable the mainline driver checks for the validity of the value read from the OSC register before checking if the read timed out. Presumably it has been silently timing out, and the increased timeout value makes it work.

@nmbath
Copy link
Author

nmbath commented Feb 23, 2022

@marckleinebudde, I would also like to a dd my thanks for your support.

I strongly suggest to use the mainline driver, as the waveshare driver is old and contains several bugs, that have been fixed on mainline.

I agree that going with mainline is the correct approach. Wanted to test what waveshare supplied to try and help identify the problem. Looks like we have found a code issue rather than overlay!

Waveshare increased the timeout from 1 ms to 500ms. Can you increase the timeout and try the mainline driver?

I have applied the following

diff --git a/drivers/net/can/spi/mcp251xfd/mcp251xfd.h b/drivers/net/can/spi/mcp251xfd/mcp251xfd.h
index cb6398c2a560..d69b3d4de65b 100644
--- a/drivers/net/can/spi/mcp251xfd/mcp251xfd.h
+++ b/drivers/net/can/spi/mcp251xfd/mcp251xfd.h
@@ -398,7 +398,7 @@
 #define MCP251XFD_OSC_STAB_SLEEP_US (3 * USEC_PER_MSEC)
 #define MCP251XFD_OSC_STAB_TIMEOUT_US (10 * MCP251XFD_OSC_STAB_SLEEP_US)
 #define MCP251XFD_POLL_SLEEP_US (10)
-#define MCP251XFD_POLL_TIMEOUT_US (USEC_PER_MSEC)
+#define MCP251XFD_POLL_TIMEOUT_US 500000
 #define MCP251XFD_SOFTRESET_RETRIES_MAX 3
 #define MCP251XFD_READ_CRC_RETRIES_MAX 3
 #define MCP251XFD_ECC_CNT_MAX 2

The outcome was:

root@raspberrypi2:~# ip link set can1 type can bitrate 250000
root@raspberrypi2:~# ifconfig can1 up
ifconfig: SIOCSIFFLAGS: No such device
root@raspberrypi2:~# 

and dmesg gives the same as before:

[  499.937284] mcp251xfd spi1.0 can1: Failed to detect MCP2518FD (osc=0x00000000).
[  499.944809] mcp251xfd spi1.0 can1: CRC read error at address 0x0e0c (length=4, data=00 00 00 00, CRC=0x0000) retrying.
[  499.955615] mcp251xfd spi1.0 can1: CRC read error at address 0x0e0c (length=4, data=00 00 00 00, CRC=0x0000) retrying.
[  499.966422] mcp251xfd spi1.0 can1: CRC read error at address 0x0e0c (length=4, data=00 00 00 00, CRC=0x0000) retrying.
[  499.977162] mcp251xfd spi1.0 can1: CRC read error at address 0x0e0c (length=4, data=00 00 00 00, CRC=0x0000).
[  499.987184] mcp251xfd spi1.0 can1: CRC read error at address 0x0000 (length=4, data=00 00 00 00, CRC=0x0000) retrying.
[  499.997978] mcp251xfd spi1.0 can1: CRC read error at address 0x0000 (length=4, data=00 00 00 00, CRC=0x0000) retrying.
[  500.008795] mcp251xfd spi1.0 can1: CRC read error at address 0x0000 (length=4, data=00 00 00 00, CRC=0x0000) retrying.
[  500.019522] mcp251xfd spi1.0 can1: CRC read error at address 0x0000 (length=4, data=00 00 00 00, CRC=0x0000).
[  500.029626] mcp251xfd spi1.0 can1: CRC read error at address 0x0e0c (length=4, data=00 00 00 00, CRC=0x0000) retrying.
[  500.040425] mcp251xfd spi1.0 can1: CRC read error at address 0x0e0c (length=4, data=00 00 00 00, CRC=0x0000) retrying.
[  500.051223] mcp251xfd spi1.0 can1: CRC read error at address 0x0e0c (length=4, data=00 00 00 00, CRC=0x0000) retrying.
[  500.061968] mcp251xfd spi1.0 can1: CRC read error at address 0x0e0c (length=4, data=00 00 00 00, CRC=0x0000).
[  500.071991] mcp251xfd spi1.0 can1: CRC read error at address 0x0000 (length=4, data=00 00 00 00, CRC=0x0000) retrying.
[  500.082828] mcp251xfd spi1.0 can1: CRC read error at address 0x0000 (length=4, data=00 00 00 00, CRC=0x0000) retrying.
[  500.093626] mcp251xfd spi1.0 can1: CRC read error at address 0x0000 (length=4, data=00 00 00 00, CRC=0x0000) retrying.
[  500.104351] mcp251xfd spi1.0 can1: CRC read error at address 0x0000 (length=4, data=00 00 00 00, CRC=0x0000).

Is there any debugging within the mcp251xfd driver that can be enabled to give more detail.

@pelwell
Copy link
Contributor

pelwell commented Feb 23, 2022

You can add #define DEBUG at the top of mcp241xfd-core.c and rebuild the module. That will enable the limited debugging.

@pelwell
Copy link
Contributor

pelwell commented Feb 23, 2022

The next step would be to enable the kernel event tracing for the duration of the ifup, something like (running as root):

# echo 1 > /sys/kernel/debug/tracing/events/spi/enable
# ifup
# echo 0 > /sys/kernel/debug/tracing/events/spi/enable
# cp /sys/kernel/debug/tracing/trace trace.txt

@nmbath
Copy link
Author

nmbath commented Feb 23, 2022

Sorry for the delay, been a hectic day!

I uploaded trace as requested

trace.txt

Also attach a trace from can0...

good.txt

@nmbath
Copy link
Author

nmbath commented Feb 23, 2022

I have installed raspy-gpio on the device. I am not sure if this is a red hearing or not, but according to the tool it dosnt look like the SPI is properly configured in terms of PINs.

root@raspberrypi2:~# ./raspi-gpio get
BANK0 (GPIO 0 to 27):
GPIO 0: level=1 func=INPUT
GPIO 1: level=1 func=INPUT
GPIO 2: level=1 func=INPUT
GPIO 3: level=1 func=INPUT
GPIO 4: level=0 alt=0 func=GPCLK0
GPIO 5: level=0 func=OUTPUT
GPIO 6: level=1 func=INPUT
GPIO 7: level=1 func=OUTPUT
GPIO 8: level=1 func=OUTPUT
GPIO 9: level=0 alt=0 func=SPI0_MISO
GPIO 10: level=0 alt=0 func=SPI0_MOSI
GPIO 11: level=0 alt=0 func=SPI0_SCLK
GPIO 12: level=0 func=INPUT
GPIO 13: level=0 func=INPUT
GPIO 14: level=1 alt=0 func=TXD0
GPIO 15: level=1 alt=0 func=RXD0
GPIO 16: level=1 func=INPUT
GPIO 17: level=0 func=INPUT
GPIO 18: level=0 alt=0 func=PCM_CLK
GPIO 19: level=0 func=INPUT
GPIO 20: level=0 alt=4 func=SPI1_MOSI
GPIO 21: level=0 func=OUTPUT
GPIO 22: level=0 func=INPUT
GPIO 23: level=0 func=INPUT
GPIO 24: level=0 func=INPUT
GPIO 25: level=1 func=INPUT
GPIO 26: level=0 func=INPUT
GPIO 27: level=0 func=INPUT

There is no SPI1_MISO on pin 19 and SPIO_SCLK on pin 21

@nmbath
Copy link
Author

nmbath commented Feb 23, 2022

@pelwell,

You suggested

You can add #define DEBUG at the top of mcp241xfd-core.c and rebuild the module. That will enable the limited debugging.

I add this to my build:

diff --git a/drivers/net/can/spi/mcp251xfd/mcp251xfd-core.c b/drivers/net/can/spi/mcp251xfd/mcp251xfd-core.c
index 5f2694f5d9c0..82b9bd354134 100644
--- a/drivers/net/can/spi/mcp251xfd/mcp251xfd-core.c
+++ b/drivers/net/can/spi/mcp251xfd/mcp251xfd-core.c
@@ -11,6 +11,7 @@
 //
 // Copyright (c) 2019 Martin Sperl <kernel@martin.sperl.org>
 //
+#define DEBUG
 
 #include <linux/bitfield.h>
 #include <linux/clk.h>

Having done this no extra messages are displayed. Do a grep for DEBUG in the mcp151xfd folder, there are no other occurrences of DEBUG.

@marckleinebudde
Copy link
Contributor

Hey @nmbath,

See predicable network interface names for the classical udev or the more modern systemd-networkd based approach.

Can you test if this combined overlay works for the waveshare Rev2.1 board?

0001-overlays-add-support-for-waveshare-can-fd-hat-rev2.1.patch.TXT

I do have other issues with high bit error rates in either TX or RX. Still trying to debug that one.

Can you describe the problem?

@dav2dg
Copy link

dav2dg commented Jul 2, 2022

@marckleinebudde
yes I am aware each board needs a different config.
These are the 20 boards I have
image
There is the only one with a problem. Even if I change the Can HAT. So tomorrow I will change the base board.
All examples are for a 2.1 board

Please see my comments above, I did do as you suggest...

I think that config snippet for the old board in mode "a" in the wiki will not work, the board uses a different pin for chip select as the overlay spi1-3cs specifies. Please use dtoverlay=waveshare-can-fd-hat-mode-a.

BTW, 9 of 11 boards work just fine with waveshare config.
I understand from this thread that there are fixes that I should upgrade to the mode-a which I have done

@nmbath I have 50 V2.1 boards, of the 11 I have tried, 9 work. Maybe it is the base board, I use a rpi CM4 with a base board from Waveshare.

@marckleinebudde
Copy link
Contributor

Some working boards and some not working boards of the same type on the same board suggests a hardware problem.

@DavidBoJ
Copy link

DavidBoJ commented Jul 4, 2022

2-CH CAN FD HAT Rev2.1

ip -d link show dev 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 minmtu 0 maxmtu 0
can state ERROR-ACTIVE (berr-counter tx 0 rx 0) restart-ms 0
bitrate 250000 sample-point 0.875
tq 25 prop-seg 69 phase-seg1 70 phase-seg2 20 sjw 1
mcp251xfd: tseg1 2..256 tseg2 1..128 sjw 1..128 brp 1..256 brp-inc 1
mcp251xfd: dtseg1 1..32 dtseg2 1..16 dsjw 1..16 dbrp 1..256 dbrp-inc 1
clock 40000000 numtxqueues 1 numrxqueues 1 gso_max_size 65536 gso_max_segs 65535

uname -a
Linux cilix-19 5.15.32-v7l+ #1538 SMP Thu Mar 31 19:39:41 BST 2022 armv7l GNU/Linux
On a Raspberry Pi4

In my application the /var/log/syslog is filled up with:
mcp251xfd spi0.0 can0: Transmit Event FIFO buffer not empty
After a while the disk is full and the system can crash. Is there anyway I can disable the logging from the CAN bus?

I have two slaves on my network to which it is difficult to establish a connection. With two others slaves it seems to work (But I didn't check the logs)
I have controlled the two slaves with Pican2 in the past but not with Bullseye
The physical network is 1.2m
Any suggestions?

@marckleinebudde
Copy link
Contributor

marckleinebudde commented Jul 4, 2022

Hey @DavidBoJ, can you create a new issue please. Please mention me, so I can answer you questions.

Thanks, Marc

@dav2dg
Copy link

dav2dg commented Jul 5, 2022

@marckleinebudde, I took your point and agree it really did look like a hardware problem and may well be for the specific problem I had.

I have since taken mutiple new Waveshare 2-CH CAN FD HAT Rev2.1, CM4102032, Waveshare base board.
After testing multiple I was not able to get the mainline overlay to work...

Success both can0 & can1
## Setup for Waveshare Dual CAN FD v2.1
# dtoverlay=spi1-3cs
# dtoverlay=mcp251xfd,spi0-0,interrupt=25
# dtoverlay=mcp251xfd,spi1-0,interrupt=24
pi@e45f014e8730:~ $ dmesg | grep -E 'can|spi|mcp2'
[    6.602899] spi_master spi0: will run message pump with realtime priority
[    6.626836] mcp251xfd spi0.0 can0: MCP2518FD rev0.0 (-RX_INT -MAB_NO_WARN +CRC_REG +CRC_RX +CRC_TX +ECC -HD c:40.00MHz m:20.00MHz r:17.00MHz e:16.66MHz) successfully initialized.
[    6.630779] spi_master spi1: will run message pump with realtime priority
[    6.639008] mcp251xfd spi1.0 can1: MCP2518FD rev0.0 (-RX_INT -MAB_NO_WARN +CRC_REG +CRC_RX +CRC_TX +ECC -HD c:40.00MHz m:20.00MHz r:17.00MHz e:16.66MHz) successfully initialized.
[    8.245417] IPv6: ADDRCONF(NETDEV_CHANGE): can0: link becomes ready
[    9.247876] IPv6: ADDRCONF(NETDEV_CHANGE): can1: link becomes ready
[   14.570723] can: controller area network core
[   14.577323] can: raw protocol
 
 
Fail - only can0
##
## NEW NEW NEW NEW NEW NEW NEW NEW 
## Mainline Mainline
##  
## dtoverlay=waveshare-can-fd-hat-mode-a
pi@e45f014e8730:~ $ dmesg | grep -E 'can|spi|mcp2'
[    6.324791] spi_master spi0: will run message pump with realtime priority
[    6.352909] mcp251xfd spi0.0 can0: MCP2518FD rev0.0 (-RX_INT -MAB_NO_WARN +CRC_REG +CRC_RX +CRC_TX +ECC -HD c:40.00MHz m:20.00MHz r:17.00MHz e:16.66MHz) successfully initialized.
[    6.422089] spi_master spi1: will run message pump with realtime priority
[    6.462702] mcp251xfd spi1.0 (unnamed net_device) (uninitialized): Failed to detect MCP251xFD (osc=0x00000000).
[    7.780180] IPv6: ADDRCONF(NETDEV_CHANGE): can0: link becomes ready
[   14.644207] can: controller area network core
[   14.651967] can: raw protocol

Any suggestions as to what I should try next. I am going to check same results on all devices.

@marckleinebudde
Copy link
Contributor

The dtoverlay=waveshare-can-fd-hat-mode-a works for the old version only.
Please try the overlay from the patch attached to #4902 (comment)

@nmbath
Copy link
Author

nmbath commented Jul 5, 2022

Also check that you do not have anything else opening the GPIO pins that the old version uses. It dose not use standard GPIO pins. I had issues with my old revision board and can1 due to something else wanting to use the GPIO pins that can1 required.

@dav2dg
Copy link

dav2dg commented Jul 5, 2022

OK will try your suggestions.
I have gone back and checked a variety of combinations.
The 2 CAN cards I was testing did have a fault.
I will check the GPIO stuff but points to a problem above. Ie with new everything and interchanged combinations consistent mode-a mainline fails..... may be GPIO.
image
Will also try the patched overlay

@dav2dg
Copy link

dav2dg commented Jul 5, 2022

Sorry ... how do I get the patch attached to #4902 (comment)
Newbie here

@marckleinebudde
Copy link
Contributor

Click on the link that says "0001-overlays-add-support-for-waveshare-can-fd-hat-rev2.1.patch.TXT"

@dav2dg
Copy link

dav2dg commented Jul 5, 2022

Sorry ... how/where do apply this???
Total newbie for applying patches ... have always avoided 'cause I don't know what to do!!!!
With some pointers I am sure I can figure it out.

@marckleinebudde
Copy link
Contributor

marckleinebudde commented Jul 5, 2022

Do you build your kernel on your own from git? If not, I'll send you the complied overlay.

Update: here's the compiled overlay:
waveshare-can-fd-hat-rev2.1-mode-a-overlay.tar.gz

@dav2dg
Copy link

dav2dg commented Jul 5, 2022

Thankyou. While I could build the kernel, I am OK to take overlays but new kernel is a bit too far.
I have done something wrong. The overlay does not seem to load
No can0, No can1

pi@e45f013eb397:~ $ tail -7 /boot/config.txt

[all]
# dtoverlay=spi1-3cs
# dtoverlay=mcp251xfd,spi0-0,interrupt=25
# dtoverlay=mcp251xfd,spi1-0,interrupt=24
# dtoverlay=waveshare-can-fd-hat-mode-a
dtoverlay=waveshare-can-fd-hat-rev2.1-mode-a-overlay-marc
pi@e45f013eb397:~ $ dmesg | grep -E 'spi|can|mcp2'
[   22.477309] can: controller area network core
[   22.522483] can: raw protocol
pi@e45f013eb397:~ $ ls -l /boot/overlays/wav*
-rwxr-xr-x 1 root root 3387 Mar 31 19:40 /boot/overlays/waveshare-can-fd-hat-mode-a.dtbo
-rwxr-xr-x 1 root root 2506 Mar 31 19:40 /boot/overlays/waveshare-can-fd-hat-mode-b.dtbo
-rwxr-xr-x 1 root root 2934 Jul  5 13:45 /boot/overlays/waveshare-can-fd-hat-rev2.1-mode-a-overlay-marc.dtbo

@marckleinebudde
Copy link
Contributor

marckleinebudde commented Jul 5, 2022

I think I've messed up the filename...I'll test here first

@pelwell
Copy link
Contributor

pelwell commented Jul 5, 2022

Is there anything in /proc/device-tree/chosen/user-warnings (dtoverlay errors will appear there)?

@dav2dg
Copy link

dav2dg commented Jul 5, 2022

Note I have added the "-marc" suffix

Error found...

pi@e45f013eb397:/proc/device-tree/chosen $ cat user-warnings
Failed to load overlay 'waveshare-can-fd-hat-rev2.1-mode-a-overlay-marc'

@pelwell
Copy link
Contributor

pelwell commented Jul 5, 2022

That's a really long filename, and until very recently there was a severe file path length limitation in the firmware overlay code. Try giving it a shorter name...

@dav2dg
Copy link

dav2dg commented Jul 5, 2022

Name length was the problem. This works:
dtoverlay=ws-short-name
Do you have a preferred name.

BTW Thanks both Can0 and Can1 work. I will test the faulty boards tomorrow. too late now!

@marckleinebudde
Copy link
Contributor

Do you have a preferred name.

Does waveshare-can-fd-hat-rev2.1-mode-a work?

@dav2dg
Copy link

dav2dg commented Jul 5, 2022

Hmmm ... new overlay allows the 2 "faulty" boards to work!!!
Name is too long, the other drivers are 7 chars shorter

pi@e45f013eb397:/boot/overlays $ ls -1 wav*
waveshare-can-fd-hat-mode-a.dtbo
waveshare-can-fd-hat-mode-b.dtbo
waveshare-can-fd-hat-rev2.1-mode-a.dtbo

@marckleinebudde
Copy link
Contributor

Can you figure out what length still works?

@dav2dg
Copy link

dav2dg commented Jul 7, 2022

Sorry I had a message prepared seems I did not press "Send"
I Originally tried waveshare-canfdhat-v2.1-a.dtbo but seemed to run into a problem with the dot in 2.1 so I changed to
waveshare-canfdhat-v2-1-a.dtbo
Here are my test stats ... THANKYOU it seems to work now on good hardware.

image

@marckleinebudde
Copy link
Contributor

Ok. I think I'll change the filename to waveshare-canfdhat-v21-a.dtbo then.

Do you get a Failed to detect MCP251xFD (osc=0x00000000). for all "N" in you table? So can1 of your CAN board number 2. is broken?

@dav2dg
Copy link

dav2dg commented Jul 18, 2022

@marckleinebudde sorry for delay I have some production deadlines.
I have not checked for Failed to detect MCP251xFD (osc=0x00000000) but my recolection is that this message was generated.
Here is a log from when I was actively testing...

Fail - only can0
##
## NEW NEW NEW NEW NEW NEW NEW NEW 
## Mainline Mainline
##  
## dtoverlay=waveshare-can-fd-hat-mode-a
pi@e45f014e8730:~ $ dmesg | grep -Ei 'can|spi|mcp2'
[    6.324791] spi_master spi0: will run message pump with realtime priority
[    6.352909] mcp251xfd spi0.0 can0: MCP2518FD rev0.0 (-RX_INT -MAB_NO_WARN +CRC_REG +CRC_RX +CRC_TX +ECC -HD c:40.00MHz m:20.00MHz r:17.00MHz e:16.66MHz) successfully initialized.
[    6.422089] spi_master spi1: will run message pump with realtime priority
[    6.462702] mcp251xfd spi1.0 (unnamed net_device) (uninitialized): Failed to detect MCP251xFD (osc=0x00000000).
[    7.780180] IPv6: ADDRCONF(NETDEV_CHANGE): can0: link becomes ready
[   14.644207] can: controller area network core
[   14.651967] can: raw protocol

I just did a test on the previous Waveshare version prior to 2.1 (maybe 2.0) using latest overlay

The result is can0 OK and can1 not present on ifconfig

pi@e45f013eb1f3:~ $ tail -4 /boot/config.txt

[all]
dtoverlay=waveshare-canfdhat-v21-a

pi@e45f013eb1f3:~ $ dmesg | grep -E 'can|spi|mcp2'
[    9.033312] spi_master spi0: will run message pump with realtime priority
[    9.162066] mcp251xfd spi0.0 can0: MCP2518FD rev0.0 (-RX_INT -MAB_NO_WARN +CRC_REG +CRC_RX +CRC_TX +ECC -HD c:40.00MHz m:20.00MHz r:17.00MHz e:16.66MHz) successfully initialized.
[    9.163206] spi_master spi1: will run message pump with realtime priority
[    9.199761] mcp251xfd spi1.0 (unnamed net_device) (uninitialized): **Failed to detect MCP251xFD (osc=0x00000000).**
[   10.520075] IPv6: ADDRCONF(NETDEV_CHANGE): can0: link becomes ready
[   29.024141] can: controller area network core
[   29.045710] can: raw protocol
pi@e45f013eb1f3:~ $

@marckleinebudde
Copy link
Contributor

The old wareshare hat without a revision number on the back only works with the waveshare-can-fd-hat-mode-a overlay. The new waveshare hat rev2.1 should work with the overlay I send you waveshare-canfdhat-v21-a.

It makes no sense to test the old card with the new overlay or vice versa.

@dav2dg
Copy link

dav2dg commented Jul 18, 2022

OK Thanks, I thought the mainline might be better for the pre 2.1 version.
What is required to get the pre 2.1 onto the mainline overlay?
Thx

@marckleinebudde
Copy link
Contributor

I just bought a rev2.1 board, it should arrive this week. In the meantime you can test if your your rev2.1 board works with my rev2.1 overlay. Both CAN interfaces should be detected.

@dav2dg
Copy link

dav2dg commented Jul 18, 2022

I have tested the compiled overlay you sent me https://github.com/raspberrypi/linux/issues/4902#issuecomment-1175047279

The results are above
https://github.com/raspberrypi/linux/issues/4902#issuecomment-1177712230

Is there another overlay I should test

@nmbath
Copy link
Author

nmbath commented Jul 18, 2022

I have had a rev 2.1 board for several months. I attach the overlay I have been using on that. Only issues is occasionally on boot can0 and can1 get swapped
mcp251xfd-combined.dtbo.zip
.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

5 participants