Message-ID: <57f07825-b838-4f1a-b91c-1fd944ac928c@fel.cvut.cz>
Date: Sun, 21 Jul 2024 15:11:13 +0200
From: Martin Pecka <peckama2@....cvut.cz>
To: Igor Russkikh <irusskikh@...vell.com>
Cc: "netdev@...r.kernel.org" <netdev@...r.kernel.org>,
 "linux-kernel@...r.kernel.org" <linux-kernel@...r.kernel.org>,
 Dmitrii Bezrukov <dbezrukov@...vell.com>,
 Jackson Pooyappadam <jpooyappadam@...vell.com>
Subject: Re: [EXTERNAL] net: atlantic: PHC time jumps ~4 seconds there and
 back on AQC107

Thanks for the quick response, Igor.

> AQC107 is now in low maintenance mode in Marvell, and you are right 
> this are of FW is not well documented.
Off-topic: Interesting, given the number of devices out there using 
AQC107...
> One suggestion. Have you tried playing with -R (slave update rate)? 
> Increasing it?
Tried it now and it seems it has no clear influence. I tested with -R 10 
and -R 0.1 and in neither case were the time jumps more or less frequent.
> I have a feeling the fact it happens periodically and then restores 
> has something to do with "rounding" or NS calculations. Surprisingly 
> uint32 fits 4 Billions of NS which is around 4 seconds...

I was also wondering whether the ~4B value could be some overflow. But 
the following investigation shows it is most probably not the case.

I've found an even simpler way to trigger this issue using phc_ctl. Run 
this command once, wait 5-60 seconds and run it again. The second run 
usually suffers from the problem (if not, try again):

$ sudo phc_ctl eth2 -- get freq "9739" wait 0.1 get freq "9739" wait 0.1 
get freq "9739" wait 0.1 get freq "9739" wait 0.1 get | grep "clock time is"
phc_ctl[158332.936]: clock time is 1721563852.538477427 or Sun Jul 21 
14:10:52 2024
phc_ctl[158333.047]: clock time is 1721563848.354551136 or Sun Jul 21 
14:10:48 2024
phc_ctl[158333.159]: clock time is 1721563848.466042545 or Sun Jul 21 
14:10:48 2024
phc_ctl[158333.271]: clock time is 1721563848.578688550 or Sun Jul 21 
14:10:48 2024
phc_ctl[158333.384]: clock time is 1721563848.690969638 or Sun Jul 21 
14:10:48 2024

9739 is a frequency adjustment that results in mac_adj value 
-1.704135816 (base 10).

Rarely, I also see very different lengths of the time jumps like 30 s, 
which lowers the probability that the overflow theory is correct:

phc_ctl[158740.458]: clock time is 1721564285.829867557 or Sun Jul 21 
14:18:05 2024
phc_ctl[158740.569]: clock time is 1721564255.876151658 or Sun Jul 21 
14:17:35 2024
phc_ctl[158740.681]: clock time is 1721564255.987820803 or Sun Jul 21 
14:17:35 2024
phc_ctl[158740.793]: clock time is 1721564256.100033550 or Sun Jul 21 
14:17:36 2024
phc_ctl[158740.905]: clock time is 1721564256.212503798 or Sun Jul 21 
14:17:36 2024

Running a slightly different command, I've observed the time jump 
doesn't happen immediately after the frequncy adjustment, but within 0.1 
s after it. It is then corrected back within a few 100s of ms:

$ while true; do sudo phc_ctl eth2 -- get freq "9739" get wait 0.1 get 
wait 0.1 get wait 0.1; done
phc_ctl[160201.304]: process slept for 0.100000 seconds
phc_ctl[160201.305]: clock time is 1721565716.611702067 or Sun Jul 21 
14:41:56 2024
phc_ctl[160201.406]: process slept for 0.100000 seconds
# right before adj_freq
phc_ctl[160201.435]: clock time is 1721565716.741565866 or Sun Jul 21 
14:41:56 2024
phc_ctl[160201.445]: adjusted clock frequency offset to 9739.000000ppb
# right after adj_freq
phc_ctl[160201.446]: clock time is 1721565716.752391936 or Sun Jul 21 
14:41:56 2024
phc_ctl[160201.546]: process slept for 0.100000 seconds
#100 ms after adj_freq, the jump happens
phc_ctl[160201.547]: clock time is 1721565721.147951767 or Sun Jul 21 
14:42:01 2024
phc_ctl[160201.648]: process slept for 0.100000 seconds
phc_ctl[160201.649]: clock time is 1721565721.250377039 or Sun Jul 21 
14:42:01 2024
phc_ctl[160201.749]: process slept for 0.100000 seconds
phc_ctl[160201.780]: clock time is 1721565721.381843414 or Sun Jul 21 
14:42:01 2024
phc_ctl[160201.791]: adjusted clock frequency offset to 9739.000000ppb
phc_ctl[160201.791]: clock time is 1721565721.392699872 or Sun Jul 21 
14:42:01 2024
phc_ctl[160201.891]: process slept for 0.100000 seconds
# 300 ms after adj_freq, the time jumps back
phc_ctl[160201.892]: clock time is 1721565717.198299859 or Sun Jul 21 
14:41:57 2024
phc_ctl[160201.993]: clock time is 1721565717.299398123 or Sun Jul 21 
14:41:57 2024
phc_ctl[160202.094]: process slept for 0.100000 seconds
phc_ctl[160202.123]: clock time is 1721565717.429400394 or Sun Jul 21 
14:41:57 2024

Last, trying to refine the delay between adj_freq call and time jump, it 
seems to me that 3 ms after the call, the time is correct, while 4 ms 
after the call it already jumps (these values need to be taken with a 
grain of salt as they're the arguments of wait in phc_ctl; but the 
results I got were quite consistent).

Thanks,

Martin


Download attachment "smime.p7s" of type "application/pkcs7-signature" (5737 bytes)

Powered by blists - more mailing lists