search

clj-holmes / clj-watson

clojure deps SCA
Eclipse Public License 2.0
84 stars 9 forks source link

Consider Cutting Down on the Logging Noise at Startup #69

Closed lread closed 3 months ago

lread commented 3 months ago

Currently

When clj-watson starts up it emits quite a few log lines, here's an example:

Jul 31, 2024 5:34:58 P.M. org.apache.commons.jcs3.engine.control.CompositeCacheManager 
INFO: Instance is null, returning unconfigured instance
Jul 31, 2024 5:34:59 P.M. org.apache.commons.jcs3.engine.control.CompositeCacheManager 
INFO: Setting default auxiliaries to "ODC"
Jul 31, 2024 5:34:59 P.M. org.apache.commons.jcs3.engine.control.CompositeCacheManager 
INFO: setting defaultCompositeCacheAttributes to [ useLateral = true, useRemote = true, useDisk = true, maxObjs = 0, maxSpoolPerRun = -1, diskUsagePattern = UPDATE, spoolChunkSize = 2 ]
Jul 31, 2024 5:34:59 P.M. org.apache.commons.jcs3.engine.control.CompositeCacheManager 
INFO: setting defaultElementAttributes to [ IS_LATERAL = false, IS_SPOOL = true, IS_REMOTE = false, IS_ETERNAL = false, MaxLifeSeconds = 86400, IdleTime = 1800, CreateTime = 1722461699056, LastAccessTime = 1722461699056, getTimeToLiveSeconds() = 86399, createTime = 1722461699056 ]
Jul 31, 2024 5:34:59 P.M. org.apache.commons.jcs3.engine.memory.AbstractDoubleLinkedListMemoryCache 
INFO: initialized MemoryCache for CENTRAL
Jul 31, 2024 5:34:59 P.M. org.apache.commons.jcs3.engine.control.CompositeCache 
INFO: Constructed cache with name [CENTRAL] and cache attributes [ useLateral = true, useRemote = true, useDisk = true, maxObjs = 0, maxSpoolPerRun = -1, diskUsagePattern = UPDATE, spoolChunkSize = 2 ]
Jul 31, 2024 5:34:59 P.M. org.apache.commons.jcs3.auxiliary.AuxiliaryCacheConfigurator 
INFO: No cache event logger defined for auxiliary [jcs.auxiliary.ODC]
Jul 31, 2024 5:34:59 P.M. org.apache.commons.jcs3.auxiliary.AuxiliaryCacheConfigurator 
INFO: Using standard serializer [org.apache.commons.jcs3.utils.serialization.StandardSerializer@58914623] for auxiliary [jcs.auxiliary.ODC]
Jul 31, 2024 5:34:59 P.M. org.apache.commons.jcs3.auxiliary.disk.indexed.IndexedDiskCache 
INFO: Region [CENTRAL] : Set maxKeySize to: "1,000,000"
Jul 31, 2024 5:34:59 P.M. org.apache.commons.jcs3.auxiliary.disk.indexed.IndexedDiskCache 
INFO: Region [CENTRAL] : Cache file root directory: /tmp/db/cache
Jul 31, 2024 5:34:59 P.M. org.apache.commons.jcs3.auxiliary.disk.indexed.IndexedDiskCache 
INFO: Region [CENTRAL] : Indexed Disk Cache is alive.
Jul 31, 2024 5:34:59 P.M. org.apache.commons.jcs3.engine.memory.AbstractDoubleLinkedListMemoryCache 
INFO: initialized MemoryCache for POM
Jul 31, 2024 5:34:59 P.M. org.apache.commons.jcs3.engine.control.CompositeCache 
INFO: Constructed cache with name [POM] and cache attributes [ useLateral = true, useRemote = true, useDisk = true, maxObjs = 0, maxSpoolPerRun = -1, diskUsagePattern = UPDATE, spoolChunkSize = 2 ]
Jul 31, 2024 5:34:59 P.M. org.apache.commons.jcs3.auxiliary.AuxiliaryCacheConfigurator 
INFO: No cache event logger defined for auxiliary [jcs.auxiliary.ODC]
Jul 31, 2024 5:34:59 P.M. org.apache.commons.jcs3.auxiliary.AuxiliaryCacheConfigurator 
INFO: Using standard serializer [org.apache.commons.jcs3.utils.serialization.StandardSerializer@75643efa] for auxiliary [jcs.auxiliary.ODC]
Jul 31, 2024 5:34:59 P.M. org.apache.commons.jcs3.auxiliary.disk.indexed.IndexedDiskCache 
INFO: Region [POM] : Set maxKeySize to: "1,000,000"
Jul 31, 2024 5:34:59 P.M. org.apache.commons.jcs3.auxiliary.disk.indexed.IndexedDiskCache 
INFO: Region [POM] : Cache file root directory: /tmp/db/cache
Jul 31, 2024 5:34:59 P.M. org.apache.commons.jcs3.auxiliary.disk.indexed.IndexedDiskCache 
INFO: Region [POM] : Indexed Disk Cache is alive.
Jul 31, 2024 5:34:59 P.M. org.apache.commons.jcs3.engine.memory.AbstractDoubleLinkedListMemoryCache 
INFO: initialized MemoryCache for NODEAUDIT
Jul 31, 2024 5:34:59 P.M. org.apache.commons.jcs3.engine.control.CompositeCache 
INFO: Constructed cache with name [NODEAUDIT] and cache attributes [ useLateral = true, useRemote = true, useDisk = true, maxObjs = 0, maxSpoolPerRun = -1, diskUsagePattern = UPDATE, spoolChunkSize = 2 ]
Jul 31, 2024 5:34:59 P.M. org.apache.commons.jcs3.auxiliary.AuxiliaryCacheConfigurator 
INFO: No cache event logger defined for auxiliary [jcs.auxiliary.ODC]
Jul 31, 2024 5:34:59 P.M. org.apache.commons.jcs3.auxiliary.AuxiliaryCacheConfigurator 
INFO: Using standard serializer [org.apache.commons.jcs3.utils.serialization.StandardSerializer@2d36a825] for auxiliary [jcs.auxiliary.ODC]
Jul 31, 2024 5:34:59 P.M. org.apache.commons.jcs3.auxiliary.disk.indexed.IndexedDiskCache 
INFO: Region [NODEAUDIT] : Set maxKeySize to: "1,000,000"
Jul 31, 2024 5:34:59 P.M. org.apache.commons.jcs3.auxiliary.disk.indexed.IndexedDiskCache 
INFO: Region [NODEAUDIT] : Cache file root directory: /tmp/db/cache
Jul 31, 2024 5:34:59 P.M. org.apache.commons.jcs3.auxiliary.disk.indexed.IndexedDiskCache 
INFO: Region [NODEAUDIT] : Indexed Disk Cache is alive.
Jul 31, 2024 5:34:59 P.M. org.apache.commons.jcs3.engine.control.CompositeCacheConfigurator 
INFO: Parsed regions [CENTRAL, POM, NODEAUDIT]
Jul 31, 2024 5:34:59 P.M. org.apache.commons.jcs3.engine.control.CompositeCacheManager 
INFO: Finished configuration in 48 ms.

My Take

Because the presentation is noisy and repetitive I am likely to just skip over the entire log. The only thing I see that seems relevant to me is the cache file root directory.

As a user, I ask myself why a tool is telling me things I do not need to know. And then I wonder if maybe I do need to know about these things it is telling me. And then I feel a bit annoyed with the tool when I realize I probably don't.

Proposal

Look into a way to reduce this startup log noise to maybe:

Nvd database root directory: /tmp/db/cache

Next Steps

If you agree, I can look into this more and follow up with a PR.

seancorfield commented 3 months ago

It seems like all that org.apache.commons.jcs3.* logging could be suppressed and new, specific (useful!) logging from Watson added?

seancorfield commented 3 months ago

Does this tie in to #68 ?

lread commented 3 months ago

Ya is certainly related to #68.

Since clj-watson turns off logging via slf4j-nop, we can assume that these logs lines are not redirected through slf4j.

I think by default Apache Commons JCS uses JUL but can be told to use log4j2. Can experiment with log bridges etc. I think we want all logs redirected to a single logging fwk where we control what we want on and off.

lread commented 3 months ago

Ok @seancorfield, I've got something working locally.

It makes sense to switch from slf4j-nop to something real. I'll start with logback-classic (can adjust if you prefer something else) with minimal logging config to suppress the noisy org.apache.commons.jcs3.*. This will turn on dependency-check logging - which includes logging for #68.