dd-trace-java icon indicating copy to clipboard operation
dd-trace-java copied to clipboard

Ignore Spring Boot example unmatched packages

Open ygree opened this issue 3 years ago • 7 comments

What Does This Do

Filters out some Spring Boot sample app libraries "com.netflix.graphql.", "org.antlr.", "org.apache.ibatis.", "org.hibernate.validator.", "org.flywaydb." and "org.springframework.security.config."

Motivation

This provides instrumentation time improvement around: 0.26s

image

Additional Notes

package classes time (s)
com.netflix.graphql 102 0.032134
org.antlr.v4 137 0.029614
org.hibernate.validator 451 0.160034
org.apache.ibatis 303 0.058716
org.flywaydb.core 222 0.040988
org.springframework.security.config 110 0.051863

ygree avatar Feb 22 '22 23:02 ygree

I think for spring-boot we can also safely ignore anything in this package: https://github.com/spring-projects/spring-boot/tree/main/spring-boot-project/spring-boot-autoconfigure/src/main/java/org/springframework/boot/autoconfigure

That should only config bean definitions, but nothing that would need like the async instrumentations or spring ones

I only consider those packages that contribute significant time to match. In my tests it showed that there are 6 classes in org.springframework.boot.autoconfigure that have been transformed:

+org.springframework.boot.autoconfigure : 367, 6 0.025543
org.springframework.boot.autoconfigure.template : 6 0.000079
org.springframework.boot.autoconfigure.aop : 3 0.000046
org.springframework.boot.autoconfigure.data : 14 0.000205
org.springframework.boot.autoconfigure.data.rest : 1 0.000012
org.springframework.boot.autoconfigure.data.neo4j : 1 0.000013
org.springframework.boot.autoconfigure.data.web : 4 0.000059
org.springframework.boot.autoconfigure.data.jpa : 5 0.000083
org.springframework.boot.autoconfigure.session : 1 0.000011
org.springframework.boot.autoconfigure.jdbc : 31 0.000419
org.springframework.boot.autoconfigure.jdbc.metadata : 2 0.000022
org.springframework.boot.autoconfigure.availability : 1 0.000012
org.springframework.boot.autoconfigure.mustache : 1 0.000013
org.springframework.boot.autoconfigure.sql : 8 0.000104
org.springframework.boot.autoconfigure.sql.init : 8 0.000104
org.springframework.boot.autoconfigure.jms : 2 0.000026
org.springframework.boot.autoconfigure.jms.activemq : 1 0.000014
org.springframework.boot.autoconfigure.jms.artemis : 1 0.000013
org.springframework.boot.autoconfigure.security : 14 0.000186
org.springframework.boot.autoconfigure.security.reactive : 2 0.000028
org.springframework.boot.autoconfigure.security.servlet : 6 0.000084
org.springframework.boot.autoconfigure.freemarker : 2 0.000026
org.springframework.boot.autoconfigure.jackson : 9 0.000117
org.springframework.boot.autoconfigure.dao : 1 0.000012
>org.springframework.boot.autoconfigure.web : 102 0.001327
org.springframework.boot.autoconfigure.web.reactive : 12 0.000163
org.springframework.boot.autoconfigure.web.reactive.function : 7 0.000086
org.springframework.boot.autoconfigure.web.reactive.function.client : 7 0.000086
org.springframework.boot.autoconfigure.web.servlet : 48 0.000636
org.springframework.boot.autoconfigure.web.servlet.error : 11 0.000143
org.springframework.boot.autoconfigure.web.format : 2 0.000030
org.springframework.boot.autoconfigure.web.client : 3 0.000042
org.springframework.boot.autoconfigure.web.embedded : 3 0.000039
org.springframework.boot.autoconfigure.websocket : 4 0.000051
org.springframework.boot.autoconfigure.websocket.servlet : 4 0.000051
org.springframework.boot.autoconfigure.hateoas : 3 0.000035
org.springframework.boot.autoconfigure.context : 5 0.000092
org.springframework.boot.autoconfigure.validation : 3 0.000043
org.springframework.boot.autoconfigure.info : 5 0.000061
org.springframework.boot.autoconfigure.cache : 14 0.000178
org.springframework.boot.autoconfigure.flyway : 13 0.000181
org.springframework.boot.autoconfigure.batch : 1 0.000013
org.springframework.boot.autoconfigure.quartz : 1 0.000011
org.springframework.boot.autoconfigure.thymeleaf : 1 0.000012
org.springframework.boot.autoconfigure.orm : 2 0.000025
org.springframework.boot.autoconfigure.orm.jpa : 2 0.000025
org.springframework.boot.autoconfigure.codec : 1 0.000012
org.springframework.boot.autoconfigure.jsonb : 1 0.000012
org.springframework.boot.autoconfigure.condition : 50 0.001601
org.springframework.boot.autoconfigure.groovy : 2 0.000028
org.springframework.boot.autoconfigure.groovy.template : 2 0.000028
org.springframework.boot.autoconfigure.task : 9 0.000105
org.springframework.boot.autoconfigure.integration : 2 0.000033
org.springframework.boot.autoconfigure.logging : 2 0.000035
org.springframework.boot.autoconfigure.http : 12 0.000166
org.springframework.boot.autoconfigure.http.codec : 3 0.000040
org.springframework.boot.autoconfigure.gson : 1 0.000014
org.springframework.boot.autoconfigure.r2dbc : 1 0.000014
org.springframework.boot.autoconfigure.transaction : 8 0.000111
org.springframework.boot.autoconfigure.transaction.jta : 3 0.000050

I'll probably add a stat for the time matching non-transformed classes to distinct it from class transformation time.

ygree avatar Feb 23 '22 02:02 ygree

The second commit also has a very weird name, since it's not JFR related AFAICS.

bantonsson avatar Feb 23 '22 06:02 bantonsson

Thanks for the detailed analysis.

This is not a comment on this specific PR, but I do think that this strategy of adding more and more ignores is not going to scale long-term, at least without improving how we do the ignore matching by using a trie or something similar. I worry that these changes may show an improvement for the application being tested because it has enough positive matches to offset the additional startsWith calls, but then degrades performance for other applications that don't contain these classes... because they will never get the benefit of the new ignores - only the cost of the additional startsWith calls.

Long-term I think we'll need to use an enhanced trie or some sort of state machine that gets compiled from a set of ignore patterns. That would also help at startup because then the logic becomes data rather than additional bytecode to be loaded and compiled by the JVM.

mcculls avatar Feb 23 '22 10:02 mcculls

@mcculls I completely agree, and it would be interesting to measure the cost of the AdditionalLibraryIgnoresMatcher, and maybe at least restructure it in the same way as the GlobalIgnoresMatcher.

bantonsson avatar Feb 23 '22 10:02 bantonsson

The second commit also has a very weird name, since it's not JFR related AFAICS.

Good catch! Thanks!

ygree avatar Feb 23 '22 16:02 ygree

Thanks for the detailed analysis.

This is not a comment on this specific PR, but I do think that this strategy of adding more and more ignores is not going to scale long-term, at least without improving how we do the ignore matching by using a trie or something similar. I worry that these changes may show an improvement for the application being tested because it has enough positive matches to offset the additional startsWith calls, but then degrades performance for other applications that don't contain these classes... because they will never get the benefit of the new ignores - only the cost of the additional startsWith calls.

Long-term I think we'll need to use an enhanced trie or some sort of state machine that gets compiled from a set of ignore patterns. That would also help at startup because then the logic becomes data rather than additional bytecode to be loaded and compiled by the JVM.

Yes, using a trie or a state machine built out of a list of packages would be a better solution long term!

ygree avatar Feb 23 '22 16:02 ygree

I'll probably add a stat for the time matching non-transformed classes to distinct it from class transformation time.

flag package total skipped (classes/duration) total transformed (classes/duration) siblings skipped (classes/duration) siblings transformed (classes/duration) children transformed (classes/duration) children skipped (classes/duration)
+ org.springframework.boot.autoconfigure 367 / 0.005924 6 / 0.019381 31 / 0.000521 6 / 0.019381 336 / 0.005403

Most of the time spent on transfomation 0.019381 and only 0.005924 on skipping unmatched classes. org.springframework.boot.autoconfigure. doesn't look like a good candidate for optimization to me.

ygree avatar Feb 23 '22 21:02 ygree