diff --git a/.github/workflows/coverage.yml b/.github/workflows/coverage.yml index 543a2121..393c1f4c 100644 --- a/.github/workflows/coverage.yml +++ b/.github/workflows/coverage.yml @@ -12,6 +12,7 @@ jobs: coverage: runs-on: ubuntu-latest + timeout-minutes: 20 steps: - uses: actions/checkout@v7 - name: Install dependencies diff --git a/.github/workflows/integration.yml b/.github/workflows/integration.yml index 2ecde8b2..7e180d1e 100644 --- a/.github/workflows/integration.yml +++ b/.github/workflows/integration.yml @@ -12,6 +12,7 @@ jobs: conmon: runs-on: ubuntu-latest + timeout-minutes: 20 steps: - uses: actions/checkout@v7 - run: sudo hack/github-actions-setup @@ -22,6 +23,7 @@ jobs: cri-o: runs-on: ubuntu-latest + timeout-minutes: 90 strategy: matrix: go-version: [stable, oldstable] diff --git a/.github/workflows/validate.yml b/.github/workflows/validate.yml index a89e0120..31ca5740 100644 --- a/.github/workflows/validate.yml +++ b/.github/workflows/validate.yml @@ -13,6 +13,7 @@ jobs: lint: runs-on: ubuntu-latest + timeout-minutes: 10 steps: - uses: actions/checkout@v7 - name: Check C code formatting diff --git a/hack/github-actions-setup b/hack/github-actions-setup index 84d6e8b8..c77da829 100755 --- a/hack/github-actions-setup +++ b/hack/github-actions-setup @@ -15,6 +15,11 @@ declare -A VERSIONS=( main() { set -x + # None of the git clones below has a timeout of its own, and a stalled + # one hangs this script until the job times out. Make git give up on a + # connection that transfers less than 1 KiB/s for a minute. + export GIT_HTTP_LOW_SPEED_LIMIT=1024 GIT_HTTP_LOW_SPEED_TIME=60 + prepare_system install_packages @@ -61,15 +66,56 @@ remove_runtimes() { sudo rm -f /usr/{local/,}{s,}bin/{runc,crun} } +APT_OPTS=( + -o Acquire::Retries=3 + -o Acquire::http::Timeout=60 + -o Acquire::https::Timeout=60 + # Fail rather than wait for a lock a timed out run may have left behind. + -o DPkg::Lock::Timeout=60 +) + +# apt_get runs apt-get with the options above, under a timeout, retrying a few +# times. +# +# The Acquire::*::Timeout settings apply to individual requests of the +# acquisition method, and are not enough on their own: a run has been seen +# printing a few "Get:" lines and then sitting there for 19 minutes, until the +# job timed out. Bounding the whole command is the only thing that reliably +# helps, and since a stalled mirror is a transient thing, retrying it is +# usually all it takes. +apt_get() { + local try timeout=180 + + # "install" is not just a download: it unpacks and configures a few dozen + # packages, and needs a good deal more time than a metadata refresh. Being + # killed in the middle of that leaves dpkg with a half-applied + # transaction, which retrying does not fix by itself -- hence the + # --configure below. + [ "$1" = "install" ] && timeout=600 + + for try in 1 2 3; do + if sudo timeout "$timeout" apt-get "${APT_OPTS[@]}" "$@"; then + return 0 + fi + echo "apt-get $1: failed or timed out, attempt $try of 3" >&2 + sudo dpkg --configure -a || true + sleep 10 + done + + return 1 +} + install_packages() { . /etc/os-release CRIU_REPO="https://download.opensuse.org/repositories/devel:/tools:/criu/xUbuntu_$VERSION_ID" - curl -fSsL $CRIU_REPO/Release.key | sudo gpg --dearmor -o /etc/apt/trusted.gpg.d/criu.gpg + # curl has no total timeout by default, and no retries at all. + curl -fSsL --retry 5 --retry-delay 3 --max-time 120 "$CRIU_REPO"/Release.key | + sudo gpg --dearmor -o /etc/apt/trusted.gpg.d/criu.gpg echo "deb $CRIU_REPO/ /" | sudo tee /etc/apt/sources.list.d/criu.list - sudo apt update - sudo apt install -y \ + apt_get update + apt_get install -y \ autoconf \ automake \ conntrack \ @@ -134,7 +180,9 @@ install_cni_plugins() { TARBALL=cni-plugins-linux-amd64-${VERSIONS["cni-plugins"]}.tgz CNI_DIR=/opt/cni/bin sudo mkdir -p "$CNI_DIR" - wget -O "$TARBALL" $URL/"${VERSIONS["cni-plugins"]}"/"$TARBALL" + # wget defaults to 20 tries and a 900 second read timeout; that is a lot + # of patience for a job that should take seconds. + wget --timeout=60 --tries=3 -O "$TARBALL" $URL/"${VERSIONS["cni-plugins"]}"/"$TARBALL" sudo tar xf "$TARBALL" -C "$CNI_DIR" rm "$TARBALL" ls -lah "$CNI_DIR" diff --git a/test/02-ctr-logs.bats b/test/02-ctr-logs.bats index 4a3a7615..9843752c 100644 --- a/test/02-ctr-logs.bats +++ b/test/02-ctr-logs.bats @@ -78,7 +78,7 @@ run_conmon_with_log_opts() { } @test "ctr logs: journald with --log-label, no '=' in label" { - start_conmon_with_default_args \ + run_conmon_expecting_failure \ --log-path "journald:" \ --log-label "CONMON_TEST_LABEL1" @@ -86,7 +86,7 @@ run_conmon_with_log_opts() { } @test "ctr logs: journald with --log-label, multiple '=' in label" { - start_conmon_with_default_args \ + run_conmon_expecting_failure \ --log-path "journald:" \ --log-label "CONMON_TEST_LABEL1=FOO=$CTR_ID" @@ -94,7 +94,7 @@ run_conmon_with_log_opts() { } @test "ctr logs: journald with --log-label, no label name" { - start_conmon_with_default_args \ + run_conmon_expecting_failure \ --log-path "journald:" \ --log-label "=$CTR_ID" @@ -102,7 +102,7 @@ run_conmon_with_log_opts() { } @test "ctr logs: journald with --log-label, invalid character" { - start_conmon_with_default_args \ + run_conmon_expecting_failure \ --log-path "journald:" \ --log-label "MY%LABEL=$CTR_ID" @@ -110,7 +110,7 @@ run_conmon_with_log_opts() { } @test "ctr logs: k8s-file with --log-label" { - start_conmon_with_default_args \ + run_conmon_expecting_failure \ --log-path "k8s-file:$LOG_PATH" \ --log-label "CONMON_TEST_LABEL1=$CTR_ID" @@ -134,7 +134,7 @@ run_conmon_with_log_opts() { } @test "ctr logs: k8s-file with --log-tag" { - start_conmon_with_default_args \ + run_conmon_expecting_failure \ --log-path "k8s-file:$LOG_PATH" \ --log-tag "CONMON_TEST_LABEL1" diff --git a/test/04-runtime.bats b/test/04-runtime.bats index 9e03a5cb..2745c3bd 100644 --- a/test/04-runtime.bats +++ b/test/04-runtime.bats @@ -88,7 +88,7 @@ teardown() { # Check that the pid is sent to the sync pipe. assert_file_exists $TEST_TMPDIR/syncpipe-output run cat $TEST_TMPDIR/syncpipe-output - CONTAINER_PID=$(cat "$PID_FILE") + CONTAINER_PID=$(cat "$CONTAINER_PIDFILE") assert_json "${output}" =~ "\"pid\": $CONTAINER_PID" } @@ -116,7 +116,7 @@ teardown() { assert_file_exists $CONMON_PID_FILE CONMON_PID=$(cat "$CONMON_PID_FILE") - wait $CONMON_PID_FILE 2>/dev/null || true + wait_for_conmon_exit "$CONMON_PID" # Check that the error is sent to the sync pipe. assert_file_exists $TEST_TMPDIR/syncpipe-output diff --git a/test/06-exec-exit-status.bats b/test/06-exec-exit-status.bats index d250e374..6cb48763 100755 --- a/test/06-exec-exit-status.bats +++ b/test/06-exec-exit-status.bats @@ -50,6 +50,11 @@ teardown() { fi # Check if we can create a simple container for testing. + # + # NB: every podman invocation in this test is wrapped in a timeout. None + # of them has any business taking long, and an unbounded one hangs the + # whole suite -- bats runs tests serially, and a command substitution + # waits for stdout to be closed, which a misbehaving conmon may never do. run timeout 10 podman --conmon $conmon_path run --rm "$UBI10_MICRO_IMAGE" true if [ "$status" -ne 0 ]; then die "cannot create test containers with podman: $output" @@ -59,37 +64,37 @@ teardown() { # Create a test container local container_id - container_id=$(podman --conmon $conmon_path run -dt "$UBI10_MICRO_IMAGE" sleep 30) + container_id=$(timeout 60 podman --conmon $conmon_path run -dt "$UBI10_MICRO_IMAGE" sleep 30) if [ -z "$container_id" ]; then die "failed to create test container" fi # Test 1: Success case - if ! podman --conmon $conmon_path exec "$container_id" true; then - podman --conmon $conmon_path rm -f "$container_id" >/dev/null 2>&1 + if ! timeout 60 podman --conmon $conmon_path exec "$container_id" true; then + timeout 60 podman --conmon $conmon_path rm -f "$container_id" >/dev/null 2>&1 echo "FAIL: true command should succeed" return 1 fi # Test 2: Failure case - this would fail with the regression - if podman --conmon $conmon_path exec "$container_id" false; then - podman --conmon $conmon_path rm -f "$container_id" >/dev/null 2>&1 + if timeout 60 podman --conmon $conmon_path exec "$container_id" false; then + timeout 60 podman --conmon $conmon_path rm -f "$container_id" >/dev/null 2>&1 echo "FAIL: false command should fail (regression detected!)" echo "This indicates the fc0a342 regression where all exec commands return 0" return 1 fi # Test 3: Custom exit code - this would return 0 with the regression - if podman --conmon $conmon_path exec "$container_id" sh -c 'exit 42'; then - podman --conmon $conmon_path rm -f "$container_id" >/dev/null 2>&1 + if timeout 60 podman --conmon $conmon_path exec "$container_id" sh -c 'exit 42'; then + timeout 60 podman --conmon $conmon_path rm -f "$container_id" >/dev/null 2>&1 echo "FAIL: 'exit 42' should fail with code 42 (regression detected!)" echo "This indicates the fc0a342 regression where all exec commands return 0" return 1 fi # Clean up - podman --conmon $conmon_path rm -f "$container_id" >/dev/null 2>&1 + timeout 60 podman --conmon $conmon_path rm -f "$container_id" >/dev/null 2>&1 echo "Integration test passed: exec exit codes work correctly" } \ No newline at end of file diff --git a/test/07-attach.bats b/test/07-attach.bats index 9370a6f4..94b7fa46 100644 --- a/test/07-attach.bats +++ b/test/07-attach.bats @@ -30,6 +30,9 @@ teardown() { # Pipe is closed without --stdin, so `/cat` does not hang indefinitely, but finishes. start_conmon_with_default_args --log-path "k8s-file:$LOG_PATH" wait_for_runtime_status "$CTR_ID" stopped + # The container being stopped does not mean conmon is done writing its + # output to the log; wait for conmon to exit before reading the log. + wait_for_conmon_exit "$CONMON_PID" # Check that log file was created assert_file_exists "$LOG_PATH" diff --git a/test/08-exec.bats b/test/08-exec.bats index 6d0057fe..cfdc7c2e 100644 --- a/test/08-exec.bats +++ b/test/08-exec.bats @@ -16,13 +16,18 @@ teardown() { @test "exec: simple --exec --exec-process-spec" { start_conmon_with_default_args --log-path "k8s-file:$LOG_PATH" wait_for_runtime_status "$CTR_ID" running + local main_conmon_pid=$CONMON_PID start_conmon_with_default_args \ --log-path "k8s-file:$LOG_PATH.exec" \ --exec \ --exec-process-spec "${BUNDLE_PATH}/process.json" + local exec_conmon_pid=$CONMON_PID wait_for_runtime_status "$CTR_ID" stopped + # Both logs are read below, so wait for both conmons to write them out. + wait_for_conmon_exit "$main_conmon_pid" + wait_for_conmon_exit "$exec_conmon_pid" # Check that the main process noticed the /tmp/test.txt. assert_file_exists "$LOG_PATH" @@ -39,14 +44,13 @@ teardown() { start_conmon_with_default_args --log-path "k8s-file:$LOG_PATH" wait_for_runtime_status "$CTR_ID" running - start_conmon_with_default_args \ + run_conmon_expecting_failure \ --log-path "k8s-file:$LOG_PATH.exec" \ --sync \ --exec \ --exec-process-spec "${BUNDLE_PATH}/process.json" \ --exec-attach - assert_failure assert "${output}" =~ "Attach can only be specified for a non-legacy exec session" } @@ -54,7 +58,7 @@ teardown() { start_conmon_with_default_args --log-path "k8s-file:$LOG_PATH" wait_for_runtime_status "$CTR_ID" running - start_conmon_with_default_args \ + run_conmon_expecting_failure \ --log-path "k8s-file:$LOG_PATH.exec" \ --api-version 1 \ --sync \ @@ -62,7 +66,6 @@ teardown() { --exec-process-spec "${BUNDLE_PATH}/process.json" \ --exec-attach - assert_failure assert "${output}" =~ "--attach specified but _OCI_ATTACHPIPE was not" } @@ -135,6 +138,7 @@ teardown() { # The exec should start now. wait_for_runtime_status "$CTR_ID" stopped + wait_for_conmon_exit "$CONMON_PID" assert_file_exists "$LOG_PATH.exec" run cat "$LOG_PATH.exec" assert "${output}" =~ "Hello from exec!" @@ -177,7 +181,7 @@ teardown() { # the second one is the exit code. assert_file_exists $TEST_TMPDIR/syncpipe-output run cat $TEST_TMPDIR/syncpipe-output - CONTAINER_PID=$(cat "$PID_FILE") + CONTAINER_PID=$(cat "$CONTAINER_PIDFILE") assert_json "${output}" =~ "\"data\": $CONTAINER_PID" assert_json "${output}" =~ '"data": 0' } diff --git a/test/10-ctrl.bats b/test/10-ctrl.bats index 6844cf44..c1ac3648 100644 --- a/test/10-ctrl.bats +++ b/test/10-ctrl.bats @@ -18,6 +18,7 @@ test_ctl_command() { local command="$1" start_conmon_with_default_args --log-path "k8s-file:$LOG_PATH" -t wait_for_runtime_status "$CTR_ID" running + local main_conmon_pid=$CONMON_PID echo "$command" > ${CTL_PATH} @@ -27,6 +28,8 @@ test_ctl_command() { --exec-process-spec "${BUNDLE_PATH}/process.json" wait_for_runtime_status "$CTR_ID" stopped + # Callers read $LOG_PATH, written by the container's conmon. + wait_for_conmon_exit "$main_conmon_pid" } # Helper function to send the resize command. Fails if the resize command @@ -87,6 +90,7 @@ test_resize_command_ok() { @test "ctrl: rotate logs" { start_conmon_with_default_args --log-path "k8s-file:$LOG_PATH" -t wait_for_runtime_status "$CTR_ID" running + local main_conmon_pid=$CONMON_PID # Remove the log. rm -f $LOG_PATH @@ -99,6 +103,7 @@ test_resize_command_ok() { --exec-process-spec "${BUNDLE_PATH}/process.json" wait_for_runtime_status "$CTR_ID" stopped + wait_for_conmon_exit "$main_conmon_pid" # Check that the log exists now. assert_file_exists "$LOG_PATH" @@ -166,6 +171,7 @@ test_resize_command_ok() { -t \ --log-rotate wait_for_runtime_status "$CTR_ID" running + local main_conmon_pid=$CONMON_PID # The control message should rotate the log echo "2 1 1" > ${CTL_PATH} @@ -174,6 +180,8 @@ test_resize_command_ok() { --log-path "k8s-file:$LOG_PATH.exec" \ --exec \ --exec-process-spec "${BUNDLE_PATH}/process.json" + # $LOG_PATH and $LOG_PATH.1, read below, are the main conmon's. + wait_for_conmon_exit "$main_conmon_pid" assert_file_exists "$LOG_PATH.exec" run cat "$LOG_PATH.exec" diff --git a/test/setup_suite.bash b/test/setup_suite.bash index a4d94769..242e1453 100644 --- a/test/setup_suite.bash +++ b/test/setup_suite.bash @@ -34,8 +34,11 @@ setup_suite() { # reason for the failure is the whole point. # NB: no --policy here, it is not supported by podman < 5.0 (as found # on e.g. Ubuntu 24.04), and plain "podman pull" pulls anyway. - if ! podman pull "$UBI10_MICRO_IMAGE"; then - suite_fail "failed to pull $UBI10_MICRO_IMAGE" + # The pull is the one thing here that talks to the network, and podman + # has no timeout of its own, so a stalled registry hangs the whole suite + # before a single test runs. Five minutes is plenty for a ~15 MB image. + if ! timeout 300 podman pull "$UBI10_MICRO_IMAGE"; then + suite_fail "failed to pull $UBI10_MICRO_IMAGE (timed out?)" return 1 fi diff --git a/test/test_helper.bash b/test/test_helper.bash index ca6195e2..b008fbbe 100644 --- a/test/test_helper.bash +++ b/test/test_helper.bash @@ -310,7 +310,11 @@ setup_test_env() { export CTR_ID CTR_ID=$(generate_ctr_id) export LOG_PATH="$TEST_TMPDIR/container.log" + # For tests that run conmon directly; conmons started by _run_conmon each + # get their own, in $CONTAINER_PIDFILE. export PID_FILE="$TEST_TMPDIR/pidfile" + # For tests that run conmon directly; conmons started by _run_conmon each + # get their own, in $CONMON_PIDFILE. export CONMON_PID_FILE="$TEST_TMPDIR/conmon-pidfile" export BUNDLE_PATH="$TEST_TMPDIR" export ROOTFS="$TEST_TMPDIR/rootfs" @@ -387,7 +391,10 @@ assert_stderr_contains() { wait_for_runtime_status() { local cid=$1 local expected_status=$2 - local how_long=5 + # Generous on purpose: this polls, so on a healthy machine it returns on + # the first iteration, and the only thing a low limit buys is flakes on a + # loaded CI runner. + local how_long=30 t1=$(expr $SECONDS + $how_long) while [ $SECONDS -lt $t1 ]; do @@ -402,10 +409,34 @@ wait_for_runtime_status() { die "timed out waiting for '$expected_status' from $cid" } -# Helper function to start conmon with default arguments. -# Additional conmon arguments can be passed to this function. -start_conmon_with_default_args() { - local extra_args=("$@") +# Helper function to wait until the conmon process $pid has exited. +# +# The container reaching the "stopped" state does not mean its output has made +# it to the log yet; conmon having exited does. +wait_for_conmon_exit() { + local pid=$1 + local how_long=${2:-10} + + local t1=$((SECONDS + how_long)) + while [ "$SECONDS" -lt "$t1" ]; do + kill -0 "$pid" 2>/dev/null || return 0 + sleep 0.1 + done + + die "timed out waiting for conmon (pid $pid) to exit" +} + +# _run_conmon runs conmon with the default arguments plus the ones given, +# leaving the result in $status and $output as `run` does. $CONMON_PIDFILE and +# $CONTAINER_PIDFILE are set to the pidfiles this conmon was told to write. +# +# A test may start more than one conmon (an --exec one, say), so each gets +# pidfiles of its own rather than having them clobber shared ones. +_run_conmon() { + ((++CONMON_STARTED)) + CONMON_PIDFILE="$TEST_TMPDIR/conmon-pidfile.$CONMON_STARTED" + CONTAINER_PIDFILE="$TEST_TMPDIR/pidfile.$CONMON_STARTED" + run timeout 10s "$CONMON_BINARY" \ --cid "$CTR_ID" \ --cuuid "$CTR_ID" \ @@ -413,14 +444,35 @@ start_conmon_with_default_args() { --bundle "$BUNDLE_PATH" \ --socket-dir-path "$SOCKET_PATH" \ --log-level trace \ - --container-pidfile "$PID_FILE" \ + --container-pidfile "$CONTAINER_PIDFILE" \ --syslog \ - --conmon-pidfile "$CONMON_PID_FILE" "${extra_args[@]}" + --conmon-pidfile "$CONMON_PIDFILE" "$@" +} + +# Helper function to run conmon with default arguments where conmon is +# expected to fail. That it did is asserted here, so the caller is left to +# check $output for the particular complaint it is after. +run_conmon_expecting_failure() { + _run_conmon "$@" + assert_failure +} + +# Helper function to start conmon with default arguments. +# Additional conmon arguments can be passed to this function. +start_conmon_with_default_args() { + local pidfile + + _run_conmon "$@" + pidfile=$CONMON_PIDFILE if [ "$status" -ne 0 ]; then - return + die "conmon failed with status $status: $output" fi + # The pid of the conmon just started. A test starting more than one has + # to save this before starting the next. + CONMON_PID=$(cat "$pidfile") + # Do not try to start the container if it has already been started. This # happens when `start_conmon_with_default_args` has already been called # and this second call uses an option like --exec, which connects to an @@ -439,7 +491,7 @@ start_conmon_with_default_args() { wait_for_runtime_status "$CTR_ID" created # Check that conmon pidfile was created - [ -f "$CONMON_PID_FILE" ] + [ -f "$pidfile" ] # Start the container and wait until it really starts. run_runtime start "$CTR_ID" @@ -453,6 +505,8 @@ start_conmon_with_default_args() { run_conmon_with_default_args() { start_conmon_with_default_args "$@" wait_for_runtime_status "$CTR_ID" stopped + # Every caller reads a log written by this conmon afterwards. + wait_for_conmon_exit "$CONMON_PID" } # Generic helper function to create pipe and read from it.