diff --git a/log-Add-logs-for-VM-runtime.patch b/log-Add-logs-for-VM-runtime.patch new file mode 100644 index 0000000000000000000000000000000000000000..2e092fcacde83651ee40ec73377bb6570f610dc5 --- /dev/null +++ b/log-Add-logs-for-VM-runtime.patch @@ -0,0 +1,563 @@ +From bbaa138415e8afeac7422ec489a3605a003792bd Mon Sep 17 00:00:00 2001 +From: zhanghailiang +Date: Tue, 19 May 2020 02:02:47 -0400 +Subject: [PATCH 2/2] log: Add logs for VM runtime + +Add logs on VM runtime path, to make it easier to do trouble shooting. + +Signed-off-by: Ying Fang +--- + accel/kvm/kvm-all.c | 5 ++++- + hw/acpi/core.c | 3 +++ + hw/arm/boot.c | 2 ++ + hw/arm/virt.c | 2 ++ + hw/char/virtio-serial-bus.c | 8 ++++++++ + hw/core/reset.c | 2 ++ + hw/pci/pci.c | 1 + + hw/usb/bus.c | 8 ++++++++ + hw/usb/host-libusb.c | 7 +++++++ + hw/virtio/virtio-pci.c | 3 +++ + hw/virtio/virtio-scsi-pci.c | 3 +++ + hw/virtio/virtio.c | 15 +++++++++++++-- + include/qemu-common.h | 2 ++ + include/qemu/qemu-log.h | 4 ++-- + monitor/monitor.c | 10 ++++++++++ + monitor/qmp-cmds.c | 2 ++ + os-posix.c | 1 + + qapi/qmp-dispatch.c | 16 ++++++++++++++++ + qdev-monitor.c | 6 ++++++ + vl.c | 8 ++++++++ + 20 files changed, 103 insertions(+), 5 deletions(-) + +diff --git a/accel/kvm/kvm-all.c b/accel/kvm/kvm-all.c +index 84edbe8b..088c22e0 100644 +--- a/accel/kvm/kvm-all.c ++++ b/accel/kvm/kvm-all.c +@@ -1277,7 +1277,10 @@ void kvm_irqchip_commit_routes(KVMState *s) + s->irq_routes->flags = 0; + trace_kvm_irqchip_commit_routes(); + ret = kvm_vm_ioctl(s, KVM_SET_GSI_ROUTING, s->irq_routes); +- assert(ret == 0); ++ if (ret < 0) { ++ error_report("Set GSI routing failed: %m"); ++ abort(); ++ } + } + + static void kvm_add_routing_entry(KVMState *s, +diff --git a/hw/acpi/core.c b/hw/acpi/core.c +index 228828a4..dac5ad22 100644 +--- a/hw/acpi/core.c ++++ b/hw/acpi/core.c +@@ -561,13 +561,16 @@ static void acpi_pm1_cnt_write(ACPIREGS *ar, uint16_t val) + uint16_t sus_typ = (val >> 10) & 7; + switch(sus_typ) { + case 0: /* soft power off */ ++ QEMU_LOG(LOG_INFO, "VM will be soft power off\n"); + qemu_system_shutdown_request(SHUTDOWN_CAUSE_GUEST_SHUTDOWN); + break; + case 1: ++ QEMU_LOG(LOG_INFO, "VM will be suspend state\n"); + qemu_system_suspend_request(); + break; + default: + if (sus_typ == ar->pm1.cnt.s4_val) { /* S4 request */ ++ QEMU_LOG(LOG_INFO, "VM will be S4 state\n"); + qapi_event_send_suspend_disk(); + qemu_system_shutdown_request(SHUTDOWN_CAUSE_GUEST_SHUTDOWN); + } +diff --git a/hw/arm/boot.c b/hw/arm/boot.c +index 3ab9de64..311508ce 100644 +--- a/hw/arm/boot.c ++++ b/hw/arm/boot.c +@@ -1303,6 +1303,8 @@ void arm_load_kernel(ARMCPU *cpu, struct arm_boot_info *info) + */ + assert(!(info->secure_board_setup && kvm_enabled())); + ++ QEMU_LOG(LOG_INFO, "load the kernel\n"); ++ + info->dtb_filename = qemu_opt_get(qemu_get_machine_opts(), "dtb"); + info->dtb_limit = 0; + +diff --git a/hw/arm/virt.c b/hw/arm/virt.c +index 4c727939..7b634cec 100644 +--- a/hw/arm/virt.c ++++ b/hw/arm/virt.c +@@ -941,6 +941,7 @@ static void virt_powerdown_req(Notifier *n, void *opaque) + /* use gpio Pin 3 for power button event */ + qemu_set_irq(qdev_get_gpio_in(gpio_key_dev, 0), 1); + } ++ QEMU_LOG(LOG_INFO, "send powerdown to vm.\n"); + } + + static void create_gpio(const VirtMachineState *vms) +@@ -1766,6 +1767,7 @@ static void machvirt_init(MachineState *machine) + } + + create_fdt(vms); ++ QEMU_LOG(LOG_INFO, "cpu init start\n"); + + cpu_class = object_class_by_name(ms->cpu_type); + vms->cpu_hotplug_enabled = has_ged && firmware_loaded && +diff --git a/hw/char/virtio-serial-bus.c b/hw/char/virtio-serial-bus.c +index f7a54f26..40ac57d5 100644 +--- a/hw/char/virtio-serial-bus.c ++++ b/hw/char/virtio-serial-bus.c +@@ -29,6 +29,7 @@ + #include "trace.h" + #include "hw/virtio/virtio-serial.h" + #include "hw/virtio/virtio-access.h" ++#include "qemu-common.h" + + static struct VirtIOSerialDevices { + QLIST_HEAD(, VirtIOSerial) devices; +@@ -255,6 +256,9 @@ static size_t send_control_event(VirtIOSerial *vser, uint32_t port_id, + virtio_stw_p(vdev, &cpkt.value, value); + + trace_virtio_serial_send_control_event(port_id, event, value); ++ QEMU_LOG(LOG_INFO, "virtio serial port %d send control message" ++ " event = %d, value = %d\n", ++ port_id, event, value); + return send_control_msg(vser, &cpkt, sizeof(cpkt)); + } + +@@ -362,6 +366,10 @@ static void handle_control_message(VirtIOSerial *vser, void *buf, size_t len) + cpkt.value = virtio_lduw_p(vdev, &gcpkt->value); + + trace_virtio_serial_handle_control_message(cpkt.event, cpkt.value); ++ QEMU_LOG(LOG_INFO, "virtio serial port '%u' handle control message" ++ " event = %d, value = %d\n", ++ virtio_ldl_p(vdev, &gcpkt->id), cpkt.event, ++ cpkt.value); + + if (cpkt.event == VIRTIO_CONSOLE_DEVICE_READY) { + if (!cpkt.value) { +diff --git a/hw/core/reset.c b/hw/core/reset.c +index 0efaf2d7..53892b80 100644 +--- a/hw/core/reset.c ++++ b/hw/core/reset.c +@@ -26,6 +26,7 @@ + #include "qemu/osdep.h" + #include "qemu/queue.h" + #include "sysemu/reset.h" ++#include "qemu-common.h" + + /* reset/shutdown handler */ + +@@ -89,6 +90,7 @@ void qemu_devices_reset(void) + { + QEMUResetEntry *re, *nre; + ++ QEMU_LOG(LOG_INFO, "reset all devices\n"); + /* reset all devices */ + QTAILQ_FOREACH_SAFE(re, &reset_handlers, entry, nre) { + re->func(re->opaque); +diff --git a/hw/pci/pci.c b/hw/pci/pci.c +index 8076a80a..46eab267 100644 +--- a/hw/pci/pci.c ++++ b/hw/pci/pci.c +@@ -2312,6 +2312,7 @@ static void pci_add_option_rom(PCIDevice *pdev, bool is_default_rom, + } else { + snprintf(name, sizeof(name), "%s.rom", object_get_typename(OBJECT(pdev))); + } ++ QEMU_LOG(LOG_INFO, "add rom file: %s\n", name); + pdev->has_rom = true; + memory_region_init_rom(&pdev->rom, OBJECT(pdev), name, size, &error_fatal); + ptr = memory_region_get_ram_ptr(&pdev->rom); +diff --git a/hw/usb/bus.c b/hw/usb/bus.c +index a28e9e3b..0fc59823 100644 +--- a/hw/usb/bus.c ++++ b/hw/usb/bus.c +@@ -9,6 +9,7 @@ + #include "monitor/monitor.h" + #include "trace.h" + #include "qemu/cutils.h" ++#include "qemu-common.h" + + static void usb_bus_dev_print(Monitor *mon, DeviceState *qdev, int indent); + +@@ -528,6 +529,10 @@ void usb_check_attach(USBDevice *dev, Error **errp) + bus->qbus.name, port->path, portspeed); + return; + } ++ ++ QEMU_LOG(LOG_INFO, "attach usb device \"%s\" (%s speed) to VM bus \"%s\", " ++ "port \"%s\" (%s speed)\n", dev->product_desc, devspeed, ++ bus->qbus.name, port->path, portspeed); + } + + void usb_device_attach(USBDevice *dev, Error **errp) +@@ -556,6 +561,9 @@ int usb_device_detach(USBDevice *dev) + + usb_detach(port); + dev->attached = false; ++ QEMU_LOG(LOG_INFO, "detach usb device \"%s\" from VM bus \"%s\", " ++ "port \"%s\"\n", dev->product_desc, ++ bus->qbus.name, port->path); + return 0; + } + +diff --git a/hw/usb/host-libusb.c b/hw/usb/host-libusb.c +index 83ebc516..10d6c0cb 100644 +--- a/hw/usb/host-libusb.c ++++ b/hw/usb/host-libusb.c +@@ -47,6 +47,7 @@ + #include "trace.h" + + #include "hw/usb.h" ++#include "qemu-common.h" + + /* ------------------------------------------------------------------------ */ + +@@ -882,6 +883,8 @@ static int usb_host_open(USBHostDevice *s, libusb_device *dev) + } + rc = libusb_open(dev, &s->dh); + if (rc != 0) { ++ QEMU_LOG(LOG_INFO, "libusb open usb device bus %d, device %d failed\n", ++ bus_num, addr); + goto fail; + } + +@@ -893,6 +896,8 @@ static int usb_host_open(USBHostDevice *s, libusb_device *dev) + + libusb_get_device_descriptor(dev, &s->ddesc); + usb_host_get_port(s->dev, s->port, sizeof(s->port)); ++ QEMU_LOG(LOG_INFO, "open a host usb device on bus %d, device %d\n", ++ bus_num, addr); + + usb_ep_init(udev); + usb_host_ep_update(s); +@@ -957,6 +962,8 @@ static int usb_host_close(USBHostDevice *s) + usb_device_detach(udev); + } + ++ QEMU_LOG(LOG_INFO, "begin to reset the usb device, bus : %d," ++ " device : %d\n", s->bus_num, s->addr); + usb_host_release_interfaces(s); + libusb_reset_device(s->dh); + usb_host_attach_kernel(s); +diff --git a/hw/virtio/virtio-pci.c b/hw/virtio/virtio-pci.c +index f6d2223e..283a6ac4 100644 +--- a/hw/virtio/virtio-pci.c ++++ b/hw/virtio/virtio-pci.c +@@ -32,6 +32,7 @@ + #include "qemu/range.h" + #include "hw/virtio/virtio-bus.h" + #include "qapi/visitor.h" ++#include "qemu-common.h" + + #define VIRTIO_PCI_REGION_SIZE(dev) VIRTIO_PCI_CONFIG_OFF(msix_present(dev)) + +@@ -1659,7 +1660,9 @@ static void virtio_pci_device_unplugged(DeviceState *d) + VirtIOPCIProxy *proxy = VIRTIO_PCI(d); + bool modern = virtio_pci_modern(proxy); + bool modern_pio = proxy->flags & VIRTIO_PCI_FLAG_MODERN_PIO_NOTIFY; ++ VirtIODevice *vdev = virtio_bus_get_device(&proxy->bus); + ++ QEMU_LOG(LOG_INFO, "device name: %s\n", !vdev ? "NULL" : vdev->name); + virtio_pci_stop_ioeventfd(proxy); + + if (modern) { +diff --git a/hw/virtio/virtio-scsi-pci.c b/hw/virtio/virtio-scsi-pci.c +index f68f689a..bd1fa953 100644 +--- a/hw/virtio/virtio-scsi-pci.c ++++ b/hw/virtio/virtio-scsi-pci.c +@@ -18,6 +18,7 @@ + #include "hw/virtio/virtio-scsi.h" + #include "qemu/module.h" + #include "virtio-pci.h" ++#include "qemu-common.h" + + typedef struct VirtIOSCSIPCI VirtIOSCSIPCI; + +@@ -49,6 +50,8 @@ static void virtio_scsi_pci_realize(VirtIOPCIProxy *vpci_dev, Error **errp) + DeviceState *proxy = DEVICE(vpci_dev); + char *bus_name; + ++ QEMU_LOG(LOG_INFO, "virtio scsi HBA %s begin to initialize.\n", ++ !proxy->id ? "NULL" : proxy->id); + if (vpci_dev->nvectors == DEV_NVECTORS_UNSPECIFIED) { + vpci_dev->nvectors = vs->conf.num_queues + 3; + } +diff --git a/hw/virtio/virtio.c b/hw/virtio/virtio.c +index 7c3822c3..aedd9f5e 100644 +--- a/hw/virtio/virtio.c ++++ b/hw/virtio/virtio.c +@@ -23,6 +23,7 @@ + #include "hw/virtio/virtio-bus.h" + #include "hw/virtio/virtio-access.h" + #include "sysemu/dma.h" ++#include "qemu-common.h" + + /* + * The alignment to use between consumer and producer parts of vring. +@@ -1172,7 +1173,14 @@ int virtio_set_status(VirtIODevice *vdev, uint8_t val) + k->set_status(vdev, val); + } + vdev->status = val; +- ++ if (val) { ++ QEMU_LOG(LOG_INFO, "%s device status is %d that means %s\n", ++ vdev->name, val, ++ (val & VIRTIO_CONFIG_S_DRIVER_OK) ? "DRIVER OK" : ++ (val & VIRTIO_CONFIG_S_DRIVER) ? "DRIVER" : ++ (val & VIRTIO_CONFIG_S_ACKNOWLEDGE) ? "ACKNOWLEDGE" : ++ (val & VIRTIO_CONFIG_S_FAILED) ? "FAILED" : "UNKNOWN"); ++ } + return 0; + } + +@@ -1614,8 +1622,11 @@ VirtQueue *virtio_add_queue(VirtIODevice *vdev, int queue_size, + break; + } + +- if (i == VIRTIO_QUEUE_MAX || queue_size > VIRTQUEUE_MAX_SIZE) ++ if (i == VIRTIO_QUEUE_MAX || queue_size > VIRTQUEUE_MAX_SIZE) { ++ QEMU_LOG(LOG_INFO, "unacceptable queue_size (%d) or num (%d)\n", ++ queue_size, i); + abort(); ++ } + + vdev->vq[i].vring.num = queue_size; + vdev->vq[i].vring.num_default = queue_size; +diff --git a/include/qemu-common.h b/include/qemu-common.h +index 0235cd3b..3b43dc10 100644 +--- a/include/qemu-common.h ++++ b/include/qemu-common.h +@@ -10,6 +10,8 @@ + #ifndef QEMU_COMMON_H + #define QEMU_COMMON_H + ++#include "qemu/qemu-log.h" ++ + #define TFR(expr) do { if ((expr) != -1) break; } while (errno == EINTR) + + /* Copyright string for -version arguments, About dialogs, etc */ +diff --git a/include/qemu/qemu-log.h b/include/qemu/qemu-log.h +index 06e5a6ac..1bf7e673 100644 +--- a/include/qemu/qemu-log.h ++++ b/include/qemu/qemu-log.h +@@ -19,8 +19,8 @@ + * with this program; if not, see . + */ + +-#ifndef QEMU_COMMON_H +-#define QEMU_COMMON_H ++#ifndef QEMU_COMMON_LOG_H ++#define QEMU_COMMON_LOG_H + + #include + #include +diff --git a/monitor/monitor.c b/monitor/monitor.c +index 3ef28171..0b40eb2e 100644 +--- a/monitor/monitor.c ++++ b/monitor/monitor.c +@@ -28,10 +28,12 @@ + #include "qapi/qapi-emit-events.h" + #include "qapi/qmp/qdict.h" + #include "qapi/qmp/qstring.h" ++#include "qapi/qmp/qjson.h" + #include "qemu/error-report.h" + #include "qemu/option.h" + #include "sysemu/qtest.h" + #include "trace.h" ++#include "qemu-common.h" + + /* + * To prevent flooding clients, events can be throttled. The +@@ -254,6 +256,7 @@ static void monitor_qapi_event_emit(QAPIEvent event, QDict *qdict) + { + Monitor *mon; + MonitorQMP *qmp_mon; ++ QString *json; + + trace_monitor_protocol_event_emit(event, qdict); + QTAILQ_FOREACH(mon, &mon_list, entry) { +@@ -264,6 +267,13 @@ static void monitor_qapi_event_emit(QAPIEvent event, QDict *qdict) + qmp_mon = container_of(mon, MonitorQMP, common); + if (qmp_mon->commands != &qmp_cap_negotiation_commands) { + qmp_send_response(qmp_mon, qdict); ++ json = qobject_to_json(QOBJECT(qdict)); ++ if (json) { ++ if (!strstr(json->string, "RTC_CHANGE")) { ++ QEMU_LOG(LOG_INFO, "%s\n", qstring_get_str(json)); ++ } ++ qobject_unref(json); ++ } + } + } + } +diff --git a/monitor/qmp-cmds.c b/monitor/qmp-cmds.c +index b9ae40ee..88c4a703 100644 +--- a/monitor/qmp-cmds.c ++++ b/monitor/qmp-cmds.c +@@ -168,8 +168,10 @@ void qmp_cont(Error **errp) + } + + if (runstate_check(RUN_STATE_INMIGRATE)) { ++ QEMU_LOG(LOG_INFO, "qmp cont is received in migration\n"); + autostart = 1; + } else { ++ QEMU_LOG(LOG_INFO, "qmp cont is received and vm is started\n"); + vm_start(); + } + } +diff --git a/os-posix.c b/os-posix.c +index 3ba7df8d..167ae051 100644 +--- a/os-posix.c ++++ b/os-posix.c +@@ -354,6 +354,7 @@ int os_mlock(void) + { + int ret = 0; + ++ QEMU_LOG(LOG_INFO, "do mlockall\n"); + ret = mlockall(MCL_CURRENT | MCL_FUTURE); + if (ret < 0) { + error_report("mlockall: %s", strerror(errno)); +diff --git a/qapi/qmp-dispatch.c b/qapi/qmp-dispatch.c +index e2c366e0..8b9d7cc9 100644 +--- a/qapi/qmp-dispatch.c ++++ b/qapi/qmp-dispatch.c +@@ -17,7 +17,9 @@ + #include "qapi/qmp/qdict.h" + #include "qapi/qmp/qjson.h" + #include "qapi/qmp/qbool.h" ++#include "qapi/qmp/qstring.h" + #include "sysemu/sysemu.h" ++#include "qemu-common.h" + + static QDict *qmp_dispatch_check_obj(const QObject *request, bool allow_oob, + Error **errp) +@@ -83,6 +85,7 @@ static QObject *do_qmp_dispatch(QmpCommandList *cmds, QObject *request, + const char *command; + QDict *args, *dict; + QmpCommand *cmd; ++ QString *json; + QObject *ret = NULL; + + dict = qmp_dispatch_check_obj(request, allow_oob, errp); +@@ -128,6 +131,19 @@ static QObject *do_qmp_dispatch(QmpCommandList *cmds, QObject *request, + qobject_ref(args); + } + ++ json = qobject_to_json(QOBJECT(args)); ++ if (json) { ++ if ((strcmp(command, "query-block-jobs") != 0) ++ && (strcmp(command, "query-migrate") != 0) ++ && (strcmp(command, "query-blockstats") != 0) ++ && (strcmp(command, "query-balloon") != 0) ++ && (strcmp(command, "set_password") != 0)) { ++ QEMU_LOG(LOG_INFO, "qmp_cmd_name: %s, arguments: %s\n", ++ command, qstring_get_str(json)); ++ } ++ qobject_unref(json); ++ } ++ + cmd->fn(args, &ret, &local_err); + if (local_err) { + error_propagate(errp, local_err); +diff --git a/qdev-monitor.c b/qdev-monitor.c +index 58222c22..139c0acd 100644 +--- a/qdev-monitor.c ++++ b/qdev-monitor.c +@@ -34,6 +34,7 @@ + #include "qemu/qemu-print.h" + #include "sysemu/block-backend.h" + #include "migration/misc.h" ++#include "qemu-common.h" + + /* + * Aliases were a bad idea from the start. Let's keep them +@@ -586,6 +587,7 @@ DeviceState *qdev_device_add(QemuOpts *opts, Error **errp) + if (path != NULL) { + bus = qbus_find(path, errp); + if (!bus) { ++ QEMU_LOG(LOG_INFO, "can not find bus for %s\n", driver); + return NULL; + } + if (!object_dynamic_cast(OBJECT(bus), dc->bus_type)) { +@@ -627,6 +629,8 @@ DeviceState *qdev_device_add(QemuOpts *opts, Error **errp) + + /* set properties */ + if (qemu_opt_foreach(opts, set_property, dev, &err)) { ++ QEMU_LOG(LOG_INFO, "the bus %s -driver %s set property failed\n", ++ bus ? bus->name : "None", driver); + goto err_del_dev; + } + +@@ -636,6 +640,8 @@ DeviceState *qdev_device_add(QemuOpts *opts, Error **errp) + dev->opts = NULL; + goto err_del_dev; + } ++ QEMU_LOG(LOG_INFO, "add qdev %s:%s success\n", driver, ++ qemu_opts_id(opts) ? qemu_opts_id(opts) : "none"); + return dev; + + err_del_dev: +diff --git a/vl.c b/vl.c +index b426b321..446f1cec 100644 +--- a/vl.c ++++ b/vl.c +@@ -1772,9 +1772,11 @@ static bool main_loop_should_exit(void) + } + if (qemu_powerdown_requested()) { + qemu_system_powerdown(); ++ QEMU_LOG(LOG_INFO, "domain is power down by outside operation\n"); + } + if (qemu_vmstop_requested(&r)) { + vm_stop(r); ++ QEMU_LOG(LOG_INFO, "domain is stopped by outside operation\n"); + } + return false; + } +@@ -2960,6 +2962,7 @@ int main(int argc, char **argv, char **envp) + + autostart = 1; + ++ QEMU_LOG(LOG_INFO, "qemu pid is %d, options parsing start\n", getpid()); + /* first pass of option parsing */ + optind = 1; + while (optind < argc) { +@@ -3174,6 +3177,7 @@ int main(int argc, char **argv, char **envp) + exit(0); + break; + case QEMU_OPTION_m: ++ QEMU_LOG(LOG_INFO, "memory options parse start\n"); + opts = qemu_opts_parse_noisily(qemu_find_opts("memory"), + optarg, true); + if (!opts) { +@@ -4163,6 +4167,7 @@ int main(int argc, char **argv, char **envp) + current_machine->maxram_size = maxram_size; + current_machine->ram_slots = ram_slots; + ++ QEMU_LOG(LOG_INFO, "configure accelerator %s start\n", machine_class->name); + /* + * Note: uses machine properties such as kernel-irqchip, must run + * after machine_set_property(). +@@ -4330,6 +4335,7 @@ int main(int argc, char **argv, char **envp) + replay_checkpoint(CHECKPOINT_INIT); + qdev_machine_init(); + ++ QEMU_LOG(LOG_INFO, "machine init start\n"); + current_machine->boot_order = boot_order; + + /* parse features once if machine provides default cpu_type */ +@@ -4367,6 +4373,7 @@ int main(int argc, char **argv, char **envp) + /* Check if IGD GFX passthrough. */ + igd_gfx_passthru(); + ++ QEMU_LOG(LOG_INFO, "device init start\n"); + /* init generic devices */ + rom_set_order_override(FW_CFG_ORDER_OVERRIDE_DEVICE); + qemu_opts_foreach(qemu_find_opts("device"), +@@ -4470,6 +4477,7 @@ int main(int argc, char **argv, char **envp) + accel_setup_post(current_machine); + os_setup_post(); + ++ QEMU_LOG(LOG_INFO, "qemu enter main_loop\n"); + main_loop(); + + gdbserver_cleanup(); +-- +2.23.0 + diff --git a/log-add-the-qemu-log-framework.patch b/log-add-the-qemu-log-framework.patch new file mode 100644 index 0000000000000000000000000000000000000000..cee5ad3975b274faf9c9f9bf749d38261c5c7eab --- /dev/null +++ b/log-add-the-qemu-log-framework.patch @@ -0,0 +1,307 @@ +From 83fb358e83090c2b78121ee460d9271c8de0cec5 Mon Sep 17 00:00:00 2001 +From: zhanghailiang +Date: Mon, 18 May 2020 08:57:40 -0400 +Subject: [PATCH 1/2] log: add the qemu-log framework + +There is few logs printed during VM runtime, in oder to make it +easier to hunt bugs within qemu, let's add the qemu-log framwork. +We'll add some logs on the key path of VM runtime in the following +patches. + +Signed-off-by: Ying Fang +--- + include/qemu/qemu-log.h | 43 ++++++++ + util/Makefile.objs | 1 + + util/qemu-log.c | 218 ++++++++++++++++++++++++++++++++++++++++ + 3 files changed, 262 insertions(+) + create mode 100644 include/qemu/qemu-log.h + create mode 100644 util/qemu-log.c + +diff --git a/include/qemu/qemu-log.h b/include/qemu/qemu-log.h +new file mode 100644 +index 00000000..06e5a6ac +--- /dev/null ++++ b/include/qemu/qemu-log.h +@@ -0,0 +1,43 @@ ++/* ++ * Introduce QEMU_LOG ++ * ++ * LOG: Introduce QEMU_LOG. ++ * ++ * Copyright (c) 2017-2020 HUAWEI TECHNOLOGIES CO.,LTD. ++ * ++ * This program is free software; you can redistribute it and/or modify ++ * it under the terms of the GNU General Public License as published by ++ * the Free Software Foundation; either version 2 of the License, or ++ * (at your option) any later version. ++ ++ * This program is distributed in the hope that it will be useful, ++ * but WITHOUT ANY WARRANTY; without even the implied warranty of ++ * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the ++ * GNU General Public License for more details. ++ ++ * You should have received a copy of the GNU General Public License along ++ * with this program; if not, see . ++ */ ++ ++#ifndef QEMU_COMMON_H ++#define QEMU_COMMON_H ++ ++#include ++#include ++#include ++#include ++#include ++#include ++#include ++#include ++ ++#define TIMESTAMP_MAX_LEN 33 /* RFC 3339 timestamp length shuold be 33 */ ++ ++void qemu_get_timestamp(char *buf, int buf_size); ++void qemu_log_print(int level, const char *funcname, int linenr, ++ const char *fmt, ...); ++ ++#define QEMU_LOG(level, format, ...) \ ++ qemu_log_print(level, __func__, __LINE__, format, ##__VA_ARGS__) ++ ++#endif +diff --git a/util/Makefile.objs b/util/Makefile.objs +index 41bf59d1..47ecbf82 100644 +--- a/util/Makefile.objs ++++ b/util/Makefile.objs +@@ -42,6 +42,7 @@ util-obj-y += buffer.o + util-obj-y += timed-average.o + util-obj-y += base64.o + util-obj-y += log.o ++util-obj-y += qemu-log.o + util-obj-y += pagesize.o + util-obj-y += qdist.o + util-obj-y += qht.o +diff --git a/util/qemu-log.c b/util/qemu-log.c +new file mode 100644 +index 00000000..add386b8 +--- /dev/null ++++ b/util/qemu-log.c +@@ -0,0 +1,218 @@ ++/* ++ * Introduce QEMU_LOG ++ * ++ * LOG: Introduce QEMU_LOG. ++ * ++ * Copyright (c) 2017-2020 HUAWEI TECHNOLOGIES CO.,LTD. ++ * ++ * This program is free software; you can redistribute it and/or modify ++ * it under the terms of the GNU General Public License as published by ++ * the Free Software Foundation; either version 2 of the License, or ++ * (at your option) any later version. ++ ++ * This program is distributed in the hope that it will be useful, ++ * but WITHOUT ANY WARRANTY; without even the implied warranty of ++ * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the ++ * GNU General Public License for more details. ++ ++ * You should have received a copy of the GNU General Public License along ++ * with this program; if not, see . ++ */ ++ ++#include "qemu/qemu-log.h" ++#include ++#include "qemu/osdep.h" ++ ++#define BEGIN_YEAR 1900 ++#define DEFAULT_SECFRACPRECISION 6 ++#define LOG_LEVEL_NAME_MAX_LEN 10 ++ ++static const int tenPowers[6] = { 1, 10, 100, 1000, 10000, 100000 }; ++ ++typedef char intTiny; ++ ++struct syslogTime { ++ intTiny timeType; /* 0 - unitinialized ++ * 1 - RFC 3164 ++ * 2 - syslog-protocol ++ */ ++ intTiny month; ++ intTiny day; ++ intTiny hour; /* 24 hour clock */ ++ intTiny minute; ++ intTiny second; ++ intTiny secfracPrecision; ++ intTiny OffsetMinute; /* UTC offset in minutes */ ++ intTiny OffsetHour; /* UTC offset in hours ++ * full UTC offset minutes ++ * = OffsetHours*60 + OffsetMinute. ++ * Then use OffsetMode to know the direction. ++ */ ++ char OffsetMode; /* UTC offset + or - */ ++ short year; ++ int secfrac; /* fractional seconds (must be 32 bit!) */ ++ intTiny inUTC; /* forced UTC? */ ++}; ++typedef struct syslogTime syslogTime_t; ++ ++typedef struct syslogName_s { ++ const char *c_name; ++ int c_val; ++} syslogName_t; ++ ++static syslogName_t syslogPriNames[] = { ++ {"emerg", LOG_EMERG}, ++ {"alert", LOG_ALERT}, ++ {"crit", LOG_CRIT}, ++ {"err", LOG_ERR}, ++ {"warning", LOG_WARNING}, ++ {"notice", LOG_NOTICE}, ++ {"info", LOG_INFO}, ++ {"debug", LOG_DEBUG}, ++ {NULL, -1} ++}; ++ ++/** ++ * Format a syslogTimestamp to a RFC3339 timestamp string (as ++ * specified in syslog-protocol). ++ * ++ * Notes: rfc_time_buf size >= TIMESTAMP_MAX_LEN ++ */ ++static void formatTimestamp3339(struct syslogTime *ts, char *rfc_time_buf) ++{ ++ int iBuf = 0; ++ int power = 0; ++ int secfrac = 0; ++ short digit = 0; ++ char *pBuf = rfc_time_buf; ++ ++ pBuf[iBuf++] = (ts->year / 1000) % 10 + '0'; ++ pBuf[iBuf++] = (ts->year / 100) % 10 + '0'; ++ pBuf[iBuf++] = (ts->year / 10) % 10 + '0'; ++ pBuf[iBuf++] = ts->year % 10 + '0'; ++ pBuf[iBuf++] = '-'; ++ /* month */ ++ pBuf[iBuf++] = (ts->month / 10) % 10 + '0'; ++ pBuf[iBuf++] = ts->month % 10 + '0'; ++ pBuf[iBuf++] = '-'; ++ /* day */ ++ pBuf[iBuf++] = (ts->day / 10) % 10 + '0'; ++ pBuf[iBuf++] = ts->day % 10 + '0'; ++ pBuf[iBuf++] = 'T'; ++ /* hour */ ++ pBuf[iBuf++] = (ts->hour / 10) % 10 + '0'; ++ pBuf[iBuf++] = ts->hour % 10 + '0'; ++ pBuf[iBuf++] = ':'; ++ /* minute */ ++ pBuf[iBuf++] = (ts->minute / 10) % 10 + '0'; ++ pBuf[iBuf++] = ts->minute % 10 + '0'; ++ pBuf[iBuf++] = ':'; ++ /* second */ ++ pBuf[iBuf++] = (ts->second / 10) % 10 + '0'; ++ pBuf[iBuf++] = ts->second % 10 + '0'; ++ ++ if (ts->secfracPrecision > 0) { ++ pBuf[iBuf++] = '.'; ++ power = tenPowers[(ts->secfracPrecision - 1) % 6]; ++ secfrac = ts->secfrac; ++ while (power > 0) { ++ digit = secfrac / power; ++ secfrac -= digit * power; ++ power /= 10; ++ pBuf[iBuf++] = digit + '0'; ++ } ++ } ++ ++ pBuf[iBuf++] = ts->OffsetMode; ++ pBuf[iBuf++] = (ts->OffsetHour / 10) % 10 + '0'; ++ pBuf[iBuf++] = ts->OffsetHour % 10 + '0'; ++ pBuf[iBuf++] = ':'; ++ pBuf[iBuf++] = (ts->OffsetMinute / 10) % 10 + '0'; ++ pBuf[iBuf++] = ts->OffsetMinute % 10 + '0'; ++ ++ pBuf[iBuf] = '\0'; ++} ++ ++void qemu_get_timestamp(char *buf, int buf_size) ++{ ++ struct timeval tp; ++ struct tm *tm; ++ struct tm tmBuf; ++ long lBias = 0; ++ time_t secs; ++ syslogTime_t ts; ++ char rfc_time_buf[TIMESTAMP_MAX_LEN] = {0}; ++ ++ /* RFC 3339 timestamp length must be greater than or equal 33 */ ++ if (buf_size < TIMESTAMP_MAX_LEN) { ++ buf[0] = '\0'; ++ printf("RFC 3339 timestamp length must be greater than or equal 33\n"); ++ return; ++ } ++ ++ gettimeofday(&tp, NULL); ++ secs = tp.tv_sec; ++ tm = localtime_r(&secs, &tmBuf); ++ ++ ts.year = tm->tm_year + BEGIN_YEAR; ++ ts.month = tm->tm_mon + 1; ++ ts.day = tm->tm_mday; ++ ts.hour = tm->tm_hour; ++ ts.minute = tm->tm_min; ++ ts.second = tm->tm_sec; ++ ts.secfrac = tp.tv_usec; ++ ts.secfracPrecision = DEFAULT_SECFRACPRECISION; ++ ++ lBias = tm->tm_gmtoff; ++ if (lBias < 0) { ++ ts.OffsetMode = '-'; ++ lBias *= -1; ++ } else { ++ ts.OffsetMode = '+'; ++ } ++ ++ ts.OffsetHour = lBias / 3600; ++ ts.OffsetMinute = (lBias % 3600) / 60; ++ ++ formatTimestamp3339(&ts, rfc_time_buf); ++ (void)snprintf(buf, buf_size, "%s", rfc_time_buf); ++} ++ ++static void qemu_get_loglevelname(int level, char *log_level_name, int len) ++{ ++ syslogName_t *c; ++ ++ for (c = syslogPriNames; c->c_name; c++) { ++ if (level == c->c_val) { ++ (void)snprintf(log_level_name, len, "%s", c->c_name); ++ return; ++ } ++ } ++ ++ printf("The log level is wrong\n"); ++} ++ ++void qemu_log_print(int level, const char *funcname, int linenr, ++ const char *fmt, ...) ++{ ++ va_list ap; ++ char time_buf[TIMESTAMP_MAX_LEN] = {0}; ++ char log_level_name[LOG_LEVEL_NAME_MAX_LEN] = {0}; ++ char buf[1024] = {0}; ++ ++ qemu_get_timestamp(time_buf, TIMESTAMP_MAX_LEN); ++ qemu_get_loglevelname(level, log_level_name, sizeof(log_level_name)); ++ ++ va_start(ap, fmt); ++ vsnprintf(buf, 1024, fmt, ap); ++ va_end(ap); ++ ++ if (funcname != NULL) { ++ fprintf(stderr, "%s|%s|qemu[%d]|[%d]|%s[%d]|: %s", time_buf, ++ log_level_name, getpid(), qemu_get_thread_id(), ++ funcname, linenr, buf); ++ } else { ++ fprintf(stderr, "%s|%s|qemu[%d]|[%d]|%s", time_buf, log_level_name, ++ getpid(), qemu_get_thread_id(), buf); ++ } ++} +-- +2.23.0 + diff --git a/qemu.spec b/qemu.spec index 7c8c4167ac4909a46abc54c1ceac297a9d4c9d91..4ee2aa95611ff057b2512399c94314ae5b59d995 100644 --- a/qemu.spec +++ b/qemu.spec @@ -1,6 +1,6 @@ Name: qemu Version: 4.1.0 -Release: 8 +Release: 9 Epoch: 2 Summary: QEMU is a generic and open source machine emulator and virtualizer License: GPLv2 and BSD and MIT and CC-BY @@ -167,6 +167,8 @@ Patch0154: ati-vga-Fix-checks-in-ati_2d_blt-to-avoid-crash.patch Patch0155: slirp-tftp-restrict-relative-path-access.patch Patch0156: ip_reass-Fix-use-after-free.patch Patch0157: bt-use-size_t-type-for-length-parameters-instead-of-.patch +Patch0158: log-add-the-qemu-log-framework.patch +Patch0159: log-Add-logs-for-VM-runtime.patch BuildRequires: flex BuildRequires: bison @@ -515,6 +517,8 @@ getent passwd qemu >/dev/null || \ * Fri May 22 2020 Huawei Technologies Co., Ltd. - ip_reass: Fix use after free - bt: use size_t type for length parameters instead of int +- log: add the qemu-log framework +- log: Add logs for VM runtime * Fri May 15 2020 Huawei Technologies Co., Ltd. - ide: Fix incorrect handling of some PRDTs in ide_dma_cb()