[Bug] PostgreSQL plugin throws NPE when executing statements prepared with RETURN_GENERATED_KEYS #14138

Search before asking

• I searched the issues and found agent NPE in PostgreSQL plugin #4943 and discussion NullPointerException: because "cacheObject" is null #12257 reporting the same NPE, but both were closed or left unanswered without a root cause.

Apache SkyWalking Component

Java Agent (apache/skywalking-java)

What happened

With Java agent 9.6.0 (the PostgreSQL plugin and jdbc-commons are unchanged in 9.8.0 and main), PostgreSQL JDBC driver 42.3.8, Hibernate 5.6.15 and HikariCP, every insert of an entity using GenerationType.IDENTITY writes 4 ERROR entries to skywalking-api.log:

ERROR ... InstMethodsInter : class[class org.postgresql.jdbc.PgPreparedStatement] before method[executeUpdate] intercept failure
java.lang.NullPointerException: Cannot invoke "org.apache.skywalking.apm.plugin.jdbc.define.StatementEnhanceInfos.getConnectionInfo()" because "cacheObject" is null
	at org.apache.skywalking.apm.plugin.jdbc.postgresql.PreparedStatementExecuteMethodsInterceptor.beforeMethod(PreparedStatementExecuteMethodsInterceptor.java:46)
	at org.apache.skywalking.apm.agent.core.plugin.interceptor.enhance.InstMethodsInter.intercept(InstMethodsInter.java:83)
	at org.postgresql.jdbc.PgPreparedStatement.executeUpdate(PgPreparedStatement.java)
	at org.apache.skywalking.apm.plugin.jdbc.trace.SWPreparedStatement$12.exe(SWPreparedStatement.java:370)
	at org.apache.skywalking.apm.plugin.jdbc.trace.SWPreparedStatement$12.exe(SWPreparedStatement.java:367)
	at org.apache.skywalking.apm.plugin.jdbc.trace.PreparedStatementTracing.execute(PreparedStatementTracing.java:56)
	at org.apache.skywalking.apm.plugin.jdbc.trace.SWPreparedStatement.executeUpdate(SWPreparedStatement.java:366)
	at com.zaxxer.hikari.pool.ProxyPreparedStatement.executeUpdate(ProxyPreparedStatement.java:61)
	at com.zaxxer.hikari.pool.HikariProxyPreparedStatement.executeUpdate(HikariProxyPreparedStatement.java)
	at org.hibernate.engine.jdbc.internal.ResultSetReturnImpl.executeUpdate(ResultSetReturnImpl.java:197)
	at org.hibernate.dialect.identity.GetGeneratedKeysDelegate.executeAndExtract(GetGeneratedKeysDelegate.java:58)
	at org.hibernate.id.insert.AbstractReturningDelegate.performInsert(AbstractReturningDelegate.java:43)
	...

The other three entries are before method[executeWithFlags], after method[executeWithFlags] and after method[executeUpdate]. On our two instances these four messages are the only agent errors, and they fill a 300 MB agent log file about every 6 days. The application itself is not affected, and the SQL span is still recorded by SWPreparedStatement.

What you expected to happen

No NPE. A statement created by prepareStatement(String, String[]) or prepareStatement(String, int) should be traced by SWPreparedStatement without errors from the interceptor of the underlying PgPreparedStatement.

Root cause

• ConnectionInstrumentation intercepts PgConnection#prepareStatement(String, String[]) with JDBCPrepareStatementWithStringArrayInterceptor, which wraps the returned statement in SWPreparedStatement but does not set the dynamic field of the real PgPreparedStatement.
• In pgjdbc 42.x (checked with 42.3.8), prepareStatement(String, String[]) constructs PgPreparedStatement directly instead of calling the 4-argument prepareStatement handled by CreatePreparedStatementInterceptor, so the dynamic field stays null. prepareStatement(String, int) with Statement.RETURN_GENERATED_KEYS delegates to it, and that is what Hibernate (GetGeneratedKeysDelegate) and MyBatis (useGeneratedKeys) use for inserts.
• PgPreparedStatement is still enhanced by PgPreparedStatementInstrumentation, so when SWPreparedStatement calls the real executeUpdate (and the nested executeWithFlags), PreparedStatementExecuteMethodsInterceptor dereferences the null dynamic field in beforeMethod and afterMethod.

The MySQL plugin's PreparedStatementExecuteMethodsInterceptor already guards this case with cacheObject != null; the PostgreSQL one does not.

How to reproduce

Run an application with the agent and the PostgreSQL plugin, and save a JPA entity whose id uses GenerationType.IDENTITY (Hibernate 5.6, pgjdbc 42.3.8). At the JDBC level, this is the following call sequence:

PreparedStatement ps = connection.prepareStatement(
    "INSERT INTO test (name) VALUES (?)", Statement.RETURN_GENERATED_KEYS);
ps.setString(1, "a");
ps.executeUpdate();

Anything else

The existing plugin test scenarios only use prepareStatement(String), so this path is not covered.

I'll submit a PR that adds the same null guard as the MySQL plugin. Setting the dynamic field on the real statement instead of wrapping it would also stop the NPE, but it changes the current tracing behavior of this path, so the PR keeps the change minimal.

Are you willing to submit a pull request to fix on your own?

• Yes I am willing to submit a pull request on my own!

Code of Conduct

• I agree to follow this project's Code of Conduct