[RFC,v1,8/9] util/qemu-thread-*: add qemu_lock, locked and unlock trace events

Message ID 20170505103822.20641-9-alex.bennee@linaro.org
State New
Headers show
Series
  • BQL and Replay Lock changes
Related show

Commit Message

Alex Bennée May 5, 2017, 10:38 a.m.
Signed-off-by: Alex Bennée <alex.bennee@linaro.org>

---
 include/qemu/thread.h    |  7 +++++--
 util/qemu-thread-posix.c | 11 +++++++++--
 util/trace-events        |  5 +++++
 3 files changed, 19 insertions(+), 4 deletions(-)

-- 
2.11.0

Comments

Paolo Bonzini May 5, 2017, 3:17 p.m. | #1
On 05/05/2017 12:38, Alex Bennée wrote:
> Signed-off-by: Alex Bennée <alex.bennee@linaro.org>


Can you look at the patch I just sent a pull request for?  It only has
locked and unlocked trace events, you can add lock on top.

Paolo

> ---

>  include/qemu/thread.h    |  7 +++++--

>  util/qemu-thread-posix.c | 11 +++++++++--

>  util/trace-events        |  5 +++++

>  3 files changed, 19 insertions(+), 4 deletions(-)

> 

> diff --git a/include/qemu/thread.h b/include/qemu/thread.h

> index 9910f49b3a..ddea4990c0 100644

> --- a/include/qemu/thread.h

> +++ b/include/qemu/thread.h

> @@ -22,9 +22,12 @@ typedef struct QemuThread QemuThread;

>  

>  void qemu_mutex_init(QemuMutex *mutex);

>  void qemu_mutex_destroy(QemuMutex *mutex);

> -void qemu_mutex_lock(QemuMutex *mutex);

>  int qemu_mutex_trylock(QemuMutex *mutex);

> -void qemu_mutex_unlock(QemuMutex *mutex);

> +void qemu_mutex_lock_impl(QemuMutex *mutex, const char *file, const int line);

> +void qemu_mutex_unlock_impl(QemuMutex *mutex, const char *file, const int line);

> +

> +#define qemu_mutex_lock(mutex) qemu_mutex_lock_impl(mutex, __FILE__, __LINE__)

> +#define qemu_mutex_unlock(mutex) qemu_mutex_unlock_impl(mutex, __FILE__, __LINE__)

>  

>  /* Prototypes for other functions are in thread-posix.h/thread-win32.h.  */

>  void qemu_rec_mutex_init(QemuRecMutex *mutex);

> diff --git a/util/qemu-thread-posix.c b/util/qemu-thread-posix.c

> index 73e3a0edf5..9da1c9e756 100644

> --- a/util/qemu-thread-posix.c

> +++ b/util/qemu-thread-posix.c

> @@ -14,6 +14,7 @@

>  #include "qemu/thread.h"

>  #include "qemu/atomic.h"

>  #include "qemu/notify.h"

> +#include "trace.h"

>  

>  static bool name_threads;

>  

> @@ -53,13 +54,17 @@ void qemu_mutex_destroy(QemuMutex *mutex)

>          error_exit(err, __func__);

>  }

>  

> -void qemu_mutex_lock(QemuMutex *mutex)

> +void qemu_mutex_lock_impl(QemuMutex *mutex, const char *file, const int line)

>  {

>      int err;

>  

> +    trace_qemu_mutex_lock(mutex, file, line);

> +

>      err = pthread_mutex_lock(&mutex->lock);

>      if (err)

>          error_exit(err, __func__);

> +

> +    trace_qemu_mutex_locked(mutex, file, line);

>  }

>  

>  int qemu_mutex_trylock(QemuMutex *mutex)

> @@ -67,13 +72,15 @@ int qemu_mutex_trylock(QemuMutex *mutex)

>      return pthread_mutex_trylock(&mutex->lock);

>  }

>  

> -void qemu_mutex_unlock(QemuMutex *mutex)

> +void qemu_mutex_unlock_impl(QemuMutex *mutex, const char *file, const int line)

>  {

>      int err;

>  

>      err = pthread_mutex_unlock(&mutex->lock);

>      if (err)

>          error_exit(err, __func__);

> +

> +    trace_qemu_mutex_unlock(mutex, file, line);

>  }

>  

>  void qemu_rec_mutex_init(QemuRecMutex *mutex)

> diff --git a/util/trace-events b/util/trace-events

> index b44ef4f895..972d7e1786 100644

> --- a/util/trace-events

> +++ b/util/trace-events

> @@ -34,6 +34,11 @@ qemu_co_mutex_lock_return(void *mutex, void *self) "mutex %p self %p"

>  qemu_co_mutex_unlock_entry(void *mutex, void *self) "mutex %p self %p"

>  qemu_co_mutex_unlock_return(void *mutex, void *self) "mutex %p self %p"

>  

> +# util/qemu-thread.c

> +qemu_mutex_lock(void *mutex, const char *file, const int line) "waiting on mutex %p (%s:%d)"

> +qemu_mutex_locked(void *mutex, const char *file, const int line) "taken mutex %p (%s:%d)"

> +qemu_mutex_unlock(void *mutex, const char *file, const int line) "released mutex %p (%s:%d)"

> +

>  # util/oslib-win32.c

>  # util/oslib-posix.c

>  qemu_memalign(size_t alignment, size_t size, void *ptr) "alignment %zu size %zu ptr %p"

>
Alex Bennée May 5, 2017, 3:59 p.m. | #2
Paolo Bonzini <pbonzini@redhat.com> writes:

> On 05/05/2017 12:38, Alex Bennée wrote:

>> Signed-off-by: Alex Bennée <alex.bennee@linaro.org>

>

> Can you look at the patch I just sent a pull request for?  It only has

> locked and unlocked trace events, you can add lock on top.


Cool - great minds think alike ;-)

I'll re-spin my trace analysis script and the lock trace point once that
pull request is merged. I would be nice if we could associate locks with
names though as the QemuMutex * is basically just an anonymous handle.
Would it be overly extravagant to add a const char * to QemuMutex to can
be init'ed with a human readable name?

Stefan,

Does the trace sub-system have any way to register a human readable
string to a given pointer value? I guess this is something that could be
added to the trace pre-amble?

>

> Paolo

>

>> ---

>>  include/qemu/thread.h    |  7 +++++--

>>  util/qemu-thread-posix.c | 11 +++++++++--

>>  util/trace-events        |  5 +++++

>>  3 files changed, 19 insertions(+), 4 deletions(-)

>>

>> diff --git a/include/qemu/thread.h b/include/qemu/thread.h

>> index 9910f49b3a..ddea4990c0 100644

>> --- a/include/qemu/thread.h

>> +++ b/include/qemu/thread.h

>> @@ -22,9 +22,12 @@ typedef struct QemuThread QemuThread;

>>

>>  void qemu_mutex_init(QemuMutex *mutex);

>>  void qemu_mutex_destroy(QemuMutex *mutex);

>> -void qemu_mutex_lock(QemuMutex *mutex);

>>  int qemu_mutex_trylock(QemuMutex *mutex);

>> -void qemu_mutex_unlock(QemuMutex *mutex);

>> +void qemu_mutex_lock_impl(QemuMutex *mutex, const char *file, const int line);

>> +void qemu_mutex_unlock_impl(QemuMutex *mutex, const char *file, const int line);

>> +

>> +#define qemu_mutex_lock(mutex) qemu_mutex_lock_impl(mutex, __FILE__, __LINE__)

>> +#define qemu_mutex_unlock(mutex) qemu_mutex_unlock_impl(mutex, __FILE__, __LINE__)

>>

>>  /* Prototypes for other functions are in thread-posix.h/thread-win32.h.  */

>>  void qemu_rec_mutex_init(QemuRecMutex *mutex);

>> diff --git a/util/qemu-thread-posix.c b/util/qemu-thread-posix.c

>> index 73e3a0edf5..9da1c9e756 100644

>> --- a/util/qemu-thread-posix.c

>> +++ b/util/qemu-thread-posix.c

>> @@ -14,6 +14,7 @@

>>  #include "qemu/thread.h"

>>  #include "qemu/atomic.h"

>>  #include "qemu/notify.h"

>> +#include "trace.h"

>>

>>  static bool name_threads;

>>

>> @@ -53,13 +54,17 @@ void qemu_mutex_destroy(QemuMutex *mutex)

>>          error_exit(err, __func__);

>>  }

>>

>> -void qemu_mutex_lock(QemuMutex *mutex)

>> +void qemu_mutex_lock_impl(QemuMutex *mutex, const char *file, const int line)

>>  {

>>      int err;

>>

>> +    trace_qemu_mutex_lock(mutex, file, line);

>> +

>>      err = pthread_mutex_lock(&mutex->lock);

>>      if (err)

>>          error_exit(err, __func__);

>> +

>> +    trace_qemu_mutex_locked(mutex, file, line);

>>  }

>>

>>  int qemu_mutex_trylock(QemuMutex *mutex)

>> @@ -67,13 +72,15 @@ int qemu_mutex_trylock(QemuMutex *mutex)

>>      return pthread_mutex_trylock(&mutex->lock);

>>  }

>>

>> -void qemu_mutex_unlock(QemuMutex *mutex)

>> +void qemu_mutex_unlock_impl(QemuMutex *mutex, const char *file, const int line)

>>  {

>>      int err;

>>

>>      err = pthread_mutex_unlock(&mutex->lock);

>>      if (err)

>>          error_exit(err, __func__);

>> +

>> +    trace_qemu_mutex_unlock(mutex, file, line);

>>  }

>>

>>  void qemu_rec_mutex_init(QemuRecMutex *mutex)

>> diff --git a/util/trace-events b/util/trace-events

>> index b44ef4f895..972d7e1786 100644

>> --- a/util/trace-events

>> +++ b/util/trace-events

>> @@ -34,6 +34,11 @@ qemu_co_mutex_lock_return(void *mutex, void *self) "mutex %p self %p"

>>  qemu_co_mutex_unlock_entry(void *mutex, void *self) "mutex %p self %p"

>>  qemu_co_mutex_unlock_return(void *mutex, void *self) "mutex %p self %p"

>>

>> +# util/qemu-thread.c

>> +qemu_mutex_lock(void *mutex, const char *file, const int line) "waiting on mutex %p (%s:%d)"

>> +qemu_mutex_locked(void *mutex, const char *file, const int line) "taken mutex %p (%s:%d)"

>> +qemu_mutex_unlock(void *mutex, const char *file, const int line) "released mutex %p (%s:%d)"

>> +

>>  # util/oslib-win32.c

>>  # util/oslib-posix.c

>>  qemu_memalign(size_t alignment, size_t size, void *ptr) "alignment %zu size %zu ptr %p"

>>



--
Alex Bennée
Paolo Bonzini May 6, 2017, 8:19 a.m. | #3
On 05/05/2017 17:59, Alex Bennée wrote:
> I'll re-spin my trace analysis script and the lock trace point once that

> pull request is merged. I would be nice if we could associate locks with

> names though as the QemuMutex * is basically just an anonymous handle.

> Would it be overly extravagant to add a const char * to QemuMutex to can

> be init'ed with a human readable name?


Sure, why not.  But please do make it a constant (as you suggest) so
that qemu_mutex_destroy does not need to g_free.

Paolo
Stefan Hajnoczi May 8, 2017, 5:52 p.m. | #4
On Fri, May 05, 2017 at 04:59:58PM +0100, Alex Bennée wrote:
> 

> Paolo Bonzini <pbonzini@redhat.com> writes:

> 

> > On 05/05/2017 12:38, Alex Bennée wrote:

> >> Signed-off-by: Alex Bennée <alex.bennee@linaro.org>

> >

> > Can you look at the patch I just sent a pull request for?  It only has

> > locked and unlocked trace events, you can add lock on top.

> 

> Cool - great minds think alike ;-)

> 

> I'll re-spin my trace analysis script and the lock trace point once that

> pull request is merged. I would be nice if we could associate locks with

> names though as the QemuMutex * is basically just an anonymous handle.

> Would it be overly extravagant to add a const char * to QemuMutex to can

> be init'ed with a human readable name?

> 

> Stefan,

> 

> Does the trace sub-system have any way to register a human readable

> string to a given pointer value? I guess this is something that could be

> added to the trace pre-amble?


No, it doesn't.  I would make the trace event take const char * and pass
in the string.

Stefan
Alex Bennée May 9, 2017, 1:50 p.m. | #5
Stefan Hajnoczi <stefanha@redhat.com> writes:

> On Fri, May 05, 2017 at 04:59:58PM +0100, Alex Bennée wrote:

>>

>> Paolo Bonzini <pbonzini@redhat.com> writes:

>>

>> > On 05/05/2017 12:38, Alex Bennée wrote:

>> >> Signed-off-by: Alex Bennée <alex.bennee@linaro.org>

>> >

>> > Can you look at the patch I just sent a pull request for?  It only has

>> > locked and unlocked trace events, you can add lock on top.

>>

>> Cool - great minds think alike ;-)

>>

>> I'll re-spin my trace analysis script and the lock trace point once that

>> pull request is merged. I would be nice if we could associate locks with

>> names though as the QemuMutex * is basically just an anonymous handle.

>> Would it be overly extravagant to add a const char * to QemuMutex to can

>> be init'ed with a human readable name?

>>

>> Stefan,

>>

>> Does the trace sub-system have any way to register a human readable

>> string to a given pointer value? I guess this is something that could be

>> added to the trace pre-amble?

>

> No, it doesn't.  I would make the trace event take const char * and pass

> in the string.


It would be nice to avoid having the string for non-trace builds. I was
thinking of something like:

  trace_register_human_name(void *ptr, const char *name)

Which compiles away to nothing when tracing is not enabled.

>

> Stefan



--
Alex Bennée
Paolo Bonzini May 9, 2017, 1:55 p.m. | #6
On 09/05/2017 15:50, Alex Bennée wrote:
>> No, it doesn't.  I would make the trace event take const char * and pass

>> in the string.

> It would be nice to avoid having the string for non-trace builds.


It can help with gdb as well (e.g. having gdb printers that print the
name of a mutex), and it shouldn't be a burden.

Paolo

> I was

> thinking of something like:

> 

>   trace_register_human_name(void *ptr, const char *name)

> 

> Which compiles away to nothing when tracing is not enabled.

>

Patch hide | download patch | download mbox

diff --git a/include/qemu/thread.h b/include/qemu/thread.h
index 9910f49b3a..ddea4990c0 100644
--- a/include/qemu/thread.h
+++ b/include/qemu/thread.h
@@ -22,9 +22,12 @@  typedef struct QemuThread QemuThread;
 
 void qemu_mutex_init(QemuMutex *mutex);
 void qemu_mutex_destroy(QemuMutex *mutex);
-void qemu_mutex_lock(QemuMutex *mutex);
 int qemu_mutex_trylock(QemuMutex *mutex);
-void qemu_mutex_unlock(QemuMutex *mutex);
+void qemu_mutex_lock_impl(QemuMutex *mutex, const char *file, const int line);
+void qemu_mutex_unlock_impl(QemuMutex *mutex, const char *file, const int line);
+
+#define qemu_mutex_lock(mutex) qemu_mutex_lock_impl(mutex, __FILE__, __LINE__)
+#define qemu_mutex_unlock(mutex) qemu_mutex_unlock_impl(mutex, __FILE__, __LINE__)
 
 /* Prototypes for other functions are in thread-posix.h/thread-win32.h.  */
 void qemu_rec_mutex_init(QemuRecMutex *mutex);
diff --git a/util/qemu-thread-posix.c b/util/qemu-thread-posix.c
index 73e3a0edf5..9da1c9e756 100644
--- a/util/qemu-thread-posix.c
+++ b/util/qemu-thread-posix.c
@@ -14,6 +14,7 @@ 
 #include "qemu/thread.h"
 #include "qemu/atomic.h"
 #include "qemu/notify.h"
+#include "trace.h"
 
 static bool name_threads;
 
@@ -53,13 +54,17 @@  void qemu_mutex_destroy(QemuMutex *mutex)
         error_exit(err, __func__);
 }
 
-void qemu_mutex_lock(QemuMutex *mutex)
+void qemu_mutex_lock_impl(QemuMutex *mutex, const char *file, const int line)
 {
     int err;
 
+    trace_qemu_mutex_lock(mutex, file, line);
+
     err = pthread_mutex_lock(&mutex->lock);
     if (err)
         error_exit(err, __func__);
+
+    trace_qemu_mutex_locked(mutex, file, line);
 }
 
 int qemu_mutex_trylock(QemuMutex *mutex)
@@ -67,13 +72,15 @@  int qemu_mutex_trylock(QemuMutex *mutex)
     return pthread_mutex_trylock(&mutex->lock);
 }
 
-void qemu_mutex_unlock(QemuMutex *mutex)
+void qemu_mutex_unlock_impl(QemuMutex *mutex, const char *file, const int line)
 {
     int err;
 
     err = pthread_mutex_unlock(&mutex->lock);
     if (err)
         error_exit(err, __func__);
+
+    trace_qemu_mutex_unlock(mutex, file, line);
 }
 
 void qemu_rec_mutex_init(QemuRecMutex *mutex)
diff --git a/util/trace-events b/util/trace-events
index b44ef4f895..972d7e1786 100644
--- a/util/trace-events
+++ b/util/trace-events
@@ -34,6 +34,11 @@  qemu_co_mutex_lock_return(void *mutex, void *self) "mutex %p self %p"
 qemu_co_mutex_unlock_entry(void *mutex, void *self) "mutex %p self %p"
 qemu_co_mutex_unlock_return(void *mutex, void *self) "mutex %p self %p"
 
+# util/qemu-thread.c
+qemu_mutex_lock(void *mutex, const char *file, const int line) "waiting on mutex %p (%s:%d)"
+qemu_mutex_locked(void *mutex, const char *file, const int line) "taken mutex %p (%s:%d)"
+qemu_mutex_unlock(void *mutex, const char *file, const int line) "released mutex %p (%s:%d)"
+
 # util/oslib-win32.c
 # util/oslib-posix.c
 qemu_memalign(size_t alignment, size_t size, void *ptr) "alignment %zu size %zu ptr %p"