Kernel module spi_sync latency

Jetson:
Jetson Orin NX 16GB

Carrier borad:
Seeedstudio reComputer J4012

kernel version:
5.15.136-rt-tegra

Im currently in the proces of writing a kernel module for a lan9252 device.

When testing the spi, I see a relative high latency between calling spi_sync to spi CS signal activate.

I measure the latency with using the “gpio_test_out” as the trigger signal for my logic analyser.
The latency is in worst case around 800uS, but normally around 230uS.

Is this the exspected latency on the Jetson, or is it possible to get a lower and more stable latency?

    gpiod_set_value(gpio_test_out, 1);
    ret = spi_sync(spi_lan9252, &m);

Changes to tegra234-p3768-0000+p3767-xxxx-nv-common.dtsi:

    spi@3210000{
        status = "okay";
        lan9252_spi: lan9252_spi@0 {
            compatible = "MICROCHIP,LAN9252_SPI";
            reg = <0x0>;
            spi-max-frequency = <3000000>;

            controller-data {
                nvidia,enable-hw-based-cs;
                nvidia,rx-clk-tap-delay = <0x0>;
                nvidia,tx-clk-tap-delay = <0x0>;
                nvidia,polling-mode;
                nvidia,disable-runtime-pm;
            };
        };

        
        spi@1 {
            compatible = "tegra-spidev";
            reg = <0x1>;
            spi-max-frequency = <3000000>;
            controller-data {
                nvidia,enable-hw-based-cs;
                nvidia,rx-clk-tap-delay = <0x10>;
                nvidia,tx-clk-tap-delay = <0x0>;
            };
        };
    };
    lan9252_irq_device {
            compatible = "MICROCHIP,LAN9252";
            status = "okay";
            label = "LAN9252_IRQ";
            lan9252_irq_value = <12>;
            lan9252-irq-gpio = <&gpio TEGRA234_MAIN_GPIO(AC, 6) 0>;
            lan9252-sync0-gpio = <&gpio TEGRA234_MAIN_GPIO(N, 1) 0>;
            lan9252-sync1-gpio = <&gpio TEGRA234_MAIN_GPIO(I, 1) 0>;
            lan9252-test-out-gpio = <&gpio TEGRA234_MAIN_GPIO(H, 0) 0>;
            lan_spi = <&lan9252_spi>; 
    };

kernel module:

#include <linux/module.h>
#include <linux/init.h>
#include <linux/mod_devicetable.h>
#include <linux/property.h>
#include <linux/platform_device.h>
#include <linux/of_device.h>
#include <linux/gpio/consumer.h>
#include <linux/proc_fs.h>
#include <linux/interrupt.h>
#include <linux/delay.h>
#include <linux/spi/spi.h>


unsigned int irq_number, sync0_number, sync1_number;

/* Declate the probe and remove functions */
static int dt_probe(struct platform_device *pdev);
static int dt_remove(struct platform_device *pdev);

static struct of_device_id lan9252_driver_ids[] = {
    {
        .compatible = "MICROCHIP,LAN9252",
    }, { /* sentinel */ }
};
MODULE_DEVICE_TABLE(of, lan9252_driver_ids);


static struct platform_driver lan9252_driver = {
    .probe = dt_probe,
    .remove = dt_remove,
    .driver = {
        .name = "lan9252_device_driver",
        .of_match_table = lan9252_driver_ids,
    },
};


/* GPIO variable */
static struct gpio_desc *lan9252_irq = NULL;
static struct gpio_desc *lan9252_sync0 = NULL;
static struct gpio_desc *lan9252_sync1 = NULL;
static struct gpio_desc *gpio_test_out = NULL;
static struct proc_dir_entry *proc_file;
struct device_node *spi_np;
struct spi_device *spi_lan9252;


static irqreturn_t gpio_irq_handler(int irq, void *dev_id)
{
    struct spi_message m;
    int ret;
    u8 tx_buf[3];
    u8 rx_buf[4];
    u16 id;

    //struct spi_transfer t[];
    struct spi_transfer t[] = {
    {
            .tx_buf = tx_buf,
            .len = 3,
        },
        {
            .rx_buf = rx_buf,
            .len = 4,
        },
    };

    // Prepare the SPI command to read from register 0x0050
    tx_buf[0] = 0x03;           // Instruction
    tx_buf[1] = (0x0050 >> 8) & 0xFF;   // MSB of the address
    tx_buf[2] = 0x0050 & 0xFF;          // LSB of the address

    t[0].tx_buf = tx_buf;
    t[0].len = 3;

    spi_message_init(&m);
    spi_message_add_tail(&t[0], &m);
    spi_message_add_tail(&t[1], &m);

    gpiod_set_value(gpio_test_out, 1);
    ret = spi_sync(spi_lan9252, &m);

    if (ret < 0) {
        printk("lan9252 - Error! SPI transfer failed\n");
        return ret;
    }

    // Combine the 4 bytes received into a 32-bit ID
    id = (rx_buf[3] << 8) | rx_buf[2];

    printk("lan9252 - Device ID: 0x%04x\n", id);
    gpiod_set_value(gpio_test_out, 0);
    return IRQ_HANDLED;
}

static irqreturn_t gpio_sync0_handler(int irq, void *dev_id)
{
    gpiod_set_value(gpio_test_out, 1);
    udelay(200);
    gpiod_set_value(gpio_test_out, 0);
    return IRQ_HANDLED;
}

static irqreturn_t gpio_sync1_handler(int irq, void *dev_id)
{
    gpiod_set_value(gpio_test_out, 1);
    udelay(300);
    gpiod_set_value(gpio_test_out, 0);
    return IRQ_HANDLED;
}



static int dt_probe(struct platform_device *pdev) {
    int lan9252_irq_value, ret;
    struct device *dev = &pdev->dev;
        struct spi_message m;
    const char *label;
    u8 tx_buf[3];
        u8 rx_buf[4];
        u16 id;

        //struct spi_transfer t[];

        struct spi_transfer t[] = {
        {
            .tx_buf = tx_buf,
            .len = 3,
        },
        {
            .rx_buf = rx_buf,
            .len = 4,
        },
        };


    printk("LAN9252_IRQ - In the probe function!\n");

    /* Check for device properties */
    if(!device_property_present(dev, "lan_spi")) {
        printk("LAN9252_IRQ  - Error! Device property 'lan_spi' not found!\n");
        return -1;
    }

    spi_np = of_parse_phandle(pdev->dev.of_node, "lan_spi", 0);
    if (!spi_np) {
            dev_err(&pdev->dev, "Failed to find SPI device node\n");
            return -ENODEV;
        }

        spi_lan9252 = of_find_spi_device_by_node(spi_np);
    //spi_dev->rt = 1;

        if (!spi_lan9252) {
            dev_err(&pdev->dev, "Failed to find SPI device\n");
            of_node_put(spi_np);
            return -EPROBE_DEFER;
        }


    if(!device_property_present(dev, "label")) {
        printk("LAN9252_IRQ  - Error! Device property 'label' not found!\n");
        return -1;
    }
    
    if(!device_property_present(dev, "lan9252_irq_value")) {
        printk("LAN9252_IRQ  - Error! Device property 'lan9252_irq_value' not found!\n");
        return -1;
    }

    if(!device_property_present(dev, "lan9252-irq-gpio")) {
        printk("LAN9252_IRQ  - Error! Device property 'lan9252-irq-gpio' not found!\n");
        return -1;
    }

    if(!device_property_present(dev, "lan9252-sync0-gpio")) {
        printk("LAN9252_IRQ  - Error! Device property 'lan9252-sync0-gpio' not found!\n");
        return -1;
    }

    if(!device_property_present(dev, "lan9252-sync1-gpio")) {
        printk("LAN9252_IRQ  - Error! Device property 'lan9252-sync1-gpio' not found!\n");
        return -1;
    }

    if(!device_property_present(dev, "lan9252-test-out-gpio")) {
        printk("LAN9252_IRQ  - Error! Device property 'lan9252-test-out-gpio' not found!\n");
        return -1;
    }

    /* Read device properties */
    ret = device_property_read_string(dev, "label", &label);
    if(ret) {
        printk("LAN9252_IRQ  - Error! Could not read 'label'\n");
        return -1;
    }
    printk("LAN9252_IRQ  - label: %s\n", label);
    ret = device_property_read_u32(dev, "lan9252_irq_value", &lan9252_irq_value);
    if(ret) {
        printk("LAN9252_IRQ  - Error! Could not read 'lan9252_irq_value'\n");
        return -1;
    }
    printk("LAN9252_IRQ  - lan9252_irq_value: %d\n", lan9252_irq_value);

    /* Init IRQ */
    lan9252_irq = gpiod_get(dev, "lan9252-irq", GPIOD_IN);
    if(IS_ERR(lan9252_irq)) {
        printk("LAN9252_IRQ  - Error! Could not setup the GPIO\n");
        return -1 * IS_ERR(lan9252_irq);
    }

    /* Setup the interrupt */
    irq_number = gpiod_to_irq(lan9252_irq);

    if(request_irq(irq_number, gpio_irq_handler, IRQF_TRIGGER_RISING, "lan9252_gpio_irq", NULL) != 0){
        printk("Error!\nCan not request interrupt nr.: %d\n", irq_number);
        return -1;
    }

    printk("LAN9252_IRQ is mapped to IRQ Nr.: %d\n", irq_number);   


    /* Init SYNC0 */
    lan9252_sync0 = gpiod_get(dev, "lan9252-sync0", GPIOD_IN);
    if(IS_ERR(lan9252_sync0)) {
        printk("LAN9252_SYNC0  - Error! Could not setup the GPIO\n");
        return -1 * IS_ERR(lan9252_sync0);
    }

    /* Setup the interrupt */
    sync0_number = gpiod_to_irq(lan9252_sync0);

    if(request_irq(sync0_number , gpio_sync0_handler, IRQF_TRIGGER_RISING, "lan9252_sync0", NULL) != 0){
        printk("Error!\nCan not request interrupt nr.: %d\n", sync0_number);
        return -1;
    }
    printk("LAN9252_SYNC0 is mapped to IRQ Nr.: %d\n", sync0_number);   


    /* Init SYNC1 */
    lan9252_sync1 = gpiod_get(dev, "lan9252-sync1", GPIOD_IN);
    if(IS_ERR(lan9252_sync1)) {
        printk("LAN9252_SYNC1  - Error! Could not setup the GPIO\n");
        return -1 * IS_ERR(lan9252_sync1);
    }

    /* Setup the interrupt */
    sync1_number = gpiod_to_irq(lan9252_sync1);

    if(request_irq(sync1_number , gpio_sync1_handler, IRQF_TRIGGER_RISING, "lan9252_sync1", NULL) != 0){
        printk("Error!\nCan not request interrupt nr.: %d\n", sync1_number);
        return -1;
    }
    printk("LAN9252_SYNC1 is mapped to IRQ Nr.: %d\n", sync1_number);   


    /* Init GPIO */
    gpio_test_out = gpiod_get(dev, "lan9252-test-out", GPIOD_OUT_LOW);
    if(IS_ERR(gpio_test_out)) {
        printk("LAN9252_TEST_OUT - Error! Could not setup the GPIO\n");
        return -1 * IS_ERR(gpio_test_out);
    }

    gpiod_set_value(gpio_test_out, 0);

    /* test spi */
    // Prepare the SPI command to read from register 0x0050
    tx_buf[0] = 0x03;           // Instruction
    tx_buf[1] = (0x0050 >> 8) & 0xFF;   // MSB of the address
    tx_buf[2] = 0x0050 & 0xFF;          // LSB of the address

    t[0].tx_buf = tx_buf;
    t[0].len = 3;

    spi_message_init(&m);
    spi_message_add_tail(&t[0], &m);
    spi_message_add_tail(&t[1], &m);


    ret = spi_sync(spi_lan9252, &m);
    if (ret < 0) {
        printk("lan9252 - Error! SPI transfer failed\n");
        return ret;
    }

    // Combine the 4 bytes received into a 32-bit ID
    id = (rx_buf[3] << 8) | rx_buf[2];

    printk("lan9252 - Device ID: 0x%04x\n", id);

    if (id != 0x9252) {
        printk("lan9252 - Device ID: 0x%04x\n", id);
        printk("lan9252 - Device ID not correct");
    return -1;
    } 


    return 0;
}


static int dt_remove(struct platform_device *pdev) {
    printk("LAN9252 - In the remove function\n");
    free_irq(sync1_number, NULL);
    free_irq(sync0_number, NULL);
    free_irq(irq_number, NULL);
    gpiod_put(lan9252_irq);
    gpiod_put(lan9252_sync0);
    gpiod_put(lan9252_sync1);
    of_node_put(spi_np);
    gpiod_put(gpio_test_out);
    proc_remove(proc_file);
    return 0;
}


static int __init lan9252_init(void) {
    printk("LAN9252 - Loading the driver...\n");
    if(platform_driver_register(&lan9252_driver)) {
        printk("LAN9252 - Error! Could not load driver\n");
        return -1;
    }
    return 0;
}


static void __exit lan9252_exit(void) {
    printk("LAN9252 - Unload driver");
    platform_driver_unregister(&lan9252_driver);
}

module_init(lan9252_init);
module_exit(lan9252_exit);

MODULE_LICENSE("GPL");
MODULE_AUTHOR("MKN");
MODULE_DESCRIPTION("LKM for LAN9252 ethercat controller");

Hi mmkunzendorf,

It seems you are using the custom carrier board.

Have you tried using JP5.1.3(R35.5.0) to check if there’s similar latency issue?

Hi KevinFFF,

I’m currently using JP6.0, but it is an standard flash without any changes. Are there anything indicating that rolling back to an earlier version of the JP will resolve the problem?

There are some users reporting that the SPI driver of JP6 have some problems and we are still working on it.
We think it might relate to a function to select the best clock source, which is removed in JP6.

Just want to know if you have the similar issue.

OK, i will create a JP5.1.3 setup and make a test

1 Like

I have now tested the setup on JP5.1.3, and see the same latency, around 220uS

Could you apply the patch in the following thread to check if it could help in your case?
Orin NX SPI delay between transfers - #21 by KevinFFF

The path for sure helps, there is still 220uS delay, when the spi returns from “AUTOSUSPEND”, but if it does not go into “AUTOSUSPEND”, the latency is down to 5-8uS (130uS before) from starting a new transfer to cs is activated, which is acceptable.

#define AUTOSUSPEND_TIMEOUT			300 /* in millisec */

From cs is activated, to sck starts, there is also a delay of 10uS, and between tx and rx with spi_sync, there is a 30uS delay, any recommendations how to reduce these timings?

It seems the expected result now.

What’s your requirement for the latency?

Could you also share the waveform for the delay you want to optimize?

Doing a “spi_sync” transfer with 3 bytes tx and 4 byte rx, the overall time cs is active are 49uS with the following setting in the device tree: spi-max-frequency = <30000000>;

From cs is active till first sck, the latency is: 10uS, between tx and rx the latency is 32us and from rx to cs is inactive, it takes 13us. It is those delays, and the delay between two messages i would like to reduce.

An overall transfer time of 15uS would be acceptable, but my goal to remove as much latency as possible.

I have tried adding the following tail to my message, but it seems not to have any effect on the latency:

    t[0].delay.value = 1;
    t[0].delay.unit = 0;
    t[0].cs_change_delay.value = 1;
    t[0].cs_change_delay.unit = 0;
    t[0].word_delay.value = 1;
    t[0].word_delay.unit = 0;

    t[1].delay.value = 1;
    t[1].delay.unit = 0;
    t[1].cs_change_delay.value = 1;
    t[1].cs_change_delay.unit = 0;
    t[1].word_delay.value = 1;
    t[1].word_delay.unit = 0;

    spi_message_init(&m);
    spi_message_add_tail(&t[0], &m);
    spi_message_add_tail(&t[1], &m);

    ret = spi_sync(spi_lan9252, &m);