Hi!
The Altera Cyclone V Soc has IEEE1588-2008 support in the MAC hardware. I have the 'wowczarek-2.3.2-libcck' branch working, mostly. The problem is, is that the sequence-numbers will occasionally get out of sync -- I'm including a snippet of the log-file that indicates this:
2017-06-29 20:58:05.189102 ptpd[558].(debug1) Received an empty PTP message (this should not happen) - ignoring
2017-06-29 20:58:05.189197 ptpd[558].(debug1) ==> DelayResp message received, sequence 36414
2017-06-29 20:58:05.189241 ptpd[558].(debug1) HandledelayResp : delayResp doesn't match with the delayReq.
2017-06-29 20:58:05.374903 ptpd[558].(debug1) Received an empty PTP message (this should not happen) - ignoring
2017-06-29 20:58:05.375007 ptpd[558].(debug1) ==> Announce message received, sequence 2582
2017-06-29 20:58:05.375085 ptpd[558].(debug1) Timer ANNOUNCE_RECEIPT started at 6.000
2017-06-29 20:58:05.419610 ptpd[558].(debug1) Timer STATUSFILE_UPDATE expired
2017-06-29 20:58:05.420019 ptpd[558].(debug1) Timer STATUSFILE_UPDATE started at 1.000
2017-06-29 20:58:05.433723 ptpd[558].(debug1) Timer DELAYREQ_INTERVAL expired
2017-06-29 20:58:05.433781 ptpd[558].(debug1) event DELAYREQ_INTERVAL_TIMEOUT_EXPIRES
2017-06-29 20:58:05.433819 ptpd[558].(debug1) ==> Issue DelayReq (1519)
2017-06-29 20:58:05.437257 ptpd[558].(debug1) Timer DELAYREQ_INTERVAL started at 1.465
2017-06-29 20:58:05.437379 ptpd[558].(debug1) ==> DelayResp message received, sequence 1519
2017-06-29 20:58:05.437425 ptpd[558].(debug1) ==> Handle DelayResp (1519)
2017-06-29 20:58:05.437481 ptpd[558].(debug1) Timer DELAY_RECEIPT started at 20.000
2017-06-29 20:58:05.437521 ptpd[558].(debug1) Ignored DelayResp sequence 1519 - wasn't waiting for one
2017-06-29 20:58:05.438786 ptpd[558].(debug1) Received an empty PTP message (this should not happen) - ignoring
2017-06-29 20:58:05.438874 ptpd[558].(debug1) ==> DelayResp message received, sequence 37270
2017-06-29 20:58:05.438917 ptpd[558].(debug1) HandledelayResp : delayResp doesn't match with the delayReq.
2017-06-29 20:58:05.445090 ptpd[558].(debug1) Received an empty PTP message (this should not happen) - ignoring
2017-06-29 20:58:05.445159 ptpd[558].(debug1) ==> DelayResp message received, sequence 36162
2017-06-29 20:58:05.445200 ptpd[558].(debug1) HandledelayResp : delayResp doesn't match with the delayReq.
2017-06-29 20:58:05.445277 ptpd[558].(debug1) Received an empty PTP message (this should not happen) - ignoring
2017-06-29 20:58:05.445333 ptpd[558].(debug1) ==> DelayResp message received, sequence 36111
2017-06-29 20:58:05.445372 ptpd[558].(debug1) HandledelayResp : delayResp doesn't match with the delayReq.
2017-06-29 20:58:05.445815 ptpd[558].(debug1) Received an empty PTP message (this should not happen) - ignoring
2017-06-29 20:58:05.445876 ptpd[558].(debug1) ==> DelayResp message received, sequence 37616
2017-06-29 20:58:05.445915 ptpd[558].(debug1) HandledelayResp : delayResp doesn't match with the delayReq.
2017-06-29 20:58:05.750833 ptpd[558].(debug1) Received an empty PTP message (this should not happen) - ignoring
2017-06-29 20:58:05.750968 ptpd[558].(debug1) ==> DelayResp message received, sequence 36591
2017-06-29 20:58:05.751016 ptpd[558].(debug1) HandledelayResp : delayResp doesn't match with the delayReq.
2017-06-29 20:58:05.825133 ptpd[558].(debug1) Timer ALARM_UPDATE expired
2017-06-29 20:58:05.825203 ptpd[558].(debug1) updateAlarms()
2017-06-29 20:58:05.946095 ptpd[558].(debug1) Received an empty PTP message (this should not happen) - ignoring
2017-06-29 20:58:05.946216 ptpd[558].(debug1) ==> DelayResp message received, sequence 37617
2017-06-29 20:58:05.946262 ptpd[558].(debug1) HandledelayResp : delayResp doesn't match with the delayReq.
2017-06-29 20:58:06.000648 ptpd[558].(debug1) Received an empty PTP message (this should not happen) - ignoring
2017-06-29 20:58:06.000741 ptpd[558].(debug1) ==> DelayResp message received, sequence 36592
2017-06-29 20:58:06.000785 ptpd[558].(debug1) HandledelayResp : delayResp doesn't match with the delayReq.
2017-06-29 20:58:06.008638 ptpd[558].(debug1) Received an empty PTP message (this should not happen) - ignoring
2017-06-29 20:58:06.008709 ptpd[558].(debug1) ==> DelayResp message received, sequence 36717
2017-06-29 20:58:06.008751 ptpd[558].(debug1) HandledelayResp : delayResp doesn't match with the delayReq.
As well, I can see that Delay_Req and Delay_Resp datagrams are being sent/received using both tcpdump and ethtool -S eth0 -- a snippet of the output from ethtool follows:
A bit about my setup: I'm using a Spectracom SecureSync for my GrandMaster, and I have perhaps two dozen or so Cyclone V SoCs in the role of PTP slaves. I'm including my .conf-file for ptpd:
`; ######### ptpd 2.3.2-linuxphc configuration
; #### BEGIN Required settings - need changed
ptpengine:interface=eth0
ptpengine:domain=2
; disable Best Master Clock Algorithm: should only be used
; for PTP master operation. Causes a PTPd master instance
; to skip the LISTENING state and transition straight to active,
; and never run the BMCA. This behaviour is part of the Telecom Profile.
; ptpengine:disable_bmca = n
; #### END Basic PTP settings
; #### BEGIN PTP message rates / intervals
; message intervals:
;
; - values specified below are the defaults
; - for multicast, if using non-default rates, this only needs specified
; on the master
; - for hybrid mode and unicast without negotiation, delay request interval
; is not received from master, so needs configured on the slave
; - for unicast operation with unicast negotiation, this needs configured
; both on master and on slave: master intervals are minimum intervals granted,
; and the _max settings are maximum granted. Slave needs all intervals between
; minimum and maximum, but if requested rates are too high,
; slave will negotiate down
;
; PTP intervals are expressed as powers of 2, so 1 = once every 2 seconds,
; 0 = 1 per second, -1 = 2 per second, -2 = 4 per second, etc.
; message intervals (minimum intervals for PTP unicast negotiation master)
; can be used in multicast mode to override master's interval
; ptpengine:log_delayreq_override = n
; maximum intervals for PTP unicast negotiation master
ptpengine:log_announce_interval_max = 5
ptpengine:log_sync_interval_max = 5
ptpengine:log_delayreq_interval_max = 5
; P2P only
ptpengine:log_peer_delayreq_interval = 0
; initial delayReq interval is the interval a multicast slave
; uses until it receives the first response and learns the actual
; interval used
ptpengine:log_delayreq_interval_initial = 0
; If a clock constantly fails to lock (LOCKED state), the low threshold may need lowered
; The current value can be observed in the status file
; Allan deviation estimates for LOCKED and TRACKING, hardware clocks
servo:adev_locked_threshold_low_hw = 50.000000
servo:adev_locked_threshold_high_hw = 500.000000
; Allan deviation estimates for LOCKED and TRACKING, software clocks (system clock)
servo:adev_locked_threshold_low = 200.000000
servo:adev_locked_threshold_high = 2000.000000
; Allan deviation measurement period
servo:adev_interval = 10
; #### END Clock stability estimates
; #### BEGIN additional clocks and clock options
; extra clocks - any additional clocks you want to sync
;clock:extra_clocks="linuxphc:ethX, linuxphc:ethY"
; preferred master clock name - all clocks will use this unless there
; is a PTP source available. When running PTPd as master, you can specify "syst"
; to drive the master NIC's clock from the system clock.
;clock:master_clock_name = "ethA"
; specify the names of any clocks you want to be read-only
;clock:readonly_clock_names="ethB"
; specify the names of any clocks you want to exclude from sync
;clock:excluded_clock_names="ethC"
; #### END additional clocks and clock options
; #### BEGIN Other settings
; panic mode: delay when clock step detected
ptpengine:panic_mode=y
ptpengine:panic_mode_duration=60
; alarm support
global:enable_alarms=y
global:alarm_initial_delay=60
global:alarm_timeout=30
; alarm when offset exceeds 100 us
ptpengine:offset_alarm_threshold=100000
; Enable outlier filter for sync between OS and hardware clocks,
; and sync between hardware clocks
clock:outlier_filter_enable = y
; do not allow a software clock (system clock) to be stepped backwards
clock:allow_step_backwards = y
; allow a hardware clock to be stepped backwards
; this should be set to Y because a NIC may randomly reset the clock
clock:allow_step_backwards_hw = y
; bind to selected CPU core for improved system latency characteristics
; core 0 = first core
global:cpuaffinity_cpucore = 0
; store best clock frequency in files
clock:store_frequency = y
; store frequency data in /etc
clock:frequency_directory = /etc
; status file location
global:status_file = /var/run/ptpd.status
; PI servo parameters (gains)
; NOTE: If the system clock is steered by a hardware clock,
; software clock gains can be set to the same values as hardware clock gains.
; software clock (system clock) control - when controlled by PTP
; using software timestamping
; servo:kp = 0.1
; servo:ki = 0.001
; software clock (system clock) control - when syncing from a hardware clock
servo:kp = 0.7
servo:ki = 0.3
; hardware clock control
servo:kp_hardware = 0.7
servo:ki_hardware = 0.3
; #### END Other settings
; ######### ptpd 2.3.2-linuxphc configuration END
; always leave a newline in the end
`
Your help is most appreciated. Thank you!
If you would like to refer to this comment somewhere else in this project, copy and paste the following link:
What you are seeing is actually a "side effect" of the driver / OS not being able to capture the transmission timestamps of the delay request messages. This is a notorious problem with many cards and drivers, almost to be expected. Ptpd silently ignores this, but as a result you have sequence gaps, because the transmitted delayResp - which is physically transmitted - is considered not sent, and the response comes back, but is dropped. I think I will need to rework this, because this behaviour causes some confusion. If you send the ptpd process a SIGUSR2, it will dump all of its counters - you can expect txTimestampErrors to be incrementing.
Transmission timestamps are delivered via the socket error queue which has to be polled after sending an event message - they should be available immediately, and they usually are, but are sometimes late. Ptpd will try a number of times with exponential backoff, but eventually gives up. Some drivers explicitly establish a validity period and purge late timestamps. Only high-end "enterprise" type NICs like Solarflare and Mellanox deal with this with no issues - most SoC timestamping MAC / PHY timestampers have the same issue, also many / most Intel NICs. This is not a problem with hardware but rather a problem with the process of grabbing TX timestamps from the FIFO. If you were running a realtime OS and could talk to the hardware directly, you would not experience this.
HTH,
Cheers,
Wojciech
If you would like to refer to this comment somewhere else in this project, copy and paste the following link:
Hi Wojciech,
I really appreciate the work you've done on implementing H/W timestamping -- Very nice!
A little more about this environment: The Cyclone V SoC uses the ST Microelectronics EMAC, and the O/S I'm using is a Linux 4.10 kernel --
I'm not seeing txTimestampErrors as much as I'm seeing rxTimestampErrors errors:
I think the DelayReqs are being transmitted from the Cyclones to the Spectracom just fine -- perhaps the problem is in the DelayResp form the Spectracom to the Cyclones?
Here is the output from the status file:
Host info : buildroot, PID 558
Local time : Thu Jun 29 22:37:53 UTC 2017
Kernel time : Thu Jun 29 22:37:53 GMT 2017
Interface : eth0, status: OK
Transport : linuxts_udpv4, H/W tstamp, multicast
PTP preset : slaveonly
Delay mechanism : E2E
Sync mode : ONE_STEP
PTP domain : 2
Port state : PTP_SLAVE
Alarms : OFMS[!] SYN[.]
Local port ID : 2cee26fffe000165(unknown)/1
Best master ID : 000cecfffe0a0fb2(unknown)/1
Best master addr : 10.0.10.200
Master priority : Priority1 128, Priority2 128, clockClass 6
Time properties : PTP timescale, tracbl: time Y, freq Y, src: GPS(0x20)
UTC properties : UTC valid: Y, UTC offset: 37
Offset from Master : -567.000387036 s, mean 0.000000000 s, dev 0.000000000 s
Mean Path Delay : 0.000000000 s, mean 0.000000000 s, dev 0.000000000 s
PTP Clock status : calibrated, not stabilised
Message rates : 1/s sync, 1/s delay, 1/s announce
Performance : Message RX 25/s 1708 Bps, TX 1/s 44 Bps
Announce received : 4148
Sync received : 18
DelayReq sent : 3884
DelayResp received : 0
State transitions : 3
PTP Engine resets : 1
OK - that would explain the reported empty messages received - as per the comment in the sources "mesage without a timestamp considered harmful". This is likely a driver issue. While for TX timestamps, PTPd has its own way of dealing with waiting for them - for RX timestamps it follows the API and does nothing special.
Thanks,
Wojciech
If you would like to refer to this comment somewhere else in this project, copy and paste the following link:
Quick update. I have your branch of PTPd working on the Altera Cyclone V SoC. This infers (implies?) that PTPd should work on the Altera Arria V SoC, too, as both of these products use the eMAC licensed from ST Microelectronics.
Thanks again for all your help!
-Allan
If you would like to refer to this comment somewhere else in this project, copy and paste the following link:
Hi!
The Altera Cyclone V Soc has IEEE1588-2008 support in the MAC hardware. I have the 'wowczarek-2.3.2-libcck' branch working, mostly. The problem is, is that the sequence-numbers will occasionally get out of sync -- I'm including a snippet of the log-file that indicates this:
2017-06-29 20:58:05.189102 ptpd[558].(debug1) Received an empty PTP message (this should not happen) - ignoring 2017-06-29 20:58:05.189197 ptpd[558].(debug1) ==> DelayResp message received, sequence 36414 2017-06-29 20:58:05.189241 ptpd[558].(debug1) HandledelayResp : delayResp doesn't match with the delayReq. 2017-06-29 20:58:05.374903 ptpd[558].(debug1) Received an empty PTP message (this should not happen) - ignoring 2017-06-29 20:58:05.375007 ptpd[558].(debug1) ==> Announce message received, sequence 2582 2017-06-29 20:58:05.375085 ptpd[558].(debug1) Timer ANNOUNCE_RECEIPT started at 6.000 2017-06-29 20:58:05.419610 ptpd[558].(debug1) Timer STATUSFILE_UPDATE expired 2017-06-29 20:58:05.420019 ptpd[558].(debug1) Timer STATUSFILE_UPDATE started at 1.000 2017-06-29 20:58:05.433723 ptpd[558].(debug1) Timer DELAYREQ_INTERVAL expired 2017-06-29 20:58:05.433781 ptpd[558].(debug1) event DELAYREQ_INTERVAL_TIMEOUT_EXPIRES 2017-06-29 20:58:05.433819 ptpd[558].(debug1) ==> Issue DelayReq (1519) 2017-06-29 20:58:05.437257 ptpd[558].(debug1) Timer DELAYREQ_INTERVAL started at 1.465 2017-06-29 20:58:05.437379 ptpd[558].(debug1) ==> DelayResp message received, sequence 1519 2017-06-29 20:58:05.437425 ptpd[558].(debug1) ==> Handle DelayResp (1519) 2017-06-29 20:58:05.437481 ptpd[558].(debug1) Timer DELAY_RECEIPT started at 20.000 2017-06-29 20:58:05.437521 ptpd[558].(debug1) Ignored DelayResp sequence 1519 - wasn't waiting for one 2017-06-29 20:58:05.438786 ptpd[558].(debug1) Received an empty PTP message (this should not happen) - ignoring 2017-06-29 20:58:05.438874 ptpd[558].(debug1) ==> DelayResp message received, sequence 37270 2017-06-29 20:58:05.438917 ptpd[558].(debug1) HandledelayResp : delayResp doesn't match with the delayReq. 2017-06-29 20:58:05.445090 ptpd[558].(debug1) Received an empty PTP message (this should not happen) - ignoring 2017-06-29 20:58:05.445159 ptpd[558].(debug1) ==> DelayResp message received, sequence 36162 2017-06-29 20:58:05.445200 ptpd[558].(debug1) HandledelayResp : delayResp doesn't match with the delayReq. 2017-06-29 20:58:05.445277 ptpd[558].(debug1) Received an empty PTP message (this should not happen) - ignoring 2017-06-29 20:58:05.445333 ptpd[558].(debug1) ==> DelayResp message received, sequence 36111 2017-06-29 20:58:05.445372 ptpd[558].(debug1) HandledelayResp : delayResp doesn't match with the delayReq. 2017-06-29 20:58:05.445815 ptpd[558].(debug1) Received an empty PTP message (this should not happen) - ignoring 2017-06-29 20:58:05.445876 ptpd[558].(debug1) ==> DelayResp message received, sequence 37616 2017-06-29 20:58:05.445915 ptpd[558].(debug1) HandledelayResp : delayResp doesn't match with the delayReq. 2017-06-29 20:58:05.750833 ptpd[558].(debug1) Received an empty PTP message (this should not happen) - ignoring 2017-06-29 20:58:05.750968 ptpd[558].(debug1) ==> DelayResp message received, sequence 36591 2017-06-29 20:58:05.751016 ptpd[558].(debug1) HandledelayResp : delayResp doesn't match with the delayReq. 2017-06-29 20:58:05.825133 ptpd[558].(debug1) Timer ALARM_UPDATE expired 2017-06-29 20:58:05.825203 ptpd[558].(debug1) updateAlarms() 2017-06-29 20:58:05.946095 ptpd[558].(debug1) Received an empty PTP message (this should not happen) - ignoring 2017-06-29 20:58:05.946216 ptpd[558].(debug1) ==> DelayResp message received, sequence 37617 2017-06-29 20:58:05.946262 ptpd[558].(debug1) HandledelayResp : delayResp doesn't match with the delayReq. 2017-06-29 20:58:06.000648 ptpd[558].(debug1) Received an empty PTP message (this should not happen) - ignoring 2017-06-29 20:58:06.000741 ptpd[558].(debug1) ==> DelayResp message received, sequence 36592 2017-06-29 20:58:06.000785 ptpd[558].(debug1) HandledelayResp : delayResp doesn't match with the delayReq. 2017-06-29 20:58:06.008638 ptpd[558].(debug1) Received an empty PTP message (this should not happen) - ignoring 2017-06-29 20:58:06.008709 ptpd[558].(debug1) ==> DelayResp message received, sequence 36717 2017-06-29 20:58:06.008751 ptpd[558].(debug1) HandledelayResp : delayResp doesn't match with the delayReq.As well, I can see that Delay_Req and Delay_Resp datagrams are being sent/received using both
tcpdumpandethtool -S eth0-- a snippet of the output fromethtoolfollows:no_ptp_rx_msg_type_ext: 291 ptp_rx_msg_type_sync: 2928 ptp_rx_msg_type_follow_up: 0 ptp_rx_msg_type_delay_req: 33093 ptp_rx_msg_type_delay_resp: 35747 ptp_rx_msg_type_pdelay_req: 0 ptp_rx_msg_type_pdelay_resp: 0 ptp_rx_msg_type_pdelay_follow_up: 0 ptp_rx_msg_type_announce: 2928 ptp_rx_msg_type_management: 0 ptp_rx_msg_pkt_reserved_type: 0 ptp_frame_type: 0 ptp_ver: 74696A bit about my setup: I'm using a Spectracom SecureSync for my GrandMaster, and I have perhaps two dozen or so Cyclone V SoCs in the role of PTP slaves. I'm including my .conf-file for ptpd:
`; ######### ptpd 2.3.2-linuxphc configuration
; #### BEGIN Required settings - need changed
ptpengine:interface=eth0
ptpengine:domain=2
; Enable / disable hardware timestamping and hardware clock sync
ptpengine:hardware_timestamping=y
ptpengine:preset=slaveonly
ptpengine:delay_mechanism=E2E
; other options: hybrid, unicast
ptpengine:ip_mode=multicast
; ptpengine:ip_mode=hybrid
; ptpengine:ip_mode=unicast
; ptpengine:alt_mcast_group = 0
; wait 15 seconds on master changes, let PTP offset stabilise
ptpengine:calibration_delay=15
; enable / disable unicast negotiation
; ptpengine:unicast_negotiation=n
; disable Best Master Clock Algorithm: should only be used
; for PTP master operation. Causes a PTPd master instance
; to skip the LISTENING state and transition straight to active,
; and never run the BMCA. This behaviour is part of the Telecom Profile.
; ptpengine:disable_bmca = n
; #### END Basic PTP settings
; #### BEGIN PTP message rates / intervals
; message intervals:
;
; - values specified below are the defaults
; - for multicast, if using non-default rates, this only needs specified
; on the master
; - for hybrid mode and unicast without negotiation, delay request interval
; is not received from master, so needs configured on the slave
; - for unicast operation with unicast negotiation, this needs configured
; both on master and on slave: master intervals are minimum intervals granted,
; and the _max settings are maximum granted. Slave needs all intervals between
; minimum and maximum, but if requested rates are too high,
; slave will negotiate down
;
; PTP intervals are expressed as powers of 2, so 1 = once every 2 seconds,
; 0 = 1 per second, -1 = 2 per second, -2 = 4 per second, etc.
; message intervals (minimum intervals for PTP unicast negotiation master)
ptpengine:log_announce_interval = 0
ptpengine:log_sync_interval = 0
ptpengine:log_delayreq_interval = 0
; can be used in multicast mode to override master's interval
; ptpengine:log_delayreq_override = n
; maximum intervals for PTP unicast negotiation master
ptpengine:log_announce_interval_max = 5
ptpengine:log_sync_interval_max = 5
ptpengine:log_delayreq_interval_max = 5
; P2P only
ptpengine:log_peer_delayreq_interval = 0
; initial delayReq interval is the interval a multicast slave
; uses until it receives the first response and learns the actual
; interval used
ptpengine:log_delayreq_interval_initial = 0
; #### END PTP message rates
; #### BEGIN Filter configuration
; this is used in slave operation only
ptpengine:sync_outlier_filter_enable=y
ptpengine:sync_outlier_filter_autotune_enable=y
ptpengine:sync_stat_filter_enable=y
ptpengine:sync_outlier_filter_stepdetect_enable=y
ptpengine:sync_outlier_filter_stepdetect_threshold = 1000000
ptpengine:sync_outlier_filter_stepdetect_level = 200000
ptpengine:delay_outlier_filter_enable=y
ptpengine:delay_outlier_filter_autotune_enable=y
ptpengine:delay_stat_filter_enable=n
ptpengine:delay_outlier_filter_stepdetect_enable=y
ptpengine:delay_outlier_filter_stepdetect_threshold = 1000000
ptpengine:delay_outlier_filter_stepdetect_level = 200000
; #### END Filter Configuration
; #### BEGIN Clock stability estimates
; If a clock constantly fails to lock (LOCKED state), the low threshold may need lowered
; The current value can be observed in the status file
; Allan deviation estimates for LOCKED and TRACKING, hardware clocks
servo:adev_locked_threshold_low_hw = 50.000000
servo:adev_locked_threshold_high_hw = 500.000000
; Allan deviation estimates for LOCKED and TRACKING, software clocks (system clock)
servo:adev_locked_threshold_low = 200.000000
servo:adev_locked_threshold_high = 2000.000000
; Allan deviation measurement period
servo:adev_interval = 10
; #### END Clock stability estimates
; #### BEGIN additional clocks and clock options
; extra clocks - any additional clocks you want to sync
;clock:extra_clocks="linuxphc:ethX, linuxphc:ethY"
; preferred master clock name - all clocks will use this unless there
; is a PTP source available. When running PTPd as master, you can specify "syst"
; to drive the master NIC's clock from the system clock.
;clock:master_clock_name = "ethA"
; specify the names of any clocks you want to be read-only
;clock:readonly_clock_names="ethB"
; specify the names of any clocks you want to exclude from sync
;clock:excluded_clock_names="ethC"
; #### END additional clocks and clock options
; #### BEGIN Other settings
; panic mode: delay when clock step detected
ptpengine:panic_mode=y
ptpengine:panic_mode_duration=60
; alarm support
global:enable_alarms=y
global:alarm_initial_delay=60
global:alarm_timeout=30
; alarm when offset exceeds 100 us
ptpengine:offset_alarm_threshold=100000
; Enable outlier filter for sync between OS and hardware clocks,
; and sync between hardware clocks
clock:outlier_filter_enable = y
; do not allow a software clock (system clock) to be stepped backwards
clock:allow_step_backwards = y
; allow a hardware clock to be stepped backwards
; this should be set to Y because a NIC may randomly reset the clock
clock:allow_step_backwards_hw = y
; bind to selected CPU core for improved system latency characteristics
; core 0 = first core
global:cpuaffinity_cpucore = 0
; store best clock frequency in files
clock:store_frequency = y
; store frequency data in /etc
clock:frequency_directory = /etc
; log file location
global:log_file = /var/run/ptpd.log
; status file location
global:status_file = /var/run/ptpd.status
; PI servo parameters (gains)
; NOTE: If the system clock is steered by a hardware clock,
; software clock gains can be set to the same values as hardware clock gains.
; software clock (system clock) control - when controlled by PTP
; using software timestamping
; servo:kp = 0.1
; servo:ki = 0.001
; software clock (system clock) control - when syncing from a hardware clock
servo:kp = 0.7
servo:ki = 0.3
; hardware clock control
servo:kp_hardware = 0.7
servo:ki_hardware = 0.3
; #### END Other settings
; ######### ptpd 2.3.2-linuxphc configuration END
; always leave a newline in the end
`
Your help is most appreciated. Thank you!
Hi there,
What you are seeing is actually a "side effect" of the driver / OS not being able to capture the transmission timestamps of the delay request messages. This is a notorious problem with many cards and drivers, almost to be expected. Ptpd silently ignores this, but as a result you have sequence gaps, because the transmitted delayResp - which is physically transmitted - is considered not sent, and the response comes back, but is dropped. I think I will need to rework this, because this behaviour causes some confusion. If you send the ptpd process a SIGUSR2, it will dump all of its counters - you can expect
txTimestampErrorsto be incrementing.Transmission timestamps are delivered via the socket error queue which has to be polled after sending an event message - they should be available immediately, and they usually are, but are sometimes late. Ptpd will try a number of times with exponential backoff, but eventually gives up. Some drivers explicitly establish a validity period and purge late timestamps. Only high-end "enterprise" type NICs like Solarflare and Mellanox deal with this with no issues - most SoC timestamping MAC / PHY timestampers have the same issue, also many / most Intel NICs. This is not a problem with hardware but rather a problem with the process of grabbing TX timestamps from the FIFO. If you were running a realtime OS and could talk to the hardware directly, you would not experience this.
HTH,
Cheers,
Wojciech
Hi Wojciech,
I really appreciate the work you've done on implementing H/W timestamping -- Very nice!
A little more about this environment: The Cyclone V SoC uses the ST Microelectronics EMAC, and the O/S I'm using is a Linux 4.10 kernel --
I'm not seeing txTimestampErrors as much as I'm seeing rxTimestampErrors errors:
~~~
2017-06-29 22:31:58.763006 ptpd[558].(info) transport: ======= transport 'Event' error counters ======
2017-06-29 22:31:58.763155 ptpd[558].(info) transport: rxErrors: 0
2017-06-29 22:31:58.763303 ptpd[558].(info) transport: txErrors: 0
2017-06-29 22:31:58.763452 ptpd[558].(info) transport: rxTimestampErrors: 46459
2017-06-29 22:31:58.763601 ptpd[558].(info) transport: txTimestampErrors: 3523
2017-06-29 22:31:58.763750 ptpd[558].(info) transport: rxDiscards: 0
2017-06-29 22:31:58.763899 ptpd[558].(info) transport: txDiscards: 0
2017-06-29 22:31:58.764047 ptpd[558].(info) transport: ===========================================
2017-06-29 22:31:58.764197 ptpd[558].(info) transport: ======= transport 'General' counters =============
2017-06-29 22:31:58.764346 ptpd[558].(info) transport: rxMsg: 50166
2017-06-29 22:31:58.764494 ptpd[558].(info) transport: txMsg: 0
2017-06-29 22:31:58.764651 ptpd[558].(info) transport: rxBytes: 4853876
2017-06-29 22:31:58.764801 ptpd[558].(info) transport: txBytes: 0
2017-06-29 22:31:58.764951 ptpd[558].(info) transport: ======= transport 'General' rates ================
2017-06-29 22:31:58.765099 ptpd[558].(info) transport: rxRateMsg: 10 / s
2017-06-29 22:31:58.765248 ptpd[558].(info) transport: txRateMsg: 0 / s
2017-06-29 22:31:58.765396 ptpd[558].(info) transport: rxRateBytes: 970 / s
2017-06-29 22:31:58.765544 ptpd[558].(info) transport: txRateBytes: 0 / s
2017-06-29 22:31:58.765718 ptpd[558].(info) transport: ======= transport 'General' error counters =======
2017-06-29 22:31:58.765876 ptpd[558].(info) transport: rxErrors: 0
2017-06-29 22:31:58.766027 ptpd[558].(info) transport: txErrors: 0
2017-06-29 22:31:58.766176 ptpd[558].(info) transport: rxTimestampErrors: 0
2017-06-29 22:31:58.766325 ptpd[558].(info) transport: txTimestampErrors: 0
2017-06-29 22:31:58.766474 ptpd[558].(info) transport: rxDiscards: 0
2017-06-29 22:31:58.766622 ptpd[558].(info) transport: txDiscards: 0
2017-06-29 22:31:58.766770 ptpd[558].(info) transport: ===========================================
Host info : buildroot, PID 558
Local time : Thu Jun 29 22:37:53 UTC 2017
Kernel time : Thu Jun 29 22:37:53 GMT 2017
Interface : eth0, status: OK
Transport : linuxts_udpv4, H/W tstamp, multicast
PTP preset : slaveonly
Delay mechanism : E2E
Sync mode : ONE_STEP
PTP domain : 2
Port state : PTP_SLAVE
Alarms : OFMS[!] SYN[.]
Local port ID : 2cee26fffe000165(unknown)/1
Best master ID : 000cecfffe0a0fb2(unknown)/1
Best master addr : 10.0.10.200
Master priority : Priority1 128, Priority2 128, clockClass 6
Time properties : PTP timescale, tracbl: time Y, freq Y, src: GPS(0x20)
UTC properties : UTC valid: Y, UTC offset: 37
Offset from Master : -567.000387036 s, mean 0.000000000 s, dev 0.000000000 s
Mean Path Delay : 0.000000000 s, mean 0.000000000 s, dev 0.000000000 s
PTP Clock status : calibrated, not stabilised
Message rates : 1/s sync, 1/s delay, 1/s announce
Performance : Message RX 25/s 1708 Bps, TX 1/s 44 Bps
Announce received : 4148
Sync received : 18
DelayReq sent : 3884
DelayResp received : 0
State transitions : 3
PTP Engine resets : 1
Clock 1: syst : name: syst state: FREERUN ref: none
Clock 2: eth0 : name: eth0 state: FREQEST ref: PTP
Clock 1: syst : offs: 0.000000000 adev: 0.000 freq: 0.000
Clock 2: eth0 : offs: 567.000387036 adev: 0.000 freq: 0.000
~~~
Thanks again for your help, it is most appreciated!
Cheers,
-Allan
Allan,
OK - that would explain the reported empty messages received - as per the comment in the sources "mesage without a timestamp considered harmful". This is likely a driver issue. While for TX timestamps, PTPd has its own way of dealing with waiting for them - for RX timestamps it follows the API and does nothing special.
Thanks,
Wojciech
Hi Wojciech,
Quick update. I have your branch of PTPd working on the Altera Cyclone V SoC. This infers (implies?) that PTPd should work on the Altera Arria V SoC, too, as both of these products use the eMAC licensed from ST Microelectronics.
Thanks again for all your help!
-Allan