Intro to Logging
-
Logging systems
- javascript app (
console.log)- useful only for devs that open Development/Debug Console
- there is a convention that libraries do not log anything
- server-side
- useful for investigation post-factum (after they happened)
- the server cannot(is not efficient to be restarted) at will (with new debug in it)
- all clients depend on this server
- solution: do not delete logging
- javascript app (
-
Issues
- there are multiple logging libraries
- each library can use any of them
- hiper efficient: libraries think that they log to their library but this is effiently redirected to the actual library (see http://www.slf4j.org/manual.html)
- as developer I might not want to see all INFO events
- wrong: you might miss important information
- if really necessary, temporarly you can put ROOT on WARN.
-
Solutions
- we need a common logging library: slf4j
- logging api standard: slf4j
- logging library: logback
- configure logback for some usage scenarios
- configure log in environments
- production:
classpath:logback.xml - development:
classpath:logback.xml - tests:
classpath:logback-test.xml(overridesclasspath:logback.xml)
- production:
- configure log locally on a dev machine or override by devops
- enable/disable levels from command line or args-files
-Dapplog.level=WARN -Dapplog.revobet.level=WARN
- enable/disable levels from command line or args-files
- configure log at runtime
-
logback.xmlif outside jvm (by devops) the file can be changed and the change is detected14:27:12,832 |-INFO in ch.qos.logback.classic.joran.action.ConfigurationAction - Will scan for changes in [file:/D:/home/raiser/work/revobet-backend/target/classes/logback.xml] 14:27:12,832 |-INFO in ch.qos.logback.classic.joran.action.ConfigurationAction - Setting ReconfigureOnChangeTask scanning period to 10 seconds - configure log from
FeatureService(false -> level high: WARN , true -> level low : DEBUG)2021-10-07 14:27:14.193+0300 1836 #INFO [main ] Register feature LoggerFeature(debugLogKafkaInternal/null with value [false]. atCompile=[false] atStart=[None] atRuntime=[None]) - org.jedio.feature.FeatureService.register (FeatureService.java:19) - 2021-10-07 14:27:14.193+0300 1836 #INFO [main ] switchLogger Logger[org.apache.kafka] to INFO - org.jedio.feature.FeatureService.change (LoggerFeature.java:71) -
- configure log from
FeatureServicenu are mod de disable -> revert to defaults- needs to take into consideration inheritance
- logging feature to configure exact level or inherited
-
- configure log in environments
- we need a common logging library: slf4j
-
Concepts
- level - ordered level. Enabling for INFO means also enabling for WARN and ERROR.
- recomandari
- mesajul - splited for performance reasons
- format
- arguments
- category - hierarchical label that can influence the decision to log (ROOT = INFO, org.* = WARN, org.revobet.* = INFO, org.revobet.feed.*=ERROR)
- there is an inheritance mecanism for enabling disabling levels
- level - ordered level. Enabling for INFO means also enabling for WARN and ERROR.
-
In java you do not delete the log instructions
-
nu stergi. ai avut nevoie de loguri sa faci codul bun vor avea nevoie si mentainerii de cod
-
problema de performanta e rezolvata prin pasarea de obiecte si nu de concatenare manuala a mesajului
-
apoi in java ai si package-ul care da un context logului
-
si poti usor configura ca orice sub un package sa nu mai fie afisat si deci sa nu consume spatiu
-
Clasele au anotarea @Slf4j
-
In loc de anotarea aia ai fi putut scrie cod in clasa private static final Logger logger = LoggerFactory.getLogger(FluxFeed.class);
-
practic fieldul log e definit in felul asta local packageului si clasei in care e
el e alt log care stie ca contextul e clasa in care e
De-asta tu oricand poti aplica filtre
revobet.* -> warn
revobet.feed.lsports->debug
revobet.controller.* ->info
tu vrei root -> warn
si apoi faci overwrite la packetul tau cu packageulSauClasaDeInteresVlad ->INFO/DEBUG
acum iti zic ce sa-ti configurezi
hai sa le comitem cu modul imediat superior celui care are loguri in acel pachet Astefel incat logul sa fie gol pentru un nou dezvoltator?
Exact cum iti trebuie la development asa raman in cod si asa sunt comise
Filtrarea o face cel ce are nevoie de ea. Nu comiti cod ca poate are unul din viitor nevoie de alta filtrae.
ok, am inteles principiul, imi setez eu local nivelurile
- Best API/contract is slf4j: https://www.slf4j.org/manual.html
- Log4j is deprecated and continued by slf4j.
- A good implementation of slf4j is logback.
- FATAL - jvm might crash
- ERROR - something bad happened usually program should stop working
- WARN - something is bad but we can continue
- INFO - operation that is not repetitive, low volume
- default level in production where you see everything that happens in production that is not repetitive or dependent on a volume
- in production that has INFO enabled: you want to know everything but do not want to affect performance or visibility with a lot of log
- examples that should not be on info
- users normal usage requests -> dependent on the volume of users/calls per user
- jobs(kafka, quartz, etc) that run hourly or often
- running something at minute/second level
- DEBUG - operation that is repeated, high volume
- TRACE - some gory details
File logback.xml or logback-test.xml
<?xml version="1.0" encoding="UTF-8"?>
<configuration debug="true" packagingData="true" scan="true" scanPeriod="30 seconds">
<!--disable debug <statusListener class="ch.qos.logback.core.status.OnConsoleStatusListener" /> -->
<timestamp key="startTimestamp" datePattern="yyyyMMddHHmmssSSS"/>
<property name="profile" value="test" />
<property name="logs" value="${application.home:-${user.dir}}/target/home/.logs-${profile}--${startTimestamp}" />
<appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
<encoder>
<!-- eclipse clickable place -->
<!-- %4relative %highlight - to color-->
<pattern>%4relative [%level] [%-10.10thread] \(%file:%line\) %-120message - %logger{10.10}.%-20.20method - %n%xException</pattern>
</encoder>
</appender>
<appender name="FILE" class="ch.qos.logback.core.rolling.RollingFileAppender">
<!-- Support multiple-JVM writing to the same log file -->
<prudent>false</prudent>
<file>${logs}/namek.log</file>
<encoder class="ch.qos.logback.classic.encoder.PatternLayoutEncoder">
<pattern>%4relative [%level] [%-10.10thread] %-200message%xThrowable - %date{yyyy-MM-dd-'T'-HH-mm-ss-SSS} %logger.%method\(%file:%line\)%n</pattern>
<!--
<pattern>%date %5p [%t] %logger.%M\(%F:%L\) - %m%n</pattern>
<pattern>%4relative %5p [%-17thread] - %-200msg - %date %logger{30}\(%file:%line\)%n</pattern>
<pattern>%4relative %coloredLevel [%-17thread] %logger{15}.%M\(%F:%L\) - %message%n%xException{5}</pattern>
<pattern>%date - [%level] - from %logger in %thread %n%message%n%xException%n</pattern></pattern>
-->
</encoder>
<rollingPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedRollingPolicy">
<fileNamePattern>${logs}/namek-%d{yyyy-MM-dd}-%02i.log</fileNamePattern>
<maxFileSize>10MB</maxFileSize>
<maxHistory>60</maxHistory>
<totalSizeCap>20GB</totalSizeCap>
</rollingPolicy>
</appender>
<appender name="FILE-WARN"
class="ch.qos.logback.core.rolling.RollingFileAppender">
<file>${logs}/namek-warn.log</file>
<encoder class="ch.qos.logback.classic.encoder.PatternLayoutEncoder">
<pattern>%4relative %level [%-10.10thread] %-200message - $d %logger{30}.%M\(%file:%line\)%n</pattern>
</encoder>
<rollingPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedRollingPolicy">
<fileNamePattern>${logs}/namek-warn-%d{yyyy-MM-dd}-%02i.log</fileNamePattern>
<maxFileSize>10MB</maxFileSize>
<maxHistory>60</maxHistory>
<totalSizeCap>20GB</totalSizeCap>
</rollingPolicy>
<filter class="ch.qos.logback.classic.filter.ThresholdFilter">
<level>WARN</level>
</filter>
</appender>
<logger name="ch.qos.logback" level="WARN" />
<root level="DEBUG">
<appender-ref ref="STDOUT" />
<appender-ref ref="FILE" />
<appender-ref ref="FILE-WARN" />
</root>
</configuration>