eric/geth
Watch
1
0
Fork
You've already forked geth
 0
Code Issues Pull requests Projects Releases Packages Wiki Activity Actions

feat: add structured control tracing

Browse source
This commit is contained in:
Eric Wendland 2026-07-05 23:09:12 +02:00
commit d9031b995d
4 changed files with 477 additions and 9 deletions
Download patch file Download diff file Expand all files Collapse all files

467
crates/geth-node/src/lib.rs
View file

@ -682,7 +682,16 @@ pub async fn handle_request_async(
node: &LocalNode,
request: ControlRequest,
) -> Result<ControlResponse, NodeError> {
match request {
let trace = control_request_trace_fields(&request);
tracing::info!(
command = trace.command,
peer_node = trace.peer_node.as_deref().unwrap_or(""),
resource = trace.resource.as_deref().unwrap_or(""),
capability = trace.capability.as_deref().unwrap_or(""),
stream = trace.stream.as_deref().unwrap_or(""),
"control request started"
);
let result = match request {
ControlRequest::PeerCardExport { out } => export_peer_card(node, out, true).await,
ControlRequest::PeerPing { node: peer_node } => peer_ping(node, &peer_node).await,
ControlRequest::PeerAuthCheck {
@ -824,6 +833,330 @@ pub async fn handle_request_async(
}
Ok(response)
}
};
match &result {
Ok(_) => tracing::info!(
command = trace.command,
peer_node = trace.peer_node.as_deref().unwrap_or(""),
resource = trace.resource.as_deref().unwrap_or(""),
capability = trace.capability.as_deref().unwrap_or(""),
stream = trace.stream.as_deref().unwrap_or(""),
"control request completed"
),
Err(error) => tracing::warn!(
command = trace.command,
peer_node = trace.peer_node.as_deref().unwrap_or(""),
resource = trace.resource.as_deref().unwrap_or(""),
capability = trace.capability.as_deref().unwrap_or(""),
stream = trace.stream.as_deref().unwrap_or(""),
error_code = node_error_code(error),
%error,
"control request failed"
),
}
result
}
#[derive(Debug, PartialEq, Eq)]
struct ControlTraceFields {
command: &'static str,
peer_node: Option<String>,
resource: Option<String>,
capability: Option<String>,
stream: Option<String>,
}
fn control_request_trace_fields(request: &ControlRequest) -> ControlTraceFields {
let mut trace = ControlTraceFields {
command: control_request_command(request),
peer_node: None,
resource: None,
capability: None,
stream: None,
};
match request {
ControlRequest::PeerPing { node }
| ControlRequest::KeychainSync { node }
| ControlRequest::AuthSync { node } => {
trace.peer_node = Some(node.clone());
}
ControlRequest::PeerAuthCheck {
node,
resource,
capability,
} => {
trace.peer_node = Some(node.clone());
trace.resource = Some(resource.clone());
trace.capability = Some(capability.clone());
}
ControlRequest::CasRootSync { node, name, .. } => {
trace.peer_node = Some(node.clone());
trace.resource = Some(format!("resource:cas-tree:{name}"));
trace.capability = Some("cas.fetch".to_owned());
trace.stream = Some(format!("cas-tree:{name}"));
}
ControlRequest::SyncNow { node } => {
trace.peer_node = node.clone();
trace.stream = Some("all".to_owned());
}
ControlRequest::NodeGrant {
node,
resource,
capability,
..
} => {
trace.peer_node = Some(node.clone());
trace.resource = Some(resource.clone());
trace.capability = Some(capability.clone());
}
ControlRequest::NodeRevokeGrant { resource, .. } => {
trace.resource = Some(resource.clone());
}
ControlRequest::AuthExplain {
resource,
capability,
..
}
| ControlRequest::AuthGrant {
resource,
capability,
..
} => {
trace.resource = Some(resource.clone());
trace.capability = Some(capability.clone());
}
ControlRequest::AuthRevoke { resource, .. }
| ControlRequest::SecretCreate { resource }
| ControlRequest::SecretRotate { resource }
| ControlRequest::SecretBearerCreate { resource, .. }
| ControlRequest::SecretBearerChallenge { resource, .. }
| ControlRequest::SecretBearerProve { resource, .. }
| ControlRequest::SecretBearerVerify { resource, .. }
| ControlRequest::SecretBearerRevoke { resource, .. }
| ControlRequest::CasAddPrivate { resource, .. }
| ControlRequest::CasGetPrivate { resource, .. } => {
trace.resource = Some(resource.clone());
}
ControlRequest::CasFetch { node, .. } => {
trace.peer_node = Some(node.clone());
trace.resource = Some("resource:cas:local".to_owned());
trace.capability = Some("cas.fetch".to_owned());
}
ControlRequest::SshCertSync { node, .. } => {
trace.peer_node = Some(node.clone());
trace.resource = Some("resource:ssh:certs".to_owned());
trace.capability = Some("ssh_cert.sync".to_owned());
trace.stream = Some("ssh-certs".to_owned());
}
ControlRequest::SshRevocationSync { node, .. } => {
trace.peer_node = Some(node.clone());
trace.resource = Some("resource:ssh:revocations".to_owned());
trace.capability = Some("ssh_revocation.sync".to_owned());
trace.stream = Some("ssh-revocations".to_owned());
}
ControlRequest::KvSet { name, key, .. } => {
trace.resource = Some(format!("resource:kv:{name}"));
trace.capability = Some(format!("kv.write_key:{key}"));
trace.stream = Some(format!("kv:{name}"));
}
ControlRequest::KvSync { node, name, .. } => {
trace.peer_node = Some(node.clone());
trace.resource = Some(format!("resource:kv:{name}"));
trace.capability = Some("kv.read".to_owned());
trace.stream = Some(format!("kv:{name}"));
}
ControlRequest::KvCreate { name } | ControlRequest::KvGet { name, .. } => {
trace.resource = Some(format!("resource:kv:{name}"));
trace.stream = Some(format!("kv:{name}"));
}
ControlRequest::DbSync { node, name, .. } => {
trace.peer_node = Some(node.clone());
trace.resource = Some(format!("resource:db:{name}"));
trace.capability = Some("db.sync".to_owned());
trace.stream = Some(format!("db:{name}"));
}
ControlRequest::DbAdd { name, .. }
| ControlRequest::DbStatus { name }
| ControlRequest::DbChanges { name, .. } => {
trace.resource = Some(format!("resource:db:{name}"));
trace.stream = Some(format!("db:{name}"));
}
ControlRequest::DocumentSync { node, name, .. } => {
trace.peer_node = Some(node.clone());
trace.resource = Some(format!("resource:document:{name}"));
trace.capability = Some("document.read".to_owned());
trace.stream = Some(format!("document:{name}"));
}
ControlRequest::DocumentCreate { name }
| ControlRequest::DocumentStatus { name }
| ControlRequest::DocumentSet { name, .. }
| ControlRequest::DocumentGet { name } => {
trace.resource = Some(format!("resource:document:{name}"));
trace.stream = Some(format!("document:{name}"));
}
ControlRequest::PubsubPub { topic, node, .. } => {
trace.peer_node = node.clone();
trace.resource = Some(format!("resource:pubsub:{topic}"));
trace.capability = Some("pubsub.publish".to_owned());
trace.stream = Some(format!("pubsub:{topic}"));
}
ControlRequest::PubsubSub { topic, node, .. } => {
trace.peer_node = node.clone();
trace.resource = Some(format!("resource:pubsub:{topic}"));
trace.capability = Some("pubsub.subscribe".to_owned());
trace.stream = Some(format!("pubsub:{topic}"));
}
ControlRequest::PipeListen { name, node, .. } => {
trace.peer_node = node.clone();
trace.resource = Some(format!("resource:pipe:{name}"));
trace.capability = Some("pipe.listen".to_owned());
trace.stream = Some(format!("pipe:{name}"));
}
ControlRequest::PipeConnect { target, node, .. }
| ControlRequest::PipeSend { target, node, .. } => {
trace.peer_node = node.clone();
trace.resource = Some(format!("resource:pipe:{target}"));
trace.capability = Some("pipe.connect".to_owned());
trace.stream = Some(format!("pipe:{target}"));
}
ControlRequest::PipeTcpForward {
node, target_addr, ..
}
| ControlRequest::PipeTcpStream {
node, target_addr, ..
} => {
trace.peer_node = Some(node.clone());
trace.resource = Some(format!("resource:pipe-tcp:{target_addr}"));
trace.capability = Some("pipe.forward".to_owned());
trace.stream = Some("pipe-tcp".to_owned());
}
ControlRequest::PipeUnixForward {
node, target_path, ..
}
| ControlRequest::PipeUnixStream {
node, target_path, ..
} => {
trace.peer_node = Some(node.clone());
trace.resource = Some(format!("resource:pipe-unix:{}", target_path.display()));
trace.capability = Some("pipe.forward".to_owned());
trace.stream = Some("pipe-unix".to_owned());
}
ControlRequest::SshProxyConnect { node, .. }
| ControlRequest::SshProxyStream { node, .. } => {
trace.peer_node = Some(node.clone());
trace.resource = Some("resource:ssh-proxy:local".to_owned());
trace.capability = Some("ssh_proxy.connect".to_owned());
trace.stream = Some("ssh-proxy".to_owned());
}
ControlRequest::SshAdminShell { node, .. } => {
trace.peer_node = Some(node.clone());
trace.resource = Some("resource:ssh-proxy:local".to_owned());
trace.capability = Some("ssh_proxy.admin_shell".to_owned());
trace.stream = Some("ssh-admin-shell".to_owned());
}
ControlRequest::OverlaySend { name, node, .. } => {
trace.peer_node = Some(node.clone());
trace.resource = Some(format!("resource:overlay:{name}"));
trace.capability = Some("overlay.route".to_owned());
trace.stream = Some(format!("overlay:{name}"));
}
ControlRequest::OverlayUp { name, .. } => {
trace.resource = Some(format!("resource:overlay:{name}"));
trace.capability = Some("overlay.route".to_owned());
trace.stream = Some(format!("overlay:{name}"));
}
_ => {}
}
trace
}
fn control_request_command(request: &ControlRequest) -> &'static str {
match request {
ControlRequest::Status => "status",
ControlRequest::NodeId => "node-id",
ControlRequest::PeerCardExport { .. } => "peer.export",
ControlRequest::PeerCardImport { .. } => "peer.import",
ControlRequest::PeerCardList => "peer.list",
ControlRequest::PeerPing { .. } => "peer.ping",
ControlRequest::PeerAuthCheck { .. } => "peer.auth-check",
ControlRequest::ResourceList => "resource.list",
ControlRequest::ResourceCreate { .. } => "resource.create",
ControlRequest::KeychainSync { .. } => "keychain.sync",
ControlRequest::AuthSync { .. } => "auth.sync",
ControlRequest::SyncStatus => "sync.status",
ControlRequest::SyncNow { .. } => "sync.now",
ControlRequest::AuthExplain { .. } => "auth.explain",
ControlRequest::AuthGrant { .. } => "auth.grant",
ControlRequest::AuthRevoke { .. } => "auth.revoke",
ControlRequest::CasFetch { .. } => "cas.fetch",
ControlRequest::CasRootSync { .. } => "cas.root.sync",
ControlRequest::CasAddPrivate { .. } => "cas.add-private",
ControlRequest::CasGetPrivate { .. } => "cas.get-private",
ControlRequest::SshCertSync { .. } => "ssh.cert.sync",
ControlRequest::SshRevocationSync { .. } => "ssh.revocation.sync",
ControlRequest::KvCreate { .. } => "kv.create",
ControlRequest::KvSet { .. } => "kv.set",
ControlRequest::KvGet { .. } => "kv.get",
ControlRequest::KvSync { .. } => "kv.sync",
ControlRequest::DbAdd { .. } => "db.add",
ControlRequest::DbStatus { .. } => "db.status",
ControlRequest::DbChanges { .. } => "db.changes",
ControlRequest::DbSync { .. } => "db.sync",
ControlRequest::DocumentCreate { .. } => "document.create",
ControlRequest::DocumentStatus { .. } => "document.status",
ControlRequest::DocumentSet { .. } => "document.set",
ControlRequest::DocumentGet { .. } => "document.get",
ControlRequest::DocumentSync { .. } => "document.sync",
ControlRequest::PubsubPub { .. } => "pubsub.pub",
ControlRequest::PubsubSub { .. } => "pubsub.sub",
ControlRequest::PipeListen { .. } => "pipe.listen",
ControlRequest::PipeConnect { .. } => "pipe.connect",
ControlRequest::PipeSend { .. } => "pipe.send",
ControlRequest::PipeRecv { .. } => "pipe.recv",
ControlRequest::PipeTcpForward { .. } => "pipe.forward-tcp",
ControlRequest::PipeTcpStream { .. } => "pipe.tcp-stream",
ControlRequest::PipeUnixForward { .. } => "pipe.forward-unix",
ControlRequest::PipeUnixStream { .. } => "pipe.unix-stream",
ControlRequest::SshProxyConnect { .. } => "ssh.proxy",
ControlRequest::SshProxyStream { .. } => "ssh.proxy-stream",
ControlRequest::SshAdminShell { .. } => "ssh.admin-shell",
ControlRequest::OverlayStatus => "overlay.status",
ControlRequest::OverlayPlan { .. } => "overlay.plan",
ControlRequest::OverlayJoin { .. } => "overlay.join",
ControlRequest::OverlayLeave { .. } => "overlay.leave",
ControlRequest::OverlayInterfacePlan { .. } => "overlay.interface-plan",
ControlRequest::OverlayUp { .. } => "overlay.up",
ControlRequest::OverlayDown { .. } => "overlay.down",
ControlRequest::OverlayPeers { .. } => "overlay.peers",
ControlRequest::OverlaySend { .. } => "overlay.send",
ControlRequest::OverlayRecv { .. } => "overlay.recv",
ControlRequest::SecretStatus => "secret.status",
ControlRequest::SecretCreate { .. } => "secret.create",
ControlRequest::SecretRotate { .. } => "secret.rotate",
ControlRequest::SecretBearerCreate { .. } => "secret.bearer.create",
ControlRequest::SecretBearerList => "secret.bearer.list",
ControlRequest::SecretBearerChallenge { .. } => "secret.bearer.challenge",
ControlRequest::SecretBearerProve { .. } => "secret.bearer.prove",
ControlRequest::SecretBearerVerify { .. } => "secret.bearer.verify",
ControlRequest::SecretBearerRevoke { .. } => "secret.bearer.revoke",
ControlRequest::ModuleStub { .. } => "module.stub",
_ => "control.request",
}
}
fn node_error_code(error: &NodeError) -> &'static str {
match error {
NodeError::Unauthorized(_) => "unauthorized",
NodeError::PeerNotFound(_) => "peer_not_found",
NodeError::IrohEndpointUnavailable => "iroh_endpoint_unavailable",
NodeError::KvNotFound(_) => "kv_not_found",
NodeError::DbNotFound(_) => "db_not_found",
NodeError::DocumentNotFound(_) => "document_not_found",
NodeError::Cas(_) => "cas_error",
NodeError::Store(_) => "store_error",
NodeError::Config(_) => "config_error",
NodeError::Codec(_) => "codec_error",
_ => "node_error",
}
}
@ -837,8 +1170,37 @@ async fn handle_stream(node: LocalNode, stream: UnixStream) -> Result<(), NodeEr
bearer_secret,
} = request
{
tracing::info!(
command = "ssh.proxy-stream",
peer_node = %peer_node,
resource = "resource:ssh-proxy:local",
capability = "ssh_proxy.connect",
stream = "ssh-proxy",
"streaming control request started"
);
let stream = reader.into_inner();
return handle_local_ssh_proxy_stream(node, &peer_node, bearer_secret, stream).await;
let result = handle_local_ssh_proxy_stream(node, &peer_node, bearer_secret, stream).await;
match &result {
Ok(_) => tracing::info!(
command = "ssh.proxy-stream",
peer_node = %peer_node,
resource = "resource:ssh-proxy:local",
capability = "ssh_proxy.connect",
stream = "ssh-proxy",
"streaming control request completed"
),
Err(error) => tracing::warn!(
command = "ssh.proxy-stream",
peer_node = %peer_node,
resource = "resource:ssh-proxy:local",
capability = "ssh_proxy.connect",
stream = "ssh-proxy",
error_code = node_error_code(error),
%error,
"streaming control request failed"
),
}
return result;
}
if let ControlRequest::PipeTcpStream {
node: peer_node,
@ -846,9 +1208,40 @@ async fn handle_stream(node: LocalNode, stream: UnixStream) -> Result<(), NodeEr
bearer_secret,
} = request
{
let resource = format!("resource:pipe-tcp:{target_addr}");
tracing::info!(
command = "pipe.tcp-stream",
peer_node = %peer_node,
resource = %resource,
capability = "pipe.forward",
stream = "pipe-tcp",
"streaming control request started"
);
let stream = reader.into_inner();
return handle_local_pipe_tcp_stream(node, &peer_node, target_addr, bearer_secret, stream)
.await;
let result =
handle_local_pipe_tcp_stream(node, &peer_node, target_addr, bearer_secret, stream)
.await;
match &result {
Ok(_) => tracing::info!(
command = "pipe.tcp-stream",
peer_node = %peer_node,
resource = %resource,
capability = "pipe.forward",
stream = "pipe-tcp",
"streaming control request completed"
),
Err(error) => tracing::warn!(
command = "pipe.tcp-stream",
peer_node = %peer_node,
resource = %resource,
capability = "pipe.forward",
stream = "pipe-tcp",
error_code = node_error_code(error),
%error,
"streaming control request failed"
),
}
return result;
}
if let ControlRequest::PipeUnixStream {
node: peer_node,
@ -856,9 +1249,40 @@ async fn handle_stream(node: LocalNode, stream: UnixStream) -> Result<(), NodeEr
bearer_secret,
} = request
{
let resource = format!("resource:pipe-unix:{}", target_path.display());
tracing::info!(
command = "pipe.unix-stream",
peer_node = %peer_node,
resource = %resource,
capability = "pipe.forward",
stream = "pipe-unix",
"streaming control request started"
);
let stream = reader.into_inner();
return handle_local_pipe_unix_stream(node, &peer_node, target_path, bearer_secret, stream)
.await;
let result =
handle_local_pipe_unix_stream(node, &peer_node, target_path, bearer_secret, stream)
.await;
match &result {
Ok(_) => tracing::info!(
command = "pipe.unix-stream",
peer_node = %peer_node,
resource = %resource,
capability = "pipe.forward",
stream = "pipe-unix",
"streaming control request completed"
),
Err(error) => tracing::warn!(
command = "pipe.unix-stream",
peer_node = %peer_node,
resource = %resource,
capability = "pipe.forward",
stream = "pipe-unix",
error_code = node_error_code(error),
%error,
"streaming control request failed"
),
}
return result;
}
let response = match handle_request_async(&node, request).await {
Ok(response) => response,
@ -11451,6 +11875,37 @@ mod tests {
assert_eq!(merged["remote"], true);
}
#[test]
fn control_trace_fields_exclude_bearer_secrets() {
let trace = control_request_trace_fields(&ControlRequest::KvSync {
node: "node:peer".to_owned(),
name: "prefs".to_owned(),
bearer_secret: Some("private-token-value".to_owned()),
});
assert_eq!(trace.command, "kv.sync");
assert_eq!(trace.peer_node.as_deref(), Some("node:peer"));
assert_eq!(trace.resource.as_deref(), Some("resource:kv:prefs"));
assert_eq!(trace.capability.as_deref(), Some("kv.read"));
assert_eq!(trace.stream.as_deref(), Some("kv:prefs"));
assert!(!format!("{trace:?}").contains("private-token-value"));
}
#[test]
fn node_error_codes_are_stable_for_common_tracing_failures() {
assert_eq!(
node_error_code(&NodeError::Unauthorized("missing grant".to_owned())),
"unauthorized"
);
assert_eq!(
node_error_code(&NodeError::PeerNotFound("node:missing".to_owned())),
"peer_not_found"
);
assert_eq!(
node_error_code(&NodeError::IrohEndpointUnavailable),
"iroh_endpoint_unavailable"
);
}
#[derive(Debug, PartialEq, Eq)]
enum RemoteGuardKind {
Capability,