Hi guys,
Some of my PTP clients can't restore after delay correction and It's pretty random. "Slave to Master" wasn't corrected. It comes back only after ptp daemon restarting. Is it a bug or I should turn on some options in ptpd2.conf?
2015-09-21 09:43:01.528976 ptpd2[100533].eth4.400 (warning) (slv) UTC Offset no longer valid - clock jump expected
2015-09-21 09:43:03.037975 ptpd2[100533].eth4.400 (info) (slv) Servo: Ignoring delayResp because of large OFM
2015-09-21 09:43:03.207580 ptpd2[100533].eth4.400 (critical) (slv) Offset above 1 second - entering panic mode
2015-09-21 09:43:15.662984 ptpd2[100533].eth4.400 (info) (slv) Servo: Ignoring delayResp because of large OFM
2015-09-21 09:43:16.208804 ptpd2[100533].eth4.400 (notice) (slv) Offset below 1 second again: exiting panic mode
2015-09-21 09:43:16.912984 ptpd2[100533].eth4.400 (info) (slv) Servo: Ignoring delayResp because of large OFM
2015-09-21 09:43:17.100481 ptpd2[100533].eth4.400 (info) (slv) Servo: Ignoring delayResp because of large OFM
2015-09-21 09:43:18.412983 ptpd2[100533].eth4.400 (info) (slv) Servo: Ignoring delayResp because of large OFM
etc.
STATS:
#Timestamp, State, Clock ID, One Way Delay, Offset From Master, Slave to Master, Master to Slave, Observed Drift, Last packet Received, One Way Delay Mean, One Way Delay Std Dev, Offset From Master Mean, Offset From Master Std Dev, Observed Drift Mean, Observed Drift Std Dev
Firstly, it's best to move up to ptpd 2.3.1 - many bugfixes and features, some include improvements to failover and recovery from issues like this.
Second - what you are seeing is the effect of a clock jump. This is the key:
2015-09-21 09:43:01.528976 ptpd2[100533].eth4.400 (warning) (slv) UTC Offset no longer valid - clock jump expected
For whatever reason your GM stopped sending the currentUtcOffsetValid flag, but it kept sending the UTC offset (36 seconds). As a result, the UTC offset was ignored and the offset from master 36. PTPd will ignore Delay Response when offset is above 1 second.
You should probably check your GM - has something happened to it? Is it getting time from GPS and has it lost signal or restarted? Looks like your GM clears the utc_valid flag, but still sends the value of the UTC to TAI offset.
You may want to set PTPd to always respect the UTC offset and thus prevent it from clock jumps caused by this:
ptpengine:always_respect_utc_offset=Y
A minor update, ptpd 2.3.1.1, is about to be released, and from that version this is set to Y by default.
If you would like to refer to this comment somewhere else in this project, copy and paste the following link:
Looking at the MAC address / clock ID of your GM, it's a Symmetricom box, so a hardware GM. Most likely its timing degraded somehow (lost GPS?) and that's why it cleared the UTCV flag. Most likely also its ClockClass dropped. Have you got only one GM or multiple ones?
If you would like to refer to this comment somewhere else in this project, copy and paste the following link:
Thank you so much,Wojciech! We'are getting data from our Data Center source. We sent them all that you suggested to check out. Meanwhile, I've upgraded ptpd to ptpd-2.3.1-2.el7.x86_64 (CentOS7.1.1503) and ptpd-2.3.1-1.el6.x86_64 (CentOS6.6), but I got this issue on both boxes: 2015-09-21 16:30:32.331125 ptpd2[47359].eth4.400 (error) (slv) Error while writing statistics (strerror: Interrupted system call). Looks like logging related issue in logStatistics() function. So, daemon starts with root rights, successfully creating/updating/removing ptpd2.lock, ptpd2.status, ptpd2_kernelclock.drift, ptpd2.log and ptpd2.stats.
If you would like to refer to this comment somewhere else in this project, copy and paste the following link:
Hi guys,
Some of my PTP clients can't restore after delay correction and It's pretty random. "Slave to Master" wasn't corrected. It comes back only after ptp daemon restarting. Is it a bug or I should turn on some options in ptpd2.conf?
ptpd-2.3.0-3
2015-09-21 09:43:15.663013, slv, 001c73ffffcdef7f(unknown)/0100b0aefffe029092, 0.000001375, -35.999997125, 23.412501769, -35.999995750, -55042.621999998, D, 0.000001261, 11, 0.000000033, 800, -55042, 1
fixed everything exept "Slave to Master"
2015-09-21 09:43:16.208829, slv, 001c73ffffcdef7f(unknown)/0100b0aefffe029092, 0.000001375, 0.000001507, 23.412501769, 0.000004389, -55041.114999998, S, 0.000001261, 11, 0.000000033, 800, -55042, 1
LOGS:
2015-09-21 09:43:01.528976 ptpd2[100533].eth4.400 (warning) (slv) UTC Offset no longer valid - clock jump expected
2015-09-21 09:43:03.037975 ptpd2[100533].eth4.400 (info) (slv) Servo: Ignoring delayResp because of large OFM
2015-09-21 09:43:03.207580 ptpd2[100533].eth4.400 (critical) (slv) Offset above 1 second - entering panic mode
2015-09-21 09:43:15.662984 ptpd2[100533].eth4.400 (info) (slv) Servo: Ignoring delayResp because of large OFM
2015-09-21 09:43:16.208804 ptpd2[100533].eth4.400 (notice) (slv) Offset below 1 second again: exiting panic mode
2015-09-21 09:43:16.912984 ptpd2[100533].eth4.400 (info) (slv) Servo: Ignoring delayResp because of large OFM
2015-09-21 09:43:17.100481 ptpd2[100533].eth4.400 (info) (slv) Servo: Ignoring delayResp because of large OFM
2015-09-21 09:43:18.412983 ptpd2[100533].eth4.400 (info) (slv) Servo: Ignoring delayResp because of large OFM
etc.
STATS:
#Timestamp, State, Clock ID, One Way Delay, Offset From Master, Slave to Master, Master to Slave, Observed Drift, Last packet Received, One Way Delay Mean, One Way Delay Std Dev, Offset From Master Mean, Offset From Master Std Dev, Observed Drift Mean, Observed Drift Std Dev
2015-09-21 09:43:02.207476, slv, 001c73ffffcdef7f(unknown)/01fc9947fffe552001, 0.000001272, -0.000000178, 0.000000828, 0.000001798, -55042.621999998, S, 0.000001261, 11, 0.000000033, 800, -55042, 1
2015-09-21 09:43:03.037994, slv, 001c73ffffcdef7f(unknown)/01fc9947fffe552001, 0.000001272, -0.000000178, 36.000001863, 0.000001798, -55042.621999998, D, 0.000001261, 11, 0.000000033, 800, -55042, 1
2015-09-21 09:43:03.207598, slv, 001c73ffffcdef7f(unknown)/01fc9947fffe552001, 0.000001272, -36.000000445, 36.000001863, -35.999999173, -55042.621999998, S, 0.000001261, 11, 0.000000033, 800, -55042, 1
2015-09-21 09:43:04.207608, slv, 001c73ffffcdef7f(unknown)/01, 0.000001272, -35.999999901, 36.000001863, -35.999998629, -55042.621999998, S, 0.000001261, 11, 0.000000033, 800, -55042, 1
2015-09-21 09:43:04.975503, slv, 001c73ffffcdef7f(unknown)/01, 0.000000846, -35.999999901, 36.000002013, -35.999998629, -55042.621999998, D, 0.000001261, 11, 0.000000033, 800, -55042, 1
2015-09-21 09:43:05.207654, slv, 001c73ffffcdef7f(unknown)/01, 0.000000846, -36.000000012, 36.000002013, -35.999999166, -55042.621999998, S, 0.000001261, 11, 0.000000033, 800, -55042, 1
2015-09-21 09:43:06.207840, slv, 001c73ffffcdef7f(unknown)/01, 0.000000846, -35.999998786, 36.000002013, -35.999997940, -55042.621999998, S, 0.000001261, 11, 0.000000033, 800, -55042, 1
2015-09-21 09:43:06.725506, slv, 001c73ffffcdef7f(unknown)/01, 0.000001316, -35.999998786, 36.000001699, -35.999997940, -55042.621999998, D, 0.000001261, 11, 0.000000033, 800, -55042, 1
2015-09-21 09:43:06.788017, slv, 001c73ffffcdef7f(unknown)/01, 0.000001532, -35.999998786, 36.000002042, -35.999997940, -55042.621999998, D, 0.000001261, 11, 0.000000033, 800, -55042, 1
2015-09-21 09:43:07.207942, slv, 001c73ffffcdef7f(unknown)/01, 0.000001532, -36.000000495, 36.000002042, -35.999998963, -55042.621999998, S, 0.000001261, 11, 0.000000033, 800, -55042, 1
2015-09-21 09:43:08.207996, slv, 001c73ffffcdef7f(unknown)/01, 0.000001532, -36.000003811, 36.000002042, -36.000002279, -55042.621999998, S, 0.000001261, 11, 0.000000033, 800, -55042, 1
2015-09-21 09:43:08.225479, slv, 001c73ffffcdef7f(unknown)/01, 0.000001629, -36.000003811, 36.000005853, -36.000002279, -55042.621999998, D, 0.000001261, 11, 0.000000033, 800, -55042, 1
2015-09-21 09:43:08.725511, slv, 001c73ffffcdef7f(unknown)/01, 0.000001486, -36.000003811, 36.000002370, -36.000002279, -55042.621999998, D, 0.000001261, 11, 0.000000033, 800, -55042, 1
2015-09-21 09:43:09.208385, slv, 001c73ffffcdef7f(unknown)/01, 0.000001486, -36.250000840, 36.000002370, -36.249999354, -55042.621999998, S, 0.000001261, 11, 0.000000033, 800, -55042, 1
2015-09-21 09:43:09.600501, slv, 001c73ffffcdef7f(unknown)/01001c73ffff1f2278, 0.000001486, -36.250000840, 36.249996035, -36.249999354, -55042.621999998, D, 0.000001261, 11, 0.000000033, 800, -55042, 1
2015-09-21 09:43:10.208159, slv, 001c73ffffcdef7f(unknown)/01001c73ffff1f2278, 0.000001486, -36.249995422, 36.249996035, -36.249993936, -55042.621999998, S, 0.000001261, 11, 0.000000033, 800, -55042, 1
2015-09-21 09:43:10.412983, slv, 001c73ffffcdef7f(unknown)/01001c73ffff1f2278, 0.000001486, -36.249995422, 36.000006168, -36.249993936, -55042.621999998, D, 0.000001261, 11, 0.000000033, 800, -55042, 1
2015-09-21 09:43:10.913005, slv, 001c73ffffcdef7f(unknown)/01001c73ffff1f2278, 0.000001486, -36.249995422, 36.000006303, -36.249993936, -55042.621999998, D, 0.000001261, 11, 0.000000033, 800, -55042, 1
2015-09-21 09:43:11.208633, slv, 001c73ffffcdef7f(unknown)/01001c73ffff1f2278, 0.000001486, -36.000004450, 36.000006303, -36.000002964, -55042.621999998, S, 0.000001261, 11, 0.000000033, 800, -55042, 1
2015-09-21 09:43:11.413006, slv, 001c73ffffcdef7f(unknown)/01001c73ffff1f2278, 0.000001253, -36.000004450, 36.000003216, -36.000002964, -55042.621999998, D, 0.000001261, 11, 0.000000033, 800, -55042, 1
2015-09-21 09:43:12.208406, slv, 001c73ffffcdef7f(unknown)/01001c73ffff1edb9a, 0.000001253, -36.000000922, 36.000003216, -35.999999669, -55042.621999998, S, 0.000001261, 11, 0.000000033, 800, -55042, 1
2015-09-21 09:43:12.975496, slv, 001c73ffffcdef7f(unknown)/01001c73ffff1edb9a, 0.000001253, -36.000000922, 35.999999624, -35.999999669, -55042.621999998, D, 0.000001261, 11, 0.000000033, 800, -55042, 1
2015-09-21 09:43:13.208223, slv, 001c73ffffcdef7f(unknown)/01001c73ffff1edb9a, 0.000001253, -35.999997607, 35.999999624, -35.999996354, -55042.621999998, S, 0.000001261, 11, 0.000000033, 800, -55042, 1
2015-09-21 09:43:13.538014, slv, 001c73ffffcdef7f(unknown)/01001c73ffff1edb9a, 0.000001200, -35.999997607, 35.999999626, -35.999996354, -55042.621999998, D, 0.000001261, 11, 0.000000033, 800, -55042, 1
2015-09-21 09:43:13.600485, slv, 001c73ffffcdef7f(unknown)/01001c73ffff1edb9a, 0.000001297, -35.999997607, 36.000001001, -35.999996354, -55042.621999998, D, 0.000001261, 11, 0.000000033, 800, -55042, 1
2015-09-21 09:43:14.208643, slv, 001c73ffffcdef7f(unknown)/01001c73ffff1edb9a, 0.000001297, -35.999997447, 36.000001001, -35.999996150, -55042.621999998, S, 0.000001261, 11, 0.000000033, 800, -55042, 1
2015-09-21 09:43:14.225502, slv, 001c73ffffcdef7f(unknown)/01001c73ffff1edb9a, 0.000001375, -35.999997447, 35.999999483, -35.999996150, -55042.621999998, D, 0.000001261, 11, 0.000000033, 800, -55042, 1
2015-09-21 09:43:15.208787, slv, 001c73ffffcdef7f(unknown)/01001c73ffff1edb9a, 0.000001375, -35.999997125, 35.999999483, -35.999995750, -55042.621999998, S, 0.000001261, 11, 0.000000033, 800, -55042, 1
2015-09-21 09:43:15.663013, slv, 001c73ffffcdef7f(unknown)/0100b0aefffe029092, 0.000001375, -35.999997125, 23.412501769, -35.999995750, -55042.621999998, D, 0.000001261, 11, 0.000000033, 800, -55042, 1
2015-09-21 09:43:16.208829, slv, 001c73ffffcdef7f(unknown)/0100b0aefffe029092, 0.000001375, 0.000001507, 23.412501769, 0.000004389, -55041.114999998, S, 0.000001261, 11, 0.000000033, 800, -55042, 1
2015-09-21 09:43:16.913002, slv, 001c73ffffcdef7f(unknown)/0100b0aefffe029092, 0.000001375, 0.000001507, 23.412501769, 0.000004389, -55041.114999998, D, 0.000001261, 11, 0.000000033, 800, -55042, 1
2015-09-21 09:43:17.100499, slv, 001c73ffffcdef7f(unknown)/0100b0aefffe029092, 0.000001375, 0.000001507, 23.412501769, 0.000004389, -55041.114999998, D, 0.000001261, 11, 0.000000033, 800, -55042, 1
Last edit: Ivan 2015-09-21
Hi,
Firstly, it's best to move up to ptpd 2.3.1 - many bugfixes and features, some include improvements to failover and recovery from issues like this.
Second - what you are seeing is the effect of a clock jump. This is the key:
For whatever reason your GM stopped sending the
currentUtcOffsetValidflag, but it kept sending the UTC offset (36 seconds). As a result, the UTC offset was ignored and the offset from master 36. PTPd will ignore Delay Response when offset is above 1 second.You should probably check your GM - has something happened to it? Is it getting time from GPS and has it lost signal or restarted? Looks like your GM clears the utc_valid flag, but still sends the value of the UTC to TAI offset.
You may want to set PTPd to always respect the UTC offset and thus prevent it from clock jumps caused by this:
A minor update, ptpd 2.3.1.1, is about to be released, and from that version this is set to Y by default.
Looking at the MAC address / clock ID of your GM, it's a Symmetricom box, so a hardware GM. Most likely its timing degraded somehow (lost GPS?) and that's why it cleared the UTCV flag. Most likely also its ClockClass dropped. Have you got only one GM or multiple ones?
Thank you so much,Wojciech! We'are getting data from our Data Center source. We sent them all that you suggested to check out. Meanwhile, I've upgraded ptpd to ptpd-2.3.1-2.el7.x86_64 (CentOS7.1.1503) and ptpd-2.3.1-1.el6.x86_64 (CentOS6.6), but I got this issue on both boxes: 2015-09-21 16:30:32.331125 ptpd2[47359].eth4.400 (error) (slv) Error while writing statistics (strerror: Interrupted system call). Looks like logging related issue in logStatistics() function. So, daemon starts with root rights, successfully creating/updating/removing ptpd2.lock, ptpd2.status, ptpd2_kernelclock.drift, ptpd2.log and ptpd2.stats.