Условное ведение журнала с минимальной цикломатической сложностью

В Python вы передаете отформатированные значения в качестве параметров функции регистрации. Форматирование строки применяется только в том случае, если включено ведение журнала. По-прежнему существуют накладные расходы, связанные с вызовом функции, но они мизерные по сравнению с форматированием.

log.info ("a = %s, b = %s", a, b)

Вы можете сделать что-то подобное для любого языка с вариативными аргументами (C / C ++, C # / Java и т. Д.).

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

Поскольку в вопросе OP конкретно упоминается Java, вот как можно использовать приведенное выше:

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

Уловка состоит в том, чтобы иметь объекты, которые не будут выполнять дорогостоящие вычисления до тех пор, пока они не станут абсолютно необходимыми. Это легко сделать в таких языках, как Smalltalk или Python, которые поддерживают лямбда-выражения и замыкания, но все же это можно сделать в Java, проявив немного воображения.

Допустим, у вас есть функция get_everything(). Он будет извлекать каждый объект из вашей базы данных в список. Очевидно, вы не хотите называть это, если результат будет отброшен. Поэтому вместо прямого вызова этой функции вы определяете внутренний класс с именем LazyGetEverything:

public class MainClass {
    private class LazyGetEverything { 
        @Override
        public String toString() { 
            return getEverything().toString(); 
        }
    }

    private Object getEverything() {
        /* returns what you want to .toString() in the inner class */
    }

    public void logEverything() {
        log.info(new LazyGetEverything());
    }
}

В этом коде вызов getEverything() заключен в оболочку, так что на самом деле он не будет выполняться, пока он не понадобится. Функция регистрации выполнит toString() для своих параметров, только если включена отладка. Таким образом, ваш код будет нести только накладные расходы на вызов функции вместо полного вызова getEverything().

С текущими фреймворками логирования вопрос спорный

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

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

Действительно ли охранные заявления добавляют сложности?

Рассмотрите возможность исключения заявлений охранников лесозаготовок из расчета цикломатической сложности.

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

Негибкие метрики могут испортить хорошего программиста. Будь осторожен!

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

Необходимость условного ведения журнала

Я предполагаю, что ваши операторы защиты были введены, потому что у вас был такой код:

private static final Logger log = Logger.getLogger(MyClass.class);

Connection connect(Widget w, Dongle d, Dongle alt) 
  throws ConnectionException
{
  log.debug("Attempting connection of dongle " + d + " to widget " + w);
  Connection c;
  try {
    c = w.connect(d);
  } catch(ConnectionException ex) {
    log.warn("Connection failed; attempting alternate dongle " + d, ex);
    c = w.connect(alt);
  }
  log.debug("Connection succeeded: " + c);
  return c;
}

В Java каждый из операторов журнала создает новый StringBuilder и вызывает метод toString() для каждого объекта, присоединенного к строке. Эти toString() методы, в свою очередь, могут создавать StringBuilder собственных экземпляров и вызывать toString() методы своих членов и т. Д. В потенциально большом графе объектов. (До Java 5 это было еще дороже, поскольку использовалось StringBuffer, и все его операции синхронизированы.)

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

Это приводит к введению охранных заявлений в форме:

  if (log.isDebugEnabled())
    log.debug("Attempting connection of dongle " + d + " to widget " + w);

С помощью этой защиты оценка аргументов d и w и конкатенация строк выполняется только при необходимости.

Решение для простой и эффективной регистрации

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

public final class FormatLogger
{

  private final Logger log;

  public FormatLogger(Logger log)
  {
    this.log = log;
  }

  public void debug(String formatter, Object... args)
  {
    log(Level.DEBUG, formatter, args);
  }

  … &c. for info, warn; also add overloads to log an exception …

  public void log(Level level, String formatter, Object... args)
  {
    if (log.isEnabled(level)) {
      /* 
       * Only now is the message constructed, and each "arg"
       * evaluated by having its toString() method invoked.
       */
      log.log(level, String.format(formatter, args));
    }
  }

}

class MyClass 
{

  private static final FormatLogger log = 
     new FormatLogger(Logger.getLogger(MyClass.class));

  Connection connect(Widget w, Dongle d, Dongle alt) 
    throws ConnectionException
  {
    log.debug("Attempting connection of dongle %s to widget %s.", d, w);
    Connection c;
    try {
      c = w.connect(d);
    } catch(ConnectionException ex) {
      log.warn("Connection failed; attempting alternate dongle %s.", d);
      c = w.connect(alt);
    }
    log.debug("Connection succeeded: %s", c);
    return c;
  }

}

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

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

Дальнейшие улучшения

Также обратите внимание, что в Java объект MessageFormat может использоваться вместо «формата» String, что дает вам дополнительные возможности, такие как формат выбора для более аккуратной обработки количественных чисел. Другой альтернативой может быть реализация вашей собственной возможности форматирования, которая вызывает некоторый интерфейс, который вы определяете для «оценки», а не базовый метод toString().

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

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

Но как всегда: если сомневаетесь, протестируйте его и измерьте влияние на загрузку процессора и память.

Спасибо за все ваши ответы! Ребята, молодцы :)

Теперь мой отзыв не такой прямолинейный, как ваш:

Да, для одного проекта (например, «одна программа развернута и работает сама по себе на одной производственной платформе»), я полагаю, вы можете пойти на меня со всеми техническими вопросами:

• выделенные объекты 'Log Retriever', которые могут быть переданы в оболочку Logger, необходим только вызов toString ()
• используется вместе с вариативной функцией (или обычным массивом Object []!)

Вот и все, как объяснили @John Millikin и @erickson.

Однако эта проблема заставила нас немного задуматься о том, «Почему мы вообще вели лог?»
Наш проект на самом деле состоит из 30 различных проектов (от 5 до 10 человек каждый), развернутых на различных производственных платформах, с потребностями в асинхронной связи. и архитектура центральной шины.
Простое ведение журнала, описанное в вопросе, подходило для каждого проекта в начале (5 лет назад), но с тех пор мы должны сделать шаг вперед. Введите KPI.

Вместо того, чтобы просить регистратор регистрировать что-либо, мы просим автоматически созданный объект (называемый KPI) зарегистрировать событие. Это простой вызов (myKPI.I_am_signaling_myself_to_you ()), который не обязательно должен быть условным (что решает проблему «искусственного увеличения цикломатической сложности»).

Этот объект KPI знает, кто его вызывает, и, поскольку он запускается с самого начала приложения, он может извлекать множество данных, которые мы ранее вычисляли на месте, когда мы регистрировали.
Плюс этот объект KPI можно отслеживать независимо и вычислять / публиковать по запросу свою информацию на единой и отдельной шине публикации.
Таким образом, каждый клиент может запросить информацию, которую он действительно хочет (например, «начался ли мой процесс, и если да, с каких это пор?»), вместо того, чтобы искать правильный файл журнала и искать загадочную строку ...

В самом деле, вопрос: «Почему мы вообще врубались?» заставили нас понять, что мы ведем журналы не только для программиста и его модульных или интеграционных тестов, но для гораздо более широкого сообщества, включая самих конечных клиентов. Наш механизм «отчетности» должен был быть централизованным, асинхронным, 24/7.

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

Еще раз спасибо за все предложения. Мы рассмотрим их для некоторых частей нашей системы, когда еще существует простое ведение журнала.
Но другой момент в этом вопросе заключался в том, чтобы проиллюстрировать вам конкретную проблему в гораздо более широком и более сложном контексте.
Надеюсь, вы понравилось. Я мог бы задать вопрос по KPI (который, верьте или нет, пока не обсуждается в SOF!) Позже на следующей неделе.

Я оставлю этот ответ на голосование до следующего вторника, затем выберу ответ (явно не этот;))

Может быть, это слишком просто, но как насчет использования рефакторинга "метода извлечения" вокруг предложения защиты? Ваш пример кода этого:

public void Example()
{
  if(myLogger.isLoggable(Level.INFO))
      myLogger.info("A String");
  if(myLogger.isLoggable(Level.FINE))
      myLogger.fine("A more complicated String");
  // +1 for each test and log message
}

Становится это:

public void Example()
{
   _LogInfo();
   _LogFine();
   // +0 for each test and log message
}

private void _LogInfo()
{
   if(!myLogger.isLoggable(Level.INFO))
      return;

   // Do your complex argument calculations/evaluations only when needed.
}

private void _LogFine(){ /* Ditto ... */ }

В C или C ++ я бы использовал препроцессор вместо операторов if для условного ведения журнала.

Передайте уровень журнала в средство ведения журнала и позвольте ему решить, следует ли записывать оператор журнала:

//if(myLogger.isLoggable(Level.INFO) {myLogger.info("A String");
myLogger.info(Level.INFO,"A String");

ОБНОВЛЕНИЕ: Ах, я вижу, что вы хотите условно создать строку журнала без условного оператора. Предположительно во время выполнения, а не во время компиляции.

Я просто скажу, что способ, которым мы это решили, - это поместить код форматирования в класс регистратора, чтобы форматирование происходило только в том случае, если уровень прошел. Очень похоже на встроенный sprintf. Например:

myLogger.info(Level.INFO,"A String %d",some_number);   

Это должно соответствовать вашим критериям.

Условное ведение журнала - зло. Это добавляет ненужный беспорядок в ваш код.

Вы всегда должны отправлять в регистратор объекты, которые у вас есть:

Logger logger = ...
logger.log(Level.DEBUG,"The foo is {0} and the bar is {1}",new Object[]{foo, bar});

а затем иметь java.util.logging.Formatter, который использует MessageFormat для сглаживания foo и bar в строку для вывода. Он будет вызываться только в том случае, если регистратор и обработчик будут регистрироваться на этом уровне.

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

_{(источник: scala-lang.org)}

Scala имеет аннотацию @ elidable (), который позволяет удалять методы с флагом компилятора.

С помощью scala REPL:

C:> scala

Добро пожаловать в Scala версии 2.8.0.final (64-разрядная серверная виртуальная машина Java HotSpot ™, Java 1. 6.0_16). Введите выражения, чтобы они оценивались. Введите: help для получения дополнительной информации.

scala> импорт scala.annotation.elidable импорт scala.annotation.elidable

scala> импорт scala.annotation.elidable._ импорт scala.annotation.elidable._

scala> @elidable (FINE) def logDebug (аргумент: строка) = println (аргумент)

logDebug: (arg: String) Единица

scala> logDebug («тестирование»)

scala>

С elide-beloset

C:> scala -Xelide-ниже 0

Добро пожаловать в Scala версии 2.8.0.final (64-разрядная серверная виртуальная машина Java HotSpot ™, Java 1. 6.0_16). Введите выражения, чтобы они оценивались. Введите: help для получения дополнительной информации.

scala> импорт scala.annotation.elidable импорт scala.annotation.elidable

scala> импорт scala.annotation.elidable._ импорт scala.annotation.elidable._

scala> @elidable (FINE) def logDebug (аргумент: строка) = println (аргумент)

logDebug: (arg: String) Единица

scala> logDebug («тестирование»)

тестирование

scala>

См. Также определение утверждения Scala

Как бы я ни ненавидел макросы в C / C ++, на работе у нас есть #defines для части if, которая, если false игнорирует (не оценивает) следующие выражения, но если true возвращает поток, в который материал может быть передан по конвейеру с помощью ' ‹< 'оператор. Нравится:

LOGGER(LEVEL_INFO) << "A String";

Я предполагаю, что это устранит дополнительную «сложность», которую видит ваш инструмент, а также устранит любое вычисление строки или любых выражений, которые нужно регистрировать, если уровень не был достигнут.

Вот элегантное решение с использованием тернарного выражения

logger.info (logger.isInfoEnabled ()? "Здесь идет инструкция журнала ...": null);

Рассмотрим функцию утилиты ведения журнала ...

void debugUtil(String s, Object… args) {
   if (LOG.isDebugEnabled())
       LOG.debug(s, args);
   }
);

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

debugUtil(“We got a %s”, new Object() {
       @Override String toString() { 
       // only evaluated if the debug statement is executed
           return expensiveCallToGetSomeValue().toString;
       }
    }
);