Jetty服务器访问日志中的负响应时间 [英] Negative response time in Jetty server access log

问题描述

我正在Jetty上运行，并且我的访问日志已配置为显示响应时间.

I'm running on Jetty and my access log is configured to show the response time.

今天我注意到很少的请求(大约60万个请求中的30个)的响应时间为负数，我想知道是否有人遇到过这种行为.

today I noticed that a very minimal amount of the requests (about 30 out of 600K) have a negative response time and I was wondering if anyone ever encountered such a behavior.

这是我的回复示例: < [IP]>--< [date]>"POST< [url]> HTTP/1.0" 201 461 -18096

This is a sample of my response: <[IP]> - - <[date]> "POST <[url]> HTTP/1.0" 201 461 -18096

如果您想在访问日志中标识它-这是我使用的grep命令:

In case you want to identify this in the access log - this is the grep command i used:

grep --color-[0-9] [0-9] *"服务器访问.2013_12_09.log

grep --color "-[0-9][0-9]*" server-access.2013_12_09.log

码头版本: 8.1.8

jetty.xml中的设置:

<New id="request-log-handler" class="org.eclipse.jetty.server.handler.RequestLogHandler">
<Set name="requestLog">
  <New class="org.eclipse.jetty.server.NCSARequestLog">
    <Arg>
      <Property name="logging.httpAccessLog" default="logs/app-access.yyyy_mm_dd.log" />
    </Arg>
    <Set name="retainDays">
      <Property name="logging.accessLogRetentionInDays" default="10" />
    </Set>
    <Set name="append">
      <Property name="logging.httpAccessLogAppend" default="true" />
    </Set>
    <!-- logs referer and user agent -->
    <Set name="extended">
      <Property name="logging.httpAccessLogExtended" default="false" />
    </Set>
    <!-- response time -->
    <Set name="logLatency">
      <Property name="logging.httpAccessLogLatency" default="true" />
    </Set>
  </New>
</Set>

推荐答案

使用Jetty 9.1.0.

Using Jetty 9.1.0.

键:

• <name> =在线上的可选/可配置条目
• {name} =强制输入

• <name> = optional / configurable entry on line
• {name} = mandatory entry

<servername> {X-Forwarded-For||remote-addr} - {authentication/principal/name} [{request-timestamp}] "{method} {uri} {protocol}" {response-status-code} {response-content-length} <extended-log> <cookies> <latency>

位置:

• <servername>可以是请求/主机标头
• <extended-log>可以是
• <cookies>可以是 或
• <latency>可以是

• <servername> can be the request/Host header
• <extended-log> can be "{referer} {user-agent}"
• <cookies> can be " -" or "{cookie.name}={cookie-value};"
• <latency> can be (now - request.getTimeStamp())

有趣的是，您的系统时钟似乎在请求期间进行了调整.整整18秒！

Interestingly, it appears that your system clock adjusted during a request. A full 18 seconds!

这就是为什么这是主导理论...

Here's why this is the leading theory ...

The request.timestamp is set when the request starts, then the latency is computed later during the access/request logging. For there to be a negative value, either something outside of Jetty itself reset the request.timeout, or the system clock changed.

这篇关于Jetty服务器访问日志中的负响应时间的文章就介绍到这了，希望我们推荐的答案对大家有所帮助，也希望大家多多支持IT屋！