Di Java terdapat beberapa Logging Framework untuk mencetak log ke dalam file atau console. Beberapa framework yang gw pernah coba adalah Slf4j, Log4j2, dan Logback. Selain itu juga ada JBoss Logging, Log4j, JUL, tinylog, dan lainnya. Dari review yang pernah gw baca, secara performa Log4j2 yang paling cepat. Log4j2 bisa dikonfigurasi untuk berjalan secara asynchronous. Tentunya dengan resiko ada potensi gagal mencatat log saat aplikasi crash karena log ga langsung di-print, melainkan diantrikan dulu ke dalam Queue lalu di-print secara asynchronous. Kalau Logback, ini jadi default logging framework di Spring Boot. Jika menggunakan Spring Boot kita ga perlu nambah dependency Logback lagi, langsung konfigurasi aja. Logback juga bisa dikonfigurasi menjadi asynchronous walau dari beberapa review yang gw baca tetap ga secepat Log4j2. Sedangkan Slf4j adalah framework abstrak untuk berbagai logging framework. Tugasnya bukan secara langsung mencetak log, melainkan jadi jembatan untuk logging framework lain. Jadi, Slf4j ini abstraknya dan kita bisa pilih implementasi frameworknya kayak Log4j, Log4j2, Logback, JUL, dan lainnya. Yang kita tulis di code adalah Slf4j, nanti Slf4j ini yang meneruskan eksekusinya ke logging framework sesuai yang kita gunakan. Kelebihannya, kita bisa gonta-ganti logging framework hanya dengan mengubah dependency dan config tanpa perubahan di code.
Slf4j-Logback
Misalkan awalnya kita menggunakan Logback.
<dependencies>
<dependency>
<groupId>org.projectlombok</groupId>
<artifactId>lombok</artifactId>
<scope>provided</scope>
<version>1.18.40</version>
</dependency>
<dependency>
<groupId>org.slf4j</groupId>
<artifactId>slf4j-api</artifactId>
<version>2.0.16</version>
</dependency>
<dependency>
<groupId>ch.qos.logback</groupId>
<artifactId>logback-classic</artifactId>
<version>1.5.13</version>
</dependency>
</dependencies>Kita menggunakan dependency Slf4j & Logback, serta Lombok agar penggunaan log di code nantinya lebih simple menggunakan anotasi @Slf4j saja. Lalu tambahkan konfigurasi logback.xml ke dalam path src/main/resources.
<?xml version="1.0" encoding="UTF-8"?>
<configuration>
<appender name="CONSOLE" class="ch.qos.logback.core.ConsoleAppender">
<encoder>
<pattern>[%d{yyyy-MM-dd HH:mm:ss}] [%thread] %-5level %logger{36} - %msg%n</pattern>
</encoder>
</appender>
<appender name="FILE" class="ch.qos.logback.core.rolling.RollingFileAppender">
<file>logs/logback.log</file>
<encoder>
<pattern>[%d{yyyy-MM-dd HH:mm:ss}] [%thread] %-5level %logger{36} - %msg%n</pattern>
</encoder>
<rollingPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedRollingPolicy">
<fileNamePattern>logs/logback-%d{yyyy-MM-dd}-%i.gz</fileNamePattern>
<maxFileSize>1GB</maxFileSize>
</rollingPolicy>
</appender>
<root level="INFO">
<appender-ref ref="CONSOLE"/>
<appender-ref ref="FILE"/>
</root>
</configuration>Kita konfigurasikan untuk membuat log ke console dan ke file logs/logback.log dengan log pattern yang sama. Log tersebut akan di-back up tiap harinya dengan format nama logback-%d{yyyy-MM-dd}-%i.gz dan max size 1GB. Root level yang diaktifkan adalah INFO. Saat kita menulis log maka akan muncul log-nya di path logs/logback.log.
@Slf4j
public class Main{
static void main(){
log.info("Hello World!");
}
}Isi log-nya jadi begini:
[1985-01-10 09:05:49] [main] INFO org.example.Main - Hello World!Slf4j-Log4j2
Misalkan kemudian setelah develop aplikasi kita berubah pikiran ingin menggunakan Log4j2, maka tinggal ubah dependency logback-classic jadi log4j-core & log4j-slf4j2-impl.
<dependencies>
<dependency>
<groupId>org.projectlombok</groupId>
<artifactId>lombok</artifactId>
<scope>provided</scope>
<version>1.18.40</version>
</dependency>
<dependency>
<groupId>org.slf4j</groupId>
<artifactId>slf4j-api</artifactId>
<version>2.0.16</version>
</dependency>
<dependency>
<groupId>org.apache.logging.log4j</groupId>
<artifactId>log4j-slf4j2-impl</artifactId>
<version>2.24.2</version>
</dependency>
<dependency>
<groupId>org.apache.logging.log4j</groupId>
<artifactId>log4j-core</artifactId>
<version>2.24.2</version>
</dependency>
</dependencies>Di bagian config perlu tambahkan file log4j2.xml ke path src/main/resources dengan konfigurasi yang kurang lebih sama dengan Logback sebelumnya. Log akan di-print ke file logs/log4j2.log.
<?xml version="1.0" encoding="UTF-8"?>
<Configuration>
<Appenders>
<Console name="Console" target="SYSTEM_OUT">
<PatternLayout pattern="[%d{yyyy-MM-dd HH:mm:ss}] [%t] %-5level %logger{36} - %msg%n"/>
</Console>
<RollingFile name="FileAppender"
fileName="logs/log4j2.log"
filePattern="logs/log4j2-%d{yyyy-MM-dd}-%i.gz">
<PatternLayout>
<pattern>[%d{yyyy-MM-dd HH:mm:ss}] [%t] %-5level %logger{36} - %msg%n</pattern>
</PatternLayout>
<Policies>
<TimeBasedTriggeringPolicy interval="1"/>
<SizeBasedTriggeringPolicy size="1GB"/>
</Policies>
</RollingFile>
</Appenders>
<Loggers>
<Root level="info">
<AppenderRef ref="Console"/>
<AppenderRef ref="FileAppender"/>
</Root>
</Loggers>
</Configuration>Di bagian code tidak perlu diubah sama sekali, Slf4j yang akan otomatis melakukan routing ke Log4j2😎. Kita tinggal diduk manis dan jalankan saja aplikasinya. Hasil log-nya seperti ini:
[1985-01-10 09:05:49] [main] INFO org.example.Main - Hello World!Dengan begini kita bisa bebas gonta-ganti logging framework dari Log4j, Log4j2, Logback, JUL, dan lainnya. Misalkan ternyata Log4j2 ada bugs seperti dulu yang pernah terjadi, maka kita bisa balik lagi ke Logback tanpa mengubah code sama sekali😎.
Log Level
Di dalam Logging terdapat kurang lebih 5 atau 6 log level.
Trace
Ini adalah level terendah dan jarang banget digunakan. Sejujurnya gw hampir ga pernah pake log level ini. Biasanya ini digunakan untuk nge-trace setiap langkah dari algoritma yang ditulis saat development.
Debug
Sesuai namanya, level ini digunakan saat melakukan debug saat development atau saat mencari bugs. Misalnya saat mau nge-print sample query yang dieksekusi yang berpotensi bermasalah. Di production harusnya level Debug dan Trace ga diaktifkan, kecuali emang lagi nyari bugs.
Info
Ini adalah log level selanjutnya di mana fungsinya adalah untuk memberikan info umum. Kayak event tertentu, sample request masuk, port tempat aplikasi jalan, config aplikasi yang sedang aktif, dan sejenisnya. Di production umumnya level ini yang diaktifkan.
Warn
Warn adalah log level yang cukup tinggi. Biasanya digunakan ketika terjadi kesalahan secara bisnis seperti input yang salah, validasi yang gagal, dan sejenisnya. Ini berguna untuk nge-track log yang perlu diperhatikan karena berpotensi diakibatkan oleh bugs.
Error
Error adalah log level tertinggi. Ini digunakan ketika terjadi kesalahan teknis pada aplikasi seperti NullPointerException, query error, ada path yang ga bisa diakses, atau internal error lainnya yang mengganggu kelancaran jalannya aplikasi. Ini berguna untuk nge-track bugs yang perlu diperbaiki secepatnya.
Fatal/Critical
Secara umum level tertinggi adalah Error seperti yang ada pada fitur Slf4j, tapi ada beberapa framework lain yang memiliki level yang lebih tinggi lagi, yaitu Fatal atau Critical. Ini biasanya untuk error yang benar-benar membuat aplikasinya benar-benar ga bisa digunakan seperti memory penuh, ga bisa konek ke database, API ga bisa diakses, dan lainnya. Di Slf4j ini termasuk scope level Error karena itu level yang paling tinggi di sana.
Log Level Config
Pada saat development biasanya level yang diaktifkan pada config adalah Debug agar saat terjadi sesuatu ketika development langsung kelihatan. Sedangkan untuk production biasanya level yang diaktifkan adalah Info agar log terkait development yang disimpan di dalam file tidak makan tempat karena di production tentu jumlah proses yang masuk akan sangat banyak. Saat menggunakan monitoring tools untuk membaca log, biasanya level yang diaktifkan adalah Warn biar proses monitoringnya hanya untuk log yang benar-benar perlu perhatian khusus.
Jika kita mengaktifkan log level Info, maka log yang akan di-print adalah log level Info dan log level lain yang levelnya lebih tinggi seperti Warn dan Error. Kalau log level yang diaktifkan adalah Warn, maka yang akan di-print adalah log level Warn dan Error saja. Begitu seterusnya. Sehingga meskipun di dalam codebase yang sama terdapat berbagai log level yang ditulis, yang akan di-print tetap sesuai level yang diaktfikan dalam config di masing-masing environment beserta log level yang lebih tinggi. Kita ga perlu khawatir log yang ga seharusnya di-print tercetak dan ga perlu handle manual di dalam code. Contohnya di konfigurasi log di atas levelnya adalah Info, jika kita print menggunakan level Debug atau Trace maka ini ga akan muncul di log.
@Slf4j
public class Main{
static void main(){
log.trace("nothing!");
log.debug("also nothing!");
log.info("printed!");
log.warn("also printed!");
log.error("it's printed too!");
}
}Yang muncul di log sebagai berikut:
[1985-01-10 09:57:30] [main] INFO org.example.Main - printed!
[1985-01-10 09:57:30] [main] WARN org.example.Main - also printed!
[1985-01-10 09:57:30] [main] ERROR org.example.Main - it's printed too!Concat Log
Untuk hal sederhana seperti pada contoh sebelumnya yang cuma print "hello world" tinggal tulis aja menggunakan String. Masalahnya adalah saat ingin print objek dengan concat String.
@Slf4j
public class Main{
static void main(){
int x = 1;
double d = 1.0;
String s = "2";
log.debug("Hello World! " + x + " + " + d + " = " + s);
}
}Di production log level yang diaktifkan adalah Info, sehingga log di atas ga dieksekusi. Melakukan concat String di sini jadi hal mubazir. Masalahnya adalah itu makan memori. Kelihatannya sepele, tapi jika banyak concat String di dalam log level yang ga terpakai kayak gini pada aplikasi dengan traffic tinggi maka lama-lama jadi beban juga.
FYI, Java menggunakan StringBuilder untuk concat String satu statement menggunakan symbol +. Dengan StringBuilder, char array dari String akan ditampung dan bisa dimutasi tanpa perlu bikin objek baru tiap append. Jadi code di atas setara dengan code berikut:
int x = 1;
double d = 1.0;
String s = "2";
log.debug(new StringBuilder().append("Hello World! ").append(x).append(" + ").append(d).append(" = ").append(s).toString());Ini mubazir kalau String tersebut ga di-print pada log karena Java bikin objek baru dan memutasi String yang pada akhirnya ga dipake. Agar lebih efisien, kita bisa menggunakan log format seperti berikut.
int x = 1;
double d = 1.0;
String s = "2";
log.debug("Hello World! {} + {} = {}", x, d, s);Kita bisa menulis String dengan format menggunakan placeholder {} untuk variabel yang ingin di-concat. Variabel yang ingin di-concat ditulis pada argument setelah format. Jumlah placeholder harus sama dengan jumlah argument yang digunakan. Dengan begini, concat hanya dilakukan jika log level yang aktif adalah Debug. Selain itu maka ga ada concat sama sekali sehingga lebih efisien😎. Oh ya, pendekatan ini beda dengan menggunakan String.format() karena itu tetap akan melakukan komputasi format String meskipun log ga terpakai sehingga ga efisien. Log dengan String format juga sebaiknya dihindari.
Computed Log
Misalkan kita ingin print sesuatu yang valuenya berasal dari komputasi sebuah method yang dieksekusi pada log Debug. Ini juga bisa bermasalah karena dapat mengganggu jalannya aplikasi jika log level yang aktif di production levelnya di atas Debug.
@Slf4j
public class Main{
static void main(){
log.debug("Hello World! {}", getComputed());
}
@SneakyThrows
private static int getComputed(){
TimeUnit.SECONDS.sleep(30);
return ThreadLocalRandom.current().nextInt();
}
}Meskipun kita udah menggunakan log format, mode sleep selama 30 detik tetap dieksekusi pada code di atas walaupun log levelnya ga aktif. Untuk mengatasinya, gunakan lambda agar eksekusi method tersebut jadi lazy.
log.atDebug().log(() -> "Hello World! " + getComputed());Kita bisa menggunakan log builder atDebug() dan mengeksekusi method log() dengan input lambda agar eksekusi method getComputed() hanya akan dilakukan jika log level Debug aktif. Dengan pendekatan ini kita bisa menggunakan concat kembali dengan aman karena methodnya lazy sehingga concat juga hanya akan dilakukan pada log level yang aktif😎.
Verdict
Saat menggunaan Spring Boot kita ga perlu nambah dependency Logback lagi jika ingin menggunakannya karena udah included by default. Dengan Log4j2 kita bisa menggunakan logging dengan performa yang cepat. Dengan Slf4j kita bisa gonta-ganti logging framework dengan gampang. Gw sendiri lebih sering menggunakan perpaduan Slf4j dengan Log4j2. Secara umum ada 5 log level yang bisa dikonfigurasi seperti Trace, Debug, Info, Warn, dan Error. Beberapa framework lain ada juga hingga level Fatal/Critical. Log hanya muncul sesuai level yang dikonfigurasi atau level di atasnya. Saat menulis log sebaiknya hindari menggunakan concat String karena akan bikin objek yang mubazir jika log dinonaktifkan. Menggunakan log format dengan placeholder dalam hal ini lebih efisien. Jika log message diambil dari hasil eksekusi sebuah method, maka gunakan lambda agar eksekusi tersebut hanya dilakukan saat levelnya aktif. Secara personal gw lebih memilih logging menggunakan lambda by default, termasuk saat concat String karena bagi gw menggunakan placeholder agak ribet.