Могу ли я действительно доверять меткам времени LOG4J для показателей производительности в производственной среде? - PullRequest
Новая
       37

Могу ли я действительно доверять меткам времени LOG4J для показателей производительности в производственной среде?

1 голос
/ 07 ноября 2019

В офисе, рядом с которым размещено мое веб-приложение, LOG4J показывает, что типичная операция, проверенная локально, занимает <1 с, </p> 

07 Nov 2019 12:30:01,860 INFO  ParticipantServiceImpl(Line 272) - User 1: Operation Start
...
07 Nov 2019 12:30:02,796 INFO  ParticipantServiceImpl(Line 881) - User 1: Operation End

. Производство LOG4J показывает, что со многими одновременными пользователями, подключающимися по всему мируна их телефонах средняя продолжительность работы ближе к 5-7 сек. Вывод часто путается и выходит из строя, но меня беспокоит отметки времени : надежны ли сами отметки времени (даже если они вышли из строя)? У меня действительно есть проблема с производительностью в реальном пользовательском интерфейсе, или у LOG4J может быть некоторая задержка сброса или одновременности? 

07 Nov 2019 12:30:01,860 INFO  ParticipantServiceImpl(Line 272) - User 1: Operation Start
07 Nov 2019 12:31:01,860 INFO  ParticipantServiceImpl(Line 272) - User 2: Operation Start
...
07 Nov 2019 12:37:02,796 INFO  ParticipantServiceImpl(Line 881) - User 1: Operation End

LOG4J настроен как 

    <RollingFile name="file" fileName="/local/content/tomcat/app/logs/app.log" append="true"
        filePattern="/local/content/tomcat/app/logs/app.log.%i"> 
        <PatternLayout>
            <Pattern>%d{DATE} %-5p %c{1}(Line %L) - %m%n</Pattern>
        </PatternLayout>
        <Policies>
            <SizeBasedTriggeringPolicy size="5 MB" />
        </Policies>
        <DefaultRolloverStrategy max="5" />
    </RollingFile>
</Appenders>

<Loggers>    
    <Logger name="com.app" level="debug">
    <AppenderRef ref="console"/>
        <AppenderRef ref="file"/>
    </Logger>

    <Logger name="com.opensymphony.xwork2.interceptor" level="info">
        <AppenderRef ref="file" />
    </Logger>

    <Logger name="org.springframework.orm" level="info">
        <AppenderRef ref="file" />
    </Logger>    

    <Logger name="org.hibernate.engine.transaction" level="DEBUG">
        <AppenderRef ref="console" />
    </Logger>   

    <Logger name="net.sf.ehcache" level="trace">
        <AppenderRef ref="file" />
    </Logger>

    <Root level="info">
      <AppenderRef ref="console"/>
      <AppenderRef ref="file"/>
    </Root>
</Loggers>

1 Ответ

0 голосов
/ 07 ноября 2019

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

Имя свойства : log4j2.clock

Переменная среды : LOG4J_CLOCK

Значение по умолчанию : SystemClock

Описание : Реализация интерфейса org.apache.logging.log4j .core.util.Clock, который используется для отметки времени событий журнала. По умолчанию System.currentTimeMillis вызывается при каждом событии журнала. Вы также можете указать полное имя класса пользовательского класса, который реализует интерфейс часов.

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

Другой подход

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

long startTime = System.currentTimeMillis();
// perfom the task
long endTime = System.currentTimeMillis();
LOG.info("Duration: " + (endTime - startTime)); // you can also convert milliseconds to hours,minutes, secconds
...