tests: cover documented recipe claims that had no test (#19)

Author: zspitzer

.github/workflows/main.yml

@@ -257,7 +257,9 @@ jobs:
           echo "Running integration tests on Lucee ${{ matrix.lucee }}..."
           FAILED=false
           RESULTS=""
-          for test in test-websocket-client test-lifecycle-callbacks test-return-value-send test-wsclient-broadcast test-wsclients-plural test-binary-send test-close; do
+          # test-session-access parked pending LDEV-6277 (wsClient.getSession() not exposed) —
+          # re-add once the Java fix lands
+          for test in test-websocket-client test-lifecycle-callbacks test-return-value-send test-wsclient-broadcast test-wsclients-plural test-binary-send test-close test-onfirstopen-rearm test-onopen-async test-request-timeout; do
             echo ""
             echo "=============================================="
             echo "Running ${test}"
@@ -292,15 +294,15 @@ jobs:
           # visible debug info in the CI log.
           echo "=== WebSocket Test Event Logs ==="
           found=false
-          for f in /tmp/ws-*-events.log; do
+          for f in /tmp/ws-*.log; do
             [ -f "$f" ] || continue
             found=true
             echo ""
             echo "--- $f ---"
             cat "$f"
           done
           if [ "$found" = "false" ]; then
-            echo "(no event logs found — no test wrote to /tmp/ws-*-events.log)"
+            echo "(no event logs found — no test wrote to /tmp/ws-*.log)"
           fi
 
       - name: Test idleTimeout (LDEV-6219)
@@ -350,7 +352,7 @@ jobs:
             echo '```' >> $GITHUB_STEP_SUMMARY
             cat /tmp/integration-results.txt >> $GITHUB_STEP_SUMMARY || true
             echo '```' >> $GITHUB_STEP_SUMMARY
-            for test in test-websocket-client test-lifecycle-callbacks test-return-value-send test-wsclient-broadcast test-wsclients-plural test-binary-send test-close; do
+            for test in test-websocket-client test-lifecycle-callbacks test-return-value-send test-wsclient-broadcast test-wsclients-plural test-binary-send test-close test-onfirstopen-rearm test-onopen-async test-request-timeout; do
               if [ -f /tmp/${test}.txt ] && grep -q "FAILED" /tmp/${test}.txt; then
                 echo "" >> $GITHUB_STEP_SUMMARY
                 echo "#### ${test}" >> $GITHUB_STEP_SUMMARY
@@ -395,14 +397,25 @@ jobs:
             lucee-express/lucee-server/context/logs/
 
   test-config-override:
-    name: Test - Config override + reflection hot-reinstall
+    name: Test - Config override (${{ matrix.override-mode }})
     runs-on: ubuntu-latest
     needs: [build-extension]
+    strategy:
+      fail-fast: false
+      matrix:
+        include:
+          - override-mode: env-var
+            env-var-value: /tmp/ws-alt-config.json
+            java-opts: ""
+          - override-mode: jvm-arg
+            env-var-value: ""
+            java-opts: "-Dlucee.websocket.config=/tmp/ws-alt-config.json"
     env:
       LUCEE_LOGGING_FORCE_APPENDER: console
       LUCEE_LOGGING_FORCE_LEVEL: info
-      LUCEE_WEBSOCKET_CONFIG: /tmp/ws-alt-config.json
+      LUCEE_WEBSOCKET_CONFIG: ${{ matrix.env-var-value }}
       LUCEE_ADMIN_PASSWORD: testadmin
+      JAVA_OPTS: ${{ matrix.java-opts }}
     steps:
       - name: Checkout
         uses: actions/checkout@v6
@@ -466,7 +479,7 @@ jobs:
           echo "WS_EXT_LEX_PATH=$LEX_FILE" >> $GITHUB_ENV
           echo "Resolved .lex to: $LEX_FILE"
 
-      - name: Start Lucee Express (with LUCEE_WEBSOCKET_CONFIG + LUCEE_ADMIN_PASSWORD in env)
+      - name: Start Lucee Express (override mode = ${{ matrix.override-mode }})
         run: cd lucee-express && ./bin/catalina.sh start
 
       - name: Wait for server
@@ -556,7 +569,7 @@ jobs:
       - name: Dump WebSocket event logs
         if: always()
         run: |
-          for f in /tmp/ws-*-events.log; do
+          for f in /tmp/ws-*.log; do
             [ -f "$f" ] || continue
             echo "--- $f ---"; cat "$f"
           done || echo "(no event logs found)"
@@ -573,7 +586,7 @@ jobs:
         if: always()
         uses: actions/upload-artifact@v7
         with:
-          name: lucee-logs-config-override-${{ steps.lucee-jar.outputs.LUCEE_VERSION }}
+          name: lucee-logs-config-override-${{ matrix.override-mode }}-${{ steps.lucee-jar.outputs.LUCEE_VERSION }}
           path: |
             lucee-express/logs/
             lucee-express/lucee-server/context/logs/

tests/README.md

@@ -0,0 +1,64 @@
+# WebSocket Extension — Tests
+
+## Two test tiers
+
+### Extension tests (this folder)
+
+Exercise the extension's own contract — WebSocket server not required beyond what Tomcat already provides:
+
+- [`test-websocket-info.cfm`](test-websocket-info.cfm) — smoke test: extension bundle loaded, [`websocketInfo()`](../../../lucee-docs/docs/03.reference/01.functions/websocketinfo) returns the expected shape (`mapping`, `config`, `instances`).
+- [`test-idle-timeout.cfm`](test-idle-timeout.cfm) — [LDEV-6219](https://luceeserver.atlassian.net/browse/LDEV-6219): per-listener `property idleTimeout` must apply to every session on that listener, not just the first.
+- [`WebSocketInfo.cfc`](WebSocketInfo.cfc) / [`WebSocketListener.cfc`](WebSocketListener.cfc) / [`TestPlaceholder.cfc`](TestPlaceholder.cfc) — support CFCs.
+- [`websockets/`](websockets/) — listener CFCs (`TestListener`, `TimeoutListener`) dropped into the configured websockets directory.
+
+Driven by CI via `curl` against a Lucee Express instance with the built `.lex` installed — see `.github/workflows/main.yml`.
+
+### Integration tests ([`tests/integration/`](integration/))
+
+End-to-end client⇄server coverage — `sendText`, `sendBinary`, `onMessage`, `onClose`, `disconnect`, `isOpen`, lifecycle ordering, broadcast semantics, reflection-after-restart, config-path overrides.
+
+These tests use [`CreateWebSocketClient`](https://github.com/lucee/extension-websocket-client) as the driver against listeners registered by this extension — so every integration test exercises **both** extensions together.
+
+## Why integration tests live here, not in the client repo
+
+Every integration test needs both extensions running. Duplicating the suite across two repos guarantees drift. Instead:
+
+- One copy lives here (server repo) — the server is the thing being driven.
+- The client repo's `test-integration` job **sparse-checkouts** `tests/integration/` from this repo, builds its branch's client `.lex`, pulls the latest server `.lex` from download.lucee.org, and runs the suite against the combined pair.
+- Each side's CI catches the bug on its own side — server changes fail here, client changes fail in [extension-websocket-client](https://github.com/lucee/extension-websocket-client).
+
+## What fails where
+
+| Bug source | Caught by |
+| --- | --- |
+| Extension load, `websocketInfo()` shape, per-listener config | Extension tests in this repo (`tests/*.cfm`) |
+| Server callback firing, broadcast, lifecycle, `wsClient` / `wsClients` APIs | Integration tests in this repo (`tests/integration/`) |
+| Reflection fallback after Lucee restart (LDEV-6221) | `test-reflection-restart.cfm` (integration, Linux-only in CI) |
+| Config overrides (env var, custom directory) | `test-config-override.cfm` (separate CI job, needs altered env) |
+| Client BIF contract (scheme handling, error shape, connection timing) | Unit tests in [extension-websocket-client](https://github.com/lucee/extension-websocket-client/tree/master/tests) |
+| Client send/receive, lifecycle, reconnect | Integration tests here — fail in both repos' CI |
+
+## Adding a test
+
+**Needs the WebSocket server contract (listener callbacks, broadcast, lifecycle)?** Add it to [`tests/integration/`](integration/). Both this repo's CI and the client repo's `test-integration` job will pick it up.
+
+**Extension-level only (BIF output, config loading, startup behaviour)?** Add a `test-*.cfm` at the top level of `tests/` and wire it into the `test` job in [`.github/workflows/main.yml`](../.github/workflows/main.yml).
+
+**Listener CFCs under test** go in `tests/integration/websockets/` (integration) or `tests/websockets/` (extension-level). Both directories are mapped as the websockets directory in their respective CI job.
+
+## Running locally
+
+Build the extension:
+
+```bash
+mvn clean install
+```
+
+Drop `target/*.lex` into a Lucee Express instance's `{lucee-config}/deploy/` folder, copy the test listener CFCs into `{lucee-config}/websockets/`, then `curl` the `.cfm` scripts:
+
+```bash
+curl http://localhost:8888/tests/test-websocket-info.cfm
+curl http://localhost:8888/tests/integration/test-lifecycle-callbacks.cfm
+```
+
+Integration tests also need the [websocket-client extension](https://github.com/lucee/extension-websocket-client) installed in the same Lucee instance. The CI workflow ([`.github/workflows/main.yml`](../.github/workflows/main.yml)) shows the full setup.

tests/integration/test-onfirstopen-rearm.cfm

@@ -0,0 +1,70 @@
+<cfscript>
+// Doc claim: "onFirstOpen can fire more than once per listener lifetime — each time
+// the channel goes from zero clients back to one, it runs again."
+//
+// Sequence: connect → disconnect (channel goes to zero) → wait → connect again.
+// Expect: onFirstOpen count == 2, onLastClose count >= 1.
+
+writeOutput( "=== onFirstOpen re-arm after onLastClose ===" & chr( 10 ) );
+
+logFile = getTempDirectory() & "ws-rearm.log";
+if ( fileExists( logFile ) )
+	fileDelete( logFile );
+
+try {
+	if ( !structKeyExists( getFunctionList(), "CreateWebSocketClient" ) )
+		throw( message="CreateWebSocketClient not available", type="TestSetupError" );
+
+	wsUrl = "ws://localhost:8888/ws/RearmListener";
+
+	// First connection — expect onFirstOpen
+	clientA = new tests.integration.ClientListener();
+	wsA = CreateWebSocketClient( wsUrl, clientA );
+	sleep( 500 );
+
+	wsA.disconnect();
+	sleep( 1500 );  // give onLastClose's async thread time to fire
+
+	// Second connection after channel drained — expect another onFirstOpen
+	clientB = new tests.integration.ClientListener();
+	wsB = CreateWebSocketClient( wsUrl, clientB );
+	sleep( 500 );
+
+	wsB.disconnect();
+	sleep( 1500 );
+
+	events = fileExists( logFile ) ? fileRead( logFile ).listToArray( chr( 10 ) ) : [];
+
+	writeOutput( chr( 10 ) & "=== Events logged ===" & chr( 10 ) );
+	for ( e in events )
+		writeOutput( "  - #e#" & chr( 10 ) );
+
+	firstOpenCount = 0;
+	for ( e in events ) {
+		if ( e == "onFirstOpen" ) firstOpenCount++;
+	}
+
+	errors = [];
+
+	// onFirstOpen firing twice is the real claim — the channel went to zero, then back to one.
+	// NOT asserting onLastClose because it runs on an async thread and races with the
+	// window we sample in; test-lifecycle-callbacks covers its existence.
+	if ( firstOpenCount != 2 )
+		arrayAppend( errors, "expected onFirstOpen to fire 2 times (once per cold start), got #firstOpenCount#" );
+
+	if ( arrayLen( errors ) ) {
+		writeOutput( chr( 10 ) & "FAILED:" & chr( 10 ) );
+		for ( err in errors )
+			writeOutput( "  - #err#" & chr( 10 ) );
+		cfheader( statuscode=500, statustext="Test Failed" );
+	}
+	else {
+		writeOutput( chr( 10 ) & "SUCCESS: onFirstOpen re-fired after channel drained" & chr( 10 ) );
+	}
+}
+catch ( any e ) {
+	writeOutput( "FAILED with exception:" & chr( 10 ) );
+	writeOutput( e.stacktrace );
+	cfheader( statuscode=500, statustext="Test Failed" );
+}
+</cfscript>

tests/integration/test-onopen-async.cfm

@@ -0,0 +1,63 @@
+<cfscript>
+// Doc claim: "onOpenAsync — fires at the same time as onOpen, in parallel. Long
+// init work that shouldn't block the connection ack."
+//
+// Test: connect, assert both onOpen and onOpenAsync logged, on DIFFERENT threads.
+
+writeOutput( "=== onOpenAsync parallel execution ===" & chr( 10 ) );
+
+logFile = getTempDirectory() & "ws-onopen-async.log";
+if ( fileExists( logFile ) )
+	fileDelete( logFile );
+
+try {
+	if ( !structKeyExists( getFunctionList(), "CreateWebSocketClient" ) )
+		throw( message="CreateWebSocketClient not available", type="TestSetupError" );
+
+	listener = new tests.integration.ClientListener();
+	ws = CreateWebSocketClient( "ws://localhost:8888/ws/OnOpenAsyncListener", listener );
+	sleep( 1000 );  // generous window for async callback to complete
+
+	ws.disconnect();
+	sleep( 300 );
+
+	events = fileExists( logFile ) ? fileRead( logFile ).listToArray( chr( 10 ) ) : [];
+
+	writeOutput( chr( 10 ) & "=== Events logged ===" & chr( 10 ) );
+	for ( e in events )
+		writeOutput( "  - #e#" & chr( 10 ) );
+
+	onOpenThread = "";
+	onAsyncThread = "";
+	for ( e in events ) {
+		if ( left( e, 14 ) == "onOpen:thread=" )
+			onOpenThread = mid( e, 15, len( e ) );
+		if ( left( e, 19 ) == "onOpenAsync:thread=" )
+			onAsyncThread = mid( e, 20, len( e ) );
+	}
+
+	errors = [];
+
+	if ( onOpenThread == "" )
+		arrayAppend( errors, "onOpen did not fire (no log entry)" );
+	if ( onAsyncThread == "" )
+		arrayAppend( errors, "onOpenAsync did not fire (no log entry)" );
+	if ( onOpenThread != "" && onOpenThread == onAsyncThread )
+		arrayAppend( errors, "onOpenAsync ran on the SAME thread as onOpen (#onOpenThread#) — not parallel" );
+
+	if ( arrayLen( errors ) ) {
+		writeOutput( chr( 10 ) & "FAILED:" & chr( 10 ) );
+		for ( err in errors )
+			writeOutput( "  - #err#" & chr( 10 ) );
+		cfheader( statuscode=500, statustext="Test Failed" );
+	}
+	else {
+		writeOutput( chr( 10 ) & "SUCCESS: onOpen (t=#onOpenThread#) and onOpenAsync (t=#onAsyncThread#) ran on different threads" & chr( 10 ) );
+	}
+}
+catch ( any e ) {
+	writeOutput( "FAILED with exception:" & chr( 10 ) );
+	writeOutput( e.stacktrace );
+	cfheader( statuscode=500, statustext="Test Failed" );
+}
+</cfscript>

tests/integration/test-request-timeout.cfm

@@ -0,0 +1,69 @@
+<cfscript>
+// Doc claim: "requestTimeout also bounds onFirstOpen and any thread spawned inside
+// it. A while loop in onFirstOpen will be killed once requestTimeout elapses."
+//
+// The listener runs a 15-second loop with requestTimeout=3. After ~3s the loop
+// should be killed; the file log should show "before-loop" and some "tick:*"
+// entries but NO "after-loop:" entry.
+
+writeOutput( "=== requestTimeout kills onFirstOpen work ===" & chr( 10 ) );
+
+logFile = getTempDirectory() & "ws-request-timeout.log";
+if ( fileExists( logFile ) )
+	fileDelete( logFile );
+
+try {
+	if ( !structKeyExists( getFunctionList(), "CreateWebSocketClient" ) )
+		throw( message="CreateWebSocketClient not available", type="TestSetupError" );
+
+	listener = new tests.integration.ClientListener();
+	ws = CreateWebSocketClient( "ws://localhost:8888/ws/LongOnFirstOpenListener", listener );
+
+	// Wait long enough for requestTimeout (3s) to fire but less than the 15s hard cap
+	sleep( 8000 );
+
+	ws.disconnect();
+	sleep( 500 );
+
+	events = fileExists( logFile ) ? fileRead( logFile ).listToArray( chr( 10 ) ) : [];
+
+	writeOutput( chr( 10 ) & "=== Events logged (#arrayLen( events )# total) ===" & chr( 10 ) );
+	// Dump first + last 5 so CI output stays readable
+	for ( i = 1; i <= min( 5, arrayLen( events ) ); i++ )
+		writeOutput( "  - #events[ i ]#" & chr( 10 ) );
+	if ( arrayLen( events ) > 10 )
+		writeOutput( "  ... (#arrayLen( events ) - 10# more)" & chr( 10 ) );
+	for ( i = max( 6, arrayLen( events ) - 4 ); i <= arrayLen( events ); i++ )
+		writeOutput( "  - #events[ i ]#" & chr( 10 ) );
+
+	reachedAfter = false;
+	sawBefore = false;
+	for ( e in events ) {
+		if ( left( e, 11 ) == "before-loop" ) sawBefore = true;
+		if ( left( e, 10 ) == "after-loop" ) reachedAfter = true;
+	}
+
+	errors = [];
+
+	if ( !sawBefore )
+		arrayAppend( errors, "onFirstOpen never started — 'before-loop' not logged" );
+
+	if ( reachedAfter )
+		arrayAppend( errors, "loop ran to completion — requestTimeout did NOT kill the long-running onFirstOpen work ('after-loop' was logged)" );
+
+	if ( arrayLen( errors ) ) {
+		writeOutput( chr( 10 ) & "FAILED:" & chr( 10 ) );
+		for ( err in errors )
+			writeOutput( "  - #err#" & chr( 10 ) );
+		cfheader( statuscode=500, statustext="Test Failed" );
+	}
+	else {
+		writeOutput( chr( 10 ) & "SUCCESS: requestTimeout killed onFirstOpen before the loop completed" & chr( 10 ) );
+	}
+}
+catch ( any e ) {
+	writeOutput( "FAILED with exception:" & chr( 10 ) );
+	writeOutput( e.stacktrace );
+	cfheader( statuscode=500, statustext="Test Failed" );
+}
+</cfscript>