Task #10181 (accepted)
Opened 11 years ago
Last modified 8 years ago
Bug: configuration_pkey failure in pixeldata
Reported by: | jamoore | Owned by: | jamoore |
---|---|---|---|
Priority: | blocker | Milestone: | Asynchronous |
Component: | Services | Version: | 4.4.8 |
Keywords: | n.a. | Cc: | java@…, jballanco-x |
Resources: | n.a. | Referenced By: | n.a. |
References: | n.a. | Remaining Time: | n.a. |
Sprint: | n.a. |
Description
2013-01-16 05:19:21,808 ERROR [ ome.services.pixeldata.PixelDataThread] (2-thread-2) ExceptionException! ome.conditions.ValidationException: PreparedStatementCallback; SQL [insert into configuration (name, value) values (?,?)]; ERROR: duplicate key value violates unique constraint "configuration_pkey"; nested exception is org.postgresql.util.PSQLException: ERROR: duplicate key value violates unique constraint "configuration_pkey" at org.springframework.jdbc.support.SQLErrorCodeSQLExceptionTranslator.doTranslate(SQLErrorCodeSQLExceptionTranslator.java:241) at org.springframework.jdbc.support.AbstractFallbackSQLExceptionTranslator.translate(AbstractFallbackSQLExceptionTranslator.java:72) at org.springframework.jdbc.core.JdbcTemplate.execute(JdbcTemplate.java:602) at org.springframework.jdbc.core.JdbcTemplate.update(JdbcTemplate.java:811) at org.springframework.jdbc.core.JdbcTemplate.update(JdbcTemplate.java:867) at org.springframework.jdbc.core.JdbcTemplate.update(JdbcTemplate.java:875) at org.springframework.jdbc.core.simple.SimpleJdbcTemplate.update(SimpleJdbcTemplate.java:249) at ome.util.actions.PostgresSqlAction.setCurrentEventLog(PostgresSqlAction.java:229) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) at java.lang.reflect.Method.invoke(Method.java:592) at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:307) at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150) at ome.util.SqlAction$LoggingSqlAction.invoke(SqlAction.java:74) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172) at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:202) at $Proxy4.setCurrentEventLog(Unknown Source) at ome.services.eventlogs.PersistentEventLogLoader.setCurrentId(PersistentEventLogLoader.java:95) at ome.services.eventlogs.PersistentEventLogLoader.getCurrentId(PersistentEventLogLoader.java:82) at ome.services.pixeldata.PersistentEventLogLoader.query(PersistentEventLogLoader.java:61) at ome.services.eventlogs.EventLogLoader.hasNext(EventLogLoader.java:137) at ome.services.pixeldata.PixelDataHandler.loadNext(PixelDataHandler.java:108) at ome.services.pixeldata.PixelDataHandler.doWork(PixelDataHandler.java:81) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
Attachments (2)
Change History (29)
comment:1 Changed 11 years ago by mtbcarroll
- Owner changed from jamoore to mtbcarroll
- Version set to 4.4.8
comment:2 Changed 11 years ago by mtbcarroll
- Status changed from new to accepted
comment:3 Changed 11 years ago by mtbcarroll
comment:4 Changed 11 years ago by mtbcarroll
setCurrentEventLog clearly expects to be isolated from other updates to the configuration table, but at first glance it seems to be called only from PixelDataHandler.loadNext() which looks to be a synchronized method of a singleton bean.
comment:5 Changed 11 years ago by mtbcarroll
I should mention that, as well as the PersistentEventLogLoader used by the pixelDataHandler bean, there also seems to be one used by the fullTextIndexer bean, but they are set with different keys so their queries/updates shouldn't clash.
comment:6 Changed 11 years ago by mtbcarroll
I wondered if perhaps the problem is that _jdbc().update(logLoaderUpdateSql, id, key) returns 0 if the key is in the table but already has the desired ID, but repeated calls of setCurrentId with the same ID, both outside and inside the same transaction, don't seem to cause any such errors.
comment:7 Changed 11 years ago by jamoore
https://github.com/openmicroscopy/openmicroscopy/pull/1512 opened with a minor (unrelated) change.
Mark: I think you are right that somehow the UPDATE is returning a 0 despite the row being present, but I wouldn't think it would be because the value is already set. I'm happy to add a try/catch for the duplicate key and re-try the update. It's not a clean solution, but might be better than nothing.
comment:8 Changed 11 years ago by mtbcarroll
Your minor unrelated change seems to delete the whole method that throws the exception. Is there anything further that I should do on this ticket?
comment:9 Changed 11 years ago by jamoore
Well, it removes the shadowing methods from the subclass (PostgresSqlAction) so that the methods in SqlAction.Impl are used.But they were identical.
The only question is if we try to do something preventative even if we can't (yet) reproduce.
comment:10 Changed 11 years ago by mtbcarroll
Ohh, right. (-: As the etiology remains a mystery, I'd probably want to avoid a loop in case there's some lasting state in which the update count stays zero but inserts also fail, but how about I catch the exception around the insert and in that case do a warn-level log and retry the update?
comment:11 Changed 11 years ago by jamoore
Exactly. I'd definitely avoid a loop.
comment:12 Changed 11 years ago by mtbcarroll
Suggested code added by https://github.com/openmicroscopy/openmicroscopy/pull/1528
Not sure if we want to close or push this ticket.
comment:13 Changed 11 years ago by mtbcarroll
- Sprint set to Blocker 4.4.9 (1)
comment:14 Changed 11 years ago by jamoore
- Milestone changed from OMERO-4.4.9 to OMERO-4.4.x
- Sprint Blocker 4.4.9 (1) deleted
A follow-up ticket would be valid, but since we haven't really done much in the way of reproducibility or fixing this, I guess let's just push it. Thanks, Mark.
comment:15 Changed 11 years ago by mtbcarroll
- Owner changed from mtbcarroll to jamoore
comment:16 Changed 11 years ago by jamoore
Moving out of 4.4.9. This may become a non-issue if the pixel data thread is re-worked, but if not, we will need to re-evaluate. See the performance issues outlined in PR 1528 (currently closed).
comment:17 Changed 10 years ago by mtbcarroll
Bug observed in current 5.0 merge build (approximately RC3) integration testing.
comment:18 Changed 10 years ago by jamoore
- Cc java@… jballanco-x added; jburel removed
CC'ing JB in case any of his indexer investigations have touched on this. Certainly his PR to use a file rather than the DB would fix this.
comment:19 Changed 10 years ago by jballanco-x
Could be related to #11993 . Will have to compare the way transactions are set up between the pixel data service and the indexer. Changes in progress for the PersistentEventLogLoader? (as well as future work on the firehose) will definitely work around this.
comment:20 Changed 10 years ago by jamoore
comment:21 Changed 10 years ago by mtbcarroll
comment:22 Changed 10 years ago by jamoore
- Milestone changed from 5.x to 5.1.0
- Priority changed from critical to blocker
With a number of reports submitted, it would be good to consider this a blocker lest it become a processor-like embarrassment.
comment:23 Changed 9 years ago by jamoore
- Milestone changed from 5.1.0 to 5.1.1
Won't be getting to this for 5.1.0. (I also think this may have been taken care of by previous work from Mark)
comment:24 Changed 9 years ago by jamoore
- Milestone changed from 5.1.1 to 5.1.2
Does anyone know the last time this was seen? Rather than try to figure this out for 5.1.1, I'm going to focus the rest on my time on bumping Hibernate with the hope that that will help anyway.
comment:25 Changed 9 years ago by jamoore
- Milestone changed from 5.1.2 to 5.1.3
comment:26 Changed 9 years ago by jamoore
- Milestone changed from 5.1.3 to 5.x
Haven't seen in some time. De-prioritizing.
comment:27 Changed 8 years ago by jamoore
- Milestone changed from 5.x to Asynchronous
Any clues how to trigger this?