Integrity check of postgresql database

[jacques2020]

Hi,

I would like to check the integrity of the database, meaning:
1) that all "links" (Projects-Dataset, Dataset-Attachment, Image-originalFile, etc...) points to existing database entries ;
2) that all objects "representing" a file in omero repository (e.g. OriginalFile) have really their corresponding file with its correct size.
and I am wondering if either developers or anyone has developed codes of any kind (in unstable or stable state) to do tasks like that. If so, I would be very grateful if you can share them with me (of course, I can return my edits, if so, if you are interested).

Indeed, we experience a malevolent act from a former employee, who made massive deletions. Because between the incident and the time we noticed it, there was some activities, I opted to merge a backup done before the incident and the current state of the database (commands used below) and also used "rsync --update" to merge the current omero repository with its backup corresponding to the one of the database backup. Now, it appears reasonable to check the integrity.

Thank you so much for your help.

-------------------------------- database merging code--------------------------
su postgres -c "pg_dump omero -a --inserts -f /tmp/omero_inserts_20141025.dump"
su postgres -c "psql -c 'ALTER DATABASE omero RENAME TO omero20141025'"
createdb -h localhost -U postgres -O omero omero
restore an older version of omero database
su postgres -c "pg_restore -Fc -d omero /tmp/omero.2014-10-23_20-51-47-CEST.pg_dump"
su postgres -c "psql omero < /tmp/omero_inserts_20141025.dump"

omero.2014-10-23_20-51-47-CEST.pg_dump was done following instructions in http://www.openmicroscopy.org/site/supp ... .html#id10

[jmoore]

Hi Jacques,

sorry to hear about your situation. I have a number of questions to try to figure out the best answers for you:

1) that all "links" (Projects-Dataset, Dataset-Attachment, Image-originalFile, etc...) points to existing database entries ;

Do you mean if the projectdatalink table points to real projects and datasets? If yes, is this because the foreign keys were dropped from your database? If no, then do you mean if all datasets are in a project, etc? I ask because in general (depending on your backups, etc) there should be no way that a link can exist if it's parent & child objects don't.

2) that all objects "representing" a file in omero repository (e.g. OriginalFile) have really their corresponding file with its correct size.

For this there are a couple of tools. You can start off by using a "dry-run" of the cleanse tool. See "bin/omero admin cleanse -h" for more information.

After that, you'll likely want to use the "bin/omero fs sets --check" tool, which also verifies the checksums.

Code: Select all

and I am wondering if either developers or anyone has developed codes of any kind (in unstable or stable state) to do tasks like that. If so, I would be very grateful if you can share them with me (of course, I can return my edits, if so, if you are interested).


I'd be interested as well!

Code: Select all

...I opted to merge a backup done before the incident and the current state of the database (commands used below) and also used "rsync --update" to merge the current omero repository with its backup corresponding to the one of the database backup.


This is certainly an interesting strategy itself. I don't know if anyone's had to use this before, but if things work out, it would be invaluable to let others know.

Wishing you the best,
~Josh.

[jacques2020]

Hi Josh,

and thank you for your answer. I will try to address your questions:

Do you mean if the projectdatalink table points to real projects and datasets? If yes, is this because the foreign keys were dropped from your database?

I don't think foreign keys were added because users have no access to postgres but through omero. However, I feeled a bit worried about that because of the merging strategy I adopted. Since I have knowledge of no previous attempt of this kind, I would feel more secure to test.

If no, then do you mean if all datasets are in a project, etc? I ask because in general (depending on your backups, etc) there should be no way that a link can exist if it's parent & child objects don't.

In my limited understanding of omero inner life, I imagined that but I am happy that you can confirm it. I also imagined that if my DB dump was taken in the middle of a process, it possible that DB is in an inconsistent state ?

For this there are a couple of tools. You can start off by using a "dry-run" of the cleanse tool. See "bin/omero admin cleanse -h" for more information.

After that, you'll likely want to use the "bin/omero fs sets --check" tool, which also verifies the checksums.

Thank you for the suggestions. I will try that and post the outcomes later.

Best

Jacques

[jmoore]

Hi Jacques,

I don't think foreign keys were added because users have no access to postgres but through omero. However, I feeled a bit worried about that because of the merging strategy I adopted. Since I have knowledge of no previous attempt of this kind, I would feel more secure to test.

Could you send us the output of "\d image", for example? That would show us the foreign key constraints. If you don't think there is any sensitive information in the inserts file, you might also send that. If no one had access to PostgreSQL and your /tmp/omero_inserts_20141025.dump contains only INSERTs, then I don't think there's anything at the PostgreSQL level that we'll need to check. OMERO may have issues with some of the data, but that we can handle when it arises.

In my limited understanding of omero inner life, I imagined that but I am happy that you can confirm it. I also imagined that if my DB dump was taken in the middle of a process, it possible that DB is in an inconsistent state ?

Only complete transactions should be contained in the dump, but even that won't completely guarantee a consistent state, since imports perform many operations over several transactions. If there was an ongoing import during either your backup or the checkpoint you're using for your INSERTs, there may be individual filesets that are incomplete.

Let us know how things go.
~Josh.

[jacques2020]

Hi Josh,

I will first tell you about the files:

1) I run the dry-run cleanse and it went smoothly I feel. (cedre-agent is the user that run the omero server).

Code: Select all

sudo -u cedre-agent /usr/local/OMERO/OMERO.server-Current/bin/omero admin cleanse --dry-run /omero/OMERO/

it reads

Code: Select all

Reconciling OMERO data directory...
/omero/OMERO/Files
   \_ /omero/OMERO/Files/811 (keep)

.../...
\_ /omero/OMERO/Thumbnails/Dir-217/217483 (keep)
\_ /omero/OMERO/Thumbnails/Dir-217/217484 (keep)
Cleansing context: 0 files (0 bytes)[/code]

and removing lines with "(keep)" it remain only lines with "(ignored/keep)"

Code: Select all

cat /home/cedre-agent/cleanse_dry-run_20141029.log | grep -v -e "(keep)"
Reconciling OMERO data directory...
/omero/OMERO/Files
   \_ /omero/OMERO/Files/Dir-408/.fuse_hidden0018ed9200000007 (ignored/keep)
   \_ /omero/OMERO/Files/Dir-408/.fuse_hidden001aaa9a00000009 (ignored/keep)
.../...


2) I also did the fs --check and got an error and cannot figure out what is the issue. Is it linked to that fact that my omero was upgraded from a version 4 and most of the data where not imported in version 5 ? or ?

here is the error

Code: Select all

sudo -u cedre-agent /usr/local/OMERO/OMERO.server-Current/bin/omero fs sets --check
Previous session expired for root on localhost:4064
Server: [localhost]
Username: [root]
Password:
Created session a8d5b95f-4371-4b97-9dad-43afb52ce72a (root@localhost:4064). Idle timeout: 60.0 min. Current group: system
Traceback (most recent call last):
  File "/usr/local/OMERO/OMERO.server-Current/bin/omero", line 125, in <module>
    rv = omero.cli.argv()
  File "/usr/local/OMERO/OMERO.server-Current/lib/python/omero/cli.py", line 1276, in argv
    cli.invoke(args[1:])
  File "/usr/local/OMERO/OMERO.server-Current/lib/python/omero/cli.py", line 823, in invoke
    stop = self.onecmd(line, previous_args)
  File "/usr/local/OMERO/OMERO.server-Current/lib/python/omero/cli.py", line 892, in onecmd
    self.execute(line, previous_args)
  File "/usr/local/OMERO/OMERO.server-Current/lib/python/omero/cli.py", line 974, in execute
    args.func(args)
  File "/usr/local/OMERO/OMERO.server-Current/lib/python/omero/plugins/fs.py", line 642, in sets
    cb = client.submit(raw)
  File "/usr/local/OMERO/OMERO.server-Current/lib/python/omero/clients.py", line 827, in submit
    closehandle=True)
  File "/usr/local/OMERO/OMERO.server-Current/lib/python/omero/clients.py", line 844, in waitOnCmd
    callback.loop(loops, ms)  # Throw LockTimeout
  File "/usr/local/OMERO/OMERO.server-Current/lib/python/omero/callbacks.py", line 321, in loop
    5000L, int(waited))
omero.LockTimeout: exception ::omero::LockTimeout
{
    serverStackTrace = None
    serverExceptionClass = None
    message = Command unfinished after 5.0 seconds
    backOff = 5000
    seconds = 5
}

I still have two questions:
- running cleanse, does it test also for file referred in postgresql DB and absent from file system or only the one in the file repository no longer referred in the DB ?

- fs sets --check (if I manage to make it run) is only for data imported since I upgraded to omero 5. Is there a way to check for the one imported before ?


3) Now, about the database, I am happy that you tell me that there is likely nothing to worry about. I looked at "\d image" as you suggested (below).

Code: Select all

su postgres -c "psql omero -c '\d image'"
                     Table "public.image"
       Column       |            Type             | Modifiers
--------------------+-----------------------------+-----------
id                 | bigint                      | not null
acquisitiondate    | timestamp without time zone | not null
archived           | boolean                     |
description        | text                        |
permissions        | bigint                      | not null
name               | character varying(255)      | not null
partial            | boolean                     |
version            | integer                     |
creation_id        | bigint                      | not null
external_id        | bigint                      |
group_id           | bigint                      | not null
owner_id           | bigint                      | not null
update_id          | bigint                      | not null
experiment         | bigint                      |
format             | bigint                      |
imagingenvironment | bigint                      |
instrument         | bigint                      |
objectivesettings  | bigint                      |
stagelabel         | bigint                      |
fileset            | bigint                      |
Indexes:
    "image_pkey" PRIMARY KEY, btree (id)
    "image_external_id_key" UNIQUE CONSTRAINT, btree (external_id)
    "i_image_experiment" btree (experiment)
    "i_image_fileset" btree (fileset)
    "i_image_format" btree (format)
    "i_image_group" btree (group_id)
    "i_image_imagingenvironment" btree (imagingenvironment)
    "i_image_instrument" btree (instrument)
    "i_image_objectivesettings" btree (objectivesettings)
    "i_image_owner" btree (owner_id)
    "i_image_stagelabel" btree (stagelabel)
Foreign-key constraints:
    "fkimage_creation_id_event" FOREIGN KEY (creation_id) REFERENCES event(id)
    "fkimage_experiment_experiment" FOREIGN KEY (experiment) REFERENCES experiment(id)
    "fkimage_external_id_externalinfo" FOREIGN KEY (external_id) REFERENCES externalinfo(id)
    "fkimage_fileset_fileset" FOREIGN KEY (fileset) REFERENCES fileset(id)
    "fkimage_format_format" FOREIGN KEY (format) REFERENCES format(id)
    "fkimage_group_id_experimentergroup" FOREIGN KEY (group_id) REFERENCES experimentergroup(id)
    "fkimage_imagingenvironment_imagingenvironment" FOREIGN KEY (imagingenvironment) REFERENCES imagingenvironment(id)
    "fkimage_instrument_instrument" FOREIGN KEY (instrument) REFERENCES instrument(id)
    "fkimage_objectivesettings_objectivesettings" FOREIGN KEY (objectivesettings) REFERENCES objectivesettings(id)
    "fkimage_owner_id_experimenter" FOREIGN KEY (owner_id) REFERENCES experimenter(id)
    "fkimage_stagelabel_stagelabel" FOREIGN KEY (stagelabel) REFERENCES stagelabel(id)
    "fkimage_update_id_event" FOREIGN KEY (update_id) REFERENCES event(id)
Referenced by:
    TABLE "roi" CONSTRAINT "fkroi_image_image" FOREIGN KEY (image) REFERENCES image(id)
    TABLE "wellsample" CONSTRAINT "fkwellsample_image_image" FOREIGN KEY (image) REFERENCES image(id)



If I understand correctly, it let the possiblity of orphan images, which is handled by omero.insight e.g. but no image belonging to unknown experimenter or without any content. My question now is, how to see orphan images of all users in a group ? logging as the PI of the group ? as root ? or it needs sql commands and it cannot be done with insight?

Fileset contains the "link" to data in the disk, does it ? and the foreign-key constraints ensures that an image cannot be empty. Is that correct ?


4) I tried the same approach for link,

Code: Select all

su postgres -c "psql omero -c '\d datasetimagelink'"
  Table "public.datasetimagelink"
   Column    |  Type   | Modifiers
-------------+---------+-----------
id          | bigint  | not null
permissions | bigint  | not null
version     | integer |
child       | bigint  | not null
creation_id | bigint  | not null
external_id | bigint  |
group_id    | bigint  | not null
owner_id    | bigint  | not null
update_id   | bigint  | not null
parent      | bigint  | not null
Indexes:
    "datasetimagelink_pkey" PRIMARY KEY, btree (id)
    "datasetimagelink_external_id_key" UNIQUE CONSTRAINT, btree (external_id)
    "datasetimagelink_parent_key" UNIQUE CONSTRAINT, btree (parent, child, owner_id)
    "i_datasetimagelink_child" btree (child)
    "i_datasetimagelink_group" btree (group_id)
    "i_datasetimagelink_owner" btree (owner_id)
    "i_datasetimagelink_parent" btree (parent)
Foreign-key constraints:
    "fkdatasetimagelink_creation_id_event" FOREIGN KEY (creation_id) REFERENCES event(id)
    "fkdatasetimagelink_external_id_externalinfo" FOREIGN KEY (external_id) REFERENCES externalinfo(id)
    "fkdatasetimagelink_group_id_experimentergroup" FOREIGN KEY (group_id) REFERENCES experimentergroup(id)
    "fkdatasetimagelink_owner_id_experimenter" FOREIGN KEY (owner_id) REFERENCES experimenter(id)
    "fkdatasetimagelink_update_id_event" FOREIGN KEY (update_id) REFERENCES event(id)


and if I understand correctly, some dataset-image links can exist pointing to non existing image or dataset, can't they ? But these are likely harmless garbage in the database (?)

5) Looking at annotation, the only risk appears to be orphan annotations. Is there any client to visualize these orphan annotation or I need sql ?

6) about inserts, I see no problem to share. It is a 6.8 GB file....
when I run it, I got many error like

Code: Select all

ERROR:  duplicate key value violates unique constraint "event_pkey"
DETAIL:  Key (id)=(2178396) already exists.

but no error of other kind

Code: Select all

grep -v -e "duplicate key value violates unique constraint"  /tmp/adding_inserts_a_second_time.err | grep -v -e "already exists."


returns no line. So, I guess it means that there where no insert that was not included because of foreign_key (if inserts come in the wrong order to satify the foreign_keys contraints, I don't know if that can happen)

Thank you so much for your help trough all that.

Jacques

[jmoore]

2) I also did the fs --check and got an error and cannot figure out what is the issue. Is it linked to that fact that my omero was upgraded from a version 4 and most of the data where not imported in version 5 ? or ?

here is the error

Code: Select all

sudo -u cedre-agent /usr/local/OMERO/OMERO.server-Current/bin/omero fs sets --check
Traceback (most recent call last):
...
omero.LockTimeout: exception ::omero::LockTimeout
{
    serverStackTrace = None
    serverExceptionClass = None
    message = Command unfinished after 5.0 seconds
    backOff = 5000
    seconds = 5
}


Sorry. This is caused by the file checks taking too long. This property should have been made configurable.

I still have two questions:
- running cleanse, does it test also for file referred in postgresql DB and absent from file system or only the one in the file repository no longer referred in the DB ?

The latter. But if the user had no access to the OMERO directory, it shouldn't be possible for a file to be removed from the filesystem without first the database transactions being committed.

- fs sets --check (if I manage to make it run) is only for data imported since I upgraded to omero 5. Is there a way to check for the one imported before ?

Not at the moment, no.

3) ...

If I understand correctly, it let the possibility of orphan images, which is handled by omero.insight e.g. but no image belonging to unknown experimenter or without any content. My question now is, how to see orphan images of all users in a group ? logging as the PI of the group ? as root ? or it needs sql commands and it cannot be done with insight?

You want a query that shows you all the images that are not contained in datasets for a whole group? If so, you can try:

Code: Select all

/bin/omero hql "select i.details.owner.omeName, i from Image i left outer join fetch i.datasetLinks l where l is null"


Fileset contains the "link" to data in the disk, does it ? and the foreign-key constraints ensures that an image cannot be empty. Is that correct ?

If an Image had no fileset, or the files in the fileset were missing, or there were no pixels file under /OMERO/Pixels for that image ID, then it'd be "empty" (i.e. no data). There are operations which would modify these files. An audit of Blitz-0.log might be the best way to determine if that occurred.

4) I tried the same approach for link, ...
and if I understand correctly, some dataset-image links can exist pointing to non existing image or dataset, can't they ? But these are likely harmless garbage in the database (?)

Hmmm....there do seem to be 2 foreign-key constraints missing:

Code: Select all

    "fkdatasetimagelink_child_image" FOREIGN KEY (child) REFERENCES image(id)
    "fkdatasetimagelink_parent_dataset" FOREIGN KEY (parent) REFERENCES dataset(id)


Any idea what happened to these? I would certainly try re-instating them to see if there are any errors.

5) Looking at annotation, the only risk appears to be orphan annotations. Is there any client to visualize these orphan annotation or I need sql ?

These is certainly trickier, but each annotation can be on a number of different objects.

6) about inserts, I see no problem to share. It is a 6.8 GB file....
when I run it, I got many error like

Code: Select all

ERROR:  duplicate key value violates unique constraint "event_pkey"
DETAIL:  Key (id)=(2178396) already exists.


but no error of other kind

Code: Select all

grep -v -e "duplicate key value violates unique constraint"  /tmp/adding_inserts_a_second_time.err | grep -v -e "already exists."


returns no line. So, I guess it means that there where no insert that was not included because of foreign_key (if inserts come in the wrong order to satify the foreign_keys contraints, I don't know if that can happen)

Interesting. And is there anything in the stdout?

Thank you so much for your help trough all that.

Sure.
~Josh

[jacques2020]

Hi,

I will sure try the piece of hql code. However, I face an issue right now (see below item 2).

1)

Hmmm....there do seem to be 2 foreign-key constraints missing:

Code: Select all
"fkdatasetimagelink_child_image" FOREIGN KEY (child) REFERENCES image(id)
"fkdatasetimagelink_parent_dataset" FOREIGN KEY (parent) REFERENCES dataset(id)



Any idea what happened to these? I would certainly try re-instating them to see if there are any errors.

I see no explanation but the fact that the database was created in march 2011 and despite the fact that I pay attention to the upgrade procedure posted on the openmicroscopy website, something could have been missed. This is the only plausible explanation. I will try the "inserts" strategy (with explicit columns) on a freshly created DB. This should fix all these problems I imagine.

2) Maybe because of my manipulations or because system disk of the server got full (but not the /usr containing the OMERO application, nor /tmp, nor the place containing the omero data or postgresql database, I got the error below). Since then, there is no way to restart omero.... I am trying to revert to the last backup. If you have any suggestion, I am very interested !

3)

but no error of other kind

Code: Select all
grep -v -e "duplicate key value violates unique constraint" /tmp/adding_inserts_a_second_time.err | grep -v -e "already exists."



returns no line. So, I guess it means that there where no insert that was not included because of foreign_key (if inserts come in the wrong order to satify the foreign_keys contraints, I don't know if that can happen)


Interesting. And is there anything in the stdout?

I attached the full file but it list several entries like

Code: Select all

setval
--------
    115
(1 row)


Many thanks
Best
Jacques

--------------------------- Blitz-0.log----------------------------- (At 10:02, the server rebooted, thus tried to stop omero) - see attached file for more context

2014-11-01 10:02:26,962 INFO [ome.services.sessions.state.SessionCache] (2-thread-1) Synchronizing session cache. Count = 5
2014-11-01 10:02:26,962 INFO [ ome.services.util.ServiceHandler] (2-thread-1) Executor.doWork -- ome.services.sessions.SessionManagerImpl.reload(6ae0f58a-c8f3-41f2-b3c8-10b1248575c6)
2014-11-01 10:02:26,962 INFO [ ome.services.util.ServiceHandler] (2-thread-1) Args: [null, InternalSF@55497367]
2014-11-01 10:02:26,970 INFO [ ome.security.basic.EventHandler] (2-thread-1) Auth: user=0,group=0,event=null(Sessions),sess=6ae0f58a-c8f3-41f2-b3c8-10b1248575c6
2014-11-01 10:02:26,978 INFO [ org.perf4j.TimingLogger] (2-thread-1) start[1414832546962] time[15] tag[omero.call.success.ome.services.sessions.SessionManagerImpl$6.doWork]
2014-11-01 10:02:26,978 INFO [ ome.services.util.ServiceHandler] (2-thread-1) Rslt: (ome.model.meta.Experimenter:Id_0, ome.model.meta.ExperimenterGroup:Id_0, (0, 1, 3, ... 4 more), ... 4 more)
2014-11-01 10:02:26,978 INFO [ ome.services.util.ServiceHandler] (2-thread-1) Executor.doWork -- ome.services.sessions.SessionManagerImpl.reload(2b8ac874-6a1c-4d67-89a5-0d09742023db)
2014-11-01 10:02:26,978 INFO [ ome.services.util.ServiceHandler] (2-thread-1) Args: [null, InternalSF@55497367]
2014-11-01 10:02:26,979 INFO [ ome.security.basic.EventHandler] (2-thread-1) Auth: user=0,group=0,event=null(Sessions),sess=6ae0f58a-c8f3-41f2-b3c8-10b1248575c6
2014-11-01 10:02:26,984 INFO [ org.perf4j.TimingLogger] (2-thread-1) start[1414832546978] time[5] tag[omero.call.success.ome.services.sessions.SessionManagerImpl$6.doWork]
2014-11-01 10:02:26,984 INFO [ ome.services.util.ServiceHandler] (2-thread-1) Rslt: (ome.model.meta.Experimenter:Id_153, ome.model.meta.ExperimenterGroup:Id_3, (3, 1), ... 4 more)
2014-11-01 10:02:26,984 INFO [ ome.services.util.ServiceHandler] (2-thread-1) Executor.doWork -- ome.services.sessions.SessionManagerImpl.reload(a04105df-191d-4453-a92f-f7102459794b)
2014-11-01 10:02:26,984 INFO [ ome.services.util.ServiceHandler] (2-thread-1) Args: [null, InternalSF@55497367]
2014-11-01 10:02:26,985 INFO [ ome.security.basic.EventHandler] (2-thread-1) Auth: user=0,group=0,event=null(Sessions),sess=6ae0f58a-c8f3-41f2-b3c8-10b1248575c6
2014-11-01 10:02:26,990 INFO [ org.perf4j.TimingLogger] (2-thread-1) start[1414832546984] time[5] tag[omero.call.success.ome.services.sessions.SessionManagerImpl$6.doWork]
2014-11-01 10:02:26,990 INFO [ ome.services.util.ServiceHandler] (2-thread-1) Rslt: (ome.model.meta.Experimenter:Id_0, ome.model.meta.ExperimenterGroup:Id_0, (0, 1, 3, ... 4 more), ... 4 more)
2014-11-01 10:02:26,990 INFO [ ome.services.util.ServiceHandler] (2-thread-1) Executor.doWork -- ome.services.sessions.SessionManagerImpl.reload(3f5c033c-50ed-409e-b936-785e6b1d1237)
2014-11-01 10:02:26,990 INFO [ ome.services.util.ServiceHandler] (2-thread-1) Args: [null, InternalSF@55497367]
2014-11-01 10:02:26,991 INFO [ ome.security.basic.EventHandler] (2-thread-1) Auth: user=0,group=0,event=null(Sessions),sess=6ae0f58a-c8f3-41f2-b3c8-10b1248575c6
2014-11-01 10:02:26,996 INFO [ org.perf4j.TimingLogger] (2-thread-1) start[1414832546990] time[5] tag[omero.call.success.ome.services.sessions.SessionManagerImpl$6.doWork]
2014-11-01 10:02:26,996 INFO [ ome.services.util.ServiceHandler] (2-thread-1) Rslt: (ome.model.meta.Experimenter:Id_0, ome.model.meta.ExperimenterGroup:Id_0, (0, 1, 3, ... 4 more), ... 4 more)
2014-11-01 10:02:26,996 INFO [ ome.services.util.ServiceHandler] (2-thread-1) Executor.doWork -- ome.services.sessions.SessionManagerImpl.reload(8c4720fc-0765-40a2-91b3-736729b52e0d)
2014-11-01 10:02:26,996 INFO [ ome.services.util.ServiceHandler] (2-thread-1) Args: [null, InternalSF@55497367]
2014-11-01 10:02:26,997 INFO [ ome.security.basic.EventHandler] (2-thread-1) Auth: user=0,group=0,event=null(Sessions),sess=6ae0f58a-c8f3-41f2-b3c8-10b1248575c6
2014-11-01 10:02:27,002 INFO [ org.perf4j.TimingLogger] (2-thread-1) start[1414832546996] time[5] tag[omero.call.success.ome.services.sessions.SessionManagerImpl$6.doWork]
2014-11-01 10:02:27,002 INFO [ ome.services.util.ServiceHandler] (2-thread-1) Rslt: (ome.model.meta.Experimenter:Id_754, ome.model.meta.ExperimenterGroup:Id_3, (3, 1), ... 4 more)
2014-11-01 10:02:27,002 INFO [ org.perf4j.TimingLogger] (2-thread-1) start[1414832546962] time[39] tag[omero.sessions.synchronization]
2014-11-01 10:02:27,002 INFO [ome.services.sessions.state.SessionCache] (2-thread-1) Synchronization took 39 ms.
2014-11-01 10:03:00,015 INFO [ ome.services.blitz.fire.SessionManagerI] (2-thread-5) Performing requestHeartbeats
2014-11-01 10:03:48,034 INFO [ ome.services.blitz.Entry] ( main) Calling close on context OMERO.blitz
2014-11-01 10:03:48,035 INFO [ o.s.blitz.repo.AbstractRepositoryI] ( main) Releasing /usr2/local/OMERO/OMERO.server-5.0.5-ice34-b47/./lib/scripts
2014-11-01 10:03:48,920 INFO [ o.s.blitz.repo.AbstractRepositoryI] ( main) Releasing /OMERO//ManagedRepository
2014-11-01 10:03:48,996 INFO [ o.s.blitz.repo.AbstractRepositoryI] ( main) Releasing /OMERO/
2014-11-01 10:03:49,046 INFO [ ome.services.blitz.fire.Registry] ( main) Removed ClusterNode/6ae0f58a-c8f3-41f2-b3c8-10b1248575c6 from registry
2014-11-01 10:03:49,047 INFO [ ome.services.util.ServiceHandler] ( main) Executor.doWork -- ome.services.blitz.fire.Ring.executeUpdate - set closed = now()
2014-11-01 10:03:49,047 INFO [ ome.services.util.ServiceHandler] ( main) Args: [null, InternalSF@55497367]
2014-11-01 10:03:49,057 ERROR [ o.h.e.def.AbstractFlushingEventListener] ( main) Could not synchronize database state with session
org.hibernate.exception.ConstraintViolationException: could not insert: [ome.model.meta.Event]
at org.hibernate.exception.SQLStateConverter.convert(SQLStateConverter.java:96) ~[hibernate-core.jar:na]
at org.hibernate.exception.JDBCExceptionHelper.convert(JDBCExceptionHelper.java:66) ~[hibernate-core.jar:na]
at org.hibernate.persister.entity.AbstractEntityPersister.insert(AbstractEntityPersister.java:2438) ~[hibernate-core.jar:na]
at org.hibernate.persister.entity.AbstractEntityPersister.insert(AbstractEntityPersister.java:2858) ~[hibernate-core.jar:na]
at org.hibernate.action.EntityInsertAction.execute(EntityInsertAction.java:79) ~[hibernate-core.jar:na]
at org.hibernate.engine.ActionQueue.execute(ActionQueue.java:267) ~[hibernate-core.jar:na]
at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:259) ~[hibernate-core.jar:na]
at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:178) ~[hibernate-core.jar:na]
at org.hibernate.event.def.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:321) ~[hibernate-core.jar:na]
at org.hibernate.event.def.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:51) [hibernate-core.jar:na]
at org.hibernate.impl.SessionImpl.flush(SessionImpl.java:1208) [hibernate-core.jar:na]
at ome.logic.UpdateImpl.afterUpdate(UpdateImpl.java:295) [server.jar:na]
at ome.logic.UpdateImpl.doAction(UpdateImpl.java:313) [server.jar:na]
at ome.logic.UpdateImpl.doAction(UpdateImpl.java:303) [server.jar:na]
at ome.logic.UpdateImpl.saveAndReturnObject(UpdateImpl.java:118) [server.jar:na]
at ome.security.basic.BasicSecuritySystem.loadEventContext(BasicSecuritySystem.java:431) [server.jar:na]
at ome.security.basic.EventHandler.doLogin(EventHandler.java:210) [server.jar:na]
at ome.security.basic.EventHandler.invoke(EventHandler.java:146) [server.jar:na]
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172) [org.springframework.aop.jar:3.0.1.RELEASE-A]
at org.springframework.orm.hibernate3.HibernateInterceptor.invoke(HibernateInterceptor.java:111) [org.springframework.orm.jar:3.0.1.RELEASE-A]
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172) [org.springframework.aop.jar:3.0.1.RELEASE-A]
at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:108) [org.springframework.transaction.jar:3.0.1.RELEASE-A]
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172) [org.springframework.aop.jar:3.0.1.RELEASE-A]
at ome.tools.hibernate.ProxyCleanupFilter$Interceptor.invoke(ProxyCleanupFilter.java:241) [server.jar:na]
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172) [org.springframework.aop.jar:3.0.1.RELEASE-A]
at ome.services.util.ServiceHandler.invoke(ServiceHandler.java:116) [server.jar:na]
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172) [org.springframework.aop.jar:3.0.1.RELEASE-A]
at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:202) [org.springframework.aop.jar:3.0.1.RELEASE-A]
at com.sun.proxy.$Proxy69.doWork(Unknown Source) [na:na]
at ome.services.util.Executor$Impl.execute(Executor.java:457) [server.jar:na]
at ome.services.util.Executor$Impl.execute(Executor.java:401) [server.jar:na]
at ome.services.blitz.fire.Ring.closeSessionsForManager(Ring.java:353) [blitz.jar:na]
at ome.services.blitz.fire.Ring.destroy(Ring.java:205) [blitz.jar:na]
at ome.services.blitz.util.BlitzConfiguration.destroy(BlitzConfiguration.java:286) [blitz.jar:na]
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:1.7.0_65]
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) ~[na:1.7.0_65]
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.7.0_65]
at java.lang.reflect.Method.invoke(Method.java:606) ~[na:1.7.0_65]
at org.springframework.beans.factory.support.DisposableBeanAdapter.invokeCustomDestroyMethod(DisposableBeanAdapter.java:273) [org.springframework.beans.jar:3.0.1.RELEASE-A]
at org.springframework.beans.factory.support.DisposableBeanAdapter.destroy(DisposableBeanAdapter.java:199) [org.springframework.beans.jar:3.0.1.RELEASE-A]
at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.destroyBean(DefaultSingletonBeanRegistry.java:486) [org.springframework.beans.jar:3.0.1.RELEASE-A]
at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.destroySingleton(DefaultSingletonBeanRegistry.java:462) [org.springframework.beans.jar:3.0.1.RELEASE-A]
at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.destroySingletons(DefaultSingletonBeanRegistry.java:430) [org.springframework.beans.jar:3.0.1.RELEASE-A]
at org.springframework.context.support.AbstractApplicationContext.destroyBeans(AbstractApplicationContext.java:1017) [org.springframework.context.jar:3.0.1.RELEASE-A]
at org.springframework.context.support.AbstractApplicationContext.doClose(AbstractApplicationContext.java:993) [org.springframework.context.jar:3.0.1.RELEASE-A]
at org.springframework.context.support.AbstractApplicationContext.close(AbstractApplicationContext.java:946) [org.springframework.context.jar:3.0.1.RELEASE-A]
at ome.system.OmeroContext.closeAll(OmeroContext.java:315) [common.jar:na]
at ome.services.blitz.Entry.shutdown(Entry.java:250) [blitz.jar:na]
at ome.services.blitz.Entry.start(Entry.java:219) [blitz.jar:na]
at ome.services.blitz.Entry.main(Entry.java:150) [blitz.jar:na]
Caused by: org.postgresql.util.PSQLException: ERROR: duplicate key value violates unique constraint "event_pkey"
Detail: Key (id)=(46359204) already exists.
at org.postgresql.core.v3.QueryExecutorImpl.receiveErrorResponse(QueryExecutorImpl.java:2103) ~[postgresql.jar:na]
at org.postgresql.core.v3.QueryExecutorImpl.processResults(QueryExecutorImpl.java:1836) ~[postgresql.jar:na]
at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:257) ~[postgresql.jar:na]
at org.postgresql.jdbc2.AbstractJdbc2Statement.execute(AbstractJdbc2Statement.java:512) ~[postgresql.jar:na]
at org.postgresql.jdbc2.AbstractJdbc2Statement.executeWithFlags(AbstractJdbc2Statement.java:388) ~[postgresql.jar:na]
at org.postgresql.jdbc2.AbstractJdbc2Statement.executeUpdate(AbstractJdbc2Statement.java:334) ~[postgresql.jar:na]
at sun.reflect.GeneratedMethodAccessor202.invoke(Unknown Source) ~[na:na]
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.7.0_65]
at java.lang.reflect.Method.invoke(Method.java:606) ~[na:1.7.0_65]
at bitronix.tm.resource.jdbc.BaseProxyHandlerClass.invoke(BaseProxyHandlerClass.java:64) ~[btm.jar:2.1.3]
at com.sun.proxy.$Proxy9.executeUpdate(Unknown Source) ~[na:na]
at org.hibernate.jdbc.NonBatchingBatcher.addToBatch(NonBatchingBatcher.java:46) ~[hibernate-core.jar:na]
at org.hibernate.persister.entity.AbstractEntityPersister.insert(AbstractEntityPersister.java:2418) ~[hibernate-core.jar:na]
... 47 common frames omitted
2014-11-01 10:03:49,057 INFO [ org.perf4j.TimingLogger] ( main) start[1414832629047] time[10] tag[omero.call.exception]
2014-11-01 10:03:49,059 WARN [ ome.services.util.ServiceHandler] ( main) DataIntegrityViolationException thrown.

org.springframework.dao.DataIntegrityViolationException: could not insert: [ome.model.meta.Event]; SQL [insert into event (containingEvent, external_id, permissions, experimenter, experimenterGroup, "session", status, time, type, id) values (?, ?, ?, ?, ?, ?, ?, ?, ?, ?)]; constraint [event_pkey]; nested exception is org.hibernate.exception.ConstraintViolationException: could not insert: [ome.model.meta.Event]
at org.springframework.orm.hibernate3.SessionFactoryUtils.convertHibernateAccessException(SessionFactoryUtils.java:637) ~[org.springframework.orm.jar:3.0.1.RELEASE-A]
at org.springframework.orm.hibernate3.HibernateAccessor.convertHibernateAccessException(HibernateAccessor.java:412) ~[org.springframework.orm.jar:3.0.1.RELEASE-A]
at org.springframework.orm.hibernate3.HibernateInterceptor.invoke(HibernateInterceptor.java:117) ~[org.springframework.orm.jar:3.0.1.RELEASE-A]
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172) [org.springframework.aop.jar:3.0.1.RELEASE-A]
at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:108) ~[org.springframework.transaction.jar:3.0.1.RELEASE-A]
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172) [org.springframework.aop.jar:3.0.1.RELEASE-A]
at ome.tools.hibernate.ProxyCleanupFilter$Interceptor.invoke(ProxyCleanupFilter.java:241) ~[server.jar:na]
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172) [org.springframework.aop.jar:3.0.1.RELEASE-A]
at ome.services.util.ServiceHandler.invoke(ServiceHandler.java:116) ~[server.jar:na]
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172) [org.springframework.aop.jar:3.0.1.RELEASE-A]
at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:202) [org.springframework.aop.jar:3.0.1.RELEASE-A]
at com.sun.proxy.$Proxy69.doWork(Unknown Source) [na:na]
at ome.services.util.Executor$Impl.execute(Executor.java:457) [server.jar:na]
at ome.services.util.Executor$Impl.execute(Executor.java:401) [server.jar:na]
at ome.services.blitz.fire.Ring.closeSessionsForManager(Ring.java:353) [blitz.jar:na]
at ome.services.blitz.fire.Ring.destroy(Ring.java:205) [blitz.jar:na]
at ome.services.blitz.util.BlitzConfiguration.destroy(BlitzConfiguration.java:286) [blitz.jar:na]
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:1.7.0_65]
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) ~[na:1.7.0_65]
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.7.0_65]
at java.lang.reflect.Method.invoke(Method.java:606) ~[na:1.7.0_65]
at org.springframework.beans.factory.support.DisposableBeanAdapter.invokeCustomDestroyMethod(DisposableBeanAdapter.java:273) [org.springframework.beans.jar:3.0.1.RELEASE-A]
at org.springframework.beans.factory.support.DisposableBeanAdapter.destroy(DisposableBeanAdapter.java:199) [org.springframework.beans.jar:3.0.1.RELEASE-A]
at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.destroyBean(DefaultSingletonBeanRegistry.java:486) [org.springframework.beans.jar:3.0.1.RELEASE-A]
at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.destroySingleton(DefaultSingletonBeanRegistry.java:462) [org.springframework.beans.jar:3.0.1.RELEASE-A]
at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.destroySingletons(DefaultSingletonBeanRegistry.java:430) [org.springframework.beans.jar:3.0.1.RELEASE-A]
at org.springframework.context.support.AbstractApplicationContext.destroyBeans(AbstractApplicationContext.java:1017) [org.springframework.context.jar:3.0.1.RELEASE-A]
at org.springframework.context.support.AbstractApplicationContext.doClose(AbstractApplicationContext.java:993) [org.springframework.context.jar:3.0.1.RELEASE-A]
at org.springframework.context.support.AbstractApplicationContext.close(AbstractApplicationContext.java:946) [org.springframework.context.jar:3.0.1.RELEASE-A]
at ome.system.OmeroContext.closeAll(OmeroContext.java:315) [common.jar:na]
at ome.services.blitz.Entry.shutdown(Entry.java:250) [blitz.jar:na]
at ome.services.blitz.Entry.start(Entry.java:219) [blitz.jar:na]
at ome.services.blitz.Entry.main(Entry.java:150) [blitz.jar:na]
Caused by: org.hibernate.exception.ConstraintViolationException: could not insert: [ome.model.meta.Event]
at org.hibernate.exception.SQLStateConverter.convert(SQLStateConverter.java:96) ~[hibernate-core.jar:na]
at org.hibernate.exception.JDBCExceptionHelper.convert(JDBCExceptionHelper.java:66) ~[hibernate-core.jar:na]
at org.hibernate.persister.entity.AbstractEntityPersister.insert(AbstractEntityPersister.java:2438) ~[hibernate-core.jar:na]
at org.hibernate.persister.entity.AbstractEntityPersister.insert(AbstractEntityPersister.java:2858) ~[hibernate-core.jar:na]
at org.hibernate.action.EntityInsertAction.execute(EntityInsertAction.java:79) ~[hibernate-core.jar:na]
at org.hibernate.engine.ActionQueue.execute(ActionQueue.java:267) ~[hibernate-core.jar:na]
at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:259) ~[hibernate-core.jar:na]
at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:178) ~[hibernate-core.jar:na]
at org.hibernate.event.def.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:321) ~[hibernate-core.jar:na]
at org.hibernate.event.def.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:51) ~[hibernate-core.jar:na]
at org.hibernate.impl.SessionImpl.flush(SessionImpl.java:1208) ~[hibernate-core.jar:na]
at ome.logic.UpdateImpl.afterUpdate(UpdateImpl.java:295) ~[server.jar:na]
at ome.logic.UpdateImpl.doAction(UpdateImpl.java:313) ~[server.jar:na]
at ome.logic.UpdateImpl.doAction(UpdateImpl.java:303) ~[server.jar:na]
at ome.logic.UpdateImpl.saveAndReturnObject(UpdateImpl.java:118) ~[server.jar:na]
at ome.security.basic.BasicSecuritySystem.loadEventContext(BasicSecuritySystem.java:431) ~[server.jar:na]
at ome.security.basic.EventHandler.doLogin(EventHandler.java:210) ~[server.jar:na]
at ome.security.basic.EventHandler.invoke(EventHandler.java:146) ~[server.jar:na]
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172) [org.springframework.aop.jar:3.0.1.RELEASE-A]
at org.springframework.orm.hibernate3.HibernateInterceptor.invoke(HibernateInterceptor.java:111) ~[org.springframework.orm.jar:3.0.1.RELEASE-A]
... 30 common frames omitted
Caused by: org.postgresql.util.PSQLException: ERROR: duplicate key value violates unique constraint "event_pkey"
Detail: Key (id)=(46359204) already exists.
at org.postgresql.core.v3.QueryExecutorImpl.receiveErrorResponse(QueryExecutorImpl.java:2103) ~[postgresql.jar:na]
at org.postgresql.core.v3.QueryExecutorImpl.processResults(QueryExecutorImpl.java:1836) ~[postgresql.jar:na]
at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:257) ~[postgresql.jar:na]
at org.postgresql.jdbc2.AbstractJdbc2Statement.execute(AbstractJdbc2Statement.java:512) ~[postgresql.jar:na]
at org.postgresql.jdbc2.AbstractJdbc2Statement.executeWithFlags(AbstractJdbc2Statement.java:388) ~[postgresql.jar:na]
at org.postgresql.jdbc2.AbstractJdbc2Statement.executeUpdate(AbstractJdbc2Statement.java:334) ~[postgresql.jar:na]
at sun.reflect.GeneratedMethodAccessor202.invoke(Unknown Source) ~[na:na]
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.7.0_65]
at java.lang.reflect.Method.invoke(Method.java:606) ~[na:1.7.0_65]
at bitronix.tm.resource.jdbc.BaseProxyHandlerClass.invoke(BaseProxyHandlerClass.java:64) ~[btm.jar:2.1.3]
at com.sun.proxy.$Proxy9.executeUpdate(Unknown Source) ~[na:na]
at org.hibernate.jdbc.NonBatchingBatcher.addToBatch(NonBatchingBatcher.java:46) ~[hibernate-core.jar:na]
at org.hibernate.persister.entity.AbstractEntityPersister.insert(AbstractEntityPersister.java:2418) ~[hibernate-core.jar:na]
... 47 common frames omitted
2014-11-01 10:03:49,059 INFO [ ome.services.util.ServiceHandler] ( main) Excp: org.springframework.dao.DataIntegrityViolationException: could not insert: [ome.model.meta.Event]; SQL [insert into event (containingEvent, external_id, permissions, experimenter, experimenterGroup, "session", status, time, type, id) values (?, ?, ?, ?, ?, ?, ?, ?, ?, ?)]; constraint [event_pkey]; nested exception is org.hibernate.exception.ConstraintViolationException: could not insert: [ome.model.meta.Event]
2014-11-01 10:03:49,059 ERROR [ ome.services.blitz.fire.Ring] ( main) Error stopping ring ome.services.blitz.fire.Ring@15a861d4
ome.conditions.ValidationException: could not insert: [ome.model.meta.Event]; SQL [insert into event (containingEvent, external_id, permissions, experimenter, experimenterGroup, "session", status, time, type, id) values (?, ?, ?, ?, ?, ?, ?, ?, ?, ?)]; constraint [event_pkey]; nested exception is org.hibernate.exception.ConstraintViolationException: could not insert: [ome.model.meta.Event]
at org.springframework.orm.hibernate3.SessionFactoryUtils.convertHibernateAccessException(SessionFactoryUtils.java:637) ~[org.springframework.orm.jar:3.0.1.RELEASE-A]
at org.springframework.orm.hibernate3.HibernateAccessor.convertHibernateAccessException(HibernateAccessor.java:412) ~[org.springframework.orm.jar:3.0.1.RELEASE-A]
at org.springframework.orm.hibernate3.HibernateInterceptor.invoke(HibernateInterceptor.java:117) ~[org.springframework.orm.jar:3.0.1.RELEASE-A]
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172) ~[org.springframework.aop.jar:3.0.1.RELEASE-A]
at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:108) ~[org.springframework.transaction.jar:3.0.1.RELEASE-A]
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172) ~[org.springframework.aop.jar:3.0.1.RELEASE-A]
at ome.tools.hibernate.ProxyCleanupFilter$Interceptor.invoke(ProxyCleanupFilter.java:241) ~[server.jar:na]
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172) ~[org.springframework.aop.jar:3.0.1.RELEASE-A]
at ome.services.util.ServiceHandler.invoke(ServiceHandler.java:116) ~[server.jar:na]
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172) ~[org.springframework.aop.jar:3.0.1.RELEASE-A]
at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:202) ~[org.springframework.aop.jar:3.0.1.RELEASE-A]
at com.sun.proxy.$Proxy69.doWork(Unknown Source) ~[na:na]
at ome.services.util.Executor$Impl.execute(Executor.java:457) ~[server.jar:na]
at ome.services.util.Executor$Impl.execute(Executor.java:401) ~[server.jar:na]
at ome.services.blitz.fire.Ring.closeSessionsForManager(Ring.java:353) ~[blitz.jar:na]
at ome.services.blitz.fire.Ring.destroy(Ring.java:205) ~[blitz.jar:na]
at ome.services.blitz.util.BlitzConfiguration.destroy(BlitzConfiguration.java:286) [blitz.jar:na]
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:1.7.0_65]
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) ~[na:1.7.0_65]
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.7.0_65]
at java.lang.reflect.Method.invoke(Method.java:606) ~[na:1.7.0_65]
at org.springframework.beans.factory.support.DisposableBeanAdapter.invokeCustomDestroyMethod(DisposableBeanAdapter.java:273) [org.springframework.beans.jar:3.0.1.RELEASE-A]
at org.springframework.beans.factory.support.DisposableBeanAdapter.destroy(DisposableBeanAdapter.java:199) [org.springframework.beans.jar:3.0.1.RELEASE-A]
at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.destroyBean(DefaultSingletonBeanRegistry.java:486) [org.springframework.beans.jar:3.0.1.RELEASE-A]
at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.destroySingleton(DefaultSingletonBeanRegistry.java:462) [org.springframework.beans.jar:3.0.1.RELEASE-A]
at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.destroySingletons(DefaultSingletonBeanRegistry.java:430) [org.springframework.beans.jar:3.0.1.RELEASE-A]
at org.springframework.context.support.AbstractApplicationContext.destroyBeans(AbstractApplicationContext.java:1017) [org.springframework.context.jar:3.0.1.RELEASE-A]
at org.springframework.context.support.AbstractApplicationContext.doClose(AbstractApplicationContext.java:993) [org.springframework.context.jar:3.0.1.RELEASE-A]
at org.springframework.context.support.AbstractApplicationContext.close(AbstractApplicationContext.java:946) [org.springframework.context.jar:3.0.1.RELEASE-A]
at ome.system.OmeroContext.closeAll(OmeroContext.java:315) [common.jar:na]
at ome.services.blitz.Entry.shutdown(Entry.java:250) [blitz.jar:na]
at ome.services.blitz.Entry.start(Entry.java:219) [blitz.jar:na]
at ome.services.blitz.Entry.main(Entry.java:150) [blitz.jar:na]
2014-11-01 10:03:49,060 INFO [ ome.services.blitz.fire.Registry] ( main) Found 0 cluster node(s) : []
2014-11-01 10:03:49,061 INFO [o.services.blitz.util.BlitzConfiguration] ( main) Shutting down Ice.Communicator
2014-11-01 10:03:49,150 INFO [ ome.services.util.ServerVersionCheck] ( main) -------------------------------------------------
2014-11-01 10:03:49,150 INFO [ ome.services.util.ServerVersionCheck] ( main) Stopping OMERO...
2014-11-01 10:03:49,150 INFO [ ome.services.util.ServerVersionCheck] ( main) -------------------------------------------------
2014-11-01 10:03:49,150 INFO [ ome.services.pixeldata.PixelDataThread] ( main) Shutting down PixelDataThread
2014-11-01 10:03:49,150 INFO [ o.s.pixeldata.PersistentEventLogLoader] ( main) Shutting down EventLogLoader
2014-11-01 10:03:49,151 INFO [ ome.services.fulltext.FullTextThread] ( main) Shutting down Full-Text Indexer
2014-11-01 10:03:49,151 INFO [ ome.services.eventlogs.EventLogQueue] ( main) Shutting down EventLogLoader
2014-11-01 10:03:49,152 INFO [ o.s.scheduler.SchedulerFactoryBean] ( main) Shutting down Quartz Scheduler
2014-11-01 10:03:49,335 INFO [.s.ShutdownSafeEhcacheManagerFactoryBean] ( main) Shutting down EHCache CacheManager
2014-11-01 10:03:49,338 INFO [ ome.services.blitz.Entry] ( main) Finished shutdown.
2014-11-01 10:18:23,417 INFO [ ome.services.blitz.Entry] ( main) Creating OMERO.blitz. Please wait...
2014-11-01 10:18:25,547 INFO [.s.ShutdownSafeEhcacheManagerFactoryBean] ( main) Initializing EHCache CacheManager
2014-11-01 10:18:26,581 INFO [ ome.services.util.DBPatchCheck] ( main) Verified database patch: OMERO5.0__0
2014-11-01 10:18:26,788 INFO [ ome.services.util.DBUserCheck] ( main) User root.id = 0
2014-11-01 10:18:26,790 INFO [ ome.services.util.DBUserCheck] ( main) User guest.id = 1
2014-11-01 10:18:26,790 INFO [ ome.services.util.DBUserCheck] ( main) Group system.id = 0
2014-11-01 10:18:26,791 INFO [ ome.services.util.DBUserCheck] ( main) Group user.id = 1
2014-11-01 10:18:26,791 INFO [ ome.services.util.DBUserCheck] ( main) Group guest.id = 2
2014-11-01 10:18:29,711 INFO [ ome.services.fulltext.FullTextAnalyzer] ( main) Initialized FullTextAnalyzer
2014-11-01 10:18:34,710 INFO [.s.ShutdownSafeEhcacheManagerFactoryBean] ( main) Shutting down EHCache CacheManager
2014-11-01 10:18:34,717 ERROR [ ome.services.blitz.Entry] ( main) Error on startup.
org.springframework.beans.factory.access.BootstrapException: Unable to return specified BeanFactory instance: factory key [OMERO.blitz], from group with resource name [classpath*:beanRefContext.xml]; nested exception is org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'OMERO.blitz' defined in URL [jar:file:/usr2/local/OMERO/OMERO.server-5.0.5-ice34-b47/lib/server/blitz.jar!/beanRefContext.xml]: Cannot resolve reference to bean 'ome.server' while setting constructor argument; nested exception is org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'ome.server' defined in URL [jar:file:/usr2/local/OMERO/OMERO.server-5.0.5-ice34-b47/lib/server/server.jar!/beanRefContext.xml]: Instantiation of bean failed; nested exception is org.springframework.beans.BeanInstantiationException: Could not instantiate bean class [ome.system.OmeroContext]: Constructor threw exception; nested exception is org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'sessionManager' defined in class path resource [ome/services/sec-primitives.xml]: Invocation of init method failed; nested exception is java.lang.RuntimeException: =====================================================
Data access exception: Did you create your database?
=====================================================

at org.springframework.beans.factory.access.SingletonBeanFactoryLocator.useBeanFactory(SingletonBeanFactoryLocator.java:409) ~[org.springframework.beans.jar:3.0.1.RELEASE-A]
at ome.system.OmeroContext.getInstance(OmeroContext.java:203) ~[common.jar:na]
at ome.services.blitz.Entry.start(Entry.java:193) [blitz.jar:na]
at ome.services.blitz.Entry.main(Entry.java:150) [blitz.jar:na]
Caused by: org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'OMERO.blitz' defined in URL [jar:file:/usr2/local/OMERO/OMERO.server-5.0.5-ice34-b47/lib/server/blitz.jar!/beanRefContext.xml]: Cannot resolve reference to bean 'ome.server' while setting constructor argument; nested exception is org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'ome.server' defined in URL [jar:file:/usr2/local/OMERO/OMERO.server-5.0.5-ice34-b47/lib/server/server.jar!/beanRefContext.xml]: Instantiation of bean failed; nested exception is org.springframework.beans.BeanInstantiationException: Could not instantiate bean class [ome.system.OmeroContext]: Constructor threw exception; nested exception is org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'sessionManager' defined in class path resource [ome/services/sec-primitives.xml]: Invocation of init method failed; nested exception is java.lang.RuntimeException: =====================================================
Data access exception: Did you create your database?
=====================================================

at org.springframework.beans.factory.support.BeanDefinitionValueResolver.resolveReference(BeanDefinitionValueResolver.java:328) ~[org.springframework.beans.jar:3.0.1.RELEASE-A]
at org.springframework.beans.factory.support.BeanDefinitionValueResolver.resolveValueIfNecessary(BeanDefinitionValueResolver.java:106) ~[org.springframework.beans.jar:3.0.1.RELEASE-A]
at org.springframework.beans.factory.support.ConstructorResolver.resolveConstructorArguments(ConstructorResolver.java:586) ~[org.springframework.beans.jar:3.0.1.RELEASE-A]
at org.springframework.beans.factory.support.ConstructorResolver.autowireConstructor(ConstructorResolver.java:140) ~[org.springframework.beans.jar:3.0.1.RELEASE-A]
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.autowireConstructor(AbstractAutowireCapableBeanFactory.java:984) ~[org.springframework.beans.jar:3.0.1.RELEASE-A]
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBeanInstance(AbstractAutowireCapableBeanFactory.java:888) ~[org.springframework.beans.jar:3.0.1.RELEASE-A]
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:479) ~[org.springframework.beans.jar:3.0.1.RELEASE-A]
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:450) ~[org.springframework.beans.jar:3.0.1.RELEASE-A]
at org.springframework.beans.factory.support.AbstractBeanFactory$1.getObject(AbstractBeanFactory.java:290) ~[org.springframework.beans.jar:3.0.1.RELEASE-A]
at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:222) ~[org.springframework.beans.jar:3.0.1.RELEASE-A]
at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:287) ~[org.springframework.beans.jar:3.0.1.RELEASE-A]
at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:193) ~[org.springframework.beans.jar:3.0.1.RELEASE-A]
at org.springframework.context.support.AbstractApplicationContext.getBean(AbstractApplicationContext.java:1048) ~[org.springframework.context.jar:3.0.1.RELEASE-A]
at org.springframework.beans.factory.access.SingletonBeanFactoryLocator.useBeanFactory(SingletonBeanFactoryLocator.java:397) ~[org.springframework.beans.jar:3.0.1.RELEASE-A]
... 3 common frames omitted
Caused by: org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'ome.server' defined in URL [jar:file:/usr2/local/OMERO/OMERO.server-5.0.5-ice34-b47/lib/server/server.jar!/beanRefContext.xml]: Instantiation of bean failed; nested exception is org.springframework.beans.BeanInstantiationException: Could not instantiate bean class [ome.system.OmeroContext]: Constructor threw exception; nested exception is org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'sessionManager' defined in class path resource [ome/services/sec-primitives.xml]: Invocation of init method failed; nested exception is java.lang.RuntimeException:

[jacques2020]

Hi,

I supplement my post of yesterday. I explored in a systematic fashion the differences in the schema of omero database between an empty one created with v 5.0.5 and the one I use. I use the command below and find numerous differences (see attached file). The select granted permission to benjamin is normal and could be safely ignored. Is there a database upgrade script that can be run to fix these differences ? Or should I edit all that manually ? I feel to have correctly upgraded the database according instruction when upgrading omero but I might have missed one. I see no other explanation.
Thank you very much for your help.
Best

Jacques

Code: Select all

pg_dump omero -s -h localhost -U omero -f /tmp/struture_omero.dump
pg_dump omero_empty -s -h localhost -U omero -f /tmp/struture_omero_empty.dump
diff -i /tmp/struture_omero.dump /tmp/struture_omero_empty.dump > /tmp/omero_populated__omero_fresh_5.0.5_diff_ignoring_case_diff.txt


[jmoore]

Morning,

1) ... I see no explanation but the fact that the database was created in march 2011 and despite the fact that I pay attention to the upgrade procedure posted on the openmicroscopy website, something could have been missed. This is the only plausible explanation. I will try the "inserts" strategy (with explicit columns) on a freshly created DB. This should fix all these problems I imagine.

That sounds like a good idea. Fresh DB + inserts from backup + inserts from running server.

2) Maybe because of my manipulations or because system disk of the server got full (but not the /usr containing the OMERO application, nor /tmp, nor the place containing the omero data or postgresql database, I got the error below). Since then, there is no way to restart omero.... I am trying to revert to the last backup. If you have any suggestion, I am very interested !
...

Code: Select all

Caused by: org.postgresql.util.PSQLException: ERROR: duplicate key value violates unique constraint "event_pkey"


Do you always get this on trying to start the server? Have you ever had a successful start? If not, then perhaps all that's missing is bumping each of the sequences to match the highest value in individual tables. You can check if this is the problem by querying the table and the sequence:

Code: Select all

omero=# select id from eventlog order by id desc limit 1;
  id 
------
1084
(1 row)

omero=# select * from seq_eventlog;
sequence_name | last_value | start_value | increment_by |      max_value      | min_value | cache_value | log_cnt | is_cycled | is_called
---------------+------------+-------------+--------------+---------------------+-----------+-------------+---------+-----------+-----------
seq_eventlog  |       1084 |           1 |            1 | 9223372036854775807 |         1 |           1 |      26 | f         | t
(1 row)


3) ...

Code: Select all

setval
--------
    115
(1 row)


That certainly sounds promising.

I supplement my post of yesterday. I explored in a systematic fashion the differences in the schema of omero database between an empty one created with v 5.0.5 and the one I use. I use the command below and find numerous differences (see attached file). The select granted permission to benjamin is normal and could be safely ignored. Is there a database upgrade script that can be run to fix these differences ? Or should I edit all that manually ? I feel to have correctly upgraded the database according instruction when upgrading omero but I might have missed one. I see no other explanation.

I would be easier if you could send me the 2 separate schemas. I tend to use apgdiff for comparing them. Glancing at the diff output, however, many of the differences are common for schema comparison due to minor formatting in the output or the ordering of columns.

~Josh

[jacques2020]

Hi,

1)

Code: Select all

That sounds like a good idea. Fresh DB + inserts from backup + inserts from running server.

That was my initial idea, but I cannot manage. Indeed, adding the inserts from backup triggers massively the foreign_keys (fk) constraints. I considered switching to replica role by adding at the very beginning of the inserts file with

Code: Select all

set session_replication_role='replica';

but in my single trial, I faced two issues: first, the fk constaints still issue error and second, I have no idea how to force a general test that the data fullfill all the contraint after having adding all the data. Any suggestion ?

2) thus for now, I barely restored the last backup of friday (31st) evening. Despites the inserts where imported, it works fine. Thus, I would tend to imagine that the error of of duplicate keys I saw on saturday was due to the saturated system disk. However, before that, I always got this error at each attempt of server starting. Even after freeing space on the various disk (30 GB+ on root, 20GB on /usr2 containing omero, etc...). I however kept the problematic DB (renaming it omero20141103) for 'forensic' investigation (and hoping to re-import the inserts from it). I never got a successful start with it even with space on disk and rebooting the computer. I sense that I have the issue you mention even if I am not clear with the use of these tables in omero. Here are my output

Code: Select all

psql omero20141103
psql (9.1.14)
Type "help" for help.

omero20141103=# select id from eventlog order by id desc limit 1;
    id   
----------
41570621
(1 row)

omero20141103=# select * from seq_eventlog;                     
sequence_name | last_value | start_value | increment_by |      max_value      | min_value | cache_value | log_cnt | is_cycled | is_called
---------------+------------+-------------+--------------+---------------------+-----------+-------------+---------+-----------+-----------
seq_eventlog  |   41555274 |           1 |            1 | 9223372036854775807 |         1 |           1 |       0 | f         | t
(1 row)



And I have little idea how to fix that. Should I edit seq_eventlog with to have last_value matching the max value (or row count) of eventlog table ? This mean that my omero was hanged / stopped in the middle of something ? and I will loose the log of some events that should have occured to finish the action ? Is it a concern if after this editing, I extract the inserts to be put in a

Fresh DB + inserts from backup + ...

3)

I would be easier if you could send me the 2 separate schemas.

They are attached.

Thank you.

Best

JAcques