fix: log the full request target in Rust audit and unlink the socket when chown fails (#55)

go/internal/proxy/handler_test.go

@@ -160,6 +160,56 @@ func TestHandler_ForwardsPercentEncodedQuery(t *testing.T) {
 	}
 }
 
+// #55: the audit uri is the raw request target, query and escapes included,
+// for allowed and denied requests alike.
+func TestHandlerAuditURIIsRequestTarget(t *testing.T) {
+	dir := t.TempDir()
+	os.WriteFile(filepath.Join(dir, "default.yaml"), []byte("service_name: default\nallowed_image_prefixes:\n  - scratch\n"), 0644)
+	policyManager, err := policy.NewManager(dir)
+	if err != nil {
+		t.Fatalf("NewManager failed: %v", err)
+	}
+	logPath := filepath.Join(t.TempDir(), "audit.log")
+	auditLog, err := audit.NewLogger(logPath)
+	if err != nil {
+		t.Fatalf("NewLogger failed: %v", err)
+	}
+	defer auditLog.Close()
+	h := NewHandler(NewRouter(policyManager), middleware.NewChain(false), auditLog, &recorderTransport{})
+
+	targets := []struct{ method, target, decision string }{
+		{"GET", "/containers/json?all=1", "ALLOW"},
+		{"DELETE", "/containers/a%2Fb?force=1", "DENY"},
+	}
+	for _, tc := range targets {
+		h.ServeHTTP(httptest.NewRecorder(), httptest.NewRequest(tc.method, tc.target, nil))
+	}
+
+	data, err := os.ReadFile(logPath)
+	if err != nil {
+		t.Fatalf("reading audit log: %v", err)
+	}
+	lines := strings.Split(strings.TrimSpace(string(data)), "\n")
+	if len(lines) != len(targets) {
+		t.Fatalf("audit log has %d lines, want %d:\n%s", len(lines), len(targets), data)
+	}
+	for i, tc := range targets {
+		var entry struct {
+			URI      string `json:"uri"`
+			Decision string `json:"decision"`
+		}
+		if err := json.Unmarshal([]byte(lines[i]), &entry); err != nil {
+			t.Fatalf("line %d: %v", i, err)
+		}
+		if entry.Decision != tc.decision {
+			t.Errorf("%s %s: decision = %q, want %q", tc.method, tc.target, entry.Decision, tc.decision)
+		}
+		if entry.URI != tc.target {
+			t.Errorf("%s %s: audit uri = %q, want %q", tc.method, tc.target, entry.URI, tc.target)
+		}
+	}
+}
+
 func TestHandler_CreateContainerValid(t *testing.T) {
 	rec := &recorderTransport{}
 	h := newTestHandler(t, map[string]string{

go/main_test.go

@@ -879,4 +879,7 @@ func TestUnixListenerChownEPERMNamesGroup(t *testing.T) {
 	if want := "the proxy's user must be a member of it"; !strings.Contains(err.Error(), want) {
 		t.Fatalf("error = %q, want it to contain %q", err, want)
 	}
+	if _, err := os.Lstat(path); !errors.Is(err, os.ErrNotExist) {
+		t.Fatalf("socket left on disk after chown failed: Lstat err = %v", err)
+	}
 }

rs/src/handler.rs

@@ -35,6 +35,12 @@ impl Handler {
         let (parts, body) = req.into_parts();
         let method = parts.method.to_string();
         let path = parts.uri.path().to_string();
+        let target = parts
+            .uri
+            .path_and_query()
+            .map(|pq| pq.as_str())
+            .unwrap_or(&path)
+            .to_string();
         let full_uri = parts.uri.to_string();
         let headers = parts.headers.clone();
         let version = parts.version;
@@ -62,7 +68,7 @@ impl Handler {
         if route.action == Action::Deny {
             let msg = route.deny_msg.unwrap_or_default();
             warn!("denied {} {}: {}", method, path, msg);
-            self.audit.deny(&method, &path, &msg);
+            self.audit.deny(&method, &target, &msg);
             return Response::builder()
                 .status(StatusCode::FORBIDDEN)
                 .body(Full::new(Bytes::from(msg)))
@@ -74,7 +80,7 @@ impl Handler {
                 let result = self.chain.execute(&method, &path, policy, body);
                 if !result.allowed {
                     warn!("denied by middleware {} {}: {}", method, path, result.reason);
-                    self.audit.deny(&method, &path, &result.reason);
+                    self.audit.deny(&method, &target, &result.reason);
                     return Response::builder()
                         .status(StatusCode::FORBIDDEN)
                         .body(Full::new(Bytes::from(result.reason)))
@@ -87,7 +93,7 @@ impl Handler {
         }
 
         info!("allowed {} {}", method, path);
-        self.audit.allow(&method, &path);
+        self.audit.allow(&method, &target);
 
         let mut forwarded = Request::builder()
             .method(method.as_str())
@@ -449,4 +455,53 @@ mod tests {
         let uri = captured.as_ref().expect("expected request to be forwarded");
         assert_eq!(uri.query(), Some(query));
     }
+
+    /// #55: the audit uri is the raw request target, query and escapes
+    /// included, for allowed and denied requests alike.
+    #[tokio::test]
+    async fn test_handler_audit_uri_is_request_target() {
+        let log_path = std::env::temp_dir().join(format!(
+            "handler-audit-uri-{}-{}.log",
+            std::process::id(),
+            std::time::SystemTime::now()
+                .duration_since(std::time::UNIX_EPOCH)
+                .unwrap()
+                .as_nanos()
+        ));
+        let _ = std::fs::remove_file(&log_path);
+        let manager = Manager::from_map(std::collections::HashMap::new());
+        let router = Arc::new(Router::new(manager));
+        let audit = AuditLogger::new(log_path.to_str().unwrap()).unwrap();
+        let captured_uri = Arc::new(std::sync::Mutex::new(None));
+        let transport = UriRecordingTransport { captured_uri };
+        let handler = Handler::new(router, Chain::new(false), audit, Box::new(transport));
+
+        let targets = [
+            ("GET", "/containers/json?all=1", "ALLOW"),
+            ("DELETE", "/containers/a%2Fb?force=1", "DENY"),
+        ];
+        for (method, target, _) in targets {
+            let req = Request::builder()
+                .method(method)
+                .uri(format!("http://localhost{}", target))
+                .body(Full::new(Bytes::new()))
+                .unwrap();
+            handler.handle(req).await;
+        }
+
+        let contents = std::fs::read_to_string(&log_path).unwrap();
+        let _ = std::fs::remove_file(&log_path);
+        let entries: Vec<serde_json::Value> = contents.lines().map(|l| serde_json::from_str(l).unwrap()).collect();
+        assert_eq!(entries.len(), targets.len(), "audit log:\n{}", contents);
+        let mut mismatches = Vec::new();
+        for ((method, target, decision), entry) in targets.iter().zip(&entries) {
+            if entry["decision"] != *decision || entry["uri"] != *target {
+                mismatches.push(format!(
+                    "{} {}: got {}/{}, want {:?}/{:?}",
+                    method, target, entry["decision"], entry["uri"], decision, target
+                ));
+            }
+        }
+        assert!(mismatches.is_empty(), "{}", mismatches.join("\n"));
+    }
 }

rs/src/main.rs

@@ -286,6 +286,16 @@ fn bind_unix_listener(addr: &str, gid: Option<u32>) -> io::Result<tokio::net::Un
     unsafe { libc::umask(previous) };
     let listener = listener?;
 
+    if let Err(e) = set_socket_ownership_and_mode(addr, gid) {
+        drop(listener);
+        let _ = std::fs::remove_file(addr);
+        return Err(e);
+    }
+
+    Ok(listener)
+}
+
+fn set_socket_ownership_and_mode(addr: &str, gid: Option<u32>) -> io::Result<()> {
     // Widen from 0600 to SOCKET_MODE only once ownership is correct,
     // so the socket is never reachable by the wrong group.
     if let Some(gid) = gid {
@@ -305,9 +315,7 @@ fn bind_unix_listener(addr: &str, gid: Option<u32>) -> io::Result<tokio::net::Un
         })?;
     }
     std::fs::set_permissions(addr, std::fs::Permissions::from_mode(SOCKET_MODE))
-        .map_err(|e| io::Error::new(e.kind(), format!("setting mode on {}: {}", addr, e)))?;
-
-    Ok(listener)
+        .map_err(|e| io::Error::new(e.kind(), format!("setting mode on {}: {}", addr, e)))
 }
 
 /// Picks the socket's group the way dockerd does
@@ -1283,6 +1291,12 @@ mod tests {
             err.to_string(),
             want
         );
+        let meta = std::fs::symlink_metadata(&path);
+        assert!(
+            matches!(&meta, Err(e) if e.kind() == io::ErrorKind::NotFound),
+            "socket left on disk after chown failed: symlink_metadata = {:?}",
+            meta
+        );
     }
 
     /// A clean shutdown must not leave the socket file on disk, matching Go

ts/src/handler.test.ts

@@ -1,6 +1,6 @@
 import { describe, it, beforeEach, afterEach } from "node:test";
 import assert from "node:assert/strict";
-import { mkdtempSync, writeFileSync, rmSync } from "node:fs";
+import { mkdtempSync, readFileSync, writeFileSync, rmSync } from "node:fs";
 import { join } from "node:path";
 import { tmpdir } from "node:os";
 import { Readable } from "node:stream";
@@ -186,4 +186,25 @@ describe("Handler", () => {
     assert.ok(transport.lastRequest, "expected request to be forwarded");
     assert.equal(transport.lastRequest.url, url);
   });
+
+  // #55: the audit uri is the raw request target, query and escapes included,
+  // for allowed and denied requests alike.
+  it("logs the raw request target as the audit uri", async () => {
+    const dir = makeEnv(defaultConfig);
+    const { handler } = newHandler(dir);
+    const targets = [
+      { method: "GET", target: "/containers/json?all=1", decision: "ALLOW" },
+      { method: "DELETE", target: "/containers/a%2Fb?force=1", decision: "DENY" },
+    ];
+    for (const { method, target } of targets) {
+      await handler.handle(makeRequest(method, target), makeResponse().res);
+    }
+    const lines = readFileSync(join(dir, "audit.log"), "utf-8").trim().split("\n");
+    assert.equal(lines.length, targets.length);
+    targets.forEach(({ method, target, decision }, i) => {
+      const entry = JSON.parse(lines[i]!) as { uri: string; decision: string };
+      assert.equal(entry.decision, decision, `${method} ${target}`);
+      assert.equal(entry.uri, target, `${method} ${target}`);
+    });
+  });
 });

ts/src/listen.test.ts

@@ -247,6 +247,7 @@ describe("listenOnSocket chown EPERM", () => {
           `(SupplementaryGroups= / group_add:)`,
       });
       assert.equal(server.listening, false, "server left listening after chown failed");
+      assert.equal(existsSync(path), false, "socket left on disk after chown failed");
     } finally {
       cleanup();
     }