chore(regTests): print logs when regTests timeout (#2031)

* add a python script to print the most recent log
* if CI timeouts, print the most recent log
* replace global timeout with timeout command
* upload all logs on failure()
* print uid + port + the log files for each df instance

.github/actions/regression-tests/action.yml

@@ -26,6 +26,7 @@ runs:
   # timeout-minutes: 20
   steps:
     - name: Run PyTests
+      id: first
       shell: bash
       run: |
         ls -l ${GITHUB_WORKSPACE}/
@@ -36,9 +37,10 @@ runs:
         export DRAGONFLY_PATH="${GITHUB_WORKSPACE}/${{inputs.build-folder-name}}/${{inputs.dfly-executable}}"
         export UBSAN_OPTIONS=print_stacktrace=1:halt_on_error=1 # to crash on errors
 
-        pytest -m "${{inputs.filter}}" --json-report --json-report-file=report.json dragonfly --ignore=dragonfly/replication_test.py --log-cli-level=INFO
+        timeout 20m pytest -m "${{inputs.filter}}" --json-report --json-report-file=report.json dragonfly --ignore=dragonfly/replication_test.py --log-cli-level=INFO || code=$?; if [[ $code -eq 124 ]]; then echo "TIMEDOUT=1">> "$GITHUB_OUTPUT"; exit 1; fi
 
     - name: Run PyTests replication test
+      id: second
       if: ${{ inputs.run-only-on-ubuntu-latest == 'true' || (inputs.run-only-on-ubuntu-latest == 'false' && matrix.runner == 'ubuntu-latest') }}
       shell: bash
       run: |
@@ -47,8 +49,25 @@ runs:
         # used by PyTests
         export DRAGONFLY_PATH="${GITHUB_WORKSPACE}/${{inputs.build-folder-name}}/${{inputs.dfly-executable}}"
 
-        pytest -m "${{inputs.filter}}" --json-report --json-report-file=rep1_report.json dragonfly/replication_test.py --df alsologtostderr --df enable_multi_shard_sync=true
-        pytest -m "${{inputs.filter}}" --json-report --json-report-file=rep2_report.json dragonfly/replication_test.py --df alsologtostderr --df enable_multi_shard_sync=false
+        run_pytest_with_args() {
+          timeout 20m pytest -m "${{inputs.filter}}" --json-report --json-report-file=rep1_report.json dragonfly/replication_test.py --log-cli-level=INFO --df alsologtostderr $1 $2 || code=$?; if [[ $code -eq 124 ]]; then echo "TIMEDOUT=1">> "$GITHUB_OUTPUT"; exit 1; fi
+        }
+
+        (run_pytest_with_args --df enable_multi_shard_sync=true)
+        (run_pytest_with_args --df enable_multi_shard_sync=false)
+
+    - name: Print last log on timeout
+      if: failure()
+      shell: bash
+      env:
+        TIMEDOUT_STEP_1: ${{ steps.first.outputs.TIMEDOUT }}
+        TIMEDOUT_STEP_2: ${{ steps.second.outputs.TIMEDOUT }}
+      run: |
+        if [[ "${{ env.TIMEDOUT_STEP_1 }}" -eq 1 ]] || [[ "${{ env.TIMEDOUT_STEP_2 }}" -eq 1 ]]; then
+          echo "🪵🪵🪵🪵🪵🪵 Latest log before timeout 🪵🪵🪵🪵🪵🪵\n\n"
+          ls -t /tmp/dragonfly*log*INFO* | head -n 1 | xargs cat
+          echo "🪵🪵🪵🪵🪵🪵 Latest log before timeout end 🪵🪵🪵🪵🪵🪵\n\n"
+        fi
 
     - name: Send notification on failure
       if: failure() && github.ref == 'refs/heads/main'

.github/workflows/regression-tests.yml

@@ -35,10 +35,16 @@ jobs:
           ls -l ..
 
       - name: Run regression tests action
-        timeout-minutes: 45
         uses: ./.github/actions/regression-tests
         with:
           dfly-executable: dragonfly
           gspace-secret: ${{ secrets.GSPACES_BOT_DF_BUILD }}
           run-only-on-ubuntu-latest: false
           build-folder-name: build
+
+      - name: Upload logs on failure
+        if: failure()
+        uses: actions/upload-artifact@v3
+        with:
+          name: logs
+          path: /tmp/dragonfly.*

tests/dragonfly/instance.py

@@ -6,6 +6,7 @@ from dataclasses import dataclass
 from typing import Dict, Optional, List, Union
 import re
 import psutil
+import itertools
 from prometheus_client.parser import text_string_to_metric_families
 from redis.asyncio import Redis as RedisClient
 
@@ -42,6 +43,9 @@ class DflyStartException(Exception):
     pass
 
 
+uid_iterator = itertools.count()
+
+
 class DflyInstance:
     """
     Represents a runnable and stoppable Dragonfly instance
@@ -129,6 +133,11 @@ class DflyInstance:
             raise DflyStartException("Process didn't start listening on port in time")
 
         self.log_files = self.get_logs_from_psutil()
+        id = next(uid_iterator)
+        logging.info(f"Starting instance with id {id} and port {self._port}")
+        logging.info(f"Log files are: ")
+        for log in self.log_files:
+            logging.info(f"🪵🪵🪵🪵🪵🪵 {log} 🪵🪵🪵🪵🪵🪵")
 
         # Remove first 6 lines - our default header with log locations (as it carries no useful information)
         # Next, replace log-level + date with port and colored arrow