Flogger automated migration from other logging APIs via Error Prone

[cslee00]

For awareness, working on Error Prone refactoring to migrate from other logging APIs:

https://github.com/cslee00/digitalascent-errorprone-logger

[hagbard]

Wow, thanks for looking at this.

Inside Google there's a quite sophisticated (but not error-prone) mechanism for doing migrations, and while the code itself is a bit hard to open-source, it does solve a lot of common problems (we decided to not just migrate people's log statements, but to canonicalize them in the process since there were so cases of "bad" or at least "questionable" usage).

e.g. Old style JDK log statements like:
Foo foo = ...;
int bar = ...;
logger.info("foo={0}, bar={1}", new Object[] { foo, bar })
would be fully rewritten to:
logger.atInfo().log("foo=%s, bar=%d", foo, bar);

And common errors (e.g. bad escaping or wrong number of placeholders) would be detected and, in some cases, automatically fixed. I'm happy to share the sort of checks and transformations we're doing if it might help you.

There are also some internal error-prone checks for Flogger correctness which we might be able to open-source if we haven't already (ensuring that once people have migrated, they conform to best practice).

[cslee00]

Would welcome any insight into checks / transformations - thanks!

So far have managed to canonicalize various source APIs, such as:

        someLogger.error("test message");
        someLogger.error(DummyLog4J2Marker.INSTANCE, "test message");
        someLogger.log(Level.ERROR, "test message");
        someLogger.log(Level.ERROR, DummyLog4J2Marker.INSTANCE, "test message");

and

        logger.error("test message");
        logger.error(DummySlf4JMarker.INSTANCE, "test message");
        logger.atInfo().log("1. Single parameter: %s","abc");
        logger.atInfo().log("2. Escaped formatting anchor: \\{}");
        logger.atInfo().log("3. Escaped anchor and single parameter: {} %s", "abc");
        logger.atInfo().log("4. Escaped anchors and single parameter: {} %s {}", "abc");
        logger.atInfo().log("5. Double-escaped anchor, single parameter: \\%s", "abc");
        logger.atInfo().log("6. Double-escaped anchor, no parameter: \\\\{}");
        logger.atInfo().log("7. Single parameter, double-escaped anchor: %s \\%s", "abc");
        logger.atInfo().log("8. Percent sign: 5%% of %s", "abc");

and

        someLogger.severe("test message");
        someLogger.log(Level.SEVERE, "test message");

        someLogger.log(CustomJULLevel.LEVEL_1, "test message");
        someLogger.log(CustomJULLevel.LEVEL_2, "test message");
        someLogger.log(CustomJULLevel.LEVEL_3, "test message");

into their canonical Flogger form, such as:

        logger.atSevere().log( "test message" );
        someLogger.at(CustomJULLevel.LEVEL_1).log( "test message" );
        logger.atInfo().log("1. Single parameter: %s","abc");
        logger.atInfo().log("2. Escaped formatting anchor: \\{}");
        logger.atInfo().log("3. Escaped anchor and single parameter: {} %s", "abc");
        logger.atInfo().log("4. Escaped anchors and single parameter: {} %s {}", "abc");
        logger.atInfo().log("5. Double-escaped anchor, single parameter: \\%s", "abc");
        logger.atInfo().log("6. Double-escaped anchor, no parameter: \\\\{}");
        logger.atInfo().log("7. Single parameter, double-escaped anchor: %s \\%s", "abc");
        logger.atInfo().log("8. Percent sign: 5%% of %s", "abc");

Current plan is to migrate (canonicalize) log statements, including transforming message format strings, leaving further refactorings / verifications to subsequent Flogger checks, such as:

• check validity of format string (parameter count, format specifiers);
• check/migrate format specifiers to appropriate types (e.g. %d vs %s)
• removal of redundant conditional statements around logging;
• migration of string-concatenated message format strings to use parameters;
• remove redundant toString() calls for parameters;
• move any expensive parameters (e.g. function calls) to be lazy;

...and likely others. It's likely that Google's Flogger checks overlap heavily here. Not finding any Flogger checks in open-source Error Prone (https://errorprone.info/bugpatterns); if those could be made open-source that would be great, no point in re-inventing them.

[hagbard]

Just FYI, escaping in printf is done with '%', so:

logger.atInfo().log("7. Single parameter, double-escaped anchor: %s \\%s", "abc");

Looks wrong to me, I think it should be:

logger.atInfo().log("7. Single parameter, double-escaped anchor: %s %%s", "abc");

[cslee00]

Thanks. Missing context: that example was from this SLF4J input:

logger.info("7. Single parameter, double-escaped anchor: {} \\\\{}", "abc");

...where SLF4J treats \{} as escaping the format anchor and \\{} as a preceding backslash before the format anchor, which is then replaced by %s.
In all cases the to-be-migrated format string escapes % as %% prior to applying API-specific format string migration.

[hagbard]

Ahh okay. It's just that as written:

logger.atInfo().log("7. Single parameter, double-escaped anchor: %s \\%s", "abc");

would trigger a "too few parameters" error in our checks and the runtime code, since it expects 2 arguments for the 2 placeholders.

Also, as regards existing checks, I think we do most of what you're suggesting already, so it's definitely not worth spending much time on that until I can get an answer about open-sourcing what we have.