AuditorImpl.java 17.6 KB
Newer Older
1 2 3 4 5
/**
 * $RCSfile$
 * $Revision: 3186 $
 * $Date: 2005-12-11 00:07:52 -0300 (Sun, 11 Dec 2005) $
 *
6
 * Copyright (C) 2005-2008 Jive Software. All rights reserved.
7
 *
8 9 10 11 12 13 14 15 16 17 18
 * Licensed under the Apache License, Version 2.0 (the "License");
 * you may not use this file except in compliance with the License.
 * You may obtain a copy of the License at
 *
 *     http://www.apache.org/licenses/LICENSE-2.0
 *
 * Unless required by applicable law or agreed to in writing, software
 * distributed under the License is distributed on an "AS IS" BASIS,
 * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
 * See the License for the specific language governing permissions and
 * limitations under the License.
19 20
 */

21
package org.jivesoftware.openfire.audit.spi;
22

23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42
import java.io.BufferedWriter;
import java.io.File;
import java.io.FileOutputStream;
import java.io.FilenameFilter;
import java.io.IOException;
import java.io.OutputStreamWriter;
import java.io.Writer;
import java.util.ArrayList;
import java.util.Arrays;
import java.util.Calendar;
import java.util.Collections;
import java.util.Comparator;
import java.util.Date;
import java.util.List;
import java.util.TimeZone;
import java.util.Timer;
import java.util.TimerTask;
import java.util.concurrent.BlockingQueue;
import java.util.concurrent.LinkedBlockingQueue;

43 44
import org.dom4j.DocumentFactory;
import org.dom4j.Element;
45 46 47
import org.jivesoftware.openfire.audit.AuditManager;
import org.jivesoftware.openfire.audit.Auditor;
import org.jivesoftware.openfire.session.Session;
48 49 50 51 52 53
import org.jivesoftware.util.FastDateFormat;
import org.jivesoftware.util.JiveGlobals;
import org.jivesoftware.util.LocaleUtils;
import org.jivesoftware.util.StringUtils;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
54 55 56 57 58 59 60
import org.xmpp.packet.IQ;
import org.xmpp.packet.Message;
import org.xmpp.packet.Packet;
import org.xmpp.packet.Presence;

public class AuditorImpl implements Auditor {

61 62
	private static final Logger Log = LoggerFactory.getLogger(AuditorImpl.class);

63 64 65 66
    private AuditManager auditManager;
    private File currentAuditFile;
    private Writer writer;
    private org.jivesoftware.util.XMLWriter xmlWriter;
67 68 69 70 71 72 73 74 75
    /**
     * Limit date used to detect when we need to rollover files. This date will be
     * configured as the last second of the day.
     */
    private Date currentDateLimit;
    /**
     * Max size in bytes that all audit log files may have. When the limit is reached
     * oldest audit log files will be removed until total size is under the limit.
     */
76
    private long maxTotalSize;
77 78 79 80
    /**
     * Max size in bytes that each audit log file may have. Once the limit has been
     * reached a new audit file will be created.
     */
81
    private long maxFileSize;
82 83 84 85 86 87 88 89
    /**
     * Max number of days to keep audit information. Once the limit has been reached
     * audit files that contain information that exceed the limit will be deleted.
     */
    private int maxDays;
    /**
     * Flag that indicates if packets can still be accepted to be saved to the audit log.
     */
90 91 92 93 94
    private boolean closed = false;
    /**
     * Directoty (absolute path) where the audit files will be saved.
     */
    private String logDir;
95 96 97 98
    /**
     * File (or better say directory) of the folder that contains the audit logs.
     */
    private File baseFolder;
99 100 101 102

    /**
     * Queue that holds the audited packets that will be later saved to an XML file.
     */
103
    private BlockingQueue<AuditPacket> logQueue = new LinkedBlockingQueue<AuditPacket>();
104

105 106 107 108 109 110 111 112
    /**
     * Allow only a limited number of files for each day, max. three digits (000-999)
     */
    private final int maxTotalFilesDay = 1000;
    /**
     * Track the current index number `...-nnn.log´
     */
    private int filesIndex = 0;
113 114 115 116 117
    /**
     * Timer to save queued logs to the XML file.
     */
    private Timer timer = new Timer("Auditor");
    private SaveQueuedPacketsTask saveQueuedPacketsTask;
118
    private FastDateFormat dateFormat;
119
    private static FastDateFormat auditFormat;
120 121 122

    public AuditorImpl(AuditManager manager) {
        auditManager = manager;
123
        dateFormat = FastDateFormat.getInstance("yyyyMMdd", TimeZone.getTimeZone("UTC"));
124
        auditFormat = FastDateFormat.getInstance("MMM dd, yyyy hh:mm:ss:SSS a", JiveGlobals.getLocale());
125 126 127
    }

    protected void setMaxValues(int totalSize, int fileSize, int days) {
128 129
        maxTotalSize = (long) totalSize * 1024l * 1024l;
        maxFileSize = (long) fileSize * 1024l * 1024l;
130 131 132 133 134 135 136 137 138 139 140 141 142 143 144 145 146 147 148 149 150 151 152 153 154 155
        maxDays = days;
    }

    public void setLogTimeout(int logTimeout) {
        // Cancel any existing task because the timeout has changed
        if (saveQueuedPacketsTask != null) {
            saveQueuedPacketsTask.cancel();
        }
        // Create a new task and schedule it with the new timeout
        saveQueuedPacketsTask = new SaveQueuedPacketsTask();
        timer.schedule(saveQueuedPacketsTask, logTimeout, logTimeout);

    }

    public void setLogDir(String logDir) {
        this.logDir = logDir;
        // Create and catch file of the base folder that will contain audit files
        baseFolder = new File(logDir);
        // Create the folder if it does not exist
        if (!baseFolder.exists()) {
            baseFolder.mkdir();
        }
    }

    public int getQueuedPacketsNumber() {
        return logQueue.size();
156 157 158 159 160 161 162 163 164 165 166 167 168 169 170 171 172 173 174 175 176 177
    }

    public void audit(Packet packet, Session session) {
        if (auditManager.isEnabled()) {
            if (packet instanceof Message) {
                if (auditManager.isAuditMessage()) {
                    writePacket(packet, session);
                }
            }
            else if (packet instanceof Presence) {
                if (auditManager.isAuditPresence()) {
                    writePacket(packet, session);
                }
            }
            else if (packet instanceof IQ) {
                if (auditManager.isAuditIQ()) {
                    writePacket(packet, session);
                }
            }
        }
    }

178 179 180 181 182 183 184
    private void writePacket(Packet packet, Session session) {
        if (!closed) {
            // Add to the logging queue this new entry that will be saved later
            logQueue.add(new AuditPacket(packet.createCopy(), session));
        }
    }

185
    public void stop() {
186 187
        // Stop queuing packets since we are being stopped
        closed = true;
188 189 190 191 192 193 194 195 196 197 198 199 200 201
        // Stop the scheduled task for saving queued packets to the XML file
        timer.cancel();
        // Save all remaining queued packets to the XML file
        saveQueuedPackets();
        close();
    }

    private void close() {
        if (xmlWriter != null) {
            try {
                xmlWriter.flush();
                writer.write("</jive>");
                xmlWriter.close();
                writer = null;
202
                xmlWriter = null;
203 204 205 206 207 208 209
            }
            catch (Exception e) {
                Log.error(LocaleUtils.getLocalizedString("admin.error"), e);
            }
        }
    }

210 211
    private void prepareAuditFile(Date auditDate) throws IOException {
        ensureMaxTotalSize();
212

213 214 215 216 217
        // Rotate file if: we just started, current file size exceeded limit or date has changed
        if (currentAuditFile == null || currentAuditFile.length() > maxFileSize ||
                xmlWriter == null || currentDateLimit == null || auditDate.after(currentDateLimit))
        {
            createAuditFile(auditDate);
218 219 220
        }
    }

221 222 223 224 225 226 227 228 229 230 231 232 233 234 235 236 237 238 239 240 241
    /**
     * Ensures that max total size limit is not exceeded. If total size of audit files
     * exceed the limit then oldest audit files will be removed until total size does
     * not exceed limit.
     */
    private void ensureMaxTotalSize() {
        // Get list of existing audit files
        FilenameFilter filter = new FilenameFilter() {
            public boolean accept(File dir, String name) {
                return name.startsWith("jive.audit-") && name.endsWith(".log");
            }
        };
        File[] files = baseFolder.listFiles(filter);
        long totalLength = 0;
        for (File file : files) {
            totalLength = totalLength + file.length();
        }
        // Check if total size has been exceeded
        if (totalLength > maxTotalSize) {
            // Sort files by name (chronological order)
            List<File> sortedFiles = new ArrayList<File>(Arrays.asList(files));
242 243 244
            Collections.sort(sortedFiles, new Comparator<File>() {
                public int compare(File o1, File o2) {
                    return o1.getName().compareTo(o2.getName());
245 246 247 248 249 250 251 252 253 254 255 256 257 258
                }
            });
            // Delete as many old files as required to be under the limit
            while (totalLength > maxTotalSize && !sortedFiles.isEmpty()) {
                File fileToDelete = sortedFiles.remove(0);
                totalLength = totalLength - fileToDelete.length();
                if (fileToDelete.equals(currentAuditFile)) {
                    // Close current file
                    close();
                }
                // Delete oldest file
                fileToDelete.delete();
            }
        }
259 260
    }

261 262 263 264 265 266 267
    /**
     * Deletes old audit files that exceeded the max number of days limit.
     */
    private void ensureMaxDays() {
        if (maxDays == -1) {
            // Do nothing since we don't have any limit
            return;
268 269
        }

270 271 272
        // Set limit date after which we need to delete old audit files
        Calendar calendar = Calendar.getInstance();
        calendar.add(Calendar.DATE, maxDays * -1);
273

274 275
        final String oldestFile =
                "jive.audit-" + dateFormat.format(calendar.getTime()) + "-000.log";
276

277 278 279 280 281 282 283 284 285 286 287 288 289 290 291 292
        // Get list of audit files to delete
        FilenameFilter filter = new FilenameFilter() {
            public boolean accept(File dir, String name) {
                return name.startsWith("jive.audit-") && name.endsWith(".log") &&
                        name.compareTo(oldestFile) < 0;
            }
        };
        File[] files = baseFolder.listFiles(filter);
        // Delete old audit files
        for (File fileToDelete : files) {
            if (fileToDelete.equals(currentAuditFile)) {
                // Close current file
                close();
            }
            fileToDelete.delete();
        }
293 294
    }

295 296 297 298 299 300 301 302 303 304 305 306 307 308 309 310 311 312 313 314 315 316 317 318 319 320 321 322 323 324 325 326 327 328 329 330 331 332 333 334 335 336 337 338 339 340 341 342 343 344 345 346 347 348 349 350 351 352 353 354 355
	/* if this new logic still causes problems one may want to 
	* use log4j or change the file format from YYYYmmdd-nnn to YYYYmmdd-HHMM */
	/**
	* Sets <b>xmlWriter</b> so this class can use it to write audit logs<br>
	* The audit filename <b>currentAuditFile</b> will be `jive.audit-YYYYmmdd-nnn.log´<br>
	* `nnn´ will be reset to `000´ when a new log file is created the next day <br>
	* `nnn´ will be increased for log files which belong to the same day<br>
	* <b>WARNING:</b> If log files of the current day are deleted and the server is restarted then
	* the value of `nnn´ may be random (it's calculated by `Math.max(files.length, filesIndex);´
	* with `filesIndex=0´ and  `files.length=nr(existing jive.audit-YYYYmmdd-???.log files)´ - 
	* if there are 10 audit files (033-043) then nnn will be 10 instead of 44).<br>
	* If  `nnn=999´ then all audit data will be written to this file till the next day.<br>
	* @param auditDate
	* @throws IOException
	*/
	private void createAuditFile(Date auditDate) throws IOException {
		final String filePrefix = "jive.audit-" + dateFormat.format(auditDate) + "-";
		if (currentDateLimit == null || auditDate.after(currentDateLimit)) {
   		// Set limit date after which we need to rollover the audit file (based on the date)
   		Calendar calendar = Calendar.getInstance();
   		calendar.setTime(auditDate);
   		calendar.set(Calendar.HOUR, 23);
   		calendar.set(Calendar.MINUTE, 59);
   		calendar.set(Calendar.SECOND, 59);
   		calendar.set(Calendar.MILLISECOND, 999);
   		currentDateLimit = calendar.getTime();
   		filesIndex = 0;
   	}
   	// Get list of existing audit files
   	FilenameFilter filter = new FilenameFilter() {
   		public boolean accept(File dir, String name) {
   			return name.startsWith(filePrefix) && name.endsWith(".log");
   		}
   	};
   	File[] files = baseFolder.listFiles(filter);
   	// if some daily files were already deleted then files.length will be smaller than filesIndex
   	// see also WARNING above
   	filesIndex = Math.max(files.length, filesIndex);
		if (filesIndex >= maxTotalFilesDay)
		{
			// don't close this file, continue auditing to it
			return;
		}
		File tmpAuditFile = new File(logDir, filePrefix + StringUtils.zeroPadString(Integer.toString(filesIndex), 3) + ".log");
		if ( (filesIndex == maxTotalFilesDay-1) && !tmpAuditFile.exists() ) 
		{
			Log.warn("Creating last audit file for this date: " + dateFormat.format(auditDate));
		}
		while ( (filesIndex<(maxTotalFilesDay-1)) && (tmpAuditFile.exists()) )
		{
			Log.debug("Audit file '"+ tmpAuditFile.getName() +"' does already exist.");
			filesIndex++;
			tmpAuditFile = new File(logDir, filePrefix + StringUtils.zeroPadString(Integer.toString(filesIndex), 3) + ".log");
		}
		currentAuditFile = tmpAuditFile;
		close();
		// always append to an existing file (after restart)
		writer = new BufferedWriter(new OutputStreamWriter(new FileOutputStream(currentAuditFile, true), "UTF-8"));
		writer.write("<jive xmlns=\"http://www.jivesoftware.org\">");
		xmlWriter = new org.jivesoftware.util.XMLWriter(writer);
	}
356 357

    /**
358
     * Saves the queued entries to an XML file and checks that very old files are deleted.
359 360
     */
    private class SaveQueuedPacketsTask extends TimerTask {
361 362
        @Override
		public void run() {
363
            try {
364 365 366
                // Ensure that saved audit logs are not too old
                ensureMaxDays();
                // Save queued packets to the audit logs
367 368 369 370 371 372 373 374 375
                saveQueuedPackets();
            }
            catch (Throwable e) {
                Log.error(LocaleUtils.getLocalizedString("admin.error"), e);
            }
        }
    }

    private void saveQueuedPackets() {
376 377 378 379
        List<AuditPacket> packets = new ArrayList<AuditPacket>(logQueue.size());
        logQueue.drainTo(packets);
        for (AuditPacket auditPacket : packets) {
            try {
380
                prepareAuditFile(auditPacket.getCreationDate());
381 382 383 384
                Element element = auditPacket.getElement();
                // Protect against null elements.
                if (element != null) {
                    xmlWriter.write(element);
385
                }
386 387 388 389 390
            }
            catch (IOException e) {
                Log.error(LocaleUtils.getLocalizedString("admin.error"), e);
                // Add again the entry to the queue to save it later
                if (xmlWriter != null) {
391 392 393 394 395 396 397 398 399 400
                    logQueue.add(auditPacket);
                }
            }
        }
        try {
            if (xmlWriter != null) {
                xmlWriter.flush();
            }
        }
        catch (IOException ioe) {
401
            Log.error(ioe.getMessage(), ioe);
402 403 404 405 406 407 408 409 410 411 412 413 414 415 416
        }
    }

    /**
     * Wrapper on a Packet with information about the packet's status at the moment
     * when the message was queued.<p>
     *
     * The idea is to wrap every packet that is needed to be audited and then add the
     * wrapper to a queue that will be later processed (i.e. saved to the XML file).
     */
    private static class AuditPacket {

        private static DocumentFactory docFactory = DocumentFactory.getInstance();

        private Element element;
417
        private Date creationDate;
418 419 420

        public AuditPacket(Packet packet, Session session) {
            element = docFactory.createElement("packet", "http://www.jivesoftware.org");
421
            creationDate = new Date();
422
            if (session != null && session.getStreamID() != null) {
423 424
                element.addAttribute("streamID", session.getStreamID().toString());
            }
425
            switch (session == null ? 0 : session.getStatus()) {
426 427 428 429 430 431 432 433 434 435 436 437 438 439 440 441 442 443
                case Session.STATUS_AUTHENTICATED:
                    element.addAttribute("status", "auth");
                    break;
                case Session.STATUS_CLOSED:
                    element.addAttribute("status", "closed");
                    break;
                case Session.STATUS_CONNECTED:
                    element.addAttribute("status", "connected");
                    // This is a workaround. Since we don't want to have an incorrect FROM attribute
                    // value we need to clean up the FROM attribute. The FROM attribute will contain
                    // an incorrect value since we are setting a fake JID until the user actually
                    // authenticates with the server.
                    packet.setFrom((String) null);
                    break;
                default:
                    element.addAttribute("status", "unknown");
                    break;
            }
444
            element.addAttribute("timestamp", auditFormat.format(creationDate));
445 446 447 448 449 450 451 452 453 454 455
            element.add(packet.getElement());
        }

        /**
         * Returns the Element associated with this audit packet.
         *
         * @return the Element.
         */
        public Element getElement() {
            return element;
        }
456 457 458 459 460 461 462 463 464 465

        /**
         * Returns the date when the packet was audited. This is the time when the
         * packet was queued to be saved.
         *
         * @return the date when the packet was audited.
         */
        public Date getCreationDate() {
            return creationDate;
        }
466 467
    }
}