Add syscall timing using rdtsc

kernel/Cargo.toml

@@ -40,6 +40,8 @@ board_pc = ["link_user"]
 link_user = []
 # Run cmdline instead of user shell, useful for automatic testing
 run_cmdline = []
+# Add performance profiling
+profile = []
 
 [profile.dev]
 # MUST >= 2 : Enable RVO to avoid stack overflow

kernel/Makefile

@@ -32,6 +32,7 @@
 #   init = /bin/ls               Only available on riscv64, run specified program instead of user shell
 #   extra_nic = on | off         Only available on x86_64, add an additional e1000 nic
 #   u_boot = /path/to/u-boot.bin Only available on aarch64, use u-boot to boot rcore
+# . extra_features = profile | ... Add additional features
 
 arch ?= riscv64
 board ?= none
@@ -210,6 +211,8 @@ ifneq ($(board), none)
 features += board_$(board)
 endif
 
+features += $(extra_features)
+
 build_args := --target targets/$(target).json --features "$(features)"
 
 ifeq ($(mode), release)

kernel/src/syscall/mod.rs

@@ -31,11 +31,23 @@ mod net;
 mod proc;
 mod time;
 
+use spin::Mutex;
+use alloc::collections::BTreeMap;
+
+#[cfg(feature = "profile")]
+lazy_static! {
+    static ref SYSCALL_TIMING: Mutex<BTreeMap<usize, i64>> = Mutex::new(BTreeMap::new());
+}
+
 /// System call dispatcher
 // This #[deny(unreachable_patterns)] checks if each match arm is defined
 // See discussion in https://github.com/oscourse-tsinghua/rcore_plus/commit/17e644e54e494835f1a49b34b80c2c4f15ed0dbe.
 #[deny(unreachable_patterns)]
 pub fn syscall(id: usize, args: [usize; 6], tf: &mut TrapFrame) -> isize {
+    #[cfg(feature = "profile")]
+    let begin_time = unsafe {
+        core::arch::x86_64::_rdtsc()
+    };
     let cid = cpu::id();
     let pid = process().pid.clone();
     let tid = processor().tid();
@@ -254,6 +266,21 @@ pub fn syscall(id: usize, args: [usize; 6], tf: &mut TrapFrame) -> isize {
         // we trust pid 0 process
         info!("=> {:x?}", ret);
     }
+    #[cfg(feature = "profile")]
+    {
+        let end_time = unsafe {
+            core::arch::x86_64::_rdtsc()
+        };
+        *SYSCALL_TIMING.lock().entry(id).or_insert(0) += end_time - begin_time;
+        if end_time % 1000 == 0 {
+            let timing = SYSCALL_TIMING.lock();
+            let mut count_vec: Vec<(&usize, &i64)> = timing.iter().collect();
+            count_vec.sort_by(|a, b| b.1.cmp(a.1));
+            for (id, time) in count_vec.iter().take(5) {
+                warn!("timing {:03} time {:012}", id, time);
+            }
+        }
+    }
     match ret {
         Ok(code) => code as isize,
         Err(err) => -(err as isize),