1. Patchew
  2. linux
  3. View series

[PATCH] perf sched timehist: Fixed timestamp error when unable to confirm event sched_in time

Yang Jihong posted 1 patch 1 year, 6 months ago
There is a newer version of this series
tools/perf/builtin-sched.c | 5 ++++-
1 file changed, 4 insertions(+), 1 deletion(-)
[PATCH] perf sched timehist: Fixed timestamp error when unable to confirm event sched_in time
Posted by Yang Jihong 1 year, 6 months ago 
If sched_in event for current task is not recorded, sched_in timestamp
will be set to end_time of time window interest, causing an error in
timestamp show. In this case, we choose to ignore this event.

Test scenario:
  perf[1229608] does not record the first sched_in event, run time and sch delay are both 0

  # perf sched timehist
  Samples of sched_switch event do not have callchains.
             time    cpu  task name                       wait time  sch delay   run time
                          [tid/pid]                          (msec)     (msec)     (msec)
  --------------- ------  ------------------------------  ---------  ---------  ---------
   2090450.763231 [0000]  perf[1229608]                       0.000      0.000      0.000
   2090450.763235 [0000]  migration/0[15]                     0.000      0.001      0.003
   2090450.763263 [0001]  perf[1229608]                       0.000      0.000      0.000
   2090450.763268 [0001]  migration/1[21]                     0.000      0.001      0.004
   2090450.763302 [0002]  perf[1229608]                       0.000      0.000      0.000
   2090450.763309 [0002]  migration/2[27]                     0.000      0.001      0.007
   2090450.763338 [0003]  perf[1229608]                       0.000      0.000      0.000
   2090450.763343 [0003]  migration/3[33]                     0.000      0.001      0.004

Before:
  arbitrarily specify a time window of interest, timestamp will be set to an incorrect value

  # perf sched timehist --time 100,200
  Samples of sched_switch event do not have callchains.
             time    cpu  task name                       wait time  sch delay   run time
                          [tid/pid]                          (msec)     (msec)     (msec)
  --------------- ------  ------------------------------  ---------  ---------  ---------
       200.000000 [0000]  perf[1229608]                       0.000      0.000      0.000
       200.000000 [0001]  perf[1229608]                       0.000      0.000      0.000
       200.000000 [0002]  perf[1229608]                       0.000      0.000      0.000
       200.000000 [0003]  perf[1229608]                       0.000      0.000      0.000
       200.000000 [0004]  perf[1229608]                       0.000      0.000      0.000
       200.000000 [0005]  perf[1229608]                       0.000      0.000      0.000
       200.000000 [0006]  perf[1229608]                       0.000      0.000      0.000
       200.000000 [0007]  perf[1229608]                       0.000      0.000      0.000

 After:

  # perf sched timehist --time 100,200
  Samples of sched_switch event do not have callchains.
             time    cpu  task name                       wait time  sch delay   run time
                          [tid/pid]                          (msec)     (msec)     (msec)
  --------------- ------  ------------------------------  ---------  ---------  ---------

Fixes: 853b74071110 ("perf sched timehist: Add option to specify time window of interest")
Signed-off-by: Yang Jihong <yangjihong@bytedance.com>
---
 tools/perf/builtin-sched.c | 5 ++++-
 1 file changed, 4 insertions(+), 1 deletion(-)

diff --git a/tools/perf/builtin-sched.c b/tools/perf/builtin-sched.c
index 8750b5f2d49b..92b1113b22ad 100644
--- a/tools/perf/builtin-sched.c
+++ b/tools/perf/builtin-sched.c
@@ -2683,9 +2683,12 @@ static int timehist_sched_change_event(struct perf_tool *tool,
 	 * - previous sched event is out of window - we are done
 	 * - sample time is beyond window user cares about - reset it
 	 *   to close out stats for time window interest
+	 * - If tprev is 0, that is, sched_in event for current task is
+	 *   not recorded, cannot determine whether sched_in event is
+	 *   within time window interest - ignore it
 	 */
 	if (ptime->end) {
-		if (tprev > ptime->end)
+		if (!tprev || (tprev && tprev > ptime->end))
 			goto out;
 
 		if (t > ptime->end)
-- 
2.25.1
Re: [PATCH] perf sched timehist: Fixed timestamp error when unable to confirm event sched_in time
Posted by Namhyung Kim 1 year, 5 months ago 
On Tue, Aug 06, 2024 at 11:43:57AM +0800, Yang Jihong wrote:
> If sched_in event for current task is not recorded, sched_in timestamp
> will be set to end_time of time window interest, causing an error in
> timestamp show. In this case, we choose to ignore this event.
> 
> Test scenario:
>   perf[1229608] does not record the first sched_in event, run time and sch delay are both 0
> 
>   # perf sched timehist
>   Samples of sched_switch event do not have callchains.
>              time    cpu  task name                       wait time  sch delay   run time
>                           [tid/pid]                          (msec)     (msec)     (msec)
>   --------------- ------  ------------------------------  ---------  ---------  ---------
>    2090450.763231 [0000]  perf[1229608]                       0.000      0.000      0.000
>    2090450.763235 [0000]  migration/0[15]                     0.000      0.001      0.003
>    2090450.763263 [0001]  perf[1229608]                       0.000      0.000      0.000
>    2090450.763268 [0001]  migration/1[21]                     0.000      0.001      0.004
>    2090450.763302 [0002]  perf[1229608]                       0.000      0.000      0.000
>    2090450.763309 [0002]  migration/2[27]                     0.000      0.001      0.007
>    2090450.763338 [0003]  perf[1229608]                       0.000      0.000      0.000
>    2090450.763343 [0003]  migration/3[33]                     0.000      0.001      0.004
> 
> Before:
>   arbitrarily specify a time window of interest, timestamp will be set to an incorrect value
> 
>   # perf sched timehist --time 100,200
>   Samples of sched_switch event do not have callchains.
>              time    cpu  task name                       wait time  sch delay   run time
>                           [tid/pid]                          (msec)     (msec)     (msec)
>   --------------- ------  ------------------------------  ---------  ---------  ---------
>        200.000000 [0000]  perf[1229608]                       0.000      0.000      0.000
>        200.000000 [0001]  perf[1229608]                       0.000      0.000      0.000
>        200.000000 [0002]  perf[1229608]                       0.000      0.000      0.000
>        200.000000 [0003]  perf[1229608]                       0.000      0.000      0.000
>        200.000000 [0004]  perf[1229608]                       0.000      0.000      0.000
>        200.000000 [0005]  perf[1229608]                       0.000      0.000      0.000
>        200.000000 [0006]  perf[1229608]                       0.000      0.000      0.000
>        200.000000 [0007]  perf[1229608]                       0.000      0.000      0.000
> 
>  After:
> 
>   # perf sched timehist --time 100,200
>   Samples of sched_switch event do not have callchains.
>              time    cpu  task name                       wait time  sch delay   run time
>                           [tid/pid]                          (msec)     (msec)     (msec)
>   --------------- ------  ------------------------------  ---------  ---------  ---------
> 
> Fixes: 853b74071110 ("perf sched timehist: Add option to specify time window of interest")
> Signed-off-by: Yang Jihong <yangjihong@bytedance.com>
> ---
>  tools/perf/builtin-sched.c | 5 ++++-
>  1 file changed, 4 insertions(+), 1 deletion(-)
> 
> diff --git a/tools/perf/builtin-sched.c b/tools/perf/builtin-sched.c
> index 8750b5f2d49b..92b1113b22ad 100644
> --- a/tools/perf/builtin-sched.c
> +++ b/tools/perf/builtin-sched.c
> @@ -2683,9 +2683,12 @@ static int timehist_sched_change_event(struct perf_tool *tool,
>  	 * - previous sched event is out of window - we are done
>  	 * - sample time is beyond window user cares about - reset it
>  	 *   to close out stats for time window interest
> +	 * - If tprev is 0, that is, sched_in event for current task is
> +	 *   not recorded, cannot determine whether sched_in event is
> +	 *   within time window interest - ignore it
>  	 */
>  	if (ptime->end) {
> -		if (tprev > ptime->end)
> +		if (!tprev || (tprev && tprev > ptime->end))

This can be 'if (!tprev || tprev > ptime->end)'

Thanks,
Namhyung


>  			goto out;
>  
>  		if (t > ptime->end)
> -- 
> 2.25.1
>

Patchew 2.1-devel-b67e4c2

© 2016 - 2026 Red Hat, Inc.