AM5716: CAN communication issues

Tony Tang

Part Number: AM5716
Other Parts Discussed in Thread: AM5718,

RT Linux SDK9.03.06.05, Kernel 6.1.119-rt, C_CAN driver. 1Mbps, 40% Bus loading, there is interferrence on CAN Bus.

CAN interreupt priority: -67, receive thread priority: -66.

#1. After multiple times of transmit fail, will trigger:

No buffer space available

adjust buffer configuration like: ip link set can0 txqueuelen xxxx, still trigger ‘No buffer space available’ after sometimes.

Question: What is the reason of this error? how to adjust from driver to avoid it?

#2. Restart CAN bus, driver print:.

net can0: c_can_hw_raminit_wait_syscon: time out

Question: what is the reason?

#3. sometimes kernel report below error before restart and reconfiguration:

[173532.658525] net can0: c_can_hw_raminit_wait_syscon: time out
[173532.658846] c_can_platform 4ae3c000.can can0: setting BTR=4d00 BRPE=0000
[173712.429712] c_can_platform 4ae3c000.can can0: can_put_echo_skb: BUG! echo_skb 3 is occupied!

#4. What result in the CAN interrupt was disabled in below log:

[179734.977159] irq 91: nobody cared (try booting with the "irqpoll" option)
[179734.977167] CPU: 0 PID: 14827 Comm: irq/91-can0 Not tainted 6.1.119-rt45-00004-gcc4dcbbb0644-dirty #2
[179734.977177] Hardware name: Generic DRA72X (Flattened Device Tree)
[179734.977184] Function entered at [<c020bd98>] from [<c0208e6c>]
[179734.977191] Function entered at [<c0208e6c>] from [<c08f94e8>]
[179734.977197] Function entered at [<c08f94e8>] from [<c08ef8a0>]
[179734.977201] Function entered at [<c08ef8a0>] from [<c0262328>]
[179734.977206] Function entered at [<c0262328>] from [<c025f234>]
179734.977211] Function entered at [<c025f234>] from [<c0262f98>]
[179734.977214] Function entered at [<c0262f98>] from [<c025e53c>]
[179734.977218] Function entered at [<c025e53c>] from [<c020136c>]
[179734.977222] Function entered at [<c020136c>] from [<c08f9620>]
[179734.977226] Function entered at [<c08f9620>] from [<c08c6508>]
[179734.977231] Function entered at [<c08c6508>] from [<c0200c28>]
[179734.977234] Exception stack(0xc2573ee0 to 0xc2573f28)
[179734.977244] 3ee0: 0000001a 04000000 c15a0600 0b402204 c15a0600 c24db480 c2514300 c15a060c
[179734.977250] 3f00: c02600dc c15a0670 c0ea8809 c0a89148 f01fc307 c2573f30 c0263900 c025fe88
[179734.977255] 3f20: 200d0013 ffffffff
[179734.977259] Function entered at [<c0200c28>] from [<c025fe88>]
[179734.977263] Function entered at [<c025fe88>] from [<c0260158>]
[179734.977266] Function entered at [<c0260158>] from [<c025fa48>]
[179734.977270] Function entered at [<c025fa48>] from [<c0242414>]
[179734.977274] Function entered at [<c0242414>] from [<c02001e4>]
[179734.977278] Exception stack(0xc2573fb0 to 0xc2573ff8)
[179734.977283] 3fa0:                                     00000000 00000000 00000000 00000000
[179734.977290] 3fc0: 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
[179734.977295] 3fe0: 00000000 00000000 00000000 00000000 00000013 00000000
[179734.977298] handlers:
[179734.977301] [<2831285b>] 0xc025f25c threaded [<a070f4a3>] 0xc06515a8
[179734.977313] Disabling IRQ #91

4 months ago

0 Josue Zamitiz-Ayala 4 months ago

TI__Mastermind 40246 points

Hello Tony,

I will take a look at this issue but please be aware that this SDK is no longer under standard support.

Secondly, can you please share any changes if any from the base SDK default?

Best,

Josue

0 Tony Tang 4 months ago in reply to Josue Zamitiz-Ayala

TI__Mastermind 30632 points

Further debugging progress from customer:

Cccording to 'No buffer space available ' return from write(), when c_can_do_tx() detected CAN Message Object is full from CAN_INTPND register, it will result in write() triggering ENOBUFS error.

According to Kernel log: net can0: c_can_hw_raminit_wait_syscon: time out, it is because when c_can_hw_raminit_wait_syscon() reset CAN RAM from register CTRL_CORE_CONTROL_IO_2 time out over 1ms. Seems CAN RAM is not reset as intended.

It is easy to trigger this issue when there is serious noise/interference during CAN communication. Seems like Message Object in CAN RAM is not transmitted in time, or CAN RAM can't be initialized.

Hope it can help you to investigate.

0 Kevin Peng 4 months ago in reply to Josue Zamitiz-Ayala

TI__Expert 4998 points

Hi Josue,

Customer confirms that they do not have any modifications based on the default SDK CAN driver part. Please help analyze the findings Tony provided above. And if you find any relative known fix in CAN driver from SDK9 to the latest SDK, please also share to us.

Thanks,

Kevin

0 Josue Zamitiz-Ayala 4 months ago in reply to Kevin Peng

TI__Mastermind 40246 points

Tony, Kevin,

Has this been recreated on a TI EVM?

Please share the procedure for recreation.

-Josue

0 Kevin Peng 4 months ago in reply to Josue Zamitiz-Ayala

TI__Expert 4998 points

Hi Josue,

It will take some time & efforts to try creating it on EVM, as customer already mass production. Before that, seeing from the error log Tony provided, could you provide some general advice that in which scenario this might happen, and what we could have a try in parallel please?

Thanks,

Kevin

0 Josue Zamitiz-Ayala 4 months ago in reply to Kevin Peng

TI__Mastermind 40246 points

Kevin, Tony,

I will see if I can try some experiments on my side. It seems like this is a race condition that needs hands on testing in order to make decisions on what to do.

I should also make the disclaimer that I am not a CAN expert and this is my first time in looking at this CAN_C driver, therefore I wont have any immediate fixes. I need time to analyze and understand the error(s) since this looks like a cascading situation where it is hard to tell the root cause.

I did find the following patch that could be related to this race condition on a newer version of the kernel - Thanks to Kevin Peng for the pointer: https://lore.kernel.org/all/20250520114332.8961-3-axfo@kvaser.com/

Customer could try to backport this and see if it helps.

Best,

Josue

0 Tony Tang 4 months ago in reply to Josue Zamitiz-Ayala

TI__Mastermind 30632 points

Josue,

Seems the driver in the URL are not for c_can_main driver, it is specific for Kvaser PCI interface CANFD controller.

--- a/drivers/net/can/kvaser_pciefd.c
+++ b/drivers/net/can/kvaser_pciefd.c

0 Josue Zamitiz-Ayala 4 months ago in reply to Tony Tang

TI__Mastermind 40246 points

Hello Team,

I did not find any relevant patches for this upstream other than for error reporting. It seems like this is a race condition created between c_can_start_xmit() and c_can_do_tx() that can lead to "echo_skb occupied" errors and dropped packets under high load conditions.

I was able to recreate some of these issues locally so I will be trying some fixes this next week. Keep in mind tomorrow is a holiday in US so I will not be available until Monday.

Fullscreen can_stress_test_20260402_182434.log Download

[0;34m[18:24:44][0m Current CAN Interface Status:
[0;34m[18:24:44][0m Interrupt Statistics:
[0;34m[18:25:13][0m ==========================================
[0;34m[18:25:13][0m RUNNING ALL TESTS SEQUENTIALLY
[0;34m[18:25:13][0m ==========================================
[0;34m[18:25:13][0m ==========================================
[0;34m[18:25:13][0m TEST 1: TX Buffer Exhaustion (ENOBUFS)
[0;34m[18:25:13][0m ==========================================
[0;34m[18:25:13][0m Setting up CAN interface: main_dcan1
[0;32m[SUCCESS][0m CAN interface main_dcan1 ready at 1000000 bps
[0;34m[18:25:14][0m Launching 8 concurrent zero-gap transmitters...
[0;34m[18:25:14][0m This should fill all 16 TX message objects immediately
write: No buffer space available
write: No buffer space available
write: No buffer space available
write: No buffer space available
write: No buffer space available
write: No buffer space available
write: No buffer space available
write: No buffer space available
[0;34m[18:25:14][0m Transmitters running... waiting 5 seconds
[0;34m[18:25:19][0m Cleaning up background processes...
[0;34m[18:25:20][0m Checking for errors after: TX Buffer Exhaustion Test
[1;33m[WARNING][0m Found kernel messages:
  [ 1987.278839] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 1987.286590] IPv6: ADDRCONF(NETDEV_CHANGE): main_dcan1: link becomes ready
  [ 7026.660491] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
[0;34m[18:25:20][0m Interface statistics:
5: main_dcan1: <NOARP,ECHO> mtu 16 qdisc pfifo_fast state DOWN mode DEFAULT group default qlen 10
    link/can  promiscuity 0 minmtu 0 maxmtu 0 
    can <LOOPBACK> state STOPPED (berr-counter tx 0 rx 0) restart-ms 0 
	  bitrate 1000000 sample-point 0.750
	  tq 50 prop-seg 7 phase-seg1 7 phase-seg2 5 sjw 1 brp 1
	  c_can: tseg1 2..16 tseg2 1..8 sjw 1..4 brp 1..1024 brp_inc 1
	  clock 20000000 
	  re-started bus-errors arbit-lost error-warn error-pass bus-off
	  0          0          0          0          0          0         numtxqueues 1 numrxqueues 1 gso_max_size 65536 gso_max_segs 65535 parentbus platform parentdev 4ae3c000.can 
    RX:  bytes packets errors dropped  missed   mcast           
          3784     473      0       0       0       0 
    TX:  bytes packets errors dropped carrier collsns           
          3784     473      0       0       0       0 

=== ERROR SUMMARY ===
echo_skb occupied errors: 0
0
RAMINIT timeout errors: 0
0
ENOBUFS errors: 0
0
IRQ 'nobody cared' errors: 0
0
====================

[0;34m[18:25:22][0m ==========================================
[0;34m[18:25:23][0m TEST 2: RAMINIT Timeout (Rapid Restart)
[0;34m[18:25:23][0m ==========================================
[0;34m[18:25:23][0m Performing 20 rapid restart cycles...
  Cycle 1/20... done
  Cycle 2/20... done
  Cycle 3/20... done
  Cycle 4/20... done
  Cycle 5/20... done
  Cycle 6/20... done
  Cycle 7/20... done
  Cycle 8/20... done
  Cycle 9/20... done
  Cycle 10/20... done
  Cycle 11/20... done
  Cycle 12/20... done
  Cycle 13/20... done
  Cycle 14/20... done
  Cycle 15/20... done
  Cycle 16/20... done
  Cycle 17/20... done
  Cycle 18/20... done
  Cycle 19/20... done
  Cycle 20/20... done
[0;34m[18:25:28][0m Rapid restart cycles complete
[0;34m[18:25:28][0m RAMINIT errors during test: 0
[0;34m[18:25:28][0m Checking for errors after: RAMINIT Timeout Test
[1;33m[WARNING][0m Found kernel messages:
  [ 7035.898773] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 7036.183227] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 7036.464752] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 7036.744812] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 7037.027679] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 7037.306793] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 7037.587371] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 7037.869079] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 7038.152832] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 7038.434020] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 7038.716400] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 7038.997955] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 7039.279296] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 7039.560943] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 7039.845031] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 7040.128784] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 7040.412567] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 7040.691406] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 7040.972778] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 7041.254058] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
[0;34m[18:25:29][0m Interface statistics:
5: main_dcan1: <NOARP,ECHO> mtu 16 qdisc pfifo_fast state DOWN mode DEFAULT group default qlen 10
    link/can  promiscuity 0 minmtu 0 maxmtu 0 
    can <LOOPBACK> state STOPPED (berr-counter tx 0 rx 0) restart-ms 0 
	  bitrate 1000000 sample-point 0.750
	  tq 50 prop-seg 7 phase-seg1 7 phase-seg2 5 sjw 1 brp 1
	  c_can: tseg1 2..16 tseg2 1..8 sjw 1..4 brp 1..1024 brp_inc 1
	  clock 20000000 
	  re-started bus-errors arbit-lost error-warn error-pass bus-off
	  0          0          0          0          0          0         numtxqueues 1 numrxqueues 1 gso_max_size 65536 gso_max_segs 65535 parentbus platform parentdev 4ae3c000.can 
    RX:  bytes packets errors dropped  missed   mcast           
         11760    1470      0       0       0       0 
    TX:  bytes packets errors dropped carrier collsns           
         11760    1470      0       0       0       0 

=== ERROR SUMMARY ===
echo_skb occupied errors: 0
0
RAMINIT timeout errors: 0
0
ENOBUFS errors: 0
0
IRQ 'nobody cared' errors: 0
0
====================

[0;34m[18:25:31][0m ==========================================
[0;34m[18:25:31][0m TEST 3: Echo SKB Race Condition
[0;34m[18:25:31][0m ==========================================
[0;34m[18:25:31][0m Setting up CAN interface: main_dcan1
[0;32m[SUCCESS][0m CAN interface main_dcan1 ready at 1000000 bps
[0;34m[18:25:32][0m Launching 20 waves of concurrent transmitters...
[0;34m[18:25:32][0m This creates race between can_put_echo_skb() and can_get_echo_skb()
  Wave 1/20... done
  Wave 2/20... done
  Wave 3/20... done
  Wave 4/20... done
  Wave 5/20... done
  Wave 6/20... done
  Wave 7/20... done
  Wave 8/20... done
  Wave 9/20... done
  Wave 10/20... done
  Wave 11/20... done
  Wave 12/20... done
  Wave 13/20... done
  Wave 14/20... done
  Wave 15/20... done
  Wave 16/20... done
  Wave 17/20... done
  Wave 18/20... done
  Wave 19/20... done
  Wave 20/20... done
[0;34m[18:25:35][0m Race condition test complete
[0;34m[18:25:35][0m Checking for errors after: Echo SKB Race Condition Test
[1;33m[WARNING][0m Found kernel messages:
  [ 7039.279296] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 7039.560943] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 7039.845031] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 7040.128784] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 7040.412567] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 7040.691406] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 7040.972778] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 7041.254058] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 7044.270446] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 7047.396209] c_can_platform 4ae3c000.can main_dcan1: can_put_echo_skb: BUG! echo_skb 7 is occupied!
  [ 7047.396514] c_can_platform 4ae3c000.can main_dcan1: can_put_echo_skb: BUG! echo_skb 10 is occupied!
  [ 7047.396606] c_can_platform 4ae3c000.can main_dcan1: can_put_echo_skb: BUG! echo_skb 11 is occupied!
  [ 7047.396728] c_can_platform 4ae3c000.can main_dcan1: can_put_echo_skb: BUG! echo_skb 12 is occupied!
  [ 7047.396850] c_can_platform 4ae3c000.can main_dcan1: can_put_echo_skb: BUG! echo_skb 13 is occupied!
  [ 7047.396942] c_can_platform 4ae3c000.can main_dcan1: can_put_echo_skb: BUG! echo_skb 14 is occupied!
  [ 7047.397064] c_can_platform 4ae3c000.can main_dcan1: can_put_echo_skb: BUG! echo_skb 15 is occupied!
  [ 7047.397155] c_can_platform 4ae3c000.can main_dcan1: can_put_echo_skb: BUG! echo_skb 16 is occupied!
  [ 7047.397277] c_can_platform 4ae3c000.can main_dcan1: can_put_echo_skb: BUG! echo_skb 17 is occupied!
  [ 7047.397399] c_can_platform 4ae3c000.can main_dcan1: can_put_echo_skb: BUG! echo_skb 18 is occupied!
  [ 7047.397491] c_can_platform 4ae3c000.can main_dcan1: can_put_echo_skb: BUG! echo_skb 19 is occupied!
[0;34m[18:25:36][0m Interface statistics:
5: main_dcan1: <NOARP,UP,LOWER_UP,ECHO> mtu 16 qdisc pfifo_fast state UP mode DEFAULT group default qlen 10
    link/can  promiscuity 0 minmtu 0 maxmtu 0 
    can <LOOPBACK> state ERROR-ACTIVE (berr-counter tx 0 rx 0) restart-ms 0 
	  bitrate 1000000 sample-point 0.750
	  tq 50 prop-seg 7 phase-seg1 7 phase-seg2 5 sjw 1 brp 1
	  c_can: tseg1 2..16 tseg2 1..8 sjw 1..4 brp 1..1024 brp_inc 1
	  clock 20000000 
	  re-started bus-errors arbit-lost error-warn error-pass bus-off
	  0          0          0          0          0          0         numtxqueues 1 numrxqueues 1 gso_max_size 65536 gso_max_segs 65535 parentbus platform parentdev 4ae3c000.can 
    RX:  bytes packets errors dropped  missed   mcast           
         39048    4893      0       0       0       0 
    TX:  bytes packets errors dropped carrier collsns           
         39064    4883      0       0       0       0 

=== ERROR SUMMARY ===
echo_skb occupied errors: 11
RAMINIT timeout errors: 0
0
ENOBUFS errors: 0
0
IRQ 'nobody cared' errors: 0
0
====================

[0;34m[18:25:38][0m ==========================================
[0;34m[18:25:38][0m TEST 4: Sustained High-Rate TX Load
[0;34m[18:25:38][0m ==========================================
[0;34m[18:25:38][0m Setting up CAN interface: main_dcan1
[0;32m[SUCCESS][0m CAN interface main_dcan1 ready at 1000000 bps
[0;34m[18:25:39][0m Launching 6 sustained transmitters at maximum rate...
[0;34m[18:25:39][0m Transmitters running... monitoring for 10 seconds
[0;34m[18:25:49][0m IRQ count during test: 0
[0;34m[18:25:49][0m Cleaning up background processes...
[0;34m[18:25:50][0m Checking for errors after: Sustained Load Test
[1;33m[WARNING][0m Found kernel messages:
  [ 7039.560943] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 7039.845031] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 7040.128784] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 7040.412567] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 7040.691406] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 7040.972778] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 7041.254058] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 7044.270446] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 7047.396209] c_can_platform 4ae3c000.can main_dcan1: can_put_echo_skb: BUG! echo_skb 7 is occupied!
  [ 7047.396514] c_can_platform 4ae3c000.can main_dcan1: can_put_echo_skb: BUG! echo_skb 10 is occupied!
  [ 7047.396606] c_can_platform 4ae3c000.can main_dcan1: can_put_echo_skb: BUG! echo_skb 11 is occupied!
  [ 7047.396728] c_can_platform 4ae3c000.can main_dcan1: can_put_echo_skb: BUG! echo_skb 12 is occupied!
  [ 7047.396850] c_can_platform 4ae3c000.can main_dcan1: can_put_echo_skb: BUG! echo_skb 13 is occupied!
  [ 7047.396942] c_can_platform 4ae3c000.can main_dcan1: can_put_echo_skb: BUG! echo_skb 14 is occupied!
  [ 7047.397064] c_can_platform 4ae3c000.can main_dcan1: can_put_echo_skb: BUG! echo_skb 15 is occupied!
  [ 7047.397155] c_can_platform 4ae3c000.can main_dcan1: can_put_echo_skb: BUG! echo_skb 16 is occupied!
  [ 7047.397277] c_can_platform 4ae3c000.can main_dcan1: can_put_echo_skb: BUG! echo_skb 17 is occupied!
  [ 7047.397399] c_can_platform 4ae3c000.can main_dcan1: can_put_echo_skb: BUG! echo_skb 18 is occupied!
  [ 7047.397491] c_can_platform 4ae3c000.can main_dcan1: can_put_echo_skb: BUG! echo_skb 19 is occupied!
  [ 7051.353637] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
[0;34m[18:25:50][0m Interface statistics:
5: main_dcan1: <NOARP,ECHO> mtu 16 qdisc pfifo_fast state DOWN mode DEFAULT group default qlen 10
    link/can  promiscuity 0 minmtu 0 maxmtu 0 
    can <LOOPBACK> state STOPPED (berr-counter tx 0 rx 0) restart-ms 0 
	  bitrate 1000000 sample-point 0.750
	  tq 50 prop-seg 7 phase-seg1 7 phase-seg2 5 sjw 1 brp 1
	  c_can: tseg1 2..16 tseg2 1..8 sjw 1..4 brp 1..1024 brp_inc 1
	  clock 20000000 
	  re-started bus-errors arbit-lost error-warn error-pass bus-off
	  0          0          0          0          0          0         numtxqueues 1 numrxqueues 1 gso_max_size 65536 gso_max_segs 65535 parentbus platform parentdev 4ae3c000.can 
    RX:  bytes packets errors dropped  missed   mcast           
         39864    4995      0       0       0       0 
    TX:  bytes packets errors dropped carrier collsns           
         39880    4985      0      21       0       0 

=== ERROR SUMMARY ===
echo_skb occupied errors: 11
RAMINIT timeout errors: 0
0
ENOBUFS errors: 0
0
IRQ 'nobody cared' errors: 0
0
====================

[0;34m[18:25:52][0m ==========================================
[0;34m[18:25:52][0m TEST 5: IRQ Handler Stress Test
[0;34m[18:25:52][0m ==========================================
[0;34m[18:25:52][0m Setting up CAN interface: main_dcan1
[0;32m[SUCCESS][0m CAN interface main_dcan1 ready at 1000000 bps
[0;34m[18:25:53][0m Starting IRQ monitoring...
[0;34m[18:25:53][0m Launching extreme burst load...
[0;34m[18:26:02][0m IRQ count: 7717 interrupts processed
[0;34m[18:26:02][0m Checking for errors after: IRQ Handler Stress Test
[1;33m[WARNING][0m Found kernel messages:
  [ 7039.845031] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 7040.128784] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 7040.412567] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 7040.691406] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 7040.972778] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 7041.254058] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 7044.270446] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 7047.396209] c_can_platform 4ae3c000.can main_dcan1: can_put_echo_skb: BUG! echo_skb 7 is occupied!
  [ 7047.396514] c_can_platform 4ae3c000.can main_dcan1: can_put_echo_skb: BUG! echo_skb 10 is occupied!
  [ 7047.396606] c_can_platform 4ae3c000.can main_dcan1: can_put_echo_skb: BUG! echo_skb 11 is occupied!
  [ 7047.396728] c_can_platform 4ae3c000.can main_dcan1: can_put_echo_skb: BUG! echo_skb 12 is occupied!
  [ 7047.396850] c_can_platform 4ae3c000.can main_dcan1: can_put_echo_skb: BUG! echo_skb 13 is occupied!
  [ 7047.396942] c_can_platform 4ae3c000.can main_dcan1: can_put_echo_skb: BUG! echo_skb 14 is occupied!
  [ 7047.397064] c_can_platform 4ae3c000.can main_dcan1: can_put_echo_skb: BUG! echo_skb 15 is occupied!
  [ 7047.397155] c_can_platform 4ae3c000.can main_dcan1: can_put_echo_skb: BUG! echo_skb 16 is occupied!
  [ 7047.397277] c_can_platform 4ae3c000.can main_dcan1: can_put_echo_skb: BUG! echo_skb 17 is occupied!
  [ 7047.397399] c_can_platform 4ae3c000.can main_dcan1: can_put_echo_skb: BUG! echo_skb 18 is occupied!
  [ 7047.397491] c_can_platform 4ae3c000.can main_dcan1: can_put_echo_skb: BUG! echo_skb 19 is occupied!
  [ 7051.353637] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 7065.828308] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
[0;34m[18:26:02][0m Interface statistics:
5: main_dcan1: <NOARP,UP,LOWER_UP,ECHO> mtu 16 qdisc pfifo_fast state UP mode DEFAULT group default qlen 10
    link/can  promiscuity 0 minmtu 0 maxmtu 0 
    can <LOOPBACK> state ERROR-ACTIVE (berr-counter tx 0 rx 0) restart-ms 0 
	  bitrate 1000000 sample-point 0.750
	  tq 50 prop-seg 7 phase-seg1 7 phase-seg2 5 sjw 1 brp 1
	  c_can: tseg1 2..16 tseg2 1..8 sjw 1..4 brp 1..1024 brp_inc 1
	  clock 20000000 
	  re-started bus-errors arbit-lost error-warn error-pass bus-off
	  0          0          0          0          0          0         numtxqueues 1 numrxqueues 1 gso_max_size 65536 gso_max_segs 65535 parentbus platform parentdev 4ae3c000.can 
    RX:  bytes packets errors dropped  missed   mcast           
        101600   12712      0       0       0       0 
    TX:  bytes packets errors dropped carrier collsns           
        101616   12702      0      21       0       0 

=== ERROR SUMMARY ===
echo_skb occupied errors: 11
RAMINIT timeout errors: 0
0
ENOBUFS errors: 0
0
IRQ 'nobody cared' errors: 0
0
====================

[0;34m[18:26:04][0m ==========================================
[0;34m[18:26:04][0m TEST 6: Combined Stress Test (All Issues)
[0;34m[18:26:04][0m ==========================================
[0;34m[18:26:04][0m Running combined stress test...
[0;34m[18:26:04][0m Phase 1: High-rate TX...
[0;34m[18:26:04][0m Setting up CAN interface: main_dcan1
[0;32m[SUCCESS][0m CAN interface main_dcan1 ready at 1000000 bps
[0;34m[18:26:08][0m Phase 2: Rapid restart cycles...
[0;34m[18:26:09][0m Phase 3: Concurrent TX waves...
[0;34m[18:26:09][0m Setting up CAN interface: main_dcan1
[0;32m[SUCCESS][0m CAN interface main_dcan1 ready at 1000000 bps
[0;34m[18:26:12][0m Combined stress test complete
[0;34m[18:26:12][0m Checking for errors after: Combined Stress Test
[1;33m[WARNING][0m Found kernel messages:
  [ 7047.396942] c_can_platform 4ae3c000.can main_dcan1: can_put_echo_skb: BUG! echo_skb 14 is occupied!
  [ 7047.397064] c_can_platform 4ae3c000.can main_dcan1: can_put_echo_skb: BUG! echo_skb 15 is occupied!
  [ 7047.397155] c_can_platform 4ae3c000.can main_dcan1: can_put_echo_skb: BUG! echo_skb 16 is occupied!
  [ 7047.397277] c_can_platform 4ae3c000.can main_dcan1: can_put_echo_skb: BUG! echo_skb 17 is occupied!
  [ 7047.397399] c_can_platform 4ae3c000.can main_dcan1: can_put_echo_skb: BUG! echo_skb 18 is occupied!
  [ 7047.397491] c_can_platform 4ae3c000.can main_dcan1: can_put_echo_skb: BUG! echo_skb 19 is occupied!
  [ 7051.353637] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 7065.828308] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 7077.794677] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 7081.448883] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 7081.549652] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 7081.650695] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 7081.752746] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 7081.853881] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 7081.954864] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 7082.054901] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 7082.156188] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 7082.266723] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 7082.368255] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 7082.700653] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
[0;34m[18:26:12][0m Interface statistics:
5: main_dcan1: <NOARP,UP,LOWER_UP,ECHO> mtu 16 qdisc pfifo_fast state UP mode DEFAULT group default qlen 10
    link/can  promiscuity 0 minmtu 0 maxmtu 0 
    can <LOOPBACK> state ERROR-ACTIVE (berr-counter tx 0 rx 0) restart-ms 0 
	  bitrate 1000000 sample-point 0.750
	  tq 50 prop-seg 7 phase-seg1 7 phase-seg2 5 sjw 1 brp 1
	  c_can: tseg1 2..16 tseg2 1..8 sjw 1..4 brp 1..1024 brp_inc 1
	  clock 20000000 
	  re-started bus-errors arbit-lost error-warn error-pass bus-off
	  0          0          0          0          0          0         numtxqueues 1 numrxqueues 1 gso_max_size 65536 gso_max_segs 65535 parentbus platform parentdev 4ae3c000.can 
    RX:  bytes packets errors dropped  missed   mcast           
        114845   15009      0       0       0       0 
    TX:  bytes packets errors dropped carrier collsns           
        114861   14999      0      21       0       0 

=== ERROR SUMMARY ===
echo_skb occupied errors: 11
RAMINIT timeout errors: 0
0
ENOBUFS errors: 0
0
IRQ 'nobody cared' errors: 0
0
====================

[0;34m[18:26:12][0m ==========================================
[0;34m[18:26:12][0m ALL TESTS COMPLETE
[0;34m[18:26:12][0m ==========================================
[0;34m[18:26:12][0m Full log saved to: /tmp/can_stress_test_20260402_182434.log
=== FINAL ERROR SUMMARY ===
Total echo_skb errors: 11
Total RAMINIT timeouts: 0
0
Total ENOBUFS errors: 0
0
Total IRQ errors: 0
0
=========================
[0;34m[18:27:44][0m Cleaning up background processes...
[0;34m[18:27:45][0m Exiting...

I need to do some more follow up and testing.

-Josue

0 Kevin Peng 4 months ago in reply to Josue Zamitiz-Ayala

TI__Expert 4998 points

Hi Josue,

Hope you have a good holiday. May I know how did you reproduce the issues? Any updates please?

Thanks,

Kevin

0 Josue Zamitiz-Ayala 4 months ago in reply to Kevin Peng

TI__Mastermind 40246 points

Hi Kevin,

I've had to focus on other issues but I can give you some update later this week. I was able to reproduce some of the issues using the internal loopback mode on the can module in the AM5718 IDK and using for loops to simulate high load situations.

With some help, I created the following script: /cfs-file/__key/communityserver-discussions-components-files/791/can_5F00_stress_5F00_test.sh

Please handle customer expectation since this SDK is no longer supported so my help will be limited as time permits. I am still trying to understand how to address this on my side.

Secondly, this is not a TI driver so it is subject to our SDK open source disclaimer.

See software-dl.ti.com/.../Overview_Technical_Support.html

-Josue

0 Josue Zamitiz-Ayala 4 months ago in reply to Josue Zamitiz-Ayala

TI__Mastermind 40246 points

Hello Kevin,

I am still working on this issue.

As an intermediary step, can you ask the customer to run the stress test sh and share the output?

best,

-Josue

0 Josue Zamitiz-Ayala 4 months ago in reply to Josue Zamitiz-Ayala

TI__Mastermind 40246 points

Kevin,

Since I am unable to recreate some of the errors the customer is experiencing, I am not sure how helpful this will be:

Here is a patch to help decrease some of the echo_skb race condition I found. Perhaps this will help.

https://e2e.ti.com/cfs-file/__key/communityserver-discussions-components-files/791/echo_5F00_skb_5F00_race.patch

The results of the CAN test might help too. Can you confirm with customer that they have done any verification of CAN bus termination, ground/signal integrity issues? Shielded cables?

-Josue

0 Kevin Peng 3 months ago in reply to Josue Zamitiz-Ayala

TI__Expert 4998 points

Hi Josue,

Customer has two identical AM5716 devices directly connected to CAN, and they modified the stress test script to adapt to the device, running run_all_tests in a loop. The comparison results of the patch performance are as follows, and there seems to be no change. The probability of reproducing the IRQ "nobody cared" issue is also very low, and it is related to USB plug/unplug actions. Their USB is configured as a virtual network interface.

The stress test results of about one hour before applying the patch are as follows:

can0: <NOARP,ECHO> mtu 16 qdisc pfifo_fast state DOWN mode DEFAULT group default qlen 10
    link/can  promiscuity 0 
    can <LOOPBACK> state STOPPED (berr-counter tx 0 rx 0) restart-ms 0 
    bitrate 1000000 sample-point 0.750 
    tq 50 prop-seg 7 phase-seg1 7 phase-seg2 5 sjw 1
    c_can: tseg1 2..16 tseg2 1..8 sjw 1..4 brp 1..1024 brp-inc 1
    clock 20000000
    re-started bus-errors arbit-lost error-warn error-pass bus-off
    0          0          0          0          0          0         
    RX: bytes  packets  errors  dropped overrun mcast   
    8091519    1049799  0       0       0       0      
    TX: bytes  packets  errors  dropped carrier collsns 
    8091560    1049785  0       141     0       0      

=== ERROR SUMMARY ===
echo_skb occupied errors: 16
RAMINIT timeout errors: 445
ENOBUFS errors: 0
0
IRQ 'nobody cared' errors: 0
0

After applying the patch and running the stress test for approximately one hour, the results are as follows: the "write: No buffer space available" (i.e., ENOBUFS) issue still occurs extensively; some echo_skb statistics were lost because dmesg was full.

can0: <NOARP,ECHO> mtu 16 qdisc pfifo_fast state DOWN mode DEFAULT group default qlen 10
    link/can  promiscuity 0
    can <LOOPBACK> state STOPPED (berr-counter tx 0 rx 0) restart-ms 0
          bitrate 1000000 sample-point 0.750
          tq 50 prop-seg 7 phase-seg1 7 phase-seg2 5 sjw 1
          c_can: tseg1 2..16 tseg2 1..8 sjw 1..4 brp 1..1024 brp-inc 1
          clock 20000000
          re-started bus-errors arbit-lost error-warn error-pass bus-off
          0          0          0          0          0          0
    RX: bytes  packets  errors  dropped overrun mcast
    6904864    895169   0       0       0       0
    TX: bytes  packets  errors  dropped carrier collsns
    6904887    895169   0       93      0       0

=== ERROR SUMMARY ===
echo_skb occupied errors: 2
RAMINIT timeout errors: 505
ENOBUFS errors: 0
0
IRQ 'nobody cared' errors: 0
0
====================

Furthermore, during the testing phase, it was discovered that applying patches may cause the additional following kernel crash issues, which directly lead to system hangs. There are two main situations:

Situation 1 (higher trigger probability):

[10376.779465] net can0: c_can_hw_raminit_wait_syscon: time out
[10819.879945] BUG: scheduling while atomic: cangen/3099/0x00000002
[10819.886508] 8<--- cut here ---
[10819.886511] Unable to handle kernel paging request at virtual address b6e5e898
[10819.886515] [b6e5e898] *pgd=81774003, *pmd=816c6003, *pte=00000000
[10819.886526] Internal error: Oops: 80000207 [#1] PREEMPT_RT ARM
[10819.886532] Modules linked in:
[10819.886535] CPU: 0 PID: 3099 Comm: cangen Tainted: G        W          6.1.119-rt45+ #9
[10819.886542] Hardware name: Generic DRA72X (Flattened Device Tree)
[10819.886545] PC is at 0xb6e5e898
[10819.886548] LR is at 0x00010fa7
[10819.886550] pc : [<b6e5e898>]    lr : [<00010fa7>]    psr: 600d0010
[10819.886555] sp : bea8eab8  ip : b6e5e898  fp : 00000003
[10819.886558] r10: 00024100  r9 : 00000001  r8 : 000007b4
[10819.886562] r7 : 00000010  r6 : 00024100  r5 : 00000000  r4 : 00000000
[10819.886566] r3 : 00000001  r2 : 00000000  r1 : 00000001  r0 : 00012fc8
[10819.886570] Flags: nZCv  IRQs on  FIQs on  Mode USER_32  ISA ARM  Segment user
[10819.886578] Control: 30c5387d  Table: 824826c0  DAC: fffffffd
[10819.886581] Register r0 information: non-paged memory
[10819.886588] Register r1 information: non-paged memory
[10819.886593] Register r2 information: NULL pointer
[10819.886597] Register r3 information: non-paged memory
[10819.886602] Register r4 information: NULL pointer
[10819.886606] Register r5 information: NULL pointer
[10819.886610] Register r6 information: non-paged memory
[10819.886615] Register r7 information: zero-size pointer
[10819.886619] Register r8 information: non-paged memory
[10819.886623] Register r9 information: non-paged memory
[10819.886627] Register r10 information: non-paged memory
[10819.886632] Register r11 information: non-paged memory
[10819.886636] Register r12 information: non-paged memory
[10819.886641] Process cangen (pid: 3099, stack limit = 0x2afaea98)
[10819.886647] Stack: (0xbea8eab8 to 0xbea90000)
[10819.886652] eaa0:                                                       00000000 ffffffff
[10819.888001] ffe0: ???????? ???????? ???????? ???????? ???????? ???????? ???????? ????????
[10819.888007] Code: bad PC value
[10821.458129] ---[ end trace 0000000000000000 ]---
[10821.458134] Kernel panic - not syncing: Fatal exception in interrupt

Situation 2 (Supplemented with function addresses):

[ 2377.191241] net can0: c_can_hw_raminit_wait_syscon: time out
[ 2377.739391] net can0: c_can_hw_raminit_wait_syscon: time out
[ 2380.394076] net can0: c_can_hw_raminit_wait_syscon: time out
[ 2383.441967] BUG: scheduling while atomic: cangen/853/0x000000
[ 2383.441967] BUG: scheduling while atomic: cangen/853/0x00000002
[ 2383.441980] Modules linked in:
[ 2383.441987] CPU: 0 PID: 853 Comm: cangen Not tainted 6.1.119-rt45+ #9
[ 2383.441996] Hardware name: Generic DRA72X (Flattened Device Tree)
[ 2383.442006] Function entered at [<c020bdf8>] from [<c0208ed4>] # at unwind_backtrace
[ 2383.442012] Function entered at [<c0208ed4>] from [<c08fd258>] # at show_stack
[ 2383.442018] Function entered at [<c08fd258>] from [<c024826c>] # at dump_stack_lvl
[ 2383.442023] Function entered at [<c024826c>] from [<c08fe6c8>] # at __schedule_bug, core.c
[ 2383.442027] Function entered at [<c08fe6c8>] from [<c08fed9c>] # at __schedule, core.c
[ 2383.442031] Function entered at [<c08fed9c>] from [<c0904e54>] # at schedule_rtlock
[ 2383.442035] Function entered at [<c0904e54>] from [<c090599c>] # at rtlock_slowlock_locked, spinlock_rt.c
[ 2383.442038] Function entered at [<c090599c>] from [<c030237c>] # at rt_spin_lock
[ 2383.442043] Function entered at [<c030237c>] from [<c0302f94>] # at ___slab_alloc, slub.c
[ 2383.442047] Function entered at [<c0302f94>] from [<c0781554>] # at kmem_cache_alloc
[ 2383.442052] Function entered at [<c0781554>] from [<c064ed78>] # at skb_clone
[ 2383.442057] Function entered at [<c064ed78>] from [<c065407c>] # at can_put_echo_skb
[ 2383.442060] Function entered at [<c065407c>] from [<c0798450>] # at c_can_start_xmit, c_can_main.c
[ 2383.442065] Function entered at [<c0798450>] from [<c07d4de8>] # at dev_hard_start_xmit
[ 2383.442069] Function entered at [<c07d4de8>] from [<c079887c>] # at sch_direct_xmit
[ 2383.442073] Function entered at [<c079887c>] from [<c08975d8>] # at __dev_queue_xmit
[ 2383.442078] Function entered at [<c08975d8>] from [<c0899574>] # at can_send
[ 2383.442081] Function entered at [<c0899574>] from [<c077369c>] # at raw_sendmsg
[ 2383.442086] Function entered at [<c077369c>] from [<c030df8c>] # at sock_write_iter
[ 2383.442090] Function entered at [<c030df8c>] from [<c030e10c>] # at vfs_write
[ 2383.442093] Function entered at [<c030e10c>] from [<c0200140>] # at ksys_write
[ 2383.442096] Exception stack(0xc1765fa8 to 0xc1765ff0)
[ 2383.442104] 5fa0:                   00000000 00000000 00000003 00024100 00000010 00000000
[ 2383.442110] 5fc0: 00000000 00000000 00024100 00000004 00000022 00000001 00024100 00000003
[ 2383.442115] 5fe0: 0000006c bea37ab0 00010d87 b6ee222c
[ 2383.445130] ------------[ cut here ]------------
[ 2383.445134] WARNING: CPU: 0 PID: 853 at kernel/softirq.c:210 0xc0228f00
[ 2383.445144] Modules linked in:
[ 2383.445150] CPU: 0 PID: 853 Comm: cangen Tainted: G        W          6.1.119-rt45+ #9
[ 2383.445158] Hardware name: Generic DRA72X (Flattened Device Tree)
[ 2383.445162] Function entered at [<c020bdf8>] from [<c0208ed4>] # at unwind_backtrace
[ 2383.445166] Function entered at [<c0208ed4>] from [<c08fd258>] # at show_stack
[ 2383.445170] Function entered at [<c08fd258>] from [<c0225814>] # at dump_stack_lvl
[ 2383.445174] Function entered at [<c0225814>] from [<c0225a00>] # at __warn
[ 2383.445178] Function entered at [<c0225a00>] from [<c0228f00>] # at warn_slowpath_fmt
[ 2383.445182] Function entered at [<c0228f00>] from [<c0798a30>] # at __local_bh_enable_ip
[ 2383.445185] Function entered at [<c0798a30>] from [<c08975d8>] # at __dev_queue_xmit
[ 2383.445189] Function entered at [<c08975d8>] from [<c0899574>] # at can_send
[ 2383.445192] Function entered at [<c0899574>] from [<c077369c>] # at raw_sendmsg
[ 2383.445196] Function entered at [<c077369c>] from [<c030df8c>] # at sock_write_iter
[ 2383.445199] Function entered at [<c030df8c>] from [<c030e10c>] # at vfs_write
[ 2383.445203] Function entered at [<c030e10c>] from [<c0200140>] # at ksys_write
[ 2383.445205] Exception stack(0xc1765fa8 to 0xc1765ff0)
[ 2383.445212] 5fa0:                   00000000 00000000 00000003 00024100 00000010 00000000
[ 2383.445218] 5fc0: 00000000 00000000 00024100 00000004 00000022 00000001 00024100 00000003
[ 2383.445222] 5fe0: 0000006c bea37ab0 00010d87 b6ee222c
[ 2383.445225] ---[ end trace 0000000000000000 ]---
[ 2383.445259] ------------[ cut here ]------------
[ 2383.445263] WARNING: CPU: 0 PID: 853 at kernel/softirq.c:148 0xc0228cb4
[ 2383.445271] Modules linked in:
[ 2383.445277] CPU: 0 PID: 853 Comm: cangen Tainted: G        W          6.1.119-rt45+ #9
[ 2383.445283] Hardware name: Generic DRA72X (Flattened Device Tree)
[ 2383.445287] Function entered at [<c020bdf8>] from [<c0208ed4>]
[ 2383.445291] Function entered at [<c0208ed4>] from [<c08fd258>]
[ 2383.445295] Function entered at [<c08fd258>] from [<c0225814>]
[ 2383.445298] Function entered at [<c0225814>] from [<c0225a00>]
[ 2383.445301] Function entered at [<c0225a00>] from [<c0228cb4>] # at warn_slowpath_fmt
[ 2383.445305] Function entered at [<c0228cb4>] from [<c07985a0>] # at __local_bh_disable_ip
[ 2383.445308] Function entered at [<c07985a0>] from [<c08975d8>]
[ 2383.445312] Function entered at [<c08975d8>] from [<c0899574>]
[ 2383.445315] Function entered at [<c0899574>] from [<c077369c>]
[ 2383.445318] Function entered at [<c077369c>] from [<c030df8c>]
[ 2383.445322] Function entered at [<c030df8c>] from [<c030e10c>]
[ 2383.445325] Function entered at [<c030e10c>] from [<c0200140>]
[ 2383.445328] Exception stack(0xc1765fa8 to 0xc1765ff0)
[ 2383.445334] 5fa0:                   00000000 00000000 00000003 00024100 00000010 00000000
[ 2383.445339] 5fc0: 00000000 00000000 00024100 00000004 00000021 00000001 00024100 00000003
[ 2383.445343] 5fe0: 0000006c bea37ab0 00010d87 b6ee222c
[ 2383.445346] ---[ end trace 0000000000000000 ]---
[ 2383.445669] 8<--- cut here ---
[ 2383.445672] Unable to handle kernel paging request at virtual address b6e8bac0
[ 2383.445677] [b6e8bac0] *pgd=824ab003, *pmd=8303f003, *pte=00000000
[ 2383.445688] Internal error: Oops: 80000207 [#1] PREEMPT_RT ARM
[ 2383.445693] Modules linked in:
[ 2383.445697] CPU: 0 PID: 853 Comm: cangen Tainted: G        W          6.1.119-rt45+ #9
[ 2383.445704] Hardware name: Generic DRA72X (Flattened Device Tree)
[ 2383.445707] PC is at 0xb6e8bac0
[ 2383.445710] LR is at 0xb6e4f7c8
[ 2383.445712] pc : [<b6e8bac0>]    lr : [<b6e4f7c8>]    psr: 800d0010
[ 2383.445717] sp : bea37bb0  ip : 00000000  fp : b6f60000
[ 2383.445720] r10: b6f63128  r9 : 00000000  r8 : 00000001
[ 2383.445724] r7 : 00000000  r6 : 00000000  r5 : b6f5e6d8  r4 : b6f5e6d8
[ 2383.445728] r3 : b6e8bac0  r2 : b6f5e6d4  r1 : 00000000  r0 : 000240e4
[ 2383.445732] Flags: Nzcv  IRQs on  FIQs on  Mode USER_32  ISA ARM  Segment user
[ 2383.445740] Control: 30c5387d  Table: 823a3080  DAC: fffffffd
[ 2383.445743] Register r0 information: non-paged memory
[ 2383.445750] Register r1 information: NULL pointer
[ 2383.445754] Register r2 information: non-paged memory
[ 2383.445759] Register r3 information: non-paged memory
[ 2383.445763] Register r4 information: non-paged memory
[ 2383.445767] Register r5 information: non-paged memory
[ 2383.445771] Register r6 information: NULL pointer
[ 2383.445775] Register r7 information: NULL pointer
[ 2383.445779] Register r8 information: non-paged memory
[ 2383.445783] Register r9 information: NULL pointer
[ 2383.445787] Register r10 information: non-paged memory
[ 2383.445792] Register r11 information: non-paged memory
[ 2383.445796] Register r12 information: NULL pointer
[ 2383.445800] Process cangen (pid: 853, stack limit = 0x271c41f1)
[ 2383.445807] Stack: (0xbea37bb0 to 0xbea38000)
[ 2383.445813] 7ba0:                                     b6f63128 00000000 b6f604fc 00000001
[ 2383.446003] Code: bad PC value
[ 2383.446008] ---[ end trace 0000000000000000 ]---
[ 2383.446012] Kernel panic - not syncing: Fatal exception in interrupt
02
[ 2384.367308] ---[ end Kernel panic - not syncing: Fatal exception in interrupt ]---

Could you help analyze based on these information, thanks.

Thanks,

Kevin

0 Josue Zamitiz-Ayala 3 months ago in reply to Kevin Peng

TI__Mastermind 40246 points

Hello Kevin,

I will take a look and try to respond by end of week.

Josue Zamitiz-Ayala said:
Can you confirm with customer that they have done any verification of CAN bus termination, ground/signal integrity issues? Shielded cables?

Can you follow up on this question?

-Josue

0 Kevin Peng 3 months ago in reply to Josue Zamitiz-Ayala

TI__Expert 4998 points

Hi Josue,

The CAN port during pressure testing was directly connected using an RJ45 Ethernet cable, with CANH, CANL, and GND all properly connected. Since this was conducted in an office environment, no shielding was applied, but significant interference may occur when actually deployed at the end customer site. PCAN packet capture was performed for 1 hour, with the stress test script showing a bus load peak of approximately 12%, and no error frames were observed.

Is there anything else you would like customer to test?

Thanks,

Kevin

0 Josue Zamitiz-Ayala 3 months ago in reply to Kevin Peng

TI__Mastermind 40246 points

Is there still no reproduction on TI boards?

-Josue

0 Tony Tang 3 months ago in reply to Josue Zamitiz-Ayala

TI__Mastermind 30632 points

Hi Josue,

Customer have not EVM/IDK.

#1. From the log you shared. during test 1, it reported write: No buffer space available, but ENOBUFS errors count is 0, are they irrelevant?

#2. “Customer has two identical AM5716 devices directly connected to CAN”, Does it need 120ohm termination for two CAN node connected directly? Do you have two IDK to test with?

#3. What is your test result with echo_skb_race.patch

#4. Customer tested with SDK6.03 over 80minutes on the same test environment, no error reported.

[01:20:09] Interface statistics:
2: can0: <NOARP,ECHO> mtu 16 qdisc pfifo_fast state DOWN mode DEFAULT group default qlen 10
    link/can  promiscuity 0
    can <LOOPBACK> state STOPPED (berr-counter tx 0 rx 0) restart-ms 0
          bitrate 1000000 sample-point 0.750
          tq 50 prop-seg 7 phase-seg1 7 phase-seg2 5 sjw 1
          c_can: tseg1 2..16 tseg2 1..8 sjw 1..4 brp 1..1024 brp-inc 1
          clock 20000000
          re-started bus-errors arbit-lost error-warn error-pass bus-off
          0          0          0          0          0          0
    RX: bytes  packets  errors  dropped overrun mcast
    5702444    734096   0       0       0       0
    TX: bytes  packets  errors  dropped carrier collsns
    5702444    734096   0       0       0       0

=== ERROR SUMMARY ===
echo_skb occupied errors: 0
0
RAMINIT timeout errors: 0
0
ENOBUFS errors: 0
0
IRQ 'nobody cared' errors: 0
0
====================

0 Josue Zamitiz-Ayala 3 months ago in reply to Tony Tang

TI__Mastermind 40246 points

Hi Tony,

#4 Very interesting detail testing with SDK 6.03. You did not specify but I am assuming this was done with RT-Linux SDK correct?

6.03 baseline for testing might be the best way to go.

#1 - Sort of expected. The stress test is purposefully sending more messages than could be taken care of so these prints are expected. The driver eventually catches up so that's why ENOBUFS is 0. so yes, not very relevant.

#2 - Yes, I believe this is part of the specification:

I do have two IDK. But I am not sure that an equivalent test can be made since we don't have the same boards.

#3 I had a 50% reduction in echo_skb errors

I will update you on what testing I can get to this week on Friday.

-Josue

0 Kevin Peng 3 months ago in reply to Josue Zamitiz-Ayala

TI__Expert 4998 points

Hi Josue,

Let me share the full background to stay on the same page here.

Customer was developing on SDK6.3 before, they have met a PRU ethernet problem on SDK6.3. And at that time, we followed your suggestion, upgrading the SDK from SDK6.3 RT-Linux to SDK9.3 RT-Linux to finally solve this issue. That's why customer cannot go back to develop SDK6.3 anymore.

AM57-LINUX-RT-SDK: AM5716 prueth driver cause linux system crash.

After migrating to SDK9.3, customer also meet a new USB problem which is specifically related to SDK9.3, with you & Siddharth support, we finally solve the issue with the patch summarized in the below thread.

AM5716: Plugging or unplugging USB device affects real-time performance

Now, back to current topic, the end customer previously do not have CAN based requirement, but now they have to use CAN due to new application requirements. The corresponding actual phenomenon has been discussed at the beginning of this thread. To narrow down the issue, let's focus on the stress test script itself:

Based on your provided stress test script, customer did the following minor modifications mainly to adjust the location of the CAN interrupt in /proc/interrupts and shortening the sleep time to improve testing efficiency.

diff --git a/can_stress_test.sh b/can_stress_test.sh
index 2f69080..1e22e13 100644
--- a/can_stress_test.sh
+++ b/can_stress_test.sh
@@ -4,15 +4,15 @@
 # Tests for Issues: ENOBUFS, RAMINIT timeout, echo_skb race, IRQ problems
 #
 # Usage: ./can_stress_test.sh [interface]
-# Example: ./can_stress_test.sh main_dcan1
+# Example: ./can_stress_test.sh can0
 #
 
 set -e
 
 # Configuration
-CAN_IFACE="${1:-main_dcan1}"
+CAN_IFACE="${1:-can0}"
 BITRATE=1000000
-LOG_FILE="/tmp/can_stress_test_$(date +%Y%m%d_%H%M%S).log"
+LOG_FILE="/home/root/can/log/can_stress_test_$(date +%Y%m%d_%H%M%S).log"
 
 # Colors for output
 RED='\033[0;31m'
@@ -61,7 +61,7 @@ check_errors() {
     log "Checking for errors after: $test_name"
 
     # Get current dmesg
-    local errors=$(dmesg | tail -50 | grep -iE "can|echo_skb|raminit|irq.*154|ENOBUFS|nobody cared|time out|occupied" | tail -20)
+    local errors=$(dmesg | tail -50 | grep -iE "can|echo_skb|raminit|irq.*91|ENOBUFS|nobody cared|time out|occupied" | tail -20)
 
     if [ -n "$errors" ]; then
         log_warning "Found kernel messages:"
@@ -201,9 +201,9 @@ test_sustained_load() {
     log "Transmitters running... monitoring for 10 seconds"
 
     # Monitor interrupt count
-    local irq_start=$(cat /proc/interrupts | grep 154 | awk '{print $2}')
+    local irq_start=$(cat /proc/interrupts | grep "91:" | awk '{print $2}')
     sleep 10
-    local irq_end=$(cat /proc/interrupts | grep 154 | awk '{print $2}')
+    local irq_end=$(cat /proc/interrupts | grep "91:" | awk '{print $2}')
     local irq_count=$((irq_end - irq_start))
 
     log "IRQ count during test: $irq_count"
@@ -223,7 +223,7 @@ test_irq_stress() {
     log "Starting IRQ monitoring..."
 
     # Get initial IRQ count
-    local irq_before=$(cat /proc/interrupts | grep 154 | awk '{print $2}')
+    local irq_before=$(cat /proc/interrupts | grep "91:" | awk '{print $2}')
 
     log "Launching extreme burst load..."
 
@@ -237,7 +237,7 @@ test_irq_stress() {
     done
 
     # Get final IRQ count
-    local irq_after=$(cat /proc/interrupts | grep 154 | awk '{print $2}')
+    local irq_after=$(cat /proc/interrupts | grep "91:" | awk '{print $2}')
     local irq_delta=$((irq_after - irq_before))
 
     log "IRQ count: $irq_delta interrupts processed"
@@ -312,15 +312,15 @@ run_all_tests() {
     log "=========================================="
 
     test_tx_buffer_exhaustion
-    sleep 2
+    sleep 0.2
     test_raminit_timeout
-    sleep 2
+    sleep 0.2
     test_echo_skb_race
-    sleep 2
+    sleep 0.2
     test_sustained_load
-    sleep 2
+    sleep 0.2
     test_irq_stress
-    sleep 2
+    sleep 0.2
     test_combined_stress
 
     log "=========================================="
@@ -344,13 +344,13 @@ show_status() {
     ip -s -d link show "$CAN_IFACE"
     echo ""
     log "Interrupt Statistics:"
-    cat /proc/interrupts | grep -E "CPU|154"
+    cat /proc/interrupts | grep -E "CPU|91:"
 }
 
 show_dmesg_errors() {
     echo ""
     log "Recent CAN-related kernel messages:"
-    dmesg | tail -50 | grep -iE "can|echo_skb|raminit|irq.*154|ENOBUFS|nobody cared|time out|occupied" || echo "No errors found"
+    dmesg | tail -50 | grep -iE "can|echo_skb|raminit|irq.*91|ENOBUFS|nobody cared|time out|occupied" || echo "No errors found"
 }
 
 # Trap Ctrl+C
@@ -375,8 +375,9 @@ done
 # Interactive mode if no arguments
 if [ $# -lt 2 ]; then
     while true; do
-        show_menu
-        read -p "Select test (0-9): " choice
+        # show_menu
+        # read -p "Select test (0-9): " choice
+        choice=7
         echo ""
 
         case $choice in
@@ -398,7 +399,7 @@ if [ $# -lt 2 ]; then
         esac
 
         echo ""
-        read -p "Press Enter to continue..."
+        # read -p "Press Enter to continue..."
     done
 fi

Double confirm with customer about their HW setup, customer has two identical AM5716 devices directly connected to CAN, the two directly connected devices both have 120-ohm resistors enabled. Furthermore, in the test script, customer did not modify the loopback on mode shown below, which means although customer connects two AM5716 devices, the result will be very similar as your HW setup of only using 1 AM57 board.

Now let's go through the stress script test result step by step:

Your Test Result Under SDK9.3 Without Patch on EVM

[0;34m[18:24:44][0m Current CAN Interface Status:
[0;34m[18:24:44][0m Interrupt Statistics:
[0;34m[18:25:13][0m ==========================================
[0;34m[18:25:13][0m RUNNING ALL TESTS SEQUENTIALLY
[0;34m[18:25:13][0m ==========================================
[0;34m[18:25:13][0m ==========================================
[0;34m[18:25:13][0m TEST 1: TX Buffer Exhaustion (ENOBUFS)
[0;34m[18:25:13][0m ==========================================
[0;34m[18:25:13][0m Setting up CAN interface: main_dcan1
[0;32m[SUCCESS][0m CAN interface main_dcan1 ready at 1000000 bps
[0;34m[18:25:14][0m Launching 8 concurrent zero-gap transmitters...
[0;34m[18:25:14][0m This should fill all 16 TX message objects immediately
write: No buffer space available
write: No buffer space available
write: No buffer space available
write: No buffer space available
write: No buffer space available
write: No buffer space available
write: No buffer space available
write: No buffer space available
[0;34m[18:25:14][0m Transmitters running... waiting 5 seconds
[0;34m[18:25:19][0m Cleaning up background processes...
[0;34m[18:25:20][0m Checking for errors after: TX Buffer Exhaustion Test
[1;33m[WARNING][0m Found kernel messages:
  [ 1987.278839] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 1987.286590] IPv6: ADDRCONF(NETDEV_CHANGE): main_dcan1: link becomes ready
  [ 7026.660491] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
[0;34m[18:25:20][0m Interface statistics:
5: main_dcan1: <NOARP,ECHO> mtu 16 qdisc pfifo_fast state DOWN mode DEFAULT group default qlen 10
    link/can  promiscuity 0 minmtu 0 maxmtu 0 
    can <LOOPBACK> state STOPPED (berr-counter tx 0 rx 0) restart-ms 0 
	  bitrate 1000000 sample-point 0.750
	  tq 50 prop-seg 7 phase-seg1 7 phase-seg2 5 sjw 1 brp 1
	  c_can: tseg1 2..16 tseg2 1..8 sjw 1..4 brp 1..1024 brp_inc 1
	  clock 20000000 
	  re-started bus-errors arbit-lost error-warn error-pass bus-off
	  0          0          0          0          0          0         numtxqueues 1 numrxqueues 1 gso_max_size 65536 gso_max_segs 65535 parentbus platform parentdev 4ae3c000.can 
    RX:  bytes packets errors dropped  missed   mcast           
          3784     473      0       0       0       0 
    TX:  bytes packets errors dropped carrier collsns           
          3784     473      0       0       0       0 

=== ERROR SUMMARY ===
echo_skb occupied errors: 0
0
RAMINIT timeout errors: 0
0
ENOBUFS errors: 0
0
IRQ 'nobody cared' errors: 0
0
====================

[0;34m[18:25:22][0m ==========================================
[0;34m[18:25:23][0m TEST 2: RAMINIT Timeout (Rapid Restart)
[0;34m[18:25:23][0m ==========================================
[0;34m[18:25:23][0m Performing 20 rapid restart cycles...
  Cycle 1/20... done
  Cycle 2/20... done
  Cycle 3/20... done
  Cycle 4/20... done
  Cycle 5/20... done
  Cycle 6/20... done
  Cycle 7/20... done
  Cycle 8/20... done
  Cycle 9/20... done
  Cycle 10/20... done
  Cycle 11/20... done
  Cycle 12/20... done
  Cycle 13/20... done
  Cycle 14/20... done
  Cycle 15/20... done
  Cycle 16/20... done
  Cycle 17/20... done
  Cycle 18/20... done
  Cycle 19/20... done
  Cycle 20/20... done
[0;34m[18:25:28][0m Rapid restart cycles complete
[0;34m[18:25:28][0m RAMINIT errors during test: 0
[0;34m[18:25:28][0m Checking for errors after: RAMINIT Timeout Test
[1;33m[WARNING][0m Found kernel messages:
  [ 7035.898773] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 7036.183227] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 7036.464752] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 7036.744812] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 7037.027679] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 7037.306793] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 7037.587371] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 7037.869079] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 7038.152832] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 7038.434020] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 7038.716400] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 7038.997955] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 7039.279296] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 7039.560943] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 7039.845031] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 7040.128784] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 7040.412567] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 7040.691406] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 7040.972778] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 7041.254058] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
[0;34m[18:25:29][0m Interface statistics:
5: main_dcan1: <NOARP,ECHO> mtu 16 qdisc pfifo_fast state DOWN mode DEFAULT group default qlen 10
    link/can  promiscuity 0 minmtu 0 maxmtu 0 
    can <LOOPBACK> state STOPPED (berr-counter tx 0 rx 0) restart-ms 0 
	  bitrate 1000000 sample-point 0.750
	  tq 50 prop-seg 7 phase-seg1 7 phase-seg2 5 sjw 1 brp 1
	  c_can: tseg1 2..16 tseg2 1..8 sjw 1..4 brp 1..1024 brp_inc 1
	  clock 20000000 
	  re-started bus-errors arbit-lost error-warn error-pass bus-off
	  0          0          0          0          0          0         numtxqueues 1 numrxqueues 1 gso_max_size 65536 gso_max_segs 65535 parentbus platform parentdev 4ae3c000.can 
    RX:  bytes packets errors dropped  missed   mcast           
         11760    1470      0       0       0       0 
    TX:  bytes packets errors dropped carrier collsns           
         11760    1470      0       0       0       0 

=== ERROR SUMMARY ===
echo_skb occupied errors: 0
0
RAMINIT timeout errors: 0
0
ENOBUFS errors: 0
0
IRQ 'nobody cared' errors: 0
0
====================

[0;34m[18:25:31][0m ==========================================
[0;34m[18:25:31][0m TEST 3: Echo SKB Race Condition
[0;34m[18:25:31][0m ==========================================
[0;34m[18:25:31][0m Setting up CAN interface: main_dcan1
[0;32m[SUCCESS][0m CAN interface main_dcan1 ready at 1000000 bps
[0;34m[18:25:32][0m Launching 20 waves of concurrent transmitters...
[0;34m[18:25:32][0m This creates race between can_put_echo_skb() and can_get_echo_skb()
  Wave 1/20... done
  Wave 2/20... done
  Wave 3/20... done
  Wave 4/20... done
  Wave 5/20... done
  Wave 6/20... done
  Wave 7/20... done
  Wave 8/20... done
  Wave 9/20... done
  Wave 10/20... done
  Wave 11/20... done
  Wave 12/20... done
  Wave 13/20... done
  Wave 14/20... done
  Wave 15/20... done
  Wave 16/20... done
  Wave 17/20... done
  Wave 18/20... done
  Wave 19/20... done
  Wave 20/20... done
[0;34m[18:25:35][0m Race condition test complete
[0;34m[18:25:35][0m Checking for errors after: Echo SKB Race Condition Test
[1;33m[WARNING][0m Found kernel messages:
  [ 7039.279296] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 7039.560943] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 7039.845031] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 7040.128784] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 7040.412567] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 7040.691406] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 7040.972778] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 7041.254058] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 7044.270446] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 7047.396209] c_can_platform 4ae3c000.can main_dcan1: can_put_echo_skb: BUG! echo_skb 7 is occupied!
  [ 7047.396514] c_can_platform 4ae3c000.can main_dcan1: can_put_echo_skb: BUG! echo_skb 10 is occupied!
  [ 7047.396606] c_can_platform 4ae3c000.can main_dcan1: can_put_echo_skb: BUG! echo_skb 11 is occupied!
  [ 7047.396728] c_can_platform 4ae3c000.can main_dcan1: can_put_echo_skb: BUG! echo_skb 12 is occupied!
  [ 7047.396850] c_can_platform 4ae3c000.can main_dcan1: can_put_echo_skb: BUG! echo_skb 13 is occupied!
  [ 7047.396942] c_can_platform 4ae3c000.can main_dcan1: can_put_echo_skb: BUG! echo_skb 14 is occupied!
  [ 7047.397064] c_can_platform 4ae3c000.can main_dcan1: can_put_echo_skb: BUG! echo_skb 15 is occupied!
  [ 7047.397155] c_can_platform 4ae3c000.can main_dcan1: can_put_echo_skb: BUG! echo_skb 16 is occupied!
  [ 7047.397277] c_can_platform 4ae3c000.can main_dcan1: can_put_echo_skb: BUG! echo_skb 17 is occupied!
  [ 7047.397399] c_can_platform 4ae3c000.can main_dcan1: can_put_echo_skb: BUG! echo_skb 18 is occupied!
  [ 7047.397491] c_can_platform 4ae3c000.can main_dcan1: can_put_echo_skb: BUG! echo_skb 19 is occupied!
[0;34m[18:25:36][0m Interface statistics:
5: main_dcan1: <NOARP,UP,LOWER_UP,ECHO> mtu 16 qdisc pfifo_fast state UP mode DEFAULT group default qlen 10
    link/can  promiscuity 0 minmtu 0 maxmtu 0 
    can <LOOPBACK> state ERROR-ACTIVE (berr-counter tx 0 rx 0) restart-ms 0 
	  bitrate 1000000 sample-point 0.750
	  tq 50 prop-seg 7 phase-seg1 7 phase-seg2 5 sjw 1 brp 1
	  c_can: tseg1 2..16 tseg2 1..8 sjw 1..4 brp 1..1024 brp_inc 1
	  clock 20000000 
	  re-started bus-errors arbit-lost error-warn error-pass bus-off
	  0          0          0          0          0          0         numtxqueues 1 numrxqueues 1 gso_max_size 65536 gso_max_segs 65535 parentbus platform parentdev 4ae3c000.can 
    RX:  bytes packets errors dropped  missed   mcast           
         39048    4893      0       0       0       0 
    TX:  bytes packets errors dropped carrier collsns           
         39064    4883      0       0       0       0 

=== ERROR SUMMARY ===
echo_skb occupied errors: 11
RAMINIT timeout errors: 0
0
ENOBUFS errors: 0
0
IRQ 'nobody cared' errors: 0
0
====================

[0;34m[18:25:38][0m ==========================================
[0;34m[18:25:38][0m TEST 4: Sustained High-Rate TX Load
[0;34m[18:25:38][0m ==========================================
[0;34m[18:25:38][0m Setting up CAN interface: main_dcan1
[0;32m[SUCCESS][0m CAN interface main_dcan1 ready at 1000000 bps
[0;34m[18:25:39][0m Launching 6 sustained transmitters at maximum rate...
[0;34m[18:25:39][0m Transmitters running... monitoring for 10 seconds
[0;34m[18:25:49][0m IRQ count during test: 0
[0;34m[18:25:49][0m Cleaning up background processes...
[0;34m[18:25:50][0m Checking for errors after: Sustained Load Test
[1;33m[WARNING][0m Found kernel messages:
  [ 7039.560943] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 7039.845031] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 7040.128784] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 7040.412567] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 7040.691406] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 7040.972778] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 7041.254058] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 7044.270446] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 7047.396209] c_can_platform 4ae3c000.can main_dcan1: can_put_echo_skb: BUG! echo_skb 7 is occupied!
  [ 7047.396514] c_can_platform 4ae3c000.can main_dcan1: can_put_echo_skb: BUG! echo_skb 10 is occupied!
  [ 7047.396606] c_can_platform 4ae3c000.can main_dcan1: can_put_echo_skb: BUG! echo_skb 11 is occupied!
  [ 7047.396728] c_can_platform 4ae3c000.can main_dcan1: can_put_echo_skb: BUG! echo_skb 12 is occupied!
  [ 7047.396850] c_can_platform 4ae3c000.can main_dcan1: can_put_echo_skb: BUG! echo_skb 13 is occupied!
  [ 7047.396942] c_can_platform 4ae3c000.can main_dcan1: can_put_echo_skb: BUG! echo_skb 14 is occupied!
  [ 7047.397064] c_can_platform 4ae3c000.can main_dcan1: can_put_echo_skb: BUG! echo_skb 15 is occupied!
  [ 7047.397155] c_can_platform 4ae3c000.can main_dcan1: can_put_echo_skb: BUG! echo_skb 16 is occupied!
  [ 7047.397277] c_can_platform 4ae3c000.can main_dcan1: can_put_echo_skb: BUG! echo_skb 17 is occupied!
  [ 7047.397399] c_can_platform 4ae3c000.can main_dcan1: can_put_echo_skb: BUG! echo_skb 18 is occupied!
  [ 7047.397491] c_can_platform 4ae3c000.can main_dcan1: can_put_echo_skb: BUG! echo_skb 19 is occupied!
  [ 7051.353637] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
[0;34m[18:25:50][0m Interface statistics:
5: main_dcan1: <NOARP,ECHO> mtu 16 qdisc pfifo_fast state DOWN mode DEFAULT group default qlen 10
    link/can  promiscuity 0 minmtu 0 maxmtu 0 
    can <LOOPBACK> state STOPPED (berr-counter tx 0 rx 0) restart-ms 0 
	  bitrate 1000000 sample-point 0.750
	  tq 50 prop-seg 7 phase-seg1 7 phase-seg2 5 sjw 1 brp 1
	  c_can: tseg1 2..16 tseg2 1..8 sjw 1..4 brp 1..1024 brp_inc 1
	  clock 20000000 
	  re-started bus-errors arbit-lost error-warn error-pass bus-off
	  0          0          0          0          0          0         numtxqueues 1 numrxqueues 1 gso_max_size 65536 gso_max_segs 65535 parentbus platform parentdev 4ae3c000.can 
    RX:  bytes packets errors dropped  missed   mcast           
         39864    4995      0       0       0       0 
    TX:  bytes packets errors dropped carrier collsns           
         39880    4985      0      21       0       0 

=== ERROR SUMMARY ===
echo_skb occupied errors: 11
RAMINIT timeout errors: 0
0
ENOBUFS errors: 0
0
IRQ 'nobody cared' errors: 0
0
====================

[0;34m[18:25:52][0m ==========================================
[0;34m[18:25:52][0m TEST 5: IRQ Handler Stress Test
[0;34m[18:25:52][0m ==========================================
[0;34m[18:25:52][0m Setting up CAN interface: main_dcan1
[0;32m[SUCCESS][0m CAN interface main_dcan1 ready at 1000000 bps
[0;34m[18:25:53][0m Starting IRQ monitoring...
[0;34m[18:25:53][0m Launching extreme burst load...
[0;34m[18:26:02][0m IRQ count: 7717 interrupts processed
[0;34m[18:26:02][0m Checking for errors after: IRQ Handler Stress Test
[1;33m[WARNING][0m Found kernel messages:
  [ 7039.845031] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 7040.128784] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 7040.412567] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 7040.691406] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 7040.972778] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 7041.254058] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 7044.270446] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 7047.396209] c_can_platform 4ae3c000.can main_dcan1: can_put_echo_skb: BUG! echo_skb 7 is occupied!
  [ 7047.396514] c_can_platform 4ae3c000.can main_dcan1: can_put_echo_skb: BUG! echo_skb 10 is occupied!
  [ 7047.396606] c_can_platform 4ae3c000.can main_dcan1: can_put_echo_skb: BUG! echo_skb 11 is occupied!
  [ 7047.396728] c_can_platform 4ae3c000.can main_dcan1: can_put_echo_skb: BUG! echo_skb 12 is occupied!
  [ 7047.396850] c_can_platform 4ae3c000.can main_dcan1: can_put_echo_skb: BUG! echo_skb 13 is occupied!
  [ 7047.396942] c_can_platform 4ae3c000.can main_dcan1: can_put_echo_skb: BUG! echo_skb 14 is occupied!
  [ 7047.397064] c_can_platform 4ae3c000.can main_dcan1: can_put_echo_skb: BUG! echo_skb 15 is occupied!
  [ 7047.397155] c_can_platform 4ae3c000.can main_dcan1: can_put_echo_skb: BUG! echo_skb 16 is occupied!
  [ 7047.397277] c_can_platform 4ae3c000.can main_dcan1: can_put_echo_skb: BUG! echo_skb 17 is occupied!
  [ 7047.397399] c_can_platform 4ae3c000.can main_dcan1: can_put_echo_skb: BUG! echo_skb 18 is occupied!
  [ 7047.397491] c_can_platform 4ae3c000.can main_dcan1: can_put_echo_skb: BUG! echo_skb 19 is occupied!
  [ 7051.353637] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 7065.828308] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
[0;34m[18:26:02][0m Interface statistics:
5: main_dcan1: <NOARP,UP,LOWER_UP,ECHO> mtu 16 qdisc pfifo_fast state UP mode DEFAULT group default qlen 10
    link/can  promiscuity 0 minmtu 0 maxmtu 0 
    can <LOOPBACK> state ERROR-ACTIVE (berr-counter tx 0 rx 0) restart-ms 0 
	  bitrate 1000000 sample-point 0.750
	  tq 50 prop-seg 7 phase-seg1 7 phase-seg2 5 sjw 1 brp 1
	  c_can: tseg1 2..16 tseg2 1..8 sjw 1..4 brp 1..1024 brp_inc 1
	  clock 20000000 
	  re-started bus-errors arbit-lost error-warn error-pass bus-off
	  0          0          0          0          0          0         numtxqueues 1 numrxqueues 1 gso_max_size 65536 gso_max_segs 65535 parentbus platform parentdev 4ae3c000.can 
    RX:  bytes packets errors dropped  missed   mcast           
        101600   12712      0       0       0       0 
    TX:  bytes packets errors dropped carrier collsns           
        101616   12702      0      21       0       0 

=== ERROR SUMMARY ===
echo_skb occupied errors: 11
RAMINIT timeout errors: 0
0
ENOBUFS errors: 0
0
IRQ 'nobody cared' errors: 0
0
====================

[0;34m[18:26:04][0m ==========================================
[0;34m[18:26:04][0m TEST 6: Combined Stress Test (All Issues)
[0;34m[18:26:04][0m ==========================================
[0;34m[18:26:04][0m Running combined stress test...
[0;34m[18:26:04][0m Phase 1: High-rate TX...
[0;34m[18:26:04][0m Setting up CAN interface: main_dcan1
[0;32m[SUCCESS][0m CAN interface main_dcan1 ready at 1000000 bps
[0;34m[18:26:08][0m Phase 2: Rapid restart cycles...
[0;34m[18:26:09][0m Phase 3: Concurrent TX waves...
[0;34m[18:26:09][0m Setting up CAN interface: main_dcan1
[0;32m[SUCCESS][0m CAN interface main_dcan1 ready at 1000000 bps
[0;34m[18:26:12][0m Combined stress test complete
[0;34m[18:26:12][0m Checking for errors after: Combined Stress Test
[1;33m[WARNING][0m Found kernel messages:
  [ 7047.396942] c_can_platform 4ae3c000.can main_dcan1: can_put_echo_skb: BUG! echo_skb 14 is occupied!
  [ 7047.397064] c_can_platform 4ae3c000.can main_dcan1: can_put_echo_skb: BUG! echo_skb 15 is occupied!
  [ 7047.397155] c_can_platform 4ae3c000.can main_dcan1: can_put_echo_skb: BUG! echo_skb 16 is occupied!
  [ 7047.397277] c_can_platform 4ae3c000.can main_dcan1: can_put_echo_skb: BUG! echo_skb 17 is occupied!
  [ 7047.397399] c_can_platform 4ae3c000.can main_dcan1: can_put_echo_skb: BUG! echo_skb 18 is occupied!
  [ 7047.397491] c_can_platform 4ae3c000.can main_dcan1: can_put_echo_skb: BUG! echo_skb 19 is occupied!
  [ 7051.353637] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 7065.828308] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 7077.794677] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 7081.448883] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 7081.549652] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 7081.650695] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 7081.752746] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 7081.853881] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 7081.954864] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 7082.054901] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 7082.156188] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 7082.266723] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 7082.368255] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 7082.700653] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
[0;34m[18:26:12][0m Interface statistics:
5: main_dcan1: <NOARP,UP,LOWER_UP,ECHO> mtu 16 qdisc pfifo_fast state UP mode DEFAULT group default qlen 10
    link/can  promiscuity 0 minmtu 0 maxmtu 0 
    can <LOOPBACK> state ERROR-ACTIVE (berr-counter tx 0 rx 0) restart-ms 0 
	  bitrate 1000000 sample-point 0.750
	  tq 50 prop-seg 7 phase-seg1 7 phase-seg2 5 sjw 1 brp 1
	  c_can: tseg1 2..16 tseg2 1..8 sjw 1..4 brp 1..1024 brp_inc 1
	  clock 20000000 
	  re-started bus-errors arbit-lost error-warn error-pass bus-off
	  0          0          0          0          0          0         numtxqueues 1 numrxqueues 1 gso_max_size 65536 gso_max_segs 65535 parentbus platform parentdev 4ae3c000.can 
    RX:  bytes packets errors dropped  missed   mcast           
        114845   15009      0       0       0       0 
    TX:  bytes packets errors dropped carrier collsns           
        114861   14999      0      21       0       0 

=== ERROR SUMMARY ===
echo_skb occupied errors: 11
RAMINIT timeout errors: 0
0
ENOBUFS errors: 0
0
IRQ 'nobody cared' errors: 0
0
====================

[0;34m[18:26:12][0m ==========================================
[0;34m[18:26:12][0m ALL TESTS COMPLETE
[0;34m[18:26:12][0m ==========================================
[0;34m[18:26:12][0m Full log saved to: /tmp/can_stress_test_20260402_182434.log
=== FINAL ERROR SUMMARY ===
Total echo_skb errors: 11
Total RAMINIT timeouts: 0
0
Total ENOBUFS errors: 0
0
Total IRQ errors: 0
0
=========================
[0;34m[18:27:44][0m Cleaning up background processes...
[0;34m[18:27:45][0m Exiting...

Result: You reproduce echo_skb errors.

Customer Test Result Under SDK9.3 Without Patch on Their Board

can0: <NOARP,ECHO> mtu 16 qdisc pfifo_fast state DOWN mode DEFAULT group default qlen 10
    link/can  promiscuity 0 
    can <LOOPBACK> state STOPPED (berr-counter tx 0 rx 0) restart-ms 0 
    bitrate 1000000 sample-point 0.750 
    tq 50 prop-seg 7 phase-seg1 7 phase-seg2 5 sjw 1
    c_can: tseg1 2..16 tseg2 1..8 sjw 1..4 brp 1..1024 brp-inc 1
    clock 20000000
    re-started bus-errors arbit-lost error-warn error-pass bus-off
    0          0          0          0          0          0         
    RX: bytes  packets  errors  dropped overrun mcast   
    8091519    1049799  0       0       0       0      
    TX: bytes  packets  errors  dropped carrier collsns 
    8091560    1049785  0       141     0       0      

=== ERROR SUMMARY ===
echo_skb occupied errors: 16
RAMINIT timeout errors: 445
ENOBUFS errors: 0
0
IRQ 'nobody cared' errors: 0
0

Result: Customer reproduce echo_skb & RAMINIT timeout errors.

Customer Test Result Under SDK9.3 With Patch on Their Board

can0: <NOARP,ECHO> mtu 16 qdisc pfifo_fast state DOWN mode DEFAULT group default qlen 10
    link/can  promiscuity 0
    can <LOOPBACK> state STOPPED (berr-counter tx 0 rx 0) restart-ms 0
          bitrate 1000000 sample-point 0.750
          tq 50 prop-seg 7 phase-seg1 7 phase-seg2 5 sjw 1
          c_can: tseg1 2..16 tseg2 1..8 sjw 1..4 brp 1..1024 brp-inc 1
          clock 20000000
          re-started bus-errors arbit-lost error-warn error-pass bus-off
          0          0          0          0          0          0
    RX: bytes  packets  errors  dropped overrun mcast
    6904864    895169   0       0       0       0
    TX: bytes  packets  errors  dropped carrier collsns
    6904887    895169   0       93      0       0

=== ERROR SUMMARY ===
echo_skb occupied errors: 2
RAMINIT timeout errors: 505
ENOBUFS errors: 0
0
IRQ 'nobody cared' errors: 0
0
====================

Result: Customer reproduce echo_skb & RAMINIT timeout errors. The echo_skb decreases because their dmesg log is full. And both two problems still exist. More importantly, your patch introduce new Kernel Hang error below during stress test: (This only happens with the patch with high possibility, never occur without patch before)

Situation 1 (higher trigger probability):

[10376.779465] net can0: c_can_hw_raminit_wait_syscon: time out
[10819.879945] BUG: scheduling while atomic: cangen/3099/0x00000002
[10819.886508] 8<--- cut here ---
[10819.886511] Unable to handle kernel paging request at virtual address b6e5e898
[10819.886515] [b6e5e898] *pgd=81774003, *pmd=816c6003, *pte=00000000
[10819.886526] Internal error: Oops: 80000207 [#1] PREEMPT_RT ARM
[10819.886532] Modules linked in:
[10819.886535] CPU: 0 PID: 3099 Comm: cangen Tainted: G        W          6.1.119-rt45+ #9
[10819.886542] Hardware name: Generic DRA72X (Flattened Device Tree)
[10819.886545] PC is at 0xb6e5e898
[10819.886548] LR is at 0x00010fa7
[10819.886550] pc : [<b6e5e898>]    lr : [<00010fa7>]    psr: 600d0010
[10819.886555] sp : bea8eab8  ip : b6e5e898  fp : 00000003
[10819.886558] r10: 00024100  r9 : 00000001  r8 : 000007b4
[10819.886562] r7 : 00000010  r6 : 00024100  r5 : 00000000  r4 : 00000000
[10819.886566] r3 : 00000001  r2 : 00000000  r1 : 00000001  r0 : 00012fc8
[10819.886570] Flags: nZCv  IRQs on  FIQs on  Mode USER_32  ISA ARM  Segment user
[10819.886578] Control: 30c5387d  Table: 824826c0  DAC: fffffffd
[10819.886581] Register r0 information: non-paged memory
[10819.886588] Register r1 information: non-paged memory
[10819.886593] Register r2 information: NULL pointer
[10819.886597] Register r3 information: non-paged memory
[10819.886602] Register r4 information: NULL pointer
[10819.886606] Register r5 information: NULL pointer
[10819.886610] Register r6 information: non-paged memory
[10819.886615] Register r7 information: zero-size pointer
[10819.886619] Register r8 information: non-paged memory
[10819.886623] Register r9 information: non-paged memory
[10819.886627] Register r10 information: non-paged memory
[10819.886632] Register r11 information: non-paged memory
[10819.886636] Register r12 information: non-paged memory
[10819.886641] Process cangen (pid: 3099, stack limit = 0x2afaea98)
[10819.886647] Stack: (0xbea8eab8 to 0xbea90000)
[10819.886652] eaa0:                                                       00000000 ffffffff
[10819.888001] ffe0: ???????? ???????? ???????? ???????? ???????? ???????? ???????? ????????
[10819.888007] Code: bad PC value
[10821.458129] ---[ end trace 0000000000000000 ]---
[10821.458134] Kernel panic - not syncing: Fatal exception in interrupt

Situation 2 (Supplemented with function addresses):

[ 2377.191241] net can0: c_can_hw_raminit_wait_syscon: time out
[ 2377.739391] net can0: c_can_hw_raminit_wait_syscon: time out
[ 2380.394076] net can0: c_can_hw_raminit_wait_syscon: time out
[ 2383.441967] BUG: scheduling while atomic: cangen/853/0x000000
[ 2383.441967] BUG: scheduling while atomic: cangen/853/0x00000002
[ 2383.441980] Modules linked in:
[ 2383.441987] CPU: 0 PID: 853 Comm: cangen Not tainted 6.1.119-rt45+ #9
[ 2383.441996] Hardware name: Generic DRA72X (Flattened Device Tree)
[ 2383.442006] Function entered at [<c020bdf8>] from [<c0208ed4>] # at unwind_backtrace
[ 2383.442012] Function entered at [<c0208ed4>] from [<c08fd258>] # at show_stack
[ 2383.442018] Function entered at [<c08fd258>] from [<c024826c>] # at dump_stack_lvl
[ 2383.442023] Function entered at [<c024826c>] from [<c08fe6c8>] # at __schedule_bug, core.c
[ 2383.442027] Function entered at [<c08fe6c8>] from [<c08fed9c>] # at __schedule, core.c
[ 2383.442031] Function entered at [<c08fed9c>] from [<c0904e54>] # at schedule_rtlock
[ 2383.442035] Function entered at [<c0904e54>] from [<c090599c>] # at rtlock_slowlock_locked, spinlock_rt.c
[ 2383.442038] Function entered at [<c090599c>] from [<c030237c>] # at rt_spin_lock
[ 2383.442043] Function entered at [<c030237c>] from [<c0302f94>] # at ___slab_alloc, slub.c
[ 2383.442047] Function entered at [<c0302f94>] from [<c0781554>] # at kmem_cache_alloc
[ 2383.442052] Function entered at [<c0781554>] from [<c064ed78>] # at skb_clone
[ 2383.442057] Function entered at [<c064ed78>] from [<c065407c>] # at can_put_echo_skb
[ 2383.442060] Function entered at [<c065407c>] from [<c0798450>] # at c_can_start_xmit, c_can_main.c
[ 2383.442065] Function entered at [<c0798450>] from [<c07d4de8>] # at dev_hard_start_xmit
[ 2383.442069] Function entered at [<c07d4de8>] from [<c079887c>] # at sch_direct_xmit
[ 2383.442073] Function entered at [<c079887c>] from [<c08975d8>] # at __dev_queue_xmit
[ 2383.442078] Function entered at [<c08975d8>] from [<c0899574>] # at can_send
[ 2383.442081] Function entered at [<c0899574>] from [<c077369c>] # at raw_sendmsg
[ 2383.442086] Function entered at [<c077369c>] from [<c030df8c>] # at sock_write_iter
[ 2383.442090] Function entered at [<c030df8c>] from [<c030e10c>] # at vfs_write
[ 2383.442093] Function entered at [<c030e10c>] from [<c0200140>] # at ksys_write
[ 2383.442096] Exception stack(0xc1765fa8 to 0xc1765ff0)
[ 2383.442104] 5fa0:                   00000000 00000000 00000003 00024100 00000010 00000000
[ 2383.442110] 5fc0: 00000000 00000000 00024100 00000004 00000022 00000001 00024100 00000003
[ 2383.442115] 5fe0: 0000006c bea37ab0 00010d87 b6ee222c
[ 2383.445130] ------------[ cut here ]------------
[ 2383.445134] WARNING: CPU: 0 PID: 853 at kernel/softirq.c:210 0xc0228f00
[ 2383.445144] Modules linked in:
[ 2383.445150] CPU: 0 PID: 853 Comm: cangen Tainted: G        W          6.1.119-rt45+ #9
[ 2383.445158] Hardware name: Generic DRA72X (Flattened Device Tree)
[ 2383.445162] Function entered at [<c020bdf8>] from [<c0208ed4>] # at unwind_backtrace
[ 2383.445166] Function entered at [<c0208ed4>] from [<c08fd258>] # at show_stack
[ 2383.445170] Function entered at [<c08fd258>] from [<c0225814>] # at dump_stack_lvl
[ 2383.445174] Function entered at [<c0225814>] from [<c0225a00>] # at __warn
[ 2383.445178] Function entered at [<c0225a00>] from [<c0228f00>] # at warn_slowpath_fmt
[ 2383.445182] Function entered at [<c0228f00>] from [<c0798a30>] # at __local_bh_enable_ip
[ 2383.445185] Function entered at [<c0798a30>] from [<c08975d8>] # at __dev_queue_xmit
[ 2383.445189] Function entered at [<c08975d8>] from [<c0899574>] # at can_send
[ 2383.445192] Function entered at [<c0899574>] from [<c077369c>] # at raw_sendmsg
[ 2383.445196] Function entered at [<c077369c>] from [<c030df8c>] # at sock_write_iter
[ 2383.445199] Function entered at [<c030df8c>] from [<c030e10c>] # at vfs_write
[ 2383.445203] Function entered at [<c030e10c>] from [<c0200140>] # at ksys_write
[ 2383.445205] Exception stack(0xc1765fa8 to 0xc1765ff0)
[ 2383.445212] 5fa0:                   00000000 00000000 00000003 00024100 00000010 00000000
[ 2383.445218] 5fc0: 00000000 00000000 00024100 00000004 00000022 00000001 00024100 00000003
[ 2383.445222] 5fe0: 0000006c bea37ab0 00010d87 b6ee222c
[ 2383.445225] ---[ end trace 0000000000000000 ]---
[ 2383.445259] ------------[ cut here ]------------
[ 2383.445263] WARNING: CPU: 0 PID: 853 at kernel/softirq.c:148 0xc0228cb4
[ 2383.445271] Modules linked in:
[ 2383.445277] CPU: 0 PID: 853 Comm: cangen Tainted: G        W          6.1.119-rt45+ #9
[ 2383.445283] Hardware name: Generic DRA72X (Flattened Device Tree)
[ 2383.445287] Function entered at [<c020bdf8>] from [<c0208ed4>]
[ 2383.445291] Function entered at [<c0208ed4>] from [<c08fd258>]
[ 2383.445295] Function entered at [<c08fd258>] from [<c0225814>]
[ 2383.445298] Function entered at [<c0225814>] from [<c0225a00>]
[ 2383.445301] Function entered at [<c0225a00>] from [<c0228cb4>] # at warn_slowpath_fmt
[ 2383.445305] Function entered at [<c0228cb4>] from [<c07985a0>] # at __local_bh_disable_ip
[ 2383.445308] Function entered at [<c07985a0>] from [<c08975d8>]
[ 2383.445312] Function entered at [<c08975d8>] from [<c0899574>]
[ 2383.445315] Function entered at [<c0899574>] from [<c077369c>]
[ 2383.445318] Function entered at [<c077369c>] from [<c030df8c>]
[ 2383.445322] Function entered at [<c030df8c>] from [<c030e10c>]
[ 2383.445325] Function entered at [<c030e10c>] from [<c0200140>]
[ 2383.445328] Exception stack(0xc1765fa8 to 0xc1765ff0)
[ 2383.445334] 5fa0:                   00000000 00000000 00000003 00024100 00000010 00000000
[ 2383.445339] 5fc0: 00000000 00000000 00024100 00000004 00000021 00000001 00024100 00000003
[ 2383.445343] 5fe0: 0000006c bea37ab0 00010d87 b6ee222c
[ 2383.445346] ---[ end trace 0000000000000000 ]---
[ 2383.445669] 8<--- cut here ---
[ 2383.445672] Unable to handle kernel paging request at virtual address b6e8bac0
[ 2383.445677] [b6e8bac0] *pgd=824ab003, *pmd=8303f003, *pte=00000000
[ 2383.445688] Internal error: Oops: 80000207 [#1] PREEMPT_RT ARM
[ 2383.445693] Modules linked in:
[ 2383.445697] CPU: 0 PID: 853 Comm: cangen Tainted: G        W          6.1.119-rt45+ #9
[ 2383.445704] Hardware name: Generic DRA72X (Flattened Device Tree)
[ 2383.445707] PC is at 0xb6e8bac0
[ 2383.445710] LR is at 0xb6e4f7c8
[ 2383.445712] pc : [<b6e8bac0>]    lr : [<b6e4f7c8>]    psr: 800d0010
[ 2383.445717] sp : bea37bb0  ip : 00000000  fp : b6f60000
[ 2383.445720] r10: b6f63128  r9 : 00000000  r8 : 00000001
[ 2383.445724] r7 : 00000000  r6 : 00000000  r5 : b6f5e6d8  r4 : b6f5e6d8
[ 2383.445728] r3 : b6e8bac0  r2 : b6f5e6d4  r1 : 00000000  r0 : 000240e4
[ 2383.445732] Flags: Nzcv  IRQs on  FIQs on  Mode USER_32  ISA ARM  Segment user
[ 2383.445740] Control: 30c5387d  Table: 823a3080  DAC: fffffffd
[ 2383.445743] Register r0 information: non-paged memory
[ 2383.445750] Register r1 information: NULL pointer
[ 2383.445754] Register r2 information: non-paged memory
[ 2383.445759] Register r3 information: non-paged memory
[ 2383.445763] Register r4 information: non-paged memory
[ 2383.445767] Register r5 information: non-paged memory
[ 2383.445771] Register r6 information: NULL pointer
[ 2383.445775] Register r7 information: NULL pointer
[ 2383.445779] Register r8 information: non-paged memory
[ 2383.445783] Register r9 information: NULL pointer
[ 2383.445787] Register r10 information: non-paged memory
[ 2383.445792] Register r11 information: non-paged memory
[ 2383.445796] Register r12 information: NULL pointer
[ 2383.445800] Process cangen (pid: 853, stack limit = 0x271c41f1)
[ 2383.445807] Stack: (0xbea37bb0 to 0xbea38000)
[ 2383.445813] 7ba0:                                     b6f63128 00000000 b6f604fc 00000001
[ 2383.446003] Code: bad PC value
[ 2383.446008] ---[ end trace 0000000000000000 ]---
[ 2383.446012] Kernel panic - not syncing: Fatal exception in interrupt
02
[ 2384.367308] ---[ end Kernel panic - not syncing: Fatal exception in interrupt ]---

We need you provide your test result of this patch on EVM, and let us know if you also meet the kernel hang error above when using this patch.

Just as an experiment (as mentioned above, customer cannot go back to SDK6.3 because you suggest them migrate to SDK9.3 before to fix the PRU Ethernet issue), customer also tried SDK6.3 with this pressure test. Impressively, no errors are found below:

[01:20:09] Interface statistics:
2: can0: <NOARP,ECHO> mtu 16 qdisc pfifo_fast state DOWN mode DEFAULT group default qlen 10
    link/can  promiscuity 0
    can <LOOPBACK> state STOPPED (berr-counter tx 0 rx 0) restart-ms 0
          bitrate 1000000 sample-point 0.750
          tq 50 prop-seg 7 phase-seg1 7 phase-seg2 5 sjw 1
          c_can: tseg1 2..16 tseg2 1..8 sjw 1..4 brp 1..1024 brp-inc 1
          clock 20000000
          re-started bus-errors arbit-lost error-warn error-pass bus-off
          0          0          0          0          0          0
    RX: bytes  packets  errors  dropped overrun mcast
    5702444    734096   0       0       0       0
    TX: bytes  packets  errors  dropped carrier collsns
    5702444    734096   0       0       0       0

=== ERROR SUMMARY ===
echo_skb occupied errors: 0
0
RAMINIT timeout errors: 0
0
ENOBUFS errors: 0
0
IRQ 'nobody cared' errors: 0
0
====================

So we already narrow down the issue, we can firstly look at why SDK9.3 introduce so many errors under a normal stress test while SDK6.3 not have, maybe fixing this issue will be beneficial to the actual problem in the application.

Thanks,

Kevin

0 Kevin Peng 3 months ago in reply to Josue Zamitiz-Ayala

TI__Expert 4998 points

An update for tonight experiment, customer increases the dmesg capacity and redo the stress test with & without the patch on SDK9.3:

Each time they do the test they will power off & power on in advance.

Without Patch Trial 1:

[01:05:09] Interface statistics:
2: can0: <NOARP,UP,LOWER_UP,ECHO> mtu 16 qdisc pfifo_fast state UP mode DEFAULT group default qlen 10
    link/can  promiscuity 0
    can <LOOPBACK> state ERROR-ACTIVE (berr-counter tx 0 rx 0) restart-ms 0
          bitrate 1000000 sample-point 0.750
          tq 50 prop-seg 7 phase-seg1 7 phase-seg2 5 sjw 1
          c_can: tseg1 2..16 tseg2 1..8 sjw 1..4 brp 1..1024 brp-inc 1
          clock 20000000
          re-started bus-errors arbit-lost error-warn error-pass bus-off
          0          0          0          0          0          0
    RX: bytes  packets  errors  dropped overrun mcast
    7505483    972924   0       0       0       0
    TX: bytes  packets  errors  dropped carrier collsns
    7505483    972924   0       31      0       0

=== ERROR SUMMARY ===
echo_skb occupied errors: 1
RAMINIT timeout errors: 844
ENOBUFS errors: 0
0
IRQ 'nobody cared' errors: 0
0
====================

Without Patch Trial 2:

[01:11:03] Interface statistics:
2: can0: <NOARP,ECHO> mtu 16 qdisc pfifo_fast state DOWN mode DEFAULT group default qlen 10
    link/can  promiscuity 0
    can <LOOPBACK> state STOPPED (berr-counter tx 0 rx 0) restart-ms 0
          bitrate 1000000 sample-point 0.750
          tq 50 prop-seg 7 phase-seg1 7 phase-seg2 5 sjw 1
          c_can: tseg1 2..16 tseg2 1..8 sjw 1..4 brp 1..1024 brp-inc 1
          clock 20000000
          re-started bus-errors arbit-lost error-warn error-pass bus-off
          0          0          0          0          0          0
    RX: bytes  packets  errors  dropped overrun mcast
    8278449    1074104  0       0       0       0
    TX: bytes  packets  errors  dropped carrier collsns
    8278452    1074104  0       51      0       0

=== ERROR SUMMARY ===
echo_skb occupied errors: 2
RAMINIT timeout errors: 969
ENOBUFS errors: 0
0
IRQ 'nobody cared' errors: 0
0
====================

Without Patch Trial 3:

[00:51:46] Interface statistics:
2: can0: <NOARP,UP,LOWER_UP,ECHO> mtu 16 qdisc pfifo_fast state UP mode DEFAULT group default qlen 10
    link/can  promiscuity 0
    can <LOOPBACK> state ERROR-ACTIVE (berr-counter tx 0 rx 0) restart-ms 0
          bitrate 1000000 sample-point 0.750
          tq 50 prop-seg 7 phase-seg1 7 phase-seg2 5 sjw 1
          c_can: tseg1 2..16 tseg2 1..8 sjw 1..4 brp 1..1024 brp-inc 1
          clock 20000000
          re-started bus-errors arbit-lost error-warn error-pass bus-off
          0          0          0          0          0          0
    RX: bytes  packets  errors  dropped overrun mcast
    6216893    805561   0       0       0       0
    TX: bytes  packets  errors  dropped carrier collsns
    6216902    805561   0       62      0       0

=== ERROR SUMMARY ===
echo_skb occupied errors: 2
RAMINIT timeout errors: 707
ENOBUFS errors: 0
0
IRQ 'nobody cared' errors: 0
0
====================

With Patch Trial 1

[01:09:21] Interface statistics:
2: can0: <NOARP,ECHO> mtu 16 qdisc pfifo_fast state DOWN mode DEFAULT group default qlen 10
    link/can  promiscuity 0
    can <LOOPBACK> state STOPPED (berr-counter tx 0 rx 0) restart-ms 0
          bitrate 1000000 sample-point 0.750
          tq 50 prop-seg 7 phase-seg1 7 phase-seg2 5 sjw 1
          c_can: tseg1 2..16 tseg2 1..8 sjw 1..4 brp 1..1024 brp-inc 1
          clock 20000000
          re-started bus-errors arbit-lost error-warn error-pass bus-off
          0          0          0          0          0          0
    RX: bytes  packets  errors  dropped overrun mcast
    7445644    965551   0       0       0       0
    TX: bytes  packets  errors  dropped carrier collsns
    7445703    965552   0       217     0       0

=== ERROR SUMMARY ===
echo_skb occupied errors: 7
RAMINIT timeout errors: 1067
ENOBUFS errors: 0
0
IRQ 'nobody cared' errors: 0
0
====================

With Patch Trial 2

[00:46:49] Interface statistics:
2: can0: <NOARP,ECHO> mtu 16 qdisc pfifo_fast state DOWN mode DEFAULT group default qlen 10
    link/can  promiscuity 0
    can <LOOPBACK> state STOPPED (berr-counter tx 0 rx 0) restart-ms 0
          bitrate 1000000 sample-point 0.750
          tq 50 prop-seg 7 phase-seg1 7 phase-seg2 5 sjw 1
          c_can: tseg1 2..16 tseg2 1..8 sjw 1..4 brp 1..1024 brp-inc 1
          clock 20000000
          re-started bus-errors arbit-lost error-warn error-pass bus-off
          0          0          0          0          0          0
    RX: bytes  packets  errors  dropped overrun mcast
    5686463    736945   0       0       0       0
    TX: bytes  packets  errors  dropped carrier collsns
    5686469    736945   0       93      0       0

=== ERROR SUMMARY ===
echo_skb occupied errors: 3
RAMINIT timeout errors: 839
ENOBUFS errors: 0
0
IRQ 'nobody cared' errors: 0
0
====================

With Patch Trial 3

第三次测试：
[00:45:46] Interface statistics:
2: can0: <NOARP,ECHO> mtu 16 qdisc pfifo_fast state DOWN mode DEFAULT group default qlen 10
    link/can  promiscuity 0
    can <LOOPBACK> state STOPPED (berr-counter tx 0 rx 0) restart-ms 0
          bitrate 1000000 sample-point 0.750
          tq 50 prop-seg 7 phase-seg1 7 phase-seg2 5 sjw 1
          c_can: tseg1 2..16 tseg2 1..8 sjw 1..4 brp 1..1024 brp-inc 1
          clock 20000000
          re-started bus-errors arbit-lost error-warn error-pass bus-off
          0          0          0          0          0          0
    RX: bytes  packets  errors  dropped overrun mcast
    5450258    706497   0       0       0       0
    TX: bytes  packets  errors  dropped carrier collsns
    5450262    706497   0       62      0       0

=== ERROR SUMMARY ===
echo_skb occupied errors: 2
RAMINIT timeout errors: 782
ENOBUFS errors: 0
0
IRQ 'nobody cared' errors: 0
0
====================

You could see that the patch does not improve to decrease the number of error for echo_skb & RAMINIT timeout errors

Furthermore, using the patch will cause sometimes appearing additional error below which never happens without patch:

[ 1631.765626] net can0: c_can_hw_raminit_wait_syscon: time out
[ 1650.264030] net can0: c_can_hw_raminit_wait_syscon: time out
[ 1655.381667] BUG: scheduling while atomic: irq/91-can0/28397/0x00000002
[ 1655.382162] softirq: huh, entered softirq 2 NET_TX 758c5363 with preempt_count 00000000, exited with ffffffff?
[ 1659.794121] net can0: c_can_hw_raminit_wait_syscon: time out
[ 1663.544073] net can0: c_can_hw_raminit_wait_syscon: time out

Thanks,

Kevin

0 Josue Zamitiz-Ayala 3 months ago in reply to Kevin Peng

TI__Mastermind 40246 points

Hello Kevin,

I am doing some analysis now. I will have to look into making a different setup instead of the testing setup I use know that is just using the internal loopback mode of the can module.

For my testing my procedure has been the following:

Setup CAN in Loop-back mode

Test with sk-echo patch:

[20:57:07] ==========================================
[20:57:07] TEST 6: Combined Stress Test (All Issues)
[20:57:07] ==========================================
[20:57:07] Running combined stress test...
[20:57:07] Phase 1: High-rate TX...
[20:57:07] Setting up CAN interface: main_dcan1
[SUCCESS] CAN interface main_dcan1 ready at 1000000 bps
[20:57:11] Phase 2: Rapid restart cycles...
[20:57:12] Phase 3: Concurrent TX waves...
[20:57:12] Setting up CAN interface: main_dcan1
[SUCCESS] CAN interface main_dcan1 ready at 1000000 bps
[20:57:14] Combined stress test complete
[20:57:14] Checking for errors after: Combined Stress Test
[WARNING] Found kernel messages:
  [ 2195.215972] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 2195.231353] IPv6: ADDRCONF(NETDEV_CHANGE): main_dcan1: link becomes ready
  [ 2329.844268] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 2333.437530] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 2333.523986] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 2333.619506] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 2333.706878] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 2333.794342] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 2333.886627] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 2333.973632] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 2334.064331] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 2334.161407] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 2334.258880] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 2334.573303] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [ 2335.245727] c_can_platform 4ae3c000.can main_dcan1: can_put_echo_skb: BUG! echo_skb 2 is occupied!
[20:57:14] Interface statistics:
5: main_dcan1: <NOARP,UP,LOWER_UP,ECHO> mtu 16 qdisc pfifo_fast state UP mode DEFAULT group default qlen 10
    link/can  promiscuity 0 minmtu 0 maxmtu 0
    can <LOOPBACK> state ERROR-ACTIVE (berr-counter tx 0 rx 0) restart-ms 0
          bitrate 1000000 sample-point 0.750
          tq 50 prop-seg 7 phase-seg1 7 phase-seg2 5 sjw 1 brp 1
          c_can: tseg1 2..16 tseg2 1..8 sjw 1..4 brp 1..1024 brp_inc 1
          clock 20000000
          re-started bus-errors arbit-lost error-warn error-pass bus-off
          0          0          0          0          0          0         numtxqueues 1 numrxqueues 1 gso_max_size 65536 gso_max_segs 65535 parentbus platfo
    RX:  bytes packets errors dropped  missed   mcast
          3001     527      0       0       0       0
    TX:  bytes packets errors dropped carrier collsns
          3008     527      0       0       0       0

=== ERROR SUMMARY ===
echo_skb occupied errors: 1
RAMINIT timeout errors: 0
0
ENOBUFS errors: 0
0
IRQ 'nobody cared' errors: 0
0
====================

[ERROR] Invalid choice:
[ERROR] Invalid choice:
[20:58:40] Cleaning up background processes...
[ERROR] Invalid choice:
[20:58:44] Cleaning up background processes...
[20:58:45] Exiting...

As you can see I still do not see any RAMINIT errors and only one echo_skb. I also do not see any kernel hangs but I have not stressed for long periods of times.

I did not see the kernel hang you mentioned, I powered on/off 6 times and it did not happen.

I agree that the customer has to review what changes were made from SDK 6.03 to SDK 9.3. I will try to help on my side but again, this is an open source driver.

I will let you know what I find on my side. I am still concerned that I cannot recreate the RAMINIT issues.
I will work on this tomorrow, as of now I recommend to revert any of the patches I made.

-Josue

0 Josue Zamitiz-Ayala 3 months ago in reply to Josue Zamitiz-Ayala

TI__Mastermind 40246 points

Kevin,

This is my test result from a test using RT-Linux 4.19 (SDK 6.03):

[02:49:40] ==========================================
[02:49:40] RUNNING ALL TESTS SEQUENTIALLY
[02:49:40] ==========================================
[02:49:40] ==========================================
[02:49:40] TEST 1: TX Buffer Exhaustion (ENOBUFS)
[02:49:40] ==========================================
[02:49:40] Setting up CAN interface: can0
[SUCCESS] CAN interface can0 ready at 1000000 bps
[02:49:41] Launching 8 concurrent zero-gap transmitters...
[02:49:41] This should fill all 16 TX message objects immediately
[02:49:41] Transmitters running... waiting 5 seconds
[02:49:46] Cleaning up background processes...
[02:49:47] Checking for errors after: TX Buffer Exhaustion Test
[WARNING] Found kernel messages:
  [ 1847.364003] c_can_platform 4ae3c000.can can0: setting BTR=4d00 BRPE=0000
  [ 1847.683963] c_can_platform 4ae3c000.can can0: setting BTR=4d00 BRPE=0000
  [ 1848.003881] c_can_platform 4ae3c000.can can0: setting BTR=4d00 BRPE=0000
  [ 1848.325147] c_can_platform 4ae3c000.can can0: setting BTR=4d00 BRPE=0000
  [ 1848.644669] c_can_platform 4ae3c000.can can0: setting BTR=4d00 BRPE=0000
  [ 1848.963790] c_can_platform 4ae3c000.can can0: setting BTR=4d00 BRPE=0000
  [ 1849.284676] c_can_platform 4ae3c000.can can0: setting BTR=4d00 BRPE=0000
  [ 1849.603573] c_can_platform 4ae3c000.can can0: setting BTR=4d00 BRPE=0000
  [ 1849.924250] c_can_platform 4ae3c000.can can0: setting BTR=4d00 BRPE=0000
  [ 1850.244440] c_can_platform 4ae3c000.can can0: setting BTR=4d00 BRPE=0000
  [ 1850.564410] c_can_platform 4ae3c000.can can0: setting BTR=4d00 BRPE=0000
  [ 1850.884711] c_can_platform 4ae3c000.can can0: setting BTR=4d00 BRPE=0000
  [ 1851.203686] c_can_platform 4ae3c000.can can0: setting BTR=4d00 BRPE=0000
  [ 1851.524778] c_can_platform 4ae3c000.can can0: setting BTR=4d00 BRPE=0000
  [ 1851.845306] c_can_platform 4ae3c000.can can0: setting BTR=4d00 BRPE=0000
  [ 1855.028788] c_can_platform 4ae3c000.can can0: setting BTR=4d00 BRPE=0000
  [ 1862.611704] c_can_platform 4ae3c000.can can0: setting BTR=4d00 BRPE=0000
  [ 1877.348525] c_can_platform 4ae3c000.can can0: setting BTR=4d00 BRPE=0000
  [ 1889.932358] c_can_platform 4ae3c000.can can0: setting BTR=4d00 BRPE=0000
  [ 2039.006779] c_can_platform 4ae3c000.can can0: setting BTR=4d00 BRPE=0000
[02:49:47] Interface statistics:
5: can0: <NOARP,ECHO> mtu 16 qdisc fq_codel state DOWN mode DEFAULT group default qlen 10
    link/can  promiscuity 0 minmtu 0 maxmtu 0
    can <LOOPBACK> state STOPPED (berr-counter tx 0 rx 0) restart-ms 0
          bitrate 1000000 sample-point 0.750
          tq 50 prop-seg 7 phase-seg1 7 phase-seg2 5 sjw 1
          c_can: tseg1 2..16 tseg2 1..8 sjw 1..4 brp 1..1024 brp-inc 1
          clock 20000000
          re-started bus-errors arbit-lost error-warn error-pass bus-off
          0          0          0          0          0          0         numtxqueues 1 numrxqueues 1 gso_max_size 65536 gso_max_segs 65535
    RX: bytes  packets  errors  dropped overrun mcast
    698107     89484    0       0       0       0
    TX: bytes  packets  errors  dropped carrier collsns
    698107     89484    0       0       0       0

=== ERROR SUMMARY ===
echo_skb occupied errors: 0
0
RAMINIT timeout errors: 0
0
ENOBUFS errors: 0
0
IRQ 'nobody cared' errors: 0
0
====================

[02:49:50] ==========================================
[02:49:50] TEST 2: RAMINIT Timeout (Rapid Restart)
[02:49:50] ==========================================
[02:49:50] Performing 20 rapid restart cycles...
  Cycle 1/20... done
  Cycle 2/20... done
  Cycle 3/20... done
  Cycle 4/20... done
  Cycle 5/20... done
  Cycle 6/20... done
  Cycle 7/20... done
  Cycle 8/20... done
  Cycle 9/20... done
  Cycle 10/20... done
  Cycle 11/20... done
  Cycle 12/20... done
  Cycle 13/20... done
  Cycle 14/20... done
  Cycle 15/20... done
  Cycle 16/20... done
  Cycle 17/20... done
  Cycle 18/20... done
  Cycle 19/20... done
  Cycle 20/20... done
[02:49:56] Rapid restart cycles complete
[02:49:56] RAMINIT errors during test: 0
[02:49:56] Checking for errors after: RAMINIT Timeout Test
[WARNING] Found kernel messages:
  [ 2048.863541] c_can_platform 4ae3c000.can can0: setting BTR=4d00 BRPE=0000
  [ 2049.187339] c_can_platform 4ae3c000.can can0: setting BTR=4d00 BRPE=0000
  [ 2049.513444] c_can_platform 4ae3c000.can can0: setting BTR=4d00 BRPE=0000
  [ 2049.835188] c_can_platform 4ae3c000.can can0: setting BTR=4d00 BRPE=0000
  [ 2050.153688] c_can_platform 4ae3c000.can can0: setting BTR=4d00 BRPE=0000
  [ 2050.474328] c_can_platform 4ae3c000.can can0: setting BTR=4d00 BRPE=0000
  [ 2050.795002] c_can_platform 4ae3c000.can can0: setting BTR=4d00 BRPE=0000
  [ 2051.124099] c_can_platform 4ae3c000.can can0: setting BTR=4d00 BRPE=0000
  [ 2051.444638] c_can_platform 4ae3c000.can can0: setting BTR=4d00 BRPE=0000
  [ 2051.764828] c_can_platform 4ae3c000.can can0: setting BTR=4d00 BRPE=0000
  [ 2052.087572] net can0: c_can_hw_raminit_wait_syscon: time out
  [ 2052.093584] c_can_platform 4ae3c000.can can0: setting BTR=4d00 BRPE=0000
  [ 2052.413876] c_can_platform 4ae3c000.can can0: setting BTR=4d00 BRPE=0000
  [ 2052.733956] c_can_platform 4ae3c000.can can0: setting BTR=4d00 BRPE=0000
  [ 2053.055166] c_can_platform 4ae3c000.can can0: setting BTR=4d00 BRPE=0000
  [ 2053.385334] c_can_platform 4ae3c000.can can0: setting BTR=4d00 BRPE=0000
  [ 2053.704011] c_can_platform 4ae3c000.can can0: setting BTR=4d00 BRPE=0000
  [ 2054.023699] c_can_platform 4ae3c000.can can0: setting BTR=4d00 BRPE=0000
  [ 2054.345783] c_can_platform 4ae3c000.can can0: setting BTR=4d00 BRPE=0000
  [ 2054.663945] c_can_platform 4ae3c000.can can0: setting BTR=4d00 BRPE=0000
[02:49:57] Interface statistics:
5: can0: <NOARP,ECHO> mtu 16 qdisc fq_codel state DOWN mode DEFAULT group default qlen 10
    link/can  promiscuity 0 minmtu 0 maxmtu 0
    can <LOOPBACK> state STOPPED (berr-counter tx 0 rx 0) restart-ms 0
          bitrate 1000000 sample-point 0.750
          tq 50 prop-seg 7 phase-seg1 7 phase-seg2 5 sjw 1
          c_can: tseg1 2..16 tseg2 1..8 sjw 1..4 brp 1..1024 brp-inc 1
          clock 20000000
          re-started bus-errors arbit-lost error-warn error-pass bus-off
          0          0          0          0          0          0         numtxqueues 1 numrxqueues 1 gso_max_size 65536 gso_max_segs 65535
    RX: bytes  packets  errors  dropped overrun mcast
    714107     91484    0       0       0       0
    TX: bytes  packets  errors  dropped carrier collsns
    714107     91484    0       0       0       0

=== ERROR SUMMARY ===
echo_skb occupied errors: 0
0
RAMINIT timeout errors: 1
ENOBUFS errors: 0
0
IRQ 'nobody cared' errors: 0
0
====================

[02:49:59] ==========================================
[02:49:59] TEST 3: Echo SKB Race Condition
[02:49:59] ==========================================
[02:49:59] Setting up CAN interface: can0
[SUCCESS] CAN interface can0 ready at 1000000 bps
[02:50:00] Launching 20 waves of concurrent transmitters...
[02:50:00] This creates race between can_put_echo_skb() and can_get_echo_skb()
  Wave 1/20... done
  Wave 2/20... done
  Wave 3/20... done
  Wave 4/20... done
  Wave 5/20... done
  Wave 6/20... done
  Wave 7/20... done
  Wave 8/20... done
  Wave 9/20... done
  Wave 10/20... done
  Wave 11/20... done
  Wave 12/20... done
  Wave 13/20... done
  Wave 14/20... done
  Wave 15/20... done
  Wave 16/20... done
  Wave 17/20... done
  Wave 18/20... done
  Wave 19/20... done
  Wave 20/20... done
[02:50:04] Race condition test complete
[02:50:04] Checking for errors after: Echo SKB Race Condition Test
[WARNING] Found kernel messages:
  [ 2049.187339] c_can_platform 4ae3c000.can can0: setting BTR=4d00 BRPE=0000
  [ 2049.513444] c_can_platform 4ae3c000.can can0: setting BTR=4d00 BRPE=0000
  [ 2049.835188] c_can_platform 4ae3c000.can can0: setting BTR=4d00 BRPE=0000
  [ 2050.153688] c_can_platform 4ae3c000.can can0: setting BTR=4d00 BRPE=0000
  [ 2050.474328] c_can_platform 4ae3c000.can can0: setting BTR=4d00 BRPE=0000
  [ 2050.795002] c_can_platform 4ae3c000.can can0: setting BTR=4d00 BRPE=0000
  [ 2051.124099] c_can_platform 4ae3c000.can can0: setting BTR=4d00 BRPE=0000
  [ 2051.444638] c_can_platform 4ae3c000.can can0: setting BTR=4d00 BRPE=0000
  [ 2051.764828] c_can_platform 4ae3c000.can can0: setting BTR=4d00 BRPE=0000
  [ 2052.087572] net can0: c_can_hw_raminit_wait_syscon: time out
  [ 2052.093584] c_can_platform 4ae3c000.can can0: setting BTR=4d00 BRPE=0000
  [ 2052.413876] c_can_platform 4ae3c000.can can0: setting BTR=4d00 BRPE=0000
  [ 2052.733956] c_can_platform 4ae3c000.can can0: setting BTR=4d00 BRPE=0000
  [ 2053.055166] c_can_platform 4ae3c000.can can0: setting BTR=4d00 BRPE=0000
  [ 2053.385334] c_can_platform 4ae3c000.can can0: setting BTR=4d00 BRPE=0000
  [ 2053.704011] c_can_platform 4ae3c000.can can0: setting BTR=4d00 BRPE=0000
  [ 2054.023699] c_can_platform 4ae3c000.can can0: setting BTR=4d00 BRPE=0000
  [ 2054.345783] c_can_platform 4ae3c000.can can0: setting BTR=4d00 BRPE=0000
  [ 2054.663945] c_can_platform 4ae3c000.can can0: setting BTR=4d00 BRPE=0000
  [ 2057.861774] c_can_platform 4ae3c000.can can0: setting BTR=4d00 BRPE=0000
[02:50:04] Interface statistics:
5: 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 <LOOPBACK> state ERROR-ACTIVE (berr-counter tx 0 rx 0) restart-ms 0
          bitrate 1000000 sample-point 0.750
          tq 50 prop-seg 7 phase-seg1 7 phase-seg2 5 sjw 1
          c_can: tseg1 2..16 tseg2 1..8 sjw 1..4 brp 1..1024 brp-inc 1
          clock 20000000
          re-started bus-errors arbit-lost error-warn error-pass bus-off
          0          0          0          0          0          0         numtxqueues 1 numrxqueues 1 gso_max_size 65536 gso_max_segs 65535
    RX: bytes  packets  errors  dropped overrun mcast
    794107     101484   0       0       0       0
    TX: bytes  packets  errors  dropped carrier collsns
    794107     101484   0       0       0       0

=== ERROR SUMMARY ===
echo_skb occupied errors: 0
0
RAMINIT timeout errors: 1
ENOBUFS errors: 0
0
IRQ 'nobody cared' errors: 0
0
====================

[02:50:06] ==========================================
[02:50:07] TEST 4: Sustained High-Rate TX Load
[02:50:07] ==========================================
[02:50:07] Setting up CAN interface: can0
[SUCCESS] CAN interface can0 ready at 1000000 bps
[02:50:07] Launching 6 sustained transmitters at maximum rate...
[02:50:07] Transmitters running... monitoring for 10 seconds
[02:50:18] IRQ count during test: 28968
[02:50:18] Cleaning up background processes...
[02:50:19] Checking for errors after: Sustained Load Test
[WARNING] Found kernel messages:
  [ 2049.513444] c_can_platform 4ae3c000.can can0: setting BTR=4d00 BRPE=0000
  [ 2049.835188] c_can_platform 4ae3c000.can can0: setting BTR=4d00 BRPE=0000
  [ 2050.153688] c_can_platform 4ae3c000.can can0: setting BTR=4d00 BRPE=0000
  [ 2050.474328] c_can_platform 4ae3c000.can can0: setting BTR=4d00 BRPE=0000
  [ 2050.795002] c_can_platform 4ae3c000.can can0: setting BTR=4d00 BRPE=0000
  [ 2051.124099] c_can_platform 4ae3c000.can can0: setting BTR=4d00 BRPE=0000
  [ 2051.444638] c_can_platform 4ae3c000.can can0: setting BTR=4d00 BRPE=0000
  [ 2051.764828] c_can_platform 4ae3c000.can can0: setting BTR=4d00 BRPE=0000
  [ 2052.087572] net can0: c_can_hw_raminit_wait_syscon: time out
  [ 2052.093584] c_can_platform 4ae3c000.can can0: setting BTR=4d00 BRPE=0000
  [ 2052.413876] c_can_platform 4ae3c000.can can0: setting BTR=4d00 BRPE=0000
  [ 2052.733956] c_can_platform 4ae3c000.can can0: setting BTR=4d00 BRPE=0000
  [ 2053.055166] c_can_platform 4ae3c000.can can0: setting BTR=4d00 BRPE=0000
  [ 2053.385334] c_can_platform 4ae3c000.can can0: setting BTR=4d00 BRPE=0000
  [ 2053.704011] c_can_platform 4ae3c000.can can0: setting BTR=4d00 BRPE=0000
  [ 2054.023699] c_can_platform 4ae3c000.can can0: setting BTR=4d00 BRPE=0000
  [ 2054.345783] c_can_platform 4ae3c000.can can0: setting BTR=4d00 BRPE=0000
  [ 2054.663945] c_can_platform 4ae3c000.can can0: setting BTR=4d00 BRPE=0000
  [ 2057.861774] c_can_platform 4ae3c000.can can0: setting BTR=4d00 BRPE=0000
  [ 2065.521479] c_can_platform 4ae3c000.can can0: setting BTR=4d00 BRPE=0000
[02:50:19] Interface statistics:
5: can0: <NOARP,ECHO> mtu 16 qdisc fq_codel state DOWN mode DEFAULT group default qlen 10
    link/can  promiscuity 0 minmtu 0 maxmtu 0
    can <LOOPBACK> state STOPPED (berr-counter tx 0 rx 0) restart-ms 0
          bitrate 1000000 sample-point 0.750
          tq 50 prop-seg 7 phase-seg1 7 phase-seg2 5 sjw 1
          c_can: tseg1 2..16 tseg2 1..8 sjw 1..4 brp 1..1024 brp-inc 1
          clock 20000000
          re-started bus-errors arbit-lost error-warn error-pass bus-off
          0          0          0          0          0          0         numtxqueues 1 numrxqueues 1 gso_max_size 65536 gso_max_segs 65535
    RX: bytes  packets  errors  dropped overrun mcast
    1031627    131174   0       0       0       0
    TX: bytes  packets  errors  dropped carrier collsns
    1031627    131174   0       0       0       0

=== ERROR SUMMARY ===
echo_skb occupied errors: 0
0
RAMINIT timeout errors: 1
ENOBUFS errors: 0
0
IRQ 'nobody cared' errors: 0
0
====================

[02:50:21] ==========================================
[02:50:21] TEST 5: IRQ Handler Stress Test
[02:50:21] ==========================================
[02:50:21] Setting up CAN interface: can0
[SUCCESS] CAN interface can0 ready at 1000000 bps
[02:50:22] Starting IRQ monitoring...
[02:50:22] Launching extreme burst load...
[02:50:31] IRQ count: 8000 interrupts processed
[02:50:31] Checking for errors after: IRQ Handler Stress Test
[WARNING] Found kernel messages:
  [ 2049.835188] c_can_platform 4ae3c000.can can0: setting BTR=4d00 BRPE=0000
  [ 2050.153688] c_can_platform 4ae3c000.can can0: setting BTR=4d00 BRPE=0000
  [ 2050.474328] c_can_platform 4ae3c000.can can0: setting BTR=4d00 BRPE=0000
  [ 2050.795002] c_can_platform 4ae3c000.can can0: setting BTR=4d00 BRPE=0000
  [ 2051.124099] c_can_platform 4ae3c000.can can0: setting BTR=4d00 BRPE=0000
  [ 2051.444638] c_can_platform 4ae3c000.can can0: setting BTR=4d00 BRPE=0000
  [ 2051.764828] c_can_platform 4ae3c000.can can0: setting BTR=4d00 BRPE=0000
  [ 2052.087572] net can0: c_can_hw_raminit_wait_syscon: time out
  [ 2052.093584] c_can_platform 4ae3c000.can can0: setting BTR=4d00 BRPE=0000
  [ 2052.413876] c_can_platform 4ae3c000.can can0: setting BTR=4d00 BRPE=0000
  [ 2052.733956] c_can_platform 4ae3c000.can can0: setting BTR=4d00 BRPE=0000
  [ 2053.055166] c_can_platform 4ae3c000.can can0: setting BTR=4d00 BRPE=0000
  [ 2053.385334] c_can_platform 4ae3c000.can can0: setting BTR=4d00 BRPE=0000
  [ 2053.704011] c_can_platform 4ae3c000.can can0: setting BTR=4d00 BRPE=0000
  [ 2054.023699] c_can_platform 4ae3c000.can can0: setting BTR=4d00 BRPE=0000
  [ 2054.345783] c_can_platform 4ae3c000.can can0: setting BTR=4d00 BRPE=0000
  [ 2054.663945] c_can_platform 4ae3c000.can can0: setting BTR=4d00 BRPE=0000
  [ 2057.861774] c_can_platform 4ae3c000.can can0: setting BTR=4d00 BRPE=0000
  [ 2065.521479] c_can_platform 4ae3c000.can can0: setting BTR=4d00 BRPE=0000
  [ 2080.264050] c_can_platform 4ae3c000.can can0: setting BTR=4d00 BRPE=0000
[02:50:31] Interface statistics:
5: 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 <LOOPBACK> state ERROR-ACTIVE (berr-counter tx 0 rx 0) restart-ms 0
          bitrate 1000000 sample-point 0.750
          tq 50 prop-seg 7 phase-seg1 7 phase-seg2 5 sjw 1
          c_can: tseg1 2..16 tseg2 1..8 sjw 1..4 brp 1..1024 brp-inc 1
          clock 20000000
          re-started bus-errors arbit-lost error-warn error-pass bus-off
          0          0          0          0          0          0         numtxqueues 1 numrxqueues 1 gso_max_size 65536 gso_max_segs 65535
    RX: bytes  packets  errors  dropped overrun mcast
    1095627    139174   0       0       0       0
    TX: bytes  packets  errors  dropped carrier collsns
    1095627    139174   0       0       0       0

=== ERROR SUMMARY ===
echo_skb occupied errors: 0
0
RAMINIT timeout errors: 1
ENOBUFS errors: 0
0
IRQ 'nobody cared' errors: 0
0
====================

[02:50:34] ==========================================
[02:50:34] TEST 6: Combined Stress Test (All Issues)
[02:50:34] ==========================================
[02:50:34] Running combined stress test...
[02:50:34] Phase 1: High-rate TX...
[02:50:34] Setting up CAN interface: can0
[SUCCESS] CAN interface can0 ready at 1000000 bps
[02:50:38] Phase 2: Rapid restart cycles...
[02:50:39] Phase 3: Concurrent TX waves...
[02:50:39] Setting up CAN interface: can0
[SUCCESS] CAN interface can0 ready at 1000000 bps
[02:50:42] Combined stress test complete
[02:50:42] Checking for errors after: Combined Stress Test
[WARNING] Found kernel messages:
  [ 2053.385334] c_can_platform 4ae3c000.can can0: setting BTR=4d00 BRPE=0000
  [ 2053.704011] c_can_platform 4ae3c000.can can0: setting BTR=4d00 BRPE=0000
  [ 2054.023699] c_can_platform 4ae3c000.can can0: setting BTR=4d00 BRPE=0000
  [ 2054.345783] c_can_platform 4ae3c000.can can0: setting BTR=4d00 BRPE=0000
  [ 2054.663945] c_can_platform 4ae3c000.can can0: setting BTR=4d00 BRPE=0000
  [ 2057.861774] c_can_platform 4ae3c000.can can0: setting BTR=4d00 BRPE=0000
  [ 2065.521479] c_can_platform 4ae3c000.can can0: setting BTR=4d00 BRPE=0000
  [ 2080.264050] c_can_platform 4ae3c000.can can0: setting BTR=4d00 BRPE=0000
  [ 2092.731854] c_can_platform 4ae3c000.can can0: setting BTR=4d00 BRPE=0000
  [ 2096.445150] c_can_platform 4ae3c000.can can0: setting BTR=4d00 BRPE=0000
  [ 2096.583550] c_can_platform 4ae3c000.can can0: setting BTR=4d00 BRPE=0000
  [ 2096.713804] c_can_platform 4ae3c000.can can0: setting BTR=4d00 BRPE=0000
  [ 2096.853808] c_can_platform 4ae3c000.can can0: setting BTR=4d00 BRPE=0000
  [ 2096.993534] c_can_platform 4ae3c000.can can0: setting BTR=4d00 BRPE=0000
  [ 2097.133615] c_can_platform 4ae3c000.can can0: setting BTR=4d00 BRPE=0000
  [ 2097.273450] c_can_platform 4ae3c000.can can0: setting BTR=4d00 BRPE=0000
  [ 2097.414196] c_can_platform 4ae3c000.can can0: setting BTR=4d00 BRPE=0000
  [ 2097.553510] c_can_platform 4ae3c000.can can0: setting BTR=4d00 BRPE=0000
  [ 2097.684794] c_can_platform 4ae3c000.can can0: setting BTR=4d00 BRPE=0000
  [ 2098.060758] c_can_platform 4ae3c000.can can0: setting BTR=4d00 BRPE=0000
[02:50:42] Interface statistics:
5: 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 <LOOPBACK> state ERROR-ACTIVE (berr-counter tx 0 rx 0) restart-ms 0
          bitrate 1000000 sample-point 0.750
          tq 50 prop-seg 7 phase-seg1 7 phase-seg2 5 sjw 1
          c_can: tseg1 2..16 tseg2 1..8 sjw 1..4 brp 1..1024 brp-inc 1
          clock 20000000
          re-started bus-errors arbit-lost error-warn error-pass bus-off
          0          0          0          0          0          0         numtxqueues 1 numrxqueues 1 gso_max_size 65536 gso_max_segs 65535
    RX: bytes  packets  errors  dropped overrun mcast
    1155373    149556   0       0       0       0
    TX: bytes  packets  errors  dropped carrier collsns
    1155373    149556   0       0       0       0

=== ERROR SUMMARY ===
echo_skb occupied errors: 0
0
RAMINIT timeout errors: 1
ENOBUFS errors: 0
0
IRQ 'nobody cared' errors: 0
0
====================

[02:50:42] ==========================================
[02:50:42] ALL TESTS COMPLETE
[02:50:42] ==========================================
[02:50:42] Full log saved to: /tmp/can_stress_test_20200419_024938.log
=== FINAL ERROR SUMMARY ===
Total echo_skb errors: 0
0
Total RAMINIT timeouts: 1
Total ENOBUFS errors: 0
0
Total IRQ errors: 0
0
=========================
[02:53:28] Cleaning up background processes...
[02:53:29] Exiting...

I don't see many errors but I do get one single RAMINIT error on my side.

A couple of subsequent tests don't show any error (ran a total of 5 more tests):

=== ERROR SUMMARY ===
echo_skb occupied errors: 0
0
RAMINIT timeout errors: 0
0
ENOBUFS errors: 0
0
IRQ 'nobody cared' errors: 0
0
====================

[02:29:50] ==========================================
[02:29:50] ALL TESTS COMPLETE
[02:29:50] ==========================================
[02:29:50] Full log saved to: /tmp/can_stress_test_20200419_022845.log

=== FINAL ERROR SUMMARY ===
Total echo_skb errors: 0
0
Total RAMINIT timeouts: 0
0
Total ENOBUFS errors: 0
0
Total IRQ errors: 0
0
=========================

Press Enter to continue...

===========================================
   CAN Stress Test Suite for AM5716
===========================================
Interface: can0
Bitrate: 1000000
Log file: /tmp/can_stress_test_20200419_022845.log

Not sure what made the first test come out with one error. have not been able to re-create.

-Josue

0 Kevin Peng 3 months ago in reply to Josue Zamitiz-Ayala

TI__Expert 4998 points

Hi Josue,

Customer did the following tests in the weekend:

1: Based on SDK 9.3, customer attempted to rollback the CAN driver and conducted continuous testing for approximately 17 hours; the echo_skb issue no longer appeared. Through repeated USB insertion and removal to verify the "nobody cares" IRQ problem, it also did not manifest. This indicates it is significantly more stable than SDK9.3, however RAMINIT timeout issues still occur frequently.

2: The stress test results are identical for both single device and dual-device direct connections; both are prone to reproducing the RAMINIT timeout problem.

3: The timeout issue occurs in the second call of c_can_hw_raminit_wait_syscon() within the function chain c_can_open()->c_can_reset_ram()->c_can_hw_raminit_syscon(enable) (i.e., inside the enable = true condition block). Attempting to increase the timeout threshold of c_can_hw_raminit_wait_syscon() to 5000us did not resolve the issue. It appears the problem is caused by DCAN1_RAMINIT_DONE in the CTRL_CORE_CONTROL_IO_2 register not being ready in time, and no detailed explanation regarding the time required for this operation was found in the TRM manual.

The diff code to rollback CAN driver on SDK9.3 is below:

diff --git a/drivers/net/can/c_can/c_can.h b/drivers/net/can/c_can/c_can.h
index 643507777..f508e6a6d 100644
--- a/drivers/net/can/c_can/c_can.h
+++ b/drivers/net/can/c_can/c_can.h
@@ -197,6 +197,7 @@ struct c_can_priv {
    unsigned int msg_obj_tx_first;
    unsigned int msg_obj_tx_last;
    u32 msg_obj_rx_mask;
+   atomic_t tx_active;
    atomic_t sie_pending;
    unsigned long tx_dir;
    int last_status;
@@ -211,7 +212,6 @@ struct c_can_priv {
    struct c_can_raminit raminit_sys;   /* RAMINIT via syscon regmap */
    void (*raminit)(const struct c_can_priv *priv, bool enable);
    u32 comm_rcv_high;
-   raw_spinlock_t echo_skb_lock;   /* Protects echo_skb array access for RT kernel */
 };
 
 struct net_device *alloc_c_can_dev(int msg_obj_num);
diff --git a/drivers/net/can/c_can/c_can_main.c b/drivers/net/can/c_can/c_can_main.c
index 46f09c92a..68f78a9b1 100644
--- a/drivers/net/can/c_can/c_can_main.c
+++ b/drivers/net/can/c_can/c_can_main.c
@@ -454,35 +454,32 @@ static netdev_tx_t c_can_start_xmit(struct sk_buff *skb,
 {
    struct can_frame *frame = (struct can_frame *)skb->data;
    struct c_can_priv *priv = netdev_priv(dev);
-   struct c_can_tx_ring *tx_ring = &priv->tx;
-   u32 idx, obj, cmd = IF_COMM_TX;
-   unsigned long flags;
+   u32 idx, obj;
 
    if (can_dev_dropped_skb(dev, skb))
        return NETDEV_TX_OK;
+   /*
+    * This is not a FIFO. C/D_CAN sends out the buffers
+    * prioritized. The lowest buffer number wins.
+    */
+   idx = fls(atomic_read(&priv->tx_active));
+   obj = idx + priv->msg_obj_tx_first;
 
-   if (c_can_tx_busy(priv, tx_ring))
-       return NETDEV_TX_BUSY;
-
-   idx = c_can_get_tx_head(tx_ring);
-   tx_ring->head++;
-   if (c_can_get_tx_free(priv, tx_ring) == 0)
+   /* If this is the last buffer, stop the xmit queue */
+   if (idx == priv->msg_obj_tx_num - 1)
        netif_stop_queue(dev);
 
-   if (idx < c_can_get_tx_tail(tx_ring))
-       cmd &= ~IF_COMM_TXRQST; /* Cache the message */
-
    /* Store the message in the interface so we can call
     * can_put_echo_skb(). We must do this before we enable
     * transmit as we might race against do_tx().
     */
    c_can_setup_tx_object(dev, IF_TX, frame, idx);
-   /* Minimal lock hold time - only during echo_skb write */
-   raw_spin_lock_irqsave(&priv->echo_skb_lock, flags);
-   can_put_echo_skb(skb, dev, idx, 0);
-   raw_spin_unlock_irqrestore(&priv->echo_skb_lock, flags);
-   obj = idx + priv->msg_obj_tx_first;
-   c_can_object_put(dev, IF_TX, obj, cmd);
+   can_put_echo_skb(skb, dev, idx, frame->len);
+
+   /* Update the active bits */
+   atomic_add((1 << idx), &priv->tx_active);
+   /* Start transmission */
+   c_can_object_put(dev, IF_TX, obj, IF_COMM_TX);
 
    return NETDEV_TX_OK;
 }
@@ -593,7 +590,6 @@ static int c_can_software_reset(struct net_device *dev)
 static int c_can_chip_config(struct net_device *dev)
 {
    struct c_can_priv *priv = netdev_priv(dev);
-   struct c_can_tx_ring *tx_ring = &priv->tx;
    int err;
 
    err = c_can_software_reset(dev);
@@ -625,8 +621,7 @@ static int c_can_chip_config(struct net_device *dev)
    priv->write_reg(priv, C_CAN_STS_REG, LEC_UNUSED);
 
    /* Clear all internal status */
-   tx_ring->head = 0;
-   tx_ring->tail = 0;
+   atomic_set(&priv->tx_active, 0);
    priv->tx_dir = 0;
 
    /* set bittiming params */
@@ -724,15 +719,14 @@ static int c_can_get_berr_counter(const struct net_device *dev,
 static void c_can_do_tx(struct net_device *dev)
 {
    struct c_can_priv *priv = netdev_priv(dev);
-   struct c_can_tx_ring *tx_ring = &priv->tx;
    struct net_device_stats *stats = &dev->stats;
-   u32 idx, obj, pkts = 0, bytes = 0, pend;
-   u8 tail;
+   u32 idx, obj, pkts = 0, bytes = 0, pend, clr;
 
    if (priv->msg_obj_tx_last > 32)
        pend = priv->read_reg32(priv, C_CAN_INTPND3_REG);
    else
        pend = priv->read_reg(priv, C_CAN_INTPND2_REG);
+   clr = pend;
 
    while ((idx = ffs(pend))) {
        idx--;
@@ -744,37 +738,19 @@ static void c_can_do_tx(struct net_device *dev)
         * NAPI. We are not transmitting.
         */
        c_can_inval_tx_object(dev, IF_NAPI, obj);
-       /* Minimal lock hold time - only during echo_skb read */
-       raw_spin_lock(&priv->echo_skb_lock);
        bytes += can_get_echo_skb(dev, idx, NULL);
-       raw_spin_unlock(&priv->echo_skb_lock);
        pkts++;
    }
 
-   if (!pkts)
-       return;
+   /* Clear the bits in the tx_active mask */
+   atomic_sub(clr, &priv->tx_active);
 
-   tx_ring->tail += pkts;
-   if (c_can_get_tx_free(priv, tx_ring)) {
-       /* Make sure that anybody stopping the queue after
-        * this sees the new tx_ring->tail.
-        */
-       smp_mb();
-       netif_wake_queue(priv->dev);
-   }
-
-   stats->tx_bytes += bytes;
-   stats->tx_packets += pkts;
-
-   tail = c_can_get_tx_tail(tx_ring);
-   if (priv->type == BOSCH_D_CAN && tail == 0) {
-       u8 head = c_can_get_tx_head(tx_ring);
+   if (clr & (1 << (priv->msg_obj_tx_num - 1)))
+       netif_wake_queue(dev);
 
-       /* Start transmission for all cached messages */
-       for (idx = tail; idx < head; idx++) {
-           obj = idx + priv->msg_obj_tx_first;
-           c_can_object_put(dev, IF_NAPI, obj, IF_COMM_TXRQST);
-       }
+   if (pkts) {
+       stats->tx_bytes += bytes;
+       stats->tx_packets += pkts;
    }
 }
 
@@ -833,9 +809,7 @@ static int c_can_read_objects(struct net_device *dev, struct c_can_priv *priv,
        ctrl = priv->read_reg(priv, C_CAN_IFACE(MSGCTRL_REG, IF_NAPI));
 
        if (ctrl & IF_MCONT_MSGLST) {
-           int n;
-
-           n = c_can_handle_lost_msg_obj(dev, IF_NAPI, obj, ctrl);
+           int n = c_can_handle_lost_msg_obj(dev, IF_NAPI, obj, ctrl);
 
            pkts += n;
            quota -= n;
@@ -1231,7 +1205,6 @@ struct net_device *alloc_c_can_dev(int msg_obj_num)
        return NULL;
 
    priv = netdev_priv(dev);
-   raw_spin_lock_init(&priv->echo_skb_lock);
    priv->msg_obj_num = msg_obj_num;
    priv->msg_obj_rx_num = msg_obj_num - msg_obj_tx_num;
    priv->msg_obj_rx_first = 1;
diff --git a/drivers/net/can/c_can/c_can_platform.c b/drivers/net/can/c_can/c_can_platform.c
index 86e95e9d6..56fa46805 100644
--- a/drivers/net/can/c_can/c_can_platform.c
+++ b/drivers/net/can/c_can/c_can_platform.c
@@ -489,8 +489,8 @@ static struct platform_driver c_can_plat_driver = {
    },
    .probe = c_can_plat_probe,
    .remove = c_can_plat_remove,
-   .suspend = c_can_suspend,
-   .resume = c_can_resume,
+   .suspend = NULL,
+   .resume = NULL,
    .id_table = c_can_id_table,
 };

Could you help analyze customer's rollback code and test on your side please? It seems only the RAMINIT timeout left need to be solved based on this solution.

Thanks,

Kevin

0 Kevin Peng 3 months ago in reply to Josue Zamitiz-Ayala

TI__Expert 4998 points

Also re-share the diff code for the stress test script at customer side (customer did the following minor modifications mainly to adjust the location of the CAN interrupt in /proc/interrupts and shortening the sleep time to improve testing efficiency), could you please review if the diff code here is reasonable or not, just want to make it sure the difference of phenomenon about RAMINIT timeout is not due to the stress test itself.

diff --git a/can_stress_test.sh b/can_stress_test.sh
index 2f69080..1e22e13 100644
--- a/can_stress_test.sh
+++ b/can_stress_test.sh
@@ -4,15 +4,15 @@
 # Tests for Issues: ENOBUFS, RAMINIT timeout, echo_skb race, IRQ problems
 #
 # Usage: ./can_stress_test.sh [interface]
-# Example: ./can_stress_test.sh main_dcan1
+# Example: ./can_stress_test.sh can0
 #
 
 set -e
 
 # Configuration
-CAN_IFACE="${1:-main_dcan1}"
+CAN_IFACE="${1:-can0}"
 BITRATE=1000000
-LOG_FILE="/tmp/can_stress_test_$(date +%Y%m%d_%H%M%S).log"
+LOG_FILE="/home/root/can/log/can_stress_test_$(date +%Y%m%d_%H%M%S).log"
 
 # Colors for output
 RED='\033[0;31m'
@@ -61,7 +61,7 @@ check_errors() {
     log "Checking for errors after: $test_name"
 
     # Get current dmesg
-    local errors=$(dmesg | tail -50 | grep -iE "can|echo_skb|raminit|irq.*154|ENOBUFS|nobody cared|time out|occupied" | tail -20)
+    local errors=$(dmesg | tail -50 | grep -iE "can|echo_skb|raminit|irq.*91|ENOBUFS|nobody cared|time out|occupied" | tail -20)
 
     if [ -n "$errors" ]; then
         log_warning "Found kernel messages:"
@@ -201,9 +201,9 @@ test_sustained_load() {
     log "Transmitters running... monitoring for 10 seconds"
 
     # Monitor interrupt count
-    local irq_start=$(cat /proc/interrupts | grep 154 | awk '{print $2}')
+    local irq_start=$(cat /proc/interrupts | grep "91:" | awk '{print $2}')
     sleep 10
-    local irq_end=$(cat /proc/interrupts | grep 154 | awk '{print $2}')
+    local irq_end=$(cat /proc/interrupts | grep "91:" | awk '{print $2}')
     local irq_count=$((irq_end - irq_start))
 
     log "IRQ count during test: $irq_count"
@@ -223,7 +223,7 @@ test_irq_stress() {
     log "Starting IRQ monitoring..."
 
     # Get initial IRQ count
-    local irq_before=$(cat /proc/interrupts | grep 154 | awk '{print $2}')
+    local irq_before=$(cat /proc/interrupts | grep "91:" | awk '{print $2}')
 
     log "Launching extreme burst load..."
 
@@ -237,7 +237,7 @@ test_irq_stress() {
     done
 
     # Get final IRQ count
-    local irq_after=$(cat /proc/interrupts | grep 154 | awk '{print $2}')
+    local irq_after=$(cat /proc/interrupts | grep "91:" | awk '{print $2}')
     local irq_delta=$((irq_after - irq_before))
 
     log "IRQ count: $irq_delta interrupts processed"
@@ -312,15 +312,15 @@ run_all_tests() {
     log "=========================================="
 
     test_tx_buffer_exhaustion
-    sleep 2
+    sleep 0.2
     test_raminit_timeout
-    sleep 2
+    sleep 0.2
     test_echo_skb_race
-    sleep 2
+    sleep 0.2
     test_sustained_load
-    sleep 2
+    sleep 0.2
     test_irq_stress
-    sleep 2
+    sleep 0.2
     test_combined_stress
 
     log "=========================================="
@@ -344,13 +344,13 @@ show_status() {
     ip -s -d link show "$CAN_IFACE"
     echo ""
     log "Interrupt Statistics:"
-    cat /proc/interrupts | grep -E "CPU|154"
+    cat /proc/interrupts | grep -E "CPU|91:"
 }
 
 show_dmesg_errors() {
     echo ""
     log "Recent CAN-related kernel messages:"
-    dmesg | tail -50 | grep -iE "can|echo_skb|raminit|irq.*154|ENOBUFS|nobody cared|time out|occupied" || echo "No errors found"
+    dmesg | tail -50 | grep -iE "can|echo_skb|raminit|irq.*91|ENOBUFS|nobody cared|time out|occupied" || echo "No errors found"
 }
 
 # Trap Ctrl+C
@@ -375,8 +375,9 @@ done
 # Interactive mode if no arguments
 if [ $# -lt 2 ]; then
     while true; do
-        show_menu
-        read -p "Select test (0-9): " choice
+        # show_menu
+        # read -p "Select test (0-9): " choice
+        choice=7
         echo ""
 
         case $choice in
@@ -398,7 +399,7 @@ if [ $# -lt 2 ]; then
         esac
 
         echo ""
-        read -p "Press Enter to continue..."
+        # read -p "Press Enter to continue..."
     done
 fi

0 Josue Zamitiz-Ayala 3 months ago in reply to Kevin Peng

TI__Mastermind 40246 points

Hello Kevin,

Kevin Peng said:
please review if the diff code here is reasonable or not

The changes are proper and reasonable. I do not see any issue with these. I already tested the time changes on my side with consistent results.

Kevin Peng said:
Could you help analyze customer's rollback code

I am happy to hear that we are getting closer, customer beat me to finishing the roll-back (I started on Friday and meant to finish today). The changes look fine, with one concern on my side:

diff --git a/drivers/net/can/c_can/c_can_platform.c b/drivers/net/can/c_can/c_can_platform.c
index 86e95e9d6..56fa46805 100644
--- a/drivers/net/can/c_can/c_can_platform.c
+++ b/drivers/net/can/c_can/c_can_platform.c
@@ -489,8 +489,8 @@ static struct platform_driver c_can_plat_driver = {
},
.probe = c_can_plat_probe,
.remove = c_can_plat_remove,
- .suspend = c_can_suspend,
- .resume = c_can_resume,
+ .suspend = NULL,
+ .resume = NULL,
.id_table = c_can_id_table,
};

Why are .suspend and .resume made NULL?

This RAMINIT issue is a tough one, it could potentially not be related to the CAN driver and more likely related to a different subsystem (Since the code is Identical in c_can_platform.c for c_can_hw_raminit_wait_syscon(), etc).

Why does it work in 4.19 and not in 6.1?

Another curve-ball on my side is RAMINIT issue was not repeatable for me. (Caveat, I only have tested in Loopback mode with one single EVM).

Given customers investigation with the registers and some info I have been looking at (link), it seems like there have been changes in the RT Linux that make spinlocks become preemtible in RT Linux, therefore one needs to use raw_spinlocks to ensure atomic low level operations like this register read. Could you ask the customer to try the following patch:

https://e2e.ti.com/cfs-file/__key/communityserver-discussions-components-files/791/use_5F00_raw_5F00_spinlock.patch

The driver for regmap alrady has the raw spinlock option so we are adding it to take this path. Hopefully this helps.

I tested my patch along with the customers patch above and these are my results:

Select test (0-9): 6

[22:37:51] ==========================================
[22:37:51] TEST 6: Combined Stress Test (All Issues)
[22:37:51] ==========================================
[22:37:51] Running combined stress test...
[22:37:51] Phase 1: High-rate TX...
[22:37:51] Setting up CAN interface: main_dcan1
[  107.513183] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
[  107.527252] IPv6: ADDRCONF(NETDEV_CHANGE): main_dcan1: link becomes ready
[SUCCESS] CAN interface main_dcan1 ready at 1000000 bps
write: No buffer space available
write: No buffer space available
write: No buffer space available
write: No buffer space available
write: No buffer space available
write: No buffer space available
write: No buffer space available
write: No buffer space available
[22:37:55] Phase 2: Rapid restart cycles...
[  111.176269] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
[  111.276306] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
[  111.376312] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
[  111.476287] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
[  111.585449] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
[  111.694946] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
[  111.799316] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
[  111.916351] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
[  112.028656] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
[  112.136474] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
[22:37:56] Phase 3: Concurrent TX waves...
[22:37:56] Setting up CAN interface: main_dcan1
[  112.479553] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
[SUCCESS] CAN interface main_dcan1 ready at 1000000 bps
write: No buffer space available
write: No buffer space available
write: No buffer space available
write: No buffer space available
write: No buffer space available
write: No buffer space available
write: No buffer space available
write: No buffer space available
write: No buffer space available
write: No buffer space available
write: No buffer space available
[22:37:58] Combined stress test complete
[22:37:58] Checking for errors after: Combined Stress Test
[WARNING] Found kernel messages:
  [  107.513183] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [  107.527252] IPv6: ADDRCONF(NETDEV_CHANGE): main_dcan1: link becomes ready
  [  111.176269] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [  111.276306] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [  111.376312] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [  111.476287] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [  111.585449] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [  111.694946] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [  111.799316] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [  111.916351] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [  112.028656] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [  112.136474] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
  [  112.479553] c_can_platform 4ae3c000.can main_dcan1: setting BTR=4d00 BRPE=0000
[22:37:58] Interface statistics:
5: main_dcan1: <NOARP,UP,LOWER_UP,ECHO> mtu 16 qdisc pfifo_fast state UP mode DEFAULT group default qlen 10
    link/can  promiscuity 0 minmtu 0 maxmtu 0
    can <LOOPBACK> state ERROR-ACTIVE (berr-counter tx 0 rx 0) restart-ms 0
          bitrate 1000000 sample-point 0.750
          tq 50 prop-seg 7 phase-seg1 7 phase-seg2 5 sjw 1 brp 1
          c_can: tseg1 2..16 tseg2 1..8 sjw 1..4 brp 1..1024 brp_inc 1
          clock 20000000
          re-started bus-errors arbit-lost error-warn error-pass bus-off
          0          0          0          0          0          0         numtxqueues 1 numrxqueues 1 gso_max_size 65536 gso_max_segs 65535 parentbus platform pa
    RX:  bytes packets errors dropped  missed   mcast
         13818    2392      0       0       0       0
    TX:  bytes packets errors dropped carrier collsns
         13818    2392      0       0       0       0

=== ERROR SUMMARY ===
echo_skb occupied errors: 0
0
RAMINIT timeout errors: 0
0
ENOBUFS errors: 0
0
IRQ 'nobody cared' errors: 0
0
====================

Best,

Josue

0 Kevin Peng 3 months ago in reply to Josue Zamitiz-Ayala

TI__Expert 4998 points

Hi Josue,

The .suspend and .resume fields are set to NULL to avoid the DCAN Initialization Sequence issue mentioned in the errata manual. Since customer does not consider power-saving scenarios and will operate at maximum performance with full power consumption, these two fields are set to NULL following the logic of not configuring CONFIG_PM.

Customer has tested use_raw_spinlock.patch, but there is no any improvement on the timeout issues.

Customer now plans to apply this CAN driver rollback code to their real application product firstly as a workaround, but they still need us continue investigate this timeout issue and provide them with reasonable explanation & solutions soon.

Thanks,

Kevin

0 Josue Zamitiz-Ayala 3 months ago in reply to Kevin Peng

TI__Mastermind 40246 points

Hello Kevin,

Kevin Peng said:
Customer now plans to apply this CAN driver rollback code to their real application product firstly as a workaround, but they still need us continue investigate this timeout issue and provide them with reasonable explanation & solutions soon.

As I mentioned above,

Josue Zamitiz-Ayala said:
Another curve-ball on my side is RAMINIT issue was not repeatable for me.

This will be hard since we cannot recreate this issue locally. Can the customer add a print to the code i linked here to make sure the code is taking the raw_spinlock pathway?

Josue Zamitiz-Ayala said:
regmap

Above you mentioned that the customer sees these RAMINIT issues even in the loopback mode without connecting to another board, is this correct?

I am aligned with the roll-back changes, they make sense. I have another patch that could be useful in case what I am assuming is happening is actually happening. Let me know what the customers discovers with regards to the raw_spinlock patch.

Otherwise they can try this patch:

https://e2e.ti.com/cfs-file/__key/communityserver-discussions-components-files/791/jiffies.patch

I am thinking preemption is actually keeping the counter in this function from actually being one µs, therefore one iteration takes longer, creating the timeouts. This patch makes it "wall clock" dependent instead on the counter and therefore preemption will not be creating RAMINIT timeouts.

LMK.

-Josue

0 Josue Zamitiz-Ayala 2 months ago in reply to Josue Zamitiz-Ayala

TI__Mastermind 40246 points

Ping for updates.

0 Kevin Peng 2 months ago in reply to Josue Zamitiz-Ayala

TI__Expert 4998 points

Hi Josue,

Thanks for asking. I just reached to customer, their feedback is for using their rollback code we discussed in the past, it could already solved most of CAN issues, only remaining RAMINIT timeout. So this is not that urgent comparing to other AM57 issues they are working currently, they will try their best to solve the other AM57 issues and come back to solve this RAMINIT timeout issue soon.

I will keep tracking with customer about their progress, and let them test your patch shared above and get back.

Thanks,

Kevin

Processors

Processors forum

AM5716: CAN communication issues