Leistungsprobleme sind für Ingenieure immer ein Problem. Es gibt verschiedene Arten der langsamen Verarbeitung. Wenn ein Prozess einfach schwerer als der Schwellenwert ist oder weil es sich um eine Charge handelt, ist jeder Prozess nicht so langsam, aber aufgrund von Chiritsumo langsam. Insbesondere letzteres ist ziemlich schwer zu identifizieren. Selbst wenn Sie Flight Recorder verwenden, ist es ziemlich schwierig herauszufinden, wo es für einfaches Java langsam ist, und die Einführung von APM in vollem Umfang ist in der Regel eine große Sache.
Diesmal habe ich versucht zu prüfen, ob ich mit AspectJ langsame Methoden verfolgen kann. Den Beispielcode erhalten Sie aus dem Folgenden. https://github.com/koduki/example-aspectj
AspectJ ist eine Java-Bibliothek zum Erreichen von AOP und Aspektorientierung. Grob gesagt ist es "eine Methode, um Querschnittsthemen (Aspekte) in mehrere Bereiche wie Protokollierung und Berechtigungsprüfung in die vorhandene Verarbeitung einzubetten". Es war sehr beliebt als Methode, um die Objektorientierung für eine Weile zu ergänzen, aber es scheint, dass ich heutzutage nicht viel sage. Dies kann daran liegen, dass die FW und dergleichen für die im Beispiel genannten Dinge gut sind, sodass es sich nicht mehr um einen Bereich handelt, den einzelne Ingenieure interessieren.
Dieses Mal werde ich versuchen, Protokolle auszugeben, indem ich einen Aspekt der "Protokollierung langsamer Methoden" erstelle, ohne die vorhandene Verarbeitung des Messziels zu ändern.
Grundsätzlich können Sie mit normalem Java-Code entwickeln, sodass Sie problemlos mit der Entwicklung mit NetBeans + Maven beginnen können. pom.xml sieht so aus. Beachten Sie, dass sowohl das Plugin als auch die Abhängigkeit hinzugefügt werden müssen.
<?xml version="1.0" encoding="UTF-8"?>
<project xmlns="http://maven.apache.org/POM/4.0.0" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xsi:schemaLocation="http://maven.apache.org/POM/4.0.0 http://maven.apache.org/xsd/maven-4.0.0.xsd">
<modelVersion>4.0.0</modelVersion>
<groupId>cn.orz.pascal</groupId>
<artifactId>example-aspectj</artifactId>
<version>0.1</version>
<packaging>jar</packaging>
<properties>
<project.build.sourceEncoding>UTF-8</project.build.sourceEncoding>
<maven.compiler.source>1.8</maven.compiler.source>
<maven.compiler.target>1.8</maven.compiler.target>
</properties>
<dependencies>
<dependency>
<groupId>org.aspectj</groupId>
<artifactId>aspectjrt</artifactId>
<version>1.8.13</version>
</dependency>
</dependencies>
<build>
<plugins>
<plugin>
<groupId>org.apache.maven.plugins</groupId>
<artifactId>maven-dependency-plugin</artifactId>
<version>3.0.2</version>
<executions>
<execution>
<goals>
<goal>build-classpath</goal>
</goals>
<configuration>
<outputProperty>aspectj-weaver-path</outputProperty>
<includeGroupIds>org.aspectj</includeGroupIds>
<includeArtifactIds>aspectjweaver</includeArtifactIds>
</configuration>
</execution>
</executions>
</plugin>
<plugin>
<groupId>org.codehaus.mojo</groupId>
<artifactId>aspectj-maven-plugin</artifactId>
<version>1.11</version>
<dependencies>
<dependency>
<groupId>org.aspectj</groupId>
<artifactId>aspectjtools</artifactId>
<version>1.8.13</version>
</dependency>
</dependencies>
<executions>
<execution>
<goals>
<goal>compile</goal>
</goals>
<configuration>
<complianceLevel>1.8</complianceLevel>
<outxml>true</outxml>
</configuration>
</execution>
</executions>
</plugin>
</plugins>
</build>
</project>
Erstellen Sie den Aspekt weiter. Sie können es jedoch als Java-Klasse schreiben, indem Sie "@ Aspect" hinzufügen.
@Aspect
public class SlowMethodLogger {
private static final long LIMIT_TIME;
static {
String limit = System.getenv("SLOW_METHOD_LIMIT");
LIMIT_TIME = (limit == null) ? 0 : Long.parseLong(limit);
}
@Around("execution(* cn.orz.pascal.example.aspectj.*.*(..))")
public Object logging(ProceedingJoinPoint proceedingJoinPoint) throws Throwable {
long start = System.nanoTime();
try {
return proceedingJoinPoint.proceed();
} finally {
long end = System.nanoTime();
long time = end - start;
if (time >= LIMIT_TIME) {
int line = proceedingJoinPoint.getSourceLocation().getLine();
String method = proceedingJoinPoint.getSignature().toString();
System.out.println("SLOW_METHOD:" + method + "\tLINE:" + line + "\tTIME(ns):" + time);
}
}
}
}
Es ist eine Methode, die @Around als einen Aspekt einbettet, der als Punktschnitt bezeichnet wird. Dieses Mal wird mit @ Around die Ausführungszeit durch Ausführen der Zielmethode [ProceedingJoinPoint.proceed ()] gemessen. Es ist ein Formular, das nur protokolliert werden soll, wenn der Wert nach der Ausführung größer als "LIMIT_TIME" ist.
Das einzubettende Ziel wird durch Ausführung angegeben, und mit dieser Schreibmethode werden alle Untergebenen unter "cn.orz.pascal.example.aspectj" unabhängig von privat / öffentlich aufgezeichnet.
Wenn Sie einfach alle Protokolle ausgeben, wird dies nicht zu einem Engpass bei der 100-Millionen-Schleifenschleife. Daher muss ein Stichprobenmechanismus für die Aufzeichnung des Timings und das Protokollierungs-Timing eingerichtet werden. Es gibt.
Diesmal ist es ein Beispiel, also verwende ich System.out.println, aber in Wirklichkeit ist es besser, log4j2 oder so etwas zu verwenden.
Jetzt erstellen wir eine Anwendung, die gemessen werden soll. Grundsätzlich ist es nicht erforderlich, den zuvor erstellten Aspekt zu kennen, geschweige denn die Bibliothek, die sich zum Zeitpunkt der Entwicklung auf AspectJ bezieht. Es muss jedoch nur das Paket mit dem unter "Ausführung" angegebenen Paket übereinstimmen. * Normalerweise wird die Ausführung entsprechend dem Messziel geändert.
package cn.orz.pascal.example.aspectj;
public class Main {
public static void main(String[] args) {
System.out.println("run");
Sub1 sub = new Sub1();
for (int i = 0; i < Integer.parseInt(args[0]); i++) {
sub.getProcess();
}
}
}
package cn.orz.pascal.example.aspectj;
public class Sub1 {
private long count = 0;
public void getProcess() {
getPrivateProcess();
}
private void getPrivateProcess() {
if (count % 3 == 0) {
try {
Thread.sleep(500);
} catch (InterruptedException ex) {
throw new RuntimeException(ex);
}
}
count += 1;
}
}
Ich habe es unter der Annahme gemacht, dass Sub in der Schleife von Main aufgerufen wird und Sub ungefähr alle drei Male langsam ist.
Führen Sie zunächst die zu messende Anwendung normal aus.
$ time SLOW_METHOD_LIMIT=500000000 java -cp "example-targetapp-0.1.jar" cn.orz.pascal.example.aspectj.Main 10
run
real 0m2.158s
user 0m0.015s
sys 0m0.000s
Es ist die erwartete Zeit, da 500 ms 4 Umdrehungen machen. Als nächstes fügen wir den zuvor erstellten Aspekt hinzu. Verwenden Sie zum Anhängen Javaagent wie JFR und andere APM-Systeme.
$ time SLOW_METHOD_LIMIT=500000000 java -cp "aspectjrt-1.8.13.jar;example-aspectj-0.1.jar;example-targetapp-0.1.jar" -javaagent:asp ectjweaver-1.8.13.jar cn.orz.pascal.example.aspectj.Main 10
run
SLOW_METHOD:void cn.orz.pascal.example.aspectj.Sub1.getPrivateProcess() LINE:24 TIME(ns):500278916
SLOW_METHOD:void cn.orz.pascal.example.aspectj.Sub1.getProcess() LINE:20 TIME(ns):503194581
SLOW_METHOD:void cn.orz.pascal.example.aspectj.Sub1.getPrivateProcess() LINE:24 TIME(ns):500142922
SLOW_METHOD:void cn.orz.pascal.example.aspectj.Sub1.getProcess() LINE:20 TIME(ns):501776905
SLOW_METHOD:void cn.orz.pascal.example.aspectj.Sub1.getPrivateProcess() LINE:24 TIME(ns):500856763
SLOW_METHOD:void cn.orz.pascal.example.aspectj.Sub1.getProcess() LINE:20 TIME(ns):502748879
SLOW_METHOD:void cn.orz.pascal.example.aspectj.Main.main(String[]) LINE:15 TIME(ns):2021801158
real 0m2.459s
user 0m0.000s
sys 0m0.000s
Ich habe es jeweils dreimal gemessen, aber in diesem Fall gab es keinen großen Leistungsunterschied. Da es sich jedoch um eine Einzelfallbasis handelt, ist es erforderlich, sie auf den tatsächlich verwendeten Code anzuwenden und über die tatsächliche Einführung zu entscheiden.
$ time SLOW_METHOD_LIMIT=500000000 java -cp "aspectjrt-1.8.13.jar;example-aspectj-0.1.jar;example-targetapp-0.1.jar" -javaagent:asp ectjweaver-1.8.13.jar cn.orz.pascal.example.aspectj.Main 1000 > /dev/null
real 2m47.602s
$ time SLOW_METHOD_LIMIT=500000000 java -cp "aspectjrt-1.8.13.jar;example-aspectj-0.1.jar;example-targetapp-0.1.jar" -javaagent:asp ectjweaver-1.8.13.jar cn.orz.pascal.example.aspectj.Main 1000 > /dev/null
real 2m47.591s
$ time SLOW_METHOD_LIMIT=500000000 java -cp "aspectjrt-1.8.13.jar;example-aspectj-0.1.jar;example-targetapp-0.1.jar" -javaagent:asp ectjweaver-1.8.13.jar cn.orz.pascal.example.aspectj.Main 1000 > /dev/null
real 2m47.572s
$ time java -cp "aspectjrt-1.8.13.jar;example-aspectj-0.1.jar;example-targetapp-0.1.jar" cn.orz.pascal. example.aspectj.Main 1000 > /dev/null
real 2m47.327s
$ time java -cp "aspectjrt-1.8.13.jar;example-aspectj-0.1.jar;example-targetapp-0.1.jar" cn.orz.pascal. example.aspectj.Main 1000 > /dev/null
real 2m47.319s
$ time java -cp "aspectjrt-1.8.13.jar;example-aspectj-0.1.jar;example-targetapp-0.1.jar" cn.orz.pascal. example.aspectj.Main 1000 > /dev/null
real 2m47.304s
Dieses Mal habe ich versucht, mit AspectJ langsame Methoden zu identifizieren. Die Installation ist einfacher als bei einem vollwertigen APM. Daher ist es praktisch, wenn Sie es schnell in eine Entwicklungs- oder Verifizierungsumgebung integrieren möchten. Außerdem scheint es einfacher zu sein, dies mit AOP zu tun, als es selbst zu erstellen, beispielsweise mit dem Mechanismus der verteilten Ablaufverfolgung. Ich habe es nicht so oft ausprobiert, aber jetzt erkenne ich die Bequemlichkeit von AspectJ ...
Dann viel Spaß beim Hacken!