Logging & Konfigurasi

Kenapa ini penting

Jam 2 pagi, seorang pelanggan mengirim pesan: "Saya sudah bayar tapi pesanan saya hilang." Tanpa log, kamu hanya bisa menebak. Dengan log yang baik, kamu bisa mencari request pelanggan itu, melihat endpoint apa yang dipanggil, status apa yang dikembalikan, berapa lama prosesnya, dan error apa yang terjadi, lengkap dengan jamnya. Log adalah kotak hitam pesawat untuk servermu. Kamu tidak membutuhkannya setiap hari, tapi saat ada masalah, hanya itu yang bisa diandalkan.

Konfigurasi juga sama pentingnya. Aplikasi yang sama berjalan di beberapa lingkungan (environment): laptopmu (development), tes otomatis (test), dan server sungguhan (production). Masing-masing butuh database, level log, dan kunci rahasia yang berbeda. Kalau nilai-nilai itu ditulis langsung di kode, kamu harus mengubah kode setiap kali pindah lingkungan, dan cepat atau lambat kunci produksi akan ter-commit ke Git.

Terakhir, server harus bisa dimatikan dengan sopan. Saat deploy versi baru, server lama dimatikan. Kalau dimatikan mendadak, pelanggan yang sedang checkout bisa mendapat error di tengah transaksi. Teknik mematikan dengan rapi ini disebut graceful shutdown.

Konsep inti

Kenapa bukan console.log?

console.log cocok untuk debugging cepat, tapi kurang untuk produksi:

• Tidak punya level, jadi pesan penting tercampur dengan pesan debug.
• Formatnya teks bebas, sehingga sulit dicari dan disaring oleh alat seperti Grafana Loki, Datadog, atau Better Stack.
• Tidak ada konteks otomatis seperti waktu, id proses, atau id request.

pino (10.4.0) adalah logger terstruktur yang sangat cepat. Setiap baris log berupa satu objek JSON (format ini disebut NDJSON, newline-delimited JSON). Mesin bisa langsung membacanya, dan saat development kamu bisa mempercantiknya dengan pino-pretty (13.2.0).

Level log

Pino memakai level standar, masing-masing dengan angka:

Opsi level menentukan level minimum yang ditulis. Dengan level: 'info', pesan debug dan trace dibuang. Pola yang umum: debug di development, info di produksi, silent di tes supaya output tes bersih.

Konteks, child logger, dan redaksi

Argumen pertama pino bisa berupa objek: logger.warn({ produkId: 7, sisaStok: 2 }, 'stok hampir habis'). Objek itu masuk ke JSON sebagai field terpisah, sehingga bisa dicari ("semua log dengan produkId 7"). Child logger (logger.child({ reqId })) membuat logger turunan yang otomatis menyertakan field tertentu di setiap barisnya.

Opsi redact menyensor field sensitif sebelum ditulis: password, header cookie, header authorization. Log sering dikirim ke layanan pihak ketiga dan dibaca banyak orang. Password atau token yang masuk ke log sama saja dengan bocor.

Request ID dengan pino-http

pino-http (11.0.0) adalah middleware yang mencatat setiap request secara otomatis: method, URL, status, dan waktu respons (responseTime dalam milidetik). Ia juga memasang req.log, sebuah child logger yang membawa request id. Semua log yang ditulis lewat req.log di dalam handler otomatis membawa id yang sama, sehingga kamu bisa melacak satu request dari awal sampai akhir.

Dengan opsi genReqId, kita memakai header X-Request-Id dari klien atau proxy kalau ada, atau membuat UUID baru, lalu mengirimkannya kembali di header respons. Kalau pelanggan melapor error, minta dia (atau frontend-mu) menyertakan request id itu. Kamu langsung tahu baris log mana yang harus dibaca.

Konfigurasi lewat environment variable dan --env-file

Prinsip dari metodologi Twelve-Factor App: konfigurasi yang berbeda antar lingkungan disimpan di environment variable, bukan di kode. Node.js sekarang bisa membaca file .env sendiri tanpa paket dotenv:

• node --env-file=.env app.js: muat file .env. Kalau file tidak ada, Node berhenti dengan error (node: .env: not found).
• node --env-file-if-exists=.env app.js: muat kalau ada, lanjut kalau tidak (dengan peringatan .env not found. Continuing without it.). Cocok untuk script dev yang juga dijalankan di CI.
• Flag ini bisa diulang. File yang belakangan menimpa file sebelumnya: --env-file=.env --env-file=.env.production.
• Variabel yang sudah ada di environment (misalnya diset oleh platform hosting atau di command line) tidak ditimpa oleh isi file. Ini perilaku yang tepat: pengaturan platform selalu menang.
• Dari dalam kode, ada juga process.loadEnvFile('.env').

Setelah dibaca, validasi semua konfigurasi sekali saat start dengan Zod (lihat src/config.js di Modul 6). Prinsipnya fail fast: lebih baik server menolak menyala dengan pesan "JWT_SECRET minimal 32 karakter" daripada menyala lalu gagal misterius saat pengguna pertama mencoba login.

Konfigurasi per lingkungan

NODE_ENV=production juga membuat Express dan banyak library lain mematikan fitur debug yang memperlambat.

Graceful shutdown

Saat sistem ingin mematikan prosesmu, ia mengirim sinyal. Docker, systemd, PM2, dan platform hosting mengirim SIGTERM. Ctrl+C di terminal mengirim SIGINT. Kalau tidak ditangani, Node langsung mati, dan request yang sedang berjalan terputus. Graceful shutdown berarti:

1. Tangkap sinyalnya dengan process.on('SIGTERM', ...).
2. Panggil server.close(): berhenti menerima koneksi baru, tapi biarkan request yang sedang berjalan selesai.
3. Setelah semua selesai, tutup koneksi database, lalu process.exit(0).
4. Pasang batas waktu (misalnya 10 detik). Kalau ada request yang macet, paksa keluar dengan process.exit(1). .unref() membuat timer ini tidak menahan proses tetap hidup.

Setelah SIGTERM, pengelola proses menunggu sebentar lalu mengirim SIGKILL (yang tidak bisa ditangkap). docker stop umumnya menunggu 10 detik (bisa diubah dengan -t), systemd menunggu 90 detik secara bawaan (TimeoutStopSec), dan PM2 memakai kill_timeout. Batas waktu paksa di aplikasimu sebaiknya lebih pendek dari waktu tunggu itu.

Contoh kode

Dasar pino, output asli:

// log.js, dasar pino
import pino from 'pino';

const logger = pino({
  level: process.env.LOG_LEVEL ?? 'info',
  redact: { paths: ['password', 'user.email'], censor: '[DISENSOR]' },
});

logger.debug('tidak muncul kalau level = info');
logger.info('server siap');
logger.warn({ sisaStok: 2, produkId: 7 }, 'stok hampir habis');
logger.info({ password: 'rahasia123', user: { id: 5, email: 'budi@mail.com' } }, 'login berhasil');

const reqLog = logger.child({ reqId: 'a1b2c3' }); // semua baris dari child membawa reqId
reqLog.error(new Error('koneksi database putus'), 'gagal simpan pesanan');

node log.js
# → {"level":30,"time":1792779330186,"pid":50347,"hostname":"Jarviss-Mac-mini.local","msg":"server siap"}
# → {"level":40,...,"sisaStok":2,"produkId":7,"msg":"stok hampir habis"}
# → {"level":30,...,"password":"[DISENSOR]","user":{"id":5,"email":"[DISENSOR]"},"msg":"login berhasil"}
# → {"level":50,...,"reqId":"a1b2c3","err":{"type":"Error","message":"koneksi database putus",
#    "stack":"Error: koneksi database putus\n    at file:///.../log.js:15:14 ..."},"msg":"gagal simpan pesanan"}

LOG_LEVEL=warn node log.js   # hanya level 40 ke atas
# → {"level":40,...,"msg":"stok hampir habis"}
# → {"level":50,...,"msg":"gagal simpan pesanan"}

node log.js | npx pino-pretty   # tampilan enak dibaca untuk development
# → [01:28:49.388] INFO (75793): server siap
# → [01:28:49.389] WARN (75793): stok hampir habis
# →     sisaStok: 2
# →     produkId: 7

Perhatikan: error yang diberikan sebagai argumen pertama otomatis diserialisasi menjadi field err lengkap dengan stack. Itu sebabnya stack trace boleh masuk log (dibaca kamu), tapi tidak boleh masuk respons (dibaca klien).

pino-http di src/app.js Proyek Akhir:

// src/app.js (potongan logging)
import { pinoHttp } from 'pino-http';
import pino from 'pino';
import crypto from 'node:crypto';

const logger = pino({
  level: config.LOG_LEVEL,
  redact: ['req.headers.cookie', 'req.headers.authorization'], // token tidak boleh masuk log
});
app.use(pinoHttp({
  logger,
  genReqId: (req, res) => {
    const id = req.headers['x-request-id'] ?? crypto.randomUUID();
    res.setHeader('X-Request-Id', id); // kirim balik supaya klien bisa melaporkannya
    return id;
  },
}));
// di handler mana pun: req.log.info({ orderId }, 'pesanan dibuat')

Satu baris log asli untuk GET /health (dipotong supaya muat):

{"level":30,"time":1792779191048,"pid":47730,"hostname":"Jarviss-Mac-mini.local",
 "req":{"id":"2c9a4728-3124-4d82-99ba-df798562a7ef","method":"GET","url":"/health","query":{},"params":{},
        "headers":{"host":"localhost:3000","user-agent":"curl/8.7.1","accept":"*/*"},
        "remoteAddress":"::1","remotePort":62939},
 "res":{"statusCode":200,"headers":{"x-request-id":"2c9a4728-3124-4d82-99ba-df798562a7ef", "...": "..."}},
 "responseTime":3,"msg":"request completed"}

Perilaku --env-file, diuji langsung:

cat .env              # PORT=3000, LOG_LEVEL=debug, DB=dev.db
cat .env.production   # LOG_LEVEL=info, DB=/var/lib/toko/prod.db
echo 'console.log(process.env.PORT, process.env.LOG_LEVEL, process.env.DB)' > env.js

node --env-file=.env env.js
# → 3000 debug dev.db
node --env-file=.env --env-file=.env.production env.js
# → 3000 info /var/lib/toko/prod.db      (file belakangan menimpa)
LOG_LEVEL=error node --env-file=.env env.js
# → 3000 error dev.db                     (variabel yang sudah ada TIDAK ditimpa file)
node --env-file=.tidak-ada env.js
# → node: .tidak-ada: not found
node --env-file-if-exists=.tidak-ada env.js
# → .tidak-ada not found. Continuing without it.
# → undefined undefined undefined

Graceful shutdown di src/server.js:

// src/server.js, titik masuk: load config, buka DB, listen, graceful shutdown
import { loadConfig } from './config.js';
import { createDb } from './db/index.js';
import { createApp } from './app.js';

const config = loadConfig();
const db = createDb(config.DATABASE_FILE);
const app = createApp({ db, config });

const server = app.listen(config.PORT, () => {
  console.log(`API jalan di http://localhost:${config.PORT} (${config.NODE_ENV})`);
});

function shutdown(signal) {
  console.log(`${signal} diterima, menutup server...`);
  server.close(() => {          // berhenti terima koneksi baru, tunggu request yang sedang jalan
    db.$client.close();         // tutup database dengan rapi
    console.log('Selesai. Sampai jumpa.');
    process.exit(0);
  });
  setTimeout(() => process.exit(1), 10_000).unref(); // paksa keluar kalau macet > 10 detik
}
process.on('SIGTERM', shutdown); // dikirim Docker/systemd/PM2 saat stop
process.on('SIGINT', shutdown);  // Ctrl+C

node --env-file=.env src/server.js & P=$!
curl -s localhost:3000/health     # → {"status":"ok","uptime":2}
kill -TERM $P; wait $P; echo "exit=$?"
# → API jalan di http://localhost:3000 (development)
# → SIGTERM diterima, menutup server...
# → Selesai. Sampai jumpa.
# → exit=0

server.js sengaja dipisah dari app.js. app.js hanya merakit aplikasi tanpa listen, sehingga tes (Modul 8) bisa memakainya tanpa membuka port.

Kesalahan umum

1. Mencatat data sensitif. logger.info({ body: req.body }) di endpoint login berarti password pengguna tersimpan di log. Pakai redact, dan jangan pernah log body mentah dari endpoint autentikasi atau pembayaran.
2. Level debug di produksi. Log membengkak, biaya penyimpanan log naik, dan pesan penting tenggelam. Atur lewat LOG_LEVEL, default info.
3. Membaca process.env di mana-mana. process.env.JWT_SECRET yang tersebar di 15 file sulit divalidasi dan dites. Baca sekali di config.js, validasi, lalu teruskan objek config ke bagian lain.
4. Tidak menangani SIGTERM. Setiap deploy memutus request yang sedang berjalan. Pasang handler shutdown dengan batas waktu.
5. Lupa bahwa nilai environment variable selalu string. PORT=3000 terbaca sebagai '3000', dan DEBUG=false terbaca sebagai string 'false' yang bernilai truthy. Pakai z.coerce.number() dan konversi boolean secara eksplisit.

Latihan

1. Mudah, Tambahkan script "dev:pretty" di package.json yang menjalankan server dalam mode watch sekaligus mempercantik log dengan pino-pretty.
2. Sedang, Konfigurasikan pino-http supaya respons 4xx dicatat dengan level warn, 5xx dengan level error, dan request ke /health tidak dicatat sama sekali (karena dipanggil setiap 30 detik oleh pemantau).
3. Menantang, Buktikan bahwa graceful shutdown benar-benar menunggu request yang sedang berjalan. Buat endpoint /lambat yang butuh 2 detik, kirim SIGTERM di tengahnya, lalu tunjukkan bahwa request itu tetap selesai sementara koneksi baru ditolak.

{
  "scripts": {
    "dev:pretty": "node --watch --env-file-if-exists=.env src/server.js | pino-pretty"
  }
}

app.use(pinoHttp({
  logger: pino(),
  customLogLevel: (req, res, err) => {
    if (err || res.statusCode >= 500) return 'error';
    if (res.statusCode >= 400) return 'warn';
    return 'info';
  },
  autoLogging: { ignore: (req) => req.url === '/health' },
}));
// request ke /health, /ok, /x (404), /boom (500) menghasilkan:
// → 30 /ok 200 request completed
// → 40 /x 404 request completed
// → 50 /boom 500 request errored
// (/health tidak tercatat)

// shutdown.js
import express from 'express';

const app = express();
app.get('/lambat', async (req, res) => {
  await new Promise((r) => setTimeout(r, 2000)); // pura-pura kerja 2 detik
  res.json({ selesai: true });
});
app.get('/cepat', (req, res) => res.json({ ok: true }));

const server = app.listen(3100, () => console.log('jalan di 3100'));

process.on('SIGTERM', () => {
  console.log('SIGTERM: berhenti menerima request baru');
  server.close(() => { console.log('semua request selesai, keluar'); process.exit(0); });
  server.closeIdleConnections(); // tutup koneksi keep-alive yang sedang menganggur
  setTimeout(() => { console.log('kelamaan, paksa keluar'); process.exit(1); }, 10_000).unref();
});

node shutdown.js & P=$!; sleep 1
curl -s localhost:3100/lambat > lambat.out & C=$!   # request 2 detik dimulai
sleep 0.5; kill -TERM $P; sleep 0.2                  # SIGTERM di tengah request
curl -s -w " [%{http_code}]" localhost:3100/cepat   # → [000]   koneksi baru ditolak
wait $C; cat lambat.out                              # → {"selesai":true}   request lama tetap selesai
wait $P; echo "exit=$?"                              # → exit=0
# log server:
# → jalan di 3100
# → SIGTERM: berhenti menerima request baru
# → semua request selesai, keluar

Ringkasan

• Pakai logger terstruktur (pino) dengan level: error/warn/info di produksi, debug di development, silent di tes.
• Sertakan konteks sebagai objek, pakai child logger, dan sensor data sensitif dengan redact.
• pino-http mencatat setiap request dan memasang req.log yang membawa request id. Kirim balik X-Request-Id supaya error bisa dilacak.
• Konfigurasi lewat environment variable. --env-file bawaan Node: file belakangan menimpa yang sebelumnya, variabel yang sudah ada tidak ditimpa. Validasi sekali saat start dan gagal cepat.
• Graceful shutdown: tangkap SIGTERM/SIGINT, server.close(), tutup database, keluar, dengan batas waktu paksa.