Friday, 19 April 2019

Write system call and ftrace

We will write a simple C program and write to file. We will see how the write is given to the disk.
Which are the layers through which the IO traverses.

Let us make a file system on the entire disk:

[root@kundan ~]# mkfs.ext4 /dev/sdh
mke2fs 1.42.9 (28-Dec-2013)
/dev/sdh is entire device, not just one partition!
Proceed anyway? (y,n) y
Discarding device blocks: done
Filesystem label=
OS type: Linux
Block size=1024 (log=0)
Fragment size=1024 (log=0)
Stride=0 blocks, Stripe width=0 blocks
130560 inodes, 522240 blocks
26112 blocks (5.00%) reserved for the super user
First data block=1
Maximum filesystem blocks=34078720
64 block groups
8192 blocks per group, 8192 fragments per group
2040 inodes per group
Superblock backups stored on blocks:
        8193, 24577, 40961, 57345, 73729, 204801, 221185, 401409

Allocating group tables: done
Writing inode tables: done
Creating journal (8192 blocks): done
Writing superblocks and filesystem accounting information: done



Let us mount the filesystem on a directory and try to write to a file in that directory.
mount /dev/sdh /mnt

USER SPACE applications :
In our C program we will write to a file in /mnt directory using O_SYNC.
O_SYNC The file is opened for synchronous I/O.  Any write's on the resulting file descriptor will block the calling process until the data has been physically written to the underlying hardware.
#include <sys/types.h>
#include <sys/stat.h>
#include <fcntl.h>
#include <unistd.h>

int main()
{
        int fd, ret;
        char buf[20] = {'X','X','X','X','X','X','X','X','X','X','X','X','X','X','X','X','X','X','X','X'};

        fd = open("/mnt/a", O_RDWR|O_SYNC|O_APPEND|O_CREAT);
        write(fd, buf, 20);
        close(fd);
        return 0;
}

Lets trace this using ftrace :
cd /sys/kernel/debug/tracing
cat /dev/null >  trace
echo vfs_write > set_graph_function
echo 10 > max_graph_depth
echo function_graph > current_tracer
echo 1 > tracing_on

/root/c_prog/a.out
/root/c_prog/a.out
/root/c_prog/a.out
/root/c_prog/a.out
/root/c_prog/a.out

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



SINGLE QUEUE IO SUBMISSION

VFS LAYER
 12)               |  vfs_write() {
...
 12)   0.080 us    |    __sb_start_write();
 12)               |    __vfs_write() {
 12)               |      ext4_file_write_iter [ext4]() {
 12)   0.216 us    |        down_write_trylock();
 12)   0.451 us    |        ext4_write_checks [ext4]();
 12)               |        __generic_file_write_iter() {
...
 12)               |              __mark_inode_dirty() {
 12)               |                ext4_dirty_inode [ext4]() {
 12)               |                  __ext4_journal_start_sb [ext4]() {
 12)   0.067 us    |                    ext4_journal_check_start [ext4]();
 12)               |                    jbd2__journal_start [jbd2]() {
 12)               |                      kmem_cache_alloc() {
 12)               |                        cache_grow_begin() {
 12)               |                          __alloc_pages_nodemask() {
...
 12)               |                  ext4_mark_inode_dirty [ext4]() {
 12)               |                    ext4_reserve_inode_write [ext4]() {
 12)               |                      __ext4_get_inode_loc [ext4]() {
 12)   0.075 us    |                        ext4_get_group_desc [ext4]();
 12)   0.068 us    |                        ext4_inode_table [ext4]();
 12)               |                        __getblk_gfp() {
 12)               |                          __find_get_block() {
 12)   0.073 us    |                            mark_page_accessed();
 12)   1.043 us    |                          }
 12)   1.702 us    |                        }
 12)   4.303 us    |                      }
 12)               |                      __ext4_journal_get_write_access [ext4]() {
 12)               |                        jbd2_journal_get_write_access [jbd2]() {
...
 12)               |                    ext4_mark_iloc_dirty [ext4]() {
 12)               |                      ext4_do_update_inode [ext4]() {
 12)   0.065 us    |                        _raw_spin_lock();
...
 12)               |          generic_perform_write() {
 12)               |            ext4_da_write_begin [ext4]() {
 12)   0.135 us    |              ext4_nonda_switch [ext4]();
..
 12)               |              __ext4_journal_start_sb [ext4]() {
 12)   0.068 us    |                ext4_journal_check_start [ext4]();
 12)               |                jbd2__journal_start [jbd2]() {
..
 12) + 11.529 us   |            }
 12)               |            ext4_da_write_end [ext4]() {
 12)   0.065 us    |              down_write();
 12)   0.065 us    |              up_write();
 12)               |              ext4_mark_inode_dirty [ext4]() {
...
 12) ! 153.424 us  |        }
 12)   0.066 us    |        up_write();
 12)               |        vfs_fsync_range() {
 12)               |          ext4_sync_file [ext4]() {
 12)               |            file_write_and_wait_range() {
 12)               |              __filemap_fdatawrite_range() {

EXT4 USING THE PAGE CACHE
..
 12)               |                do_writepages() {
 12)               |                  ext4_writepages [ext4]() {
 12)   0.203 us    |                    mapping_tagged();
 12)   0.063 us    |                    ext4_io_submit_init [ext4]();
...
 12)               |                    ext4_init_io_end [ext4]() {
 12)               |                      kmem_cache_alloc() {
 12)               |                        cache_grow_begin() {
..
 12)               |                    mpage_prepare_extent_to_map [ext4]() {
 12)               |                      pagevec_lookup_tag() {
 12)   0.333 us    |                        find_get_pages_tag();
 12)   1.010 us    |                      }
 12)               |                      mpage_process_page_bufs [ext4]() {
 12)               |                        mpage_submit_page [ext4]() {
...
 12)               |                          ext4_bio_write_page [ext4]() {
..
 12)   0.065 us    |                              unlock_page_memcg();
 12)   6.516 us    |                            }
 12)               |                            bio_alloc_bioset() {
 12)               |                              mempool_alloc() {
 12)               |                                mempool_alloc_slab() {
 12)   0.165 us    |                                  kmem_cache_alloc();
 12)   1.015 us    |                                }
 12)   1.872 us    |                              }
 12)               |                              bvec_alloc() {
 12)               |                                mempool_alloc() {
 12)               |                                  mempool_alloc_slab() {
 12)   0.115 us    |                                    kmem_cache_alloc();
 12)   0.662 us    |                                  }
 12)   1.303 us    |                                }
 12)   1.972 us    |                              }
 12)   5.461 us    |                            }
PAGE CACHE RAM PAGES ADDED TO BIO
 12)   0.087 us    |                            bio_add_page();
..
 12)               |                      __pagevec_release() {
...
 12) + 14.431 us   |                      }
 12) + 38.890 us   |                    }
 12)               |                    ext4_io_submit [ext4]() {

BLOCK IO, ELEVATOR, REQUEST and MERGE
 12)               |                      submit_bio() {
 12)               |                        generic_make_request() {
 12)               |                          generic_make_request_checks() {
...
 12)   0.156 us    |                          blk_queue_enter();
 12)               |                          blk_queue_bio() {
 12)   0.206 us    |                            blk_queue_bounce();
...
 12)               |                            elv_merge() {
 12)   0.263 us    |                              elv_rqhash_find();
..
 12)               |                            get_request() {
 12)               |                              elv_may_queue() {
 12)               |                                cfq_may_queue() {
 12)   0.087 us    |                                  ioc_lookup_icq();
...
 12)   0.133 us    |                              blk_rq_init();
 12)               |                              ioc_create_icq() {
..
 12)               |                            blk_init_request_from_bio() {
 12)   0.258 us    |                              blk_rq_bio_prep();
 12)   0.897 us    |                            }
...
 12)   0.098 us    |                    ext4_put_io_end_defer [ext4]();
 12)   0.156 us    |                    mpage_release_unused_pages [ext4]();
 12)               |                    blk_finish_plug() {
 12)               |                      blk_flush_plug_list() {
 12)   0.065 us    |                        _raw_spin_lock();
 12)               |                        __elv_add_request() {
 12)               |                          elv_attempt_insert_merge() {
 12)   0.081 us    |                            elv_rqhash_find();
 12)   0.659 us    |                          }
 12)   0.091 us    |                          elv_rqhash_add();
 12)               |                          cfq_insert_request() {
...
...
 12)               |                            __blk_run_queue() {
 12)               |                              scsi_request_fn [scsi_mod]() {
 12)               |                                blk_peek_request() {
...
SCSI COMMAND PREPARATION
 12)               |                                  scsi_prep_fn [scsi_mod]() {
 12)   0.063 us    |                                    scsi_prep_state_check.isra.29 [scsi_mod]();
 12)   0.208 us    |                                    get_device();
 12)               |                                    scsi_init_command [scsi_mod]() {
 12)   0.067 us    |                                      init_timer_key();
 12)   0.068 us    |                                      scsi_add_cmd_to_list [scsi_mod]();
 12)   1.629 us    |                                    }
 12)               |                                    scsi_setup_cmnd [scsi_mod]() {
 12)   0.739 us    |                                      alua_prep_fn [scsi_dh_alua]();
 12)               |                                      sd_init_command [sd_mod]() {
 12)   3.654 us    |                                        sd_setup_read_write_cmnd [sd_mod]();
 12)   4.406 us    |                                      }
 12)   7.198 us    |                                    }
 12) + 11.997 us   |                                  }
 12) + 32.313 us   |                                }
 12)               |                                blk_queue_start_tag() {
 12)               |                                  blk_start_request() {
...
 12)   0.210 us    |                                scsi_init_cmd_errh [scsi_mod]();
 12)               |                                scsi_dispatch_cmd [scsi_mod]() {
 12)   0.070 us    |                                  scsi_log_send [scsi_mod]();
EMULEX DRIVER CALLS
 12)               |                                  lpfc_queuecommand [lpfc]() {
 12)   0.075 us    |                                    scsi_is_fc_rport [scsi_transport_fc]();
 12)               |                                    lpfc_get_scsi_buf_s3 [lpfc]() {
 12)   0.068 us    |                                      _raw_spin_lock_irqsave();
 12)   0.075 us    |                                      _raw_spin_unlock_irqrestore();
 12)   1.391 us    |                                    }
 12)   1.556 us    |                                    lpfc_scsi_prep_dma_buf_s3 [lpfc]();
 12)               |                                    lpfc_scsi_prep_cmnd [lpfc]() {
 12)   0.083 us    |                                      int_to_scsilun [scsi_mod]();
 12)   1.306 us    |                                    }
 12)               |                                    lpfc_sli_issue_iocb [lpfc]() {
 12)   0.067 us    |                                      _raw_spin_lock_irqsave();
 12)               |                                      __lpfc_sli_issue_iocb_s3 [lpfc]() {
 12)   0.068 us    |                                        lpfc_sli_next_iocb_slot [lpfc]();
 12)   0.473 us    |                                        lpfc_sli_submit_iocb [lpfc]();
 12)   0.092 us    |                                        lpfc_sli_next_iocb_slot [lpfc]();
 12)   2.945 us    |                                      }
 12)   0.075 us    |                                      _raw_spin_unlock_irqrestore();
 12)   4.852 us    |                                    }
 12) + 13.464 us   |                                  }
....





MULTIQUEUE IO SUBMISSION ON NVME


Lets make filesystem and mount a NVMe device :

For nvme devices :
mkfs.ext4 /dev/nvme0n4

ncpp240034:~ # mkfs.ext4 /dev/nvme0n4
mke2fs 1.43.8 (1-Jan-2018)
/dev/nvme0n4 contains a ext4 file system
        last mounted on /root/my_mnt on Fri Mar 22 03:13:32 2019
Proceed anyway? (y,N) y
Creating filesystem with 26214400 4k blocks and 6566400 inodes
Filesystem UUID: 5f8ca338-eb67-488a-93c2-ec0d4260e9db
Superblock backups stored on blocks:
        32768, 98304, 163840, 229376, 294912, 819200, 884736, 1605632, 2654208,
        4096000, 7962624, 11239424, 20480000, 23887872

Allocating group tables: done
Writing inode tables: done
Creating journal (131072 blocks): done
Writing superblocks and filesystem accounting information: done

MOUNT the device 
ncpp240034:~ # mount /dev/nvme0n4 /mnt


Lets write to the device and take an ftrace:

cd /sys/kernel/debug/tracing
cat /dev/null >  trace
echo vfs_write > set_graph_function
echo 30 > max_graph_depth
echo function_graph > current_tracer
echo 1 > tracing_on

/root/kundan/a.out
/root/kundan/a.out
/root/kundan/a.out
/root/kundan/a.out
/root/kundan/a.out
/root/kundan/a.out
/root/kundan/a.out
/root/kundan/a.out
/root/kundan/a.out
/root/kundan/a.out

cp trace /root/kundan/vfs_write_trace
echo 0 > tracing_on
echo > set_graph_function
echo 0 > max_graph_depth
cat /dev/null >  trace


Ftrace on NVMe enabled with multiqueue

VFS : 
 22)               |        vfs_fsync_range() {

EXT4 : 
 22)               |          ext4_sync_file [ext4]() {
 22)               |            file_write_and_wait_range() {
 22)               |              __filemap_fdatawrite_range() {
 22)   0.065 us    |                _raw_spin_lock();
 22)   0.074 us    |                wbc_attach_and_unlock_inode();
 22)               |                do_writepages() {
 22)               |                  ext4_writepages [ext4]() {
 22)   0.097 us    |                    mapping_tagged();
 22)   0.074 us    |                    ext4_io_submit_init [ext4]();
 22)               |                    tag_pages_for_writeback() {
 22)   0.071 us    |                      _raw_spin_lock_irq();
 22)   1.200 us    |                    }
 22)   0.089 us    |                    blk_start_plug();
 22)               |                    ext4_init_io_end [ext4]() {
 22)               |                      kmem_cache_alloc() {
 22)               |                        cache_grow_begin() {
 22)               |                          __alloc_pages_nodemask() {
 22)               |                            get_page_from_freelist() {
 22)   0.062 us    |                              __inc_numa_state();
 22)   0.072 us    |                              __inc_numa_state();
 22)   1.500 us    |                            }
 22)   2.143 us    |                          }
 22)   0.068 us    |                          mod_zone_page_state();
 22)   0.197 us    |                          get_random_u32();
 22)   5.046 us    |                        }
 22)               |                        cache_grow_end.part.47() {
 22)   0.089 us    |                          _raw_spin_lock();
 22)   0.732 us    |                        }
 22)   7.554 us    |                      }
 22)   8.249 us    |                    }
 22)               |                    mpage_prepare_extent_to_map [ext4]() {
 22)               |                      pagevec_lookup_tag() {
 22)   0.186 us    |                        find_get_pages_tag();
 22)   0.862 us    |                      }
 22)               |                      mpage_process_page_bufs [ext4]() {
 22)               |                        mpage_submit_page [ext4]() {
 22)               |                          clear_page_dirty_for_io() {
 22)   0.077 us    |                            page_mapping();
 22)               |                            page_mkclean() {
 22)   0.089 us    |                              page_mapped();
 22)   0.774 us    |                            }
 22)   0.146 us    |                            dec_node_page_state();
 22)   0.091 us    |                            dec_zone_page_state();
 22)   4.023 us    |                          }
 22)               |                          ext4_bio_write_page [ext4]() {
 22)               |                            __test_set_page_writeback() {
 22)   0.062 us    |                              page_mapping();
 22)   0.063 us    |                              lock_page_memcg();
 22)   0.066 us    |                              _raw_spin_lock_irqsave();
....
BIO SUBMISSION
 22)               |                    ext4_io_submit [ext4]() {
 22)               |                      submit_bio() {
 22)               |                        generic_make_request() {
 22)               |                          generic_make_request_checks() {
 22)               |                            create_task_io_context() {
 22)   0.282 us    |                              kmem_cache_alloc_node();
 22)   0.075 us    |                              _raw_spin_lock();
 22)   1.663 us    |                            }
 22)   0.345 us    |                            blk_throtl_bio();
 22)   4.395 us    |                          }
 22)   0.291 us    |                          blk_queue_enter();

BLK IO MAKE REQUEST
 22)               |                          blk_mq_make_request() {
 22)   0.094 us    |                            blk_queue_bounce();
 22)   0.314 us    |                            blk_queue_split();
 22)   0.186 us    |                            bio_integrity_prep();
 22)   0.125 us    |                            blk_attempt_plug_merge();
 22)               |                            __blk_mq_sched_bio_merge() {
 22)   0.155 us    |                              _raw_spin_lock();
 22)   1.486 us    |                            }
 22)               |                            wbt_wait() {
 22)               |                              rwb_arm_timer() {
 22)   0.062 us    |                                nsecs_to_jiffies();
 22)               |                                mod_timer() {
 22)               |                                  lock_timer_base() {
 22)   0.086 us    |                                    _raw_spin_lock_irqsave();
 22)   0.786 us    |                                  }
 22)   0.066 us    |                                  detach_if_pending();
 22)   0.068 us    |                                  get_nohz_timer_target();
 22)   0.091 us    |                                  _raw_spin_lock();
 22)               |                                  __internal_add_timer() {
 22)   0.080 us    |                                    calc_wheel_index();
 22)   0.763 us    |                                  }
 22)   0.066 us    |                                  trigger_dyntick_cpu.isra.34();
 22)   0.083 us    |                                  _raw_spin_unlock_irqrestore();
 22)   6.335 us    |                                }
 22)   7.660 us    |                              }
 22)   9.377 us    |                            }
 22)               |                            blk_mq_get_request() {
 22)               |                              blk_mq_get_tag() {
 22)   0.443 us    |                                __blk_mq_get_tag();
 22)   1.303 us    |                              }
 22)   0.074 us    |                              __blk_mq_tag_busy();
 22)   3.192 us    |                            }
 22)               |                            blk_mq_bio_to_request() {
 22)               |                              blk_init_request_from_bio() {
 22)   0.169 us    |                                blk_rq_bio_prep();
 22)   0.854 us    |                              }
 22)               |                              blk_account_io_start() {
 22)   0.255 us    |                                disk_map_sector_rcu();
 22)               |                                part_round_stats() {
 22)               |                                  part_in_flight() {
 22)               |                                    blk_mq_in_flight() {
 22)               |                                      blk_mq_queue_tag_busy_iter() {
 22)               |                                        bt_iter() {
 22)   0.106 us    |                                          blk_mq_check_inflight();
 22)   0.792 us    |                                        }
 22)   4.822 us    |                                      }
 22)   5.472 us    |                                    }
 22)   6.220 us    |                                  }
 22)   7.038 us    |                                }
 22)   0.088 us    |                                part_inc_in_flight();
 22)   9.377 us    |                              }
 22) + 11.598 us   |                            }
 22) + 32.441 us   |                          }
 22) + 39.520 us   |                        }
 22) + 40.232 us   |                      }
 22) + 40.947 us   |                    }
 22)   0.125 us    |                    ext4_put_io_end_defer [ext4]();
 22)   0.088 us    |                    mpage_release_unused_pages [ext4]();
 22)               |                    blk_finish_plug() {
 22)               |                      blk_flush_plug_list() {
 22)               |                        blk_mq_flush_plug_list() {
 22)               |                          blk_mq_sched_insert_requests() {
 22)               |                            blk_mq_insert_requests() {
 22)   0.065 us    |                              _raw_spin_lock();
 22)   0.192 us    |                              blk_mq_hctx_mark_pending.isra.32();
 22)   1.526 us    |                            }
RUN THE BLK MQ HW QUEUE
 22)               |                            blk_mq_run_hw_queue() {
 22)               |                              __blk_mq_delay_run_hw_queue() {
 22)               |                                __blk_mq_run_hw_queue() {
 22)               |                                  blk_mq_sched_dispatch_requests() {
 22)               |                                    blk_mq_flush_busy_ctxs() {
 22)               |                                      flush_busy_ctx() {
 22)   0.065 us    |                                        _raw_spin_lock();
 22)   0.869 us    |                                      }
 22)   1.703 us    |                                    }
 22)               |                                    blk_mq_dispatch_rq_list() {
 22)   0.071 us    |                                      blk_mq_get_driver_tag();

NVME FC DRIVER 
 22)               |                                      nvme_fc_queue_rq [nvme_fc]() {
 22)   0.820 us    |                                        nvme_setup_cmd [nvme_core]();
 22)               |                                        nvme_fc_start_fcp_op [nvme_fc]() {
 22)   0.415 us    |                                          blk_rq_map_sg();
 22)               |                                          blk_mq_start_request() {
 22)   0.148 us    |                                            ktime_get();
 22)   0.088 us    |                                            wbt_issue();
 22)               |                                            blk_add_timer() {
 22)   0.069 us    |                                              round_jiffies_up();
 22)   0.063 us    |                                              round_jiffies_up();
 22)               |                                              mod_timer() {
 22)               |                                                lock_timer_base() {
 22)   0.142 us    |                                                  _raw_spin_lock_irqsave();
 22)   0.891 us    |                                                }
 22)   0.066 us    |                                                detach_if_pending();
 22)   0.071 us    |                                                get_nohz_timer_target();
 22)   0.063 us    |                                                _raw_spin_lock();
 22)               |                                                __internal_add_timer() {
 22)   0.063 us    |                                                  calc_wheel_index();
 22)   0.783 us    |                                                }
 22)   0.066 us    |                                                trigger_dyntick_cpu.isra.34();
 22)   0.083 us    |                                                _raw_spin_unlock_irqrestore();
 22)   6.628 us    |                                              }
 22)   9.134 us    |                                            }
 22) + 11.792 us   |                                          }
QLOGIC DRIVER IO SUBMISSION 
 22)               |                                          qla_nvme_post_cmd [qla2xxx]() {
 22)               |                                            mempool_alloc() {
 22)               |                                              mempool_alloc_slab() {
 22)               |                                                kmem_cache_alloc() {
 22)   0.078 us    |                                                  _raw_spin_lock();
 22)   0.114 us    |                                                  transfer_objects();
 22)   0.083 us    |                                                  get_first_slab();
 22)   0.065 us    |                                                  get_first_slab();
 22)   0.063 us    |                                                  get_first_slab();
 22)   0.069 us    |                                                  get_first_slab();
 22)   5.358 us    |                                                }
 22)   5.988 us    |                                              }
 22)   6.860 us    |                                            }
 22)   0.066 us    |                                            __init_waitqueue_head();
 22)   0.066 us    |                                            _raw_spin_lock_irqsave();
 22)   0.077 us    |                                            _raw_spin_unlock_irqrestore();
 22) + 10.649 us   |                                          }
 22) + 26.126 us   |                                        }
 22) + 28.609 us   |                                      }
 22) + 30.317 us   |                                    }
 22) + 33.449 us   |                                  }
 22) + 34.135 us   |                                }
 22) + 34.886 us   |                              }
 22) + 35.535 us   |                            }
 22) + 38.483 us   |                          }
 22) + 39.526 us   |                        }
 22) + 40.320 us   |                      }
 22) + 41.001 us   |                    }
 22) ! 143.595 us  |                  }
 22) ! 144.438 us  |                }
 22)   0.123 us    |                wbc_detach_inode();
 22) ! 147.312 us  |              }

Friday, 14 September 2018

entry_64.S

entry_64.S is collection of functions written in assembly. This file has many routines which are used in interrupts, system calls etc.
Let us see one by one how many such routines are present in this file.

Functions present in this file :

A) save_rest : Handle the saving of extra registers

B) ret_from_fork : This function is executed by the child process right after its creation through a fork
Called from :
1. copy_thread
 p->thread.ip = (unsigned long) ret_from_fork;
This is done to set the new threads instruction pointer.

2. /* Save restore flags to clear handle leaking NT */
#define switch_to(prev, next, last) \
...
     "jnz   ret_from_fork\n\t"   \
...
From switch_to the function ret_from_fork is called if the program was never executed.


C) system_call : This is the entry of any system call.

MSR_LSTAR is initialised with this function at startup.
This fiunction calls the system call function from the sys_call_table :
call *sys_call_table(,%rax,8)  # XXX: rip relative

Also entry to system call and return from system call is handled.
ret_from_sys_call :
on a return for system call the process scheduling in called :
...
 SCHEDULE_USER
...
# define SCHEDULE_USER call schedule


D)  The various stub functions are usually entries in the sys_call_table

stub_execve, stub_rt_sigreturn, stub_x32_execve
0 syscalls_64.h       60 __SYSCALL_64(59, stub_execve, stub_execve)
1 sys_call_table_64.c 33 #define stub_execve sys_execve

0 syscalls_64.h       16 __SYSCALL_64(15, stub_rt_sigreturn, stub_rt_sigreturn)
1 sys_call_table_64.c 34 #define stub_rt_sigreturn sys_rt_sigreturn

0 syscalls_64.h 309 __SYSCALL_X32(513, stub_x32_rt_sigreturn, stub_x32_rt_sigreturn)

0 syscalls_64.h 316 __SYSCALL_X32(520, stub_x32_execve, stub_x32_execve)


E) interrupt and "irq_entries_start"
ENTRY(interrupt)
ENTRY(irq_entries_start)
In native_init_IRQ the interrupt entry is used to initialize IDT with the defaults :
set_intr_gate(i, interrupt[i - FIRST_EXTERNAL_VECTOR]);

F) Interrupt entry/exit
Now comes the interrupt entry and exit functions. Under common_interrupt label we see that do_IRQ function is called.

If interrupt came when we were in kernel mode then control jumps to retint_kernel which calls for scheduling:

retint_kernel :
 preempt_schedule_irq
 void __sched preempt_schedule_irq(void)
  ...
  local_irq_enable();
  __schedule();
  local_irq_disable();
  ...

If interrupt came when we were in USER mode then control jumps to retint_careful which calls for scheduling:
retint_careful:
...
SCHEDULE_USER
...

G) ENTRY(call_softirq)
Call softirq on interrupt stack. This function is called from do_softirq()

Wednesday, 29 August 2018

Linux system call implementation x86_64


Userspace call of the systemcall:

x86_64 user programs invoke a system call by putting the system call number (0 for read) into the RAX register, and the other parameters into specific registers (RDI, RSI, RDX for the first 3 parameters), then issue the x86_64 syscall instruction.
http://man7.org/linux/man-pages/man2/syscall.2.html
x86-64      syscall               rax        rax     -        [5]

This instruction causes the processor to transition to ring 0 and invoke the function referenced by the MSR_LSTAR model-specific register.

The MSR_LSTAR model-specific register is initialized at the kernel bootup:


/* May not be marked __init: used by software suspend */
void syscall_init(void)
{
extern char _entry_trampoline[];
extern char entry_SYSCALL_64_trampoline[];

int cpu = smp_processor_id();
unsigned long SYSCALL64_entry_trampoline =
(unsigned long)get_cpu_entry_area(cpu)->entry_trampoline +
(entry_SYSCALL_64_trampoline - _entry_trampoline);

wrmsr(MSR_STAR, 0, (__USER32_CS << 16) | __KERNEL_CS);
if (static_cpu_has(X86_FEATURE_PTI))
wrmsrl(MSR_LSTAR, SYSCALL64_entry_trampoline);
else
wrmsrl(MSR_LSTAR, (unsigned long)entry_SYSCALL_64);

#ifdef CONFIG_IA32_EMULATION
wrmsrl(MSR_CSTAR, (unsigned long)entry_SYSCALL_compat);
/*
* This only works on Intel CPUs.
* On AMD CPUs these MSRs are 32-bit, CPU truncates MSR_IA32_SYSENTER_EIP.
* This does not cause SYSENTER to jump to the wrong location, because
* AMD doesn't allow SYSENTER in long mode (either 32- or 64-bit).
*/
wrmsrl_safe(MSR_IA32_SYSENTER_CS, (u64)__KERNEL_CS);
wrmsrl_safe(MSR_IA32_SYSENTER_ESP, (unsigned long)(cpu_entry_stack(cpu) + 1));
wrmsrl_safe(MSR_IA32_SYSENTER_EIP, (u64)entry_SYSENTER_compat);
#else
wrmsrl(MSR_CSTAR, (unsigned long)ignore_sysret);
wrmsrl_safe(MSR_IA32_SYSENTER_CS, (u64)GDT_ENTRY_INVALID_SEG);
wrmsrl_safe(MSR_IA32_SYSENTER_ESP, 0ULL);
wrmsrl_safe(MSR_IA32_SYSENTER_EIP, 0ULL);
#endif

/* Flags to clear on syscall */
wrmsrl(MSR_SYSCALL_MASK,
       X86_EFLAGS_TF|X86_EFLAGS_DF|X86_EFLAGS_IF|
       X86_EFLAGS_IOPL|X86_EFLAGS_AC|X86_EFLAGS_NT);
}

The system_call is the function which gets called for each system call.
entry_64.S file has the definition of the system_call function.
The system_call code pushes the registers onto the kernel stack, and calls the function pointer at entry RAX in the sys_call_table table.

ENTRY(system_call)
...
movq %r10,%rcx /* fixup for C */
call *sys_call_table(,%rax,8)
movq %rax,RAX-ARGOFFSET(%rsp)
...
END(system_call)

Tuesday, 14 August 2018

Linux internals segmentation fault generation


Linux process has many sections. Vaguely speaking these sections can be data, text, stack heap etc.
When a Linux process is created these sections are formed and virtual memory is allocated to these.

Presence of these sections in Linux kernel.

Each of these sections are represented by vm_area_struct in Linux.

The Linux task_struct has memory struct in mm_struct. The mm_struct has vm_area_struct for all these sections.

For all the sections the virtual address will be accessed.

https://en.wikipedia.org/wiki/Memory_management_unit MMU diagram tells the translation of virtual memory to physical memory by CPU/MMU.

The MMU part of CPU checks if the virtual to physical translation is present in the TLB cache.
If no translation exist in TLB it raises an page fault exception.

As a result of the Page fault exception the page fault handler is called.

In Linux the page fault handler is do_page_fault function. In the do_page_fault function faulting address is taken from the cr2 register: read_cr2();

__do_page_fault is called. This function checks if there is vm_area_struct present for the faulting address.

If the virtual area is present in a VMA then good_area handling is invoked, else it goes bad_area function:

bad_area function : 
Eventually a SEGV is generated in __bad_area_nosemaphore function.
tsk->thread.cr2 = address;
tsk->thread.error_code = error_code;
tsk->thread.trap_nr = X86_TRAP_PF;

force_sig_info_fault(SIGSEGV, si_code, address, tsk, 0);


good_area handling :
If we see that the faulting address is correct then handle_mm_fault function is called to allocate a new page frame, similar to the demand paging explained in the Memory Initialization topic.

Sunday, 5 August 2018

Linux Kernel NVMe driver


In this blog we will go through Linux NVMe kernel driver.

The NVMe kernel driver has a table of nvme_id_table. As like the pci devices, this table has Vendor and device ID this driver would support.
When this driver is inserted the nvme_init function will register this id_table to the PCI.

On the insertion of this driver the probe function of this device is called.

nvme_probe is the driver probe function.

nvme_dev is allocated with the queues. Though NVMe supports the 64k queues pnly queues are created equal to number of CPUs existing in the system.

nvme_dev_map does the ioremap of the registers + 4096 :

enum {
NVME_REG_CAP = 0x0000, /* Controller Capabilities */
NVME_REG_VS = 0x0008, /* Version */
NVME_REG_INTMS = 0x000c, /* Interrupt Mask Set */
NVME_REG_INTMC = 0x0010, /* Interrupt Mask Clear */
NVME_REG_CC = 0x0014, /* Controller Configuration */
NVME_REG_CSTS = 0x001c, /* Controller Status */
NVME_REG_NSSR = 0x0020, /* NVM Subsystem Reset */
NVME_REG_AQA = 0x0024, /* Admin Queue Attributes */
NVME_REG_ASQ = 0x0028, /* Admin SQ Base Address */
NVME_REG_ACQ = 0x0030, /* Admin CQ Base Address */
NVME_REG_CMBLOC = 0x0038, /* Controller Memory Buffer Location */
NVME_REG_CMBSZ = 0x003c, /* Controller Memory Buffer Size */
NVME_REG_DBS = 0x1000, /* SQ 0 Tail Doorbell */
};

We can see the three queues admin, submission and completion queues of the NVME device.

Now the NVMe driver creates the DMA pool of Physical Region Pages. The prp_page_pool and prp_small_pool are the pools created for the IOs. These are done in nvme_setup_prp_pools function. From LDD3 "A DMApool is an allocation mechanism for small, coherent DMA mappings. Mappings obtained from dma_alloc_coherent may have a minimum size of one page. If your device needs smaller DMA areas than that, you should probably be using a DMA pool."
Function : nvme_setup_prp_pools
creates pools using dma_pool_create
The pools are used to allocate memory dma_pool_alloc in nvme_setup_prps function.
These DMA pools are used while doing IOs in nvme_setup_prps function.

Next the NVME driver moves to function nvme_init_ctrl to initialize the controller structures.
3 work queues are initiated :
INIT_WORK(&ctrl->scan_work, nvme_scan_work);
INIT_WORK(&ctrl->async_event_work, nvme_async_event_work);
INIT_WORK(&ctrl->fw_act_work, nvme_fw_act_work);

device_create_with_groups creates the sysfs entries.

At the last nvme_probe calls reset_work.

====================================================
nvme_reset_work function : 
====================================================
Calls nvme_pci_enable
calls pci_enable_device_mem --> enables device memory
pci_set_master --> makes the pci device as master
Reads the pci device capability(NVME_REG_CAP) and determines the io_queue_depth
Checks if CMB is enabled by reading the NVME_REG_VS and ioremap the CMB

Note about CMB :
The Controller Memory Buffer (CMB) is a region of general purpose read/write memory on the controller that may be used for a variety of purposes. The controller indicates which purposes the memory may be used for by setting support flags in the CMBSZ register.
Submission Queues in host memory require the controller to perform a PCI Express read from host memory in order to fetch the queue entries. Submission Queues in controller memory enable host software to directly write the entire Submission Queue Entry to the controller's internal memory space, avoiding one read from the controller to the host.

Calls nvme_pci_configure_admin_queue
calls nvme_alloc_queue--> does the allocation for the admin queue. allocates completion queue and the submission queue using dma_zalloc_coherent etc.
calls nvme_init_queue to initialize submission queue tail, completion queue head. Also initializes the doorbell regs.
Configures the completion queue interrupt using queue_request_irq

Calls nvme_alloc_admin_tags
Allocates the block mq tag set. The tag sets are used to force completion on the same CPU where the request was generated.
also initializes the admin_q using blk_mq_init_queue.
dev->ctrl.admin_q = blk_mq_init_queue
So a request_queue is initialized and blk_mq_make_request etc. is allocated to same.

Calls nvme_init_identify
calls nvme_identify_ctrl--> sends nvme_admin_identify = 0x06 command to the controller -->>
command is submitted to the admin queue using __nvme_submit_sync_cmd
this function allocates a request and calls blk_execute_rq to wait for the command to return.
Based on the returned data nvme_init_subnqn initializes the NQN.

Calls nvme_setup_io_queues
Sets the number of queue as number of CPUS present
calls nvme_create_io_queues to create the queues
nvme_alloc_queue allocates CQ and SQ for each CPU(Same as done for the admin queue)
nvme_create_queue --> creates CQ, SQ and registers the IRQ for each queue "queue_request_irq"

Calls nvme_start_ctrl
Starts the nvme_queue_scan -- > launches scan_work --> Calls nvme_scan_work
   nvme_scan_work will first call nvme_identify_ctrl :
    sends : 
c.identify.opcode = nvme_admin_identify;
c.identify.cns = NVME_ID_CNS_CTRL;
   based on the number received from identify a validate or sequential scan is triggered
calls nvme_scan_ns_sequential
calls nvme_validate_ns
calls nvme_alloc_ns --> does blk_mq_init_queue --> sends identify command
forms a disk name and creates a disk using device_add_disk --- >> this will create /dev/ entries
Disk name is formed like :
sprintf(disk_name, "nvme%dn%d", ctrl->instance, ns->instance)
it comes like nvme0n1 etc.
nvme_identify_ns sends following command
c.identify.opcode = nvme_admin_identify;
c.identify.nsid = cpu_to_le32(nsid);
c.identify.cns = NVME_ID_CNS_NS;
nvme_report_ns_ids fills the ns_id, eui, nguid and uuid



Lets see how the IO path looks after these are done by the Linux driver :

A probe at nvme_setup_cmd function  :

[105617.151466]  ? sched_clock_cpu+0x11/0xb0
[105617.155491]  ? __lock_acquire.isra.34+0x259/0xa90
[105617.160307]  blk_mq_try_issue_directly+0xbb/0x110
[105617.165118]  ? blk_mq_make_request+0x382/0x700
[105617.169675]  blk_mq_make_request+0x3b0/0x700
[105617.174045]  ? blk_mq_make_request+0x382/0x700
[105617.178593]  ? blk_queue_enter+0x6a/0x1f0
[105617.182714]  generic_make_request+0x11e/0x2f0
[105617.187176]  ? __lock_acquire.isra.34+0x259/0xa90
[105617.191988]  submit_bio+0x73/0x150
[105617.195494]  ? sched_clock+0x9/0x10
[105617.199083]  ? submit_bio+0x73/0x150
[105617.202757]  ? sched_clock_cpu+0x11/0xb0
[105617.206783]  do_mpage_readpage+0x489/0x7d0
[105617.210983]  ? I_BDEV+0x20/0x20
[105617.214235]  mpage_readpages+0x127/0x1b0
[105617.218260]  ? I_BDEV+0x20/0x20
[105617.221503]  ? I_BDEV+0x20/0x20
[105617.224750]  ? sched_clock_cpu+0x11/0xb0
[105617.228782]  blkdev_readpages+0x1d/0x20
[105617.232718]  __do_page_cache_readahead+0x223/0x2f0
[105617.237625]  ? find_get_entry+0xaf/0x120
[105617.241656]  force_page_cache_readahead+0x8e/0x100
[105617.246548]  ? force_page_cache_readahead+0x8e/0x100
[105617.251622]  page_cache_sync_readahead+0x42/0x50
[105617.256345]  generic_file_read_iter+0x646/0x800
[105617.260988]  ? sched_clock+0x9/0x10
[105617.264577]  ? sched_clock_cpu+0x11/0xb0
[105617.268605]  blkdev_read_iter+0x37/0x40
[105617.272542]  __vfs_read+0xe2/0x140
[105617.276054]  vfs_read+0x96/0x140
[105617.279393]  SyS_read+0x58/0xc0
[105617.282644]  do_syscall_64+0x5a/0x190
[105617.286412]  entry_SYSCALL64_slow_path+0x25/0x25


ftrace looks like :
 0)               |      submit_bio() {
 0)               |        generic_make_request() {
 0)               |          generic_make_request_checks() {
 0)               |            _cond_resched() {
 0)   0.306 us    |              rcu_note_context_switch();
 0)   0.116 us    |              _raw_spin_lock();
 0)   0.130 us    |              update_rq_clock();
 0)               |              pick_next_task_fair() {
 ...
 ...
 ...
 0) * 72635.26 us |          }
 0) * 72636.55 us |        }
 0) * 72637.80 us |      }
 0)               |      blk_mq_make_request() {
 0)   0.343 us    |        blk_queue_bounce();
 0)   9.507 us    |        blk_queue_split();
 0)   0.637 us    |        bio_integrity_prep();
 0)               |        blk_attempt_plug_merge() {
 0)               |          blk_rq_merge_ok() {
 0)   0.316 us    |            blk_integrity_merge_bio();
 0)   1.817 us    |          }
 0)   0.153 us    |          blk_try_merge();
 0)               |          bio_attempt_back_merge() {
 0)   3.396 us    |            ll_back_merge_fn();
 0)   4.443 us    |          }
 0)   9.640 us    |        }
 0)               |        __blk_mq_sched_bio_merge() {
 0)   0.110 us    |          _raw_spin_lock();
 0)   1.883 us    |        }
 0)   1.193 us    |        wbt_wait();
 0)               |        blk_mq_get_request() {
 0)               |          blk_mq_get_tag() {
 0)   0.837 us    |            __blk_mq_get_tag();
 0)   2.130 us    |          }
 0)   0.130 us    |          __blk_mq_tag_busy();
 0)   5.217 us    |        }
 0)               |        blk_init_request_from_bio() {
 0)   0.346 us    |          blk_rq_bio_prep();
 0)   1.843 us    |        }
 0)               |        blk_account_io_start() {
 0)   0.640 us    |          disk_map_sector_rcu();
 0)               |          part_round_stats() {
 0)   0.160 us    |            part_round_stats_single();
 0)   1.060 us    |          }
 0)   3.720 us    |        }
 0)               |        blk_flush_plug_list() {
 0)               |          blk_mq_flush_plug_list() {
 0)   0.133 us    |            plug_ctx_cmp();
 0)               |            blk_mq_sched_insert_requests() {
 0)               |              blk_mq_insert_requests() {
 0)   0.113 us    |                _raw_spin_lock();
 0)   0.370 us    |                blk_mq_hctx_mark_pending.isra.29();
 0)   2.426 us    |              }
 0)               |              blk_mq_run_hw_queue() {
 0)               |                __blk_mq_delay_run_hw_queue() {
 0)               |                  __blk_mq_run_hw_queue() {
 0) ! 175.500 us  |                    blk_mq_sched_dispatch_requests();
 0) ! 177.577 us  |                  }
 0) ! 179.030 us  |                }
 0) ! 180.086 us  |              }
 0) ! 184.673 us  |            }
 0)               |            blk_mq_sched_insert_requests() {
 0)               |              blk_mq_insert_requests() {
 0)   0.113 us    |                _raw_spin_lock();
 0)   0.346 us    |                blk_mq_hctx_mark_pending.isra.29();
 0)   2.257 us    |              }
 0)               |              blk_mq_run_hw_queue() {
 0)               |                __blk_mq_delay_run_hw_queue() {
 0)               |                  __blk_mq_run_hw_queue() {
 0) ! 585.063 us  |                    blk_mq_sched_dispatch_requests();
 0) ! 587.033 us  |                  }
 0) ! 588.216 us  |                }
 0) ! 589.040 us  |              }
 0) ! 593.647 us  |            }
 0) ! 783.930 us  |          }
 0) ! 785.350 us  |        }
 0) ! 829.913 us  |      }
 0) @ 100015.7 us |    }

This is the flow of the events after blk_mq_make_request:
Calls blk_mq_try_issue_directly to issue the IO, it calls nvme_queue_rq to submit the request
nvme_queue_rq function calls nvme_setup_cmd and nvme_setup_rw to setup the read/write
This function sets the command type, namespace ID, LBA Number etc.
nvme_map_data does the DMA mapping using :
blk_rq_map_sg
nvme_setup_prps
After these are done __nvme_submit_cmd writes the command to submission queue tail


static void __nvme_submit_cmd(struct nvme_queue *nvmeq,
struct nvme_command *cmd)
{
u16 tail = nvmeq->sq_tail;

if (nvmeq->sq_cmds_io)
memcpy_toio(&nvmeq->sq_cmds_io[tail], cmd, sizeof(*cmd));
else
memcpy(&nvmeq->sq_cmds[tail], cmd, sizeof(*cmd));

if (++tail == nvmeq->q_depth)
tail = 0;
if (nvme_dbbuf_update_and_check_event(tail, nvmeq->dbbuf_sq_db,
      nvmeq->dbbuf_sq_ei))
writel(tail, nvmeq->q_db);
nvmeq->sq_tail = tail;
}


After the submission is done :
nvme_process_cq will see for the completion of command. It reads the completion queue, fetches the command status and rings the dorrbell.

static void nvme_process_cq(struct nvme_queue *nvmeq)
{
struct nvme_completion cqe;
int consumed = 0;

while (nvme_read_cqe(nvmeq, &cqe)) {
nvme_handle_cqe(nvmeq, &cqe);
consumed++;
}

if (consumed)
nvme_ring_cq_doorbell(nvmeq);
}

Also if directly is not used for the submission, in such a case nvme_irq processes the completion queue:

static irqreturn_t nvme_irq(int irq, void *data)
{
irqreturn_t result;
struct nvme_queue *nvmeq = data;
spin_lock(&nvmeq->q_lock);
nvme_process_cq(nvmeq);
result = nvmeq->cqe_seen ? IRQ_HANDLED : IRQ_NONE;
nvmeq->cqe_seen = 0;
spin_unlock(&nvmeq->q_lock);
return result;
}

Error handling : 

void nvme_complete_rq(struct request *req)
{
if (unlikely(nvme_req(req)->status && nvme_req_needs_retry(req))) {
nvme_req(req)->retries++;
blk_mq_requeue_request(req, true);
return;
}

blk_mq_end_request(req, nvme_error_status(req));
}
EXPORT_SYMBOL_GPL(nvme_complete_rq);

static blk_status_t nvme_error_status(struct request *req)
{
switch (nvme_req(req)->status & 0x7ff) {
case NVME_SC_SUCCESS:
return BLK_STS_OK;
case NVME_SC_CAP_EXCEEDED:
return BLK_STS_NOSPC;
case NVME_SC_ONCS_NOT_SUPPORTED:
return BLK_STS_NOTSUPP;
case NVME_SC_WRITE_FAULT:
case NVME_SC_READ_ERROR:
case NVME_SC_UNWRITTEN_BLOCK:
case NVME_SC_ACCESS_DENIED:
case NVME_SC_READ_ONLY:
return BLK_STS_MEDIUM;
case NVME_SC_GUARD_CHECK:
case NVME_SC_APPTAG_CHECK:
case NVME_SC_REFTAG_CHECK:
case NVME_SC_INVALID_PI:
return BLK_STS_PROTECTION;
case NVME_SC_RESERVATION_CONFLICT:
return BLK_STS_NEXUS;
default:
return BLK_STS_IOERR;
}
}