search

ibm-cloud-architecture / cloudpak-for-applications

Apache License 2.0
25 stars 34 forks source link

DB2 SQL Error: SQLCODE=-1035, SQLSTATE=57019, SQLERRMC=null, DRIVER=4.27.25 #5

Closed tivrfoa closed 3 years ago

tivrfoa commented 3 years ago

Hi!

I'm testing the quarkus branch. I'm running on Ubuntu 18.04

I started the DB2 successfully:

docker run -itd --name db2-cos --privileged=true -p 50000:50000 -e LICENSE=accept -e DB2INST1_PASSWORD=db2inst1 -e DBNAME=orderdb vandepol/db2-cos
Unable to find image 'vandepol/db2-cos:latest' locally
latest: Pulling from vandepol/db2-cos
ac9208207ada: Pull complete 
db3b974ae005: Pull complete 
c85ac4b59d53: Pull complete 
37c3a9982fa6: Pull complete 
3d09beecf055: Pull complete 
a21a7002b66f: Pull complete 
4af2eb854f2a: Pull complete 
db9454eb22df: Pull complete 
3125ca754c1c: Pull complete 
9c2109d1d43d: Pull complete 
b85909f67209: Pull complete 
7ed52f6068b5: Pull complete 
Digest: sha256:d49d6665a3c8124383d4294fa36087c29d01a4fca57132577abebf7725e85bc8
Status: Downloaded newer image for vandepol/db2-cos:latest
a44ccc8a0738ad81ecabcedf7765833038e2103a96089a17c2a2cdf872ff19dc
user:~$ docker ps
CONTAINER ID        IMAGE               COMMAND                  CREATED              STATUS              PORTS                                                          NAMES
a44ccc8a0738        vandepol/db2-cos    "/var/db2_setup/lib/…"   About a minute ago   Up About a minute   22/tcp, 55000/tcp, 60006-60007/tcp, 0.0.0.0:50000->50000/tcp   db2-cos

But got the error:

2020-11-17 10:24:26,096 INFO  [io.quarkus] (Quarkus Main Thread) customer-order-services-quarkus 1.0-SNAPSHOT on JVM (powered by Quarkus 1.9.1.Final) started in 10.339s. Listening on: http://0.0.0.0:8080
2020-11-17 10:24:26,100 INFO  [io.quarkus] (Quarkus Main Thread) Profile dev activated. Live Coding activated.
2020-11-17 10:24:26,100 INFO  [io.quarkus] (Quarkus Main Thread) Installed features: [agroal, cdi, hibernate-orm, jdbc-db2, mutiny, narayana-jta, resteasy, resteasy-jsonb, smallrye-context-propagation]
2
2020-11-17 10:24:53,125 WARN  [io.agr.pool] (Agroal_14145862941) Datasource '<default>': DB2 SQL Error: SQLCODE=-1035, SQLSTATE=57019, SQLERRMC=null, DRIVER=4.27.25
2020-11-17 10:24:53,126 WARN  [org.hib.eng.jdb.spi.SqlExceptionHelper] (executor-thread-2) SQL Error: -1035, SQLState: 57019
2020-11-17 10:24:53,126 ERROR [org.hib.eng.jdb.spi.SqlExceptionHelper] (executor-thread-2) DB2 SQL Error: SQLCODE=-1035, SQLSTATE=57019, SQLERRMC=null, DRIVER=4.27.25
2020-11-17 10:24:53,135 ERROR [io.qua.ver.htt.run.QuarkusErrorHandler] (executor-thread-2) HTTP Request to /jaxrs/Category failed, error id: 45ff06b3-4e20-40a5-8fad-3882d358a916-1: org.jboss.resteasy.spi.UnhandledException: javax.persistence.PersistenceException: org.hibernate.exception.GenericJDBCException: Unable to acquire JDBC Connection
    at org.jboss.resteasy.core.ExceptionHandler.handleApplicationException(ExceptionHandler.java:106)
    at org.jboss.resteasy.core.ExceptionHandler.handleException(ExceptionHandler.java:372)
    at org.jboss.resteasy.core.SynchronousDispatcher.writeException(SynchronousDispatcher.java:218)
    at org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:519)
    at org.jboss.resteasy.core.SynchronousDispatcher.lambda$invoke$4(SynchronousDispatcher.java:261)
    at org.jboss.resteasy.core.SynchronousDispatcher.lambda$preprocess$0(SynchronousDispatcher.java:161)
    at org.jboss.resteasy.core.interception.jaxrs.PreMatchContainerRequestContext.filter(PreMatchContainerRequestContext.java:364)
    at org.jboss.resteasy.core.SynchronousDispatcher.preprocess(SynchronousDispatcher.java:164)
    at org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:247)
    at io.quarkus.resteasy.runtime.standalone.RequestDispatcher.service(RequestDispatcher.java:73)
    at io.quarkus.resteasy.runtime.standalone.VertxRequestHandler.dispatch(VertxRequestHandler.java:131)
    at io.quarkus.resteasy.runtime.standalone.VertxRequestHandler.access$000(VertxRequestHandler.java:37)
    at io.quarkus.resteasy.runtime.standalone.VertxRequestHandler$1.run(VertxRequestHandler.java:94)
    at io.quarkus.runtime.CleanableExecutor$CleaningRunnable.run(CleanableExecutor.java:231)
    at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)
    at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
    at org.jboss.threads.ContextClassLoaderSavingRunnable.run(ContextClassLoaderSavingRunnable.java:35)
    at org.jboss.threads.EnhancedQueueExecutor.safeRun(EnhancedQueueExecutor.java:2046)
    at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.doRunTask(EnhancedQueueExecutor.java:1578)
    at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1426)
    at org.jboss.threads.DelegatingRunnable.run(DelegatingRunnable.java:29)
    at org.jboss.threads.ThreadLocalResettingRunnable.run(ThreadLocalResettingRunnable.java:29)
    at java.base/java.lang.Thread.run(Thread.java:834)
    at org.jboss.threads.JBossThread.run(JBossThread.java:479)
Caused by: javax.persistence.PersistenceException: org.hibernate.exception.GenericJDBCException: Unable to acquire JDBC Connection
    at org.hibernate.internal.ExceptionConverterImpl.convert(ExceptionConverterImpl.java:154)
    at org.hibernate.query.internal.AbstractProducedQuery.list(AbstractProducedQuery.java:1542)
    at org.hibernate.query.Query.getResultList(Query.java:165)
    at org.pwte.example.service.ProductSearchServiceImpl.getTopLevelCategories(ProductSearchServiceImpl.java:59)
    at org.pwte.example.service.ProductSearchServiceImpl_ClientProxy.getTopLevelCategories(ProductSearchServiceImpl_ClientProxy.zig:285)
    at org.pwte.example.resources.CategoryResource.loadTopLevelCategories(CategoryResource.java:57)
    at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
    at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.base/java.lang.reflect.Method.invoke(Method.java:566)
    at org.jboss.resteasy.core.MethodInjectorImpl.invoke(MethodInjectorImpl.java:170)
    at org.jboss.resteasy.core.MethodInjectorImpl.invoke(MethodInjectorImpl.java:130)
    at org.jboss.resteasy.core.ResourceMethodInvoker.internalInvokeOnTarget(ResourceMethodInvoker.java:643)
    at org.jboss.resteasy.core.ResourceMethodInvoker.invokeOnTargetAfterFilter(ResourceMethodInvoker.java:507)
    at org.jboss.resteasy.core.ResourceMethodInvoker.lambda$invokeOnTarget$2(ResourceMethodInvoker.java:457)
    at org.jboss.resteasy.core.interception.jaxrs.PreMatchContainerRequestContext.filter(PreMatchContainerRequestContext.java:364)
    at org.jboss.resteasy.core.ResourceMethodInvoker.invokeOnTarget(ResourceMethodInvoker.java:459)
    at org.jboss.resteasy.core.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:419)
    at org.jboss.resteasy.core.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:393)
    at org.jboss.resteasy.core.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:68)
    at org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:492)
    ... 20 more
Caused by: org.hibernate.exception.GenericJDBCException: Unable to acquire JDBC Connection
    at org.hibernate.exception.internal.StandardSQLExceptionConverter.convert(StandardSQLExceptionConverter.java:47)
    at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:113)
    at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:99)
    at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.acquireConnectionIfNeeded(LogicalConnectionManagedImpl.java:111)
    at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.getPhysicalConnection(LogicalConnectionManagedImpl.java:138)
    at org.hibernate.engine.jdbc.internal.StatementPreparerImpl.connection(StatementPreparerImpl.java:50)
    at org.hibernate.engine.jdbc.internal.StatementPreparerImpl$5.doPrepare(StatementPreparerImpl.java:149)
    at org.hibernate.engine.jdbc.internal.StatementPreparerImpl$StatementPreparationTemplate.prepareStatement(StatementPreparerImpl.java:176)
    at org.hibernate.engine.jdbc.internal.StatementPreparerImpl.prepareQueryStatement(StatementPreparerImpl.java:151)
    at org.hibernate.loader.Loader.prepareQueryStatement(Loader.java:2104)
    at org.hibernate.loader.Loader.executeQueryStatement(Loader.java:2041)
    at org.hibernate.loader.Loader.executeQueryStatement(Loader.java:2019)
    at org.hibernate.loader.Loader.doQuery(Loader.java:948)
    at org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:349)
    at org.hibernate.loader.Loader.doList(Loader.java:2850)
    at org.hibernate.loader.Loader.doList(Loader.java:2832)
    at org.hibernate.loader.Loader.listIgnoreQueryCache(Loader.java:2664)
    at org.hibernate.loader.Loader.list(Loader.java:2659)
    at org.hibernate.loader.hql.QueryLoader.list(QueryLoader.java:506)
    at org.hibernate.hql.internal.ast.QueryTranslatorImpl.list(QueryTranslatorImpl.java:400)
    at org.hibernate.engine.query.spi.HQLQueryPlan.performList(HQLQueryPlan.java:219)
    at org.hibernate.internal.SessionImpl.list(SessionImpl.java:1414)
    at org.hibernate.query.internal.AbstractProducedQuery.doList(AbstractProducedQuery.java:1565)
    at org.hibernate.query.internal.AbstractProducedQuery.list(AbstractProducedQuery.java:1533)
    ... 39 more
Caused by: com.ibm.db2.jcc.am.SqlException: DB2 SQL Error: SQLCODE=-1035, SQLSTATE=57019, SQLERRMC=null, DRIVER=4.27.25
    at com.ibm.db2.jcc.am.b7.a(b7.java:815)
    at com.ibm.db2.jcc.am.b7.a(b7.java:66)
    at com.ibm.db2.jcc.am.b7.a(b7.java:140)
    at com.ibm.db2.jcc.am.Connection.completeSqlca(Connection.java:5285)
    at com.ibm.db2.jcc.t4.z.q(z.java:865)
    at com.ibm.db2.jcc.t4.z.p(z.java:721)
    at com.ibm.db2.jcc.t4.z.l(z.java:542)
    at com.ibm.db2.jcc.t4.z.d(z.java:153)
    at com.ibm.db2.jcc.t4.b.k(b.java:1498)
    at com.ibm.db2.jcc.t4.b.b(b.java:1410)
    at com.ibm.db2.jcc.t4.b.a(b.java:6804)
    at com.ibm.db2.jcc.t4.b.b(b.java:931)
    at com.ibm.db2.jcc.t4.b.a(b.java:844)
    at com.ibm.db2.jcc.t4.b.a(b.java:443)
    at com.ibm.db2.jcc.t4.b.a(b.java:416)
    at com.ibm.db2.jcc.t4.b.<init>(b.java:354)
    at com.ibm.db2.jcc.DB2SimpleDataSource.getConnection(DB2SimpleDataSource.java:233)
    at com.ibm.db2.jcc.DB2SimpleDataSource.getConnection(DB2SimpleDataSource.java:200)
    at com.ibm.db2.jcc.DB2Driver.connect(DB2Driver.java:474)
    at com.ibm.db2.jcc.DB2Driver.connect(DB2Driver.java:116)
    at io.agroal.pool.ConnectionFactory.createConnection(ConnectionFactory.java:200)
    at io.agroal.pool.ConnectionPool$CreateConnectionTask.call(ConnectionPool.java:419)
    at io.agroal.pool.ConnectionPool$CreateConnectionTask.call(ConnectionPool.java:401)
    at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
    at io.agroal.pool.util.PriorityScheduledExecutor.beforeExecute(PriorityScheduledExecutor.java:65)
    at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1126)
    at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
    at java.base/java.lang.Thread.run(Thread.java:834)
tivrfoa commented 3 years ago

So, I think docker command to start DB2 hadn't finished. I run the docker on the foreground so I could see what it does, and after a long time (11 minutes) it finished.

$ docker start -ia db2-cos 
(*) Preparing the environment before updating the instance ... 
(*) Fixing /etc/services file for DB2 ... 
(*) Fixing db2nodes file configuration ... 
11/17/2020 13:37:15     0   0   SQL1032N  No start database manager command was issued.
SQL1032N  No start database manager command was issued.  SQLSTATE=57019
(*) Creating instance ... 
DBI1446I  The db2icrt command is running.
...
...
...
2020-11-17-13.48.09.037804+000 E413027E526           LEVEL: Event
PID     : 21052                TID : 139760135825152 PROC : db2sysc 0
INSTANCE: db2inst1             NODE : 000            DB   : ORDERDB
APPHDL  : 0-61                 APPID: *LOCAL.db2inst1.201117134759
AUTHID  : DB2INST1             HOSTNAME: a44ccc8a0738
EDUID   : 130                  EDUNAME: db2agent (idle) 0
FUNCTION: DB2 UDB, base sys utilities, sqeLocalDatabase::FreeResourcesOnDBShutdown, probe:16479
STOP    : DATABASE: ORDERDB  : DEACTIVATED: NO

I don't know why it takes so long to start, but my humble machine also doesn't help ...