Re: [PATCH 6/6] system/memory: Trace names of MemoryRegions rather than host pointers

2023-11-02 Thread Bernhard Beschow



Am 30. Oktober 2023 03:36:44 UTC schrieb "Philippe Mathieu-Daudé" 
:
>Hi Bernhard,
>
>On 28/10/23 14:24, Bernhard Beschow wrote:
>> Tracing the host pointer of the accessed MemoryRegion seems to be a debug
>> feature for developing QEMU itself. When analyzing guest behavior by 
>> comparing
>> traces, these pointers generate a lot of noise since the pointers differ 
>> between
>> QEMU invocations, making this task harder than it needs to be. Moreover, the
>> pointers seem to be redundant to the names already assigned to MemoryRegions.
>
>I tried that few years ago but this got lost:
>https://lore.kernel.org/qemu-devel/20210307074833.143106-1-f4...@amsat.org/
>
>> Remove the pointers from the traces and trace the names where missing. When
>> developing QEMU, developers could just add the host pointer tracing for
>> themselves.
>
>But sometimes an object exposing a MR is instantiated multiple times,
>each time, and now you can not distinct which object is accessed.
>
>IIRC a suggestion was to cache the QOM parent path and display that,
>which should be constant to diff tracing logs. But then IIRC again the
>issue was the QOM path is resolved once the object is realized, which
>happens *after* we initialize the MR within the object. Maybe the
>solution is to add a memory_region_qom_pathname() getter and do lazy
>initialization?

Would logging the guest rather than the host address (in addition to the MR 
name) work?

Best regards,
Bernhard

>
>> Signed-off-by: Bernhard Beschow 
>> ---
>>   docs/devel/tracing.rst |  4 ++--
>>   system/memory.c| 26 --
>>   system/trace-events| 12 ++--
>>   3 files changed, 24 insertions(+), 18 deletions(-)
>> 
>> diff --git a/docs/devel/tracing.rst b/docs/devel/tracing.rst
>> index d288480db1..8c31d5f76e 100644
>> --- a/docs/devel/tracing.rst
>> +++ b/docs/devel/tracing.rst
>> @@ -18,8 +18,8 @@ events::
>> $ qemu --trace "memory_region_ops_*" ...
>>   ...
>> -719585@1608130130.441188:memory_region_ops_read cpu 0 mr 0x562fdfbb3820 
>> addr 0x3cc value 0x67 size 1
>> -719585@1608130130.441190:memory_region_ops_write cpu 0 mr 
>> 0x562fdfbd2f00 addr 0x3d4 value 0x70e size 2
>> +719585@1608130130.441188:memory_region_ops_read cpu 0 addr 0x3cc value 
>> 0x67 size 1
>> +719585@1608130130.441190:memory_region_ops_write cpu 0 addr 0x3d4 value 
>> 0x70e size 2
>
>Is this example missing the MR name?
>
>> This output comes from the "log" trace backend that is enabled by 
>> default when
>>   ``./configure --enable-trace-backends=BACKENDS`` was not explicitly 
>> specified.
>> diff --git a/system/memory.c b/system/memory.c
>> index 4928f2525d..076a992b74 100644
>> --- a/system/memory.c
>> +++ b/system/memory.c
>> @@ -444,10 +444,11 @@ static MemTxResult  
>> memory_region_read_accessor(MemoryRegion *mr,
>> tmp = mr->ops->read(mr->opaque, addr, size);
>>   if (mr->subpage) {
>> -trace_memory_region_subpage_read(get_cpu_index(), mr, addr, tmp, 
>> size);
>> +trace_memory_region_subpage_read(get_cpu_index(), addr, tmp, size,
>> + memory_region_name(mr));
>>   } else if 
>> (trace_event_get_state_backends(TRACE_MEMORY_REGION_OPS_READ)) {
>>   hwaddr abs_addr = memory_region_to_absolute_addr(mr, addr);
>> -trace_memory_region_ops_read(get_cpu_index(), mr, abs_addr, tmp, 
>> size,
>> +trace_memory_region_ops_read(get_cpu_index(), abs_addr, tmp, size,
>>memory_region_name(mr));
>>   }
>>   memory_region_shift_read_access(value, shift, mask, tmp);
>> @@ -467,10 +468,11 @@ static MemTxResult 
>> memory_region_read_with_attrs_accessor(MemoryRegion *mr,
>> r = mr->ops->read_with_attrs(mr->opaque, addr, , size, attrs);
>>   if (mr->subpage) {
>> -trace_memory_region_subpage_read(get_cpu_index(), mr, addr, tmp, 
>> size);
>> +trace_memory_region_subpage_read(get_cpu_index(), addr, tmp, size,
>> + memory_region_name(mr));
>>   } else if 
>> (trace_event_get_state_backends(TRACE_MEMORY_REGION_OPS_READ)) {
>>   hwaddr abs_addr = memory_region_to_absolute_addr(mr, addr);
>> -trace_memory_region_ops_read(get_cpu_index(), mr, abs_addr, tmp, 
>> size,
>> +trace_memory_region_ops_read(get_cpu_index(), abs_addr, tmp, size,
>>memory_region_name(mr));
>>   }
>>   memory_region_shift_read_access(value, shift, mask, tmp);
>> @@ -488,10 +490,11 @@ static MemTxResult 
>> memory_region_write_accessor(MemoryRegion *mr,
>>   uint64_t tmp = memory_region_shift_write_access(value, shift, mask);
>> if (mr->subpage) {
>> -trace_memory_region_subpage_write(get_cpu_index(), mr, addr, tmp, 
>> size);
>> +trace_memory_region_subpage_write(get_cpu_index(), addr, tmp, size,
>> +  

Re: [PATCH 6/6] system/memory: Trace names of MemoryRegions rather than host pointers

2023-10-29 Thread Philippe Mathieu-Daudé

Hi Bernhard,

On 28/10/23 14:24, Bernhard Beschow wrote:

Tracing the host pointer of the accessed MemoryRegion seems to be a debug
feature for developing QEMU itself. When analyzing guest behavior by comparing
traces, these pointers generate a lot of noise since the pointers differ between
QEMU invocations, making this task harder than it needs to be. Moreover, the
pointers seem to be redundant to the names already assigned to MemoryRegions.


I tried that few years ago but this got lost:
https://lore.kernel.org/qemu-devel/20210307074833.143106-1-f4...@amsat.org/


Remove the pointers from the traces and trace the names where missing. When
developing QEMU, developers could just add the host pointer tracing for
themselves.


But sometimes an object exposing a MR is instantiated multiple times,
each time, and now you can not distinct which object is accessed.

IIRC a suggestion was to cache the QOM parent path and display that,
which should be constant to diff tracing logs. But then IIRC again the
issue was the QOM path is resolved once the object is realized, which
happens *after* we initialize the MR within the object. Maybe the
solution is to add a memory_region_qom_pathname() getter and do lazy
initialization?


Signed-off-by: Bernhard Beschow 
---
  docs/devel/tracing.rst |  4 ++--
  system/memory.c| 26 --
  system/trace-events| 12 ++--
  3 files changed, 24 insertions(+), 18 deletions(-)

diff --git a/docs/devel/tracing.rst b/docs/devel/tracing.rst
index d288480db1..8c31d5f76e 100644
--- a/docs/devel/tracing.rst
+++ b/docs/devel/tracing.rst
@@ -18,8 +18,8 @@ events::
  
  $ qemu --trace "memory_region_ops_*" ...

  ...
-719585@1608130130.441188:memory_region_ops_read cpu 0 mr 0x562fdfbb3820 
addr 0x3cc value 0x67 size 1
-719585@1608130130.441190:memory_region_ops_write cpu 0 mr 0x562fdfbd2f00 
addr 0x3d4 value 0x70e size 2
+719585@1608130130.441188:memory_region_ops_read cpu 0 addr 0x3cc value 
0x67 size 1
+719585@1608130130.441190:memory_region_ops_write cpu 0 addr 0x3d4 value 
0x70e size 2


Is this example missing the MR name?

  
  This output comes from the "log" trace backend that is enabled by default when

  ``./configure --enable-trace-backends=BACKENDS`` was not explicitly specified.
diff --git a/system/memory.c b/system/memory.c
index 4928f2525d..076a992b74 100644
--- a/system/memory.c
+++ b/system/memory.c
@@ -444,10 +444,11 @@ static MemTxResult  
memory_region_read_accessor(MemoryRegion *mr,
  
  tmp = mr->ops->read(mr->opaque, addr, size);

  if (mr->subpage) {
-trace_memory_region_subpage_read(get_cpu_index(), mr, addr, tmp, size);
+trace_memory_region_subpage_read(get_cpu_index(), addr, tmp, size,
+ memory_region_name(mr));
  } else if (trace_event_get_state_backends(TRACE_MEMORY_REGION_OPS_READ)) {
  hwaddr abs_addr = memory_region_to_absolute_addr(mr, addr);
-trace_memory_region_ops_read(get_cpu_index(), mr, abs_addr, tmp, size,
+trace_memory_region_ops_read(get_cpu_index(), abs_addr, tmp, size,
   memory_region_name(mr));
  }
  memory_region_shift_read_access(value, shift, mask, tmp);
@@ -467,10 +468,11 @@ static MemTxResult 
memory_region_read_with_attrs_accessor(MemoryRegion *mr,
  
  r = mr->ops->read_with_attrs(mr->opaque, addr, , size, attrs);

  if (mr->subpage) {
-trace_memory_region_subpage_read(get_cpu_index(), mr, addr, tmp, size);
+trace_memory_region_subpage_read(get_cpu_index(), addr, tmp, size,
+ memory_region_name(mr));
  } else if (trace_event_get_state_backends(TRACE_MEMORY_REGION_OPS_READ)) {
  hwaddr abs_addr = memory_region_to_absolute_addr(mr, addr);
-trace_memory_region_ops_read(get_cpu_index(), mr, abs_addr, tmp, size,
+trace_memory_region_ops_read(get_cpu_index(), abs_addr, tmp, size,
   memory_region_name(mr));
  }
  memory_region_shift_read_access(value, shift, mask, tmp);
@@ -488,10 +490,11 @@ static MemTxResult 
memory_region_write_accessor(MemoryRegion *mr,
  uint64_t tmp = memory_region_shift_write_access(value, shift, mask);
  
  if (mr->subpage) {

-trace_memory_region_subpage_write(get_cpu_index(), mr, addr, tmp, 
size);
+trace_memory_region_subpage_write(get_cpu_index(), addr, tmp, size,
+  memory_region_name(mr));
  } else if (trace_event_get_state_backends(TRACE_MEMORY_REGION_OPS_WRITE)) 
{
  hwaddr abs_addr = memory_region_to_absolute_addr(mr, addr);
-trace_memory_region_ops_write(get_cpu_index(), mr, abs_addr, tmp, size,
+trace_memory_region_ops_write(get_cpu_index(), abs_addr, tmp, size,
memory_region_name(mr));
  }
  mr->ops->write(mr->opaque, addr, tmp, size);
@@ 

[PATCH 6/6] system/memory: Trace names of MemoryRegions rather than host pointers

2023-10-28 Thread Bernhard Beschow
Tracing the host pointer of the accessed MemoryRegion seems to be a debug
feature for developing QEMU itself. When analyzing guest behavior by comparing
traces, these pointers generate a lot of noise since the pointers differ between
QEMU invocations, making this task harder than it needs to be. Moreover, the
pointers seem to be redundant to the names already assigned to MemoryRegions.

Remove the pointers from the traces and trace the names where missing. When
developing QEMU, developers could just add the host pointer tracing for
themselves.

Signed-off-by: Bernhard Beschow 
---
 docs/devel/tracing.rst |  4 ++--
 system/memory.c| 26 --
 system/trace-events| 12 ++--
 3 files changed, 24 insertions(+), 18 deletions(-)

diff --git a/docs/devel/tracing.rst b/docs/devel/tracing.rst
index d288480db1..8c31d5f76e 100644
--- a/docs/devel/tracing.rst
+++ b/docs/devel/tracing.rst
@@ -18,8 +18,8 @@ events::
 
 $ qemu --trace "memory_region_ops_*" ...
 ...
-719585@1608130130.441188:memory_region_ops_read cpu 0 mr 0x562fdfbb3820 
addr 0x3cc value 0x67 size 1
-719585@1608130130.441190:memory_region_ops_write cpu 0 mr 0x562fdfbd2f00 
addr 0x3d4 value 0x70e size 2
+719585@1608130130.441188:memory_region_ops_read cpu 0 addr 0x3cc value 
0x67 size 1
+719585@1608130130.441190:memory_region_ops_write cpu 0 addr 0x3d4 value 
0x70e size 2
 
 This output comes from the "log" trace backend that is enabled by default when
 ``./configure --enable-trace-backends=BACKENDS`` was not explicitly specified.
diff --git a/system/memory.c b/system/memory.c
index 4928f2525d..076a992b74 100644
--- a/system/memory.c
+++ b/system/memory.c
@@ -444,10 +444,11 @@ static MemTxResult  
memory_region_read_accessor(MemoryRegion *mr,
 
 tmp = mr->ops->read(mr->opaque, addr, size);
 if (mr->subpage) {
-trace_memory_region_subpage_read(get_cpu_index(), mr, addr, tmp, size);
+trace_memory_region_subpage_read(get_cpu_index(), addr, tmp, size,
+ memory_region_name(mr));
 } else if (trace_event_get_state_backends(TRACE_MEMORY_REGION_OPS_READ)) {
 hwaddr abs_addr = memory_region_to_absolute_addr(mr, addr);
-trace_memory_region_ops_read(get_cpu_index(), mr, abs_addr, tmp, size,
+trace_memory_region_ops_read(get_cpu_index(), abs_addr, tmp, size,
  memory_region_name(mr));
 }
 memory_region_shift_read_access(value, shift, mask, tmp);
@@ -467,10 +468,11 @@ static MemTxResult 
memory_region_read_with_attrs_accessor(MemoryRegion *mr,
 
 r = mr->ops->read_with_attrs(mr->opaque, addr, , size, attrs);
 if (mr->subpage) {
-trace_memory_region_subpage_read(get_cpu_index(), mr, addr, tmp, size);
+trace_memory_region_subpage_read(get_cpu_index(), addr, tmp, size,
+ memory_region_name(mr));
 } else if (trace_event_get_state_backends(TRACE_MEMORY_REGION_OPS_READ)) {
 hwaddr abs_addr = memory_region_to_absolute_addr(mr, addr);
-trace_memory_region_ops_read(get_cpu_index(), mr, abs_addr, tmp, size,
+trace_memory_region_ops_read(get_cpu_index(), abs_addr, tmp, size,
  memory_region_name(mr));
 }
 memory_region_shift_read_access(value, shift, mask, tmp);
@@ -488,10 +490,11 @@ static MemTxResult 
memory_region_write_accessor(MemoryRegion *mr,
 uint64_t tmp = memory_region_shift_write_access(value, shift, mask);
 
 if (mr->subpage) {
-trace_memory_region_subpage_write(get_cpu_index(), mr, addr, tmp, 
size);
+trace_memory_region_subpage_write(get_cpu_index(), addr, tmp, size,
+  memory_region_name(mr));
 } else if (trace_event_get_state_backends(TRACE_MEMORY_REGION_OPS_WRITE)) {
 hwaddr abs_addr = memory_region_to_absolute_addr(mr, addr);
-trace_memory_region_ops_write(get_cpu_index(), mr, abs_addr, tmp, size,
+trace_memory_region_ops_write(get_cpu_index(), abs_addr, tmp, size,
   memory_region_name(mr));
 }
 mr->ops->write(mr->opaque, addr, tmp, size);
@@ -509,10 +512,11 @@ static MemTxResult 
memory_region_write_with_attrs_accessor(MemoryRegion *mr,
 uint64_t tmp = memory_region_shift_write_access(value, shift, mask);
 
 if (mr->subpage) {
-trace_memory_region_subpage_write(get_cpu_index(), mr, addr, tmp, 
size);
+trace_memory_region_subpage_write(get_cpu_index(), addr, tmp, size,
+  memory_region_name(mr));
 } else if (trace_event_get_state_backends(TRACE_MEMORY_REGION_OPS_WRITE)) {
 hwaddr abs_addr = memory_region_to_absolute_addr(mr, addr);
-trace_memory_region_ops_write(get_cpu_index(), mr, abs_addr, tmp, size,
+trace_memory_region_ops_write(get_cpu_index(), abs_addr, tmp, size,