Document ts2phc offset spike mitigation and new parameter (dsr8mr3)

Change-Id: I88b65a84f8f879d716e37fb2e9e6b67a74e793ac
Signed-off-by: Ngairangbam Mili <ngairangbam.mili@windriver.com>
This commit is contained in:
Ngairangbam Mili 2024-04-18 07:03:05 +00:00
parent 3049528a18
commit b664d790dd
1 changed files with 137 additions and 1 deletions

View File

@ -75,7 +75,7 @@ Each of the fields are explained below:
parameter.
.. code-block:: none
~(keystone_admin)]$ system ptp-instance-parameter-add <ptp4l instance> clockAccuracy=0x21
@ -205,3 +205,139 @@ The |PTP| Announce Message Attributes can be viewed using the `pmc` tool.
The log output for dynamically updated values can be found in
``/var/log/collectd.log``.
Ts2phc Offset Spike Mitigation
------------------------------
Ts2phc can be configured to detect and ignore intermittent offset spikes that
may result in incorrect clock adjustments. This behaviour is controlled using
the global instance parameter ``max_phc_update_skip_cnt``. The
``max_phc_update_skip_cnt`` parameter is the number of consecutive offset
spikes in a row that will be ignored. For example, setting
``max_phc_update_skip_cnt`` to 120 would allow ts2phc to ignore 120 consecutive
offset spike incidents before adjusting the clock.
Offset Spike Characterization
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
The |prod| systems using the realtime kernel may experience an intermittent
offset spike behaviour in ts2phc. This intermittent offset spike behaviour
results from |GNSS| messages that take time to arrive at the userspace ts2phc
application. The delayed |GNSS| messages can cause ts2phc application to
calculate an incorrect adjustment value for the |PHCs|. This results in ts2phc
making large adjustments to its |PHCs| and can cause unstable system time. An
example of this behaviour can be seen in the log snippet below. If log events
similar to the given example are observed, configuring offset spike mitigation
in ts2phc can improve timing stability by detecting and ignoring these large
offset calculations.
Example:
.. code-block:: none
2024-03-07T15:39:57.821 controller-1 ts2phc: debug [212517.301] ts11 nmea sentence: GNRMC
2024-03-07T15:39:58.001 controller-1 ts2phc: debug [212517.480] ts11 nmea delay: 820982637 ns
### Large nmea delay value above ^^ indicates an offset spike has occurred
2024-03-07T15:39:58.001 controller-1 ts2phc: debug [212517.480] ts11 enp81s0f1 extts index 0 at 1709826035.000000000 corr 0 src 1709826034.179042651 diff 1000000000 servo state 2
2024-03-07T15:39:58.001 controller-1 ts2phc: debug [212517.480] ts11 enp81s0f1 master offset1000000000 s2 freq +900000000
### Ts2phc makes large adjustment ^^ to clock, resulting in degraded timing accuracy
2024-03-07T15:39:58.058 controller-1 ts2phc: debug [212517.538] ts11 nmea sentence: GNRMC
2024-03-07T15:39:58.935 controller-1 ts2phc: debug [212518.413] ts11 nmea delay: 58600490 ns
2024-03-07T15:39:58.935 controller-1 ts2phc: debug [212518.413] ts11 enp81s0f1 extts index 0 at 1709826035.100878397 corr 0 src 1709826036.874841070 diff -899121603 servo state 2
2024-03-07T15:39:58.935 controller-1 ts2phc: debug [212518.413] ts11 enp81s0f1 master offset -899121603 s2 freq -899121603
### Subsequent cycles show wide swings ^^ in clock adjustments as ts2phc stabilizes
2024-03-07T15:39:58.999 controller-1 ts2phc: debug [212518.479] ts11 nmea sentence: GNRMC
2024-03-07T15:39:59.834 controller-1 ts2phc: debug [212519.313] ts11 nmea delay: -449462 ns
2024-03-07T15:39:59.834 controller-1 ts2phc: debug [212519.313] ts11 enp81s0f1 extts index 0 at 1709826036.996688203 corr 0 src 1709826037.833824291 diff -3311797 servo state 2
2024-03-07T15:39:59.834 controller-1 ts2phc: debug [212519.313] ts11 enp81s0f1 master offset -3311797 s2 freq -273048278
2024-03-07T15:40:04.178 controller-1 ts2phc: debug [212523.658] ts11 nmea sentence: GNRMC [… omitted lines]
2024-03-07T15:40:32.054 controller-1 ts2phc: debug [212551.534] ts11 nmea sentence: GNRMC
2024-03-07T15:40:33.000 controller-1 ts2phc: debug [212552.480] ts11 nmea delay: 54715299 ns
2024-03-07T15:40:33.000 controller-1 ts2phc: debug [212552.480] ts11 enp81s0f1 extts index 0 at 1709826070.000000003 corr 0 src 1709826070.945357401 diff 3 servo state 2
2024-03-07T15:40:33.000 controller-1 ts2phc: debug [212552.480] ts11 enp81s0f1 master offset 3 s2 freq +2
2024-03-07T15:40:33.054 controller-1 ts2phc: debug [212552.534] ts11 nmea sentence: GNRMC
2024-03-07T15:40:34.002 controller-1 ts2phc: debug [212553.480] ts11 nmea delay: 54504252 ns
2024-03-07T15:40:34.002 controller-1 ts2phc: debug [212553.480] ts11 enp81s0f1 extts index 0 at 1709826071.000000001 corr 0 src 1709826071.945587288 diff 1 servo state 2
2024-03-07T15:40:34.002 controller-1 ts2phc: debug [212553.480] ts11 enp81s0f1 master offset 1 s2 freq +0
### After a period of 25-30 seconds, ts2phc has stabilized and is back to small adjustments
Configure Offset Spike Mitigation
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
The offset spike mitigation behaviour is enabled in ts2phc by default with a
value of ``max_phc_update_skip_cnt`` = 120.
To configure the number of consecutive offset spikes that will be ignored by ts2phc, use the
following |PTP| instance parameter:
.. code-block:: none
system ptp-instance-parameter-add <ts2phc instance name> max_phc_update_skip_cnt=120
# Apply the configuration. This will restart all PTP services.
system ptp-instance-apply
The value 120 will allow ts2phc to ignore up to 120 consecutive offset spikes.
This value may need to be adjusted based on testing and observation in your environment.
Consecutive occurrences are not observed often, with subsequent updates
arriving in a timely manner.
Disable Offset Spike Mitigation
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
The offset spike mitigation can be disabled by setting ``max_phc_update_skip_cnt=0``.
**Offset mitigation log example:**
.. code-block:: none
2024-03-07T15:41:04.639 controller-1 ts2phc: debug [212584.120] ts11 nmea sentence: GNRMC
2024-03-07T15:41:05.013 controller-1 ts2phc: debug [212584.493] ts11 nmea delay: 639834481 ns
### Large nmea delay above ^^ indicating an offset spike has occurred
2024-03-07T15:41:05.013 controller-1 ts2phc: debug [212584.493] ts11 enp81s0f1 extts index 0 at 1709826102.000000000 corr 0 src 1709826101.373785045 diff 1000000000 servo state 2
2024-03-07T15:41:05.013 controller-1 ts2phc: debug [212584.493] ts11 Offset spike detected. Skip current PHC update enp81s0f1 offset 1000000000 s2 freq +0
### Mitigation catches this and skips adjusting the clock ^^
2024-03-07T15:41:05.013 controller-1 ts2phc: debug [212584.493] ts11 Current skip count: 1
### “Current skip count” ^^ indicates the number of consecutive spikes detected
### Because the next update to arrive does not have an offset spike, the current skip count will be reset to 0 and will begin incrementing again when another spike occurs
2024-03-07T15:41:05.063 controller-1 ts2phc: debug [212584.543] ts11 nmea sentence: GNRMC
2024-03-07T15:41:06.001 controller-1 ts2phc: debug [212585.480] ts11 nmea delay: 63592544 ns
2024-03-07T15:41:06.001 controller-1 ts2phc: debug [212585.480] ts11 enp81s0f1 extts index 0 at 1709826103.000000000 corr 0 src 1709826103.936434314 diff 0 servo state 2
2024-03-07T15:41:06.001 controller-1 ts2phc: debug [212585.480] ts11 enp81s0f1 master offset 0 s2 freq +0
### Subsequent ts2phc adjustments are small because the clock remained tightly synced
2024-03-07T15:41:06.067 controller-1 ts2phc: debug [212585.533] ts11 nmea sentence: GNRMC
2024-03-07T15:41:07.000 controller-1 ts2phc: debug [212586.480] ts11 nmea delay: 53524772 ns
2024-03-07T15:41:07.000 controller-1 ts2phc: debug [212586.480] ts11 enp81s0f1 extts index 0 at 1709826104.000000000 corr 0 src 1709826104.946499286 diff 0 servo state 2
2024-03-07T15:41:07.000 controller-1 ts2phc: debug [212586.480] ts11 enp81s0f1 master offset 0 s2 freq +0
2024-03-07T15:41:07.050 controller-1 ts2phc: debug [212586.530] ts11 nmea sentence: GNRMC
2024-03-07T15:41:08.000 controller-1 ts2phc: debug [212587.480] ts11 nmea delay: 50802510 ns
2024-03-07T15:41:08.000 controller-1 ts2phc: debug [212587.480] ts11 enp81s0f1 extts index 0 at 1709826104.999999999 corr 0 src 1709826105.949221716 diff -1 servo state 2
2024-03-07T15:41:08.000 controller-1 ts2phc: debug [212587.480] ts11 enp81s0f1 master offset -1 s2 freq -1
**Ts2phc config file example:**
.. code-block::
[global]
##
## Default Data Set
##
leapfile /usr/share/zoneinfo/leap-seconds.list
message_tag ts11
ts2phc.nmea_serialport /dev/ttyGNSS_5100_0
ts2phc.pulsewidth 100000000
logging_level 7
max_phc_update_skip_cnt 120
[enp81s0f1]
##
## Associated interface: enp81s0f1
##
ts2phc.extts_polarity rising