Enhance logging and add policy test client

- Refactored logOutput function to trace-log stdout and stderr lines for better debugging.
- Introduced a new policy test client in cmd/policytest/main.go to publish events and check policy responses.
- Added a script to run the policy test, ensuring proper cleanup and error handling.
- Updated policy event processing to ensure newline-terminated JSON for compatibility with shell-readers.

app/sprocket.go

@@ -472,12 +472,28 @@ func (sm *SprocketManager) logOutput(stdout, stderr io.ReadCloser) {
 	defer stdout.Close()
 	defer stderr.Close()
 
+	// Trace-log stdout lines
 	go func() {
-		io.Copy(os.Stdout, stdout)
+		scanner := bufio.NewScanner(stdout)
+		for scanner.Scan() {
+			line := scanner.Text()
+			if line == "" {
+				continue
+			}
+			log.T.F("sprocket stdout: %s", line)
+		}
 	}()
 
+	// Trace-log stderr lines
 	go func() {
-		io.Copy(os.Stderr, stderr)
+		scanner := bufio.NewScanner(stderr)
+		for scanner.Scan() {
+			line := scanner.Text()
+			if line == "" {
+				continue
+			}
+			log.T.F("sprocket stderr: %s", line)
+		}
 	}()
 }
 

cmd/policytest/main.go

@@ -0,0 +1,60 @@
+package main
+
+import (
+	"context"
+	"flag"
+	"fmt"
+	"time"
+
+	"lol.mleku.dev/chk"
+	"lol.mleku.dev/log"
+	"next.orly.dev/pkg/crypto/p256k"
+	"next.orly.dev/pkg/encoders/event"
+	"next.orly.dev/pkg/encoders/kind"
+	"next.orly.dev/pkg/encoders/tag"
+	"next.orly.dev/pkg/protocol/ws"
+)
+
+func main() {
+	var err error
+	url := flag.String("url", "ws://127.0.0.1:3334", "relay websocket URL")
+	timeout := flag.Duration("timeout", 20*time.Second, "publish timeout")
+	flag.Parse()
+
+	// Minimal client that publishes a single kind 4678 event and reports OK/err
+	var rl *ws.Client
+	if rl, err = ws.RelayConnect(context.Background(), *url); chk.E(err) {
+		log.E.F("connect error: %v", err)
+		return
+	}
+	defer rl.Close()
+
+	signer := &p256k.Signer{}
+	if err = signer.Generate(); chk.E(err) {
+		log.E.F("signer generate error: %v", err)
+		return
+	}
+
+	ev := &event.E{
+		CreatedAt: time.Now().Unix(),
+		Kind:      kind.K{K: 4678}.K, // arbitrary custom kind
+		Tags:      tag.NewS(),
+		Content:   []byte("policy test: expect rejection"),
+	}
+	if err = ev.Sign(signer); chk.E(err) {
+		log.E.F("sign error: %v", err)
+		return
+	}
+
+	ctx, cancel := context.WithTimeout(context.Background(), *timeout)
+	defer cancel()
+
+	if err = rl.Publish(ctx, ev); err != nil {
+		// Expected path if policy rejects: client returns error with reason (from OK false)
+		fmt.Println("policy reject:", err)
+		return
+	}
+
+	log.I.Ln("publish result: accepted")
+	fmt.Println("ACCEPT")
+}

pkg/policy/policy.go

@@ -684,8 +684,8 @@ func (pm *PolicyManager) ProcessEvent(evt *PolicyEvent) (*PolicyResponse, error)
 		return nil, fmt.Errorf("failed to serialize event: %v", err)
 	}
 
-	// Send the event JSON to the policy script
-	if _, err := stdin.Write(eventJSON); chk.E(err) {
+	// Send the event JSON to the policy script (newline-terminated for shell-readers)
+	if _, err := stdin.Write(append(eventJSON, '\n')); chk.E(err) {
 		return nil, fmt.Errorf("failed to write event to policy: %v", err)
 	}
 
@@ -734,13 +734,9 @@ func (pm *PolicyManager) readResponses() {
 
 // logOutput logs the output from stdout and stderr
 func (pm *PolicyManager) logOutput(stdout, stderr io.ReadCloser) {
-	defer stdout.Close()
 	defer stderr.Close()
 
-	go func() {
-		io.Copy(os.Stdout, stdout)
-	}()
-
+	// Only log stderr, stdout is used by readResponses
 	go func() {
 		io.Copy(os.Stderr, stderr)
 	}()

pkg/protocol/ws/client.go

@@ -374,14 +374,9 @@ func (r *Client) ConnectWithTLS(
 					if env, message, err = okenvelope.Parse(message); chk.E(err) {
 						continue
 					}
-					if okCallback, exist := r.okCallbacks.Load(string(env.EventID)); exist {
+					eventIDHex := hex.Enc(env.EventID)
+					if okCallback, exist := r.okCallbacks.Load(eventIDHex); exist {
 						okCallback(env.OK, env.ReasonString())
-					} else {
-						// log.I.F(
-						// 	"{%s} got an unexpected OK message for event %0x",
-						// 	r.URL,
-						// 	env.EventID,
-						// )
 					}
 				}
 			}

pkg/version/version

@@ -1 +1 @@
-v0.17.1
+v0.17.2

scripts/run-policy-test.sh

@@ -0,0 +1,53 @@
+#!/bin/bash
+set -euo pipefail
+
+# Config
+PORT=${PORT:-34567}
+URL=${URL:-ws://127.0.0.1:${PORT}}
+LOG=/tmp/orly-policy.out
+PID=/tmp/orly-policy.pid
+DATADIR=$(mktemp -d)
+
+cleanup() {
+  trap - EXIT
+  if [[ -f "$PID" ]]; then
+    kill -INT "$(cat "$PID")" 2>/dev/null || true
+    rm -f "$PID"
+  fi
+  rm -rf "$DATADIR"
+}
+trap cleanup EXIT
+
+echo "Building relay and test client..."
+go build -o orly .
+go build -o cmd/policytest/policytest ./cmd/policytest
+
+echo "Starting relay on ${URL} with policy enabled (data dir: ${DATADIR})..."
+ORLY_DATA_DIR="$DATADIR" \
+ORLY_PORT=${PORT} \
+ORLY_POLICY_ENABLED=true \
+ORLY_ACL_MODE=none \
+ORLY_LOG_LEVEL=trace \
+./orly >"$LOG" 2>&1 & echo $! >"$PID"
+
+sleep 1
+if ! ps -p "$(cat "$PID")" >/dev/null 2>&1; then
+  echo "Relay failed to start; logs:" >&2
+  sed -n '1,200p' "$LOG" >&2
+  exit 1
+fi
+
+echo "Running policy test against ${URL}..."
+set +e
+out=$(cmd/policytest/policytest -url "${URL}" 2>&1)
+rc=$?
+set -e
+echo "$out"
+
+# Expect rejection; return 0 if we saw REJECT, else forward exit code
+if grep -q '^REJECT:' <<<"$out"; then
+  exit 0
+fi
+exit $rc
+
+