search

sustainable-computing-io / kepler

Kepler (Kubernetes-based Efficient Power Level Exporter) uses eBPF to probe performance counters and other system stats, use ML models to estimate workload energy consumption based on these stats, and exports them as Prometheus metrics
https://sustainable-computing.io
Apache License 2.0
1.1k stars 175 forks source link

Kepler stops sending data after 1h #1321

Open AydinMirMohammadi opened 5 months ago

AydinMirMohammadi commented 5 months ago

What happened?

I have deployed kepler in a lab environment & and setup defaults including the grafana dashboard. It works as expected.

After one hour no more data is send. See Image

kepler

After restarting the kepler pod, data is collected but also stops after one hour. This happens multiple times

What did you expect to happen?

I expect that the data is send continiuosly

How can we reproduce it (as minimally and precisely as possible)?

I have just use the provided helm charts

Anything else we need to know?

No response

Kepler image tag

Kubernetes version

```console Client Version: version.Info{Major:"1", Minor:"26", GitVersion:"v1.26.1", GitCommit:"8f94681cd294aa8cfd3407b8191f6c70214973a4", GitTreeState:"clean", BuildDate:"2023-01-18T15:58:16Z", GoVersion:"go1.19.5", Compiler:"gc", Platform:"windows/amd64"} Kustomize Version: v4.5.7 Server Version: version.Info{Major:"1", Minor:"27", GitVersion:"v1.27.9", GitCommit:"d33c44091f0e760b0053f06023e87a1c99dfd302", GitTreeState:"clean", BuildDate:"2024-01-31T01:58:06Z", GoVersion:"go1.20.12", Compiler:"gc", Platform:"linux/amd64"} ```

Cloud provider or bare metal

Azure AKS

OS version

```console # On Linux: $ cat /etc/os-release # paste output here $ uname -a # paste output here # On Windows: C:\> wmic os get Caption, Version, BuildNumber, OSArchitecture # paste output here ```

Install tools

Kepler deployment config

For on kubernetes: ```console $ KEPLER_NAMESPACE=kepler # provide kepler configmap $ kubectl get configmap kepler-cfm -n ${KEPLER_NAMESPACE} # paste output here # provide kepler deployment description $ kubectl describe deployment kepler-exporter -n ${KEPLER_NAMESPACE} ``` For standalone: # put your Kepler command argument here

Container runtime (CRI) and version (if applicable)

Related plugins (CNI, CSI, ...) and versions (if applicable)

rootfs commented 5 months ago

@AydinMirMohammadi thanks for reporting! Can you get some info when the dashboard stops getting kepler metrics?

kubectl logs -n kepler daemonset/kepler-exporter
AydinMirMohammadi commented 5 months ago

Thank you for your support.

I restarted the pod at ~17:43 and kepler has start reporting. It stops at ~18:30.

Screenshot Grafana

From Prometheus I get metrics, but the value don't change. I attached the log and the query (from browser, not cmdline) Kepler Log.txt query.json

rootfs commented 5 months ago

There is nothing concerning in the log.

The last 1m metrics are as below. 

# cat query.json | jq '.data.result[]' | jq -r '[.metric.pod_name, .metric.mode, .values[0][0], (.values[0][1]|tonumber) ] | @csv' |sort -k 4 -g -t"," |tail -5
"eventbus-65dbf87c96-pb27n","idle",1712167266.220,19957
"kernel_processes","idle",1712167266.220,21333
"prometheus-kube-prometheus-stack-prometheus-0","idle",1712167266.220,21333
"calico-node-zlzlv","idle",1712167266.220,31266
"system_processes","idle",1712167266.220,795366

I forgot that the metrics are cumulative, we need two samples at different timestamps to get the delta. Can you try taking the metrics again, preferrably with 3 samples and each with at least 30seconds (default kepler sample interval) apart?

In addition, please also get the kepler metrics from kepler pod directly, also 3 times with 30seconds apart, that'll help identify if kepler is still emitting metrics:

kubectl exec -ti -n kepler daemonset/kepler-exporter -- bash -c "curl  http://localhost:9102/metrics |grep ^kepler_"
AydinMirMohammadi commented 5 months ago

Hi, just restart the pod and collect the logs from browser. After one hour, in grafana, the reporting stops. grafana

Here are the files: Kepler+2min.txt Kepler+25min.txt Kepler+45min.txt Kepler+105min.txt Prometheus+2min.json Prometheus+25min.json Prometheus+45min.json Prometheus+105min.json

Thanks Aydin

rootfs commented 5 months ago

Kepler still emits new metrics:

in the 2min data:

% grep kepler_container_joules Kepler+2min.txt |sort -k 2 -g |tail -5
kepler_container_joules_total{container_id="cad29061d20effdae3861e9ae31dfc912aec40295b831033d26ecc690241c0a8",container_name="prometheus",container_namespace="monitoring",mode="idle",pod_name="prometheus-kube-prometheus-stack-prometheus-0",source=""} 264
kepler_container_joules_total{container_id="6752ceb66a0c652dccba0a985e94f509a08d1cb6ef05fde26ffde04b6a266b0a",container_name="eventbus",container_namespace="app-eshop",mode="idle",pod_name="eventbus-65dbf87c96-dt2lh",source=""} 279
kepler_container_joules_total{container_id="system_processes",container_name="system_processes",container_namespace="system",mode="dynamic",pod_name="system_processes",source=""} 324
kepler_container_joules_total{container_id="c0ded97c33b174f38bef8f238105995058e193068e81f3d4d8f598d8c356a5fc",container_name="calico-node",container_namespace="calico-system",mode="idle",pod_name="calico-node-kqmm6",source=""} 579
kepler_container_joules_total{container_id="system_processes",container_name="system_processes",container_namespace="system",mode="idle",pod_name="system_processes",source=""} 12165

In the 25min data:

% grep kepler_container_joules Kepler+25min.txt |sort -k 2 -g |tail -5
kepler_container_joules_total{container_id="6752ceb66a0c652dccba0a985e94f509a08d1cb6ef05fde26ffde04b6a266b0a",container_name="eventbus",container_namespace="app-eshop",mode="idle",pod_name="eventbus-65dbf87c96-dt2lh",source=""} 3375
kepler_container_joules_total{container_id="cad29061d20effdae3861e9ae31dfc912aec40295b831033d26ecc690241c0a8",container_name="prometheus",container_namespace="monitoring",mode="idle",pod_name="prometheus-kube-prometheus-stack-prometheus-0",source=""} 3458
kepler_container_joules_total{container_id="system_processes",container_name="system_processes",container_namespace="system",mode="dynamic",pod_name="system_processes",source=""} 4015
kepler_container_joules_total{container_id="c0ded97c33b174f38bef8f238105995058e193068e81f3d4d8f598d8c356a5fc",container_name="calico-node",container_namespace="calico-system",mode="idle",pod_name="calico-node-kqmm6",source=""} 5494
kepler_container_joules_total{container_id="system_processes",container_name="system_processes",container_namespace="system",mode="idle",pod_name="system_processes",source=""} 152060

The counters are growing.

On the Prometheus side, the numbers are also growing:

In the 2min data:

% cat Prometheus+2min.json | jq '.data.result[]' | jq -r '[.metric.pod_name, .metric.mode, (.value[1]|tonumber)] |@csv '  |sort -k3 -t"," -g |tail
"postgres-7f889f7d74-d4f6p","idle",23
"calico-kube-controllers-6c788cf6df-k2k64","idle",26
"tigera-operator-78f7d86fc6-jqqj4","idle",28
"kube-prometheus-stack-grafana-558998bbc-tvl5w","idle",31
"kepler-9m7wc","idle",89
"prometheus-kube-prometheus-stack-prometheus-0","idle",118
"eventbus-65dbf87c96-dt2lh","idle",131
"system_processes","dynamic",133
"calico-node-kqmm6","idle",276
"system_processes","idle",4976

And the 25min data:

 % cat Prometheus+25min.json | jq '.data.result[]' | jq -r '[.metric.pod_name, .metric.mode, (.value[1]|tonumber)] |@csv '  |sort -k3 -t"," -g |tail
"kube-prometheus-stack-grafana-558998bbc-tvl5w","idle",705
"kube-proxy-7s5ng","idle",750
"calico-kube-controllers-6c788cf6df-k2k64","idle",1112
"tigera-operator-78f7d86fc6-jqqj4","idle",1213
"kepler-9m7wc","idle",2381
"eventbus-65dbf87c96-dt2lh","idle",3214
"prometheus-kube-prometheus-stack-prometheus-0","idle",3287
"system_processes","dynamic",3827
"calico-node-kqmm6","idle",5246
"system_processes","idle",144942

Can you check if the metrics e.g. sum(rate(kepler_container_joules_total[1m])) on the prometheus UI? It could be somewhere in the grafana and prometheus connection (e.g. token expiration)

AydinMirMohammadi commented 5 months ago

Sorry for the missing declaration. The 2min, 25min and 45min are good. They stopped and the 105min is the not good one.

And I see - I have forgotten the 110min. I will collect new files

marceloamaral commented 5 months ago

@AydinMirMohammadi could you please get the Kepler logs when the problem happens?

AydinMirMohammadi commented 5 months ago

Thank you for the support and sorry for the delay

grafana-dashboard

The kepler log has not changed after start. kepler-log-after-stop-reporting.txt

I have attached the metrics (kepler and prometheus) after the start and after the problem began. kepler-metrics-at-start.txt kepler-metrics-after-stop-reporting.txt kepler-metrics-after-stop-reporting+5min.txt

prometheus-metrics-at-start.json prometheus-metrics-after-stop-reporting.json prometheus-metrics-after-stop-reporting+5min.json

rootfs commented 5 months ago

@AydinMirMohammadi thanks for sharing the info. I think there are something oddly happening on the dashboard, potentially an expired token used by grafana that caused the grafana unable to get the latest promethues metrics.

The prometheus query data show the counters are still growing after dashboard stopping (checking pod prometheus-kube-prometheus-stack-prometheus-0 in stopping and stopping+5min)

% cat prometheus-metrics-after-stop-reporting.json | jq '.data.result[]' | jq -r '[.metric.pod_name, .metric.mode, (.value[1]|tonumber)] |@csv '  |sort -k3 -t"," -g |tail
"kube-proxy-ldcf7","idle",2505
"kube-prometheus-stack-grafana-558998bbc-66gqx","idle",2877
"tigera-operator-6997cbcb7c-vh5sj","idle",3054
"calico-kube-controllers-6c788cf6df-wb242","idle",3712
"kepler-lr4m7","idle",7224
"calico-node-4hsgd","idle",7551
"system_processes","dynamic",9485
"eventbus-65dbf87c96-6mzv2","idle",10291
"prometheus-kube-prometheus-stack-prometheus-0","idle",10962
"system_processes","idle",417893
% cat prometheus-metrics-after-stop-reporting+5min.json  | jq '.data.result[]' | jq -r '[.metric.pod_name, .metric.mode, (.value[1]|tonumber)] |@csv '  |sort -k3 -t"," -g |tail
"kube-proxy-ldcf7","idle",2689
"kube-prometheus-stack-grafana-558998bbc-66gqx","idle",3065
"tigera-operator-6997cbcb7c-vh5sj","idle",3311
"calico-kube-controllers-6c788cf6df-wb242","idle",3974
"kepler-lr4m7","idle",7660
"calico-node-4hsgd","idle",8964
"system_processes","dynamic",9485
"eventbus-65dbf87c96-6mzv2","idle",11047
"prometheus-kube-prometheus-stack-prometheus-0","idle",11717
"system_processes","idle",446857
rootfs commented 5 months ago

@sthaha can you take a look? thanks

AydinMirMohammadi commented 5 months ago

I will check this also an another system. A colleague of me has deployed kepler on an onprem cluster with the same behavior.