Home › Forums › BlockHosts

Can't open or read: /var/log/secure

Mon, 2007–Jun–18

I have a problem with recently installed blockhosts on FC4.

A dry-run and manual run seems to work ok but when invoked by an ftp-attempt it complains about not being able to open or read /var/log/secure.

------- looking into log file: /var/log/secure
Traceback (most recent call last):
File "/usr/bin/blockhosts.py", line 1172, in open
self._fp = open(self._logfile, "r")
IOError: [Errno 13] Permission denied: '/var/log/secure'
FATAL ERROR: Can't open or read: /var/log/secure

The file indeed is there and fileprivs for /var/log/secure is 600 and changing into a+r doesn't change anything.
Logrotating the file, making it zero bytes long is the same.

I checked the code but couldn't figger out what the problem is.
Any suggestion? I'm running out of ideas ;-)

Rgds
/c

‹ Ubuntu Dapper - using daemons, not inetd. How to make blockhosts run? nighttime attack ›
Wed, 2007-06-20 18:46 — ac

strange...

So, a manual run (not-dry run) works fine?
Try it with --verbose option - is it opening the /var/log/secure file?

That message does point out what you said - that the permissions that blockhosts is running as, under init, it is unable to access /var/log/secure.

Sat, 2007-06-23 06:49 — cj (not verified)

Can't open or read: /var/log/secure

sorry for a lengthy reply, I tried to show all info in one go...

A manual run shows this using --verbose:

[root@bilbo etc]# blockhosts.py --verbose
blockhosts 2.0.4 started: 2007-06-23 12:36:29 CEST
... load blockfile: /etc/hosts.allow
... found both markers, count of hosts being watched: 0
... loading log file, offset: /var/log/secure 880
... will discard all host entries older than 2007-06-22 12:36:29 CEST
... updates: counts: hosts to block: 0; hosts being watched: 0
... no email to send.
[root@bilbo etc]#

while an ftp attempt shows this in the log:

blockhosts 2.0.4 started: 2007-06-23 12:37:13 CEST
Debug mode enabled.
Got config and options: Configuration: {'NOTIFY_ADDRESS': 'cj@****.org', 'VERBOSE':

... bunch of debug info deleted, hope it's not needed for now ;-)

File lock obtained (/tmp/blockhosts.lock) for excluding other instances
pattern to search for blocked ip: ALL: \s*(::ffff:)?(?P\d{1,3}\.\d{1,3}\.\d{1,3}\.\d{1,3})\s* : deny
... load blockfile: /etc/hosts.allow
... seen all state 1 lines, now inside blockhosts markers at offset 843
2: found logfile name line: /var/log/secure
... found both markers, count of hosts being watched: 0
block-file: Got initial watched hosts data:
{}
-------------------
block-file: Got remaining lines:
['\n', '# ----------------------------------------\n', '# finally, the command to execute the blockhosts script, based on\n', '# connection to particular service or services:\n', '\n', '#sshd, proftpd, vsftpd: ALL: spawn /usr/bin/blockhosts.py \\\n', '# --logfiles="/var/log/secure,/var/log/vsftpd.log" \\\n', '# --echo "%c-%s" --mail --check-ip "%h" & \\\n', '#: allow\n', '\n', 'sshd, proftpd, vsftpd: ALL: spawn /usr/bin/blockhosts.py \\\n', ' --debug --echo "%c-%s" \\\n', ' --mail --check-ip "%h" >> /var/log/blockhosts.log 2>&1 & \\\n', ': allow\n', '\n', '# add --verbose >> /var/log/blockhosts.log 2>&1 \n', '# after "%h%" if extra logging is needed\n', '\n']
-------------------
------- looking into log file: /var/log/secure
Traceback (most recent call last):
File "/usr/bin/blockhosts.py", line 1172, in open
self._fp = open(self._logfile, "r")
IOError: [Errno 13] Permission denied: '/var/log/secure'
FATAL ERROR: Can't open or read: /var/log/secure

What user is blockhosts running under when invoked from the ftp-attempt? For the sake of trying, I tried to chmod the secure.log to 777 to no avail...

Any ideas are appreciated.
Rgds
/c

Sat, 2007-06-23 09:37 — Anonymous (not verified)

stumped

Can't see any thing to recommend here next, this is very mysterious.

If you know Python, would be very interesting if you could debug this a bit more by narrowing down the code.

Put the following in a file named "btest.py", and replace blockhosts.py with python btest.py in your hosts.allow file, to run this file instead - also run btest.py on command line (python btest.py) to test it out:

file = "/var/log/secure"
fp = open(file, "r")
print "No Exception, Opened File", file

If that works, that will provide more info. If it fails, even when /var/log/secure is 777, then it is some user/permission issue.

Sat, 2007-06-23 13:21 — cj (not verified)

While poking around in

While poking around in various ends I have now managed to get past the access problem and, actually, I do not really know what the solution was ;-)
However, it is still just partially working.

I've managed to get it to lock me out using ssh but it fails when I try the ftp.

From the log:
Jun 23 16:40:24 bilbo xinetd[25071]: START: ftp pid=25077 from=66.199.184.254
Jun 23 16:40:25 bilbo blockhosts: echo tag: 66.199.184.254-vsftpd@192.168.1.90
Jun 23 16:40:25 bilbo blockhosts: echo tag: 66.199.184.254-vsftpd@192.168.1.90
Jun 23 16:40:25 bilbo blockhosts: FATAL ERROR: Exiting: another instance running? File (/tmp/blockhosts.lock) already locked
Jun 23 16:40:26 bilbo blockhosts: final counts: blocking 0, watching 0

As I understand from the loglines, it looks like the blockhosts.py script is invoked twice for an ftp-attempt since it complains about the lockfile being there already. It was indeed manually deleted before the attempt. I tried to disable the use of lockfile using the conf but due to the default in the .py-script it doesn't help, it's there anyway and I didn't want to abuse the script...

I jumped to another idea and disabled the call to blockhosts in the /ets/hosts.allow-file and planned to run the script periodically from cron instead to see if it makes a difference. And now it isn't complaining about a stray lockfile anymore. It will, however, not block the IP I'm using.

I got a buch of such lines in the logfile and the threshold is set to three for now:

Jun 23 17:03:02 bilbo blockhosts: echo tag: 192.108.114.19-vsftpd@192.168.1.90
Jun 23 17:03:03 bilbo blockhosts: final counts: blocking 0, watching 0
Jun 23 17:03:04 bilbo vsftpd[25249]: Sat Jun 23 15:03:04 2007 [pid 25249] [anonymous] FAIL LOGIN: Client "192.108.114.19"
Jun 23 17:03:15 bilbo vsftpd(pam_unix)[25249]: authentication failure; logname= uid=0 euid=0 tty= ruser= rhost=192.108.114.19 user=cj
Jun 23 17:03:18 bilbo vsftpd[25249]: Sat Jun 23 15:03:18 2007 [pid 25249] [cj] FAIL LOGIN: Client "192.108.114.19"

But running the script manually after a while doesn't catch those, 6-7 failed logins. I recon it should work if I run it that way?

I like the script and the concept and really want it to work but is beginning to feel a little confused by now. Normally it is not that difficult to get stuff like this working but now I feel like I am running in circles... There is probably no problem with the script, it's most likely my setup that is out of sync...

Ideas?

Rgds
/c

Sat, 2007-06-23 18:02 — Anonymous (not verified)

multiple instances - and no pattern for that vsftpd

> FATAL ERROR: Exiting: another instance running?

This is actually a misleading message - it is an error for one of the instances, but really should be "Warning" - another instance is already running, so don't need to run two blockhosts at the same time - it is not really an error.

The reason two of them are running is probably because you may have a cron entry and the vsftpd/tcp wrappers based entry both running at the same time.

As to why it is not catching entries, that is because vsftpd has again changed the log statement - therefore the pattern is not catching it. There will need to be an update to blockhosts to capture that:

Current line:

    "VSFTPD-Fail": r"""^[^[]+?\[pid \d+\] .* FAIL LOGIN: Client "(::ffff:)?(?P<host>\d{1,3}\.\d{1,3}\.\d{1,3}\.\d{1,3})"$""",

will not recognize the pattern you have shown in the log.

Not tested, the following may work:

    "VSFTPD-Fail": r"""\[pid \d+\] .* FAIL LOGIN: Client "(::ffff:)?(?P<host>\d{1,3}\.\d{1,3}\.\d{1,3}\.\d{1,3})"$""",

Finally - if you look at your logs, the same process id is used by vsftpd for both failure attempts - at Jun 23 17:03:04 and Jun 23 17:03:18 - if many attempts are allowed per pid, then there is no way scripts like blockhosts will work - there is some setting in the new vsftpd to exit the vsftpd server process on a fixed number of failures, that should be set (or default checked - should be 3 or so for example).

[Editor: changed less-than etc characters to use HTML entities to display correctly.]

Sun, 2007-06-24 04:36 — cj (not verified)

Geez - thanx!

You made my day! :-D

I had to start learning about Pythons regex and eventually I figured it out, exactly as you pointed out.
I compared the example logline in the blockhosts.py-file with the regex used initially and then compared those to the ones that you provided to understand the difference. The one in the original file was not the same as either of the one that you posted, however ;-)

I made a couple of attempts and sure enough, after a minor mod to your proposed line (adding <host> after ?P), it finally works!

Those are the relevant lines for vsftpd, I kept them all for reference and to see which one is working:

"VSFTPD-Fail-0": r"""^[^[]+?\[pid \d+\] \[.*\] FAIL LOGIN: Client "(?P<host>\d{1,3}\.\d{1,3}\.\d{1,3}\.\d{1,3})"$""",
"VSFTPD-Fail-1": r"""^[^[]+?\[pid \d+\] .* FAIL LOGIN: Client "(::ffff:)?(?P<host>\d{1,3}\.\d{1,3}\.\d{1,3}\.\d{1,3})"$""",
"VSFTPD-Fail-2": r"""\[pid \d+\] .* FAIL LOGIN: Client "(::ffff:)?(?P<host>\d{1,3}\.\d{1,3}\.\d{1,3}\.\d{1,3})"$""",

The first line was there from start, the third was the one that finally works and now all offending IP's are blocked.

Thanx! I very much appreciate the time you all took to help me solve this.

Now I will start examining the problem of concurrent scripts and how to start it, but that seems minor.

Thanx again.

B rgds
/c

[Editor: changed all less-than and greater-than character to use HTML enties.]

Sun, 2007-06-24 07:44 — ac

thanks - what OS and vsftpd version?

Thanks for reporting this - version 2.0.5 (or newer) fixes this pattern, now available at the download page.

The forum posting software gobbles up less-than < characters - I've fixed them in the comments above, they are now correct need to use HTML entities &lt;

The exact pattern I'll use is probably going to be a small modification, like this:

    "VSFTPD-Fail": r"""^[^[]+?(vsftpd.+)?\[pid \d+\] .* FAIL LOGIN: Client "(::ffff:)?(?P<host>\d{1,3}\.\d{1,3}\.\d{1,3}\.\d{1,3})"$""",

Finally: can you post the name and version of the distribution/operating system, as well of vsftpd you are using?

Sun, 2007-06-24 16:42 — cj (not verified)

Sure, the details are as

Sure, the details are as follows:

Linux FC4, 2.6.17-1, will be replaced later by a more recent version but will do for now due to plenty of stuff to upgrade... (don't upgrade if it ain't broken...)
Your script is (well, was, before my stab) 2.0.4 and the vsftpd is vsftpd.i386 v. 2.0.3-1.

I have now gone back to running blockhosts per call using hosts.allow and no problems with the lockfile. I have also set up cron to crank up blockhosts twice a day to send the reports and update stats if was not made on the fly for some reason.
Hopefully the next abuse attempt will be soon so I can see when it works :-)

Thanx for a great piece of software and your support.

Rgds
/christer