Logger showing messages as WARN even if they aren't Java

Question

I have there this class GameLogger:

package me.retamrovec.thebridge.game;

import org.jetbrains.annotations.NotNull;

import java.util.logging.*;

public class GameLogger extends Logger {

    String prefix;

    public GameLogger(@NotNull Game game) {
        super(getAnonymousLogger().getName(), null);
        prefix = "[TheBridge-GameLogger-" + game.getUniqueId() + "] ";
        Handler handler = new ConsoleHandler();
        handler.setLevel(Level.ALL);
        handler.setFormatter(new SimpleFormatter() {
            private static final String format = "%1$s %n";

            @Override
            public String format(LogRecord record) {
                return String.format(format,
                        record.getMessage()
                        );
            }
        });

        addHandler(handler);
        setLevel(Level.ALL);
    }

    @Override
    public void log(@NotNull LogRecord logRecord) {
        logRecord.setMessage(prefix + logRecord.getMessage());
        super.log(logRecord);
    }

    @Override
    public void warning(String message) {
        log(Level.WARNING, message);
    }

    @Override
    public void severe(String message) {
        log(Level.SEVERE, message);
    }

    @Override
    public void info(String message) {
        log(Level.INFO, message);
    }
}

and then this piece of code:

        gameLogger.info(". Hey! This is " + tick + "/20 game tick.");
        gameLogger.fine(".. Hey! This is " + tick + "/20 game tick.");
        gameLogger.severe("... Hey! This is " + tick + "/20 game tick.");
        gameLogger.warning(".... Hey! This is " + tick + "/20 game tick.");
        gameLogger.finest("..... Hey! This is " + tick + "/20 game tick.");
        gameLogger.finer("...... Hey! This is " + tick + "/20 game tick.");

The issue is, every log (fine, info, severe, finest, finer) are marked as WARN even if they aren't, when I try to debug what is LogRecord's level, then it returns me level which should be here.

I tried using GameLogger#log(Level, String), still same result.

Answer 1

It's interesting that you say that all your logging lines are marked as WARN even when they aren't. Because when I ran the code in your question, I got this:

[TheBridge-GameLogger-8] . Hey! This is 7/20 game tick.
[TheBridge-GameLogger-8] .. Hey! This is 7/20 game tick.
[TheBridge-GameLogger-8] ... Hey! This is 7/20 game tick.
[TheBridge-GameLogger-8] .... Hey! This is 7/20 game tick.
[TheBridge-GameLogger-8] ..... Hey! This is 7/20 game tick.
[TheBridge-GameLogger-8] ...... Hey! This is 7/20 game tick.

None of these are marked as WARN, or any other level for that matter. Also, I set tick to 7 and set the getUniqueId() method in your Game class to unconditionally return 8, just to get your code to compile.

There is no log level in your log output, because your custom SimpleFormatter subclass doesn't write out any log level. All it writes out is the message, which has gained a prefix in your override of the log method.

If you want to output the log level, you will need to modify your formatter to write it out. One way to do this would be to modify your formatter to add an extra placeholder for the level. While doing this, however, I found that automatically attaching the prefix to the message was unhelpful: it seemed more natural to put the log message in between the prefix and the message, rather than before or after them. I therefore deleted your override of the log method, and used the formatter to include the prefix in the log messages.

I ended up with the following:

        handler.setFormatter(new SimpleFormatter() {
            private static final String format = "%1$s %2$-7s %3$s %n";

            @Override
            public String format(LogRecord record) {
                return String.format(format,
                        prefix,
                        record.getLevel(),
                        record.getMessage());
            };
        });

I included the -7 in %2$-7s to ensure that log messages after the levels align. When I then ran your code, I got the following output, which I would hope is closer to what you are looking for:

[TheBridge-GameLogger-8] INFO    . Hey! This is 7/20 game tick.
[TheBridge-GameLogger-8] FINE    .. Hey! This is 7/20 game tick.
[TheBridge-GameLogger-8] SEVERE  ... Hey! This is 7/20 game tick.
[TheBridge-GameLogger-8] WARNING .... Hey! This is 7/20 game tick.
[TheBridge-GameLogger-8] FINEST  ..... Hey! This is 7/20 game tick.
[TheBridge-GameLogger-8] FINER   ...... Hey! This is 7/20 game tick.

I also didn't see what you were gaining with your overrides of the warning(), severe() and info() methods. I deleted them and got identical output.

Answer 2

Okay, what I did was: I used Bukkit#getLogger and writed it so it still has prefix, I need and it works perfectly, still I don't know how would I fix always WARN, but seems like something was overriding my format.