001: /*
002: * Copyright (c) 1998-2008 Caucho Technology -- all rights reserved
003: *
004: * This file is part of Resin(R) Open Source
005: *
006: * Each copy or derived work must preserve the copyright notice and this
007: * notice unmodified.
008: *
009: * Resin Open Source is free software; you can redistribute it and/or modify
010: * it under the terms of the GNU General Public License as published by
011: * the Free Software Foundation; either version 2 of the License, or
012: * (at your option) any later version.
013: *
014: * Resin Open Source is distributed in the hope that it will be useful,
015: * but WITHOUT ANY WARRANTY; without even the implied warranty of
016: * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE, or any warranty
017: * of NON-INFRINGEMENT. See the GNU General Public License for more
018: * details.
019: *
020: * You should have received a copy of the GNU General Public License
021: * along with Resin Open Source; if not, write to the
022: *
023: * Free Software Foundation, Inc.
024: * 59 Temple Place, Suite 330
025: * Boston, MA 02111-1307 USA
026: *
027: * @author Scott Ferguson
028: */
029:
030: package com.caucho.server.log;
031:
032: import com.caucho.config.ConfigException;
033: import com.caucho.config.types.Bytes;
034: import com.caucho.config.types.Period;
035: import com.caucho.loader.CloseListener;
036: import com.caucho.loader.Environment;
037: import com.caucho.server.connection.AbstractHttpRequest;
038: import com.caucho.server.connection.AbstractHttpResponse;
039: import com.caucho.server.util.CauchoSystem;
040: import com.caucho.util.*;
041: import com.caucho.vfs.Path;
042:
043: import javax.annotation.PostConstruct;
044: import javax.servlet.ServletContext;
045: import javax.servlet.ServletException;
046: import javax.servlet.http.Cookie;
047: import javax.servlet.http.HttpServletRequest;
048: import javax.servlet.http.HttpServletResponse;
049: import java.io.IOException;
050: import java.util.ArrayList;
051: import java.util.logging.Logger;
052: import java.util.regex.*;
053:
054: /**
055: * Represents an log of every top-level request to the server.
056: */
057: public class AccessLog extends AbstractAccessLog implements
058: AlarmListener {
059: protected static final L10N L = new L10N(AccessLog.class);
060: protected static final Logger log = Logger
061: .getLogger(AccessLog.class.getName());
062:
063: // Default maximum log size = 1G
064: private static final long ROLLOVER_SIZE = 1024L * 1024L * 1024L;
065: // Milliseconds in a day
066: private static final long DAY = 24L * 3600L * 1000L;
067: // How often to check size
068: private static final long ROLLOVER_CHECK_TIME = 600L * 1000L;
069:
070: public static final int BUFFER_SIZE = 65536;
071: private static final int BUFFER_GAP = 8 * 1024;
072:
073: private QDate _calendar = QDate.createLocal();
074: private String _timeFormat;
075: private int _timeFormatSecondOffset = -1;
076:
077: private final AccessLogWriter _logWriter = new AccessLogWriter(this );
078:
079: // AccessStream
080: private Object _streamLock = new Object();
081:
082: private String _format;
083: private Segment[] _segments;
084:
085: private ArrayList<Pattern> _excludeList = new ArrayList<Pattern>();
086: private Pattern[] _excludes = new Pattern[0];
087:
088: private boolean _isAutoFlush;
089:
090: private boolean _isSharedBuffer = true;
091: private Object _sharedBufferLock;
092:
093: private long _autoFlushTime = 60000;
094:
095: private final CharBuffer _cb = new CharBuffer();
096:
097: private final CharBuffer _timeCharBuffer = new CharBuffer();
098: private final ByteBuffer _timeBuffer = new ByteBuffer();
099: private long _lastTime;
100:
101: private Alarm _alarm = new Alarm(this );
102: private boolean _isActive;
103:
104: public AccessLog() {
105: setRolloverSize(new Bytes(ROLLOVER_SIZE));
106: }
107:
108: /**
109: * Sets the access log format.
110: */
111: public void setFormat(String format) {
112: _format = format;
113: }
114:
115: /**
116: * Sets the log path
117: */
118: public void setPath(Path path) {
119: super .setPath(path);
120:
121: _logWriter.setPath(path);
122: }
123:
124: /**
125: * Sets the formatted path.
126: */
127: public void setPathFormat(String pathFormat) throws ConfigException {
128: super .setPathFormat(pathFormat);
129:
130: _logWriter.setPathFormat(pathFormat);
131: }
132:
133: /**
134: * Sets the archive name format
135: */
136: public void setArchiveFormat(String format) {
137: _logWriter.setArchiveFormat(format);
138: }
139:
140: /**
141: * Sets the maximum number of rolled logs.
142: *
143: * @param count maximum count of the log file
144: */
145: public void setRolloverCount(int count) {
146: _logWriter.setRolloverCount(count);
147: }
148:
149: /**
150: * Sets the log rollover period, rounded up to the nearest hour.
151: *
152: * @param period the new rollover period in milliseconds.
153: */
154: public void setRolloverPeriod(Period period) {
155: _logWriter.setRolloverPeriod(period);
156: }
157:
158: /**
159: * Sets the log rollover size, rounded up to the megabyte.
160: *
161: * @param size maximum size of the log file
162: */
163: public void setRolloverSize(Bytes bytes) {
164: _logWriter.setRolloverSize(bytes);
165: }
166:
167: /**
168: * Sets how often the log rollover will be checked.
169: *
170: * @param period how often the log rollover will be checked.
171: */
172: public void setRolloverCheckTime(long period) {
173: _logWriter.setRolloverCheckPeriod(period);
174: }
175:
176: /**
177: * Sets the auto-flush attribute.
178: */
179: public void setAutoFlush(boolean isAutoFlush) {
180: _isAutoFlush = isAutoFlush;
181: }
182:
183: /**
184: * Sets the autoFlushTime
185: */
186: public void setAutoFlushTime(Period period) {
187: _autoFlushTime = period.getPeriod();
188: }
189:
190: /**
191: * Sets the shared buffer attribute.
192: */
193: public void setSharedBuffer(boolean isSharedBuffer) {
194: _isSharedBuffer = isSharedBuffer;
195: }
196:
197: /**
198: * Adds an exclusion pattern.
199: */
200: public void addExclude(Pattern pattern) {
201: _excludeList.add(pattern);
202: _excludes = new Pattern[_excludeList.size()];
203: _excludeList.toArray(_excludes);
204: }
205:
206: /**
207: * Initialize the log.
208: */
209: @PostConstruct
210: public void init() throws ServletException, IOException {
211: _isActive = true;
212:
213: Environment.addClassLoaderListener(new CloseListener(this ));
214:
215: if (_format == null)
216: _format = "%h %l %u %t \"%r\" %>s %b \"%{Referer}i\" \"%{User-Agent}i\"";
217:
218: ArrayList<Segment> segments = parseFormat(_format);
219:
220: _segments = new Segment[segments.size()];
221: segments.toArray(_segments);
222:
223: if (_timeFormat == null || _timeFormat.equals("")) {
224: _timeFormat = "[%d/%b/%Y:%H:%M:%S %z]";
225: _timeFormatSecondOffset = 0;
226: }
227:
228: _logWriter.init();
229: _sharedBufferLock = _logWriter.getBufferLock();
230:
231: if (_autoFlushTime > 0)
232: _alarm.queue(_autoFlushTime);
233: }
234:
235: /**
236: * Parses the access log string.
237: */
238: private ArrayList<Segment> parseFormat(String format) {
239: ArrayList<Segment> segments = new ArrayList<Segment>();
240: CharBuffer cb = new CharBuffer();
241:
242: int i = 0;
243: while (i < _format.length()) {
244: char ch = _format.charAt(i++);
245:
246: if (ch != '%' || i >= _format.length()) {
247: cb.append((char) ch);
248: continue;
249: }
250:
251: String arg = null;
252: ch = _format.charAt(i++);
253: if (ch == '>')
254: ch = _format.charAt(i++);
255: else if (ch == '{') {
256: if (cb.length() > 0)
257: segments.add(new Segment(this , Segment.TEXT, cb
258: .toString()));
259: cb.clear();
260: while (i < _format.length()
261: && _format.charAt(i++) != '}')
262: cb.append(_format.charAt(i - 1));
263: arg = cb.toString();
264: cb.clear();
265:
266: ch = _format.charAt(i++);
267: }
268:
269: switch (ch) {
270: case 'b':
271: case 'c':
272: case 'h':
273: case 'i':
274: case 'l':
275: case 'n':
276: case 'r':
277: case 's':
278: case 'T':
279: case 'D':
280: case 'o':
281: case 'u':
282: case 'U':
283: if (cb.length() > 0)
284: segments.add(new Segment(this , Segment.TEXT, cb
285: .toString()));
286: cb.clear();
287: segments.add(new Segment(this , ch, arg));
288: break;
289:
290: case 't':
291: if (cb.length() > 0)
292: segments.add(new Segment(this , Segment.TEXT, cb
293: .toString()));
294: cb.clear();
295: if (arg != null)
296: _timeFormat = arg;
297: segments.add(new Segment(this , ch, arg));
298: break;
299:
300: default:
301: cb.append('%');
302: i--;
303: break;
304: }
305: }
306:
307: cb.append(CauchoSystem.getNewlineString());
308: segments.add(new Segment(this , Segment.TEXT, cb.toString()));
309:
310: return segments;
311: }
312:
313: /**
314: * Logs a request using the current format.
315: */
316: public void log(HttpServletRequest req, HttpServletResponse res,
317: ServletContext application) throws IOException {
318: AbstractHttpRequest request = (AbstractHttpRequest) req;
319: AbstractHttpResponse response = (AbstractHttpResponse) res;
320:
321: // skip excluded urls
322: if (_excludes.length > 0) {
323: byte[] data = request.getUriBuffer();
324: int sublen = request.getUriLength();
325:
326: String uri = new String(data, 0, sublen);
327:
328: for (Pattern pattern : _excludes) {
329: if (pattern.matcher(uri).find()) {
330: return;
331: }
332: }
333: }
334:
335: if (_isSharedBuffer && (!_isAutoFlush || _autoFlushTime <= 0)) {
336: synchronized (_sharedBufferLock) {
337: byte[] buffer = _logWriter.getBuffer(BUFFER_GAP);
338: int length = _logWriter.getLength();
339:
340: length = log(request, response, buffer, length,
341: buffer.length - length);
342:
343: _logWriter.setLength(length);
344: }
345: } else {
346: byte[] buffer = request.getLogBuffer();
347:
348: int length = log(request, response, buffer, 0,
349: buffer.length);
350:
351: if (_isAutoFlush && _autoFlushTime > 0)
352: _logWriter.writeThrough(buffer, 0, length);
353: else
354: _logWriter.writeBuffer(buffer, 0, length);
355: }
356: }
357:
358: /**
359: * Logs a request using the current format.
360: *
361: * @param request the servlet request.
362: * @param response the servlet response.
363: * @param buffer byte buffer containing the response
364: * @param offset buffer starting offset
365: * @param length length allowed in the buffer
366: *
367: * @return the new tail of the buffer
368: */
369: private int log(AbstractHttpRequest request,
370: AbstractHttpResponse response, byte[] buffer, int offset,
371: int length) throws IOException {
372: int len = _segments.length;
373: for (int i = 0; i < len; i++) {
374: Segment segment = _segments[i];
375: String value = null;
376: CharBuffer cbValue = null;
377: CharSegment csValue = null;
378:
379: switch (segment._code) {
380: case Segment.TEXT:
381: int sublen = segment._data.length;
382: byte[] data = segment._data;
383: for (int j = 0; j < sublen; j++)
384: buffer[offset++] = data[j];
385: break;
386:
387: case Segment.CHAR:
388: buffer[offset++] = segment._ch;
389: break;
390:
391: case 'b':
392: if (response.getStatusCode() == 304)
393: buffer[offset++] = (byte) '-';
394: else
395: offset = print(buffer, offset, response
396: .getContentLength());
397: break;
398:
399: // cookie
400: case 'c':
401: Cookie cookie = request.getCookie(segment._string);
402: if (cookie == null)
403: cookie = response.getCookie(segment._string);
404: if (cookie == null)
405: buffer[offset++] = (byte) '-';
406: else
407: offset = print(buffer, offset, cookie.getValue());
408: break;
409:
410: // set cookie
411: case Segment.SET_COOKIE:
412: ArrayList cookies = response.getCookies();
413: if (cookies == null || cookies.size() == 0)
414: buffer[offset++] = (byte) '-';
415: else {
416: _cb.clear();
417: response.fillCookie(_cb, (Cookie) cookies.get(0),
418: 0, 0, false);
419:
420: offset = print(buffer, offset, _cb.getBuffer(), 0,
421: _cb.getLength());
422: }
423: break;
424:
425: case 'h':
426: offset = request.printRemoteAddr(buffer, offset);
427: break;
428:
429: // input header
430: case 'i':
431: csValue = request.getHeaderBuffer(segment._string);
432: if (csValue == null)
433: buffer[offset++] = (byte) '-';
434: else
435: offset = print(buffer, offset, csValue);
436: break;
437:
438: case 'l':
439: buffer[offset++] = (byte) '-';
440: break;
441:
442: // request attribute
443: case 'n':
444: Object oValue = request.getAttribute(segment._string);
445: if (oValue == null)
446: buffer[offset++] = (byte) '-';
447: else
448: offset = print(buffer, offset, String
449: .valueOf(oValue));
450: break;
451:
452: // output header
453: case 'o':
454: value = response.getHeader(segment._string);
455: if (value == null)
456: buffer[offset++] = (byte) '-';
457: else
458: offset = print(buffer, offset, value);
459: break;
460:
461: case 'r':
462: offset = print(buffer, offset, request.getMethod());
463:
464: buffer[offset++] = (byte) ' ';
465:
466: data = request.getUriBuffer();
467: sublen = request.getUriLength();
468: System.arraycopy(data, 0, buffer, offset, sublen);
469: offset += sublen;
470: buffer[offset++] = (byte) ' ';
471:
472: offset = print(buffer, offset, request.getProtocol());
473: break;
474:
475: case 's':
476: int status = response.getStatusCode();
477: buffer[offset++] = (byte) ('0' + (status / 100) % 10);
478: buffer[offset++] = (byte) ('0' + (status / 10) % 10);
479: buffer[offset++] = (byte) ('0' + status % 10);
480: break;
481:
482: case 't':
483: long date = Alarm.getCurrentTime();
484:
485: if (date / 1000 != _lastTime / 1000)
486: fillTime(date);
487:
488: sublen = _timeBuffer.getLength();
489: data = _timeBuffer.getBuffer();
490:
491: synchronized (_timeBuffer) {
492: System.arraycopy(data, 0, buffer, offset, sublen);
493: }
494:
495: offset += sublen;
496: break;
497:
498: case 'T': {
499: long startTime = request.getStartTime();
500: long endTime = Alarm.getExactTime();
501:
502: offset = print(buffer, offset, (int) ((endTime
503: - startTime + 500) / 1000));
504: break;
505: }
506:
507: case 'D': {
508: long startTime = request.getStartTime();
509: long endTime = Alarm.getExactTime();
510:
511: offset = print(buffer, offset,
512: (int) ((endTime - startTime) * 1000));
513: break;
514: }
515:
516: case 'u':
517: value = request.getRemoteUser(false);
518: if (value == null)
519: buffer[offset++] = (byte) '-';
520: else {
521: buffer[offset++] = (byte) '"';
522: offset = print(buffer, offset, value);
523: buffer[offset++] = (byte) '"';
524: }
525: break;
526:
527: case 'U':
528: offset = print(buffer, offset, request.getRequestURI());
529: break;
530:
531: default:
532: throw new IOException();
533: }
534: }
535:
536: return offset;
537: }
538:
539: /**
540: * Prints a CharSegment to the log.
541: *
542: * @param buffer receiving byte buffer.
543: * @param offset offset into the receiving buffer.
544: * @param cb the new char segment to be logged.
545: * @return the new offset into the byte buffer.
546: */
547: private int print(byte[] buffer, int offset, CharSegment cb) {
548: char[] charBuffer = cb.getBuffer();
549: int cbOffset = cb.getOffset();
550: int length = cb.getLength();
551:
552: // truncate for hacker attacks
553: if (buffer.length - offset - 256 < length)
554: length = buffer.length - offset - 256;
555:
556: for (int i = length - 1; i >= 0; i--)
557: buffer[offset + i] = (byte) charBuffer[cbOffset + i];
558:
559: return offset + length;
560: }
561:
562: /**
563: * Prints a String to the log.
564: *
565: * @param buffer receiving byte buffer.
566: * @param offset offset into the receiving buffer.
567: * @param s the new string to be logged.
568: * @return the new offset into the byte buffer.
569: */
570: private int print(byte[] buffer, int offset, String s) {
571: int length = s.length();
572:
573: _cb.ensureCapacity(length);
574: char[] cBuf = _cb.getBuffer();
575:
576: s.getChars(0, length, cBuf, 0);
577:
578: for (int i = length - 1; i >= 0; i--)
579: buffer[offset + i] = (byte) cBuf[i];
580:
581: return offset + length;
582: }
583:
584: /**
585: * Prints a String to the log.
586: *
587: * @param buffer receiving byte buffer.
588: * @param offset offset into the receiving buffer.
589: * @param s the new string to be logged.
590: * @return the new offset into the byte buffer.
591: */
592: private int print(byte[] buffer, int offset, char[] cb, int cbOff,
593: int length) {
594: for (int i = length - 1; i >= 0; i--)
595: buffer[offset + i] = (byte) cb[cbOff + i];
596:
597: return offset + length;
598: }
599:
600: /**
601: * Prints an integer to the log.
602: *
603: * @param buffer receiving byte buffer.
604: * @param offset offset into the receiving buffer.
605: * @param v the new integer to be logged.
606: * @return the new offset into the byte buffer.
607: */
608: private int print(byte[] buffer, int offset, long v) {
609: if (v == 0) {
610: buffer[offset] = (byte) '0';
611: return offset + 1;
612: }
613:
614: if (v < 0) {
615: buffer[offset++] = (byte) '-';
616: v = -v;
617: }
618:
619: int length = 0;
620: int exp = 10;
621:
622: for (; exp <= v && exp > 0; length++)
623: exp = 10 * exp;
624:
625: offset += length;
626: for (int i = 0; i <= length; i++) {
627: buffer[offset - i] = (byte) (v % 10 + '0');
628: v = v / 10;
629: }
630:
631: return offset + 1;
632: }
633:
634: /**
635: * Flushes the log.
636: */
637: public void flush() {
638: // server/0213, 021q
639: _logWriter.flush();
640: _logWriter.waitForFlush(5000L);
641: _logWriter.rollover();
642: }
643:
644: /**
645: * The alarm listener.
646: */
647: public void handleAlarm(Alarm alarm) {
648: try {
649: flush();
650: } finally {
651: alarm = _alarm;
652: if (alarm != null && _autoFlushTime > 0)
653: alarm.queue(_autoFlushTime);
654: }
655: }
656:
657: /**
658: * Closes the log, flushing the results.
659: */
660: public void destroy() throws IOException {
661: _isActive = false;
662:
663: Alarm alarm = _alarm;
664: ;
665: _alarm = null;
666:
667: if (alarm != null)
668: alarm.dequeue();
669:
670: _logWriter.close();
671: }
672:
673: /**
674: * Fills the time buffer with the formatted time.
675: *
676: * @param date current time in milliseconds
677: */
678: private void fillTime(long date) throws IOException {
679: if (date / 1000 == _lastTime / 1000)
680: return;
681:
682: synchronized (_timeBuffer) {
683: if (_timeFormatSecondOffset >= 0
684: && date / 60000 == _lastTime / 60000) {
685: byte[] bBuf = _timeBuffer.getBuffer();
686:
687: int sec = (int) (date / 1000 % 60);
688:
689: bBuf[_timeFormatSecondOffset + 0] = (byte) ('0' + sec / 10);
690: bBuf[_timeFormatSecondOffset + 1] = (byte) ('0' + sec % 10);
691:
692: return;
693: }
694:
695: _timeCharBuffer.clear();
696: QDate.formatLocal(_timeCharBuffer, date, _timeFormat);
697:
698: if (_timeFormatSecondOffset >= 0)
699: _timeFormatSecondOffset = _timeCharBuffer
700: .lastIndexOf(':') + 1;
701:
702: char[] cBuf = _timeCharBuffer.getBuffer();
703: int length = _timeCharBuffer.getLength();
704:
705: _timeBuffer.setLength(length);
706: byte[] bBuf = _timeBuffer.getBuffer();
707:
708: for (int i = length - 1; i >= 0; i--)
709: bBuf[i] = (byte) cBuf[i];
710: }
711:
712: _lastTime = date;
713: }
714:
715: /**
716: * Represents one portion of the access log.
717: */
718: static class Segment {
719: final static int TEXT = 0;
720: final static int CHAR = 1;
721: final static int SET_COOKIE = 2;
722:
723: int _code;
724: byte[] _data;
725: byte _ch;
726: String _string;
727: AccessLog _log;
728:
729: /**
730: * Creates a new log segment.
731: *
732: * @param log the owning log
733: * @param code the segment code, telling what kind of segment it is
734: * @param string the parameter for the segment code.
735: */
736: Segment(AccessLog log, int code, String string) {
737: _log = log;
738: _code = code;
739:
740: _string = string;
741: if (string != null) {
742: if (code == 'o'
743: && string.equalsIgnoreCase("Set-Cookie"))
744: _code = SET_COOKIE;
745:
746: _data = _string.getBytes();
747: if (code == TEXT && _string.length() == 1) {
748: _ch = (byte) _string.charAt(0);
749: _code = CHAR;
750: }
751: }
752: }
753: }
754: }
|