fix: improve dispatch and event handling with layers

Cargo.toml

@@ -87,6 +87,7 @@ tracing = "0.1.40"
 tracing-error = { version = "0.2.0", features = ["traced-error"] }
 tracing-log = "0.2.0"
 tracing-subscriber = { version = "0.3.18", features = ["env-filter"] }
+tracing-tree = "0.4.0"
 umask = "2.1.0"
 warp = "0.3.7"
 

DEVELOPMENT.md

@@ -60,6 +60,18 @@ The global debug level can be overly noisy. Instead of doing `-vvvv`, try:
 RUST_LOG=none,kty=debug
 ```
 
+### Tracing Tree
+
+It can be a little difficult to reason about how events filter through the
+application. Towards that end, `dispatch` has `tracing::instrument` on it in
+most places. This can be used to render a tree based on the spans that lets you
+see what functions are being called and what their return values are. To see
+this data, you can use the same format as `RUST_LOG` and export:
+
+```bash
+TRACING_TREE=none,kty=trace
+```
+
 ## Ingress Tunnel
 
 If testing port forwarding and running the service locally (aka not on the

src/cli.rs

@@ -70,17 +70,31 @@ impl Command for Root {
             return Err(eyre!("log level already set"));
         }
 
-        let filter = EnvFilter::builder()
+        let fmt_filter = EnvFilter::builder()
             .with_default_directive(self.verbosity.log_level_filter().as_trace().into())
             .from_env_lossy();
 
         let fmt = tracing_subscriber::fmt::layer()
             .pretty()
             .with_writer(Mutex::new(self.log_file.clone()))
-            .with_filter(filter);
+            .with_filter(fmt_filter);
+
+        let tree_filter = EnvFilter::from_env("TRACING_TREE");
+
+        let tree = tracing_tree::HierarchicalLayer::default()
+            .with_writer(Mutex::new(self.log_file.clone()))
+            .with_indent_lines(true)
+            .with_indent_amount(2)
+            .with_thread_names(true)
+            .with_thread_ids(true)
+            .with_verbose_exit(true)
+            .with_verbose_entry(true)
+            .with_targets(true)
+            .with_filter(tree_filter);
 
         let registry = tracing_subscriber::registry()
             .with(fmt)
+            .with(tree)
             .with(ErrorLayer::default());
 
         if self.no_telemetry {

src/cli/resources.rs

@@ -42,7 +42,7 @@ pub struct Crd {}
 #[async_trait::async_trait]
 impl Command for Crd {
     #[allow(clippy::blocks_in_conditions)]
-    #[tracing::instrument(err, skip(self), fields(activity = "resources.crd"))]
+    #[tracing::instrument(err, skip_all, fields(activity = "resources.crd"))]
     async fn run(&self) -> Result<()> {
         let mut serializer = serde_yaml::Serializer::new(std::io::stdout());
         for resource in crate::resources::all() {
@@ -62,7 +62,7 @@ pub struct Delete {
 #[async_trait::async_trait]
 impl Command for Delete {
     #[allow(clippy::blocks_in_conditions)]
-    #[tracing::instrument(err, skip(self), fields(activity = "resources.delete"))]
+    #[tracing::instrument(err, skip_all, fields(activity = "resources.delete"))]
     async fn run(&self) -> Result<()> {
         let client = Client::try_default().await?;
 
@@ -102,7 +102,7 @@ pub struct Install {
 #[async_trait::async_trait]
 impl Command for Install {
     #[allow(clippy::blocks_in_conditions)]
-    #[tracing::instrument(err, skip(self), fields(activity = "resources.install"))]
+    #[tracing::instrument(err, skip_all, fields(activity = "resources.install"))]
     async fn run(&self) -> Result<()> {
         let namespace = namespace(self.namespace.as_ref()).await?;
 

src/cli/serve.rs

@@ -169,7 +169,7 @@ impl Serve {
 #[async_trait::async_trait]
 impl Command for Serve {
     #[allow(clippy::blocks_in_conditions)]
-    #[tracing::instrument(err, skip(self), fields(activity = "serve"))]
+    #[tracing::instrument(err, skip_all, fields(activity = "serve"))]
     async fn run(&self) -> Result<()> {
         tokio::select! {
             result = self.serve_http() => result,

src/cli/users.rs

@@ -45,7 +45,7 @@ pub struct Check {
 #[async_trait::async_trait]
 impl Command for Check {
     #[allow(clippy::blocks_in_conditions)]
-    #[tracing::instrument(err, skip(self), fields(activity = "users.check"))]
+    #[tracing::instrument(err, skip_all, fields(activity = "users.check"))]
     async fn run(&self) -> Result<()> {
         let identity = Identity::new(self.id.clone(), self.groups.clone());
 
@@ -101,7 +101,7 @@ enum Output {
 #[async_trait::async_trait]
 impl Command for Grant {
     #[allow(clippy::blocks_in_conditions)]
-    #[tracing::instrument(err, skip(self), fields(activity = "users.grant"))]
+    #[tracing::instrument(err, skip_all, fields(activity = "users.grant"))]
     async fn run(&self) -> Result<()> {
         let binding = ClusterRoleBinding {
             metadata: ObjectMeta {
@@ -179,7 +179,7 @@ pub struct Key {
 #[async_trait::async_trait]
 impl Command for Key {
     #[allow(clippy::blocks_in_conditions)]
-    #[tracing::instrument(err, skip(self), fields(activity = "users.key"))]
+    #[tracing::instrument(err, skip_all, fields(activity = "users.key"))]
     async fn run(&self) -> Result<()> {
         let mut keys: Vec<PublicKey> = self
             .keys

src/identity.rs

@@ -40,7 +40,7 @@ impl Identity {
 
 #[async_trait::async_trait]
 impl Authenticate for Identity {
-    #[tracing::instrument(skip(self, ctrl))]
+    #[tracing::instrument(skip_all)]
     async fn authenticate(&self, ctrl: &Controller) -> Result<Option<Identity>> {
         let client = self.client(ctrl)?;
 

src/identity/key.rs

@@ -59,7 +59,7 @@ impl Key {
         self.spec.expiration < Utc::now()
     }
 
-    #[tracing::instrument(skip(self, client))]
+    #[tracing::instrument(skip_all)]
     pub async fn update(&self, client: kube::Client) -> Result<()> {
         Api::<Key>::default_namespaced(client)
             .patch(
@@ -122,7 +122,7 @@ impl Authenticate for PublicKey {
     // - get the user from owner references
     // - validate the expiration
     // - should there be a status field or condition for an existing key?
-    #[tracing::instrument(skip(self, ctrl))]
+    #[tracing::instrument(skip_all)]
     async fn authenticate(&self, ctrl: &Controller) -> Result<Option<Identity>> {
         let keys: Api<Key> = Api::default_namespaced(ctrl.client()?);
 

src/resources/tunnel.rs

@@ -227,7 +227,7 @@ impl StreamMetrics<'_> {
     }
 }
 
-#[tracing::instrument(skip(src, dst))]
+#[tracing::instrument(skip_all)]
 async fn stream(
     mut src: impl AsyncRead + AsyncWrite + Unpin + Send,
     mut dst: impl AsyncRead + AsyncWrite + Unpin + Send,

src/ssh/session.rs

@@ -106,7 +106,7 @@ impl Session {
         self.features.contains(feature)
     }
 
-    #[tracing::instrument(skip(self))]
+    #[tracing::instrument(skip_all)]
     async fn send_code(&mut self) -> Result<Auth> {
         CODE_GENERATED.inc();
 
@@ -143,7 +143,7 @@ impl Session {
     }
 
     // TODO: need to handle 429 responses and backoff.
-    #[tracing::instrument(skip(self))]
+    #[tracing::instrument(skip_all)]
     async fn authenticate_code(&mut self) -> Result<Auth> {
         let (code, key) = {
             let State::CodeSent(code, key) = &self.state else {
@@ -247,7 +247,7 @@ impl server::Handler for Session {
     }
 
     // TODO: add some kind of event to log successful authentication.
-    #[tracing::instrument(skip(self, _session))]
+    #[tracing::instrument(skip_all)]
     async fn auth_succeeded(&mut self, _session: &mut server::Session) -> Result<()> {
         let State::Authenticated(identity) = &self.state else {
             UNEXPECTED_STATE
@@ -267,7 +267,7 @@ impl server::Handler for Session {
         Ok(())
     }
 
-    #[tracing::instrument(skip(self, channel))]
+    #[tracing::instrument(skip_all)]
     async fn channel_open_session(
         &mut self,
         channel: russh::Channel<server::Msg>,
@@ -393,7 +393,7 @@ impl server::Handler for Session {
         Ok(true)
     }
 
-    #[tracing::instrument(skip(self, data))]
+    #[tracing::instrument(skip_all)]
     async fn data(&mut self, _: ChannelId, data: &[u8], _: &mut server::Session) -> Result<()> {
         TOTAL_BYTES.inc_by(data.len() as u64);
 

src/widget/apex.rs

@@ -75,6 +75,7 @@ impl Apex {
 }
 
 impl Widget for Apex {
+    #[tracing::instrument(ret(level = Level::TRACE), skip(self, buffer, area), fields(name = self._name()))]
     fn dispatch(&mut self, event: &Event, buffer: &Buffer, area: Rect) -> Result<Broadcast> {
         if let Event::Tunnel(Err(err)) = event {
             self.view.push(Error::from(err.message()).boxed().into());

src/widget/log.rs

@@ -57,7 +57,7 @@ pub struct Log<'a> {
 //   probably be an "editor" widget that takes something to populate the lines.
 impl Log<'_> {
     #[allow(clippy::blocks_in_conditions)]
-    #[tracing::instrument(skip(client, pod), fields(activity = "pod.logs"))]
+    #[tracing::instrument(skip_all, fields(activity = "pod.logs"))]
     pub fn new(client: kube::Client, pod: Arc<Pod>) -> Self {
         WIDGET_VIEWS.pod.log.inc();
 

src/widget/node.rs

@@ -27,7 +27,7 @@ pub struct List {
 #[bon::bon]
 impl List {
     #[allow(clippy::blocks_in_conditions)]
-    #[tracing::instrument(skip(client), fields(activity = "node.list"))]
+    #[tracing::instrument(skip_all, fields(activity = "node.list"))]
     #[builder]
     pub fn new(client: kube::Client) -> Self {
         WIDGET_VIEWS.node.list.inc();

src/widget/pod.rs

@@ -29,7 +29,7 @@ pub struct List {
 
 impl List {
     #[allow(clippy::blocks_in_conditions)]
-    #[tracing::instrument(skip(client), fields(activity = "pod.list"))]
+    #[tracing::instrument(skip_all, fields(activity = "pod.list"))]
     pub fn new(client: kube::Client) -> Self {
         WIDGET_VIEWS.pod.list.inc();
 

src/widget/pod/shell.rs

@@ -212,7 +212,7 @@ struct Exec {
 #[async_trait::async_trait]
 impl Raw for Exec {
     #[allow(clippy::blocks_in_conditions)]
-    #[tracing::instrument(skip(self, stdin, stdout), fields(activity = "pod.exec"))]
+    #[tracing::instrument(skip_all, fields(activity = "pod.exec"))]
     async fn start(
         &mut self,
         stdin: &mut UnboundedReceiver<Event>,

src/widget/table.rs

@@ -12,6 +12,7 @@ use ratatui::{
     Frame,
 };
 use tachyonfx::{fx, EffectTimer, Interpolation};
+use tracing::Level;
 
 use super::{
     error::Error,
@@ -148,6 +149,7 @@ impl<S> Widget for Table<S>
 where
     S: Items,
 {
+    #[tracing::instrument(ret(level = tracing::Level::TRACE), skip_all, fields(name = self._name()))]
     fn dispatch(&mut self, event: &Event, _: &Buffer, area: Rect) -> Result<Broadcast> {
         let Some(key) = event.key() else {
             return Ok(Broadcast::Ignored);
@@ -260,6 +262,7 @@ impl Filtered {
 }
 
 impl Widget for Filtered {
+    #[tracing::instrument(ret(level = Level::TRACE), skip_all, fields(name = self._name()))]
     fn dispatch(&mut self, event: &Event, buffer: &Buffer, area: Rect) -> Result<Broadcast> {
         match self.view.dispatch(event, buffer, area) {
             Ok(Broadcast::Selected(idx)) => {
@@ -268,22 +271,32 @@ impl Widget for Filtered {
                 Ok(Broadcast::Consumed)
             }
             Ok(Broadcast::Ignored) => {
-                if let Some(Keypress::Printable('/')) = event.key() {
-                    TABLE_FILTER.inc();
-
-                    self.view.push(
-                        Text::builder()
-                            .title("Filter")
-                            .content(self.filter.clone())
-                            .build()
-                            .boxed()
-                            .into(),
-                    );
-
-                    Ok(Broadcast::Consumed)
-                } else {
-                    Ok(Broadcast::Ignored)
+                let Some(Keypress::Printable('/')) = event.key() else {
+                    return Ok(Broadcast::Ignored);
+                };
+
+                // If there's more than one widget in the view, either there's already a filter
+                // or a detail is being drawn. In either case, don't create a new filter. The
+                // fact that this exists is unfortunate and suggests that the abstractions here
+                // are wrong. If this continues, especially in this component, it is likely time
+                // to figure out a better abstraction. Note, I've tried a couple and none have
+                // worked very well.
+                if self.view.len() > 1 {
+                    return Ok(Broadcast::Ignored);
                 }
+
+                TABLE_FILTER.inc();
+
+                self.view.push(
+                    Text::builder()
+                        .title("Filter")
+                        .content(self.filter.clone())
+                        .build()
+                        .boxed()
+                        .into(),
+                );
+
+                Ok(Broadcast::Consumed)
             }
             Ok(x) => Ok(x),
             Err(e) => {

src/widget/tabs.rs

@@ -58,6 +58,7 @@ impl Bar {
 }
 
 impl Widget for Bar {
+    #[tracing::instrument(ret(level = tracing::Level::TRACE), skip_all, fields(name = self._name()))]
     fn dispatch(&mut self, event: &Event, _: &Buffer, area: Rect) -> Result<Broadcast> {
         let Some(key) = event.key() else {
             return Ok(Broadcast::Ignored);
@@ -215,6 +216,7 @@ impl TabbedView {
 }
 
 impl Widget for TabbedView {
+    #[tracing::instrument(ret(level = tracing::Level::TRACE), skip_all, fields(name = self._name()))]
     fn dispatch(&mut self, event: &Event, buffer: &Buffer, area: Rect) -> Result<Broadcast> {
         match self.view.dispatch(event, buffer, area)? {
             Broadcast::Selected(idx) => {