search

nxp-archive / openil_linuxptp

PTP IEEE 1588 stack for Linux
GNU General Public License v2.0
136 stars 60 forks source link

Configured TAPRIO - ptp4l do not sync #19

Open rezabfil-sec opened 3 years ago

rezabfil-sec commented 3 years ago

Hi, I am having a simple three node setup formed in a triangle:

Link_1: source-->hop-->sink. Link_2: source-->sink

On the source is configured ETF qdisc as follows:

qdisc replace dev enp3s0 parent root handle 100 mqprio        \
      num_tc 3                                        \
      map 2 2 1 0 2 2 2 2 2 2 2 2 2 2 2 2 \
      queues 1@0 1@1 2@2 \
      hw 0

qdisc replace dev enp3s0 parent 100:1 etf \
    clockid CLOCK_TAI delta 500000 offload  skip_sock_check

qdisc replace dev enp3s0 parent 100:2 etf \
    clockid CLOCK_TAI delta 500000 offload deadline_mode skip_sock_check

The hop has a following TAPRIO + ETF configuration:

qdisc replace dev enp5s0 parent root handle 100 taprio  \
  num_tc 3                                  \ 
  map 2 2 1 0 2 2 2 2 2 2 2 2 2 2 2 2 \  
  queues 1@0 1@1 2@2 \
  base-time 1605802187000000000          \ 
  flags 0x1                                                       \
  txtime-delay 400000 \
  sched-entry S 01 250000 \
  sched-entry S 00 50000 \ 
  sched-entry S 02 250000 \
  sched-entry S 00 50000 \ 
  sched-entry S 04 350000 \
  sched-entry S 00 50000 \ 
  clockid CLOCK_TAI                                                                                                                                                                                                                         

  qdisc replace dev enp5s0 parent 100:1 etf \
    clockid CLOCK_TAI delta 500000 offload  skip_sock_check                                                                                                                                                                                     
  qdisc replace dev enp5s0 parent 100:2 etf \   
     clockid CLOCK_TAI delta 500000 offload deadline_mode skip_sock_check

I am collecting traffic on the sink using TCPDUMP.

All of the connections are done using the Intel i210 cards.

The issue I am facing is that after I configured the hop using TAPRIO (w/ flags 0x1 and also w/o), the ptp4l stops to be in sync with other hops and also stops to exchange messages.

ptp4l gPTP.cfg on the hop, sink and source follow same logic :

[global]
gmCapable               1
priority1               248
priority2               248
logAnnounceInterval     2
logSyncInterval         2
logMinDelayReqInterval  2
logMinPdelayReqInterval 2
syncReceiptTimeout      5
announceReceiptTimeout  5
neighborPropDelayThresh 1000
min_neighbor_prop_delay -20000000
assume_two_step         1
path_trace_enabled      1
follow_up_info          1
transportSpecific       0x1
ptp_dst_mac             01:80:C2:00:00:0E
network_transport       L2

[enp3s0]
boundary_clock_jbod     1
[enp4s0]
boundary_clock_jbod     1

Executing following ptp4lcommand:

ptp4l -f gPTP.cfg --step_threshold=1 --socket_priority 1

What have I tried so far:

Before I introduced the TAPRIO qdisc, everything was working well and the clocks were in sync.

When using pmc -u -b 0 -t 1 "GET PARENT_DATA_SET", I see each node elects one of own ifaces as GM.

Any pointers on how to solve this issue would be appreciated!

Thanks!

vladimiroltean commented 3 years ago

Does it start working if you add a sched-entry S ff 50000 to the taprio schedule?

rezabfil-sec commented 3 years ago

I updated as following:

qdisc replace dev enp4s0 parent root handle 100 taprio  \
      num_tc 3                                  \
      map 2 2 1 0 2 2 2 2 2 2 2 2 2 2 2 2 \
      queues 1@0 1@1 2@2 \
      base-time 1605802187000000000          \
      flags 0x1                                                       \
      txtime-delay 400000 \
      sched-entry S 01 250000 \
      sched-entry S 00 50000 \
      sched-entry S 02 250000 \
      sched-entry S 00 50000 \
      sched-entry S 04 350000 \
      sched-entry S 00 50000 \
      sched-entry S ff 50000 \
      clockid CLOCK_TAI

qdisc replace dev enp4s0 parent 100:1 etf \
    clockid CLOCK_TAI delta 500000 offload  skip_sock_check

qdisc replace dev enp4s0 parent 100:2 etf \
    clockid CLOCK_TAI delta 500000 offload deadline_mode skip_sock_check

Unfortunately, the result is the same.

vladimiroltean commented 3 years ago

Can you please show the output of ptp4l?

rezabfil-sec commented 3 years ago

On each node it follows the same structure.

ptp4l -f /data/gPTP.cfg --step_threshold=1 --socket_priority 1 -m Results:


ptp4l[60122.623]: selected /dev/ptp0 as PTP clock
ptp4l[60122.623]: port 2: just a bunch of devices
ptp4l[60122.686]: port 1: INITIALIZING to LISTENING on INIT_COMPLETE
ptp4l[60122.730]: port 2: INITIALIZING to LISTENING on INIT_COMPLETE
ptp4l[60122.731]: port 0: INITIALIZING to LISTENING on INIT_COMPLETE                                                                                                                                                                            ptp4l[60143.285]: port 2: LISTENING to MASTER on ANNOUNCE_RECEIPT_TIMEOUT_EXPIRES                                       ptp4l[60143.285]: selected local clock 6cb311.fffe.525468 as best master
ptp4l[60143.285]: port 2: assuming the grand master role
ptp4l[60146.300]: port 1: LISTENING to MASTER on ANNOUNCE_RECEIPT_TIMEOUT_EXPIRES
ptp4l[60146.300]: selected local clock 6cb311.fffe.525468 as best master
ptp4l[60146.300]: port 1: assuming the grand master role
ptp4l[60146.300]: port 2: assuming the grand master role

phc2sys phc2sys -a -r --step_threshold=1 --transportSpecific=1 -x -E pi Results:

phc2sys[60311.576]: reconfiguring after port state change
phc2sys[60311.577]: selecting enp4s0 for synchronization
phc2sys[60311.577]: selecting enp3s0 for synchronization
phc2sys[60311.577]: no source, selecting enp3s0 as the default clock
phc2sys[60311.577]: enp4s0 phc offset        76 s0 freq     -54 delay  11184
phc2sys[60312.577]: enp4s0 phc offset       129 s2 freq      -1 delay  10624
phc2sys[60313.578]: enp4s0 phc offset       167 s2 freq    +166 delay  10624
phc2sys[60314.578]: enp4s0 phc offset       -41 s2 freq      +8 delay  10560
phc2sys[60315.578]: enp4s0 phc offset       -75 s2 freq     -38 delay  10656
phc2sys[60316.578]: port 6cb311.fffe.525468-1 changed state
phc2sys[60316.578]: reconfiguring after port state change
phc2sys[60316.578]: selecting enp4s0 for synchronization
phc2sys[60316.579]: selecting enp3s0 for synchronization
phc2sys[60316.579]: no source, selecting enp3s0 as the default clock
phc2sys[60316.579]: enp4s0 phc offset       -46 s2 freq     -32 delay  10656
phc2sys[60317.579]: enp4s0 phc offset       -56 s2 freq     -56 delay  10592
phc2sys[60318.579]: port 6cb311.fffe.525468-2 changed state
phc2sys[60318.579]: reconfiguring after port state change
phc2sys[60318.579]: selecting enp4s0 for synchronization
phc2sys[60318.580]: selecting enp3s0 for synchronization
phc2sys[60318.580]: no source, selecting enp3s0 as the default clock
phc2sys[60318.580]: enp4s0 phc offset        31 s0 freq     -56 delay  10608
phc2sys[60319.580]: enp4s0 phc offset        44 s2 freq      -3 delay  10608
phc2sys[60320.580]: enp4s0 phc offset        -3 s2 freq      -6 delay  10592
phc2sys[60321.580]: enp4s0 phc offset        17 s2 freq     +13 delay  10608
phc2sys[60322.581]: enp4s0 phc offset       -46 s2 freq     -45 delay  10624
phc2sys[60323.581]: enp4s0 phc offset       -28 s2 freq     -41 delay  10624
phc2sys[60324.581]: enp4s0 phc offset        43 s2 freq     +22 delay  10608
phc2sys[60325.581]: enp4s0 phc offset       -53 s2 freq     -61 delay  10608
phc2sys[60326.581]: enp4s0 phc offset       -18 s2 freq     -42 delay  10608
phc2sys[60327.582]: enp4s0 phc offset        14 s2 freq     -16 delay  10576
phc2sys[60328.582]: enp4s0 phc offset        36 s2 freq     +10 delay  10608
phc2sys[60329.201]: enp4s0 phc offset       -47 s2 freq     -62 delay  10608
vladimiroltean commented 3 years ago

Are there any Sync packets being sent by the hop node? How about received by the sink? Do the "ethtool -S" counters indicate anything about packet drops?

vladimiroltean commented 3 years ago

If no Sync packets are even sent, can you try increasing neighborPropDelayThresh to a very large value like 1000000?

rezabfil-sec commented 3 years ago

I tried with 1000000 and 2000000, unfortunately it still results in the same behavior.

Also, I do not see any traffic using tcpdump on the corresponding interfaces.

output for "ethtool -S" on of the interfaces:

     tx_queue_3_packets: 26
     tx_queue_3_bytes: 3588
     tx_queue_3_restart: 0
     rx_queue_3_packets: 66
     rx_queue_3_bytes: 8316
     rx_queue_3_drops: 0
     rx_queue_3_csum_err: 0
     rx_queue_3_alloc_failed: 0

I kept an eye on it for some time and it is not increasing..

I see other traffic going through the iface - e.g. ping between source and sink..

vladimiroltean commented 3 years ago

Ok, then please share the full output of "ptp4l -f gPTP.cfg --step_threshold=1 --socket_priority 1 -l 7" taken on the hop node. If there is no Sync packet it is because there is no peer delay protocol running. As to why there isn't any peer delay, I don't know.

rezabfil-sec commented 3 years ago

Sure, here is the output of ptp4l -f /data/gPTP.cfg --step_threshold=1 --socket_priority 1 -H -l 7 -m: 

ptp4l[8908.365]: config item (null).assume_two_step is 1
ptp4l[8908.366]: config item (null).check_fup_sync is 0
ptp4l[8908.366]: config item (null).tx_timestamp_timeout is 1
ptp4l[8908.366]: config item (null).hwts_filter is 0
ptp4l[8908.366]: config item (null).clock_servo is 0
ptp4l[8908.366]: config item (null).clock_type is 32768
ptp4l[8908.366]: config item (null).clock_servo is 0
ptp4l[8908.366]: config item (null).clockClass is 248
ptp4l[8908.366]: config item (null).clockAccuracy is 254
ptp4l[8908.366]: config item (null).offsetScaledLogVariance is 65535
ptp4l[8908.366]: config item (null).productDescription is ';;'
ptp4l[8908.366]: config item (null).revisionData is ';;'
ptp4l[8908.366]: config item (null).userDescription is ''
ptp4l[8908.366]: config item (null).manufacturerIdentity is '00:00:00'
ptp4l[8908.366]: config item (null).domainNumber is 0
ptp4l[8908.366]: config item (null).slaveOnly is 0
ptp4l[8908.366]: config item (null).gmCapable is 1
ptp4l[8908.366]: config item (null).gmCapable is 1
ptp4l[8908.366]: config item (null).G.8275.defaultDS.localPriority is 128
ptp4l[8908.366]: config item (null).maxStepsRemoved is 255
ptp4l[8908.366]: config item (null).time_stamping is 1
ptp4l[8908.366]: config item (null).twoStepFlag is 1
ptp4l[8908.366]: config item (null).twoStepFlag is 1
ptp4l[8908.366]: config item (null).time_stamping is 1
ptp4l[8908.366]: config item (null).priority1 is 248
ptp4l[8908.366]: config item (null).priority2 is 248
ptp4l[8908.366]: interface index 5 is up
ptp4l[8908.367]: interface index 6 is up
ptp4l[8908.367]: config item (null).free_running is 0
ptp4l[8908.367]: selected /dev/ptp2 as PTP clock
ptp4l[8908.367]: config item (null).clockIdentity is '000000.0000.000000'
ptp4l[8908.367]: config item (null).uds_address is '/var/run/ptp4l'
ptp4l[8908.367]: section item /var/run/ptp4l.announceReceiptTimeout now 0
ptp4l[8908.367]: section item /var/run/ptp4l.delay_mechanism now 0
ptp4l[8908.367]: section item /var/run/ptp4l.network_transport now 0
ptp4l[8908.367]: section item /var/run/ptp4l.delay_filter_length now 1
ptp4l[8908.367]: config item (null).free_running is 0
ptp4l[8908.367]: config item (null).freq_est_interval is 1
ptp4l[8908.367]: config item (null).write_phase_mode is 0
ptp4l[8908.367]: config item (null).gmCapable is 1
ptp4l[8908.367]: config item (null).kernel_leap is 1
ptp4l[8908.367]: config item (null).utc_offset is 37
ptp4l[8908.367]: config item (null).timeSource is 160
ptp4l[8908.367]: config item (null).pi_proportional_const is 0.000000
ptp4l[8908.367]: config item (null).pi_integral_const is 0.000000
ptp4l[8908.367]: config item (null).pi_proportional_scale is 0.000000
ptp4l[8908.367]: config item (null).pi_proportional_exponent is -0.300000
ptp4l[8908.367]: config item (null).pi_proportional_norm_max is 0.700000
ptp4l[8908.367]: config item (null).pi_integral_scale is 0.000000
ptp4l[8908.367]: config item (null).pi_integral_exponent is 0.400000
ptp4l[8908.367]: config item (null).pi_integral_norm_max is 0.300000
ptp4l[8908.367]: config item (null).step_threshold is 1.000000
ptp4l[8908.367]: config item (null).first_step_threshold is 0.000020
ptp4l[8908.367]: config item (null).max_frequency is 900000000
ptp4l[8908.367]: config item (null).servo_offset_threshold is 0
ptp4l[8908.367]: config item (null).servo_num_offset_values is 10
ptp4l[8908.367]: config item (null).dataset_comparison is 0
ptp4l[8908.368]: config item (null).delay_filter_length is 10
ptp4l[8908.368]: config item (null).delay_filter is 1
ptp4l[8908.368]: config item (null).tsproc_mode is 0
ptp4l[8908.368]: config item (null).initial_delay is 0
ptp4l[8908.368]: config item (null).summary_interval is 0
ptp4l[8908.368]: config item (null).sanity_freq_limit is 200000000
ptp4l[8908.368]: PI servo: sync interval 1.000 kp 0.700 ki 0.300000
ptp4l[8908.368]: config item /var/run/ptp4l.boundary_clock_jbod is 0
ptp4l[8908.368]: config item /var/run/ptp4l.network_transport is 0
ptp4l[8908.368]: config item /var/run/ptp4l.masterOnly is 0
ptp4l[8908.368]: config item /var/run/ptp4l.BMCA is 0
ptp4l[8908.368]: config item /var/run/ptp4l.delayAsymmetry is 0
ptp4l[8908.368]: config item /var/run/ptp4l.follow_up_info is 1
ptp4l[8908.368]: config item /var/run/ptp4l.freq_est_interval is 1
ptp4l[8908.368]: config item /var/run/ptp4l.msg_interval_request is 0
ptp4l[8908.368]: config item /var/run/ptp4l.net_sync_monitor is 0
ptp4l[8908.368]: config item /var/run/ptp4l.path_trace_enabled is 1
ptp4l[8908.368]: config item /var/run/ptp4l.tc_spanning_tree is 0
ptp4l[8908.368]: config item /var/run/ptp4l.ingressLatency is 0
ptp4l[8908.368]: config item /var/run/ptp4l.egressLatency is 0
ptp4l[8908.368]: config item /var/run/ptp4l.delay_mechanism is 0
ptp4l[8908.368]: config item /var/run/ptp4l.hybrid_e2e is 0
ptp4l[8908.368]: config item /var/run/ptp4l.fault_badpeernet_interval is 16
ptp4l[8908.368]: config item /var/run/ptp4l.fault_reset_interval is 4
ptp4l[8908.368]: config item /var/run/ptp4l.delay_filter_length is 1
ptp4l[8908.368]: config item /var/run/ptp4l.delay_filter is 1
ptp4l[8908.368]: config item /var/run/ptp4l.tsproc_mode is 0
ptp4l[8908.368]: config item (null).slave_event_monitor is ''
ptp4l[8908.368]: config item enp5s0.boundary_clock_jbod is 1
ptp4l[8908.368]: config item enp5s0.network_transport is 3
ptp4l[8908.368]: config item enp5s0.masterOnly is 0
ptp4l[8908.368]: config item enp5s0.BMCA is 0
ptp4l[8908.368]: config item enp5s0.delayAsymmetry is 0
ptp4l[8908.368]: config item enp5s0.follow_up_info is 1
ptp4l[8908.368]: config item enp5s0.freq_est_interval is 1
ptp4l[8908.368]: config item enp5s0.msg_interval_request is 0
ptp4l[8908.368]: config item enp5s0.net_sync_monitor is 0
ptp4l[8908.368]: config item enp5s0.path_trace_enabled is 1
ptp4l[8908.368]: config item enp5s0.tc_spanning_tree is 0
ptp4l[8908.368]: config item enp5s0.ingressLatency is 0
ptp4l[8908.368]: config item enp5s0.egressLatency is 0
ptp4l[8908.368]: config item enp5s0.delay_mechanism is 1
ptp4l[8908.368]: config item enp5s0.unicast_master_table is 0
ptp4l[8908.368]: config item enp5s0.unicast_listen is 0
ptp4l[8908.368]: config item enp5s0.hybrid_e2e is 0
ptp4l[8908.368]: config item enp5s0.fault_badpeernet_interval is 16
ptp4l[8908.369]: config item enp5s0.fault_reset_interval is 4
ptp4l[8908.369]: config item enp5s0.delay_filter_length is 10
ptp4l[8908.369]: config item enp5s0.delay_filter is 1
ptp4l[8908.369]: config item enp5s0.tsproc_mode is 0
ptp4l[8908.369]: config item enp6s0.boundary_clock_jbod is 1
ptp4l[8908.369]: config item enp6s0.network_transport is 3
ptp4l[8908.369]: config item enp6s0.masterOnly is 0
ptp4l[8908.369]: config item enp6s0.BMCA is 0
ptp4l[8908.369]: port 2: just a bunch of devices
ptp4l[8908.369]: config item enp6s0.delayAsymmetry is 0
ptp4l[8908.369]: config item enp6s0.follow_up_info is 1
ptp4l[8908.369]: config item enp6s0.freq_est_interval is 1
ptp4l[8908.369]: config item enp6s0.msg_interval_request is 0
ptp4l[8908.369]: config item enp6s0.net_sync_monitor is 0
ptp4l[8908.369]: config item enp6s0.path_trace_enabled is 1
ptp4l[8908.369]: config item enp6s0.tc_spanning_tree is 0
ptp4l[8908.369]: config item enp6s0.ingressLatency is 0
ptp4l[8908.369]: config item enp6s0.egressLatency is 0
ptp4l[8908.369]: config item enp6s0.delay_mechanism is 1
ptp4l[8908.369]: config item enp6s0.unicast_master_table is 0
ptp4l[8908.369]: config item enp6s0.unicast_listen is 0
ptp4l[8908.369]: config item enp6s0.hybrid_e2e is 0
ptp4l[8908.369]: config item enp6s0.fault_badpeernet_interval is 16
ptp4l[8908.369]: config item enp6s0.fault_reset_interval is 4
ptp4l[8908.369]: config item enp6s0.delay_filter_length is 10
ptp4l[8908.369]: config item enp6s0.delay_filter is 1
ptp4l[8908.369]: config item enp6s0.tsproc_mode is 0
ptp4l[8908.369]: config item enp5s0.logMinDelayReqInterval is 2
ptp4l[8908.369]: config item enp5s0.logAnnounceInterval is 2
ptp4l[8908.369]: config item enp5s0.inhibit_announce is 0
ptp4l[8908.369]: config item enp5s0.ignore_source_id is 0
ptp4l[8908.369]: config item enp5s0.announceReceiptTimeout is 5
ptp4l[8908.369]: config item enp5s0.syncReceiptTimeout is 5
ptp4l[8908.369]: config item enp5s0.transportSpecific is 1
ptp4l[8908.369]: config item enp5s0.ignore_transport_specific is 0
ptp4l[8908.369]: config item enp5s0.G.8275.portDS.localPriority is 128
ptp4l[8908.369]: config item enp5s0.logSyncInterval is 2
ptp4l[8908.369]: config item enp5s0.operLogSyncInterval is 0
ptp4l[8908.369]: config item enp5s0.logMinPdelayReqInterval is 2
ptp4l[8908.369]: config item enp5s0.operLogPdelayReqInterval is 0
ptp4l[8908.369]: config item enp5s0.neighborPropDelayThresh is 3000000
ptp4l[8908.369]: config item enp5s0.min_neighbor_prop_delay is -20000000
ptp4l[8908.369]: config item enp5s0.asCapable is 1
ptp4l[8908.369]: config item enp5s0.inhibit_delay_req is 0
ptp4l[8908.369]: config item enp5s0.ptp_dst_mac is '01:80:C2:00:00:0E'
ptp4l[8908.369]: config item enp5s0.p2p_dst_mac is '01:80:C2:00:00:0E'
ptp4l[8908.369]: config item global.socket_priority is 1
ptp4l[8908.415]: port 1: INITIALIZING to LISTENING on INIT_COMPLETE
ptp4l[8908.415]: config item enp6s0.logMinDelayReqInterval is 2
ptp4l[8908.415]: config item enp6s0.logAnnounceInterval is 2
ptp4l[8908.415]: config item enp6s0.inhibit_announce is 0
ptp4l[8908.415]: config item enp6s0.ignore_source_id is 0
ptp4l[8908.415]: config item enp6s0.announceReceiptTimeout is 5
ptp4l[8908.415]: config item enp6s0.syncReceiptTimeout is 5
ptp4l[8908.415]: config item enp6s0.transportSpecific is 1
ptp4l[8908.415]: config item enp6s0.ignore_transport_specific is 0
ptp4l[8908.415]: config item enp6s0.G.8275.portDS.localPriority is 128
ptp4l[8908.415]: config item enp6s0.logSyncInterval is 2
ptp4l[8908.415]: config item enp6s0.operLogSyncInterval is 0
ptp4l[8908.415]: config item enp6s0.logMinPdelayReqInterval is 2
ptp4l[8908.415]: config item enp6s0.operLogPdelayReqInterval is 0
ptp4l[8908.415]: config item enp6s0.neighborPropDelayThresh is 3000000
ptp4l[8908.415]: config item enp6s0.min_neighbor_prop_delay is -20000000
ptp4l[8908.415]: config item enp6s0.asCapable is 1
ptp4l[8908.415]: config item enp6s0.inhibit_delay_req is 0
ptp4l[8908.415]: config item enp6s0.ptp_dst_mac is '01:80:C2:00:00:0E'
ptp4l[8908.415]: config item enp6s0.p2p_dst_mac is '01:80:C2:00:00:0E'
ptp4l[8908.415]: config item global.socket_priority is 1
ptp4l[8908.470]: port 2: INITIALIZING to LISTENING on INIT_COMPLETE
ptp4l[8908.471]: config item /var/run/ptp4l.logMinDelayReqInterval is 2
ptp4l[8908.471]: config item /var/run/ptp4l.logAnnounceInterval is 2
ptp4l[8908.471]: config item /var/run/ptp4l.inhibit_announce is 0
ptp4l[8908.471]: config item /var/run/ptp4l.ignore_source_id is 0
ptp4l[8908.471]: config item /var/run/ptp4l.announceReceiptTimeout is 0
ptp4l[8908.471]: config item /var/run/ptp4l.syncReceiptTimeout is 5
ptp4l[8908.471]: config item /var/run/ptp4l.transportSpecific is 1
ptp4l[8908.471]: config item /var/run/ptp4l.ignore_transport_specific is 0
ptp4l[8908.471]: config item /var/run/ptp4l.G.8275.portDS.localPriority is 128
ptp4l[8908.471]: config item /var/run/ptp4l.logSyncInterval is 2
ptp4l[8908.471]: config item /var/run/ptp4l.operLogSyncInterval is 0
ptp4l[8908.471]: config item /var/run/ptp4l.logMinPdelayReqInterval is 2
ptp4l[8908.471]: config item /var/run/ptp4l.operLogPdelayReqInterval is 0
ptp4l[8908.471]: config item /var/run/ptp4l.neighborPropDelayThresh is 3000000
ptp4l[8908.471]: config item /var/run/ptp4l.min_neighbor_prop_delay is -20000000
ptp4l[8908.471]: config item /var/run/ptp4l.asCapable is 1
ptp4l[8908.471]: config item /var/run/ptp4l.inhibit_delay_req is 0
ptp4l[8908.471]: config item (null).uds_address is '/var/run/ptp4l'
ptp4l[8908.471]: port 0: INITIALIZING to LISTENING on INIT_COMPLETE
ptp4l[8908.471]: port 1: ignoring message
ptp4l[8908.471]: port 1: received link status notification
ptp4l[8908.471]: interface index 5 is up
ptp4l[8908.471]: port 2: received link status notification
ptp4l[8908.471]: interface index 6 is up

ptp4l[8929.245]: port 1: announce timeout
ptp4l[8929.245]: port 1: LISTENING to MASTER on ANNOUNCE_RECEIPT_TIMEOUT_EXPIRES
ptp4l[8929.245]: selected local clock 6cb311.fffe.525436 as best master
ptp4l[8929.245]: port 1: assuming the grand master role
ptp4l[8929.246]: port 1: master tx announce timeout
ptp4l[8929.612]: port 2: announce timeout
ptp4l[8929.612]: port 2: LISTENING to MASTER on ANNOUNCE_RECEIPT_TIMEOUT_EXPIRES
ptp4l[8929.612]: selected local clock 6cb311.fffe.525436 as best master
ptp4l[8929.612]: port 1: assuming the grand master role
ptp4l[8929.612]: port 2: assuming the grand master role
ptp4l[8929.613]: port 2: master tx announce timeout
ptp4l[8933.245]: port 1: master sync timeout
ptp4l[8933.246]: port 1: master tx announce timeout
ptp4l[8933.612]: port 2: master sync timeout
ptp4l[8933.613]: port 2: master tx announce timeout
ptp4l[8934.430]: port 1: received link status notification
ptp4l[8934.430]: port 2: received link status notification
ptp4l[8937.245]: port 1: master sync timeout
ptp4l[8937.246]: port 1: master tx announce timeout
ptp4l[8937.612]: port 2: master sync timeout
ptp4l[8937.613]: port 2: master tx announce timeout
ptp4l[8941.245]: port 1: master sync timeout
ptp4l[8941.246]: port 1: master tx announce timeout
ptp4l[8941.612]: port 2: master sync timeout
ptp4l[8941.613]: port 2: master tx announce timeout
ptp4l[8945.245]: port 1: master sync timeout
ptp4l[8945.246]: port 1: master tx announce timeout
ptp4l[8945.612]: port 2: master sync timeout
ptp4l[8945.613]: port 2: master tx announce timeout

Thanks for looking into it!

rezabfil-sec commented 3 years ago

I modified a bit the config and rerun the tests.

ptp4l -f /data/gPTP.cfg --step_threshold=1 -H -m -l 7

ptp4l[5745.041]: config item (null).assume_two_step is 1
ptp4l[5745.041]: config item (null).check_fup_sync is 0
ptp4l[5745.041]: config item (null).tx_timestamp_timeout is 100
ptp4l[5745.041]: config item (null).hwts_filter is 0
ptp4l[5745.041]: config item (null).clock_servo is 0
ptp4l[5745.042]: config item (null).clock_type is 32768
ptp4l[5745.042]: config item (null).clock_servo is 0
ptp4l[5745.042]: config item (null).clockClass is 248
ptp4l[5745.042]: config item (null).clockAccuracy is 254
ptp4l[5745.042]: config item (null).offsetScaledLogVariance is 65535
ptp4l[5745.042]: config item (null).productDescription is ';;'
ptp4l[5745.042]: config item (null).revisionData is ';;'
ptp4l[5745.042]: config item (null).userDescription is ''
ptp4l[5745.042]: config item (null).manufacturerIdentity is '00:00:00'
ptp4l[5745.042]: config item (null).domainNumber is 0
ptp4l[5745.042]: config item (null).slaveOnly is 0
ptp4l[5745.042]: config item (null).gmCapable is 1
ptp4l[5745.042]: config item (null).gmCapable is 1
ptp4l[5745.042]: config item (null).G.8275.defaultDS.localPriority is 128
ptp4l[5745.042]: config item (null).maxStepsRemoved is 255
ptp4l[5745.042]: config item (null).time_stamping is 1
ptp4l[5745.042]: config item (null).twoStepFlag is 1
ptp4l[5745.042]: config item (null).twoStepFlag is 1
ptp4l[5745.042]: config item (null).time_stamping is 1
ptp4l[5745.042]: config item (null).priority1 is 248
ptp4l[5745.042]: config item (null).priority2 is 248
ptp4l[5745.042]: interface index 5 is up
ptp4l[5745.042]: interface index 6 is up
ptp4l[5745.042]: config item (null).free_running is 0
ptp4l[5745.042]: selected /dev/ptp2 as PTP clock
ptp4l[5745.043]: config item (null).clockIdentity is '000000.0000.000000'
ptp4l[5745.043]: config item (null).uds_address is '/var/run/ptp4l'
ptp4l[5745.043]: section item /var/run/ptp4l.announceReceiptTimeout now 0
ptp4l[5745.043]: section item /var/run/ptp4l.delay_mechanism now 0
ptp4l[5745.043]: section item /var/run/ptp4l.network_transport now 0
ptp4l[5745.043]: section item /var/run/ptp4l.delay_filter_length now 1
ptp4l[5745.043]: config item (null).free_running is 0
ptp4l[5745.043]: config item (null).freq_est_interval is 1
ptp4l[5745.043]: config item (null).write_phase_mode is 0
ptp4l[5745.043]: config item (null).gmCapable is 1
ptp4l[5745.043]: config item (null).kernel_leap is 1
ptp4l[5745.043]: config item (null).utc_offset is 37
ptp4l[5745.043]: config item (null).timeSource is 160
ptp4l[5745.043]: config item (null).pi_proportional_const is 0.000000
ptp4l[5745.043]: config item (null).pi_integral_const is 0.000000
ptp4l[5745.043]: config item (null).pi_proportional_scale is 0.000000
ptp4l[5745.043]: config item (null).pi_proportional_exponent is -0.300000
ptp4l[5745.043]: config item (null).pi_proportional_norm_max is 0.700000
ptp4l[5745.043]: config item (null).pi_integral_scale is 0.000000
ptp4l[5745.043]: config item (null).pi_integral_exponent is 0.400000
ptp4l[5745.043]: config item (null).pi_integral_norm_max is 0.300000
ptp4l[5745.043]: config item (null).step_threshold is 1.000000
ptp4l[5745.043]: config item (null).first_step_threshold is 0.000020
ptp4l[5745.043]: config item (null).max_frequency is 900000000
ptp4l[5745.043]: config item (null).servo_offset_threshold is 0
ptp4l[5745.043]: config item (null).servo_num_offset_values is 10
ptp4l[5745.043]: config item (null).dataset_comparison is 0
ptp4l[5745.043]: config item (null).delay_filter_length is 10
ptp4l[5745.043]: config item (null).delay_filter is 1
ptp4l[5745.043]: config item (null).tsproc_mode is 0
ptp4l[5745.043]: config item (null).initial_delay is 0
ptp4l[5745.043]: config item (null).summary_interval is 0
ptp4l[5745.043]: config item (null).sanity_freq_limit is 200000000
ptp4l[5745.043]: PI servo: sync interval 1.000 kp 0.700 ki 0.300000
ptp4l[5745.043]: config item /var/run/ptp4l.boundary_clock_jbod is 0
ptp4l[5745.043]: config item /var/run/ptp4l.network_transport is 0
ptp4l[5745.043]: config item /var/run/ptp4l.masterOnly is 0
ptp4l[5745.043]: config item /var/run/ptp4l.BMCA is 0
ptp4l[5745.043]: config item /var/run/ptp4l.delayAsymmetry is 0
ptp4l[5745.043]: config item /var/run/ptp4l.follow_up_info is 1
ptp4l[5745.043]: config item /var/run/ptp4l.freq_est_interval is 1
ptp4l[5745.043]: config item /var/run/ptp4l.msg_interval_request is 0
ptp4l[5745.043]: config item /var/run/ptp4l.net_sync_monitor is 0
ptp4l[5745.044]: config item /var/run/ptp4l.path_trace_enabled is 1
ptp4l[5745.044]: config item /var/run/ptp4l.tc_spanning_tree is 0
ptp4l[5745.044]: config item /var/run/ptp4l.ingressLatency is 0
ptp4l[5745.044]: config item /var/run/ptp4l.egressLatency is 0
ptp4l[5745.044]: config item /var/run/ptp4l.delay_mechanism is 0
ptp4l[5745.044]: config item /var/run/ptp4l.hybrid_e2e is 0
ptp4l[5745.044]: config item /var/run/ptp4l.fault_badpeernet_interval is 16
ptp4l[5745.044]: config item /var/run/ptp4l.fault_reset_interval is 4
ptp4l[5745.044]: config item /var/run/ptp4l.delay_filter_length is 1
ptp4l[5745.044]: config item /var/run/ptp4l.delay_filter is 1
ptp4l[5745.044]: config item /var/run/ptp4l.tsproc_mode is 0
ptp4l[5745.044]: config item (null).slave_event_monitor is ''
ptp4l[5745.044]: config item enp5s0.boundary_clock_jbod is 1
ptp4l[5745.044]: config item enp5s0.network_transport is 3
ptp4l[5745.044]: config item enp5s0.masterOnly is 0
ptp4l[5745.044]: config item enp5s0.BMCA is 0
ptp4l[5745.044]: config item enp5s0.delayAsymmetry is 0
ptp4l[5745.044]: config item enp5s0.follow_up_info is 1
ptp4l[5745.044]: config item enp5s0.freq_est_interval is 1
ptp4l[5745.044]: config item enp5s0.msg_interval_request is 0
ptp4l[5745.044]: config item enp5s0.net_sync_monitor is 0
ptp4l[5745.044]: config item enp5s0.path_trace_enabled is 1
ptp4l[5745.044]: config item enp5s0.tc_spanning_tree is 0
ptp4l[5745.044]: config item enp5s0.ingressLatency is 0
ptp4l[5745.044]: config item enp5s0.egressLatency is 0
ptp4l[5745.044]: config item enp5s0.delay_mechanism is 2
ptp4l[5745.044]: config item enp5s0.unicast_master_table is 0
ptp4l[5745.044]: config item enp5s0.unicast_listen is 0
ptp4l[5745.044]: config item enp5s0.hybrid_e2e is 0
ptp4l[5745.044]: config item enp5s0.fault_badpeernet_interval is 16
ptp4l[5745.044]: config item enp5s0.fault_reset_interval is 4
ptp4l[5745.044]: config item enp5s0.delay_filter_length is 10
ptp4l[5745.044]: config item enp5s0.delay_filter is 1
ptp4l[5745.044]: config item enp5s0.tsproc_mode is 0
ptp4l[5745.044]: config item enp6s0.boundary_clock_jbod is 1
ptp4l[5745.044]: config item enp6s0.network_transport is 3
ptp4l[5745.044]: config item enp6s0.masterOnly is 0
ptp4l[5745.044]: config item enp6s0.BMCA is 0
ptp4l[5745.044]: port 2: just a bunch of devices
ptp4l[5745.044]: config item enp6s0.delayAsymmetry is 0
ptp4l[5745.044]: config item enp6s0.follow_up_info is 1
ptp4l[5745.044]: config item enp6s0.freq_est_interval is 1
ptp4l[5745.044]: config item enp6s0.msg_interval_request is 0
ptp4l[5745.044]: config item enp6s0.net_sync_monitor is 0
ptp4l[5745.044]: config item enp6s0.path_trace_enabled is 1
ptp4l[5745.044]: config item enp6s0.tc_spanning_tree is 0
ptp4l[5745.044]: config item enp6s0.ingressLatency is 0
ptp4l[5745.044]: config item enp6s0.egressLatency is 0
ptp4l[5745.044]: config item enp6s0.delay_mechanism is 2
ptp4l[5745.044]: config item enp6s0.unicast_master_table is 0
ptp4l[5745.044]: config item enp6s0.unicast_listen is 0
ptp4l[5745.044]: config item enp6s0.hybrid_e2e is 0
ptp4l[5745.044]: config item enp6s0.fault_badpeernet_interval is 16
ptp4l[5745.044]: config item enp6s0.fault_reset_interval is 4
ptp4l[5745.044]: config item enp6s0.delay_filter_length is 10
ptp4l[5745.044]: config item enp6s0.delay_filter is 1
ptp4l[5745.044]: config item enp6s0.tsproc_mode is 0
ptp4l[5745.044]: config item enp5s0.logMinDelayReqInterval is 0
ptp4l[5745.044]: config item enp5s0.logAnnounceInterval is 0
ptp4l[5745.045]: config item enp5s0.inhibit_announce is 0
ptp4l[5745.045]: config item enp5s0.ignore_source_id is 0
ptp4l[5745.045]: config item enp5s0.announceReceiptTimeout is 3
ptp4l[5745.045]: config item enp5s0.syncReceiptTimeout is 3
ptp4l[5745.045]: config item enp5s0.transportSpecific is 1
ptp4l[5745.045]: config item enp5s0.ignore_transport_specific is 0
ptp4l[5745.045]: config item enp5s0.G.8275.portDS.localPriority is 128
ptp4l[5745.045]: config item enp5s0.logSyncInterval is -3
ptp4l[5745.045]: config item enp5s0.operLogSyncInterval is 0
ptp4l[5745.045]: config item enp5s0.logMinPdelayReqInterval is 0
ptp4l[5745.045]: config item enp5s0.operLogPdelayReqInterval is 0
ptp4l[5745.045]: config item enp5s0.neighborPropDelayThresh is 800
ptp4l[5745.045]: config item enp5s0.min_neighbor_prop_delay is -20000000
ptp4l[5745.045]: config item enp5s0.asCapable is 1
ptp4l[5745.045]: config item enp5s0.inhibit_delay_req is 0
ptp4l[5745.045]: config item enp5s0.ptp_dst_mac is '01:80:C2:00:00:0E'
ptp4l[5745.045]: config item enp5s0.p2p_dst_mac is '01:80:C2:00:00:0E'
ptp4l[5745.045]: config item global.socket_priority is 0
ptp4l[5745.102]: port 1: INITIALIZING to LISTENING on INIT_COMPLETE
ptp4l[5745.102]: config item enp6s0.logMinDelayReqInterval is 0
ptp4l[5745.102]: config item enp6s0.logAnnounceInterval is 0
ptp4l[5745.102]: config item enp6s0.inhibit_announce is 0
ptp4l[5745.102]: config item enp6s0.ignore_source_id is 0
ptp4l[5745.102]: config item enp6s0.announceReceiptTimeout is 3
ptp4l[5745.102]: config item enp6s0.syncReceiptTimeout is 3
ptp4l[5745.102]: config item enp6s0.transportSpecific is 1
ptp4l[5745.102]: config item enp6s0.ignore_transport_specific is 0
ptp4l[5745.102]: config item enp6s0.G.8275.portDS.localPriority is 128
ptp4l[5745.102]: config item enp6s0.logSyncInterval is -3
ptp4l[5745.102]: config item enp6s0.operLogSyncInterval is 0
ptp4l[5745.102]: config item enp6s0.logMinPdelayReqInterval is 0
ptp4l[5745.102]: config item enp6s0.operLogPdelayReqInterval is 0
ptp4l[5745.102]: config item enp6s0.neighborPropDelayThresh is 800
ptp4l[5745.102]: config item enp6s0.min_neighbor_prop_delay is -20000000
ptp4l[5745.102]: config item enp6s0.asCapable is 1
ptp4l[5745.102]: config item enp6s0.inhibit_delay_req is 0
ptp4l[5745.103]: config item enp6s0.ptp_dst_mac is '01:80:C2:00:00:0E'
ptp4l[5745.103]: config item enp6s0.p2p_dst_mac is '01:80:C2:00:00:0E'
ptp4l[5745.103]: config item global.socket_priority is 0
ptp4l[5745.142]: port 2: INITIALIZING to LISTENING on INIT_COMPLETE
ptp4l[5745.142]: config item /var/run/ptp4l.logMinDelayReqInterval is 0
ptp4l[5745.142]: config item /var/run/ptp4l.logAnnounceInterval is 0
ptp4l[5745.142]: config item /var/run/ptp4l.inhibit_announce is 0
ptp4l[5745.142]: config item /var/run/ptp4l.ignore_source_id is 0
ptp4l[5745.142]: config item /var/run/ptp4l.announceReceiptTimeout is 0
ptp4l[5745.142]: config item /var/run/ptp4l.syncReceiptTimeout is 3
ptp4l[5745.142]: config item /var/run/ptp4l.transportSpecific is 1
ptp4l[5745.142]: config item /var/run/ptp4l.ignore_transport_specific is 0
ptp4l[5745.142]: config item /var/run/ptp4l.G.8275.portDS.localPriority is 128
ptp4l[5745.142]: config item /var/run/ptp4l.logSyncInterval is -3
ptp4l[5745.142]: config item /var/run/ptp4l.operLogSyncInterval is 0
ptp4l[5745.142]: config item /var/run/ptp4l.logMinPdelayReqInterval is 0
ptp4l[5745.142]: config item /var/run/ptp4l.operLogPdelayReqInterval is 0
ptp4l[5745.142]: config item /var/run/ptp4l.neighborPropDelayThresh is 800
ptp4l[5745.142]: config item /var/run/ptp4l.min_neighbor_prop_delay is -20000000
ptp4l[5745.142]: config item /var/run/ptp4l.asCapable is 1
ptp4l[5745.142]: config item /var/run/ptp4l.inhibit_delay_req is 0
ptp4l[5745.142]: config item (null).uds_address is '/var/run/ptp4l'
ptp4l[5745.142]: port 0: INITIALIZING to LISTENING on INIT_COMPLETE
ptp4l[5745.142]: port 1: received link status notification
ptp4l[5745.142]: interface index 5 is up
ptp4l[5745.142]: port 2: received link status notification
ptp4l[5745.143]: interface index 6 is up
ptp4l[5745.265]: port 1: peer port id set to 6cb311.fffe.52545e-1
ptp4l[5745.266]: missing timestamp on transmitted peer delay response
ptp4l[5745.266]: port 1: LISTENING to FAULTY on FAULT_DETECTED (FT_UNSPECIFIED)
ptp4l[5745.306]: waiting 2^{4} seconds to clear fault on port 1
ptp4l[5745.938]: port 2: peer port id set to 6cb311.fffe.525468-2
ptp4l[5745.939]: missing timestamp on transmitted peer delay response
ptp4l[5745.939]: port 2: LISTENING to FAULTY on FAULT_DETECTED (FT_UNSPECIFIED)
ptp4l[5745.974]: waiting 2^{4} seconds to clear fault on port 2
ptp4l[5761.306]: clearing fault on port 1
ptp4l[5761.306]: config item enp5s0.logMinDelayReqInterval is 0
ptp4l[5761.306]: config item enp5s0.logAnnounceInterval is 0
ptp4l[5761.306]: config item enp5s0.inhibit_announce is 0
ptp4l[5761.306]: config item enp5s0.ignore_source_id is 0
ptp4l[5761.306]: config item enp5s0.announceReceiptTimeout is 3
ptp4l[5761.306]: config item enp5s0.syncReceiptTimeout is 3
ptp4l[5761.306]: config item enp5s0.transportSpecific is 1
ptp4l[5761.306]: config item enp5s0.ignore_transport_specific is 0
ptp4l[5761.306]: config item enp5s0.G.8275.portDS.localPriority is 128
ptp4l[5761.306]: config item enp5s0.logSyncInterval is -3
ptp4l[5761.306]: config item enp5s0.operLogSyncInterval is 0
ptp4l[5761.306]: config item enp5s0.logMinPdelayReqInterval is 0
ptp4l[5761.306]: config item enp5s0.operLogPdelayReqInterval is 0
ptp4l[5761.306]: config item enp5s0.neighborPropDelayThresh is 800
ptp4l[5761.306]: config item enp5s0.min_neighbor_prop_delay is -20000000
ptp4l[5761.306]: config item enp5s0.asCapable is 1
ptp4l[5761.306]: config item enp5s0.inhibit_delay_req is 0
ptp4l[5761.306]: config item enp5s0.ptp_dst_mac is '01:80:C2:00:00:0E'
ptp4l[5761.306]: config item enp5s0.p2p_dst_mac is '01:80:C2:00:00:0E'
ptp4l[5761.306]: config item global.socket_priority is 0
ptp4l[5761.338]: port 1: FAULTY to LISTENING on INIT_COMPLETE
ptp4l[5761.338]: port 1: ignoring message
ptp4l[5761.338]: port 1: received link status notification
ptp4l[5761.338]: interface index 5 is up
ptp4l[5761.974]: clearing fault on port 2
ptp4l[5761.974]: config item enp6s0.logMinDelayReqInterval is 0
ptp4l[5761.974]: config item enp6s0.logAnnounceInterval is 0
ptp4l[5761.974]: config item enp6s0.inhibit_announce is 0
ptp4l[5761.974]: config item enp6s0.ignore_source_id is 0
ptp4l[5761.974]: config item enp6s0.announceReceiptTimeout is 3
ptp4l[5761.974]: config item enp6s0.syncReceiptTimeout is 3
ptp4l[5761.974]: config item enp6s0.transportSpecific is 1
ptp4l[5761.974]: config item enp6s0.ignore_transport_specific is 0
ptp4l[5761.974]: config item enp6s0.G.8275.portDS.localPriority is 128
ptp4l[5761.974]: config item enp6s0.logSyncInterval is -3
ptp4l[5761.974]: config item enp6s0.operLogSyncInterval is 0
ptp4l[5761.974]: config item enp6s0.logMinPdelayReqInterval is 0
ptp4l[5761.974]: config item enp6s0.operLogPdelayReqInterval is 0
ptp4l[5761.974]: config item enp6s0.neighborPropDelayThresh is 800
ptp4l[5761.974]: config item enp6s0.min_neighbor_prop_delay is -20000000
ptp4l[5761.974]: config item enp6s0.asCapable is 1
ptp4l[5761.974]: config item enp6s0.inhibit_delay_req is 0
ptp4l[5761.974]: config item enp6s0.ptp_dst_mac is '01:80:C2:00:00:0E'
ptp4l[5761.974]: config item enp6s0.p2p_dst_mac is '01:80:C2:00:00:0E'
ptp4l[5761.974]: config item global.socket_priority is 0
ptp4l[5762.014]: port 2: FAULTY to LISTENING on INIT_COMPLETE
ptp4l[5762.014]: port 2: ignoring message
ptp4l[5762.014]: port 2: received link status notification
ptp4l[5762.014]: interface index 6 is up
ptp4l[5762.266]: port 1: peer port id set to 6cb311.fffe.52545e-1
ptp4l[5762.266]: missing timestamp on transmitted peer delay response
ptp4l[5762.266]: port 1: LISTENING to FAULTY on FAULT_DETECTED (FT_UNSPECIFIED)
ptp4l[5762.302]: waiting 2^{4} seconds to clear fault on port 1
ptp4l[5763.003]: port 2: peer port id set to 6cb311.fffe.525468-2
ptp4l[5763.003]: missing timestamp on transmitted peer delay response
ptp4l[5763.003]: port 2: LISTENING to FAULTY on FAULT_DETECTED (FT_UNSPECIFIED)
ptp4l[5763.042]: waiting 2^{4} seconds to clear fault on port 2
ptp4l[5778.302]: clearing fault on port 1
ptp4l[5778.302]: config item enp5s0.logMinDelayReqInterval is 0
ptp4l[5778.302]: config item enp5s0.logAnnounceInterval is 0
ptp4l[5778.302]: config item enp5s0.inhibit_announce is 0
ptp4l[5778.302]: config item enp5s0.ignore_source_id is 0
ptp4l[5778.302]: config item enp5s0.announceReceiptTimeout is 3
ptp4l[5778.302]: config item enp5s0.syncReceiptTimeout is 3
ptp4l[5778.302]: config item enp5s0.transportSpecific is 1
ptp4l[5778.302]: config item enp5s0.ignore_transport_specific is 0
ptp4l[5778.302]: config item enp5s0.G.8275.portDS.localPriority is 128
ptp4l[5778.302]: config item enp5s0.logSyncInterval is -3
ptp4l[5778.302]: config item enp5s0.operLogSyncInterval is 0
ptp4l[5778.302]: config item enp5s0.logMinPdelayReqInterval is 0
ptp4l[5778.302]: config item enp5s0.operLogPdelayReqInterval is 0
ptp4l[5778.302]: config item enp5s0.neighborPropDelayThresh is 800
ptp4l[5778.302]: config item enp5s0.min_neighbor_prop_delay is -20000000
ptp4l[5778.302]: config item enp5s0.asCapable is 1
ptp4l[5778.302]: config item enp5s0.inhibit_delay_req is 0
ptp4l[5778.302]: config item enp5s0.ptp_dst_mac is '01:80:C2:00:00:0E'
ptp4l[5778.302]: config item enp5s0.p2p_dst_mac is '01:80:C2:00:00:0E'
ptp4l[5778.302]: config item global.socket_priority is 0
ptp4l[5778.342]: port 1: FAULTY to LISTENING on INIT_COMPLETE
ptp4l[5778.342]: port 1: received link status notification
ptp4l[5778.342]: interface index 5 is up
ptp4l[5779.042]: clearing fault on port 2
ptp4l[5779.042]: config item enp6s0.logMinDelayReqInterval is 0
ptp4l[5779.042]: config item enp6s0.logAnnounceInterval is 0
ptp4l[5779.042]: config item enp6s0.inhibit_announce is 0
ptp4l[5779.042]: config item enp6s0.ignore_source_id is 0
ptp4l[5779.042]: config item enp6s0.announceReceiptTimeout is 3
ptp4l[5779.042]: config item enp6s0.syncReceiptTimeout is 3
ptp4l[5779.042]: config item enp6s0.transportSpecific is 1
ptp4l[5779.042]: config item enp6s0.ignore_transport_specific is 0
ptp4l[5779.042]: config item enp6s0.G.8275.portDS.localPriority is 128
ptp4l[5779.042]: config item enp6s0.logSyncInterval is -3
ptp4l[5779.042]: config item enp6s0.operLogSyncInterval is 0
ptp4l[5779.042]: config item enp6s0.logMinPdelayReqInterval is 0
ptp4l[5779.042]: config item enp6s0.operLogPdelayReqInterval is 0
ptp4l[5779.042]: config item enp6s0.neighborPropDelayThresh is 800
ptp4l[5779.042]: config item enp6s0.min_neighbor_prop_delay is -20000000
ptp4l[5779.042]: config item enp6s0.asCapable is 1
ptp4l[5779.042]: config item enp6s0.inhibit_delay_req is 0
ptp4l[5779.042]: config item enp6s0.ptp_dst_mac is '01:80:C2:00:00:0E'
ptp4l[5779.042]: config item enp6s0.p2p_dst_mac is '01:80:C2:00:00:0E'
ptp4l[5779.042]: config item global.socket_priority is 0
ptp4l[5779.078]: port 2: FAULTY to LISTENING on INIT_COMPLETE
ptp4l[5779.078]: port 2: received link status notification
ptp4l[5779.078]: interface index 6 is up
ptp4l[5779.267]: port 1: peer port id set to 6cb311.fffe.52545e-1
ptp4l[5779.267]: missing timestamp on transmitted peer delay response
ptp4l[5779.267]: port 1: LISTENING to FAULTY on FAULT_DETECTED (FT_UNSPECIFIED)
ptp4l[5779.298]: waiting 2^{4} seconds to clear fault on port 1
ptp4l[5780.078]: port 2: delay timeout
ptp4l[5780.078]: missing timestamp on transmitted peer delay request
ptp4l[5780.078]: port 2: LISTENING to FAULTY on FAULT_DETECTED (FT_UNSPECIFIED)
ptp4l[5780.118]: waiting 2^{4} seconds to clear fault on port 2

I also modified the config to make it simpler.

 [global]
gmCapable               1
priority1               248
priority2               248
logAnnounceInterval     0
logSyncInterval         -3
syncReceiptTimeout      3
neighborPropDelayThresh 800
min_neighbor_prop_delay -20000000
assume_two_step         1
path_trace_enabled      1
follow_up_info          1
transportSpecific       0x1
ptp_dst_mac             01:80:C2:00:00:0E
network_transport       L2
delay_mechanism         P2P
tx_timestamp_timeout    100

[enp5s0]
network_transport       L2
boundary_clock_jbod     1
delay_mechanism         P2P
[enp6s0]
network_transport       L2
boundary_clock_jbod     1
delay_mechanism         P2P

Also, in comparison to the previous config, I started to see a traffic on the interfaces, so it might be a progress in the right direction. However, still not working..

vladimiroltean commented 3 years ago

ptp4l[5779.267]: missing timestamp on transmitted peer delay response

Ah! I think I know this error! What kernel do you have? Do you have this patch? https://github.com/torvalds/linux/commit/1e08511d5d01884a3c9070afd52a47799312074a

rezabfil-sec commented 3 years ago

It is Ubuntu 20.04 LTS. I think the patch should be applied based on the supported version. cat /proc/version Linux version 5.4.0-45-generic (buildd@lgw01-amd64-033) (gcc version 9.3.0 (Ubuntu 9.3.0-10ubuntu2)) #49-Ubuntu SMP Wed Aug 26 13:38:52 UTC 2020

vladimiroltean commented 3 years ago

Yes, the patch is included in v5.4.45.

Why don't you make the config even simpler? Just forget about that gPTP.cfg, run "ptp4l -i enp5s0 -2 -P -m" on the hop node and the sink, and see what it does with the taprio schedule in place. You can gradually add boundary_clock_jbod, 802.1AS, etc etc, later, once you have something that works with tc-etf enabled on the qdisc.

rezabfil-sec commented 3 years ago

Giving an update. I tried to see the behavior on a simpler setup with just two nodes and followed exactly the same configuration as provided in https://tsn.readthedocs.io/qdiscs.html#configuring-taprio-qdisc and https://tsn.readthedocs.io/timesync.html.

Unfortunately, even for that scenario the issue persists.

What worked is to not run the TAPRIO using the txtime-assist mode, which is not suitable for our scenario.

Are you able to reproduce this issue? Thank you!

tribela commented 3 years ago

I have same problem too. Any progress here?

rezabfil-sec commented 3 years ago

The problem is still present. I have tried variety of tests for a simple setup and simple ptp configuration as well as more complex solutions.

The only case where it works is for two nodes directly connected with i210 and following TAPRIO and PTP configuration:

qdisc replace dev <iface name> parent root handle 100 taprio  \
      num_tc 3                                  \
      map 2 2 1 0 2 2 2 2 2 2 2 2 2 2 2 2 \
      queues 1@0 1@1 2@2 \
      base-time 1605802187000000000          \
      sched-entry S 01 250000 \
      sched-entry S 00 50000 \
      sched-entry S 02 250000 \
      sched-entry S 00 50000 \
      sched-entry S 04 350000 \
      sched-entry S 00 50000 \
      clockid CLOCK_TAI

qdisc replace dev <iface name> parent 100:1 etf \
    clockid CLOCK_TAI delta 500000 offload  skip_sock_check

qdisc replace dev <iface name> parent 100:2 etf \
    clockid CLOCK_TAI delta 500000 offload deadline_mode skip_sock_check

ptp4l -i <iface_name> -2 -P -m

Besides, I tried the same configuration on Intel i225 and I can see the same behavior, meaning it works only with the setup above. In case I configured with the flags 0x2 for full TAPRIO offload, the PTP does not work at all.

Unfortunately, as soon as you want to have more than 2 nodes directly connected, the PTP synchronization does not work anymore.

The current solution is to use dedicated ports to run the ptp4l daemon and later synchronize the remaining clocks on the node with phc2sys. This is, of course, not optimal, as you need additional wires just to ensure clocks are synchronized, not even talking about the configuration overhead.

Hope it helps. If there are any ideas on how to debug the issue, I am open to testing it! After trying different configs, as shown in previous messages, I ran out of ideas.

tribela commented 3 years ago

After present tx_timestamp_timeout 500 to gPTP.cfg, the problem solved for me.

rezabfil-sec commented 3 years ago

Great it works for you! Could you please provide more information about your setup? E.g. how many machines, network card, and which OS and kernel version you used?

Unfortunately, for me it does not work. I had a little hope when testing it, but with closer look I realized the nodes do not communicate with each other and each selects itself as a GM.

Output of PMC, where grandmasterIdentity is different on each node. node 1:

test@node1:~# pmc -u -b 1 -t 1 "GET PARENT_DATA_SET"
sending: GET PARENT_DATA_SET
        6cb311.fffe.525490-0 seq 0 RESPONSE MANAGEMENT PARENT_DATA_SET
                parentPortIdentity                    6cb311.fffe.525498-0 
                parentStats                           0
                observedParentOffsetScaledLogVariance 0xffff
                observedParentClockPhaseChangeRate    0x7fffffff
                grandmasterPriority1                  248
                gm.ClockClass                         248
                gm.ClockAccuracy                      0xfe
                gm.OffsetScaledLogVariance            0xffff
                grandmasterPriority2                  248
                grandmasterIdentity                   6cb311.fffe.525498

Node 2:

test@node2:~# pmc -u -b 1 -t 1 "GET PARENT_DATA_SET"
sending: GET PARENT_DATA_SET
        6cb311.fffe.525490-0 seq 0 RESPONSE MANAGEMENT PARENT_DATA_SET
                parentPortIdentity                    6cb311.fffe.525490-0
                parentStats                           0
                observedParentOffsetScaledLogVariance 0xffff
                observedParentClockPhaseChangeRate    0x7fffffff
                grandmasterPriority1                  248
                gm.ClockClass                         248
                gm.ClockAccuracy                      0xfe
                gm.OffsetScaledLogVariance            0xffff
                grandmasterPriority2                  248
                grandmasterIdentity                   6cb311.fffe.525490

Thanks in advance!

ccvca commented 2 years ago

I encounter the same problem here, even using a 'passthrough configuraiton' in TAPRIO:

qdisc taprio 100: dev enp5s0 root refcnt 9 tc 3 map 0 1 2 0 1 2 0 1 2 1 2 0 1 2 0 1
queues offset 0 count 1 offset 1 count 1 offset 2 count 1
clockid TAI flags 0x1   base-time 1576540800000000000 cycle-time 500000 cycle-time-extension 0
        index 0 cmd S gatemask 0xff interval 500000

qdisc pfifo 0: dev enp5s0 parent 100:4 limit 1000p
qdisc pfifo 0: dev enp5s0 parent 100:3 limit 1000p
qdisc pfifo 0: dev enp5s0 parent 100:2 limit 1000p
qdisc pfifo 0: dev enp5s0 parent 100:1 limit 1000p
ptp4l[36243.083]: port 1: INITIALIZING to LISTENING on INIT_COMPLETE
ptp4l[36243.083]: port 0: INITIALIZING to LISTENING on INIT_COMPLETE
ptp4l[36249.346]: port 1: LISTENING to MASTER on ANNOUNCE_RECEIPT_TIMEOUT_EXPIRES
ptp4l[36249.346]: selected local clock 001b21.fffe.decffc as best master
ptp4l[36249.346]: port 1: assuming the grand master role
ptp4l[36250.346]: missing timestamp on transmitted sync
ptp4l[36250.346]: port 1: MASTER to FAULTY on FAULT_DETECTED (FT_UNSPECIFIED)

Kernel: Linux tsn 5.6.17-rt10 ptp4l -v: 3.1.1

PS: On the other side, I can see some packages:

sudo tcpdump -i enp4s0 -vv src 172.16.1.201
tcpdump: listening on enp4s0, link-type EN10MB (Ethernet), capture size 262144 bytes
13:43:15.380940 IP (tos 0x0, ttl 1, id 58927, offset 0, flags [DF], proto UDP (17), length 92)
    172.16.1.201.ptp-general > ptp-primary.mcast.net.ptp-general: [udp sum ok] UDP, length 64
13:43:16.379952 IP (tos 0x0, ttl 1, id 59044, offset 0, flags [DF], proto UDP (17), length 72)
    172.16.1.201.ptp-event > ptp-primary.mcast.net.ptp-event: [udp sum ok] UDP, length 44
13:43:16.382742 IP (tos 0xc0, ttl 1, id 0, offset 0, flags [DF], proto IGMP (2), length 48, options (RA))
    172.16.1.201 > 224.0.0.22: igmp v3 report, 2 group record(s) [gaddr ptp-primary.mcast.net to_in { }] [gaddr 224.0.0.107 to_in { }]
13:43:16.722814 IP (tos 0xc0, ttl 1, id 0, offset 0, flags [DF], proto IGMP (2), length 48, options (RA))
    172.16.1.201 > 224.0.0.22: igmp v3 report, 2 group record(s) [gaddr ptp-primary.mcast.net to_in { }] [gaddr 224.0.0.107 to_in { }]
13:43:32.384396 IP (tos 0xc0, ttl 1, id 0, offset 0, flags [DF], proto IGMP (2), length 48, options (RA))
    172.16.1.201 > 224.0.0.22: igmp v3 report, 2 group record(s) [gaddr 224.0.0.107 to_ex { }] [gaddr ptp-primary.mcast.net to_ex { }]
13:43:32.730551 IP (tos 0xc0, ttl 1, id 0, offset 0, flags [DF], proto IGMP (2), length 48, options (RA))
    172.16.1.201 > 224.0.0.22: igmp v3 report, 2 group record(s) [gaddr 224.0.0.107 to_ex { }] [gaddr ptp-primary.mcast.net to_ex { }]
13:43:39.187444 IP (tos 0x0, ttl 1, id 59222, offset 0, flags [DF], proto UDP (17), length 92)
    172.16.1.201.ptp-general > ptp-primary.mcast.net.ptp-general: [udp sum ok] UDP, length 64
13:43:40.186395 IP (tos 0x0, ttl 1, id 59740, offset 0, flags [DF], proto UDP (17), length 72)
    172.16.1.201.ptp-event > ptp-primary.mcast.net.ptp-event: [udp sum ok] UDP, length 44
13:43:40.189331 IP (tos 0xc0, ttl 1, id 0, offset 0, flags [DF], proto IGMP (2), length 48, options (RA))
    172.16.1.201 > 224.0.0.22: igmp v3 report, 2 group record(s) [gaddr ptp-primary.mcast.net to_in { }] [gaddr 224.0.0.107 to_in { }]
13:43:40.230439 IP (tos 0xc0, ttl 1, id 0, offset 0, flags [DF], proto IGMP (2), length 48, options (RA))
    172.16.1.201 > 224.0.0.22: igmp v3 report, 2 group record(s) [gaddr ptp-primary.mcast.net to_in { }] [gaddr 224.0.0.107 to_in { }]
13:43:56.190056 IP (tos 0xc0, ttl 1, id 0, offset 0, flags [DF], proto IGMP (2), length 48, options (RA))
    172.16.1.201 > 224.0.0.22: igmp v3 report, 2 group record(s) [gaddr 224.0.0.107 to_ex { }] [gaddr ptp-primary.mcast.net to_ex { }]
13:43:56.706124 IP (tos 0xc0, ttl 1, id 0, offset 0, flags [DF], proto IGMP (2), length 48, options (RA))
    172.16.1.201 > 224.0.0.22: igmp v3 report, 2 group record(s) [gaddr 224.0.0.107 to_ex { }] [gaddr ptp-primary.mcast.net to_ex { }]
ccvca commented 2 years ago

It looks like in my case, the problem is related to the flags 0x01. If I configure it without the flags parameter, it works.

rezabfil-sec commented 2 years ago

@ccvca How many hops and bridges do you have in your setup? For me the flags 0x1 solved it for 1 hop (directly connected nodes), but once more hops are present the issue is still present. Thanks!

ccvca commented 2 years ago

I do also have a direct Connection between two PCs. No Switches involved.