Logging with Play!

1. Introduction

In this tutorial, we’ll present how logging is done within a Play application.

Play provides an API for logging via the play.api.Logger class. It’s important to note that the Logger class uses Logback behind the scenes by default.

2. Creating and Using Loggers

In a Play application, we create and access logger instances through the play.api.Logger class.

Let’s write an example:

private val logger = Logger(getClass)
logger.info("get all users called")

In the above example, we show the most common case, which is the logger creation with the current class as an argument.

Another very common pattern is to create loggers with more generic names:

private val accessLogger = Logger("access")

3. Appenders

Appenders are responsible for writing the logging events to a destination. There are many implementations of the Appender interface, such as FileAppender, DBAppender, ListAppender, and more.

The following example shows how we can log to the console and a file simultaneously:

<appender name="FILE" class="ch.qos.logback.core.FileAppender">
    <file>${application.home}/logs/application.log</file>
    <encoder>
        <charset>UTF-8</charset>
        <pattern>
            %d{yyyy-MM-dd  HH:mm:ss.SSS}  %highlight(%-5level)  %cyan(%logger{36})  %magenta(%X{akkaSource})  %msg%n
        </pattern>
    </encoder>
</appender>

<appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
    <encoder>
        <charset>UTF-8</charset>
        <pattern>
            %d{yyyy-MM-dd  HH:mm:ss.SSS}  %highlight(%-5level)  %cyan(%logger{36})  %magenta(%X{akkaSource})  %msg%n
        </pattern>
    </encoder>
</appender>

<root level="WARN">
    <appender-ref ref="STDOUT"/>
    <appender-ref ref="FILE"/>
</root>

4. Configuration

In a Play application, the default settings file location is conf/logback.xml.

Of course, we can define different locations for the configuration file. In particular, we can set the -Dlogger.resource if the file is in the classpath or -Dlogger.file if the file is in the file system. It’s important to note that the configuration takes precedence in the following order: files set by the system properties > conf directory > default configuration.

Also, by setting the system property -Dlogback.debug=true, we can check the Logback configuration during the startup.

5. Implementing a Simple Logging Filter

A widespread need in web applications is to monitor endpoint calls. As an illustration, we’ll implement a logging filter to log the request times for every HTTP call.

Let’s see the LoggingFilter class:

class LoggingFilter @Inject() (implicit val mat: Materializer, ec: ExecutionContext) extends Filter {

  private val logger = Logger("time")

  def apply(nextFilter: RequestHeader => Future[Result])(requestHeader: RequestHeader): Future[Result] = {

    val startTime = System.currentTimeMillis

    logger.info(s"called ${requestHeader.uri}")

    nextFilter(requestHeader).map { result =>
      val handlerDefOpt: Option[HandlerDef] = requestHeader.attrs.get(Router.Attrs.HandlerDef)
      val action = handlerDefOpt.map(handlerDef => s"${handlerDef.controller}.${handlerDef.method}").getOrElse(requestHeader.uri)
      val endTime = System.currentTimeMillis
      val requestTime = endTime - startTime

      logger.info(s"${action} took ${requestTime}ms and returned ${result.header.status}")

      result.withHeaders("Request-Time" -> requestTime.toString)
    }
  }
}

Now we need to add the following to the application.conf, so the LoggingFilter is applied:

play.filters.enabled += "guice.filter.LoggingFilter"

As a result, every HTTP call produces a log message with the request time:

2022-06-19  21:45:34.912  INFO   time    guice.controllers.UserController.index took 66ms and returned 200

6. Conclusion

In this short article, we presented how we can use and configure logging with the Play framework.

As always, the code of the above examples is available over on GitHub.