Linux libaio example and ftrace

LIBAIO

Lets see sample program which uses libaio and delve into the IO path for the same. 

#include <linux/aio_abi.h>
#include <sys/syscall.h>
#include <linux/aio_abi.h>
#include <errno.h>
#include <stdio.h>
#include <stdlib.h>
#include <sys/types.h>
#include <sys/stat.h>
#include <fcntl.h>
#include <unistd.h>
#include <inttypes.h>
#include <assert.h>
typedef unsigned long uintptr_t;
int fd = 0;
int fd1 = 0;
// first operation
char buff1[512];
struct iocb iocb1    = {0};

// second operation
char buff2[512];
struct iocb iocb2    = {0};
aio_context_t ioctx = 0;
unsigned maxevents = 128;

// syscall wrappers
static inline int
io_setup(unsigned maxevents, aio_context_t *ctx) {
    return syscall(SYS_io_setup, maxevents, ctx);
}

static inline int
io_submit(aio_context_t ctx, long nr, struct iocb **iocbpp) {
    return syscall(SYS_io_submit, ctx, nr, iocbpp);
}

static inline int
io_getevents(aio_context_t ctx, long min_nr, long nr,
                 struct io_event *events, struct timespec *timeout) {
    return syscall(SYS_io_getevents, ctx, min_nr, nr, events, timeout);
}

static inline int
io_destroy(aio_context_t ctx)
{
    return syscall(SYS_io_destroy, ctx);
}

void fill_iocb_1(int local_fd)
{
iocb1.aio_data       = 0xbeef; // will be returned in completion
iocb1.aio_fildes     = local_fd;
iocb1.aio_lio_opcode = IOCB_CMD_PREAD;
iocb1.aio_reqprio    = 0;
iocb1.aio_buf        = (uintptr_t)buff1;
iocb1.aio_nbytes     = sizeof(buff1);
iocb1.aio_offset     = 0;      // read file at offset 0
}

void fill_iocb_2(int local_fd)
{
iocb2.aio_data       = 0xbaba; // will be returned in completion
iocb2.aio_fildes     = local_fd;
iocb2.aio_lio_opcode = IOCB_CMD_PREAD;
iocb2.aio_reqprio    = 0;
iocb2.aio_buf        = (uintptr_t)buff2;
iocb2.aio_nbytes     = sizeof(buff2);
iocb2.aio_offset     = 4096;   // read file at offset 4096 (bytes)
}

int main()
{
struct iocb *iocb_ptrs[2] = { &iocb1, &iocb2 };
size_t nevents = 2;
struct io_event events[nevents];
int ret = 0;
nevents = 2;
fd = open("/root/test", O_RDWR|O_DIRECT);
if(fd < 0)
{
perror("file open");
exit(1);
}
ioctx = 0;
if (io_setup(maxevents, &ioctx) < 0) {
perror("io_setup");
exit(1);
}
else {
printf("io_setup is successsful\n");
}
fill_iocb_1(fd);
fill_iocb_2(fd);
// submit operations
ret = io_submit(ioctx, 2, iocb_ptrs);
if (ret < 0) {
perror("io_submit");
exit(1);
} else if (ret != 2) {
perror("io_submit: unhandled partial success");
exit(1);
}
ret = io_getevents(ioctx, 1 /* min */, nevents, events, NULL);
if (ret < 0) {
perror("io_getevents");
exit(1);
}
printf("Got %d events\n", ret);
for (size_t i=0; i<ret; i++) {
struct io_event *ev = &events[i];
assert(ev->data == 0xbeef || ev->data == 0xbaba);
printf("Event returned with res=%lld res2=%lld\n", ev->res, ev->res2);
nevents--;
if (ev->res < 0 ){
printf("Error \n");
}
if(i == 0)
{
printf("Data = \n");
for (int j = 0; j < 512; j++)
printf("%d\n", buff1[j]);
printf("\n");
}
}
io_destroy(ioctx);
close(fd);
return 0;
}

Lets ftrace the io_submit and io_getevents functions : 
cd /sys/kernel/debug/tracing
cat /dev/null >  trace
echo __x64_sys_io_submit > set_graph_function
echo 10 > max_graph_depth
echo function_graph > current_tracer
echo 1 > tracing_on

/root/libaio/./a.out  

cp trace ~/io_submit_dio_trace_depth_10_2
echo 0 > tracing_on
echo > set_graph_function
echo 0 > max_graph_depth
cat /dev/null >  trace

libaio and O_DIRECT
https://stackoverflow.com/questions/34235892/should-libaio-engine-to-be-used-with-unbuffered-io-directonly

Compilation : 
gcc -D_GNU_SOURCE my_aio.c


# tracer: function_graph
#
# CPU  DURATION                  FUNCTION CALLS
# |     |   |                     |   |   |   |
 11)               |  __x64_sys_io_submit() {
 11)               |    lookup_ioctx() {
 11)               |      do_page_fault() {
 11)               |        __do_page_fault() {
 11)   0.307 us    |          down_read_trylock();
 11)               |          find_vma() {
 11)   0.433 us    |            vmacache_find();
 11)   0.270 us    |            vmacache_update();
 11)   1.626 us    |          }
 11)               |          handle_mm_fault() {
 11)   0.319 us    |            mem_cgroup_from_task();
 11)   0.264 us    |            __count_memcg_events();
 11)               |            __handle_mm_fault() {
 11)   0.330 us    |              pmd_devmap_trans_unstable();
 11)               |              do_fault() {
 11)               |                filemap_map_pages() {
 11)               |                  alloc_set_pte() {
 11)   0.322 us    |                    pmd_devmap_trans_unstable();
 11)   0.332 us    |                    _raw_spin_lock();
 11)   1.027 us    |                    page_add_file_rmap();
 11)   3.002 us    |                  }
 11)   0.346 us    |                  unlock_page();
 11)               |                  alloc_set_pte() {
 11)   0.801 us    |                    page_add_file_rmap();
 11)   1.358 us    |                  }
 11)   0.282 us    |                  unlock_page();
 11)               |                  alloc_set_pte() {
 11)   0.791 us    |                    page_add_file_rmap();
 11)   1.336 us    |                  }
 11)   0.270 us    |                  unlock_page();
 11)   8.944 us    |                }
 11)   9.706 us    |              }
 11) + 11.120 us   |            }
 11) + 12.799 us   |          }
 11)   0.266 us    |          up_read();
 11) + 17.076 us   |        }
 11) + 17.596 us   |      }
 11) + 19.061 us   |    }
 11)               |    io_submit_one() {
 11)               |      kmem_cache_alloc() {
 11)   0.358 us    |        should_failslab();
 11)   0.960 us    |      }
 11)   0.334 us    |      __get_reqs_available();
 11)               |      fget() {
 11)   0.300 us    |        __fget();
 11)   0.953 us    |      }
 11)               |      aio_read() {
 11)   0.755 us    |        aio_prep_rw();
 11)   0.545 us    |        aio_setup_rw();
 11)               |        rw_verify_area() {
 11)               |          security_file_permission() {
 11)               |            apparmor_file_permission() {
 11)               |              common_file_perm() {
 11)   0.285 us    |                aa_file_perm();
 11)   0.866 us    |              }
 11)   1.408 us    |            }
 11)   0.292 us    |            __fsnotify_parent();
 11)   0.319 us    |            fsnotify();
 11)   3.108 us    |          }
 11)   3.707 us    |        }
 11)               |        generic_file_read_iter() {
 11)               |          filemap_write_and_wait_range() {
 11)   0.392 us    |            __filemap_fdatawrite_range();
 11)               |            __filemap_fdatawait_range() {
 11)               |              pagevec_lookup_range_tag() {
 11)   0.760 us    |                find_get_pages_range_tag();
 11)   1.475 us    |              }
 11)   2.040 us    |            }
 11)   0.313 us    |            filemap_check_errors();
 11)   4.029 us    |          }
 11)               |          touch_atime() {
 11)               |            atime_needs_update() {
 11)               |              current_time() {
 11)   0.263 us    |                ktime_get_coarse_real_ts64();
 11)   0.266 us    |                timespec64_trunc();
 11)   1.393 us    |              }
 11)   1.980 us    |            }
 11)   2.514 us    |          }
 11)   0.690 us    |          btrfs_direct_IO [btrfs]();
 11)               |          _cond_resched() {
 11)   0.335 us    |            rcu_all_qs();
 11)   0.859 us    |          }
 11)               |          pagecache_get_page() {
 11)   0.574 us    |            find_get_entry();
 11)   2.355 us    |          }
 11)   0.340 us    |          mark_page_accessed();
 11)               |          touch_atime() {
 11)               |            atime_needs_update() {
 11)               |              current_time() {
 11)   0.268 us    |                ktime_get_coarse_real_ts64();
 11)   0.268 us    |                timespec64_trunc();
 11)   1.318 us    |              }
 11)   1.876 us    |            }
 11)   2.436 us    |          }
 11) + 17.043 us   |        }
 11)   0.429 us    |        aio_complete_rw();
 11)   0.295 us    |        kfree();
 11) + 25.152 us   |      }
 11)   0.276 us    |      _raw_spin_lock_irqsave();
 11)   0.274 us    |      _raw_spin_unlock_irqrestore();
 11)               |      fput() {
 11)   0.287 us    |        fput_many();
 11)   0.786 us    |      }
 11)   0.547 us    |      kmem_cache_free();
 11) + 32.749 us   |    }
 11)               |    io_submit_one() {
 11)               |      kmem_cache_alloc() {
 11)   0.266 us    |        should_failslab();
 11)   0.799 us    |      }
 11)   0.296 us    |      __get_reqs_available();
 11)               |      fget() {
 11)   0.328 us    |        __fget();
 11)   0.823 us    |      }
 11)               |      aio_read() {
 11)   0.366 us    |        aio_prep_rw();
 11)   0.294 us    |        aio_setup_rw();
 11)               |        rw_verify_area() {
 11)               |          security_file_permission() {
 11)               |            apparmor_file_permission() {
 11)               |              common_file_perm() {
 11)   0.330 us    |                aa_file_perm();
 11)   0.859 us    |              }
 11)   1.359 us    |            }
 11)   0.276 us    |            __fsnotify_parent();
 11)   0.285 us    |            fsnotify();
 11)   3.073 us    |          }
 11)   3.628 us    |        }
 11)               |        generic_file_read_iter() {
 11)               |          filemap_write_and_wait_range() {
 11)   0.281 us    |            __filemap_fdatawrite_range();
 11)               |            __filemap_fdatawait_range() {
 11)               |              pagevec_lookup_range_tag() {
 11)   0.401 us    |                find_get_pages_range_tag();
 11)   0.909 us    |              }
 11)   1.440 us    |            }
 11)   0.273 us    |            filemap_check_errors();
 11)   3.073 us    |          }
 11)               |          touch_atime() {
 11)               |            atime_needs_update() {
 11)               |              current_time() {
 11)   0.268 us    |                ktime_get_coarse_real_ts64();
 11)   0.268 us    |                timespec64_trunc();
 11)   1.388 us    |              }
 11)   1.974 us    |            }
 11)   2.546 us    |          }
 11)   0.311 us    |          btrfs_direct_IO [btrfs]();
 11)   7.110 us    |        }
 11)   0.344 us    |        aio_complete_rw();
 11)   0.308 us    |        kfree();
 11) + 14.100 us   |      }
 11)   0.322 us    |      _raw_spin_lock_irqsave();
 11)   0.304 us    |      refill_reqs_available();
 11)   0.344 us    |      _raw_spin_unlock_irqrestore();
 11)               |      fput() {
 11)   0.265 us    |        fput_many();
 11)   0.804 us    |      }
 11)   0.293 us    |      kmem_cache_free();
 11) + 21.363 us   |    }
 11) + 76.921 us   |  }

Linux io_uring example and internals

Linux io_uring basics and details can be fetched from here https://kernel.dk/io_uring.pdf. Reader is encouraged to complete this document first. 

Also various examples of io_uring are mentioned here:
https://github.com/shuveb/io_uring-by-example   

I am using 5.3.18-22 kernel in this blog. 

Lets see the program to do read of twenty(20) 512bytes blocks from a block device.

#include <stdio.h>
#include <stdlib.h>
#include <sys/stat.h>
#include <sys/ioctl.h>
#include <sys/syscall.h>
#include <sys/mman.h>
#include <sys/uio.h>
#include <linux/fs.h>

#include <fcntl.h>
#include <unistd.h>
#include <string.h>
/* If your compilation fails because the header file below is missing,
 * your kernel is probably too old to support io_uring.

 * */
#include <linux/io_uring.h>

#define QUEUE_DEPTH 1
#define BLOCK_SZ    512

/* This is x86 specific */
#define read_barrier()  __asm__ __volatile__("":::"memory")
#define write_barrier() __asm__ __volatile__("":::"memory")

struct app_io_sq_ring {
    unsigned *head;
    unsigned *tail;
    unsigned *ring_mask;
    unsigned *ring_entries;
    unsigned *flags;
    unsigned *array;
};

struct app_io_cq_ring {
    unsigned *head;
    unsigned *tail;
    unsigned *ring_mask;
    unsigned *ring_entries;
    struct io_uring_cqe *cqes;
};

struct submitter {
    int ring_fd;
    struct app_io_sq_ring sq_ring;
    struct io_uring_sqe *sqes;
    struct app_io_cq_ring cq_ring;
};

int io_uring_setup(unsigned entries, struct io_uring_params *p)
{
    return (int) syscall(__NR_io_uring_setup, entries, p);
}

int io_uring_enter(int ring_fd, unsigned int to_submit,
                          unsigned int min_complete, unsigned int flags)
{
    return (int) syscall(__NR_io_uring_enter, ring_fd, to_submit, min_complete,
                   flags, NULL, 0);
}

struct io_info {
    int num_io;
    struct iovec iovecs[];
};

struct file_info {
    off_t file_sz;
    struct iovec iovecs[];      /* Referred by readv/writev */
};

int submit_to_sq(char *file_path, struct submitter *s) {
    struct io_info *ii;
    struct stat st;

    int file_fd = open(file_path, O_RDONLY);
    if (file_fd < 0 ) {
        perror("open");
        return 1;
    }

    struct app_io_sq_ring *sring = &s->sq_ring;
    unsigned index = 0, tail = 0, next_tail = 0;
    off_t file_sz = 0;

    // fetch the block device size

    if(fstat(file_fd, &st) < 0) {
        perror("fstat");
        return -1;
    }

    if (S_ISBLK(st.st_mode)) {
        unsigned long long bytes;
        if (ioctl(file_fd, BLKGETSIZE64, &bytes) != 0) {
            perror("ioctl");
            return -1;
        }
        file_sz =  bytes;
    } else if (S_ISREG(st.st_mode))
        file_sz =  st.st_size;

    printf("sz = %llu\n", file_sz);

    if (file_sz < 0)
        return 1;

    //Lets submit IO to read first 20 blocks
    struct iovec *iovecs;//[20];
    ii = malloc(sizeof(*ii) + sizeof(struct iovec) * 20);
    memset (ii, 0, sizeof(*ii) + (sizeof(struct iovec) * 20));

    iovecs = ii->iovecs;
    ii->num_io = 20;

    for (int i = 0;i < 20;i++)
    {
        iovecs[i].iov_len = 512;

        void *buf;
        if( posix_memalign(&buf, BLOCK_SZ, BLOCK_SZ)) {
            perror("posix_memalign");
            return 1;
        }

        iovecs[i].iov_base = buf;
    }
    /* Add our submission queue entry to the tail of the SQE ring buffer */

    next_tail = tail = *sring->tail;
    read_barrier();
    index = tail & *s->sq_ring.ring_mask;

    next_tail++;

    struct io_uring_sqe *sqe = &s->sqes[index];
    sqe->fd = file_fd;
    sqe->flags = 0;
    sqe->opcode = IORING_OP_READV;
    sqe->addr = (unsigned long) iovecs;
    sqe->len = 20;
    sqe->off = 0;
    sqe->user_data = (unsigned long long) ii;
    sring->array[index] = index;
    tail = next_tail;

    /* Update the tail so the kernel can see it. */
    if(*sring->tail != tail) {
        *sring->tail = tail;
        write_barrier();
    }

    int ret =  io_uring_enter(s->ring_fd, 1, 1,  IORING_ENTER_GETEVENTS);
    if(ret < 0) {
        perror("io_uring_enter");
        return 1;
    }
    return 0;
}

void read_from_cq(struct submitter *s) {
    struct iovec *iovecs;
    struct io_info *ii;
    struct app_io_cq_ring *cring = &s->cq_ring;
    struct io_uring_cqe *cqe;
    unsigned head, reaped = 0;
    head = *cring->head;
    do {
        read_barrier();
        /*
         * Remember, this is a ring buffer. If head == tail, it means that the
         * buffer is empty.
         * */
        if (head == *cring->tail)
            break;

        /* Get the entry */
        cqe = &cring->cqes[head & *s->cq_ring.ring_mask];
        ii = (struct io_info*) cqe->user_data;
        iovecs = ii->iovecs;
        if (cqe->res < 0)
            fprintf(stderr, "Error: %s\n", strerror(abs(cqe->res)));

        for (int i = 0; i < 20; i++)
        {
             printf("iov_base  = %p, iov_len = %d\n",
                 iovecs[i].iov_base, iovecs[i].iov_len);
             printf("%d, %d\n", *((char *)iovecs[i].iov_base) , *((char *)iovecs[i].iov_base + 1));

        }
        head++;
    } while (1);
    cring->head = head;
    write_barrier();
}

int app_setup_uring(struct submitter *s) {
struct app_io_sq_ring *sring = &s->sq_ring;
    struct app_io_cq_ring *cring = &s->cq_ring;
    struct io_uring_params p;
    void *sq_ptr, *cq_ptr;
    memset(&p, 0, sizeof(p));
    s->ring_fd = io_uring_setup(QUEUE_DEPTH, &p);
    if (s->ring_fd < 0) {
        perror("io_uring_setup");
        return 1;
    }

    // Fetch and decide on submission and completion ring sizes
    int sring_sz = p.sq_off.array + p.sq_entries * sizeof(unsigned);
    int cring_sz = p.cq_off.cqes + p.cq_entries * sizeof(struct io_uring_cqe);
    printf("sring_sz  = %d, cring_sz = %d\n", sring_sz, cring_sz);

    //  mmap the submission ring
    sq_ptr = mmap(0, sring_sz, PROT_READ | PROT_WRITE,
            MAP_SHARED | MAP_POPULATE,
            s->ring_fd, IORING_OFF_SQ_RING);
    if (sq_ptr == MAP_FAILED) {
        perror("mmap");
        return 1;
    }

    // mmap the completion ring
    /* Map in the completion queue ring buffer in older kernels separately */
        cq_ptr = mmap(0, cring_sz, PROT_READ | PROT_WRITE,
                MAP_SHARED | MAP_POPULATE,
                s->ring_fd, IORING_OFF_CQ_RING);

        if (cq_ptr == MAP_FAILED) {

            perror("mmap");
            return 1;
        }
    /* Save useful fields in a global app_io_sq_ring struct for later easy reference */
    sring->head = sq_ptr + p.sq_off.head;
    sring->tail = sq_ptr + p.sq_off.tail;
    sring->ring_mask = sq_ptr + p.sq_off.ring_mask;
    sring->ring_entries = sq_ptr + p.sq_off.ring_entries;
    sring->flags = sq_ptr + p.sq_off.flags;
    sring->array = sq_ptr + p.sq_off.array;
    /* Map in the submission queue entries array */
    s->sqes = mmap(0, p.sq_entries * sizeof(struct io_uring_sqe),
            PROT_READ | PROT_WRITE, MAP_SHARED | MAP_POPULATE,
            s->ring_fd, IORING_OFF_SQES);
    if (s->sqes == MAP_FAILED) {
        perror("mmap");
        return 1;
    }
    /* Save useful fields in a global app_io_cq_ring struct for later easy reference */
    cring->head = cq_ptr + p.cq_off.head;
    cring->tail = cq_ptr + p.cq_off.tail;
    cring->ring_mask = cq_ptr + p.cq_off.ring_mask;
    cring->ring_entries = cq_ptr + p.cq_off.ring_entries;
    cring->cqes = cq_ptr + p.cq_off.cqes;
    return 0;
}
int main(int argc, char *argv[]) {
    struct submitter *s;
    s = malloc(sizeof(*s));
    if (!s) {
        perror("malloc");
        return 1;
    }
    memset(s, 0, sizeof(*s));
    if(app_setup_uring(s)) {
        fprintf(stderr, "Unable to setup uring!\n");
        return 1;
    }
    printf("setup completed\n");

    // Open the block device and read the data

    submit_to_sq(argv[1], s);
    printf("submit cq completed\n");
    read_from_cq(s);
    printf("read cq completed\n");
}

Output of this program :

 ./a.out /dev/sdej

sring_sz  = 148, cring_sz = 176

setup completed

sz = 5369364480

submit cq completed

iov_base  = 0x17aca00, iov_len = 512

0, 0

iov_base  = 0x17ace00, iov_len = 512

0, 0

iov_base  = 0x17ad200, iov_len = 512

-128, 2

iov_base  = 0x17ad600, iov_len = 512

0, 0

iov_base  = 0x17ada00, iov_len = 512

0, 0

iov_base  = 0x17ade00, iov_len = 512

0, 0

iov_base  = 0x17ae200, iov_len = 512

0, 0

iov_base  = 0x17ae800, iov_len = 512

0, 0

iov_base  = 0x17aec00, iov_len = 512

-127, 2

iov_base  = 0x17af000, iov_len = 512

-119, 2

iov_base  = 0x17af400, iov_len = 512

0, 0

iov_base  = 0x17af800, iov_len = 512

8, 0

iov_base  = 0x17afc00, iov_len = 512

0, 0

iov_base  = 0x17b0000, iov_len = 512

0, 0

iov_base  = 0x17b0400, iov_len = 512

0, 0

iov_base  = 0x17b0a00, iov_len = 512

0, 0

iov_base  = 0x17b0e00, iov_len = 512

2, -128

iov_base  = 0x17b1200, iov_len = 512

0, 0

iov_base  = 0x17b1600, iov_len = 512

0, 0

iov_base  = 0x17b1a00, iov_len = 512

0, 0

read cq completed

Lets see the system calls this program uses : 

cat /proc/kallsyms | grep uring_setup

ffffffff9cf30b30 t io_uring_setup

ffffffff9cf31350 T __x64_sys_io_uring_setup

Also after this mmap is done for submission and completion rings. Then we use io_uring_enter

 cat /proc/kallsyms | grep io_uring_enter

ffffffff9cf300c0 T __ia32_sys_io_uring_enter

ffffffff9cf30390 T __x64_sys_io_uring_enter

Ftrace for the io_uring_enter : 

# tracer: function_graph

#

# CPU  DURATION                  FUNCTION CALLS

# |     |   |                     |   |   |   |

  9)               |  __x64_sys_io_uring_enter() {

  9)               |    __fdget() {

  9)   0.395 us    |      __fget_light();

  9)   1.620 us    |    }

  9)   0.370 us    |    mutex_lock();

  9)               |    io_ring_submit() {

  9)   0.315 us    |      io_get_sqring();

  9)               |      io_submit_sqe() {

  9)               |        kmem_cache_alloc() {

  9)   0.333 us    |          should_failslab();

  9)   1.075 us    |        }

  9)               |        fget() {

  9)   0.318 us    |          __fget();

  9)   0.960 us    |        }

  9)               |        io_queue_sqe() {

  9)               |          __io_submit_sqe() {

  9)               |            io_read() {

  9)   1.003 us    |              io_prep_rw();

  9)               |              io_import_iovec.isra.28() {

  9)               |                rw_copy_check_uvector() {

  9)               |                  __kmalloc() {

  9)   0.343 us    |                    kmalloc_slab();

  9)   0.325 us    |                    should_failslab();

  9)   1.579 us    |                  }

  9)   2.604 us    |                }

  9)   3.300 us    |              }

  9)               |              rw_verify_area() {

  9)               |                security_file_permission() {

  9)               |                  apparmor_file_permission() {

  9)   0.480 us    |                    common_file_perm();

  9)   1.030 us    |                  }

  9)   0.303 us    |                  __fsnotify_parent();

  9)   0.320 us    |                  fsnotify();

  9)   3.010 us    |                }

  9)   3.650 us    |              }

  9)               |              blkdev_read_iter() {

  9)               |                generic_file_read_iter() {

  9)               |                  _cond_resched() {

  9)   0.295 us    |                    rcu_all_qs();

  9)   0.888 us    |                  }

  9)               |                  pagecache_get_page() {

  9)   0.420 us    |                    find_get_entry();

  9)   1.133 us    |                  }

  9)               |                  touch_atime() {

  9)   0.758 us    |                    atime_needs_update();

  9)   0.493 us    |                    __sb_start_write();

  9)   0.622 us    |                    __mnt_want_write();

  9)   0.513 us    |                    current_time();

  9)   0.767 us    |                    generic_update_time();

  9)   0.293 us    |                    __mnt_drop_write();

  9)   0.290 us    |                    __sb_end_write();

  9)   6.542 us    |                  }

  9) + 10.372 us   |                }

  9) + 10.992 us   |              }

  9)   0.302 us    |              io_async_list_note();

  9)   0.385 us    |              kfree();

  9) + 22.211 us   |            }

  9) + 23.097 us   |          }

  9)               |          kmem_cache_alloc_trace() {

  9)   0.285 us    |            should_failslab();

  9)   0.888 us    |          }

  9)               |          queue_work_on() {

  9)               |            __queue_work() {

  9)   0.295 us    |              get_work_pool();

  9)   0.375 us    |              _raw_spin_lock();

  9)               |              insert_work() {

  9)   0.287 us    |                get_pwq.isra.24();

  9)               |                wake_up_process() {

  9)               |                  try_to_wake_up() {

  9)   0.480 us    |                    _raw_spin_lock_irqsave();

  9)   1.093 us    |                    select_task_rq_fair();

  9)   0.315 us    |                    _raw_spin_lock();

  9)   0.420 us    |                    update_rq_clock();

  9)   3.212 us    |                    ttwu_do_activate();

  9)   0.405 us    |                    _raw_spin_unlock_irqrestore();

  9)   8.424 us    |                  }

  9)   9.002 us    |                }

  9) + 10.362 us   |              }

  9) + 12.360 us   |            }

  9) + 12.982 us   |          }

  9) + 38.604 us   |        }

  9) + 42.868 us   |      }

  9) + 45.786 us   |    }

  9)   0.345 us    |    mutex_unlock();

  9)               |    io_cqring_wait() {

  9)   0.310 us    |      init_wait_entry();

  9)               |      prepare_to_wait_event() {

  9)   0.307 us    |        _raw_spin_lock_irqsave();

  9)   0.300 us    |        _raw_spin_unlock_irqrestore();

  9)   1.545 us    |      }

  9)               |      schedule() {

  9)               |        rcu_note_context_switch() {

  9)   0.293 us    |          rcu_qs();

  9)   0.905 us    |        }

  9)   0.315 us    |        _raw_spin_lock();

  9)               |        update_rq_clock() {

  9)   0.367 us    |          update_rq_clock.part.85();

  9)   0.912 us    |        }

  9)               |        deactivate_task() {

  9)               |          dequeue_task_fair() {

  9)               |            dequeue_entity() {

  9)               |              update_curr() {

  9)   0.352 us    |                update_min_vruntime();

  9)   0.570 us    |                cpuacct_charge();

  9)               |                __cgroup_account_cputime() {

  9)   0.552 us    |                  cgroup_rstat_updated();

  9)   1.487 us    |                }

  9)   4.268 us    |              }

  9)               |              __update_load_avg_se() {

  9)   0.467 us    |                __accumulate_pelt_segments();

  9)   1.555 us    |              }

  9)   0.508 us    |              _raw_spin_lock();

  9)               |              __update_load_avg_cfs_rq() {

  9)   0.455 us    |                __accumulate_pelt_segments();

  9)   1.525 us    |              }

  9)               |              dbs_update_util_handler() {

  9)   0.498 us    |                cpufreq_this_cpu_can_update();

  9)   1.433 us    |              }

  9)   0.450 us    |              clear_buddies();

  9)   0.448 us    |              account_entity_dequeue();

  9)   0.462 us    |              update_cfs_group();

  9)   0.552 us    |              update_min_vruntime();

  9) + 16.094 us   |            }

  9)   0.478 us    |            hrtick_update();

  9) + 18.077 us   |          }

  9) + 18.975 us   |        }

  9)               |        pick_next_task_fair() {

  9)               |          newidle_balance() {

  9)   0.583 us    |            __msecs_to_jiffies();

  9)   1.758 us    |          }

  9)   2.788 us    |        }

  9)               |        put_prev_task_fair() {

  9)               |          put_prev_entity() {

  9)   0.477 us    |            check_cfs_rq_runtime();

  9)   1.347 us    |          }

  9)   2.385 us    |        }

  9)               |        pick_next_task_idle() {

  9)               |          set_next_task_idle() {

  9)   0.573 us    |            __update_idle_core();

  9)   1.512 us    |          }

  9)   2.535 us    |        }

  9)   0.430 us    |        enter_lazy_tlb();

  9)   1.495 us    |        finish_task_switch();

  9) ! 853.302 us  |      }

  9)               |      prepare_to_wait_event() {

  9)   0.585 us    |        _raw_spin_lock_irqsave();

  9)   0.873 us    |        _raw_spin_unlock_irqrestore();

  9)   2.938 us    |      }

  9)               |      finish_wait() {

  9)   0.297 us    |        _raw_spin_lock_irqsave();

  9)   0.305 us    |        _raw_spin_unlock_irqrestore();

  9)   1.605 us    |      }

  9) ! 862.405 us  |    }

  9)   0.315 us    |    io_ring_drop_ctx_refs();

  9) ! 915.753 us  |  }