Re: [Linuxptp-users] phc offset explodes after a while

[Koehrer M. (ETAS/ESW5) <mat...@et...>]

Hi all,

thanks for the feedback.
I did some new tests...
> 
> Your PCA (64 bit kernel) is the slave, and your PCB (32 bit kernel) is
> the master. The source of the problem is in the master.
> 
> 1. Maybe there is another program on host PCB that is resetting the
>    time of the PTP clock?
No, I checked already for that.
Without running the ptp tools, there is no time jump at all.

 
> 2. What happens when you run with the roles reversed?
>    Use ptp4l -s on host PCB.
The same behaviour happens - now on the other PC.
I think this is no wonder as both are using the same type of NIC.

> 3. On host PCB, try the following script with nothing else running.
> 
> 	testptp -s
> 	while [ 1 ]; do
> 		date;
> 		testptp -g;
> 		sleep 1;
> 	done
> 
>    Does the sudden jump in time also occur?  The testptp program is
>    under /Documentation/ptp in the Linux kernel sources.
OK, I did this using my original setup. PCB is master, PCA is slave.
On PCB I added your proposed commands and logged the output 
via "logger" to the log file to have all results in a single file per PC.

------- BEGIN PCB (Master) --------
Jan 31 09:55:08 pcb testptp: clock time: 1391158543.964709305 or Fri Jan 31 09:55:43 2014
Jan 31 09:55:09 pcb phc2sys: [5455.412] phc offset     -1124 s2 freq   -2642 delay   4120
Jan 31 09:55:09 pcb date: Fri Jan 31 09:55:09 CET 2014
Jan 31 09:55:09 pcb testptp: clock time: 1391158544.967732260 or Fri Jan 31 09:55:44 2014
Jan 31 09:55:10 pcb phc2sys: [5456.412] phc offset      6967 s2 freq   +5112 delay   4120
Jan 31 09:55:10 pcb date: Fri Jan 31 09:55:10 CET 2014
Jan 31 09:55:10 pcb testptp: clock time: 1391158545.970753621 or Fri Jan 31 09:55:45 2014
Jan 31 09:55:11 pcb phc2sys: [5457.413] phc offset      6980 s2 freq   +7215 delay   4119
Jan 31 09:55:11 pcb date: Fri Jan 31 09:55:11 CET 2014
Jan 31 09:55:11 pcb testptp: clock time: 1391158546.973770115 or Fri Jan 31 09:55:46 2014
Jan 31 09:55:12 pcb phc2sys: [5458.413] phc offset      -620 s2 freq   +1709 delay   4119
Jan 31 09:55:12 pcb date: Fri Jan 31 09:55:12 CET 2014
Jan 31 09:55:12 pcb testptp: clock time: 1391158547.976781979 or Fri Jan 31 09:55:47 2014
Jan 31 09:55:13 pcb phc2sys: [5459.413] phc offset 70368744182224 s2 freq +599999999 delay   4119
Jan 31 09:55:13 pcb date: Fri Jan 31 09:55:13 CET 2014
************ Here is the jump:
Jan 31 09:55:13 pcb testptp: clock time: 1391228917.600794255 or Sat Feb  1 05:28:37 2014
Jan 31 09:55:14 pcb phc2sys: [5460.413] phc offset 70368144122243 s2 freq +599999999 delay   1600
Jan 31 09:55:14 pcb date: Fri Jan 31 09:55:14 CET 2014
Jan 31 09:55:14 pcb testptp: clock time: 1391228918.002014685 or Sat Feb  1 05:28:38 2014
Jan 31 09:55:15 pcb phc2sys: [5461.413] phc offset 70367544038218 s2 freq +599999999 delay   1648
Jan 31 09:55:15 pcb date: Fri Jan 31 09:55:15 CET 2014
Jan 31 09:55:15 pcb testptp: clock time: 1391228918.403224428 or Sat Feb  1 05:28:38 2014
Jan 31 09:55:16 pcb phc2sys: [5462.413] phc offset 70366943954855 s2 freq +599999999 delay   1648
Jan 31 09:55:16 pcb date: Fri Jan 31 09:55:16 CET 2014
Jan 31 09:55:16 pcb testptp: clock time: 1391228918.804436187 or Sat Feb  1 05:28:38 2014
----------- END PCB --------------

------------- BEGIN PCA (Slave) ----------------
Jan 31 09:55:10 pca ptp4l: [5467.031] ingress:1391158545769528578  origin:1391158545769530044 path_delay:733 c1:0 c2:0
Jan 31 09:55:10 pca ptp4l: [5467.031] master offset      -2199 s2 freq  -10448 path delay       733
Jan 31 09:55:11 pca phc2sys: [5467.603] phc offset      4115 s2 freq  +31537 delay   6748
Jan 31 09:55:11 pca ptp4l: [5468.031] ingress:1391158546769555014  origin:1391158546769547343 path_delay:734 c1:0 c2:0
Jan 31 09:55:11 pca ptp4l: [5468.031] master offset       6937 s2 freq   -1972 path delay       734
Jan 31 09:55:12 pca phc2sys: [5468.604] phc offset     -2634 s2 freq  +26022 delay   6810
Jan 31 09:55:12 pca ptp4l: [5469.031] ingress:1391158547769564771  origin:1391158547769554271 path_delay:736 c1:0 c2:0
Jan 31 09:55:12 pca ptp4l: [5469.031] master offset       9764 s2 freq   +2936 path delay       736
Jan 31 09:55:13 pca phc2sys: [5469.604] phc offset      8630 s2 freq  +36496 delay   6763
Jan 31 09:55:13 pca ptp4l: [5470.031] ingress:1391158548769579072  origin:1391158548769576093 path_delay:738 c1:0 c2:0
Jan 31 09:55:13 pca ptp4l: [5470.031] master offset       2241 s2 freq   -1658 path delay       738
Jan 31 09:55:14 pca phc2sys: [5470.604] phc offset     12870 s2 freq  +43325 delay   6555
********** Here is the jump:
Jan 31 09:55:14 pca ptp4l: [5471.031] ingress:1391158549769582167  origin:1391228917916706058 path_delay:3137 c1:0 c2:0
Jan 31 09:55:14 pca ptp4l: [5471.031] master offset -70368147127028 s2 freq -599999999 path delay      3137
Jan 31 09:55:15 pca phc2sys: [5471.604] phc offset -343848810 s2 freq -500000 delay   6105
Jan 31 09:55:15 pca ptp4l: [5472.031] ingress:1391158551368868373  origin:1391228918316714536 path_delay:7912 c1:0 c2:0
Jan 31 09:55:15 pca ptp4l: [5472.031] master offset -70366947854075 s2 freq -599999999 path delay      7912
Jan 31 09:55:16 pca phc2sys: [5472.604] phc offset -943159536 s2 freq -500000 delay   6752
Jan 31 09:55:16 pca ptp4l: [5473.032] ingress:1391158552968869361  origin:1391228918716717414 path_delay:12701 c1:0 c2:0
Jan 31 09:55:16 pca ptp4l: [5473.032] master offset -70365747860754 s2 freq -599999999 path delay     12701
Jan 31 09:55:17 pca phc2sys: [5473.605] phc offset -1542448802 s2 freq -500000 delay   6090
------------ END PCA ---------------

I wonder why the time presented by the testptp program does not fit to  the system time. Here is always a delta of about 35 seconds.

I hope that helps to identify the issue.

Thanks a lot

Mathias