Bug 1892467

Summary: linuxptp-daemon crash
Product: OpenShift Container Platform Reporter: Sebastian Scheinkman <sscheink>
Component: NetworkingAssignee: Sebastian Scheinkman <sscheink>
Networking sub component: ptp QA Contact: Nikita <nkononov>
Status: CLOSED ERRATA Docs Contact:
Severity: urgent    
Priority: urgent CC: elevin, nkononov, yjoseph, zshi
Version: 4.6Flags: nkononov: needinfo-
Target Milestone: ---   
Target Release: 4.7.0   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: Doc Type: No Doc Update
Doc Text:
Story Points: ---
Clone Of:
: 1906708 (view as bug list) Environment:
Last Closed: 2021-02-24 15:29:18 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Bug Depends On:    
Bug Blocks: 1893480, 1906708    

Description Sebastian Scheinkman 2020-10-28 20:36:36 UTC
Description of problem:
linuxptp-daemon crash trying to part a message for metrics

1028 09:23:10.318238 3415980 daemon.go:106] Phc2sysOpts: -n 24 -i ens9f0 -w -m -u 1
I1028 09:23:10.318243 3415980 daemon.go:122] ------------------------------------
E1028 09:23:10.319377 3415980 metrics.go:215] starting metrics server failed: listen tcp 0.0.0.0:9091: bind: address already in use
I1028 09:23:11.318476 3415980 daemon.go:210] Starting phc2sys...
I1028 09:23:11.318496 3415980 daemon.go:211] phc2sys cmd: /usr/sbin/phc2sys -n 24 -i ens9f0 -w -m -u 1
I1028 09:23:12.318631 3415980 daemon.go:210] Starting ptp4l...
I1028 09:23:12.318677 3415980 daemon.go:211] ptp4l cmd: /usr/sbin/ptp4l -f /ptp4l-conf/etcd-1-master-ptp-profile.conf -i ens9f0 -2 -s -m --summary_interval 1
ptp4l[435056.445]: selected /dev/ptp3 as PTP clock
phc2sys[435056.446]: Waiting for ptp4l...
ptp4l[435056.461]: port 1: INITIALIZING to LISTENING on INIT_COMPLETE
ptp4l[435056.461]: port 0: INITIALIZING to LISTENING on INIT_COMPLETE
ptp4l[435056.754]: port 1: new foreign master 86a539.fffe.96186d-19
ptp4l[435056.946]: selected local clock 3cfdfe.fffe.bcf2c4 as best master
ptp4l[435057.002]: selected best master clock 86a539.fffe.96186d
ptp4l[435057.002]: updating UTC offset to 37
E1028 09:23:12.876622 3415980 metrics.go:153] ptp4l failed to parse offset from master output to error strconv.ParseFloat: parsing "to": invalid syntax
E1028 09:23:12.876891 3415980 metrics.go:158] ptp4l failed to parse max offset from master output to error strconv.ParseFloat: parsing "to": invalid syntax
panic: runtime error: index out of range [4] with length 3
goroutine 330 [running]:
github.com/openshift/linuxptp-daemon/pkg/daemon.extractRegularMetrics(0x13e9639, 0x5, 0xc0009ac3c0, 0x2c, 0x20, 0x0, 0xc000538000, 0x0)
        /go/src/github.com/openshift/linuxptp-daemon/pkg/daemon/metrics.go:161 +0x7af
github.com/openshift/linuxptp-daemon/pkg/daemon.extractMetrics(0x13e9639, 0x5, 0xc0009ac3c0, 0x2c)
        /go/src/github.com/openshift/linuxptp-daemon/pkg/daemon/metrics.go:103 +0x139
github.com/openshift/linuxptp-daemon/pkg/daemon.cmdRun.func2(0xc000380500, 0xc0001295e0, 0xc0005403c0)
        /go/src/github.com/openshift/linuxptp-daemon/pkg/daemon/daemon.go:230 +0x10c
created by github.com/openshift/linuxptp-daemon/pkg/daemon.cmdRun
        /go/src/github.com/openshift/linuxptp-daemon/pkg/daemon/daemon.go:226 +0x3b6

Comment 3 Sebastian Scheinkman 2020-11-23 14:09:30 UTC
Validation

I1123 13:42:34.469209  702600 daemon.go:105] Phc2sysOpts: -a -r -n 24 -m -u 1 -z /var/run/ptp4l.0.socket -t [eth7]                                                                                                                                 │··········
I1123 13:42:34.469215  702600 daemon.go:166] ------------------------------------                                                                                                                                                                  │··········
I1123 13:42:35.469533  702600 daemon.go:240] Starting phc2sys...                                                                                                                                                                                   │··········
I1123 13:42:35.469548  702600 daemon.go:241] phc2sys cmd: /usr/sbin/phc2sys -a -r -n 24 -m -u 1 -z /var/run/ptp4l.0.socket -t [eth7]                                                                                                               │··········
I1123 13:42:36.469609  702600 daemon.go:240] Starting ptp4l...                                                                                                                                                                                     │··········
I1123 13:42:36.469623  702600 daemon.go:241] ptp4l cmd: /usr/sbin/ptp4l -f /var/run/ptp4l.0.config -i eth7 -2 -s --summary_interval -4 -m                                                                                                          │··········
ptp4l[232952.950]: [eth7] selected /dev/ptp7 as PTP clock                                                                                                                                                                                          │··········
phc2sys[232952.951]: [eth7] Waiting for ptp4l...                                                                                                                                                                                                   │··········
ptp4l[232952.965]: [eth7] port 1: INITIALIZING to LISTENING on INIT_COMPLETE                                                                                                                                                                       │··········
ptp4l[232952.965]: [eth7] port 0: INITIALIZING to LISTENING on INIT_COMPLETE                                                                                                                                                                       │··········
ptp4l[232953.387]: [eth7] selected local clock 644c36.fffe.11eff0 as best master                                                                                                                                                                   │··········
ptp4l[232953.830]: [eth7] selected local clock 644c36.fffe.11eff0 as best master                                                                                                                                                                   │··········
ptp4l[232953.830]: [eth7] port 1: new foreign master 94aef0.fffe.0514d8-4                                                                                                                                                                          │··········
phc2sys[232953.952]: [eth7] Waiting for ptp4l...                                                                                                                                                                                                   │··········
ptp4l[232954.074]: [eth7] selected best master clock 00b0ae.fffe.06d828                                                                                                                                                                            │··········
ptp4l[232954.074]: [eth7] updating UTC offset to 37                                                                                                                                                                                                │··········
E1123 13:42:37.594740  702600 metrics.go:157] ptp4l failed to parse output offset to 37: unexpected number of fields                                                                                                                               │··········
ptp4l[232954.074]: [eth7] port 1: LISTENING to UNCALIBRATED on RS_SLAVE                                                                                                                                                                            │··········
ptp4l[232954.136]: [eth7] master offset -37820656482 s0 freq      +0 path delay       492     

can we move this to verify?

Comment 6 errata-xmlrpc 2021-02-24 15:29:18 UTC
Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory (Moderate: OpenShift Container Platform 4.7.0 security, bug fix, and enhancement update), and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

https://access.redhat.com/errata/RHSA-2020:5633