#412 Improve logs

app/org/thp/cortex/controllers/AnalyzerCtrl.scala

@@ -44,7 +44,9 @@ class AnalyzerCtrl @Inject() (
 
   private def analyzerJson(isAdmin: Boolean)(analyzer: Worker): JsObject =
     if (isAdmin)
-      analyzer.toJson + ("configuration" -> Json.parse(analyzer.configuration())) + ("analyzerDefinitionId" -> JsString(analyzer.workerDefinitionId()))
+      analyzer.toJson + ("configuration" -> Json.parse(analyzer.configuration())) + ("analyzerDefinitionId" -> JsString(
+        analyzer.workerDefinitionId()
+      ))
     else
       analyzer.toJson + ("analyzerDefinitionId" -> JsString(analyzer.workerDefinitionId()))
 

app/org/thp/cortex/controllers/AttachmentCtrl.scala

@@ -18,8 +18,7 @@ import play.api.libs.Files.DefaultTemporaryFileCreator
 import play.api.mvc._
 import play.api.{mvc, Configuration}
 
-/**
-  * Controller used to access stored attachments (plain or zipped)
+/** Controller used to access stored attachments (plain or zipped)
   */
 @Singleton
 class AttachmentCtrl(
@@ -41,8 +40,7 @@ class AttachmentCtrl(
   ) =
     this(configuration.get[String]("datastore.attachment.password"), tempFileCreator, attachmentSrv, authenticated, components, executionContextSrv)
 
-  /**
-    * Download an attachment, identified by its hash, in plain format
+  /** Download an attachment, identified by its hash, in plain format
     * File name can be specified. This method is not protected : browser will
     * open the document directly. It must be used only for safe file
     */
@@ -51,7 +49,7 @@ class AttachmentCtrl(
     executionContextSrv.withDefault { implicit ec =>
       if (hash.startsWith("{{")) // angularjs hack
         NoContent
-      else if (!name.getOrElse("").intersect(AttachmentAttributeFormat.forbiddenChar).isEmpty)
+      else if (name.getOrElse("").intersect(AttachmentAttributeFormat.forbiddenChar).nonEmpty)
         mvc.Results.BadRequest("File name is invalid")
       else
         Result(
@@ -69,15 +67,14 @@ class AttachmentCtrl(
     }
   }
 
-  /**
-    * Download an attachment, identified by its hash, in zip format.
+  /** Download an attachment, identified by its hash, in zip format.
     * Zip file is protected by the password "malware"
     * File name can be specified (zip extension is append)
     */
   @Timed("controllers.AttachmentCtrl.downloadZip")
   def downloadZip(hash: String, name: Option[String]): Action[AnyContent] = authenticated(Roles.read) { _ =>
     executionContextSrv.withDefault { implicit ec =>
-      if (!name.getOrElse("").intersect(AttachmentAttributeFormat.forbiddenChar).isEmpty)
+      if (name.getOrElse("").intersect(AttachmentAttributeFormat.forbiddenChar).nonEmpty)
         BadRequest("File name is invalid")
       else {
         val f = tempFileCreator.create("zip", hash).path

app/org/thp/cortex/controllers/ResponderCtrl.scala

@@ -69,7 +69,7 @@ class ResponderCtrl @Inject() (
   def listForType(dataType: String): Action[AnyContent] = authenticated(Roles.read).async { request =>
     import org.elastic4play.services.QueryDSL._
     val (responderList, responderCount) = workerSrv.findRespondersForUser(request.userId, "dataTypeList" ~= dataType, Some("all"), Nil)
-    renderer.toOutput(OK, responderList.map(responderJson(false)), responderCount)
+    renderer.toOutput(OK, responderList.map(responderJson(isAdmin = false)), responderCount)
   }
 
   def create(responderDefinitionId: String): Action[Fields] = authenticated(Roles.orgAdmin).async(fieldsBodyParser) { implicit request =>

app/org/thp/cortex/controllers/StreamCtrl.scala

@@ -70,8 +70,7 @@ class StreamCtrl(
     )
   private[StreamCtrl] lazy val logger = Logger(getClass)
 
-  /**
-    * Create a new stream entry with the event head
+  /** Create a new stream entry with the event head
     */
   @Timed("controllers.StreamCtrl.create")
   def create: Action[AnyContent] = authenticated(Roles.read) {
@@ -85,8 +84,7 @@ class StreamCtrl(
   private[controllers] def isValidStreamId(streamId: String): Boolean =
     streamId.length == 10 && streamId.forall(alphanumeric.contains)
 
-  /**
-    * Get events linked to the identified stream entry
+  /** Get events linked to the identified stream entry
     * This call waits up to "refresh", if there is no event, return empty response
     */
   @Timed("controllers.StreamCtrl.get")
@@ -113,10 +111,10 @@ class StreamCtrl(
   }
 
   @Timed("controllers.StreamCtrl.status")
-  def status = Action { implicit request =>
+  def status: Action[AnyContent] = Action { implicit request =>
     val status = authenticated.expirationStatus(request) match {
       case ExpirationWarning(duration) => Json.obj("remaining" -> duration.toSeconds, "warning" -> true)
-      case ExpirationError             => Json.obj("remaining" -> 0, "warning"                  -> true)
+      case ExpirationError             => Json.obj("remaining" -> 0, "warning" -> true)
       case ExpirationOk(duration)      => Json.obj("remaining" -> duration.toSeconds, "warning" -> false)
     }
     Ok(status)

app/org/thp/cortex/models/Audit.scala

@@ -70,13 +70,14 @@ class AuditModel(auditName: String, auditedModels: immutable.Set[AuditedModel])
 
   def mergeAttributeFormat(context: String, format1: AttributeFormat[_], format2: AttributeFormat[_]): Option[AttributeFormat[_]] =
     (format1, format2) match {
-      case (OptionalAttributeFormat(f1), f2)                                              => mergeAttributeFormat(context, f1, f2)
-      case (f1, OptionalAttributeFormat(f2))                                              => mergeAttributeFormat(context, f1, f2)
-      case (MultiAttributeFormat(f1), MultiAttributeFormat(f2))                           => mergeAttributeFormat(context, f1, f2).map(MultiAttributeFormat(_))
-      case (f1, EnumerationAttributeFormat(_) | ListEnumerationAttributeFormat(_))        => mergeAttributeFormat(context, f1, StringAttributeFormat)
-      case (EnumerationAttributeFormat(_) | ListEnumerationAttributeFormat(_), f2)        => mergeAttributeFormat(context, StringAttributeFormat, f2)
-      case (ObjectAttributeFormat(subAttributes1), ObjectAttributeFormat(subAttributes2)) => mergeAttributes(context, subAttributes1 ++ subAttributes2)
-      case (f1, f2) if f1 == f2                                                           => Some(f1)
+      case (OptionalAttributeFormat(f1), f2)                                       => mergeAttributeFormat(context, f1, f2)
+      case (f1, OptionalAttributeFormat(f2))                                       => mergeAttributeFormat(context, f1, f2)
+      case (MultiAttributeFormat(f1), MultiAttributeFormat(f2))                    => mergeAttributeFormat(context, f1, f2).map(MultiAttributeFormat(_))
+      case (f1, EnumerationAttributeFormat(_) | ListEnumerationAttributeFormat(_)) => mergeAttributeFormat(context, f1, StringAttributeFormat)
+      case (EnumerationAttributeFormat(_) | ListEnumerationAttributeFormat(_), f2) => mergeAttributeFormat(context, StringAttributeFormat, f2)
+      case (ObjectAttributeFormat(subAttributes1), ObjectAttributeFormat(subAttributes2)) =>
+        mergeAttributes(context, subAttributes1 ++ subAttributes2)
+      case (f1, f2) if f1 == f2 => Some(f1)
       case (f1, f2) =>
         logger.warn(s"Attribute $f1 != $f2")
         None

app/org/thp/cortex/services/AccessLogFilter.scala

@@ -0,0 +1,32 @@
+package org.thp.cortex.services
+
+import play.api.Logger
+import play.api.http.HttpErrorHandler
+import play.api.mvc.{EssentialAction, EssentialFilter, RequestHeader}
+
+import javax.inject.Inject
+import scala.concurrent.ExecutionContext
+
+class AccessLogFilter @Inject() (errorHandler: HttpErrorHandler)(implicit ec: ExecutionContext) extends EssentialFilter {
+
+  val logger: Logger = Logger(getClass)
+
+  override def apply(next: EssentialAction): EssentialAction =
+    (requestHeader: RequestHeader) => {
+      val startTime = System.currentTimeMillis
+      next(requestHeader)
+        .recoverWith { case error => errorHandler.onServerError(requestHeader, error) }
+        .map { result =>
+          val endTime     = System.currentTimeMillis
+          val requestTime = endTime - startTime
+
+          logger.info(
+            s"${requestHeader.remoteAddress} ${requestHeader.method} ${requestHeader.uri} took ${requestTime}ms and returned ${result.header.status} ${result
+              .body
+              .contentLength
+              .fold("")(b => s"$b bytes")}"
+          )
+          result.withHeaders("Request-Time" -> requestTime.toString)
+        }
+    }
+}

app/org/thp/cortex/services/CustomWSAPI.scala

@@ -19,7 +19,7 @@ object CustomWSAPI {
       .parse()
 
   def parseProxyConfig(config: Configuration): Option[WSProxyServer] =
-    config.getOptional[Configuration]("play.ws.proxy").map { proxyConfig ⇒
+    config.getOptional[Configuration]("play.ws.proxy").map { proxyConfig =>
       DefaultWSProxyServer(
         proxyConfig.get[String]("host"),
         proxyConfig.get[Int]("port"),
@@ -35,7 +35,7 @@ object CustomWSAPI {
   def getWS(config: Configuration)(implicit mat: Materializer): AhcWSClient = {
     val clientConfig = parseWSConfig(config)
     val clientConfigWithTruststore = config.getOptional[String]("play.cert") match {
-      case Some(p) ⇒
+      case Some(p) =>
         logger.warn("""Use of "cert" parameter in configuration file is deprecated. Please use:
                       | ws.ssl {
                       |   trustManager = {
@@ -67,7 +67,7 @@ object CustomWSAPI {
                 )
             )
         )
-      case None ⇒ clientConfig
+      case None => clientConfig
     }
     AhcWSClient(clientConfigWithTruststore, None)
   }
@@ -84,13 +84,13 @@ object CustomWSAPI {
 
 @Singleton
 class CustomWSAPI(
-                   ws: AhcWSClient,
-                   val proxy: Option[WSProxyServer],
-                   config: Configuration,
-                   environment: Environment,
-                   lifecycle: ApplicationLifecycle,
-                   mat: Materializer
-                 ) extends WSClient {
+    ws: AhcWSClient,
+    val proxy: Option[WSProxyServer],
+    config: Configuration,
+    environment: Environment,
+    lifecycle: ApplicationLifecycle,
+    mat: Materializer
+) extends WSClient {
   private[CustomWSAPI] lazy val logger = Logger(getClass)
 
   @Inject() def this(config: Configuration, environment: Environment, lifecycle: ApplicationLifecycle, mat: Materializer) =
@@ -110,7 +110,7 @@ class CustomWSAPI(
     try {
       new CustomWSAPI(Configuration(subConfig.underlying.atKey("play").withFallback(config.underlying)), environment, lifecycle, mat)
     } catch {
-      case NonFatal(e) ⇒
+      case NonFatal(e) =>
         logger.error(s"WSAPI configuration error, use default values", e)
         this
     }

app/org/thp/cortex/services/DockerJobRunnerSrv.scala

@@ -50,10 +50,11 @@ class DockerJobRunnerSrv(
       system: ActorSystem
     )
 
-  lazy val logger = Logger(getClass)
+  lazy val logger: Logger = Logger(getClass)
 
   lazy val isAvailable: Boolean =
     Try {
+      logger.debug(s"Retrieve docker information ...")
       logger.info(s"Docker is available:\n${client.info()}")
       true
     }.recover {
@@ -103,6 +104,8 @@ class DockerJobRunnerSrv(
       else containerConfigBuilder.build()
     val containerCreation = client.createContainer(containerConfig)
     //          Option(containerCreation.warnings()).flatMap(_.asScala).foreach(logger.warn)
+
+    logger.debug(s"Container configuration: $containerConfig")
     logger.info(
       s"Execute container ${containerCreation.id()}\n" +
         s"  timeout: ${timeout.fold("none")(_.toString)}\n" +
@@ -119,6 +122,7 @@ class DockerJobRunnerSrv(
       case r =>
         val outputFile = jobDirectory.resolve("output").resolve("output.json")
         if (!Files.exists(outputFile) || Files.size(outputFile) == 0) {
+          logger.warn(s"The worker didn't generate output file, use output stream.")
           val output = Try(client.logs(containerCreation.id(), LogsParam.stdout(), LogsParam.stderr()).readFully())
             .fold(e => s"Container logs can't be read (${e.getMessage})", identity)
           val message = r.fold(e => s"Docker creation error: ${e.getMessage}\n$output", _ => output)