Делфи ошибка 105

Недавно я столкнулся с интересным случаем. Ребята из подразделения эксплуатации завели в mantis тикет, описывающий сценарий работы одной из программ, который не укладывался в их понимание правильной картины мира. С моей точки зрения все выглядело немного сумбурно и не очень логично. В общем, опишу немного саму ситуацию и предысторию.

Программа, которая вызвала нарекания, была написана давно, еще на заре автоматизации компании, в которой я сейчас работаю. Она была предназначена, если уж совсем упрощать, для перекладывания файлов. Ну, то есть, пользователи выкладывали файлы в определенные каталоги. Эти файлы надо было обнаружить, систематизировать, основываясь на определенным образом составленных именах файлов, в зависимости от результата систематизации обработать, например, подписать, и выложить на FTP, попутно создав в БД записи об обработанных файлах. Все это делалось для того, чтобы другой софт, используя записи в БД, мог генерировать странички, которые показывались пользователям, и, в случае необходимости, отдавать содержимое с FTP сервера.

Изначально, часть этой работы выполнял shell-скрипт, но, как это обычно и бывает, постепенно возникали все новые и новые «хотелки», и, в конце концов, скрипт переписали на Delphi 6. Заодно, запихали в БД нормативно-справочную информацию и создали программу для работы с ней. Правда, при этом потребовали от этой программы и GUI интерфейс и возможность выполняться в качестве консольного приложения. Дело в том, что программу использовали два типа пользователей: первые — обычные работники, которым нужен был графический пользовательский интерфейс; вторые — сотрудники службы эксплуатации, которые хотели продолжать использовать программу в режиме «малой» автоматизации, примерно так, как раньше использовался shell-скрипт. Этим вторым GUI только мешал. Поэтому автору пришлось пойти на хитрость. Он указал, что приложение является консольным (выставив соответствующую опцию ConsoleApp=1). И при этом, не стал отказываться от инициализации визуального фреймворка (далее идет код из dpr файла):

begin
  Application.Initialize;
  Application.Title := 'Название программы';
  Application.CreateForm(TdmMain, dmMain);
  Application.CreateForm(TfmMain, fmMain);
  Application.Run;
end.

Если при запуске обнаруживались параметры командной строки, на экране не показывались окна, диалоги и другие элементы графического интерфейса, просто в обработчике OnCreate главной формы выполнялся нужный метод (btnPublish.Click;) и работа завершалась.

    if SilentRun then begin
      btnPublish.Click;
      WriteToLog('END');
      Application.Terminate;
    end;

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

Но, довольно истории, вернемся к возникающей ошибке, вернее, к ошибкам. Это именно то, что и смущало меня: работники службы эксплуатации сообщали о двух разных ошибках: одна — socket error #11002, а другая — I/O error 105. Первая — про невозможность доступа к FTP, вторая — про попытку писать в файл, открытый для чтения. И да, сообщали об этих ошибках разные люди.

Для начала, я решил выяснить, почему одни сотрудники сообщают об обычной ошибке, возникающей при работе с FTP, а другие ссылаются на совершенно другую ошибку, к FTP, скорее всего, отношения не имеющую? После долгих расспросов выяснилось, что каждый из этих сотрудников смотрит в свой лог. Оказалось, что программа ведет три лога: один — в БД, второй (очень похожий на первый по содержанию) ведется в памяти, а по завершении работы отправляется по почте, и третий — ведется в обычном текстовом файле. Так вот, те сотрудники, которые сообщали об ошибке ввода/вывода, смотрели в лог, присланный по почте, а те, которые жаловались на ошибку при работе с FTP, смотрели в лог, ведущийся в текстовом файле.

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

Ладно, глаза боятся, руки делают — стал я изучать исходный текст, программа-то не моя. Тактика была простой: найти места, выдающие ошибки. Довольно быстро выяснилось, как выдается ошибка работы с FTP. Ошибка возникала практически сразу при старте: делалась попытка подключения к серверу, а так как эксплуатация указала для этого неверные данные, то подключение срывалось, продолжение работы становилось бессмысленным, о чем и сообщалось записью в текстовый лог, после чего выполнение прерывалось вызовом процедуры Delphi Halt(1);.

...
if SilentRun then
          MyHalt('Ошибка подключения к FTP-серверу '+ edtFTPServerTo.Text+':'+#10+e.Message)
        else
          ErrorBrk('Ошибка подключения к FTP-серверу '+ edtFTPServerTo.Text+':'+#10+e.Message);
...
procedure TfmMain.MyHalt(msg: String);
begin
  MyWriteln(msg);
  SendMail(resError);
  ASP_LogEvent('', cProgName, 'Publish', ASP_logTypeGUI, ASP_logSeverityError, msg, msg, '');
  Halt(1);
end;
...

Логика проста и понятна. Но откуда бралось сообщение об ошибке ввода/вывода в логе из электронного письма?

Продолжение исследования выявило тот факт, что такого текста I/O error 105 для логирования ошибок в программе не предусмотрено. Этот факт позволил сделать предположение, что в исходном тексте есть место, которое перехватывает необработанные исключительные ситуации, и логирует их текст «как есть». И действительно, такое место нашлось, и, что самое интересное, после логирования и отправки письма, работа программы не прерывалась вызовом процедуры Halt, выполнение просто заканчивалось как ни в чем не бывало!

...
except
    on e: exception do begin
      regexp.Free;
      keys.Free;
      if IdFTP.Connected then IdFTP.Disconnect;
      IdFTP.Free;
      if UserCanSign then
        CryptoCOM := nil;
      ASP_LogEvent('', cProgName, 'Publish', ASP_logTypeGUI, ASP_logSeverityError, e.Message, e.Message, '');
      DisableStop;
      MemoLog({FormatDateTime('dd.mm.yyyy hh:nn:ss', Now) + ': }'Ошибка: ' + e.Message);
      PrintTotals;
      SendMail(resError);
    end;
  end;
...

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

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

...
procedure TfmMain.MyWriteLn(msg: String);
var TextOEM: PChar;
begin
  WriteToLog(msg);
  GetMem(TextOEM, Length(msg) + 1);
  try
    CharToOem(PChar(msg), TextOEM);
    Writeln(TextOEM);
  finally
    FreeMem(TextOEM);
  end;
end;
...

При этом, вызов этой процедуры осуществлялся только в режиме без GUI — присутствовали все необходимые проверки. То есть, единственным местом, в котором могла возникнуть исключительная ситуация, был вывод в консоль (на самом деле, это, конечно, не единственный возможный источник, но для других выводились бы более явные ошибки). Если бы именно тут и происходила ошибка, то процедура Halt не выполнялась бы, управление передавалось в блок обработки исключительных ситуаций, там формировалось бы сообщение об ошибке, которое, вместе с остальным журналом работы, и посылалось бы в письме. Идеальный кандидат найден. Теперь осталось понять, что это за зверь такой: ошибка ввода/вывода 105.

Непродолжительный поиск в интернете практически сразу вывел на схожую проблему у одного из пользователей Stack Overflow. Из обсуждения стало понятным, что проблема кроется именно в «двуличной» природе программы — попытка предоставить и GUI интерфейс, и дать возможность работать в качестве обычного консольного приложения, к сожалению, не удалась. Все в соответствии с пословицами и поговорками. Для меня осталось загадкой лишь то, как могла данная ошибка вылезти только что, после стольких лет эксплуатации. Ведь наверняка это был не первый случай проблем с коннектом к FTP серверу. Скорее всего, такие сбои происходили и раньше, но либо в их природе так и не смогли (не захотели?) разобраться, либо просто игнорировали. Либо что-то, все-таки, отличало данный конкретный случай от многих других. Но то нам не ведомо.

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