Re: [PATCH] clocksource: Use correct limit for wd-cs-wd read back delay in printing

[kernel test robot <lkp@intel.com>]

Hi Aaron,

kernel test robot noticed the following build warnings:

[auto build test WARNING on tip/timers/core]
[also build test WARNING on linus/master v6.16 next-20250731]
[If your patch is applied to the wrong git tree, kindly drop us a note.
And when submitting patch, we suggest to use '--base' as documented in
https://git-scm.com/docs/git-format-patch#_base_tree_information]

url:    https://github.com/intel-lab-lkp/linux/commits/Aaron-Lu/clocksource-Use-correct-limit-for-wd-cs-wd-read-back-delay-in-printing/20250731-200709
base:   tip/timers/core
patch link:    https://lore.kernel.org/r/20250731120454.GA309%40bytedance
patch subject: [PATCH] clocksource: Use correct limit for wd-cs-wd read back delay in printing
config: i386-buildonly-randconfig-001-20250801 (https://download.01.org/0day-ci/archive/20250801/202508010911.AmkxEw1p-lkp@intel.com/config)
compiler: clang version 20.1.8 (https://github.com/llvm/llvm-project 87f0227cb60147a26a1eeb4fb06e3b505e9c7261)
reproduce (this is a W=1 build): (https://download.01.org/0day-ci/archive/20250801/202508010911.AmkxEw1p-lkp@intel.com/reproduce)

If you fix the issue in a separate patch/commit (i.e. not just a new version of
the same patch/commit), kindly add following tags
| Reported-by: kernel test robot <lkp@intel.com>
| Closes: https://lore.kernel.org/oe-kbuild-all/202508010911.AmkxEw1p-lkp@intel.com/

All warnings (new ones prefixed by >>):

>> kernel/time/clocksource.c:293:43: warning: format specifies type 'long' but the argument has type 'int64_t' (aka 'long long') [-Wformat]
     292 |         pr_warn("timekeeping watchdog on CPU%d: wd-%s-wd excessive read-back delay of %lldns vs. limit of %ldns, wd-wd read-back delay only %lldns, attempt %d, marking %s unstable\n",
         |                                                                                                           ~~~
         |                                                                                                           %lld
     293 |                 smp_processor_id(), cs->name, wd_delay, md + cs->uncertainty_margin, wd_seq_delay, nretries, cs->name);
         |                                                         ^~~~~~~~~~~~~~~~~~~~~~~~~~~
   include/linux/printk.h:560:37: note: expanded from macro 'pr_warn'
     560 |         printk(KERN_WARNING pr_fmt(fmt), ##__VA_ARGS__)
         |                                    ~~~     ^~~~~~~~~~~
   include/linux/printk.h:507:60: note: expanded from macro 'printk'
     507 | #define printk(fmt, ...) printk_index_wrap(_printk, fmt, ##__VA_ARGS__)
         |                                                     ~~~    ^~~~~~~~~~~
   include/linux/printk.h:479:19: note: expanded from macro 'printk_index_wrap'
     479 |                 _p_func(_fmt, ##__VA_ARGS__);                           \
         |                         ~~~~    ^~~~~~~~~~~
   1 warning generated.


vim +293 kernel/time/clocksource.c

   252	
   253	static enum wd_read_status cs_watchdog_read(struct clocksource *cs, u64 *csnow, u64 *wdnow)
   254	{
   255		int64_t md = 2 * watchdog->uncertainty_margin;
   256		unsigned int nretries, max_retries;
   257		int64_t wd_delay, wd_seq_delay;
   258		u64 wd_end, wd_end2;
   259	
   260		max_retries = clocksource_get_max_watchdog_retry();
   261		for (nretries = 0; nretries <= max_retries; nretries++) {
   262			local_irq_disable();
   263			*wdnow = watchdog->read(watchdog);
   264			*csnow = cs->read(cs);
   265			wd_end = watchdog->read(watchdog);
   266			wd_end2 = watchdog->read(watchdog);
   267			local_irq_enable();
   268	
   269			wd_delay = cycles_to_nsec_safe(watchdog, *wdnow, wd_end);
   270			if (wd_delay <= md + cs->uncertainty_margin) {
   271				if (nretries > 1 && nretries >= max_retries) {
   272					pr_warn("timekeeping watchdog on CPU%d: %s retried %d times before success\n",
   273						smp_processor_id(), watchdog->name, nretries);
   274				}
   275				return WD_READ_SUCCESS;
   276			}
   277	
   278			/*
   279			 * Now compute delay in consecutive watchdog read to see if
   280			 * there is too much external interferences that cause
   281			 * significant delay in reading both clocksource and watchdog.
   282			 *
   283			 * If consecutive WD read-back delay > md, report
   284			 * system busy, reinit the watchdog and skip the current
   285			 * watchdog test.
   286			 */
   287			wd_seq_delay = cycles_to_nsec_safe(watchdog, wd_end, wd_end2);
   288			if (wd_seq_delay > md)
   289				goto skip_test;
   290		}
   291	
   292		pr_warn("timekeeping watchdog on CPU%d: wd-%s-wd excessive read-back delay of %lldns vs. limit of %ldns, wd-wd read-back delay only %lldns, attempt %d, marking %s unstable\n",
 > 293			smp_processor_id(), cs->name, wd_delay, md + cs->uncertainty_margin, wd_seq_delay, nretries, cs->name);
   294		return WD_READ_UNSTABLE;
   295	
   296	skip_test:
   297		pr_info("timekeeping watchdog on CPU%d: %s wd-wd read-back delay of %lldns\n",
   298			smp_processor_id(), watchdog->name, wd_seq_delay);
   299		pr_info("wd-%s-wd read-back delay of %lldns, clock-skew test skipped!\n",
   300			cs->name, wd_delay);
   301		return WD_READ_SKIP;
   302	}
   303	

-- 
0-DAY CI Kernel Test Service
https://github.com/intel/lkp-tests/wiki