[Qemu-devel] [PATCHv1 0/4] Timers: add timer debugging through -timer-debug-log

[Alex Bligh]

This patch set adds facilities for debugging timers using the additional
command line option -timer-debug-log=FILE. If this option is selected,
a debugging file will be written showing information about the current
state of timers in the system, which the author feels will be useful for
debugging in the field.

Note that the option is a command line option rather than a configure
time option. This is because users in the field having issues are unlikely
to have a compile time option enabled.

It would be useful to get this feature in prior to 1.7 as it has little
impact other than making a major change to a subsystem more debuggable.
This patch has been lightly test.

Impact of changes whether or not -timer-debug-log is specified:

1. QEMUTimer is expanded to hold additional debugging information. Some
   of this is unused when the command line option is unspecified.

2. The file and line number of the caller that allocated the timer are
   recorded. This is useful for debugging in gdb.

It is felt these are minimal in nature.

Additional impact of changes only when -timer-debug-log is specified:

1. On every timer modification, the current clock time for that timer
   is read, and the additional debug information filled in.

2. Every second (roughly) a file is written (atomically) containing the
   timer debug information.

The debug information includes information on the number of timer
expiries since the timer was created, the average expiry time (in
nanoseconds), and the number of short expiries, being the number of
times the timer was asked to expire in less than one microsecond
(these usually but not always indicate a bug).

The file format is designed to be useful both to a mailing list and
to a user armed with gdb. An example of the output follows:

Timer list at 0x7f4d6cf0d6e0 clock 0:
           Address       Expiries      AvgLength       NumShort Source

Timer list at 0x7f4d6cf0cbc0 clock 0:
           Address       Expiries      AvgLength       NumShort Source

Timer list at 0x7f4d6cf0d750 clock 1:
           Address       Expiries      AvgLength       NumShort Source

Timer list at 0x7f4d6cf0cc30 clock 1:
           Address       Expiries      AvgLength       NumShort Source
    0x7f4d6cf51550              1       27462700              0 i8254.c:333

Timer list at 0x7f4d6cf0d7c0 clock 2:
           Address       Expiries      AvgLength       NumShort Source

Timer list at 0x7f4d6cf0cca0 clock 2:
           Address       Expiries      AvgLength       NumShort Source
    0x7f4d6cf6eed0              1      999997000              0 
mc146818rtc.c:858

Note that the somewhat strange choice to output to a file has been taken
because the tracing infrastructure is unlikely to be enabled in a distro
environment.

Alex Bligh (4):
  Timers: add debugging macros wrapping timer functions and debug
    structures
  Timers: add command line option -timer-debug-log
  Timers: Instrument timer_mod
  Timers: produce timer-debug-log file

 include/block/aio.h  |   20 ++++++---
 include/qemu/timer.h |   70 ++++++++++++++++++++++--------
 qemu-options.hx      |   11 +++++
 qemu-timer.c         |  118 ++++++++++++++++++++++++++++++++++++++++++++++++--
 vl.c                 |    3 ++
 5 files changed, 194 insertions(+), 28 deletions(-)

-- 
1.7.9.5