CODEWITHSUNDEEP
scalaakkalogbackslf4jakka-http
user5325596
user5325596

Reputation: 2410

How to configure logback to get nice logs of akka-http logRequest event

As a result of the answer to this question I am able to get logRequest to log to a file called access.log.

I have

val routes =
      path("ping" ) {
        withLog(accessLog) {
          logRequest("ping", Logging.InfoLevel) {
            complete("pong")
          }
        }
      }

Part of my logback.xml configuration looks like 

 <appender name="ACCESSLOG" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <file>log/access.log</file>
        <encoder class="ch.qos.logback.classic.encoder.PatternLayoutEncoder">
            <pattern>
                %d{yyyy-MM-dd HH:mm:ss} %msg%n
            </pattern>
        </encoder>
        <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
            <fileNamePattern>log/access-%d{yyyy-MM-dd}.%i.log</fileNamePattern>
            <timeBasedFileNamingAndTriggeringPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP">
                <maxFileSize>64 MB</maxFileSize>
            </timeBasedFileNamingAndTriggeringPolicy>
        </rollingPolicy>
    </appender>

And the resulting entry in the log file looks like

2019-02-06 16:51:04 ping: HttpRequest(HttpMethod(GET),http://localhost:8080/ping,List(Host: localhost:8080, Connection: keep-alive, Cache-Control: max-age=0, Upgrade-Insecure-Requests: 1, User-Agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_14_2) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/71.0.3578.98 Safari/537.36, Accept: text/html, application/xhtml+xml, application/xml;q=0.9, image/webp, image/apng, */*;q=0.8, Accept-Encoding: gzip, deflate, br, Accept-Language: en-GB, en-US;q=0.9, en;q=0.8, Cookie: xxx, Timeout-Access: <function1>),HttpEntity.Strict(none/none,ByteString()),HttpProtocol(HTTP/1.1))

What can I do to get my log entries to look something like

2019-02-06 16:51:04 GET /ping <time_taken>

Upvotes: 0

Views: 1504

Answers (2)

pme
pme

Reputation: 14803

Check the Documentation for the pattern.

We are fine with this one:

  <conversionRule conversionWord="coloredLevel" converterClass="play.api.libs.logback.ColoredLevel" />
    ...
  <appender ...>
    <encoder>
        <pattern>%date %coloredLevel %logger{15} - %message%n%xException{10}</pattern>
    </encoder>
 </appender>

Here is another example (where I found the results):

<appender name="ACCESS_FILE" ...>
  ....     
    <encoder>
            <pattern>%date [%level] from %logger - %message%n%xException</pattern>
        </encoder>
    </appender>

This gives you:

2018-06-26 12:13:50,377 [INFO] from access-filter - 6. GET /assets/javascripts/versioned.js took 113ms and returned 200
2018-06-26 12:13:50,377 [INFO] from access-filter - 6. GET /assets/scala-adapters-client-jsdeps.js took 113ms and returned 200

Upvotes: 0

Ivan Stanislavciuc
Ivan Stanislavciuc

Reputation: 7275

You can define a method that will produce a LogEntry and you set your log message in the way you want.

  def myLogEntry(req: HttpRequest): LogEntry = {
    LogEntry(s"${req.method} /${req.uri.path}", Logging.InfoLevel)
  }

  logRequest(myLogEntry _) {
    complete("pong")
  }

The problem is with information like <time_taken> as it's not available when directive logRequest is executed. This directive prints log message on incoming http request when directive is triggered. There is no information yet for the inner route result, completed or rejected.

Check out this blog post to see how time can be calculated.

Upvotes: 1

Related Questions