java - starter - play framework seed
Código de manejo de solicitud de marco de juego extremadamente lento 2.3 (1)
Entonces, después de un mes, finalmente puedo decir que este problema está resuelto. Y la respuesta es que no hay ningún problema. La nueva instrumentación por defecto de reliquia no informa correctamente el tiempo consumido por las transacciones de Play Framework 2 y podría decirse por cualquier marco asíncrono que se ejecute en Netty.
Para llegar a esa conclusión, tuve que incluir algunas métricas personalizadas para las transacciones más problemáticas solo para descubrir que mi instrumentación personalizada usa mucho menos tiempo del reportado por la nueva reliquia.
Después de eso, probé en el cliente usando firebug y los tiempos informados coincidían con mis métricas personalizadas.
Hace solo una semana descubrí esta publicación en foros newrelic:
Y después de desactivar toda la instrumentación para netty, akka y jugar con estas líneas en el archivo newrelic de configuración, finalmente comencé a obtener tiempos realistas con la instrumentación predeterminada:
common: &default_settings
class_transformer:
# Disable all Akka instrumentations
com.newrelic.instrumentation.akka-2.0:
enabled: false
com.newrelic.instrumentation.akka-2.1:
enabled: false
com.newrelic.instrumentation.akka-2.2:
enabled: false
# Disable all Netty instrumentations
com.newrelic.instrumentation.netty-3.4:
enabled: false
com.newrelic.instrumentation.netty-3.8:
enabled: false
com.newrelic.instrumentation.netty-4.0.0:
enabled: false
com.newrelic.instrumentation.netty-4.0.8:
enabled: false
# Disable all Play 2 instrumentations
com.newrelic.instrumentation.play-2.1:
enabled: false
com.newrelic.instrumentation.play-2.2:
enabled: false
com.newrelic.instrumentation.play-2.3:
enabled: false
# New in Release 3.22, the Play 2.4 instrumentation does not respect
# the older play2_instrumentation configuration setting
com.newrelic.instrumentation.play-2.4:
enabled: false
# Disable all Scala-language instrumentations
com.newrelic.instrumentation.scala-2.9.3:
enabled: false
En newrelic documentations dice:
Puede optar por deshabilitar parte o la totalidad de esta instrumentación si encuentra que las métricas informadas no son valiosas para usted, o si la instrumentación incurre en más sobrecarga de la que le gustaría. Si desactiva selectivamente parte de la instrumentación, algunos segmentos de actividad no serán informados y su tiempo total será subestimado.
Pero en mi humilde opinión debería decir:
Puede optar por desactivar TODA esta instrumentación si desea obtener métricas realistas.
¿Por qué este comportamiento? Solo puedo adivinar que Play y Netty reutilizan algunos hilos en un pool por muchas transacciones y el agente newrelic no puede separar correctamente el tiempo que consume la base de datos y netty, duplicar y, a veces, triplicar los tiempos reales consumidos por la aplicación.
Este problema engañó drásticamente a mi equipo (y a los patrocinadores del proyecto). No culpo totalmente a Newrelic, esta herramienta es útil, pero esto me dejó como una lección para no confiar solo en una herramienta.
Me estoy enfrentando a un rendimiento extremadamente lento de los métodos:
HttpRequestDecoder.unfoldAndFireMessageReceived()
y
Future$PromiseCompletingRunnable.run()
Estos dos métodos utilizan alrededor de la mitad del tiempo de cada transacción en el servidor. Sucede bajo bajo rendimiento y durante horas de alto uso.
Por ejemplo, a la 1 a.m. con solo yo haciendo solicitudes a la aplicación, obtengo gráficos en una nueva reliquia como estos:
En esta transacción, solo esos dos métodos consumen 1 segundo completo, ¡incluso más lento que el acceso a la base de datos a través de Hibernate! Una vez más, solo un usuario en la aplicación.
Si la transacción es más pesada, toma aún más tiempo:
En este caso, estos dos métodos consumen un promedio de 2.5 segundos cuando mi propio código consume 1.5 segundos, dando un total de 4 segundos. Creo en ese momento que tal vez esto era solo una nueva métrica reliquia engañosa. Quizás newrelic estaba mostrando los nombres de estos métodos, pero en realidad fue un código escrito por mí. Así que decidí obtener una métrica personalizada como esta:
playController(){
//Start timer
//do the job
//stop the timer() and send metric to new relic
//return;
}
Y el resultado fue que mi código tardaba 1.5 segundos. Entonces, realmente es el manejador de solicitudes de juego el que está consumiendo esta vez.
Este comportamiento está matando mi aplicación cuando tengo una carga alta. Estos dos métodos pueden consumir hasta 20 segundos cuando el flujo de audio es de alrededor de 500 solicitudes por minuto (¡no es realmente un alto rendimiento!) Pero mi código se mantiene estable en un máximo de 3 segundos.
Realmente no creo que esto sea un problema de subprocesos, porque incluso ocurre cuando hay un solo usuario, pero se vuelve realmente problemático cuando hay muchas solicitudes simultáneas. Traté de cambiar el número de subprocesos para "aplicaciones sincrónicas", como la mención de documentación, pero no obtuve ningún cambio de rendimiento, incluso empeoró.
Estoy realmente preocupado por este problema porque hay un caso similar en las listas de distribución de correo con más de dos años sin respuesta.
Incluso hay una pregunta similar en StackOverflow pero para play 2.1 sin respuesta y sin actividad aparent:
Transacciones lentas en NewRelic teniendo Play Framework como backend
¿Alguna idea de lo que puede estar causando este comportamiento?