We're Hiring!

debugging ldap

Having a problem deploying OMERO? Please ask new questions at https://forum.image.sc/tags/omero
Please note:
Historical discussions about OMERO. Please look for and ask new questions at https://forum.image.sc/tags/omero

The OMERO.server installation documentation begins here and you can find OMERO.web deployment documentation here.

debugging ldap

Postby axkibe » Wed Mar 04, 2015 12:53 pm

Hello I just installed an Omero Server and on base it seems to run fine*, I cannot get LDAP to work tough.

However, after having done things to the book, at least I believe so, what options do I have to debug why it does not work? I don't see anything SSL or LDAP related in OMERO.server/var/log.

Code: Select all
omero@omero:~/OMERO.server$ bin/omero config get
omdero.ldap.base=dc=csc,dc=univie,dc=ac,dc=at
omdero.ldap.config=true
omdero.ldap.urls=ldaps://ldap.csc.univie.ac.at:636
omero.data.dir=/omero
omero.db.name=omero_db
omero.db.pass=xxx
omero.db.user=omero_dbuser
omero.ldap.referral=follow
omero.ldap.user_filter=(objectClass=inetOrgPerson)
omero.ldap.user_mapping=omeName=uid,firstName=givenName,lastName=sn,email=mail
omero.ldap.user_mapping==
omero.security.keyStore=/home/omero/.keystore/omero.jks
omero.security.keyStorePassword=xxx
omero.security.trustStore=/home/omero/.truststore/omero.jts
omero.security.trustStorePassword=xxx


Code: Select all
omero@omero:~/OMERO.server$ bin/omero admin diagnostics

================================================================================
OMERO Diagnostics 5.0.8-ice35-b60
================================================================================
       
Commands:   java -version                  1.7.0     (/usr/bin/java)
Commands:   python -V                      2.7.8     (/usr/bin/python)
Commands:   icegridnode --version          3.5.1     (/usr/bin/icegridnode)
Commands:   icegridadmin --version         3.5.1     (/usr/bin/icegridadmin)
Commands:   psql --version                 9.4.1     (/usr/bin/psql)

Server:     icegridnode                    running
Server:     Blitz-0                        active (pid = 21946, enabled)
Server:     DropBox                        active (pid = 21956, enabled)
Server:     FileServer                     active (pid = 21958, enabled)
Server:     Indexer-0                      active (pid = 21960, enabled)
Server:     MonitorServer                  active (pid = 21961, enabled)
Server:     OMERO.Glacier2                 active (pid = 21966, enabled)
Server:     OMERO.IceStorm                 active (pid = 21968, enabled)
Server:     PixelData-0                    active (pid = 21969, enabled)
Server:     Processor-0                    active (pid = 21980, enabled)
Server:     Tables-0                       active (pid = 21989, enabled)
Server:     TestDropBox                    inactive (enabled)

OMERO:      SSL port                       4064
OMERO:      TCP port                       4063

Log dir:    /home/omero/OMERO.server-5.0.8-ice35-b60/var/log exists

Log files:  Blitz-0.log                    1.0 MB        errors=1    warnings=36 
Log files:  DropBox.log                    14.0 KB       errors=0    warnings=5   
Log files:  FileServer.log                 1.0 KB       
Log files:  Indexer-0.log                  15.0 KB     
Log files:  MonitorServer.log              8.0 KB       
Log files:  OMEROweb.log                   n/a
Log files:  PixelData-0.log                18.0 KB     
Log files:  Processor-0.log                9.0 KB        errors=0    warnings=3   
Log files:  Tables-0.log                   9.0 KB        errors=0    warnings=3   
Log files:  TestDropBox.log                n/a
Log files:  master.err                     16.0 KB       errors=0    warnings=11 
Log files:  master.out                     0.0 KB       
Log files:  Total size                     1.26 MB


Environment:OMERO_HOME=(unset)             
Environment:OMERO_NODE=(unset)             
Environment:OMERO_MASTER=(unset)           
Environment:OMERO_TEMPDIR=(unset)         
Environment:PATH=/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games
Environment:PYTHONPATH=(unset)             
Environment:ICE_HOME=(unset)               
Environment:LD_LIBRARY_PATH=(unset)       
Environment:DYLD_LIBRARY_PATH=(unset)     

OMERO data dir: '/omero'   Exists? True   Is writable? True
OMERO temp dir: '/home/omero/omero/tmp'   Exists? True   Is writable? True   (Size: 0)
OMERO.web status... [RUNNING] (PID 1262)


Code: Select all
omero@omero:~/OMERO.server$ ldapsearch -H ldaps://ldap.csc.univie.ac.at:636 -x -b "dc=csc,dc=univie,dc=ac,dc=at" (objectClass=inetOrgPerson)
...SNIP...
# axel, People, csc.univie.ac.at
dn: uid=axel,ou=People,dc=csc,dc=univie,dc=ac,dc=at
cn: Axel Kittenberger
gidNumber: 707
givenName: Axel
homeDirectory: /csc/axel
objectClass: top
objectClass: posixAccount
objectClass: inetOrgPerson
objectClass: sambaSamAccount
sn: Kittenberger
uid: axel
uidNumber: 10807
loginShell: /bin/bash
displayName: Axel Kittenberger
sambaPasswordHistory: 00000000000000000000000000000000000000000000000000000000
00000000
sambaAcctFlags: [U          ]
sambaSID: S-1-5-21-XXX
sambaPrimaryGroupSID: S-1-5-21-XXX
sambaNTPassword: XXX
sambaPwdLastSet: 1425465343

...SNIP...


I have no idea what fails, trust relationship to the ssl server? ssl server even reachable, cannot find user? etc. I don't see any helpful log? I went straight to ldaps SSL, since I disabled plain ldap on our server long ago and I don't want to fiddle with it to get omero running...

PS: I do not store emails from users. Might this be an issue? Since out of some strange reason Omero requires Firstname/Lastname/Email as absolutely mandatory?

PPS: *I got some issue at first since I disabled IPv6 in the kernel. I usually do this on all servers here, since it wont get out of the router anyway and had some strange effects when some tools tried to go IPv6. However omero had some strange error messages regarding IPv6 and wouldn't start. Once I allowed the kernel again to have it, it started up fine.
axkibe
 
Posts: 19
Joined: Wed Mar 04, 2015 10:12 am

Re: debugging ldap

Postby jmoore » Wed Mar 04, 2015 1:54 pm

Hi Axel,

axkibe wrote:However, after having done things to the book, at least I believe so, what options do I have to debug why it does not work? I don't see anything SSL or LDAP related in OMERO.server/var/log.


You can certainly start by adding a line to etc/logback.xml:
Code: Select all
  <logger name="ome.security" level="DEBUG"/>


and see if you get anything useful. (A restart is not necessary; just wait ~1 minute before retrying). You might also send us Blitz-0.log as well as master.err after trying with the new setting. Your diagnostics, config, and local search certainly look sensible as well as consistent.


I have no idea what fails, trust relationship to the ssl server? ssl server even reachable, cannot find user? etc. I don't see any helpful log? I went straight to ldaps SSL, since I disabled plain ldap on our server long ago and I don't want to fiddle with it to get omero running...


No problem. I assume the test you tried is to login as "axel" with this LDAP configuration?

PS: I do not store emails from users. Might this be an issue? Since out of some strange reason Omero requires Firstname/Lastname/Email as absolutely mandatory?


No, that's mostly a UI demand. The database can accept null emails without a problem.

PPS: *I got some issue at first since I disabled IPv6 in the kernel. I usually do this on all servers here, since it wont get out of the router anyway and had some strange effects when some tools tried to go IPv6. However omero had some strange error messages regarding IPv6 and wouldn't start. Once I allowed the kernel again to have it, it started up fine.


I don't know if this would be related to LDAP. But just regarding OMERO+IPv6: did you see https://www.openmicroscopy.org/site/support/omero5.0/sysadmins/config.html#ice ?

Cheers,
~Josh.
User avatar
jmoore
Site Admin
 
Posts: 1591
Joined: Fri May 22, 2009 1:29 pm
Location: Germany

Re: debugging ldap

Postby axkibe » Wed Mar 04, 2015 2:23 pm

Yes thank you. User axel is the one I know the password of :)

To get as clean as possible log, I stopped the server, added the debug line, moved all contens of var/log away and restarted it. Then I tried to log in as axel.

Code: Select all
omero@omero:~/OMERO.server$ cat var/log/Blitz-0.log
2015-03-04 15:16:49,535 INFO  [                ome.services.blitz.Entry] (      main) Creating OMERO.blitz. Please wait...
2015-03-04 15:16:51,931 INFO  [.s.ShutdownSafeEhcacheManagerFactoryBean] (      main) Initializing EHCache CacheManager
2015-03-04 15:16:52,386 INFO  [          ome.services.util.DBPatchCheck] (      main) Verified database patch: OMERO5.0__0
2015-03-04 15:16:52,428 INFO  [           ome.services.util.DBUserCheck] (      main) User root.id = 0
2015-03-04 15:16:52,430 INFO  [           ome.services.util.DBUserCheck] (      main) User guest.id = 1
2015-03-04 15:16:52,430 INFO  [           ome.services.util.DBUserCheck] (      main) Group system.id = 0
2015-03-04 15:16:52,430 INFO  [           ome.services.util.DBUserCheck] (      main) Group user.id = 1
2015-03-04 15:16:52,430 INFO  [           ome.services.util.DBUserCheck] (      main) Group guest.id = 2
2015-03-04 15:16:56,562 INFO  [  ome.services.fulltext.FullTextAnalyzer] (      main) Initialized FullTextAnalyzer
2015-03-04 15:17:10,550 INFO  [        ome.services.db.DatabaseIdentity] (      main) Using LSID format: urn:lsid:export.openmicroscopy.org:%s:e9a76670-c147-445f-9f6c-b2b0b6520c1b_%s%s
2015-03-04 15:17:18,256 INFO  [                 org.perf4j.TimingLogger] (      main) start[1425478631077] time[7179] tag[ome.io.nio.SimpleBackOff.256X256]
2015-03-04 15:17:18,954 INFO  [                 org.perf4j.TimingLogger] (      main) start[1425478638258] time[696] tag[ome.io.nio.SimpleBackOff.256X256]
2015-03-04 15:17:19,738 INFO  [                 org.perf4j.TimingLogger] (      main) start[1425478638955] time[782] tag[ome.io.nio.SimpleBackOff.256X256]
2015-03-04 15:17:20,071 INFO  [                 org.perf4j.TimingLogger] (      main) start[1425478639738] time[333] tag[ome.io.nio.SimpleBackOff.256X256]
2015-03-04 15:17:21,163 INFO  [                 org.perf4j.TimingLogger] (      main) start[1425478640071] time[1091] tag[ome.io.nio.SimpleBackOff.256X256]
2015-03-04 15:17:21,305 INFO  [                 org.perf4j.TimingLogger] (      main) start[1425478641163] time[141] tag[ome.io.nio.SimpleBackOff.256X256]
2015-03-04 15:17:21,472 INFO  [                 org.perf4j.TimingLogger] (      main) start[1425478641307] time[164] tag[ome.io.nio.SimpleBackOff.256X256]
2015-03-04 15:17:21,661 INFO  [                 org.perf4j.TimingLogger] (      main) start[1425478641472] time[188] tag[ome.io.nio.SimpleBackOff.256X256]
2015-03-04 15:17:21,953 INFO  [                 org.perf4j.TimingLogger] (      main) start[1425478641661] time[291] tag[ome.io.nio.SimpleBackOff.256X256]
2015-03-04 15:17:22,180 INFO  [                 org.perf4j.TimingLogger] (      main) start[1425478641953] time[226] tag[ome.io.nio.SimpleBackOff.256X256]
2015-03-04 15:17:22,470 INFO  [                 org.perf4j.TimingLogger] (      main) start[1425478642181] time[289] tag[ome.io.nio.SimpleBackOff.256X256]
2015-03-04 15:17:23,206 INFO  [                 org.perf4j.TimingLogger] (      main) start[1425478642470] time[735] tag[ome.io.nio.SimpleBackOff.256X256]
2015-03-04 15:17:23,364 INFO  [                 org.perf4j.TimingLogger] (      main) start[1425478643206] time[158] tag[ome.io.nio.SimpleBackOff.256X256]
2015-03-04 15:17:23,523 INFO  [                 org.perf4j.TimingLogger] (      main) start[1425478643365] time[158] tag[ome.io.nio.SimpleBackOff.256X256]
2015-03-04 15:17:23,698 INFO  [                 org.perf4j.TimingLogger] (      main) start[1425478643523] time[174] tag[ome.io.nio.SimpleBackOff.256X256]
2015-03-04 15:17:23,881 INFO  [                 org.perf4j.TimingLogger] (      main) start[1425478643698] time[183] tag[ome.io.nio.SimpleBackOff.256X256]
2015-03-04 15:17:24,048 INFO  [                 org.perf4j.TimingLogger] (      main) start[1425478643882] time[166] tag[ome.io.nio.SimpleBackOff.256X256]
2015-03-04 15:17:24,215 INFO  [                 org.perf4j.TimingLogger] (      main) start[1425478644048] time[166] tag[ome.io.nio.SimpleBackOff.256X256]
2015-03-04 15:17:26,132 INFO  [                 org.perf4j.TimingLogger] (      main) start[1425478644215] time[1916] tag[ome.io.nio.SimpleBackOff.256X256]
2015-03-04 15:17:26,307 INFO  [                 org.perf4j.TimingLogger] (      main) start[1425478646132] time[174] tag[ome.io.nio.SimpleBackOff.256X256]
2015-03-04 15:17:26,339 INFO  [                ome.io.nio.PixelsService] (      main) Using Bio-Formats Cache: /omero/BioFormatsCache
2015-03-04 15:17:26,340 INFO  [                ome.io.nio.PixelsService] (      main) PixelsService(path=/omero, resolver=ome.services.OmeroFilePathResolver@2579946b, backoff=ome.io.nio.SimpleBackOff(factor=411.9), sizes=ome.io.nio.ConfiguredTileSizes(w=256,h=256,W=3192,H=3192))
2015-03-04 15:17:27,495 INFO  [    ome.services.fulltext.FullTextThread] (      main) Initializing Full-Text Indexer
2015-03-04 15:17:27,569 INFO  [  ome.services.pixeldata.PixelDataThread] (      main) Initializing PixelDataThread (create events only)
2015-03-04 15:17:27,592 INFO  [      ome.services.util.JvmSettingsCheck] (      main) Java version: 1.7.0_75; Linux; amd64; 3.16.0-4-amd64
2015-03-04 15:17:27,592 INFO  [      ome.services.util.JvmSettingsCheck] (      main) Max Memory (MB):   =    603
2015-03-04 15:17:27,592 INFO  [      ome.services.util.JvmSettingsCheck] (      main) OS Memory (MB):    =   3963
2015-03-04 15:17:27,592 INFO  [      ome.services.util.JvmSettingsCheck] (      main) Processors:        =      1
2015-03-04 15:17:28,310 INFO  [    ome.services.util.ServerVersionCheck] (      main) -------------------------------------------------
2015-03-04 15:17:28,311 INFO  [    ome.services.util.ServerVersionCheck] (      main) OMERO Version: 5.0.8-ice35-b60 Ready.
2015-03-04 15:17:28,311 INFO  [    ome.services.util.ServerVersionCheck] (      main) -------------------------------------------------
2015-03-04 15:17:28,630 INFO  [                 ome.system.UpgradeCheck] (      main) no update needed
2015-03-04 15:17:28,649 INFO  [    ome.tools.hibernate.ExtendedMetadata] (      main) Calculating ExtendedMetadata...
2015-03-04 15:17:29,579 INFO  [      o.s.scheduler.SchedulerFactoryBean] (      main) Starting Quartz Scheduler now
2015-03-04 15:17:29,614 INFO  [        ome.services.util.ServiceHandler] (      main)  Executor.doWork -- ome.services.util.NamespaceCheck.namespaceCheck
2015-03-04 15:17:29,614 INFO  [        ome.services.util.ServiceHandler] (      main)  Args:   [null, InternalSF@2137849956]
2015-03-04 15:17:30,627 INFO  [         ome.security.basic.EventHandler] (      main)  Auth:   user=0,group=0,event=1651(Internal),sess=18103857-440b-4c01-a8ab-a4062b190164
2015-03-04 15:17:30,926 INFO  [                 org.perf4j.TimingLogger] (      main) start[1425478649614] time[1311] tag[omero.call.success.ome.services.util.NamespaceCheck$1.doWork]
2015-03-04 15:17:30,926 INFO  [        ome.services.util.ServiceHandler] (      main)  Rslt:   null
2015-03-04 15:17:34,793 INFO  [o.services.blitz.util.BlitzConfiguration] (      main) Initializing Ice.Communicator
2015-03-04 15:17:35,528 INFO  [            ome.services.blitz.fire.Ring] (      main) Checking cluster
2015-03-04 15:17:35,630 INFO  [        ome.services.blitz.fire.Registry] (      main) Found 0 cluster node(s) : []
2015-03-04 15:17:35,631 INFO  [            ome.services.blitz.fire.Ring] (      main) Got 0 cluster uuids : []
2015-03-04 15:17:35,632 INFO  [        ome.services.util.ServiceHandler] (      main)  Executor.doWork -- ome.services.blitz.fire.Ring.getManagerList
2015-03-04 15:17:35,632 INFO  [        ome.services.util.ServiceHandler] (      main)  Args:   [null, InternalSF@2137849956]
2015-03-04 15:17:35,675 INFO  [         ome.security.basic.EventHandler] (      main)  Auth:   user=0,group=0,event=null(Internal),sess=18103857-440b-4c01-a8ab-a4062b190164
2015-03-04 15:17:35,818 INFO  [                 org.perf4j.TimingLogger] (      main) start[1425478655632] time[186] tag[omero.call.success.ome.services.blitz.fire.Ring$2.doWork]
2015-03-04 15:17:35,819 INFO  [        ome.services.util.ServiceHandler] (      main)  Rslt:   (da3bbd5d-aef4-4a7d-9e2d-8756163225b8)
2015-03-04 15:17:35,819 INFO  [            ome.services.blitz.fire.Ring] (      main) Purging node: da3bbd5d-aef4-4a7d-9e2d-8756163225b8
2015-03-04 15:17:36,302 INFO  [        ome.services.util.ServiceHandler] (      main)  Executor.doWork -- ome.services.blitz.fire.Ring.executeUpdate - set closed = now()
2015-03-04 15:17:36,310 INFO  [        ome.services.util.ServiceHandler] (      main)  Args:   [null, InternalSF@2137849956]
2015-03-04 15:17:36,462 INFO  [         ome.security.basic.EventHandler] (      main)  Auth:   user=0,group=0,event=1652(Internal),sess=18103857-440b-4c01-a8ab-a4062b190164
2015-03-04 15:17:36,553 INFO  [                 org.perf4j.TimingLogger] (      main) start[1425478656310] time[242] tag[omero.call.success.ome.services.blitz.fire.Ring$3.doWork]
2015-03-04 15:17:36,554 INFO  [        ome.services.util.ServiceHandler] (      main)  Rslt:   0
2015-03-04 15:17:36,554 INFO  [            ome.services.blitz.fire.Ring] (      main) Removed 0 entries with value da3bbd5d-aef4-4a7d-9e2d-8756163225b8
2015-03-04 15:17:36,555 INFO  [        ome.services.util.ServiceHandler] (      main)  Executor.doWork -- ome.services.blitz.fire.Ring.setManagerDown
2015-03-04 15:17:36,555 INFO  [        ome.services.util.ServiceHandler] (      main)  Args:   [null, InternalSF@2137849956]
2015-03-04 15:17:36,670 INFO  [         ome.security.basic.EventHandler] (      main)  Auth:   user=0,group=0,event=1653(Internal),sess=18103857-440b-4c01-a8ab-a4062b190164
2015-03-04 15:17:36,719 INFO  [                 org.perf4j.TimingLogger] (      main) start[1425478656555] time[163] tag[omero.call.success.ome.services.blitz.fire.Ring$4.doWork]
2015-03-04 15:17:36,719 INFO  [        ome.services.util.ServiceHandler] (      main)  Rslt:   1
2015-03-04 15:17:36,719 INFO  [            ome.services.blitz.fire.Ring] (      main) Removed manager: da3bbd5d-aef4-4a7d-9e2d-8756163225b8
2015-03-04 15:17:36,720 INFO  [            ome.services.blitz.fire.Ring] (      main) handleRingShutdown: da3bbd5d-aef4-4a7d-9e2d-8756163225b8
2015-03-04 15:17:36,721 INFO  [        ome.services.util.ServiceHandler] (      main)  Executor.doWork -- ome.services.blitz.fire.Ring.addManager
2015-03-04 15:17:36,721 INFO  [        ome.services.util.ServiceHandler] (      main)  Args:   [null, InternalSF@2137849956]
2015-03-04 15:17:36,894 INFO  [         ome.security.basic.EventHandler] (      main)  Auth:   user=0,group=0,event=1654(Internal),sess=18103857-440b-4c01-a8ab-a4062b190164
2015-03-04 15:17:36,938 INFO  [       ome.security.basic.CurrentDetails] (      main) Adding log:INSERT,class ome.model.meta.Node,501
2015-03-04 15:17:37,025 INFO  [                 org.perf4j.TimingLogger] (      main) start[1425478656721] time[304] tag[omero.call.success.ome.services.blitz.fire.Ring$5.doWork]
2015-03-04 15:17:37,025 INFO  [        ome.services.util.ServiceHandler] (      main)  Rslt:   ome.model.meta.Node:Id_501
2015-03-04 15:17:37,046 INFO  [        ome.services.blitz.fire.Registry] (      main) Added ClusterNode/18103857-440b-4c01-a8ab-a4062b190164 to registry
2015-03-04 15:17:39,899 INFO  [        ome.services.util.ServiceHandler] (l.Server-1)  Executor.doWork -- ome.services.sessions.SessionManagerImpl.createSession
2015-03-04 15:17:39,899 INFO  [        ome.services.util.ServiceHandler] (l.Server-1)  Args:   [null, InternalSF@2137849956]
2015-03-04 15:17:39,947 INFO  [    ome.security.basic.BasicEventContext] (l.Server-1)  cctx:   group=0
2015-03-04 15:17:40,036 INFO  [         ome.security.basic.EventHandler] (l.Server-1)  Auth:   user=0,group=0,event=1655(Sessions),sess=18103857-440b-4c01-a8ab-a4062b190164
2015-03-04 15:17:40,431 INFO  [      o.s.blitz.repo.AbstractRepositoryI] (      main) Initializing repository in /omero
2015-03-04 15:17:40,442 INFO  [       ome.security.basic.CurrentDetails] (l.Server-1) Adding log:INSERT,class ome.model.meta.Session,1575
2015-03-04 15:17:40,717 INFO  [o.services.blitz.repo.ManagedRepositoryI] (      main) Repository template: %user%_%userId%//%year%-%month%/%day%/%time%
2015-03-04 15:17:40,749 INFO  [      o.s.blitz.repo.AbstractRepositoryI] (      main) Initializing repository in /omero/ManagedRepository
2015-03-04 15:17:40,818 INFO  [                 org.perf4j.TimingLogger] (l.Server-1) start[1425478659899] time[918] tag[omero.call.success.ome.services.sessions.SessionManagerImpl$2.doWork]
2015-03-04 15:17:40,818 INFO  [        ome.services.util.ServiceHandler] (l.Server-1)  Rslt:   (ome.model.meta.Experimenter:Id_0, ome.model.meta.ExperimenterGroup:Id_0, (0, 1), ... 4 more)
2015-03-04 15:17:40,851 INFO  [      o.s.blitz.repo.AbstractRepositoryI] (      main) Initializing repository in /home/omero/OMERO.server-5.0.8-ice35-b60/./lib/scripts
2015-03-04 15:17:40,992 INFO  [ ome.services.blitz.fire.SessionManagerI] (l.Server-1) Created session ServiceFactoryI(session-f60966ca-db26-4c53-9764-830375a172ec/96fa0257-b253-4fd4-b58a-12dc95160a4f) for user root (agent=Python service)
2015-03-04 15:17:41,185 INFO  [                      omero.cmd.SessionI] (l.Server-7) Added servant to adapter: 96fa0257-b253-4fd4-b58a-12dc95160a4f/f60966ca-db26-4c53-9764-830375a172ecomero.api.IConfig(omero.api._IConfigTie@d0193eb1)
2015-03-04 15:17:41,288 INFO  [        ome.services.util.ServiceHandler] (2-thread-3)  Executor.doWork -- ome.services.blitz.repo.LegacyRepositoryI.takeover
2015-03-04 15:17:41,288 INFO  [        ome.services.util.ServiceHandler] (2-thread-3)  Args:   [null, InternalSF@2137849956]
2015-03-04 15:17:41,290 INFO  [        ome.services.util.ServiceHandler] (2-thread-4)  Executor.doWork -- ome.services.blitz.repo.ScriptRepositoryI.takeover
2015-03-04 15:17:41,290 INFO  [        ome.services.util.ServiceHandler] (2-thread-4)  Args:   [null, InternalSF@2137849956]
2015-03-04 15:17:41,291 INFO  [        ome.services.util.ServiceHandler] (2-thread-2)  Executor.doWork -- ome.services.blitz.repo.LegacyRepositoryI.takeover
2015-03-04 15:17:41,291 INFO  [        ome.services.util.ServiceHandler] (2-thread-2)  Args:   [null, InternalSF@2137849956]
2015-03-04 15:17:41,305 INFO  [        ome.services.util.ServiceHandler] (l.Server-2)  Meth:   interface ome.api.IConfig.getConfigValue
2015-03-04 15:17:41,305 INFO  [        ome.services.util.ServiceHandler] (l.Server-2)  Args:   [omero.data.dir]
2015-03-04 15:17:41,486 INFO  [         ome.security.basic.EventHandler] (2-thread-3)  Auth:   user=0,group=0,event=1656(Internal),sess=18103857-440b-4c01-a8ab-a4062b190164
2015-03-04 15:17:41,509 INFO  [         ome.security.basic.EventHandler] (2-thread-4)  Auth:   user=0,group=0,event=1657(Internal),sess=18103857-440b-4c01-a8ab-a4062b190164
2015-03-04 15:17:41,517 INFO  [      o.s.blitz.repo.AbstractRepositoryI] (2-thread-3) Opened repository ManagedRepository (uuid=18a05e16-cbd4-4ec8-a352-400e2b08f905)
2015-03-04 15:17:41,541 INFO  [      o.s.blitz.repo.AbstractRepositoryI] (2-thread-4) Opened repository scripts (uuid=ScriptRepo)
2015-03-04 15:17:41,570 INFO  [         ome.security.basic.EventHandler] (2-thread-2)  Auth:   user=0,group=0,event=1659(Internal),sess=18103857-440b-4c01-a8ab-a4062b190164
2015-03-04 15:17:41,583 INFO  [         ome.security.basic.EventHandler] (l.Server-2)  Auth:   user=0,group=0,event=1658(User),sess=96fa0257-b253-4fd4-b58a-12dc95160a4f
2015-03-04 15:17:41,607 INFO  [      o.s.blitz.repo.AbstractRepositoryI] (2-thread-2) Opened repository omero (uuid=deddf59c-b526-40ce-a965-55d38703a3f8)
2015-03-04 15:17:41,612 INFO  [   ome.services.scripts.ScriptRepoHelper] (      main) Registering JythonScripts: WildcardFileFilter(*.jy)
2015-03-04 15:17:41,612 INFO  [   ome.services.scripts.ScriptRepoHelper] (      main) Registering PythonScripts: WildcardFileFilter(*.py)
2015-03-04 15:17:41,612 INFO  [   ome.services.scripts.ScriptRepoHelper] (      main) Registering MatlabScripts: WildcardFileFilter(*.m)
2015-03-04 15:17:41,614 INFO  [    ome.services.blitz.util.CheckAllJobs] (  Thread-8) Waiting 120 secs. for callbacks
2015-03-04 15:17:41,628 INFO  [                 org.perf4j.TimingLogger] (l.Server-2) start[1425478661305] time[322] tag[omero.call.success.ome.logic.ConfigImpl.getConfigValue]
2015-03-04 15:17:41,631 INFO  [        ome.services.util.ServiceHandler] (l.Server-2)  Rslt:   /omero
2015-03-04 15:17:41,632 INFO  [o.services.sessions.SessionContext$Count] (l.Server-3) -Reference count: 96fa0257-b253-4fd4-b58a-12dc95160a4f=0
2015-03-04 15:17:41,633 INFO  [                      omero.cmd.SessionI] (l.Server-3) doDestroy(ServiceFactoryI(session-f60966ca-db26-4c53-9764-830375a172ec/96fa0257-b253-4fd4-b58a-12dc95160a4f))
2015-03-04 15:17:41,633 INFO  [                      omero.cmd.SessionI] (l.Server-3) Unregistered servant:96fa0257-b253-4fd4-b58a-12dc95160a4f/f60966ca-db26-4c53-9764-830375a172ecomero.api.IConfig(omero.api._IConfigTie@d0193eb1)
2015-03-04 15:17:41,633 INFO  [                      omero.cmd.SessionI] (l.Server-3) Removed servant from adapter: f60966ca-db26-4c53-9764-830375a172ecomero.api.IConfig
2015-03-04 15:17:41,634 INFO  [ome.services.sessions.SessionManagerImpl] (l.Server-3) closeSession called and no more references: 96fa0257-b253-4fd4-b58a-12dc95160a4f
2015-03-04 15:17:41,634 INFO  [ome.services.sessions.state.SessionCache] (l.Server-3) Destroying session 96fa0257-b253-4fd4-b58a-12dc95160a4f due to : Remove session called
2015-03-04 15:17:41,634 INFO  [                 org.perf4j.TimingLogger] (l.Server-3) start[1425478660827] time[806] tag[omero.session]
2015-03-04 15:17:41,715 INFO  [        ome.services.util.ServiceHandler] (      main)  Executor.doWork -- ome.services.scripts.ScriptRepoHelper.loadAll(true)
2015-03-04 15:17:41,715 INFO  [        ome.services.util.ServiceHandler] (      main)  Args:   [null, InternalSF@2137849956]
2015-03-04 15:17:41,763 INFO  [        ome.services.blitz.fire.Registry] (2-thread-3) Updated InternalRepository-18a05e16-cbd4-4ec8-a352-400e2b08f905 in registry
2015-03-04 15:17:41,779 INFO  [        ome.services.blitz.fire.Registry] (2-thread-4) Updated InternalRepository-ScriptRepo in registry
2015-03-04 15:17:41,788 INFO  [        ome.services.blitz.fire.Registry] (2-thread-2) Updated InternalRepository-deddf59c-b526-40ce-a965-55d38703a3f8 in registry
2015-03-04 15:17:41,796 INFO  [        ome.services.blitz.fire.Registry] (2-thread-3) Updated PublicRepository-18a05e16-cbd4-4ec8-a352-400e2b08f905 in registry
2015-03-04 15:17:41,797 INFO  [      o.s.blitz.repo.AbstractRepositoryI] (2-thread-3) Repository now active
2015-03-04 15:17:41,813 INFO  [        ome.services.blitz.fire.Registry] (2-thread-4) Updated PublicRepository-ScriptRepo in registry
2015-03-04 15:17:41,826 INFO  [                 org.perf4j.TimingLogger] (2-thread-3) start[1425478661288] time[537] tag[omero.call.success.ome.services.blitz.repo.AbstractRepositoryI$GetOrCreateRepo.doWork]
2015-03-04 15:17:41,826 INFO  [        ome.services.util.ServiceHandler] (2-thread-3)  Rslt:   ome.model.core.OriginalFile:Id_1
2015-03-04 15:17:41,827 INFO  [        ome.services.util.ServiceHandler] (2-thread-3)  Executor.doWork -- ome.services.blitz.repo.LegacyRepositoryI.getDescription(1)
2015-03-04 15:17:41,828 INFO  [        ome.services.util.ServiceHandler] (2-thread-3)  Args:   [null, InternalSF@2137849956]
2015-03-04 15:17:41,830 INFO  [        ome.services.blitz.fire.Registry] (2-thread-2) Updated PublicRepository-deddf59c-b526-40ce-a965-55d38703a3f8 in registry
2015-03-04 15:17:41,830 INFO  [      o.s.blitz.repo.AbstractRepositoryI] (2-thread-4) Repository now active
2015-03-04 15:17:41,834 INFO  [      o.s.blitz.repo.AbstractRepositoryI] (2-thread-2) Repository now active
2015-03-04 15:17:41,851 INFO  [         ome.security.basic.EventHandler] (      main)  Auth:   user=0,group=0,event=1660(Internal),sess=18103857-440b-4c01-a8ab-a4062b190164
2015-03-04 15:17:41,856 INFO  [                 org.perf4j.TimingLogger] (2-thread-2) start[1425478661291] time[564] tag[omero.call.success.ome.services.blitz.repo.AbstractRepositoryI$GetOrCreateRepo.doWork]
2015-03-04 15:17:41,856 INFO  [        ome.services.util.ServiceHandler] (2-thread-2)  Rslt:   ome.model.core.OriginalFile:Id_3
2015-03-04 15:17:41,856 INFO  [        ome.services.util.ServiceHandler] (2-thread-2)  Executor.doWork -- ome.services.blitz.repo.LegacyRepositoryI.getDescription(3)
2015-03-04 15:17:41,857 INFO  [        ome.services.util.ServiceHandler] (2-thread-2)  Args:   [null, InternalSF@2137849956]
2015-03-04 15:17:41,863 INFO  [         ome.security.basic.EventHandler] (2-thread-3)  Auth:   user=0,group=0,event=null(Internal),sess=18103857-440b-4c01-a8ab-a4062b190164
2015-03-04 15:17:41,879 INFO  [         ome.security.basic.EventHandler] (2-thread-2)  Auth:   user=0,group=0,event=null(Internal),sess=18103857-440b-4c01-a8ab-a4062b190164
2015-03-04 15:17:41,883 INFO  [                 org.perf4j.TimingLogger] (2-thread-4) start[1425478661290] time[592] tag[omero.call.success.ome.services.blitz.repo.AbstractRepositoryI$GetOrCreateRepo.doWork]
2015-03-04 15:17:41,883 INFO  [        ome.services.util.ServiceHandler] (2-thread-4)  Rslt:   ome.model.core.OriginalFile:Id_2
2015-03-04 15:17:41,883 INFO  [        ome.services.util.ServiceHandler] (2-thread-4)  Executor.doWork -- ome.services.blitz.repo.ScriptRepositoryI.getDescription(2)
2015-03-04 15:17:41,883 INFO  [        ome.services.util.ServiceHandler] (2-thread-4)  Args:   [null, InternalSF@2137849956]
2015-03-04 15:17:41,885 INFO  [         ome.security.basic.EventHandler] (2-thread-4)  Auth:   user=0,group=0,event=null(Internal),sess=18103857-440b-4c01-a8ab-a4062b190164
2015-03-04 15:17:41,933 INFO  [                 org.perf4j.TimingLogger] (2-thread-3) start[1425478661828] time[105] tag[omero.call.success.ome.services.blitz.repo.AbstractRepositoryI$1.doWork]
2015-03-04 15:17:41,933 INFO  [        ome.services.util.ServiceHandler] (2-thread-3)  Rslt:   ome.model.core.OriginalFile:Id_1
2015-03-04 15:17:41,962 INFO  [                 org.perf4j.TimingLogger] (2-thread-4) start[1425478661884] time[78] tag[omero.call.success.ome.services.blitz.repo.AbstractRepositoryI$1.doWork]
2015-03-04 15:17:41,963 INFO  [        ome.services.util.ServiceHandler] (2-thread-4)  Rslt:   ome.model.core.OriginalFile:Id_2
2015-03-04 15:17:41,963 INFO  [                 org.perf4j.TimingLogger] (2-thread-2) start[1425478661857] time[106] tag[omero.call.success.ome.services.blitz.repo.AbstractRepositoryI$1.doWork]
2015-03-04 15:17:41,963 INFO  [        ome.services.util.ServiceHandler] (2-thread-2)  Rslt:   ome.model.core.OriginalFile:Id_3
2015-03-04 15:17:42,434 INFO  [                 org.perf4j.TimingLogger] (      main) start[1425478661715] time[719] tag[omero.call.success.ome.services.scripts.ScriptRepoHelper$5.doWork]
2015-03-04 15:17:42,435 INFO  [        ome.services.util.ServiceHandler] (      main)  Rslt:   (ome.model.core.OriginalFile:Id_4, ome.model.core.OriginalFile:Id_5, ome.model.core.OriginalFile:Id_6, ... 13 more)
2015-03-04 15:17:42,436 INFO  [                ome.services.blitz.Entry] (      main) OMERO.blitz now accepting connections.
2015-03-04 15:17:45,527 INFO  [        ome.services.util.ServiceHandler] (l.Server-0)  Executor.doWork -- ome.services.sessions.SessionManagerImpl.createSession
2015-03-04 15:17:45,527 INFO  [        ome.services.util.ServiceHandler] (l.Server-0)  Args:   [null, InternalSF@2137849956]
2015-03-04 15:17:45,529 INFO  [        ome.services.util.ServiceHandler] (l.Server-2)  Executor.doWork -- ome.services.sessions.SessionManagerImpl.createSession
2015-03-04 15:17:45,529 INFO  [        ome.services.util.ServiceHandler] (l.Server-2)  Args:   [null, InternalSF@2137849956]
2015-03-04 15:17:45,532 INFO  [    ome.security.basic.BasicEventContext] (l.Server-2)  cctx:   group=0
2015-03-04 15:17:45,535 INFO  [    ome.security.basic.BasicEventContext] (l.Server-0)  cctx:   group=0
2015-03-04 15:17:45,614 INFO  [         ome.security.basic.EventHandler] (l.Server-2)  Auth:   user=0,group=0,event=1662(Sessions),sess=18103857-440b-4c01-a8ab-a4062b190164
2015-03-04 15:17:45,617 INFO  [         ome.security.basic.EventHandler] (l.Server-0)  Auth:   user=0,group=0,event=1661(Sessions),sess=18103857-440b-4c01-a8ab-a4062b190164
2015-03-04 15:17:45,715 INFO  [       ome.security.basic.CurrentDetails] (l.Server-0) Adding log:INSERT,class ome.model.meta.Session,1576
2015-03-04 15:17:45,731 INFO  [       ome.security.basic.CurrentDetails] (l.Server-2) Adding log:INSERT,class ome.model.meta.Session,1577
2015-03-04 15:17:45,863 INFO  [                 org.perf4j.TimingLogger] (l.Server-0) start[1425478665527] time[335] tag[omero.call.success.ome.services.sessions.SessionManagerImpl$2.doWork]
2015-03-04 15:17:45,863 INFO  [        ome.services.util.ServiceHandler] (l.Server-0)  Rslt:   (ome.model.meta.Experimenter:Id_0, ome.model.meta.ExperimenterGroup:Id_0, (0, 1), ... 4 more)
2015-03-04 15:17:45,865 INFO  [ ome.services.blitz.fire.SessionManagerI] (l.Server-0) Created session ServiceFactoryI(session-916703b4-1a1d-4bb0-a51a-d845d466f871/740a9720-750d-4e4f-98c2-cfecd7e08bf4) for user root (agent=Python service)
2015-03-04 15:17:45,865 INFO  [                 org.perf4j.TimingLogger] (l.Server-2) start[1425478665529] time[335] tag[omero.call.success.ome.services.sessions.SessionManagerImpl$2.doWork]
2015-03-04 15:17:45,865 INFO  [        ome.services.util.ServiceHandler] (l.Server-2)  Rslt:   (ome.model.meta.Experimenter:Id_0, ome.model.meta.ExperimenterGroup:Id_0, (0, 1), ... 4 more)
2015-03-04 15:17:45,866 INFO  [ ome.services.blitz.fire.SessionManagerI] (l.Server-2) Created session ServiceFactoryI(session-d794ba6a-c496-433c-99da-9231cd378857/90632ed3-ea2d-4b46-9352-721381931e01) for user root (agent=Python service)
2015-03-04 15:17:45,898 INFO  [                      omero.cmd.SessionI] (l.Server-4) Added servant to adapter: 90632ed3-ea2d-4b46-9352-721381931e01/d794ba6a-c496-433c-99da-9231cd378857omero.api.IConfig(omero.api._IConfigTie@ee8b44ad)
2015-03-04 15:17:45,900 INFO  [        ome.services.util.ServiceHandler] (l.Server-7)  Meth:   interface ome.api.IConfig.getConfigValue
2015-03-04 15:17:45,900 INFO  [        ome.services.util.ServiceHandler] (l.Server-7)  Args:   [omero.data.dir]
2015-03-04 15:17:45,997 INFO  [                      omero.cmd.SessionI] (l.Server-9) Added servant to adapter: 740a9720-750d-4e4f-98c2-cfecd7e08bf4/916703b4-1a1d-4bb0-a51a-d845d466f871omero.grid.SharedResources(omero.grid._SharedResourcesTie@28192a18)
2015-03-04 15:17:46,003 INFO  [         ome.security.basic.EventHandler] (l.Server-7)  Auth:   user=0,group=0,event=1663(User),sess=90632ed3-ea2d-4b46-9352-721381931e01
2015-03-04 15:17:46,038 INFO  [                 org.perf4j.TimingLogger] (l.Server-7) start[1425478665900] time[137] tag[omero.call.success.ome.logic.ConfigImpl.getConfigValue]
2015-03-04 15:17:46,038 INFO  [        ome.services.util.ServiceHandler] (l.Server-7)  Rslt:   /omero
2015-03-04 15:17:46,041 INFO  [        ome.services.util.ServiceHandler] (l.Server-3)  Meth:   interface ome.api.IConfig.getDatabaseUuid
2015-03-04 15:17:46,041 INFO  [        ome.services.util.ServiceHandler] (l.Server-3)  Args:   ()
2015-03-04 15:17:46,127 INFO  [         ome.security.basic.EventHandler] (l.Server-3)  Auth:   user=0,group=0,event=1664(User),sess=90632ed3-ea2d-4b46-9352-721381931e01
2015-03-04 15:17:46,175 INFO  [                 org.perf4j.TimingLogger] (l.Server-3) start[1425478666041] time[134] tag[omero.call.success.ome.logic.ConfigImpl.getDatabaseUuid]
2015-03-04 15:17:46,175 INFO  [        ome.services.util.ServiceHandler] (l.Server-3)  Rslt:   e9a76670-c147-445f-9f6c-b2b0b6520c1b
2015-03-04 15:17:46,274 INFO  [                      omero.cmd.SessionI] (l.Server-8) Added servant to adapter: 90632ed3-ea2d-4b46-9352-721381931e01/d794ba6a-c496-433c-99da-9231cd378857omero.api.IQuery(omero.api._IQueryTie@449d385c)
2015-03-04 15:17:46,394 INFO  [        ome.services.util.ServiceHandler] (l.Server-0)  Meth:   interface ome.api.IQuery.findByQuery
2015-03-04 15:17:46,394 INFO  [        ome.services.util.ServiceHandler] (l.Server-0)  Args:   [select f from OriginalFile f where hash = :uuid, PARAMS:uuid=deddf59c-b526-40ce-a965-55d38703a3f8 ]
2015-03-04 15:17:46,415 INFO  [         ome.security.basic.EventHandler] (l.Server-0)  Auth:   user=0,group=0,event=null(User),sess=90632ed3-ea2d-4b46-9352-721381931e01
2015-03-04 15:17:46,475 INFO  [                 org.perf4j.TimingLogger] (l.Server-0) start[1425478666394] time[80] tag[omero.call.success.ome.logic.QueryImpl.findByQuery]
2015-03-04 15:17:46,477 INFO  [        ome.services.util.ServiceHandler] (l.Server-0)  Rslt:   ome.model.core.OriginalFile:Id_3
2015-03-04 15:18:00,038 INFO  [ ome.services.blitz.fire.SessionManagerI] (2-thread-5) Performing requestHeartbeats
2015-03-04 15:19:00,656 INFO  [        ome.services.util.ServiceHandler] (l.Server-4)  Executor.doWork -- ome.services.sessions.SessionManagerImpl.executeCheckPasswordRO(guest)
2015-03-04 15:19:00,682 INFO  [        ome.services.util.ServiceHandler] (l.Server-4)  Args:   [null, InternalSF@2137849956]
2015-03-04 15:19:00,687 INFO  [         ome.security.basic.EventHandler] (l.Server-4)  Auth:   user=0,group=0,event=null(Sessions),sess=18103857-440b-4c01-a8ab-a4062b190164
2015-03-04 15:19:00,693 INFO  [                 org.perf4j.TimingLogger] (l.Server-4) start[1425478740682] time[10] tag[omero.call.success.ome.services.sessions.SessionManagerImpl$8.doWork]
2015-03-04 15:19:00,693 INFO  [        ome.services.util.ServiceHandler] (l.Server-4)  Rslt:   true
2015-03-04 15:19:00,695 INFO  [        ome.services.util.ServiceHandler] (l.Server-1)  Executor.doWork -- ome.services.sessions.SessionManagerImpl.createSession
2015-03-04 15:19:00,695 INFO  [        ome.services.util.ServiceHandler] (l.Server-1)  Args:   [null, InternalSF@2137849956]
2015-03-04 15:19:00,697 INFO  [    ome.security.basic.BasicEventContext] (l.Server-1)  cctx:   group=0
2015-03-04 15:19:00,721 INFO  [         ome.security.basic.EventHandler] (l.Server-1)  Auth:   user=0,group=0,event=1665(Sessions),sess=18103857-440b-4c01-a8ab-a4062b190164
2015-03-04 15:19:00,755 INFO  [       ome.security.basic.CurrentDetails] (l.Server-1) Adding log:INSERT,class ome.model.meta.Session,1578
2015-03-04 15:19:00,819 INFO  [                 org.perf4j.TimingLogger] (l.Server-1) start[1425478740695] time[123] tag[omero.call.success.ome.services.sessions.SessionManagerImpl$2.doWork]
2015-03-04 15:19:00,819 INFO  [        ome.services.util.ServiceHandler] (l.Server-1)  Rslt:   (ome.model.meta.Experimenter:Id_1, ome.model.meta.ExperimenterGroup:Id_2, (2), ... 4 more)
2015-03-04 15:19:00,833 INFO  [ ome.services.blitz.fire.SessionManagerI] (l.Server-1) Created session ServiceFactoryI(session-d413b3a8-390c-4587-ae71-93df7800ead2/cc2ee420-96b1-4339-9272-4cdfc3522975) for user guest (agent=OMERO.web)
2015-03-04 15:19:00,887 INFO  [                      omero.cmd.SessionI] (l.Server-3) Added servant to adapter: cc2ee420-96b1-4339-9272-4cdfc3522975/d413b3a8-390c-4587-ae71-93df7800ead2omero.api.ISession(omero.api._ISessionTie@d11251f1)
2015-03-04 15:19:00,908 INFO  [        ome.services.util.ServiceHandler] (l.Server-4)  Meth:   interface ome.api.ISession.getSession
2015-03-04 15:19:00,908 INFO  [        ome.services.util.ServiceHandler] (l.Server-4)  Args:   [cc2ee420-96b1-4339-9272-4cdfc3522975]
2015-03-04 15:19:00,909 INFO  [                 org.perf4j.TimingLogger] (l.Server-4) start[1425478740909] time[0] tag[omero.call.success.ome.services.sessions.SessionBean.getSession]
2015-03-04 15:19:00,909 INFO  [        ome.services.util.ServiceHandler] (l.Server-4)  Rslt:   ome.model.meta.Session:Id_1578
2015-03-04 15:19:00,931 INFO  [                      omero.cmd.SessionI] (l.Server-5) Added servant to adapter: cc2ee420-96b1-4339-9272-4cdfc3522975/d413b3a8-390c-4587-ae71-93df7800ead2omero.api.IConfig(omero.api._IConfigTie@de4a1f13)
2015-03-04 15:19:00,932 INFO  [        ome.services.util.ServiceHandler] (l.Server-9)  Meth:   interface ome.api.IConfig.getConfigValue
2015-03-04 15:19:00,933 INFO  [        ome.services.util.ServiceHandler] (l.Server-9)  Args:   [omero.router.insecure]
2015-03-04 15:19:00,955 INFO  [         ome.security.basic.EventHandler] (l.Server-9)  Auth:   user=1,group=2,event=1666(User),sess=cc2ee420-96b1-4339-9272-4cdfc3522975
2015-03-04 15:19:00,979 INFO  [                 org.perf4j.TimingLogger] (l.Server-9) start[1425478740933] time[46] tag[omero.call.success.ome.logic.ConfigImpl.getConfigValue]
2015-03-04 15:19:00,979 INFO  [        ome.services.util.ServiceHandler] (l.Server-9)  Rslt:   OMERO.Glacier2/router:tcp -p 4063 -h @omero.host@
2015-03-04 15:19:00,988 INFO  [ ome.services.blitz.fire.SessionManagerI] (l.Server-1) Found session locally: cc2ee420-96b1-4339-9272-4cdfc3522975
2015-03-04 15:19:00,990 INFO  [ ome.services.blitz.fire.SessionManagerI] (l.Server-1) Rejoining session ServiceFactoryI(session-df4bde88-27c4-4e8a-9434-ce61e64f2119/cc2ee420-96b1-4339-9272-4cdfc3522975) (agent=OMERO.web;secure=False)
2015-03-04 15:19:00,992 INFO  [o.services.sessions.SessionContext$Count] (l.Server-4) -Reference count: cc2ee420-96b1-4339-9272-4cdfc3522975=1
2015-03-04 15:19:00,992 INFO  [                      omero.cmd.SessionI] (l.Server-4) cleanupSelf(ServiceFactoryI(session-d413b3a8-390c-4587-ae71-93df7800ead2/cc2ee420-96b1-4339-9272-4cdfc3522975)).
2015-03-04 15:19:00,993 INFO  [                      omero.cmd.SessionI] (l.Server-4) Unregistered servant:cc2ee420-96b1-4339-9272-4cdfc3522975/d413b3a8-390c-4587-ae71-93df7800ead2omero.api.ISession(omero.api._ISessionTie@d11251f1)
2015-03-04 15:19:00,993 INFO  [                      omero.cmd.SessionI] (l.Server-4) Removed servant from adapter: d413b3a8-390c-4587-ae71-93df7800ead2omero.api.ISession
2015-03-04 15:19:00,993 INFO  [                      omero.cmd.SessionI] (l.Server-4) Unregistered servant:cc2ee420-96b1-4339-9272-4cdfc3522975/d413b3a8-390c-4587-ae71-93df7800ead2omero.api.IConfig(omero.api._IConfigTie@de4a1f13)
2015-03-04 15:19:00,993 INFO  [                      omero.cmd.SessionI] (l.Server-4) Removed servant from adapter: d413b3a8-390c-4587-ae71-93df7800ead2omero.api.IConfig
2015-03-04 15:19:01,000 INFO  [                      omero.cmd.SessionI] (l.Server-9) Added servant to adapter: cc2ee420-96b1-4339-9272-4cdfc3522975/df4bde88-27c4-4e8a-9434-ce61e64f2119omero.api.IConfig(omero.api._IConfigTie@d1d9ec56)
2015-03-04 15:19:01,007 INFO  [        ome.services.util.ServiceHandler] (l.Server-1)  Meth:   interface ome.api.IConfig.getConfigValue
2015-03-04 15:19:01,008 INFO  [        ome.services.util.ServiceHandler] (l.Server-1)  Args:   [omero.version]
2015-03-04 15:19:01,042 INFO  [         ome.security.basic.EventHandler] (l.Server-1)  Auth:   user=1,group=2,event=1667(User),sess=cc2ee420-96b1-4339-9272-4cdfc3522975
2015-03-04 15:19:01,054 INFO  [                 org.perf4j.TimingLogger] (l.Server-1) start[1425478741008] time[46] tag[omero.call.success.ome.logic.ConfigImpl.getConfigValue]
2015-03-04 15:19:01,054 INFO  [        ome.services.util.ServiceHandler] (l.Server-1)  Rslt:   5.0.8-ice35-b60
2015-03-04 15:19:01,073 INFO  [        ome.services.util.ServiceHandler] (l.Server-5)  Executor.doWork -- ome.services.sessions.SessionManagerImpl.executeCheckPasswordRO(axel)
2015-03-04 15:19:01,073 INFO  [        ome.services.util.ServiceHandler] (l.Server-5)  Args:   [null, InternalSF@2137849956]
2015-03-04 15:19:01,075 INFO  [         ome.security.basic.EventHandler] (l.Server-5)  Auth:   user=0,group=0,event=null(Sessions),sess=18103857-440b-4c01-a8ab-a4062b190164
2015-03-04 15:19:01,076 WARN  [                     ome.logic.AdminImpl] (l.Server-5) Password provider returned null: ome.security.auth.PasswordProviders@821b0ec
2015-03-04 15:19:01,077 INFO  [                 org.perf4j.TimingLogger] (l.Server-5) start[1425478741073] time[4] tag[omero.call.success.ome.services.sessions.SessionManagerImpl$8.doWork]
2015-03-04 15:19:01,078 INFO  [        ome.services.util.ServiceHandler] (l.Server-5)  Rslt:   false
2015-03-04 15:19:01,080 INFO  [        ome.services.util.ServiceHandler] (l.Server-5)  Executor.doWork -- java.lang.String.axel
2015-03-04 15:19:01,080 INFO  [        ome.services.util.ServiceHandler] (l.Server-5)  Args:   [null, InternalSF@2137849956]
2015-03-04 15:19:01,082 INFO  [         ome.security.basic.EventHandler] (l.Server-5)  Auth:   user=0,group=0,event=null(Internal),sess=18103857-440b-4c01-a8ab-a4062b190164
2015-03-04 15:19:01,087 INFO  [                 org.perf4j.TimingLogger] (l.Server-5) start[1425478741080] time[6] tag[omero.call.success.ome.services.blitz.fire.PermissionsVerifierI$1.doWork]
2015-03-04 15:19:01,087 INFO  [        ome.services.util.ServiceHandler] (l.Server-5)  Rslt:   null
2015-03-04 15:19:01,092 INFO  [        ome.services.util.ServiceHandler] (l.Server-4)  Executor.doWork -- ome.services.sessions.SessionManagerImpl.executeCheckPasswordRO(axel)
2015-03-04 15:19:01,092 INFO  [        ome.services.util.ServiceHandler] (l.Server-4)  Args:   [null, InternalSF@2137849956]
2015-03-04 15:19:01,095 INFO  [         ome.security.basic.EventHandler] (l.Server-4)  Auth:   user=0,group=0,event=null(Sessions),sess=18103857-440b-4c01-a8ab-a4062b190164
2015-03-04 15:19:01,095 WARN  [                     ome.logic.AdminImpl] (l.Server-4) Password provider returned null: ome.security.auth.PasswordProviders@821b0ec
2015-03-04 15:19:01,096 INFO  [                 org.perf4j.TimingLogger] (l.Server-4) start[1425478741093] time[3] tag[omero.call.success.ome.services.sessions.SessionManagerImpl$8.doWork]
2015-03-04 15:19:01,097 INFO  [        ome.services.util.ServiceHandler] (l.Server-4)  Rslt:   false
2015-03-04 15:19:01,106 INFO  [        ome.services.util.ServiceHandler] (l.Server-4)  Executor.doWork -- java.lang.String.axel
2015-03-04 15:19:01,106 INFO  [        ome.services.util.ServiceHandler] (l.Server-4)  Args:   [null, InternalSF@2137849956]
2015-03-04 15:19:01,112 INFO  [         ome.security.basic.EventHandler] (l.Server-4)  Auth:   user=0,group=0,event=null(Internal),sess=18103857-440b-4c01-a8ab-a4062b190164
2015-03-04 15:19:01,116 INFO  [                 org.perf4j.TimingLogger] (l.Server-4) start[1425478741107] time[9] tag[omero.call.success.ome.services.blitz.fire.PermissionsVerifierI$1.doWork]
2015-03-04 15:19:01,124 INFO  [        ome.services.util.ServiceHandler] (l.Server-4)  Rslt:   null
2015-03-04 15:19:01,140 INFO  [        ome.services.util.ServiceHandler] (l.Server-3)  Executor.doWork -- ome.services.sessions.SessionManagerImpl.executeCheckPasswordRO(guest)
2015-03-04 15:19:01,140 INFO  [        ome.services.util.ServiceHandler] (l.Server-3)  Args:   [null, InternalSF@2137849956]
2015-03-04 15:19:01,142 INFO  [         ome.security.basic.EventHandler] (l.Server-3)  Auth:   user=0,group=0,event=null(Sessions),sess=18103857-440b-4c01-a8ab-a4062b190164
2015-03-04 15:19:01,145 INFO  [                 org.perf4j.TimingLogger] (l.Server-3) start[1425478741140] time[4] tag[omero.call.success.ome.services.sessions.SessionManagerImpl$8.doWork]
2015-03-04 15:19:01,145 INFO  [        ome.services.util.ServiceHandler] (l.Server-3)  Rslt:   true
2015-03-04 15:19:01,146 INFO  [        ome.services.util.ServiceHandler] (l.Server-9)  Executor.doWork -- ome.services.sessions.SessionManagerImpl.createSession
2015-03-04 15:19:01,146 INFO  [        ome.services.util.ServiceHandler] (l.Server-9)  Args:   [null, InternalSF@2137849956]
2015-03-04 15:19:01,148 INFO  [    ome.security.basic.BasicEventContext] (l.Server-9)  cctx:   group=0
2015-03-04 15:19:01,161 INFO  [         ome.security.basic.EventHandler] (l.Server-9)  Auth:   user=0,group=0,event=1668(Sessions),sess=18103857-440b-4c01-a8ab-a4062b190164
2015-03-04 15:19:01,192 INFO  [       ome.security.basic.CurrentDetails] (l.Server-9) Adding log:INSERT,class ome.model.meta.Session,1579
2015-03-04 15:19:01,234 INFO  [                 org.perf4j.TimingLogger] (l.Server-9) start[1425478741146] time[87] tag[omero.call.success.ome.services.sessions.SessionManagerImpl$2.doWork]
2015-03-04 15:19:01,234 INFO  [        ome.services.util.ServiceHandler] (l.Server-9)  Rslt:   (ome.model.meta.Experimenter:Id_1, ome.model.meta.ExperimenterGroup:Id_2, (2), ... 4 more)
2015-03-04 15:19:01,236 INFO  [ ome.services.blitz.fire.SessionManagerI] (l.Server-9) Created session ServiceFactoryI(session-deadb7ab-0b70-4fd0-ab9b-e7729e23362b/4ce26c85-f970-4f3c-8ed1-71f1a31e63a7) for user guest (agent=OMERO.web)
2015-03-04 15:19:01,244 INFO  [                      omero.cmd.SessionI] (l.Server-1) Added servant to adapter: 4ce26c85-f970-4f3c-8ed1-71f1a31e63a7/deadb7ab-0b70-4fd0-ab9b-e7729e23362bomero.api.ISession(omero.api._ISessionTie@d5b361b)
2015-03-04 15:19:01,250 INFO  [        ome.services.util.ServiceHandler] (l.Server-3)  Meth:   interface ome.api.ISession.getSession
2015-03-04 15:19:01,250 INFO  [        ome.services.util.ServiceHandler] (l.Server-3)  Args:   [4ce26c85-f970-4f3c-8ed1-71f1a31e63a7]
2015-03-04 15:19:01,250 INFO  [                 org.perf4j.TimingLogger] (l.Server-3) start[1425478741250] time[0] tag[omero.call.success.ome.services.sessions.SessionBean.getSession]
2015-03-04 15:19:01,250 INFO  [        ome.services.util.ServiceHandler] (l.Server-3)  Rslt:   ome.model.meta.Session:Id_1579
2015-03-04 15:19:01,265 INFO  [                      omero.cmd.SessionI] (l.Server-5) Added servant to adapter: 4ce26c85-f970-4f3c-8ed1-71f1a31e63a7/deadb7ab-0b70-4fd0-ab9b-e7729e23362bomero.api.IConfig(omero.api._IConfigTie@2f18fe39)
2015-03-04 15:19:01,268 INFO  [        ome.services.util.ServiceHandler] (l.Server-9)  Meth:   interface ome.api.IConfig.getConfigValue
2015-03-04 15:19:01,268 INFO  [        ome.services.util.ServiceHandler] (l.Server-9)  Args:   [omero.version]
2015-03-04 15:19:01,285 INFO  [         ome.security.basic.EventHandler] (l.Server-9)  Auth:   user=1,group=2,event=1669(User),sess=4ce26c85-f970-4f3c-8ed1-71f1a31e63a7
2015-03-04 15:19:01,300 INFO  [                 org.perf4j.TimingLogger] (l.Server-9) start[1425478741268] time[32] tag[omero.call.success.ome.logic.ConfigImpl.getConfigValue]
2015-03-04 15:19:01,300 INFO  [        ome.services.util.ServiceHandler] (l.Server-9)  Rslt:   5.0.8-ice35-b60
2015-03-04 15:19:01,315 INFO  [        ome.services.util.ServiceHandler] (l.Server-1)  Executor.doWork -- ome.services.sessions.SessionManagerImpl.executeCheckPasswordRO(guest)
2015-03-04 15:19:01,315 INFO  [        ome.services.util.ServiceHandler] (l.Server-1)  Args:   [null, InternalSF@2137849956]
2015-03-04 15:19:01,317 INFO  [         ome.security.basic.EventHandler] (l.Server-1)  Auth:   user=0,group=0,event=null(Sessions),sess=18103857-440b-4c01-a8ab-a4062b190164
2015-03-04 15:19:01,565 INFO  [                 org.perf4j.TimingLogger] (l.Server-1) start[1425478741315] time[249] tag[omero.call.success.ome.services.sessions.SessionManagerImpl$8.doWork]
2015-03-04 15:19:01,566 INFO  [        ome.services.util.ServiceHandler] (l.Server-1)  Rslt:   true
2015-03-04 15:19:01,568 INFO  [        ome.services.util.ServiceHandler] (l.Server-4)  Executor.doWork -- ome.services.sessions.SessionManagerImpl.createSession
2015-03-04 15:19:01,568 INFO  [        ome.services.util.ServiceHandler] (l.Server-4)  Args:   [null, InternalSF@2137849956]
2015-03-04 15:19:01,580 INFO  [    ome.security.basic.BasicEventContext] (l.Server-4)  cctx:   group=0
2015-03-04 15:19:01,594 INFO  [         ome.security.basic.EventHandler] (l.Server-4)  Auth:   user=0,group=0,event=1670(Sessions),sess=18103857-440b-4c01-a8ab-a4062b190164
2015-03-04 15:19:01,608 INFO  [       ome.security.basic.CurrentDetails] (l.Server-4) Adding log:INSERT,class ome.model.meta.Session,1580
2015-03-04 15:19:01,662 INFO  [                 org.perf4j.TimingLogger] (l.Server-4) start[1425478741568] time[93] tag[omero.call.success.ome.services.sessions.SessionManagerImpl$2.doWork]
2015-03-04 15:19:01,663 INFO  [        ome.services.util.ServiceHandler] (l.Server-4)  Rslt:   (ome.model.meta.Experimenter:Id_1, ome.model.meta.ExperimenterGroup:Id_2, (2), ... 4 more)
2015-03-04 15:19:01,667 INFO  [ ome.services.blitz.fire.SessionManagerI] (l.Server-4) Created session ServiceFactoryI(session-1e70d7d8-a05d-4242-af04-3166348cd467/0fb49509-3586-4627-a0af-106b25f3e73f) for user guest (agent=OMERO.web)
2015-03-04 15:19:01,676 INFO  [                      omero.cmd.SessionI] (l.Server-3) Added servant to adapter: 0fb49509-3586-4627-a0af-106b25f3e73f/1e70d7d8-a05d-4242-af04-3166348cd467omero.api.ISession(omero.api._ISessionTie@47a7a166)
2015-03-04 15:19:01,677 INFO  [        ome.services.util.ServiceHandler] (l.Server-1)  Meth:   interface ome.api.ISession.getSession
2015-03-04 15:19:01,678 INFO  [        ome.services.util.ServiceHandler] (l.Server-1)  Args:   [0fb49509-3586-4627-a0af-106b25f3e73f]
2015-03-04 15:19:01,678 INFO  [                 org.perf4j.TimingLogger] (l.Server-1) start[1425478741678] time[0] tag[omero.call.success.ome.services.sessions.SessionBean.getSession]
2015-03-04 15:19:01,678 INFO  [        ome.services.util.ServiceHandler] (l.Server-1)  Rslt:   ome.model.meta.Session:Id_1580
2015-03-04 15:19:01,689 INFO  [                      omero.cmd.SessionI] (l.Server-5) Added servant to adapter: 0fb49509-3586-4627-a0af-106b25f3e73f/1e70d7d8-a05d-4242-af04-3166348cd467omero.api.IConfig(omero.api._IConfigTie@49dcb18b)
2015-03-04 15:19:01,690 INFO  [        ome.services.util.ServiceHandler] (l.Server-4)  Meth:   interface ome.api.IConfig.getConfigValue
2015-03-04 15:19:01,691 INFO  [        ome.services.util.ServiceHandler] (l.Server-4)  Args:   [omero.version]
2015-03-04 15:19:01,714 INFO  [         ome.security.basic.EventHandler] (l.Server-4)  Auth:   user=1,group=2,event=1671(User),sess=0fb49509-3586-4627-a0af-106b25f3e73f
2015-03-04 15:19:01,737 INFO  [                 org.perf4j.TimingLogger] (l.Server-4) start[1425478741691] time[46] tag[omero.call.success.ome.logic.ConfigImpl.getConfigValue]
2015-03-04 15:19:01,737 INFO  [        ome.services.util.ServiceHandler] (l.Server-4)  Rslt:   5.0.8-ice35-b60
2015-03-04 15:19:41,722 WARN  [    ome.services.blitz.util.CheckAllJobs] (  Thread-8) Forcibly closed 4 abandoned job(s).
omero@omero:~/OMERO.server$


master.err is empty
axkibe
 
Posts: 19
Joined: Wed Mar 04, 2015 10:12 am

Re: debugging ldap

Postby jmoore » Wed Mar 04, 2015 2:34 pm

Ah, that's what I get for not reading carefully enough. Your log really had *nothing* about LDAP in it, which made me go back to your config:
Code: Select all
omdero.ldap.base=dc=csc,dc=univie,dc=ac,dc=at
omdero.ldap.config=true


:)

~J.
User avatar
jmoore
Site Admin
 
Posts: 1591
Joined: Fri May 22, 2009 1:29 pm
Location: Germany

Re: debugging ldap

Postby axkibe » Wed Mar 04, 2015 2:36 pm

Ach, thank you!!!!

PS. I cannot delete "omero.ldap.user_mapping==" config key I accidently created. When I try to set it without value it complains about having an '=' sign in it.
axkibe
 
Posts: 19
Joined: Wed Mar 04, 2015 10:12 am

Re: debugging ldap

Postby jmoore » Wed Mar 04, 2015 2:37 pm

Code: Select all
bin/omero config set omdero.bad.key

(i.e. nothing after the key name) should do what you want.

~J.
User avatar
jmoore
Site Admin
 
Posts: 1591
Joined: Fri May 22, 2009 1:29 pm
Location: Germany

Re: debugging ldap

Postby axkibe » Wed Mar 04, 2015 2:46 pm

okay, LDAP works now.
axkibe
 
Posts: 19
Joined: Wed Mar 04, 2015 10:12 am

Re: debugging ldap

Postby axkibe » Wed Mar 04, 2015 2:47 pm

Code: Select all
omero@omero:~/OMERO.server$ bin/omero config set omero.ldap.user_mapping=
"=" in key name. Did you mean "...set omero.ldap.user_mapping "?


I did not mean without equal, I did create one key with an equals sign.
Not that this really matters. I just wondered.
axkibe
 
Posts: 19
Joined: Wed Mar 04, 2015 10:12 am

Re: debugging ldap

Postby jmoore » Wed Mar 04, 2015 3:03 pm

Interesting. Perhaps try bin/omero config edit?

Cheers,
~Josh.
User avatar
jmoore
Site Admin
 
Posts: 1591
Joined: Fri May 22, 2009 1:29 pm
Location: Germany

Re: debugging ldap

Postby axkibe » Wed Mar 04, 2015 3:12 pm

Code: Select all
bin/omero config set muh= kuh


does not complain, it creates the key with an equal sign. I suggest rejecting this as wll.

I will just leave these two now in there, they don't do any harm. I suppose.
axkibe
 
Posts: 19
Joined: Wed Mar 04, 2015 10:12 am

Next

Return to Installation and Deployment

Who is online

Users browsing this forum: No registered users and 1 guest