Skip to Content.
Sympa Menu

grouper-users - Re: [grouper-users] Grouper applications stuck after time of inactivity

Subject: Grouper Users - Open Discussion List

List archive

Re: [grouper-users] Grouper applications stuck after time of inactivity


Chronological Thread 
  • From: Sonia Zorba <>
  • To: "Hyzer, Chris" <>
  • Cc: grouper-users <>
  • Subject: Re: [grouper-users] Grouper applications stuck after time of inactivity
  • Date: Fri, 2 Sep 2016 19:10:43 +0200 (CEST)
  • Ironport-phdr: 9a23:sUJSWhS0JZEZ4SXiYClaQnSO/9psv+yvbD5Q0YIujvd0So/mwa67YxON2/xhgRfzUJnB7Loc0qyN7PCmBDdLuMvJmUtBWaIPfidNsd8RkQ0kDZzNImzAB9muURYHGt9fXkRu5XCxPBsdMs//Y1rPvi/6tmZKSV2sfTZyc67VC5zflYD//OCo+oaZK1FNjzqsc75oBBStpkPMrsQQh81vJrtnmTXTpX4dQONQxGogF1WJlR+0stW35pRq2yNZp+ln9shJX+P7Y/JrHvRjED06PjVtt4XQvh7ZQF7X6w==

Hi,

this started happening when we configured the application to use the external
LDAP. At the time there weren't other applications on the server. This
happens both with Tomcat 6 and Tomcat 8.

I restarted Tomcat several time, trying to change some configurations, but
nothing is changed.
I initially used the API binary without patches.

Today I have installed the patches using the Grouper installer (on api, ui
and ws). All was ok. About 3 hours later, I accessed the Grouper UI and it
was stuck, waiting for something:

2016-09-02 14:31:43,692: [http-nio-8080-exec-10] DEBUG
BaseSourceAdapter.getSubjectByIdOrIdentifier(277) - - method:
getSubjectByIdOrIdentifier, idOrIdentifier: GrouperSystem, exceptionIfNull:
false
2016-09-02 14:43:33,055: [http-nio-8080-exec-1] DEBUG
LdapSourceAdapter.getLdapUnique(862) - - method: getLdapUnique, search:
Search [params=scope: SUBTREE_SCOPE, filter: (& (uid=%TERM%)
(objectclass=inetOrgPerson)), base: ou=people,dc=inaf,dc=it,
searchType=searchSubject], searchValue: GrouperSystem, attributeNames: Array
size: 9: [0]: uid

It waited more than 10 minutes, then the page became unreachable.

In catalina.out I have found:

02-Sep-2016 14:43:46.124 SEVERE [http-nio-8080-exec-7]
org.apache.catalina.realm.JNDIRealm.authenticate Exception performing
authentication
javax.naming.NameNotFoundException: [LDAP: error code 32 - No Such Object];
remaining name 'ou=people,dc=inaf,dc=it'

Restarting the server all was ok again.

Now, 4 hours later, the same behavior...

I think my problem could be firewall/connection related, similar to these:

http://shibboleth.1660669.n2.nabble.com/Sjibb-LDAP-pool-hangs-on-firewall-TCP-session-truncation-td7626121.html
https://bz.apache.org/bugzilla/show_bug.cgi?id=45834

but I'm not a network expert and I don't know what I could configure in
Grouper/Tomcat to avoid this issue (if there is something that I can do).

This is my grouperPatchStatus.properties:

# added by grouper-installer
grouper_v2_3_0_api_patch_0.date = 2016/09/02 11:20:28
# added by grouper-installer
grouper_v2_3_0_api_patch_0.state = applied

# added by grouper-installer
grouper_v2_3_0_api_patch_1.date = 2016/09/02 11:20:31

# added by grouper-installer
grouper_v2_3_0_api_patch_1.state = applied

# added by grouper-installer
grouper_v2_3_0_api_patch_2.date = 2016/09/02 11:20:33

# added by grouper-installer
grouper_v2_3_0_api_patch_2.state = applied

# added by grouper-installer
grouper_v2_3_0_api_patch_3.date = 2016/09/02 11:20:35

# added by grouper-installer
grouper_v2_3_0_api_patch_3.state = applied

# added by grouper-installer
grouper_v2_3_0_api_patch_4.date = 2016/09/02 11:20:37

# added by grouper-installer
grouper_v2_3_0_api_patch_4.state = applied

# added by grouper-installer
grouper_v2_3_0_api_patch_5.date = 2016/09/02 11:20:39

# added by grouper-installer
grouper_v2_3_0_api_patch_5.state = applied

# added by grouper-installer
grouper_v2_3_0_api_patch_6.date = 2016/09/02 11:20:42

# added by grouper-installer
grouper_v2_3_0_api_patch_6.state = applied

# added by grouper-installer
grouper_v2_3_0_api_patch_7.date = 2016/09/02 11:20:46

# added by grouper-installer
grouper_v2_3_0_api_patch_7.state = applied

# added by grouper-installer
grouper_v2_3_0_api_patch_8.date = 2016/09/02 11:20:49

# added by grouper-installer
grouper_v2_3_0_api_patch_8.state = applied

# added by grouper-installer
grouper_v2_3_0_api_patch_9.date = 2016/09/02 11:20:51

# added by grouper-installer
grouper_v2_3_0_api_patch_9.state = applied

# added by grouper-installer
grouper_v2_3_0_api_patch_10.date = 2016/09/02 11:20:53

# added by grouper-installer
grouper_v2_3_0_api_patch_10.state = applied

# added by grouper-installer
grouper_v2_3_0_api_patch_11.date = 2016/09/02 11:20:55

# added by grouper-installer
grouper_v2_3_0_api_patch_11.state = applied

# added by grouper-installer
grouper_v2_3_0_api_patch_12.date = 2016/09/02 11:20:57

# added by grouper-installer
grouper_v2_3_0_api_patch_12.state = applied

# added by grouper-installer
grouper_v2_3_0_api_patch_13.date = 2016/09/02 11:20:58

# added by grouper-installer
grouper_v2_3_0_api_patch_13.state = applied

# added by grouper-installer
grouper_v2_3_0_api_patch_14.date = 2016/09/02 11:21:00

# added by grouper-installer
grouper_v2_3_0_api_patch_14.state = applied

# added by grouper-installer
grouper_v2_3_0_api_patch_15.date = 2016/09/02 11:21:02

# added by grouper-installer
grouper_v2_3_0_api_patch_15.state = applied

# added by grouper-installer
grouper_v2_3_0_api_patch_16.date = 2016/09/02 11:21:03

# added by grouper-installer
grouper_v2_3_0_api_patch_16.state = applied

# added by grouper-installer
grouper_v2_3_0_api_patch_17.date = 2016/09/02 11:21:05

# added by grouper-installer
grouper_v2_3_0_api_patch_17.state = applied

# added by grouper-installer
grouper_v2_3_0_api_patch_18.date = 2016/09/02 11:21:07

# added by grouper-installer
grouper_v2_3_0_api_patch_18.state = applied

# added by grouper-installer
grouper_v2_3_0_api_patch_19.date = 2016/09/02 11:21:09

# added by grouper-installer
grouper_v2_3_0_api_patch_19.state = applied

# added by grouper-installer
grouper_v2_3_0_api_patch_20.date = 2016/09/02 11:21:11

# added by grouper-installer
grouper_v2_3_0_api_patch_20.state = applied

# added by grouper-installer
grouper_v2_3_0_api_patch_21.date = 2016/09/02 11:21:13

# added by grouper-installer
grouper_v2_3_0_api_patch_21.state = applied

# added by grouper-installer
grouper_v2_3_0_api_patch_22.date = 2016/09/02 11:21:14

# added by grouper-installer
grouper_v2_3_0_api_patch_22.state = applied

Cheers,
Sonia


----- Original Message -----
From: "Hyzer, Chris"
<>
To: "Sonia Zorba"
<>,
"grouper-users"
<>
Sent: Thursday, September 1, 2016 3:53:34 PM
Subject: RE: [grouper-users] Grouper applications stuck after time of
inactivity

I think those errors are not accurate...

Have you reloaded the webapp, or do you restart tomcat when applying changes?
Is this app the only one in that tomcat or do other apps run there too?
Which patches do you have installed exactly? See
grouperPatchStatus.properties

Did this only start happening recently?

Thanks
Chris

-----Original Message-----
From:


[mailto:]
On Behalf Of Sonia Zorba
Sent: Thursday, September 01, 2016 4:15 AM
To:

Subject: [grouper-users] Grouper applications stuck after time of inactivity

Hi,

I'm experiencing a strange behavior from several days.

I have a Grouper 2.3.0 installed on Tomcat 8 (web services + UI).

My sources are:
- an LDAP owned by an external machine;
- an LDAP in localhost;

I'm the only person currently using this testing machine, so in the
night there are no requests to Grouper. When I open the UI application
or call the webservice for the first time in the morning, the
applications wait about 15 minutes, then all is working correctly.

I increased the logging levels, but I only see a long wait:

2016-09-01 08:56:18,701: [http-nio-8080-exec-4] DEBUG
LdapSourceAdapter.getLdapResultsHelper(740) - - searchType: searchSubject,
filter: (& (uid=GrouperSystem) (objectclass=inetOrgPerson))

2016-09-01 09:11:57,658: [http-nio-8080-exec-4] DEBUG
LdapSourceAdapter.getLdapUnique(862) - - method: getLdapUnique, search:
Search [params=scope: SUBTREE_SCOPE, filter: (& (uid=%TERM%)
(objectclass=inetOrgPerson)), base: ou=[...], searchType=searchSubject],
searchValue: GrouperSystem, attributeNames: Array size: 9: [0]: uid


This happens when Grouper call the external LDAP (the localhost one
responds immediately).

I tried calling the services and the UI with curl all night with a cron
job each minute and the problem didn't happen.
However, in the first access with another testing webapp that uses the
GrouperClient API, that webapp waited for 15 minutes too! So this seems
associated to each single client or session created.

I read that could be a problem of "connection pools leak", so I would
try to forcedly close abandoned connections. How I can configure this in
the Grouper settings?

Morover, in my catalina.out I read these bad memory leak warning:

31-Aug-2016 23:55:18.765 WARNING [localhost-startStop-4]
org.apache.catalina.loader.WebappClassLoaderBase.clearReferencesThreads The
web application [grouper] appears to have started a thread named [Abandoned
connection cleanup thread] but has failed to stop it. This is very likely to
create a memory leak. Stack trace of thread:

java.lang.Object.wait(Native Method)

java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:135)


com.mysql.jdbc.AbandonedConnectionCleanupThread.run(AbandonedConnectionCleanupThread.java:43)

31-Aug-2016 23:55:18.766 WARNING [localhost-startStop-4]
org.apache.catalina.loader.WebappClassLoaderBase.clearReferencesThreads The
web application [grouper] appears to have started a thread named
[C3P0PooledConnectionPoolManager[identityToken->12yj2ui9i1qqmmey649b1u|3b702e77]-AdminTaskTimer]
but has failed to stop it. This is very likely to create a memory leak.
Stack trace of thread:

java.lang.Object.wait(Native Method)

java.util.TimerThread.mainLoop(Timer.java:552)

java.util.TimerThread.run(Timer.java:505)

31-Aug-2016 23:55:18.767 WARNING [localhost-startStop-4]
org.apache.catalina.loader.WebappClassLoaderBase.clearReferencesThreads The
web application [grouper] appears to have started a thread named
[C3P0PooledConnectionPoolManager[identityToken->12yj2ui9i1qqmmey649b1u|3b702e77]-HelperThread-#0]
but has failed to stop it. This is very likely to create a memory leak.
Stack trace of thread:

java.lang.Object.wait(Native Method)


com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread.run(ThreadPoolAsynchronousRunner.java:683)

31-Aug-2016 23:55:18.767 WARNING [localhost-startStop-4]
org.apache.catalina.loader.WebappClassLoaderBase.clearReferencesThreads The
web application [grouper] appears to have started a thread named
[C3P0PooledConnectionPoolManager[identityToken->12yj2ui9i1qqmmey649b1u|3b702e77]-HelperThread-#1]
but has failed to stop it. This is very likely to create a memory leak.
Stack trace of thread:

java.lang.Object.wait(Native Method)


com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread.run(ThreadPoolAsynchronousRunner.java:683)

31-Aug-2016 23:55:18.768 WARNING [localhost-startStop-4]
org.apache.catalina.loader.WebappClassLoaderBase.clearReferencesThreads The
web application [grouper] appears to have started a thread named
[C3P0PooledConnectionPoolManager[identityToken->12yj2ui9i1qqmmey649b1u|3b702e77]-HelperThread-#2]
but has failed to stop it. This is very likely to create a memory leak.
Stack trace of thread:

java.lang.Object.wait(Native Method)


com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread.run(ThreadPoolAsynchronousRunner.java:683)

31-Aug-2016 23:55:18.768 WARNING [localhost-startStop-4]
org.apache.catalina.loader.WebappClassLoaderBase.clearReferencesThreads The
web application [grouper] appears to have started a thread named
[net.sf.ehcache.CacheManager@3e2b44dd] but has failed to stop it. This is
very likely to create a memory leak.


I don't know if this could be related to the wait too. I added these
JAVA_OPTS but it didn't help:

JAVA_OPTS="$JAVA_OPTS -Djava.awt.headless=true -Xms512M -Xmx1024m
-XX:+UseConcMarkSweepGC -Dfile.encoding=UTF-8 -XX:PermSize=64m
-XX:MaxPermSize=512m"


Your help will be really appreciate.

Thanks,
Sonia



Archive powered by MHonArc 2.6.19.

Top of Page