Bug #35666 NPE logging slow queries when useServerPrepStmts=true

Submitted:	29 Mar 2008 9:50	Modified:	7 Jul 2008 13:53
Reporter:	Stephen Marquard	Email Updates:
Status:	Closed	Impact on me:	None
Category:	Connector / J	Severity:	S3 (Non-critical)
Version:	5.1.6	OS:	Linux
Assigned to:		CPU Architecture:	Any

Description:
When useServerPrepStmts=true and slow query logging is enabled, the mysql connector throws an NPE when it encounters a slow query.

How to repeat:
To reproduce, use a connection string such as:

url@javax.sql.BaseDataSource=jdbc:mysql://localhost:3306/sakai?useUnicode=true&characterEncoding=UTF-8&useServerPrepStmts=true&slowQueryThresholdMillis=1&logSlowQueries=true&maxQuerySizeToLog=128000

Any query that takes > 1ms to execute generates an error such as the stack trace below, with the common factor being the NPE at ServerPreparedStatement.java:1396

java.sql.SQLException: java.lang.NullPointerException
        at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:1055)
        at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:956)
        at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:926)
        at com.mysql.jdbc.ServerPreparedStatement.executeInternal(ServerPreparedStatement.java:864)
        at com.mysql.jdbc.PreparedStatement.executeQuery(PreparedStatement.java:1885)
        at org.apache.commons.dbcp.DelegatingPreparedStatement.executeQuery(DelegatingPreparedStatement.java:93)
        at org.sakaiproject.db.impl.BasicSqlService.dbRead(BasicSqlService.java:549)
        at org.sakaiproject.db.impl.BasicSqlService.dbRead(BasicSqlService.java:468)
        at org.sakaiproject.authz.impl.DbAuthzGroupService$DbStorage.isAllowed(DbAuthzGroupService.java:1505)
        at org.sakaiproject.authz.impl.BaseAuthzGroupService.isAllowed(BaseAuthzGroupService.java:832)
        at org.sakaiproject.authz.impl.SakaiSecurity.checkAuthzGroups(SakaiSecurity.java:289)
        at org.sakaiproject.authz.impl.SakaiSecurity.unlock(SakaiSecurity.java:256)
        at org.sakaiproject.authz.impl.SakaiSecurity.unlock(SakaiSecurity.java:223)
        at org.sakaiproject.authz.impl.SakaiSecurity.unlock(SakaiSecurity.java:215)
        at org.sakaiproject.authz.impl.SakaiSecurity.unlock(SakaiSecurity.java:201)
        at org.sakaiproject.site.impl.BaseSiteService.unlockCheck(BaseSiteService.java:165)
        at org.sakaiproject.site.impl.BaseSiteService.unlock(BaseSiteService.java:185)
        at org.sakaiproject.site.impl.BaseSiteService.getSiteVisit(BaseSiteService.java:701)
        at org.sakaiproject.site.cover.SiteService.getSiteVisit(SiteService.java:130)
        at org.sakaiproject.portal.util.PortalSiteHelper.getSiteVisit(PortalSiteHelper.java:559)
        at org.sakaiproject.portal.charon.handlers.SiteHandler.doSite(SiteHandler.java:189)
        at org.sakaiproject.portal.charon.handlers.SiteHandler.doGet(SiteHandler.java:114)
        at org.sakaiproject.portal.charon.SkinnableCharonPortal.doGet(SkinnableCharonPortal.java:891)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:690)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:803)
        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:269)
        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:188)
        at org.sakaiproject.util.RequestFilter.doFilter(RequestFilter.java:592)
        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:215)
        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:188)
        at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:210)
        at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:174)
        at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127)
        at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:117)
        at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:108)
        at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:151)
        at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:870)
        at org.apache.coyote.http11.Http11BaseProtocol$Http11ConnectionHandler.processConnection(Http11BaseProtocol.java:665)
        at org.apache.tomcat.util.net.PoolTcpEndpoint.processSocket(PoolTcpEndpoint.java:528)
        at org.apache.tomcat.util.net.LeaderFollowerWorkerThread.runIt(LeaderFollowerWorkerThread.java:81)
        at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:685)
        at java.lang.Thread.run(Thread.java:595)
Caused by: java.lang.NullPointerException
        at com.mysql.jdbc.ServerPreparedStatement.serverExecute(ServerPreparedStatement.java:1396)
        at com.mysql.jdbc.ServerPreparedStatement.executeInternal(ServerPreparedStatement.java:838)
        ... 38 more

A patch for this bug has been committed. After review, it may
be pushed to the relevant source trees for release in the next
version. You can access the patch from:

  http://lists.mysql.com/commits/44686

An entry has been added to the 5.1.6 Changelog:

When useServerPrepStmts=true and slow query logging is enabled, the connector throws a NullPointerException when it encounters a slow query.

A patch for this bug has been committed. After review, it may
be pushed to the relevant source trees for release in the next
version. You can access the patch from:

  http://lists.mysql.com/commits/50724

Page generated in 0.039 sec. using MySQL 8.4.7-u6-cloud

Timestamp references displayed by the system are UTC.
Content reproduced on this site is the property of the respective copyright holders.
It is not reviewed in advance by Oracle and does not necessarily represent the opinion of Oracle or any other party.