Thread: [Linuxptp-users] Software timestamping delay - master offset drift
PTP IEEE 1588 stack for Linux
Brought to you by:
rcochran
Menu
▾
▴
linuxptp-users
|
From: Elder C. <eld...@ti...> - 2023-05-11 16:02:10
|
I had already notice this while trying to solve the clock sync issue of the other thread. Test setup is two Fitlet PCs, connected point-to-point. The master offset increases, non monotonically but with a very definite trend, whether with or without the step_threshold parameter. $ uname -srvm Linux 5.15.0-70-generic #77~20.04.1-Ubuntu SMP Wed Apr 5 09:38:34 UTC 2023 x86_64 $ ptp4l -v 3.1-00246-g5498f74 What am I missing? $ sudo ptp4l -S -m -q --clientOnly=1 --step_threshold=0.01 -i enp3s0 ptp4l[17804.187]: port 1 (enp3s0): INITIALIZING to LISTENING on INIT_COMPLETE ptp4l[17804.188]: port 0 (/var/run/ptp4l): INITIALIZING to LISTENING on INIT_COMPLETE ptp4l[17804.188]: port 0 (/var/run/ptp4lro): INITIALIZING to LISTENING on INIT_COMPLETE ptp4l[17805.578]: port 1 (enp3s0): new foreign master 0001c0.fffe.1a3e8e-1 ptp4l[17809.579]: selected best master clock 0001c0.fffe.1a3e8e ptp4l[17809.579]: foreign master not using PTP timescale ptp4l[17809.579]: port 1 (enp3s0): LISTENING to UNCALIBRATED on RS_SLAVE ptp4l[17810.584]: master offset 159453 s0 freq +100000000 path delay 216530 ptp4l[17811.584]: master offset 204915 s0 freq +100000000 path delay 216530 ptp4l[17812.585]: master offset 253667 s0 freq +100000000 path delay 210875 ptp4l[17813.585]: master offset 216052 s0 freq +100000000 path delay 222827 ptp4l[17814.585]: master offset 218133 s0 freq +100000000 path delay 222827 ptp4l[17815.585]: master offset 238977 s0 freq +100000000 path delay 218369 ptp4l[17816.585]: master offset 243903 s0 freq +100000000 path delay 218369 ptp4l[17817.585]: master offset 161090 s0 freq +100000000 path delay 218369 ptp4l[17818.585]: master offset 243281 s0 freq +100000000 path delay 218369 ptp4l[17819.585]: master offset 252487 s0 freq +100000000 path delay 218369 ptp4l[17820.585]: master offset 243551 s0 freq +100000000 path delay 215088 ptp4l[17821.586]: master offset 253522 s0 freq +100000000 path delay 216985 ptp4l[17822.586]: master offset 254771 s0 freq +100000000 path delay 216985 ptp4l[17823.586]: master offset 236767 s0 freq +100000000 path delay 216985 ptp4l[17824.586]: master offset 260883 s0 freq +100000000 path delay 215088 ptp4l[17825.586]: master offset 231376 s0 freq +100000000 path delay 215088 ptp4l[17826.586]: master offset 279783 s1 freq +100000000 path delay 208463 ptp4l[17827.586]: master offset -4948 s2 freq +99999500 path delay 208463 ptp4l[17827.586]: port 1 (enp3s0): UNCALIBRATED to SLAVE on MASTER_CLOCK_SELECTED ptp4l[17828.586]: master offset -26034 s2 freq +99997366 path delay 208463 ptp4l[17829.586]: master offset 9262 s2 freq +100000000 path delay 196545 ptp4l[17830.587]: master offset -64129 s2 freq +99993492 path delay 196545 ptp4l[17831.587]: master offset 8086 s2 freq +100000000 path delay 180968 ptp4l[17832.587]: master offset 19802 s2 freq +100000000 path delay 180968 ptp4l[17833.587]: master offset 25994 s2 freq +100000000 path delay 196545 ptp4l[17834.587]: master offset 33958 s2 freq +100000000 path delay 180968 ptp4l[17835.587]: master offset -43154 s2 freq +99995546 path delay 187560 ptp4l[17836.587]: master offset 24553 s2 freq +100000000 path delay 187560 ptp4l[17837.587]: master offset 22863 s2 freq +100000000 path delay 209257 ptp4l[17838.588]: master offset -6513 s2 freq +99999204 path delay 214778 ptp4l[17839.588]: master offset 25468 s2 freq +100000000 path delay 212728 ptp4l[17840.588]: master offset 31602 s2 freq +100000000 path delay 206895 ptp4l[17841.588]: master offset 31784 s2 freq +100000000 path delay 206895 ptp4l[17842.588]: master offset 14909 s2 freq +100000000 path delay 211621 ptp4l[17843.588]: master offset 25457 s2 freq +100000000 path delay 211621 ptp4l[17844.588]: master offset 5632 s2 freq +100000000 path delay 211621 ptp4l[17845.589]: master offset 43463 s2 freq +100000000 path delay 208242 ptp4l[17846.589]: master offset 42612 s2 freq +100000000 path delay 208242 ptp4l[17847.589]: master offset 22200 s2 freq +100000000 path delay 211621 ptp4l[17848.589]: master offset 26093 s2 freq +100000000 path delay 211507 ptp4l[17849.589]: master offset -67089 s2 freq +99993079 path delay 211507 ptp4l[17850.589]: master offset 18941 s2 freq +100000000 path delay 211507 ptp4l[17851.589]: master offset 53578 s2 freq +100000000 path delay 211507 ptp4l[17852.589]: master offset 41217 s2 freq +100000000 path delay 212352 ptp4l[17853.589]: master offset -29075 s2 freq +99996852 path delay 212352 ptp4l[17854.590]: master offset 63911 s2 freq +100000000 path delay 212352 ptp4l[17855.590]: master offset 48070 s2 freq +100000000 path delay 213941 ptp4l[17856.590]: master offset -15308 s2 freq +99998213 path delay 211507 ptp4l[17857.590]: master offset 52932 s2 freq +100000000 path delay 211507 ptp4l[17858.590]: master offset 72178 s2 freq +100000000 path delay 210398 ptp4l[17859.590]: master offset -25048 s2 freq +99997214 path delay 211507 ptp4l[17860.590]: master offset 59028 s2 freq +100000000 path delay 210398 ptp4l[17861.591]: master offset 83153 s2 freq +100000000 path delay 210398 ptp4l[17862.591]: master offset -15561 s2 freq +99998147 path delay 209111 ptp4l[17863.591]: master offset 87904 s2 freq +100000000 path delay 206645 ptp4l[17864.591]: master offset 14074 s2 freq +100000000 path delay 206645 ptp4l[17865.591]: master offset 110231 s2 freq +100000000 path delay 194703 ptp4l[17866.591]: master offset 23757 s2 freq +100000000 path delay 194703 ptp4l[17867.591]: master offset 20245 s2 freq +100000000 path delay 179716 ptp4l[17868.591]: master offset 18863 s2 freq +100000000 path delay 179716 ptp4l[17869.591]: master offset 95764 s2 freq +100000000 path delay 174219 ptp4l[17870.591]: master offset 49927 s2 freq +100000000 path delay 174219 ptp4l[17871.592]: master offset 140161 s2 freq +100000000 path delay 172870 ptp4l[17872.592]: master offset 26294 s2 freq +100000000 path delay 174498 ptp4l[17873.592]: master offset 34713 s2 freq +100000000 path delay 172870 ptp4l[17874.592]: master offset 24618 s2 freq +100000000 path delay 172870 ptp4l[17875.592]: master offset 152488 s2 freq +100000000 path delay 171713 ptp4l[17876.592]: master offset 32740 s2 freq +100000000 path delay 174498 ptp4l[17877.592]: master offset 118871 s2 freq +100000000 path delay 171713 ptp4l[17878.592]: master offset 160898 s2 freq +100000000 path delay 170332 ptp4l[17879.593]: master offset 157665 s2 freq +100000000 path delay 171767 ptp4l[17880.593]: master offset 19963 s2 freq +100000000 path delay 217720 ptp4l[17881.593]: master offset 93649 s2 freq +100000000 path delay 217720 ptp4l[17882.593]: master offset 108074 s2 freq +100000000 path delay 220966 ptp4l[17883.593]: master offset 87514 s2 freq +100000000 path delay 220966 ptp4l[17884.593]: master offset 77271 s2 freq +100000000 path delay 215470 ptp4l[17885.593]: master offset 114914 s2 freq +100000000 path delay 215470 ptp4l[17886.593]: master offset 98124 s2 freq +100000000 path delay 215470 ptp4l[17887.593]: master offset 129160 s2 freq +100000000 path delay 215470 ptp4l[17888.594]: master offset 100582 s2 freq +100000000 path delay 215470 ptp4l[17889.594]: master offset 125095 s2 freq +100000000 path delay 215110 ptp4l[17890.594]: master offset 124738 s2 freq +100000000 path delay 215110 ptp4l[17891.594]: master offset 106051 s2 freq +100000000 path delay 215500 ptp4l[17892.594]: master offset 126470 s2 freq +100000000 path delay 215500 ptp4l[17893.594]: master offset 131971 s2 freq +100000000 path delay 215500 ptp4l[17894.594]: master offset 48569 s2 freq +100000000 path delay 215500 ptp4l[17895.594]: master offset 134499 s2 freq +100000000 path delay 215500 ptp4l[17896.595]: master offset 134927 s2 freq +100000000 path delay 215771 ptp4l[17897.595]: master offset 57682 s2 freq +100000000 path delay 219586 ptp4l[17898.595]: master offset 137885 s2 freq +100000000 path delay 214427 ptp4l[17899.595]: master offset 141448 s2 freq +100000000 path delay 213856 ptp4l[17900.595]: master offset 157021 s2 freq +100000000 path delay 208183 ptp4l[17901.595]: master offset 127072 s2 freq +100000000 path delay 212943 ptp4l[17902.595]: master offset 153837 s2 freq +100000000 path delay 206355 ptp4l[17903.595]: master offset 86728 s2 freq +100000000 path delay 212943 ptp4l[17904.595]: master offset 53300 s2 freq +100000000 path delay 197715 ... ptp4l[18856.714]: master offset 1642006 s2 freq +100000000 path delay 210466 ptp4l[18857.714]: master offset 1638704 s2 freq +100000000 path delay 210466 ptp4l[18858.714]: master offset 1562520 s2 freq +100000000 path delay 209583 ptp4l[18859.715]: master offset 1658159 s2 freq +100000000 path delay 205885 ptp4l[18860.715]: master offset 1658522 s2 freq +100000000 path delay 196826 ptp4l[18861.715]: master offset 1548773 s2 freq +100000000 path delay 196826 ptp4l[18862.715]: master offset 1661950 s2 freq +100000000 path delay 185949 ptp4l[18863.715]: master offset 1671314 s2 freq +100000000 path delay 185949 ptp4l[18864.715]: master offset 1674822 s2 freq +100000000 path delay 185949 ptp4l[18865.715]: master offset 1596681 s2 freq +100000000 path delay 185949 ptp4l[18866.716]: master offset 1666690 s2 freq +100000000 path delay 185949 ptp4l[18867.716]: master offset 1670159 s2 freq +100000000 path delay 185949 ptp4l[18868.716]: master offset 1649541 s2 freq +100000000 path delay 196826 ptp4l[18869.716]: master offset 1558798 s2 freq +100000000 path delay 196826 ptp4l[18870.716]: master offset 1688908 s2 freq +100000000 path delay 185949 ptp4l[18871.716]: master offset 1666295 s2 freq +100000000 path delay 185949 ptp4l[18872.716]: master offset 1668525 s2 freq +100000000 path delay 185635 ptp4l[18873.717]: master offset 1673801 s2 freq +100000000 path delay 200040 |
|
From: Richard C. <ric...@gm...> - 2023-05-12 00:43:20
|
On Thu, May 11, 2023 at 01:01:54PM -0300, Elder Costa wrote: > The master offset increases, non monotonically but with a very definite > trend, whether with or without the step_threshold parameter. > What am I missing? Maybe you have ntpd or systemd timesync or chrony running on the client and/or the server? IIRC Ubuntu enables systemd thing by default, and it is hard to get rid of. Thanks, Richard |
|
From: Elder C. <eld...@ti...> - 2023-05-12 12:44:52
|
Em qui., 11 de mai. de 2023 às 21:43, Richard Cochran < ric...@gm...> escreveu: > Maybe you have ntpd or systemd timesync or chrony running on the > client and/or the server? > > IIRC Ubuntu enables systemd thing by default, and it is hard to get > rid of. I disabled clock sync by NTP before starting these tests because I intended to manually alter the clocks as part of the tests. After altering the system clock of the master with date -s 'XX.YY', it proceeds from that without syncing with the real time. At home it occurred to me the issue could have something to do with those "time +100000000" in the log. I assumed that could be the value of a virtual clock of 100MHz that was adjusted to compensate for the delays. The negative offsets has a lower value. I guessed the positive should have a higher than +100000000 to lower the delay. What if I switched the rules of the two Fitlets? That produced the log below. Then I switched the rules again to see if I reproduced the problem. It turns out it did not. Notice the freq values are all relatively low and alternate between positive and negative values. Based on these results, it seems to me that clock value is really a delta. I had already noticed that some days ago. Yesterday, all the runs showed that +100000000 and that drift occurred. Today all the runs show a lower clock and the offset stays in the tens of us range with some a few hundreds, which is perfect for my application (1ms is good, 2.5 ms would still be pretty acceptable). Any ideas? Here is the log, snipped to avoid clutter. cve@cve-sbc-flt1:~$ sudo ptp4l -S -m -q --clientOnly=1 --step_threshold=0.001 -i enp3s0 [sudo] password for cve: ptp4l[483.312]: port 1 (enp3s0): INITIALIZING to LISTENING on INIT_COMPLETE ptp4l[483.312]: port 0 (/var/run/ptp4l): INITIALIZING to LISTENING on INIT_COMPLETE ptp4l[483.312]: port 0 (/var/run/ptp4lro): INITIALIZING to LISTENING on INIT_COMPLETE ptp4l[484.261]: port 1 (enp3s0): new foreign master 0001c0.fffe.1a3cda-1 ptp4l[488.262]: selected best master clock 0001c0.fffe.1a3cda ptp4l[488.262]: foreign master not using PTP timescale ptp4l[488.262]: port 1 (enp3s0): LISTENING to UNCALIBRATED on RS_SLAVE ptp4l[490.263]: master offset -37039670930503 s0 freq -0 path delay 229600 ptp4l[491.263]: master offset -37039670924487 s0 freq -0 path delay 229600 ptp4l[492.264]: master offset -37039670928753 s0 freq -0 path delay 232188 ptp4l[493.264]: master offset -37039670917021 s0 freq -0 path delay 234777 ptp4l[494.264]: master offset -37039670952779 s0 freq -0 path delay 234777 ptp4l[495.264]: master offset -37039670932443 s0 freq -0 path delay 239541 ptp4l[496.264]: master offset -37039671053736 s0 freq -0 path delay 244305 ptp4l[497.265]: master offset -37039671066600 s0 freq -0 path delay 239541 ptp4l[498.265]: master offset -37039670962899 s0 freq -0 path delay 239541 ptp4l[499.265]: master offset -37039670952525 s0 freq -0 path delay 239065 ptp4l[500.265]: master offset -37039670957832 s0 freq -0 path delay 241685 ptp4l[501.265]: master offset -37039671028566 s0 freq -0 path delay 242272 ptp4l[502.266]: master offset -37039670976362 s0 freq -0 path delay 242272 ptp4l[503.266]: master offset -37039670953205 s0 freq -0 path delay 240855 ptp4l[504.266]: master offset -37039671002137 s0 freq -0 path delay 240855 ptp4l[505.266]: master offset -37039671039068 s0 freq -0 path delay 239652 ptp4l[506.266]: master offset -37039670976926 s1 freq -2901 path delay 239652 ptp4l[507.267]: master offset -103222 s2 freq -13326 path delay 239652 ptp4l[507.267]: port 1 (enp3s0): UNCALIBRATED to SLAVE on MASTER_CLOCK_SELECTED ptp4l[508.267]: master offset -89679 s2 freq -12062 path delay 239652 ptp4l[509.267]: master offset -77666 s2 freq -10938 path delay 236179 ptp4l[510.267]: master offset -85815 s2 freq -11839 path delay 221372 ptp4l[511.267]: master offset -40116 s2 freq -7309 path delay 221372 ptp4l[512.267]: master offset -46752 s2 freq -8019 path delay 195594 ptp4l[513.268]: master offset -20651 s2 freq -5430 path delay 195101 ptp4l[514.268]: master offset 79506 s2 freq +4665 path delay 195101 ptp4l[515.268]: master offset 101894 s2 freq +7006 path delay 195101 ptp4l[516.268]: master offset 82552 s2 freq +5154 path delay 195101 ptp4l[517.269]: master offset 55103 s2 freq +2465 path delay 195101 ptp4l[518.269]: master offset 58935 s2 freq +2907 path delay 195101 ptp4l[519.269]: master offset 63706 s2 freq +3448 path delay 195594 ptp4l[520.269]: master offset 58163 s2 freq +2951 path delay 195594 ... ptp4l[2942.407]: master offset 42215 s2 freq +1370 path delay 217699 ptp4l[2943.407]: master offset 29546 s2 freq +133 path delay 217699 ptp4l[2944.407]: master offset -5205 s2 freq -3348 path delay 232956 ptp4l[2945.408]: master offset 19100 s2 freq -898 path delay 232956 ptp4l[2946.408]: master offset -75752 s2 freq -10459 path delay 232956 ptp4l[2947.408]: master offset 39169 s2 freq +1072 path delay 229773 ptp4l[2948.408]: master offset 18187 s2 freq -1008 path delay 229773 cve@cve-sbc-flt1:~$ |
|
From: Elder C. <eld...@ti...> - 2023-05-13 14:01:15
|
> ptp4l[484.261]: port 1 (enp3s0): new foreign master 0001c0.fffe.1a3cda-1 > ptp4l[488.262]: selected best master clock 0001c0.fffe.1a3cda > ptp4l[488.262]: foreign master not using PTP timescale > ptp4l[488.262]: port 1 (enp3s0): LISTENING to UNCALIBRATED on RS_SLAVE > ptp4l[490.263]: master offset -37039670930503 s0 freq -0 path delay 229600 > > ptp4l[17805.578]: port 1 (enp3s0): new foreign master 0001c0.fffe.1a3e8e-1 > ptp4l[17809.579]: selected best master clock 0001c0.fffe.1a3e8e > ptp4l[17809.579]: foreign master not using PTP timescale > ptp4l[17809.579]: port 1 (enp3s0): LISTENING to UNCALIBRATED on RS_SLAVE > ptp4l[17810.584]: master offset 159453 s0 freq +100000000 path delay 216530 > Where does that initial freq value come from? Is it possible to force it to +0 like in the log of the first run above, the one that synchronizes? If the latter is possible, but requires code change to be tested, where should I look at in the source code? |
|
From: Elder C. <eld...@ti...> - 2023-05-16 14:12:31
|
> > ptp4l[484.261]: port 1 (enp3s0): new foreign master 0001c0.fffe.1a3cda-1 > > ptp4l[488.262]: selected best master clock 0001c0.fffe.1a3cda > > ptp4l[488.262]: foreign master not using PTP timescale > > ptp4l[488.262]: port 1 (enp3s0): LISTENING to UNCALIBRATED on RS_SLAVE > > ptp4l[490.263]: master offset -37039670930503 s0 freq -0 path delay > 229600 > > > > ptp4l[17805.578]: port 1 (enp3s0): new foreign master 0001c0.fffe.1a3e8e-1 > > ptp4l[17809.579]: selected best master clock 0001c0.fffe.1a3e8e > > ptp4l[17809.579]: foreign master not using PTP timescale > > ptp4l[17809.579]: port 1 (enp3s0): LISTENING to UNCALIBRATED on RS_SLAVE > > ptp4l[17810.584]: master offset 159453 s0 freq +100000000 path delay > 216530 > > > > Where does that initial freq value come from? > > Is it possible to force it to +0 like in the log of the > first run above, the one that synchronizes? > > If the latter is possible, but requires code change to be > tested, where should I look at in the source code? No hints on this? |
|
From: Miroslav L. <mli...@re...> - 2023-05-16 14:50:51
|
On Tue, May 16, 2023 at 11:04:36AM -0300, Elder Costa wrote: > > > ptp4l[484.261]: port 1 (enp3s0): new foreign master 0001c0.fffe.1a3cda-1 > > > ptp4l[488.262]: selected best master clock 0001c0.fffe.1a3cda > > > ptp4l[488.262]: foreign master not using PTP timescale > > > ptp4l[488.262]: port 1 (enp3s0): LISTENING to UNCALIBRATED on RS_SLAVE > > > ptp4l[490.263]: master offset -37039670930503 s0 freq -0 path delay > > 229600 > > > > > > ptp4l[17805.578]: port 1 (enp3s0): new foreign master 0001c0.fffe.1a3e8e-1 > > > ptp4l[17809.579]: selected best master clock 0001c0.fffe.1a3e8e > > > ptp4l[17809.579]: foreign master not using PTP timescale > > > ptp4l[17809.579]: port 1 (enp3s0): LISTENING to UNCALIBRATED on RS_SLAVE > > > ptp4l[17810.584]: master offset 159453 s0 freq +100000000 path delay > > 216530 > > > > > > > Where does that initial freq value come from? It's the current frequency of the clock. > > Is it possible to force it to +0 like in the log of the > > first run above, the one that synchronizes? phc_ctl CLOCK_REALTIME freq 0 -- Miroslav Lichvar |
|
From: Elder C. <eld...@ti...> - 2023-05-16 15:41:10
|
> > > Is it possible to force it to +0 like in the log of the > > > first run above, the one that synchronizes? > > phc_ctl CLOCK_REALTIME freq 0 > Hello, Miroslav, thank you very much. BR. |
×
Want the latest updates on software, tech news, and AI?
Get latest updates about software, tech news, and AI from SourceForge directly in your inbox once a month.
Thanks for helping keep SourceForge clean.
X