Any Issues with Servlet Listener and WebSphere?

I’m getting a strange error deploying to WebSphere. It’s a new database so the change sets are running for the first time. It appears to be attempting to create the lock table more than once. Here’s the log:

    [8/19/09 15:51:02:017 EST] 0000001d liquibase     I   Create Database Lock Table [8/19/09 15:51:02:695 EST] 0000001d liquibase     I   Create Database Lock Table [8/19/09 15:51:02:798 EST] 0000001d FFDCJanitor   I com.ibm.ws.ffdc.impl.FFDCJanitor doCleanupIfNeeded FFDCJANITOR_DELETED_FILES [8/19/09 15:51:03:829 EST] 0000001d FfdcProvider  I com.ibm.ws.ffdc.impl.FfdcProvider logIncident FFDC1003I: FFDC Incident emitted on /cgu/Dev/was/profiles/DevCgu2N1/logs/ffdc/Dev1CguEmbsM1_1d681d68_09.08.19_15.51.02.8587966554215370852797.txt com.ibm.ws.rsadapter.jdbc.WSJccStatement.pmiExecute 1192 [8/19/09 15:51:03:855 EST] 0000001d FfdcProvider  I com.ibm.ws.ffdc.impl.FfdcProvider logIncident FFDC1003I: FFDC Incident emitted on /cgu/Dev/was/profiles/DevCgu2N1/logs/ffdc/Dev1CguEmbsM1_1d681d68_09.08.19_15.51.03.8391347178466102139222.txt com.ibm.ws.rsadapter.jdbc.WSJdbcStatement.execute 296 [8/19/09 15:51:04:015 EST] 0000001d FfdcProvider  I com.ibm.ws.ffdc.impl.FfdcProvider logIncident FFDC1003I: FFDC Incident emitted on /cgu/Dev/was/profiles/DevCgu2N1/logs/ffdc/Dev1CguEmbsM1_1d681d68_09.08.19_15.51.03.8793722506604788977227.txt com.ibm.ws.webcontainer.webapp.WebApp.notifyServletContextCreated 1341 [8/19/09 15:51:04:026 EST] 0000001d webapp        E com.ibm.ws.webcontainer.webapp.WebApp notifyServletContextCreated SRVE0283E: Exception caught while initializing context: {0}                                  java.lang.RuntimeException: liquibase.exception.LockException: liquibase.exception.JDBCException: Error executing SQL CREATE TABLE DATABASECHANGELOGLOCK (ID INT NOT NULL, LOCKED SMALLINT NOT NULL, LOCKGRANTED TIMESTAMP, LOCKEDBY VARCHAR(255), CONSTRAINT PK_DBCHGLOGLOCK PRIMARY KEY (ID)) at liquibase.servlet.LiquibaseServletListener.contextInitialized(LiquibaseServletListener.java:149) at com.ibm.ws.webcontainer.webapp.WebApp.notifyServletContextCreated(WebApp.java:1591) at com.ibm.ws.webcontainer.webapp.WebApp.commonInitializationFinish(WebApp.java:353) at com.ibm.ws.webcontainer.webapp.WebAppImpl.initialize(WebAppImpl.java:293) at com.ibm.ws.webcontainer.webapp.WebGroupImpl.addWebApplication(WebGroupImpl.java:100) at com.ibm.ws.webcontainer.VirtualHostImpl.addWebApplication(VirtualHostImpl.java:166) at com.ibm.ws.webcontainer.WSWebContainer.addWebApp(WSWebContainer.java:728) at com.ibm.ws.webcontainer.WSWebContainer.addWebApplication(WSWebContainer.java:613) at com.ibm.ws.webcontainer.component.WebContainerImpl.install(WebContainerImpl.java:376) at com.ibm.ws.webcontainer.component.WebContainerImpl.start(WebContainerImpl.java:668) at com.ibm.ws.runtime.component.ApplicationMgrImpl.start(ApplicationMgrImpl.java:1144) at com.ibm.ws.runtime.component.DeployedApplicationImpl.fireDeployedObjectStart(DeployedApplicationImpl.java:1313) at com.ibm.ws.runtime.component.DeployedModuleImpl.start(DeployedModuleImpl.java:611) at com.ibm.ws.runtime.component.DeployedApplicationImpl.start(DeployedApplicationImpl.java:938) at com.ibm.ws.runtime.component.ApplicationMgrImpl.startApplication(ApplicationMgrImpl.java:723) at com.ibm.ws.runtime.component.ApplicationMgrImpl$1.run(ApplicationMgrImpl.java:1288) at com.ibm.ws.security.auth.ContextManagerImpl.runAs(ContextManagerImpl.java:4388) at com.ibm.ws.security.auth.ContextManagerImpl.runAsSystem(ContextManagerImpl.java:4566) at com.ibm.ws.security.core.SecurityContext.runAsSystem(SecurityContext.java:255) at com.ibm.ws.runtime.component.ApplicationMgrImpl.startApplicationDynamically(ApplicationMgrImpl.java:1293) at com.ibm.ws.runtime.component.ApplicationMgrImpl.start(ApplicationMgrImpl.java:2065) at com.ibm.ws.runtime.component.CompositionUnitMgrImpl.start(CompositionUnitMgrImpl.java:437) at com.ibm.ws.runtime.component.CompositionUnitImpl.start(CompositionUnitImpl.java:122) at com.ibm.ws.runtime.component.CompositionUnitMgrImpl.start(CompositionUnitMgrImpl.java:380) at com.ibm.ws.runtime.component.CompositionUnitMgrImpl.startCompositionUnit(CompositionUnitMgrImpl.java:651) at com.ibm.ws.runtime.component.CompositionUnitMgrImpl.startCompositionUnit(CompositionUnitMgrImpl.java:613) at com.ibm.ws.runtime.component.ApplicationMgrImpl.startApplication(ApplicationMgrImpl.java:1199) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:37) at java.lang.reflect.Method.invoke(Method.java:599) at sun.reflect.misc.Trampoline.invoke(MethodUtil.java:36) at sun.reflect.GeneratedMethodAccessor42.invoke(Unknown Source) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:37) at java.lang.reflect.Method.invoke(Method.java:599) at sun.reflect.misc.MethodUtil.invoke(MethodUtil.java:243) at javax.management.modelmbean.RequiredModelMBean.invokeMethod(RequiredModelMBean.java:1085) at javax.management.modelmbean.RequiredModelMBean.invoke(RequiredModelMBean.java:966) at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.invoke(DefaultMBeanServerInterceptor.java:848) at com.sun.jmx.mbeanserver.JmxMBeanServer.invoke(JmxMBeanServer.java:773) at com.ibm.ws.management.AdminServiceImpl$1.run(AdminServiceImpl.java:1310) at com.ibm.ws.security.util.AccessController.doPrivileged(AccessController.java:118) at com.ibm.ws.management.AdminServiceImpl.invoke(AdminServiceImpl.java:1203) at com.ibm.ws.management.connector.AdminServiceDelegator.invoke(AdminServiceDelegator.java:181) at com.ibm.ws.management.connector.ipc.CallRouter.route(CallRouter.java:242) at com.ibm.ws.management.connector.ipc.IPCConnectorInboundLink.doWork(IPCConnectorInboundLink.java:292) at com.ibm.ws.management.connector.ipc.IPCConnectorInboundLink$IPCConnectorReadCallback.complete(IPCConnectorInboundLink.java:514) at com.ibm.ws.tcp.channel.impl.AioReadCompletionListener.futureCompleted(AioReadCompletionListener.java:165) at com.ibm.io.async.AbstractAsyncFuture.invokeCallback(AbstractAsyncFuture.java:217) at com.ibm.io.async.AsyncChannelFuture.fireCompletionActions(AsyncChannelFuture.java:161) at com.ibm.io.async.AsyncFuture.completed(AsyncFuture.java:138) at com.ibm.io.async.ResultHandler.complete(ResultHandler.java:204) at com.ibm.io.async.ResultHandler.runEventProcessingLoop(ResultHandler.java:775) at com.ibm.io.async.ResultHandler$2.run(ResultHandler.java:905) at com.ibm.ws.util.ThreadPool$Worker.run(ThreadPool.java:1527) Caused by: liquibase.exception.LockException: liquibase.exception.JDBCException: Error executing SQL CREATE TABLE DATABASECHANGELOGLOCK (ID INT NOT NULL, LOCKED SMALLINT NOT NULL, LOCKGRANTED TIMESTAMP, LOCKEDBY VARCHAR(255), CONSTRAINT PK_DBCHGLOGLOCK PRIMARY KEY (ID)) at liquibase.lock.LockHandler.acquireLock(LockHandler.java:79) at liquibase.lock.LockHandler.waitForLock(LockHandler.java:150) at liquibase.Liquibase.update(Liquibase.java:100) at liquibase.servlet.LiquibaseServletListener.contextInitialized(LiquibaseServletListener.java:137) ... 54 more Caused by: liquibase.exception.JDBCException: Error executing SQL CREATE TABLE DATABASECHANGELOGLOCK (ID INT NOT NULL, LOCKED SMALLINT NOT NULL, LOCKGRANTED TIMESTAMP, LOCKEDBY VARCHAR(255), CONSTRAINT PK_DBCHGLOGLOCK PRIMARY KEY (ID)) at liquibase.database.template.JdbcTemplate.execute(JdbcTemplate.java:55) at liquibase.database.template.JdbcTemplate.execute(JdbcTemplate.java:86) at liquibase.database.AbstractDatabase.checkDatabaseChangeLogLockTable(AbstractDatabase.java:755) at liquibase.lock.LockHandler.acquireLock(LockHandler.java:40) ... 57 more Caused by: com.ibm.db2.jcc.a.ho: The name of the object to be created is identical to the existing name "EMBS.DATABASECHANGELOGLOCK" of type "TABLE".. SQLCODE=-601, SQLSTATE=42710, DRIVER=4.3.85 at com.ibm.db2.jcc.a.dd.a(dd.java:676) at com.ibm.db2.jcc.a.dd.a(dd.java:60) at com.ibm.db2.jcc.a.dd.a(dd.java:127) at com.ibm.db2.jcc.a.im.c(im.java:2483) at com.ibm.db2.jcc.a.im.d(im.java:2460) at com.ibm.db2.jcc.a.im.b(im.java:1901) at com.ibm.db2.jcc.t4.db.h(db.java:219) at com.ibm.db2.jcc.t4.db.b(db.java:45) at com.ibm.db2.jcc.t4.t.b(t.java:38) at com.ibm.db2.jcc.t4.sb.g(sb.java:120) at com.ibm.db2.jcc.a.im.cb(im.java:1896) at com.ibm.db2.jcc.a.im.a(im.java:2821) at com.ibm.db2.jcc.a.im.e(im.java:970) at com.ibm.db2.jcc.a.im.execute(im.java:954) at com.ibm.ws.rsadapter.jdbc.WSJdbcStatement.pmiExecute(WSJdbcStatement.java:1485) at com.ibm.ws.rsadapter.jdbc.WSJdbcStatement.execute(WSJdbcStatement.java:632) at liquibase.database.template.JdbcTemplate$1ExecuteStatementCallback.doInStatement(JdbcTemplate.java:78) at liquibase.database.template.JdbcTemplate.execute(JdbcTemplate.java:48) ... 60 more

Thanks in advance,
Christian.

I have not tried liquibase under websphere, but it should work fine.  There was an issue at one point with liquibase trying to create the databasechangelog table twice under certain circumstances. 

If you run it again now that the table was created does it work?

What version of liquibase are you running?

Nathan

If you run it again now that the table was created does it work?

What version of liquibase are you running?

I would have thought it would move on too but on the next attempt it still tries to create the databasechangelogLock table. Maybe the call to connection.getMetaData() from the JDBC driver on the websphere box is querying the wrong catalog table and thus making LiquiBase think the table isn’t there. But this seems very unlikely. I’ll get some JDBC logging turned on and look into further. The process is a little slow as I don’t have immediate access to this box.

The version of LiquiBase is 1.9.4.

Thanks again,
Christian.

OK I worked out the problem. This issue is reproducible on any app server using a connection to DB2.

The problem is in our Websphere environment the guys set up an additional connection parameter of “currentShema=TheDefaultSchema”.

I’ve created http://liquibase.jira.com/browse/CORE-448 explaining how to reproduce the issue.