Articles in this blog

Thursday, 17 December 2015

Linux Device Model Internals


In this illustration I will be showing how bus_type, device_driver and device structures are linked. It also shows how the match and probe function of device driver is called for devices. I used Linux kernel 3.19 for making this simple program.

This program tries to 
1. Register a bus. 
2. Register a device_driver to that bus and 
3. Add a device_driver device to the driver.

At the last step the match and probe functions of the device driver are called.
In the probe function I am creating a simple character device.


#include <linux/kernel.h>
#include <linux/module.h>
#include <linux/types.h>
#include <linux/major.h>
#include <linux/kdev_t.h>
#include <linux/fs.h>

#include <linux/device.h>
#include <linux/cdev.h>
#include <linux/slab.h>
#include <linux/semaphore.h>

#include <asm/uaccess.h>


dev_t my_devt;

char drv_name[] = "my_chr_drv";
struct class *my_class;
struct device *my_device;
struct device *my_chr_device;

char global_buf[20];

struct my_super_device
{
    struct cdev my_cdev;
    int count;
    struct semaphore my_sem;
};

struct my_super_device *my_super;

ssize_t my_read (struct file *myfile, char __user *my_buf, size_t len, loff_t *off)
{
    int ret;   
    //printk("len = %d\n",len);
    ret = copy_to_user(my_buf, global_buf, len);
    if(ret != 0)
        printk("not able to copy\n");
    printk("copied the data to user buffer\n");
    return len;
}

ssize_t my_write (struct file *my_file, const char __user *buf, size_t len, loff_t *off)
{
   
    int ret;   
    ret = copy_from_user(global_buf, buf, len);
    if(ret != 0)
        printk("not able to copy\n");
    printk("copied the data from user buffer\n");
    return len;
}

int my_mmap (struct file *my_file, struct vm_area_struct *my_vm)
{
    return 0;
}

int my_open (struct inode *my_inode, struct file *my_file)
{
    struct my_super_device *super_ptr;
    printk("open called\n");
    printk("cdev address = %p\n", my_inode->i_cdev);
   
    super_ptr = container_of(my_inode->i_cdev, struct my_super_device, my_cdev);   
    up(&(super_ptr->my_sem));
    printk("super address = %p\n", super_ptr);
    return 0;
}

int my_release (struct inode *my_inode, struct file *my_file)
{
    struct my_super_device *super_ptr;
    printk("release called\n");

    super_ptr = container_of(my_inode->i_cdev, struct my_super_device, my_cdev);   
    down(&(super_ptr->my_sem));
    return 0;
}

unsigned int my_poll (struct file *my_file, struct poll_table_struct *poll_table)
{
    return 0;
}

struct file_operations myfops = {
    .owner = THIS_MODULE,
    .read = my_read,
    .write = my_write,
    .poll = my_poll,
    .open = my_open,
    .release = my_release,
};

int my_bus_match(struct device *dev, struct device_driver *drv)
{
    printk("Entered %s\n",__func__);
    return 1;
}
int my_bus_uevent(struct device *dev, struct kobj_uevent_env *env)
{
    printk("Entered %s\n",__func__);
    return 0;
}

void my_bus_release(struct device *dev)
{
    printk("Entered %s\n",__func__);
    return ;
}

struct device my_bus = {
        .init_name = "my_bus",
    .release = my_bus_release,
};

struct bus_type my_bus_type = {
    .name = "my_bus",
    .match = my_bus_match,
    .uevent = my_bus_uevent,
};

int my_driver_probe(struct device *dev)
{
    int ret;   

    printk("Entered %s\n",__func__);

        ret = alloc_chrdev_region(&my_devt, 0, 1, drv_name);
        if(ret == 0)
                printk("dev_t major is %d minor is %d\n", MAJOR(my_devt), MINOR(my_devt));

        my_class =  class_create(THIS_MODULE, "my_class");
        if(my_class != NULL)
                printk("class created as %s\n", my_class->name);

        my_chr_device = device_create(my_class, NULL, my_devt, NULL, "my_chr_drv");
        if(my_chr_device != NULL)
                printk("device created dev_t as  %d\n", my_chr_device->devt);

        my_super = kzalloc(sizeof(struct my_super_device), GFP_KERNEL);

        sema_init(&(my_super->my_sem), 1);

        cdev_init(&(my_super->my_cdev), &myfops);

        cdev_add(&(my_super->my_cdev), my_devt, 1);
    return 0;
}

int my_driver_remove(struct device *dev)
{
    printk("Entered %s\n",__func__);

    if(my_chr_device != NULL)
        device_destroy(my_class, my_devt);
    if(my_class != NULL)
        class_destroy(my_class);
    if(my_devt != 0)
        unregister_chrdev_region(my_devt,1);

    return 0;
}

struct device_driver my_dev_driver = {
    .owner = THIS_MODULE,
    .name = "my_chr_drv",
    .bus = &my_bus_type,
    .probe = my_driver_probe,
    .remove = my_driver_remove,
};

static int __init my_init(void)
{
     int ret = 0;

    printk("in init\n");

    /*Register the bus*/
    ret = device_register(&my_bus);
    if(ret == 0)
        printk("device registerd correctly\n");
    else
        printk("ret = %d\n",ret);

    ret = bus_register(&my_bus_type);
    if(ret == 0)
        printk("bus registered correctly\n");
    else
        printk("ret = %d\n",ret);

    /*add device for the device driver*/
    my_device = kzalloc(sizeof(struct device), GFP_KERNEL);
    device_initialize(my_device);

    my_device->parent = &my_bus;
    my_device->bus = &my_bus_type;
    my_device->init_name = "my_chr_dev";

    ret = device_add(my_device);
    if(ret == 0)
        printk("device added correctly\n");
    else
        printk("ret = %d\n",ret);

    /*Now register the driver*/
    ret = driver_register(&my_dev_driver);
    if(ret == 0)
        printk("driver registered correctly\n");
    else
        printk("ret = %d\n",ret);

    return 0;
}

static void __exit my_exit(void)
{
    printk("in exit\n");
    driver_unregister(&my_dev_driver);
    bus_unregister(&my_bus_type);
    device_unregister(&my_bus);
}

module_init(my_init);
module_exit(my_exit);
MODULE_AUTHOR("Kundan");
MODULE_LICENSE("GPL");



Here is the snipped ftrace for the device_add function of the driver taken from this program.




# tracer: function_graph
#
# CPU  DURATION                  FUNCTION CALLS
# |     |   |                     |   |   |   |
 1)               |  device_add() {
 1)               |    device_private_init() {
 1)               |      kmem_cache_alloc_trace() {
 1)   0.291 us    |        _cond_resched();
 1)   2.375 us    |      }
 1)   4.088 us    |    }
 1)               |    dev_set_name() {
 1)               |      __kmalloc_track_caller() {
 1)   0.240 us    |        kmalloc_slab();
 1)   0.220 us    |        _cond_resched();
 1)   3.277 us    |      }
 1)   0.231 us    |      kfree();
 1)   7.374 us    |    }
 1)   0.601 us    |    get_device_parent();
 1)   0.280 us    |    _raw_spin_lock();
 1)   0.210 us    |    _raw_spin_unlock();
 1)               |    sysfs_create_dir_ns() {
 1)               |        kernfs_add_one() {
 1)               |          mutex_lock() {
 1)   0.210 us    |            _cond_resched();
 1)   1.704 us    |          }
 1)   0.401 us    |          kernfs_name_hash();
 1)   0.511 us    |          kernfs_link_sibling();
 1)   0.291 us    |          mutex_unlock();
 1)               |          kernfs_activate() {
 1)               |            mutex_lock() {
 1)   0.210 us    |              _cond_resched();
 1)   1.733 us    |            }
 1)               |            kernfs_next_descendant_post() {
 1)   0.271 us    |              kernfs_leftmost_descendant();
 1)   1.903 us    |            }
 1)   0.220 us    |            kernfs_next_descendant_post();
 1)   0.261 us    |            mutex_unlock();
 1)   9.459 us    |          }
 1) + 19.107 us   |        }
 1) + 49.938 us   |      }
 1) + 51.360 us   |    }
 1)   0.251 us    |    kernfs_get();
 1)               |    acpi_platform_notify() {
 1)               |      acpi_get_bus_type() {
 1)               |        down_read() {
 1)   0.200 us    |          _cond_resched();
 1)   1.714 us    |        }
 1)   0.250 us    |        pci_acpi_bus_match();
 1)   0.221 us    |        usb_acpi_bus_match();
 1)   0.261 us    |        up_read();
 1) + 10.039 us   |      }
 1)   0.281 us    |      acpi_bind_one();
 1) + 13.626 us   |    }
 1)               |    device_create_file() {
 1) + 46.381 us   |    }
 1)   0.250 us    |    sysfs_create_groups();
 1)               |    bus_add_device() {
 1)               |      device_add_groups() {
 1)   0.220 us    |        sysfs_create_groups();
 1)   1.933 us    |      }
 1)               |      sysfs_create_link() {
 1)               |        sysfs_do_create_link_sd.isra.2() {
 1)   0.501 us    |    kfree();
 1)   0.581 us    |    kfree();
 1)               |    bus_probe_device() {
 1)               |      device_attach() {
 1)               |        mutex_lock() {
 1)   0.251 us    |          _cond_resched();
 1)   1.803 us    |        }
 1)               |        bus_for_each_drv() {
 1)   0.271 us    |          _raw_spin_lock();
 1)   0.221 us    |          _raw_spin_unlock();
 1)               |          __device_attach() {
 1)               |            my_bus_match [bus_final_1]() {
 1)               |              printk() {
 1)               |                vprintk_default() {
 1)               |                  vprintk_emit() {
 1)   0.291 us    |                    _raw_spin_lock();
 1)   0.496 us    |                    log_store();
 1)   0.085 us    |                    _raw_spin_unlock();
 1)   0.265 us    |                    console_trylock();
 1)   2.800 us    |                    console_unlock();
 1) + 15.946 us   |                  }
 1) + 17.038 us   |                }
 1) + 18.301 us   |              }
 1) + 19.412 us   |            }
 1)               |            driver_probe_device() {
 1)               |              pm_runtime_barrier() {
 1)   0.115 us    |                _raw_spin_lock_irq();
 1)   0.135 us    |                __pm_runtime_barrier();
 1)   1.393 us    |              }
 1)               |              pinctrl_bind_pins() {
 1)               |              my_driver_probe [bus_final_1]() {
 1)               |                printk() {
 1)               |                  vprintk_default() {
 1)   4.534 us    |                    vprintk_emit();
 1)   5.130 us    |                  }
 1)   5.711 us    |                }
 1)               |                alloc_chrdev_region() {
 1)               |                  __register_chrdev_region() {
 1)   0.155 us    |                    kmem_cache_alloc_trace();
 1)   0.516 us    |                    mutex_lock();
 1)   0.106 us    |                    mutex_unlock();
 1)   2.660 us    |                  }
 1)   3.327 us    |                }
 1)               |                printk() {
 1)               |                  vprintk_default() {
 1)   2.841 us    |                    vprintk_emit();
 1)   3.427 us    |                  }
 1)   4.053 us    |                }
 1)               |                __class_create() {
 1)               |                  kmem_cache_alloc_trace() {
 1)   0.090 us    |                    _cond_resched();
 1)   0.902 us    |                  }
 1)               |                  __class_register() {
 1)   1.348 us    |                    kmem_cache_alloc_trace();
 1)   0.091 us    |                    __mutex_init();
 1)   0.216 us    |                    __kmalloc_track_caller();
 1)   0.101 us    |                    kfree();
 1)   0.110 us    |                    _raw_spin_lock();
 1)   0.080 us    |                    _raw_spin_unlock();
 1)   3.927 us    |                    sysfs_create_dir_ns();
 1)   0.110 us    |                    kernfs_get();
 1)   0.090 us    |                    class_child_ns_type();
 1)   0.586 us    |                    kmem_cache_alloc_trace();
 1) + 30.034 us   |                  }
 1) + 32.197 us   |                }
 1)               |                printk() {
 1)               |                  vprintk_default() {
 1)   2.680 us    |                    vprintk_emit();
 1)   3.266 us    |                  }
 1)   3.858 us    |                }
 1)               |                device_create() {
 1)               |                  device_create_groups_vargs() {
 1)   0.542 us    |                    kmem_cache_alloc_trace();
 1)   0.861 us    |                    device_initialize();
 1)   0.206 us    |                    __kmalloc_track_caller();
 1)   0.100 us    |                    kfree();
 1) # 2434.891 us |                    device_add();
 1) # 2443.262 us |                  }
 1) # 2443.979 us |                }
 1)               |                printk() {
 1)               |                  vprintk_default() {
 1)   5.891 us    |                    vprintk_emit();
 1)   6.703 us    |                  }
 1)   7.410 us    |                }
 1)               |                kmem_cache_alloc_trace() {
 1)   0.090 us    |                  _cond_resched();
 1)   0.896 us    |                }
 1)   0.255 us    |                cdev_init();
 1)               |                cdev_add() {
 1)               |                  kobj_map() {
 1)   0.240 us    |                    __kmalloc();
 1)   0.400 us    |                    mutex_lock();
 1)   0.100 us    |                    mutex_unlock();
 1)   2.685 us    |                  }
 1)   3.402 us    |                }
 1) # 2511.166 us |              }
 1) # 3992.051 us |  }

Wednesday, 9 December 2015

Linux Interrupt handling for x86 systems


Lets see how the interrupts are handled in x86 system.
For this depiction I have used Linux 3.15 kernel source.

The do_IRQ function is called from the arch/x86/kernel/entry_64.S
...
common_interrupt:
XCPT_FRAME
ASM_CLAC
addq $-0x80,(%rsp) /* Adjust vector to [-256,-1] range */
interrupt do_IRQ
...

do_IRQ implementation
__visible unsigned int __irq_entry do_IRQ(struct pt_regs *regs)
{
struct pt_regs *old_regs = set_irq_regs(regs);

/* high bit used in ret_from_ code  */
unsigned vector = ~regs->orig_ax;
unsigned irq;

irq_enter();
exit_idle();

irq = __this_cpu_read(vector_irq[vector]);

if (!handle_irq(irq, regs)) {
ack_APIC_irq();    ---- End of Interrupt

if (irq != VECTOR_RETRIGGERED) {
pr_emerg_ratelimited("%s: %d.%d No irq handler for vector (irq %d)\n",
    __func__, smp_processor_id(),
    vector, irq);
} else {
__this_cpu_write(vector_irq[vector], VECTOR_UNDEFINED);
}
}

irq_exit();

set_irq_regs(old_regs);
return 1;
}

The do_IRQ implementation first enters into the interrupt context using function irq_enter(). (arch/x86/kernel/irq.c)
The function irq_enter does many stuffs with timers and updates the jiffies.
The function also increments the preempt count : preempt_count_add(HARDIRQ_OFFSET); in __irq_enter()

Then it calls exit_idle to end the idle loop.

Taking the irq number 
Then the do_IRQ function reads the IRQ number from this CPU's vector array.
unsigned vector = ~regs->orig_ax;

irq = __this_cpu_read(vector_irq[vector]);

Now things are set to execute the interrupt handler. It is done in handle_irq function.
bool handle_irq(unsigned irq, struct pt_regs *regs)
{
struct irq_desc *desc;

stack_overflow_check(regs);

desc = irq_to_desc(irq);
if (unlikely(!desc))
return false;

generic_handle_irq_desc(irq, desc);
return true;
}

This function just fetches the interrupt descriptor and calls generic_handle_irq_desc.

static inline void generic_handle_irq_desc(unsigned int irq, struct irq_desc *desc)
{
desc->handle_irq(irq, desc);
}

This function calls handle_irq for this descriptor:
desc->handle_irq(irq, desc);

The handle_irq would have been set by irq_set_chip_and_handler_name at the time of initialization.
Generally this will point to handle_edge_irq or handle_level_irq. These functions are set depending upon if the interrupt getting handled is level triggered or edge.

Difference between Edge triggered and Level Triggered interrupt handling 

The edge triggered interrupts need not be masked when it is getting handled, whereas the level triggered interrupts need to be masked.

handle_edge_irq
void
handle_edge_irq(unsigned int irq, struct irq_desc *desc)
{
raw_spin_lock(&desc->lock);

desc->istate &= ~(IRQS_REPLAY | IRQS_WAITING);
/*
* If we're currently running this IRQ, or its disabled,
* we shouldn't process the IRQ. Mark it pending, handle
* the necessary masking and go out
*/
if (unlikely(irqd_irq_disabled(&desc->irq_data) ||
    irqd_irq_inprogress(&desc->irq_data) || !desc->action)) {
if (!irq_check_poll(desc)) {
desc->istate |= IRQS_PENDING;
mask_ack_irq(desc);
goto out_unlock;
}
}
kstat_incr_irqs_this_cpu(irq, desc);

/* Start handling the irq */
desc->irq_data.chip->irq_ack(&desc->irq_data);

do {
if (unlikely(!desc->action)) {
mask_irq(desc);
goto out_unlock;
}

/*
* When another irq arrived while we were handling
* one, we could have masked the irq.
* Renable it, if it was not disabled in meantime.
*/
if (unlikely(desc->istate & IRQS_PENDING)) {
if (!irqd_irq_disabled(&desc->irq_data) &&
   irqd_irq_masked(&desc->irq_data))
unmask_irq(desc);
}

handle_irq_event(desc);

} while ((desc->istate & IRQS_PENDING) &&
!irqd_irq_disabled(&desc->irq_data));

out_unlock:
raw_spin_unlock(&desc->lock);
}

EXPORT_SYMBOL(handle_edge_irq);

[BOOKMARK]As, the edge triggered interrupt are not masked they can appear on another CPU even if they are getting handled on one CPU.
The first part of function handle_edge_irq checks if it is running on another CPU then it masks the interrupt and sends and acknowledgment for it.

if (unlikely(irqd_irq_disabled(&desc->irq_data) ||
    irqd_irq_inprogress(&desc->irq_data) || !desc->action)) {
if (!irq_check_poll(desc)) {
desc->istate |= IRQS_PENDING;
mask_ack_irq(desc);
goto out_unlock;
}
}

Next  handle_edge_irq sends an ack to interrupt controller.
/* Start handling the irq */
desc->irq_data.chip->irq_ack(&desc->irq_data);


Next there is a loop to handle all the interrupt requests which come for this irq.

do {
if (unlikely(!desc->action)) {
mask_irq(desc);
goto out_unlock;
}

/*
* When another irq arrived while we were handling
* one, we could have masked the irq.
* Renable it, if it was not disabled in meantime.
*/
if (unlikely(desc->istate & IRQS_PENDING)) {
if (!irqd_irq_disabled(&desc->irq_data) &&
   irqd_irq_masked(&desc->irq_data))
unmask_irq(desc);
}

handle_irq_event(desc);

} while ((desc->istate & IRQS_PENDING) &&
!irqd_irq_disabled(&desc->irq_data));


Here it checks for another pending interrupt(which might have come on another CPU) and executes it. See [BOOKMARK]


handle_level_irq :
void
handle_level_irq(unsigned int irq, struct irq_desc *desc)
{
raw_spin_lock(&desc->lock);
mask_ack_irq(desc);

if (unlikely(irqd_irq_inprogress(&desc->irq_data)))
if (!irq_check_poll(desc))
goto out_unlock;

desc->istate &= ~(IRQS_REPLAY | IRQS_WAITING);
kstat_incr_irqs_this_cpu(irq, desc);

/*
* If its disabled or no action available
* keep it masked and get out of here
*/
if (unlikely(!desc->action || irqd_irq_disabled(&desc->irq_data))) {
desc->istate |= IRQS_PENDING;
goto out_unlock;
}

handle_irq_event(desc);

cond_unmask_irq(desc);

out_unlock:
raw_spin_unlock(&desc->lock);
}
EXPORT_SYMBOL_GPL(handle_level_irq);

As this function has to run with all the interrupts masked. There are less race conditions than handle_edge_irq
This function just calls mask_ack_irq(desc);

handle_irq_event : This function runs all the handlers registered with this interrupt

do {
irqreturn_t res;

trace_irq_handler_entry(irq, action);
res = action->handler(irq, action->dev_id);
trace_irq_handler_exit(irq, action, res);

if (WARN_ONCE(!irqs_disabled(),"irq %u handler %pF enabled interrupts\n",
     irq, action->handler))
local_irq_disable();

switch (res) {
case IRQ_WAKE_THREAD:
/*
* Catch drivers which return WAKE_THREAD but
* did not set up a thread function
*/
if (unlikely(!action->thread_fn)) {
warn_no_thread(irq, action);
break;
}

__irq_wake_thread(desc, action);

/* Fall through to add to randomness */
case IRQ_HANDLED:
flags |= action->flags;
break;

default:
break;
}

retval |= res;
action = action->next;
} while (action);


End of Interrupt : The APIC on x86 systems has to send the #EOI signal on the PCI bus to tell that interrupt processing is finished. This is done just after the irq is handled in do_IRQ function.

do_IRQ()
...
if (!handle_irq(irq, regs)) {
ack_APIC_irq();
...



Following ftrace graph on do_IRQ function will tell you the sequence of events :
1)   ==========> |
 1)               |  do_IRQ() {
 1)               |    irq_enter() {
 1)               |      rcu_irq_enter() {
 1)   0.201 us    |        rcu_eqs_exit_common.isra.45();
 1)   1.223 us    |      }
 1)               |      tick_irq_enter() {
 1)   0.190 us    |        tick_check_oneshot_broadcast_this_cpu();
 1)               |        ktime_get() {
 1)   1.192 us    |          read_hpet();
 1)   2.174 us    |        }
 1)               |        update_ts_time_stats() {
 1)   0.175 us    |          nr_iowait_cpu();
 1)   1.217 us    |        }
 1)               |        ktime_get() {
 1)   1.057 us    |          read_hpet();
 1)   2.019 us    |        }
 1)   0.135 us    |        touch_softlockup_watchdog();
 1)               |        tick_do_update_jiffies64() {
 1)   0.185 us    |          _raw_spin_lock();
 1)               |          do_timer() {
 1)   0.140 us    |            calc_global_load();
 1)   1.162 us    |          }
 1)   0.135 us    |          _raw_spin_unlock();
 1)               |          update_wall_time() {
 1)   0.200 us    |            _raw_spin_lock_irqsave();
 1)   0.967 us    |            read_hpet();
 1)   0.140 us    |            ntp_tick_length();
 1)   0.136 us    |            ntp_tick_length();
 1)   0.136 us    |            ntp_tick_length();
 1)               |            timekeeping_update.constprop.8() {
 1)   0.290 us    |              update_vsyscall();
 1)               |              raw_notifier_call_chain() {
 1)   0.246 us    |                notifier_call_chain();
 1)   1.193 us    |              }
 1)   3.526 us    |            }
 1)   0.191 us    |            _raw_spin_unlock_irqrestore();
 1) + 11.778 us   |          }
 1) + 16.802 us   |        }
 1)   0.135 us    |        touch_softlockup_watchdog();
 1) + 29.011 us   |      }
 1)               |      _local_bh_enable() {
 1)   0.145 us    |        __local_bh_enable();
 1)   1.107 us    |      }
 1) + 34.723 us   |    }
 1)               |    exit_idle() {
 1)               |      atomic_notifier_call_chain() {
 1)   0.145 us    |        notifier_call_chain();
 1)   1.107 us    |      }
 1)   2.069 us    |    }
 1)               |    handle_irq() {
 1)   0.225 us    |      irq_to_desc();
 1)               |      handle_edge_irq() {
 1)   0.175 us    |        _raw_spin_lock();
 1)   0.180 us    |        irq_may_run();
 1)               |        apic_ack_edge() {
 1)   0.140 us    |          irq_complete_move();
 1)   0.140 us    |          irq_move_irq();
 1)   2.069 us    |        }
 1)               |        handle_irq_event() {
 1)   0.140 us    |          _raw_spin_unlock();
 1)               |          handle_irq_event_percpu() {
 1)               |            i8042_interrupt() {
 1)   0.231 us    |              _raw_spin_lock_irqsave();
 1)   0.155 us    |              _raw_spin_unlock_irqrestore();
 1)               |              serio_interrupt() {
 1)   0.205 us    |                _raw_spin_lock_irqsave();
 1)               |                psmouse_interrupt [psmouse]() {
 1)               |                  psmouse_handle_byte [psmouse]() {
 1)   0.315 us    |                    synaptics_process_byte [psmouse]();
 1)   1.303 us    |                  }
 1)   2.390 us    |                }
 1)   0.210 us    |                _raw_spin_unlock_irqrestore();
 1)   5.816 us    |              }
 1) + 14.528 us   |            }
 1)   0.340 us    |            add_interrupt_randomness();
 1)   0.196 us    |            note_interrupt();
 1) + 18.517 us   |          }
 1)   0.196 us    |          _raw_spin_lock();
 1) + 21.462 us   |        }
 1)   0.150 us    |        _raw_spin_unlock();
 1) + 28.525 us   |      }
 1) + 30.554 us   |    }
 1)               |    irq_exit() {
 1)   0.165 us    |      idle_cpu();
 1)               |      tick_nohz_irq_exit() {
 1)               |        __tick_nohz_idle_enter() {
 1)               |          ktime_get() {
 1)   1.298 us    |            read_hpet();
 1)   2.340 us    |          }
 1)   0.151 us    |          timekeeping_max_deferment();
 1)               |          get_next_timer_interrupt() {
 1)   0.206 us    |            _raw_spin_lock();
 1)   0.151 us    |            _raw_spin_unlock();
 1)               |            hrtimer_get_next_event() {
 1)   0.191 us    |              _raw_spin_lock_irqsave();
 1)   0.151 us    |              _raw_spin_unlock_irqrestore();
 1)   2.109 us    |            }
 1)   5.100 us    |          }
 1)               |          hrtimer_start() {
 1)               |            __hrtimer_start_range_ns() {
 1)               |              lock_hrtimer_base.isra.22() {
 1)   0.180 us    |                _raw_spin_lock_irqsave();
 1)   1.147 us    |              }
 1)   0.246 us    |              __remove_hrtimer();
 1)   0.135 us    |              get_nohz_timer_target();
 1)   0.321 us    |              enqueue_hrtimer();
 1)   0.156 us    |              _raw_spin_unlock_irqrestore();
 1)   6.373 us    |            }
 1)   7.329 us    |          }
 1) + 18.691 us   |        }
 1) + 19.658 us   |      }
 1)               |      rcu_irq_exit() {
 1)   0.225 us    |        rcu_eqs_enter_common.isra.44();
 1)   1.277 us    |      }
 1) + 23.781 us   |    }
 1) + 94.920 us   |  }
 1)   <========== |