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

39

Общий шаблон для обнаружения ошибки следует за этим сценарием:

  1. Соблюдайте странности, например, отсутствие вывода или зависание программы.
  2. Найдите соответствующее сообщение в журнале или выходе программы, например, «Не удалось найти Foo». (Следующее применимо только в том случае, если этот путь используется для обнаружения ошибки. Если трассировка стека или другая отладочная информация легко доступны, это уже другая история.)
  3. Найдите код, где печатается сообщение.
  4. Отладка кода между первым местом, где Foo вводит (или должен вводить) картинку, и местом, где печатается сообщение.

На третьем этапе процесс отладки часто останавливается, потому что в коде есть много мест, где выводится «Не удалось найти Foo» (или шаблонную строку Could not find {name}). Фактически, несколько раз орфографическая ошибка помогала мне находить фактическое местоположение намного быстрее, чем я в противном случае - это делало сообщение уникальным во всей системе и часто во всем мире, что немедленно приводило к попаданию в поисковую систему.

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

l0b0
источник
54
Вместо этого используйте ваши следы стека. Трассировка стека точно скажет вам не только, где произошла ошибка, но и каждая функция, которая вызвала каждую функцию, которая вызвала ее. Записать всю трассировку при возникновении исключения, если это необходимо. Если вы работаете на языке, который не имеет исключений, например C, это другая история.
Роберт Харви
6
@ l0b0 небольшой совет по формулировке. «что думает это сообщество ... плюсы и минусы» - это фразы, которые можно рассматривать как слишком широкие. Это сайт, на котором можно задавать «хорошие субъективные» вопросы, и в обмен на разрешение вопросов такого типа вы, как ОП, должны будете выполнять работу по «прислушиванию» комментариев и ответов к значимому консенсусу.
Руон
@ rwong Спасибо! Я чувствую, что вопрос уже получил очень хороший и точный ответ, хотя это, возможно, было бы лучше задать на форуме. Я отозвал свой ответ на комментарий Роберта Харви после прочтения уточняющего ответа JohnWu, на случай, если вы об этом имеете в виду. Если нет, есть ли у вас какие-то конкретные советы пастырей?
10
1
Мои сообщения выглядят как «Не удалось найти Foo во время вызова bar ()». Проблема решена. Shrug. Недостатком является то, что клиенты видят немного утечку, но мы все равно стараемся скрыть от них подробности сообщений об ошибках, делая их доступными только системным администраторам, которые не могут дать обезьянам возможность увидеть имена некоторых функций. В противном случае, да, хороший маленький уникальный идентификатор / код сделает свое дело.
Легкость гонки с Моникой
1
Это ОЧЕНЬ полезно, когда клиент звонит вам, а его компьютер не работает на английском языке! Гораздо меньше проблемы в эти дни , как мы теперь имеем электронную почту и файлы журналов .....
Ian

Ответы:

12

В целом это действительная и ценная стратегия. Вот несколько мыслей.

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

Некоторые важные части данных, которые должны быть собраны (которые мы все знаем):

  • Расположение кода, то есть стек вызовов и приблизительная строка кода
    • «Приблизительная строка кода» не требуется, если функции разумно разложены на достаточно маленькие блоки.
  • Любые фрагменты данных, которые имеют отношение к успеху / провалу функции
  • «Команда» высокого уровня, которая может зафиксировать то, что пытается выполнить пользователь-пользователь / внешний агент / пользователь API.
    • Идея заключается в том, что программное обеспечение будет принимать и обрабатывать команды, поступающие откуда-то.
    • В ходе этого процесса могли происходить от десятков до сотен тысяч вызовов функций.
    • Мы бы хотели, чтобы любая телеметрия, генерируемая в ходе этого процесса, прослеживалась до команды самого высокого уровня, которая запускает этот процесс.
    • Для веб-систем исходный HTTP-запрос и его данные будут примером такой «информации запроса высокого уровня»
    • Для систем с графическим интерфейсом пользователь нажимает на что-то, что подходит под это описание.

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

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

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

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

Еще одна ошибка, которая усложняет отслеживание телеметрии, - отсутствие ссылок на объекты (нулевые указатели или ссылки). Когда некоторые важные данные отсутствуют, может быть невозможно сообщить что-либо полезное для сбоя.

С точки зрения написания журнала сообщений:

  • Для некоторых программных проектов может потребоваться локализация (перевод на иностранный язык) даже для сообщений журнала, предназначенных только для администраторов.
  • Некоторым программным проектам может потребоваться четкое разделение между конфиденциальными данными и нечувствительными данными даже для целей ведения журнала, и у администраторов не будет возможности случайно увидеть определенные конфиденциальные данные.
  • Не пытайтесь запутать сообщение об ошибке. Это подорвало бы доверие клиентов. Администраторы клиентов рассчитывают прочитать эти журналы и разобраться в этом. Не позволяйте им почувствовать, что есть какой-то секрет, который должен быть скрыт от администраторов клиентов.
  • Ожидайте, что клиенты принесут часть телеметрического журнала и приготовят гриль персоналу технической поддержки. Они ожидают знать. Обучите персонал службы технической поддержки правильному объяснению журнала телеметрии.
rwong
источник
1
Действительно, AOP рекламировал, в первую очередь, присущую ему способность решать эту проблему - добавлять Tracer к каждому соответствующему вызову - с минимальным вмешательством в базу кода.
епископ
Я также добавил бы к списку «записи сообщений журнала», что важно характеризовать сбой в терминах «почему» и «как исправить», а не просто «что» произошло.
епископ
58

Представьте, что у вас есть тривиальная служебная функция, которая используется в сотнях мест в вашем коде:

decimal Inverse(decimal input)
{
    return 1 / input;
}

Если бы мы делали, как вы предлагаете, мы могли бы написать

decimal Inverse(decimal input)
{
    try 
    {
        return 1 / input;
    }
    catch(Exception ex)
    {
        log.Write("Error 27349262 occurred.");
    }
}

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

Допустим, вы видите 27349262 в ваших выходных данных или в ваших журналах. Где вы смотрите, чтобы найти код, который передал нулевое значение? Помните, что функция с ее уникальным идентификатором используется в сотнях мест. Таким образом, вы можете знать, что деление на ноль произошло, но вы не знаете, чье 0это.

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

Если вас беспокоит многословность трассировки стека, вам не нужно выводить ее как строку, как это дает среда выполнения. Вы можете настроить его. Например, если вам нужна сокращенная трассировка стека, идущая только по nуровням, вы можете написать что-то вроде этого (если вы используете c #):

static class ExtensionMethods
{
    public static string LimitedStackTrace(this Exception input, int layers)
    {
        return string.Join
        (
            ">",
            new StackTrace(input)
                .GetFrames()
                .Take(layers)
                .Select
                (
                    f => f.GetMethod()
                )
                .Select
                (
                    m => string.Format
                    (
                        "{0}.{1}", 
                        m.DeclaringType, 
                        m.Name
                    )
                )
                .Reverse()
        );
    }
}

И используйте это так:

public class Haystack
{
    public static void Needle()
    {
        throw new Exception("ZOMG WHERE DID I GO WRONG???!");
    }

    private static void Test()
    {
        Needle();
    }

    public static void Main()
    {
        try
        {
            Test();
        }
        catch(System.Exception e)
        {
            //Get 3 levels of stack trace
            Console.WriteLine
            (
                "Error '{0}' at {1}", 
                e.Message, 
                e.LimitedStackTrace(3)
            );  
        }
    }
}

Выход:

Error 'ZOMG WHERE DID I GO WRONG???!' at Haystack.Main>Haystack.Test>Haystack.Needle

Может быть, проще, чем поддерживать идентификаторы сообщений, и более гибко.

Украсть мой код из DotNetFiddle

Джон Ву
источник
32
Хм, я полагаю, я недостаточно четко изложил свою точку зрения. Я знаю, что они уникальны, Роберт - по местоположению кода . Они не уникальны для каждого пути кода . Знание местоположения часто бесполезно, например, если истинная проблема в том, что вход был установлен неправильно. Я немного отредактировал свой язык, чтобы подчеркнуть.
Джон У
1
Хорошие моменты, вы оба. Существует другая проблема со следами стека, которая может или не может быть прерывателем сделки в зависимости от ситуации: их размер может привести к тому, что они затопят сообщения, особенно если вы хотите включить всю трассировку стека, а не сокращенную версию, как некоторые языки делать по умолчанию. Возможно, альтернативой было бы написать отдельный журнал трассировки стека и включить нумерованные индексы в этот журнал в выходных данных приложения.
10
12
Если вы получаете так много из них, что вы беспокоитесь о затоплении вашего ввода / вывода, значит что-то серьезно не так. Или ты просто скуп? Реальным ударом производительности, вероятно, является раскрутка стека.
Джон У
9
Отредактировано с помощью решения для сокращения следов стека, если вы пишете журналы на дискету 3.5;)
John Wu
7
@JohnWu А также не забывайте «IOException« Файл не найден »в [...]», который сообщает вам о пятидесяти слоях стека вызовов, но не говорит, какой именно кровавый файл не был найден.
Joker_vD
6

SAP NetWeaver делает это десятилетиями.

Он оказался ценным инструментом при устранении ошибок в огромном кодовом чудовище, которое является типичной системой SAP ERP.

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

Когда вы хотите вывести сообщение об ошибке, вы указываете только переменные класса, числа, серьезности и сообщения. Текстовое представление сообщения создается во время выполнения. Обычно вы видите класс и номер сообщения в любом контексте, где появляются сообщения. Это имеет несколько полезных эффектов:

  • Вы можете автоматически найти любые строки кода в базе кода ABAP, которые создают конкретное сообщение об ошибке.

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

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

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

Пример всплывающего сообщения об ошибке с номером сообщения:

Error1

Поиск этой ошибки в репозитории ошибок:

Error2

Найдите это в кодовой базе:

error3

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

" Do not use special characters
my_custom_error_handler->post_error( class = 'EU' number = '271').
IF 1 = 2.
   MESSAGE e271(eu).
ENDIF.    

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

Philipp
источник
Каталоги сообщений также были частью GNU / Linux - и UNIX вообще как стандарт POSIX - в течение некоторого времени.
епископ
@bishop Я обычно не программирую специально для систем POSIX, поэтому я не знаком с этим. Возможно, вы могли бы опубликовать другой ответ, который объясняет каталоги сообщений POSIX и что OP мог бы узнать из их реализации.
Филипп
3
Я был частью проекта, который сделал это еще во времена прошлого. Одна из проблем, с которой мы столкнулись, заключалась в том, что наряду со всем остальным мы поместили в базу данных сообщение «не удалось подключиться к базе данных».
JimmyJames
5

Проблема с этим подходом состоит в том, что он ведет к более детальному ведению журнала. 99,9999% из которых вы никогда не увидите.

Вместо этого я рекомендую записывать состояние в начале вашего процесса и успех / провал процесса.

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

OrderPlaced {id:xyz; ...order data..}
OrderPlaced {id:xyz; ...Fail, ErrorMessage..}

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

Кроме того, я могу при необходимости избежать больше регистрации, только регистрируя сбои или сохраняя состояние в другом месте (база данных? Очередь сообщений?)

Очевидно, что мы должны быть особенно осторожны при регистрации конфиденциальных данных. Так что это особенно хорошо работает, если ваше решение использует очереди сообщений или шаблон хранилища событий. По логу нужно только сказать "Сообщение xyz Failed"

Ewan
источник
Помещение конфиденциальных данных в очередь все еще регистрирует их. Это опрометчиво, так же как хранение чувствительных входных данных в БД без какой-либо криптографии.
jpmc26
если ваша система запускает очереди или базу данных, тогда данные уже есть, и безопасность должна быть такой же. Ведение слишком большого количества журналов является плохим только потому, что журнал обычно выходит за рамки контроля безопасности.
Эван
Да, но в этом все дело. Это не рекомендуется, потому что эти данные остаются там постоянно и, как правило, в полностью открытом тексте. Для конфиденциальных данных лучше просто не рисковать и минимизировать время хранения, а затем быть очень осведомленным и очень осторожным о том, как вы храните его.
jpmc26
Это традиционно постоянно, потому что вы пишете в файл. Но очередь ошибок временная.
Эван
Я бы сказал, что, вероятно, зависит от реализации (и, возможно, даже от настроек) очереди. Вы не можете просто выбросить это в любую очередь и ожидать, что это будет безопасно. А что происходит после того, как очередь расходуется? Журналы все еще должны быть где-то для просмотра. Кроме того, это не дополнительный вектор атаки, который я хотел бы открыть даже временно. Если атака обнаружит, что туда попадают конфиденциальные данные, даже самые последние записи могут оказаться полезными. Кроме того, существует риск того, что кто-то не узнает и не щелкнет переключателем, поэтому он тоже начинает запись на диск. Это просто банка червей.
jpmc26
1

Я бы предположил, что ведение журнала - это не способ, а скорее то обстоятельство, которое считается исключительным (оно блокирует вашу программу), и следует выдать исключение. Скажи, что твой код был:

public Foo GetFoo() {

     //Expecting that this should never by null.
     var aFoo = ....;

     if (aFoo == null) Log("Could not find Foo.");

     return aFoo;
}

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

public Foo GetFooById(int id) {
     var aFoo = ....;

     if (aFoo == null) throw new ApplicationException("Could not find Foo for ID: " + id);

     return aFoo;
}

И это вернет трассировку стека вместе с исключением, которое можно использовать для отладки.

С другой стороны, если мы ожидаем, что Foo может быть нулевым при получении, и это нормально, нам нужно исправить вызывающие сайты:

void DoSomeFoo(Foo aFoo) {

    //Guard checks on your input - complete with stack trace!
    if (aFoo == null) throw new ArgumentNullException(nameof(aFoo));

    ... operations on Foo...
}

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

Пэдди
источник
0

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

Тем не менее, это действительно зависит от того, что вы хотите, чтобы ваш идентификатор сделал для вас:

  • Соотносить сообщения об ошибках, предоставленные пользователю, с вашими журналами?
  • Укажите, какой код выполнялся при создании сообщения?
  • Отслеживать имя машины и сервисный экземпляр?
  • Отслеживать идентификатор потока?

Все эти вещи могут быть сделаны из коробки с надлежащим программным обеспечением регистрации (то есть не Console.WriteLine()или Debug.WriteLine()).

Лично, что более важно, это способность восстанавливать пути исполнения. Вот для чего предназначены инструменты типа Zipkin . Один идентификатор для отслеживания поведения одного пользовательского действия во всей системе. Поместив свои журналы в центральную поисковую систему, вы можете не только найти самые продолжительные действия, но и вызвать журналы, которые относятся к этому единственному действию (например, стек ELK ).

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

Берин Лорич
источник