[SOLVED] Java logger broke?


#1

Hello,
This is a question unrelated to jme, but it is an error I have never seen in all of my years of java, and I am at a loss.

My java logger is not filling parameters.
Example:

[2019-02-26 10:55:19] [INFO   ] Server starting 
[2019-02-26 10:55:19] [INFO   ] Framework Version: {0} 
[2019-02-26 10:55:19] [INFO   ] Version: {0} 
[2019-02-26 10:55:19] [INFO   ] Loading JDBC 
[2019-02-26 10:55:20] [INFO   ] Connecting to database 
[2019-02-26 10:55:20] [INFO   ] Connected to DB 
[2019-02-26 10:55:20] [SEVERE ] null 
[2019-02-26 10:55:20] [WARNING] Generating new JME World! 
[2019-02-26 10:55:20] [INFO   ] Loading world {0} 
[2019-02-26 10:55:20] [INFO   ] Starting Groovy script engine 
[2019-02-26 10:55:20] [INFO   ] Script path: {0} 
[2019-02-26 10:55:20] [INFO   ] Running on jMonkeyEngine 3.3-6719
 * Branch: master
 * Git Hash: 512b096
 * Build Date: 2019-02-26 
Bullet-Native: Initializing java classes
[2019-02-26 10:55:20] [INFO   ] Server {0} running on port {1,number,#} 
[2019-02-26 10:55:20] [INFO   ] Server ready 

It just broke today, and I have spent several hours trying to fix it with no luck. Has anyone seen this kind of thing before?

EDIT: I found the issue! my simple formatter is not correct:

        Logger mainLogger = Logger.getLogger("<CENSORED>");
        mainLogger.setUseParentHandlers(false);
        ConsoleHandler handler = new ConsoleHandler();
        handler.setFormatter(new SimpleFormatter() {
            private static final String format = "[%1$tF %1$tT] [%2$-7s] %3$s %n";

            @Override
            public synchronized String format(LogRecord lr) {
                return String.format(format,
                        new Date(lr.getMillis()),
                        lr.getLevel().getLocalizedName(),
                        lr.getMessage()
                );
            }
        });
        mainLogger.addHandler(handler);

Forgot to format the message :disappointed_relieved: in my override.


#2

Another important caveat here is that you’d have to ensure that mainLogger (the logger reference) doesn’t get garbage collected. That’s often the case if you’d have a “silence this logger code” like getLogger("xyz").setParentHandler(null); (google the exact semantics).

That way when getLogger goes out of scope, it’s garbage collected and thus sometimes the settings get lost.

Not related to this one, just so people which may stumble across this thread know what to look at possibly.


#3

Thanks for the heads up, I did not know that!