//! What a plug-in may import from the host ([`IMPORTS`]), from plug-in API level 2 on: //! `vc_progress` reports how far a run has got, `vc_cancelled` tells it the user or a host limit //! asked it to stop, and `vc_log` writes a log line. A module may import them only when its //! manifest gives `api` 2 and lists the `progress` permission, and the host checks each import when //! the module is loaded ([`check_imports`], [`check_granted`]): one it doesn't offer, one with //! another signature and one the manifest doesn't allow are refused by name. //! //! Each call's arguments are checked: progress is clamped and passed on only when it changes (with //! a known total, to another tenth of a percent; past [`MAX_PROGRESS_REPORTS`], once per //! [`PROGRESS_STRIDE`] changes), log text must lie inside the module's memory and be UTF-8, and //! each line ([`MAX_LOG_LINE`]) and each run ([`MAX_LOG_LINES`], [`MAX_LOG_BYTES`], //! [`MAX_LOG_READ`]) are capped. Nothing a module passes can panic the host. use wasmi::{Caller, Engine, Extern, ExternType, Linker, Module, StoreLimits, ValType}; use crate::manifest::Manifest; use crate::permissions::{self, PROGRESS_API, Permission}; use crate::{Error, Result}; /// The module a plug-in imports host functions from (the name a Rust or C toolchain gives /// `extern` functions by default). pub const MODULE: &str = "env"; /// What the host passes as the step's description with a plug-in's progress /// ([`vectorcraft_doc::cancel::progress`]), so a progress window shows a share rather than a count /// of artboards or files. pub const PROGRESS_STEP: &str = "plug-in"; /// Longest log line: its first 1,024 bytes of text, shown as at most 1,024 characters with hidden /// characters escaped. A longer one is cut and ends with `…`. pub const MAX_LOG_LINE: usize = 1024; /// Most log lines one run writes; later ones are dropped, after one "log truncated" line. pub const MAX_LOG_LINES: usize = 200; /// Most bytes of log text, as written with its escapes, one run writes; lines past it are dropped /// as past [`MAX_LOG_LINES`]. pub const MAX_LOG_BYTES: usize = 32 * 1024; /// Most bytes of text the host reads from a run's `vc_log` calls, checked or not: a call that /// would read past it is dropped as past [`MAX_LOG_LINES`]. pub const MAX_LOG_READ: usize = 1024 * 1024; /// Most progress reports one run passes on at the full rate; after them, one changed report in /// [`PROGRESS_STRIDE`] is, and so is the first after a total becomes known or unknown. The run's /// last report is always kept ([`Report::progress`]). pub const MAX_PROGRESS_REPORTS: usize = 2000; /// Past [`MAX_PROGRESS_REPORTS`], how many changed reports go by for each one passed on. pub const PROGRESS_STRIDE: usize = 1000; /// What `vc_log` returns: the line was written. pub const LOG_WRITTEN: i32 = 0; /// What `vc_log` returns: the run's log budget is spent, so the line was dropped. pub const LOG_DROPPED: i32 = 1; /// What `vc_log` returns: the text doesn't lie inside the module's memory. pub const LOG_OUTSIDE_MEMORY: i32 = -1; /// What `vc_log` returns: the text is not UTF-8. pub const LOG_NOT_UTF8: i32 = -2; /// What `vc_log` returns: the level is not 0 to 3. pub const LOG_BAD_LEVEL: i32 = -3; /// One host import: its name and its type. pub struct Import { pub name: &'static str, params: &'static [ValType], results: &'static [ValType], /// Its type as WebAssembly text writes it. pub signature: &'static str, } /// The host imports of API level 2, in module [`MODULE`]: /// /// - `vc_progress(done: i64, total: i64)`: `done` of `total` steps are finished (`total` 0 or less: /// not known). Negative values count as 0 and `done` is clamped to `total`; /// - `vc_cancelled() -> i32`: 1 once the user cancelled the run or its time budget ran out, else 0; /// - `vc_log(level: i32, ptr: i32, len: i32) -> i32`: writes the UTF-8 text at `ptr` as a log line /// of `level` (0 error, 1 warning, 2 information, 3 debug) → [`LOG_WRITTEN`], [`LOG_DROPPED`], /// [`LOG_OUTSIDE_MEMORY`], [`LOG_NOT_UTF8`] or [`LOG_BAD_LEVEL`]. pub const IMPORTS: [Import; 3] = [ Import { name: "vc_progress", params: &[ValType::I64, ValType::I64], results: &[], signature: "(param i64 i64)" }, Import { name: "vc_cancelled", params: &[], results: &[ValType::I32], signature: "(result i32)" }, Import { name: "vc_log", params: &[ValType::I32, ValType::I32, ValType::I32], results: &[ValType::I32], signature: "(param i32 i32 i32) (result i32)", }, ]; /// A log line's level. #[derive(Clone, Copy, Debug, PartialEq, Eq)] pub enum LogLevel { Error, Warn, Info, Debug, } impl LogLevel { /// The level `vc_log`'s `level` names. fn from_code(code: i32) -> Option { match code { 0 => Some(LogLevel::Error), 1 => Some(LogLevel::Warn), 2 => Some(LogLevel::Info), 3 => Some(LogLevel::Debug), _ => None, } } fn log_level(self) -> log::Level { match self { LogLevel::Error => log::Level::Error, LogLevel::Warn => log::Level::Warn, LogLevel::Info => log::Level::Info, LogLevel::Debug => log::Level::Debug, } } } /// A line a plug-in wrote with `vc_log`: its control and bidirectional formatting characters /// escaped ([`permissions::display_text`]), and cut to [`MAX_LOG_LINE`]. #[derive(Clone, Debug, PartialEq, Eq)] pub struct LogLine { pub level: LogLevel, pub text: String, } /// The text of the line that stands for the lines a run's log budget dropped. pub const LOG_TRUNCATED: &str = "log truncated: later lines were dropped"; /// What a run reported through the host imports. #[derive(Clone, Debug, Default, PartialEq, Eq)] pub struct Report { /// Its last progress report, clamped: `(done, total)`, `total` 0 when not known. pub progress: Option<(u64, u64)>, /// The lines it wrote, then [`LOG_TRUNCATED`] once its budget dropped one. pub lines: Vec, /// Did its log budget drop a line? pub truncated: bool, } /// When a run must stop (native: a wall-clock deadline). #[derive(Clone, Copy)] pub(crate) struct Deadline { #[cfg(not(target_arch = "wasm32"))] at: std::time::Instant, } impl Deadline { pub(crate) fn new(wall_time_ms: u64) -> Self { #[cfg(target_arch = "wasm32")] let _ = wall_time_ms; Self { #[cfg(not(target_arch = "wasm32"))] at: std::time::Instant::now() + std::time::Duration::from_millis(wall_time_ms), } } pub(crate) fn passed(&self) -> bool { #[cfg(not(target_arch = "wasm32"))] if std::time::Instant::now() >= self.at { return true; } false } pub(crate) fn check(&self) -> Result<()> { if self.passed() { Err(Error::Limit("time budget".into())) } else { Ok(()) } } } /// One run's state that the host imports read and write. pub(crate) struct Run { /// The plug-in's id, which its log lines carry. id: String, /// Are its progress reports passed on ([`vectorcraft_doc::cancel::progress`])? A live /// effect's are not: it is drawn as part of something else, such as an export. forward: bool, /// Are its log lines written to the app's log? Not while the module is being loaded. logged: bool, deadline: Deadline, /// The last report passed on, as per mille of a known total (with 1) or the count of an /// unknown one (with 0), how many were, and how many changed ones went by since the last. last: Option<(u64, u64)>, reports: usize, skipped: usize, /// Bytes of log text written (with their escapes) and read. log_bytes: usize, log_read: usize, pub(crate) report: Report, } impl Run { pub(crate) fn new(id: &str, forward: bool, logged: bool, deadline: Deadline) -> Self { Run { id: id.to_string(), forward, logged, deadline, last: None, reports: 0, skipped: 0, log_bytes: 0, log_read: 0, report: Report::default(), } } fn progress(&mut self, done: i64, total: i64) { let total = u64::try_from(total).unwrap_or(0); let done = u64::try_from(done).unwrap_or(0); let done = if total > 0 { done.min(total) } else { done }; self.report.progress = Some((done, total)); let key = if total > 0 { ((u128::from(done) * 1000 / u128::from(total)) as u64, 1) } else { (done, 0) }; if !self.forward || self.last == Some(key) { return; } let switched = self.last.is_some_and(|(_, t)| (t > 0) != (total > 0)); if self.reports >= MAX_PROGRESS_REPORTS && !switched { self.skipped += 1; if self.skipped < PROGRESS_STRIDE { return; } } self.skipped = 0; self.last = Some(key); self.reports += 1; vectorcraft_doc::cancel::progress(done, total, PROGRESS_STEP); } fn cancelled(&self) -> i32 { i32::from(vectorcraft_doc::cancel::is_cancelled() || self.deadline.passed()) } /// Writes the `len` bytes at `ptr` in `memory` as a line of `level` → what `vc_log` returns. fn log(&mut self, level: i32, memory: &[u8], ptr: usize, len: usize) -> i32 { let Some(level) = LogLevel::from_code(level) else { return LOG_BAD_LEVEL }; let Some(bytes) = ptr.checked_add(len).and_then(|end| memory.get(ptr..end)) else { return LOG_OUTSIDE_MEMORY }; if self.report.truncated { return LOG_DROPPED; } if self.log_read.saturating_add(len) > MAX_LOG_READ { return self.truncate(); } self.log_read += len; let Ok(text) = std::str::from_utf8(bytes) else { return LOG_NOT_UTF8 }; // A character the cut splits is left out. let head = text.get(..text.floor_char_boundary(MAX_LOG_LINE)).unwrap_or(text); let shown = if head.len() < text.len() { let mut shown = permissions::display_text(head, MAX_LOG_LINE - 1); if !shown.ends_with('…') { shown.push('…'); } shown } else { permissions::display_text(head, MAX_LOG_LINE) }; if self.report.lines.len() >= MAX_LOG_LINES || self.log_bytes + shown.len() > MAX_LOG_BYTES { return self.truncate(); } self.log_bytes += shown.len(); self.write(level, shown); LOG_WRITTEN } /// Drops the line and the run's later ones, after one line that says so → [`LOG_DROPPED`]. fn truncate(&mut self) -> i32 { self.report.truncated = true; self.write(LogLevel::Warn, LOG_TRUNCATED.to_string()); LOG_DROPPED } fn write(&mut self, level: LogLevel, text: String) { if self.logged { log::log!(target: "vectorcraft_plugins", level.log_level(), "{}: {text}", self.id); } self.report.lines.push(LogLine { level, text }); } } /// What a store holds: its memory limits and the run's state. pub(crate) struct Host { pub(crate) limits: StoreLimits, pub(crate) run: Run, } /// A linker that offers the host imports when `granted`, and no import otherwise. pub(crate) fn linker(engine: &Engine, granted: bool) -> Linker { let mut linker = Linker::::new(engine); if granted { // Each name is defined once, so none of these fails. let _ = linker.func_wrap(MODULE, "vc_progress", |mut caller: Caller<'_, Host>, done: i64, total: i64| { caller.data_mut().run.progress(done, total); }); let _ = linker.func_wrap(MODULE, "vc_cancelled", |caller: Caller<'_, Host>| -> i32 { caller.data().run.cancelled() }); let _ = linker.func_wrap(MODULE, "vc_log", |mut caller: Caller<'_, Host>, level: i32, ptr: i32, len: i32| -> i32 { let Some(Extern::Memory(memory)) = caller.get_export("memory") else { return LOG_OUTSIDE_MEMORY }; let (data, host) = memory.data_and_store_mut(&mut caller); host.run.log(level, data, ptr as u32 as usize, len as u32 as usize) }); } linker } /// Checks that every import of `module` is a host import with the host's signature → their names. /// Any other import is refused, and the error names it. pub(crate) fn check_imports(module: &Module) -> Result> { let mut names = Vec::new(); for imp in module.imports() { let offered = if imp.module() == MODULE { IMPORTS.iter().find(|i| i.name == imp.name()) } else { None }; let (from, name) = (permissions::display_text(imp.module(), 64), permissions::display_text(imp.name(), 64)); let Some(host) = offered else { return Err(Error::Abi(format!( "the module imports `{from}.{name}`, which the host doesn't offer: a plug-in may import only `env.vc_progress`, `env.vc_cancelled` and `env.vc_log` (plug-in API level 2), and no WASI, files or network" ))); }; match imp.ty() { ExternType::Func(f) if f.params() == host.params && f.results() == host.results => names.push(host.name), _ => { let signature = host.signature; return Err(Error::Abi(format!("the module imports `env.{name}` with another type than the host's: it is {signature}"))); } } } Ok(names) } /// Checks that `manifest` allows the host imports `imports`: `api` 2 and the `progress` /// permission. The error names the first import it doesn't allow. pub(crate) fn check_granted(manifest: &Manifest, imports: &[&str]) -> Result<()> { match imports.first() { Some(name) if manifest.api < PROGRESS_API || !manifest.permissions().contains(&Permission::Progress) => Err(Error::Abi(format!( "the module imports `env.{name}`, which a plug-in may use only at plug-in API level {PROGRESS_API} (`api` {PROGRESS_API}) and with the permission `progress`" ))), _ => Ok(()), } } #[cfg(test)] mod tests { use super::*; fn run() -> Run { Run::new("test", true, false, Deadline::new(60_000)) } /// Progress is clamped: negative counts are 0 and `done` never passes a known total. #[test] fn progress_is_clamped() { let mut r = run(); for ((done, total), want) in [((5, 3), (3, 3)), ((-4, 10), (0, 10)), ((7, -1), (7, 0)), ((i64::MAX, i64::MAX), (i64::MAX as u64, i64::MAX as u64))] { r.progress(done, total); assert_eq!(r.report.progress, Some(want), "{done} of {total}"); } } /// Reports are passed on only when they change (with a known total, to another tenth of a /// percent, however the total changes; with an unknown total, each change of `done`), and past /// [`MAX_PROGRESS_REPORTS`] once per [`PROGRESS_STRIDE`] changes, except the first after the /// total becomes known; the last one is always kept. #[test] fn progress_is_passed_on_at_a_bounded_rate() { use std::cell::RefCell; use std::rc::Rc; let seen = Rc::new(RefCell::new(Vec::new())); let sink: vectorcraft_doc::cancel::ProgressSink = { let seen = seen.clone(); Rc::new(move |d, t, w| seen.borrow_mut().push((d, t, w.to_string()))) }; let token = vectorcraft_doc::cancel::CancelToken::new(); let mut r = run(); vectorcraft_doc::cancel::scope(&token, Some(sink), || { for done in 0..=1_000_000 { r.progress(done, 1_000_000); } }); let seen = seen.borrow(); assert_eq!(seen.len(), 1001, "one per tenth of a percent"); assert_eq!(seen.last(), Some(&(1_000_000, 1_000_000, PROGRESS_STEP.to_string()))); let mut unknown = run(); let later = Rc::new(RefCell::new(Vec::new())); let sink: vectorcraft_doc::cancel::ProgressSink = { let later = later.clone(); Rc::new(move |d, t, _| later.borrow_mut().push((d, t))) }; vectorcraft_doc::cancel::scope(&token, Some(sink), || { for done in 0..10_000 { unknown.progress(done, 0); } assert_eq!(unknown.reports, MAX_PROGRESS_REPORTS + (10_000 - MAX_PROGRESS_REPORTS) / PROGRESS_STRIDE); assert_eq!(unknown.report.progress, Some((9_999, 0)), "the last report is kept"); // A total that becomes known is passed on at once, and the reports after it keep // coming at the slower rate. unknown.progress(10, 100); assert_eq!(later.borrow().last(), Some(&(10, 100))); for done in 11..=100 { unknown.progress(done, 100); } }); assert_eq!(later.borrow().last(), Some(&(10, 100)), "90 changes are fewer than the stride"); assert_eq!(unknown.report.progress, Some((100, 100))); // A new total at the same tenth of a percent is not a new step. let mut retotalled = run(); let steps = Rc::new(RefCell::new(Vec::new())); let sink: vectorcraft_doc::cancel::ProgressSink = { let steps = steps.clone(); Rc::new(move |d, t, _| steps.borrow_mut().push((d, t))) }; vectorcraft_doc::cancel::scope(&token, Some(sink), || { for total in 10..2_010 { retotalled.progress(total / 10, total - total % 10); } }); assert_eq!(*steps.borrow(), [(1, 10)]); assert_eq!(retotalled.report.progress, Some((200, 2_000))); } /// Text outside memory, text that isn't UTF-8 and an unknown level are errors; a long line is /// cut, also inside a character, and hidden characters are escaped. #[test] fn log_text_is_checked_and_cut() { let mut r = run(); let memory = b"hello\xff\xfe\nworld"; assert_eq!(r.log(2, memory, 0, 5), LOG_WRITTEN); assert_eq!(r.log(2, memory, 0, memory.len() + 1), LOG_OUTSIDE_MEMORY); assert_eq!(r.log(2, memory, usize::MAX, 2), LOG_OUTSIDE_MEMORY); assert_eq!(r.log(2, memory, 4, 3), LOG_NOT_UTF8); assert_eq!(r.log(4, memory, 0, 5), LOG_BAD_LEVEL); assert_eq!(r.log(-1, memory, 0, 5), LOG_BAD_LEVEL); assert_eq!(r.log(0, memory, 7, 6), LOG_WRITTEN); // The cut falls inside the 512th "é", which is left out. let long = format!("a{}", "é".repeat(MAX_LOG_LINE)); assert_eq!(r.log(1, long.as_bytes(), 0, long.len()), LOG_WRITTEN); let lines = &r.report.lines; assert_eq!(lines[0], LogLine { level: LogLevel::Info, text: "hello".into() }); assert_eq!(lines[1], LogLine { level: LogLevel::Error, text: "\\u{000A}world".into() }); assert_eq!(lines[2], LogLine { level: LogLevel::Warn, text: format!("a{}…", "é".repeat(MAX_LOG_LINE / 2 - 1)) }); assert!(!r.report.truncated); // Text past the cut is checked too. let bad_tail = [vec![b'a'; MAX_LOG_LINE * 2], vec![0xff]].concat(); assert_eq!(r.log(2, &bad_tail, 0, bad_tail.len()), LOG_NOT_UTF8); // A cut line of escapes is at most MAX_LOG_LINE characters, its ellipsis included. let controls = vec![1u8; MAX_LOG_LINE * 2]; assert_eq!(r.log(2, &controls, 0, controls.len()), LOG_WRITTEN); let text = &r.report.lines[3].text; assert!(text.starts_with("\\u{0001}") && text.ends_with('…') && text.chars().count() <= MAX_LOG_LINE, "{text}"); } /// The byte budget counts a line as written, with its escapes, so short lines of hidden /// characters can't write more than [`MAX_LOG_BYTES`]. #[test] fn log_budget_counts_escaped_text() { let mut r = run(); let controls = [1u8; 100]; let shown = "\\u{0001}".len() * controls.len(); let fit = MAX_LOG_BYTES / shown; for i in 0..fit { assert_eq!(r.log(2, &controls, 0, controls.len()), LOG_WRITTEN, "line {i}"); } assert_eq!(r.log(2, &controls, 0, controls.len()), LOG_DROPPED); let written: usize = r.report.lines.iter().filter(|l| l.text != LOG_TRUNCATED).map(|l| l.text.len()).sum(); assert!(written <= MAX_LOG_BYTES, "{written}"); } /// The host reads at most [`MAX_LOG_READ`] bytes of log text in a run, so long texts can't /// make it check more; once past it, later calls are dropped without reading. #[test] fn log_text_read_is_bounded() { let mut r = run(); let big = vec![b'a'; MAX_LOG_READ / 4]; for _ in 0..4 { assert_eq!(r.log(2, &big, 0, big.len()), LOG_WRITTEN); } assert_eq!(r.log(2, b"x", 0, 1), LOG_DROPPED); assert!(r.report.truncated); let mut huge = run(); let over = vec![0xffu8; MAX_LOG_READ + 1]; assert_eq!(huge.log(2, &over, 0, over.len()), LOG_DROPPED, "dropped before it is checked"); assert_eq!(huge.log(2, b"x", 0, 1), LOG_DROPPED); } /// Lines past the run's budget are dropped, with one line that says so. #[test] fn log_lines_past_the_budget_are_dropped_with_one_truncation_line() { let mut r = run(); for i in 0..MAX_LOG_LINES + 50 { let want = if i < MAX_LOG_LINES { LOG_WRITTEN } else { LOG_DROPPED }; assert_eq!(r.log(2, b"line", 0, 4), want, "line {i}"); } assert_eq!(r.report.lines.len(), MAX_LOG_LINES + 1); assert_eq!(r.report.lines.last(), Some(&LogLine { level: LogLevel::Warn, text: LOG_TRUNCATED.into() })); assert!(r.report.truncated); // So is text past the run's bytes. let mut bytes = run(); let big = vec![b'x'; MAX_LOG_LINE]; let fit = MAX_LOG_BYTES / MAX_LOG_LINE; for _ in 0..fit { assert_eq!(bytes.log(2, &big, 0, big.len()), LOG_WRITTEN); } assert_eq!(bytes.log(2, b"x", 0, 1), LOG_DROPPED); assert_eq!(bytes.report.lines.len(), fit + 1); } }