Архив для категории: Александр Алексеев

К нам обратился человек, который пожаловался на то, что его приложение работало нормально, пока он не добавил в него EurekaLog. После включения в проекте EurekaLog стало появляться исключение Out of system resources. Исключение возбуждалось вспомогательной функцией OutOfResources из модуля Vcl.Graphics.

Стек вызова для исключения выглядел следующий образом:

• Vcl.Graphics.OutOfResources
• Vcl.Graphics.GDIError
• Vcl.Graphics.GDICheck
• Vcl.Graphics.TransparentStretchBlt
• Vcl.Graphics.TBitmap.Draw
• Vcl.Graphics.TCanvas.Draw
• SomeComponent.TSomeDBGrid.DrawCell
• Vcl.Grids.DrawCells
• Vcl.Grids.TCustomGrid.Paint
• Vcl.Controls.TCustomControl.PaintWindow
• Vcl.Controls.TWinControl.PaintHandler
• Vcl.Controls.TWinControl.WMPrintClient
• …

Само исключение возбуждается такой функцией:

procedure OutOfResources;
begin
  raise EOutOfResources.Create(SOutOfResources);
end;

Которая в свою очередь вызывается из:

procedure GDIError;
const
  BufSize = 256;
var
  ErrorCode: Integer;
  Buf: array [Byte] of Char;
begin
  ErrorCode := GetLastError;
  if (ErrorCode <> 0) and (FormatMessage(FORMAT_MESSAGE_FROM_SYSTEM, nil, ErrorCode, LOCALE_USER_DEFAULT, Buf, BufSize, nil) <> 0) then
    raise EOutOfResources.Create(Buf)
  else
    OutOfResources;
end;

function GDICheck(Value: THandle): THandle;
begin
  if Value = 0 then
    GDIError;
  Result := Value;
end;

Заметьте, что такая реализация в VCL имеет проблему: вне зависимоси от ошибки возбуждается исключение класса EOutOfResources, даже если ошибка не равна ERROR_NOT_ENOUGH_MEMORY, ERROR_NO_SYSTEM_RESOURCES (или аналогичной). Логичнее было бы возбуждать что-то типа EInvalidGraphicOperation в общем случае и возбуждать EOutOfResources только для ошибок подобного типа.

Из полного баг-отчёта EurekaLog было видно, что показатели памяти и описателей находятся в разумной норме, т.е. проблема не в нехватке памяти. Откуда следует, что (вероятнее всего) GetLastError вернула 0. В самом деле, строка в TransparentStretchBlt, которая проваливает проверку GDICheck выглядит следующим образом:

MemBmp := GDICheck(CreateCompatibleBitmap(SrcDC, SrcW, SrcH));

Из документации видно, что функция CreateCompatibleBitmap не устанавливает значение GetLastError при неудаче.

Впрочем, у функции не так много причин завершиться неудачей: либо ей переданы неверные аргументы, либо ей нехватает памяти для создания bitmap. Заметьте, что нехватка памяти также возможна, если в SrcW и SrcH находится «мусор», который «слишком большой». Таким образом, хотя мы не знаем точную причину неудачи CreateCompatibleBitmap, но мы можем предположить, что проблема — в аргументах.

Значения SrcDC, SrcW и SrcH являются параметрами функции и приходят в неё из TBitmap.Draw:

TransparentStretchBlt
  (ACanvas.FHandle, Left, Top, Right - Left, Bottom - Top, 
   Canvas.FHandle { SrcDC }, 0, 0, 
   FDIB.dsbm.bmWidth { SrcW }, FDIB.dsbm.bmHeight { SrcH }, 
   MaskDC, 0, 0);

Где Canvas — это поле FCanvas bitmap-а, создаваемое по запросу, а FDIB — поле из FImage: TBitmapImage. Таким образом, все параметры (SrcDC, SrcW и SrcH) приходят в функцию TransparentStretchBlt из полей объекта класса TBitmap.

Следовательно, TBitmap, который пытается рисовать TSomeDBGrid.DrawCell, повреждён. Поскольку исключения не происходит без EurekaLog, но происходит с EurekaLog, то содержимое памяти TBitmap меняется при включении EurekaLog. Наиболее вероятное объяснение такого поведения: ошибка типа «use after free». Без отладочных инструментов в программе код может обратиться к уже удалённому TBitmap и «успешно» выполнить с ним операцию — поскольку память освобождённых объектов не удаляется физически, а лишь помечается как «свободная», без изменения её содежимого. При добавлении в программу EurekaLog её конфигурация по умолчанию включает проверки памяти, которые стирают память при её освобождении.

Проверить эту гипотезу можно изменив настройку «When memory is released» в положение «Do nothing» и отключив опцию «Catch memory problems». Если после этого исключение EOutOfResources пропадёт, то в коде имеется ошибка вида «use after free». Наиболее вероятна ошибка в коде SomeComponent, но есть небольшой ненулевой шанс, что клиент нашёл ошибку в VCL.

К сожалению, мы не получили ответа от клиента.

Читать на сайте автора.

С нами связался человек, который утверждал, что нашёл баг в EurekaLog. Он обосновал это утверждение следующим образом: если создать новое приложение DataSnap и добавить в него EurekaLog, то приложение вылетит с Access Violation при выходе.

При расследовании выяснилось следующее:

• В модуле данных ServerContainerUnit1 находится компонент сервера DSServer1;
• Тот же модуль данных содержит два вспомогательных компонента: DSTCPServerTransport1 и DSServerClass1;
• Оба компонента DSTCPServerTransport1 и DSServerClass1 указывают DSServer1 как «Server»;
• При выходе приложения модуль данных ServerContainerUnit1 будет уничтожен;
• Уничтожение модуля данных означает уничтожение всех компонентов в нём — включая DSTCPServerTransport1 и DSServerClass1.

  Вот где это происходит:

  • TDSServerClass.Destroy
  • TComponent.DestroyComponents
  • TDataModule.Destroy
  • TDSTCPServerTransport.Destroy
  • TComponent.DestroyComponents
  • TDataModule.Destroy

  При этом ни TDSServerClass.Destroy, ни TDSTCPServerTransport.Destroy не уведомляют сервер о том, что они уничтожаются. В результате DSServer1 продолжает хранить ссылку на (уже удалённые) DSTCPServerTransport1 и DSServerClass1.

• Итак, после удаления DSTCPServerTransport1 и DSServerClass1 очистка модуля данных ServerContainerUnit1 продолжается;
• Настаёт очередь удаления DSServer1. В частности, при этом DSServer1 пытается остановить все зарегистрированные в нём транспорты:
  • TDSCustomServer.StopTransports
  • TDSCustomServer.Stop
  • TDSServer.Stop
  • TDSServer.Destroy
  • TObject.Free
  • TComponent.DestroyComponents
  • TDataModule.Destroy

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

Как видим, это — баг в DataSnap, а не в EurekaLog. EurekaLog лишь помогла найти этот баг. Действительно, когда EurekaLog не подключена, то DSServer1 может «успешно» вызвать StopTransports, поскольку память уже удалённых объектов не будет изменена, и вызов методов уже удалённых объектов внутри StopTransports пройдёт «успешно».

Заметьте, что эта ошибка сидит в DataSnap уже целую вечность и её никто не исправляет — ровно потому, что в голом приложении нет средств для её обнаружения. Похожие проблемы есть и в пустом приложении Fire Monkey (FMX), а также во многих стандартных компонентах Delphi.

Конкретно эту ошибку можно обойти, если заставить DSServer1 удаляться первым:

procedure TServerContainer1.DataModuleDestroy(Sender: TObject);
begin
  FreeAndNil(DSServer1);
end;

Другие ошибки аналогичного плана нужно исследовать отдельно.

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

Читать на сайте автора.

Это перевод Why does my command line redirection echo with an extra 1? Who’s inserting these rogue 1s everywhere? Автор: Реймонд Чен.

Если вы оставите включённым

Читать на сайте автора.

К нам обратился человек, который пожаловался на то, что его приложение работало нормально, пока он не добавил в него 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.

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

Читать на сайте автора.