EurekaLog очищает моё изображение? (даже в VCL есть баги)

К нам обратился клиент, который утверждал, что EurekaLog удаляет его изображения в программе. В частности, утверждалось, что код клиента "работал отлично", пока в приложение не была добавлена EurekaLog. После добавления EurekaLog ранее "рабочий" код перестал работать, вместо этого очищая изображение. Клиент также утверждал, что если отключить опцию "Extended memory manager" в EurekaLog, то всё снова работает прекрасно, но если эта опция включена, то ничего не работает, даже если отключить все остальные опции отладки памяти.

Упрощённый код выглядит действительно просто:

Buffer := TBitmap.Create;
try
  Buffer.SetSize(64, 64);
  Buffer.Canvas.StretchDraw(Rect(0, 0, 64, 64), Bitmap); 
  Bitmap.SetSize(64, 64);
  Bitmap.Canvas.Draw(0, 0, Buffer); 
finally
  Buffer.Free;
end;

Видите ли вы проблему в этом коде?

Утверждение клиента про опцию "Extended memory manager" оказалось не совсем верным: клиент не отключал опцию "When memory is released" - она стояла у него в положении "Fill memory with non-zeros", хотя "отключенная" опция должна стоять в "Do nothing". Из-за этого я довольно долго шёл по ложному пути, который я не буду описывать здесь.

Итак, верные входные данные выглядят так: опция "Extended memory manager" включена, если опция "When memory is released" стоит в положении "Do nothing", то всё работает как надо, а если - в положении "Fill memory with non-zeros", то копируемый растр удаляется.

О чём нам это говорит? Конечно же, это просто кричит об ошибке обращения к данным после их удаления (use after free)!

Но как нам найти баг в коде?

В данном случае сделать это будет весьма не просто.

Проблема состоит в том, что какой-то код читает данные из уже удалённого объекта (или области памяти). А дело-то в том, что в Delphi нет точек останова на чтение данных. На запись - есть, а на чтение - нет. Т.е. если бы какой-то код писал в память удалённого объекта/памяти, то мы могли бы поставить точку останова на данные и просто запустить программу на выполнение, ожидая, когда отладчик остановится на точке останова и ткнёт нас носом в "плохой" код. Но сделать так же для операции чтения мы не сможем.

Как быть?

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

К счастью код выше удаляет не так много участков памяти и сделать это можно за разумное время. Запустите программу, установите точку останова на функции EurekaFreeMem (да, вам понадобится EurekaLog редакции Enterprise - с исходным кодом, в редакции Professional исходного кода нет). Выполните код и отметьте все места, где срабатывает EurekaFreeMem. Иногда также придётся ставить точку останова и на realloc, но в данном случае достаточно точки останова на FreeMem.

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

Дальше вам нужно пройти по коду EurekaLog, пока вы не увидите код вызова очистки памяти. В частности, он вызывается так:

function EurekaFreeMem(P: Pointer): Integer;
// ...
begin
  // ...
      if CheckOurPointer(P, True, True, Error, IsDummy, SharedBlock, Caller) then
  // ...
end;  

function CheckOurPointer(var P: Pointer; const CheckForFree, 
  ClearData: Boolean; out Error: TMemoryError; out Dummy: Boolean; 
  out SharedBlock: Boolean; const AFirstAddr: Pointer = nil): Boolean;
// ...
begin
  // ...
        if ClearData then
        begin
          if (loCatchLeaksExceptions in LeaksOptions) and
             (PtrDummy^.BlockType = btObject) then
            PtrDummy^.Tag := Pointer(P^);

          FillReleasedMem(P, PtrDummy^.SingleSize, { ... });
        end;
  // ...
end;

Т.е. вы можете ставить точку останова не на EurekaFreeMem, а на проверку ClearData или место вызова FillReleasedMem (в функции CheckOurPointer есть два места, где вызывается FillReleasedMem, поэтому можно ставить и на начало FillReleasedMem).

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

Открывайте машинный отладчик (View / Debug Windows / CPU Windows / Entire CPU):

Мы не можем поменять значение ClearData через команду Evaluate / Modify, потому что он передан неизменяемым параметром. Но вы можете поменять его значение на стеке, если вы знаете, как это сделать. Либо вы можете выполнить операцию сравнения и поменять флаг.

В любом случае отладчик теперь должен показать, что проверка провалилась и код будет пропущен:

Итак, продолжите выполнение программы (и отключите все точки останова). Мы только что не стали очищать первый удаляемый блок памяти. Выполните код до конца. Он заработал?

Если нет (а в данном случае - нет), то перезапустите программу, повторите все действия, но только пропустите один вызов EurekaFreeMem и остановитесь на втором. Снова измените проверку, чтобы не вызывать функцию очистки памяти. Запустите программу до конца. Заработала? Если нет, то перезапустите и пропустите два вызова EurekaFreeMem, отключите очистку на третьем. И так далее.

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

В данном случае это оказался TBitmapImage с таким стеком:

Vcl.Graphics.TBitmapImage.Destroy
System.TObject.Free
Vcl.Graphics.TSharedImage.Release
Vcl.Graphics.TBitmap.NewImage
Vcl.Graphics.TBitmap.ReadDIB
Vcl.Graphics.TBitmap.ReadStream
Vcl.Graphics.TBitmap.LoadFromStream
Vcl.Graphics.TBitmap.HandleNeeded
Vcl.Graphics.TBitmap.GetCanvas
Vcl.Graphics.TBitmap.Draw
Vcl.Graphics.TCanvas.StretchDraw

Сам же код удаления выглядит так:

procedure TBitmap.NewImage(NewHandle: HBITMAP; NewPalette: HPALETTE;
  const NewDIB: TDIBSection; OS2Format: Boolean; RLEStream: TStream = nil);
  // ...
begin
  // ...
  EnterCriticalSection(BitmapImageLock);
  try
    FImage.Release; // - удаляется тут
    FImage := Image;
    FImage.Reference;
  finally
    LeaveCriticalSection(BitmapImageLock);
  end;
  // ...
end;

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

Как нам её найти?

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

Для этого я остановился в момент удаления объекта и вычислил через Evaluate / Modify значение Pointer(Self) (если вы стоите внутри TBitmapImage.Destroy), либо Pointer(FImage) (если вы стоите внутри TBitmap.NewImage). Предположим, что это значение равно $2A411E0. Для удобства запишем его в полной форме: $02A411E0.

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

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

К счастью, когда вы выполняете код по F7/F8 в машинном отладчике - он показывает вам (подсветкой) какие регистры были изменены только что выполненной командой. Это немного упрощает отслеживание адресов.

Вам придётся выполните какое-то количество кода, когда вы впервые заметите наше значение:

В данном случае происходит восстановление сохранённых регистров процессора при выходе из процедуры TBitmap.LoadFromStream.

Разумеется, это не означает, что баг в коде находится в методе TBitmap.LoadFromStream. Это означает, что в машинном регистре всё ещё хранится ссылка на уже удалённый объект TBitmapImage и, вероятно, кто-то выше по коду использует этот регистр для доступа к (уже удалённым) данным.

Продолжаем выполнение кода.

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

Код читает поле из объекта, хранящегося в регистре ESI, и загружает это значение в регистр EAX. Обратите внимание, что загруженное значение равно DEADBEEF - это отладочный маркер, которым EurekaLog заполняет удаляемую память. Это ещё раз подтверждает, что вот именно этот код обращается к уже удалённому объекту.

Помимо DEADBEEF вы также можете встретить и другие значения: $CCCCCCCC, $FEEEFEEE, $FDFDFDFD, $FADEDEAD, $00009999. EurekaLog пытается зарезервировать хотя бы один из них для отладочных целей и будет использовать первый, для которого резервирование удалось. Также могут встречаться значения, близкие к ним (т.е. отладочный маркер + смещение, например DEADBE8F).

Кроме того, это может быть и указатель на код, пройдя по которому вы попадёте в начало процедуры DeadObjectVirtualMethodCall или DeadInterfaceMethodCall - это служебный код EurekaLog для отлова вызовов виртуальных методов уже удалённых объектов и интерфейсов. К сожалению, указатели на DeadObjectVirtualMethodCall или DeadInterfaceMethodCall не фиксированы и будут индивидуальны в каждой программе. Возможно, вам стоит выписать их на бумажку заранее при запуске программы, чтобы потом следить, не появятся ли они в регистрах процессора.

В любом случае, мы нашли код, который обращается к уже удалённому объекту. Вот он:

procedure TBitmap.Draw(ACanvas: TCanvas; const Rect: TRect);
// ...
begin
  with Rect, FImage do
  begin
    // ...
        StretchBlt(ACanvas.FHandle, Left, Top, Right - Left, Bottom - Top,
          Canvas.FHandle, 0, 0, FDIB.dsbm.bmWidth,
          FDIB.dsbm.bmHeight, ACanvas.CopyMode);
    // ...        
  end;
end;

Видите ли вы теперь ошибку в коде?

Ошибка состоит в использовании оператора with.

Действительно, использование оператора with заставляет оптимизатор Delphi сохранить ссылку на вычисленное выражение в with куда-то (в данном случае - в регистр ESI). А поскольку речь идёт об объекте (которые хранятся по ссылке, а не по значению), то сохраняются не данные объекта, а лишь ссылка на них. Т.е. любое изменение данных (в том числе - их удаление/очистка) из вызываемых в коде процедур пройдёт незамеченным. В частности:

  // FImage кэшируется оператором with
  with Rect, FImage do 
  // ...
      // FImage удаляется (пересоздаётся), но ссылка на удалённый объект всё ещё хранится в кэше with
      Canvas.RequiredState(csAllValid); 
  // ...
        // FImage.FDIB ссылается на удалённый объект
        StretchBlt(ACanvas.FHandle, Left, Top, Right - Left, Bottom - Top,
          Canvas.FHandle, 0, 0, FDIB.dsbm.bmWidth, 
          FDIB.dsbm.bmHeight, ACanvas.CopyMode);
  // ...

А самая жопа с этим with в том, что отладчик не способен правильно его интерпретировать. К примеру, не работает вычисление выражений по наведению курсора мыши. А если мы попытаемся вычислить значения указанных выражений (например, FImage.FDIB.dsbm.bmWidth), то отладчик, конечно же, вернёт вам корректное значение от нового объекта FImage, а не от удалённого старого, что сохранён оператором with.

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

Итого: проблема оказалась в баге в VCL. Поздравления клиенту!

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

К счастью, в данном случае можно предложить обходной путь. Для этого нам нужно вынести пересоздание FImage вне блока with. Например:

Buffer := TBitmap.Create;
try 
  Bitmap.Canvas; // - добавлено
  Buffer.SetSize(64, 64);
  Buffer.Canvas.StretchDraw(Rect(0, 0, 64, 64), Bitmap); 
  Bitmap.SetSize(64, 64);
  Bitmap.Canvas.Draw(0, 0, Buffer); 
finally
  Buffer.Free;
end;

Если же предложить обходной путь не удаётся, то остаётся только отключать проверки памяти в EurekaLog.

Мораль истории:

• Не используйте with;
• Если вы имеете проблему памяти и в коде есть with - перепишите код без него;
• В VCL тоже есть ошибки;
• Если в вашей программе "возникают" ошибки после добавления в неё EurekaLog - попробуйте отключить проверки памяти в EurekaLog. Если после этого проблема уходит - 99%, что в вашей программе есть баг с памятью.

P.S. Вы можете проголосовать за исправление бага тут: [RSP-38694] Using "with" in VCL causes "use after free" bugs.