SQLCODE=-290 – Roll forward pending on table space when OS is restarted

A customer had caused themselves a bit of bother by restarting the OS before shutting down DB2 just thinking that it will deal with it….

After doing this only Files wasn’t working so I checked the SystemOut.log and saw the following error.

[5/8/12 15:28:07:729 GMT] 00000016 SchedulerTask E   CLFWY0327E: Unable to sync scheduler task information with configuration.
com.ibm.websphere.scheduler.SchedulerNotAvailableException: com.ibm.db2.jcc.am.SqlException: Table space access is not allowed.. SQLCODE=-290, SQLSTATE=55039, DRIVER=3.59.81
at com.ibm.ws.scheduler.TaskStoreImpl.findByName(TaskStoreImpl.java:1579)
at com.ibm.ws.scheduler.SchedulerImpl$7.run(SchedulerImpl.java:1912)
at java.security.AccessController.doPrivileged(AccessController.java:251)
at com.ibm.ws.scheduler.SchedulerImpl.findByName(SchedulerImpl.java:1881)
at com.ibm.ws.scheduler.SchedulerImpl.findByName(SchedulerImpl.java:1865)
at com.ibm.ws.scheduler.SchedulerImpl.findTasksByName(SchedulerImpl.java:1828)
at com.ibm.lconn.scheduler.admintasks.SchedulerTaskManager.syncSchedulerTasksWithConfig(SchedulerTaskManager.java:153)
at com.ibm.lconn.scheduler.service.Scheduler.init(Scheduler.java:74)
at com.ibm.quickr.share.platform.config.Platform.<init>(Platform.java:450)
at com.ibm.quickr.share.platform.config.Platform.init(Platform.java:669)
at com.ibm.quickr.share.platform.config.PlatformInitializer.contextInitialized(PlatformInitializer.java:28)
at com.ibm.ws.webcontainer.webapp.WebApp.notifyServletContextCreated(WebApp.java:1707)
at com.ibm.ws.webcontainer.webapp.WebApp.commonInitializationFinish(WebApp.java:380)
at com.ibm.ws.webcontainer.webapp.WebAppImpl.initialize(WebAppImpl.java:299)
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:731)
at com.ibm.ws.webcontainer.WSWebContainer.addWebApplication(WSWebContainer.java:616)
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:1123)
at com.ibm.ws.runtime.component.DeployedApplicationImpl.fireDeployedObjectStart(DeployedApplicationImpl.java:1319)
at com.ibm.ws.runtime.component.DeployedModuleImpl.start(DeployedModuleImpl.java:610)
at com.ibm.ws.runtime.component.DeployedApplicationImpl.fireDeployedObjectStart(DeployedApplicationImpl.java:1319)
at com.ibm.ws.runtime.component.DeployedModuleImpl.start(DeployedModuleImpl.java:610)
at com.ibm.ws.runtime.component.DeployedApplicationImpl.start(DeployedApplicationImpl.java:944)
at com.ibm.ws.runtime.component.ApplicationMgrImpl.startApplication(ApplicationMgrImpl.java:726)
at com.ibm.ws.runtime.component.ApplicationMgrImpl.start(ApplicationMgrImpl.java:2048)
at com.ibm.ws.runtime.component.CompositionUnitMgrImpl.start(CompositionUnitMgrImpl.java:441)
at com.ibm.ws.runtime.component.CompositionUnitImpl.start(CompositionUnitImpl.java:123)
at com.ibm.ws.runtime.component.CompositionUnitMgrImpl.start(CompositionUnitMgrImpl.java:384)
at com.ibm.ws.runtime.component.CompositionUnitMgrImpl.access$300(CompositionUnitMgrImpl.java:112)
at com.ibm.ws.runtime.component.CompositionUnitMgrImpl$CUInitializer.run(CompositionUnitMgrImpl.java:951)
at com.ibm.wsspi.runtime.component.WsComponentImpl$_AsynchInitializer.run(WsComponentImpl.java:349)
at com.ibm.ws.util.ThreadPool$Worker.run(ThreadPool.java:1604)
Caused by: com.ibm.db2.jcc.am.SqlException: Table space access is not allowed.. SQLCODE=-290, SQLSTATE=55039, DRIVER=3.59.81
at com.ibm.db2.jcc.am.dd.a(dd.java:679)
at com.ibm.db2.jcc.am.dd.a(dd.java:60)
at com.ibm.db2.jcc.am.dd.a(dd.java:127)
at com.ibm.db2.jcc.am.qm.b(qm.java:3900)
at com.ibm.db2.jcc.am.qm.a(qm.java:3882)
at com.ibm.db2.jcc.t4.cb.a(cb.java:793)
at com.ibm.db2.jcc.t4.cb.m(cb.java:763)
at com.ibm.db2.jcc.t4.cb.i(cb.java:246)
at com.ibm.db2.jcc.t4.cb.c(cb.java:54)
at com.ibm.db2.jcc.t4.q.c(q.java:44)
at com.ibm.db2.jcc.t4.rb.j(rb.java:147)
at com.ibm.db2.jcc.am.bn.ib(bn.java:2048)
at com.ibm.db2.jcc.am.cn.b(cn.java:3845)
at com.ibm.db2.jcc.am.cn.bc(cn.java:678)
at com.ibm.db2.jcc.am.cn.executeQuery(cn.java:652)
at com.ibm.ws.rsadapter.jdbc.WSJdbcPreparedStatement.pmiExecuteQuery(WSJdbcPreparedStatement.java:1099)
at com.ibm.ws.rsadapter.jdbc.WSJdbcPreparedStatement.executeQuery(WSJdbcPreparedStatement.java:720)
at com.ibm.ws.scheduler.TaskStoreImpl.executeQueryWithRetry(TaskStoreImpl.java:1775)
at com.ibm.ws.scheduler.TaskStoreImpl$ExecuteQueryPriviledged.run(TaskStoreImpl.java:1662)
at java.security.AccessController.doPrivileged(AccessController.java:251)
at com.ibm.ws.scheduler.TaskStoreImpl.executePrivilegedQueryWithRetry(TaskStoreImpl.java:1831)
at com.ibm.ws.scheduler.TaskStoreImpl.findByName(TaskStoreImpl.java:1490)
… 32 more

I restarted the application but the same appeared so I checked DB2. The db2diag.log found by running db2 get dbm cfg | grep -i diag was huge so I archived it using b2diag -A and shut everything (Connections and DB2) down and then started it back up again.

Picking through the db2diag.log I found the following warning.

2012-05-10-09.30.00.093460+000 E46586E440          LEVEL: Warning
PID     : 26475                TID  : 1088047424   PROC : db2acd 0
INSTANCE: db2inst1             NODE : 000
FUNCTION: DB2 UDB, Health Monitor, HealthIndicator::update, probe:500
MESSAGE : ADM10502W  Health indicator “Table Space Operational State”
(“ts.ts_op_status”) is in state “Roll forward pending” on “table
space” “db2inst1.FILES   .FILESTS32”.

A bit of Googling found TSM Server Fails to Start with ANR9999D_3831306406, sqlCode=-290 with a suggestion of how to deal with it. When the OS’ rug was pulled out from underneath it DB2 was probably performing an action on this table space. When DB2 came back up it was marked as “pending roll forward” effectively saying, “hey is it safe to continue what I was doing?”

Running db2 “rollforward db FILES to end of logs tablespace(FILESTS32) online” replayed the logs and changed the status and on a restart of Files the application was accessible.

                                 Rollforward Status

Input database alias                   = FILES
Number of nodes have returned status   = 1

Node number                            = 0
Rollforward status                     = not pending
Next log file to be read               =
Log files processed                    =  –
Last committed transaction             = 2012-05-07-13.41.18.000000 UTC

DB20000I  The ROLLFORWARD command completed successfully.

Advertisements