Bugfix/cloud init restart qemu

include/multipass/exceptions/ssh_exception.h

@@ -46,4 +46,12 @@ class SSHExecFailure : public SSHException
 private:
     int ec;
 };
+
+class SSHVMNotRunning : public SSHException
+{
+public:
+    explicit SSHVMNotRunning(const std::string& what_arg) : SSHException(what_arg)
+    {
+    }
+};
 } // namespace multipass

src/platform/backends/qemu/qemu_virtual_machine.cpp

@@ -616,6 +616,11 @@ void mp::QemuVirtualMachine::initialize_vm_process()
                 }
             }
         }
+        else if (qmp_object.contains("error"))
+        {
+            auto error = qmp_object["error"].toObject();
+            mpl::error(vm_name, "QMP error: {}", error["desc"].toString());
+        }
     });
 
     QObject::connect(vm_process.get(), &Process::ready_read_standard_error, [this]() {

src/platform/backends/shared/base_virtual_machine.cpp

@@ -88,22 +88,19 @@ mp::utils::TimeoutAction log_and_retry(const ExceptionT& e,
     return mp::utils::TimeoutAction::retry;
 };
 
-std::optional<mp::SSHSession> wait_until_ssh_up_helper(mp::VirtualMachine* virtual_machine,
-                                                       std::chrono::milliseconds timeout,
-                                                       const mp::SSHKeyProvider& key_provider)
+auto ssh_session_connect_lambda(mp::VirtualMachine* virtual_machine,
+                                const mp::SSHKeyProvider& key_provider,
+                                std::optional<mp::SSHSession>& ssh_session)
 {
     static constexpr auto wait_step = 1s;
-    mpl::debug(virtual_machine->vm_name, "Waiting for SSH to be up");
-
-    std::optional<mp::SSHSession> session = std::nullopt;
-    auto action = [virtual_machine, &key_provider, &session] {
+    return [virtual_machine, &key_provider, &ssh_session] {
         virtual_machine->ensure_vm_is_running();
         try
         {
-            session.emplace(virtual_machine->ssh_hostname(wait_step),
-                            virtual_machine->ssh_port(),
-                            virtual_machine->ssh_username(),
-                            key_provider);
+            ssh_session.emplace(virtual_machine->ssh_hostname(wait_step),
+                                virtual_machine->ssh_port(),
+                                virtual_machine->ssh_username(),
+                                key_provider);
 
             std::lock_guard<decltype(virtual_machine->state_mutex)> lock{
                 virtual_machine->state_mutex};
@@ -124,6 +121,16 @@ std::optional<mp::SSHSession> wait_until_ssh_up_helper(mp::VirtualMachine* virtu
             return log_and_retry(e, virtual_machine);
         }
     };
+}
+
+std::optional<mp::SSHSession> wait_until_ssh_up_helper(mp::VirtualMachine* virtual_machine,
+                                                       std::chrono::milliseconds timeout,
+                                                       const mp::SSHKeyProvider& key_provider)
+{
+    mpl::debug(virtual_machine->vm_name, "Waiting for SSH to be up");
+
+    std::optional<mp::SSHSession> session = std::nullopt;
+    auto action = ssh_session_connect_lambda(virtual_machine, key_provider, session);
 
     auto on_timeout = [virtual_machine] {
         std::lock_guard<decltype(virtual_machine->state_mutex)> lock{virtual_machine->state_mutex};
@@ -273,7 +280,8 @@ void mp::BaseVirtualMachine::renew_ssh_session()
         const std::unique_lock lock{state_mutex};
         if (!MP_UTILS.is_running(
                 current_state())) // spend time updating state only if we need a new session
-            throw SSHException{fmt::format("SSH unavailable on instance {}: not running", vm_name)};
+            throw SSHVMNotRunning{
+                fmt::format("SSH unavailable on instance {}: not running", vm_name)};
     }
 
     mpl::debug(vm_name, "{} SSH session", ssh_session ? "Renewing cached" : "Caching new");
@@ -290,13 +298,19 @@ void mp::BaseVirtualMachine::wait_until_ssh_up(std::chrono::milliseconds timeout
 
 void mp::BaseVirtualMachine::wait_for_cloud_init(std::chrono::milliseconds timeout)
 {
-    auto action = [this] {
+    auto ssh_session_connect = ssh_session_connect_lambda(this, key_provider, this->ssh_session);
+    auto action = [this, ssh_session_connect] {
         ensure_vm_is_running();
         try
         {
             ssh_exec("[ -e /var/lib/cloud/instance/boot-finished ]");
             return mp::utils::TimeoutAction::done;
         }
+        catch (const SSHVMNotRunning& e)
+        {
+            ssh_session_connect();
+            return mp::utils::TimeoutAction::retry;
+        }
         catch (const SSHExecFailure& e)
         {
             return mp::utils::TimeoutAction::retry;

tests/qemu/test_qemu_backend.cpp

@@ -268,6 +268,51 @@ TEST_F(QemuBackend, machineStartSuspendSendsMonitoringEvent)
     machine->suspend();
 }
 
+TEST_F(QemuBackend, QMPErrorGetsLogged)
+{
+    EXPECT_CALL(*mock_qemu_platform_factory, make_qemu_platform(_)).WillOnce([this](auto...) {
+        return std::move(mock_qemu_platform);
+    });
+
+    NiceMock<mpt::MockVMStatusMonitor> mock_monitor;
+    mp::QemuVirtualMachineFactory backend{data_dir.path()};
+
+    process_factory->register_callback([](mpt::MockProcess* process) {
+        if (process->program().startsWith(
+                "qemu-system-")) // we only care about the actual vm process
+        {
+            EXPECT_CALL(*process, write(_)).WillRepeatedly([process](const QByteArray& data) {
+                QJsonParseError parse_error;
+                auto json = QJsonDocument::fromJson(data, &parse_error);
+                if (parse_error.error == QJsonParseError::NoError)
+                {
+                    auto json_object = json.object();
+                    auto execute = json_object["execute"];
+
+                    if (execute == "qmp_capabilities") // Use the qmp_capabilities process write to
+                                                       // cause an error
+                    {
+                        EXPECT_CALL(*process, read_all_standard_output())
+                            .WillRepeatedly(Return("{\"error\": {\"desc\": \"some error\"}} "));
+                        emit process->ready_read_standard_output();
+                    }
+                }
+
+                return data.size();
+            });
+        }
+    });
+
+    auto machine = backend.create_virtual_machine(default_description, key_provider, mock_monitor);
+
+    EXPECT_CALL(mock_monitor, persist_state_for(_, _));
+    EXPECT_CALL(mock_monitor, on_resume());
+    logger_scope.mock_logger->screen_logs(mpl::Level::error);
+    logger_scope.mock_logger->expect_log(mpl::Level::error, "QMP error: some error");
+    machine->start();
+    machine->state = mp::VirtualMachine::State::running; // Necessary to properly shutdown
+}
+
 TEST_F(QemuBackend, throwsWhenShutdownWhileStarting)
 {
     mpt::MockProcess* vmproc = nullptr;

tests/test_base_virtual_machine.cpp

@@ -1289,6 +1289,22 @@ TEST_F(BaseVM, waitForCloudInitErrorTimesOutThrows)
         mpt::match_what(StrEq("timed out waiting for initialization to complete")));
 }
 
+TEST_F(BaseVM, waitForCloudInitVMDownReconnects)
+{
+    vm.simulate_cloud_init();
+    EXPECT_CALL(vm, ensure_vm_is_running())
+        .Times(3); // Twice in cloud-init, once inside ssh connect lambda
+    EXPECT_CALL(vm, ssh_hostname(_));
+    EXPECT_CALL(vm, ssh_port());
+    EXPECT_CALL(vm, ssh_username());
+    EXPECT_CALL(vm, ssh_exec)
+        .WillOnce(Throw(mp::SSHVMNotRunning{"VM is touching grass"}))
+        .WillOnce(Return(""));
+
+    std::chrono::milliseconds timeout(2000);
+    EXPECT_NO_THROW(vm.wait_for_cloud_init(timeout));
+}
+
 TEST_F(BaseVM, waitForSSHUpThrowsOnTimeout)
 {
     vm.simulate_waiting_for_ssh();