The delay of the .poll function in the driver code has not taken effect?

Question

I added a GPIO driver to the kernel code of Linux v3.10, and added a .poll function to the driver code. I don't know why I added 8ms to the poll() function of test code, but I noticed that the delay (poll_wait(file, &WaitQueue, wait);) did not take effect when dmesg was printed. I don't know why? Also, may I ask if it is appropriate to add a mutex in the interrupt callback function?

#driver code:

#include <linux/init.h>
#include <linux/module.h>
#include <linux/platform_device.h>
#include <linux/of_gpio.h>
#include <linux/gpio.h>
#include <linux/sys_config.h>
#include <linux/major.h>
#include <linux/seq_file.h>
#include <linux/device.h>
#include <linux/sched.h>
#include <linux/interrupt.h>
#include <linux/poll.h>
#include <linux/wait.h>
#include <linux/mutex.h>

static int MajorDevNum = 0;
static struct class *SpiioClass;
static int SpiioGpio;
static int IrqOccurred = 0;
static wait_queue_head_t WaitQueue;
struct mutex RWLock;

static ssize_t spiio_drv_read(struct file *file, char __user *buf, size_t size, loff_t *offset)
{
        int value = 0;
        char userValue = value ? 1:0;
        // wake_event_interruptible(wq, IrqOccrred);
        userValue = gpio_get_value(SpiioGpio) ? 1 : 0;
        printk("read value is %d\n", userValue);
        if (copy_to_user(buf, &userValue, sizeof(char) != 0)) {
                printk("failed to copy to user\n");
                return  -1;
        } else {
                return sizeof(char);
        }
}

static ssize_t spiio_drv_write(struct file *file, const char __user *buf, size_t size, loff_t *offset)
{
   return -1;
}

static int spiio_drv_open(struct inode *node, struct file *file)
{
    printk("this is open\n");
    return 0;
}

static int spiio_drv_close(struct inode *node, struct file *file)
{
    return 0;
}

static long spiio_drv_ioctl(struct file *file, unsigned int cmd, unsigned long arg)
{
        return 0;
}

static unsigned int spiio_drv_poll(struct file *file, struct poll_table_struct *wait)
{
    printk("this is poll.\n");
    poll_wait(file, &WaitQueue, wait);
    if (IrqOccurred) {
        mutex_lock(&RWLock);
        IrqOccurred = 0;  // need lock
        mutex_unlock(&RWLock);
        printk(" an irq occurred. return %d\n", POLLIN);
        return POLLIN;
    }
    printk("no irq occurred, IrqOccurred = %d\n", IrqOccurred);
    return 0;
}

static irqreturn_t spiio_irq_handler(int irq, void *dev_id)
{
        // pr_info("spiio irq ocurred on IRQ %d\n", irq);
        wake_up_interruptible(&WaitQueue);
        mutex_lock(&RWLock);
        IrqOccurred = 1;
        mutex_unlock(&RWLock);
        return IRQ_HANDLED;
}

static struct file_operations spiio_drv = {
    .owner = THIS_MODULE,
    .open = spiio_drv_open,
    .read = spiio_drv_read,
    .write = spiio_drv_write,
    .release = spiio_drv_close,
    .unlocked_ioctl = spiio_drv_ioctl,
    .poll = spiio_drv_poll,
};

int spiio_probe(struct platform_device *pdev)
{
    struct device_node *nd = pdev->dev.of_node;
    struct gpio_config config;
    printk("gpio count:%d\n", of_gpio_named_count(nd, "spiio_gpio"));
    SpiioGpio = of_get_named_gpio_flags(nd, "spiio_gpio", 0, (enum of_gpio_flags *)&config);
    if (!gpio_is_valid(SpiioGpio))
        printk("gpio isn't valid\n");
    if (gpio_request(SpiioGpio, pdev->name) < 0)
        printk("gpio request faispiio %d\n", SpiioGpio);
    if (gpio_direction_input(SpiioGpio) < 0)
        printk("gpio_direction_input failed %d\n", SpiioGpio);
    init_waitqueue_head(&WaitQueue);

    // if (request_irq(gpio_to_irq(SpiioGpio), spiio_irq_handler, IRQF_TRIGGER_HIGH, "spiio_irq", NULL) < 0)
    if (request_irq(gpio_to_irq(SpiioGpio), spiio_irq_handler, IRQF_TRIGGER_RISING, "spiio_irq", NULL) < 0)
        printk("requst_irq failed\n");

    MajorDevNum = register_chrdev(0, "spiio", &spiio_drv); /* /dev/spiio */
    if (MajorDevNum < 0)
        printk("failed to get major device number\n");

    SpiioClass = class_create(THIS_MODULE, "spiio_class");
    if (IS_ERR(SpiioClass)) {
        printk("%s %s line %d\n", __FILE__, __FUNCTION__, __LINE__);
        unregister_chrdev(MajorDevNum, "spiio");
        gpio_free(SpiioGpio);
        return PTR_ERR(SpiioClass);
    }
    device_create(SpiioClass, NULL, MKDEV(MajorDevNum, 0), NULL, "spiio%d", 0); /* /dev/100ask_spiio0 */
    mutex_init(&RWLock);
    printk("gpio is ok, registered GPIO: %d\n", SpiioGpio);
    return 0;
}

int spiio_remove(struct platform_device *pdev)
{
    free_irq(gpio_to_irq(SpiioGpio), NULL);
    device_destroy(SpiioClass, MKDEV(MajorDevNum, 0));
    class_destroy(SpiioClass);
    unregister_chrdev(MajorDevNum, "spiio");
    gpio_free(SpiioGpio);
    mutex_destroy(&RWLock);
    printk("gpio remove ...\n");
    return 0;
}

struct of_device_id ids[] = {
    { .compatible = "dobot, spiio" },
    {},
};

static struct platform_driver chip_demo_gpio_driver = {
    .probe = spiio_probe,
    .remove = spiio_remove,
    .driver = {
        .name = "spiio",
        .of_match_table = ids,
    },
};

static int __init spiio_init(void)
{
    int err;
    err = platform_driver_register(&chip_demo_gpio_driver);
    return err;
}

test code:

#include "spidev.h"
#include <poll.h>
#include <time.h>    

int SpiDevFd = 0;

struct _SPI_Settings spi_settings;

int ReadData(int fd)
{
    int ret = 0;
    int ret2 = 0;
    char buffer[2] = {0};
    short revents;
    struct pollfd pfd;
    int timeout_ms = 8;

        pfd.fd = fd;
        pfd.events = POLLIN;
    
        uint8_t tx[256] = {0};
    for (int i = 0; i <= 255; i++)
    {
        tx[i] = i;
    }
    uint8_t rx[ARRAY_SIZE(tx)] = {
         0,
    };

    while (1) {
        memset(buffer, 0, sizeof(buffer));
        ret = poll(&pfd, 1, timeout_ms);
        revents = pfd.revents;
        if (ret) {
            TransferSpi(SpiDevFd, &spi_settings, tx, sizeof(tx), rx);
            hex_dump(rx, ARRAY_SIZE(rx), 32, "RX");
        } else {
            printf("ret = %d\n", ret);
            exit(-1);
        }
    }
    return 0;
}

int main() {
    // int fd = open("/sys/class/gpio_sw/gpio_pin_1/data", O_RDONLY);
   //  int fd = open("/sys/class/gpio_sw/PH1/data", O_RDONLY);
    int fd = open("/dev/spiio0", O_RDONLY);
    if (fd < 0) {
        perror("Failed to open GPIO value file\n");
        return 1;
    }
    
    spi_settings.mode = 0;
    spi_settings.bits = 8;
    spi_settings.speed = 20*1000*1000;
    spi_settings.delay = 0;
    SpiDevFd = OpenSpiDev("/dev/spidev2.0", &spi_settings);
    if (SpiDevFd < 0) {
                perror("Failed to spi dev file\n");
                return 1;
        }

    int ret = ReadData(fd);    

    close(fd);
    return 0;
}

The part of dmesg:

[ 3458.628570] gpio count:1
[ 3458.629278] gpio is ok, registered GPIO: 225
[ 3461.818972] this is open
[ 3461.819640] this is poll.
[ 3461.819679]  an irq occurred. return 1
[ 3461.820758] this is poll.
[ 3461.820777] no irq occurred, IrqOccurred = 0
[ 3461.822363] this is poll.
[ 3461.822373]  an irq occurred. return 1
[ 3461.823260] this is poll.
[ 3461.823273] no irq occurred, IrqOccurred = 0
[ 3461.831337] this is poll.
[ 3461.831356] no irq occurred, IrqOccurred = 0