Stackdriver-Protokollierungsprotokolle sind in GAE SE für Java 8 falsch ausgerichtet

Wenn Sie während der asynchronen Verarbeitung mit einer Anwendung in der Google AppEngine Standard Environment für Java8 ein Protokoll ausgeben, Es ist eine Geschichte, die gegen das Problem gekämpft hat, dass das Protokoll nicht korrekt mit der Anforderung verknüpft ist und als Protokoll einer anderen Anforderung ausgegeben wird, die zu detailliert ist, um übertragen zu werden.

Die Sprache ist Scala und Skinny Micro wird verwendet.

Zusammenfassung

Erste Schlussfolgerung. GAE sollte "ThreadManager.createThreadForCurrentRequest" anstelle eines eigenen Threads verwenden. Wenn Ihnen die Protokollverschiebung in der Stackdriver-Protokollierung nichts ausmacht, lassen Sie es uns gefallen.

Informationen zu den erforderlichen Informationen

GAE SE for java8?

Es wurde im September 2017 allgemein verfügbar. Google Cloud Platform Blog: Java 8 on App Engine standard environment is now generally available

Protokollausgabe mit GAE SE

Es gibt offizielle Unterlagen. Reading and Writing Application Logs

Demnach sollten Sie die Protokolleinstellungen in logging.properties beschreiben, während Sie das Protokoll mit java.util.logging ausgeben. Wenn Sie slf4j verwenden, können Sie SLF4J JDK14 Binding verwenden.

Verwenden Sie einfach "java.util.logging", um das Protokoll auszugeben, ohne sich darum zu kümmern, und es wird in der Stackdriver-Protokollierung gut angezeigt. Mit GAE SE ist diese Art von Bereich sehr praktisch.

Was bedeutet es, dass die Protokollausgabe ausgeschaltet ist?

Wenn Sie Ihren eigenen Thread verwenden und sich abmelden, wird dieser als Protokoll für eine andere Anforderung ausgegeben. Die Stackdriver-Protokollierung verfügt über eine Funktion, mit der Protokolle für jede Anforderung erfasst werden. Sie können die Protokolle für jede Anforderung anzeigen (siehe Abbildung unten).

• Die Anfrage wird dreimal in der Reihenfolge / sample / myEc → / sample / threadManagerEc → / sample / myEc gesendet.

• ↓ Protokollausgabe bei der ersten Anforderung an / sample / myEc

• ↓ Protokollausgabe der zweiten Anforderung an / sample / threadManagerEc

• ↓ Protokollausgabe der dritten Anforderung an / sample / myEc

Kurz gesagt, das Protokoll, das in der Anforderung an "/ sample / myEc" ausgegeben werden soll, wird als das einer anderen Anforderung "/ sample / threadManagerEc" behandelt.

Code

Der Code, der das Protokoll verschiebt, sieht folgendermaßen aus. Wie oben erwähnt, lautet die Sprache Scala und es wird Skinny Micro verwendet.

Es ist ein bisschen lang, aber ich habe das Ganze draufgelegt.

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}

//Fallklasse für von json empfangene Parameter
case class Param(text: String) extends AnyVal

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

  //Gemeinsame Verarbeitung als Controller
  private def _run(executionContext: ExecutionContext)(implicit ctx: SkinnyContext) = {
    log.info(s"[START]${LocalDateTime.now()} Thread: ${Thread.currentThread().getId}")
    
    // Future.Asynchrone Verarbeitung mit Übernehmen
    val resF: Future[String] = Future.apply {
      log.info(s"[Future-START]${LocalDateTime.now()} Thread: ${Thread.currentThread().getId}")
      Thread.sleep(1000)
      //Vom Text zum Text der Anfrage=Holen Sie sich den Parameter 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)  //Geben Sie ExecutionContext explizit an
    
    //Treffen Sie die Zukunft
    val result = Await.result(resF, Duration.apply(3000, TimeUnit.MILLISECONDS))     
    log.info(s"[END]${LocalDateTime.now()} Thread: ${Thread.currentThread().getId}")
    result
  }

  //ExecutionContext mit eigenem Thread-Pool
  private val myExecutionContext: ExecutionContext =
    ExecutionContext.fromExecutor(Executors.newFixedThreadPool(3))

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

  //ExecutionContext mit 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)
  }
}

Der Grund, warum Await.result den Wert von Future abruft, ist, dass Async nicht vom Steg der GAE SE unterstützt wird. Servlet asynchronous processing support in App Engine Java 8 standard environment - Stack Overflow

Ursache der Protokollverschiebung

Verursacht durch "ExecutionContext", dh den für die asynchrone Verarbeitung verwendeten Thread.

Das Folgende ist eine Zusammenfassung des in ↑ um ExecutionContext beschriebenen Codes.

• Der Pfad / sample / myEc bereitet seinen eigenen Thread-Pool vor und generiert daraus ExecutionContext.
• Im Pfad "/ sample / threadManagerEc" wird "ThreadManager.createThreadForCurrentRequest" verwendet, um "ExecutionContext" zu erstellen.

Es stellt sich heraus, dass das Protokoll für den Thread, der ohne Verwendung von "ThreadManager" erstellt wurde, deaktiviert ist.

Dokumentation zu Threads

Dies ist die Java 7-Dokumentation für Thread. Java 7 Runtime Environment

Und dies ist die Dokumentation für die Java 8-Ära. Java 8 Runtime Environment Klicken Sie hier, um die Dokumentunterschiede zwischen Java 7 und 8 anzuzeigen.

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().

Grundsätzlich können Sie Threads wie "new Thread ()" frei generieren und verwenden. Und die Fortsetzung

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.

Es heißt, dass Sie "ThreadManager" verwenden sollten, wenn Sie die AppEngine-API verwenden. Die Stackdriver-Protokollierung ist ebenfalls ein GCP-Dienst, sodass sie intern auf die AppEngine-API trifft. Daher funktioniert sie wahrscheinlich nicht wie erwartet, es sei denn, es handelt sich um einen von "ThreadManager" verwalteten Thread.

Davon

• Ich möchte, dass die Stackdriver-Protokollierung das Protokoll korrekt ausgibt --Verwenden Sie den von ThreadManager verwalteten Thread als Thread für die asynchrone Verarbeitung. ――Ich mache mir ein wenig Sorgen um die Leistung, weil ich es jedes Mal schaffen muss (ich habe kein Benchmarking durchgeführt). --Stackdriver Logging spielt keine Rolle ――Lass uns Threads (Pool) machen, wie du willst
• Die Leistungsabstimmung sollte einfach sein, da Sie die Anzahl der Gewinde frei einstellen können.

Es kommt zum Schluss.