linuxptp-users Mailing List for linuxptp (Page 29)
PTP IEEE 1588 stack for Linux
Brought to you by:
rcochran
Menu
▾
▴
linuxptp-users — Open discussion on using the linuxptp software.
You can subscribe to this list here.
| 2012 |
Jan
|
Feb
(10) |
Mar
(47) |
Apr
|
May
(26) |
Jun
(10) |
Jul
(4) |
Aug
(2) |
Sep
(2) |
Oct
(20) |
Nov
(14) |
Dec
(8) |
|---|---|---|---|---|---|---|---|---|---|---|---|---|
| 2013 |
Jan
(6) |
Feb
(18) |
Mar
(27) |
Apr
(57) |
May
(32) |
Jun
(21) |
Jul
(79) |
Aug
(108) |
Sep
(13) |
Oct
(73) |
Nov
(51) |
Dec
(24) |
| 2014 |
Jan
(24) |
Feb
(41) |
Mar
(39) |
Apr
(5) |
May
(6) |
Jun
(2) |
Jul
(5) |
Aug
(15) |
Sep
(7) |
Oct
(6) |
Nov
|
Dec
(7) |
| 2015 |
Jan
(27) |
Feb
(18) |
Mar
(37) |
Apr
(8) |
May
(13) |
Jun
(44) |
Jul
(4) |
Aug
(50) |
Sep
(35) |
Oct
(6) |
Nov
(24) |
Dec
(19) |
| 2016 |
Jan
(30) |
Feb
(30) |
Mar
(23) |
Apr
(4) |
May
(12) |
Jun
(19) |
Jul
(26) |
Aug
(13) |
Sep
|
Oct
(23) |
Nov
(37) |
Dec
(15) |
| 2017 |
Jan
(33) |
Feb
(19) |
Mar
(20) |
Apr
(43) |
May
(39) |
Jun
(23) |
Jul
(20) |
Aug
(27) |
Sep
(10) |
Oct
(15) |
Nov
|
Dec
(24) |
| 2018 |
Jan
(3) |
Feb
(10) |
Mar
(34) |
Apr
(34) |
May
(28) |
Jun
(50) |
Jul
(27) |
Aug
(75) |
Sep
(21) |
Oct
(42) |
Nov
(25) |
Dec
(31) |
| 2019 |
Jan
(39) |
Feb
(28) |
Mar
(19) |
Apr
(7) |
May
(30) |
Jun
(22) |
Jul
(54) |
Aug
(36) |
Sep
(19) |
Oct
(33) |
Nov
(36) |
Dec
(32) |
| 2020 |
Jan
(29) |
Feb
(38) |
Mar
(29) |
Apr
(30) |
May
(39) |
Jun
(45) |
Jul
(31) |
Aug
(52) |
Sep
(40) |
Oct
(8) |
Nov
(48) |
Dec
(30) |
| 2021 |
Jan
(35) |
Feb
(32) |
Mar
(23) |
Apr
(55) |
May
(43) |
Jun
(63) |
Jul
(17) |
Aug
(24) |
Sep
(9) |
Oct
(31) |
Nov
(67) |
Dec
(55) |
| 2022 |
Jan
(31) |
Feb
(48) |
Mar
(76) |
Apr
(18) |
May
(13) |
Jun
(46) |
Jul
(75) |
Aug
(54) |
Sep
(59) |
Oct
(65) |
Nov
(44) |
Dec
(7) |
| 2023 |
Jan
(38) |
Feb
(32) |
Mar
(35) |
Apr
(23) |
May
(46) |
Jun
(53) |
Jul
(18) |
Aug
(10) |
Sep
(24) |
Oct
(15) |
Nov
(40) |
Dec
(6) |
|
From: Miroslav L. <mli...@re...> - 2022-05-04 10:34:10
|
On Tue, May 03, 2022 at 02:26:21PM +0000, Oleg Obleukhov via Linuxptp-users wrote: > Hi team, > In large distributed networks very many factors can lead to a short term spike in offset. Primarily network equipment without Transparent Clock support (even on a single device). PTP was designed for networks with constant delay. On switched networks that requires full on-path PTP support. If you don't have that, you should be looking at NTP or another protocol designed for networks with variable delays, where more effective filtering can be implemented. Of course, that doesn't mean linuxptp couldn't try to do better in these suboptimal conditions. The question is if it's in the scope of the project. As you seem to have found out, the main issue with the current design is that dropping samples can lead to servo instability. > Looking at ptp4l config I didn’t to find anything to overcome this situation and ignore this 1 bad outlier. > I implemented a quick patch https://gist.github.com/leoleovich/5a4dff7e089bd429c5d208d9276e1683 which can mitigate this and it works very well: > Preventing unnecessary tuning of the servo for a short period of time by using a padding technique (simply filling with previous values). That patch seems to be dropping the sample and there is a different output shown in the example. Is there a newer version of the patch you didn't publish? > The bottom line is - we need to find a way to ignore outliers in a locked state where it’s not expected to have shot term large jumps in offset. > Please check this out and let me know if there is a better way to handle this situation or if this patch can inspire any other ideas… If a spike filter needs to be implemented, I think it would better if the threshold was automatically adjusted based on the jitter. For an example, see the "Popcorn spike suppressor" in RFC5905 (NTPv4). -- Miroslav Lichvar |
|
From: Oleg O. <leo...@fb...> - 2022-05-03 15:18:25
|
Hi team, In large distributed networks very many factors can lead to a short term spike in offset. Primarily network equipment without Transparent Clock support (even on a single device). Path delay calculations have the filtering buffer which helps to mitigate synchronous changes in path delay, however this doesn’t help if only syncs are affected for example. We often end up in a situation like this (for demonstration we set delay_filter_length = 1): Apr 21 09:21:29 ptp4l[1732497.662]: master offset 17 s2 freq -12361 path delay 4070 Apr 21 09:21:30 ptp4l[1732498.662]: master offset 0 s2 freq -12373 path delay 4074 Apr 21 09:21:31 ptp4l[1732499.662]: master offset 37 s2 freq -12336 path delay 4067 Apr 21 09:21:32 ptp4l[1732500.662]: master offset 3 s2 freq -12359 path delay 4067 Apr 21 09:21:33 ptp4l[1732501.662]: master offset -122 s2 freq -12483 path delay 4193 Apr 21 09:21:34 ptp4l[1732502.662]: master offset 119 s2 freq -12279 path delay 4068 Apr 21 09:21:35 ptp4l[1732503.662]: master offset -25 s2 freq -12387 path delay 4110 Apr 21 09:21:36 ptp4l[1732504.662]: master offset 57 s2 freq -12313 path delay 4063 Apr 21 09:21:37 ptp4l[1732505.662]: master offset -18 s2 freq -12371 path delay 4063 Apr 21 09:21:38 ptp4l[1732506.662]: master offset 13 s2 freq -12345 path delay 4068 Apr 21 09:21:39 ptp4l[1732507.662]: master offset -76 s2 freq -12430 path delay 4107 Apr 21 09:21:40 ptp4l[1732508.662]: master offset -24 s2 freq -12401 path delay 4107 Apr 21 09:21:41 ptp4l[1732509.662]: master offset 279231 s2 freq +266847 path delay 4070 Apr 21 09:21:42 ptp4l[1732510.662]: master offset -454738 s2 freq -383353 path delay 179782 Apr 21 09:21:43 ptp4l[1732511.662]: master offset 258063 s2 freq +193027 path delay -162110 Apr 21 09:21:44 ptp4l[1732512.662]: master offset 52769 s2 freq +65152 path delay -162110 Apr 21 09:21:45 ptp4l[1732513.662]: master offset -221568 s2 freq -193355 path delay 34721 Apr 21 09:21:46 ptp4l[1732514.662]: master offset 19170 s2 freq -19087 path delay -25061 Apr 21 09:21:47 ptp4l[1732515.662]: master offset 25906 s2 freq -6600 path delay -25061 Apr 21 09:21:48 ptp4l[1732516.662]: master offset -10978 s2 freq -35712 path delay 6064 Apr 21 09:21:49 ptp4l[1732517.662]: master offset 12336 s2 freq -15692 path delay 6064 Apr 21 09:21:50 ptp4l[1732518.662]: master offset 18310 s2 freq -6017 path delay 3439 Apr 21 09:21:51 ptp4l[1732519.662]: master offset 11139 s2 freq -7695 path delay 4247 Apr 21 09:21:52 ptp4l[1732520.662]: master offset 5108 s2 freq -10384 path delay 5614 Apr 21 09:21:53 ptp4l[1732521.662]: master offset 3093 s2 freq -10867 path delay 5614 Apr 21 09:21:54 ptp4l[1732522.662]: master offset 2945 s2 freq -10087 path delay 4281 Apr 21 09:21:55 ptp4l[1732523.662]: master offset 205 s2 freq -11943 path delay 4700 Apr 21 09:21:56 ptp4l[1732524.662]: master offset -212 s2 freq -12299 path delay 4700 Apr 21 09:21:57 ptp4l[1732525.662]: master offset 325 s2 freq -11825 path delay 4079 Apr 21 09:21:58 ptp4l[1732526.662]: master offset -414 s2 freq -12467 path delay 4287 Apr 21 09:21:59 ptp4l[1732527.662]: master offset -142 s2 freq -12319 path delay 4098 Apr 21 09:22:00 ptp4l[1732528.662]: master offset -236 s2 freq -12456 path delay 4171 Apr 21 09:22:01 ptp4l[1732529.662]: master offset -182 s2 freq -12473 path delay 4171 Apr 21 09:22:02 ptp4l[1732530.662]: master offset 83 s2 freq -12262 path delay 4028 Apr 21 09:22:03 ptp4l[1732531.662]: master offset -113 s2 freq -12433 path delay 4126 Apr 21 09:22:04 ptp4l[1732532.662]: master offset 11 s2 freq -12343 path delay 4057 Apr 21 09:22:05 ptp4l[1732533.662]: master offset -94 s2 freq -12445 path delay 4125 Apr 21 09:22:06 ptp4l[1732534.662]: master offset 73 s2 freq -12306 path delay 4049 Apr 21 09:22:07 ptp4l[1732535.662]: master offset -23 s2 freq -12380 path delay 4077 As you see we have a “regular” path delay is around “4100” with an offset within ±200ns when suddenly offset jumps to "27923" for a very short amount of time (in fact only once) everything goes crazy. The issue is further complicated because delay_req/resp may not be affected when syncs are (different queues, fabric paths etc). So with delay_filter_length set to 10 (default) there may be short term asymmetry literally for 1 packet. Looking at ptp4l config I didn’t to find anything to overcome this situation and ignore this 1 bad outlier. I implemented a quick patch https://gist.github.com/leoleovich/5a4dff7e089bd429c5d208d9276e1683 which can mitigate this and it works very well: May 2 14:34:26 ptp4l[2772335.049]: master offset -9 s2 freq -10406 path delay 3957 May 2 14:34:27 ptp4l[2772336.049]: master offset 0 s2 freq -10399 path delay 3957 May 2 14:34:28 ptp4l[2772337.049]: master offset -7 s2 freq -10406 path delay 3957 May 2 14:34:30 ptp4l[2772338.805]: master offset 7 s2 freq -10395 path delay 3957 May 2 14:34:30 ptp4l[2772339.049]: master offset -6 s2 freq -10405 path delay 3957 May 2 14:34:31 ptp4l[2772340.049]: master offset -16 s2 freq -10417 path delay 3957 May 2 14:34:32 ptp4l[2772341.049]: skip 1/2 large offset (>20000) 486196 May 2 14:34:33 ptp4l[2772342.049]: master offset 26 s2 freq -10380 path delay 3956 May 2 14:34:34 ptp4l[2772343.049]: master offset 20 s2 freq -10378 path delay 3956 May 2 14:34:35 ptp4l[2772344.049]: master offset 14 s2 freq -10378 path delay 3956 May 2 14:34:36 ptp4l[2772345.049]: master offset -21 s2 freq -10409 path delay 3956 May 2 14:34:37 ptp4l[2772346.049]: master offset 3 s2 freq -10391 path delay 3955 Preventing unnecessary tuning of the servo for a short period of time by using a padding technique (simply filling with previous values). The bottom line is - we need to find a way to ignore outliers in a locked state where it’s not expected to have shot term large jumps in offset. Please check this out and let me know if there is a better way to handle this situation or if this patch can inspire any other ideas… Thank you in advance, Oleg. |
|
From: Richard C. <ric...@gm...> - 2022-04-18 20:58:04
|
On Mon, Apr 18, 2022 at 08:24:17PM +0000, Cole Walker wrote: > Would you be open to me proposing a fix for this in ts2phc or do you think this issue should be addressed by adjusting the driver priority? After a PPS event, the ts2phc program needs to determine the ToD of that event. It does so by reading the PHC time immediately after the detection of PPS event and computing the nearest whole second to the given PHC time. IMO it is reasonable to expect the system to allow that read operation to occur within under 1/2 second from the PPS event. So I don't think changes to ts2phc are needed. Thanks, Richard |
|
From: Cole W. <ce....@li...> - 2022-04-18 20:24:29
|
Hi Richard, thanks for the info. I've continued my investigation of this and was hoping to get your thoughts. It appears that the increase in the nmea delay value on my realtime system is related to the priority (or niceness value) of this process: ice-gnss-0000:5 >From the ice driver code, this is the process that writes to the GNSS tty. Giving this process a better priority causes the ts2phc master offset to stay very stable as it is not waiting for nmea data. My main question is: Should ts2phc be expected to handle these variations in nmea delay without causing the offset to jump? This appears to be less of an issue with the specific device/driver and rather just an issue of running on a realtime system where the nmea delay could be affected by system utilization. Would you be open to me proposing a fix for this in ts2phc or do you think this issue should be addressed by adjusting the driver priority? Thanks for your help, Cole ________________________________ From: Richard Cochran <ric...@gm...> Sent: April 15, 2022 2:28 AM To: Cole Walker <ce....@li...> Cc: Keller, Jacob E <jac...@in...>; lin...@li... <lin...@li...> Subject: Re: [Linuxptp-users] ts2phc master offset value periodically spikes On Tue, Apr 12, 2022 at 02:35:17PM -0700, Richard Cochran wrote: > There are patches floating around that convert the tty stuff into a > proper kthread that can be given sched_fifo priority. You'll have to > port those or do something similar yourself. Once upon a time, there was a low latency option for serial ports. At some point, it was removed. In 2015, an attempt was made to restore some kind of low latency performance. https://www.spinics.net/lists/linux-serial/msg17767.html This went nowhere, but in 2019 another attempt was made. https://lore.kernel.org/lkml/201...@pe.../ HTH, Richard |
|
From: Richard C. <ric...@gm...> - 2022-04-15 06:28:47
|
On Tue, Apr 12, 2022 at 02:35:17PM -0700, Richard Cochran wrote: > There are patches floating around that convert the tty stuff into a > proper kthread that can be given sched_fifo priority. You'll have to > port those or do something similar yourself. Once upon a time, there was a low latency option for serial ports. At some point, it was removed. In 2015, an attempt was made to restore some kind of low latency performance. https://www.spinics.net/lists/linux-serial/msg17767.html This went nowhere, but in 2019 another attempt was made. https://lore.kernel.org/lkml/201...@pe.../ HTH, Richard |
|
From: Jacob K. <jac...@in...> - 2022-04-14 22:58:59
|
On 4/12/2022 1:22 PM, Cole Walker wrote:
> Hi Jake, I'm still working my way through this issue. I was looking at
> the ice driver code and I noticed this comment in ice_gnss.c (1.7.16):
>
> L96
> /* Send the data to the tty layer for users to read. This doesn't
> * actually push the data through unless tty->low_latency is set.
> */
> tty_insert_flip_string(port, buf, i);
> tty_flip_buffer_push(port);
>
> Given that I am running on a real-time system, do you think there is any
> chance that this could be contributing? How would I go about testing this?
>
Really not sure. If this ends up going to an output pin of some kind you
could try measuring the actual latency of the output pin but I'm not
familiar with the GNSS code.
> I'm thinking I need to rebuild the driver and add something after L289?
>
> /* Initialize the tty driver*/
> tty_driver->owner = THIS_MODULE;
> tty_driver->driver_name = dev_driver_string(dev);
> tty_driver->name = (const char *)ttydrv_name;
> tty_driver->type = TTY_DRIVER_TYPE_SERIAL;
> tty_driver->subtype = SERIAL_TYPE_NORMAL;
> tty_driver->init_termios = tty_std_termios;
> tty_driver->init_termios.c_iflag &= ~INLCR;
> tty_driver->init_termios.c_iflag |= IGNCR;
> tty_driver->init_termios.c_oflag &= ~OPOST;
> tty_driver->init_termios.c_lflag &= ~ICANON;
> tty_driver->init_termios.c_cflag &= ~(CSIZE | CBAUD | CBAUDEX);
> # Something like
> tty_driver->low_latency = 1;
>
>
You could try this, but Richard seemed to think it won't do much in the
RT setup..
> I have also been running the change described below for a few days and
> the master offset is incredibly stable when ts2phc_slave_offset() is
> changed to
>
> if (source_ts.tv_nsec > 500000000) {
> source_ts.tv_sec++;
> } else {
> source_ts.tv_sec++;
> pr_info("Timing went weird, advancing tv_sec anyways.");
> }
>
I'm not an expert on ts2phc so I don't know if this change is correct.
This basically just always enforces the tv_sec incrementing. It doesn't
feel correct at a glance.. but as I said I'm no expert in this program.
> But that does not really address the root cause of the nmea delay spikes.
>
I suspect given your RT system that the tty issues are the cause. I
think Richard is correct that the issue will be that without using a
kthread and proper scheduling priority the RT kernel can end up starving
the background work, which might be the cause of some of the instability
here...
>
> Thanks for your input on any of these points,
>
Perhaps someone else on the list here can help with whether that ts2phc
change is safe/correct or not.
Thanks,
Jake
|
|
From: Richard C. <ric...@gm...> - 2022-04-12 21:35:26
|
On Tue, Apr 12, 2022 at 08:22:26PM +0000, Cole Walker wrote: > Given that I am running on a real-time system, do you think there is any chance that this could be contributing? How would I go about testing this? A busy preempt_rt system can easily delay background work like uart for a LONG time. > # Something like > tty_driver->low_latency = 1; Unfortunately that doesn't do anything at all. There are patches floating around that convert the tty stuff into a proper kthread that can be given sched_fifo priority. You'll have to port those or do something similar yourself. Recently there has been some talk on LKML on just this topic, namely getting "low_latency" to actually do something again. But I wouldn't hold your breath. HTH, Richard |
|
From: Cole W. <ce....@li...> - 2022-04-12 20:22:42
|
Hi Jake, I'm still working my way through this issue. I was looking at the ice driver code and I noticed this comment in ice_gnss.c (1.7.16):
L96
/* Send the data to the tty layer for users to read. This doesn't
* actually push the data through unless tty->low_latency is set.
*/
tty_insert_flip_string(port, buf, i);
tty_flip_buffer_push(port);
Given that I am running on a real-time system, do you think there is any chance that this could be contributing? How would I go about testing this?
I'm thinking I need to rebuild the driver and add something after L289?
/* Initialize the tty driver*/
tty_driver->owner = THIS_MODULE;
tty_driver->driver_name = dev_driver_string(dev);
tty_driver->name = (const char *)ttydrv_name;
tty_driver->type = TTY_DRIVER_TYPE_SERIAL;
tty_driver->subtype = SERIAL_TYPE_NORMAL;
tty_driver->init_termios = tty_std_termios;
tty_driver->init_termios.c_iflag &= ~INLCR;
tty_driver->init_termios.c_iflag |= IGNCR;
tty_driver->init_termios.c_oflag &= ~OPOST;
tty_driver->init_termios.c_lflag &= ~ICANON;
tty_driver->init_termios.c_cflag &= ~(CSIZE | CBAUD | CBAUDEX);
# Something like
tty_driver->low_latency = 1;
I have also been running the change described below for a few days and the master offset is incredibly stable when ts2phc_slave_offset() is changed to
if (source_ts.tv_nsec > 500000000) {
source_ts.tv_sec++;
} else {
source_ts.tv_sec++;
pr_info("Timing went weird, advancing tv_sec anyways.");
}
But that does not really address the root cause of the nmea delay spikes.
Thanks for your input on any of these points,
Cole
________________________________
From: Cole Walker <ce....@li...>
Sent: April 6, 2022 12:52 PM
To: Keller, Jacob E <jac...@in...>; lin...@li... <lin...@li...>
Subject: Re: [Linuxptp-users] ts2phc master offset value periodically spikes
Unfortunately, the issue is still present with the 1.8.3 ice driver. Logs are at the end of this message.
Interesting that the nmea delay is much higher at all times now. This is from the same system as the previous data.
Anecdotally, it seems less frequent.
I also did a little more digging around the code I referenced earlier
ts2phc_slave.c ts2phc_slave_offset()
if (source_ts.tv_nsec > 500000000) {
source_ts.tv_sec++;
}
Normally the PPS ensures that tv_nsec is pretty close to the previous value, because one second has elapsed.
But in cases where there is a large nmea delay spike, the tv_nsec value could be at say 100000000, because the seconds value has rolled over.
The logic here in ts2phc seems to only advance the tv_sec value based on the tv_nsec value, which leads to cases like in the logs below where the second value was not incremented, even though it should be.
I'm not sure what the correct solution for this would be? Should ts2phc be performing a more robust check to compute the tv_sec value?
I tried something like this just to see what the behaviour would be and it prevented the master offset issue. I'm not sure what the implications of always advancing the timing might be though.
if (source_ts.tv_nsec > 500000000) {
source_ts.tv_sec++;
} else {
source_ts.tv_sec++;
pr_info("Timing went weird, advancing tv_sec anyways.");
}
2022-04-06T17:09:22.000 controller-0 ts2phc: info [8933.654] tv_sec 1649262489
2022-04-06T17:09:22.000 controller-0 ts2phc: info [8933.654] tv_nsec 499622726
2022-04-06T17:09:22.000 controller-0 ts2phc: info [8933.654] Timing went weird, advancing tv_sec anyways.
2022-04-06T17:09:22.000 controller-0 ts2phc: info [8933.654] enp81s0f0 extts index 0 at 1649262490.000000000 corr 0 src 1649262490.499622726 diff 0
2022-04-06T17:09:22.000 controller-0 ts2phc: info [8933.654] enp81s0f0 master offset 0 s2 freq +0
### Reproduction of issue
ethtool -i enp81s0f0
driver: ice
version: 1.8.3
firmware-version: 3.10 0x80009be5 1.3086.0
expansion-rom-version:
bus-info: 0000:51:00.0
supports-statistics: yes
supports-test: yes
supports-eeprom-access: yes
supports-register-dump: yes
supports-priv-flags: yes
Logs:
2022-04-06T16:14:18.000 controller-0 ts2phc: debug [5629.712] enp138s0f0 extts index 0 at 1649259186.000000000 corr 0 src 1649259186.903003525 diff 0
2022-04-06T16:14:18.000 controller-0 ts2phc: debug [5629.712] enp138s0f0 master offset 0 s2 freq +0
2022-04-06T16:14:19.000 controller-0 ts2phc: debug [5630.711] nmea delay: 2509974014846 ns
2022-04-06T16:14:19.000 controller-0 ts2phc: debug [5630.711] enp81s0f0 extts index 0 at 1649259187.000000000 corr 0 src 1649259187.622769768 diff 0
2022-04-06T16:14:19.000 controller-0 ts2phc: debug [5630.711] enp81s0f0 master offset 0 s2 freq -0
2022-04-06T16:14:19.000 controller-0 ts2phc: debug [5630.712] enp138s0f0 extts index 0 at 1649259187.000000000 corr 0 src 1649259187.622769768 diff 0
2022-04-06T16:14:19.000 controller-0 ts2phc: debug [5630.712] enp138s0f0 master offset 0 s2 freq +0
2022-04-06T16:14:20.000 controller-0 ts2phc: debug [5631.711] nmea delay: 2509985703545 ns
2022-04-06T16:14:20.000 controller-0 ts2phc: debug [5631.711] enp81s0f0 extts index 0 at 1649259188.000000001 corr 0 src 1649259188.611065163 diff 1
2022-04-06T16:14:20.000 controller-0 ts2phc: debug [5631.711] enp81s0f0 master offset 1 s2 freq +1
2022-04-06T16:14:20.000 controller-0 ts2phc: debug [5631.712] enp138s0f0 extts index 0 at 1649259188.000000000 corr 0 src 1649259188.611065163 diff 0
2022-04-06T16:14:20.000 controller-0 ts2phc: debug [5631.712] enp138s0f0 master offset 0 s2 freq +0
2022-04-06T16:14:21.000 controller-0 ts2phc: debug [5632.711] nmea delay: 2509975679106 ns
2022-04-06T16:14:21.000 controller-0 ts2phc: debug [5632.711] enp81s0f0 extts index 0 at 1649259189.000000000 corr 0 src 1649259189.621072451 diff 0
2022-04-06T16:14:21.000 controller-0 ts2phc: debug [5632.711] enp81s0f0 master offset 0 s2 freq +0
2022-04-06T16:14:21.000 controller-0 ts2phc: debug [5632.712] enp138s0f0 extts index 0 at 1649259189.000000000 corr 0 src 1649259189.621072451 diff 0
2022-04-06T16:14:21.000 controller-0 ts2phc: debug [5632.712] enp138s0f0 master offset 0 s2 freq +0
2022-04-06T16:14:22.000 controller-0 ts2phc: debug [5633.711] nmea delay: 2510153705944 ns
# Nmea delay increases by 178,026,838 ns - less than before
# Issue appears here
2022-04-06T16:14:22.000 controller-0 ts2phc: debug [5633.711] enp81s0f0 extts index 0 at 1649259190.000000000 corr 0 src 1649259189.443022927 diff 1000000000
### The src value here should have had its seconds value incremented, but because of how ts2phc is only checking the nanoseconds value, it did not. The real source time is actually
### 1649259190.443022927
2022-04-06T16:14:22.000 controller-0 ts2phc: debug [5633.711] enp81s0f0 master offset 1000000000 s2 freq +900000000
2022-04-06T16:14:22.000 controller-0 ts2phc: debug [5633.712] enp138s0f0 extts index 0 at 1649259190.000000000 corr 0 src 1649259189.443022927 diff 1000000000
2022-04-06T16:14:22.000 controller-0 ts2phc: debug [5633.712] enp138s0f0 master offset 1000000000 s2 freq +900000000
2022-04-06T16:14:23.000 controller-0 ts2phc: debug [5634.711] nmea delay: 2509910614292 ns
2022-04-06T16:14:23.000 controller-0 ts2phc: debug [5634.711] enp81s0f0 extts index 0 at 1649259190.100442268 corr 0 src 1649259191.686226081 diff -899557732
2022-04-06T16:14:23.000 controller-0 ts2phc: debug [5634.711] enp81s0f0 master offset -899557732 s2 freq -899557732
2022-04-06T16:14:23.000 controller-0 ts2phc: debug [5634.735] nmea delay: 2509910614292 ns
2022-04-06T16:14:23.000 controller-0 ts2phc: debug [5634.735] enp138s0f0 extts index 0 at 1649259190.100838162 corr 0 src 1649259191.709715088 diff -899161838
2022-04-06T16:14:23.000 controller-0 ts2phc: debug [5634.735] enp138s0f0 master offset -899161838 s2 freq -899161838
2022-04-06T16:14:24.000 controller-0 ts2phc: debug [5635.711] nmea delay: 2509934750724 ns
2022-04-06T16:14:24.000 controller-0 ts2phc: debug [5635.711] enp138s0f0 extts index 0 at 1649259191.956652053 corr 0 src 1649259192.661952069 diff -43347947
2022-04-06T16:14:24.000 controller-0 ts2phc: debug [5635.711] enp138s0f0 master offset -43347947 s2 freq -313096498
2022-04-06T16:14:24.000 controller-0 ts2phc: debug [5635.734] nmea delay: 2509934750724 ns
2022-04-06T16:14:24.000 controller-0 ts2phc: debug [5635.734] enp81s0f0 extts index 0 at 1649259191.998895877 corr 0 src 1649259192.685191330 diff -1104123
2022-04-06T16:14:24.000 controller-0 ts2phc: debug [5635.734] enp81s0f0 master offset -1104123 s2 freq -270971442
2022-04-06T16:14:25.000 controller-0 ts2phc: debug [5636.711] nmea delay: 2509932763703 ns
2022-04-06T16:14:25.000 controller-0 ts2phc: debug [5636.711] enp81s0f0 extts index 0 at 1649259193.285100826 corr 0 src 1649259193.663917395 diff 285100826
2022-04-06T16:14:25.000 controller-0 ts2phc: debug [5636.711] enp81s0f0 master offset 285100826 s2 freq +14902270
2022-04-06T16:14:25.000 controller-0 ts2phc: debug [5636.711] enp138s0f0 extts index 0 at 1649259193.270039664 corr 0 src 1649259193.663917395 diff 270039664
2022-04-06T16:14:25.000 controller-0 ts2phc: debug [5636.711] enp138s0f0 master offset 270039664 s2 freq -12713272
2022-04-06T16:14:26.000 controller-0 ts2phc: debug [5637.711] nmea delay: 2509951412014 ns
2022-04-06T16:14:26.000 controller-0 ts2phc: debug [5637.711] enp81s0f0 extts index 0 at 1649259194.270335612 corr 0 src 1649259194.645246996 diff 270335612
2022-04-06T16:14:26.000 controller-0 ts2phc: debug [5637.711] enp81s0f0 master offset 270335612 s2 freq +85667303
2022-04-06T16:14:26.000 controller-0 ts2phc: debug [5637.711] enp138s0f0 extts index 0 at 1649259194.283026443 corr 0 src 1649259194.645246996 diff 283026443
2022-04-06T16:14:26.000 controller-0 ts2phc: debug [5637.711] enp138s0f0 master offset 283026443 s2 freq +81285407
2022-04-06T16:14:27.000 controller-0 ts2phc: debug [5638.711] nmea delay: 2509955664247 ns
2022-04-06T16:14:27.000 controller-0 ts2phc: debug [5638.711] enp81s0f0 extts index 0 at 1649259195.184702116 corr 0 src 1649259195.640978094 diff 184702116
2022-04-06T16:14:27.000 controller-0 ts2phc: debug [5638.711] enp81s0f0 master offset 184702116 s2 freq +81134491
2022-04-06T16:14:27.000 controller-0 ts2phc: debug [5638.711] enp138s0f0 extts index 0 at 1649259195.201826252 corr 0 src 1649259195.640978094 diff 201826252
2022-04-06T16:14:27.000 controller-0 ts2phc: debug [5638.711] enp138s0f0 master offset 201826252 s2 freq +84993149
2022-04-06T16:14:28.000 controller-0 ts2phc: debug [5639.711] nmea delay: 2509976851503 ns
2022-04-06T16:14:28.000 controller-0 ts2phc: debug [5639.711] enp81s0f0 extts index 0 at 1649259196.103565395 corr 0 src 1649259196.619782066 diff 103565395
2022-04-06T16:14:28.000 controller-0 ts2phc: debug [5639.711] enp81s0f0 master offset 103565395 s2 freq +55408405
2022-04-06T16:14:28.000 controller-0 ts2phc: debug [5639.711] enp138s0f0 extts index 0 at 1649259196.116836545 corr 0 src 1649259196.619782066 diff 116836545
2022-04-06T16:14:28.000 controller-0 ts2phc: debug [5639.711] enp138s0f0 master offset 116836545 s2 freq +60551317
2022-04-06T16:14:29.000 controller-0 ts2phc: debug [5640.711] nmea delay: 2509968770585 ns
2022-04-06T16:14:29.000 controller-0 ts2phc: debug [5640.711] enp81s0f0 extts index 0 at 1649259197.048144368 corr 0 src 1649259197.627846823 diff 48144368
2022-04-06T16:14:29.000 controller-0 ts2phc: debug [5640.711] enp81s0f0 master offset 48144368 s2 freq +31056996
2022-04-06T16:14:29.000 controller-0 ts2phc: debug [5640.711] enp138s0f0 extts index 0 at 1649259197.056262530 corr 0 src 1649259197.627846823 diff 56262530
2022-04-06T16:14:29.000 controller-0 ts2phc: debug [5640.711] enp138s0f0 master offset 56262530 s2 freq +35028266
2022-04-06T16:14:30.000 controller-0 ts2phc: debug [5641.711] nmea delay: 2509756017458 ns
2022-04-06T16:14:30.000 controller-0 ts2phc: debug [5641.711] enp81s0f0 extts index 0 at 1649259198.017075025 corr 0 src 1649259198.840576852 diff 17075025
2022-04-06T16:14:30.000 controller-0 ts2phc: debug [5641.711] enp81s0f0 master offset 17075025 s2 freq +14430964
2022-04-06T16:14:30.000 controller-0 ts2phc: debug [5641.711] enp138s0f0 extts index 0 at 1649259198.021210240 corr 0 src 1649259198.840576852 diff 21210240
2022-04-06T16:14:30.000 controller-0 ts2phc: debug [5641.711] enp138s0f0 master offset 21210240 s2 freq +16854735
2022-04-06T16:14:31.000 controller-0 ts2phc: debug [5642.711] nmea delay: 2509827437737 ns
2022-04-06T16:14:31.000 controller-0 ts2phc: debug [5642.711] enp81s0f0 extts index 0 at 1649259199.002635929 corr 0 src 1649259199.769146714 diff 2635929
2022-04-06T16:14:31.000 controller-0 ts2phc: debug [5642.711] enp81s0f0 master offset 2635929 s2 freq +5114375
2022-04-06T16:14:31.000 controller-0 ts2phc: debug [5642.711] enp138s0f0 extts index 0 at 1649259199.004338678 corr 0 src 1649259199.769146714 diff 4338678
2022-04-06T16:14:31.000 controller-0 ts2phc: debug [5642.711] enp138s0f0 master offset 4338678 s2 freq +6346245
2022-04-06T16:14:32.000 controller-0 ts2phc: debug [5643.711] nmea delay: 2509935546499 ns
2022-04-06T16:14:32.000 controller-0 ts2phc: debug [5643.711] enp81s0f0 extts index 0 at 1649259199.997516909 corr 0 src 1649259200.661016877 diff -2483091
2022-04-06T16:14:32.000 controller-0 ts2phc: debug [5643.711] enp81s0f0 master offset -2483091 s2 freq +786134
2022-04-06T16:14:32.000 controller-0 ts2phc: debug [5643.735] nmea delay: 2509935546499 ns
2022-04-06T16:14:32.000 controller-0 ts2phc: debug [5643.735] enp138s0f0 extts index 0 at 1649259199.997982651 corr 0 src 1649259200.685558481 diff -2017349
2022-04-06T16:14:32.000 controller-0 ts2phc: debug [5643.735] enp138s0f0 master offset -2017349 s2 freq +1291821
2022-04-06T16:14:33.000 controller-0 ts2phc: debug [5644.711] nmea delay: 2509920466181 ns
2022-04-06T16:14:33.000 controller-0 ts2phc: debug [5644.711] enp81s0f0 extts index 0 at 1649259200.996728630 corr 0 src 1649259201.676078609 diff -3271370
2022-04-06T16:14:33.000 controller-0 ts2phc: debug [5644.711] enp81s0f0 master offset -3271370 s2 freq -747072
2022-04-06T16:14:33.000 controller-0 ts2phc: debug [5644.711] enp138s0f0 extts index 0 at 1649259200.996564380 corr 0 src 1649259201.676078609 diff -3435620
2022-04-06T16:14:33.000 controller-0 ts2phc: debug [5644.711] enp138s0f0 master offset -3435620 s2 freq -731655
2022-04-06T16:14:34.000 controller-0 ts2phc: debug [5645.711] nmea delay: 2509926722531 ns
2022-04-06T16:14:34.000 controller-0 ts2phc: debug [5645.711] enp81s0f0 extts index 0 at 1649259201.997474950 corr 0 src 1649259202.669808104 diff -2525050
2022-04-06T16:14:34.000 controller-0 ts2phc: debug [5645.711] enp81s0f0 master offset -2525050 s2 freq -982163
2022-04-06T16:14:34.000 controller-0 ts2phc: debug [5645.711] enp138s0f0 extts index 0 at 1649259201.997294167 corr 0 src 1649259202.669808104 diff -2705833
2022-04-06T16:14:34.000 controller-0 ts2phc: debug [5645.711] enp138s0f0 master offset -2705833 s2 freq -1032554
2022-04-06T16:14:35.000 controller-0 ts2phc: debug [5646.711] nmea delay: 2509941317000 ns
2022-04-06T16:14:35.000 controller-0 ts2phc: debug [5646.711] enp81s0f0 extts index 0 at 1649259202.998456996 corr 0 src 1649259203.655186682 diff -1543004
2022-04-06T16:14:35.000 controller-0 ts2phc: debug [5646.711] enp81s0f0 master offset -1543004 s2 freq -757632
2022-04-06T16:14:35.000 controller-0 ts2phc: debug [5646.711] enp138s0f0 extts index 0 at 1649259202.998326440 corr 0 src 1649259203.655186682 diff -1673560
2022-04-06T16:14:35.000 controller-0 ts2phc: debug [5646.711] enp138s0f0 master offset -1673560 s2 freq -812031
2022-04-06T16:14:36.000 controller-0 ts2phc: debug [5647.711] nmea delay: 2509814140165 ns
2022-04-06T16:14:36.000 controller-0 ts2phc: debug [5647.711] enp81s0f0 extts index 0 at 1649259203.999214738 corr 0 src 1649259204.782347244 diff -785262
2022-04-06T16:14:36.000 controller-0 ts2phc: debug [5647.711] enp81s0f0 master offset -785262 s2 freq -462792
2022-04-06T16:14:36.000 controller-0 ts2phc: debug [5647.711] enp138s0f0 extts index 0 at 1649259203.999138674 corr 0 src 1649259204.782347244 diff -861326
2022-04-06T16:14:36.000 controller-0 ts2phc: debug [5647.711] enp138s0f0 master offset -861326 s2 freq -501865
2022-04-06T16:14:37.000 controller-0 ts2phc: debug [5648.711] nmea delay: 2509751928748 ns
2022-04-06T16:14:37.000 controller-0 ts2phc: debug [5648.711] enp81s0f0 extts index 0 at 1649259204.999677674 corr 0 src 1649259205.844542654 diff -322326
2022-04-06T16:14:37.000 controller-0 ts2phc: debug [5648.711] enp81s0f0 master offset -322326 s2 freq -235434
2022-04-06T16:14:37.000 controller-0 ts2phc: debug [5648.711] enp138s0f0 extts index 0 at 1649259204.999640826 corr 0 src 1649259205.844542654 diff -359174
2022-04-06T16:14:37.000 controller-0 ts2phc: debug [5648.711] enp138s0f0 master offset -359174 s2 freq -258110
2022-04-06T16:14:38.000 controller-0 ts2phc: debug [5649.711] nmea delay: 2509991234371 ns
2022-04-06T16:14:38.000 controller-0 ts2phc: debug [5649.711] enp81s0f0 extts index 0 at 1649259205.999913221 corr 0 src 1649259206.605219127 diff -86779
2022-04-06T16:14:38.000 controller-0 ts2phc: debug [5649.711] enp81s0f0 master offset -86779 s2 freq -96585
2022-04-06T16:14:38.000 controller-0 ts2phc: debug [5649.711] enp138s0f0 extts index 0 at 1649259205.999899162 corr 0 src 1649259206.605219127 diff -100838
2022-04-06T16:14:38.000 controller-0 ts2phc: debug [5649.711] enp138s0f0 master offset -100838 s2 freq -107527
2022-04-06T16:14:39.000 controller-0 ts2phc: debug [5650.711] nmea delay: 2509947413836 ns
2022-04-06T16:14:39.000 controller-0 ts2phc: debug [5650.711] enp81s0f0 extts index 0 at 1649259207.000009874 corr 0 src 1649259207.649028886 diff 9874
2022-04-06T16:14:39.000 controller-0 ts2phc: debug [5650.711] enp81s0f0 master offset 9874 s2 freq -25966
2022-04-06T16:14:39.000 controller-0 ts2phc: debug [5650.711] enp138s0f0 extts index 0 at 1649259207.000006827 corr 0 src 1649259207.649028886 diff 6827
2022-04-06T16:14:39.000 controller-0 ts2phc: debug [5650.711] enp138s0f0 master offset 6827 s2 freq -30113
2022-04-06T16:14:40.000 controller-0 ts2phc: debug [5651.711] nmea delay: 2509936137470 ns
2022-04-06T16:14:40.000 controller-0 ts2phc: debug [5651.711] enp81s0f0 extts index 0 at 1649259208.000035874 corr 0 src 1649259208.660289498 diff 35874
2022-04-06T16:14:40.000 controller-0 ts2phc: debug [5651.711] enp81s0f0 master offset 35874 s2 freq +2997
2022-04-06T16:14:40.000 controller-0 ts2phc: debug [5651.711] enp138s0f0 extts index 0 at 1649259208.000037012 corr 0 src 1649259208.660289498 diff 37012
2022-04-06T16:14:40.000 controller-0 ts2phc: debug [5651.711] enp138s0f0 master offset 37012 s2 freq +2120
2022-04-06T16:14:41.000 controller-0 ts2phc: debug [5652.711] nmea delay: 2509928033738 ns
2022-04-06T16:14:41.000 controller-0 ts2phc: debug [5652.711] enp81s0f0 extts index 0 at 1649259209.000032893 corr 0 src 1649259209.668373960 diff 32893
2022-04-06T16:14:41.000 controller-0 ts2phc: debug [5652.711] enp81s0f0 master offset 32893 s2 freq +10778
2022-04-06T16:14:41.000 controller-0 ts2phc: debug [5652.712] enp138s0f0 extts index 0 at 1649259209.000034923 corr 0 src 1649259209.668373960 diff 34923
2022-04-06T16:14:41.000 controller-0 ts2phc: debug [5652.712] enp138s0f0 master offset 34923 s2 freq +11135
2022-04-06T16:14:42.000 controller-0 ts2phc: debug [5653.711] nmea delay: 2509940063772 ns
2022-04-06T16:14:42.000 controller-0 ts2phc: debug [5653.711] enp81s0f0 extts index 0 at 1649259210.000022122 corr 0 src 1649259210.656329379 diff 22122
2022-04-06T16:14:42.000 controller-0 ts2phc: debug [5653.711] enp81s0f0 master offset 22122 s2 freq +9875
2022-04-06T16:14:42.000 controller-0 ts2phc: debug [5653.711] enp138s0f0 extts index 0 at 1649259210.000023801 corr 0 src 1649259210.656329379 diff 23801
2022-04-06T16:14:42.000 controller-0 ts2phc: debug [5653.711] enp138s0f0 master offset 23801 s2 freq +10490
2022-04-06T16:14:43.000 controller-0 ts2phc: debug [5654.711] nmea delay: 2509927318786 ns
2022-04-06T16:14:43.000 controller-0 ts2phc: debug [5654.711] enp138s0f0 extts index 0 at 1649259211.000013309 corr 0 src 1649259211.669047253 diff 13309
2022-04-06T16:14:43.000 controller-0 ts2phc: debug [5654.711] enp138s0f0 master offset 13309 s2 freq +7138
2022-04-06T16:14:43.000 controller-0 ts2phc: debug [5654.711] nmea delay: 2509927318786 ns
2022-04-06T16:14:43.000 controller-0 ts2phc: debug [5654.711] enp81s0f0 extts index 0 at 1649259211.000012247 corr 0 src 1649259211.669529431 diff 12247
2022-04-06T16:14:43.000 controller-0 ts2phc: debug [5654.711] enp81s0f0 master offset 12247 s2 freq +6636
2022-04-06T16:14:44.000 controller-0 ts2phc: debug [5655.711] nmea delay: 2509787447823 ns
2022-04-06T16:14:44.000 controller-0 ts2phc: debug [5655.711] enp81s0f0 extts index 0 at 1649259212.000005608 corr 0 src 1649259212.808906417 diff 5608
2022-04-06T16:14:44.000 controller-0 ts2phc: debug [5655.711] enp81s0f0 master offset 5608 s2 freq +3671
2022-04-06T16:14:44.000 controller-0 ts2phc: debug [5655.711] enp138s0f0 extts index 0 at 1649259212.000006170 corr 0 src 1649259212.808906417 diff 6170
2022-04-06T16:14:44.000 controller-0 ts2phc: debug [5655.711] enp138s0f0 master offset 6170 s2 freq +3992
2022-04-06T16:14:45.000 controller-0 ts2phc: debug [5656.711] nmea delay: 2509951116255 ns
2022-04-06T16:14:45.000 controller-0 ts2phc: debug [5656.711] enp81s0f0 extts index 0 at 1649259213.000001935 corr 0 src 1649259213.645217296 diff 1935
2022-04-06T16:14:45.000 controller-0 ts2phc: debug [5656.711] enp81s0f0 master offset 1935 s2 freq +1681
2022-04-06T16:14:45.000 controller-0 ts2phc: debug [5656.711] enp138s0f0 extts index 0 at 1649259213.000002176 corr 0 src 1649259213.645217296 diff 2176
2022-04-06T16:14:45.000 controller-0 ts2phc: debug [5656.711] enp138s0f0 master offset 2176 s2 freq +1849
2022-04-06T16:14:46.000 controller-0 ts2phc: debug [5657.711] nmea delay: 2509962512441 ns
2022-04-06T16:14:46.000 controller-0 ts2phc: debug [5657.711] enp81s0f0 extts index 0 at 1649259214.000000255 corr 0 src 1649259214.633802454 diff 255
2022-04-06T16:14:46.000 controller-0 ts2phc: debug [5657.711] enp81s0f0 master offset 255 s2 freq +581
2022-04-06T16:14:46.000 controller-0 ts2phc: debug [5657.711] nmea delay: 2509962512441 ns
2022-04-06T16:14:46.000 controller-0 ts2phc: debug [5657.711] enp138s0f0 extts index 0 at 1649259214.000000326 corr 0 src 1649259214.634282788 diff 326
2022-04-06T16:14:46.000 controller-0 ts2phc: debug [5657.711] enp138s0f0 master offset 326 s2 freq +651
2022-04-06T16:14:47.000 controller-0 ts2phc: debug [5658.711] nmea delay: 2509993558162 ns
2022-04-06T16:14:47.000 controller-0 ts2phc: debug [5658.711] enp81s0f0 extts index 0 at 1649259214.999999672 corr 0 src 1649259215.602748084 diff -328
2022-04-06T16:14:47.000 controller-0 ts2phc: debug [5658.711] enp81s0f0 master offset -328 s2 freq +75
2022-04-06T16:14:47.000 controller-0 ts2phc: debug [5658.711] enp138s0f0 extts index 0 at 1649259214.999999673 corr 0 src 1649259215.602748084 diff -327
2022-04-06T16:14:47.000 controller-0 ts2phc: debug [5658.711] enp138s0f0 master offset -327 s2 freq +96
2022-04-06T16:14:48.000 controller-0 ts2phc: debug [5659.711] nmea delay: 2509948356591 ns
2022-04-06T16:14:48.000 controller-0 ts2phc: debug [5659.711] enp81s0f0 extts index 0 at 1649259215.999999597 corr 0 src 1649259216.647931976 diff -403
2022-04-06T16:14:48.000 controller-0 ts2phc: debug [5659.711] enp81s0f0 master offset -403 s2 freq -99
2022-04-06T16:14:48.000 controller-0 ts2phc: debug [5659.711] enp138s0f0 extts index 0 at 1649259215.999999576 corr 0 src 1649259216.647931976 diff -424
2022-04-06T16:14:48.000 controller-0 ts2phc: debug [5659.711] enp138s0f0 master offset -424 s2 freq -99
2022-04-06T16:14:49.000 controller-0 ts2phc: debug [5660.711] nmea delay: 2509934274125 ns
2022-04-06T16:14:49.000 controller-0 ts2phc: debug [5660.711] enp81s0f0 extts index 0 at 1649259216.999999695 corr 0 src 1649259217.661995587 diff -305
2022-04-06T16:14:49.000 controller-0 ts2phc: debug [5660.711] enp81s0f0 master offset -305 s2 freq -122
2022-04-06T16:14:49.000 controller-0 ts2phc: debug [5660.711] enp138s0f0 extts index 0 at 1649259216.999999675 corr 0 src 1649259217.661995587 diff -325
2022-04-06T16:14:49.000 controller-0 ts2phc: debug [5660.711] enp138s0f0 master offset -325 s2 freq -127
2022-04-06T16:14:50.000 controller-0 ts2phc: debug [5661.711] nmea delay: 2509872356945 ns
2022-04-06T16:14:50.000 controller-0 ts2phc: debug [5661.711] enp138s0f0 extts index 0 at 1649259217.999999802 corr 0 src 1649259218.723898860 diff -198
2022-04-06T16:14:50.000 controller-0 ts2phc: debug [5661.711] enp138s0f0 master offset -198 s2 freq -98
2022-04-06T16:14:50.000 controller-0 ts2phc: debug [5661.719] nmea delay: 2509872356945 ns
2022-04-06T16:14:50.000 controller-0 ts2phc: debug [5661.719] enp81s0f0 extts index 0 at 1649259217.999999817 corr 0 src 1649259218.731992063 diff -183
2022-04-06T16:14:50.000 controller-0 ts2phc: debug [5661.719] enp81s0f0 master offset -183 s2 freq -91
2022-04-06T16:14:51.000 controller-0 ts2phc: debug [5662.711] nmea delay: 2509933742082 ns
2022-04-06T16:14:51.000 controller-0 ts2phc: debug [5662.711] enp81s0f0 extts index 0 at 1649259218.999999908 corr 0 src 1649259219.662487750 diff -92
2022-04-06T16:14:51.000 controller-0 ts2phc: debug [5662.711] enp81s0f0 master offset -92 s2 freq -55
2022-04-06T16:14:51.000 controller-0 ts2phc: debug [5662.713] enp138s0f0 extts index 0 at 1649259218.999999899 corr 0 src 1649259219.662487750 diff -101
2022-04-06T16:14:51.000 controller-0 ts2phc: debug [5662.713] enp138s0f0 master offset -101 s2 freq -60
2022-04-06T16:14:52.000 controller-0 ts2phc: debug [5663.711] nmea delay: 2509775065917 ns
2022-04-06T16:14:52.000 controller-0 ts2phc: debug [5663.711] enp81s0f0 extts index 0 at 1649259219.999999963 corr 0 src 1649259220.821147460 diff -37
2022-04-06T16:14:52.000 controller-0 ts2phc: debug [5663.711] enp81s0f0 master offset -37 s2 freq -28
2022-04-06T16:14:52.000 controller-0 ts2phc: debug [5663.711] enp138s0f0 extts index 0 at 1649259219.999999959 corr 0 src 1649259220.821147460 diff -41
2022-04-06T16:14:52.000 controller-0 ts2phc: debug [5663.711] enp138s0f0 master offset -41 s2 freq -30
2022-04-06T16:14:53.000 controller-0 ts2phc: debug [5664.711] nmea delay: 2509967368784 ns
2022-04-06T16:14:53.000 controller-0 ts2phc: debug [5664.711] enp81s0f0 extts index 0 at 1649259220.999999992 corr 0 src 1649259221.628826145 diff -8
2022-04-06T16:14:53.000 controller-0 ts2phc: debug [5664.711] enp81s0f0 master offset -8 s2 freq -10
2022-04-06T16:14:53.000 controller-0 ts2phc: debug [5664.711] enp138s0f0 extts index 0 at 1649259220.999999989 corr 0 src 1649259221.628826145 diff -11
2022-04-06T16:14:53.000 controller-0 ts2phc: debug [5664.711] enp138s0f0 master offset -11 s2 freq -13
2022-04-06T16:14:54.000 controller-0 ts2phc: debug [5665.710] nmea delay: 2509977424196 ns
2022-04-06T16:14:54.000 controller-0 ts2phc: debug [5665.711] enp81s0f0 extts index 0 at 1649259222.000000000 corr 0 src 1649259222.618754760 diff 0
2022-04-06T16:14:54.000 controller-0 ts2phc: debug [5665.711] enp81s0f0 master offset 0 s2 freq -4
2022-04-06T16:14:54.000 controller-0 ts2phc: debug [5665.711] enp138s0f0 extts index 0 at 1649259222.000000002 corr 0 src 1649259222.618754760 diff 2
2022-04-06T16:14:54.000 controller-0 ts2phc: debug [5665.711] enp138s0f0 master offset 2 s2 freq -3
2022-04-06T16:14:55.000 controller-0 ts2phc: debug [5666.710] nmea delay: 2509995474831 ns
2022-04-06T16:14:55.000 controller-0 ts2phc: debug [5666.711] enp81s0f0 extts index 0 at 1649259223.000000004 corr 0 src 1649259223.600686830 diff 4
2022-04-06T16:14:55.000 controller-0 ts2phc: debug [5666.711] enp81s0f0 master offset 4 s2 freq -0
2022-04-06T16:14:55.000 controller-0 ts2phc: debug [5666.711] enp138s0f0 extts index 0 at 1649259223.000000004 corr 0 src 1649259223.600686830 diff 4
2022-04-06T16:14:55.000 controller-0 ts2phc: debug [5666.711] enp138s0f0 master offset 4 s2 freq -0
2022-04-06T16:14:56.000 controller-0 ts2phc: debug [5667.710] nmea delay: 2510018314999 ns
2022-04-06T16:14:56.000 controller-0 ts2phc: debug [5667.710] enp81s0f0 extts index 0 at 1649259224.000000004 corr 0 src 1649259224.577832227 diff 4
2022-04-06T16:14:56.000 controller-0 ts2phc: debug [5667.711] enp81s0f0 master offset 4 s2 freq +1
2022-04-06T16:14:56.000 controller-0 ts2phc: debug [5667.711] enp138s0f0 extts index 0 at 1649259224.000000005 corr 0 src 1649259224.577832227 diff 5
________________________________
From: Keller, Jacob E <jac...@in...>
Sent: March 31, 2022 8:59 PM
To: Cole Walker <ce....@li...>; lin...@li... <lin...@li...>
Subject: Re: [Linuxptp-users] ts2phc master offset value periodically spikes
On 3/31/2022 2:44 PM, Cole Walker wrote:
> Thanks for the reply, Jacob.
>
> The kernel is 5.10.74-200.1644
>
> I am going to try the 1.8.3 ICE driver first, as that is easier than a
> kernel change in my environment.
>
> Do you have any insight as to what could be causing the nmea delay to
> increase like that? Would the driver affect it? It does seem to be a
> common factor in this behaviour and I wonder if it is worth
> investigating further.
>
> Cole
Sure. Please try out the 1.8.3 ICE driver and let me see if there's any
results different.
I suspect that something must be going wrong with delivering the
timestamps to ts2phc, either in the device or in the driver. Nothing
else makes much sense. You get an incorrect timestamp, and then it
ofcourse thinks there is a big delay, so it starts frequency tuning,
then the next few timestamps are valid so it eventually corrects itself.
I doubt this is a bug in ts2phc but perhaps it is. I am a bit suspicious
of that particular line in ts2phc you brought up where that check adds
to the second value.
The jump in difference is almost exactly 0.5 seconds. That feels quite
suspicious.
Thanks,
Jake
|
|
From: Jakub R. <j.r...@el...> - 2022-04-11 15:12:53
|
Greetings, While testing devices with gPTP we encountered, in our opinion, quite inconsequential behavior. Using different setups, we set following flags and had following outcome: gmCapable = 0 , slaveOnly = 0 -> OK gmCapable = 1 , slaveOnly = 0 -> OK gmCapable = 0 , slaveOnly = 1 -> Cannot mix 1588 slaveOnly with 802.1AS !gmCapable gmCapable = 1 , slaveOnly = 1 -> OK Frankly, I would expect combination of "gmCapable = 1 , slaveOnly = 1" to fail rather than "gmCapable = 0 , slaveOnly = 1". masterOnly flags are working properly. For some devices we really want to keep slaveOnly devices, even with gPTP, but we were surprised that these options are mutually exclusive. Is there a particular reason only one of these cases fails to start? Best regards Jakub Raczynski |
|
From: Sunil K. <mn....@gm...> - 2022-04-09 01:32:27
|
Thanks for the update. On Fri, Apr 8, 2022, 10:12 PM Richard Cochran <ric...@gm...> wrote: > On Wed, Apr 06, 2022 at 10:15:34AM +0530, Sunil Kumar wrote: > > I would like to know what is the timeline for release of Linux PTP stack > > which adheres/supports to IEEE802.1AS-2020 > > No timeline and no plans to support that. > > Thanks, > Richard > |
|
From: Richard C. <ric...@gm...> - 2022-04-08 16:42:45
|
On Wed, Apr 06, 2022 at 10:15:34AM +0530, Sunil Kumar wrote: > I would like to know what is the timeline for release of Linux PTP stack > which adheres/supports to IEEE802.1AS-2020 No timeline and no plans to support that. Thanks, Richard |
|
From: Sunil K. <mn....@gm...> - 2022-04-08 03:33:27
|
Hi Richard, Sorry to disturb your busy schedule, Could you please help me in finding any information available on linuxptp stack support for IEEE802.1AS-2020 standard is there any release timeline finalized I have sent mail to linuxptp user and devel lists but, i haven't received any response from them If you could you point in the right direction(i.e., whom to contact to get this information) it would be extremely helpful Regards, Sunil Kumar Regards, Sunil Kumar +91-8904376498 On Wed, Apr 6, 2022 at 10:15 AM Sunil Kumar <mn....@gm...> wrote: > Hi Respected Sir, > > I would like to know what is the timeline for release of Linux PTP stack > which adheres/supports to IEEE802.1AS-2020 > If it is already released codul you please let me know how to access the > same > Eager awaiting your kind response > > Thanks & Regards, > Sunil Kumar > |
|
From: Cole W. <ce....@li...> - 2022-04-06 16:52:37
|
Unfortunately, the issue is still present with the 1.8.3 ice driver. Logs are at the end of this message.
Interesting that the nmea delay is much higher at all times now. This is from the same system as the previous data.
Anecdotally, it seems less frequent.
I also did a little more digging around the code I referenced earlier
ts2phc_slave.c ts2phc_slave_offset()
if (source_ts.tv_nsec > 500000000) {
source_ts.tv_sec++;
}
Normally the PPS ensures that tv_nsec is pretty close to the previous value, because one second has elapsed.
But in cases where there is a large nmea delay spike, the tv_nsec value could be at say 100000000, because the seconds value has rolled over.
The logic here in ts2phc seems to only advance the tv_sec value based on the tv_nsec value, which leads to cases like in the logs below where the second value was not incremented, even though it should be.
I'm not sure what the correct solution for this would be? Should ts2phc be performing a more robust check to compute the tv_sec value?
I tried something like this just to see what the behaviour would be and it prevented the master offset issue. I'm not sure what the implications of always advancing the timing might be though.
if (source_ts.tv_nsec > 500000000) {
source_ts.tv_sec++;
} else {
source_ts.tv_sec++;
pr_info("Timing went weird, advancing tv_sec anyways.");
}
2022-04-06T17:09:22.000 controller-0 ts2phc: info [8933.654] tv_sec 1649262489
2022-04-06T17:09:22.000 controller-0 ts2phc: info [8933.654] tv_nsec 499622726
2022-04-06T17:09:22.000 controller-0 ts2phc: info [8933.654] Timing went weird, advancing tv_sec anyways.
2022-04-06T17:09:22.000 controller-0 ts2phc: info [8933.654] enp81s0f0 extts index 0 at 1649262490.000000000 corr 0 src 1649262490.499622726 diff 0
2022-04-06T17:09:22.000 controller-0 ts2phc: info [8933.654] enp81s0f0 master offset 0 s2 freq +0
### Reproduction of issue
ethtool -i enp81s0f0
driver: ice
version: 1.8.3
firmware-version: 3.10 0x80009be5 1.3086.0
expansion-rom-version:
bus-info: 0000:51:00.0
supports-statistics: yes
supports-test: yes
supports-eeprom-access: yes
supports-register-dump: yes
supports-priv-flags: yes
Logs:
2022-04-06T16:14:18.000 controller-0 ts2phc: debug [5629.712] enp138s0f0 extts index 0 at 1649259186.000000000 corr 0 src 1649259186.903003525 diff 0
2022-04-06T16:14:18.000 controller-0 ts2phc: debug [5629.712] enp138s0f0 master offset 0 s2 freq +0
2022-04-06T16:14:19.000 controller-0 ts2phc: debug [5630.711] nmea delay: 2509974014846 ns
2022-04-06T16:14:19.000 controller-0 ts2phc: debug [5630.711] enp81s0f0 extts index 0 at 1649259187.000000000 corr 0 src 1649259187.622769768 diff 0
2022-04-06T16:14:19.000 controller-0 ts2phc: debug [5630.711] enp81s0f0 master offset 0 s2 freq -0
2022-04-06T16:14:19.000 controller-0 ts2phc: debug [5630.712] enp138s0f0 extts index 0 at 1649259187.000000000 corr 0 src 1649259187.622769768 diff 0
2022-04-06T16:14:19.000 controller-0 ts2phc: debug [5630.712] enp138s0f0 master offset 0 s2 freq +0
2022-04-06T16:14:20.000 controller-0 ts2phc: debug [5631.711] nmea delay: 2509985703545 ns
2022-04-06T16:14:20.000 controller-0 ts2phc: debug [5631.711] enp81s0f0 extts index 0 at 1649259188.000000001 corr 0 src 1649259188.611065163 diff 1
2022-04-06T16:14:20.000 controller-0 ts2phc: debug [5631.711] enp81s0f0 master offset 1 s2 freq +1
2022-04-06T16:14:20.000 controller-0 ts2phc: debug [5631.712] enp138s0f0 extts index 0 at 1649259188.000000000 corr 0 src 1649259188.611065163 diff 0
2022-04-06T16:14:20.000 controller-0 ts2phc: debug [5631.712] enp138s0f0 master offset 0 s2 freq +0
2022-04-06T16:14:21.000 controller-0 ts2phc: debug [5632.711] nmea delay: 2509975679106 ns
2022-04-06T16:14:21.000 controller-0 ts2phc: debug [5632.711] enp81s0f0 extts index 0 at 1649259189.000000000 corr 0 src 1649259189.621072451 diff 0
2022-04-06T16:14:21.000 controller-0 ts2phc: debug [5632.711] enp81s0f0 master offset 0 s2 freq +0
2022-04-06T16:14:21.000 controller-0 ts2phc: debug [5632.712] enp138s0f0 extts index 0 at 1649259189.000000000 corr 0 src 1649259189.621072451 diff 0
2022-04-06T16:14:21.000 controller-0 ts2phc: debug [5632.712] enp138s0f0 master offset 0 s2 freq +0
2022-04-06T16:14:22.000 controller-0 ts2phc: debug [5633.711] nmea delay: 2510153705944 ns
# Nmea delay increases by 178,026,838 ns - less than before
# Issue appears here
2022-04-06T16:14:22.000 controller-0 ts2phc: debug [5633.711] enp81s0f0 extts index 0 at 1649259190.000000000 corr 0 src 1649259189.443022927 diff 1000000000
### The src value here should have had its seconds value incremented, but because of how ts2phc is only checking the nanoseconds value, it did not. The real source time is actually
### 1649259190.443022927
2022-04-06T16:14:22.000 controller-0 ts2phc: debug [5633.711] enp81s0f0 master offset 1000000000 s2 freq +900000000
2022-04-06T16:14:22.000 controller-0 ts2phc: debug [5633.712] enp138s0f0 extts index 0 at 1649259190.000000000 corr 0 src 1649259189.443022927 diff 1000000000
2022-04-06T16:14:22.000 controller-0 ts2phc: debug [5633.712] enp138s0f0 master offset 1000000000 s2 freq +900000000
2022-04-06T16:14:23.000 controller-0 ts2phc: debug [5634.711] nmea delay: 2509910614292 ns
2022-04-06T16:14:23.000 controller-0 ts2phc: debug [5634.711] enp81s0f0 extts index 0 at 1649259190.100442268 corr 0 src 1649259191.686226081 diff -899557732
2022-04-06T16:14:23.000 controller-0 ts2phc: debug [5634.711] enp81s0f0 master offset -899557732 s2 freq -899557732
2022-04-06T16:14:23.000 controller-0 ts2phc: debug [5634.735] nmea delay: 2509910614292 ns
2022-04-06T16:14:23.000 controller-0 ts2phc: debug [5634.735] enp138s0f0 extts index 0 at 1649259190.100838162 corr 0 src 1649259191.709715088 diff -899161838
2022-04-06T16:14:23.000 controller-0 ts2phc: debug [5634.735] enp138s0f0 master offset -899161838 s2 freq -899161838
2022-04-06T16:14:24.000 controller-0 ts2phc: debug [5635.711] nmea delay: 2509934750724 ns
2022-04-06T16:14:24.000 controller-0 ts2phc: debug [5635.711] enp138s0f0 extts index 0 at 1649259191.956652053 corr 0 src 1649259192.661952069 diff -43347947
2022-04-06T16:14:24.000 controller-0 ts2phc: debug [5635.711] enp138s0f0 master offset -43347947 s2 freq -313096498
2022-04-06T16:14:24.000 controller-0 ts2phc: debug [5635.734] nmea delay: 2509934750724 ns
2022-04-06T16:14:24.000 controller-0 ts2phc: debug [5635.734] enp81s0f0 extts index 0 at 1649259191.998895877 corr 0 src 1649259192.685191330 diff -1104123
2022-04-06T16:14:24.000 controller-0 ts2phc: debug [5635.734] enp81s0f0 master offset -1104123 s2 freq -270971442
2022-04-06T16:14:25.000 controller-0 ts2phc: debug [5636.711] nmea delay: 2509932763703 ns
2022-04-06T16:14:25.000 controller-0 ts2phc: debug [5636.711] enp81s0f0 extts index 0 at 1649259193.285100826 corr 0 src 1649259193.663917395 diff 285100826
2022-04-06T16:14:25.000 controller-0 ts2phc: debug [5636.711] enp81s0f0 master offset 285100826 s2 freq +14902270
2022-04-06T16:14:25.000 controller-0 ts2phc: debug [5636.711] enp138s0f0 extts index 0 at 1649259193.270039664 corr 0 src 1649259193.663917395 diff 270039664
2022-04-06T16:14:25.000 controller-0 ts2phc: debug [5636.711] enp138s0f0 master offset 270039664 s2 freq -12713272
2022-04-06T16:14:26.000 controller-0 ts2phc: debug [5637.711] nmea delay: 2509951412014 ns
2022-04-06T16:14:26.000 controller-0 ts2phc: debug [5637.711] enp81s0f0 extts index 0 at 1649259194.270335612 corr 0 src 1649259194.645246996 diff 270335612
2022-04-06T16:14:26.000 controller-0 ts2phc: debug [5637.711] enp81s0f0 master offset 270335612 s2 freq +85667303
2022-04-06T16:14:26.000 controller-0 ts2phc: debug [5637.711] enp138s0f0 extts index 0 at 1649259194.283026443 corr 0 src 1649259194.645246996 diff 283026443
2022-04-06T16:14:26.000 controller-0 ts2phc: debug [5637.711] enp138s0f0 master offset 283026443 s2 freq +81285407
2022-04-06T16:14:27.000 controller-0 ts2phc: debug [5638.711] nmea delay: 2509955664247 ns
2022-04-06T16:14:27.000 controller-0 ts2phc: debug [5638.711] enp81s0f0 extts index 0 at 1649259195.184702116 corr 0 src 1649259195.640978094 diff 184702116
2022-04-06T16:14:27.000 controller-0 ts2phc: debug [5638.711] enp81s0f0 master offset 184702116 s2 freq +81134491
2022-04-06T16:14:27.000 controller-0 ts2phc: debug [5638.711] enp138s0f0 extts index 0 at 1649259195.201826252 corr 0 src 1649259195.640978094 diff 201826252
2022-04-06T16:14:27.000 controller-0 ts2phc: debug [5638.711] enp138s0f0 master offset 201826252 s2 freq +84993149
2022-04-06T16:14:28.000 controller-0 ts2phc: debug [5639.711] nmea delay: 2509976851503 ns
2022-04-06T16:14:28.000 controller-0 ts2phc: debug [5639.711] enp81s0f0 extts index 0 at 1649259196.103565395 corr 0 src 1649259196.619782066 diff 103565395
2022-04-06T16:14:28.000 controller-0 ts2phc: debug [5639.711] enp81s0f0 master offset 103565395 s2 freq +55408405
2022-04-06T16:14:28.000 controller-0 ts2phc: debug [5639.711] enp138s0f0 extts index 0 at 1649259196.116836545 corr 0 src 1649259196.619782066 diff 116836545
2022-04-06T16:14:28.000 controller-0 ts2phc: debug [5639.711] enp138s0f0 master offset 116836545 s2 freq +60551317
2022-04-06T16:14:29.000 controller-0 ts2phc: debug [5640.711] nmea delay: 2509968770585 ns
2022-04-06T16:14:29.000 controller-0 ts2phc: debug [5640.711] enp81s0f0 extts index 0 at 1649259197.048144368 corr 0 src 1649259197.627846823 diff 48144368
2022-04-06T16:14:29.000 controller-0 ts2phc: debug [5640.711] enp81s0f0 master offset 48144368 s2 freq +31056996
2022-04-06T16:14:29.000 controller-0 ts2phc: debug [5640.711] enp138s0f0 extts index 0 at 1649259197.056262530 corr 0 src 1649259197.627846823 diff 56262530
2022-04-06T16:14:29.000 controller-0 ts2phc: debug [5640.711] enp138s0f0 master offset 56262530 s2 freq +35028266
2022-04-06T16:14:30.000 controller-0 ts2phc: debug [5641.711] nmea delay: 2509756017458 ns
2022-04-06T16:14:30.000 controller-0 ts2phc: debug [5641.711] enp81s0f0 extts index 0 at 1649259198.017075025 corr 0 src 1649259198.840576852 diff 17075025
2022-04-06T16:14:30.000 controller-0 ts2phc: debug [5641.711] enp81s0f0 master offset 17075025 s2 freq +14430964
2022-04-06T16:14:30.000 controller-0 ts2phc: debug [5641.711] enp138s0f0 extts index 0 at 1649259198.021210240 corr 0 src 1649259198.840576852 diff 21210240
2022-04-06T16:14:30.000 controller-0 ts2phc: debug [5641.711] enp138s0f0 master offset 21210240 s2 freq +16854735
2022-04-06T16:14:31.000 controller-0 ts2phc: debug [5642.711] nmea delay: 2509827437737 ns
2022-04-06T16:14:31.000 controller-0 ts2phc: debug [5642.711] enp81s0f0 extts index 0 at 1649259199.002635929 corr 0 src 1649259199.769146714 diff 2635929
2022-04-06T16:14:31.000 controller-0 ts2phc: debug [5642.711] enp81s0f0 master offset 2635929 s2 freq +5114375
2022-04-06T16:14:31.000 controller-0 ts2phc: debug [5642.711] enp138s0f0 extts index 0 at 1649259199.004338678 corr 0 src 1649259199.769146714 diff 4338678
2022-04-06T16:14:31.000 controller-0 ts2phc: debug [5642.711] enp138s0f0 master offset 4338678 s2 freq +6346245
2022-04-06T16:14:32.000 controller-0 ts2phc: debug [5643.711] nmea delay: 2509935546499 ns
2022-04-06T16:14:32.000 controller-0 ts2phc: debug [5643.711] enp81s0f0 extts index 0 at 1649259199.997516909 corr 0 src 1649259200.661016877 diff -2483091
2022-04-06T16:14:32.000 controller-0 ts2phc: debug [5643.711] enp81s0f0 master offset -2483091 s2 freq +786134
2022-04-06T16:14:32.000 controller-0 ts2phc: debug [5643.735] nmea delay: 2509935546499 ns
2022-04-06T16:14:32.000 controller-0 ts2phc: debug [5643.735] enp138s0f0 extts index 0 at 1649259199.997982651 corr 0 src 1649259200.685558481 diff -2017349
2022-04-06T16:14:32.000 controller-0 ts2phc: debug [5643.735] enp138s0f0 master offset -2017349 s2 freq +1291821
2022-04-06T16:14:33.000 controller-0 ts2phc: debug [5644.711] nmea delay: 2509920466181 ns
2022-04-06T16:14:33.000 controller-0 ts2phc: debug [5644.711] enp81s0f0 extts index 0 at 1649259200.996728630 corr 0 src 1649259201.676078609 diff -3271370
2022-04-06T16:14:33.000 controller-0 ts2phc: debug [5644.711] enp81s0f0 master offset -3271370 s2 freq -747072
2022-04-06T16:14:33.000 controller-0 ts2phc: debug [5644.711] enp138s0f0 extts index 0 at 1649259200.996564380 corr 0 src 1649259201.676078609 diff -3435620
2022-04-06T16:14:33.000 controller-0 ts2phc: debug [5644.711] enp138s0f0 master offset -3435620 s2 freq -731655
2022-04-06T16:14:34.000 controller-0 ts2phc: debug [5645.711] nmea delay: 2509926722531 ns
2022-04-06T16:14:34.000 controller-0 ts2phc: debug [5645.711] enp81s0f0 extts index 0 at 1649259201.997474950 corr 0 src 1649259202.669808104 diff -2525050
2022-04-06T16:14:34.000 controller-0 ts2phc: debug [5645.711] enp81s0f0 master offset -2525050 s2 freq -982163
2022-04-06T16:14:34.000 controller-0 ts2phc: debug [5645.711] enp138s0f0 extts index 0 at 1649259201.997294167 corr 0 src 1649259202.669808104 diff -2705833
2022-04-06T16:14:34.000 controller-0 ts2phc: debug [5645.711] enp138s0f0 master offset -2705833 s2 freq -1032554
2022-04-06T16:14:35.000 controller-0 ts2phc: debug [5646.711] nmea delay: 2509941317000 ns
2022-04-06T16:14:35.000 controller-0 ts2phc: debug [5646.711] enp81s0f0 extts index 0 at 1649259202.998456996 corr 0 src 1649259203.655186682 diff -1543004
2022-04-06T16:14:35.000 controller-0 ts2phc: debug [5646.711] enp81s0f0 master offset -1543004 s2 freq -757632
2022-04-06T16:14:35.000 controller-0 ts2phc: debug [5646.711] enp138s0f0 extts index 0 at 1649259202.998326440 corr 0 src 1649259203.655186682 diff -1673560
2022-04-06T16:14:35.000 controller-0 ts2phc: debug [5646.711] enp138s0f0 master offset -1673560 s2 freq -812031
2022-04-06T16:14:36.000 controller-0 ts2phc: debug [5647.711] nmea delay: 2509814140165 ns
2022-04-06T16:14:36.000 controller-0 ts2phc: debug [5647.711] enp81s0f0 extts index 0 at 1649259203.999214738 corr 0 src 1649259204.782347244 diff -785262
2022-04-06T16:14:36.000 controller-0 ts2phc: debug [5647.711] enp81s0f0 master offset -785262 s2 freq -462792
2022-04-06T16:14:36.000 controller-0 ts2phc: debug [5647.711] enp138s0f0 extts index 0 at 1649259203.999138674 corr 0 src 1649259204.782347244 diff -861326
2022-04-06T16:14:36.000 controller-0 ts2phc: debug [5647.711] enp138s0f0 master offset -861326 s2 freq -501865
2022-04-06T16:14:37.000 controller-0 ts2phc: debug [5648.711] nmea delay: 2509751928748 ns
2022-04-06T16:14:37.000 controller-0 ts2phc: debug [5648.711] enp81s0f0 extts index 0 at 1649259204.999677674 corr 0 src 1649259205.844542654 diff -322326
2022-04-06T16:14:37.000 controller-0 ts2phc: debug [5648.711] enp81s0f0 master offset -322326 s2 freq -235434
2022-04-06T16:14:37.000 controller-0 ts2phc: debug [5648.711] enp138s0f0 extts index 0 at 1649259204.999640826 corr 0 src 1649259205.844542654 diff -359174
2022-04-06T16:14:37.000 controller-0 ts2phc: debug [5648.711] enp138s0f0 master offset -359174 s2 freq -258110
2022-04-06T16:14:38.000 controller-0 ts2phc: debug [5649.711] nmea delay: 2509991234371 ns
2022-04-06T16:14:38.000 controller-0 ts2phc: debug [5649.711] enp81s0f0 extts index 0 at 1649259205.999913221 corr 0 src 1649259206.605219127 diff -86779
2022-04-06T16:14:38.000 controller-0 ts2phc: debug [5649.711] enp81s0f0 master offset -86779 s2 freq -96585
2022-04-06T16:14:38.000 controller-0 ts2phc: debug [5649.711] enp138s0f0 extts index 0 at 1649259205.999899162 corr 0 src 1649259206.605219127 diff -100838
2022-04-06T16:14:38.000 controller-0 ts2phc: debug [5649.711] enp138s0f0 master offset -100838 s2 freq -107527
2022-04-06T16:14:39.000 controller-0 ts2phc: debug [5650.711] nmea delay: 2509947413836 ns
2022-04-06T16:14:39.000 controller-0 ts2phc: debug [5650.711] enp81s0f0 extts index 0 at 1649259207.000009874 corr 0 src 1649259207.649028886 diff 9874
2022-04-06T16:14:39.000 controller-0 ts2phc: debug [5650.711] enp81s0f0 master offset 9874 s2 freq -25966
2022-04-06T16:14:39.000 controller-0 ts2phc: debug [5650.711] enp138s0f0 extts index 0 at 1649259207.000006827 corr 0 src 1649259207.649028886 diff 6827
2022-04-06T16:14:39.000 controller-0 ts2phc: debug [5650.711] enp138s0f0 master offset 6827 s2 freq -30113
2022-04-06T16:14:40.000 controller-0 ts2phc: debug [5651.711] nmea delay: 2509936137470 ns
2022-04-06T16:14:40.000 controller-0 ts2phc: debug [5651.711] enp81s0f0 extts index 0 at 1649259208.000035874 corr 0 src 1649259208.660289498 diff 35874
2022-04-06T16:14:40.000 controller-0 ts2phc: debug [5651.711] enp81s0f0 master offset 35874 s2 freq +2997
2022-04-06T16:14:40.000 controller-0 ts2phc: debug [5651.711] enp138s0f0 extts index 0 at 1649259208.000037012 corr 0 src 1649259208.660289498 diff 37012
2022-04-06T16:14:40.000 controller-0 ts2phc: debug [5651.711] enp138s0f0 master offset 37012 s2 freq +2120
2022-04-06T16:14:41.000 controller-0 ts2phc: debug [5652.711] nmea delay: 2509928033738 ns
2022-04-06T16:14:41.000 controller-0 ts2phc: debug [5652.711] enp81s0f0 extts index 0 at 1649259209.000032893 corr 0 src 1649259209.668373960 diff 32893
2022-04-06T16:14:41.000 controller-0 ts2phc: debug [5652.711] enp81s0f0 master offset 32893 s2 freq +10778
2022-04-06T16:14:41.000 controller-0 ts2phc: debug [5652.712] enp138s0f0 extts index 0 at 1649259209.000034923 corr 0 src 1649259209.668373960 diff 34923
2022-04-06T16:14:41.000 controller-0 ts2phc: debug [5652.712] enp138s0f0 master offset 34923 s2 freq +11135
2022-04-06T16:14:42.000 controller-0 ts2phc: debug [5653.711] nmea delay: 2509940063772 ns
2022-04-06T16:14:42.000 controller-0 ts2phc: debug [5653.711] enp81s0f0 extts index 0 at 1649259210.000022122 corr 0 src 1649259210.656329379 diff 22122
2022-04-06T16:14:42.000 controller-0 ts2phc: debug [5653.711] enp81s0f0 master offset 22122 s2 freq +9875
2022-04-06T16:14:42.000 controller-0 ts2phc: debug [5653.711] enp138s0f0 extts index 0 at 1649259210.000023801 corr 0 src 1649259210.656329379 diff 23801
2022-04-06T16:14:42.000 controller-0 ts2phc: debug [5653.711] enp138s0f0 master offset 23801 s2 freq +10490
2022-04-06T16:14:43.000 controller-0 ts2phc: debug [5654.711] nmea delay: 2509927318786 ns
2022-04-06T16:14:43.000 controller-0 ts2phc: debug [5654.711] enp138s0f0 extts index 0 at 1649259211.000013309 corr 0 src 1649259211.669047253 diff 13309
2022-04-06T16:14:43.000 controller-0 ts2phc: debug [5654.711] enp138s0f0 master offset 13309 s2 freq +7138
2022-04-06T16:14:43.000 controller-0 ts2phc: debug [5654.711] nmea delay: 2509927318786 ns
2022-04-06T16:14:43.000 controller-0 ts2phc: debug [5654.711] enp81s0f0 extts index 0 at 1649259211.000012247 corr 0 src 1649259211.669529431 diff 12247
2022-04-06T16:14:43.000 controller-0 ts2phc: debug [5654.711] enp81s0f0 master offset 12247 s2 freq +6636
2022-04-06T16:14:44.000 controller-0 ts2phc: debug [5655.711] nmea delay: 2509787447823 ns
2022-04-06T16:14:44.000 controller-0 ts2phc: debug [5655.711] enp81s0f0 extts index 0 at 1649259212.000005608 corr 0 src 1649259212.808906417 diff 5608
2022-04-06T16:14:44.000 controller-0 ts2phc: debug [5655.711] enp81s0f0 master offset 5608 s2 freq +3671
2022-04-06T16:14:44.000 controller-0 ts2phc: debug [5655.711] enp138s0f0 extts index 0 at 1649259212.000006170 corr 0 src 1649259212.808906417 diff 6170
2022-04-06T16:14:44.000 controller-0 ts2phc: debug [5655.711] enp138s0f0 master offset 6170 s2 freq +3992
2022-04-06T16:14:45.000 controller-0 ts2phc: debug [5656.711] nmea delay: 2509951116255 ns
2022-04-06T16:14:45.000 controller-0 ts2phc: debug [5656.711] enp81s0f0 extts index 0 at 1649259213.000001935 corr 0 src 1649259213.645217296 diff 1935
2022-04-06T16:14:45.000 controller-0 ts2phc: debug [5656.711] enp81s0f0 master offset 1935 s2 freq +1681
2022-04-06T16:14:45.000 controller-0 ts2phc: debug [5656.711] enp138s0f0 extts index 0 at 1649259213.000002176 corr 0 src 1649259213.645217296 diff 2176
2022-04-06T16:14:45.000 controller-0 ts2phc: debug [5656.711] enp138s0f0 master offset 2176 s2 freq +1849
2022-04-06T16:14:46.000 controller-0 ts2phc: debug [5657.711] nmea delay: 2509962512441 ns
2022-04-06T16:14:46.000 controller-0 ts2phc: debug [5657.711] enp81s0f0 extts index 0 at 1649259214.000000255 corr 0 src 1649259214.633802454 diff 255
2022-04-06T16:14:46.000 controller-0 ts2phc: debug [5657.711] enp81s0f0 master offset 255 s2 freq +581
2022-04-06T16:14:46.000 controller-0 ts2phc: debug [5657.711] nmea delay: 2509962512441 ns
2022-04-06T16:14:46.000 controller-0 ts2phc: debug [5657.711] enp138s0f0 extts index 0 at 1649259214.000000326 corr 0 src 1649259214.634282788 diff 326
2022-04-06T16:14:46.000 controller-0 ts2phc: debug [5657.711] enp138s0f0 master offset 326 s2 freq +651
2022-04-06T16:14:47.000 controller-0 ts2phc: debug [5658.711] nmea delay: 2509993558162 ns
2022-04-06T16:14:47.000 controller-0 ts2phc: debug [5658.711] enp81s0f0 extts index 0 at 1649259214.999999672 corr 0 src 1649259215.602748084 diff -328
2022-04-06T16:14:47.000 controller-0 ts2phc: debug [5658.711] enp81s0f0 master offset -328 s2 freq +75
2022-04-06T16:14:47.000 controller-0 ts2phc: debug [5658.711] enp138s0f0 extts index 0 at 1649259214.999999673 corr 0 src 1649259215.602748084 diff -327
2022-04-06T16:14:47.000 controller-0 ts2phc: debug [5658.711] enp138s0f0 master offset -327 s2 freq +96
2022-04-06T16:14:48.000 controller-0 ts2phc: debug [5659.711] nmea delay: 2509948356591 ns
2022-04-06T16:14:48.000 controller-0 ts2phc: debug [5659.711] enp81s0f0 extts index 0 at 1649259215.999999597 corr 0 src 1649259216.647931976 diff -403
2022-04-06T16:14:48.000 controller-0 ts2phc: debug [5659.711] enp81s0f0 master offset -403 s2 freq -99
2022-04-06T16:14:48.000 controller-0 ts2phc: debug [5659.711] enp138s0f0 extts index 0 at 1649259215.999999576 corr 0 src 1649259216.647931976 diff -424
2022-04-06T16:14:48.000 controller-0 ts2phc: debug [5659.711] enp138s0f0 master offset -424 s2 freq -99
2022-04-06T16:14:49.000 controller-0 ts2phc: debug [5660.711] nmea delay: 2509934274125 ns
2022-04-06T16:14:49.000 controller-0 ts2phc: debug [5660.711] enp81s0f0 extts index 0 at 1649259216.999999695 corr 0 src 1649259217.661995587 diff -305
2022-04-06T16:14:49.000 controller-0 ts2phc: debug [5660.711] enp81s0f0 master offset -305 s2 freq -122
2022-04-06T16:14:49.000 controller-0 ts2phc: debug [5660.711] enp138s0f0 extts index 0 at 1649259216.999999675 corr 0 src 1649259217.661995587 diff -325
2022-04-06T16:14:49.000 controller-0 ts2phc: debug [5660.711] enp138s0f0 master offset -325 s2 freq -127
2022-04-06T16:14:50.000 controller-0 ts2phc: debug [5661.711] nmea delay: 2509872356945 ns
2022-04-06T16:14:50.000 controller-0 ts2phc: debug [5661.711] enp138s0f0 extts index 0 at 1649259217.999999802 corr 0 src 1649259218.723898860 diff -198
2022-04-06T16:14:50.000 controller-0 ts2phc: debug [5661.711] enp138s0f0 master offset -198 s2 freq -98
2022-04-06T16:14:50.000 controller-0 ts2phc: debug [5661.719] nmea delay: 2509872356945 ns
2022-04-06T16:14:50.000 controller-0 ts2phc: debug [5661.719] enp81s0f0 extts index 0 at 1649259217.999999817 corr 0 src 1649259218.731992063 diff -183
2022-04-06T16:14:50.000 controller-0 ts2phc: debug [5661.719] enp81s0f0 master offset -183 s2 freq -91
2022-04-06T16:14:51.000 controller-0 ts2phc: debug [5662.711] nmea delay: 2509933742082 ns
2022-04-06T16:14:51.000 controller-0 ts2phc: debug [5662.711] enp81s0f0 extts index 0 at 1649259218.999999908 corr 0 src 1649259219.662487750 diff -92
2022-04-06T16:14:51.000 controller-0 ts2phc: debug [5662.711] enp81s0f0 master offset -92 s2 freq -55
2022-04-06T16:14:51.000 controller-0 ts2phc: debug [5662.713] enp138s0f0 extts index 0 at 1649259218.999999899 corr 0 src 1649259219.662487750 diff -101
2022-04-06T16:14:51.000 controller-0 ts2phc: debug [5662.713] enp138s0f0 master offset -101 s2 freq -60
2022-04-06T16:14:52.000 controller-0 ts2phc: debug [5663.711] nmea delay: 2509775065917 ns
2022-04-06T16:14:52.000 controller-0 ts2phc: debug [5663.711] enp81s0f0 extts index 0 at 1649259219.999999963 corr 0 src 1649259220.821147460 diff -37
2022-04-06T16:14:52.000 controller-0 ts2phc: debug [5663.711] enp81s0f0 master offset -37 s2 freq -28
2022-04-06T16:14:52.000 controller-0 ts2phc: debug [5663.711] enp138s0f0 extts index 0 at 1649259219.999999959 corr 0 src 1649259220.821147460 diff -41
2022-04-06T16:14:52.000 controller-0 ts2phc: debug [5663.711] enp138s0f0 master offset -41 s2 freq -30
2022-04-06T16:14:53.000 controller-0 ts2phc: debug [5664.711] nmea delay: 2509967368784 ns
2022-04-06T16:14:53.000 controller-0 ts2phc: debug [5664.711] enp81s0f0 extts index 0 at 1649259220.999999992 corr 0 src 1649259221.628826145 diff -8
2022-04-06T16:14:53.000 controller-0 ts2phc: debug [5664.711] enp81s0f0 master offset -8 s2 freq -10
2022-04-06T16:14:53.000 controller-0 ts2phc: debug [5664.711] enp138s0f0 extts index 0 at 1649259220.999999989 corr 0 src 1649259221.628826145 diff -11
2022-04-06T16:14:53.000 controller-0 ts2phc: debug [5664.711] enp138s0f0 master offset -11 s2 freq -13
2022-04-06T16:14:54.000 controller-0 ts2phc: debug [5665.710] nmea delay: 2509977424196 ns
2022-04-06T16:14:54.000 controller-0 ts2phc: debug [5665.711] enp81s0f0 extts index 0 at 1649259222.000000000 corr 0 src 1649259222.618754760 diff 0
2022-04-06T16:14:54.000 controller-0 ts2phc: debug [5665.711] enp81s0f0 master offset 0 s2 freq -4
2022-04-06T16:14:54.000 controller-0 ts2phc: debug [5665.711] enp138s0f0 extts index 0 at 1649259222.000000002 corr 0 src 1649259222.618754760 diff 2
2022-04-06T16:14:54.000 controller-0 ts2phc: debug [5665.711] enp138s0f0 master offset 2 s2 freq -3
2022-04-06T16:14:55.000 controller-0 ts2phc: debug [5666.710] nmea delay: 2509995474831 ns
2022-04-06T16:14:55.000 controller-0 ts2phc: debug [5666.711] enp81s0f0 extts index 0 at 1649259223.000000004 corr 0 src 1649259223.600686830 diff 4
2022-04-06T16:14:55.000 controller-0 ts2phc: debug [5666.711] enp81s0f0 master offset 4 s2 freq -0
2022-04-06T16:14:55.000 controller-0 ts2phc: debug [5666.711] enp138s0f0 extts index 0 at 1649259223.000000004 corr 0 src 1649259223.600686830 diff 4
2022-04-06T16:14:55.000 controller-0 ts2phc: debug [5666.711] enp138s0f0 master offset 4 s2 freq -0
2022-04-06T16:14:56.000 controller-0 ts2phc: debug [5667.710] nmea delay: 2510018314999 ns
2022-04-06T16:14:56.000 controller-0 ts2phc: debug [5667.710] enp81s0f0 extts index 0 at 1649259224.000000004 corr 0 src 1649259224.577832227 diff 4
2022-04-06T16:14:56.000 controller-0 ts2phc: debug [5667.711] enp81s0f0 master offset 4 s2 freq +1
2022-04-06T16:14:56.000 controller-0 ts2phc: debug [5667.711] enp138s0f0 extts index 0 at 1649259224.000000005 corr 0 src 1649259224.577832227 diff 5
________________________________
From: Keller, Jacob E <jac...@in...>
Sent: March 31, 2022 8:59 PM
To: Cole Walker <ce....@li...>; lin...@li... <lin...@li...>
Subject: Re: [Linuxptp-users] ts2phc master offset value periodically spikes
On 3/31/2022 2:44 PM, Cole Walker wrote:
> Thanks for the reply, Jacob.
>
> The kernel is 5.10.74-200.1644
>
> I am going to try the 1.8.3 ICE driver first, as that is easier than a
> kernel change in my environment.
>
> Do you have any insight as to what could be causing the nmea delay to
> increase like that? Would the driver affect it? It does seem to be a
> common factor in this behaviour and I wonder if it is worth
> investigating further.
>
> Cole
Sure. Please try out the 1.8.3 ICE driver and let me see if there's any
results different.
I suspect that something must be going wrong with delivering the
timestamps to ts2phc, either in the device or in the driver. Nothing
else makes much sense. You get an incorrect timestamp, and then it
ofcourse thinks there is a big delay, so it starts frequency tuning,
then the next few timestamps are valid so it eventually corrects itself.
I doubt this is a bug in ts2phc but perhaps it is. I am a bit suspicious
of that particular line in ts2phc you brought up where that check adds
to the second value.
The jump in difference is almost exactly 0.5 seconds. That feels quite
suspicious.
Thanks,
Jake
|
|
From: Sunil K. <mn....@gm...> - 2022-04-06 04:45:53
|
Hi Respected Sir, I would like to know what is the timeline for release of Linux PTP stack which adheres/supports to IEEE802.1AS-2020 If it is already released codul you please let me know how to access the same Eager awaiting your kind response Thanks & Regards, Sunil Kumar |
|
From: Richard C. <ric...@gm...> - 2022-04-05 05:56:07
|
On Mon, Apr 04, 2022 at 01:25:19PM -0400, PATRICK KEROULAS wrote: > This looks simple indeed. Though, I'm not sure about the rationale > for exposing 2 sockets. Is the intention to accommodate both trusted > (GET+SET) and untrusted (GET) applications? Yes, and that is already merged. The new patch is about the configuration option. Thanks, Richard |
|
From: PATRICK K. <pat...@ra...> - 2022-04-04 17:25:45
|
On Sun, Apr 3, 2022 at 1:13 PM Martin Pecka <pec...@fe...> wrote: > > Hi Patrick, > > The use case is: we have a bunch of slave clocks that we would like > to monitor by running pmc on each (+ snmp eventually). If this feature > would allow running pmc without sudo, it would provide an elegant > solution. > > I proposed to linuxptp-devel on 29 March patch ([PATCH] UDS: added option to set file mode for the created socket.). This patch would allow you to explicitly set the file mode of the created socket. That would be an alternative (and easier) solution than the patch implementing dropping root privileges. > > There is, however, ongoing discussion about the implementation on linuxptp-users (Config section for /var/log/ptp4lro creates an additional port). We haven't yet settled on the ideal implementation of the feature. > > Martin Hello Martin, Your patch works fine for me given a non default interface `-i` to pmc, since my user doesn't have write permission in `/vav/run`. This looks simple indeed. Though, I'm not sure about the rationale for exposing 2 sockets. Is the intention to accommodate both trusted (GET+SET) and untrusted (GET) applications? Anyways, I'll keep an eye on the upcoming development. Thanks, Patrick |
|
From: Martin P. <pec...@fe...> - 2022-04-03 17:05:59
|
Hi Patrick, > The use case is: we have a bunch of slave clocks that we would like > to monitor by running pmc on each (+ snmp eventually). If this feature > would allow running pmc without sudo, it would provide an elegant > solution. I proposed to linuxptp-devel on 29 March patch ([PATCH] UDS: added option to set file mode for the created socket. <https://www.mail-archive.com/lin...@li.../msg05540.html>). This patch would allow you to explicitly set the file mode of the created socket. That would be an alternative (and easier) solution than the patch implementing dropping root privileges. There is, however, ongoing discussion about the implementation on linuxptp-users (Config section for /var/log/ptp4lro creates an additional port <https://www.mail-archive.com/lin...@li.../msg02694.html>). We haven't yet settled on the ideal implementation of the feature. Martin |
|
From: PATRICK K. <pat...@ra...> - 2022-04-01 15:22:15
|
On Thu, Mar 31, 2022 at 10:57 PM Richard Cochran <ric...@gm...> wrote: > > On Thu, Mar 31, 2022 at 02:56:28PM -0400, PATRICK KEROULAS wrote: > > Hello, > > What happened to this feature? > > https://www.mail-archive.com/lin...@li.../msg05061.html > > Would it be of practical value to you? > > If so, I'll gladly put it in the queue... Hello Richard, The use case is: we have a bunch of slave clocks that we would like to monitor by running pmc on each (+ snmp eventually). If this feature would allow running pmc without sudo, it would provide an elegant solution. Thank you, Patrick |
|
From: Richard C. <ric...@gm...> - 2022-04-01 02:57:17
|
On Thu, Mar 31, 2022 at 02:56:28PM -0400, PATRICK KEROULAS wrote: > Hello, > What happened to this feature? > https://www.mail-archive.com/lin...@li.../msg05061.html Would it be of practical value to you? If so, I'll gladly put it in the queue... Thanks, Richard |
|
From: Keller, J. E <jac...@in...> - 2022-04-01 00:59:23
|
On 3/31/2022 2:44 PM, Cole Walker wrote: > Thanks for the reply, Jacob. > > The kernel is 5.10.74-200.1644 > > I am going to try the 1.8.3 ICE driver first, as that is easier than a > kernel change in my environment. > > Do you have any insight as to what could be causing the nmea delay to > increase like that? Would the driver affect it? It does seem to be a > common factor in this behaviour and I wonder if it is worth > investigating further. > > Cole Sure. Please try out the 1.8.3 ICE driver and let me see if there's any results different. I suspect that something must be going wrong with delivering the timestamps to ts2phc, either in the device or in the driver. Nothing else makes much sense. You get an incorrect timestamp, and then it ofcourse thinks there is a big delay, so it starts frequency tuning, then the next few timestamps are valid so it eventually corrects itself. I doubt this is a bug in ts2phc but perhaps it is. I am a bit suspicious of that particular line in ts2phc you brought up where that check adds to the second value. The jump in difference is almost exactly 0.5 seconds. That feels quite suspicious. Thanks, Jake |
|
From: Cole W. <ce....@li...> - 2022-03-31 21:44:50
|
Thanks for the reply, Jacob.
The kernel is 5.10.74-200.1644
I am going to try the 1.8.3 ICE driver first, as that is easier than a kernel change in my environment.
Do you have any insight as to what could be causing the nmea delay to increase like that? Would the driver affect it? It does seem to be a common factor in this behaviour and I wonder if it is worth investigating further.
Cole
________________________________
From: Keller, Jacob E <jac...@in...>
Sent: March 31, 2022 4:37 PM
To: lin...@li... <lin...@li...>
Subject: Re: [Linuxptp-users] ts2phc master offset value periodically spikes
On 3/31/2022 9:32 AM, Cole Walker wrote:
> Hello,
>
> I'm looking for some assistance getting to the root of an issue where
> ts2phc will be stable for a period of time and then experience a spike
> in the master offset value. The debug logs show a few interesting things
> and I'm looking for input on what steps to take next.
>
> My setup:
>
> linuxptp version 3.1.1
>
> I have two NICs using the Intel ICE driver. NIC0 has an integrated GNSS
> module and I am using ts2phc to sync them.
>
Hi,
> ethtool -i enp81s0f0
> driver: ice
> version: 1.7.16
> firmware-version: 3.10 0x80009be5 1.3086.0
> expansion-rom-version:
> bus-info: 0000:51:00.0
> supports-statistics: yes
> supports-test: yes
> supports-eeprom-access: yes
> supports-register-dump: yes
> supports-priv-flags: yes
>
>
This is with the ice driver and E810 device. Ok.
It looks like you're using a slightly older out-of-tree driver release.
What kernel are you running on?
There was a fair bit of work done on PTP around these releases, and I am
curious if you could try this with the 1.8.3 driver, or with a recent
kernel (5.16) in-tree driver.
sphc config - the pulsewidth and extts_polarity values are taken from
> the user guide for the NICs.
>
> [global]
> leapfile /usr/share/zoneinfo/leap-seconds.list
> logging_level 7
> ts2phc.nmea_serialport /dev/ttyGNSS_5100_0
> ts2phc.pulsewidth 100000000
>
> [enp81s0f0]
> ts2phc.extts_polarity rising
>
> [enp138s0f0]
> ts2phc.extts_polarity rising
>
>
>
> Log sample:
>
> 2022-03-15T04:50:26.000 controller-0 ts2phc: debug [1036434.421] nmea
> delay: 379832699 ns
> 2022-03-15T04:50:26.000 controller-0 ts2phc: debug [1036434.422]
> enp81s0f0 extts index 0 at 1647319864.000000000 corr 0 src
> 1647319864.620189416 diff 0
> 2022-03-15T04:50:26.000 controller-0 ts2phc: debug [1036434.422]
> enp81s0f0 master offset 0 s2 freq +0
> 2022-03-15T04:50:26.000 controller-0 ts2phc: debug [1036434.422] nmea
> delay: 379832699 ns
> 2022-03-15T04:50:26.000 controller-0 ts2phc: debug [1036434.422]
> enp138s0f0 extts index 0 at 1647319863.999999999 corr 0 src
> 1647319864.620839770 diff -1
> 2022-03-15T04:50:26.000 controller-0 ts2phc: debug [1036434.422]
> enp138s0f0 master offset -1 s2 freq +1
> 2022-03-15T04:50:27.000 controller-0 ts2phc: debug [1036435.421] nmea
> delay: 319026253 ns
> 2022-03-15T04:50:27.000 controller-0 ts2phc: debug [1036435.422]
> enp81s0f0 extts index 0 at 1647319865.000000000 corr 0 src
> 1647319865.680996587 diff 0
> 2022-03-15T04:50:27.000 controller-0 ts2phc: debug [1036435.422]
> enp81s0f0 master offset 0 s2 freq +0
> 2022-03-15T04:50:27.000 controller-0 ts2phc: debug [1036435.422] nmea
> delay: 319026253 ns
> 2022-03-15T04:50:27.000 controller-0 ts2phc: debug [1036435.422]
> enp138s0f0 extts index 0 at 1647319865.000000000 corr 0 src
> 1647319865.681640151 diff 0
> 2022-03-15T04:50:27.000 controller-0 ts2phc: debug [1036435.422]
> enp138s0f0 master offset 0 s2 freq +1
> 2022-03-15T04:50:28.000 controller-0 ts2phc: debug [1036436.421] nmea
> delay: 314155539 ns
> 2022-03-15T04:50:28.000 controller-0 ts2phc: debug [1036436.422]
> enp81s0f0 extts index 0 at 1647319866.000000000 corr 0 src
> 1647319866.685874828 diff 0
> 2022-03-15T04:50:28.000 controller-0 ts2phc: debug [1036436.422]
> enp81s0f0 master offset 0 s2 freq +0
> 2022-03-15T04:50:28.000 controller-0 ts2phc: debug [1036436.422] nmea
> delay: 314155539 ns
> 2022-03-15T04:50:28.000 controller-0 ts2phc: debug [1036436.422]
> enp138s0f0 extts index 0 at 1647319866.000000001 corr 0 src
> 1647319866.686513484 diff 1
> 2022-03-15T04:50:28.000 controller-0 ts2phc: debug [1036436.422]
> enp138s0f0 master offset 1 s2 freq +2
> 2022-03-15T04:50:29.000 controller-0 ts2phc: debug [1036437.422] nmea
> delay: 790744992 ns
>
It looks like nmea delay increased by about half a second here.
> # Things go weird here
> # The src value appears to be behind the previous one?
> 2022-03-15T04:50:29.000 controller-0 ts2phc: debug [1036437.422]
> enp138s0f0 extts index 0 at 1647319866.999999999 corr 0 src
> 1647319866.209929593 diff 999999999
> 2022-03-15T04:50:29.000 controller-0 ts2phc: debug [1036437.422]
> enp138s0f0 master offset 999999999 s2 freq +900000000
> 2022-03-15T04:50:30.000 controller-0 ts2phc: debug [1036437.434] nmea
> delay: 790744992 ns
> 2022-03-15T04:50:30.000 controller-0 ts2phc: debug [1036437.434]
> enp81s0f0 extts index 0 at 1647319867.000000000 corr 0 src
> 1647319866.221685020 diff 1000000000
> 2022-03-15T04:50:30.000 controller-0 ts2phc: debug [1036437.434]
> enp81s0f0 master offset 1000000000 s2 freq +900000000
> 2022-03-15T04:50:30.000 controller-0 ts2phc: debug [1036438.351] nmea
> delay: 234127497 ns
> 2022-03-15T04:50:30.000 controller-0 ts2phc: debug [1036438.351]
> enp81s0f0 extts index 0 at 1647319867.111604645 corr 0 src
> 1647319868.695211166 diff -888395355
> 2022-03-15T04:50:30.000 controller-0 ts2phc: debug [1036438.351]
> enp81s0f0 master offset -888395355 s2 freq -888395355
> 2022-03-15T04:50:30.000 controller-0 ts2phc: debug [1036438.351] nmea
> delay: 234127497 ns
> 2022-03-15T04:50:30.000 controller-0 ts2phc: debug [1036438.351]
> enp138s0f0 extts index 0 at 1647319867.100432414 corr 0 src
> 1647319868.695795473 diff -899567586
> 2022-03-15T04:50:30.000 controller-0 ts2phc: debug [1036438.351]
> enp138s0f0 master offset -899567586 s2 freq -899567584
>
>
>
> The offset eventually stabilizes and carries on for a while before this
> symptom occurs again.
> I have made sure that ntpd is disabled and I am not running any other
> ptp services.
>
>
>
> Looking at the ts2phc code, it appears to me that the behaviour occurs
> in ts2phc_slave.c ts2phc_slave_offset() when this check isn't true.
>
> if (source_ts.tv_nsec > 500000000) {
> source_ts.tv_sec++;
> }
I'd have to did into ptp4l code to understand what this check is even doing.
>
> So something is resulting in source_ts.tv_nsec being a bad value.
>
>
> I would appreciate your thoughts on this issue. Should I be looking into
> the driver code, or is there more I can investigate in tsphc?
>
I'd be suspicious that something is wrong in the driver here.
We did a bunch of work on the driver around the 1.7.x release and into
the 1.8.x release. I would recommend trying out 1.8.3 and seeing if this
behavior persists.
> Let me know if additional log output would be useful.
>
I'm not sure what else logging could be useful. I had thought at first
that the issue came from a reported timestamp being incorrectly
extended, but looking at the ice driver the external timestamp events
actually do capture the full 64 bit timestamp value so that extension
function is not used.
>
> Thanks for your help,
>
> Cole
>
_______________________________________________
Linuxptp-users mailing list
Lin...@li...
https://lists.sourceforge.net/lists/listinfo/linuxptp-users
|
|
From: Martin P. <pec...@fe...> - 2022-03-31 20:59:09
|
<div dir='auto'><div><br><div><br><div class="elided-text">On Mar 31, 2022 22:16, "Keller, Jacob E" <jac...@in...> wrote:<blockquote style="margin:0 0 0 0.8ex;border-left:1px #ccc solid;padding-left:1ex"><p dir="ltr"> Change the uds_open function to pass in the file mode. <br> </p> </blockquote></div>I can do that, but that would require changing the transport_open interface (and thus also raw_open, udp_open etc.) and probably also either port_initialize or adding a member variable to port class. All of that seem like pretty big changes for such a small feature. Any better ideas?</div></div></div> |
|
From: Keller, J. E <jac...@in...> - 2022-03-31 20:37:32
|
On 3/31/2022 9:32 AM, Cole Walker wrote:
> Hello,
>
> I'm looking for some assistance getting to the root of an issue where
> ts2phc will be stable for a period of time and then experience a spike
> in the master offset value. The debug logs show a few interesting things
> and I'm looking for input on what steps to take next.
>
> My setup:
>
> linuxptp version 3.1.1
>
> I have two NICs using the Intel ICE driver. NIC0 has an integrated GNSS
> module and I am using ts2phc to sync them.
>
Hi,
> ethtool -i enp81s0f0
> driver: ice
> version: 1.7.16
> firmware-version: 3.10 0x80009be5 1.3086.0
> expansion-rom-version:
> bus-info: 0000:51:00.0
> supports-statistics: yes
> supports-test: yes
> supports-eeprom-access: yes
> supports-register-dump: yes
> supports-priv-flags: yes
>
>
This is with the ice driver and E810 device. Ok.
It looks like you're using a slightly older out-of-tree driver release.
What kernel are you running on?
There was a fair bit of work done on PTP around these releases, and I am
curious if you could try this with the 1.8.3 driver, or with a recent
kernel (5.16) in-tree driver.
sphc config - the pulsewidth and extts_polarity values are taken from
> the user guide for the NICs.
>
> [global]
> leapfile /usr/share/zoneinfo/leap-seconds.list
> logging_level 7
> ts2phc.nmea_serialport /dev/ttyGNSS_5100_0
> ts2phc.pulsewidth 100000000
>
> [enp81s0f0]
> ts2phc.extts_polarity rising
>
> [enp138s0f0]
> ts2phc.extts_polarity rising
>
>
>
> Log sample:
>
> 2022-03-15T04:50:26.000 controller-0 ts2phc: debug [1036434.421] nmea
> delay: 379832699 ns
> 2022-03-15T04:50:26.000 controller-0 ts2phc: debug [1036434.422]
> enp81s0f0 extts index 0 at 1647319864.000000000 corr 0 src
> 1647319864.620189416 diff 0
> 2022-03-15T04:50:26.000 controller-0 ts2phc: debug [1036434.422]
> enp81s0f0 master offset 0 s2 freq +0
> 2022-03-15T04:50:26.000 controller-0 ts2phc: debug [1036434.422] nmea
> delay: 379832699 ns
> 2022-03-15T04:50:26.000 controller-0 ts2phc: debug [1036434.422]
> enp138s0f0 extts index 0 at 1647319863.999999999 corr 0 src
> 1647319864.620839770 diff -1
> 2022-03-15T04:50:26.000 controller-0 ts2phc: debug [1036434.422]
> enp138s0f0 master offset -1 s2 freq +1
> 2022-03-15T04:50:27.000 controller-0 ts2phc: debug [1036435.421] nmea
> delay: 319026253 ns
> 2022-03-15T04:50:27.000 controller-0 ts2phc: debug [1036435.422]
> enp81s0f0 extts index 0 at 1647319865.000000000 corr 0 src
> 1647319865.680996587 diff 0
> 2022-03-15T04:50:27.000 controller-0 ts2phc: debug [1036435.422]
> enp81s0f0 master offset 0 s2 freq +0
> 2022-03-15T04:50:27.000 controller-0 ts2phc: debug [1036435.422] nmea
> delay: 319026253 ns
> 2022-03-15T04:50:27.000 controller-0 ts2phc: debug [1036435.422]
> enp138s0f0 extts index 0 at 1647319865.000000000 corr 0 src
> 1647319865.681640151 diff 0
> 2022-03-15T04:50:27.000 controller-0 ts2phc: debug [1036435.422]
> enp138s0f0 master offset 0 s2 freq +1
> 2022-03-15T04:50:28.000 controller-0 ts2phc: debug [1036436.421] nmea
> delay: 314155539 ns
> 2022-03-15T04:50:28.000 controller-0 ts2phc: debug [1036436.422]
> enp81s0f0 extts index 0 at 1647319866.000000000 corr 0 src
> 1647319866.685874828 diff 0
> 2022-03-15T04:50:28.000 controller-0 ts2phc: debug [1036436.422]
> enp81s0f0 master offset 0 s2 freq +0
> 2022-03-15T04:50:28.000 controller-0 ts2phc: debug [1036436.422] nmea
> delay: 314155539 ns
> 2022-03-15T04:50:28.000 controller-0 ts2phc: debug [1036436.422]
> enp138s0f0 extts index 0 at 1647319866.000000001 corr 0 src
> 1647319866.686513484 diff 1
> 2022-03-15T04:50:28.000 controller-0 ts2phc: debug [1036436.422]
> enp138s0f0 master offset 1 s2 freq +2
> 2022-03-15T04:50:29.000 controller-0 ts2phc: debug [1036437.422] nmea
> delay: 790744992 ns
>
It looks like nmea delay increased by about half a second here.
> # Things go weird here
> # The src value appears to be behind the previous one?
> 2022-03-15T04:50:29.000 controller-0 ts2phc: debug [1036437.422]
> enp138s0f0 extts index 0 at 1647319866.999999999 corr 0 src
> 1647319866.209929593 diff 999999999
> 2022-03-15T04:50:29.000 controller-0 ts2phc: debug [1036437.422]
> enp138s0f0 master offset 999999999 s2 freq +900000000
> 2022-03-15T04:50:30.000 controller-0 ts2phc: debug [1036437.434] nmea
> delay: 790744992 ns
> 2022-03-15T04:50:30.000 controller-0 ts2phc: debug [1036437.434]
> enp81s0f0 extts index 0 at 1647319867.000000000 corr 0 src
> 1647319866.221685020 diff 1000000000
> 2022-03-15T04:50:30.000 controller-0 ts2phc: debug [1036437.434]
> enp81s0f0 master offset 1000000000 s2 freq +900000000
> 2022-03-15T04:50:30.000 controller-0 ts2phc: debug [1036438.351] nmea
> delay: 234127497 ns
> 2022-03-15T04:50:30.000 controller-0 ts2phc: debug [1036438.351]
> enp81s0f0 extts index 0 at 1647319867.111604645 corr 0 src
> 1647319868.695211166 diff -888395355
> 2022-03-15T04:50:30.000 controller-0 ts2phc: debug [1036438.351]
> enp81s0f0 master offset -888395355 s2 freq -888395355
> 2022-03-15T04:50:30.000 controller-0 ts2phc: debug [1036438.351] nmea
> delay: 234127497 ns
> 2022-03-15T04:50:30.000 controller-0 ts2phc: debug [1036438.351]
> enp138s0f0 extts index 0 at 1647319867.100432414 corr 0 src
> 1647319868.695795473 diff -899567586
> 2022-03-15T04:50:30.000 controller-0 ts2phc: debug [1036438.351]
> enp138s0f0 master offset -899567586 s2 freq -899567584
>
>
>
> The offset eventually stabilizes and carries on for a while before this
> symptom occurs again.
> I have made sure that ntpd is disabled and I am not running any other
> ptp services.
>
>
>
> Looking at the ts2phc code, it appears to me that the behaviour occurs
> in ts2phc_slave.c ts2phc_slave_offset() when this check isn't true.
>
> if (source_ts.tv_nsec > 500000000) {
> source_ts.tv_sec++;
> }
I'd have to did into ptp4l code to understand what this check is even doing.
>
> So something is resulting in source_ts.tv_nsec being a bad value.
>
>
> I would appreciate your thoughts on this issue. Should I be looking into
> the driver code, or is there more I can investigate in tsphc?
>
I'd be suspicious that something is wrong in the driver here.
We did a bunch of work on the driver around the 1.7.x release and into
the 1.8.x release. I would recommend trying out 1.8.3 and seeing if this
behavior persists.
> Let me know if additional log output would be useful.
>
I'm not sure what else logging could be useful. I had thought at first
that the issue came from a reported timestamp being incorrectly
extended, but looking at the ice driver the external timestamp events
actually do capture the full 64 bit timestamp value so that extension
function is not used.
>
> Thanks for your help,
>
> Cole
>
|
|
From: Keller, J. E <jac...@in...> - 2022-03-31 20:16:18
|
> -----Original Message----- > From: Martin Pecka <pec...@fe...> > Sent: Thursday, March 31, 2022 7:38 AM > To: Richard Cochran <ric...@gm...> > Cc: lin...@li... > Subject: Re: [Linuxptp-users] Config section for /var/log/ptp4lro creates an > additional port > > > >>> You can make two global options, one for each flavor. > >> I'm sorry, I don't understand your suggestion. Can you explain in a bit more > >> detail, please? > > Right now we have: > > > > uds_address /var/run/ptp4l > > uds_ro_address /var/run/ptp4lro > > > > You could add: > > > > uds_address_filemode 0660 > > uds_ro_address_filemode 0666 > > > > Hm? > > That would be ideal, but I'm out of ideas with the implementation. The > file mode setting is needed in uds.c, but the uds_open() function has no > flag telling it whether it is RW or RO (or some other?) UDS port. > Change the uds_open function to pass in the file mode. |
|
From: PATRICK K. <pat...@ra...> - 2022-03-31 19:13:15
|
Hello, What happened to this feature? https://www.mail-archive.com/lin...@li.../msg05061.html Regards, Patrick |
27 messages has been excluded from this view by a project administrator.
