search

crc-org / crc

CRC is a tool to help you run containers. It manages a local OpenShift 4.x cluster, Microshift or a Podman VM optimized for testing and development purposes
https://crc.dev
Apache License 2.0
1.26k stars 239 forks source link

[BUG] Idle CRC install causes high CPU usage #707

Open chirino opened 5 years ago

chirino commented 5 years ago

General information

CRC version

chirino-mbp:~ chirino$ crc version
version: 1.0.0-rc.0+34371d3
OpenShift version: 4.2.0-0.nightly-2019-09-26-192831 (embedded in binary)
chirino-mbp:~ chirino$

CRC status

chirino-mbp:~ chirino$ crc status
CRC VM:          Running
OpenShift:       Running (v4.2.0-0.nightly-2019-09-26-192831)
Disk Usage:      13.15GB of 32.2GB (Inside the CRC VM)
Cache Usage:     11.71GB
Cache Directory: /Users/chirino/.crc/cache

CRC config

chirino-mbp:~ chirino$ crc config view
chirino-mbp:~ chirino$

Host Operating System

chirino-mbp:~ chirino$ sw_vers
ProductName:    Mac OS X
ProductVersion: 10.14.6
BuildVersion:   18G95
chirino-mbp:~ chirino$

Steps to reproduce

  1. Just install
  2. Look at the OS X Activity Monitor for CPU usage of hyperkit process

Expected

  1. A fresh idle CRC install should have very low CPU usage. Ideally under 10%. Right now it hovers between 130 and 160%
  2. Please compare to a minishift install.

Actual

Screen Shot 2019-10-11 at 10 41 24 AM

Logs

You can start crc with crc start --log-level debug to collect logs. Please consider posting this on http://gist.github.com/ and post the link in the issue.

gbraad commented 5 years ago

Please file this issue against OpenShift itself. Related to https://github.com/code-ready/crc/issues/607#issuecomment-532752174 These are part of on-going discussions with the OpenShift team, but external pressure/information/assessment is always helpful when having these.

gbraad commented 5 years ago

Please compare to a minishift install.

Minishift is running OpenShift 3.x. OpenShift 4.x operates under a different set of rules and design concepts; the cluster is self-maintaing in the sense that operators control the state of the cluster.

chirino commented 5 years ago

If the state of the cluster is not changing like in a freshly installed idle cluster, then there should be little CPU usage by the operators. Something seems to be spinning needlessly.

gbraad commented 5 years ago

Something seems to be spinning needlessly.

Operators are continously inspecting the state of the cluster. This, in the case of CRC, might not be needed as often, but at the moment there is no 'profile' to determine or adjust this. Please file an issue against OpenShift raising these concerns.

stale[bot] commented 4 years ago

This issue has been automatically marked as stale because it has not had recent activity. It will be closed if no further activity occurs. Thank you for your contributions.

gbraad commented 4 years ago

but at the moment there is no 'profile' to determine or adjust this

@cfergeau ^^ hopefully the type/profile designator of a cluster could help with this. This could be part of an enhancement.

tsmaeder commented 4 years ago

@praveenkumar thanks for reopening. I just noticed again that crc seems to be consuming 20-25% of my 8 cores even when it's not doing anything productive (for me). The fan is constantly spinning 🤷

tsmaeder commented 4 years ago

I would be happy to assist debugging this, but I haven't found a way (like minishift ssh && ps)

gbraad commented 4 years ago

Thanks @tsmaeder. You ned to login to the VM using the ~/.crc/machines/crc/crc_id_rsakey withcore@{crc ip}` as username and endpoint. Please check journal output and the containers/processes that run.

tsmaeder commented 4 years ago

Whoaaa...not so fast. When you say "login", you mean ssh to the crc VM?

tsmaeder commented 4 years ago

Also, there is no file named ~/.crc/machines/crc/crc_id_rsakey. Im on Windows 10. There is id_rsaand id_rsa.pub

gbraad commented 4 years ago

On Windows you can read ~ as meaning C:\Users\[username]\. After start, the original login key has been replaced with a machine specific key that has to life somewhere in this folder.

On Wed, Apr 22, 2020 at 7:33 PM Thomas Mäder notifications@github.com wrote:

Also, there is no file named ~/.crc/machines/crc/crc_id_rsakey. Im on Windows 10.

— You are receiving this because you commented. Reply to this email directly, view it on GitHub https://github.com/code-ready/crc/issues/707#issuecomment-617721679, or unsubscribe https://github.com/notifications/unsubscribe-auth/AAAAOZUIVK43QOIFG5I3LEDRN3IXVANCNFSM4I72XCRQ .

--

Gerard Braad | http://gbraad.nl [ Doing Open Source Matters ]

tsmaeder commented 4 years ago

Sorry, but even when I've started crc, there simply is no such file in ~.crc\machines\crc. I've tried

ssh -i \Users\thomas\.crc\machines\crc\id_rsa core@172.17.234.195

and that does not work because:

Permissions for '\\Users\\thomas\\.crc\\machines\\crc\\id_rsa' are too open.

gbraad commented 4 years ago

Permissions for '\Users\thomas\.crc\machines\crc\id_rsa' are too open.

Please, use a different SSH client or modify the permissions for the file:

On Thu, Apr 23, 2020 at 2:58 PM Thomas Mäder notifications@github.com wrote:

Sorry, but even when I've started crc, there simply is no such file in ~.crc\machines\crc. I've tried

ssh -i \Users\thomas.crc\machines\crc\id_rsa core@172.17.234.195

and that does not work because:

Permissions for '\Users\thomas\.crc\machines\crc\id_rsa' are too open.

— You are receiving this because you commented. Reply to this email directly, view it on GitHub https://github.com/code-ready/crc/issues/707#issuecomment-618217893, or unsubscribe https://github.com/notifications/unsubscribe-auth/AAAAOZUWYPNHHLOBRO6YJULRN7RK5ANCNFSM4I72XCRQ .

--

Gerard Braad | http://gbraad.nl [ Doing Open Source Matters ]

tsmaeder commented 4 years ago

So...output from top in the VM shows:

    PID USER      PR  NI    VIRT    RES    SHR S  %CPU  %MEM     TIME+ COMMAND
   5354 root      20   0 1967168   1.1g 103428 S  12.3   8.6   4:03.29 hyperkube
   4284 root      20   0 2744444 197624  92224 S  10.0   1.4   2:23.44 hyperkube
   5774 root      20   0 8582536 160588  82960 S   4.7   1.1   1:10.20 etcd
  15897 root      20   0  754204  78204  38276 S   3.3   0.6   0:12.90 cluster-kube-co
   5738 root      20   0  978548 244504  94208 S   2.7   1.7   0:40.19 hyperkube
  14538 root      20   0  603460 107904  35216 S   1.7   0.8   0:02.67 service-ca-oper
  14187 1000400+  20   0  138364  84448  22540 S   1.3   0.6   0:11.80 marketplace-ope
   5954 root      20   0  125572  21632  13076 S   1.0   0.2   0:15.37 etcd
      1 root      20   0  248432  17348   8988 S   0.7   0.1   0:31.80 systemd
tsmaeder commented 4 years ago

And running journalctl -f prints out sth. like this:

-- Logs begin at Tue 2020-04-28 08:53:11 UTC. --
May 05 08:09:05 crc-w6th5-master-0 hyperkube[4284]: I0505 08:09:05.789030    4284 prober.go:129] Liveness probe for "console-8c7b46fb4-68x4w_openshift-console(678c3951-c414-4abf-a88f-62d7c518ee7a):console" succeeded
May 05 08:09:06 crc-w6th5-master-0 hyperkube[4284]: I0505 08:09:06.195683    4284 prober.go:129] Liveness probe for "oauth-openshift-57bf8db445-4ftl9_openshift-authentication(5c8b3e00-fc78-4a7e-aaca-41010efcb2ef):oauth-openshift" succeeded
May 05 08:09:06 crc-w6th5-master-0 hyperkube[4284]: I0505 08:09:06.372860    4284 prober.go:129] Liveness probe for "kube-apiserver-crc-w6th5-master-0_openshift-kube-apiserver(18099743a76a23dd198872d9e8cef07d):kube-apiserver-16" succeeded
May 05 08:09:06 crc-w6th5-master-0 hyperkube[4284]: I0505 08:09:06.421005    4284 prober.go:129] Readiness probe for "keycloak-76f4958776-xdb5s_che(8a3e7534-f7fc-4043-be47-c2ca5a1a237f):keycloak" succeeded
May 05 08:09:06 crc-w6th5-master-0 hyperkube[4284]: I0505 08:09:06.804467    4284 prober.go:129] Liveness probe for "olm-operator-6d454db9dd-4sz4q_openshift-operator-lifecycle-manager(20d09aa4-99c0-42c2-bb39-382c89a3f02e):olm-operator" succeeded
May 05 08:09:06 crc-w6th5-master-0 hyperkube[4284]: I0505 08:09:06.893091    4284 prober.go:129] Liveness probe for "community-operators-6978b58679-vkpbl_openshift-marketplace(a0f5b1ed-ca28-4e6e-9424-4c17b8cc87e7):community-operators" succeeded
May 05 08:09:06 crc-w6th5-master-0 hyperkube[4284]: I0505 08:09:06.966659    4284 prober.go:129] Liveness probe for "catalog-operator-5d644f7b4b-zfhb6_openshift-operator-lifecycle-manager(065e9209-cdf0-4980-9720-6d64ae77eef4):catalog-operator" succeeded
May 05 08:09:07 crc-w6th5-master-0 hyperkube[4284]: I0505 08:09:07.043166    4284 prober.go:129] Readiness probe for "postgres-59f7548b97-cpqsx_che(cb225208-3e6a-4264-8b55-ccc5c1dafa0a):postgres" succeeded
May 05 08:09:07 crc-w6th5-master-0 hyperkube[4284]: I0505 08:09:07.061209    4284 prober.go:129] Readiness probe for "che-644799f96d-pzt6n_che(010ed5f2-369d-4d27-ad85-350331936339):che" succeeded
May 05 08:09:07 crc-w6th5-master-0 hyperkube[4284]: I0505 08:09:07.233632    4284 prober.go:129] Liveness probe for "apiserver-j2ptx_openshift-apiserver(757ca6f1-8aad-4e74-b286-ef97fea62bb2):openshift-apiserver" succeeded
May 05 08:09:07 crc-w6th5-master-0 hyperkube[4284]: I0505 08:09:07.516541    4284 prober.go:129] Readiness probe for "packageserver-7f65fb758f-rvfpj_openshift-operator-lifecycle-manager(aa1e18d8-fa29-4a6a-a1d9-debf5f11c4b8):packageserver" succeeded
May 05 08:09:07 crc-w6th5-master-0 hyperkube[4284]: I0505 08:09:07.519357    4284 prober.go:129] Readiness probe for "redhat-operators-df8c4b6dd-9c9kr_openshift-marketplace(522421e3-f623-40bf-9cfd-dcb5d5b5e55a):redhat-operators" succeeded
May 05 08:09:07 crc-w6th5-master-0 hyperkube[4284]: I0505 08:09:07.577080    4284 prober.go:129] Readiness probe for "ovs-m586r_openshift-sdn(e84328eb-0176-423f-a663-b7637779688c):openvswitch" succeeded
May 05 08:09:08 crc-w6th5-master-0 hyperkube[4284]: I0505 08:09:08.035735    4284 prober.go:129] Readiness probe for "apiserver-j2ptx_openshift-apiserver(757ca6f1-8aad-4e74-b286-ef97fea62bb2):openshift-apiserver" succeeded
May 05 08:09:08 crc-w6th5-master-0 hyperkube[4284]: I0505 08:09:08.065487    4284 prober.go:129] Readiness probe for "marketplace-operator-7fbcb88798-wxcdc_openshift-marketplace(d0914397-0048-47b9-a8e3-f79eacf5ef59):marketplace-operator" succeeded
May 05 08:09:08 crc-w6th5-master-0 hyperkube[4284]: I0505 08:09:08.364497    4284 prober.go:129] Readiness probe for "image-registry-864894cbd5-8n5ff_openshift-image-registry(9ee1722d-1f91-404f-84e0-1e09a49f3c9a):registry" succeeded
May 05 08:09:08 crc-w6th5-master-0 hyperkube[4284]: I0505 08:09:08.590832    4284 kubelet_pods.go:1328] Generating status for "cluster-image-registry-operator-f9697f69d-44484_openshift-image-registry(9d88f3c1-3070-48dd-9682-079f13c912d3)"
May 05 08:09:08 crc-w6th5-master-0 hyperkube[4284]: I0505 08:09:08.591638    4284 status_manager.go:426] Ignoring same status for pod "cluster-image-registry-operator-f9697f69d-44484_openshift-image-registry(9d88f3c1-3070-48dd-9682-079f13c912d3)", status: {Phase:Running Conditions:[{Type:Initialized Status:True LastProbeTime:0001-01-01 00:00:00 +0000 UTC LastTransitionTime:2020-02-14 06:47:20 +0000 UTC Reason: Message:} {Type:Ready Status:True LastProbeTime:0001-01-01 00:00:00 +0000 UTC LastTransitionTime:2020-05-05 07:45:33 +0000 UTC Reason: Message:} {Type:ContainersReady Status:True LastProbeTime:0001-01-01 00:00:00 +0000 UTC LastTransitionTime:2020-05-05 07:45:33 +0000 UTC Reason: Message:} {Type:PodScheduled Status:True LastProbeTime:0001-01-01 00:00:00 +0000 UTC LastTransitionTime:2020-02-14 06:47:19 +0000 UTC Reason: Message:}] Message: Reason: NominatedNodeName: HostIP:172.18.0.115 PodIP:10.128.0.8 PodIPs:[{IP:10.128.0.8}] StartTime:2020-02-14 06:47:20 +0000 UTC InitContainerStatuses:[] ContainerStatuses:[{Name:cluster-image-registry-operator State:{Waiting:nil Running:&ContainerStateRunning{StartedAt:2020-05-05 07:45:29 +0000 UTC,} Terminated:nil} LastTerminationState:{Waiting:nil Running:nil Terminated:&ContainerStateTerminated{ExitCode:255,Signal:0,Reason:Error,Message:,StartedAt:2020-05-05 07:24:29 +0000 UTC,FinishedAt:2020-05-05 07:44:31 +0000 UTC,ContainerID:cri-o://ec9a8c73f953f10e8268c061fe72428963d86a7f42e9ed8ec6f459fe29fc8945,}} Ready:true RestartCount:33 Image:quay.io/openshift-release-dev/ocp-v4.0-art-dev@sha256:ffa87c992c5a2c51290e6d67cb609f29893dd147c31cff639ff6785ae7a1cfe2 ImageID:quay.io/openshift-release-dev/ocp-v4.0-art-dev@sha256:ffa87c992c5a2c51290e6d67cb609f29893dd147c31cff639ff6785ae7a1cfe2 ContainerID:cri-o://a53f9886272560abc72de35e7c032b338e8133d60c0a43034d1093a3c80a3b6f Started:0xc004a020fa} {Name:cluster-image-registry-operator-watch State:{Waiting:nil Running:&ContainerStateRunning{StartedAt:2020-05-05 07:45:31 +0000 UTC,} Terminated:nil} LastTerminationState:{Waiting:nil Running:nil Terminated:&ContainerStateTerminated{ExitCode:255,Signal:0,Reason:Error,Message:,StartedAt:2020-05-05 07:24:33 +0000 UTC,FinishedAt:2020-05-05 07:44:29 +0000 UTC,ContainerID:cri-o://2c082b45e6bff88273bf6261fad13b79c9623be146109e2de29efd0f36fd37f4,}} Ready:true RestartCount:33 Image:quay.io/openshift-release-dev/ocp-v4.0-art-dev@sha256:ffa87c992c5a2c51290e6d67cb609f29893dd147c31cff639ff6785ae7a1cfe2 ImageID:quay.io/openshift-release-dev/ocp-v4.0-art-dev@sha256:ffa87c992c5a2c51290e6d67cb609f29893dd147c31cff639ff6785ae7a1cfe2 ContainerID:cri-o://081ed45f80bd91f17282f451372b6465e4ac83e23292e63b5fa4c81259342e6c Started:0xc004a020fb}] QOSClass:Burstable EphemeralContainerStatuses:[]}
May 05 08:09:08 crc-w6th5-master-0 hyperkube[4284]: I0505 08:09:08.592461    4284 volume_manager.go:356] Waiting for volumes to attach and mount for pod "cluster-image-registry-operator-f9697f69d-44484_openshift-image-registry(9d88f3c1-3070-48dd-9682-079f13c912d3)"
May 05 08:09:08 crc-w6th5-master-0 hyperkube[4284]: I0505 08:09:08.592743    4284 volume_manager.go:387] All volumes are attached and mounted for pod "cluster-image-registry-operator-f9697f69d-44484_openshift-image-registry(9d88f3c1-3070-48dd-9682-079f13c912d3)"
May 05 08:09:08 crc-w6th5-master-0 hyperkube[4284]: I0505 08:09:08.594115    4284 kuberuntime_manager.go:634] computePodActions got {KillPod:false CreateSandbox:false SandboxID:7e7abc0cddaaae1458dc169c1278a1568828be71e2a0ca7642401de1799971ff Attempt:33 NextInitContainerToStart:nil ContainersToStart:[] ContainersToKill:map[] EphemeralContainersToStart:[]} for pod "cluster-image-registry-operator-f9697f69d-44484_openshift-image-registry(9d88f3c1-3070-48dd-9682-079f13c912d3)"
May 05 08:09:08 crc-w6th5-master-0 hyperkube[4284]: I0505 08:09:08.737778    4284 configmap.go:191] Setting up volume trusted-ca for pod 9d88f3c1-3070-48dd-9682-079f13c912d3 at /var/lib/kubelet/pods/9d88f3c1-3070-48dd-9682-079f13c912d3/volumes/kubernetes.io~configmap/trusted-ca
May 05 08:09:08 crc-w6th5-master-0 hyperkube[4284]: I0505 08:09:08.737892    4284 configmap.go:215] Received configMap openshift-image-registry/trusted-ca containing (1) pieces of data, 222148 total bytes
May 05 08:09:08 crc-w6th5-master-0 hyperkube[4284]: I0505 08:09:08.737993    4284 secret.go:186] Setting up volume image-registry-operator-tls for pod 9d88f3c1-3070-48dd-9682-079f13c912d3 at /var/lib/kubelet/pods/9d88f3c1-3070-48dd-9682-079f13c912d3/volumes/kubernetes.io~secret/image-registry-operator-tls
May 05 08:09:08 crc-w6th5-master-0 hyperkube[4284]: I0505 08:09:08.738107    4284 secret.go:210] Received secret openshift-image-registry/image-registry-operator-tls containing (2) pieces of data, 4384 total bytes
May 05 08:09:08 crc-w6th5-master-0 hyperkube[4284]: I0505 08:09:08.737827    4284 secret.go:186] Setting up volume cluster-image-registry-operator-token-zll72 for pod 9d88f3c1-3070-48dd-9682-079f13c912d3 at /var/lib/kubelet/pods/9d88f3c1-3070-48dd-9682-079f13c912d3/volumes/kubernetes.io~secret/cluster-image-registry-operator-token-zll72
May 05 08:09:08 crc-w6th5-master-0 hyperkube[4284]: I0505 08:09:08.738737    4284 secret.go:210] Received secret openshift-image-registry/cluster-image-registry-operator-token-zll72 containing (4) pieces of data, 14130 total bytes
May 05 08:09:09 crc-w6th5-master-0 hyperkube[4284]: I0505 08:09:09.213752    4284 prober.go:129] Liveness probe for "certified-operators-87ffdbddc-4sl95_openshift-marketplace(862f8a85-c437-4ba6-a68d-1ae5b540f094):certified-operators" succeeded
May 05 08:09:09 crc-w6th5-master-0 hyperkube[4284]: I0505 08:09:09.219244    4284 prober.go:129] Readiness probe for "openshift-kube-scheduler-crc-w6th5-master-0_openshift-kube-scheduler(1eb4467a62fcbfd01b5adae23d59d853):scheduler" succeeded
May 05 08:09:09 crc-w6th5-master-0 hyperkube[4284]: I0505 08:09:09.288483    4284 prober.go:129] Liveness probe for "console-operator-57f5bcc578-b59hx_openshift-console-operator(53d85123-9461-4eb3-969d-c161cb8df4d5):console-operator" succeeded
May 05 08:09:09 crc-w6th5-master-0 hyperkube[4284]: I0505 08:09:09.375585    4284 prober.go:129] Readiness probe for "kube-controller-manager-crc-w6th5-master-0_openshift-kube-controller-manager(5eaf736088bfd8c6bd10b8e68a8ece05):kube-controller-manager-11" succeeded
May 05 08:09:09 crc-w6th5-master-0 hyperkube[4284]: I0505 08:09:09.502454    4284 prober.go:129] Readiness probe for "olm-operator-6d454db9dd-4sz4q_openshift-operator-lifecycle-manager(20d09aa4-99c0-42c2-bb39-382c89a3f02e):olm-operator" succeeded
May 05 08:09:09 crc-w6th5-master-0 hyperkube[4284]: I0505 08:09:09.611134    4284 prober.go:129] Readiness probe for "sdn-twbd8_openshift-sdn(5c7d4386-e5dd-4c3d-a3d5-100ef7d6951e):sdn" succeeded
May 05 08:09:09 crc-w6th5-master-0 hyperkube[4284]: I0505 08:09:09.688882    4284 prober.go:129] Liveness probe for "openshift-kube-scheduler-crc-w6th5-master-0_openshift-kube-scheduler(1eb4467a62fcbfd01b5adae23d59d853):scheduler" succeeded
May 05 08:09:09 crc-w6th5-master-0 hyperkube[4284]: I0505 08:09:09.693528    4284 prober.go:129] Readiness probe for "community-operators-6978b58679-vkpbl_openshift-marketplace(a0f5b1ed-ca28-4e6e-9424-4c17b8cc87e7):community-operators" succeeded
May 05 08:09:09 crc-w6th5-master-0 hyperkube[4284]: I0505 08:09:09.883631    4284 prober.go:129] Liveness probe for "redhat-operators-df8c4b6dd-9c9kr_openshift-marketplace(522421e3-f623-40bf-9cfd-dcb5d5b5e55a):redhat-operators" succeeded
May 05 08:09:10 crc-w6th5-master-0 hyperkube[4284]: I0505 08:09:10.041652    4284 prober.go:129] Liveness probe for "ovs-m586r_openshift-sdn(e84328eb-0176-423f-a663-b7637779688c):openvswitch" succeeded
May 05 08:09:10 crc-w6th5-master-0 hyperkube[4284]: I0505 08:09:10.095396    4284 prober.go:129] Readiness probe for "kube-controller-manager-crc-w6th5-master-0_openshift-kube-controller-manager(5eaf736088bfd8c6bd10b8e68a8ece05):cluster-policy-controller-11" succeeded
May 05 08:09:10 crc-w6th5-master-0 hyperkube[4284]: I0505 08:09:10.589742    4284 kubelet_pods.go:1328] Generating status for "postgres-59f7548b97-cpqsx_che(cb225208-3e6a-4264-8b55-ccc5c1dafa0a)"
May 05 08:09:10 crc-w6th5-master-0 hyperkube[4284]: I0505 08:09:10.589798    4284 kubelet_pods.go:1328] Generating status for "packageserver-7f65fb758f-rvfpj_openshift-operator-lifecycle-manager(aa1e18d8-fa29-4a6a-a1d9-debf5f11c4b8)"
May 05 08:09:10 crc-w6th5-master-0 hyperkube[4284]: I0505 08:09:10.589806    4284 kubelet_pods.go:1328] Generating status for "oauth-openshift-57bf8db445-4ftl9_openshift-authentication(5c8b3e00-fc78-4a7e-aaca-41010efcb2ef)"
May 05 08:09:10 crc-w6th5-master-0 hyperkube[4284]: I0505 08:09:10.590012    4284 status_manager.go:426] Ignoring same status for pod "postgres-59f7548b97-cpqsx_che(cb225208-3e6a-4264-8b55-ccc5c1dafa0a)", status: {Phase:Running Conditions:[{Type:Initialized Status:True LastProbeTime:0001-01-01 00:00:00 +0000 UTC LastTransitionTime:2020-04-21 13:55:11 +0000 UTC Reason: Message:} {Type:Ready Status:True LastProbeTime:0001-01-01 00:00:00 +0000 UTC LastTransitionTime:2020-05-05 07:45:47 +0000 UTC Reason: Message:} {Type:ContainersReady Status:True LastProbeTime:0001-01-01 00:00:00 +0000 UTC LastTransitionTime:2020-05-05 07:45:47 +0000 UTC Reason: Message:} {Type:PodScheduled Status:True LastProbeTime:0001-01-01 00:00:00 +0000 UTC LastTransitionTime:2020-04-21 13:55:11 +0000 UTC Reason: Message:}] Message: Reason: NominatedNodeName: HostIP:172.18.0.115 PodIP:10.128.0.15 PodIPs:[{IP:10.128.0.15}] StartTime:2020-04-21 13:55:11 +0000 UTC InitContainerStatuses:[] ContainerStatuses:[{Name:postgres State:{Waiting:nil Running:&ContainerStateRunning{StartedAt:2020-05-05 07:45:31 +0000 UTC,} Terminated:nil} LastTerminationState:{Waiting:nil Running:nil Terminated:&ContainerStateTerminated{ExitCode:255,Signal:0,Reason:Error,Message:,StartedAt:2020-05-05 07:24:33 +0000 UTC,FinishedAt:2020-05-05 07:44:31 +0000 UTC,ContainerID:cri-o://f8f46159a27a56e56826968077c781ad34e0365d6655c03ffd0de7785dd4ca30,}} Ready:true RestartCount:33 Image:docker.io/centos/postgresql-96-centos7:9.6 ImageID:docker.io/centos/postgresql-96-centos7@sha256:617c75aab798753ee5e0323d60069757b17a2255abd9de44ca342e4a8bb68b15 ContainerID:cri-o://44b01ff61a136f4e64cf430874279ac11c99eb7c3851aa926dad125d5e3ac41c Started:0xc002d5b360}] QOSClass:Burstable EphemeralContainerStatuses:[]}
May 05 08:09:10 crc-w6th5-master-0 hyperkube[4284]: I0505 08:09:10.590298    4284 status_manager.go:426] Ignoring same status for pod "packageserver-7f65fb758f-rvfpj_openshift-operator-lifecycle-manager(aa1e18d8-fa29-4a6a-a1d9-debf5f11c4b8)", status: {Phase:Running Conditions:[{Type:Initialized Status:True LastProbeTime:0001-01-01 00:00:00 +0000 UTC LastTransitionTime:2020-05-05 07:45:35 +0000 UTC Reason: Message:} {Type:Ready Status:True LastProbeTime:0001-01-01 00:00:00 +0000 UTC LastTransitionTime:2020-05-05 07:45:57 +0000 UTC Reason: Message:} {Type:ContainersReady Status:True LastProbeTime:0001-01-01 00:00:00 +0000 UTC LastTransitionTime:2020-05-05 07:45:57 +0000 UTC Reason: Message:} {Type:PodScheduled Status:True LastProbeTime:0001-01-01 00:00:00 +0000 UTC LastTransitionTime:2020-05-05 07:45:35 +0000 UTC Reason: Message:}] Message: Reason: NominatedNodeName: HostIP:172.18.0.115 PodIP:10.128.0.46 PodIPs:[{IP:10.128.0.46}] StartTime:2020-05-05 07:45:35 +0000 UTC InitContainerStatuses:[] ContainerStatuses:[{Name:packageserver State:{Waiting:nil Running:&ContainerStateRunning{StartedAt:2020-05-05 07:45:49 +0000 UTC,} Terminated:nil} LastTerminationState:{Waiting:nil Running:nil Terminated:nil} Ready:true RestartCount:0 Image:quay.io/openshift-release-dev/ocp-v4.0-art-dev@sha256:dbde7140eb5c05e05252e2bc2891f47761aecf465803d08831c6b20c84bebbb8 ImageID:quay.io/openshift-release-dev/ocp-v4.0-art-dev@sha256:dbde7140eb5c05e05252e2bc2891f47761aecf465803d08831c6b20c84bebbb8 ContainerID:cri-o://8b13063d6be76f23c184e4e49d1cb71252d5595e76102bddbf92eac00de55a73 Started:0xc001c5fcf0}] QOSClass:Burstable EphemeralContainerStatuses:[]}
May 05 08:09:10 crc-w6th5-master-0 hyperkube[4284]: I0505 08:09:10.590495    4284 volume_manager.go:356] Waiting for volumes to attach and mount for pod "postgres-59f7548b97-cpqsx_che(cb225208-3e6a-4264-8b55-ccc5c1dafa0a)"
May 05 08:09:10 crc-w6th5-master-0 hyperkube[4284]: I0505 08:09:10.590582    4284 volume_manager.go:387] All volumes are attached and mounted for pod "postgres-59f7548b97-cpqsx_che(cb225208-3e6a-4264-8b55-ccc5c1dafa0a)"
May 05 08:09:10 crc-w6th5-master-0 hyperkube[4284]: I0505 08:09:10.590809    4284 kuberuntime_manager.go:634] computePodActions got {KillPod:false CreateSandbox:false SandboxID:3f9d6d441864c051290dbe96537e92fd10a591d24d95d1cce87d570f33a548d8 Attempt:33 NextInitContainerToStart:nil ContainersToStart:[] ContainersToKill:map[] EphemeralContainersToStart:[]} for pod "postgres-59f7548b97-cpqsx_che(cb225208-3e6a-4264-8b55-ccc5c1dafa0a)"
May 05 08:09:10 crc-w6th5-master-0 hyperkube[4284]: I0505 08:09:10.590754    4284 status_manager.go:426] Ignoring same status for pod "oauth-openshift-57bf8db445-4ftl9_openshift-authentication(5c8b3e00-fc78-4a7e-aaca-41010efcb2ef)", status: {Phase:Running Conditions:[{Type:Initialized Status:True LastProbeTime:0001-01-01 00:00:00 +0000 UTC LastTransitionTime:2020-05-05 07:47:14 +0000 UTC Reason: Message:} {Type:Ready Status:True LastProbeTime:0001-01-01 00:00:00 +0000 UTC LastTransitionTime:2020-05-05 07:47:34 +0000 UTC Reason: Message:} {Type:ContainersReady Status:True LastProbeTime:0001-01-01 00:00:00 +0000 UTC LastTransitionTime:2020-05-05 07:47:34 +0000 UTC Reason: Message:} {Type:PodScheduled Status:True LastProbeTime:0001-01-01 00:00:00 +0000 UTC LastTransitionTime:2020-05-05 07:47:14 +0000 UTC Reason: Message:}] Message: Reason: NominatedNodeName: HostIP:172.18.0.115 PodIP:10.128.0.53 PodIPs:[{IP:10.128.0.53}] StartTime:2020-05-05 07:47:14 +0000 UTC InitContainerStatuses:[] ContainerStatuses:[{Name:oauth-openshift State:{Waiting:nil Running:&ContainerStateRunning{StartedAt:2020-05-05 07:47:24 +0000 UTC,} Terminated:nil} LastTerminationState:{Waiting:nil Running:nil Terminated:nil} Ready:true RestartCount:0 Image:quay.io/openshift-release-dev/ocp-v4.0-art-dev@sha256:2ddf01b3566076b30aab707d27a288224c4a29434fea133cab9e5cedfc87dc35 ImageID:quay.io/openshift-release-dev/ocp-v4.0-art-dev@sha256:2ddf01b3566076b30aab707d27a288224c4a29434fea133cab9e5cedfc87dc35 ContainerID:cri-o://e88d4e80c15fe2b6ccc320745bf801dc04b4e7502c14c16893a6d74d3ba3ccef Started:0xc00358a68d}] QOSClass:Burstable EphemeralContainerStatuses:[]}
May 05 08:09:10 crc-w6th5-master-0 hyperkube[4284]: I0505 08:09:10.591110    4284 volume_manager.go:356] Waiting for volumes to attach and mount for pod "packageserver-7f65fb758f-rvfpj_openshift-operator-lifecycle-manager(aa1e18d8-fa29-4a6a-a1d9-debf5f11c4b8)"
May 05 08:09:10 crc-w6th5-master-0 hyperkube[4284]: I0505 08:09:10.591123    4284 volume_manager.go:356] Waiting for volumes to attach and mount for pod "oauth-openshift-57bf8db445-4ftl9_openshift-authentication(5c8b3e00-fc78-4a7e-aaca-41010efcb2ef)"
May 05 08:09:10 crc-w6th5-master-0 hyperkube[4284]: I0505 08:09:10.591160    4284 volume_manager.go:387] All volumes are attached and mounted for pod "packageserver-7f65fb758f-rvfpj_openshift-operator-lifecycle-manager(aa1e18d8-fa29-4a6a-a1d9-debf5f11c4b8)"
May 05 08:09:10 crc-w6th5-master-0 hyperkube[4284]: I0505 08:09:10.591179    4284 volume_manager.go:387] All volumes are attached and mounted for pod "oauth-openshift-57bf8db445-4ftl9_openshift-authentication(5c8b3e00-fc78-4a7e-aaca-41010efcb2ef)"
May 05 08:09:10 crc-w6th5-master-0 hyperkube[4284]: I0505 08:09:10.591312    4284 kuberuntime_manager.go:634] computePodActions got {KillPod:false CreateSandbox:false SandboxID:16f89dcbbe2495bddffd9eab379042c041cc7c59f44806abf5861f25b808720c Attempt:0 NextInitContainerToStart:nil ContainersToStart:[] ContainersToKill:map[] EphemeralContainersToStart:[]} for pod "packageserver-7f65fb758f-rvfpj_openshift-operator-lifecycle-manager(aa1e18d8-fa29-4a6a-a1d9-debf5f11c4b8)"
May 05 08:09:10 crc-w6th5-master-0 hyperkube[4284]: I0505 08:09:10.591501    4284 kuberuntime_manager.go:634] computePodActions got {KillPod:false CreateSandbox:false SandboxID:1e8519dfbddad1cc67ab6901d8e578b0ce7bc5a657dc302649fc763ab6c441a7 Attempt:0 NextInitContainerToStart:nil ContainersToStart:[] ContainersToKill:map[] EphemeralContainersToStart:[]} for pod "oauth-openshift-57bf8db445-4ftl9_openshift-authentication(5c8b3e00-fc78-4a7e-aaca-41010efcb2ef)"
May 05 08:09:10 crc-w6th5-master-0 hyperkube[4284]: I0505 08:09:10.651340    4284 secret.go:186] Setting up volume v4-0-config-system-router-certs for pod 5c8b3e00-fc78-4a7e-aaca-41010efcb2ef at /var/lib/kubelet/pods/5c8b3e00-fc78-4a7e-aaca-41010efcb2ef/volumes/kubernetes.io~secret/v4-0-config-system-router-certs
May 05 08:09:10 crc-w6th5-master-0 hyperkube[4284]: I0505 08:09:10.651406    4284 secret.go:186] Setting up volume v4-0-config-system-ocp-branding-template for pod 5c8b3e00-fc78-4a7e-aaca-41010efcb2ef at /var/lib/kubelet/pods/5c8b3e00-fc78-4a7e-aaca-41010efcb2ef/volumes/kubernetes.io~secret/v4-0-config-system-ocp-branding-template
May 05 08:09:10 crc-w6th5-master-0 hyperkube[4284]: I0505 08:09:10.651433    4284 secret.go:210] Received secret openshift-authentication/v4-0-config-system-ocp-branding-template containing (3) pieces of data, 478384 total bytes
May 05 08:09:10 crc-w6th5-master-0 hyperkube[4284]: I0505 08:09:10.651487    4284 configmap.go:191] Setting up volume v4-0-config-system-service-ca for pod 5c8b3e00-fc78-4a7e-aaca-41010efcb2ef at /var/lib/kubelet/pods/5c8b3e00-fc78-4a7e-aaca-41010efcb2ef/volumes/kubernetes.io~configmap/v4-0-config-system-service-ca
May 05 08:09:10 crc-w6th5-master-0 hyperkube[4284]: I0505 08:09:10.651505    4284 configmap.go:215] Received configMap openshift-authentication/v4-0-config-system-service-ca containing (1) pieces of data, 1200 total bytes
May 05 08:09:10 crc-w6th5-master-0 hyperkube[4284]: I0505 08:09:10.651750    4284 secret.go:210] Received secret openshift-authentication/v4-0-config-system-router-certs containing (1) pieces of data, 3884 total bytes
May 05 08:09:10 crc-w6th5-master-0 hyperkube[4284]: I0505 08:09:10.651821    4284 configmap.go:191] Setting up volume v4-0-config-system-trusted-ca-bundle for pod 5c8b3e00-fc78-4a7e-aaca-41010efcb2ef at /var/lib/kubelet/pods/5c8b3e00-fc78-4a7e-aaca-41010efcb2ef/volumes/kubernetes.io~configmap/v4-0-config-system-trusted-ca-bundle
May 05 08:09:10 crc-w6th5-master-0 hyperkube[4284]: I0505 08:09:10.651838    4284 configmap.go:215] Received configMap openshift-authentication/v4-0-config-system-trusted-ca-bundle containing (1) pieces of data, 222148 total bytes
May 05 08:09:10 crc-w6th5-master-0 hyperkube[4284]: I0505 08:09:10.651871    4284 secret.go:186] Setting up volume oauth-openshift-token-h75ws for pod 5c8b3e00-fc78-4a7e-aaca-41010efcb2ef at /var/lib/kubelet/pods/5c8b3e00-fc78-4a7e-aaca-41010efcb2ef/volumes/kubernetes.io~secret/oauth-openshift-token-h75ws
May 05 08:09:10 crc-w6th5-master-0 hyperkube[4284]: I0505 08:09:10.651891    4284 secret.go:210] Received secret openshift-authentication/oauth-openshift-token-h75ws containing (4) pieces of data, 14066 total bytes
May 05 08:09:10 crc-w6th5-master-0 hyperkube[4284]: I0505 08:09:10.651938    4284 secret.go:186] Setting up volume v4-0-config-system-session for pod 5c8b3e00-fc78-4a7e-aaca-41010efcb2ef at /var/lib/kubelet/pods/5c8b3e00-fc78-4a7e-aaca-41010efcb2ef/volumes/kubernetes.io~secret/v4-0-config-system-session
May 05 08:09:10 crc-w6th5-master-0 hyperkube[4284]: I0505 08:09:10.651957    4284 secret.go:210] Received secret openshift-authentication/v4-0-config-system-session containing (1) pieces of data, 189 total bytes
May 05 08:09:10 crc-w6th5-master-0 hyperkube[4284]: I0505 08:09:10.652123    4284 secret.go:186] Setting up volume default-token-rqznw for pod cb225208-3e6a-4264-8b55-ccc5c1dafa0a at /var/lib/kubelet/pods/cb225208-3e6a-4264-8b55-ccc5c1dafa0a/volumes/kubernetes.io~secret/default-token-rqznw
May 05 08:09:10 crc-w6th5-master-0 hyperkube[4284]: I0505 08:09:10.652142    4284 secret.go:210] Received secret che/default-token-rqznw containing (4) pieces of data, 13957 total bytes
May 05 08:09:10 crc-w6th5-master-0 hyperkube[4284]: I0505 08:09:10.652165    4284 secret.go:186] Setting up volume v4-0-config-system-serving-cert for pod 5c8b3e00-fc78-4a7e-aaca-41010efcb2ef at /var/lib/kubelet/pods/5c8b3e00-fc78-4a7e-aaca-41010efcb2ef/volumes/kubernetes.io~secret/v4-0-config-system-serving-cert
May 05 08:09:10 crc-w6th5-master-0 hyperkube[4284]: I0505 08:09:10.652206    4284 secret.go:186] Setting up volume olm-operator-serviceaccount-token-4t6ff for pod aa1e18d8-fa29-4a6a-a1d9-debf5f11c4b8 at /var/lib/kubelet/pods/aa1e18d8-fa29-4a6a-a1d9-debf5f11c4b8/volumes/kubernetes.io~secret/olm-operator-serviceaccount-token-4t6ff
May 05 08:09:10 crc-w6th5-master-0 hyperkube[4284]: I0505 08:09:10.652220    4284 secret.go:210] Received secret openshift-authentication/v4-0-config-system-serving-cert containing (2) pieces of data, 4355 total bytes
May 05 08:09:10 crc-w6th5-master-0 hyperkube[4284]: I0505 08:09:10.652243    4284 secret.go:186] Setting up volume apiservice-cert for pod aa1e18d8-fa29-4a6a-a1d9-debf5f11c4b8 at /var/lib/kubelet/pods/aa1e18d8-fa29-4a6a-a1d9-debf5f11c4b8/volumes/kubernetes.io~secret/apiservice-cert
May 05 08:09:10 crc-w6th5-master-0 hyperkube[4284]: I0505 08:09:10.652259    4284 secret.go:210] Received secret openshift-operator-lifecycle-manager/v1.packages.operators.coreos.com-cert containing (2) pieces of data, 992 total bytes
May 05 08:09:10 crc-w6th5-master-0 hyperkube[4284]: I0505 08:09:10.652221    4284 secret.go:210] Received secret openshift-operator-lifecycle-manager/olm-operator-serviceaccount-token-4t6ff containing (4) pieces of data, 14158 total bytes
May 05 08:09:10 crc-w6th5-master-0 hyperkube[4284]: I0505 08:09:10.652204    4284 configmap.go:191] Setting up volume v4-0-config-system-cliconfig for pod 5c8b3e00-fc78-4a7e-aaca-41010efcb2ef at /var/lib/kubelet/pods/5c8b3e00-fc78-4a7e-aaca-41010efcb2ef/volumes/kubernetes.io~configmap/v4-0-config-system-cliconfig
May 05 08:09:10 crc-w6th5-master-0 hyperkube[4284]: I0505 08:09:10.652440    4284 configmap.go:215] Received configMap openshift-authentication/v4-0-config-system-cliconfig containing (1) pieces of data, 2621 total bytes
May 05 08:09:10 crc-w6th5-master-0 hyperkube[4284]: I0505 08:09:10.652583    4284 secret.go:186] Setting up volume v4-0-config-user-idp-0-file-data for pod 5c8b3e00-fc78-4a7e-aaca-41010efcb2ef at /var/lib/kubelet/pods/5c8b3e00-fc78-4a7e-aaca-41010efcb2ef/volumes/kubernetes.io~secret/v4-0-config-user-idp-0-file-data
May 05 08:09:10 crc-w6th5-master-0 hyperkube[4284]: I0505 08:09:10.652612    4284 secret.go:210] Received secret openshift-authentication/v4-0-config-user-idp-0-file-data containing (1) pieces of data, 70 total bytes
May 05 08:09:10 crc-w6th5-master-0 hyperkube[4284]: I0505 08:09:10.706472    4284 prober.go:129] Readiness probe for "router-default-77c77568f4-npdrs_openshift-ingress(f7f99054-223d-4217-a78f-0ba962aeb203):router" succeeded
May 05 08:09:10 crc-w6th5-master-0 hyperkube[4284]: I0505 08:09:10.834955    4284 eviction_manager.go:229] eviction manager: synchronize housekeeping
May 05 08:09:10 crc-w6th5-master-0 hyperkube[4284]: I0505 08:09:10.931267    4284 helpers.go:781] eviction manager: observations: signal=nodefs.inodesFree, available: 11133225, capacity: 12089416, time: 2020-05-05 08:09:10.836389447 +0000 UTC m=+1479.372311709
May 05 08:09:10 crc-w6th5-master-0 hyperkube[4284]: I0505 08:09:10.931305    4284 helpers.go:781] eviction manager: observations: signal=imagefs.available, available: 5540868Ki, capacity: 31952576Ki, time: 2020-05-05 08:09:10.836389447 +0000 UTC m=+1479.372311709
May 05 08:09:10 crc-w6th5-master-0 hyperkube[4284]: I0505 08:09:10.931316    4284 helpers.go:781] eviction manager: observations: signal=imagefs.inodesFree, available: 11133225, capacity: 12089416, time: 2020-05-05 08:09:10.836389447 +0000 UTC m=+1479.372311709
May 05 08:09:10 crc-w6th5-master-0 hyperkube[4284]: I0505 08:09:10.931323    4284 helpers.go:781] eviction manager: observations: signal=pid.available, available: 4192165, capacity: 4Mi, time: 2020-05-05 08:09:10.930091433 +0000 UTC m=+1479.466013695
May 05 08:09:10 crc-w6th5-master-0 hyperkube[4284]: I0505 08:09:10.931329    4284 helpers.go:781] eviction manager: observations: signal=memory.available, available: 9684940Ki, capacity: 14017024Ki, time: 2020-05-05 08:09:10.836389447 +0000 UTC m=+1479.372311709
May 05 08:09:10 crc-w6th5-master-0 hyperkube[4284]: I0505 08:09:10.931334    4284 helpers.go:781] eviction manager: observations: signal=allocatableMemory.available, available: 9649876Ki, capacity: 14017024Ki, time: 2020-05-05 08:09:10.931189835 +0000 UTC m=+1479.467112097
May 05 08:09:10 crc-w6th5-master-0 hyperkube[4284]: I0505 08:09:10.931340    4284 helpers.go:781] eviction manager: observations: signal=nodefs.available, available: 5540868Ki, capacity: 31952576Ki, time: 2020-05-05 08:09:10.836389447 +0000 UTC m=+1479.372311709
May 05 08:09:10 crc-w6th5-master-0 hyperkube[4284]: I0505 08:09:10.931468    4284 eviction_manager.go:320] eviction manager: no resources are starved
May 05 08:09:10 crc-w6th5-master-0 hyperkube[4284]: I0505 08:09:10.954880    4284 prober.go:129] Readiness probe for "certified-operators-87ffdbddc-4sl95_openshift-marketplace(862f8a85-c437-4ba6-a68d-1ae5b540f094):certified-operators" succeeded
May 05 08:09:11 crc-w6th5-master-0 hyperkube[4284]: I0505 08:09:11.257157    4284 prober.go:129] Readiness probe for "console-operator-57f5bcc578-b59hx_openshift-console-operator(53d85123-9461-4eb3-969d-c161cb8df4d5):console-operator" succeeded
May 05 08:09:11 crc-w6th5-master-0 hyperkube[4284]: I0505 08:09:11.355774    4284 prober.go:129] Liveness probe for "packageserver-7f65fb758f-rvfpj_openshift-operator-lifecycle-manager(aa1e18d8-fa29-4a6a-a1d9-debf5f11c4b8):packageserver" succeeded
May 05 08:09:11 crc-w6th5-master-0 hyperkube[4284]: I0505 08:09:11.406482    4284 prober.go:129] Liveness probe for "kube-controller-manager-crc-w6th5-master-0_openshift-kube-controller-manager(5eaf736088bfd8c6bd10b8e68a8ece05):kube-controller-manager-11" succeeded
May 05 08:09:11 crc-w6th5-master-0 hyperkube[4284]: I0505 08:09:11.589651    4284 kubelet_pods.go:1328] Generating status for "router-default-77c77568f4-npdrs_openshift-ingress(f7f99054-223d-4217-a78f-0ba962aeb203)"
tsmaeder commented 4 years ago

@gbraad anything else I can provide to move this one forward?

gbraad commented 4 years ago

We are in the process to collect deltas on our end

carlmes commented 4 years ago

Just reporting that I have a similar problem on latest MacOS version of CRC, where hyperkit is constantly using CPU on a brand new instance, that has been idle for at least an hour:

image 
▶ crc status
CRC VM:          Running
OpenShift:       Running (v4.4.3)
Disk Usage:      15.88GB of 32.72GB (Inside the CRC VM)
Cache Usage:     12.05GB

Logging into the VM: ssh -i ~/.crc/machines/crc/id_rsa core@apps-crc.testing

Top processes:

   PID USER      PR  NI    VIRT    RES    SHR S  %CPU  %MEM     TIME+ COMMAND                                                                                                                                                           
  31328 root      20   0 3798784   1.3g  75944 S  11.6   2.7  11:16.65 kube-apiserver                                                                                                                                                    
   2457 root      20   0 7610232 295512  61360 S  11.3   0.6  10:54.46 kubelet                                                                                                                                                           
   3313 root      20   0 8652228 258208  95804 S   7.9   0.5   5:19.08 etcd                                                                                                                                                              
 112616 nobody    20   0  118200  29072   9948 S   7.9   0.1   0:37.29 node_exporter                                                                                                                                                     
 118053 1000370+  20   0  716188 617032  38828 S   4.6   1.2   1:23.07 prometheus                                                                                                                                                        
 118084 1000370+  20   0  715932 617916  38060 S   4.6   1.2   1:27.02 prometheus                                                                                                                                                        
 346578 core      20   0   97908  13636   8144 S   3.0   0.0   0:04.19 systemd                                                                                                                                                           
      1 root      20   0  255260  23972   9060 S   2.6   0.0   2:33.07 systemd                                                                                                                                                           
  11030 root      20   0 1405172 137056  38064 S   2.0   0.3   1:32.55 cluster-etcd-op
carlmes commented 4 years ago

Looks like it might be a hyperkit issue - see this very long thread on the subject: https://github.com/docker/for-mac/issues/3499

dcanadillas commented 3 years ago

I am having the same issue on a MBP 16" i9 (8 cores). My Hyperkit CPU gets around 300% if doing something and 160% when idle. It doesn't seem to me to be only on Hyperkit side, in the case of my Minikube uses a lot less CPU using Hyperkit. CRC is completely useless for me because my machine gets too slow. 

❯ crc version
CodeReady Containers version: 1.28.0+08de64bd
OpenShift version: 4.7.13 (not embedded in executable)

❯ crc status
CRC VM:          Running
OpenShift:       Running (v4.7.13)
Disk Usage:      13.02GB of 32.74GB (Inside the CRC VM)
Cache Usage:     11.21GB
Cache Directory: /Users/dcanadillas/.crc/cache
PID   COMMAND      %CPU  TIME     #TH    #WQ  #PORT MEM    PURG   CMPRS  PGRP PPID STATE
5992  hyperkit     236.8 21:33.42 13/4   0    25    13G+   0B     2566M- 5988 1    running
147   WindowServer 20.3  18:25.28 16     5    3827+ 320M+  68K+   94M-   147  1    sleeping
1770  Activity Mon 6.4   04:09.80 6      4/1  1230+ 102M-  2388K+ 70M-   1770 1    sleeping
5776  iTerm2       5.0   00:15.93 11     8    321   95M+   2696K+ 31M-   5776 1    sleeping
6389  top          4.6   00:04.18 1/1    0    29    4640K  0B     704K-  6389 5779 running
1058  com.docker.h 3.1   06:06.32 17     0    41    4474M  0B     362M-  891  1044 sleeping
758   Google Chrom 2.8   07:40.40 39     1    1415+ 373M+  0B     275M-  758  1    sleeping
0     kernel_task  2.7   07:43.97 331/16 0    0     45M    0B     0B     0    0    running
867   crc          1.1   00:19.91 23     0    58    29M+   0B     6180K- 867  729  sleeping
...
kai-mersmann-ecc commented 3 years ago

We have the same issue on all devices we use with CRC and Ubuntu 20.04. Idle CRC consumes permanently almost all CPU capacity. Increasing # of assigned cpu cores leads to the additional cores being almost fully utilized as well. Is there any way to alter this behaviour?

cfergeau commented 3 years ago

On my RHEL test machine, I see one CPU core being used 100%, and the others ~20%. I suspect most of this is coming from kubernetes/OpenShift design though, so I'm not sure how much this can be improved :-/

fs30000 commented 2 years ago

Here is the same. Installed crc on a RHEL VM and the fan simply does not stop. No matter what what OS i use, same result. Right now on a iddle system the load inside the CRC VM is: load average: 29.97, 25.60, 25.45. On the host, RHEL8: load average: 4.05, 4.09, 4.20.

Even if the operators are doing something, is it a case for this kind of load?!

The big CPU suckers seem to be kube-apiserver, etcd and kubelet.

Any idea on how to troubleshoot this?

EDIT: crc version 2.0.1 from Red Hat's site.

as-polyakov commented 2 years ago

macOs 12.4 - the same situation. CRC consumes 200% cpu being idle and only is capable of serving basic hello world. Anything non trivial throws it over the edge and laptop as well as CRC becomes unusable

I am wondering how we can prioritize this issue higher, seems like it basically hinders many folks from using CRC at all

Is there any alternative to CRC to try out for local development on OpenShift?

CRC version: 2.5.1+5b02b826
OpenShift version: 4.10.18
Podman version: 4.1.0
cfergeau commented 2 years ago

What are your system's specs, in prarticular the amount of RAM?

as-polyakov commented 2 years ago

2019 MBP Core i7 6 core, 32 GB ram

crc VM has 24 GB memory and 4-6 cores. It doesn't really matter how much cores and memory you give it, it is barely usable with any amount and becomes completely unusable and unstable if you try to do anything non-trivial. For example, web console routinely crashes, internal registry gives EOF in the middle of container downloads, etc.

Vanilla configuration, all is out of the box. I can provide any debug info but I think the point here also made by other folks - there's smth seriously wrong with crc here which doesn't even seem to be related to hyperkit or macos (since folks reporting the same issue on Linux based systems) and you don't need a sophisticated scenario - just install it and check the CPU. Then throw a container and see your laptop melting

fs30000 commented 2 years ago

You don't even need to start a container. It's nuclear all the time. Everything default. Openshift, the same s**t. Someone said it is like this by design. My mind is blown.

as-polyakov commented 2 years ago

I think it is clearly an issue. It can't be unusable by design. This is nuts that latest macbook almost dies immediately after you start empty cluster and surely dies once you run hello world in it. Fans never stop, their console GUI crashes and restarts every couple of minutes. I couldn't get a container with more or less non-trivial image to start since it never was able to finish downloading it from internal registry which gave up midway and threw EOF all the time.

Redhat, please take it seriously. It says this is a product for local development. It is surely not in this current form. We are a large company (DataRobot) and we looked at adopting CRC for our internal dev. So far I am struggling to recommend that we move forward

cfergeau commented 2 years ago

As a data point, I just downloaded crc 2.7.1 on my macbook x86_64/32GB running macOS Big Sur, I kept the default parameters for crc, ran crc setup; crc start; oc new-app https://github.com/openshift/ruby-hello-world.git#beta4 and waited until the application was deployed. The fan of the macbook started a few times, but I don't think they reached their maximum speed, and the application was eventually deployed. I did not use the macbook extensively while doing this, but its GUI stayed responsive while doing this.

Detailed steps regarding what you are doing would be useful, so that we can try to reproduce and understand what's happening for you.

taneem-ibrahim commented 2 years ago

@as-polyakov Hi Anton - I am following up from our call yesterday. I chatted with the CRC team. Would you be able to provide the steps that you followed? Did you have a lot of the other applications running on your mac at the same time? We have not been able to reproduce this locally on our macs so we would like to understand the steps that you followed.

When you reproduce this on your mac, could you check and share the following items with us:

gbraad commented 2 years ago

To add; If needed, we can join a call. Especially as some issues are hard to reproduce, it helps to have a look at the actual problem. Perhaps it is caused by an external factor we aren't aware of, like a network tools (little snitch), a virus scanner, or corporate VPN as requirement. Screenshot, debug logs, maybe even a CPU graph can help to identify more around the issue. OpenShift sometime spikes to perform background processes, but if the CPU has a high load it mostly tries to reconcile and/or fails to do so.

gbraad commented 2 years ago

Note; the latest versions of CRC make use of the new Virtualization Framework using our vfkit driver. Issues regarding load are therefore in recent versions not caused by Hyperkit.

as-polyakov commented 2 years ago

@gbraad we are preparing the repro example. High level the situation was this - idle install itself with CRC doing nothing already takes a significant CPU (around 150-200% on my macbook), in agreement with other peoples observations. Then we try to upload a pretty sizeable image to internal registry (12GB) and without limiting max-concurrency to 1 it never succeeds - CPU is at 600% and registry just crashes all the time as well as web GUI.

With "max-concurrent-uploads": 1 we were able to upload the image but then once pods start deploying they concurrently fetch the image and situation repeats - everything in a constant crash loop with 600% CPU.

Maybe this high level info helps while the team prepares repro example

fs30000 commented 2 years ago

Seems it's a generic kubernetes problem. Whatever instalation you do, cpu will skyrocket. Be it crc, openshift or k8s. I installed openshift in a powerful server. Load was stupidly high. Someone said this was by design. In a time everyone is talking about saving energy, this is lame and stupid.

cfergeau commented 2 years ago

Then we try to upload a pretty sizeable image to internal registry (12GB) and without limiting max-concurrency to 1 it never succeeds - CPU is at 600% and registry just crashes all the time as well as web GUI.

I tried this scenario with 2 images, a 15GiB image filled with 0s, and an image of the same size filled with random data. The image filled with 0s could be uploaded to a crc cluster with its default settings with no huge impact on CPU. The one filled with random data was indeed harder to upload, I could not use the default cluster settings (raised both disk and memory, not sure both were needed or just disk), and I could observe the increased CPU usage. However, I was able to successfully upload the image without significant problems.

Looking at top inside the VM, CPU usage is coming from vm/haproxy, both processes are related to network traffic, kube-apiserver also shows up, I'm not sure why (I'm pushing with podman to the internal registry), and finally there's a dockerregistry process which I expect is the process adding the image to the registry.

Apart from the vm process, I suspect the same CPU usage would be observed on a real cluster, ie pushing an image to an OpenShift cluster seems to be quite heavyweight. Maybe it could be optimized at the OpenShift level, but I'm not sure at the crc level there is much we can do :-/

aaronsuns commented 9 months ago

Same here

CRC VM:          Running
OpenShift:       Running (v4.14.0-0.okd-2023-12-01-225814)
RAM Usage:       7.544GB of 16.36GB
Disk Usage:      77.61GB of 106.8GB (Inside the CRC VM)
Cache Usage:     25.31GB

login inside the VM, those are top 3 ordered by CPU usage.

USER         PID %CPU %MEM    VSZ   RSS TTY      STAT START   TIME COMMAND
root        2859 31.1 12.0 3945820 1929400 ?     Sl   08:06   6:06 kube-apiserver --openshift-config=/etc/kubernetes/static-pod-resources/configmaps/config/config.yaml --advertise-address=192.168.126.11 -v=2 --permit-address-sharing
root        1954  8.4  1.1 2370632 189512 ?      Ssl  08:06   1:39 /usr/bin/kubelet --config=/etc/kubernetes/kubelet.conf --bootstrap-kubeconfig=/etc/kubernetes/kubeconfig --kubeconfig=/var/lib/kubelet/kubeconfig --container-runtime-endpoint=/var/run/crio/crio.sock --runtime-cgroups=/system.slice/crio.service --node-labels=node-role.kubernetes.io/control-plane,node-role.kubernetes.io/master,node.openshift.io/os_id=fedora --node-ip=192.168.126.11 --minimum-container-ttl-duration=6m0s --cloud-provider= --volume-plugin-dir=/etc/kubernetes/kubelet-plugins/volume/exec --hostname-override= --provider-id= --register-with-taints=node-role.kubernetes.io/master=:NoSchedule --pod-infra-container-image=quay.io/openshift/okd-content@sha256:ee1598710d2b9c5f3143255fa0ba5f1ee96b31e29c5ef99aa9abde1d33abb814 --system-reserved=cpu=200m,memory=350Mi,ephemeral-storage=350Mi --v=2
root        3296  7.1  2.4 10380252 394876 ?     S<sl 08:06   1:23 etcd --logger=zap --log-level=info --experimental-initial-corrupt-check=true --snapshot-count=10000 --initial-advertise-peer-urls=https://192.168.126.11:2380 --cert-file=/etc/kubernetes/static-pod-certs/secrets/etcd-all-certs/etcd-serving-crc-d4g2s-master-0.crt --key-file=/etc/kubernetes/static-pod-certs/secrets/etcd-all-certs/etcd-serving-crc-d4g2s-master-0.key --trusted-ca-file=/etc/kubernetes/static-pod-certs/configmaps/etcd-serving-ca/ca-bundle.crt --client-cert-auth=true --peer-cert-file=/etc/kubernetes/static-pod-certs/secrets/etcd-all-certs/etcd-peer-crc-d4g2s-master-0.crt --peer-key-file=/etc/kubernetes/static-pod-certs/secrets/etcd-all-certs/etcd-peer-crc-d4g2s-master-0.key --peer-trusted-ca-file=/etc/kubernetes/static-pod-certs/configmaps/etcd-peer-client-ca/ca-bundle.crt --peer-client-cert-auth=true --advertise-client-urls=https://192.168.126.11:2379 --listen-client-urls=https://0.0.0.0:2379,unixs://192.168.126.11:0 --listen-peer-urls=https://0.0.0.0:2380 --metrics=extensive --listen-metrics-urls=https://0.0.0.0:9978