
Hace unos meses, comencé a escribir un generador de perfiles desde cero y, desde entonces, el código se convirtió en la base de mis herramientas de validación de perfiles. El único problema con este proyecto: quería escribir un generador de perfiles adecuado sin sesgo de punto seguro desde cero. Este es un esfuerzo noble, pero requiere mucha programación C/C++/Unix, que es delicada, y no todos pueden leer el código C/C++.
Para las personas que no están familiarizadas con el sesgo de punto seguro: un punto seguro es un punto en el tiempo en el que la JVM tiene un estado definido conocido y todos los subprocesos se han detenido. La propia JVM necesita puntos seguros para realizar las principales recolecciones de elementos no utilizados, definiciones de clases, desoptimizaciones de métodos y más. Los subprocesos verifican regularmente si deben ingresar a un punto seguro, por ejemplo, en la entrada, salida o saltos hacia atrás del método. Un generador de perfiles que solo genera perfiles en un punto seguro tiene un sesgo inherente porque solo incluye marcos de las ubicaciones dentro de los métodos donde los subprocesos verifican un punto seguro. La única ventaja es que el recorrido de pila en puntos seguros es un poco menos propenso a errores, ya que hay menos mutaciones de montón y pila. Para obtener más información, considere leer el excelente artículo. Java Safepoint y perfiles asincrónicos por Seetha Wenner, la uno más técnico de JP Bempelo el artículo clásico Puntos seguros: significado, efectos secundarios y gastos generales por Nitsan Wakart. Para concluir: los generadores de perfiles sesgados de Safepoint no le brindan una visión holística de su aplicación, pero aún pueden ser útiles para analizar los principales problemas de rendimiento donde observa el panorama general.
Esta publicación de blog tiene como objetivo desarrollar un pequeño perfilador de Java en código Java puro que todos puedan entender. Los perfiladores no son ciencia espacial, e ignorando el sesgo de punto seguro, podemos escribir un perfilador utilizable que genere un gráfico de llamas en solo 240 líneas de código.
Puedes encontrar todo el proyecto en GitHub. Siéntase libre de usarlo como base para sus aventuras.
Implementamos el generador de perfiles en un subproceso de daemon iniciado por un agente de Java. Esto nos permite iniciar y ejecutar el perfilador junto con el programa Java que queremos perfilar. Las partes principales del perfilador son:
Comenzamos implementando los puntos de entrada del agente:
public class Main { public static void agentmain(String agentArgs) { premain(agentArgs); } public static void premain(String agentArgs) { Main main = new Main(); main.run(new Options(agentArgs)); } private void run(Options options) { Thread t = new Thread(new Profiler(options)); t.setDaemon(true); t.setName("Profiler"); t.start(); } }
El premain
se llama cuando el agente está conectado a la JVM al principio. Esto es típico porque el usuario pasó el -javagent
a la JVM. En nuestro ejemplo, esto significa que el usuario ejecuta Java con
java -javaagent:./target/tiny_profiler.jar=agentArgs ...
Pero también existe la posibilidad de que el usuario adjunte el agente en tiempo de ejecución. En este caso, la JVM llama al método agentmain
. Para obtener más información sobre el agente de Java, visite el Documentación JDK.
Tenga en cuenta que tenemos que configurar el Premain-Class
y el Agent-Class
atributos en el archivo MANIFEST de nuestro archivo JAR resultante.
Nuestro agente Java analiza los argumentos del agente para obtener las opciones. Las opciones son modeladas y analizadas por la clase Opciones:
public class Options { /** interval option */ private Duration interval = Duration.ofMillis(10); /** flamegraph option */ private Optional<Path> flamePath; /** table option */ private boolean printMethodTable = true; ... }
La parte interesante de la clase Main es su método de ejecución: la clase Profiler implementa la interfaz Runnable para que podamos crear un hilo directamente:
Thread t = new Thread(new Profiler(options));
A continuación, marcamos el subproceso del perfilador como un subproceso daemon; esto significa que la JVM termina al final de la aplicación perfilada incluso cuando el subproceso del perfilador se está ejecutando:
t.setDaemon(true);
No, ya casi terminamos; solo tenemos que empezar el hilo. Antes de hacer esto, le damos un nombre al subproceso, esto no es obligatorio, pero facilita la depuración.
t.setName("Profiler"); t.start();
El muestreo real tiene lugar en la clase Profiler:
public class Profiler implements Runnable { private final Options options; private final Store store; public Profiler(Options options) { this.options = options; this.store = new Store(options.getFlamePath()); Runtime.getRuntime().addShutdownHook(new Thread(this::onEnd)); } private static void sleep(Duration duration) { // ... } @Override public void run() { while (true) { Duration start = Duration.ofNanos(System.nanoTime()); sample(); Duration duration = Duration.ofNanos(System.nanoTime()) .minus(start); Duration sleep = options.getInterval().minus(duration); sleep(sleep); } } private void sample() { Thread.getAllStackTraces().forEach( (thread, stackTraceElements) -> { if (!thread.isDaemon()) { // exclude daemon threads store.addSample(stackTraceElements); } }); } private void onEnd() { if (options.printMethodTable()) { store.printMethodTable(); } store.storeFlameGraphIfNeeded(); }
Comenzamos mirando el constructor. La parte interesante es
Runtime.getRuntime().addShutdownHook(new Thread(this::onEnd));
lo que hace que la JVM llame al Profiler::onEnd
cuando se apaga. Esto es importante ya que el subproceso del generador de perfiles se cancela silenciosamente y todavía queremos imprimir los resultados capturados. Puede leer más sobre los ganchos de apagado en el Documentación de Java.
Después de esto, echamos un vistazo al ciclo de creación de perfiles en el run
método:
while (true) { Duration start = Duration.ofNanos(System.nanoTime()); sample(); Duration duration = Duration.ofNanos(System.nanoTime()) .minus(start); Duration sleep = options.getInterval().minus(duration); sleep(sleep); }
Esto llama el sample
método y duerme el tiempo requerido después, para asegurar que el sample
el método se llama cada interval
(típicamente 10 ms).
El muestreo básico tiene lugar en este sample
método:
Thread.getAllStackTraces().forEach( (thread, stackTraceElements) -> { if (!thread.isDaemon()) { // exclude daemon threads store.addSample(stackTraceElements); } });
Usamos aquí el Thread::getAllStackTraces
método para obtener los rastros de pila de todos los subprocesos. Esto desencadena un punto seguro y es por eso que este generador de perfiles está sesgado por puntos seguros. No tendría sentido tomar los rastros de la pila de un subconjunto de subprocesos, ya que no hay ningún método en el JDK para esto. Llamar a Thread::getStackTrace en un subconjunto de subprocesos activaría muchos puntos seguros, no solo uno, lo que resultaría en una penalización de rendimiento más significativa que obtener los seguimientos para todos los subprocesos.
El resultado de Thread::getAllStackTraces
se filtra para que no incluyamos subprocesos daemon (como el subproceso Profiler o subprocesos Fork-Join-Pool no utilizados). Pasamos los rastros correspondientes a la Tienda, que se ocupa del posprocesamiento.
Esta es la última clase de este generador de perfiles y también, con mucho, el procesamiento posterior, el almacenamiento y la salida de la información recopilada más importantes:
package me.bechberger; import java.io.BufferedOutputStream; import java.io.OutputStream; import java.io.PrintStream; import java.nio.file.Path; import java.util.HashMap; import java.util.List; import java.util.Map; import java.util.Optional; import java.util.stream.Stream; /** * store of the traces */ public class Store { /** too large and browsers can't display it anymore */ private final int MAX_FLAMEGRAPH_DEPTH = 100; private static class Node { // ... } private final Optional<Path> flamePath; private final Map<String, Long> methodOnTopSampleCount = new HashMap<>(); private final Map<String, Long> methodSampleCount = new HashMap<>(); private long totalSampleCount = 0; /** * trace tree node, only populated if flamePath is present */ private final Node rootNode = new Node("root"); public Store(Optional<Path> flamePath) { this.flamePath = flamePath; } private String flattenStackTraceElement( StackTraceElement stackTraceElement) { // call intern to safe some memory return (stackTraceElement.getClassName() + "." + stackTraceElement.getMethodName()).intern(); } private void updateMethodTables(String method, boolean onTop) { methodSampleCount.put(method, methodSampleCount.getOrDefault(method, 0L) + 1); if (onTop) { methodOnTopSampleCount.put(method, methodOnTopSampleCount.getOrDefault(method, 0L) + 1); } } private void updateMethodTables(List<String> trace) { for (int i = 0; i < trace.size(); i++) { String method = trace.get(i); updateMethodTables(method, i == 0); } } public void addSample(StackTraceElement[] stackTraceElements) { List<String> trace = Stream.of(stackTraceElements) .map(this::flattenStackTraceElement) .toList(); updateMethodTables(trace); if (flamePath.isPresent()) { rootNode.addTrace(trace); } totalSampleCount++; } // the only reason this requires Java 17 :P private record MethodTableEntry( String method, long sampleCount, long onTopSampleCount) { } private void printMethodTable(PrintStream s, List<MethodTableEntry> sortedEntries) { // ... } public void printMethodTable() { // sort methods by sample count // the print a table // ... } public void storeFlameGraphIfNeeded() { // ... } }
El generador de perfiles llama al addSample
que aplana los elementos traza de la pila y los almacena en el árbol de trazas (para el gráfico de llama) y cuenta las trazas de las que forma parte cualquier método.
La parte interesante es el árbol de seguimiento modelado por la clase Nodo. La idea es que cada rastro A -> B -> C
(A
llamadas B
, B
llamadas C
, [C, B, A]
) cuando lo devuelve la JVM) se puede representar como un nodo raíz con un nodo secundario A
con niño B
con niño C
, de modo que cada rastro capturado sea una ruta desde el nodo raíz hasta una hoja. Contamos cuantas veces un nodo forma parte de la traza. Esto se puede usar para generar la estructura de datos de árbol para d3-flame-graph que usamos para crear agradables flamegraphs como:
Tenga en cuenta que la clase de Nodo real es la siguiente:
private static class Node { private final String method; private final Map<String, Node> children = new HashMap<>(); private long samples = 0; public Node(String method) { this.method = method; } private Node getChild(String method) { return children.computeIfAbsent(method, Node::new); } private void addTrace(List<String> trace, int end) { samples++; if (end > 0) { getChild(trace.get(end)).addTrace(trace, end - 1); } } public void addTrace(List<String> trace) { addTrace(trace, trace.size() - 1); } /** * Write in d3-flamegraph format */ private void writeAsJson(PrintStream s, int maxDepth) { s.printf("{ \"name\": \"%s\", \"value\": %d, \"children\": [", method, samples); if (maxDepth > 1) { for (Node child : children.values()) { child.writeAsJson(s, maxDepth - 1); s.print(","); } } s.print("]}"); } public void writeAsHTML(PrintStream s, int maxDepth) { s.print(""" <head> <link rel="stylesheet" type="text/css" href="https://cdn.jsdelivr.net/npm/d3-flame-graph@4.1.3/dist/d3-flamegraph.css"> </head> <body> <div id="chart"></div> <script type="text/javascript" src="https://d3js.org/d3.v7.js"></script> <script type="text/javascript" src="https://cdn.jsdelivr.net/npm/d3-flame-graph@4.1.3/dist/d3-flamegraph.min.js"></script> <script type="text/javascript"> var chart = flamegraph().width(window.innerWidth); d3.select("#chart").datum("""); writeAsJson(s, maxDepth); s.print(""" ).call(chart); window.onresize = () => chart.width(window.innerWidth); </script> </body> """); } }
Llamé al generador de perfiles final tiny-profiler y sus fuentes están en GitHub (con licencia del MIT). El generador de perfiles debería funcionar en cualquier plataforma con un JDK 17 o posterior. El uso es bastante simple:
# build it mvn package # run your program and print the table of methods sorted by their sample count # and the flame graph, taking a sample every 10ms java -javaagent:target/tiny-profiler.jar=flamegraph=flame.html ...
Puede ejecutarlo fácilmente en el punto de referencia del renacimiento y crear el gráfico de llamas que se muestra anteriormente:
# download a benchmark > test -e renaissance.jar || wget https://github.com/renaissance-benchmarks/renaissance/releases/download/v0.14.2/renaissance-gpl-0.14.2.jar -O renaissance.jar > java -javaagent:./target/tiny_profiler.jar=flamegraph=flame.html -jar renaissance.jar dotty ... ===== method table ====== Total samples: 11217 Method Samples Percentage On top Percentage dotty.tools.dotc.typer.Typer.typed 59499 530.44 2 0.02 dotty.tools.dotc.typer.Typer.typedUnadapted 31050 276.81 7 0.06 scala.runtime.function.JProcedure1.apply 24283 216.48 13 0.12 dotty.tools.dotc.Driver.process 19012 169.49 0 0.00 dotty.tools.dotc.typer.Typer.typedUnnamed$1 18774 167.37 7 0.06 dotty.tools.dotc.typer.Typer.typedExpr 18072 161.11 0 0.00 scala.collection.immutable.List.foreach 16271 145.06 3 0.03 ...
La sobrecarga para este ejemplo es de alrededor del 2 % en mi MacBook Pro 13″ durante un intervalo de 10 ms, lo que hace que el generador de perfiles sea utilizable cuando ignora el sesgo de punto seguro.
Es posible escribir un perfilador de Java en 240 líneas de Java puro y el perfilador resultante podría incluso usarse para analizar problemas de rendimiento. Este generador de perfiles no está diseñado para reemplazar a los generadores de perfiles reales como async-profiler, pero desmitifica el funcionamiento interno de los generadores de perfiles simples.
Espero que hayas disfrutado de esta publicación de blog cargada de código. Como siempre, estoy feliz por cualquier comentario, problema o relaciones públicas.
Esta entrada de blog es parte de mi trabajo en el máquina savia equipo en SAVIAhaciendo que la creación de perfiles sea más fácil para todos. Partes significativas de esta publicación se han escrito debajo del canal en inglés…
Calle Eloy Gonzalo, 27
Madrid, Madrid.
Código Postal 28010
Paseo de la Reforma 26
Colonia Juárez, Cuauhtémoc
Ciudad de México 06600
Real Cariari
Autopista General Cañas,
San José, SJ 40104
Av. Jorge Basadre 349
San Isidro
Lima, LIM 15073