Hey guys,

I have been looking everywhere to see if there were already answered
questions related to the timeouts topic, but I found out any so here I am.

I have a couple of PTP setups, one with Microsemi GM and Cisco BC, another
with other brands involved.
Both setups are giving me the same outputs so I was looking to understand
what was going on and if it was my fault in terms of PTP settings.
These setups are working by means of ITU-G.8275.2 profile (L3, unicast) –
slaves are working with linuxptp v2.0.
Let me also add that these two setups are located in different areas well
distant one from another, therefore getting different GPS references – to
ensure that it was not related to hardware faults.

They can be simply schematized as (GPS feeded) GM --- BC --- slave1 (exanic
driver) | --- slave2 (ixgbe driver)

Hardware timestamping is used on the slaves, which are running on an
Exablaze or on an Intel board with PHCs support.
ethtool ensures their hw capabilities.

The slave synchronization happens correctly in both setups. I am able to
get a good PPS output from the boards and the GM, showing that slaves
synchronized correctly in time with the GM itself.
However in the logs there are different “unicast request timeout”s and
“delay timeout”s:
ptp4l[7685725.646]: delay   filtered        119   raw        124
ptp4l[7685726.437]: master offset          0 s2 freq   -1817 path
delay       119
ptp4l[7685726.550]: port 1: unicast request timeout
ptp4l[7685727.032]: port 1: delay timeout
ptp4l[7685727.033]: delay   filtered        119   raw        123
ptp4l[7685727.437]: master offset         -3 s2 freq   -1820 path
delay       119
ptp4l[7685728.066]: port 1: delay timeout
ptp4l[7685728.066]: delay   filtered        120   raw        124
ptp4l[7685728.445]: master offset         -6 s2 freq   -1824 path
delay       120
ptp4l[7685728.973]: port 1: delay timeout
ptp4l[7685728.974]: delay   filtered        120   raw        121
ptp4l[7685729.264]: port 1: delay timeout
ptp4l[7685729.265]: delay   filtered        120   raw        115
ptp4l[7685729.445]: master offset         -1 s2 freq   -1821 path
delay       120
ptp4l[7685730.063]: port 1: delay timeout
ptp4l[7685730.064]: delay   filtered        120   raw        118
ptp4l[7685730.445]: master offset          9 s2 freq   -1811 path
delay       120
ptp4l[7685730.550]: port 1: unicast request timeout
ptp4l[7685731.408]: port 1: delay timeout
ptp4l[7685731.408]: delay   filtered        120   raw        126
…

This is the simple ptp4l.conf file (where 10.10.10.10 is the BC):
[global]
unicast_listen                           1
unicast_req_duration             60
domainNumber                     44
verbose                          1
logging_level                    7
clock_type                       OC
network_transport                UDPv4
delay_mechanism                  E2E
time_stamping                    hardware
tsproc_mode                      filter
delay_filter                     moving_median
delay_filter_length              50
egressLatency                    0
ingressLatency                   0
boundary_clock_jbod      0
[unicast_master_table]
table_id                                 1
logQueryInterval                 2
peer_address                     10.10.10.10
UDPv4                                    10.10.10.10
[enp94s0d1]
unicast_master_table             1

These are the ptp4l options:
-f /etc/ptp4l.conf -s -i enp94s0d1 -p /dev/ptp10 # where the PHC for this
specific slave is 10, as confirmed by ethtool – other slaves are different,
but we always check that we are using the correct ptp device

And phc2sys to synchronize the system clock:
-s /dev/ptp10 -w -n 44

The setups therefore seem to be working properly in terms of
synchronization, but those timeouts are puzzling me. Am I doing something
wrong?

I tried to go with code analysis (please correct me if I got anything
wrong!).
bc_event function (port.c) is triggered and the file descriptor index
fd_index is equal to FD_DELAY_TIMER (2) or FD_UNICAST_REQ_TIMER (8).
This is triggered by port_event (port.c), which in turn is triggered by
clock_poll (clock.c).
clock_poll is checking for every port the events which occurred, making use
of the poll Linux library.
Some strategic debug prints (in port.c and clock.c) were therefore placed
so that the output becomes:

…
ptp4l[7688565.452]: port 1: UNCALIBRATED to SLAVE on MASTER_CLOCK_SELECTED
ptp4l[7688565.516]: Event index (i): 2, revents associated: 1, POLLIN: 1,
POLLPRI: 2
ptp4l[7688565.516]: bc_event with FD_DELAY_TIMER
ptp4l[7688565.516]: port 1: delay timeout
ptp4l[7688565.516]: Event index (i): 1, revents associated: 1, POLLIN: 1,
POLLPRI: 2
ptp4l[7688565.516]: delay   filtered        119   raw        118
ptp4l[7688566.372]: Event index (i): 1, revents associated: 1, POLLIN: 1,
POLLPRI: 2
ptp4l[7688566.452]: Event index (i): 0, revents associated: 1, POLLIN: 1,
POLLPRI: 2
ptp4l[7688566.452]: master offset         32 s2 freq   -1811 path
delay       119
ptp4l[7688567.451]: Event index (i): 0, revents associated: 1, POLLIN: 1,
POLLPRI: 2
ptp4l[7688567.451]: master offset          1 s2 freq   -1832 path
delay       119
ptp4l[7688567.464]: Event index (i): 2, revents associated: 1, POLLIN: 1,
POLLPRI: 2
ptp4l[7688567.464]: bc_event with FD_DELAY_TIMER
ptp4l[7688567.464]: port 1: delay timeout
ptp4l[7688567.465]: Event index (i): 1, revents associated: 1, POLLIN: 1,
POLLPRI: 2
ptp4l[7688567.465]: delay   filtered        118   raw        114
ptp4l[7688568.371]: Event index (i): 1, revents associated: 1, POLLIN: 1,
POLLPRI: 2
ptp4l[7688568.451]: Event index (i): 0, revents associated: 1, POLLIN: 1,
POLLPRI: 2
ptp4l[7688568.451]: master offset         -8 s2 freq   -1841 path
delay       118
ptp4l[7688568.583]: Event index (i): 2, revents associated: 1, POLLIN: 1,
POLLPRI: 2
ptp4l[7688568.583]: bc_event with FD_DELAY_TIMER
ptp4l[7688568.583]: port 1: delay timeout
ptp4l[7688568.584]: Event index (i): 1, revents associated: 1, POLLIN: 1,
POLLPRI: 2
ptp4l[7688568.584]: delay   filtered        118   raw        117
ptp4l[7688568.865]: Event index (i): 8, revents associated: 1, POLLIN: 1,
POLLPRI: 2
ptp4l[7688568.865]: bc_event with FD_UNICAST_REQ_TIMER
ptp4l[7688568.865]: port 1: unicast request timeout
…

Do you have any advice? Do you have a clear idea on why this is happening
or what can I try to improve the setups?
We played with the different timeouts along the GM-BC chain, but still
getting the same problem.

It was possible to see that the slideset hosted by the Linux Foundation
“IEEE 1588 & PTP USING EMBEDDED LINUX SYSTEMS, by Insop Song” has delay
timeouts on the slaves as well. This is making me wonder if I am puzzling
for nothing.

Thanks in advance!
Francesco
_______________________________________________
Linuxptp-users mailing list
Linuxptp-users@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/linuxptp-users

Reply via email to