Как R облегчает мою жизнь разработчика

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

Иногда можно собрать нужную информацию, просто скомбинировав несколько линуксовых команд пайпом (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. А если у вас возникнут вопросы, то пишите их в комментариях — постараюсь ответить.