[PATCH 0/2] Separate memory access logs from guest_errors

[PATCH 0/2] Separate memory access logs from guest_errors

[BALATON Zoltan]

Originally memory access logs were a debug define that then were
converted to log messages but were classified as guest_errors which
already logs misc errors. As invalid memory access logs can come from
accessing not emulated peripherals or memory areas, these often
generate a lot of messages that are better be controlled separately
from other errors to avoid obscuring those. As an example try
'qemu-system-ppc -d guest_errors' to see the problem. After this
series the actual guest error logs are easier to spot. I've tried to
submit this before but there were some people who liked the current
behaviour so now this series has another patch that preserves the old
optino printing a warning to allow time to get used to the new
behaviour (which actually brings back the old behaviour when mem
access logs were a debug define).

Regards,
BALATON Zoltan

BALATON Zoltan (2):
  log: Add separate debug option for logging invalid memory accesses
  log: Suggest using -d guest_error,memaccess instead of guest_errors

 docs/devel/secure-coding-practices.rst | 2 +-
 include/qemu/log.h                     | 1 +
 system/memory.c                        | 6 +++---
 system/physmem.c                       | 2 +-
 tests/avocado/smmu.py                  | 2 +-
 tests/qtest/pnv-host-i2c-test.c        | 2 +-
 util/log.c                             | 8 +++++++-
 7 files changed, 15 insertions(+), 8 deletions(-)

-- 
2.30.9

[PATCH 1/2] log: Add separate debug option for logging invalid memory accesses

[BALATON Zoltan]

Currently -d guest_errors enables logging of different invalid actions
by the guest such as misusing hardware, accessing missing features or
invalid memory areas. The memory access logging can be quite verbose
which obscures the other messages enabled by this debug switch so
separate it by adding a new -d memaccess option to make it possible to
control it independently of other guest error logs.

Signed-off-by: BALATON Zoltan <balaton@eik.bme.hu>
---
 include/qemu/log.h | 1 +
 system/memory.c    | 6 +++---
 system/physmem.c   | 2 +-
 util/log.c         | 2 ++
 4 files changed, 7 insertions(+), 4 deletions(-)

diff --git a/include/qemu/log.h b/include/qemu/log.h
index e10e24cd4f..6122e34bdd 100644
--- a/include/qemu/log.h
+++ b/include/qemu/log.h
@@ -37,6 +37,7 @@ bool qemu_log_separate(void);
 #define LOG_PER_THREAD     (1 << 20)
 #define CPU_LOG_TB_VPU     (1 << 21)
 #define LOG_TB_OP_PLUGIN   (1 << 22)
+#define LOG_MEM_ACCESS     (1 << 23)
 
 /* Lock/unlock output. */
 
diff --git a/system/memory.c b/system/memory.c
index f6f6fee6d8..e35a473248 100644
--- a/system/memory.c
+++ b/system/memory.c
@@ -1380,7 +1380,7 @@ bool memory_region_access_valid(MemoryRegion *mr,
 {
     if (mr->ops->valid.accepts
         && !mr->ops->valid.accepts(mr->opaque, addr, size, is_write, attrs)) {
-        qemu_log_mask(LOG_GUEST_ERROR, "Invalid %s at addr 0x%" HWADDR_PRIX
+        qemu_log_mask(LOG_MEM_ACCESS, "Invalid %s at addr 0x%" HWADDR_PRIX
                       ", size %u, region '%s', reason: rejected\n",
                       is_write ? "write" : "read",
                       addr, size, memory_region_name(mr));
@@ -1388,7 +1388,7 @@ bool memory_region_access_valid(MemoryRegion *mr,
     }
 
     if (!mr->ops->valid.unaligned && (addr & (size - 1))) {
-        qemu_log_mask(LOG_GUEST_ERROR, "Invalid %s at addr 0x%" HWADDR_PRIX
+        qemu_log_mask(LOG_MEM_ACCESS, "Invalid %s at addr 0x%" HWADDR_PRIX
                       ", size %u, region '%s', reason: unaligned\n",
                       is_write ? "write" : "read",
                       addr, size, memory_region_name(mr));
@@ -1402,7 +1402,7 @@ bool memory_region_access_valid(MemoryRegion *mr,
 
     if (size > mr->ops->valid.max_access_size
         || size < mr->ops->valid.min_access_size) {
-        qemu_log_mask(LOG_GUEST_ERROR, "Invalid %s at addr 0x%" HWADDR_PRIX
+        qemu_log_mask(LOG_MEM_ACCESS, "Invalid %s at addr 0x%" HWADDR_PRIX
                       ", size %u, region '%s', reason: invalid size "
                       "(min:%u max:%u)\n",
                       is_write ? "write" : "read",
diff --git a/system/physmem.c b/system/physmem.c
index dc1db3a384..0f0e8f3bed 100644
--- a/system/physmem.c
+++ b/system/physmem.c
@@ -2745,7 +2745,7 @@ static bool flatview_access_allowed(MemoryRegion *mr, MemTxAttrs attrs,
     if (memory_region_is_ram(mr)) {
         return true;
     }
-    qemu_log_mask(LOG_GUEST_ERROR,
+    qemu_log_mask(LOG_MEM_ACCESS,
                   "Invalid access to non-RAM device at "
                   "addr 0x%" HWADDR_PRIX ", size %" HWADDR_PRIu ", "
                   "region '%s'\n", addr, len, memory_region_name(mr));
diff --git a/util/log.c b/util/log.c
index 6219819855..1aa7396277 100644
--- a/util/log.c
+++ b/util/log.c
@@ -503,6 +503,8 @@ const QEMULogItem qemu_log_items[] = {
       "open a separate log file per thread; filename must contain '%d'" },
     { CPU_LOG_TB_VPU, "vpu",
       "include VPU registers in the 'cpu' logging" },
+    { LOG_MEM_ACCESS, "memaccess",
+      "log invalid memory accesses" },
     { 0, NULL, NULL },
 };
 
-- 
2.30.9

Re: [PATCH 1/2] log: Add separate debug option for logging invalid memory accesses

[Peter Maydell]

On Sun, 6 Oct 2024 at 17:50, BALATON Zoltan <balaton@eik.bme.hu> wrote:
>
> Currently -d guest_errors enables logging of different invalid actions
> by the guest such as misusing hardware, accessing missing features or
> invalid memory areas. The memory access logging can be quite verbose
> which obscures the other messages enabled by this debug switch so
> separate it by adding a new -d memaccess option to make it possible to
> control it independently of other guest error logs.
>
> Signed-off-by: BALATON Zoltan <balaton@eik.bme.hu>
> ---
>  include/qemu/log.h | 1 +
>  system/memory.c    | 6 +++---
>  system/physmem.c   | 2 +-
>  util/log.c         | 2 ++
>  4 files changed, 7 insertions(+), 4 deletions(-)

It seems reasonable to me to separate out "log invalid
memory accesses", yes.

> diff --git a/util/log.c b/util/log.c
> index 6219819855..1aa7396277 100644
> --- a/util/log.c
> +++ b/util/log.c
> @@ -503,6 +503,8 @@ const QEMULogItem qemu_log_items[] = {
>        "open a separate log file per thread; filename must contain '%d'" },
>      { CPU_LOG_TB_VPU, "vpu",
>        "include VPU registers in the 'cpu' logging" },
> +    { LOG_MEM_ACCESS, "memaccess",
> +      "log invalid memory accesses" },
>      { 0, NULL, NULL },

As a naming thing, these are logging specifically invalid
memory accesses, not all accesses, so we should have
both the user-facing name and the LOG_ constant be
named appropriately. Perhaps
  LOG_INV_MEM_ACCESS, "invalid_mem_accesses" ?

thanks
-- PMM

Re: [PATCH 1/2] log: Add separate debug option for logging invalid memory accesses

[BALATON Zoltan]

On Mon, 14 Oct 2024, Peter Maydell wrote:
> On Sun, 6 Oct 2024 at 17:50, BALATON Zoltan <balaton@eik.bme.hu> wrote:
>>
>> Currently -d guest_errors enables logging of different invalid actions
>> by the guest such as misusing hardware, accessing missing features or
>> invalid memory areas. The memory access logging can be quite verbose
>> which obscures the other messages enabled by this debug switch so
>> separate it by adding a new -d memaccess option to make it possible to
>> control it independently of other guest error logs.
>>
>> Signed-off-by: BALATON Zoltan <balaton@eik.bme.hu>
>> ---
>>  include/qemu/log.h | 1 +
>>  system/memory.c    | 6 +++---
>>  system/physmem.c   | 2 +-
>>  util/log.c         | 2 ++
>>  4 files changed, 7 insertions(+), 4 deletions(-)
>
> It seems reasonable to me to separate out "log invalid
> memory accesses", yes.
>
>> diff --git a/util/log.c b/util/log.c
>> index 6219819855..1aa7396277 100644
>> --- a/util/log.c
>> +++ b/util/log.c
>> @@ -503,6 +503,8 @@ const QEMULogItem qemu_log_items[] = {
>>        "open a separate log file per thread; filename must contain '%d'" },
>>      { CPU_LOG_TB_VPU, "vpu",
>>        "include VPU registers in the 'cpu' logging" },
>> +    { LOG_MEM_ACCESS, "memaccess",
>> +      "log invalid memory accesses" },
>>      { 0, NULL, NULL },
>
> As a naming thing, these are logging specifically invalid
> memory accesses, not all accesses, so we should have
> both the user-facing name and the LOG_ constant be
> named appropriately. Perhaps
>  LOG_INV_MEM_ACCESS, "invalid_mem_accesses" ?

That's way too long to type and remember. Maybe invalid_mem could do?

Regards,
BALATON Zoltan

> thanks
> -- PMM
>
>

[PATCH 2/2] log: Suggest using -d guest_error,memaccess instead of guest_errors

[BALATON Zoltan]

Rename guest_errors to guest_error to match the log constant and print
a warning for -d guest_errors to remind using guest_error,memaccess
instead but preserve previous behaviour for convenience.

Signed-off-by: BALATON Zoltan <balaton@eik.bme.hu>
---
As this is a debug switch I think no formal deprecation is needed but
this is to allow people to change their commands and scripts then it
may be removed eventually.

 docs/devel/secure-coding-practices.rst | 2 +-
 tests/avocado/smmu.py                  | 2 +-
 tests/qtest/pnv-host-i2c-test.c        | 2 +-
 util/log.c                             | 6 +++++-
 4 files changed, 8 insertions(+), 4 deletions(-)

diff --git a/docs/devel/secure-coding-practices.rst b/docs/devel/secure-coding-practices.rst
index 0454cc527e..b330b01956 100644
--- a/docs/devel/secure-coding-practices.rst
+++ b/docs/devel/secure-coding-practices.rst
@@ -85,7 +85,7 @@ request completes.  Unexpected accesses must not cause memory corruption or
 leaks in QEMU.
 
 Invalid device register accesses can be reported with
-``qemu_log_mask(LOG_GUEST_ERROR, ...)``.  The ``-d guest_errors`` command-line
+``qemu_log_mask(LOG_GUEST_ERROR, ...)``.  The ``-d guest_error`` command-line
 option enables these log messages.
 
 Live Migration
diff --git a/tests/avocado/smmu.py b/tests/avocado/smmu.py
index 83fd79e922..7ed836c12d 100644
--- a/tests/avocado/smmu.py
+++ b/tests/avocado/smmu.py
@@ -46,7 +46,7 @@ def common_vm_setup(self, custom_kernel=False):
         self.vm.add_args("-accel", "kvm")
         self.vm.add_args("-cpu", "host")
         self.vm.add_args("-machine", "iommu=smmuv3")
-        self.vm.add_args("-d", "guest_errors")
+        self.vm.add_args("-d", "guest_error,memaccess")
         self.vm.add_args('-bios', os.path.join(BUILD_DIR, 'pc-bios',
                          'edk2-aarch64-code.fd'))
         self.vm.add_args('-device', 'virtio-rng-pci,rng=rng0')
diff --git a/tests/qtest/pnv-host-i2c-test.c b/tests/qtest/pnv-host-i2c-test.c
index 7f64d597ac..63a2acf9de 100644
--- a/tests/qtest/pnv-host-i2c-test.c
+++ b/tests/qtest/pnv-host-i2c-test.c
@@ -418,7 +418,7 @@ static void test_host_i2c(const void *data)
 
     qts = qtest_initf("-M %s -smp %d,cores=1,threads=%d -nographic "
                       "-nodefaults -serial mon:stdio -S "
-                      "-d guest_errors",
+                      "-d guest_error,memaccess",
                       machine, SMT, SMT);
 
     /* Check the I2C master status registers after POR */
diff --git a/util/log.c b/util/log.c
index 1aa7396277..279c2b5cfb 100644
--- a/util/log.c
+++ b/util/log.c
@@ -486,7 +486,7 @@ const QEMULogItem qemu_log_items[] = {
       "show CPU state before CPU resets" },
     { LOG_UNIMP, "unimp",
       "log unimplemented functionality" },
-    { LOG_GUEST_ERROR, "guest_errors",
+    { LOG_GUEST_ERROR, "guest_error",
       "log when the guest OS does something invalid (eg accessing a\n"
       "non-existent register)" },
     { CPU_LOG_PAGE, "page",
@@ -521,6 +521,10 @@ int qemu_str_to_log_mask(const char *str)
             for (item = qemu_log_items; item->mask != 0; item++) {
                 mask |= item->mask;
             }
+        } else if (g_str_equal(*tmp, "guest_errors")) {
+            warn_report("Log option guest_errors is deprecated. "
+                        "Use guest_error,memaccess instead.");
+            mask |= LOG_GUEST_ERROR | LOG_MEM_ACCESS;
 #ifdef CONFIG_TRACE_LOG
         } else if (g_str_has_prefix(*tmp, "trace:") && (*tmp)[6] != '\0') {
             trace_enable_events((*tmp) + 6);
-- 
2.30.9

Re: [PATCH 2/2] log: Suggest using -d guest_error,memaccess instead of guest_errors

[Peter Maydell]

On Sun, 6 Oct 2024 at 17:49, BALATON Zoltan <balaton@eik.bme.hu> wrote:
>
> Rename guest_errors to guest_error to match the log constant

I don't think this is a good reason to change the user-facing
behaviour. Also, I don't think the existing names are so bad:

 -d guest_errors
   this is plural because we are asking to log all guest errors
 qemu_log_mask(LOG_GUEST_ERROR, ...)
   this is singular because we are logging a single error here.

If we do want to change things for consistency, we should decide
on what the user-facing option name ought to be (and I think
plural is fine), and then change the internal define to match
that, not vice versa.

> and print
> a warning for -d guest_errors to remind using guest_error,memaccess
> instead but preserve previous behaviour for convenience.
>
> Signed-off-by: BALATON Zoltan <balaton@eik.bme.hu>

thanks
-- PMM

Re: [PATCH 2/2] log: Suggest using -d guest_error,memaccess instead of guest_errors

[BALATON Zoltan]

On Mon, 14 Oct 2024, Peter Maydell wrote:
> On Sun, 6 Oct 2024 at 17:49, BALATON Zoltan <balaton@eik.bme.hu> wrote:
>>
>> Rename guest_errors to guest_error to match the log constant
>
> I don't think this is a good reason to change the user-facing
> behaviour. Also, I don't think the existing names are so bad:
>
> -d guest_errors
>   this is plural because we are asking to log all guest errors
> qemu_log_mask(LOG_GUEST_ERROR, ...)
>   this is singular because we are logging a single error here.
>
> If we do want to change things for consistency, we should decide
> on what the user-facing option name ought to be (and I think
> plural is fine), and then change the internal define to match
> that, not vice versa.

The point of this patch is not to match the define with the option. 
Originally I had a patch that just separated memory access logs and left 
guest_errors as it is but without the memory access logs. But I think 
Philippe said that he likes this option to log both. So to satisfy all 
needs I'v added this patch to preserve what guest_errors is doing now but 
let it be changed later after some time for people to get used to it (or 
leave it if that's what people like). Leaving guest_errors to log both is 
not an option as I want to have separate options for memory access and 
guest errors so they can be turned on or off independently. So if we have 
to keep guest_errors to log both then we need a new option for just guest 
errors for which one that matches the definen seemed like an easy way that 
is consistent with the other debug options. I'd be OK to leave 
guest_errors but without the memory access logs, then this patch is not 
needed but some people did not like that before.

Regards,
BALATON Zoltan

>> and print
>> a warning for -d guest_errors to remind using guest_error,memaccess
>> instead but preserve previous behaviour for convenience.
>>
>> Signed-off-by: BALATON Zoltan <balaton@eik.bme.hu>
>
> thanks
> -- PMM
>
>