Use %ptSp instead of open coded variants to print content of
struct timespec64 in human readable format.
Reviewed-by: Martin K. Petersen <martin.petersen@oracle.com>
Signed-off-by: Andy Shevchenko <andriy.shevchenko@linux.intel.com>
---
drivers/scsi/fnic/fnic_trace.c | 52 ++++++++++++++--------------------
1 file changed, 22 insertions(+), 30 deletions(-)
diff --git a/drivers/scsi/fnic/fnic_trace.c b/drivers/scsi/fnic/fnic_trace.c
index cdc6b12b1ec2..0a849a195a8e 100644
--- a/drivers/scsi/fnic/fnic_trace.c
+++ b/drivers/scsi/fnic/fnic_trace.c
@@ -138,9 +138,8 @@ int fnic_get_trace_data(fnic_dbgfs_t *fnic_dbgfs_prt)
*/
len += scnprintf(fnic_dbgfs_prt->buffer + len,
(trace_max_pages * PAGE_SIZE * 3) - len,
- "%16llu.%09lu %-50s %8x %8x %16llx %16llx "
- "%16llx %16llx %16llx\n", (u64)val.tv_sec,
- val.tv_nsec, str, tbp->host_no, tbp->tag,
+ "%ptSp %-50s %8x %8x %16llx %16llx %16llx %16llx %16llx\n",
+ &val, str, tbp->host_no, tbp->tag,
tbp->data[0], tbp->data[1], tbp->data[2],
tbp->data[3], tbp->data[4]);
rd_idx++;
@@ -180,9 +179,8 @@ int fnic_get_trace_data(fnic_dbgfs_t *fnic_dbgfs_prt)
*/
len += scnprintf(fnic_dbgfs_prt->buffer + len,
(trace_max_pages * PAGE_SIZE * 3) - len,
- "%16llu.%09lu %-50s %8x %8x %16llx %16llx "
- "%16llx %16llx %16llx\n", (u64)val.tv_sec,
- val.tv_nsec, str, tbp->host_no, tbp->tag,
+ "%ptSp %-50s %8x %8x %16llx %16llx %16llx %16llx %16llx\n",
+ &val, str, tbp->host_no, tbp->tag,
tbp->data[0], tbp->data[1], tbp->data[2],
tbp->data[3], tbp->data[4]);
rd_idx++;
@@ -215,30 +213,26 @@ int fnic_get_stats_data(struct stats_debug_info *debug,
{
int len = 0;
int buf_size = debug->buf_size;
- struct timespec64 val1, val2;
+ struct timespec64 val, val1, val2;
int i = 0;
- ktime_get_real_ts64(&val1);
+ ktime_get_real_ts64(&val);
len = scnprintf(debug->debug_buffer + len, buf_size - len,
"------------------------------------------\n"
"\t\tTime\n"
"------------------------------------------\n");
+ val1 = timespec64_sub(val, stats->stats_timestamps.last_reset_time);
+ val2 = timespec64_sub(val, stats->stats_timestamps.last_read_time);
len += scnprintf(debug->debug_buffer + len, buf_size - len,
- "Current time : [%lld:%ld]\n"
- "Last stats reset time: [%lld:%09ld]\n"
- "Last stats read time: [%lld:%ld]\n"
- "delta since last reset: [%lld:%ld]\n"
- "delta since last read: [%lld:%ld]\n",
- (s64)val1.tv_sec, val1.tv_nsec,
- (s64)stats->stats_timestamps.last_reset_time.tv_sec,
- stats->stats_timestamps.last_reset_time.tv_nsec,
- (s64)stats->stats_timestamps.last_read_time.tv_sec,
- stats->stats_timestamps.last_read_time.tv_nsec,
- (s64)timespec64_sub(val1, stats->stats_timestamps.last_reset_time).tv_sec,
- timespec64_sub(val1, stats->stats_timestamps.last_reset_time).tv_nsec,
- (s64)timespec64_sub(val1, stats->stats_timestamps.last_read_time).tv_sec,
- timespec64_sub(val1, stats->stats_timestamps.last_read_time).tv_nsec);
+ "Current time : [%ptSp]\n"
+ "Last stats reset time: [%ptSp]\n"
+ "Last stats read time: [%ptSp]\n"
+ "delta since last reset: [%ptSp]\n"
+ "delta since last read: [%ptSp]\n",
+ &val,
+ &stats->stats_timestamps.last_reset_time, &val1,
+ &stats->stats_timestamps.last_read_time, &val2);
stats->stats_timestamps.last_read_time = val1;
@@ -416,8 +410,8 @@ int fnic_get_stats_data(struct stats_debug_info *debug,
jiffies_to_timespec64(stats->misc_stats.last_ack_time, &val2);
len += scnprintf(debug->debug_buffer + len, buf_size - len,
- "Last ISR time: %llu (%8llu.%09lu)\n"
- "Last ACK time: %llu (%8llu.%09lu)\n"
+ "Last ISR time: %llu (%ptSp)\n"
+ "Last ACK time: %llu (%ptSp)\n"
"Max ISR jiffies: %llu\n"
"Max ISR time (ms) (0 denotes < 1 ms): %llu\n"
"Corr. work done: %llu\n"
@@ -437,10 +431,8 @@ int fnic_get_stats_data(struct stats_debug_info *debug,
"Number of rport not ready: %lld\n"
"Number of receive frame errors: %lld\n"
"Port speed (in Mbps): %lld\n",
- (u64)stats->misc_stats.last_isr_time,
- (s64)val1.tv_sec, val1.tv_nsec,
- (u64)stats->misc_stats.last_ack_time,
- (s64)val2.tv_sec, val2.tv_nsec,
+ (u64)stats->misc_stats.last_isr_time, &val1,
+ (u64)stats->misc_stats.last_ack_time, &val2,
(u64)atomic64_read(&stats->misc_stats.max_isr_jiffies),
(u64)atomic64_read(&stats->misc_stats.max_isr_time_ms),
(u64)atomic64_read(&stats->misc_stats.corr_work_done),
@@ -857,8 +849,8 @@ void copy_and_format_trace_data(struct fc_trace_hdr *tdata,
len = *orig_len;
len += scnprintf(fnic_dbgfs_prt->buffer + len, max_size - len,
- "%ptTs.%09lu ns%8x %c%8x\t",
- &tdata->time_stamp.tv_sec, tdata->time_stamp.tv_nsec,
+ "%ptSs ns%8x %c%8x\t",
+ &tdata->time_stamp,
tdata->host_no, tdata->frame_type, tdata->frame_len);
fc_trace = (char *)FC_TRACE_ADDRESS(tdata);
--
2.50.1On Thu 2025-11-13 15:32:33, Andy Shevchenko wrote:
> Use %ptSp instead of open coded variants to print content of
> struct timespec64 in human readable format.
I was about to commit the changes into printk/linux.git and
found a mistake during the final double check, see below.
> diff --git a/drivers/scsi/fnic/fnic_trace.c b/drivers/scsi/fnic/fnic_trace.c
> index cdc6b12b1ec2..0a849a195a8e 100644
> --- a/drivers/scsi/fnic/fnic_trace.c
> +++ b/drivers/scsi/fnic/fnic_trace.c
> @@ -215,30 +213,26 @@ int fnic_get_stats_data(struct stats_debug_info *debug,
> {
> int len = 0;
> int buf_size = debug->buf_size;
> - struct timespec64 val1, val2;
> + struct timespec64 val, val1, val2;
> int i = 0;
>
> - ktime_get_real_ts64(&val1);
> + ktime_get_real_ts64(&val);
> len = scnprintf(debug->debug_buffer + len, buf_size - len,
> "------------------------------------------\n"
> "\t\tTime\n"
> "------------------------------------------\n");
>
> + val1 = timespec64_sub(val, stats->stats_timestamps.last_reset_time);
> + val2 = timespec64_sub(val, stats->stats_timestamps.last_read_time);
> len += scnprintf(debug->debug_buffer + len, buf_size - len,
> - "Current time : [%lld:%ld]\n"
> - "Last stats reset time: [%lld:%09ld]\n"
> - "Last stats read time: [%lld:%ld]\n"
> - "delta since last reset: [%lld:%ld]\n"
> - "delta since last read: [%lld:%ld]\n",
> - (s64)val1.tv_sec, val1.tv_nsec,
> - (s64)stats->stats_timestamps.last_reset_time.tv_sec,
> - stats->stats_timestamps.last_reset_time.tv_nsec,
> - (s64)stats->stats_timestamps.last_read_time.tv_sec,
> - stats->stats_timestamps.last_read_time.tv_nsec,
> - (s64)timespec64_sub(val1, stats->stats_timestamps.last_reset_time).tv_sec,
> - timespec64_sub(val1, stats->stats_timestamps.last_reset_time).tv_nsec,
> - (s64)timespec64_sub(val1, stats->stats_timestamps.last_read_time).tv_sec,
> - timespec64_sub(val1, stats->stats_timestamps.last_read_time).tv_nsec);
> + "Current time : [%ptSp]\n"
> + "Last stats reset time: [%ptSp]\n"
> + "Last stats read time: [%ptSp]\n"
> + "delta since last reset: [%ptSp]\n"
> + "delta since last read: [%ptSp]\n",
Both delta times are printed at the end.
> + &val,
> + &stats->stats_timestamps.last_reset_time, &val1,
> + &stats->stats_timestamps.last_read_time, &val2);
I think that this should be:
&stats->stats_timestamps.last_reset_time,
&stats->stats_timestamps.last_read_time,
&val1, &val2);
> stats->stats_timestamps.last_read_time = val1;
The original code stored the current time in "val1". This should be:
stats->stats_timestamps.last_read_time = val;
> @@ -416,8 +410,8 @@ int fnic_get_stats_data(struct stats_debug_info *debug,
> jiffies_to_timespec64(stats->misc_stats.last_ack_time, &val2);
Just for record. Another values are stored into @val1 and @val2 at
this point.
> len += scnprintf(debug->debug_buffer + len, buf_size - len,
> - "Last ISR time: %llu (%8llu.%09lu)\n"
> - "Last ACK time: %llu (%8llu.%09lu)\n"
> + "Last ISR time: %llu (%ptSp)\n"
> + "Last ACK time: %llu (%ptSp)\n"
> "Max ISR jiffies: %llu\n"
> "Max ISR time (ms) (0 denotes < 1 ms): %llu\n"
> "Corr. work done: %llu\n"
> @@ -437,10 +431,8 @@ int fnic_get_stats_data(struct stats_debug_info *debug,
> "Number of rport not ready: %lld\n"
> "Number of receive frame errors: %lld\n"
> "Port speed (in Mbps): %lld\n",
> - (u64)stats->misc_stats.last_isr_time,
> - (s64)val1.tv_sec, val1.tv_nsec,
> - (u64)stats->misc_stats.last_ack_time,
> - (s64)val2.tv_sec, val2.tv_nsec,
> + (u64)stats->misc_stats.last_isr_time, &val1,
> + (u64)stats->misc_stats.last_ack_time, &val2,
So, this is correct!
> (u64)atomic64_read(&stats->misc_stats.max_isr_jiffies),
> (u64)atomic64_read(&stats->misc_stats.max_isr_time_ms),
> (u64)atomic64_read(&stats->misc_stats.corr_work_done),
Now, I think that there is no need to resend the entire huge patchset.
I could either fix this when comitting or commit the rest and
you could send only this patch for review.
Best Regards,
Petr
PS: All other patches look good. Well, nobody acked 7th patch yet.
But I think that the change is pretty straightforward and
we could do it even without an ack.
On Wed, Nov 19, 2025 at 11:08:01AM +0100, Petr Mladek wrote:
> On Thu 2025-11-13 15:32:33, Andy Shevchenko wrote:
> > Use %ptSp instead of open coded variants to print content of
> > struct timespec64 in human readable format.
>
> I was about to commit the changes into printk/linux.git and
> found a mistake during the final double check, see below.
>
> > diff --git a/drivers/scsi/fnic/fnic_trace.c b/drivers/scsi/fnic/fnic_trace.c
> > index cdc6b12b1ec2..0a849a195a8e 100644
> > --- a/drivers/scsi/fnic/fnic_trace.c
> > +++ b/drivers/scsi/fnic/fnic_trace.c
> > @@ -215,30 +213,26 @@ int fnic_get_stats_data(struct stats_debug_info *debug,
> > {
> > int len = 0;
> > int buf_size = debug->buf_size;
> > - struct timespec64 val1, val2;
> > + struct timespec64 val, val1, val2;
> > int i = 0;
> >
> > - ktime_get_real_ts64(&val1);
> > + ktime_get_real_ts64(&val);
> > len = scnprintf(debug->debug_buffer + len, buf_size - len,
> > "------------------------------------------\n"
> > "\t\tTime\n"
> > "------------------------------------------\n");
> >
> > + val1 = timespec64_sub(val, stats->stats_timestamps.last_reset_time);
> > + val2 = timespec64_sub(val, stats->stats_timestamps.last_read_time);
> > len += scnprintf(debug->debug_buffer + len, buf_size - len,
> > - "Current time : [%lld:%ld]\n"
> > - "Last stats reset time: [%lld:%09ld]\n"
> > - "Last stats read time: [%lld:%ld]\n"
> > - "delta since last reset: [%lld:%ld]\n"
> > - "delta since last read: [%lld:%ld]\n",
> > - (s64)val1.tv_sec, val1.tv_nsec,
> > - (s64)stats->stats_timestamps.last_reset_time.tv_sec,
> > - stats->stats_timestamps.last_reset_time.tv_nsec,
> > - (s64)stats->stats_timestamps.last_read_time.tv_sec,
> > - stats->stats_timestamps.last_read_time.tv_nsec,
> > - (s64)timespec64_sub(val1, stats->stats_timestamps.last_reset_time).tv_sec,
> > - timespec64_sub(val1, stats->stats_timestamps.last_reset_time).tv_nsec,
> > - (s64)timespec64_sub(val1, stats->stats_timestamps.last_read_time).tv_sec,
> > - timespec64_sub(val1, stats->stats_timestamps.last_read_time).tv_nsec);
> > + "Current time : [%ptSp]\n"
> > + "Last stats reset time: [%ptSp]\n"
> > + "Last stats read time: [%ptSp]\n"
> > + "delta since last reset: [%ptSp]\n"
> > + "delta since last read: [%ptSp]\n",
>
> Both delta times are printed at the end.
>
> > + &val,
> > + &stats->stats_timestamps.last_reset_time, &val1,
> > + &stats->stats_timestamps.last_read_time, &val2);
>
> I think that this should be:
>
> &stats->stats_timestamps.last_reset_time,
> &stats->stats_timestamps.last_read_time,
> &val1, &val2);
>
> > stats->stats_timestamps.last_read_time = val1;
>
> The original code stored the current time in "val1". This should be:
>
> stats->stats_timestamps.last_read_time = val;
>
> > @@ -416,8 +410,8 @@ int fnic_get_stats_data(struct stats_debug_info *debug,
> > jiffies_to_timespec64(stats->misc_stats.last_ack_time, &val2);
>
> Just for record. Another values are stored into @val1 and @val2 at
> this point.
>
> > len += scnprintf(debug->debug_buffer + len, buf_size - len,
> > - "Last ISR time: %llu (%8llu.%09lu)\n"
> > - "Last ACK time: %llu (%8llu.%09lu)\n"
> > + "Last ISR time: %llu (%ptSp)\n"
> > + "Last ACK time: %llu (%ptSp)\n"
> > "Max ISR jiffies: %llu\n"
> > "Max ISR time (ms) (0 denotes < 1 ms): %llu\n"
> > "Corr. work done: %llu\n"
> > @@ -437,10 +431,8 @@ int fnic_get_stats_data(struct stats_debug_info *debug,
> > "Number of rport not ready: %lld\n"
> > "Number of receive frame errors: %lld\n"
> > "Port speed (in Mbps): %lld\n",
> > - (u64)stats->misc_stats.last_isr_time,
> > - (s64)val1.tv_sec, val1.tv_nsec,
> > - (u64)stats->misc_stats.last_ack_time,
> > - (s64)val2.tv_sec, val2.tv_nsec,
> > + (u64)stats->misc_stats.last_isr_time, &val1,
> > + (u64)stats->misc_stats.last_ack_time, &val2,
>
> So, this is correct!
>
> > (u64)atomic64_read(&stats->misc_stats.max_isr_jiffies),
> > (u64)atomic64_read(&stats->misc_stats.max_isr_time_ms),
> > (u64)atomic64_read(&stats->misc_stats.corr_work_done),
>
>
> Now, I think that there is no need to resend the entire huge patchset.
>
> I could either fix this when comitting or commit the rest and
> you could send only this patch for review.
Thank you for the thoroughly done review, I changed that patch between the
versions and the problem is that for printf() specifiers (extensions) we do not
have an automatic type checking. We starve for a GCC plugin for that, yeah...
In any case, if you fold your changes in, I will appreciate that!
Otherwise it's also fine with me to send a patch separately later on.
> PS: All other patches look good. Well, nobody acked 7th patch yet.
> But I think that the change is pretty straightforward and
> we could do it even without an ack.
This is my understanding as well. It changes the output, but that output is
debug anyway. So I don't expect breakage of anything we have an obligation
to keep working.
--
With Best Regards,
Andy Shevchenko
© 2016 - 2026 Red Hat, Inc.