Jika Anda ingin melakukan sesuatu dengan baik, terlebih dahulu Anda harus mempertajam alat Anda.
Banyak pemrogram mungkin lupa betapa pentingnya mencatat perilaku aplikasi. Saat bertemu bug bersamaan yang disebabkan oleh tekanan tinggi di lingkungan multi-utas, Anda dapat memahami pentingnya merekam log.
Beberapa orang sangat senang menambahkan kalimat ini ke kode:
log.info ("Logging Happy and Carefree");
Dia bahkan mungkin tidak menyadari pentingnya log aplikasi dalam pemeliharaan, penyetelan dan identifikasi kesalahan. Saya pikir SLF4J adalah API logging terbaik, terutama karena mendukung cara yang bagus untuk menyuntikkan skema:
LOG.DEBUG ("Ditemukan {} Catatan Pencocokan Filter: '{}'", catatan, filter);
Untuk log4j, Anda hanya dapat melakukan ini:
log.debug ("Found" + Records + "RecordsMatching Filter: '" + Filter + "'");
Tulisan ini tidak hanya lebih bertele -tele dan buruk, tetapi juga memiliki splicing string yang mempengaruhi efisiensi (ketika level ini tidak memerlukan output).
Slf4j memperkenalkan fitur injeksi {}, dan karena splicing string dihindari setiap saat, metode tostring tidak akan dipanggil, dan tidak perlu menambahkan isDebugeNabled. SLF4J adalah aplikasi mode penampilan, itu hanya fasad. Untuk implementasi tertentu, saya merekomendasikan kerangka kerja logback. Saya sudah mengiklankannya sekali sebelumnya, bukan log4j yang sudah lengkap. Ini memiliki banyak fitur menarik. Tidak seperti log4j, masih dalam pengembangan dan peningkatan aktif.
Alat lain untuk direkomendasikan adalah perf4j:
Perf4j adalah ke system.currentTimemillis () seperti log4j untuk system.out.println ()
Sama seperti log4j adalah alternatif yang lebih baik untuk system.out.println, perf4j lebih seperti penggantian untuk system.currentTimemillis (). Saya telah memperkenalkan perf4j dalam sebuah proyek dan mengamati kinerja di bawah beban tinggi. Administrator dan pengguna bisnis keduanya terpana oleh grafik indah yang disediakan oleh gadget ini. Kami dapat melihat masalah kinerja kapan saja. Perf4j harus menjadi artikel khusus untuk dibicarakan. Sekarang, pertama -tama Anda dapat melihat panduan pengembangnya. Ada juga ceki gülcü (pencipta log4j, slf4j dan proyek logback) yang menyediakan cara mudah bagi kami untuk menghapus dependensi pada googging commons.
Jangan lupa level log
Setiap kali Anda ingin menambahkan baris log, Anda akan berpikir, level log mana yang harus digunakan di sini? Sekitar 90% programmer tidak terlalu memperhatikan masalah ini. Mereka menggunakan satu level untuk merekam log, biasanya info atau debug. Mengapa?
Kerangka log memiliki dua keunggulan utama dibandingkan dengan System.out: Klasifikasi dan level. Keduanya memungkinkan Anda untuk secara selektif memfilter log, secara permanen atau tepat saat pemecahan masalah kesalahan.
Kesalahan: Terjadi kesalahan serius dan harus segera ditangani. Tingkat kesalahan ini tidak dapat ditoleransi untuk sistem apa pun. Sebagai contoh: Pengecualian Pointer NULL, database tidak tersedia, dan kasus penggunaan jalur kritis tidak dapat terus dieksekusi.
WARN: Proses selanjutnya akan berlanjut, tetapi harus dianggap serius. Sebenarnya, saya berharap ada dua level di sini: satu adalah masalah yang jelas dengan solusi (seperti "data saat ini tidak tersedia, menggunakan data yang di -cache"), dan yang lainnya adalah masalah dan saran potensial (seperti "program berjalan dalam mode pengembangan" atau "kata sandi konsol manajemen tidak cukup aman". Aplikasi dapat mentolerir informasi ini, tetapi mereka harus diperiksa dan diperbaiki.
DEBUG: Apa yang dikhawatirkan pengembang. Nanti saya akan berbicara tentang hal -hal apa yang harus direkam pada level ini.
Trace: Informasi lebih rinci, hanya digunakan dalam tahap pengembangan. Anda mungkin masih perlu memperhatikan informasi ini dalam waktu singkat setelah produk diluncurkan, tetapi catatan log ini hanya sementara dan pada akhirnya harus dimatikan. Sulit untuk membedakan perbedaan antara debug dan jejak, tetapi jika Anda menambahkan garis log dan menghapusnya setelah pengembangan dan pengujian, log harus berada di level jejak.
Daftar di atas hanyalah sebuah saran, Anda dapat mencatat sesuai dengan aturan Anda sendiri, tetapi yang terbaik adalah memiliki aturan tertentu. Pengalaman pribadi saya adalah: Jangan memfilter log pada tingkat kode, tetapi gunakan level log yang benar untuk dengan cepat menyaring informasi yang diinginkan, yang dapat menghemat banyak waktu.
Hal terakhir yang perlu dikatakan adalah pernyataan bersyarat yang terkenal ini adalah*yang diaktifkan. Beberapa orang suka menambahkan ini sebelum setiap log:
if (log.isdebugeNabled ()) log.debug ("Place for Your Commercial");Secara pribadi, saya pikir Anda harus menghindari menambahkan hal yang berantakan ini ke kode. Kinerja tampaknya tidak jauh lebih baik (terutama setelah menggunakan SLF4J), yang lebih seperti optimasi prematur. Juga, tidakkah Anda merasa sedikit berlebihan? Jarang, pernyataan penilaian eksplisit ini secara eksplisit diperlukan kecuali kami membuktikan bahwa membuat pesan log itu sendiri terlalu mahal. Jika tidak, Anda dapat mengingat sebanyak yang seharusnya dan membiarkan kerangka log khawatir tentang ini.
Apakah Anda tahu apa yang Anda rekam?
Setiap kali Anda menulis satu baris log, luangkan waktu sejenak untuk melihat apa yang Anda cetak dalam file log. Baca log Anda dan cari tahu di mana pengecualian berada. Pertama, setidaknya hindari pengecualian penunjuk nol:
log.debug ("Permintaan pemrosesan dengan ID: {}", request.getId ());
Sudahkah Anda mengonfirmasi bahwa permintaan itu bukan nol?
Koleksi rekaman juga merupakan lubang besar. Jika Anda menggunakan Hibernate untuk mendapatkan kumpulan objek domain dari database, Anda secara tidak sengaja menulisnya seperti ini: log.debug ("Pengguna yang kembali: {}", pengguna);
SLF4J hanya akan memanggil metode ToString ketika pernyataan ini memang dicetak, tentu saja ini keren. Namun, jika memori meluap, masalah seleksi n+1, utas kelaparan sampai mati, pengecualian inisialisasi yang tertunda, ruang penyimpanan log habis ... semua ini mungkin terjadi. Cara terbaik adalah merekam ID objek (atau hanya ukuran koleksi). Namun, mengumpulkan ID membutuhkan panggilan metode getID untuk setiap objek, yang sebenarnya bukan tugas yang mudah di Java. Groovy memiliki operator ekspansi yang hebat (pengguna*.id). Di Java kita dapat menggunakan Perpustakaan Commons Beanutils untuk mensimulasikan:
LOG.DEBUG ("Mengembalikan ID Pengguna: {}", kumpulkan (pengguna, "id"));
Ini mungkin bagaimana metode pengumpulan diimplementasikan:
Public Static Collection Collect (Koleksi Koleksi, String PropertyName) {return collectionutils.collect (koleksi, beantopropertyvaluetransformer baru (propertiName));}Akhirnya, metode ToString tidak dapat diimplementasikan dengan benar atau digunakan.
Pertama, untuk masuk, ada banyak cara untuk membuat tostring untuk setiap kelas. Yang terbaik adalah menggunakan TostringBuilder untuk menghasilkan (tetapi bukan versi implementasi refleksi).
Kedua, perhatikan array dan set atipikal. Implementasi array dan beberapa koleksi alternatif mungkin tidak menyebut metode tostring dari masing -masing elemen satu per satu. Metode Arrays#DeeptoString yang disediakan oleh JDK dapat digunakan. Periksa log yang Anda cetak pada diri sendiri untuk melihat apakah ada informasi tentang pengecualian format.
Hindari efek samping
Pencetakan log umumnya tidak memiliki banyak dampak pada kinerja program. Baru -baru ini, seorang teman saya melemparkan pengecualian LazyInitialization Exception hibernate pada sistem yang berjalan pada beberapa platform khusus. Seperti yang mungkin Anda duga dari ini, beberapa cetakan log yang menghasilkan koleksi inisialisasi tertunda dimuat ketika sesi terhubung. Dalam hal ini, jika level log meningkat, koleksi tidak akan lagi diinisialisasi. Jika Anda tidak mengetahui informasi konteks ini, berapa lama waktu yang Anda butuhkan untuk menemukan bug ini.
Efek samping lainnya adalah mempengaruhi kecepatan berjalan program. Jawaban cepat untuk pertanyaan ini: Jika log dicetak terlalu banyak atau tostring dan splicing string tidak digunakan dengan benar, pencetakan log akan berdampak negatif pada kinerja. Seberapa besar itu? Yah, saya telah melihat program restart setiap 15 menit karena terlalu banyak log menyebabkan benang kelaparan sampai mati. Ini adalah efek sampingnya! Dari pengalaman saya, mencetak seratus megabyte dalam satu jam hampir merupakan batas atas.
Tentu saja, jika proses bisnis dibatalkan karena pengecualian pencetakan log, efek samping ini akan sangat bagus. Saya sering melihat orang menulis ini untuk menghindari ini:
coba {log.trace ("id =" + request.getUser (). getId () + "mengakses" + manager.getPage (). getUrl (). ToString ())} catch (nullpointerException e) {}Ini adalah kode yang nyata, tetapi untuk membuat dunia lebih murni, tolong jangan menulisnya seperti ini.
Jelaskan dengan jelas
Setiap catatan log berisi data dan deskripsi. Lihatlah contoh ini:
log.debug ("pesan diproses"); log.debug (message.getjmsmessageId ()); log.debug ("pesan dengan id '{}' diproses", message.getjmsmessageId ()); Ketika kesalahan pemecahan masalah dalam sistem yang tidak dikenal, log jenis apa yang Anda sukai? Percayalah, contoh -contoh ini biasa terjadi. Ada juga mode negatif:
if (pesan contoh dari TextMessage)
// ...
kalau tidak
log.warn ("Jenis Pesan Tidak Diketahui");
Apakah sulit untuk menambahkan jenis pesan, ID pesan, dll. Ke log peringatan ini? Saya tahu bahwa terjadi kesalahan, tapi apa itu? Apa informasi konteksnya?
Contoh negatif ketiga adalah "log ajaib". Contoh nyata: Banyak programmer di tim tahu bahwa 3 ≥ angka mengikuti! Nomor yang diikuti oleh nomor #, diikuti oleh log nomor pseudo-acak berarti "pesan dengan ID XYZ telah diterima". Tidak ada yang mau mengubah log ini. Jika seseorang mengetik keyboard dan memilih string unik "&&&!#", Ia akan dengan cepat menemukan informasi yang diinginkannya.
Hasilnya adalah bahwa seluruh file log terlihat seperti string besar karakter acak. Beberapa orang tidak bisa tidak bertanya -tanya apakah ini adalah program Perl.
File log harus dapat dibaca, jelas, dan digambarkan sendiri. Jangan gunakan angka ajaib, nilai catatan, angka, ID dan konteksnya. Catat data yang diproses dan artinya. Catat apa yang dilakukan program. Log yang baik harus menjadi dokumen yang bagus dari kode program.
Sudahkah saya menyebutkan untuk tidak mencetak kata sandi dan memiliki informasi pribadi? Saya percaya tidak ada programmer yang bodoh.
Sesuaikan format Anda
Format log adalah alat yang sangat berguna, yang secara tidak terlihat menambahkan informasi konteks yang berharga ke log. Tetapi Anda harus berpikir dengan jelas tentang jenis informasi apa yang termasuk dalam format Anda. Misalnya, tidak ada artinya untuk merekam tanggal dalam log yang ditulis setiap siklus per jam, karena nama log Anda sudah berisi informasi ini. Sebaliknya, jika Anda tidak merekam nama utas, ketika dua utas bekerja secara paralel, Anda tidak akan dapat melacak utas melalui log - log telah tumpang tindih bersama. Dalam aplikasi tunggal, tidak apa-apa untuk melakukan ini, tapi itu sudah merupakan masa lalu.
Dari pengalaman saya, format log yang ideal harus mencakup (kecuali informasi log itu sendiri, tentu saja): Waktu saat ini (tidak ada tanggal, presisi milidetik), level log, nama utas, nama log sederhana (bukan dengan nama lengkap), dan pesan. Dalam logback akan terlihat seperti ini:
<Appender name = "stdout"> <coderer> <pat pola>%d {hh: mm: ss.sss}%-5 level [%utas] [%logger {0}]%m%n </pater> </encoder> </pespencer>Nama file, nama kelas, nomor baris, tidak perlu terdaftar, meskipun tampaknya berguna. Saya juga melihat logging kosong dalam kode:
log.info (""); Karena programmer percaya bahwa nomor baris akan menjadi bagian dari format log, dan dia tahu bahwa jika pesan log kosong muncul di baris 67 file, itu berarti bahwa pengguna telah diautentikasi. Tidak hanya itu, merekam nama metode nama kelas, atau nomor baris memiliki dampak besar pada kinerja.
Fitur yang lebih maju dari kerangka kerja logging adalah konteks diagnostik yang dipetakan. MDC hanyalah peta yang lokal untuk meluas. Anda dapat memasukkan pasangan nilai kunci ke dalam peta ini, sehingga semua catatan log dari utas ini dapat memperoleh informasi yang sesuai dari peta ini sebagai bagian dari format output.
Catat parameter dan nilai pengembalian metode
Jika Anda menemukan bug di tahap pengembangan, Anda biasanya menggunakan debugger untuk melacak alasan spesifik. Sekarang katakanlah Anda tidak akan menggunakan debugger lagi. Misalnya, karena bug ini muncul di lingkungan pengguna beberapa hari yang lalu, yang bisa Anda dapatkan hanyalah beberapa log. Apa yang bisa Anda temukan dari ini?
Jika Anda mengikuti prinsip sederhana pencetakan parameter masuk dan keluar untuk setiap metode, Anda tidak memerlukan debugger sama sekali. Tentu saja, setiap metode dapat mengakses sistem eksternal, memblokir, menunggu, dll., Dan ini harus diperhitungkan. Lihat saja format berikut:
public string printDocument (dokumen dokumen, mode mode) {log.debug ("Memasukkan printDocument (doc = {}, mode = {})", doc, mode); String id = ...; // Log Operasi Pencetakan yang panjang. mengembalikan id;}Karena Anda mencatat log di awal dan akhir metode, Anda dapat secara manual menemukan kode yang tidak efisien, dan bahkan mendeteksi penyebab yang dapat menyebabkan kebuntuan dan kelaparan - Anda hanya perlu melihat apakah tidak ada "meninggalkan" setelah "masuk". Jika arti nama metode Anda jelas, itu akan menjadi hal yang menyenangkan untuk menghapus log. Demikian pula, menganalisis pengecualian lebih mudah karena Anda tahu apa yang Anda lakukan di setiap langkah. Jika ada banyak metode untuk direkam dalam kode, Anda dapat menggunakan bagian AOP untuk menyelesaikannya. Ini mengurangi kode duplikat, tetapi Anda harus sangat berhati -hati saat menggunakannya, dan jika Anda tidak hati -hati, itu dapat menyebabkan sejumlah besar output log.
Level yang paling cocok untuk jenis log ini adalah debug dan jejak. Jika Anda menemukan bahwa suatu metode dipanggil terlalu sering dan merekam lognya dapat memengaruhi kinerja, Anda hanya perlu menurunkan level lognya, atau menghapus log secara langsung (atau hanya satu dari seluruh metode panggilan?) Namun, terlalu banyak log yang lebih baik daripada yang lebih sedikit. Pikirkan logging sebagai tes unit, kode Anda harus ditutupi dengan log seperti halnya tes unitnya ada di mana -mana. Tidak ada bagian dari sistem yang tidak memerlukan log sama sekali. Ingat, kadang -kadang Anda perlu tahu apakah sistem Anda berfungsi dengan baik, dan Anda hanya dapat melihat log yang terus -menerus membanjiri layar.
Amati sistem eksternal
Saran ini sedikit berbeda dari yang sebelumnya: jika Anda berkomunikasi dengan sistem eksternal, ingatlah untuk merekam data keluar dan membaca data sistem Anda. Integrasi sistem adalah tugas, dan mendiagnosis masalah antara dua aplikasi (bayangkan perusahaan yang berbeda, lingkungan, tim teknis) sangat sulit. Baru -baru ini kami menemukan bahwa merekam konten pesan lengkap, termasuk header SOAP dan HTTP Apache CXF, sangat efektif selama fase integrasi dan pengujian sistem.
Ini mahal, dan jika mempengaruhi kinerja, Anda hanya dapat mematikan log. Tetapi dengan cara ini, sistem Anda mungkin berjalan dengan sangat cepat dan menggantung dengan cepat, jadi Anda tidak dapat melakukan apa -apa? Saat berintegrasi dengan sistem eksternal, Anda hanya bisa ekstra hati -hati dan bersiap untuk mengorbankan beberapa overhead. Jika Anda cukup beruntung dan integrasi sistem ditangani oleh ESB, yang terbaik adalah mencatat permintaan dan respons di bus. Anda dapat merujuk pada komponen log bagal ini.
Terkadang jumlah data yang dipertukarkan dengan sistem eksternal menentukan bahwa tidak mungkin bagi Anda untuk menuliskan semuanya. Di sisi lain, yang terbaik adalah menyimpan semuanya di dalam log selama fase pengujian dan tahap rilis awal dan bersiaplah untuk mengorbankan kinerja. Ini dapat dilakukan dengan menyesuaikan level log. Lihatlah tips berikut:
Koleksi <Integer> requestIds = // ... if (log.isdebugeNabled ()) log.debug ("memproses id: {}", requestIds); else log.info ("memproses ukuran id: {}", requestIds.size ()); Jika logger ini dikonfigurasi ke tingkat debug, ia mencetak kumpulan ID permintaan yang lengkap. Jika dikonfigurasi untuk mencetak informasi info, itu hanya akan menghasilkan ukuran set. Anda mungkin bertanya apakah saya lupa kondisi ISInfoEnabled, silakan lihat saran kedua. Hal lain yang patut dicatat di sini adalah bahwa set ID tidak bisa nol. Meskipun dapat mencetak secara normal di bawah debug sebagai nol, itu adalah penunjuk nol besar ketika dikonfigurasi sebagai info. Ingat efek samping yang disebutkan dalam saran ke -4?
Pengecualian logging yang benar
Pertama, jangan mencatat pengecualian, biarkan kerangka kerja atau wadah melakukan ini. Tentu saja ada pengecualian: Jika Anda melempar pengecualian (RMI, EJB, dll.) Dari layanan jarak jauh, pengecualian diserialisasi untuk memastikan bahwa mereka dapat dikembalikan ke klien (bagian dari API). Jika tidak, klien akan menerima noclassdeffounderror atau pengecualian aneh lainnya alih -alih pesan kesalahan nyata.
Perekaman pengecualian adalah salah satu tanggung jawab pencatatan yang paling penting, tetapi banyak programmer cenderung menggunakan penebangan sebagai cara untuk menangani pengecualian. Mereka biasanya hanya mengembalikan nilai default (biasanya nol, 0 atau string kosong), dan berpura -pura tidak terjadi apa pun. Terkadang, mereka pertama -tama akan merekam pengecualian, kemudian membungkus pengecualian dan kemudian membuangnya:
Log.Error ("IO Exception", E); Lempar Customexception baru (E);Dengan cara ini, informasi tumpukan biasanya akan dicetak dua kali, karena tempat -tempat di mana pengecualian mycustomexception ditangkap akan dicetak lagi. Catatan log, atau membungkusnya dan membuangnya, jangan menggunakannya secara bersamaan, jika tidak log Anda akan terlihat membingungkan.
Bagaimana jika kita benar -benar ingin masuk? Untuk beberapa alasan (mungkin tidak membaca API dan dokumentasi?), Sekitar setengah dari penebangan saya pikir salah. Lakukan tes kecil, manakah dari pernyataan log berikut yang dapat mencetak pengecualian pointer nol dengan benar?
coba {integer x = null; ++ x;} catch (exception e) {log.error (e); // A Log.Error (E, E); // B LOG.Error ("" + e); // c log.Error (e.tostring ()); // d log.Error (e.getMessage ()); // e log.Error (null, e); // f log.Error ("", e); // g log.Error ("{}", e); // h LOG.Error ("{}", e.getMessage ()); // I LOG.Error ("File konfigurasi membaca kesalahan:" + e); // J LOG.Error ("File Konfigurasi Bacaan Kesalahan:" + E.GetMessage ()); // k log.Error ("File Konfigurasi Bacaan Kesalahan", E); // l}Aneh bahwa hanya G dan L (ini lebih baik) yang benar! A dan B tidak dikompilasi di bawah SLF4J sama sekali. Orang lain akan membuang informasi jejak tumpukan atau mencetak informasi yang salah. Misalnya, E tidak mencetak apa pun karena pengecualian pointer nol itu sendiri tidak memberikan informasi pengecualian dan informasi tumpukan tidak dicetak. Ingat, parameter pertama biasanya informasi teks, tentang kesalahan itu sendiri. Jangan menulis informasi pengecualian di dalamnya. Secara otomatis akan keluar setelah mencetak log, di depan informasi tumpukan. Tetapi jika Anda ingin mencetak ini, tentu saja Anda harus meneruskan pengecualian ke parameter kedua.
Log harus dapat dibaca dan mudah diurai
Sekarang ada dua kelompok pengguna yang tertarik pada log Anda: kami manusia (apakah Anda setuju atau tidak, para pembuat kode ada di sini), dan komputer (biasanya skrip shell yang ditulis oleh administrator sistem). Log harus cocok untuk dipahami oleh kedua pengguna. Jika seseorang melihat log program Anda di belakang Anda dan melihat ini:
Maka Anda pasti tidak mengikuti saran saya. Log harus mudah dibaca dan dipahami sebagai kode.
Di sisi lain, jika program Anda menghasilkan setengah dari GB log setiap jam, tidak ada seorang pun atau editor teks grafis yang dapat menyelesaikannya. Pada saat ini, orang -orang tua kami, grep, sed dan awk, datang ketika mereka datang ke lapangan. Jika memungkinkan, yang terbaik adalah log yang Anda rekam untuk memperjelas kedua komputer. Jangan format nomor, gunakan beberapa format yang membuat cocok secara teratur, dll. Jika tidak mungkin, cetak data dalam dua format:
LOG.DEBUG ("Permintaan TTL diatur ke: {} ({})", Tanggal baru (TTL), TTL); // Minta TTL diatur ke: Rab 28 Apr 20:14:12 CEST 2010 (1272478452437 Durasi Final, Durasi, Durasi. {} ms ({}) ", durasimillis, durasi); // Mengimpor mengambil: 123456789ms (1 hari 10 jam 17 menit 36 detik)Komputer melihat "MS setelah 1970 Epoch" format waktu seperti itu akan berterima kasih, sementara orang senang melihat sesuatu seperti "1 hari 10 jam 17 menit 36 detik".
Singkatnya, jurnal ini juga dapat ditulis sama elegannya dengan puisi, jika Anda bersedia memikirkannya.
Di atas adalah kumpulan informasi tentang format output penyesuaian log Java. Teman yang tertarik dapat merujuknya.