milestone: buggy but semi-working strace-rs

operating_systems/linux/strace_rs/Cargo.toml

@@ -12,4 +12,4 @@ num = "0.4.3"
 num-derive = "0.4.2"
 num-traits = "0.2.19"
 tracing = "0.1.40"
-tracing-subscriber = "0.3.18"
+tracing-subscriber = { version = "0.3.18", features = ["env-filter"] }

operating_systems/linux/strace_rs/src/lib.rs

@@ -5,12 +5,18 @@ extern crate bitflags;
 
 use anyhow::{anyhow, bail, Result};
 use libc;
-use nix::{sys::wait::{WaitPidFlag, WaitStatus}, unistd::Pid};
+use nix::{
+    sys::{
+        signal::Signal,
+        wait::{WaitPidFlag, WaitStatus},
+    },
+    unistd::Pid,
+};
 use std::ffi::CString;
 use std::io::Error;
 use std::ptr;
 
-use tracing::{debug, error};
+use tracing::{debug, trace};
 pub mod ptrace;
 
 unsafe fn do_child<T>(args: T) -> Result<()>
@@ -22,8 +28,10 @@ where
         .map(|arg| CString::new(arg.as_str()).expect("CString::new failed"))
         .collect();
 
+    // TODO(Jonathon): lookup on $PATH if necessary.
     let child_prog = cstrings.get(0).unwrap().clone();
     debug!(?child_prog, "starting child");
+
     let child_prog = child_prog.into_raw();
     let mut c_pointers: Vec<*const libc::c_char> =
         cstrings.iter().map(|cstr| cstr.as_ptr()).collect();
@@ -40,16 +48,19 @@ where
     envp.push(ptr::null());
     let envp: *const *const libc::c_char = envp.as_ptr();
 
-    // If a child knows that it wants to be traced, it can make the PTRACE_TRACEME ptrace request, 
-    // which starts tracing. In addition, it means that the next signal sent to this process will stop 
+    // If a child knows that it wants to be traced, it can make the PTRACE_TRACEME ptrace request,
+    // which starts tracing. In addition, it means that the next signal sent to this process will stop
     // it and notify the parent (via wait), so that the parent knows to start tracing.
-    ptrace::traceme().map_err(|errno| anyhow!("failed TRACEME. errno {}", errno))?; 
+    ptrace::traceme().map_err(|errno| anyhow!("failed TRACEME. errno {}", errno))?;
     // After doing a TRACEME, we SIGSTOP ourselves so that the parent can continue this
     // child's execution. This assures that the tracer does not miss the early syscalls made by
     // the child.
     let result = libc::raise(libc::SIGSTOP);
-    if result == -1 {
-        bail!("child failed to SIGSTOP itself. errno {}", Error::last_os_error());
+    if result != 0 {
+        bail!(
+            "child failed to SIGSTOP itself. errno {}",
+            Error::last_os_error()
+        );
     }
 
     libc::execve(child_prog, argv, envp);
@@ -59,22 +70,33 @@ where
     bail!("errno = {}", errno)
 }
 
-fn wait_for_status(child: i32) -> Result<bool> {
+// Run the child until either entry to or exit from a system call.
+// If it returns false, the child has exited.
+fn wait_for_syscall(child: i32) -> Result<bool> {
     loop {
-        let status = nix::sys::wait::waitpid(
-            Pid::from_raw(child), 
-            Some(WaitPidFlag::WUNTRACED)
-        )?;
+        _ = ptrace::singlestep(child)
+            .map_err(|errno| anyhow!("SINGLESTEP failed. errno {}", errno))?;
+        let status = nix::sys::wait::waitpid(Pid::from_raw(child), Some(WaitPidFlag::WUNTRACED))
+            .map_err(|errno| anyhow!("waitpid had error. errno {}", errno))?;
         match status {
             WaitStatus::Exited(_, code) => {
                 debug!("{} signalled exited. exit code: {:?}", child, code);
-                return Ok(true);  
-            },
-            WaitStatus::Stopped(_, signal) => {
-                debug!("{} signalled stopped: {:?}", child, signal);
+                return Ok(true);
+            }
+            WaitStatus::PtraceSyscall(_) => {
+                debug!("{} syscall stopped", child);
+                return Ok(false);
+            }
+            WaitStatus::Stopped(_, Signal::SIGTRAP) => {
+                debug!("{} syscall stopped", child);
                 return Ok(false);
-            },
-            _ => {},
+            }
+            WaitStatus::PtraceEvent(_, _, _) => {
+                debug!("{} ignoring syscall ptrace event", child);
+            }
+            other => {
+                trace!("{} ignoring wait status {:?}", child, other);
+            }
         }
     }
 }
@@ -83,27 +105,33 @@ fn do_trace(child: i32) -> Result<()> {
     debug!(%child, "starting trace of child");
     let _ = child;
     // Wait until child has sent itself the SIGSTOP above, and is ready to be traced.
-    if wait_for_status(child)? {
-        bail!("child unexpected exit during trace setup")
+    let status = nix::sys::wait::waitpid(Pid::from_raw(child), Some(WaitPidFlag::WUNTRACED))?;
+    if let WaitStatus::Stopped(_, _) = status {
+        debug!("child {} is ready for tracing", child);
+    } else {
+        bail!("child unexpected signal during trace setup: {:?}", status);
     }
 
     if let Err(errno) = ptrace::setoptions(child, ptrace::Options::SysGood) {
-        bail!("failed to ptrace child with PTRACE_O_TRACESYSGOOD. errno={}", errno);
+        bail!(
+            "failed to ptrace child with PTRACE_O_TRACESYSGOOD. errno={}",
+            errno
+        );
     }
 
     loop {
-        if wait_for_status(child)? {
+        if wait_for_syscall(child)? {
             break;
         }
-        let registers = ptrace::getregs(child)
-            .map_err(|errno| anyhow!("ptrace failed errno {}", errno))?;
+        let registers =
+            ptrace::getregs(child).map_err(|errno| anyhow!("ptrace failed errno {}", errno))?;
         let syscall = registers.orig_rax;
         print!("syscall({}) = ", syscall);
-        if wait_for_status(child)? {
+        if wait_for_syscall(child)? {
             break;
         }
-        let registers = ptrace::getregs(child)
-            .map_err(|errno| anyhow!("ptrace failed errno {}", errno))?;
+        let registers =
+            ptrace::getregs(child).map_err(|errno| anyhow!("ptrace failed errno {}", errno))?;
         let retval = registers.rax;
         println!("{}\n", retval);
     }

operating_systems/linux/strace_rs/src/main.rs

@@ -1,8 +1,9 @@
 use std::process;
 
 use anyhow::Result;
-use tracing::Level;
+use tracing::level_filters::LevelFilter;
 use tracing_subscriber;
+use tracing_subscriber::EnvFilter;
 
 use strace_rs::trace_command;
 
@@ -19,7 +20,11 @@ fn main() -> Result<()> {
     }
 
     tracing_subscriber::fmt()
-        .with_max_level(Level::TRACE)
+        .with_env_filter(
+            EnvFilter::builder()
+                .with_default_directive(LevelFilter::INFO.into())
+                .from_env_lossy(),
+        )
         .init();
 
     // We’ll start with the entry point. We check that we were passed a command,

operating_systems/linux/strace_rs/src/ptrace.rs

@@ -134,6 +134,10 @@ bitflags! {
   }
 }
 
+pub fn singlestep(pid: libc::pid_t) -> Result<libc::c_long, i32> {
+    unsafe { _ptrace(Request::SingleStep, pid, ptr::null_mut(), ptr::null_mut()) }
+}
+
 pub fn setoptions(pid: libc::pid_t, opts: Options) -> Result<libc::c_long, i32> {
     unsafe {
         _ptrace(