... در قسمت اول در رابطه با انتخاب کتابخانه مناسب مفصلا صحبت کردیم و سعی کردیم کلاف سردرگم در بحث لاگ را تا حدودی باز کنیم. امیدوارم که به این مهم دست یافته باشم.
در قسمت اول ما در نهایت به این نتیجه رسیدیم که از کتابخانهی sla4j بعنوان facade library استفاده کنیم و از logback بعنوان کتابخانهی اصلی. اگر منظور من رو متوجه نمیشید الان، مطمئن بشید که قسمت اول را مطالعه فرمودید. خب بریم آموزش کار با logback را شروع کنیم!
فریمورک Logback یکی از پراستفادهترین فریمورکهای لاگ در کامیونیتی جاواست. یجورایی جایگزین فریمورک محبوب Log4j است. Logback پیادهسازی سریعترین نسبت به Log4j دارد، گزینههای بیشتری برای تنظیمات محیا میکند و همچنین انعظافپذیری بیشتری برای ذخیره سازی در فایل دارد.
در این مقدمه من معماری Logback رو شرح میدم و نشان میدهم که چگونه از آن برای ساخت اپلیکیشنهای بهتر استفاده کنید.
۳ کلاس اصلی معماری Logback را تشکیل میدهد: Logger، Appender، و Layout.
شی logger یک context برای پیامهای لاگ میباشد. این همان کلاسی است که اپلیکیشن برای ایجاد پیامهای لاگ ازش استفاده میکند.
و appenderها. آنها پیامهای لاگ را در مکان(های) نهایی قرار میدهد. یک logger میتواند چندین appender داشته باشد. بطور معمول ما پیامهای لاگ را در فایل ذخیره میکنیم، اما logback امکانات بیشتری هم به ما میدهد (در قسمت اول اشاره شده است).
و اما Layout. لیئوت پیامها را برای خروجی آماده میکند. Logback این امکان را میدهد که شما کلاسهای خاص خودتان را برای فرمتدهی به پیامها استفاده کنید، همانطور که این امکان را میدهد که کلاسهای موجود را تنظیم کنید.
فریمورک Logback از slf4j بعنوان اینترفیس اصلی خودش استفاده میکنه. قبل از اینکه شروع کنیم به لاگ انداختن پیامها، نیاز است که Logback و Slf4j را به فایل pom.xml اضافه کنیم.
نیاز هست که بگم من از maven برای مدیریت وابستگیها استفاده میکنم؟! فکر نمیکنم!
<dependency> <groupId>ch.qos.logback</groupId> <artifactId>logback-core</artifactId> <version>1.2.3</version> </dependency> <dependency> <groupId>org.slf4j</groupId> <artifactId>slf4j-api</artifactId> <version>1.7.25</version> </dependency> <dependency> <groupId>org.slf4j</groupId> <artifactId>slf4j-simple</artifactId> <version>1.6.4</version> </dependency>
فریمورک Logback همچنین به logback-classic.jar در classpath نیاز داره در حالت runtime. به همین خاطر آن را هم به فایل pom.xml اضافه میکنیم بعنوان یک dependency:
<dependency> <groupId>ch.qos.logback</groupId> <artifactId>logback-classic</artifactId> <version>1.2.3</version> </dependency>
خب بیاید با یک مثال سریع استفادهی Logback تو یک اپلیکیشن را بررسی کنیم.
اول از همه، ما به یک فایل تنظیمات نیاز داریم (configuration file). من یک فایل بنام logback.xml ایجاد میکنم و یجایی در classpath قرار میدهم:
<configuration> <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender"> <encoder> <pattern>%d{HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %msg%n</pattern> </encoder> </appender> <root level="debug"> <appender-ref ref="STDOUT" /> </root> </configuration>
و سپس یک کلاس Example ایجاد میکنیم و در متد main کد سادهی زیر را قرار میدهیم:
public class Example { private static final Logger logger = LoggerFactory.getLogger(Example.class); public static void main(String[] args) { logger.info("Example log from {}", Example.class.getSimpleName()); } }
خب وقتی اجرا میکنیم چه اتفاقی میافتد؟ من انتظار دارم چنین خطی را مشاهده کنم:
09:08:41.774 [main] INFO me.mujan.Example - Example log from Example
خروجی را مشاهده کنید:
خب، همه چیز همانطور به نظر میرسد که انتظار میرفت!
الان میفهمیم چرا Logback انقدر محبوب است، تو چند دقیقه برنامه رو بالا آوردیم. بریم یک نگاهی بندازیم به تنظیمات و کدی که نوشتیم تا کمی برامون روشن بشه چطور داره کار میکنه.
تا اینجای کار مفاهیم پایهای رو فهمیدیم. حالا وقت این است که عمیقتر به موضوع بنگریم.
برای ثبت پیام تو Logback، ما Logger رو مقداردهی اولیه (initialize) میکنیم:
private static final Logger logger = LoggerFactory.getLogger(Example.class);
و بعد از آن استفاده میکنیم:
logger.info("Example log from {}", Example.class.getSimpleName());
اینی که الان ایجاد شده loggin context ماست. نمیدونم چطور باید ترجمهاش کنم. کلاس LoggerFactory برای ما ایجادش میکند و یک اسمی هم به Logger میدهد. متد getLogger یک نسخهی overload دیگه هم داره که میتوانید به آن String پاس دهید.
یک Logger چیزی بنام Level دارد که هم امکان تنظیم شدن در فایل تنظیمات را دارد هم میتوانیم به کمک Logger.setLevel() آن را تنظیم کنیم. توجه داشته باشید که سطحی که در کد نوشته میشود روی فایلهای تنظیمات بازنویسی (override) میشود. یعنی اولویت دارد.
سطوحی که وجود دارد به ترتیب اولویت بدین شرح است: TRACE، DEBUG، INFO، WARN و ERROR که هر سطح متد متناظر خودش را دارد که ما برای لاگ کردن پیام در آن سطح از آن استفاده میکنیم.
چنانچه Logger بطور شفاف سطح (level) را مشخص نکرده باشد، آن را از نزدیکترین نیا (ancestor) به ارث میبرد. root logger در حالت پیشفرض روی DEBUG ست شده است که با هم خواهیم دید چگونه میتوان آن را بازنویسی کرد.
خب، تمام حواستان را جمع کنید، میخواهم در مثال زیر چند مفهوم مهم را بررسی کنیم. یکی از آن مفاهیم سلسلهمراتب logger هاست. چطور یک logger میتواند نیای یک logger دیگر باشد و طبعا چطور یک logger فرزند یک logger دیگر میشود. همچنین اشارهای به مفهوم level ها خواهم کرد. اینها را در قالب مثال توضیح خواهم داد.
به کد زیر نگاه کنید، من این تکه کد رو درون متد main نوشتهام:
Logger parentLogger = (Logger) LoggerFactory.getLogger("me.mujan.mylogger"); parentLogger.setLevel(Level.INFO); parentLogger.warn("This message is logged because WARN > INFO."); parentLogger.debug("This message is not logged because DEBUG < INFO.");
فکرمیکنید خروجی چه میباشد؟ کدام پیام(ها) در کنسول پرینت میشود؟ خروجی به شکل زیر است:
10:47:03.532 [main] WARN me.mujan.mylogger - This message is logged because WARN > INFO.
متن پیامها خودشان گویا هستند، ولی من توضیح بیشتری میدهم. پیام "This message is not logged because DEBUG < INFO." که با استفاده از متد debug() لاگ شده بود در کنسول چاپ نشده است. چرا؟ چون سطح logger با استفاده متد setLevel() روی INFO سِت شده است و از آنجایی اولویت INFO کمتر از DEBUG است، پیامی که با متد debug() میخواهد لاگ شود در اصل اجرا نمیشود.
اگر من level را با Level.TRACE ست کنم چه رخ خواهد داد؟
parentLogger.setLevel(Level.TRACE);
قطعا هر دو پیام اجرا میشود چرا که اولویت TRACE از تمام سطوح بیشتر است.
بیاید به تکه کد اول دقت کنیم:
Logger parentLogger = (Logger) LoggerFactory.getLogger("me.mujan.mylogger");
بعنوان نام logger من اسم "me.mujan.mylogger" به متد getLogger پاس دادهام. ما میتوانیم به کمک همین نامگذاری در اصل یک سلسلهمراتب درست کنیم. فرض کنیم میخواهیم یک context دیگر ایجاد کنیم، و میخواهیم این context از parentLogger تنظیمات را ارث ببرد. باید چکار کنم؟
یک logger دیگر ایجاد میکنم و نام آبجکتش را childLogger میگذارم. ولی هنگام نامگذاری خود لاگر باید از الگوی خاصی پیروی کنم تا سلسلهمراتب را بدرستی ایجاد کنم. برای اینکه childLogger تنظیمات را از parentLogger به ارث ببرد باید هنگام نامگذاری childLogger یک نقطه (dot) به انتهای "me.mujan.mylogger" اضافه کنم و در ادامه یک نام برای childLogger بگذارم. به این شکل میشود:
Logger childLogger = (Logger) LoggerFactory.getLogger("me.mujan.mylogger.child");
با این نامگذاری من ارثبری را ایجاد کردهام. حالا childLogger تنظیمات را از parentLogger به ارث میبرد. یعنی چی؟ یعنی از این پس هم childLogger سطحاش (level) میشود INFO. اجازه دهید کد را کامل کنیم:
Logger parentLogger = (Logger) LoggerFactory.getLogger("me.mujan.mylogger"); parentLogger.setLevel(Level.INFO); // دقت شود Logger childLogger = (Logger) LoggerFactory.getLogger("me.mujan.mylogger.child"); parentLogger.warn("This message is logged because WARN > INFO."); parentLogger.debug("This message is not logged because DEBUG < INFO."); childLogger.info("INFO == INFO"); childLogger.debug("DEBUG < INFO");
خب به کد دقت کنید، الان انتظار داریم که چه چیزهایی در خروجی چاپ شود؟ دقت کردید که ما سطح را فقط برای parentLogger قرار دادیم. خروجی به شکل زیر است:
11:26:10.971 [main] WARN me.mujan.mylogger - This message is logged because WARN > INFO. 11:26:10.978 [main] INFO me.mujan.mylogger.child - INFO == INFO
فکرمیکنم به میزان لازم توضیح دادهام.
برخلاف پیامهای سادهای که در بالا دیدیم، عمدهی پیامهای کاربردی لاگ نیازمند چسباندن چندین رشته بهم است (جلوتر منظورم رو بهتر میفهمید). که خب این کار هم مستلزم اخذ حافظه، سریال کردن آبجکت، الحاق رشتهها و احتمالا تمیزکاری های گاربیج کالکتر (garbage collector) است. پیام زیر را نگاه کنید:
log.debug("Current count is " + count);
در این حالت ما خودمان باید متحمل هزینههای ساخت پیام شویم. اما Logback یک راه بهتر به ما معرفی میکند. پیامهای پارامتریک. همان پیام قبلی را میتوانیم به شکل زیر ارسال کنیم:
log.debug("Current count is {}", count);
نکتهی مهم کجاست؟ کروشهها {} (بعضی ها بهش کِرلیبراکت میگن و حدادعادلیش هم میشه کمانک) هر آبجکتی را قبول میکنند. بعبارتی شما وقتی {} میگذارید، میتوانید هر آبجکتی را به آن پاس دهید، تا بطور خودکار متد toString آن آبجکت فراخوانی شود و پیام را ایجاد کند. باید مثالهای بیشتری ببینیم تا خوب جا بیافتد!
Logger logger = (Logger) LoggerFactory.getLogger("me.mujan.mylogger"); String msg = "@Mujan"; logger.info("My weblog address in Virgool is:{} ", msg);
خروجی کد بالا میشود:
11:41:56.240 [main] INFO me.mujan.mylogger - My weblog address in Virgool is: @Mujan
خب همانطور که ملاحظه میکنید میتوان رشته را پارمتریک پاس داد. آیا فقط رشته؟ خیر هر آبجکتی را میتوانید پاس دهید. برویم کمی عمیقتر شویم!
توی مثالهای قبلی ما از یک فایل تنظیمات کوتاه (تقریبا ۱۱ خطی) استفاده کردیم. رفتار پیشفرض Logback به این شکل است که اگر نتواند فایل configuration را پیدا کند خودش یک ConsoleAppender ایجاد میکند و وصل میکند به root logger.
فایل configuration درون classpath قرار میگیره و نامش میتونه logback.xml یا logback-test.xml باشه. بطور کلی logback برای پیدا کردن فایل تنظیمات چنین رفتاری دارد:
نکته: نسخهی فعلی Logback از تنظیمات Groovy پشتیبانی نمیکند چرا که Groovy با جاوا ۹ سازگار نیست.
بریم نگاهی دقیقتر بخود تنظیمات بیاندازیم!
برید و فایل تنظیماتی رو که قبلا نوشته بودیم رو مجددا مشاهده کنید، تمام این فایل درون تگهای <configuration> قرار دارد.
همچنین ما تگی مشاهده میکنیم بنام Appender که از نوع ConsoleAppender است و نامش را هم STDOUT قرار دادیم. درون این تگ هم تگی بنام encoder وجود دارد. تگ encoder الگویی مشاهده printf-style دارد.
در آخر هم تگ root را داریم. این تگ root logger را روی حالت DEBUG تنظیم کرده است و با استفاده از تگ appender-ref آنرا به STDOUT ارجاع دادهایم.
فایل تنظیمات logback میتونه خیلی پیچیده باشد، به همین خاطر چندین مکانیزم درونی برای مشکلیابی برایش ایجاد کردهاند. برای مشاهده اطلاعات debug در فرایند تنظیمات Logback، میتوانید امکان دیباگ رو برای تنظیمات روشن کنید!
<configuration debug="true"> ... </configuration>
توی عکس زیر هم تنظیمات و هم خروجی را مشاهده میکنید:
مکانیزم دیگری که وجود داره StatusListener نام دارد که میتونید در این خصوص خودتان تحقیق کنید.
امکان reload کردن تنظیمات در زمانیکه برنامه در حال اجرا است یکی از امکانات پرقدرت و بسیار خوب logback برای troubleshooting است. این امکان رو میتوانید با پارامتر scan برای logback محیا کنید.
رفتار پیشفرض برای scan کردن فایل تنظیمات روی بازههای ۶۰ ثانیهای میباشد که آن را هم میتواند با اضافه کردن scanPeriod تغییر دهید. همچنین میتوانید مقادیر را به میلیثانیه، ثانیه، دقیقه و ساعت وارد کنید:
<configuration scan="true" scanPeriod="15 seconds"> ... </configuration>
توی مثالهای سادهی بالا ما سطح root logger رو تنظیم کردیم و سپس مرتبطش کردیم با Console appender. ولی در واقع میتوانیم سطح تمام loggerهای خود را بطور مجزا تعریف کنیم. تماشا کنید:
<configuration> <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender"> <encoder> <pattern>%d{HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %msg%n</pattern </encoder> </appender> <logger name="me.mujan.logback" level="INFO" /> <logger name="me.mujan.logback.child" level="WARN" /> <root level="debug"> <appender-ref ref="STDOUT" /> </root> </configuration>
فایلهای تنظیمات logback از متغیرها نیز پشتیبانی میکند. ما متغیرها را هم میتوانیم درون اسکریپت تنظیمات تعریف کنیم، هم بصورت خارجی. یک متغیر میتواند توی هرنقطه از اسکریپت تنظیمات تعریف شود.
برای مثال، اینجا یک تنظیمات برای FileAppender داریم:
<property name="LOG_DIR" value="/var/log/application" /> <appender name="FILE" class="ch.qos.logback.core.FileAppender"> <file>${LOG_DIR}/tests.log</file> <append>true</append> <encoder> <pattern>%-4relative [%thread] %-5level %logger{35} - %msg%n</pattern> </encoder> </appender>
در بالای تنظیمات، یک متغیر با کمک تگ property بنام LOG_DIR ایجاد کردیم. سپس از آن بعنوان بخشی از آدرس تعریف appender استفاده کردیم.
خصیصهها (متغیرها) درون تگ property تغریف میشوند. اما آنها از منابع خارجی هم قابل دسترس هستند، نظیر system properties. میتوانیم تعریف property رو در این مثال حذف کنیم و مقدار LOG_DIR رو از طریق کامندلاین بدیم:
$ java -DLOG_DIR=/var/log/application me.mujan.logback.LogbackTests
در اصل Loggerها LoggingEventsها رو به Appenderها ارسال میکند. این Appenderها هستند که کار اصلی لاگ انداختن را انجام میدهند. بطور معمول هم ما لاگ را چیزی درنظر میگیریم که در کنسول یا فایل ذخیره میشود ولی همانطور که در قسمت اول اشاره کردیم Logback امکانات بیشتری هم دارد. کتابخانه Logback-core چندین appender محیا میکند.
تشریح ConsoleAppender
همانطور که تا الان مشاهده کردید، ما از ConsoleAppender استفاده کردیم. در واقع ConsoleAppender پیامها را به System.out و System.err ارسال نمیکند. در عوض از OutputStreamWriter استفاده میکند.
تشریح FileAppender
کلاس FileAppender پیامها در فایل میریزد. این کلاس از رنج پارامترهای زیادی در تنظیمات استفاده میکند. بریم و کانفیگ پایهای آن را ببینیم:
<configuration debug="true"> <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender"> <!-- encoders are assigned the type ch.qos.logback.classic.encoder.PatternLayoutEncoder by default --> <encoder> <pattern>%d{HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %msg%n</pattern> </encoder> </appender> <appender name="FILE" class="ch.qos.logback.core.FileAppender"> <file>tests.log</file> <append>true</append> <encoder> <pattern>%-4relative [%thread] %-5level %logger{35} - %msg%n</pattern> </encoder> </appender> <logger name="me.mujan.logback" level="INFO" /> <logger name="me.mujan.logback.tests" level="WARN"> <appender-ref ref="FILE" /> </logger> <root level="debug"> <appender-ref ref="STDOUT" /> </root> </configuration>
در اینجا FileAppender با تگ file تنظیم شده است. تگ append نیز مشخص کرده است که اگر فایل موجود بود، دیگر آن را ایجاد نکند، و به ادامهی فایل اضافه کند، که اگر امتحانی هم چندین بار اجرا کنید میبینید که هر بار به ادامهی فایل لاگها اضافه میشود.
این رو هم دقت میکنید که مابقی loggerها از root logger ارث بری میکند. میتونیم این تنظیمات رو هم بازنویسی کنیم:
<logger name="me.mujan.logback.tests" level="WARN" additivity="false" > <appender-ref ref="FILE" /> </logger> <root level="debug"> <appender-ref ref="STDOUT" /> </root>
در اینجا additivity رو هم false قرار دادیم تا رفتار پیشفرض غیرفعال شود. الان tests نه در کنسول لاگ میکند و نه دیگر لاگری از نسل آن چنین میکند.
طبق معمول مقالاتی که نگارش کردهام، هرچه جلوتر میرویم توضیحات کمتری درمورد کانفیگها و کدها میدهم (برخلاف ابتدای کار)، چرا که اعتقاد دارم الان میتونید بدرستی فایل کانفیگ را بخوانید. فلذا از این پس توجه بیشتری را باید داشته باشید.
بررسی RollingFileAppender
اغلب اوقات ما نمیخواهیم که پیامهای لاگ به یک فایل مشخص اضافه شود (بعد از مدتی حجم فایل وحشتناک میشود)، به همین خاطر ما فایلها یا براساس زمان، یا براساس حجم (یا بر اساس هر دو) ریست شوند یا رها شوند و فایل دیگری ایجاد شوند.
<property name="LOG_FILE" value="LogFile" />
<appender name="FILE" class="ch.qos.logback.core.rolling.RollingFileAppender">
<file>${LOG_FILE}.log</file>
<rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
<!-- daily rollover -->
<fileNamePattern>${LOG_FILE}.%d{yyyy-MM-dd}.gz</fileNamePattern>
<!-- keep 30 days' worth of history capped at 3GB total size -->
<maxHistory>30</maxHistory>
<totalSizeCap>3GB</totalSizeCap>
</rollingPolicy>
<encoder>
<pattern>%-4relative [%thread] %-5level %logger{35} - %msg%n</pattern>
</encoder>
</appender>
در RollingFileAppender یک RollingPolicy هست. که توی این مثال ما TimeBasedRollingPolicy را کانفیگ کردهایم.
مشابه FileAppender، ما appender را هم با یک نام فایل تنظیم کردیم، که البته در اینجا از متغیرها استفاده کردیم.
ما همچنین fileNamePattern را درون RollingPolicy قرار دادیدم. این الگو اسم فایلها را مشخص میکند.
دقت کنید TimeBasedPolicy تنها گزینهی ما برای rolling کردن فایلها نیست. Logback گزینههای دیگری نظیر SizeAndTimeBasedRollingPolicy را دارد که براساس حجم فایل لاگ کنونی و زمان است و همچنین FixedWindowRollingPolicy که هربار logger اجرا میشود roll میکند. برای اطلاعات بیشتر در اینباره اینجا را مطالعه کنید.
آخرین نکتهی مهم دربارهی RollingFileAppender اینکه، یک فشردهساز داخلی هم دارد. وقتی ما نام فایل را LogFile.gz قرار دادیم، خودش شروع به فشرده سازی هم میکند.
ایجاد Custom Appenders
ما همچنین میتونیم بر اساس کلاسهای پایهی Logback شروع کنیم و appenderهای خودمان را بنویسیم، چه کار جالبانگیزی!
در این مورد خودتان جستوجو کنید.
و خب رسیدیم به Layoutها. Layoutها پیامهای لاگ را فرمت میدهند. مشابه اجزای دیگر Logback ما میتونیم layoutها را هم توسعه بدیم و نسخهی بومی و خودمانی آن را ایجاد کنیم. ولی همان PatternLayout پیشفرض عمدهی نیازهای ما را پوشش میدهد.
تا اینجای کار ما در تمام مثالهایی که دیدیم از PatternLayout استفاده شده بود:
<encoder> <pattern>%d{HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %msg%n</pattern> </encoder>
این اسکریپت تنظیمات شامل تنظیمات برای PatternLayoutEncoder است. ما این Encoder را به Appenderی که ایجاد کردیم پاس میدهیم و خود این Encoder از PatternLayout برای فرمتدهی پیامها استفاده میکند.
متنی که در تگ pattern قرار دارد چگونگی فرمتدهی پیامهای لاگ را مشخص میکند. PatternLayout تنوع بالایی از کلمات مشخص را پیادهسازی کرده که به کمک آنها بتوانیم الگوهای لاگ را مشخص کنیم و تغییر دهیم.
اجازه دهید کمی این قسمت را باز کنیم. PatternLayout کلمات از پیشتعریفشده را با استفاده از % تشخیص میدهد، بنابراین داریم:
خودتان بخوانید، واضح و مبرهن است. چنین الگویی، چنین پیامی را تولید میکند (تو مثالها هم دیدیم):
21:32:10.311 [main] DEBUG me.mujan.logback.LogbackTests - Logging message: This is a String
به اطلاعات بیشتری در این خصوص نیاز دارید؟ بسیار عالی، اینجا را بخوانید.
عجب مقالهی سنگین و مفصلی در رابطه با Logback شد. عاشق نگارش مقالاتی هستم که نمونهی فارسی آنها موجود نیست، تا شاید بتوانم به مقدار ناچیزی در پیشبرد کار شما همکاران عزیزم، مفید واقع شوم.
در این مقاله ما پایه و اساس Logback در اپلیکیشن را پوشش دادیم. به سه جز کلی آن پرداختیم، یعنی loggerها، appenderها، و layout. دیدیم که Logback تنظیمات پرتوانی دارد و ما میتوانیم با کمک آن تمام اجزای آن را customize کنیم. همچنین FileAppender و RollingFileAppender را بعنوان پراستفادهترین ها به تشریح بحث کردیم و گفتیم چطور آن را مدیریت کنید یا لاگ فایلهاتون را فشرده کنید.
برنامهی من اینجا با Logback خاتمه یافت، ولی اگر شرایط محیا شود، شاید استفاده از Logback در Spring Boot را هم بعنوان قسمت سوم اضافه خواهم کرد.
در آخر بابت ایراد احتمالی نگارشی و فنی پیشاپیش عذرخواهی میکنم و خواهشمندم که گوشزد کنید. براتون آرزوی موفقیت دارم :)