search

hartkopp / can-isotp

Linux Kernel Module for ISO 15765-2:2016 CAN transport protocol PLEASE NOTE: This module is part of the mainline Linux kernel since version 5.10
Other
239 stars 69 forks source link

~5ms delay between consecutive frames #23

Closed zzincubus closed 3 years ago

zzincubus commented 4 years ago

There appears to be a ~5ms delay introduced between consecutive frames when sending a large message, and the ECU has responded with a st_min of 0 (30 00 00).

This seems to be around the check for so->tx_gap (which was so->tx_gap.tv64). iosotp_tx_burst. Have made a quick change to look at the st_min rather than the tx_gap which is working for now. Not a kernel expert so unsure if this would have any side effects.

hartkopp commented 4 years ago

Can you send a candump log (candump -L canX) output? Are you using the CAN_ISOTP_FORCE_TXSTMIN flag in the can_isotp_options ?

zzincubus commented 4 years ago

The CAN_ISOTP_FORCE_TXSTMIN flag was not set, and the below shows some debug from the module, can get raw can log next week if required.

Feb 12 11:19:39 LINUX11 kernel: [ 112.102963] peak_usb 1-14:1.0 can0: setting BTR0=0x01 BTR1=0x1c Feb 12 11:19:39 LINUX11 kernel: [ 112.115672] IPv6: ADDRCONF(NETDEV_CHANGE): can0: link becomes ready Feb 12 11:19:39 LINUX11 kernel: [ 112.118186] can: isotp protocol (rev 20200115 alpha) Feb 12 11:20:50 LINUX11 kernel: [ 182.881660] peak_usb 1-14:1.0 can0: setting BTR0=0x01 BTR1=0x1c Feb 12 11:24:26 LINUX11 kernel: [ 399.055074] CIFS: Attempting to mount //S-BIR3341-V1/linux Feb 12 11:28:23 LINUX11 kernel: [ 636.310910] barcode_mgr (6358) used greatest stack depth: 5544 bytes left Feb 12 11:28:24 LINUX11 kernel: [ 637.647914] peak_usb 1-14:1.0 can0: setting BTR0=0x01 BTR1=0x1c Feb 12 11:28:24 LINUX11 kernel: [ 637.665909] can: isotp protocol (rev 20200115 alpha) Feb 12 11:30:01 LINUX11 kernel: [ 734.251611] peak_usb 1-14:1.0 can0: setting BTR0=0x01 BTR1=0x1c Feb 12 11:30:01 LINUX11 kernel: [ 734.266233] can: isotp protocol (rev 20200212 alpha) Feb 12 11:31:15 LINUX11 kernel: [ 808.730185] peak_usb 1-14:1.0 can0: setting BTR0=0x01 BTR1=0x1c Feb 12 11:31:15 LINUX11 kernel: [ 808.748593] can: isotp protocol (rev 20200212 alpha) Feb 12 11:32:16 LINUX11 kernel: [ 869.442777] peak_usb 1-14:1.0 can0: setting BTR0=0x01 BTR1=0x1c Feb 12 11:32:23 LINUX11 kernel: [ 876.646818] can-isotp: isotp_sendmsg: starting txtimer for fc Feb 12 11:32:23 LINUX11 kernel: [ 876.649901] can-isotp: isotp_rcv_fc: FC frame: FS 0, BS 0, STmin 0x00, tx_gap 4448256 Feb 12 11:32:23 LINUX11 kernel: [ 876.649905] can-isotp: isotp_rcv_fc: starting txtimer for sending Feb 12 11:32:23 LINUX11 kernel: [ 876.654510] can-isotp: isotp_tx_timer_tsklet: next pdu to send. Feb 12 11:32:23 LINUX11 kernel: [ 876.654529] can-isotp: isotp_tx_timer_tsklet: we are done Feb 12 11:32:24 LINUX11 kernel: [ 877.189778] can-isotp: isotp_sendmsg: starting txtimer for fc Feb 12 11:32:24 LINUX11 kernel: [ 877.192186] can-isotp: isotp_rcv_fc: FC frame: FS 0, BS 0, STmin 0x00, tx_gap 4448256 Feb 12 11:32:24 LINUX11 kernel: [ 877.192187] can-isotp: isotp_rcv_fc: starting txtimer for sending Feb 12 11:32:24 LINUX11 kernel: [ 877.196637] can-isotp: isotp_tx_timer_tsklet: next pdu to send. Feb 12 11:32:24 LINUX11 kernel: [ 877.201089] can-isotp: isotp_tx_timer_tsklet: next pdu to send. Feb 12 11:32:24 LINUX11 kernel: [ 877.205539] can-isotp: isotp_tx_timer_tsklet: next pdu to send. Feb 12 11:32:24 LINUX11 kernel: [ 877.209991] can-isotp: isotp_tx_timer_tsklet: next pdu to send. Feb 12 11:32:24 LINUX11 kernel: [ 877.214478] can-isotp: isotp_tx_timer_tsklet: next pdu to send. Feb 12 11:32:24 LINUX11 kernel: [ 877.219101] can-isotp: isotp_tx_timer_tsklet: next pdu to send. Feb 12 11:32:24 LINUX11 kernel: [ 877.223693] can-isotp: isotp_tx_timer_tsklet: next pdu to send. Feb 12 11:32:24 LINUX11 kernel: [ 877.228266] can-isotp: isotp_tx_timer_tsklet: next pdu to send. Feb 12 11:32:24 LINUX11 kernel: [ 877.232738] can-isotp: isotp_tx_timer_tsklet: next pdu to send. Feb 12 11:32:24 LINUX11 kernel: [ 877.237366] can-isotp: isotp_tx_timer_tsklet: next pdu to send. Feb 12 11:32:24 LINUX11 kernel: [ 877.241843] can-isotp: isotp_tx_timer_tsklet: next pdu to send. Feb 12 11:32:24 LINUX11 kernel: [ 877.246562] can-isotp: isotp_tx_timer_tsklet: next pdu to send. Feb 12 11:32:24 LINUX11 kernel: [ 877.251272] can-isotp: isotp_tx_timer_tsklet: next pdu to send. Feb 12 11:32:24 LINUX11 kernel: [ 877.255978] can-isotp: isotp_tx_timer_tsklet: next pdu to send. Feb 12 11:32:24 LINUX11 kernel: [ 877.260647] can-isotp: isotp_tx_timer_tsklet: next pdu to send. Feb 12 11:32:24 LINUX11 kernel: [ 877.265344] can-isotp: isotp_tx_timer_tsklet: next pdu to send. Feb 12 11:32:24 LINUX11 kernel: [ 877.269969] can-isotp: isotp_tx_timer_tsklet: next pdu to send. Feb 12 11:32:24 LINUX11 kernel: [ 877.274664] can-isotp: isotp_tx_timer_tsklet: next pdu to send. Feb 12 11:32:24 LINUX11 kernel: [ 877.279358] can-isotp: isotp_tx_timer_tsklet: next pdu to send. Feb 12 11:32:24 LINUX11 kernel: [ 877.283843] can-isotp: isotp_tx_timer_tsklet: next pdu to send. Feb 12 11:32:24 LINUX11 kernel: [ 877.288516] can-isotp: isotp_tx_timer_tsklet: next pdu to send.

hartkopp commented 4 years ago

When you provide the struct can_isotp_options with the CAN_ISOTP_OPTS sockopt there is a field for frame_txtime. I assume that you pass the '4448256' value here - maybe through an uninitialized memory.