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.
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
tsphc 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
# 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++;
}
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?
Let me know if additional log output would be useful.
Thanks for your help,
Cole
_______________________________________________
Linuxptp-users mailing list
Linuxptp-users@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/linuxptp-users
