diff --git a/internal/server/instance/drivers/driver_qemu.go b/internal/server/instance/drivers/driver_qemu.go index f424d876b36..96a259d1fb4 100644 --- a/internal/server/instance/drivers/driver_qemu.go +++ b/internal/server/instance/drivers/driver_qemu.go @@ -357,7 +357,7 @@ type qemu struct { // otherwise the qmp.Connect call will fail to use the monitor socket file. func (d *qemu) getAgentClient() (*http.Client, error) { // Check if the agent is running. - monitor, err := qmp.Connect(d.monitorPath(), qemuSerialChardevName, d.getMonitorEventHandler()) + monitor, err := qmp.Connect(d.monitorPath(), qemuSerialChardevName, d.getMonitorEventHandler(), d.QMPLogFilePath()) if err != nil { return nil, err } @@ -535,7 +535,7 @@ func (d *qemu) generateAgentCert() (string, string, string, string, error) { // Freeze freezes the instance. func (d *qemu) Freeze() error { // Connect to the monitor. - monitor, err := qmp.Connect(d.monitorPath(), qemuSerialChardevName, d.getMonitorEventHandler()) + monitor, err := qmp.Connect(d.monitorPath(), qemuSerialChardevName, d.getMonitorEventHandler(), d.QMPLogFilePath()) if err != nil { return err } @@ -732,7 +732,7 @@ func (d *qemu) Shutdown(timeout time.Duration) error { } // Connect to the monitor. - monitor, err := qmp.Connect(d.monitorPath(), qemuSerialChardevName, d.getMonitorEventHandler()) + monitor, err := qmp.Connect(d.monitorPath(), qemuSerialChardevName, d.getMonitorEventHandler(), d.QMPLogFilePath()) if err != nil { op.Done(err) return err @@ -1140,7 +1140,7 @@ func (d *qemu) startupHook(monitor *qmp.Monitor, stage string) error { for _, command := range commandList { jsonCommand, _ := json.Marshal(command) - err = monitor.RunJSON(jsonCommand, nil) + err = monitor.RunJSON(jsonCommand, nil, true) if err != nil { err = fmt.Errorf("Failed to run QMP command %s at %s stage: %w", jsonCommand, stage, err) return err @@ -1210,7 +1210,7 @@ func (d *qemu) start(stateful bool, op *operationlock.InstanceOperation) error { defer revert.Fail() // Rotate the log files. - for _, logfile := range []string{d.LogFilePath(), d.common.ConsoleBufferLogPath()} { + for _, logfile := range []string{d.LogFilePath(), d.common.ConsoleBufferLogPath(), d.QMPLogFilePath()} { if util.PathExists(logfile) { _ = os.Remove(logfile + ".old") err := os.Rename(logfile, logfile+".old") @@ -1751,7 +1751,7 @@ func (d *qemu) start(stateful bool, op *operationlock.InstanceOperation) error { }) // Start QMP monitoring. - monitor, err := qmp.Connect(d.monitorPath(), qemuSerialChardevName, d.getMonitorEventHandler()) + monitor, err := qmp.Connect(d.monitorPath(), qemuSerialChardevName, d.getMonitorEventHandler(), d.QMPLogFilePath()) if err != nil { op.Done(err) return err @@ -2324,7 +2324,7 @@ func (d *qemu) deviceAttachPath(deviceName string, configCopy map[string]string, defer reverter.Fail() // Check if the agent is running. - monitor, err := qmp.Connect(d.monitorPath(), qemuSerialChardevName, d.getMonitorEventHandler()) + monitor, err := qmp.Connect(d.monitorPath(), qemuSerialChardevName, d.getMonitorEventHandler(), d.QMPLogFilePath()) if err != nil { return fmt.Errorf("Failed to connect to QMP monitor: %w", err) } @@ -2402,7 +2402,7 @@ func (d *qemu) deviceAttachPath(deviceName string, configCopy map[string]string, func (d *qemu) deviceAttachBlockDevice(deviceName string, configCopy map[string]string, mount deviceConfig.MountEntryItem) error { // Check if the agent is running. - monitor, err := qmp.Connect(d.monitorPath(), qemuSerialChardevName, d.getMonitorEventHandler()) + monitor, err := qmp.Connect(d.monitorPath(), qemuSerialChardevName, d.getMonitorEventHandler(), d.QMPLogFilePath()) if err != nil { return fmt.Errorf("Failed to connect to QMP monitor: %w", err) } @@ -2426,7 +2426,7 @@ func (d *qemu) deviceDetachPath(deviceName string, rawConfig deviceConfig.Device mountTag := fmt.Sprintf("incus_%s", deviceName) // Check if the agent is running. - monitor, err := qmp.Connect(d.monitorPath(), qemuSerialChardevName, d.getMonitorEventHandler()) + monitor, err := qmp.Connect(d.monitorPath(), qemuSerialChardevName, d.getMonitorEventHandler(), d.QMPLogFilePath()) if err != nil { return err } @@ -2459,7 +2459,7 @@ func (d *qemu) deviceDetachPath(deviceName string, rawConfig deviceConfig.Device func (d *qemu) deviceDetachBlockDevice(deviceName string, rawConfig deviceConfig.Device) error { // Check if the agent is running. - monitor, err := qmp.Connect(d.monitorPath(), qemuSerialChardevName, d.getMonitorEventHandler()) + monitor, err := qmp.Connect(d.monitorPath(), qemuSerialChardevName, d.getMonitorEventHandler(), d.QMPLogFilePath()) if err != nil { return err } @@ -2519,7 +2519,7 @@ func (d *qemu) deviceAttachNIC(deviceName string, configCopy map[string]string, } // Check if the agent is running. - monitor, err := qmp.Connect(d.monitorPath(), qemuSerialChardevName, d.getMonitorEventHandler()) + monitor, err := qmp.Connect(d.monitorPath(), qemuSerialChardevName, d.getMonitorEventHandler(), d.QMPLogFilePath()) if err != nil { return err } @@ -2554,7 +2554,7 @@ func (d *qemu) deviceAttachNIC(deviceName string, configCopy map[string]string, func (d *qemu) getPCIHotplug() (string, error) { // Check if the agent is running. - monitor, err := qmp.Connect(d.monitorPath(), qemuSerialChardevName, d.getMonitorEventHandler()) + monitor, err := qmp.Connect(d.monitorPath(), qemuSerialChardevName, d.getMonitorEventHandler(), d.QMPLogFilePath()) if err != nil { return "", err } @@ -2589,7 +2589,7 @@ func (d *qemu) deviceAttachPCI(deviceName string, configCopy map[string]string, defer reverter.Fail() // Check if the agent is running. - monitor, err := qmp.Connect(d.monitorPath(), qemuSerialChardevName, d.getMonitorEventHandler()) + monitor, err := qmp.Connect(d.monitorPath(), qemuSerialChardevName, d.getMonitorEventHandler(), d.QMPLogFilePath()) if err != nil { return err } @@ -2732,7 +2732,7 @@ func (d *qemu) deviceStop(dev device.Device, instanceRunning bool, _ string) err // deviceDetachNIC detaches a NIC device from a running instance. func (d *qemu) deviceDetachNIC(deviceName string) error { // Check if the agent is running. - monitor, err := qmp.Connect(d.monitorPath(), qemuSerialChardevName, d.getMonitorEventHandler()) + monitor, err := qmp.Connect(d.monitorPath(), qemuSerialChardevName, d.getMonitorEventHandler(), d.QMPLogFilePath()) if err != nil { return err } @@ -2786,7 +2786,7 @@ func (d *qemu) deviceDetachNIC(deviceName string) error { // deviceDetachPCI detaches a generic PCI device from a running instance. func (d *qemu) deviceDetachPCI(deviceName string) error { // Check if the agent is running. - monitor, err := qmp.Connect(d.monitorPath(), qemuSerialChardevName, d.getMonitorEventHandler()) + monitor, err := qmp.Connect(d.monitorPath(), qemuSerialChardevName, d.getMonitorEventHandler(), d.QMPLogFilePath()) if err != nil { return err } @@ -4972,7 +4972,7 @@ func (d *qemu) Stop(stateful bool) error { } // Connect to the monitor. - monitor, err := qmp.Connect(d.monitorPath(), qemuSerialChardevName, d.getMonitorEventHandler()) + monitor, err := qmp.Connect(d.monitorPath(), qemuSerialChardevName, d.getMonitorEventHandler(), d.QMPLogFilePath()) if err != nil { d.logger.Warn("Failed connecting to monitor, forcing stop", logger.Ctx{"err": err}) @@ -5080,7 +5080,7 @@ func (d *qemu) Stop(stateful bool) error { // Unfreeze restores the instance to running. func (d *qemu) Unfreeze() error { // Connect to the monitor. - monitor, err := qmp.Connect(d.monitorPath(), qemuSerialChardevName, d.getMonitorEventHandler()) + monitor, err := qmp.Connect(d.monitorPath(), qemuSerialChardevName, d.getMonitorEventHandler(), d.QMPLogFilePath()) if err != nil { return err } @@ -5124,7 +5124,7 @@ func (d *qemu) snapshot(name string, expiry time.Time, stateful bool) error { } // Connect to the monitor. - monitor, err = qmp.Connect(d.monitorPath(), qemuSerialChardevName, d.getMonitorEventHandler()) + monitor, err = qmp.Connect(d.monitorPath(), qemuSerialChardevName, d.getMonitorEventHandler(), d.QMPLogFilePath()) if err != nil { return err } @@ -6010,7 +6010,7 @@ func (d *qemu) updateMemoryLimit(newLimit string) error { newSizeMB := newSizeBytes / 1024 / 1024 // Connect to the monitor. - monitor, err := qmp.Connect(d.monitorPath(), qemuSerialChardevName, d.getMonitorEventHandler()) + monitor, err := qmp.Connect(d.monitorPath(), qemuSerialChardevName, d.getMonitorEventHandler(), d.QMPLogFilePath()) if err != nil { return err // The VM isn't running as no monitor socket available. } @@ -6863,7 +6863,7 @@ func (d *qemu) MigrateSend(args instance.MigrateSendArgs) error { // migrateSendLive performs live migration send process. func (d *qemu) migrateSendLive(pool storagePools.Pool, clusterMoveSourceName string, rootDiskSize int64, filesystemConn io.ReadWriteCloser, stateConn io.ReadWriteCloser, volSourceArgs *localMigration.VolumeSourceArgs) error { - monitor, err := qmp.Connect(d.monitorPath(), qemuSerialChardevName, d.getMonitorEventHandler()) + monitor, err := qmp.Connect(d.monitorPath(), qemuSerialChardevName, d.getMonitorEventHandler(), d.QMPLogFilePath()) if err != nil { return err } @@ -8230,7 +8230,7 @@ func (d *qemu) DeviceEventHandler(runConf *deviceConfig.RunConfig) error { } // Get the QMP monitor. - m, err := qmp.Connect(d.monitorPath(), qemuSerialChardevName, d.getMonitorEventHandler()) + m, err := qmp.Connect(d.monitorPath(), qemuSerialChardevName, d.getMonitorEventHandler(), d.QMPLogFilePath()) if err != nil { return err } @@ -8403,7 +8403,7 @@ func (d *qemu) statusCode() api.StatusCode { } // Connect to the monitor. - monitor, err := qmp.Connect(d.monitorPath(), qemuSerialChardevName, d.getMonitorEventHandler()) + monitor, err := qmp.Connect(d.monitorPath(), qemuSerialChardevName, d.getMonitorEventHandler(), d.QMPLogFilePath()) if err != nil { // If cannot connect to monitor, but qemu process in pid file still exists, then likely qemu // is unresponsive and this instance is in an error state. @@ -8461,6 +8461,11 @@ func (d *qemu) LogFilePath() string { return filepath.Join(d.LogPath(), "qemu.log") } +// QMPLogFilePath returns the instance's QMP log path. +func (d *qemu) QMPLogFilePath() string { + return filepath.Join(d.LogPath(), "qemu.qmp.log") +} + // FillNetworkDevice takes a nic or infiniband device type and enriches it with automatically // generated name and hwaddr properties if these are missing from the device. func (d *qemu) FillNetworkDevice(name string, m deviceConfig.Device) (deviceConfig.Device, error) { @@ -8852,7 +8857,7 @@ func (d *qemu) checkFeatures(hostArch int, qemuPath string) (map[string]any, err // Try and connect to QMP socket until cancelled. for { - monitor, err = qmp.Connect(monitorPath.Name(), qemuSerialChardevName, nil) + monitor, err = qmp.Connect(monitorPath.Name(), qemuSerialChardevName, nil, d.QMPLogFilePath()) // QMP successfully connected or we have been cancelled. if err == nil || ctx.Err() != nil { break @@ -9090,7 +9095,7 @@ func (d *qemu) agentMetricsEnabled() bool { func (d *qemu) deviceAttachUSB(usbConf deviceConfig.USBDeviceItem) error { // Check if the agent is running. - monitor, err := qmp.Connect(d.monitorPath(), qemuSerialChardevName, d.getMonitorEventHandler()) + monitor, err := qmp.Connect(d.monitorPath(), qemuSerialChardevName, d.getMonitorEventHandler(), d.QMPLogFilePath()) if err != nil { return err } @@ -9110,7 +9115,7 @@ func (d *qemu) deviceAttachUSB(usbConf deviceConfig.USBDeviceItem) error { func (d *qemu) deviceDetachUSB(usbDev deviceConfig.USBDeviceItem) error { // Check if the agent is running. - monitor, err := qmp.Connect(d.monitorPath(), qemuSerialChardevName, d.getMonitorEventHandler()) + monitor, err := qmp.Connect(d.monitorPath(), qemuSerialChardevName, d.getMonitorEventHandler(), d.QMPLogFilePath()) if err != nil { return err } @@ -9156,7 +9161,7 @@ func (d *qemu) setCPUs(monitor *qmp.Monitor, count int) error { if monitor == nil { var err error - monitor, err = qmp.Connect(d.monitorPath(), qemuSerialChardevName, d.getMonitorEventHandler()) + monitor, err = qmp.Connect(d.monitorPath(), qemuSerialChardevName, d.getMonitorEventHandler(), d.QMPLogFilePath()) if err != nil { return err } @@ -9366,7 +9371,7 @@ func (d *qemu) ConsoleLog() (string, error) { defer op.Done(nil) // Check if the agent is running. - monitor, err := qmp.Connect(d.monitorPath(), qemuSerialChardevName, d.getMonitorEventHandler()) + monitor, err := qmp.Connect(d.monitorPath(), qemuSerialChardevName, d.getMonitorEventHandler(), d.QMPLogFilePath()) if err != nil { return "", err } @@ -9421,7 +9426,7 @@ func (d *qemu) consoleSwapRBWithSocket() error { } // Check if the agent is running. - monitor, err := qmp.Connect(d.monitorPath(), qemuSerialChardevName, d.getMonitorEventHandler()) + monitor, err := qmp.Connect(d.monitorPath(), qemuSerialChardevName, d.getMonitorEventHandler(), d.QMPLogFilePath()) if err != nil { return err } @@ -9445,7 +9450,7 @@ func (d *qemu) consoleSwapRBWithSocket() error { // consoleSwapSocketWithRB swaps the qemu backend for the instance's console to a ring buffer. func (d *qemu) consoleSwapSocketWithRB() error { // Check if the agent is running. - monitor, err := qmp.Connect(d.monitorPath(), qemuSerialChardevName, d.getMonitorEventHandler()) + monitor, err := qmp.Connect(d.monitorPath(), qemuSerialChardevName, d.getMonitorEventHandler(), d.QMPLogFilePath()) if err != nil { return err } diff --git a/internal/server/instance/drivers/driver_qemu_metrics.go b/internal/server/instance/drivers/driver_qemu_metrics.go index 6a92cb8267f..6f05e3a707d 100644 --- a/internal/server/instance/drivers/driver_qemu_metrics.go +++ b/internal/server/instance/drivers/driver_qemu_metrics.go @@ -19,7 +19,7 @@ import ( func (d *qemu) getQemuMetrics() (*metrics.MetricSet, error) { // Connect to the monitor. - monitor, err := qmp.Connect(d.monitorPath(), qemuSerialChardevName, d.getMonitorEventHandler()) + monitor, err := qmp.Connect(d.monitorPath(), qemuSerialChardevName, d.getMonitorEventHandler(), d.QMPLogFilePath()) if err != nil { return nil, err } diff --git a/internal/server/instance/drivers/qmp/monitor.go b/internal/server/instance/drivers/qmp/monitor.go index da71fd93965..8e9188a00d5 100644 --- a/internal/server/instance/drivers/qmp/monitor.go +++ b/internal/server/instance/drivers/qmp/monitor.go @@ -4,6 +4,8 @@ import ( "context" "encoding/json" "fmt" + "os" + "slices" "strings" "sync" "time" @@ -31,6 +33,9 @@ var EventVMShutdownReasonDisconnect = "disconnect" // EventDiskEjected is used to indicate that a disk device was ejected by the guest. var EventDiskEjected = "DEVICE_TRAY_MOVED" +// ExcludedCommands is used to filter verbose commands from the QMP logs. +var ExcludedCommands = []string{"ringbuf-read"} + // Monitor represents a QMP monitor. type Monitor struct { path string @@ -43,6 +48,7 @@ type Monitor struct { eventHandler func(name string, data map[string]any) serialCharDev string onDisconnectEvent bool + logFile string } // start handles the background goroutines for event handling and monitoring the ringbuffer. @@ -179,12 +185,28 @@ func (m *Monitor) ping() error { } // RunJSON executes a JSON-formatted command. -func (m *Monitor) RunJSON(request []byte, resp any) error { +func (m *Monitor) RunJSON(request []byte, resp any, logCommand bool) error { // Check if disconnected if m.disconnected { return ErrMonitorDisconnect } + var log *os.File + var err error + if logCommand { + log, err = os.OpenFile(m.logFile, os.O_APPEND|os.O_WRONLY|os.O_CREATE, 0600) + if err != nil { + return err + } + + defer log.Close() + + _, err = fmt.Fprintf(log, "[%s] QUERY: %s\n", time.Now().Format(time.RFC3339), request) + if err != nil { + return err + } + } + out, err := m.qmp.Run(request) if err != nil { // Confirm the daemon didn't die. @@ -196,12 +218,19 @@ func (m *Monitor) RunJSON(request []byte, resp any) error { return err } + // Handle weird QEMU QMP bug. + responses := strings.Split(string(out), "\r\n") + out = []byte(responses[len(responses)-1]) + + if logCommand { + _, err = fmt.Fprintf(log, "[%s] REPLY: %s\n\n", time.Now().Format(time.RFC3339), out) + if err != nil { + return err + } + } + // Decode the response if needed. if resp != nil { - // Handle weird QEMU QMP bug. - responses := strings.Split(string(out), "\r\n") - out = []byte(responses[len(responses)-1]) - err = json.Unmarshal(out, &resp) if err != nil { // Confirm the daemon didn't die. @@ -233,11 +262,12 @@ func (m *Monitor) Run(cmd string, args any, resp any) error { return err } - return m.RunJSON(request, resp) + logCommand := !slices.Contains(ExcludedCommands, cmd) + return m.RunJSON(request, resp, logCommand) } // Connect creates or retrieves an existing QMP monitor for the path. -func Connect(path string, serialCharDev string, eventHandler func(name string, data map[string]any)) (*Monitor, error) { +func Connect(path string, serialCharDev string, eventHandler func(name string, data map[string]any), logFile string) (*Monitor, error) { monitorsLock.Lock() defer monitorsLock.Unlock() @@ -278,6 +308,7 @@ func Connect(path string, serialCharDev string, eventHandler func(name string, d monitor.chDisconnect = make(chan struct{}, 1) monitor.eventHandler = eventHandler monitor.serialCharDev = serialCharDev + monitor.logFile = logFile // Default to generating a shutdown event when the monitor disconnects so that devices can be // cleaned up. This will be disabled after a shutdown event is received from QEMU itself to avoid diff --git a/internal/server/scriptlet/qemu.go b/internal/server/scriptlet/qemu.go index 1f6d3832875..b072243f5ad 100644 --- a/internal/server/scriptlet/qemu.go +++ b/internal/server/scriptlet/qemu.go @@ -34,7 +34,7 @@ func QEMURun(l logger.Logger, m *qmp.Monitor, instance string, stage string) err } var resp map[string]any - err = m.RunJSON(request, &resp) + err = m.RunJSON(request, &resp, true) if err != nil { return nil, err }