I want to synchronize 2 embedded systems. One hase a RTC and should be the master.
PTPd is started this way:
ptpd2 -i eth0 -M -C -V
The second one should synchronize to the master:
ptpd2 -s -i eth0 -V -C
The Problem is, that the slave does not update its system time. The messages on the slave show that it receives the correct time:
2016-03-04 10:10:39.363983, slv, 0011b8fffe000f2d(unknown)/01, 0.000126991, 0.126527611, -0.126437831, 0.126643259, 500000.000000000, S
2016-03-04 10:10:39.473098, slv, 0011b8fffe000f2d(unknown)/01, 0.000126102, 0.126527611, -0.126431932, 0.126643259, 500000.000000000, D
2016-03-04 10:10:40.098373, slv, 0011b8fffe000f2d(unknown)/01, 0.000132090, 0.126527611, -0.125871098, 0.126643259, 500000.000000000, D
2016-03-04 10:10:40.364424, slv, 0011b8fffe000f2d(unknown)/01, 0.000132090, 0.126502583, -0.125871098, 0.126620989, 500000.000000000, S
2016-03-04 10:10:41.364928, slv, 0011b8fffe000f2d(unknown)/01, 0.000132090, 0.126477258, -0.125871098, 0.126597708, 500000.000000000, S
2016-03-04 10:10:41.597591, slv, 0011b8fffe000f2d(unknown)/01, 0.000143337, 0.126477258, -0.125896773, 0.126597708, 500000.000000000, D
But when I type date the system time is not updated:
~# date
Thu Jan 1 00:31:32 UTC 1970
I use ptpd2 version 2.3.1-rc2.
Does anybody know what is wrong here?
If you would like to refer to this comment somewhere else in this project, copy and paste the following link:
I am having the same problem. Unfortunately there does not seem to be any documentation on how to use this PTP package. There are references to how it adjusts "the clock", but never specifies what clock they are talking about. It looks like this implementation only syncs the PTP Hardware Clock (PHC), but does not transfer that to the Linux system clock. I don't see any options in the configuration file to enable/disable this behavior as one would expect. The Linuxptp package has an additional utility that syncs the system clock with the PHC. I don't see something like that here. It would be nice if the project description page was updated to make it clear what this package does besides just implenting PTP.
If you would like to refer to this comment somewhere else in this project, copy and paste the following link:
There is the no_adjust option. I think this should disable the synchronisation of the system clock. But default this shouldn't be set.
I started master and slave with --clock:no_adjust N but it doesn't change anything.
I did the same with ptpd2.2.2. With this version PTP did synchronize the system clocks like expected.
If you would like to refer to this comment somewhere else in this project, copy and paste the following link:
Standard PTPd does not run hardware timestamping so it does not sync the PHC clock; this functionality should arrive in the next version. "the clock" is the wall clock - the system clock.
If you would like to refer to this comment somewhere else in this project, copy and paste the following link:
Clock is being updated - you can see offset from master decreasing. Furthermore, your log shows the correct date, which is performed using standard gettimeofday(), so the system clock is updated, only the "date" command for some reason shows incorrect time. You can try setting clock:set_rtc_on_step=y - in case if it's a problem with the RTC.
It would also be helpful to state what h/w platform you are using, what kernel version and what OS.
If you would like to refer to this comment somewhere else in this project, copy and paste the following link:
I am about to acquire a Wandboard for testing and it's also based on i.MX6. Again, note that your log output was showing the correct date, just the "date" command was not. The set_rtc_on_step setting will only set the RTC when it steps the clock, so this should probably only take effect after reboot.
I have not seen this behaviour before. The writeMessage() function which logs a log message, uses gettimeofday() and it is showing correct time in your output, so if gettimeofday() has the right time, but date does not, something is clearly wrong and I'm not sure how PTPd is involved in this.
PTPd has got a very nice way to observe its current status - the status file. If you set global:status_file=/path/to/file you can watch it with watch -n 1 cat /path/to/file - this is normally much more convenient than tracking the log file.
Thanks,
Wojciech
If you would like to refer to this comment somewhere else in this project, copy and paste the following link:
I checked the coreutils/src/date.c code - it only uses gettime() and localtime() to get the time. I'm struggling to understand why gettimeofday() returns correct time but gettime() does not. gettime() used by coreutils is a wrapper which may use gettimeofday() or clock_gettime(CLOCK_REALTIME). It may be the case that for some reason the two return different values - or it's a problem with coreutils / date.
Last edit: Wojciech Owczarek 2016-03-07
If you would like to refer to this comment somewhere else in this project, copy and paste the following link:
This is the wrapper that date uses. gettimeofday() clearly works. Either nanotime() or clock_gettime(CLOCK_REALTIME) are returning 0 seconds. nanotime() is a BSD function, so this leaves clock_gettime. Can you try compiling the attached source (gcc -o timetest timetest.c), running it and showing the output?
OK. Check out the example config file I mentioned, it has a decent set of parameters for filters and is well commented. With this version you get full support for timestamping hardware in your i.mx6.
To confirm that this issue is gone, you should probably also test the final ptpd 2.3.1 from sourceforge, or the official PTPd git souce http://github.com/ptpd/ptpd and see if it has the same problem or not. There has been a long list of changes between 2.3.1rc2 and 2.3.1.
Thanks,
Wojciech
Last edit: Wojciech Owczarek 2016-03-07
If you would like to refer to this comment somewhere else in this project, copy and paste the following link:
I'm also also having this same problem. I am currently using the version in the hw timestamping branch here: https://github.com/wowczarek/ptpd/tree/wowczarek-2.3.2-hwtest. Like the OP, I was having system clock updates with ptpd2.2.2. I've poured over all the docs and experimented with various settings - no success. Used the test/linuxphc_hw.conf config file as well as the one obtained from ptpd -O.
I'm afraid "it's not updating the system clock" is too little information.
What's in the log file? What's in the status file? Any chance your system clock has a negative offset and PTPd is refusing to step the clock backwards?
I have some RHEL7 systems available to hand - let me have a look.
What's the NIC you're using?
Thanks,
Wojciech
If you would like to refer to this comment somewhere else in this project, copy and paste the following link:
Status file:
Host info : ssit-lab-2, PID 22262
Local time : Thu May 19 07:43:36 EDT 2016
Kernel time : Thu May 19 11:43:36 GMT 2016
Interface : enp3s0f0
Preset : masterslave
Transport : ipv4, multicast, HW PTP
Delay mechanism : E2E
Sync mode : TWO_STEP
PTP domain : 0
Port state : PTP_SLAVE
Local port ID : 38eaa7fffe3846b6(unknown)/277
Best master ID : 38eaa7fffe38476a(unknown)/177
Best master IP : 192.168.77.1
GM priority : Priority1 100, Priority2 128, clockClass 248
Time properties : ARB timescale, tracbl: time N, freq N, src: INTERNAL_OSCILLATOR(0xa0)
UTC properties : UTC valid: N, UTC offset: 0
Offset from Master : 0.000001664 s, mean -0.000000312 s, dev 0.000002586 s
Mean Path Delay : 0.000020629 s, mean 0.000020063 s, dev 0.000000064 s
PTP Clock status : calibrated, in control, not stabilised
Message rates : 1/s sync, 1/s delay, 1/2s announce
TimingService : current PTP0, best PTP0, pref PTP0
TimingServices : total 1, avail 1, oper 1, idle 0, in_ctrl 1
Performance : Message RX 7/s, TX 1/s
Announce received : 39514
Sync received : 79021
Follow-up received : 79006
DelayReq sent : 79068
DelayResp received : 78923
State transitions : 7
PTP Engine resets : 1
I see your system clock is showing up with reference "EXT" - I take it you have made system clock the master clock (for when your node becomes a PTP master).
The correct behaviour in this situation should be that a PTP reference is preferred over an EXT reference when it is available - I need to re-test this.
Thanks,
Wojciech
If you would like to refer to this comment somewhere else in this project, copy and paste the following link:
sodding SourceForge... Four out of five times when I press "post", I lose my message and it's not posted. And the one time it does, I get all content and forget to copy the next one before trying to post! </rant>
I have just pushed a change to my 2.3.2-linuxphc branch which fixes your situation. The master clock is now only used when PTPd is running as master or passive, and will otherwise happily sync to whatever best clock is selected. The reference name was also changed to "PREFMST" so it can be clearly identified. This has been tested successfully when switching between MASTER / SLAVE / PASSIVE.
FYI - the log file you sent is not the log file, it is the statistics file. The actual logs (which are pretty rich) go to syslog, unless you specify a log file - check the man page / ptpd help / hw config example.
Thanks,
Wojciech
If you would like to refer to this comment somewhere else in this project, copy and paste the following link:
OK, based on what you said I removed the clock:masterclockname = "syst" option and the clock did eventually sync in slave-only mode. It took longer than I expected so I may not have noticed it when I was trying various options. I will also need the masterslave mode so I am gald you were able to reproduce and fix the issue. I will update and retest tomorrow.
Many thanks,
Dan
Second post due to SourceForge posting
If you would like to refer to this comment somewhere else in this project, copy and paste the following link:
I can't tell if the system clock is being slewed or not but there is definitely not a step occurring at startup. Any ideas what settings may be affecting this? I would prefer a step to occur if the offset was greater than X (forward or back).
Thanks,
Dan
If you would like to refer to this comment somewhere else in this project, copy and paste the following link:
Thanks - there was an issue with some quotes around variables that affected some autoconf versions. This now builds cleanly. The URL is the url of the official ptpd repo - which is where this code is going when it's ready.
OK - I need to post some documentation about the clock model in the new code.
The system clock will only sync when the PTP clock is in LOCKED state. In your example, the NIC clock is TRACKING, so the system clock will not sync to it. This behaviour is meant to protect clocks from being dragged around if the source clock is misbehaving. So if your PTP clock is in good sync, OS clock syncs to it. If it goes wild, it goes out of LOCKED state and the OS clock detaches to protect its stability, and will re-sync when PTP is back in LOCKED.
The state is based on the short term Allan deviation (adev) value, it has a high and low watermark setting (low is to enter LOCKED state, high is to leave it). Grep the built-in help for "adev" to see which settings control this. These settings are separate for hardware and for software clocks.
At very low message rates, when outlier filters are enabled and when the network is very noisy, things may take a while to stabilise. In your first output there was "Clock 2: enp3s0f0 : offs: -0.000001664 adev: 4001.599 freq: -6992.020" - if 4000 is as low as it gets, you may want to set your threshold to that.
The general rule is that you need to observe your clocks when you deploy them and see how they play with your network, and then set the various filter thresholds based on that. I would also recommend to set higher message rates, 4/sec or 8/sec or more. If the network is noisy, more samples for filters to choose from always helps.
Comment re. stepping at certain thresholds noted, this is on my to-do list. Again, the principle with ptpd is to do the least amount of damage to clocks. Some care about the PTP clock (say if they use it for packet timestamping) so would prefer the clock not to be stepped at will, some only use it as a means to deliver time to the OS clocks.
Does your PTP NIC reach the LOCKED state at all? What are the network conditions like?
Watch the commits in that branch, I will be adding a step threshold.
Thanks,
Wojciech
If you would like to refer to this comment somewhere else in this project, copy and paste the following link:
...and by the way - while some PTP clients do this, I think the decision to step the clock needs a more thoughtful approach. If you just blindly step when a threshold is crossed, this may do more damage than necessary. Say, you had a network event which caused the offset to look very high for say ten seconds. You see the offset, step the clock, offset goes away, then the event passes and you step it back because it is now off again. The better way is that an outlier filter holds / blocks the offset for some period of time and lets go only if enough time has passed - which is what PTPd aims to do.
Thanks,
Wojciech
If you would like to refer to this comment somewhere else in this project, copy and paste the following link:
I hear ya. I figured there was an aversion to stepping the clock for good reasons. The one exception that I think seems reasonable would be at startup. I see that there is an option for that but perhaps my problem is rooted in the NIC clock attaining the LOCKED state. I will watch this and let you know.
I have been moving the GM source clock around on occasion to see how the system responds. I am protyping the use of PTP for an embedded system. My test rig is three nodes - one GM and two slaves. I will need the slaves to become the GM if/when GM fails. No real traffic in the system other than PTP, metrics collection, and display. I do not have a 1588 switch yet, I will be adding one with a transparent clock shortly.
If the system can sync up at startup, then there should be no need to step - even after failover - and yes, timestamping is the primary goal here. The objective system does not have a battery on board so the rtc will be zero at boot.
I will do more testing on Monday and try your suggestions. Thank you Wojciech.
Thanks,
Dan
If you would like to refer to this comment somewhere else in this project, copy and paste the following link:
Following you guidance, I tweaked the servo:adev settings - but no change. Monitoring the .status file, I see that the slave system starts up with both hw and system clocking in FREERUN. The phc eventually attains LOCKED state (sometimes) and syst clock moves to the 'STEP 5' state. The higer message rates (and latger servo:adev window) seem to keep the ptp clock from flipping between LOCKED and TRACKING, but the syst clock is still not stepped.
If you actually watch the status file (as in, with the watch command if you have it in your shell - watch -n 1 cat somefile - you will see that the number after "STEP" is a countdown.
Yes, I've been using 'watch' on the status file. It was hanging on STEP 5 indefinitely.
However, I have noe set ptpengine:panic_mode=n and it works much better. I will tweak it in and let you know if I observe the hanging behaviour again. Perhaps I'll set the panic duration to a lower value - say 3.
Thanks,
Dan
If you would like to refer to this comment somewhere else in this project, copy and paste the following link:
I want to synchronize 2 embedded systems. One hase a RTC and should be the master.
PTPd is started this way:
ptpd2 -i eth0 -M -C -V
The second one should synchronize to the master:
ptpd2 -s -i eth0 -V -C
The Problem is, that the slave does not update its system time. The messages on the slave show that it receives the correct time:
2016-03-04 10:10:39.363983, slv, 0011b8fffe000f2d(unknown)/01, 0.000126991, 0.126527611, -0.126437831, 0.126643259, 500000.000000000, S
2016-03-04 10:10:39.473098, slv, 0011b8fffe000f2d(unknown)/01, 0.000126102, 0.126527611, -0.126431932, 0.126643259, 500000.000000000, D
2016-03-04 10:10:40.098373, slv, 0011b8fffe000f2d(unknown)/01, 0.000132090, 0.126527611, -0.125871098, 0.126643259, 500000.000000000, D
2016-03-04 10:10:40.364424, slv, 0011b8fffe000f2d(unknown)/01, 0.000132090, 0.126502583, -0.125871098, 0.126620989, 500000.000000000, S
2016-03-04 10:10:41.364928, slv, 0011b8fffe000f2d(unknown)/01, 0.000132090, 0.126477258, -0.125871098, 0.126597708, 500000.000000000, S
2016-03-04 10:10:41.597591, slv, 0011b8fffe000f2d(unknown)/01, 0.000143337, 0.126477258, -0.125896773, 0.126597708, 500000.000000000, D
But when I type date the system time is not updated:
~# date
Thu Jan 1 00:31:32 UTC 1970
I use ptpd2 version 2.3.1-rc2.
Does anybody know what is wrong here?
I am having the same problem. Unfortunately there does not seem to be any documentation on how to use this PTP package. There are references to how it adjusts "the clock", but never specifies what clock they are talking about. It looks like this implementation only syncs the PTP Hardware Clock (PHC), but does not transfer that to the Linux system clock. I don't see any options in the configuration file to enable/disable this behavior as one would expect. The Linuxptp package has an additional utility that syncs the system clock with the PHC. I don't see something like that here. It would be nice if the project description page was updated to make it clear what this package does besides just implenting PTP.
There is the no_adjust option. I think this should disable the synchronisation of the system clock. But default this shouldn't be set.
I started master and slave with --clock:no_adjust N but it doesn't change anything.
I did the same with ptpd2.2.2. With this version PTP did synchronize the system clocks like expected.
Standard PTPd does not run hardware timestamping so it does not sync the PHC clock; this functionality should arrive in the next version. "the clock" is the wall clock - the system clock.
Clock is being updated - you can see offset from master decreasing. Furthermore, your log shows the correct date, which is performed using standard gettimeofday(), so the system clock is updated, only the "date" command for some reason shows incorrect time. You can try setting
clock:set_rtc_on_step=y- in case if it's a problem with the RTC.It would also be helpful to state what h/w platform you are using, what kernel version and what OS.
I tried
ptpd2 -s -i eth0 -V -C --clock:set_rtc_on_step=ybut it still does not update the time.I use a i.MX6 on a custom eval board, kernel version 4.4.0-yocto-standard and the OS is poky1.8.1 from the Yocto-Project.
I am about to acquire a Wandboard for testing and it's also based on i.MX6. Again, note that your log output was showing the correct date, just the "date" command was not. The set_rtc_on_step setting will only set the RTC when it steps the clock, so this should probably only take effect after reboot.
I have not seen this behaviour before. The
writeMessage()function which logs a log message, uses gettimeofday() and it is showing correct time in your output, so ifgettimeofday()has the right time, butdatedoes not, something is clearly wrong and I'm not sure how PTPd is involved in this.Since you're using i.MX6, you may want to use my current PTPd branch which supports hardware timestamping: https://github.com/wowczarek/ptpd/tree/wowczarek-2.3.2-hwtest - and use the config file
test/linuxphc_hw.conf.PTPd has got a very nice way to observe its current status - the status file. If you set
global:status_file=/path/to/fileyou can watch it withwatch -n 1 cat /path/to/file- this is normally much more convenient than tracking the log file.Thanks,
Wojciech
I checked the coreutils/src/date.c code - it only uses
gettime()andlocaltime()to get the time. I'm struggling to understand whygettimeofday()returns correct time butgettime()does not.gettime()used by coreutils is a wrapper which may usegettimeofday()orclock_gettime(CLOCK_REALTIME). It may be the case that for some reason the two return different values - or it's a problem with coreutils / date.Last edit: Wojciech Owczarek 2016-03-07
void gettime (struct timespec *ts) { #if HAVE_NANOTIME nanotime (ts); #else # if defined CLOCK_REALTIME && HAVE_CLOCK_GETTIME if (clock_gettime (CLOCK_REALTIME, ts) == 0) return; # endif { struct timeval tv; gettimeofday (&tv, NULL); ts->tv_sec = tv.tv_sec; ts->tv_nsec = tv.tv_usec * 1000; } #endif }This is the wrapper that
dateuses. gettimeofday() clearly works. Eithernanotime()orclock_gettime(CLOCK_REALTIME)are returning 0 seconds.nanotime()is a BSD function, so this leavesclock_gettime. Can you try compiling the attached source (gcc -o timetest timetest.c), running it and showing the output?Here ist the output of timetest after the log of ptpd2 shows the current date. There is no bit difference between the two functions:
I also tested also to sync the slave with the older ptpd2.2.2.
Here it does sync the system clock. The log of the slave is listed below:
I tested your new ptpd2 version 2.3.2 from Github. There the system time is updated, when I started it with the same command:
./ptpd2 -s -i eth0 -V -COK. Check out the example config file I mentioned, it has a decent set of parameters for filters and is well commented. With this version you get full support for timestamping hardware in your i.mx6.
To confirm that this issue is gone, you should probably also test the final ptpd 2.3.1 from sourceforge, or the official PTPd git souce http://github.com/ptpd/ptpd and see if it has the same problem or not. There has been a long list of changes between 2.3.1rc2 and 2.3.1.
Thanks,
Wojciech
Last edit: Wojciech Owczarek 2016-03-07
I'm also also having this same problem. I am currently using the version in the hw timestamping branch here: https://github.com/wowczarek/ptpd/tree/wowczarek-2.3.2-hwtest. Like the OP, I was having system clock updates with ptpd2.2.2. I've poured over all the docs and experimented with various settings - no success. Used the test/linuxphc_hw.conf config file as well as the one obtained from ptpd -O.
Running on CentOS 7 3.10.0-327.el7.x86_64 #1 SMP x86_64 x86_64 x86_64 GNU/Linux.
I'm afraid "it's not updating the system clock" is too little information.
What's in the log file? What's in the status file? Any chance your system clock has a negative offset and PTPd is refusing to step the clock backwards?
I have some RHEL7 systems available to hand - let me have a look.
What's the NIC you're using?
Thanks,
Wojciech
Status file:
Host info : ssit-lab-2, PID 22262
Local time : Thu May 19 07:43:36 EDT 2016
Kernel time : Thu May 19 11:43:36 GMT 2016
Interface : enp3s0f0
Preset : masterslave
Transport : ipv4, multicast, HW PTP
Delay mechanism : E2E
Sync mode : TWO_STEP
PTP domain : 0
Port state : PTP_SLAVE
Local port ID : 38eaa7fffe3846b6(unknown)/277
Best master ID : 38eaa7fffe38476a(unknown)/177
Best master IP : 192.168.77.1
GM priority : Priority1 100, Priority2 128, clockClass 248
Time properties : ARB timescale, tracbl: time N, freq N, src: INTERNAL_OSCILLATOR(0xa0)
UTC properties : UTC valid: N, UTC offset: 0
Offset from Master : 0.000001664 s, mean -0.000000312 s, dev 0.000002586 s
Mean Path Delay : 0.000020629 s, mean 0.000020063 s, dev 0.000000064 s
PTP Clock status : calibrated, in control, not stabilised
Message rates : 1/s sync, 1/s delay, 1/2s announce
TimingService : current PTP0, best PTP0, pref PTP0
TimingServices : total 1, avail 1, oper 1, idle 0, in_ctrl 1
Performance : Message RX 7/s, TX 1/s
Announce received : 39514
Sync received : 79021
Follow-up received : 79006
DelayReq sent : 79068
DelayResp received : 78923
State transitions : 7
PTP Engine resets : 1
Clock 1: syst : name: syst state: LOCKED ref: EXT
Clock 2: enp3s0f0 : name: enp3s0f0 state: TRACKING ref: PTP
Clock 1: syst : offs: 0.000000000 adev: 0.000 freq: 0.000
Clock 2: enp3s0f0 : offs: -0.000001664 adev: 4001.599 freq: -6992.020
log file:
2016-05-19 07:49:45.969390, slv, 38eaa7fffe38476a(unknown)/177, 0.000020406, 0.000002559, 0.000017307, 0.000022078, -5464.220000000, D, 13890, 0.000020173, 181, -0.000000201, 9319 0.000022078, 0.000017307
2016-05-19 07:49:46.433610, slv, 38eaa7fffe38476a(unknown)/177, 0.000020404, 0.000002559, 0.000019548, 0.000022078, -5464.220000000, D, 13891, 0.000020173, 181, -0.000000201, 9319 0.000022078, 0.000019548
2016-05-19 07:49:46.495068, slv, 38eaa7fffe38476a(unknown)/177, 0.000020411, 0.000002559, 0.000019751, 0.000022078, -5464.220000000, D, 13892, 0.000020173, 181, -0.000000201, 9319 0.000022078, 0.000019751
2016-05-19 07:49:46.733373, slv, 38eaa7fffe38476a(unknown)/177, 0.000020411, 0.000001667, 0.000019751, 0.000022078, -5464.220000000, S, 14102, 0.000020173, 181, -0.000000201, 9319 0.000022078, 0.000019751
2016-05-19 07:49:46.809344, slv, 38eaa7fffe38476a(unknown)/177, 0.000020421, 0.000001667, 0.000020413, 0.000022078, -5564.240000000, D, 13893, 0.000020173, 181, -0.000000201, 9319 0.000022078, 0.000020413
2016-05-19 07:49:47.733437, slv, 38eaa7fffe38476a(unknown)/177, 0.000020421, 0.000001399, 0.000020413, 0.000021554, -5564.240000000, S, 14103, 0.000020173, 181, -0.000000201, 9319 0.000021554, 0.000020413
2016-05-19 07:49:48.421530, slv, 38eaa7fffe38476a(unknown)/177, 0.000020441, 0.000001399, 0.000022825, 0.000021554, -5648.180000000, D, 13894, 0.000020173, 181, -0.000000201, 9319 0.000021554, 0.000022825
2016-05-19 07:49:48.733404, slv, 38eaa7fffe38476a(unknown)/177, 0.000020441, 0.000000572, 0.000022825, 0.000020454, -5648.180000000, S, 14104, 0.000020173, 181, -0.000000201, 9319 0.000020454, 0.000022825
2016-05-19 07:49:49.613603, slv, 38eaa7fffe38476a(unknown)/177, 0.000020469, 0.000000572, 0.000024086, 0.000020454, -5682.500000000, D, 13895, 0.000020173, 181, -0.000000201, 9319 0.000020454, 0.000024086
2016-05-19 07:49:49.733442, slv, 38eaa7fffe38476a(unknown)/177, 0.000020469, -0.000000559, 0.000024086, 0.000019338, -5682.500000000, S, 14105, 0.000020173, 181, -0.000000201, 9319 0.000019338, 0.000024086
2016-05-19 07:49:50.616489, slv, 38eaa7fffe38476a(unknown)/177, 0.000020488, -0.000000559, 0.000022825, 0.000019338, -5648.960000000, D, 13896, 0.000020173, 181, -0.000000201, 9319 0.000019338, 0.000022825
2016-05-19 07:49:50.733481, slv, 38eaa7fffe38476a(unknown)/177, 0.000020488, -0.000001407, 0.000022825, 0.000018804, -5648.960000000, S, 14106, 0.000020173, 181, -0.000000201, 9319 0.000018804, 0.000022825
2016-05-19 07:49:51.733544, slv, 38eaa7fffe38476a(unknown)/177, 0.000020488, -0.000002960, 0.000022825, 0.000016252, -5564.540000000, S, 14107, 0.000020173, 181, -0.000000201, 9319 0.000016252, 0.000022825
2016-05-19 07:49:51.767033, slv, 38eaa7fffe38476a(unknown)/177, 0.000020486, -0.000002960, 0.000023072, 0.000016252, -5386.940000000, D, 13897, 0.000020173, 181, -0.000000201, 9319 0.000016252, 0.000023072
2016-05-19 07:49:52.733485, slv, 38eaa7fffe38476a(unknown)/177, 0.000020486, -0.000002959, 0.000023072, 0.000018804, -5386.940000000, S, 14108, 0.000020173, 181, -0.000000201, 9319 0.000018804, 0.000023072
2016-05-19 07:49:52.743201, slv, 38eaa7fffe38476a(unknown)/177, 0.000020483, -0.000002959, 0.000023072, 0.000018804, -5209.400000000, D, 13898, 0.000020173, 181, -0.000000201, 9319 0.000018804, 0.000023072
2016-05-19 07:49:53.481468, slv, 38eaa7fffe38476a(unknown)/177, 0.000020475, -0.000002959, 0.000019125, 0.000018804, -5209.400000000, D, 13899, 0.000020173, 181, -0.000000201, 9319 0.000018804, 0.000019125
2016-05-19 07:49:53.733596, slv, 38eaa7fffe38476a(unknown)/177, 0.000020475, -0.000001676, 0.000019125, 0.000018804, -5209.400000000, S, 14109, 0.000020173, 181, -0.000000201, 9319 0.000018804, 0.000019125
2016-05-19 07:49:54.733632, slv, 38eaa7fffe38476a(unknown)/177, 0.000020475, -0.000001634, 0.000019125, 0.000018876, -5108.840000000, S, 14110, 0.000020173, 181, -0.000000201, 9319 0.000018876, 0.000019125
2016-05-19 07:49:55.469639, slv, 38eaa7fffe38476a(unknown)/177, 0.000020440, -0.000001634, 0.000016113, 0.000018876, -5010.800000000, D, 13900, 0.000020173, 181, -0.000000201, 9319 0.000018876, 0.000016113
2016-05-19 07:49:55.733633, slv, 38eaa7fffe38476a(unknown)/177, 0.000020440, -0.000000387, 0.000016113, 0.000021265, -5010.800000000, S, 14111, 0.000020173, 181, -0.000000201, 9319 0.000021265, 0.000016113
2016-05-19 07:49:56.733613, slv, 38eaa7fffe38476a(unknown)/177, 0.000020440, 0.000001370, 0.000016113, 0.000022357, -4987.580000000, S, 14112, 0.000020173, 181, -0.000000201, 9319 0.000022357, 0.000016113
2016-05-19 07:49:57.175217, slv, 38eaa7fffe38476a(unknown)/177, 0.000020405, 0.000001370, 0.000015362, 0.000022357, -5069.780000000, D, 13901, 0.000020173, 181, -0.000000201, 9319 0.000022357, 0.000015362
2016-05-19 07:49:57.191015, slv, 38eaa7fffe38476a(unknown)/177, 0.000020380, 0.000001370, 0.000015197, 0.000022357, -5069.780000000, D, 13902, 0.000020173, 181, -0.000000201, 9319 0.000022357, 0.000015197
2016-05-19 07:49:57.733700, slv, 38eaa7fffe38476a(unknown)/177, 0.000020380, 0.000001946, 0.000015197, 0.000022357, -5069.780000000, S, 14113, 0.000020173, 181, -0.000000201, 9319 0.000022357, 0.000015197
2016-05-19 07:49:58.733717, slv, 38eaa7fffe38476a(unknown)/177, 0.000020380, 0.000003311, 0.000015197, 0.000025027, -5186.540000000, S, 14114, 0.000020173, 181, -0.000000201, 9319 0.000025027, 0.000015197
2016-05-19 07:49:58.762211, slv, 38eaa7fffe38476a(unknown)/177, 0.000020369, 0.000003311, 0.000016113, 0.000025027, -5385.200000000, D, 13903, 0.000020173, 181, -0.000000201, 9319 0.000025027, 0.000016113
2016-05-19 07:49:59.733707, slv, 38eaa7fffe38476a(unknown)/177, 0.000020369, 0.000003317, 0.000016113, 0.000022357, -5385.200000000, S, 14115, 0.000020173, 181, -0.000000201, 9319 0.000022357, 0.000016113
2016-05-19 07:50:00.446495, slv, 38eaa7fffe38476a(unknown)/177, 0.000020362, 0.000003317, 0.000016113, 0.000022357, -5584.220000000, D, 13904, 0.000020173, 181, -0.000000201, 9319 0.000022357, 0.000016113
2016-05-19 07:50:00.733792, slv, 38eaa7fffe38476a(unknown)/177, 0.000020362, 0.000001621, 0.000016113, 0.000021616, -5584.220000000, S, 14116, 0.000020173, 181, -0.000000201, 9319 0.000021616, 0.000016113
2016-05-19 07:50:01.204716, slv, 38eaa7fffe38476a(unknown)/177, 0.000020345, 0.000001621, 0.000017094, 0.000021616, -5681.480000000, D, 13905, 0.000020173, 181, -0.000000201, 9319 0.000021616, 0.000017094
2016-05-19 07:50:01.641438, slv, 38eaa7fffe38476a(unknown)/177, 0.000020353, 0.000001621, 0.000023199, 0.000021616, -5681.480000000, D, 13906, 0.000020173, 181, -0.000000201, 9319 0.000021616, 0.000023199
2016-05-19 07:50:01.733807, slv, 38eaa7fffe38476a(unknown)/177, 0.000020353, 0.000000827, 0.000023199, 0.000020754, -5681.480000000, S, 14117, 0.000020173, 181, -0.000000201, 9319 0.000020754, 0.000023199
2016-05-19 07:50:02.733844, slv, 38eaa7fffe38476a(unknown)/177, 0.000020353, 0.000000000, 0.000023199, 0.000019953, -5731.100000000, S, 14118, 0.000020173, 181, -0.000000201, 9319 0.000019953, 0.000023199
2016-05-19 07:50:03.607441, slv, 38eaa7fffe38476a(unknown)/177, 0.000020387, 0.000000000, 0.000025330, 0.000019953, -5731.100000000, D, 13907, 0.000020173, 181, -0.000000201, 9319 0.000019953, 0.000025330
2016-05-19 07:50:03.733860, slv, 38eaa7fffe38476a(unknown)/177, 0.000020387, -0.000001449, 0.000025330, 0.000017888, -5731.100000000, S, 14119, 0.000020173, 181, -0.000000201, 9319 0.000017888, 0.000025330
2016-05-19 07:50:04.733886, slv, 38eaa7fffe38476a(unknown)/177, 0.000020387, -0.000002581, 0.000025330, 0.000017723, -5644.160000000, S, 14120, 0.000020173, 181, -0.000000201, 9319 0.000017723, 0.000025330
2016-05-19 07:50:04.795268, slv, 38eaa7fffe38476a(unknown)/177, 0.000020405, -0.000002581, 0.000023199, 0.000017723, -5489.300000000, D, 13908, 0.000020173, 181, -0.000000201, 9319 0.000017723, 0.000023199
2016-05-19 07:50:05.733864, slv, 38eaa7fffe38476a(unknown)/177, 0.000020405, -0.000002673, 0.000023199, 0.000017723, -5489.300000000, S, 14121, 0.000020173, 181, -0.000000201, 9319 0.000017723, 0.000023199
2016-05-19 07:50:05.740550, slv, 38eaa7fffe38476a(unknown)/177, 0.000020406, -0.000002673, 0.000023199, 0.000017723, -5328.920000000, D, 13909, 0.000020173, 181, -0.000000201, 9319 0.000017723, 0.000023199
2016-05-19 07:50:06.427640, slv, 38eaa7fffe38476a(unknown)/177, 0.000020407, -0.000002673, 0.000023199, 0.000017723, -5328.920000000, D, 13910, 0.000020173, 181, -0.000000201, 9319 0.000017723, 0.000023199
2016-05-19 07:50:06.733949, slv, 38eaa7fffe38476a(unknown)/177, 0.000020407, -0.000002600, 0.000023199, 0.000017888, -5328.920000000, S, 14122, 0.000020173, 181, -0.000000201, 9319 0.000017888, 0.000023199
2016-05-19 07:50:07.733876, slv, 38eaa7fffe38476a(unknown)/177, 0.000020407, -0.000000504, 0.000023199, 0.000021918, -5172.920000000, S, 14123, 0.000020428, 45, -0.000000225, 1994 0.000021918, 0.000023199
2016-05-19 07:50:08.256707, slv, 38eaa7fffe38476a(unknown)/177, 0.000020404, -0.000000504, 0.000017965, 0.000021918, -5142.680000000, D, 13911, 0.000020428, 45, -0.000000225, 1994 0.000021918, 0.000017965
2016-05-19 07:50:08.733980, slv, 38eaa7fffe38476a(unknown)/177, 0.000020404, 0.000002779, 0.000017965, 0.000024452, -5142.680000000, S, 14124, 0.000020428, 45, -0.000000225, 1994 0.000024452, 0.000017965
2016-05-19 07:50:09.432875, slv, 38eaa7fffe38476a(unknown)/177, 0.000020421, 0.000002779, 0.000021567, 0.000024452, -5309.420000000, D, 13912, 0.000020428, 45, -0.000000225, 1994 0.000024452, 0.000021567
2016-05-19 07:50:09.733973, slv, 38eaa7fffe38476a(unknown)/177, 0.000020421, 0.000002696, 0.000021567, 0.000021766, -5309.420000000, S, 14125, 0.000020428, 45, -0.000000225, 1994 0.000021766, 0.000021567
2016-05-19 07:50:10.734056, slv, 38eaa7fffe38476a(unknown)/177, 0.000020421, 0.000001344, 0.000021567, 0.000021766, -5471.180000000, S, 14126, 0.000020428, 45, -0.000000225, 1994 0.000021766, 0.000021567
2016-05-19 07:50:10.741390, slv, 38eaa7fffe38476a(unknown)/177, 0.000020451, 0.000001344, 0.000021567, 0.000021766, -5551.820000000, D, 13913, 0.000020428, 45, -0.000000225, 1994 0.000021766, 0.000021567
2016-05-19 07:50:11.053012, slv, 38eaa7fffe38476a(unknown)/177, 0.000020470, 0.000001344, 0.000021567, 0.000021766, -5551.820000000, D, 13914, 0.000020428, 45, -0.000000225, 1994 0.000021766, 0.000021567
2016-05-19 07:50:11.587669, slv, 38eaa7fffe38476a(unknown)/177, 0.000020494, 0.000001344, 0.000023041, 0.000021766, -5551.820000000, D, 13915, 0.000020428, 45, -0.000000225, 1994 0.000021766, 0.000023041
2016-05-19 07:50:11.701399, slv, 38eaa7fffe38476a(unknown)/177, 0.000020524, 0.000001344, 0.000023202, 0.000021766, -5551.820000000, D, 13916, 0.000020428, 45, -0.000000225, 1994 0.000021766, 0.000023202
2016-05-19 07:50:11.734075, slv, 38eaa7fffe38476a(unknown)/177, 0.000020524, 0.000000315, 0.000023202, 0.000019810, -5551.820000000, S, 14127, 0.000020428, 45, -0.000000225, 1994 0.000019810, 0.000023202
2016-05-19 07:50:12.734042, slv, 38eaa7fffe38476a(unknown)/177, 0.000020524, -0.000001198, 0.000023202, 0.000018841, -5570.720000000, S, 14128, 0.000020428, 45, -0.000000225, 1994 0.000018841, 0.000023202
2016-05-19 07:50:13.640560, slv, 38eaa7fffe38476a(unknown)/177, 0.000020542, -0.000001198, 0.000022889, 0.000018841, -5498.840000000, D, 13917, 0.000020428, 45, -0.000000225, 1994 0.000018841, 0.000022889
2016-05-19 07:50:13.734093, slv, 38eaa7fffe38476a(unknown)/177, 0.000020542, -0.000001755, 0.000022889, 0.000018713, -5498.840000000, S, 14129, 0.000020428, 45, -0.000000225, 1994 0.000018713, 0.000022889
2016-05-19 07:50:14.624282, slv, 38eaa7fffe38476a(unknown)/177, 0.000020547, -0.000001755, 0.000022889, 0.000018713, -5393.540000000, D, 13918, 0.000020428, 45, -0.000000225, 1994 0.000018713, 0.000022889
2016-05-19 07:50:14.734091, slv, 38eaa7fffe38476a(unknown)/177, 0.000020547, -0.000001767, 0.000022889, 0.000018841, -5393.540000000, S, 14130, 0.000020428, 45, -0.000000225, 1994 0.000018841, 0.000022889
2016-05-19 07:50:15.734100, slv, 38eaa7fffe38476a(unknown)/177, 0.000020547, -0.000001706, 0.000022889, 0.000018841, -5287.520000000, S, 14131, 0.000020428, 45, -0.000000225, 1994 0.000018841, 0.000022889
NIC:
Intel i350
03:00.1 0200: 8086:1521 (rev 01)
Subsystem: 103c:339e
Kernel driver in use: igb
clock:allow_step_backwards = y
Thank you!
OK - this is a completely different issue.
I see your system clock is showing up with reference "EXT" - I take it you have made system clock the master clock (for when your node becomes a PTP master).
The correct behaviour in this situation should be that a PTP reference is preferred over an EXT reference when it is available - I need to re-test this.
Thanks,
Wojciech
sodding SourceForge... Four out of five times when I press "post", I lose my message and it's not posted. And the one time it does, I get all content and forget to copy the next one before trying to post! </rant>
I have just pushed a change to my 2.3.2-linuxphc branch which fixes your situation. The master clock is now only used when PTPd is running as master or passive, and will otherwise happily sync to whatever best clock is selected. The reference name was also changed to "PREFMST" so it can be clearly identified. This has been tested successfully when switching between MASTER / SLAVE / PASSIVE.
FYI - the log file you sent is not the log file, it is the statistics file. The actual logs (which are pretty rich) go to syslog, unless you specify a log file - check the man page / ptpd help / hw config example.
Thanks,
Wojciech
OK, based on what you said I removed the clock:masterclockname = "syst" option and the clock did eventually sync in slave-only mode. It took longer than I expected so I may not have noticed it when I was trying various options. I will also need the masterslave mode so I am gald you were able to reproduce and fix the issue. I will update and retest tomorrow.
Many thanks,
Dan
Second post due to SourceForge posting
I pulled the updates and tried to build. Running autoconf -vi produces an error in .configure
596: PACKAGE_URL='http://github.com/ptpd/ptpd
'
Don't know where this is pulled from but...fyi.
...
using ./test/linuxphc_hw.conf with the following mods:
clock:allow_step_backwards=Y
clock:allow_step_backwards_hw=Y
clock:step_startup_force=y
clock:step_startup=y
clock:set_rtc_on_step=y
Results:
GM:
Clock 1: syst : name: syst state: LOCKED ref: PREFMST
Clock 2: enp3s0f1 : name: enp3s0f1 state: LOCKED ref: syst
Clock 1: syst : offs: 0.000000000 adev: 0.000 freq: 0.000
Clock 2: enp3s0f1 : offs: 0.000000003 adev: 4.259 freq: -5433.762
Slave:
Clock 1: syst : name: syst state: FREERUN ref: none
Clock 2: enp3s0f1 : name: enp3s0f1 state: TRACKING ref: PTP
Clock 1: syst : offs: 0.000000000 adev: 0.000 freq: 7798.843
Clock 2: enp3s0f1 : offs: 0.000346228 adev: 0.000 freq: 319281.778
I can't tell if the system clock is being slewed or not but there is definitely not a step occurring at startup. Any ideas what settings may be affecting this? I would prefer a step to occur if the offset was greater than X (forward or back).
Thanks,
Dan
Hi,
Thanks - there was an issue with some quotes around variables that affected some autoconf versions. This now builds cleanly. The URL is the url of the official ptpd repo - which is where this code is going when it's ready.
OK - I need to post some documentation about the clock model in the new code.
The system clock will only sync when the PTP clock is in LOCKED state. In your example, the NIC clock is TRACKING, so the system clock will not sync to it. This behaviour is meant to protect clocks from being dragged around if the source clock is misbehaving. So if your PTP clock is in good sync, OS clock syncs to it. If it goes wild, it goes out of LOCKED state and the OS clock detaches to protect its stability, and will re-sync when PTP is back in LOCKED.
The state is based on the short term Allan deviation (adev) value, it has a high and low watermark setting (low is to enter LOCKED state, high is to leave it). Grep the built-in help for "adev" to see which settings control this. These settings are separate for hardware and for software clocks.
At very low message rates, when outlier filters are enabled and when the network is very noisy, things may take a while to stabilise. In your first output there was "Clock 2: enp3s0f0 : offs: -0.000001664 adev: 4001.599 freq: -6992.020" - if 4000 is as low as it gets, you may want to set your threshold to that.
The general rule is that you need to observe your clocks when you deploy them and see how they play with your network, and then set the various filter thresholds based on that. I would also recommend to set higher message rates, 4/sec or 8/sec or more. If the network is noisy, more samples for filters to choose from always helps.
Comment re. stepping at certain thresholds noted, this is on my to-do list. Again, the principle with ptpd is to do the least amount of damage to clocks. Some care about the PTP clock (say if they use it for packet timestamping) so would prefer the clock not to be stepped at will, some only use it as a means to deliver time to the OS clocks.
Does your PTP NIC reach the LOCKED state at all? What are the network conditions like?
Watch the commits in that branch, I will be adding a step threshold.
Thanks,
Wojciech
...and by the way - while some PTP clients do this, I think the decision to step the clock needs a more thoughtful approach. If you just blindly step when a threshold is crossed, this may do more damage than necessary. Say, you had a network event which caused the offset to look very high for say ten seconds. You see the offset, step the clock, offset goes away, then the event passes and you step it back because it is now off again. The better way is that an outlier filter holds / blocks the offset for some period of time and lets go only if enough time has passed - which is what PTPd aims to do.
Thanks,
Wojciech
I hear ya. I figured there was an aversion to stepping the clock for good reasons. The one exception that I think seems reasonable would be at startup. I see that there is an option for that but perhaps my problem is rooted in the NIC clock attaining the LOCKED state. I will watch this and let you know.
I have been moving the GM source clock around on occasion to see how the system responds. I am protyping the use of PTP for an embedded system. My test rig is three nodes - one GM and two slaves. I will need the slaves to become the GM if/when GM fails. No real traffic in the system other than PTP, metrics collection, and display. I do not have a 1588 switch yet, I will be adding one with a transparent clock shortly.
If the system can sync up at startup, then there should be no need to step - even after failover - and yes, timestamping is the primary goal here. The objective system does not have a battery on board so the rtc will be zero at boot.
I will do more testing on Monday and try your suggestions. Thank you Wojciech.
Thanks,
Dan
Following you guidance, I tweaked the servo:adev settings - but no change. Monitoring the .status file, I see that the slave system starts up with both hw and system clocking in FREERUN. The phc eventually attains LOCKED state (sometimes) and syst clock moves to the 'STEP 5' state. The higer message rates (and latger servo:adev window) seem to keep the ptp clock from flipping between LOCKED and TRACKING, but the syst clock is still not stepped.
What do you think?
Thanks,
Dan
Hi Dan,
If you actually watch the status file (as in, with the watch command if you have it in your shell -
watch -n 1 cat somefile- you will see that the number after "STEP" is a countdown.See these two settings:
ptpengine:panic_mode
ptpengine:panic_mode_duration
This is disabled by default but if you'e using linuxphc_hw.conf, it is set to 60 sec. This should count down 5.4.3.2.1 and then step. Does it do that?
If you want to step immediately in cases like this, then set panic mode to n.
Thanks,
Wojciech
Yes, I've been using 'watch' on the status file. It was hanging on STEP 5 indefinitely.
However, I have noe set ptpengine:panic_mode=n and it works much better. I will tweak it in and let you know if I observe the hanging behaviour again. Perhaps I'll set the panic duration to a lower value - say 3.
Thanks,
Dan