Случайное повреждение в файле, созданном/обновленном из сценария оболочки на отдельном клиенте для монтирования NFS

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

В тот же период времени, когда это произошло, кажется, что 10-50 проблем из 100 000+ рабочих мест.

Вот то, что я считаю эффективной (дистиллированной) версией оболочки задания:

#!/bin/bash
## cwd is /nfs/path/to/jobwd
## This file is /nfs/path/to/jobwd/job_wrapper

gotEXIT()
{
    ## end of script, however gotEXIT is called because we trap EXIT
    END="EndTime: `date`\nStatus: Ended”
    echo -e "${END}" >> job_info
    cat job_info | sendmail [email protected]
}
trap gotEXIT EXIT

function jobSetVar { echo "job.$1: $2" >> job_info; }
export -f jobSetVar

MSG=“${email_metadata}\n${job_metadata}”
echo -e "${MSG}\nStatus: Started" | sendmail [email protected]
echo -e "${MSG}" > job_info

## At the job’s end, the output from `time` command is the first non-corrupt data in job_info
/usr/bin/time -f "Elapsed: %e\nUser: %U\nSystem: %S" -a -o job_info job_command

## 10-360 minutes later…
RC=$?
echo -e "ExitCode: ${RC}" >> job_info

Поэтому я думаю, что есть два варианта:

  1. echo -e "${MSG}" > job_info
    Эта команда удаляет поврежденные данные.

  2. /usr/bin/time -f "Elapsed: %e\nUser: %U\nSystem: %S" -a -o job_info job_command
    Это искажает существующие данные, а затем выводит их правильно.

Однако некоторые задания, но не все, вызывают jobSetVar, что не приводит к повреждению.

Итак, я копаюсь в time.c (из GNU time 1.7), чтобы увидеть, когда файл открыт. Подводя итог, time.c фактически таков:

FILE *outfp;

void main (int argc, char** argv) {
  const char **command_line;
  RESUSE res;

  /* internally, getargs opens “job_info”, so outfp = fopen ("job_info", "a”) */
  command_line = getargs (argc, argv); 
  /* run_command doesn't care about outfp */
  run_command (command_line, &res);
  /* internally, summarize calls fprintf and putc on outfp FILE pointer */
  summarize (outfp, output_format, command_line, &res);  /
  fflush (outfp);
}

Таким образом, time имеет FILE *outfp (дескриптор job_info), открытый все время задания. Затем он записывает сводку в конце задания, а затем фактически не закрывает файл (не уверен, что это необходимо с fflush?). Я понятия не имею, одновременно ли bash также открывает дескриптор файла. .

ИЗМЕНИТЬ:

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

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

Вот пример шестнадцатеричного дампа:

40000000 00000000 00000000 00000000 
00000000 00000000 C8B450AC 772B0000
01000000 00000000 C8B450AC 772B0000
[ 361 x 0x00] 

Затем на 409-м байте продолжается неповрежденный раздел:

Elapsed: 879.07
User: 0.71
System: 31.49
ExitCode: 0
EndTime: Fri Dec  6 15:29:27 PST 2013
Status: Ended

Другой файл выглядит так:

01000000 04000000 805443FC 9D2B0000 E04144FC 9D2B0000 E04144FC 9D2B0000
[96 x 0x00]
[Repeat above 3 times ]
01000000 04000000 805443FC 9D2B0000 E04144FC 9D2B0000 E04144FC 9D2B0000

Далее следует неповрежденный раздел:

Elapsed: 12621.27
User: 12472.32
System: 40.37
ExitCode: 0
EndTime: Thu Nov 14 08:01:14 PST 2013
Status: Ended

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

EDIT 2: Первое электронное письмо, отправленное из заявления echo -e, проходит нормально. Последнее электронное письмо никогда не отправляется из-за отсутствия метаданных электронной почты из-за повреждения. Таким образом, MSG в этот момент не поврежден. Предполагается, что job_info вероятно в этот момент также не поврежден, но мы пока не смогли это проверить. Это производственная система, в которой не было серьезных изменений кода, и я проверил с помощью аудита, что никакие задания не выполнялись одновременно, которые могли бы затронуть этот файл. Проблема кажется несколько недавней (последние 2 месяца), но, возможно, она случалась раньше и проскользнула. Эта ошибка не позволяет создавать отчеты, что означает, что задания считаются неудачными, поэтому они обычно отправляются повторно, но у одного конкретного пользователя есть задания продолжительностью около 9 часов, в которых эта ошибка вызывает особое разочарование. Я хотел бы получить больше информации или способ воспроизвести это по желанию, но я надеялся, что кто-то, возможно, сталкивался с подобной проблемой, особенно недавно. Я не управляю серверами NFS, но я попытаюсь поговорить с администраторами, чтобы узнать, какие обновления были запущены на серверах NFS во время этих проблем (я полагаю, RHEL6).


person Brian    schedule 08.12.2013    source источник
comment
Интересный эффект! Не могли бы вы привести пример того, как обычно выглядит поврежденный файл?   -  person Marcus Rickert    schedule 09.12.2013
comment
я добавил несколько примеров   -  person Brian    schedule 09.12.2013


Ответы (3)


Ну, электронные письма, соответствующие поврежденным файлам job_info, должны сообщить вам, что было в MSG (что, вероятно, будет обычным делом). Вы можете проверить, как работает NFS: есть вероятность, что вы используете NFS через UDP без контрольных сумм. Это может объяснить некоторые искаженные данные. Я также слышал, что контрольные суммы UDP/TCP недостаточно надежны, и данные все еще могут оказаться поврежденными — возможно, вы столкнулись с такой проблемой (я видел, как поврежденные пакеты проскальзывали через сетевой стек, по крайней мере однажды, и я вполне уверен, что какая-то контрольная сумма происходила). Предположительно, MSG отправляется как один пакет, и в нем может быть что-то, что делает конфликт контрольной суммы с мусором, который вы видите, более вероятным. Конечно, это также может быть ошибка NFS (клиентской или серверной), ошибка файловой системы на стороне сервера, поврежденная часть ОЗУ... возможности здесь почти безграничны (хотя я вижу, как тот факт, что всегда повреждается MSG, заставляет некоторых из тех, что маловероятны). Проблема может быть связана с поиском (что происходит во время добавления). У вас также может быть ошибка где-то еще в системе, из-за которой несколько клиентов открывают один и тот же файл job_info, что делает его беспорядочным.

person mornfall    schedule 09.12.2013
comment
Я добавил больше информации. Завтра я свяжусь с администраторами, чтобы попытаться узнать информацию об ОС и версиях клиента и сервера NFS. Я не верю, что это оперативная память, так как это произошло как минимум на шести разных пакетных узлах и двух отдельных серверах (у всех есть ECC, FWIW). Я не думаю, что это связано с сетью, и, насколько я знаю, это проявилось только в этом конкретном файле и на этих двух серверах. Так что это довольно запутанно, потому что я, по крайней мере, ожидал, что это появится где-то еще в системе, учитывая, что запись в этот файл довольно проста. - person Brian; 09.12.2013

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

Shell открывает файл job_info для записи, выводит сообщение MSG и затем закрывает свой файловый дескриптор перед запуском основного задания. Программа «time» открывает тот же файл для добавления, что и поток, и я подозреваю, что поиск по NFS выполняется неправильно, что может вызвать этот мусор. Не могу объяснить почему, но обычно этого не происходит (и не происходит). Такие редкие случаи могут указывать на какое-то состояние гонки где-то, могут быть вызваны неупорядоченной доставкой пакетов (из-за скачка задержки в сети) или повторной передачей, которая вызывает дублирование данных, или где-то ошибкой. На первый взгляд я бы заподозрил какую-то ошибку, но эта ошибка может быть вызвана каким-то поведением сети, например. необычно большая задержка или всплеск потери пакетов.

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

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

Еще одна вещь, которую можно попробовать, хотя это может быть сложно из-за редких случаев, — это захват интересных сеансов NFS с помощью tcpdump или wireshark. В действительно сложных случаях мы делаем одновременный захват как на стороне клиента, так и на стороне сервера, а затем сравниваем логику протокола, чтобы убедиться, что сеть работает или не работает правильно. Это целая тема сама по себе, требует тщательной подготовки и удачи, но обычно это последнее средство отчаянного устранения неполадок :)

person Mindaugas Kubilius    schedule 09.12.2013

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

В реализацию linux-nfs добавлено исправление ошибки: http://www.spinics.net/lists/linux-nfs/msg41357.html

person Brian    schedule 31.03.2014