Fix deployment-tests workflow - use Express template directly, add trace logging, upload artifacts

zspitzer · zspitzer · commit d706d7c4634c · 2025-12-09T15:18:19.000+01:00
diff --git a/.github/workflows/deployment-tests.yml b/.github/workflows/deployment-tests.yml
@@ -1,5 +1,8 @@
 name: Deployment Timing Tests
 
+# Tests for LDEV-5478 / LDEV-5960 - deploy folder timing issues
+# Verifies that extensions in the deploy folder are fully initialized before requests are served
+
 on:
   workflow_dispatch:
     inputs:
@@ -15,6 +18,9 @@ on:
       - 'custom/deployment-tests/**'
       - '.github/workflows/deployment-tests.yml'
 
+env:
+  EXPRESS_TEMPLATE_URL: https://cdn.lucee.org/express-templates/lucee-tomcat-11.0.13-template.zip
+
 jobs:
   # First job: Build the test extensions
   build-extensions:
@@ -68,39 +74,40 @@ jobs:
           java-version: 21
           distribution: temurin
 
-      - name: Cache Lucee Express
-        uses: actions/cache@v4
-        with:
-          path: lucee-express-cache/
-          key: lucee-express-${{ matrix.luceeVersion }}
-
-      - name: Cache Lucee downloads
-        uses: actions/cache@v4
-        with:
-          path: /home/runner/work/_actions/lucee/script-runner/main/lucee-download-cache
-          key: lucee-downloads
-
       - name: Download slow-startup extension
         uses: actions/download-artifact@v4
         with:
           name: slow-startup-extension
           path: extensions/
 
-      - name: Download Lucee Express
-        uses: lucee/script-runner@main
-        with:
-          webroot: ${{ github.workspace }}/custom/deployment-tests
-          execute: /fetch-express.cfm
-          luceeVersionQuery: ${{ matrix.luceeVersion }}
-        env:
-          fetch: ${{ matrix.luceeVersion }}
+      - name: Download Lucee Express template
+        run: |
+          curl -L -o express-template.zip "$EXPRESS_TEMPLATE_URL"
+          unzip -q express-template.zip -d express
+
+      - name: Download Lucee JAR
+        run: |
+          # Get Lucee JAR filename via update API
+          LUCEE_FILENAME=$(curl -s "https://update.lucee.org/rest/update/provider/latest/${{ matrix.luceeVersion }}/filename" | tr -d '"')
+          echo "Lucee filename: $LUCEE_FILENAME"
+          LUCEE_URL="https://cdn.lucee.org/$LUCEE_FILENAME"
+          echo "Downloading from: $LUCEE_URL"
+          curl -L -f -o lucee.jar "$LUCEE_URL"
+          # Validate JAR
+          if ! unzip -t lucee.jar > /dev/null 2>&1; then
+            echo "ERROR: Downloaded JAR is corrupt!"
+            exit 1
+          fi
+          # Install into Express
+          rm -f express/lib/lucee-*.jar
+          cp lucee.jar express/lib/
 
       - name: Prepare test environment
         run: |
           echo "## Test: ${{ matrix.luceeVersion }}" >> $GITHUB_STEP_SUMMARY
           echo "" >> $GITHUB_STEP_SUMMARY
 
-          # Create test script in webroot
+          # Copy test script to webroot
           cp custom/deployment-tests/test-slow-startup.cfm express/webapps/ROOT/
 
           # Copy extension to deploy folder BEFORE starting Lucee
@@ -109,36 +116,53 @@ jobs:
           echo "Extension in deploy folder:"
           ls -la express/lucee-server/deploy/
 
+          # Configure trace logging
+          echo 'export LUCEE_LOGGING_FORCE_LEVEL=trace' >> express/bin/setenv.sh
+          chmod +x express/bin/setenv.sh
+
+          # Configure Tomcat port
+          sed -i 's/port="8080"/port="8888"/g' express/conf/server.xml
+
       - name: Start Lucee and test IMMEDIATELY (no sleep!)
         id: test
         run: |
-          # Start Lucee in background
-          ./express/bin/startup.sh
+          cd express
+
+          # Start Lucee
+          echo "Starting Lucee Express..."
+          ./bin/catalina.sh start
+          echo "Lucee started"
 
           # Make request IMMEDIATELY - this is the key test!
           # If LDEV-5478 exists, this will fail because onStart() hasn't completed
           echo "Making immediate request (no delay)..."
 
-          # Try up to 10 times with 1 second between attempts
-          # The first few might fail due to Tomcat not being ready yet
+          # Try up to 30 times with 1 second between attempts
+          # The first few will fail due to Tomcat not being ready yet
           # But once Tomcat IS ready, if the extension isn't, that's the bug!
-          for i in {1..10}; do
+          for i in {1..30}; do
             echo "Attempt $i..."
             HTTP_CODE=$(curl -s -o /tmp/response.txt -w "%{http_code}" http://127.0.0.1:8888/test-slow-startup.cfm 2>/dev/null || echo "000")
             echo "HTTP Code: $HTTP_CODE"
             if [ "$HTTP_CODE" != "000" ]; then
               # Got a response from Tomcat
+              echo "=== Response ==="
               cat /tmp/response.txt
               echo ""
+              echo "================"
               if [ "$HTTP_CODE" = "200" ]; then
                 echo "TEST PASSED: Extension ready on first request"
                 echo "### Result: PASSED" >> $GITHUB_STEP_SUMMARY
+                echo '```' >> $GITHUB_STEP_SUMMARY
                 cat /tmp/response.txt >> $GITHUB_STEP_SUMMARY
+                echo '```' >> $GITHUB_STEP_SUMMARY
                 exit 0
               else
                 echo "TEST FAILED: Extension NOT ready - LDEV-5478 reproduced!"
                 echo "### Result: FAILED (LDEV-5478 reproduced)" >> $GITHUB_STEP_SUMMARY
+                echo '```' >> $GITHUB_STEP_SUMMARY
                 cat /tmp/response.txt >> $GITHUB_STEP_SUMMARY
+                echo '```' >> $GITHUB_STEP_SUMMARY
                 exit 1
               fi
             fi
@@ -152,38 +176,20 @@ jobs:
       - name: Stop Lucee
         if: always()
         run: |
-          ./express/bin/shutdown.sh || true
+          cd express
+          ./bin/shutdown.sh || true
 
-      - name: Show Lucee logs
+      - name: Show catalina.out
         if: always()
         run: |
-          echo "## Logs" >> $GITHUB_STEP_SUMMARY
-          echo "" >> $GITHUB_STEP_SUMMARY
+          echo "=== catalina.out ==="
+          cat express/logs/catalina.out || echo "No catalina.out found"
 
-          echo "### catalina.out" >> $GITHUB_STEP_SUMMARY
-          if [ -f express/logs/catalina.out ]; then
-            echo '```' >> $GITHUB_STEP_SUMMARY
-            tail -100 express/logs/catalina.out >> $GITHUB_STEP_SUMMARY
-            echo '```' >> $GITHUB_STEP_SUMMARY
-          fi
-
-          echo "### deploy.log" >> $GITHUB_STEP_SUMMARY
-          if [ -f express/lucee-server/context/logs/deploy.log ]; then
-            echo '```' >> $GITHUB_STEP_SUMMARY
-            cat express/lucee-server/context/logs/deploy.log >> $GITHUB_STEP_SUMMARY
-            echo '```' >> $GITHUB_STEP_SUMMARY
-          fi
-
-          echo "### exception.log" >> $GITHUB_STEP_SUMMARY
-          if [ -f express/lucee-server/context/logs/exception.log ]; then
-            echo '```' >> $GITHUB_STEP_SUMMARY
-            cat express/lucee-server/context/logs/exception.log >> $GITHUB_STEP_SUMMARY
-            echo '```' >> $GITHUB_STEP_SUMMARY
-          fi
-
-          echo "### out.log" >> $GITHUB_STEP_SUMMARY
-          if [ -f express/lucee-server/context/logs/out.log ]; then
-            echo '```' >> $GITHUB_STEP_SUMMARY
-            cat express/lucee-server/context/logs/out.log >> $GITHUB_STEP_SUMMARY
-            echo '```' >> $GITHUB_STEP_SUMMARY
-          fi
+      - name: Upload logs on failure
+        if: failure()
+        uses: actions/upload-artifact@v4
+        with:
+          name: lucee-logs-${{ matrix.luceeVersion }}
+          path: |
+            express/logs/
+            express/lucee-server/context/logs/
