[ome-devel] OMERO 5 deletion performance

Yanling Liu vrnova at gmail.com
Tue Jun 3 14:29:44 BST 2014


Hi, Josh

This is the log information from Blitz-0.log file:

2014-06-03 07:56:43,460 INFO  [         ome.security.basic.EventHandler]
(2-thread-4)  Auth:
user=0,group=0,event=null(Sessions),sess=82f64ba5-c6f4-40e1-b10b-3803eea50634
2014-06-03 07:56:43,462 INFO  [                 org.perf4j.TimingLogger]
(2-thread-4) start[1401796603460] time[2]
tag[omero.call.success.ome.services.sessions.SessionManagerImpl$6.doWork]
2014-06-03 07:56:43,462 INFO  [        ome.services.util.ServiceHandler]
(2-thread-4)  Rslt:    (ome.model.meta.Experimenter:Id_52,
ome.model.meta.ExperimenterGroup:Id_3, (3, 1), ... 4 more)
2014-06-03 07:56:43,462 INFO  [                 org.perf4j.TimingLogger]
(2-thread-4) start[1401796603432] time[30]
tag[omero.sessions.synchronization]
2014-06-03 07:56:43,463 INFO  [ome.services.sessions.state.SessionCache]
(2-thread-4) Synchronization took 30 ms.
2014-06-03 07:57:00,012 INFO  [ ome.services.blitz.fire.SessionManagerI]
(2-thread-1) Performing requestHeartbeats
2014-06-03 07:57:41,128 INFO  [ ome.services.blitz.fire.SessionManagerI]
(.Server-19) Found session locally: a040dd26-7e10-4ce4-bb18-5f8497f4d7b7
2014-06-03 07:57:41,130 INFO  [ ome.services.blitz.fire.SessionManagerI]
(.Server-19) Rejoining session
ServiceFactoryI(session-8817f9ad-0541-438b-ac7f-9b82695a2a8e/a040dd26-7e10-4ce4-bb18-5f8497f4d7b7)
(agent=OMERO.web)
2014-06-03 07:57:41,134 INFO  [o.services.sessions.SessionContext$Count]
(.Server-19) -Reference count: a040dd26-7e10-4ce4-bb18-5f8497f4d7b7=0
2014-06-03 07:57:41,134 INFO  [                      omero.cmd.SessionI]
(.Server-19)
cleanupSelf(ServiceFactoryI(session-8817f9ad-0541-438b-ac7f-9b82695a2a8e/a040dd26-7e10-4ce4-bb18-5f8497f4d7b7)).
omero at fr-s-ivg-mia-d2:~/omero/OMERO.server$ tail var/log/Blitz-0.log
2014-06-03 09:16:43,450 INFO  [         ome.security.basic.EventHandler]
(2-thread-2)  Auth:
user=0,group=0,event=null(Sessions),sess=82f64ba5-c6f4-40e1-b10b-3803eea50634
2014-06-03 09:16:43,452 INFO  [                 org.perf4j.TimingLogger]
(2-thread-2) start[1401801403450] time[2]
tag[omero.call.success.ome.services.sessions.SessionManagerImpl$6.doWork]
2014-06-03 09:16:43,452 INFO  [        ome.services.util.ServiceHandler]
(2-thread-2)  Rslt:    (ome.model.meta.Experimenter:Id_0,
ome.model.meta.ExperimenterGroup:Id_0, (0, 1, 3, ... 1 more), ... 4 more)
2014-06-03 09:16:43,452 INFO  [                 org.perf4j.TimingLogger]
(2-thread-2) start[1401801403426] time[26]
tag[omero.sessions.synchronization]
2014-06-03 09:16:43,453 INFO  [ome.services.sessions.state.SessionCache]
(2-thread-2) Synchronization took 26 ms.
2014-06-03 09:17:13,151 INFO  [ ome.services.blitz.fire.SessionManagerI]
(.Server-19) Found session locally: 0f848c0a-c91e-403c-b49e-bb01496b821d
2014-06-03 09:17:13,152 INFO  [ ome.services.blitz.fire.SessionManagerI]
(.Server-19) Rejoining session
ServiceFactoryI(session-8dae7d7e-a49e-4bca-9734-0ceddd7188de/0f848c0a-c91e-403c-b49e-bb01496b821d)
(agent=OMERO.web)
2014-06-03 09:17:13,154 INFO  [o.services.sessions.SessionContext$Count]
(.Server-19) -Reference count: 0f848c0a-c91e-403c-b49e-bb01496b821d=0
2014-06-03 09:17:13,154 INFO  [                      omero.cmd.SessionI]
(.Server-19)
cleanupSelf(ServiceFactoryI(session-8dae7d7e-a49e-4bca-9734-0ceddd7188de/0f848c0a-c91e-403c-b49e-bb01496b821d)).
2014-06-03 09:18:00,012 INFO  [ ome.services.blitz.fire.SessionManagerI]
(2-thread-3) Performing requestHeartbeats

Seems normal to me.

But I do found something in postgres log file:

2014-06-03 08:43:19 EDT WARNING:  out of shared memory
2014-06-03 08:43:19 EDT ERROR:  out of shared memory
2014-06-03 08:43:19 EDT HINT:  You might need to increase
max_locks_per_transaction.
2014-06-03 08:43:19 EDT STATEMENT:  create temporary table HT_job (id int8
not null) on commit drop
2014-06-03 08:43:19 EDT ERROR:  current transaction is aborted, commands
ignored until end of transaction block
2014-06-03 08:43:19 EDT STATEMENT:  insert into HT_job select job0_.id as
id from job job0_ where
    (
      1 = $1 OR
      1 = $2 OR
      (group_id in ($3)) OR
      (owner_id = $4 AND (select (__g.permissions & 1024) = 1024 from
experimentergroup __g where __g.id = group_id)) OR
      (group_id in ($5,$6) AND (select (__g.permissions & 64) = 64 from
experimentergroup __g where __g.id = group_id)) OR
      ((select (__g.permissions & 4) = 4 from experimentergroup __g where __
g.id = group_id))
    ) and id=$7 and owner_id=$8
2014-06-03 08:43:19 EDT ERROR:  current transaction is aborted, commands
ignored until end of transaction block
2014-06-03 08:43:19 EDT STATEMENT:  drop table HT_job

In postgresql.conf I have following settings:

max_connections = 100
#max_locks_per_transaction = 64         # min 10

Mote the max_locks_per_transaction is commented out by default. I am not an
expert on postgres and I would appreciate if you may provide some hints on
how to set postgres parameters properly for OMERO.

Thanks,

On Tue, Jun 3, 2014 at 6:28 AM, Josh Moore <josh at glencoesoftware.com> wrote:

> Hi Yanling,
>
> >> On Mon, Jun 2, 2014 at 10:02 AM, Yanling Liu <vrnova at gmail.com> wrote:
> >>
> >>> I have OMERO 5 installed on Ubuntu 12.04 64bit 8GB Mem, 4 Cores @
> 3.47GHz
> >>> and NFS mounted storage for OMERO data storage.
> >>>
> >>> When deleting couple hundred images (each at 1k x 1k pixels) through
> >>> OMERO web, it took long time (> 10 minutes) to finish. In general
> project
> >>> and dataset deletion are very slow in OMERO web. I wonder if there's
> any
> >>> hint to tune the performance of OMERO.
> >>>
> >>> I have increased JVM memory usage based on OMERO documentation.
>
> Though there are further tunings you can try, Deletion performance is
> quite poor at the moment, but it's something we're actively working on.
>
>
> > On Mon, Jun 2, 2014 at 11:09 AM, Yanling Liu <vrnova at gmail.com> wrote:
> >
> >> By looking OMEROweb.log, deleting single file takes 5 good seconds. Is
> >> this normal and expected? How could I find out if this because OMERO
> >> itself, or postgres, or NFS storage access speed?
> >>
> >> Thanks ahead.....
>
> Could you send us the var/log/Blitz-0.log file for the time of the
> deletion?
>
>
>
> On Jun 2, 2014, at 5:12 PM, Yanling Liu wrote:
>
> > Also I am getting this error:
> >
> > 2014-06-02 16:07:37,242 ERROR [      omeroweb.webclient.webclient_utils]
> > (proc.20168) _formatReport:38 Format report: {'warning': '', 'error':
> > 'Failure during DeleteHandle.steps
> > :org.hibernate.exception.GenericJDBCException: could not insert/select
> ids
> > for bulk delete'}
> >
> > Anything wrong with postgres? Or is it because I selected too many files
> > for bulk deletion?
>
> Possibly. Again, the log file would be the most helpful. There may be an
> issue with your PG installation.
>
> Cheers,
> ~Josh.
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.openmicroscopy.org.uk/pipermail/ome-devel/attachments/20140603/6a5747a0/attachment.html>


More information about the ome-devel mailing list