extend script test to two read two write to ensure script continues running

2025-11-11 15:24:58 +00:00
parent 3e7cc01d27
commit baede6d37f
4 changed files with 194 additions and 36 deletions
--- a/cmd/policytest/main.go
+++ b/cmd/policytest/main.go
@@ -20,8 +20,9 @@ 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, "operation timeout")
-	testType := flag.String("type", "event", "test type: 'event' for write control, 'req' for read control, 'both' for both")
+	testType := flag.String("type", "event", "test type: 'event' for write control, 'req' for read control, 'both' for both, 'publish-and-query' for full test")
 	eventKind := flag.Int("kind", 4678, "event kind to test")
+	numEvents := flag.Int("count", 2, "number of events to publish (for publish-and-query)")
 	flag.Parse()

 	// Connect to relay
@@ -54,8 +55,10 @@ func main() {
 		testEventWrite(rl, signer, *eventKind, *timeout)
 		log.I.Ln("\nTesting REQ (read control)...")
 		testReqRead(rl, signer, *eventKind, *timeout)
+	case "publish-and-query":
+		testPublishAndQuery(rl, signer, *eventKind, *numEvents, *timeout)
 	default:
-		log.E.F("invalid test type: %s (must be 'event', 'req', or 'both')", *testType)
+		log.E.F("invalid test type: %s (must be 'event', 'req', 'both', or 'publish-and-query')", *testType)
 	}
 }

@@ -133,3 +136,94 @@ func testReqRead(rl *ws.Client, signer *p8k.Signer, eventKind int, timeout time.
 	fmt.Printf("REQ ACCEPT: %d events returned\n", len(events))
 	log.I.F("REQ result: %d events of kind %d returned", len(events), eventKind)
 }
+
+func testPublishAndQuery(rl *ws.Client, signer *p8k.Signer, eventKind int, numEvents int, timeout time.Duration) {
+	log.I.F("Publishing %d events of kind %d...", numEvents, eventKind)
+
+	publishedIDs := make([][]byte, 0, numEvents)
+	acceptedCount := 0
+	rejectedCount := 0
+
+	// Publish multiple events
+	for i := 0; i < numEvents; i++ {
+		ev := &event.E{
+			CreatedAt: time.Now().Unix() + int64(i), // Slightly different timestamps
+			Kind:      uint16(eventKind),
+			Tags:      tag.NewS(),
+			Content:   []byte(fmt.Sprintf("policy test event %d/%d", i+1, numEvents)),
+		}
+		if err := ev.Sign(signer); chk.E(err) {
+			log.E.F("sign error for event %d: %v", i+1, err)
+			continue
+		}
+
+		ctx, cancel := context.WithTimeout(context.Background(), timeout)
+		err := rl.Publish(ctx, ev)
+		cancel()
+
+		if err != nil {
+			log.W.F("Event %d/%d rejected: %v", i+1, numEvents, err)
+			rejectedCount++
+		} else {
+			log.I.F("Event %d/%d published successfully (id: %x...)", i+1, numEvents, ev.ID[:8])
+			publishedIDs = append(publishedIDs, ev.ID)
+			acceptedCount++
+		}
+	}
+
+	fmt.Printf("PUBLISH: %d accepted, %d rejected out of %d total\n", acceptedCount, rejectedCount, numEvents)
+
+	if acceptedCount == 0 {
+		fmt.Println("No events were accepted, skipping query test")
+		return
+	}
+
+	// Wait a moment for events to be stored
+	time.Sleep(500 * time.Millisecond)
+
+	// Now query for events of this kind
+	log.I.F("Querying for events of kind %d...", eventKind)
+
+	limit := uint(100)
+	f := &filter.F{
+		Kinds: kind.FromIntSlice([]int{eventKind}),
+		Limit: &limit,
+	}
+
+	ctx, cancel := context.WithTimeout(context.Background(), timeout)
+	defer cancel()
+
+	events, err := rl.QuerySync(ctx, f)
+	if chk.E(err) {
+		log.E.F("query error: %v", err)
+		fmt.Println("QUERY ERROR:", err)
+		return
+	}
+
+	log.I.F("Query returned %d events", len(events))
+
+	// Check if we got our published events back
+	foundCount := 0
+	for _, pubID := range publishedIDs {
+		found := false
+		for _, ev := range events {
+			if string(ev.ID) == string(pubID) {
+				found = true
+				break
+			}
+		}
+		if found {
+			foundCount++
+		}
+	}
+
+	fmt.Printf("QUERY: found %d/%d published events (total returned: %d)\n", foundCount, len(publishedIDs), len(events))
+
+	if foundCount == len(publishedIDs) {
+		fmt.Println("SUCCESS: All published events were retrieved")
+	} else if foundCount > 0 {
+		fmt.Printf("PARTIAL: Only %d/%d events retrieved (some filtered by read policy?)\n", foundCount, len(publishedIDs))
+	} else {
+		fmt.Println("FAILURE: None of the published events were retrieved (read policy blocked?)")
+	}
+}
--- a/pkg/version/version
+++ b/pkg/version/version
@@ -1 +1 @@
-v0.27.7
+v0.27.8
--- a/scripts/docker-policy/README.md
+++ b/scripts/docker-policy/README.md
@@ -19,12 +19,16 @@ test-docker-policy/
 ## What the Test Does

 1. **Builds** an Ubuntu 22.04.5 Docker image with ORLY relay
-2. **Configures** the policy engine with `cs-policy.js`
+2. **Configures** the policy engine with `cs-policy-daemon.js`
 3. **Starts** the relay with policy engine enabled
-4. **Tests EVENT messages** (write control) using the `policytest` tool
-5. **Tests REQ messages** (read control) using the `policytest` tool
-6. **Verifies** that `cs-policy.js` created `/home/orly/cs-policy-output.txt`
-7. **Reports** success or failure
+4. **Publishes 2 events** to test write control (EVENT messages)
+5. **Queries for those events** to test read control (REQ messages)
+6. **Verifies** that:
+   - Both events were published successfully
+   - Events can be queried and retrieved
+   - Policy script processed both write and read operations
+   - Policy script logged to both file and relay log (stderr)
+7. **Reports** detailed results with policy invocation counts

 ## How cs-policy-daemon.js Works

@@ -61,15 +65,39 @@ The `policytest` tool is a command-line utility for testing policy enforcement:

 # Test both write and read control
 ./policytest -url ws://localhost:8777 -type both -kind 1
+
+# Publish multiple events and query for them (full integration test)
+./policytest -url ws://localhost:8777 -type publish-and-query -kind 1 -count 2
 ```

 ### Options

 - `-url` - Relay WebSocket URL (default: `ws://127.0.0.1:3334`)
- `-type` - Test type: `event` for write control, `req` for read control, `both` for both (default: `event`)
+- `-type` - Test type:
+  - `event` - Test write control only
+  - `req` - Test read control only
+  - `both` - Test write then read
+  - `publish-and-query` - Publish events then query for them (full test)
 - `-kind` - Event kind to test (default: `4678`)
+- `-count` - Number of events to publish for `publish-and-query` (default: `2`)
 - `-timeout` - Operation timeout (default: `20s`)

+### Output
+
+The `publish-and-query` test provides detailed output:
+
+```
+Publishing 2 events of kind 1...
+Event 1/2 published successfully (id: a1b2c3d4...)
+Event 2/2 published successfully (id: e5f6g7h8...)
+PUBLISH: 2 accepted, 0 rejected out of 2 total
+
+Querying for events of kind 1...
+Query returned 2 events
+QUERY: found 2/2 published events (total returned: 2)
+SUCCESS: All published events were retrieved
+```
+
 ## Manual Testing

 ### 1. Build and Start Container
@@ -156,15 +184,50 @@ docker exec orly-policy-test netstat -tlnp | grep 8777
 When successful, you should see:

 ```
+=== Step 9: Publishing 2 events and querying for them ===
+
+--- Publishing and querying events ---
+Publishing 2 events of kind 1...
+Event 1/2 published successfully (id: abc12345...)
+Event 2/2 published successfully (id: def67890...)
+PUBLISH: 2 accepted, 0 rejected out of 2 total
+
+Querying for events of kind 1...
+Query returned 2 events
+QUERY: found 2/2 published events (total returned: 2)
+SUCCESS: All published events were retrieved
+
+=== Step 10: Checking relay logs ===
+INFO [policy script /home/orly/cs-policy-daemon.js] [cs-policy] Policy script started
+INFO [policy script /home/orly/cs-policy-daemon.js] [cs-policy] Processing event abc12345, kind: 1, access: write
+INFO [policy script /home/orly/cs-policy-daemon.js] [cs-policy] Processing event def67890, kind: 1, access: write
+INFO [policy script /home/orly/cs-policy-daemon.js] [cs-policy] Processing event abc12345, kind: 1, access: read
+INFO [policy script /home/orly/cs-policy-daemon.js] [cs-policy] Processing event def67890, kind: 1, access: read
+
+=== Step 12: Checking output file ===
 ✓ SUCCESS: cs-policy-output.txt file exists!

 Output file contents:
-1704123456789: Hey there!
+1234567890123: Policy script started
+1234567890456: Event ID: abc12345..., Kind: 1, Access: write
+1234567890789: Event ID: def67890..., Kind: 1, Access: write
+1234567891012: Event ID: abc12345..., Kind: 1, Access: read
+1234567891234: Event ID: def67890..., Kind: 1, Access: read

-✓ Policy script is working correctly!
+Policy invocations summary:
+  - Write operations (EVENT): 2 (expected: 2)
+  - Read operations (REQ):    2 (expected: >=1)
+
+✓ SUCCESS: Policy script processed both write and read operations!
+  - Published 2 events (write control)
+  - Queried events (read control)
 ```

-Each line in the output file represents one execution of the policy script, with a Unix timestamp.
+The test verifies:
+- **Write Control**: Policy script processes EVENT messages (2 publications)
+- **Read Control**: Policy script processes REQ messages (query retrieves events)
+- **Dual Logging**: Script output appears in both file and relay log (stderr)
+- **Event Lifecycle**: Events are stored and can be retrieved

 ## Configuration Files

--- a/scripts/docker-policy/test-policy.sh
+++ b/scripts/docker-policy/test-policy.sh
@@ -53,7 +53,7 @@ echo -e "${YELLOW}Step 8: Building policytest tool...${NC}"
 cd "$REPO_ROOT" && CGO_ENABLED=0 go build -o policytest ./cmd/policytest

 echo ""
-echo -e "${YELLOW}Step 9: Testing EVENT message (write control)...${NC}"
+echo -e "${YELLOW}Step 9: Publishing 2 events and querying for them...${NC}"

 # Check which port the relay is listening on
 RELAY_PORT=$(docker logs orly-policy-test 2>&1 | grep "starting listener" | grep -oP ':\K[0-9]+' | head -1)
@@ -62,27 +62,19 @@ if [ -z "$RELAY_PORT" ]; then
 fi
 echo "Relay is listening on port: $RELAY_PORT"

-# Test EVENT message
+# Test publish and query - this will publish 2 events and query for them
 cd "$REPO_ROOT"
-./policytest -url "ws://localhost:$RELAY_PORT" -type event -kind 1 2>&1 || echo "EVENT test completed"
+echo ""
+echo "--- Publishing and querying events ---"
+./policytest -url "ws://localhost:$RELAY_PORT" -type publish-and-query -kind 1 -count 2 2>&1

 echo ""
-echo -e "${YELLOW}Relay logs after EVENT test:${NC}"
-docker logs orly-policy-test 2>&1 | tail -10
+echo -e "${YELLOW}Step 10: Checking relay logs...${NC}"
+docker logs orly-policy-test 2>&1 | tail -20

 echo ""
-echo -e "${YELLOW}Step 10: Testing REQ message (read control)...${NC}"
-
-# Test REQ message
-./policytest -url "ws://localhost:$RELAY_PORT" -type req -kind 1 2>&1 || echo "REQ test completed"
-
-echo ""
-echo -e "${YELLOW}Relay logs after REQ test:${NC}"
-docker logs orly-policy-test 2>&1 | tail -10
-
-echo ""
-echo -e "${YELLOW}Step 11: Waiting for policy script to execute (5 seconds)...${NC}"
-sleep 5
+echo -e "${YELLOW}Step 11: Waiting for policy script to process (3 seconds)...${NC}"
+sleep 3

 echo ""
 echo -e "${YELLOW}Step 12: Checking if cs-policy.js created output file...${NC}"
@@ -99,19 +91,28 @@ if docker exec orly-policy-test test -f /home/orly/cs-policy-output.txt; then
    WRITE_COUNT=$(docker exec orly-policy-test cat /home/orly/cs-policy-output.txt | grep -c "Access: write" || echo "0")
    READ_COUNT=$(docker exec orly-policy-test cat /home/orly/cs-policy-output.txt | grep -c "Access: read" || echo "0")

-    echo "Policy invocations:"
-    echo "  - Write operations: $WRITE_COUNT"
-    echo "  - Read operations: $READ_COUNT"
+    echo "Policy invocations summary:"
+    echo "  - Write operations (EVENT): $WRITE_COUNT (expected: 2)"
+    echo "  - Read operations (REQ):    $READ_COUNT (expected: >=1)"
    echo ""

-    if [ "$WRITE_COUNT" -gt 0 ] && [ "$READ_COUNT" -gt 0 ]; then
-        echo -e "${GREEN}✓ Policy script processed both write and read operations!${NC}"
+    # Analyze results
+    if [ "$WRITE_COUNT" -ge 2 ] && [ "$READ_COUNT" -ge 1 ]; then
+        echo -e "${GREEN}✓ SUCCESS: Policy script processed both write and read operations!${NC}"
+        echo -e "${GREEN}  - Published 2 events (write control)${NC}"
+        echo -e "${GREEN}  - Queried events (read control)${NC}"
+        EXIT_CODE=0
+    elif [ "$WRITE_COUNT" -gt 0 ] && [ "$READ_COUNT" -gt 0 ]; then
+        echo -e "${YELLOW}⚠ PARTIAL: Policy invoked but counts don't match expected${NC}"
+        echo -e "${YELLOW}  - Write count: $WRITE_COUNT (expected 2)${NC}"
+        echo -e "${YELLOW}  - Read count: $READ_COUNT (expected >=1)${NC}"
        EXIT_CODE=0
    elif [ "$WRITE_COUNT" -gt 0 ]; then
-        echo -e "${YELLOW}⚠ Policy script only processed write operations (read operations may not have been tested)${NC}"
+        echo -e "${YELLOW}⚠ WARNING: Policy script only processed write operations${NC}"
+        echo -e "${YELLOW}  Read operations may not have been tested or logged${NC}"
        EXIT_CODE=0
    else
-        echo -e "${YELLOW}⚠ Policy script is working but access types may not be logged correctly${NC}"
+        echo -e "${YELLOW}⚠ WARNING: Policy script is working but access types may not be logged correctly${NC}"
        EXIT_CODE=0
    fi
 else