#24 Fail2ban 0.8.1 stops working

open-accepted
Cyril Jaquier
None
5
2007-10-29
2007-10-29
Anonymous
No

I have fail2ban installed in a Debian Etch server, it's working OK until some time that is still checking the log but not banning anything but there is still new lines matching regex, log is as follows:

2007-10-28 06:30:53,465 fail2ban.filter : DEBUG /var/log/mail.log has been modified
2007-10-28 06:30:53,465 fail2ban.filter : DEBUG Opened /var/log/mail.log
2007-10-28 06:30:53,468 fail2ban.filter : DEBUG Setting file position to 76673695L for /var/log/mail.log
2007-10-28 06:30:53,473 fail2ban.filter.datedetector: DEBUG Sorting the template list
2007-10-28 06:30:53,837 fail2ban.actions: WARNING [spam] Ban 83.29.138.213
2007-10-28 06:30:53,837 fail2ban.actions.action: DEBUG iptables -nL INPUT | grep -q fail2ban-SPAM
2007-10-28 06:30:53,876 fail2ban.actions.action: DEBUG iptables -nL INPUT | grep -q fail2ban-SPAM returned successfully
2007-10-28 06:30:53,877 fail2ban.actions.action: DEBUG iptables -I fail2ban-SPAM 1 -s 83.29.138.213 -p tcp --dport smtp -j DROP
2007-10-28 06:30:53,894 fail2ban.actions.action: DEBUG iptables -I fail2ban-SPAM 1 -s 83.29.138.213 -p tcp --dport smtp -j DROP ret
urned successfully
2007-10-28 06:30:54,476 fail2ban.filter : DEBUG /var/log/mail.log has been modified
2007-10-28 06:30:54,477 fail2ban.filter : DEBUG Opened /var/log/mail.log
2007-10-28 06:30:54,478 fail2ban.filter : DEBUG Setting file position to 76673695L for /var/log/mail.log
2007-10-28 06:30:54,479 fail2ban.filter.datedetector: DEBUG Sorting the template list
2007-10-28 06:30:54,898 fail2ban.actions: WARNING [spam] Ban 71.58.28.162
2007-10-28 06:30:54,899 fail2ban.actions.action: DEBUG iptables -nL INPUT | grep -q fail2ban-SPAM
2007-10-28 06:30:54,937 fail2ban.actions.action: DEBUG iptables -nL INPUT | grep -q fail2ban-SPAM returned successfully
2007-10-28 06:30:54,938 fail2ban.actions.action: DEBUG iptables -I fail2ban-SPAM 1 -s 71.58.28.162 -p tcp --dport smtp -j DROP
2007-10-28 06:30:54,958 fail2ban.actions.action: DEBUG iptables -I fail2ban-SPAM 1 -s 71.58.28.162 -p tcp --dport smtp -j DROP retu
rned successfully
2007-10-28 06:30:55,479 fail2ban.filter : DEBUG /var/log/mail.log has been modified
2007-10-28 06:30:55,480 fail2ban.filter : DEBUG Opened /var/log/mail.log
2007-10-28 06:30:55,481 fail2ban.filter : DEBUG Setting file position to 76673695L for /var/log/mail.log
2007-10-28 06:30:55,484 fail2ban.filter.datedetector: DEBUG Sorting the template list
2007-10-28 06:30:56,484 fail2ban.filter : DEBUG /var/log/mail.log has been modified
2007-10-28 06:30:56,488 fail2ban.filter : DEBUG Opened /var/log/mail.log
2007-10-28 06:30:56,490 fail2ban.filter : DEBUG Setting file position to 76673695L for /var/log/mail.log
2007-10-28 06:30:56,495 fail2ban.filter.datedetector: DEBUG Sorting the template list
2007-10-28 06:30:57,494 fail2ban.filter : DEBUG /var/log/mail.log has been modified
2007-10-28 06:30:57,494 fail2ban.filter : DEBUG Opened /var/log/mail.log
2007-10-28 06:30:57,495 fail2ban.filter : DEBUG Setting file position to 76673695L for /var/log/mail.log
2007-10-28 06:30:57,496 fail2ban.filter.datedetector: DEBUG Sorting the template list
2007-10-28 06:30:58,496 fail2ban.filter : DEBUG /var/log/mail.log has been modified
2007-10-28 06:30:58,503 fail2ban.filter : DEBUG Opened /var/log/mail.log
2007-10-28 06:30:58,506 fail2ban.filter : DEBUG Setting file position to 76673695L for /var/log/mail.log
2007-10-28 06:30:58,512 fail2ban.filter.datedetector: DEBUG Sorting the template list
2007-10-28 06:30:59,514 fail2ban.filter : DEBUG /var/log/mail.log has been modified
2007-10-28 06:30:59,514 fail2ban.filter : DEBUG Opened /var/log/mail.log
2007-10-28 06:30:59,515 fail2ban.filter : DEBUG Setting file position to 76673695L for /var/log/mail.log
2007-10-28 06:30:59,516 fail2ban.filter.datedetector: DEBUG Sorting the template list
2007-10-28 06:31:00,518 fail2ban.filter : DEBUG /var/log/mail.log has been modified
2007-10-28 06:31:00,519 fail2ban.filter : DEBUG Opened /var/log/mail.log
2007-10-28 06:31:00,523 fail2ban.filter : DEBUG Setting file position to 76673695L for /var/log/mail.log
2007-10-28 06:31:00,527 fail2ban.filter.datedetector: DEBUG Sorting the template list
2007-10-28 06:31:01,532 fail2ban.filter : DEBUG /var/log/mail.log has been modified
2007-10-28 06:31:01,532 fail2ban.filter : DEBUG Opened /var/log/mail.log
2007-10-28 06:31:01,536 fail2ban.filter : DEBUG Setting file position to 76673695L for /var/log/mail.log
2007-10-28 06:31:01,543 fail2ban.filter.datedetector: DEBUG Sorting the template list
2007-10-28 06:31:02,547 fail2ban.filter : DEBUG /var/log/mail.log has been modified
2007-10-28 06:31:02,547 fail2ban.filter : DEBUG Opened /var/log/mail.log
2007-10-28 06:31:02,548 fail2ban.filter : DEBUG Setting file position to 76673695L for /var/log/mail.log
2007-10-28 06:31:02,550 fail2ban.filter.datedetector: DEBUG Sorting the template list
2007-10-28 06:31:03,550 fail2ban.filter : DEBUG /var/log/mail.log has been modified
2007-10-28 06:31:03,551 fail2ban.filter : DEBUG Opened /var/log/mail.log
2007-10-28 06:31:03,552 fail2ban.filter : DEBUG Setting file position to 76673695L for /var/log/mail.log
2007-10-28 06:31:03,555 fail2ban.filter.datedetector: DEBUG Sorting the template list
2007-10-28 06:31:04,554 fail2ban.filter : DEBUG /var/log/mail.log has been modified
2007-10-28 06:31:04,554 fail2ban.filter : DEBUG Opened /var/log/mail.log
2007-10-28 06:31:04,555 fail2ban.filter : DEBUG Setting file position to 76673695L for /var/log/mail.log
2007-10-28 06:31:04,557 fail2ban.filter.datedetector: DEBUG Sorting the template list
2007-10-28 06:31:05,557 fail2ban.filter : DEBUG /var/log/mail.log has been modified
2007-10-28 06:31:05,557 fail2ban.filter : DEBUG Opened /var/log/mail.log
2007-10-28 06:31:05,558 fail2ban.filter : DEBUG Setting file position to 76673695L for /var/log/mail.log
2007-10-28 06:31:05,560 fail2ban.filter.datedetector: DEBUG Sorting the template list
2007-10-28 06:31:06,561 fail2ban.filter : DEBUG /var/log/mail.log has been modified
2007-10-28 06:31:06,561 fail2ban.filter : DEBUG Opened /var/log/mail.log
2007-10-28 06:31:06,562 fail2ban.filter : DEBUG Setting file position to 76673695L for /var/log/mail.log
2007-10-28 06:31:06,569 fail2ban.filter.datedetector: DEBUG Sorting the template list
2007-10-28 06:31:08,571 fail2ban.filter : DEBUG /var/log/mail.log has been modified
2007-10-28 06:31:08,572 fail2ban.filter : DEBUG Opened /var/log/mail.log
2007-10-28 06:31:08,572 fail2ban.filter : DEBUG Setting file position to 76673695L for /var/log/mail.log
2007-10-28 06:31:08,574 fail2ban.filter.datedetector: DEBUG Sorting the template list
2007-10-28 06:31:09,574 fail2ban.filter : DEBUG /var/log/mail.log has been modified
2007-10-28 06:31:09,575 fail2ban.filter : DEBUG Opened /var/log/mail.log
2007-10-28 06:31:09,575 fail2ban.filter : DEBUG Setting file position to 76673695L for /var/log/mail.log
2007-10-28 06:31:09,577 fail2ban.filter.datedetector: DEBUG Sorting the template list
2007-10-28 06:31:10,578 fail2ban.filter : DEBUG /var/log/mail.log has been modified
2007-10-28 06:31:10,578 fail2ban.filter : DEBUG Opened /var/log/mail.log
2007-10-28 06:31:10,579 fail2ban.filter : DEBUG Setting file position to 76673695L for /var/log/mail.log
2007-10-28 06:31:10,580 fail2ban.filter.datedetector: DEBUG Sorting the template list
2007-10-28 06:31:11,582 fail2ban.filter : DEBUG /var/log/mail.log has been modified
2007-10-28 06:31:11,582 fail2ban.filter : DEBUG Opened /var/log/mail.log
2007-10-28 06:31:11,583 fail2ban.filter : DEBUG Setting file position to 76673695L for /var/log/mail.log
2007-10-28 06:31:11,584 fail2ban.filter.datedetector: DEBUG Sorting the template list

Other times Fail2ban simply start unban of every banned IP, and closes itself (no server process running), without error in the logs.

Contact: jralfageme@alhsys.es

Discussion

1 2 > >> (Page 1 of 2)
  • Cyril Jaquier
    Cyril Jaquier
    2007-10-29

    Logged In: YES
    user_id=933467
    Originator: NO

    Hi,

    Interesting... The position stays the same (76673695L). This is probably not normal. Could you use screen and run this in one terminal:

    # fail2ban-server -f

    and in another one:

    # fail2ban-client reload

     
  • Cyril Jaquier
    Cyril Jaquier
    2007-10-29

    • assigned_to: nobody --> lostcontrol
    • summary: Fail2ban 8.0.1 stops working --> Fail2ban 0.8.1 stops working
    • status: open --> open-accepted
     
  • Logged In: NO

    I didn't realized the log position wasn't changing, I tried the commands but I'm doing something wrong:

    #fail2ban-server -f
    2007-10-30 08:15:15,542 fail2ban.server : INFO Starting Fail2ban

    # fail2ban-client reload
    ERROR Could not find server

     
  • Cyril Jaquier
    Cyril Jaquier
    2007-10-30

    Logged In: YES
    user_id=933467
    Originator: NO

    Could you try to set the socket file explicitly?

    # fail2ban-server -f -s /tmp/fail2ban-test.sock

    and

    # fail2ban-client -vvv -s /tmp/fail2ban-test.sock reload

     
  • Logged In: NO

    Now it works, I'll wait until problem arises again and attach info show by the server running in foreground:

    # fail2ban-server -f -s /tmp/fail2ban-test.sock
    2007-10-30 11:48:35,801 fail2ban.server : INFO Starting Fail2ban
    2007-10-30 11:48:45,040 fail2ban.comm : DEBUG Connection closed
    2007-10-30 11:48:45,041 fail2ban.comm : DEBUG Starting new thread to handle the request
    2007-10-30 11:48:45,042 fail2ban.comm : DEBUG Command: ['set', 'logtarget', '/var/log/fail2ban.log']

     
  • Logged In: NO

    Server crashed completely this time:

    # fail2ban-server -f -s /tmp/fail2ban-test.sock
    2007-10-30 15:37:05,699 fail2ban.server : INFO Starting Fail2ban
    2007-10-30 15:37:16,653 fail2ban.comm : DEBUG Connection closed
    2007-10-30 15:37:16,654 fail2ban.comm : DEBUG Starting new thread to handle the request
    2007-10-30 15:37:16,654 fail2ban.comm : DEBUG Command: ['set', 'logtarget', '/var/log/fail2ban.log']
    [Errno 514] Unknown error 514
    Traceback (most recent call last):
    File "logging/__init__.py", line 737, in emit
    ValueError: I/O operation on closed file
    Traceback (most recent call last):
    File "logging/__init__.py", line 737, in emit
    ValueError: I/O operation on closed file

    Thanks for your support

     
  • Cyril Jaquier
    Cyril Jaquier
    2007-10-31

    Logged In: YES
    user_id=933467
    Originator: NO

    Can you reproduce this crash? Could you try the attached patch? I'm not really sure about the origin of this bug :/ I found [1] and that could be a candidate too...

    Thanks

    [1] http://mail.python.org/pipermail/python-dev/2007-January/070626.html
    File Added: remove-handler-before-close.patch

     
  • Logged In: NO

    Crash cannot be reproduced, it simply happens without any apparent reason and it's not posible to know when it's going to happen again, if you don't mind I'm going to wait for another crash before apply the patch just to be sure of the reason, usually crashes 24-48 hours before starting the server.

    Thanks for your support :-)

     
  • Logged In: NO

    I had a new crash, this time server was still running but not responding, and I don't know why because there is no log since first time logs rotated, because I forgot change logrotate script to made a reload with new parameters in mind I think adding "/usr/bin/fail2ban-client -s "/tmp/fail2ban-test.sock" reload" in postrotate commands is enough.

    Patch was applied to my server.py "/usr/share/fail2ban/server/server.py" I will wait to see what happens now.

    Last crash:

    # /usr/bin/fail2ban-client -s "/tmp/fail2ban-test.sock" ping
    ERROR Unable to contact server. Is it running?
    # ps ax | grep fail2ban
    2728 pts/1 Sl+ 52:14 /usr/bin/python /usr/bin/fail2ban-server -f -s /tmp/fail2ban-test.sock
    # fail2ban-server -f -s /tmp/fail2ban-test.sock
    2007-10-30 15:49:14,691 fail2ban.server : INFO Starting Fail2ban
    2007-10-30 15:49:20,828 fail2ban.comm : DEBUG Connection closed
    2007-10-30 15:49:20,828 fail2ban.comm : DEBUG Starting new thread to handle the request
    2007-10-30 15:49:20,829 fail2ban.comm : DEBUG Command: ['set', 'logtarget', '/var/log/fail2ban.log']

    Thanks

     
1 2 > >> (Page 1 of 2)