Skip to content

Commit

Permalink
internal/server: Log QMP interaction to a file
Browse files Browse the repository at this point in the history 
Signed-off-by: Benjamin Somers <[email protected]>
  • Loading branch information
@bensmrs
bensmrs committed Oct 31, 2024
1 parent 213b71b commit 8bdac00
Show file tree
Hide file tree
Showing 4 changed files with 74 additions and 38 deletions.
63 changes: 34 additions & 29 deletions internal/server/instance/drivers/driver_qemu.go
View file
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
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
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
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

0 comments on commit 8bdac00

Please sign in to comment.