PATCHES ACCEPTED TO BACKPORT FROM TRUNK:
[ start all new proposals below, under PATCHES PROPOSED. ]
- * mod_log_config: Allow to choose request start or end time
- as time stamp in log (httpd traditionally uses start, many
- other components, e.g. Tomcat use end time, so they are kind
- of hard to correlate). Also add more format choices for time stamps.
- Needed get_request_end_time() was already ported back.
- trunk patch: http://svn.apache.org/r979120 (remaining parts)
- 2.4.x patch: http://svn.apache.org/r979120 (remaining parts)
- 2.2.x patch: http://people.apache.org/~rjung/patches/httpd-2.2.x-mod_log_config-more_time_formats-v2.patch
- +1: rjung, wrowe, ylavic
- rjung: I had forgotten the docs part. Added in v2 patch. OK to keep Bill's vote?
-
PATCHES PROPOSED TO BACKPORT FROM TRUNK:
[ New proposals should be added at the end of the list ]
<tr><td><code>%{<var>format</var>}t</code></td>
<td>The time, in the form given by format, which should be in
- <code>strftime(3)</code> format. (potentially localized)</td></tr>
+ an extended <code>strftime(3)</code> format (potentially localized).
+ If the format starts with <code>begin:</code> (default) the time is taken
+ at the beginning of the request processing. If it starts with
+ <code>end:</code> it is the time when the log entry gets written,
+ close to the end of the request processing. In addition to the formats
+ supported by <code>strftime(3)</code>, the following format tokens are
+ supported:
+ <table>
+ <tr><td><code>sec</code></td><td>number of seconds since the Epoch</td></tr>
+ <tr><td><code>msec</code></td><td>number of milliseconds since the Epoch</td></tr>
+ <tr><td><code>usec</code></td><td>number of microseconds since the Epoch</td></tr>
+ <tr><td><code>msec_frac</code></td><td>millisecond fraction</td></tr>
+ <tr><td><code>usec_frac</code></td><td>microsecond fraction</td></tr>
+ </table>
+ These tokens can not be combined with each other or <code>strftime(3)</code>
+ formatting in the same format string. You can use multiple
+ <code>%{<var>format</var>}t</code> tokens instead. The extended
+ <code>strftime(3)</code> tokens are available in 2.2.30 and later.
+ </td></tr>
<tr><td><code>%T</code></td>
<td>The time taken to serve the request, in seconds.</td></tr>
<dt>Agent (Browser) log format</dt>
<dd><code>"%{User-agent}i"</code></dd>
</dl>
+
+ <p>You can use the <code>%{format}t</code> directive multiple
+ times to build up a time format using the extended format tokens
+ like <code>msec_frac</code>:</p>
+ <dl>
+<dt>Timestamp including milliseconds</dt>
+<dd><code>"%{%d/%b/%Y %T}t.%{msec_frac}t %{%z}t"</code></dd>
+
+ </dl>
+
</section>
</section>
unsigned t_validate;
} cached_request_time;
+#define TIME_FMT_CUSTOM 0
+#define TIME_FMT_CLF 1
+#define TIME_FMT_ABS_SEC 2
+#define TIME_FMT_ABS_MSEC 3
+#define TIME_FMT_ABS_USEC 4
+#define TIME_FMT_ABS_MSEC_FRAC 5
+#define TIME_FMT_ABS_USEC_FRAC 6
+
#define TIME_CACHE_SIZE 4
#define TIME_CACHE_MASK 3
static cached_request_time request_time_cache[TIME_CACHE_SIZE];
static const char *log_request_time(request_rec *r, char *a)
{
apr_time_exp_t xt;
+ apr_time_t request_time = r->request_time;
+ int fmt_type = TIME_FMT_CUSTOM;
+ char *fmt = a;
+
+ if (fmt && *fmt) {
+ if (!strncmp(fmt, "begin", 5)) {
+ fmt += 5;
+ if (!*fmt) {
+ fmt_type = TIME_FMT_CLF;
+ }
+ else if (*fmt == ':') {
+ fmt++;
+ a = fmt;
+ }
+ }
+ else if (!strncmp(fmt, "end", 3)) {
+ fmt += 3;
+ if (!*fmt) {
+ request_time = get_request_end_time(r);
+ fmt_type = TIME_FMT_CLF;
+ }
+ else if (*fmt == ':') {
+ fmt++;
+ a = fmt;
+ request_time = get_request_end_time(r);
+ }
+ }
+ if (!strncmp(fmt, "msec", 4)) {
+ fmt += 4;
+ if (!*fmt) {
+ fmt_type = TIME_FMT_ABS_MSEC;
+ }
+ else if (!strcmp(fmt, "_frac")) {
+ fmt_type = TIME_FMT_ABS_MSEC_FRAC;
+ }
+ }
+ else if (!strncmp(fmt, "usec", 4)) {
+ fmt += 4;
+ if (!*fmt) {
+ fmt_type = TIME_FMT_ABS_USEC;
+ }
+ else if (!strcmp(fmt, "_frac")) {
+ fmt_type = TIME_FMT_ABS_USEC_FRAC;
+ }
+ }
+ else if (!strcmp(fmt, "sec")) {
+ fmt_type = TIME_FMT_ABS_SEC;
+ }
+ else if (!*fmt) {
+ fmt_type = TIME_FMT_CLF;
+ }
+ }
+ else {
+ fmt_type = TIME_FMT_CLF;
+ }
- /* ### I think getting the time again at the end of the request
- * just for logging is dumb. i know it's "required" for CLF.
- * folks writing log parsing tools don't realise that out of order
- * times have always been possible (consider what happens if one
- * process calculates the time to log, but then there's a context
- * switch before it writes and before that process is run again the
- * log rotation occurs) and they should just fix their tools rather
- * than force the server to pay extra cpu cycles. if you've got
- * a problem with this, you can set the define. -djg
- */
- if (a && *a) { /* Custom format */
+ if (fmt_type >= TIME_FMT_ABS_SEC) { /* Absolute (micro-/milli-)second time
+ * or msec/usec fraction
+ */
+ char* buf = apr_palloc(r->pool, 20);
+ switch (fmt_type) {
+ case TIME_FMT_ABS_SEC:
+ apr_snprintf(buf, 20, "%" APR_TIME_T_FMT, apr_time_sec(request_time));
+ break;
+ case TIME_FMT_ABS_MSEC:
+ apr_snprintf(buf, 20, "%" APR_TIME_T_FMT, apr_time_as_msec(request_time));
+ break;
+ case TIME_FMT_ABS_USEC:
+ apr_snprintf(buf, 20, "%" APR_TIME_T_FMT, request_time);
+ break;
+ case TIME_FMT_ABS_MSEC_FRAC:
+ apr_snprintf(buf, 20, "%03" APR_TIME_T_FMT, apr_time_msec(request_time));
+ break;
+ case TIME_FMT_ABS_USEC_FRAC:
+ apr_snprintf(buf, 20, "%06" APR_TIME_T_FMT, apr_time_usec(request_time));
+ break;
+ default:
+ return "-";
+ }
+ return buf;
+ }
+ else if (fmt_type == TIME_FMT_CUSTOM) { /* Custom format */
/* The custom time formatting uses a very large temp buffer
* on the stack. To avoid using so much stack space in the
* common case where we're not using a custom format, the code
* for the custom format in a separate function. (That's why
* log_request_time_custom is not inlined right here.)
*/
-#ifdef I_INSIST_ON_EXTRA_CYCLES_FOR_CLF_COMPLIANCE
- ap_explode_recent_localtime(&xt, get_request_end_time(r));
-#else
- ap_explode_recent_localtime(&xt, r->request_time);
-#endif
+ ap_explode_recent_localtime(&xt, request_time);
return log_request_time_custom(r, a, &xt);
}
- else { /* CLF format */
+ else { /* CLF format */
/* This code uses the same technique as ap_explode_recent_localtime():
* optimistic caching with logic to detect and correct race conditions.
* See the comments in server/util_time.c for more information.
*/
cached_request_time* cached_time = apr_palloc(r->pool,
sizeof(*cached_time));
-#ifdef I_INSIST_ON_EXTRA_CYCLES_FOR_CLF_COMPLIANCE
- apr_time_t request_time = get_request_end_time(r);
-#else
- apr_time_t request_time = r->request_time;
-#endif
unsigned t_seconds = (unsigned)apr_time_sec(request_time);
unsigned i = t_seconds & TIME_CACHE_MASK;
*cached_time = request_time_cache[i];
projects / thirdparty / apache / httpd.git / commitdiff
