[PATCH v2] tracing/hwlat: Do the latency calculations in nanoseconds

[PATCH v2] tracing/hwlat: Do the latency calculations in nanoseconds

[Wenwu Hou]

tr->max_latency is expected to hold nanoseconds: tracing_max_lat_read()
converts it with nsecs_to_usecs() to print the usecs documented in
hwlat_detector.rst, and the other latency tracers store nanoseconds there
too.

Do all the latency calculations in nanoseconds instead, and only convert
the durations to microseconds when recording the hwlat event.

Fixes: e7c15cd8a1133 ("tracing: Added hardware latency tracer")
Suggested-by: Steven Rostedt <rostedt@goodmis.org>
Signed-off-by: Wenwu Hou <hwenwur@gmail.com>
---
Tested in a 4-vCPU KVM guest; all three hwlat modes worked as expected.

Changes in v2:
- Perform the latency calculations in nanoseconds instead of converting
  only the maximum latency, as suggested by Steven Rostedt.
- Convert the durations to microseconds only when recording the hwlat event
  to preserve the existing event format.

 kernel/trace/trace_hwlat.c | 14 ++++++--------
 1 file changed, 6 insertions(+), 8 deletions(-)

diff --git a/kernel/trace/trace_hwlat.c b/kernel/trace/trace_hwlat.c
index 65e184d800ff1..a16905ac12b0d 100644
--- a/kernel/trace/trace_hwlat.c
+++ b/kernel/trace/trace_hwlat.c
@@ -203,14 +203,12 @@ static int get_sample(void)
 	time_type start, t1, t2, last_t2;
 	s64 diff, outer_diff, total, last_total = 0;
 	u64 sample = 0;
-	u64 sample_width = READ_ONCE(hwlat_data.sample_width);
+	u64 sample_width = READ_ONCE(hwlat_data.sample_width) * NSEC_PER_USEC;
 	u64 thresh = tracing_thresh;
 	u64 outer_sample = 0;
 	int ret = -1;
 	unsigned int count = 0;
 
-	do_div(thresh, NSEC_PER_USEC); /* modifies interval value */
-
 	kdata->nmi_total_ts = 0;
 	kdata->nmi_count = 0;
 	/* Make sure NMIs see this first */
@@ -229,7 +227,7 @@ static int get_sample(void)
 
 		if (time_u64(last_t2)) {
 			/* Check the delta from outer loop (t2 to next t1) */
-			outer_diff = time_to_us(time_sub(t1, last_t2));
+			outer_diff = time_sub(t1, last_t2);
 			/* This shouldn't happen */
 			if (outer_diff < 0) {
 				hwlat_err(BANNER "time running backwards\n");
@@ -240,7 +238,7 @@ static int get_sample(void)
 		}
 		last_t2 = t2;
 
-		total = time_to_us(time_sub(t2, start)); /* sample width */
+		total = time_sub(t2, start); /* sample width */
 
 		/* Check for possible overflows */
 		if (total < last_total) {
@@ -250,7 +248,7 @@ static int get_sample(void)
 		last_total = total;
 
 		/* This checks the inner loop (t1 to t2) */
-		diff = time_to_us(time_sub(t2, t1));     /* current diff */
+		diff = time_sub(t2, t1);     /* current diff */
 
 		if (diff > thresh || outer_diff > thresh) {
 			if (!count)
@@ -286,8 +284,8 @@ static int get_sample(void)
 			do_div(kdata->nmi_total_ts, NSEC_PER_USEC);
 
 		s.seqnum = atomic64_inc_return(&hwlat_data.count);
-		s.duration = sample;
-		s.outer_duration = outer_sample;
+		s.duration = time_to_us(sample);
+		s.outer_duration = time_to_us(outer_sample);
 		s.nmi_total_ts = kdata->nmi_total_ts;
 		s.nmi_count = kdata->nmi_count;
 		s.count = count;
-- 
2.43.0

Re: [PATCH v2] tracing/hwlat: Do the latency calculations in nanoseconds

[sashiko-bot]

Thank you for your contribution! Sashiko AI review found 1 potential
issue to consider:
- [Medium] tracing/hwlat: get_sample() leaves NMI callback enabled on
  goto out path
--

commit b2b5eb31ef0ca8b02c68fc0666337a94df8c67b9
Author: Wenwu Hou <hwenwur@gmail.com>

tracing/hwlat: Do the latency calculations in nanoseconds

This commit changes get_sample() to perform its latency calculations in
nanoseconds so tr->max_latency is stored in nanoseconds, converting the
durations to microseconds only when recording the hwlat event.

> diff --git a/kernel/trace/trace_hwlat.c b/kernel/trace/trace_hwlat.c
> index 3fe274b84f1c2..b230cf14de93e 100644
> --- a/kernel/trace/trace_hwlat.c
> +++ b/kernel/trace/trace_hwlat.c
> @@ -203,14 +203,12 @@ static int get_sample(void)
>  	time_type start, t1, t2, last_t2;
>  	s64 diff, outer_diff, total, last_total = 0;
>  	u64 sample = 0;
> -	u64 sample_width = READ_ONCE(hwlat_data.sample_width);
> +	u64 sample_width = READ_ONCE(hwlat_data.sample_width) * NSEC_PER_USEC;
>  	u64 thresh = tracing_thresh;
>  	u64 outer_sample = 0;
>  	int ret = -1;
>  	unsigned int count = 0;
>  
> -	do_div(thresh, NSEC_PER_USEC); /* modifies interval value */
> -
>  	kdata->nmi_total_ts = 0;
>  	kdata->nmi_count = 0;
>  	/* Make sure NMIs see this first */
> @@ -229,7 +227,7 @@ static int get_sample(void)
>  
>  		if (time_u64(last_t2)) {
>  			/* Check the delta from outer loop (t2 to next t1) */
> -			outer_diff = time_to_us(time_sub(t1, last_t2));
> +			outer_diff = time_sub(t1, last_t2);
>  			/* This shouldn't happen */
>  			if (outer_diff < 0) {
>  				hwlat_err(BANNER "time running backwards\n");
> @@ -240,7 +238,7 @@ static int get_sample(void)
>  		}
>  		last_t2 = t2;
>  
> -		total = time_to_us(time_sub(t2, start)); /* sample width */
> +		total = time_sub(t2, start); /* sample width */
>  
>  		/* Check for possible overflows */
>  		if (total < last_total) {
> @@ -250,7 +248,7 @@ static int get_sample(void)
>  		last_total = total;
>  
>  		/* This checks the inner loop (t1 to t2) */
> -		diff = time_to_us(time_sub(t2, t1));     /* current diff */
> +		diff = time_sub(t2, t1);     /* current diff */

[Severity: Medium]
Can the "goto out" paths when outer_diff < 0 or diff < 0 leave
trace_hwlat_callback_enabled set to true?

Previously, time_to_us() passed the delta through unsigned div_u64(), which
cleared the sign bit and made the negative checks unreachable.  Assigning
time_sub() directly makes those error paths reachable on a backward clock
reading, and jumping to out skips clearing trace_hwlat_callback_enabled:

kernel/trace/trace_hwlat.c:get_sample() {
	...
	trace_hwlat_callback_enabled = true;
	...
	do {
		...
			if (outer_diff < 0) {
				hwlat_err(BANNER "time running backwards\n");
				goto out;
			}
		...
		if (diff < 0) {
			hwlat_err(BANNER "time running backwards\n");
			goto out;
		}
		...
	} while (total <= sample_width);

	barrier(); /* finish the above in the view for NMIs */
	trace_hwlat_callback_enabled = false;
	...
out:
	return ret;
}

Because nothing else resets trace_hwlat_callback_enabled, NMI tracking stays
active while kthread_fn() re-enables interrupts and sleeps, and remains enabled
even after the tracer is stopped if kthread_stop() wakes the thread before
another sample finishes normally.

-- 
Sashiko AI review · https://sashiko.dev/#/patchset/20261112121502.2070755-1-hwenwur@gmail.com?part=1

Re: [PATCH v2] tracing/hwlat: Do the latency calculations in nanoseconds

[Wenwu Hou]

On Thu, Nov 12, 2026 at 12:28:19PM +0000, sashiko-bot@kernel.org wrote:
> Thank you for your contribution! Sashiko AI review found 1 potential
> issue to consider:
> - [Medium] tracing/hwlat: get_sample() leaves NMI callback enabled on
>   goto out path
> --
> 
> commit b2b5eb31ef0ca8b02c68fc0666337a94df8c67b9
> Author: Wenwu Hou <hwenwur@gmail.com>
> 
> tracing/hwlat: Do the latency calculations in nanoseconds
> 
> This commit changes get_sample() to perform its latency calculations in
> nanoseconds so tr->max_latency is stored in nanoseconds, converting the
> durations to microseconds only when recording the hwlat event.
> 
> > diff --git a/kernel/trace/trace_hwlat.c b/kernel/trace/trace_hwlat.c
> > index 3fe274b84f1c2..b230cf14de93e 100644
> > --- a/kernel/trace/trace_hwlat.c
> > +++ b/kernel/trace/trace_hwlat.c
> > @@ -203,14 +203,12 @@ static int get_sample(void)
> >  	time_type start, t1, t2, last_t2;
> >  	s64 diff, outer_diff, total, last_total = 0;
> >  	u64 sample = 0;
> > -	u64 sample_width = READ_ONCE(hwlat_data.sample_width);
> > +	u64 sample_width = READ_ONCE(hwlat_data.sample_width) * NSEC_PER_USEC;
> >  	u64 thresh = tracing_thresh;
> >  	u64 outer_sample = 0;
> >  	int ret = -1;
> >  	unsigned int count = 0;
> >  
> > -	do_div(thresh, NSEC_PER_USEC); /* modifies interval value */
> > -
> >  	kdata->nmi_total_ts = 0;
> >  	kdata->nmi_count = 0;
> >  	/* Make sure NMIs see this first */
> > @@ -229,7 +227,7 @@ static int get_sample(void)
> >  
> >  		if (time_u64(last_t2)) {
> >  			/* Check the delta from outer loop (t2 to next t1) */
> > -			outer_diff = time_to_us(time_sub(t1, last_t2));
> > +			outer_diff = time_sub(t1, last_t2);
> >  			/* This shouldn't happen */
> >  			if (outer_diff < 0) {
> >  				hwlat_err(BANNER "time running backwards\n");
> > @@ -240,7 +238,7 @@ static int get_sample(void)
> >  		}
> >  		last_t2 = t2;
> >  
> > -		total = time_to_us(time_sub(t2, start)); /* sample width */
> > +		total = time_sub(t2, start); /* sample width */
> >  
> >  		/* Check for possible overflows */
> >  		if (total < last_total) {
> > @@ -250,7 +248,7 @@ static int get_sample(void)
> >  		last_total = total;
> >  
> >  		/* This checks the inner loop (t1 to t2) */
> > -		diff = time_to_us(time_sub(t2, t1));     /* current diff */
> > +		diff = time_sub(t2, t1);     /* current diff */
> 
> [Severity: Medium]
> Can the "goto out" paths when outer_diff < 0 or diff < 0 leave
> trace_hwlat_callback_enabled set to true?
> 
> Previously, time_to_us() passed the delta through unsigned div_u64(), which
> cleared the sign bit and made the negative checks unreachable.  Assigning
> time_sub() directly makes those error paths reachable on a backward clock
> reading, and jumping to out skips clearing trace_hwlat_callback_enabled:
> 

will fix in v3


> kernel/trace/trace_hwlat.c:get_sample() {
> 	...
> 	trace_hwlat_callback_enabled = true;
> 	...
> 	do {
> 		...
> 			if (outer_diff < 0) {
> 				hwlat_err(BANNER "time running backwards\n");
> 				goto out;
> 			}
> 		...
> 		if (diff < 0) {
> 			hwlat_err(BANNER "time running backwards\n");
> 			goto out;
> 		}
> 		...
> 	} while (total <= sample_width);
> 
> 	barrier(); /* finish the above in the view for NMIs */
> 	trace_hwlat_callback_enabled = false;
> 	...
> out:
> 	return ret;
> }
> 
> Because nothing else resets trace_hwlat_callback_enabled, NMI tracking stays
> active while kthread_fn() re-enables interrupts and sleeps, and remains enabled
> even after the tracer is stopped if kthread_stop() wakes the thread before
> another sample finishes normally.
> 
> -- 
> Sashiko AI review · https://sashiko.dev/#/patchset/20261112121502.2070755-1-hwenwur@gmail.com?part=1