Excessive prepareStatement probe overhead in EAP
-
- Posts: 13
- Joined: Mon Jun 09, 2014 4:47 pm
Excessive prepareStatement probe overhead in EAP
Hope this is the right place to report issues with the EAP. It's looking great so far, the UI is more responsive than ever, and the new features are great.
One not so nice change is that I'm seeing a lot more overhead than I'm used to from prepareStatement calls with CPU profiling enabled, specifically: com.yourkit.probes.builtin.Databases$Connection_prepareStatement_Probe.onEnter()
Is this a known issue?
One not so nice change is that I'm seeing a lot more overhead than I'm used to from prepareStatement calls with CPU profiling enabled, specifically: com.yourkit.probes.builtin.Databases$Connection_prepareStatement_Probe.onEnter()
Is this a known issue?
-
- Posts: 6172
- Joined: Wed Aug 11, 2004 8:37 am
Re: Excessive prepareStatement probe overhead in EAP
Hi,
Do you use the latest EAP build?
With which version do you compare? Is it v2013?
How do you measure the overhead? Could you please provide the numbers, what it was and what it is now.
Could you please make sure you specify the same agent startup options for both versions.
It's known that the probes add overhead which can be eliminated by turning them off, but we are not aware of regressions in the EAP version comparing with v2013.
Best regards,
Anton
Do you use the latest EAP build?
With which version do you compare? Is it v2013?
How do you measure the overhead? Could you please provide the numbers, what it was and what it is now.
Could you please make sure you specify the same agent startup options for both versions.
It's known that the probes add overhead which can be eliminated by turning them off, but we are not aware of regressions in the EAP version comparing with v2013.
Best regards,
Anton
-
- Posts: 13
- Joined: Mon Jun 09, 2014 4:47 pm
Re: Excessive prepareStatement probe overhead in EAP
Hi Anton,
That's right: YourKit 2014 build 14060, Java 1.7.0_60.
Thankfully it's easy to reproduce - it's by far away the top consumer of time when sampling of a JDBC based application, so it's bubbling to the top and skewing results. Here's a quick comparison between no agent, agents with no options and sampling, on Mac OS with JMH:
Here's the Maven project with the benchmark already compiled:
https://www.dropbox.com/s/ocwt4m4brsihj ... tement.zip
Run using the following command to get the same result as the 2014 Sampling result above. Only the jvmArgs differed for each test:
Cheers,
Danny
That's right: YourKit 2014 build 14060, Java 1.7.0_60.
Thankfully it's easy to reproduce - it's by far away the top consumer of time when sampling of a JDBC based application, so it's bubbling to the top and skewing results. Here's a quick comparison between no agent, agents with no options and sampling, on Mac OS with JMH:
Code: Select all
Benchmark Mode Samples Score Score error Units
Baseline thrpt 20 3153144.913 448483.596 ops/ms
2013 Agent thrpt 20 441568.866 8597.291 ops/ms
2014 Agent thrpt 20 440193.374 6290.117 ops/ms
2013 Sampling thrpt 20 430578.975 4573.058 ops/ms
2014 Sampling thrpt 20 66.734 38.889 ops/ms
https://www.dropbox.com/s/ocwt4m4brsihj ... tement.zip
Run using the following command to get the same result as the 2014 Sampling result above. Only the jvmArgs differed for each test:
Code: Select all
java -jar target/microbenchmarks.jar -i 20 -wi 10 -f 1 -jvmArgs -agentpath:/Applications/YourKit.app/bin/mac/libyjpagent.jnilib=sampling
Danny
-
- Posts: 13
- Joined: Mon Jun 09, 2014 4:47 pm
Re: Excessive prepareStatement probe overhead in EAP
Oh, I should add:
- Presumably, the difference between the baseline and the agent indicates that there's quite a bit of overhead with the agent, even when not sampling, though there's no regression there
- To compile the project yourself:
Code: Select all
mvn install
-
- Posts: 6172
- Joined: Wed Aug 11, 2004 8:37 am
Re: Excessive prepareStatement probe overhead in EAP
Hi Danny
Thank you for providing the detail.
We managed to reproduce the problem.
Our first observation is that v2013 did not handle most of the events in the test.
We have slightly modified the example, and indeed see some performance degradation in v2014.
We're investigating which changes are responsible, and how to fix it.
I'll inform you informed of the results.
Best regards,
Anton
Thank you for providing the detail.
We managed to reproduce the problem.
Our first observation is that v2013 did not handle most of the events in the test.
We have slightly modified the example, and indeed see some performance degradation in v2014.
We're investigating which changes are responsible, and how to fix it.
I'll inform you informed of the results.
Best regards,
Anton
-
- Posts: 6172
- Joined: Wed Aug 11, 2004 8:37 am
Re: Excessive prepareStatement probe overhead in EAP
Hi Danny
Could you please try the latest build 14062:
http://www.yourkit.com/eap
Probe overhead has been reduced.
The modified test (see detail below) now works with v2014 faster than with v2013 in multithreaded mode. In a single thread mode v2014 is still slightly slower, but this is expected: the optimizations in v2014 were targeted at improving profiling of multithreaded applications, which is the most important and popular case.
The test needed a modification to make comparison fair. The problem with v2013 was that it simply ignored all events in DummyConnection because it was not created via one of "predefined" ways v2013 can recognize - DataSource or Driver. In contrast, version 2014 handles such connections, thus its overhead in your original test was much higher - the version 2013's probes were almost no-ops.
To make v2013 and v2014 register the same set of events (that is, to make events visible to v2013), we've added a dummy DataSource to create DummyConnection instead of directly calling new DummyConnection() in the benchmark:
The benchmark main class is:
DataSource is created per-thread and is stored as a thread local.
We also added calls to Statement.close() to better measure probe impact.
Please also note that running without sampling makes no sense in this test, since the Databases probe activity mode is Auto by default, i.e. it's active only when CPU sampling or tracing is running:
http://www.yourkit.com/docs/java/help/r ... probes.jsp
Best regards,
Anton
Could you please try the latest build 14062:
http://www.yourkit.com/eap
Probe overhead has been reduced.
The modified test (see detail below) now works with v2014 faster than with v2013 in multithreaded mode. In a single thread mode v2014 is still slightly slower, but this is expected: the optimizations in v2014 were targeted at improving profiling of multithreaded applications, which is the most important and popular case.
The test needed a modification to make comparison fair. The problem with v2013 was that it simply ignored all events in DummyConnection because it was not created via one of "predefined" ways v2013 can recognize - DataSource or Driver. In contrast, version 2014 handles such connections, thus its overhead in your original test was much higher - the version 2013's probes were almost no-ops.
To make v2013 and v2014 register the same set of events (that is, to make events visible to v2013), we've added a dummy DataSource to create DummyConnection instead of directly calling new DummyConnection() in the benchmark:
Code: Select all
public class DummyDataSource implements DataSource {
@Override
public Connection getConnection() throws SQLException {
return new DummyConnection();
}
@Override
public Connection getConnection(final String username, final String password) throws SQLException {
return null;
}
@Override
public PrintWriter getLogWriter() throws SQLException {
return null;
}
@Override
public void setLogWriter(final PrintWriter out) throws SQLException {
}
@Override
public void setLoginTimeout(final int seconds) throws SQLException {
}
@Override
public int getLoginTimeout() throws SQLException {
return 0;
}
@Override
public Logger getParentLogger() throws SQLFeatureNotSupportedException {
return null;
}
@Override
public <T> T unwrap(final Class<T> iface) throws SQLException {
return null;
}
@Override
public boolean isWrapperFor(final Class<?> iface) throws SQLException {
return false;
}
}
Code: Select all
public class MyBenchmark {
private static final ThreadLocal<Connection> DUMMY_CONNECTION = new ThreadLocal<Connection>() {
@Override
protected Connection initialValue() {
try {
return new DummyDataSource().getConnection();
}
catch (SQLException e) {
System.exit(-1);
return null;
}
}
};
@GenerateMicroBenchmark
public void testMethod() throws SQLException {
final PreparedStatement stmt = DUMMY_CONNECTION.get().prepareStatement("SELECT * FROM table");
stmt.close();
}
}
We also added calls to Statement.close() to better measure probe impact.
Please also note that running without sampling makes no sense in this test, since the Databases probe activity mode is Auto by default, i.e. it's active only when CPU sampling or tracing is running:
http://www.yourkit.com/docs/java/help/r ... probes.jsp
Best regards,
Anton
-
- Posts: 13
- Joined: Mon Jun 09, 2014 4:47 pm
Re: Excessive prepareStatement probe overhead in EAP
Hi Anton,
Definitely improved in terms of raw throughput, about twice the overhead of 2013 using your test approach on a single threaded test. The individual iteration throughput varies a lot, thus the high score error. It'd probably be more reliable test to sleep/spin for some time to simulate the normal overhead of preparing a statement; I guess it's unreasonable to expect that the probes would be able to keep up with so much activity:
The reason I mentioned the performance of agent without sampling, is because the results show a massive difference between having an agent and none on probed methods. Any insight into why there is such high overhead without active probes or sampling?
Danny
Definitely improved in terms of raw throughput, about twice the overhead of 2013 using your test approach on a single threaded test. The individual iteration throughput varies a lot, thus the high score error. It'd probably be more reliable test to sleep/spin for some time to simulate the normal overhead of preparing a statement; I guess it's unreasonable to expect that the probes would be able to keep up with so much activity:
Code: Select all
Benchmark Mode Samples Score Score error Units
No agent thrpt 20 361463.717 4853.858 ops/ms
Agent thrpt 20 1735.598 1482.994 ops/ms
Agent with sampling thrpt 20 315.739 181.982 ops/ms
2013 Agent with sampling thrpt 20 649.419 310.372 ops/ms
Danny
-
- Posts: 6172
- Joined: Wed Aug 11, 2004 8:37 am
Re: Excessive prepareStatement probe overhead in EAP
Difference between "No agent" and "Agent": the probe callbacks which are inactive (please see the link in my previous message about probe activity modes). They are almost negligible in real life, but can make a difference when applied to empty DummyConnection methods. Adding small code to a real method is almost invisible, but adding it to an empty method body significantly increases the method time: almost-zero plus something is many times bigger than almost-zero. Furthermore, JVM effectively inlines empty prepareStatement() method making its execution impact even more negligible, but it cannot do this when the probe inserts its callbacks. Should it be a real life method doing something useful (or if we added sleep/spin as you suggested), the picture would change: the inactive probe callbacks would not be such a huge impact on the test results.
You can try specifying startup option "probe_disable=*" to totally eliminate the probes. You can additionally disable CPU tracing instrumentation with "disabletracing" to ensure the method remains empty.
Difference between "Agent" and "Agent with sampling": sampling makes the probes in Auto mode active, and they start working.
Alternatively to starting sampling, you can change the probe activity mode from Auto to On with the startup option "probe_on=*" (and without "sampling"). I can't test right now, but I guess the result will be similar to what you have got for "Agent with sampling".
Best regards,
Anton
You can try specifying startup option "probe_disable=*" to totally eliminate the probes. You can additionally disable CPU tracing instrumentation with "disabletracing" to ensure the method remains empty.
Difference between "Agent" and "Agent with sampling": sampling makes the probes in Auto mode active, and they start working.
Alternatively to starting sampling, you can change the probe activity mode from Auto to On with the startup option "probe_on=*" (and without "sampling"). I can't test right now, but I guess the result will be similar to what you have got for "Agent with sampling".
Best regards,
Anton
-
- Posts: 13
- Joined: Mon Jun 09, 2014 4:47 pm
Re: Excessive prepareStatement probe overhead in EAP
Thanks for your help Anton. It's definitely better with the later build, and I'm now setting all of the probes off by default for this application, and I'll turn them on when I need them (and I'll disable them when I really need low overhead).
It's not always obvious from the CPU data which methods are covered by probes - perhaps as a future enhancement you could mark methods that match active/on probes in the UI?
It's not always obvious from the CPU data which methods are covered by probes - perhaps as a future enhancement you could mark methods that match active/on probes in the UI?
-
- Posts: 6172
- Joined: Wed Aug 11, 2004 8:37 am
Re: Excessive prepareStatement probe overhead in EAP
Hello Danny
We've just released build 14064 with more improvements.
Best regards,
Anton
We've just released build 14064 with more improvements.
Thank you for the suggestion. I've added a feature request.perhaps as a future enhancement you could mark methods that match active/on probes in the UI?
Best regards,
Anton