Description of problem:
During the PTP verification test with 4.16.38 ocp version, an offset spike occurred on the second NIC, causing it to go into FREERUN status, and immediately the status of all NICs changed to FREERUN. ------------------------ 2025-05-14T03:34:04.777837949+00:00 stdout F ts2phc[158897.775]: [ts2phc.0.config:6] /dev/ptp0 offset 0 s2 freq -0 2025-05-14T03:34:04.777978876+00:00 stderr F I0514 03:34:04.777943 14642 stats.go:61] state updated for ts2phc =s2 2025-05-14T03:34:04.778423243+00:00 stdout F ts2phc[158897.775]: [ts2phc.0.config:7] adding tstamp 1747193681.000000000 to clock /dev/ptp0 2025-05-14T03:34:04.778484105+00:00 stdout F ts2phc[158897.775]: [ts2phc.0.config:7] adding tstamp 1747193681.000000000 to clock /dev/ptp1 2025-05-14T03:34:04.778528826+00:00 stdout F ts2phc[158897.775]: [ts2phc.0.config:7] adding tstamp 1747193681.000000001 to clock /dev/ptp3 2025-05-14T03:34:04.778528826+00:00 stdout F ts2phc[158897.775]: [ts2phc.0.config:7] nmea delay: 321247879 ns 2025-05-14T03:34:04.778642351+00:00 stdout F ts2phc[158897.775]: [ts2phc.0.config:6] /dev/ptp3 offset -999999999 s2 freq -100000000 2025-05-14T03:34:04.778681171+00:00 stdout F GM (Grand Master Clock) (State:FreeRun) 2025-05-14T03:34:04.778681171+00:00 stdout F *├── ClockClass (State:6) 2025-05-14T03:34:04.778681171+00:00 stdout F *├── OVER-ALL-TS2PHC (State:FreeRun) 2025-05-14T03:34:04.778681171+00:00 stdout F * ├── ts2phc (State:Locked) 2025-05-14T03:34:04.778681171+00:00 stdout F * └── State: Locked Iface: ens1f0 Offset -1410 2025-05-14T03:34:04.778681171+00:00 stdout F * ├── ts2phc (State:FreeRun) 2025-05-14T03:34:04.778681171+00:00 stdout F * └── State: FreeRun Iface: ens3f0 Offset -999999999 2025-05-14T03:34:04.778681171+00:00 stdout F * └── ts2phc (State:Locked) 2025-05-14T03:34:04.778681171+00:00 stdout F * └── State: Locked Iface: ens2f0 Offset -958 2025-05-14T03:34:04.778681171+00:00 stdout F *├── OVER-ALL-DPLL (State:Locked) 2025-05-14T03:34:04.778681171+00:00 stdout F * ├── dpll (State:Locked) 2025-05-14T03:34:04.778681171+00:00 stdout F * └── State: Locked Iface: ens1f0 Offset 5 2025-05-14T03:34:04.778681171+00:00 stdout F * ├── dpll (State:Locked) 2025-05-14T03:34:04.778681171+00:00 stdout F * └── State: Locked Iface: ens3f0 Offset -2 2025-05-14T03:34:04.778776845+00:00 stdout F * └── dpll (State:Locked) 2025-05-14T03:34:04.778776845+00:00 stdout F * └── State: Locked Iface: ens2f0 Offset -3 2025-05-14T03:34:04.778776845+00:00 stdout F *└── GNSS (State:Locked) 2025-05-14T03:34:04.778729275+00:00 stderr F I0514 03:34:04.778629 14642 stats.go:61] state updated for ts2phc =s0 2025-05-14T03:34:04.778729275+00:00 stderr F I0514 03:34:04.778684 14642 event.go:676] clock class change request from 6 to 248 2025-05-14T03:34:04.778729275+00:00 stderr F I0514 03:34:04.778697 14642 event.go:693] PTP State: GM State s0, Clock Class 248 Time 2025-05-14 03:34:04.778696906 +0000 UTC m=+158817.171667398 sourceLost false 2025-05-14T03:34:04.778776845+00:00 stdout F * └── dpll (State:Locked) 2025-05-14T03:34:04.778776845+00:00 stdout F * └── State: Locked Iface: ens2f0 Offset -3 2025-05-14T03:34:04.778776845+00:00 stdout F *└── GNSS (State:Locked) 2025-05-14T03:34:04.778803272+00:00 stderr F I0514 03:34:04.778723 14642 pmc.go:65] pmc -u -b 0 -f /var/run/ptp4l.0.config "GET GRANDMASTER_SETTINGS_NP" 2025-05-14T03:34:04.779048261+00:00 stdout F ts2phc[158897.776]: [ts2phc.0.config:6] /dev/ptp1 offset -1000000000 s2 freq -100000000 2025-05-14T03:34:04.779190367+00:00 stderr F I0514 03:34:04.779172 14642 stats.go:61] state updated for ts2phc =s0 2025-05-14T03:34:04.779249979+00:00 stdout F GM (Grand Master Clock) (State:FreeRun) 2025-05-14T03:34:04.779249979+00:00 stdout F *├── GNSS (State:Locked) 2025-05-14T03:34:04.779249979+00:00 stdout F *├── ClockClass (State:248) 2025-05-14T03:34:04.779249979+00:00 stdout F *├── OVER-ALL-TS2PHC (State:FreeRun) 2025-05-14T03:34:04.779249979+00:00 stdout F * ├── ts2phc (State:FreeRun) 2025-05-14T03:34:04.779249979+00:00 stdout F * └── State: FreeRun Iface: ens3f0 Offset -999999999 2025-05-14T03:34:04.779249979+00:00 stdout F * ├── ts2phc (State:FreeRun) 2025-05-14T03:34:04.779249979+00:00 stdout F * └── State: FreeRun Iface: ens2f0 Offset -1000000000 2025-05-14T03:34:04.779249979+00:00 stdout F * └── ts2phc (State:Locked) 2025-05-14T03:34:04.779249979+00:00 stdout F * └── State: Locked Iface: ens1f0 Offset -1410 2025-05-14T03:34:04.779249979+00:00 stdout F *└── OVER-ALL-DPLL (State:Locked) 2025-05-14T03:34:04.779249979+00:00 stdout F * ├── dpll (State:Locked) 2025-05-14T03:34:04.779249979+00:00 stdout F * └── State: Locked Iface: ens3f0 Offset -2 2025-05-14T03:34:04.779249979+00:00 stdout F * ├── dpll (State:Locked) 2025-05-14T03:34:04.779249979+00:00 stdout F * └── State: Locked Iface: ens2f0 Offset -3 2025-05-14T03:34:04.779249979+00:00 stdout F * └── dpll (State:Locked) 2025-05-14T03:34:04.779249979+00:00 stdout F * └── State: Locked Iface: ens1f0 Offset 5 2025-05-14T03:34:04.779327304+00:00 stderr F I0514 03:34:04.779242 14642 event.go:676] clock class change request from 6 to 248 2025-05-14T03:34:04.779451657+00:00 stdout F ts2phc[158897.776]: [ts2phc.0.config:6] /dev/ptp0 offset -1000000000 s2 freq -100000000 2025-05-14T03:34:04.779525129+00:00 stdout F GM (Grand Master Clock) (State:FreeRun) 2025-05-14T03:34:04.779525129+00:00 stdout F *├── ClockClass (State:248) 2025-05-14T03:34:04.779525129+00:00 stdout F *├── OVER-ALL-TS2PHC (State:FreeRun) 2025-05-14T03:34:04.779525129+00:00 stdout F * ├── ts2phc (State:FreeRun) 2025-05-14T03:34:04.779525129+00:00 stdout F * └── State: FreeRun Iface: ens3f0 Offset -999999999 2025-05-14T03:34:04.779525129+00:00 stdout F * ├── ts2phc (State:FreeRun) 2025-05-14T03:34:04.779525129+00:00 stdout F * └── State: FreeRun Iface: ens2f0 Offset -1000000000 2025-05-14T03:34:04.779525129+00:00 stdout F * └── ts2phc (State:FreeRun) 2025-05-14T03:34:04.779525129+00:00 stdout F * └── State: FreeRun Iface: ens1f0 Offset -1000000000 2025-05-14T03:34:04.779525129+00:00 stdout F *├── OVER-ALL-DPLL (State:Locked) 2025-05-14T03:34:04.779525129+00:00 stdout F * ├── dpll (State:Locked) 2025-05-14T03:34:04.779525129+00:00 stdout F * └── State: Locked Iface: ens2f0 Offset -3 2025-05-14T03:34:04.779525129+00:00 stdout F * ├── dpll (State:Locked) 2025-05-14T03:34:04.779525129+00:00 stdout F * └── State: Locked Iface: ens3f0 Offset -2 2025-05-14T03:34:04.779525129+00:00 stdout F * └── dpll (State:Locked) 2025-05-14T03:34:04.779525129+00:00 stdout F * └── State: Locked Iface: ens1f0 Offset 5 2025-05-14T03:34:04.779525129+00:00 stdout F *└── GNSS (State:Locked) 2025-05-14T03:34:04.779635431+00:00 stderr F I0514 03:34:04.779448 14642 stats.go:61] state updated for ts2phc =s0 2025-05-14T03:34:04.779635431+00:00 stderr F I0514 03:34:04.779492 14642 event.go:676] clock class change request from 6 to 248 2025-05-14T03:34:04.779635431+00:00 stderr F E0514 03:34:04.779505 14642 event.go:688] clock class request busy updating previous request, will try next event 2025-05-14T03:34:04.820192764+00:00 stdout F phc2sys[158897.817]: [ptp4l.0.config:6] CLOCK_REALTIME phc offset -4025329 s2 freq -4031192 delay 526 2025-05-14T03:34:04.882808673+00:00 stdout F phc2sys[158897.880]: [ptp4l.0.config:6] CLOCK_REALTIME phc offset -10009294 s2 freq -11222756 delay 554 2025-05-14T03:34:04.945435402+00:00 stdout F phc2sys[158897.942]: [ptp4l.0.config:6] CLOCK_REALTIME phc offset -15509239 s2 freq -19725489 delay 559 2025-05-14T03:34:05.002159484+00:00 stdout F ts2phc[158897.999]: [ts2phc.0.config:7] adding tstamp 1747193682.022016032 to clock /dev/ptp0 2025-05-14T03:34:05.002281105+00:00 stdout F ts2phc[158897.999]: [ts2phc.0.config:7] adding tstamp 1747193682.022065222 to clock /dev/ptp1 2025-05-14T03:34:05.002409538+00:00 stdout F ts2phc[158897.999]: [ts2phc.0.config:7] adding tstamp 1747193682.022104706 to clock /dev/ptp3 2025-05-14T03:34:05.002549203+00:00 stdout F ts2phc[158897.999]: [ts2phc.0.config:7] nmea delay: 321247879 ns 2025-05-14T03:34:05.002824263+00:00 stdout F ts2phc[158897.999]: [ts2phc.0.config:6] /dev/ptp3 offset 22104706 s2 freq +22104706 2025-05-14T03:34:05.003088068+00:00 stdout F ts2phc[158898.000]: [ts2phc.0.config:6] /dev/ptp1 offset 22065222 s2 freq +22065222 2025-05-14T03:34:05.003262517+00:00 stderr F I0514 03:34:05.003230 14642 stats.go:61] state updated for ts2phc =s0 2025-05-14T03:34:05.003315995+00:00 stderr F I0514 03:34:05.003259 14642 event.go:425] dpll State s2, gnss State s2, tsphc state s0, gm state s0, 2025-05-14T03:34:05.003410967+00:00 stderr F I0514 03:34:05.003273 14642 event.go:676] clock class change request from 6 to 248 2025-05-14T03:34:05.003454786+00:00 stderr F E0514 03:34:05.003411 14642 event.go:688] clock class request busy updating previous request, will try next event 2025-05-14T03:34:05.003611723+00:00 stdout F GM[1747193645]:[ts2phc.0.config] ens1f0 T-GM-STATUS s0 2025-05-14T03:34:05.003679312+00:00 stderr F I0514 03:34:05.003618 14642 stats.go:61] state updated for ts2phc =s0 2025-05-14T03:34:05.003728409+00:00 stderr F I0514 03:34:05.003676 14642 event.go:676] clock class change request from 6 to 248 2025-05-14T03:34:05.003876638+00:00 stdout F ts2phc[158898.001]: [ts2phc.0.config:6] /dev/ptp0 offset 22016032 s2 freq +22016032 2025-05-14T03:34:05.003961585+00:00 stderr F I0514 03:34:05.003942 14642 stats.go:61] state updated for ts2phc =s0 2025-05-14T03:34:05.004065418+00:00 stderr F I0514 03:34:05.004025 14642 event.go:676] clock class change request from 6 to 248 2025-05-14T03:34:05.004065418+00:00 stderr F E0514 03:34:05.004044 14642 event.go:688] clock class request busy updating previous request, will try next event 2025-05-14T03:34:05.004273528+00:00 stderr F E0514 03:34:05.004066 14642 event.go:688] clock class request busy updating previous request, will try next event 2025-05-14T03:34:05.008154207+00:00 stdout F phc2sys[158898.005]: [ptp4l.0.config:6] CLOCK_REALTIME phc offset -20439257 s2 freq -29308279 delay 557 2025-05-14T03:34:05.070732767+00:00 stdout F phc2sys[158898.068]: [ptp4l.0.config:6] CLOCK_REALTIME phc offset -19605479 s2 freq -34606278 delay 560 2025-05-14T03:34:05.133378458+00:00 stdout F phc2sys[158898.130]: [ptp4l.0.config:6] CLOCK_REALTIME phc offset -16177216 s2 freq -37059658 delay 573 2025-05-14T03:34:05.160322403+00:00 stdout F ts2phc[158898.157]: [ts2phc.0.config:7] nmea sentence: GNRMC,033405.00,A,3715.35579,N,12703.14484,E,0.000,,140525,,,A,V 2025-05-14T03:34:05.160693145+00:00 stdout F ts2phc[158898.157]: [ts2phc.0.config:7] nmea sentence: GNGGA,033405.00,3715.35579,N,12703.14484,E,1,12,99.99,53.4,M,18.8,M,, 2025-05-14T03:34:05.196031492+00:00 stdout F phc2sys[158898.193]: [ptp4l.0.config:6] CLOCK_REALTIME phc offset -12607596 s2 freq -38343203 delay 565 2025-05-14T03:34:05.258650480+00:00 stdout F phc2sys[158898.256]: [ptp4l.0.config:6] CLOCK_REALTIME phc offset -8968301 s2 freq -38486187 delay 574 2025-05-14T03:34:05.280147359+00:00 stderr F I0514 03:34:05.280075 14642 pmc.go:95] pmc result: sending: GET GRANDMASTER_SETTINGS_NP 2025-05-14T03:34:05.280147359+00:00 stderr F 507c6f.fffe.53b0a0-0 seq 0 RESPONSE MANAGEMENT GRANDMASTER_SETTINGS_NP 2025-05-14T03:34:05.280147359+00:00 stderr F clockClass 6 2025-05-14T03:34:05.280147359+00:00 stderr F clockAccuracy 0x27 2025-05-14T03:34:05.280147359+00:00 stderr F offsetScaledLogVariance 0x4e5d 2025-05-14T03:34:05.280147359+00:00 stderr F currentUtcOffset 37 2025-05-14T03:34:05.280147359+00:00 stderr F leap61 0 2025-05-14T03:34:05.280147359+00:00 stderr F leap59 0 2025-05-14T03:34:05.280147359+00:00 stderr F currentUtcOffsetValid 1 2025-05-14T03:34:05.280147359+00:00 stderr F ptpTimescale 1 2025-05-14T03:34:05.280147359+00:00 stderr F timeTraceable 1 2025-05-14T03:34:05.280147359+00:00 stderr F frequencyTraceable 1 2025-05-14T03:34:05.280147359+00:00 stderr F timeSource 0x20 2025-05-14T03:34:05.284147573+00:00 stderr F I0514 03:34:05.284057 14642 pmc.go:135] pmc result: sending: SET GRANDMASTER_SETTINGS_NP 2025-05-14T03:34:05.284147573+00:00 stderr F 507c6f.fffe.53b0a0-0 seq 0 RESPONSE MANAGEMENT GRANDMASTER_SETTINGS_NP 2025-05-14T03:34:05.284147573+00:00 stderr F clockClass 248 2025-05-14T03:34:05.284147573+00:00 stderr F clockAccuracy 0x27 2025-05-14T03:34:05.284147573+00:00 stderr F offsetScaledLogVariance 0xffff 2025-05-14T03:34:05.284147573+00:00 stderr F currentUtcOffset 37 2025-05-14T03:34:05.284147573+00:00 stderr F leap61 0 2025-05-14T03:34:05.284147573+00:00 stderr F leap59 0 2025-05-14T03:34:05.284147573+00:00 stderr F currentUtcOffsetValid 1 2025-05-14T03:34:05.284147573+00:00 stderr F ptpTimescale 1 2025-05-14T03:34:05.284147573+00:00 stderr F timeTraceable 0 2025-05-14T03:34:05.284147573+00:00 stderr F frequencyTraceable 1 2025-05-14T03:34:05.284147573+00:00 stderr F timeSource 0xa0 2025-05-14T03:34:05.284220271+00:00 stdout F ptp4l[158898.281]: [ptp4l.0.config:5] port 1 (ens1f0): assuming the grand master role 2025-05-14T03:34:05.284596969+00:00 stderr F I0514 03:34:05.284571 14642 event.go:940] received ts2phc.0.config,248,GM 2025-05-14T03:34:05.284623361+00:00 stdout F ptp4l[1747193645]:[ts2phc.0.config] CLOCK_CLASS_CHANGE 248
Version-Release number of selected component (if applicable):
ptp-operator-4.16.0-202503121138
How reproducible:
Not sure.
Steps to Reproduce:
# ptpConfig - grandmaster --- apiVersion: ptp.openshift.io/v1 kind: PtpConfig metadata: name: grandmaster namespace: openshift-ptp spec: profile: - name: grandmaster phc2sysOpts: -r -u 0 -m -N 8 -R 16 -S 2 -s ens1f0 -n 24 plugins: e810: enableDefaultConfig: false pins: ens1f0: SMA1: 2 1 SMA2: 2 2 U.FL1: 0 1 U.FL2: 0 2 ens2f0: SMA1: 1 1 SMA2: 1 2 U.FL1: 0 1 U.FL2: 0 2 ens3f0: SMA1: 1 1 SMA2: 1 2 U.FL1: 0 1 U.FL2: 0 2 settings: LocalHoldoverTimeout: 14400 LocalMaxHoldoverOffSet: 1500 MaxInSpecOffset: 1500 ublxCmds: - args: - -P - "29.20" - -z - CFG-HW-ANT_CFG_VOLTCTRL,1 reportOutput: false - args: - -P - "29.20" - -e - GPS reportOutput: false - args: - -P - "29.20" - -d - Galileo reportOutput: false - args: - -P - "29.20" - -d - GLONASS reportOutput: false - args: - -P - "29.20" - -d - BeiDou reportOutput: false - args: - -P - "29.20" - -d - SBAS reportOutput: false - args: - -P - "29.20" - -t - -w - "5" - -v - "1" - -e - SURVEYIN,600,50000 reportOutput: true - args: - -P - "29.20" - -p - MON-HW reportOutput: true - args: - -P - "29.20" - -p - CFG-MSG,1,38,248 reportOutput: true - args: - -P - "29.20" - -p - CFG-MSG,0xf0,0x02,0 reportOutput: false - args: - -P - "29.20" - -p - CFG-MSG,0xf0,0x03,0 reportOutput: false ptp4lConf: | [ens1f0] masterOnly 1 [ens1f1] masterOnly 1 [ens1f2] masterOnly 1 [ens1f3] masterOnly 1 [ens2f0] masterOnly 1 [ens2f1] masterOnly 1 [ens2f2] masterOnly 1 [ens2f3] masterOnly 1 [ens3f0] masterOnly 1 [ens3f1] masterOnly 1 [ens3f2] masterOnly 1 [ens3f3] masterOnly 1 [global] # # Default Data Set # twoStepFlag 1 slaveOnly 0 priority1 128 priority2 128 domainNumber 24 #utc_offset 37 clockClass 6 clockAccuracy 0x27 offsetScaledLogVariance 0xFFFF free_running 0 freq_est_interval 1 dscp_event 0 dscp_general 0 dataset_comparison G.8275.x G.8275.defaultDS.localPriority 128 # # Port Data Set # logAnnounceInterval -3 logSyncInterval -4 logMinDelayReqInterval -4 logMinPdelayReqInterval 0 announceReceiptTimeout 3 syncReceiptTimeout 0 delayAsymmetry 0 fault_reset_interval -4 neighborPropDelayThresh 20000000 masterOnly 0 G.8275.portDS.localPriority 128 # # Run time options # assume_two_step 0 logging_level 6 path_trace_enabled 0 follow_up_info 0 hybrid_e2e 0 inhibit_multicast_service 0 net_sync_monitor 0 tc_spanning_tree 0 tx_timestamp_timeout 50 unicast_listen 0 unicast_master_table 0 unicast_req_duration 3600 use_syslog 1 verbose 0 summary_interval -4 kernel_leap 1 check_fup_sync 0 clock_class_threshold 7 # # Servo Options # pi_proportional_const 0.0 pi_integral_const 0.0 pi_proportional_scale 0.0 pi_proportional_exponent -0.3 pi_proportional_norm_max 0.7 pi_integral_scale 0.0 pi_integral_exponent 0.4 pi_integral_norm_max 0.3 step_threshold 2.0 first_step_threshold 0.00002 clock_servo pi sanity_freq_limit 200000000 ntpshm_segment 0 # # Transport options # transportSpecific 0x0 ptp_dst_mac 01:1B:19:00:00:00 p2p_dst_mac 01:80:C2:00:00:0E udp_ttl 1 udp6_scope 0x0E uds_address /var/run/ptp4l # # Default interface options # clock_type BC network_transport L2 delay_mechanism E2E time_stamping hardware tsproc_mode filter delay_filter moving_median delay_filter_length 10 egressLatency 0 ingressLatency 0 boundary_clock_jbod 1 # # Clock description # productDescription ;; revisionData ;; manufacturerIdentity 00:00:00 userDescription ; # timeSource 0xA0 means internal oscillator, 0x20 means GPS timeSource 0x20 ptp4lOpts: -2 --summary_interval -4 ptpClockThreshold: holdOverTimeout: 240 maxOffsetThreshold: 1500 minOffsetThreshold: -1500 ptpSchedulingPolicy: SCHED_FIFO ptpSchedulingPriority: 10 ptpSettings: logReduce: "true" ts2phcConf: | [nmea] ts2phc.master 1 [global] use_syslog 0 verbose 1 logging_level 7 ts2phc.pulsewidth 100000000 leapfile /usr/share/zoneinfo/leap-seconds.list #GNSS module s /dev/ttyGNSS* -al use _0 ts2phc.nmea_serialport /dev/gnss0 ts2phc.nmea_delay -100000000 [ens1f0] ts2phc.extts_polarity rising ts2phc.extts_correction 0 [ens2f0] ts2phc.extts_polarity rising #ts2phc.extts_correction -10 ts2phc.master 0 [ens3f0] ts2phc.extts_polarity rising #ts2phc.extts_correction -10 ts2phc.master 0 ts2phcOpts: ' ' recommend: - match: - nodeLabel: node-role.kubernetes.io/master priority: 4 profile: grandmaster
Actual results:
FreeRun
Expected results:
Locked or Holdover
Additional info:
HPE ProLiant DL110 Gen11/ProLiant DL110 Gen11
- is blocked by
-
OCPBUGS-58890 ptp all sync-state event should be FREERUN. Instead sends event as LOCKED
-
- Closed
-