juegos - Java vm se ralentiza con todos los hilos ocupados con operaciones de cadena
juegos con hilos en java (9)
Me encuentro con un problema muy peculiar. Mi tomcat funciona perfectamente con aproximadamente un 25% de CPU 24/7, pero algunos días mi CPU dispara hasta un 60% y el sistema se detiene y no se recupera.
Cuando tomo un volcado de hilo durante la ralentización, casi todos los hilos están ocupados con algún tipo de String u operación relacionada.
No hay errores de OutOfMemory ni se lanzan excepciones, todas las solicitudes se siguen manejando pero los tiempos de respuesta se deterioran hasta el enésimo grado donde incluso una solicitud de segundo por segundo se ralentiza para tomar 60 segundos y más.
Mi configuración del servidor es la siguiente:
Ubuntu 12.04.2 LTS Linux 3.2.0-38-virtual #60-Ubuntu SMP x86_64 x86_64 x86_64 GNU/Linux
java version "1.7.0_13" Java(TM) SE Runtime Environment (build 1.7.0_13-b20) Java HotSpot(TM) 64-Bit Server VM (build 23.7-b01, mixed mode)
export JAVA_OPTS=''-server -Xms18g -Xmx18g -XX:MaxPermSize=512m -XX:ThreadStackSize=512 -XX:NewRatio=1 -XX:SurvivorRatio=4 -XX:+UseConcMarkSweepGC -XX:+UseParNewGC -XX:+CMSClassUnloadingEnabled -Xloggc:/usr/tomcat/logs/gc.log -XX:+PrintGCDetails -XX:+PrintGCDateStamps -XX:+PrintTenuringDistribution -Dcom.sun.management.jmxremote -Dcom.sun.management.jmxremote.port=9999 -Dcom.sun.management.jmxremote.authenticate=false -Dcom.sun.management.jmxremote.ssl=false -Djava.awt.headless=true''
Haga clic aquí para descargar el volcado de hilo. He eliminado la mayor parte de los hilos y sus stackTraces
Haga clic aquí para descargar el registro vmstat
Haga clic aquí para descargar el registro de gc
¿Alguna idea sobre la causa de esto? Gracias
¿Hay alguna anomalía en el registro de GC? Parece que estás ejecutando un gran montón con algunas opciones inusuales y haces muchas cosas asignando String. Tal vez sufra la fragmentación de Heap con el tiempo (CMS no se compacta). Además, asegúrese de que no se produzca ningún intercambio (puede suceder si el montón es demasiado grande, por lo que rara vez lo visita VM).
Sospecho que esto está relacionado con GC, ya que aparentemente no hay ningún hilo bloqueado. ¿Has probado con un JDK más reciente? También podría intentar de nuevo, pero eliminar una opción algo poco común -XX: + CMSScavengeBeforeRemark, porque es posible que no tengan mucha cobertura de prueba con cada versión menor de JDK.
Otra sospecha podrían ser las solicitudes entrantes que usan caracteres extraños (cirílicos o árabes) que conducen a una sobrecarga de mapeo masivo de Charset. También verifica si hay algún robot en tu página, ¿hay solicitudes sospechosas? Definitivamente necesita stacktraces más largos para descubrir la operación raíz de la manipulación de cadenas.
Creo que su problema es esta decisión de configuración -XX:PermSize=320m -XX:MaxPermSize=320m
al no permitir que su PemSpace cambie dinámicamente, está causando un punto muerto cuando lo agota. Recuerde que el caché interno usa PermSpace. Intentaría cambiar -XX:MaxPermSize=320m
a -XX:MaxPermSize=512m
.
Después de haber escaneado a través del volcado de hilo mirando los hilos RUNNABLE, una cosa se destaca. Su sistema parece estar procesando / tratando de procesar una gran cantidad de solicitudes al mismo tiempo. Y a menos que tenga un número de núcleos, es probable que haya mucho tiempo rebanando. Por otro lado, no veo clara >> evidencia << que esto esté relacionado con GC. (Pero no incluiste los registros del GC ...)
Sugiero que mires dos cosas.
- Mire las estadísticas de la memoria virtual del sistema operativo. Una causa posible de la ralentización catastrófica del sistema es la agitación de la memoria virtual. Aquí es donde la demanda total de aplicaciones para páginas de memoria virtual excede la memoria física disponible ... y el sistema operativo pasa mucho tiempo intercambiando páginas entre la memoria física y el disco de intercambio / archivo de página.
- Mire el patrón de solicitudes que está recibiendo. Podría ser que en ciertos momentos el número / tipo de solicitudes que recibe simplemente exceda la capacidad de su sistema.
Si el problema es la expansión de VM, entonces la solución es reducir la demanda de memoria de la aplicación. La forma más sencilla de hacerlo es reducir el tamaño del montón de Java.
Si el problema es la carga, entonces es más difícil de resolver:
- Podría intentar reforzar su hardware (o agregar más VCPU a su virtual).
- Podría intentar distribuir la carga en varias instancias de su servidor.
- Podría intentar reducir el número de subprocesos de trabajo para que su servidor no intente gestionar tantas solicitudes a la vez.
- Podría intentar perfilar la aplicación y / o analizar las estadísticas de solicitud para ver si hay zonas activas que podrían ajustarse o una funcionalidad costosa que podría desactivarse ...
Finalmente, podría ver si ayuda cambiar de CMS a Parallel Collector; consulte la página de ajuste de Oracle GC: Colectores disponibles . Pero dudo que este sea un problema de GC.
Esto no es un problema de memoria, ya que en su volcado el GC no está ocupado y hay suficiente memoria disponible. Además, la CPU está atascada en un 60%, pero si la aplicación estuviera ocupada calculando (GC u otra cosa) estaría bloqueada al 100%, lo mismo si se tratara de un ataque de red. Entonces, el origen de este problema debe incluir alguna operación de disco-IO.
Se sabe que Tomcat tiene errores y tiene varios problemas graves. Una cosa que encontré es que sin ninguna razón en particular, Tomcat repentinamente inundó su propio archivo de registro con entradas sin sentido. Esto no solo causó que el disco se llene al 100%, sino que redujo drásticamente las solicitudes entrantes. Puede verificar esto echando un vistazo a los registros de tomcat y su tamaño.
Si esta no es la fuente, debe usar las herramientas disponibles para verificar si hay algún disco extraño IO de Tomcat y continuar desde allí.
Intente aumentar el tamaño máximo de la memoria caché de código con la siguiente opción de JVM:
-XX:ReservedCodeCacheSize=256m
Ver mi respuesta a otra pregunta para el contexto de esta sugerencia.
Lo primero que debe hacer es averiguar qué hilos consumen realmente la CPU. Podrían ser los subprocesos que al realizar operaciones de cadena o podría ser otro subproceso de máquina virtual que puede realizar operaciones de GC y barrido. El enlace dice cómo relacionar conjuntamente los picos de CPU con el volcado de subprocesos
Una vez que pueda apuntar los hilos, sería más claro en cuanto a lo que debería ser el próximo paso adelante.
Espero que esto ayude
Para tratar de identificar las solicitudes ofensivas, puede configurar la válvula de detección de rosca atascada en Tomcat.
Esta válvula permite detectar solicitudes que tardan mucho tiempo en procesarse, lo que puede indicar que el hilo que lo está procesando está atascado.
Cuando se detecta una solicitud de este tipo, la traza actual de la pila de su cadena se escribe en el registro de Tomcat con un nivel WARN.
Los ID y los nombres de los hilos atascados están disponibles a través de JMX en los atributos stuckThreadIds y stuckThreadNames. Los identificadores se pueden usar con el MBean estándar de Threading JVM (java.lang: type = Threading) para recuperar otra información sobre cada thread bloqueado.
Si la utilización de la CPU es inferior al 100% y la aplicación se detiene, esto implica que algo impide que la CPU se utilice por completo.
La E / S o el cambio excesivo de contexto (por ejemplo, causado por bloqueos) son los culpables habituales de esto.
¿Puedes publicar el resultado de vmsstat 1 durante uno de los eventos? - El próximo paso en el diagnóstico es eliminar la ambigüedad si el cambio de contexto es el problema aquí.
BTrace usar BTrace diagnosticar el método de invocación.
Escriba un script de brecha como este:
Traza la clase de prefijo com.xx.xx
que invoca cualquier método de String e imprime los tiempos de invocación.
@TLS
private static Map<String, Integer> countMap = BTraceUtils.newHashMap();
private static String prefix = "com.xx.xx";// package like com.xx.xx which you want to trace ()
@OnMethod(clazz = "java.lang.String", method = "/.*/") //all method in String
public static void traceMethodInvoke() {
String str = BTraceUtils.jstackStr();
for (String currentClass : str.split("//n")) {
if (BTraceUtils.Strings.startsWith(currentClass, prefix)) {
if (!countMap.containsKey(currentClass)) {
countMap.put(currentClass, 1);
} else {
countMap.put(currentClass, countMap.get(currentClass) + 1);
}
break;
}
}
}
@OnTimer(5000)
public static void print() {
BTraceUtils.println("========================================");
for (Map.Entry<String, Integer> entry : countMap.entrySet()) {
if (entry.getValue() > 100) {// print if cont > 10
BTraceUtils.println(entry.getValue() + "/t/t" + entry.getKey());
}
}
BTraceUtils.println("===========================================");
}
El resultado es como este:
====================================================
1022 com.xx.xx.classA#m1
322 com.xx.xx.classA#m2
2022 com.xx.xx.classA#m21
422 com.xx.xx.ccc.classX#m11
522 com.xx.xx.zz.classS#m44
.........
Puede cambiar el prefix
para rastrear otro prefijo del paquete.
Según el resultado, puede analizar el código fuente y descubrir los problemas.