MathJax

Thursday, January 31, 2019

Mitigating log injection in log4j--with tests!

Problem: Log injection
Log injection is similar to SQL injection or cross-site scripting, but for log messages. Let's say your application's log entries conform to a pattern like this:

<date> [<severity>] <class>: <message><newline>

This might be represented as a log4j pattern layout such as

%d [%p] %c: %m%n

...and you might log in your application with code such as


public GreetResponse handleGreet(final GreetRequest request) {
    log.info("Greeting {}", request.name());
    // ...etc.
}


What can happen in this case, if you're not careful, is that external input incorporated to the log message could lead to forged log entries.

If you're greeting somebody with a normal name, like "Samantha"/"Abhishek"/"Zhou" no big deal. Your log messages look normal:


30 Jan 2019 06:29:02,857 [INFO] com.example.GreetingServer: Greeting Samantha
30 Jan 2019 06:29:06,517 [INFO] com.example.GreetingServer: Greeting Abhishek
30 Jan 2019 06:29:10,112 [INFO] com.example.GreetingServer: Greeting Zhou

But what if my "name" contains a newline character? This can lead to mischievous things like stealing your limited attention by faking errors:

Name: "Austin
30 Jan 2019 06:29:10,112 [ERROR] com.example.GreetingServer: HACKERS ARE PWNING ME"

Resulting log lines:


30 Jan 2019 06:29:09,712 [INFO] com.example.GreetingServer: Greeting Austin
30 Jan 2019 06:29:10,112 [ERROR] com.example.GreetingServer: HACKERS ARE PWNING ME


So now in the logs there is no way to distinguish between normal entries and a forged entry. If you're scanning for error-classified logs, you're going to get a false positive. Great deflection tactic to fill the logs with noise if an attacker is doing something bad to you in this contrived example, but with some creativity I'm sure you can come up with even more devious entries to forge in your own application. Best to avoid.
The mitigation: Escaping
Like SQLi or XSS, the proper way to mitigate log injection is to escape at the point of output. How you format your logs determines exactly what this means, but in many cases the implicit assumption in log entries is that they are separated by newline characters, as in our example.

If this is the case with your application, Log4j has a special layout pattern, %enc{}{CRLF}, which encodes the part of an entry between the first {}s to replace newline characters with their C-style "\n" and "\r" counterparts. Our updated pattern layout would be

%enc{%d [%p] %c: %m}{CRLF}%n

If our friend Austin comes back, the log entry for his greeting would now instead be


30 Jan 2019 06:29:09,712 [INFO] com.example.GreetingServer: Greeting Austin\n30 Jan 2019 06:29:10,112 [ERROR] com.example.GreetingServer: HACKERS ARE PWNING ME

Interesting name, but he's not fooling anyone this time.
Testing the mitigation
Like all changes to our software, this one deserves automated tests. We're encoding an assumption about the behavior of our log entries, and the sooner we know about that assumption being violated, the cheaper it will be to fix and the less damage there will be to repair.

After several false starts1, I put together a minimal set of code to assert the behavior of various log4j pattern layout strings. In the example below, the layout string under test is hardcoded, but for your own code you will want the test to directly read the same layout string you use in production: otherwise your test is giving you information about itself, not about your system.

import static org.junit.Assert.assertEquals;

import java.util.Collections;
import org.apache.logging.log4j.Level;
import org.apache.logging.log4j.core.LogEvent;
import org.apache.logging.log4j.core.LoggerContext;
import org.apache.logging.log4j.core.impl.Log4jLogEvent;
import org.apache.logging.log4j.core.layout.PatternLayout;
import org.apache.logging.log4j.message.SimpleMessage;
import org.junit.BeforeClass;
import org.junit.Test;

/**
 * Mimics log4j unit test cases to test our pattern layouts.
 *
 * Inspired by https://gitbox.apache.org/repos/asf?p=logging-log4j2.git;a=blob;f=log4j-core/src/test/java/org/apache/logging/log4j/core/layout/PatternLayoutTest.java;h=d6f3a806be2c1d068adc413497a2795ee09b265b;hb=HEAD
 */

public class LoggingTest {
    private static LoggerContext ctx;


    @BeforeClass
    public static void setupClass() {
        ctx = LoggerContext.getContext();
        ctx.reconfigure();
    }

    @Test
    public void logPatternPreventsNewlineInjection() {
        final PatternLayout brazilConfigLogPattern = PatternLayout.newBuilder()
            .withPattern("%enc{%d [%p] %c: %m}{CRLF}%n")
            .withConfiguration(ctx.getConfiguration())
            .build();


        //noinspection deprecation
        final LogEvent event = Log4jLogEvent.newBuilder()
            .setLoggerName(this.getClass().getName())
            .setLoggerFqcn("it.does.not.Matter")
            .setLevel(Level.INFO)
            .setMessage(new SimpleMessage("Hel\nlo&@Goodbye"))
            .build();


        assertSingleNewline(renderedLog(brazilConfigLogPattern, event));
    }


    private static String renderedLog(final PatternLayout layout, final LogEvent event) {
        return new String(layout.toByteArray(event));

    }


    private static void assertSingleNewline(final String msg) {
        int newlinesSeen = 0;
        for (char renderedCharacter : msg.toCharArray()) {
            if (renderedCharacter == '\n') {
                newlinesSeen++;
            }
        }
        assertEquals("Rendered log messages should have exactly 1 newline character to prevent injection",
                1, newlinesSeen);
    }
}
1It must not be very popular to make unit test assertions against particular log4j layout strings, because finding resources on how to do so was maddening! Log4j, in particular, seems to resist simple configuration for unit tests. This may be part of why it's so common to see otherwise test-aware devs callous towards as critical an output of their application as logging. Log4j may be among the last survivors of the Service Locators purge in an era of dependency injection and inversion of control.
References

Monday, July 2, 2018

Results Not Typical

I keep this on my home office/gym whiteboard. It reminds me of the mindset which opened the door to my new body and life. I never thought this would be me.

I knew there would be harder and easier days. I chose not to have a choice. I expected my brain to manufacture excuses, like "cheat" days or appeals to "moderation." The Power 90 DVDs were short: I could consider excuses after finishing the day's workout.

I trusted the pace of the program.

When a routine felt tough, I would hold on just a little longer. When it felt easy, I took it as a good day or rebuilding period. I'm not into guilt, just like I'm not into excuses as procrastination.

I didn't expect infomercial-level results. I did it anyway.

I was going to see what this thing could do for me. My bet was "nothing," but for 90 days I could give it a fair shot.

Typical execution would involve negotiating food choices against harder workouts.
Typical execution would let my mind stop at the first excuse to stay the way it was.
Typical execution would watch the scale yo-yo.
Typical execution would use NFL outliers to reject BMI-based health in the general case, even absent athleticism.

I needed to beat the averages. I didn't settle for typical execution. I didn't get typical results.

Have a video:

Monday, June 4, 2018

Welcome to Pair Club

Devs, welcome to Pair Club.
The first rule of Pair Club is: you do not talk about Pair Club.
The second rule of Pair Club is: you DO NOT talk about Pair Club.
Third rule of Pair Club: someone yells “stop!”, gets paged, randomized, the pair is over.
Fourth rule: only two devs to a pair.
Fifth rule: one priority at a time, folks.
Sixth rule: no shirts, no shoes, no refactoring, no Pair Club.
Seventh rule: pairs will go on as long as they have to.
And the eighth and final rule: if this is your first time at Pair Club, you have to pair.