#605 Add custom log levels, create debug logging method

- Log levels in the log file too
- Create migration from old boolean "stop spam" property to new log level property

src/main/java/fr/xephi/authme/ConsoleLogger.java

@@ -1,7 +1,9 @@
 package fr.xephi.authme;
 
 import com.google.common.base.Throwables;
+import fr.xephi.authme.output.LogLevel;
 import fr.xephi.authme.settings.NewSetting;
+import fr.xephi.authme.settings.properties.PluginSettings;
 import fr.xephi.authme.settings.properties.SecuritySettings;
 import fr.xephi.authme.util.StringUtils;
 
@@ -21,6 +23,7 @@ public final class ConsoleLogger {
     private static final String NEW_LINE = System.getProperty("line.separator");
     private static final DateFormat DATE_FORMAT = new SimpleDateFormat("[MM-dd HH:mm:ss]");
     private static Logger logger;
+    private static LogLevel logLevel = LogLevel.INFO;
     private static boolean useLogging = false;
     private static File logFile;
     private static FileWriter fileWriter;
@@ -28,15 +31,35 @@ public final class ConsoleLogger {
     private ConsoleLogger() {
     }
 
+    // --------
+    // Configurations
+    // --------
+
+    /**
+     * Set the logger to use.
+     *
+     * @param logger The logger
+     */
     public static void setLogger(Logger logger) {
         ConsoleLogger.logger = logger;
     }
 
+    /**
+     * Set the file to log to if enabled.
+     *
+     * @param logFile The log file
+     */
     public static void setLogFile(File logFile) {
         ConsoleLogger.logFile = logFile;
     }
 
+    /**
+     * Load the required settings.
+     *
+     * @param settings The settings instance
+     */
     public static void setLoggingOptions(NewSetting settings) {
+        ConsoleLogger.logLevel = settings.getProperty(PluginSettings.LOG_LEVEL);
         ConsoleLogger.useLogging = settings.getProperty(SecuritySettings.USE_LOGGING);
         if (useLogging) {
             if (fileWriter == null) {
@@ -51,64 +74,81 @@ public final class ConsoleLogger {
         }
     }
 
-    /**
-     * Print an info message.
-     *
-     * @param message String
-     */
-    public static void info(String message) {
-        logger.info(message);
-        if (useLogging) {
-            writeLog("[INFO] " + message);
-        }
 
-    }
+    // --------
+    // Logging methods
+    // --------
 
     /**
-     * Print an error message.
+     * Log a WARN message.
      *
-     * @param message String
+     * @param message The message to log
      */
     public static void warning(String message) {
         logger.warning(message);
-        if (useLogging) {
+        writeLog("[WARN] " + message);
-            writeLog("[WARN] " + message);
-        }
     }
 
     /**
-     * Write a message into the log file with a TimeStamp.
+     * Log an INFO message.
      *
-     * @param message String
+     * @param message The message to log
      */
-    private static void writeLog(String message) {
+    public static void info(String message) {
-        String dateTime;
+        logger.info(message);
-        synchronized (DATE_FORMAT) {
+        writeLog("[INFO] " + message);
-            dateTime = DATE_FORMAT.format(new Date());
+    }
-        }
+
-        try {
+    /**
-            fileWriter.write(dateTime);
+     * Log a FINE message if enabled.
-            fileWriter.write(": ");
+     * <p>
-            fileWriter.write(message);
+     * Implementation note: this logs a message on INFO level because
-            fileWriter.write(NEW_LINE);
+     * levels below INFO are disabled by Bukkit/Spigot.
-            fileWriter.flush();
+     *
-        } catch (IOException ignored) {
+     * @param message The message to log
+     */
+    public static void fine(String message) {
+        if (logLevel.includes(LogLevel.FINE)) {
+            logger.info(message);
+            writeLog("[FINE] " + message);
         }
     }
 
     /**
-     * Logs a Throwable with the provided message and saves the stack trace to the log file.
+     * Log a DEBUG message if enabled.
+     * <p>
+     * Implementation note: this logs a message on INFO level and prefixes it with "DEBUG" because
+     * levels below INFO are disabled by Bukkit/Spigot.
+     *
+     * @param message The message to log
+     */
+    public static void debug(String message) {
+        if (logLevel.includes(LogLevel.DEBUG)) {
+            logger.info("Debug: " + message);
+            writeLog("[DEBUG] " + message);
+        }
+    }
+
+    /**
+     * Log a Throwable with the provided message on WARNING level
+     * and save the stack trace to the log file.
      *
      * @param message The message to accompany the exception
      * @param th      The Throwable to log
      */
     public static void logException(String message, Throwable th) {
         warning(message + " " + StringUtils.formatException(th));
-        if (useLogging) {
+        writeLog(Throwables.getStackTraceAsString(th));
-            writeLog(Throwables.getStackTraceAsString(th));
-        }
     }
 
+
+    // --------
+    // Helpers
+    // --------
+
+    /**
+     * Close all file handles.
+     */
     public static void close() {
         if (fileWriter != null) {
             try {
@@ -119,4 +159,26 @@ public final class ConsoleLogger {
             }
         }
     }
+
+    /**
+     * Write a message into the log file with a TimeStamp if enabled.
+     *
+     * @param message The message to write to the log
+     */
+    private static void writeLog(String message) {
+        if (useLogging) {
+            String dateTime;
+            synchronized (DATE_FORMAT) {
+                dateTime = DATE_FORMAT.format(new Date());
+            }
+            try {
+                fileWriter.write(dateTime);
+                fileWriter.write(": ");
+                fileWriter.write(message);
+                fileWriter.write(NEW_LINE);
+                fileWriter.flush();
+            } catch (IOException ignored) {
+            }
+        }
+    }
 }

src/main/java/fr/xephi/authme/command/executable/email/RecoverEmailCommand.java

@@ -12,7 +12,6 @@ import fr.xephi.authme.security.PasswordSecurity;
 import fr.xephi.authme.security.RandomString;
 import fr.xephi.authme.security.crypts.HashedPassword;
 import fr.xephi.authme.settings.properties.EmailSettings;
-import fr.xephi.authme.util.StringUtils;
 import org.bukkit.entity.Player;
 
 import javax.inject.Inject;
@@ -46,13 +45,11 @@ public class RecoverEmailCommand extends PlayerCommand {
             return;
         }
         if (dataSource.isAuthAvailable(playerName)) {
-            if (PlayerCache.getInstance().isAuthenticated(playerName)) {
+            if (playerCache.isAuthenticated(playerName)) {
                 commandService.send(player, MessageKey.ALREADY_LOGGED_IN_ERROR);
                 return;
             }
 
-            String thePass = RandomString.generate(commandService.getProperty(EmailSettings.RECOVERY_PASSWORD_LENGTH));
-            HashedPassword hashNew = passwordSecurity.computeHash(thePass, playerName);
             PlayerAuth auth;
             if (playerCache.isAuthenticated(playerName)) {
                 auth = playerCache.getAuth(playerName);
@@ -62,17 +59,15 @@ public class RecoverEmailCommand extends PlayerCommand {
                 commandService.send(player, MessageKey.UNKNOWN_USER);
                 return;
             }
-            if (StringUtils.isEmpty(commandService.getProperty(EmailSettings.MAIL_ACCOUNT))) {
-                ConsoleLogger.warning("No mail account set in settings");
-                commandService.send(player, MessageKey.ERROR);
-                return;
-            }
 
             if (!playerMail.equalsIgnoreCase(auth.getEmail()) || "your@email.com".equalsIgnoreCase(playerMail)
                 || "your@email.com".equalsIgnoreCase(auth.getEmail())) {
                 commandService.send(player, MessageKey.INVALID_EMAIL);
                 return;
             }
+
+            String thePass = RandomString.generate(commandService.getProperty(EmailSettings.RECOVERY_PASSWORD_LENGTH));
+            HashedPassword hashNew = passwordSecurity.computeHash(thePass, playerName);
             auth.setPassword(hashNew);
             dataSource.updatePassword(auth);
             sendMailSsl.sendPasswordMail(auth, thePass);

src/main/java/fr/xephi/authme/hooks/BungeeCordMessage.java

@@ -2,14 +2,12 @@ package fr.xephi.authme.hooks;
 
 import com.google.common.io.ByteArrayDataInput;
 import com.google.common.io.ByteStreams;
-
 import fr.xephi.authme.ConsoleLogger;
 import fr.xephi.authme.cache.auth.PlayerAuth;
 import fr.xephi.authme.cache.auth.PlayerCache;
 import fr.xephi.authme.datasource.DataSource;
 import fr.xephi.authme.security.crypts.HashedPassword;
 import fr.xephi.authme.settings.NewSetting;
-import fr.xephi.authme.settings.properties.SecuritySettings;
 import fr.xephi.authme.util.BukkitService;
 import org.bukkit.entity.Player;
 import org.bukkit.plugin.messaging.PluginMessageListener;
@@ -56,21 +54,13 @@ public class BungeeCordMessage implements PluginMessageListener {
                     if ("login".equals(act)) {
                         playerCache.updatePlayer(auth);
                         dataSource.setLogged(name);
-
+                        ConsoleLogger.fine("Player " + auth.getNickname() + " has logged in from one of your server!");
-                        if (!settings.getProperty(SecuritySettings.REMOVE_SPAM_FROM_CONSOLE)) {
-                            ConsoleLogger.info("Player " + auth.getNickname() + " has logged in from one of your server!");
-                        }
                     } else if ("logout".equals(act)) {
                         playerCache.removePlayer(name);
                         dataSource.setUnlogged(name);
-
+                        ConsoleLogger.fine("Player " + auth.getNickname() + " has logged out from one of your server!");
-                        if (!settings.getProperty(SecuritySettings.REMOVE_SPAM_FROM_CONSOLE)) {
-                            ConsoleLogger.info("Player " + auth.getNickname() + " has logged out from one of your server!");
-                        }
                     } else if ("register".equals(act)) {
-                        if (!settings.getProperty(SecuritySettings.REMOVE_SPAM_FROM_CONSOLE)) {
+                        ConsoleLogger.fine("Player " + auth.getNickname() + " has registered out from one of your server!");
-                            ConsoleLogger.info("Player " + auth.getNickname() + " has registered out from one of your server!");
-                        }
                     } else if ("changepassword".equals(act)) {
                         final String password = args[2];
                         final String salt = args.length >= 4 ? args[3] : null;

src/main/java/fr/xephi/authme/output/LogLevel.java

@@ -0,0 +1,38 @@
+package fr.xephi.authme.output;
+
+/**
+ * Log level.
+ */
+public enum LogLevel {
+
+    /** Info: general messages. */
+    INFO(3),
+
+    /** Fine: more detailed messages that may still be interesting to plugin users. */
+    FINE(2),
+
+    /** Debug: very detailed messages for debugging. */
+    DEBUG(1);
+
+    private int value;
+
+    /**
+     * Constructor.
+     *
+     * @param value the log level; the higher the number the more "important" the level.
+     *              A log level enables its number and all above.
+     */
+    LogLevel(int value) {
+        this.value = value;
+    }
+
+    /**
+     * Return whether the current log level includes the given log level.
+     *
+     * @param level the level to process
+     * @return true if the level is enabled, false otherwise
+     */
+    public boolean includes(LogLevel level) {
+        return value <= level.value;
+    }
+}

src/main/java/fr/xephi/authme/process/join/AsynchronousJoin.java

@@ -18,7 +18,6 @@ import fr.xephi.authme.settings.properties.HooksSettings;
 import fr.xephi.authme.settings.properties.PluginSettings;
 import fr.xephi.authme.settings.properties.RegistrationSettings;
 import fr.xephi.authme.settings.properties.RestrictionSettings;
-import fr.xephi.authme.settings.properties.SecuritySettings;
 import fr.xephi.authme.task.PlayerDataTaskManager;
 import fr.xephi.authme.util.BukkitService;
 import fr.xephi.authme.util.Utils;
@@ -128,9 +127,7 @@ public class AsynchronousJoin implements AsynchronousProcess {
                 bukkitService.callEvent(ev);
                 if (ev.isCancelled()) {
                     player.updateInventory();
-                    if (!service.getProperty(SecuritySettings.REMOVE_SPAM_FROM_CONSOLE)) {
+                    ConsoleLogger.fine("ProtectInventoryEvent has been cancelled for " + player.getName() + "...");
-                        ConsoleLogger.info("ProtectInventoryEvent has been cancelled for " + player.getName() + "...");
-                    }
                 }
             }
 

src/main/java/fr/xephi/authme/process/login/AsynchronousLogin.java

@@ -22,7 +22,6 @@ import fr.xephi.authme.settings.Settings;
 import fr.xephi.authme.settings.properties.DatabaseSettings;
 import fr.xephi.authme.settings.properties.EmailSettings;
 import fr.xephi.authme.settings.properties.RestrictionSettings;
-import fr.xephi.authme.settings.properties.SecuritySettings;
 import fr.xephi.authme.task.PlayerDataTaskManager;
 import fr.xephi.authme.util.BukkitService;
 import fr.xephi.authme.util.StringUtils;
@@ -165,9 +164,7 @@ public class AsynchronousLogin implements AsynchronousProcess {
                 service.send(player, MessageKey.ADD_EMAIL_MESSAGE);
             }
 
-            if (!service.getProperty(SecuritySettings.REMOVE_SPAM_FROM_CONSOLE)) {
+            ConsoleLogger.fine(player.getName() + " logged in!");
-                ConsoleLogger.info(player.getName() + " logged in!");
-            }
 
             // makes player isLoggedin via API
             playerCache.addPlayer(auth);
@@ -183,9 +180,7 @@ public class AsynchronousLogin implements AsynchronousProcess {
             }
             syncProcessManager.processSyncPlayerLogin(player);
         } else if (player.isOnline()) {
-            if (!service.getProperty(SecuritySettings.REMOVE_SPAM_FROM_CONSOLE)) {
+            ConsoleLogger.fine(player.getName() + " used the wrong password");
-                ConsoleLogger.info(player.getName() + " used the wrong password");
-            }
             if (service.getProperty(RestrictionSettings.KICK_ON_WRONG_PASSWORD)) {
                 bukkitService.scheduleSyncDelayedTask(new Runnable() {
                     @Override
@@ -230,10 +225,8 @@ public class AsynchronousLogin implements AsynchronousProcess {
 
         String message = ChatColor.GRAY + StringUtils.join(ChatColor.GRAY + ", ", formattedNames) + ".";
 
-        if (!service.getProperty(SecuritySettings.REMOVE_SPAM_FROM_CONSOLE)) {
+        ConsoleLogger.fine("The user " + player.getName() + " has " + auths.size() + " accounts:");
-            ConsoleLogger.info("The user " + player.getName() + " has " + auths.size() + " accounts:");
+        ConsoleLogger.fine(message);
-            ConsoleLogger.info(message);
-        }
 
         for (Player onlinePlayer : bukkitService.getOnlinePlayers()) {
             if (onlinePlayer.getName().equalsIgnoreCase(player.getName())

src/main/java/fr/xephi/authme/process/register/ProcessSyncEmailRegister.java

@@ -6,7 +6,6 @@ import fr.xephi.authme.permission.AuthGroupType;
 import fr.xephi.authme.process.ProcessService;
 import fr.xephi.authme.process.SynchronousProcess;
 import fr.xephi.authme.settings.Settings;
-import fr.xephi.authme.settings.properties.SecuritySettings;
 import fr.xephi.authme.task.PlayerDataTaskManager;
 import fr.xephi.authme.util.Utils;
 import org.bukkit.entity.Player;
@@ -36,9 +35,7 @@ public class ProcessSyncEmailRegister implements SynchronousProcess {
         playerDataTaskManager.registerMessageTask(name, true);
 
         player.saveData();
-        if (!service.getProperty(SecuritySettings.REMOVE_SPAM_FROM_CONSOLE)) {
+        ConsoleLogger.fine(player.getName() + " registered " + Utils.getPlayerIp(player));
-            ConsoleLogger.info(player.getName() + " registered " + Utils.getPlayerIp(player));
-        }
     }
 
 }

src/main/java/fr/xephi/authme/process/register/ProcessSyncPasswordRegister.java

@@ -10,7 +10,6 @@ import fr.xephi.authme.service.BungeeService;
 import fr.xephi.authme.settings.Settings;
 import fr.xephi.authme.settings.properties.EmailSettings;
 import fr.xephi.authme.settings.properties.RegistrationSettings;
-import fr.xephi.authme.settings.properties.SecuritySettings;
 import fr.xephi.authme.task.PlayerDataTaskManager;
 import fr.xephi.authme.util.Utils;
 import org.bukkit.Bukkit;
@@ -75,10 +74,7 @@ public class ProcessSyncPasswordRegister implements SynchronousProcess {
         }
 
         player.saveData();
-
+        ConsoleLogger.fine(player.getName() + " registered " + Utils.getPlayerIp(player));
-        if (!service.getProperty(SecuritySettings.REMOVE_SPAM_FROM_CONSOLE)) {
-            ConsoleLogger.info(player.getName() + " registered " + Utils.getPlayerIp(player));
-        }
 
         // Kick Player after Registration is enabled, kick the player
         if (service.getProperty(RegistrationSettings.FORCE_KICK_AFTER_REGISTER)) {

src/main/java/fr/xephi/authme/settings/SettingsMigrationService.java

@@ -1,7 +1,9 @@
 package fr.xephi.authme.settings;
 
 import fr.xephi.authme.ConsoleLogger;
+import fr.xephi.authme.output.LogLevel;
 import fr.xephi.authme.settings.domain.Property;
+import fr.xephi.authme.settings.properties.PluginSettings;
 import fr.xephi.authme.settings.propertymap.PropertyMap;
 import org.bukkit.configuration.file.FileConfiguration;
 
@@ -48,7 +50,8 @@ public class SettingsMigrationService {
         return changes
             | performMailTextToFileMigration(configuration, pluginFolder)
             | migrateJoinLeaveMessages(configuration)
-            | migrateForceSpawnSettings(configuration);
+            | migrateForceSpawnSettings(configuration)
+            | changeBooleanSettingToLogLevelProperty(configuration);
     }
 
     public boolean containsAllSettings(FileConfiguration configuration, PropertyMap propertyMap) {
@@ -141,6 +144,25 @@ public class SettingsMigrationService {
             | moveProperty(oldForceWorlds, FORCE_SPAWN_ON_WORLDS, configuration);
     }
 
+    /**
+     * Changes the old boolean property "hide spam from console" to the new property specifying
+     * the log level.
+     *
+     * @param configuration The file configuration
+     * @return True if the configuration has changed, false otherwise
+     */
+    private static boolean changeBooleanSettingToLogLevelProperty(FileConfiguration configuration) {
+        final String oldPath = "Security.console.noConsoleSpam";
+        final Property<LogLevel> newProperty = PluginSettings.LOG_LEVEL;
+        if (!newProperty.isPresent(configuration) && configuration.contains(oldPath)) {
+            ConsoleLogger.info("Moving '" + oldPath + "' to '" + newProperty.getPath() + "'");
+            LogLevel level = configuration.getBoolean(oldPath) ? LogLevel.INFO : LogLevel.FINE;
+            configuration.set(newProperty.getPath(), level.name());
+            return true;
+        }
+        return false;
+    }
+
     /**
      * Checks for an old property path and moves it to a new path if present.
      *

src/main/java/fr/xephi/authme/settings/properties/PluginSettings.java

@@ -1,5 +1,6 @@
 package fr.xephi.authme.settings.properties;
 
+import fr.xephi.authme.output.LogLevel;
 import fr.xephi.authme.settings.domain.Comment;
 import fr.xephi.authme.settings.domain.Property;
 import fr.xephi.authme.settings.domain.SettingsClass;
@@ -59,6 +60,14 @@ public class PluginSettings implements SettingsClass {
     public static final Property<Boolean> KEEP_COLLISIONS_DISABLED =
         newProperty("settings.restrictions.keepCollisionsDisabled", false);
 
+    @Comment({
+        "Log level: INFO, FINE, DEBUG. Use INFO for general messages,",
+        "FINE for some additional detailed ones (like password failed),",
+        "and DEBUG for debugging"
+    })
+    public static final Property<LogLevel> LOG_LEVEL =
+        newProperty(LogLevel.class, "settings.logLevel", LogLevel.FINE);
+
     private PluginSettings() {
     }
 

src/main/java/fr/xephi/authme/settings/properties/SecuritySettings.java

@@ -22,10 +22,6 @@ public class SecuritySettings implements SettingsClass {
     public static final Property<Boolean> USE_RELOAD_COMMAND_SUPPORT =
         newProperty("Security.ReloadCommand.useReloadCommandSupport", true);
 
-    @Comment("Remove spam from console?")
-    public static final Property<Boolean> REMOVE_SPAM_FROM_CONSOLE =
-        newProperty("Security.console.noConsoleSpam", false);
-
     @Comment("Remove passwords from console?")
     public static final Property<Boolean> REMOVE_PASSWORD_FROM_CONSOLE =
         newProperty("Security.console.removePassword", true);

src/main/resources/config.yml

@@ -266,6 +266,10 @@ settings:
     # Do we need to prevent people to login with another case?
     # If Xephi is registered, then Xephi can login, but not XEPHI/xephi/XePhI
     preventOtherCase: false
+    # Log level: INFO, FINE, DEBUG. Use INFO for general messages,
+    # FINE for some additional detailed ones (like password failed),
+    # and DEBUG for debug messages
+    logLevel: 'FINE'
 ExternalBoardOptions:
     # MySQL column for the salt, needed for some forum/cms support
     mySQLColumnSalt: ''
@@ -311,8 +315,6 @@ Security:
         # /reload support
         useReloadCommandSupport: true
     console:
-        # Remove spam console
-        noConsoleSpam: false
         # Replace passwords in the console when player type a command like /login
         removePassword: true
         # Copy AuthMe log output in a separate file as well?

src/test/java/fr/xephi/authme/command/executable/authme/ReloadCommandTest.java

@@ -8,9 +8,11 @@ import fr.xephi.authme.datasource.DataSource;
 import fr.xephi.authme.datasource.DataSourceType;
 import fr.xephi.authme.initialization.Reloadable;
 import fr.xephi.authme.initialization.SettingsDependent;
+import fr.xephi.authme.output.LogLevel;
 import fr.xephi.authme.output.MessageKey;
 import fr.xephi.authme.settings.NewSetting;
 import fr.xephi.authme.settings.properties.DatabaseSettings;
+import fr.xephi.authme.settings.properties.PluginSettings;
 import fr.xephi.authme.settings.properties.SecuritySettings;
 import org.bukkit.command.CommandSender;
 import org.junit.Before;
@@ -67,7 +69,7 @@ public class ReloadCommandTest {
     @Before
     public void setDefaultSettings() {
         // Mock properties retrieved by ConsoleLogger
-        given(settings.getProperty(SecuritySettings.REMOVE_SPAM_FROM_CONSOLE)).willReturn(false);
+        given(settings.getProperty(PluginSettings.LOG_LEVEL)).willReturn(LogLevel.INFO);
         given(settings.getProperty(SecuritySettings.USE_LOGGING)).willReturn(false);
     }
 

src/test/java/fr/xephi/authme/output/LogLevelTest.java

@@ -0,0 +1,31 @@
+package fr.xephi.authme.output;
+
+import org.junit.Test;
+
+import static java.lang.String.format;
+import static org.hamcrest.Matchers.equalTo;
+import static org.junit.Assert.assertThat;
+
+/**
+ * Test for {@link LogLevel}.
+ */
+public class LogLevelTest {
+
+    @Test
+    public void shouldIncludeProperLevels() {
+        checkLevelInclusion(LogLevel.INFO, true, false, false);
+        checkLevelInclusion(LogLevel.FINE, true, true, false);
+        checkLevelInclusion(LogLevel.DEBUG, true, true, true);
+    }
+
+    private void checkLevelInclusion(LogLevel level, boolean... expectedValues) {
+        LogLevel[] levels = LogLevel.values();
+        assertThat("Number of expected values corresponds to number of log levels",
+            expectedValues.length, equalTo(levels.length));
+        for (int i = 0; i < levels.length; ++i) {
+            assertThat(format("%s.includes(%s) should be %b", level, levels[i], expectedValues[i]),
+                level.includes(levels[i]), equalTo(expectedValues[i]));
+        }
+    }
+
+}