Fail2ban: Feature: monitor multiple systemd journals (machinectl, systemd-nspawn)

[lkraav]

I have a separate sshd on a separate port in a systemd-nspawn container. Host sshd is nicely protected, but container sshd gets hammered and fail2ban running on the host is not able to do anything about it, because it doesn't see the container's journal. Seeing the container's journal is trivial on the commandline journalctl -M <machinename>, so I'd assume it may not be terribly difficult to get fail2ban to monitor more than one journal like this. Perhaps nobody has had the need to think about this before - searching issues for machinectl returns empty.

Thoughts?

[lkraav]

Ping? Still trying to get a host level fail2ban instance to monitor container journals.

[sebres]

I don't know that we somewhere in code should filter local mashine only (IMHO, neither journal.LOCAL_ONLY, nor other things like this_machine filtering journal to the current machine only will be set)... So I think it should find all messages, also from another machine containers...

Can you make following test, and look whether entries from another journal container are present there:

DIST="hours=1"; python -c "$(echo -e "import datetime; from systemd import journal; j = journal.Reader(converters={'__CURSOR': lambda x: x}); j.seek_realtime((datetime.datetime.now()-datetime.timedelta($DIST))); j.add_match('SYSLOG_IDENTIFIER=sshd');\nfor r in j:\n  print('[%s] %s - %s: %s' % (r.get('_SOURCE_REALTIME_TIMESTAMP', r.get('__REALTIME_TIMESTAMP')), r.get('_HOSTNAME'), r.get('_MACHINE_ID'), r['MESSAGE']))")"

Please note that the given time distance here is 1 hour (otherwise correct value of the DIST variable)...

[lkraav]

Thanks. It only sees the host machine gusto records. Example:

[2016-08-23 15:17:25.602149] gusto - 8e913bce-5ef6-b441-ef5e-edef0000001c: User child is on pid 1657

[sebres]

Are you sure, that the second machine wrote something in log in the last hour?

[lkraav]

Yes, the container is running a constant workload and outputting stuff to its journal.

Maybe these man systemd-nspawn parameters have to be tested.

--link-journal=
           Control whether the container's journal shall be made visible to the host system. If enabled, allows viewing the container's journal files from the host (but not vice versa).
           Takes one of "no", "host", "try-host", "guest", "try-guest", "auto". If "no", the journal is not linked. If "host", the journal files are stored on the host file system (beneath
           /var/log/journal/machine-id) and the subdirectory is bind-mounted into the container at the same location. If "guest", the journal files are stored on the guest file system
           (beneath /var/log/journal/machine-id) and the subdirectory is symlinked into the host at the same location.  "try-host" and "try-guest" do the same but do not fail if the host
           does not have persistent journalling enabled. If "auto" (the default), and the right subdirectory of /var/log/journal exists, it will be bind mounted into the container. If the
           subdirectory does not exist, no linking is performed. Effectively, booting a container once with "guest" or "host" will link the journal persistently if further on the default of
           "auto" is used.

       -j
           Equivalent to --link-journal=try-guest.

Currently my cmdline is simple /usr/bin/systemd-nspawn -bjD /srv/conversionready --bind=/home/trac/src:/home/trac/src --bind=/run/mysql:/var/lib/mysql.

But like I said earlier journalctl -M <machinectl> already works without issues, so doesn't look like a configuration update should be needed.

[sebres]

Can you post at least one verbose record from this "other" machine, I mean pair records from the output of:

journalctl -M ... -t sshd -r -o verbose

[lkraav]

Sure, check this

$ journalctl -M conversionready -t sshd -r -o verbose
-- Logs begin at T 2016-02-09 15:45:59 EET, end at T 2016-08-23 16:00:45 EEST. --
T 2016-08-23 15:57:20.472448 EEST [s=18c2a86860a34dba93b0448a43f70be4;i=34e78e;b=cab24fe4172b4cbbba4ba76a13490245;m=155ae053d3f;t=53abcb485ba69;x=c322412777588920]
    _TRANSPORT=syslog
    SYSLOG_FACILITY=10
    SYSLOG_IDENTIFIER=sshd
    _UID=0
    _GID=0
    _BOOT_ID=cab24fe4172b4cbbba4ba76a13490245
    _MACHINE_ID=b1a8bea60eeed7e12b01a470537bdfd0
    _HOSTNAME=conversionready
    PRIORITY=6
    MESSAGE=pam_unix(sshd:session): session closed for user pawel
    _PID=12079
    _SOURCE_REALTIME_TIMESTAMP=1471957040472448
T 2016-08-23 15:57:20.478613 EEST [s=18c2a86860a34dba93b0448a43f70be4;i=34e78d;b=cab24fe4172b4cbbba4ba76a13490245;m=155ae053c6b;t=53abcb485b995;x=f964fa7def074f63]
...

[sebres]

If you know the path where is the journal of this machine (bound local), you can test this one:

JRPATH="/path/to/machine-journal"; DIST="hours=1"; python -c "$(echo -e "import datetime; from systemd import journal; j = journal.Reader(path='$JRPATH', converters={'__CURSOR': lambda x: x}); j.seek_realtime((datetime.datetime.now()-datetime.timedelta($DIST))); j.add_match('SYSLOG_IDENTIFIER=sshd');\nfor r in j:\n  print('[%s] %s - %s: %s' % (r.get('_SOURCE_REALTIME_TIMESTAMP', r.get('__REALTIME_TIMESTAMP')), r.get('_HOSTNAME'), r.get('_MACHINE_ID'), r['MESSAGE']))")"

If it will work, we can extend fail2ban to provide path as optional parameter to the systemd-filter;

Otherwise I don't know how we can create an instance of python systemd journal to read this "remote" records...

Another way would be a new backend engine (e.g. backend = command) read the log entries from pipe of command, e.g. something like journalctl -M ... -o verbose -f. But this would be a lot of work...

[lkraav]

Works. (y)

$ JRPATH="/var/log/journal/b1a8bea60eeed7e12b01a470537bdfd0"; DIST="hours=1"; python -c "$(echo -e "import datetime; from systemd import journal; j = journal.Reader(path='$JRPATH', converters={'__CURSOR': lambda x: x}); j.seek_realtime((datetime.datetime.now()-datetime.timedelta($DIST))); j.add_match('SYSLOG_IDENTIFIER=sshd');\nfor r in j:\n  print('[%s] %s - %s: %s' % (r.get('_SOURCE_REALTIME_TIMESTAMP', r.get('__REALTIME_TIMESTAMP')), r.get('_HOSTNAME'), r.get('_MACHINE_ID'), r['MESSAGE']))")"
[2016-08-23 15:35:46.807631] conversionready - b1a8bea6-0eee-d7e1-2b01-a470537bdfd0: Received disconnect from 121.18.238.29 port 47615:11:  [preauth]
...

[sebres]

Fine, I'll look how we can provide it as parameter in jail config file...

[sebres]

So I've implemented it (and fixed pair other things with systemd-backend) in #1523, however in 0.10-branch...
I'll try later to rebase resp. reintegrate this PR in 0.9, if it going easy, otherwise firstly in 0.10-th...

Oh yeah, the syntax for the configuration of jail.local in your case:

[jail-machine-x]
...
backend = systemd[journalpath=/var/log/journal/b1a8bea60eeed7e12b01a470537bdfd0]
...

[lkraav]

Thanks a ton. Remind me to buy you dinner when I'm in your town. 0.9-branch patch set would be nice, and get me testing this quicker, as Gentoo doesn't seem to have 0.10-branch testing ebuilds yet.

[sebres]

Here you go:
https://github.com/fail2ban/fail2ban/compare/master...sebres:_0.9/systemd-journal-path-gh-1408

Does almost the same (a little bit different, because missing some things from 0.10, e.g. that's why fewer test covered). But it should work...

BTW. Note that it is relative current master (0.9.6) so I don't know how it can be compatible to previous versions...

[lkraav]

I'm about to test it. It is unclear from the documentation, if giving backend value parameters, is the default system journal still implied, or must I explicitly now specify all journals I want to process, including the main system journal?

[lkraav]

Also, journalpfiles or journalfiles?

EDIT source says journalfiles

[sebres]

is the default system journal still implied

No, it will be used only if you use backend = systemd without any parameter...

And of course journalfiles, where did you found it with p (I had an typo, but I thought I fixed it everywhere)?

But I think, you should specify it with path, as it stands here - https://github.com/fail2ban/fail2ban/issues/1408#issuecomment-242151682

Example for 2 standalone jails, as path:

[local-jail]
backend = systemd

[jail-machine-x]
backend = systemd[journalpath=/var/log/journal/b1a8bea60eeed7e12b01a470537bdfd0]

Or if you want multiple journals in a single jail, then as files:

[comon-jail]
backend = systemd[journalfiles="/var/log/journal/...local-id.../system.journal, /var/log/journal/...remote-id.../system.journal"]

Of course you can define it once for all jails, you should then place it in default section [DEFAULT]...

And I don't know, whether it works recursively, if you specify a root path, like here:

[jail-machine-x]
backend = systemd[journalpath=/var/log/journal/]

You can test it with python command from above (you know, how it all began), you should then see messages from both journals...

[sebres]

It seems to work recursively, I've currently tried:

JRPATH="/var/log/journal"; DIST="hours=1"; python -c "$(echo -e "import datetime; from systemd import journal; j = journal.Reader(path='$JRPATH', converters={'__CURSOR': lambda x: x}); j.seek_realtime((datetime.datetime.now()-datetime.timedelta($DIST))); j.add_match('SYSLOG_IDENTIFIER=sshd');\nfor r in j:\n  print('[%s] %s - %s: %s' % (r.get('_SOURCE_REALTIME_TIMESTAMP', r.get('__REALTIME_TIMESTAMP')), r.get('_HOSTNAME'), r.get('_MACHINE_ID'), r['MESSAGE']))")"

and I see some messages...

[lkraav]

It seems to work recursively, I've currently tried:

Hmm, here it only seems to successfully find records from the container machine, but not from the host machine. Even if I specify the full directory to the host machine id, result still empty. Replace with container journal id, works. Weird.

[sebres]

Weird.

Well I've tested it only with local/host journals... (have no containers ready to hand...

but not from the host machine

Have you tried with the common root path for both journals?
Where is your host journals? Could it be runtime logs (so in /run/log/journal)?

[lkraav]

Have you tried with the common root path for both journals?

Yes I also tried it with just /var/log/journal first.

Where is your host journals? Could it be runtime logs (so in /run/log/journal)?

$ ls -l /var/log/journal
total 4
drwxr-sr-x+ 1 root systemd-journal        10846 20. aug   23:06 8e913bce5ef6b441ef5eedef0000001c
lrwxrwxrwx  1 root systemd-journal           69 15. sept   2014 b1a8bea60eeed7e12b01a470537bdfd0 -> /srv/conversionready/var/log/journal/b1a8bea60eeed7e12b01a470537bdfd0
drwxr-sr-x  1 root systemd-journal-remote    48 14. dets   2015 remote

[sebres]

Hmm, possibly interferes with symlink, indeed weird

So, can you do that with 2 separately jails (one for host, one for container)? Or with journalfiles instead of journalpath?

[lkraav]

Something is wrong with parsing the new backend = systemd[] value vs requiring logpath.

With regular backend = systemd everything works.

Setting anything additional with backend = systemd[journalfiles=""] causes jail parser to fail

ERROR  No file(s) found for glob 
ERROR  Failed during configuration: Have not found any log file for sshd jail
Traceback (most recent call last):
  File "/usr/bin/fail2ban-client", line 472, in <module>
    if client.start(sys.argv):
  File "/usr/bin/fail2ban-client", line 405, in start
    self.dumpConfig(self.__stream)
  File "/usr/bin/fail2ban-client", line 461, in dumpConfig
    for c in cmd:
TypeError: 'NoneType' object is not iterable

But we shouldn't be requiring a log file for anything systemd.

[sebres]

0.9 or 0.10?

[lkraav]

I rebased your two patches on top of 0.9.5. No conflicts appeared.

EDIT

$ git log1 -20
* 92ece5f - (HEAD -> lkraav-0.9.5+, refs/patches/lkraav-0.9.5+/jail-configuration-extended) jail configuration extended with new syntax to pass options to the backend (see gh-1408), examples:   - `backend = systemd[journalpath=/run/log/journal/machine-1]`   - `backend = systemd[journalpfiles="/run/log/journal/machine-1/system.journal, /run/log/journal/machine-1/user.journal"]`   - `backend = systemd[journalflags=2]` (7 hours ago) <sebres>
* 6eda0d7 - (refs/patches/lkraav-0.9.5+/systemd-added-new-constructor) [systemd] added new constructor parameters like journalpath, journalfiles and journalflags for systemd backup optimized FilterSystemd method `run`: better wait in idle (no busy-loop), better poll handling, the ban will executed anywhere (at least at 100th log-entry), also if we have never ending logging in this jail (e.g. extremely logging or too many failures) systemd test cases extended (7 hours ago) <sebres>
*   dca5ff4 - (tag: 0.9.5) Merge branch 'bf-common-zzz' (6 weeks ago) <Yaroslav Halchenko>
...

[sebres]

I think I had miss still one change...

https://github.com/fail2ban/fail2ban/blob/5797ea0ae2932ed5f752508da1f49bd76356e537/fail2ban/client/jailreader.py#L200

- self.__opts.get('backend', None) != "systemd":
+ not self.__opts.get('backend', None).startswith("systemd"):

no computer ready to hand (smartphone), so be patient until tomorrow...

[lkraav]

Thanks, I'll patch it and give it a shot right now.

[lkraav]

It looks like it works now :) thanks a ton.

I will have the final confirmation when something also gets detected for the host machine. Right now, sshd hammering on container was successfully blocked.

[sebres]

ssh xxx@localhost with wrong usr-pwd
local host should be in ignore list, so you'll see in f2b.log a found failure + ignored messages

[lkraav]

Everything has been working great. Except one question has come up - is this implementation affected by systemd auto-rotating logs? After running for a while, I'm seeing service hammering in manually tailing the journal, but fail2ban doesn't see it. If I restart fail2ban, it immediately recognizes and bans the offender.

This seems like losing track of the journal at one point. Thoughts?

[sebres]

Something about that in fail2ban.log? Did you mean "remote" journal or both?

[lkraav]

Something about that in fail2ban.log? Did you mean "remote" journal or both?

The issue was with the remote log.

I'll check up on what the rotation settings are for both main and remote log + if something is visible in fail2ban.log.

[sebres]

something is visible in fail2ban.log

ping