CON-1514 summarize startup failure evidence

Author: Hannes Zietsman

tests/cli/test_machines_commands.py

@@ -130,7 +130,7 @@ def test_successful_destroy_does_not_warn_when_instance_is_already_gone(
         assert exit_info.value.code == 0
         assert destroy_instance.call_count == 1
         captured = capsys.readouterr()
-        assert "Instance 123 destroyed successfully on attempt 1." in captured.out
+        assert "Temporary test instance 123 destroyed." in captured.out
         assert "WARNING: failed to destroy test instance 123" not in captured.out
 
 
@@ -193,7 +193,9 @@ def test_ignore_requirements_warns_on_success(self, parse_argv, monkeypatch, cap
         assert "Requirement checks are skipped as a pass/fail gate" in out
         assert "does not qualify this machine for verification" in out
         assert out.count("does not qualify this machine for verification") >= 2
-        assert "Test passed." in out
+        assert "Self-test summary" in out
+        assert "Status: passed" in out
+        assert "Result: self-test completed successfully." in out
 
     def test_ignore_requirements_warning_in_raw_summary(self, parse_argv, monkeypatch, capsys):
         from vastai.cli.commands import machines
@@ -406,7 +408,7 @@ def test_no_offer_non_raw_renders_once_without_stale_placeholders(
         search = Mock(side_effect=[[], [broader_offer]])
         monkeypatch.setattr("vastai.cli.commands.machines.offers_api.search_offers", search)
 
-        args = parse_argv(["self-test", "machine", "42"])
+        args = parse_argv(["self-test", "machine", "42", "--log-level", "debug"])
         with pytest.raises(SystemExit) as exc_info:
             args.func(args)
 
@@ -428,7 +430,7 @@ def test_preflight_outputs_actual_required_once(
         search = Mock(return_value=[bad_offer])
         monkeypatch.setattr("vastai.cli.commands.machines.offers_api.search_offers", search)
 
-        args = parse_argv(["self-test", "machine", "42"])
+        args = parse_argv(["self-test", "machine", "42", "--log-level", "debug"])
         with pytest.raises(SystemExit) as exc_info:
             args.func(args)
 
@@ -442,6 +444,49 @@ def test_preflight_outputs_actual_required_once(
         assert "--filter" not in captured.out
         assert search.call_count == 1
 
+    def test_default_info_preflight_failure_is_compact(
+        self, parse_argv, patch_get_client, monkeypatch, capsys
+    ):
+        bad_offer = _self_test_offer(cuda_max_good=11.7, reliability=0.9)
+        search = Mock(return_value=[bad_offer])
+        monkeypatch.setattr("vastai.cli.commands.machines.offers_api.search_offers", search)
+
+        args = parse_argv(["self-test", "machine", "42"])
+        with pytest.raises(SystemExit) as exc_info:
+            args.func(args)
+
+        captured = capsys.readouterr()
+        assert exc_info.value.code == 1
+        assert "Starting self-test for machine 42." in captured.out
+        assert "Preflight failed." in captured.out
+        assert "Self-test summary" in captured.out
+        assert "Status: failed" in captured.out
+        assert "Failed checks: CUDA version, Reliability" in captured.out
+        assert "Reason: 2 preflight requirement check(s) failed." in captured.out
+        assert "Preflight diagnostics for machine 42 failed:" not in captured.out
+        assert "actual: 11.7 CUDA" not in captured.out
+        assert "purpose:" not in captured.out
+
+    def test_warning_log_level_keeps_summary_but_suppresses_info_lifecycle(
+        self, parse_argv, patch_get_client, monkeypatch, capsys
+    ):
+        bad_offer = _self_test_offer(cuda_max_good=11.7, reliability=0.9)
+        search = Mock(return_value=[bad_offer])
+        monkeypatch.setattr("vastai.cli.commands.machines.offers_api.search_offers", search)
+
+        args = parse_argv(["self-test", "machine", "42", "--log-level", "warning"])
+        with pytest.raises(SystemExit) as exc_info:
+            args.func(args)
+
+        captured = capsys.readouterr()
+        assert exc_info.value.code == 1
+        assert "Starting self-test for machine 42." not in captured.out
+        assert "Preflight failed." not in captured.out
+        assert "Self-test summary" in captured.out
+        assert "Status: failed" in captured.out
+        assert "Failed checks: CUDA version, Reliability" in captured.out
+        assert "actual: 11.7 CUDA" not in captured.out
+
     def test_selected_offer_is_reused_for_rental(
         self, parse_argv, patch_get_client, monkeypatch
     ):
@@ -470,7 +515,7 @@ def test_preflight_normalizes_api_gpu_ram_units(
         search = Mock(return_value=[bad_offer])
         monkeypatch.setattr("vastai.cli.commands.machines.offers_api.search_offers", search)
 
-        args = parse_argv(["self-test", "machine", "42"])
+        args = parse_argv(["self-test", "machine", "42", "--log-level", "debug"])
         with pytest.raises(SystemExit) as exc_info:
             args.func(args)
 
@@ -600,7 +645,7 @@ def test_preflight_direct_port_overage_renders_advisory(
             Mock(return_value=[offer]),
         )
 
-        args = parse_argv(["self-test", "machine", "42"])
+        args = parse_argv(["self-test", "machine", "42", "--log-level", "debug"])
         with pytest.raises(SystemExit) as exc_info:
             args.func(args)
 
@@ -763,6 +808,48 @@ def test_env_test_image_overrides_default_mapping(
         assert create.call_args.kwargs["image"] == "vastai/test:p3-env"
         assert create.call_args.kwargs["runtype"] == "ssh_direc ssh_proxy"
 
+    @pytest.mark.parametrize(
+        "argv,env_level,expected_level,expected_source",
+        [
+            (["self-test", "machine", "42", "--raw"], None, "info", "default"),
+            (["self-test", "machine", "42", "--log-level", "debug", "--raw"], None, "debug", "argument"),
+            (["self-test", "machine", "42", "--debugging", "--raw"], None, "debug", "debugging"),
+            (["self-test", "machine", "42", "--raw"], "debug", "debug", "VAST_LOG_LEVEL"),
+            (["self-test", "machine", "42", "--raw"], "not-a-level", "info", "default_invalid_VAST_LOG_LEVEL"),
+        ],
+    )
+    def test_self_test_log_level_resolution(
+        self,
+        parse_argv,
+        patch_get_client,
+        monkeypatch,
+        argv,
+        env_level,
+        expected_level,
+        expected_source,
+    ):
+        offer = _self_test_offer()
+        if env_level is None:
+            monkeypatch.delenv("VAST_LOG_LEVEL", raising=False)
+        else:
+            monkeypatch.setenv("VAST_LOG_LEVEL", env_level)
+        monkeypatch.setattr(
+            "vastai.cli.commands.machines.offers_api.search_offers",
+            Mock(return_value=[offer]),
+        )
+        monkeypatch.setattr(
+            "vastai.cli.commands.machines.instances_api.create_instance",
+            Mock(side_effect=RuntimeError("stop before live rental")),
+        )
+
+        args = parse_argv(argv)
+        result = args.func(args)
+
+        assert result["diagnostics"]["log_level"] == {
+            "level": expected_level,
+            "source": expected_source,
+        }
+
     def test_default_cuda_mapping_still_selects_official_image(
         self, parse_argv, patch_get_client, monkeypatch
     ):
@@ -919,15 +1006,16 @@ def test_cleanup_404_after_destroy_is_not_reported_as_leak(
         monkeypatch.setattr("vastai.cli.commands.machines.instances_api.show_instance", show)
         monkeypatch.setattr("vastai.cli.commands.machines.instances_api.destroy_instance", destroy)
 
-        args = parse_argv(["self-test", "machine", "42"])
+        args = parse_argv(["self-test", "machine", "42", "--log-level", "debug"])
         with pytest.raises(SystemExit) as exc_info:
             args.func(args)
 
         captured = capsys.readouterr()
         assert exc_info.value.code == 1
-        assert "Runtime failure diagnostics:" in captured.out
-        assert "- code: daemon_startup_failed" in captured.out
-        assert "- remediation: Inspect docker daemon, OCI runtime, and container startup logs." in captured.out
+        assert "Runtime failure diagnostics" in captured.out
+        assert "    code: daemon_startup_failed" in captured.out
+        assert "  Remediation:" in captured.out
+        assert "    Inspect docker daemon, OCI runtime, and container startup logs." in captured.out
         assert "WARNING: failed to destroy test instance" not in captured.out
         assert "api_key=secret" not in captured.out
         destroy.assert_called_once()
@@ -947,7 +1035,7 @@ def test_create_instance_error_redacts_api_key(
         )
         monkeypatch.setattr("vastai.cli.commands.machines.instances_api.create_instance", create)
 
-        args = parse_argv(["self-test", "machine", "42"])
+        args = parse_argv(["self-test", "machine", "42", "--log-level", "debug"])
         with pytest.raises(SystemExit) as exc_info:
             args.func(args)
 
@@ -1080,15 +1168,16 @@ def test_progress_endpoint_failure_prints_external_port(
             Mock(side_effect=requests.exceptions.ConnectTimeout("timed out")),
         )
 
-        args = parse_argv(["self-test", "machine", "42"])
+        args = parse_argv(["self-test", "machine", "42", "--log-level", "debug"])
         with pytest.raises(SystemExit) as exc_info:
             args.func(args)
 
         captured = capsys.readouterr()
         assert exc_info.value.code == 1
         assert "External port tested: 45000" in captured.out
-        assert "- external port tested: 45000" in captured.out
-        assert "- mapped container ports: 22/tcp, 5000/tcp" in captured.out
+        assert "  Connection attempt:" in captured.out
+        assert "    external port tested: 45000" in captured.out
+        assert "    mapped container ports: 22/tcp, 5000/tcp" in captured.out
 
     def test_progress_endpoint_lost_after_success_records_different_failure(
         self, parse_argv, patch_get_client, monkeypatch

tests/cli/test_runtime_diagnostics.py

@@ -171,6 +171,88 @@ def test_status_msg_classifies_generic_daemon_startup_failure():
     assert result["underlying_error"] == status_msg
 
 
+def test_status_msg_classifies_startup_wrapper_build_line():
+    status_msg = (
+        "#6 [3/6] RUN export DEBIAN_FRONTEND=noninteractive; "
+        "apt-get update || echo 'V220614a: error during apt-get update!';"
+    )
+
+    result = diag.classify_status_msg(status_msg)
+
+    assert result["code"] == diag.DAEMON_STARTUP_FAILED
+    assert result["stage"] == diag.STAGE_STARTUP
+    assert result["underlying_error"] == status_msg
+
+
+def test_startup_daemon_log_evidence_distinguishes_apt_success_from_cdi_failure():
+    daemon_log = "\n".join(
+        [
+            "#6 [3/6] RUN export DEBIAN_FRONTEND=noninteractive; apt-get update || echo 'V220614a: error during apt-get update!';",
+            "#6 2.268 Fetched 49.3 MB in 2s (26.6 MB/s)",
+            "#6 DONE 3.3s",
+            "Successfully loaded vastai/test:self-test-v2-cuda-11.8",
+            "Error response from daemon: failed to inject CDI devices: unresolvable CDI devices D.host/gpu=0, D.host/gpu=1, D.host/gpu=2, D.host/gpu=3: unknown",
+        ]
+    )
+
+    evidence = diag.summarize_startup_daemon_log(daemon_log)
+
+    assert evidence["apt_update"]["status"] == "completed"
+    assert evidence["apt_update"]["error_marker_printed"] is False
+    assert evidence["cdi_gpu_device_injection"]["gpu_ids"] == ["0", "1", "2", "3"]
+    assert "completed successfully" in evidence["findings"][0]
+
+
+def test_startup_failure_refinement_prints_host_runtime_cause_for_cdi():
+    diagnostic = diag.classify_status_msg(
+        "#6 [3/6] RUN export DEBIAN_FRONTEND=noninteractive; apt-get update || echo 'V220614a: error during apt-get update!';"
+    )
+    daemon_log = "\n".join(
+        [
+            "#6 [3/6] RUN export DEBIAN_FRONTEND=noninteractive; apt-get update || echo 'V220614a: error during apt-get update!';",
+            "#6 DONE 3.3s",
+            "Error response from daemon: failed to inject CDI devices: unresolvable CDI devices D.host/gpu=0: unknown",
+        ]
+    )
+
+    refined = diag.refine_startup_failure_with_daemon_log(diagnostic, daemon_log)
+
+    assert refined["code"] == diag.DAEMON_STARTUP_FAILED
+    assert refined["summary"] == "Docker/NVIDIA runtime failed before the self-test container could start."
+    assert "NVIDIA container runtime/CDI" in refined["remediation"]
+    assert refined["startup_evidence"]["apt_update"]["status"] == "completed"
+    assert refined["startup_evidence"]["cdi_gpu_device_injection"]["gpu_ids"] == ["0"]
+
+
+def test_startup_failure_refinement_uses_status_message_when_daemon_log_lacks_cdi():
+    diagnostic = diag.classify_status_msg(
+        "Error response from daemon: failed to create task for container: failed to inject CDI devices: "
+        "unresolvable CDI devices D.host/gpu=0, D.host/gpu=1: unknown"
+    )
+    daemon_log = "container setup log did not include the final status error"
+
+    refined = diag.refine_startup_failure_with_daemon_log(diagnostic, daemon_log)
+
+    assert refined["summary"] == "Docker/NVIDIA runtime failed before the self-test container could start."
+    assert refined["startup_evidence"]["cdi_gpu_device_injection"]["gpu_ids"] == ["0", "1"]
+    assert refined["startup_evidence"]["sources"] == ["instance/daemon.log", "instance status message"]
+
+
+def test_startup_daemon_log_evidence_detects_actual_apt_update_marker_output():
+    daemon_log = "\n".join(
+        [
+            "#6 [3/6] RUN export DEBIAN_FRONTEND=noninteractive; apt-get update || echo 'V220614a: error during apt-get update!';",
+            "#6 2.100 V220614a: error during apt-get update!",
+            "#6 DONE 2.2s",
+        ]
+    )
+
+    evidence = diag.summarize_startup_daemon_log(daemon_log)
+
+    assert evidence["apt_update"]["status"] == "failed"
+    assert evidence["apt_update"]["error_marker_printed"] is True
+
+
 def test_status_msg_classifies_other_errors_as_status_error():
     result = diag.classify_status_msg("Error: host reported an unknown fault")
 

tests/cli/test_self_test_support_bundle.py

@@ -105,9 +105,9 @@ def fake_bundle(**kwargs):
 
     captured = capsys.readouterr()
     assert exc_info.value.code == 1
-    assert "Self-test diagnostic bundle saved to:" in captured.out
-    assert "self-test-result.json" in captured.out
-    assert "Review this tarball before sharing it with support." in captured.out
+    assert f"Support bundle: {tmp_path / 'vast_selftest_42_20260602T100000Z.tar.gz'}" in captured.out
+    assert "self-test-result.json" not in captured.out
+    assert "Next: inspect the support bundle or rerun with --log-level debug" in captured.out
 
 
 def test_self_test_bundle_creation_error_preserves_original_failure(
@@ -144,11 +144,11 @@ def test_self_test_bundle_creation_error_preserves_original_failure(
     captured = capsys.readouterr()
     assert exc_info.value.code == 1
     assert "WARNING: failed to create self-test diagnostic bundle: disk full" in captured.out
-    assert "Test failed: 8 preflight requirement check(s) failed." in captured.out
+    assert "Reason: 8 preflight requirement check(s) failed." in captured.out
 
 
 def test_self_test_runtime_failure_bundle_includes_instance_logs(
-    parse_argv, patch_get_client, monkeypatch, tmp_path
+    parse_argv, patch_get_client, monkeypatch, tmp_path, capsys
 ):
     from vastai.cli.commands import machines
 
@@ -198,7 +198,10 @@ def fake_show_instance(client, id):
             "id": id,
             "actual_status": "created",
             "intended_status": "running",
-            "status_msg": "docker_build() error writing dockerfile",
+            "status_msg": (
+                "#6 [3/6] RUN export DEBIAN_FRONTEND=noninteractive; "
+                "apt-get update || echo 'V220614a: error during apt-get update!';"
+            ),
             "label": "vast-self-test-machine-42",
         }
 
@@ -207,7 +210,16 @@ def fake_logs(client, instance_id, tail=None, filter=None, daemon_logs=False):
         assert instance_id == 123
         assert tail == machines.INSTANCE_LOG_TAIL_LINES
         assert filter is None
-        return "daemon startup failure" if daemon_logs else "container startup failure"
+        if daemon_logs:
+            return "\n".join(
+                [
+                    "#6 [3/6] RUN export DEBIAN_FRONTEND=noninteractive; apt-get update || echo 'V220614a: error during apt-get update!';",
+                    "#6 2.268 Fetched 49.3 MB in 2s (26.6 MB/s)",
+                    "#6 DONE 3.3s",
+                    "Error response from daemon: failed to inject CDI devices: unresolvable CDI devices D.host/gpu=0, D.host/gpu=1: unknown",
+                ]
+            )
+        return "container startup failure"
 
     def fake_destroy_instance(client, id):
         assert client is patch_get_client
@@ -222,18 +234,37 @@ def fake_destroy_instance(client, id):
     monkeypatch.setattr(machines.instances_api, "logs", fake_logs)
     monkeypatch.setattr(machines.instances_api, "destroy_instance", fake_destroy_instance)
 
-    args = parse_argv(["self-test", "machine", "42", "--support-bundle-dir", str(tmp_path)])
+    args = parse_argv([
+        "self-test",
+        "machine",
+        "42",
+        "--support-bundle-dir",
+        str(tmp_path),
+        "--log-level",
+        "debug",
+    ])
     with pytest.raises(SystemExit) as exc_info:
         args.func(args)
 
     assert exc_info.value.code == 1
+    captured = capsys.readouterr()
     assert 123 in destroyed
     assert created["include_local_host_artifacts"] is False
     assert created["result"]["failure_code"] == "daemon_startup_failed"
+    assert created["result"]["failure"]["summary"] == "Docker/NVIDIA runtime failed before the self-test container could start."
+    assert created["result"]["failure"]["startup_evidence"]["apt_update"]["status"] == "completed"
     assert created["extra_files"]["instance/container.log"] == "container startup failure"
-    assert created["extra_files"]["instance/daemon.log"] == "daemon startup failure"
+    assert "failed to inject CDI devices" in created["extra_files"]["instance/daemon.log"]
     assert '"label": "vast-self-test-machine-42"' in created["extra_files"]["instance/show-instance.json"]
     assert created["extra_errors"] == []
+    assert "Runtime failure diagnostics" in captured.out
+    assert "  Result:" in captured.out
+    assert "  What happened:" in captured.out
+    assert "Vast startup wrapper apt-get update completed successfully." in captured.out
+    assert "Docker/NVIDIA runtime failed to inject CDI GPU devices for GPUs 0, 1." in captured.out
+    assert "  Where to read next:" in captured.out
+    assert "instance/daemon.log in the diagnostic bundle" in captured.out
+    assert "Reason: Docker/NVIDIA runtime failed before the self-test container could start." in captured.out
 
 
 def test_dump_logs_command_creates_cli_visible_bundle(parse_argv, monkeypatch, tmp_path):