* Emilio G. Cota (c...@braap.org) wrote:
> 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)
> -------------------------------------------------------------------------------
> -------------------------------------------------------------------------------
>
> Signed-off-by: Emilio G. Cota <c...@braap.org>
> ---
> monitor.c | 11 +++++++++++
> hmp-commands-info.hx | 22 ++++++++++++++++++++++
> 2 files changed, 33 insertions(+)
>
> diff --git a/monitor.c b/monitor.c
> index a1999e396c..94f673511b 100644
> --- a/monitor.c
> +++ b/monitor.c
> @@ -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;
> diff --git a/hmp-commands-info.hx b/hmp-commands-info.hx
> index 70639f656a..cbee8b944d 100644
> --- a/hmp-commands-info.hx
> +++ b/hmp-commands-info.hx
> @@ -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
>
> {
Reviewed-by: Dr. David Alan Gilbert <dgilb...@redhat.com>
> --
> 2.17.1
>
--
Dr. David Alan Gilbert / dgilb...@redhat.com / Manchester, UK
