diff --git a/cmd/policytest/main.go b/cmd/policytest/main.go index 305f441..86f42b3 100644 --- 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?)") + } +} diff --git a/pkg/version/version b/pkg/version/version index d296010..76ba65b 100644 --- a/pkg/version/version +++ b/pkg/version/version @@ -1 +1 @@ -v0.27.7 \ No newline at end of file +v0.27.8 \ No newline at end of file diff --git a/scripts/docker-policy/README.md b/scripts/docker-policy/README.md index c349add..92b260b 100644 --- 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 diff --git a/scripts/docker-policy/test-policy.sh b/scripts/docker-policy/test-policy.sh index eeca83f..5cc1526 100755 --- 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