Grafana: values з записів в логах Loki, та dual-Y-axes графіки в Grafana

Автор |  15/08/2023
 

Фукція в AWS Lambda пише логи в CloudWatch Logs, звідки ми через lambda-promtail забираємо їх в Grafana Loki, звідки потім можемо використати в графіках Grafana.

Що треба зробити: в логах пишеться час “Init duration” та “Max Memory Used”.

В CloudWatch таких метрик нема, а нам цікаво мати графік по цим данним, бо це може бути ознакою cold start, які ми хочемо відслідковувати.

Тож треба:

  • отримати ці дані і використати як values в графіку
  • побудувати графік, де зліва будуть відображатись мілісекунди на запуск, а справа – скільки пам’яті при цьому було використано

Grafana Loki і values з labels

Тож що можемо зробити:

  • зі stram selector вибираємо файл логу потрібної фунції
  • через log filter вибираємо  записи, які містять строку “Init Duration”
  • з log parcer regex отримуємо значення з Max Memory Used або Init duration, і створюємо нову label з цим значенням

Тобто для створеня лейбли max_mem_use повністю запит буде таким:

{__aws_cloudwatch_log_group="/aws/lambda/app-prod-ApiHandler-v3"} |~ "Init Duration"| regexp ".*Max Memory Used[\\s\\S]{2}(?P<max_mem_use>.*) MB.*"

Окей, лейблу отримали – далі  треба побудувати графік, тобто створити metric query і використати значення з лейбли max_mem_use як value.

Для цього беремо unwrap expression, і вказуємо ім’я лейбли, значення котрої хочемо відобразити:

sum(sum_over_time({__aws_cloudwatch_log_group="/aws/lambda/app-prod-ApiHandler-v3"} |= "Init Duration"| regexp ".*Max Memory Used[\\s\\S]{2}(?P<max_mem_use>.*) MB.*" | unwrap max_mem_use [15m]))

Та отримуємо суму всіх записів в лог-файлі – між 08:07:28 і 08:08:29 маємо сумарно 1773 мегабайти:

Перевіряємо в логах – вибираємо записи за цей проміжок, 08:07:00 і 08:09:00:

Отримуємо 9 записів, в кожній 197 мегабайт – сумарно 1773.

Grafana panel і dual-Y-axes

В графіках Grafana є можливість відображати на одному графіку результати двох запитів по різним осям і з різним розташуванням.

Тобто з лівої сторони по осі Y (вертикалі) виводити одні значення, з правої по Y – інші, а по осі X (горизонталі) – треті, як правило тут час.

Проте налаштовується це не зовсім очевидно, а спроби загуглити приводять до посту Learn Grafana: How to use dual axis graphs за 2020 рік, який застарів, бо зараз це робиться через Overrides.

Отже, маємо графік з двома Query:

Далі, Init Duration в мілісекундах хочемо відображати зліва як Unit > miliseconds, а Memory Used – справа як Unit > megabytes.

З Init Duration все просто – налаштовуємо Standard options > Unit > ms:

А для Memory – йдемо в Overrides і додаємо нові параметри для поля max_mem_use:

В Property вибираємо Axis > Placement:

І встановлюємо значення Right:

Далі, щоб відображати юніт як мегабайти – додаємо другий Override property – Unit:

І встановлюємо значення megabytes:

Тепер на графіку з однієї сторони маємо час запуску функції, а з другої – скільки пам’яті вона при цьому споживала, і явно бачимо кореляцію між цими значеннями:

Єдине, що ці дані все ж не зовсім вірно допоможуть з визначенням саме cold starts, так як в цей проміжок просто було багато запитів до API Gateway > Lambda, і вона запускалась в декількох інстансах – тому і маємо спайк на графіку Init duration та Memory:

Тому треба трохи переробити: запити з Loki винести в Recording Rules та писати у вигляді звичайних метрик в Prometheus/VictoriaMetrics, а потім в Query графіку отримане з Loki значення ділити на кількість отриманиз записів з логу в цей період.

Додаємо два Recording Rules:

- name: Backend-Lambda

  rules:

  - record: aws:backend:lambda:init_duration:ms
    expr: sum(sum_over_time({__aws_cloudwatch_log_group=~"/aws/lambda/app-(dev|staging|prod)-ApiHandler-v3"} |= "Init Duration"| regexp ".*Init Duration[\\s\\S]{2}(?P<init_duration>.*) ms.*" | unwrap init_duration [15m])) by (__aws_cloudwatch_log_group)
          /
          sum(count_over_time({__aws_cloudwatch_log_group=~"/aws/lambda/app-(dev|staging|prod)-ApiHandler-v3"} |= "Init Duration" [15m])) by (__aws_cloudwatch_log_group)

  - record: aws:backend:lambda:max_mem_use:mb
    expr: sum(sum_over_time({__aws_cloudwatch_log_group=~"/aws/lambda/app-(dev|staging|prod)-ApiHandler-v3"} |= "Init Duration" | regexp ".*Max Memory Used[\\s\\S]{2}(?P<max_mem_use>.*) MB.*" | unwrap max_mem_use [15m])) by (__aws_cloudwatch_log_group)
          /
          sum(count_over_time({__aws_cloudwatch_log_group=~"/aws/lambda/app-(dev|staging|prod)-ApiHandler-v3"} |= "Init Duration" [15m])) by (__aws_cloudwatch_log_group)

В другій частині запиту через count_over_time отримуємо загальну кількість записів, які були отримані.

Робимо Query в Grafana:

aws:backend:lambda:init_duration:ms{__aws_cloudwatch_log_group="/aws/lambda/app-$environment-ApiHandler-v3"}

Та:

aws:backend:lambda:max_mem_use:mb{__aws_cloudwatch_log_group="/aws/lambda/app-$environment-ApiHandler-v3"}

І маємо більш корректний графік:

Готово.