nxp-archive / openil

OpenIL is an open source project based on Buildroot and designed for embedded industrial solution.
Other
136 stars 55 forks source link

Time sychronization #48

Closed sabarishsubramanian closed 4 years ago

sabarishsubramanian commented 4 years ago

Hello

I am trying to have a time sychronization of three TSN boards. I am trying to do in openil- community part.

The pdf which i have is of openil where they use SJA1105 tools and all. where in community part there is no more SJA1105 tools exits.

Could someone please help me how to start and proceed further?

Regards sabarish s

sabarishsubramanian commented 4 years ago

I have a host pc, 3 tsn boards and a switch. The connection is done according to the pdf of openil.

Now i wanna time synchronise it. How shall i start and proceed further since in openil community there are no more SJA1105 tools exits.

I know this issues is solved in openil community since i cant find any documentation kindly help me.

Please someone help me figure this out.

Thank you

vladimiroltean commented 4 years ago

Hi Sabarish,

I will post a detailed guide here but at the moment I need to take care of some other pressing issues, so it will take me a day or so.

Thanks, -Vladimir

sabarishsubramanian commented 4 years ago

Ok no problem i will wait your reply and documentation soon.

Thank you

Regards sabarish subramanian

vladimiroltean commented 4 years ago

Yes, I am working on it. It is taking a while.

vladimiroltean commented 4 years ago

Setup

It is recommended that you update the openil-community image on all boards to at least the following commit(which at the time of writing is the most recent).

Follow the official U-Boot steps to reprogram the EEPROM to make sure that all boards have unique MAC addresses.

For the synchronized 802.1Qbv demo, the following setup is advised:

+------------------------------------------------------------+
|                                          LS1021A-TSN       |
|                         gianfar            Board 1         |
|                 +-------- eth2                             |
|                 |      DSA master                          |
|                 |                                          |
|              cpu port                                      |
|   +--------+         +--------+         +--------+         |
|   |        |         |        |         |        |         |
|   |  swp5  |         |  swp3  |         |  eth1  | gianfar |
|   |        |         |        |         |        |         |
|   +--------+ sja1105 +--------+         +--------+         |
|   |        |         |        |         |        |         |
|   |  swp4  |         |  swp2  |         |  eth0  | gianfar |
|   |        |         |        |         |        |         |
+---+--------+---------+--------+---------+--------+---------+
                                              |
                                              |
                                      +-------+
                                      |
+-------------------------------------|----------------------+
|                                     |    LS1021A-TSN       |
|                         gianfar     |      Board 2         |
|                 +-------- eth2      |                      |
|                 |      DSA master   |                      |
|                 |                   |                      |
|              cpu port               |                      |
|   +--------+         +--------+     |   +--------+         |
|   |        |         |        |     |   |        |         |
|   |  swp5  |         |  swp3  |<----+   |  eth1  | gianfar |
|   |        |         |        |         |        |         |
|   +--------+ sja1105 +--------+         +--------+         |
|   |        |         |        |         |        |         |
|   |  swp4  |         |  swp2  |-----+   |  eth0  | gianfar |
|   |        |         |        |     |   |        |         |
+---+--------+---------+--------+-----|---+--------+---------+
                                      |
                                      |
                                      |
+-------------------------------------|----------------------+
|                                     |    LS1021A-TSN       |
|                         gianfar     |       Board 3        |
|                 +-------- eth2      |                      |
|                 |      DSA master   |                      |
|                 |                   |                      |
|              cpu port               |                      |
|   +--------+         +--------+     |   +--------+         |
|   |        |         |        |     |   |        |         |
|   |  swp5  |         |  swp3  |     |   |  eth1  | gianfar |
|   |        |         |        |     |   |        |         |
|   +--------+ sja1105 +--------+     |   +--------+         |
|   |        |         |        |     |   |        |         |
|   |  swp4  |         |  swp2  |     +-->|  eth0  | gianfar |
|   |        |         |        |         |        |         |
+---+--------+---------+--------+---------+--------+---------+

Other setups (perhaps more complex) are possible.

Compared to the official OpenIL setup, the external switch is no longer needed, since PTP synchronization is now done through the sja1105 switch (more details below).

First step is to run the command below on all 3 boards, which enables root SSH access with no credentials (warning: this exposes the board and potentially the entire network to security issues, only do it for the purposes of the demo):

$ passwordless-ssh-login

Board 1 is a TSN traffic sender (endpoint) on the eth0 port, and Board 3 is a TSN traffic receiver on the eth0 port. Board 2 is a TSN bridge on swp2 and swp3.

In the default openil-community board image for LS1021A-TSN:

On Board 1 and Board 3, the default setup needs to be changed.

On Board 1, remove eth0 from the bridge and assign a static IP:

$ vim /etc/systemd/network/eth0.network

[Match]
Name=eth0

[Network]
Address=172.15.0.1/24
VLAN=eth0.100

$ vim /etc/systemd/network/eth0.100.netdev

[NetDev]
Name=eth0.100
Kind=vlan

[VLAN]
Id=100

$ vim /etc/systemd/network/eth0.100.network

[Match]
Name=eth0.100

[Network]
Address=172.15.100.1/24

$ systemctl restart systemd-networkd
$ ip link set dev eth0 nomaster

On Board 3, do the same as above, but add Address=172.15.0.3/24 instead on eth0, and Address=172.15.100.3/24 on eth0.100.

On Board 2, you can optionally assign a static IP to br0 (by default it is using DHCP). We will be using this to verify network connectivity between the 3 boards:

vim /etc/systemd/network/br0.network

[Match]
Name=br0

[Network]
Address=172.15.0.2/24

$ systemctl restart systemd-networkd

After the 3 boards have been configured, you can check connectivity by running from Board 1:

$ ping 172.15.0.2
$ ping 172.15.0.3
$ ping 172.15.100.3

Now reconfigure the linuxptp service. On Board 1 and Board 3, edit the /etc/linuxptp.cfg file, which is based on the gPTP.cfg profile. At the end of the file, the following network devices are enabled by default:

[swp2]
[swp3]
[swp4]
[swp5]

This needs to be changed for Board 1 and Board 3, where we want to run 802.1AS in endpoint mode, on eth0. So change the above lines to:

[eth0]

Following a restart of the linuxptp service:

$ systemctl restart linuxptp

To monitor the 802.1AS synchronization process, you can run the following command on each board:

$ journalctl -b -u linuxptp -f

Different output is expected on different boards. One of the boards will become a grandmaster (it is irrelevant which). That board will show something as follows in the log:

-- Logs begin at Thu 2019-10-10 12:56:03 UTC. --
Oct 10 13:07:27 OpenIL ptp4l[179]: [690.412] port 1: assuming the grand master role
Oct 10 13:07:27 OpenIL ptp4l[179]: [690.412] port 2: assuming the grand master role
Oct 10 13:07:27 OpenIL ptp4l[179]: [690.412] port 3: assuming the grand master role
Oct 10 13:07:27 OpenIL ptp4l[179]: [690.413] port 4: assuming the grand master role
Oct 10 13:51:06 OpenIL ptp4l[179]: [3309.532] port 1: new foreign master 001f7b.fffe.63034f-1
Oct 10 13:51:06 OpenIL ptp4l[179]: [3309.532] selected best master clock 001f7b.fffe.63034f
Oct 10 13:51:06 OpenIL ptp4l[179]: [3309.532] port 1: assuming the grand master role
Oct 10 13:51:06 OpenIL ptp4l[179]: [3309.532] port 2: assuming the grand master role
Oct 10 13:51:06 OpenIL ptp4l[179]: [3309.532] port 3: assuming the grand master role
Oct 10 13:51:06 OpenIL ptp4l[179]: [3309.532] port 4: assuming the grand master role

While the other 2 will become slaves and print the following synchronization log:

Oct 10 14:31:55 OpenIL ptp4l[330]: [5758.247] rms    4 max    4 freq -17418 +/-   5 delay   484 +/-   0
Oct 10 14:31:56 OpenIL ptp4l[330]: [5759.250] rms    4 max    4 freq -17423 +/-   5 delay   484 +/-   0
Oct 10 14:31:57 OpenIL ptp4l[330]: [5760.254] rms    4 max    4 freq -17419 +/-   5 delay   484 +/-   0
Oct 10 14:31:58 OpenIL ptp4l[330]: [5761.257] rms    4 max    4 freq -17422 +/-   5 delay   484 +/-   0
Oct 10 14:31:59 OpenIL ptp4l[330]: [5762.261] rms    4 max    4 freq -17422 +/-   5 delay   484 +/-   0
Oct 10 14:32:00 OpenIL ptp4l[330]: [5763.264] rms    4 max    4 freq -17416 +/-   4 delay   484 +/-   0
Oct 10 14:32:01 OpenIL ptp4l[330]: [5764.269] rms    4 max    4 freq -17420 +/-   5 delay   484 +/-   0
Oct 10 14:32:02 OpenIL ptp4l[330]: [5765.272] rms    4 max    4 freq -17423 +/-   4 delay   484 +/-   0
Oct 10 14:32:03 OpenIL ptp4l[330]: [5766.277] rms    3 max    4 freq -17422 +/-   4 delay   482 +/-   0
Oct 10 14:32:04 OpenIL ptp4l[330]: [5767.280] rms    3 max    6 freq -17420 +/-   4 delay   480 +/-   0
Oct 10 14:32:05 OpenIL ptp4l[330]: [5768.284] rms    4 max    8 freq -17417 +/-   5 delay   480 +/-   0
Oct 10 14:32:06 OpenIL ptp4l[330]: [5769.286] rms    6 max    8 freq -17425 +/-   7 delay   480 +/-   0
Oct 10 14:32:07 OpenIL ptp4l[330]: [5770.290] rms    5 max    8 freq -17422 +/-   6 delay   482 +/-   0
Oct 10 14:32:08 OpenIL ptp4l[330]: [5771.294] rms    5 max    8 freq -17418 +/-   6 delay   480 +/-   0

The above information (only the last line is interpreted) means:

Now that the PTP service is running and there is IP connectivity between the boards, one must understand the clock distribution scheme in the network.

The PTP grandmaster needs to serve time to the other boards. On the LS1021A-TSN board there is no battery-backed RTC, so there is no persistent source of time on the board. One has to rely on the NTP service to provide time. So please note which one of the 3 boards is the one that became grandmaster, and connect it to the Internet (or to an NTP server) on interface eth1. It should get an IP automatically through DHCP, and the ntpd.service should get a time in 2019.

You can monitor the time with:

$ phc_ctl CLOCK_REALTIME get
phc_ctl[9927.473]: clock time is 1570722084.719546320 or Thu Oct 10 15:41:24 2019

To hasten the process of getting time over NTP, you can run the following, after you have connected eth1 to an NTP server:

$ systemctl restart systemd-networkd
$ systemctl restart ntpd

Now make sure that the system clock is synchronized to the PTP Hardware Clock (the time of the NIC that participates in PTP):

journalctl -b -u linuxptp-system-clock.service -f
-- Logs begin at Thu 2019-10-10 12:56:03 UTC. --
Oct 24 05:29:18 OpenIL phc2sys[374]: [1546.695] CLOCK_REALTIME phc offset       -11 s2 freq -31993653 delay   5944
Oct 24 05:29:19 OpenIL phc2sys[374]: [1547.696] CLOCK_REALTIME phc offset        21 s2 freq -31993625 delay   5944
Oct 24 05:29:20 OpenIL phc2sys[374]: [1548.699] CLOCK_REALTIME phc offset       -26 s2 freq -31993665 delay   5862
Oct 24 05:29:21 OpenIL phc2sys[374]: [1549.700] CLOCK_REALTIME phc offset        -2 s2 freq -31993649 delay   5862
Oct 24 05:29:22 OpenIL phc2sys[374]: [1550.701] CLOCK_REALTIME phc offset        29 s2 freq -31993619 delay   5861
Oct 24 05:29:23 OpenIL phc2sys[374]: [1551.702] CLOCK_REALTIME phc offset        -8 s2 freq -31993647 delay   5862
Oct 24 05:29:24 OpenIL phc2sys[374]: [1552.706] CLOCK_REALTIME phc offset        -3 s2 freq -31993644 delay   5862
Oct 24 05:29:25 OpenIL phc2sys[374]: [1553.709] CLOCK_REALTIME phc offset         4 s2 freq -31993638 delay   5862
Oct 24 05:29:26 OpenIL phc2sys[374]: [1554.711] CLOCK_REALTIME phc offset         6 s2 freq -31993635 delay   5944
Oct 24 05:29:27 OpenIL phc2sys[374]: [1555.712] CLOCK_REALTIME phc offset         8 s2 freq -31993631 delay   5944
Oct 24 05:29:28 OpenIL phc2sys[374]: [1556.715] CLOCK_REALTIME phc offset       -24 s2 freq -31993661 delay   5862
Oct 24 05:29:29 OpenIL phc2sys[374]: [1557.717] CLOCK_REALTIME phc offset        -4 s2 freq -31993648 delay   5862

Runtime

The demo just shows baseline hardware functionality at the moment - it just explains what are the basic building blocks and how to migrate from sja1105-tool. It configures the switch on Board 2 to apply time-based scheduling on a traffic stream generated by Board 1 towards Board 3.

The traffic stream will be an adaptive ping flood, just as in the official documentation. The cycle-time will be a large value such as 30 ms, for the effect of the time-aware scheduling to be visible.

On board 1 and 3, run the following commands to make ping traffic on eth0.100 be classified with VLAN PCP 5:

ip link set dev eth0.100 type vlan \
    ingress-qos-map 0:0 1:1 2:2 3:3 4:4 5:5 6:6 7:7 \
    egress-qos-map 0:0 1:1 2:2 3:3 4:4 5:5 6:6 7:7
iptables -t mangle -A POSTROUTING -p icmp -j CLASSIFY --set-class 0:5
ping -A 172.15.100.3

On board 2, VLAN awareness is disabled by default. So all VLAN-tagged traffic passes without port membership checks, and the VLAN PCP is ignored. To enable VLAN filtering, run the following:

ip link set dev br0 type bridge vlan_filtering 1
bridge vlan add dev swp2 vid 100
bridge vlan add dev swp3 vid 100
bridge vlan add dev swp4 vid 100
bridge vlan add dev swp5 vid 100

The mapping on Board 2's switch between VLAN PCP and traffic classes is implicitly one to 1, so VLAN PCP 5 goes to traffic class 5, etc.

PTP traffic goes to traffic class 7 by default.

Save the script below to a file called taprio.sh and execute it:

#!/bin/bash

set -e -u -o pipefail

NSEC_PER_SEC="1000000000"

gatemask() {
    local tc_list="$1"
    local mask=0

    for tc in ${tc_list}; do
        mask=$((${mask} | (1 << ${tc})))
    done

    printf "%02x" ${mask}
}

# Given @frame_len bytes, @count frames and @link_speed in Mbps,
# returns the minimum number of nanoseconds required to keep a Qbv gate open
# to transmit that.
qbv_window() {
    local frame_len=$1
    local count=$2
    local link_speed=$3
    local bit_time=$((1000 / ${link_speed}))
    # 7 bytes preamble, 1 byte SFD, 4 bytes FCS and 12 bytes IFG
    local overhead=24
    local octets=$((${frame_len} + ${overhead}))
    local window=$((${octets} * 8 * ${bit_time}))

    if [ $window -lt 1000 ]; then
        echo 1000
    else
        echo $window
    fi
}

if ! systemctl is-active --quiet linuxptp; then
    echo "Please start the linuxptp service"
    exit
fi

speed_mbps=$(ethtool swp2 | gawk \
    '/Speed:/ { speed=gensub(/^(.*)Mb\/s/, "\\1", "g", $2); print speed; }')

now=$(phc_ctl /dev/ptp1 get | gawk '/clock time is/ { print $5; }')
# Phase-align the base time to the start of the next second.
sec=$(echo "${now}" | gawk -F. '{ print $1; }')
base_time="$(((${sec} + 1) * ${NSEC_PER_SEC}))"

# 30 ms
cycle_time=30000000

# PTP: create a window for 1 packet of 200 bytes at the current link speed
t1=$(qbv_window 200 1 $speed_mbps)
# ping: create a window for 1 packet of 64 bytes
t2=$(qbv_window 64 1 $speed_mbps)
# Best effort: the rest of the time up to 30 ms
t0=$(($cycle_time - $t1 - $t2))

tc qdisc add dev swp2 parent root handle 100 taprio \
    num_tc 8 \
    map 0 1 2 3 4 5 6 7 \
    queues 1@0 1@1 1@2 1@3 1@4 1@5 1@6 1@7 \
    base-time ${base_time} \
    sched-entry S $(gatemask 7) $t0 \
    sched-entry S $(gatemask 5) $t1 \
    sched-entry S $(gatemask "0 1 2 3 4 6") $t2 \
    flags 2

More complete documentation on the tc-taprio offload command for the sja1105 is available here.

Please note that at the time of writing I did not have access to 3 LS1021A-TSN boards, so boards 1 and 3 were LS1028A-RDB during my testing. I will keep updating this post if I find any issues with the steps.

sabarishsubramanian commented 4 years ago

Thank you @vladimiroltean am trying to do the steps according to the above mentioned. If i get stuck with something will let you know .

sabarishsubramanian commented 4 years ago

Hello

I tried the steps which was given by you. Everything works fine, even the pinging happens between the board.

Am now experiencing a problem in time synchronization and it is as follows: BOARD1: [root@OpenIL ~] # journalctl -b -u linuxptp -f -- Logs begin at Thu 2019-10-10 12:56:03 UTC. -- Oct 10 13:05:01 OpenIL ptp4l[180]: [544.942] port 1: rogue peer delay response Oct 10 13:05:01 OpenIL ptp4l[180]: [544.947] port 1: MASTER to FAULTY on FAULT_DETECTED (FT_UNSPECIFIED) Oct 10 13:05:01 OpenIL ptp4l[180]: [545.040] selected local clock 00049f.fffe.ef0000 as best master Oct 10 13:05:01 OpenIL ptp4l[180]: [545.041] port 1: assuming the grand master role Oct 10 13:05:17 OpenIL ptp4l[180]: [561.124] port 1: FAULTY to LISTENING on INIT_COMPLETE Oct 10 13:05:21 OpenIL ptp4l[180]: [564.727] port 1: announce timeout Oct 10 13:05:21 OpenIL ptp4l[180]: [564.728] bc_event 2683: returning EV_ANNOUNCE_RECEIPT_TIMEOUT_EXPIRES Oct 10 13:05:21 OpenIL ptp4l[180]: [564.728] port 1: LISTENING to MASTER on ANNOUNCE_RECEIPT_TIMEOUT_EXPIRES Oct 10 13:05:21 OpenIL ptp4l[180]: [564.728] selected local clock 00049f.fffe.ef0000 as best master Oct 10 13:05:21 OpenIL ptp4l[180]: [564.728] port 1: assuming the grand master role

BOARD 2: [root@OpenIL ~] # journalctl -b -u linuxptp -f -- Logs begin at Tue 2019-09-03 09:27:20 UTC. -- Sep 03 09:29:03 OpenIL ptp4l[165]: [108.362] port 4: assuming the grand master role Sep 03 09:29:03 OpenIL ptp4l[165]: [108.367] selected local clock 00049f.fffe.ef0505 as best master Sep 03 09:29:03 OpenIL ptp4l[165]: [108.367] port 1: assuming the grand master role Sep 03 09:29:03 OpenIL ptp4l[165]: [108.367] port 2: assuming the grand master role Sep 03 09:29:03 OpenIL ptp4l[165]: [108.367] port 3: assuming the grand master role Sep 03 09:29:03 OpenIL ptp4l[165]: [108.367] port 4: assuming the grand master role Sep 03 09:30:09 OpenIL systemd[1]: Stopping Precision Time Protocol daemon... Sep 03 09:30:09 OpenIL systemd[1]: linuxptp.service: Succeeded. Sep 03 09:30:09 OpenIL systemd[1]: Stopped Precision Time Protocol daemon. Sep 03 09:30:09 OpenIL systemd[1]: linuxptp.service: Consumed 2.282s CPU time.

BOARD3 : [root@OpenIL ~] # journalctl -b -u linuxptp -f -- Logs begin at Thu 2019-10-10 12:56:03 UTC. -- Oct 10 13:04:52 OpenIL ptp4l[180]: [534.990] port 1: MASTER to FAULTY on FAULT_DETECTED (FT_UNSPECIFIED) Oct 10 13:04:52 OpenIL ptp4l[180]: [535.070] selected local clock 00049f.fffe.ef0606 as best master Oct 10 13:04:52 OpenIL ptp4l[180]: [535.071] port 1: assuming the grand master role Oct 10 13:05:08 OpenIL ptp4l[180]: [551.151] port 1: FAULTY to LISTENING on INIT_COMPLETE Oct 10 13:05:08 OpenIL ptp4l[180]: [551.361] clockcheck: clock jumped backward or running slower than expected! Oct 10 13:05:12 OpenIL ptp4l[180]: [555.091] port 1: announce timeout Oct 10 13:05:12 OpenIL ptp4l[180]: [555.091] bc_event 2683: returning EV_ANNOUNCE_RECEIPT_TIMEOUT_EXPIRES Oct 10 13:05:12 OpenIL ptp4l[180]: [555.091] port 1: LISTENING to MASTER on ANNOUNCE_RECEIPT_TIMEOUT_EXPIRES Oct 10 13:05:12 OpenIL ptp4l[180]: [555.091] selected local clock 00049f.fffe.ef0606 as best master Oct 10 13:05:12 OpenIL ptp4l[180]: [555.091] port 1: assuming the grand master role

According to this it seems like the boards are not communicating the time information within themself. But the ping to other boards works fine. How can i solve this issue?

Thanks in advance.

vladimiroltean commented 4 years ago

This is strange, sorry for the inconvenience. I think this is what is going on: When you run the ip link set dev br0 type bridge vlan_filtering 1 command, the driver does this:

[  379.897744] sja1105 spi0.1: Reset switch and programmed static config. Reason: VLAN filtering
[  379.908409] sja1105 spi0.1: Disabled switch tagging

The switch reset introduces a momentary disruption in the synchronization process. The PTP slaves then adjust their clocks to a sudden spike in PTP time, which makes their frequency adjustment stuck to a high value from which they don't recover. They keep printing the clockcheck messages. I reproduced this issue, and by restarting the ptp4l process with -l 7 for debugging output, I see:

ptp4l[103607.121]: port 1: drop erroneous nratio 0.898000, max offset 0.000200

So all further frequency adjustments are too large and get dropped.

As a workaround until I figure out how to recover automatically from this, can you please run on all 3 boards, in whatever order:

systemctl stop linuxptp
phc_ctl /dev/ptp0 freq 0 && phc_ctl /dev/ptp1 freq 0
systemctl start linuxptp

The above resets the frequency adjustment for the eTSEC PTP hardware clock (/dev/ptp0) and for the sja1105 PTP hardware clock (/dev/ptp1). It works fine afterwards for me.

sabarishsubramanian commented 4 years ago
systemctl stop linuxptp
phc_ctl /dev/ptp0 freq 0 && phc_ctl /dev/ptp1 freq 0
systemctl start linuxptp

i ran this above commands

and gave

$ journalctl -b -u linuxptp -f

BOARD 1

[root@OpenIL ~] # journalctl -b -u linuxptp -f
-- Logs begin at Thu 2019-10-10 12:56:03 UTC. --
Oct 10 13:59:57 OpenIL ptp4l[327]: [3841.097] port 1: announce timeout
Oct 10 13:59:57 OpenIL ptp4l[327]: [3841.097] bc_event 2683: returning EV_ANNOUNCE_RECEIPT_TIMEOUT_EXPIRES
Oct 10 13:59:57 OpenIL ptp4l[327]: [3841.097] port 1: LISTENING to MASTER on ANNOUNCE_RECEIPT_TIMEOUT_EXPIRES
Oct 10 13:59:57 OpenIL ptp4l[327]: [3841.097] selected local clock 00049f.fffe.ef0000 as best master
Oct 10 13:59:57 OpenIL ptp4l[327]: [3841.097] port 1: assuming the grand master role
Oct 10 13:59:59 OpenIL ptp4l[327]: [3842.756] port 1: new foreign master 00049f.fffe.ef0505-2
Oct 10 13:59:59 OpenIL ptp4l[327]: [3842.756] selected best master clock 00049f.fffe.ef0505
Oct 10 13:59:59 OpenIL ptp4l[327]: [3842.756] port 1: assuming the grand master role
Oct 10 14:00:03 OpenIL ptp4l[327]: [3846.758] selected best master clock 00049f.fffe.ef0505
Oct 10 14:00:03 OpenIL ptp4l[327]: [3846.758] port 1: assuming the grand master role

BOARD 2

[root@OpenIL ~] # journalctl -b -u linuxptp -f
-- Logs begin at Tue 2019-09-03 09:27:20 UTC. --
Sep 03 10:53:47 OpenIL ptp4l[307]: [5192.617] clockcheck: clock jumped backward or running slower than expected!
Sep 03 10:53:47 OpenIL ptp4l[307]: [5192.617] port 2: SLAVE to UNCALIBRATED on SYNCHRONIZATION_FAULT
Sep 03 10:53:47 OpenIL ptp4l[307]: [5192.743] clockcheck: clock jumped forward or running faster than expected!
Sep 03 10:53:47 OpenIL ptp4l[307]: [5192.868] port 2: UNCALIBRATED to SLAVE on MASTER_CLOCK_SELECTED
Sep 03 10:53:48 OpenIL ptp4l[307]: [5193.119] rms 3037000489 max 8589934561 freq -25266 +/-  32 delay   626 +/-   0
Sep 03 10:53:49 OpenIL ptp4l[307]: [5193.996] clockcheck: clock jumped backward or running slower than expected!
Sep 03 10:53:49 OpenIL ptp4l[307]: [5193.996] port 2: SLAVE to UNCALIBRATED on SYNCHRONIZATION_FAULT
Sep 03 10:53:49 OpenIL ptp4l[307]: [5194.121] clockcheck: clock jumped forward or running faster than expected!
Sep 03 10:53:49 OpenIL ptp4l[307]: [5194.122] rms 3037000483 max 8589934544 freq -25252 +/-  13 delay   626 +/-   0
Sep 03 10:53:49 OpenIL ptp4l[307]: [5194.247] port 2: UNCALIBRATED to SLAVE on MASTER_CLOCK_SELECTED
Sep 03 10:53:50 OpenIL ptp4l[307]: [5195.124] clockcheck: clock jumped forward or running faster than expected!
Sep 03 10:53:50 OpenIL ptp4l[307]: [5195.124] rms 3037000506 max 8589934610 freq -25218 +/-  21 delay   626 +/-   0
Sep 03 10:53:50 OpenIL ptp4l[307]: [5195.125] port 2: SLAVE to UNCALIBRATED on SYNCHRONIZATION_FAULT
Sep 03 10:53:50 OpenIL ptp4l[307]: [5195.249] clockcheck: clock jumped backward or running slower than expected!
Sep 03 10:53:50 OpenIL ptp4l[307]: [5195.375] port 2: UNCALIBRATED to SLAVE on MASTER_CLOCK_SELECTED
Sep 03 10:53:51 OpenIL ptp4l[307]: [5196.128] rms   12 max   18 freq -25235 +/-  11 delay   626 +/-   0
Sep 03 10:53:51 OpenIL ptp4l[307]: [5196.754] clockcheck: clock jumped backward or running slower than expected!
Sep 03 10:53:51 OpenIL ptp4l[307]: [5196.754] port 2: SLAVE to UNCALIBRATED on SYNCHRONIZATION_FAULT
Sep 03 10:53:51 OpenIL ptp4l[307]: [5196.881] clockcheck: clock jumped forward or running faster than expected!
Sep 03 10:53:52 OpenIL ptp4l[307]: [5197.005] port 2: UNCALIBRATED to SLAVE on MASTER_CLOCK_SELECTED
Sep 03 10:53:52 OpenIL ptp4l[307]: [5197.130] rms 3796250625 max 10737418240 freq -25241 +/-   5 delay   626 +/-   0
Sep 03 10:53:53 OpenIL ptp4l[307]: [5198.133] rms    8 max   11 freq -25250 +/-   5 delay   625 +/-   0
Sep 03 10:53:53 OpenIL ptp4l[307]: [5198.258] clockcheck: clock jumped backward or running slower than expected!
Sep 03 10:53:53 OpenIL ptp4l[307]: [5198.259] port 2: SLAVE to UNCALIBRATED on SYNCHRONIZATION_FAULT
Sep 03 10:53:53 OpenIL ptp4l[307]: [5198.383] clockcheck: clock jumped forward or running faster than expected!
Sep 03 10:53:53 OpenIL ptp4l[307]: [5198.509] port 2: UNCALIBRATED to SLAVE on MASTER_CLOCK_SELECTED
Sep 03 10:53:54 OpenIL ptp4l[307]: [5199.136] rms 3796250625 max 10737418240 freq -25212 +/-  32 delay   624 +/-   0
Sep 03 10:53:55 OpenIL ptp4l[307]: [5200.138] rms   37 max   41 freq -25253 +/-  13 delay   625 +/-   0
Sep 03 10:53:55 OpenIL ptp4l[307]: [5200.891] clockcheck: clock jumped backward or running slower than expected!
Sep 03 10:53:55 OpenIL ptp4l[307]: [5200.892] port 2: SLAVE to UNCALIBRATED on SYNCHRONIZATION_FAULT
Sep 03 10:53:56 OpenIL ptp4l[307]: [5201.141] clockcheck: clock jumped forward or running faster than expected!
Sep 03 10:53:56 OpenIL ptp4l[307]: [5201.141] rms 8547888651 max 13958643725 freq -25254 +/-  15 delay   624 +/-   0
Sep 03 10:53:56 OpenIL ptp4l[307]: [5201.392] port 2: UNCALIBRATED to SLAVE on MASTER_CLOCK_SELECTED
Sep 03 10:53:57 OpenIL ptp4l[307]: [5202.145] rms 4935125805 max 13958643692 freq -25255 +/-   5 delay   623 +/-   0
Sep 03 10:53:58 OpenIL ptp4l[307]: [5203.147] rms    7 max   12 freq -25245 +/-   5 delay   623 +/-   0
Sep 03 10:53:59 OpenIL ptp4l[307]: [5204.151] rms    6 max   13 freq -25241 +/-   5 delay   623 +/-   0
Sep 03 10:54:00 OpenIL ptp4l[307]: [5205.153] rms    4 max    8 freq -25245 +/-   6 delay   623 +/-   0
Sep 03 10:54:01 OpenIL ptp4l[307]: [5206.156] rms    5 max    8 freq -25247 +/-   7 delay   623 +/-   0
Sep 03 10:54:02 OpenIL ptp4l[307]: [5207.158] rms    3 max    7 freq -25242 +/-   3 delay   624 +/-   0
Sep 03 10:54:03 OpenIL ptp4l[307]: [5208.162] rms    5 max   10 freq -25249 +/-   6 delay   625 +/-   0
Sep 03 10:54:04 OpenIL ptp4l[307]: [5209.165] rms    2 max    4 freq -25250 +/-   2 delay   625 +/-   0
Sep 03 10:54:05 OpenIL ptp4l[307]: [5210.167] rms    6 max   12 freq -25250 +/-   8 delay   625 +/-   0
Sep 03 10:54:06 OpenIL ptp4l[307]: [5211.170] rms    4 max    6 freq -25248 +/-   5 delay   625 +/-   0
Sep 03 10:54:07 OpenIL ptp4l[307]: [5212.173] rms    6 max    9 freq -25240 +/-   5 delay   625 +/-   0
Sep 03 10:54:08 OpenIL ptp4l[307]: [5213.176] rms    3 max    8 freq -25246 +/-   4 delay   625 +/-   0
Sep 03 10:54:09 OpenIL ptp4l[307]: [5214.179] rms    5 max   11 freq -25249 +/-   6 delay   625 +/-   0
Sep 03 10:54:10 OpenIL ptp4l[307]: [5215.181] rms    5 max    8 freq -25242 +/-   6 delay   625 +/-   0
Sep 03 10:54:11 OpenIL ptp4l[307]: [5216.184] rms    3 max    5 freq -25247 +/-   3 delay   626 +/-   0
Sep 03 10:54:12 OpenIL ptp4l[307]: [5217.187] rms    5 max    9 freq -25249 +/-   7 delay   625 +/-   0
Sep 03 10:54:13 OpenIL ptp4l[307]: [5218.190] rms    5 max   10 freq -25248 +/-   7 delay   625 +/-   0
Sep 03 10:54:14 OpenIL ptp4l[307]: [5219.193] rms    8 max   12 freq -25244 +/-  11 delay   625 +/-   0
Sep 03 10:54:15 OpenIL ptp4l[307]: [5220.196] rms    7 max   13 freq -25257 +/-   6 delay   624 +/-   0
Sep 03 10:54:16 OpenIL ptp4l[307]: [5221.199] rms    4 max    8 freq -25248 +/-   5 delay   624 +/-   0
Sep 03 10:54:17 OpenIL ptp4l[307]: [5222.201] rms    4 max   10 freq -25249 +/-   5 delay   624 +/-   0
Sep 03 10:54:18 OpenIL ptp4l[307]: [5223.205] rms    4 max    7 freq -25246 +/-   5 delay   624 +/-   0
Sep 03 10:54:18 OpenIL ptp4l[307]: [5223.705] clockcheck: clock jumped backward or running slower than expected!
Sep 03 10:54:18 OpenIL ptp4l[307]: [5223.708] port 2: SLAVE to UNCALIBRATED on SYNCHRONIZATION_FAULT
Sep 03 10:54:18 OpenIL ptp4l[307]: [5223.831] clockcheck: clock jumped forward or running faster than expected!
Sep 03 10:54:19 OpenIL ptp4l[307]: [5223.959] port 2: UNCALIBRATED to SLAVE on MASTER_CLOCK_SELECTED
Sep 03 10:54:19 OpenIL ptp4l[307]: [5224.209] rms    6 max   10 freq -25251 +/-  18 delay   625 +/-   0
Sep 03 10:54:20 OpenIL ptp4l[307]: [5225.212] rms   13 max   22 freq -25253 +/-   9 delay   626 +/-   0
Sep 03 10:54:21 OpenIL ptp4l[307]: [5226.218] rms   13 max   21 freq -25239 +/-   4 delay   626 +/-   0
Sep 03 10:54:21 OpenIL ptp4l[307]: [5226.709] clockcheck: clock jumped forward or running faster than expected!
Sep 03 10:54:21 OpenIL ptp4l[307]: [5226.718] port 2: SLAVE to UNCALIBRATED on SYNCHRONIZATION_FAULT
Sep 03 10:54:21 OpenIL ptp4l[307]: [5226.835] clockcheck: clock jumped backward or running slower than expected!
Sep 03 10:54:22 OpenIL ptp4l[307]: [5226.969] port 2: UNCALIBRATED to SLAVE on MASTER_CLOCK_SELECTED
Sep 03 10:54:22 OpenIL ptp4l[307]: [5227.220] rms 3037000498 max 8589934586 freq -25244 +/-   8 delay   626 +/-   0
Sep 03 10:54:22 OpenIL ptp4l[307]: [5227.713] clockcheck: clock jumped backward or running slower than expected!
Sep 03 10:54:22 OpenIL ptp4l[307]: [5227.721] port 2: SLAVE to UNCALIBRATED on SYNCHRONIZATION_FAULT
Sep 03 10:54:22 OpenIL ptp4l[307]: [5227.838] clockcheck: clock jumped forward or running faster than expected!
^C

BOARD 3

[root@OpenIL ~] # journalctl -b -u linuxptp -f
-- Logs begin at Thu 2019-10-10 12:56:03 UTC. --
Oct 10 14:03:10 OpenIL ptp4l[288]: [4033.949] rms 21387010 max 50331962 freq  -4417 +/- 164 delay   634 +/-   0
Oct 10 14:03:11 OpenIL ptp4l[288]: [4034.954] rms  232 max  412 freq  -3827 +/- 128 delay   635 +/-   0
Oct 10 14:03:12 OpenIL ptp4l[288]: [4035.958] rms   91 max  121 freq  -4181 +/-  68 delay   635 +/-   0
Oct 10 14:03:13 OpenIL ptp4l[288]: [4036.963] rms  101 max  117 freq  -4310 +/-  14 delay   634 +/-   0
Oct 10 14:03:14 OpenIL ptp4l[288]: [4037.965] rms 38555647 max 109051837 freq  -4281 +/-  45 delay   634 +/-   0
Oct 10 14:03:15 OpenIL ptp4l[288]: [4038.970] rms 4294967294 max 8589934643 freq  -4286 +/-  41 delay   636 +/-   0
Oct 10 14:03:16 OpenIL ptp4l[288]: [4039.974] rms   36 max   40 freq  -4273 +/-  12 delay   636 +/-   0
Oct 10 14:03:17 OpenIL ptp4l[288]: [4040.977] rms   25 max   31 freq  -4291 +/-   5 delay   636 +/-   0
Oct 10 14:03:18 OpenIL ptp4l[288]: [4041.981] rms 11863275 max 33554409 freq  -4304 +/-   8 delay   635 +/-   0
Oct 10 14:03:19 OpenIL ptp4l[288]: [4042.989] rms 3037000499 max 8589934589 freq  -4293 +/-  21 delay   636 +/-   0
Oct 10 14:03:20 OpenIL ptp4l[288]: [4043.992] rms 3037000504 max 8589934602 freq  -4256 +/-  19 delay   635 +/-   0
Oct 10 14:03:22 OpenIL ptp4l[288]: [4044.996] rms 3037113406 max 8589934619 freq +8188782 +/- 14190818 delay   634 +/-   0
Oct 10 14:03:23 OpenIL ptp4l[288]: [4046.000] rms 38366633 max 66671562 freq +8188398 +/- 14191039 delay   634 +/-   0
Oct 10 14:03:23 OpenIL ptp4l[288]: [4046.501] port 1: rx sync timeout
Oct 10 14:03:23 OpenIL ptp4l[288]: [4046.501] bc_event 2683: returning EV_ANNOUNCE_RECEIPT_TIMEOUT_EXPIRES
Oct 10 14:03:23 OpenIL ptp4l[288]: [4046.501] port 1: SLAVE to MASTER on ANNOUNCE_RECEIPT_TIMEOUT_EXPIRES
Oct 10 14:03:23 OpenIL ptp4l[288]: [4046.502] selected local clock 00049f.fffe.ef0606 as best master
Oct 10 14:03:23 OpenIL ptp4l[288]: [4046.502] port 1: assuming the grand master role
Oct 10 14:03:27 OpenIL ptp4l[288]: [4050.094] selected best master clock 00049f.fffe.ef0000
Oct 10 14:03:27 OpenIL ptp4l[288]: [4050.094] port 1: MASTER to SLAVE on RS_SLAVE
Oct 10 14:03:28 OpenIL ptp4l[288]: [4051.647] rms 11864410 max 33557619 freq   -825 +/- 5133 delay   633 +/-   0
Oct 10 14:03:29 OpenIL ptp4l[288]: [4052.651] rms 7517222610 max 15036352053 freq +8188394 +/- 14191042 delay   633 +/-   0
Oct 10 14:03:30 OpenIL ptp4l[288]: [4053.655] rms 9212885490 max 15048691197 freq +8188416 +/- 14191029 delay   633 +/-   0
Oct 10 14:03:31 OpenIL ptp4l[288]: [4054.658] rms  388 max  739 freq  -5120 +/- 280 delay   633 +/-   0
Oct 10 14:03:32 OpenIL ptp4l[288]: [4055.662] rms  222 max  267 freq  -4405 +/- 133 delay   633 +/-   0
Oct 10 14:03:33 OpenIL ptp4l[288]: [4056.665] rms  221 max  261 freq  -4151 +/-  25 delay   633 +/-   0
Oct 10 14:03:34 OpenIL ptp4l[288]: [4057.669] rms  100 max  145 freq  -4157 +/-  18 delay   632 +/-   0
Oct 10 14:03:35 OpenIL ptp4l[288]: [4058.673] rms 44487316 max 125829131 freq  -4214 +/-  13 delay   632 +/-   0
Oct 10 14:03:36 OpenIL ptp4l[288]: [4059.677] rms 11863276 max 33554412 freq  -4280 +/-  28 delay   632 +/-   0
Oct 10 14:03:37 OpenIL ptp4l[288]: [4060.680] rms    7 max   11 freq  -4286 +/-   9 delay   634 +/-   0
Oct 10 14:03:38 OpenIL ptp4l[288]: [4061.684] rms   13 max   27 freq  -4262 +/-  10 delay   634 +/-   0
Oct 10 14:03:39 OpenIL ptp4l[288]: [4062.688] rms   11 max   19 freq  -4254 +/-   7 delay   633 +/-   0
Oct 10 14:03:40 OpenIL ptp4l[288]: [4063.692] rms    6 max   12 freq  -4264 +/-   9 delay   633 +/-   0
Oct 10 14:03:41 OpenIL ptp4l[288]: [4064.696] rms    3 max    5 freq  -4263 +/-   4 delay   633 +/-   0
Oct 10 14:03:42 OpenIL ptp4l[288]: [4065.700] rms    5 max    8 freq  -4266 +/-   7 delay   633 +/-   0
Oct 10 14:03:43 OpenIL ptp4l[288]: [4066.704] rms 14829104 max 41943040 freq  -4263 +/-  10 delay   634 +/-   0
Oct 10 14:03:44 OpenIL ptp4l[288]: [4067.707] rms   11 max   16 freq  -4268 +/-   9 delay   635 +/-   0
Oct 10 14:03:45 OpenIL ptp4l[288]: [4068.713] rms    4 max    7 freq  -4267 +/-   3 delay   635 +/-   0
Oct 10 14:03:46 OpenIL ptp4l[288]: [4069.717] rms    8 max   12 freq  -4275 +/-   8 delay   635 +/-   0
Oct 10 14:03:47 OpenIL ptp4l[288]: [4070.721] rms 17794923 max 50331644 freq  -4235 +/-  45 delay   634 +/-   0
Oct 10 14:03:48 OpenIL ptp4l[288]: [4071.725] rms   42 max   46 freq  -4260 +/-  15 delay   635 +/-   0
Oct 10 14:03:49 OpenIL ptp4l[288]: [4072.728] rms 3037268708 max 8589934545 freq -8195198 +/- 14187113 delay   635 +/-   0
Oct 10 14:03:50 OpenIL ptp4l[288]: [4073.736] rms 3036958875 max 8589804002 freq -4100445 +/- 10835317 delay   636 +/-   0
Oct 10 14:03:51 OpenIL ptp4l[288]: [4074.739] rms 11863250 max 33554338 freq  -5007 +/- 678 delay   636 +/-   0
Oct 10 14:03:52 OpenIL ptp4l[288]: [4075.744] rms 3037000465 max 8589934493 freq  -4057 +/- 175 delay   635 +/-   0
Oct 10 14:03:53 OpenIL ptp4l[288]: [4076.747] rms 11863246 max 33554328 freq  -4322 +/- 102 delay   635 +/-   0
Oct 10 14:03:54 OpenIL ptp4l[288]: [4077.751] rms 4294967298 max 8589934693 freq  -4228 +/-  63 delay   635 +/-   0
^C

i can still see its not yet synchronized

vladimiroltean commented 4 years ago

Can you do the following: Boot the board acting as a switch (2) first. Keep the ptp4l logging open. Boot the board acting as a GM (1). Watch the ptp4l process on board 2 while it synchronizes to the GM. Boot the board acting as slave (3). Watch it again until it synchronizes through the switch to the GM. Everything should be fine at this point. Then, while you run the setup commands on board 2, can you monitor the other two, to see which one appears to break the synchronization?

sabarishsubramanian commented 4 years ago

Hello @vladimiroltean

I tried to do the above steps

after doing the first two steps only i got this in each board

Board 2

[root@OpenIL ~] # journalctl -b -u linuxptp -f
-- Logs begin at Tue 2019-09-03 09:27:20 UTC. --
Sep 03 09:27:28 OpenIL ptp4l[166]: [13.505] port 2: LISTENING to FAULTY on FAULT_DETECTED (FT_UNSPECIFIED)
Sep 03 09:27:28 OpenIL ptp4l[166]: [13.572] port 3: link down
Sep 03 09:27:28 OpenIL ptp4l[166]: [13.573] port 3: LISTENING to FAULTY on FAULT_DETECTED (FT_UNSPECIFIED)
Sep 03 09:27:29 OpenIL ptp4l[166]: [13.671] port 4: link down
Sep 03 09:27:29 OpenIL ptp4l[166]: [13.672] port 4: LISTENING to FAULTY on FAULT_DETECTED (FT_UNSPECIFIED)
Sep 03 09:27:29 OpenIL ptp4l[166]: [13.750] selected local clock 00049f.fffe.ef0505 as best master
Sep 03 09:27:29 OpenIL ptp4l[166]: [13.750] port 1: assuming the grand master role
Sep 03 09:27:29 OpenIL ptp4l[166]: [13.750] port 2: assuming the grand master role
Sep 03 09:27:29 OpenIL ptp4l[166]: [13.750] port 3: assuming the grand master role
Sep 03 09:27:29 OpenIL ptp4l[166]: [13.751] port 4: assuming the grand master role
Sep 03 09:28:38 OpenIL ptp4l[166]: [83.229] port 2: link up
Sep 03 09:28:38 OpenIL ptp4l[166]: [83.341] port 2: FAULTY to LISTENING on INIT_COMPLETE
Sep 03 09:28:42 OpenIL ptp4l[166]: [87.320] port 2: LISTENING to MASTER on ANNOUNCE_RECEIPT_TIMEOUT_EXPIRES
Sep 03 09:28:42 OpenIL ptp4l[166]: [87.320] selected local clock 00049f.fffe.ef0505 as best master
Sep 03 09:28:42 OpenIL ptp4l[166]: [87.321] port 1: assuming the grand master role
Sep 03 09:28:42 OpenIL ptp4l[166]: [87.321] port 2: assuming the grand master role
Sep 03 09:28:42 OpenIL ptp4l[166]: [87.321] port 3: assuming the grand master role
Sep 03 09:28:42 OpenIL ptp4l[166]: [87.321] port 4: assuming the grand master role
Sep 03 09:29:07 OpenIL ptp4l[166]: [112.336] port 2: link down
Sep 03 09:29:07 OpenIL ptp4l[166]: [112.336] port 2: MASTER to FAULTY on FAULT_DETECTED (FT_UNSPECIFIED)
Sep 03 09:29:07 OpenIL ptp4l[166]: [112.380] selected local clock 00049f.fffe.ef0505 as best master
Sep 03 09:29:07 OpenIL ptp4l[166]: [112.380] port 1: assuming the grand master role
Sep 03 09:29:07 OpenIL ptp4l[166]: [112.381] port 2: assuming the grand master role
Sep 03 09:29:07 OpenIL ptp4l[166]: [112.381] port 3: assuming the grand master role
Sep 03 09:29:07 OpenIL ptp4l[166]: [112.381] port 4: assuming the grand master role
Sep 03 09:29:07 OpenIL ptp4l[166]: [112.382] selected local clock 00049f.fffe.ef0505 as best master
Sep 03 09:29:07 OpenIL ptp4l[166]: [112.382] port 1: assuming the grand master role
Sep 03 09:29:07 OpenIL ptp4l[166]: [112.382] port 2: assuming the grand master role
Sep 03 09:29:07 OpenIL ptp4l[166]: [112.382] port 3: assuming the grand master role
Sep 03 09:29:07 OpenIL ptp4l[166]: [112.382] port 4: assuming the grand master role
Sep 03 09:29:13 OpenIL ptp4l[166]: [118.583] port 2: link up
Sep 03 09:29:14 OpenIL ptp4l[166]: [118.661] port 2: FAULTY to LISTENING on INIT_COMPLETE
Sep 03 09:29:17 OpenIL ptp4l[166]: [121.702] port 2: new foreign master 00049f.fffe.ef0000-1
Sep 03 09:29:17 OpenIL ptp4l[166]: [122.013] port 2: LISTENING to MASTER on ANNOUNCE_RECEIPT_TIMEOUT_EXPIRES
Sep 03 09:29:17 OpenIL ptp4l[166]: [122.013] selected local clock 00049f.fffe.ef0505 as best master
Sep 03 09:29:17 OpenIL ptp4l[166]: [122.013] port 1: assuming the grand master role
Sep 03 09:29:17 OpenIL ptp4l[166]: [122.015] port 2: assuming the grand master role
Sep 03 09:29:17 OpenIL ptp4l[166]: [122.016] port 3: assuming the grand master role
Sep 03 09:29:17 OpenIL ptp4l[166]: [122.016] port 4: assuming the grand master role
Sep 03 09:29:19 OpenIL ptp4l[166]: [123.702] selected best master clock 00049f.fffe.ef0000
Sep 03 09:29:19 OpenIL ptp4l[166]: [123.702] port 2: MASTER to UNCALIBRATED on RS_SLAVE
Sep 03 09:29:20 OpenIL ptp4l[166]: [124.963] port 2: UNCALIBRATED to SLAVE on MASTER_CLOCK_SELECTED
Sep 03 09:29:21 OpenIL ptp4l[166]: [125.590] clockcheck: clock jumped forward or running faster than expected!
Sep 03 09:29:21 OpenIL ptp4l[166]: [125.592] rms 47816127266 max 95523692514 freq -22833 +/- 8630 delay   626 +/-   0
Sep 03 09:29:21 OpenIL ptp4l[166]: [125.593] port 2: SLAVE to UNCALIBRATED on SYNCHRONIZATION_FAULT
Sep 03 09:29:21 OpenIL ptp4l[166]: [125.715] clockcheck: clock jumped backward or running slower than expected!
Sep 03 09:29:21 OpenIL ptp4l[166]: [125.842] port 2: UNCALIBRATED to SLAVE on MASTER_CLOCK_SELECTED
Sep 03 09:29:22 OpenIL ptp4l[166]: [126.593] rms   27 max   43 freq -26030 +/-  36 delay   625 +/-   0
Sep 03 09:29:22 OpenIL ptp4l[166]: [127.094] clockcheck: clock jumped forward or running faster than expected!
Sep 03 09:29:22 OpenIL ptp4l[166]: [127.094] port 2: SLAVE to UNCALIBRATED on SYNCHRONIZATION_FAULT
Sep 03 09:29:22 OpenIL ptp4l[166]: [127.219] clockcheck: clock jumped backward or running slower than expected!
Sep 03 09:29:22 OpenIL ptp4l[166]: [127.346] port 2: UNCALIBRATED to SLAVE on MASTER_CLOCK_SELECTED
Sep 03 09:29:23 OpenIL ptp4l[166]: [127.596] rms 1518500238 max 4294967261 freq -26044 +/-  16 delay   623 +/-   0
Sep 03 09:29:24 OpenIL ptp4l[166]: [128.599] rms   24 max   38 freq -26053 +/-  13 delay   625 +/-   0
Sep 03 09:29:24 OpenIL ptp4l[166]: [129.476] clockcheck: clock jumped backward or running slower than expected!
Sep 03 09:29:24 OpenIL ptp4l[166]: [129.476] port 2: SLAVE to UNCALIBRATED on SYNCHRONIZATION_FAULT
Sep 03 09:29:25 OpenIL ptp4l[166]: [129.601] clockcheck: clock jumped forward or running faster than expected!
Sep 03 09:29:25 OpenIL ptp4l[166]: [129.602] rms 4935125812 max 13958643710 freq -26042 +/-   8 delay   623 +/-   0
Sep 03 09:29:25 OpenIL ptp4l[166]: [129.727] port 2: UNCALIBRATED to SLAVE on MASTER_CLOCK_SELECTED
Sep 03 09:29:26 OpenIL ptp4l[166]: [130.604] rms   38 max   60 freq -26059 +/-  36 delay   625 +/-   0
Sep 03 09:29:26 OpenIL ptp4l[166]: [130.729] clockcheck: clock jumped backward or running slower than expected!
Sep 03 09:29:26 OpenIL ptp4l[166]: [130.730] port 2: SLAVE to UNCALIBRATED on SYNCHRONIZATION_FAULT
Sep 03 09:29:26 OpenIL ptp4l[166]: [130.855] clockcheck: clock jumped forward or running faster than expected!
Sep 03 09:29:26 OpenIL ptp4l[166]: [130.981] port 2: UNCALIBRATED to SLAVE on MASTER_CLOCK_SELECTED
Sep 03 09:29:26 OpenIL ptp4l[166]: [131.231] clockcheck: clock jumped backward or running slower than expected!
Sep 03 09:29:26 OpenIL ptp4l[166]: [131.231] port 2: SLAVE to UNCALIBRATED on SYNCHRONIZATION_FAULT
Sep 03 09:29:26 OpenIL ptp4l[166]: [131.349] clockcheck: clock jumped forward or running faster than expected!
Sep 03 09:29:26 OpenIL ptp4l[166]: [131.482] port 2: UNCALIBRATED to SLAVE on MASTER_CLOCK_SELECTED
Sep 03 09:29:27 OpenIL ptp4l[166]: [131.607] rms 8589934562 max 17179869131 freq -26042 +/-  51 delay   625 +/-   0
Sep 03 09:29:27 OpenIL ptp4l[166]: [131.858] clockcheck: clock jumped backward or running slower than expected!
Sep 03 09:29:27 OpenIL ptp4l[166]: [131.858] port 2: SLAVE to UNCALIBRATED on SYNCHRONIZATION_FAULT
Sep 03 09:29:27 OpenIL ptp4l[166]: [131.983] clockcheck: clock jumped forward or running faster than expected!
Sep 03 09:29:27 OpenIL ptp4l[166]: [132.109] port 2: UNCALIBRATED to SLAVE on MASTER_CLOCK_SELECTED
Sep 03 09:29:28 OpenIL ptp4l[166]: [132.612] rms 6074000969 max 17179869097 freq -25965 +/-  38 delay   625 +/-   0

So i didnt proceed to step 3 and later

can you please help me out of it

Thanks in advance

Regards sabarish s

vladimiroltean commented 4 years ago

Does the synchronization work directly between boards 1 and 3 (eth0 and eth0)?

sabarishsubramanian commented 4 years ago

Does the synchronization work directly between boards 1 and 3 (eth0 and eth0)?

I have the connection same which was mentioned by you

Just for an interface am using a switch so that i can connect it wirelessly through ssh at eth1 in all boards

But rest of the connections are same as you mentioned above.

BOARD 1

[root@OpenIL ~] # ptp4l -f /etc/linuxptp.cfg -m
ptp4l[5448.262]: selected /dev/ptp0 as PTP clock
ptp4l[5448.341]: port 1: INITIALIZING to LISTENING on INIT_COMPLETE
ptp4l[5448.344]: port 0: INITIALIZING to LISTENING on INIT_COMPLETE
ptp4l[5451.527]: port 1: announce timeout
ptp4l[5451.528]: bc_event 2683: returning EV_ANNOUNCE_RECEIPT_TIMEOUT_EXPIRES
ptp4l[5451.529]: port 1: LISTENING to MASTER on ANNOUNCE_RECEIPT_TIMEOUT_EXPIRES
ptp4l[5451.531]: selected local clock 00049f.fffe.ef0000 as best master
ptp4l[5451.532]: port 1: assuming the grand master role

BOARD 3

[root@OpenIL ~] # ptp4l -f /etc/linuxptp.cfg -m
ptp4l[5450.221]: selected /dev/ptp0 as PTP clock
ptp4l[5450.311]: port 1: INITIALIZING to LISTENING on INIT_COMPLETE
ptp4l[5450.313]: port 0: INITIALIZING to LISTENING on INIT_COMPLETE
ptp4l[5453.734]: port 1: new foreign master 00049f.fffe.ef0000-1
ptp4l[5453.734]: selected best master clock 00049f.fffe.ef0000
ptp4l[5453.734]: port 1: LISTENING to SLAVE on RS_SLAVE
ptp4l[5455.241]: rms 316374926 max 632750120 freq -4784 +/- 1879 delay 780 +/- 0
ptp4l[5456.244]: rms 168 max 254 freq -4778 +/- 232 delay 781 +/- 0
ptp4l[5457.247]: rms 276 max 289 freq -4266 +/- 80 delay 781 +/- 0
ptp4l[5458.251]: rms 177 max 229 freq -4163 +/- 9 delay 781 +/- 0
ptp4l[5459.253]: rms 58 max 94 freq -4214 +/- 19 delay 781 +/- 0
ptp4l[5460.255]: rms 10 max 14 freq -4274 +/- 12 delay 781 +/- 0
ptp4l[5461.258]: rms 15 max 20 freq -4299 +/- 6 delay 780 +/- 0
ptp4l[5462.261]: rms 12 max 21 freq -4308 +/- 6 delay 781 +/- 0
ptp4l[5463.264]: rms 3 max 6 freq -4302 +/- 4 delay 781 +/- 0
ptp4l[5464.267]: rms 3 max 6 freq -4303 +/- 4 delay 781 +/- 0
ptp4l[5465.269]: rms 3 max 6 freq -4302 +/- 5 delay 781 +/- 0
ptp4l[5466.272]: rms 4 max 5 freq -4299 +/- 4 delay 780 +/- 0
ptp4l[5467.276]: rms 4 max 10 freq -4299 +/- 5 delay 780 +/- 0
ptp4l[5468.279]: rms 4 max 6 freq -4301 +/- 5 delay 781 +/- 0
ptp4l[5469.282]: rms 4 max 6 freq -4302 +/- 5 delay 781 +/- 0
ptp4l[5470.284]: rms 3 max 7 freq -4302 +/- 5 delay 782 +/- 0
ptp4l[5471.287]: rms 3 max 3 freq -4298 +/- 3 delay 782 +/- 0
ptp4l[5472.291]: rms 4 max 7 freq -4297 +/- 5 delay 782 +/- 0
ptp4l[5473.293]: rms 4 max 8 freq -4297 +/- 6 delay 782 +/- 0
ptp4l[5474.296]: rms 4 max 8 freq -4294 +/- 6 delay 782 +/- 0
ptp4l[5475.299]: rms 4 max 7 freq -4297 +/- 6 delay 782 +/- 0
ptp4l[5476.302]: rms 2 max 3 freq -4296 +/- 3 delay 782 +/- 0
ptp4l[5477.305]: rms 3 max 7 freq -4298 +/- 4 delay 782 +/- 0
ptp4l[5478.308]: rms 5 max 7 freq -4302 +/- 6 delay 782 +/- 0
^C
sabarishsubramanian commented 4 years ago

Hey

There is synchronization happening between board 1 and 3 when i connect the ETH0 board 1 to ETH0 of board 3.

But later i tried to do with board 1 and 2 ETH0 OF BAORD 1 TO eth 3 of board 2 removing board 3 from the setup

and board 2 and 3 ETh 2 of board 2 to eth0 of board 3 removing board 1 from setup.

In both the cases board 2 is not synchronising.

Is there any problem with the bridge of board 2 because i dont think there is problem with the boards.

I read in one of your thread to reduce the spi max freq from 12mhz to 6 mhz i even did that.

Kindly help me out.

Thanks

regards sabarish s

vladimiroltean commented 4 years ago

Why did you reduce the SPI frequency? What other changes have you made?

sabarishsubramanian commented 4 years ago

I changed because 12mhzwas not working for me also so i one of the thread i saw u asked to lower the freqz to 6mhz so i did it

just that one change i did nothing else

vladimiroltean commented 4 years ago

What do you mean "was not working"? What was not working?

sabarishsubramanian commented 4 years ago

https://github.com/openil/openil/issues/27#issuecomment-550352870

I am continuing this project and i got the same error so is saw you asked to reduce spi freq

vladimiroltean commented 4 years ago

Yes but that was just to understand if the SPI bus is the problem or not. It is not a proper solution to reduce the SPI frequency to half. I also never heard back on that thread. There is a lot of SPI communication going on for PTP and it needs to happen pretty fast for reliable synchronization. I will test the boards at 6 MHz and see if I reproduce your issues. Do all 3 boards need the reduced SPI frequency?

vladimiroltean commented 4 years ago

Is the power plug grounded? Is the microUSB cable plugged in?

sabarishsubramanian commented 4 years ago
# dmesg
[    0.000000] Booting Linux on physical CPU 0xf00
[    0.000000] Linux version 5.5.0-rc1 (ssubramanian@ii-tsn2) (gcc version 8.3.0 (Buildroot 2019.11-git-g2b2c0eb694)) #1 SMP Mon Dec 16 14:22:29 CET 2019
[    0.000000] CPU: ARMv7 Processor [410fc075] revision 5 (ARMv7), cr=10c5387d
[    0.000000] CPU: div instructions available: patching division code
[    0.000000] CPU: PIPT / VIPT nonaliasing data cache, VIPT aliasing instruction cache
[    0.000000] OF: fdt: Machine model: NXP LS1021A-TSN Board
[    0.000000] Memory policy: Data cache writealloc
[    0.000000] efi: Getting EFI parameters from FDT:
[    0.000000] efi: UEFI not found.
[    0.000000] cma: Reserved 64 MiB at 0xbc000000
[    0.000000] On node 0 totalpages: 262144
[    0.000000]   DMA zone: 1728 pages used for memmap
[    0.000000]   DMA zone: 0 pages reserved
[    0.000000]   DMA zone: 196608 pages, LIFO batch:63
[    0.000000]   HighMem zone: 65536 pages, LIFO batch:15
[    0.000000] psci: probing for conduit method from DT.
[    0.000000] psci: Using PSCI v0.1 Function IDs from DT
[    0.000000] percpu: Embedded 21 pages/cpu s54056 r8192 d23768 u86016
[    0.000000] pcpu-alloc: s54056 r8192 d23768 u86016 alloc=21*4096
[    0.000000] pcpu-alloc: [0] 0 [0] 1 
[    0.000000] Built 1 zonelists, mobility grouping on.  Total pages: 260416
[    0.000000] Kernel command line: console=ttyS0,115200n8 root=/dev/mmcblk0p2 rw rootwait
[    0.000000] Dentry cache hash table entries: 131072 (order: 7, 524288 bytes, linear)
[    0.000000] Inode-cache hash table entries: 65536 (order: 6, 262144 bytes, linear)
[    0.000000] mem auto-init: stack:off, heap alloc:off, heap free:off
[    0.000000] Memory: 933352K/1048576K available (16384K kernel code, 2077K rwdata, 11500K rodata, 2048K init, 6604K bss, 49688K reserved, 65536K cma-reserved, 196608K highmem)
[    0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=2, Nodes=1
[    0.000000] Running RCU self tests
[    0.000000] rcu: Hierarchical RCU implementation.
[    0.000000] rcu:     RCU event tracing is enabled.
[    0.000000] rcu:     RCU lockdep checking is enabled.
[    0.000000] rcu:     RCU restricting CPUs from NR_CPUS=16 to nr_cpu_ids=2.
[    0.000000] rcu: RCU calculated value of scheduler-enlistment delay is 10 jiffies.
[    0.000000] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=2
[    0.000000] NR_IRQS: 16, nr_irqs: 16, preallocated irqs: 16
[    0.000000] GIC: Using split EOI/Deactivate mode
[    0.000000] random: get_random_bytes called from start_kernel+0x33c/0x508 with crng_init=0
[    0.000000] arch_timer: cp15 timer(s) running at 12.50MHz (phys).
[    0.000000] clocksource: arch_sys_counter: mask: 0xffffffffffffff max_cycles: 0x2e2049cda, max_idle_ns: 440795202628 ns
[    0.000006] sched_clock: 56 bits at 12MHz, resolution 80ns, wraps every 4398046511080ns
[    0.000024] Switching to timer-based delay loop, resolution 80ns
[    0.002147] Console: colour dummy device 80x30
[    0.002195] Lock dependency validator: Copyright (c) 2006 Red Hat, Inc., Ingo Molnar
[    0.002208] ... MAX_LOCKDEP_SUBCLASSES:  8
[    0.002222] ... MAX_LOCK_DEPTH:          48
[    0.002234] ... MAX_LOCKDEP_KEYS:        8192
[    0.002248] ... CLASSHASH_SIZE:          4096
[    0.002261] ... MAX_LOCKDEP_ENTRIES:     32768
[    0.002274] ... MAX_LOCKDEP_CHAINS:      65536
[    0.002287] ... CHAINHASH_SIZE:          32768
[    0.002300]  memory used by lock dependency info: 3997 kB
[    0.002313]  memory used for stack traces: 2112 kB
[    0.002326]  per task-struct memory footprint: 1536 bytes
[    0.002411] Calibrating delay loop (skipped), value calculated using timer frequency.. 25.00 BogoMIPS (lpj=125000)
[    0.002433] pid_max: default: 32768 minimum: 301
[    0.002812] Mount-cache hash table entries: 2048 (order: 1, 8192 bytes, linear)
[    0.002842] Mountpoint-cache hash table entries: 2048 (order: 1, 8192 bytes, linear)
[    0.006086] CPU: Testing write buffer coherency: ok
[    0.007438] CPU0: update cpu_capacity 1024
[    0.007458] CPU0: thread -1, cpu 0, socket 15, mpidr 80000f00
[    0.009446] Setting up static identity map for 0x80300000 - 0x803000ac
[    0.010816] rcu: Hierarchical SRCU implementation.
[    0.018290] EFI services will not be available.
[    0.019630] smp: Bringing up secondary CPUs ...
[    0.022062] CPU1: update cpu_capacity 1024
[    0.022073] CPU1: thread -1, cpu 1, socket 15, mpidr 80000f01
[    0.022905] smp: Brought up 1 node, 2 CPUs
[    0.022936] SMP: Total of 2 processors activated (50.00 BogoMIPS).
[    0.022950] CPU: All CPU(s) started in HYP mode.
[    0.022963] CPU: Virtualization extensions available.
[    0.025208] devtmpfs: initialized
[    0.041880] VFP support v0.3: implementor 41 architecture 2 part 30 variant 7 rev 5
[    0.043466] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 ns
[    0.043521] futex hash table entries: 512 (order: 3, 32768 bytes, linear)
[    0.045895] pinctrl core: initialized pinctrl subsystem
[    0.050769] thermal_sys: Registered thermal governor 'step_wise'
[    0.051554] DMI not present or invalid.
[    0.052996] NET: Registered protocol family 16
[    0.058537] DMA: preallocated 256 KiB pool for atomic coherent allocations
[    0.060551] audit: initializing netlink subsys (disabled)
[    0.061097] audit: type=2000 audit(0.060:1): state=initialized audit_enabled=0 res=1
[    0.064175] cpuidle: using governor menu
[    0.064624] No ATAGs?
[    0.064883] hw-breakpoint: found 5 (+1 reserved) breakpoint and 4 watchpoint registers.
[    0.064957] hw-breakpoint: maximum watchpoint size is 8 bytes.
[    0.068757] Serial: AMBA PL011 UART driver
[    0.076944] Machine: NXP LS1021A-TSN Board
[    0.076977] SoC family: QorIQ LS1021A
[    0.076992] SoC ID: svr:0x87081120, Revision: 2.0
[    0.169015] AT91: Could not find identification node
[    0.173680] iommu: Default domain type: Translated 
[    0.174658] vgaarb: loaded
[    0.176771] SCSI subsystem initialized
[    0.177348] libata version 3.00 loaded.
[    0.178107] usbcore: registered new interface driver usbfs
[    0.178279] usbcore: registered new interface driver hub
[    0.178419] usbcore: registered new device driver usb
[    0.179935] imx-i2c 2180000.i2c: can't get pinctrl, bus recovery not supported
[    0.183255] i2c i2c-0: IMX I2C adapter registered
[    0.183763] i2c i2c-0: using dma0chan16 (tx) and dma0chan17 (rx) for DMA transfers
[    0.185063] pps_core: LinuxPPS API ver. 1 registered
[    0.185082] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti <giometti@linux.it>
[    0.185131] PTP clock support registered
[    0.185446] EDAC MC: Ver: 3.0.0
[    0.189642] Advanced Linux Sound Architecture Driver Initialized.
[    0.194029] clocksource: Switched to clocksource arch_sys_counter
[    0.836430] NET: Registered protocol family 2
[    0.838418] tcp_listen_portaddr_hash hash table entries: 512 (order: 2, 20480 bytes, linear)
[    0.838526] TCP established hash table entries: 8192 (order: 3, 32768 bytes, linear)
[    0.838651] TCP bind hash table entries: 8192 (order: 6, 294912 bytes, linear)
[    0.839399] TCP: Hash tables configured (established 8192 bind 8192)
[    0.839764] UDP hash table entries: 512 (order: 3, 40960 bytes, linear)
[    0.839898] UDP-Lite hash table entries: 512 (order: 3, 40960 bytes, linear)
[    0.840349] NET: Registered protocol family 1
[    0.842154] RPC: Registered named UNIX socket transport module.
[    0.842232] RPC: Registered udp transport module.
[    0.842248] RPC: Registered tcp transport module.
[    0.842263] RPC: Registered tcp NFSv4.1 backchannel transport module.
[    0.842289] NET: Registered protocol family 44
[    0.842321] PCI: CLS 0 bytes, default 64
[    0.844837] hw perfevents: enabled with armv7_cortex_a7 PMU driver, 5 counters available
[    0.848895] Initialise system trusted keyrings
[    0.849568] workingset: timestamp_bits=14 max_order=18 bucket_order=4
[    0.879552] squashfs: version 4.0 (2009/01/31) Phillip Lougher
[    0.881811] NFS: Registering the id_resolver key type
[    0.881945] Key type id_resolver registered
[    0.882019] Key type id_legacy registered
[    0.882158] ntfs: driver 2.1.32 [Flags: R/O].
[    0.883294] fuse: init (API version 7.31)
[    0.885408] Key type asymmetric registered
[    0.885496] Asymmetric key parser 'x509' registered
[    0.885782] bounce: pool size: 64 pages
[    0.885890] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 247)
[    0.885963] io scheduler mq-deadline registered
[    0.885981] io scheduler kyber registered
[    1.068716] Serial: 8250/16550 driver, 5 ports, IRQ sharing enabled
[    1.082332] printk: console [ttyS0] disabled
[    1.082960] 21c0500.serial: ttyS0 at MMIO 0x21c0500 (irq = 33, base_baud = 9375000) is a 16550A
[    1.825305] printk: console [ttyS0] enabled
[    1.831425] SuperH (H)SCI(F) driver initialized
[    1.837448] msm_serial: driver initialized
[    1.841804] STMicroelectronics ASC driver initialized
[    1.848680] 2950000.serial: ttyLP0 at MMIO 0x2950000 (irq = 38, base_baud = 6250000) is a FSL_LPUART
[    1.859130] fsl-lpuart 2950000.serial: DMA tx channel request failed, operating without tx DMA
[    1.867822] fsl-lpuart 2950000.serial: DMA rx channel request failed, operating without rx DMA
[    1.876848] 2980000.serial: ttyLP3 at MMIO 0x2980000 (irq = 39, base_baud = 9375000) is a FSL_LPUART
[    1.886965] fsl-lpuart 2980000.serial: DMA tx channel request failed, operating without tx DMA
[    1.895635] fsl-lpuart 2980000.serial: DMA rx channel request failed, operating without rx DMA
[    1.904846] STM32 USART driver initialized
[    1.941071] brd: module loaded
[    1.971468] loop: module loaded
[    1.977563] at24 0-0051: 4096 byte 24c32 EEPROM, writable, 1 bytes/write
[    1.999686] vmap allocation for size 1073745920 failed: use vmalloc=<size> to increase size
[    2.008130] fsl-quadspi 1550000.spi: ioremap failed for resource [mem 0x40000000-0x7fffffff]
[    2.016594] fsl-quadspi 1550000.spi: Freescale QuadSPI probe failed
[    2.022885] fsl-quadspi: probe of 1550000.spi failed with error -12
[    2.036821] libphy: Fixed MDIO Bus: probed
[    2.043778] tun: Universal TUN/TAP device driver, 1.6
[    2.049693] CAN device driver interface
[    2.055440] spi_master spi0: will run message pump with realtime priority
[    2.063205] sja1105 spi0.1: Probed switch chip: SJA1105T
[    2.069640] bgmac_bcma: Broadcom 47xx GBit MAC driver loaded
[    2.076857] libphy: Freescale PowerQUICC MII Bus: probed
[    2.095786] libphy: Freescale PowerQUICC MII Bus: probed
[    2.103800] fsl-gianfar soc:ethernet@2d10000: enabled errata workarounds, flags: 0x4
[    2.123703] fsl-gianfar soc:ethernet@2d10000 eth0: mac: 00:04:9f:ef:00:00
[    2.130515] fsl-gianfar soc:ethernet@2d10000 eth0: Running with NAPI enabled
[    2.137573] fsl-gianfar soc:ethernet@2d10000 eth0: RX BD ring size for Q[0]: 256
[    2.144976] fsl-gianfar soc:ethernet@2d10000 eth0: RX BD ring size for Q[1]: 256
[    2.152342] fsl-gianfar soc:ethernet@2d10000 eth0: TX BD ring size for Q[0]: 256
[    2.159758] fsl-gianfar soc:ethernet@2d10000 eth0: TX BD ring size for Q[1]: 256
[    2.168364] fsl-gianfar soc:ethernet@2d50000: enabled errata workarounds, flags: 0x4
[    2.187804] fsl-gianfar soc:ethernet@2d50000 eth1: mac: 00:04:9f:ef:01:01
[    2.194610] fsl-gianfar soc:ethernet@2d50000 eth1: Running with NAPI enabled
[    2.201632] fsl-gianfar soc:ethernet@2d50000 eth1: RX BD ring size for Q[0]: 256
[    2.209034] fsl-gianfar soc:ethernet@2d50000 eth1: RX BD ring size for Q[1]: 256
[    2.216436] fsl-gianfar soc:ethernet@2d50000 eth1: TX BD ring size for Q[0]: 256
[    2.223802] fsl-gianfar soc:ethernet@2d50000 eth1: TX BD ring size for Q[1]: 256
[    2.233727] fsl-gianfar soc:ethernet@2d90000: enabled errata workarounds, flags: 0x4
[    2.253044] fsl-gianfar soc:ethernet@2d90000 eth2: mac: 00:04:9f:ef:02:02
[    2.259870] fsl-gianfar soc:ethernet@2d90000 eth2: Running with NAPI enabled
[    2.266930] fsl-gianfar soc:ethernet@2d90000 eth2: RX BD ring size for Q[0]: 256
[    2.274334] fsl-gianfar soc:ethernet@2d90000 eth2: RX BD ring size for Q[1]: 256
[    2.281700] fsl-gianfar soc:ethernet@2d90000 eth2: TX BD ring size for Q[0]: 256
[    2.289101] fsl-gianfar soc:ethernet@2d90000 eth2: TX BD ring size for Q[1]: 256
[    2.297076] e1000e: Intel(R) PRO/1000 Network Driver - 3.2.6-k
[    2.302887] e1000e: Copyright(c) 1999 - 2015 Intel Corporation.
[    2.308954] igb: Intel(R) Gigabit Ethernet Network Driver - version 5.6.0-k
[    2.315925] igb: Copyright (c) 2007-2014 Intel Corporation.
[    2.326942] pegasus: v0.9.3 (2013/04/25), Pegasus/Pegasus II USB Ethernet driver
[    2.334442] usbcore: registered new interface driver pegasus
[    2.340186] usbcore: registered new interface driver asix
[    2.345675] usbcore: registered new interface driver ax88179_178a
[    2.351814] usbcore: registered new interface driver cdc_ether
[    2.357794] usbcore: registered new interface driver smsc75xx
[    2.363623] usbcore: registered new interface driver smsc95xx
[    2.369458] usbcore: registered new interface driver net1080
[    2.375206] usbcore: registered new interface driver cdc_subset
[    2.381172] usbcore: registered new interface driver zaurus
[    2.386879] usbcore: registered new interface driver cdc_ncm
[    2.393459] dwc3 3100000.usb3: Failed to get clk 'ref': -2
[    2.404050] ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver
[    2.410602] ehci-pci: EHCI PCI platform driver
[    2.415165] ehci-platform: EHCI generic platform driver
[    2.420656] ehci-orion: EHCI orion driver
[    2.424936] SPEAr-ehci: EHCI SPEAr driver
[    2.429143] ehci-st: EHCI STMicroelectronics driver
[    2.434256] ehci-exynos: EHCI EXYNOS driver
[    2.438626] ehci-atmel: EHCI Atmel driver
[    2.442818] tegra-ehci: Tegra EHCI driver
[    2.447076] ohci_hcd: USB 1.1 'Open' Host Controller (OHCI) Driver
[    2.453269] ohci-pci: OHCI PCI platform driver
[    2.457844] ohci-platform: OHCI generic platform driver
[    2.463290] SPEAr-ohci: OHCI SPEAr driver
[    2.467536] ohci-st: OHCI STMicroelectronics driver
[    2.472600] ohci-atmel: OHCI Atmel driver
[    2.477662] xhci-hcd xhci-hcd.0.auto: xHCI Host Controller
[    2.483343] xhci-hcd xhci-hcd.0.auto: new USB bus registered, assigned bus number 1
[    2.491720] xhci-hcd xhci-hcd.0.auto: hcc params 0x0220f66c hci version 0x100 quirks 0x0000000002010010
[    2.501255] xhci-hcd xhci-hcd.0.auto: irq 45, io mem 0x03100000
[    2.511918] hub 1-0:1.0: USB hub found
[    2.516134] hub 1-0:1.0: 1 port detected
[    2.522349] xhci-hcd xhci-hcd.0.auto: xHCI Host Controller
[    2.527912] xhci-hcd xhci-hcd.0.auto: new USB bus registered, assigned bus number 2
[    2.535602] xhci-hcd xhci-hcd.0.auto: Host supports USB 3.0 SuperSpeed
[    2.542397] usb usb2: We don't know the algorithms for LPM for this host, disabling LPM.
[    2.552697] hub 2-0:1.0: USB hub found
[    2.557020] hub 2-0:1.0: 1 port detected
[    2.564208] usbcore: registered new interface driver cdc_acm
[    2.569849] cdc_acm: USB Abstract Control Model driver for USB modems and ISDN adapters
[    2.578036] usbcore: registered new interface driver usb-storage
[    2.593048] i2c /dev entries driver
[    2.605234] pps pps0: new PPS source ptp0
[    2.617105] ina2xx 0-0044: power monitor ina220 (Rshunt = 1000 uOhm)
[    2.625970] ina2xx 0-0045: power monitor ina220 (Rshunt = 1000 uOhm)
[    2.632716] lm90 0-004c: 0-004c supply vcc not found, using dummy regulator
[    2.650748] imx2-wdt 2ad0000.watchdog: timeout 60 sec (nowayout=0)
[    2.663865] qoriq_cpufreq: Freescale QorIQ CPU frequency scaling driver
[    2.671821] sdhci: Secure Digital Host Controller Interface driver
[    2.678051] sdhci: Copyright(c) Pierre Ossman
[    2.684911] Synopsys Designware Multimedia Card Interface Driver
[    2.692745] sdhci-pltfm: SDHCI platform and OF driver helper
[    2.726792] mmc0: SDHCI controller on 1560000.esdhc [1560000.esdhc] using ADMA 64-bit
[    2.742508] ledtrig-cpu: registered to indicate activity on CPUs
[    2.749987] usbcore: registered new interface driver usbhid
[    2.755607] usbhid: USB HID core driver
[    2.763030] mma8452 0-001e: 0-001e supply vdd not found, using dummy regulator
[    2.772167] mma8452 0-001e: registering fsl,fxls8471 accelerometer; ID 0x6a
[    2.791650] sgtl5000 0-002a: sgtl5000 revision 0x11
[    2.799374] sgtl5000 0-002a: Using internal LDO instead of VDDD: check ER1 erratum
[    2.820744] mmc0: Problem switching card into high-speed mode!
[    2.827003] mmc0: new SDHC card at address 0001
[    2.834907] mmcblk0: mmc0:0001 00000 7.45 GiB 
[    2.847247]  mmcblk0: p1 p2
[    2.854082] random: fast init done
[    2.862697] drop_monitor: Initializing network drop monitor service
[    2.869548] GACT probability NOT on
[    2.873067] Mirror/redirect action on
[    2.876895] u32 classifier
[    2.879593]     input device check on
[    2.883238]     Actions configured
[    2.888833] IPVS: Registered protocols ()
[    2.893019] usb 1-1: new high-speed USB device number 2 using xhci-hcd
[    2.894222] IPVS: Connection hash table configured (size=4096, memory=32Kbytes)
[    2.907697] IPVS: ipvs loaded.
[    2.913366] NET: Registered protocol family 10
[    2.921486] Segment Routing with IPv6
[    2.925696] sit: IPv6, IPv4 and MPLS over IPv4 tunneling driver
[    2.933315] NET: Registered protocol family 17
[    2.938163] bridge: filtering via arp/ip/ip6tables is no longer available by default. Update your scripts to load br_netfilter if you need this.
[    2.951772] can: controller area network core (rev 20170425 abi 9)
[    2.958228] NET: Registered protocol family 29
[    2.962665] can: raw protocol (rev 20170425)
[    2.967132] can: broadcast manager protocol (rev 20170425 t)
[    2.972791] can: netlink gateway (rev 20190810) max_hops=1
[    2.979132] 8021q: 802.1Q VLAN Support v1.8
[    2.983904] Key type dns_resolver registered
[    2.988432] ThumbEE CPU extension supported.
[    2.992707] Registering SWP/SWPB emulation handler
[    2.998153] Loading compiled-in X.509 certificates
[    3.018138] sja1105 spi0.1: Probed switch chip: SJA1105T
[    3.047924] sja1105 spi0.1: Enabled switch tagging
[    3.054989] sja1105 spi0.1 swp5 (uninitialized): PHY [mdio@2d24000:06] driver [Broadcom BCM5464]
[    3.068432] sja1105 spi0.1 swp2 (uninitialized): PHY [mdio@2d24000:03] driver [Broadcom BCM5464]
[    3.081253] sja1105 spi0.1 swp3 (uninitialized): PHY [mdio@2d24000:04] driver [Broadcom BCM5464]
[    3.095460] sja1105 spi0.1 swp4 (uninitialized): PHY [mdio@2d24000:05] driver [Broadcom BCM5464]
[    3.107329] sja1105 spi0.1: configuring for fixed/rgmii link mode
[    3.114974] DSA: tree 0 setup
[    3.119806] sja1105 spi0.1: Link is Up - 1Gbps/Full - flow control off
[    3.127699] hctosys: unable to open rtc device (rtc0)
[    3.132976] ALSA device list:
[    3.136278]   No soundcards found.
[    3.151044] hub 1-1:1.0: USB hub found
[    3.155138] hub 1-1:1.0: 3 ports detected
[    3.244552] usb 2-1: new SuperSpeed Gen 1 USB device number 2 using xhci-hcd
[    3.311415] hub 2-1:1.0: USB hub found
[    3.315363] hub 2-1:1.0: 3 ports detected
[    3.617164] EXT4-fs (mmcblk0p2): recovery complete
[    3.626833] EXT4-fs (mmcblk0p2): mounted filesystem with ordered data mode. Opts: (null)
[    3.635181] VFS: Mounted root (ext4 filesystem) on device 179:2.
[    3.644279] devtmpfs: mounted
[    3.650696] Freeing unused kernel memory: 2048K
[    3.655999] Run /sbin/init as init process
[    4.336712] systemd[1]: System time before build time, advancing clock.
[    4.463675] systemd[1]: systemd 243 running in system mode. (-PAM +AUDIT -SELINUX -IMA -APPARMOR -SMACK +SYSVINIT +UTMP -LIBCRYPTSETUP -GCRYPT -GNUTLS -ACL -XZ -LZ4 -SECCOMP +BLKID -ELFUTILS +KMOD -IDN2 -IDN -PCRE2 default-hierarchy=hybrid)
[    4.486667] systemd[1]: Detected architecture arm.
[    4.637741] systemd[1]: Set hostname to <OpenIL>.
[    4.690649] systemd[1]: Couldn't move remaining userspace processes, ignoring: Input/output error
[    5.524462] systemd[1]: /usr/lib/systemd/system/dbus.socket:5: ListenStream= references a path below legacy directory /var/run/, updating /var/run/dbus/system_bus_socket \xe2\x86\x92 /run/dbus/system_bus_socket; please update the unit file accordingly.
[    5.737119] random: systemd: uninitialized urandom read (16 bytes read)
[    5.756427] systemd[1]: Created slice system-serial\x2dgetty.slice.
[    5.795331] random: systemd: uninitialized urandom read (16 bytes read)
[    5.803629] systemd[1]: Started Dispatch Password Requests to Console Directory Watch.
[    5.844664] random: systemd: uninitialized urandom read (16 bytes read)
[    5.852706] systemd[1]: Started Forward Password Requests to Wall Directory Watch.
[    5.895220] systemd[1]: Reached target Paths.
[    5.934705] systemd[1]: Reached target Remote File Systems.
[    6.838843] EXT4-fs (mmcblk0p2): re-mounted. Opts: (null)
[    6.845141] ext4 filesystem being remounted at / supports timestamps until 2038 (0x7fffffff)
[    6.999029] audit: type=1130 audit(1570712163.650:2): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=systemd-journald comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
[    7.168961] audit: type=1131 audit(1570712163.820:3): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=systemd-bootchart comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=failed'
[    7.327064] audit: type=1130 audit(1570712163.980:4): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=systemd-remount-fs comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
[    7.398186] audit: type=1130 audit(1570712164.050:5): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=systemd-sysctl comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
[    7.514948] systemd-journald[115]: Received client request to flush runtime journal.
[    7.564913] audit: type=1130 audit(1570712164.220:6): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=systemd-journal-flush comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
[    7.715014] audit: type=1130 audit(1570712164.370:7): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=systemd-tmpfiles-setup-dev comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
[    8.074779] audit: type=1130 audit(1570712164.730:8): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=systemd-tmpfiles-setup comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
[    8.195691] audit: type=1130 audit(1570712164.840:9): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=systemd-udevd comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
[   11.328327] br0: port 1(swp3) entered blocking state
[   11.333379] br0: port 1(swp3) entered disabled state
[   11.343673] flexcan 2a70000.can: 2a70000.can supply xceiver not found, using dummy regulator
[   11.404127] device swp3 entered promiscuous mode
[   11.415875] flexcan 2a80000.can: 2a80000.can supply xceiver not found, using dummy regulator
[   11.426470] flexcan 2a90000.can: 2a90000.can supply xceiver not found, using dummy regulator
[   11.437104] flexcan 2aa0000.can: 2aa0000.can supply xceiver not found, using dummy regulator
[   11.480482] br0: port 2(swp4) entered blocking state
[   11.485625] br0: port 2(swp4) entered disabled state
[   11.493296] device swp4 entered promiscuous mode
[   11.580476] br0: port 3(swp2) entered blocking state
[   11.585720] br0: port 3(swp2) entered disabled state
[   11.617680] device swp2 entered promiscuous mode
[   11.630109] br0: port 4(swp5) entered blocking state
[   11.635245] br0: port 4(swp5) entered disabled state
[   11.673604] device swp5 entered promiscuous mode
[   12.156152] fsl-gianfar soc:ethernet@2d90000 eth2: Link is Up - 1Gbps/Full - flow control off
[   12.196029] IPv6: ADDRCONF(NETDEV_CHANGE): eth2: link becomes ready
[   12.221199] device eth2 entered promiscuous mode
[   12.229026] sja1105 spi0.1 swp2: configuring for phy/rgmii-id link mode
[   12.346815] sja1105 spi0.1 swp5: configuring for phy/rgmii-id link mode
[   12.384144] sja1105 spi0.1 swp4: configuring for phy/rgmii-id link mode
[   12.392814] sja1105 spi0.1 swp3: configuring for phy/rgmii-id link mode
[   14.504842] random: crng init done
[   14.508700] random: 7 urandom warning(s) missed due to ratelimiting
[   15.124517] fsl-gianfar soc:ethernet@2d50000 eth1: Link is Up - 1Gbps/Full - flow control off
[   15.133331] fsl-gianfar soc:ethernet@2d10000 eth0: Link is Up - 1Gbps/Full - flow control off
[   15.164162] IPv6: ADDRCONF(NETDEV_CHANGE): eth1: link becomes ready
[   15.171756] IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
[   15.218539] IPv6: ADDRCONF(NETDEV_CHANGE): eth0.100: link becomes ready
[   20.004505] fsl-gianfar soc:ethernet@2d10000 eth0: Link is Up - 1Gbps/Full - flow control off
[  604.484358] fsl-gianfar soc:ethernet@2d10000 eth0: Link is Down
[  618.004494] fsl-gianfar soc:ethernet@2d10000 eth0: Link is Up - 1Gbps/Full - flow control off
[ 1645.524380] fsl-gianfar soc:ethernet@2d10000 eth0: Link is Down
[ 1651.764475] fsl-gianfar soc:ethernet@2d10000 eth0: Link is Up - 1Gbps/Full - flow control off
[ 3252.324342] fsl-gianfar soc:ethernet@2d10000 eth0: Link is Down
[ 3312.564490] fsl-gianfar soc:ethernet@2d50000 eth1: Link is Up - 1Gbps/Full - flow control off
[ 3443.684624] fsl-gianfar soc:ethernet@2d10000 eth0: Link is Up - 1Gbps/Full - flow control off
vladimiroltean commented 4 years ago

Is the power plug grounded? Is the microUSB cable plugged in?

Can you please also answer these questions? Are you logged into the boards through ssh or through console?

sabarishsubramanian commented 4 years ago

I have logged to boards through ssh

vladimiroltean commented 4 years ago

That's what I suspected. Can you please repeat all tests, including SPI at 12 MHz, through console, please? I'll explain later if it works.

sabarishsubramanian commented 4 years ago

okay i will repeat all test making spi frequency 12mhz

but how can i access to all boards at the same time through console?

vladimiroltean commented 4 years ago

USB hub?

Although at the moment it's important to see if the SPI bus works at 12 MHz with the microUSB cable plugged in.

vladimiroltean commented 4 years ago

A simpler experiment may be to plug the microUSB cable into the board's own USB port.

sabarishsubramanian commented 4 years ago

I have 3 boards i used to flash the memory card and insert in boards and then i connect a usb through my pc to the board and use minicom and assign ip and mac address to it so once done for board 1 i disconnect the usb and connect the board through ssh and work since i have only one usb

and i proceed to do for later boards.

so how can i use a console for it?

vladimiroltean commented 4 years ago

Just test one board at 12 MHz connected to your computer. I would like to know if there is any issue with the SPI bus at full frequncy, that's all.

sabarishsubramanian commented 4 years ago

okay i ll change the frq of 1 board to 12 mhz and run ip link set dev br0 type bridge vlan_filtering 1 ip link set dev br0 type bridge vlan_filtering 0 this command n check

sabarishsubramanian commented 4 years ago

[root@OpenIL ~] # ip link set dev br0 type bridge vlan_filtering 1 [ 8476.621162] sja1105 spi0.1: Reset switch and programmed static config. Reason: VLAN filtering [ 8476.639586] sja1105 spi0.1: Disabled switch tagging [root@OpenIL ~] # ip link set dev br0 type bridge vlan_filtering 0 [ 8484.190730] sja1105 spi0.1: Reset switch and programmed static config. Reason: VLAN filtering [ 8484.210782] sja1105 spi0.1: Enabled switch tagging

I got this at board 1

vladimiroltean commented 4 years ago

At 12 MHz? Ok, nice. Can you please keep the microUSB cable plugged in? As I said, it's not necessary that you use the console, so you can plug it into one of the board's own USB A ports (yes, I know this looks silly).

sabarishsubramanian commented 4 years ago

Hey @vladimiroltean

Today i first changed the spi frequency of all the boards to 12mhz and i followed all the above commands.

I had the usb connecting to one of the boards and i was accessing all the 3 boards through ssh command.

And then i get an output as such:

Board 2

[root@OpenIL ~] # ptp4l -f /etc/linuxptp.cfg -m
ptp4l[1201.934]: selected /dev/ptp1 as PTP clock
ptp4l[1202.011]: port 1: INITIALIZING to LISTENING on INIT_COMPLETE
ptp4l[1202.091]: port 2: INITIALIZING to LISTENING on INIT_COMPLETE
ptp4l[1202.171]: port 3: INITIALIZING to LISTENING on INIT_COMPLETE
ptp4l[1202.251]: port 4: INITIALIZING to LISTENING on INIT_COMPLETE
ptp4l[1202.253]: port 0: INITIALIZING to LISTENING on INIT_COMPLETE
ptp4l[1202.255]: port 3: link down
ptp4l[1202.255]: port 3: LISTENING to FAULTY on FAULT_DETECTED (FT_UNSPECIFIED)
ptp4l[1202.332]: port 4: link down
ptp4l[1202.332]: port 4: LISTENING to FAULTY on FAULT_DETECTED (FT_UNSPECIFIED)
ptp4l[1202.420]: selected local clock 00049f.fffe.ef0505 as best master
ptp4l[1202.421]: port 3: assuming the grand master role
ptp4l[1202.421]: port 4: assuming the grand master role
ptp4l[1205.208]: port 1: announce timeout
ptp4l[1205.208]: bc_event 2683: returning EV_ANNOUNCE_RECEIPT_TIMEOUT_EXPIRES
ptp4l[1205.209]: port 1: LISTENING to MASTER on ANNOUNCE_RECEIPT_TIMEOUT_EXPIRES
ptp4l[1205.209]: selected local clock 00049f.fffe.ef0505 as best master
ptp4l[1205.209]: port 1: assuming the grand master role
ptp4l[1205.209]: port 3: assuming the grand master role
ptp4l[1205.209]: port 4: assuming the grand master role
ptp4l[1205.313]: port 2: new foreign master 00049f.fffe.ef0000-1
ptp4l[1205.313]: selected best master clock 00049f.fffe.ef0000
ptp4l[1205.313]: port 2: LISTENING to SLAVE on RS_SLAVE
ptp4l[1205.775]: port 1: new foreign master 00049f.fffe.ef0606-1
ptp4l[1205.776]: selected best master clock 00049f.fffe.ef0000
ptp4l[1206.941]: clockcheck: clock jumped backward or running slower than expected!
ptp4l[1207.066]: clockcheck: clock jumped forward or running faster than expected!
ptp4l[1207.068]: rms 5929935758 max 12884951473 freq +15987531 +/- 16012469 delay   621 +/-   0
ptp4l[1207.192]: clockcheck: clock jumped backward or running slower than expected!
ptp4l[1207.317]: clockcheck: clock jumped forward or running faster than expected!
ptp4l[1208.069]: clockcheck: clock jumped backward or running slower than expected!
ptp4l[1208.070]: rms 7890368882 max 12884951476 freq -24843 +/-  24 delay   622 +/-   0
ptp4l[1208.194]: clockcheck: clock jumped forward or running faster than expected!
ptp4l[1208.445]: clockcheck: clock jumped backward or running slower than expected!
ptp4l[1208.565]: clockcheck: clock jumped forward or running faster than expected!
ptp4l[1209.072]: rms 4555500760 max 12884901917 freq -24837 +/-  20 delay   627 +/-   0
ptp4l[1210.075]: rms   27 max   36 freq -24857 +/-   7 delay   622 +/-   0
ptp4l[1210.325]: clockcheck: clock jumped backward or running slower than expected!
ptp4l[1210.451]: clockcheck: clock jumped forward or running faster than expected!
ptp4l[1211.078]: rms 5219844615 max 14763950096 freq -24878 +/-  22 delay   621 +/-   0
ptp4l[1212.081]: rms   21 max   24 freq -24856 +/-   7 delay   622 +/-   0
ptp4l[1213.083]: rms   17 max   26 freq -24842 +/-   6 delay   624 +/-   0
ptp4l[1214.086]: rms    7 max   11 freq -24846 +/-   6 delay   624 +/-   0
ptp4l[1215.088]: rms    3 max    7 freq -24853 +/-   4 delay   626 +/-   0
ptp4l[1216.091]: rms    5 max    9 freq -24856 +/-   7 delay   626 +/-   0
ptp4l[1217.094]: rms    4 max    8 freq -24857 +/-   5 delay   626 +/-   0
ptp4l[1218.097]: rms    4 max    7 freq -24856 +/-   6 delay   626 +/-   0
ptp4l[1219.099]: rms    6 max    9 freq -24865 +/-   6 delay   626 +/-   0
ptp4l[1220.102]: rms    6 max    9 freq -24867 +/-   7 delay   626 +/-   0
ptp4l[1221.108]: rms    4 max    9 freq -24868 +/-   6 delay   626 +/-   0
ptp4l[1222.109]: rms    3 max    6 freq -24868 +/-   3 delay   627 +/-   0
ptp4l[1223.110]: rms    3 max    7 freq -24867 +/-   4 delay   627 +/-   0
ptp4l[1224.112]: rms    5 max   10 freq -24869 +/-   7 delay   627 +/-   0
ptp4l[1225.115]: rms    3 max    6 freq -24870 +/-   3 delay   627 +/-   0
ptp4l[1226.118]: rms    6 max   10 freq -24878 +/-   6 delay   627 +/-   0
ptp4l[1227.121]: rms    4 max    7 freq -24876 +/-   5 delay   626 +/-   0
ptp4l[1228.123]: rms    5 max    8 freq -24879 +/-   7 delay   627 +/-   0
ptp4l[1229.126]: rms    6 max   11 freq -24881 +/-   7 delay   628 +/-   0
ptp4l[1230.129]: rms    4 max   10 freq -24884 +/-   4 delay   627 +/-   0
ptp4l[1231.132]: rms 6074001004 max 17179869195 freq -24883 +/-   5 delay   627 +/-   0
ptp4l[1232.135]: rms   10 max   16 freq -24900 +/-  14 delay   627 +/-   0
ptp4l[1233.138]: rms   12 max   17 freq -24886 +/-   5 delay   627 +/-   0
ptp4l[1234.015]: clockcheck: clock jumped backward or running slower than expected!
ptp4l[1234.140]: clockcheck: clock jumped forward or running faster than expected!
ptp4l[1234.142]: rms 6074000998 max 17179869178 freq -24880 +/-   5 delay   627 +/-   0
ptp4l[1235.143]: rms   17 max   26 freq -24867 +/-  15 delay   627 +/-   0

and yes the synchronisation is happening between board 1 and 3 when i connect eth0 of each other.

kindly let me know to proceed.

Thank you

vladimiroltean commented 4 years ago

I still cannot reproduce this behavior on 2 different boards. There is a hardware issue in that the microUSB cable must be plugged in, otherwise the K22 microcontroller responsible for UART and remote power management, which is powered from VBUS (therefore not powered when the USB cable is not plugged in), will induce noise in the power rails of the rest of the board and causing abnormal behavior to the Ethernet PHYs and the switch SPI interface. So please try this experiment with all 3 boards plugged into an USB hub and with access through serial console instead of SSH.

vladimiroltean commented 4 years ago

Update: I have found some random issues with SPI software timestamping which appeared to cause symptoms like the one you showed in this thread. Could you please update to the latest master branch and try to run the example again?

sabarishsubramanian commented 4 years ago

Hey @vladimiroltean

I updated the patch to current version. I tried doing the experiment again but i couldnt able to synchronise still.

below i will show you my work

Am using ssh root to connect through all boards.

[ edited: same clockcheck error log as above ]

How can i proceed now ? should i try doing with a usb hub or is there some other way to do.

sabarishsubramanian commented 4 years ago

hey @vladimiroltean

I updated the patch on all 3 boards [root@OpenIL ~] # cat /etc/os-release NAME=OpenIL VERSION=1.6-community-g2fa26e27ea ID=OpenIL VERSION_ID=1.6-community PRETTY_NAME="OpenIL 1.6-community"

Then i followed the procedure https://github.com/openil/openil/issues/48#issuecomment-567433477

Board 2

[root@OpenIL ~] # ptp4l -f /etc/linuxptp.cfg -m
ptp4l[2151.839]: selected /dev/ptp1 as PTP clock
ptp4l[2151.930]: port 1: INITIALIZING to LISTENING on INIT_COMPLETE
ptp4l[2152.020]: port 2: INITIALIZING to LISTENING on INIT_COMPLETE
ptp4l[2152.110]: port 3: INITIALIZING to LISTENING on INIT_COMPLETE
ptp4l[2152.200]: port 4: INITIALIZING to LISTENING on INIT_COMPLETE
ptp4l[2152.201]: port 0: INITIALIZING to LISTENING on INIT_COMPLETE
ptp4l[2152.202]: port 3: link down
ptp4l[2152.202]: port 3: LISTENING to FAULTY on FAULT_DETECTED (FT_UNSPECIFIED)
ptp4l[2152.280]: port 4: link down
ptp4l[2152.280]: port 4: LISTENING to FAULTY on FAULT_DETECTED (FT_UNSPECIFIED)
ptp4l[2152.370]: selected local clock 00049f.fffe.ef0505 as best master
ptp4l[2152.370]: port 3: assuming the grand master role
ptp4l[2152.371]: port 4: assuming the grand master role
ptp4l[2155.034]: port 1: LISTENING to MASTER on ANNOUNCE_RECEIPT_TIMEOUT_EXPIRES
ptp4l[2155.035]: selected local clock 00049f.fffe.ef0505 as best master
ptp4l[2155.036]: port 1: assuming the grand master role
ptp4l[2155.036]: port 3: assuming the grand master role
ptp4l[2155.036]: port 4: assuming the grand master role
ptp4l[2155.996]: port 2: LISTENING to MASTER on ANNOUNCE_RECEIPT_TIMEOUT_EXPIRES
ptp4l[2155.996]: selected local clock 00049f.fffe.ef0505 as best master
ptp4l[2155.996]: port 1: assuming the grand master role
ptp4l[2155.997]: port 2: assuming the grand master role
ptp4l[2155.997]: port 3: assuming the grand master role
ptp4l[2155.997]: port 4: assuming the grand master role
ptp4l[2156.003]: port 2: new foreign master 00049f.fffe.ef0000-1
ptp4l[2156.003]: selected best master clock 00049f.fffe.ef0000
ptp4l[2156.003]: port 2: MASTER to SLAVE on RS_SLAVE
ptp4l[2156.798]: port 1: new foreign master 00049f.fffe.ef0606-1
ptp4l[2156.798]: selected best master clock 00049f.fffe.ef0000
ptp4l[2157.102]: rms 18500435887 max 37000873357 freq -22212 +/- 8395 delay   628 +/-   0
ptp4l[2158.122]: rms   47 max   60 freq -25440 +/-   8 delay   632 +/-   0
ptp4l[2159.122]: rms   25 max   44 freq -25442 +/-  11 delay   629 +/-   0
ptp4l[2160.123]: rms    5 max    9 freq -25422 +/-   6 delay   631 +/-   0
ptp4l[2161.124]: rms    6 max   11 freq -25417 +/-   8 delay   629 +/-   0
ptp4l[2162.124]: rms    5 max   10 freq -25415 +/-   6 delay   628 +/-   0
ptp4l[2163.125]: rms    5 max   11 freq -25414 +/-   7 delay   629 +/-   0
ptp4l[2164.125]: rms    5 max    9 freq -25415 +/-   6 delay   629 +/-   0
ptp4l[2165.126]: rms    7 max   11 freq -25413 +/-  10 delay   630 +/-   0
ptp4l[2166.127]: rms    5 max    9 freq -25413 +/-   7 delay   629 +/-   0
ptp4l[2167.128]: rms    3 max    7 freq -25416 +/-   4 delay   629 +/-   0
ptp4l[2168.128]: rms    4 max   10 freq -25417 +/-   5 delay   628 +/-   0
ptp4l[2169.129]: rms    5 max    9 freq -25418 +/-   7 delay   628 +/-   0
ptp4l[2170.129]: rms    6 max    9 freq -25413 +/-   7 delay   628 +/-   0
ptp4l[2171.130]: rms    5 max    9 freq -25415 +/-   6 delay   628 +/-   0
ptp4l[2172.131]: rms    5 max   10 freq -25412 +/-   7 delay   628 +/-   0
ptp4l[2173.131]: rms    5 max    9 freq -25414 +/-   7 delay   628 +/-   0
ptp4l[2174.132]: rms    6 max    9 freq -25417 +/-   8 delay   629 +/-   0
ptp4l[2175.133]: rms    5 max    9 freq -25415 +/-   7 delay   628 +/-   0
ptp4l[2176.133]: rms    4 max    8 freq -25416 +/-   5 delay   629 +/-   0
ptp4l[2176.884]: clockcheck: clock jumped forward or running faster than expected!
ptp4l[2177.009]: clockcheck: clock jumped backward or running slower than expected!
ptp4l[2177.134]: clockcheck: clock jumped backward or running slower than expected!
ptp4l[2177.134]: rms 8070939538 max 17179869186 freq -25414 +/-   5 delay   628 +/-   0
ptp4l[2177.244]: clockcheck: clock jumped forward or running faster than expected!
ptp4l[2177.385]: clockcheck: clock jumped backward or running slower than expected!
ptp4l[2177.509]: clockcheck: clock jumped forward or running faster than expected!
ptp4l[2177.885]: clockcheck: clock jumped backward or running slower than expected!
ptp4l[2178.010]: clockcheck: clock jumped forward or running faster than expected!
ptp4l[2178.135]: rms 8589934594 max 17179869190 freq -25400 +/-  12 delay   628 +/-   0
ptp4l[2179.136]: rms   20 max   24 freq -25411 +/-   9 delay   628 +/-   0

Its still not synchronized...

I guess its the board 2 whose clock jump forward and make this synchronisation issue because when i try to connect the board 1 and board 3 from eth 0 of both they get synchronised

vladimiroltean commented 4 years ago

I don't know what to suggest to change in your setup, because I don't understand what is wrong. The only way I see to go forward is to get you a debugging kernel image, with tracepoints for the sja1105 driver, give you some steps to collect a trace.dat file from your failing setup, and I'll have a look at that. Only board 2 needs this debugging kernel.

# Go to the openil build tree
git fetch origin
# It should say, among other things:
# + baca464abacb...358e9b02a1df sja1105-tracepoints           -> origin/sja1105-tracepoints  (forced update)

# Update your branch to the debugging one, compared to the master branch it contains a single extra patch for the kernel
git checkout sja1105-tracepoints
# Rebuild the kernel
make linux-dirclean
make linux

# Go to the board 2 console, prepare it for transferring the new kernel
mkdir /boot
mount /dev/mmcblk0p1 /boot
mv /boot/uImage /boot/uImage.old # save the old kernel image
passwordless-ssh-login # make sure root login to the board works

# Then go back to the computer console and transfer the new kernel through ssh
scp output/images/uImage root@<board-ip>:/boot/uImage

# Reboot the board into the new kernel

# The debugging procedure itself:
trace-cmd list | grep sja1105 # Make sure the sja1105 tracepoints are available
# Stop the background services, we'll be running ptp4l in foreground
systemctl disable --now linuxptp
systemctl disable --now linuxptp-system-clock
# Restart ptp4l, but with tracepoints on. Wait for the "clockcheck" messages to appear and then collect data for a few more seconds. After that, hit ctrl-c and wait until the trace.dat file is saved.
trace-cmd record -e sja1105 ptp4l -f /etc/linuxptp.cfg -m

# Go back to the computer console and transfer the trace.dat file from the board
scp root@<board-ip>:trace.dat .
# Then please attach the trace.dat file somewhere and share it with me.

Thanks and sorry for the trouble.

sabarishsubramanian commented 4 years ago

Can you just do one thing in this thread you can see we have tried lots of command to start the synchronisation.

Can you just post a final commands that should be used rather than using all which was mentioned previously so that the other commands can be chucked out.

sabarishsubramanian commented 4 years ago

Reboot the board into the new kernel

when i reboot in board 2 after this step i get

U-Boot SPL 2019.10-rc3 (Jan 07 2020 - 11:48:27 +0100) Trying to boot from MMC1

U-Boot 2019.10-rc3 (Jan 07 2020 - 11:48:27 +0100)

CPU: Freescale LayerScape LS1021E, Version: 2.0, (0x87081120) Clock Configuration: CPU0(ARMV7):1200 MHz, Bus:300 MHz, DDR:800 MHz (1600 MT/s data rate), Reset Configuration Word (RCW): 00000000: 0608000c 00000000 00000000 00000000 00000010: 30000000 08007900 40105a00 21046000 00000020: 00000000 00000000 00000000 10002000
00000030: 20124801 8804b340 00000000 00000000
Model: NXP LS1021A-TSN Board
I2C: ready
DRAM: 1 GiB
Using SERDES1 Protocol: 48 (0x30)
MMC: FSL_SDHC: 0
Loading Environment from MMC... OK
EEPROM: Invalid ID (ff ff ff ff)
In: serial
Out: serial
Err: serial
SEC0: RNG instantiated
SCSI:
Net: eth0: ethernet@2d10000 [PRIME], eth1: ethernet@2d50000
Hit any key to stop autoboot: 0
switch to partitions #0, OK
mmc0 is current device
Scanning mmc 0:1...
Found /extlinux/extlinux.conf
Retrieving file: /extlinux/extlinux.conf
160 bytes read in 30 ms (4.9 KiB/s)
1: OpenIL 1.6-community - NXP LS1021A-TSN
Retrieving file: /extlinux/../uImage
Skipping OpenIL 1.6-community - NXP LS1021A-TSN for failure retrieving kernel
SCRIPT FAILED: continuing...
Scanning mmc 0:2...
starting USB...
Bus usb3@3100000: Register 200017f NbrPorts 2
Starting the controller
USB XHCI 1.00
scanning bus usb3@3100000 for devices... 3 USB Device(s) found
scanning usb for storage devices... 0 Storage Device(s) found

Device 0: unknown device
PCIe0: pcie@3400000 Root Complex: no link
PCIe1: pcie@3500000 disabled
ethernet@2d10000 Waiting for PHY auto negotiation to complete......... TIMEOUT ! Could not initialize PHY ethernet@2d10000
Speed: 1000, full duplex
BOOTP broadcast 1
BOOTP broadcast 2
BOOTP broadcast 3
BOOTP broadcast 4
BOOTP broadcast 5
BOOTP broadcast 6
BOOTP broadcast 7
BOOTP broadcast 8
BOOTP broadcast 9
BOOTP broadcast 10
BOOTP broadcast 11
BOOTP broadcast 12
BOOTP broadcast 13
BOOTP broadcast 14
BOOTP broadcast 15
BOOTP broadcast 16
BOOTP broadcast 17

Retry time exceeded; starting again
Speed: 1000, full duplex
BOOTP broadcast 1
BOOTP broadcast 2
BOOTP broadcast 3
BOOTP broadcast 4
BOOTP broadcast 5
BOOTP broadcast 6
BOOTP broadcast 7
BOOTP broadcast 8
BOOTP broadcast 9
BOOTP broadcast 10
BOOTP broadcast 11
BOOTP broadcast 12
BOOTP broadcast 13
BOOTP broadcast 14
BOOTP broadcast 15
BOOTP broadcast 16
BOOTP broadcast 17

Retry time exceeded; starting again
Trying load from qspi..
SF: Detected s25fl256s1 with page size 256 Bytes, erase size 64 KiB, total 32 MB Offset exceeds device limit
sf - SPI flash sub-system

Usage:
sf probe [[bus:]cs] [hz] [mode] - init flash device on given SPI bus
and chip select
sf read addr offset|partition len - read len' bytes starting at offset' or from start of mtd
partition'to memory ataddr'
sf write addr offset|partition len - write len' bytes from memory ataddr' to flash at offset' or to start of mtdpartition'
sf erase offset|partition [+]len - erase len' bytes fromoffset'
or from start of mtd partition' +len' round up len' to block size sf update addr offset|partition len - erase and writelen' bytes from memoy at addr' to flash atoffset'
or to start of mtd `partition'
sf protect lock/unlock sector len - protect/unprotect 'len' bytes starting at address 'sector'

Wrong Image Format for bootm command
ERROR: can't get kernel image!

i didnt proceed further then

vladimiroltean commented 4 years ago

I have cleaned up this thread and only kept relevant information so that it can be followed. Let's to the in-depth debugging separately and only update this thread with the conclusions.

vladimiroltean commented 4 years ago

Retrieving file: /extlinux/../uImage Skipping OpenIL 1.6-community - NXP LS1021A-TSN for failure retrieving kernel

So from this message it is clear that U-Boot couldn't find or load the uImage file in the boot partition.

=> fatls mmc 0:1
            extlinux/
 80625815   rootfs.ext2.gz.uboot
      201   version.json
    20892   ls1021a-tsn.dtb
 14103104   uImage

4 file(s), 1 dir(s)

If you have properly saved the uImage.old kernel, you can still boot into the board manually:

=> fatload mmc 0:1 $kernel_addr_r uImage.old && fatload mmc 0:1 $fdt_addr_r ls1021a-tsn.dtb
14103104 bytes read in 624 ms (21.6 MiB/s)
20892 bytes read in 25 ms (815.4 KiB/s)
=> setenv bootargs $bootargs console=ttyS0,115200n8 root=/dev/mmcblk0p2 rw rootwait
=> bootm $kernel_addr_r - $fdt_addr_r

You should then figure out why the uImage file can't be loaded by U-Boot: is it present on the boot partition?

sabarishsubramanian commented 4 years ago

Qbv demo

[root@OpenIL ~] # iptables -t mangle -A POSTROUTING -p icmp -j CLASSIFY --set-class 0:5 iptables v1.8.3 (legacy): unknown option "--set-class" Try `iptables -h' or 'iptables --help' for more information.

Am trying to give the above command on board 1 and 3. i got the following.

I have checked the current version of iptables its 1.8.4.

Do you suggest me to update to current version to eliminate the above error or is there any other way to execute in the current version itself.

vladimiroltean commented 4 years ago

It looks like the kernel that gets built by Buildroot does not have CONFIG_NETFILTER_XT_TARGET_CLASSIFY=y, which is an omission on my part.

There is an alternative to this command though:

iptables -t mangle -A POSTROUTING -p icmp -j CLASSIFY --set-class 0:5

You can do the following instead:

tc qdisc add dev eth0.100 clsact
tc filter add dev eth0.100 egress protocol ip pref 100 flower skip_hw ip_proto icmp action skbedit priority 5

which is a perfectly valid alternative of changing the skb->priority for ping packets, which in turn gets mapped to the proper VLAN PCP.

sabarishsubramanian commented 4 years ago

when i try to ping from baord one to board 3 using ping -A 172.15.100.3 am not getting 30 ms.

Board 1[root@OpenIL ~] # ping -A 172.15.100.3 PING 172.15.100.3 (172.15.100.3) 56(84) bytes of data. 64 bytes from 172.15.100.3: icmp_seq=1 ttl=64 time=8.47 ms 64 bytes from 172.15.100.3: icmp_seq=2 ttl=64 time=29.3 ms 64 bytes from 172.15.100.3: icmp_seq=3 ttl=64 time=49.2 ms 64 bytes from 172.15.100.3: icmp_seq=4 ttl=64 time=69.0 ms 64 bytes from 172.15.100.3: icmp_seq=5 ttl=64 time=79.4 ms 64 bytes from 172.15.100.3: icmp_seq=6 ttl=64 time=98.3 ms 64 bytes from 172.15.100.3: icmp_seq=7 ttl=64 time=109 ms 64 bytes from 172.15.100.3: icmp_seq=8 ttl=64 time=93.3 ms 64 bytes from 172.15.100.3: icmp_seq=9 ttl=64 time=101 ms 64 bytes from 172.15.100.3: icmp_seq=10 ttl=64 time=69.6 ms 64 bytes from 172.15.100.3: icmp_seq=11 ttl=64 time=60.6 ms 64 bytes from 172.15.100.3: icmp_seq=12 ttl=64 time=0.372 ms 64 bytes from 172.15.100.3: icmp_seq=13 ttl=64 time=6.21 ms 64 bytes from 172.15.100.3: icmp_seq=14 ttl=64 time=18.6 ms 64 bytes from 172.15.100.3: icmp_seq=15 ttl=64 time=4.49 ms 64 bytes from 172.15.100.3: icmp_seq=16 ttl=64 time=24.5 ms 64 bytes from 172.15.100.3: icmp_seq=17 ttl=64 time=16.4 ms 64 bytes from 172.15.100.3: icmp_seq=18 ttl=64 time=12.4 ms 64 bytes from 172.15.100.3: icmp_seq=19 ttl=64 time=10.6 ms 64 bytes from 172.15.100.3: icmp_seq=20 ttl=64 time=10.5 ms 64 bytes from 172.15.100.3: icmp_seq=21 ttl=64 time=12.5 ms 64 bytes from 172.15.100.3: icmp_seq=22 ttl=64 time=16.5 ms 64 bytes from 172.15.100.3: icmp_seq=23 ttl=64 time=22.5 ms 64 bytes from 172.15.100.3: icmp_seq=24 ttl=64 time=28.5 ms 64 bytes from 172.15.100.3: icmp_seq=25 ttl=64 time=34.4 ms 64 bytes from 172.15.100.3: icmp_seq=26 ttl=64 time=39.5 ms 64 bytes from 172.15.100.3: icmp_seq=27 ttl=64 time=43.5 ms 64 bytes from 172.15.100.3: icmp_seq=28 ttl=64 time=15.6 ms . . . 64 bytes from 172.15.100.3: icmp_seq=60 ttl=64 time=22.5 ms 64 bytes from 172.15.100.3: icmp_seq=61 ttl=64 time=31.2 ms ^C --- 172.15.100.3 ping statistics --- 62 packets transmitted, 61 received, 1.6129% packet loss, time 1619ms rtt min/avg/max/mdev = 0.372/30.536/109.454/25.107 ms, pipe 5, ipg/ewma 26.540/22.218 ms

an also when i try to change something in taprio.sh file and run again i get this Board 2: [root@OpenIL ~] # ./taprio.sh Error: Exclusivity flag on, cannot modify.

vladimiroltean commented 4 years ago

an also when i try to change something in taprio.sh file and run again i get this Board 2: [root@OpenIL ~] # ./taprio.sh Error: Exclusivity flag on, cannot modify.

You need to delete the existing schedule first:

tc qdisc del dev swp2 root
sabarishsubramanian commented 4 years ago

OK

And why is the packets doesnt follow the request reply pattern and the clock time is variable ? not 30 ms.

vladimiroltean commented 4 years ago

when i try to ping from baord one to board 3 using ping -A 172.15.100.3 am not getting 30 ms.

Board 1[root@OpenIL ~] # ping -A 172.15.100.3 PING 172.15.100.3 (172.15.100.3) 56(84) bytes of data. 64 bytes from 172.15.100.3: icmp_seq=1 ttl=64 time=8.47 ms 64 bytes from 172.15.100.3: icmp_seq=2 ttl=64 time=29.3 ms 64 bytes from 172.15.100.3: icmp_seq=3 ttl=64 time=49.2 ms 64 bytes from 172.15.100.3: icmp_seq=4 ttl=64 time=69.0 ms 64 bytes from 172.15.100.3: icmp_seq=5 ttl=64 time=79.4 ms 64 bytes from 172.15.100.3: icmp_seq=6 ttl=64 time=98.3 ms 64 bytes from 172.15.100.3: icmp_seq=7 ttl=64 time=109 ms 64 bytes from 172.15.100.3: icmp_seq=8 ttl=64 time=93.3 ms 64 bytes from 172.15.100.3: icmp_seq=9 ttl=64 time=101 ms 64 bytes from 172.15.100.3: icmp_seq=10 ttl=64 time=69.6 ms 64 bytes from 172.15.100.3: icmp_seq=11 ttl=64 time=60.6 ms 64 bytes from 172.15.100.3: icmp_seq=12 ttl=64 time=0.372 ms 64 bytes from 172.15.100.3: icmp_seq=13 ttl=64 time=6.21 ms 64 bytes from 172.15.100.3: icmp_seq=14 ttl=64 time=18.6 ms 64 bytes from 172.15.100.3: icmp_seq=15 ttl=64 time=4.49 ms 64 bytes from 172.15.100.3: icmp_seq=16 ttl=64 time=24.5 ms 64 bytes from 172.15.100.3: icmp_seq=17 ttl=64 time=16.4 ms 64 bytes from 172.15.100.3: icmp_seq=18 ttl=64 time=12.4 ms 64 bytes from 172.15.100.3: icmp_seq=19 ttl=64 time=10.6 ms 64 bytes from 172.15.100.3: icmp_seq=20 ttl=64 time=10.5 ms 64 bytes from 172.15.100.3: icmp_seq=21 ttl=64 time=12.5 ms 64 bytes from 172.15.100.3: icmp_seq=22 ttl=64 time=16.5 ms 64 bytes from 172.15.100.3: icmp_seq=23 ttl=64 time=22.5 ms 64 bytes from 172.15.100.3: icmp_seq=24 ttl=64 time=28.5 ms 64 bytes from 172.15.100.3: icmp_seq=25 ttl=64 time=34.4 ms 64 bytes from 172.15.100.3: icmp_seq=26 ttl=64 time=39.5 ms 64 bytes from 172.15.100.3: icmp_seq=27 ttl=64 time=43.5 ms 64 bytes from 172.15.100.3: icmp_seq=28 ttl=64 time=15.6 ms . . . 64 bytes from 172.15.100.3: icmp_seq=60 ttl=64 time=22.5 ms 64 bytes from 172.15.100.3: icmp_seq=61 ttl=64 time=31.2 ms ^C --- 172.15.100.3 ping statistics --- 62 packets transmitted, 61 received, 1.6129% packet loss, time 1619ms rtt min/avg/max/mdev = 0.372/30.536/109.454/25.107 ms, pipe 5, ipg/ewma 26.540/22.218 ms

In the pcap file you have shared on email, the ICMP requests have PCP 0 and the ICMP replies have PCP 5. So the request and the reply are sent through different timeslots and there isn't a fixed 30 ms cycle-time between them. Either PCP 0 or PCP 5 would have worked, but not a combination of both, I guess.

vladimiroltean commented 4 years ago

And why is the packets doesnt follow the request reply pattern and the clock time is variable ? not 30 ms.

My output is:

[root@OpenIL ~] # ping 10.0.100.103 -A
PING 10.0.100.103 (10.0.100.103) 56(84) bytes of data.
64 bytes from 10.0.100.103: icmp_seq=1 ttl=64 time=12.1 ms
64 bytes from 10.0.100.103: icmp_seq=2 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=3 ttl=64 time=47.8 ms
64 bytes from 10.0.100.103: icmp_seq=4 ttl=64 time=65.7 ms
64 bytes from 10.0.100.103: icmp_seq=5 ttl=64 time=79.9 ms
64 bytes from 10.0.100.103: icmp_seq=6 ttl=64 time=95.8 ms
64 bytes from 10.0.100.103: icmp_seq=7 ttl=64 time=107 ms
64 bytes from 10.0.100.103: icmp_seq=8 ttl=64 time=110 ms
64 bytes from 10.0.100.103: icmp_seq=9 ttl=64 time=108 ms
64 bytes from 10.0.100.103: icmp_seq=10 ttl=64 time=97.9 ms
64 bytes from 10.0.100.103: icmp_seq=11 ttl=64 time=70.9 ms
64 bytes from 10.0.100.103: icmp_seq=12 ttl=64 time=32.9 ms
64 bytes from 10.0.100.103: icmp_seq=13 ttl=64 time=28.9 ms
64 bytes from 10.0.100.103: icmp_seq=14 ttl=64 time=28.8 ms
64 bytes from 10.0.100.103: icmp_seq=15 ttl=64 time=2.89 ms
64 bytes from 10.0.100.103: icmp_seq=16 ttl=64 time=13.9 ms
64 bytes from 10.0.100.103: icmp_seq=17 ttl=64 time=28.9 ms
64 bytes from 10.0.100.103: icmp_seq=18 ttl=64 time=15.9 ms
64 bytes from 10.0.100.103: icmp_seq=19 ttl=64 time=5.88 ms
64 bytes from 10.0.100.103: icmp_seq=20 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=21 ttl=64 time=25.9 ms
64 bytes from 10.0.100.103: icmp_seq=22 ttl=64 time=22.9 ms
64 bytes from 10.0.100.103: icmp_seq=23 ttl=64 time=20.9 ms
64 bytes from 10.0.100.103: icmp_seq=24 ttl=64 time=20.9 ms
64 bytes from 10.0.100.103: icmp_seq=25 ttl=64 time=21.9 ms
64 bytes from 10.0.100.103: icmp_seq=26 ttl=64 time=23.9 ms
64 bytes from 10.0.100.103: icmp_seq=27 ttl=64 time=25.9 ms
64 bytes from 10.0.100.103: icmp_seq=28 ttl=64 time=27.9 ms
64 bytes from 10.0.100.103: icmp_seq=29 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=30 ttl=64 time=1.80 ms
64 bytes from 10.0.100.103: icmp_seq=31 ttl=64 time=5.86 ms
64 bytes from 10.0.100.103: icmp_seq=32 ttl=64 time=12.9 ms
64 bytes from 10.0.100.103: icmp_seq=33 ttl=64 time=21.9 ms
64 bytes from 10.0.100.103: icmp_seq=34 ttl=64 time=0.810 ms
64 bytes from 10.0.100.103: icmp_seq=35 ttl=64 time=10.9 ms
64 bytes from 10.0.100.103: icmp_seq=36 ttl=64 time=22.9 ms
64 bytes from 10.0.100.103: icmp_seq=37 ttl=64 time=4.79 ms
64 bytes from 10.0.100.103: icmp_seq=38 ttl=64 time=16.9 ms
64 bytes from 10.0.100.103: icmp_seq=39 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=40 ttl=64 time=42.8 ms
64 bytes from 10.0.100.103: icmp_seq=41 ttl=64 time=49.9 ms
64 bytes from 10.0.100.103: icmp_seq=42 ttl=64 time=61.8 ms
64 bytes from 10.0.100.103: icmp_seq=43 ttl=64 time=69.9 ms
64 bytes from 10.0.100.103: icmp_seq=44 ttl=64 time=73.9 ms
64 bytes from 10.0.100.103: icmp_seq=45 ttl=64 time=72.9 ms
64 bytes from 10.0.100.103: icmp_seq=46 ttl=64 time=66.9 ms
64 bytes from 10.0.100.103: icmp_seq=47 ttl=64 time=49.9 ms
64 bytes from 10.0.100.103: icmp_seq=48 ttl=64 time=31.9 ms
64 bytes from 10.0.100.103: icmp_seq=49 ttl=64 time=15.9 ms
64 bytes from 10.0.100.103: icmp_seq=50 ttl=64 time=3.88 ms
64 bytes from 10.0.100.103: icmp_seq=51 ttl=64 time=25.9 ms
64 bytes from 10.0.100.103: icmp_seq=52 ttl=64 time=20.9 ms
64 bytes from 10.0.100.103: icmp_seq=53 ttl=64 time=15.9 ms
64 bytes from 10.0.100.103: icmp_seq=54 ttl=64 time=13.9 ms
64 bytes from 10.0.100.103: icmp_seq=55 ttl=64 time=13.9 ms
64 bytes from 10.0.100.103: icmp_seq=56 ttl=64 time=15.9 ms
64 bytes from 10.0.100.103: icmp_seq=57 ttl=64 time=18.9 ms
64 bytes from 10.0.100.103: icmp_seq=58 ttl=64 time=23.9 ms
64 bytes from 10.0.100.103: icmp_seq=59 ttl=64 time=28.9 ms
64 bytes from 10.0.100.103: icmp_seq=60 ttl=64 time=33.8 ms
64 bytes from 10.0.100.103: icmp_seq=61 ttl=64 time=37.9 ms
64 bytes from 10.0.100.103: icmp_seq=62 ttl=64 time=40.9 ms
64 bytes from 10.0.100.103: icmp_seq=63 ttl=64 time=41.9 ms
64 bytes from 10.0.100.103: icmp_seq=64 ttl=64 time=41.9 ms
64 bytes from 10.0.100.103: icmp_seq=65 ttl=64 time=39.9 ms
64 bytes from 10.0.100.103: icmp_seq=66 ttl=64 time=37.9 ms
64 bytes from 10.0.100.103: icmp_seq=67 ttl=64 time=33.9 ms
64 bytes from 10.0.100.103: icmp_seq=68 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=69 ttl=64 time=26.9 ms
64 bytes from 10.0.100.103: icmp_seq=70 ttl=64 time=23.9 ms
64 bytes from 10.0.100.103: icmp_seq=71 ttl=64 time=22.9 ms
64 bytes from 10.0.100.103: icmp_seq=72 ttl=64 time=22.9 ms
64 bytes from 10.0.100.103: icmp_seq=73 ttl=64 time=23.9 ms
64 bytes from 10.0.100.103: icmp_seq=74 ttl=64 time=24.9 ms
64 bytes from 10.0.100.103: icmp_seq=75 ttl=64 time=26.9 ms
64 bytes from 10.0.100.103: icmp_seq=76 ttl=64 time=28.9 ms
64 bytes from 10.0.100.103: icmp_seq=77 ttl=64 time=30.8 ms
64 bytes from 10.0.100.103: icmp_seq=78 ttl=64 time=31.9 ms
64 bytes from 10.0.100.103: icmp_seq=79 ttl=64 time=31.9 ms
64 bytes from 10.0.100.103: icmp_seq=80 ttl=64 time=31.9 ms
64 bytes from 10.0.100.103: icmp_seq=81 ttl=64 time=31.9 ms
64 bytes from 10.0.100.103: icmp_seq=82 ttl=64 time=30.9 ms
64 bytes from 10.0.100.103: icmp_seq=83 ttl=64 time=30.0 ms
64 bytes from 10.0.100.103: icmp_seq=84 ttl=64 time=30.0 ms
64 bytes from 10.0.100.103: icmp_seq=85 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=86 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=87 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=88 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=89 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=90 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=91 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=92 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=93 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=94 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=95 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=96 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=97 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=98 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=99 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=100 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=101 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=102 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=103 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=104 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=105 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=106 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=107 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=108 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=109 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=110 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=111 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=112 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=113 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=114 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=115 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=116 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=117 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=118 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=119 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=120 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=121 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=122 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=123 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=124 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=125 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=126 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=127 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=128 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=129 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=130 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=131 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=132 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=133 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=134 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=135 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=136 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=137 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=138 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=139 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=140 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=141 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=142 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=143 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=144 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=145 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=146 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=147 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=148 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=149 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=150 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=151 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=152 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=153 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=154 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=155 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=156 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=157 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=158 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=159 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=160 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=161 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=162 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=163 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=164 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=165 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=166 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=167 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=168 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=169 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=170 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=171 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=172 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=173 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=174 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=175 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=176 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=177 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=178 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=179 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=180 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=181 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=182 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=183 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=184 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=185 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=186 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=187 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=188 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=189 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=190 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=191 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=192 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=193 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=194 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=195 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=196 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=197 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=198 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=199 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=200 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=201 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=202 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=203 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=204 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=205 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=206 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=207 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=208 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=209 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=210 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=211 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=212 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=213 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=214 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=215 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=216 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=217 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=218 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=219 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=220 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=221 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=222 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=223 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=224 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=225 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=226 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=227 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=228 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=229 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=230 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=231 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=232 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=233 ttl=64 time=30.0 ms
64 bytes from 10.0.100.103: icmp_seq=234 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=235 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=236 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=237 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=238 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=239 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=240 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=241 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=242 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=243 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=244 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=245 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=246 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=247 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=248 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=249 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=250 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=251 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=252 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=253 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=254 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=255 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=256 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=257 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=258 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=259 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=260 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=261 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=262 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=263 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=264 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=265 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=266 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=267 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=268 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=269 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=270 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=271 ttl=64 time=29.9 ms
64 bytes from 10.0.100.103: icmp_seq=272 ttl=64 time=29.9 ms

so as you can see, it's taking a few tens of packets to align, but afterwards it should lock pretty solid.

What debugging steps have you taken? Have you tried to remove the classification rules so that ping goes to PCP 0? Have you tried to e.g. increase the timeslot for ping traffic?

I admit the traffic demonstration itself is pretty rudimentary, since the packet transmission itself is not time-based, but it is a very quick way to prove that it actually does something, and with PTP, the timebase on all 3 boards is actually the same, so it's not difficult to build on top of this example by sending time-based traffic. I will improve upon this example when I have some time, perhaps by adapting the time-test.sh example to the LS1021A-TSN board.

vladimiroltean commented 4 years ago

Or maybe you just didn't wait for enough packets for the adaptive ping to discover the RTT? In my log it locked at about 80 packets, you stopped it after 61.

Again, this is completely to be expected given the nature of the traffic being used here. Ping is not time-based (you don't specify the base-time or the cycle-time anywhere).