Tomcat logging confusion

If I’m understanding correctly you end up with a logging properties that looks like:

java.util.logging.ConsoleHandler.level = FINER
org.apache.catalina.realm.level = FINER

The Java Logging Overview section 1.1 states:

Applications make logging calls on Logger objects. Loggers are organized in a hierarchical namespace and child Loggers may inherit some logging properties from their parents in the namespace.

When reading the logger names the parent loggers are to the left of the dots.
Therefore, org.apache.catalina is the parent of org.apache.catalina.realm and org.apache.catalina.core.

The executing code code has to demand a logger in order for it to exist. Simply adding lines in the properties file doesn’t create loggers. If it did they would just be garbage collected anyway. This means that say you have a logger tree A <- B <- C. You want to set the level for B and therefor all of B children so you add A.B.level line in the properties file. However, at run-time the loggers that are demanded are A and C

So what you have to work with is "" <- A <- A.B.C when you are expecting "" <- A <- A.B <- A.B.C

Putting that all together, I think at runtime your loggers look like:

"" <- org.apache.catalina <- org.apache.catalina.realm.RealmBase and no Tomcat code has created an actual logger named org.apache.catalina.realm.

You can verify by connecting JConsole to runnting JVM and checking the MBean tab and listing the logger names. On Tomcat this won’t work because the loggers returned depend on the calling classloader.

To work around this you can use the config option to demand and hold the logger in memory. You just have to install this on the custom code on the system class path.

Otherwise you have to specify all the known child logger names in the properties file which can be verbose.

First idea: If we look at the CSS specifity we know that .mydiv{ color:red} is not as specific as div.mydiv{color: green} so a div.mydiv contains text in red? Inheriance means if not specified what is anti-inheritance.

Unlike CSS, JUL has a runtime logger tree and a properties file. That runtime logger tree is dynamically adjusted as executing code demands loggers. The properties are only ever used if code demands a logger. Specifying a logger name in the properties file doesn’t mean a thing unless the logger is created by code. This can change the parents of a logger and therefore the level. Give it a spin:

package so;

import java.io.ByteArrayInputStream;
import java.io.ByteArrayOutputStream;
import java.io.IOException;
import java.util.Properties;
import java.util.logging.Level;
import java.util.logging.LogManager;
import java.util.logging.Logger;

public class TheMissingParent {

    private static final Logger[] LAZY_ONE;
    static {
        LAZY_ONE = new Logger[] { Logger.getLogger("org.apache.catalina"),
                Logger.getLogger("org.apache.catalina.realm.RealmBase") };
    }

    private static volatile Logger[] LAZY_TWO;

    public static void main(String[] args) {
        loadProperties();
        printAncestors(LAZY_ONE);
        findlLongLostParents();
        System.out.println("====");
        printAncestors(LAZY_ONE);
    }

    private static void loadProperties() {
        Properties props = new Properties();
        props.put("org.apache.catalina.realm.level", "FINER");

        try(ByteArrayOutputStream out = new ByteArrayOutputStream()) {
            props.store(out, "");
            LogManager.getLogManager().readConfiguration(new ByteArrayInputStream(out.toByteArray()));
        } catch (IOException ioe) {
            throw new AssertionError(ioe);
        }
    }

    private static void findlLongLostParents() {
        LAZY_TWO = new Logger[] {Logger.getLogger("org.apache.catalina.realm") };
    }

    private static void printAncestors(Logger[] loggers) {
        // System.out.println(loggers.toString());
        for (Logger l : loggers) {
            printAncestors(l);
            System.out.println();
        }
    }

    private static void printAncestors(Logger l) {
        if (l != null) {
            printAncestors(l.getParent());
            System.out.print("<-");
            String name = l.getName();
            if (name != null && name.isEmpty()) {
                System.out.append("\"\"");
            } else {
                System.out.append(name);
            }

            for(Logger p = l; p != null; p = p.getParent()) {
                Level lvl = p.getLevel();
                if (lvl != null) {
                    System.out.append('{').append(lvl.getName()).append('}');
                    break;
                }
            }
        }
    }
}

This will output:

<-""{INFO}<-org.apache.catalina{INFO}
<-""{INFO}<-org.apache.catalina{INFO}<-org.apache.catalina.realm.RealmBase{INFO}
====
<-""{INFO}<-org.apache.catalina{INFO}
<-""{INFO}<-org.apache.catalina{INFO}<-org.apache.catalina.realm{FINER}<-org.apache.catalina.realm.RealmBase{FINER}

This is the core issue. If Tomcat (or some custom code) never demands a org.apache.catalina.realm logger that line in the properties file is just dead code.

Second, if you say so, noone specified to org.apache.catalina nor org.apache nor org nor “ to be level INFO, so where would the value INFO came from?

That behavior is described in the LoggerManager class level docs:

If neither of these properties is defined then, as described above, the LogManager will read its initial configuration from a properties file “lib/logging.properties” in the JRE directory.

The root logger named as empty string "" is the parent of all loggers. The root logger is always created.