feat: SSH log relay emits proper DECNET syslog for sshd events

New log_relay.py replaces raw 'cat' on the rsyslog pipe. Intercepts
sshd and bash lines and re-emits them as structured RFC 5424 events:
login_success, session_opened, disconnect, connection_closed, command.
Parsers updated to accept non-nil PROCID (sshd uses PID).
This commit is contained in:
2026-04-14 02:07:35 -04:00
parent a6c7cfdf66
commit 7ff5703250
8 changed files with 240 additions and 79 deletions

View File

@@ -24,7 +24,7 @@ _RFC5424_RE = re.compile(
r"(\S+) " # 1: TIMESTAMP r"(\S+) " # 1: TIMESTAMP
r"(\S+) " # 2: HOSTNAME (decky name) r"(\S+) " # 2: HOSTNAME (decky name)
r"(\S+) " # 3: APP-NAME (service) r"(\S+) " # 3: APP-NAME (service)
r"- " # PROCID always NILVALUE r"\S+ " # PROCID (NILVALUE or PID)
r"(\S+) " # 4: MSGID (event_type) r"(\S+) " # 4: MSGID (event_type)
r"(.+)$", # 5: SD element + optional MSG r"(.+)$", # 5: SD element + optional MSG
) )
@@ -32,8 +32,6 @@ _SD_BLOCK_RE = re.compile(r'\[decnet@55555\s+(.*?)\]', re.DOTALL)
_PARAM_RE = re.compile(r'(\w+)="((?:[^"\\]|\\.)*)"') _PARAM_RE = re.compile(r'(\w+)="((?:[^"\\]|\\.)*)"')
_IP_FIELDS = ("src_ip", "src", "client_ip", "remote_ip", "ip") _IP_FIELDS = ("src_ip", "src", "client_ip", "remote_ip", "ip")
# bash PROMPT_COMMAND logger output: "CMD uid=0 pwd=/root cmd=ls -lah"
_BASH_CMD_RE = re.compile(r"CMD\s+uid=(\S+)\s+pwd=(\S+)\s+cmd=(.*)")
@@ -74,16 +72,6 @@ def parse_rfc5424(line: str) -> Optional[dict[str, Any]]:
except ValueError: except ValueError:
ts_formatted = ts_raw ts_formatted = ts_raw
# Normalize bash CMD lines from SSH honeypot PROMPT_COMMAND logger
if service == "bash" and msg:
cmd_match = _BASH_CMD_RE.match(msg)
if cmd_match:
service = "ssh"
event_type = "command"
fields["uid"] = cmd_match.group(1)
fields["pwd"] = cmd_match.group(2)
fields["command"] = cmd_match.group(3)
return { return {
"timestamp": ts_formatted, "timestamp": ts_formatted,
"decky": decky, "decky": decky,

View File

@@ -26,7 +26,7 @@ _RFC5424_RE = re.compile(
r"(\S+) " # 1: TIMESTAMP r"(\S+) " # 1: TIMESTAMP
r"(\S+) " # 2: HOSTNAME (decky name) r"(\S+) " # 2: HOSTNAME (decky name)
r"(\S+) " # 3: APP-NAME (service) r"(\S+) " # 3: APP-NAME (service)
r"- " # PROCID always NILVALUE r"\S+ " # PROCID (NILVALUE or PID)
r"(\S+) " # 4: MSGID (event_type) r"(\S+) " # 4: MSGID (event_type)
r"(.+)$", # 5: SD element + optional MSG r"(.+)$", # 5: SD element + optional MSG
) )
@@ -40,8 +40,6 @@ _PARAM_RE = re.compile(r'(\w+)="((?:[^"\\]|\\.)*)"')
# Field names to probe for attacker IP, in priority order # Field names to probe for attacker IP, in priority order
_IP_FIELDS = ("src_ip", "src", "client_ip", "remote_ip", "ip") _IP_FIELDS = ("src_ip", "src", "client_ip", "remote_ip", "ip")
# bash PROMPT_COMMAND logger output: "CMD uid=0 pwd=/root cmd=ls -lah"
_BASH_CMD_RE = re.compile(r"CMD\s+uid=(\S+)\s+pwd=(\S+)\s+cmd=(.*)")
@dataclass @dataclass
@@ -103,18 +101,6 @@ def parse_line(line: str) -> LogEvent | None:
fields = _parse_sd_params(sd_rest) fields = _parse_sd_params(sd_rest)
# Normalize bash CMD lines from SSH honeypot PROMPT_COMMAND logger
if service == "bash":
# Free-text MSG follows the SD element (which is "-" for these lines)
msg = sd_rest.lstrip("- ").strip()
cmd_match = _BASH_CMD_RE.match(msg)
if cmd_match:
service = "ssh"
event_type = "command"
fields["uid"] = cmd_match.group(1)
fields["pwd"] = cmd_match.group(2)
fields["command"] = cmd_match.group(3)
attacker_ip = _extract_attacker_ip(fields) attacker_ip = _extract_attacker_ip(fields)
return LogEvent( return LogEvent(

View File

@@ -65,6 +65,8 @@ RUN mkdir -p /root/projects /root/backups /var/www/html && \
printf 'DB_HOST=10.0.0.5\nDB_USER=admin\nDB_PASS=changeme123\nDB_NAME=prod_db\n' > /root/projects/.env && \ printf 'DB_HOST=10.0.0.5\nDB_USER=admin\nDB_PASS=changeme123\nDB_NAME=prod_db\n' > /root/projects/.env && \
printf '[Unit]\nDescription=App Server\n[Service]\nExecStart=/usr/bin/python3 /opt/app/server.py\n' > /root/projects/app.service printf '[Unit]\nDescription=App Server\n[Service]\nExecStart=/usr/bin/python3 /opt/app/server.py\n' > /root/projects/app.service
COPY decnet_logging.py /opt/decnet_logging.py
COPY log_relay.py /opt/log_relay.py
COPY entrypoint.sh /entrypoint.sh COPY entrypoint.sh /entrypoint.sh
RUN chmod +x /entrypoint.sh RUN chmod +x /entrypoint.sh

View File

@@ -34,8 +34,8 @@ fi
# Logging pipeline: named pipe → rsyslogd (RFC 5424) → stdout → Docker log capture # Logging pipeline: named pipe → rsyslogd (RFC 5424) → stdout → Docker log capture
mkfifo /var/run/decnet-logs mkfifo /var/run/decnet-logs
# Relay pipe to stdout so Docker captures all syslog events # Relay pipe through Python log_relay — normalizes sshd/bash events to DECNET format
cat /var/run/decnet-logs & python3 /opt/log_relay.py &
# Start rsyslog (reads /etc/rsyslog.d/99-decnet.conf, writes to the pipe above) # Start rsyslog (reads /etc/rsyslog.d/99-decnet.conf, writes to the pipe above)
rsyslogd rsyslogd

106
templates/ssh/log_relay.py Normal file
View File

@@ -0,0 +1,106 @@
#!/usr/bin/env python3
"""
SSH log relay — reads rsyslog output from the named pipe and re-emits
matched sshd/bash events as proper DECNET RFC 5424 syslog lines to stdout.
Matched events:
- Accepted password (login_success)
- Connection closed (connection_closed)
- Disconnected from user (disconnect)
- Session opened (session_opened)
- bash CMD (command)
"""
import os
import re
import sys
from decnet_logging import syslog_line, write_syslog_file, SEVERITY_INFO, SEVERITY_WARNING
NODE_NAME = os.environ.get("NODE_NAME", "ssh-decky")
SERVICE = "ssh"
# sshd patterns
_ACCEPTED_RE = re.compile(
r"Accepted (\S+) for (\S+) from (\S+) port (\d+)"
)
_SESSION_RE = re.compile(
r"session opened for user (\S+?)(?:\(uid=\d+\))? by"
)
_DISCONNECTED_RE = re.compile(
r"Disconnected from user (\S+) (\S+) port (\d+)"
)
_CONN_CLOSED_RE = re.compile(
r"Connection closed by (\S+) port (\d+)"
)
# bash PROMPT_COMMAND pattern
_BASH_CMD_RE = re.compile(
r"CMD\s+uid=(\S+)\s+pwd=(\S+)\s+cmd=(.*)"
)
def _handle_line(line: str) -> None:
"""Parse a raw rsyslog line and emit a DECNET syslog line if it matches."""
# --- Accepted password ---
m = _ACCEPTED_RE.search(line)
if m:
method, user, src_ip, port = m.groups()
write_syslog_file(syslog_line(
SERVICE, NODE_NAME, "login_success", SEVERITY_WARNING,
src_ip=src_ip, username=user, auth_method=method, src_port=port,
))
return
# --- Session opened ---
m = _SESSION_RE.search(line)
if m:
user = m.group(1)
write_syslog_file(syslog_line(
SERVICE, NODE_NAME, "session_opened", SEVERITY_INFO,
username=user,
))
return
# --- Disconnected from user ---
m = _DISCONNECTED_RE.search(line)
if m:
user, src_ip, port = m.groups()
write_syslog_file(syslog_line(
SERVICE, NODE_NAME, "disconnect", SEVERITY_INFO,
src_ip=src_ip, username=user, src_port=port,
))
return
# --- Connection closed ---
m = _CONN_CLOSED_RE.search(line)
if m:
src_ip, port = m.groups()
write_syslog_file(syslog_line(
SERVICE, NODE_NAME, "connection_closed", SEVERITY_INFO,
src_ip=src_ip, src_port=port,
))
return
# --- bash CMD ---
m = _BASH_CMD_RE.search(line)
if m:
uid, pwd, cmd = m.groups()
write_syslog_file(syslog_line(
SERVICE, NODE_NAME, "command", SEVERITY_INFO,
uid=uid, pwd=pwd, command=cmd,
))
return
def main() -> None:
pipe_path = "/var/run/decnet-logs"
while True:
with open(pipe_path, "r") as pipe:
for line in pipe:
_handle_line(line.rstrip("\n"))
if __name__ == "__main__":
main()

View File

@@ -131,30 +131,12 @@ class TestParseRfc5424:
assert result["msg"] == "login attempt" assert result["msg"] == "login attempt"
def test_bash_cmd_normalized_to_ssh_command(self): def test_non_nil_procid_accepted(self):
line = '<14>1 2026-04-14T05:48:12.628417+00:00 SRV-BRAVO-13 bash - - - CMD uid=0 pwd=/root cmd=ls /var/www/html' line = '<38>1 2026-04-14T05:48:12.611006+00:00 SRV-BRAVO-13 sshd 282 - - Accepted password for root from 192.168.1.5 port 50854 ssh2'
result = parse_rfc5424(line) result = parse_rfc5424(line)
assert result is not None assert result is not None
assert result["service"] == "ssh" assert result["service"] == "sshd"
assert result["event_type"] == "command" assert result["decky"] == "SRV-BRAVO-13"
assert result["fields"]["command"] == "ls /var/www/html"
assert result["fields"]["uid"] == "0"
assert result["fields"]["pwd"] == "/root"
def test_bash_cmd_simple_command(self):
line = '<14>1 2026-04-14T05:48:13.332072+00:00 SRV-BRAVO-13 bash - - - CMD uid=0 pwd=/root cmd=ls'
result = parse_rfc5424(line)
assert result is not None
assert result["service"] == "ssh"
assert result["event_type"] == "command"
assert result["fields"]["command"] == "ls"
def test_bash_non_cmd_not_normalized(self):
line = '<14>1 2026-04-14T05:48:12.628417+00:00 SRV-BRAVO-13 bash - - - some other bash message'
result = parse_rfc5424(line)
assert result is not None
assert result["service"] == "bash"
assert result["event_type"] == "-"
class TestIsServiceContainer: class TestIsServiceContainer:

View File

@@ -155,37 +155,17 @@ class TestParserAttackerIP:
assert parse_line(line) is None assert parse_line(line) is None
class TestParserBashNormalization: class TestParserProcidFlexibility:
def test_bash_cmd_normalized_to_ssh_command(self): def test_non_nil_procid_accepted(self):
line = '<14>1 2026-04-14T05:48:12.628417+00:00 SRV-BRAVO-13 bash - - - CMD uid=0 pwd=/root cmd=ls /var/www/html' line = '<38>1 2026-04-14T05:48:12.611006+00:00 SRV-BRAVO-13 sshd 282 - - Accepted password for root'
event = parse_line(line) event = parse_line(line)
assert event is not None assert event is not None
assert event.service == "ssh" assert event.service == "sshd"
assert event.event_type == "command" assert event.decky == "SRV-BRAVO-13"
assert event.fields["command"] == "ls /var/www/html"
assert event.fields["uid"] == "0"
assert event.fields["pwd"] == "/root"
def test_bash_cmd_simple(self): def test_nil_procid_still_works(self):
line = '<14>1 2026-04-14T05:48:13.332072+00:00 SRV-BRAVO-13 bash - - - CMD uid=0 pwd=/root cmd=ls' event = parse_line(_make_line())
event = parse_line(line)
assert event is not None assert event is not None
assert event.service == "ssh"
assert event.fields["command"] == "ls"
def test_bash_non_cmd_stays_as_bash(self):
line = '<14>1 2026-04-14T05:48:12.628417+00:00 SRV-BRAVO-13 bash - - - some other bash message'
event = parse_line(line)
assert event is not None
assert event.service == "bash"
assert event.event_type == "-"
def test_bash_cmd_with_complex_command(self):
line = '<14>1 2026-04-14T05:48:32.006502+00:00 SRV-BRAVO-13 bash - - - CMD uid=0 pwd=/root cmd=cat /etc/passwd | grep root'
event = parse_line(line)
assert event is not None
assert event.service == "ssh"
assert event.fields["command"] == "cat /etc/passwd | grep root"
# --------------------------------------------------------------------------- # ---------------------------------------------------------------------------

117
tests/test_ssh_log_relay.py Normal file
View File

@@ -0,0 +1,117 @@
"""Tests for the SSH log relay that normalizes sshd/bash events."""
import os
import sys
import types
from pathlib import Path
import pytest
_SSH_TPL = str(Path(__file__).resolve().parent.parent / "templates" / "ssh")
def _load_relay():
"""Import log_relay with a real decnet_logging from the SSH template dir."""
# Clear any stale stubs
for mod_name in ("decnet_logging", "log_relay"):
sys.modules.pop(mod_name, None)
if _SSH_TPL not in sys.path:
sys.path.insert(0, _SSH_TPL)
import log_relay
return log_relay
_relay = _load_relay()
def _capture(line: str) -> str | None:
"""Run _handle_line, collect output via monkey-patched write_syslog_file."""
collected: list[str] = []
original = _relay.write_syslog_file
_relay.write_syslog_file = lambda s: collected.append(s)
try:
_relay._handle_line(line)
finally:
_relay.write_syslog_file = original
return collected[0] if collected else None
class TestSshdAcceptedPassword:
def test_accepted_password_emits_login_success(self):
emitted = _capture(
'<38>1 2026-04-14T05:48:12.611006+00:00 SRV-BRAVO-13 sshd 282 - - Accepted password for root from 192.168.1.5 port 50854 ssh2'
)
assert emitted is not None
assert "login_success" in emitted
assert 'src_ip="192.168.1.5"' in emitted
assert 'username="root"' in emitted
assert 'auth_method="password"' in emitted
def test_accepted_publickey(self):
emitted = _capture(
'<38>1 2026-04-14T05:48:12.611006+00:00 SRV-BRAVO-13 sshd 282 - - Accepted publickey for admin from 10.0.0.1 port 12345 ssh2'
)
assert emitted is not None
assert 'auth_method="publickey"' in emitted
assert 'username="admin"' in emitted
class TestSshdSessionOpened:
def test_session_opened(self):
emitted = _capture(
'<86>1 2026-04-14T05:48:12.611880+00:00 SRV-BRAVO-13 sshd 282 - - pam_unix(sshd:session): session opened for user root(uid=0) by (uid=0)'
)
assert emitted is not None
assert "session_opened" in emitted
assert 'username="root"' in emitted
class TestSshdDisconnected:
def test_disconnected(self):
emitted = _capture(
'<38>1 2026-04-14T05:54:50.710536+00:00 SRV-BRAVO-13 sshd 282 - - Disconnected from user root 192.168.1.5 port 50854'
)
assert emitted is not None
assert "disconnect" in emitted
assert 'src_ip="192.168.1.5"' in emitted
assert 'username="root"' in emitted
class TestSshdConnectionClosed:
def test_connection_closed(self):
emitted = _capture(
'<38>1 2026-04-14T05:47:55.621236+00:00 SRV-BRAVO-13 sshd 280 - - Connection closed by 192.168.1.5 port 52900 [preauth]'
)
assert emitted is not None
assert "connection_closed" in emitted
assert 'src_ip="192.168.1.5"' in emitted
class TestBashCommand:
def test_bash_cmd(self):
emitted = _capture(
'<14>1 2026-04-14T05:48:12.628417+00:00 SRV-BRAVO-13 bash - - - CMD uid=0 pwd=/root cmd=ls /var/www/html'
)
assert emitted is not None
assert "command" in emitted
assert 'command="ls /var/www/html"' in emitted
def test_bash_cmd_with_pipes(self):
emitted = _capture(
'<14>1 2026-04-14T05:48:32.006502+00:00 SRV-BRAVO-13 bash - - - CMD uid=0 pwd=/root cmd=cat /etc/passwd | grep root'
)
assert emitted is not None
assert "cat /etc/passwd | grep root" in emitted
class TestUnmatchedLines:
def test_pam_env_ignored(self):
assert _capture('<83>1 2026-04-14T05:48:12.615198+00:00 SRV-BRAVO-13 sshd 282 - - pam_env(sshd:session): Unable to open env file') is None
def test_session_closed_ignored(self):
assert _capture('<86>1 2026-04-14T05:54:50.710577+00:00 SRV-BRAVO-13 sshd 282 - - pam_unix(sshd:session): session closed for user root') is None
def test_syslogin_ignored(self):
assert _capture('<38>1 2026-04-14T05:54:50.710307+00:00 SRV-BRAVO-13 sshd 282 - - syslogin_perform_logout: logout() returned an error') is None