Failed to connect to cloud based MySQL compatiable service

Dremio used to work great with cloud based MySQL 5.6 compatible service - RDS, which is provided by aliyun.com.

But recently we purchased a new instance of RDS (MySQL 5.6) and Dremio failed to connect. I’m running Dremio 3.1 with docker and following traces are shown in the logs:

standalone_1  | 2019-03-12 07:15:38,377 [Plugin Startup: testdb] ERROR c.d.e.store.jdbc.JdbcStoragePlugin - Connection is not valid.
standalone_1  | java.sql.SQLException: Unknown system variable 'session_track_schema'
standalone_1  | 	at org.mariadb.jdbc.internal.util.exceptions.ExceptionMapper.get(ExceptionMapper.java:179) ~[mariadb-java-client-1.6.2.jar:na]
standalone_1  | 	at org.mariadb.jdbc.internal.util.exceptions.ExceptionMapper.getException(ExceptionMapper.java:118) ~[mariadb-java-client-1.6.2.jar:na]
standalone_1  | 	at org.mariadb.jdbc.internal.util.exceptions.ExceptionMapper.throwException(ExceptionMapper.java:92) ~[mariadb-java-client-1.6.2.jar:na]
standalone_1  | 	at org.mariadb.jdbc.MariaDbDataSource.getConnection(MariaDbDataSource.java:262) ~[mariadb-java-client-1.6.2.jar:na]
standalone_1  | 	at org.mariadb.jdbc.MariaDbDataSource.getPooledConnection(MariaDbDataSource.java:410) ~[mariadb-java-client-1.6.2.jar:na]
standalone_1  | 	at org.apache.commons.dbcp2.datasources.InstanceKeyDataSource.testCPDS(InstanceKeyDataSource.java:1018) ~[commons-dbcp2-2.2.0.jar:2.2.0]
standalone_1  | 	at org.apache.commons.dbcp2.datasources.SharedPoolDataSource.registerPool(SharedPoolDataSource.java:167) ~[commons-dbcp2-2.2.0.jar:2.2.0]
standalone_1  | 	at org.apache.commons.dbcp2.datasources.SharedPoolDataSource.getPooledConnectionAndInfo(SharedPoolDataSource.java:127) ~[commons-dbcp2-2.2.0.jar:2.2.0]
standalone_1  | 	at org.apache.commons.dbcp2.datasources.InstanceKeyDataSource.getConnection(InstanceKeyDataSource.java:884) ~[commons-dbcp2-2.2.0.jar:2.2.0]
standalone_1  | 	at org.apache.commons.dbcp2.datasources.InstanceKeyDataSource.getConnection(InstanceKeyDataSource.java:858) ~[commons-dbcp2-2.2.0.jar:2.2.0]
standalone_1  | 	at com.dremio.exec.store.jdbc.CloseableDataSource$DatasourceWrapper.getConnection(CloseableDataSource.java:87) ~[dremio-extra-plugin-jdbc-3.1.3-201902130614340856-5cd4808.jar:3.1.3-201902130614340856-5cd4808]
standalone_1  | 	at com.dremio.exec.store.jdbc.JdbcStoragePlugin.getState(JdbcStoragePlugin.java:404) ~[dremio-extra-plugin-jdbc-3.1.3-201902130614340856-5cd4808.jar:3.1.3-201902130614340856-5cd4808]
standalone_1  | 	at com.dremio.exec.catalog.ManagedStoragePlugin.setLocals(ManagedStoragePlugin.java:450) [dremio-sabot-kernel-3.1.3-201902130614340856-5cd4808.jar:3.1.3-201902130614340856-5cd4808]
standalone_1  | 	at com.dremio.exec.catalog.ManagedStoragePlugin.access$600(ManagedStoragePlugin.java:76) [dremio-sabot-kernel-3.1.3-201902130614340856-5cd4808.jar:3.1.3-201902130614340856-5cd4808]
standalone_1  | 	at com.dremio.exec.catalog.ManagedStoragePlugin$1.run(ManagedStoragePlugin.java:256) [dremio-sabot-kernel-3.1.3-201902130614340856-5cd4808.jar:3.1.3-201902130614340856-5cd4808]
standalone_1  | 	at com.dremio.concurrent.RenamingRunnable.run(RenamingRunnable.java:36) [dremio-common-3.1.3-201902130614340856-5cd4808.jar:3.1.3-201902130614340856-5cd4808]
standalone_1  | 	at com.dremio.concurrent.SingletonRunnable.run(SingletonRunnable.java:41) [dremio-common-3.1.3-201902130614340856-5cd4808.jar:3.1.3-201902130614340856-5cd4808]
standalone_1  | 	at com.dremio.concurrent.SafeRunnable.run(SafeRunnable.java:40) [dremio-common-3.1.3-201902130614340856-5cd4808.jar:3.1.3-201902130614340856-5cd4808]
standalone_1  | 	at com.dremio.concurrent.Runnables$1.run(Runnables.java:45) [dremio-common-3.1.3-201902130614340856-5cd4808.jar:3.1.3-201902130614340856-5cd4808]
standalone_1  | Caused by: java.sql.SQLException: Unknown system variable 'session_track_schema'
standalone_1  | 	at org.mariadb.jdbc.internal.protocol.AbstractQueryProtocol.readErrorPacket(AbstractQueryProtocol.java:1193) ~[mariadb-java-client-1.6.2.jar:na]
standalone_1  | 	at org.mariadb.jdbc.internal.protocol.AbstractQueryProtocol.readPacket(AbstractQueryProtocol.java:1068) ~[mariadb-java-client-1.6.2.jar:na]
standalone_1  | 	at org.mariadb.jdbc.internal.protocol.AbstractQueryProtocol.getResult(AbstractQueryProtocol.java:1031) ~[mariadb-java-client-1.6.2.jar:na]
standalone_1  | 	at org.mariadb.jdbc.internal.protocol.AbstractConnectProtocol.additionalData(AbstractConnectProtocol.java:606) ~[mariadb-java-client-1.6.2.jar:na]
standalone_1  | 	at org.mariadb.jdbc.internal.protocol.AbstractConnectProtocol.connect(AbstractConnectProtocol.java:426) ~[mariadb-java-client-1.6.2.jar:na]
standalone_1  | 	at org.mariadb.jdbc.internal.protocol.AbstractConnectProtocol.connectWithoutProxy(AbstractConnectProtocol.java:1028) ~[mariadb-java-client-1.6.2.jar:na]
standalone_1  | 	at org.mariadb.jdbc.internal.util.Utils.retrieveProxy(Utils.java:483) ~[mariadb-java-client-1.6.2.jar:na]
standalone_1  | 	at org.mariadb.jdbc.MariaDbDataSource.getConnection(MariaDbDataSource.java:259) ~[mariadb-java-client-1.6.2.jar:na]
standalone_1  | 	... 15 common frames omitted
standalone_1  | 2019-03-12 07:15:38,412 [qtp1343715686-126] INFO  c.d.exec.catalog.CatalogServiceImpl - User Error Occurred [ErrorId: acdb0612-ebd7-4442-9dc2-b9b7ef6bab82]
standalone_1  | com.dremio.common.exceptions.UserException: Failure while configuring source [testdb]
standalone_1  | 	at com.dremio.common.exceptions.UserException$Builder.build(UserException.java:746) ~[dremio-common-3.1.3-201902130614340856-5cd4808.jar:3.1.3-201902130614340856-5cd4808]
standalone_1  | 	at com.dremio.exec.catalog.CatalogServiceImpl.createOrUpdateSource(CatalogServiceImpl.java:639) [dremio-sabot-kernel-3.1.3-201902130614340856-5cd4808.jar:3.1.3-201902130614340856-5cd4808]
standalone_1  | 	at com.dremio.exec.catalog.CatalogServiceImpl.createSource(CatalogServiceImpl.java:378) [dremio-sabot-kernel-3.1.3-201902130614340856-5cd4808.jar:3.1.3-201902130614340856-5cd4808]
standalone_1  | 	at com.dremio.exec.catalog.CatalogServiceImpl.access$600(CatalogServiceImpl.java:102) [dremio-sabot-kernel-3.1.3-201902130614340856-5cd4808.jar:3.1.3-201902130614340856-5cd4808]
standalone_1  | 	at com.dremio.exec.catalog.CatalogServiceImpl$SourceModifier.createSource(CatalogServiceImpl.java:972) [dremio-sabot-kernel-3.1.3-201902130614340856-5cd4808.jar:3.1.3-201902130614340856-5cd4808]
standalone_1  | 	at com.dremio.exec.catalog.CatalogImpl.createSource(CatalogImpl.java:519) [dremio-sabot-kernel-3.1.3-201902130614340856-5cd4808.jar:3.1.3-201902130614340856-5cd4808]
standalone_1  | 	at com.dremio.exec.catalog.DelegatingCatalog.createSource(DelegatingCatalog.java:189) [dremio-sabot-kernel-3.1.3-201902130614340856-5cd4808.jar:3.1.3-201902130614340856-5cd4808]
standalone_1  | 	at com.dremio.dac.service.source.SourceService.registerSourceWithRuntime(SourceService.java:157) [dremio-dac-backend-3.1.3-201902130614340856-5cd4808.jar:3.1.3-201902130614340856-5cd4808]
standalone_1  | 	at com.dremio.dac.service.source.SourceService.registerSourceWithRuntime(SourceService.java:148) [dremio-dac-backend-3.1.3-201902130614340856-5cd4808.jar:3.1.3-201902130614340856-5cd4808]
standalone_1  | 	at com.dremio.dac.service.source.SourceService.registerSourceWithRuntime(SourceService.java:144) [dremio-dac-backend-3.1.3-201902130614340856-5cd4808.jar:3.1.3-201902130614340856-5cd4808]
standalone_1  | 	at com.dremio.dac.resource.PutSourceResource.putSource(PutSourceResource.java:80) [dremio-dac-backend-3.1.3-201902130614340856-5cd4808.jar:3.1.3-201902130614340856-5cd4808]
standalone_1  | 	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:1.8.0_181]
standalone_1  | 	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[na:1.8.0_181]
standalone_1  | 	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.8.0_181]
standalone_1  | 	at java.lang.reflect.Method.invoke(Method.java:498) ~[na:1.8.0_181]
standalone_1  | 	at org.glassfish.jersey.server.model.internal.ResourceMethodInvocationHandlerFactory$1.invoke(ResourceMethodInvocationHandlerFactory.java:81) [jersey-server-2.25.1.jar:na]
standalone_1  | 	at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher$1.run(AbstractJavaResourceMethodDispatcher.java:144) [jersey-server-2.25.1.jar:na]
standalone_1  | 	at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.invoke(AbstractJavaResourceMethodDispatcher.java:161) [jersey-server-2.25.1.jar:na]
standalone_1  | 	at org.glassfish.jersey.server.model.internal.JavaResourceMethodDispatcherProvider$TypeOutInvoker.doDispatch(JavaResourceMethodDispatcherProvider.java:205) [jersey-server-2.25.1.jar:na]
standalone_1  | 	at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.dispatch(AbstractJavaResourceMethodDispatcher.java:99) [jersey-server-2.25.1.jar:na]
standalone_1  | 	at org.glassfish.jersey.server.model.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:389) [jersey-server-2.25.1.jar:na]
standalone_1  | 	at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:347) [jersey-server-2.25.1.jar:na]
standalone_1  | 	at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:102) [jersey-server-2.25.1.jar:na]
standalone_1  | 	at org.glassfish.jersey.server.ServerRuntime$2.run(ServerRuntime.java:326) [jersey-server-2.25.1.jar:na]
standalone_1  | 	at org.glassfish.jersey.internal.Errors$1.call(Errors.java:271) [jersey-common-2.25.1.jar:na]
standalone_1  | 	at org.glassfish.jersey.internal.Errors$1.call(Errors.java:267) [jersey-common-2.25.1.jar:na]
standalone_1  | 	at org.glassfish.jersey.internal.Errors.process(Errors.java:315) [jersey-common-2.25.1.jar:na]
standalone_1  | 	at org.glassfish.jersey.internal.Errors.process(Errors.java:297) [jersey-common-2.25.1.jar:na]
standalone_1  | 	at org.glassfish.jersey.internal.Errors.process(Errors.java:267) [jersey-common-2.25.1.jar:na]
standalone_1  | 	at org.glassfish.jersey.process.internal.RequestScope.runInScope(RequestScope.java:317) [jersey-common-2.25.1.jar:na]
standalone_1  | 	at org.glassfish.jersey.server.ServerRuntime.process(ServerRuntime.java:305) [jersey-server-2.25.1.jar:na]
standalone_1  | 	at org.glassfish.jersey.server.ApplicationHandler.handle(ApplicationHandler.java:1154) [jersey-server-2.25.1.jar:na]
standalone_1  | 	at org.glassfish.jersey.servlet.WebComponent.serviceImpl(WebComponent.java:473) [jersey-container-servlet-core-2.25.1.jar:na]
standalone_1  | 	at org.glassfish.jersey.servlet.WebComponent.service(WebComponent.java:427) [jersey-container-servlet-core-2.25.1.jar:na]
standalone_1  | 	at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:388) [jersey-container-servlet-core-2.25.1.jar:na]
standalone_1  | 	at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:341) [jersey-container-servlet-core-2.25.1.jar:na]
standalone_1  | 	at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:228) [jersey-container-servlet-core-2.25.1.jar:na]
standalone_1  | 	at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:812) [jetty-servlet-9.2.26.v20180806.jar:9.2.26.v20180806]
standalone_1  | 	at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1669) [jetty-servlet-9.2.26.v20180806.jar:9.2.26.v20180806]
standalone_1  | 	at org.eclipse.jetty.servlets.UserAgentFilter.doFilter(UserAgentFilter.java:83) [jetty-servlets-9.2.26.v20180806.jar:9.2.26.v20180806]
standalone_1  | 	at org.eclipse.jetty.servlets.GzipFilter.doFilter(GzipFilter.java:301) [jetty-servlets-9.2.26.v20180806.jar:9.2.26.v20180806]
standalone_1  | 	at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1652) [jetty-servlet-9.2.26.v20180806.jar:9.2.26.v20180806]
standalone_1  | 	at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:585) [jetty-servlet-9.2.26.v20180806.jar:9.2.26.v20180806]
standalone_1  | 	at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1127) [jetty-server-9.2.26.v20180806.jar:9.2.26.v20180806]
standalone_1  | 	at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:515) [jetty-servlet-9.2.26.v20180806.jar:9.2.26.v20180806]
standalone_1  | 	at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1061) [jetty-server-9.2.26.v20180806.jar:9.2.26.v20180806]
standalone_1  | 	at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141) [jetty-server-9.2.26.v20180806.jar:9.2.26.v20180806]
standalone_1  | 	at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:97) [jetty-server-9.2.26.v20180806.jar:9.2.26.v20180806]
standalone_1  | 	at org.eclipse.jetty.server.handler.RequestLogHandler.handle(RequestLogHandler.java:95) [jetty-server-9.2.26.v20180806.jar:9.2.26.v20180806]
standalone_1  | 	at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:97) [jetty-server-9.2.26.v20180806.jar:9.2.26.v20180806]
standalone_1  | 	at org.eclipse.jetty.server.Server.handle(Server.java:499) [jetty-server-9.2.26.v20180806.jar:9.2.26.v20180806]
standalone_1  | 	at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:311) [jetty-server-9.2.26.v20180806.jar:9.2.26.v20180806]
standalone_1  | 	at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:258) [jetty-server-9.2.26.v20180806.jar:9.2.26.v20180806]
standalone_1  | 	at org.eclipse.jetty.io.AbstractConnection$2.run(AbstractConnection.java:544) [jetty-io-9.2.26.v20180806.jar:9.2.26.v20180806]
standalone_1  | 	at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:635) [jetty-util-9.2.26.v20180806.jar:9.2.26.v20180806]
standalone_1  | 	at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:555) [jetty-util-9.2.26.v20180806.jar:9.2.26.v20180806]
standalone_1  | 	at java.lang.Thread.run(Thread.java:748) [na:1.8.0_181]
standalone_1  | Caused by: java.util.concurrent.ExecutionException: java.lang.Exception: Unavailable: Unknown system variable 'session_track_schema'
standalone_1  | 	at com.google.common.util.concurrent.AbstractFuture.getDoneValue(AbstractFuture.java:500) ~[guava-20.0.jar:na]
standalone_1  | 	at com.google.common.util.concurrent.AbstractFuture.get(AbstractFuture.java:401) ~[guava-20.0.jar:na]
standalone_1  | 	at com.google.common.util.concurrent.AbstractFuture$TrustedFuture.get(AbstractFuture.java:83) ~[guava-20.0.jar:na]
standalone_1  | 	at com.google.common.util.concurrent.ForwardingFuture.get(ForwardingFuture.java:68) ~[guava-20.0.jar:na]
standalone_1  | 	at com.google.common.util.concurrent.AbstractCheckedFuture.checkedGet(AbstractCheckedFuture.java:104) ~[guava-20.0.jar:na]
standalone_1  | 	at com.dremio.exec.catalog.CatalogServiceImpl.createOrUpdateSource(CatalogServiceImpl.java:627) [dremio-sabot-kernel-3.1.3-201902130614340856-5cd4808.jar:3.1.3-201902130614340856-5cd4808]
standalone_1  | 	... 55 common frames omitted
standalone_1  | Caused by: java.lang.Exception: Unavailable: Unknown system variable 'session_track_schema'
standalone_1  | 	at com.dremio.exec.catalog.ManagedStoragePlugin$1.run(ManagedStoragePlugin.java:261) ~[dremio-sabot-kernel-3.1.3-201902130614340856-5cd4808.jar:3.1.3-201902130614340856-5cd4808]
standalone_1  | 	at com.dremio.concurrent.RenamingRunnable.run(RenamingRunnable.java:36) ~[dremio-common-3.1.3-201902130614340856-5cd4808.jar:3.1.3-201902130614340856-5cd4808]
standalone_1  | 	at com.dremio.concurrent.SingletonRunnable.run(SingletonRunnable.java:41) ~[dremio-common-3.1.3-201902130614340856-5cd4808.jar:3.1.3-201902130614340856-5cd4808]
standalone_1  | 	at com.dremio.concurrent.SafeRunnable.run(SafeRunnable.java:40) ~[dremio-common-3.1.3-201902130614340856-5cd4808.jar:3.1.3-201902130614340856-5cd4808]
standalone_1  | 	at com.dremio.concurrent.Runnables$1.run(Runnables.java:45) ~[dremio-common-3.1.3-201902130614340856-5cd4808.jar:3.1.3-201902130614340856-5cd4808]
standalone_1  | 172.17.0.1 - - [12/Mar/2019:07:15:38 +0000] "PUT /apiv2/source/testdb?nocache=1552374937340 HTTP/1.0" 400 130 "https://dremio.hireall.cn/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_14_3) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/72.0.3626.119 Safari/537.36"

To my understanding, session_track_schema is a variable introduced in MySQL 5.7 but somehow some logic within com.dremio.exec.store.jdbc.CloseableDataSource or the higher stack is asking Dremio to connect the DB with it. Looks like Dremio sees the new RDS instance as MySQL 5.7?

Is that part of Dremio non-oss (I failed to find the related source code)? Or any help on explaining the logic which related to the session_track_schema setting would be appreciated.

BTW, while showing this error connecting to the new RDS instance, Dremio could still connect the old RDS correctly. Both of the instances are claimed to be compatible with MySQL 5.6 and having innodb _version of 5.6.16. There are only minor version differences customized by aliyun.com exists between the 2 instances. I tried to tweak around but no luck to make Dremio work with the new instance.

We’ve fixed the issue and for anyone who might be interested in the solution:

The cloud service provider aliyun.com did some tricky work to re-use the unused MySQL capability bit of 5.6 to indicate some other customized service capability.

However, mariadb-java-client-1.6.2.jar honers this bit and attempts to do what it’s meant for, which the 5.6 server is actually not capable with.

So a ugly solution is to comment out following codes in mariadb-connector-j:

if ((serverCapabilities & MariaDbServerCapabilities.CLIENT_SESSION_TRACK) != 0) {
    sessionOption.append(", session_track_schema=1");
    if (options.rewriteBatchedStatements) {
        sessionOption.append(", session_track_system_variables='auto_increment_increment' ");
    }
}

and compile / replace the library shipped with Dremio.

1 Like