Thanks Miroslav and Jake. I'm running linuxptp-1.4 and Linux kernel 2.6.35.7 with customization. My older linuxptp version has pi_f_offset_const instead of first_step_threshold, which I didn't alter.
I added debugging code to confirm that the step takes place, however unclear how things are afterward. (1) On one slave clock device, where its system time is off by 1 hour and 35 minutes behind. Jun 19 14:31:24 (none) user.warn ptp4l: [16.960] port 1: get_ts_info not supported Jun 19 14:31:24 (none) user.notice ptp4l: [16.961] port 1: INITIALIZING to LISTENING on INITIALIZE Jun 19 14:31:24 (none) user.notice ptp4l: [16.961] port 0: INITIALIZING to LISTENING on INITIALIZE Jun 19 14:31:26 (none) user.notice ptp4l: [18.886] port 1: new foreign master 00b0ae.fffe.02d104-1 Jun 19 14:31:30 (none) user.notice ptp4l: [22.886] selected best master clock 00b0ae.fffe.02d104 Jun 19 14:31:30 (none) user.notice ptp4l: [22.886] port 1: LISTENING to UNCALIBRATED on RS_SLAVE Jun 19 14:31:30 (none) user.notice ptp4l: [23.118] port 1: minimum delay request interval 2^-7 Jun 19 14:31:33 (none) user.info ptp4l: [25.823] master offset -5479246314194 s0 freq +0 path delay 3492 Jun 19 14:31:34 (none) user.info ptp4l: [26.823] master offset -5479246315624 s0 freq +0 path delay 3550 Jun 19 14:31:35 (none) user.info ptp4l: [27.823] master offset -5479246316774 s0 freq +0 path delay 3512 Jun 19 14:31:36 (none) user.info ptp4l: [28.822] master offset -5479246318180 s0 freq +0 path delay 3542 Jun 19 14:31:37 (none) user.info ptp4l: [29.822] master offset -5479246319340 s0 freq +0 path delay 3486 Jun 19 14:31:38 (none) user.info ptp4l: [30.822] master offset -5479247196552 s0 freq +0 path delay 295486 Jun 19 14:31:39 (none) user.info ptp4l: [31.822] master offset -5479246905902 s0 freq +0 path delay 3520 Jun 19 14:31:40 (none) user.info ptp4l: [32.822] master offset -5479246907136 s0 freq +0 path delay 3506 Jun 19 14:31:41 (none) user.info ptp4l: [33.822] master offset -5479246908448 s0 freq +0 path delay 3538 Jun 19 14:31:42 (none) user.info ptp4l: [34.822] master offset -5479246909704 s0 freq +0 path delay 3514 Jun 19 14:31:43 (none) user.info ptp4l: [35.822] master offset -5479247782844 s0 freq +0 path delay 294126 Jun 19 14:31:44 (none) user.info ptp4l: [36.822] master offset -5479247493484 s0 freq +0 path delay 3518 Jun 19 14:31:45 (none) user.info ptp4l: [37.821] master offset -5479247494752 s0 freq +0 path delay 3538 Jun 19 14:31:46 (none) user.info ptp4l: [38.821] master offset -5479247496104 s0 freq +0 path delay 3546 Jun 19 14:31:47 (none) user.info ptp4l: [39.821] master offset -5479247497316 s0 freq +0 path delay 3514 Jun 19 14:31:48 (none) user.info ptp4l: [40.821] master offset -5479247498658 s0 freq +0 path delay 3540 Jun 19 14:31:49 (none) user.info ptp4l: [41.821] master offset -5479248375064 s1 freq -128819 path delay 295242 Jun 19 14:31:49 (none) user.info ptp4l: [41.821] Step system clock... Jun 19 14:31:49 (none) user.info ptp4l: [41.821] clockadj_set_freq: clkid=0 freq= +28819 Jun 19 14:31:49 (none) user.info ptp4l: [41.821] clockadj_step: clkid=0 step=5479248375064 Jun 19 14:31:50 (none) user.info ptp4l: [42.821] master offset -5479248376376 s2 freq -100000000 path delay 295242 Jun 19 14:31:50 (none) user.info ptp4l: [42.821] clockadj_set_freq: clkid=0 freq= +0 Jun 19 14:31:50 (none) user.notice ptp4l: [42.821] port 1: UNCALIBRATED to SLAVE on MASTER_CLOCK_SELECTED Jun 19 14:31:51 (none) user.info ptp4l: [43.921] master offset -5479248085876 s2 freq -100000000 path delay 3494 Jun 19 14:31:51 (none) user.info ptp4l: [43.921] clockadj_set_freq: clkid=0 freq= +0 Jun 19 14:31:52 (none) user.info ptp4l: [45.021] master offset -5479248087212 s2 freq -100000000 path delay 3518 Jun 19 14:31:52 (none) user.info ptp4l: [45.021] clockadj_set_freq: clkid=0 freq= +0 Jun 19 14:31:53 (none) user.info ptp4l: [46.121] master offset -5479248088444 s2 freq -100000000 path delay 3502 Jun 19 14:31:53 (none) user.info ptp4l: [46.121] clockadj_set_freq: clkid=0 freq= +0 Jun 19 14:31:55 (none) user.info ptp4l: [47.221] master offset -5479200033936 s2 freq -100000000 path delay -14414590 Jun 19 14:31:55 (none) user.info ptp4l: [47.221] clockadj_set_freq: clkid=0 freq= +0 Jun 19 14:31:56 (none) user.info ptp4l: [48.320] master offset -5478966697088 s2 freq -100000000 path delay -81086222 Jun 19 14:31:56 (none) user.info ptp4l: [48.321] clockadj_set_freq: clkid=0 freq= +0 Jun 19 14:31:57 (none) user.info ptp4l: [49.420] master offset -5478802913984 s2 freq -100000000 path delay -78204170 Jun 19 14:31:57 (none) user.info ptp4l: [49.420] clockadj_set_freq: clkid=0 freq= +0 Jun 19 14:31:58 (none) user.info ptp4l: [50.520] master offset -5478862522102 s2 freq -100000000 path delay -6196760 Jun 19 14:31:58 (none) user.info ptp4l: [50.520] clockadj_set_freq: clkid=0 freq= +0 Jun 19 14:31:59 (none) user.info ptp4l: [51.620] master offset -5478868723712 s2 freq -100000000 path delay 3538 Jun 19 14:31:59 (none) user.info ptp4l: [51.620] clockadj_set_freq: clkid=0 freq= +0 Jun 19 14:32:00 (none) user.info ptp4l: [52.720] master offset -5478868724940 s2 freq -100000000 path delay 3518 Jun 19 14:32:00 (none) user.info ptp4l: [52.720] clockadj_set_freq: clkid=0 freq= +0 Jun 19 14:32:01 (none) user.info ptp4l: [53.820] master offset -5478710523928 s2 freq -100000000 path delay -50266518 Jun 19 14:32:01 (none) user.info ptp4l: [53.820] clockadj_set_freq: clkid=0 freq= +0 Jun 19 14:32:02 (none) user.info ptp4l: [54.920] master offset -5478513781464 s2 freq -100000000 path delay -80343798 Jun 19 14:32:02 (none) user.info ptp4l: [54.920] clockadj_set_freq: clkid=0 freq= +0 (2) On another slave clock device, where its system time is almost same as the correct time. sbin #ptp4l -m -q -i eth3 -s -S ptp4l[841529.107]: clockadj_set_freq: clkid=0 freq= -25768 ptp4l[841529.107]: port 1: get_ts_info not supported ptp4l[841529.108]: port 1: INITIALIZING to LISTENING on INITIALIZE ptp4l[841529.108]: port 0: INITIALIZING to LISTENING on INITIALIZE ptp4l[841529.628]: port 1: new foreign master 00b0ae.fffe.02d103-1 ptp4l[841533.629]: selected best master clock 00b0ae.fffe.02d103 ptp4l[841533.629]: port 1: LISTENING to UNCALIBRATED on RS_SLAVE ptp4l[841533.709]: port 1: minimum delay request interval 2^-7 ptp4l[841535.566]: master offset 496921588 s0 freq -74232 path delay 1186 ptp4l[841536.566]: master offset 496919220 s0 freq -74232 path delay 1214 ptp4l[841537.566]: master offset 497436366 s0 freq -74232 path delay -171964 ptp4l[841538.567]: master offset 497260880 s0 freq -74232 path delay 1186 ptp4l[841539.567]: master offset 497258554 s0 freq -74232 path delay 1212 ptp4l[841540.567]: master offset 497256258 s0 freq -74232 path delay 1204 ptp4l[841541.567]: master offset 497253920 s0 freq -74232 path delay 1202 ptp4l[841542.567]: master offset 497251618 s0 freq -74232 path delay 1200 ptp4l[841543.567]: master offset 497768934 s0 freq -74232 path delay -172016 ptp4l[841544.567]: master offset 497593414 s0 freq -74232 path delay 1196 ptp4l[841545.567]: master offset 497591074 s0 freq -74232 path delay 1204 ptp4l[841546.567]: master offset 497588774 s0 freq -74232 path delay 1200 ptp4l[841547.567]: master offset 497586420 s0 freq -74232 path delay 1218 ptp4l[841548.567]: master offset 498103830 s0 freq -74232 path delay -172036 ptp4l[841549.567]: master offset 497928290 s0 freq -74232 path delay 1204 ptp4l[841550.567]: master offset 497925954 s0 freq -74232 path delay 1204 ptp4l[841551.567]: master offset 497923672 s1 freq -11601 path delay 1182 ptp4l[841551.567]: Step system clock... ptp4l[841551.567]: clockadj_set_freq: clkid=0 freq= +11601 ptp4l[841551.567]: clockadj_step: clkid=0 step= 497923672 ptp4l[841552.567]: master offset 497921336 s2 freq +50278454 path delay 1182 ptp4l[841552.567]: clockadj_set_freq: clkid=0 freq= +21546 ptp4l[841552.567]: port 1: UNCALIBRATED to SLAVE on MASTER_CLOCK_SELECTED ptp4l[841553.517]: master offset 497918992 s2 freq +50776139 path delay 1222 ptp4l[841553.517]: clockadj_set_freq: clkid=0 freq= +23861 ptp4l[841554.466]: master offset 418089084 s2 freq +43211237 path delay 24354298 ptp4l[841554.466]: clockadj_set_freq: clkid=0 freq= -11237 ptp4l[841555.423]: master offset 403879084 s2 freq +42194116 path delay 12854794 ptp4l[841555.423]: clockadj_set_freq: clkid=0 freq= +5884 ptp4l[841556.381]: master offset 416730386 s2 freq +43895976 path delay 1188 ptp4l[841556.381]: clockadj_set_freq: clkid=0 freq= +4024 ptp4l[841557.337]: master offset 416728028 s2 freq +44312469 path delay 1206 ptp4l[841557.337]: clockadj_set_freq: clkid=0 freq= -12469 ptp4l[841558.293]: master offset 416725754 s2 freq +44728967 path delay 1180 ptp4l[841558.293]: clockadj_set_freq: clkid=0 freq= -28967 ptp4l[841559.248]: master offset 416723444 s2 freq +45145459 path delay 1186 ptp4l[841559.248]: clockadj_set_freq: clkid=0 freq= -45459 ptp4l[841560.203]: master offset 416721094 s2 freq +45561946 path delay 1200 ptp4l[841560.203]: clockadj_set_freq: clkid=0 freq= +38054 ptp4l[841561.157]: master offset 389860090 s2 freq +43265705 path delay 7781368 ptp4l[841561.157]: clockadj_set_freq: clkid=0 freq= +34295 ptp4l[841562.114]: master offset 186064456 s2 freq +23072206 path delay 68717870 ptp4l[841562.114]: clockadj_set_freq: clkid=0 freq= +27794 ptp4l[841563.091]: master offset 43535162 s2 freq +8862812 path delay 68388060 ptp4l[841563.091]: clockadj_set_freq: clkid=0 freq= +37188 I also added code to verify if the servo reset occurs when the calculated offset is higher than default sanity_freq_limit. Jun 18 20:08:59 (none) user.warn ptp4l: [521.858] clockcheck: clock jumped backward or running slower than expected! Jun 18 20:08:59 (none) user.info ptp4l: [521.858] MAX-foffset=-206031909 flimit=200000000 Jun 18 20:08:59 (none) user.info ptp4l: [521.858] pi_reset ..................... Jun 18 20:08:59 (none) user.warn ptp4l: [521.966] clockcheck: clock jumped forward or running faster than expected! Jun 18 20:08:59 (none) user.info ptp4l: [521.966] MIN-foffset=+267792097 flimit=200000000 Jun 18 20:08:59 (none) user.info ptp4l: [521.966] pi_reset ..................... Jun 18 20:08:59 (none) user.info ptp4l: [522.070] master offset 1015988 s0 freq +108331 path delay 3518 Jun 18 20:09:00 (none) user.info ptp4l: [523.070] master offset 1014652 s0 freq +108331 path delay 3542 Jun 18 20:09:01 (none) user.info ptp4l: [524.070] master offset 1013376 s0 freq +108331 path delay 3538 Jun 18 20:09:02 (none) user.info ptp4l: [525.070] master offset 924804 s0 freq +108331 path delay 32622 Jun 18 20:09:03 (none) user.info ptp4l: [526.070] master offset 952644 s0 freq +108331 path delay 3506 Jun 18 20:09:04 (none) user.info ptp4l: [527.070] master offset 951354 s0 freq +108331 path delay 3512 -----Original Message----- From: Miroslav Lichvar [mailto:[email protected]] Sent: Friday, June 19, 2015 4:04 AM To: Daniel Le Cc: [email protected] Subject: Re: [Linuxptp-users] sanity_freq_limit On Fri, Jun 19, 2015 at 04:15:20AM +0000, Daniel Le wrote: > And the log messages at start in "good case". I didn't save the log where my > system time was initially off a few minutes, though I remember the master > offsets were above 200000000. I'll need to reproduce such condition in order > to capture the exact log messages. Your config looks good to me. The default value of first_step_threshold is 20 microseconds, so in your test with ~1.5 millisecond initial offset it should have stepped. > ptp4l[792717.068]: master offset -1567668 s0 freq -13556 path delay > 1194 > ptp4l[792718.068]: master offset -1569978 s0 freq -13556 path delay > 1200 > ptp4l[792719.068]: master offset -1554292 s1 freq -13510 path delay > -4826 > ptp4l[792720.068]: master offset -1556592 s2 freq -170726 path delay > -4826 But as we can see, it didn't step for some reason. Here is a test I did using the same config file and it does step for me. ptp4l[8898442.271]: master offset -1093869 s0 freq -1946 path delay 54642 ptp4l[8898443.271]: master offset -1094931 s0 freq -1946 path delay 54642 ptp4l[8898444.271]: master offset -1102224 s1 freq -6078 path delay 55329 ptp4l[8898445.271]: master offset 9378 s2 freq -5131 path delay 55329 What linuxptp and kernel versions are you using? -- Miroslav Lichvar ------------------------------------------------------------------------------ _______________________________________________ Linuxptp-users mailing list [email protected] https://lists.sourceforge.net/lists/listinfo/linuxptp-users
