Discussion:
[Linuxptp-users] Hardware PTP clock synchronization
Гаврилов Александр
2013-08-01 07:55:00 UTC
Permalink
Hello!

I encountered a problem while obtaining the time from the adapter Intel pro1000 (82576).
I use Fedora 18 kernel version 3.9.6.
The values of the time I get through clock_gettime (id, timevalue) for the device / dev/ptp0.
The source of the PTP packet is switch Hirschmann MAR1140. Wireshark shows the presence of all necessary for the implementation of the protocol PTP packets at the input adapter interface,
but the time in the PTP counters are not adjusted in accordance with the values ​​of the packages.
I compiled linuxptp-1.2 downloaded from http://linuxptp.sourceforge.net/ and run the following commands:

Hardware timestamping:

# ptp4l -i p16p1 -p /dev/ptp0 -m -2 -H

ptp4l[3704.267]: selected /dev/ptp0 as PTP clock
ptp4l[3704.278]: port 1: INITIALIZING to LISTENING on INITIALIZE
ptp4l[3704.278]: port 0: INITIALIZING to LISTENING on INITIALIZE
ptp4l[3705.077]: port 1: new foreign master ece555.fffe.2de639-2
ptp4l[3709.401]: selected best master clock ece555.fffe.2de639
ptp4l[3709.401]: port 1: LISTENING to UNCALIBRATED on RS_SLAVE
ptp4l[3710.039]: recvmsg tx timestamp failed: Resource temporarily unavailable
ptp4l[3710.039]: port 1: send delay request failed
ptp4l[3710.039]: port 1: UNCALIBRATED to FAULTY on FAULT_DETECTED
ptp4l[3725.690]: port 1: FAULTY to LISTENING on FAULT_CLEARED
ptp4l[3726.698]: port 1: new foreign master ece555.fffe.2de639-2
ptp4l[3731.022]: selected best master clock ece555.fffe.2de639
ptp4l[3731.022]: port 1: LISTENING to UNCALIBRATED on RS_SLAVE
ptp4l[3731.193]: recvmsg tx timestamp failed: Resource temporarily unavailable
ptp4l[3731.193]: port 1: send delay request failed
ptp4l[3731.193]: port 1: UNCALIBRATED to FAULTY on FAULT_DETECTED

Software timestamping:

# ptp4l -i p16p1 -p /dev/ptp0 -m -2 -S

ptp4l[3826.218]: port 1: INITIALIZING to LISTENING on INITIALIZE
ptp4l[3826.218]: port 0: INITIALIZING to LISTENING on INITIALIZE
ptp4l[3828.312]: port 1: new foreign master ece555.fffe.2de639-2
ptp4l[3832.218]: port 1: LISTENING to MASTER on ANNOUNCE_RECEIPT_TIMEOUT_EXPIRES
ptp4l[3832.636]: selected best master clock ece555.fffe.2de639
ptp4l[3832.636]: port 1: MASTER to UNCALIBRATED on RS_SLAVE
ptp4l[3833.805]: negative path delay -3374260
ptp4l[3833.805]: path_delay = (t2 - t3) + (t4 - t1)
ptp4l[3833.805]: t2 - t3 = -87573969
ptp4l[3833.805]: t4 - t1 = +80825448
ptp4l[3833.805]: c1 0
ptp4l[3833.805]: c2 0
ptp4l[3833.805]: c3 0
ptp4l[3833.805]: port 1: minimum delay request interval 2^3
ptp4l[3834.628]: negative path delay -35159469
ptp4l[3834.628]: path_delay = (t2 - t3) + (t4 - t1)
ptp4l[3834.628]: t2 - t3 = -910670474
ptp4l[3834.628]: t4 - t1 = +840351536
ptp4l[3834.628]: c1 0
ptp4l[3834.628]: c2 0
ptp4l[3834.628]: c3 0
ptp4l[3834.798]: master offset -10774702751233 s0 adj +0 path delay -19266864
ptp4l[3835.879]: master offset -10774619261329 s0 adj +0 path delay -19266864


What is the difference between hardware and software timestamping in this case?
Why Hardware timestamping is not working properly?
Why software timestamping shows the correct time values​​, but does not synchronize time with hardware ptp clock (/dev/ptp0)?

Sincerely, Alexander.
Keller, Jacob E
2013-08-01 17:44:37 UTC
Permalink
-----Original Message-----
Sent: Thursday, August 01, 2013 12:55 AM
Subject: [Linuxptp-users] Hardware PTP clock synchronization
Hello!
I encountered a problem while obtaining the time from the adapter Intel pro1000 (82576).
I use Fedora 18 kernel version 3.9.6.
The values of the time I get through clock_gettime (id, timevalue) for the
device / dev/ptp0.
The source of the PTP packet is switch Hirschmann MAR1140. Wireshark
shows the presence of all necessary for the implementation of the
protocol PTP packets at the input adapter interface,
but the time in the PTP counters are not adjusted in accordance with the
values ​​of the packages.
I compiled linuxptp-1.2 downloaded from
# ptp4l -i p16p1 -p /dev/ptp0 -m -2 -H
You are on a modern kernel. Please do not use -p /dev/ptpX option. Let the program automatically determine it. It may be the case that you don't have the right ptp device.

Richard: do we have a check in place to ensure the passed argument is correct if we can check? I don't remember.
ptp4l[3704.267]: selected /dev/ptp0 as PTP clock
ptp4l[3704.278]: port 1: INITIALIZING to LISTENING on INITIALIZE
ptp4l[3704.278]: port 0: INITIALIZING to LISTENING on INITIALIZE
ptp4l[3705.077]: port 1: new foreign master ece555.fffe.2de639-2
ptp4l[3709.401]: selected best master clock ece555.fffe.2de639
ptp4l[3709.401]: port 1: LISTENING to UNCALIBRATED on RS_SLAVE
ptp4l[3710.039]: recvmsg tx timestamp failed: Resource temporarily unavailable
This means your tx timestamp is not being properly detected. I don't know for sure why this is, but there are a few reasons. I will forward this to the intel engineer who designed the driver for this part.
ptp4l[3710.039]: port 1: send delay request failed
ptp4l[3710.039]: port 1: UNCALIBRATED to FAULTY on FAULT_DETECTED
ptp4l[3725.690]: port 1: FAULTY to LISTENING on FAULT_CLEARED
ptp4l[3726.698]: port 1: new foreign master ece555.fffe.2de639-2
ptp4l[3731.022]: selected best master clock ece555.fffe.2de639
ptp4l[3731.022]: port 1: LISTENING to UNCALIBRATED on RS_SLAVE
ptp4l[3731.193]: recvmsg tx timestamp failed: Resource temporarily unavailable
ptp4l[3731.193]: port 1: send delay request failed
ptp4l[3731.193]: port 1: UNCALIBRATED to FAULTY on FAULT_DETECTED
hardware timestamping is not working correctly because you are not properly receiving the tx timestamps.
# ptp4l -i p16p1 -p /dev/ptp0 -m -2 -S
ptp4l[3826.218]: port 1: INITIALIZING to LISTENING on INITIALIZE
ptp4l[3826.218]: port 0: INITIALIZING to LISTENING on INITIALIZE
ptp4l[3828.312]: port 1: new foreign master ece555.fffe.2de639-2
ptp4l[3832.218]: port 1: LISTENING to MASTER on
ANNOUNCE_RECEIPT_TIMEOUT_EXPIRES
ptp4l[3832.636]: selected best master clock ece555.fffe.2de639
ptp4l[3832.636]: port 1: MASTER to UNCALIBRATED on RS_SLAVE
ptp4l[3833.805]: negative path delay -3374260
ptp4l[3833.805]: path_delay = (t2 - t3) + (t4 - t1)
ptp4l[3833.805]: t2 - t3 = -87573969
ptp4l[3833.805]: t4 - t1 = +80825448
ptp4l[3833.805]: c1 0
ptp4l[3833.805]: c2 0
ptp4l[3833.805]: c3 0
ptp4l[3833.805]: port 1: minimum delay request interval 2^3
ptp4l[3834.628]: negative path delay -35159469
ptp4l[3834.628]: path_delay = (t2 - t3) + (t4 - t1)
ptp4l[3834.628]: t2 - t3 = -910670474
ptp4l[3834.628]: t4 - t1 = +840351536
ptp4l[3834.628]: c1 0
ptp4l[3834.628]: c2 0
ptp4l[3834.628]: c3 0
ptp4l[3834.798]: master offset -10774702751233 s0 adj +0 path delay
-19266864
ptp4l[3835.879]: master offset -10774619261329 s0 adj +0 path delay
-19266864
What is the difference between hardware and software timestamping in this case?
Why Hardware timestamping is not working properly?
Why software timestamping shows the correct time values​​, but does not
synchronize time with hardware ptp clock (/dev/ptp0)?
Hardware timestamping uses the ptp device, and coordinates with the driver for doing timestamps in the MAC or PHY. Software timestamping does software based stamps as late as possible in the driver. It does not use the PHC device at all and directly modifies the kernel time. They are completely different modes.
Sin
Richard Cochran
2013-08-01 17:58:17 UTC
Permalink
Post by Keller, Jacob E
Post by Гаврилов Александр
I encountered a problem while obtaining the time from the adapter Intel
pro1000 (82576).
...
Post by Keller, Jacob E
Post by Гаврилов Александр
ptp4l[3704.267]: selected /dev/ptp0 as PTP clock
ptp4l[3704.278]: port 1: INITIALIZING to LISTENING on INITIALIZE
ptp4l[3704.278]: port 0: INITIALIZING to LISTENING on INITIALIZE
ptp4l[3705.077]: port 1: new foreign master ece555.fffe.2de639-2
ptp4l[3709.401]: selected best master clock ece555.fffe.2de639
ptp4l[3709.401]: port 1: LISTENING to UNCALIBRATED on RS_SLAVE
ptp4l[3710.039]: recvmsg tx timestamp failed: Resource temporarily unavailable
This means your tx timestamp is not being properly detected. I don't
know for sure why this is, but there are a few reasons. I will
forward this to the intel engineer who designed the driver for this
part.
I wrote the original igb ptp code, but I never tested the 82576
because I don't have one. I am not sure if Intel tested this either.

How about just increasing the tx_timestamp_timeout configuration
option to 100 or 1000?

Thanks,
Richard
Keller, Jacob E
2013-08-01 20:54:26 UTC
Permalink
Post by Richard Cochran
Post by Keller, Jacob E
Post by Гаврилов Александр
I encountered a problem while obtaining the time from the adapter Intel
pro1000 (82576).
...
Post by Keller, Jacob E
Post by Гаврилов Александр
ptp4l[3704.267]: selected /dev/ptp0 as PTP clock
ptp4l[3704.278]: port 1: INITIALIZING to LISTENING on INITIALIZE
ptp4l[3704.278]: port 0: INITIALIZING to LISTENING on INITIALIZE
ptp4l[3705.077]: port 1: new foreign master ece555.fffe.2de639-2
ptp4l[3709.401]: selected best master clock ece555.fffe.2de639
ptp4l[3709.401]: port 1: LISTENING to UNCALIBRATED on RS_SLAVE
ptp4l[3710.039]: recvmsg tx timestamp failed: Resource temporarily unavailable
This means your tx timestamp is not being properly detected. I don't
know for sure why this is, but there are a few reasons. I will
forward this to the intel engineer who designed the driver for this
part.
I wrote the original igb ptp code, but I never tested the 82576
because I don't have one. I am not sure if Intel tested this either.
How about just increasing the tx_timestamp_timeout configuration
option to 100 or 1000?
Thanks,
Richard
I believe this is actually physical hardware dropping the timestamps,
not an issue of not returning them fast enough. I know that Matthew Vick
has done some testing of the 82576 but not that much. I also believe the
use of poll has since removed any of the issues due to timing (we poll
for an entire second if it isn't there!) You could try increasing the
poll time just in case to see if it helps..

Basically, the 82576 is not a very reliable pa
Keller, Jacob E
2013-08-01 17:49:39 UTC
Permalink
-----Original Message-----
Sent: Thursday, August 01, 2013 12:55 AM
Subject: [Linuxptp-users] Hardware PTP clock synchronization
Hello!
I encountered a problem while obtaining the time from the adapter Intel pro1000 (82576).
I use Fedora 18 kernel version 3.9.6.
The values of the time I get through clock_gettime (id, timevalue) for the
device / dev/ptp0.
The source of the PTP packet is switch Hirschmann MAR1140. Wireshark
shows the presence of all necessary for the implementation of the
protocol PTP packets at the input adapter interface,
but the time in the PTP counters are not adjusted in accordance with the
values ​​of the packages.
I compiled linuxptp-1.2 downloaded from
# ptp4l -i p16p1 -p /dev/ptp0 -m -2 -H
Also please re-try with -P, for peer to peer delay mechanism. The 82576 does not always perform well when using E2E and can potentially drop packets due to its internal timestamping design having some flaws. See if it starts working if you can use peer delay mechanism? If your ptp source cannot use P2P, hopefully we can find out why E2E isn't working for you...

- Jake
ptp4l[3704.267]: selected /dev/ptp0 as PTP clock
ptp4l[3704.278]: port 1: INITIALIZING to LISTENING on INITIALIZE
ptp4l[3704.278]: port 0: INITIALIZING to LISTENING on INITIALIZE
ptp4l[3705.077]: port 1: new foreign master ece555.fffe.2de639-2
ptp4l[3709.401]: selected best master clock ece555.fffe.2de639
ptp4l[3709.401]: port 1: LISTENING to UNCALIBRATED on RS_SLAVE
ptp4l[3710.039]: recvmsg tx timestamp failed: Resource temporarily unavailable
ptp4l[3710.039]: port 1: send delay request failed
ptp4l[3710.039]: port 1: UNCALIBRATED to FAULTY on FAULT_DETECTED
ptp4l[3725.690]: port 1: FAULTY to LISTENING on FAULT_CLEARED
ptp4l[3726.698]: port 1: new foreign master ece555.fffe.2de639-2
ptp4l[3731.022]: selected best master clock ece555.fffe.2de639
ptp4l[3731.022]: port 1: LISTENING to UNCALIBRATED on RS_SLAVE
ptp4l[3731.193]: recvmsg tx timestamp failed: Resource temporarily unavailable
ptp4l[3731.193]: port 1: send delay request failed
ptp4l[3731.193]: port 1: UNCALIBRATED to FAULTY on FAULT_DETECTED
# ptp4l -i p16p1 -p /dev/ptp0 -m -2 -S
ptp4l[3826.218]: port 1: INITIALIZING to LISTENING on INITIALIZE
ptp4l[3826.218]: port 0: INITIALIZING to LISTENING on INITIALIZE
ptp4l[3828.312]: port 1: new foreign master ece555.fffe.2de639-2
ptp4l[3832.218]: port 1: LISTENING to MASTER on
ANNOUNCE_RECEIPT_TIMEOUT_EXPIRES
ptp4l[3832.636]: selected best master clock ece555.fffe.2de639
ptp4l[3832.636]: port 1: MASTER to UNCALIBRATED on RS_SLAVE
ptp4l[3833.805]: negative path delay -3374260
ptp4l[3833.805]: path_delay = (t2 - t3) + (t4 - t1)
ptp4l[3833.805]: t2 - t3 = -87573969
ptp4l[3833.805]: t4 - t1 = +80825448
ptp4l[3833.805]: c1 0
ptp4l[3833.805]: c2 0
ptp4l[3833.805]: c3 0
ptp4l[3833.805]: port 1: minimum delay request interval 2^3
ptp4l[3834.628]: negative path delay -35159469
ptp4l[3834.628]: path_delay = (t2 - t3) + (t4 - t1)
ptp4l[3834.628]: t2 - t3 = -910670474
ptp4l[3834.628]: t4 - t1 = +840351536
ptp4l[3834.628]: c1 0
ptp4l[3834.628]: c2 0
ptp4l[3834.628]: c3 0
ptp4l[3834.798]: master offset -10774702751233 s0 adj +0 path delay
-19266864
ptp4l[3835.879]: master offset -10774619261329 s0 adj +0 path delay
-19266864
What is the difference between hardware and software timestamping in this case?
Why Hardware timestamping is not working properly?
Why software timestamping shows the correct time values​​, but does not
synchronize time with hardware ptp clock (/dev/ptp0)?
Sincerely, Alexander.
------------------------------------------------------------------------------
Get your SQL database under version control now!
Version control is standard for application code, but databases havent
caught up. So what steps can you take to put your SQL databases under
version control? Why should you start doing it? Read more to find out.
http://pubads.g.doubleclick.net/gampad/clk?id=49501711&iu=/4140/ost
g.clktrk
_______________________________________________
Linuxptp-users mailing list
https://lists.sourc
Гаврилов Александр
2013-08-02 06:33:12 UTC
Permalink
Thanks for your interest in my problem!

lspci output:
Intel 82576 Gigabit ethernet controller (rev 01)
Intel 82576 Gigabit ethernet controller (rev 01)

ethtool output:
ethtool -T p16p1
Time stamping parameters for p16p1:
Capabilities:
hardware-transmit (SOF_TIMESTAMPING_TX_HARDWARE)
software-transmit (SOF_TIMESTAMPING_TX_SOFTWARE)
hardware-receive (SOF_TIMESTAMPING_RX_HARDWARE)
software-receive (SOF_TIMESTAMPING_RX_SOFTWARE)
software-system-clock (SOF_TIMESTAMPING_SOFTWARE)
hardware-raw-clock (SOF_TIMESTAMPING_RAW_HARDWARE)
PTP Hardware Clock: 0
Hardware Transmit Timestamp Modes:
off (HWTSTAMP_TX_OFF)
on (HWTSTAMP_TX_ON)
Hardware Receive Filter Modes:
none (HWTSTAMP_FILTER_NONE)
ptpv1-l4-sync (HWTSTAMP_FILTER_PTP_V1_L4_SYNC)
ptpv1-l4-delay-req (HWTSTAMP_FILTER_PTP_V1_L4_DELAY_REQ)
ptpv2-l4-sync (HWTSTAMP_FILTER_PTP_V2_L4_SYNC)
ptpv2-l4-delay-req (HWTSTAMP_FILTER_PTP_V2_L4_DELAY_REQ)
ptpv2-l2-sync (HWTSTAMP_FILTER_PTP_V2_L2_SYNC)
ptpv2-l2-delay-req (HWTSTAMP_FILTER_PTP_V2_L2_DELAY_REQ)
ptpv2-event (HWTSTAMP_FILTER_PTP_V2_EVENT)
Post by Keller, Jacob E
You are on a modern kernel. Please do not use -p /dev/ptpX option. Let the program automatically determine it.
Ok, it works.
Post by Keller, Jacob E
How about just increasing the tx_timestamp_timeout configuration option to 100 or 1000?
Set a tx_timestamp_timeout value to 1000 in configuration file.
Post by Keller, Jacob E
Also please re-try with -P, for peer to peer delay mechanism.
ptp4l -2 -i p16p1 -P -m -H -s
ptp4l[728.271]: selected /dev/ptp0 as PTP clock
ptp4l[728.288]: port 1: INITIALIZING to LISTENING on INITIALIZE
ptp4l[728.288]: port 0: INITIALIZING to LISTENING on INITIALIZE
ptp4l[729.462]: port 1: new foreign master ece555.fffe.2de639-2
ptp4l[733.452]: selected best master clock ece555.fffe.2de639
ptp4l[733.452]: port 1: LISTENING to UNCALIBRATED on RS_SLAVE
ptp4l[734.458]: recvmsg tx timestamp failed: Resource temporarily unavailable
ptp4l[734.458]: port 1: send peer delay request failed
ptp4l[734.458]: port 1: UNCALIBRATED to FAULTY on FAULT_DETECTED
Post by Keller, Jacob E
I wrote the original igb ptp code, but I never tested the 82576
because I don't have one. I am not sure if Intel tested this either.

Richard, you are an employee Intel?
Or a driver for Intel card are developing people who do not work in Intel?
I wrote to tech support intel two months ago, they said that my question is redirected to a deeper level.
To this day there is no response from Intel.
Post by Keller, Jacob E
Basically, the 82576 is not a very reliable part for timestamping...
What kind of adapter would you recommend instead of 82576? (gigabit).


In any case, thank you very much!
Richard Cochran
2013-08-02 08:47:58 UTC
Permalink
Post by Гаврилов Александр
Richard, you are an employee Intel?
No, I am not.
Post by Гаврилов Александр
Or a driver for Intel card are developing people who do not work in Intel?
The driver is for the Linux kernel, and anyone may contribute to that
project. Intel does develop Linux drivers, of course, but they also
cooperate with non-Intel developers, too.

I am the author and maintainer of the PTP Hardware Clock (PHC)
subsystem of the Linux kernel.
Post by Гаврилов Александр
Post by Keller, Jacob E
Basically, the 82576 is not a very reliable part for timestamping...
It sounds like to me that the 82576 has a hardware bug (and not a
driver issue).
Post by Гаврилов Александр
What kind of adapter would you recommend instead of 82576? (gigabit).
I would recommend the i210. It is not expensive, and it has excellent
capabilities.

Thanks,
Richard
Keller, Jacob E
2013-08-02 17:54:00 UTC
Permalink
Hi Alexander,
Post by Гаврилов Александр
Thanks for your interest in my problem!
Would it be possible for you to attempt using LinuxPTP 1.3 (released
today!)? or the git tree? I know you said you were using version 1.2,
but it appears based on your error log that you are not using the
version which fixes the tx timestamp timeout issue by using poll().
Please just for clarity re-test using LinuxPTP 1.3? :)
Post by Гаврилов Александр
Intel 82576 Gigabit ethernet controller (rev 01)
Intel 82576 Gigabit ethernet controller (rev 01)
ethtool -T p16p1
hardware-transmit (SOF_TIMESTAMPING_TX_HARDWARE)
software-transmit (SOF_TIMESTAMPING_TX_SOFTWARE)
hardware-receive (SOF_TIMESTAMPING_RX_HARDWARE)
software-receive (SOF_TIMESTAMPING_RX_SOFTWARE)
software-system-clock (SOF_TIMESTAMPING_SOFTWARE)
hardware-raw-clock (SOF_TIMESTAMPING_RAW_HARDWARE)
PTP Hardware Clock: 0
off (HWTSTAMP_TX_OFF)
on (HWTSTAMP_TX_ON)
none (HWTSTAMP_FILTER_NONE)
ptpv1-l4-sync (HWTSTAMP_FILTER_PTP_V1_L4_SYNC)
ptpv1-l4-delay-req (HWTSTAMP_FILTER_PTP_V1_L4_DELAY_REQ)
ptpv2-l4-sync (HWTSTAMP_FILTER_PTP_V2_L4_SYNC)
ptpv2-l4-delay-req (HWTSTAMP_FILTER_PTP_V2_L4_DELAY_REQ)
ptpv2-l2-sync (HWTSTAMP_FILTER_PTP_V2_L2_SYNC)
ptpv2-l2-delay-req (HWTSTAMP_FILTER_PTP_V2_L2_DELAY_REQ)
ptpv2-event (HWTSTAMP_FILTER_PTP_V2_EVENT)
Post by Keller, Jacob E
You are on a modern kernel. Please do not use -p /dev/ptpX option. Let the program automatically determine it.
Ok, it works.
Was hoping this would solve the problem... :( Ok.
Post by Гаврилов Александр
Post by Keller, Jacob E
How about just increasing the tx_timestamp_timeout configuration option to 100 or 1000?
Set a tx_timestamp_timeout value to 1000 in configuration file.
Post by Keller, Jacob E
Also please re-try with -P, for peer to peer delay mechanism.
I realize now that you are using a switch which probably only does one
mode..
Post by Гаврилов Александр
ptp4l -2 -i p16p1 -P -m -H -s
ptp4l[728.271]: selected /dev/ptp0 as PTP clock
ptp4l[728.288]: port 1: INITIALIZING to LISTENING on INITIALIZE
ptp4l[728.288]: port 0: INITIALIZING to LISTENING on INITIALIZE
ptp4l[729.462]: port 1: new foreign master ece555.fffe.2de639-2
ptp4l[733.452]: selected best master clock ece555.fffe.2de639
ptp4l[733.452]: port 1: LISTENING to UNCALIBRATED on RS_SLAVE
I just noticed this. This is weird..
Post by Гаврилов Александр
ptp4l[734.458]: recvmsg tx timestamp failed: Resource temporarily unavailable
You get the tx timestamp failed error instead of the polling failed
error. That means that the LinuxPTP attempts to poll and then still
fails to receive the message. I am very unsure why this happens. I
believe this is the right place to look regarding the issue.
Post by Гаврилов Александр
ptp4l[734.458]: port 1: send peer delay request failed
ptp4l[734.458]: port 1: UNCALIBRATED to FAULTY on FAULT_DETECTED
Post by Keller, Jacob E
I wrote the original igb ptp code, but I never tested the 82576
because I don't have one. I am not sure if Intel tested this either.
Richard wrote the original patch which added PTP support into the
driver, and then a developer here on my team updated it to support newer
devices. I know the validation team for the driver did some testing, but
the 82576 is not very good for PTP. (details on why below)
Post by Гаврилов Александр
Post by Keller, Jacob E
Basically, the 82576 is not a very reliable part for timestamping...
What kind of adapter would you recommend instead of 82576? (gigabit).
Richard suggested the i210, and I also would recommend this part.
Obviously I am somewhat biased as I am an Intel engineer. However this
part definitely is better than the 82576 because it supports
timestamping all packets (vastly reducing issues)
Post by Гаврилов Александр
Basically, the 82576 is not a very reliable part for timestamping.
Why?
Sincerely, Alexander.
The 82576 was one of the first parts Intel ND did with 1588 support. The
hardware was done years before we had a stable PTP kernel support, and
before a lot of things were understood well, and therefor the design of
the MAC chip does not really work well for 1588 support. Mainly, when
timestamping it can only store one timestamp for RX and TX and the
driver has to process packets fast enough, otherwise dropped timestamps
can occur. This is the issue you are seeing. Newer parts have solved
this issue by enabling the device to insert a timestamp for each packet
directly into the packet buffer.
Post by Гаврилов Александр
In any case, thank you very much!
I asked Matthew Vick, the developer who worked on the igb driver, and
did the refreshed PTP work. He has since moved onto other work so he
does not have much time to work on this. However, he did some touch
testing of the 82576, and was able to get it to work.76e10e95

I believe the likely issue you are seeing is related to the switch you
are working against (he tried back to back).

Do you know the Sync transmit rate? It is normally once per second.
However some switches set this to a much higher rate. This causes issues
because the 82576 part cannot really handle timestamping packets if they
arrive too quickly together, which would be the result of dropped
timestamps.

some questions, and other information that may help:

1)
if you are comfortable instrumenting LinuxPTP code, could you please add
some pr_err() calls into sk.c's sk_receive call around line 221? This is
really bothering me that the poll isn't timing out and is indeed waking
up with something on the error queue when there is nothing there.

2)
could you get a dmesg log for your device, and also an ethtool -i on
your device so I know the igb version number you are using...

3)
what is the sync rate of the switch? once per second? or faster?

4)
could you send me a packet dump of the packets transmitted? via
tcpdump..

I am very concerned because you are in an incredibly weird state.. It
looks like poll() succeeds but then recvmsg fails, which is just not
good. I don't know what could be causing this...

Hope we can debug this and resolve the issue..

Thanks,
Jak
Dale Smith
2013-08-02 18:36:13 UTC
Permalink
Post by Keller, Jacob E
Richard suggested the i210, and I also would recommend this part.
Obviously I am somewhat biased as I am an Intel engineer. However this
part definitely is better than the 82576 because it supports
timestamping all packets (vastly reducing issues)
Something I'm unclear on after reading the i210 datasheets, is if it is
possible for it to use an external servoed vcxo or the like for the 1588
clock, or does it only do the missing pulse / extra pulse thing to adjust
the 1588 clock frequency?

Thanks,
-Dale
Keller, Jacob E
2013-08-02 20:16:01 UTC
Permalink
On Fri, Aug 2, 2013 at 1:54 PM, Keller, Jacob E
Richard suggested the i210, and I also would recommend this part.
Obviously I am somewhat biased as I am an Intel engineer. However this
part definitely is better than the 82576 because it supports
timestamping all packets (vastly reducing issues)
Something I'm unclear on after reading the i210 datasheets, is if it
is possible for it to use an external servoed vcxo or the like for the
1588 clock, or does it only do the missing pulse / extra pulse thing
to adjust the 1588 clock frequency?
Thanks,
-Dale
I do not believe you can use an external servo to create the 1588 clock.
You may, however, be able to use an external PPS signal and have that
timestamped and software tune the onboard 1588 clock frequency.
Dale Smith
2013-08-02 21:20:20 UTC
Permalink
Yeah, that's pretty much what I suspected.

A reason you want to use something like a vcxo, is so get get a really
clean clock for driving things like A2D converters. It's important if you
are doing signal analysis. A fixed frequency clock with pulse
addition/subtraction to get the right number of clocks edges per second
just doesn't cut it.

Thanks,
-Dale
Post by Keller, Jacob E
On Fri, Aug 2, 2013 at 1:54 PM, Keller, Jacob E
Richard suggested the i210, and I also would recommend this part.
Obviously I am somewhat biased as I am an Intel engineer. However this
part definitely is better than the 82576 because it supports
timestamping all packets (vastly reducing issues)
Something I'm unclear on after reading the i210 datasheets, is if it
is possible for it to use an external servoed vcxo or the like for the
1588 clock, or does it only do the missing pulse / extra pulse thing
to adjust the 1588 clock frequency?
Thanks,
-Dale
I do not believe you can use an external servo to create the 1588 clock.
You may, however, be able to use an external PPS signal and have that
timestamped and software tune the onboard 1588 clock frequency.
I don't know this for certain though.
Thanks,
Jake
Keller, Jacob E
2013-08-02 23:30:10 UTC
Permalink
I agree with you.. But the architects here usually just consider
1588/PTP support sort of a "best effort" when designing the hardware.
That tends towards not really properly supporting the feature. At least
early on there weren't many hardware guys here who actually understood
what PTP needed either, so some of the older designs just don't quite do
the right thing.

That is why some of the designs really don't work quite as well as one
would like.

Thanks,
Jake
Post by Dale Smith
Yeah, that's pretty much what I suspected.
A reason you want to use something like a vcxo, is so get get a really
clean clock for driving things like A2D converters. It's important if
you are doing signal analysis. A fixed frequency clock with pulse
addition/subtraction to get the right number of clocks edges per
second just doesn't cut it.
Thanks,
-Dale
On Fri, Aug 2, 2013 at 4:16 PM, Keller, Jacob E
On Fri, Aug 2, 2013 at 1:54 PM, Keller, Jacob E
Richard suggested the i210, and I also would
recommend this
part.
Obviously I am somewhat biased as I am an Intel
engineer.
However this
part definitely is better than the 82576 because it
supports
timestamping all packets (vastly reducing issues)
Something I'm unclear on after reading the i210 datasheets,
is if it
is possible for it to use an external servoed vcxo or the
like for the
1588 clock, or does it only do the missing pulse / extra
pulse thing
to adjust the 1588 clock frequency?
Thanks,
-Dale
I do not believe you can use an external servo to create the 1588 clock.
You may, however, be able to use an external PPS signal and have that
timestamped and software tune the onboard 1588 clock
frequency.
I don't know this for certain though.
Thanks,
Гаврилов Александр
2013-08-02 06:48:40 UTC
Permalink
Post by Keller, Jacob E
Basically, the 82576 is not a very reliable part for timestamping.
Why?

Sincerely, Alexander.
Гаврилов Александр
2013-08-03 08:14:43 UTC
Permalink
Hello!
I would recommend the i210. It is not expensive, and it has excellent capabilities.
We need fiber optic interface (for example, I350F, but it is too
expensive for us, we will try to use 82576).
Would it be possible for you to attempt using LinuxPTP 1.3
Ok, i try.

------------------------------------------------------

DMESG log:
3.949188] igb: module verification failed: signature and/or required key missing - tainting kernel
[ 3.949987] Intel(R) Gigabit Ethernet Network Driver - version 4.3.0
[ 3.949990] Copyright (c) 2007-2013 Intel Corporation.
[ 3.952065] igb 0000:04:00.0: irq 49 for MSI/MSI-X
[ 3.952074] igb 0000:04:00.0: irq 50 for MSI/MSI-X
[ 3.982512] igb 0000:04:00.0: added PHC on eth0
[ 3.982516] igb 0000:04:00.0: Intel(R) Gigabit Ethernet Network Connection
[ 3.982518] igb 0000:04:00.0: eth0: (PCIe:2.5GT/s:Width x4)
[ 3.982520] igb 0000:04:00.0: eth0: MAC:
[ 3.982521] 00:1b:21:d9:ef:34
[ 3.982596] igb 0000:04:00.0: eth0: PBA No: E31745-004
[ 3.982597] igb 0000:04:00.0: LRO is disabled
[ 3.982599] igb 0000:04:00.0: Using MSI-X interrupts. 1 rx queue(s), 1 tx queue(s)
[ 3.983868] igb 0000:04:00.1: irq 51 for MSI/MSI-X
[ 3.983875] igb 0000:04:00.1: irq 52 for MSI/MSI-X
[ 3.986161] microcode: CPU0 sig=0x1067a, pf=0x10, revision=0xa07
[ 3.989520] tun: Universal TUN/TAP device driver, 1.6
[ 3.989522] tun: (C) 1999-2004 Max Krasnyansky <***@qualcomm.com>
[ 4.014485] igb 0000:04:00.1: added PHC on eth1
[ 4.014489] igb 0000:04:00.1: Intel(R) Gigabit Ethernet Network Connection
[ 4.014491] igb 0000:04:00.1: eth1: (PCIe:2.5GT/s:Width x4)
[ 4.014493] igb 0000:04:00.1: eth1: MAC:
[ 4.014494] 00:1b:21:d9:ef:35
[ 4.014568] igb 0000:04:00.1: eth1: PBA No: E31745-004
[ 4.014570] igb 0000:04:00.1: LRO is disabled
[ 4.014572] igb 0000:04:00.1: Using MSI-X interrupts. 1 rx queue(s), 1 tx queue(s)
[ 36.905039] igb: p16p1 NIC Link is Up 1000 Mbps Full Duplex, Flow Control: None
[ 348.347009] igb 0000:04:00.0: clearing Tx timestamp hang
[ 371.862010] igb 0000:04:00.0: clearing Tx timestamp hang
[ 429.447013] igb 0000:04:00.0: clearing Tx timestamp hang
[ 475.400010] igb 0000:04:00.0: clearing Tx timestamp hang
[ 504.270012] igb 0000:04:00.0: clearing Tx timestamp hang

------------------------------------------------------

ETHTOOL:
[***@lab32 linuxptp-1.3]# ethtool -i p16p1
driver: igb
version: 4.3.0
firmware-version: 1.2.1
bus-info: 0000:04:00.0
supports-statistics: yes
supports-test: yes
supports-eeprom-access: yes
supports-register-dump: yes
supports-priv-flags: no

------------------------------------------------------

ptp4l.conf:

[global]
#
# Default Data Set
#
twoStepFlag 1
slaveOnly 1
priority1 128
priority2 128
domainNumber 0
clockClass 248
clockAccuracy 0xFE
offsetScaledLogVariance 0xFFFF
free_running 0
freq_est_interval 1
#
# Port Data Set
#
logAnnounceInterval 1
logSyncInterval 0
logMinDelayReqInterval 1
logMinPdelayReqInterval 1
announceReceiptTimeout 3
delayAsymmetry 0
#
# Run time options
#
assume_two_step 1
logging_level 6
path_trace_enabled 0
follow_up_info 0
#tx_timestamp_retries 1
tx_timestamp_timeout 1000
use_syslog 1
verbose 0
#
# Servo Options
#
pi_proportional_const 0.0
pi_integral_const 0.0
pi_offset_const 0.0
clock_servo pi
#
# Transport options
#
transportSpecific 0x0
ptp_dst_mac 01:1B:19:00:00:00
p2p_dst_mac 01:80:C2:00:00:0E
udp6_scope 0x0E
#
# Default interface options
#
network_transport L2
delay_mechanism E2E
time_stamping hardware

------------------------------------------------------

[***@lab32 linuxptp-1.3]# ptp4l -f "ptp4l.conf" -i p16p1 -m
ptp4l[2946.559]: selected /dev/ptp0 as PTP clock
ptp4l[2946.573]: port 1: INITIALIZING to LISTENING on INITIALIZE
ptp4l[2946.573]: port 0: INITIALIZING to LISTENING on INITIALIZE
ptp4l[2947.895]: port 1: new foreign master ece555.fffe.2de639-2
ptp4l[2951.885]: selected best master clock ece555.fffe.2de639
ptp4l[2951.885]: port 1: LISTENING to UNCALIBRATED on RS_SLAVE
ptp4l[2955.029]: poll tx timestamp timeout
ptp4l[2955.029]: port 1: send delay request failed
ptp4l[2955.029]: port 1: UNCALIBRATED to FAULTY on FAULT_DETECTED (FT_UNSPECIFIED)

wireshark:

31 9.975069000 Hirschma_2d:e6:39 IeeeI&MS_00:00:00 PTPv2 60 Sync Message

Ethernet II, Src: Hirschma_2d:e6:39 (ec:e5:55:2d:e6:39), Dst: IeeeI&MS_00:00:00 (01:1b:19:00:00:00)
.... 0010 = versionPTP: 2
correction: 0,000000 nanoseconds
ClockIdentity: 0xece555fffe2de639
ptp.v2.flags == 0x0200
originTimestamp (seconds): 1375519750
originTimestamp (nanoseconds): 317139647

32 9.975971000 Hirschma_2d:e6:39 IeeeI&MS_00:00:00 PTPv2 60 Follow_Up Message
33 10.972569000 Hirschma_2d:e6:39 IeeeI&MS_00:00:00 PTPv2 60 Sync Message
34 10.973499000 Hirschma_2d:e6:39 IeeeI&MS_00:00:00 PTPv2 60 Follow_Up Message
35 10.973698000 Hirschma_2d:e6:39 IeeeI&MS_00:00:00 PTPv2 78 Announce Message
36 11.121565000 IntelCor_d9:ef:34 IeeeI&MS_00:00:00 PTPv2 58 Delay_Req Message
37 11.122969000 Hirschma_2d:e6:39 IeeeI&MS_00:00:00 PTPv2 68 Delay_Resp Message
38 11.511230000 Hirschma_2d:e6:42 Spanning-tree-(for-bridges)_00 STP 60 RST. Root = 32768/0/ec:e5:55:2d:e6:39 Cost = 0 Port = 0x8002
39 11.970068000 Hirschma_2d:e6:39 IeeeI&MS_00:00:00 PTPv2 60 Sync Message

Sincerely, Alexander.
Richard Cochran
2013-08-03 13:31:22 UTC
Permalink
Post by Гаврилов Александр
#tx_timestamp_retries 1
tx_timestamp_timeout 1000
Good ...
Post by Гаврилов Александр
ptp4l[2946.559]: selected /dev/ptp0 as PTP clock
ptp4l[2946.573]: port 1: INITIALIZING to LISTENING on INITIALIZE
ptp4l[2946.573]: port 0: INITIALIZING to LISTENING on INITIALIZE
ptp4l[2947.895]: port 1: new foreign master ece555.fffe.2de639-2
ptp4l[2951.885]: selected best master clock ece555.fffe.2de639
ptp4l[2951.885]: port 1: LISTENING to UNCALIBRATED on RS_SLAVE
ptp4l[2955.029]: poll tx timestamp timeout
^^^^^^^^^^^^^^^^^^^^^^^^^
Post by Гаврилов Александр
ptp4l[2955.029]: port 1: send delay request failed
Hm, before you had:

ptp4l[3709.401]: port 1: LISTENING to UNCALIBRATED on RS_SLAVE
ptp4l[3710.039]: recvmsg tx timestamp failed: Resource temporarily unavailable
ptp4l[3710.039]: port 1: send delay request failed

ptp4l[733.452]: port 1: LISTENING to UNCALIBRATED on RS_SLAVE
ptp4l[734.458]: recvmsg tx timestamp failed: Resource temporarily unavailable
ptp4l[734.458]: port 1: send peer delay request failed

So I suspect that you were running a version prior to 1.2, can that be
true?

In any case, the hardware is clearly missing time stamps. You can just
ignore this error. What happens when you let the program continue?
Does every delay request throw an error, or do some succeed?

If only some of the messages fail, then you can just set the
fault_reset_interval config option to "ASAP" to avoid the long fault
time.

HTH,
Richard
Гаврилов Александр
2013-08-03 09:12:22 UTC
Permalink
My problem - any way get time values from 82576 in program. May be, through modification of the source code driver igb-4.3.0, or ptp4l. We havent time to buy a new card. What can you recommend?

Sincerely, Alexander.
Richard Cochran
2013-08-03 13:40:13 UTC
Permalink
Post by Гаврилов Александр
My problem - any way get time values from 82576 in program. May be,
through modification of the source code driver igb-4.3.0, or
ptp4l. We havent time to buy a new card. What can you recommend?
I doubt you can fix this by changing the source code. It appears that
the *hardware* is dropping the time stamps.

[ It might possibly be a driver issue, but to find out and fix this
you need to read and understand both the 82576 data sheet and the
igb driver, and then figure out what is going wrong. ]

If you find that only some of the Tx time stamps are being missed,
then you can change the fault reset option to ASAP, to let the ptp4l
program continue without the pauses after the faults.

HTH,
Richard
Alex Gavrilov
2013-08-03 14:33:29 UTC
Permalink
Post by Richard Cochran
So I suspect that you were running a version prior to 1.2, can that be
true?

Yes, i ran 1.0 version, this is my bug, sorry.
Post by Richard Cochran
In any case, the hardware is clearly missing time stamps. You can just ignore this error. What happens when you let the program continue? Does every delay request throw an error, or do some succeed?
1 time hardware clock was synchronized, and in the application i see
what time "/dev/ptp0" synchronizes (through clock_gettime). But again
it did not work. I also thought that if the synchronization happens
sometimes, even with errors, we would arrange this option. But the
synchronization is no longer happening, how much we try to.
Post by Richard Cochran
If only some of the messages fail, then you can just set the fault_reset_interval config option to "ASAP" to avoid the long fault time.
Okay, I'll try it.
Post by Richard Cochran
In any case, the hardware is clearly missing time stamps.
In what could be the reason? Switch sync time is too long (2 sec).
My boss does not believe that the Intel certified card can not be
fully tested and have a hardware error.

Can I get an official response from Intel about this card (or any
official response to convince my boss, they 2 months not responding).

Sincerely, Alexander.
Richard Cochran
2013-08-03 17:02:18 UTC
Permalink
Post by Alex Gavrilov
1 time hardware clock was synchronized, and in the application i see
what time "/dev/ptp0" synchronizes (through clock_gettime). But again
it did not work.
What did not work?
Post by Alex Gavrilov
I also thought that if the synchronization happens
sometimes, even with errors, we would arrange this option. But the
synchronization is no longer happening, how much we try to.
Are you talking about the Linux system time? If so, you can
sychronize it to /dev/ptp0 using the phc2sys program.
Post by Alex Gavrilov
In what could be the reason? Switch sync time is too long (2 sec).
My boss does not believe that the Intel certified card can not be
fully tested and have a hardware error.
Hardware ships with bugs. It is a fact of life.

When bugs are discovered, an erratum is published that tells you that
the bug does exist. Intel calls their errata "Specification Update".
You should look if there is one for the 82576.

Even if none have been published, that doesn't mean there aren't
hardware bugs. You and your boss might find this document interesting.
It describes an Intel PTP hardware implementation with bugs.

http://www.intel.com/content/dam/www/public/us/en/documents/specification-updates/ixp4xx-product-line-network-processors-spec-update.pdf

Look especially at Item #40 on page 39:

40. IEEE-1588 Time Sync Lock-up Fails to Time-Stamp a Second PTP Message

Problem: A lock-up condition has been identified in the
IEEE-1588 Time Sync block that prevents all subsequent
messages form being time-stamped. It occurs when a
message has been time-stamped and the registers are
locked, after which - if a new message comes in before
the previous time stamp is read and the lock bit is
cleared - the Time Sync block enters a lock-up
condition and prevents all furthers messages from
being time-stamped. This occurs for both received and
transmitted messages.

Implication: Under very typical usage scenarios, the IEEE-1588 unit
can lock up and will not capture time stamps after the
initial one is locked.

Workaround: If IEEE-1588 functionality is required, it must be
implemented with external hardware.

This says that PTP function in the silicon is totally useless.
Post by Alex Gavrilov
Can I get an official response from Intel about this card (or any
official response to convince my boss, they 2 months not responding).
Maybe you can, but don't hold your breath.

Thanks,
Richard
Alex Gavrilov
2013-08-03 19:08:08 UTC
Permalink
Post by Richard Cochran
What did not work?
Richard, you wrote: "In any case, the hardware is clearly missing time
stamps. You can just ignore this error.". But these errors are
constantly - during 4 hours only once sinchronization was happened.
Tomorrow i write this moment from ptp4l log (saved on my work).
Post by Richard Cochran
Are you talking about the Linux system time? If so, you can sychronize it to /dev/ptp0 using the phc2sys program.
I need to get the exact time value in "/dev/ptp0" and query from my program
through clock_gettime(ID_PTP0, timeval);
Post by Richard Cochran
Hardware ships with bugs. It is a fact of life. ......
Spec update for 82576 not contains bugs with 1588:

http://www.intel.com/content/www/us/en/ethernet-controllers/82576eb-gigabit-ethernet-controller-spec-update.html

How a series of 210, 350, 82576 refers to a series of IXPxxx?

Thank you very much for your answers!

Sincerely, Alexander.
Richard Cochran
2013-08-04 05:20:42 UTC
Permalink
Post by Alex Gavrilov
Post by Richard Cochran
What did not work?
Richard, you wrote: "In any case, the hardware is clearly missing time
stamps. You can just ignore this error.". But these errors are
constantly - during 4 hours only once sinchronization was happened.
You mean that only one delay request every four hours is successful?

The PTP can work will occasional dropping of messages, but what you
have here is obviously not good enough.
Okay, but after you finish with Intel, you can expect to see a new
erratum published.
Post by Alex Gavrilov
How a series of 210, 350, 82576 refers to a series of IXPxxx?
This is just an example of a real life hardware bug from Intel. You
said that your boss cannot believe such a thing is possible. However,
it is not a matter of belief, hardware bugs are an undeniable fact.

If I were you, I would post your issue to the e1000-devel mailing
list. It is most probably a hardware bug (but perhaps a driver bug).
In any case, it is not a bug in linuxptp.

Also, buy another card.
Гаврилов Александр
2013-08-05 06:56:23 UTC
Permalink
Hello!

Here is an example of the log where synchronization occured:

-----------------------------------------------------------------------

ptp4l -2 -i p16p1 -m -H -s
ptp4l[17534.938]: selected /dev/ptp0 as PTP clock
ptp4l[17534.957]: port 1: INITIALIZING to LISTENING on INITIALIZE
ptp4l[17534.957]: port 0: INITIALIZING to LISTENING on INITIALIZE
ptp4l[17536.761]: port 1: new foreign master ece555.fffe.2de639-2
ptp4l[17540.751]: selected best master clock ece555.fffe.2de639
ptp4l[17540.751]: port 1: LISTENING to UNCALIBRATED on RS_SLAVE
ptp4l[17542.696]: port 1: minimum delay request interval 2^3
ptp4l[17542.746]: master offset 50001478246023551 s0 adj +0 path delay 1276
ptp4l[17543.744]: master offset 50001478246021573 s0 adj +0 path delay 974
ptp4l[17544.741]: master offset 50001478246019277 s0 adj +0 path delay 974
ptp4l[17545.739]: master offset 50001478246016997 s1 adj +0 path delay 974
ptp4l[17546.736]: master offset -5048 s2 adj -5048 path delay 974
ptp4l[17546.736]: port 1: UNCALIBRATED to SLAVE on MASTER_CLOCK_SELECTED
ptp4l[17547.734]: master offset -2323 s2 adj -3837 path delay 974
ptp4l[17548.732]: master offset -789 s2 adj -3000 path delay 974
ptp4l[17549.729]: master offset -95 s2 adj -2543 path delay 974
ptp4l[17550.726]: master offset 123 s2 adj -2354 path delay 974
ptp4l[17551.724]: master offset 110 s2 adj -2330 path delay 974
ptp4l[17552.721]: master offset 106 s2 adj -2301 path delay 974
ptp4l[17553.719]: master offset 109 s2 adj -2266 path delay 974
ptp4l[17554.716]: master offset 104 s2 adj -2238 path delay 974
ptp4l[17555.714]: master offset -27 s2 adj -2338 path delay 974
ptp4l[17556.711]: master offset -48 s2 adj -2367 path delay 974
ptp4l[17557.709]: master offset -53 s2 adj -2386 path delay 974
ptp4l[17558.706]: master offset 45 s2 adj -2304 path delay 974
ptp4l[17559.704]: master offset 275 s2 adj -2061 path delay 716
ptp4l[17560.701]: master offset 9 s2 adj -2244 path delay 716
ptp4l[17561.699]: master offset -131 s2 adj -2382 path delay 716
ptp4l[17562.696]: master offset -176 s2 adj -2466 path delay 716
ptp4l[17563.694]: master offset -102 s2 adj -2445 path delay 716
ptp4l[17564.691]: master offset -28 s2 adj -2401 path delay 716
ptp4l[17565.689]: master offset 47 s2 adj -2335 path delay 716
ptp4l[17566.686]: master offset 2 s2 adj -2366 path delay 716
ptp4l[17567.684]: master offset -27 s2 adj -2394 path delay 716
ptp4l[17568.681]: master offset 40 s2 adj -2335 path delay 716
ptp4l[17569.679]: master offset -13 s2 adj -2376 path delay 716
ptp4l[17570.676]: master offset 69 s2 adj -2298 path delay 589
ptp4l[17571.674]: master offset 9 s2 adj -2337 path delay 589
ptp4l[17572.671]: master offset -52 s2 adj -2396 path delay 589
ptp4l[17572.955]: recvmsg tx timestamp failed: Resource temporarily unavailable
ptp4l[17572.955]: port 1: send delay request failed
ptp4l[17572.955]: port 1: SLAVE to FAULTY on FAULT_DETECTED
ptp4l[17591.068]: port 1: FAULTY to LISTENING on FAULT_CLEARED
ptp4l[17592.622]: port 1: new foreign master ece555.fffe.2de639-2
ptp4l[17596.612]: selected best master clock ece555.fffe.2de639
ptp4l[17596.612]: port 1: LISTENING to UNCALIBRATED on RS_SLAVE
ptp4l[17597.609]: master offset 1492 s2 adj -867 path delay 589
ptp4l[17597.609]: port 1: UNCALIBRATED to SLAVE on MASTER_CLOCK_SELECTED
ptp4l[17597.654]: recvmsg tx timestamp failed: Resource temporarily unavailable
ptp4l[17597.654]: port 1: send delay request failed
ptp4l[17597.654]: port 1: SLAVE to FAULTY on FAULT_DETECTED

-----------------------------------------------------------------------

I350-F2 - can you recommend this ethernet adapter
as alternative? (gigabit, fiber optic interface)
Keller, Jacob E
2013-08-05 20:26:04 UTC
Permalink
-----Original Message-----
Sent: Sunday, August 04, 2013 11:56 PM
Subject: Re: [Linuxptp-users] Hardware PTP clock synchronization
Hello!
-----------------------------------------------------------------------
ptp4l -2 -i p16p1 -m -H -s
ptp4l[17534.938]: selected /dev/ptp0 as PTP clock
ptp4l[17534.957]: port 1: INITIALIZING to LISTENING on INITIALIZE
ptp4l[17534.957]: port 0: INITIALIZING to LISTENING on INITIALIZE
ptp4l[17536.761]: port 1: new foreign master ece555.fffe.2de639-2
ptp4l[17540.751]: selected best master clock ece555.fffe.2de639
ptp4l[17540.751]: port 1: LISTENING to UNCALIBRATED on RS_SLAVE
ptp4l[17542.696]: port 1: minimum delay request interval 2^3
ptp4l[17542.746]: master offset 50001478246023551 s0 adj +0 path delay 1276
ptp4l[17543.744]: master offset 50001478246021573 s0 adj +0 path delay 974
ptp4l[17544.741]: master offset 50001478246019277 s0 adj +0 path delay 974
ptp4l[17545.739]: master offset 50001478246016997 s1 adj +0 path delay 974
ptp4l[17546.736]: master offset -5048 s2 adj -5048 path delay
974
ptp4l[17546.736]: port 1: UNCALIBRATED to SLAVE on
MASTER_CLOCK_SELECTED
ptp4l[17547.734]: master offset -2323 s2 adj -3837 path delay
974
ptp4l[17548.732]: master offset -789 s2 adj -3000 path delay 974
ptp4l[17549.729]: master offset -95 s2 adj -2543 path delay 974
ptp4l[17550.726]: master offset 123 s2 adj -2354 path delay 974
ptp4l[17551.724]: master offset 110 s2 adj -2330 path delay 974
ptp4l[17552.721]: master offset 106 s2 adj -2301 path delay 974
ptp4l[17553.719]: master offset 109 s2 adj -2266 path delay 974
ptp4l[17554.716]: master offset 104 s2 adj -2238 path delay 974
ptp4l[17555.714]: master offset -27 s2 adj -2338 path delay 974
ptp4l[17556.711]: master offset -48 s2 adj -2367 path delay 974
ptp4l[17557.709]: master offset -53 s2 adj -2386 path delay 974
ptp4l[17558.706]: master offset 45 s2 adj -2304 path delay 974
ptp4l[17559.704]: master offset 275 s2 adj -2061 path delay 716
ptp4l[17560.701]: master offset 9 s2 adj -2244 path delay 716
ptp4l[17561.699]: master offset -131 s2 adj -2382 path delay 716
ptp4l[17562.696]: master offset -176 s2 adj -2466 path delay 716
ptp4l[17563.694]: master offset -102 s2 adj -2445 path delay 716
ptp4l[17564.691]: master offset -28 s2 adj -2401 path delay 716
ptp4l[17565.689]: master offset 47 s2 adj -2335 path delay 716
ptp4l[17566.686]: master offset 2 s2 adj -2366 path delay 716
ptp4l[17567.684]: master offset -27 s2 adj -2394 path delay 716
ptp4l[17568.681]: master offset 40 s2 adj -2335 path delay 716
ptp4l[17569.679]: master offset -13 s2 adj -2376 path delay 716
ptp4l[17570.676]: master offset 69 s2 adj -2298 path delay 589
ptp4l[17571.674]: master offset 9 s2 adj -2337 path delay 589
ptp4l[17572.671]: master offset -52 s2 adj -2396 path delay 589
ptp4l[17572.955]: recvmsg tx timestamp failed: Resource temporarily unavailable
ptp4l[17572.955]: port 1: send delay request failed
ptp4l[17572.955]: port 1: SLAVE to FAULTY on FAULT_DETECTED
ptp4l[17591.068]: port 1: FAULTY to LISTENING on FAULT_CLEARED
ptp4l[17592.622]: port 1: new foreign master ece555.fffe.2de639-2
ptp4l[17596.612]: selected best master clock ece555.fffe.2de639
ptp4l[17596.612]: port 1: LISTENING to UNCALIBRATED on RS_SLAVE
ptp4l[17597.609]: master offset 1492 s2 adj -867 path delay 589
ptp4l[17597.609]: port 1: UNCALIBRATED to SLAVE on
MASTER_CLOCK_SELECTED
ptp4l[17597.654]: recvmsg tx timestamp failed: Resource temporarily unavailable
ptp4l[17597.654]: port 1: send delay request failed
ptp4l[17597.654]: port 1: SLAVE to FAULTY on FAULT_DETECTED
-----------------------------------------------------------------------
I350-F2 - can you recommend this ethernet adapter
as alternative? (gigabit, fiber optic interface)
It still appears to be running version 1.0. Could you please ensure you have updated to v1.2 or v1.3 and try again?

In regards to "hardware bugs"... the 82576 is not "bugged" or "glitched" so much as it is simply flawed. It has a design bug or flaw, but it is doing exactly what it was designed to do.

However, I believe you really need to update to ptp4l v1.2 since this has resolved a rather important issue around polling for Tx timestamps, and vastly reduces issues with software dropping Tx timestamps because it couldn't process them fast enough.

In addition it may be the case that you need to update your kernel. I don't recall any specific fixes for this type of issue but it is possible.

And yes, I would highly suggest posting on the e1000-devel list, because that would get proper recognition from among other folks at Intel..

While Intel's Ethernet products are validated and certified.. I don't believe much 1588/PTP testing and certification is done, especially on older hardware.

- Jake
Richard Cochran
2013-08-06 07:43:33 UTC
Permalink
Post by Гаврилов Александр
Hello!
This is interesting...
Post by Гаврилов Александр
ptp4l -2 -i p16p1 -m -H -s
ptp4l[17534.938]: selected /dev/ptp0 as PTP clock
ptp4l[17534.957]: port 1: INITIALIZING to LISTENING on INITIALIZE
ptp4l[17534.957]: port 0: INITIALIZING to LISTENING on INITIALIZE
ptp4l[17536.761]: port 1: new foreign master ece555.fffe.2de639-2
ptp4l[17540.751]: selected best master clock ece555.fffe.2de639
ptp4l[17540.751]: port 1: LISTENING to UNCALIBRATED on RS_SLAVE
ptp4l[17542.696]: port 1: minimum delay request interval 2^3
The average delay request interval is eight seconds.
Post by Гаврилов Александр
ptp4l[17542.746]: master offset 50001478246023551 s0 adj +0 path delay 1276
ptp4l[17543.744]: master offset 50001478246021573 s0 adj +0 path delay 974
ptp4l[17544.741]: master offset 50001478246019277 s0 adj +0 path delay 974
ptp4l[17545.739]: master offset 50001478246016997 s1 adj +0 path delay 974
ptp4l[17546.736]: master offset -5048 s2 adj -5048 path delay 974
ptp4l[17546.736]: port 1: UNCALIBRATED to SLAVE on MASTER_CLOCK_SELECTED
ptp4l[17547.734]: master offset -2323 s2 adj -3837 path delay 974
ptp4l[17548.732]: master offset -789 s2 adj -3000 path delay 974
ptp4l[17549.729]: master offset -95 s2 adj -2543 path delay 974
ptp4l[17550.726]: master offset 123 s2 adj -2354 path delay 974
ptp4l[17551.724]: master offset 110 s2 adj -2330 path delay 974
ptp4l[17552.721]: master offset 106 s2 adj -2301 path delay 974
ptp4l[17553.719]: master offset 109 s2 adj -2266 path delay 974
ptp4l[17554.716]: master offset 104 s2 adj -2238 path delay 974
ptp4l[17555.714]: master offset -27 s2 adj -2338 path delay 974
ptp4l[17556.711]: master offset -48 s2 adj -2367 path delay 974
ptp4l[17557.709]: master offset -53 s2 adj -2386 path delay 974
ptp4l[17558.706]: master offset 45 s2 adj -2304 path delay 974
Looking at the last column (moving average of the path delay), you
have two successful path delay measurements ...
Post by Гаврилов Александр
ptp4l[17559.704]: master offset 275 s2 adj -2061 path delay 716
... now three ...
Post by Гаврилов Александр
ptp4l[17560.701]: master offset 9 s2 adj -2244 path delay 716
ptp4l[17561.699]: master offset -131 s2 adj -2382 path delay 716
ptp4l[17562.696]: master offset -176 s2 adj -2466 path delay 716
ptp4l[17563.694]: master offset -102 s2 adj -2445 path delay 716
ptp4l[17564.691]: master offset -28 s2 adj -2401 path delay 716
ptp4l[17565.689]: master offset 47 s2 adj -2335 path delay 716
ptp4l[17566.686]: master offset 2 s2 adj -2366 path delay 716
ptp4l[17567.684]: master offset -27 s2 adj -2394 path delay 716
ptp4l[17568.681]: master offset 40 s2 adj -2335 path delay 716
ptp4l[17569.679]: master offset -13 s2 adj -2376 path delay 716
ptp4l[17570.676]: master offset 69 s2 adj -2298 path delay 589
... and now four ...
Post by Гаврилов Александр
ptp4l[17571.674]: master offset 9 s2 adj -2337 path delay 589
ptp4l[17572.671]: master offset -52 s2 adj -2396 path delay 589
ptp4l[17572.955]: recvmsg tx timestamp failed: Resource temporarily unavailable
ptp4l[17572.955]: port 1: send delay request failed
... and the fifth one fails.
Post by Гаврилов Александр
ptp4l[17572.955]: port 1: SLAVE to FAULTY on FAULT_DETECTED
ptp4l[17591.068]: port 1: FAULTY to LISTENING on FAULT_CLEARED
ptp4l[17592.622]: port 1: new foreign master ece555.fffe.2de639-2
ptp4l[17596.612]: selected best master clock ece555.fffe.2de639
ptp4l[17596.612]: port 1: LISTENING to UNCALIBRATED on RS_SLAVE
ptp4l[17597.609]: master offset 1492 s2 adj -867 path delay 589
ptp4l[17597.609]: port 1: UNCALIBRATED to SLAVE on MASTER_CLOCK_SELECTED
ptp4l[17597.654]: recvmsg tx timestamp failed: Resource temporarily unavailable
ptp4l[17597.654]: port 1: send delay request failed
ptp4l[17597.654]: port 1: SLAVE to FAULTY on FAULT_DETECTED
In order to get the best out of the 82576, I recommend:

1. Make sure you are using the latest version (ptp4l -v).

2. Set tx_timestamp_timeout to 1000.

3. Set fault_reset_interval to ASAP.

4. If the above steps do not yield reasonable results, then recompile
the driver, changing IGB_PTP_TX_TIMEOUT from (HZ * 15) to (HZ).

It appears that the hardware is sometimes missing or dropping the Tx
time stamp on the delay request messages. Changing IGB_PTP_TX_TIMEOUT
will clear the driver's Tx time stamp timer more often. This might
make the card more responsive in the presence of time stamp loss.

Good luck,
Richard
Keller, Jacob E
2013-08-06 17:07:11 UTC
Permalink
I agree with Richard's suggestions. Could you also obtain a dmesg log as
well to go along with this when you re-test using those changes.

Thanks,
Jake
Post by Richard Cochran
Post by Гаврилов Александр
Hello!
This is interesting...
Post by Гаврилов Александр
ptp4l -2 -i p16p1 -m -H -s
ptp4l[17534.938]: selected /dev/ptp0 as PTP clock
ptp4l[17534.957]: port 1: INITIALIZING to LISTENING on INITIALIZE
ptp4l[17534.957]: port 0: INITIALIZING to LISTENING on INITIALIZE
ptp4l[17536.761]: port 1: new foreign master ece555.fffe.2de639-2
ptp4l[17540.751]: selected best master clock ece555.fffe.2de639
ptp4l[17540.751]: port 1: LISTENING to UNCALIBRATED on RS_SLAVE
ptp4l[17542.696]: port 1: minimum delay request interval 2^3
The average delay request interval is eight seconds.
Post by Гаврилов Александр
ptp4l[17542.746]: master offset 50001478246023551 s0 adj +0 path delay 1276
ptp4l[17543.744]: master offset 50001478246021573 s0 adj +0 path delay 974
ptp4l[17544.741]: master offset 50001478246019277 s0 adj +0 path delay 974
ptp4l[17545.739]: master offset 50001478246016997 s1 adj +0 path delay 974
ptp4l[17546.736]: master offset -5048 s2 adj -5048 path delay 974
ptp4l[17546.736]: port 1: UNCALIBRATED to SLAVE on MASTER_CLOCK_SELECTED
ptp4l[17547.734]: master offset -2323 s2 adj -3837 path delay 974
ptp4l[17548.732]: master offset -789 s2 adj -3000 path delay 974
ptp4l[17549.729]: master offset -95 s2 adj -2543 path delay 974
ptp4l[17550.726]: master offset 123 s2 adj -2354 path delay 974
ptp4l[17551.724]: master offset 110 s2 adj -2330 path delay 974
ptp4l[17552.721]: master offset 106 s2 adj -2301 path delay 974
ptp4l[17553.719]: master offset 109 s2 adj -2266 path delay 974
ptp4l[17554.716]: master offset 104 s2 adj -2238 path delay 974
ptp4l[17555.714]: master offset -27 s2 adj -2338 path delay 974
ptp4l[17556.711]: master offset -48 s2 adj -2367 path delay 974
ptp4l[17557.709]: master offset -53 s2 adj -2386 path delay 974
ptp4l[17558.706]: master offset 45 s2 adj -2304 path delay 974
Looking at the last column (moving average of the path delay), you
have two successful path delay measurements ...
Post by Гаврилов Александр
ptp4l[17559.704]: master offset 275 s2 adj -2061 path delay 716
... now three ...
Post by Гаврилов Александр
ptp4l[17560.701]: master offset 9 s2 adj -2244 path delay 716
ptp4l[17561.699]: master offset -131 s2 adj -2382 path delay 716
ptp4l[17562.696]: master offset -176 s2 adj -2466 path delay 716
ptp4l[17563.694]: master offset -102 s2 adj -2445 path delay 716
ptp4l[17564.691]: master offset -28 s2 adj -2401 path delay 716
ptp4l[17565.689]: master offset 47 s2 adj -2335 path delay 716
ptp4l[17566.686]: master offset 2 s2 adj -2366 path delay 716
ptp4l[17567.684]: master offset -27 s2 adj -2394 path delay 716
ptp4l[17568.681]: master offset 40 s2 adj -2335 path delay 716
ptp4l[17569.679]: master offset -13 s2 adj -2376 path delay 716
ptp4l[17570.676]: master offset 69 s2 adj -2298 path delay 589
... and now four ...
Post by Гаврилов Александр
ptp4l[17571.674]: master offset 9 s2 adj -2337 path delay 589
ptp4l[17572.671]: master offset -52 s2 adj -2396 path delay 589
ptp4l[17572.955]: recvmsg tx timestamp failed: Resource temporarily unavailable
ptp4l[17572.955]: port 1: send delay request failed
... and the fifth one fails.
Post by Гаврилов Александр
ptp4l[17572.955]: port 1: SLAVE to FAULTY on FAULT_DETECTED
ptp4l[17591.068]: port 1: FAULTY to LISTENING on FAULT_CLEARED
ptp4l[17592.622]: port 1: new foreign master ece555.fffe.2de639-2
ptp4l[17596.612]: selected best master clock ece555.fffe.2de639
ptp4l[17596.612]: port 1: LISTENING to UNCALIBRATED on RS_SLAVE
ptp4l[17597.609]: master offset 1492 s2 adj -867 path delay 589
ptp4l[17597.609]: port 1: UNCALIBRATED to SLAVE on MASTER_CLOCK_SELECTED
ptp4l[17597.654]: recvmsg tx timestamp failed: Resource temporarily unavailable
ptp4l[17597.654]: port 1: send delay request failed
ptp4l[17597.654]: port 1: SLAVE to FAULTY on FAULT_DETECTED
1. Make sure you are using the latest version (ptp4l -v).
2. Set tx_timestamp_timeout to 1000.
3. Set fault_reset_interval to ASAP.
4. If the above steps do not yield reasonable results, then recompile
the driver, changing IGB_PTP_TX_TIMEOUT from (HZ * 15) to (HZ).
It appears that the hardware is sometimes missing or dropping the Tx
time stamp on the delay request messages. Changing IGB_PTP_TX_TIMEOUT
will clear the driver's Tx time stamp timer more often. This might
make the card more responsive in the presence of time stamp loss.
Гаврилов Александр
2013-08-05 07:30:22 UTC
Permalink
Hello!

And more thing:
on my card 82676 i can read time registers directly in DOS - it work
fine. But in linux this causes an error "tx timestamp timeout".

Sincerely, Alexander.
Richard Cochran
2013-08-06 07:45:40 UTC
Permalink
Post by Гаврилов Александр
Hello!
on my card 82676 i can read time registers directly in DOS - it work
fine. But in linux this causes an error "tx timestamp timeout".
Are you running another program that sends PTP messages at the same
time as ptp4l?

If so, then this would explain the missing Tx time stamps.

Thanks,
Richard
Keller, Jacob E
2013-08-06 17:12:24 UTC
Permalink
Post by Гаврилов Александр
Hello!
on my card 82676 i can read time registers directly in DOS - it work
fine. But in linux this causes an error "tx timestamp timeout".
Sincerely, Alexander.
How are you doing this? Some other program running along side? or just
using a register read tool like ethregs, ethtool, or your own custom
one?

You should not interfere with registers of a device while it is in
operation. Especially not the 1588 registers. The Tx time stamp
registers read-once to unlatch. After they are read, the flag which
indicates that there is a time stamp available for the driver is cleared
and the hardware is free to take a new time stamp. Effectively you
trying to read directly from the registers interferes with how the
driver has to behave to function correctly!!!

Please explain what you are trying to do and why. Maybe we can find a
better way to do what you want.

I am almost certain this is
Гаврилов Александр
2013-08-05 11:58:12 UTC
Permalink
Hello!.

Intel® 82576 Gigabit Ethernet Controller Datasheet:
"On both transmit and receive sides the timestamp values are locked in registers until values are read by
software. As a result if a new PTP packet that requires time stamp arrives before software access it is
not time stamped. In some cases in the receive path a packet that was timestamped might be lost and
not reach the host. To avoid a deadlock condition on the time stamp registers the software should keep
a watch dog timer to clear locking of the time stamp register. The interval counted by such a timer
should be at least higher then the expected interval between two Sync or Delay_Req packets depends
on the node state (Master or Slave)."

How should I modify the source code of igb driver (or ptp4l) to use
the timer?

Sincerely, Alexander.
Keller, Jacob E
2013-08-05 20:20:55 UTC
Permalink
-----Original Message-----
Sent: Monday, August 05, 2013 4:58 AM
Subject: Re: [Linuxptp-users] Hardware PTP clock synchronization
Hello!.
"On both transmit and receive sides the timestamp values are locked in
registers until values are read by
software. As a result if a new PTP packet that requires time stamp arrives
before software access it is
not time stamped. In some cases in the receive path a packet that was
timestamped might be lost and
not reach the host. To avoid a deadlock condition on the time stamp
registers the software should keep
a watch dog timer to clear locking of the time stamp register. The interval
counted by such a timer
should be at least higher then the expected interval between two Sync or
Delay_Req packets depends
on the node state (Master or Slave)."
How should I modify the source code of igb driver (or ptp4l) to use
the timer?
Sincerely, Alexander.
You should not have to modify the 82576 driver code.

- Jake
Richard Cochran
2013-08-06 07:24:07 UTC
Permalink
Post by Гаврилов Александр
Hello!.
"On both transmit and receive sides the timestamp values are locked in registers until values are read by
software. As a result if a new PTP packet that requires time stamp arrives before software access it is
not time stamped. In some cases in the receive path a packet that was timestamped might be lost and
not reach the host. To avoid a deadlock condition on the time stamp registers the software should keep
a watch dog timer to clear locking of the time stamp register. The interval counted by such a timer
should be at least higher then the expected interval between two Sync or Delay_Req packets depends
on the node state (Master or Slave)."
How should I modify the source code of igb driver (or ptp4l) to use
the timer?
The timer is already implemented in the driver.

Moreover, the text you quote is about the *receive* path. You issue is
occurring on the *transmit* path.

Thanks,
Richard
Alex Gavrilov
2013-08-06 19:10:19 UTC
Permalink
Post by Keller, Jacob E
It still appears to be running version 1.0
Yes, it was one of the first experiments, on version 1.
I am currently using version 1.3, but there is no improvement.
Post by Keller, Jacob E
1. Make sure you are using the latest version (ptp4l -v).
Yes, i compiled the latest version 1.3, but command "ptp4l -v" say nothing
(version 1.0 say "1.0") - is this normal?
Post by Keller, Jacob E
2. Set tx_timestamp_timeout to 1000.
Set, no changes.
Post by Keller, Jacob E
3. Set fault_reset_interval to ASAP.
Set, faster recovering after errors.
Post by Keller, Jacob E
4. If the above steps do not yield reasonable results, then recompile
the driver, changing IGB_PTP_TX_TIMEOUT from (HZ * 15) to (HZ).
Ok, i try this tomorrow.
Post by Keller, Jacob E
Are you running another program that sends PTP messages at the same
time as ptp4l?
Running nothing, and wireshark shows only input packets from switch and
output packets from 82676, according to work of process ptp4l.

I subscribed to E1000-devel mailing list, but still not received
confirmation letter...

I try to use ptp4l in software mode - he shows big master offset (i set
difference between current system time and time in switch of one day), and
this offset does not decrease with time - any clock (realtime, /dev/ptp0)
not synchronized with time from switch. I try to set little difference -
but synchronization does not occur.

Also i found "Ptpd" project (worked only in software mode) - but i can not
get it to work (may be, i need to exactly select the parameters of its
command-line).

Richard and Jake, thank you.
Sincerely, Alexander.
Richard Cochran
2013-08-07 07:49:52 UTC
Permalink
Post by Alex Gavrilov
Post by Richard Cochran
1. Make sure you are using the latest version (ptp4l -v).
Yes, i compiled the latest version 1.3, but command "ptp4l -v" say nothing
(version 1.0 say "1.0") - is this normal?
No, it is not normal. Something is terribly wrong. What happens when
you recompile? Do you see output like this?

gcc -Wall -DVER=1.3 -I/lib/modules/3.7.10-00002-gfc74603/build/usr/include -c -o ptp4l.o ptp4l.c
^^^^^^^^^

What is the output of: ./version.sh ?

gcc -v ?
Post by Alex Gavrilov
Post by Richard Cochran
Are you running another program that sends PTP messages at the same
time as ptp4l?
Running nothing, and wireshark shows only input packets from switch and
output packets from 82676, according to work of process ptp4l.
And no other programs are reading the registers of your PCIe card,
bypassing the driver?
Post by Alex Gavrilov
I try to use ptp4l in software mode - he shows big master offset (i set
difference between current system time and time in switch of one day), and
this offset does not decrease with time - any clock (realtime, /dev/ptp0)
not synchronized with time from switch. I try to set little difference -
but synchronization does not occur.
Looking at the output from your other mail, something in your system
seems to be totally broken. The estimated frequency offset is way too
large. Can it be that your oscillator is so badly off? What
architecture is the machine that are you running?

Thanks,
Richard
Alex Gavrilov
2013-08-07 06:43:45 UTC
Permalink
Post by Keller, Jacob E
How are you doing this? Some other program running along side? or just
using a register read tool like ethregs, ethtool, or your own custom
one?

I use assembler code like this to read time registers:

.model large

test_data segment "FAR_DATA" public use16

BASE_Ethernet dd 0CE8E0000h

buffer dd 1000 dup (055555555h)
test_data ends

assume ds:test_data

.code
P386
PUBLIC _read
_read proc C far
mov ax, test_data
mov ds, ax

xor ax, ax
mov gs, ax
;precion time
mov EBX, BASE_Ethernet
;read vendor and device id
mov eax, 00
mov edx, dword ptr[GS:EBX+EAX]

mov eax, 10h
mov edx, dword ptr[GS:EBX+EAX]

mov eax, 0B638h
mov edx, dword ptr[GS:EBX+EAX]

mov eax, 0B608h
mov edx, 01000001h
mov dword ptr[GS:EBX+EAX], edx

// System time register low
mov eax, 0B600h
mov edx, dword ptr[GS:EBX+EAX]

// System time register high
mov eax, 0B604h
mov ecx, dword ptr[GS:EBX+EAX]
mov buffer+0, edx
mov buffer+4, ecx

xor ax, ax
mov ah, 86h
mov cx, 00E4h
mov dx, 0E1C0h
int 15h

mov eax, 0B600h
mov edx, dword ptr[GS:EBX+EAX]

mov eax, 0B604h
mov ecx, dword ptr[GS:EBX+EAX]

mov buffer+8, edx
mov buffer+12, ecx

mov ax, 2100h
int 21h

_read endp

================================================================================

This is output from software mode:

[***@lab32 linuxptp-1.3]# ./ptp4l -i p16p1 -m -s -2 -S
ptp4l[3662.740]: port 1: INITIALIZING to LISTENING on INITIALIZE
ptp4l[3662.740]: port 0: INITIALIZING to LISTENING on INITIALIZE
ptp4l[3663.635]: port 1: new foreign master ece555.fffe.2de639-2
ptp4l[3667.295]: selected best master clock ece555.fffe.2de639
ptp4l[3667.295]: port 1: LISTENING to UNCALIBRATED on RS_SLAVE
ptp4l[3667.433]: port 1: minimum delay request interval 2^3
ptp4l[3674.614]: master offset -3600882843951 s0 freq +0 path delay
19917808
ptp4l[3675.529]: master offset -3600965414318 s0 freq +0 path delay
19917808
ptp4l[3676.444]: master offset -3601047983089 s0 freq +0 path delay
19917808
ptp4l[3677.359]: master offset -3601130555972 s0 freq +0 path delay
19917808
ptp4l[3678.274]: master offset -3601213123527 s0 freq +0 path delay
19917808
ptp4l[3679.189]: master offset -3601295694079 s0 freq +0 path delay
19917808
ptp4l[3680.104]: master offset -3601378264480 s0 freq +0 path delay
19917808
ptp4l[3681.019]: master offset -3601460837143 s0 freq +0 path delay
19917808
ptp4l[3681.934]: master offset -3601543405035 s0 freq +0 path delay
19917808
ptp4l[3682.849]: master offset -3601617688457 s0 freq +0 path delay
11630558
ptp4l[3683.889]: master offset -3601575495165 s0 freq +0 path delay
11630558
ptp4l[3684.970]: master offset -3601491859633 s0 freq +0 path delay
11630558
ptp4l[3686.051]: master offset -3601408225417 s0 freq +0 path delay
11630558
ptp4l[3687.132]: master offset -3601324587614 s0 freq +0 path delay
11630558
ptp4l[3688.213]: master offset -3601240952059 s0 freq +0 path delay
11630558
ptp4l[3689.294]: master offset -3601157315298 s0 freq +0 path delay
11630558
ptp4l[3690.376]: master offset -3601073679242 s0 freq +0 path delay
11630558
ptp4l[3691.457]: master offset -3600990048190 s1 freq -499999 path delay
11630558
ptp4l[3692.538]: master offset 83635426 s2 freq +499999 path delay
11630558
ptp4l[3692.538]: port 1: UNCALIBRATED to SLAVE on MASTER_CLOCK_SELECTED
ptp4l[3693.618]: master offset 166278466 s2 freq +499999 path delay
11630558
ptp4l[3694.698]: master offset 248915872 s2 freq +499999 path delay
11630558
ptp4l[3695.778]: master offset 331556238 s2 freq +499999 path delay
11630558
ptp4l[3696.858]: master offset 414192925 s2 freq +499999 path delay
11630558
ptp4l[3697.939]: master offset 496831388 s2 freq +499999 path delay
11630558
ptp4l[3699.019]: master offset 579467338 s2 freq +499999 path delay
11630558
ptp4l[3699.547]: negative path delay -20170126
ptp4l[3699.547]: path_delay = (t2 - t3) + (t4 - t1)
ptp4l[3699.547]: t2 - t3 = -527626340
ptp4l[3699.547]: t4 - t1 = +487286088
ptp4l[3699.547]: c1 0
ptp4l[3699.547]: c2 0
ptp4l[3699.547]: c3 0
ptp4l[3700.099]: master offset 672708283 s2 freq +499999 path delay
1030330
ptp4l[3701.179]: master offset 755347634 s2 freq +499999 path delay
1030330
ptp4l[3702.259]: master offset 837984697 s2 freq +499999 path delay
1030330
ptp4l[3703.339]: master offset 920619941 s2 freq +499999 path delay
1030330
ptp4l[3704.419]: master offset 1003256503 s2 freq +499999 path delay
1030330
ptp4l[3705.499]: master offset 1085896816 s2 freq +499999 path delay
1030330
ptp4l[3706.580]: master offset 1168532970 s2 freq +499999 path delay
1030330
ptp4l[3707.660]: master offset 1251172248 s2 freq +499999 path delay
1030330
ptp4l[3707.780]: negative path delay -4575009
ptp4l[3707.780]: path_delay = (t2 - t3) + (t4 - t1)
ptp4l[3707.780]: t2 - t3 = -119839683
ptp4l[3707.780]: t4 - t1 = +110689664
ptp4l[3707.780]: c1 0
ptp4l[3707.780]: c2 0
ptp4l[3707.780]: c3 0
ptp4l[3708.740]: master offset 1335211571 s2 freq +499999 path delay
-371004
ptp4l[3709.820]: master offset 1417849294 s2 freq +499999 path delay
-371004
ptp4l[3710.900]: master offset 1500486714 s2 freq +499999 path delay
-371004
ptp4l[3711.980]: master offset 1583127615 s2 freq +499999 path delay
-371004
ptp4l[3712.437]: negative path delay -17447934
ptp4l[3712.437]: path_delay = (t2 - t3) + (t4 - t1)
ptp4l[3712.437]: t2 - t3 = -456377356
ptp4l[3712.437]: t4 - t1 = +421481488
ptp4l[3712.437]: c1 0
ptp4l[3712.437]: c2 0
ptp4l[3712.437]: c3 0
ptp4l[3713.060]: master offset 1669178480 s2 freq +499999 path delay
-3786390
ptp4l[3714.141]: master offset 1751818940 s2 freq +499999 path delay
-3786390
ptp4l[3715.221]: master offset 1834452210 s2 freq +499999 path delay
-3786390
ptp4l[3716.301]: master offset 1917090475 s2 freq +499999 path delay
-3786390

..................

ptp4l[3748.588]: master offset 4291761715 s2 freq +499999 path delay
-16421545
ptp4l[3749.502]: master offset 4208194235 s2 freq +499999 path delay
-16421545
ptp4l[3750.416]: master offset 4124624400 s2 freq +499999 path delay
-16421545
ptp4l[3751.330]: master offset 4041058127 s2 freq +499999 path delay
-16421545
ptp4l[3752.244]: master offset 3957487906 s2 freq +499999 path delay
-16421545
ptp4l[3753.158]: master offset 3871178456 s2 freq +499999 path delay
-13679959
ptp4l[3754.072]: master offset 3787610419 s2 freq +499999 path delay
-13679959
ptp4l[3754.986]: master offset 3704042098 s2 freq +499999 path delay
-13679959
ptp4l[3755.899]: master offset 3620471338 s2 freq +499999 path delay
-13679959
ptp4l[3756.813]: master offset 3536907176 s2 freq +499999 path delay
-13679959
ptp4l[3757.727]: master offset 3453337347 s2 freq +499999 path delay
-13679959
ptp4l[3758.641]: master offset 3369769030 s2 freq +499999 path delay
-13679959
ptp4l[3759.555]: master offset 3286198208 s2 freq +499999 path delay
-13679959
ptp4l[3760.469]: master offset 3202632841 s2 freq +499999 path delay
-13679959
ptp4l[3761.383]: master offset 3119062093 s2 freq +499999 path delay
-13679959
ptp4l[3762.297]: master offset 3037484098 s2 freq +499999 path delay
-15669616
ptp4l[3763.211]: master offset 2953914687 s2 freq +499999 path delay
-15669616
ptp4l[3764.125]: master offset 2870344300 s2 freq +499999 path delay
-15669616
ptp4l[3765.039]: master offset 2786777817 s2 freq +499999 path delay
-15669616
ptp4l[3765.953]: master offset 2703207832 s2 freq +499999 path delay
-15669616

// Now i set the system time 3 minutes later

ptp4l[3766.867]: master offset -184373487503 s2 freq -499999 path delay
-15669616
ptp4l[3767.782]: master offset -244904123137 s2 freq -499999 path delay
-15669616
ptp4l[3768.697]: master offset -244986692808 s2 freq -499999 path delay
-15669616
ptp4l[3769.611]: master offset -245069524049 s2 freq -499999 path delay
-15409219
ptp4l[3770.526]: master offset -245152095532 s2 freq -499999 path delay
-15409219
ptp4l[3771.441]: master offset -245234667781 s2 freq -499999 path delay
-15409219
ptp4l[3772.356]: master offset -245317238846 s2 freq -499999 path delay
-15409219
ptp4l[3773.271]: master offset -245399809517 s2 freq -499999 path delay
-15409219
ptp4l[3774.186]: master offset -245482380317 s2 freq -499999 path delay
-15409219
ptp4l[3775.101]: master offset -245564950736 s2 freq -499999 path delay
-15409219
ptp4l[3776.016]: master offset -245651797025 s2 freq -499999 path delay
-11138069
ptp4l[3776.931]: master offset -245734364095 s2 freq -499999 path delay
-11138069
ptp4l[3777.846]: master offset -245816936362 s2 freq -499999 path delay
-11138069
ptp4l[3778.761]: master offset -245899506317 s2 freq -499999 path delay
-11138069
ptp4l[3779.676]: master offset -245982076996 s2 freq -499999 path delay
-11138069
ptp4l[3780.591]: master offset -246064649662 s2 freq -499999 path delay
-11138069
ptp4l[3781.506]: master offset -246147219442 s2 freq -499999 path delay
-11138069
ptp4l[3782.421]: master offset -246229789738 s2 freq -499999 path delay
-11138069
ptp4l[3783.335]: master offset -246312361277 s2 freq -499999 path delay
-11138069
ptp4l[3784.250]: master offset -246394935192 s2 freq -499999 path delay
-11138069
ptp4l[3785.165]: master offset -246477503182 s2 freq -499999 path delay
-11138069
ptp4l[3786.080]: master offset -246560075063 s2 freq -499999 path delay
-11138069
ptp4l[3786.995]: master offset -246642643873 s2 freq -499999 path delay
-11138069
ptp4l[3787.910]: master offset -246726552120 s2 freq -499999 path delay
-9801273
ptp4l[3788.825]: master offset -246809116029 s2 freq -499999 path delay
-9801273
ptp4l[3789.740]: master offset -246891694912 s2 freq -499999 path delay
-9801273
ptp4l[3790.655]: master offset -246974266288 s2 freq -499999 path delay
-9801273
ptp4l[3791.570]: master offset -247056836091 s2 freq -499999 path delay
-9801273
ptp4l[3792.485]: master offset -247139407748 s2 freq -499999 path delay
-9801273
ptp4l[3793.400]: master offset -247221976743 s2 freq -499999 path delay
-9801273
ptp4l[3794.315]: master offset -247304547766 s2 freq -499999 path delay
-9801273
ptp4l[3795.230]: master offset -247387119374 s2 freq -499999 path delay
-9801273
ptp4l[3796.145]: master offset -247469691472 s2 freq -499999 path delay
-9801273
ptp4l[3797.060]: master offset -247552261826 s2 freq -499999 path delay
-9801273
ptp4l[3797.974]: master offset -247634828784 s2 freq -499999 path delay
-9801273
ptp4l[3798.889]: master offset -247717403809 s2 freq -499999 path delay
-9801273
ptp4l[3799.804]: master offset -247803975548 s2 freq -499999 path delay
-5799605
ptp4l[3800.719]: master offset -247886547571 s2 freq -499999 path delay
-5799605
ptp4l[3801.634]: master offset -247972786822 s2 freq -499999 path delay
-2131630
ptp4l[3802.549]: master offset -248055356849 s2 freq -499999 path delay
-2131630
ptp4l[3803.464]: master offset -248137926479 s2 freq -499999 path delay
-2131630
ptp4l[3804.379]: master offset -248220500692 s2 freq -499999 path delay
-2131630
ptp4l[3805.294]: master offset -248303066839 s2 freq -499999 path delay
-2131630
ptp4l[3806.209]: master offset -248385640426 s2 freq -499999 path delay
-2131630
ptp4l[3807.124]: master offset -248468210352 s2 freq -499999 path delay
-2131630
ptp4l[3808.039]: master offset -248550776956 s2 freq -499999 path delay
-2131630
ptp4l[3808.954]: master offset -248633349754 s2 freq -499999 path delay
-2131630
ptp4l[3809.869]: master offset -248715922523 s2 freq -499999 path delay
-2131630
ptp4l[3810.783]: master offset -248798492430 s2 freq -499999 path delay
-2131630
ptp4l[3811.698]: master offset -248881065214 s2 freq -499999 path delay
-2131630
ptp4l[3812.613]: master offset -248963638033 s2 freq -499999 path delay
-2131630
ptp4l[3813.529]: master offset -249046207387 s2 freq -499999 path delay
-2131630
ptp4l[3814.443]: master offset -249128775858 s2 freq -499999 path delay
-2131630
ptp4l[3815.358]: master offset -249216564776 s2 freq -499999 path delay
3084008
ptp4l[3816.273]: master offset -249305384629 s2 freq -499999 path delay
9329309
ptp4l[3817.188]: master offset -249387951398 s2 freq -499999 path delay
9329309
ptp4l[3818.103]: master offset -249470515958 s2 freq -499999 path delay
9329309
ptp4l[3819.018]: master offset -249553090712 s2 freq -499999 path delay
9329309
ptp4l[3819.933]: master offset -249635661793 s2 freq -499999 path delay
9329309
ptp4l[3820.848]: master offset -249718235879 s2 freq -499999 path delay
9329309
ptp4l[3821.763]: master offset -249804313381 s2 freq -499999 path delay
12839243
ptp4l[3822.678]: master offset -249886885945 s2 freq -499999 path delay
12839243
ptp4l[3823.593]: master offset -249969454960 s2 freq -499999 path delay
12839243
ptp4l[3824.508]: master offset -250052027757 s2 freq -499999 path delay
12839243
ptp4l[3825.422]: master offset -250134594992 s2 freq -499999 path delay
12839243
ptp4l[3826.337]: master offset -250217170036 s2 freq -499999 path delay
12839243
ptp4l[3827.252]: master offset -250299737141 s2 freq -499999 path delay
12839243
ptp4l[3828.167]: master offset -250382311667 s2 freq -499999 path delay
12839243
ptp4l[3829.082]: master offset -250464879632 s2 freq -499999 path delay
12839243
ptp4l[3829.997]: master offset -250549709940 s2 freq -499999 path delay
15094493
ptp4l[3830.912]: master offset -250632276312 s2 freq -499999 path delay
15094493
ptp4l[3831.827]: master offset -250714849892 s2 freq -499999 path delay
15094493
ptp4l[3832.742]: master offset -250797421715 s2 freq -499999 path delay
15094493
ptp4l[3833.657]: master offset -250879992478 s2 freq -499999 path delay
15094493
ptp4l[3834.572]: master offset -250962561110 s2 freq -499999 path delay
15094493
ptp4l[3835.487]: master offset -251045133506 s2 freq -499999 path delay
15094493
ptp4l[3836.402]: master offset -251127704238 s2 freq -499999 path delay
15094493
ptp4l[3837.317]: master offset -251210276836 s2 freq -499999 path delay
15094493
ptp4l[3838.232]: master offset -251292839652 s2 freq -499999 path delay
15094493
ptp4l[3839.147]: master offset -251377298486 s2 freq -499999 path delay
16974996
ptp4l[3840.061]: master offset -251459869458 s2 freq -499999 path delay
16974996
ptp4l[3840.976]: master offset -251542443888 s2 freq -499999 path delay
16974996
ptp4l[3841.891]: master offset -251623961572 s2 freq -499999 path delay
15924128
ptp4l[3842.806]: master offset -251706532240 s2 freq -499999 path delay
15924128
..................

Sincerely, Alexander.
Richard Cochran
2013-08-07 08:15:49 UTC
Permalink
Post by Alex Gavrilov
.model large
test_data segment "FAR_DATA" public use16
You are running this program under DOS?

If so, why?
Post by Alex Gavrilov
================================================================================
^^^^^
Why does this interface name look so strange?
Post by Alex Gavrilov
ptp4l[3662.740]: port 1: INITIALIZING to LISTENING on INITIALIZE
ptp4l[3662.740]: port 0: INITIALIZING to LISTENING on INITIALIZE
ptp4l[3663.635]: port 1: new foreign master ece555.fffe.2de639-2
ptp4l[3667.295]: selected best master clock ece555.fffe.2de639
ptp4l[3667.295]: port 1: LISTENING to UNCALIBRATED on RS_SLAVE
ptp4l[3667.433]: port 1: minimum delay request interval 2^3
ptp4l[3674.614]: master offset -3600882843951 s0 freq +0 path delay 19917808
Path delay is estimated at 20 milliseconds! Are your packets going
through a router?
Post by Alex Gavrilov
ptp4l[3675.529]: master offset -3600965414318 s0 freq +0 path delay 19917808
ptp4l[3676.444]: master offset -3601047983089 s0 freq +0 path delay 19917808
ptp4l[3677.359]: master offset -3601130555972 s0 freq +0 path delay 19917808
ptp4l[3678.274]: master offset -3601213123527 s0 freq +0 path delay 19917808
ptp4l[3679.189]: master offset -3601295694079 s0 freq +0 path delay 19917808
ptp4l[3680.104]: master offset -3601378264480 s0 freq +0 path delay 19917808
ptp4l[3681.019]: master offset -3601460837143 s0 freq +0 path delay 19917808
ptp4l[3681.934]: master offset -3601543405035 s0 freq +0 path delay 19917808
ptp4l[3682.849]: master offset -3601617688457 s0 freq +0 path delay 11630558
ptp4l[3683.889]: master offset -3601575495165 s0 freq +0 path delay 11630558
ptp4l[3684.970]: master offset -3601491859633 s0 freq +0 path delay 11630558
ptp4l[3686.051]: master offset -3601408225417 s0 freq +0 path delay 11630558
ptp4l[3687.132]: master offset -3601324587614 s0 freq +0 path delay 11630558
ptp4l[3688.213]: master offset -3601240952059 s0 freq +0 path delay 11630558
ptp4l[3689.294]: master offset -3601157315298 s0 freq +0 path delay 11630558
ptp4l[3690.376]: master offset -3601073679242 s0 freq +0 path delay 11630558
ptp4l[3691.457]: master offset -3600990048190 s1 freq -499999 path delay 11630558
The frequency offset is greater than 500 ppm. What is your system
clock? Can it really be so badly out of tune?
Post by Alex Gavrilov
ptp4l[3692.538]: master offset 83635426 s2 freq +499999 path delay 11630558
ptp4l[3692.538]: port 1: UNCALIBRATED to SLAVE on MASTER_CLOCK_SELECTED
ptp4l[3693.618]: master offset 166278466 s2 freq +499999 path delay 11630558
ptp4l[3694.698]: master offset 248915872 s2 freq +499999 path delay 11630558
ptp4l[3695.778]: master offset 331556238 s2 freq +499999 path delay 11630558
ptp4l[3696.858]: master offset 414192925 s2 freq +499999 path delay 11630558
ptp4l[3697.939]: master offset 496831388 s2 freq +499999 path delay 11630558
ptp4l[3699.019]: master offset 579467338 s2 freq +499999 path delay 11630558
The offset keeps growing, and the frequency adjustment is maxed
out. This means one (or more) of the following:

- The network delay and jitter are huge.
- The local time stamps are broken (can't think how this could
happen with SW time stamps).
- The remote time stamps are broken (master is broken).
- The local oscillator is unusable.

Are you able to synchronize this system using ntp? radclock? ptpd?

Is this system running as a guest in a virtual machine?

Thanks,
Richard

Loading...