Пожалуй, самые неприятные баги – те, что воспроизводятся один раз из ста. Их не пощупать, не продебажить и даже не проверить результат.

Так и тут прилетает мне баг от тестировщика с описанием:

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

У меня, естественно, ни разу не воспроизвелось. Ну и как с этим работать?

Посмотрел я на это дело и сделал самое очевидное заключение:

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

Ответ очень красивый, но почему-то он не устроил начальство. Тянул я с этим багом, наверное, месяц, а каждую неделю тестировщик прибегал ко мне и радостно говорил, что снова его воспроизвел, и нач. департамента тоже раз в неделю спрашивал, когда же я с этим багом разберусь. И вообще, мол, почему на других страницах все хорошо, и только на одной странице такая фигня (эх, знать бы самому… Ну, как вариант, другие страницы просматриваются реже, а баг и так редкий, вот и не воспроизводился он на других страницах).

Мог бы я так отмораживаться и дольше, но тут мне вдруг ударило в голову:

«Я программист или кто?» «Если не я, то кто?» «Неужели я реально не могу справиться с каким‑то вшивым багом?».

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

1. Оценка диспозиции

Итак, первое, что нужно понять: какой стиль отвечает за такое «кривое» отображение.

Ага, вот он, в компоненте mat-sidenav-content добавляется margin-left. Он высчитывается автоматически и должен быть 227px, но иногда (очень редко) там ставится 14px, что и вызывает проблему.

Кто же отвечает за расчет ширины и как она высчитывается?

Кто отвечает – понятно, компонент sidenav из библиотеки Angular Material. А вот чтобы понять, как высчитывается, нужно пойти на гитхаб и изучить код.

Штош, пойдем.

2. Идем в разведку

Наша библиотека лежит здесь (ссылка сразу на версию 11, которую мы используем в проекте).

В первую очередь, изучим mat-sidenav-content, ведь именно он добавляет неправильный стиль.

Сразу видим, где этот стиль добавляется:

  host: {
    'class': 'mat-drawer-content mat-sidenav-content',
    '[style.margin-left.px]': '_container._contentMargins.left',
    '[style.margin-right.px]': '_container._contentMargins.right',
  },

Отлично, а где у нас _container? В этом классе такого поля не наблюдается, значит, оно в базовом классе MatDrawerContent. Идем туда.

Видим там наш контейнер:

@Inject(forwardRef(() => MatDrawerContainer)) public _container: MatDrawerContainer,

Супер, теперь идем в MatDrawerContainer и находим там объект _contentMargins.

_contentMargins: {left: number | null; right: number | null} = {left: null, right: null};

Скрин прикладывать не буду, класс большой. Нас интересует строка 586.

Где этот объект заполняется? Да вот здесь, в методе updateContentMargins():

updateContentMargins() {
    // 1. For drawers in `over` mode, they don't affect the content.
    // 2. For drawers in `side` mode they should shrink the content. We do this by adding to the
    //    left margin (for left drawer) or right margin (for right the drawer).
    // 3. For drawers in `push` mode the should shift the content without resizing it. We do this by
    //    adding to the left or right margin and simultaneously subtracting the same amount of
    //    margin from the other side.
    let left = 0;
    let right = 0;

    if (this._left && this._left.opened) {
      if (this._left.mode == 'side') {
        left += this._left._getWidth();
      } else if (this._left.mode == 'push') {
        const width = this._left._getWidth();
        left += width;
        right -= width;
      }
    }

    if (this._right && this._right.opened) {
      if (this._right.mode == 'side') {
        right += this._right._getWidth();
      } else if (this._right.mode == 'push') {
        const width = this._right._getWidth();
        right += width;
        left -= width;
      }
    }

    // If either `right` or `left` is zero, don't set a style to the element. This
    // allows users to specify a custom size via CSS class in SSR scenarios where the
    // measured widths will always be zero. Note that we reset to `null` here, rather
    // than below, in order to ensure that the types in the `if` below are consistent.
    left = left || null!;
    right = right || null!;

    if (left !== this._contentMargins.left || right !== this._contentMargins.right) {
      this._contentMargins = {left, right};

      // Pull back into the NgZone since in some cases we could be outside. We need to be careful
      // to do it only when something changed, otherwise we can end up hitting the zone too often.
      this._ngZone.run(() => this._contentMarginChanges.next(this._contentMargins));
    }
  }

Внимательно читаем код. И комментарии тоже. А впрочем, давайте лучше продебажим этот метод, может, что-то поймем.

Нам нужно понять, как рассчитывается переменная left, потому что именно она потом присваивается к this._contentMargins.left.

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

В процессе дебага обращаю внимание, что метод updateContentMargins() у нас вызывается трижды: первый раз ширина 0px, второй раз 14px (Ого, это же цифра из бага! Что-то интересное). А третий раз уже 227px.

Итак, есть первые два предположения:

В сценариях воспроизведения бага метод либо не вызывается третий раз, либо в момент третьего вызова ширина все еще 14px.

Ну что ж, пойдем смотреть по стектрейсу, откуда идут вызовы.

Первый раз из конструктора, второй раз из метода ngAfterContentInit(), третий раз из подписки на this._doCheckSubject.

Ок, зафиксировали.

3. А что там у других?

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

На каждый change detection цикл в Angular происходит вызов ngDoCheck, который делает this._doCheckSubject.next(), и у нас есть подписка на этот subject, которая вызывает метод с расчетами.

  ngDoCheck() {
    // If users opted into autosizing, do a check every change detection cycle.
    if (this._autosize && this._isPushed()) {
      // Run outside the NgZone, otherwise the debouncer will throw us into an infinite loop.
      this._ngZone.runOutsideAngular(() => this._doCheckSubject.next());
    }
  }

Все логично, но почему же на первой странице расчеты не вызываются? Нет change detection циклов? Или не попадаем внутрь условия if в ngDoCheck? Давайте проверим в дебаггере.

4. Магия какая-то.

Конечно же, change detection циклы есть, куда ж без них. И внутрь if мы попадаем, и next() пуляем. Только вот subscribe не срабатывает.

Вот этот код, где мы должны попасть (но не попадаем) в subscribe:

    // Avoid hitting the NgZone through the debounce timeout.
    this._ngZone.runOutsideAngular(() => {
      this._doCheckSubject.pipe(
        debounceTime(10), // Arbitrary debounce time, less than a frame at 60fps
        takeUntil(this._destroyed)
      ).subscribe(() => this.updateContentMargins());
    });

Как так? Отписались мы от него, что ли? Ну, там есть отписка, поставим брейкпоинт на this._destroyed.next(). Он находится в методе ngOnDestroy . Конечно же, метод не вызывается, с чего бы ему, компонент-то не уничтожен.

Что за магия такая? Как код может игнорировать событие next в потоке, если он на этот поток подписан?

В этот момент я понял, что я чего-то не понял, но пока еще не понял, чего именно я не понял.

Итак, next вызывается при каждом doCheck, постоянно. Это факт.
Subscribe не вызывается, это тоже факт.
Поток не завершен и мы от него не отписывались, и это тоже факт.

Что остается?

На всякий случай, загуглю (освежу в памяти), как работает debounceTime(10)

debounceTime is an RxJS operator that delays the emission of values from an observable for a specified duration. If a new value is emitted from the source observable before the delay time elapses, the previous value is discarded, and the timer is reset.
(Gemini)

Так-так-так. Если новое значение приходит до того, как пройдет время (10мс в нашем случае), то прежнее значение будет отброшено и таймер перезапущен.

Значит, если предположить, что мы вызываем next() чаще, чем раз в 10мс, то subscribe не будет выполнен. Бинго? Посмотрим…

5. А что там с циклами?

Давайте проверим, что у нас там вообще с нашими циклами. Для этого воспользуемся расширением Angular Dev Tools, которое умеет их показывать. Обновляем страницу, запускаем запись, и....

Ё-мое, сотни или тысячи циклов в секунду. Никуда не годится, что за фигня вообще?

На всякий случай проверяю другую страницу. Ну, здесь все норм, 1-2 цикла в секунду. Не супер, конечно, но для легаси проекта, в котором onPush стоит через пень-колоду – норм.

Итак, кажется, я нашел причину, по которой наша страница не перерисовывается, когда у левой панели обновляется ширина. Если кратко, то цепочка такая:

1. Ширина отступа пересчитывается в подписке на _doCheckSubjectкомпонента sidenav в библиотеке Angular Material.

2. Компонент sidenav на каждый change detection цикл эмитит next() для _doCheckSubject.

3. Подписка на _doCheckSubject срабатывает, если между предыдущим и текущим эмитом прошло более 10мс.

4. На нашей странице происходит более 100 циклов в секунду, что не дает подписке сработать.

Кстати, а почему у левой панели вообще меняется ширина? Ответ простой, компонент получает список страниц из сервиса по подписке, операция асинхронная, поэтому ширина изменяется уже после инициализации левого меню.

И кстати, это дает ответ на вопрос, почему баг воспроизводится непостоянно. Причина в race condition: либо сервис успеет отдать список страниц до того, как раскрутится карусель с циклами (и метод updateContentMargins() будет вызван третий раз с правильными координатами), либо не успеет.

Ну всё, пойдем искать утечку с циклами.

6. Перекрываем краник.

Поскольку Angular Dev Tools не дал нам никакой информации, кто же вызывает все эти циклы, пойдем на вкладку Performance и будем искать там. Пары секунд записи нам вполне хватит.

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

К сожалению, тут лес из ангуляровских функций и найти что-то сложно. Но внимательный поиск выцепил нетипичное для angular название onSelectionChange, да еще и сразу после хука ngAfterContentChecked. Нажимаем на функцию и видим, в каком она лежит компоненте.

Кажется, победа близко!

Во-первых, этот компонент как раз расположен на проблемной странице. Во-вторых, у него есть явный косяк.

Хук ngAfterContentChecked срабатывает на каждый change detection цикл. А в нем вызывается метод onSelectionChange, который использует setTimeout. А setTimeout вызывает новый цикл.

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

Дальше все стало просто смешно. В функции onSelectionChange изменялось значение поля veryImportantUnusedField, но это поле не используется ни в классе, ни в шаблоне. (название поля примерное)

Так что я просто сношу и метод, и хук.

Тестируем результат:

Прекрасно, циклы на странице пришли в норму. Проверяю, что на каждый цикл вызовается метод пересчета ширины в компоненте sidebar — да, работает.

Итак, победа. Страшный баг повержен, а я записываю себе в актив одно из самых необычных расследований за свою 15-летнюю карьеру программиста.

Будет интересно обсудить в комментариях другие веселые и грустные баги, которые вам встречались.

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