Grouper Users - Open Discussion List

[Tom Zeller <>]

I'll readily acknowledge a bug, but unfortunately there's not much to
work with, ldappc logging in 1.4 could use improvement :-)

Ldappc should print out something like :

INFO  DebugLog.info(64) -
[edu.internet2.middleware.ldappc.LdappcProvisionControl] *****
Starting Provisioning *****
DEBUG DebugLog.debug(88) -
[edu.internet2.middleware.ldappc.GrouperSubjectRetriever] Found
GrouperSystem
INFO  DebugLog.info(75) - Started GrouperSession:
7fb26d7ec8c248f187aaf90fbb72fd76,'GrouperSystem','application'
INFO  GroupEntrySynchronizer.<init>(162) - Group initial cache size = 100
DEBUG GroupEntrySynchronizer.clearRoot(1133) - search base
'ou=groups,dc=example,dc=edu' filter '(!(objectClass=groupOfNames))'
...

And you're not seeing "Group initial cache size" right ?

The line before that is essentially :

 Name rootDn = ldapCtx.getNameParser(LdapUtil.EMPTY_NAME).parse(rootDnStr);

Then a search is done on the base of the group tree.

Can you check your ldap server logs ? Maybe a connection (timeout) issue ?

TomZ

On Fri, Jul 17, 2009 at 2:58 PM, Paul 
Engle<>
 wrote:
> -----BEGIN PGP SIGNED MESSAGE-----
> Hash: SHA1
>
>
> All,
>  Since upgrading to 1.4.2, I'm having seemingly random
> failures of our main ldappc provisioning. The initial run goes
> fine, but then once it starts running the intervals, I can
> never predict how long it will go. Sometimes it runs for hours
> (interval is 15 minutes), sometimes it dies after just a few
> intervals. It rarely lasts more than a day, though.
>
> I have logging cranked up, but the debug log doesn't give any
> more than the following when it fails:
>
> 2009-07-16 22:49:43,520: [Timer-0] INFO  DebugLog.info(64)
> - -[edu.internet2.middleware.ldappc.LdappcProvisionControl]
> *****Starting Provisioning *****
> 2009-07-16 22:49:43,864: [Timer-0] DEBUG DebugLog.debug(88)
> - -[edu.internet2.middleware.ldappc.GrouperSubjectRetriever]
> Found GrouperSystem
> 2009-07-16 22:49:43,900: [Timer-0] INFO  DebugLog.info(75)
> - -Started GrouperSession:
> 326d5e437ead4c72b51e7b46d41831dc,'GrouperSystem','application'
> 2009-07-16 22:50:43,925: [Timer-0] INFO  DebugLog.info(75) -
> Stopped GrouperSession:
> 326d5e437ead4c72b51e7b46d41831dc,'GrouperSystem','application'
> 2009-07-16 22:50:43,924: [Timer-0] FATAL ErrorLog.fatal(122) -
> [edu.internet2.middleware.ldappc.LdappcGrouperProvisioner]
> Grouper Provision Failed: null
> 2009-07-16 22:50:43,925: [Timer-0] INFO  DebugLog.info(75) -
> Subject ID Lookups: 353390
> 2009-07-16 22:50:43,926: [Timer-0] INFO  DebugLog.info(75) -
> Subject Table Hits: 307329
> 2009-07-16 22:50:43,926: [Timer-0] INFO  DebugLog.info(75) -
> Subject hit ratio:  87.0%
>
> During successful intervals, the logs typically have
> GroupEntrySynchronizer messages between the Started & Stopped
> lines. Since I'm not seeing those when it fails, it seems like
> it may be something during the initialization of the interval
> run. The database isn't changing between the last success and
> the failure, so I don't think it's something in the data. Any
> pointers for what to look for would be great.
>
> In other news, the slowness I was seeing in initial
> provisioning runs is gone now. A combination of moving to 1.4.2
> & giving grouper a dedicated ldap server to talk to. Now the
> initial provisioning takes around 2 hours (down from 30+).
>
>  -paul
>
> - --
> Paul D. Engle              |  Rice University
> Sr. Systems Administrator  |  Information Technology - MS119
> (713)348-4702              |  PO Box 1892
> 
>             |  Houston, TX 77252-1892
> -----BEGIN PGP SIGNATURE-----
> Version: GnuPG v1.4.7 (MingW32)
>
> iD8DBQFKYNffCpkISWtyHNsRAtPxAJ9IvXi++U0Wm0bBzBh3Qk+7yvNxuQCgmmlA
> Ooso4JJhD2AeT9+9B6MgDBw=
> =GsqV
> -----END PGP SIGNATURE-----