Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

internal/server: Log QMP interaction to a file #1345

Merged
merged 1 commit into from
Oct 31, 2024
+74 −38
Merged

internal/server: Log QMP interaction to a file #1345

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
1 commit
Select commit
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
63 changes: 34 additions & 29 deletions internal/server/instance/drivers/driver_qemu.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -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
}
Expand Down Expand Up @@ -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
}
Expand Down Expand Up @@ -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
Expand Down Expand Up @@ -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
Expand Down Expand Up @@ -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")
Expand Down Expand Up @@ -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
Expand Down Expand Up @@ -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)
}
Expand Down Expand Up @@ -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)
}
Expand All @@ -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
}
Expand Down Expand Up @@ -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
}
Expand Down Expand Up @@ -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
}
Expand Down Expand Up @@ -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
}
Expand Down Expand Up @@ -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
}
Expand Down Expand Up @@ -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
}
Expand Down Expand Up @@ -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
}
Expand Down Expand Up @@ -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})

Expand Down Expand Up @@ -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
}
Expand Down Expand Up @@ -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
}
Expand Down Expand Up @@ -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.
}
Expand Down Expand Up @@ -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
}
Expand Down Expand Up @@ -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
}
Expand Down Expand Up @@ -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.
Expand Down Expand Up @@ -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) {
Expand Down Expand Up @@ -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
Expand Down Expand Up @@ -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
}
Expand All @@ -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
}
Expand Down Expand Up @@ -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
}
Expand Down Expand Up @@ -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
}
Expand Down Expand Up @@ -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
}
Expand All @@ -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
}
Expand Down
2 changes: 1 addition & 1 deletion internal/server/instance/drivers/driver_qemu_metrics.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -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
}
Expand Down
45 changes: 38 additions & 7 deletions internal/server/instance/drivers/qmp/monitor.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -4,6 +4,8 @@ import (
"context"
"encoding/json"
"fmt"
"os"
"slices"
"strings"
"sync"
"time"
Expand Down Expand Up @@ -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
Expand All @@ -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.
Expand Down Expand Up @@ -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.
Expand All @@ -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.
Expand Down Expand Up @@ -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()

Expand Down Expand Up @@ -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
Expand Down
2 changes: 1 addition & 1 deletion internal/server/scriptlet/qemu.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -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
}
Expand Down
Loading