Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

memory leak of keda apiserver adapter #1639

Closed
abowloflrf opened this issue Mar 1, 2021 · 1 comment · Fixed by #1654
Closed

memory leak of keda apiserver adapter #1639

abowloflrf opened this issue Mar 1, 2021 · 1 comment · Fixed by #1654
Assignees
Labels
bug Something isn't working

Comments

@abowloflrf
Copy link
Contributor

abowloflrf commented Mar 1, 2021

Report

Adapter's memory usage keep incresing after i create about 50 ScaledObjects in cluster (about 2-26 11:00 +8:00), each ScaleObject contains two cron trigger.

2-26 container memory monitoring:

image

last two days from now(3-1):

image

logs of adapter:

I0225 03:14:31.186575       1 main.go:88] keda_metrics_adapter "msg"="KEDA Version: 2.1.0"
I0225 03:14:31.186650       1 main.go:89] keda_metrics_adapter "msg"="KEDA Commit: 4866ce69c4897df532b43390bafe4477275bf65a"
I0225 03:14:31.186658       1 main.go:90] keda_metrics_adapter "msg"="Go Version: go1.15.6"
I0225 03:14:31.186665       1 main.go:91] keda_metrics_adapter "msg"="Go OS/Arch: linux/amd64"
I0225 03:14:34.093300       1 request.go:655] Throttling request took 1.047930602s, request: GET:https://172.31.32.1:443/apis/authentication.k8s.io/v1beta1?timeout=32s
I0225 03:14:35.245550       1 provider.go:46] keda_metrics_adapter/provider "msg"="starting"
I0225 03:14:35.245605       1 main.go:149] keda_metrics_adapter "msg"="starting adapter..."
2021-02-25 03:14:35.245657 I | Starting metrics server at :9022
I0225 03:14:35.719909       1 serving.go:325] Generated self-signed cert (apiserver.local.config/certificates/apiserver.crt, apiserver.local.config/certificates/apiserver.key)
I0225 03:14:35.963040       1 requestheader_controller.go:169] Starting RequestHeaderAuthRequestController
I0225 03:14:35.963042       1 configmap_cafile_content.go:202] Starting client-ca::kube-system::extension-apiserver-authentication::client-ca-file
I0225 03:14:35.963078       1 configmap_cafile_content.go:202] Starting client-ca::kube-system::extension-apiserver-authentication::requestheader-client-ca-file
I0225 03:14:35.963102       1 shared_informer.go:240] Waiting for caches to sync for RequestHeaderAuthRequestController
I0225 03:14:35.963108       1 shared_informer.go:240] Waiting for caches to sync for client-ca::kube-system::extension-apiserver-authentication::requestheader-client-ca-file
I0225 03:14:35.963101       1 shared_informer.go:240] Waiting for caches to sync for client-ca::kube-system::extension-apiserver-authentication::client-ca-file
I0225 03:14:35.963392       1 dynamic_serving_content.go:130] Starting serving-cert::apiserver.local.config/certificates/apiserver.crt::apiserver.local.config/certificates/apiserver.key
I0225 03:14:35.963890       1 secure_serving.go:197] Serving securely on [::]:6443
I0225 03:14:35.963996       1 tlsconfig.go:240] Starting DynamicServingCertificateController
I0225 03:14:36.063273       1 shared_informer.go:247] Caches are synced for client-ca::kube-system::extension-apiserver-authentication::requestheader-client-ca-file
I0225 03:14:36.063287       1 shared_informer.go:247] Caches are synced for client-ca::kube-system::extension-apiserver-authentication::client-ca-file
I0225 03:14:36.063309       1 shared_informer.go:247] Caches are synced for RequestHeaderAuthRequestController
E0226 03:33:14.350824       1 writers.go:107] apiserver was unable to write a JSON response: http2: stream closed
E0226 03:33:14.350868       1 status.go:71] apiserver received an error that is not an metav1.Status: &errors.errorString{s:"http2: stream closed"}
E0226 03:33:14.352320       1 writers.go:120] apiserver was unable to write a fallback JSON response: http2: stream closed
E0226 03:36:14.344144       1 writers.go:107] apiserver was unable to write a JSON response: http2: stream closed
E0226 03:36:14.344187       1 status.go:71] apiserver received an error that is not an metav1.Status: &errors.errorString{s:"http2: stream closed"}
E0226 03:36:14.345359       1 writers.go:120] apiserver was unable to write a fallback JSON response: http2: stream closed
E0226 04:44:57.306185       1 writers.go:107] apiserver was unable to write a JSON response: http2: stream closed
E0226 04:44:57.306237       1 status.go:71] apiserver received an error that is not an metav1.Status: &errors.errorString{s:"http2: stream closed"}
E0226 04:44:57.307292       1 writers.go:120] apiserver was unable to write a fallback JSON response: http2: stream closed
E0226 04:57:14.379313       1 writers.go:107] apiserver was unable to write a JSON response: http2: stream closed
E0226 04:57:14.379351       1 writers.go:107] apiserver was unable to write a JSON response: http2: stream closed
E0226 04:57:14.379357       1 status.go:71] apiserver received an error that is not an metav1.Status: &errors.errorString{s:"http2: stream closed"}
E0226 04:57:14.380469       1 status.go:71] apiserver received an error that is not an metav1.Status: &errors.errorString{s:"http2: stream closed"}
E0226 04:57:14.381667       1 writers.go:120] apiserver was unable to write a fallback JSON response: http2: stream closed
E0226 04:57:14.382795       1 writers.go:120] apiserver was unable to write a fallback JSON response: http2: stream closed
E0226 04:59:14.378782       1 writers.go:107] apiserver was unable to write a JSON response: http2: stream closed
E0226 04:59:14.378846       1 status.go:71] apiserver received an error that is not an metav1.Status: &errors.errorString{s:"http2: stream closed"}
E0226 04:59:14.380067       1 writers.go:120] apiserver was unable to write a fallback JSON response: http2: stream closed
E0226 05:02:44.378595       1 writers.go:107] apiserver was unable to write a JSON response: http2: stream closed
E0226 05:02:44.378625       1 status.go:71] apiserver received an error that is not an metav1.Status: &errors.errorString{s:"http2: stream closed"}
E0226 05:02:44.380046       1 writers.go:120] apiserver was unable to write a fallback JSON response: http2: stream closed
E0226 05:09:14.386477       1 writers.go:107] apiserver was unable to write a JSON response: http2: stream closed
E0226 05:09:14.386521       1 status.go:71] apiserver received an error that is not an metav1.Status: &errors.errorString{s:"http2: stream closed"}
E0226 05:09:14.387547       1 writers.go:120] apiserver was unable to write a fallback JSON response: http2: stream closed
I0226 05:10:28.492022       1 trace.go:205] Trace[596748940]: "List" url:/apis/external.metrics.k8s.io/v1beta1/namespaces/ratel/cron-asia-shanghai-017xx5-022xx0,user-agent:kube-controller-manager/v1.16.9 (linux/amd64) kubernetes/4f7ea78/system:serviceaccount:kube-system:horizontal-pod-autoscaler,client:10.245.10.194 (26-Feb-2021 05:10:27.702) (total time: 789ms):
Trace[596748940]: ---"Listing from storage done" 789ms (05:10:00.491)
Trace[596748940]: [789.639748ms] [789.639748ms] END
E0226 05:58:44.419219       1 writers.go:107] apiserver was unable to write a JSON response: http2: stream closed
E0226 05:58:44.419250       1 status.go:71] apiserver received an error that is not an metav1.Status: &errors.errorString{s:"http2: stream closed"}
E0226 05:58:44.420316       1 writers.go:120] apiserver was unable to write a fallback JSON response: http2: stream closed
I0226 07:10:28.803049       1 trace.go:205] Trace[7220889]: "List" url:/apis/external.metrics.k8s.io/v1beta1/namespaces/ratel/cron-asia-shanghai-017xx1-4-022xx1-4,user-agent:kube-controller-manager/v1.16.9 (linux/amd64) kubernetes/4f7ea78/system:serviceaccount:kube-system:horizontal-pod-autoscaler,client:10.245.10.194 (26-Feb-2021 07:10:28.262) (total time: 540ms):
Trace[7220889]: ---"Listing from storage done" 540ms (07:10:00.802)
Trace[7220889]: [540.91826ms] [540.91826ms] END
E0226 07:29:14.440098       1 writers.go:107] apiserver was unable to write a JSON response: http2: stream closed
E0226 07:29:14.440162       1 status.go:71] apiserver received an error that is not an metav1.Status: &errors.errorString{s:"http2: stream closed"}
E0226 07:29:14.442551       1 writers.go:120] apiserver was unable to write a fallback JSON response: http2: stream closed
E0226 08:01:14.451965       1 writers.go:107] apiserver was unable to write a JSON response: http2: stream closed
E0226 08:01:14.452006       1 status.go:71] apiserver received an error that is not an metav1.Status: &errors.errorString{s:"http2: stream closed"}
E0226 08:01:14.453552       1 writers.go:120] apiserver was unable to write a fallback JSON response: http2: stream closed
E0226 10:08:19.076388       1 writers.go:107] apiserver was unable to write a JSON response: http2: stream closed
E0226 10:08:19.076439       1 status.go:71] apiserver received an error that is not an metav1.Status: &errors.errorString{s:"http2: stream closed"}
E0226 10:08:19.077531       1 writers.go:120] apiserver was unable to write a fallback JSON response: http2: stream closed
E0226 12:08:19.143205       1 writers.go:107] apiserver was unable to write a JSON response: http2: stream closed
E0226 12:08:19.143256       1 status.go:71] apiserver received an error that is not an metav1.Status: &errors.errorString{s:"http2: stream closed"}
E0226 12:08:19.144410       1 writers.go:120] apiserver was unable to write a fallback JSON response: http2: stream closed
E0226 13:17:44.576198       1 writers.go:107] apiserver was unable to write a JSON response: http2: stream closed
E0226 13:17:44.576232       1 status.go:71] apiserver received an error that is not an metav1.Status: &errors.errorString{s:"http2: stream closed"}
E0226 13:17:44.577280       1 writers.go:120] apiserver was unable to write a fallback JSON response: http2: stream closed
E0226 13:47:49.182685       1 writers.go:107] apiserver was unable to write a JSON response: http2: stream closed
E0226 13:47:49.182717       1 status.go:71] apiserver received an error that is not an metav1.Status: &errors.errorString{s:"http2: stream closed"}
E0226 13:47:49.183764       1 writers.go:120] apiserver was unable to write a fallback JSON response: http2: stream closed
E0226 13:52:44.588163       1 writers.go:107] apiserver was unable to write a JSON response: http2: stream closed
E0226 13:52:44.588191       1 status.go:71] apiserver received an error that is not an metav1.Status: &errors.errorString{s:"http2: stream closed"}
E0226 13:52:44.589258       1 writers.go:120] apiserver was unable to write a fallback JSON response: http2: stream closed
E0226 14:32:14.604367       1 writers.go:107] apiserver was unable to write a JSON response: http2: stream closed
E0226 14:32:14.604400       1 status.go:71] apiserver received an error that is not an metav1.Status: &errors.errorString{s:"http2: stream closed"}
E0226 14:32:14.605432       1 writers.go:120] apiserver was unable to write a fallback JSON response: http2: stream closed
E0226 14:56:14.614756       1 writers.go:107] apiserver was unable to write a JSON response: http2: stream closed
E0226 14:56:14.614793       1 status.go:71] apiserver received an error that is not an metav1.Status: &errors.errorString{s:"http2: stream closed"}
E0226 14:56:14.616634       1 writers.go:120] apiserver was unable to write a fallback JSON response: http2: stream closed
E0226 15:06:57.720662       1 writers.go:107] apiserver was unable to write a JSON response: http2: stream closed
E0226 15:06:57.720700       1 status.go:71] apiserver received an error that is not an metav1.Status: &errors.errorString{s:"http2: stream closed"}
E0226 15:06:57.722194       1 writers.go:120] apiserver was unable to write a fallback JSON response: http2: stream closed
E0226 15:48:19.242035       1 writers.go:107] apiserver was unable to write a JSON response: http2: stream closed
E0226 15:48:19.242088       1 status.go:71] apiserver received an error that is not an metav1.Status: &errors.errorString{s:"http2: stream closed"}
E0226 15:48:19.243669       1 writers.go:120] apiserver was unable to write a fallback JSON response: http2: stream closed
E0226 16:12:44.644621       1 writers.go:107] apiserver was unable to write a JSON response: http2: stream closed
E0226 16:12:44.644656       1 status.go:71] apiserver received an error that is not an metav1.Status: &errors.errorString{s:"http2: stream closed"}
E0226 16:12:44.645892       1 writers.go:120] apiserver was unable to write a fallback JSON response: http2: stream closed
E0226 17:25:44.672310       1 writers.go:107] apiserver was unable to write a JSON response: http2: stream closed
E0226 17:25:44.672343       1 status.go:71] apiserver received an error that is not an metav1.Status: &errors.errorString{s:"http2: stream closed"}
E0226 17:25:44.673429       1 writers.go:120] apiserver was unable to write a fallback JSON response: http2: stream closed
E0226 17:39:44.677090       1 writers.go:107] apiserver was unable to write a JSON response: http2: stream closed
E0226 17:39:44.677128       1 status.go:71] apiserver received an error that is not an metav1.Status: &errors.errorString{s:"http2: stream closed"}
E0226 17:39:44.679114       1 writers.go:120] apiserver was unable to write a fallback JSON response: http2: stream closed
E0226 19:30:19.332091       1 writers.go:107] apiserver was unable to write a JSON response: http2: stream closed
E0226 19:30:19.332141       1 status.go:71] apiserver received an error that is not an metav1.Status: &errors.errorString{s:"http2: stream closed"}
E0226 19:30:19.333812       1 writers.go:120] apiserver was unable to write a fallback JSON response: http2: stream closed
I0226 20:10:29.879893       1 trace.go:205] Trace[446364659]: "List" url:/apis/external.metrics.k8s.io/v1beta1/namespaces/ratel/cron-asia-shanghai-017xx5-022xx0,user-agent:kube-controller-manager/v1.16.9 (linux/amd64) kubernetes/4f7ea78/system:serviceaccount:kube-system:horizontal-pod-autoscaler,client:10.245.10.194 (26-Feb-2021 20:10:29.077) (total time: 801ms):
Trace[446364659]: ---"Listing from storage done" 801ms (20:10:00.879)
Trace[446364659]: [801.91393ms] [801.91393ms] END
I0226 21:10:29.201988       1 trace.go:205] Trace[1466029855]: "List" url:/apis/external.metrics.k8s.io/v1beta1/namespaces/ratel/cron-asia-shanghai-017xx5-022xx0,user-agent:kube-controller-manager/v1.16.9 (linux/amd64) kubernetes/4f7ea78/system:serviceaccount:kube-system:horizontal-pod-autoscaler,client:10.245.10.194 (26-Feb-2021 21:10:28.666) (total time: 535ms):
Trace[1466029855]: ---"Listing from storage done" 535ms (21:10:00.201)
Trace[1466029855]: [535.108182ms] [535.108182ms] END

Expected Behavior

Stable memory usage.

Actual Behavior

Adapter's memory usage keep incresing after i create about 50 ScaledObjects in cluster, each ScaleObject contains two cron trigger

Steps to Reproduce the Problem

Logs from KEDA operator

Operator's log looks normal, there are no warning or error level logs.

KEDA Version

2.1.0

Kubernetes Version

1.16

Platform

Alibaba Cloud

Scaler Details

Cron

Update

#1654 <- This PR may fix this problem

@abowloflrf abowloflrf added the bug Something isn't working label Mar 1, 2021
@abowloflrf
Copy link
Contributor Author

We're currently using Keda in our production cluster now. So I restarted the adapter Pod directly to avoid OOM . But it seems has not help with the memory increasing.

image

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working
Projects
None yet
Development

Successfully merging a pull request may close this issue.

3 participants