sshguard duplicates processes multiple times if run from syslogd

Issue #103 wontfix
Vladimir Grebenschikov created an issue

in /etc/syslog.conf:

auth.info;authpriv.info |exec /usr/local/sbin/sshguard -a 20 -p 21600 -s 604800 -l - -l /var/log/exim/rejectlog -b 20:/var/db/sshguard.blacklist 

after a while lots of parallel sshguard processes are seen (see below)

and then, attempt to edit ipfw table in parallel slow downs the system dramatically, and leads to denial of service

$ pstree
...
 |-+= 55514 root /usr/sbin/syslogd
 | |-+= 08592 root /bin/sh /usr/local/sbin/sshguard ...
 | | |--- 08594 root tail -F -n 0 - /var/log/exim/rejectlog
 | | |--- 08595 root /usr/local/libexec/sshg-parser
 | | |--- 08596 root /usr/local/libexec/sshg-blocker ...
 | | \-+- 08597 root /bin/sh /usr/local/sbin/sshguard ...
 | |   \--- 08598 root /bin/sh /usr/local/libexec/sshg-fw-ipfw
 | |-+= 13154 root /bin/sh /usr/local/sbin/sshguard ...
 | | |--- 13156 root tail -F -n 0 - /var/log/exim/rejectlog
 | | |--- 13157 root /usr/local/libexec/sshg-parser
 | | |--- 13158 root /usr/local/libexec/sshg-blocker ...
 | | \-+- 13159 root /bin/sh /usr/local/sbin/sshguard ...
 | |   \--- 13160 root /bin/sh /usr/local/libexec/sshg-fw-ipfw
 | |-+= 17958 root /bin/sh /usr/local/sbin/sshguard ...
 | | |--- 17959 root tail -F -n 0 - /var/log/exim/rejectlog
 | | |--- 17960 root /usr/local/libexec/sshg-parser
 | | |--- 17961 root /usr/local/libexec/sshg-blocker ...
 | | \-+- 17962 root /bin/sh /usr/local/sbin/sshguard ...
 | |   \--- 17963 root /bin/sh /usr/local/libexec/sshg-fw-ipfw
 | |-+= 25118 root /bin/sh /usr/local/sbin/sshguard ...
 | | |--- 25120 root tail -F -n 0 - /var/log/exim/rejectlog
 | | |--- 25121 root /usr/local/libexec/sshg-parser
 | | |--- 25122 root /usr/local/libexec/sshg-blocker ...
 | | \-+- 25123 root /bin/sh /usr/local/sbin/sshguard ...
 | |   \--- 25124 root /bin/sh /usr/local/libexec/sshg-fw-ipfw
 | |-+= 29769 root /bin/sh /usr/local/sbin/sshguard ...
 | | |--- 29771 root tail -F -n 0 - /var/log/exim/rejectlog
 | | |--- 29772 root /usr/local/libexec/sshg-parser
 | | |--- 29773 root /usr/local/libexec/sshg-blocker ...
 | | \-+- 29774 root /bin/sh /usr/local/sbin/sshguard ...
 | |   \--- 29775 root /bin/sh /usr/local/libexec/sshg-fw-ipfw
 | |-+= 34686 root /bin/sh /usr/local/sbin/sshguard ...
 | | |--- 34688 root tail -F -n 0 - /var/log/exim/rejectlog
 | | |--- 34689 root /usr/local/libexec/sshg-parser
 | | |--- 34690 root /usr/local/libexec/sshg-blocker ...
 | | \-+- 34691 root /bin/sh /usr/local/sbin/sshguard ...
 | |   \--- 34692 root /bin/sh /usr/local/libexec/sshg-fw-ipfw
 | |-+= 42812 root /bin/sh /usr/local/sbin/sshguard ...
 | | |--- 42813 root tail -F -n 0 - /var/log/exim/rejectlog
 | | |--- 42814 root /usr/local/libexec/sshg-parser
 | | |--- 42815 root /usr/local/libexec/sshg-blocker ...
 | | \-+- 42816 root /bin/sh /usr/local/sbin/sshguard ...
 | |   \--- 42817 root /bin/sh /usr/local/libexec/sshg-fw-ipfw
 | |-+= 47486 root /bin/sh /usr/local/sbin/sshguard ...
 | | |--- 47488 root tail -F -n 0 - /var/log/exim/rejectlog
 | | |--- 47489 root /usr/local/libexec/sshg-parser
 | | |--- 47490 root /usr/local/libexec/sshg-blocker ...
 | | \-+- 47491 root /bin/sh /usr/local/sbin/sshguard ...
 | |   \--- 47492 root /bin/sh /usr/local/libexec/sshg-fw-ipfw
 | |-+= 52566 root /bin/sh /usr/local/sbin/sshguard ...
 | | |--- 52571 root tail -F -n 0 - /var/log/exim/rejectlog
 | | |--- 52572 root /usr/local/libexec/sshg-parser
 | | |--- 52573 root /usr/local/libexec/sshg-blocker ...
 | | \-+- 52574 root /bin/sh /usr/local/sbin/sshguard ...
 | |   \--- 52575 root /bin/sh /usr/local/libexec/sshg-fw-ipfw
 | |-+= 55577 root /bin/sh /usr/local/sbin/sshguard ...
 | | |--- 55579 root tail -F -n 0 - /var/log/exim/rejectlog
 | | |--- 55580 root /usr/local/libexec/sshg-parser
 | | |--- 55581 root /usr/local/libexec/sshg-blocker ...
 | | \-+- 55582 root /bin/sh /usr/local/sbin/sshguard ...
 | |   \--- 55583 root /bin/sh /usr/local/libexec/sshg-fw-ipfw
 | |-+= 60880 root /bin/sh /usr/local/sbin/sshguard ...
 | | |--- 60881 root tail -F -n 0 - /var/log/exim/rejectlog
 | | |--- 60882 root /usr/local/libexec/sshg-parser
 | | |--- 60883 root /usr/local/libexec/sshg-blocker ...
 | | \-+- 60884 root /bin/sh /usr/local/sbin/sshguard ...
 | |   \--- 60885 root /bin/sh /usr/local/libexec/sshg-fw-ipfw
 | |-+= 65563 root /bin/sh /usr/local/sbin/sshguard ...
 | | |--- 65564 root tail -F -n 0 - /var/log/exim/rejectlog
 | | |--- 65565 root /usr/local/libexec/sshg-parser
 | | |--- 65566 root /usr/local/libexec/sshg-blocker ...
 | | \-+- 65567 root /bin/sh /usr/local/sbin/sshguard ...
 | |   \--- 65568 root /bin/sh /usr/local/libexec/sshg-fw-ipfw
 | |-+= 71632 root /bin/sh /usr/local/sbin/sshguard ...
 | | |--- 71634 root tail -F -n 0 - /var/log/exim/rejectlog
 | | |--- 71635 root /usr/local/libexec/sshg-parser
 | | |--- 71636 root /usr/local/libexec/sshg-blocker ...
 | | \-+- 71637 root /bin/sh /usr/local/sbin/sshguard ...
 | |   \--- 71638 root /bin/sh /usr/local/libexec/sshg-fw-ipfw
 | |-+= 77174 root /bin/sh /usr/local/sbin/sshguard ...
 | | |--- 77176 root tail -F -n 0 - /var/log/exim/rejectlog
 | | |--- 77177 root /usr/local/libexec/sshg-parser
 | | |--- 77178 root /usr/local/libexec/sshg-blocker ...
 | | \-+- 77179 root /bin/sh /usr/local/sbin/sshguard ...
 | |   \--- 77180 root /bin/sh /usr/local/libexec/sshg-fw-ipfw
 | |-+= 81813 root /bin/sh /usr/local/sbin/sshguard ...
 | | |--- 81814 root tail -F -n 0 - /var/log/exim/rejectlog
 | | |--- 81815 root /usr/local/libexec/sshg-parser
 | | |--- 81816 root /usr/local/libexec/sshg-blocker ...
 | | \-+- 81817 root /bin/sh /usr/local/sbin/sshguard ...
 | |   \--- 81818 root /bin/sh /usr/local/libexec/sshg-fw-ipfw
 | |-+= 89332 root /bin/sh /usr/local/sbin/sshguard ...
 | | |--- 89334 root tail -F -n 0 - /var/log/exim/rejectlog
 | | |--- 89335 root /usr/local/libexec/sshg-parser
 | | |--- 89336 root /usr/local/libexec/sshg-blocker ...
 | | \-+- 89337 root /bin/sh /usr/local/sbin/sshguard ...
 | |   \--- 89338 root /bin/sh /usr/local/libexec/sshg-fw-ipfw
 | |-+= 94871 root /bin/sh /usr/local/sbin/sshguard ...
 | | |--- 94873 root tail -F -n 0 - /var/log/exim/rejectlog
 | | |--- 94874 root /usr/local/libexec/sshg-parser
 | | |--- 94875 root /usr/local/libexec/sshg-blocker ...
 | | \-+- 94876 root /bin/sh /usr/local/sbin/sshguard ...
 | |   \--- 94877 root /bin/sh /usr/local/libexec/sshg-fw-ipfw
 | \-+= 99516 root /bin/sh /usr/local/sbin/sshguard ...
 |   |--- 99523 root tail -F -n 0 - /var/log/exim/rejectlog
 |   |--- 99524 root /usr/local/libexec/sshg-parser
 |   |--- 99525 root /usr/local/libexec/sshg-blocker ...
 |   \-+- 99526 root /bin/sh /usr/local/sbin/sshguard ...
 |     \--- 99527 root /bin/sh /usr/local/libexec/sshg-fw-ipfw
...

lsof for sshguard shell processes shows different pipes for each:

sh      8592 root    0u  PIPE 0xfffff801ef2da5f0    32768        ->0xfffff801ef2da758, cnt=16738, in=16738
sh      13154 root    0u  PIPE 0xfffff801017322f8    32768        ->0xfffff80101732460, cnt=18704, in=18704
sh      17958 root    0u  PIPE 0xfffff80067624be0    65536        ->0xfffff80067624d48, cnt=50625, in=50625
sh      25118 root    0u  PIPE 0xfffff801ebcab8e8    65536        ->0xfffff801ebcaba50, cnt=65506, in=65506
sh      29769 root    0u  PIPE 0xfffff80127a425f0    65536        ->0xfffff80127a42758, cnt=65417, in=65417
sh      34686 root    0u  PIPE 0xfffff802117c98e8    65536        ->0xfffff802117c9a50, cnt=65465, in=65465
sh      42812 root    0u  PIPE 0xfffff801084908e8    65536        ->0xfffff80108490a50, cnt=65360, in=65360
sh      47486 root    0u  PIPE 0xfffff80067624000    65536        ->0xfffff80067624168, cnt=65493, in=65493
sh      52566 root    0u  PIPE 0xfffff801ebcaa000    65536        ->0xfffff801ebcaa168, cnt=65490, in=65490
sh      55577 root    0u  PIPE 0xfffff801bc436be0    16384        ->0xfffff801bc436d48, cnt=2592, in=2592
sh      60880 root    0u  PIPE 0xfffff80020928000    16384        ->0xfffff80020928168, cnt=14987, in=14987
sh      65563 root    0u  PIPE 0xfffff800676245f0    16384        ->0xfffff80067624758, cnt=12085, in=12085
sh      71632 root    0u  PIPE 0xfffff801017325f0    65536        ->0xfffff80101732758, cnt=65500, in=65500
sh      71686 root    0u  PIPE 0xfffff80101733be0    16384        ->0xfffff80101733d48, cnt=12909, in=12909
sh      77174 root    0u  PIPE 0xfffff800114ef2f8    65536        ->0xfffff800114ef460, cnt=65442, in=65442
sh      81813 root    0u  PIPE 0xfffff801ebcaa5f0    65536        ->0xfffff801ebcaa758, cnt=65505, in=65505
sh      89332 root    0u  PIPE 0xfffff80014ed5000    65536        ->0xfffff80014ed5168, cnt=65420, in=65420
sh      94871 root    0u  PIPE 0xfffff800676258e8    65536        ->0xfffff80067625a50, cnt=65501, in=65501
sh      99516 root    0u  PIPE 0xfffff801084902f8    65536        ->0xfffff80108490460, cnt=65500, in=65500

But syslog has only one pipe opened:

$ lsof -p 55514 | fgrep PIPE
syslogd 55514 root   32u  PIPE 0xfffff8017ac8c460         0         ->0xfffff8017ac8c2f8

Looks like shell script does not handle properly closing of the pipe and all child processes remain running after syslog reopens pipe

That was worked before properly

$ uname -a
FreeBSD srv 11.2-RELEASE-p1 FreeBSD 11.2-RELEASE-p1 #5 r337530: Thu Aug  9 15:22:16 MSK 2018     root@srv:/usr/obj/usr/src/sys/SRV  amd64

Comments (11)

  1. Vladimir Grebenschikov reporter

    Probably, same issue is cause for multiple duplicates in blacklist database:

    $ cat /var/db/sshguard.blacklist | cut -d\| -f4 | sort | uniq -c | sort -n
    ...
       5 39.51.29.250
       5 39.55.49.116
       7 61.165.12.250
      11 93.174.93.166
      12 167.114.113.171
      16 107.170.235.75
      63 14.186.232.53
      63 14.42.51.32
      86 185.24.233.25
     189 85.96.177.102
     229 159.89.163.220
     230 162.243.33.40
     297 124.112.184.231
     323 27.76.99.112
     387 136.243.95.113
     495 80.229.40.48
    $
    
  2. Kevin Zheng

    I'm not sure what changed to cause this to break. While I can give you suggestions to help you debug this, piping logs to SSHGuard from syslogd has been unsupported for some time due to several other issues. Consider having SSHGuard monitor the files syslog is configured to log to directly.

  3. Vladimir Grebenschikov reporter

    I'm not sure what changed to cause this to break

    I guess when shell wrapper instead of binary was invented with all these tail-F wrappers

    I can give you suggestions to help you debug this

    I did some digging - shell script completely ignores closing of stdin because of tail -F (which reads stdin) completely ignores reading from closed file:

    $ tail -F /dev/null
    <forever wait>
    

    piping logs to SSHGuard from syslogd has been unsupported for some time due to several other issues

    Then, I guess, this should be reflected in documentation, right now using syslog pipe is the first suggested method from docs:

    https://www.sshguard.net/docs/setup/

    SYSLOG syslogd can be configured to pipe logs to SSHGuard using syslog.conf: auth.info;authpriv.info |exec /path/to/sshguard

    Consider having SSHGuard monitor the files syslog is configured to log to directly.

    Already did ... but ... first upgrade to 2.x was just break sshguard silently because of incompatible configuration changes, and then after configuration fix - system stared to be unresponsive after a while due to unexpected parallel behavior with firewall - problem hidden twice for production system ...

  4. Kevin Zheng

    Sorry, it looks like we didn't update our documentation online. We do keep our man pages updated, so we'll point our setup page to the man page we update.

    I'm sorry about the silent breakage; SSHGuard 2 tried to preserve flags from SSHGuard 1, but it looks like the flags that got removed didn't get passed through correctly. The shell script is indeed a bit of a hack, but helps separate SSHGuard into distinct components that can be privsep'ed.

    However, you're not supposed to pipe anything to tail -F, that is intended to be used with file inputs.

    Before 2.x was released we had a call for testing to users and package maintainers, and didn't see this issues reported. Because we have limited capacity to test different configurations, we do encourage our users to participate in these calls for testing when they can.

  5. Vladimir Grebenschikov reporter

    well, I understand intent of wrapper script as a way to glue binary parts between each other. main part:

    eval $tailcmd | $libexec/sshg-parser | \
        $libexec/sshg-blocker $flags | ($BACKEND ; pkill -PIPE -P $$)
    

    in simplest way it looks like logs_reader | logs_parser | blocker

    so reader should handle properly reading from stdin and terminate chain in case of closing stdin, while for files it should reopen after rename/delete or seek to begin after truncate (tail -F does all these except proper exit on close of stdin)

  6. Vladimir Grebenschikov reporter

    What is interesting - freebsd's tail properly handle reading from stdin, but only if it is run as default

    # tail reads from stdin:
    $ echo x | tail -F
    x
    $ 
    
    # tail reads from stdin device
    $ echo x | tail -F /dev/stdin
    x
    <forever wait>
    
  7. Log in to comment