суббота, 21 марта 2015 г.

Про ошибки и про то, как они обнаруживаются... внезапно

Каждый программист сталкивается в процессе своей трудовой деятельности с целым рядом кошмарных проблем. Округление финансовых данных, работа с датами, кодировки текста - это лишь малый перечень того, с чем приходится бороться поколениям программистов. И, как каждый приличный кошмар, эти программистские кошмары имеют нехорошую привычку возвращаться. Один из таких comeback-ов я наблюдал совсем недавно. Есть такое известное выражение: "Эта штука сильнее, чем "Фауст" Гёте". Так вот, запаслись попкорном? Тогда начнем...

Не секрет, что работа программиста редко бывает связана только с одной какой-либо технологией. Чаще всего, намешано, бывает, не меньше, чем в винегрете. Вот и в описываемом случае, смешались в кучу кони, люди... А именно, криптография (с использованием CAPICOM), Delphi, БД Oracle, Java, 1С. Но, обо всем по порядку.
 
Имеем следующую последовательность действий: некий документ, созданный и сохраненный в 1С, должен быть подписан. Подписание производится при помощи сервиса, написанного на Delphi и крутящегося на машине с Windows. Windows упоминается тут не просто так - подписание производится с помощью CAPICOM. Сервис следит за данными, которые размещаются в таблицах базы данных (Oracle). Данные в эти таблицы записывает программа, написанная на Java, предварительно забрав их из 1С с помощью Web сервиса и FTP сервера. Хороша солянка?
 
Далее, после подписания информация о подписи сохраняется в базе сервиса, а сами подписанные данные уходят, тоже при помощи Java кода, в другую подсистему. Там они вновь подписываются, теперь уже в Internet Explorer при помощи JavaScript и все того же CAPICOM, и отправляются обратно в 1С. По пути эти подписанные данные опять проходят через базу данных Oracle, где их все также поджидает сервис на Delphi, который, на этот раз, с помощью... правильно, CAPICOM, проверяет валидность подписей. Результат проверки опять сохраняется в БД сервиса, и, вместе со всеми остальными данными, при помощи Java модуля и web сервиса, доставляется в 1С, где сохраняется в БД MS SQL (1С у нас работает на ней), после чего показывается  пользователям. Круговорот завершен.
 
По факту, после всех этих перипетий, пользователю должна быть показана информация о двух подписях. Иногда путь документа начинается не в 1С, а в другой системе, тогда подписей может быть больше.
 
"Ну и в чем тут может быть проблема?" - спросите вы. Проблема, и не одна, конечно, может скрываться где угодно, но, в этом конкретном случае, вызывало удивление количество показываемых пользователям подписей и данных по ним.

В некоторых случаях, не всегда, а лишь в некоторых случаях, количество показанных пользователю подписей оказывалось больше, чем следовало бы. Часть подписей, как бы, задваивалась. У таких подписей все было одинаковым, все, кроме даты подписания. И даты эти отличались на одну секунду. Когда что-то такое происходит, сразу возникает подозрение на ошибки округления. Но вот где, и, главное, почему они возникают?
 
Ответ на вопрос, почему подписей больше, чем нужно, был получен довольно быстро - для отображения использовался запрос к БД 1С, который содержал конструкцию GROUP BY, куда было включено, помимо других полей, и поле с датой подписания. Сразу становится понятным, что если у записей совпадут значения всех полей, используемых для группировки, то записи будут представлены, как одна, а если значения не совпадут - получим в выборке столько записей, сколько уникальных значений хранится в полях.
 
Вообще-то, система была устроена таким образом, что в 1С всегда передавалась информация обо всех подписях. Лично я был уверен, что разработчики, колдующие над 1С, будут показывать информацию только из последней загрузки. Но они пошли другим путем, и у них, возможно, были на то свои причины. И лишь благодаря этому их решению, мы и узнали о том, что одна и та же, по сути, подпись, попадает в 1С с разной датой подписания.
 
Дальнейший разбор полетов привел к пониманию того, что различие также наблюдалось и в БД сервиса, ответственного за подписание и проверку подписей, то есть, в Oracle. Причем, дата в записи, которая соответствовала подписанию, была меньше на секунду, чем дата в записи, соответствующей проверке подписи.
 
После этого внимательно посмотрели на код Delphi. При подписании, сам момент подписания определялся очень просто - вызывалась функция Now, возвращающая текущее системное время. Именно это время передавалось и в CAPICOM - для установки атрибута времени подписания, и в БД Oracle - для сохранения информации о подписи. При проверке же подписей, информация целиком и полностью получалась из CAPICOM и затем записывалась в БД. И в этой информации время подписания  было на секунду больше, чем время, сохраненное в момент подписания.
 
Следующий шаг - решили посмотреть дамп самой подписи и выяснили, что время там лежит такое, как и в результатах, возвращаемых при проверке. То есть, источник проблемы скрывался где-то в коде, так или иначе связанным с подписанием. Поэтому соответствующие места в программе на Delphi, да и в БД Oracle, были подвергнуты более тщательному изучению. И это дало свои плоды. Вот что удалось выяснить.
 
Для определения времени подписания использовалась функция Delphi Now. Оставим в стороне вопросы, связанные с обоснованием такого решения и значимостью получаемого результата, нам важно сейчас разобраться в технических деталях того, что происходит с полученным временем. Итак, используемая функция возвращает дату и время, причем время возвращается с миллисекундами. Это время, как уже упоминалось, передается в CAPICOM. Но в данных подписи в ASN.1 формате лежит время с точностью до секунд. Опытным путем было выяснено, что CAPICOM округляет время согласно обычным правилам округления: если миллисекунд больше, чем 500, записывается на одну секунду больше, если меньше - миллисекунды просто отбрасываются. Опыты покрыли не весь возможный набор значений, поэтому обобщений по поводу того, как округляется ровно 500 миллисекунд, я делать не буду. Но это не так уж и важно, гораздо важнее сам факт округления значений. Еще более существенные вещи были обнаружены при исследовании таблиц в БД Oracle.
 
Оказалось, что, не смотря на то, что большинство полей, используемых для хранения даты и времени, имели тип TIMESTAMP, именно поля для хранения даты и времени подписания имели тип DATE. А ведь известно, что поля этого типа в Oracle хранят значения с точностью до секунд, причем при попытке записи времени с миллисекундами, последние просто отбрасываются.
 
Вот она, первопричина бед. При подписывании одно и тоже время передается в два разных компонента: в CAPICOM и в БД Oracle. И компоненты эти работают с переданным в них временем совершенно по разному. Один - CAPICOM - округляет миллисекунды, а второй - Oracle - миллисекунды отбрасывает. При проверке подписей таких проблем нет, так как время подписания берется из самой подписи, без миллисекунд, и сохраняется в БД в поле с типом DATE без преобразований - миллисекунд-то нет!
 
Решение тоже нашлось практически мгновенно: в получаемом при помощи функции Now времени стали просто округлять миллисекунды до секунд. И уже такое, обработанное, без миллисекунд, время стали передавать и в CAPICOM, и в БД Oracle, лишая их возможности обработать его по разному.
 
Вообще, это удивительная история. Ошибка с отличием времени подписания, сохраняемого в БД, от времени подписания, сохранённого в самой подписи, жила в софте не один год. Может быть, она не была так уж критична? Возможно, хотя, это, все-таки, рассогласование данных. Ведь, как только их стали активнее использовать, на несоответствие сразу обратили внимание. Сама ошибка, по природе своей, плавающая, зависящая от данных. Обнаружилась она тоже благодаря случаю - не совсем ожидаемому алгоритму отображения этих самых данных в сопряженной системе. В общем, удивительное - рядом! Но вся эта история показывает, насколько важно быть предельно внимательным с одними и теми же данными, которые хранятся в различных технологических компонентах сложных систем, а также с данными, которые пересекают границы взаимосвязанных подсистем. А это, в свою очередь, доказывает необходимость тщательного, глубокого и досконального проектирования, чтобы не возникало ситуаций, высмеянных гениальным комиком: - "К пуговицам претензии есть? К пуговицам претензий нет".

Комментариев нет:

Отправить комментарий