difftreelog
feat derivation graph to spans
in: trunk
6 files changed
cmds/fleet/Cargo.tomldiffbeforeafterboth--- a/cmds/fleet/Cargo.toml
+++ b/cmds/fleet/Cargo.toml
@@ -50,7 +50,7 @@
tracing-opentelemetry.workspace = true
[features]
-default = []
+default = ["indicatif"]
# Not quite stable
indicatif = [
"dep:tracing-indicatif",
cmds/fleet/src/main.rsdiffbeforeafterboth--- a/cmds/fleet/src/main.rs
+++ b/cmds/fleet/src/main.rs
@@ -120,7 +120,8 @@
let indicatif_layer = {
use std::time::Duration;
- IndicatifLayer::new().with_progress_style(
+ IndicatifLayer::new().with_max_progress_bars(10, Some(ProgressStyle::default_spinner()))
+ .with_progress_style(
ProgressStyle::with_template(
"{color_start}{span_child_prefix} {span_name}{{{span_fields}}}{color_end} {wide_msg} {color_start}{download_progress} {elapsed}{color_end}",
)
crates/nix-eval/build.rsdiffbeforeafterboth--- a/crates/nix-eval/build.rs
+++ b/crates/nix-eval/build.rs
@@ -18,6 +18,7 @@
"nix-util",
"nix-util-c",
"nix-store",
+ "nix-store-c",
"nix-expr",
"nix-flake",
"nix-fetchers",
@@ -72,6 +73,12 @@
.include_paths
.into_iter()
.chain(
+ pkg_config::probe_library("nix-store-c")
+ .expect("nix-store-c")
+ .include_paths
+ .into_iter(),
+ )
+ .chain(
pkg_config::probe_library("nix-flake-c")
.expect("nix-flake-c")
.include_paths
crates/nix-eval/src/drv.rsdiffbeforeafterboth--- /dev/null
+++ b/crates/nix-eval/src/drv.rs
@@ -0,0 +1,150 @@
+use std::collections::{HashMap, HashSet, VecDeque};
+use std::ffi::CString;
+
+use anyhow::{Result, bail};
+use serde::Deserialize;
+
+use crate::nix_raw::{derivation_free, derivation_to_json, store_drv_from_store_path};
+use crate::{copy_nix_str, with_store_context};
+
+fn store_dir() -> Result<String> {
+ let mut out = String::new();
+ with_store_context(|c, store, _| unsafe {
+ crate::nix_raw::store_get_storedir(c, store, Some(copy_nix_str), (&raw mut out).cast())
+ })?;
+ Ok(out)
+}
+
+fn to_absolute_store_path(store_dir: &str, path: &str) -> String {
+ if path.starts_with('/') {
+ path.to_owned()
+ } else {
+ format!("{store_dir}/{path}")
+ }
+}
+
+pub struct Derivation(*mut crate::nix_raw::derivation);
+unsafe impl Send for Derivation {}
+
+impl Derivation {
+ pub fn from_path(drv_path: &str) -> Result<Self> {
+ let path_c = CString::new(drv_path)?;
+ let store_path = with_store_context(|c, store, _| unsafe {
+ crate::nix_raw::store_parse_path(c, store, path_c.as_ptr())
+ })?;
+ let drv = with_store_context(|c, store, _| unsafe {
+ store_drv_from_store_path(c, store, store_path)
+ });
+ unsafe { crate::nix_raw::store_path_free(store_path) };
+ let drv = drv?;
+ if drv.is_null() {
+ bail!("failed to read derivation from {drv_path}");
+ }
+ Ok(Self(drv))
+ }
+
+ pub fn to_json_string(&self) -> Result<String> {
+ let mut out = String::new();
+ with_store_context(|c, _, _| unsafe {
+ derivation_to_json(c, self.0, Some(copy_nix_str), (&raw mut out).cast())
+ })?;
+ Ok(out)
+ }
+
+ pub fn parsed(&self) -> Result<DrvParsed> {
+ let s = self.to_json_string()?;
+ Ok(serde_json::from_str(&s)?)
+ }
+}
+
+impl Drop for Derivation {
+ fn drop(&mut self) {
+ unsafe { derivation_free(self.0) };
+ }
+}
+
+#[derive(Debug, Deserialize)]
+pub struct DrvParsed {
+ pub inputs: DrvInputs,
+ pub outputs: HashMap<String, serde_json::Value>,
+}
+
+#[derive(Debug, Deserialize)]
+pub struct DrvInputs {
+ #[serde(default)]
+ pub srcs: Vec<String>,
+ #[serde(default)]
+ pub drvs: HashMap<String, DrvInputEntry>,
+}
+
+#[derive(Debug, Deserialize)]
+pub struct DrvInputEntry {
+ pub outputs: Vec<String>,
+}
+
+#[derive(Debug)]
+pub struct DrvGraph {
+ pub root: String,
+ pub nodes: HashMap<String, DrvNode>,
+}
+
+#[derive(Debug)]
+pub struct DrvNode {
+ pub name: String,
+ pub input_drvs: HashMap<String, Vec<String>>,
+ pub input_srcs: Vec<String>,
+ pub outputs: Vec<String>,
+}
+
+impl DrvGraph {
+ pub fn resolve(drv_path: &str) -> Result<Self> {
+ let sd = store_dir()?;
+ let root = to_absolute_store_path(&sd, drv_path);
+
+ let mut nodes = HashMap::new();
+ let mut queue = VecDeque::new();
+ let mut visited = HashSet::new();
+ queue.push_back(root.clone());
+ visited.insert(root.clone());
+
+ while let Some(path) = queue.pop_front() {
+ let drv = Derivation::from_path(&path)?;
+ let parsed = drv.parsed()?;
+
+ let input_drvs: HashMap<String, Vec<String>> = parsed
+ .inputs
+ .drvs
+ .into_iter()
+ .map(|(k, v)| (to_absolute_store_path(&sd, &k), v.outputs))
+ .collect();
+
+ for dep_path in input_drvs.keys() {
+ if visited.insert(dep_path.clone()) {
+ queue.push_back(dep_path.clone());
+ }
+ }
+
+ nodes.insert(
+ path.clone(),
+ DrvNode {
+ name: extract_drv_name(&path),
+ input_drvs,
+ input_srcs: parsed.inputs.srcs,
+ outputs: parsed.outputs.into_keys().collect(),
+ },
+ );
+ }
+
+ Ok(Self { root, nodes })
+ }
+}
+
+fn extract_drv_name(drv_path: &str) -> String {
+ drv_path
+ .rsplit('/')
+ .next()
+ .and_then(|f| f.strip_suffix(".drv"))
+ .and_then(|f| f.split_once('-').map(|(_, name)| name))
+ .unwrap_or(drv_path)
+ .to_owned()
+}
crates/nix-eval/src/lib.rsdiffbeforeafterboth--- a/crates/nix-eval/src/lib.rs
+++ b/crates/nix-eval/src/lib.rs
@@ -13,7 +13,7 @@
use std::mem::transmute;
pub use anyhow::Result;
-use tracing::{Instrument, info, instrument, warn};
+use tracing::{Span, instrument, warn};
use self::logging::{ErrorInfoBuilder, nix_logging_cxx};
use self::nix_cxx::set_fetcher_setting;
@@ -26,8 +26,9 @@
clear_err, copy_value, err_NIX_ERR_KEY, err_NIX_ERR_NIX_ERROR, err_NIX_ERR_OVERFLOW,
err_NIX_ERR_UNKNOWN, err_code, err_info_msg, err_msg, eval_state_build,
eval_state_builder_load, eval_state_builder_new, eval_state_builder_set_eval_setting,
- expr_eval_from_string, fetchers_settings, fetchers_settings_free, fetchers_settings_new,
- flake_lock, flake_lock_flags, flake_lock_flags_free, flake_lock_flags_new, flake_reference,
+ expr_eval_from_string, fetchers_settings,
+ fetchers_settings_free, fetchers_settings_new, flake_lock, flake_lock_flags,
+ flake_lock_flags_free, flake_lock_flags_new, flake_reference,
flake_reference_and_fragment_from_string, flake_reference_parse_flags,
flake_reference_parse_flags_free, flake_reference_parse_flags_new,
flake_reference_parse_flags_set_base_directory, flake_settings, flake_settings_free,
@@ -43,6 +44,7 @@
};
// Contains macros helpers
+pub mod drv;
pub mod logging;
#[doc(hidden)]
pub mod macros;
@@ -321,7 +323,7 @@
thread_local! {
static THREAD_STATE: RefCell<ThreadState> = RefCell::new(ThreadState::new().expect("thread state init shouldn't fail"));
}
-fn with_default_context<T>(f: impl FnOnce(*mut c_context, *mut c_eval_state) -> T) -> Result<T> {
+pub(crate) fn with_default_context<T>(f: impl FnOnce(*mut c_context, *mut c_eval_state) -> T) -> Result<T> {
let global = &GLOBAL_STATE.state;
let (ctx, state) = THREAD_STATE.with_borrow_mut(|w| (w.ctx.0, global.0));
let mut ctx = NixContext(ctx);
@@ -331,6 +333,20 @@
v
}
+/// Same as with_default_context, but also passes store...
+/// Yep, this code is garbage and needs to be refactored.
+pub(crate) fn with_store_context<T>(
+ f: impl FnOnce(*mut c_context, *mut c_store, *mut c_eval_state) -> T,
+) -> Result<T> {
+ let global = &GLOBAL_STATE;
+ let (ctx, store, state) =
+ THREAD_STATE.with_borrow_mut(|w| (w.ctx.0, global.store.0, global.state.0));
+ let mut ctx = NixContext(ctx);
+ let v = ctx.run_in_context(|c| f(c, store, state));
+ std::mem::forget(ctx);
+ v
+}
+
pub fn set_setting(s: &CStr, v: &CStr) -> Result<()> {
with_default_context(|c, _| unsafe { setting_set(c, s.as_ptr(), v.as_ptr()) }).map(|_| ())
}
@@ -423,7 +439,7 @@
}
}
-unsafe extern "C" fn copy_nix_str(start: *const c_char, n: c_uint, user_data: *mut c_void) {
+pub(crate) unsafe extern "C" fn copy_nix_str(start: *const c_char, n: c_uint, user_data: *mut c_void) {
let s = unsafe { slice::from_raw_parts(start.cast::<u8>(), n as usize) };
let s = std::str::from_utf8(s).expect("c string has invalid utf-8");
unsafe { *user_data.cast::<String>() = s.to_owned() };
@@ -836,6 +852,7 @@
})?;
Ok(out)
}
+ #[instrument(name = "build", skip(self), fields(output))]
pub fn build(&self, output: &str) -> Result<PathBuf> {
if !self.is_derivation() {
bail!("expected derivation to build")
@@ -853,11 +870,19 @@
} else {
self.clone()
};
+
+ let drv_path = v
+ .get_field("drvPath")
+ .context("getting drvPath")?
+ .to_string()?;
+ let graph = drv::DrvGraph::resolve(&drv_path)?;
+ let _guard = logging::register_build_graph(&Span::current(), &graph);
+
// to_string here blocks until the path is built
let s = v.builtin_to_string()?;
let rs = s.to_realised_string()?;
- let drv_path = rs.as_str().to_owned();
- Ok(PathBuf::from(drv_path))
+ let out_path = rs.as_str().to_owned();
+ Ok(PathBuf::from(out_path))
}
pub fn as_json<T: DeserializeOwned>(&self) -> Result<T> {
let to_json = Self::eval("builtins.toJSON")?;
@@ -1102,11 +1127,19 @@
assert_eq!(test_result, "PREFIX_BODY_SUFFIX");
let test_result: String = nix_go_json!(builtins.uppercaseSuffix2("test")("suffix"));
assert_eq!(test_result, "TESTsuffix");
-
- let nix_ctx = NixContext::new();
- let store = GLOBAL_STATE.store.parse_path(s.as_c_str())?;
- // nix_raw::store_get_fs_closure(1);
+ let drv_path = nix_go!(attrs.packages["x86_64-linux"]["fleet-install-secrets"].drvPath)
+ .to_string()?;
+ let graph = drv::DrvGraph::resolve(&drv_path)?;
+ eprintln!(
+ "fleet-install-secrets dependency graph: {} nodes",
+ graph.nodes.len()
+ );
+ for (path, node) in &graph.nodes {
+ if !node.input_drvs.is_empty() {
+ eprintln!(" {} ({} deps)", node.name, node.input_drvs.len());
+ }
+ }
Ok(())
}
crates/nix-eval/src/logging.rsdiffbeforeafterboth1use std::collections::HashMap;2use std::fmt::Arguments;3use std::sync::{LazyLock, Mutex};45use cxx::ExternType;6use tracing::{7 Level, Span, debug, debug_span, error, error_span, info, info_span, trace, trace_span, warn,8 warn_span,9};10#[cfg(feature = "indicatif")]11use tracing_indicatif::span_ext::IndicatifSpanExt as _;12use vte::Parser;1314#[derive(Debug)]15enum ActivityType {16 Unknown = 0,17 CopyPath = 100,18 FileTransfer = 101,19 Realise = 102,20 CopyPaths = 103,21 Builds = 104,22 Build = 105,23 OptimiseStore = 106,24 VerifyPaths = 107,25 Substitute = 108,26 QueryPathInfo = 109,27 PostBuildHook = 110,28 BuildWaiting = 111,29 FetchTree = 112,30}3132fn strip_prefix_suffix<'s, 'p>(a: &'s str, pref: &'p str, suff: &'p str) -> Option<&'s str> {33 a.strip_prefix(pref)?.strip_suffix(suff)34}3536fn parse_path(path: &str) -> &str {37 strip_prefix_suffix(path, "\x1b[35;1m", "\x1b[0m").unwrap_or(path)38}3940fn parse_drv(drv: &str) -> &str {41 let drv = parse_path(drv);42 if let Some(pkg) = drv.strip_prefix("/nix/store/") {43 let mut it = pkg.splitn(2, '-');44 it.next();45 if let Some(pkg) = it.next() {46 return pkg;47 }48 }49 drv50}51fn parse_host(host: &str) -> &str {52 if host.is_empty() || host == "local" {53 return "local";54 }55 // https/ssh is the default56 host.strip_prefix("https://").unwrap_or(host)57}5859impl ActivityType {60 fn name(&self) -> &'static str {61 match self {62 ActivityType::Unknown => "nix",63 ActivityType::CopyPath => "nix::copy-path",64 ActivityType::FileTransfer => "nix::file-transfer",65 ActivityType::Realise => "nix::realise",66 ActivityType::CopyPaths => "nix::copy-paths",67 ActivityType::Builds => "nix::builds",68 ActivityType::Build => "nix::build",69 ActivityType::OptimiseStore => "nix::optimise-store",70 ActivityType::VerifyPaths => "nix::verify-paths",71 ActivityType::Substitute => "nix::substitute",72 ActivityType::QueryPathInfo => "nix::query-path-info",73 ActivityType::PostBuildHook => "nix::post-build-hook",74 ActivityType::BuildWaiting => "nix::build-waiting",75 ActivityType::FetchTree => "nix::fetch-tree",76 }77 }78 fn format(79 &self,80 values: &[FieldValue],81 s: &str,82 into: impl FnOnce(Arguments<'_>) -> Span,83 ) -> Span {84 use FieldValue::*;85 match (self, values) {86 (ActivityType::QueryPathInfo, [Str(drv), Str(host)]) => {87 let drv = parse_drv(drv);88 let host = parse_host(host);89 debug_span!(target: "nix::query-path-info", "querying", drv, host)90 }91 (ActivityType::Substitute, [Str(drv), Str(host)]) => {92 let drv = parse_drv(drv);93 let host = parse_host(host);94 debug_span!(target: "nix::substitute", "substituting", drv, host)95 }96 (ActivityType::CopyPath, [Str(drv), Str(from), Str(to)]) => {97 let drv = parse_drv(drv);98 let from = parse_host(from);99 let to = parse_host(to);100 debug_span!(target: "nix::copy-path", "copying", drv, from, to)101 }102 (ActivityType::Build, [Str(drv), Str(host), Int(_), Int(_)]) => {103 let drv = parse_drv(drv);104 let host = parse_host(host);105 info_span!(target: "nix::build", "building", drv, host)106 }107 (ActivityType::FileTransfer, [Str(file)]) => {108 info_span!(target: "nix::file-transfer", "downloading", file)109 }110 (ActivityType::Realise, []) => {111 debug_span!(target: "nix::realise", "realising")112 }113 (ActivityType::CopyPaths, []) => {114 debug_span!(target: "nix::copy-paths", "copying paths")115 }116 (ActivityType::Unknown, [])117 if s.starts_with("copying \"") && s.ends_with("\" to the store") =>118 {119 let tree = s120 .trim_start_matches("copying \"")121 .trim_end_matches("\" to the store");122 debug_span!(target: "nix::trees", "copying", tree)123 }124 (ActivityType::Unknown, [])125 if s.starts_with("copying '") && s.ends_with("' to the store") =>126 {127 let tree = s128 .trim_start_matches("copying '")129 .trim_end_matches("' to the store");130 debug_span!(target: "nix::trees", "copying", tree)131 }132 (ActivityType::Unknown, []) if s.starts_with("hashing '") && s.ends_with("'") => {133 let tree = s.trim_start_matches("hashing '").trim_end_matches("'");134 debug_span!(target: "nix::trees", "hashing", tree)135 }136 (ActivityType::Unknown, []) if s.starts_with("connecting to '") && s.ends_with("'") => {137 let host = s138 .trim_start_matches("connecting to '")139 .trim_end_matches("'");140 debug_span!(target: "nix::remote", "connecting", host)141 }142 (ActivityType::Unknown, [])143 if s.starts_with("copying outputs from '") && s.ends_with("'") =>144 {145 let host = s146 .trim_start_matches("copying outputs from '")147 .trim_end_matches("'");148 debug_span!(target: "nix::remote", "copying outputs", host)149 }150 (ActivityType::Unknown, [])151 if s.starts_with("copying dependencies to '") && s.ends_with("'") =>152 {153 let host = s154 .trim_start_matches("copying dependencies to '")155 .trim_end_matches("'");156 debug_span!(target: "nix::remote", "copying dependencies", host)157 }158 (ActivityType::Unknown, [])159 if s.starts_with("waiting for the upload lock to '") && s.ends_with("'") =>160 {161 let host = s162 .trim_start_matches("waiting for the upload lock to '")163 .trim_end_matches("'");164 debug_span!(target: "nix::remote", "waiting for upload lock", host)165 }166 (ActivityType::BuildWaiting, [])167 if s.starts_with("waiting for a machine to build '") && s.ends_with("'") =>168 {169 let drv = parse_drv(170 s.trim_start_matches("waiting for a machine to build '")171 .trim_end_matches("'"),172 );173 debug_span!(target: "nix::build-waiting", "waiting for available builder", drv)174 }175 (ActivityType::Unknown, []) if s == "querying info about missing paths" => {176 debug_span!(target: "nix::remote", "querying")177 }178 _ => into(format_args!("{}({values:?})", self.name())),179 }180 }181 fn from_int(v: u32) -> Self {182 match v {183 0 => Self::Unknown,184 100 => Self::CopyPath,185 101 => Self::FileTransfer,186 102 => Self::Realise,187 103 => Self::CopyPaths,188 104 => Self::Builds,189 105 => Self::Build,190 106 => Self::OptimiseStore,191 107 => Self::VerifyPaths,192 108 => Self::Substitute,193 109 => Self::QueryPathInfo,194 110 => Self::PostBuildHook,195 111 => Self::BuildWaiting,196 112 => Self::FetchTree,197 _ => {198 warn!("unknown nix action: {v}");199 Self::Unknown200 }201 }202 }203}204205#[derive(Debug)]206enum ResultType {207 FileLinked = 100,208 BuildLogLine = 101,209 UntrustedPath = 102,210 CorruptedPath = 103,211 SetPhase = 104,212 Progress = 105,213 SetExpected = 106,214 PostBuildLogLine = 107,215 FetchStatus = 108,216217 Unknown = 999,218}219impl ResultType {220 fn from_int(v: u32) -> Self {221 match v {222 100 => Self::FileLinked,223 101 => Self::BuildLogLine,224 102 => Self::UntrustedPath,225 103 => Self::CorruptedPath,226 104 => Self::SetPhase,227 105 => Self::Progress,228 106 => Self::SetExpected,229 107 => Self::PostBuildLogLine,230 108 => Self::FetchStatus,231232 _ => {233 warn!("unknown nix result: {v}");234 Self::Unknown235 }236 }237 }238}239#[derive(Clone, Copy)]240enum Verbosity {241 Error,242 Warn,243 Notice,244 Info,245 Talkative,246 Chatty,247 Debug,248 Vomit,249}250impl From<Verbosity> for tracing::Level {251 fn from(val: Verbosity) -> Self {252 match val {253 Verbosity::Error => Level::ERROR,254 Verbosity::Warn => Level::WARN,255 Verbosity::Notice => Level::WARN,256 Verbosity::Info => Level::INFO,257 Verbosity::Talkative => Level::DEBUG,258 Verbosity::Chatty => Level::DEBUG,259 Verbosity::Debug => Level::DEBUG,260 Verbosity::Vomit => Level::TRACE,261 }262 }263}264impl Verbosity {265 fn from_int(u: u32) -> Self {266 [267 Self::Error,268 Self::Warn,269 Self::Notice,270 Self::Info,271 Self::Talkative,272 Self::Chatty,273 Self::Debug,274 Self::Vomit,275 ]276 .get(u as usize)277 .cloned()278 .unwrap_or_else(|| {279 warn!("unknown log level: {u}");280 Verbosity::Vomit281 })282 }283}284285static NIX_SPAN_MAPPING: LazyLock<Mutex<HashMap<u64, Span>>> =286 LazyLock::new(|| Mutex::new(HashMap::new()));287288#[derive(Debug)]289enum FieldValue {290 Int(i32),291 Str(String),292}293294struct StartActivityBuilder {295 activity_id: u64,296 verbosity: Verbosity,297 typ: ActivityType,298 fields: Vec<FieldValue>,299}300impl StartActivityBuilder {301 fn add_int_field(&mut self, i: i32) {302 self.fields.push(FieldValue::Int(i));303 }304 fn add_string_field(&mut self, v: &[u8]) {305 let v = String::from_utf8_lossy(v);306 self.fields.push(FieldValue::Str(v.to_string()));307 }308 fn emit(&mut self, parent: u64, s: &str) {309 let mut mapping = NIX_SPAN_MAPPING.lock().expect("not poisoned");310311 let parent = mapping.get(&parent);312313 // let meta = spans.alloc_metadata(314 // self.typ.name(),315 // self.verbosity.into(),316 // MetadataKind::Span,317 // "nix activity start",318 // None,319 // None,320 // None,321 // self.typ.fields(),322 // );323 //324 // let mut fields = meta.fields().iter();325 // let span = if let Some(parent) = parent {326 // let s = Span::new(327 // meta,328 // &match meta.fields().len() {329 // 1 => meta.fields().value_set(330 // &<[_; 1]>::try_from([(331 // &fields.next().expect("has field"),332 // Some(&format_args!("Test") as &dyn tracing::Value),333 // )])334 // .expect("valid size"),335 // ),336 // _ => unreachable!(),337 // },338 // );339 // s.follows_from(parent);340 // s341 // } else {342 // Span::new_root(343 // meta,344 // &match meta.fields().len() {345 // 1 => meta.fields().value_set(346 // &<[_; 1]>::try_from([(347 // &fields.next().expect("has field"),348 // Some(&format_args!("Test") as &dyn tracing::Value),349 // )])350 // .expect("valid size"),351 // ),352 // _ => unreachable!(),353 // },354 // )355 // };356 //357 // let id = span.id().expect("id created");358359 let span = {360 let _in_parent = parent.map(|p| p.enter());361 let level: Level = self.verbosity.into();362 if level == Level::ERROR {363 self.typ364 .format(&self.fields, s, |v| error_span!("action", v))365 } else if level == Level::WARN {366 self.typ367 .format(&self.fields, s, |v| warn_span!("action", v))368 } else if level == Level::INFO {369 self.typ370 .format(&self.fields, s, |v| info_span!("action", v))371 } else if level == Level::DEBUG {372 self.typ373 .format(&self.fields, s, |v| debug_span!("action", v))374 } else {375 self.typ376 .format(&self.fields, s, |v| trace_span!("action", v))377 }378 };379 if !s.trim().is_empty() {380 let s = ansi_filter(s);381 #[cfg(feature = "indicatif")]382 {383 span.pb_set_message(s);384 }385 let _e = span.enter();386 let level: Level = self.verbosity.into();387 if level == Level::ERROR {388 error!(target: "nix", "{}", s)389 } else if level == Level::WARN {390 warn!(target: "nix", "{}", s)391 } else if level == Level::INFO {392 info!(target: "nix", "{}", s)393 } else if level == Level::DEBUG {394 debug!(target: "nix", "{}", s)395 } else {396 trace!(target: "nix", "{}", s)397 }398 } else {399 #[cfg(feature = "indicatif")]400 {401 span.pb_start();402 }403 }404 mapping.insert(self.activity_id, span);405 }406 fn emit_result(&mut self, ty: u32) {407 let mapping = NIX_SPAN_MAPPING.lock().expect("not poisoned");408409 let Some(parent) = mapping.get(&self.activity_id) else {410 panic!("unexpected result for dead parent");411 };412413 let _in_parent = parent.enter();414 let res = ResultType::from_int(ty);415416 use FieldValue::*;417 match (&res, self.fields.as_slice()) {418 // ResultType::FileLinked => todo!(),419 (ResultType::BuildLogLine, [Str(s)]) => {420 let s = ansi_filter(s);421 info!("{s}");422 }423 // ResultType::UntrustedPath => todo!(),424 // ResultType::CorruptedPath => todo!(),425 // ResultType::SetPhase => todo!(),426 (ResultType::SetExpected, [Int(act_ty), Int(_expected)]) => {427 let _act_ty = ActivityType::from_int(*act_ty as u32);428 }429 (ResultType::SetPhase, [Str(phase)]) => {430 // parent.pb_set_message(phase);431 debug!(target: "nix::phase", phase)432 }433 (ResultType::Progress, [Int(_done), Int(_expected), Int(_), Int(_)]) => {434 #[cfg(feature = "indicatif")]435 {436 parent.pb_set_length(*_expected as u64);437 parent.pb_set_position(*_done as u64);438 }439 }440 _ => warn!("unknown progress report: {:?}({:?})", &res, &self.fields),441 }442 }443}444fn new_start_activity(activity_id: u64, lvl: u32, typ: u32) -> Box<StartActivityBuilder> {445 Box::new(StartActivityBuilder {446 activity_id,447 verbosity: Verbosity::from_int(lvl),448 typ: ActivityType::from_int(typ),449 fields: vec![],450 })451}452453fn emit_warn(v: &str) {454 warn!(target: "nix::eval", "{v}")455}456fn emit_stop(v: u64) {457 let mut mapping = NIX_SPAN_MAPPING.lock().expect("not poisoned");458 mapping.remove(&v);459}460fn emit_log(lvl: u32, v: &[u8]) {461 let verbosity = Verbosity::from_int(lvl);462 let level: Level = verbosity.into();463 let v = String::from_utf8_lossy(v);464 if level == Level::ERROR {465 error!(target: "nix", "{v}")466 } else if level == Level::WARN {467 warn!(target: "nix", "{v}")468 } else if level == Level::INFO {469 info!(target: "nix", "{v}")470 } else if level == Level::DEBUG {471 debug!(target: "nix", "{v}")472 } else {473 trace!(target: "nix", "{v}")474 }475}476477struct AnsiFiltered {478 output: String,479}480impl vte::Perform for AnsiFiltered {481 fn print(&mut self, c: char) {482 self.output.push(c);483 }484485 fn execute(&mut self, byte: u8) {486 // We don't want \r, bells, etc487 if byte == b'\n' {488 self.output.push('\n');489 } else if byte == b'\t' {490 // TODO: align output to the correct multiplier?491 self.output.push('\t');492 }493 }494495 fn osc_dispatch(&mut self, _params: &[&[u8]], _bell_terminated: bool) {}496 fn esc_dispatch(&mut self, _intermediates: &[u8], _ignore: bool, _byte: u8) {}497498 fn csi_dispatch(499 &mut self,500 params: &vte::Params,501 _intermediates: &[u8],502 _ignore: bool,503 action: char,504 ) {505 use std::fmt::Write;506 if action != 'm' {507 // Only plain colors are enabled, everything other might corrupt the output508 return;509 }510 self.output.push_str("\x1b[");511 for (i, par) in params.iter().enumerate() {512 if i != 0 {513 let _ = write!(self.output, ";");514 }515 for (i, sub) in par.iter().enumerate() {516 if i != 0 {517 let _ = write!(self.output, ":");518 }519 let _ = write!(self.output, "{sub}");520 }521 }522 self.output.push(action);523 }524}525fn ansi_filter(i: &str) -> String {526 let mut out = AnsiFiltered {527 output: String::new(),528 };529 let mut parser = Parser::new();530531 // For some reason it gets stuck with longer inputs532 for chunk in i.as_bytes().chunks(50) {533 parser.advance(&mut out, chunk);534 }535536 out.output537}538539#[derive(Debug)]540pub struct StackFrame {541 pub msg: String,542 pub pos: String,543}544545#[derive(Debug)]546pub struct ErrorInfoBuilder {547 level: Level,548 msg: String,549 pub stack_frames: Vec<StackFrame>,550}551fn new_error_info(lvl: u32, v: &[u8]) -> Box<ErrorInfoBuilder> {552 let verbosity = Verbosity::from_int(lvl);553 let level: Level = verbosity.into();554 let v = String::from_utf8_lossy(v);555 Box::new(ErrorInfoBuilder {556 level,557 msg: v.to_string(),558 stack_frames: Vec::new(),559 })560}561impl ErrorInfoBuilder {562 fn push_stack_frame(&mut self, v: &[u8], pos: &[u8]) {563 let v = String::from_utf8_lossy(v);564 let pos = String::from_utf8_lossy(pos);565 self.stack_frames.push(StackFrame {566 msg: v.to_string(),567 pos: pos.to_string(),568 });569 }570 fn emit_error_info(&mut self) {571 error!("{}", self.msg);572 for frame in &self.stack_frames {573 error!(" {} at {}", frame.msg, frame.pos)574 }575 }576}577578#[cxx::bridge]579pub mod nix_logging_cxx {580 extern "Rust" {581 type StartActivityBuilder;582 fn new_start_activity(activity_id: u64, lvl: u32, typ: u32) -> Box<StartActivityBuilder>;583 fn add_int_field(&mut self, i: i32);584 fn add_string_field(&mut self, v: &[u8]);585 fn emit(&mut self, parent: u64, s: &str);586 fn emit_result(&mut self, ty: u32);587 }588 extern "Rust" {589 type ErrorInfoBuilder;590 fn new_error_info(lvl: u32, v: &[u8]) -> Box<ErrorInfoBuilder>;591 fn push_stack_frame(&mut self, v: &[u8], pos: &[u8]);592 fn emit_error_info(&mut self);593 }594 extern "Rust" {595 fn emit_warn(v: &str);596 fn emit_stop(id: u64);597 fn emit_log(lvl: u32, v: &[u8]);598 }599 unsafe extern "C++" {600 include!("nix-eval/src/logging.hh");601602 type nix_c_context = crate::nix_raw::c_context;603604 fn apply_tracing_logger();605 unsafe fn extract_error_info(ctx: *const nix_c_context) -> Box<ErrorInfoBuilder>;606 }607}608609unsafe impl ExternType for crate::nix_raw::c_context {610 type Id = cxx::type_id!("nix_c_context");611612 type Kind = cxx::kind::Opaque;613}1use std::collections::{HashMap, VecDeque};2use std::fmt::Arguments;3use std::sync::{LazyLock, Mutex};45use cxx::ExternType;6use tracing::{7 Level, Span, debug, debug_span, error, error_span, info, info_span, trace, trace_span, warn,8 warn_span,9};10#[cfg(feature = "indicatif")]11use tracing_indicatif::span_ext::IndicatifSpanExt as _;12use vte::Parser;1314#[derive(Debug)]15enum ActivityType {16 Unknown = 0,17 CopyPath = 100,18 FileTransfer = 101,19 Realise = 102,20 CopyPaths = 103,21 Builds = 104,22 Build = 105,23 OptimiseStore = 106,24 VerifyPaths = 107,25 Substitute = 108,26 QueryPathInfo = 109,27 PostBuildHook = 110,28 BuildWaiting = 111,29 FetchTree = 112,30}3132fn strip_prefix_suffix<'s, 'p>(a: &'s str, pref: &'p str, suff: &'p str) -> Option<&'s str> {33 a.strip_prefix(pref)?.strip_suffix(suff)34}3536fn parse_path(path: &str) -> &str {37 strip_prefix_suffix(path, "\x1b[35;1m", "\x1b[0m").unwrap_or(path)38}3940fn parse_drv(drv: &str) -> &str {41 let drv = parse_path(drv);42 if let Some(pkg) = drv.strip_prefix("/nix/store/") {43 let mut it = pkg.splitn(2, '-');44 it.next();45 if let Some(pkg) = it.next() {46 return pkg;47 }48 }49 drv50}51fn parse_host(host: &str) -> &str {52 if host.is_empty() || host == "local" {53 return "local";54 }55 // https/ssh is the default56 host.strip_prefix("https://").unwrap_or(host)57}5859impl ActivityType {60 fn name(&self) -> &'static str {61 match self {62 ActivityType::Unknown => "nix",63 ActivityType::CopyPath => "nix::copy-path",64 ActivityType::FileTransfer => "nix::file-transfer",65 ActivityType::Realise => "nix::realise",66 ActivityType::CopyPaths => "nix::copy-paths",67 ActivityType::Builds => "nix::builds",68 ActivityType::Build => "nix::build",69 ActivityType::OptimiseStore => "nix::optimise-store",70 ActivityType::VerifyPaths => "nix::verify-paths",71 ActivityType::Substitute => "nix::substitute",72 ActivityType::QueryPathInfo => "nix::query-path-info",73 ActivityType::PostBuildHook => "nix::post-build-hook",74 ActivityType::BuildWaiting => "nix::build-waiting",75 ActivityType::FetchTree => "nix::fetch-tree",76 }77 }78 fn format(79 &self,80 values: &[FieldValue],81 s: &str,82 into: impl FnOnce(Arguments<'_>) -> Span,83 ) -> Span {84 use FieldValue::*;85 match (self, values) {86 (ActivityType::QueryPathInfo, [Str(drv), Str(host)]) => {87 let drv = parse_drv(drv);88 let host = parse_host(host);89 debug_span!(target: "nix::query-path-info", "querying", drv, host)90 }91 (ActivityType::Substitute, [Str(drv), Str(host)]) => {92 let drv = parse_drv(drv);93 let host = parse_host(host);94 debug_span!(target: "nix::substitute", "substituting", drv, host)95 }96 (ActivityType::CopyPath, [Str(drv), Str(from), Str(to)]) => {97 let drv = parse_drv(drv);98 let from = parse_host(from);99 let to = parse_host(to);100 debug_span!(target: "nix::copy-path", "copying", drv, from, to)101 }102 (ActivityType::Build, [Str(drv), Str(host), Int(_), Int(_)]) => {103 let drv = parse_drv(drv);104 let host = parse_host(host);105 info_span!(target: "nix::build", "building", drv, host)106 }107 (ActivityType::FileTransfer, [Str(file)]) => {108 info_span!(target: "nix::file-transfer", "downloading", file)109 }110 (ActivityType::Realise, []) => {111 debug_span!(target: "nix::realise", "realising")112 }113 (ActivityType::CopyPaths, []) => {114 debug_span!(target: "nix::copy-paths", "copying paths")115 }116 (ActivityType::Unknown, [])117 if s.starts_with("copying \"") && s.ends_with("\" to the store") =>118 {119 let tree = s120 .trim_start_matches("copying \"")121 .trim_end_matches("\" to the store");122 debug_span!(target: "nix::trees", "copying", tree)123 }124 (ActivityType::Unknown, [])125 if s.starts_with("copying '") && s.ends_with("' to the store") =>126 {127 let tree = s128 .trim_start_matches("copying '")129 .trim_end_matches("' to the store");130 debug_span!(target: "nix::trees", "copying", tree)131 }132 (ActivityType::Unknown, []) if s.starts_with("hashing '") && s.ends_with("'") => {133 let tree = s.trim_start_matches("hashing '").trim_end_matches("'");134 debug_span!(target: "nix::trees", "hashing", tree)135 }136 (ActivityType::Unknown, []) if s.starts_with("connecting to '") && s.ends_with("'") => {137 let host = s138 .trim_start_matches("connecting to '")139 .trim_end_matches("'");140 debug_span!(target: "nix::remote", "connecting", host)141 }142 (ActivityType::Unknown, [])143 if s.starts_with("copying outputs from '") && s.ends_with("'") =>144 {145 let host = s146 .trim_start_matches("copying outputs from '")147 .trim_end_matches("'");148 debug_span!(target: "nix::remote", "copying outputs", host)149 }150 (ActivityType::Unknown, [])151 if s.starts_with("copying dependencies to '") && s.ends_with("'") =>152 {153 let host = s154 .trim_start_matches("copying dependencies to '")155 .trim_end_matches("'");156 debug_span!(target: "nix::remote", "copying dependencies", host)157 }158 (ActivityType::Unknown, [])159 if s.starts_with("waiting for the upload lock to '") && s.ends_with("'") =>160 {161 let host = s162 .trim_start_matches("waiting for the upload lock to '")163 .trim_end_matches("'");164 debug_span!(target: "nix::remote", "waiting for upload lock", host)165 }166 (ActivityType::BuildWaiting, [])167 if s.starts_with("waiting for a machine to build '") && s.ends_with("'") =>168 {169 let drv = parse_drv(170 s.trim_start_matches("waiting for a machine to build '")171 .trim_end_matches("'"),172 );173 debug_span!(target: "nix::build-waiting", "waiting for available builder", drv)174 }175 (ActivityType::Unknown, []) if s == "querying info about missing paths" => {176 debug_span!(target: "nix::remote", "querying")177 }178 _ => into(format_args!("{}({values:?})", self.name())),179 }180 }181 fn from_int(v: u32) -> Self {182 match v {183 0 => Self::Unknown,184 100 => Self::CopyPath,185 101 => Self::FileTransfer,186 102 => Self::Realise,187 103 => Self::CopyPaths,188 104 => Self::Builds,189 105 => Self::Build,190 106 => Self::OptimiseStore,191 107 => Self::VerifyPaths,192 108 => Self::Substitute,193 109 => Self::QueryPathInfo,194 110 => Self::PostBuildHook,195 111 => Self::BuildWaiting,196 112 => Self::FetchTree,197 _ => {198 warn!("unknown nix action: {v}");199 Self::Unknown200 }201 }202 }203}204205#[derive(Debug)]206enum ResultType {207 FileLinked = 100,208 BuildLogLine = 101,209 UntrustedPath = 102,210 CorruptedPath = 103,211 SetPhase = 104,212 Progress = 105,213 SetExpected = 106,214 PostBuildLogLine = 107,215 FetchStatus = 108,216217 Unknown = 999,218}219impl ResultType {220 fn from_int(v: u32) -> Self {221 match v {222 100 => Self::FileLinked,223 101 => Self::BuildLogLine,224 102 => Self::UntrustedPath,225 103 => Self::CorruptedPath,226 104 => Self::SetPhase,227 105 => Self::Progress,228 106 => Self::SetExpected,229 107 => Self::PostBuildLogLine,230 108 => Self::FetchStatus,231232 _ => {233 warn!("unknown nix result: {v}");234 Self::Unknown235 }236 }237 }238}239#[derive(Clone, Copy)]240enum Verbosity {241 Error,242 Warn,243 Notice,244 Info,245 Talkative,246 Chatty,247 Debug,248 Vomit,249}250impl From<Verbosity> for tracing::Level {251 fn from(val: Verbosity) -> Self {252 match val {253 Verbosity::Error => Level::ERROR,254 Verbosity::Warn => Level::WARN,255 Verbosity::Notice => Level::WARN,256 Verbosity::Info => Level::INFO,257 Verbosity::Talkative => Level::DEBUG,258 Verbosity::Chatty => Level::DEBUG,259 Verbosity::Debug => Level::DEBUG,260 Verbosity::Vomit => Level::TRACE,261 }262 }263}264impl Verbosity {265 fn from_int(u: u32) -> Self {266 [267 Self::Error,268 Self::Warn,269 Self::Notice,270 Self::Info,271 Self::Talkative,272 Self::Chatty,273 Self::Debug,274 Self::Vomit,275 ]276 .get(u as usize)277 .cloned()278 .unwrap_or_else(|| {279 warn!("unknown log level: {u}");280 Verbosity::Vomit281 })282 }283}284285static NIX_SPAN_MAPPING: LazyLock<Mutex<HashMap<u64, Span>>> =286 LazyLock::new(|| Mutex::new(HashMap::new()));287288struct DrvGraphEntry {289 name: String,290 parent: Option<String>,291 span: Option<Span>,292 refcount: usize,293}294295static DRV_GRAPH: LazyLock<Mutex<HashMap<String, DrvGraphEntry>>> =296 LazyLock::new(|| Mutex::new(HashMap::new()));297298static ACTIVITY_TO_DRV: LazyLock<Mutex<HashMap<u64, String>>> =299 LazyLock::new(|| Mutex::new(HashMap::new()));300301pub struct BuildGraphGuard {302 paths: Vec<String>,303}304305impl Drop for BuildGraphGuard {306 fn drop(&mut self) {307 let mut drv_graph = DRV_GRAPH.lock().expect("not poisoned");308 for path in &self.paths {309 if let Some(entry) = drv_graph.get_mut(path) {310 entry.refcount -= 1;311 if entry.refcount == 0 {312 drv_graph.remove(path);313 }314 }315 }316 }317}318319pub fn register_build_graph(parent: &Span, graph: &crate::drv::DrvGraph) -> BuildGraphGuard {320 let mut drv_graph = DRV_GRAPH.lock().expect("not poisoned");321 let mut paths = Vec::new();322323 drv_graph324 .entry(graph.root.clone())325 .and_modify(|e| e.refcount += 1)326 .or_insert_with(|| DrvGraphEntry {327 name: graph.nodes[&graph.root].name.clone(),328 parent: None,329 span: Some(parent.clone()),330 refcount: 1,331 });332 paths.push(graph.root.clone());333334 let mut queue = VecDeque::new();335 queue.push_back(graph.root.clone());336337 let mut visited = std::collections::HashSet::new();338 visited.insert(graph.root.clone());339340 while let Some(path) = queue.pop_front() {341 let Some(node) = graph.nodes.get(&path) else {342 continue;343 };344 for dep_path in node.input_drvs.keys() {345 if !visited.insert(dep_path.clone()) {346 continue;347 }348 let Some(dep_node) = graph.nodes.get(dep_path) else {349 continue;350 };351 if let Some(entry) = drv_graph.get_mut(dep_path) {352 entry.refcount += 1;353 } else {354 drv_graph.insert(dep_path.clone(), DrvGraphEntry {355 name: dep_node.name.clone(),356 parent: Some(path.clone()),357 span: None,358 refcount: 1,359 });360 }361 paths.push(dep_path.clone());362 queue.push_back(dep_path.clone());363 }364 }365366 BuildGraphGuard { paths }367}368369fn ensure_drv_span(drv_path: &str) -> Option<Span> {370 let mut drv_graph = DRV_GRAPH.lock().expect("not poisoned");371372 if let Some(span) = drv_graph.get(drv_path).and_then(|e| e.span.clone()) {373 return Some(span);374 }375376 let mut chain = vec![];377 let mut current = drv_path.to_owned();378 loop {379 let Some(entry) = drv_graph.get(¤t) else {380 break;381 };382 if entry.span.is_some() {383 chain.push(current);384 break;385 }386 chain.push(current.clone());387 match &entry.parent {388 Some(p) => current = p.clone(),389 None => break,390 }391 }392393 if chain.is_empty() {394 return None;395 }396397 for i in (0..chain.len()).rev() {398 let path = &chain[i];399 if drv_graph.get(path).unwrap().span.is_some() {400 continue;401 }402 let parent_span = chain403 .get(i + 1)404 .and_then(|p| drv_graph.get(p))405 .and_then(|e| e.span.clone());406 let name = drv_graph.get(path).unwrap().name.clone();407 let span = {408 let _enter = parent_span.as_ref().map(|s| s.enter());409 info_span!(target: "nix::build", "building", drv = %name)410 };411 drv_graph.get_mut(path).unwrap().span = Some(span);412 }413414 drv_graph.get(drv_path).and_then(|e| e.span.clone())415}416417#[derive(Debug)]418enum FieldValue {419 Int(i32),420 Str(String),421}422423struct StartActivityBuilder {424 activity_id: u64,425 verbosity: Verbosity,426 typ: ActivityType,427 fields: Vec<FieldValue>,428}429impl StartActivityBuilder {430 fn add_int_field(&mut self, i: i32) {431 self.fields.push(FieldValue::Int(i));432 }433 fn add_string_field(&mut self, v: &[u8]) {434 let v = String::from_utf8_lossy(v);435 self.fields.push(FieldValue::Str(v.to_string()));436 }437 fn emit(&mut self, parent: u64, s: &str) {438 let graph_span = if matches!(self.typ, ActivityType::Build) {439 self.fields.first().and_then(|f| match f {440 FieldValue::Str(drv_path) => {441 let clean = parse_path(drv_path);442 let span = ensure_drv_span(clean);443 if span.is_some() {444 ACTIVITY_TO_DRV445 .lock()446 .expect("not poisoned")447 .insert(self.activity_id, clean.to_owned());448 }449 span450 }451 _ => None,452 })453 } else {454 None455 };456457 let mut mapping = NIX_SPAN_MAPPING.lock().expect("not poisoned");458459 let span = if let Some(span) = graph_span {460 #[cfg(feature = "indicatif")]461 span.pb_start();462 span463 } else {464 let parent = mapping.get(&parent);465 let _in_parent = parent.map(|p| p.enter());466 let level: Level = self.verbosity.into();467 if level == Level::ERROR {468 self.typ469 .format(&self.fields, s, |v| error_span!("action", v))470 } else if level == Level::WARN {471 self.typ472 .format(&self.fields, s, |v| warn_span!("action", v))473 } else if level == Level::INFO {474 self.typ475 .format(&self.fields, s, |v| info_span!("action", v))476 } else if level == Level::DEBUG {477 self.typ478 .format(&self.fields, s, |v| debug_span!("action", v))479 } else {480 self.typ481 .format(&self.fields, s, |v| trace_span!("action", v))482 }483 };484 if !s.trim().is_empty() {485 let s = ansi_filter(s);486 #[cfg(feature = "indicatif")]487 {488 span.pb_set_message(&s);489 }490 let _e = span.enter();491 let level: Level = self.verbosity.into();492 if level == Level::ERROR {493 error!(target: "nix", "{}", s)494 } else if level == Level::WARN {495 warn!(target: "nix", "{}", s)496 } else if level == Level::INFO {497 info!(target: "nix", "{}", s)498 } else if level == Level::DEBUG {499 debug!(target: "nix", "{}", s)500 } else {501 trace!(target: "nix", "{}", s)502 }503 } else {504 #[cfg(feature = "indicatif")]505 {506 span.pb_start();507 }508 }509 mapping.insert(self.activity_id, span);510 }511 fn emit_result(&mut self, ty: u32) {512 let mapping = NIX_SPAN_MAPPING.lock().expect("not poisoned");513514 let Some(parent) = mapping.get(&self.activity_id) else {515 panic!("unexpected result for dead parent");516 };517518 let _in_parent = parent.enter();519 let res = ResultType::from_int(ty);520521 use FieldValue::*;522 match (&res, self.fields.as_slice()) {523 // ResultType::FileLinked => todo!(),524 (ResultType::BuildLogLine, [Str(s)]) => {525 let s = ansi_filter(s);526 info!("{s}");527 }528 // ResultType::UntrustedPath => todo!(),529 // ResultType::CorruptedPath => todo!(),530 // ResultType::SetPhase => todo!(),531 (ResultType::SetExpected, [Int(act_ty), Int(_expected)]) => {532 let _act_ty = ActivityType::from_int(*act_ty as u32);533 }534 (ResultType::SetPhase, [Str(phase)]) => {535 // parent.pb_set_message(phase);536 debug!(target: "nix::phase", phase)537 }538 (ResultType::Progress, [Int(_done), Int(_expected), Int(_), Int(_)]) => {539 #[cfg(feature = "indicatif")]540 {541 parent.pb_set_length(*_expected as u64);542 parent.pb_set_position(*_done as u64);543 }544 }545 _ => warn!("unknown progress report: {:?}({:?})", &res, &self.fields),546 }547 }548}549fn new_start_activity(activity_id: u64, lvl: u32, typ: u32) -> Box<StartActivityBuilder> {550 Box::new(StartActivityBuilder {551 activity_id,552 verbosity: Verbosity::from_int(lvl),553 typ: ActivityType::from_int(typ),554 fields: vec![],555 })556}557558fn emit_warn(v: &str) {559 warn!(target: "nix::eval", "{v}")560}561fn emit_stop(v: u64) {562 {563 let mut mapping = NIX_SPAN_MAPPING.lock().expect("not poisoned");564 mapping.remove(&v);565 }566 if let Some(drv_path) = ACTIVITY_TO_DRV.lock().expect("not poisoned").remove(&v) {567 if let Some(entry) = DRV_GRAPH.lock().expect("not poisoned").get_mut(&drv_path) {568 entry.span = None;569 }570 }571}572fn emit_log(lvl: u32, v: &[u8]) {573 let verbosity = Verbosity::from_int(lvl);574 let level: Level = verbosity.into();575 let v = String::from_utf8_lossy(v);576 if level == Level::ERROR {577 error!(target: "nix", "{v}")578 } else if level == Level::WARN {579 warn!(target: "nix", "{v}")580 } else if level == Level::INFO {581 info!(target: "nix", "{v}")582 } else if level == Level::DEBUG {583 debug!(target: "nix", "{v}")584 } else {585 trace!(target: "nix", "{v}")586 }587}588589struct AnsiFiltered {590 output: String,591}592impl vte::Perform for AnsiFiltered {593 fn print(&mut self, c: char) {594 self.output.push(c);595 }596597 fn execute(&mut self, byte: u8) {598 // We don't want \r, bells, etc599 if byte == b'\n' {600 self.output.push('\n');601 } else if byte == b'\t' {602 // TODO: align output to the correct multiplier?603 self.output.push('\t');604 }605 }606607 fn osc_dispatch(&mut self, _params: &[&[u8]], _bell_terminated: bool) {}608 fn esc_dispatch(&mut self, _intermediates: &[u8], _ignore: bool, _byte: u8) {}609610 fn csi_dispatch(611 &mut self,612 params: &vte::Params,613 _intermediates: &[u8],614 _ignore: bool,615 action: char,616 ) {617 use std::fmt::Write;618 if action != 'm' {619 // Only plain colors are enabled, everything other might corrupt the output620 return;621 }622 self.output.push_str("\x1b[");623 for (i, par) in params.iter().enumerate() {624 if i != 0 {625 let _ = write!(self.output, ";");626 }627 for (i, sub) in par.iter().enumerate() {628 if i != 0 {629 let _ = write!(self.output, ":");630 }631 let _ = write!(self.output, "{sub}");632 }633 }634 self.output.push(action);635 }636}637fn ansi_filter(i: &str) -> String {638 let mut out = AnsiFiltered {639 output: String::new(),640 };641 let mut parser = Parser::new();642643 // For some reason it gets stuck with longer inputs644 for chunk in i.as_bytes().chunks(50) {645 parser.advance(&mut out, chunk);646 }647648 out.output649}650651#[derive(Debug)]652pub struct StackFrame {653 pub msg: String,654 pub pos: String,655}656657#[derive(Debug)]658pub struct ErrorInfoBuilder {659 level: Level,660 msg: String,661 pub stack_frames: Vec<StackFrame>,662}663fn new_error_info(lvl: u32, v: &[u8]) -> Box<ErrorInfoBuilder> {664 let verbosity = Verbosity::from_int(lvl);665 let level: Level = verbosity.into();666 let v = String::from_utf8_lossy(v);667 Box::new(ErrorInfoBuilder {668 level,669 msg: v.to_string(),670 stack_frames: Vec::new(),671 })672}673impl ErrorInfoBuilder {674 fn push_stack_frame(&mut self, v: &[u8], pos: &[u8]) {675 let v = String::from_utf8_lossy(v);676 let pos = String::from_utf8_lossy(pos);677 self.stack_frames.push(StackFrame {678 msg: v.to_string(),679 pos: pos.to_string(),680 });681 }682 fn emit_error_info(&mut self) {683 error!("{}", self.msg);684 for frame in &self.stack_frames {685 error!(" {} at {}", frame.msg, frame.pos)686 }687 }688}689690#[cxx::bridge]691pub mod nix_logging_cxx {692 extern "Rust" {693 type StartActivityBuilder;694 fn new_start_activity(activity_id: u64, lvl: u32, typ: u32) -> Box<StartActivityBuilder>;695 fn add_int_field(&mut self, i: i32);696 fn add_string_field(&mut self, v: &[u8]);697 fn emit(&mut self, parent: u64, s: &str);698 fn emit_result(&mut self, ty: u32);699 }700 extern "Rust" {701 type ErrorInfoBuilder;702 fn new_error_info(lvl: u32, v: &[u8]) -> Box<ErrorInfoBuilder>;703 fn push_stack_frame(&mut self, v: &[u8], pos: &[u8]);704 fn emit_error_info(&mut self);705 }706 extern "Rust" {707 fn emit_warn(v: &str);708 fn emit_stop(id: u64);709 fn emit_log(lvl: u32, v: &[u8]);710 }711 unsafe extern "C++" {712 include!("nix-eval/src/logging.hh");713714 type nix_c_context = crate::nix_raw::c_context;715716 fn apply_tracing_logger();717 unsafe fn extract_error_info(ctx: *const nix_c_context) -> Box<ErrorInfoBuilder>;718 }719}720721unsafe impl ExternType for crate::nix_raw::c_context {722 type Id = cxx::type_id!("nix_c_context");723724 type Kind = cxx::kind::Opaque;725}