Re: [Linuxptp-users] clockcheck - need to filter large spurious phase jumps?
PTP IEEE 1588 stack for Linux
Brought to you by:
rcochran
Menu
▾
▴
Re: [Linuxptp-users] clockcheck - need to filter large spurious phase jumps?
|
From: Rich S. <sch...@gm...> - 2013-11-06 17:18:23
|
*1. Last night ptp4 and phc2sys got into a loop of sorts:* Nov 6 01:34:47 pluto ptp4l: [381207.181] master offset -3312879535876 s2 freq -599999999 path delay -332476904 Nov 6 01:34:47 pluto phc2sys: [381207.216] phc offset 3313004697655 s2 freq +500000 delay 4863 Nov 6 01:34:49 pluto ptp4l: [381209.180] master offset -3311679354743 s2 freq -599999999 path delay -332476904 Nov 6 01:34:51 pluto ptp4l: [381211.178] master offset -3310479396557 s2 freq -599999999 path delay -332476904 Nov 6 01:34:51 pluto phc2sys: [381211.216] phc offset 3310601232712 s2 freq +500000 delay 4713 Nov 6 01:34:52 pluto ptp4l: [381211.853] negative path delay -192163390 Nov 6 01:34:52 pluto ptp4l: [381211.853] path_delay = (t2 - t3) + (t4 - t1) Nov 6 01:34:52 pluto ptp4l: [381211.853] t2 - t3 = -1024845438 Nov 6 01:34:52 pluto ptp4l: [381211.853] t4 - t1 = +640518657 Nov 6 01:34:52 pluto ptp4l: [381211.853] c1 0 Nov 6 01:34:52 pluto ptp4l: [381211.853] c2 0 Nov 6 01:34:52 pluto ptp4l: [381211.854] c3 0 Nov 6 01:34:53 pluto ptp4l: [381213.178] master offset -3309260051493 s2 freq -599999999 path delay -351664636 Nov 6 01:34:55 pluto ptp4l: [381215.177] master offset -3308059890747 s2 freq -599999999 path delay -351664636 Nov 6 01:35:11 pluto phc2sys: [381231.217] phc offset -67053297050824 s2 freq -500000 delay 4718 Nov 6 01:35:13 pluto ptp4l: [381233.183] master offset 67052031445161 s2 freq +599999999 path delay -97064991 ... during the night a number of jumps are detected by phc2sys (lines deleted)... Nov 6 05:14:00 pluto ptp4l: [394359.794] master offset 66882744861346 s2 freq +599999999 path delay -32382521 Nov 6 05:14:00 pluto phc2sys: [394359.859] phc offset -66882716164068 s2 freq -500000 delay 4717 Nov 6 05:14:02 pluto ptp4l: [394361.796] master offset 66881544843520 s2 freq +599999999 path delay -32382521 Nov 6 05:14:04 pluto ptp4l: [394363.797] master offset 66880344836655 s2 freq +599999999 path delay -32382521 Nov 6 05:14:04 pluto phc2sys: [394363.859] phc offset -66880315280640 s2 freq -500000 delay 4717 Nov 6 05:14:06 pluto ptp4l: [394365.798] master offset 66879099025472 s2 freq +599999999 path delay 13411172 Nov 6 05:14:08 pluto ptp4l: [394367.799] master offset 66877899010215 s2 freq +599999999 path delay 13411172 Nov 6 05:14:08 pluto phc2sys: [394367.859] phc offset -66877914394903 s2 freq -500000 delay 4727 Nov 6 05:14:10 pluto ptp4l: [394369.800] master offset 66876589756605 s2 freq +599999999 path delay 122641620 ...lines deleted... Nov 6 06:40:17 pluto ptp4l: [399536.604] master offset 63777989946575 s2 freq +599999999 path delay 283612433 Nov 6 06:40:19 pluto ptp4l: [399538.605] master offset 63776799780537 s2 freq +599999999 path delay 273757038 Nov 6 06:40:20 pluto phc2sys: [399540.146] phc offset -134142308172546 s2 freq -500000 delay 4717 Nov 6 06:40:21 pluto ptp4l: [399540.605] clockcheck: clock jumped forward or running faster than expected! Nov 6 06:40:21 pluto ptp4l: [399540.606] master offset 134144343946703 s0 freq +0 path delay 273757038 ... lines deleted... Nov 6 06:41:11 pluto ptp4l: [399591.102] negative path delay -66539 Nov 6 06:41:11 pluto ptp4l: [399591.102] path_delay = (t2 - t3) + (t4 - t1) Nov 6 06:41:11 pluto ptp4l: [399591.102] t2 - t3 = -484054584 Nov 6 06:41:11 pluto ptp4l: [399591.102] t4 - t1 = +483921505 Nov 6 06:41:11 pluto ptp4l: [399591.102] c1 0 Nov 6 06:41:11 pluto ptp4l: [399591.102] c2 0 Nov 6 06:41:11 pluto ptp4l: [399591.102] c3 0 Nov 6 06:41:12 pluto phc2sys: [399592.148] phc offset 2561210209 s2 freq +500000 delay 4713 Nov 6 06:41:13 pluto ptp4l: [399592.586] master offset 31642 s2 freq -72514 path delay 1932384 Nov 6 06:41:15 pluto ptp4l: [399594.585] master offset 155956 s2 freq -5611 path delay 2021789 Nov 6 06:41:16 pluto phc2sys: [399596.149] phc offset 2558838385 s2 freq +500000 delay 4712 Nov 6 06:41:17 pluto ptp4l: [399596.584] master offset 235565 s2 freq +57587 path delay 2021789 Nov 6 06:41:19 pluto ptp4l: [399598.583] master offset 189166 s2 freq +69722 path delay 2021789 ... *2. This morning ptp4 reports that clock time is 17.1 hours offset:* Nov 6 16:14:27 pluto ptp4l: [433991.680] master offset 61591498021410 s2 freq +599999999 path delay 383379265 Nov 6 16:14:29 pluto ptp4l: [433993.680] master offset 61590330241412 s2 freq +599999999 path delay 351150078 Nov 6 16:14:31 pluto ptp4l: [433995.680] master offset 61589133175281 s2 freq +599999999 path delay 348198056 Nov 6 16:14:33 pluto ptp4l: [433997.680] master offset 61587955406085 s2 freq +599999999 path delay 325950874 Nov 6 16:14:35 pluto ptp4l: [433999.680] master offset 61586755389932 s2 freq +599999999 path delay 325950874 Nov 6 16:14:37 pluto ptp4l: [434001.680] master offset 61585555381755 s2 freq +599999999 path delay 325950874 Nov 6 16:14:39 pluto ptp4l: [434003.681] master offset 61584332985592 s2 freq +599999999 path delay 348330452 Nov 6 16:14:41 pluto ptp4l: [434005.681] master offset 61583132971605 s2 freq +599999999 path delay 348330452 Nov 6 16:14:43 pluto ptp4l: [434007.681] master offset 61581932953300 s2 freq +599999999 path delay 348330452 Nov 6 16:14:45 pluto ptp4l: [434009.681] master offset 61580761060120 s2 freq +599999999 path delay 320211807 Nov 6 16:14:47 pluto ptp4l: [434011.681] master offset 61579561037423 s2 freq +599999999 path delay 320211807 Nov 6 16:14:49 pluto ptp4l: [434013.681] master offset 61578361028013 s2 freq +599999999 path delay 320211807 Nov 6 16:14:51 pluto ptp4l: [434015.681] master offset 61577183886161 s2 freq +599999999 path delay 29733548217.1 Actually it is (24 - 17.1) = 6h 53m behind: root@pluto:/tmp# testptp -g -d /dev/ptp1;date clock time: 1383816008.279232658 or Thu Nov 7 09:20:08 2013 Wed Nov 6 16:12:23 UTC 2013 *3. I set the correct time on the clock using ntpdate, and sync the PHC:root@pluto:/tmp# testptp -s -d /dev/ptp1set time okayroot@pluto:/tmp# testptp -g -d /dev/ptp1;dateclock time: 1383754501.245498330 or Wed Nov 6 16:15:01 2013Wed Nov 6 16:14:59 UTC 20134. ptp4l responds:* Nov 6 16:14:53 pluto ptp4l: [434017.681] master offset 61575983886672 s2 freq +599999999 path delay 297335482 Nov 6 16:14:55 pluto ptp4l: [434019.680] clockcheck: clock jumped backward or running slower than expected! Nov 6 16:14:55 pluto ptp4l: [434019.681] master offset -360063735 s0 freq +0 path delay 277518883 Nov 6 16:14:55 pluto ptp4l: [434019.681] port 1: SLAVE to UNCALIBRATED on SYNCHRONIZATION_FAULT Nov 6 16:14:57 pluto ptp4l: [434021.681] master offset -1560079696 s1 freq -599999999 path delay 277518883 Nov 6 16:14:59 pluto ptp4l: [434023.681] master offset 1198240376 s2 freq -879811 path delay 277518883 Nov 6 16:14:59 pluto ptp4l: [434023.681] port 1: UNCALIBRATED to SLAVE on MASTER_CLOCK_SELECTED Nov 6 16:15:01 pluto ptp4l: [434025.681] master offset 1201022077 s2 freq +180247096 path delay 277518883 Nov 6 16:15:03 pluto ptp4l: [434027.682] master offset 840864807 s2 freq +180321772 path delay 277518883 Nov 6 16:15:05 pluto ptp4l: [434029.682] master offset 480264272 s2 freq +126151226 path delay 277518883 Nov 6 16:15:07 pluto ptp4l: [434031.682] master offset 277988358 s2 freq +97052910 path delay 227454323 ...lines deleted... *# testptp -g -d /dev/ptp1;dateclock time: 1383754506.107142710 or Wed Nov 6 16:15:06 2013Wed Nov 6 16:15:05 UTC 2013# testptp -s -d /dev/ptp1set time okay# testptp -g -d /dev/ptp1;dateclock time: 1383754512.793827793 or Wed Nov 6 16:15:12 2013Wed Nov 6 16:15:12 UTC 2013# testptp -g -d /dev/ptp1;dateclock time: 1383754517.291075454 or Wed Nov 6 16:15:17 2013Wed Nov 6 16:15:17 UTC 2013*... Now I'm running ptp4l without phc2sys and will watch for any clock jumps today. On Wed, Nov 6, 2013 at 5:22 AM, Richard Cochran <ric...@gm...>wrote: > On Tue, Nov 05, 2013 at 04:26:21PM -0500, Rich Schmidt wrote: > > This is Rich Schmidt, linuxptp newbie. > > > > I am testing linuxptp on this system at the US Naval Observatory: > > Supermicro SYS-5015A-EHF-D525 (Atom) > > Intel 82547L NICs driver: e1000e version: 2.5.4-NAPI firmware-version: > > 1.9-0 > > Debian with kernel 3.12.0-rc > > > > Running: > > Sync PHC to USNO Master Clock via Zyfer Gsync PTP GrandMaster: > > ptp4l -i eth1 -l 7 -s -p /dev/ptp1 > > > > Sync CLOCK_REALTIME to PHC: > > phc2sys -s /dev/ptp1 -L 100000000 -l 7 -R 0.25 -O 0 > > Can you try this again running ptp4l alone without phc2sys? > > If no funny offsets appear, this would indicate a certain kind of > driver problem, when both programs access the PHC. > > Thanks, > Richard > |
