Fail2ban broken on CentOS 6 using inotify #44

Closed
bgooren opened this Issue Apr 9, 2012 · 31 comments

Projects

None yet
@bgooren
bgooren commented Apr 9, 2012

Hi,

I see some weird behavior on some of our CentOS (5.x and 6.x) boxes running fail2ban (from EPEL).
After some investigation it turns out that out-of-the-box it fails to handle the log rotation of /var/log/secure (sshd logs).

So I took a look at my logs and the fail2ban sourcecode, and noticed the following:

  • on the servers where fail2ban works like clockwork it's using gamin (fail2ban-0.8.4-23.el5)
  • where it's not working it's using inotify (fail2ban-0.8.4-28.el6.noarch)

By default CentOS does not use "copytruncate" while rotating /var/log/secure, but "create". The result is that the "full" logfile is moved and a new file with the original name is created. This applies to both types of servers.

Looking at the source code of fail2ban I see that in server/filter.py (class FileContainer) it checks for a rotated log file as indicated by a different first line or inode number.
Next, I see that FilterGamin listens for GAMCreated, GAMChanged and GAMExists.
FilterPyinotify listens for IN_MODIFY;

Now not being an expert on Gamin and Inotify I assume this is why it is no longer working:

  • With Gamin we get a GAMCreated event after the file is moved; The FileContainer then notices a different hash and inode and thus a rotated file
  • With Inotify the log file is moved and no longer written to when it's rotated. IN_MODIFY is not emitted for the file since it's contents have not changed.

A simple solution appears to be to also monitor for IN_MOVED_SELF, but according to https://github.com/manos/python-inotify-tail_example this does not work with pyinotify on files.

@yarikoptic
Member

@leeclemens Could you have a look at this issue? Sounds like a big blow and we definitely needs to fix it up one way or another

@bgooren
bgooren commented Apr 23, 2012

Quick fix for this, for users, is to use

backend = gamin

to switch back to gamin for file change monitoring.

@leeclemens
Contributor

Interesting scenerio, sorry it's been so long to reply.

To clarify, the issue is with the logfile fail2ban is monitoring is rotated?

Using inotify, new log is not detected (and subsequently not monitored); however, using gamin the new log is detected?

Can you include your logrotate.d configuration for the log file being rotated?

@leeclemens
Contributor

@bgrooren bah, that's not a fix, that's a workaround :) may ultimately be an issue with pyinotify or ultimately how you are rotating the log - so please do include that information.

Can you also include the version of pyinotify you are using?

@bgooren
bgooren commented Apr 29, 2012

That's why I said "quick fix" ;-)

I'm using stock centos 6, which has python-inotify-0.9.1-1.el6.noarch. The default logrotate config for sshd is (/etc/logrotate.d/syslog):

/var/log/cron
/var/log/maillog
/var/log/messages
/var/log/secure
/var/log/spooler
{
    sharedscripts
    postrotate
    /bin/kill -HUP `cat /var/run/syslogd.pid 2> /dev/null` 2> /dev/null || true
    endscript
}

Like I mentioned before, the reason for inotify not working is that centos 6 uses the following defaults (/etc/logrotate.conf):

# see "man logrotate" for details
# rotate log files weekly
weekly

# keep 4 weeks worth of backlogs
rotate 4

# create new (empty) log files after rotating old ones
create

# use date as a suffix of the rotated file
dateext

# uncomment this if you want your log files compressed
#compress

# RPM packages drop log rotation information into this directory
include /etc/logrotate.d

# no packages own wtmp and btmp -- we'll rotate them here
/var/log/wtmp {
    monthly
    create 0664 root utmp
    minsize 1M
    rotate 1
}

/var/log/btmp {
    missingok
    monthly
    create 0600 root utmp
    rotate 1
}

# system-specific logs may be also be configured here.

So: "create" instead of "copyrotate". Inotify tracks changes by inode, so when the logfile opened at fail2ban start time is rotated, no more changes are written to it. Fail2ban fails to detect the fact that the file was rotated, and does not start tracking changes to new newly created logfile.

@leeclemens
Contributor

The default in RHEL is create as well (since 5, at least).

If you enable debug logging, do you see something like this after the secure log has been rotated and then written to?

2012-04-30 09:29:13,237 fail2ban.filter : DEBUG Callback for Event: <Event dir=False mask=0x8000 maskname=IN_IGNORED name='' path=/var/log/secure pathname=/var/log/secure wd=1 >
2012-04-30 09:29:13,238 fail2ban.filter : INFO Log rotation detected for /var/log/secure
2012-04-30 09:29:13,239 fail2ban.filter.datedetector: DEBUG Sorting the template list

@bgooren
bgooren commented May 21, 2012

Hi, I've just enabled debug logging on one of the affected servers. As soon as the secure log is rotated I will post the result here.

@bgooren
bgooren commented May 28, 2012

Ok so last night a log rotation happened; this is what /var/log/messages says:

May 27 03:07:05 web1 <31>fail2ban.filter : DEBUG  process_IN_MODIFY called
May 27 03:07:05 web1 <30>fail2ban.filter : INFO   Log rotation detected for /var/log/exim/main.log
May 27 03:07:05 web1 <31>fail2ban.filter.datedetector: DEBUG  Sorting the template list

So somehow it does pick up the log rotation of the exim (mailserver) log, but it does not log anything regarding the secure log.

@l4m3rx
l4m3rx commented Jun 12, 2012

Hi :) I have some expirience with pyinotify and the problem ur talking about is 100% 'cose ur not catchin IN_CREATE event. You shoud catch it in, 'cose the rotation most time is : 1.Move file to *.1 2. Create new file .
I havent tested it , but i think this shoud fix ur issue:

root@gh0st:~# diff -Naur filterpyinotify.py.orig filterpyinotify.py
--- filterpyinotify.py.orig 2012-06-12 13:24:30.629496444 +0300
+++ filterpyinotify.py  2012-06-12 13:26:02.446167603 +0300
@@ -29,6 +29,8 @@

 import time, logging, pyinotify

+# monitored events. (IN_CREATE so we can catch rotation)
+watchEvents = pyinotify.IN_MODIFY | pyinotify.IN_CREATE
 # Gets the instance of the logger.
 logSys = logging.getLogger("fail2ban.filter")

@@ -75,7 +77,7 @@
        if self.containsLogPath(path):
            logSys.error(path + " already exists")
        else:
 -                     wd = self.__monitor.add_watch(path, pyinotify.IN_MODIFY) 
 +                    wd = self.__monitor.add_watch(path, watchEvents)
            self.__watches.update(wd)
            FileFilter.addLogPath(self, path, tail)
            logSys.info("Added logfile = %s" % path)
@fredstluka

I'm seeing exactly the same problem and have confirmed that the
backend = gamin
"quick fix" causes the problem to go away. Thanks bgooren!
I knew I had a fail2ban problem and suspected it was related to
logrotate, but hadn't narrowed it down any further yet.

I'm a huge fan of fail2ban and recommend it to all of my clients.
Is there a real fix for this in the works? Or should I make sure they
all switch from auto to gamin when they upgrade to fail2ban-0.8.4-28?

Thanks!
--Fred Stluka

@yarikoptic
Member

someone should look into taking the fix @l4m3rx suggested ... I started to craft a unittest for that but haven't had a chance to finish it... may be in upcoming week ...

@jwestyp
jwestyp commented Jul 9, 2012

I can confirm this problem on 5 CentOS 6.2 servers. As soon as my logs rotated Sunday just after midnight, fail2ban stopped banning. Logs show "fail2ban.filter : INFO Log rotation detected" which was my first clue that it had something to do with it.

@yarikoptic
Member

ok -- I have pushed a _enh/test_backends branch into my clone which supposed to fix this issue + provides unittests for polling and pyinotify (disabled for gamin since it seems completely ... not working atm for me). Due to all the threading and tests being as close to real use cases as possible, tests are still somewhat fragile and fail from time to time ;) but pyinotify now should work -- it will monitor parent directory for CREATE event. Please test if you get a chance :
https://github.com/yarikoptic/fail2ban/tree/_enh/test_backends

@yarikoptic
Member

ok -- that point was not yet good ;) now (0.8.6-95-gc0c1232) that branch seems to work just perfect. If I hear no complaints or do not see problem with my instance -- I will merge it into master tomorrow, thus closing this issue

@yarikoptic yarikoptic added a commit that referenced this issue Jul 20, 2012
@yarikoptic yarikoptic Merge branch '_enh/test_backends' -- fixing inotify backend, RF backe…
…nds, unittests

* _enh/test_backends:
  RF: reordered tests + enabled gamin now that its fix is pending in Debian
  ENH+BF: filtergamin -- to be more inline with current design of filterinotify
  ENH: 1 more sleep_4_poll to guarantee difference in time stamp
  ENH: few more delays for cases relying on time stamps
  ENH: tests much more robust now across pythons 2.4 -- 2.7
  BF+RF: pyinotify refreshes watcher upon CREATE, unified/simplified *(add|del)LogPath among *Filters
  ENH: fail2ban-testcases -- custom logging format to ease debugging, non-0 exit code in case of failure
  ENH: Filter's testcases -- rename, del + list again --- a bit unstable, might still fail from time to time
  BF: pyinotify -- monitor the parent directory for IN_CREATE + process freshly added file (Closes gh-44)
  ENH: first working unittest for checking polling and inotify backends
  RF/BF: just use pyinotify.ThreadedNotifier thread in filterpyinotify
  RF: filter.py -- single readline in a loop
  ENH: FilterPoll -- adjusted some msgs + allowed to operate without jail (for testing)
  Minor additional comment to DEVELOP
  ENH: extended test LogfileMonitor
dca5634
@yarikoptic yarikoptic added a commit to yarikoptic/fail2ban that referenced this issue Jul 20, 2012
@yarikoptic yarikoptic Merge commit '0.8.6-90-g08564bd' into debian-devel
* commit '0.8.6-90-g08564bd':
  ENH: fail2ban-testcases -- custom logging format to ease debugging, non-0 exit code in case of failure
  ENH: Filter's testcases -- rename, del + list again --- a bit unstable, might still fail from time to time
  BF: pyinotify -- monitor the parent directory for IN_CREATE + process freshly added file (Closes gh-44)
  ENH: first working unittest for checking polling and inotify backends
  RF/BF: just use pyinotify.ThreadedNotifier thread in filterpyinotify
  RF: filter.py -- single readline in a loop
  ENH: FilterPoll -- adjusted some msgs + allowed to operate without jail (for testing)
  Minor additional comment to DEVELOP
  ENH: extended test LogfileMonitor
  ENH: add more verbosity levels to be controlled while running unittests
  Added few tests of FileFilter.  yet to place them into a Jail-ed execution test
  DOC: distilling some of server "design" into DEVELOP notes for common good
  ENH: minor, just  trailing spaces/tabs + reformated a string
  ENH: added a basic test for FilterPoll for detection of modifications
  clarified that the are existing test cases and the 'coming soon' is about creating new ones.
  Added beginnings of documentation for developers
  BF: usedns=no was not working at all
  RF: filtertestcase.py to put common testing into a helping subroutine
  ENH: be able to control verbosity from cmdline for fail2ban-testcases
09dd317
@octavsly

I am still seeing this in gentoo net-analyzer/fail2ban-0.8.7.1. I will switch DEBUG on. In the meantime here is the logrotate of the one with the problem.

/var/log/yate /var/log/yate-cdr.tsv {
create 0640 yate yate
size=30M
rotate 10
missingok
notifempty
postrotate
# Recommended by yate web page
# /bin/kill -HUP /bin/cat /var/run/yate/yate.pid
# gentoo style doing the same thing
/etc/init.d/yate reload > /dev/null 2>&1 || true
endscript
}

@yarikoptic
Member

What python version? If less than 2.6 try current master

@octavsly

Python 2.7.3-r2 and 3.2.3
On Nov 16, 2012 2:03 PM, "Yaroslav Halchenko" notifications@github.com
wrote:

What python version? If less than 2.6 try current master


Reply to this email directly or view it on GitHubhttps://github.com/fail2ban/fail2ban/issues/44#issuecomment-10446190.

@yarikoptic
Member

then more information would be needed (indeed output with debug level), and please also run fail2ban-testcases -- do all of them pass?

would you know a quick way to install centos in a chroot? e.g. in debian land we have debootstrap allowing to do that in 1 command... may be I could replicate the issue locally

@yarikoptic
Member

disregard the last one -- you are using gentoo, although original report about centos -- so that is what confused me... might be worth starting a new bug report

I would still advise trying current master though

@octavsly

fail2ban-testcases is not installed. I will download it from github.

I seem to be able to install debootstrap on my gentoo but I would first try
finding the issue without it since it feels like a long operation
On Nov 16, 2012 3:43 PM, "Yaroslav Halchenko" notifications@github.com
wrote:

then more information would be needed (indeed output with debug level),
and please also run fail2ban-testcases -- do all of them pass?

would you know a quick way to install centos in a chroot? e.g. in debian
land we have debootstrap allowing to do that in 1 command... may be I could
replicate the issue locally


Reply to this email directly or view it on GitHubhttps://github.com/fail2ban/fail2ban/issues/44#issuecomment-10448936.

@octavsly

weurope trash # git clone https://github.com/fail2ban/fail2ban.git
Cloning into 'fail2ban'...
remote: Counting objects: 8485, done.
remote: Compressing objects: 100% (2089/2089), done.
remote: Total 8485 (delta 6330), reused 8391 (delta 6258)
Receiving objects: 100% (8485/8485), 1.25 MiB | 527 KiB/s, done.
Resolving deltas: 100% (6330/6330), done.

weurope fail2ban # ./fail2ban-testcases-all
Testing using /usr/bin/python2.7
Fail2ban 0.8.7.1 test suite. Python 2.7.3 (default, Jul  4 2012, 16:16:47) [GCC 4.5.3]. Please wait...
I: Skipping gamin backend testing. Got exception 'No module named gamin'
.................F.............FFFFF[2012-11-24 15:56:32,013 pyinotify WARNING] Unable to retrieve Watch object associated to <_RawEvent cookie=0 mask=0x8000 name='' wd=2 >
[2012-11-24 15:56:32,031 pyinotify WARNING] Unable to retrieve Watch object associated to <_RawEvent cookie=0 mask=0x8000 name='' wd=1 >
..[2012-11-24 15:56:37,450 pyinotify WARNING] Unable to retrieve Watch object associated to <_RawEvent cookie=0 mask=0x8000 name='' wd=2 >
...
======================================================================
FAIL: testNewChangeViaIsModified (testcases.filtertestcase.LogFileMonitor)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "/root/trash/fail2ban/testcases/filtertestcase.py", line 222, in testNewChangeViaIsModified
    self.assertTrue(self.isModified())
AssertionError: False is not true

======================================================================
FAIL: MonitorFailures<class 'server.filterpoll.FilterPoll'>(/tmp/monitorfailuresGbMcTWfail2ban)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "/root/trash/fail2ban/testcases/filtertestcase.py", line 469, in test_delLogPath
    self.assert_correct_last_attempt(GetFailures.FAILURES_01)
  File "/root/trash/fail2ban/testcases/filtertestcase.py", line 382, in assert_correct_last_attempt
    self.assertTrue(self.isFilled(10)) # give Filter a chance to react
AssertionError: False is not true

======================================================================
FAIL: MonitorFailures<class 'server.filterpoll.FilterPoll'>(/tmp/monitorfailures3RR5onfail2ban)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "/root/trash/fail2ban/testcases/filtertestcase.py", line 398, in test_grow_file
    self.assertTrue(self.isFilled(6))
AssertionError: False is not true

======================================================================
FAIL: MonitorFailures<class 'server.filterpoll.FilterPoll'>(/tmp/monitorfailuresNcThh7fail2ban)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "/root/trash/fail2ban/testcases/filtertestcase.py", line 436, in test_move_file
    self.assertEqual(self.filter.failManager.getFailTotal(), 2) # Fails with Poll from time to time
AssertionError: 0 != 2

======================================================================
FAIL: MonitorFailures<class 'server.filterpoll.FilterPoll'>(/tmp/monitorfailuresxYDJdAfail2ban)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "/root/trash/fail2ban/testcases/filtertestcase.py", line 454, in test_new_bogus_file
    self.assert_correct_last_attempt(GetFailures.FAILURES_01)
  File "/root/trash/fail2ban/testcases/filtertestcase.py", line 382, in assert_correct_last_attempt
    self.assertTrue(self.isFilled(10)) # give Filter a chance to react
AssertionError: False is not true

======================================================================
FAIL: MonitorFailures<class 'server.filterpoll.FilterPoll'>(/tmp/monitorfailures17AhcOfail2ban)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "/root/trash/fail2ban/testcases/filtertestcase.py", line 419, in test_rewrite_file
    self.assert_correct_last_attempt(GetFailures.FAILURES_01)
  File "/root/trash/fail2ban/testcases/filtertestcase.py", line 382, in assert_correct_last_attempt
    self.assertTrue(self.isFilled(10)) # give Filter a chance to react
AssertionError: False is not true

----------------------------------------------------------------------
Ran 41 tests in 62.384s

FAILED (failures=6)
E: Failed with  /usr/bin/python2.7
@octavsly
2012-11-21 03:25:02,632 fail2ban.filter.datedetector: DEBUG  Sorting the template list
2012-11-21 03:26:06,094 fail2ban.filter : DEBUG  Callback for Event: <Event dir=False mask=0x2 maskname=IN_MODIFY name='' path=/var/log/yate pathname=/var/log/yate wd=2 >
2012-11-21 03:26:06,131 fail2ban.filter.datedetector: DEBUG  Sorting the template list
2012-11-21 03:26:06,684 fail2ban.filter : DEBUG  Callback for Event: <Event dir=False mask=0x2 maskname=IN_MODIFY name='' path=/var/log/yate pathname=/var/log/yate wd=2 >
2012-11-21 03:26:06,859 fail2ban.filter.datedetector: DEBUG  Sorting the template list
2012-11-21 03:26:06,872 fail2ban.filter : DEBUG  Callback for Event: <Event dir=False mask=0x2 maskname=IN_MODIFY name='' path=/var/log/yate pathname=/var/log/yate wd=2 >
2012-11-21 03:26:06,877 fail2ban.filter.datedetector: DEBUG  Sorting the template list
2012-11-21 03:26:50,095 fail2ban.filter : DEBUG  Callback for Event: <Event dir=False mask=0x2 maskname=IN_MODIFY name='' path=/var/log/yate pathname=/var/log/yate wd=2 >
2012-11-21 03:26:50,169 fail2ban.filter.datedetector: DEBUG  Sorting the template list
2012-11-21 03:26:50,215 fail2ban.filter : DEBUG  Callback for Event: <Event dir=False mask=0x2 maskname=IN_MODIFY name='' path=/var/log/yate pathname=/var/log/yate wd=2 >
2012-11-21 03:26:50,290 fail2ban.filter.datedetector: DEBUG  Sorting the template list
--
2012-11-21 03:28:10,317 fail2ban.filter.datedetector: DEBUG  Sorting the template list
2012-11-21 03:28:38,140 fail2ban.filter : DEBUG  Callback for Event: <Event dir=False mask=0x2 maskname=IN_MODIFY name='' path=/var/log/yate pathname=/var/log/yate wd=2 >
2012-11-21 03:28:38,432 fail2ban.filter.datedetector: DEBUG  Sorting the template list
2012-11-21 03:28:38,444 fail2ban.filter : DEBUG  Callback for Event: <Event dir=False mask=0x2 maskname=IN_MODIFY name='' path=/var/log/yate pathname=/var/log/yate wd=2 >
2012-11-21 03:28:38,449 fail2ban.filter.datedetector: DEBUG  Sorting the template list
--
2012-11-21 03:31:52,216 fail2ban.filter.datedetector: DEBUG  Sorting the template list
2012-11-21 03:31:52,292 fail2ban.filter : DEBUG  Callback for Event: <Event dir=False mask=0x2 maskname=IN_MODIFY name='' path=/var/log/yate pathname=/var/log/yate wd=2 >
2012-11-21 03:31:52,299 fail2ban.filter : INFO   Log rotation detected for /var/log/yate
2012-11-21 03:31:52,307 fail2ban.filter.datedetector: DEBUG  Sorting the template list
--
2012-11-21 03:32:00,265 fail2ban.actions.action: DEBUG  iptables -I fail2ban-Guestbook 1 -s 93.182.157.17 -j DROP returned successfully
2012-11-21 03:32:26,060 fail2ban.filter : DEBUG  Callback for Event: <Event dir=False mask=0x8000 maskname=IN_IGNORED name='' path=/var/log/yate pathname=/var/log/yate wd=2 >
2012-11-21 03:32:26,065 fail2ban.filter : INFO   Log rotation detected for /var/log/yate
2012-11-21 03:32:26,214 fail2ban.filter.datedetector: DEBUG  Sorting the template list

After the rotation no mention of the /var/log/yate since today (2012/11/24)

Let me know if there is something else I could try. For the time being I will switct back to pooling which seems to work OK

@yarikoptic
Member

On Sat, 24 Nov 2012, octavsly wrote:

2012-11-21 03:31:52,299 fail2ban.filter : INFO Log rotation detected for
/var/log/yate

...<
2012-11-21 03:32:26,065 fail2ban.filter : INFO Log rotation detected for
/var/log/yate

do you have multiple jails pointing to the same log?

Yaroslav O. Halchenko
Postdoctoral Fellow, Department of Psychological and Brain Sciences
Dartmouth College, 419 Moore Hall, Hinman Box 6207, Hanover, NH 03755
Phone: +1 (603) 646-9834 Fax: +1 (603) 646-1419
WWW: http://www.linkedin.com/in/yarik

@octavsly

Only once

[yate]

enabled = true
maxretry = 40
bantime = 360000
filter = yate
action = iptables[name=yate, port=5060, protocol=udp]
sendmail-whois[name=yate, dest=root@localhost, sender=fail2ban@localhost]
logpath = /var/log/yate

/var/log/yate /var/log/yate-cdr.tsv {
create 0640 yate yate
size=30M
rotate 10
missingok
notifempty
postrotate
# Recommended by yate web page
# /bin/kill -HUP /bin/cat /var/run/yate/yate.pid
# gentoo style doing the same thing
/etc/init.d/yate reload > /dev/null 2>&1 || true
endscript
}

@opoplawski
Contributor

This is still not working with fail2ban 0.8.8 and python-inotify 0.9.1 on EL6:
./fail2ban-testcases
....................................[2013-01-14 18:47:31,601 pyinotify WARNING] Unable to retrieve Watch object associated to <_RawEvent cookie=0 mask=0x8000 name='' wd=2 >
[2013-01-14 18:47:31,603 pyinotify WARNING] Unable to retrieve Watch object associated to <_RawEvent cookie=0 mask=0x8000 name='' wd=1 >
..[2013-01-14 18:47:36,266 pyinotify WARNING] Unable to retrieve Watch object associated to <_RawEvent cookie=0 mask=0x8000 name='' wd=2 >
...
----------------------------------------------------------------------
Fail2ban 0.8.8 test suite. Python 2.6.6 (r266:84292, Sep 11 2012, 05:25:09) [GCC 4.4.6 20120305 (Red Hat 4.4.6-4)]. Please wait...
I: Skipping gamin backend testing. Got exception 'No module named gamin'
Ran 41 tests in 30.522s
OK

@opoplawski
Contributor

I should note that not only does the test fail, it fails in production after logrotation.

@tampinc
tampinc commented Feb 10, 2013

I am also experiencing this failure.

CentOS6 (2.6.32-279.19.1.el6.i686)
Fail2Ban v0.8.8
Python 2.6.6
python-inotify 0.9.1-1.el6

Fail2ban stopped banning after the installation of pyinotify which occurred as a dependency when I updated the fail2ban package to 0.8.8 from the EPEL repository. Fail2ban worked fine previously. For the moment I am putting a "[DEFAULT] backend=gamin" into the jail.local and it works again.

Cheers,
Chris

@cgrigor
cgrigor commented Feb 14, 2013

have the same failure
Linux version 2.6.32-279.el6.x86_64 (mockbuild@c6b9.bsys.dev.centos.org) (gcc version 4.4.6 20120305 (Red Hat 4.4.6-4) (GCC) ) #1 SMP
fail2ban-0.8.8-1.el6.noarch
python-2.6.6-29.el6_2.2.x86_64
python-inotify-0.9.1-1.el6.noarch

I tried changing the jail.conf to

backend = gamin

restarted sshd / fail2ban

secure log is still empty and the system is still logging into the rotated log /var/log/secure until i restarted rsyslogd

@poudenes

Hello all,

I using Centos 6.4 and have problems with fail2ban. When i start fail2ban it says ok. Logs give no errors.
A fail2ban-testcases-all got follow log with problems:

Testing using /usr/bin/python2.6
Fail2ban 0.8.8 test suite. Python 2.6.6 (r266:84292, Feb 22 2013, 00:00:18) [GCC 4.4.7 20120313 (Red Hat 4.4.7-3)]. Please wait...
.....................................F...........Exception in thread Thread-61:
Traceback (most recent call last):
File "/usr/lib64/python2.6/threading.py", line 532, in __bootstrap_inner
self.run()
File "/usr/lib64/python2.6/threading.py", line 484, in run
self.__target(_self.__args, *_self.__kwargs)
File "/root/fail2ban/server/asyncserver.py", line 143, in start
asyncore.loop(use_poll = False) # fixes the "Unexpected communication problem" issue on Python 2.6 and 3.0
File "/usr/lib64/python2.6/asyncore.py", line 210, in loop
poll_fun(timeout, map)
File "/usr/lib64/python2.6/asyncore.py", line 140, in poll
r, w, e = select.select(r, w, e, timeout)
error: (9, 'Bad file descriptor')

..........F.................FFFFFF
F.......[2013-05-10 22:12:18,673 pyinotify WARNING] Unable to retrieve Watch object associated to <_RawEvent cookie=0 mask=0x8000 name='' wd=2 >
[2013-05-10 22:12:18,673 pyinotify WARNING] Unable to retrieve Watch object associated to <_RawEvent cookie=0 mask=0x8000 name='' wd=1 >
..[2013-05-10 22:12:25,628 pyinotify WARNING] Unable to retrieve Watch object associated to <_RawEvent cookie=0 mask=0x8000 name='' wd=2 >
.[2013-05-10 22:12:26,258 pyinotify WARNING] Unable to retrieve Watch object associated to <_RawEvent cookie=0 mask=0x8000 name='' wd=2 >
.[2013-05-10 22:12:27,007 pyinotify WARNING] Unable to retrieve Watch object associated to <_RawEvent cookie=0 mask=0x8000 name='' wd=2 >

.....

FAIL: testInaccessibleFile (testcases.clientreadertestcase.ConfigReaderTest)

Traceback (most recent call last):
File "/root/fail2ban/testcases/clientreadertestcase.py", line 68, in testInaccessibleFile
self.assertFalse(self.c.read('d')) # should not be readable BUT present
AssertionError

FAIL: testNewChangeViaIsModified (testcases.filtertestcase.LogFileMonitor)

Traceback (most recent call last):
File "/root/fail2ban/testcases/filtertestcase.py", line 245, in testNewChangeViaIsModified
self.assertTrue(self.isModified())
AssertionError

FAIL: test_delLogPath (testcases.filtertestcase.MonitorFailures(/tmp/monitorfailures_FilterPollCNpLbdfail2ban))

Traceback (most recent call last):
File "/root/fail2ban/testcases/filtertestcase.py", line 531, in test_delLogPath
self.assert_correct_last_attempt(GetFailures.FAILURES_01)
File "/root/fail2ban/testcases/filtertestcase.py", line 408, in assert_correct_last_attempt
self.assertTrue(self.isFilled(20)) # give Filter a chance to react
AssertionError

FAIL: test_grow_file (testcases.filtertestcase.MonitorFailures(/tmp/monitorfailures_FilterPollCNpLbdfail2ban))

Traceback (most recent call last):
File "/root/fail2ban/testcases/filtertestcase.py", line 424, in test_grow_file
self.assertTrue(self.isFilled(6))
AssertionError

FAIL: test_move_file (testcases.filtertestcase.MonitorFailures(/tmp/monitorfailures_FilterPollCNpLbdfail2ban))

Traceback (most recent call last):
File "/root/fail2ban/testcases/filtertestcase.py", line 463, in test_move_file
self.assertEqual(self.filter.failManager.getFailTotal(), 2)
AssertionError: 0 != 2

FAIL: test_move_into_file (testcases.filtertestcase.MonitorFailures(/tmp/monitorfailures_FilterPollCNpLbdfail2ban))

Traceback (most recent call last):
File "/root/fail2ban/testcases/filtertestcase.py", line 505, in test_move_into_file
self._test_move_into_file(interim_kill=False)
File "/root/fail2ban/testcases/filtertestcase.py", line 483, in _test_move_into_file
self.assert_correct_last_attempt(GetFailures.FAILURES_01)
File "/root/fail2ban/testcases/filtertestcase.py", line 408, in assert_correct_last_attempt
self.assertTrue(self.isFilled(20)) # give Filter a chance to react
AssertionError

FAIL: test_move_into_file_after_removed (testcases.filtertestcase.MonitorFailures(/tmp/monitorfailures_FilterPollCNpLbdfail2ban))

Traceback (most recent call last):
File "/root/fail2ban/testcases/filtertestcase.py", line 510, in test_move_into_file_after_removed
self._test_move_into_file(interim_kill=True)
File "/root/fail2ban/testcases/filtertestcase.py", line 483, in _test_move_into_file
self.assert_correct_last_attempt(GetFailures.FAILURES_01)
File "/root/fail2ban/testcases/filtertestcase.py", line 408, in assert_correct_last_attempt
self.assertTrue(self.isFilled(20)) # give Filter a chance to react
AssertionError

FAIL: test_new_bogus_file (testcases.filtertestcase.MonitorFailures(/tmp/monitorfailures_FilterPollCNpLbdfail2ban))

Traceback (most recent call last):
File "/root/fail2ban/testcases/filtertestcase.py", line 516, in test_new_bogus_file
self.assert_correct_last_attempt(GetFailures.FAILURES_01)
File "/root/fail2ban/testcases/filtertestcase.py", line 408, in assert_correct_last_attempt
self.assertTrue(self.isFilled(20)) # give Filter a chance to react
AssertionError

FAIL: test_rewrite_file (testcases.filtertestcase.MonitorFailures(/tmp/monitorfailures_FilterPollCNpLbdfail2ban))

Traceback (most recent call last):
File "/root/fail2ban/testcases/filtertestcase.py", line 445, in test_rewrite_file
self.assert_correct_last_attempt(GetFailures.FAILURES_01)
File "/root/fail2ban/testcases/filtertestcase.py", line 408, in assert_correct_last_attempt
self.assertTrue(self.isFilled(20)) # give Filter a chance to react
AssertionError


Ran 100 tests in 186.577s

FAILED (failures=9)
E: Failed with /usr/bin/python2.6

What can this be and what can i do to let run fail2ban correct?

@yarikoptic
Member

ha -- doesn't it look like what I just reported from a sparc box?
#223
and now I remember that someone had similar complaints before

..........F.................FFFFFF

Yaroslav O. Halchenko, Ph.D.
http://neuro.debian.net http://www.pymvpa.org http://www.fail2ban.org
Senior Research Associate, Psychological and Brain Sciences Dept.
Dartmouth College, 419 Moore Hall, Hinman Box 6207, Hanover, NH 03755
Phone: +1 (603) 646-9834 Fax: +1 (603) 646-1419
WWW: http://www.linkedin.com/in/yarik

@poudenes

Very strange... yesterday a kernel update for Centos 6.4 and some more (32MB) in total. After update reboot my VPS, everything was started. Did a manual startup of Fail2ban and it is working again.. It blocks, it send emails that it has block something... ehmm :) but i'm happy again

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment