Re: [PATCH v3] hw/uefi: add "info firmware-log" + "query-firmware-log" monitor commands

[Markus Armbruster <armbru@redhat.com>]

Yet another thing...

Markus Armbruster <armbru@redhat.com> writes:

> One more thing...  or rather two.
>
> Markus Armbruster <armbru@redhat.com> writes:
>
>> Gerd Hoffmann <kraxel@redhat.com> writes:
>>
>>> Starting with the edk2-stable202508 tag OVMF (and ArmVirt too) have
>>> optional support for logging to a memory buffer.  There is guest side
>>> support -- for example in linux kernels v6.17+ -- to read that buffer.
>>> But that might not helpful if your guest stops booting early enough that
>>> guest tooling can not be used yet.  So host side support to read that
>>> log buffer is a useful thing to have.
>>>
>>> This patch implements both qmp and hmp monitor commands to read the
>>> firmware log.
>>
>> So this is just for EDK2, at least for now.
>>
>>> Signed-off-by: Gerd Hoffmann <kraxel@redhat.com>
>>> ---
>>>  include/monitor/hmp.h      |   1 +
>>>  hw/uefi/ovmf-log.c         | 265 +++++++++++++++++++++++++++++++++++++
>>>  tests/qtest/qmp-cmd-test.c |   2 +
>>>  hmp-commands-info.hx       |  14 ++
>>>  hw/uefi/meson.build        |   2 +-
>>>  qapi/machine.json          |  23 ++++
>>>  6 files changed, 306 insertions(+), 1 deletion(-)
>>>  create mode 100644 hw/uefi/ovmf-log.c
>>>
>>> diff --git a/include/monitor/hmp.h b/include/monitor/hmp.h
>>> index ae116d9804a3..885c0ecd2aed 100644
>>> --- a/include/monitor/hmp.h
>>> +++ b/include/monitor/hmp.h
>>> @@ -178,5 +178,6 @@ void hmp_boot_set(Monitor *mon, const QDict *qdict);
>>>  void hmp_info_mtree(Monitor *mon, const QDict *qdict);
>>>  void hmp_info_cryptodev(Monitor *mon, const QDict *qdict);
>>>  void hmp_dumpdtb(Monitor *mon, const QDict *qdict);
>>> +void hmp_info_firmware_log(Monitor *mon, const QDict *qdict);
>>>  
>>>  #endif
>>> diff --git a/hw/uefi/ovmf-log.c b/hw/uefi/ovmf-log.c
>>> new file mode 100644
>>> index 000000000000..89e27d916531
>>> --- /dev/null
>>> +++ b/hw/uefi/ovmf-log.c
>>> @@ -0,0 +1,265 @@
>>> +/*
>>> + * SPDX-License-Identifier: GPL-2.0-or-later
>>> + *
>>> + * print ovmf debug log
>>> + *
>>> + * see OvmfPkg/Library/MemDebugLogLib/ in edk2
>>> + */
>>> +
>>> +#include "qemu/osdep.h"
>>> +#include "qemu/units.h"
>>> +#include "qemu/base64.h"
>>> +#include "qemu/target-info-qapi.h"
>>> +#include "hw/boards.h"
>>> +#include "hw/i386/x86.h"
>>> +#include "hw/arm/virt.h"
>>> +#include "system/dma.h"
>>> +#include "monitor/hmp.h"
>>> +#include "monitor/monitor.h"
>>> +#include "qapi/error.h"
>>> +#include "qapi/type-helpers.h"
>>> +#include "qapi/qapi-commands-machine.h"
>>> +
>>> +
>>> +/* ----------------------------------------------------------------------- */
>>> +/* copy from edk2                                                          */
>>> +
>>> +#define MEM_DEBUG_LOG_MAGIC1  0x3167646d666d766f  /* "ovmfmdg1" */
>>> +#define MEM_DEBUG_LOG_MAGIC2  0x3267646d666d766f  /* "ovmfmdg2" */
>>> +
>>> +/*
>>> + * Mem Debug Log buffer header.
>>> + * The Log buffer is circular. Only the most
>>> + * recent messages are retained. Older messages
>>> + * will be discarded if the buffer overflows.
>>> + * The Debug Log starts just after the header.
>>> + */
>>> +typedef struct {
>>> +    /*
>>> +     * Magic values
>>> +     * These fields are used by tools to locate the buffer in
>>> +     * memory. These MUST be the first two fields of the structure.
>>> +     * Use a 128 bit Magic to vastly reduce the possibility of
>>> +     * a collision with random data in memory.
>>> +     */
>>> +    uint64_t             Magic1;
>>> +    uint64_t             Magic2;
>>> +    /*
>>> +     * Header Size
>>> +     * This MUST be the third field of the structure
>>> +     */
>>> +    uint64_t             HeaderSize;
>>> +    /*
>>> +     * Debug log size (minus header)
>>> +     */
>>> +    uint64_t             DebugLogSize;
>>> +    /*
>>> +     * edk2 uses this for locking access.
>>> +     */
>>> +    uint64_t             MemDebugLogLock;
>>> +    /*
>>> +     * Debug log head offset
>>> +     */
>>> +    uint64_t             DebugLogHeadOffset;
>>> +    /*
>>> +     *  Debug log tail offset
>>> +     */
>>> +    uint64_t             DebugLogTailOffset;
>>> +    /*
>>> +     * Flag to indicate if the buffer wrapped and was thus truncated.
>>> +     */
>>> +    uint64_t             Truncated;
>>> +    /*
>>> +     * Firmware Build Version (PcdFirmwareVersionString)
>>> +     */
>>> +    char                 FirmwareVersion[128];

Note for later: FirmwareVersion is an array.

>>> +} MEM_DEBUG_LOG_HDR;

[...]

>>> +static void handle_ovmf_log_range(GString *out,
>>> +                                  dma_addr_t start,
>>> +                                  dma_addr_t end,
>>> +                                  Error **errp)
>>> +{
>>> +    g_autofree char *buf = NULL;
>>> +
>>> +    if (start > end) {
>>> +        return;
>>> +    }
>>> +
>>> +    buf = g_malloc(end - start + 1);
>>
>> How big can this buffer become?  See [*] below.
>>
>>> +    if (dma_memory_read(&address_space_memory, start,
>>> +                        buf, end - start,
>>> +                        MEMTXATTRS_UNSPECIFIED)) {
>>> +        error_setg(errp, "firmware log: buffer read error");
>>> +        return;
>>> +    }
>>> +
>>> +    buf[end - start] = 0;
>>> +    g_string_append_printf(out, "%s", buf);
>>
>> This falls apart when the log contains '\0'.  Suggest something like
>>
>>        g_string_append_len(out, buf, end - start);
>>
>> or even better, the direct read Daniel suggested.
>>
>>> +}
>>> +
>>> +FirmwareLog *qmp_query_firmware_log(Error **errp)
>>> +{
>>> +    MEM_DEBUG_LOG_HDR header;
>>> +    dma_addr_t offset, base;
>>> +    FirmwareLog *ret;
>>> +    g_autoptr(GString) log = g_string_new("");
>>> +
>>> +    offset = find_ovmf_log();
>>> +    if (offset == -1) {
>>> +        error_setg(errp, "firmware log: not found");
>>> +        return NULL;
>>> +    }
>>> +
>>> +    if (dma_memory_read(&address_space_memory, offset,
>>> +                        &header, sizeof(header),
>>> +                        MEMTXATTRS_UNSPECIFIED)) {
>>> +        error_setg(errp, "firmware log: header read error");
>>> +        return NULL;
>>> +    }
>>> +
>>> +    if (header.DebugLogSize > MiB) {
>>> +        /* default size is 128k (32 pages), allow up to 1M */
>>> +        error_setg(errp, "firmware log: log buffer is too big");
>>
>> [*] We limit the buffer to 1MiB.  No objection to the size.
>>
>> What do you mean by "default" in "default size"?  Is the size
>> configurable in EDK2?
>>
>> Should we try to cope more gracefully with oversized log buffers?  It's
>> a ring buffer.  What about silently reading the latest 1MiB then?
>> Behaves just as if the ring buffer was 1MiB.
>>
>>> +        return NULL;
>>> +    }
>>> +
>>> +    if (header.DebugLogHeadOffset > header.DebugLogSize ||
>>> +        header.DebugLogTailOffset > header.DebugLogSize) {
>>> +        error_setg(errp, "firmware log: invalid header");
>>> +        return NULL;
>>> +    }
>>> +
>>> +    base = offset + header.HeaderSize;
>>> +    if (header.DebugLogHeadOffset > header.DebugLogTailOffset) {
>>> +        /* wrap around */
>>> +        handle_ovmf_log_range(log,
>>> +                              base + header.DebugLogHeadOffset,
>>> +                              base + header.DebugLogSize,
>>> +                              errp);
>>> +        if (*errp) {
>>> +            return NULL;
>>> +        }
>>> +        handle_ovmf_log_range(log,
>>> +                              base + 0,
>>> +                              base + header.DebugLogTailOffset,
>>> +                              errp);
>>> +        if (*errp) {
>>> +            return NULL;
>>> +        }
>>> +    } else {
>>> +        handle_ovmf_log_range(log,
>>> +                              base + header.DebugLogHeadOffset,
>>> +                              base + header.DebugLogTailOffset,
>>> +                              errp);
>>> +        if (*errp) {
>>> +            return NULL;
>>> +        }
>>> +    }
>>> +
>>> +    ret = g_new0(FirmwareLog, 1);
>>> +    ret->version = g_strdup(header.FirmwareVersion);

FirmwareVersion is char[128].  g_strdup() copies until the first zero
byte.  I fear a malicious guest can set up its memory to make us
allocate and copy a lot more than 127 bytes.

Please use g_strndup().

>>> +    ret->log = g_base64_encode((const guchar *)log->str, log->len);
>>> +    return ret;
>>
>> Note for later [**]: both ->version and ->log are non-null on success.
>>
>>> +}

[...]