Di Java terdapat beberapa Logging Framework untuk memaintain 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. Masing-masing ada kelebihan dan kekurangannya. Dari review yang pernah gw baca, secara performa Log4j2 yang paling bagus karena berjalan secara asynchronous. Tentunya dengan resiko ada potensi gagal mencatat log saat aplikasi crash karena log ga langsung diprint, melainkan diantrikan dulu ke dalam Queue lalu diprint secara asynchronous. Kalau Logback, ini jadi default logging framework di Spring Boot. Kalau kita pakai Spring Boot kita ga perlu nambah dependency Logback lagi, langsung konfigurasi aja. By default ini synchronous dan log langsung diprint sehingga lebih konsisten. Resikonya, kalau traffic tinggi tentu bisa blocking. Tapi Logback juga bisa dikonfigurasi manual 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 nge-print 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 jalankan 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.
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 dan 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>
<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 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 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 step dari algoritma saat development di local.
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 request seperti input yang salah, validasi business logic 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 menyimpan 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 akan memberatkan juga.
FYI, di Java versi terdahulu, saat kita concat String itu yang terjadi adalah Java akan bikin objek baru terus-terusan tiap concat karena String itu Immutable. Di versi yang lebih terbaru, ini udah di-improve. Compiler Java akan mengonversi concat dalam satu statement ini menggunakan StringBuilder saat compile. Dengan StringBuilder, objek String bisa dimutasi tanpa perlu bikin objek baru tiap concat sehingga lebih efisien. Jadi code di atas setelah compile ke bytecode bentuknya kurang lebih seperti ini:
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());Concat ini udah di-handle otomatis di Java, sehingga kita ga perlu handle manual. Ini hanya berlaku pada concat satu statement. Kalau concat lebih dari satu statement, apalagi concat di dalam looping maka ini tetap beban karena Java akan bikin StringBuilder tiap statement. Makanya best practice concat dengan statement lebih dari satu kayak saat looping maka perlu handle sendiri pake StringBuilder.
Walaupun sudah improve, Java tetap bikin objek baru. Bedanya kali ini bukan bikin objek String baru lagi terus-terusan tiap concat. Ini masih mubazir kalau String tersebut ga di-print pada log karena Java akan bikin StringBuilder untuk concat dan memutasi String yang kemudian 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😎.
Computed Log
Misalkan kita ingin print sesuatu yang objeknya diambil dari sebuah method yang dieksekusi pada log Debug. Ini juga bisa bermasalah karena dapat mengganggu jalannya aplikasi jika log level yang aktif levelnya di atas Debug.
@Slf4j
public class Main{
static void main(){
log.debug("Hello World! {}", getComputed());
}
@SneakyThrows
private static int getComputed(){
TimeUnit.SECONDS.sleep(3);
return ThreadLocalRandom.current().nextInt();
}
}Meskipun kita udah ga menggunakan concat, komputasi tetap dijalankan pada code di atas. Untuk mengatasinya, kita bisa menggunakan lambda agar method tersebut jadi lazy.
log.atDebug().log(() -> "Hello World! " + getComputed());Kita bisa menggunakan builder atDebug() dan mengeksekusi 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 jika level Debug aktif😎.
Verdict
Dengan Logback saat menggunaan Spring Boot kita ga perlu nambah dependency lagi 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.