diff --git a/.github/workflows/ci.yml b/.github/workflows/ci.yml index 26751c5f2..a6820b0ad 100644 --- a/.github/workflows/ci.yml +++ b/.github/workflows/ci.yml @@ -15,7 +15,7 @@ env: PACKAGE_NAME: "ansys-systemcoupling-core" PACKAGE_NAMESPACE: "ansys.systemcoupling.core" DOCUMENTATION_CNAME: "systemcoupling.docs.pyansys.com" - DOC_BUILD_SYC_VERSION: 26_1 + DOC_BUILD_SYC_VERSION: 27_1 # Intermittent gRPC ping timeout issues seen with the 26.1 container. # Pin the gRPC version for 261 doc and test and set channel options to # try to avoid ping timeout issues. This is mainly seen in the long-running @@ -29,8 +29,12 @@ env: # 3. Align min ping intervals to 90 seconds to avoid 5-minute throttling effects # 4. Keep ping response timeout permissive to avoid false negatives on long solves PYSYC_GRPC_CHANNEL_OPTIONS_JSON_261: '{"grpc.keepalive_time_ms": 90000, "grpc.keepalive_timeout_ms": 2147483647, "grpc.keepalive_permit_without_calls": 0, "grpc.http2.max_pings_without_data": 0, "grpc.http2.min_time_between_pings_ms": 90000, "grpc.http2.min_ping_interval_without_data_ms": 90000}' + # gRPC channel options for v27.1: More passive keepalive to avoid server "too_many_pings" errors. + # v27.1 has stricter ping-strike limits than v26.1. Even 90s keepalive is rejected. + # Try 300s (5 minutes) as a more conservative approach for long-running solve() RPC. + PYSYC_GRPC_CHANNEL_OPTIONS_JSON_271: '{"grpc.keepalive_time_ms": 300000, "grpc.keepalive_timeout_ms": 2147483647, "grpc.keepalive_permit_without_calls": 0, "grpc.http2.max_pings_without_data": 0, "grpc.http2.min_time_between_pings_ms": 300000, "grpc.http2.min_ping_interval_without_data_ms": 300000}' FLUENT_IMAGE_VERSION: "v26.1.latest" - SYC_IMAGE_VERSION: "v26.1.0" + SYC_IMAGE_VERSION: "latest" MAPDL_IMAGE_VERSION: "v25.2-ubuntu-cicd" permissions: {} # Zero permissions can be granted at the workflow level if not all jobs require permissions. @@ -169,10 +173,10 @@ jobs: with: image-tag: v26.1.0 - #- name: Generate API for latest - # uses: ./.github/actions/generate-api - # with: - # image-tag: latest + - name: Generate API for latest + uses: ./.github/actions/generate-api + with: + image-tag: latest - name: Clean out dist run: rm -rf dist @@ -221,102 +225,102 @@ jobs: username: ${{ secrets.GH_USERNAME }} password: ${{ secrets.PYANSYS_CI_BOT_TOKEN }} - - name: Unit Test v24.1.0 - uses: ./.github/actions/unit-test - with: - image-tag: v24.1.0 - upload-coverage: false - - - name: Unit Test v24.2.0 (SP5) - uses: ./.github/actions/unit-test - with: - image-tag: v24.2.0-sp05 - upload-coverage: false - - - name: Unit Test v25.1.0 (SP4) + # - name: Unit Test v24.1.0 + # uses: ./.github/actions/unit-test + # with: + # image-tag: v24.1.0 + # upload-coverage: false + + # - name: Unit Test v24.2.0 (SP5) + # uses: ./.github/actions/unit-test + # with: + # image-tag: v24.2.0-sp05 + # upload-coverage: false + + # - name: Unit Test v25.1.0 (SP4) + # uses: ./.github/actions/unit-test + # with: + # image-tag: v25.1.0-sp04 + # upload-coverage: false + # env: + # ANSYSLMD_LICENSE_FILE: "1055@${{ secrets.LICENSE_SERVER }}" + + # - name: Unit Test v25.2.0 (SP3) + # uses: ./.github/actions/unit-test + # with: + # image-tag: v25.2.0-sp03 + # upload-coverage: false + # env: + # ANSYSLMD_LICENSE_FILE: "1055@${{ secrets.LICENSE_SERVER }}" + + # - name: Pin grpcio for v26.1 tests + # run: | + # pip install -q --force-reinstall grpcio==${GRPCIO_VERSION_261} grpcio-status==${GRPCIO_VERSION_261} grpcio-health-checking==${GRPCIO_VERSION_261} > /dev/null + # python - <<'PY' + # import grpc + # import grpc_status + # import grpc_health + # print(f"grpcio version: {grpc.__version__}") + # print(f"grpcio-status module: {grpc_status.__name__}") + # print(f"grpcio-health-checking module: {grpc_health.__name__}") + # PY + # env: + # GRPCIO_VERSION_261: ${{ env.GRPCIO_VERSION_261 }} + + # - name: Diagnostic - effective gRPC options for v26.1 tests + # run: | + # python - <<'PY' + # import json + # import os + + # raw = os.environ.get("PYSYC_GRPC_CHANNEL_OPTIONS_JSON", "") + # print(f"PYSYC_GRPC_CHANNEL_OPTIONS_JSON={raw}") + # try: + # parsed = json.loads(raw) if raw else {} + # except Exception as exc: + # parsed = {"_parse_error": str(exc)} + # print(f"parsed_grpc_options={parsed}") + # PY + # env: + # PYSYC_GRPC_CHANNEL_OPTIONS_JSON: ${{ env.PYSYC_GRPC_CHANNEL_OPTIONS_JSON_261 }} + + # - name: Unit Test v26.1.0 (attempt 1) + # id: unit_test_v261_attempt1 + # continue-on-error: true + # uses: ./.github/actions/unit-test + # with: + # image-tag: v26.1.0 + # upload-coverage: true + # env: + # ANSYSLMD_LICENSE_FILE: "1055@${{ secrets.LICENSE_SERVER }}" + # PYSYC_GRPC_CHANNEL_OPTIONS_JSON: ${{ env.PYSYC_GRPC_CHANNEL_OPTIONS_JSON_261 }} + + # - name: Unit Test v26.1.0 (attempt 2 on transient failure) + # id: unit_test_v261_attempt2 + # if: steps.unit_test_v261_attempt1.outcome == 'failure' + # continue-on-error: true + # uses: ./.github/actions/unit-test + # with: + # image-tag: v26.1.0 + # upload-coverage: true + # env: + # ANSYSLMD_LICENSE_FILE: "1055@${{ secrets.LICENSE_SERVER }}" + # PYSYC_GRPC_CHANNEL_OPTIONS_JSON: ${{ env.PYSYC_GRPC_CHANNEL_OPTIONS_JSON_261 }} + + # - name: Fail if v26.1 retries exhausted + # if: steps.unit_test_v261_attempt1.outcome == 'failure' && steps.unit_test_v261_attempt2.outcome == 'failure' + # run: | + # echo "v26.1 unit tests failed on both attempts." + # exit 1 + + - name: Unit Test latest uses: ./.github/actions/unit-test with: - image-tag: v25.1.0-sp04 + image-tag: latest upload-coverage: false env: ANSYSLMD_LICENSE_FILE: "1055@${{ secrets.LICENSE_SERVER }}" - - name: Unit Test v25.2.0 (SP3) - uses: ./.github/actions/unit-test - with: - image-tag: v25.2.0-sp03 - upload-coverage: false - env: - ANSYSLMD_LICENSE_FILE: "1055@${{ secrets.LICENSE_SERVER }}" - - - name: Pin grpcio for v26.1 tests - run: | - pip install -q --force-reinstall grpcio==${GRPCIO_VERSION_261} grpcio-status==${GRPCIO_VERSION_261} grpcio-health-checking==${GRPCIO_VERSION_261} > /dev/null - python - <<'PY' - import grpc - import grpc_status - import grpc_health - print(f"grpcio version: {grpc.__version__}") - print(f"grpcio-status module: {grpc_status.__name__}") - print(f"grpcio-health-checking module: {grpc_health.__name__}") - PY - env: - GRPCIO_VERSION_261: ${{ env.GRPCIO_VERSION_261 }} - - - name: Diagnostic - effective gRPC options for v26.1 tests - run: | - python - <<'PY' - import json - import os - - raw = os.environ.get("PYSYC_GRPC_CHANNEL_OPTIONS_JSON", "") - print(f"PYSYC_GRPC_CHANNEL_OPTIONS_JSON={raw}") - try: - parsed = json.loads(raw) if raw else {} - except Exception as exc: - parsed = {"_parse_error": str(exc)} - print(f"parsed_grpc_options={parsed}") - PY - env: - PYSYC_GRPC_CHANNEL_OPTIONS_JSON: ${{ env.PYSYC_GRPC_CHANNEL_OPTIONS_JSON_261 }} - - - name: Unit Test v26.1.0 (attempt 1) - id: unit_test_v261_attempt1 - continue-on-error: true - uses: ./.github/actions/unit-test - with: - image-tag: v26.1.0 - upload-coverage: true - env: - ANSYSLMD_LICENSE_FILE: "1055@${{ secrets.LICENSE_SERVER }}" - PYSYC_GRPC_CHANNEL_OPTIONS_JSON: ${{ env.PYSYC_GRPC_CHANNEL_OPTIONS_JSON_261 }} - - - name: Unit Test v26.1.0 (attempt 2 on transient failure) - id: unit_test_v261_attempt2 - if: steps.unit_test_v261_attempt1.outcome == 'failure' - continue-on-error: true - uses: ./.github/actions/unit-test - with: - image-tag: v26.1.0 - upload-coverage: true - env: - ANSYSLMD_LICENSE_FILE: "1055@${{ secrets.LICENSE_SERVER }}" - PYSYC_GRPC_CHANNEL_OPTIONS_JSON: ${{ env.PYSYC_GRPC_CHANNEL_OPTIONS_JSON_261 }} - - - name: Fail if v26.1 retries exhausted - if: steps.unit_test_v261_attempt1.outcome == 'failure' && steps.unit_test_v261_attempt2.outcome == 'failure' - run: | - echo "v26.1 unit tests failed on both attempts." - exit 1 - - #- name: Unit Test latest - # uses: ./.github/actions/unit-test - # with: - # image-tag: latest - # upload-coverage: false - # env: - # ANSYSLMD_LICENSE_FILE: "1055@${{ secrets.LICENSE_SERVER }}" - docs: name: Build Documentation needs: [doc-style, build] @@ -343,21 +347,21 @@ jobs: - name: Install pysystemcoupling with doc dependencies run: | wheel_name=`echo dist/*.whl` - pip install -q --force-reinstall ${wheel_name}[doc] > /dev/null - - - name: Pin grpcio for docs build (v26.1) - run: | - pip install -q --force-reinstall grpcio==${GRPCIO_VERSION_261} grpcio-status==${GRPCIO_VERSION_261} grpcio-health-checking==${GRPCIO_VERSION_261} > /dev/null - python - <<'PY' - import grpc - import grpc_status - import grpc_health - print(f"grpcio version: {grpc.__version__}") - print(f"grpcio-status module: {grpc_status.__name__}") - print(f"grpcio-health-checking module: {grpc_health.__name__}") - PY - env: - GRPCIO_VERSION_261: ${{ env.GRPCIO_VERSION_261 }} + pip install --force-reinstall ${wheel_name}[doc] + + # - name: Pin grpcio for docs build (v26.1) + # run: | + # pip install -q --force-reinstall grpcio==${GRPCIO_VERSION_261} grpcio-status==${GRPCIO_VERSION_261} grpcio-health-checking==${GRPCIO_VERSION_261} > /dev/null + # python - <<'PY' + # import grpc + # import grpc_status + # import grpc_health + # print(f"grpcio version: {grpc.__version__}") + # print(f"grpcio-status module: {grpc_status.__name__}") + # print(f"grpcio-health-checking module: {grpc_health.__name__}") + # PY + # env: + # GRPCIO_VERSION_261: ${{ env.GRPCIO_VERSION_261 }} - name: Docker Login uses: docker/login-action@650006c6eb7dba73a995cc03b0b2d7f5ca915bee # v4.2.0 @@ -398,13 +402,93 @@ jobs: print(f"parsed_grpc_options={parsed}") PY env: - PYSYC_GRPC_CHANNEL_OPTIONS_JSON: ${{ env.PYSYC_GRPC_CHANNEL_OPTIONS_JSON_261 }} + PYSYC_GRPC_CHANNEL_OPTIONS_JSON: ${{ env.PYSYC_GRPC_CHANNEL_OPTIONS_JSON_271 }} + + - name: Diagnostic - preflight container launch for docs build + run: | + set -o pipefail + export SYC_CONTAINER_USER=$(id -u):$(id -g) + mkdir -p ci-logs/preflight + image_ref="ghcr.io/ansys/pysystem-coupling:${SYC_IMAGE_TAG}" + + # Capture container lifecycle events because launch uses --rm and + # failing containers may disappear before docker logs can read them. + since_ts=$(date -u +"%Y-%m-%dT%H:%M:%SZ") + docker events --since "${since_ts}" --format '{{json .}}' > ci-logs/preflight/docker-events.jsonl 2>&1 & + events_pid=$! + cleanup() { + kill "${events_pid}" >/dev/null 2>&1 || true + } + trap cleanup EXIT + + if ! python - <<'PY' 2>&1 | tee ci-logs/preflight/python-preflight.log + import ansys.systemcoupling.core as pysystemcoupling + + with pysystemcoupling.launch_container() as syc: + assert syc.ping() + print(f"preflight_connected_version={syc.version}") + PY + then + echo "Preflight launch failed. Capturing docker diagnostics..." + docker version > ci-logs/preflight/docker-version.txt 2>&1 || true + docker info > ci-logs/preflight/docker-info.txt 2>&1 || true + docker network ls > ci-logs/preflight/docker-network-ls.txt 2>&1 || true + docker inspect bridge > ci-logs/preflight/docker-network-bridge.inspect.json 2>&1 || true + docker image inspect "${image_ref}" > ci-logs/preflight/syc-image.inspect.json 2>&1 || true + docker ps -a --no-trunc --format '{{.ID}} {{.Image}} {{.Names}} {{.Status}}' > ci-logs/preflight/containers.txt || true + + # Basic image sanity check independent of pysystemcoupling launch path. + docker run --rm --entrypoint /bin/bash "${image_ref}" -lc 'id && ls -la /syc/SystemCoupling || true' > ci-logs/preflight/image-sanity.log 2>&1 || true + + # Probe entrypoint execution under the same user mapping used in docs. + docker run --rm --user "$(id -u):$(id -g)" --entrypoint /bin/bash "${image_ref}" -lc 'id; ls -l /syc/SystemCoupling/bin/systemcoupling; /syc/SystemCoupling/bin/systemcoupling --help' > ci-logs/preflight/image-user-entrypoint-probe.log 2>&1 || true + + docker ps -a --format '{{.ID}} {{.Image}} {{.Names}}' | while read -r cid image name; do + if echo "${image} ${name}" | grep -Eiq 'pysystem-coupling|systemcoupling'; then + safe_name=$(echo "${name}" | tr '/: ' '___') + docker logs "${cid}" > "ci-logs/preflight/${safe_name}.log" 2>&1 || true + docker inspect "${cid}" > "ci-logs/preflight/${safe_name}.inspect.json" 2>/dev/null || true + fi + done + exit 1 + fi + env: + PYSYC_GRPC_CHANNEL_OPTIONS_JSON: ${{ env.PYSYC_GRPC_CHANNEL_OPTIONS_JSON_271 }} + ANSYSLMD_LICENSE_FILE: "1055@${{ secrets.LICENSE_SERVER }}" + SYC_LAUNCH_CONTAINER: 1 + SYC_IMAGE_TAG: ${{ env.SYC_IMAGE_VERSION }} - name: Build HTML + timeout-minutes: 10 run: | set -o pipefail export SYC_CONTAINER_USER=$(id -u):$(id -g) + # Background diagnostics monitor: runs inside this step so output is + # visible in the CI log even if the job is manually cancelled + # (separate step + upload approach doesn't work on cancellation). + _diag_counter=0 + ( + # Wait for containers to start before first snapshot + sleep 60 + while true; do + _diag_counter=$((_diag_counter + 1)) + _diag_ts=$(date '+%Y-%m-%d_%H-%M-%S') + echo "::group::[DIAGNOSTICS] Snapshot ${_diag_counter} at ${_diag_ts}" + echo "--- Running containers ---" + docker ps -a --format '{{.ID}} {{.Image}} {{.Names}} {{.Status}}' || true + docker ps -a --format '{{.ID}} {{.Image}} {{.Names}}' | while read -r cid image name; do + if echo "${image} ${name}" | grep -Eiq 'pysystem-coupling|pyfluent|fluent|mapdl|systemcoupling'; then + echo "--- docker logs (last 80 lines): ${name} ---" + docker logs --tail 80 "${cid}" 2>&1 || true + fi + done + echo "::endgroup::" + sleep 120 + done + ) & + _DIAG_PID=$! + # On the first attempt do a full clean build. # On retries, clean only build artefacts while preserving # doc/source/examples so sphinx-gallery .md5 files remain available. @@ -435,10 +519,14 @@ jobs: exit 1 fi done + + kill "${_DIAG_PID}" 2>/dev/null || true env: PYSYC_DOC_BUILD_VERSION: ${{ env.DOC_BUILD_SYC_VERSION }} PYSYC_BUILD_SPHINX_GALLERY: 1 - PYSYC_GRPC_CHANNEL_OPTIONS_JSON: ${{ env.PYSYC_GRPC_CHANNEL_OPTIONS_JSON_261 }} + PYSYC_GRPC_CHANNEL_OPTIONS_JSON: ${{ env.PYSYC_GRPC_CHANNEL_OPTIONS_JSON_271 }} + PYSYC_SERVER_LOGGING_LEVEL: 5 + PYSYC_PRESERVE_CONTAINER: 1 ANSYSLMD_LICENSE_FILE: "1055@${{ secrets.LICENSE_SERVER }}" SYC_LAUNCH_CONTAINER: 1 SYC_IMAGE_TAG: ${{ env.SYC_IMAGE_VERSION }} @@ -451,6 +539,55 @@ jobs: DOCKER_IMAGE: ghcr.io/ansys/mapdl:${{ env.MAPDL_IMAGE_VERSION }} PYMAPDL_GRPC_TRANSPORT: "insecure" + - name: Collect System Coupling server logs + if: always() + run: | + mkdir -p ci-logs/syc-server-logs + + # Find and collect all SyC_Log_* files from the host + echo "Searching for SyC_Log_*.txt files on host filesystem..." + find /tmp -name "SyC_Log_*.txt" -type f 2>/dev/null | while read f; do + echo "Found: $f" + cp "$f" ci-logs/syc-server-logs/ 2>/dev/null || true + done + find . -name "SyC_Log_*.txt" -type f 2>/dev/null | while read f; do + echo "Found: $f" + cp "$f" ci-logs/syc-server-logs/ 2>/dev/null || true + done + + # Extract SyC log files from running or stopped docker containers + echo "Extracting logs from docker containers..." + docker ps -a --format '{{.ID}} {{.Names}}' 2>/dev/null | while read cid name; do + if [ -z "$cid" ]; then continue; fi + + echo "Processing container: $name ($cid)" + + # Try to find SyC_Log files inside the container via find + for search_path in /working /tmp /root /home; do + docker exec "$cid" find "$search_path" -name "SyC_Log_*.txt" -type f 2>/dev/null | while read logfile; do + if [ -n "$logfile" ]; then + echo "Copying from $name: $logfile" + docker cp "$cid:$logfile" ci-logs/syc-server-logs/ 2>/dev/null || true + fi + done || true + done + done + + echo "Collected SyC log files:" + ls -lah ci-logs/syc-server-logs/ || echo "No SyC log files found" + + - name: Clean up preserved containers + if: always() + run: | + echo "Cleaning up preserved containers..." + docker ps -a --format '{{.ID}} {{.Names}}' 2>/dev/null | while read cid name; do + if [ -z "$cid" ]; then continue; fi + if echo "${name}" | grep -Eiq 'pysystem-coupling|pyfluent|fluent|mapdl|systemcoupling'; then + echo "Removing container: $name" + docker rm -f "$cid" 2>/dev/null || true + fi + done + - name: Collect docs failure diagnostics if: failure() run: | diff --git a/doc/changelog.d/681.added.md b/doc/changelog.d/681.added.md new file mode 100644 index 000000000..564cd0218 --- /dev/null +++ b/doc/changelog.d/681.added.md @@ -0,0 +1 @@ +Chore: build using \"latest\" container diff --git a/doc/source/conf.py b/doc/source/conf.py index 70bf2179b..24d564b1f 100755 --- a/doc/source/conf.py +++ b/doc/source/conf.py @@ -210,8 +210,22 @@ def backup_folder(): def _reset_example(gallery_conf, fname: str, when: str): + import logging + import time + example_name = fname.replace(".py", "") + # Enable DEBUG logging for all examples to capture instrumentation diagnostics. + # This must be set early before examples create sessions/threads. + if when == "before": + from ansys.systemcoupling.core.util.logging import LOG + + try: + LOG.set_level(logging.DEBUG) + print("[_reset_example] DEBUG logging enabled for diagnostics") + except Exception as exc: + print(f"[_reset_example] Warning: Could not enable DEBUG logging: {exc}") + # Add any examples that need MAPDL to this list using_mapdl_examples = ["oscillating_plate", "turek_hron_fsi2", "cht_pipe"] @@ -232,19 +246,82 @@ def _reset_example(gallery_conf, fname: str, when: str): _clean_up_example_folder("00-systemcoupling", example_name) if using_mapdl_container: - subprocess.run( - ["docker", "compose", "-f", "mapdl-docker-compose.yml", "up", "-d"] + print( + f"[_reset_example] BEFORE example '{example_name}': " + f"launching MAPDL container..." ) - print("MAPDL container launched") + start_time = time.time() + try: + subprocess.run( + ["docker", "compose", "-f", "mapdl-docker-compose.yml", "up", "-d"], + timeout=120, + ) + elapsed = time.time() - start_time + print( + f"[_reset_example] MAPDL container launched successfully " + f"({elapsed:.1f}s)" + ) + except subprocess.TimeoutExpired: + print( + f"[_reset_example] TIMEOUT after 120s while launching MAPDL " + f"container" + ) + raise + except Exception as exc: + print( + f"[_reset_example] Exception launching MAPDL container: " + f"{type(exc).__name__}: {exc}" + ) + raise else: if using_mapdl_container: - subprocess.run( - ["docker", "compose", "-f", "mapdl-docker-compose.yml", "down"] + print( + f"[_reset_example] AFTER example '{example_name}': " + f"stopping MAPDL container..." ) - print("MAPDL container removed") - # Add sleep after example to see if it helps with grpcs errors seen after everything - # should have finished. + # Pass --timeout to docker compose to force-kill after 30s if graceful + # shutdown stalls (e.g. after an abrupt gRPC disconnect mid-solve). + # Also pass timeout to subprocess.run as a safety net in case docker + # compose itself hangs. + start_time = time.time() + try: + subprocess.run( + [ + "docker", + "compose", + "-f", + "mapdl-docker-compose.yml", + "down", + "--timeout", + "30", + ], + timeout=60, + ) + elapsed = time.time() - start_time + print( + f"[_reset_example] MAPDL container stopped successfully " + f"({elapsed:.1f}s)" + ) + except subprocess.TimeoutExpired: + print( + f"[_reset_example] TIMEOUT after 60s while stopping MAPDL " + f"container" + ) + raise + except Exception as exc: + print( + f"[_reset_example] Exception stopping MAPDL container: " + f"{type(exc).__name__}: {exc}" + ) + raise + # Add sleep after example to see if it helps with grpcs errors seen after + # everything should have finished. + print( + f"[_reset_example] AFTER example '{example_name}': sleeping 10s " + f"before cleanup..." + ) time.sleep(10) + print(f"[_reset_example] AFTER example '{example_name}': cleanup complete") rst_epilog = make_replacements_for_versioned_class_refs(("CASE", "SETUP", "SOLUTION")) diff --git a/examples/00-systemcoupling/cht_pipe.py b/examples/00-systemcoupling/cht_pipe.py index a4b74fff7..1ef3ce7bd 100644 --- a/examples/00-systemcoupling/cht_pipe.py +++ b/examples/00-systemcoupling/cht_pipe.py @@ -244,6 +244,9 @@ target_variable="HFLW", ) +# TEMP: disable AnsRpcBridge +syc.setup.coupling_participant[solid_name].use_ans_rpc_bridge = False + # %% # Define constants and calculate Biot number # ------------------------------------------ diff --git a/src/ansys/systemcoupling/core/__init__.py b/src/ansys/systemcoupling/core/__init__.py index 4e53a12e4..d66a42e9a 100644 --- a/src/ansys/systemcoupling/core/__init__.py +++ b/src/ansys/systemcoupling/core/__init__.py @@ -102,6 +102,13 @@ def launch( an argument has an associated value, the argument name and its value should be specified as two consecutive items of the list. + Notes + ----- + Environment variables: + - ``PYSYC_SERVER_LOGGING_LEVEL``: Enable System Coupling server-side logging + by specifying a logging level (e.g., ``5`` for verbose output). Log files + will be written to the working directory as ``SyC_Log_*.txt``. + Returns ------- ansys.systemcoupling.core.session.Session @@ -110,6 +117,14 @@ def launch( """ rpc = SycGrpc() version = str(version) if version is not None else None + + # Check for server-side logging level via environment variable + # e.g., PYSYC_SERVER_LOGGING_LEVEL=5 will add "-l 5" to launch args + server_logging_level = os.environ.get("PYSYC_SERVER_LOGGING_LEVEL") + if server_logging_level: + extra_args = list(extra_args) + ["-l", str(server_logging_level)] + LOG.info(f"System Coupling server logging level: {server_logging_level}") + if pypim.is_configured(): LOG.info( "Starting System Coupling remotely. Any launch arguments other " diff --git a/src/ansys/systemcoupling/core/client/grpc_client.py b/src/ansys/systemcoupling/core/client/grpc_client.py index bd7a79763..717675d06 100644 --- a/src/ansys/systemcoupling/core/client/grpc_client.py +++ b/src/ansys/systemcoupling/core/client/grpc_client.py @@ -523,36 +523,143 @@ def start_output(self, handle_output=None): Standard output and error streams are combined in the output streamed to this client. """ + LOG.debug("[start_output] ENTER: Starting output streaming") def default_handler(text): + import sys + + # Log to ensure this is being called (first 5 times, then every 100) + if not hasattr(default_handler, "_call_count"): + default_handler._call_count = 0 + default_handler._call_count += 1 + + if ( + default_handler._call_count <= 5 + or default_handler._call_count % 100 == 0 + ): + text_repr = repr(text[:80]) if len(text) > 0 else "" + LOG.debug( + f"[default_handler] PRINTING output call #{default_handler._call_count}: " + f"{text_repr}" + ) + print(text) + # Ensure stdout is flushed to prevent buffering + sys.stdout.flush() handle_output = handle_output or default_handler self.__output_thread = threading.Thread( target=self._read_stdstreams, args=(handle_output,) ) self.__output_thread.daemon = True + LOG.debug("[start_output] Starting daemon thread for output reading") self.__output_thread.start() + LOG.debug("[start_output] Output thread started") def end_output(self): """Stop streaming standard streams.""" + LOG.debug("[end_output] Called to stop output streaming") self.__ostream_service.end_streaming() def _read_stdstreams(self, handle_output): - output_iter = self.__ostream_service.begin_streaming() + import time + + LOG.debug("[_read_stdstreams] ENTER: Starting output streaming thread") + stream_start = time.time() + try: + LOG.debug("[_read_stdstreams] Calling begin_streaming()...") + output_iter = self.__ostream_service.begin_streaming() + LOG.debug( + "[_read_stdstreams] begin_streaming() returned, starting read loop" + ) + except Exception as e: + LOG.error( + f"[_read_stdstreams] EXCEPTION calling begin_streaming: " + f"{type(e).__name__}: {e}" + ) + return + text = "" - while True: - try: - response = next(output_iter) - text += response.text - if text and text[-1] == "\n": - handle_output(text[0:-1]) - text = "" - except StopIteration: - # Flush any trailing text - if text: - handle_output(text) - break + chunk_count = 0 + lines_flushed = 0 + try: + while True: + try: + response = next(output_iter) + chunk_count += 1 + + # Extract text from response and get details + chunk_text = ( + response.text if hasattr(response, "text") else str(response) + ) + chunk_len = len(chunk_text) + has_newline = "\n" in chunk_text + is_whitespace_only = chunk_text.isspace() if chunk_len > 0 else True + text += chunk_text + + # Log first 5 and every 100th chunk with detailed info + if chunk_count <= 5 or chunk_count % 100 == 0: + elapsed = time.time() - stream_start + if chunk_len == 0: + chunk_repr = "" + elif is_whitespace_only: + chunk_repr = f"" + else: + chunk_repr = repr(chunk_text[:60]) + LOG.debug( + f"[_read_stdstreams] chunk {chunk_count} after {elapsed:.1f}s: " + f"len={chunk_len}, newline={has_newline}, accum_len={len(text)}, " + f"first60={chunk_repr}" + ) + + # Periodic progress log (every 50 chunks) + if chunk_count % 50 == 0: + elapsed = time.time() - stream_start + LOG.debug( + f"[_read_stdstreams] {chunk_count} chunks after {elapsed:.1f}s, " + f"lines={lines_flushed}, accum={len(text)}" + ) + + # Split and flush complete lines + while "\n" in text: + line, text = text.split("\n", 1) + lines_flushed += 1 + # Log first 5 flushed lines and every 100th line + if lines_flushed <= 5 or lines_flushed % 100 == 0: + line_repr = repr(line[:80]) if len(line) > 0 else "" + LOG.debug( + f"[_read_stdstreams] FLUSHED line {lines_flushed}: {line_repr}" + ) + handle_output(line) + + except StopIteration: + elapsed = time.time() - stream_start + LOG.debug( + f"[_read_stdstreams] Stream ended after {chunk_count} chunks, " + f"{elapsed:.1f}s, lines_flushed={lines_flushed}" + ) + # Flush any trailing text + if text: + LOG.debug( + f"[_read_stdstreams] Flushing trailing text: " + f"len={len(text)}, content={repr(text[:100])}" + ) + handle_output(text) + lines_flushed += 1 + break + except Exception as e: + elapsed = time.time() - stream_start + LOG.error( + f"[_read_stdstreams] EXCEPTION after {chunk_count} chunks, {elapsed:.1f}s: " + f"{type(e).__name__}: {e}" + ) + break + finally: + elapsed = time.time() - stream_start + LOG.debug( + f"[_read_stdstreams] EXIT: {chunk_count} chunks, {lines_flushed} lines, " + f"{elapsed:.1f}s total" + ) def __getattr__(self, name): """Support command and query interfaces as method attributes, mainly to provide an diff --git a/src/ansys/systemcoupling/core/client/grpc_transport.py b/src/ansys/systemcoupling/core/client/grpc_transport.py index bec860de9..201aa9568 100644 --- a/src/ansys/systemcoupling/core/client/grpc_transport.py +++ b/src/ansys/systemcoupling/core/client/grpc_transport.py @@ -39,6 +39,7 @@ from ansys.systemcoupling.core.client.syc_launch_script import path_to_system_coupling from ansys.systemcoupling.core.syc_version import ( + SYC_LATEST_VERSION_CONCAT, SYC_VERSION_CONCAT, normalize_version, ) @@ -153,6 +154,9 @@ def __init__(self, launching: bool, connection_type: ConnectionType, **kwargs): version_str = SYC_VERSION_CONCAT else: + # Might be connecting to a container in which case "latest" is a valid version string. + # We assume that this corresponds to a particular version of System Coupling. + version = SYC_LATEST_VERSION_CONCAT if version == "latest" else version version_str = version if version else SYC_VERSION_CONCAT # Store normalised version info diff --git a/src/ansys/systemcoupling/core/client/syc_container.py b/src/ansys/systemcoupling/core/client/syc_container.py index 2c7c76c58..30ee62bed 100644 --- a/src/ansys/systemcoupling/core/client/syc_container.py +++ b/src/ansys/systemcoupling/core/client/syc_container.py @@ -108,6 +108,17 @@ def start_container( else: args = ["-m", "cosimgui", f"--grpcport=0.0.0.0:{port}", "--ptrace"] + # Apply server-side logging level if requested. + # PYSYC_SERVER_LOGGING_LEVEL is already handled in launch() for the process + # launch path, but in container mode the extra_args are not forwarded, so + # we check the env var here directly. + server_logging_level = os.getenv("PYSYC_SERVER_LOGGING_LEVEL") + if server_logging_level: + args = args + ["-l", server_logging_level] + LOG.info( + f"System Coupling container server logging level: {server_logging_level}" + ) + LOG.debug("Starting System Coupling docker container...") mounted_from = str(Path(mounted_from).absolute()) @@ -116,7 +127,6 @@ def start_container( "docker", "run", "-d", - "--rm", "-p", f"{port}:{port}", "-v", @@ -130,6 +140,16 @@ def start_container( f"ghcr.io/ansys/pysystem-coupling:{image_tag}", ] + args + # Optionally preserve container after exit for debugging (e.g., log extraction) + # By default, use --rm to clean up. Set PYSYC_PRESERVE_CONTAINER=1 to keep it. + preserve_container = os.getenv("PYSYC_PRESERVE_CONTAINER", "").lower() in ( + "1", + "true", + "yes", + ) + if not preserve_container: + run_args.insert(3, "--rm") + # Additional environment container_user = os.getenv("SYC_CONTAINER_USER") if container_user: diff --git a/src/ansys/systemcoupling/core/participant/manager.py b/src/ansys/systemcoupling/core/participant/manager.py index 2a4552439..bcecc1bf4 100644 --- a/src/ansys/systemcoupling/core/participant/manager.py +++ b/src/ansys/systemcoupling/core/participant/manager.py @@ -158,6 +158,10 @@ def solve(self): raise self.__solve_exception def _do_solve(self, syc_solve_thread): + import time + + start_time = time.time() + LOG.info(f"[_do_solve] ENTER at {start_time}") connection_threads = [ threading.Thread( target=lambda host_port, name=name, part=participant: self._participant_connect( @@ -168,28 +172,45 @@ def _do_solve(self, syc_solve_thread): for name, participant in self.__participants.items() ] - LOG.info("Starting SyC solve thread...") + LOG.info("[_do_solve] Starting SyC solve thread...") syc_solve_thread.start() - LOG.info("Waiting for participants to connect.") + LOG.info("[_do_solve] Waiting for participants to connect.") _start_threads(connection_threads) _join_threads(connection_threads) connection_threads.clear() - if self._get_n_connected() < len(self.__participants): + n_connected = self._get_n_connected() + LOG.debug( + f"[_do_solve] After connection: {n_connected}/" + f"{len(self.__participants)} connected" + ) + if n_connected < len(self.__participants): LOG.error("Some participants were unable to connect to System Coupling.") self.__syc_session.solution.abort() else: LOG.info("Participants connected.") - LOG.info("Starting participant solve threads.") + LOG.info("[_do_solve] Starting participant solve threads.") partsolve_threads = [ - threading.Thread(target=participant.solve) - for participant in self.__participants.values() + threading.Thread( + target=self._participant_solve_wrapper, + args=(name, participant), + daemon=True, + ) + for name, participant in self.__participants.items() ] _start_threads(partsolve_threads) - LOG.info("Waiting for all solve threads to join.") - _join_threads(partsolve_threads) - LOG.info("All participant solve threads joined.") + LOG.info( + f"[_do_solve] Entering _join_threads_or_abort for " + f"{len(partsolve_threads)} threads..." + ) + _join_threads_or_abort( + partsolve_threads, lambda: self.__solve_exception is not None + ) + elapsed = time.time() - start_time + LOG.info( + f"[_do_solve] Returned from _join_threads_or_abort after {elapsed:.1f}s" + ) def _clear_n_connected(self) -> None: with self.__connection_lock: @@ -210,21 +231,76 @@ def _get_host_and_port(self, participant_name: str) -> Tuple[str, int]: def _participant_connect( self, name: str, host_port: Tuple[str, int], participant: ParticipantProtocol ) -> None: + import time + + connect_start = time.time() + LOG.debug(f"[_participant_connect] {name}: ENTER at {connect_start}") try: + LOG.debug( + f"[_participant_connect] {name}: Calling connect() with SyC at " + f"{host_port[0]}:{host_port[1]}..." + ) participant.connect(*host_port, name) + connect_elapsed = time.time() - connect_start + LOG.info( + f"[_participant_connect] {name}: connect() returned after " + f"{connect_elapsed:.1f}s (note: backend connection may occur later " + f"during solve)" + ) self._increment_n_connected() except Exception as e: - LOG.error(f"Participant {name} failed to connect. Exception: {e}") + connect_elapsed = time.time() - connect_start + LOG.error( + f"[_participant_connect] {name}: EXCEPTION after {connect_elapsed:.1f}s: " + f"{type(e).__name__}: {e}" + ) + + def _participant_solve_wrapper( + self, name: str, participant: ParticipantProtocol + ) -> None: + """Wrapper around participant.solve() that logs timing and exceptions.""" + import time + + solve_start = time.time() + LOG.info(f"[_participant_solve] {name}: ENTER at {solve_start}") + try: + LOG.debug(f"[_participant_solve] {name}: Calling participant.solve()...") + participant.solve() + solve_elapsed = time.time() - solve_start + LOG.info(f"[_participant_solve] {name}: SUCCESS after {solve_elapsed:.1f}s") + except Exception as e: + solve_elapsed = time.time() - solve_start + LOG.error( + f"[_participant_solve] {name}: EXCEPTION after {solve_elapsed:.1f}s: " + f"{type(e).__name__}: {e}" + ) + raise def _syc_solve(self): + import time + + start_time = time.time() + LOG.debug(f"[_syc_solve] ENTER at {start_time}") try: # We use `syc_session.solution._solve` here as it is # the lower level solve command. `sys_session.solution.solve` # would bring us recursively back into *this* function + rpc_start = time.time() + LOG.debug("[_syc_solve] About to call syc_session.solution._solve()...") + LOG.debug(f"[_syc_solve] RPC call start time: {rpc_start}") self.__syc_session.solution._solve() + rpc_elapsed = time.time() - rpc_start + LOG.debug(f"[_syc_solve] RPC call returned after {rpc_elapsed:.2f}s") + LOG.debug( + f"[_syc_solve] SUCCESS at {time.time() - start_time:.2f}s elapsed" + ) except Exception as e: + elapsed = time.time() - start_time self.__solve_exception = e - LOG.error(f"Solve terminated with exception: {e}.") + LOG.error( + f"[_syc_solve] EXCEPTION after {elapsed:.2f}s: {type(e).__name__}: {e}" + ) + LOG.debug(f"[_syc_solve] Exception stored; thread exiting") def _start_threads(threads: List[threading.Thread]) -> None: @@ -235,3 +311,58 @@ def _start_threads(threads: List[threading.Thread]) -> None: def _join_threads(threads: List[threading.Thread]) -> None: for thread in threads: thread.join() + + +def _join_threads_or_abort( + threads: List[threading.Thread], + abort_check, + poll_interval: float = 1.0, + max_wait_seconds: float = 600.0, +) -> None: + """Join threads, stopping early if ``abort_check()`` returns True or timeout exceeded. + + Used to avoid deadlocking when the SyC solve thread has already failed: + participant solve threads may be blocked indefinitely waiting for SyC + coupling coordination data that will never arrive. Once the SyC failure + is detected we give up waiting so that the exception can propagate and + example cleanup (container teardown) can proceed. + + If max_wait_seconds is exceeded without all threads joining or SyC failure + detected, abort with a warning to prevent indefinite hangs. + """ + import time + + start_time = time.time() + LOG.debug( + f"[_join_threads_or_abort] ENTER: {len(threads)} threads, " + f"poll_interval={poll_interval}s, max_wait={max_wait_seconds}s" + ) + poll_count = 0 + while any(t.is_alive() for t in threads): + poll_count += 1 + alive_count = sum(1 for t in threads if t.is_alive()) + should_abort = abort_check() + elapsed = time.time() - start_time + LOG.debug( + f"[_join_threads_or_abort] poll {poll_count} at {elapsed:.1f}s: " + f"{alive_count}/{len(threads)} alive, abort_check={should_abort}" + ) + if should_abort: + LOG.warning( + f"[_join_threads_or_abort] SyC solve thread failed; abandoning wait " + f"for {alive_count} participant solve threads to allow exception " + f"propagation and cleanup." + ) + return + if elapsed >= max_wait_seconds: + LOG.error( + f"[_join_threads_or_abort] TIMEOUT after {elapsed:.1f}s with " + f"{alive_count}/{len(threads)} threads still alive. " + f"SyC thread likely hung in RPC call. Abandoning wait." + ) + return + for t in threads: + t.join(timeout=poll_interval) + LOG.debug( + f"[_join_threads_or_abort] EXIT: all threads joined after {time.time() - start_time:.1f}s" + ) diff --git a/src/ansys/systemcoupling/core/syc_version.py b/src/ansys/systemcoupling/core/syc_version.py index a7916f91f..98fcf60bb 100644 --- a/src/ansys/systemcoupling/core/syc_version.py +++ b/src/ansys/systemcoupling/core/syc_version.py @@ -29,7 +29,13 @@ SYC_MAJOR_VERSION = 26 SYC_MINOR_VERSION = 1 +# Version for "latest" tag in container images. +SYC_MAJOR_LATEST_VERSION = 27 +SYC_MINOR_LATEST_VERSION = 1 + + SYC_VERSION_CONCAT = f"{SYC_MAJOR_VERSION}{SYC_MINOR_VERSION}" +SYC_LATEST_VERSION_CONCAT = f"{SYC_MAJOR_LATEST_VERSION}{SYC_MINOR_LATEST_VERSION}" SYC_VERSION_DOT = f"{SYC_MAJOR_VERSION}.{SYC_MINOR_VERSION}" SYC_VERSION_UNDERSCORE = f"{SYC_MAJOR_VERSION}_{SYC_MINOR_VERSION}"