Browse Source

logging refactoring

jrivard@gmail.com 6 years ago
parent
commit
4c943f704c
79 changed files with 375 additions and 283 deletions
  1. 1 1
      server/src/main/java/password/pwm/PwmAboutProperty.java
  2. 36 23
      server/src/main/java/password/pwm/PwmApplication.java
  3. 3 3
      server/src/main/java/password/pwm/PwmEnvironment.java
  4. 5 4
      server/src/main/java/password/pwm/config/Configuration.java
  5. 2 2
      server/src/main/java/password/pwm/config/PwmSettingXml.java
  6. 2 2
      server/src/main/java/password/pwm/config/profile/ChallengeProfile.java
  7. 4 1
      server/src/main/java/password/pwm/config/profile/LdapProfile.java
  8. 1 1
      server/src/main/java/password/pwm/config/stored/ConfigurationReader.java
  9. 2 2
      server/src/main/java/password/pwm/config/stored/NGStoredConfigurationFactory.java
  10. 2 2
      server/src/main/java/password/pwm/config/stored/StoredConfigurationImpl.java
  11. 1 1
      server/src/main/java/password/pwm/config/value/FileValue.java
  12. 2 2
      server/src/main/java/password/pwm/health/HealthMonitor.java
  13. 2 2
      server/src/main/java/password/pwm/http/ContextManager.java
  14. 2 2
      server/src/main/java/password/pwm/http/HttpEventManager.java
  15. 1 1
      server/src/main/java/password/pwm/http/filter/AuthenticationFilter.java
  16. 2 5
      server/src/main/java/password/pwm/http/filter/ConfigAccessFilter.java
  17. 1 1
      server/src/main/java/password/pwm/http/filter/RequestInitializationFilter.java
  18. 1 1
      server/src/main/java/password/pwm/http/servlet/ShortcutServlet.java
  19. 2 2
      server/src/main/java/password/pwm/http/servlet/admin/AppDashboardData.java
  20. 1 1
      server/src/main/java/password/pwm/http/servlet/command/CommandServlet.java
  21. 2 2
      server/src/main/java/password/pwm/http/servlet/configeditor/ConfigEditorServlet.java
  22. 5 1
      server/src/main/java/password/pwm/http/servlet/configguide/ConfigGuideServlet.java
  23. 6 2
      server/src/main/java/password/pwm/http/servlet/configmanager/DebugItemGenerator.java
  24. 1 1
      server/src/main/java/password/pwm/http/servlet/helpdesk/HelpdeskVerificationOptionsBean.java
  25. 1 1
      server/src/main/java/password/pwm/http/servlet/newuser/NewUserServlet.java
  26. 1 1
      server/src/main/java/password/pwm/http/servlet/oauth/OAuthMachine.java
  27. 5 2
      server/src/main/java/password/pwm/http/servlet/resource/ResourceServletConfiguration.java
  28. 1 1
      server/src/main/java/password/pwm/http/state/SessionStateService.java
  29. 2 2
      server/src/main/java/password/pwm/ldap/LdapConnectionService.java
  30. 1 1
      server/src/main/java/password/pwm/ldap/LdapOperationsHelper.java
  31. 2 2
      server/src/main/java/password/pwm/ldap/PasswordChangeProgressChecker.java
  32. 8 7
      server/src/main/java/password/pwm/svc/PwmServiceManager.java
  33. 1 1
      server/src/main/java/password/pwm/svc/cache/CacheService.java
  34. 2 2
      server/src/main/java/password/pwm/svc/cluster/ClusterService.java
  35. 2 2
      server/src/main/java/password/pwm/svc/email/EmailServerUtil.java
  36. 4 4
      server/src/main/java/password/pwm/svc/email/EmailService.java
  37. 1 1
      server/src/main/java/password/pwm/svc/event/AuditService.java
  38. 1 1
      server/src/main/java/password/pwm/svc/event/LdapXmlUserHistory.java
  39. 2 2
      server/src/main/java/password/pwm/svc/event/SyslogAuditService.java
  40. 9 18
      server/src/main/java/password/pwm/svc/intruder/DataStoreRecordStore.java
  41. 3 3
      server/src/main/java/password/pwm/svc/report/ReportService.java
  42. 6 2
      server/src/main/java/password/pwm/svc/report/UserCacheService.java
  43. 2 2
      server/src/main/java/password/pwm/svc/stats/StatisticsBundle.java
  44. 7 4
      server/src/main/java/password/pwm/svc/stats/StatisticsManager.java
  45. 11 5
      server/src/main/java/password/pwm/svc/token/DataStoreTokenMachine.java
  46. 2 2
      server/src/main/java/password/pwm/svc/token/TokenService.java
  47. 1 1
      server/src/main/java/password/pwm/svc/wordlist/AbstractWordlist.java
  48. 10 13
      server/src/main/java/password/pwm/svc/wordlist/SharedHistoryManager.java
  49. 1 1
      server/src/main/java/password/pwm/svc/wordlist/WordlistImporter.java
  50. 1 1
      server/src/main/java/password/pwm/util/CASFilterAuthenticationProvider.java
  51. 4 4
      server/src/main/java/password/pwm/util/LocaleHelper.java
  52. 13 15
      server/src/main/java/password/pwm/util/PwmPasswordRuleValidator.java
  53. 3 3
      server/src/main/java/password/pwm/util/db/DatabaseAccessorImpl.java
  54. 4 4
      server/src/main/java/password/pwm/util/db/DatabaseUtil.java
  55. 5 5
      server/src/main/java/password/pwm/util/db/JDBCDriverLoader.java
  56. 2 2
      server/src/main/java/password/pwm/util/form/FormUtility.java
  57. 2 2
      server/src/main/java/password/pwm/util/localdb/AbstractJDBCLocalDB.java
  58. 1 1
      server/src/main/java/password/pwm/util/localdb/DerbyLocalDB.java
  59. 3 3
      server/src/main/java/password/pwm/util/localdb/LocalDBFactory.java
  60. 29 31
      server/src/main/java/password/pwm/util/localdb/LocalDBStoredQueue.java
  61. 1 1
      server/src/main/java/password/pwm/util/localdb/LocalDBUtility.java
  62. 20 9
      server/src/main/java/password/pwm/util/localdb/WorkQueueProcessor.java
  63. 17 10
      server/src/main/java/password/pwm/util/localdb/XodusLocalDB.java
  64. 1 1
      server/src/main/java/password/pwm/util/logging/LocalDBLogger.java
  65. 1 1
      server/src/main/java/password/pwm/util/logging/PwmLogManager.java
  66. 55 6
      server/src/main/java/password/pwm/util/logging/PwmLogger.java
  67. 2 2
      server/src/main/java/password/pwm/util/macro/StandardMacros.java
  68. 1 1
      server/src/main/java/password/pwm/util/operations/ActionExecutor.java
  69. 2 2
      server/src/main/java/password/pwm/util/operations/PasswordUtility.java
  70. 2 2
      server/src/main/java/password/pwm/util/operations/cr/DbCrOperator.java
  71. 21 20
      server/src/main/java/password/pwm/util/operations/cr/NMASCrOperator.java
  72. 1 1
      server/src/main/java/password/pwm/util/operations/otp/AbstractOtpOperator.java
  73. 3 3
      server/src/main/java/password/pwm/util/operations/otp/DbOtpOperator.java
  74. 1 1
      server/src/main/java/password/pwm/util/operations/otp/LocalDbOtpOperator.java
  75. 2 1
      server/src/main/java/password/pwm/util/operations/otp/OTPPamUtil.java
  76. 2 2
      server/src/main/java/password/pwm/util/queue/SmsQueueManager.java
  77. 1 1
      server/src/main/java/password/pwm/util/secure/X509Utils.java
  78. 1 1
      server/src/main/java/password/pwm/ws/client/rest/RestClientHelper.java
  79. 1 1
      server/src/main/java/password/pwm/ws/client/rest/form/RestFormDataClient.java

+ 1 - 1
server/src/main/java/password/pwm/PwmAboutProperty.java

@@ -141,7 +141,7 @@ public enum PwmAboutProperty
                 catch ( Throwable t )
                 {
                     aboutMap.put( pwmAboutProperty.name(), LocaleHelper.getLocalizedMessage( null, Display.Value_NotApplicable, null ) );
-                    LOGGER.trace( "error generating about value for '" + pwmAboutProperty.name() + "', error: " + t.getMessage() );
+                    LOGGER.trace( () -> "error generating about value for '" + pwmAboutProperty.name() + "', error: " + t.getMessage() );
                 }
             }
         }

+ 36 - 23
server/src/main/java/password/pwm/PwmApplication.java

@@ -99,7 +99,7 @@ import java.util.LinkedHashMap;
 import java.util.List;
 import java.util.Locale;
 import java.util.Map;
-import java.util.concurrent.Executor;
+import java.util.concurrent.ExecutorService;
 import java.util.concurrent.ScheduledExecutorService;
 import java.util.concurrent.ScheduledFuture;
 import java.util.concurrent.TimeUnit;
@@ -224,7 +224,7 @@ public class PwmApplication
                     break;
 
                 default:
-                    LOGGER.trace( "setting log level to TRACE because application mode is " + getApplicationMode() );
+                    LOGGER.trace( () -> "setting log level to TRACE because application mode is " + getApplicationMode() );
                     break;
             }
         }
@@ -344,11 +344,11 @@ public class PwmApplication
                 {
                     tempMap.put( entry.getKey().getKey(), entry.getValue() );
                 }
-                LOGGER.trace( "non-default app properties read from configuration: " + JsonUtil.serializeMap( tempMap ) );
+                LOGGER.trace( () -> "non-default app properties read from configuration: " + JsonUtil.serializeMap( tempMap ) );
             }
             else
             {
-                LOGGER.trace( "no non-default app properties in configuration" );
+                LOGGER.trace( () -> "no non-default app properties in configuration" );
             }
         }
 
@@ -369,7 +369,7 @@ public class PwmApplication
         try
         {
             final Map<PwmAboutProperty, String> infoMap = PwmAboutProperty.makeInfoBean( this );
-            LOGGER.trace( "application info: " + JsonUtil.serializeMap( infoMap ) );
+            LOGGER.trace( () ->  "application info: " + JsonUtil.serializeMap( infoMap ) );
         }
         catch ( Exception e )
         {
@@ -417,7 +417,7 @@ public class PwmApplication
             LOGGER.debug( "error initializing UserAgentUtils: " + e.getMessage() );
         }
 
-        LOGGER.trace( "completed post init tasks in " + TimeDuration.fromCurrent( startTime ).asCompactString() );
+        LOGGER.trace( () -> "completed post init tasks in " + TimeDuration.fromCurrent( startTime ).asCompactString() );
     }
 
     private static void outputKeystore( final PwmApplication pwmApplication ) throws Exception
@@ -426,7 +426,7 @@ public class PwmApplication
         final String keystoreFileString = applicationParams.get( PwmEnvironment.ApplicationParameter.AutoExportHttpsKeyStoreFile );
         if ( keystoreFileString != null && !keystoreFileString.isEmpty() )
         {
-            LOGGER.trace( "attempting to output keystore as configured by environment parameters to " + keystoreFileString );
+            LOGGER.trace( () -> "attempting to output keystore as configured by environment parameters to " + keystoreFileString );
             final File keyStoreFile = new File( keystoreFileString );
             final String password = applicationParams.get( PwmEnvironment.ApplicationParameter.AutoExportHttpsKeyStorePassword );
             final String alias = applicationParams.get( PwmEnvironment.ApplicationParameter.AutoExportHttpsKeyStoreAlias );
@@ -435,10 +435,10 @@ public class PwmApplication
             keyStore.store( outputContents, password.toCharArray() );
             if ( keyStoreFile.exists() )
             {
-                LOGGER.trace( "deleting existing keystore file " + keyStoreFile.getAbsolutePath() );
+                LOGGER.trace( () -> "deleting existing keystore file " + keyStoreFile.getAbsolutePath() );
                 if ( keyStoreFile.delete() )
                 {
-                    LOGGER.trace( "deleted existing keystore file: " + keyStoreFile.getAbsolutePath() );
+                    LOGGER.trace( () -> "deleted existing keystore file: " + keyStoreFile.getAbsolutePath() );
                 }
             }
 
@@ -457,7 +457,7 @@ public class PwmApplication
         final String tomcatOutputFileStr = applicationParams.get( PwmEnvironment.ApplicationParameter.AutoWriteTomcatConfOutputFile );
         if ( tomcatOutputFileStr != null && !tomcatOutputFileStr.isEmpty() )
         {
-            LOGGER.trace( "attempting to output tomcat configuration file as configured by environment parameters to " + tomcatOutputFileStr );
+            LOGGER.trace( () -> "attempting to output tomcat configuration file as configured by environment parameters to " + tomcatOutputFileStr );
             final File tomcatOutputFile = new File( tomcatOutputFileStr );
             final File tomcatSourceFile;
             {
@@ -487,10 +487,10 @@ public class PwmApplication
             );
             if ( tomcatOutputFile.exists() )
             {
-                LOGGER.trace( "deleting existing tomcat configuration file " + tomcatOutputFile.getAbsolutePath() );
+                LOGGER.trace( () -> "deleting existing tomcat configuration file " + tomcatOutputFile.getAbsolutePath() );
                 if ( tomcatOutputFile.delete() )
                 {
-                    LOGGER.trace( "deleted existing tomcat configuration file: " + tomcatOutputFile.getAbsolutePath() );
+                    LOGGER.trace( () -> "deleted existing tomcat configuration file: " + tomcatOutputFile.getAbsolutePath() );
                 }
             }
 
@@ -709,7 +709,8 @@ public class PwmApplication
         }
         else
         {
-            LOGGER.trace( "retrieved instanceID " + newInstanceID + "" + " from localDB" );
+            final String id = newInstanceID;
+            LOGGER.trace( () -> "retrieved instanceID " + id + "" + " from localDB" );
         }
 
         if ( newInstanceID.length() < 1 )
@@ -826,7 +827,7 @@ public class PwmApplication
         {
             try
             {
-                LOGGER.trace( "beginning close of LocalDB" );
+                LOGGER.trace( () -> "beginning close of LocalDB" );
                 localDB.close();
             }
             catch ( Exception e )
@@ -979,7 +980,7 @@ public class PwmApplication
         final File tempDirectory = new File( pwmEnvironment.getApplicationPath() + File.separator + "temp" );
         if ( !tempDirectory.exists() )
         {
-            LOGGER.trace( "preparing to create temporary directory " + tempDirectory.getAbsolutePath() );
+            LOGGER.trace( () -> "preparing to create temporary directory " + tempDirectory.getAbsolutePath() );
             if ( tempDirectory.mkdir() )
             {
                 LOGGER.debug( "created " + tempDirectory.getAbsolutePath() );
@@ -1024,20 +1025,30 @@ public class PwmApplication
 
     public ScheduledFuture scheduleFutureJob(
             final Runnable runnable,
-            final Executor executor,
+            final ExecutorService executor,
             final TimeDuration delay
     )
     {
+        if ( applicationExecutorService.isShutdown() )
+        {
+            return null;
+        }
+
         return applicationExecutorService.schedule(  new WrappedRunner( runnable, executor ), delay.asMillis(), TimeUnit.MILLISECONDS );
     }
 
     public void scheduleFixedRateJob(
             final Runnable runnable,
-            final Executor executor,
+            final ExecutorService executor,
             final TimeDuration initialDelay,
             final TimeDuration frequency
     )
     {
+        if ( applicationExecutorService.isShutdown() )
+        {
+            return;
+        }
+
         if ( initialDelay != null )
         {
             applicationExecutorService.schedule( new WrappedRunner( runnable, executor ), initialDelay.asMillis(), TimeUnit.MILLISECONDS );
@@ -1046,10 +1057,7 @@ public class PwmApplication
         final Runnable jobWithNextScheduler = () ->
         {
             new WrappedRunner( runnable, executor ).run();
-            if ( !applicationExecutorService.isShutdown() )
-            {
-                scheduleFixedRateJob( runnable, executor, null, frequency );
-            }
+            scheduleFixedRateJob( runnable, executor, null, frequency );
         };
 
         applicationExecutorService.schedule(  jobWithNextScheduler, frequency.asMillis(), TimeUnit.MILLISECONDS );
@@ -1058,9 +1066,9 @@ public class PwmApplication
     private static class WrappedRunner implements Runnable
     {
         private final Runnable runnable;
-        private final Executor executor;
+        private final ExecutorService executor;
 
-        WrappedRunner( final Runnable runnable, final Executor executor )
+        WrappedRunner( final Runnable runnable, final ExecutorService executor )
         {
             this.runnable = runnable;
             this.executor = executor;
@@ -1069,6 +1077,11 @@ public class PwmApplication
         @Override
         public void run()
         {
+            if ( executor.isShutdown() )
+            {
+                return;
+            }
+
             try
             {
                 executor.execute( runnable );

+ 3 - 3
server/src/main/java/password/pwm/PwmEnvironment.java

@@ -234,7 +234,7 @@ public class PwmEnvironment
         }
         if ( applicationPathIsWebInfPath )
         {
-            LOGGER.trace( "applicationPath appears to be servlet /WEB-INF directory" );
+            LOGGER.trace( () -> "applicationPath appears to be servlet /WEB-INF directory" );
         }
     }
 
@@ -263,7 +263,7 @@ public class PwmEnvironment
             );
         }
 
-        LOGGER.trace( "examining applicationPath of " + applicationPath.getAbsolutePath() + "" );
+        LOGGER.trace( () -> "examining applicationPath of " + applicationPath.getAbsolutePath() + "" );
 
         if ( !applicationPath.exists() )
         {
@@ -290,7 +290,7 @@ public class PwmEnvironment
         }
 
         final File infoFile = new File( applicationPath.getAbsolutePath() + File.separator + PwmConstants.APPLICATION_PATH_INFO_FILE );
-        LOGGER.trace( "checking " + infoFile.getAbsolutePath() + " status" );
+        LOGGER.trace( () -> "checking " + infoFile.getAbsolutePath() + " status" );
         if ( infoFile.exists() )
         {
             final String errorMsg = "The file " + infoFile.getAbsolutePath() + " exists, and an applicationPath was not explicitly specified."

+ 5 - 4
server/src/main/java/password/pwm/config/Configuration.java

@@ -94,6 +94,7 @@ import java.util.Locale;
 import java.util.Map;
 import java.util.Set;
 import java.util.TreeMap;
+import java.util.function.Supplier;
 
 /**
  * @author Jason D. Rivard
@@ -126,18 +127,18 @@ public class Configuration implements SettingReader
     public void outputToLog( )
     {
         final Map<String, String> debugStrings = storedConfiguration.getModifiedSettingDebugValues( PwmConstants.DEFAULT_LOCALE, true );
-        final List<String> outputStrings = new ArrayList<>();
+        final List<Supplier<CharSequence>> outputStrings = new ArrayList<>();
 
         for ( final Map.Entry<String, String> entry : debugStrings.entrySet() )
         {
             final String spacedValue = entry.getValue().replace( "\n", "\n   " );
             final String output = " " + entry.getKey() + "\n   " + spacedValue + "\n";
-            outputStrings.add( output );
+            outputStrings.add( () -> output );
         }
 
-        LOGGER.trace( "--begin current configuration output--" );
+        LOGGER.trace( () -> "--begin current configuration output--" );
         outputStrings.forEach( LOGGER::trace );
-        LOGGER.trace( "--end current configuration output--" );
+        LOGGER.trace( () -> "--end current configuration output--" );
     }
 
     public List<FormConfiguration> readSettingAsForm( final PwmSetting setting )

+ 2 - 2
server/src/main/java/password/pwm/config/PwmSettingXml.java

@@ -75,7 +75,7 @@ public class PwmSettingXml
                 final Instant startTime = Instant.now();
                 final Document newDoc = builder.build( inputStream );
                 final TimeDuration parseDuration = TimeDuration.fromCurrent( startTime );
-                LOGGER.trace( "parsed PwmSettingXml in " + parseDuration.toString() + ", loads=" + LOAD_COUNTER.getAndIncrement() );
+                LOGGER.trace( () -> "parsed PwmSettingXml in " + parseDuration.toString() + ", loads=" + LOAD_COUNTER.getAndIncrement() );
 
                 xmlDocCache = newDoc;
 
@@ -93,7 +93,7 @@ public class PwmSettingXml
                         {
                             //ignored
                         }
-                        LOGGER.trace( "cached PwmSettingXml discarded" );
+                        LOGGER.trace( () -> "cached PwmSettingXml discarded" );
                         xmlDocCache = null;
                     }
                 };

+ 2 - 2
server/src/main/java/password/pwm/config/profile/ChallengeProfile.java

@@ -102,7 +102,7 @@ public class ChallengeProfile implements Profile, Serializable
         }
         catch ( PwmOperationalException e )
         {
-            LOGGER.trace( "configured challengeSet for profile '" + profileID + "' is not valid: " + e.getMessage() );
+            LOGGER.trace( () -> "configured challengeSet for profile '" + profileID + "' is not valid: " + e.getMessage() );
         }
 
         ChallengeSet readHelpdeskChallengeSet = null;
@@ -119,7 +119,7 @@ public class ChallengeProfile implements Profile, Serializable
         }
         catch ( PwmOperationalException e )
         {
-            LOGGER.trace( "discarding configured helpdesk challengeSet for profile '" + profileID + "' issue: " + e.getMessage() );
+            LOGGER.trace( () -> "discarding configured helpdesk challengeSet for profile '" + profileID + "' issue: " + e.getMessage() );
         }
 
         final int minRandomSetup = ( int ) Configuration.JavaTypeConverter.valueToLong( storedConfiguration.readSetting( PwmSetting.CHALLENGE_MIN_RANDOM_SETUP, profileID ) );

+ 4 - 1
server/src/main/java/password/pwm/config/profile/LdapProfile.java

@@ -169,7 +169,10 @@ public class LdapProfile extends AbstractProfile implements Profile
                     pwmApplication.getCacheService().put( cacheKey, cachePolicy, canonicalValue );
                 }
 
-                LOGGER.trace( "read and cached canonical ldap DN value for input '" + dnValue + "' as '" + canonicalValue + "'" );
+                {
+                    final String finalCanonical = canonicalValue;
+                    LOGGER.trace( () -> "read and cached canonical ldap DN value for input '" + dnValue + "' as '" + finalCanonical + "'" );
+                }
             }
             catch ( ChaiUnavailableException | ChaiOperationException e )
             {

+ 1 - 1
server/src/main/java/password/pwm/config/stored/ConfigurationReader.java

@@ -263,7 +263,7 @@ public class ConfigurationReader
                 pwmApplication.writeAppAttribute( PwmApplication.AppAttribute.CONFIG_HASH, actualChecksum );
             }
 
-            LOGGER.trace( "renaming file " + tempWriteFile.getAbsolutePath() + " to " + configFile.getAbsolutePath() );
+            LOGGER.trace( () -> "renaming file " + tempWriteFile.getAbsolutePath() + " to " + configFile.getAbsolutePath() );
             try
             {
                 Files.move( tempWriteFile.toPath(), configFile.toPath(), StandardCopyOption.REPLACE_EXISTING, StandardCopyOption.ATOMIC_MOVE );

+ 2 - 2
server/src/main/java/password/pwm/config/stored/NGStoredConfigurationFactory.java

@@ -148,7 +148,7 @@ public class NGStoredConfigurationFactory
             }
             else
             {
-                LOGGER.trace( "parsing setting key=" + key + ", profile=" + storedConfigReference.getProfileID() );
+                LOGGER.trace( () -> "parsing setting key=" + key + ", profile=" + storedConfigReference.getProfileID() );
                 if ( settingElement.getChild( StoredConfiguration.XML_ELEMENT_DEFAULT ) != null )
                 {
                     try
@@ -171,7 +171,7 @@ public class NGStoredConfigurationFactory
         {
             final String key = storedConfigReference.getRecordID();
 
-            LOGGER.trace( "parsing property key=" + key + ", profile=" + storedConfigReference.getProfileID() );
+            LOGGER.trace( () -> "parsing property key=" + key + ", profile=" + storedConfigReference.getProfileID() );
             if ( settingElement.getChild( StoredConfiguration.XML_ELEMENT_DEFAULT ) != null )
             {
                 return new StringValue( settingElement.getValue() );

+ 2 - 2
server/src/main/java/password/pwm/config/stored/StoredConfigurationImpl.java

@@ -625,7 +625,7 @@ public class StoredConfigurationImpl implements StoredConfiguration
             }
         }
 
-        LOGGER.trace( "StoredConfiguration validator completed in " + TimeDuration.fromCurrent( startTime ).asCompactString() );
+        LOGGER.trace( () -> "StoredConfiguration validator completed in " + TimeDuration.fromCurrent( startTime ).asCompactString() );
         return errorStrings;
     }
 
@@ -1017,7 +1017,7 @@ public class StoredConfigurationImpl implements StoredConfiguration
 
 
         final String result = SecureEngine.hash( sb.toString(), PwmConstants.SETTING_CHECKSUM_HASH_METHOD );
-        LOGGER.trace( "computed setting checksum in " + TimeDuration.fromCurrent( startTime ).asCompactString() );
+        LOGGER.trace( () -> "computed setting checksum in " + TimeDuration.fromCurrent( startTime ).asCompactString() );
         return result;
     }
 

+ 1 - 1
server/src/main/java/password/pwm/config/value/FileValue.java

@@ -241,7 +241,7 @@ public class FileValue extends AbstractValue implements StoredValue
             }
             catch ( PwmUnrecoverableException e )
             {
-                LOGGER.trace( "error generating file hash" );
+                LOGGER.trace( () -> "error generating file hash" );
             }
             output.add( details );
         }

+ 2 - 2
server/src/main/java/password/pwm/health/HealthMonitor.java

@@ -216,7 +216,7 @@ public class HealthMonitor implements PwmService
         }
 
         final Instant startTime = Instant.now();
-        LOGGER.trace( "beginning background health check process" );
+        LOGGER.trace( () -> "beginning background health check process" );
         final List<HealthRecord> tempResults = new ArrayList<>();
         for ( final HealthChecker loopChecker : HEALTH_CHECKERS )
         {
@@ -257,7 +257,7 @@ public class HealthMonitor implements PwmService
         healthRecords.clear();
         healthRecords.addAll( tempResults );
         lastHealthCheckTime = Instant.now();
-        LOGGER.trace( "health check process completed (" + TimeDuration.fromCurrent( startTime ).asCompactString() + ")" );
+        LOGGER.trace( () -> "health check process completed (" + TimeDuration.compactFromCurrent( startTime ) + ")" );
     }
 
     public ServiceInfoBean serviceInfo( )

+ 2 - 2
server/src/main/java/password/pwm/http/ContextManager.java

@@ -466,7 +466,7 @@ public class ContextManager implements Serializable
                 return;
             }
 
-            LOGGER.trace( "waiting up to " + maxRequestWaitTime.asCompactString()
+            LOGGER.trace( () -> "waiting up to " + maxRequestWaitTime.asCompactString()
                     + " for " + startingRequetsInProgress  + " requests to complete." );
             JavaHelper.pause(
                     maxRequestWaitTime.asMillis(),
@@ -476,7 +476,7 @@ public class ContextManager implements Serializable
 
             final int requestsInPrgoress = pwmApplication.getInprogressRequests().get();
             final TimeDuration waitTime = TimeDuration.fromCurrent( startTime  );
-            LOGGER.trace( "after " + waitTime.asCompactString() + ", " + requestsInPrgoress
+            LOGGER.trace( () -> "after " + waitTime.asCompactString() + ", " + requestsInPrgoress
                     + " requests in progress, proceeding with restart" );
         }
     }

+ 2 - 2
server/src/main/java/password/pwm/http/HttpEventManager.java

@@ -67,7 +67,7 @@ public class HttpEventManager implements
                 pwmApplication.getStatisticsManager().updateEps( EpsStatistic.SESSIONS, 1 );
             }
 
-            LOGGER.trace( "new http session created" );
+            LOGGER.trace( () -> "new http session created" );
         }
         catch ( PwmUnrecoverableException e )
         {
@@ -96,7 +96,7 @@ public class HttpEventManager implements
             }
             else
             {
-                LOGGER.trace( "invalidated uninitialized session" );
+                LOGGER.trace( () -> "invalidated uninitialized session" );
             }
         }
         catch ( PwmUnrecoverableException e )

+ 1 - 1
server/src/main/java/password/pwm/http/filter/AuthenticationFilter.java

@@ -359,7 +359,7 @@ public class AuthenticationFilter extends AbstractPwmFilter
                 }
                 catch ( Exception e )
                 {
-                    LOGGER.trace( "could not load authentication class '" + authenticationMethod + "', will ignore" );
+                    LOGGER.trace( () -> "could not load authentication class '" + authenticationMethod + "', will ignore" );
                     IGNORED_AUTH_METHODS.add( authenticationMethod );
                 }
 

+ 2 - 5
server/src/main/java/password/pwm/http/filter/ConfigAccessFilter.java

@@ -154,7 +154,7 @@ public class ConfigAccessFilter extends AbstractPwmFilter
                     {
                             errorMsg,
                     }
-                    );
+            );
             return denyAndError( pwmRequest, errorInformation );
         }
 
@@ -287,10 +287,7 @@ public class ConfigAccessFilter extends AbstractPwmFilter
             return ProcessStatus.Continue;
         }
 
-        if ( configManagerBean.getPrePasswordEntryUrl() == null )
-        {
-            configManagerBean.setPrePasswordEntryUrl( pwmRequest.getHttpServletRequest().getRequestURL().toString() );
-        }
+        configManagerBean.setPrePasswordEntryUrl( pwmRequest.getHttpServletRequest().getRequestURL().toString() );
 
         forwardToJsp( pwmRequest );
         return ProcessStatus.Halt;

+ 1 - 1
server/src/main/java/password/pwm/http/filter/RequestInitializationFilter.java

@@ -494,7 +494,7 @@ public class RequestInitializationFilter implements Filter
         }
         catch ( UnknownHostException e )
         {
-            LOGGER.trace( "unknown host while trying to compute hostname for src request: " + e.getMessage() );
+            LOGGER.trace( () -> "unknown host while trying to compute hostname for src request: " + e.getMessage() );
         }
         return "";
     }

+ 1 - 1
server/src/main/java/password/pwm/http/servlet/ShortcutServlet.java

@@ -178,7 +178,7 @@ public class ShortcutServlet extends AbstractPwmServlet
 
         if ( !labelsFromHeader.isEmpty() )
         {
-            LOGGER.trace( "detected the following labels from headers: " + StringHelper.stringCollectionToString( labelsFromHeader, "," ) );
+            LOGGER.trace( () -> "detected the following labels from headers: " + StringHelper.stringCollectionToString( labelsFromHeader, "," ) );
             visibleItems.keySet().retainAll( labelsFromHeader );
         }
         else

+ 2 - 2
server/src/main/java/password/pwm/http/servlet/admin/AppDashboardData.java

@@ -168,7 +168,7 @@ public class AppDashboardData implements Serializable
         builder.sessionCount( pwmApplication.getSessionTrackService().sessionCount() );
         builder.requestsInProgress( pwmApplication.getInprogressRequests().get() );
 
-        LOGGER.trace( "AppDashboardData bean created in " + TimeDuration.compactFromCurrent( startTime ) );
+        LOGGER.trace( () -> "AppDashboardData bean created in " + TimeDuration.compactFromCurrent( startTime ) );
         return builder.build();
     }
 
@@ -549,7 +549,7 @@ public class AppDashboardData implements Serializable
         }
         catch ( PwmUnrecoverableException e )
         {
-            LOGGER.trace( "error building AppDashboardData node-state: " + e.getMessage() );
+            LOGGER.trace( () -> "error building AppDashboardData node-state: " + e.getMessage() );
         }
 
         return Collections.unmodifiableList( nodeData );

+ 1 - 1
server/src/main/java/password/pwm/http/servlet/command/CommandServlet.java

@@ -107,7 +107,7 @@ public abstract class CommandServlet extends ControlledPwmServlet
         try
         {
             final Map<String, Object> map = JsonUtil.deserializeStringObjectMap( body );
-            LOGGER.trace( "CSP Report: " + JsonUtil.serializeMap( map, JsonUtil.Flag.PrettyPrint ) );
+            LOGGER.trace( () -> "CSP Report: " + JsonUtil.serializeMap( map, JsonUtil.Flag.PrettyPrint ) );
         }
         catch ( Exception e )
         {

+ 2 - 2
server/src/main/java/password/pwm/http/servlet/configeditor/ConfigEditorServlet.java

@@ -536,7 +536,7 @@ public class ConfigEditorServlet extends ControlledPwmServlet
                     final String value = JsonUtil.deserialize( bodyString, String.class );
                     configManagerBean.getStoredConfiguration().writeConfigProperty( ConfigurationProperty.NOTES,
                             value );
-                    LOGGER.trace( "updated notesText" );
+                    LOGGER.trace( () -> "updated notesText" );
                 }
                 catch ( Exception e )
                 {
@@ -552,7 +552,7 @@ public class ConfigEditorServlet extends ControlledPwmServlet
                         final PwmSettingTemplate template = PwmSettingTemplate.valueOf( requestedTemplate );
                         configManagerBean.getStoredConfiguration().writeConfigProperty(
                                 ConfigurationProperty.LDAP_TEMPLATE, template.toString() );
-                        LOGGER.trace( "setting template to: " + requestedTemplate );
+                        LOGGER.trace( () -> "setting template to: " + requestedTemplate );
                     }
                     catch ( IllegalArgumentException e )
                     {

+ 5 - 1
server/src/main/java/password/pwm/http/servlet/configguide/ConfigGuideServlet.java

@@ -509,7 +509,11 @@ public class ConfigGuideServlet extends ControlledPwmServlet
         {
             configGuideBean.setStep( step );
             pwmRequest.outputJsonResult( RestResultBean.forSuccessMessage( pwmRequest, Message.Success_Unknown ) );
-            LOGGER.trace( "setting current step to: " + step );
+
+            {
+                final GuideStep finalStep = step;
+                LOGGER.trace( () -> "setting current step to: " + finalStep );
+            }
         }
 
         return ProcessStatus.Continue;

+ 6 - 2
server/src/main/java/password/pwm/http/servlet/configmanager/DebugItemGenerator.java

@@ -491,7 +491,7 @@ public class DebugItemGenerator
                     }
                     catch ( Exception e )
                     {
-                        LOGGER.trace( "error generating file summary info: " + e.getMessage() );
+                        LOGGER.trace( () -> "error generating file summary info: " + e.getMessage() );
                     }
                 }
                 csvPrinter.flush();
@@ -537,7 +537,11 @@ public class DebugItemGenerator
                     outputStream.flush();
                 }
             }
-            LOGGER.trace( "output " + counter + " lines to " + this.getFilename() );
+
+            {
+                final int finalCounter = counter;
+                LOGGER.trace( () -> "output " + finalCounter + " lines to " + this.getFilename() );
+            }
         }
     }
 

+ 1 - 1
server/src/main/java/password/pwm/http/servlet/helpdesk/HelpdeskVerificationOptionsBean.java

@@ -120,7 +120,7 @@ public class HelpdeskVerificationOptionsBean implements Serializable
                 }
                 catch ( PwmUnrecoverableException e )
                 {
-                    LOGGER.trace( "error while calculating available token methods: " + e.getMessage() );
+                    LOGGER.trace( () -> "error while calculating available token methods: " + e.getMessage() );
                 }
             }
             tokenDestinations = Collections.unmodifiableList( TokenDestinationItem.stripValues( returnList ) );

+ 1 - 1
server/src/main/java/password/pwm/http/servlet/newuser/NewUserServlet.java

@@ -159,7 +159,7 @@ public class NewUserServlet extends ControlledPwmServlet
         if ( !StringUtil.isEmpty( signedFormData ) )
         {
             final Map<String, String> jsonForm = RestFormSigningServer.readSignedFormValue( pwmApplication, signedFormData );
-            LOGGER.trace( "detected signedForm parameter in request, will read and place in bean; keys=" + JsonUtil.serializeCollection( jsonForm.keySet() ) );
+            LOGGER.trace( () -> "detected signedForm parameter in request, will read and place in bean; keys=" + JsonUtil.serializeCollection( jsonForm.keySet() ) );
             newUserBean.setRemoteInputData( jsonForm );
         }
 

+ 1 - 1
server/src/main/java/password/pwm/http/servlet/oauth/OAuthMachine.java

@@ -326,7 +326,7 @@ public class OAuthMachine
             }
         }
 
-        LOGGER.trace( "calculated oauth self end point URI as '" + redirectUri + "' using method " + debugSource );
+        LOGGER.trace( () -> "calculated oauth self end point URI as '" + redirectUri + "' using method " + debugSource );
         return redirectUri;
     }
 

+ 5 - 2
server/src/main/java/password/pwm/http/servlet/resource/ResourceServletConfiguration.java

@@ -69,7 +69,7 @@ class ResourceServletConfiguration
 
     private ResourceServletConfiguration( final PwmApplication pwmApplication )
     {
-        LOGGER.trace( "initializing" );
+        LOGGER.trace( () -> "initializing" );
         final Configuration configuration = pwmApplication.getConfig();
         maxCacheItems = Integer.parseInt( configuration.readAppProperty( AppProperty.HTTP_RESOURCES_MAX_CACHE_ITEMS ) );
         cacheExpireSeconds = Long.parseLong( configuration.readAppProperty( AppProperty.HTTP_RESOURCES_EXPIRATION_SECONDS ) );
@@ -210,7 +210,10 @@ class ResourceServletConfiguration
                 IOUtils.copy( stream, byteArrayOutputStream );
                 final ImmutableByteArray contents = new ImmutableByteArray( byteArrayOutputStream.toByteArray() );
                 memoryMap.put( name, new MemoryFileResource( name, contents, lastModified ) );
-                LOGGER.trace( "discovered file in configured resource bundle: " + entry.getName() );
+                {
+                    final String finalEntry = entry.getName();
+                    LOGGER.trace( () -> "discovered file in configured resource bundle: " + finalEntry );
+                }
             }
         }
         return memoryMap;

+ 1 - 1
server/src/main/java/password/pwm/http/state/SessionStateService.java

@@ -109,7 +109,7 @@ public class SessionStateService implements PwmService
         }
 
 
-        LOGGER.trace( "initialized " + sessionBeanProvider.getClass().getName() + " provider" );
+        LOGGER.trace( () -> "initialized " + sessionBeanProvider.getClass().getName() + " provider" );
     }
 
     @Override

+ 2 - 2
server/src/main/java/password/pwm/ldap/LdapConnectionService.java

@@ -79,7 +79,7 @@ public class LdapConnectionService implements PwmService
         this.lastLdapErrors.putAll( readLastLdapFailure( pwmApplication ) );
 
         final int connectionsPerProfile = maxSlotsPerProfile( pwmApplication );
-        LOGGER.trace( "allocating " + connectionsPerProfile + " ldap proxy connections per profile" );
+        LOGGER.trace( () -> "allocating " + connectionsPerProfile + " ldap proxy connections per profile" );
         slotIncrementer = new AtomicLoopIntIncrementer( connectionsPerProfile );
 
         for ( final LdapProfile ldapProfile : pwmApplication.getConfig().getLdapProfiles().values() )
@@ -93,7 +93,7 @@ public class LdapConnectionService implements PwmService
     public void close( )
     {
         status = STATUS.CLOSED;
-        LOGGER.trace( "closing ldap proxy connections" );
+        LOGGER.trace( () -> "closing ldap proxy connections" );
         if ( chaiProviderFactory != null )
         {
             try

+ 1 - 1
server/src/main/java/password/pwm/ldap/LdapOperationsHelper.java

@@ -231,7 +231,7 @@ public class LdapOperationsHelper
             {
                 if ( ldapProfile.readSettingAsBoolean( PwmSetting.LDAP_GUID_AUTO_ADD ) )
                 {
-                    LOGGER.trace( "assigning new GUID to user " + userIdentity );
+                    LOGGER.trace( () -> "assigning new GUID to user " + userIdentity );
                     return GUIDHelper.assignGuidToUser( pwmApplication, sessionLabel, userIdentity, guidAttributeName );
                 }
             }

+ 2 - 2
server/src/main/java/password/pwm/ldap/PasswordChangeProgressChecker.java

@@ -361,7 +361,7 @@ public class PasswordChangeProgressChecker
                     pwmSession, userIdentity );
             if ( checkResults.size() <= 1 )
             {
-                LOGGER.trace( "only one replica returned data, marking as complete" );
+                LOGGER.trace( () -> "only one replica returned data, marking as complete" );
                 return completedReplicationRecord;
             }
             else
@@ -381,7 +381,7 @@ public class PasswordChangeProgressChecker
                 }
                 final Percent pctComplete = new Percent( duplicateValues + 1, checkResults.size() );
                 final ProgressRecord progressRecord = makeReplicaProgressRecord( pctComplete );
-                LOGGER.trace( "read password replication sync status as: " + JsonUtil.serialize( progressRecord ) );
+                LOGGER.trace( () -> "read password replication sync status as: " + JsonUtil.serialize( progressRecord ) );
                 return progressRecord;
             }
         }

+ 8 - 7
server/src/main/java/password/pwm/svc/PwmServiceManager.java

@@ -87,7 +87,10 @@ public class PwmServiceManager
         initialized = true;
 
         final TimeDuration timeDuration = TimeDuration.fromCurrent( startTime );
-        LOGGER.trace( "started " + serviceCounter + " services in " + timeDuration.asCompactString() );
+        {
+            final int finalServiceCounter = serviceCounter;
+            LOGGER.trace( () -> "started " + finalServiceCounter + " services in " + timeDuration.asCompactString() );
+        }
     }
 
     private PwmService initService( final Class<? extends PwmService> serviceClass )
@@ -139,7 +142,7 @@ public class PwmServiceManager
             return;
         }
 
-        LOGGER.trace( "beginning to close all services" );
+        LOGGER.trace( () -> "beginning to close all services" );
         final Instant startTime = Instant.now();
 
 
@@ -154,22 +157,20 @@ public class PwmServiceManager
         }
         initialized = false;
 
-        final TimeDuration timeDuration = TimeDuration.fromCurrent( startTime );
-        LOGGER.trace( "closed all services in " + timeDuration.asCompactString() );
-
+        LOGGER.trace( () -> "closed all services in " + TimeDuration.compactFromCurrent( startTime ) );
     }
 
     private void shutDownService( final Class<? extends PwmService> serviceClass )
     {
 
-        LOGGER.trace( "closing service " + serviceClass.getName() );
+        LOGGER.trace( () -> "closing service " + serviceClass.getName() );
         final PwmService loopService = runningServices.get( serviceClass );
         try
         {
             final Instant startTime = Instant.now();
             loopService.close();
             final TimeDuration timeDuration = TimeDuration.fromCurrent( startTime );
-            LOGGER.trace( "successfully closed service " + serviceClass.getName() + " (" + timeDuration.asCompactString() + ")" );
+            LOGGER.trace( () -> "successfully closed service " + serviceClass.getName() + " (" + timeDuration.asCompactString() + ")" );
         }
         catch ( Exception e )
         {

+ 1 - 1
server/src/main/java/password/pwm/svc/cache/CacheService.java

@@ -196,6 +196,6 @@ public class CacheService implements PwmService
             traceOutput.append( ", histogram=" );
             traceOutput.append( JsonUtil.serializeMap( memoryCacheStore.storedClassHistogram( "" ) ) );
         }
-        LOGGER.trace( traceOutput );
+        LOGGER.trace( () -> traceOutput );
     }
 }

+ 2 - 2
server/src/main/java/password/pwm/svc/cluster/ClusterService.java

@@ -79,7 +79,7 @@ public class ClusterService implements PwmService
                 {
                     case DB:
                     {
-                        LOGGER.trace( "starting database-backed cluster provider" );
+                        LOGGER.trace( () -> "starting database-backed cluster provider" );
                         clusterSettings = ClusterSettings.fromConfigForDB( pwmApplication.getConfig() );
                         clusterDataServiceProvider = new DatabaseClusterDataService( pwmApplication );
                     }
@@ -87,7 +87,7 @@ public class ClusterService implements PwmService
 
                     case LDAP:
                     {
-                        LOGGER.trace( "starting ldap-backed cluster provider" );
+                        LOGGER.trace( () -> "starting ldap-backed cluster provider" );
                         clusterSettings = ClusterSettings.fromConfigForLDAP( pwmApplication.getConfig() );
                         clusterDataServiceProvider = new LDAPClusterDataService( pwmApplication );
                     }

+ 2 - 2
server/src/main/java/password/pwm/svc/email/EmailServerUtil.java

@@ -189,7 +189,7 @@ public class EmailServerUtil
                 final Optional<IOException> optionalIoException = JavaHelper.extractNestedExceptionType( e, IOException.class );
                 if ( optionalIoException.isPresent() )
                 {
-                    LOGGER.trace( "message send failure cause is due to an I/O error: " + optionalIoException.get().getMessage() );
+                    LOGGER.trace( () -> "message send failure cause is due to an I/O error: " + optionalIoException.get().getMessage() );
                     return true;
                 }
             }
@@ -200,7 +200,7 @@ public class EmailServerUtil
                 {
                     final SMTPSendFailedException smtpSendFailedException = optionalSmtpSendFailedException.get();
                     final int returnCode = smtpSendFailedException.getReturnCode();
-                    LOGGER.trace( "message send failure cause is due to server response code: " + returnCode );
+                    LOGGER.trace( () -> "message send failure cause is due to server response code: " + returnCode );
                     if ( retyableStatusCodes.contains( returnCode ) )
                     {
                         return true;

+ 4 - 4
server/src/main/java/password/pwm/svc/email/EmailService.java

@@ -356,13 +356,13 @@ public class EmailService implements PwmService
             if ( threadLocalTransport.get() == null )
             {
 
-                LOGGER.trace( "initializing new threadLocal transport, stats: " + stats() );
+                LOGGER.trace( () -> "initializing new threadLocal transport, stats: " + stats() );
                 threadLocalTransport.set( getSmtpTransport( ) );
                 newThreadLocalTransport.getAndIncrement();
             }
             else
             {
-                LOGGER.trace( "using existing threadLocal transport, stats: " + stats() );
+                LOGGER.trace( () -> "using existing threadLocal transport, stats: " + stats() );
                 useExistingTransport.getAndIncrement();
             }
 
@@ -370,14 +370,14 @@ public class EmailService implements PwmService
 
             if ( !serverTransport.getTransport().isConnected() )
             {
-                LOGGER.trace( "connecting threadLocal transport, stats: " + stats() );
+                LOGGER.trace( () -> "connecting threadLocal transport, stats: " + stats() );
                 threadLocalTransport.set( getSmtpTransport( ) );
                 serverTransport = threadLocalTransport.get();
                 newConnectionCounter.getAndIncrement();
             }
             else
             {
-                LOGGER.trace( "using existing threadLocal: stats: " + stats() );
+                LOGGER.trace( () -> "using existing threadLocal: stats: " + stats() );
                 useExistingConnection.getAndIncrement();
             }
 

+ 1 - 1
server/src/main/java/password/pwm/svc/event/AuditService.java

@@ -393,7 +393,7 @@ public class AuditService implements PwmService
                 }
                 else
                 {
-                    LOGGER.trace( "skipping update of user history, audit record does not have a perpetratorDN: " + JsonUtil.serialize( auditRecord ) );
+                    LOGGER.trace( () -> "skipping update of user history, audit record does not have a perpetratorDN: " + JsonUtil.serialize( auditRecord ) );
                 }
             }
         }

+ 1 - 1
server/src/main/java/password/pwm/svc/event/LdapXmlUserHistory.java

@@ -199,7 +199,7 @@ class LdapXmlUserHistory implements UserHistoryStore
 
         if ( corAttribute == null || corAttribute.length() < 1 )
         {
-            LOGGER.trace( "no user event log attribute configured, skipping read of log data" );
+            LOGGER.trace( () -> "no user event log attribute configured, skipping read of log data" );
             return new StoredHistory();
         }
 

+ 2 - 2
server/src/main/java/password/pwm/svc/event/SyslogAuditService.java

@@ -131,7 +131,7 @@ public class SyslogAuditService
                 final SyslogIF syslogInstance = makeSyslogInstance( syslogCfg );
                 syslogInstances.add( syslogInstance );
             }
-            LOGGER.trace( "queued service running for syslog entries" );
+            LOGGER.trace( () -> "queued service running for syslog entries" );
         }
         catch ( IllegalArgumentException e )
         {
@@ -275,7 +275,7 @@ public class SyslogAuditService
             try
             {
                 syslogInstance.info( auditRecord );
-                LOGGER.trace( "delivered syslog audit event: " + auditRecord );
+                LOGGER.trace( () -> "delivered syslog audit event: " + auditRecord );
                 lastError = null;
                 StatisticsManager.incrementStat( this.pwmApplication, Statistic.SYSLOG_MESSAGES_SENT );
                 return WorkQueueProcessor.ProcessResult.SUCCESS;

+ 9 - 18
server/src/main/java/password/pwm/svc/intruder/DataStoreRecordStore.java

@@ -180,7 +180,7 @@ class DataStoreRecordStore implements RecordStore
         }
         eldestRecord = Instant.now();
 
-        final long startTime = System.currentTimeMillis();
+        final Instant startTime = Instant.now();
         final int recordsExamined = 0;
         int recordsRemoved = 0;
 
@@ -208,17 +208,19 @@ class DataStoreRecordStore implements RecordStore
             recordsRemoved += recordsToRemove.size();
             recordsToRemove.clear();
         }
-        final TimeDuration totalDuration = TimeDuration.fromCurrent( startTime );
-        LOGGER.trace( "completed cleanup of intruder table in " + totalDuration.asCompactString() + ", recordsExamined=" + recordsExamined + ", recordsRemoved=" + recordsRemoved );
+        {
+            final int finalRemoved = recordsRemoved;
+            LOGGER.trace( () -> "completed cleanup of intruder table in "
+                    + TimeDuration.compactFromCurrent( startTime ) + ", recordsExamined="
+                    + recordsExamined + ", recordsRemoved=" + finalRemoved );
+        }
     }
 
     private List<String> discoverPurgableKeys( final TimeDuration maxRecordAge )
     {
         final List<String> recordsToRemove = new ArrayList<>();
-        ClosableIterator<String> dbIterator = null;
-        try
+        try ( ClosableIterator<String> dbIterator = dataStore.iterator() )
         {
-            dbIterator = dataStore.iterator();
             while ( intruderManager.status() == PwmService.STATUS.OPEN && dbIterator.hasNext() && recordsToRemove.size() < MAX_REMOVALS_PER_CYCLE )
             {
                 final String key = dbIterator.next();
@@ -236,21 +238,10 @@ class DataStoreRecordStore implements RecordStore
                 }
             }
         }
-        catch ( PwmDataStoreException e )
+        catch ( PwmDataStoreException | PwmUnrecoverableException e )
         {
             LOGGER.error( "unable to perform intruder table cleanup: " + e.getMessage() );
         }
-        catch ( PwmUnrecoverableException e )
-        {
-            LOGGER.error( "unable to perform intruder table cleanup: " + e.getMessage() );
-        }
-        finally
-        {
-            if ( dbIterator != null )
-            {
-                dbIterator.close();
-            }
-        }
         return recordsToRemove;
     }
 }

+ 3 - 3
server/src/main/java/password/pwm/svc/report/ReportService.java

@@ -432,7 +432,7 @@ public class ReportService implements PwmService
                 throws ChaiUnavailableException, ChaiOperationException, PwmUnrecoverableException, PwmOperationalException
         {
             final Instant startTime = Instant.now();
-            LOGGER.trace( "beginning ldap search process" );
+            LOGGER.trace( () -> "beginning ldap search process" );
 
             resetJobStatus();
             clearWorkQueue();
@@ -445,7 +445,7 @@ public class ReportService implements PwmService
             );
 
 
-            LOGGER.trace( "completed ldap search process, transferring search results to work queue" );
+            LOGGER.trace( () -> "completed ldap search process, transferring search results to work queue" );
 
             final TransactionSizeCalculator transactionCalculator = new TransactionSizeCalculator(
                     TransactionSizeCalculator.Settings.builder()
@@ -467,7 +467,7 @@ public class ReportService implements PwmService
                 dnQueue.addAll( bufferList );
                 transactionCalculator.recordLastTransactionDuration( TimeDuration.fromCurrent( loopStart ) );
             }
-            LOGGER.trace( "completed transfer of ldap search results to work queue in " + TimeDuration.fromCurrent( startTime ).asCompactString() );
+            LOGGER.trace( () -> "completed transfer of ldap search results to work queue in " + TimeDuration.fromCurrent( startTime ).asCompactString() );
         }
     }
 

+ 6 - 2
server/src/main/java/password/pwm/svc/report/UserCacheService.java

@@ -84,8 +84,12 @@ public class UserCacheService implements PwmService
         {
             LOGGER.error( "unable to store user status cache to localdb: " + e.getMessage() );
         }
-        LOGGER.trace( "updateCache: " + ( preExisting ? "updated existing" : "created new" ) + " user cache for "
-                + userInfo.getUserIdentity() + " user key " + storageKey.getKey() );
+
+        {
+            final boolean finalPreExisting = preExisting;
+            LOGGER.trace( () -> "updateCache: " + ( finalPreExisting ? "updated existing" : "created new" ) + " user cache for "
+                    + userInfo.getUserIdentity() + " user key " + storageKey.getKey() );
+        }
         return null;
     }
 

+ 2 - 2
server/src/main/java/password/pwm/svc/stats/StatisticsBundle.java

@@ -134,7 +134,7 @@ public class StatisticsBundle
             }
             catch ( Exception e )
             {
-                LOGGER.trace( "unable to parse statistics value for stat " + statistic.toString() + ", value=" + avgStrValue );
+                LOGGER.trace( () -> "unable to parse statistics value for stat " + statistic.toString() + ", value=" + avgStrValue );
             }
         }
 
@@ -161,7 +161,7 @@ public class StatisticsBundle
                     }
                     catch ( Exception e )
                     {
-                        LOGGER.trace( "unable to parse statistics value for stat " + statistic.toString() + ", value=" + avgStrValue );
+                        LOGGER.trace( () ->  "unable to parse statistics value for stat " + statistic.toString() + ", value=" + avgStrValue );
                     }
                 }
                 return avgBean.getAverage().toString();

+ 7 - 4
server/src/main/java/password/pwm/svc/stats/StatisticsManager.java

@@ -538,7 +538,7 @@ public class StatisticsManager implements PwmService
     public int outputStatsToCsv( final OutputStream outputStream, final Locale locale, final boolean includeHeader )
             throws IOException
     {
-        LOGGER.trace( "beginning output stats to csv process" );
+        LOGGER.trace( () -> "beginning output stats to csv process" );
         final Instant startTime = Instant.now();
 
         final StatisticsManager statsManger = pwmApplication.getStatisticsManager();
@@ -575,8 +575,11 @@ public class StatisticsManager implements PwmService
         }
 
         csvPrinter.flush();
-        LOGGER.trace( "completed output stats to csv process; output " + counter + " records in " + TimeDuration.fromCurrent(
-                startTime ).asCompactString() );
+        {
+            final int finalCounter = counter;
+            LOGGER.trace( () -> "completed output stats to csv process; output " + finalCounter + " records in "
+                    + TimeDuration.compactFromCurrent( startTime ) );
+        }
         return counter;
     }
 
@@ -621,7 +624,7 @@ public class StatisticsManager implements PwmService
         if ( statisticsManager.status() != STATUS.OPEN )
         {
             LOGGER.trace(
-                    "skipping requested statistic increment of " + statistic + " due to StatisticsManager being closed" );
+                    () -> "skipping requested statistic increment of " + statistic + " due to StatisticsManager being closed" );
             return;
         }
 

+ 11 - 5
server/src/main/java/password/pwm/svc/token/DataStoreTokenMachine.java

@@ -82,7 +82,10 @@ public class DataStoreTokenMachine implements TokenMachine
             PwmUnrecoverableException, PwmOperationalException
     {
         final Instant startTime = Instant.now();
-        LOGGER.trace( "beginning purge cycle; database size = " + size() );
+        {
+            final long finalSize = size();
+            LOGGER.trace( () -> "beginning purge cycle; database size = " + finalSize );
+        }
         try ( ClosableIterator<String> keyIterator = dataStore.iterator() )
         {
             while ( tokenService.status() == PwmService.STATUS.OPEN && keyIterator.hasNext() )
@@ -98,8 +101,11 @@ public class DataStoreTokenMachine implements TokenMachine
         {
             LOGGER.error( "unexpected error while cleaning expired stored tokens: " + e.getMessage() );
         }
-        LOGGER.trace( "completed record purge cycle in " + TimeDuration.fromCurrent( startTime ).asCompactString()
-                + "; database size = " + size() );
+        {
+            final long finalSize = size();
+            LOGGER.trace( () -> "completed record purge cycle in " + TimeDuration.compactFromCurrent( startTime )
+                    + "; database size = " + finalSize );
+        }
     }
 
     private boolean testIfTokenNeedsPurging( final TokenPayload theToken )
@@ -146,14 +152,14 @@ public class DataStoreTokenMachine implements TokenMachine
             }
             catch ( PwmException e )
             {
-                LOGGER.trace( "error while trying to decrypted stored token payload for key '" + storedHash + "', will purge record, error: " + e.getMessage() );
+                LOGGER.trace( () -> "error while trying to decrypted stored token payload for key '" + storedHash + "', will purge record, error: " + e.getMessage() );
                 dataStore.remove( storedHash );
                 return null;
             }
 
             if ( testIfTokenNeedsPurging( tokenPayload ) )
             {
-                LOGGER.trace( "stored token key '" + storedHash + "', has an outdated issue/expire date and will be purged" );
+                LOGGER.trace( () -> "stored token key '" + storedHash + "', has an outdated issue/expire date and will be purged" );
                 dataStore.remove( storedHash );
             }
             else

+ 2 - 2
server/src/main/java/password/pwm/svc/token/TokenService.java

@@ -131,7 +131,7 @@ public class TokenService implements PwmService
     public void init( final PwmApplication pwmApplication )
             throws PwmException
     {
-        LOGGER.trace( "opening" );
+        LOGGER.trace( () -> "opening" );
         status = STATUS.OPENING;
 
         this.pwmApplication = pwmApplication;
@@ -200,7 +200,7 @@ public class TokenService implements PwmService
             final int cleanerFrequencySeconds = Integer.parseInt( configuration.readAppProperty( AppProperty.TOKEN_CLEANER_INTERVAL_SECONDS ) );
             final TimeDuration cleanerFrequency = TimeDuration.of( cleanerFrequencySeconds, TimeDuration.Unit.SECONDS );
             pwmApplication.scheduleFixedRateJob( new CleanerTask(), executorService, TimeDuration.MINUTE, cleanerFrequency );
-            LOGGER.trace( "token cleanup will occur every " + cleanerFrequency.asCompactString() );
+            LOGGER.trace( () -> "token cleanup will occur every " + cleanerFrequency.asCompactString() );
         }
 
 

+ 1 - 1
server/src/main/java/password/pwm/svc/wordlist/AbstractWordlist.java

@@ -266,7 +266,7 @@ abstract class AbstractWordlist implements Wordlist, PwmService
     void clearImpl( final Activity postCleanActivity ) throws LocalDBException
     {
         final Instant startTime = Instant.now();
-        getLogger().trace( "clearing stored wordlist" );
+        getLogger().trace( () -> "clearing stored wordlist" );
         activity = Wordlist.Activity.Clearing;
         writeWordlistStatus( WordlistStatus.builder().build() );
         getWordlistBucket().clear();

+ 10 - 13
server/src/main/java/password/pwm/svc/wordlist/SharedHistoryManager.java

@@ -168,7 +168,7 @@ public class SharedHistoryManager implements PwmService
     private boolean checkDbVersion( )
             throws Exception
     {
-        LOGGER.trace( "checking version number stored in LocalDB" );
+        LOGGER.trace( () -> "checking version number stored in LocalDB" );
 
         final Object versionInDB = localDB.get( META_DB, KEY_VERSION );
         final String currentVersion = "version=" + settings.version;
@@ -183,7 +183,7 @@ public class SharedHistoryManager implements PwmService
         }
         else
         {
-            LOGGER.trace( "existing db version matches current db version db=(" + versionInDB + ")  current=(" + currentVersion + ")" );
+            LOGGER.trace( () -> "existing db version matches current db version db=(" + versionInDB + ")  current=(" + currentVersion + ")" );
         }
 
         return result;
@@ -212,12 +212,12 @@ public class SharedHistoryManager implements PwmService
             if ( oldestEntryStr == null || oldestEntryStr.length() < 1 )
             {
                 oldestEntry = 0;
-                LOGGER.trace( "no oldestEntry timestamp stored, will rescan" );
+                LOGGER.trace( () -> "no oldestEntry timestamp stored, will rescan" );
             }
             else
             {
                 oldestEntry = Long.parseLong( oldestEntryStr );
-                LOGGER.trace( "oldest timestamp loaded from localDB, age is " + TimeDuration.fromCurrent( oldestEntry ).asCompactString() );
+                LOGGER.trace( () -> "oldest timestamp loaded from localDB, age is " + TimeDuration.fromCurrent( oldestEntry ).asCompactString() );
             }
         }
         catch ( LocalDBException e )
@@ -302,13 +302,9 @@ public class SharedHistoryManager implements PwmService
             final boolean preExisting = localDB.contains( WORDS_DB, hashedWord );
             localDB.put( WORDS_DB, hashedWord, Long.toString( System.currentTimeMillis() ) );
 
-            {
-                final StringBuilder logOutput = new StringBuilder();
-                logOutput.append( preExisting ? "updated" : "added" ).append( " word" );
-                logOutput.append( " (" ).append( TimeDuration.compactFromCurrent( startTime ) ).append( ")" );
-                logOutput.append( " (" ).append( this.size() ).append( " total words)" );
-                LOGGER.trace( logOutput.toString() );
-            }
+            LOGGER.trace( () -> ( preExisting ? "updated" : "added" ) + " word"
+                    + " (" + TimeDuration.compactFromCurrent( startTime ) + ")"
+                    + " (" + this.size() + " total words)" );
         }
         catch ( Exception e )
         {
@@ -396,7 +392,8 @@ public class SharedHistoryManager implements PwmService
 
                         if ( removeCount % 1000 == 0 )
                         {
-                            LOGGER.trace( "wordDB reduce operation in progress, removed=" + removeCount + ", total=" + ( initialSize - removeCount ) );
+                            final int finalRemove = removeCount;
+                            LOGGER.trace( () -> "wordDB reduce operation in progress, removed=" + finalRemove + ", total=" + ( initialSize - finalRemove ) );
                         }
                     }
                     else
@@ -480,7 +477,7 @@ public class SharedHistoryManager implements PwmService
 
         if ( needsClearing )
         {
-            LOGGER.trace( "clearing wordlist" );
+            LOGGER.trace( () -> "clearing wordlist" );
             try
             {
                 localDB.truncate( WORDS_DB );

+ 1 - 1
server/src/main/java/password/pwm/svc/wordlist/WordlistImporter.java

@@ -266,7 +266,7 @@ class WordlistImporter implements Runnable
     {
         flushBuffer();
         getLogger().info( makeStatString() );
-        getLogger().trace( "beginning wordlist size query" );
+        getLogger().trace( () -> "beginning wordlist size query" );
         final long wordlistSize = wordlistBucket.size();
 
         final String logMsg = "population complete, added " + wordlistSize

+ 1 - 1
server/src/main/java/password/pwm/util/CASFilterAuthenticationProvider.java

@@ -157,7 +157,7 @@ public class CASFilterAuthenticationProvider implements PwmHttpFilterAuthenticat
         final String encodedPsw = ( String ) casAttributes.get( "credential" );
         if ( encodedPsw == null )
         {
-            LOGGER.trace( "No credential" );
+            LOGGER.trace( () -> "No credential" );
         }
         else
         {

+ 4 - 4
server/src/main/java/password/pwm/util/LocaleHelper.java

@@ -565,13 +565,13 @@ public class LocaleHelper
                 {
                     if ( DEBUG_FLAG )
                     {
-                        LOGGER.trace( "missing resource bundle: bundle=" + pwmLocaleBundle.getTheClass().getName() + ", locale=" + locale.toString() );
+                        LOGGER.trace( () -> "missing resource bundle: bundle=" + pwmLocaleBundle.getTheClass().getName() + ", locale=" + locale.toString() );
                     }
                     returnList.addAll( pwmLocaleBundle.getKeys() );
                 }
                 else
                 {
-                    LOGGER.trace( "checking file " + bundleFilename );
+                    LOGGER.trace( () -> "checking file " + bundleFilename );
                     checkProperties.load( stream );
                     for ( final String key : pwmLocaleBundle.getKeys() )
                     {
@@ -579,7 +579,7 @@ public class LocaleHelper
                         {
                             if ( DEBUG_FLAG )
                             {
-                                LOGGER.trace( "missing resource: bundle=" + pwmLocaleBundle.getTheClass().toString() + ", locale=" + locale.toString() + "' key=" + key );
+                                LOGGER.trace( () -> "missing resource: bundle=" + pwmLocaleBundle.getTheClass().toString() + ", locale=" + locale.toString() + "' key=" + key );
                             }
                             returnList.add( key );
                         }
@@ -590,7 +590,7 @@ public class LocaleHelper
             {
                 if ( DEBUG_FLAG )
                 {
-                    LOGGER.trace( "error loading resource bundle for class='" + pwmLocaleBundle.getTheClass().toString()
+                    LOGGER.trace( () -> "error loading resource bundle for class='" + pwmLocaleBundle.getTheClass().toString()
                             + ", locale=" + locale.toString() + "', error: " + e.getMessage() );
                 }
             }

+ 13 - 15
server/src/main/java/password/pwm/util/PwmPasswordRuleValidator.java

@@ -120,12 +120,12 @@ public class PwmPasswordRuleValidator
         {
             try
             {
-                LOGGER.trace( "calling chai directory password validation checker" );
+                LOGGER.trace( () -> "calling chai directory password validation checker" );
                 user.testPasswordPolicy( password.getStringValue() );
             }
             catch ( UnsupportedOperationException e )
             {
-                LOGGER.trace( "Unsupported operation was thrown while validating password: " + e.toString() );
+                LOGGER.trace( () -> "Unsupported operation was thrown while validating password: " + e.toString() );
             }
             catch ( ChaiUnavailableException e )
             {
@@ -138,7 +138,7 @@ public class PwmPasswordRuleValidator
                 final ChaiError passwordError = e.getErrorCode();
                 final PwmError pwmError = PwmError.forChaiError( passwordError );
                 final ErrorInformation info = new ErrorInformation( pwmError == null ? PwmError.PASSWORD_UNKNOWN_VALIDATION : pwmError );
-                LOGGER.trace( "ChaiPasswordPolicyException was thrown while validating password: " + e.toString() );
+                LOGGER.trace( () -> "ChaiPasswordPolicyException was thrown while validating password: " + e.toString() );
                 errorResults.add( info );
             }
         }
@@ -321,7 +321,7 @@ public class PwmPasswordRuleValidator
 
                     if ( containsDisallowedValue( passwordString, disallowedValue, threshold ) )
                     {
-                        LOGGER.trace( "password rejected, same as user attr " + attrName );
+                        LOGGER.trace( () -> "password rejected, same as user attr " + attrName );
                         errorList.add( new ErrorInformation( PwmError.PASSWORD_SAMEASATTR ) );
                     }
                 }
@@ -349,10 +349,9 @@ public class PwmPasswordRuleValidator
                         errorList.add( new ErrorInformation( PwmError.PASSWORD_TOO_WEAK ) );
                         if ( EXTRA_LOGGING )
                         {
-                            final String msg = "password rejected, password strength of "
+                            LOGGER.trace( () -> "password rejected, password strength of "
                                     + passwordStrength + " is lower than policy requirement of "
-                                    + requiredPasswordStrength;
-                            LOGGER.trace( msg );
+                                    + requiredPasswordStrength );
                         }
                     }
                 }
@@ -372,8 +371,7 @@ public class PwmPasswordRuleValidator
                 errorList.add( new ErrorInformation( PwmError.PASSWORD_INVALID_CHAR ) );
                 if ( EXTRA_LOGGING )
                 {
-                    final String msg = "password rejected, does not match configured regex pattern: " + pattern.toString();
-                    LOGGER.trace( msg );
+                    LOGGER.trace( () -> "password rejected, does not match configured regex pattern: " + pattern.toString() );
                 }
             }
         }
@@ -391,7 +389,7 @@ public class PwmPasswordRuleValidator
                 errorList.add( new ErrorInformation( PwmError.PASSWORD_INVALID_CHAR ) );
                 if ( EXTRA_LOGGING )
                 {
-                    LOGGER.trace( "password rejected, matches configured no-regex pattern: " + pattern.toString() );
+                    LOGGER.trace( () -> "password rejected, matches configured no-regex pattern: " + pattern.toString() );
                 }
             }
         }
@@ -569,7 +567,7 @@ public class PwmPasswordRuleValidator
                 if ( password.toLowerCase().contains( samAccountName.toLowerCase() ) )
                 {
                     errorList.add( new ErrorInformation( PwmError.PASSWORD_INWORDLIST ) );
-                    LOGGER.trace( "Password violation due to ADComplexity check: Password contains sAMAccountName" );
+                    LOGGER.trace( () -> "Password violation due to ADComplexity check: Password contains sAMAccountName" );
                 }
             }
             final String displayName = userAttrs.get( "displayName" );
@@ -578,7 +576,7 @@ public class PwmPasswordRuleValidator
                 if ( checkContainsTokens( password, displayName ) )
                 {
                     errorList.add( new ErrorInformation( PwmError.PASSWORD_INWORDLIST ) );
-                    LOGGER.trace( "Password violation due to ADComplexity check: Tokens from displayName used in password" );
+                    LOGGER.trace( () -> "Password violation due to ADComplexity check: Tokens from displayName used in password" );
                 }
             }
         }
@@ -759,18 +757,18 @@ public class PwmPasswordRuleValidator
                 if ( responseMap.containsKey( REST_RESPONSE_KEY_ERROR_MSG ) )
                 {
                     final String errorMessage = responseMap.get( REST_RESPONSE_KEY_ERROR_MSG ).toString();
-                    LOGGER.trace( "external web service reported error: " + errorMessage );
+                    LOGGER.trace( () -> "external web service reported error: " + errorMessage );
                     returnedErrors.add( new ErrorInformation( PwmError.PASSWORD_CUSTOM_ERROR, errorMessage, errorMessage, null ) );
                 }
                 else
                 {
-                    LOGGER.trace( "external web service reported error without specifying an errorMessage" );
+                    LOGGER.trace( () -> "external web service reported error without specifying an errorMessage" );
                     returnedErrors.add( new ErrorInformation( PwmError.PASSWORD_CUSTOM_ERROR ) );
                 }
             }
             else
             {
-                LOGGER.trace( "external web service did not report an error" );
+                LOGGER.trace( () -> "external web service did not report an error" );
             }
 
         }

+ 3 - 3
server/src/main/java/password/pwm/util/db/DatabaseAccessorImpl.java

@@ -469,7 +469,7 @@ class DatabaseAccessorImpl implements DatabaseAccessor
             return;
         }
 
-        LOGGER.trace( "accessor #" + accessorNumber + " begin operation: " + JsonUtil.serialize( debugInfo ) );
+        LOGGER.trace( () -> "accessor #" + accessorNumber + " begin operation: " + JsonUtil.serialize( debugInfo ) );
     }
 
     private void traceResult(
@@ -488,7 +488,7 @@ class DatabaseAccessorImpl implements DatabaseAccessor
         {
             map.put( "result", String.valueOf( result ) );
         }
-        LOGGER.trace( "accessor #" + accessorNumber + " operation result: " + StringUtil.mapToString( map ) );
+        LOGGER.trace( () -> "accessor #" + accessorNumber + " operation result: " + StringUtil.mapToString( map ) );
     }
 
     private interface SqlFunction<T>
@@ -567,7 +567,7 @@ class DatabaseAccessorImpl implements DatabaseAccessor
             lock.unlock();
         }
 
-        LOGGER.trace( "closed accessor #" + accessorNumber );
+        LOGGER.trace( () -> "closed accessor #" + accessorNumber );
     }
 
     private boolean containsImpl( final DatabaseTable table, final String key )

+ 4 - 4
server/src/main/java/password/pwm/util/db/DatabaseUtil.java

@@ -118,13 +118,13 @@ class DatabaseUtil
         try
         {
             checkIfTableExists( connection, table );
-            LOGGER.trace( "table " + table + " appears to exist" );
+            LOGGER.trace( () -> "table " + table + " appears to exist" );
             tableExists = true;
         }
         catch ( DatabaseException e )
         {
             // assume error was due to table missing;
-            LOGGER.trace( "error while checking for table: " + e.getMessage() + ", assuming due to table non-existence" );
+            LOGGER.trace( () -> "error while checking for table: " + e.getMessage() + ", assuming due to table non-existence" );
         }
 
         if ( !tableExists )
@@ -147,7 +147,7 @@ class DatabaseUtil
                     + "  " + DatabaseService.VALUE_COLUMN + " " + dbConfiguration.getColumnTypeValue() + " " + "\n"
                     + ")" + "\n";
 
-            LOGGER.trace( "attempting to execute the following sql statement:\n " + sqlString );
+            LOGGER.trace( () ->  "attempting to execute the following sql statement:\n " + sqlString );
 
             Statement statement = null;
             try
@@ -177,7 +177,7 @@ class DatabaseUtil
 
             Statement statement = null;
 
-            LOGGER.trace( "attempting to execute the following sql statement:\n " + sqlString );
+            LOGGER.trace( () -> "attempting to execute the following sql statement:\n " + sqlString );
 
             try
             {

+ 5 - 5
server/src/main/java/password/pwm/util/db/JDBCDriverLoader.java

@@ -61,7 +61,7 @@ public class JDBCDriverLoader
             throws DatabaseException
     {
         final List<ClassLoaderStrategy> strategies = dbConfiguration.getClassLoaderStrategies();
-        LOGGER.trace( "attempting to load jdbc driver using strategies: " + JsonUtil.serializeCollection( strategies ) );
+        LOGGER.trace( () -> "attempting to load jdbc driver using strategies: " + JsonUtil.serializeCollection( strategies ) );
         final List<String> errorMsgs = new ArrayList<>();
         for ( final ClassLoaderStrategy strategy : strategies )
         {
@@ -222,7 +222,7 @@ public class JDBCDriverLoader
                 {
                     final String prefixName = PwmConstants.PWM_APP_NAME.toLowerCase() + "_jdbcJar_";
                     tempFile = File.createTempFile( prefixName, "jar" );
-                    LOGGER.trace( "created temp file " + tempFile.getAbsolutePath() );
+                    LOGGER.trace( () -> "created temp file " + tempFile.getAbsolutePath() );
                 }
 
                 try ( FileOutputStream fos = new FileOutputStream( tempFile ) )
@@ -262,7 +262,7 @@ public class JDBCDriverLoader
             {
                 if ( tempFile.delete() )
                 {
-                    LOGGER.trace( "removed temporary file " + tempFile.getAbsolutePath() );
+                    LOGGER.trace( () -> "removed temporary file " + tempFile.getAbsolutePath() );
                 }
             }
             tempFile = null;
@@ -309,7 +309,7 @@ public class JDBCDriverLoader
             if ( driverCache.containsKey( jdbcDriverHash ) )
             {
                 urlClassLoader = driverCache.get( jdbcDriverHash );
-                LOGGER.trace( "loaded classloader from static cache" );
+                LOGGER.trace( () -> "loaded classloader from static cache" );
             }
             else
             {
@@ -382,7 +382,7 @@ public class JDBCDriverLoader
             }
             else
             {
-                LOGGER.trace( "reusing existing temp jar file " + tempFile.getAbsolutePath() );
+                LOGGER.trace( () -> "reusing existing temp jar file " + tempFile.getAbsolutePath() );
             }
 
             return tempFile;

+ 2 - 2
server/src/main/java/password/pwm/util/form/FormUtility.java

@@ -350,7 +350,7 @@ public class FormUtility
                 {
                     // since only one value searched, it must be that one value
                     final String attributeName = labelMap.values().iterator().next();
-                    LOGGER.trace( "found duplicate value for attribute '" + attributeName + "' on entry " + userIdentity );
+                    LOGGER.trace( () -> "found duplicate value for attribute '" + attributeName + "' on entry " + userIdentity );
                     final ErrorInformation error = new ErrorInformation( PwmError.ERROR_FIELD_DUPLICATE, null, new String[]
                             {
                                     attributeName,
@@ -379,7 +379,7 @@ public class FormUtility
                     if ( compareResult )
                     {
                         final String label = labelMap.get( name );
-                        LOGGER.trace( "found duplicate value for attribute '" + label + "' on entry " + userIdentity );
+                        LOGGER.trace( () ->  "found duplicate value for attribute '" + label + "' on entry " + userIdentity );
                         final ErrorInformation error = new ErrorInformation( PwmError.ERROR_FIELD_DUPLICATE, null, new String[]
                                 {
                                         label,

+ 2 - 2
server/src/main/java/password/pwm/util/localdb/AbstractJDBCLocalDB.java

@@ -82,7 +82,7 @@ public abstract class AbstractJDBCLocalDB implements LocalDBProvider
         try
         {
             checkIfTableExists( connection, db );
-            LOGGER.trace( "table " + db + " appears to exist" );
+            LOGGER.trace( () -> "table " + db + " appears to exist" );
         }
         catch ( final LocalDBException e )
         {
@@ -303,7 +303,7 @@ public abstract class AbstractJDBCLocalDB implements LocalDBProvider
 
             final LocalDB.LocalDBIterator iterator = new DbIterator( db );
             dbIterators.add( iterator );
-            LOGGER.trace( this.getClass().getSimpleName() + " issued iterator for " + db.toString() + ", outstanding iterators: " + dbIterators.size() );
+            LOGGER.trace( () -> this.getClass().getSimpleName() + " issued iterator for " + db.toString() + ", outstanding iterators: " + dbIterators.size() );
             return iterator;
         }
         catch ( final Exception e )

+ 1 - 1
server/src/main/java/password/pwm/util/localdb/DerbyLocalDB.java

@@ -83,7 +83,7 @@ public class DerbyLocalDB extends AbstractJDBCLocalDB
         {
             if ( "XJ015".equals( e.getSQLState() ) )
             {
-                LOGGER.trace( "Derby shutdown succeeded. SQLState=" + e.getSQLState() + ", message=" + e.getMessage() );
+                LOGGER.trace( () -> "Derby shutdown succeeded. SQLState=" + e.getSQLState() + ", message=" + e.getMessage() );
             }
             else
             {

+ 3 - 3
server/src/main/java/password/pwm/util/localdb/LocalDBFactory.java

@@ -87,7 +87,7 @@ public class LocalDBFactory
 
         if ( !readonly )
         {
-            LOGGER.trace( "clearing TEMP db" );
+            LOGGER.trace( () -> "clearing TEMP db" );
             localDB.truncate( LocalDB.DB.TEMP );
 
             final LocalDBUtility localDBUtility = new LocalDBUtility( localDB );
@@ -153,7 +153,7 @@ public class LocalDBFactory
         {
             if ( dbFileLocation.mkdir() )
             {
-                LOGGER.trace( "created directory at " + dbFileLocation.getAbsolutePath() );
+                LOGGER.trace( () -> "created directory at " + dbFileLocation.getAbsolutePath() );
             }
 
 
@@ -166,7 +166,7 @@ public class LocalDBFactory
             throw new LocalDBException( new ErrorInformation( PwmError.ERROR_LOCALDB_UNAVAILABLE, errorMsg ) );
         }
 
-        LOGGER.trace( "db init completed for " + theClass );
+        LOGGER.trace( () -> "db init completed for " + theClass );
     }
 
     private static Map<LocalDBProvider.Parameter, String> makeParameterMap( final Configuration configuration, final boolean readOnly )

+ 29 - 31
server/src/main/java/password/pwm/util/localdb/LocalDBStoredQueue.java

@@ -44,6 +44,7 @@ import java.util.Set;
 import java.util.concurrent.atomic.AtomicInteger;
 import java.util.concurrent.locks.ReadWriteLock;
 import java.util.concurrent.locks.ReentrantReadWriteLock;
+import java.util.function.Supplier;
 
 /**
  * A LIFO {@link Queue} implementation backed by a localDB instance.  {@code this} instances are internally
@@ -699,7 +700,10 @@ LocalDBStoredQueue implements Queue<String>, Deque<String>
             headPosition = headPositionStr != null && headPositionStr.length() > 0 ? new Position( headPositionStr ) : new Position( "0" );
             tailPosition = tailPositionStr != null && tailPositionStr.length() > 0 ? new Position( tailPositionStr ) : new Position( "0" );
 
-            LOGGER.trace( "loaded for db " + db + "; headPosition=" + headPosition + ", tailPosition=" + tailPosition + ", size=" + this.size() );
+            {
+                final int finalSize = this.size();
+                LOGGER.trace( () -> "loaded for db " + db + "; headPosition=" + headPosition + ", tailPosition=" + tailPosition + ", size=" + finalSize );
+            }
 
             repair();
 
@@ -1026,45 +1030,39 @@ LocalDBStoredQueue implements Queue<String>, Deque<String>
                 return;
             }
 
-            final StringBuilder sb = new StringBuilder();
-            try
+            final Supplier<CharSequence> debugOutput = () ->
             {
-                sb.append( input );
-                sb.append( "  tailPosition=" ).append( tailPosition ).append( ", headPosition=" ).append( headPosition ).append( ", db=" ).append( db );
-                sb.append( ", size=" ).append( internalSize() ).append( "\n" );
-
-                LocalDB.LocalDBIterator<String> keyIter = null;
+                final StringBuilder sb = new StringBuilder();
                 try
                 {
-                    keyIter = localDB.iterator( db );
-                    int rowCount = 0;
-                    while ( keyIter.hasNext() && rowCount < DEBUG_MAX_ROWS )
+                    sb.append( input );
+                    sb.append( "  tailPosition=" ).append( tailPosition ).append( ", headPosition=" ).append( headPosition ).append( ", db=" ).append( db );
+                    sb.append( ", size=" ).append( internalSize() ).append( "\n" );
+
+                    try ( LocalDB.LocalDBIterator<String> keyIter = localDB.iterator( db ) )
                     {
-                        final String key = keyIter.next();
-                        String value = localDB.get( db, key );
-                        value = value == null ? "" : value;
-                        value = value.length() < DEBUG_MAX_WIDTH ? value : value.substring( 0, DEBUG_MAX_WIDTH ) + "...";
-                        final String row = key + " " + value;
-                        sb.append( row ).append( "\n" );
-                        rowCount++;
+                        int rowCount = 0;
+                        while ( keyIter.hasNext() && rowCount < DEBUG_MAX_ROWS )
+                        {
+                            final String key = keyIter.next();
+                            String value = localDB.get( db, key );
+                            value = value == null ? "" : value;
+                            value = value.length() < DEBUG_MAX_WIDTH ? value : value.substring( 0, DEBUG_MAX_WIDTH ) + "...";
+                            final String row = key + " " + value;
+                            sb.append( row ).append( "\n" );
+                            rowCount++;
+                        }
                     }
                 }
-                finally
+                catch ( LocalDBException e )
                 {
-                    if ( keyIter != null )
-                    {
-                        keyIter.close();
-                    }
+                    LOGGER.error( "error generating logMsg: " + e.getMessage() );
                 }
 
+                return sb.toString();
+            };
 
-            }
-            catch ( LocalDBException e )
-            {
-                e.printStackTrace();
-            }
-
-            LOGGER.trace( sb.toString() );
+            LOGGER.trace( debugOutput );
         }
 
         private void repair( ) throws LocalDBException
@@ -1122,7 +1120,7 @@ LocalDBStoredQueue implements Queue<String>, Deque<String>
 
             if ( tailTrim == 0 && headTrim == 0 )
             {
-                LOGGER.trace( "repair unnecessary for " + db );
+                LOGGER.trace( () -> "repair unnecessary for " + db );
             }
             else
             {

+ 1 - 1
server/src/main/java/password/pwm/util/localdb/LocalDBUtility.java

@@ -311,7 +311,7 @@ public class LocalDBUtility
         }
         finally
         {
-            LOGGER.trace( "import process completed" );
+            LOGGER.trace( () -> "import process completed" );
             statTimer.cancel();
             IOUtils.closeQuietly( csvReader );
             IOUtils.closeQuietly( countingInputStream );

+ 20 - 9
server/src/main/java/password/pwm/util/localdb/WorkQueueProcessor.java

@@ -109,7 +109,7 @@ public final class WorkQueueProcessor<W extends Serializable>
         {
             logger.debug( "opening with " + queue.size() + " items in work queue" );
         }
-        logger.trace( "initializing worker thread with settings " + JsonUtil.serialize( settings ) );
+        logger.trace( () -> "initializing worker thread with settings " + JsonUtil.serialize( settings ) );
 
         this.workerThread = new WorkerThread();
         workerThread.setDaemon( true );
@@ -262,7 +262,7 @@ public final class WorkQueueProcessor<W extends Serializable>
             eldestItem = itemWrapper.getDate();
             workerThread.notifyWorkPending();
 
-            logger.trace( "item submitted: " + makeDebugText( itemWrapper ) );
+            logger.trace( () -> "item submitted: " + makeDebugText( itemWrapper ) );
         }
     }
 
@@ -276,10 +276,21 @@ public final class WorkQueueProcessor<W extends Serializable>
         return eldestItem;
     }
 
-    private String makeDebugText( final ItemWrapper<W> itemWrapper ) throws PwmOperationalException
+    private String makeDebugText( final ItemWrapper<W> itemWrapper )
     {
         final int itemsInQueue = WorkQueueProcessor.this.queueSize();
-        String traceMsg = "[" + itemWrapper.toDebugString( itemProcessor ) + "]";
+
+        String itemMsg;
+        try
+        {
+            itemMsg = itemWrapper.toDebugString( itemProcessor );
+        }
+        catch ( PwmOperationalException e )
+        {
+            itemMsg = "error";
+        }
+
+        String traceMsg = "[" + itemMsg + "]";
         if ( itemsInQueue > 0 )
         {
             traceMsg += ", " + itemsInQueue + " items in queue";
@@ -313,11 +324,11 @@ public final class WorkQueueProcessor<W extends Serializable>
                 logger.error( "unexpected error processing work item queue: " + JavaHelper.readHostileExceptionMessage( t ), t );
             }
 
-            logger.trace( "worker thread beginning shutdown..." );
+            logger.trace( () -> "worker thread beginning shutdown..." );
 
             if ( !queue.isEmpty() )
             {
-                logger.trace( "processing remaining " + queue.size() + " items" );
+                logger.trace( () -> "processing remaining " + queue.size() + " items" );
 
                 try
                 {
@@ -333,14 +344,14 @@ public final class WorkQueueProcessor<W extends Serializable>
                 }
             }
 
-            logger.trace( "thread exiting..." );
+            logger.trace( () -> "thread exiting..." );
             running.set( false );
         }
 
         void flushQueueAndClose( )
         {
             shutdownFlag.set( true );
-            logger.trace( "shutdown flag set" );
+            logger.trace( () -> "shutdown flag set" );
             notifyWorkPending();
 
             // rest until not running for up to 3 seconds....
@@ -569,7 +580,7 @@ public final class WorkQueueProcessor<W extends Serializable>
         final TimeDuration lagTime = TimeDuration.fromCurrent( itemWrapper.getDate() );
         avgLagTime.update( lagTime.asMillis() );
         sendRate.markEvents( 1 );
-        logger.trace( "successfully processed item=" + makeDebugText( itemWrapper ) + "; lagTime=" + lagTime.asCompactString()
+        logger.trace( () -> "successfully processed item=" + makeDebugText( itemWrapper ) + "; lagTime=" + lagTime.asCompactString()
                 + "; " + StringUtil.mapToString( debugInfo() ) );
     }
 

+ 17 - 10
server/src/main/java/password/pwm/util/localdb/XodusLocalDB.java

@@ -116,7 +116,7 @@ public class XodusLocalDB implements LocalDBProvider
     {
         this.fileLocation = dbDirectory;
 
-        LOGGER.trace( "begin environment open" );
+        LOGGER.trace( () -> "begin environment open" );
         final Instant startTime = Instant.now();
 
         final EnvironmentConfig environmentConfig = makeEnvironmentConfig( initParameters );
@@ -135,9 +135,9 @@ public class XodusLocalDB implements LocalDBProvider
 
         readOnly = parameters.containsKey( Parameter.readOnly ) && Boolean.parseBoolean( parameters.get( Parameter.readOnly ) );
 
-        LOGGER.trace( "preparing to open with configuration " + JsonUtil.serializeMap( environmentConfig.getSettings() ) );
+        LOGGER.trace( () -> "preparing to open with configuration " + JsonUtil.serializeMap( environmentConfig.getSettings() ) );
         environment = Environments.newInstance( dbDirectory.getAbsolutePath() + File.separator + FILE_SUB_PATH, environmentConfig );
-        LOGGER.trace( "environment open (" + TimeDuration.fromCurrent( startTime ).asCompactString() + ")" );
+        LOGGER.trace( () -> "environment open (" + TimeDuration.fromCurrent( startTime ).asCompactString() + ")" );
 
         environment.executeInTransaction( txn ->
         {
@@ -152,7 +152,8 @@ public class XodusLocalDB implements LocalDBProvider
 
         for ( final LocalDB.DB db : LocalDB.DB.values() )
         {
-            LOGGER.trace( "opened " + db + " with " + this.size( db ) + " records" );
+            final long finalSize = this.size( db );
+            LOGGER.trace( () -> "opened " + db + " with " + finalSize + " records" );
         }
 
         outputReadme( new File( dbDirectory.getPath() + File.separator + FILE_SUB_PATH + File.separator + README_FILENAME ) );
@@ -185,7 +186,7 @@ public class XodusLocalDB implements LocalDBProvider
             try
             {
                 environmentConfig.setSettings( singleMap );
-                LOGGER.trace( "set env setting from appProperty: " + key + "=" + value );
+                LOGGER.trace( () -> "set env setting from appProperty: " + key + "=" + value );
             }
             catch ( InvalidSettingException e )
             {
@@ -412,7 +413,10 @@ public class XodusLocalDB implements LocalDBProvider
     {
         checkStatus( true );
 
-        LOGGER.trace( "begin truncate of " + db.toString() + ", size=" + this.size( db ) );
+        {
+            final long finalSize = this.size( db );
+            LOGGER.trace( () -> "begin truncate of " + db.toString() + ", size=" + finalSize );
+        }
         final Instant startDate = Instant.now();
 
         environment.executeInTransaction( transaction ->
@@ -422,9 +426,12 @@ public class XodusLocalDB implements LocalDBProvider
             cachedStoreObjects.put( db, newStoreReference );
         } );
 
-        LOGGER.trace( "completed truncate of " + db.toString()
-                + " (" + TimeDuration.fromCurrent( startDate ).asCompactString() + ")"
-                + ", size=" + this.size( db ) );
+        {
+            final long finalSize = this.size( db );
+            LOGGER.trace( () -> "completed truncate of " + db.toString()
+                    + " (" + TimeDuration.fromCurrent( startDate ).asCompactString() + ")"
+                    + ", size=" + finalSize );
+        }
     }
 
     @Override
@@ -467,7 +474,7 @@ public class XodusLocalDB implements LocalDBProvider
 
     private void outputStats( )
     {
-        LOGGER.trace( "xodus environment stats: " + StringUtil.mapToString( debugInfo() ) );
+        LOGGER.trace( () -> "xodus environment stats: " + StringUtil.mapToString( debugInfo() ) );
     }
 
     @Override

+ 1 - 1
server/src/main/java/password/pwm/util/logging/LocalDBLogger.java

@@ -308,7 +308,7 @@ public class LocalDBLogger implements PwmService
         }
         catch ( PatternSyntaxException e )
         {
-            LOGGER.trace( "invalid regex syntax for " + searchParameters.getUsername() + ", reverting to plaintext search" );
+            LOGGER.trace( () -> "invalid regex syntax for " + searchParameters.getUsername() + ", reverting to plaintext search" );
         }
         if ( pattern != null )
         {

+ 1 - 1
server/src/main/java/password/pwm/util/logging/PwmLogManager.java

@@ -206,7 +206,7 @@ public class PwmLogManager
 
         if ( pwmApplication.getApplicationMode() == PwmApplicationMode.READ_ONLY )
         {
-            LOGGER.trace( "skipping initialization of LocalDBLogger due to read-only mode" );
+            LOGGER.trace( () -> "skipping initialization of LocalDBLogger due to read-only mode" );
             return null;
         }
 

+ 55 - 6
server/src/main/java/password/pwm/util/logging/PwmLogger.java

@@ -41,6 +41,7 @@ import java.io.IOException;
 import java.time.Instant;
 import java.util.HashMap;
 import java.util.Map;
+import java.util.function.Supplier;
 
 /**
  * @author Jason D. Rivard
@@ -143,9 +144,19 @@ public class PwmLogger
 
     private void doLogEvent( final PwmLogLevel level, final SessionLabel sessionLabel, final Object message, final Throwable e )
     {
+        doLogEvent( level, sessionLabel, () -> message == null ? "" : message.toString(), e );
+    }
+
+    private void doLogEvent( final PwmLogLevel level, final SessionLabel sessionLabel, final Supplier<Object> message, final Throwable e )
+    {
+        if ( !isEnabled( level ) )
+        {
+            return;
+        }
+
         final PwmLogLevel effectiveLevel = level == null ? PwmLogLevel.TRACE : level;
         final String topic = log4jLogger.getName();
-        final String effectiveMessage = message == null ? "" : message.toString();
+        final String effectiveMessage = message == null ? "" : message.get().toString();
         final PwmLogEvent logEvent = PwmLogEvent.createPwmLogEvent( Instant.now(), topic, effectiveMessage, sessionLabel,
                 e, effectiveLevel );
         doLogEvent( logEvent );
@@ -242,7 +253,7 @@ public class PwmLogger
         doLogEvent( level, sessionLabel, message, null );
     }
 
-    public void trace( final CharSequence message )
+    public void trace( final Supplier<CharSequence> message )
     {
         doLogEvent( PwmLogLevel.TRACE, null, message, null );
     }
@@ -294,22 +305,34 @@ public class PwmLogger
 
     public void debug( final SessionLabel sessionLabel, final CharSequence message )
     {
-        doLogEvent( PwmLogLevel.DEBUG, sessionLabel, message, null );
+        if ( log4jLogger.isDebugEnabled() )
+        {
+            doLogEvent( PwmLogLevel.DEBUG, sessionLabel, message, null );
+        }
     }
 
     public void debug( final SessionLabel sessionLabel, final ErrorInformation errorInformation )
     {
-        doLogEvent( PwmLogLevel.DEBUG, sessionLabel, convertErrorInformation( errorInformation ), null );
+        if ( log4jLogger.isDebugEnabled() )
+        {
+            doLogEvent( PwmLogLevel.DEBUG, sessionLabel, convertErrorInformation( errorInformation ), null );
+        }
     }
 
     public void debug( final CharSequence message, final Throwable exception )
     {
-        doPwmSessionLogEvent( PwmLogLevel.DEBUG, null, message, exception );
+        if ( log4jLogger.isDebugEnabled() )
+        {
+            doPwmSessionLogEvent( PwmLogLevel.DEBUG, null, message, exception );
+        }
     }
 
     public void debug( final PwmSession pwmSession, final CharSequence message, final Throwable e )
     {
-        doPwmSessionLogEvent( PwmLogLevel.DEBUG, pwmSession, message, e );
+        if ( log4jLogger.isDebugEnabled() )
+        {
+            doPwmSessionLogEvent( PwmLogLevel.DEBUG, pwmSession, message, e );
+        }
     }
 
     public void info( final CharSequence message )
@@ -552,5 +575,31 @@ public class PwmLogger
 
         return returnString;
     }
+
+    public boolean isEnabled( final PwmLogLevel pwmLogLevel )
+    {
+        /*
+        if ( minimumDbLogLevel != null )
+        {
+            final int compareValue = minimumDbLogLevel.compareTo( pwmLogLevel );
+            final boolean dbLogLevelHigher =  compareValue <= 0;
+            System.out.println( " dbLogLevelHigher=" + dbLogLevelHigher
+                    + ", compareValue=" + compareValue
+                    + " pwmLogLevel=" + pwmLogLevel
+                    + ", minDbLevel=" + minimumDbLogLevel );
+        }
+        */
+
+        return (
+                log4jLogger != null
+                        && log4jLogger.isEnabledFor( pwmLogLevel.getLog4jLevel() )
+        )
+                ||
+                (
+                        localDBLogger != null
+                                && minimumDbLogLevel != null
+                                && minimumDbLogLevel.compareTo( pwmLogLevel ) <= 0
+                );
+    }
 }
 

+ 2 - 2
server/src/main/java/password/pwm/util/macro/StandardMacros.java

@@ -175,13 +175,13 @@ public abstract class StandardMacros
                 }
                 catch ( PwmUnrecoverableException e )
                 {
-                    LOGGER.trace( "could not replace value for '" + matchValue + "', ldap error: " + e.getMessage() );
+                    LOGGER.trace( () -> "could not replace value for '" + matchValue + "', ldap error: " + e.getMessage() );
                     return "";
                 }
 
                 if ( ldapValue == null || ldapValue.length() < 1 )
                 {
-                    LOGGER.trace( "could not replace value for '" + matchValue + "', user does not have value for '" + ldapAttr + "'" );
+                    LOGGER.trace( () -> "could not replace value for '" + matchValue + "', user does not have value for '" + ldapAttr + "'" );
                     return "";
                 }
             }

+ 1 - 1
server/src/main/java/password/pwm/util/operations/ActionExecutor.java

@@ -219,7 +219,7 @@ public class ActionExecutor
 
             if ( !successStatus.contains( clientResponse.getStatusCode() ) )
             {
-                LOGGER.trace( "response status code " + clientResponse.getStatusCode() + " is not one of the configured success status codes: "
+                LOGGER.trace( () -> "response status code " + clientResponse.getStatusCode() + " is not one of the configured success status codes: "
                         + StringUtil.collectionToString( successStatus ) );
 
                 throw new PwmOperationalException( new ErrorInformation(

+ 2 - 2
server/src/main/java/password/pwm/util/operations/PasswordUtility.java

@@ -1027,7 +1027,7 @@ public class PasswordUtility
                     : null;
             if ( pwmApplication.getConfig().isDevDebugMode() )
             {
-                LOGGER.trace( "generated cacheKey for password check request: " + cacheKey );
+                LOGGER.trace( () -> "generated cacheKey for password check request: " + cacheKey );
             }
             try
             {
@@ -1042,7 +1042,7 @@ public class PasswordUtility
                         }
                         else
                         {
-                            LOGGER.trace( "cache hit!" );
+                            LOGGER.trace( () -> "cache hit!" );
                             final ErrorInformation errorInformation = JsonUtil.deserialize( cachedValue, ErrorInformation.class );
                             throw new PwmDataValidationException( errorInformation );
                         }

+ 2 - 2
server/src/main/java/password/pwm/util/operations/cr/DbCrOperator.java

@@ -84,7 +84,7 @@ public class DbCrOperator implements CrOperator
             }
             else
             {
-                LOGGER.trace( "user guid for " + theUser.getEntryDN() + " not found in remote database (key=" + userGUID + ")" );
+                LOGGER.trace( () -> "user guid for " + theUser.getEntryDN() + " not found in remote database (key=" + userGUID + ")" );
             }
         }
         catch ( ChaiValidationException e )
@@ -165,7 +165,7 @@ public class DbCrOperator implements CrOperator
             );
         }
 
-        LOGGER.trace( "attempting to save responses for " + theUser.getEntryDN() + " in remote database (key=" + userGUID + ")" );
+        LOGGER.trace( () -> "attempting to save responses for " + theUser.getEntryDN() + " in remote database (key=" + userGUID + ")" );
 
         try
         {

+ 21 - 20
server/src/main/java/password/pwm/util/operations/cr/NMASCrOperator.java

@@ -45,6 +45,7 @@ import com.novell.ldapchai.provider.ChaiProviderImplementor;
 import com.novell.ldapchai.provider.ChaiSetting;
 import com.novell.ldapchai.provider.DirectoryVendor;
 import com.novell.ldapchai.provider.JLDAPProviderImpl;
+import com.novell.security.nmas.NMASConstants;
 import com.novell.security.nmas.client.NMASCallback;
 import com.novell.security.nmas.client.NMASCompletionCallback;
 import com.novell.security.nmas.lcm.LCMEnvironment;
@@ -178,7 +179,7 @@ public class NMASCrOperator implements CrOperator
         }
         else
         {
-            LOGGER.trace( "pre-existing SASL provider for " + NMASCrPwmSaslProvider.SASL_PROVIDER_NAME + " has not been detected" );
+            LOGGER.trace( () -> "pre-existing SASL provider for " + NMASCrPwmSaslProvider.SASL_PROVIDER_NAME + " has not been detected" );
         }
 
         final boolean useLocalProvider = Boolean.parseBoolean( pwmApplication.getConfig().readAppProperty( AppProperty.NMAS_USE_LOCAL_SASL_FACTORY ) );
@@ -187,15 +188,15 @@ public class NMASCrOperator implements CrOperator
         {
             if ( useLocalProvider )
             {
-                LOGGER.trace( "registering built-in local SASL provider" );
+                LOGGER.trace( () -> "registering built-in local SASL provider" );
                 saslProvider = new NMASCrPwmSaslProvider();
             }
             else
             {
-                LOGGER.trace( "registering NMAS library SASL provider" );
+                LOGGER.trace( () -> "registering NMAS library SASL provider" );
                 saslProvider = new com.novell.sasl.client.NovellSaslProvider();
             }
-            LOGGER.trace( "initialized security provider " + saslProvider.getClass().getName() );
+            LOGGER.trace( () -> "initialized security provider " + saslProvider.getClass().getName() );
         }
         catch ( Throwable t )
         {
@@ -486,7 +487,7 @@ public class NMASCrOperator implements CrOperator
             {
                 if ( theUser.isPasswordLocked() )
                 {
-                    LOGGER.trace( "user " + theUser.getEntryDN() + " appears to be intruder locked, aborting nmas ResponseSet loading" );
+                    LOGGER.trace( () -> "user " + theUser.getEntryDN() + " appears to be intruder locked, aborting nmas ResponseSet loading" );
                     throw new PwmUnrecoverableException( new ErrorInformation( PwmError.ERROR_INTRUDER_LDAP, "nmas account is intruder locked-out" ) );
                 }
                 else if ( !theUser.isAccountEnabled() )
@@ -723,20 +724,20 @@ public class NMASCrOperator implements CrOperator
 
             public void handle( final Callback[] callbacks ) throws UnsupportedCallbackException
             {
-                LOGGER.trace( "entering ChalRespCallbackHandler.handle()" );
+                LOGGER.trace( () -> "entering ChalRespCallbackHandler.handle()" );
                 for ( final Callback callback : callbacks )
                 {
                     final String callbackClassname = callback.getClass().getName();
-                    LOGGER.trace( "evaluating callback: " + callback.toString() + ", class=" + callbackClassname );
+                    LOGGER.trace( () -> "evaluating callback: " + callback.toString() + ", class=" + callbackClassname );
 
                     // note in some cases instanceof check fails due to classloader issues, using getName string comparison instead
                     if ( NMASCompletionCallback.class.getName().equals( callbackClassname ) )
                     {
-                        LOGGER.trace( "received NMASCompletionCallback, ignoring" );
+                        LOGGER.trace( () -> "received NMASCompletionCallback, ignoring" );
                     }
                     else if ( NMASCallback.class.getName().equals( callbackClassname ) )
                     {
-                        LOGGER.trace( "callback is instance of NMASCompletionCallback, calling handleNMASCallback()" );
+                        LOGGER.trace( () -> "callback is instance of NMASCompletionCallback, calling handleNMASCallback()" );
                         try
                         {
                             handleNMASCallback( ( NMASCallback ) callback );
@@ -748,7 +749,7 @@ public class NMASCrOperator implements CrOperator
                     }
                     else if ( LCMUserPromptCallback.class.getName().equals( callbackClassname ) )
                     {
-                        LOGGER.trace( "callback is instance of LCMUserPromptCallback, calling handleLCMUserPromptCallback()" );
+                        LOGGER.trace( () -> "callback is instance of LCMUserPromptCallback, calling handleLCMUserPromptCallback()" );
                         try
                         {
                             handleLCMUserPromptCallback( ( LCMUserPromptCallback ) callback );
@@ -761,7 +762,7 @@ public class NMASCrOperator implements CrOperator
                     else
                     {
                         unsupportedCallbackHasOccurred = true;
-                        LOGGER.trace( "throwing UnsupportedCallbackException for " + callback.toString() + ", class=" + callback.getClass().getName() );
+                        LOGGER.trace( () -> "throwing UnsupportedCallbackException for " + callback.toString() + ", class=" + callback.getClass().getName() );
                         throw new UnsupportedCallbackException( callback );
                     }
                 }
@@ -774,7 +775,7 @@ public class NMASCrOperator implements CrOperator
                 Instant lastLogTime = Instant.now();
                 while ( !done && TimeDuration.fromCurrent( startTime ).isShorterThan( maxThreadIdleTime ) )
                 {
-                    LOGGER.trace( "attempt to read return code, but isNmasDone=false, will await completion" );
+                    LOGGER.trace( () -> "attempt to read return code, but isNmasDone=false, will await completion" );
                     JavaHelper.pause( 10 );
                     if ( completeOnUnsupportedFailure )
                     {
@@ -786,7 +787,7 @@ public class NMASCrOperator implements CrOperator
                     }
                     if ( TimeDuration.SECOND.isLongerThan( TimeDuration.fromCurrent( lastLogTime ) ) )
                     {
-                        LOGGER.trace( "waiting for return code: " + TimeDuration.fromCurrent( startTime ).asCompactString()
+                        LOGGER.trace( () -> "waiting for return code: " + TimeDuration.fromCurrent( startTime ).asCompactString()
                                 + " unsupportedCallbackHasOccurred=" + unsupportedCallbackHasOccurred );
                         lastLogTime = Instant.now();
                     }
@@ -890,7 +891,7 @@ public class NMASCrOperator implements CrOperator
         {
             try
             {
-                LOGGER.trace( "starting NMASSessionThread, activeCount=" + sessionMonitorThreads.size() + ", " + this.toDebugString() );
+                LOGGER.trace( () -> "starting NMASSessionThread, activeCount=" + sessionMonitorThreads.size() + ", " + this.toDebugString() );
                 sessionMonitorThreads.add( this );
                 controlWatchdogThread();
                 doLoginSequence();
@@ -899,7 +900,7 @@ public class NMASCrOperator implements CrOperator
             {
                 sessionMonitorThreads.remove( this );
                 controlWatchdogThread();
-                LOGGER.trace( "exiting NMASSessionThread, activeCount=" + sessionMonitorThreads.size() + ", " + this.toDebugString() );
+                LOGGER.trace( () -> "exiting NMASSessionThread, activeCount=" + sessionMonitorThreads.size() + ", " + this.toDebugString() );
             }
         }
 
@@ -913,7 +914,7 @@ public class NMASCrOperator implements CrOperator
             if ( this.ldapConn == null )
             {
                 setLoginState( NMASThreadState.COMPLETED );
-                setLoginResult( new com.novell.security.nmas.client.NMASLoginResult( -1681 ) );
+                setLoginResult( new com.novell.security.nmas.client.NMASLoginResult( NMASConstants.NMAS_E_TRANSPORT ) );
                 lastActivityTimestamp = Instant.now();
                 return;
             }
@@ -980,7 +981,7 @@ public class NMASCrOperator implements CrOperator
         public void abort( )
         {
             setLoginState( NMASThreadState.ABORTED );
-            setLoginResult( new com.novell.security.nmas.client.NMASLoginResult( -1681 ) );
+            setLoginResult( new com.novell.security.nmas.client.NMASLoginResult( NMASConstants.NMAS_E_TRANSPORT ) );
 
             try
             {
@@ -997,7 +998,7 @@ public class NMASCrOperator implements CrOperator
             }
             catch ( Exception e )
             {
-                LOGGER.trace( "error during NMASResponseSession abort: " + e.getMessage(), e );
+                LOGGER.trace( () -> "error during NMASResponseSession abort: " + e.getMessage() );
             }
         }
 
@@ -1055,7 +1056,7 @@ public class NMASCrOperator implements CrOperator
             {
                 threadDebugInfo.append( "\n " ).append( thread.toDebugString() );
             }
-            LOGGER.trace( threadDebugInfo.toString() );
+            LOGGER.trace( () -> threadDebugInfo.toString() );
         }
 
     }
@@ -1123,7 +1124,7 @@ public class NMASCrOperator implements CrOperator
         {
             try
             {
-                LOGGER.trace( "creating new SASL Client instance" );
+                LOGGER.trace( () -> "creating new SASL Client instance" );
                 final SaslClientFactory realFactory = getRealSaslClientFactory();
                 return realFactory.createSaslClient( mechanisms, authorizationId, protocol, serverName, props, cbh );
             }

+ 1 - 1
server/src/main/java/password/pwm/util/operations/otp/AbstractOtpOperator.java

@@ -131,7 +131,7 @@ public abstract class AbstractOtpOperator implements OtpOperator
         }
         OTPUserRecord otpconfig = null;
         /* Try format by format */
-        LOGGER.trace( String.format( "detecting format from value: %s", value ) );
+        LOGGER.trace( () -> String.format( "detecting format from value: %s", value ) );
         /* - PWM JSON */
         try
         {

+ 3 - 3
server/src/main/java/password/pwm/util/operations/otp/DbOtpOperator.java

@@ -59,7 +59,7 @@ public class DbOtpOperator extends AbstractOtpOperator
     @Override
     public OTPUserRecord readOtpUserConfiguration( final UserIdentity theUser, final String userGUID ) throws PwmUnrecoverableException
     {
-        LOGGER.trace( String.format( "Enter: readOtpUserConfiguration(%s, %s)", theUser, userGUID ) );
+        LOGGER.trace( () -> String.format( "Enter: readOtpUserConfiguration(%s, %s)", theUser, userGUID ) );
         if ( userGUID == null || userGUID.length() < 1 )
         {
             throw new PwmUnrecoverableException( new ErrorInformation( PwmError.ERROR_MISSING_GUID, "cannot save otp to db, user does not have a GUID" ) );
@@ -109,7 +109,7 @@ public class DbOtpOperator extends AbstractOtpOperator
                     "cannot save OTP secret to remote database, user " + theUser + " does not have a guid" ) );
         }
 
-        LOGGER.trace( "attempting to save OTP secret for " + theUser + " in remote database (key=" + userGUID + ")" );
+        LOGGER.trace( () -> "attempting to save OTP secret for " + theUser + " in remote database (key=" + userGUID + ")" );
 
         try
         {
@@ -150,7 +150,7 @@ public class DbOtpOperator extends AbstractOtpOperator
                     ) );
         }
 
-        LOGGER.trace( "attempting to clear OTP secret for " + theUser + " in remote database (key=" + userGUID + ")" );
+        LOGGER.trace( () -> "attempting to clear OTP secret for " + theUser + " in remote database (key=" + userGUID + ")" );
 
         try
         {

+ 1 - 1
server/src/main/java/password/pwm/util/operations/otp/LocalDbOtpOperator.java

@@ -60,7 +60,7 @@ public class LocalDbOtpOperator extends AbstractOtpOperator
     @Override
     public OTPUserRecord readOtpUserConfiguration( final UserIdentity theUser, final String userGUID ) throws PwmUnrecoverableException
     {
-        LOGGER.trace( String.format( "Enter: readOtpUserConfiguration(%s, %s)", theUser, userGUID ) );
+        LOGGER.trace( () -> String.format( "Enter: readOtpUserConfiguration(%s, %s)", theUser, userGUID ) );
         if ( userGUID == null || userGUID.length() < 1 )
         {
             throw new PwmUnrecoverableException( new ErrorInformation( PwmError.ERROR_MISSING_GUID, "cannot save otp to localDB, user does not have a GUID" ) );

+ 2 - 1
server/src/main/java/password/pwm/util/operations/otp/OTPPamUtil.java

@@ -95,7 +95,8 @@ public class OTPPamUtil
                     }
                     else
                     {
-                        LOGGER.trace( String.format( "Unrecognized line: \"%s\"", line ) );
+                        final String finalLine = line;
+                        LOGGER.trace( () -> String.format( "Unrecognized line: \"%s\"", finalLine ) );
                     }
                 }
                 if ( recoveryCodes.isEmpty() )

+ 2 - 2
server/src/main/java/password/pwm/util/queue/SmsQueueManager.java

@@ -396,7 +396,7 @@ public class SmsQueueManager implements PwmService
             final Matcher m = p.matcher( resultBody );
             if ( m.matches() )
             {
-                LOGGER.trace( "result body matched configured regex match setting: " + regex );
+                LOGGER.trace( () -> "result body matched configured regex match setting: " + regex );
                 return;
             }
         }
@@ -494,7 +494,7 @@ public class SmsQueueManager implements PwmService
 
             final String requestData = makeRequestData( to, message );
 
-            LOGGER.trace( "preparing to send SMS data: " + requestData );
+            LOGGER.trace( () -> "preparing to send SMS data: " + requestData );
 
             final PwmHttpClientRequest pwmHttpClientRequest = makeRequest( requestData );
 

+ 1 - 1
server/src/main/java/password/pwm/util/secure/X509Utils.java

@@ -199,7 +199,7 @@ public abstract class X509Utils
         }
         catch ( Exception e )
         {
-            LOGGER.trace( "exception while testing ldap server cert validity against default keystore: " + e.getMessage() );
+            LOGGER.trace( () -> "exception while testing ldap server cert validity against default keystore: " + e.getMessage() );
         }
 
         return false;

+ 1 - 1
server/src/main/java/password/pwm/ws/client/rest/RestClientHelper.java

@@ -67,7 +67,7 @@ public class RestClientHelper
             LOGGER.debug( "beginning external rest call to: " + httpPost.toString() + ", body: " + jsonRequestBody );
             httpResponse = PwmHttpClient.getHttpClient( pwmApplication.getConfig() ).execute( httpPost );
             final String responseBody = EntityUtils.toString( httpResponse.getEntity() );
-            LOGGER.trace( "external rest call returned: " + httpResponse.getStatusLine().toString() + ", body: " + responseBody );
+            LOGGER.trace( () -> "external rest call returned: " + httpResponse.getStatusLine().toString() + ", body: " + responseBody );
             if ( httpResponse.getStatusLine().getStatusCode() != 200 )
             {
                 final String errorMsg = "received non-200 response code (" + httpResponse.getStatusLine().getStatusCode() + ") when executing web-service";

+ 1 - 1
server/src/main/java/password/pwm/ws/client/rest/form/RestFormDataClient.java

@@ -119,7 +119,7 @@ public class RestFormDataClient
         {
             httpResponse = getHttpClient( pwmApplication.getConfig() ).makeRequest( pwmHttpClientRequest );
             final String responseBody = httpResponse.getBody();
-            LOGGER.trace( "external rest call returned: " + httpResponse.getStatusPhrase() + ", body: " + responseBody );
+            LOGGER.trace( () -> "external rest call returned: " + httpResponse.getStatusPhrase() + ", body: " + responseBody );
             if ( httpResponse.getStatusCode() != 200 )
             {
                 final String errorMsg = "received non-200 response code (" + httpResponse.getStatusCode() + ") when executing web-service";