OVS parsing on busy nodes results in heavy node allocations, CPU use #17312
Description
On a heavily loaded node in a cluster with many services, OVS parsing is one of the biggest sources of allocations, which contributes to the 1-1.5 cores the node is consuming:
Total allocations by method:
$ go tool pprof --alloc_objects /tmp/openshift ~/Downloads/heap-starter-ca-central-1-node-compute-ca43a.dms
File: openshift
Type: alloc_objects
Time: Nov 14, 2017 at 4:22pm (EST)
Entering interactive mode (type "help" for commands, "o" for options)
(pprof) top30
Showing nodes accounting for 6145327513, 92.29% of 6658576269 total
Dropped 3009 nodes (cum <= 33292881)
Showing top 30 nodes out of 236
flat flat% sum% cum cum%
1994734310 29.96% 29.96% 1994734310 29.96% runtime.rawstringtmp /usr/lib/golang/src/runtime/string.go
985757034 14.80% 44.76% 985757034 14.80% reflect.unsafe_New /usr/lib/golang/src/runtime/malloc.go
875220879 13.14% 57.91% 875220879 13.14% strings.makeCutsetFunc /usr/lib/golang/src/strings/strings.go
823740993 12.37% 70.28% 823740993 12.37% runtime.convT2E /usr/lib/golang/src/runtime/iface.go
200515912 3.01% 73.29% 1277226464 19.18% github.com/openshift/origin/pkg/util/ovs.ParseFlow /builddir/build/BUILD/atomic-openshift-git-0.94b7dea/_output/local/go/src/github.com/openshift/origin/pkg/util/ovs/parse.go
198606718 2.98% 76.27% 207126656 3.11% github.com/openshift/origin/vendor/github.com/prometheus/client_golang/prometheus.makeLabelPairs /builddir/build/BUILD/atomic-openshift-git-0.94b7dea/_output/local/go/src/github.com/openshift/origin/vendor/github.com/prometheus/client_golang/prometheus/value.go
133371095 2.00% 78.27% 133371095 2.00% syscall.ByteSliceFromString /usr/lib/golang/src/syscall/syscall.go
108737937 1.63% 79.91% 186021644 2.79% runtime.mapassign /usr/lib/golang/src/runtime/hashmap.go
102560061 1.54% 81.45% 402018023 6.04% github.com/openshift/origin/pkg/util/ovs.parseActions /builddir/build/BUILD/atomic-openshift-git-0.94b7dea/_output/local/go/src/github.com/openshift/origin/pkg/util/ovs/parse.go
99503066 1.49% 82.94% 299457962 4.50% github.com/openshift/origin/pkg/util/ovs.actionToOvsField /builddir/build/BUILD/atomic-openshift-git-0.94b7dea/_output/local/go/src/github.com/openshift/origin/pkg/util/ovs/parse.go
84957585 1.28% 84.22% 84957585 1.28% runtime.makemap /usr/lib/golang/src/runtime/hashmap.go
76322753 1.15% 85.36% 76322753 1.15% runtime.hashGrow /usr/lib/golang/src/runtime/hashmap.go
75668740 1.14% 86.50% 150608527 2.26% os.Lstat /usr/lib/golang/src/os/stat_unix.go
62899286 0.94% 87.45% 62899286 0.94% os.NewFile /usr/lib/golang/src/os/file_unix.go
57990164 0.87% 88.32% 57990164 0.87% runtime.convT2I /usr/lib/golang/src/runtime/iface.go
42950399 0.65% 88.96% 42950399 0.65% strings.FieldsFunc /usr/lib/golang/src/strings/strings.go
39519398 0.59% 89.55% 66109693 0.99% reflect.MakeSlice /usr/lib/golang/src/reflect/value.go
29665835 0.45% 90.00% 117243382 1.76% github.com/openshift/origin/vendor/github.com/prometheus/client_golang/prometheus.NewDesc /builddir/build/BUILD/atomic-openshift-git-0.94b7dea/_output/local/go/src/github.com/openshift/origin/vendor/github.com/prometheus/client_golang/prometheus/desc.go
25282650 0.38% 90.38% 50972521 0.77% strings.Replace /usr/lib/golang/src/strings/strings.go
24138407 0.36% 90.74% 46988477 0.71% os.Stat /usr/lib/golang/src/os/stat_unix.go
22819601 0.34% 91.08% 45555807 0.68% io/ioutil.readAll /usr/lib/golang/src/io/ioutil/ioutil.go
13373557 0.2% 91.29% 498120778 7.48% github.com/openshift/origin/vendor/k8s.io/kubernetes/pkg/kubelet/kuberuntime.(*kubeGenericRuntimeManager).GetPods /builddir/build/BUILD/atomic-openshift-git-0.94b7dea/_output/local/go/src/github.com/openshift/origin/vendor/k8s.io/kubernetes/pkg/kubelet/kuberuntime/kuberuntime_manager.go
13124456 0.2% 91.48% 63623462 0.96% github.com/openshift/origin/vendor/github.com/prometheus/client_golang/prometheus.(*Registry).Gather /builddir/build/BUILD/atomic-openshift-git-0.94b7dea/_output/local/go/src/github.com/openshift/origin/vendor/github.com/prometheus/client_golang/prometheus/registry.go
11370668 0.17% 91.65% 265900049 3.99% github.com/openshift/origin/vendor/github.com/prometheus/common/expfmt.writeSample /builddir/build/BUILD/atomic-openshift-git-0.94b7dea/_output/local/go/src/github.com/openshift/origin/vendor/github.com/prometheus/common/expfmt/text_create.go
9829358 0.15% 91.80% 82547394 1.24% os.(*File).readdirnames /usr/lib/golang/src/os/dir_unix.go
9251919 0.14% 91.94% 216367652 3.25% github.com/openshift/origin/vendor/github.com/prometheus/client_golang/prometheus.NewConstMetric /builddir/build/BUILD/atomic-openshift-git-0.94b7dea/_output/local/go/src/github.com/openshift/origin/vendor/github.com/prometheus/client_golang/prometheus/value.go
Cumulative allocations
pprof) top30
Showing nodes accounting for 3183546734, 47.81% of 6658576269 total
Dropped 3009 nodes (cum <= 33292881)
Showing top 30 nodes out of 236
flat flat% sum% cum cum%
0 0% 0% 6644154905 99.78% runtime.goexit /usr/lib/golang/src/runtime/asm_amd64.s
0 0% 0% 2475485174 37.18% github.com/openshift/origin/vendor/google.golang.org/grpc.(*Server).serveStreams.func1.1 /builddir/build/BUILD/atomic-openshift-git-0.94b7dea/_output/local/go/src/github.com/openshift/origin/vendor/google.golang.org/grpc/server.go
1615516 0.024% 0.024% 2474108874 37.16% github.com/openshift/origin/vendor/google.golang.org/grpc.(*Server).processUnaryRPC /builddir/build/BUILD/atomic-openshift-git-0.94b7dea/_output/local/go/src/github.com/openshift/origin/vendor/google.golang.org/grpc/server.go
0 0% 0.024% 2474076105 37.16% github.com/openshift/origin/vendor/google.golang.org/grpc.(*Server).handleStream /builddir/build/BUILD/atomic-openshift-git-0.94b7dea/_output/local/go/src/github.com/openshift/origin/vendor/google.golang.org/grpc/server.go
0 0% 0.024% 2363458686 35.49% encoding/json.(*decodeState).unmarshal /usr/lib/golang/src/encoding/json/decode.go
0 0% 0.024% 2363458686 35.49% encoding/json.(*decodeState).value /usr/lib/golang/src/encoding/json/decode.go
0 0% 0.024% 2357789137 35.41% encoding/json.(*decodeState).object /usr/lib/golang/src/encoding/json/decode.go
0 0% 0.024% 2349679177 35.29% encoding/json.(*Decoder).Decode /usr/lib/golang/src/encoding/json/stream.go
0 0% 0.024% 2312217811 34.73% github.com/openshift/origin/vendor/k8s.io/apimachinery/pkg/util/wait.JitterUntil /builddir/build/BUILD/atomic-openshift-git-0.94b7dea/_output/local/go/src/github.com/openshift/origin/vendor/k8s.io/apimachinery/pkg/util/wait/wait.go
0 0% 0.024% 2312209619 34.73% github.com/openshift/origin/vendor/k8s.io/apimachinery/pkg/util/wait.JitterUntil.func1 /builddir/build/BUILD/atomic-openshift-git-0.94b7dea/_output/local/go/src/github.com/openshift/origin/vendor/k8s.io/apimachinery/pkg/util/wait/wait.go
0 0% 0.024% 2311261102 34.71% github.com/openshift/origin/vendor/k8s.io/apimachinery/pkg/util/wait.Until /builddir/build/BUILD/atomic-openshift-git-0.94b7dea/_output/local/go/src/github.com/openshift/origin/vendor/k8s.io/apimachinery/pkg/util/wait/wait.go
0 0% 0.024% 2301634836 34.57% encoding/json.(*decodeState).array /usr/lib/golang/src/encoding/json/decode.go
1994734310 29.96% 29.98% 1994734310 29.96% runtime.rawstringtmp /usr/lib/golang/src/runtime/string.go
0 0% 29.98% 1755664988 26.37% runtime.slicebytetostring /usr/lib/golang/src/runtime/string.go
0 0% 29.98% 1348179428 20.25% github.com/openshift/origin/pkg/cmd/util/docker.(*KubeDocker).ListContainers <autogenerated>
0 0% 29.98% 1348179428 20.25% github.com/openshift/origin/vendor/k8s.io/kubernetes/pkg/kubelet/dockershim/libdocker.(*instrumentedInterface).ListContainers <autogenerated>
0 0% 29.98% 1348179428 20.25% github.com/openshift/origin/vendor/k8s.io/kubernetes/pkg/kubelet/dockershim/libdocker.(*kubeDockerClient).ListContainers /builddir/build/BUILD/atomic-openshift-git-0.94b7dea/_output/local/go/src/github.com/openshift/origin/vendor/k8s.io/kubernetes/pkg/kubelet/dockershim/libdocker/kube_docker_client.go
0 0% 29.98% 1348179428 20.25% github.com/openshift/origin/vendor/k8s.io/kubernetes/pkg/kubelet/dockershim/libdocker.instrumentedInterface.ListContainers /builddir/build/BUILD/atomic-openshift-git-0.94b7dea/_output/local/go/src/github.com/openshift/origin/vendor/k8s.io/kubernetes/pkg/kubelet/dockershim/libdocker/instrumented_client.go
914085 0.014% 30.00% 1346945115 20.23% github.com/openshift/origin/vendor/github.com/docker/engine-api/client.(*Client).ContainerList /builddir/build/BUILD/atomic-openshift-git-0.94b7dea/_output/local/go/src/github.com/openshift/origin/vendor/github.com/docker/engine-api/client/container_list.go
200515912 3.01% 33.01% 1277226464 19.18% github.com/openshift/origin/pkg/util/ovs.ParseFlow /builddir/build/BUILD/atomic-openshift-git-0.94b7dea/_output/local/go/src/github.com/openshift/origin/pkg/util/ovs/parse.go
0 0% 33.01% 1254201779 18.84% github.com/openshift/origin/pkg/network/node.(*OsdnNode).alreadySetUp /builddir/build/BUILD/atomic-openshift-git-0.94b7dea/_output/local/go/src/github.com/openshift/origin/pkg/network/node/sdn_controller.go
0 0% 33.01% 1253996982 18.83% github.com/openshift/origin/pkg/network/node.(*ovsController).AlreadySetUp /builddir/build/BUILD/atomic-openshift-git-0.94b7dea/_output/local/go/src/github.com/openshift/origin/pkg/network/node/ovscontroller.go
0 0% 33.01% 1253199817 18.82% github.com/openshift/origin/pkg/network/node.runOVSHealthCheck.func2 /builddir/build/BUILD/atomic-openshift-git-0.94b7dea/_output/local/go/src/github.com/openshift/origin/pkg/network/node/healthcheck.go
0 0% 33.01% 1253189154 18.82% github.com/openshift/origin/pkg/network/node.(*OsdnNode).SetupSDN.func1 /builddir/build/BUILD/atomic-openshift-git-0.94b7dea/_output/local/go/src/github.com/openshift/origin/pkg/network/node/sdn_controller.go
985757034 14.80% 47.81% 985757034 14.80% reflect.unsafe_New /usr/lib/golang/src/runtime/malloc.go
0 0% 47.81% 942570492 14.16% github.com/openshift/origin/vendor/k8s.io/kubernetes/pkg/kubelet/apis/cri/v1alpha1/runtime._ImageService_ListImages_Handler /builddir/build/BUILD/atomic-openshift-git-0.94b7dea/_output/local/go/src/github.com/openshift/origin/vendor/k8s.io/kubernetes/pkg/kubelet/apis/cri/v1alpha1/runtime/api.pb.go
9877 0.00015% 47.81% 942554108 14.16% github.com/openshift/origin/vendor/k8s.io/kubernetes/pkg/kubelet/dockershim.(*dockerService).ListImages /builddir/build/BUILD/atomic-openshift-git-0.94b7dea/_output/local/go/src/github.com/openshift/origin/vendor/k8s.io/kubernetes/pkg/kubelet/dockershim/docker_image.go
0 0% 47.81% 942554108 14.16% github.com/openshift/origin/vendor/k8s.io/kubernetes/pkg/kubelet/dockershim/remote.(*dockerService).ListImages /builddir/build/BUILD/atomic-openshift-git-0.94b7dea/_output/local/go/src/github.com/openshift/origin/vendor/k8s.io/kubernetes/pkg/kubelet/dockershim/remote/docker_service.go
This is tied to the OVS health checking - the function to verify the status is expensive. Since we're eventually going to need to do this anyway for other reasons, we should probably just fix ovs.Parse to not allocate extensively.