/*
 * RHQ Management Platform
 * Copyright (C) 2005-2008 Red Hat, Inc.
 * All rights reserved.
 *
 * This program is free software; you can redistribute it and/or modify
 * it under the terms of the GNU General Public License as published by
 * the Free Software Foundation version 2 of the License.
 *
 * This program is distributed in the hope that it will be useful,
 * but WITHOUT ANY WARRANTY; without even the implied warranty of
 * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the
 * GNU General Public License for more details.
 *
 * You should have received a copy of the GNU General Public License
 * along with this program; if not, write to the Free Software
 * Foundation, Inc., 675 Mass Ave, Cambridge, MA 02139, USA.
 */
package org.rhq.helpers.rtfilter.filter;

import java.io.BufferedWriter;
import java.io.File;
import java.io.FileWriter;
import java.io.IOException;
import java.io.InputStream;
import java.net.InetAddress;
import java.util.Properties;
import java.util.regex.Matcher;
import java.util.regex.Pattern;

import javax.servlet.Filter;
import javax.servlet.FilterChain;
import javax.servlet.FilterConfig;
import javax.servlet.ServletContext;
import javax.servlet.ServletException;
import javax.servlet.ServletRequest;
import javax.servlet.ServletResponse;
import javax.servlet.UnavailableException;
import javax.servlet.http.HttpServletRequest;

import org.apache.commons.logging.Log;
import org.apache.commons.logging.LogFactory;

import org.rhq.helpers.rtfilter.util.ServletUtility;

/**
 * A servlet filter that measures how long it takes to service each request, and logs the stats to a log file. There
 * is one log file per webapp, and one line per request. When this filter is deployed globally in Tomcat via
 * conf/web.xml, there will be one instance of this filter per deployed webapp, inserted ahead of any per-webapp filters
 * in the filter chain. We assume the same is true for other servlet containers, but Tomcat is the only servlet
 * container that has been tested.
 *
 * @author Heiko W. Rupp
 * @author Ian Springer
 */
public class RtFilter implements Filter {
    private static final String JAVA_IO_TMPDIR_SYSPROP = "java.io.tmpdir";
    private static final String JBOSSAS_SERVER_HOME_DIR_SYSPROP = "jboss.server.home.dir";
    private static final String TOMCAT_SERVER_HOME_DIR_SYSPROP = "catalina.home";

    private static final String JBOSSAS_SERVER_LOG_SUBDIR = "log";
    private static final String TOMCAT_SERVER_LOG_SUBDIR = "logs";

    private static final String DEFAULT_LOG_FILE_PREFIX = "";
    private static final long DEFAULT_FLUSH_TIMEOUT = 60L * 1000; // 1 minute
    private static final long DEFAULT_FLUSH_AFTER_LINES = 10L;
    private static final long DEFAULT_MAX_LOG_FILE_SIZE = 1024L * 1024 * 5; // 5 MB
    private static final boolean DEFAULT_CHOP_QUERY_STRING = true;

    private final Log log = LogFactory.getLog(this.getClass());

    private boolean initialized = false;
    private boolean fileDone = false;
    private long requestCount = 0;
    private boolean chopUrl = DEFAULT_CHOP_QUERY_STRING;
    private File logDirectory;
    private BufferedWriter writer;
    private Pattern dontLogPattern = null;
    private long timeBetweenFlushes = DEFAULT_FLUSH_TIMEOUT;
    private boolean matchOnUriOnly = true;
    private long flushAfterLines = DEFAULT_FLUSH_AFTER_LINES;
    private String logFilePrefix = DEFAULT_LOG_FILE_PREFIX;
    private boolean flushingNeeded = false;
    private long t2;
    private File logFile;
    private long lastLogFileSize = 0;
    private long maxLogFileSize = DEFAULT_MAX_LOG_FILE_SIZE;
    private String contextName;
    private String myHostName; // InetAddr.getHostname()
    private String myCHostName; // InetAddr.getCanonicalHostname()

    private final Object lock = new Object();
    private Properties vhostMappings = new Properties();
    private static final String HOST_TOKEN = "%HOST%";

    /**
     * Does the real magic. If a fatal exception occurs during processing, the filter will revert to an uninitialized
     * state and refuse to process any further requests (see {@link #handleFatalError(Exception)}).
     *
     * @see javax.servlet.Filter#doFilter(javax.servlet.ServletRequest, javax.servlet.ServletResponse,
     *      javax.servlet.FilterChain)
     */
    public void doFilter(ServletRequest req, ServletResponse resp, FilterChain chain) throws IOException,
        ServletException {
        long t1 = 0;
        HttpServletRequest hreq = (HttpServletRequest) req;
        RtFilterResponseWrapper hresp = new RtFilterResponseWrapper(resp);

        synchronized (lock) {
            if (this.initialized) {
                try {
                    t1 = System.currentTimeMillis();
                    this.requestCount++;
                    if ((this.requestCount > 1) && (t1 > (this.t2 + this.timeBetweenFlushes))) {
                        this.flushingNeeded = true;
                    }
                } catch (Exception e) {
                    handleFatalError(e);
                }
            }
        }

        try {
            chain.doFilter(req, hresp);
        } finally {
            synchronized (lock) {
                if (this.initialized) {
                    try {
                        this.t2 = System.currentTimeMillis();

                        int statusCode = hresp.getStatus();
                        // Only log successful requests (2xx or 3xx) since that's all we care about for now...
                        if ((statusCode < 200) || (statusCode >= 400)) {
                            return;
                        }

                        String uri = hreq.getRequestURI();
                        String url = getRequestURL(hreq);

                        // If the input matches the passed don't log regexp, then don't log the request.
                        if (this.dontLogPattern != null) {
                            Matcher matcher = this.dontLogPattern.matcher((this.matchOnUriOnly) ? uri : url);
                            if (matcher.matches()) {
                                return;
                            }
                        }

                        // If the logfile was not yet created, lets do it now.
                        // We only reach this point if the request was for a valid vhost.
                        if (!fileDone) {
                            openFile(req.getServerName());
                        }

                        truncateLogFileIfMaxSizeExceeded();

                        // If we got this far, write the request info to the log.
                        writeLogEntry(req, hresp, uri, url, t1);
                    } catch (Exception e) {
                        handleFatalError(e);
                    }
                }
            }
        }
    }

    /**
     * Open the logfile for the given serverName. If serverName is localhost, then no
     * vhost portion is added to the logfile name. Otherwise the logfile name is
     * prefix + vhost + "_" + contextRoot + "_rt.log"<br/>
     * E.g. '/devel/jboss-4.0.3SP1/server/default/log/rt/snert.home.bsd.de_test_rt.log'.
     * <br/>
     * After opening the file we open a writer where we send results to. If
     * opening fails, no exceptions are thrown, as throwing any exception would cause the associated webapp to
     * fail to deploy - not something we ever want to do. Instead, the filter will simply not try to process any
     * requests (i.e. doFilter() will call the rest of the filter chain, and then just return).
     * <p/>
     * This method will set the fileDone variable to true upon success.<br/>
     * This method will set the initialized variable to false upon failure.<br/>
     * @param serverName Name of the virtual host
     */
    private void openFile(String serverName) {
        String vhost = "";
        boolean found = false;

        if ("localhost".equals(serverName) || "127.0.0.1".equals(serverName)) {
            vhost = "";
            found = true;
        }

        // try to see if the user provided a mapping for this server name
        if (!found && vhostMappings.containsKey(serverName)) {
            found = true;
            vhost = vhostMappings.getProperty(serverName);
            if (vhost == null || vhost.equals(""))
                vhost = ""; // It is in the mapping, but no value set -> no vhost
            else
                vhost += "_"; // Otherwise take it and append the separator
            if (log.isDebugEnabled())
                log.debug("Vhost determined from mapping >" + vhost + "<");
        }

        // check server name against hostname and hostname.fqdn an see if they match
        if (!found && vhostMappings.containsKey(HOST_TOKEN)) {
            vhost = vhostMappings.getProperty(HOST_TOKEN);
            if (myHostName.startsWith(serverName) || myCHostName.startsWith(serverName)) {
                // Match, so take the mapping from the file
                if (vhost == null || vhost.equals("")) {
                    vhost = ""; // It is in the mapping, but no value set -> no vhost
                } else {
                    vhost += "_"; // Otherwise take it and append the separator
                }
                found = true;
                if (log.isDebugEnabled())
                    log.debug("Vhost determined from %HOST% token >" + vhost + "<");
            }
        }

        if (!found) {
            try {
                InetAddress localHost = InetAddress.getLocalHost();
                if (localHost.getHostName().equalsIgnoreCase(serverName)
                    || localHost.getCanonicalHostName().equalsIgnoreCase(serverName)
                    || localHost.getHostAddress().equals(serverName)) {
                    vhost = "";
                    found = true;
                }
            } catch (Exception e) {
                found = false;
            }
        }

        // Nothing found? Fall back to serverName + _ as prefix
        if (!found) {
            vhost = serverName + "_"; // Not found in mapping? Take it literal + separator
        }

        // if this is a sub-context (e.g. news/radio), then replace the / by a _ to
        // prevent interpretation of the / as a dir separator.
        String contextFileName = contextName.replace('/', '_');

        String logFileName = this.logFilePrefix + vhost + contextFileName + "_rt.log";
        this.logFile = new File(this.logDirectory, logFileName);
        log.info("-- Filter openFile: Writing response-time log for webapp with context root '" + this.contextName
            + "' to '" + this.logFile + "' (hashCode=" + hashCode() + ")...");
        boolean append = true;
        try {
            openFileWriter(append);
            fileDone = true;
        } catch (Exception e) {
            // reset the initialized flag in case of error
            this.initialized = false;
            log.warn(e.getMessage());
        }

    }

    /**
     * Read initialization parameters, and determine the context root.
     * The logfile name will be determined later, as we don't know the vhost yet.
     *
     * @see javax.servlet.Filter#init(javax.servlet.FilterConfig)
     */
    public void init(FilterConfig filterConfig) throws ServletException {
        try {
            synchronized (lock) {
                myHostName = InetAddress.getLocalHost().getHostName();
                myCHostName = InetAddress.getLocalHost().getCanonicalHostName();
                initializeParameters(filterConfig);
                ServletContext servletContext = filterConfig.getServletContext();
                this.contextName = ServletUtility.getContextRoot(servletContext);

                /*
                 * We don't open the file here, as we have no way to know the vhost this filter instance is for.
                 * Instead we mark ourselves as initialized, and try to open the file in doFilter().
                 */

                this.initialized = true;
                log.info("Initialized response-time filter for webapp with context root '" + this.contextName + "'.");
            }
        } catch (Exception e) {
            handleFatalError(e);
        }
    }

    /**
     * Cleanup when the filter gets unloaded (at webapp shutdown).
     *
     * @see javax.servlet.Filter#destroy()
     */
    public void destroy() {
        synchronized (lock) {
            log.info("-- Filter destroy: " + this.requestCount + " requests processed (hashCode=" + hashCode() + ").");
            closeFileWriter();
            this.initialized = false;
        }
    }

    private void writeLogEntry(ServletRequest req, RtFilterResponseWrapper responseWrapper, String uri, String url,
        long t1) throws Exception {
        long duration = this.t2 - t1;
        if (duration < 0) {
            log.error("Calculated response time for request to [" + url + "] (" + duration + " ms) is negative!");
            return;
        }
        if (duration == 0) {
            // Impossible - we must be on Windows, where the system clock is only accurate to about 15 ms
            // (see http://www.simongbrown.com/blog/2007/08/20/millisecond_accuracy_in_java.html).
            // NOTE: With some tweaking, it is possible to make the Windows clock accurate to millisecond precision
            // (see http://www.lochan.org/2005/keith-cl/useful/win32time.html).
            // TODO: We should explain the above in our docs.
            // Bump the duration up to 1, so at least we're not saying the request defied the laws of physics.
            duration = 1;
        }

        if (log.isDebugEnabled()) {
            log.debug("Request to [" + url + "] took " + duration + " ms");
        }

        String remoteIp = req.getRemoteAddr();

        // Format: <url> <when> <duration> <status> <IP>
        StringBuilder buf = new StringBuilder();
        buf.append((this.chopUrl) ? uri : url).append(" ").append(this.t2).append(" ").append(duration).append(" ")
            .append(responseWrapper.getStatus()).append(" ").append(remoteIp);

        // Check if log file was externally truncated before writing to it. NOTE: It's important to do this just prior
        // to writing to the file to minimize the chances of the file becoming corrupt (i.e. front-padded with NUL
        // characters).
        rewindLogFileIfSizeDecreased();
        this.writer.append(buf);
        this.writer.newLine();
        if (this.flushingNeeded || ((this.requestCount % this.flushAfterLines) == 0)) {
            this.writer.flush();
            this.flushingNeeded = false;
            this.lastLogFileSize = this.logFile.length();
        }
    }

    /**
     * Initialize parameters from the web.xml filter init-params
     *
     * @param conf the filter configuration
     */
    private void initializeParameters(FilterConfig conf) throws UnavailableException {
        String chop = conf.getInitParameter(InitParams.CHOP_QUERY_STRING);
        if (chop != null) {
            this.chopUrl = Boolean.valueOf(chop.trim()).booleanValue();
        }

        String logDirectoryPath = conf.getInitParameter(InitParams.LOG_DIRECTORY);
        if (logDirectoryPath != null) {
            this.logDirectory = new File(logDirectoryPath.trim());
        } else {
            /*
             * If this is a JBossAS deployed container, or a Standalone TC container, use a logical
             * default (so those plugins can be written in a compatible way).
             * First, try to default to "${JBOSS_SERVER_HOME_DIR_SYSPROP}/JBOSSAS_SERVER_LOG_SUBDIR/rt";
             * If not set try "${TOMCAT_SERVER_HOME_DIR_SYSPROP}/TOMCAT_SERVER_LOG_SUBDIR/rt";
             * If, for some reason, neither property is set, fall back to "${java.io.tmpdir}/rhq/rt".
             */
            File serverLogDir = null;
            String serverHomeDirPath = System.getProperty(JBOSSAS_SERVER_HOME_DIR_SYSPROP);

            if (null != serverHomeDirPath) {
                serverLogDir = new File(serverHomeDirPath, JBOSSAS_SERVER_LOG_SUBDIR);
            } else {
                serverHomeDirPath = System.getProperty(TOMCAT_SERVER_HOME_DIR_SYSPROP);
                if (serverHomeDirPath != null) {
                    serverLogDir = new File(serverHomeDirPath, TOMCAT_SERVER_LOG_SUBDIR);
                }
            }

            if (null != serverLogDir) {
                this.logDirectory = new File(serverLogDir, "rt");
            } else {
                this.logDirectory = new File(System.getProperty(JAVA_IO_TMPDIR_SYSPROP), "rhq/rt");
                log
                    .warn("The 'logDirectory' filter init param was not set. Also, the standard system properties were not set ("
                        + JBOSSAS_SERVER_HOME_DIR_SYSPROP
                        + ", "
                        + TOMCAT_SERVER_HOME_DIR_SYSPROP
                        + "); defaulting RT log directory to '" + this.logDirectory + "'.");
            }
        }

        if (this.logDirectory.exists()) {
            if (!this.logDirectory.isDirectory()) {
                throw new UnavailableException("Log directory '" + this.logDirectory
                    + "' exists but is not a directory.");
            }
        } else {
            try {
                this.logDirectory.mkdirs();
            } catch (Exception e) {
                throw new UnavailableException("Unable to create log directory '" + this.logDirectory + "' - cause: "
                    + e);
            }

            if (!logDirectory.exists()) {
                throw new UnavailableException("Unable to create log directory '" + this.logDirectory + "'.");
            }
        }

        String logFilePrefixString = conf.getInitParameter(InitParams.LOG_FILE_PREFIX);
        if (logFilePrefixString != null) {
            this.logFilePrefix = logFilePrefixString.trim();
        }

        String dontLog = conf.getInitParameter(InitParams.DONT_LOG_REG_EX);
        if (dontLog != null) {
            this.dontLogPattern = Pattern.compile(dontLog.trim());
        }

        String flushTimeout = conf.getInitParameter(InitParams.TIME_BETWEEN_FLUSHES_IN_SEC);
        if (flushTimeout != null) {
            try {
                timeBetweenFlushes = Long.parseLong(flushTimeout.trim()) * 1000;
            } catch (NumberFormatException nfe) {
                timeBetweenFlushes = DEFAULT_FLUSH_TIMEOUT;
            }
        }

        String uriOnly = conf.getInitParameter(InitParams.MATCH_ON_URI_ONLY);
        if (uriOnly != null) {
            matchOnUriOnly = Boolean.getBoolean(uriOnly.trim());
        }

        String lines = conf.getInitParameter(InitParams.FLUSH_AFTER_LINES);
        if (lines != null) {
            try {
                flushAfterLines = Long.parseLong(lines.trim());
                if (flushAfterLines <= 0) {
                    throw new NumberFormatException();
                }
            } catch (NumberFormatException nfe) {
                log.error("Invalid '" + InitParams.FLUSH_AFTER_LINES + "' init parameter: " + lines
                    + " (value must be a positive integer) - using default.");
                flushAfterLines = DEFAULT_FLUSH_AFTER_LINES;
            }
        }

        String maxLogFileSizeString = conf.getInitParameter(InitParams.MAX_LOG_FILE_SIZE);
        if (maxLogFileSizeString != null) {
            try {
                this.maxLogFileSize = Long.parseLong(maxLogFileSizeString.trim());
                if (this.maxLogFileSize <= 0) {
                    throw new NumberFormatException();
                }
            } catch (NumberFormatException e) {
                log.error("Invalid '" + InitParams.MAX_LOG_FILE_SIZE + "' init parameter: " + maxLogFileSizeString
                    + " (value must be a positive integer) - using default.");
                this.maxLogFileSize = DEFAULT_MAX_LOG_FILE_SIZE;
            }
        }

        /*
         * Read mappings from a vhost mapping file in the format of a properties file
         * inputhost = mapped host
         * This file needs to live in the search path - e.g. in server/<config>/conf/
         * The name of it must be passed as init-param to the filter. Otherwise the mapping
         * will not be used.
         *  <param-name>vHostMappingFile</param-name>
         */
        String vhostMappingFileString = conf.getInitParameter(InitParams.VHOST_MAPPING_FILE);
        if (vhostMappingFileString != null) {
            InputStream stream = getClass().getClassLoader().getResourceAsStream(vhostMappingFileString);
            if (stream != null) {
                try {
                    vhostMappings.load(stream);
                } catch (IOException e) {
                    log.warn("Can't read vhost mappings from " + vhostMappingFileString + " :" + e.getMessage());
                } finally {
                    if (stream != null)
                        try {
                            stream.close();
                        } catch (Exception e) {
                            log.debug(e);
                        }
                }
            } else {
                log.warn("Can't read vhost mappings from " + vhostMappingFileString);
            }
        }
    }

    /**
     * Open a BufferedWriter that can be used to write the log lines.
     *
     * @param append if true, append to the end of the file; if false, truncate the file and write from the beginning
     *
     * @throws Exception if the logfile cannot be opened for writing
     */
    private void openFileWriter(boolean append) throws Exception {
        // Check if the file exists. If not, attempt to create it.
        if (!this.logFile.exists()) {
            boolean success;
            try {
                success = this.logFile.createNewFile();
            } catch (Exception e) {
                throw new Exception("Response time log '" + this.logFile + "' could not be created - cause: " + e);
            }

            if (!success) {
                throw new Exception("Response time log '" + this.logFile + "' could not be created.");
            }
        }

        // File now exists - check if we can write it.
        if (!this.logFile.canWrite()) {
            throw new Exception("Response time log '" + this.logFile + "' is not writable.");
        }

        // File is writable - open it for writing.
        try {
            this.writer = new BufferedWriter(new FileWriter(this.logFile, append));
        } catch (IOException e) {
            throw new Exception("Failed to open response time log '" + this.logFile + "' for writing - cause: " + e);
        }

        this.lastLogFileSize = this.logFile.length();
    }

    private void closeFileWriter() {
        if (this.writer != null) {
            try {
                this.writer.close();
                log.debug("Closed writer for response time log '" + this.logFile + "'.");
            } catch (IOException e) {
                log.error("Failed to close writer for response time log '" + this.logFile + "'.");
            }
        }
    }

    private void truncateLogFileIfMaxSizeExceeded() throws Exception {
        if (this.logFile.length() > this.maxLogFileSize) {
            log.warn("Response time log '" + this.logFile + "' has exceeded maximum file size (" + this.maxLogFileSize
                + " bytes) - truncating it...");
            closeFileWriter();
            boolean append = false;
            openFileWriter(append);
        }
    }

    /**
     * Check if the logfile has been truncated by an external process and rewind to its start.
     *
     * @throws Exception if the file cannot be rewound for any reason
     */
    private void rewindLogFileIfSizeDecreased() throws Exception {
        if (this.logFile.length() < this.lastLogFileSize) {
            if (log.isDebugEnabled()) {
                log.debug("Logfile " + this.logFile
                    + " has been truncated (probably by RHQ Agent) - rewinding writer...");
            }
            closeFileWriter();
            boolean append = true;
            openFileWriter(append);
        }
    }

    private static String getRequestURL(HttpServletRequest hreq) {
        String queryString = hreq.getQueryString();
        String url = hreq.getRequestURI();
        if (queryString != null) {
            url += "?" + queryString;
        }
        return url;
    }

    private void handleFatalError(Exception e) {
        this.initialized = false;
        log.fatal(
            "RHQ response-time filter experienced an unrecoverable failure. Response-time collection is now disabled for context '"
                + this.contextName + "'.", e);
    }

    abstract class InitParams {
        public static final String CHOP_QUERY_STRING = "chopQueryString";
        public static final String LOG_DIRECTORY = "logDirectory";
        public static final String LOG_FILE_PREFIX = "logFilePrefix";
        public static final String DONT_LOG_REG_EX = "dontLogRegEx";
        public static final String TIME_BETWEEN_FLUSHES_IN_SEC = "timeBetweenFlushesInSec";
        public static final String MATCH_ON_URI_ONLY = "matchOnUriOnly";
        public static final String FLUSH_AFTER_LINES = "flushAfterLines";
        public static final String MAX_LOG_FILE_SIZE = "maxLogFileSize";
        public static final String VHOST_MAPPING_FILE = "vHostMappingFile";
    }
}
