From d13f4bb71bcd9e903cd87e6f2625a9f8dc1b5ed6 Mon Sep 17 00:00:00 2001
From: Jean-Noel Rouvignac <jean-noel.rouvignac@forgerock.com>
Date: Tue, 21 May 2013 12:47:35 +0000
Subject: [PATCH] OPENDJ-902 (CR-1702) Add connectionID to the HTTP access log + move to extended log format OPENDJ-858 (CR-1702) Add stats tracking to HTTP client connections
---
opends/src/messages/messages/config.properties | 5 +
opends/src/server/org/opends/server/protocols/http/HTTPClientConnection.java | 31 +++++--
opends/src/admin/messages/FileBasedHTTPAccessLogPublisherCfgDefn.properties | 2
opends/src/server/org/opends/server/loggers/TextHTTPAccessLogPublisher.java | 137 +++++++++++++++++++++++++++------
opends/src/server/org/opends/server/loggers/HTTPRequestInfo.java | 7 +
opends/src/admin/defn/org/opends/server/admin/std/FileBasedHTTPAccessLogPublisherConfiguration.xml | 29 ++++--
6 files changed, 165 insertions(+), 46 deletions(-)
diff --git a/opends/src/admin/defn/org/opends/server/admin/std/FileBasedHTTPAccessLogPublisherConfiguration.xml b/opends/src/admin/defn/org/opends/server/admin/std/FileBasedHTTPAccessLogPublisherConfiguration.xml
index 28e0737..33d466e 100644
--- a/opends/src/admin/defn/org/opends/server/admin/std/FileBasedHTTPAccessLogPublisherConfiguration.xml
+++ b/opends/src/admin/defn/org/opends/server/admin/std/FileBasedHTTPAccessLogPublisherConfiguration.xml
@@ -292,8 +292,8 @@
</adm:synopsis>
<adm:default-behavior>
<adm:defined>
- <adm:value>cs-host c-ip cs-username datetime cs-method cs-uri-query
- cs-version sc-status sc-bytes cs(User-Agent) x-connection-id</adm:value>
+ <adm:value>cs-host c-ip cs-username x-datetime cs-method cs-uri-query
+ cs-version sc-status cs(User-Agent) x-connection-id x-etime</adm:value>
</adm:defined>
</adm:default-behavior>
<adm:syntax>
@@ -302,15 +302,24 @@
<adm:regex>[a-zA-Z0-9-()]+( [a-zA-Z0-9-()]+)*</adm:regex>
<adm:usage>FORMAT</adm:usage>
<adm:synopsis>
- A string describing the extended log format to be used for logging
- HTTP accesses. Available values are listed on the W3C working draft
- http://www.w3.org/TR/WD-logfile.html and Microsoft website
+ A space separated list of fields describing the extended log format
+ to be used for logging HTTP accesses. Available values are listed on
+ the W3C working draft http://www.w3.org/TR/WD-logfile.html
+ and Microsoft website
http://www.microsoft.com/technet/prodtechnol/WindowsServer2003/Library/IIS/676400bc-8969-4aa7-851a-9319490a9bbb.mspx?mfr=true
- . Please note that "date" and "time" have been merged into
- "datetime" and that its ouput is controlled by
- "ds-cfg-log-record-time-format" property. OpenDJ adds the
- application specific field "x-connection-id" which displays the
- internal connection ID assigned to the HTTP client connection.
+
+ OpenDJ supports the following standard fields: "c-ip", "c-port",
+ "cs-host", "cs-method", "cs-uri-query", "cs(User-Agent)",
+ "cs-username", "cs-version", "s-computername", "s-ip", "s-port",
+ "sc-status".
+
+ OpenDJ supports the following application specific field extensions:
+ "x-connection-id" displays the internal connection ID assigned to
+ the HTTP client connection, "x-datetime" displays the completion
+ date and time for the logged HTTP request and its ouput is
+ controlled by the "ds-cfg-log-record-time-format" property,
+ "x-etime" displays the total execution time for the logged HTTP
+ request.
</adm:synopsis>
</adm:pattern>
</adm:string>
diff --git a/opends/src/admin/messages/FileBasedHTTPAccessLogPublisherCfgDefn.properties b/opends/src/admin/messages/FileBasedHTTPAccessLogPublisherCfgDefn.properties
index afb30b0..9e4cea3 100644
--- a/opends/src/admin/messages/FileBasedHTTPAccessLogPublisherCfgDefn.properties
+++ b/opends/src/admin/messages/FileBasedHTTPAccessLogPublisherCfgDefn.properties
@@ -13,7 +13,7 @@
property.log-file-permissions.synopsis=The UNIX permissions of the log files created by this File Based HTTP Access Log Publisher.
property.log-file-permissions.syntax.string.pattern.synopsis=A valid UNIX mode string. The mode string must contain three digits between zero and seven.
property.log-format.synopsis=Specifies how log records should be formatted and written to the HTTP access log.
-property.log-format.syntax.string.pattern.synopsis=A string describing the extended log format to be used for logging HTTP accesses. Available values are listed on the W3C working draft http://www.w3.org/TR/WD-logfile.html and Microsoft website http://www.microsoft.com/technet/prodtechnol/WindowsServer2003/Library/IIS/676400bc-8969-4aa7-851a-9319490a9bbb.mspx?mfr=true . Please note that "date" and "time" have been merged into "datetime" and that its ouput is controlled by "ds-cfg-log-record-time-format" property. OpenDJ adds the application specific field "x-connection-id" which displays the internal connection ID assigned to the HTTP client connection.
+property.log-format.syntax.string.pattern.synopsis=A space separated list of fields describing the extended log format to be used for logging HTTP accesses. Available values are listed on the W3C working draft http://www.w3.org/TR/WD-logfile.html and Microsoft website http://www.microsoft.com/technet/prodtechnol/WindowsServer2003/Library/IIS/676400bc-8969-4aa7-851a-9319490a9bbb.mspx?mfr=true OpenDJ supports the following standard fields: "c-ip", "c-port", "cs-host", "cs-method", "cs-uri-query", "cs(User-Agent)", "cs-username", "cs-version", "s-computername", "s-ip", "s-port", "sc-status". OpenDJ supports the following application specific field extensions: "x-connection-id" displays the internal connection ID assigned to the HTTP client connection, "x-datetime" displays the completion date and time for the logged HTTP request and its ouput is controlled by the "ds-cfg-log-record-time-format" property, "x-etime" displays the total execution time for the logged HTTP request.
property.log-record-time-format.synopsis=Specifies the format string that is used to generate log record timestamps.
property.log-record-time-format.syntax.string.pattern.synopsis=Any valid format string that can be used with the java.text.SimpleDateFormat class.
property.queue-size.synopsis=The maximum number of log records that can be stored in the asynchronous queue.
diff --git a/opends/src/messages/messages/config.properties b/opends/src/messages/messages/config.properties
index e1b4cfe..a536c76 100644
--- a/opends/src/messages/messages/config.properties
+++ b/opends/src/messages/messages/config.properties
@@ -2181,3 +2181,8 @@
SEVERE_ERR_CONFIG_LOGGER_INVALID_HTTP_ACCESS_LOGGER_CLASS_732=Class %s specified \
in attribute ds-cfg-java-class of configuration entry %s cannot be \
instantiated as a Directory Server HTTP access logger: %s
+SEVERE_ERR_CONFIG_LOGGING_EMPTY_LOG_FORMAT_733=The log format for configuration \
+ entry %s is empty. No information will be logged even if logging is activated
+MILD_WARN_CONFIG_LOGGING_UNSUPPORTED_FIELDS_IN_LOG_FORMAT_734=The log format \
+ for %s contains the folowing unsupported fields: %s. Their output will be \
+ replaced with a dash ("-") character
diff --git a/opends/src/server/org/opends/server/loggers/HTTPRequestInfo.java b/opends/src/server/org/opends/server/loggers/HTTPRequestInfo.java
index ea009af..cfd68c1 100644
--- a/opends/src/server/org/opends/server/loggers/HTTPRequestInfo.java
+++ b/opends/src/server/org/opends/server/loggers/HTTPRequestInfo.java
@@ -134,6 +134,13 @@
long getConnectionID();
/**
+ * Returns the total processing time for this HTTP request.
+ *
+ * @return the total processing time for this HTTP request
+ */
+ long getTotalProcessingTime();
+
+ /**
* Logs the current request info in the HTTP access log.
*
* @param statusCode
diff --git a/opends/src/server/org/opends/server/loggers/TextHTTPAccessLogPublisher.java b/opends/src/server/org/opends/server/loggers/TextHTTPAccessLogPublisher.java
index f93b0ec..4e66347 100644
--- a/opends/src/server/org/opends/server/loggers/TextHTTPAccessLogPublisher.java
+++ b/opends/src/server/org/opends/server/loggers/TextHTTPAccessLogPublisher.java
@@ -33,9 +33,13 @@
import java.io.IOException;
import java.text.SimpleDateFormat;
import java.util.ArrayList;
+import java.util.Arrays;
+import java.util.Collection;
import java.util.HashMap;
+import java.util.HashSet;
import java.util.List;
import java.util.Map;
+import java.util.Set;
import org.opends.messages.Message;
import org.opends.server.admin.server.ConfigurationChangeListener;
@@ -60,6 +64,30 @@
implements ConfigurationChangeListener<FileBasedHTTPAccessLogPublisherCfg>
{
+ // Extended log format standard fields
+ private static final String ELF_C_IP = "c-ip";
+ private static final String ELF_C_PORT = "c-port";
+ private static final String ELF_CS_HOST = "cs-host";
+ private static final String ELF_CS_METHOD = "cs-method";
+ private static final String ELF_CS_URI_QUERY = "cs-uri-query";
+ private static final String ELF_CS_USER_AGENT = "cs(User-Agent)";
+ private static final String ELF_CS_USERNAME = "cs-username";
+ private static final String ELF_CS_VERSION = "cs-version";
+ private static final String ELF_S_COMPUTERNAME = "s-computername";
+ private static final String ELF_S_IP = "s-ip";
+ private static final String ELF_S_PORT = "s-port";
+ private static final String ELF_SC_STATUS = "sc-status";
+ // Application specific fields (eXtensions)
+ private static final String X_CONNECTION_ID = "x-connection-id";
+ private static final String X_DATETIME = "x-datetime";
+ private static final String X_ETIME = "x-etime";
+
+ private static final Set<String> ALL_SUPPORTED_FIELDS = new HashSet<String>(
+ Arrays.asList(ELF_C_IP, ELF_C_PORT, ELF_CS_HOST, ELF_CS_METHOD,
+ ELF_CS_URI_QUERY, ELF_CS_USER_AGENT, ELF_CS_USERNAME, ELF_CS_VERSION,
+ ELF_S_COMPUTERNAME, ELF_S_IP, ELF_S_PORT, ELF_SC_STATUS,
+ X_CONNECTION_ID, X_DATETIME, X_ETIME));
+
/**
* Returns an instance of the text HTTP access log publisher that will print
* all messages to the provided writer. This is used to print the messages to
@@ -83,7 +111,7 @@
private TextWriter writer = null;
private FileBasedHTTPAccessLogPublisherCfg cfg = null;
- private String[] logFormatFields;
+ private List<String> logFormatFields;
private String timeStampFormat = "dd/MMM/yyyy:HH:mm:ss Z";
@@ -95,7 +123,7 @@
// Default result code.
ResultCode resultCode = ResultCode.SUCCESS;
boolean adminActionRequired = false;
- final ArrayList<Message> messages = new ArrayList<Message>();
+ final List<Message> messages = new ArrayList<Message>();
final File logFile = getFileForPath(config.getLogFile());
final FileNamingPolicy fnPolicy = new TimeStampNaming(logFile);
@@ -153,7 +181,7 @@
{
// The asynchronous setting is being turned off.
final AsynchronousTextWriter asyncWriter =
- ((AsynchronousTextWriter) writer);
+ (AsynchronousTextWriter) writer;
writer = mfWriter;
asyncWriter.shutdown(false);
}
@@ -161,7 +189,7 @@
if (writer instanceof ParallelTextWriter && !config.isAsynchronous())
{
// The asynchronous setting is being turned off.
- final ParallelTextWriter asyncWriter = ((ParallelTextWriter) writer);
+ final ParallelTextWriter asyncWriter = (ParallelTextWriter) writer;
writer = mfWriter;
asyncWriter.shutdown(false);
}
@@ -186,8 +214,8 @@
writer = asyncWriter;
}
- if ((cfg.isAsynchronous() && config.isAsynchronous())
- && (cfg.getQueueSize() != config.getQueueSize()))
+ if (cfg.isAsynchronous() && config.isAsynchronous()
+ && cfg.getQueueSize() != config.getQueueSize())
{
adminActionRequired = true;
}
@@ -200,6 +228,13 @@
cfg = config;
logFormatFields = extractFieldsOrder(cfg.getLogFormat());
+ Message errorMessage = validateLogFormat(logFormatFields);
+ if (errorMessage != null)
+ {
+ resultCode = DirectoryServer.getServerErrorResultCode();
+ adminActionRequired = true;
+ messages.add(errorMessage);
+ }
}
}
catch (final Exception e)
@@ -214,15 +249,59 @@
}
- private String[] extractFieldsOrder(String logFormat)
+ private List<String> extractFieldsOrder(String logFormat)
{
- if (logFormat != null)
- {
- return logFormat.split("\\s");
+ // there will always be at least one field value due to the regexp
+ // validating the log format
+ return Arrays.asList(logFormat.split(" "));
+ }
+
+ /**
+ * Validates the provided fields for the log format.
+ *
+ * @param fields
+ * the fields comprising the log format.
+ * @return an error message when validation fails, null otherwise
+ */
+ private Message validateLogFormat(List<String> fields)
+ {
+ final Collection<String> unsupportedFields =
+ subtract(fields, ALL_SUPPORTED_FIELDS);
+ if (!unsupportedFields.isEmpty())
+ { // there are some unsupported fields. List them.
+ return WARN_CONFIG_LOGGING_UNSUPPORTED_FIELDS_IN_LOG_FORMAT.get(cfg.dn()
+ .toString(), collectionToString(unsupportedFields, ", "));
+ }
+ if (fields.size() == unsupportedFields.size())
+ { // all fields are unsupported
+ return ERR_CONFIG_LOGGING_EMPTY_LOG_FORMAT.get(cfg.dn().toString());
}
return null;
}
+ /**
+ * Returns a new Collection containing a - b.
+ *
+ * @param <T>
+ * @param a
+ * the collection to subtract from, must not be null
+ * @param b
+ * the collection to subtract, must not be null
+ * @return a new collection with the results
+ */
+ private <T> Collection<T> subtract(Collection<T> a, Collection<T> b)
+ {
+ final Collection<T> result = new ArrayList<T>();
+ for (T elem : a)
+ {
+ if (!b.contains(elem))
+ {
+ result.add(elem);
+ }
+ }
+ return result;
+ }
+
/** {@inheritDoc} */
@Override
public void initializeLogPublisher(
@@ -289,11 +368,15 @@
final Message message = ERR_CONFIG_LOGGING_CANNOT_OPEN_FILE.get(
logFile.toString(), cfg.dn().toString(), String.valueOf(e));
throw new InitializationException(message, e);
-
}
this.cfg = cfg;
logFormatFields = extractFieldsOrder(cfg.getLogFormat());
+ Message error = validateLogFormat(logFormatFields);
+ if (error != null)
+ {
+ throw new InitializationException(error);
+ }
timeStampFormat = cfg.getLogRecordTimeFormat();
cfg.addFileBasedHTTPAccessChangeListener(this);
@@ -379,25 +462,27 @@
public void logRequestInfo(HTTPRequestInfo ri)
{
final Map<String, Object> fields = new HashMap<String, Object>();
- fields.put("c-ip", ri.getClientAddress());
- fields.put("cs-host", ri.getClientHost());
- fields.put("c-port", ri.getClientPort());
- fields.put("s-ip", ri.getServerAddress());
- fields.put("s-computername", ri.getServerHost());
- fields.put("s-port", ri.getServerPort());
- fields.put("cs-username", ri.getAuthUser());
- fields.put("datetime", TimeThread.getUserDefinedTime(timeStampFormat));
- fields.put("cs-method", ri.getMethod());
- fields.put("cs-uri-query", ri.getQuery());
- fields.put("cs-version", ri.getProtocol());
- fields.put("sc-status", ri.getStatusCode());
- fields.put("cs(User-Agent)", ri.getUserAgent());
- fields.put("x-connection-id", ri.getConnectionID());
+ fields.put(ELF_C_IP, ri.getClientAddress());
+ fields.put(ELF_C_PORT, ri.getClientPort());
+ fields.put(ELF_CS_HOST, ri.getClientHost());
+ fields.put(ELF_CS_METHOD, ri.getMethod());
+ fields.put(ELF_CS_URI_QUERY, ri.getQuery());
+ fields.put(ELF_CS_USER_AGENT, ri.getUserAgent());
+ fields.put(ELF_CS_USERNAME, ri.getAuthUser());
+ fields.put(ELF_CS_VERSION, ri.getProtocol());
+ fields.put(ELF_S_IP, ri.getServerAddress());
+ fields.put(ELF_S_COMPUTERNAME, ri.getServerHost());
+ fields.put(ELF_S_PORT, ri.getServerPort());
+ fields.put(ELF_SC_STATUS, ri.getStatusCode());
+ fields.put(X_CONNECTION_ID, ri.getConnectionID());
+ fields.put(X_DATETIME, TimeThread.getUserDefinedTime(timeStampFormat));
+ fields.put(X_ETIME, ri.getTotalProcessingTime());
writeLogRecord(fields, logFormatFields);
}
- private void writeLogRecord(Map<String, Object> fields, String... fieldnames)
+ private void writeLogRecord(Map<String, Object> fields,
+ List<String> fieldnames)
{
if (fieldnames == null)
{
diff --git a/opends/src/server/org/opends/server/protocols/http/HTTPClientConnection.java b/opends/src/server/org/opends/server/protocols/http/HTTPClientConnection.java
index c142413..6a4506e 100644
--- a/opends/src/server/org/opends/server/protocols/http/HTTPClientConnection.java
+++ b/opends/src/server/org/opends/server/protocols/http/HTTPClientConnection.java
@@ -186,6 +186,9 @@
private final HTTPStatistics statTracker;
private boolean useNanoTime = false;
+ /** Total execution time for this request. */
+ private AtomicLong totalProcessingTime = new AtomicLong();
+
/** The protocol in use for this client connection. */
private String protocol;
@@ -298,6 +301,13 @@
/** {@inheritDoc} */
@Override
+ public long getTotalProcessingTime()
+ {
+ return totalProcessingTime.get();
+ }
+
+ /** {@inheritDoc} */
+ @Override
public String getProtocol()
{
return protocol;
@@ -370,17 +380,11 @@
@Override
public void sendResponse(Operation operation)
{
+ final long time = getProcessingTime(operation);
+ this.totalProcessingTime.addAndGet(time);
+
if (keepStats)
{
- long time;
- if (useNanoTime)
- {
- time = operation.getProcessingNanoTime();
- }
- else
- {
- time = operation.getProcessingTime();
- }
this.statTracker.updateRequestMonitoringData(getMethod(), time);
this.statTracker.updateOperationMonitoringData(operation
.getOperationType(), time);
@@ -407,6 +411,15 @@
}
}
+ private long getProcessingTime(Operation operation)
+ {
+ if (useNanoTime)
+ {
+ return operation.getProcessingNanoTime();
+ }
+ return operation.getProcessingTime();
+ }
+
private ProtocolOp toResponseProtocolOp(Operation operation)
{
final int resultCode = operation.getResultCode().getIntValue();
--
Gitblit v1.10.0