grouper-users - [grouper-users] RE: Status Monitoring - Two Errors

Subject: Grouper Users - Open Discussion List

List archive

[grouper-users] RE: Status Monitoring - Two Errors

From: "Black, Carey M." <>
To: Ryan Rumbaugh <>
Cc: "" <>
Subject: [grouper-users] RE: Status Monitoring - Two Errors
Date: Tue, 28 Aug 2018 04:30:42 +0000
Accept-language: en-US
Authentication-results: spf=pass (sender IP is 128.146.138.11) smtp.mailfrom=osu.edu; internet2.edu; dkim=pass (signature was verified) header.d=osu.edu;internet2.edu; dmarc=pass action=none header.from=osu.edu;
Authentication-results-original: spf=none (sender IP is ) ;
Ironport-phdr: 9a23:4hfcgxRZSihq8mOHBgL9uVzYL9psv+yvbD5Q0YIujvd0So/mwa67ZReEt8tkgFKBZ4jH8fUM07OQ7/i/HzRYqb+681k6OKRWUBEEjchE1ycBO+WiTXPBEfjxciYhF95DXlI2t1uyMExSBdqsLwaK+i764jEdAAjwOhRoLerpBIHSk9631+ev8JHPfglEnjWwba9wIRmssQndqtQdjJd/JKo21hbHuGZDdf5MxWNvK1KTnhL86dm18ZV+7SleuO8v+tBZX6nicKs2UbJXDDI9M2Ao/8LrrgXMTRGO5nQHTGoblAdDDhXf4xH7WpfxtTb6tvZ41SKHM8D6Uaw4VDK/5KpwVhTmlDkIOCI48GHPi8x/kqRboA66pxdix4LYeZyZOOZicq/Ye94RWGhPUdtLVyFZAo2ycZYBD/YPM+hboYnypVoOogexCgS3Huzj1iNEi2Xq0aEmzegsFxzN0gw6H9IJtXTZtNv5OboWUe+v0KbIzi3PZO5I1Djn8ojHbBAgquyLU75qf8ba1E4iGBjBjlqKtYPlPCmZ2vkTv2WV9OdgUvmvi3M9pw5vvzev294hh4/UjYwbzVDE8D92wIczJdCgR057e9mkEIZIty6ELYt6WNktQ3lwuCoiy70Gv4K7czYQyJQh2RHfd+KLf5KW7R3+SeadOSt4i2h/eL6liBaz8FCsyvH8VsmuzllFtDdKnsPWtnAQ0Rzf8siHSudh/ke5wjaAyRrT6v9AIU8qiarXMZwhzaQulpUJqUjDBjX2mELxjK+YbkUk/emo6+L7Yrn8upCcMIp0hhnjMqQym8y/Bf40Mg4QUGiH/+m3yb7t/VXhTblUlPI6jrTVvZXHKcgGu6K0BgFV34k/5xqjCjqm3soXkHYaIF9AfR+KjZTlNEzWLPzmAvqzmUqgnCtoyvzcILHtHJvAImLenLrjfrtx80BcxxQwwNxD4p9ZD7IML+/tVkDqsdHXEwI2PgOqz+viFdpw2YITVG2KD6CEMa7ftVGI6+QyKOeWfoAVoizyK/096v7uk3A5nVgdcLGx05YLb360AulqL1yEbHT0jNoNCGAKsREgQ+Dwj12CTCJTaG21X6Ih4DE0FZiqDZ/ZRoCqnLyOwju0HoFXZmBBDFCAC3Dod5iYW/cIbyKSJcxhniYYWrimTo8tzRCutAnkxLp7NufY5DcXuY7+2NVw+uHfiAw++Dl6D8mSz22BU2R5nm0WSDI5waxypElwx1Wf3adlm/BYEMZc5/JNUgc0L57cyOl6BsjpVQLFZNiGVFWmTs+7DT0vQN882NgOY11gG9m4kB/MwjeqD6cPl7OXHJw07r7c33/pKsZy0XbG07Qhj0E4TctVLGGmm7V/+BbJB47SiEiZk6eqdb8A3C7W6muP12uOvEdEUAFuS6XFW24QZlfIodjj+EzNUqKuWvwbNV572MeEYpFXb9fgkFpGDKP5IsnbaWuslGeYAxuC3LqXb4OsdmkAinbzEk8Bxko5+X+NNkx2LS67rnOWKXokXQblZ0rn8q8n8iiTSVQpiQyGchsyhPKO5hcJiKnEGLso1bUetXJk8m0sRgzv1s/KC9eGuwtqdbldZtV4+lpcyGbFrFUsZ867N643nlcFaEw3pE7o2xhtQqR42ckx5CpwnEwrdfzeiQgRMWrBnPWScqbSNnG0+Rmub6DM3VSL182LvKoD9adwqlP/sRuvG1Z4tXhrzood33id48DSBREJGdLqU0kx/gRnvbySfSAmr53Zz3xiMKS481qgk9IkDeco0FCsKtBELeWJGBKhEssGCtKoJfBw3VWlc0FMMOVb7qVhJ8q9bLOP07KqO+A1mjWggCxH7Ylx31jK+TB7T7vPxItDzv2FjQY=
Spamdiagnosticmetadata: NSPM
Spamdiagnosticoutput: 1:99

Ryan,

FWIW: I have yet to try out the deprovisioning tool/logic. But I expect I will be using it someday. J

“Grouper newbie” (Oh… you are one of those…. J )

You might need to get out your “secret decoder ring”. J

https://spaces.at.internet2.edu/display/Grouper/Glossary

“stem” (old school term) = “folder” ( current term )

If you do anything with gsh (or the full Java API ) you will soon translate that term and a few others without the ring. :)

Short answer… apply patch GRP-1832. ( or if it is installed…. Then that patch needs a patch. J )

FWIW: When you start up GSH it will output the patch list that is installed while it is “loading”.

Longer answer: https://spaces.at.internet2.edu/display/Grouper/Grouper+patching

And/or

https://spaces.at.internet2.edu/display/Grouper/Grouper+patching+autorun

Well that is interesting….

GRP-1832 was released in “grouper_v2_3_0_api_patch_108”

The most shiny API patch released on about “Jul 26, 2018”.

Carey Matthew

PS. An aside:

I found this line of code in the group source.. it made me ROFL!

throw new RuntimeException("Wont happen");

From: <> On Behalf Of Ryan Rumbaugh
Sent: Monday, August 27, 2018 6:13 PM
To:
Subject: [grouper-users] RE: Status Monitoring - Two Errors

Thanks for your suggestion to check the configuration settings. We do have those settings however.

After a bit more reading I realized I could simply call the loaderRunOneJob method on the deprovisioning process, however, when doing so I now get this exception:

groovy:000> loaderRunOneJob("OTHER_JOB_deprovisioningDaemon");

ERROR java.lang.RuntimeException:

java.lang.RuntimeException: Dont pass more than 100 ids: 3968

at edu.internet2.middleware.grouper.app.loader.GrouperLoader.runOnceByJobName (GrouperLoader.java:1625)

at edu.internet2.middleware.grouper.app.gsh.loaderRunOneJob.invoke (loaderRunOneJob.java:95)

at edu.internet2.middleware.grouper.app.gsh.loaderRunOneJob$invoke.call (Unknown Source)

at groovysh_evaluate.loaderRunOneJob (groovysh_evaluate:4)

I tracked down this issue in JIRA (https://bugs.internet2.edu/jira/browse/GRP-1832?page=com.atlassian.jira.plugin.system.issuetabpanels%3Aall-tabpanel

) and the solution appears to have been “sending a batch of 100 stem ids”. Any suggestions on exactly what that means to a Grouper newbie?

Ryan Rumbaugh

From: Black, Carey M. <>
Sent: Monday, August 27, 2018 10:21 AM
To: Ryan Rumbaugh <>;
Subject: RE: Status Monitoring - Two Errors

Ryan,

RE: “I had been restarting the API daemon” … ( due to docker use )

I have often wondered how the “shutdown process” works for the daemon. Is it “graceful” ( and lets all running jobs complete before shutdown) or does it just “pull the plug”?

I think it just pulls the plug.

Which “leaves” running jobs as “in progress”(in the DB status table) and they refuse to immediately start when the loader restarts. Well, until the “in progress” record(s) get old enough that they are assumed to be dead. Then the jobs will no longer refuse to start.

I say that to say this:

If the loader is restarted repeatedly, quickly, and/or often, you may be interrupting the running jobs and leaving them as “in progress” (in the DB) and producing more delay on the jobs re-starting again. But it all depends on how fast/often those things are spinning up and down.

However, maybe If you always spinning up instances (and let the old ones run for a bit) you may be able to “wait till a good time” to turn them off.

Maybe if you cycle out the old instances gracefully by timing it with these settings?

“

##################################

## enabled / disabled cron

##################################

#quartz cron-like schedule for enabled/disabled daemon. Note, this has nothing to do with the changelog

#leave blank to disable this, the default is 12:01am, 11:01am, 3:01pm every day: 0 1 0,11,15 * * ?

changeLog.enabledDisabled.quartz.cron = 0 1 0,11,15 * * ?

“

RE: how to schedule the “deprovisioningDaemon”

Verify that your grouper-loader.base.properties has this block: ( or you can add it to your grouper-loader.properties )

NOTE: it was added to the default base as of GRP-1623. ( which maps to grouper_v2_3_0_api_patch_107 ( and for the UI grouper_v2_3_0_ui_patch_44 ) ) You likely are past those patches… but just saying. J

“

#####################################

## Deprovisioning Job

#####################################

otherJob.deprovisioningDaemon.class = edu.internet2.middleware.grouper.app.deprovisioning.GrouperDeprovisioningJob

otherJob.deprovisioningDaemon.quartzCron = 0 0 2 * * ?

“

HTH.

Carey Matthew

From: <> On Behalf Of Ryan Rumbaugh
Sent: Monday, August 27, 2018 10:12 AM
To:
Subject: [grouper-users] RE: Status Monitoring - Two Errors

An update to this issue that may be helpful to others…

Before I left the office on Friday I ran the gsh command “loaderRunOneJob(“CHANGE_LOG_changeLogTempToChangeLog”)” process and now the number of rows in the change_entry_temp table is zero! I tried running that before, but really didn’t see much of anything happening. Maybe I was just too impatient.

Now when accessing grouper/status?diagnosticType=all the only error is related to “OTHER_JOB_deprovisioningDaemon”. If anyone had any tips on how to get that kick started it would be greatly appreciated.

Ryan Rumbaugh

From: <> On Behalf Of Ryan Rumbaugh
Sent: Friday, August 24, 2018 9:15 AM
To:
Subject: [grouper-users] Status Monitoring - Two Errors

Good morning,

We would like to begin monitoring the status of grouper by using the diagnostic pages at grouper/status?diagnosticType=all, but before doing so I would like to take care of the two issues shown below.

Can anyone provide tips/suggestions on how to fix the two failures for CHANGE_LOG_changeLogTempToChangeLog and OTHER_JOB_deprovisioningDaemon?

We had a Java heap issue late last week which I believe caused the “grouper_change_log_entry_temp” table to keep growing. It’s at 69,886 rows currently while earlier this week it was at 50k. Thanks for any insight.

2 errors in the diagnostic tasks:

DiagnosticLoaderJobTest, Loader job CHANGE_LOG_changeLogTempToChangeLog

DiagnosticLoaderJobTest, Loader job OTHER_JOB_deprovisioningDaemon

Error stack for: loader_CHANGE_LOG_changeLogTempToChangeLog

java.lang.RuntimeException: Cant find a success in job CHANGE_LOG_changeLogTempToChangeLog since: 2018/08/16 14:19:22.000, expecting one in the last 30 minutes

at edu.internet2.middleware.grouper.j2ee.status.DiagnosticLoaderJobTest.doTask(DiagnosticLoaderJobTest.java:175)

at edu.internet2.middleware.grouper.j2ee.status.DiagnosticTask.executeTask(DiagnosticTask.java:78)

at edu.internet2.middleware.grouper.j2ee.status.GrouperStatusServlet.doGet(GrouperStatusServlet.java:180)

at javax.servlet.http.HttpServlet.service(HttpServlet.java:635)

at javax.servlet.http.HttpServlet.service(HttpServlet.java:742)

at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:230)

at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:165)

at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:52)

at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:192)

at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:165)

at org.owasp.csrfguard.CsrfGuardFilter.doFilter(CsrfGuardFilter.java:110)

at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:192)

at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:165)

at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:198)

at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:96)

at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:478)

at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:140)

at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:80)

at org.apache.catalina.valves.AbstractAccessLogValve.invoke(AbstractAccessLogValve.java:624)

at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:87)

at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:341)

at org.apache.coyote.ajp.AjpProcessor.service(AjpProcessor.java:478)

at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:66)

at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:798)

at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1441)

at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49)

at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)

at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)

at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)

at java.lang.Thread.run(Thread.java:748)

Error stack for: loader_OTHER_JOB_deprovisioningDaemon

java.lang.RuntimeException: Cant find a success in job OTHER_JOB_deprovisioningDaemon, expecting one in the last 3120 minutes

at edu.internet2.middleware.grouper.j2ee.status.DiagnosticLoaderJobTest.doTask(DiagnosticLoaderJobTest.java:173)