Hello,
I hope someone may be able to help me here. I have trouble syncing two
Linux systems using PTP.
Setup:
Two PCBs with a BegleCore module and a DP83640 PHY are connected with
each other over Ethernet. One board should act as the PTP master, the
other as the slave.
Debian 10, Kernel: 4.19.94
Driver for the Phy is loaded.
Using linuxptp v3.1
On the master system I run the command:
sudo ptp4l -i eth0 -f linuxptp/configs/configMaster.cfg -m
On the client system I run:
sudo ptp4l -i eth0 -f linuxptp/configs/configslave.cfg -m
Content of configMaster.cfg:
[global]
serverOnly 1
BMCA noop
Content of configSlave.cfg:
[global]
clientOnly 1
BMCA noop
step_threshold 1
This results in the following output on the slave:
ptp4l[438753.396]: selected /dev/ptp0 as PTP clock
ptp4l[438753.409]: port 1 (eth0): INITIALIZING to SLAVE on INIT_COMPLETE
ptp4l[438753.414]: port 0 (/var/run/ptp4l): INITIALIZING to LISTENING on
INIT_COMPLETE
ptp4l[438753.418]: port 0 (/var/run/ptp4lro): INITIALIZING to LISTENING
on INIT_COMPLETE
ptp4l[438754.075]: port 1 (eth0): new foreign master
304511.fffe.0ff048-1
ptp4l[438758.074]: selected best master clock 304511.fffe.0ff048
ptp4l[438762.072]: master offset 2426120726467 s0 freq -261066 path
delay 15040
ptp4l[438762.074]: selected best master clock 304511.fffe.0ff048
ptp4l[438765.074]: master offset 2426120697575 s1 freq -270698 path
delay 15156
ptp4l[438767.072]: master offset 2426120678191 s0 freq -270698 path
delay 15156
ptp4l[438768.075]: master offset 2426120668273 s1 freq -280618 path
delay 15830
ptp4l[438769.072]: master offset 2426120658469 s0 freq -280618 path
delay 15830
ptp4l[438770.073]: master offset 2426120648789 s0 freq -280618 path
delay 16022
ptp4l[438771.076]: master offset 2426120639057 s1 freq -290350 path
delay 16022
...
The reported offset is approximatly 40 min. Before running ptp4l I had
set the PTP clocks in the PHYs with `testptp -s` to the current system
time. The PTP clocks were therefore actually within a few seconds of
each other.
Each time ptp4l reports a "master offset <x> s1 ..." it does step the
PTP clock back by 40 min (checked with `testptp -g`). Yet the reported
offset only changes by about 10 us.
I also looked into the network traffic with Wireshark and saw, that the
Follow-Up messages from the master contain a timestamp that is by about
69 min of what the PTP clock in the PHY is set to.
After adding debug outputs to ptp4l I saw, that on the slave, the
timestamp it extracts from the cmsgs returned from the socket is offset
by about -27 min from what the client PTP clock actually is.
In detail: In sk.c after line 377 (ts = (struct timespec *)
CMSG_DATA(cm);) I printed out the value of ts[2].tv_sec, wich, as far as
I can tell, will sometime later be used to calculate the master offset.
This resulted in an ouput of for example: 1638869732 s.
When I read the value of the PTP clock the same way the tool testptp
does, by opening the /dev/ptp0 device and calling clock_gettime(...), I
would get 1638867306 s
The difference from the false timestamps (+69 min) send by the master
and the falsely read timestamps (-27 min) by the client results in the
40 min of assumed offset between the master clock and the client clock.
Here the output with -l 7 added for debug info:
bcm@BCM-4:~$ sudo ptp4l -i eth0 -f linuxptp/configs/configSlave.cfg -m
-l 7
ptp4l[526775.711]: config item (null).assume_two_step is 0
ptp4l[526775.718]: config item (null).check_fup_sync is 0
ptp4l[526775.720]: config item (null).tx_timestamp_timeout is 10
ptp4l[526775.723]: config item (null).hwts_filter is 0
ptp4l[526775.725]: config item (null).clock_servo is 0
ptp4l[526775.727]: config item (null).clock_type is 32768
ptp4l[526775.728]: config item (null).clock_servo is 0
ptp4l[526775.729]: config item (null).clockClass is 248
ptp4l[526775.733]: config item (null).clockAccuracy is 254
ptp4l[526775.733]: config item (null).offsetScaledLogVariance is 65535
ptp4l[526775.734]: config item (null).productDescription is ';;'
ptp4l[526775.734]: config item (null).revisionData is ';;'
ptp4l[526775.736]: config item (null).userDescription is ''
ptp4l[526775.737]: config item (null).manufacturerIdentity is '00:00:00'
ptp4l[526775.739]: config item (null).domainNumber is 0
ptp4l[526775.739]: config item (null).clientOnly is 1
ptp4l[526775.740]: config item (null).gmCapable is 1
ptp4l[526775.741]: config item (null).gmCapable is 1
ptp4l[526775.743]: config item (null).G.8275.defaultDS.localPriority is
128
ptp4l[526775.744]: config item (null).maxStepsRemoved is 255
ptp4l[526775.745]: config item (null).clock_class_threshold is 248
ptp4l[526775.745]: config item (null).time_stamping is 1
ptp4l[526775.745]: config item (null).twoStepFlag is 1
ptp4l[526775.748]: config item (null).twoStepFlag is 1
ptp4l[526775.749]: config item (null).time_stamping is 1
ptp4l[526775.749]: config item (null).priority1 is 128
ptp4l[526775.750]: config item (null).priority2 is 128
ptp4l[526775.751]: interface index 4 is up
ptp4l[526775.757]: config item (null).free_running is 0
ptp4l[526775.758]: selected /dev/ptp0 as PTP clock
ptp4l[526775.759]: config item (null).clockIdentity is
'000000.0000.000000'
ptp4l[526775.761]: config item (null).uds_address is '/var/run/ptp4l'
ptp4l[526775.763]: section item /var/run/ptp4l.announceReceiptTimeout
now 0
ptp4l[526775.767]: section item /var/run/ptp4l.delay_mechanism now 0
ptp4l[526775.767]: section item /var/run/ptp4l.network_transport now 0
ptp4l[526775.768]: section item /var/run/ptp4l.delay_filter_length now 1
ptp4l[526775.769]: config item (null).uds_ro_address is
'/var/run/ptp4lro'
ptp4l[526775.771]: section item /var/run/ptp4lro.announceReceiptTimeout
now 0
ptp4l[526775.772]: section item /var/run/ptp4lro.delay_mechanism now 0
ptp4l[526775.772]: section item /var/run/ptp4lro.network_transport now 0
ptp4l[526775.773]: section item /var/run/ptp4lro.delay_filter_length now
1
ptp4l[526775.774]: config item (null).free_running is 0
ptp4l[526775.777]: config item (null).freq_est_interval is 1
ptp4l[526775.777]: config item (null).write_phase_mode is 0
ptp4l[526775.777]: config item (null).gmCapable is 1
ptp4l[526775.778]: config item (null).kernel_leap is 1
ptp4l[526775.778]: config item (null).utc_offset is 37
ptp4l[526775.780]: config item (null).timeSource is 160
ptp4l[526775.781]: config item (null).step_window is 0
ptp4l[526775.785]: config item (null).pi_proportional_const is 0.000000
ptp4l[526775.786]: config item (null).pi_integral_const is 0.000000
ptp4l[526775.787]: config item (null).pi_proportional_scale is 0.000000
ptp4l[526775.787]: config item (null).pi_proportional_exponent is
-0.300000
ptp4l[526775.787]: config item (null).pi_proportional_norm_max is
0.700000
ptp4l[526775.788]: config item (null).pi_integral_scale is 0.000000
ptp4l[526775.789]: config item (null).pi_integral_exponent is 0.400000
ptp4l[526775.789]: config item (null).pi_integral_norm_max is 0.300000
ptp4l[526775.789]: config item (null).step_threshold is 1.000000
ptp4l[526775.790]: config item (null).first_step_threshold is 0.000020
ptp4l[526775.790]: config item (null).max_frequency is 900000000
ptp4l[526775.792]: config item (null).servo_offset_threshold is 0
ptp4l[526775.793]: config item (null).servo_num_offset_values is 10
ptp4l[526775.794]: config item (null).dataset_comparison is 0
ptp4l[526775.797]: config item (null).tsproc_mode is 0
ptp4l[526775.797]: config item (null).delay_filter is 1
ptp4l[526775.798]: config item (null).delay_filter_length is 10
ptp4l[526775.798]: config item (null).initial_delay is 0
ptp4l[526775.801]: config item (null).summary_interval is 0
ptp4l[526775.801]: config item (null).sanity_freq_limit is 200000000
ptp4l[526775.801]: PI servo: sync interval 1.000 kp 0.700 ki 0.300000
ptp4l[526775.803]: config item /var/run/ptp4l.boundary_clock_jbod is 0
ptp4l[526775.804]: config item /var/run/ptp4l.serverOnly is 0
ptp4l[526775.806]: config item /var/run/ptp4l.BMCA is 1
ptp4l[526775.807]: config item /var/run/ptp4l.network_transport is 0
ptp4l[526775.807]: config item /var/run/ptp4l.delayAsymmetry is 0
ptp4l[526775.808]: config item /var/run/ptp4l.follow_up_info is 0
ptp4l[526775.811]: config item /var/run/ptp4l.freq_est_interval is 1
ptp4l[526775.811]: config item /var/run/ptp4l.msg_interval_request is 0
ptp4l[526775.812]: config item /var/run/ptp4l.net_sync_monitor is 0
ptp4l[526775.813]: config item /var/run/ptp4l.path_trace_enabled is 0
ptp4l[526775.815]: config item /var/run/ptp4l.tc_spanning_tree is 0
ptp4l[526775.816]: config item /var/run/ptp4l.ingressLatency is 0
ptp4l[526775.816]: config item /var/run/ptp4l.egressLatency is 0
ptp4l[526775.817]: config item /var/run/ptp4l.delay_mechanism is 0
ptp4l[526775.817]: config item /var/run/ptp4l.hybrid_e2e is 0
ptp4l[526775.820]: config item /var/run/ptp4l.fault_badpeernet_interval
is 16
ptp4l[526775.821]: config item /var/run/ptp4l.fault_reset_interval is 4
ptp4l[526775.822]: config item /var/run/ptp4l.tsproc_mode is 0
ptp4l[526775.822]: config item /var/run/ptp4l.delay_filter is 1
ptp4l[526775.822]: config item /var/run/ptp4l.delay_filter_length is 1
ptp4l[526775.824]: config item /var/run/ptp4lro.boundary_clock_jbod is 0
ptp4l[526775.825]: config item /var/run/ptp4lro.serverOnly is 0
ptp4l[526775.825]: config item /var/run/ptp4lro.BMCA is 1
ptp4l[526775.826]: config item /var/run/ptp4lro.network_transport is 0
ptp4l[526775.827]: config item /var/run/ptp4lro.delayAsymmetry is 0
ptp4l[526775.828]: config item /var/run/ptp4lro.follow_up_info is 0
ptp4l[526775.831]: config item /var/run/ptp4lro.freq_est_interval is 1
ptp4l[526775.832]: config item /var/run/ptp4lro.msg_interval_request is
0
ptp4l[526775.832]: config item /var/run/ptp4lro.net_sync_monitor is 0
ptp4l[526775.835]: config item /var/run/ptp4lro.path_trace_enabled is 0
ptp4l[526775.835]: config item /var/run/ptp4lro.tc_spanning_tree is 0
ptp4l[526775.835]: config item /var/run/ptp4lro.ingressLatency is 0
ptp4l[526775.836]: config item /var/run/ptp4lro.egressLatency is 0
ptp4l[526775.837]: config item /var/run/ptp4lro.delay_mechanism is 0
ptp4l[526775.839]: config item /var/run/ptp4lro.hybrid_e2e is 0
ptp4l[526775.840]: config item
/var/run/ptp4lro.fault_badpeernet_interval is 16
ptp4l[526775.841]: config item /var/run/ptp4lro.fault_reset_interval is
4
ptp4l[526775.841]: config item /var/run/ptp4lro.tsproc_mode is 0
ptp4l[526775.841]: config item /var/run/ptp4lro.delay_filter is 1
ptp4l[526775.842]: config item /var/run/ptp4lro.delay_filter_length is 1
ptp4l[526775.844]: config item (null).slave_event_monitor is ''
ptp4l[526775.845]: config item eth0.boundary_clock_jbod is 0
ptp4l[526775.845]: config item eth0.serverOnly is 0
ptp4l[526775.846]: config item eth0.BMCA is 1
ptp4l[526775.846]: config item eth0.network_transport is 1
ptp4l[526775.848]: config item eth0.delayAsymmetry is 0
ptp4l[526775.849]: config item eth0.follow_up_info is 0
ptp4l[526775.849]: config item eth0.freq_est_interval is 1
ptp4l[526775.850]: config item eth0.msg_interval_request is 0
ptp4l[526775.850]: config item eth0.net_sync_monitor is 0
ptp4l[526775.852]: config item eth0.path_trace_enabled is 0
ptp4l[526775.854]: config item eth0.tc_spanning_tree is 0
ptp4l[526775.855]: config item eth0.ingressLatency is 0
ptp4l[526775.855]: config item eth0.egressLatency is 0
ptp4l[526775.856]: config item eth0.delay_mechanism is 1
ptp4l[526775.856]: config item eth0.unicast_master_table is 0
ptp4l[526775.859]: config item eth0.unicast_listen is 0
ptp4l[526775.859]: config item eth0.hybrid_e2e is 0
ptp4l[526775.860]: config item eth0.fault_badpeernet_interval is 16
ptp4l[526775.860]: config item eth0.fault_reset_interval is 4
ptp4l[526775.861]: config item eth0.tsproc_mode is 0
ptp4l[526775.861]: config item eth0.delay_filter is 1
ptp4l[526775.864]: config item eth0.delay_filter_length is 10
ptp4l[526775.865]: config item eth0.logMinDelayReqInterval is 0
ptp4l[526775.865]: config item eth0.logAnnounceInterval is 1
ptp4l[526775.866]: config item eth0.inhibit_announce is 0
ptp4l[526775.869]: config item eth0.ignore_source_id is 0
ptp4l[526775.870]: config item eth0.announceReceiptTimeout is 3
ptp4l[526775.870]: config item eth0.syncReceiptTimeout is 0
ptp4l[526775.871]: config item eth0.transportSpecific is 0
ptp4l[526775.872]: config item eth0.ignore_transport_specific is 0
ptp4l[526775.874]: config item eth0.G.8275.portDS.localPriority is 128
ptp4l[526775.875]: config item eth0.logSyncInterval is 0
ptp4l[526775.875]: config item eth0.operLogSyncInterval is 0
ptp4l[526775.876]: config item eth0.logMinPdelayReqInterval is 0
ptp4l[526775.879]: config item eth0.operLogPdelayReqInterval is 0
ptp4l[526775.880]: config item eth0.neighborPropDelayThresh is 20000000
ptp4l[526775.880]: config item eth0.min_neighbor_prop_delay is -20000000
ptp4l[526775.881]: config item eth0.delay_response_timeout is 0
ptp4l[526775.881]: config item eth0.asCapable is 1
ptp4l[526775.882]: config item eth0.inhibit_delay_req is 0
ptp4l[526775.885]: config item eth0.udp_ttl is 1
ptp4l[526775.893]: config item (null).dscp_event is 0
ptp4l[526775.896]: config item (null).dscp_general is 0
ptp4l[526775.900]: port 1 (eth0): INITIALIZING to SLAVE on INIT_COMPLETE
ptp4l[526775.902]: config item /var/run/ptp4l.logMinDelayReqInterval is
0
ptp4l[526775.905]: config item /var/run/ptp4l.logAnnounceInterval is 1
ptp4l[526775.906]: config item /var/run/ptp4l.inhibit_announce is 0
ptp4l[526775.908]: config item /var/run/ptp4l.ignore_source_id is 0
ptp4l[526775.910]: config item /var/run/ptp4l.announceReceiptTimeout is
0
ptp4l[526775.910]: config item /var/run/ptp4l.syncReceiptTimeout is 0
ptp4l[526775.912]: config item /var/run/ptp4l.transportSpecific is 0
ptp4l[526775.915]: config item /var/run/ptp4l.ignore_transport_specific
is 0
ptp4l[526775.916]: config item
/var/run/ptp4l.G.8275.portDS.localPriority is 128
ptp4l[526775.919]: config item /var/run/ptp4l.logSyncInterval is 0
ptp4l[526775.920]: config item /var/run/ptp4l.operLogSyncInterval is 0
ptp4l[526775.920]: config item /var/run/ptp4l.logMinPdelayReqInterval is
0
ptp4l[526775.921]: config item /var/run/ptp4l.operLogPdelayReqInterval
is 0
ptp4l[526775.923]: config item /var/run/ptp4l.neighborPropDelayThresh is
20000000
ptp4l[526775.924]: config item /var/run/ptp4l.min_neighbor_prop_delay is
-20000000
ptp4l[526775.924]: config item /var/run/ptp4l.delay_response_timeout is
0
ptp4l[526775.925]: config item /var/run/ptp4l.asCapable is 1
ptp4l[526775.927]: config item /var/run/ptp4l.inhibit_delay_req is 0
ptp4l[526775.928]: config item (null).uds_address is '/var/run/ptp4l'
ptp4l[526775.929]: port 0 (/var/run/ptp4l): INITIALIZING to LISTENING on
INIT_COMPLETE
ptp4l[526775.930]: config item /var/run/ptp4lro.logMinDelayReqInterval
is 0
ptp4l[526775.933]: config item /var/run/ptp4lro.logAnnounceInterval is 1
ptp4l[526775.934]: config item /var/run/ptp4lro.inhibit_announce is 0
ptp4l[526775.934]: config item /var/run/ptp4lro.ignore_source_id is 0
ptp4l[526775.935]: config item /var/run/ptp4lro.announceReceiptTimeout
is 0
ptp4l[526775.936]: config item /var/run/ptp4lro.syncReceiptTimeout is 0
ptp4l[526775.937]: config item /var/run/ptp4lro.transportSpecific is 0
ptp4l[526775.937]: config item
/var/run/ptp4lro.ignore_transport_specific is 0
ptp4l[526775.938]: config item
/var/run/ptp4lro.G.8275.portDS.localPriority is 128
ptp4l[526775.939]: config item /var/run/ptp4lro.logSyncInterval is 0
ptp4l[526775.940]: config item /var/run/ptp4lro.operLogSyncInterval is 0
ptp4l[526775.941]: config item /var/run/ptp4lro.logMinPdelayReqInterval
is 0
ptp4l[526775.943]: config item /var/run/ptp4lro.operLogPdelayReqInterval
is 0
ptp4l[526775.944]: config item /var/run/ptp4lro.neighborPropDelayThresh
is 20000000
ptp4l[526775.944]: config item /var/run/ptp4lro.min_neighbor_prop_delay
is -20000000
ptp4l[526775.945]: config item /var/run/ptp4lro.delay_response_timeout
is 0
ptp4l[526775.946]: config item /var/run/ptp4lro.asCapable is 1
ptp4l[526775.948]: config item /var/run/ptp4lro.inhibit_delay_req is 0
ptp4l[526775.949]: config item (null).uds_address is '/var/run/ptp4l'
ptp4l[526775.950]: port 0 (/var/run/ptp4lro): INITIALIZING to LISTENING
on INIT_COMPLETE
ptp4l[526775.952]: port 1 (eth0): received link status notification
ptp4l[526775.955]: interface index 4 is up
ptp4l[526776.598]: port 1 (eth0): setting asCapable
ptp4l[526776.614]: port 1 (eth0): delay timeout
ptp4l[526776.752]: port 1 (eth0): new foreign master
304511.fffe.0ff048-1
ptp4l[526776.928]: port 1 (eth0): delay timeout
ptp4l[526777.908]: port 1 (eth0): delay timeout
ptp4l[526777.945]: port 1 (eth0): delay timeout
ptp4l[526779.134]: port 1 (eth0): delay timeout
ptp4l[526779.616]: port 1 (eth0): delay timeout
ptp4l[526780.752]: selected best master clock 304511.fffe.0ff048
ptp4l[526780.842]: port 1 (eth0): delay timeout
ptp4l[526781.343]: port 1 (eth0): delay timeout
ptp4l[526782.171]: port 1 (eth0): delay timeout
ptp4l[526782.173]: delay filtered 17998 raw 17998
ptp4l[526782.235]: port 1 (eth0): announce timeout
ptp4l[526782.235]: config item eth0.udp_ttl is 1
ptp4l[526782.238]: config item (null).dscp_event is 0
ptp4l[526782.239]: config item (null).dscp_general is 0
ptp4l[526782.239]: selected local clock 304511.fffe.0e6de7 as best
master
ptp4l[526783.276]: port 1 (eth0): delay timeout
ptp4l[526783.278]: delay filtered 18586 raw 18586
ptp4l[526783.599]: master offset 2393871961236 s0 freq -1953122 path
delay 18586
ptp4l[526784.325]: port 1 (eth0): delay timeout
ptp4l[526784.327]: delay filtered 18723 raw 18860
ptp4l[526784.601]: master offset 2393871950451 s1 freq -1953124 path
delay 18723
ptp4l[526784.753]: selected best master clock 304511.fffe.0ff048
ptp4l[526786.165]: port 1 (eth0): delay timeout
ptp4l[526786.167]: delay filtered 17800 raw 17800
ptp4l[526786.599]: master offset 2393871930170 s0 freq -1953124 path
delay 17800
ptp4l[526787.599]: master offset 2393871919846 s0 freq -1953124 path
delay 17800
ptp4l[526787.925]: port 1 (eth0): delay timeout
ptp4l[526787.927]: delay filtered 17271 raw 16742
ptp4l[526788.601]: master offset 2393871909811 s1 freq -1953124 path
delay 17271
ptp4l[526789.267]: port 1 (eth0): delay timeout
ptp4l[526789.599]: master offset 2393871899331 s0 freq -1953124 path
delay 17271
ptp4l[526790.114]: port 1 (eth0): delay timeout
ptp4l[526790.115]: delay filtered 17726 raw 17726
ptp4l[526790.566]: port 1 (eth0): delay timeout
ptp4l[526790.568]: delay filtered 17763 raw 20202
ptp4l[526790.570]: port 1 (eth0): delay timeout
ptp4l[526790.571]: delay filtered 17800 raw 20062
ptp4l[526790.599]: master offset 2393871887998 s0 freq -1953124 path
delay 17800
ptp4l[526791.601]: master offset 2393871877754 s1 freq -1953124 path
delay 17800
ptp4l[526792.507]: port 1 (eth0): delay timeout
ptp4l[526792.600]: clockcheck: clock jumped forward or running faster
than expected!
ptp4l[526792.600]: master offset 2393871867110 s0 freq -1953124 path
delay 17800
ptp4l[526793.021]: port 1 (eth0): delay timeout
ptp4l[526793.022]: delay filtered 17763 raw 17334
ptp4l[526793.209]: port 1 (eth0): delay timeout
ptp4l[526793.211]: delay filtered 17800 raw 18344
ptp4l[526793.602]: master offset 2393871856458 s1 freq -1953124 path
delay 17800
ptp4l[526794.600]: clockcheck: clock jumped forward or running faster
than expected!
ptp4l[526794.600]: master offset 2393871845490 s0 freq -1953124 path
delay 17800
ptp4l[526794.704]: port 1 (eth0): delay timeout
ptp4l[526794.705]: delay filtered 17763 raw 15476
ptp4l[526795.598]: port 1 (eth0): delay timeout
ptp4l[526795.600]: delay filtered 17800 raw 20214
ptp4l[526795.603]: master offset 2393871835326 s1 freq -1953124 path
delay 17800
ptp4l[526796.600]: master offset 2393871824602 s0 freq -1953124 path
delay 17800
ptp4l[526797.274]: port 1 (eth0): delay timeout
ptp4l[526797.275]: delay filtered 18072 raw 18564
ptp4l[526797.600]: clockcheck: clock jumped forward or running faster
than expected!
ptp4l[526797.601]: master offset 2393871813694 s0 freq -1953124 path
delay 18072
ptp4l[526798.581]: port 1 (eth0): delay timeout
ptp4l[526798.583]: delay filtered 18454 raw 20222
ptp4l[526798.602]: master offset 2393871802424 s1 freq -1953124 path
delay 18454
ptp4l[526799.086]: port 1 (eth0): delay timeout
ptp4l[526799.374]: port 1 (eth0): delay timeout
...
Can someone help me out here?
Kind regards
Maximilian
_______________________________________________
Linuxptp-users mailing list
Linuxptp-users@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/linuxptp-users
