Трасси… что? Доклад Яндекса

Отладка приложения занимает бо́льшую часть нашего времени. Кто-то пользуется DevTools, кто-то обходится обычным console.log, кто-то использует профайлеры. Зачастую этих инструментов более чем достаточно. Но есть еще один, не такой известный и популярный в JavaScript-мире. О нем я и рассказал в докладе.

— Всем привет! Надеюсь, вы бодры, веселы, перекусили, заварили себе кофейку, потому что сейчас будет очень интересная и при этом доступная тема: «Трасси… что?». Правильнее было бы называть доклад «Трасси… что-о-о?!», но не будем так.

Давайте познакомимся. Меня зовут Алексей Охрименко, я разработчик Яндекс.Музыки. У Музыки 12 стран присутствия, 15 млн активных слушателей и больше 65 млн активных треков. Там я работаю разработчиком и стараюсь делать этот проект лучше.



Помимо того, что я пишу в Яндексе на React, я еще и Google Developer Expert по Angular. Кому еще нравится фильм «Сплит»?

Также, кому интересно, заходите в созданное мной телеграм-комьюнити tensorflow_js. Если вы когда-то интересовались машинным обучение и знаете JavaScript или Python, обязательно заходите в эти группы, будем рады вам помочь. Подписывайтесь на мои социальные сети, там я под никнеймом obe’njiro или obenjíro, как удобно. И у меня есть телеграм-канал obenjiro_notes, в котором я периодически выкладываю самое интересное и классное, что только бывает.

Я обожаю странные инструменты, которые экономят огромное количество времени. Сейчас хочу с вами поговорить о трассировщиках.

Что такое трассировка?

Смотрите, у нас у всех есть некий словарный запас: трассировка, отладка, профилирование, логирование. Мы все эти термины слышали. Но как их поделить, как сделать четкую иерархию?



Самое главное: у нас есть одна главная цель — отладить наше приложение. С помощью отладки мы пытаемся улучшить качество, скорость, еще что-то.

А вот трассировка, профилирование, логирование — это всего лишь некие подходы/методологии, позволяющие достичь нашей цели.

Кстати, есть огромное количество разных интересных способов достичь целей отладки. К примеру, Wolf fence algorithm, Delta Debugging, Saff Squeeze, Causality tracking, PostMortem debug.



Сейчас вы подумаете: «Вот это классные темы! Поговорим о них».

Но что мы скажем богу прокрастинации? Не сегодня! В этот раз мы поговорим только про трассировку и существующие инструменты.

И еще раз. Что такое трассировка?

Трассировка — это получение информации о каждом шаге выполнения. Самое важное отличие от других подходов — в том, что мы получаем информацию о каждом шаге. Но что означает «шаг»?

Для трассировки нет необходимости получать информацию о каждой строчке кода.

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

Базовые способы трассировки

Трассировка может быть сделана множеством разных способов. Вы можете банально вставить console.log везде.

Если вам не хочется делать это вручную, настраивать, есть огромное количество хороших библиотек: Winston, Log4js, Scribe и многие другие — я тут не перечислял все.

Есть наш замечательный Chrome DevTools со своим пошаговым отладчиком. Мы можем трассировать нашу программу с помощью него.

Есть огромное количество профессиональных инструментов: Dtrace, Ptrace и многие другие. Но у них есть ряд ограничений. Я поговорю о них чуть попозже.

И, конечно, есть некие специализированные инструменты, которые и являются предметом доклада.



Именно о них я и хочу вам рассказать. Но прежде чем мы приступим, посмотрим на существующие подходы к трассировке.

console.log (Winston, Log4js, Scribe)

Сначала про логи. Самое простое, банальное, но при этом проверенное временем решение.

function doSomething(a, b, c) {
    const result = a + b + c;   
    return result;
}

function doSomething(a, b, c) {
    console.log('args', arguments);

    const result = a + b + c;

    console.log('result', result);
    
    return result;
}

Простейший вариант — я вставляю console.log вначале, и в конце нашей функции вывожу информацию об аргументах и результате выполнения функции.

Естественно, я не хочу выводить trace-логи каждый раз. Они нужны мне только во время отладки.

Поэтому я добавляю некое условие — проверку на то, что у нас есть, к примеру, environment-переменная Trace. Или, если мы в браузере, я могу взять за основу какой-нибудь query-параметр либо проверить наличие определенной куки.

function doSomething(a, b, c) {
    if (process.env.TRACE) {
        console.log('args', arguments);
    }
    const result = a + b + c;
    if (process.env.TRACE) {
        console.log('result', result);
    }
    return result;
}

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

const winston = require('winston');
const logger = winston.createLogger({
    transports: [
        new winston.transports.Console({ 
            level: process.env.LOG_LEVEL || 'error'
        })
    ]
});

function doSomething(a, b, c) {
    logger.log('silly', 'args', arguments);
    const result = a + b + c;
    logger.log('silly', ‘result', result);
    return result;
}

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

И это супер, но…



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

Chrome DevTools, Step Debugger

Давайте посмотрим что-нибудь более автоматизированное. К примеру, Chrome DevTools и его Step Debugger.

В Node.js мы можем использовать node --inspect-brk main.js, и наше приложение начнется сразу с break point, то есть автоматически остановится в самом начале своего выполнения. Или мы можем воткнуть debugger в наш main file, если речь о фронтенде.



Как только мы откроем DevTools, у нас будет панелька, которая позволяет выполнять пошаговую отладку нашего приложения, и мы будем, скажем так, близки к термину трассировка. То есть будем выполнять программу шаг за шагом, каждый раз нажимать на следующий шаг и получать информацию о каждом шаге.

Круто? Увы, не очень.

1. Есть баги, завязанные на скорость выполнения. Если вы будете выполнять вашу программу слишком медленно или слишком быстро, у вас не будет воспроизводиться баг.
2. Есть множество платформ (Node.js, веб, мобильный веб, смарт-ТВ) и runners (Jest, Selenium), которые мы просто не сможем одновременно сконфигурировать и везде запустить отладчики. В лучшем случае — потратим на это очень много времени.
3. Есть Web Workers, Service Workers, postMessage, разнообразные коммуникации между разными iframe. Даже в рамках базового JavaScript у нас может возникнуть множество проблем с отладкой.
4. Есть ограничения нашей среды разработки. Иногда, к примеру, мы не можем получить доступ к исходникам и у нас нет SourceMaps. Из за того, как проект собирается и деплоится. Мы можем вообще не иметь прямого доступа к машине, на которой выполняется код, — к примеру, мы можем разрабатывать на dev-сервере и docker-образе). Конечно, мы можем настроить отладку там, но какой ценой?
5. И самое главное: с пошаговым отладчиком, если вы не видите всей картины, не знаете свою кодовую базу идеально и не знаете, где искать этого Уолли, то можете потратить на это безумное количество времени.

Dtrace, Ptrace, etc.

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

Для эффективного использования, чтобы вы получали именно хорошую отладочную информацию, необходимо подключить провайдер и создать так называемые пробы. И эти пробы будут использоваться как некий объект, через который вы будете сообщать Dtrace о происходящих событиях.

const dtp = require('dtrace-provider')
    .createDTraceProvider(provider);

// Add probes
dtp.addProbe('func-a-entry', 'int'); 

// Create function
function funcA() {
    var key = 0;
    dtp.fire('func-a-entry', () => [ key ]);
}

И все замечательно, но, к сожалению, это не все. Вам не только JavaScript придется писать, но и Dtrace скрипт. То есть есть такая штука. Она не сильно сложная, но, в любом случае, вам придется с ней ознакомиться.

#!/usr/sbin/dtrace -s
#pragma D option quiet

BEGIN
{
    printf("Tracing...\n");
    depth = 0;
}

nodefunc*:::*entry
{
    printf("[%Y] %*s --> %s\n", walltimestamp, depth, "", probename);
    depth += 2;
}

nodefunc*:::*return
/self->func[arg0]/
{
    depth -= 2;
    printf("[%Y] %*s <-- %s)\n", walltimestamp, depth, "", probename);
}

Написав ее, вы можете получить эту интересную отладочную информацию и получать ее на нативном, скажем так, уровне — то, что делают ребята из C++, из других языков программирования.

./func-trace.d
Tracing...
[16:06:04]  --> func-a-entry
[16:06:09]  <-- func-a-return

Всё это, конечно, замечательно. Но в основном все эти инструменты для Node.js, они слишком низкоуровневые, ну правда. Те, кто знают C/C++, будут чувствовать себя как рыба в воде. А остальным будет тяжеловато. И требуется некая поддержка кодовой базы. То есть вам придется дополнять ваш код в зависимости от изменений. Это дополнительная работа, которой все-таки хочется избежать.

Специализированные инструменты

И теперь самое интересное. Есть специально созданные инструменты для трассировки, именно под JavaScript, под веб и Node.js.

Давайте взглянем на некоторые из них. Лично я знаю два засветившихся в мире фронтенда: TraceGL от Рика Арендса и SpyJS от Артема Говорова.

TraceGL

Это инструмент, который изначально был бесплатен, но вы могли заплатить за него дополнительно, как бы поддержать автора. В какой-то момент, к сожалению, этот инструмент просто перестал существовать. К сожалению, поддержка комьюнити оказалась не такая большая, как ожидал автор, плюс наложились проблемы самого инструмента. Но есть ряд разработчиков, которые форкнули когда-то выложенный TraceGL, запатчили основные существенные баги, и мы можем склонировать этот репозиторий и воспользоваться trace-сервером из этого репозитория.

git clone git@github.com:/traceglMPL/tracegl.git
cd tracegl
node trace/trace_server.js

После чего мы можем указать нашу программу и передать ее в TraceGL клиент как аргумент. Она запустится, то есть TraceGL аугментирует вашу кодовую базу и добавит отладочную информацию.

node ~/tracegl  yourprogram.js

Давайте взглянем на этот инструмент. Всё очень быстро и качественно работает. И огромное количество отладочной информации, которую вы видите на экране, — все это отрисовано с помощью WebGL. Вы всё рисуете с помощью WebGL и шейдеров: шрифты, кнопки, тексты, скроллы. Автор проделал огромную работу. Но в связи с этим появились и дополнительные проблемы — не на всех машинах доступны и хорошо работают шейдеры. Кто пытался сделать качественные кроссбраузерные и кроссплатформенные веб-игры — поймет, о чем речь.

Если мы посмотрим на программу, то увидим три замечательные особенности: мини-карту, то есть некую общую карту того, что вообще произошло; набор stack traces, нажав на которые, мы можем перейти к нашей кодовой базе и увидеть, к примеру, как выполнялись те или иные if, else, switch statements, операторы условного перехода. То есть мы можем проанализировать, как выполнялась наша программа в реальном времени. Не знаю, как для вас, а для меня это безумно круто. Когда я впервые это увидел, был просто в безумном восторге.

Но, как и говорил, инструмент устарел, он не поддерживает TypeScript, не поддерживает современный JavaScript, поэтому нам он не подойдет.

SpyJS

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



SpyJS — это инструмент, который интегрирован в WebStorm. Все, что нужно, чтобы прямо сейчас начать трассировку вашего приложения с помощью SpyJS: вместо профиля отладки создать профиль для SpyJS. Вы также запускаете через WebStorm ваше приложение — как Node.js, так и фронтенд…

SpyJS через проксирование дополняет вашу кодовую базу, добавляет все необходимое для трассировки вашего приложения.

Если посмотреть, что происходит, то у вас появляется дополнительная отладочная информация либо в момент прогона, либо после него, и вы можете по stack traces, по событиям исследовать и открывать так называемый trace view. Это view, в котором есть вся отладочная информация, необходимая, чтобы понять, какие операторы условного перехода отработали, какие функции когда и при каких условиях были вызваны.

SpyJS встроен в среду разработки, и вы можете отлаживать ваше приложение вообще без браузера. Ну, класс!

У этого инструмента есть ряд нюансов. Все-таки он накладывает довольно большой overhead по производительности, имейте это в виду. Вообще SpyJS изначально конкурировал с TraceGL, и TraceGL выигрывал как раз за счет производительности, наличия мини-карты и более понятного и простого интерфейса. Но SpyJS сейчас монополист в плане специализированных инструментов по отладке.

Фатальный недостаток

Но все вышеперечисленные инструменты обладают фатальным недостатком. Они написаны не мной. :) Поэтому была начата разработка инструмента под названием TraceMePlz.

Зачем?

Это важный вопрос, всегда задавайте его себе, прежде чем что-то писать.

1. TraceGL был удобен, у него была мини-карта. Одна мини-карта чего стоит. Те, кто играл в «Варкрафт», поймут, о чем я.
2. Во всех существующих инструментов трассировки не хватает возможности сравнивать side by side. К примеру, у нас запущен одновременно фронтенд, бэкенд, тесты, воркеры, сервис-воркеры, кластер на ноде и end-to-end-тесты. Комбинация всего этого приводит к баге. Как мы можем это в реальном виде увидеть? Существующими инструментами — к сожалению, никак. Вам придется открыть на каждый из этих проектов свой инструмент для трассировки на несколько мониторов и пытаться выловить эту информацию.
3. Существующий SpyJS не только неудобный, но и довольно медленный. Безусловно, это все субъективно, но с TraceGL мне удавалось трассировать более сложные и тяжелые проекты. (Никаких замеров не производил, все это — личное впечатление от работы с этими инструментами.)
4. И последнее, самое важное: кастомный пайплайн сборки. Проблема всех инструментов, как TraceGL, так и SpyJS: они рассчитывали, что интегрируются в вашу экосистему. Создается некий прокси, который проксирует ответ из фронтенда на бэкенд. Создается аугментация вашей кодовой базы. Но все это рассчитано на то, что у вас есть некий стандартный процесс работы. А представьте, что, к примеру, вы разрабатываете не на локальной машине, а на Dev-сервере. Что у вас есть одновременно SSR, SPA, а еще server components на React. Динамическая подгрузка, еще что-то. К сожалению, в таких ситуациях SpyJS и многие другие просто бесполезны. На их настройку вы потратите больше времени, чем на поиск и устранение бага.

Я долго думал, что можно сделать, как подойти к этим проблемам. Здесь мне помог инструмент под названием TypeWiz. Сейчас будет немного оффтопа.



Если кто-то его еще не видел — попробуйте, реально классный инструмент. К примеру, у нас есть простой файл main.ts без типов:

function greet(who) {
    return `Hello, ${who}`;
}

console.log(greet('Uri')); 

Мы запускаем TypeWiz:

typewiz-node <main.ts>

И в нашем коде магически появляются типы:

function greet(who: string) {
    return `Hello, ${who}`;
}

console.log(greet('Uri'));

Он в рантайме, добавляя в вашу кодовую базу некий код и собирая с помощью него информацию о типах объектов во время выполнения, превратить ваш TypeScript, у которого, допустим, нет типов, в TypeScript, у которого указаны все типы. Он использует информацию из рантайма, берет эти типы и вставляет их обратно в файл. Вы можете за считанные минуты получить полный type coverage вашего приложения.


Это все, конечно, круто. Но чем TypeWiz меня так вдохновил?

У него есть режим под названием CLI. Он вам позволяет просто добавить в готовый исходный код вот эти консоль-логи, эту необходимую отладочную информацию.

И как?

Давайте посмотрим, как это происходит.

const parser = require('@babel/parser');
const generate = require('@babel/generator');
const traverse = require('@babel/traverse');
const t = require('@babel/types');

Чтобы все это сделать, достаточно использовать Babel. У него есть парсер, который позволяет получить поддержку почти всей современной кодовой базы. Есть traverse, позволяющий ходить по AST, которые мы распарсили, и получать из этого информацию. Есть генератор и типы, которые позволяют нам создавать дополнительную кодовую базу и с помощью генератора обратно сгенерировать это синтаксическое дерево в файл.

Самое простое, что можем сделать: создать этот парсер и подключить вообще все существующие плагины, за исключением Flow. Flow и TypeScript несовместимы, поэтому приходится выбирать, что вам нужно поддерживать в текущий момент.

    const ast = parser.parse(content, {
     sourceType: 'script',
      allowUndeclaredExports: true,
      plugins: [
        'jsx',
        'typescript',
        ……
      ]
    });

Дальше мы проходимся по нашему дереву и для ArrowFunctionExpression, FunctionExpression, FunctionDeclaration, Method вставляем дополнительный код, то есть вызов функции, который позволит передать трассировочную информацию.

    traverse(ast, {
      enter(path) {
        if (
          path.isMethod() ||
          path.isArrowFunctionExpression() ||
          path.isFunctionExpression() ||
          path.isFunctionDeclaration()
        ) {
          injectIntoNode(path.node, content, filename);
        }
      },
    });

Теперь мы берем типы и делаем call expression, вызов функции. В нем мы передаем наши параметры, аргументы, текущее название файла, что мы вызываем и в каком месте мы это делаем.

const callExpr = t.callExpression(t.identifier('Ωsend'), [
    t.stringLiteral(filename),
    t.stringLiteral('args'),
    t.stringLiteral(String([
      node.start, 
      node.end, 
      node.loc.start.line, 
      node.loc.end.line,
    ]))
  ] 

Всё это превращается в некую строчку в нашей кодовой базе, которая автоматически расставляется во всех местах, необходимых для сбора информации о трассировке.

Ωsend("args", "test/a.js", "143,163,12,14", { a, b, c }, Ωend);

Помните, как я показывал консоль-логи, когда мы расставляли вручную? Мы всё это можем автоматизировать. Затем генерируем и вставляем это в кодовую базу.

return generate(ast).code;

Но есть одна проблема. babel/generator ломает форматирование кода. Тут пришлось прибегнуть к магии MagicString (подробнее о нем можете прочитать у меня в статье). MagicString решило не только проблему с форматированием кода, упростило добавление новых языков в будущем и увеличило производительность инструмента.

И всё. Неважно, что вы используете: Webpack, Babel, TypeScript, Flow или вообще PHP. Подход будет одним и тем же, абсолютно. Поменяется лишь некий набор библиотек. И этот подход универсален, он подходит для всего. Неважно, как вы деплоите, есть ли у вас свой сборщик, язык и парсер или вы делаете что-то свое, уникальное. У вас все будет работать.

Смотрите, как это выглядит со стороны. Вы запускаете инструмент для трассировки и указываете, к примеру, что в папке public лежит все, что связано с фронтендом. Я туда передаю, соответственно, некий паттерн, по которому найдутся все фронтенд-файлы, и указываю channel (это именно параметр «с»), что это информация о фронтенде для сервера.

npx @tracemeplz/cli  ./public/**.js  -c="front"

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

npx @tracemeplz/cli  ./server/**.js  -c="back"

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

npx @tracemeplz/server

Рассмотрим на максимально простом примере. У нас есть некая кнопка. При нажатии на нее мы делаем fetch, это уходит на бэкенд, бэкенд идет за какими-то моковыми данными и возвращает результат на фронтенд.


Давайте глянем, как это выглядит в TraceMePlz. Не обращайте внимания на код. Я хочу лишь показать две особенности. Смотрите, слева находится фронтенд, клики и всё, что происходит, а справа бэкенд. Как видите, это одна из особенностей, о которых я рассказывал: side by side.


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

Один из дополнительных плюсов, которые есть уже из коробки, — мини-карта. То, чего не хватает в SpyJS, и то, что было в TraceGL.


Еще один бонус — «быстрый поиск».



Все это возможно благодаря тому, что мы просто используем Monaco Editor. Он из коробки поддерживает множество вариантов, умеет делать fallback для старых систем. Мало того, из коробки получилось сделать syntax highlight для более полумиллиона строчек трассировочного кода. Этого более чем достаточно даже для очень большой сессии трассировки.

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

npx @tracemeplz/cli  ./public/**.js   --remove

Просто убрать всю эту отладочную информацию, когда она нам больше не нужна.

Теперь немножко про трасировочную информацию. Как она сейчас выглядит?



У нас есть названия наших функций, если у функции нет имени — оно формируется по некоему алгоритму в зависимости от того, где, когда и при каких условиях вызывается метод. В любом случае мы получаем информацию о том, когда мы зашли в функцию, когда из нее вышли, какой метод инициировал вызов другого метода и что это за методы. То есть мы получаем эту цепочку вызовов stack trace.



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



Мы получаем информацию об аргументах, которые были переданы. Изначально мы это делаем, копируя только верхнюю часть свойств объекта. Остальное превращается в запись вида [Object object]. Делаем мы это, потому что объекты иногда могут достигать множества мегабайтов в размере, поэтому по умолчанию ограничивается максимальный размер дампа. Но вы это сможете регулировать.

TraceMePlz — крут, но...

1. Он сейчас не опубликован. К сожалению, с такими инструментами всегда есть огромное количество подводных камней. Но постараюсь в ближайшее время его уже опубликовать.
2. Пока нет фильтрации, но есть поиск. Вы прямо сейчас можете искать что-то с помощью RegExp, можете найти аргументы по паттерну, что в других инструментах не так интуитивно и просто.
3. Пока не логируются операторы условного и безусловного перехода. Этой информации пока нет. Но, опять же, добавить ее будет не слишком сложно.

Возможно, неожиданное применение

Прежде чем мы закончим, я хочу рассказать про одно очень странное и неожиданное, возможно, применение. Все инструменты трассировки — замечательные, классные, но всегда возникает спор: «А он мне точно нужен?»

Однако есть один кейс, в котором инструменты трассировки мне помогали. А именно — увеличение bus factor (фактора автобуса). Для тех, кто не знает, bus factor — это когда один автобус сбивает одного программиста. Сколько таких автобусов нужно, чтобы остановилась разработка нашего проекта, то есть сколько людей должен сбить автобус, чтобы мы перестали понимать, что происходит в нашем проекте?

Так вот, в проектах с большой кодовой базой, которые еще и живут очень долго, bus factor часто стремится к нулю. Чтобы этого избежать, у нас есть один маленький трюк — трассировщик. Вы не представляете, сколько раз он меня спасал. Он помогал мне вливаться в кодовую базу очень быстро без какой-либо помощи. Я просто запускал трассировщик, выполнял некие действия и тут же в реальном времени понимал, что происходит с системой, как она работает. И это очень-очень круто.

Мало того, в TraceMePlz есть встроенная возможность сделать Diff и визуально понять, в чем отличие работающего кода от неработающего.



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

Прислушивайтесь к себе и своему коду, обязательно пользуйтесь инструментами для трассировки.

Подписывайтесь на мой телеграм-канал. Там обязательно будет отдельный анонс о релизе TraceMePlz.