Bug #50432 first call to stored procedure after a long time give "function does not exist"
Submitted: 19 Jan 2010 7:58 Modified: 25 Jan 2010 6:50
Reporter: Kenneth NGUYEN Email Updates:
Status: Not a Bug Impact on me:
None 
Category:MySQL Server: Prepared statements Severity:S3 (Non-critical)
Version:5.1.32 OS:Solaris
Assigned to: CPU Architecture:Any
Tags: function does not exist

[19 Jan 2010 7:58] Kenneth NGUYEN
Description:
A first reference to a store procedure after a long time, i.e. a day or so, gives SQLException: FUNCTION ... does not exist. 

Subsequence reference to the function is OK. However, the problem repeats if we donot refer to the same function for a day or so.

How to repeat:
Here is the code from the program:
--------------------------------------------------------------------------------
 public TransactionVO[] getCsoInfo(int msisdn) 
 {
		TransactionVO[] trans = null;
		Connection conn = null;
		ResultSet rs = null;
		CallableStatement cStmt = null;
		
		try 
		{
			InitialContext ic = new InitialContext();
			DataSource ds = (DataSource) ic.lookup("java:comp/env/jdbc/PrepaidDB");
			conn = ds.getConnection();

			cStmt = conn.prepareCall("{call GETCSOINFO(?,?,?)}");
			cStmt.setInt(1, msisdn);
			cStmt.registerOutParameter(2, Types.BOOLEAN);
			cStmt.registerOutParameter(3, Types.INTEGER);
			cStmt.setQueryTimeout(1800);

			if (cStmt.execute()) 
			{
				boolean valid = false;
				String topUpStatus = "999";
				
				valid = cStmt.getBoolean(2);
				rs = cStmt.getResultSet();
				
				if(valid)
				{
					int totalrecords = cStmt.getInt(3);
					trans = new TransactionVO[totalrecords];
					
					while (rs.next()) 
					{
						
						
						
						
					}
				}
				else
				{
					
				}
			} 
			else 
			{
				
			}

			rs.close();
			rs = null;
			cStmt.close();
			cStmt = null;
			conn.close(); // Return to connection pool
			conn = null; // Make sure we don't close it twice
		} 
		catch (SQLException e) 
		{
			serviceLogger.error(clientIP + "\t| " +msisdn+ "\t| SQLException: " + e.getMessage());
		} catch (NamingException e) 
		{
			// TODO Auto-generated catch block
			e.printStackTrace();
			serviceLogger.error(clientIP + "\t| " +msisdn+ "\t| NamingException: " + e.getMessage());
		} 
		finally 
		{
			// Always make sure result sets and statements are closed,
			// and the connection is returned to the pool
			if (rs != null) {
				try {
					rs.close();
				} catch (SQLException e) {
					;
				}
				rs = null;
			}
			if (cStmt != null) {
				try {
					cStmt.close();
				} catch (SQLException e) {
					;
				}
				cStmt = null;
			}
			if (conn != null) {
				try {
					conn.close();
				} catch (SQLException e) {
					;
				}
				conn = null;
			}
		}
		
		return trans;
 }

---------------------------------------------------------------------------- 
The first activation after a long time will give error:

ERROR | 2010-01-19 13:54:47,154 | DatabaseController.java        | getCsoInfo                | 10.128.74.31     | 83103932      | SQLException: FUNCTION GETCSOINFO does not exist
 
but upon second trigger (2010-01-19 13:54:58,722), there is no error.
[19 Jan 2010 13:12] Tonci Grgin
Hi Kenneth and thanks for your report.

What happens if you add autoreconnect=true option to your connection string? Which version of c/J do you use? Are you using any pooling mechanism?
[20 Jan 2010 2:40] Kenneth NGUYEN
Hi Sveta,
Here is our connect string:

<Resource name="jdbc/PrepaidDB" auth="Container" type="javax.sql.DataSource"
               maxActive="100" maxIdle="30" maxWait="10000"
               username="xxxx" password="xxxx" driverClassName="com.mysql.jdbc.Driver"
               url="jdbc:mysql://10.252.65.181,10.252.65.182/prepaidbbom?autoReconnect=true&amp;failOverReadOnly=false"/> 

At the time of the error, there is no failover. 
Here is our driver:  mysql-connector-java-5.1.7-bin.jar 

Thanks and regards,
Kenneth
[20 Jan 2010 9:53] Tonci Grgin
Kenneth, you do realize I'm not Sveta, right ;-)

Now, you should realize that your connection is stale... Please reconfigure pool you're using to check validity of connection before using it, with PING or something.
This is expected behavior for me as c/J does not know that the connection pool is dealing out is stale, it's pool's responsibility to deal out only valid connections.
[22 Jan 2010 1:54] Kenneth NGUYEN
Hi Tonci,
We have changed the connection pool to test the connection, but the problem persists.

<Resource name="jdbc/PrepaidDB" auth="Container" type="javax.sql.DataSource" 
               factory="org.apache.commons.dbcp.BasicDataSourceFactory"
               validationQuery="SELECT 1"
               maxActive="100" maxIdle="30" maxWait="10000"
               username="xxxx" password="xxxx" driverClassName="com.mysql.jdbc.Driver"
               testOnBorrow="true" 
               url="jdbc:mysql://10.252.65.181,10.252.65.182/prepaidbbom?autoReconnect=true&amp;failOverReadOnly=false"/> 
 
Regards,
[22 Jan 2010 9:25] Tonci Grgin
Hi Kenneth.

First things first. Since c/J 5.1.3 the validation query is:
/* ping */ (exactly) so please change it.
The number of your max... connections in pool configuration is rather high, are you sure MySQL server is set for such high number of connections? Please check server variables and make changes if necessary.
Still, this looks like pool dealing out stale connections since it happens much after default wait_timeout passes ( wait_timeout             | 28800).
To me, the scenario appears to be:
  o *all* of the connections get disconnected since wait_timeout has long passed
  o pool checks connection but as it was disconnected, it takes some time to restore it (and with different id) thus pool discards it as non-valid
  o pool runs completely out of connections thus your first call does not return
  o pool and c/J have no means of communication, so c/J knows nothing of pools troubles
  o auto-reconnect in c/J kicks in, new connection is established, second call succeeds

So, I'd change validation query first and then reconfigure pool like this:
  testWhileIdle=true (which also activates the evictor thread)
  timeBetweenEvictionRunsMillis=<no of millisecs between eviction runs>
I think testing while idle will help keep connections actually connected to MySQL server during long periods of inactivity.
But, start with changing validation query first, so that it matches your c/J version.
[22 Jan 2010 9:29] Tonci Grgin
Ping changes described in http://lists.mysql.com/announce/482:
* Specifying a "validation query" in your connection pool that starts with
 "/* ping */"
_exactly_ will cause the driver to instead send a ping to the server and return a fake result set (much   lighter weight), and when using a ReplicationConnection or a LoadBalancedConnection, will send the ping across all active connections.
[25 Jan 2010 2:10] Kenneth NGUYEN
Thanks, Tonci. The problem has been solved! :-)
[25 Jan 2010 6:50] Tonci Grgin
No problem Kenneth, glad it works now.

Bug#50544 has been filed to cover this change in documentation.