So, I’ve been looking at this in detail over the past couple of days. I have narrowed it down to one test of our REST API that causes the problem. Once that test fails to delete its test space, a bunch of other tests fail.
What, you might wonder, does this problematic test do?
It calls a REST Endpoint. One of ours. Is that endpoint holding any state? No, it doesn’t appear to be. What about the service the endpoint calls? Nope, and plenty of comparable integration tests talk to that service without equivalent failures.
I’m more than a bit puzzled. I can confirm that the endpoint works normally, so I’m not exactly worried about the release. I can ignore the test in CI for confluence 7.14 until I can find a more fundamental solution. At the same time, I can’t help but think that the problem may be with Confluence and not with ScriptRunner.
To help me debug this, I setup a couple of simple event listeners on the SpaceWillRemoveEvent and SpaceRemoveEvent:
log.debug "Space will be removed ${event.space.key}"
log.debug "Progress meter: ${event.progressMeter.status} ${event.progressMeter.percentageComplete} ${event.progressMeter.currentCount} ${event.progressMeter.total}"
On the failing test, only the first one fires during test cleanup. Here’s the output in my atlassian-confluence.log file, along with the error that follows:
2021-09-15 16:54:15,575 DEBUG [http-nio-8080-exec-3] [onresolve.scriptrunner.runner.ScriptBindingsManager] Space will be removed SPCFXTR1751493783
2021-09-15 16:54:15,576 DEBUG [http-nio-8080-exec-3] [onresolve.scriptrunner.runner.ScriptBindingsManager] Progress meter: Deleting custom content from space 2 0 0
2021-09-15 16:54:15,604 WARN [http-nio-8080-exec-3] [confluence.impl.hibernate.ConfluenceHibernateTransactionManager] Commit failed. Rolling back. Error: Hibernate operation: could not execute statement; sql=n/a; Referential integrity constraint violation: "FKLMWEU06NFT59G7MW1I1MYORYS: PUBLIC.CONTENT FOREIGN KEY(SPACEID) REFERENCES PUBLIC.SPACES(SPACEID) (917530)"; SQL statement:
delete from SPACES where SPACEID=? [23503-200]; nested exception is org.h2.jdbc.JdbcSQLIntegrityConstraintViolationException: Referential integrity constraint violation: "FKLMWEU06NFT59G7MW1I1MYORYS: PUBLIC.CONTENT FOREIGN KEY(SPACEID) REFERENCES PUBLIC.SPACES(SPACEID) (917530)"; SQL statement:
delete from SPACES where SPACEID=? [23503-200]
at org.h2.message.DbException.getJdbcSQLException(DbException.java:459)
at org.h2.message.DbException.getJdbcSQLException(DbException.java:429)
at org.h2.message.DbException.get(DbException.java:205)
at org.h2.message.DbException.get(DbException.java:181)
at org.h2.constraint.ConstraintReferential.checkRow(ConstraintReferential.java:373)
at org.h2.constraint.ConstraintReferential.checkRowRefTable(ConstraintReferential.java:390)
at org.h2.constraint.ConstraintReferential.checkRow(ConstraintReferential.java:265)
at org.h2.table.Table.fireConstraints(Table.java:1057)
at org.h2.table.Table.fireAfterRow(Table.java:1075)
at org.h2.command.dml.Delete.update(Delete.java:153)
at org.h2.command.CommandContainer.update(CommandContainer.java:198)
at org.h2.command.Command.executeUpdate(Command.java:251)
at org.h2.server.TcpServerThread.process(TcpServerThread.java:406)
at org.h2.server.TcpServerThread.run(TcpServerThread.java:183)
at java.lang.Thread.run(Thread.java:748)
-- url: /confluence/plugins/servlet/scriptrunner/remote-control | traceId: 47e933eccafe744e | userName: admin
2021-09-15 16:54:15,604 WARN [http-nio-8080-exec-3] [confluence.impl.hibernate.ConfluenceHibernateTransactionManager] Performing rollback. Transactions:
[com.atlassian.confluence.spaces.DefaultSpaceManager.removeSpace]: PROPAGATION_REQUIRES_NEW,ISOLATION_DEFAULT (Session #1458418868)
[null]: PROPAGATION_REQUIRES_NEW,ISOLATION_DEFAULT (Session #220329135)
[pluginRequires_New_Read_WriteTx]: PROPAGATION_REQUIRES_NEW,ISOLATION_DEFAULT (Session #1204409187)
[null]: PROPAGATION_REQUIRES_NEW,ISOLATION_DEFAULT (Session #1871825828)
[null]: PROPAGATION_REQUIRES_NEW,ISOLATION_DEFAULT (Session #409590822)
[null]: PROPAGATION_REQUIRES_NEW,ISOLATION_DEFAULT (Session #287629328)
->[null]: PROPAGATION_REQUIRES_NEW,ISOLATION_DEFAULT (Session #2018796876)
-- url: /confluence/plugins/servlet/scriptrunner/remote-control | traceId: 47e933eccafe744e | userName: admin
2021-09-15 16:54:15,605 WARN [http-nio-8080-exec-3] [confluence.impl.hibernate.ConfluenceHibernateTransactionManager] Performing rollback. Transactions:
->[com.atlassian.confluence.spaces.DefaultSpaceManager.removeSpace]: PROPAGATION_REQUIRES_NEW,ISOLATION_DEFAULT (Session #1458418868)
[null]: PROPAGATION_REQUIRES_NEW,ISOLATION_DEFAULT (Session #220329135)
[pluginRequires_New_Read_WriteTx]: PROPAGATION_REQUIRES_NEW,ISOLATION_DEFAULT (Session #1204409187)
[null]: PROPAGATION_REQUIRES_NEW,ISOLATION_DEFAULT (Session #1871825828)
[null]: PROPAGATION_REQUIRES_NEW,ISOLATION_DEFAULT (Session #409590822)
[null]: PROPAGATION_REQUIRES_NEW,ISOLATION_DEFAULT (Session #287629328)
[null]: PROPAGATION_REQUIRES_NEW,ISOLATION_DEFAULT (Session #2018796876)
2021-09-15 16:54:15,583 ERROR [http-nio-8080-exec-3] [atlassian.confluence.pages.DefaultPageManager] Exception occurred while deleting page with ID 884820: No row with the given identifier exists: [com.atlassian.confluence.pages.Page#884821]
-- url: /confluence/plugins/servlet/scriptrunner/remote-control | traceId: 47e933eccafe744e | userName: admin
2021-09-15 16:54:15,600 ERROR [http-nio-8080-exec-3] [engine.jdbc.spi.SqlExceptionHelper] Referential integrity constraint violation: "FKLMWEU06NFT59G7MW1I1MYORYS: PUBLIC.CONTENT FOREIGN KEY(SPACEID) REFERENCES PUBLIC.SPACES(SPACEID) (917530)"; SQL statement:
delete from SPACES where SPACEID=? [23503-200]
-- url: /confluence/plugins/servlet/scriptrunner/remote-control | traceId: 47e933eccafe744e | userName: admin
2021-09-15 16:54:15,601 ERROR [http-nio-8080-exec-3] [org.hibernate.internal.ExceptionMapperStandardImpl] HHH000346: Error during managed flush [org.hibernate.exception.ConstraintViolationException: could not execute statement]
-- url: /confluence/plugins/servlet/scriptrunner/remote-control | traceId: 47e933eccafe744e | userName: admin
I don’t have the source for the 7.14.0-beta1 version, but I can guess from the 7.13 source and the class files from the jars in the webapp that this log means the com.atlassian.confluence.content.CustomContentSpaceRemovalListener
has fired okay. I guess the question is what’s happening at lines 269 and 214 in the DefaultSpaceManager nowadays, and why might it fail as described above. I don’t doubt that separating the deletion of a space into separate transactions is the underlying cause.
BTW, @ttranminh , I tried your suggestion of flushing the index queue before removing the space. No dice. Same error.
I’m open to any ideas, of course. I’d also be happy to hop on a call and talk code in detail. You know where to find me.
EDIT: As a further aside, here’s the database cleanup I’ve had to do after the test fails leaving behind some detritus.
delete from public.NOTIFICATIONS where CONTENTID in (select CONTENTID from public.content where SPACEID = :deadSpaceId)
delete from public.CONTENTPROPERTIES where CONTENTID in (select CONTENTID from public.content where SPACEID = :deadSpaceId)
delete from public.BODYCONTENT where CONTENTID in (select CONTENTID from public.content where SPACEID = :deadSpaceId)
delete from public.content where SPACEID = :deadSpaceId
This is true even if I start a new thread after the first attempt to delete the dead space fails. So simply retrying the space deletion after a short period isn’t a solution. The space deletion partly happens, then fails midway through, leaving behind some junk that causes all future space deletion operations to fail.