9 октября 2020 г.

Добавление EurekaLog в программу вызывает Access Violation?

К нам обратился человек, который пожаловался на то, что его приложение работало нормально, пока он не добавил в него EurekaLog. После включения в проекте EurekaLog стало появляться исключение AccessViolation с текстом Access violation at address 00E15025 in module 'Project.exe'. Read of address 83EC8B69 и таким стеком:
  • Contoso.pas TContosoEventMessage.BasePerform
  • Vcl.Forms.pas TApplication.WndProc
  • System.Classes.pas StdWndProc
  • Vcl.Forms.pas TApplication.HandleMessage
  • Vcl.Forms.pas TApplication.Run
  • Project.dpr Initialization
(все имена заменены; Contoso - это некая известная библиотека для Delphi).

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

Адрес в сообщении об ошибке (83EC8B69 - "случайный") и короткий стек могут указывать на проблему "управление ушло по мусорному указателю и вылетело в случайном месте". К сожалению, в отчёте не были включены секции CPU и ассемблера (отключены в настройках). В этом случае диагностика по исходному коду была бы невозможной. Признаться, я сначала хотел так и ответить, дав рекомендацию по усилению контроля за памятью.

Но вот именно такой стек возможен также в случае, если BasePerform вызывается главным потоком как процедура, поставленная в очередь для Synchronize. И действительно - поиск по исходникам выдал такой код:
function TContosoEventMessage.Perform(AThread: TContosoThread): Boolean;
begin
  FMsgThread := AThread as TContosoEventThread;
  if FMsgThread.Active then begin
    if FMsgThread.Options.Synchronize then
      TContosoThread.Queue(nil, BasePerform)
    else
      BasePerform;
  end;
  Result := True;
end;
Т.е. у класса сообщения есть функция для обработки этого сообщения. И если в опциях чего-то там указан флаг Synchronize, то непосредственно обработка сообщения (BasePerform) будет выполнена не в текущем потоке, а будет отправлена на выполнение в главный поток - через TThread.Queue.

И да, в отчёте также был виден этот фоновый поток от Contoso, который мог бы выполнить такой код.

Сам метод BasePerform является просто обёрткой вокруг InternalHandle:
procedure TContosoEventMessage.BasePerform;
begin
  FMsgThread.InternalHandle(Self);
end;
И отчёт EurekaLog показывает, что вылет произошёл на первой же строчке.

Что мы имеем?
  1. Фоновый поток поставил в очередь метод, заполнив поле FMsgThread.
  2. Главный поток попробовал выполнить этот метод и вылетел при попытке прочитать поле FMsgThread.
Вторая строка является предположением, поскольку, как я уже сказал, ассемблера в отчёте не было. Но гипотеза вполне себе, поскольку если иначе вылет был бы внутри InternalHandle.

Т.е. вроде как налицо проблема с памятью. И, кстати говоря, это самая частая "проблема" проектов, которые включают EurekaLog. В самом деле, посмотрите на такой код:
procedure TForm1.Button1Click(Sender: TObject);
var
  List: TList;
begin
  List := TList.Create;
  List.Free;

  List.Clear; // - использование объекта после удаления
end;
Корректный ли это код? Нет, конечно. Но будет ли он "работать". Да, с большой вероятностью он корректно отработает. Происходит это по той простой причине, что "освобождённая" память (и, следовательно, "освобождённый" объект) в действительности не удаляются, а просто помечаются как свободные. Т.е. их память остаётся доступной в неизменном виде. Конечно, если между особождением памяти/объекта и повторным доступом к нему будет много операций, то есть какой-то шанс, что они испортят бывшую память. Но на коротких пробегах вы не заметите проблемы.

Добавление EurekaLog в программу меняет ситуацию на корню, поскольку EurekaLog по умолчанию включает проверки памяти и активно борется с указанными багами.

Что-ж, посмотрим может ли у нас сейчас быть такая ситуация. Для этого нужно понять где освобождается память для FMsgThread. Поскольку он приходит из параметра метода - посмотрим, кто вызывает метод BasePerform. Поиск по исходникам подсказал такой код (поиск показал несколько мест, но конкретное место было выбрано исходя из состояние фонового потока из отчёта):
procedure TContosoThread.Execute;
// ...
begin
// ...
              for i := 0 to oReceivedMsgs.Count - 1 do 
              begin
                oMsg := TContosoThreadMsgBase(oReceivedMsgs[i]);
                try
                  if not oMsg.Perform(Self) then
                    Break;
                finally
                  oMsg.Destroy;
                end;
// ...
end;
Оп, а вот он и баг. Сценарий происходящего:
  1. Фоновый поток перебирает входящие сообщения.
  2. Каждое сообщение обрабатывается (Perform).
  3. Какое-то сообщение указывает, что его нужно синхронизировать в главный поток.
  4. Фоновый поток ставит сообщение в очередь (Queue).
  5. Фоновый поток удаляет сообщение (Destroy), но указатель на сообщение всё ещё сидит в очереди.
  6. Главный поток приступает к обработке запланированных сообщений (BasePerform).
  7. Обработка сообщения вызывает Access Violation, потому что сообщение уже удалено.
Т.е. баг тут либо в управлении памятью, либо в синхронизации потоков. Как возникла такая ошибка? Очевидно, изначально были написаны базовые классы, которые предполагали линейное выполнение: "взяли сообщение - обработали - освободили". Потом был написан особый класс-наследник, который переопределил поведение "обработать" на "поставить в очередь и выйти". А базовый класс (с циклом) про это не в курсе. Что и привело к багу.

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

Я подозреваю, что исправление проблемы могло бы быть в замене Queue на Synchronize.

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

3 комментария :

  1. а что за библиотека то? а то вдруг начну использовать, а там мина тикает

    ОтветитьУдалить
    Ответы
    1. Вы серьёзно полагаете, что я убрал все имена, чтобы сообщить об этом в комментарии?

      Смысл поста не в том, чтобы тыкать пальцем в кого-то, а чтобы продемонстрировать, что простое добавление кода в проект может привести к раскрытию ранее скрытых багов.

      Удалить
  2. Давненько не было ваших постов

    ОтветитьУдалить

Можно использовать некоторые HTML-теги, например:

<b>Жирный</b>
<i>Курсив</i>
<a href="http://www.example.com/">Ссылка</a>

Вам необязательно регистрироваться для комментирования - для этого просто выберите из списка "Анонимный" (для анонимного комментария) или "Имя/URL" (для указания вашего имени и (опционально) ссылки на сайт). Все прочие варианты потребуют от вас входа в вашу учётку.

Пожалуйста, по возможности используйте "Имя/URL" вместо "Анонимный". URL можно просто не указывать.

Ваше сообщение может быть помечено как спам спам-фильтром - не волнуйтесь, оно появится после проверки администратором.