tomcat-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From ma...@apache.org
Subject svn commit: r1212095 - in /tomcat/trunk: java/org/apache/juli/logging/DirectJDKLog.java java/org/apache/juli/logging/UserDataHelper.java java/org/apache/tomcat/util/http/Cookies.java webapps/docs/config/systemprops.xml
Date Thu, 08 Dec 2011 20:33:57 GMT
Author: markt
Date: Thu Dec  8 20:33:56 2011
New Revision: 1212095

URL: http://svn.apache.org/viewvc?rev=1212095&view=rev
Log:
Fix https://issues.apache.org/bugzilla/show_bug.cgi?id=52184
Add a helper class that provides options (via system properties) for controlling how errors
triggered by invalid input data are handled.
Currently only addresses invalid cookies but can be used elsewhere as the need arises.

Added:
    tomcat/trunk/java/org/apache/juli/logging/UserDataHelper.java
Modified:
    tomcat/trunk/java/org/apache/juli/logging/DirectJDKLog.java
    tomcat/trunk/java/org/apache/tomcat/util/http/Cookies.java
    tomcat/trunk/webapps/docs/config/systemprops.xml

Modified: tomcat/trunk/java/org/apache/juli/logging/DirectJDKLog.java
URL: http://svn.apache.org/viewvc/tomcat/trunk/java/org/apache/juli/logging/DirectJDKLog.java?rev=1212095&r1=1212094&r2=1212095&view=diff
==============================================================================
--- tomcat/trunk/java/org/apache/juli/logging/DirectJDKLog.java (original)
+++ tomcat/trunk/java/org/apache/juli/logging/DirectJDKLog.java Thu Dec  8 20:33:56 2011
@@ -172,13 +172,26 @@ class DirectJDKLog implements Log {
             Throwable dummyException=new Throwable();
             StackTraceElement locations[]=dummyException.getStackTrace();
             // Caller will be the third element (or later if logger is wrapped)
-            String cname = "unknown";
-            String method = "unknown";
-            if (locations != null && locations.length >2) {
-                StackTraceElement caller=locations[2];
-                cname=caller.getClassName();
-                method=caller.getMethodName();
+            String cname = null;
+            String method = null;
+            if (locations != null) {
+                int i = 2;
+                while (locations.length > i) {
+                    StackTraceElement caller = locations[i];
+                    if (caller.getClassName().startsWith("org.apache.juli")) {
+                        i++;
+                    } else {
+                        cname = caller.getClassName();
+                        method = caller.getMethodName();
+                        break;
+                    }
+                }
             }
+            if (cname == null) {
+                cname = "unknown";
+                method = "unknown";
+            }
+
             if (ex==null) {
                 logger.logp(level, cname, method, msg);
             } else {

Added: tomcat/trunk/java/org/apache/juli/logging/UserDataHelper.java
URL: http://svn.apache.org/viewvc/tomcat/trunk/java/org/apache/juli/logging/UserDataHelper.java?rev=1212095&view=auto
==============================================================================
--- tomcat/trunk/java/org/apache/juli/logging/UserDataHelper.java (added)
+++ tomcat/trunk/java/org/apache/juli/logging/UserDataHelper.java Thu Dec  8 20:33:56 2011
@@ -0,0 +1,160 @@
+/*
+ * Licensed to the Apache Software Foundation (ASF) under one or more
+ * contributor license agreements.  See the NOTICE file distributed with
+ * this work for additional information regarding copyright ownership.
+ * The ASF licenses this file to You 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.
+ */
+package org.apache.juli.logging;
+
+/**
+ * This helper class assists with the logging associated with invalid input
+ * data. A developer may want all instances of invalid input data logged to
+ * assist with debugging whereas in production it is likely to be desirable not
+ * to log anything for invalid data. The following settings may be used:
+ * <ul>
+ * <li>NOTHING: Log nothing.</li>
+ * <li>DEBUG_ALL: Log all problems at DEBUG log level.</li>
+ * <li>INFO_THEN_DEBUG: Log first problem at INFO log level and any further
+ *     issues in the following TBD (configurable) seconds at DEBUG level</li>
+ * <li>INFO_ALL: Log all problems at INFO log level.</li>
+ * </ul>
+ * By default, INFO_THEN_DEBUG is used with a suppression time of 24 hours.
+ *
+ * NOTE: This class is not completely thread-safe. When using INFO_THEN_DEBUG it
+ * is possible that several INFO messages will be logged before dropping to
+ * DEBUG.
+ */
+public class UserDataHelper {
+
+    private final Log log;
+
+    private Config config;
+
+    // A value of 0 is equivalent to using INFO_ALL
+    // A negative value will trigger infinite suppression
+    private long suppressionTime;
+
+    private volatile long lastInfoTime = 0;
+
+
+    public UserDataHelper(Log log) {
+        this.log = log;
+
+        String configString = System.getProperty(
+                "org.apache.juli.logging.UserDataHelper.CONFIG");
+        if (configString == null) {
+            config = Config.INFO_THEN_DEBUG;
+        } else {
+            try {
+                config = Config.valueOf(configString);
+            } catch (IllegalArgumentException iae) {
+                // Ignore - use default
+                config = Config.INFO_THEN_DEBUG;
+            }
+        }
+
+        // Default suppression time of 1 day.
+        suppressionTime = Long.getLong(
+                "org.apache.juli.logging.UserDataHelper.SUPPRESSION_TIME",
+                60 * 60 * 24).longValue();
+
+        if (suppressionTime == 0) {
+            config = Config.INFO_ALL;
+        }
+    }
+
+
+    public boolean isEnabled() {
+        if (Config.NONE == config) {
+            return false;
+        } else if (Config.DEBUG_ALL == config) {
+            return log.isDebugEnabled();
+        } else if (Config.INFO_THEN_DEBUG == config) {
+            if (logAtInfo(false)) {
+                return log.isInfoEnabled();
+            } else {
+                return log.isDebugEnabled();
+            }
+        } else if (Config.INFO_ALL == config) {
+            return log.isInfoEnabled();
+        }
+        // Should never happen
+        return false;
+    }
+
+
+    public void log(String message) {
+        if (Config.NONE == config) {
+            // NOOP;
+        } else if (Config.DEBUG_ALL == config) {
+            log.debug(message);
+        } else if (Config.INFO_THEN_DEBUG == config) {
+            if (logAtInfo(true)) {
+                log.info(message);
+            } else {
+                log.debug(message);
+            }
+        } else if (Config.INFO_ALL == config) {
+            log.info(message);
+        }
+    }
+
+
+    public void log(String message, Throwable t) {
+        if (Config.NONE == config) {
+            // NOOP;
+        } else if (Config.DEBUG_ALL == config) {
+            log.debug(message, t);
+        } else if (Config.INFO_THEN_DEBUG == config) {
+            if (logAtInfo(true)) {
+                log.info(message, t);
+            } else {
+                log.debug(message, t);
+            }
+        } else if (Config.INFO_ALL == config) {
+            log.info(message, t);
+        }
+    }
+
+
+    /*
+     * Not completely thread-safe but good enough for this use case. I couldn't
+     * see a simple enough way to make it completely thread-safe that was not
+     * likely to compromise performance.
+     */
+    private boolean logAtInfo(boolean updateLastLoggedTime) {
+
+        if (suppressionTime < 0 && lastInfoTime > 0) {
+            return false;
+        }
+
+        long now = System.currentTimeMillis();
+
+        if (lastInfoTime + suppressionTime > now) {
+            return false;
+        }
+
+        if (updateLastLoggedTime) {
+            lastInfoTime = now;
+        }
+        return true;
+    }
+
+
+    private static enum Config {
+        NONE,
+        DEBUG_ALL,
+        INFO_THEN_DEBUG,
+        INFO_ALL
+    }
+}

Modified: tomcat/trunk/java/org/apache/tomcat/util/http/Cookies.java
URL: http://svn.apache.org/viewvc/tomcat/trunk/java/org/apache/tomcat/util/http/Cookies.java?rev=1212095&r1=1212094&r2=1212095&view=diff
==============================================================================
--- tomcat/trunk/java/org/apache/tomcat/util/http/Cookies.java (original)
+++ tomcat/trunk/java/org/apache/tomcat/util/http/Cookies.java Thu Dec  8 20:33:56 2011
@@ -19,6 +19,9 @@ package org.apache.tomcat.util.http;
 import java.io.PrintWriter;
 import java.io.StringWriter;
 
+import org.apache.juli.logging.Log;
+import org.apache.juli.logging.LogFactory;
+import org.apache.juli.logging.UserDataHelper;
 import org.apache.tomcat.util.buf.ByteChunk;
 import org.apache.tomcat.util.buf.MessageBytes;
 
@@ -33,8 +36,9 @@ import org.apache.tomcat.util.buf.Messag
  */
 public final class Cookies {
 
-    private static final org.apache.juli.logging.Log log =
-        org.apache.juli.logging.LogFactory.getLog(Cookies.class );
+    private static final Log log = LogFactory.getLog(Cookies.class);
+
+    private static final UserDataHelper userDataLog = new UserDataHelper(log);
 
     // expected average number of cookies per request
     public static final int INITIAL_SIZE=4;
@@ -346,8 +350,10 @@ public final class Cookies {
                         // INVALID COOKIE, advance to next delimiter
                         // The starting character of the cookie value was
                         // not valid.
-                        log.info("Cookies: Invalid cookie. " +
-                                "Value not a token or quoted value");
+                        if (userDataLog.isEnabled()) {
+                            userDataLog.log("Cookies: Invalid cookie. " +
+                                    "Value not a token or quoted value");
+                        }
                         while (pos < end && bytes[pos] != ';' &&
                                bytes[pos] != ',')
                             {pos++; }
@@ -428,8 +434,9 @@ public final class Cookies {
                 }
 
                 // Unknown cookie, complain
-                log.info("Cookies: Unknown Special Cookie");
-
+                if (userDataLog.isEnabled()) {
+                    userDataLog.log("Cookies: Unknown Special Cookie");
+                }
             } else { // Normal Cookie
                 if (valueStart == -1 && !CookieSupport.ALLOW_NAME_ONLY) {
                     // Skip name only cookies if not supported

Modified: tomcat/trunk/webapps/docs/config/systemprops.xml
URL: http://svn.apache.org/viewvc/tomcat/trunk/webapps/docs/config/systemprops.xml?rev=1212095&r1=1212094&r2=1212095&view=diff
==============================================================================
--- tomcat/trunk/webapps/docs/config/systemprops.xml (original)
+++ tomcat/trunk/webapps/docs/config/systemprops.xml Thu Dec  8 20:33:56 2011
@@ -459,6 +459,7 @@
          To simply override the console output formatter, one can use the described property.
Example:
          <code>-Dorg.apache.juli.formatter=org.apache.juli.OneLineFormatter</code></p>
     </property>
+
     <property name="org.apache.juli.AsyncOverflowDropType">
       <p>When the memory limit of records has been reached the system needs to determine
what action to take.
          Currently there are three actions that can be taken:
@@ -487,6 +488,35 @@
       <p>The default value is <code>1000</code> milliseconds.</p>
     </property>
 
+    <property name="org.apache.juli.logging.UserDataHelper.CONFIG">
+      <p>The type of logging to use for errors generated by invalid input data.
+         The options are: <code>DEBUG_ALL</code>, <code>INFO_THEN_DEBUG</code>,
+         <code>INFO_ALL</code> and <code>NONE</code>. When
+         <code>INFO_THEN_DEBUG</code> is used, the period for which errors are
+         logged at DEBUG rather than INFO is controlled by the system property
+         <code>org.apache.juli.logging.UserDataHelper.SUPPRESSION_TIME</code>.
+         </p>
+      <p>The default value is <code>INFO_THEN_DEBUG</code>.</p>
+      <p>The errors currently logged using this system are:
+         <ul>
+         <li>invalid cookies.</li>
+         </ul>
+         Other errors triggered by invalid input data may be added to this
+         system in later versions.</p>
+    </property>
+
+    <property name="org.apache.juli.logging.UserDataHelper.SUPPRESSION_TIME">
+      <p>When using <code>INFO_THEN_DEBUG</code> for
+         <code>org.apache.juli.logging.UserDataHelper.CONFIG</code> this system
+         property controls how long messages are logged at DEBUG after a message
+         has been logged at INFO. Once this period has elapsed, the next message
+         will be logged at INFO followed by a new suppression period where
+         messages are logged at DEBUG and so on.</p>
+      <p>A value of <code>0</code> is equivalent to using <code>INFO_ALL</code>
+         for <code>org.apache.juli.logging.UserDataHelper.CONFIG</code>.</p>
+      <p>A negative value means an infinite suppression period.</p>
+      <p>The default value is <code>86400</code> (24 hours).</p>
+    </property>
   </properties>
 
 </section>



---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@tomcat.apache.org
For additional commands, e-mail: dev-help@tomcat.apache.org


Mime
View raw message