Как разработчик, я ежедневно сталкиваюсь с большим количеством данных, которые нужны для принятия каких‑либо решений. Логи, конфиги, данные профилирования, аналитические выгрузки из БД и даже сведения о том, когда был написан данный код — это всё данные. Иногда бывает достаточно посмотреть глазами, и картина станет ясной. Но чем больше данных, тем меньше помогает «метод пристального взгляда» и тем нужнее какие‑то инструменты анализа — а у нас в Яндекс Еде данных бывает очень много.

Иногда можно собрать нужную информацию, просто скомбинировав несколько линуксовых команд пайпом (cat data.log | grep … | awk .. | sort | uniq -c | sort -r | head), иногда пригодятся электронные таблицы, иногда проще написать небольшую программку для анализа данных. Но когда я освоился с языком R и его экосистемой, то всё это стало ненужным.

Представьте, что у вас есть небольшая аналитическая in‑memory база данных с полностью динамической структурой, поддержкой любых типов в полях, в том числе и объектов со структурой любой сложности. А ещё удобный язык запросов к ней, импорт и экспорт популярных форматов данных из любых источников, хоть из буфера обмена. Всё это бесплатно, с удобным GUI и мощным движком визуализации данных.

Узнал я про R практически случайно: на моей первой работе нужно было сделать что‑то, чтобы заменить огромный лист с формулами в Excel (сотня столбцов и десятки тысяч строк), который тормозил всё больше и больше. С тех пор я использовал R как более удобную и мощную альтернативу электронным таблицам, когда нужно посчитать какую‑нибудь статистику на датасетах размером в миллионы строк и построить красивые графики, которые помогают представить какие‑то выводы руководству в простом и наглядном виде.

В какой‑то момент я заинтересовался языком и его библиотеками подробнее, начал основательно читать документацию (а не просто применять знакомые рецепты), и вдруг меня осенило: значительная часть моей работы (исключая написание кода, разумеется) — это работа с данными. А это значит, к ним можно применить специально для этого сделанный инструмент…

Сейчас это новообретённое осознание упрощает мою работу. Работа с данными с помощью R помогает мне, во‑первых, быть уверенным в результатах анализа, а во‑вторых, делает его в большинстве случаев лёгким, быстрым и приятным. В статье я покажу несколько примеров, где я «увидел данные» и сделал свою работу более эффективной.

Tidyverse — библиотеки, которые упрощают жизнь

Эффективная работа с данными в R во многом возможна благодаря библиотекам tidyverse. Они спроектированы так, чтобы им было удобно работать друг с другом: например, у них единообразное наименование функций, а также одинаковый подход к аргументам и принципам работы.

Один из ключевых компонентов этой экосистемы — пакет magrittr. Он вводит pipe‑оператор, благодаря которому конструкции вида f(g(h(x, 1), 'col'), 'mean') превращаются в изящное x %>% h(1) %>% g('col') %>% f('mean'), где аргументы функций не отрываются от их имён.

Скажу больше: эта штука оказалась настолько удобной, что в сам язык R версии 4.1.0 был введён встроенный оператор |> с почти той же функциональностью. Благодаря ему обработка данных становится очень похожа на наращивание команд через пайп в шелле (вида grep … | cut … | awk …). Вот только вместо просто текстовых потоков между функциями обычно передаются таблички с данными.

Tidy Data

Tidy Data — это принцип организации табличных данных. Но на самом деле он организует не столько данные, сколько мышление. Он до банальности прост:

1. Одна строка — одно наблюдение.

2. Один столбец — одна переменная.

3. Одна ячейка — одно значение.

Польза его не столько в том, что он декларирует, по сути, очевидные вещи (концепция очень близка к нормальным формам БД), а скорее в том, что он заставляет задуматься: «Что нужно рассматривать как одно наблюдение? А что есть одно значение?»

Как только структура данных становится ясна, обычно становится ясен и путь, каким именно образом их преобразовать к нужному виду.

Как это выглядит на практике

Первый пример: сравнение feature-флагов

Начнём с простого. Как и в любом большом проекте, у нас в Яндекс Еде есть множество фича-флагов. Задача — понять, значения каких флагов совпадают в проде и на тестинге, а какие различаются. Хранятся они все в виде большого JSON-файла. Причём по историческим причинам формат этого файла таков, что описание флага вписывается не в схеме, а в самом конфиге.

{
  "feature_flag_1": {
     "description": "Здесь какое-то описание",
     "enabled": true
  },
  "feature_flag_2": {
     "description": "Здесь другое описание",
     "enabled": false
  }
}

Поэтому просто взять два JSON‑файла и сделать diff не получается: вылезает множество различий в описаниях (которые не важны), или где‑то diff вместо различия в значениях находит различия в названиях. Это нам не подходит.

Предлагаю сделать небольшую паузу и подумать, как бы вы решили эту задачу, совершая минимум действий с клавиатуры. Среди идей от коллег, например, вставить JSON в IPython‑ноутбук в виде строкового значения, разобрать и сравнить, преобразовав данные в set.

Мой вариант с R укладывается в три строки, одну из которых даже не нужно полностью набирать.

# (копируем в буфер конфигурацию теста)
clipboard() %>% parse_json %>% enframe %>% unnest_wider(value) -> test
# (копируем в буфер конфигурацию прода)
clipboard() %>% parse_json %>% enframe %>% unnest_wider(value) -> prod # нажал вверх и исправил четыре символа

# смотрим разницу, приводя отсутствующие значения к False
prod %>% full_join(test, by='name') %>% filter(coalesce(enabled.x, F) != coalesce(enabled.y, F)) %>% View

Разумеется, предварительно у меня уже есть открытая RStudio, в которой подключены нужные библиотеки: library(tidyverse) и library(jsonlite).

Как это работает в R

А теперь давайте разбираться, что же здесь произошло.

Как мы помним, цепочки вида a %>% b %>% c %>% d — это последовательный вызов функций. clipboard(), как несложно понять, просто возвращает содержимое буфера обмена. Далее начинает работать функция parse_json из пакета jsonlite, которая превращает json‑текст в list. А list в точности отражает иерархическую структуру JSON.

Так, из примера в JSON получится следующий список:

list(feature_flag_1 = list(description = "Здесь какое-то описание", 
    enabled = TRUE), feature_flag_2 = list(description = "Здесь другое описание", 
    enabled = FALSE))

lobstr::tree(l)
#> <list>
#> ├─feature_flag_1: <list>
#> │ ├─description: "Здесь какое-то описание"
#> │ └─enabled: TRUE
#> └─feature_flag_2: <list>
#>   ├─description: "Здесь другое описание"
#>   └─enabled: FALSE

Далее мы начинаем приводить эти данные к tidy‑виду: одна строка — одно наблюдение, один столбец — одна переменная. «Наблюдение» здесь — один фича‑флаг, а «переменные» — описание и признак включённости.

Сначала мы превращаем список в таблицу с помощью функции enframe. На выходе получаем такую табличку:

> l %>% enframe
# A tibble: 2 × 2
  name           value           
  <chr>          <list>          
1 feature_flag_1 <named list [2]>
2 feature_flag_2 <named list [2]>

В первом столбце таблицы — ключи объекта, во втором — значения. Но так как значения не простые, а составные, то они представлены в виде списка.

list(description = "Здесь какое-то описание", enabled = TRUE)

Чтобы «развернуть» такой список в столбцы, есть функция unnest_wider. Она собирает все возможные имена, вложенные в этот список, и распределяет их по столбцам. Там, где данные отсутствуют, появится значение NA. Таким образом, у нас получается датафрейм следующего вида:

> l %>% enframe %>% unnest_wider(value)
# A tibble: 2 × 3
  name           description             enabled
  <chr>          <chr>                   <lgl>  
1 feature_flag_1 Здесь какое-то описание TRUE   
2 feature_flag_2 Здесь другое описание   FALSE 

Поначалу это заклинание может выглядеть довольно непростым, однако к нему очень быстро привыкаешь. Что‑то типа ... %>% parse_json %>% enframe %>% unnest_wider(value) я пишу постоянно.

Соответственно, после выполнения первых двух команд у меня есть два датафрейма — для боевого и тестового окружения. Теперь осталось их соединить и сравнить.

prod %>% 
  full_join(test, by='name') %>% 
  filter(coalesce(enabled.x, F) != coalesce(enabled.y, F)) %>% 
  View

# A tibble: 3 × 5
  name           description.x           enabled.x description.y              enabled.y
  <chr>          <chr>                   <lgl>     <chr>                       <lgl>    
1 feature_flag_1 Здесь какое-то описание    TRUE      Здесь какое-то описание    TRUE     
2 feature_flag_2 Здесь другое описание      FALSE     NA                         NA       
3 feature_flag_3 NA                         NA        Здесь другое описание      TRUE

Когда все нужные функции tidyverse вспоминаются примерно с той же скоростью, что и операторы SQL, то подобное сравнение (включая копирование конфигов, переключение между окошками, просмотр промежуточных результатов) занимает меньше минуты.

Второй пример: более сложный, со встроенным разбором

Давайте усложним задачу — нужно выяснить, кто, когда и какие значения менял. В силу особенностей хранения, опять‑таки, конфиг перезаписывается целиком с указанием времени и автора изменений. Для простоты предположим, что история у нас есть в следующем виде:

[{"author":"pupkin","datetime":"2024-01-17 16:54:23","value":{"feature_flag_1":{"description":"Enable dark mode","enabled":true},"feature_flag_2":{"description":"Show notifications","enabled":false}}},{"author":"ivanov","datetime":"2024-01-18 09:12:45","value":{"feature_flag_1":{"description":"Enable dark mode","enabled":false},"feature_flag_2":{"description":"Show notifications","enabled":true},"feature_flag_3":{"description":"Enable beta features","enabled":true}}},{"author":"pupkin","datetime":"2024-01-19 11:30:10","value":{"feature_flag_1":{"description":"Enable dark mode","enabled":true},"feature_flag_2":{"description":"Show notifications","enabled":true},"feature_flag_3":{"description":"Enable beta features","enabled":false},"feature_flag_4":{"description":"Allow location access","enabled":true},"feature_flag_5":{"description":"Enable offline mode","enabled":true}}},{"author":"ivanov","datetime":"2024-01-20 14:45:33","value":{"feature_flag_1":{"description":"Enable dark mode","enabled":false},"feature_flag_2":{"description":"Show notifications","enabled":false},"feature_flag_3":{"description":"Enable beta features","enabled":true},"feature_flag_4":{"description":"Allow location access","enabled":true}}},{"author":"pupkin","datetime":"2024-01-21 08:22:17","value":{"feature_flag_1":{"description":"Enable dark mode","enabled":true},"feature_flag_2":{"description":"Show notifications","enabled":true},"feature_flag_3":{"description":"Enable beta features","enabled":false}}}]

Для начала разберём её в list, а затем превратим в таблицу.

clipboard() %>% parse_json %>% enframe %>% unnest_wider(value)

...и обнаружим, что данные всё ещё далеки от tidy-представления: одна строка — это одна запись в логе, а содержимое спрятано в двухуровневой иерархии в value. Таким образом, в одной строке — сразу множество наблюдений, а в одной ячейке — множество значений.

С такой структурой данных мы можем утомительно делать unnest_wider несколько раз, но лучше воспользоваться удобной фичей пакета jsonlite, который может разворачивать несложные json-файлы в датафреймы за нас:

> clipboard() %>% fromJSON(flatten=T) %>% glimpse
Rows: 5
Columns: 12
$ author                           <chr> "pupkin", "ivanov", "pupkin", "ivanov", "pupkin"
$ datetime                         <chr> "2024-01-17 16:54:23", "2024-01-18 09:12:45", "2024-01-19 11:30:10", "2024-01-20 14:45:33", "2024-01-2…
$ value.feature_flag_1.description <chr> "Enable dark mode", "Enable dark mode", "Enable dark mode", "Enable dark mode", "Enable dark mode"
$ value.feature_flag_1.enabled     <lgl> TRUE, FALSE, TRUE, FALSE, TRUE
$ value.feature_flag_2.description <chr> "Show notifications", "Show notifications", "Show notifications", "Show notifications", "Show notifica…
$ value.feature_flag_2.enabled     <lgl> FALSE, TRUE, TRUE, FALSE, TRUE
$ value.feature_flag_3.description <chr> NA, "Enable beta features", "Enable beta features", "Enable beta features", "Enable beta features"
$ value.feature_flag_3.enabled     <lgl> NA, TRUE, FALSE, TRUE, FALSE
$ value.feature_flag_4.description <chr> NA, NA, "Allow location access", "Allow location access", NA
$ value.feature_flag_4.enabled     <lgl> NA, NA, TRUE, TRUE, NA
$ value.feature_flag_5.description <chr> NA, NA, "Enable offline mode", NA, NA
$ value.feature_flag_5.enabled     <lgl> NA, NA, TRUE, NA, NA

> clipboard() %>% fromJSON(flatten=T)
  author            datetime value.feature_flag_1.description value.feature_flag_1.enabled value.feature_flag_2.description value.feature_flag_2.enabled value.feature_flag_3.description
1 pupkin 2024-01-17 16:54:23                 Enable dark mode                         TRUE               Show notifications                        FALSE                             <NA>
2 ivanov 2024-01-18 09:12:45                 Enable dark mode                        FALSE               Show notifications                         TRUE             Enable beta features
3 pupkin 2024-01-19 11:30:10                 Enable dark mode                         TRUE               Show notifications                         TRUE             Enable beta features
4 ivanov 2024-01-20 14:45:33                 Enable dark mode                        FALSE               Show notifications                        FALSE             Enable beta features
5 pupkin 2024-01-21 08:22:17                 Enable dark mode                         TRUE               Show notifications                         TRUE             Enable beta features
  value.feature_flag_3.enabled value.feature_flag_4.description value.feature_flag_4.enabled value.feature_flag_5.description value.feature_flag_5.enabled
1                           NA                             <NA>                         NA                             <NA>                           NA
2                         TRUE                             <NA>                         NA                             <NA>                           NA
3                        FALSE            Allow location access                       TRUE              Enable offline mode                         TRUE
4                         TRUE            Allow location access                       TRUE                             <NA>                           NA
5                        FALSE                             <NA>                         NA                             <NA>                           NA

Мы получили не очень удобную табличку с кучей столбцов (в реальности их больше 1200), но это лишь промежуточное представление. В нём есть определённая польза: заметим, что благодаря автоматической конвертации сходных JSON‑структур в таблицы на месте пропущенных значений сами собой появились NA (мы потом превратим их в FALSE).

А в каком виде нам нужны конечные данные? Задача ведь узнать, кто и когда менял значения и какие именно. Значит, одним наблюдением здесь будет «изменение одного значения», и ему должна соответствовать одна строка. Столбцы будут такие: кто, когда, какой флаг и на какое значение.

Первым шагом приведём табличку в более приятный вид: удалим лишние столбцы с описаниями и превратим её из «широкой» в «высокую» — чтобы все названия флагов попали в один столбец.

src %>% fromJSON(flatten=T) %>%
  select(-ends_with('.description')) %>% 
  pivot_longer(ends_with('.enabled'))

# A tibble: 25 × 4
   author datetime            name                         value
   <chr>  <chr>               <chr>                        <lgl>
 1 pupkin 2024-01-17 16:54:23 value.feature_flag_1.enabled TRUE 
 2 pupkin 2024-01-17 16:54:23 value.feature_flag_2.enabled FALSE
 3 pupkin 2024-01-17 16:54:23 value.feature_flag_3.enabled NA   
 4 pupkin 2024-01-17 16:54:23 value.feature_flag_4.enabled NA   
 5 pupkin 2024-01-17 16:54:23 value.feature_flag_5.enabled NA   
 6 ivanov 2024-01-18 09:12:45 value.feature_flag_1.enabled FALSE
 7 ivanov 2024-01-18 09:12:45 value.feature_flag_2.enabled TRUE 
 8 ivanov 2024-01-18 09:12:45 value.feature_flag_3.enabled TRUE 
 9 ivanov 2024-01-18 09:12:45 value.feature_flag_4.enabled NA   
10 ivanov 2024-01-18 09:12:45 value.feature_flag_5.enabled NA   
# ℹ 15 more rows
# ℹ Use `print(n = ...)` to see more rows

Что за магия тут происходит

Функция pivot_longer делает таблицу «выше и уже», соединяя выбранные столбцы в один и добавляя новый столбец, в котором хранятся имена бывших столбцов.

ends_with — особая конструкция, работающая внутри функции select и в аналогичных местах, позволяющая выбрать столбцы по концу имени, а если перед ней поставить минус, то эти столбцы будут, напротив, исключены. Подробнее про селекторы можно прочитать в документации.

Поэтому мы с её помощью сначала исключаем ненужные столбцы, а потом выбираем те, которые нужно «схлопнуть», и получаем результат.

Также нужно заменить отсутствующие значения на FALSE и сделать время временем, а не строкой:

… %>% mutate(value = coalesce(value, F)) %>% type_convert

Функция type_convert пытается угадать тип данных в столбце — здесь это и поможет преобразовать строки в даты.

Теперь осталось сгруппировать их по имени флага и выбрать только те значения, где они не совпадают с предыдущим:

… %>% arrange(datetime) %>% group_by(name) %>% filter(value != lag(value, default=F)) 

Или, если нам не нужно сохранять группировку по имени (чтобы, например, посчитать количество изменений по каждому флагу), можно написать так:

… %>% arrange(datetime) %>% filter(value != lag(value, default=F), .by=name)

Или даже так:

… %>% filter(value != lag(value, default=F, order_by=datetime), .by=name)

Получаем на выходе прекрасную удобную табличку с нужными данными.

Конечно, обычно такие длинные цепочки вызовов сразу не напишешь, да это и не нужно. Рабочий процесс выглядит так: посмотрел на данные, применил пару преобразований, оценил промежуточный результат. Если всё правильно, то возвращаешь к редактированию предыдущую команду и наращиваешь цепочку вызовов.

%>% group_by(author) %>% tally(sort=T)

%>% group_by(author) %>% summarise(flags = n_distinct(name), changes=n())

… %>% ggplot(aes(x=datetime, color=as.factor(author)) %>% geom_density()

Обзор реальных кейсов

Теперь, когда читатель понял удобство интерактивной работы, я перейду к более сложным и продвинутым примерам. В них раскрывается истинная мощь такого подхода к данным. В целом общая тактика такова:

1. Загрузить какие‑то данные.

2. Привести каждый набор к tidy‑виду.

3. Агрегировать как нужно.

4. Посмотреть на итоговый результат разными способами.

5. При необходимости найти больше данных и повторить.

Реальная задача с Feature Flags

Реальная задача с feature flags на самом деле выглядела так:

1. Получить список флагов из кода при помощи статического анализатора (да, я люблю писать плагины к Psalm). Данные включают в себя наименование флага, а также файл и номер строки, где он объявлен.

2. Сравнить флаги, которые объявлены в коде и которые сконфигурированы в проде. Тут обнаружилось, что часть флагов из кода в принципе никогда не включались ни на проде, ни на тесте.

3. Поскольку статический анализатор выдаёт файл и номер строки, с помощью инструмента blame можно узнать, кто его там написал. Здесь можно вытянуть столбец прямо из таблички, превратить его в шелл‑команды, запустить, распарсить вывод — и это всё при желании можно запихнуть в одну длинную команду с множеством %>%. Правда, поскольку blame — операция затратная, результаты я тут же сохранил в отдельную переменную.

4. Далее на основании этих данных можно строить графики, приходить к авторам и выяснять, по какой причине флаг никогда не включался, и так далее.

Из интересных приёмов, которые здесь пригодились, — создание столбцов со значениями‑списками и последующее склеивание их в команды. Чтобы blame по файлам, где используются фича‑флаги, был быстрее, его стоит запрашивать не по всему файлу, а по отдельным строкам с упоминаниями. В одном файле таковых упоминаний может быть несколько, и в идеале команда должна выглядеть так:

arc blame --json -L 100,100 -L 208,208 -L 514,514 File.php

Arc — это наша система контроля версий. О ней мы писали несколько лет назад.

Выполнять команду с захватом вывода можно с помощью system(command, intern=T), но как её сформировать? Жизнь облегчает пакет glue:

ff_usages %>% 
  mutate(linepart = glue::glue("-L {line},{line}")) %>%
  group_by(path) %>% 
  summarise(lines=str_flatten(linepart, " ")) %>% 
  glue::glue_data("arc blame --json {lines} {path}") -> commands

Здесь функция glue::glue формирует строки вида -L 100,100 по шаблону. Затем, сгруппированные по пути к файлу, они склеиваются воедино с помощью str_flatten, а в итоге glue::glue_data из каждой строки таблицы делает текстовую строку‑команду.

Теперь выполняем команды. Тут нам пригодится map из пакета purrr. В качестве первого аргумента она принимает список, в качестве второго — функцию. Остальные аргументы просто передаются в указанную функцию. С pipe‑оператором конструкция выглядит удобно и изящно:

# можно написать и более «классический» вариант с анонимной функцией и без pipe-оператора
cmds.output <- map(commands, \(x) system(x, intern=T))

# но с помощью синтаксического сахара всё становится гораздо прозрачнее:
commands %>% map(system, intern=T) -> cmds.output

map и str_flatten пригодятся и для обработки результатов команд, а system возвращает вывод, разбитый по строкам.

cmds.output %>% map(\(x) x %>% str_flatten %>% parse_json) 

И далее уже знакомыми инструментами можно разбирать JSON. Из итоговых материалов, например, следующий график:

Вот так несколькими несложными методами мы определили, какие фича‑флаги в проде висят долго в одном состоянии, а какие не включались вовсе — возможно, их потеряли или они вовсе не нужны?

Агрегация данных по мониторингу из разных мест

В нашем монолите несколько сот разных эндпоинтов с разной нагрузкой. При этом среднее время ответа также различается — некоторые работают быстрее, некоторые медленнее. Для того чтобы найти те, которые более всего влияют на общую нагрузку, нужно сопоставить данные по RPS и по времени ответа. Эти данные считаются с помощью разбора логов nginx. По историческим причинам конфигурация мониторинга для большого монолита обновляется вручную и выглядит как‑то так:

route_order_cancel:
    And:  
      - Equals: {http_host: "example.com"}
      - StartsWith: {request_url: "/orders/"}
      - Or:
          - EndsWith: {request_url: "/cancel"}
          - EndsWith: {request_url: "/cancel/"}
          - Contains: {request_url: "/cancel?"}
          - Contains: {request_url: "/cancel/?"}

Соответственно, понять, каким именно эндпоинтам это соответствует, может быть довольно нетривиальной задачей, но только в том случае, если мы не используем ленивую функциональную природу R.

Мониторинг конфигурируется с помощью YAML‑файлов и точно так же, как и JSON, читается в иерархический список с помощью yaml::read_yaml. Список всех возможных эндпоинтов мы получим с помощью команды symfony debug:route --json. Осталось только сопоставить эти данные: определить, какое «человекопонятное» имя из конфигурации мониторинга соответствует тому или иному эндпоинту. Код, который выполняет такой, казалось бы, нетривиальный матчинг всего со всем, оказалось очень легко написать.

Ключевая функция — purrr::modify_tree, которая рекурсивно обходит список, включая вложенные списки, и может модифицировать элементы. Обходить будем следующим образом: каждый «лист» с предикатом будем сравнивать с таблицей роутов и заменять его на булев вектор, в котором каждый элемент будет обозначать, соответствует ли роут с соответствующим номером этому предикату. Логические операции в таком случае будут простой свёрткой результатов вычислений предикатов.

Основная часть кода — это перевод предикатов в соответствующие выражения R. Привожу его в несколько упрощённом виде. Уверен, что это можно было бы написать ещё проще, но с текущей задачей он справился на отлично. Единственный очевидный недостаток такого подхода — все правила вычисляются для всех роутов, оттого оно работает несколько неторопливо (единицы секунд на сопоставление ~ тысячи роутов и нескольких сотен правил), но в контексте анализа это совершенно несущественная задержка.

monitoring_rule_exec <- function(rule, routes) {
  # обрабатывает конкретный предикат
  handleUrl <- function(clause, fun) {
    fun(clause[[1]]) %>% replace_na(FALSE) # исполняем функцию и заменяем NA на FALSE
  }
  
  handlers <- list(
    Equals = function(clause) {
      field <- names(clause)[[1]]
      expected <- clause[[1]]
 
      # поскольку symfony выдаёт маршруты в виде регулярок, то мы должны проверить,
      # соответствует ли заданный URL ему
      switch(field,
             http_host=stri_detect_regex(expected, routes$hostRegex),
             request_url=stri_detect_regex(expected, routes$pathRegex),
             request_method=expected == routes$method
      ) %>% replace_na(FALSE)
    },
    
    StartsWith = function(clause) {
      handleUrl(clause, \(x) stri_startswith(routes$path, fixed=x))
    },
    
    EndsWith = function(clause) {
      handleUrl(clause, \(x) stri_endswith(routes$path, fixed=x))
    },
    
    Contains = function(clause) {
      handleUrl(clause, \(x) stri_detect(routes$path, fixed=x))
    },  
    
    Or = function(clause) {
      purrr::reduce(clause, `|`)
    },
    
    And = function(clause) {
      purrr::reduce(clause, `&`)
    },
    
    Not = function(clause) {
      !clause[[1]]
    } 
  )
  
  rule %>% modify_tree(post = \(el) {
    h <- handlers[[names(el)]]
    el[[1]] %>% h %>% return # да, return — это тоже функция
  })
}

Далее с этими данными можно эффективно отсеять роуты, которые нас не интересуют. По оставшимся можно выгрузить статистику из системы мониторинга по OpenAPI (пакет rapiclient позволяет сделать клиент по openapi‑описанию) и дальше искать интересующее.

На итоговом графике сразу видно, что нагрузка на большую часть эндпоинтов невелика, а вот api_order_integration_order имеет достаточно большое время ответа и при этом заметный RPS.

Разбор php-fpm.slow.log

Другая задача из разряда анализа производительности — анализ slow‑лога php‑fpm. Несмотря на то, что он не слишком‑то хорошо структурирован, средства tidyverse делают его разбор довольно простым делом. Сам лог выглядит примерно так:

[08-Dec-2024 16:56:48]  [pool www] pid 3863
script_filename = /code/index.php
[0x0000000005fbc2d0] realpath() /code/includes/stream_wrappers.inc:377
[0x0000000005fbbdd0] getLocalPath()   /code/includes/stream_wrappers.inc:695
[0x00007ffff7ee1700] url_stat() unknown:0
[0x0000000005fbbb60] file_exists() /code/includes/common.inc:4945
[0x0000000005fbb058] drupal_aggregated_file_exists() /code/includes/common.inc:4994
[0x0000000005fb92c0] drupal_build_js_cache() /code/includes/common.inc:4429
[0x0000000005fb8d80] drupal_get_js() /code/includes/theme.inc:2703
[0x0000000005fb6f60] template_process_html() /code/includes/theme.inc:1125
[0x0000000005fb6010] theme() /code/includes/common.inc:5967
[0x0000000005fb5af0] drupal_render() /code/includes/common.inc:5814
[0x0000000005fb49b8] drupal_render_page() /code/includes/common.inc:2701
[0x0000000005fb4600] drupal_deliver_html_page() /code/includes/common.inc:2589
[0x0000000005fb3f50] drupal_deliver_page() /code/includes/menu.inc:532
[0x0000000005fb3d70] menu_execute_active_handler() /code/index.php:21

[08-Dec-2024 16:56:48]  [pool www] pid 3883
script_filename = /code/index.php
[0x00000000027b95a0] realpath() /code/includes/stream_wrappers.inc:377
[0x00000000027b90a0] getLocalPath() /code/includes/stream_wrappers.inc:695
[0x00007ffff7ee1700] url_stat() unknown:0
[0x00000000027b8e30] file_exists() /code/includes/common.inc:4945
[0x00000000027b8328] drupal_aggregated_file_exists() /code/includes/common.inc:4994
[0x00000000027b6590] drupal_build_js_cache() /code/includes/common.inc:4429
[0x00000000027b6050] drupal_get_js() /code/includes/theme.inc:2703
[0x00000000027b4230] template_process_html() /code/includes/theme.inc:1125
[0x00000000027b32e0] theme() /code/includes/common.inc:5967
[0x00000000027b2dc0] drupal_render() /code/includes/common.inc:5814
[0x00000000027b1c88] drupal_render_page() /code/includes/common.inc:2701
[0x00000000027b18d0] drupal_deliver_html_page() /code/includes/common.inc:2589
[0x00000000027b1220] drupal_deliver_page() /code/includes/menu.inc:532
[0x00000000027b1040] menu_execute_active_handler() /code/index.php:21

Мыслить в парадигме tidy‑data здесь можно двумя способами:

• Во‑первых, одно наблюдение — это одно зависание, то есть одна запись лога.

• Во‑вторых, одно наблюдение — это одно конкретное место в коде, которое участвует в медленном запросе. Для исследования интереснее скорее второе, а первое будет лишь промежуточным представлением.

Записи разделяются двойным переводом строки, и мы их можем легко разделить на отдельные записи:

read_file(‘php-fpm.slow.log’) %>% 
  str_split_1("\n\n") %>% str_trim() -> entries

Далее отделяем «заголовок» записи и заодно прописываем синтетический id — он пригодится, чтобы отслеживать, к какому трейсу принадлежат его части. Функция separate_wider_regex позволяет разделить строку на столбцы по регулярному выражению. Синтаксис её довольно очевиден: мы составляем регулярку по частям, и именованные части превратятся в столбцы.

entries %>% 
  enframe(name='id') %>%
  separate_wider_regex(value, c(
    '\\[',
    date='.+?', '\\]\\s+\\[pool ',
    pool='[^\\]]+', '\\] pid ',
    pid='\\d+',
    '\\nscript_filename = ',
    script='.*?', '\\n', 
    trace='(?s).*')) 

 Теперь у нас есть первое tidy-представление: каждая строка — это один факт зависания:

# A tibble: 2 × 6
     id date                 pool  pid   script          trace                                                                                                     
  <int> <chr>                <chr> <chr> <chr>           <chr>                                                                                                     
1     1 08-Dec-2014 16:56:48 www   3863  /code/index.php "[0x0000000005fbc2d0] realpath() /code/includes/stream_wrappers.inc:377\n[0x0000000005fbbdd0] getLocalPat…
2     2 08-Dec-2014 16:56:48 www   3883  /code/index.php "[0x00000000027b95a0] realpath() /code/includes/stream_wrappers.inc:377\n[0x00000000027b90a0] getLocalPat…

Теперь нужно развернуть каждый трейс. Для этого используем аналогичную технику:

… %>%  separate_longer_delim(trace, regex("\\n")) %>%
  separate_wider_regex(trace, c(
    '\\[', address=".*?", '\\]\\s+',
    call = '.+?', ' ', file='.+?', ':', line='\\d+'
  )) %>% type_convert %>%
  mutate(date = lubridate::parse_date_time2(date, 'dbYHMS', tz='Europe/Moscow'))

Разделяем трейс по переводу строки с помощью separate_longer_delim — не «вширь» (wider), а «в длину» (longer), то есть все остальные строки при этом размножаются. Затем с помощью separate_wider_regex уже разделяем каждый трейс на столбцы дальше, автоматически конвертируем типы с помощью type_convert и вручную добиваем дату, с которой автоматика не справилась:

# A tibble: 28 × 9
      id date                       pool    pid script          address            call                   file   line
   <int> <dttm>                     <chr> <dbl> <chr>           <chr>              <chr>                  <chr> <dbl>
 1     1 2014-12-08 16:56:48.000000 www    3863 /code/index.php 0x0000000005fbc2d0 realpath()             /cod…   377
 2     1 2014-12-08 16:56:48.000000 www    3863 /code/index.php 0x0000000005fbbdd0 getLocalPath()         /cod…   695
 3     1 2014-12-08 16:56:48.000000 www    3863 /code/index.php 0x00007ffff7ee1700 url_stat()             unkn…     0
 4     1 2014-12-08 16:56:48.000000 www    3863 /code/index.php 0x0000000005fbbb60 file_exists()          /cod…  4945
 5     1 2014-12-08 16:56:48.000000 www    3863 /code/index.php 0x0000000005fbb058 drupal_aggregated_fil… /cod…  4994
 6     1 2014-12-08 16:56:48.000000 www    3863 /code/index.php 0x0000000005fb92c0 drupal_build_js_cache… /cod…  4429
 7     1 2014-12-08 16:56:48.000000 www    3863 /code/index.php 0x0000000005fb8d80 drupal_get_js()        /cod…  2703
 8     1 2014-12-08 16:56:48.000000 www    3863 /code/index.php 0x0000000005fb6f60 template_process_html… /cod…  1125
 9     1 2014-12-08 16:56:48.000000 www    3863 /code/index.php 0x0000000005fb6010 theme()                /cod…  5967
10     1 2014-12-08 16:56:48.000000 www    3863 /code/index.php 0x0000000005fb5af0 drupal_render()        /cod…  5814
# ℹ 18 more rows
# ℹ Use `print(n = ...)` to see more rows

Теперь с этими данными легко и удобно проводить практически любой анализ.

Полезные мелочи

Также очень удобно использовать R для обработки логов. Логи представляют собой множество JSON‑строк, в которых внутри могут быть также JSON, сериализованные в строку.

Это всё можно пропустить через jqr для деления на отдельные сообщения и превратить в датафрейм, а затем найти столбец с JSON‑сообщениями и распарсить его в столбцы. Делается это столь же просто:

… %>% mutate(message = map(message, parse_json)) %>% unnest_wider(message)

После некоторой привычки рутинные задачи тоже становится проще сделать через R. Например, проверить, какие директории прописаны у тех или иных EntityManager в конфигурации Doctrine в YAML. Строк там много, и глазами это смотреть довольно долго, и, что хуже, есть риск что‑то пропустить. С помощью clipboard() %>% yaml::yaml.load %>% … это становится не только быстрее, но и надёжнее.

На входе, в принципе, может быть всё что угодно — например, вывод strace. Я превратил его в датафрейм с одним столбцом (read_file %>% str_split_1("\n") %>% as_tibble_col), а затем распарсил при помощи регулярок (separate_wider_regex). Поскольку strace был сразу нескольких процессов, а также там были unfinished‑сообщения, их можно легко сгруппировать по процессам и с помощью функций lag/lead доклеить к началу сообщения его конец (а затем концы просто удалить). Далее я выделил интересующие системные вызовы и посмотрел статистику по частоте, времени и другим параметрам.

Заключение

Сейчас мне достаточно сложно представить свою жизнь без R/RStudio. Казалось бы, специализированный инструмент для аналитиков оказался практически незаменимым обычному разработчику в повседневной разработческой жизни. Практически в любой задаче есть элементы анализа данных, и эффективный инструмент превращает эту часть из скучной рутины в лёгкую и быструю работу.

• Во‑первых, теперь я на всё смотрю, как на данные, и этот подход в принципе направляет мысль так, как я раньше и представить не мог. Это очень влияет на работу и повседневную жизнь.

• Во‑вторых, любые данные легко и просто приводятся в tidy‑вид: упомянутые выше парсеры лога strace или php‑fpm.slow я написал буквально за 15 минут. Думаю, написание парсера на любом языке заняло бы примерно столько же времени, но с R на выходе я получаю данные, с которыми можно удобно проводить самый разный анализ.

• В‑третьих, добавление данных в рабочую среду буквально методом копипаста (clipboard()%>% parse_json %>% …) открывает возможность джоинить всё и вся, вместо того чтобы сверять какие‑то вещи глазами. Единственное, что лучше сразу сохранять данные в какую-то переменную, потому что данные в буфере обмена не вечны.

Надеюсь, мой рассказ вдохновит вас тоже попробовать R/RStudio. А если у вас возникнут вопросы, то пишите их в комментариях — постараюсь ответить.