Merge pull request tock#1443 from gendx/add-strace-feature

Add strace feature to trace syscalls in the kernel.

doc/Configuration.md

@@ -0,0 +1,28 @@
+Configuration
+=============
+
+Because Tock is meant to run on various platforms (spanning multiple
+architectures and various available peripherals), and with multiple use cases in
+mind (for example, "production" vs. debug build with various levels of debugging
+detail), Tock provides various configuration options so that each build can be
+adapted to each use case.
+
+In Tock, configuration follows some principles to avoid pitfalls of "ifdef"
+conditional code (which can be tricky to test). This is currently done in two
+ways.
+
+- **Separation of the code into multiple packages.** Each level of abstraction
+  (core kernel, CPU architecture, chip, board) has its own package, so that
+  configuring a board is done by depending on the relevant chip and declaring
+  the relevant drivers for peripherals avaialble on the board. You can see more
+  details on the [compilation page](Compilation.md).
+
+- **Custom kernel configuration.** To facilitate fine-grained configuration of
+  the kernel (for example to enable tracing the syscalls to the debug output), a
+  `Config` struct is defined in `kernel/src/config.rs`. To change the
+  configuration, modify the values in the static `const` object defined in this
+  file. To use the configuration, simply read the values. For example, to use a
+  boolean configuration, just use an if statement: the fact that the
+  configuration is `const` should allow the compiler to optimize away dead code
+  (so that this configuration has zero cost), while still checking syntax and
+  types.

doc/README.md

@@ -25,6 +25,7 @@ Tock Guides
 - **[Syscalls](Syscalls.md)** - Kernel/Userland abstraction.
 - **[Userland](Userland.md)** - Description of userland applications.
 - **[Networking Stack](Networking_Stack.md)** - Design of the networking stack in Tock.
+- **[Configuration](Configuration.md)** - Configuration options for the kernel.
 
 ### Interface Details
 - **[Syscall Interfaces](syscalls)** - API between userland and the kernel.

kernel/src/callback.rs

@@ -3,6 +3,8 @@
 use core::fmt;
 use core::ptr::NonNull;
 
+use crate::config;
+use crate::debug;
 use crate::process;
 use crate::sched::Kernel;
 
@@ -96,7 +98,8 @@ impl Callback {
     /// The arguments (`r0-r2`) are the values passed back to the process and
     /// are specific to the individual `Driver` interfaces.
     pub fn schedule(&mut self, r0: usize, r1: usize, r2: usize) -> bool {
-        self.app_id
+        let res = self
+            .app_id
             .kernel
             .process_map_or(false, self.app_id.idx(), |process| {
                 process.enqueue_task(process::Task::FunctionCall(process::FunctionCall {
@@ -107,6 +110,21 @@ impl Callback {
                     argument3: self.appdata,
                     pc: self.fn_ptr.as_ptr() as usize,
                 }))
-            })
+            });
+        if config::CONFIG.trace_syscalls {
+            debug!(
+                "[{:?}] schedule[{:#x}:{}] @{:#x}({:#x}, {:#x}, {:#x}, {:#x}) = {}",
+                self.app_id,
+                self.callback_id.driver_num,
+                self.callback_id.subscribe_num,
+                self.fn_ptr.as_ptr() as usize,
+                r0,
+                r1,
+                r2,
+                self.appdata,
+                res
+            );
+        }
+        res
     }
 }

kernel/src/config.rs

@@ -0,0 +1,42 @@
+//! Data structure for storing compile-time configuration options in the kernel.
+//!
+//! The rationale for configuration based on a `const` object is twofold.
+//!
+//! - In theory, Cargo features could be used for boolean-based configuration. However, these
+//!   features are generally error-prone for non-trivial use cases. First, they are globally enabled
+//!   as long as a dependency relationship requires a feature (even for other dependency
+//!   relationships that do not want the feature). Second, code gated by a non-enabled feature
+//!   isn't even type-checked by the compiler, and therefore we can end up with broken features due
+//!   to refactoring code (if these features aren't tested during the refactoring), or to
+//!   incompatible feature combinations.
+//!
+//! - Cargo features can only contain bits. On the other hand, a constant value can contain
+//!   arbitrary types, which allow configuration based on integers, strings, or even more complex
+//!   values.
+//!
+//! With a typed `const` configuration, all code paths are type-checked by the compiler - even
+//! those that end up disabled - which greatly reduces the risks of breaking a feature or
+//! combination of features because they are disabled in tests.
+//!
+//! In the meantime, after type-checking, the compiler can optimize away dead code by folding
+//! constants throughout the code, so for example a boolean condition used in an `if` block will in
+//! principle have a zero cost on the resulting binary - as if a Cargo feature was used instead.
+//! Some simple experiments on generated Tock code have confirmed this zero cost in practice.
+
+/// Data structure holding compile-time configuration options.
+///
+/// To change the configuration, modify the relevant values in the `CONFIG` constant object defined
+/// at the end of this file.
+crate struct Config {
+    /// Whether the kernel should trace syscalls to the debug output.
+    ///
+    /// If enabled, the kernel will print a message in the debug output for each system call and
+    /// callback, with details including the application ID, and system call or callback parameters.
+    crate trace_syscalls: bool,
+}
+
+/// A unique instance of `Config` where compile-time configuration options are defined. These
+/// options are available in the kernel crate to be used for relevant configuration.
+crate const CONFIG: Config = Config {
+    trace_syscalls: false,
+};

kernel/src/lib.rs

@@ -23,6 +23,7 @@ pub mod ipc;
 pub mod syscall;
 
 mod callback;
+mod config;
 mod driver;
 mod grant;
 mod mem;

kernel/src/process.rs

@@ -9,6 +9,8 @@ use crate::callback::{AppId, CallbackId};
 use crate::capabilities::ProcessManagementCapability;
 use crate::common::cells::MapCell;
 use crate::common::{Queue, RingBuffer};
+use crate::config;
+use crate::debug;
 use crate::mem::{AppSlice, Shared};
 use crate::platform::mpu::{self, MPU};
 use crate::platform::Chip;
@@ -524,6 +526,7 @@ impl<C: Chip> ProcessType for Process<'a, C> {
 
     fn remove_pending_callbacks(&self, callback_id: CallbackId) {
         self.tasks.map(|tasks| {
+            let count_before = tasks.len();
             tasks.retain(|task| match task {
                 // Remove only tasks that are function calls with an id equal
                 // to `callback_id`.
@@ -533,6 +536,16 @@ impl<C: Chip> ProcessType for Process<'a, C> {
                 },
                 _ => true,
             });
+            if config::CONFIG.trace_syscalls {
+                let count_after = tasks.len();
+                debug!(
+                    "[{}] remove_pending_callbacks[{:#x}:{}] = {} callback(s) removed",
+                    self.app_idx,
+                    callback_id.driver_num,
+                    callback_id.subscribe_num,
+                    count_before - count_after,
+                );
+            }
         });
     }
 

kernel/src/sched.rs

@@ -7,6 +7,8 @@ use crate::callback::{Callback, CallbackId};
 use crate::capabilities;
 use crate::common::cells::NumericCellExt;
 use crate::common::dynamic_deferred_call::DynamicDeferredCall;
+use crate::config;
+use crate::debug;
 use crate::grant::Grant;
 use crate::ipc;
 use crate::memop;
@@ -285,9 +287,21 @@ impl Kernel {
                             match syscall {
                                 Syscall::MEMOP { operand, arg0 } => {
                                     let res = memop::memop(process, operand, arg0);
+                                    if config::CONFIG.trace_syscalls {
+                                        debug!(
+                                            "[{:?}] memop({}, {:#x}) = {:#x}",
+                                            appid,
+                                            operand,
+                                            arg0,
+                                            usize::from(res)
+                                        );
+                                    }
                                     process.set_syscall_return_value(res.into());
                                 }
                                 Syscall::YIELD => {
+                                    if config::CONFIG.trace_syscalls {
+                                        debug!("[{:?}] yield", appid);
+                                    }
                                     process.set_yielded_state();
 
                                     // There might be already enqueued callbacks
@@ -305,8 +319,7 @@ impl Kernel {
                                     };
                                     process.remove_pending_callbacks(callback_id);
 
-                                    let callback_ptr = NonNull::new(callback_ptr);
-                                    let callback = callback_ptr.map(|ptr| {
+                                    let callback = NonNull::new(callback_ptr).map(|ptr| {
                                         Callback::new(appid, callback_id, appdata, ptr.cast())
                                     });
 
@@ -320,6 +333,17 @@ impl Kernel {
                                                 None => ReturnCode::ENODEVICE,
                                             },
                                         );
+                                    if config::CONFIG.trace_syscalls {
+                                        debug!(
+                                            "[{:?}] subscribe({:#x}, {}, @{:#x}, {:#x}) = {:#x}",
+                                            appid,
+                                            driver_number,
+                                            subdriver_number,
+                                            callback_ptr as usize,
+                                            appdata,
+                                            usize::from(res)
+                                        );
+                                    }
                                     process.set_syscall_return_value(res.into());
                                 }
                                 Syscall::COMMAND {
@@ -338,6 +362,17 @@ impl Kernel {
                                                 None => ReturnCode::ENODEVICE,
                                             },
                                         );
+                                    if config::CONFIG.trace_syscalls {
+                                        debug!(
+                                            "[{:?}] cmd({:#x}, {}, {:#x}, {:#x}) = {:#x}",
+                                            appid,
+                                            driver_number,
+                                            subdriver_number,
+                                            arg0,
+                                            arg1,
+                                            usize::from(res)
+                                        );
+                                    }
                                     process.set_syscall_return_value(res.into());
                                 }
                                 Syscall::ALLOW {
@@ -359,6 +394,17 @@ impl Kernel {
                                             None => ReturnCode::ENODEVICE,
                                         }
                                     });
+                                    if config::CONFIG.trace_syscalls {
+                                        debug!(
+                                            "[{:?}] allow({:#x}, {}, @{:#x}, {:#x}) = {:#x}",
+                                            appid,
+                                            driver_number,
+                                            subdriver_number,
+                                            allow_address as usize,
+                                            allow_size,
+                                            usize::from(res)
+                                        );
+                                    }
                                     process.set_syscall_return_value(res.into());
                                 }
                             }
@@ -387,6 +433,17 @@ impl Kernel {
                     None => break,
                     Some(cb) => match cb {
                         Task::FunctionCall(ccb) => {
+                            if config::CONFIG.trace_syscalls {
+                                debug!(
+                                    "[{:?}] function_call @{:#x}({:#x}, {:#x}, {:#x}, {:#x})",
+                                    appid,
+                                    ccb.pc,
+                                    ccb.argument0,
+                                    ccb.argument1,
+                                    ccb.argument2,
+                                    ccb.argument3,
+                                );
+                            }
                             process.set_process_function(ccb);
                         }
                         Task::IPC((otherapp, ipc_type)) => {