make script stderr print into relay logs

docs/POLICY_USAGE_GUIDE.md

@@ -369,13 +369,15 @@ Ensure scripts are executable and have appropriate permissions.
 
 Scripts MUST write ONLY JSON responses to stdout. Any other output (debug messages, logs, etc.) will break the JSONL protocol and cause errors.
 
+**Debug Output**: Use stderr for debug messages - all stderr output from policy scripts is automatically logged to the relay log with the prefix `[policy script /path/to/script]`.
+
 ```javascript
 // ❌ WRONG - This will cause "broken pipe" errors
 console.log("Policy script starting...");  // This goes to stdout!
 console.log(JSON.stringify(response));     // Correct
 
 // ✅ CORRECT - Use stderr or file for debug output
-console.error("Policy script starting...");  // This goes to stderr (OK)
+console.error("Policy script starting...");  // This goes to stderr (appears in relay log)
 fs.appendFileSync('/tmp/policy.log', 'Starting...\n');  // This goes to file (OK)
 console.log(JSON.stringify(response));      // Stdout for JSON only
 ```
@@ -529,13 +531,11 @@ Expected output (valid JSON only):
 ```javascript
 #!/usr/bin/env node
 
-const fs = require('fs');
 const readline = require('readline');
 
-// Use stderr or file for debug logging
+// Use stderr for debug logging - appears in relay log automatically
-const logFile = '/tmp/policy-debug.log';
 function debug(msg) {
-  fs.appendFileSync(logFile, `${Date.now()}: ${msg}\n`);
+  console.error(`[policy] ${msg}`);
 }
 
 // Create readline interface
@@ -551,11 +551,15 @@ debug('Policy script started');
 rl.on('line', (line) => {
   try {
     const event = JSON.parse(line);
-    debug(`Processing event ${event.id}`);
+    debug(`Processing event ${event.id}, kind: ${event.kind}, access: ${event.access_type}`);
 
     // Your policy logic here
     const action = shouldAccept(event) ? 'accept' : 'reject';
 
+    if (action === 'reject') {
+      debug(`Rejected event ${event.id}: policy violation`);
+    }
+
     // ONLY JSON to stdout
     console.log(JSON.stringify({
       id: event.id,
@@ -581,10 +585,30 @@ rl.on('close', () => {
 
 function shouldAccept(event) {
   // Your policy logic
-  return !event.content.toLowerCase().includes('spam');
+  if (event.content.toLowerCase().includes('spam')) {
+    return false;
+  }
+
+  // Different logic for read vs write
+  if (event.access_type === 'write') {
+    // Write control logic
+    return event.content.length < 10000;
+  } else if (event.access_type === 'read') {
+    // Read control logic
+    return true; // Allow all reads
+  }
+
+  return true;
 }
 ```
 
+**Relay Log Output Example:**
+```
+INFO [policy script /home/orly/.config/ORLY/policy.js] [policy] Policy script started
+INFO [policy script /home/orly/.config/ORLY/policy.js] [policy] Processing event abc123, kind: 1, access: write
+INFO [policy script /home/orly/.config/ORLY/policy.js] [policy] Processing event def456, kind: 1, access: read
+```
+
 #### Event Fields
 
 Scripts receive additional context fields:

pkg/policy/policy.go

@@ -635,7 +635,17 @@ func (sr *ScriptRunner) logOutput(stdout, stderr io.ReadCloser) {
 
 	// Only log stderr, stdout is used by readResponses
 	go func() {
-		io.Copy(os.Stderr, stderr)
+		scanner := bufio.NewScanner(stderr)
+		for scanner.Scan() {
+			line := scanner.Text()
+			if line != "" {
+				// Log script stderr output through relay logging system
+				log.I.F("[policy script %s] %s", sr.scriptPath, line)
+			}
+		}
+		if err := scanner.Err(); chk.E(err) {
+			log.E.F("error reading stderr from policy script %s: %v", sr.scriptPath, err)
+		}
 	}()
 }
 

pkg/version/version

@@ -1 +1 @@
-v0.27.6
+v0.27.7

scripts/docker-policy/README.md

@@ -26,21 +26,19 @@ test-docker-policy/
 6. **Verifies** that `cs-policy.js` created `/home/orly/cs-policy-output.txt`
 7. **Reports** success or failure
 
-## How cs-policy.js Works
+## How cs-policy-daemon.js Works
 
-The policy script writes a timestamped message to `/home/orly/cs-policy-output.txt` each time it's executed:
+The policy script is a long-lived process that:
+1. Reads events from stdin (one JSON event per line)
+2. Processes each event and returns a JSON response to stdout
+3. Logs debug information to:
+   - `/home/orly/cs-policy-output.txt` (file output)
+   - stderr (appears in relay log with prefix `[policy script /path]`)
 
-```javascript
+**Key Features:**
-#!/usr/bin/env node
+- Logs event details including kind, ID, and access type (read/write)
-const fs = require('fs')
+- Writes debug output to stderr which appears in the relay log
-const filePath = '/home/orly/cs-policy-output.txt'
+- Returns JSON responses to stdout for policy decisions
-
-if (fs.existsSync(filePath)) {
-    fs.appendFileSync(filePath, `${Date.now()}: Hey there!\n`)
-} else {
-    fs.writeFileSync(filePath, `${Date.now()}: Hey there!\n`)
-}
-```
 
 ## Quick Start
 

scripts/docker-policy/cs-policy-daemon.js

@@ -12,13 +12,14 @@ const rl = readline.createInterface({
   terminal: false
 });
 
-// Log that script started
+// Log that script started - to both file and stderr
 fs.appendFileSync(filePath, `${Date.now()}: Policy script started\n`);
+console.error('[cs-policy] Policy script started');
 
 // Process each line of input (policy events)
 rl.on('line', (line) => {
   try {
-    // Log that we received an event
+    // Log that we received an event (to file)
     fs.appendFileSync(filePath, `${Date.now()}: Received event: ${line.substring(0, 100)}...\n`);
 
     // Parse the policy event
@@ -27,7 +28,11 @@ rl.on('line', (line) => {
     // Log event details including access type
     const accessType = event.access_type || 'unknown';
     const eventKind = event.kind || 'unknown';
-    fs.appendFileSync(filePath, `${Date.now()}: Event ID: ${event.id || 'unknown'}, Kind: ${eventKind}, Access: ${accessType}\n`);
+    const eventId = event.id || 'unknown';
+
+    // Log to both file and stderr (stderr appears in relay log)
+    fs.appendFileSync(filePath, `${Date.now()}: Event ID: ${eventId}, Kind: ${eventKind}, Access: ${accessType}\n`);
+    console.error(`[cs-policy] Processing event ${eventId.substring(0, 8)}, kind: ${eventKind}, access: ${accessType}`);
 
     // Respond with "accept" to allow the event
     const response = {
@@ -38,8 +43,9 @@ rl.on('line', (line) => {
 
     console.log(JSON.stringify(response));
   } catch (err) {
-    // Log errors
+    // Log errors to both file and stderr
     fs.appendFileSync(filePath, `${Date.now()}: Error: ${err.message}\n`);
+    console.error(`[cs-policy] Error processing event: ${err.message}`);
 
     // Reject on error
     console.log(JSON.stringify({
@@ -51,4 +57,5 @@ rl.on('line', (line) => {
 
 rl.on('close', () => {
   fs.appendFileSync(filePath, `${Date.now()}: Policy script stopped\n`);
+  console.error('[cs-policy] Policy script stopped');
 });