Access log pattern %D and %T (response time) prints "-" in Undertow in JBoss EAP 7

Environment

• Red Hat JBoss Enterprise Application Platform (EAP)
  • 7.x

Issue

• Use of %D and %T in access logs pattern to print the time taken to process the requests in milliseconds logs - instead of the actual time:

    <access-log pattern="Time Taken: %T %D %h %l %u %t %r %s %b %I %{COOKIE}i %{SET-COOKIE}o"/>
  

Resolution

• You need to set the attribute record-request-start-time to true when using %D or %T patterns to log response time in access log, otherwise it just prints - instead of the actual response time.

• To show the actual response time, the attribute record-request-start-time should be set to true in the listener (http-listener, ajp-listener or https-listener you are using) inside the undertow subsystem. For example:

    <subsystem xmlns="urn:jboss:domain:undertow:3.0">
        ...
        <server name="default-server">
            <http-listener name="default" redirect-socket="https" socket-binding="http" record-request-start-time="true"/>
            <host name="default-host" alias="localhost">
                <location name="/" handler="welcome-content"/>
                <access-log pattern="Time Taken: %T %D %h %l %u %t %r %s %b %I %{COOKIE}i %{SET-COOKIE}o"/>
                <filter-ref name="server-header"/>
                <filter-ref name="x-powered-by-header"/>
            </host>
        </server>
        ...
    </subsystem>
  

  Note that, when you are using ajp-listener and/or https-listener in addition to http-listener, record-request-start-time="true" must be set on all listeners.

• You can set the attribute to true from CLI. For example:

    /subsystem=undertow/server=default-server/http-listener=default:write-attribute(name=record-request-start-time,value=true)
    /subsystem=undertow/server=default-server/ajp-listener=ajp:write-attribute(name=record-request-start-time,value=true)
    /subsystem=undertow/server=default-server/https-listener=https:write-attribute(name=record-request-start-time,value=true)
  

Root Cause

• record-request-start-time attribute in the http-listener tag of the Undertow subsystem is by default false.

This solution is part of Red Hat’s fast-track publication program, providing a huge library of solutions that Red Hat engineers have created while supporting our customers. To give you the knowledge you need the instant it becomes available, these articles may be presented in a raw and unedited form.