marckleinebudde / linux

Linux kernel source tree
Other
6 stars 7 forks source link

MCP25xxfd driver test on MCP2518FD #3

Closed Pillar1989 closed 4 years ago

Pillar1989 commented 4 years ago

@marckleinebudde I have tested MCP2517FD and there is no problem. But there is something wrong with MCP2518FD. If you are willing to discuss this, I can provide you with any other information.

pi@raspberrypi:~/linux-mark $ sudo ip link set can0 up type can bitrate 1000000   dbitrate 8000000 restart-ms 1000 berr-reporting on fd on
RTNETLINK answers: Connection timed out
pi@raspberrypi:~/linux-mark $ dmesg  | grep spi
[    4.035135] spi_master spi0: will run message pump with realtime priority
[    4.043169] mcp25xxfd spi0.1 can0: MCP2518FD rev0.0 (-RX_INT -MAB_NO_WARN +CRC_REG +CRC_RX +CRC_TX +ECC -HD m:20.00MHz r:18.50MHz e:17.85MHz) successfully initialized.
[    4.058282] mcp25xxfd spi0.0 can1: MCP2518FD rev0.0 (-RX_INT -MAB_NO_WARN +CRC_REG +CRC_RX +CRC_TX +ECC -HD m:20.00MHz r:18.50MHz e:17.85MHz) successfully initialized.
[  156.725121] mcp25xxfd spi0.1 can0: Controller failed to enter mode Mixed (CAN FD/CAN 2.0) Mode (0) and stays in Configuration Mode (4).
[67749.538453] mcp25xxfd spi0.1 can0: Controller failed to enter mode Mixed (CAN FD/CAN 2.0) Mode (0) and stays in Configuration Mode (4).
marckleinebudde commented 4 years ago

Hello @Pillar1989,

please provide more details.

Can you replace the MCP25XXFD_POLL_TIMEOUT_US in https://github.com/marckleinebudde/linux/blob/d955c30f70d6f65fc4ba476f97633afb6528911e/drivers/net/can/spi/mcp25xxfd/mcp25xxfd-core.c#L488 by 500000, recompile and try again. This increases the original timeout from 1ms to 500ms. Maybe the timeout was a bit to small.

Pillar1989 commented 4 years ago

pi@raspberrypi:~/linux-mark $ sudo ip link set can0 up type can bitrate 1000000 dbitrate 8000000 restart-ms 1000 berr-reporting on fd on RTNETLINK answers: Connection timed out pi@raspberrypi:~/linux-mark $ dmesg | tail [ 342.972734] Voltage normalised (0x00000000) [ 349.212751] rpi_firmware_get_throttled: 3 callbacks suppressed [ 349.212758] Under-voltage detected! (0x00050005) [ 355.452610] Voltage normalised (0x00000000) [ 628.045118] mcp25xxfd spi0.1 can0: Controller failed to enter mode Mixed (CAN FD/CAN 2.0) Mode (0) and stays in Configuration Mode (4). [ 628.045279] A link change request failed with some changes committed already. Interface can0 may have been left with an inconsistent configuration, please check. [ 642.494409] Under-voltage detected! (0x00050005) [ 652.894582] Voltage normalised (0x00000000) [ 658.767935] mcp25xxfd spi0.1 can0: Controller failed to enter mode Mixed (CAN FD/CAN 2.0) Mode (0) and stays in Configuration Mode (4). [ 658.768097] A link change request failed with some changes committed already. Interface can0 may have been left with an inconsistent configuration, please check. pi@raspberrypi:~/linux-mark $ git remote -v origin https://github.com/marckleinebudde/linux (fetch) origin https://github.com/marckleinebudde/linux (push) pi@raspberrypi:~/linux-mark $ git branch -a



- Is the above command sufficient to reproduce the issue?
Yes
- Do you get the issue every time?
Yes
marckleinebudde commented 4 years ago
* Which CAN hardware are you using?
  The Seeed‘s new MCP2518FD PI hat

Oh, I have to get one of these :) Is it available already?

The difference from MCP2517FD is that both MCP2518FD are connected to spi0.

So you're using spi0.0 and spi0.1 on the new board?

pi@raspberrypi:~/linux-mark $ git diff
diff --git a/drivers/net/can/spi/mcp25xxfd/mcp25xxfd-core.c b/drivers/net/can/spi/mcp25xxfd/mcp25xxfd-core.c
index 387980597..e06376ff0 100644
--- a/drivers/net/can/spi/mcp25xxfd/mcp25xxfd-core.c
+++ b/drivers/net/can/spi/mcp25xxfd/mcp25xxfd-core.c
@@ -485,7 +485,7 @@ __mcp25xxfd_chip_set_mode(const struct mcp25xxfd_priv *priv,
                                       FIELD_GET(MCP25XXFD_REG_CON_OPMOD_MASK,
                                                 con) == mode_req,
                                       MCP25XXFD_POLL_SLEEP_US,
-                                      MCP25XXFD_POLL_TIMEOUT_US);
+                                      500000);
        if (err) {
                u8 mode = FIELD_GET(MCP25XXFD_REG_CON_OPMOD_MASK, con);

The change looks alright, but it still doesn't work.

pi@raspberrypi:~/linux-mark $ sudo ip link set can0 up type can bitrate 1000000   dbitrate 8000000 restart-ms 1000 berr-reporting on fd on
RTNETLINK answers: Connection timed out

Can you try normal CAN-2.0? sudo ip link set can0 txqueuelen 10 up type can bitrate 500000 restart-ms 0 berr-reporting on

pi@raspberrypi:~/linux-mark $ dmesg | tail
[  342.972734] Voltage normalised (0x00000000)
[  349.212751] rpi_firmware_get_throttled: 3 callbacks suppressed
[  349.212758] Under-voltage detected! (0x00050005)
[  355.452610] Voltage normalised (0x00000000)
[  628.045118] mcp25xxfd spi0.1 can0: Controller failed to enter mode Mixed (CAN FD/CAN 2.0) Mode (0) and stays in Configuration Mode (4).
[  628.045279] A link change request failed with some changes committed already. Interface can0 may have been left with an inconsistent configuration, please check.
[  642.494409] Under-voltage detected! (0x00050005)
[  652.894582] Voltage normalised (0x00000000)
[  658.767935] mcp25xxfd spi0.1 can0: Controller failed to enter mode Mixed (CAN FD/CAN 2.0) Mode (0) and stays in Configuration Mode (4).
[  658.768097] A link change request failed with some changes committed already. Interface can0 may have been left with an inconsistent configuration, please check.

You should use a better power supply. I think the raspi will clock down the CPU and thus the SPI core, let's rule out that this is doesn't interfere here.

What about the other mcp2518fd connected to spi0.0? Does that properly work?

pi@raspberrypi:~/linux-mark $ git remote -v
origin    https://github.com/marckleinebudde/linux (fetch)
origin    https://github.com/marckleinebudde/linux (push)
pi@raspberrypi:~/linux-mark $ git branch -a
* v4.19-rpi/mcp25xxfd-20200429-36
  remotes/origin/v4.19-rpi/mcp25xxfd-20200429-36
pi@raspberrypi:~/linux-mark $ 

v4.19-rpi/mcp25xxfd-20200429-36 should be recent enough.

Can you post the contents of the files /sys/kernel/debug/regmap/spi0.0-crc/registers and /sys/kernel/debug/regmap/spi0.1-crc/registers directly after boot (and driver loading) and then again after the failed ip link.

* Is the above command sufficient to reproduce the issue?
  Yes

* Do you get the issue every time?
  Yes

That's good.

Pillar1989 commented 4 years ago

Oh, I have to get one of these :) Is it available already?

It hasn't started selling yet, just giving it away to some people who need it. mkl@pengutronix.deDoes this mailbox of yours accept mail? Your code has helped me a lot and I can give one away to you.

So you're using spi0.0 and spi0.1 on the new board?

Yes

Can you try normal CAN-2.0?

Yes, But there are still not work.

pi@raspberrypi:~ $ sudo ip link set can0 up type can bitrate 500000 restart-ms 100 fd off
RTNETLINK answers: Connection timed out
pi@raspberrypi:~ $ dmesg | tail
[17715.424980] mcp25xxfd spi0.1 can0: Controller failed to enter mode CAN 2.0 Mode (6) and stays in Configuration Mode (4).
[17715.425142] A link change request failed with some changes committed already. Interface can0 may have been left with an inconsistent configuration, please check.
pi@raspberrypi:~ $ 

Can you post the contents of the files /sys/kernel/debug/regmap/spi0.0-crc/registers and /sys/kernel/debug/regmap/spi0.1-crc/registers directly after boot (and driver loading) and then again after the failed ip link.

The following is the result after using normal CAN-2.0 mode.

pi@raspberrypi:~ $ sudo cat  /sys/kernel/debug/regmap/spi0.0-crc/registers
000: 01980760
004: 003e0f0f
008: 000e0303
00c: 00021000
010: 00000000
014: 00000000
018: 40400040
01c: 00000000
020: 00000000
024: 00000000
028: 00000000
02c: 00000000
030: 00000000
034: 00200000
038: 00000000
03c: 00000000
040: 00000400
044: 00000000
048: 00000000
04c: 00000000
050: 00600480
054: 00000005
058: 00000008
05c: 00600400
060: 00000000
064: 00000018
068: 00600400
06c: 00000000
070: 00000028
074: 00600400
078: 00000000
07c: 00000038
080: 00600400
084: 00000000
088: 00000048
08c: 00600400
090: 00000000
094: 00000058
098: 00600400
09c: 00000000
0a0: 00000068
0a4: 00600400
0a8: 00000000
0ac: 00000078
0b0: 00600400
0b4: 00000000
0b8: 00000088
0bc: 00600400
0c0: 00000000
0c4: 00000098
0c8: 00600400
0cc: 00000000
0d0: 000000a8
0d4: 00600400
0d8: 00000000
0dc: 000000b8
0e0: 00600400
0e4: 00000000
0e8: 000000c8
0ec: 00600400
0f0: 00000000
0f4: 000000d8
0f8: 00600400
0fc: 00000000
100: 000000e8
104: 00600400
108: 00000000
10c: 000000f8
110: 00600400
114: 00000000
118: 00000108
11c: 00600400
120: 00000000
124: 00000118
128: 00600400
12c: 00000000
130: 00000128
134: 00600400
138: 00000000
13c: 00000138
140: 00600400
144: 00000000
148: 00000148
14c: 00600400
150: 00000000
154: 00000158
158: 00600400
15c: 00000000
160: 00000168
164: 00600400
168: 00000000
16c: 00000178
170: 00600400
174: 00000000
178: 00000188
17c: 00600400
180: 00000000
184: 00000198
188: 00600400
18c: 00000000
190: 000001a8
194: 00600400
198: 00000000
19c: 000001b8
1a0: 00600400
1a4: 00000000
1a8: 000001c8
1ac: 00600400
1b0: 00000000
1b4: 000001d8
1b8: 00600400
1bc: 00000000
1c0: 000001e8
1c4: 00600400
1c8: 00000000
1cc: 000001f8
1d0: 00000000
1d4: 00000000
1d8: 00000000
1dc: 00000000
1e0: 00000000
1e4: 00000000
1e8: 00000000
1ec: 00000000
1f0: 00000000
1f4: 00000000
1f8: 00000000
1fc: 00000000
200: 00000000
204: 00000000
208: 00000000
20c: 00000000
210: 00000000
214: 00000000
218: 00000000
21c: 00000000
220: 00000000
224: 00000000
228: 00000000
22c: 00000000
230: 00000000
234: 00000000
238: 00000000
23c: 00000000
240: 00000000
244: 00000000
248: 00000000
24c: 00000000
250: 00000000
254: 00000000
258: 00000000
25c: 00000000
260: 00000000
264: 00000000
268: 00000000
26c: 00000000
270: 00000000
274: 00000000
278: 00000000
27c: 00000000
280: 00000000
284: 00000000
288: 00000000
28c: 00000000
290: 00000000
294: 00000000
298: 00000000
29c: 00000000
2a0: 00000000
2a4: 00000000
2a8: 00000000
2ac: 00000000
2b0: 00000000
2b4: 00000000
2b8: 00000000
2bc: 00000000
2c0: 00000000
2c4: 00000000
2c8: 00000000
2cc: 00000000
2d0: 00000000
2d4: 00000000
2d8: 00000000
2dc: 00000000
2e0: 00000000
2e4: 00000000
2e8: 00000000
2ec: 00000000
400: b2a2c406
404: bb86a598
408: 7c6b697f
40c: e8fc17f8
410: 55ec6982
414: 1fde6520
418: aa6117ee
41c: 245e555e
420: 32a9568c
424: 13be1e62
428: b3feac61
42c: 812be63f
430: 31552d53
434: bbeb4a67
438: f82d4ec5
43c: 05797d47
440: c5dd2ba7
444: 47c6a06b
448: fe492d4d
44c: cea9309f
450: 1954aa9b
454: 3afbdbfc
458: a9a838ff
45c: 7be0038f
460: 70cf06b6
464: f504967e
468: 0d4a251a
46c: ae1a9e9d
470: 74bcb142
474: b6b41365
478: 0dd2c12b
47c: 5c6484c5
480: d492f8d4
484: f215ba1b
488: 65646400
48c: a7dce633
490: 009b9878
494: 2789d798
498: 2fb0ddc5
49c: 25586144
4a0: d3ffda37
4a4: 36ceb8a0
4a8: 0a73e110
4ac: 390b0b77
4b0: 14c7de50
4b4: a8a71304
4b8: 5a6997d1
4bc: 10e711d1
4c0: 31374df5
4c4: 19d68141
4c8: 507a2115
4cc: b1ffb3f5
4d0: 1507cccb
4d4: da50fbe0
4d8: e2eb76e7
4dc: 3b7f7b32
4e0: 8a69f636
4e4: 1f1e23f2
4e8: 4868a8ab
4ec: fed854c4
4f0: 091182d9
4f4: 8b29c64d
4f8: cf0dd6e7
4fc: c3745673
500: fcb85ffb
504: 3faec92b
508: f866fba2
50c: f969e3e6
510: 5574a8da
514: 9ffb36fa
518: 8b48de31
51c: f91a8d59
520: b8a76574
524: 59136268
528: 78d6af33
52c: d3d3ffb3
530: 4d20795c
534: 2d696629
538: 02eb0aa2
53c: 575222f2
540: b9af3030
544: 751c9db2
548: 5a046c20
54c: f65e17e5
550: 57c43d1a
554: 0fedce70
558: c28f8eaf
55c: 18c386cb
560: 2b2a6ae7
564: 0916e9b5
568: 1018288b
56c: 566314f1
570: c416bb20
574: b2ccffb0
578: a3a712e8
57c: 9195a118
580: a8667061
584: 6151a547
588: 1473865a
58c: 00738cb6
590: e508bdd5
594: b2a0f224
598: 87abef80
59c: 100e9090
5a0: 2adaf3b2
5a4: 76f98100
5a8: 9577aa58
5ac: c4a9da36
5b0: 71cfb980
5b4: 2b6837f2
5b8: ae63ecf0
5bc: 8107bd71
5c0: ca39792a
5c4: 485f2bfe
5c8: 85452a79
5cc: 131711ec
5d0: 4059b878
5d4: b10c762d
5d8: 82bb1473
5dc: 37028560
5e0: 5cb99641
5e4: 585c8213
5e8: 9d5d8c0b
5ec: 00591ff7
5f0: 583883f1
5f4: bb8c9054
5f8: ae0d1f61
5fc: 3514080c
600: b8f7f86f
604: 55b7f163
608: 5d58010b
60c: 4621c71b
610: 1470a5f3
614: f468d4d5
618: 8bbf627c
61c: 56faf618
620: 0d4bdeb6
624: 0941d945
628: 85bcbd6b
62c: 0bb99b91
630: 47812f65
634: 7af57bfc
638: 0aaf1aa9
63c: 7c431eea
640: 0e8f4625
644: e6820e67
648: 474d2a11
64c: 36a34925
650: 51d51837
654: 9cc55ef7
658: f8ef5606
65c: dcd577cb
660: 2e9efe09
664: 514a0243
668: 010e84b8
66c: f3ec5a06
670: ff17a068
674: 7c2bbdd2
678: e4f75950
67c: f9fe915a
680: a9186786
684: 0d9b75df
688: d0765179
68c: aaa2dd41
690: f1404198
694: 74bae5b5
698: b26ab057
69c: 31796992
6a0: 819a0fad
6a4: 9d1c9919
6a8: 9c76094d
6ac: 2a381af4
6b0: 69c6f2cc
6b4: 67bf773b
6b8: ab62d7e3
6bc: 6073fa0b
6c0: 3e2da749
6c4: 616f92d9
6c8: 13d22169
6cc: 4fb1d649
6d0: b25c211b
6d4: 861df024
6d8: b9c19ea5
6dc: 12c66951
6e0: 23486f4b
6e4: 347da9cb
6e8: 76d4c1ee
6ec: fc3b47e5
6f0: ec4e1d51
6f4: 357f24dc
6f8: feb35f80
6fc: b966acea
700: 9d7f4cb5
704: 9f7f387f
708: 55743133
70c: 05a4dab2
710: b7d61d6d
714: 7199ccac
718: e689564c
71c: 65d2aa6d
720: c8fd2041
724: c211a080
728: beb4b28b
72c: deb57188
730: a112756a
734: aa115670
738: 13d8572d
73c: c43bca61
740: afc5d1bf
744: 4e7eca2f
748: 44d32217
74c: ed8ab091
750: d046d9d4
754: fae24dd5
758: 8a08b685
75c: c91cee95
760: 3325c6a9
764: 08d34bd6
768: c111d124
76c: c8d5fb16
770: 54d6a157
774: a3b2fcf1
778: aeeb70b2
77c: c03ae133
780: 66f9d1e7
784: 34f8854b
788: b4548829
78c: f4a819a1
790: 04d50918
794: 12a0dd92
798: a034f1e3
79c: 01081d08
7a0: bbbfffb6
7a4: 3e4f2e4b
7a8: f99af967
7ac: b53a4607
7b0: 79478802
7b4: facb0717
7b8: a9f8d480
7bc: 6d12f783
7c0: 203b56c1
7c4: 015c6965
7c8: 529608e3
7cc: f27d36c5
7d0: 89cee996
7d4: 21d71a16
7d8: 1ddb56d5
7dc: 61ce976a
7e0: faa45730
7e4: 359f2dc6
7e8: 595be95f
7ec: ebfed50c
7f0: 74170497
7f4: be6444d6
7f8: beaad4a7
7fc: fba4d855
800: b68d7e24
804: 93aae769
808: 5318b532
80c: bb0e57c5
810: 135ef461
814: c7b8b505
818: 570d7132
81c: 5734255d
820: f463021a
824: 5542dade
828: 9a44e39c
82c: 64a9f75e
830: 50128d4f
834: e0688be5
838: 4a791574
83c: ca1ca952
840: 0ca9f294
844: 15588869
848: 516c3b18
84c: 20e4dceb
850: 627241bb
854: cf42a8d0
858: 81b303f0
85c: 630d815b
860: bfeb51f1
864: 9b12a5f6
868: 35f4ea98
86c: cb60960c
870: b4e60950
874: a8ee1a3d
878: dd3a7a81
87c: ad84e01c
880: b85d94ce
884: 18dc31dd
888: dd50e941
88c: c9f1c1f4
890: 575658a2
894: b3ab6ff6
898: 20a8933d
89c: 6f21ab27
8a0: 2fb112f7
8a4: 83f02766
8a8: 7cfe0015
8ac: b7cf8ef4
8b0: d244628a
8b4: e1b576c8
8b8: fa227a68
8bc: 114667f5
8c0: 21bd74e1
8c4: 6b8e4a75
8c8: f2843a51
8cc: 6b2c1630
8d0: 1616712d
8d4: 9bbbf636
8d8: a6cb0e26
8dc: c553a0d7
8e0: 8b5260e4
8e4: 0958a800
8e8: 400bce0d
8ec: bdab7465
8f0: 70f4a837
8f4: 64755255
8f8: 2932def4
8fc: b8539839
900: 70fb0285
904: 70deaa07
908: 98b6cd27
90c: f0be4d37
910: 2c8f2111
914: b8c336aa
918: b3b3a220
91c: 198fabf9
920: 4ae5ca0c
924: 446a0828
928: 4d726b2e
92c: 6873a236
930: 161eaf45
934: ebe0174f
938: ace77e76
93c: 7b92871f
940: bb65f43e
944: 55e1dfe4
948: b5d0611b
94c: a588ed2f
950: 141f885f
954: 80b7d60a
958: a92f5422
95c: 91387fd2
960: 7b907bf5
964: 6253a85f
968: 49f3221b
96c: 6af53691
970: 327fa432
974: 9b3d1c20
978: 43bb53b4
97c: c63d72b9
980: b6fbd38a
984: 155e816c
988: 712f0081
98c: 82fbbf98
990: cc406a33
994: 1a582e02
998: 8ef85606
99c: 0754015b
9a0: b07a11f4
9a4: 05302047
9a8: cd17365a
9ac: 7d986018
9b0: 6a17755f
9b4: 6e6b4b96
9b8: ba0dc9ea
9bc: 7124e9dc
9c0: ef3ffce5
9c4: ec79f84b
9c8: d2ab99d3
9cc: dafa7e93
9d0: e574ad09
9d4: e0e55e56
9d8: 8a92f77e
9dc: 4ce4bd1e
9e0: 6cb8ea71
9e4: 5d4b4cab
9e8: c52e2d39
9ec: 77ab5e67
9f0: 1d015875
9f4: 200d19ec
9f8: 16ac3f96
9fc: 5564915b
a00: d984b86c
a04: 068620d9
a08: edd2445d
a0c: 8b8cd765
a10: 04c0fa1c
a14: bea136b4
a18: a33059e7
a1c: d4704960
a20: 7ead112d
a24: b2529dc0
a28: 7f501a97
a2c: 888109a3
a30: 17f5acdd
a34: 2ad32cb6
a38: aaf69f07
a3c: ba5f3f77
a40: 3291d5f5
a44: 0594002c
a48: f5ee7109
a4c: ff8d2893
a50: 0114ef59
a54: 03aedaec
a58: 3aef3795
a5c: 5ea64d7c
a60: 1b611ec6
a64: 7042015b
a68: 050714d3
a6c: dace7d1f
a70: 655c2310
a74: beeb4c22
a78: 0b531aa6
a7c: 3df76201
a80: 3ee06f30
a84: 1d502b53
a88: 9c524eba
a8c: ab9d4e56
a90: 58562d50
a94: 14add053
a98: ecae7c81
a9c: 12bca859
aa0: 2d29dce3
aa4: 55ecbb1f
aa8: 55d63837
aac: 7cfddd9f
ab0: b7fba8fa
ab4: b6f75ee8
ab8: a3e974d8
abc: edbad459
ac0: aa0453aa
ac4: 69660885
ac8: 1d9626f3
acc: e31c7eac
ad0: 1d5530d1
ad4: 8edd72b7
ad8: 2e9bb20c
adc: 425633db
ae0: 2bac5a37
ae4: 5d98e159
ae8: 1d58255e
aec: 2168fc0c
af0: 155ee31b
af4: 25d3ce38
af8: 88afb446
afc: ad960b66
b00: aeeb87a1
b04: 75781278
b08: 933e8170
b0c: e7e673d0
b10: 3caab850
b14: 22e93e71
b18: a6bb6dbc
b1c: 77d6e6b8
b20: fed797b6
b24: 43f0c515
b28: 5eeed9b7
b2c: 5fcb5c67
b30: 17832979
b34: af2c50eb
b38: 2a6504fd
b3c: e7446cc9
b40: faaf5f3e
b44: dc644152
b48: c425ab80
b4c: d4a18654
b50: 5c527819
b54: 687b608f
b58: 40fab52e
b5c: 1479a945
b60: bae5bc48
b64: fcc42ca3
b68: 9564e527
b6c: 1fd5fdae
b70: 65d38c12
b74: b4617b91
b78: faed6e30
b7c: 1657af18
b80: 9ae26496
b84: d54470bb
b88: e6438442
b8c: e749f6e4
b90: 11f2c276
b94: 84ae72a6
b98: fb8d757b
b9c: f444404f
ba0: ae09b684
ba4: c610de3a
ba8: c1b8294b
bac: e98b7ff8
bb0: 5342bffe
bb4: 2f61d670
bb8: 28addf20
bbc: e067dc0f
bc0: 3edb7809
bc4: 11966889
bc8: dcf50d89
bcc: baac55d1
bd0: 7596a051
bd4: 6ba93abe
bd8: 9ea44cfb
bdc: e6e42cff
be0: 3723dbd6
be4: 5781ed72
be8: 4e537949
bec: fda1bb5f
bf0: d5d76972
bf4: 44814de6
bf8: baf10af4
bfc: 7df26966
e00: 00000468
e04: 03030003
e08: 00002391
e0c: 00000000
e10: 00000000
e14: 00000000
pi@raspberrypi:~ $ sudo cat  /sys/kernel/debug/regmap/spi0.1-crc/registers
000: 018b0760
004: 00440900
008: 000e0303
00c: 00021000
010: b397c105
014: 00010000
018: 40400040
01c: 00000004
020: 00000000
024: 00000000
028: 00000000
02c: 00000000
030: 00000000
034: 00200000
038: 00000000
03c: 00000000
040: 07000429
044: 00000000
048: 00000000
04c: 00000000
050: 00600480
054: 00000005
058: 00000060
05c: 07600490
060: 00000007
064: 00000060
068: 1f000429
06c: 00000000
070: 000000e0
074: 00600400
078: 00000000
07c: 00000360
080: 00600400
084: 00000000
088: 00000370
08c: 00600400
090: 00000000
094: 00000380
098: 00600400
09c: 00000000
0a0: 00000390
0a4: 00600400
0a8: 00000000
0ac: 000003a0
0b0: 00600400
0b4: 00000000
0b8: 000003b0
0bc: 00600400
0c0: 00000000
0c4: 000003c0
0c8: 00600400
0cc: 00000000
0d0: 000003d0
0d4: 00600400
0d8: 00000000
0dc: 000003e0
0e0: 00600400
0e4: 00000000
0e8: 000003f0
0ec: 00600400
0f0: 00000000
0f4: 00000400
0f8: 00600400
0fc: 00000000
100: 00000410
104: 00600400
108: 00000000
10c: 00000420
110: 00600400
114: 00000000
118: 00000430
11c: 00600400
120: 00000000
124: 00000440
128: 00600400
12c: 00000000
130: 00000450
134: 00600400
138: 00000000
13c: 00000460
140: 00600400
144: 00000000
148: 00000470
14c: 00600400
150: 00000000
154: 00000480
158: 00600400
15c: 00000000
160: 00000490
164: 00600400
168: 00000000
16c: 000004a0
170: 00600400
174: 00000000
178: 000004b0
17c: 00600400
180: 00000000
184: 000004c0
188: 00600400
18c: 00000000
190: 000004d0
194: 00600400
198: 00000000
19c: 000004e0
1a0: 00600400
1a4: 00000000
1a8: 000004f0
1ac: 00600400
1b0: 00000000
1b4: 00000500
1b8: 00600400
1bc: 00000000
1c0: 00000510
1c4: 00600400
1c8: 00000000
1cc: 00000520
1d0: 00000082
1d4: 00000000
1d8: 00000000
1dc: 00000000
1e0: 00000000
1e4: 00000000
1e8: 00000000
1ec: 00000000
1f0: 00000000
1f4: 00000000
1f8: 00000000
1fc: 00000000
200: 00000000
204: 00000000
208: 00000000
20c: 00000000
210: 00000000
214: 00000000
218: 00000000
21c: 00000000
220: 00000000
224: 00000000
228: 00000000
22c: 00000000
230: 00000000
234: 00000000
238: 00000000
23c: 00000000
240: 00000000
244: 00000000
248: 00000000
24c: 00000000
250: 00000000
254: 00000000
258: 00000000
25c: 00000000
260: 00000000
264: 00000000
268: 00000000
26c: 00000000
270: 00000000
274: 00000000
278: 00000000
27c: 00000000
280: 00000000
284: 00000000
288: 00000000
28c: 00000000
290: 00000000
294: 00000000
298: 00000000
29c: 00000000
2a0: 00000000
2a4: 00000000
2a8: 00000000
2ac: 00000000
2b0: 00000000
2b4: 00000000
2b8: 00000000
2bc: 00000000
2c0: 00000000
2c4: 00000000
2c8: 00000000
2cc: 00000000
2d0: 00000000
2d4: 00000000
2d8: 00000000
2dc: 00000000
2e0: 00000000
2e4: 00000000
2e8: 00000000
2ec: 00000000
400: 00000000
404: 00000000
408: 00000000
40c: 00000000
410: 00000000
414: 00000000
418: 00000000
41c: 00000000
420: 00000000
424: 00000000
428: 00000000
42c: 00000000
430: 00000000
434: 00000000
438: 00000000
43c: 00000000
440: 00000000
444: 00000000
448: 00000000
44c: 00000000
450: 00000000
454: 00000000
458: 00000000
45c: 00000000
460: 00000000
464: 00000000
468: 00000000
46c: 00000000
470: 00000000
474: 00000000
478: 00000000
47c: 00000000
480: 00000000
484: 00000000
488: 00000000
48c: 00000000
490: 00000000
494: 00000000
498: 00000000
49c: 00000000
4a0: 00000000
4a4: 00000000
4a8: 00000000
4ac: 00000000
4b0: 00000000
4b4: 00000000
4b8: 00000000
4bc: 00000000
4c0: 00000000
4c4: 00000000
4c8: 00000000
4cc: 00000000
4d0: 00000000
4d4: 00000000
4d8: 00000000
4dc: 00000000
4e0: 00000000
4e4: 00000000
4e8: 00000000
4ec: 00000000
4f0: 00000000
4f4: 00000000
4f8: 00000000
4fc: 00000000
500: 00000000
504: 00000000
508: 00000000
50c: 00000000
510: 00000000
514: 00000000
518: 00000000
51c: 00000000
520: 00000000
524: 00000000
528: 00000000
52c: 00000000
530: 00000000
534: 00000000
538: 00000000
53c: 00000000
540: 00000000
544: 00000000
548: 00000000
54c: 00000000
550: 00000000
554: 00000000
558: 00000000
55c: 00000000
560: 00000000
564: 00000000
568: 00000000
56c: 00000000
570: 00000000
574: 00000000
578: 00000000
57c: 00000000
580: 00000000
584: 00000000
588: 00000000
58c: 00000000
590: 00000000
594: 00000000
598: 00000000
59c: 00000000
5a0: 00000000
5a4: 00000000
5a8: 00000000
5ac: 00000000
5b0: 00000000
5b4: 00000000
5b8: 00000000
5bc: 00000000
5c0: 00000000
5c4: 00000000
5c8: 00000000
5cc: 00000000
5d0: 00000000
5d4: 00000000
5d8: 00000000
5dc: 00000000
5e0: 00000000
5e4: 00000000
5e8: 00000000
5ec: 00000000
5f0: 00000000
5f4: 00000000
5f8: 00000000
5fc: 00000000
600: 00000000
604: 00000000
608: 00000000
60c: 00000000
610: 00000000
614: 00000000
618: 00000000
61c: 00000000
620: 00000000
624: 00000000
628: 00000000
62c: 00000000
630: 00000000
634: 00000000
638: 00000000
63c: 00000000
640: 00000000
644: 00000000
648: 00000000
64c: 00000000
650: 00000000
654: 00000000
658: 00000000
65c: 00000000
660: 00000000
664: 00000000
668: 00000000
66c: 00000000
670: 00000000
674: 00000000
678: 00000000
67c: 00000000
680: 00000000
684: 00000000
688: 00000000
68c: 00000000
690: 00000000
694: 00000000
698: 00000000
69c: 00000000
6a0: 00000000
6a4: 00000000
6a8: 00000000
6ac: 00000000
6b0: 00000000
6b4: 00000000
6b8: 00000000
6bc: 00000000
6c0: 00000000
6c4: 00000000
6c8: 00000000
6cc: 00000000
6d0: 00000000
6d4: 00000000
6d8: 00000000
6dc: 00000000
6e0: 00000000
6e4: 00000000
6e8: 00000000
6ec: 00000000
6f0: 00000000
6f4: 00000000
6f8: 00000000
6fc: 00000000
700: 00000000
704: 00000000
708: 00000000
70c: 00000000
710: 00000000
714: 00000000
718: 00000000
71c: 00000000
720: 00000000
724: 00000000
728: 00000000
72c: 00000000
730: 00000000
734: 00000000
738: 00000000
73c: 00000000
740: 00000000
744: 00000000
748: 00000000
74c: 00000000
750: 00000000
754: 00000000
758: 00000000
75c: 00000000
760: 00000000
764: 00000000
768: 00000000
76c: 00000000
770: 00000000
774: 00000000
778: 00000000
77c: 00000000
780: 00000000
784: 00000000
788: 00000000
78c: 00000000
790: 00000000
794: 00000000
798: 00000000
79c: 00000000
7a0: 00000000
7a4: 00000000
7a8: 00000000
7ac: 00000000
7b0: 00000000
7b4: 00000000
7b8: 00000000
7bc: 00000000
7c0: 00000000
7c4: 00000000
7c8: 00000000
7cc: 00000000
7d0: 00000000
7d4: 00000000
7d8: 00000000
7dc: 00000000
7e0: 00000000
7e4: 00000000
7e8: 00000000
7ec: 00000000
7f0: 00000000
7f4: 00000000
7f8: 00000000
7fc: 00000000
800: 00000000
804: 00000000
808: 00000000
80c: 00000000
810: 00000000
814: 00000000
818: 00000000
81c: 00000000
820: 00000000
824: 00000000
828: 00000000
82c: 00000000
830: 00000000
834: 00000000
838: 00000000
83c: 00000000
840: 00000000
844: 00000000
848: 00000000
84c: 00000000
850: 00000000
854: 00000000
858: 00000000
85c: 00000000
860: 00000000
864: 00000000
868: 00000000
86c: 00000000
870: 00000000
874: 00000000
878: 00000000
87c: 00000000
880: 00000000
884: 00000000
888: 00000000
88c: 00000000
890: 00000000
894: 00000000
898: 00000000
89c: 00000000
8a0: 00000000
8a4: 00000000
8a8: 00000000
8ac: 00000000
8b0: 00000000
8b4: 00000000
8b8: 00000000
8bc: 00000000
8c0: 00000000
8c4: 00000000
8c8: 00000000
8cc: 00000000
8d0: 00000000
8d4: 00000000
8d8: 00000000
8dc: 00000000
8e0: 00000000
8e4: 00000000
8e8: 00000000
8ec: 00000000
8f0: 00000000
8f4: 00000000
8f8: 00000000
8fc: 00000000
900: 00000000
904: 00000000
908: 00000000
90c: 00000000
910: 00000000
914: 00000000
918: 00000000
91c: 00000000
920: 00000000
924: 00000000
928: 00000000
92c: 00000000
930: 00000000
934: 00000000
938: 00000000
93c: 00000000
940: 00000000
944: 00000000
948: 00000000
94c: 00000000
950: 00000000
954: 00000000
958: 00000000
95c: 00000000
960: 00000000
964: 00000000
968: 00000000
96c: 00000000
970: 00000000
974: 00000000
978: 00000000
97c: 00000000
980: 00000000
984: 00000000
988: 00000000
98c: 00000000
990: 00000000
994: 00000000
998: 00000000
99c: 00000000
9a0: 00000000
9a4: 00000000
9a8: 00000000
9ac: 00000000
9b0: 00000000
9b4: 00000000
9b8: 00000000
9bc: 00000000
9c0: 00000000
9c4: 00000000
9c8: 00000000
9cc: 00000000
9d0: 00000000
9d4: 00000000
9d8: 00000000
9dc: 00000000
9e0: 00000000
9e4: 00000000
9e8: 00000000
9ec: 00000000
9f0: 00000000
9f4: 00000000
9f8: 00000000
9fc: 00000000
a00: 00000000
a04: 00000000
a08: 00000000
a0c: 00000000
a10: 00000000
a14: 00000000
a18: 00000000
a1c: 00000000
a20: 00000000
a24: 00000000
a28: 00000000
a2c: 00000000
a30: 00000000
a34: 00000000
a38: 00000000
a3c: 00000000
a40: 00000000
a44: 00000000
a48: 00000000
a4c: 00000000
a50: 00000000
a54: 00000000
a58: 00000000
a5c: 00000000
a60: 00000000
a64: 00000000
a68: 00000000
a6c: 00000000
a70: 00000000
a74: 00000000
a78: 00000000
a7c: 00000000
a80: 00000000
a84: 00000000
a88: 00000000
a8c: 00000000
a90: 00000000
a94: 00000000
a98: 00000000
a9c: 00000000
aa0: 00000000
aa4: 00000000
aa8: 00000000
aac: 00000000
ab0: 00000000
ab4: 00000000
ab8: 00000000
abc: 00000000
ac0: 00000000
ac4: 00000000
ac8: 00000000
acc: 00000000
ad0: 00000000
ad4: 00000000
ad8: 00000000
adc: 00000000
ae0: 00000000
ae4: 00000000
ae8: 00000000
aec: 00000000
af0: 00000000
af4: 00000000
af8: 00000000
afc: 00000000
b00: 00000000
b04: 00000000
b08: 00000000
b0c: 00000000
b10: 00000000
b14: 00000000
b18: 00000000
b1c: 00000000
b20: 00000000
b24: 00000000
b28: 00000000
b2c: 00000000
b30: 00000000
b34: 00000000
b38: 00000000
b3c: 00000000
b40: 00000000
b44: 00000000
b48: 00000000
b4c: 00000000
b50: 00000000
b54: 00000000
b58: 00000000
b5c: 00000000
b60: 00000000
b64: 00000000
b68: 00000000
b6c: 00000000
b70: 00000000
b74: 00000000
b78: 00000000
b7c: 00000000
b80: 00000000
b84: 00000000
b88: 00000000
b8c: 00000000
b90: 00000000
b94: 00000000
b98: 00000000
b9c: 00000000
ba0: 00000000
ba4: 00000000
ba8: 00000000
bac: 00000000
bb0: 00000000
bb4: 00000000
bb8: 00000000
bbc: 00000000
bc0: 00000000
bc4: 00000000
bc8: 00000000
bcc: 00000000
bd0: 00000000
bd4: 00000000
bd8: 00000000
bdc: 00000000
be0: 00000000
be4: 00000000
be8: 00000000
bec: 00000000
bf0: 00000000
bf4: 00000000
bf8: 00000000
bfc: 00000000
e00: 00000468
e04: 03030003
e08: 00003d09
e0c: 00000001
e10: 00000000
e14: 00000000
marckleinebudde commented 4 years ago

Oh, I have to get one of these :) Is it available already?

It hasn't started selling yet, just giving it away to some people who need it. mkl@pengutronix.deDoes this mailbox of yours accept mail? Your code has helped me a lot and I can give one away to you.

Thanks, yes, that's my current e-mail.

So you're using spi0.0 and spi0.1 on the new board?

Yes

What about the other mcp2518fd connected to spi0.0? Does that properly work?

Can you try normal CAN-2.0?

Yes, But there are still not work.

Okay, so this problem is not related to CAN-FD.

pi@raspberrypi:~ $ sudo ip link set can0 up type can bitrate 500000 restart-ms 100 fd off
RTNETLINK answers: Connection timed out
pi@raspberrypi:~ $ dmesg | tail
[17715.424980] mcp25xxfd spi0.1 can0: Controller failed to enter mode CAN 2.0 Mode (6) and stays in Configuration Mode (4).
[17715.425142] A link change request failed with some changes committed already. Interface can0 may have been left with an inconsistent configuration, please check.
pi@raspberrypi:~ $ 

Can you post the contents of the files /sys/kernel/debug/regmap/spi0.0-crc/registers and /sys/kernel/debug/regmap/spi0.1-crc/registers directly after boot (and driver loading) and then again after the failed ip link.

The following is the result after using normal CAN-2.0 mode.

I'll look into the register dumps later.

marckleinebudde commented 4 years ago

The register dump looks okay so far. But the controller has shut down already.

Can you use the https://github.com/marckleinebudde/linux/tree/v5.6-rpi/mcp25xxfd-debug-1 branch or chery-pick the topmost commit, which is https://github.com/marckleinebudde/linux/commit/d98f6ae87b674f2692e4c20e8ed8a58b3cd12e7c and test again. In case of failure please post the complete register dump from the dmesg.

Pillar1989 commented 4 years ago

What's wrong with McP25xxfd_dump?

[    0.000000] Booting Linux on physical CPU 0x0
[    0.000000] Linux version 4.19.118-v7l+ (pi@raspberrypi) (gcc version 8.3.0 (Raspbian 8.3.0-6+rpi1)) #1 SMP Tue May 26 03:05:44 BST 2020
[    0.000000] CPU: ARMv7 Processor [410fd083] revision 3 (ARMv7), cr=30c5383d
[    0.000000] CPU: div instructions available: patching division code
[    0.000000] CPU: PIPT / VIPT nonaliasing data cache, PIPT instruction cache
[    0.000000] OF: fdt: Machine model: Raspberry Pi 4 Model B Rev 1.1
[    0.000000] Memory policy: Data cache writealloc
[    0.000000] cma: Reserved 256 MiB at 0x000000001ec00000
[    0.000000] On node 0 totalpages: 1012736
[    0.000000]   DMA zone: 1728 pages used for memmap
[    0.000000]   DMA zone: 0 pages reserved
[    0.000000]   DMA zone: 196608 pages, LIFO batch:63
[    0.000000]   HighMem zone: 816128 pages, LIFO batch:63
[    0.000000] random: get_random_bytes called from start_kernel+0xc0/0x4e0 with crng_init=0
[    0.000000] percpu: Embedded 16 pages/cpu s36748 r8192 d20596 u65536
[    0.000000] pcpu-alloc: s36748 r8192 d20596 u65536 alloc=16*4096
[    0.000000] pcpu-alloc: [0] 0 [0] 1 [0] 2 [0] 3 
[    0.000000] Built 1 zonelists, mobility grouping on.  Total pages: 1011008
[    0.000000] Kernel command line: coherent_pool=1M 8250.nr_uarts=0 cma=64M cma=256M  smsc95xx.macaddr=DC:A6:32:1F:BA:DC vc_mem.mem_base=0x3ec00000 vc_mem.mem_size=0x40000000  console=ttyS0,115200 console=tty1 root=PARTUUID=738a4d67-02 rootfstype=ext4 elevator=deadline fsck.repair=yes rootwait
[    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: 3735568K/4050944K available (8192K kernel code, 691K rwdata, 2420K rodata, 2048K init, 858K bss, 53232K reserved, 262144K cma-reserved, 3264512K 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)   (2048 kB)
                     .data : 0x(ptrval) - 0x(ptrval)   ( 692 kB)
                      .bss : 0x(ptrval) - 0x(ptrval)   ( 859 kB)
[    0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1
[    0.000000] ftrace: allocating 28868 entries in 85 pages
[    0.000000] rcu: Hierarchical RCU implementation.
[    0.000000] NR_IRQS: 16, nr_irqs: 16, preallocated irqs: 16
[    0.000000] GIC: Using split EOI/Deactivate mode
[    0.000000] arch_timer: cp15 timer(s) running at 54.00MHz (phys).
[    0.000000] clocksource: arch_sys_counter: mask: 0xffffffffffffff max_cycles: 0xc743ce346, max_idle_ns: 440795203123 ns
[    0.000005] sched_clock: 56 bits at 54MHz, resolution 18ns, wraps every 4398046511102ns
[    0.000022] Switching to timer-based delay loop, resolution 18ns
[    0.000251] Console: colour dummy device 80x30
[    0.000694] console [tty1] enabled
[    0.000746] Calibrating delay loop (skipped), value calculated using timer frequency.. 108.00 BogoMIPS (lpj=540000)
[    0.000783] pid_max: default: 32768 minimum: 301
[    0.001065] Mount-cache hash table entries: 2048 (order: 1, 8192 bytes)
[    0.001098] Mountpoint-cache hash table entries: 2048 (order: 1, 8192 bytes)
[    0.001872] CPU: Testing write buffer coherency: ok
[    0.002288] CPU0: thread -1, cpu 0, socket 0, mpidr 80000000
[    0.002943] Setting up static identity map for 0x200000 - 0x20003c
[    0.003117] rcu: Hierarchical SRCU implementation.
[    0.003995] smp: Bringing up secondary CPUs ...
[    0.004891] CPU1: thread -1, cpu 1, socket 0, mpidr 80000001
[    0.005873] CPU2: thread -1, cpu 2, socket 0, mpidr 80000002
[    0.006814] CPU3: thread -1, cpu 3, socket 0, mpidr 80000003
[    0.006935] smp: Brought up 1 node, 4 CPUs
[    0.007003] SMP: Total of 4 processors activated (432.00 BogoMIPS).
[    0.007026] CPU: All CPU(s) started in HYP mode.
[    0.007046] CPU: Virtualization extensions available.
[    0.007834] devtmpfs: initialized
[    0.018754] VFP support v0.3: implementor 41 architecture 3 part 40 variant 8 rev 0
[    0.018994] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 ns
[    0.019036] futex hash table entries: 1024 (order: 4, 65536 bytes)
[    0.025118] pinctrl core: initialized pinctrl subsystem
[    0.026002] NET: Registered protocol family 16
[    0.028923] DMA: preallocated 1024 KiB pool for atomic coherent allocations
[    0.030369] hw-breakpoint: found 5 (+1 reserved) breakpoint and 4 watchpoint registers.
[    0.030402] hw-breakpoint: maximum watchpoint size is 8 bytes.
[    0.030607] Serial: AMBA PL011 UART driver
[    0.033692] bcm2835-mbox fe00b880.mailbox: mailbox enabled
[    0.050018] raspberrypi-firmware soc:firmware: Attached to firmware from 2020-04-27 14:33, variant start
[    0.060034] raspberrypi-firmware soc:firmware: Firmware hash is 3a8f1793b758d6fb7f375edaa260e069ecd34c88
[    0.101932] bcm2835-dma fe007000.dma: DMA legacy API manager at (ptrval), dmachans=0x1
[    0.105080] vgaarb: loaded
[    0.105451] SCSI subsystem initialized
[    0.105651] usbcore: registered new interface driver usbfs
[    0.105722] usbcore: registered new interface driver hub
[    0.105804] usbcore: registered new device driver usb
[    0.107059] clocksource: Switched to clocksource arch_sys_counter
[    0.183921] VFS: Disk quotas dquot_6.6.0
[    0.184031] VFS: Dquot-cache hash table entries: 1024 (order 0, 4096 bytes)
[    0.184218] FS-Cache: Loaded
[    0.184413] CacheFiles: Loaded
[    0.184934] simple-framebuffer: probe of 0.framebuffer failed with error -12
[    0.194101] NET: Registered protocol family 2
[    0.194861] tcp_listen_portaddr_hash hash table entries: 512 (order: 0, 6144 bytes)
[    0.194906] TCP established hash table entries: 8192 (order: 3, 32768 bytes)
[    0.194977] TCP bind hash table entries: 8192 (order: 4, 65536 bytes)
[    0.195060] TCP: Hash tables configured (established 8192 bind 8192)
[    0.195195] UDP hash table entries: 512 (order: 2, 16384 bytes)
[    0.195240] UDP-Lite hash table entries: 512 (order: 2, 16384 bytes)
[    0.195460] NET: Registered protocol family 1
[    0.196008] RPC: Registered named UNIX socket transport module.
[    0.196035] RPC: Registered udp transport module.
[    0.196056] RPC: Registered tcp transport module.
[    0.196077] RPC: Registered tcp NFSv4.1 backchannel transport module.
[    0.196105] PCI: CLS 0 bytes, default 64
[    0.197866] hw perfevents: enabled with armv7_cortex_a15 PMU driver, 7 counters available
[    0.199994] Initialise system trusted keyrings
[    0.200187] workingset: timestamp_bits=14 max_order=20 bucket_order=6
[    0.209312] FS-Cache: Netfs 'nfs' registered for caching
[    0.209851] NFS: Registering the id_resolver key type
[    0.209889] Key type id_resolver registered
[    0.209911] Key type id_legacy registered
[    0.209943] nfs4filelayout_init: NFSv4 File Layout Driver Registering...
[    0.214466] Key type asymmetric registered
[    0.214493] Asymmetric key parser 'x509' registered
[    0.214616] bounce: pool size: 64 pages
[    0.214669] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 250)
[    0.214844] io scheduler noop registered
[    0.214868] io scheduler deadline registered (default)
[    0.215043] io scheduler cfq registered
[    0.215066] io scheduler mq-deadline registered (default)
[    0.215089] io scheduler kyber registered
[    0.245677] brcm-pcie fd500000.pcie: dmabounce: initialised - 32768 kB, threshold 0x00000000c0000000
[    0.245724] brcm-pcie fd500000.pcie: could not get clock
[    0.245797] brcm-pcie fd500000.pcie: host bridge /scb/pcie@7d500000 ranges:
[    0.245849] brcm-pcie fd500000.pcie:   MEM 0x600000000..0x603ffffff -> 0xf8000000
[    0.297098] brcm-pcie fd500000.pcie: link up, 5.0 Gbps x1 (!SSC)
[    0.297376] brcm-pcie fd500000.pcie: PCI host bridge to bus 0000:00
[    0.297407] pci_bus 0000:00: root bus resource [bus 00-01]
[    0.297436] pci_bus 0000:00: root bus resource [mem 0x600000000-0x603ffffff] (bus address [0xf8000000-0xfbffffff])
[    0.297500] pci 0000:00:00.0: [14e4:2711] type 01 class 0x060400
[    0.297637] pci 0000:00:00.0: PME# supported from D0 D3hot
[    0.300407] PCI: bus0: Fast back to back transfers disabled
[    0.300438] pci 0000:00:00.0: bridge configuration invalid ([bus 00-00]), reconfiguring
[    0.300664] pci 0000:01:00.0: [1106:3483] type 00 class 0x0c0330
[    0.300789] pci 0000:01:00.0: reg 0x10: [mem 0x00000000-0x00000fff 64bit]
[    0.301106] pci 0000:01:00.0: PME# supported from D0 D3cold
[    0.303879] PCI: bus1: Fast back to back transfers disabled
[    0.303909] pci_bus 0000:01: busn_res: [bus 01] end is updated to 01
[    0.303954] pci 0000:00:00.0: BAR 8: assigned [mem 0x600000000-0x6000fffff]
[    0.303988] pci 0000:01:00.0: BAR 0: assigned [mem 0x600000000-0x600000fff 64bit]
[    0.304076] pci 0000:00:00.0: PCI bridge to [bus 01]
[    0.304105] pci 0000:00:00.0:   bridge window [mem 0x600000000-0x6000fffff]
[    0.304332] pcieport 0000:00:00.0: enabling device (0140 -> 0142)
[    0.304516] pcieport 0000:00:00.0: Signaling PME with IRQ 54
[    0.304683] pcieport 0000:00:00.0: AER enabled with IRQ 54
[    0.304863] pci 0000:01:00.0: enabling device (0140 -> 0142)
[    0.308911] iproc-rng200 fe104000.rng: hwrng registered
[    0.309155] vc-mem: phys_addr:0x00000000 mem_base=0x3ec00000 mem_size:0x40000000(1024 MiB)
[    0.309670] vc-sm: Videocore shared memory driver
[    0.310081] gpiomem-bcm2835 fe200000.gpiomem: Initialised: Registers at 0xfe200000
[    0.320029] brd: module loaded
[    0.329610] loop: module loaded
[    0.330357] Loading iSCSI transport class v2.0-870.
[    0.332014] libphy: Fixed MDIO Bus: probed
[    0.332440] bcmgenet fd580000.genet: failed to get enet clock
[    0.332471] bcmgenet fd580000.genet: GENET 5.0 EPHY: 0x0000
[    0.332501] bcmgenet fd580000.genet: failed to get enet-wol clock
[    0.332530] bcmgenet fd580000.genet: failed to get enet-eee clock
[    0.332566] bcmgenet: Skipping UMAC reset
[    0.332815] unimac-mdio unimac-mdio.-19: DMA mask not set
[    0.347097] libphy: bcmgenet MII bus: probed
[    0.387589] unimac-mdio unimac-mdio.-19: Broadcom UniMAC MDIO bus at 0x(ptrval)
[    0.388515] usbcore: registered new interface driver r8152
[    0.388587] usbcore: registered new interface driver lan78xx
[    0.388655] usbcore: registered new interface driver smsc95xx
[    0.388966] xhci_hcd 0000:01:00.0: xHCI Host Controller
[    0.389011] xhci_hcd 0000:01:00.0: new USB bus registered, assigned bus number 1
[    0.391252] xhci_hcd 0000:01:00.0: hcc params 0x002841eb hci version 0x100 quirks 0x0000001000000890
[    0.391591] genirq: irq_chip Brcm_MSI did not update eff. affinity mask of irq 55
[    0.392468] usb usb1: New USB device found, idVendor=1d6b, idProduct=0002, bcdDevice= 4.19
[    0.392502] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[    0.392531] usb usb1: Product: xHCI Host Controller
[    0.392555] usb usb1: Manufacturer: Linux 4.19.118-v7l+ xhci-hcd
[    0.392579] usb usb1: SerialNumber: 0000:01:00.0
[    0.393098] hub 1-0:1.0: USB hub found
[    0.393191] hub 1-0:1.0: 1 port detected
[    0.393670] xhci_hcd 0000:01:00.0: xHCI Host Controller
[    0.393706] xhci_hcd 0000:01:00.0: new USB bus registered, assigned bus number 2
[    0.393748] xhci_hcd 0000:01:00.0: Host supports USB 3.0 SuperSpeed
[    0.394169] usb usb2: New USB device found, idVendor=1d6b, idProduct=0003, bcdDevice= 4.19
[    0.394200] usb usb2: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[    0.394229] usb usb2: Product: xHCI Host Controller
[    0.394252] usb usb2: Manufacturer: Linux 4.19.118-v7l+ xhci-hcd
[    0.394276] usb usb2: SerialNumber: 0000:01:00.0
[    0.394776] hub 2-0:1.0: USB hub found
[    0.394845] hub 2-0:1.0: 4 ports detected
[    0.396008] dwc_otg: version 3.00a 10-AUG-2012 (platform bus)
[    0.396211] dwc_otg: FIQ enabled
[    0.396220] dwc_otg: NAK holdoff enabled
[    0.396228] dwc_otg: FIQ split-transaction FSM enabled
[    0.396240] Module dwc_common_port init
[    0.396455] usbcore: registered new interface driver uas
[    0.396568] usbcore: registered new interface driver usb-storage
[    0.396756] mousedev: PS/2 mouse device common for all mice
[    0.397973] bcm2835-wdt bcm2835-wdt: Broadcom BCM2835 watchdog timer
[    0.399580] sdhci: Secure Digital Host Controller Interface driver
[    0.399605] sdhci: Copyright(c) Pierre Ossman
[    0.400006] mmc-bcm2835 fe300000.mmcnr: could not get clk, deferring probe
[    0.400406] sdhci-pltfm: SDHCI platform and OF driver helper
[    0.403418] ledtrig-cpu: registered to indicate activity on CPUs
[    0.403578] hidraw: raw HID events driver (C) Jiri Kosina
[    0.403709] usbcore: registered new interface driver usbhid
[    0.403732] usbhid: USB HID core driver
[    0.404514] vchiq: vchiq_init_state: slot_zero = (ptrval), is_master = 0
[    0.406267] [vc_sm_connected_init]: start
[    0.415063] [vc_sm_connected_init]: end - returning 0
[    0.416170] Initializing XFRM netlink socket
[    0.416213] NET: Registered protocol family 17
[    0.416310] Key type dns_resolver registered
[    0.416611] Registering SWP/SWPB emulation handler
[    0.417250] registered taskstats version 1
[    0.417279] Loading compiled-in X.509 certificates
[    0.426959] uart-pl011 fe201000.serial: cts_event_workaround enabled
[    0.427039] fe201000.serial: ttyAMA0 at MMIO 0xfe201000 (irq = 34, base_baud = 0) is a PL011 rev2
[    0.432151] bcm2835-power bcm2835-power: Broadcom BCM2835 power domains driver
[    0.432684] brcmstb_thermal fd5d2200.thermal: registered AVS TMON of-sensor driver
[    0.433329] mmc-bcm2835 fe300000.mmcnr: mmc_debug:0 mmc_debug2:0
[    0.433356] mmc-bcm2835 fe300000.mmcnr: DMA channel allocated
[    0.457633] sdhci-iproc fe340000.emmc2: Linked as a consumer to regulator.3
[    0.457731] sdhci-iproc fe340000.emmc2: Linked as a consumer to regulator.4
[    0.477022] mmc1: queuing unknown CIS tuple 0x80 (2 bytes)
[    0.478663] mmc1: queuing unknown CIS tuple 0x80 (3 bytes)
[    0.480287] mmc1: queuing unknown CIS tuple 0x80 (3 bytes)
[    0.483159] mmc1: queuing unknown CIS tuple 0x80 (7 bytes)
[    0.484767] mmc1: queuing unknown CIS tuple 0x80 (3 bytes)
[    0.492800] mmc0: SDHCI controller on fe340000.emmc2 [fe340000.emmc2] using ADMA
[    0.495311] of_cfs_init
[    0.495407] of_cfs_init: OK
[    0.495964] Waiting for root device PARTUUID=738a4d67-02...
[    0.540929] random: fast init done
[    0.553868] mmc1: new high speed SDIO card at address 0001
[    0.596749] mmc0: new ultra high speed DDR50 SDHC card at address aaaa
[    0.597888] mmcblk0: mmc0:aaaa SS16G 14.8 GiB
[    0.600201]  mmcblk0: p1 p2
[    0.616732] EXT4-fs (mmcblk0p2): mounted filesystem with ordered data mode. Opts: (null)
[    0.616802] VFS: Mounted root (ext4 filesystem) readonly on device 179:2.
[    0.621642] devtmpfs: mounted
[    0.629040] Freeing unused kernel memory: 2048K
[    0.657316] Run /sbin/init as init process
[    0.757110] usb 1-1: new high-speed USB device number 2 using xhci_hcd
[    0.939749] usb 1-1: New USB device found, idVendor=2109, idProduct=3431, bcdDevice= 4.21
[    0.939789] usb 1-1: New USB device strings: Mfr=0, Product=1, SerialNumber=0
[    0.939816] usb 1-1: Product: USB2.0 Hub
[    0.941701] hub 1-1:1.0: USB hub found
[    0.941972] hub 1-1:1.0: 4 ports detected
[    1.091448] systemd[1]: System time before build time, advancing clock.
[    1.183116] NET: Registered protocol family 10
[    1.184359] Segment Routing with IPv6
[    1.219495] systemd[1]: systemd 241 running in system mode. (+PAM +AUDIT +SELINUX +IMA +APPARMOR +SMACK +SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS +ACL +XZ +LZ4 +SECCOMP +BLKID +ELFUTILS +KMOD -IDN2 +IDN -PCRE2 default-hierarchy=hybrid)
[    1.220207] systemd[1]: Detected architecture arm.
[    1.234850] systemd[1]: Set hostname to <raspberrypi>.
[    1.863440] random: systemd: uninitialized urandom read (16 bytes read)
[    1.895136] systemd[1]: Condition check resulted in Journal Audit Socket being skipped.
[    1.895268] random: systemd: uninitialized urandom read (16 bytes read)
[    1.895352] systemd[1]: Reached target Swap.
[    1.895964] random: systemd: uninitialized urandom read (16 bytes read)
[    1.896276] systemd[1]: Started Forward Password Requests to Wall Directory Watch.
[    1.896997] systemd[1]: Started Dispatch Password Requests to Console Directory Watch.
[    1.903774] systemd[1]: Listening on Journal Socket.
[    1.908260] systemd[1]: Created slice User and Session Slice.
[    1.909209] systemd[1]: Listening on Journal Socket (/dev/log).
[    2.475107] EXT4-fs (mmcblk0p2): re-mounted. Opts: (null)
[    2.594913] systemd-journald[123]: Received request to flush runtime journal from PID 1
[    3.137175] rpivid-mem feb00000.hevc-decoder: rpivid-hevcmem initialised: Registers at 0xfeb00000 length 0x0000ffff
[    3.140443] rpivid-mem feb10000.rpivid-local-intc: rpivid-intcmem initialised: Registers at 0xfeb10000 length 0x00000fff
[    3.143065] rpivid-mem feb20000.h264-decoder: rpivid-h264mem initialised: Registers at 0xfeb20000 length 0x0000ffff
[    3.150748] rpivid-mem feb30000.vp9-decoder: rpivid-vp9mem initialised: Registers at 0xfeb30000 length 0x0000ffff
[    3.167509] snd_bcm2835: module is from the staging directory, the quality is unknown, you have been warned.
[    3.204258] bcm2835_audio soc:audio: card created with 8 channels
[    3.276896] [drm] Initialized v3d 1.0.0 20180419 for fec00000.v3d on minor 0
[    3.333657] [drm] No displays found. Consider forcing hotplug if HDMI is attached
[    3.333755] vc4-drm soc:gpu: bound fe600000.firmwarekms (ops vc4_fkms_ops [vc4])
[    3.334218] [drm] Initialized vc4 0.0.0 20140616 for soc:gpu on minor 1
[    3.334229] [drm] Supports vblank timestamp caching Rev 2 (21.10.2013).
[    3.334238] [drm] No driver support for vblank timestamp query.
[    3.334248] [drm] Setting vblank_disable_immediate to false because get_vblank_timestamp == NULL
[    3.345943] vc_sm_cma: module is from the staging directory, the quality is unknown, you have been warned.
[    3.348175] bcm2835_vc_sm_cma_probe: Videocore shared memory driver
[    3.348191] [vc_sm_connected_init]: start
[    3.361297] [vc_sm_connected_init]: installed successfully
[    3.362351] media: Linux media interface: v0.10
[    3.416402] videodev: Linux video capture interface: v2.00
[    3.485130] cfg80211: Loading compiled-in X.509 certificates for regulatory database
[    3.495129] bcm2835_mmal_vchiq: module is from the staging directory, the quality is unknown, you have been warned.
[    3.500835] bcm2835_v4l2: module is from the staging directory, the quality is unknown, you have been warned.
[    3.521011] bcm2835_codec: module is from the staging directory, the quality is unknown, you have been warned.
[    3.534123] cfg80211: Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7'
[    3.535428] bcm2835-codec bcm2835-codec: Device registered as /dev/video10
[    3.535463] bcm2835-codec bcm2835-codec: Loaded V4L2 decode
[    3.542005] bcm2835-codec bcm2835-codec: Device registered as /dev/video11
[    3.542037] bcm2835-codec bcm2835-codec: Loaded V4L2 encode
[    3.566267] bcm2835-codec bcm2835-codec: Device registered as /dev/video12
[    3.566307] bcm2835-codec bcm2835-codec: Loaded V4L2 isp
[    3.586220] brcmfmac: F1 signature read @0x18000000=0x15264345
[    3.597249] brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac43455-sdio for chip BCM4345/6
[    3.597606] usbcore: registered new interface driver brcmfmac
[    3.793838] CAN device driver interface
[    3.803165] spi_master spi0: will run message pump with realtime priority
[    3.838926] brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac43455-sdio for chip BCM4345/6
[    3.857195] mcp25xxfd spi0.1 (unnamed net_device) (uninitialized): -------------------- register dump --------------------
[    3.857208] OSC: osc(0x000)=0x00000460
[    3.857219]          SCLKRDY         Synchronized SCLKDIV
[    3.857229]           OSCRDY   x     Clock Ready
[    3.857239]           PLLRDY         PLL Ready
[    3.857249]          CLKODIV =  3        Clock Output Divisor
[    3.857258]          SCLKDIV         System Clock Divisor
[    3.857268]            LPMEN         Low Power Mode (LPM) Enable (MCP2518FD only)
[    3.857278]           OSCDIS         Clock (Oscillator) Disable
[    3.857287]            PLLEN         PLL Enable

[    3.857315] CON: con(0x000)=0x048b0760
[    3.857327]            TXBWS = 0x00      Transmit Bandwidth Sharing
[    3.857336]             ABAT         Abort All Pending Transmissions
[    3.857346]            REQOP = 0x04      Request Operation Mode
[    3.857355]            OPMOD = 0x04      Operation Mode Status
[    3.857364]            TXQEN         Enable Transmit Queue
[    3.857373]             STEF   x     Store in Transmit Event FIFO
[    3.857383]         SERR2LOM         Transition to Listen Only Mode on System Error
[    3.857392]            ESIGM   x     Transmit ESI in Gateway Mode
[    3.857401]            RTXAT   x     Restrict Retransmission Attempts
[    3.857410]           BRSDIS         Bit Rate Switching Disable
[    3.857420]             BUSY         CAN Module is Busy
[    3.857429]              WFT = 0x03      Selectable Wake-up Filter Time
[    3.857439]           WAKFIL   x     Enable CAN Bus Line Wake-up Filter
[    3.857448]           PXEDIS   x     Protocol Exception Event Detection Disabled
[    3.857458]         ISOCRCEN   x     Enable ISO CRC in CAN FD Frames
[    3.857467]            DNCNT = 0x00      Device Net Filter Bit Number

[    3.857485] TBC: tbc(0x010)=0x98016d7d

[    3.857503] VEC: vec(0x018)=0x40400040
[    3.857512]  rxcode: No Interrupt (0x40)
[    3.857527]  txcode: No Interrupt (0x40)
[    3.857540]  icode: No Interrupt (0x40)

[    3.857564] INT: intf(0x01c)=0x00000004
[    3.857572]      IE  IF  IE & IF
[    3.857583]  IVMI                Invalid Message Interrupt
[    3.857592]  WAKI                Bus Wake Up Interrupt
[    3.857602]  CERRI               CAN Bus Error Interrupt
[    3.857611]  SERRI               System Error Interrupt
[    3.857620]  RXOVI               Receive FIFO Overflow Interrupt
[    3.857630]  TXATI               Transmit Attempt Interrupt
[    3.857639]  SPICRCI             SPI CRC Error Interrupt
[    3.857649]  ECCI                ECC Error Interrupt
[    3.857668]  TEFI                Transmit Event FIFO Interrupt
[    3.857677]  MODI                Mode Change Interrupt
[    3.857687]  TBCI        x       Time Base Counter Interrupt
[    3.857696]  RXI             Receive FIFO Interrupt
[    3.857705]  TXI             Transmit FIFO Interrupt

[    3.857723] RXIF: rxif(0x020)=0x00000000
[    3.857731] Receive FIFO Interrupt Pending bits:
[    3.857739]      -none-

[    3.857757] RXOVIF: rxovif(0x028)=0x00000000
[    3.857765] Receive FIFO Overflow Interrupt Pending bits:
[    3.857773]      -none-

[    3.857790] TXIF: txif(0x024)=0x00000000
[    3.857799] Transmit FIFO Interrupt Pending bits:
[    3.857807]      -none-

[    3.857824] TXATIF: txatif(0x02c)=0x00000000
[    3.857832] Transmit FIFO Attempt Interrupt Pending bits:
[    3.857841]      -none-

[    3.857858] TXREQ: txreq(0x030)=0x00000000
[    3.857866] Message Send Request bits:
[    3.857874]      -none-

[    3.857892] TREC: trec(0x034)=0x00200000
[    3.857901]             TXBO   x     Transmitter in Bus Off State
[    3.857911]             TXBP         Transmitter in Error Passive State
[    3.857920]             RXBP         Receiver in Error Passive State
[    3.857929]           TXWARN         Transmitter in Error Warning State
[    3.857938]           RXWARN         Receiver in Error Warning State
[    3.857948]            EWARN         Transmitter or Receiver is in Error Warning State
[    3.857958]              TEC =   0       Transmit Error Counter
[    3.857967]              REC =   0       Receive Error Counter

[    3.857984] BDIAG0: bdiag0(0x038)=0x00000000
[    3.857994]         DTERRCNT =   0       Data Bit Rate Transmit Error Counter
[    3.858003]         DRERRCNT =   0       Data Bit Rate Receive Error Counter
[    3.858012]         NTERRCNT =   0       Nominal Bit Rate Transmit Error Counter
[    3.858022]         NRERRCNT =   0       Nominal Bit Rate Receive Error Counter

[    3.858039] BDIAG1: bdiag1(0x03c)=0x00000000
[    3.858052]            DLCMM         DLC Mismatch
[    3.858061]              ESI         ESI flag of a received CAN FD message was set
[    3.858071]          DCRCERR         Data CRC Error
[    3.858080]         DSTUFERR         Data Bit Stuffing Error
[    3.858089]         DFORMERR         Data Format Error
[    3.858098]         DBIT1ERR         Data BIT1 Error
[    3.858107]         DBIT0ERR         Data BIT0 Error
[    3.858117]          TXBOERR         Device went to bus-off (and auto-recovered)
[    3.858126]          NCRCERR         CRC Error
[    3.858135]         NSTUFERR         Bit Stuffing Error
[    3.858144]         NFORMERR         Format Error
[    3.858154]          NACKERR         Transmitted message was not acknowledged
[    3.858167]         NBIT1ERR         Bit1 Error
[    3.858177]         NBIT0ERR         Bit0 Error
[    3.858187]         EFMSGCNT =   0       Error Free Message Counter bits

[    3.858203] -------------------- TEF --------------------
[    3.858213] TEFCON: tefcon(0x040)=0x07000429
[    3.858223]            FSIZE =   7       FIFO Size
[    3.858232]           FRESET   x     FIFO Reset
[    3.858241]             UINC         Increment Tail
[    3.858250]          TEFTSEN   x     Transmit Event FIFO Time Stamp Enable
[    3.858259]          TEFOVIE   x     Transmit Event FIFO Overflow Interrupt Enable
[    3.858269]           TEFFIE         Transmit Event FIFO Full Interrupt Enable
[    3.858278]           TEFHIE         Transmit Event FIFO Half Full Interrupt Enable
[    3.858287]          TEFNEIE   x     Transmit Event FIFO Not Empty Interrupt Enable

[    3.858304] TEFSTA: tefsta(0x044)=0x00000000
[    3.858314]          TEFOVIF         Transmit Event FIFO Overflow Interrupt Flag
[    3.858323]           TEFFIF         Transmit Event FIFO Full Interrupt Flag (0 = not full)
[    3.858332]           TEFHIF         Transmit Event FIFO Half Full Interrupt Flag (0= < half full)
[    3.858342]          TEFNEIF         Transmit Event FIFO Not Empty Interrupt Flag (0=empty)

[    3.858359] TEFUA: tefua(0x048)=0x00000000

[    3.858375] -------------------- TX_FIFO --------------------
[    3.858385] FIFOCON: fifocon(0x05c)=0x07600490
[    3.858394]           PLSIZE =   0       Payload Size
[    3.858403]            FSIZE =   7       FIFO Size
[    3.858413]             TXAT =   3       Retransmission Attempts
[    3.858422]            TXPRI =   0       Message Transmit Priority
[    3.858430]           FRESET   x     FIFO Reset
[    3.858440]            TXREQ         Message Send Request
[    3.858449]             UINC         Increment Head/Tail
[    3.858458]             TXEN   x     TX/RX FIFO Selection (0=RX, 1=TX)
[    3.858467]            RTREN         Auto RTR Enable
[    3.858476]           RXTSEN         Received Message Time Stamp Enable
[    3.858485]           TXATIE   x     Transmit Attempts Exhausted Interrupt Enable
[    3.858494]           RXOVIE         Overflow Interrupt Enable
[    3.858503]         TFERFFIE         Transmit/Receive FIFO Empty/Full Interrupt Enable
[    3.858513]         TFHRFHIE         Transmit/Receive FIFO Half Empty/Half Full Interrupt Enable
[    3.858522]         TFNRFNIE         Transmit/Receive FIFO Not Full/Not Empty Interrupt Enable

[    3.858540] FIFOSTA: fifosta(0x060)=0x00000007
[    3.858549]           FIFOCI =   0       FIFO Message Index
[    3.858558]            TXABT         Message Aborted Status (1=aborted, 0=completed successfully)
[    3.858567]           TXLARB         Message Lost Arbitration Status
[    3.858577]            TXERR         Error Detected During Transmission
[    3.858586]           TXATIF         Transmit Attempts Exhausted Interrupt Pending
[    3.858595]           RXOVIF         Receive FIFO Overflow Interrupt Flag
[    3.858607]         TFERFFIF   x     Transmit/Receive FIFO Empty/Full Interrupt Flag
[    3.858616]         TFHRFHIF   x     Transmit/Receive FIFO Half Empty/Half Full Interrupt Flag
[    3.858625]         TFNRFNIF   x     Transmit/Receive FIFO Not Full/Not Empty Interrupt Flag

[    3.858645] FIFOUA: fifoua(0x064)=0x00000060

[    3.858661]  -------------------- RX_FIFO --------------------
[    3.858674] FIFOCON: fifocon(0x068)=0x1f000429
[    3.858684]           PLSIZE =   0       Payload Size
[    3.858694]            FSIZE =  31       FIFO Size
[    3.858703]             TXAT =   0       Retransmission Attempts
[    3.858712]            TXPRI =   0       Message Transmit Priority
[    3.858721]           FRESET   x     FIFO Reset
[    3.858730]            TXREQ         Message Send Request
[    3.858739]             UINC         Increment Head/Tail
[    3.858754]             TXEN         TX/RX FIFO Selection (0=RX, 1=TX)
[    3.858769]            RTREN         Auto RTR Enable
[    3.858782]           RXTSEN   x     Received Message Time Stamp Enable
[    3.858791]           TXATIE         Transmit Attempts Exhausted Interrupt Enable
[    3.858800]           RXOVIE   x     Overflow Interrupt Enable
[    3.858816]         TFERFFIE         Transmit/Receive FIFO Empty/Full Interrupt Enable
[    3.858829]         TFHRFHIE         Transmit/Receive FIFO Half Empty/Half Full Interrupt Enable
[    3.858839]         TFNRFNIE   x     Transmit/Receive FIFO Not Full/Not Empty Interrupt Enable

[    3.858859] FIFOSTA: fifosta(0x06c)=0x00000000
[    3.858868]           FIFOCI =   0       FIFO Message Index
[    3.858877]            TXABT         Message Aborted Status (1=aborted, 0=completed successfully)
[    3.858887]           TXLARB         Message Lost Arbitration Status
[    3.858896]            TXERR         Error Detected During Transmission
[    3.858905]           TXATIF         Transmit Attempts Exhausted Interrupt Pending
[    3.858914]           RXOVIF         Receive FIFO Overflow Interrupt Flag
[    3.858924]         TFERFFIF         Transmit/Receive FIFO Empty/Full Interrupt Flag
[    3.858933]         TFHRFHIF         Transmit/Receive FIFO Half Empty/Half Full Interrupt Flag
[    3.858942]         TFNRFNIF         Transmit/Receive FIFO Not Full/Not Empty Interrupt Flag

[    3.858960] FIFOUA: fifoua(0x070)=0x000000e0

[    3.858984] mcp25xxfd spi0.1 (unnamed net_device) (uninitialized): ------------------------- end -------------------------
[    3.858996] mcp25xxfd spi0.1 (unnamed net_device) (uninitialized): ----------------------- RAM dump ----------------------
[    3.859004] 
               TEF Overview:
[    3.859015]         head (p) =        0x00    0x00000000
[    3.859026]       tail (c/p) = 0x00   0x00    0x00000000

[    3.859046] TEF Object: 0x00 (0x400)  priv-HEAD  chip-TAIL  priv-TAIL  chip-FIFO-empty  priv-FIFO-empty
[    3.859055]               id = 0x00000000
[    3.859064]            flags = 0x00000000
[    3.859073]               ts = 0x00000000
[    3.859082]              SEQ = 0x000000      Sequence

[    3.859101] TEF Object: 0x01 (0x40c)
[    3.859109]               id = 0x00000000
[    3.859118]            flags = 0x00000000
[    3.859127]               ts = 0x00000000
[    3.859136]              SEQ = 0x000000      Sequence

[    3.859154] TEF Object: 0x02 (0x418)
[    3.859163]               id = 0x00000000
[    3.859171]            flags = 0x00000000
[    3.859180]               ts = 0x00000000
[    3.859189]              SEQ = 0x000000      Sequence

[    3.859207] TEF Object: 0x03 (0x424)
[    3.859216]               id = 0x00000000
[    3.859224]            flags = 0x00000000
[    3.859233]               ts = 0x00000000
[    3.859242]              SEQ = 0x000000      Sequence

[    3.859260] TEF Object: 0x04 (0x430)
[    3.859268]               id = 0x00000000
[    3.859277]            flags = 0x00000000
[    3.859286]               ts = 0x00000000
[    3.859295]              SEQ = 0x000000      Sequence

[    3.859322] TEF Object: 0x05 (0x43c)
[    3.859334]               id = 0x00000000
[    3.859349]            flags = 0x00000000
[    3.859364]               ts = 0x00000000
[    3.859376]              SEQ = 0x000000      Sequence

[    3.859403] TEF Object: 0x06 (0x448)
[    3.859416]               id = 0x00000000
[    3.859430]            flags = 0x00000000
[    3.859444]               ts = 0x00000000
[    3.859456]              SEQ = 0x000000      Sequence

[    3.859483] TEF Object: 0x07 (0x454)
[    3.859495]               id = 0x00000000
[    3.859504]            flags = 0x00000000
[    3.859519]               ts = 0x00000000
[    3.859535]              SEQ = 0x000000      Sequence

[    3.859551] 
               TX Overview:
[    3.859564]       head (c/p) = 0x00    0x00    0x00000000
[    3.859581]       tail (c/p) = 0x00    0x00    0x00000000

[    3.859606] TX Object: 0x00 (0x460)  chip-HEAD  priv-HEAD  chip-TAIL  priv-TAIL  chip-FIFO-empty  priv-FIFO-empty
[    3.859620]               id = 0x00000000
[    3.859634]            flags = 0x00000000
[    3.859645]    SEQ_MCP2517FD = 0x000000      Sequence (MCP2517)
[    3.859655]    SEQ_MCP2518FD = 0x000000      Sequence (MCP2518)
[    3.859665]             data = -none-

[    3.859683] TX Object: 0x01 (0x470)
[    3.859692]               id = 0x00000000
[    3.859701]            flags = 0x00000000
[    3.859711]    SEQ_MCP2517FD = 0x000000      Sequence (MCP2517)
[    3.859720]    SEQ_MCP2518FD = 0x000000      Sequence (MCP2518)
[    3.859729]             data = -none-

[    3.859747] TX Object: 0x02 (0x480)
[    3.859762]               id = 0x00000000
[    3.859777]            flags = 0x00000000
[    3.859789]    SEQ_MCP2517FD = 0x000000      Sequence (MCP2517)
[    3.859802]    SEQ_MCP2518FD = 0x000000      Sequence (MCP2518)
[    3.859811]             data = -none-

[    3.859829] TX Object: 0x03 (0x490)
[    3.859838]               id = 0x00000000
[    3.859847]            flags = 0x00000000
[    3.859856]    SEQ_MCP2517FD = 0x000000      Sequence (MCP2517)
[    3.859865]    SEQ_MCP2518FD = 0x000000      Sequence (MCP2518)
[    3.859873]             data = -none-

[    3.859891] TX Object: 0x04 (0x4a0)
[    3.859900]               id = 0x00000000
[    3.859908]            flags = 0x00000000
[    3.859917]    SEQ_MCP2517FD = 0x000000      Sequence (MCP2517)
[    3.859926]    SEQ_MCP2518FD = 0x000000      Sequence (MCP2518)
[    3.859935]             data = -none-

[    3.859953] TX Object: 0x05 (0x4b0)
[    3.859961]               id = 0x00000000
[    3.859970]            flags = 0x00000000
[    3.859979]    SEQ_MCP2517FD = 0x000000      Sequence (MCP2517)
[    3.859989]    SEQ_MCP2518FD = 0x000000      Sequence (MCP2518)
[    3.859997]             data = -none-

[    3.860015] TX Object: 0x06 (0x4c0)
[    3.860029]               id = 0x00000000
[    3.860043]            flags = 0x00000000
[    3.860056]    SEQ_MCP2517FD = 0x000000      Sequence (MCP2517)
[    3.860071]    SEQ_MCP2518FD = 0x000000      Sequence (MCP2518)
[    3.860084]             data = -none-

[    3.860110] TX Object: 0x07 (0x4d0)
[    3.860125]               id = 0x00000000
[    3.860138]            flags = 0x00000000
[    3.860148]    SEQ_MCP2517FD = 0x000000      Sequence (MCP2517)
[    3.860157]    SEQ_MCP2518FD = 0x000000      Sequence (MCP2518)
[    3.860166]             data = -none-

[    3.860182] 
               RX Overview:
[    3.860204] Unable to handle kernel NULL pointer dereference at virtual address 0000000c
[    3.860245] pgd = (ptrval)
[    3.860284] [0000000c] *pgd=1b67d003, *pmd=fbea0003
[    3.860333] Internal error: Oops: 207 [#1] SMP ARM
[    3.860355] Modules linked in: mcp25xxfd(+) can_dev brcmfmac brcmutil bcm2835_codec(C) v4l2_mem2mem videobuf2_dma_contig bcm2835_v4l2(C) bcm2835_mmal_vchiq(C) v4l2_common videobuf2_vmalloc cfg80211 videobuf2_memops videobuf2_v4l2 videobuf2_common rfkill videodev media raspberrypi_hwmon hwmon vc_sm_cma(C) vc4 drm_kms_helper v3d gpu_sched snd_soc_core drm snd_compress snd_bcm2835(C) drm_panel_orientation_quirks snd_pcm_dmaengine snd_pcm rpivid_mem snd_timer snd syscopyarea spi_bcm2835 sysfillrect sysimgblt fb_sys_fops uio_pdrv_genirq uio ip_tables x_tables ipv6
[    3.860560] CPU: 1 PID: 242 Comm: modprobe Tainted: G         C        4.19.118-v7l+ #1
[    3.860586] Hardware name: BCM2835
[    3.860638] PC is at mcp25xxfd_dump+0x1724/0x1de8 [mcp25xxfd]
[    3.860667] LR is at irq_work_queue+0x14/0x2c
[    3.860687] pc : [<bf871d84>]    lr : [<c0323040>]    psr: 60000013
[    3.860709] sp : db23ba80  ip : 00000007  fp : db23baec
[    3.860729] r10: 00000000  r9 : bf875940  r8 : 00005940
[    3.860750] r7 : 00000000  r6 : db3695bc  r5 : db3693ec  r4 : db368500
[    3.860771] r3 : 663e5698  r2 : 663e5698  r1 : 00000000  r0 : 0000000d
[    3.860795] Flags: nZCv  IRQs on  FIQs on  Mode SVC_32  ISA ARM  Segment user
[    3.860819] Control: 30c5383d  Table: 1b122380  DAC: 55555555
[    3.860841] Process modprobe (pid: 242, stack limit = 0x(ptrval))
[    3.860863] Stack: (0xdb23ba80 to 0xdb23c000)
[    3.860887] ba80: bf875940 bf875940 bf875940 bf875940 bf875940 db23baa0 00000000 db3693ec
[    3.860917] baa0: bf876cd0 bf876ca0 bf8759b8 00000000 bf875940 bf8748f4 bf875940 00000000
[    3.860947] bac0: db23baec c1004d88 00000004 1e2e5383 00000001 db368500 00000000 00000000
[    3.860994] bae0: db23bb34 db23baf0 bf86d274 bf87066c 00000000 00000000 00000000 db23bb08
[    3.861035] bb00: 048b0760 663e5698 db23bb34 db368500 c1004d88 bf874c28 bf87403c bf874c6c
[    3.861065] bb20: bf874bdc 00000003 db23bb84 db23bb38 bf86d37c bf86d124 60000013 00000000
[    3.861095] bb40: e45aa882 00000000 c09dbdd4 00007094 00000460 663e5698 db23bb84 00000000
[    3.861123] bb60: c1004d88 db368500 00000000 db368000 db368000 ef3f2400 db23bc4c db23bb88
[    3.861152] bb80: bf86e3bc bf86d294 db23bbe8 c1004d88 eff6a3d4 c0bda6d8 c0bda6c4 bf878010
[    3.861181] bba0: db23bbdc db23bbb0 c08664b0 c0865fc8 00000000 663e5698 db23bbec ef3f2400
[    3.861210] bbc0: c1004d88 bf878000 00000000 00000000 db23bc24 db23bbe0 c0866f94 c0866468
[    3.861254] bbe0: 00000000 eff60a20 00000000 00000000 00000000 00000000 00000000 00000000
[    3.861284] bc00: db369000 db368500 db19be40 663e5698 ef3f2400 00000038 db23bc3c 663e5698
[    3.861313] bc20: c07290f0 ef3f2400 00000000 bf878000 00000000 00000000 bf878010 0000001d
[    3.861342] bc40: db23bc6c db23bc50 c076807c bf86e0b0 c1156cc8 ef3f2400 c1156ccc 00000000
[    3.861372] bc60: db23bc9c db23bc70 c0718894 c0767ffc 00000000 ef3f2400 bf878010 ef3f2434
[    3.861400] bc80: c0718c40 db23bf38 db19b9c0 c1004d88 db23bcd4 db23bca0 c0718b28 c0718694
[    3.861429] bca0: c09d696c c02944e8 ef3f2434 bf878010 ef3f2400 bf878010 ef3f2434 c0718c40
[    3.861459] bcc0: db23bf38 db19b9c0 db23bcf4 db23bcd8 c0718d3c c0718ac4 dbad7334 c1004d88
[    3.861487] bce0: bf878010 c0718c40 db23bd24 db23bcf8 c07167a4 c0718c4c db23bd30 ef994358
[    3.861516] bd00: dbad7334 663e5698 bf878010 c106d190 db674680 00000000 db23bd34 db23bd28
[    3.861545] bd20: c0718120 c071672c db23bd5c db23bd38 c0717ba4 c0718100 bf87540c db23bd48
[    3.861574] bd40: bf878010 bf87e000 c1004d88 00000000 db23bd74 db23bd60 c071951c c07179e0
[    3.861602] bd60: bf878080 bf87e000 db23bd84 db23bd78 c0767fa8 c07194a4 db23bd94 db23bd88
[    3.861631] bd80: bf87e028 c0767f4c db23be0c db23bd98 c0203004 bf87e00c db23bdc4 c09d696c
[    3.861661] bda0: 00000000 00000002 db23bdcc db23bdb8 c09d696c c02944e8 006000c0 c03bf3b0
[    3.861689] bdc0: db23be0c db23bdd0 c03bf3b0 c03ccbfc 00000001 c03ad8e8 00000001 db19bac0
[    3.861718] bde0: db0fb8c0 663e5698 00000002 bf878080 00000002 db19ba80 bf878080 db23bf38
[    3.861747] be00: db23be34 db23be10 c02babc4 c0202fc0 db23be34 db23be20 00000002 00000002
[    3.861776] be20: db19b980 bf878080 db23bf14 db23be38 c02bd14c c02bab5c bf87808c 00007fff
[    3.861804] be40: bf878080 c02b9b4c c1004d88 c0b9a5c4 c0b9a5f4 c0b9a59c c0c10a9c c0a03af4
[    3.861833] be60: bf87827c bf878194 bf8781b0 c02b934c c02b9284 bf8780c8 db23be9c c0b9a1c4
[    3.861861] be80: c03d0001 00000000 c0c2c9f8 c0c1e3ec 00000000 00000000 00000000 00000000
[    3.861890] bea0: 00000000 00000000 6e72656b 00006c65 00000000 00000000 00000000 00000000
[    3.861918] bec0: 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
[    3.861947] bee0: 00000000 663e5698 7fffffff c1004d88 00000000 0002d064 00000004 c02011c4
[    3.861976] bf00: db23a000 0000017b db23bfa4 db23bf18 c02bd6ac c02bae6c 7fffffff 00000000
[    3.862005] bf20: 00000003 db23bf24 db23bf24 f12e7000 00014434 00000000 f12ee852 f12f1080
[    3.862034] bf40: f12e7000 00014434 f12fad04 f12fab24 f12f53f0 0000c000 0000e120 00000000
[    3.862062] bf60: 00000000 00000000 00004fc4 0000002b 0000002c 00000020 00000024 00000015
[    3.862091] bf80: 00000000 663e5698 3d874700 00000000 00000000 0000017b 00000000 db23bfa8
[    3.862119] bfa0: c02011a4 c02bd5e4 3d874700 00000000 00000004 0002d064 00000000 0002ec3c
[    3.862149] bfc0: 3d874700 00000000 00000000 0000017b 01d21240 00000000 01d20e00 00000000
[    3.862177] bfe0: bebb79a8 bebb7998 00022cb8 b6cdcaf0 60000010 00000004 00000000 00000000
[    3.862280] [<bf871d84>] (mcp25xxfd_dump [mcp25xxfd]) from [<bf86d274>] (__mcp25xxfd_chip_set_mode+0x15c/0x170 [mcp25xxfd])
[    3.862351] [<bf86d274>] (__mcp25xxfd_chip_set_mode [mcp25xxfd]) from [<bf86d37c>] (mcp25xxfd_chip_softreset+0xf4/0x2bc [mcp25xxfd])
[    3.862418] [<bf86d37c>] (mcp25xxfd_chip_softreset [mcp25xxfd]) from [<bf86e3bc>] (mcp25xxfd_probe+0x318/0x85c [mcp25xxfd])
[    3.862476] [<bf86e3bc>] (mcp25xxfd_probe [mcp25xxfd]) from [<c076807c>] (spi_drv_probe+0x8c/0xb0)
[    3.862517] [<c076807c>] (spi_drv_probe) from [<c0718894>] (really_probe+0x20c/0x2cc)
[    3.862552] [<c0718894>] (really_probe) from [<c0718b28>] (driver_probe_device+0x70/0x188)
[    3.862587] [<c0718b28>] (driver_probe_device) from [<c0718d3c>] (__driver_attach+0xfc/0x100)
[    3.862620] [<c0718d3c>] (__driver_attach) from [<c07167a4>] (bus_for_each_dev+0x84/0xc4)
[    3.862653] [<c07167a4>] (bus_for_each_dev) from [<c0718120>] (driver_attach+0x2c/0x30)
[    3.862685] [<c0718120>] (driver_attach) from [<c0717ba4>] (bus_add_driver+0x1d0/0x214)
[    3.862718] [<c0717ba4>] (bus_add_driver) from [<c071951c>] (driver_register+0x84/0x118)
[    3.862752] [<c071951c>] (driver_register) from [<c0767fa8>] (__spi_register_driver+0x68/0x6c)
[    3.862803] [<c0767fa8>] (__spi_register_driver) from [<bf87e028>] (mcp25xxfd_driver_init+0x28/0x1000 [mcp25xxfd])
[    3.862866] [<bf87e028>] (mcp25xxfd_driver_init [mcp25xxfd]) from [<c0203004>] (do_one_initcall+0x50/0x220)
[    3.862907] [<c0203004>] (do_one_initcall) from [<c02babc4>] (do_init_module+0x74/0x244)
[    3.862942] [<c02babc4>] (do_init_module) from [<c02bd14c>] (load_module+0x22ec/0x25f4)
[    3.862975] [<c02bd14c>] (load_module) from [<c02bd6ac>] (sys_finit_module+0xd4/0xec)
[    3.863009] [<c02bd6ac>] (sys_finit_module) from [<c02011a4>] (__sys_trace_return+0x0/0x1c)
[    3.863035] Exception stack(0xdb23bfa8 to 0xdb23bff0)
[    3.863058] bfa0:                   3d874700 00000000 00000004 0002d064 00000000 0002ec3c
[    3.863088] bfc0: 3d874700 00000000 00000000 0000017b 01d21240 00000000 01d20e00 00000000
[    3.863116] bfe0: bebb79a8 bebb7998 00022cb8 b6cdcaf0
[    3.863142] Code: e51ba054 e3058940 e50b7030 eb283db7 (e5d7300c) 
[    3.863187] ---[ end trace 3c4767274e259e20 ]---
[    3.864361] brcmfmac: brcmf_c_preinit_dcmds: Firmware: BCM4345/6 wl0: Mar  2 2020 23:30:41 version 7.45.202 (r724630 CY) FWID 01-72f6ece2
[    5.367206] Under-voltage detected! (0x00050000)
[    5.412202] 8021q: 802.1Q VLAN Support v1.8
[    5.462434] uart-pl011 fe201000.serial: no DMA platform data
[    5.462959] random: crng init done
[    5.462988] random: 7 urandom warning(s) missed due to ratelimiting
[    5.673229] Adding 102396k swap on /var/swap.  Priority:-2 extents:1 across:102396k SSFS
[    5.752440] IPv6: ADDRCONF(NETDEV_UP): wlan0: link is not ready
[    5.752541] brcmfmac: brcmf_cfg80211_set_power_mgmt: power save enabled
[    6.067388] bcmgenet: Skipping UMAC reset
[    6.167570] bcmgenet fd580000.genet: configuring instance for external RGMII (no delay)
[    6.168052] IPv6: ADDRCONF(NETDEV_UP): eth0: link is not ready
[    7.207227] bcmgenet fd580000.genet eth0: Link is Down
[   10.977150] IPv6: ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready
[   12.075425] Bluetooth: Core ver 2.22
[   12.075527] NET: Registered protocol family 31
[   12.075551] Bluetooth: HCI device and connection manager initialized
[   12.078828] Bluetooth: HCI socket layer initialized
[   12.078865] Bluetooth: L2CAP socket layer initialized
[   12.078929] Bluetooth: SCO socket layer initialized
[   12.094664] Bluetooth: HCI UART driver ver 2.3
[   12.094700] Bluetooth: HCI UART protocol H4 registered
[   12.094832] Bluetooth: HCI UART protocol Three-wire (H5) registered
[   12.095103] Bluetooth: HCI UART protocol Broadcom registered
[   12.356932] Bluetooth: BNEP (Ethernet Emulation) ver 1.3
[   12.356969] Bluetooth: BNEP filters: protocol multicast
[   12.357009] Bluetooth: BNEP socket layer initialized
[   15.767195] Voltage normalised (0x00000000)
[   28.247176] Under-voltage detected! (0x00050005)
[   36.567175] Voltage normalised (0x00000000)
marckleinebudde commented 4 years ago

What's wrong with McP25xxfd_dump?

It seems you cannot call it that early (during driver initialization). Here we see that mcp25xxfd_dump() is called when the driver itself is loaded and the device is being probed:

[    3.862280] [<bf871d84>] (mcp25xxfd_dump [mcp25xxfd]) from [<bf86d274>] (__mcp25xxfd_chip_set_mode+0x15c/0x170 [mcp25xxfd])
[    3.862351] [<bf86d274>] (__mcp25xxfd_chip_set_mode [mcp25xxfd]) from [<bf86d37c>] (mcp25xxfd_chip_softreset+0xf4/0x2bc [mcp25xxfd])
[    3.862418] [<bf86d37c>] (mcp25xxfd_chip_softreset [mcp25xxfd]) from [<bf86e3bc>] (mcp25xxfd_probe+0x318/0x85c [mcp25xxfd])
[    3.862476] [<bf86e3bc>] (mcp25xxfd_probe [mcp25xxfd]) from [<c076807c>] (spi_drv_probe+0x8c/0xb0)
[    3.862517] [<c076807c>] (spi_drv_probe) from [<c0718894>] (really_probe+0x20c/0x2cc)
[    3.862552] [<c0718894>] (really_probe) from [<c0718b28>] (driver_probe_device+0x70/0x188)
[    3.862587] [<c0718b28>] (driver_probe_device) from [<c0718d3c>] (__driver_attach+0xfc/0x100)
[    3.862620] [<c0718d3c>] (__driver_attach) from [<c07167a4>] (bus_for_each_dev+0x84/0xc4)
[    3.862653] [<c07167a4>] (bus_for_each_dev) from [<c0718120>] (driver_attach+0x2c/0x30)
[    3.862685] [<c0718120>] (driver_attach) from [<c0717ba4>] (bus_add_driver+0x1d0/0x214)
[    3.862718] [<c0717ba4>] (bus_add_driver) from [<c071951c>] (driver_register+0x84/0x118)
[    3.862752] [<c071951c>] (driver_register) from [<c0767fa8>] (__spi_register_driver+0x68/0x6c)
[    3.862803] [<c0767fa8>] (__spi_register_driver) from [<bf87e028>] (mcp25xxfd_driver_init+0x28/0x1000 [mcp25xxfd])
[    3.862866] [<bf87e028>] (mcp25xxfd_driver_init [mcp25xxfd]) from [<c0203004>] (do_one_initcall+0x50/0x220)
[    3.862907] [<c0203004>] (do_one_initcall) from [<c02babc4>] (do_init_module+0x74/0x244)
[    3.862942] [<c02babc4>] (do_init_module) from [<c02bd14c>] (load_module+0x22ec/0x25f4)
[    3.862975] [<c02bd14c>] (load_module) from [<c02bd6ac>] (sys_finit_module+0xd4/0xec)
[    3.863009] [<c02bd6ac>] (sys_finit_module) from [<c02011a4>] (__sys_trace_return+0x0/0x1c)

What I'm missing is the error message prior to the mcp25xxfd_dump():

[    3.597606] usbcore: registered new interface driver brcmfmac
[    3.793838] CAN device driver interface
[    3.803165] spi_master spi0: will run message pump with realtime priority
[    3.838926] brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac43455-sdio for chip BCM4345/6
[    3.857195] mcp25xxfd spi0.1 (unnamed net_device) (uninitialized): -------------------- register dump --------------------
[    3.857208] OSC: osc(0x000)=0x00000460

Please look again at the patch https://github.com/marckleinebudde/linux/commit/d98f6ae87b674f2692e4c20e8ed8a58b3cd12e7c or better use that branch. The mcp25xxfd_dump() is only called in the error path. And that is if the device doesn't enter into the requested operation mode. But in the dump we see that requested and actual operation mode match. At least they match when the register contents for the dump is read from the controller.

[    3.857346]            REQOP = 0x04        Request Operation Mode
[    3.857355]            OPMOD = 0x04        Operation Mode Status
Pillar1989 commented 4 years ago

@marckleinebudde We replaced it with another MCP2518FD PI HAT and reinforced its fixation on the RPI. Surprisingly it worked when CAN0 and CAN1 were opened. I'll test it several more times.

marckleinebudde commented 4 years ago

@Pillar1989 so false alarm from the SW point of view?

giampiero7 commented 4 years ago

Hi! I'd like to try this driver too. Do you have a quick setup guide to install this driver on a fresh Raspbian installation without having to recompile the whole kernel? Hopefully just compiling and installing the module... Thanks!

marckleinebudde commented 4 years ago

Hey @giampiero7,

this is not going to work, as we need several backports of SPI and CAN infrastructure patches to the raspi kernel. This cannot be done with external kernel modules.

giampiero7 commented 4 years ago

Thanks for the quick response! So the only way is to recompile the kernel with patches + driver? Any idea when is this going to the mainline?

marckleinebudde commented 4 years ago

Yes, you have to can checkout the latest raspi branch and compile it, currently that is: https://github.com/marckleinebudde/linux/tree/v5.6-rpi/mcp25xxfd-20200429-39

The driver will hit mainline as time permits to work on this. Hopefully soon!

Pillar1989 commented 4 years ago

https://www.raspberrypi.org/forums/viewtopic.php?t=269769 According to the RPI forum, the next kernel support version should be v5.4, according to the RPI convention, they will only choose the LTS version of the kernel.

marckleinebudde commented 4 years ago

@Pillar1989 once the driver is mainline, we can always backport it to the "official" raspi kernel.

marckleinebudde commented 4 years ago

@Pillar1989 I've tested the board and both CAN ports are working out of the box. Thanks again for the board!

marckleinebudde commented 4 years ago

FYI: these references are false positives, as there are #3 in kernel dmesg output in the patch description.

intx82 commented 3 years ago

I have very similar issue. Also faced with:

mcp25xxfd spi1.0 can0: Controller failed to enter mode CAN 2.0 Mode (6) and stays in Configuration Mode (4).

My hardware is Olinuxino-imx233 and MIKROE-3060 MCP2518FD module.

root@OpenWrt:~# uname -a Linux OpenWrt 5.4.67 #0 Sat Sep 26 16:26:19 2020 armv5tejl GNU/Linux

Here is full log, where i am also added some debug messages to watch CiCON register value in real-time.
There is only one thing, that i don't done at this time - do hardware MCP reset, but think that will not help

After reading errata, i have tried with CRC quirks and without, that was also useless

Do you have any idea, how to fix this? Thanks.

[    1.170000] mcp25xxfd spi1.0: Linked as a consumer to regulator.1
[    1.170000] spi_master spi1: will run message pump with realtime priority
[    1.180000] mcp25xxfd spi1.0: setup mode 0, 8 bits/w, 10000000 Hz max --> 0
[    1.180000] mcp25xxfd spi1.0: can_rx_offload_init_queue: skb_queue_len_max=512
[    1.190000] mcp25xxfd spi1.0 (unnamed net_device) (uninitialized): Set mode: Configuration (4)
[    1.190000] mcp25xxfd spi1.0 (unnamed net_device) (uninitialized): REG Con: 0x48b0760
[    1.190000] mcp25xxfd spi1.0 (unnamed net_device) (uninitialized): REG Con: 0x48b0760
[    1.200000] mcp25xxfd spi1.0 can0: MCP2518FD rev0.0 (+RX_INT -MAB_NO_WARN -CRC_REG -CRC_RX -CRC_TX +ECC +HD c:40.00MHz m:10.00MHz r:10.00MHz e:0.00MHz) successfully initialized.
[    1.220000] mcp25xxfd spi1.0 can0: Set mode: Sleep (1)
[    1.220000] driver: 'mcp25xxfd': driver_bound: bound to device 'spi1.0'
[    1.220000] bus: 'spi': really_probe: bound device spi1.0 to driver mcp25xxfd
[   60.800000] mcp25xxfd spi1.0 can0: MCP25xxFD open
[   60.800000] mcp25xxfd spi1.0 can0: FIFO setup: TEF: 8*12 bytes = 96 bytes, TX: 8*16 bytes = 128 bytes
[   60.800000] mcp25xxfd spi1.0 can0: FIFO setup: RX-0: 32*20 bytes = 640 bytes
[   60.800000] mcp25xxfd spi1.0 can0: FIFO setup: free: 1184 bytes
[   60.800000] mcp25xxfd spi1.0 can0: Set mode: Configuration (4)
[   60.800000] mcp25xxfd spi1.0 can0: REG Con: 0x4980760
[   60.800000] mcp25xxfd spi1.0 can0: REG Con: 0x4980760
[   60.810000] mcp25xxfd spi1.0 can0: Set mode: CAN 2.0 (6)
[   60.810000] mcp25xxfd spi1.0 can0: REG Con: 0x68b0760
[   60.810000] mcp25xxfd spi1.0 can0: REG Con: 0x68b0760
[   60.810000] mcp25xxfd spi1.0 can0: REG Con: 0x68b0760
[   60.810000] mcp25xxfd spi1.0 can0: REG Con: 0x68b0760
...
[   60.860000] mcp25xxfd spi1.0 can0: REG Con: 0x68b0760
[   60.860000] mcp25xxfd spi1.0 can0: REG Con: 0x68b0760
[   60.860000] mcp25xxfd spi1.0 can0: REG Con: 0x68b0760
[   60.860000] mcp25xxfd spi1.0 can0: REG Con: 0x68b0760
[   60.860000] mcp25xxfd spi1.0 can0: REG Con: 0x68b0760
[   60.860000] mcp25xxfd spi1.0 can0: Controller failed to enter mode CAN 2.0 Mode (6) and stays in Configuration Mode (4).
[   60.870000] mcp25xxfd spi1.0 can0: Set mode: Sleep (1)
[   60.870000] mcp25xxfd spi1.0 can0: Set mode: Sleep (1)

Got a few additional words. When CAN interface configures to 500000 bitrate, there are no errors at all. But, when configure it to 125000, MCP having trouble to change mode. As i think, trouble somewhere in bitrate calculation.


root@OpenWrt:~# ip link set can0 up type can bitrate 125000 restart-ms 100 fd off
RTNETLINK answers: Operation timed out
root@OpenWrt:~# ip link set can0 up type can bitrate 500000 restart-ms 100 fd off
root@OpenWrt:~# dmesg | grep spi
[  177.390000] mcp25xxfd spi1.0 can0: FIFO setup: TEF: 8*12 bytes = 96 bytes, TX: 8*16 bytes = 128 bytes
[  177.390000] mcp25xxfd spi1.0 can0: FIFO setup: RX-0: 32*20 bytes = 640 bytes
[  177.390000] mcp25xxfd spi1.0 can0: FIFO setup: free: 1184 bytes
[  177.390000] mcp25xxfd spi1.0 can0: Set mode: Configuration (4)
[  177.390000] mcp25xxfd spi1.0 can0: REG Con: 0x4980760
[  177.390000] mcp25xxfd spi1.0 can0: REG Con: 0x4980760
[  177.400000] mcp25xxfd spi1.0 can0: Set mode: CAN 2.0 (6)
[  177.400000] mcp25xxfd spi1.0 can0: REG Con: 0x68b0760
[  177.400000] mcp25xxfd spi1.0 can0: REG Con: 0x68b0760
[  177.400000] mcp25xxfd spi1.0 can0: REG Con: 0x68b0760
...
 177.450000] mcp25xxfd spi1.0 can0: REG Con: 0x68b0760
[  177.450000] mcp25xxfd spi1.0 can0: Controller failed to enter mode CAN 2.0 Mode (6) and stays in Configuration Mode (4).
[  177.460000] mcp25xxfd spi1.0 can0: Set mode: Sleep (1)
[  177.460000] mcp25xxfd spi1.0 can0: Set mode: Sleep (1)
[  190.760000] mcp25xxfd spi1.0 can0: MCP25xxFD open
[  190.760000] mcp25xxfd spi1.0 can0: FIFO setup: TEF: 8*12 bytes = 96 bytes, TX: 8*16 bytes = 128 bytes
[  190.760000] mcp25xxfd spi1.0 can0: FIFO setup: RX-0: 32*20 bytes = 640 bytes
[  190.760000] mcp25xxfd spi1.0 can0: FIFO setup: free: 1184 bytes
[  190.760000] mcp25xxfd spi1.0 can0: Set mode: Configuration (4)
[  190.760000] mcp25xxfd spi1.0 can0: REG Con: 0x48b0760
[  190.760000] mcp25xxfd spi1.0 can0: REG Con: 0x48b0760
[  190.760000] mcp25xxfd spi1.0 can0: Set mode: CAN 2.0 (6)
[  190.760000] mcp25xxfd spi1.0 can0: REG Con: 0x68b0760
[  190.760000] mcp25xxfd spi1.0 can0: REG Con: 0x6cb0f60
[  190.760000] mcp25xxfd spi1.0 can0: REG Con: 0x6cb0f60
marckleinebudde commented 3 years ago

Hey @intx82, can you create a new issue and include which driver version you are using?

intx82 commented 3 years ago

It is very interesting, but after hardware reset issue is gone

marckleinebudde commented 3 years ago

Fine! If this happens again, please create a new issue.

intx82 commented 3 years ago

I have a little question, after seen this part of the code:

    /* Configure GPIOs:
     * - PIN0: GPIO Input
     * - PIN1: GPIO Input/RX Interrupt
     *
     * PIN1 must be Input, otherwise there is a glitch on the
     * rx-INT line. It happens between setting the PIN as output
     * (in the first byte of the SPI transfer) and configuring the
     * PIN as interrupt (in the last byte of the SPI transfer).
     */
    val = MCP25XXFD_REG_IOCON_PM0 | MCP25XXFD_REG_IOCON_TRIS1 |
        MCP25XXFD_REG_IOCON_TRIS0;

Is pull-up needed for INT/INT1 lines? Because i often have missing packets

That's all followed by logs like:

[  179.600000] mcp25xxfd spi1.0 can0: CRC read error at address 0x0034 (length=4, data=ff ff ff ff, CRC=0xffff) retrying.
[  179.800000] mcp25xxfd spi1.0 can0: CRC read error at address 0x001c (length=4, data=ff ff ff ff, CRC=0xffff) retrying.
[  214.660000] mcp25xxfd spi1.0 can0: CRC read error at address 0x001c (length=4, data=ff ff ff ff, CRC=0xffff) retrying.
[  214.870000] mcp25xxfd spi1.0 can0: CRC read error at address 0x001c (length=4, data=ff ff ff ff, CRC=0xffff) retrying.
[  215.070000] mcp25xxfd spi1.0 can0: CRC read error at address 0x001c (length=4, data=ff ff ff ff, CRC=0xffff) retrying.
[  215.260000] mcp25xxfd spi1.0 can0: CRC read error at address 0x001c (length=4, data=ff ff ff ff, CRC=0xffff) retrying.
[  215.450000] mcp25xxfd spi1.0 can0: CRC read error at address 0x001c (length=4, data=ff ff ff ff, CRC=0xffff) retrying.
...
marckleinebudde commented 3 years ago

Which driver version are you using? Does this error happen during normal operation, or during ifup/down?

intx82 commented 3 years ago

Using latest version from v5.9/mcp25xxfd-wip branch (commit: 2402aaa) And happen that on every recieved packet (read irq)

If i didn't solve this tomorrow, i will open new issue with additional info

marckleinebudde commented 3 years ago

I'm not sure if this uinc feature is stable. Better use the driver from the master branch of https://git.kernel.org/pub/scm/linux/kernel/git/netdev/net-next.git/

Note: The driver was renamed from mcp25xxfd to mcp251xfd, so if you're using the microchip,mcp25xxfd compatible in your device tree, it's microchip,mcp251xfd now.

marckleinebudde commented 3 years ago

Is pull-up needed for INT/INT1 lines? Because i often have missing packets.

Are you using the DT property microchip,rx-int-gpios:?

According to the mcp2518fd datasheet the int1 pin is actively driven in both directions.

Are you using IRQ_TYPE_LEVEL_LOW in you DT?

intx82 commented 3 years ago

Yes, almost the same string as written in bindings documents

interrupt-parent = <&gpio0>;
interrupts = <2 8>;
microchip,rx-int-gpios = <&gpio0 5 GPIO_ACTIVE_LOW>; 

I am also tried with '2' (by falling edge) in 'interrupts' parameter, effect is the same.

Here is full dts file: https://gist.github.com/intx82/b0ff6f6713f27bd2aa4dcbc27a9f943b#file-imx23-olinuxino-mcp2518-spidev

marckleinebudde commented 3 years ago

[ 179.600000] mcp25xxfd spi1.0 can0: CRC read error at address 0x0034 (length=4, data=ff ff ff ff, CRC=0xffff) retrying.

Do you get this message for each and every packet received? Reading 0xff from the bus, means the MISO line is high the whole transfer. From the timestamps and register it seems the retry works. Can you ensure that there's no mechanical/electrical problem?

marckleinebudde commented 3 years ago

interrupts = <2 8>;

better use IRQ_TYPE_LEVEL_LOW not magic numbers.

Please remove the microchip,rx-int-gpios completely and see if it fixes your problem.

marckleinebudde commented 3 years ago
                mcp251x@0 {
                    status = "okay";
                    compatible = "microchip,mcp2518fd";
                    reg = <0>;                  
                    clocks = <&mcp251x_clock>;

                    interrupt-parent = <&gpio0>;
                    interrupts = <2 8>;

                    microchip,rx-int-gpios = <&gpio0 5 GPIO_ACTIVE_LOW>; 
                    //clkdiv2;

The property clkdiv2 is not supported, can be removed.

                    spi-max-frequency = <5000000>;

5MHz is quite slow. With a 40 MHz Osc, the SPI clock can be 17MHz max and the driver will take care of this. Or do you see more CRC problem otherwise?

                    vdd-supply = <&reg_3v3>;
                    xceiver-supply = <&reg_3v3>;

No need for these dummy regulators, the are optional to the driver. You can remove them,

                };
intx82 commented 3 years ago

CLKDIV2 it is my experiments around previous trouble. I have tried to use SCLKDIV bit to divide clock by two, and then set baudrate to lower value. But the issue is gone with hardware reset, and this is fine.

About CLK, have tried to use 2,5,10mhz and every time behavior is the same.

This is remote setup, and I don't have direct access to them About IRQ_TYPE_LEVEL_LOW, yes, that should be fine, but DTC show Syntax error with any non-numeric defines here.

Now, i am going to 'clone' 'net-next.git' and response when test it.

intx82 commented 3 years ago

Logs without microchip,rx-int-gpios = <&gpio0 5 GPIO_ACTIVE_LOW>;

root@OpenWrt:~# ip link set can0 up type can bitrate 10000 restart-ms 100 fd off
root@OpenWrt:~# candump -c -c -ta can0,0:0,#FFFFFFFF
 (1602766289.011028)  can0  001   [4]  AA 55 AA 55
 (1602766289.803827)  can0  001   [4]  AA 55 AA 55
 (1602766290.324570)  can0  001   [4]  AA 55 AA 55
 (1602766290.789198)  can0  001   [4]  AA 55 AA 55
 (1602766291.235577)  can0  001   [4]  AA 55 AA 55
 (1602766291.736558)  can0  001   [4]  AA 55 AA 55
 (1602766292.237816)  can0  20000004   [8]  00 10 00 00 00 00 00 81   ERRORFRAME
^Croot@OpenWrt:~# dmesg | grep "spi"
[    0.130000] bus: 'spi': registered
[    0.130000] device class 'spi_master': registering
[    0.150000] device: '80010000.spi': device_add
[    0.150000] bus: 'platform': add device 80010000.spi
[    0.220000] device: '80034000.spi': device_add
[    0.220000] bus: 'platform': add device 80034000.spi
[    1.090000] device class 'spidev': registering
[    1.090000] bus: 'spi': add driver spidev
[    1.090000] bus: 'platform': add driver spi_gpio
[    1.090000] bus: 'platform': add driver mxs-spi
[    1.090000] bus: 'platform': driver_probe_device: matched device 80034000.spi with driver mxs-spi
[    1.090000] bus: 'platform': really_probe: probing driver mxs-spi with device 80034000.spi
[    1.090000] mxs-spi 80034000.spi: no init pinctrl state
[    1.100000] device: 'spi1': device_add
[    1.100000] mxs-spi 80034000.spi: registered master spi1
[    1.110000] spi spi1.0: setup mode 0, 8 bits/w, 15000000 Hz max --> 0
[    1.110000] device: 'spi1.0': device_add
[    1.110000] bus: 'spi': add device spi1.0
[    1.120000] mxs-spi 80034000.spi: registered child spi1.0
[    1.120000] driver: 'mxs-spi': driver_bound: bound to device '80034000.spi'
[    1.120000] bus: 'platform': really_probe: bound device 80034000.spi to driver mxs-spi
[    1.150000] bus: 'spi': add driver mcp251x
[    1.160000] bus: 'spi': add driver mcp25xxfd
[    1.160000] bus: 'spi': driver_probe_device: matched device spi1.0 with driver mcp25xxfd
[    1.160000] bus: 'spi': really_probe: probing driver mcp25xxfd with device spi1.0
[    1.160000] mcp25xxfd spi1.0: no pinctrl handle
[    1.160000] spi_master spi1: will run message pump with realtime priority
[    1.160000] mcp25xxfd spi1.0: setup mode 0, 8 bits/w, 15000000 Hz max --> 0
[    1.160000] mcp25xxfd spi1.0: can_rx_offload_init_queue: skb_queue_len_max=512
[    1.190000] mcp25xxfd spi1.0 can0: MCP2518FD rev0.0 (-RX_INT -MAB_NO_WARN +CRC_REG +CRC_RX +CRC_TX +ECC +HD c:40.00MHz m:15.00MHz r:15.00MHz e:0.00MHz) successfully initialized.
[    1.200000] driver: 'mcp25xxfd': driver_bound: bound to device 'spi1.0'
[    1.200000] bus: 'spi': really_probe: bound device spi1.0 to driver mcp25xxfd
[    1.210000] bus: 'spi': add driver enc28j60
[    1.210000] bus: 'spi': add driver encx24j600
[    1.810000] bus: 'platform': driver_probe_device: matched device 80010000.spi with driver mxs-mmc
[    1.810000] bus: 'platform': really_probe: probing driver mxs-mmc with device 80010000.spi
[    1.810000] mxs-mmc 80010000.spi: no init pinctrl state
[    1.810000] mxs-mmc 80010000.spi: 80010000.spi supply vmmc not found, using dummy regulator
[    1.820000] devices_kset: Moving 80010000.spi to end of list
[    1.820000] mxs-mmc 80010000.spi: Linked as a consumer to regulator.0
[    1.880000] mxs-mmc 80010000.spi: initialized
[    1.880000] driver: 'mxs-mmc': driver_bound: bound to device '80010000.spi'
[    1.880000] bus: 'platform': really_probe: bound device 80010000.spi to driver mxs-mmc
[    1.880000] bus: 'spi': add driver leds_spi_byte
[   84.940000] mcp25xxfd spi1.0 can0: FIFO setup: TEF: 8*12 bytes = 96 bytes, TX: 8*16 bytes = 128 bytes
[   84.940000] mcp25xxfd spi1.0 can0: FIFO setup: RX-0: 32*20 bytes = 640 bytes
[   84.940000] mcp25xxfd spi1.0 can0: FIFO setup: free: 1184 bytes
[   93.160000] mcp25xxfd spi1.0 can0: CRC read error at address 0x001c (length=4, data=ff ff ff ff, CRC=0xffff) retrying.
[   93.950000] mcp25xxfd spi1.0 can0: CRC read error at address 0x001c (length=4, data=ff ff ff ff, CRC=0xffff) retrying.
[   94.470000] mcp25xxfd spi1.0 can0: CRC read error at address 0x001c (length=4, data=ff ff ff ff, CRC=0xffff) retrying.
[   94.940000] mcp25xxfd spi1.0 can0: CRC read error at address 0x001c (length=4, data=ff ff ff ff, CRC=0xffff) retrying.
[   95.380000] mcp25xxfd spi1.0 can0: CRC read error at address 0x001c (length=4, data=ff ff ff ff, CRC=0xffff) retrying.
[   95.890000] mcp25xxfd spi1.0 can0: CRC read error at address 0x001c (length=4, data=ff ff ff ff, CRC=0xffff) retrying.
[   96.390000] mcp25xxfd spi1.0 can0: New error state: 2

What was really sent

image

intx82 commented 3 years ago

I will ask someone on remote setup to do photos, how them all connected and attach it when have them

marckleinebudde commented 3 years ago

Try removing the MCP251XFD_REG_OSC_LPMEN from mcp251xfd_chip_clock_init() to disable deep sleep mode. The question is why does the driver read 0xff from the chip. Please add a #define DEBUG in front of all includes in mcp251xfd-core.c and mcp251xfd-regmap.c. Make sure you don't have any other modifications to the driver.

marckleinebudde commented 3 years ago

Can you sync the clocks and run candump any,0:0,#FFFFFFFF -extA? Please send different data in each packet. Can you use a more standard bitrate of 250kbit or 500kbit?

intx82 commented 3 years ago

Good news, with 'net-next' driver, there are no CRC error messages. So CRC errors going from UINC feature. Bad news, rx-irq still handles not every time, But, i think, i should check connections at first.

root@OpenWrt:~# ip link set can0 up type can bitrate 250000 restart-ms 100 fd off
root@OpenWrt:~# candump -c -c -e -x -tA can0,0:0,#FFFFFFFF
 (2020-10-15 14:12:40.394999)  can0  RX - -  001   [4]  05 FF FF FF
 (2020-10-15 14:12:41.396820)  can0  RX - -  001   [4]  06 DE AD CA
 (2020-10-15 14:12:42.394708)  can0  RX - -  001   [4]  07 CA DE AD
 (2020-10-15 14:12:43.398504)  can0  RX - -  001   [4]  08 00 00 00
 (2020-10-15 14:12:44.400366)  can0  RX - -  001   [4]  09 11 22 33
 (2020-10-15 14:12:45.394137)  can0  RX - -  001   [4]  00 BA BE 00
 (2020-10-15 14:12:57.993714)  can0  RX - -  001   [4]  01 01 02 03
 (2020-10-15 14:12:58.992111)  can0  RX - -  001   [4]  02 AA 55 AA
 (2020-10-15 14:12:59.990041)  can0  RX - -  001   [4]  03 BB CC DD
^Croot@OpenWrt:~# dmesg | grep "spi"
[    0.130000] bus: 'spi': registered
[    0.130000] device class 'spi_master': registering
[    0.140000] device: '80010000.spi': device_add
[    0.140000] bus: 'platform': add device 80010000.spi
[    0.210000] device: '80034000.spi': device_add
[    0.210000] bus: 'platform': add device 80034000.spi
[    1.090000] device class 'spidev': registering
[    1.090000] bus: 'spi': add driver spidev
[    1.090000] bus: 'platform': add driver spi_gpio
[    1.090000] bus: 'platform': add driver mxs-spi
[    1.090000] bus: 'platform': driver_probe_device: matched device 80034000.spi with driver mxs-spi
[    1.090000] bus: 'platform': really_probe: probing driver mxs-spi with device 80034000.spi
[    1.090000] mxs-spi 80034000.spi: no init pinctrl state
[    1.090000] device: 'spi1': device_add
[    1.100000] mxs-spi 80034000.spi: registered master spi1
[    1.110000] spi spi1.0: setup mode 0, 8 bits/w, 15000000 Hz max --> 0
[    1.110000] device: 'spi1.0': device_add
[    1.110000] bus: 'spi': add device spi1.0
[    1.110000] mxs-spi 80034000.spi: registered child spi1.0
[    1.110000] driver: 'mxs-spi': driver_bound: bound to device '80034000.spi'
[    1.110000] bus: 'platform': really_probe: bound device 80034000.spi to driver mxs-spi
[    1.160000] bus: 'spi': add driver mcp251x
[    1.160000] bus: 'spi': add driver mcp251xfd
[    1.160000] bus: 'spi': driver_probe_device: matched device spi1.0 with driver mcp251xfd
[    1.160000] bus: 'spi': really_probe: probing driver mcp251xfd with device spi1.0
[    1.160000] mcp251xfd spi1.0: no pinctrl handle
[    1.160000] spi_master spi1: will run message pump with realtime priority
[    1.170000] mcp251xfd spi1.0: setup mode 0, 8 bits/w, 15000000 Hz max --> 0
[    1.170000] mcp251xfd spi1.0: can_rx_offload_init_queue: skb_queue_len_max=512
[    1.190000] mcp251xfd spi1.0 can0: MCP2518FD rev0.0 (+RX_INT -MAB_NO_WARN +CRC_REG +CRC_RX +CRC_TX +ECC +HD c:40.00MHz m:15.00MHz r:15.00MHz e:0.00MHz) successfully initialized.
[    1.210000] driver: 'mcp251xfd': driver_bound: bound to device 'spi1.0'
[    1.210000] bus: 'spi': really_probe: bound device spi1.0 to driver mcp251xfd
[    1.210000] bus: 'spi': add driver enc28j60
[    1.220000] bus: 'spi': add driver encx24j600
[    1.830000] bus: 'platform': driver_probe_device: matched device 80010000.spi with driver mxs-mmc
[    1.830000] bus: 'platform': really_probe: probing driver mxs-mmc with device 80010000.spi
[    1.830000] mxs-mmc 80010000.spi: no init pinctrl state
[    1.830000] mxs-mmc 80010000.spi: 80010000.spi supply vmmc not found, using dummy regulator
[    1.840000] devices_kset: Moving 80010000.spi to end of list
[    1.840000] mxs-mmc 80010000.spi: Linked as a consumer to regulator.0
[    1.900000] mxs-mmc 80010000.spi: initialized
[    1.900000] driver: 'mxs-mmc': driver_bound: bound to device '80010000.spi'
[    1.900000] bus: 'platform': really_probe: bound device 80010000.spi to driver mxs-mmc
[    1.900000] bus: 'spi': add driver leds_spi_byte
[  253.250000] mcp251xfd spi1.0 can0: FIFO setup: TEF: 8*12 bytes = 96 bytes, TX: 8*16 bytes = 128 bytes
[  253.250000] mcp251xfd spi1.0 can0: FIFO setup: RX-0: 32*20 bytes = 640 bytes
[  253.250000] mcp251xfd spi1.0 can0: FIFO setup: free: 1184 bytes
root@OpenWrt:~# dmesg | tail -n 10
[   26.990000] br-lan: port 1(eth0) entered blocking state
[   27.000000] br-lan: port 1(eth0) entered disabled state
[   27.000000] device eth0 entered promiscuous mode
[   27.210000] br-lan: port 1(eth0) entered blocking state
[   27.210000] br-lan: port 1(eth0) entered forwarding state
[   27.720000] IPv6: ADDRCONF(NETDEV_CHANGE): br-lan: link becomes ready
[  253.250000] mcp251xfd spi1.0 can0: FIFO setup: TEF: 8*12 bytes = 96 bytes, TX: 8*16 bytes = 128 bytes
[  253.250000] mcp251xfd spi1.0 can0: FIFO setup: RX-0: 32*20 bytes = 640 bytes
[  253.250000] mcp251xfd spi1.0 can0: FIFO setup: free: 1184 bytes
[  253.260000] IPv6: ADDRCONF(NETDEV_CHANGE): can0: link becomes ready
root@OpenWrt:~# cat /proc/interrupts 
           CPU0       
 16:      88871         -  28 Edge      MXS Timer Tick
 17:         20         -   0 Edge      uart-pl011
 18:       1863         -  14 Edge      mxs-dma
 19:          9         -  20 Edge      mxs-dma
 21:          6         -  15 Edge      80010000.spi
 25:          9         -   2 Edge      spi1.0
124:          0         -  26 Edge      mxs-dma
130:          0         -  53 Edge      dcp-vmi-irq
131:          0         -  54 Edge      dcp-irq
132:          0         -   2 Edge      80034000.spi
142:          0         -  27 Edge      80058000.i2c
143:          0         -  22 Edge      RTC alarm
147:          0         -  24 Edge      8006c000.serial
148:     181912         -  11 Edge      80080000.usb
Err:          0
root@OpenWrt:~# ip -det -stat link show can0
2: can0: <NOARP,UP,LOWER_UP,ECHO> mtu 16 qdisc fq_codel 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 100 
          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 
          re-started bus-errors arbit-lost error-warn error-pass bus-off
          0          0          0          0          0          0         numtxqueues 1 gso_max_size 65536 gso_max_segs 65535 
    RX: bytes  packets  errors  dropped overrun mcast   
    36         9        0       0       0       0       
    TX: bytes  packets  errors  dropped carrier collsns 
    0          0        0       0       0       0       

image

marckleinebudde commented 3 years ago

Assuming the windows is 4 seconds in the future compared to the linux...it seems the first 4 CAN frames are missing. 9 Interrupts correspond to the 9 received CAN frames:

 25:          9         -   2 Edge      spi1.0
    RX: bytes  packets  errors  dropped overrun mcast
    36         9        0       0       0       0

Can you re-create the issue and then post the file /sys/kernel/debug/regmap/spi1.0-crc/registers.

intx82 commented 3 years ago

Yes, you are right about missing packets. Let i get photo of remote setup, check all connections, and if i didn't found any suspect connection, i will open the issue, is it ok?

Register values:

root@OpenWrt:~# cat /sys/kernel/debug/regmap/spi1.0-crc/registers
000: 06cb0760
004: 008a1300
008: 000e0303
00c: 00021000
010: 0ecbb615
014: 00010000
018: 40400040
01c: 3f1a8004
020: 00000000
024: 00000000
028: 00000000
02c: 00000000
030: 00000000
034: 00000000
038: 00000004
03c: 00080009
040: 07000029
044: 00000000
048: 00000000
04c: 00000000
050: 00600080
054: 00000005
058: 00000060
05c: 07600090
060: 00000007
064: 00000060
068: 1f000029
06c: 00000900
070: 00000194
074: 00600000
078: 00000000
07c: 00000360
080: 00600000
084: 00000000
088: 00000370
08c: 00600000
090: 00000000
094: 00000380
098: 00600000
09c: 00000000
0a0: 00000390
0a4: 00600000
0a8: 00000000
0ac: 000003a0
0b0: 00600000
0b4: 00000000
0b8: 000003b0
0bc: 00600000
0c0: 00000000
0c4: 000003c0
0c8: 00600000
0cc: 00000000
0d0: 000003d0
0d4: 00600000
0d8: 00000000
0dc: 000003e0
0e0: 00600000
0e4: 00000000
0e8: 000003f0
0ec: 00600000
0f0: 00000000
0f4: 00000400
0f8: 00600000
0fc: 00000000
100: 00000410
104: 00600000
108: 00000000
10c: 00000420
110: 00600000
114: 00000000
118: 00000430
11c: 00600000
120: 00000000
124: 00000440
128: 00600000
12c: 00000000
130: 00000450
134: 00600000
138: 00000000
13c: 00000460
140: 00600000
144: 00000000
148: 00000470
14c: 00600000
150: 00000000
154: 00000480
158: 00600000
15c: 00000000
160: 00000490
164: 00600000
168: 00000000
16c: 000004a0
170: 00600000
174: 00000000
178: 000004b0
17c: 00600000
180: 00000000
184: 000004c0
188: 00600000
18c: 00000000
190: 000004d0
194: 00600000
198: 00000000
19c: 000004e0
1a0: 00600000
1a4: 00000000
1a8: 000004f0
1ac: 00600000
1b0: 00000000
1b4: 00000500
1b8: 00600000
1bc: 00000000
1c0: 00000510
1c4: 00600000
1c8: 00000000
1cc: 00000520
1d0: 00000082
1d4: 00000000
1d8: 00000000
1dc: 00000000
1e0: 00000000
1e4: 00000000
1e8: 00000000
1ec: 00000000
1f0: 00000000
1f4: 00000000
1f8: 00000000
1fc: 00000000
200: 00000000
204: 00000000
208: 00000000
20c: 00000000
210: 00000000
214: 00000000
218: 00000000
21c: 00000000
220: 00000000
224: 00000000
228: 00000000
22c: 00000000
230: 00000000
234: 00000000
238: 00000000
23c: 00000000
240: 00000000
244: 00000000
248: 00000000
24c: 00000000
250: 00000000
254: 00000000
258: 00000000
25c: 00000000
260: 00000000
264: 00000000
268: 00000000
26c: 00000000
270: 00000000
274: 00000000
278: 00000000
27c: 00000000
280: 00000000
284: 00000000
288: 00000000
28c: 00000000
290: 00000000
294: 00000000
298: 00000000
29c: 00000000
2a0: 00000000
2a4: 00000000
2a8: 00000000
2ac: 00000000
2b0: 00000000
2b4: 00000000
2b8: 00000000
2bc: 00000000
2c0: 00000000
2c4: 00000000
2c8: 00000000
2cc: 00000000
2d0: 00000000
2d4: 00000000
2d8: 00000000
2dc: 00000000
2e0: 00000000
2e4: 00000000
2e8: 00000000
2ec: 00000000
400: 00000000
404: 00000000
408: 00000000
40c: 00000000
410: 00000000
414: 00000000
418: 00000000
41c: 00000000
420: 00000000
424: 00000000
428: 00000000
42c: 00000000
430: 00000000
434: 00000000
438: 00000000
43c: 00000000
440: 00000000
444: 00000000
448: 00000000
44c: 00000000
450: 00000000
454: 00000000
458: 00000000
45c: 00000000
460: 00000000
464: 00000000
468: 00000000
46c: 00000000
470: 00000000
474: 00000000
478: 00000000
47c: 00000000
480: 00000000
484: 00000000
488: 00000000
48c: 00000000
490: 00000000
494: 00000000
498: 00000000
49c: 00000000
4a0: 00000000
4a4: 00000000
4a8: 00000000
4ac: 00000000
4b0: 00000000
4b4: 00000000
4b8: 00000000
4bc: 00000000
4c0: 00000000
4c4: 00000000
4c8: 00000000
4cc: 00000000
4d0: 00000000
4d4: 00000000
4d8: 00000000
4dc: 00000000
4e0: 00000001
4e4: 00000004
4e8: 262d055d
4ec: ffffff05
4f0: 00000000
4f4: 00000001
4f8: 00000004
4fc: 288f8072
500: caadde06
504: 00000000
508: 00000001
50c: 00000004
510: 2af17c95
514: addeca07
518: 00000000
51c: 00000001
520: 00000004
524: 2d553d4f
528: 00000008
52c: 00000000
530: 00000001
534: 00000004
538: 2fb9140e
53c: 33221109
540: 00000000
544: 00000001
548: 00000004
54c: 321832ac
550: 00beba00
554: 00000000
558: 00000001
55c: 00000004
560: 5022545c
564: 03020101
568: 00000000
56c: 00000001
570: 00000004
574: 5282ce0a
578: aa55aa02
57c: 00000000
580: 00000001
584: 00000004
588: 54e3fffc
58c: ddccbb03
590: 00000000
594: 00000000
598: 00000000
59c: 00000000
marckleinebudde commented 3 years ago

As all the discussion is here, stay here :)

marckleinebudde commented 3 years ago

What have you send prio to the above dump? what was recived?

intx82 commented 3 years ago

All that listed above only Did you find something strange?

..
98: 00000000
59c: 00000000
root@OpenWrt:~# exit
Connection to * closed.
intl@kbp-lhp-a00640:~/wrk/embd/dlab/linux-can/openwrt/build_dir/target-arm_arm926ej-s_musl_eabi/linux-mxs/linux-5.4.67/arch/arm/boot/dts$ ssh root@*
root@*'s password: 
BusyBox v1.31.1 () built-in shell (ash)
 -----------------------------------------------------
 OpenWrt SNAPSHOT, r14572-4682d4d770
 -----------------------------------------------------
root@OpenWrt:~# 
root@OpenWrt:~# ip -stat -det link show can0
2: can0: <NOARP,UP,LOWER_UP,ECHO> mtu 16 qdisc fq_codel 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 100 
          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 
          re-started bus-errors arbit-lost error-warn error-pass bus-off
          0          0          0          0          0          0         numtxqueues 1 gso_max_size 65536 gso_max_segs 65535 
    RX: bytes  packets  errors  dropped overrun mcast   
    36         9        0       0       0       0       
    TX: bytes  packets  errors  dropped carrier collsns 
    0          0        0       0       0       0       
root@OpenWrt:~# 
marckleinebudde commented 3 years ago

From the dump I see:

BDIAG0: bdiag0(0x038)=0x00000004
        DTERRCNT =   0          Data Bit Rate Transmit Error Counter
        DRERRCNT =   0          Data Bit Rate Receive Error Counter
        NTERRCNT =   0          Nominal Bit Rate Transmit Error Counter
        NRERRCNT =   4          Nominal Bit Rate Receive Error Counter

BDIAG1: bdiag1(0x03c)=0x00080009
           DLCMM                DLC Mismatch
             ESI                ESI flag of a received CAN FD message was set
         DCRCERR                Data CRC Error
        DSTUFERR                Data Bit Stuffing Error
        DFORMERR                Data Format Error
        DBIT1ERR                Data BIT1 Error
        DBIT0ERR                Data BIT0 Error
         TXBOERR                Device went to bus-off (and auto-recovered)
         NCRCERR                CRC Error
        NSTUFERR                Bit Stuffing Error
        NFORMERR   x            Format Error
         NACKERR                Transmitted message was not acknowledged
        NBIT1ERR                Bit1 Error
        NBIT0ERR                Bit0 Error
        EFMSGCNT =   9          Error Free Message Counter

It seems the controller has detected 4 broken and 9 good frames.

You can decode the dump yourself, use the mcp25xxfd-dump /sys/kernel/debug/regmap/spi1.0-crc/registers. The tool is available in my can-utils repo: https://github.com/marckleinebudde/can-utils/tree/mcp25xxfd-dump build with ./autogen.sh; configure; make

marckleinebudde commented 3 years ago

Here's the contents of the RX-RAM. The first received object was "05 ff ff ff", the last one "03 bb cc dd", which is consistent with the candump.

RX Overview:
      head (c/p) = 0x09    0x00    0x00000000
      tail (c/p) = 0x09    0x00    0x00000000

RX Object: 0x00 (0x4e0)  priv-HEAD  priv-TAIL  priv-FIFO-empty
              id = 0x00000001
           flags = 0x00000004
              ts = 0x262d055d
            data = 05 ff ff ff

RX Object: 0x01 (0x4f4)
              id = 0x00000001
           flags = 0x00000004
              ts = 0x288f8072
            data = 06 de ad ca

RX Object: 0x02 (0x508)
              id = 0x00000001
           flags = 0x00000004
              ts = 0x2af17c95
            data = 07 ca de ad

RX Object: 0x03 (0x51c)
              id = 0x00000001
           flags = 0x00000004
              ts = 0x2d553d4f
            data = 08 00 00 00

RX Object: 0x04 (0x530)
              id = 0x00000001
           flags = 0x00000004
              ts = 0x2fb9140e
            data = 09 11 22 33

RX Object: 0x05 (0x544)
              id = 0x00000001
           flags = 0x00000004
              ts = 0x321832ac
            data = 00 ba be 00

RX Object: 0x06 (0x558)
              id = 0x00000001
           flags = 0x00000004
              ts = 0x5022545c
            data = 01 01 02 03

RX Object: 0x07 (0x56c)
              id = 0x00000001
           flags = 0x00000004
              ts = 0x5282ce0a
            data = 02 aa 55 aa

RX Object: 0x08 (0x580)
              id = 0x00000001
           flags = 0x00000004
              ts = 0x54e3fffc
            data = 03 bb cc dd

RX Object: 0x09 (0x594)  chip-HEAD  chip-TAIL  chip-FIFO-empty
              id = 0x00000000
           flags = 0x00000000
              ts = 0x00000000
            data = -none-
intx82 commented 3 years ago

What a magic utility, great work :)

What i have got for today:

photo_2020-10-15_19-48-10

Later i will add DEBUG define, and write about results

root@OpenWrt:/# ip link set can0 up type can bitrate 250000 restart-ms 100 fd off
[  202.270000] IPv6: ADDRCONF(NETDEV_CHANGE): can0: link becomes ready
root@OpenWrt:/# candump -c -c -e -x -tA can0,0:0,#FFFFFFFF
/**< There we lost 6 frames from begin >*/
 (2020-10-16 08:18:14.792616)  can0  RX - -  000   [4]  AA 55 AA 55  // Frame 6 from send log below
 (2020-10-16 08:18:14.901305)  can0  RX - -  000   [4]  11 22 33 FF
 (2020-10-16 08:18:15.013369)  can0  RX - -  000   [4]  00 00 00 00
 (2020-10-16 08:18:15.119431)  can0  RX - -  000   [4]  FF FF FF FF
 (2020-10-16 08:18:15.229464)  can0  RX - -  001   [4]  00 BA BE 00
 (2020-10-16 08:18:15.337464)  can0  RX - -  001   [4]  AA BB CC DD
 (2020-10-16 08:18:15.449966)  can0  RX - -  001   [4]  EE FF 00 11
 (2020-10-16 08:18:15.555465)  can0  RX - -  001   [4]  00 01 02 03
 (2020-10-16 08:18:15.669468)  can0  RX - -  001   [4]  22 33 44 55
 (2020-10-16 08:18:15.773592)  can0  RX - -  001   [4]  00 01 02 03
 (2020-10-16 08:18:15.887563)  can0  RX - -  000   [4]  AA 55 AA 55
 (2020-10-16 08:18:15.993656)  can0  RX - -  000   [4]  11 22 33 FF
 (2020-10-16 08:18:16.103688)  can0  RX - -  000   [4]  00 00 00 00
 (2020-10-16 08:18:16.211657)  can0  RX - -  000   [4]  FF FF FF FF
 (2020-10-16 08:18:16.325691)  can0  RX - -  001   [4]  00 BA BE 00
 (2020-10-16 08:18:16.431721)  can0  RX - -  001   [4]  AA BB CC DD  // Frame 21 
/**< There we lost 16 frames, from 22 to 37 >*/
 (2020-10-16 08:18:18.294197)  can0  RX - -  000   [4]  00 00 00 00   // Frame 38
 (2020-10-16 08:18:18.399415)  can0  RX - -  000   [4]  FF FF FF FF
 (2020-10-16 08:18:18.514385)  can0  RX - -  001   [4]  00 BA BE 00
 (2020-10-16 08:18:18.622354)  can0  RX - -  001   [4]  AA BB CC DD
 (2020-10-16 08:18:18.728415)  can0  RX - -  001   [4]  EE FF 00 11
 (2020-10-16 08:18:18.839416)  can0  RX - -  001   [4]  00 01 02 03
 (2020-10-16 08:18:18.952511)  can0  RX - -  001   [4]  22 33 44 55
 (2020-10-16 08:18:19.058479)  can0  RX - -  001   [4]  00 01 02 03
 (2020-10-16 08:18:19.168572)  can0  RX - -  000   [4]  AA 55 AA 55
 (2020-10-16 08:18:19.274540)  can0  RX - -  000   [4]  11 22 33 FF
 (2020-10-16 08:18:19.388572)  can0  RX - -  000   [4]  00 00 00 00
 (2020-10-16 08:18:19.496603)  can0  RX - -  000   [4]  FF FF FF FF
 (2020-10-16 08:18:19.604634)  can0  RX - -  001   [4]  00 BA BE 00
 (2020-10-16 08:18:19.714728)  can0  RX - -  001   [4]  AA BB CC DD
 (2020-10-16 08:18:19.826697)  can0  RX - -  001   [4]  EE FF 00 11
 (2020-10-16 08:18:19.934728)  can0  RX - -  001   [4]  00 01 02 03
/**< There we also lost for 16 frames */>
 (2020-10-16 08:18:21.794063)  can0  RX - -  001   [4]  00 BA BE 00
 (2020-10-16 08:18:21.903281)  can0  RX - -  001   [4]  AA BB CC DD
 (2020-10-16 08:18:22.015312)  can0  RX - -  001   [4]  EE FF 00 11
 (2020-10-16 08:18:22.121404)  can0  RX - -  001   [4]  00 01 02 03
 (2020-10-16 08:18:22.231372)  can0  RX - -  001   [4]  22 33 44 55
 (2020-10-16 08:18:22.339496)  can0  RX - -  001   [4]  00 01 02 03
 (2020-10-16 08:18:22.453496)  can0  RX - -  000   [4]  AA 55 AA 55
 (2020-10-16 08:18:22.561464)  can0  RX - -  000   [4]  11 22 33 FF
 (2020-10-16 08:18:22.671494)  can0  RX - -  000   [4]  00 00 00 00
 (2020-10-16 08:18:22.779462)  can0  RX - -  000   [4]  FF FF FF FF
 (2020-10-16 08:18:22.889430)  can0  RX - -  001   [4]  00 BA BE 00
 (2020-10-16 08:18:22.997585)  can0  RX - -  001   [4]  AA BB CC DD
 (2020-10-16 08:18:23.103677)  can0  RX - -  001   [4]  EE FF 00 11
 (2020-10-16 08:18:23.217646)  can0  RX - -  001   [4]  00 01 02 03
 (2020-10-16 08:18:23.323737)  can0  RX - -  001   [4]  22 33 44 55
 (2020-10-16 08:18:23.435737)  can0  RX - -  001   [4]  00 01 02 03
^C
root@OpenWrt:/# ip -stat -det link show can0
2: can0: <NOARP,UP,LOWER_UP,ECHO> mtu 16 qdisc fq_codel 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 1) restart-ms 100
          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
          re-started bus-errors arbit-lost error-warn error-pass bus-off
          0          0          0          0          0          0         numtxqueues 1 gso_max_size 65536 gso_max_segs 65535
    RX: bytes  packets  errors  dropped overrun mcast
    192        48       0       0       0       0
    TX: bytes  packets  errors  dropped carrier collsns
    0          0        0       0       0       0

root@OpenWrt:/# cat /sys/kernel/debug/regmap/spi1.0-crc/registers | grep 038
038: 00000040

And what was sent:

NO    Direction  Time Scale        Frame Type      Frame Format        Frame ID    Length         Data 
0     Send     11:18:15:460     Data frame     Standard frame     00000001     4     00 ba be 00     
1     Send     11:18:15:566     Data frame     Standard frame     00000001     4     aa bb cc dd     
2     Send     11:18:15:677     Data frame     Standard frame     00000001     4     ee ff 00 11     
3     Send     11:18:15:786     Data frame     Standard frame     00000001     4     00 01 02 03     
4     Send     11:18:15:898     Data frame     Standard frame     00000001     4     22 33 44 55     
5     Send     11:18:16:005     Data frame     Standard frame     00000001     4     00 01 02 03     
6     Send     11:18:16:116     Data frame     Standard frame     00000000     4     aa 55 aa 55     
7     Send     11:18:16:221     Data frame     Standard frame     00000000     4     11 22 33 ff     
8     Send     11:18:16:336     Data frame     Standard frame     00000000     4     00 00 00 00     
9     Send     11:18:16:441     Data frame     Standard frame     00000000     4     ff ff ff ff     
10    Send     11:18:16:553     Data frame     Standard frame     00000001     4     00 ba be 00     
11    Send     11:18:16:659     Data frame     Standard frame     00000001     4     aa bb cc dd     
12    Send     11:18:16:767     Data frame     Standard frame     00000001     4     ee ff 00 11     
13    Send     11:18:16:879     Data frame     Standard frame     00000001     4     00 01 02 03     
14    Send     11:18:16:990     Data frame     Standard frame     00000001     4     22 33 44 55     
15    Send     11:18:17:097     Data frame     Standard frame     00000001     4     00 01 02 03     
16    Send     11:18:17:210     Data frame     Standard frame     00000000     4     aa 55 aa 55     
17    Send     11:18:17:317     Data frame     Standard frame     00000000     4     11 22 33 ff     
18    Send     11:18:17:430     Data frame     Standard frame     00000000     4     00 00 00 00     
19    Send     11:18:17:535     Data frame     Standard frame     00000000     4     ff ff ff ff     
20    Send     11:18:17:645     Data frame     Standard frame     00000001     4     00 ba be 00     
21    Send     11:18:17:753     Data frame     Standard frame     00000001     4     aa bb cc dd     
22    Send     11:18:17:866     Data frame     Standard frame     00000001     4     ee ff 00 11     
23    Send     11:18:17:971     Data frame     Standard frame     00000001     4     00 01 02 03     
24    Send     11:18:18:084     Data frame     Standard frame     00000001     4     22 33 44 55     
25    Send     11:18:18:190     Data frame     Standard frame     00000001     4     00 01 02 03     
26    Send     11:18:18:302     Data frame     Standard frame     00000000     4     aa 55 aa 55     
27    Send     11:18:18:409     Data frame     Standard frame     00000000     4     11 22 33 ff     
28    Send     11:18:18:519     Data frame     Standard frame     00000000     4     00 00 00 00     
29    Send     11:18:18:627     Data frame     Standard frame     00000000     4     ff ff ff ff     
30    Send     11:18:18:742     Data frame     Standard frame     00000001     4     00 ba be 00     
31    Send     11:18:18:847     Data frame     Standard frame     00000001     4     aa bb cc dd     
32    Send     11:18:18:959     Data frame     Standard frame     00000001     4     ee ff 00 11     
33    Send     11:18:19:066     Data frame     Standard frame     00000001     4     00 01 02 03     
34    Send     11:18:19:178     Data frame     Standard frame     00000001     4     22 33 44 55     
35    Send     11:18:19:284     Data frame     Standard frame     00000001     4     00 01 02 03     
36    Send     11:18:19:394     Data frame     Standard frame     00000000     4     aa 55 aa 55     
37    Send     11:18:19:506     Data frame     Standard frame     00000000     4     11 22 33 ff     
38    Send     11:18:19:617     Data frame     Standard frame     00000000     4     00 00 00 00     
39    Send     11:18:19:722     Data frame     Standard frame     00000000     4     ff ff ff ff     
40    Send     11:18:19:834     Data frame     Standard frame     00000001     4     00 ba be 00     
41    Send     11:18:19:944     Data frame     Standard frame     00000001     4     aa bb cc dd     
42    Send     11:18:20:053     Data frame     Standard frame     00000001     4     ee ff 00 11     
43    Send     11:18:20:160     Data frame     Standard frame     00000001     4     00 01 02 03     
44    Send     11:18:20:270     Data frame     Standard frame     00000001     4     22 33 44 55     
45    Send     11:18:20:377     Data frame     Standard frame     00000001     4     00 01 02 03     
46    Send     11:18:20:485     Data frame     Standard frame     00000000     4     aa 55 aa 55     
47    Send     11:18:20:598     Data frame     Standard frame     00000000     4     11 22 33 ff     
48    Send     11:18:20:709     Data frame     Standard frame     00000000     4     00 00 00 00     
49    Send     11:18:20:815     Data frame     Standard frame     00000000     4     ff ff ff ff     
50    Send     11:18:20:928     Data frame     Standard frame     00000001     4     00 ba be 00     
51    Send     11:18:21:036     Data frame     Standard frame     00000001     4     aa bb cc dd     
52    Send     11:18:21:143     Data frame     Standard frame     00000001     4     ee ff 00 11     
53    Send     11:18:21:255     Data frame     Standard frame     00000001     4     00 01 02 03     
54    Send     11:18:21:366     Data frame     Standard frame     00000001     4     22 33 44 55     
55    Send     11:18:21:472     Data frame     Standard frame     00000001     4     00 01 02 03     
56    Send     11:18:21:583     Data frame     Standard frame     00000000     4     aa 55 aa 55     
57    Send     11:18:21:689     Data frame     Standard frame     00000000     4     11 22 33 ff     
58    Send     11:18:21:802     Data frame     Standard frame     00000000     4     00 00 00 00     
59    Send     11:18:21:910     Data frame     Standard frame     00000000     4     ff ff ff ff     
60    Send     11:18:22:018     Data frame     Standard frame     00000001     4     00 ba be 00     
61    Send     11:18:22:129     Data frame     Standard frame     00000001     4     aa bb cc dd     
62    Send     11:18:22:241     Data frame     Standard frame     00000001     4     ee ff 00 11     
63    Send     11:18:22:348     Data frame     Standard frame     00000001     4     00 01 02 03     
64    Send     11:18:22:456     Data frame     Standard frame     00000001     4     22 33 44 55     
65    Send     11:18:22:565     Data frame     Standard frame     00000001     4     00 01 02 03     
66    Send     11:18:22:678     Data frame     Standard frame     00000000     4     aa 55 aa 55     
67    Send     11:18:22:785     Data frame     Standard frame     00000000     4     11 22 33 ff     
68    Send     11:18:22:894     Data frame     Standard frame     00000000     4     00 00 00 00     
69    Send     11:18:23:006     Data frame     Standard frame     00000000     4     ff ff ff ff     
70    Send     11:18:23:117     Data frame     Standard frame     00000001     4     00 ba be 00     
71    Send     11:18:23:223     Data frame     Standard frame     00000001     4     aa bb cc dd     
72    Send     11:18:23:335     Data frame     Standard frame     00000001     4     ee ff 00 11     
73    Send     11:18:23:440     Data frame     Standard frame     00000001     4     00 01 02 03     
74    Send     11:18:23:553     Data frame     Standard frame     00000001     4     22 33 44 55     
75    Send     11:18:23:658     Data frame     Standard frame     00000001     4     00 01 02 03     
76    Send     11:18:23:769     Data frame     Standard frame     00000000     4     aa 55 aa 55     
77    Send     11:18:23:877     Data frame     Standard frame     00000000     4     11 22 33 ff     
78    Send     11:18:23:991     Data frame     Standard frame     00000000     4     00 00 00 00     
79    Send     11:18:24:097     Data frame     Standard frame     00000000     4     ff ff ff ff     
80    Send     11:18:24:208     Data frame     Standard frame     00000001     4     00 ba be 00     
81    Send     11:18:24:316     Data frame     Standard frame     00000001     4     aa bb cc dd     
82    Send     11:18:24:429     Data frame     Standard frame     00000001     4     ee ff 00 11     
83    Send     11:18:24:534     Data frame     Standard frame     00000001     4     00 01 02 03     
84    Send     11:18:24:644     Data frame     Standard frame     00000001     4     22 33 44 55     
85    Send     11:18:24:753     Data frame     Standard frame     00000001     4     00 01 02 03     
86    Send     11:18:24:866     Data frame     Standard frame     00000000     4     aa 55 aa 55     
87    Send     11:18:24:974     Data frame     Standard frame     00000000     4     11 22 33 ff     
88    Send     11:18:25:084     Data frame     Standard frame     00000000     4     00 00 00 00     
89    Send     11:18:25:192     Data frame     Standard frame     00000000     4     ff ff ff ff     
90    Send     11:18:25:302     Data frame     Standard frame     00000001     4     00 ba be 00     
91    Send     11:18:25:410     Data frame     Standard frame     00000001     4     aa bb cc dd     
92    Send     11:18:25:517     Data frame     Standard frame     00000001     4     ee ff 00 11     
93    Send     11:18:25:630     Data frame     Standard frame     00000001     4     00 01 02 03     
94    Send     11:18:25:735     Data frame     Standard frame     00000001     4     22 33 44 55     
95    Send     11:18:25:849     Data frame     Standard frame     00000001     4     00 01 02 03     
96    Send     11:18:25:961     Data frame     Standard frame     00000000     4     aa 55 aa 55     
97    Send     11:18:26:065     Data frame     Standard frame     00000000     4     11 22 33 ff     
98    Send     11:18:26:178     Data frame     Standard frame     00000000     4     00 00 00 00     
99    Send     11:18:26:285     Data frame     Standard frame     00000000     4     ff ff ff ff     
100   Send     11:18:26:394     Data frame     Standard frame     00000001     4     00 ba be 00     
101   Send     11:18:26:505     Data frame     Standard frame     00000001     4     aa bb cc dd     
102   Send     11:18:26:615     Data frame     Standard frame     00000001     4     ee ff 00 11     
103   Send     11:18:26:722     Data frame     Standard frame     00000001     4     00 01 02 03     
104   Send     11:18:26:833     Data frame     Standard frame     00000001     4     22 33 44 55     
105   Send     11:18:26:940     Data frame     Standard frame     00000001     4     00 01 02 03     
106   Send     11:18:27:052     Data frame     Standard frame     00000000     4     aa 55 aa 55     
107   Send     11:18:27:159     Data frame     Standard frame     00000000     4     11 22 33 ff     
108   Send     11:18:27:269     Data frame     Standard frame     00000000     4     00 00 00 00     
109   Send     11:18:27:379     Data frame     Standard frame     00000000     4     ff ff ff ff     
110   Send     11:18:27:490     Data frame     Standard frame     00000001     4     00 ba be 00     
111   Send     11:18:27:599     Data frame     Standard frame     00000001     4     aa bb cc dd     
marckleinebudde commented 3 years ago

Hey @intx82!

As you see from the dmesg output, the mcp251xfd has a RX-FIFO with a depth of 32 CAN frames:

[  253.250000] mcp251xfd spi1.0 can0: FIFO setup: TEF: 8*12 bytes = 96 bytes, TX: 8*16 bytes = 128 bytes
[  253.250000] mcp251xfd spi1.0 can0: FIFO setup: RX-0: 32*20 bytes = 640 bytes

That means the controller can receive 32 messages back-to-back without any help from the imx23. So there is no SPI problem. Can you remove the check mark "only send once" in the windows tool and retest?

The usual mode of operation of CAN controllers is to send a CAN frame and wait for one other node on the CAN-bus to mark the frame as correctly received in the "ack" slot. See "Base frame format" in the wiki article on CAN. The frame is repeated until some node acks the frame (or the sending node leaves the bus due to too high error TX error counters). Most CAN controllers have a special mode called one-shot-mode (or similar), where the CAN frame is only tries to send once. I suspect this mode is active here.

intx82 commented 3 years ago

After re-wiring board, and change mode to 'Loopback mode' in windows tool - everything works fine. Yes, you are right, windows CAN adapter send to MCP wrong EOF part of frame, that leads to 'Form Error'.

@marckleinebudde Thank you, for your support, it was really very helpful.

marckleinebudde commented 3 years ago

Loopback mode doesn't sound correct either....

intx82 commented 3 years ago

Yes, sounds very interesting, because with changing mode to loopback, timings diagram was not changed. But it works. When i compared them, they have very little differences in level intervals between each other.

Top line is RX from ATA6561, and bottom line is TX

Normal mode (as it called it win-utillity):

image

In loopback mode, frame that handled correctly:

image

I didn't store broken frame to present it now, but part after ACK bit of the frame is totally different. If the issue is back i will store it, may be to someone it could be helpful.

marckleinebudde commented 3 years ago

For your setup you should use normal mode.

After the ACK bit, there's the ACK delimiter (1 bit) and then 7 End of Frame bits....See the wiki article I linked above.