Фольклор программистов и инженеров (часть 1)

в 7:00, , рубрики: Блог компании NIX, инженерные системы, истории из жизни, Программирование, фольклор, Читальный зал

Фольклор программистов и инженеров (часть 1) - 1

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

Аллергия автомобиля на ванильное мороженое

История для инженеров, которые понимают, что очевидное не всегда является решением, и что насколько бы факты ни казались неправдоподобными, это всё равно факты. В подразделение Pontiac Division корпорации General Motors поступила жалоба:

Пишу вам второй раз, и не виню вас в том, что вы не отвечаете, ведь это звучит безумно. У нашей семьи есть традиция: каждый вечер после ужина есть мороженое. Сорта мороженого каждый раз меняются, и поужинав, вся семья выбирает, какое мороженое нужно купить, после чего я еду в магазин. Недавно я купил новый Pontiac, и с тех пор мои поездки за мороженым превратились в проблему. Видите ли, каждый раз, когда я покупаю ванильное мороженое и возвращаюсь из магазина, машина не заводится. Если я приношу любое другое мороженое, машина заводится без проблем. Хочу задать серьёзный вопрос, вне зависимости от того, насколько глупо это прозвучит: «Что такого есть в Pontiac, из-за чего он не заводится, когда я приношу ванильное мороженое, но при этом легко заводится, если я приношу мороженое с другим вкусом?».

Как вы понимаете, президент подразделения отнёсся к письму скептически. Однако на всякий случай отправил инженера проверить. Тот был удивлён, что его встретил обеспеченный, хорошо образованный мужчина, живущий в прекрасном районе. Они договорились встретиться сразу после ужина, чтобы вдвоём съездить в магазин за мороженым. В тот вечер было ванильное, и когда они вернулись в машину, та не завелась.

Инженер приезжал ещё три вечера. В первый раз мороженое было шоколадным. Машина завелась. Во второй раз было клубничное мороженое. Машина завелась. На третий вечер он попросил взять ванильное. Машина не завелась.

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

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

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

Мораль: даже совершенно безумные проблемы иногда бывают реальными.

Crash Bandicoot

Переживать такое болезненно. Как программист, ты привыкаешь обвинять свой код в первую очередь, во вторую, в третью… и где-то в десятитысячную очередь обвиняешь компилятор. И ещё ниже по списку уже обвиняешь оборудование.

Вот моя история о баге железа.

Для игры Crash Bandicoot я написал код для загрузки и сохранения на карту памяти. Для такого самодовольного разработчика игр это было словно прогуляться по парку: я считал, что работа займёт несколько дней. Однако в результате отлаживал код шесть недель. Попутно я решал и другие задачи, но каждые несколько дней на несколько часов возвращался к этому коду. Это была агония.

Симптом выглядел так: когда сохраняешь текущее прохождение игры и обращаешься к карте памяти, почти всегда всё проходит нормально… Но иногда операция чтения или записи завершается по таймауту без какой-либо очевидной причины. Короткая запись зачастую повреждает карту памяти. Когда игрок пытается сохраниться, он не только не сохраняется, но ещё и рушит карту. Блин.

Спустя некоторое время наш продюсер в Sony, Конни Бус, начала паниковать. Мы не могли отгрузить игру с таким багом, и спустя шесть недель я не понимал, в чём причина этой проблемы. Через Конни мы связались с другими разработчиками PS1: кто-нибудь сталкивался с подобным? Нет. Ни у кого не было проблем с картой памяти.

Когда у тебя нет идей по отладке, то практически единственным подходом остаётся «разделять и властвовать»: убираешь всё больше и больше кода из ошибочной программы, пока не остаётся сравнительно небольшой фрагмент, при работе которого до сих пор возникает проблема. То есть отрезаешь от программы по куску, пока не остаётся та часть, что содержит баг.

Но дело в том, что очень трудно вырезать куски из видеоигры. Как её запускать, если ты убрал код, эмулирующий гравитацию? Или отрисовывающий персонажей?

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

Короче, я это сделал. Удалял всё новые и новые куски кода, пока не остался начальный код, который настраивает систему для запуска игры, инициализирует оборудование для отрисовки и т.д. Конечно, на этой стадии я не мог сделать меню сохранения и загрузки, потому что пришлось бы делать заглушку для всего кода, отвечающего за графику. Но я мог притвориться пользователем, который использует (невидимый) экран сохранения и загрузки и просит сохранить, а потом записать на карту памяти.

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

В какой-то момент, вероятно, в три утра, мне в голову пришла мысль. Операции чтения и записи (ввода-вывода) подразумевают точное время выполнения. Когда работаешь с жёстким диском, картой памяти или Bluetooth-модулем, низкоуровневый код, отвечающий за чтение и запись, делает это в соответствии с тактовыми импульсами.

С помощью часов устройство, которое не связано напрямую с процессором, синхронизируется с исполняемым в процессоре кодом. Часы определяют частоту бодов — скорость передачи данных. Если с таймингами возникает путаница, то также путается либо оборудование, либо ПО, либо они оба. И это очень плохо, потому что данные могут повредиться.

А вдруг что-то в нашем коде путает тайминги? Я проверил всё, что с этим связано, в коде тестовой программы, и заметил, что мы задали программируемому таймеру в PS1 частоту 1 кГц (1000 тактов в секунду). Это довольно много, по умолчанию при запуске приставки он работает с частотой 100 Гц. И большинство игр использует именно эту частоту.

Энди, разработчик игры, задал таймеру частоту 1 кГц чтобы движения вычислялись точнее. Энди склонен к чрезмерности, и если мы эмулируем гравитацию, то делаем это настолько точно, насколько возможно!

Но что если ускорение таймера как-то повлияло на общий тайминг программы, а значит и на часы, которые регулируют частоту бодов для карты памяти?

Я закомментировал код с таймером. Ошибка больше не повторялась. Но это не означает, что мы её исправили, ведь сбой возникал случайным образом. А вдруг мне просто повезло?

Через несколько дней я снова экспериментировал с тестовой программой. Баг не повторялся. Я вернулся к полной кодовой базе игры и изменил код сохранения и загрузки так, чтобы программируемый таймер сбрасывался в исходное значение (100 Гц) перед обращением к карте памяти, а затем снова возвращался к 1 кГц. Сбоев больше не возникало.

Но почему так произошло?

Я снова вернулся к тестовой программе. Попробовал найти какую-то закономерность в возникновении ошибки при таймере в 1 кГц. В конце концов я заметил, что ошибка возникает, когда кто-то играет с контроллером PS1. Поскольку сам я редко это делал бы — зачем мне контроллер при тестировании кода сохранения и загрузки? — то я и не замечал этой зависимости. Но однажды один из наших художников ждал, когда я закончу тестирование, — наверняка в тот момент я ругался, — и нервно крутил контроллер в руках. Возникла ошибка. «Погоди, что?! Ну-ка сделай так снова!».

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

Я пришёл к Конни и рассказал о своём открытии. Она передала информацию одному из инженеров, проектировавшему PS1. «Невозможно, — ответил он, — это не может быть аппаратной проблемой». Я попросил Конни устроить нам беседу.

Инженер позвонил мне, и мы поспорили с ним на его ломаном английском и моём (крайне) ломаном японском. Наконец я сказал: «Давайте я просто пришлю свою тестовую программу в 30 строк, при которой движение контроллера приводит к багу». Он согласился. Заявил, что это потеря времени, и что он ужасно занят работой над новым проектом, но уступит, потому что мы очень важный разработчик для Sony. Я подчистил свою тестовую программу и отправил ему.

На следующий вечер (мы были в Лос-Анджелесе, а он в Токио) он позвонил мне и смущённо извинился. Это была аппаратная проблема.

Я не знаю, в чём именно заключался баг, но, насколько я слышал в штаб-квартире Sony, если задать таймеру достаточно высокое значение, то это мешало компонентам на материнской плате поблизости от кристалла таймера. Одним из них был контроллер частоты бодов для карты памяти, который также задавал частоту бодов для контроллеров. Я не инженер, так что мог что-то напутать.

Но суть в том, что между компонентами на материнской плате возникали помехи. И при одновременной передаче данных через порт контроллера и порт карты памяти при таймере, работающем с частотой 1 кГц, биты пропадали, данные терялись, а карта повреждалась.

Сбойные коровы

В 1980-х мой ментор Сергей писал ПО для СМ-1800, советского клона PDP-11. Этот микрокомпьютер только что установили на ЖД-станции под Свердловском, важным транспортным узлом СССР. Новая система была спроектирована для маршрутизации вагонов и грузопотоков. Но в ней оказался досадный баг, который приводил к случайным сбоям и падениям. Падения возникали всегда, когда кто-то уходил вечером домой. Но несмотря на тщательное расследование на следующий день, при всех ручных и автоматических тестах компьютер работал корректно. Обычно это свидетельствует о состоянии гонки или каком-то ином баге конкурентности, который проявляется при определённых условиях. Устав от звонков поздней ночью, Сергей решил докопаться до сути, и первым делом понять, какие условия на сортировочной станции приводили к поломке компьютера.

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

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

Чернобыльская АЭС взорвалась в 1986-м, и радиоактивные осадки сделали непригодными к обитанию прилегающие территории. Загрязнению подверглись обширные территории в северной Украине, Белоруссии и западной России. Заподозрив высокий уровень радиации в прибывающих вагонах, Сергей разработал метод проверки этой теории. Населению иметь дозиметры запрещалось, поэтому Сергей проставился нескольким военным на ЖД-станции. После нескольких порций водки ему удалось убедить солдата измерить уровень радиации в одном из подозрительных вагонов. Оказалось, что уровень в разы превышает обычные значения.

Мало того, что скот сильно фонил радиацией, её уровень был настолько велик, что это приводило к случайному выпадению битов в памяти СМ-1800, которая стояла в здании рядом со станцией.

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

По трубам

Когда-то компания Movietech Solutions создала ПО для кинотеатров, предназначенное для учёта и продажи билетов и общего управления. DOS-версия флагманского приложения была довольно популярна среди небольших и средних сетей кинотеатров в Северной Америке. Поэтому не удивительно, что когда анонсировали версию под Windows 95, интегрированную с новейшими сенсорными экранами и киосками самообслуживания, а также оснащённую всевозможными средствами отчётности, она тоже быстро стала популярной. Чаще всего обновление проходило без проблем. ИТ-специалисты на местах устанавливали новое оборудование, мигрировали данные, и бизнес продолжался. За исключением случаев, когда не продолжался. Когда такое происходило, компания отправляла Джеймса по прозвищу «Чистильщик».

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

Поэтому не удивительно, что в это суматошное время Джеймс пришёл утром в офис, и не успел дойти до своего стола, как его встретил руководитель, наполненный кофеином сверх обычного.

— Боюсь, тебе нужно как можно скорее отправиться в Аннаполис в Новой Шотландии. У них легла вся система, и после ночи совместной работы с их инженерами мы не можем понять, что произошло. Похоже, на сервере отказала сеть. Но только после того, как система проработала несколько минут.

— Они не вернулись к старой системе? — совершенно серьёзно ответил Джеймс, хотя мысленно он вытаращил глаза от удивления.

— Именно: у их айтишника «изменились приоритеты» и он решил уйти с их старым сервером. Джеймс, они установили систему на шести площадках и только что заплатили за премиальную поддержку, а их бизнес сейчас ведётся как в 1950-х.

Джеймс слегка выпрямился.

— Это другое дело. Ладно, приступаю.

Когда он прибыл в Аннаполис, то первым делом нашёл первый кинотеатр клиента, в котором возникла проблема. На взятой в аэропорте карте всё выглядело прилично, но окрестности нужного адреса выглядели подозрительно. Не гетто, но напоминали фильмы в жанре «нуар». Когда Джеймс припарковался у обочины в центре, к нему приблизилась проститутка. Учитывая размер Аннаполиса, она, скорее всего, была единственная на весь город. Её появление сразу же напомнило о знаменитом персонаже, который на большом экране предлагал секс за деньги. Нет, не о Джулии Робертс, а о Джоне Войте [намёк на фильм «Полуночный ковбой» — прим. пер.].

Отправив проститутку восвояси, Джеймс отправился к кинотеатру. Окрестности стали получше, но всё равно создавалось впечатление захудалости. Не то чтобы Джеймс слишком беспокоился. Он уже бывал в убогих местах. А это была Канада, в которой даже грабители достаточно вежливы, чтобы сказать «спасибо» после того, как отобрали ваш бумажник.

Боковой вход в кинотеатр находился в промозглой аллее. Джеймс подошёл к двери и постучал. Вскоре она заскрипела и приоткрылась.

— Вы чистильщик? — раздался изнутри хриплый голос.

— Да, это я… я приехал, чтобы всё исправить.

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

На первый взгляд всё было в порядке. Джеймс залогинился на сервер и проверил обычные подозрительные места. Никаких проблем. Однако из предосторожности Джеймс выключил сервер, заменил сетевую карту и откатил систему. Она моментально заработала в полном объёме. Персонал снова начал продавать билеты.

Джеймс позвонил Марку и сообщил о ситуации. Не трудно предположить, что Джеймс может захотеть задержаться здесь и посмотреть, не произойдёт ли что-нибудь неожиданное. Он спустился по лестнице и начал расспрашивать сотрудников и произошедшем. Очевидно, что система перестала работать. Они её выключили и включили, всё заработало. Но спустя 10 минут система отвалилась.

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

Затем вошёл один из сотрудников.

— Система опять работает.

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

— Система лежит.

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

Джеймс нажал кнопку и узор исчез. Он поторопился к билетной кассе и по пути встретил возвращавшегося к нему сотрудника.

— Система опять работает.

Если можно мысленно сделать фейспалм, то именно это Джеймс и сделал. Скринсейвер. Он использует OpenGL. И поэтому во время работы потребляет все ресурсы серверного процессора. В результате каждое обращение к серверу завершается по таймауту.

Джеймс вернулся в серверную, залогинился и заменил скринсейвер с прекрасными трубами на пустой экран. То есть вместо скринсейвера, поглощающего 100 % ресурсов процессора, поставил другой, не потребляющий ресурсы. Затем подождал 10 минут, чтобы проверить свою догадку.

Когда Джеймс приехал в следующий кинотеатр, он задумался о том, как объяснить своему руководителю, что он только что пролетел 800 км, чтобы отключить скринсейвер.

Сбой в определённую фазу Луны

Правдивая история. Однажды возник программный баг, который зависел от фазы Луны. Там была маленькая подпрограмма, которая обычно использовалась в разных программах MIT для вычисления приближения к истинной фазе Луны. GLS встроила эту подпрограмму в программу на LISP, которая при записи файла выводила строку с временной меткой длиной почти 80 символов. Очень редко первая строка сообщения получалась слишком длинной и переходила на следующую строку. И когда программа потом читала этот файл, она ругалась. Длина первой строки зависела от точной даты и времени, а также от длины спецификации фазы в момент печати временной метки. То есть баг в буквальном смысле зависел от фазы Луны!

Первое бумажное издание Jargon File (Steele-1983) содержало образец такой строки, приводившей к описанному багу, однако наборщик «исправил» её. С тех пор это описывают как «баг фазы Луны».

Однако будьте осторожны с предположениями. Несколько лет назад инженеры из CERN (European Center for Nuclear Research) столкнулись с ошибками в экспериментах, проводившихся на Большом электрон-позитронном коллайдере. Поскольку компьютеры активно обрабатывают гигантское количество данных, генерируемых этим устройством, прежде чем показать результат учёным, многие предполагали, что ПО каким-то образом чувствительно к фазе Луны. Несколько отчаянных инженеров докопались до истины. Ошибка возникала из-за небольшого изменения геометрии кольца длиной 27 км в связи с деформацией Земли при проходе Луны! Эта история вошла в фольклор физиков как «Ньютоновская месть физике частиц» и пример связи простейших и старейших физических законов с наиболее передовыми научными концепциями.

Смывание в туалете останавливает поезд

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

Во время одной из проверок инженер, ехавший в поезде, пошёл в туалет. Вскоре он смыл за собой, БУМ! Аварийная остановка.

Инженер связался с машинистом и спросил:

— Что ты делал перед самым торможением?

— Ну, я притормаживал на спуске…

Это было странно, потому что при обычном курсировании поезд притормаживает на спусках десятки раз. Состав отправился дальше, и на следующем спуске машинист предупредил:

— Я собираюсь притормаживать.

Ничего не произошло.

— Что ты делал при последнем торможении? — спросил машинист.

— Ну… я был в туалете…

— Ну, тогда иди в туалет и сделай то, что делал, когда будем спускаться опять!

Инженер отправился в туалет, и когда машинист предупредил: «Я торможу», он спустил воду. Конечно же, поезд тут же остановился.

Теперь они могли воспроизвести проблему и нужно было найти причину.

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

Шлюз, ненавидевший FORTRAN

Несколько месяцев назад мы заметили, что сетевые подключения к сети на материке [дело было на Гавайях] становились очень-очень медленными. Это могло длиться 10-15 минут, а затем неожиданно возникало снова. Спустя некоторое время мой коллега пожаловался мне, что подключения к сети на материке вообще не работают. У него был какой-то код на FORTRAN, который нужно было скопировать на машину на материке, но это не получалось, потому что «сеть не держалась достаточно долго, чтобы завершилась загрузка по FTP».

Да, получалось так, что отказы сети возникали тогда, когда коллега пытался передать по FTP файл с исходным кодом на FORTRAN на машину на материке. Мы попробовали архивировать файл: тогда он спокойно копировался (но на целевой машине не было распаковщика, так что проблема не была решена). Наконец мы «разделили» код на FORTRAN на очень маленькие фрагменты и отправили их по очереди. Большинство фрагментов скопировалось без проблем, но несколько штук не прошли, либо прошли после многочисленных попыток.

Изучив проблемные фрагменты, мы обнаружили, что у них есть кое-что общее: все они содержат блоки комментариев, которые начинаются и заканчиваются строками, состоящими из прописных букв С (так коллега предпочитал комментировать на FORTRAN). Мы отправили на материк электронные письма специалистам по сетям и попросили о помощи. Конечно, им захотелось увидеть образцы наших файлов, не поддающихся пересылке по FTP… но наши письма до них не дошли. Наконец мы придумали просто описать, как выглядят непересылаемые файлы. Это сработало :) [Осмелюсь ли я добавить сюда пример одного из проблемных комментариев на FORTRAN? Наверное, не стоит!]

В конце концов нам удалось разобраться. Между нашей частью кампуса и выходом в сеть на материке недавно установили новый шлюз. У него были ОГРОМНЫЕ трудности с передачей пакетов, которые содержали повторяющиеся фрагменты из прописных С! Всего несколько таких пакетов могли занять все ресурсы шлюза и не позволяли пробиться большинству других пакетов. Мы пожаловались производителю шлюза… и нам ответили: «А, да, вы столкнулись с багом повторяющихся С! Мы о нём уже знаем». В конце концов мы решили проблему, купив новый шлюз другого производителя (в защиту первого скажу, что неспособность передавать программы на FORTRAN для кого-то может оказаться преимуществом!).

Трудные времена

Несколько лет назад, работая над созданием ETL-системы на Perl, предназначенной для снижения расходов на третий этап клинических испытаний, мне потребовалось обработать около 40 000 дат. Две из них не прошли проверку. Меня это не слишком обеспокоило, потому что эти даты были взяты из предоставленных клиентом данных, которые часто, скажем так, удивляли. Но когда я проверил исходные данные, оказалось, что этим датами были 1 января 2011 и 1 января 2007. Я подумал, что баг содержится в только что написанной мной программе, но оказалось, ему уже 30 лет. Это может звучать таинственно для тех, кто не знаком с экосистемой программного обеспечения. Из-за давнего решения другой компании, принятого ради заработка денег, мой клиент заплатил мне за исправление бага, который одна компания внесла случайно, а другая намеренно. Чтобы вы поняли, о чём речь, мне нужно рассказать о компании, которая добавила фичу, в результате ставшую багом, а также ещё о нескольких любопытных событиях, внёсших вклад в исправленный мной таинственный баг.

В старые добрые времена компьютеры Apple иногда спонтанно сбрасывали свою дату на 1 января 1904 года. Причина была простой: для отслеживания даты и времени использовались работающие от батарейки «системные часы». Что происходило, когда батарейка садилась? Компьютеры начинали отслеживать дату по количеству секунд с начала эпохи. Под эпохой подразумевалась референсная исходная дата, и для Macintosh’ей это было 1 января 1904. И после умирания батарейки текущая дата сбрасывалась на указанную. Но почему так происходило?

Раньше для хранения количества секунд с исходной даты Apple использовала 32 бита. Один бит может хранить одно из двух значений — 1 или 0. Два бита могут хранить одно из четырёх значений: 00, 01, 10, 11. Три бита — одно значение из восьми: 000, 001, 010, 011, 100, 101, 110, 111, и т.д. А 32 могли хранить одно из 232 значений, то есть 4 294 967 296 секунд. Для дат по версии Apple это равнялось примерно 136 годам, поэтому старые Маки не могут обрабатывать даты после 2040 года. И если системная батарейка садится, дата сбрасывается на 0 секунд с начала эпохи, и приходится вручную выставлять дату при каждом включении компьютера (или пока вы не купите новую батарейку).

Однако решение Apple хранить даты в виде секунд с начала эпохи означало, что мы не можем обрабатывать даты до начала эпохи, что имело далеко идущие последствия, как мы увидим. Apple ввела фичу, а не баг. Помимо прочего это означало, что операционная система Macintosh была неуязвима для «бага миллениума» (чего не скажешь про многие приложения для Мака, имевших собственные системы исчисления дат для обхода ограничений).

Идём дальше. Мы использовали Lotus 1-2-3, разработанное IBM «киллер-приложение», которое помогло запустить PC-революцию, хотя на Apple-компьютерах была VisiCalc, обеспечившая успех персональным компьютерам. Справедливости ради, если бы 1-2-3 не появилась, PC вряд ли взлетели бы, а история персональных компьютеров могла развиваться бы совсем иначе. Lotus 1-2-3 некорректно обрабатывала 1900-й как високосный год. Когда Microsoft выпустила свою первую электронную таблицу Multiplan, та заняла маленькую долю рынка. И когда запустили проект Excel, решили не только скопировать у Lotus 1-2-3 схему именования строк и колонок, но и обеспечить совместимость по багам, сознательно обрабатывая 1900-й как високосный год. Эта проблема существует по сей день. То есть в 1-2-3 это было багом, а в Excel — сознательным решением, которое гарантировало, что все пользователи 1-2-3 могут импортировать свои таблицы в Excel без изменения данных, даже если они ошибочные.

Но тут была ещё одна проблема. Сначала Microsoft выпустила Excel для Macintosh, который не признавал даты до 1 января 1904. А в Excel началом эпохи считалось 1 января 1900 года. Поэтому разработчики внесли изменение, чтобы их программа распознавала вид эпохи и хранила внутри себя данные в соответствии с нужной эпохой. Microsoft даже написала об этом поясняющую статью. И это решение привело к моему багу.

Моя ETL-система получала от покупателей Excel-таблицы, которые создавались под Windows, но могли быть созданы и на Маке. Поэтому началом эпохи в таблице могло быть как 1 января 1900 года, так и 1 января 1904 года. Как это узнать? Формат файла Excel показывает нужную информацию, а парсер который я применял, не показывал (теперь показывает), и предполагал, что вы знаете эпоху для конкретной таблицы. Наверное, можно было потратить больше времени на то, чтобы разобраться в двоичном формате Excel и прислать патч автору парсера, но мне нужно было сделать для клиента много другого, поэтому я быстро написал эвристику для определения эпохи. Она была простой.

В Excel дата 5 июля 1998 может быть представлена в формате «07-05-98» (бесполезная американская система), «Jul 5, 98», «July 5, 1998», «5-Jul-98» или в каком-нибудь другом бесполезном формате (по иронии судьбы, одним из форматов, который не предлагала моя версия Excel, был стандарт ISO 8601). Однако внутри таблицы неформатированная дата хранилась либо как «35981» для эпохи-1900, либо как «34519» для эпохи-1904 (числа представляют количество дней с начала эпохи). Я просто с помощью простого парсера извлекал год из отформатированной даты, а затем с помощью парсера Excel извлекал год из неотформатированной даты. Если оба значения отличались на 4 года, от я понимал, что использую систему с эпохой-1904.

Почему я не использовал просто отформатированные даты? Потому что 5 июля 1998 может быть отформатировано как «July, 98» с потерей дня месяца. Мы получали таблицы от такого количества компаний, которые создавали их такими разными способами, что разбираться с датами должны были мы (в данном случае я). Кроме того, если Excel понимает правильно, то и мы должны!

Тогда же я столкнулся с 39082. Напомню, что Lotus 1-2-3 считал 1900-й високосным, и это добросовестно повторили в Excel. А поскольку это добавляло к 1900-му один день, многие функции вычисления дат могли ошибаться на этот самый день. То есть 39082 могло быть 1 января 2011 (на Маках) или 31 декабря 2006 (в Windows). Если мой «парсер лет» извлекал из отформатированного значения 2011-й год, то всё хорошо. Но поскольку парсер Excel не знает, какая используется эпоха, он по умолчанию применяет эпоху-1900, возвращая 2006-й год. Моё приложение видело, что разница составляет 5 лет, считало это ошибкой, журналировало и возвращало неотформатированное значение.

Чтобы это обойти, я написал вот это (псевдокод):

diff = formatted_year - parsed_year
if 0 == diff
    assume 1900 date system
if 4 == diff
    assume 1904 date system
if 5 == diff and month is December and day is 31
    assume 1904 date system

И тогда все 40 000 дат отпарсились корректно.

Посреди больших заданий на печать

В начале 1980-х мой отец работал в Storage Technology, в не существующем ныне подразделении, которое создавало ленточные накопители и пневматические системы для высокоскоростной подачи лент.

Они так переделывали накопители, чтобы те могли иметь один центральный привод «А», соединённый с семью приводами «Б», а маленькая ОС в оперативной памяти, управлявшая приводом «А», могла делегировать операции чтения и записи по всем приводам «Б».

При каждом запуске привода «А» нужно было вставлять дискету в периферийный дисковод, подключённый к «А», чтобы загрузить в его память операционную систему. Она была крайне примитивной: вычислительная мощность обеспечивалась 8-битным микроконтроллером.

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

У одного клиента была проблема. Посреди задания на печать один конкретный привод «А» мог перестать работать, из-за чего вставало всё задание. Чтобы восстановить работу привода, персоналу приходилось всё перезагружать. И если это происходило посреди шестичасового задания, то терялось огромное количество дорогостоящего компьютерного времени и срывалось расписание всей операции.

Из Storage Technologies отправили техников. Но несмотря на все попытки, они не смогли воспроизвести баг в тестовых условиях: похоже, сбой возникал посреди больших заданий на печать. Проблема была не в оборудовании, они заменили всё, что могли: оперативную память, микроконтроллер, дисковод, все мыслимые части ленточного привода — проблема сохранялась.

Тогда техники позвонили в штаб-квартиру и позвали Эксперта.

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

Эксперт опять сел в кресло и стал ждать сбоя. Прошло около шести часов, и сбой произошёл. У Эксперта опять не было идей, не считая того, что всё случилось в заполненном людьми помещении. Он приказал перезапустить задание, снова сел и стал ждать.

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

Фальшпол был сделан из алюминиевых плиток, уложенных на высоте 6—8 дюймов. Под фальшполом проходили многочисленные провода от компьютеров, чтобы кто-нибудь случайно не наступил на важный кабель. Плитки были уложены очень плотно, чтобы под фальшпол не попадал мусор.

Эксперт понял, что одна из плиток была деформирована. Когда сотрудник наступал на её угол, плитка тёрлась краями о соседние плитки. С ними тёрлись и пластмассовые детали, соединявшие плитки, из-за чего возникали статические микроразряды, создававшие радиочастотные помехи.

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

Это прилив!

История произошла в серверной комнате, на четвёртом или пятом этаже офиса в Портсмуте (кажется), в районе доков.

Однажды упал Unix-сервер с основной базой данных. Его перезагружали, но он радостно продолжал раз за разом падать. Решили позвать кого-нибудь из службы поддержки.

Чувак из поддержки… кажется, его звали Марк, но это не важно… вряд ли я с ним знаком. Это не важно, правда. Остановимся на «Марке», хорошо? Отлично.

Итак, через несколько часов прибыл Марк (от Лидса до Портсмута путь не близкий, знаете ли), включил сервер и всё заработало без проблем. Типичная чёртова поддержка, клиент из-за этого очень расстраивается. Марк просматривает файлы журнала и не находит ничего предосудительного. Тогда Марк возвращается на поезд (или на каком там виде транспорта он приехал, это могла быть и хромая корова, насколько я знаю… короче, это не важно, ладно?) и отправляется обратно в Лидс, впустую потратив день.

Тем же вечером сервер падает снова. История та же… сервер не поднимается. Марк удалённо пытается помочь, но клиент не может запустить сервер.

Опять поезд, автобус, лимонное безе или ещё какая-то херня, и Марк опять в Портсмуте. Глянь-ка, сервер загружается без проблем! Чудо. Марк несколько часов проверяет, что с операционкой или ПО всё в порядке, и отправляется в Лидс.

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

Ситуация повторялась несколько дней. Сервер работает, примерно через 10 часов падает и не запускается в течение следующих 2 часов. Они проверили охлаждение, утечки памяти, они проверили всё, но ничего не нашли. Затем сбои прекратились.

Неделя прошла беззаботно… все были счастливы. Счастливы, пока всё не началось опять. Картина та же. 10 часов работы, 2—3 часа простоя…

А потом кто-то (кажется, мне говорили, что этот человек не имел отношения к ИТ) сказал:

«Это прилив!»

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

«Он перестаёт работать с приливом».

Казалось бы, это совершенно чуждая концепция для сотрудников ИТ-поддержки, которые вряд ли читают «ежегодник приливов», сидя за кофе. Они объяснили, что это никак не может быть связано с приливом, потому что сервер работал неделю без сбоев.

«На прошлой неделе прилив был низким, а на этой высоким».

Немного терминологии для тех, у кого нет лицензии на управление яхтой. Приливы зависят от лунного цикла. И по мере вращения Земли, каждые 12,5 часа гравитационное притяжение Солнца и Луны создаёт приливную волну. В начале 12,5-часового цикла возникает прилив, в середине цикла — отлив, а в конце снова прилив. Но поскольку орбита Луны меняется, меняется и разница между отливом и приливом. Когда Луна находится между Солнцем и Землёй или с противоположной стороны от Земли (полнолуние или отсутствие Луны), мы получаем сизигийские приливы — самые высокие приливы и самые низкие отливы. В полулуние мы получаем квадратурные приливы — самые низкие приливы. Разница между двумя экстремумами сильно уменьшается. Лунный цикл длится 28 дней: сизигийские — квадратурные — сизигийские — квадратурные.

Когда технарям объяснили суть приливных сил, те сразу же подумали о том, что нужно позвонить в полицию. И вполне логично. Но оказалось, что чувак был прав. За две недели до этого неподалёку от офиса пришвартовался эсминец. Каждый раз, когда прилив поднимал его на определённую высоту, радарный пост корабля оказывался на уровне пола серверной. И радар (или средство РЭБ, или какая-то другая игрушка военных) устраивал в компьютерах хаос.

Полётное задание для ракеты

Мне поручили портировать большую (около 400 тыс. строк) систему управления и контроля запуска ракет под новые версии операционной системы, компилятора и языка. Точнее, с Solaris 2.5.1 на Solaris 7, и с Verdix Ada Development System (VADS), написанной на Ada 83, на систему Rational Apex Ada, написанную на Ada 95. VADS была куплена компанией Rational, и её продукт устарел, хотя Rational постаралась реализовать совместимые версии специфических для VADS пакетов, чтобы облегчить переход на компилятор Apex.

Три человека помогали мне просто получить чисто скомпилированный код. На это ушло две недели. А затем я самостоятельно работал над тем, чтобы заставить систему работать. Короче, это были худшие архитектура и реализация программной системы, что мне встречались, поэтому на завершение портирования ушло ещё два месяца. Затем систему передали на тестирование, что заняло ещё несколько месяцев. Я сразу исправлял баги, которые находили при тестировании, но их количество быстро снизилось (исходный код был production-системой, поэтому его функциональность работала достаточно надёжно, мне лишь пришлось убрать баги, возникшие при адаптации под новый компилятор). В конце концов, когда всё работало так, как и должно было, меня перевели на другой проект.

А в пятницу перед Днём благодарения раздался телефонный звонок.

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

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

И внимание было обращено на меня, как на человека, портировавшего систему.

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

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

Поскольку в журналах не было ничего интересного, решили попытаться воспроизвести проблему в местной лаборатории. Это была непростая задача, поскольку событие возникало примерно один раз на 1000 прогонов. Одной из предполагаемых причин было то, что вызов разработанной поставщиком мьютекс-функции (часть пакета миграции VADS) Unlock не приводил к разблокированию. Поток обработки, вызывавший функцию, обрабатывал heartbeat-сообщения, которые номинально приходили каждую секунду. Мы подняли частоту до 10 Гц, то есть 10 раз в секунду, и начали прогон. Примерно через час система заблокировалась. В журнале мы увидели, что последовательность записанных сообщений была такой же, как во время сбойного испытания. Сделали ещё несколько прогонов, система стабильно блокировалась через 45—90 минут после начала, и каждый раз в журнале была одна и та же трасса. Несмотря на то, что технически мы сейчас исполняли другой код — частота сообщений была другой — поведение системы повторялось, поэтому мы уверились, что этот нагрузочный сценарий приводил к той же проблеме.

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

В этой реализации системы использовалась система задач Ada, и использовалась невероятно плохо. Задачи — это высокоуровневая параллельно исполняемая конструкция в Ada, что-то вроде потоков исполнения, только встроенная в сам язык. Когда двум задачам нужно взаимодействовать, они «назначают рандеву» (rendezvous), обмениваются нужными данными, а затем прекращают рандеву и возвращаются к своим независимым исполнениям. Однако система была реализована иначе. После того, как с целевой задачей проводилось рандеву, эта целевая задача проводила рандеву с другой задачей, которая потом проводила рандеву с третьей, и так далее, пока не завершалась какая-то обработка. После этого все эти рандеву завершались и каждая задача должна была вернуться к своему исполнению. То есть мы имели дело с самой дорогой в мире системой вызова функций, которая стопорила весь «многозадачный» процесс, пока обрабатывала часть входных данных. И раньше это не приводило к проблемам лишь потому, что пропускная способность была очень низкой.

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

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

Также при изучении журнала выяснилось, что, несмотря на зависание обработки heartbeat-сообщений, которое блокировало все операции ввода-вывода процесса и не давало выполнять другие обработки, прочие независимые задачи продолжали исполняться. То есть работа блокировалась не целиком, только (критическая) цепочка задач.

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

Я сделал Ada-пакет, который содержал задачу, перечисляемый тип и глобальную переменную этого типа. Перечисляемые литералы были привязаны к конкретным выражениям проблемной последовательности (например, Incrementing_Buffer_Index, Locking_Mutex, Mutex_Unlocked), а затем вставил в неё выражения присваивания, которые присваивали соответствующее перечисление глобальной переменной. Поскольку объектный код всего этого просто хранил постоянную в памяти, переключение задачи в результате его исполнения было крайне маловероятно. В первую очередь мы подозревали выражения, которые могли переключить задачу, поскольку блокировка возникала при исполнении, а не возвращении при обратном переключении задачи (по нескольким причинам).

Отслеживающая задача просто выполнялась в цикле и периодически проверяла, изменилось ли значение глобальной переменной. При каждом изменении значение сохранялось в файл. Затем недолгое ожидание и новая проверка. Я записывал переменную в файл потому, что задача исполнялась только тогда, когда система выбирала её для исполнения при переключении задачи в проблемной области. Что бы ни происходило в этой задаче, это не влияло бы на другие, не связанные с ней заблокированные задачи.

Ожидалось, что когда система дойдёт до исполнения проблемного кода, глобальная переменная будет сбрасываться при переходе к каждому следующему выражению. Затем произойдёт что-то, приводящее к переключению задачи, и поскольку частота его исполнения (10 Гц) ниже, чем у мониторящей задачи, монитор мог зафиксировать значение глобальной переменной и записать его. В нормальной ситуации я мог бы получить повторяющуюся последовательность подмножества перечислений: последние значения переменной на момент переключения задачи. При зависании глобальная переменная не должна больше меняться, и последнее записанное значение покажет, исполнение какого выражения не завершилось.

Запустил код с отслеживанием. Он завис. А мониторинг сработал как по маслу.

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

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

Чтобы защитить нужный фрагмент кода, я заменил вызовы мьютекс-функций (построенных на основе мьютекс-функциональности ОС) маленьким нативным мьютекс-пакетом Ada, чтобы с его помощью управлять доступом мьютексов к этому фрагменту.

Вставил в код и запустил тест. Семь часов спустя код продолжал работать.

Мой код передали в Rational, там его скомпилировали, дизассемблировали и проверили, что в нём не используется тот же подход, который применялся в проблемных мьютекс-функциях.

Это была самая многолюдная проверка кода в моей карьере :) В комнате со мной было около десяти инженеров и менеджеров, ещё десяток людей подключились по конференц-звонку — и все они исследовали около 20 строк кода.

Код прошёл проверку, собрали новые исполняемые файлы и передали на формальное регрессионное тестирование. Пару недель спустя испытания обратного отсчёта прошли успешно, и ракета взлетела.

Ладно, это всё хорошо и прекрасно, но в чём суть этой истории?

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

Я был не единственным, кто работал над этой проблемой, хотя и находился в центре внимания, поскольку делал портирование. Но хотя я и делал его, это не означает, что я разбирался со всеми сотнями тысяч строк кода, или хотя бы бегло просмотрел их. Код и журналы анализировали инженеры по всей стране, но когда они говорили мне свои гипотезы о причинах сбоя, мне хватало полминуты, чтобы опровергнуть их. И когда меня просили проанализировать теории, я перекладывал это на кого-нибудь другого, потому что мне было очевидно, что эти инженеры идут не тем путём. Звучит самонадеянно? Да, это так, но я отклонил гипотезы и запросы по другой причине.

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

За годы работы я накопил много знаний и опыта. Я был одним из пионеров использования Ada, понимал её достоинства и недостатки. Я знаю, как runtime-библиотеки Ada обрабатывают задачи и работают с параллельным исполнением. И я разбираюсь в низкоуровневом программировании на уровне памяти, регистров и ассемблера. Иными словами, у меня глубокие познания в своей сфере. И я использовал их для поиска причины проблемы. Я не просто обошёл баг, а понимал, как найти его в условиях очень чувствительной среды исполнения.

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

Для решения действительно трудных проблем вам нужно быть не просто программистом. Вам нужно понимать «судьбу» кода, как он взаимодействует со своим окружением и как работает само окружение.

И тогда у вас будет своя испорченная праздничная неделя.


Продолжение следует.

Автор: NIX

Источник


* - обязательные к заполнению поля


https://ajax.googleapis.com/ajax/libs/jquery/3.4.1/jquery.min.js