Route Rhai's debug function to the faux-mgs log.

  - The `debug("message")` function is routed to the faux-mgs slog logging.
    Prefixing a message with "crit|", "trace|", "error|", "warn|", "error|", or "debug|"
    will log at that corresponding level. Leaving off the prefix or using some other
    prefix will log at the debug level.

print still goes to stdout.

Author: lzrd

faux-mgs/src/rhaiscript.rs

@@ -3,6 +3,12 @@
 
 use crate::anyhow;
 use crate::debug;
+use crate::info;
+use crate::warn;
+use slog::crit;
+use slog::error;
+use slog::trace;
+
 use crate::fs;
 use crate::json;
 use crate::run_command;
@@ -255,7 +261,9 @@ pub async fn interpreter(
     let interface = sp.interface().to_string().to_owned();
     let reset_watchdog_timeout_ms = sp.reset_watchdog_timeout_ms() as i64;
 
+    let thread_log = log.clone();
     let handle = std::thread::spawn(move || {
+        let log = thread_log;
         // Create Engine
         let mut engine = Engine::new();
 
@@ -320,15 +328,14 @@ pub async fn interpreter(
             // Offer proper JSON to Dynamic::Map conversion
             .register_fn("json_to_map", move |v: Dynamic| -> Dynamic {
                 match v.into_string() {
-                    Ok(s) => {
-                        match serde_json::from_str::<Dynamic>(&s) {
-                            Ok(v) => v,
-                            Err(e) => {
-                                let err = format!("{{\"error\": \"{:?}\"}}", e).to_string();
-                                serde_json::from_str::<Dynamic>(&err).unwrap()
-                            }
+                    Ok(s) => match serde_json::from_str::<Dynamic>(&s) {
+                        Ok(v) => v,
+                        Err(e) => {
+                            let err = format!("{{\"error\": \"{:?}\"}}", e)
+                                .to_string();
+                            serde_json::from_str::<Dynamic>(&err).unwrap()
                         }
-                    }
+                    },
                     Err(e) => {
                         let err =
                             format!("{{\"error\": \"{:?}\"}}", e).to_string();
@@ -369,6 +376,50 @@ pub async fn interpreter(
                 },
             );
 
+        // A script can log via debug at any level:
+        //   debug("INFO|log message at INFO level");
+        //   debug("CRIT|log message at CRIT level");
+        // etc.
+        let rhai_log = log.clone();
+        engine.on_debug(move |x, src, pos| {
+            let src = if src.is_some() {
+                format!("{}@", src.unwrap())
+            } else {
+                "".to_string()
+            };
+            let x: Vec<&str> = x.trim_matches('"').splitn(2, '|').collect();
+            let (level, msg) = if x.len() == 1 {
+                ("info".to_string(), x[0].to_string())
+            } else {
+                let level = x[0].to_string().to_lowercase();
+                let msg = x[1].to_string();
+                match level.as_str() {
+                    "info" => ("info".to_string(), msg),
+                    "crit" => ("crit".to_string(), msg),
+                    "error" => ("error".to_string(), msg),
+                    "trace" => ("trace".to_string(), msg),
+                    "warn" => ("warn".to_string(), msg),
+                    "debug" => ("debug".to_string(), msg),
+                    _ => ("debug".to_string(), format!("{}|{}", level, msg)),
+                }
+            };
+            let src = if src.len() > 0 {
+                format!("{}@", src)
+            } else {
+                "".to_string()
+            };
+            let msg = format!("{}pos={:?} {}", src, pos, msg);
+            match level.as_str() {
+                "crit" => crit!(rhai_log, "{msg}"),
+                "debug" => debug!(rhai_log, "{msg}"),
+                "error" => error!(rhai_log, "{msg}"),
+                "info" => info!(rhai_log, "{msg}"),
+                "trace" => trace!(rhai_log, "{msg}"),
+                "warn" => warn!(rhai_log, "{msg}"),
+                _ => unreachable!(),
+            }
+        });
+
         // Print registered functions if you're interested.
 
         // engine.gen_fn_signatures(false).into_iter().for_each(|func| println!("{func}"));

gateway-sp-comms/src/single_sp/update.rs

@@ -22,7 +22,6 @@ use gateway_messages::UpdateStatus;
 use hubtools::Error as HubtoolsError;
 use hubtools::RawHubrisArchive;
 use slog::debug;
-use slog::trace;
 use slog::error;
 use slog::info;
 use slog::warn;
@@ -657,7 +656,7 @@ async fn send_update_in_chunks(
     let id = update_id.into();
     while !CursorExt::is_empty(&image) {
         let prior_pos = image.position();
-        trace!(
+        debug!(
             log, "sending update chunk";
             "id" => %update_id,
             "offset" => offset,

scripts/README.md

@@ -58,6 +58,12 @@ Rhai calls the script's `main() -> i64 {}`.
   - rhai_fs::FilesystemPackage - file system access
   - [rhai_chrono::ChronoPackage](https://github.com/iganev/rhai-chrono) - standard time formats.
 
+### Modified Rhai behaviod
+  - The `debug("message")` function is routed to the faux-mgs slog logging.
+    Prefixing a message with "crit|", "trace|", "error|", "warn|", "error|", or "debug|"
+    will log at that corresponding level. Leaving off the prefix or using some other
+    prefix will log at the debug level.
+
 ### Custom functions:
 
   - faux_mgs(["arg0", .., "argN"]) -> #{} // Run any faux-mgs command -> map

scripts/targets.json

@@ -1,6 +1,4 @@
 {
-  "host_system": "slab",
-
   "repo-home": "${HOME}/Oxide/src",
   "base_repo": "${repo-home}/hubris/master",
   "ut_repo": "${repo-home}/hubris/epoch",

scripts/upgrade-rollback.rhai

@@ -29,12 +29,16 @@ fn main() {
 
     print("\n## Determine initial FW state and update if needed");
 
-    // There should be no updates in progress.
-    // If there was a previous RoT update in progress and
-    // the SP has since been reset, then update-status
-    // for SP and RoT will return None.
-    // However, the RoT will refuse requests to reset or update.
+    // Generally, there should no updates in progress
+    // and we can proceed with installation of the
+    // baseline images if needed.
+    // .
+    // If a previous test was aborted, some recovery may
+    // be necessary.
+    //
+    // A corner case that may require a hard-reset is described in:
     // https://github.com/oxidecomputer/hubris/issues/1022
+
     let problems = 0;
     for attempt in 1..=2 {
         problems = 0;
@@ -50,7 +54,7 @@ fn main() {
                 let id = r?.id;
                 debug(`r=${r}`);
                 debug(`id=${id}`);
-                print(`Failed: component ${component}: ${r}`);
+                debug(`Failed: component ${component}: ${r}`);
                 print(`The SP probably needs to be reset before continuing`);
                 print(`Trying to abort the update with id=${id}`);
                 let r = faux_mgs(["update-abort", component, `${id}`]);
@@ -93,7 +97,7 @@ fn main() {
     let flash_rot = result?.ok?.rot;
 
     print("");
-    print(`Elapsed time so far: ${start_ts.elapsed}`);
+    print(`Elapsed time: ${start_ts.elapsed}`);
     print(`Now=${datetime_local()}`);
     print("");