hmp-commands-info: add sync-profile

The command introduced here is just for developers. This means that:

- the info displayed and the output format could change in the future
- the command is only meant to be used from HMP, not from QMP

Sample output:

(qemu) sync-profile
sync-profile is off
(qemu) info sync-profile
Type               Object  Call site  Wait Time (s)         Count  Average (us)
-------------------------------------------------------------------------------
-------------------------------------------------------------------------------
(qemu) sync-profile on
(qemu) sync-profile
sync-profile is on
(qemu) info sync-profile 15
Type               Object  Call site                 Wait Time (s)         Count  Average (us)
----------------------------------------------------------------------------------------------
condvar    0x55a01813ced0  cpus.c:1165                    91.38235          2842      32154.24
BQL mutex  0x55a0171b7140  cpus.c:1434                    12.56490          5787       2171.23
BQL mutex  0x55a0171b7140  accel/tcg/cpu-exec.c:432        7.75846          2844       2728.01
BQL mutex  0x55a0171b7140  accel/tcg/cputlb.c:870          5.09889          2884       1767.99
BQL mutex  0x55a0171b7140  accel/tcg/cpu-exec.c:529        3.46140          3254       1063.74
BQL mutex  0x55a0171b7140  accel/tcg/cputlb.c:804          0.76333          8655         88.20
BQL mutex  0x55a0171b7140  cpus.c:1466                     0.60893          2941        207.05
BQL mutex  0x55a0171b7140  util/main-loop.c:236            0.00894          6425          1.39
mutex      [           3]  util/qemu-timer.c:520           0.00342         50611          0.07
mutex      [           2]  util/qemu-timer.c:426           0.00254         31336          0.08
mutex      [           3]  util/qemu-timer.c:234           0.00107         19275          0.06
mutex      0x55a0171d9960  vl.c:763                        0.00043          6425          0.07
mutex      0x55a0180d1bb0  monitor.c:458                   0.00015          1603          0.09
mutex      0x55a0180e4c78  chardev/char.c:109              0.00002           217          0.08
mutex      0x55a0180d1bb0  monitor.c:448                   0.00001           162          0.08
----------------------------------------------------------------------------------------------
(qemu) info sync-profile -m 15
Type               Object  Call site                 Wait Time (s)         Count  Average (us)
----------------------------------------------------------------------------------------------
condvar    0x55a01813ced0  cpus.c:1165                    95.11196          3051      31174.03
BQL mutex  0x55a0171b7140  accel/tcg/cpu-exec.c:432        7.92108          3052       2595.37
BQL mutex  0x55a0171b7140  cpus.c:1434                    13.38253          6210       2155.00
BQL mutex  0x55a0171b7140  accel/tcg/cputlb.c:870          5.09901          3093       1648.57
BQL mutex  0x55a0171b7140  accel/tcg/cpu-exec.c:529        4.21123          3468       1214.31
BQL mutex  0x55a0171b7140  cpus.c:1466                     0.60895          3156        192.95
BQL mutex  0x55a0171b7140  accel/tcg/cputlb.c:804          0.76337          9282         82.24
BQL mutex  0x55a0171b7140  util/main-loop.c:236            0.00944          6889          1.37
mutex      0x55a01813ce80  tcg/tcg.c:397                   0.00000            24          0.15
mutex      0x55a0180d1bb0  monitor.c:458                   0.00018          1922          0.09
mutex      [           2]  util/qemu-timer.c:426           0.00266         32710          0.08
mutex      0x55a0180e4c78  chardev/char.c:109              0.00002           260          0.08
mutex      0x55a0180d1bb0  monitor.c:448                   0.00001           187          0.08
mutex      0x55a0171d9960  vl.c:763                        0.00047          6889          0.07
mutex      [           3]  util/qemu-timer.c:520           0.00362         53377          0.07
----------------------------------------------------------------------------------------------
(qemu) info sync-profile -m -n 15
Type               Object  Call site                 Wait Time (s)         Count  Average (us)
----------------------------------------------------------------------------------------------
condvar    0x55a01813ced0  cpus.c:1165                   101.39331          3398      29839.12
BQL mutex  0x55a0171b7140  accel/tcg/cpu-exec.c:432        7.92112          3399       2330.43
BQL mutex  0x55a0171b7140  cpus.c:1434                    14.28280          6922       2063.39
BQL mutex  0x55a0171b7140  accel/tcg/cputlb.c:870          5.77505          3445       1676.36
BQL mutex  0x55a0171b7140  accel/tcg/cpu-exec.c:529        5.66139          3883       1457.99
BQL mutex  0x55a0171b7140  cpus.c:1466                     0.60901          3519        173.06
BQL mutex  0x55a0171b7140  accel/tcg/cputlb.c:804          0.76351         10338         73.85
BQL mutex  0x55a0171b7140  util/main-loop.c:236            0.01032          7664          1.35
mutex      0x55a0180e4f08  util/qemu-timer.c:426           0.00041           901          0.45
mutex      0x55a01813ce80  tcg/tcg.c:397                   0.00000            24          0.15
mutex      0x55a0180d1bb0  monitor.c:458                   0.00022          2319          0.09
mutex      0x55a0180e4c78  chardev/char.c:109              0.00003           306          0.08
mutex      0x55a0180e4f08  util/qemu-timer.c:520           0.00068          8565          0.08
mutex      0x55a0180d1bb0  monitor.c:448                   0.00002           215          0.08
mutex      0x55a0180e4f78  util/qemu-timer.c:426           0.00247         34224          0.07
----------------------------------------------------------------------------------------------
(qemu) sync-profile reset
(qemu) info sync-profile -m 2
Type               Object  Call site               Wait Time (s)         Count  Average (us)
--------------------------------------------------------------------------------------------
condvar    0x55a01813ced0  cpus.c:1165                   2.78756            99      28157.12
BQL mutex  0x55a0171b7140  accel/tcg/cputlb.c:870        0.33054           102       3240.55
--------------------------------------------------------------------------------------------
(qemu) sync-profile off
(qemu) sync-profile
sync-profile is off
(qemu) sync-profile reset
(qemu) info sync-profile
Type               Object  Call site  Wait Time (s)         Count  Average (us)
-------------------------------------------------------------------------------
-------------------------------------------------------------------------------

Reviewed-by: Dr. David Alan Gilbert <dgilbert@redhat.com>
Signed-off-by: Emilio G. Cota <cota@braap.org>
Signed-off-by: Paolo Bonzini <pbonzini@redhat.com>
This commit is contained in:
Emilio G. Cota 2017-08-08 13:54:42 -04:00 committed by Paolo Bonzini
parent dd12e1bbf2
commit 97bfafe28a
2 changed files with 33 additions and 0 deletions

View File

@ -297,6 +297,28 @@ STEXI
@item info opcount
@findex info opcount
Show dynamic compiler opcode counters
ETEXI
{
.name = "sync-profile",
.args_type = "mean:-m,no_coalesce:-n,max:i?",
.params = "[-m] [-n] [max]",
.help = "show synchronization profiling info, up to max entries "
"(default: 10), sorted by total wait time. (-m: sort by "
"mean wait time; -n: do not coalesce objects with the "
"same call site)",
.cmd = hmp_info_sync_profile,
},
STEXI
@item info sync-profile [-m|-n] [@var{max}]
@findex info sync-profile
Show synchronization profiling info, up to @var{max} entries (default: 10),
sorted by total wait time.
-m: sort by mean wait time
-n: do not coalesce objects with the same call site
When different objects that share the same call site are coalesced, the "Object"
field shows---enclosed in brackets---the number of objects being coalesced.
ETEXI
{

View File

@ -1454,6 +1454,17 @@ static void hmp_info_opcount(Monitor *mon, const QDict *qdict)
}
#endif
static void hmp_info_sync_profile(Monitor *mon, const QDict *qdict)
{
int64_t max = qdict_get_try_int(qdict, "max", 10);
bool mean = qdict_get_try_bool(qdict, "mean", false);
bool coalesce = !qdict_get_try_bool(qdict, "no_coalesce", false);
enum QSPSortBy sort_by;
sort_by = mean ? QSP_SORT_BY_AVG_WAIT_TIME : QSP_SORT_BY_TOTAL_WAIT_TIME;
qsp_report((FILE *)mon, monitor_fprintf, max, sort_by, coalesce);
}
static void hmp_info_history(Monitor *mon, const QDict *qdict)
{
int i;