[PATCH v4 2/2] trace: Example of non-tracing recorder use

Christophe de Dinechin posted 2 patches 5 years, 6 months ago
Maintainers: "Dr. David Alan Gilbert" <dgilbert@redhat.com>, Stefan Hajnoczi <stefanha@redhat.com>, Markus Armbruster <armbru@redhat.com>
[PATCH v4 2/2] trace: Example of non-tracing recorder use
Posted by Christophe de Dinechin 5 years, 6 months ago
This patch is a simple example showing how the recorder can be used to
have one "topic" covering multiple entries. Here, the topic is "lock",
the idea being to have the latest lock changes for instance in case of
a crash or hang.

Here are a few use cases:

* Tracing  lock updates:
    RECORDER_TRACES=lock qemu
* Showing lock changes prior to a hang
    RECORDER_TRACES=lock qemu &
    # Wait until hang
    killall -USR2 qemu  # This will trigger a dump
* Graphic visualization of lock states:
    RECORDER_TRACES="lock=state,id" qemu &
    recorder_scope state
    # Hit the 't' key to toggle timing display
    # Hit the 'c' key to dump the screen data as CSV
    cat recorder_scope_data-1.csv

Signed-off-by: Christophe de Dinechin <dinechin@redhat.com>
---
 util/qemu-thread-common.h | 7 +++++++
 1 file changed, 7 insertions(+)

diff --git a/util/qemu-thread-common.h b/util/qemu-thread-common.h
index 2af6b12085..0de07a471f 100644
--- a/util/qemu-thread-common.h
+++ b/util/qemu-thread-common.h
@@ -15,6 +15,9 @@
 
 #include "qemu/thread.h"
 #include "trace.h"
+#include "trace/recorder.h"
+
+RECORDER_DEFINE(lock, 16, "Lock state");
 
 static inline void qemu_mutex_post_init(QemuMutex *mutex)
 {
@@ -23,12 +26,14 @@ static inline void qemu_mutex_post_init(QemuMutex *mutex)
     mutex->line = 0;
 #endif
     mutex->initialized = true;
+    record(lock, "Init state %d for %p", -1, mutex);
 }
 
 static inline void qemu_mutex_pre_lock(QemuMutex *mutex,
                                        const char *file, int line)
 {
     trace_qemu_mutex_lock(mutex, file, line);
+    record(lock, "Locking state %d for %p", 1, mutex);
 }
 
 static inline void qemu_mutex_post_lock(QemuMutex *mutex,
@@ -39,6 +44,7 @@ static inline void qemu_mutex_post_lock(QemuMutex *mutex,
     mutex->line = line;
 #endif
     trace_qemu_mutex_locked(mutex, file, line);
+    record(lock, "Locked state %d for %p", 2, mutex);
 }
 
 static inline void qemu_mutex_pre_unlock(QemuMutex *mutex,
@@ -49,6 +55,7 @@ static inline void qemu_mutex_pre_unlock(QemuMutex *mutex,
     mutex->line = 0;
 #endif
     trace_qemu_mutex_unlock(mutex, file, line);
+    record(lock, "Unkocked state %d for %p", 0, mutex);
 }
 
 #endif
-- 
2.26.2


Re: [PATCH v4 2/2] trace: Example of non-tracing recorder use
Posted by Stefan Hajnoczi 5 years, 6 months ago
On Thu, Jul 23, 2020 at 03:29:03PM +0200, Christophe de Dinechin wrote:
> This patch is a simple example showing how the recorder can be used to
> have one "topic" covering multiple entries. Here, the topic is "lock",
> the idea being to have the latest lock changes for instance in case of
> a crash or hang.
> 
> Here are a few use cases:
> 
> * Tracing  lock updates:
>     RECORDER_TRACES=lock qemu
> * Showing lock changes prior to a hang
>     RECORDER_TRACES=lock qemu &
>     # Wait until hang
>     killall -USR2 qemu  # This will trigger a dump
> * Graphic visualization of lock states:
>     RECORDER_TRACES="lock=state,id" qemu &
>     recorder_scope state
>     # Hit the 't' key to toggle timing display
>     # Hit the 'c' key to dump the screen data as CSV
>     cat recorder_scope_data-1.csv

Dan raised a good point regarding integrating recorder functionality
behind the tracetool interface.

On the other hand, I would like to see where this goes so that we have
enough experience to design the tracetool interface, if necessary.

Therefore I am for merging this as-is and taking action when it's clear
that duplication is taking place.

Stefan
Re: [PATCH v4 2/2] trace: Example of non-tracing recorder use
Posted by Markus Armbruster 5 years, 6 months ago
Stefan Hajnoczi <stefanha@redhat.com> writes:

> On Thu, Jul 23, 2020 at 03:29:03PM +0200, Christophe de Dinechin wrote:
>> This patch is a simple example showing how the recorder can be used to
>> have one "topic" covering multiple entries. Here, the topic is "lock",
>> the idea being to have the latest lock changes for instance in case of
>> a crash or hang.
>> 
>> Here are a few use cases:
>> 
>> * Tracing  lock updates:
>>     RECORDER_TRACES=lock qemu
>> * Showing lock changes prior to a hang
>>     RECORDER_TRACES=lock qemu &
>>     # Wait until hang
>>     killall -USR2 qemu  # This will trigger a dump
>> * Graphic visualization of lock states:
>>     RECORDER_TRACES="lock=state,id" qemu &
>>     recorder_scope state
>>     # Hit the 't' key to toggle timing display
>>     # Hit the 'c' key to dump the screen data as CSV
>>     cat recorder_scope_data-1.csv
>
> Dan raised a good point regarding integrating recorder functionality
> behind the tracetool interface.
>
> On the other hand, I would like to see where this goes so that we have
> enough experience to design the tracetool interface, if necessary.
>
> Therefore I am for merging this as-is and taking action when it's clear
> that duplication is taking place.

Sounds like we should not yet commit to a stable external interface.

The monitor command is HMP only.  Not a stable interface.  A QMP command
would have to be marked experimental with the customary x- prefix.

The environment variable is an external interface of the recorder
library.  Attempting to police such interfaces of libraries we use seems
futile.