Message-ID: <20250825045711.7f4ed42f@pumpkin>
Date: Mon, 25 Aug 2025 04:57:11 +0100
From: David Laight <david.laight.linux@...il.com>
To: Antoine Gagniere <antoine@...niere.dev>
Cc: jonathan.lemon@...il.com, vadim.fedorenko@...ux.dev,
 netdev@...r.kernel.org
Subject: Re: [PATCH] ptp: ocp: Fix PCI delay estimation

On Mon, 18 Aug 2025 00:29:33 +0200
Antoine Gagniere <antoine@...niere.dev> wrote:

> Since linux 6.12, a sign error causes the initial value of ts_window_adjust, (used in gettimex64) to be impossibly high, causing consumers like chrony to reject readings from PTP_SYS_OFFSET_EXTENDED.
> 
> This patch fixes ts_window_adjust's inital value and the sign-ness of various format flags
> 
> Context
> -------
> 
> The value stored in the read-write attribute ts_window_adjust is a number of nanoseconds subtracted to the post_ts timestamp of the reading in gettimex64, used notably in the ioctl PTP_SYS_OFFSET_EXTENDED, to compensate for PCI delay.
> Its initial value is set by estimating PCI delay.
> 
> Bug
> ---
> 
> The PCI delay estimation starts with the value U64_MAX and makes 3 measurements, taking the minimum value.
> However because the delay was stored in a s64, U64_MAX was interpreted as -1, which compared as smaller than any positive values measured.
> Then, that delay is divided by ~10 and placed in ts_window_adjust, which is a u32.
> So ts_window_adjust ends up with (u32)(((s64)U64_MAX >> 5) * 3) inside, which is 4294967293
> 
> Symptom
> -------
> 
> The consequence was that the post_ts of gettimex64, returned by PTP_SYS_OFFSET_EXTENDED, was substracted 4.29 seconds.
> As a consequence chrony rejected all readings from the PHC
> 
> Difficulty to diagnose
> ----------------------
> 
> Using cat to read the attribute value showed -3 because the format flags %d was used instead of %u, resulting in a re-interpret cast.
> 
> Fixes
> -----
> 
> 1. Using U32_MAX as initial value for PCI delays: no one is expecting an ioread to take more than 4 s
>    This will correctly compare as bigger that actual PCI delay measurements.
> 2. Fixing the sign of various format flags
> 
> Signed-off-by: Antoine Gagniere <antoine@...niere.dev>
> ---
>  drivers/ptp/ptp_ocp.c | 32 +++++++++++++++++---------------
>  1 file changed, 17 insertions(+), 15 deletions(-)
> 
> diff --git a/drivers/ptp/ptp_ocp.c b/drivers/ptp/ptp_ocp.c
> index b651087f426f..153827722a63 100644
> --- a/drivers/ptp/ptp_ocp.c
> +++ b/drivers/ptp/ptp_ocp.c
> @@ -1558,7 +1558,8 @@ ptp_ocp_watchdog(struct timer_list *t)
>  static void
>  ptp_ocp_estimate_pci_timing(struct ptp_ocp *bp)
>  {
> -	ktime_t start, end, delay = U64_MAX;
> +	ktime_t start, end;
> +	s64 delay_ns = U32_MAX; /* 4.29 seconds is high enough */

Isn't this the only change that matters?
Changing from ktime_get_raw_ns() to ktime_get_raw() is pointless.
Both are 64 bit and are not going to wrap.
(This is ignoring the fact that I think they are always identical.)

>  	u32 ctrl;
>  	int i;
>  
> @@ -1568,15 +1569,16 @@ ptp_ocp_estimate_pci_timing(struct ptp_ocp *bp)
>  
>  		iowrite32(ctrl, &bp->reg->ctrl);
>  
> -		start = ktime_get_raw_ns();
> +		start = ktime_get_raw();
>  
>  		ctrl = ioread32(&bp->reg->ctrl);
>  
> -		end = ktime_get_raw_ns();
> +		end = ktime_get_raw();
>  
> -		delay = min(delay, end - start);
> +		delay_ns = min(delay_ns, ktime_to_ns(end - start));
>  	}
> -	bp->ts_window_adjust = (delay >> 5) * 3;
> +	delay_ns = max(0, delay_ns);
> +	bp->ts_window_adjust = (delay_ns >> 5) * 3;
>  }
>  
>  static int
> @@ -1894,7 +1896,7 @@ ptp_ocp_devlink_info_get(struct devlink *devlink, struct devlink_info_req *req,
>  	int err;
>  
>  	fw_image = bp->fw_loader ? "loader" : "fw";
> -	sprintf(buf, "%d.%d", bp->fw_tag, bp->fw_version);
> +	sprintf(buf, "%hhu.%hu", bp->fw_tag, bp->fw_version);

WTF is %hhu about?
The varargs parameters are subject to integer promotion, %d or %u is fine.

>  	err = devlink_info_version_running_put(req, fw_image, buf);
>  	if (err)
>  		return err;
> @@ -3196,7 +3198,7 @@ signal_show(struct device *dev, struct device_attribute *attr, char *buf)
>  	i = (uintptr_t)ea->var;
>  	signal = &bp->signal[i];
>  
> -	count = sysfs_emit(buf, "%llu %d %llu %d", signal->period,
> +	count = sysfs_emit(buf, "%lli %d %lli %d", signal->period,

Use %lld not %lli (and below).

	David


>  			   signal->duty, signal->phase, signal->polarity);
>  
>  	ts = ktime_to_timespec64(signal->start);
> @@ -3230,7 +3232,7 @@ period_show(struct device *dev, struct device_attribute *attr, char *buf)
>  	struct ptp_ocp *bp = dev_get_drvdata(dev);
>  	int i = (uintptr_t)ea->var;
>  
> -	return sysfs_emit(buf, "%llu\n", bp->signal[i].period);
> +	return sysfs_emit(buf, "%lli\n", bp->signal[i].period);
>  }
>  static EXT_ATTR_RO(signal, period, 0);
>  static EXT_ATTR_RO(signal, period, 1);
> @@ -3244,7 +3246,7 @@ phase_show(struct device *dev, struct device_attribute *attr, char *buf)
>  	struct ptp_ocp *bp = dev_get_drvdata(dev);
>  	int i = (uintptr_t)ea->var;
>  
> -	return sysfs_emit(buf, "%llu\n", bp->signal[i].phase);
> +	return sysfs_emit(buf, "%lli\n", bp->signal[i].phase);
>  }
>  static EXT_ATTR_RO(signal, phase, 0);
>  static EXT_ATTR_RO(signal, phase, 1);
> @@ -3289,7 +3291,7 @@ start_show(struct device *dev, struct device_attribute *attr, char *buf)
>  	struct timespec64 ts;
>  
>  	ts = ktime_to_timespec64(bp->signal[i].start);
> -	return sysfs_emit(buf, "%llu.%lu\n", ts.tv_sec, ts.tv_nsec);
> +	return sysfs_emit(buf, "%lli.%li\n", ts.tv_sec, ts.tv_nsec);
>  }
>  static EXT_ATTR_RO(signal, start, 0);
>  static EXT_ATTR_RO(signal, start, 1);
> @@ -3444,7 +3446,7 @@ utc_tai_offset_show(struct device *dev,
>  {
>  	struct ptp_ocp *bp = dev_get_drvdata(dev);
>  
> -	return sysfs_emit(buf, "%d\n", bp->utc_tai_offset);
> +	return sysfs_emit(buf, "%u\n", bp->utc_tai_offset);
>  }
>  
>  static ssize_t
> @@ -3472,7 +3474,7 @@ ts_window_adjust_show(struct device *dev,
>  {
>  	struct ptp_ocp *bp = dev_get_drvdata(dev);
>  
> -	return sysfs_emit(buf, "%d\n", bp->ts_window_adjust);
> +	return sysfs_emit(buf, "%u\n", bp->ts_window_adjust);
>  }
>  
>  static ssize_t
> @@ -3964,7 +3966,7 @@ _signal_summary_show(struct seq_file *s, struct ptp_ocp *bp, int nr)
>  
>  	on = signal->running;
>  	sprintf(label, "GEN%d", nr + 1);
> -	seq_printf(s, "%7s: %s, period:%llu duty:%d%% phase:%llu pol:%d",
> +	seq_printf(s, "%7s: %s, period:%lli duty:%d%% phase:%lli pol:%d",
>  		   label, on ? " ON" : "OFF",
>  		   signal->period, signal->duty, signal->phase,
>  		   signal->polarity);
> @@ -3974,7 +3976,7 @@ _signal_summary_show(struct seq_file *s, struct ptp_ocp *bp, int nr)
>  	val = ioread32(&reg->status);
>  	seq_printf(s, " %x]", val);
>  
> -	seq_printf(s, " start:%llu\n", signal->start);
> +	seq_printf(s, " start:%lli\n", signal->start);
>  }
>  
>  static void
> @@ -4231,7 +4233,7 @@ ptp_ocp_summary_show(struct seq_file *s, void *data)
>  
>  		seq_printf(s, "%7s: %lld.%ld == %ptT TAI\n", "PHC",
>  			   ts.tv_sec, ts.tv_nsec, &ts);
> -		seq_printf(s, "%7s: %lld.%ld == %ptT UTC offset %d\n", "SYS",
> +		seq_printf(s, "%7s: %lld.%ld == %ptT UTC offset %u\n", "SYS",
>  			   sys_ts.tv_sec, sys_ts.tv_nsec, &sys_ts,
>  			   bp->utc_tai_offset);
>  		seq_printf(s, "%7s: PHC:SYS offset: %lld  window: %lld\n", "",

Powered by blists - more mailing lists