Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
13 changes: 9 additions & 4 deletions crates/engine/src/cmd/exports.rs
Original file line number Diff line number Diff line change
Expand Up @@ -190,6 +190,9 @@ pub struct Started {
pub(crate) start: web_time::Instant,
/// The admitted invocation; cloned metadata never selects replacement authority.
pub(crate) owner: crate::policy::Continuation,
/// The project it started in, its name as the log keeps it and its `Session::opened`: the
/// log's entry names that one, not one opened while it ran.
pub(crate) project: (String, u64),
}

#[cfg(not(target_arch = "wasm32"))]
Expand Down Expand Up @@ -235,7 +238,8 @@ pub(crate) fn export_start_raw(s: &mut Session, op: crate::policy::Authorized<cr
owner.check()?;
let current = owner.clone();
let still = std::sync::Arc::new(move || current.check().is_ok());
let started = Started { command, params: p.clone(), at: crate::project_log::now_ms(), start: web_time::Instant::now(), owner };
let project = (crate::project_log::kept_name(&s.title()), s.opened);
let started = Started { command, params: p.clone(), at: crate::project_log::now_ms(), start: web_time::Instant::now(), owner, project };
let work = crate::render::rustgis_tiles::cache::with_still(still, || start(s, p))?;
Ok(ExportRun { name, started, work })
}
Expand All @@ -245,7 +249,7 @@ pub(crate) fn export_start_raw(s: &mut Session, op: crate::policy::Authorized<cr
/// its answer: the troubleshooting history files what it says (its failure too) under that
/// command, and the session's log has its entry, as when it runs here.
pub fn export_land(s: &mut Session, started: Started, done: Result<Wrote, String>) -> CmdResult {
let Started { command, params, at, start, owner } = started;
let Started { command, params, at, start, owner, project } = started;
let before = s.diagnostic_source.replace(command);
let mark = s.notice_mark();
let landed: CmdResult = (|| {
Expand All @@ -268,8 +272,9 @@ pub fn export_land(s: &mut Session, started: Started, done: Result<Wrote, String
}
s.diagnostic_source = before;
if s.log.on() && crate::project_log::is_logged(s, command, &params) {
let entry = crate::project_log::entry(command, crate::project_log::kept_params(&params), &landed, at, start.elapsed());
s.log.push(entry);
let (kept, partial) = crate::project_log::kept_and_partial(&params);
// The project it started in, not one opened while it ran.
s.log.push(crate::project_log::entry(project, command, kept, partial, &landed, at, start.elapsed()));
}
landed
}
Expand Down
2 changes: 1 addition & 1 deletion crates/engine/src/cmd/project.rs
Original file line number Diff line number Diff line change
Expand Up @@ -34,7 +34,7 @@ pub fn commands() -> Vec<C> {
// The session log (#797): read, written out, emptied, turned on or off. It sits outside
// the project, so none of these changes the project or takes an undo step.
C::new("project.log", "Session Log", "Project", log).roles(&[]).effects(crate::policy::Effects::NONE.with(crate::policy::Effect::Files)).view().params(
r#"{"since"?: milliseconds since 1970 (UTC), "until"?: milliseconds, "command"?: "a command id, or the start of one (layer.)", "failed"?: bool (true: only those that failed; false: only those that succeeded), "limit"?: entries, a whole number (default 100, the newest; 1 to 1000)} → {"entries": [{"at", "command", "params", "ok", "error"?, "millis"}], "count": matching, "total": in the log, "on": bool}"#,
r#"{"since"?: milliseconds since 1970 (UTC), "until"?: milliseconds, "command"?: "a command id, or the start of one (layer.)", "failed"?: bool (true: only those that failed; false: only those that succeeded), "limit"?: entries, a whole number (default 100, the newest; 1 to 1000)} → {"entries": [{"at", "command", "params", "ok", "error"?, "millis", "project": the project open when it ran, "partial"?: true when params were cut or had secrets taken out}], "count": matching, "total": in the log, "on": bool}"#,
),
C::new("project.exportLog", "Export Session Log", "Project", export_log).roles(&[]).effects(crate::policy::Effects::NONE.with(crate::policy::Effect::Files))
.view()
Expand Down
10 changes: 6 additions & 4 deletions crates/engine/src/lib.rs
Original file line number Diff line number Diff line change
Expand Up @@ -1499,11 +1499,13 @@ impl Session {
// command's result as it was, without an entry, and says so in the app's log.
let logged = std::panic::catch_unwind(std::panic::AssertUnwindSafe(|| {
if project_log::is_logged(self, id, params) {
let params = match step {
Some(label) => serde_json::json!({"step": label}),
None => project_log::kept_params(params),
// The step's label isn't a parameter: the command, run again, takes none.
let (params, partial) = match step {
Some(label) => (serde_json::json!({"step": label}), false),
None => project_log::kept_and_partial(params),
};
let e = project_log::entry(id, params, &res, at, start.elapsed());
let project = (project_log::kept_name(&self.title()), self.opened);
let e = project_log::entry(project, id, params, partial, &res, at, start.elapsed());
if joins && res.is_ok() { self.log.join_last(e) } else { self.log.push(e) }
}
}));
Expand Down
125 changes: 116 additions & 9 deletions crates/engine/src/project_log.rs
Original file line number Diff line number Diff line change
Expand Up @@ -247,17 +247,70 @@ fn embedded_redacted(v: &Value, depth: usize) -> Value {
o.iter()
.map(|(k, x)| {
// Preserve History's plain-key refinement; the log-only fields share diagnostics'
// canonical list. Clipping already bounds recursion and text before this pass.
// canonical list.
let sensitive =
rustgis_data::address::normalized_name(k).as_deref() != Some("key") && rustgis_data::address::log_sensitive(k);
(k.clone(), if sensitive { Value::String(String::new()) } else { embedded_redacted(x, depth + 1) })
})
.collect(),
),
// Past eight levels, left out, as `clip` does: JSON read from a text wasn't clipped, and
// what is that deep isn't looked at.
Value::Array(_) | Value::Object(_) => Value::String("…".into()),
Comment thread
coderabbitai[bot] marked this conversation as resolved.
Resolved
other => other.clone(),
}
}

/// JSON whose every object has each of its keys once, as its text is read: deserializing one with
/// a key written twice (at any depth) fails.
struct UniqueKeys;

impl<'de> Deserialize<'de> for UniqueKeys {
fn deserialize<D: serde::Deserializer<'de>>(d: D) -> Result<Self, D::Error> {
d.deserialize_any(UniqueKeys)
}
}

impl<'de> serde::de::Visitor<'de> for UniqueKeys {
type Value = UniqueKeys;

fn expecting(&self, f: &mut std::fmt::Formatter) -> std::fmt::Result {
f.write_str("JSON")
}
fn visit_bool<E>(self, _: bool) -> Result<Self, E> {
Ok(self)
}
fn visit_i64<E>(self, _: i64) -> Result<Self, E> {
Ok(self)
}
fn visit_u64<E>(self, _: u64) -> Result<Self, E> {
Ok(self)
}
fn visit_f64<E>(self, _: f64) -> Result<Self, E> {
Ok(self)
}
fn visit_str<E>(self, _: &str) -> Result<Self, E> {
Ok(self)
}
fn visit_unit<E>(self) -> Result<Self, E> {
Ok(self)
}
fn visit_seq<A: serde::de::SeqAccess<'de>>(self, mut items: A) -> Result<Self, A::Error> {
while items.next_element::<UniqueKeys>()?.is_some() {}
Ok(self)
}
fn visit_map<A: serde::de::MapAccess<'de>>(self, mut keys: A) -> Result<Self, A::Error> {
let mut seen = std::collections::HashSet::new();
while let Some(key) = keys.next_key::<String>()? {
if !seen.insert(key) {
return Err(serde::de::Error::custom("a key written twice"));
}
keys.next_value::<UniqueKeys>()?;
}
Ok(self)
}
}

/// `t` with each JSON object it holds (from a `{` to where the object ends) redacted. Texts are
/// clipped before this, so trying each `{` stays cheap; the secret names are looked for once.
pub(crate) fn json_in_text_redacted(t: &str) -> String {
Expand All @@ -273,7 +326,19 @@ pub(crate) fn json_in_text_redacted(t: &str) -> String {
match objects.next() {
Some(Ok(v @ Value::Object(_))) => {
let end = objects.byte_offset();
out.push_str(&serde_json::to_string(&crate::cmd::history::redacted(&v)).unwrap_or_default());
// Redacted by the log's own rule, as its parameters are. When that takes nothing
// out, the object is kept as written: a script copied back from the log is the
// one that ran, and its spacing doesn't make it partial. Not when a key is written
// twice, though: the value read is the last one, but the text still holds the
// first (a secret, perhaps, under an escaped name), so that object is written
// out again from what was read.
let kept = redacted(&v);
let written = from.get(..end).unwrap_or("");
if kept == v && serde_json::from_str::<UniqueKeys>(written).is_ok() {
out.push_str(written);
} else {
out.push_str(&serde_json::to_string(&kept).unwrap_or_default());
}
rest = from.get(end..).unwrap_or("");
}
// Cut short by the clip, or an object that doesn't parse (a trailing comma, single
Expand Down Expand Up @@ -430,7 +495,19 @@ fn clip(v: &Value, chars: usize, items: usize, depth: usize) -> Value {

/// The entry of command `id`, which started at `at` and took `took`; its error without secrets,
/// clipped to [`LOG_ERROR_CHARS`].
pub(crate) fn entry(id: &str, params: Value, res: &CmdResult, at: u64, took: web_time::Duration) -> LogEntry {
/// `partial`: its parameters aren't all as given ([`kept_and_partial`]). It is the entry of the
/// project given, its name as the log keeps it ([`kept_name`]) and its `Session::opened`: the one
/// open as the command ended (the one it opened, for one that opens a project), or for an export,
/// the one it started in.
pub(crate) fn entry(
project: (String, u64),
id: &str,
params: Value,
partial: bool,
res: &CmdResult,
at: u64,
took: web_time::Duration,
) -> LogEntry {
let error = res.as_ref().err().map(|e| kept_error(e));
LogEntry {
at,
Expand All @@ -439,9 +516,27 @@ pub(crate) fn entry(id: &str, params: Value, res: &CmdResult, at: u64, took: web
ok: res.is_ok(),
error,
millis: u64::try_from(took.as_millis()).unwrap_or(u64::MAX),
project: project.0,
opened: project.1,
partial,
}
}

/// A project's name as the log keeps it: cut at [`crate::cmd::MAX_NAME`] characters and a `…`, as
/// a name read from a file may be longer than one given to `project.rename`.
pub(crate) fn kept_name(name: &str) -> String {
let max = crate::cmd::MAX_NAME;
if name.chars().nth(max).is_some() { format!("{}…", name.chars().take(max).collect::<String>()) } else { name.to_string() }
}

/// `params` as the log keeps them ([`kept_params`]), and whether that is less than they were:
/// cut to fit or with secrets taken out, so they wouldn't run again as they ran.
pub(crate) fn kept_and_partial(params: &Value) -> (Value, bool) {
let kept = kept_params(params);
let partial = kept != *params;
(kept, partial)
}

/// Most entries the log keeps; past it, the oldest go first.
pub const LOG_LIMIT: usize = 10_000;
/// The most entries of plugins' commands the log keeps, their oldest going first past it: a
Expand All @@ -454,9 +549,9 @@ pub const LOG_LIST_ITEMS: usize = 100;
pub const LOG_ERROR_CHARS: usize = 500;

/// One command run in the session: when it started (UTC, milliseconds since 1970), its id, its
/// parameters (secrets taken out, large values clipped), whether it succeeded, its error, and how
/// long it took.
#[derive(Clone, Debug, PartialEq, Serialize, Deserialize)]
/// parameters (secrets taken out, large values clipped), whether it succeeded, its error, how
/// long it took, and the project it ran in.
#[derive(Clone, Debug, Default, PartialEq, Serialize, Deserialize)]
pub struct LogEntry {
pub at: u64,
pub command: String,
Expand All @@ -467,6 +562,17 @@ pub struct LogEntry {
pub error: Option<String>,
#[serde(default)]
pub millis: u64,
/// The name of the project open when it ran (the one it opened, for a command that opens one).
#[serde(default)]
pub project: String,
/// Which of the session's projects that was ([`Session::opened`]), so two of the same name
/// (two new ones, both "Untitled") are told apart. The session's own: not saved with the log.
#[serde(skip)]
pub opened: u64,
/// Its parameters aren't all as given (cut to fit, or with secrets taken out): copied, they
/// wouldn't run as they ran.
#[serde(default, skip_serializing_if = "std::ops::Not::not")]
pub partial: bool,
}

impl LogEntry {
Expand Down Expand Up @@ -607,7 +713,7 @@ impl SessionLog {
/// line). Entry by entry, so a long log isn't held as text first.
pub fn write(&self, w: &mut dyn std::io::Write, csv: bool) -> std::io::Result<()> {
if csv {
w.write_all(b"time_utc,at,command,ok,millis,error,params\n")?;
w.write_all(b"time_utc,at,command,ok,millis,error,params,project\n")?;
}
self.entries.iter().try_for_each(|e| write_entry(w, e, csv))
}
Expand All @@ -634,14 +740,15 @@ fn write_entry(w: &mut dyn std::io::Write, e: &LogEntry, csv: bool) -> std::io::
if csv {
writeln!(
w,
"{},{},{},{},{},{},{}",
"{},{},{},{},{},{},{},{}",
e.time_utc(),
e.at,
csv_cell(&e.command),
e.ok,
e.millis,
csv_cell(e.error.as_deref().unwrap_or("")),
csv_cell(&e.params.to_string())
csv_cell(&e.params.to_string()),
csv_cell(&e.project)
)
} else {
serde_json::to_writer(&mut *w, e).map_err(std::io::Error::other)?;
Expand Down
Loading
Loading