ALPHA: wire is a tool to deploy nixos systems
wire.althaea.zone/
improve logging in various ways
+53
-34
+1
CHANGELOG.md
+1
CHANGELOG.md
+2
-2
wire/cli/src/apply.rs
+2
-2
wire/cli/src/apply.rs
···
12
12
use std::path::PathBuf;
13
13
use std::sync::{Arc, Mutex};
14
14
use thiserror::Error;
15
-
use tracing::{Span, error, info, instrument};
15
+
use tracing::{Span, error, info};
16
16
17
17
use crate::cli::{ApplyArgs, ApplyTarget};
18
18
···
48
48
}))
49
49
}
50
50
51
-
#[instrument(skip_all, fields(goal = %args.goal, on = %args.on.iter().join(", ")))]
51
+
// #[instrument(skip_all, fields(goal = %args.goal, on = %args.on.iter().join(", ")))]
52
52
pub async fn apply(
53
53
hive: &mut Hive,
54
54
args: ApplyArgs,
+2
-1
wire/cli/src/tracing_setup.rs
+2
-1
wire/cli/src/tracing_setup.rs
···
66
66
pub fn setup_logging(verbosity: Verbosity<WarnLevel>, clobber_lock: Arc<Mutex<()>>) {
67
67
let filter = verbosity.log_level_filter().as_trace();
68
68
let registry = tracing_subscriber::registry();
69
-
69
+
70
70
let layer = tracing_subscriber::fmt::layer::<Registry>()
71
71
.without_time()
72
+
.with_target(false)
72
73
.with_writer(move || NonClobberingWriter::new(clobber_lock.clone()))
73
74
.with_filter(filter);
74
75
+7
-1
wire/key_agent/src/main.rs
+7
-1
wire/key_agent/src/main.rs
···
10
10
use prost::Message;
11
11
use prost::bytes::Bytes;
12
12
use sha2::{Digest, Sha256};
13
+
use std::fmt;
14
+
use std::fmt::Display;
13
15
use std::os::unix::fs::PermissionsExt;
14
16
use std::os::unix::fs::chown;
15
17
use std::path::{Path, PathBuf};
···
22
24
std::fs::create_dir_all(prefix)?;
23
25
24
26
Ok(())
27
+
}
28
+
29
+
fn pretty_keyspec(spec: &KeySpec) -> String {
30
+
format!("{} {}:{} {}", spec.destination, spec.user, spec.group, spec.permissions)
25
31
}
26
32
27
33
#[tokio::main]
···
43
49
44
50
let digest = Sha256::digest(&key_bytes).to_vec();
45
51
46
-
println!("Writing key {spec:?}, {:?} bytes of data", key_bytes.len());
52
+
println!("Writing {}, {:?} bytes of data", pretty_keyspec(&spec), key_bytes.len());
47
53
48
54
if digest != spec.digest {
49
55
return Err(anyhow::anyhow!(
+18
-11
wire/lib/src/commands/interactive.rs
+18
-11
wire/lib/src/commands/interactive.rs
···
2
2
// Copyright 2024-2025 wire Contributors
3
3
4
4
use nix::sys::termios::{LocalFlags, SetArg, Termios, tcgetattr, tcsetattr};
5
+
use std::fmt::Debug;
5
6
use nix::{
6
7
poll::{PollFd, PollFlags, PollTimeout, poll},
7
8
unistd::{pipe as posix_pipe, read as posix_read, write as posix_write},
···
17
18
os::fd::{AsFd, OwnedFd},
18
19
sync::Arc,
19
20
};
20
-
use tracing::{debug, error, info, trace};
21
+
use tracing::{Span, debug, error, info, trace, warn};
22
+
use tracing::instrument;
21
23
22
24
use crate::SubCommandModifiers;
23
25
use crate::commands::CommandArguments;
···
34
36
type MasterReader = Box<dyn Read + Send>;
35
37
type Child = Box<dyn portable_pty::Child + Send + Sync>;
36
38
39
+
#[derive(Debug)]
37
40
pub(crate) struct InteractiveCommand<'t> {
38
41
target: Option<&'t Target>,
39
42
output_mode: Arc<ChildOutputMode>,
···
66
69
condvar: Condvar,
67
70
}
68
71
69
-
struct WatchStdinArguments {
72
+
struct WatchStdoutArguments {
70
73
began_tx: Sender<()>,
71
74
reader: MasterReader,
72
75
succeed_needle: Arc<String>,
···
76
79
stderr_collection: Arc<Mutex<VecDeque<String>>>,
77
80
stdout_collection: Arc<Mutex<VecDeque<String>>>,
78
81
completion_status: Arc<CompletionStatus>,
82
+
span: Span
79
83
}
80
84
81
85
/// the underlying command began
···
110
114
}
111
115
112
116
#[allow(clippy::too_many_lines)]
113
-
fn run_command_with_env<S: AsRef<str>>(
117
+
#[instrument(level = "trace", skip_all, name = "run", fields(elevated = %arguments.elevated))]
118
+
fn run_command_with_env<S: AsRef<str> + Debug>(
114
119
&mut self,
115
120
arguments: CommandArguments<S>,
116
121
envs: std::collections::HashMap<String, String>,
···
208
213
let completion_status = Arc::new(CompletionStatus::new());
209
214
210
215
let stdout_handle = {
211
-
let arguments = WatchStdinArguments {
216
+
let arguments = WatchStdoutArguments {
212
217
began_tx,
213
218
reader,
214
219
succeed_needle: self.succeed_needle.clone(),
···
218
223
stderr_collection: stderr_collection.clone(),
219
224
stdout_collection: stdout_collection.clone(),
220
225
completion_status: completion_status.clone(),
226
+
span: Span::current()
221
227
};
222
228
223
229
std::thread::spawn(move || dynamic_watch_sudo_stdout(arguments))
···
229
235
posix_pipe().map_err(|x| HiveLibError::CommandError(CommandError::PosixPipe(x)))?;
230
236
231
237
std::thread::spawn(move || {
232
-
watch_stdin_from_user(&cancel_stdin_pipe_r, master_writer, &write_stdin_pipe_r)
238
+
watch_stdin_from_user(&cancel_stdin_pipe_r, master_writer, &write_stdin_pipe_r, Span::current())
233
239
});
234
240
235
241
info!("Setup threads");
···
298
304
impl WireCommandChip for InteractiveChildChip {
299
305
type ExitStatus = (portable_pty::ExitStatus, String);
300
306
307
+
#[instrument(skip_all)]
301
308
async fn wait_till_success(mut self) -> Result<Self::ExitStatus, CommandError> {
302
-
info!("trying to grab status...");
303
-
304
309
drop(self.write_stdin_pipe_w);
305
310
306
311
let exit_status = tokio::task::spawn_blocking(move || self.child.wait())
···
382
387
Ok(command)
383
388
}
384
389
385
-
fn dynamic_watch_sudo_stdout(arguments: WatchStdinArguments) -> Result<(), CommandError> {
386
-
let WatchStdinArguments {
390
+
#[instrument(skip_all, name = "log", parent = arguments.span)]
391
+
fn dynamic_watch_sudo_stdout(arguments: WatchStdoutArguments) -> Result<(), CommandError> {
392
+
let WatchStdoutArguments {
387
393
began_tx,
388
394
mut reader,
389
395
succeed_needle,
···
393
399
stdout_collection,
394
400
stderr_collection,
395
401
completion_status,
402
+
..
396
403
} = arguments;
397
404
398
405
let mut buffer = [0u8; 1024];
···
408
415
log_buffer.process(&new_data);
409
416
410
417
for line in log_buffer.take_lines() {
411
-
trace!("line: {line}");
412
-
413
418
if line.contains(start_needle.as_ref()) {
414
419
debug!("{start_needle} was found, switching mode...");
415
420
let _ = began_tx.send(());
···
475
480
}
476
481
477
482
/// Exits on any data written to `cancel_pipe_r`
483
+
#[instrument(skip_all, level = "trace", parent = span)]
478
484
fn watch_stdin_from_user(
479
485
cancel_pipe_r: &OwnedFd,
480
486
mut master_writer: MasterWriter,
481
487
write_pipe_r: &OwnedFd,
488
+
span: Span
482
489
) -> Result<(), CommandError> {
483
490
const WRITER_POSITION: usize = 0;
484
491
const SIGNAL_POSITION: usize = 1;
+6
-5
wire/lib/src/commands/mod.rs
+6
-5
wire/lib/src/commands/mod.rs
···
24
24
pub(crate) mod interactive_logbuffer;
25
25
pub(crate) mod noninteractive;
26
26
27
-
#[derive(Copy, Clone)]
27
+
#[derive(Copy, Clone, Debug)]
28
28
pub(crate) enum ChildOutputMode {
29
29
Raw,
30
30
Nix,
···
36
36
Right(R),
37
37
}
38
38
39
+
#[derive(Debug)]
39
40
pub(crate) struct CommandArguments<S: AsRef<str>> {
40
41
pub(crate) command_string: S,
41
42
pub(crate) keep_stdin_open: bool,
···
68
69
modifiers: SubCommandModifiers,
69
70
) -> Result<Self, HiveLibError>;
70
71
71
-
fn run_command<S: AsRef<str>>(
72
+
fn run_command<S: AsRef<str> + std::fmt::Debug>(
72
73
&mut self,
73
74
command_arugments: CommandArguments<S>,
74
75
) -> Result<Self::ChildChip, HiveLibError> {
75
76
self.run_command_with_env(command_arugments, std::collections::HashMap::new())
76
77
}
77
78
78
-
fn run_command_with_env<S: AsRef<str>>(
79
+
fn run_command_with_env<S: AsRef<str> + std::fmt::Debug>(
79
80
&mut self,
80
81
command_arugments: CommandArguments<S>,
81
82
args: HashMap<String, String>,
···
101
102
unimplemented!()
102
103
}
103
104
104
-
fn run_command_with_env<S: AsRef<str>>(
105
+
fn run_command_with_env<S: AsRef<str> + std::fmt::Debug>(
105
106
&mut self,
106
107
command_arugments: CommandArguments<S>,
107
108
envs: HashMap<String, String>,
···
157
158
158
159
if !matches!(
159
160
log,
160
-
SubcommandLog::Internal(LogMessage::Msg { .. }) | SubcommandLog::Raw(..)
161
+
SubcommandLog::Internal(LogMessage::Msg { .. })
161
162
) {
162
163
return None;
163
164
}
+5
-4
wire/lib/src/hive/node.rs
+5
-4
wire/lib/src/hive/node.rs
···
9
9
use std::fmt::Display;
10
10
use std::path::PathBuf;
11
11
use std::sync::{Arc, Mutex};
12
-
use tracing::{error, info, instrument, trace};
12
+
use tracing::{Level, error, event, instrument, trace};
13
13
14
14
use crate::SubCommandModifiers;
15
15
use crate::commands::{
···
348
348
}
349
349
}
350
350
351
-
#[instrument(skip_all, name = "goal", fields(node = %self.context.name))]
351
+
#[instrument(skip_all, fields(goal = %self.context.goal, node = %self.context.name))]
352
352
pub async fn execute(mut self) -> Result<(), HiveLibError> {
353
353
let steps = self
354
354
.steps
···
358
358
trace!("Will execute step `{step}` for {}", self.context.name);
359
359
})
360
360
.collect::<Vec<_>>();
361
+
let length = steps.len();
361
362
362
-
for step in steps {
363
-
info!("Executing step `{step}`");
363
+
for (position, step) in steps.iter().enumerate() {
364
+
event!(Level::INFO, step = step.to_string(), progress = format!("{}/{length}", position + 1));
364
365
365
366
step.execute(&mut self.context).await.inspect_err(|_| {
366
367
error!("Failed to execute `{step}`");
+2
-2
wire/lib/src/hive/steps/activate.rs
+2
-2
wire/lib/src/hive/steps/activate.rs
···
17
17
18
18
impl Display for SwitchToConfiguration {
19
19
fn fmt(&self, f: &mut std::fmt::Formatter<'_>) -> std::fmt::Result {
20
-
write!(f, "Switch to configuration")
20
+
write!(f, "switch-to-configuration")
21
21
}
22
22
}
23
23
···
81
81
matches!(ctx.goal, Goal::SwitchToConfiguration(..))
82
82
}
83
83
84
-
#[instrument(skip_all, name = "switch")]
84
+
#[instrument(skip_all, name = "activate")]
85
85
async fn execute(&self, ctx: &mut Context<'_>) -> Result<(), HiveLibError> {
86
86
let built_path = ctx.state.build.as_ref().unwrap();
87
87
+5
-1
wire/lib/src/hive/steps/keys.rs
+5
-1
wire/lib/src/hive/steps/keys.rs
···
20
20
use tokio::process::Command;
21
21
use tokio::{fs::File, io::AsyncRead};
22
22
use tokio_util::codec::LengthDelimitedCodec;
23
-
use tracing::debug;
23
+
use tracing::{Span, debug, field, instrument};
24
24
25
25
use crate::HiveLibError;
26
26
use crate::commands::common::push;
···
203
203
)
204
204
}
205
205
206
+
#[instrument(skip_all, name = "keys", fields(filter = field::Empty))]
206
207
async fn execute(&self, ctx: &mut Context<'_>) -> Result<(), HiveLibError> {
208
+
Span::current().record("filter", format!("{:?}", self.filter));
209
+
207
210
let agent_directory = ctx.state.key_agent_directory.as_ref().unwrap();
208
211
209
212
let futures = ctx
···
289
292
)
290
293
}
291
294
295
+
#[instrument(skip_all, name = "push_agent")]
292
296
async fn execute(&self, ctx: &mut Context<'_>) -> Result<(), HiveLibError> {
293
297
let arg_name = format!(
294
298
"WIRE_KEY_AGENT_{platform}",
+5
-7
wire/lib/src/hive/steps/ping.rs
+5
-7
wire/lib/src/hive/steps/ping.rs
···
3
3
4
4
use std::fmt::Display;
5
5
6
-
use tracing::{info, instrument, warn};
6
+
use tracing::{Level, event, instrument};
7
7
8
8
use crate::{
9
9
HiveLibError,
···
27
27
#[instrument(skip_all, name = "ping")]
28
28
async fn execute(&self, ctx: &mut Context<'_>) -> Result<(), HiveLibError> {
29
29
loop {
30
-
info!("Attempting host {}", ctx.node.target.get_preferred_host()?);
30
+
event!(Level::INFO, status = "attempting", host = ctx.node.target.get_preferred_host()?.to_string());
31
31
32
32
if ctx
33
33
.node
···
35
35
.await
36
36
.is_ok()
37
37
{
38
+
event!(Level::INFO, status = "success", host = ctx.node.target.get_preferred_host()?.to_string());
38
39
return Ok(());
39
40
}
40
41
41
-
warn!(
42
-
"Failed to ping host {}",
43
-
// ? will take us out if we ran out of hosts
44
-
ctx.node.target.get_preferred_host()?
45
-
);
42
+
// ? will take us out if we ran out of hosts
43
+
event!(Level::WARN, status = "failed to ping", host = ctx.node.target.get_preferred_host()?.to_string());
46
44
ctx.node.target.host_failed();
47
45
}
48
46
}