Программист
0,5
рейтинг
30 июля 2015 в 17:52

Разработка → Когда программа падает только по средам перевод

Откиньтесь на спинку кресла и отдохните – пришло время рассказать об одном из моих самых любимых багов.

Это была моя самая первая работа в сфере IT – летняя практика в компании, разрабатывающей очень серьезное медицинское оборудование, в частности системы подачи анестезии и мониторы для пациентов больниц. Монитор для пациента – это такая попискивающая коробка рядом с лежачим больным, которая меряет пульс, давление, частоту дыхание и прочее, а также оповещает медсестер в случае неприятностей. Офис был полон двухметровых баллонов с веселящим газом, по нему расхаживали роскошнобородые гуру-эксперты по встраиваемым системам, и были целые комнаты-хранилища специально для документации, необходимой для сертификации различного оборудования. Народ до сих пор шепотом рассказывал об одном баге, пропущенном тестировщиками с десяток лет назад, из-за которого система подачи анестезии перезапустилась посреди операции. Стоит ли говорить, что зеленого сопляка-студента вроде меня и за километр бы не подпустили к боевым системам?

Вместо этого мне поручили проект-прототип с целью опробовать в действии самые горячие технологические новинки 1997 года – сервер на C++, который бы слушал мониторы по последовательному порту, сливал интересные данные в базу на SQL Server и отправлял их на Java-апплет через CORBA, чтобы доктора и родственники могли следить за самочувствием больного через интернет. Красота же! Особенно с учетом того, что практического опыта у меня не было ни с одной из этих систем и технологий!

После нескольких недель адского костылестроения, преимущественно потраченных на курение мануалов от Visibroker ORB и утомительное вылавливание ошибок приведения типов, моя система «Симпсон» была более-менее готова. Сервер «Гомер» сохранял и выдавал данные, а клиент «Барт» отображал их для пользователя. За это время я узнал, что CORBA – безнадежно перемудрена, AWT – это жесть (GridBagLayout-ы, бррр!), апплеты работают с черепашьей скоростью – но в остальном Java вроде неплохой язык. Беспокоил только один мелкий баг – время от времени сервер на С++ падал, и я решил выяснить причину.

Поскольку в соседней комнате у нас был тестовый стенд с настоящим монитором, во время разработки и тестирования я пользовался крайне удобным «демо-режимом», радостно воспроизводящим по кругу имитацию сердечного приступа. В этом режиме мой сервер ни разу не упал – он делал это иногда во время ручного управления монитором, особенно во время показов, но хоть ты тресни, я не мог добиться стабильного воспроизведения сбоя. Я добавил логирование ко всем событиям, бегал туда-сюда между монитором и своим рабочим местом, медленно и вдумчиво воспроизводя необходимые шаги («установите фильтр в X, поверните ручку управления ровно на три деления по часовой, нажмите сюда…»), но падение не воспроизводилось. Чем бы ни было это «злобное событие», как я его прозвал, оно избегало любого логирования! Может быть, проблема была в I/O или на уровне железа? Может быть, космические лучи сбрасывали биты в памяти моего компьютера?

Несколько недель бесплодных экспериментов привели меня в полное отчаянье. Я докатился до того, что добавил вывод printf после каждой чертовой строчки кода между получением данных из последовательного порта и записью их в базу данных… и в процессе, просмотрев каждую из этих строчек по много раз, до меня вдруг дошло.

Когда я описывал схему базы данных, в необъяснимой попытке сэкономить место, я по глупости и малолетству использовал timestamp события в качестве первичного ключа. Если два события придут в одну и ту же миллисекунду, база выкинет исключение о нарушении уникальности. Я обнаружил это довольно рано, но подумал, что это может произойти только в каких-то совсем странных случаях, когда кто-то копается во внутренних настройках монитора, и с чистой совестью обернул этот код в try/catch с логированием ошибки.

Но! Код логирования был написан в олдскульном стиле, и текст ошибки записывался в строковой буфер длиной 80 символов. Сообщение о нарушении уникальности ключа всегда было одинаковым, однако перед ним ставилась дата в расширенном формате на английском, типа такого:

Monday, July 17, 1997, 10:38:47.123


У названий дней на английском есть забавное свойство:
Название Длина в символах
Sunday 6
Monday 6
Friday 6
Tuesday 7
Thursday 8
Saturday 8
Wednesday 9
Уже догадались?

В среду, и только в среду, если кто-то изменял определенные настройки монитора определенным образом, два события могли произойти одновременно и вызвать сбой в базе данных. А сообщение об ошибке получалось длиной ровно 81 байт (включая нулевой символ), переполняло буфер и вызывало падение всей системы!

С тех пор я усвоил три вещи. Во-первых, всегда использовать автоинкрементный первичный ключ в любой потребовавшейся мне таблице. Во-вторых, логировать дату в формате ISO – YYYY-MM-DD, без дней недели. Но самое главное – даже у самого случайного и непредсказуемого бага есть логичное объяснение, и его можно найти, если копнуть достаточно глубоко.
Перевод: Jani Patokallio
@impwx
карма
119,0
рейтинг 0,5
Программист
Реклама помогает поддерживать и развивать наши сервисы

Подробнее
Реклама

Самое читаемое Разработка

Комментарии (41)

  • +37
    Всё равно 1 августа программа превратилась бы в тыкву, чего уж тут на среды жаловаться.
    • +1
      Неа.
      Friday всего 6 символов, даже если бы выводилось «01» вместо «1», то краша всё равно не было бы.
      А вот 2ое или 3ье августа, это да.
      • –1
        Дело не в пятнице.
        1е августа 2015- суббота.
        Saturday = 8символов.
        Да еще и название месяца не короткое July(4), а длинное August(6). Про September(9) я вообще молчу
        • +3
          А 1е августа 1997?
          • +13
            Да, вы правы. В августе программа бы работала аж три дня в неделю. А вот в сентябре её бы окончательно накрыло.

            Вывод: не затягивайте со сроками сдачи =)
  • +2
    >>и его можно найти, если копнуть достаточно глубоко
    Например потратить неделю на отладку. Почти всегда это непозволительная роскошь.
    • +3
      Автор говорит, что можно, а уж нужно или нет — решать вам.
      • +1
        ну если ресурсы не ограничены, то тут так то да, вообще никаких преград нет. Нет исходных кодов? Есть дизасемблер, не знаешь асм, не беда его можно изучить и вернуться к вопросу. Слишком много кода? Можно нанять помощников, ну и тд
        • +4
          Если в результате багов будут теряться миллионы, или хуже того — умирать люди, о «непозволительной роскоши» придётся рассказывать не в комментариях
          • 0
            +1
            Насколько я помню, для такого рода систем даже вводят формальные доказательства корректности программ. Что очень накладно по времени.
            • 0
              Зачастую верификация просто невозможна. Если говорить за life-critical embedded, то, например, когда программа работает на неидельной железке (что всегда так, вопрос вероятностей сбоев) у которой есть пачка аппаратных багов, бывают flip'ы битов памяти и т. п. казусы, защищаются всякими watchdog'ами, дополнительным контролем, использую мажоритарное принятие решения системой и прочее. А от части человеческих ошибок стараются защититься всякими стандартами типа MISRA C.
  • +29
    Из той же серии: OpenOffice не печатает по вторникам bugs.launchpad.net/ubuntu/+source/cupsys/+bug/255161/comments/28
    • +2
      Занимательный пример криптоархеологии.
  • +3
    Честно говоря, теперь страшно ложиться в больницу — оно-то и раньше было не особо спокойно было, а теперь и на технику надежды нет… Вдруг и сегодня кто-то использует последнее слово в программировании?!
    • +13
      Вспоминается ужасающий баг в Therac-25.
      • 0
        Блин, они там это все еще и на асме писали.
    • +8
      то есть до этой истории вы об этом даже не подозревали?)
    • +1
      Если б вы знали, как делается промышленная автоматика (и, собственно, не только промышленная, а в целом) — вам было бы страшно выходить на улицу вообще
    • 0
      Если бы вы только знали КТО пишет автопилоты к самолетам…
  • +19
    У меня была похожая история: проект не собирался по понедельникам.
  • 0
    В заголовке забыли поставить вопросительный знак :)
  • +7
    и его можно найти, если копнуть достаточно глубоко.

    Самого главного не усвоил — копать надо экскаватором или на худой конец лопатой. Для поиска причины падений обычно используют core-dumps / отладчик / стек-трейс. Такая элементарная ошибка была бы видна на первом же трейсе — segfault во время вызова printf (использования printf при разработке на c++ — вообще отдельный вопрос).
    • +3
      Тоже подумал что stack trace должен был сразу помочь
  • –4
    Жаль тогда не было valgrind-а, шикарный инструмент, такие баги влёт отлавливает.
  • +21
    Раз начали делиться историями, то и я напишу. Однажды перестал собираться проект в TFS. Причем как перестал — очень странно. Билд просто не начинался, ошибка возникала непосредственно при попытке запуска, выдавая диалоговое окно, сообщающее про конфликт первичного ключа. Причем иногда все-таки работал — так и жили. Пытались запустить до тех пор, пока вдруг не получалось.

    Искал я причину в интернете долго (два месяца) — но в итоге догадался декомпилировать код сервера, чтобы посмотреть где же он падает. Выяснил, что падает в хранимой процедуре. Декомпилировать хранимую процедуру было куда сложнее: она была шифрованной, а программа для расшифровки — шароварной. А триальном же режиме программа расшифровывала лишь первые 200 байт — и в них не вмещался даже заголовок хранимки.

    Что мешало программу купить — уже не помню. То ли были серьезные подозрения на кота в мешке, то ли не было возможности перевести автору деньги, то ли денег не было, но наверное просто жаба душила платить довольно крупную сумму за программу для разовой работы с неизвестной заранее пользой. Коллега за ночь взломал защиту той программы, и удалось продолжить исследования.

    Выяснилось, что все билды в TFS лежат в одной таблице, первичным ключом билда при этом является его имя. И это самое имя присваивается билду аж три раза. Сначала создается запись в БД с автоинкрементным числом вместо имени, потом это число заменяется на временное имя вида BuildDefinitionName.20150730.5
    Третий раз имя билда меняется уже в процессе самого построения, в процессе выполнения задачи AssignBuildName.

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

    Теперь в чем была проблема. Дело в том, что мы присваивали нашим билдам имена на основе нашего собственного автоинкрементного счетчика версий. Причем, поскольку мы мигрировали с другой системы построения, а не начинали проект сразу в TFS — наши номера билдов начинались где-то с 1900. И, спустя полгода после миграции, внутренний счетчик билда TFS дошел до этой цифры. Тогда-то все и началось!

    Когда причина проблемы стала ясна, решилась проблема очень просто: я просто стал добавлять префикс «b» всем билдам, плюс добавил его всем старым билддам в БД простым UPDATE. После этого все заработало. С тех пор я полюбил смотреть в чужие исходники, и часто обращаюсь именно к этому способу решения мистических проблем…
  • +21
    Эта статья могла уместиться в 3-4 предложения. Бывают же такие любители рассказать поинтересней.
  • –10
    Что ж, бывает. «Протоны», например, 16 мая падают. Не иначе по аналогичной причине.
    • –6
      Всё ясно. Чёрный юмор тут не любят.
      • +1
        скорее неуместный
  • 0
    Когда читал: «Несколько недель бесплодных экспериментов привели меня в полное отчаянье. Я докатился до того, что добавил вывод printf после каждой чертовой строчки кода между получением данных из серийного порта и записью их в базу данных… » — я прям представлял, как вы злились и чувствовали себя.
    К сожалению, подобного рода ситуации встречаются с каждым программистов, даже при использовании уже отточенной для себя технологии.
  • –6
    Поведаю об одном интересном баге, который правил недавно, и в котором отчасти виноват лично ДА Медведев:

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

    Отправляется заявка на сервер, в ней передается время. Если в течении минуты никто не вызвал игрока — то заявка снимается. Долго не мог понять, дело оказало в следующем: оказалось что UTC time в один и тот же момент времени возвращает разные значения. В зависимости от версии iOS. На старых iOS был еще перевод на летнее время, потом этот балбес Медведев начал крутить стрелки, вышла новая версия, потом еще из думы руки приложили переведя стрелки еще раз. Естесвенно программисты в Apple это предугадать не могли и каждая версия iOS переходит (или не переходит) на летнее время по разному. В результате всякие уведомления и напоминания на старой версии приходят с разницей в час, ну и в игре у нас заявка приходила уже устаревшей (на час) и сразу снималась. То, что GetTimeUTC может вернуть разные значения и его нельзя использовать для синхронизации — для меня было открытием.

    Рассказал жене — они грит на работе у них программисты сталкивались с похожим багом, тоже нелестно отзывались о крутителях стрелок.
    • +4
      То есть, вы на веру принимаете время, переданное с клиента?
      • 0
        Там используется Photon (который не сервер, обычный) — то есть там обеспечивается взаимодействие и обмен данными между клиентами, сервера как такового нет. Сервер просто тиражирует заявку всем клиентам, передает её. Получается что да, но там иначе не сделаешь, или надо лицензию на сервер покупать.
        • +1
          Отправляется заявка на сервер, в ней передается время. Если в течении минуты никто не вызвал игрока — то заявка снимается
          Тогда вопрос – заявка снимается кем именно? Самим клиентом? или «тиражирующим» сервером?
          Если самим клиентом – тогда в чём проблема, в пределах одного клиента время будет правильным.
          Если сервером – то снова встаёт вопрос о том, зачем нужно передавать время с клиента.
          • +1
            Сервера нет (вернее он просто соединяет клиентов, пересылая данные). У каждого клиента она считается не актуальной — так наверно правильнее сказать.
            • +4
              Т.е. если у человека на телефоне выставлено неправильное время — он так никогда сыграть в вашу игру и не сможет?
              • 0
                в gotomeeting такая же проблема, если на винде время указано неправильное, то подключиться не удастся
  • 0
    Бгг, когда то столкнулся с кодом, который начинал падать после пары недель работы, коллега который к тому времени уже уволился, любил писать код:
    char buffer[48];
    sprintf(buffer, "insert into aaa(f1,f2,f3) values(%d,%d,%d)", index1, index2, index3);
    

    Он не учитывал, что 32битный инт в десятичном представлении мог занимать до 11 символов (-2147483647).
  • 0
    Повезло Вам с летней практикой! Я вот сотню ADSL-модемов тестировал на работоспособность, просто выходя через них в инет(
  • 0

Только зарегистрированные пользователи могут оставлять комментарии. Войдите, пожалуйста.