 31f5a726b5
			
		
	
	
		31f5a726b5
		
	
	
	
	
		
			
			These trace events were very useful to help me to understand and find a reordering issue in vfio, for example: qemu_mutex_lock locked mutex 0x10905ad8 vfio_region_write (0001:03:00.0:region1+0xc0, 0x2020c, 4) qemu_mutex_unlock unlocked mutex 0x10905ad8 qemu_mutex_lock locked mutex 0x10905ad8 vfio_region_write (0001:03:00.0:region1+0xc4, 0xa0000, 4) qemu_mutex_unlock unlocked mutex 0x10905ad8 that also helped me to see the desired result after the fix: qemu_mutex_lock locked mutex 0x10905ad8 vfio_region_write (0001:03:00.0:region1+0xc0, 0x2000c, 4) vfio_region_write (0001:03:00.0:region1+0xc4, 0xb0000, 4) qemu_mutex_unlock unlocked mutex 0x10905ad8 So it could be a good idea to have these traces implemented. It's worth mentioning that they should be surgically enabled during the debugging, otherwise it can flood the trace logs with lock/unlock messages. How to use it: trace-event qemu_mutex_lock on|off trace-event qemu_mutex_unlock on|off or trace-event qemu_mutex* on|off Signed-off-by: Jose Ricardo Ziviani <joserz@linux.vnet.ibm.com> Message-Id: <1493054398-26013-1-git-send-email-joserz@linux.vnet.ibm.com> Reviewed-by: Fam Zheng <famz@redhat.com> [Also handle trylock, cond_wait and win32; trace "unlocked" while still in the critical section, so that "unlocked" always comes before the next "locked" tracepoint. - Paolo] Signed-off-by: Paolo Bonzini <pbonzini@redhat.com>
		
			
				
	
	
		
			62 lines
		
	
	
		
			3.3 KiB
		
	
	
	
		
			Plaintext
		
	
	
	
	
	
			
		
		
	
	
			62 lines
		
	
	
		
			3.3 KiB
		
	
	
	
		
			Plaintext
		
	
	
	
	
	
| # See docs/tracing.txt for syntax documentation.
 | |
| 
 | |
| # util/aio-posix.c
 | |
| run_poll_handlers_begin(void *ctx, int64_t max_ns) "ctx %p max_ns %"PRId64
 | |
| run_poll_handlers_end(void *ctx, bool progress) "ctx %p progress %d"
 | |
| poll_shrink(void *ctx, int64_t old, int64_t new) "ctx %p old %"PRId64" new %"PRId64
 | |
| poll_grow(void *ctx, int64_t old, int64_t new) "ctx %p old %"PRId64" new %"PRId64
 | |
| 
 | |
| # util/async.c
 | |
| aio_co_schedule(void *ctx, void *co) "ctx %p co %p"
 | |
| aio_co_schedule_bh_cb(void *ctx, void *co) "ctx %p co %p"
 | |
| 
 | |
| # util/thread-pool.c
 | |
| thread_pool_submit(void *pool, void *req, void *opaque) "pool %p req %p opaque %p"
 | |
| thread_pool_complete(void *pool, void *req, void *opaque, int ret) "pool %p req %p opaque %p ret %d"
 | |
| thread_pool_cancel(void *req, void *opaque) "req %p opaque %p"
 | |
| 
 | |
| # util/buffer.c
 | |
| buffer_resize(const char *buf, size_t olen, size_t len) "%s: old %zd, new %zd"
 | |
| buffer_move_empty(const char *buf, size_t len, const char *from) "%s: %zd bytes from %s"
 | |
| buffer_move(const char *buf, size_t len, const char *from) "%s: %zd bytes from %s"
 | |
| buffer_free(const char *buf, size_t len) "%s: capacity %zd"
 | |
| 
 | |
| # util/qemu-coroutine.c
 | |
| qemu_aio_coroutine_enter(void *ctx, void *from, void *to, void *opaque) "ctx %p from %p to %p opaque %p"
 | |
| qemu_coroutine_yield(void *from, void *to) "from %p to %p"
 | |
| qemu_coroutine_terminate(void *co) "self %p"
 | |
| 
 | |
| # util/qemu-coroutine-lock.c
 | |
| qemu_co_queue_run_restart(void *co) "co %p"
 | |
| qemu_co_mutex_lock_uncontended(void *mutex, void *self) "mutex %p self %p"
 | |
| qemu_co_mutex_lock_entry(void *mutex, void *self) "mutex %p self %p"
 | |
| 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/oslib-win32.c
 | |
| # util/oslib-posix.c
 | |
| qemu_memalign(size_t alignment, size_t size, void *ptr) "alignment %zu size %zu ptr %p"
 | |
| qemu_anon_ram_alloc(size_t size, void *ptr) "size %zu ptr %p"
 | |
| qemu_vfree(void *ptr) "ptr %p"
 | |
| qemu_anon_ram_free(void *ptr, size_t size) "ptr %p size %zu"
 | |
| 
 | |
| # util/hbitmap.c
 | |
| hbitmap_iter_skip_words(const void *hb, void *hbi, uint64_t pos, unsigned long cur) "hb %p hbi %p pos %"PRId64" cur 0x%lx"
 | |
| hbitmap_reset(void *hb, uint64_t start, uint64_t count, uint64_t sbit, uint64_t ebit) "hb %p items %"PRIu64",%"PRIu64" bits %"PRIu64"..%"PRIu64
 | |
| hbitmap_set(void *hb, uint64_t start, uint64_t count, uint64_t sbit, uint64_t ebit) "hb %p items %"PRIu64",%"PRIu64" bits %"PRIu64"..%"PRIu64
 | |
| 
 | |
| # util/lockcnt.c
 | |
| lockcnt_fast_path_attempt(const void *lockcnt, int expected, int new) "lockcnt %p fast path %d->%d"
 | |
| lockcnt_fast_path_success(const void *lockcnt, int expected, int new) "lockcnt %p fast path %d->%d succeeded"
 | |
| lockcnt_unlock_attempt(const void *lockcnt, int expected, int new) "lockcnt %p unlock %d->%d"
 | |
| lockcnt_unlock_success(const void *lockcnt, int expected, int new) "lockcnt %p unlock %d->%d succeeded"
 | |
| lockcnt_futex_wait_prepare(const void *lockcnt, int expected, int new) "lockcnt %p preparing slow path %d->%d"
 | |
| lockcnt_futex_wait(const void *lockcnt, int val) "lockcnt %p waiting on %d"
 | |
| lockcnt_futex_wait_resume(const void *lockcnt, int new) "lockcnt %p after wait: %d"
 | |
| lockcnt_futex_wake(const void *lockcnt) "lockcnt %p waking up one waiter"
 | |
| 
 | |
| # util/qemu-thread-posix.c
 | |
| qemu_mutex_locked(void *lock) "locked mutex %p"
 | |
| qemu_mutex_unlocked(void *lock) "unlocked mutex %p"
 |