Browse Source

make script stderr print into relay logs

main
mleku 2 months ago
parent
commit
3e7cc01d27
No known key found for this signature in database
  1. 38
      docs/POLICY_USAGE_GUIDE.md
  2. 12
      pkg/policy/policy.go
  3. 2
      pkg/version/version
  4. 28
      scripts/docker-policy/README.md
  5. 15
      scripts/docker-policy/cs-policy-daemon.js

38
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. 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 ```javascript
// ❌ WRONG - This will cause "broken pipe" errors // ❌ WRONG - This will cause "broken pipe" errors
console.log("Policy script starting..."); // This goes to stdout! console.log("Policy script starting..."); // This goes to stdout!
console.log(JSON.stringify(response)); // Correct console.log(JSON.stringify(response)); // Correct
// ✅ CORRECT - Use stderr or file for debug output // ✅ 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) fs.appendFileSync('/tmp/policy.log', 'Starting...\n'); // This goes to file (OK)
console.log(JSON.stringify(response)); // Stdout for JSON only console.log(JSON.stringify(response)); // Stdout for JSON only
``` ```
@ -529,13 +531,11 @@ Expected output (valid JSON only):
```javascript ```javascript
#!/usr/bin/env node #!/usr/bin/env node
const fs = require('fs');
const readline = require('readline'); 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) { function debug(msg) {
fs.appendFileSync(logFile, `${Date.now()}: ${msg}\n`); console.error(`[policy] ${msg}`);
} }
// Create readline interface // Create readline interface
@ -551,11 +551,15 @@ debug('Policy script started');
rl.on('line', (line) => { rl.on('line', (line) => {
try { try {
const event = JSON.parse(line); 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 // Your policy logic here
const action = shouldAccept(event) ? 'accept' : 'reject'; const action = shouldAccept(event) ? 'accept' : 'reject';
if (action === 'reject') {
debug(`Rejected event ${event.id}: policy violation`);
}
// ONLY JSON to stdout // ONLY JSON to stdout
console.log(JSON.stringify({ console.log(JSON.stringify({
id: event.id, id: event.id,
@ -581,10 +585,30 @@ rl.on('close', () => {
function shouldAccept(event) { function shouldAccept(event) {
// Your policy logic // 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 #### Event Fields
Scripts receive additional context fields: Scripts receive additional context fields:

12
pkg/policy/policy.go

@ -635,7 +635,17 @@ func (sr *ScriptRunner) logOutput(stdout, stderr io.ReadCloser) {
// Only log stderr, stdout is used by readResponses // Only log stderr, stdout is used by readResponses
go func() { 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)
}
}() }()
} }

2
pkg/version/version

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

28
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` 6. **Verifies** that `cs-policy.js` created `/home/orly/cs-policy-output.txt`
7. **Reports** success or failure 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)
```javascript 2. Processes each event and returns a JSON response to stdout
#!/usr/bin/env node 3. Logs debug information to:
const fs = require('fs') - `/home/orly/cs-policy-output.txt` (file output)
const filePath = '/home/orly/cs-policy-output.txt' - stderr (appears in relay log with prefix `[policy script /path]`)
if (fs.existsSync(filePath)) { **Key Features:**
fs.appendFileSync(filePath, `${Date.now()}: Hey there!\n`) - Logs event details including kind, ID, and access type (read/write)
} else { - Writes debug output to stderr which appears in the relay log
fs.writeFileSync(filePath, `${Date.now()}: Hey there!\n`) - Returns JSON responses to stdout for policy decisions
}
```
## Quick Start ## Quick Start

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

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

Loading…
Cancel
Save