Grouper Users - Open Discussion List

["Bryan E. Wooten" <>]

We are running 2.1.3 with Oracle 11g.

 

Here are 5 jstack traces. Jstack.startup.out is just gsh with %0 prompt up. The rest are after entering loaderRunOneJob("CHANGE_LOG_changeLogTempToChangeLog"). They were taken at 2-5 minute intervals.

 

I diffed them and the only difference is the date/time stamp. I guess that is a clue.

 

-Bryan

 

From: Chris Hyzer [mailto:]
Sent: Wednesday, May 08, 2013 7:10 PM
To: Bryan E. Wooten
Cc:
Subject: RE: Grouper Loader Cron Question

 

Can you tell me which version of grouper and which DB you are using, and can you analyze all your tables which helps improve performance.  If this doesn’t help, and you are running on unix, do a ps to get the process id, and do  jstack (in the bin dir of java), and get a stack of where things are held up.  Then wait a bit, and run it again.  Do this a few times and forward all the results to me J

 

Thanks,

Chris

 

From: Bryan E. Wooten []
Sent: Wednesday, May 08, 2013 4:38 PM
To: Chris Hyzer;
Subject: RE: Grouper Loader Cron Question

 

Sorry I didn’t get back to you sooner. After I sent the email I shut down the loader and wanted to try another test.

 

I started the gsh and ran loaderRunOneJob("CHANGE_LOG_changeLogTempToChangeLog"). After an hour it never returned.

 

So I looked at the change log tables in the DB and noted they had over 300k rows. So I deleted all of them.

 

I did some manual operations in the UI and now have about 11 rows. Yet when I run loaderRunOneJob("CHANGE_LOG_changeLogTempToChangeLog") it still never returns. I am not sure what I messed up.

 

The loader ldap groups I created have created about 50 or so groups with memberships ranging from a dozen to well over 100k. Many in the 30-40k range.

 

At this point I am at a loss. Afer running the loaderRunOneJob all I see in the log is this:

 

2013-05-08 14:28:13,439: [main] DEBUG LdapSourceAdapter.getLdapResultsHelper(620) -  - searchType: search filter: (&(cn=grouperTestStringOnStartupASDFGHJ)(objectclass=person))

2013-05-08 14:28:13,444: [main] DEBUG LdapSourceAdapter.searchHelper(434) -  - set has 0 subjects

2013-05-08 14:28:13,604: [main] INFO  EventLog.info(156) -  - [62131623ee6e424f8fc2e1c446a793d5,'GrouperSystem','application'] session: start (3ms)

2013-05-08 14:28:13,618: [main] INFO  EventLog.info(156) -  - [f5ddccf0c7ea479db3b6b0e4119a6dbb,'GrouperSystem','application'] session: start (3ms)

2013-05-08 14:28:13,625: [main] INFO  EventLog.info(156) -  - [5399a684e8a04a9f8ad404d477bbb7b2,'GrouperSystem','application'] session: start (3ms)

2013-05-08 14:28:13,655: [main] INFO  EventLog.info(156) -  - [5399a684e8a04a9f8ad404d477bbb7b2,'GrouperSystem','application'] add group type: 'grouperLoader' (22ms)

2013-05-08 14:28:38,324: [main] INFO  EventLog.info(156) -  - [4f66109b46f7479f8365a21fd99e05d7,'GrouperSystem','application'] session: start (15ms)

2013-05-08 14:28:38,434: [main] INFO  EhcacheController.getCache(192) -  - cache not configured explicitly: edu.internet2.middleware.grouper.util.declaredMethodsCache, to override default values, configure in the resource /ehcache.xml.  Default values are:maxElementsInMemory: 2000, eternal: false, timeToIdleSeconds: 0, timeToLiveSeconds: 86400, overFlowToDisk: false

 

And then nothing.

 

 

From: Chris Hyzer []
Sent: Wednesday, May 08, 2013 11:01 AM
To: Bryan E. Wooten;
Subject: RE: Grouper Loader Cron Question

 

Can you send more entries?  So the problem is not that things are not running when they should, but rather you want to know what is running if not your jobs specified?  There are other things that go on in the loader like copying data from the temp table to the change log table, but that doesn’t look like it is this stuff…  there isn’t much data here, so we would need to debug and set a breakpoint in the event log to see what is calling it…

 

Thanks,

Chris

 

From: [] On Behalf Of Bryan E. Wooten
Sent: Wednesday, May 08, 2013 12:49 PM
To:
Subject: [grouper-users] Grouper Loader Cron Question

 

I have configured 4 Grouper Ldap Loader Groups all with the quartz cron set to 0 0/15 * * * ?.

 

When I start the loader I see this every minute in the grouper log file:

 

2013-05-08 10:12:28,074: [main] INFO  EventLog.info(156) -  - [fa268fb3dc584eddbd16df5161bc3355,'GrouperSystem','application'] session: start (421ms)

2013-05-08 10:12:28,290: [main] INFO  EventLog.info(156) -  - [fe97cc7b58314f88a9a32e0de63d195a,'GrouperSystem','application'] session: start (12ms)

2013-05-08 10:12:28,297: [main] INFO  EventLog.info(156) -  - [1bd661bdfdf846a59753722f7f20edda,'GrouperSystem','application'] session: start (3ms)

2013-05-08 10:12:29,950: [main] INFO  EventLog.info(156) -  - [bb8bf229826a455f97f6fd1dcd407a72,'GrouperSystem','application'] session: start (11ms)

2013-05-08 10:12:30,313: [main] INFO  EventLog.info(156) -  - [bc5fa26423054cb1ba63f41dd0b04cc3,'GrouperSystem','application'] session: start (3ms)

2013-05-08 10:12:30,327: [main] INFO  EventLog.info(156) -  - [0cc24c919218497cade64297843cb8f8,'GrouperSystem','application'] session: start (3ms)

2013-05-08 10:12:30,334: [main] INFO  EventLog.info(156) -  - [5e259f1d1d6a432cb45e347decd9a799,'GrouperSystem','application'] session: start (3ms)

2013-05-08 10:12:30,358: [main] INFO  EventLog.info(156) -  - [5e259f1d1d6a432cb45e347decd9a799,'GrouperSystem','application'] add group type: 'grouperLoader' (21ms)

2013-05-08 10:13:14,475: [main] INFO  EventLog.info(156) -  - [2e4cd7b6557b42d18098fbeca861d9c0,'GrouperSystem','application'] session: start (13ms)

 

Any idea what is causing this?

 

-Bryan

 

Attachment: jstack.1.out
Description: jstack.1.out

Attachment: jstack.2.out
Description: jstack.2.out

Attachment: jstack.3.out
Description: jstack.3.out

Attachment: jstack.4.out
Description: jstack.4.out

Attachment: jstack.startup.out
Description: jstack.startup.out