Avnu / tsn-doc

Documentation on TSN Linux components, interfaces and usage
BSD 3-Clause "New" or "Revised" License
40 stars 20 forks source link

phc2sys stucks in "Waiting for ptp4l..." #21

Closed elabbing closed 6 months ago

elabbing commented 3 years ago

Hello, I have a host PC as follow with Intel i210 adapter:

@ubuntu:~$ uname -a
Linux ubuntu 5.4.0-48-generic #52~18.04.1-Ubuntu

I follow tsn-doc tutorial, setting-up vlan, disabling network manager for pointed device, disabling NTP, etc. then using:

art@ubuntu:~$ sudo ptp4l -i enp1s0 -f configs/gPTP.cfg --step_threshold=1 -m
[sudo] password di art: 
ptp4l[5663.757]: selected /dev/ptp0 as PTP clock
ptp4l[5663.788]: port 1: INITIALIZING to LISTENING on INIT_COMPLETE
ptp4l[5663.788]: port 0: INITIALIZING to LISTENING on INIT_COMPLETE
ptp4l[5663.788]: port 1: link down
ptp4l[5663.788]: port 1: LISTENING to FAULTY on FAULT_DETECTED (FT_UNSPECIFIED)
ptp4l[5663.819]: selected local clock 6cb311.fffe.523b81 as best master
ptp4l[5663.819]: port 1: assuming the grand master role
ptp4l[5692.030]: selected local clock 6cb311.fffe.523b81 as best master
ptp4l[5692.030]: port 1: assuming the grand master role
art@ubuntu:~$ sudo pmc -u -b 0 -t 1 "SET GRANDMASTER_SETTINGS_NP clockClass 248 clockAccuracy 0xfe offsetScaledLogVariance 0xffff currentUtcOffset 37 leap61 0 leap59 0 currentUtcOffsetValid 1 ptpTimescale 1 timeTraceable 1 frequencyTraceable 0 timeSource 0xa0"
sending: SET GRANDMASTER_SETTINGS_NP
    6cb311.fffe.523b81-0 seq 0 RESPONSE MANAGEMENT GRANDMASTER_SETTINGS_NP 
        clockClass              248
        clockAccuracy           0xfe
        offsetScaledLogVariance 0xffff
        currentUtcOffset        37
        leap61                  0
        leap59                  0
        currentUtcOffsetValid   1
        ptpTimescale            1
        timeTraceable           1
        frequencyTraceable      0
        timeSource              0xa0
art@ubuntu:~$ sudo phc2sys -w -m -s enp1s0 -c CLOCK_REALTIME --step_threshold=1 –transportSpecific=1
phc2sys[1374.742]: Waiting for ptp4l...
phc2sys[1375.743]: Waiting for ptp4l...
phc2sys[1376.743]: Waiting for ptp4l...
...

phc2sys never syncs. If I run sudo ptp4l -i enp1s0 --step_threshold=1 -m

it seems to work, but clock_check gives system is not syncronized:

phc-rt delta is not 37 sec !
phc-tai delta is greater than 50 usec !
TAI offset set in kernel is not correct !
Please verify ptp4l and phc config and restart them if necessary to synchronize the clocks !

Any hints, please? Thanks a lot

edersondisouza commented 3 years ago

Hi @elabbing,

Is the i210 interface up? Is it connected to something? What does ip link show enp1s0 show? Another hint is that you can use -l [num] to make the output of phc2sys/ptp4l more verbose - 7 is the most verbose.

elabbing commented 3 years ago

Thank you Ederson. Hereip link output:


1: lo: <LOOPBACK,UP,LOWER_UP> mtu 65536 qdisc noqueue state UNKNOWN mode DEFAULT group default qlen 1000
    link/loopback 00:00:00:00:00:00 brd 00:00:00:00:00:00
2: enp1s0: <NO-CARRIER,BROADCAST,MULTICAST,UP> mtu 1500 qdisc mq state DOWN mode DEFAULT group default qlen 1000
    link/ether 6c:b3:11:52:3b:81 brd ff:ff:ff:ff:ff:ff
3: enp0s25: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc fq_codel state UP mode DEFAULT group default qlen 1000
    link/ether 00:19:99:85:71:3a brd ff:ff:ff:ff:ff:ff
4: enp1s0.5@enp1s0: <NO-CARRIER,BROADCAST,MULTICAST,UP> mtu 1500 qdisc noqueue state LOWERLAYERDOWN mode DEFAULT group default qlen 1000
    link/ether 6c:b3:11:52:3b:81 brd ff:ff:ff:ff:ff:ff

Here ptp4l and phc2sys output, running in 2 different shell (terminal emulator):

sudo ptp4l -i enp1s0 -f configs/gPTP.cfg --step_threshold=1 -m
ptp4l[2762.729]: selected /dev/ptp0 as PTP clock
ptp4l[2762.768]: port 1: INITIALIZING to LISTENING on INIT_COMPLETE
ptp4l[2762.768]: port 0: INITIALIZING to LISTENING on INIT_COMPLETE
ptp4l[2762.768]: port 1: link down
ptp4l[2762.768]: port 1: LISTENING to FAULTY on FAULT_DETECTED (FT_UNSPECIFIED)
ptp4l[2762.796]: selected local clock 6cb311.fffe.523b81 as best master
ptp4l[2762.796]: port 1: assuming the grand master role
sudo phc2sys -w -m -s enp1s0 -c CLOCK_REALTIME --step_threshold=1 –transportSpecific=1 -l 7
phc2sys[3057.535]: config item (null).clock_servo is 0
phc2sys[3057.535]: config item (null).kernel_leap is 1
phc2sys[3057.535]: config item (null).sanity_freq_limit is 200000000
phc2sys[3057.535]: config item (null).pi_proportional_const is 0.700000
phc2sys[3057.535]: config item (null).pi_integral_const is 0.300000
phc2sys[3057.535]: config item (null).pi_proportional_scale is 0.000000
phc2sys[3057.535]: config item (null).pi_proportional_exponent is -0.300000
phc2sys[3057.535]: config item (null).pi_proportional_norm_max is 0.700000
phc2sys[3057.535]: config item (null).pi_integral_scale is 0.000000
phc2sys[3057.535]: config item (null).pi_integral_exponent is 0.400000
phc2sys[3057.535]: config item (null).pi_integral_norm_max is 0.300000
phc2sys[3057.535]: config item (null).step_threshold is 1.000000
phc2sys[3057.535]: config item (null).first_step_threshold is 0.000020
phc2sys[3057.535]: config item (null).max_frequency is 900000000
phc2sys[3057.535]: config item (null).servo_offset_threshold is 0
phc2sys[3057.535]: config item (null).servo_num_offset_values is 10
phc2sys[3057.535]: PI servo: sync interval 1.000 kp 0.700 ki 0.300000
phc2sys[3057.535]: ioctl PTP_SYS_OFFSET_PRECISE: Operation not supported
phc2sys[3057.535]: config item (null).pi_proportional_const is 0.700000
phc2sys[3057.535]: config item (null).pi_integral_const is 0.300000
phc2sys[3057.535]: config item (null).pi_proportional_scale is 0.000000
phc2sys[3057.535]: config item (null).pi_proportional_exponent is -0.300000
phc2sys[3057.535]: config item (null).pi_proportional_norm_max is 0.700000
phc2sys[3057.535]: config item (null).pi_integral_scale is 0.000000
phc2sys[3057.535]: config item (null).pi_integral_exponent is 0.400000
phc2sys[3057.535]: config item (null).pi_integral_norm_max is 0.300000
phc2sys[3057.535]: config item (null).step_threshold is 1.000000
phc2sys[3057.535]: config item (null).first_step_threshold is 0.000020
phc2sys[3057.536]: config item (null).max_frequency is 900000000
phc2sys[3057.536]: config item (null).servo_offset_threshold is 0
phc2sys[3057.536]: config item (null).servo_num_offset_values is 10
phc2sys[3057.536]: PI servo: sync interval 1.000 kp 0.700 ki 0.300000
phc2sys[3057.536]: config item (null).transportSpecific is 0
phc2sys[3057.536]: config item (null).domainNumber is 0
phc2sys[3057.536]: config item (null).uds_address is '/var/run/ptp4l'
phc2sys[3058.537]: Waiting for ptp4l...
phc2sys[3059.538]: Waiting for ptp4l...
phc2sys[3060.539]: Waiting for ptp4l...

I 'm following TSN-doc obviously.

Maybe it's mandatory using igb-avb driver, instead of igb standard driver? Thanks a lot for your help

edersondisouza commented 3 years ago

Hi @elabbing,

It appears that the network interface is actually down, from this:

enp1s0: <NO-CARRIER,BROADCAST,MULTICAST,UP> mtu 1500 qdisc mq state DOWN mode DEFAULT group default qlen 1000

Is the interface connected to a switch or another machine? I'd suggest to connect it, so that ptp4l startup can complete and phc2sys connect to ptp4l.

And no, there's no need for the igb-avb driver.

elabbing commented 3 years ago

I run some test with 2 PC linked back to back. First test with any config file, second one using config file gPTP.cfg.

Test without config file goes straight, but it needs link up in order to phc2sys starts to sync. After sync , if disconnect ethernet cable phc2sys seems to go on normally.

Test with gPTP.cfg doesn't work.

Here output, if could help to solve. Many thanks

sudo ptp4l -i enp1s0 -m -l 7

ptp4l[23102.807]: config item (null).assume_two_step is 0
ptp4l[23102.807]: config item (null).check_fup_sync is 0
ptp4l[23102.807]: config item (null).tx_timestamp_timeout is 1
ptp4l[23102.807]: config item (null).hwts_filter is 0
ptp4l[23102.807]: config item (null).clock_servo is 0
ptp4l[23102.807]: config item (null).clock_type is 32768
ptp4l[23102.807]: config item (null).clock_servo is 0
ptp4l[23102.807]: config item (null).clockClass is 248
ptp4l[23102.807]: config item (null).clockAccuracy is 254
ptp4l[23102.807]: config item (null).offsetScaledLogVariance is 65535
ptp4l[23102.807]: config item (null).productDescription is ';;'
ptp4l[23102.807]: config item (null).revisionData is ';;'
ptp4l[23102.807]: config item (null).userDescription is ''
ptp4l[23102.807]: config item (null).manufacturerIdentity is '00:00:00'
ptp4l[23102.807]: config item (null).domainNumber is 0
ptp4l[23102.807]: config item (null).slaveOnly is 0
ptp4l[23102.807]: config item (null).gmCapable is 1
ptp4l[23102.807]: config item (null).gmCapable is 1
ptp4l[23102.807]: config item (null).G.8275.defaultDS.localPriority is 128
ptp4l[23102.807]: config item (null).maxStepsRemoved is 255
ptp4l[23102.807]: config item (null).time_stamping is 1
ptp4l[23102.808]: config item (null).twoStepFlag is 1
ptp4l[23102.808]: config item (null).twoStepFlag is 1
ptp4l[23102.808]: config item (null).time_stamping is 1
ptp4l[23102.808]: config item (null).priority1 is 128
ptp4l[23102.808]: config item (null).priority2 is 128
ptp4l[23102.808]: interface index 2 is up
ptp4l[23102.808]: config item (null).free_running is 0
ptp4l[23102.808]: selected /dev/ptp0 as PTP clock
ptp4l[23102.808]: config item (null).clockIdentity is '000000.0000.000000'
ptp4l[23102.808]: config item (null).uds_address is '/var/run/ptp4l'
ptp4l[23102.808]: section item /var/run/ptp4l.announceReceiptTimeout now 0
ptp4l[23102.808]: section item /var/run/ptp4l.delay_mechanism now 0
ptp4l[23102.808]: section item /var/run/ptp4l.network_transport now 0
ptp4l[23102.808]: section item /var/run/ptp4l.delay_filter_length now 1
ptp4l[23102.808]: config item (null).free_running is 0
ptp4l[23102.808]: config item (null).freq_est_interval is 1
ptp4l[23102.808]: config item (null).gmCapable is 1
ptp4l[23102.808]: config item (null).kernel_leap is 1
ptp4l[23102.808]: config item (null).utc_offset is 37
ptp4l[23102.808]: config item (null).timeSource is 160
ptp4l[23102.808]: config item (null).pi_proportional_const is 0.000000
ptp4l[23102.808]: config item (null).pi_integral_const is 0.000000
ptp4l[23102.808]: config item (null).pi_proportional_scale is 0.000000
ptp4l[23102.808]: config item (null).pi_proportional_exponent is -0.300000
ptp4l[23102.808]: config item (null).pi_proportional_norm_max is 0.700000
ptp4l[23102.808]: config item (null).pi_integral_scale is 0.000000
ptp4l[23102.808]: config item (null).pi_integral_exponent is 0.400000
ptp4l[23102.808]: config item (null).pi_integral_norm_max is 0.300000
ptp4l[23102.808]: config item (null).step_threshold is 0.000000
ptp4l[23102.808]: config item (null).first_step_threshold is 0.000020
ptp4l[23102.808]: config item (null).max_frequency is 900000000
ptp4l[23102.808]: config item (null).servo_offset_threshold is 0
ptp4l[23102.808]: config item (null).servo_num_offset_values is 10
ptp4l[23102.808]: config item (null).dataset_comparison is 0
ptp4l[23102.808]: config item (null).delay_filter_length is 10
ptp4l[23102.808]: config item (null).delay_filter is 1
ptp4l[23102.808]: config item (null).tsproc_mode is 0
ptp4l[23102.808]: config item (null).initial_delay is 0
ptp4l[23102.808]: config item (null).summary_interval is 0
ptp4l[23102.808]: config item (null).sanity_freq_limit is 200000000
ptp4l[23102.808]: PI servo: sync interval 1.000 kp 0.700 ki 0.300000
ptp4l[23102.808]: config item /var/run/ptp4l.boundary_clock_jbod is 0
ptp4l[23102.808]: config item /var/run/ptp4l.network_transport is 0
ptp4l[23102.808]: config item /var/run/ptp4l.masterOnly is 0
ptp4l[23102.809]: config item /var/run/ptp4l.BMCA is 0
ptp4l[23102.809]: config item /var/run/ptp4l.delayAsymmetry is 0
ptp4l[23102.809]: config item /var/run/ptp4l.follow_up_info is 0
ptp4l[23102.809]: config item /var/run/ptp4l.freq_est_interval is 1
ptp4l[23102.809]: config item /var/run/ptp4l.net_sync_monitor is 0
ptp4l[23102.809]: config item /var/run/ptp4l.path_trace_enabled is 0
ptp4l[23102.809]: config item /var/run/ptp4l.tc_spanning_tree is 0
ptp4l[23102.809]: config item /var/run/ptp4l.ingressLatency is 0
ptp4l[23102.809]: config item /var/run/ptp4l.egressLatency is 0
ptp4l[23102.809]: config item /var/run/ptp4l.delay_mechanism is 0
ptp4l[23102.809]: config item /var/run/ptp4l.hybrid_e2e is 0
ptp4l[23102.809]: config item /var/run/ptp4l.fault_badpeernet_interval is 16
ptp4l[23102.809]: config item /var/run/ptp4l.fault_reset_interval is 4
ptp4l[23102.809]: config item /var/run/ptp4l.delay_filter_length is 1
ptp4l[23102.809]: config item /var/run/ptp4l.delay_filter is 1
ptp4l[23102.809]: config item /var/run/ptp4l.tsproc_mode is 0
ptp4l[23102.809]: config item enp1s0.boundary_clock_jbod is 0
ptp4l[23102.809]: config item enp1s0.network_transport is 1
ptp4l[23102.809]: config item enp1s0.masterOnly is 0
ptp4l[23102.809]: config item enp1s0.BMCA is 0
ptp4l[23102.809]: config item enp1s0.delayAsymmetry is 0
ptp4l[23102.809]: config item enp1s0.follow_up_info is 0
ptp4l[23102.809]: config item enp1s0.freq_est_interval is 1
ptp4l[23102.809]: config item enp1s0.net_sync_monitor is 0
ptp4l[23102.809]: config item enp1s0.path_trace_enabled is 0
ptp4l[23102.809]: config item enp1s0.tc_spanning_tree is 0
ptp4l[23102.809]: config item enp1s0.ingressLatency is 0
ptp4l[23102.809]: config item enp1s0.egressLatency is 0
ptp4l[23102.809]: config item enp1s0.delay_mechanism is 1
ptp4l[23102.809]: config item enp1s0.unicast_master_table is 0
ptp4l[23102.809]: config item enp1s0.unicast_listen is 0
ptp4l[23102.809]: config item enp1s0.hybrid_e2e is 0
ptp4l[23102.809]: config item enp1s0.fault_badpeernet_interval is 16
ptp4l[23102.809]: config item enp1s0.fault_reset_interval is 4
ptp4l[23102.809]: config item enp1s0.delay_filter_length is 10
ptp4l[23102.809]: config item enp1s0.delay_filter is 1
ptp4l[23102.810]: config item enp1s0.tsproc_mode is 0
ptp4l[23102.810]: config item enp1s0.logMinDelayReqInterval is 0
ptp4l[23102.810]: config item enp1s0.logAnnounceInterval is 1
ptp4l[23102.810]: config item enp1s0.inhibit_announce is 0
ptp4l[23102.810]: config item enp1s0.ignore_source_id is 0
ptp4l[23102.810]: config item enp1s0.announceReceiptTimeout is 3
ptp4l[23102.810]: config item enp1s0.syncReceiptTimeout is 0
ptp4l[23102.810]: config item enp1s0.transportSpecific is 0
ptp4l[23102.810]: config item enp1s0.ignore_transport_specific is 0
ptp4l[23102.810]: config item enp1s0.G.8275.portDS.localPriority is 128
ptp4l[23102.810]: config item enp1s0.logSyncInterval is 0
ptp4l[23102.810]: config item enp1s0.operLogSyncInterval is 0
ptp4l[23102.810]: config item enp1s0.logMinPdelayReqInterval is 0
ptp4l[23102.810]: config item enp1s0.operLogPdelayReqInterval is 0
ptp4l[23102.810]: config item enp1s0.neighborPropDelayThresh is 20000000
ptp4l[23102.810]: config item enp1s0.min_neighbor_prop_delay is -20000000
ptp4l[23102.810]: config item enp1s0.asCapable is 1
ptp4l[23102.810]: config item enp1s0.inhibit_delay_req is 0
ptp4l[23102.810]: config item enp1s0.udp_ttl is 1
ptp4l[23102.810]: config item (null).dscp_event is 0
ptp4l[23102.810]: config item (null).dscp_general is 0
ptp4l[23102.811]: port 1: INITIALIZING to LISTENING on INIT_COMPLETE
ptp4l[23102.811]: config item /var/run/ptp4l.logMinDelayReqInterval is 0
ptp4l[23102.811]: config item /var/run/ptp4l.logAnnounceInterval is 1
ptp4l[23102.811]: config item /var/run/ptp4l.inhibit_announce is 0
ptp4l[23102.811]: config item /var/run/ptp4l.ignore_source_id is 0
ptp4l[23102.811]: config item /var/run/ptp4l.announceReceiptTimeout is 0
ptp4l[23102.811]: config item /var/run/ptp4l.syncReceiptTimeout is 0
ptp4l[23102.811]: config item /var/run/ptp4l.transportSpecific is 0
ptp4l[23102.811]: config item /var/run/ptp4l.ignore_transport_specific is 0
ptp4l[23102.811]: config item /var/run/ptp4l.G.8275.portDS.localPriority is 128
ptp4l[23102.811]: config item /var/run/ptp4l.logSyncInterval is 0
ptp4l[23102.811]: config item /var/run/ptp4l.operLogSyncInterval is 0
ptp4l[23102.811]: config item /var/run/ptp4l.logMinPdelayReqInterval is 0
ptp4l[23102.811]: config item /var/run/ptp4l.operLogPdelayReqInterval is 0
ptp4l[23102.811]: config item /var/run/ptp4l.neighborPropDelayThresh is 20000000
ptp4l[23102.811]: config item /var/run/ptp4l.min_neighbor_prop_delay is -20000000
ptp4l[23102.811]: config item /var/run/ptp4l.asCapable is 1
ptp4l[23102.811]: config item /var/run/ptp4l.inhibit_delay_req is 0
ptp4l[23102.811]: config item (null).uds_address is '/var/run/ptp4l'
ptp4l[23102.811]: port 0: INITIALIZING to LISTENING on INIT_COMPLETE
ptp4l[23102.811]: port 1: received link status notification
ptp4l[23102.811]: interface index 2 is up
ptp4l[23109.825]: port 1: announce timeout
ptp4l[23109.825]: port 1: LISTENING to MASTER on ANNOUNCE_RECEIPT_TIMEOUT_EXPIRES
ptp4l[23109.825]: selected local clock 6cb311.fffe.523b81 as best master
ptp4l[23109.825]: port 1: assuming the grand master role
ptp4l[23109.826]: port 1: master tx announce timeout
ptp4l[23109.826]: port 1: setting asCapable
ptp4l[23110.825]: port 1: master sync timeout
ptp4l[23111.330]: port 0: setting asCapable
ptp4l[23111.826]: port 1: master sync timeout
ptp4l[23111.827]: port 1: master tx announce timeout
...

...
ptp4l[23132.832]: port 1: master sync timeout
ptp4l[23132.833]: timed out while polling for tx timestamp
ptp4l[23132.833]: increasing tx_timestamp_timeout may correct this issue, but it is likely caused by a driver bug
ptp4l[23132.833]: port 1: send sync failed
ptp4l[23132.833]: port 1: MASTER to FAULTY on FAULT_DETECTED (FT_UNSPECIFIED)
ptp4l[23132.834]: waiting 2^{4} seconds to clear fault on port 1
ptp4l[23148.834]: clearing fault on port 1
ptp4l[23148.834]: config item enp1s0.logMinDelayReqInterval is 0
ptp4l[23148.834]: config item enp1s0.logAnnounceInterval is 1
ptp4l[23148.834]: config item enp1s0.inhibit_announce is 0
ptp4l[23148.834]: config item enp1s0.ignore_source_id is 0
ptp4l[23148.834]: config item enp1s0.announceReceiptTimeout is 3
ptp4l[23148.834]: config item enp1s0.syncReceiptTimeout is 0
ptp4l[23148.834]: config item enp1s0.transportSpecific is 0
ptp4l[23148.834]: config item enp1s0.ignore_transport_specific is 0
ptp4l[23148.834]: config item enp1s0.G.8275.portDS.localPriority is 128
ptp4l[23148.834]: config item enp1s0.logSyncInterval is 0
ptp4l[23148.834]: config item enp1s0.operLogSyncInterval is 0
ptp4l[23148.834]: config item enp1s0.logMinPdelayReqInterval is 0
ptp4l[23148.834]: config item enp1s0.operLogPdelayReqInterval is 0
ptp4l[23148.834]: config item enp1s0.neighborPropDelayThresh is 20000000
ptp4l[23148.834]: config item enp1s0.min_neighbor_prop_delay is -20000000
ptp4l[23148.834]: config item enp1s0.asCapable is 1
ptp4l[23148.834]: config item enp1s0.inhibit_delay_req is 0
ptp4l[23148.834]: config item enp1s0.udp_ttl is 1
ptp4l[23148.835]: config item (null).dscp_event is 0
ptp4l[23148.835]: config item (null).dscp_general is 0
ptp4l[23148.835]: port 1: FAULTY to LISTENING on INIT_COMPLETE
ptp4l[23148.835]: port 1: received link status notification
ptp4l[23148.835]: interface index 2 is up
ptp4l[23156.272]: port 1: announce timeout
ptp4l[23156.272]: port 1: LISTENING to MASTER on ANNOUNCE_RECEIPT_TIMEOUT_EXPIRES
ptp4l[23156.272]: selected local clock 6cb311.fffe.523b81 as best master
ptp4l[23156.272]: port 1: assuming the grand master role
ptp4l[23156.273]: port 1: master tx announce timeout
ptp4l[23156.273]: port 1: setting asCapable
ptp4l[23157.273]: port 1: master sync timeout
ptp4l[23158.273]: port 1: master sync timeout
ptp4l[23158.274]: port 1: master tx announce timeout
ptp4l[23159.273]: port 1: master sync timeout
ptp4l[23160.274]: port 1: master sync timeout
ptp4l[23160.275]: port 1: master tx announce timeout
ptp4l[23161.274]: port 1: master sync timeout
ptp4l[23162.275]: port 1: master sync timeout
ptp4l[23162.276]: port 1: master tx announce timeout
ptp4l[23163.275]: port 1: master sync timeout
ptp4l[23163.276]: timed out while polling for tx timestamp
ptp4l[23163.276]: increasing tx_timestamp_timeout may correct this issue, but it is likely caused by a driver bug
ptp4l[23163.276]: port 1: send sync failed
ptp4l[23163.276]: port 1: MASTER to FAULTY on FAULT_DETECTED (FT_UNSPECIFIED)
ptp4l[23163.276]: waiting 2^{4} seconds to clear fault on port 1
ptp4l[23179.276]: clearing fault on port 1
ptp4l[23179.277]: config item enp1s0.logMinDelayReqInterval is 0
ptp4l[23179.277]: config item enp1s0.logAnnounceInterval is 1
ptp4l[23179.277]: config item enp1s0.inhibit_announce is 0
ptp4l[23179.277]: config item enp1s0.ignore_source_id is 0
ptp4l[23179.277]: config item enp1s0.announceReceiptTimeout is 3
ptp4l[23179.277]: config item enp1s0.syncReceiptTimeout is 0
ptp4l[23179.277]: config item enp1s0.transportSpecific is 0
ptp4l[23179.277]: config item enp1s0.ignore_transport_specific is 0
ptp4l[23179.277]: config item enp1s0.G.8275.portDS.localPriority is 128
ptp4l[23179.277]: config item enp1s0.logSyncInterval is 0
ptp4l[23179.277]: config item enp1s0.operLogSyncInterval is 0
ptp4l[23179.277]: config item enp1s0.logMinPdelayReqInterval is 0
ptp4l[23179.277]: config item enp1s0.operLogPdelayReqInterval is 0
ptp4l[23179.277]: config item enp1s0.neighborPropDelayThresh is 20000000
ptp4l[23179.277]: config item enp1s0.min_neighbor_prop_delay is -20000000
ptp4l[23179.277]: config item enp1s0.asCapable is 1
ptp4l[23179.277]: config item enp1s0.inhibit_delay_req is 0
ptp4l[23179.277]: config item enp1s0.udp_ttl is 1
ptp4l[23179.277]: config item (null).dscp_event is 0
ptp4l[23179.277]: config item (null).dscp_general is 0
ptp4l[23179.278]: port 1: FAULTY to LISTENING on INIT_COMPLETE
ptp4l[23179.278]: port 1: received link status notification
ptp4l[23179.278]: interface index 2 is up
ptp4l[23185.738]: port 1: announce timeout
ptp4l[23185.738]: port 1: LISTENING to MASTER on ANNOUNCE_RECEIPT_TIMEOUT_EXPIRES
ptp4l[23185.738]: selected local clock 6cb311.fffe.523b81 as best master
ptp4l[23185.738]: port 1: assuming the grand master role
ptp4l[23185.739]: port 1: master tx announce timeout
ptp4l[23185.739]: port 1: setting asCapable
ptp4l[23186.738]: port 1: master sync timeout
ptp4l[23187.738]: port 1: master sync timeout
ptp4l[23187.739]: port 1: master tx announce timeout
...
sudo phc2sys -w -m -s enp1s0 -c CLOCK_REALTIME --step_threshold=1 –transportSpecific=1 -l 7

...
...
phc2sys[23111.330]: config item (null).uds_address is '/var/run/ptp4l'
phc2sys[23112.331]: CLOCK_REALTIME phc offset    148816 s0 freq +18810889 delay   5002
phc2sys[23113.331]: CLOCK_REALTIME phc offset    148836 s1 freq +18810909 delay   4865
phc2sys[23114.331]: CLOCK_REALTIME phc offset         6 s2 freq +18810915 delay   4797
phc2sys[23115.331]: CLOCK_REALTIME phc offset       109 s2 freq +18811019 delay   4797
phc2sys[23116.332]: CLOCK_REALTIME phc offset        32 s2 freq +18810975 delay   4865
phc2sys[23117.332]: CLOCK_REALTIME phc offset        12 s2 freq +18810965 delay   4865
phc2sys[23118.332]: CLOCK_REALTIME phc offset        61 s2 freq +18811017 delay   4865
phc2sys[23119.333]: CLOCK_REALTIME phc offset        10 s2 freq +18810985 delay   4797
phc2sys[23120.333]: CLOCK_REALTIME phc offset       -41 s2 freq +18810937 delay   4865
phc2sys[23121.333]: CLOCK_REALTIME phc offset       -95 s2 freq +18810870 delay   4865
phc2sys[23122.333]: CLOCK_REALTIME phc offset        17 s2 freq +18810954 delay   4865
phc2sys[23123.333]: CLOCK_REALTIME phc offset       -12 s2 freq +18810930 delay   4865
phc2sys[23124.334]: CLOCK_REALTIME phc offset        35 s2 freq +18810973 delay   4865
phc2sys[23125.334]: CLOCK_REALTIME phc offset        -4 s2 freq +18810945 delay   4865
phc2sys[23126.334]: CLOCK_REALTIME phc offset        17 s2 freq +18810965 delay   4797
phc2sys[23127.334]: CLOCK_REALTIME phc offset         5 s2 freq +18810958 delay   4728
...

Second test with config file gPTP.cfg :


sudo ptp4l -i enp1s0 -f configs/gPTP.cfg –step_threshold=1 -m -l 7

ptp4l[22173.735]: config item (null).assume_two_step is 1
ptp4l[22173.735]: config item (null).check_fup_sync is 0
ptp4l[22173.735]: config item (null).tx_timestamp_timeout is 1
ptp4l[22173.735]: config item (null).hwts_filter is 0
ptp4l[22173.735]: config item (null).clock_servo is 0
ptp4l[22173.735]: config item (null).clock_type is 32768
ptp4l[22173.735]: config item (null).clock_servo is 0
ptp4l[22173.735]: config item (null).clockClass is 248
ptp4l[22173.735]: config item (null).clockAccuracy is 254
ptp4l[22173.735]: config item (null).offsetScaledLogVariance is 65535
ptp4l[22173.735]: config item (null).productDescription is ';;'
ptp4l[22173.735]: config item (null).revisionData is ';;'
ptp4l[22173.735]: config item (null).userDescription is ''
ptp4l[22173.735]: config item (null).manufacturerIdentity is '00:00:00'
ptp4l[22173.735]: config item (null).domainNumber is 0
ptp4l[22173.735]: config item (null).slaveOnly is 0
ptp4l[22173.735]: config item (null).gmCapable is 1
ptp4l[22173.735]: config item (null).gmCapable is 1
ptp4l[22173.735]: config item (null).G.8275.defaultDS.localPriority is 128
ptp4l[22173.735]: config item (null).maxStepsRemoved is 255
ptp4l[22173.735]: config item (null).time_stamping is 1
ptp4l[22173.735]: config item (null).twoStepFlag is 1
ptp4l[22173.735]: config item (null).twoStepFlag is 1
ptp4l[22173.735]: config item (null).time_stamping is 1
ptp4l[22173.735]: config item (null).priority1 is 248
ptp4l[22173.735]: config item (null).priority2 is 248
ptp4l[22173.736]: interface index 2 is up
ptp4l[22173.736]: config item (null).free_running is 0
ptp4l[22173.736]: selected /dev/ptp0 as PTP clock
ptp4l[22173.736]: config item (null).clockIdentity is '000000.0000.000000'
ptp4l[22173.736]: config item (null).uds_address is '/var/run/ptp4l'
ptp4l[22173.736]: section item /var/run/ptp4l.announceReceiptTimeout now 0
ptp4l[22173.736]: section item /var/run/ptp4l.delay_mechanism now 0
ptp4l[22173.736]: section item /var/run/ptp4l.network_transport now 0
ptp4l[22173.736]: section item /var/run/ptp4l.delay_filter_length now 1
ptp4l[22173.736]: config item (null).free_running is 0
ptp4l[22173.736]: config item (null).freq_est_interval is 1
ptp4l[22173.736]: config item (null).gmCapable is 1
ptp4l[22173.736]: config item (null).kernel_leap is 1
ptp4l[22173.736]: config item (null).utc_offset is 37
ptp4l[22173.736]: config item (null).timeSource is 160
ptp4l[22173.736]: config item (null).pi_proportional_const is 0.000000
ptp4l[22173.736]: config item (null).pi_integral_const is 0.000000
ptp4l[22173.736]: config item (null).pi_proportional_scale is 0.000000
ptp4l[22173.736]: config item (null).pi_proportional_exponent is -0.300000
ptp4l[22173.736]: config item (null).pi_proportional_norm_max is 0.700000
ptp4l[22173.736]: config item (null).pi_integral_scale is 0.000000
ptp4l[22173.736]: config item (null).pi_integral_exponent is 0.400000
ptp4l[22173.736]: config item (null).pi_integral_norm_max is 0.300000
ptp4l[22173.736]: config item (null).step_threshold is 1.000000
ptp4l[22173.736]: config item (null).first_step_threshold is 0.000020
ptp4l[22173.736]: config item (null).max_frequency is 900000000
ptp4l[22173.736]: config item (null).servo_offset_threshold is 0
ptp4l[22173.736]: config item (null).servo_num_offset_values is 10
ptp4l[22173.736]: config item (null).dataset_comparison is 0
ptp4l[22173.736]: config item (null).delay_filter_length is 10
ptp4l[22173.736]: config item (null).delay_filter is 1
ptp4l[22173.736]: config item (null).tsproc_mode is 0
ptp4l[22173.736]: config item (null).initial_delay is 0
ptp4l[22173.736]: config item (null).summary_interval is 0
ptp4l[22173.736]: config item (null).sanity_freq_limit is 200000000
ptp4l[22173.736]: PI servo: sync interval 1.000 kp 0.700 ki 0.300000
ptp4l[22173.736]: config item /var/run/ptp4l.boundary_clock_jbod is 0
ptp4l[22173.736]: config item /var/run/ptp4l.network_transport is 0
ptp4l[22173.736]: config item /var/run/ptp4l.masterOnly is 0
ptp4l[22173.736]: config item /var/run/ptp4l.BMCA is 0
ptp4l[22173.736]: config item /var/run/ptp4l.delayAsymmetry is 0
ptp4l[22173.736]: config item /var/run/ptp4l.follow_up_info is 1
ptp4l[22173.736]: config item /var/run/ptp4l.freq_est_interval is 1
ptp4l[22173.736]: config item /var/run/ptp4l.net_sync_monitor is 0
ptp4l[22173.736]: config item /var/run/ptp4l.path_trace_enabled is 1
ptp4l[22173.736]: config item /var/run/ptp4l.tc_spanning_tree is 0
ptp4l[22173.736]: config item /var/run/ptp4l.ingressLatency is 0
ptp4l[22173.736]: config item /var/run/ptp4l.egressLatency is 0
ptp4l[22173.736]: config item /var/run/ptp4l.delay_mechanism is 0
ptp4l[22173.736]: config item /var/run/ptp4l.hybrid_e2e is 0
ptp4l[22173.736]: config item /var/run/ptp4l.fault_badpeernet_interval is 16
ptp4l[22173.736]: config item /var/run/ptp4l.fault_reset_interval is 4
ptp4l[22173.736]: config item /var/run/ptp4l.delay_filter_length is 1
ptp4l[22173.736]: config item /var/run/ptp4l.delay_filter is 1
ptp4l[22173.736]: config item /var/run/ptp4l.tsproc_mode is 0
ptp4l[22173.736]: config item enp1s0.boundary_clock_jbod is 0
ptp4l[22173.736]: config item enp1s0.network_transport is 3
ptp4l[22173.736]: config item enp1s0.masterOnly is 0
ptp4l[22173.736]: config item enp1s0.BMCA is 0
ptp4l[22173.736]: config item enp1s0.delayAsymmetry is 0
ptp4l[22173.736]: config item enp1s0.follow_up_info is 1
ptp4l[22173.736]: config item enp1s0.freq_est_interval is 1
ptp4l[22173.736]: config item enp1s0.net_sync_monitor is 0
ptp4l[22173.736]: config item enp1s0.path_trace_enabled is 1
ptp4l[22173.736]: config item enp1s0.tc_spanning_tree is 0
ptp4l[22173.736]: config item enp1s0.ingressLatency is 0
ptp4l[22173.736]: config item enp1s0.egressLatency is 0
ptp4l[22173.736]: config item enp1s0.delay_mechanism is 2
ptp4l[22173.736]: config item enp1s0.unicast_master_table is 0
ptp4l[22173.736]: config item enp1s0.unicast_listen is 0
ptp4l[22173.736]: config item enp1s0.hybrid_e2e is 0
ptp4l[22173.736]: config item enp1s0.fault_badpeernet_interval is 16
ptp4l[22173.736]: config item enp1s0.fault_reset_interval is 4
ptp4l[22173.736]: config item enp1s0.delay_filter_length is 10
ptp4l[22173.736]: config item enp1s0.delay_filter is 1
ptp4l[22173.737]: config item enp1s0.tsproc_mode is 0
ptp4l[22173.737]: config item enp1s0.logMinDelayReqInterval is 0
ptp4l[22173.737]: config item enp1s0.logAnnounceInterval is 0
ptp4l[22173.737]: config item enp1s0.inhibit_announce is 0
ptp4l[22173.737]: config item enp1s0.ignore_source_id is 0
ptp4l[22173.737]: config item enp1s0.announceReceiptTimeout is 3
ptp4l[22173.737]: config item enp1s0.syncReceiptTimeout is 3
ptp4l[22173.737]: config item enp1s0.transportSpecific is 1
ptp4l[22173.737]: config item enp1s0.ignore_transport_specific is 0
ptp4l[22173.737]: config item enp1s0.G.8275.portDS.localPriority is 128
ptp4l[22173.737]: config item enp1s0.logSyncInterval is -3
ptp4l[22173.737]: config item enp1s0.operLogSyncInterval is 0
ptp4l[22173.737]: config item enp1s0.logMinPdelayReqInterval is 0
ptp4l[22173.737]: config item enp1s0.operLogPdelayReqInterval is 0
ptp4l[22173.737]: config item enp1s0.neighborPropDelayThresh is 800
ptp4l[22173.737]: config item enp1s0.min_neighbor_prop_delay is -20000000
ptp4l[22173.737]: config item enp1s0.asCapable is 1
ptp4l[22173.737]: config item enp1s0.inhibit_delay_req is 0
ptp4l[22173.737]: config item enp1s0.ptp_dst_mac is '01:80:C2:00:00:0E'
ptp4l[22173.737]: config item enp1s0.p2p_dst_mac is '01:80:C2:00:00:0E'
ptp4l[22173.737]: config item global.socket_priority is 0
ptp4l[22173.760]: port 1: INITIALIZING to LISTENING on INIT_COMPLETE
ptp4l[22173.760]: config item /var/run/ptp4l.logMinDelayReqInterval is 0
ptp4l[22173.760]: config item /var/run/ptp4l.logAnnounceInterval is 0
ptp4l[22173.760]: config item /var/run/ptp4l.inhibit_announce is 0
ptp4l[22173.760]: config item /var/run/ptp4l.ignore_source_id is 0
ptp4l[22173.760]: config item /var/run/ptp4l.announceReceiptTimeout is 0
ptp4l[22173.760]: config item /var/run/ptp4l.syncReceiptTimeout is 3
ptp4l[22173.760]: config item /var/run/ptp4l.transportSpecific is 1
ptp4l[22173.760]: config item /var/run/ptp4l.ignore_transport_specific is 0
ptp4l[22173.760]: config item /var/run/ptp4l.G.8275.portDS.localPriority is 128
ptp4l[22173.760]: config item /var/run/ptp4l.logSyncInterval is -3
ptp4l[22173.760]: config item /var/run/ptp4l.operLogSyncInterval is 0
ptp4l[22173.760]: config item /var/run/ptp4l.logMinPdelayReqInterval is 0
ptp4l[22173.760]: config item /var/run/ptp4l.operLogPdelayReqInterval is 0
ptp4l[22173.760]: config item /var/run/ptp4l.neighborPropDelayThresh is 800
ptp4l[22173.760]: config item /var/run/ptp4l.min_neighbor_prop_delay is -20000000
ptp4l[22173.760]: config item /var/run/ptp4l.asCapable is 1
ptp4l[22173.760]: config item /var/run/ptp4l.inhibit_delay_req is 0
ptp4l[22173.760]: config item (null).uds_address is '/var/run/ptp4l'
ptp4l[22173.760]: port 0: INITIALIZING to LISTENING on INIT_COMPLETE
ptp4l[22173.760]: port 1: received link status notification
ptp4l[22173.760]: interface index 2 is up
ptp4l[22174.760]: port 1: delay timeout
ptp4l[22175.760]: port 1: delay timeout
ptp4l[22176.760]: port 1: delay timeout
ptp4l[22177.757]: port 1: announce timeout
ptp4l[22177.757]: port 1: LISTENING to MASTER on ANNOUNCE_RECEIPT_TIMEOUT_EXPIRES
ptp4l[22177.757]: selected local clock 6cb311.fffe.523b81 as best master
ptp4l[22177.757]: port 1: assuming the grand master role
ptp4l[22177.758]: port 1: master tx announce timeout
ptp4l[22177.760]: port 1: delay timeout
ptp4l[22177.882]: port 1: master sync timeout
ptp4l[22178.008]: port 1: master sync timeout
ptp4l[22178.133]: port 1: master sync timeout
ptp4l[22178.259]: port 1: master sync timeout
ptp4l[22178.384]: port 1: master sync timeout
ptp4l[22178.509]: port 1: master sync timeout
ptp4l[22178.634]: port 1: master sync timeout
ptp4l[22178.759]: port 1: master tx announce timeout
ptp4l[22178.760]: port 1: master sync timeout
ptp4l[22178.761]: port 1: delay timeout
ptp4l[22178.885]: port 1: master sync timeout
ptp4l[22179.010]: port 1: master sync timeout
ptp4l[22179.135]: port 1: master sync timeout
ptp4l[22179.261]: port 1: master sync timeout
ptp4l[22179.386]: port 1: master sync timeout
ptp4l[22179.511]: port 1: master sync timeout
ptp4l[22179.637]: port 1: master sync timeout
ptp4l[22179.759]: port 1: master tx announce timeout
...

...
ptp4l[22535.867]: port 1: master tx announce timeout
ptp4l[22535.939]: port 1: master sync timeout
ptp4l[22536.065]: port 1: master sync timeout
ptp4l[22536.190]: port 1: master sync timeout
ptp4l[22536.315]: port 1: master sync timeout
ptp4l[22536.440]: port 1: master sync timeout
ptp4l[22536.566]: port 1: master sync timeout
ptp4l[22536.691]: port 1: master sync timeout
ptp4l[22536.817]: port 1: master sync timeout
ptp4l[22536.866]: port 1: delay timeout
ptp4l[22536.867]: port 1: peer port id set to 089e01.fffe.55da81-1
ptp4l[22536.867]: delay   filtered     113983   raw     113983
ptp4l[22536.867]: port 1: master tx announce timeout
ptp4l[22536.942]: port 1: master sync timeout
ptp4l[22537.067]: port 1: master sync timeout
ptp4l[22537.193]: port 1: master sync timeout
ptp4l[22537.318]: port 1: master sync timeout
ptp4l[22537.443]: port 1: master sync timeout
ptp4l[22537.569]: port 1: master sync timeout
ptp4l[22537.694]: port 1: master sync timeout
ptp4l[22537.819]: port 1: master sync timeout
ptp4l[22537.867]: port 1: delay timeout
ptp4l[22537.868]: delay   filtered     113874   raw     113766
ptp4l[22537.868]: port 1: master tx announce timeout
...

...
ptp4l[22554.873]: delay   filtered     103546   raw     114109
ptp4l[22554.873]: port 1: master tx announce timeout
ptp4l[22554.992]: port 1: master sync timeout
ptp4l[22555.117]: port 1: master sync timeout
ptp4l[22555.242]: port 1: master sync timeout
ptp4l[22555.368]: port 1: master sync timeout
ptp4l[22555.493]: port 1: master sync timeout
ptp4l[22555.618]: port 1: master sync timeout
ptp4l[22555.743]: port 1: master sync timeout
ptp4l[22555.869]: port 1: master sync timeout
ptp4l[22555.872]: port 1: delay timeout
ptp4l[22555.873]: delay   filtered     103546   raw     109713
ptp4l[22555.874]: port 1: master tx announce timeout
ptp4l[22555.994]: port 1: master sync timeout
ptp4l[22556.120]: port 1: master sync timeout
ptp4l[22556.245]: port 1: master sync timeout
ptp4l[22556.370]: port 1: master sync timeout
ptp4l[22556.495]: port 1: master sync timeout
ptp4l[22556.621]: port 1: master sync timeout
ptp4l[22556.746]: port 1: master sync timeout
ptp4l[22556.871]: port 1: master sync timeout
ptp4l[22556.872]: port 1: delay timeout
ptp4l[22556.874]: port 1: master tx announce timeout
ptp4l[22556.996]: port 1: master sync timeout
`^C`

sudo phc2sys -w -m -s enp1s0 -c CLOCK_REALTIME --step_threshold=1 –transportSpecific=1 -l 7

phc2sys[22195.914]: config item (null).clock_servo is 0
phc2sys[22195.914]: config item (null).kernel_leap is 1
phc2sys[22195.914]: config item (null).sanity_freq_limit is 200000000
phc2sys[22195.914]: config item (null).pi_proportional_const is 0.700000
phc2sys[22195.914]: config item (null).pi_integral_const is 0.300000
phc2sys[22195.914]: config item (null).pi_proportional_scale is 0.000000
phc2sys[22195.914]: config item (null).pi_proportional_exponent is -0.300000
phc2sys[22195.914]: config item (null).pi_proportional_norm_max is 0.700000
phc2sys[22195.914]: config item (null).pi_integral_scale is 0.000000
phc2sys[22195.914]: config item (null).pi_integral_exponent is 0.400000
phc2sys[22195.914]: config item (null).pi_integral_norm_max is 0.300000
phc2sys[22195.914]: config item (null).step_threshold is 1.000000
phc2sys[22195.914]: config item (null).first_step_threshold is 0.000020
phc2sys[22195.914]: config item (null).max_frequency is 900000000
phc2sys[22195.914]: config item (null).servo_offset_threshold is 0
phc2sys[22195.914]: config item (null).servo_num_offset_values is 10
phc2sys[22195.914]: PI servo: sync interval 1.000 kp 0.700 ki 0.300000
phc2sys[22195.914]: ioctl PTP_SYS_OFFSET_PRECISE: Operation not supported
phc2sys[22195.914]: config item (null).pi_proportional_const is 0.700000
phc2sys[22195.914]: config item (null).pi_integral_const is 0.300000
phc2sys[22195.914]: config item (null).pi_proportional_scale is 0.000000
phc2sys[22195.914]: config item (null).pi_proportional_exponent is -0.300000
phc2sys[22195.914]: config item (null).pi_proportional_norm_max is 0.700000
phc2sys[22195.914]: config item (null).pi_integral_scale is 0.000000
phc2sys[22195.914]: config item (null).pi_integral_exponent is 0.400000
phc2sys[22195.914]: config item (null).pi_integral_norm_max is 0.300000
phc2sys[22195.914]: config item (null).step_threshold is 1.000000
phc2sys[22195.914]: config item (null).first_step_threshold is 0.000020
phc2sys[22195.914]: config item (null).max_frequency is 900000000
phc2sys[22195.914]: config item (null).servo_offset_threshold is 0
phc2sys[22195.914]: config item (null).servo_num_offset_values is 10
phc2sys[22195.914]: PI servo: sync interval 1.000 kp 0.700 ki 0.300000
phc2sys[22195.914]: config item (null).transportSpecific is 0
phc2sys[22195.914]: config item (null).domainNumber is 0
phc2sys[22195.914]: config item (null).uds_address is '/var/run/ptp4l'

phc2sys[22196.915]: Waiting for ptp4l...
phc2sys[22197.917]: Waiting for ptp4l...
...

...

phc2sys[22559.231]: Waiting for ptp4l...
phc2sys[22559.232]: uds: sendto failed: No such file or directory
phc2sys[22560.233]: Waiting for ptp4l...
phc2sys[22560.233]: uds: sendto failed: No such file or directory
phc2sys[22561.234]: Waiting for ptp4l...
phc2sys[22561.234]: uds: sendto failed: No such file or directory
^C
edersondisouza commented 3 years ago

Hi @elabbing,

I noticed from your logs that ptp4l is using transportSpecific 0 instead of 1. Can you confirm which value is on configs/gPTP.cfg? The default should be 1, but as long as they agree (the config and the option passed to phc2sys), it should work.

elabbing commented 3 years ago

Ok, many thanks. gPTP.cfg I used had misconfiguration. Now it works. You could suggest some docs with detailed discussion about transportspecific and other options, please?

elabbing commented 3 years ago

Now, another issue. Running the sequence:

sudo tc qdisc add dev enp1s0 parent root handle 6666 mqprio num_tc 2 map 1 1 1 0 1 1 1 1 1 1 1 1 1 1 1 1 queues 1@0 1@1 hw 0
sudo tc qdisc replace dev enp1s0 parent 6666:2 handle 8888 cbs idleslope 3648 sendslope -996352 hicredit 12 locredit -113 offload 1

sudo tc qdisc add dev enp1s0 parent 8888:1 etf clockid CLOCK_TAI delta 500000 offload

sudo ptp4l -i enp1s0 -f configs/gPTP.cfg --step_threshold=1 -m

sudo pmc -u -b 0 -t 1 "SET GRANDMASTER_SETTINGS_NP clockClass 248 clockAccuracy 0xfe offsetScaledLogVariance 0xffff currentUtcOffset 37 leap61 0 leap59 0 currentUtcOffsetValid 1 ptpTimescale 1 timeTraceable 1 frequencyTraceable 0 timeSource 0xa0"
sudo phc2sys -w -m -s enp1s0 -c CLOCK_REALTIME --step_threshold=1 --transportSpecific=1

ptp4l output stucks in:

ptp4l[143990.630]: port 1: FAULTY to LISTENING on INIT_COMPLETE
ptp4l[143990.630]: port 1: received link status notification
ptp4l[143990.630]: interface index 2 is up
ptp4l[143991.577]: port 1: peer port id set to 089e01.fffe.55da81-1
ptp4l[143991.577]: send failed: 105 No buffer space available
ptp4l[143991.578]: port 1: send peer delay response failed
ptp4l[143991.578]: port 1: LISTENING to FAULTY on FAULT_DETECTED (FT_UNSPECIFIED)
ptp4l[143991.608]: waiting 2^{4} seconds to clear fault on port 1

and phc2sys stucks in:

phc2sys[143982.793]: config item (null).uds_address is '/var/run/ptp4l'
phc2sys[143983.797]: Waiting for ptp4l...
phc2sys[143984.798]: Waiting for ptp4l...
phc2sys[143985.799]: Waiting for ptp4l...

I hope you could help me.

elabbing commented 3 years ago

I test following too (only MQPRIO and CBS QDisc):

sudo tc qdisc add dev enp1s0 parent root handle 6666 mqprio num_tc 2 map 1 1 1 0 1 1 1 1 1 1 1 1 1 1 1 1 queues 1@0 1@1 hw 0
sudo tc qdisc replace dev enp1s0 parent 6666:2 handle 8888 cbs idleslope 3648 sendslope -996352 hicredit 12 locredit -113 offload 1

sudo ptp4l -i enp1s0 -f configs/gPTP.cfg --step_threshold=1 -m

sudo pmc -u -b 0 -t 1 "SET GRANDMASTER_SETTINGS_NP clockClass 248 clockAccuracy 0xfe offsetScaledLogVariance 0xffff currentUtcOffset 37 leap61 0 leap59 0 currentUtcOffsetValid 1 ptpTimescale 1 timeTraceable 1 frequencyTraceable 0 timeSource 0xa0"

And all seems run well:

...
ptp4l[144900.202]: port 1: master sync timeout
ptp4l[144900.330]: port 1: master sync timeout
ptp4l[144900.382]: port 1: master tx announce timeout
ptp4l[144900.444]: port 1: delay timeout
ptp4l[144900.444]: delay   filtered      80181   raw      32597
ptp4l[144900.455]: port 1: master sync timeout
ptp4l[144900.581]: port 1: master sync timeout
...
...
phc2sys[144872.967]: CLOCK_REALTIME phc offset        21 s2 freq  +47400 delay   4958
phc2sys[144873.968]: CLOCK_REALTIME phc offset       -18 s2 freq  +47368 delay   4958
phc2sys[144874.969]: CLOCK_REALTIME phc offset       -28 s2 freq  +47352 delay   4818
phc2sys[144875.970]: CLOCK_REALTIME phc offset        36 s2 freq  +47408 delay   5028
phc2sys[144876.979]: CLOCK_REALTIME phc offset       137 s2 freq  +47520 delay   5168
phc2sys[144877.980]: CLOCK_REALTIME phc offset      -201 s2 freq  +47223 delay   4959
phc2sys[144878.981]: CLOCK_REALTIME phc offset       -36 s2 freq  +47327 delay   4819
...

Then I type: sudo tc qdisc add dev enp1s0 parent 8888:1 etf clockid CLOCK_TAI delta 500000 offload

and ptp4l stucks, but phc2sys continues to run.

Tricky for me...

edersondisouza commented 3 years ago

Hi @elabbing,

To get more information about transportSpecific (and other configuration options), I'll refer you to the IEEE-1588 Standard.

About your second issue, what happens is that ptp4l can't send data through an ETF qdisc. To send data through ETF, an application needs to timestamp each packet with a desired launch time. As ptp4l doesn't do that, I'd suggest you to direct ptp4l traffic to another qdisc.

elabbing commented 3 years ago

Hi @elabbing,

To get more information about transportSpecific (and other configuration options), I'll refer you to the IEEE-1588 Standard.

Ok, thanks.

About your second issue, what happens is that ptp4l can't send data through an ETF qdisc. To send data through ETF, an application needs to timestamp each packet with a desired launch time. As ptp4l doesn't do that, I'd suggest you to direct ptp4l traffic to another qdisc.

In TSN-doc is stated: Three qdiscs are required to set up an AVB system: MQPRIO, CBS and ETF.

and further is exaplained as to set Time Synchronization through ptp4l please, see https://tsn.readthedocs.io/avb.html#system-setup

Could you clarify that?

edersondisouza commented 3 years ago

The AVB application - in our documentation, the one using GStreamer AVTP plugin or Alsa AAF plugin - is the one that uses the CBS and ETF qdisc. Not ptp4l. In fact, ptp4l messages could be delayed by CBS - if it tries to send a message when credit is over, which is undesirable.

So, the documentation sets up the qdiscs for the application. You can verify that it defines Linux socket priority 3 as the one that will go over the TSN qdiscs (CBS and ETF). The applications are then instructed to also use socket priority 3. However, ptp4l doesn't use socket priority 3. So, it will be best effort.

elabbing commented 3 years ago

The AVB application - in our documentation, the one using GStreamer AVTP plugin or Alsa AAF plugin - is the one that uses the >CBS and ETF qdisc. Not ptp4l. In fact, ptp4l messages could be delayed by CBS - if it tries to send a message when credit is >over, which is undesirable.

So, if I understand well, in TSN-doc is described a system set-up don't work for ptp4l and QDisc running at the same time? In other word, if I set-up ptp4l first and then QDisc on the same host PC, this breaks the host clocks synchronization, LAN sync, or both ? But, on the other hand, I need running both ptp4l and QDisc to build a TSB-AVB compliant system?

So, the documentation sets up the qdiscs for the application. You can verify that it defines Linux socket priority 3 as the one that >will go over the TSN qdiscs (CBS and ETF). The applications are then instructed to also use socket priority 3. However, ptp4l >doesn't use socket priority 3. So, it will be best effort.

For ALSA and GSreamer, in TSN-doc is reported priority set to 2 as follow:

pcm.aaf0 {
        type aaf
        ifname eth0.5
        addr 01:AA:AA:AA:AA:AA

                                       prio 2

        streamid AA:BB:CC:DD:EE:FF:000B
        mtt 50000
        time_uncertainty 1000
        frames_per_pdu 12
        ptime_tolerance 100
}
gst-launch-1.0 clockselect. \( clock-id=realtime \
    filesrc location=piano2.wav ! wavparse ! audioconvert ! \
    audiobuffersplit output-buffer-duration=12/48000 ! \
    avtpaafpay mtt=50000000 tu=1000000 streamid=0xAABBCCDDEEFF000B processing-deadline=0 ! \
    avtpsink ifname=eth0.5 address=01:AA:AA:AA:AA:AA 

                                priority=2 

processing-deadline=0 \)

It is reported as working configuration. Maybe I fail to understand anything? Many thanks

edersondisouza commented 3 years ago

Hi,

About the priority 2 vs 3: well spotted! I just thought of the video example (which uses priority 3).

About qdiscs vs ptp4l, they do work together. If you follow the examples, you should get everything working fine: ptp4l, TSN traffic (audio and/or video) and even some other best-effort traffic as well, try it! If you run into any issues, please ask!

I noticed that you use a slightly different MQPRIO configuration than that in the TSN-doc examples, so let's take a step back and look at MQPRIO configuration there - as is the one which deals with priorities. I'll try to break it down so that you can do the changes needed for your case in a more informed way. There, first command is:

sudo tc qdisc add dev eth0 parent root handle 6666 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

Taking a closer look at the map, which is basically an array from with 16 items, indexed from 0 to 15, we see that index 2 has value 1:

2 2 1 0 2 2 2 2 2 2 2 2 2 2 2 2

And index 3 has value 0:

2 2 1 0 2 2 2 2 2 2 2 2 2 2 2 2

Which means that priority 2 is mapped to traffic class 1, and priority 3 to traffic class 0. All other priorities (0-1, 4-15) are mapped to traffic class 2. Note that, if an application doesn't set the priority of a socket, it will be 0. While ptp4l can be configured to use a given socket priority, that is not done in the documentation, so it will use 0.

After you run the mqprio command, if you check the qdiscs for the NIC, you'll get something like:

$ tc qdisc show dev enp6s0 
qdisc mqprio 6666: root  tc 3 map 2 2 1 0 2 2 2 2 2 2 2 2 2 2 2 2 
             queues:(0:0) (1:1) (2:3) 
qdisc fq 0: parent 6666:4 limit 10000p flow_limit 100p buckets 1024 orphan_mask 1023 quantum 3028b initial_quantum 15140b low_rate_threshold 550Kbit refill_delay 40.0ms 
qdisc fq 0: parent 6666:3 limit 10000p flow_limit 100p buckets 1024 orphan_mask 1023 quantum 3028b initial_quantum 15140b low_rate_threshold 550Kbit refill_delay 40.0ms 
qdisc fq 0: parent 6666:2 limit 10000p flow_limit 100p buckets 1024 orphan_mask 1023 quantum 3028b initial_quantum 15140b low_rate_threshold 550Kbit refill_delay 40.0ms 
qdisc fq 0: parent 6666:1 limit 10000p flow_limit 100p buckets 1024 orphan_mask 1023 quantum 3028b initial_quantum 15140b low_rate_threshold 550Kbit refill_delay 40.0ms

Note that there are 4 queues under the mqprio (note that their "parent" has the handle of the mqprio one). That's basically because the NIC I'm using has 4 hardware queues. A question that may arise here is: which traffic goes to each queue?

The answer is in the mqprio command:

queues 1@0 1@1 2@2

Think of this as an array whose size is the number of traffic queues (in our example, 3) in which each position there's a set of hardware queues. Something like:

queues [hw queues for traffic class 0] [hw queues for traffic class 1] [hw queues for traffic class 2]

And the x@y is the count@offset of the hardware queues that will be used for the traffic class. So, for traffic class 0, we have:

1@0

Meaning 1 hardware queue, at offset 0. Again, think of the 4 hardware queues as an array indexed from 0 to 3. Next, for traffic class 1:

1@1

Meaning 1 hardware queue, at offset 1. Finally, for traffic class 2:

2@2

Meaning 2 hardware queues, starting at offset 2. So, in the end, from hardware queues perspective, the mapping is something like:

[Traffic class 0] [Traffic class 1] [Traffic class 2] [Traffic class 2]

So, back to the result of mqprio command, we have:

$ tc qdisc show dev enp6s0 
qdisc mqprio 6666: root  tc 3 map 2 2 1 0 2 2 2 2 2 2 2 2 2 2 2 2 
             queues:(0:0) (1:1) (2:3) 
qdisc fq 0: parent 6666:4 limit (...) # This queue is for traffic class 2
qdisc fq 0: parent 6666:3 limit (...) # This queue is for traffic class 2
qdisc fq 0: parent 6666:2 limit (...) # This queue is for traffic class 1
qdisc fq 0: parent 6666:1 limit (...) # This queue is for traffic class 0

Now that we got the MQPRIO side, let's go to CBS and ETF. Back in the qdiscs, you will note that the qdiscs for traffic class 0 and 1 are generic fq qdiscs. We don't want that, we want to use our TSN capable ones. So next step is:

sudo tc qdisc replace dev eth0 parent 6666:1 handle 7777 cbs \
        idleslope 98688 sendslope -901312 hicredit 153 locredit -1389 \
        offload 1

sudo tc qdisc replace dev eth0 parent 6666:2 handle 8888 cbs \
        idleslope 3648 sendslope -996352 hicredit 12 locredit -113 \
        offload 1

After running those, if we check the qdisics we'll have something like:

$ tc qdisc show dev enp6s0 
qdisc mqprio 6666: root  tc 3 map 2 2 1 0 2 2 2 2 2 2 2 2 2 2 2 2 
             queues:(0:0) (1:1) (2:3) 
qdisc cbs 8888: parent 6666:2 hicredit 12 locredit -113 sendslope -996352 idleslope 3648 offload 1 
qdisc pfifo 0: parent 8888: limit 1000p
qdisc pfifo 0: parent 7777: limit 1000p
qdisc fq 0: parent 6666:4 limit 10000p flow_limit 100p buckets 1024 orphan_mask 1023 quantum 3028b initial_quantum 15140b low_rate_threshold 550Kbit refill_delay 40.0ms 
qdisc fq 0: parent 6666:3 limit 10000p flow_limit 100p buckets 1024 orphan_mask 1023 quantum 3028b initial_quantum 15140b low_rate_threshold 550Kbit refill_delay 40.0ms 
qdisc cbs 7777: parent 6666:1 hicredit 153 locredit -1389 sendslope -901312 idleslope 98688 offload 1 

Wow, looks messy. But we can navigate through this. There are still the two fq related to traffic class 2:

(...)
qdisc fq 0: parent 6666:4 limit 10000p flow_limit 100p buckets 1024 orphan_mask 1023 quantum 3028b initial_quantum 15140b low_rate_threshold 550Kbit refill_delay 40.0ms 
qdisc fq 0: parent 6666:3 limit 10000p flow_limit 100p buckets 1024 orphan_mask 1023 quantum 3028b initial_quantum 15140b low_rate_threshold 550Kbit refill_delay 40.0ms 
(...)

There are the two CBS ones that we added:

(...)
qdisc cbs 8888: parent 6666:2 hicredit 12 locredit -113 sendslope -996352 idleslope 3648 offload 1 
(...)
qdisc cbs 7777: parent 6666:1 hicredit 153 locredit -1389 sendslope -901312 idleslope 98688 offload 1

And finally, under each CBS, there's a pfifo qdisc (note their parents handle mach the CBS ones):

(...)
qdisc pfifo 0: parent 8888: limit 1000p
qdisc pfifo 0: parent 7777: limit 1000p
(...)

Now, packets that are sent via a socket with priority 2 will be mapped to traffic class 1. Traffic class 1 traffic go to the second hardware queue. But before getting there, it will pass through the CBS queue with handle 8888. Something similar happens to packets sent to a socket with priority 3, but those will end up going to the CBS queue with handle 7777. All other packets will go to either of the remaining fq qdiscs under MQPRIO.

So, in the documentation example, only the audio and video traffic will be sent through the TSN qdiscs. Packets generated by ptp4l will go to either of the remaining fq qdiscs under MQPRIO.

Note that in the example, those pfifo qdiscs will be replaced with ETF ones:

sudo tc qdisc add dev eth0 parent 7777:1 etf \
        clockid CLOCK_TAI \
        delta 500000 \
        offload

sudo tc qdisc add dev eth0 parent 8888:1 etf \
        clockid CLOCK_TAI \
        delta 500000 \
        offload

The final look of the qdiscs will be something like:

$ tc qdisc show dev enp6s0 
qdisc mqprio 6666: root  tc 3 map 2 2 1 0 2 2 2 2 2 2 2 2 2 2 2 2 
             queues:(0:0) (1:1) (2:3) 
qdisc cbs 8888: parent 6666:2 hicredit 12 locredit -113 sendslope -996352 idleslope 3648 offload 1 
qdisc fq 0: parent 6666:4 limit 10000p flow_limit 100p buckets 1024 orphan_mask 1023 quantum 3028b initial_quantum 15140b low_rate_threshold 550Kbit refill_delay 40.0ms 
qdisc fq 0: parent 6666:3 limit 10000p flow_limit 100p buckets 1024 orphan_mask 1023 quantum 3028b initial_quantum 15140b low_rate_threshold 550Kbit refill_delay 40.0ms 
qdisc etf 804e: parent 8888:1 clockid TAI delta 500000 offload on deadline_mode off skip_sock_check off
qdisc cbs 7777: parent 6666:1 hicredit 153 locredit -1389 sendslope -901312 idleslope 98688 offload 1 
qdisc etf 804d: parent 7777:1 clockid TAI delta 500000 offload on deadline_mode off skip_sock_check off

However, a packet that goes to an ETF qdisc needs to have a timestamp associated to it, indicating when it should be transmitted. Both the Gstreamer AVTP plugin as well as the Alsa AAF plugin take care of that, but ptp4l doesn't do that, so it can't send packets if an ETF qdisc is in the way.

With that, I hope you can tweak the configuration as needed - for instance, if your NIC has a different number of HW queues or so.

elabbing commented 3 years ago

Thanks a lot, great reply! Now, I take some time to study more deeply.

edersondisouza commented 3 years ago

Hi @elabbing,

Can this issue be closed now?

elabbing commented 3 years ago

yes, many thanks

petipok commented 2 years ago

Hello, I got stuck with the same issue, the phc2sys stucks in "Waiting for ptp4l...", and I don't have a clue now what to change. I tried to follow the guide, but I could make the qdisc part work with the following way:

sudo tc qdisc add dev enp2s0 parent root handle 6666 mqprio num_tc 2 map 1 1 1 0 1 1 1 1 1 1 1 1 1 1 1 1 queues 1@0 1@1 hw 0
sudo tc qdisc replace dev enp2s0 parent 6666:1 handle 8888 cbs idleslope 3648 sendslope -996352 hicredit 12 locredit -113 offload 1
sudo tc qdisc add dev enp2s0 parent 8888:1 etf clockid CLOCK_TAI delta 500000 offload
sudo ptp4l -i enp2s0 -f /usr/share/doc/linuxptp/gPTP.cfg --step_threshold=1 -m
sudo pmc -u -b 0 -t 1 "SET GRANDMASTER_SETTINGS_NP clockClass 248 clockAccuracy 0xfe offsetScaledLogVariance 0xffff currentUtcOffset 37 leap61 0 leap59 0 currentUtcOffsetValid 1 ptpTimescale 1 timeTraceable 1 frequencyTraceable 0 timeSource 0xa0"
sudo phc2sys -w -m -s enp2s0 -c CLOCK_REALTIME -S 1

I could not find a way to substitute the --transportSpecific=1 parameter in the last command, it seems to be an invalid argument.

My system is a Debian 10 with kernel 4.19.0-18-amd64 and would like to set up the ALSA streaming with 2 identical computers with Intel I210 controller. The num_tc 3 parameter did not work, so I changed it to num_tc 2 and the map to map 1 1 1 0 1 1 1 1 1 1 1 1 1 1 1 1.

Any idea how to proceed from this point?

Thank you!

edersondisouza commented 2 years ago

@petipok

It seems you are having issues on some previous steps: what did happen when you tried to use num_tc 3 for mqprio? Also, what is the linuxptp version in your systems? Trying with more verbose log doesn't yield more clues?

petipok commented 2 years ago

@edersondisouza I got this with num_tc 3: sudo tc qdisc add dev enp2s0 parent root handle 6666 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 RTNETLINK answers: Invalid argument

Furthermore, thanks for pointing out the ptp4l version, I had v1.92. After updating it from github to v3.1 the synchronization seems to work correctly now!

However I can not hear the audio stream on the listener side, but that is another topic, I am debugging it now.