better logging for daemons

----Original Message----
From: grouper-dev-request@internet2.edu grouper-dev-request@internet2.edu On Behalf Of Black, Carey M.
Sent: Friday, August 18, 2017 4:32 PM
To: Redman, Chad <chad_redman@unc.edu>; grouper-users@internet2.edu
Cc: grouper-dev@internet2.edu
Subject: [grouper-dev] RE: loader log is very chatty and full of lines of questionable value....

Chad,

Thanks for the insights.

I will enable the two " grouper.app.loader.GrouperLoader [Config | Type ] " settings and see if those are more helpful.

My heartburn is that I think the other lines ( non ' session: start' ) are useful. But I appear to have to take 4 "bad lines" to get 1 "good one". ( Not a great trade off. And not clear as to why that is the current, default, condition.)
So I hate to lose the good to get rid of the bad. ( But it looks like I need to do that just to keep from filling up disks. )

Maybe the classes you pointed at will give me similar insights to what the loader is or is not doing.
Thanks again. ( I am still finding my way through the configuration and tuning. I have a feeling that this will take a bit of time to polish....)

–
Carey Matthew Black.123@osu.edu

----Original Message----
From: Redman, Chad chad_redman@unc.edu
Sent: Friday, August 18, 2017 2:55 PM
To: Black, Carey M. <black.123@osu.edu>; grouper-users@internet2.edu
Cc: grouper-dev@internet2.edu
Subject: RE: loader log is very chatty and full of lines of questionable value....

The default log4.properties has:

1. 1. Grouper Event Logging
   2. * Logs at info only
      log4j.logger.edu.internet2.middleware.grouper.log.EventLog = INFO, grouper_event

We took that out for our loader. The log4j settings we currently have on our loader server are:

--------------------------
log4j.appender.R = org.apache.log4j.FileAppender
log4j.appender.R.File = ${log4j.filename.sync}
log4j.appender.R.layout = org.apache.log4j.PatternLayout
log4j.appender.R.layout.ConversionPattern = %d

{ISO8601}

: [%t] %-5p %C

{1}

.%M(%L) - %m%n

log4j.rootLogger = WARN, R

1. 1. All Internet2 (warn to grouper_error per default logger) log4j.logger.edu.internet2.middleware = WARN

log4j.logger.edu.internet2.middleware.grouper.RegistryInstall = INFO

log4j.logger.edu.internet2.middleware.grouper.app.loader.GrouperLoaderType = DEBUG

log4j.logger.edu.internet2.middleware.grouper.app.loader.GrouperLoaderConfig = DEBUG
--------------------------

The GrouperLoaderType DEBUG setting is pretty useful for summarizing some of the actual loader actions. The GrouperLoaderConfig DEBUG doesn't print out very much, just the LDAP settings periodically.

Maybe the EventLog logging of session starts can be changed to print at level debug instead of info? For a while, we had kept the level at info only in the UI, because there was no other way to see who was logging in. But we eventually turned it off in the UI as well, being too verbose.

-Chad

----Original Message----
From: grouper-dev-request@internet2.edu grouper-dev-request@internet2.edu On Behalf Of Black, Carey M.
Sent: Friday, August 18, 2017 2:14 PM
To: grouper-users@internet2.edu
Cc: grouper-dev@internet2.edu
Subject: [grouper-dev] RE: loader log is very chatty and full of lines of questionable value....

Bump.

I am seeing 1G log files created per day.
4721929 lines that have ' session: start'
1153101 lines that do not.

That is 4.7M lines of logs that end up in our splunk system that provide no known useful information.

Does anyone else see this on their systems?
Does anyone use the Grouper Loader process?

Any hints about how to make the logging better? ( Other than track down the line of code and wrapper it with an if block. )

–
Carey Matthew Black.123@osu.edu

----Original Message----
From: grouper-users-request@internet2.edu grouper-users-request@internet2.edu On Behalf Of Black, Carey M.
Sent: Wednesday, August 16, 2017 2:57 PM
To: grouper-users@internet2.edu
Subject: [grouper-users] loader log is very chatty and full of lines of questionable value....

I am trying to use the Loader process to sync some data into grouper from LDAP. ( That part is working as far as I can tell after I gave it enough ram to not fall over. )

However, in the grouper_error.log (for where the loader is logging) I am seeing a lot of lines like :
"
2017-08-16 14:25:04,783: [DefaultQuartzScheduler_Worker-7] INFO EventLog.info(156) - - [9a3e8...c35b,'GrouperSystem','application'] session: start (0ms) "

And by a lot I mean ( Just from today's file...):

$ wc -l grouper_error.log ; grep -c ' session: start' grouper_error.log; grep -vc ' session: start' grouper_error.log;
3135034 grouper_error.log ( Total lines in the file)
2379686 ( Lines that are ' session: start' lines, 75% of the file!)
755517 ( Lines that are not ' session: start' lines )

Can anyone tell me how to suppress ONLY those lines?
I might be wrong but other lines that say things like "add member" , "delete member" (etc...) look like they are being logged from the same location. [ AKA: " INFO EventLog.info(156)" ]

Could any explain why those log statements are there?
I really don't understand what they are trying to communicate.

–
Carey Matthew Black.123@osu.edu