Les journaux Stackdriver Logging ne sont pas alignés dans GAE SE pour Java 8

Si vous générez un journal lors d'un traitement asynchrone avec une application sur l'environnement standard Google AppEngine pour Java8, C'est une histoire qui a combattu le problème que le journal n'est pas correctement lié à la demande et est sorti comme le journal d'une autre demande, qui est trop détaillé pour être transmis.

Le langage est Scala et Skinny Micro est utilisé.

Résumé

Première conclusion. GAE doit utiliser ThreadManager.createThreadForCurrentRequest au lieu de son propre thread. Si le changement de journal dans Stackdriver Logging ne vous dérange pas, aimons-le.

À propos des informations préalables

GAE SE for java8?

Il est devenu généralement disponible en septembre 2017. Google Cloud Platform Blog: Java 8 on App Engine standard environment is now generally available

Sortie de journal avec GAE SE

Il existe une documentation officielle. Reading and Writing Application Logs

D'après cela, il semble que vous deviez décrire les paramètres du journal dans logging.properties lors de la sortie du journal en utilisant java.util.logging. Si vous utilisez slf4j, vous pouvez utiliser SLF4J JDK14 Binding.

Utilisez simplement java.util.logging pour générer le journal sans vous en soucier, et il s'affichera bien dans Stackdriver Logging. Avec GAE SE, ce type de zone est très pratique.

Qu'est-ce que cela signifie que la sortie du journal est désactivée?

Si vous utilisez votre propre Thread et que vous vous déconnectez, il sera affiché sous forme de journal pour une autre demande. Stackdriver Logging dispose d'une fonction qui collecte les journaux pour chaque demande, et vous pouvez voir les journaux pour chaque demande, comme illustré dans l'image ci-dessous.

La requête est envoyée 3 fois dans l'ordre de / sample / myEc → / sample / threadManagerEc → / sample / myEc.

↓ Enregistrer la sortie de la première requête à / sample / myEc

↓ Journalise la sortie de la deuxième requête vers / sample / threadManagerEc

↓ Enregistrer la sortie de la troisième requête vers / sample / myEc

En bref, le journal qui doit être généré dans la requête vers / sample / myEc est traité comme celui d'une autre requête / sample / threadManagerEc.

code

Le code qui déplace le journal ressemble à ceci. Comme mentionné ci-dessus, le langage est Scala et Skinny Micro est utilisé.

C'est un peu long, mais je mets le tout dessus.

import java.time.LocalDateTime
import java.util.concurrent.{Executors, TimeUnit}

import com.google.appengine.api.ThreadManager
import skinny.micro.AsyncWebApp
import skinny.micro.context.SkinnyContext
import skinny.micro.contrib.json4s.JSONSupport

import scala.concurrent.duration.Duration
import scala.concurrent.{Await, ExecutionContext, Future}

//Classe de cas pour les paramètres reçus par json
case class Param(text: String) extends AnyVal

class SampleController extends AsyncWebApp with JSONSupport {
  private lazy val log = org.slf4j.LoggerFactory.getLogger(getClass)

  //Traitement commun en tant que contrôleur
  private def _run(executionContext: ExecutionContext)(implicit ctx: SkinnyContext) = {
    log.info(s"[START]${LocalDateTime.now()} Thread: ${Thread.currentThread().getId}")
    
    // Future.Traitement asynchrone avec apply
    val resF: Future[String] = Future.apply {
      log.info(s"[Future-START]${LocalDateTime.now()} Thread: ${Thread.currentThread().getId}")
      Thread.sleep(1000)
      //Du corps au texte de la demande=Obtenez le paramètre qui est xxx
      val param = fromJSONString[Param](request.body).get
      log.info(s"$requestPath param: $param")
      log.info(s"[Future-END]${LocalDateTime.now()} Thread: ${Thread.currentThread().getId}")
      param.toString
    }(executionContext)  //Spécifiez explicitement ExecutionContext
    
    //Rencontrez le futur
    val result = Await.result(resF, Duration.apply(3000, TimeUnit.MILLISECONDS))     
    log.info(s"[END]${LocalDateTime.now()} Thread: ${Thread.currentThread().getId}")
    result
  }

  //ExecutionContext avec son propre pool de threads
  private val myExecutionContext: ExecutionContext =
    ExecutionContext.fromExecutor(Executors.newFixedThreadPool(3))

  post("/sample/myEc") { implicit ctx =>
    _run(myExecutionContext)
  }

  //ExecutionContext à l'aide de ThreadManager
  private val threadManagerExecutionContext: ExecutionContext = new ExecutionContext {
    override def execute(runnable: Runnable): Unit =
      ThreadManager.createThreadForCurrentRequest(runnable).run()
    override def reportFailure(cause: Throwable): Unit =
      ExecutionContext.defaultReporter
  }

  post("/sample/threadManagerEc") { implicit ctx =>
    _run(threadManagerExecutionContext)
  }
}

ʻAwait.result récupère la valeur de Future` car async n'est pas pris en charge par la jetée GAE SE. Servlet asynchronous processing support in App Engine Java 8 standard environment - Stack Overflow

Cause du décalage du journal

ʻExecutionContext`, c'est-à-dire le thread utilisé pour le traitement asynchrone.

Ce qui suit est un résumé du code décrit dans ↑ autour de ʻExecutionContext`.

Le chemin / sample / myEc prépare son propre pool de threads et l'utilise pour générer ʻExecutionContext. --Dans le chemin / sample / threadManagerEc, ThreadManager.createThreadForCurrentRequest est utilisé pour créer ʻExecutionContext.

Il s'avère que le journal du thread créé sans utiliser ThreadManager est désactivé.

Documentation sur les threads

Ceci est la documentation Java 7 pour Thread. Java 7 Runtime Environment

Et voici la documentation de l'ère Java 8. Java 8 Runtime Environment Cliquez ici pour les différences de document entre Java 7 et 8.

With the Java 8 runtime, you can still create threads that way, but you can also use Java's built-in APIs, for example new Thread().

Donc, fondamentalement, vous pouvez librement générer et utiliser Thread comme new Thread (). Et la suite

Currently, if you want to call App Engine APIs (com.google.appengine.api.*), you must call those APIs from a request thread or from a thread created using the ThreadManager API.

Il indique que vous devez utiliser ThreadManager lorsque vous utilisez l'API AppEngine. Stackdriver Logging est également un service GCP, il atteint donc l'API AppEngine en interne, il ne fonctionnera donc probablement pas comme prévu à moins qu'il ne s'agisse d'un thread géré par ThreadManager.

De cela

--Je souhaite que Stackdriver Logging génère correctement le journal --Utilisez le thread géré par ThreadManager comme thread utilisé pour le traitement asynchrone.

Je suis un peu inquiet pour les performances car je dois y arriver à chaque fois (je n'ai pas fait de benchmark) --Stackdriver Logging n'a pas d'importance ――Faisons des threads (pool) comme vous le souhaitez
Le réglage des performances devrait être facile car vous pouvez ajuster librement le nombre de threads.

Il arrive à la conclusion.