Rollback Exception

Module Development
1

While running driver module, importing and creating tags, the system does a settings backup which blows up our module with the following exception:

[code] simpleorm.utils.SException$Jdbc: Executing SELECT TAG_PROPERTIES.TAG_PROPERTIES_ID, TAG_PROPERTIES.TAG_PATH, TAG_PROPERTIES.TIE_NUMBER, TAG_PROPERTIES.TAG_ID FROM TAG_PROPERTIES

simpleorm.utils.SException$Jdbc: Executing SELECT TAG_PROPERTIES.TAG_PROPERTIES_ID, TAG_PROPERTIES.TAG_PATH, TAG_PROPERTIES.TIE_NUMBER, TAG_PROPERTIES.TAG_ID FROM TAG_PROPERTIES
at simpleorm.sessionjdbc.SQueryExecute.executeQuery(SQueryExecute.java:63)
at simpleorm.sessionjdbc.SSessionJdbc.queryNoFlush(SSessionJdbc.java:489)
at simpleorm.sessionjdbc.SSessionJdbc.query(SSessionJdbc.java:498)
at com.inductiveautomation.ignition.gateway.localdb.PersistenceInterfaceImpl.query(PersistenceInterfaceImpl.java:145)
at com.ruggedcom.elan.tags.PropertiesManager.getAllTagProperties(PropertiesManager.java:39)
at com.ruggedcom.elan.tags.TagFactory.setTagsOffline(TagFactory.java:72)
at com.ruggedcom.elan.ElanDriver.setReconnect(ElanDriver.java:248)
at com.ruggedcom.elan.ElanDriver.getMessages(ElanDriver.java:564)
at com.ruggedcom.elan.protocol.network.ReceivePacket.runImpl(ReceivePacket.java:44)
at com.ruggedcom.elan.protocol.network.CommonThread.run(CommonThread.java:25)
Caused by: java.sql.SQLTransactionRollbackException: transaction rollback: serialization failure
at org.hsqldb.jdbc.Util.sqlException(Unknown Source)
at org.hsqldb.jdbc.Util.sqlException(Unknown Source)
at org.hsqldb.jdbc.JDBCPreparedStatement.fetchResult(Unknown Source)
at org.hsqldb.jdbc.JDBCPreparedStatement.executeQuery(Unknown Source)
at org.apache.commons.dbcp.DelegatingPreparedStatement.executeQuery(DelegatingPreparedStatement.java:93)
at com.inductiveautomation.ignition.gateway.localdb.hsql.DelegatingDataSource$DelegatingConnection$DelegatingPreparedStatement.executeQuery(DelegatingDataSource.java:538)
at simpleorm.sessionjdbc.SQueryExecute.executeQuery(SQueryExecute.java:61)
… 9 more
Caused by: org.hsqldb.HsqlException: transaction rollback: serialization failure
at org.hsqldb.error.Error.error(Unknown Source)
at org.hsqldb.error.Error.error(Unknown Source)
at org.hsqldb.Session.executeCompiledStatement(Unknown Source)
at org.hsqldb.Session.execute(Unknown Source)
… 14 more[/code]

Complete log attached
logs.bin.gz (584 KB)

2

Just noticed that this also happens on a second system where we are only updating the tag values.

3

Any idea why this is happening? Or even better, how to stop it?

4

Should we just try and trap exceptions and retry the operation?

5

Hi,

Sorry for the delay, we’ve all been running around like wild people in the last few weeks. I just spoke to Dmitry. Since there’s a suspicion that this is caused by the database checkpoints, I told him how to turn them off (edit gateway.xml and change ‘localdb.autobackup.count’ to 0, restart the gateway) or change the rate (.delay in that file), to see if that makes a difference, in order to confirm the correlation.

I’m going to look into the error myself a bit more. Considering that the errors reported are “transaction rollback” exceptions, I’m a little concerned that they may be hiding the real exception. Still, I’ll see what I can come up with.

Regards,

6

As far as I can tell, the exception isn’t being masked, so this likely has to do purely with concurrency.

I have an idea that might help us get more information in a more organized way. The ORM system in Ignition has pretty good logging, but if you’re doing a lot of things, it could be a bit verbose. However, I’ve put together some log4j settings that you could add to log4j.properties (in the data dir) which will redirect the messages to their own file.

Could you try adding this to the log4j.properties file, restarting Ignition, and running it until you see some of these errors? After one or two errors, you can stop the gateway and remove these settings. Then zip and post the resulting file, “simpleormdebug.log” (which should show up in the ignition install dir):

log4j.appender.SimpleOrm=org.apache.log4j.RollingFileAppender
log4j.appender.SimpleOrm.layout=org.apache.log4j.PatternLayout
log4j.appender.SimpleOrm.layout.ConversionPattern=%-5p [%-30c{1}] [%d{HH:mm:ss,SSS}]: %m%n
log4j.appender.SimpleOrm.File=simpleormlog.log
log4j.appender.SimpleOrm.MaxFileSize=10MB

log4j.logger.simpleorm.utils.SLogSlf4j=ALL, SimpleOrm
log4j.additivity.simpleorm.utils.SLogSlf4j=false

Regards,

7

Setting localdb.autobackup.delay to 15 (minutes) helped.

8

Hi,

That helps indicate that it must really be a problem with the snapshots, as you thought. However, I don’t think this is something that should really happen, and is possibly and issue with HSQL that should be fixed. For the purposes of trying to track it down, perhaps you could set the backup time to 1, and follow the instructions above to capture a log of the error occurring.

Regards,

9

How to access the running instance of HSQLDBManager?

10

You can’t currently access it, and I’m not sure we would want you to- we’re constantly talking about trying to switch to a different internal database system (such as h2 or sqlite), so we would prefer to keep it as abstract as possible.

Did you get a chance to try the logging that I suggested? It might help us track down what’s at the root of those error, or at least give us more info if we have to contact the hsqldb developers.

Thanks,

11

Sorry for taking so long with the reply.
I made some changes to the queries explicitly using SQueryMode.SFOR_UPDATE and SQueryMode.SREAD_ONLY as required and now it is working.
We cannot reproduce the error. I hope this is the solution.