GAE DevAppServer is forcibly killing my MySQL connection after 5 seconds

10 views
Skip to first unread message

Derek A. via StackOverflow

unread,
Aug 8, 2016, 2:01:06 PM8/8/16
to google-appengin...@googlegroups.com

I working on a port of our Web application to GAE and Google Cloud SQL. I am using MySQL 5.6 and the DevAppServer locally during development, and I have some queries that take longer than 5 seconds to return. There seems to be some sort of default timeout and the query fails after approximately 5 seconds in the DevAppServer. I have not yet tried running this in GAE directly (mainly because I can't complete the page because the query keeps failing).

Here is the call stack:

Aug 08, 2016 10:34:05 AM org.glassfish.jersey.server.ServerRuntime$Responder mapException
FINER: Starting mapping of the exception.
org.glassfish.jersey.server.internal.process.MappableException: com.mysql.jdbc.exceptions.jdbc4.CommunicationsException: Communications link failure

The last packet successfully received from the server was 5,006 milliseconds ago.  The last packet sent successfully to the server was 5,001 milliseconds ago.
    at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.mapTargetToRuntimeEx(AbstractJavaResourceMethodDispatcher.java:179)
    at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.access$200(AbstractJavaResourceMethodDispatcher.java:72)
    at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher$1.run(AbstractJavaResourceMethodDispatcher.java:149)
    at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.invoke(AbstractJavaResourceMethodDispatcher.java:161)
    at org.glassfish.jersey.server.model.internal.JavaResourceMethodDispatcherProvider$ResponseOutInvoker.doDispatch(JavaResourceMethodDispatcherProvider.java:160)
    at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.dispatch(AbstractJavaResourceMethodDispatcher.java:99)
    at org.glassfish.jersey.server.model.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:389)
    at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:347)
    at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:102)
    at org.glassfish.jersey.server.ServerRuntime$2.run(ServerRuntime.java:326)
    at org.glassfish.jersey.internal.Errors$1.call(Errors.java:271)
    at org.glassfish.jersey.internal.Errors$1.call(Errors.java:267)
    at org.glassfish.jersey.internal.Errors.process(Errors.java:315)
    at org.glassfish.jersey.internal.Errors.process(Errors.java:297)
    at org.glassfish.jersey.internal.Errors.process(Errors.java:267)
    at org.glassfish.jersey.process.internal.RequestScope.runInScope(RequestScope.java:317)
    at org.glassfish.jersey.server.ServerRuntime.process(ServerRuntime.java:305)
    at org.glassfish.jersey.server.ApplicationHandler.handle(ApplicationHandler.java:1154)
    at org.glassfish.jersey.servlet.WebComponent.serviceImpl(WebComponent.java:473)
    at org.glassfish.jersey.servlet.WebComponent.service(WebComponent.java:427)
    at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:388)
    at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:341)
    at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:228)
    at org.mortbay.jetty.servlet.ServletHolder.handle(ServletHolder.java:511)
    at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1166)
    at com.google.appengine.api.socket.dev.DevSocketFilter.doFilter(DevSocketFilter.java:74)
    at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1157)
    at com.google.appengine.tools.development.ResponseRewriterFilter.doFilter(ResponseRewriterFilter.java:128)
    at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1157)
    at com.google.appengine.tools.development.HeaderVerificationFilter.doFilter(HeaderVerificationFilter.java:34)
    at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1157)
    at com.google.appengine.api.blobstore.dev.ServeBlobFilter.doFilter(ServeBlobFilter.java:63)
    at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1157)
    at com.google.apphosting.utils.servlet.TransactionCleanupFilter.doFilter(TransactionCleanupFilter.java:50)
    at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1157)
    at com.google.appengine.tools.development.StaticFileFilter.doFilter(StaticFileFilter.java:125)
    at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1157)
    at com.google.appengine.tools.development.DevAppServerModulesFilter.doDirectRequest(DevAppServerModulesFilter.java:366)
    at com.google.appengine.tools.development.DevAppServerModulesFilter.doDirectModuleRequest(DevAppServerModulesFilter.java:349)
    at com.google.appengine.tools.development.DevAppServerModulesFilter.doFilter(DevAppServerModulesFilter.java:116)
    at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1157)
    at org.mortbay.jetty.servlet.ServletHandler.handle(ServletHandler.java:388)
    at org.mortbay.jetty.security.SecurityHandler.handle(SecurityHandler.java:216)
    at org.mortbay.jetty.servlet.SessionHandler.handle(SessionHandler.java:182)
    at org.mortbay.jetty.handler.ContextHandler.handle(ContextHandler.java:765)
    at org.mortbay.jetty.webapp.WebAppContext.handle(WebAppContext.java:418)
    at com.google.appengine.tools.development.DevAppEngineWebAppContext.handle(DevAppEngineWebAppContext.java:98)
    at org.mortbay.jetty.handler.HandlerWrapper.handle(HandlerWrapper.java:152)
    at com.google.appengine.tools.development.JettyContainerService$ApiProxyHandler.handle(JettyContainerService.java:511)
    at org.mortbay.jetty.handler.HandlerWrapper.handle(HandlerWrapper.java:152)
    at org.mortbay.jetty.Server.handle(Server.java:326)
    at org.mortbay.jetty.HttpConnection.handleRequest(HttpConnection.java:542)
    at org.mortbay.jetty.HttpConnection$RequestHandler.headerComplete(HttpConnection.java:923)
    at org.mortbay.jetty.HttpParser.parseNext(HttpParser.java:547)
    at org.mortbay.jetty.HttpParser.parseAvailable(HttpParser.java:212)
    at org.mortbay.jetty.HttpConnection.handle(HttpConnection.java:404)
    at org.mortbay.io.nio.SelectChannelEndPoint.run(SelectChannelEndPoint.java:409)
    at org.mortbay.thread.QueuedThreadPool$PoolThread.run(QueuedThreadPool.java:582)
Caused by: com.mysql.jdbc.exceptions.jdbc4.CommunicationsException: Communications link failure

The last packet successfully received from the server was 5,006 milliseconds ago.  The last packet sent successfully to the server was 5,001 milliseconds ago.
    at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
    at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:57)
    at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
    at java.lang.reflect.Constructor.newInstance(Constructor.java:526)
    at com.google.appengine.tools.development.agent.runtime.Runtime.newInstance_(Runtime.java:142)
    at com.google.appengine.tools.development.agent.runtime.Runtime.newInstance(Runtime.java:150)
    at com.mysql.jdbc.Util.handleNewInstance(Util.java:404)
    at com.mysql.jdbc.SQLError.createCommunicationsException(SQLError.java:981)
    at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3465)
    at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3365)
    at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3805)
    at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:2478)
    at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2625)
    at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2551)
    at com.mysql.jdbc.PreparedStatement.executeInternal(PreparedStatement.java:1861)
    at com.mysql.jdbc.PreparedStatement.executeQuery(PreparedStatement.java:1962)
    at com.mysql.jdbc.CallableStatement.executeQuery(CallableStatement.java:858)
    at com.[redacted].[redacted].sql.SqlQuery.executeQuery(SqlQuery.java:132)
    at com.[redacted].[redacted].business.user.InterfaceManager.performDQLSearch(InterfaceManager.java:216)
    at com.[redacted].[redacted].business.user.InterfaceManager.performFilterSearch(InterfaceManager.java:275)
    at com.[redacted].[redacted].rest.client.Search.searchFilter(Search.java:139)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:606)
    at com.google.appengine.tools.development.agent.runtime.Runtime.invoke(Runtime.java:130)
    at org.glassfish.jersey.server.model.internal.ResourceMethodInvocationHandlerFactory$1.invoke(ResourceMethodInvocationHandlerFactory.java:81)
    at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher$1.run(AbstractJavaResourceMethodDispatcher.java:144)
    ... 55 more
Caused by: java.net.SocketException: Socket operation timed out: The API call remote_socket.Receive() took too long to respond and was cancelled.
    at com.google.appengine.api.socket.SocketApiHelper.makeSyncCall(SocketApiHelper.java:76)
    at com.google.appengine.api.socket.AppEngineSocketImpl.receive(AppEngineSocketImpl.java:710)
    at com.google.appengine.api.socket.AppEngineSocketInputStream.read(AppEngineSocketInputStream.java:35)
    at com.mysql.jdbc.util.ReadAheadInputStream.fill(ReadAheadInputStream.java:100)
    at com.mysql.jdbc.util.ReadAheadInputStream.readFromUnderlyingStreamIfNecessary(ReadAheadInputStream.java:143)
    at com.mysql.jdbc.util.ReadAheadInputStream.read(ReadAheadInputStream.java:173)
    at com.mysql.jdbc.MysqlIO.readFully(MysqlIO.java:2954)
    at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3375)
    ... 74 more

Aug 08, 2016 10:34:05 AM com.[redacted].[redacted].rest.internal.GenericExceptionMapper toResponse
SEVERE: Communications link failure

The last packet successfully received from the server was 5,006 milliseconds ago.  The last packet sent successfully to the server was 5,001 milliseconds ago.
com.mysql.jdbc.exceptions.jdbc4.CommunicationsException: Communications link failure

The last packet successfully received from the server was 5,006 milliseconds ago.  The last packet sent successfully to the server was 5,001 milliseconds ago.
    at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
    at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:57)
    at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
    at java.lang.reflect.Constructor.newInstance(Constructor.java:526)
    at com.google.appengine.tools.development.agent.runtime.Runtime.newInstance_(Runtime.java:142)
    at com.google.appengine.tools.development.agent.runtime.Runtime.newInstance(Runtime.java:150)
    at com.mysql.jdbc.Util.handleNewInstance(Util.java:404)
    at com.mysql.jdbc.SQLError.createCommunicationsException(SQLError.java:981)
    at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3465)
    at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3365)
    at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3805)
    at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:2478)
    at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2625)
    at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2551)
    at com.mysql.jdbc.PreparedStatement.executeInternal(PreparedStatement.java:1861)
    at com.mysql.jdbc.PreparedStatement.executeQuery(PreparedStatement.java:1962)
    at com.mysql.jdbc.CallableStatement.executeQuery(CallableStatement.java:858)
    at com.[redacted].[redacted].sql.SqlQuery.executeQuery(SqlQuery.java:132)
    at com.[redacted].[redacted].business.user.InterfaceManager.performDQLSearch(InterfaceManager.java:216)
    at com.[redacted].[redacted].business.user.InterfaceManager.performFilterSearch(InterfaceManager.java:275)
    at com.[redacted].[redacted].rest.client.Search.searchFilter(Search.java:139)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:606)
    at com.google.appengine.tools.development.agent.runtime.Runtime.invoke(Runtime.java:130)
    at org.glassfish.jersey.server.model.internal.ResourceMethodInvocationHandlerFactory$1.invoke(ResourceMethodInvocationHandlerFactory.java:81)
    at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher$1.run(AbstractJavaResourceMethodDispatcher.java:144)
    at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.invoke(AbstractJavaResourceMethodDispatcher.java:161)
    at org.glassfish.jersey.server.model.internal.JavaResourceMethodDispatcherProvider$ResponseOutInvoker.doDispatch(JavaResourceMethodDispatcherProvider.java:160)
    at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.dispatch(AbstractJavaResourceMethodDispatcher.java:99)
    at org.glassfish.jersey.server.model.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:389)
    at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:347)
    at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:102)
    at org.glassfish.jersey.server.ServerRuntime$2.run(ServerRuntime.java:326)
    at org.glassfish.jersey.internal.Errors$1.call(Errors.java:271)
    at org.glassfish.jersey.internal.Errors$1.call(Errors.java:267)
    at org.glassfish.jersey.internal.Errors.process(Errors.java:315)
    at org.glassfish.jersey.internal.Errors.process(Errors.java:297)
    at org.glassfish.jersey.internal.Errors.process(Errors.java:267)
    at org.glassfish.jersey.process.internal.RequestScope.runInScope(RequestScope.java:317)
    at org.glassfish.jersey.server.ServerRuntime.process(ServerRuntime.java:305)
    at org.glassfish.jersey.server.ApplicationHandler.handle(ApplicationHandler.java:1154)
    at org.glassfish.jersey.servlet.WebComponent.serviceImpl(WebComponent.java:473)
    at org.glassfish.jersey.servlet.WebComponent.service(WebComponent.java:427)
    at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:388)
    at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:341)
    at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:228)
    at org.mortbay.jetty.servlet.ServletHolder.handle(ServletHolder.java:511)
    at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1166)
    at com.google.appengine.api.socket.dev.DevSocketFilter.doFilter(DevSocketFilter.java:74)
    at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1157)
    at com.google.appengine.tools.development.ResponseRewriterFilter.doFilter(ResponseRewriterFilter.java:128)
    at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1157)
    at com.google.appengine.tools.development.HeaderVerificationFilter.doFilter(HeaderVerificationFilter.java:34)
    at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1157)
    at com.google.appengine.api.blobstore.dev.ServeBlobFilter.doFilter(ServeBlobFilter.java:63)
    at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1157)
    at com.google.apphosting.utils.servlet.TransactionCleanupFilter.doFilter(TransactionCleanupFilter.java:50)
    at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1157)
    at com.google.appengine.tools.development.StaticFileFilter.doFilter(StaticFileFilter.java:125)
    at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1157)
    at com.google.appengine.tools.development.DevAppServerModulesFilter.doDirectRequest(DevAppServerModulesFilter.java:366)
    at com.google.appengine.tools.development.DevAppServerModulesFilter.doDirectModuleRequest(DevAppServerModulesFilter.java:349)
    at com.google.appengine.tools.development.DevAppServerModulesFilter.doFilter(DevAppServerModulesFilter.java:116)
    at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1157)
    at org.mortbay.jetty.servlet.ServletHandler.handle(ServletHandler.java:388)
    at org.mortbay.jetty.security.SecurityHandler.handle(SecurityHandler.java:216)
    at org.mortbay.jetty.servlet.SessionHandler.handle(SessionHandler.java:182)
    at org.mortbay.jetty.handler.ContextHandler.handle(ContextHandler.java:765)
    at org.mortbay.jetty.webapp.WebAppContext.handle(WebAppContext.java:418)
    at com.google.appengine.tools.development.DevAppEngineWebAppContext.handle(DevAppEngineWebAppContext.java:98)
    at org.mortbay.jetty.handler.HandlerWrapper.handle(HandlerWrapper.java:152)
    at com.google.appengine.tools.development.JettyContainerService$ApiProxyHandler.handle(JettyContainerService.java:511)
    at org.mortbay.jetty.handler.HandlerWrapper.handle(HandlerWrapper.java:152)
    at org.mortbay.jetty.Server.handle(Server.java:326)
    at org.mortbay.jetty.HttpConnection.handleRequest(HttpConnection.java:542)
    at org.mortbay.jetty.HttpConnection$RequestHandler.headerComplete(HttpConnection.java:923)
    at org.mortbay.jetty.HttpParser.parseNext(HttpParser.java:547)
    at org.mortbay.jetty.HttpParser.parseAvailable(HttpParser.java:212)
    at org.mortbay.jetty.HttpConnection.handle(HttpConnection.java:404)
    at org.mortbay.io.nio.SelectChannelEndPoint.run(SelectChannelEndPoint.java:409)
    at org.mortbay.thread.QueuedThreadPool$PoolThread.run(QueuedThreadPool.java:582)
Caused by: java.net.SocketException: Socket operation timed out: The API call remote_socket.Receive() took too long to respond and was cancelled.
    at com.google.appengine.api.socket.SocketApiHelper.makeSyncCall(SocketApiHelper.java:76)
    at com.google.appengine.api.socket.AppEngineSocketImpl.receive(AppEngineSocketImpl.java:710)
    at com.google.appengine.api.socket.AppEngineSocketInputStream.read(AppEngineSocketInputStream.java:35)
    at com.mysql.jdbc.util.ReadAheadInputStream.fill(ReadAheadInputStream.java:100)
    at com.mysql.jdbc.util.ReadAheadInputStream.readFromUnderlyingStreamIfNecessary(ReadAheadInputStream.java:143)
    at com.mysql.jdbc.util.ReadAheadInputStream.read(ReadAheadInputStream.java:173)
    at com.mysql.jdbc.MysqlIO.readFully(MysqlIO.java:2954)
    at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3375)
    ... 74 more

Aug 08, 2016 10:34:05 AM com.[redacted].[redacted].rest.internal.ResponseUtils addCommonHeaders
FINE: Set response header -> Access-Control-Allow-Origin: *
Aug 08, 2016 10:34:05 AM org.glassfish.jersey.server.ServerRuntime$Responder mapException
FINER: Exception 'Communications link failure

The last packet successfully received from the server was 5,006 milliseconds ago.  The last packet sent successfully to the server was 5,001 milliseconds ago.' has been mapped by 'com.[redacted].[redacted].rest.internal.GenericExceptionMapper' to response 'Internal Server Error' (500:SERVER_ERROR).

It was able to put a break point in the MySQL driver code and found this exception:

java.net.SocketException: Socket operation timed out: The API call remote_socket.Receive() took too long to respond and was cancelled.

Socket operation timed out: The API call remote_socket.Receive() took too long to respond and was cancelled.

Now i have tried running the same SP call using my library code outside of the GAE DevAppServer and it works fine:

package com.[redacted].poc.sql.TestSQL;

import java.util.logging.Level;
import java.util.logging.Logger;

import org.apache.commons.lang3.time.StopWatch;

import com.[redacted].[redacted].data.DataTable;
import com.[redacted].[redacted].sql.AutoConnection;
import com.[redacted].[redacted].sql.DatabaseManager;
import com.[redacted].[redacted].sql.ResultSetEx;
import com.[redacted].[redacted].sql.SqlIntegerParameter;
import com.[redacted].[redacted].sql.SqlQuery;
import com.[redacted].[redacted].sql.SqlStringParameter;

/**
 * Hello world!
 *
 */
public class App {

    private static final Logger logger = Logger.getLogger(App.class.getName());

    public static void main(String[] args) {
        try {
            DatabaseManager.initialize("jdbc:mysql://127.0.0.1:3306/[redacted]?user=[redacted]&password=[redacted]");

            final String xml = [redacted];

            final StopWatch swTotal = new StopWatch();
            final StopWatch swRs1 = new StopWatch();
            final StopWatch swRs2 = new StopWatch();
            try (AutoConnection db = new AutoConnection(DatabaseManager.getDbConnection())) {
                assert (db != null);
                assert (db.getConnection() != null);
                try (final SqlQuery sql = DatabaseManager.buildStoredProcedureCall(logger, db.getConnection(),
                        "text_search", new SqlIntegerParameter("user_id", Integer.valueOf(2)),
                        new SqlIntegerParameter("project_id", Integer.valueOf(2)),
                        new SqlStringParameter("search_criteria_xml", xml), new SqlIntegerParameter("page_number", 1),
                        new SqlIntegerParameter("page_size", 25))) {
                    logger.info("Running query");
                    swTotal.start();
                    swRs1.start();
                    try (final ResultSetEx rs = new ResultSetEx(sql.executeQuery())) {
                        swRs1.stop();
                        final DataTable dt = DatabaseManager.copyToDataTable(rs);
                        logger.info(String.format("Returned %d rows", dt.getTotalRows()));

                        boolean pagingOk = false;

                        if (sql.getMoreResults()) {
                            swRs2.start();
                            try (final ResultSetEx rs2 = new ResultSetEx(sql.getResultSet())) {
                                swRs2.stop();
                                if (rs2.next()) {
                                    pagingOk = true;

                                    final int totalRows = rs2.getInt("total_rows");
                                    final int lastPageNum = rs2.getInt("page_number");
                                    final int lastPageSize = rs2.getInt("page_size");
                                    final int totalPages = rs2.getInt("total_pages");
                                    final String searchXml = rs2.getString("search_criteria_xml");
                                    dt.setTotalRows(totalRows);
                                    dt.setPageNumber(lastPageNum);
                                    dt.setPageSize(lastPageSize);
                                    dt.setTotalPages(totalPages);
                                    dt.setSearchXml(searchXml);
                                }
                            }
                        }
                        if (!pagingOk) {
                            throw new Exception("Paging information results missing");
                        }
                    }
                }
            } finally {
                logger.info("Total elapsed time  : " + swTotal.toString());
                logger.info("1st result set time :" + swRs1.toString());
                logger.info("2nd result set time :" + swRs2.toString());
            }
        } catch (Exception ex) {
            logger.log(Level.SEVERE, ex.getMessage(), ex);
        }
    }
}

Here is the output:

Aug 08, 2016 10:42:46 AM com.[redacted].poc.sql.TestSQL.App main
INFO: Running query
Aug 08, 2016 10:42:55 AM com.[redacted].poc.sql.TestSQL.App main
INFO: Returned 0 rows
Aug 08, 2016 10:42:55 AM com.[redacted].poc.sql.TestSQL.App main
INFO: Total elapsed time  : 00:00:08.900
Aug 08, 2016 10:42:55 AM com.[redacted].poc.sql.TestSQL.App main
INFO: 1st result set time :00:00:08.876
Aug 08, 2016 10:42:55 AM com.[redacted].poc.sql.TestSQL.App main
INFO: 2nd result set time :00:00:00.000

So it appears to me that something inside the GAE library is forcibly killing the SQL connection at the socket level. The application needs to process the query result, so I can't ignore it. Has anyone found a setting or some other way to resolve this issue? I've gone over the GAE docs at nausium, and done plenty of Google searching to no avail. It seems odd to me that there would be a hard 5 second limit on a query that you are unable to override. I know they allow a 60 second max timeout on UrlFetch and Task Queue calls, so I am hoping I am just missing something...



Please DO NOT REPLY directly to this email but go to StackOverflow:
http://stackoverflow.com/questions/38835647/gae-devappserver-is-forcibly-killing-my-mysql-connection-after-5-seconds

Derek A. via StackOverflow

unread,
Aug 8, 2016, 2:31:07 PM8/8/16
to google-appengin...@googlegroups.com
 main
INFO: Returned 25 rows
Aug 08, 2016 10:42:55 AM com.[redacted].poc.sql.TestSQL.App main
INFO: Total elapsed time  : 00:00:08.900
Aug 08, 2016 10:42:55 AM com.[redacted].poc.sql.TestSQL.App main
INFO: 1st result set time :00:00:08.876
Aug 08, 2016 10:42:55 AM com.[redacted].poc.sql.TestSQL.App main
INFO: 2nd result set time :00:00:00.000
Reply all
Reply to author
Forward
0 new messages