Xavier SPI in slave mode keep reporting CS_INACTIVE error

Hi,
We are using spi0 to communicate with external FPGA in slave mode. The FPGA keep sending 884 bytes a frame in 5ms period(mode: 8bit, 5Mbps,SPI_MODE_0). And on soc side spidev test module read and print out the received data. We found some of the data’s uncorectly receive in random. Further debug found FIFO status always report a CS_INACTIVE error. But the HW signal seems very clean. After run the jetson_clocks script, Errors will be reduced a lot.How did this happen? Could you help to give some guidance also further debug method? Thanks!

jetpack verison: 4.4

log:
[ 3310.980253] spi_master spi0: Before DMA EN
[ 3310.980258] spi_master spi0: CMD[03f01027]: Sl M0 CS0 [HHHH] MSB MSb Rx Pa 8b TRANS[00ff0374]:BSY I:255 B:884
FIFO[00400005]:RxF:0 TxE:64 Err RxSTA[E] TxSTA[E]DMA[00000000]: RxTr:0 TxTr:0 B:883
[ 3310.981042] spi_master spi0: @isr
[ 3310.981052] spi_master spi0: CMD[03f01027]: Sl M0 CS0 [HHHH] MSB MSb Rx Pa 8b TRANS[40ff01c9]:RDY I:255 B:457
FIFO[80400005]:RxF:0 TxE:64 Err[Cs] RxSTA[E] TxSTA[E]DMA[00000000]: RxTr:0 TxTr:0 B:883
[ 3310.981095] spi_master spi0: transferred[457] != requested[884]
[ 3310.981231] spi_master spi0: CMD[03f01027]: Sl M0 CS0 [HHHH] MSB MSb Rx Pa 8b TRANS[00ff01c9]:BSY I:255 B:457
FIFO[00400005]:RxF:0 TxE:64 Err RxSTA[E] TxSTA[E]DMA[00000000]: RxTr:0 TxTr:0 B:883
[ 3310.981569] spi_master spi0: rx-dma-err [status:80400005]
[ 3310.981688] spi_master spi0: CMD[03f01027]: Sl M0 CS0 [HHHH] MSB MSb Rx Pa 8b TRANS[00ff01c9]:BSY I:255 B:457
FIFO[00400005]:RxF:0 TxE:64 Err RxSTA[E] TxSTA[E]DMA[00000000]: RxTr:0 TxTr:0 B:883
[ 3310.982020] spi_master spi0: failed to transfer one message from queue

pad config as follows:
busybox devmem 0x0243d040 w 0x00000450 #sck
busybox devmem 0x0243d020 w 0x00000450 #miso
busybox devmem 0x0243d058 w 0x00000450 #mosi
busybox devmem 0x0243d010 w 0x00000448 #cs0
busybox devmem 0x0243d050 w 0x00000448 #cs1

Could you check after below command.

sudo nvpmodel -m 0
sudo jetson_clocks

I have checked after run this command you mentioned, the errors may reduced a lot.
I have replicated this errors on the dev board, two dev board connect with spi1.

What’s the speed? What’s if reduce transfer speed?

We use 5000000 speed, the max speed for xavier is 65000000 according datasheet, and real bandwidth is only 884*200=1.35Mbps.
If I increase the time interval to 20ms, the error also reduced a lot.
the irq not lose from the log, why xavier think the cs input is inactive?

Did you using spidev_test to test it. What’s the command? Did it able reproduce with device loopback test?

I have tested it between two dev board, one for master and other is slave.
The test program is changed from spidev_test.c, for master just write, for slave just read.

What we verify the master/slave by spidev_test like below link.
Could you check if any parameter to reproduce by device loopback.

@ShaneCCC

write program for master:

#include <stdint.h>
#include <unistd.h>
#include <stdio.h>
#include <stdlib.h>
#include <string.h>
#include <getopt.h>
#include <fcntl.h>
#include <sys/ioctl.h>
#include <linux/ioctl.h>
#include <sys/stat.h>
#include <linux/types.h>
#include <linux/spi/spidev.h>

#define ARRAY_SIZE(a) (sizeof(a) / sizeof((a)[0]))
#define DEFAULT_SIZE 8192

static void pabort(const char *s)
{
	perror(s);
	abort();
}

static const char *device = "/dev/spidev0.0";
static uint32_t mode=SPI_MODE_0;
static uint8_t bits = 8;
static uint32_t speed = 5000000;
static int tx_len = 884;
static uint32_t count=1;

uint8_t default_tx[DEFAULT_SIZE] = {0};

static void hex_dump(const void *src, size_t length, char *prefix)
{
        const unsigned char *address = src;
	size_t ll=length;

        printf("%s(0x%x) | ", prefix, count);
        while (length-- > 0) {
		if((ll-length)>6 && *address == 0)
			*address++;
		else
                	printf("%02X ", *address++);
        }
        printf("\n");
}

static void transfer(int fd)
{
	int ret;
	struct spi_ioc_transfer tr = {
		.rx_buf = 0,
		.tx_buf = (unsigned long)default_tx,
		.len = tx_len,
		.speed_hz = speed,
		.bits_per_word = bits,
	};

	ret = ioctl(fd, SPI_IOC_MESSAGE(1), &tr);
	if (ret < 1)
		pabort("can't send spi message");


	hex_dump(default_tx, tx_len, "TX");
}

int main(int argc, char *argv[])
{
	int ret = 0;
	int fd;

	fd = open(device, O_RDWR);
	if (fd < 0)
		pabort("can't open device");

	/*
	 * spi mode
	 */
	ret = ioctl(fd, SPI_IOC_WR_MODE32, &mode);
	if (ret == -1)
		pabort("can't get spi mode");
	ret = ioctl(fd, SPI_IOC_RD_MODE32, &mode);
	if (ret == -1)
		pabort("can't get spi mode");

	/*
	 * bits per word
	 */
	ret = ioctl(fd, SPI_IOC_WR_BITS_PER_WORD, &bits);
	if (ret == -1)
		pabort("can't set bits per word");

	ret = ioctl(fd, SPI_IOC_RD_BITS_PER_WORD, &bits);
	if (ret == -1)
		pabort("can't get bits per word");

	/*
	 * max speed hz
	 */
	ret = ioctl(fd, SPI_IOC_WR_MAX_SPEED_HZ, &speed);
	if (ret == -1)
		pabort("can't set max speed hz");

	ret = ioctl(fd, SPI_IOC_RD_MAX_SPEED_HZ, &speed);
	if (ret == -1)
		pabort("can't get max speed hz");

	printf("spi mode: 0x%x\n", mode);
	printf("bits per word: %d\n", bits);
	printf("max speed: %d Hz (%d KHz)\n", speed, speed/1000);

		while(1){
			memset(default_tx, 0, DEFAULT_SIZE);
			default_tx[0] = 0xeb;
			default_tx[1] = 0x90;
			default_tx[2] = (count>>24)&0xff;
			default_tx[3] = (count>>16)&0xff;
			default_tx[4] = (count>>8)&0xff;
			default_tx[5] = count&0xff;
			default_tx[tx_len-2] = 0xaa;
			default_tx[tx_len-1] = 0xaa;
        
			transfer(fd);
			count++;
			usleep(5000);
		}

	close(fd);

	return ret;
}

read program for slave:

#include <stdint.h>
#include <unistd.h>
#include <stdio.h>
#include <stdlib.h>
#include <string.h>
#include <getopt.h>
#include <fcntl.h>
#include <sys/ioctl.h>
#include <linux/ioctl.h>
#include <sys/stat.h>
#include <linux/types.h>
#include <linux/spi/spidev.h>

#define ARRAY_SIZE(a) (sizeof(a) / sizeof((a)[0]))
#define DEFAULT_SIZE	8192

static void pabort(const char *s)
{
	perror(s);
	abort();
}

static const char *device = "/dev/spidev0.0";
static uint32_t mode=SPI_MODE_0;
static uint8_t bits = 8;
static uint32_t speed = 5000000;
static int rx_len = 884;
static uint32_t pre_count=0;
static uint32_t cur_count=0;

uint8_t default_rx[DEFAULT_SIZE] = {0, };
static uint32_t pre = 0;
static uint32_t cur = 0;

static void hex_dump(const void *src, size_t length, char *prefix)
{
        const unsigned char *address = src;

	if(cur==0){
		cur=address[2]<<24| address[3]<<16| address[4]<<8| address[5];
		pre=cur;
	}else{
		cur=address[2]<<24| address[3]<<16| address[4]<<8| address[5];
		if(cur-pre!=1){
			fprintf(stderr, "pre:%d, cur:%d------", pre, cur);
		fprintf(stderr, "%s | %02X %02X %02X %02X %02X %02X %02X %02X\n\n", 
				prefix, address[0], address[1], address[2], address[3], address[4], address[5],
			       	address[rx_len-2], address[rx_len-1]);
	        }
		pre=cur;
	}
}

static void transfer(int fd)
{
	int ret;
	struct spi_ioc_transfer tr = {
		.rx_buf = (unsigned long)default_rx,
		.tx_buf = 0,
		.len = rx_len,
		.speed_hz = speed,
		.bits_per_word = bits,
	};

	ret = ioctl(fd, SPI_IOC_MESSAGE(1), &tr);
	if (ret < 1){
		pabort("can't send spi message");
		return;
	}
	hex_dump(default_rx, rx_len, "RX");
	memset(default_rx, 0, DEFAULT_SIZE);
}

int main(int argc, char *argv[])
{
	int ret = 0;
	int fd;

	fd = open(device, O_RDWR);
	if (fd < 0)
		pabort("can't open device");

	/*
	 * spi mode
	 */
	ret = ioctl(fd, SPI_IOC_RD_MODE32, &mode);
	if (ret == -1)
		pabort("can't get spi mode");

	/*
	 * bits per word
	 */
	ret = ioctl(fd, SPI_IOC_WR_BITS_PER_WORD, &bits);
	if (ret == -1)
		pabort("can't set bits per word");

	ret = ioctl(fd, SPI_IOC_RD_BITS_PER_WORD, &bits);
	if (ret == -1)
		pabort("can't get bits per word");

	/*
	 * max speed hz
	 */
	ret = ioctl(fd, SPI_IOC_WR_MAX_SPEED_HZ, &speed);
	if (ret == -1)
		pabort("can't set max speed hz");

	ret = ioctl(fd, SPI_IOC_RD_MAX_SPEED_HZ, &speed);
	if (ret == -1)
		pabort("can't get max speed hz");

	fprintf(stderr, "spi mode: 0x%x\n", mode);
	fprintf(stderr, "bits per word: %d\n", bits);
	fprintf(stderr, "max speed: %d Hz (%d KHz)\n", speed, speed/1000);

	while(1){
		transfer(fd);
	}

	close(fd);

	return ret;
}

slave device-tree config:

        spi@3210000 {
                status = "okay";
                compatible = "nvidia,tegra186-spi-slave";

                spi@0 {
                        compatible = "spidev";
                        reg = <0>;
                        spi-max-frequency = <65000000>;
                };
        };

Could you attached the binary file here to try.

Could you use spidev_test tools to verify it.

Thanks

I have verified it use spidev_test you provided, and the phenomenon has not changed.
As you said, run the following command:

for slave:  sudo ./spidev_test -D /dev/spidev0.0 -s5000000 -g884 -b8 -H -p0 -n-1 -r 
for master: sudo ./spidev_test -D /dev/spidev0.0 -s5000000 -g884-b8-H -p0 -n-1 -zzz -t

Could you clarify the connection. FPGA as master send data to Jetson SPI0?

@ShaneCCC
For our use case,FPGA as master send data to Jetson SPI1, sometimes error occurs.
I have also replicated this errors on two dev board, one is master and another is slave, use SPI0.

For those two cases, the error may reduced a lot after run jetson_clock command.

Please try the -g896 as 32 multiple

@ShaneCCC
I have try it with the -g896 as 32 multiple , but no useless.
Could you check it with two dev board inside.

@ShaneCCC
Have you made any progress with this?

thanks

I am arranging devices to check it.

I run the test with two Jetson devices.
The result as below. Looks like some others speed have failed rate.

Slave device 
nvidia@nvidia-desktop:~$ ./spidev_test -D /dev/spidev2.0 -g 512 -s 11000000 -r -p0 -n1 -zzz
using device: /dev/spidev2.0
setting spi mode for read,write
setting spi bpw
setting max speed for rd/wr
spi mode: 0
bits per word: 8 bytes per word: 1
max speed: 11000000 Hz (11000 KHz)
no. runs: 1
Using seed:0x62276730
loop count = 0
transfer: Return actual transfer length: 512
receive bytes [512]
0000: 00 01 02 03 04 05 06 07 08 09 0A 0B 0C 0D 0E 0F
0010: 10 11 12 13 14 15 16 17 18 19 1A 1B 1C 1D 1E 1F
0020: 20 21 22 23 24 25 26 27 28 29 2A 2B 2C 2D 2E 2F
0030: 30 31 32 33 34 35 36 37 38 39 3A 3B 3C 3D 3E 3F
0040: 40 41 42 43 44 45 46 47 48 49 4A 4B 4C 4D 4E 4F
0050: 50 51 52 53 54 55 56 57 58 59 5A 5B 5C 5D 5E 5F
0060: 60 61 62 63 64 65 66 67 68 69 6A 6B 6C 6D 6E 6F
0070: 70 71 72 73 74 75 76 77 78 79 7A 7B 7C 7D 7E 7F
0080: 80 81 82 83 84 85 86 87 88 89 8A 8B 8C 8D 8E 8F
0090: 90 91 92 93 94 95 96 97 98 99 9A 9B 9C 9D 9E 9F
00A0: A0 A1 A2 A3 A4 A5 A6 A7 A8 A9 AA AB AC AD AE AF
00B0: B0 B1 B2 B3 B4 B5 B6 B7 B8 B9 BA BB BC BD BE BF
00C0: C0 C1 C2 C3 C4 C5 C6 C7 C8 C9 CA CB CC CD CE CF
00D0: D0 D1 D2 D3 D4 D5 D6 D7 D8 D9 DA DB DC DD DE DF
00E0: E0 E1 E2 E3 E4 E5 E6 E7 E8 E9 EA EB EC ED EE EF
00F0: F0 F1 F2 F3 F4 F5 F6 F7 F8 F9 FA FB FC FD FE 00
0100: 01 02 03 04 05 06 07 08 09 0A 0B 0C 0D 0E 0F 10
0110: 11 12 13 14 15 16 17 18 19 1A 1B 1C 1D 1E 1F 20
0120: 21 22 23 24 25 26 27 28 29 2A 2B 2C 2D 2E 2F 30
0130: 31 32 33 34 35 36 37 38 39 3A 3B 3C 3D 3E 3F 40
0140: 41 42 43 44 45 46 47 48 49 4A 4B 4C 4D 4E 4F 50
0150: 51 52 53 54 55 56 57 58 59 5A 5B 5C 5D 5E 5F 60
0160: 61 62 63 64 65 66 67 68 69 6A 6B 6C 6D 6E 6F 70
0170: 71 72 73 74 75 76 77 78 79 7A 7B 7C 7D 7E 7F 80
0180: 81 82 83 84 85 86 87 88 89 8A 8B 8C 8D 8E 8F 90
0190: 91 92 93 94 95 96 97 98 99 9A 9B 9C 9D 9E 9F A0
01A0: A1 A2 A3 A4 A5 A6 A7 A8 A9 AA AB AC AD AE AF B0
01B0: B1 B2 B3 B4 B5 B6 B7 B8 B9 BA BB BC BD BE BF C0
01C0: C1 C2 C3 C4 C5 C6 C7 C8 C9 CA CB CC CD CE CF D0
01D0: D1 D2 D3 D4 D5 D6 D7 D8 D9 DA DB DC DD DE DF E0
01E0: E1 E2 E3 E4 E5 E6 E7 E8 E9 EA EB EC ED EE EF F0
01F0: F1 F2 F3 F4 F5 F6 F7 F8 F9 FA FB FC FD FE 00 01
transfer: received packet size:512 len:512 stat:0
/dev/spidev2.0: TEST PASSED
====== Transfer stats ====
Receive:
       total: 512B (0KiB 0MiB)
       total: 1P
        good: 512B (0KiB 0MiB)
        good: 1P
       ioerr: 0P
     dataerr: 0P
 Rate:
        good: 202B/s (0KB/s)
        good: 0P/s
 packet drop: -1/10000

  Total time: 2.534314s



Master device
nvidia@nvidia-desktop:~$ ./spidev_test -D /dev/spidev0.0 -g 512 -s 11000000 -t -p0 -n1 -zzz
using device: /dev/spidev0.0
setting spi mode for read,write
setting spi bpw
setting max speed for rd/wr
spi mode: 0
bits per word: 8 bytes per word: 1
max speed: 11000000 Hz (11000 KHz)
no. runs: 1
Using seed:0x61b4336f
loop count = 0
using sequential pattern ....
transfer bytes [512]
0000: 00 01 02 03 04 05 06 07 08 09 0A 0B 0C 0D 0E 0F
0010: 10 11 12 13 14 15 16 17 18 19 1A 1B 1C 1D 1E 1F
0020: 20 21 22 23 24 25 26 27 28 29 2A 2B 2C 2D 2E 2F
0030: 30 31 32 33 34 35 36 37 38 39 3A 3B 3C 3D 3E 3F
0040: 40 41 42 43 44 45 46 47 48 49 4A 4B 4C 4D 4E 4F
0050: 50 51 52 53 54 55 56 57 58 59 5A 5B 5C 5D 5E 5F
0060: 60 61 62 63 64 65 66 67 68 69 6A 6B 6C 6D 6E 6F
0070: 70 71 72 73 74 75 76 77 78 79 7A 7B 7C 7D 7E 7F
0080: 80 81 82 83 84 85 86 87 88 89 8A 8B 8C 8D 8E 8F
0090: 90 91 92 93 94 95 96 97 98 99 9A 9B 9C 9D 9E 9F
00A0: A0 A1 A2 A3 A4 A5 A6 A7 A8 A9 AA AB AC AD AE AF
00B0: B0 B1 B2 B3 B4 B5 B6 B7 B8 B9 BA BB BC BD BE BF
00C0: C0 C1 C2 C3 C4 C5 C6 C7 C8 C9 CA CB CC CD CE CF
00D0: D0 D1 D2 D3 D4 D5 D6 D7 D8 D9 DA DB DC DD DE DF
00E0: E0 E1 E2 E3 E4 E5 E6 E7 E8 E9 EA EB EC ED EE EF
00F0: F0 F1 F2 F3 F4 F5 F6 F7 F8 F9 FA FB FC FD FE 00
0100: 01 02 03 04 05 06 07 08 09 0A 0B 0C 0D 0E 0F 10
0110: 11 12 13 14 15 16 17 18 19 1A 1B 1C 1D 1E 1F 20
0120: 21 22 23 24 25 26 27 28 29 2A 2B 2C 2D 2E 2F 30
0130: 31 32 33 34 35 36 37 38 39 3A 3B 3C 3D 3E 3F 40
0140: 41 42 43 44 45 46 47 48 49 4A 4B 4C 4D 4E 4F 50
0150: 51 52 53 54 55 56 57 58 59 5A 5B 5C 5D 5E 5F 60
0160: 61 62 63 64 65 66 67 68 69 6A 6B 6C 6D 6E 6F 70
0170: 71 72 73 74 75 76 77 78 79 7A 7B 7C 7D 7E 7F 80
0180: 81 82 83 84 85 86 87 88 89 8A 8B 8C 8D 8E 8F 90
0190: 91 92 93 94 95 96 97 98 99 9A 9B 9C 9D 9E 9F A0
01A0: A1 A2 A3 A4 A5 A6 A7 A8 A9 AA AB AC AD AE AF B0
01B0: B1 B2 B3 B4 B5 B6 B7 B8 B9 BA BB BC BD BE BF C0
01C0: C1 C2 C3 C4 C5 C6 C7 C8 C9 CA CB CC CD CE CF D0
01D0: D1 D2 D3 D4 D5 D6 D7 D8 D9 DA DB DC DD DE DF E0
01E0: E1 E2 E3 E4 E5 E6 E7 E8 E9 EA EB EC ED EE EF F0
01F0: F1 F2 F3 F4 F5 F6 F7 F8 F9 FA FB FC FD FE 00 01
/dev/spidev0.0: TEST PASSED
====== Transfer stats ====
Transmit:
       total: 512B (0KiB 0MiB)
       total: 1P
       ioerr: 0B (0KiB 0MiB)
       ioerr: 0P
 Rate:
  wire total: -1B/s (0KB/s)
       total: -1B/s (0KB/s)
  wire total: -1P/s
       total: -1P/s

  Total time: 0.002223s