[AutosysPredictionEngine] Prediction for <Jobstream name> at <timestamp> timed out. Timeout period is 30

Products

• Automic Automation Intelligence

Issue/Introduction

After upgrading to AAI 6.0.0 the messages below were seen in the jaws.log

 

[AutosysPredictionEngine] Prediction for <Jobstream name> at 2020/05/22 07:52:28.000 CDT timed out.  Timeout period is 30

WARN  [GenericSessionImpl] error in rollback: : org.hibernate.TransactionException: JDBC rollback failed
        at org.hibernate.transaction.JDBCTransaction.rollback(JDBCTransaction.java:204)
        at com.termalabs.common.connection.hibernate.GenericSessionImpl.rollback(GenericSessionImpl.java:274)
        at com.termalabs.common.connection.hibernate.GenericSessionImpl.close(GenericSessionImpl.java:301)
        at com.termalabs.server.cache.JobStreamRunVendorImpl.getLatestJobStreamRun(JobStreamRunVendorImpl.java:615)
        at com.termalabs.server.autosys.old.PredictionEngineWorker.buildOrderedListOfJobs(PredictionEngineWorker.java:3217)
        at com.termalabs.server.autosys.old.PredictionEngineWorker.initJobs(PredictionEngineWorker.java:3140)
        at com.termalabs.server.autosys.old.PredictionEngineWorker.initVariables(PredictionEngineWorker.java:3071)
        at com.termalabs.server.autosys.old.PredictionEngineWorker.generatePrediction(PredictionEngineWorker.java:424)
        at com.termalabs.server.autosys.old.PredictionEngineWorker.run(PredictionEngineWorker.java:386)
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
        at java.util.concurrent.FutureTask.run(FutureTask.java:266)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
        at java.lang.Thread.run(Thread.java:748)
Caused by: java.sql.SQLRecoverableException: IO Error: Operation interrupted
        at oracle.jdbc.driver.T4CConnection.doRollback(T4CConnection.java:1041)
        at oracle.jdbc.driver.PhysicalConnection.rollback(PhysicalConnection.java:1966)
        at com.mchange.v2.c3p0.impl.NewProxyConnection.rollback(NewProxyConnection.java:855)
        at org.hibernate.transaction.JDBCTransaction.rollbackAndResetAutoCommit(JDBCTransaction.java:217)
        at org.hibernate.transaction.JDBCTransaction.rollback(JDBCTransaction.java:196)
        ... 13 more
Caused by: java.io.InterruptedIOException: Operation interrupted
        at oracle.net.nt.TimeoutSocketChannel.handleInterrupt(TimeoutSocketChannel.java:311)
        at oracle.net.nt.TimeoutSocketChannel.write(TimeoutSocketChannel.java:221)
        at oracle.net.ns.NIOPacket.writeToSocketChannel(NIOPacket.java:211)
        at oracle.net.ns.NIONSDataChannel.writeDataToSocketChannel(NIONSDataChannel.java:181)
        at oracle.net.ns.NIONSDataChannel.writeDataToSocketChannel(NIONSDataChannel.java:132)
        at oracle.jdbc.driver.T4CMAREngineNIO.prepareForReading(T4CMAREngineNIO.java:96)
        at oracle.jdbc.driver.T4CMAREngineNIO.unmarshalUB1(T4CMAREngineNIO.java:534)
        at oracle.jdbc.driver.T4CTTIfun.receive(T4CTTIfun.java:485)
        at oracle.jdbc.driver.T4CTTIfun.doRPC(T4CTTIfun.java:252)
        at oracle.jdbc.driver.T4C7Ocommoncall.doOROLLBACK(T4C7Ocommoncall.java:67)
        at oracle.jdbc.driver.T4CConnection.doRollback(T4CConnection.java:1036)
        ... 17 more

2020-06-08 11:27:43,052 ERROR [PredictionEngineWorker] Error in prediction: com.termalabs.common.datastore.DataAccessException: Error while executing query:
"from JobStreamRun jsr left join fetch jsr.jobStreamRunJobRuns where jsr.jobStream.id = :jobStreamId and jsr.initialJobRunStartTime = (select max(jsr.initial
JobRunStartTime) from JobStreamRun jsr  where jsr.jobStream.id = :jobStreamId  and jsr.complete = true)"; jobStreamId=UUID[<jobStreamID>]
        at com.termalabs.common.connection.hibernate.RichQueryCommon.executeAndTime(RichQueryCommon.java:1047)
        at com.termalabs.common.connection.hibernate.RichQueryCommon.list(RichQueryCommon.java:969)
        at com.termalabs.server.hibernate.RichQuery$CollectionQuery.asSetUnfiltered(RichQuery.java:175)
        at com.termalabs.server.hibernate.RichQuery$CollectionQuery.asSet(RichQuery.java:155)
        at com.termalabs.server.hibernate.RichQuery$CollectionQuery.uniqueResult(RichQuery.java:226)
        at com.termalabs.server.hibernate.jaws.HibernateJobStreamRunData.getLatestCompleteJobStreamRun(HibernateJobStreamRunData.java:528)
        at com.termalabs.server.cache.JobStreamRunVendorImpl.getLatestJobStreamRun(JobStreamRunVendorImpl.java:611)
        at com.termalabs.server.autosys.old.PredictionEngineWorker.buildOrderedListOfJobs(PredictionEngineWorker.java:3217)
        at com.termalabs.server.autosys.old.PredictionEngineWorker.initJobs(PredictionEngineWorker.java:3140)
        at com.termalabs.server.autosys.old.PredictionEngineWorker.initVariables(PredictionEngineWorker.java:3071)
        at com.termalabs.server.autosys.old.PredictionEngineWorker.generatePrediction(PredictionEngineWorker.java:424)
        at com.termalabs.server.autosys.old.PredictionEngineWorker.run(PredictionEngineWorker.java:386)
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
        at java.util.concurrent.FutureTask.run(FutureTask.java:266)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
        at java.lang.Thread.run(Thread.java:748)
Caused by: org.hibernate.exception.JDBCConnectionException: could not load an entity: [com.termalabs.common.hibernate.jaws.JobRun#UUID[xxxxxxx]]
        at org.hibernate.exception.SQLStateConverter.convert(SQLStateConverter.java:97)
        at org.hibernate.exception.JDBCExceptionHelper.convert(JDBCExceptionHelper.java:66)
        at org.hibernate.loader.Loader.loadEntity(Loader.java:1899)
        at org.hibernate.loader.entity.AbstractEntityLoader.load(AbstractEntityLoader.java:71)
        at org.hibernate.loader.entity.AbstractEntityLoader.load(AbstractEntityLoader.java:65)
        at org.hibernate.persister.entity.AbstractEntityPersister.load(AbstractEntityPersister.java:3062)
        at org.hibernate.event.def.DefaultLoadEventListener.loadFromDatasource(DefaultLoadEventListener.java:434)
        at org.hibernate.event.def.DefaultLoadEventListener.doLoad(DefaultLoadEventListener.java:415)
        at org.hibernate.event.def.DefaultLoadEventListener.load(DefaultLoadEventListener.java:165)
        at org.hibernate.event.def.DefaultLoadEventListener.proxyOrLoad(DefaultLoadEventListener.java:207)
        at org.hibernate.event.def.DefaultLoadEventListener.onLoad(DefaultLoadEventListener.java:126)
        at org.hibernate.impl.SessionImpl.fireLoad(SessionImpl.java:906)
        at org.hibernate.impl.SessionImpl.internalLoad(SessionImpl.java:874)
        at org.hibernate.type.EntityType.resolveIdentifier(EntityType.java:590)
        at org.hibernate.type.EntityType.resolve(EntityType.java:412)
        at org.hibernate.engine.TwoPhaseLoad.initializeEntity(TwoPhaseLoad.java:139)
        at org.hibernate.loader.Loader.initializeEntitiesAndCollections(Loader.java:877)
        at org.hibernate.loader.Loader.doQuery(Loader.java:752)
        at org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:259)
        at org.hibernate.loader.Loader.doList(Loader.java:2232)
        at org.hibernate.loader.Loader.listIgnoreQueryCache(Loader.java:2129)
        at org.hibernate.loader.Loader.list(Loader.java:2124)
        at org.hibernate.loader.hql.QueryLoader.list(QueryLoader.java:401)
        at org.hibernate.hql.ast.QueryTranslatorImpl.list(QueryTranslatorImpl.java:363)
        at org.hibernate.engine.query.HQLQueryPlan.performList(HQLQueryPlan.java:196)
        at org.hibernate.impl.SessionImpl.list(SessionImpl.java:1149)
        at org.hibernate.impl.QueryImpl.list(QueryImpl.java:102)
        at com.termalabs.common.connection.hibernate.RichQueryCommon$1.execute(RichQueryCommon.java:972)
        at com.termalabs.common.connection.hibernate.RichQueryCommon$1.execute(RichQueryCommon.java:969)
        ... 16 in common
Caused by: java.sql.SQLRecoverableException: Closed Connection
        at oracle.jdbc.driver.PhysicalConnection.needLine(PhysicalConnection.java:3247)
        at oracle.jdbc.driver.OracleStatement.closeOrCache(OracleStatement.java:1392)
        at oracle.jdbc.driver.OracleStatement.close(OracleStatement.java:1375)
        at oracle.jdbc.driver.OracleStatementWrapper.close(OracleStatementWrapper.java:119)
        at oracle.jdbc.driver.OraclePreparedStatementWrapper.close(OraclePreparedStatementWrapper.java:96)
        at com.mchange.v2.c3p0.impl.NewProxyPreparedStatement.close(NewProxyPreparedStatement.java:1811)
        at org.hibernate.jdbc.AbstractBatcher.closePreparedStatement(AbstractBatcher.java:563)
        at org.hibernate.jdbc.AbstractBatcher.closeStatement(AbstractBatcher.java:291)
        at org.hibernate.jdbc.AbstractBatcher.closeQueryStatement(AbstractBatcher.java:307)
        at org.hibernate.jdbc.AbstractBatcher.closeQueryStatement(AbstractBatcher.java:234)
        at org.hibernate.loader.Loader.getResultSet(Loader.java:1826)
        at org.hibernate.loader.Loader.doQuery(Loader.java:697)
        at org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:259)
        ... 43 in common

Environment

Release : 6.0

Component : AUTOMIC AUTOMATION INTELLIGENCE ENGINE

Resolution

To work around the issue disable monitoring for the jobstream in the error message below:

[AutosysPredictionEngine] Prediction for <Jobstream name> at 2020/05/22 07:52:28.000 CDT timed out.  Timeout period is 30

 

You can do this by going to Admin Tab and selecting Jobstreams.

Find the job stream that is in the error message and select the edit icon.

Uncheck the box that says "Make this jobstream available for monitoring and alerts" like below:

Restart services and monitor the jaws.log to see if the error/warn messages go away.