sander/perfix
1
0
Fork 0
Code Issues Pull requests Projects Releases Packages Wiki Activity Actions

Finally implemented callstack completely and correctly

Browse source
This commit is contained in:
Sander Hautvast 2018-07-15 12:56:40 +02:00
parent 7a86aa854d
commit 74e270776d
12 changed files with 235 additions and 99 deletions
Show stats Download patch file Download diff file Expand all files Collapse all files

3
agent.iml
View file

@ -31,6 +31,9 @@
<orderEntry type="library" name="Maven: org.nanohttpd:nanohttpd:2.3.1" level="project" />
<orderEntry type="library" scope="TEST" name="Maven: junit:junit:4.12" level="project" />
<orderEntry type="library" scope="TEST" name="Maven: org.hamcrest:hamcrest-core:1.3" level="project" />
<orderEntry type="library" name="Maven: org.apache.commons:commons-dbcp2:2.4.0" level="project" />
<orderEntry type="library" name="Maven: org.apache.commons:commons-pool2:2.5.0" level="project" />
<orderEntry type="library" name="Maven: commons-logging:commons-logging:1.2" level="project" />
<orderEntry type="library" scope="TEST" name="Maven: com.h2database:h2:1.4.195" level="project" />
<orderEntry type="library" scope="TEST" name="Maven: org.springframework.boot:spring-boot-starter-web:1.5.3.RELEASE" level="project" />
<orderEntry type="library" scope="TEST" name="Maven: org.springframework.boot:spring-boot-starter:1.5.3.RELEASE" level="project" />

6
pom.xml
View file

@ -32,6 +32,12 @@
<version>4.12</version>
<scope>test</scope>
</dependency>
<!-- https://mvnrepository.com/artifact/org.apache.commons/commons-dbcp2 -->
<dependency>
<groupId>org.apache.commons</groupId>
<artifactId>commons-dbcp2</artifactId>
<version>2.4.0</version>
</dependency>
<dependency>
<groupId>com.h2database</groupId>
<artifactId>h2</artifactId>

55
src/main/java/perfix/MethodNode.java Normal file
View file

@ -0,0 +1,55 @@
package perfix;
import java.util.ArrayList;
import java.util.List;
import java.util.Objects;
public class MethodNode {
public final String name;
public final List<MethodNode> children;
public MethodNode parent;
public Report report;
public MethodNode(String name) {
this.name = name;
this.children = new ArrayList<>();
}
public void addChild(MethodNode child){
children.add(child);
}
public String getName() {
return name;
}
public Report getReport() {
return report;
}
public List<MethodNode> getChildren() {
return children;
}
@Override
public String toString() {
return "MethodNode{" +
"name='" + name + '\'' +
'}';
}
@Override
public boolean equals(Object o) {
if (this == o) return true;
if (o == null || getClass() != o.getClass()) return false;
MethodNode that = (MethodNode) o;
return Objects.equals(name, that.name);
}
@Override
public int hashCode() {
return Objects.hash(name);
}
}

57
src/main/java/perfix/Registry.java
View file

@ -1,5 +1,7 @@
package perfix;
import perfix.instrument.Util;
import java.util.*;
import java.util.concurrent.ConcurrentHashMap;
import java.util.concurrent.ConcurrentSkipListMap;
@ -8,26 +10,56 @@ import java.util.concurrent.atomic.LongAdder;
public class Registry {
private static final Map<String, List<MethodInvocation>> methods = new ConcurrentHashMap<>();
private static final Map<String, Set<String>> callstack = new ConcurrentHashMap<>();
private static final ThreadLocal<String> currentMethod = new ThreadLocal<>();
private static final List<MethodNode> callstack = new ArrayList<>();
private static final ThreadLocal<MethodNode> currentMethod = new ThreadLocal<>();
@SuppressWarnings("unused") //used in generated code
public static MethodInvocation startJdbc(String name) {
if (!Util.isFirstExecutionStarted()) {
Util.startExecution();
return start(name);
} else {
return null;
}
}
@SuppressWarnings("unused")
public static MethodInvocation start(String name) {
MethodInvocation methodInvocation = new MethodInvocation(name);
String parent = currentMethod.get();
MethodNode newNode = new MethodNode(methodInvocation.getName());
MethodNode parent = currentMethod.get();
if (parent != null) {
callstack.computeIfAbsent(parent, k -> new HashSet<>()).add(methodInvocation.getName());
parent.addChild(newNode);
newNode.parent = parent;
} else {
callstack.add(newNode);
}
currentMethod.set(methodInvocation.getName());
currentMethod.set(newNode);
return methodInvocation;
}
@SuppressWarnings("unused")
public static void stopJdbc(MethodInvocation queryInvocation) {
if (Util.isFirstExecutionStarted() && queryInvocation != null) {
stop(queryInvocation);
Util.endExecution();
}
}
@SuppressWarnings("unused")
public static void stop(MethodInvocation methodInvocation) {
if (methodInvocation != null) {
methodInvocation.t1 = System.nanoTime();
methods.computeIfAbsent(methodInvocation.getName(), key -> new ArrayList<>()).add(methodInvocation);
}
MethodNode methodNode = currentMethod.get();
if (methodNode != null) {
currentMethod.set(methodNode.parent);
}
}
public static SortedMap<Long, Report> sortedMethodsByDuration() {
SortedMap<Long, Report> sortedByTotal = new ConcurrentSkipListMap<>(Comparator.reverseOrder());
@ -41,12 +73,19 @@ public class Registry {
return sortedByTotal;
}
//work in progress
public static Map<String, Set<Report>> getCallStack() {
callstack.forEach((name, children) -> {
public static List<MethodNode> getCallStack() {
addReport(callstack);
return callstack;
}
private static void addReport(List<MethodNode> callstack) {
callstack.forEach(methodNode -> {
LongAdder totalDuration = new LongAdder();
List<MethodInvocation> methodInvocations = methods.get(methodNode.name);
methodInvocations.forEach(methodInvocation -> totalDuration.add(methodInvocation.getDuration()));
methodNode.report = new Report(methodNode.name, methodInvocations.size(), totalDuration.longValue());
addReport(methodNode.children);
});
return null;
}
}

25
src/main/java/perfix/instrument/Instrumentor.java
View file

@ -60,6 +60,31 @@ public abstract class Instrumentor {
}
}
/* record times at beginning and end of sql call
* sql calls are special in the sense that certain jdbc connection pool implementations
* create a nested chain of jdbc statement implementations, resulting in too many reported
* (measured) calls if not handled in a way to prevent this */
void instrumentJdbcCall(CtMethod methodToinstrument, String metricName) {
try {
methodToinstrument.addLocalVariable("_perfixmethod", perfixMethodInvocationClass);
methodToinstrument.insertBefore("_perfixmethod = perfix.Registry.startJdbc(" + metricName + ");");
methodToinstrument.insertAfter("perfix.Registry.stopJdbc(_perfixmethod);");
} catch (CannotCompileException e) {
throw new RuntimeException(e);
}
}
/* record times at beginning and end of method body*/
void instrumentJdbcCall(CtMethod methodToinstrument) {
try {
methodToinstrument.addLocalVariable("_perfixmethod", perfixMethodInvocationClass);
methodToinstrument.insertBefore("_perfixmethod = perfix.Registry.startJdbc(perfix.instrument.StatementText.toString(_perfixSqlStatement));");
methodToinstrument.insertAfter("perfix.Registry.stopJdbc(_perfixmethod);");
} catch (CannotCompileException e) {
throw new RuntimeException(e);
}
}
byte[] bytecode(CtClass classToInstrument) throws IOException, CannotCompileException {
classToInstrument.detach();
return classToInstrument.toBytecode();

79
src/main/java/perfix/instrument/JdbcInstrumentor.java
View file

@ -12,19 +12,6 @@ import static java.util.Arrays.stream;
public class JdbcInstrumentor extends Instrumentor {
private static final String JAVASQL_EXECUTE_METHOD = "execute";
private static final String JAVASQL_EXECUTEQUERY_METHOD = "executeQuery";
private static final String JAVASQL_EXECUTEUPDATE_METHOD = "executeUpdate";
private static final String JAVASQL_PACKAGE = "java/sql";
private static final String JAVASQL_STATEMENT_INTERFACE = "java.sql.Statement";
private static final String JAVASQL_PREPAREDSTATEMENT_INTERFACE = "java.sql.PreparedStatement";
private static final String JAVASQL_CONNECTION_INTERFACE = "java.sql.Connection";
private static final String JAVASQL_PREPAREDSTATEMENT_RESOURCENAME = "java/sql/PreparedStatement";
private static final String JAVASQL_PREPARED_STATEMENT_CLASSNAME = "java.sql.PreparedStatement";
private static final String JAVASQL_PREPARESTATEMENT_METHODNAME = "prepareStatement";
private static final String PERFIX_SQLSTATEMENT_FIELD = "_perfixSqlStatement";
private static final String PERFIX_SETSQL_METHOD = "setSqlForPerfix";
private static CtClass statementTextClass = null;
JdbcInstrumentor(List<String> includes, ClassPool classPool) {
@ -39,11 +26,11 @@ public class JdbcInstrumentor extends Instrumentor {
/* Need to enhance interface to be able to set a statement (string) for perfix. */
byte[] instrumentJdbcPreparedStatement(CtClass preparedStatementInterface, byte[] uninstrumentedByteCode) {
try {
preparedStatementInterface.getDeclaredMethod(PERFIX_SETSQL_METHOD);
preparedStatementInterface.getDeclaredMethod("setSqlForPerfix");
} catch (NotFoundException e1) {
e1.printStackTrace();
try {
CtMethod setSqlForPerfix = new CtMethod(CtClass.voidType, PERFIX_SETSQL_METHOD, new CtClass[]{stringClass}, preparedStatementInterface);
CtMethod setSqlForPerfix = new CtMethod(CtClass.voidType, "setSqlForPerfix", new CtClass[]{stringClass}, preparedStatementInterface);
preparedStatementInterface.addMethod(setSqlForPerfix);
} catch (CannotCompileException e2) {
@ -66,21 +53,21 @@ public class JdbcInstrumentor extends Instrumentor {
* and injected into the PreparedStatement instance under a fixed name, whatever the implementation type */
byte[] instrumentJdbcConnection(CtClass classToInstrument, byte[] uninstrumentedByteCode) {
try {
stream(classToInstrument.getDeclaredMethods(JAVASQL_PREPARESTATEMENT_METHODNAME)).forEach(method -> {
stream(classToInstrument.getDeclaredMethods("prepareStatement")).forEach(method -> {
try {
// The sql statement String that is the first argument for this method is injected into PreparedStatementImpl
// using a name known (only) to perfix, so that it can fetch it later in that class (instance)
// this way no JDBC implementor specific code is needed
CtClass preparedStatementInterface = classpool.get(JAVASQL_PREPARED_STATEMENT_CLASSNAME);
CtClass preparedStatementInterface = classpool.get("java.sql.PreparedStatement");
try {
preparedStatementInterface.getDeclaredMethod(PERFIX_SETSQL_METHOD);
preparedStatementInterface.getDeclaredMethod("setSqlForPerfix");
} catch (NotFoundException e1) {
CtMethod setSqlForPerfix = new CtMethod(CtClass.voidType, PERFIX_SETSQL_METHOD, new CtClass[]{stringClass}, preparedStatementInterface);
CtMethod setSqlForPerfix = new CtMethod(CtClass.voidType, "setSqlForPerfix", new CtClass[]{stringClass}, preparedStatementInterface);
preparedStatementInterface.addMethod(setSqlForPerfix);
}
method.insertAfter(JAVASSIST_RETURNVALUE + "." + PERFIX_SETSQL_METHOD + "(" + JAVASSIST_FIRST_ARGUMENT_NAME + ");"); //$_ is result instance, $1 is first argument
method.insertAfter("$_.setSqlForPerfix($1);"); //$_ is result instance, $1 is first argument
} catch (CannotCompileException | NotFoundException e) {
// suppress
e.printStackTrace();
@ -100,26 +87,14 @@ public class JdbcInstrumentor extends Instrumentor {
try {
addPerfixFields(preparedStatementClass);
addPerfixStatementSetter(preparedStatementClass);
// instrument execute to record query duration
stream(preparedStatementClass.getDeclaredMethods(JAVASQL_EXECUTE_METHOD)).forEach(method ->
instrumentMethod(method, PERFIX_SQLSTATEMENT_FIELD + ".toString()")
);
// instrument executeQuery to record query duration
stream(preparedStatementClass.getDeclaredMethods(JAVASQL_EXECUTEQUERY_METHOD)).forEach(method ->
instrumentMethod(method, PERFIX_SQLSTATEMENT_FIELD + ".toString()")
);
// instrument executeUpdate to record query duration
stream(preparedStatementClass.getDeclaredMethods(JAVASQL_EXECUTEUPDATE_METHOD)).forEach(method ->
instrumentMethod(method, PERFIX_SQLSTATEMENT_FIELD + ".toString()")
);
stream(preparedStatementClass.getDeclaredMethods("execute")).forEach(this::instrumentJdbcCall);
stream(preparedStatementClass.getDeclaredMethods("executeQuery")).forEach(this::instrumentJdbcCall);
stream(preparedStatementClass.getDeclaredMethods("executeUpdate")).forEach(this::instrumentJdbcCall);
getDeclaredMethods(preparedStatementClass, "setString", "setObject", "setDate", "setTime", "setTimestamp")
.forEach(method -> {
try {
method.insertBefore(PERFIX_SQLSTATEMENT_FIELD + ".set($1, \"\'\"+$2+\"\'\");");
method.insertBefore("perfix.instrument.StatementText.set(_perfixSqlStatement,$1, \"\'\"+$2+\"\'\");");
} catch (CannotCompileException e) {
throw new RuntimeException(e);
}
@ -129,7 +104,7 @@ public class JdbcInstrumentor extends Instrumentor {
"setInt", "setFloat", "setDouble", "setBoolean", "setLong", "setShort")
.forEach(method -> {
try {
method.insertBefore(PERFIX_SQLSTATEMENT_FIELD + ".set($1, $2);");
method.insertBefore("perfix.instrument.StatementText.set(_perfixSqlStatement,$1,$2);");
} catch (CannotCompileException e) {
throw new RuntimeException(e);
}
@ -138,7 +113,7 @@ public class JdbcInstrumentor extends Instrumentor {
getDeclaredMethods(preparedStatementClass, "setNull")
.forEach(method -> {
try {
method.insertBefore(PERFIX_SQLSTATEMENT_FIELD + ".set($1, \"[NULL]\");");
method.insertBefore("perfix.instrument.StatementText.set(_perfixSqlStatement,$1,\"[NULL]\");");
} catch (CannotCompileException e) {
throw new RuntimeException(e);
}
@ -171,12 +146,12 @@ public class JdbcInstrumentor extends Instrumentor {
byte[] instrumentJdbcStatement(CtClass classToInstrument, byte[] uninstrumentedByteCode) {
try {
//instrument executeQuery to record query duration
stream(classToInstrument.getDeclaredMethods(JAVASQL_EXECUTEQUERY_METHOD)).forEach(method ->
instrumentMethod(method, JAVASSIST_FIRST_ARGUMENT_NAME)
stream(classToInstrument.getDeclaredMethods("executeQuery")).forEach(method ->
instrumentJdbcCall(method, "$1")
);
//instrument executeUpdate to record query duration
stream(classToInstrument.getDeclaredMethods(JAVASQL_EXECUTEUPDATE_METHOD)).forEach(method ->
instrumentMethod(method, JAVASSIST_FIRST_ARGUMENT_NAME)
stream(classToInstrument.getDeclaredMethods("executeUpdate")).forEach(method ->
instrumentJdbcCall(method, "$1")
);
return bytecode(classToInstrument);
} catch (Exception e) {
@ -188,43 +163,43 @@ public class JdbcInstrumentor extends Instrumentor {
private void addPerfixFields(CtClass preparedStatementClass) throws CannotCompileException, NotFoundException {
// add a String field that will contain the statement
CtField perfixSqlField = new CtField(statementTextClass, PERFIX_SQLSTATEMENT_FIELD, preparedStatementClass);
CtField perfixSqlField = new CtField(statementTextClass, "_perfixSqlStatement", preparedStatementClass);
perfixSqlField.setModifiers(Modifier.PRIVATE);
preparedStatementClass.addField(perfixSqlField);
}
private void addPerfixStatementSetter(CtClass preparedStatementImplClass) throws CannotCompileException {
// add setter for the new field
CtMethod setSqlForPerfix = new CtMethod(CtClass.voidType, PERFIX_SETSQL_METHOD, new CtClass[]{stringClass}, preparedStatementImplClass);
CtMethod setSqlForPerfix = new CtMethod(CtClass.voidType, "setSqlForPerfix", new CtClass[]{stringClass}, preparedStatementImplClass);
setSqlForPerfix.setModifiers(Modifier.PUBLIC);
setSqlForPerfix.setBody(PERFIX_SQLSTATEMENT_FIELD + "= new perfix.instrument.StatementText(" + JAVASSIST_FIRST_ARGUMENT_NAME + ");");
setSqlForPerfix.setBody("_perfixSqlStatement=new perfix.instrument.StatementText($1);");
preparedStatementImplClass.addMethod(setSqlForPerfix);
}
boolean isJdbcStatementImpl(String resource, CtClass ctClass) throws NotFoundException {
if (!resource.startsWith(JAVASQL_PACKAGE)) {
if (!resource.startsWith("java/sql")) {
return stream(ctClass.getInterfaces())
.anyMatch(i -> i.getName().equals(JAVASQL_STATEMENT_INTERFACE) && !i.getName().equals(JAVASQL_PREPARED_STATEMENT_CLASSNAME));
.anyMatch(i -> i.getName().equals("java.sql.Statement") && !i.getName().equals("java.sql.PreparedStatement"));
}
return false;
}
boolean isJdbcPreparedStatement(String resource) {
return resource.equals(JAVASQL_PREPAREDSTATEMENT_RESOURCENAME);
return resource.equals("java/sql/PreparedStatement");
}
boolean isJdbcPreparedStatementImpl(String resource, CtClass ctClass) throws NotFoundException {
if (!resource.startsWith(JAVASQL_PACKAGE)) {
if (!resource.startsWith("java/sql")) {
return stream(ctClass.getInterfaces())
.anyMatch(i -> i.getName().equals(JAVASQL_PREPAREDSTATEMENT_INTERFACE));
.anyMatch(i -> i.getName().equals("java.sql.PreparedStatement"));
}
return false;
}
boolean isJdbcConnectionImpl(String resource, CtClass ctClass) throws NotFoundException {
if (!resource.startsWith(JAVASQL_PACKAGE)) {
if (!resource.startsWith("java/sql")) {
return stream(ctClass.getInterfaces())
.anyMatch(i -> i.getName().equals(JAVASQL_CONNECTION_INTERFACE));
.anyMatch(i -> i.getName().equals("java.sql.Connection"));
}
return false;
}

53
src/main/java/perfix/instrument/StatementText.java
View file

@ -12,47 +12,62 @@ public class StatementText {
this.sql = new StringBuilder(sql);
}
public void set(int index, Object value) {
if (index < 1 || index > vars.length + 1) {
public static void set(StatementText statementText, int index, Object value) {
if (statementText != null) {
if (index < 1 || index > statementText.vars.length + 1) {
throw new IndexOutOfBoundsException("" + index);
}
vars[index - 1] = value;
statementText.vars[index - 1] = value;
} else {
if (statementText!=null){
System.out.println(statementText);
} else {
System.out.println("null");
}
}
}
public void set(int index, int value){
set(index, Integer.toString(value));
@SuppressWarnings("unused") //used in generated code
public static String toString(StatementText statementText) {
return statementText != null ? statementText.toString() : "[none]";
}
public void set(int index, long value){
set(index, Long.toString(value));
public static void set(StatementText statementText, int index, int value) {
set(statementText, index, Integer.toString(value));
}
public void set(int index, double value){
set(index, Double.toString(value));
public static void set(StatementText statementText, int index, long value) {
set(statementText, index, Long.toString(value));
}
public void set(int index, boolean value){
set(index, Boolean.toString(value));
public static void set(StatementText statementText, int index, double value) {
set(statementText, index, Double.toString(value));
}
public void set(int index, float value){
set(index, Float.toString(value));
public static void set(StatementText statementText, int index, boolean value) {
set(statementText, index, Boolean.toString(value));
}
public void set(int index, short value){
set(index, Short.toString(value));
public static void set(StatementText statementText, int index, float value) {
set(statementText, index, Float.toString(value));
}
public static void set(StatementText statementText, int index, short value) {
set(statementText, index, Short.toString(value));
}
@Override
public String toString() {
StringBuilder output=new StringBuilder(sql);
int found = 0;
for (int i = 0; i < sql.length(); i++) {
if (sql.charAt(i) == BOUNDVAR_MARK) {
sql.deleteCharAt(i);
sql.insert(i, vars[found++]);
if (output.charAt(i) == BOUNDVAR_MARK) {
output.deleteCharAt(i);
output.insert(i, vars[found++]);
}
}
return sql.toString();
return output.toString();
}
private int countVars(String sql) {

18
src/main/java/perfix/instrument/Util.java Normal file
View file

@ -0,0 +1,18 @@
package perfix.instrument;
public class Util {
private final static ThreadLocal<Boolean> STATEMENT_INSTRUMENTED_TL = new ThreadLocal<>();
public static void startExecution() {
STATEMENT_INSTRUMENTED_TL.set(true);
}
public static void endExecution() {
STATEMENT_INSTRUMENTED_TL.set(false);
}
public static boolean isFirstExecutionStarted() {
Boolean isStarted = STATEMENT_INSTRUMENTED_TL.get();
return isStarted != null ? isStarted : false;
}
}

2
src/main/java/perfix/server/HTTPServer.java
View file

@ -40,8 +40,6 @@ public class HTTPServer extends NanoHTTPD {
private Response perfixMetrics() {
try {
return addCors(newFixedLengthResponse(Response.Status.OK, "application/json", Serializer.toJSONString(new ArrayList<>(Registry.sortedMethodsByDuration().values()))));
} catch (Exception e) {
e.printStackTrace();
return newFixedLengthResponse(e.toString());

11
src/main/java/perfix/server/json/SynthSerializerFactory.java
View file

@ -131,15 +131,10 @@ public class SynthSerializerFactory implements SerializerFactory {
* The generated code fills a StringBuilder. The values are generated by the subserializers
*/
private String handleArray(CtClass beanClass) {
String source = "\tStringBuilder result=new StringBuilder(\"[\");\n";
String source = "\tjava.util.StringJoiner result=new java.util.StringJoiner(\",\",\"[\",\"]\");\n";
source += "\tfor (int i=0; i<array.length; i++){\n";
source += "\t\tresult.append(" + Serializer.class.getName() + ".toJSONString(array[i]));\n";
source += "\t\tresult.append(\", \");\n";
source += "\t};\n";
source += "\tresult.setLength(result.length()-2);\n";
source += "\tresult.append(\"]\");\n";
source += "\treturn result.toString();\n";
source += "}";
source += "\t\tresult.add(" + Serializer.class.getName() + ".toJSONString(array[i]));\n";
source += "\t};\n\treturn result.toString();\n}";
return source;
}

4
src/test/java/StatementTextTest.java
View file

@ -7,8 +7,8 @@ public class StatementTextTest {
@Test
public void testReplace(){
StatementText b = new StatementText("select ? from ?");
b.set(1, "alpha");
b.set(2, "beta");
StatementText.set(b,1, "alpha");
StatementText.set(b,2, "beta");
Assert.assertEquals("select alpha from beta",b.toString());
}
}

15
src/testapp/java/testperfix/cmdline/App.java
View file

@ -1,5 +1,7 @@
package testperfix.cmdline;
import org.apache.commons.dbcp2.BasicDataSource;
import java.sql.*;
import java.util.concurrent.TimeUnit;
@ -18,8 +20,7 @@ public class App {
private static void run() {
try {
Class.forName("org.h2.Driver");
someJdbcStatentMethod();
someJdbcStatementMethod();
someJdbcPreparedStatementMethod();
someOtherMethod();
TimeUnit.SECONDS.sleep(1);
@ -28,9 +29,15 @@ public class App {
}
}
private static void someJdbcStatentMethod() {
private static void someJdbcStatementMethod() {
try {
Connection connection = DriverManager.getConnection("jdbc:h2:mem:default", "sa", "");
BasicDataSource dataSource=new BasicDataSource();
dataSource.setDriverClassName("org.h2.Driver");
dataSource.setUrl("jdbc:h2:mem:default");
dataSource.setUsername("sa");
dataSource.setPassword("");
Connection connection = dataSource.getConnection();
Statement statement = connection.createStatement();
statement.executeQuery("select CURRENT_DATE() -- simple statement");
connection.close();