1/*2 * Licensed to the Apache Software Foundation (ASF) under one3 * or more contributor license agreements. See the NOTICE file4 * distributed with this work for additional information5 * regarding copyright ownership. The ASF licenses this file6 * to you under the Apache License, Version 2.0 (the7 * "License"); you may not use this file except in compliance8 * with the License. You may obtain a copy of the License at9 *10 * http://www.apache.org/licenses/LICENSE-2.011 *12 * Unless required by applicable law or agreed to in writing, software13 * distributed under the License is distributed on an "AS IS" BASIS,14 * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.15 * See the License for the specific language governing permissions and16 * limitations under the License.17 */1819/* Portions copyright (C) The Apache Software Foundation. All rights reserved.20 *21 * This software is published under the terms of the Apache Software22 * License version 1.1, a copy of which has been included with this23 * distribution in the LICENSE.txt file. */2425package org.apache.hadoop.chukwa.inputtools.log4j;
262728import java.io.File;
29import java.io.FilenameFilter;
30import java.io.IOException;
31import java.text.SimpleDateFormat;
32import java.util.ArrayList;
33import java.util.Calendar;
34import java.util.Collections;
35import java.util.Date;
36import java.util.GregorianCalendar;
37import java.util.List;
38import java.util.Locale;
39import java.util.TimeZone;
40import java.util.regex.Pattern;
4142import org.apache.hadoop.chukwa.datacollection.controller.ChukwaAgentController;
43import org.apache.hadoop.chukwa.datacollection.controller.ClientFinalizer;
44import org.apache.hadoop.chukwa.util.AdaptorNamingUtils;
45import org.apache.hadoop.chukwa.util.RecordConstants;
46import org.apache.log4j.FileAppender;
47import org.apache.log4j.Layout;
48import org.apache.log4j.Logger;
49import org.apache.log4j.helpers.LogLog;
50import org.apache.log4j.spi.LoggingEvent;
5152/**53 ChukwaDailyRollingFileAppender is a slightly modified version of54 DailyRollingFileAppender, with modified versions of its55 <code>subAppend()</code> and <code>rollOver()</code> functions. 56 We would have preferred to sub-class DailyRollingFileAppender but57 its authors clearly did not intend that to be a viable option since58 they made too much of the class private or package-private5960 DailyRollingFileAppender extends {@link FileAppender} so that the61 underlying file is rolled over at a user chosen frequency.6263 <p>The rolling schedule is specified by the <b>DatePattern</b>64 option. This pattern should follow the {@link SimpleDateFormat}65 conventions. In particular, you <em>must</em> escape literal text66 within a pair of single quotes. A formatted version of the date67 pattern is used as the suffix for the rolled file name.6869 <p>For example, if the <b>File</b> option is set to70 <code>/foo/bar.log</code> and the <b>DatePattern</b> set to71 <code>'.'yyyy-MM-dd</code>, on 2001-02-16 at midnight, the logging72 file <code>/foo/bar.log</code> will be copied to73 <code>/foo/bar.log.2001-02-16</code> and logging for 2001-02-1774 will continue in <code>/foo/bar.log</code> until it rolls over75 the next day.7677 <p>Is is possible to specify monthly, weekly, half-daily, daily,78 hourly, or minutely rollover schedules.7980 <p><table border="1" cellpadding="2">81 <tr>82 <th>DatePattern</th>83 <th>Rollover schedule</th>84 <th>Example</th>8586 <tr>87 <td><code>'.'yyyy-MM</code>88 <td>Rollover at the beginning of each month</td>8990 <td>At midnight of May 31st, 2002 <code>/foo/bar.log</code> will be91 copied to <code>/foo/bar.log.2002-05</code>. Logging for the month92 of June will be output to <code>/foo/bar.log</code> until it is93 also rolled over the next month.9495 <tr>96 <td><code>'.'yyyy-ww</code>9798 <td>Rollover at the first day of each week. The first day of the99 week depends on the locale.</td>100101 <td>Assuming the first day of the week is Sunday, on Saturday102 midnight, June 9th 2002, the file <i>/foo/bar.log</i> will be103 copied to <i>/foo/bar.log.2002-23</i>. Logging for the 24th week104 of 2002 will be output to <code>/foo/bar.log</code> until it is105 rolled over the next week.106107 <tr>108 <td><code>'.'yyyy-MM-dd</code>109110 <td>Rollover at midnight each day.</td>111112 <td>At midnight, on March 8th, 2002, <code>/foo/bar.log</code> will113 be copied to <code>/foo/bar.log.2002-03-08</code>. Logging for the114 9th day of March will be output to <code>/foo/bar.log</code> until115 it is rolled over the next day.116117 <tr>118 <td><code>'.'yyyy-MM-dd-a</code>119120 <td>Rollover at midnight and midday of each day.</td>121122 <td>At noon, on March 9th, 2002, <code>/foo/bar.log</code> will be123 copied to <code>/foo/bar.log.2002-03-09-AM</code>. Logging for the124 afternoon of the 9th will be output to <code>/foo/bar.log</code>125 until it is rolled over at midnight.126127 <tr>128 <td><code>'.'yyyy-MM-dd-HH</code>129130 <td>Rollover at the top of every hour.</td>131132 <td>At approximately 11:00.000 o'clock on March 9th, 2002,133 <code>/foo/bar.log</code> will be copied to134 <code>/foo/bar.log.2002-03-09-10</code>. Logging for the 11th hour135 of the 9th of March will be output to <code>/foo/bar.log</code>136 until it is rolled over at the beginning of the next hour.137138139 <tr>140 <td><code>'.'yyyy-MM-dd-HH-mm</code>141142 <td>Rollover at the beginning of every minute.</td>143144 <td>At approximately 11:23,000, on March 9th, 2001,145 <code>/foo/bar.log</code> will be copied to146 <code>/foo/bar.log.2001-03-09-10-22</code>. Logging for the minute147 of 11:23 (9th of March) will be output to148 <code>/foo/bar.log</code> until it is rolled over the next minute.149150 </table>151152 <p>Do not use the colon ":" character in anywhere in the153 <b>DatePattern</b> option. The text before the colon is interpeted154 as the protocol specificaion of a URL which is probably not what155 you want. */156157publicclassChukwaDailyRollingFileAppenderextends FileAppender {
158159static Logger log = Logger.getLogger(ChukwaDailyRollingFileAppender.class);
160// The code assumes that the following constants are in a increasing161// sequence.162staticfinalint TOP_OF_TROUBLE = -1;
163staticfinalint TOP_OF_MINUTE = 0;
164staticfinalint TOP_OF_HOUR = 1;
165staticfinalint HALF_DAY = 2;
166staticfinalint TOP_OF_DAY = 3;
167staticfinalint TOP_OF_WEEK = 4;
168staticfinalint TOP_OF_MONTH = 5;
169170staticfinal String adaptorType = ChukwaAgentController.CharFileTailUTF8NewLineEscaped;
171172staticfinal Object lock = new Object();
173static String lastRotation = "";
174175/**176 * The date pattern. By default, the pattern is set to "'.'yyyy-MM-dd" meaning177 * daily rollover.178 */179private String datePattern = "'.'yyyy-MM-dd";
180181/**182 * The log file will be renamed to the value of the scheduledFilename variable183 * when the next interval is entered. For example, if the rollover period is184 * one hour, the log file will be renamed to the value of "scheduledFilename"185 * at the beginning of the next hour.186 * 187 * The precise time when a rollover occurs depends on logging activity.188 */189private String scheduledFilename;
190191/**192 * The next time we estimate a rollover should occur.193 */194privatelong nextCheck = System.currentTimeMillis() - 1;
195196/**197 * Regex to select log files to be deleted198 */199private String cleanUpRegex = null;
200201/**202 * Set the maximum number of backup files to keep around.203 */204privateint maxBackupIndex = 10;
205206privateClientFinalizer clientFinalizer = null;
207208boolean hasBeenActivated = false;
209 Date now = new Date();
210211 SimpleDateFormat sdf;
212213RollingCalendar rc = newRollingCalendar();
214215int checkPeriod = TOP_OF_TROUBLE;
216217ChukwaAgentController chukwaClient;
218boolean chukwaClientIsNull = true;
219staticfinal Object chukwaLock = new Object();
220221 String chukwaClientHostname;
222int chukwaClientPortNum;
223long chukwaClientConnectNumRetry;
224long chukwaClientConnectRetryInterval;
225226 String recordType;
227228// The gmtTimeZone is used only in computeCheckPeriod() method.229staticfinal TimeZone gmtTimeZone = TimeZone.getTimeZone("GMT");
230231/**232 * The default constructor does nothing.233 */234publicChukwaDailyRollingFileAppender() throws IOException {
235super();
236 }
237238/**239 Instantiate a <code>DailyRollingFileAppender</code> and open the240 file designated by <code>filename</code>. The opened filename will241 become the output destination for this appender.242243 */244publicChukwaDailyRollingFileAppender(Layout layout, String filename,
245 String datePattern) throws IOException {
246super(layout, filename, true);
247 System.out
248 .println("Daily Rolling File Appender successfully registered file with agent: "249 + filename);
250this.datePattern = datePattern;
251 }
252253/**254 * The <b>DatePattern</b> takes a string in the same format as expected by255 * {@link SimpleDateFormat}. This options determines the rollover schedule.256 */257publicvoid setDatePattern(String pattern) {
258 datePattern = pattern;
259 }
260261/** Returns the value of the <b>DatePattern</b> option. */262public String getDatePattern() {
263return datePattern;
264 }
265266public String getRecordType() {
267if (recordType != null)
268return recordType;
269else270return"unknown";
271 }
272273publicvoid setRecordType(String recordType) {
274this.recordType = recordType;
275 }
276277publicvoid activateOptions() {
278279// Prevent early initialisation280if (!hasBeenActivated)
281 { return;}
282283super.activateOptions();
284if (datePattern != null && fileName != null) {
285 now.setTime(System.currentTimeMillis());
286 sdf = new SimpleDateFormat(datePattern);
287int type = computeCheckPeriod();
288 printPeriodicity(type);
289 rc.setType(type);
290 File file = new File(fileName);
291 scheduledFilename = fileName + sdf.format(new Date(file.lastModified()));
292293 } else {
294 LogLog
295 .error("Either File or DatePattern options are not set for appender ["296 + name + "].");
297 }
298 }
299300void printPeriodicity(int type) {
301switch (type) {
302case TOP_OF_MINUTE:
303 LogLog.debug("Appender [" + name + "] to be rolled every minute.");
304break;
305case TOP_OF_HOUR:
306 LogLog
307 .debug("Appender [" + name + "] to be rolled on top of every hour.");
308break;
309case HALF_DAY:
310 LogLog.debug("Appender [" + name
311 + "] to be rolled at midday and midnight.");
312break;
313case TOP_OF_DAY:
314 LogLog.debug("Appender [" + name + "] to be rolled at midnight.");
315break;
316case TOP_OF_WEEK:
317 LogLog.debug("Appender [" + name + "] to be rolled at start of week.");
318break;
319case TOP_OF_MONTH:
320 LogLog.debug("Appender [" + name
321 + "] to be rolled at start of every month.");
322break;
323default:
324 LogLog.warn("Unknown periodicity for appender [" + name + "].");
325 }
326 }
327328// This method computes the roll over period by looping over the329// periods, starting with the shortest, and stopping when the r0 is330// different from from r1, where r0 is the epoch formatted according331// the datePattern (supplied by the user) and r1 is the332// epoch+nextMillis(i) formatted according to datePattern. All date333// formatting is done in GMT and not local format because the test334// logic is based on comparisons relative to 1970-01-01 00:00:00335// GMT (the epoch).336337int computeCheckPeriod() {
338RollingCalendar rollingCalendar = newRollingCalendar(gmtTimeZone,
339 Locale.ENGLISH);
340// set sate to 1970-01-01 00:00:00 GMT341 Date epoch = new Date(0);
342if (datePattern != null) {
343for (int i = TOP_OF_MINUTE; i <= TOP_OF_MONTH; i++) {
344 SimpleDateFormat simpleDateFormat = new SimpleDateFormat(datePattern);
345 simpleDateFormat.setTimeZone(gmtTimeZone); // do all date formatting in346// GMT347 String r0 = simpleDateFormat.format(epoch);
348 rollingCalendar.setType(i);
349 Date next = new Date(rollingCalendar.getNextCheckMillis(epoch));
350 String r1 = simpleDateFormat.format(next);
351// System.out.println("Type = "+i+", r0 = "+r0+", r1 = "+r1);352if (r0 != null && r1 != null && !r0.equals(r1)) {
353return i;
354 }
355 }
356 }
357return TOP_OF_TROUBLE; // Deliberately head for trouble...358 }
359360/**361 * Rollover the current file to a new file.362 */363void rollOver() throws IOException {
364365/* Compute filename, but only if datePattern is specified */366if (datePattern == null) {
367 errorHandler.error("Missing DatePattern option in rollOver().");
368return;
369 }
370371 String datedFilename = fileName + sdf.format(now);
372// It is too early to roll over because we are still within the373// bounds of the current interval. Rollover will occur once the374// next interval is reached.375if (scheduledFilename.equals(datedFilename)) {
376return;
377 }
378379// close current file, and rename it to datedFilename380this.closeFile();
381382 File target = new File(scheduledFilename);
383if (target.exists()) {
384 target.delete();
385 }
386387 File file = new File(fileName);
388389boolean result = file.renameTo(target);
390if (result) {
391 LogLog.debug(fileName + " -> " + scheduledFilename);
392 } else {
393 LogLog.error("Failed to rename [" + fileName + "] to ["394 + scheduledFilename + "].");
395 }
396397try {
398// This will also close the file. This is OK since multiple399// close operations are safe.400this.setFile(fileName, false, this.bufferedIO, this.bufferSize);
401 } catch (IOException e) {
402 errorHandler.error("setFile(" + fileName + ", false) call failed.");
403 }
404 scheduledFilename = datedFilename;
405 cleanUp();
406 }
407408public String getCleanUpRegex() {
409return cleanUpRegex;
410 }
411412publicvoid setCleanUpRegex(String cleanUpRegex) {
413this.cleanUpRegex = cleanUpRegex;
414 }
415416publicint getMaxBackupIndex() {
417return maxBackupIndex;
418 }
419420publicvoid setMaxBackupIndex(int maxBackupIndex) {
421this.maxBackupIndex = maxBackupIndex;
422 }
423424protectedsynchronizedvoid cleanUp() {
425 String regex = "";
426try {
427 File actualFile = new File(fileName);
428429 String directoryName = actualFile.getParent();
430 String actualFileName = actualFile.getName();
431 File dirList = new File(directoryName);
432433if (cleanUpRegex == null || !cleanUpRegex.contains("$fileName")) {
434 LogLog
435 .error("cleanUpRegex == null || !cleanUpRegex.contains(\"$fileName\")");
436return;
437 }
438 regex = cleanUpRegex.replace("$fileName", actualFileName);
439 String[] dirFiles = dirList.list(newLogFilter(actualFileName, regex));
440441 List<String> files = new ArrayList<String>();
442for (String file : dirFiles) {
443 files.add(file);
444 }
445 Collections.sort(files);
446447while (files.size() > maxBackupIndex) {
448 String file = files.remove(0);
449 File f = new File(directoryName + "/" + file);
450 f.delete();
451 LogLog.debug("Removing: " + file);
452 }
453 } catch (Exception e) {
454 errorHandler
455 .error("cleanUp(" + fileName + "," + regex + ") call failed.");
456 }
457 }
458459privateclassLogFilterimplements FilenameFilter {
460private Pattern p = null;
461private String logFile = null;
462463publicLogFilter(String logFile, String regex) {
464this.logFile = logFile;
465 p = Pattern.compile(regex);
466 }
467468 @Override
469publicboolean accept(File dir, String name) {
470// ignore current log file471if (name.intern() == this.logFile.intern()) {
472return false;
473 }
474// ignore file without the same prefix475if (!name.startsWith(logFile)) {
476return false;
477 }
478return p.matcher(name).find();
479 }
480 }
481482/**483 * Fix for late-initialisation484 */485 @Override
486protectedboolean checkEntryConditions() {
487if (!hasBeenActivated) {
488synchronized(chukwaLock) {
489if (!hasBeenActivated) {
490 hasBeenActivated = true;
491 activateOptions();
492 }
493 }
494 }
495returnsuper.checkEntryConditions();
496 }
497498/**499 * This method differentiates DailyRollingFileAppender from its super class.500 * 501 * <p>Before actually logging, this method will check whether it is time to do502 * a rollover. If it is, it will schedule the next rollover time and then503 * rollover.504 * */505protectedvoid subAppend(LoggingEvent event) {
506try {
507// we set up the chukwa adaptor here because this is the first508// point which is called after all setters have been called with509// their values from the log4j.properties file, in particular we510// needed to give setCukwaClientPortNum() and -Hostname() a shot511512// Make sure only one thread can do this513// and use the boolean to avoid the first level locking514if (chukwaClientIsNull) {
515synchronized (chukwaLock) {
516517 String log4jFileName = getFile();
518 String recordType = getRecordType();
519520long currentLength = 0L;
521try {
522 File fooLog = new File(log4jFileName);
523 log4jFileName = fooLog.getAbsolutePath();
524 currentLength = fooLog.length();
525 } catch (Throwable e) {
526 log.warn("Exception while trying to get current file size for " + log4jFileName);
527 currentLength = 0L;
528 }
529530if (chukwaClient == null) {
531if (getChukwaClientHostname() != null532 && getChukwaClientPortNum() != 0) {
533 chukwaClient = newChukwaAgentController(
534 getChukwaClientHostname(), getChukwaClientPortNum());
535 log.debug("setup adaptor with hostname "536 + getChukwaClientHostname() + " and portnum "537 + getChukwaClientPortNum());
538 } else {
539 chukwaClient = newChukwaAgentController();
540 log
541 .debug("setup adaptor with no args, which means it used its defaults");
542 }
543544 chukwaClientIsNull = false;
545546// Watchdog is watching for ChukwaAgent only once every 5 minutes,547// so there's no point in retrying more than once every 5 mins.548// In practice, if the watchdog is not able to automatically restart549// the agent, it will take more than 20 minutes to get Ops to550// restart it.551// Also its a good to limit the number of communications between552// Hadoop and Chukwa, that's why 30 minutes.553long retryInterval = chukwaClientConnectRetryInterval;
554if (retryInterval == 0) {
555 retryInterval = 1000 * 60 * 30;
556 }
557long numRetries = chukwaClientConnectNumRetry;
558if (numRetries == 0) {
559 numRetries = 48;
560 }
561562 String name = AdaptorNamingUtils.synthesizeAdaptorID
563 (ChukwaAgentController.CharFileTailUTF8NewLineEscaped, recordType, log4jFileName);
564565 String adaptorID = chukwaClient.addByName(name, ChukwaAgentController.CharFileTailUTF8NewLineEscaped,
566 recordType,currentLength + " " + log4jFileName, currentLength,
567 numRetries, retryInterval);
568569// Setup a shutdownHook for the controller570 clientFinalizer = newClientFinalizer(chukwaClient);
571 Runtime.getRuntime().addShutdownHook(clientFinalizer);
572573if (adaptorID != null) {
574 log.debug("Added file tailing adaptor to chukwa agent for file "575 + log4jFileName + ", adaptorId:" + adaptorID
576 + " using this recordType :" + recordType
577 + ", starting at offset:" + currentLength);
578 } else {
579 log.debug("Chukwa adaptor not added, addFile(" + log4jFileName
580 + ") returned " + adaptorID
581 + ", current offset:" + currentLength);
582 }
583584 }
585 }
586 }
587588long n = System.currentTimeMillis();
589if (n >= nextCheck) {
590 now.setTime(n);
591 nextCheck = rc.getNextCheckMillis(now);
592try {
593 rollOver();
594 } catch (IOException ioe) {
595 LogLog.error("rollOver() failed.", ioe);
596 }
597 }
598599boolean written = false;
600if(layout.ignoresThrowable()) {
601 String[] s = event.getThrowableStrRep();
602if (s != null) {
603int len = s.length;
604 StringBuilder sb = new StringBuilder();
605 sb.append(this.layout.format(event));
606for(int i = 0; i < len; i++) {
607 sb.append(s[i]).append("\n");
608 }
609//escape the newlines from record bodies, exception and then write this record to the log file610 written = true;
611this.qw.write(RecordConstants.escapeAllButLastRecordSeparator("\n",sb.toString()));
612 }
613 }
614615if (!written) {
616//escape the newlines from record bodies and then write this record to the log file617this.qw.write(RecordConstants.escapeAllButLastRecordSeparator("\n",this.layout.format(event)));
618 }
619620if (this.immediateFlush) {
621this.qw.flush();
622 }
623 } catch (Throwable e) {
624 System.err.println("Exception in ChukwaRollingAppender: "625 + e.getMessage());
626 e.printStackTrace();
627 }
628629 }
630631public String getChukwaClientHostname() {
632return chukwaClientHostname;
633 }
634635publicvoid setChukwaClientHostname(String chukwaClientHostname) {
636this.chukwaClientHostname = chukwaClientHostname;
637 }
638639publicint getChukwaClientPortNum() {
640return chukwaClientPortNum;
641 }
642643publicvoid setChukwaClientPortNum(int chukwaClientPortNum) {
644this.chukwaClientPortNum = chukwaClientPortNum;
645 }
646647publicvoid setChukwaClientConnectNumRetry(int i) {
648this.chukwaClientConnectNumRetry = i;
649 }
650651publicvoid setChukwaClientConnectRetryInterval(long i) {
652this.chukwaClientConnectRetryInterval = i;
653 }
654655 }
656657658/**659 * RollingCalendar is a helper class to DailyRollingFileAppender. Given a660 * periodicity type and the current time, it computes the start of the next661 * interval.662 * */663classRollingCalendarextends GregorianCalendar {
664665/**666 * 667 */668privatestaticfinallong serialVersionUID = 2153481574198792767L;
669int type = ChukwaDailyRollingFileAppender.TOP_OF_TROUBLE;
670671RollingCalendar() {
672super();
673 }
674675RollingCalendar(TimeZone tz, Locale locale) {
676super(tz, locale);
677 }
678679void setType(int type) {
680this.type = type;
681 }
682683publiclong getNextCheckMillis(Date now) {
684return getNextCheckDate(now).getTime();
685 }
686687public Date getNextCheckDate(Date now) {
688this.setTime(now);
689690switch (type) {
691case ChukwaDailyRollingFileAppender.TOP_OF_MINUTE:
692this.set(Calendar.SECOND, 0);
693this.set(Calendar.MILLISECOND, 0);
694this.add(Calendar.MINUTE, 1);
695break;
696case ChukwaDailyRollingFileAppender.TOP_OF_HOUR:
697this.set(Calendar.MINUTE, 0);
698this.set(Calendar.SECOND, 0);
699this.set(Calendar.MILLISECOND, 0);
700this.add(Calendar.HOUR_OF_DAY, 1);
701break;
702case ChukwaDailyRollingFileAppender.HALF_DAY:
703this.set(Calendar.MINUTE, 0);
704this.set(Calendar.SECOND, 0);
705this.set(Calendar.MILLISECOND, 0);
706int hour = get(Calendar.HOUR_OF_DAY);
707if (hour < 12) {
708this.set(Calendar.HOUR_OF_DAY, 12);
709 } else {
710this.set(Calendar.HOUR_OF_DAY, 0);
711this.add(Calendar.DAY_OF_MONTH, 1);
712 }
713break;
714case ChukwaDailyRollingFileAppender.TOP_OF_DAY:
715this.set(Calendar.HOUR_OF_DAY, 0);
716this.set(Calendar.MINUTE, 0);
717this.set(Calendar.SECOND, 0);
718this.set(Calendar.MILLISECOND, 0);
719this.add(Calendar.DATE, 1);
720break;
721case ChukwaDailyRollingFileAppender.TOP_OF_WEEK:
722this.set(Calendar.DAY_OF_WEEK, getFirstDayOfWeek());
723this.set(Calendar.HOUR_OF_DAY, 0);
724this.set(Calendar.SECOND, 0);
725this.set(Calendar.MILLISECOND, 0);
726this.add(Calendar.WEEK_OF_YEAR, 1);
727break;
728case ChukwaDailyRollingFileAppender.TOP_OF_MONTH:
729this.set(Calendar.DATE, 1);
730this.set(Calendar.HOUR_OF_DAY, 0);
731this.set(Calendar.SECOND, 0);
732this.set(Calendar.MILLISECOND, 0);
733this.add(Calendar.MONTH, 1);
734break;
735default:
736thrownew IllegalStateException("Unknown periodicity type.");
737 }
738return getTime();
739 }
740 }