failures are not recognised
Brought to you by:
deksai,
tagishandy
Menu
▾
▴
#31 failures are not recognised
Hallo,
I have just installed 0.5.0, but it seems that it does not recognise failure attempts. I have tried many times to connect through ssh as debil@147.228.47.45 (user is not existing), but pam-abl still does not hold any attempt:
Failed users:
<none>
Failed hosts:
196.44.162.30 (3)
Blocked based on rule [*]
where 196.44.162.30 was added manually using pam-abl -f -H 196.44.162.30. The expected host to be blocked is 147.228.47.73
My config is in the attachment, my PAM is configured as follows:
auth required pam_env.so
auth required pam-abl.so config=/etc/security/pam_abl.conf
auth required pam_nologin.so
auth required pam_unix.so try_first_pass likeauth
And the /var/log/security looks like (with pam-abl debug set to ON):
Invalid user debil from 147.228.47.73
Jan 02 15:42:16 [sshd] input_userauth_request: invalid user debil [preauth]
Jan 02 15:42:16 [sshd] Postponed keyboard-interactive for invalid user debil from 147.228.47.73 port 56437 ssh2 [preauth]
Jan 02 15:42:17 [sshd] pam_unix(sshd:auth): authentication failure; logname= uid=0 euid=0 tty=ssh ruser= rhost=ul502p23-kky.fav.zcu.cz
Jan 02 15:42:19 [sshd] error: PAM: Authentication failure for illegal user debil from ul502p23-kky.fav.zcu.cz
Jan 02 15:42:19 [sshd] Failed keyboard-interactive/pam for invalid user debil from 147.228.47.73 port 56437 ssh2
Jan 02 15:42:19 [sshd] Postponed keyboard-interactive for invalid user debil from 147.228.47.73 port 56437 ssh2 [preauth]
Jan 02 15:42:22 [sshd] pam_unix(sshd:auth): authentication failure; logname= uid=0 euid=0 tty=ssh ruser= rhost=ul502p23-kky.fav.zcu.cz
Jan 02 15:42:24 [sshd] error: PAM: Authentication failure for illegal user debil from ul502p23-kky.fav.zcu.cz
Jan 02 15:42:24 [sshd] Failed keyboard-interactive/pam for invalid user debil from 147.228.47.73 port 56437 ssh2
Jan 02 15:42:24 [sshd] Postponed keyboard-interactive for invalid user debil from 147.228.47.73 port 56437 ssh2 [preauth]
Jan 02 15:42:25 [sshd] pam_unix(sshd:auth): authentication failure; logname= uid=0 euid=0 tty=ssh ruser= rhost=ul502p23-kky.fav.zcu.cz
Jan 02 15:42:27 [sshd] error: PAM: Authentication failure for illegal user debil from ul502p23-kky.fav.zcu.cz
Jan 02 15:42:27 [sshd] Failed keyboard-interactive/pam for invalid user debil from 147.228.47.73 port 56437 ssh2
Jan 02 15:42:27 [sshd] Disconnecting: Too many authentication failures for debil [preauth]
There is nomessage from pam-abl??!!. What may be wrong?
Thank you very much,
Dan T.
The configuration of PAM
I've been trying to reproduce the problem but for the moment couldn't.
It looks like pam-abl isn't even loaded for some reason.
I think the 'easiest' way to debug the problem is to strace sshd while you try to login.
That we we can see if it actually loads pam-abl.so and if it tries to perhaps print it's output to another log or something.
If you need help with the strace, just let me know (don't forget -f to trace the child processes).
That's the output I wanted.
From the trace I can conclude that pam-abl and berkeley db are loaded correctly:
[pid 23547] open("/lib64/security/pam-abl.so", O_RDONLY) = 8
[pid 23547] open("/usr/lib64/libdb-4.8.so", O_RDONLY) = 8
The databases are opened anr read/written from:
[pid 23556] open("/var/db/abl/hosts.db", O_RDWR) = 9
pam-abl even manages to write a lot off stuff to syslog:
[pid 23556] socket(PF_FILE, SOCK_DGRAM|SOCK_CLOEXEC, 0) = 8
[pid 23556] connect(8, {sa_family=AF_FILE, path="/dev/log"}, 110) = 0
[pid 23556] sendto(8, "<87>Jan 4 08:35:24 pam-abl[2355"..., 84, ...
...
So the debug output should be somewhere in a log file. Perhaps you should grep on "pam-abl" in your log dir.
For example on my machine all pam logging goes to /var/log/auth.log. I don't know how your syslogd is configured, so I don't know where the log is written to.
If you can't find where it is written to, you can always rerun the strace but with an extra "-s 1024" option. This will make sure that strace prints the first 1024 chars off all strings passed to system calls. This way we can see what pam-abl writes to syslog.
You can also attach to your already running sshd process using "-p <pid>". You can find the pid by running "pgrep sshd".
Conclusion:
For the moment I can't tell you why no failed authentications are logged. According to the strace pam-abl does what it needs to do. Perhaps if we see what it writes to syslog, will know what's wrong.
NOTE:
I noticed in your config this comment.
# Must be here ??!!
db_home=/var/db/abl/
The db_home directory is used by Berkeley db for it's lock files. This way it can make sure that no 2 processes write to the db at the same time.
Hallo,
thanks for you comment. I have only been able to find the following old messages:
Jan 05 11:59:13 [pam-abl] Opertion denyed (13) while opening the database environment
Jan 05 11:59:13 [pam-abl] Opertion denyed (13) while Creating database environment.
Jan 05 11:59:13 [pam-abl] The database environment could not be opened
Jan 05 12:04:44 [pam-abl] Opertion denyed (13) while opening the database environment
Jan 05 12:04:44 [pam-abl] Opertion denyed (13) while Creating database environment.
Jan 05 12:04:44 [pam-abl] The database environment could not be opened
Jan 05 12:04:44 [unix_chkpwd] password check failed for user (dtihelka)
Jan 05 12:04:49 [pam-abl] Opertion denyed (13) while opening the database environment
Jan 05 12:04:49 [pam-abl] Opertion denyed (13) while Creating database environment.
Jan 05 12:04:49 [pam-abl] The database environment could not be opened
but the messages did not appeared when I have tried login failure now ???!!! I have no idea why, since the use of 'logger "message"' did wrote the "message" into the log file ...
What I have also noticed is the following list of files in /var/db/abl:
uk508p02-kky abl # pwd
/var/db/abl
uk508p02-kky abl # ls -all
celkem 11079
drwxr-xr-x 2 root root 304 8. led 15.01 .
drwxr-xr-x 5 root root 168 4. led 20.55 ..
-rw-r----- 1 root root 50 8. led 15.01 __db.register
-rw-r----- 1 root root 24576 8. led 15.01 __db.001
-rw-r----- 1 root root 90112 8. led 15.01 __db.002
-rw-r----- 1 root root 270336 8. led 15.01 __db.003
-rw-r----- 1 root root 163840 8. led 15.01 __db.004
-rw-r----- 1 root root 802816 8. led 15.01 __db.005
-rw-r----- 1 root root 49152 8. led 15.01 __db.006
-rw------- 1 root root 16384 8. led 15.01 hosts.db
-rw-r----- 1 root root 10485760 8. led 15.01 log.0000000001
-rw------- 1 root root 16384 8. led 15.01 users.db
The only updated files are those __* Is it correct?
Thanks,
Dan
The only way I have seen these "Operation denied" messages is if I run the process that does pam authentication with insufficient rights. For example if I first create the database by running "pam-abl <my config>" as root and then let a service not running as root trying to authenticate.
In your case this shouldn't be the problem, because sshd normally runs as root and root should be able to do everything.
> "but the messages did not appeared when I have tried login failure now ???!!!"
Does the problem still occur? Or does it work as expected now?
The __db.0* files are berkeley db specific. In these case they are shared memory regions ( http://sepp.oetiker.ch/subversion-1.4.2-rp/ref/env/region.html ). Not much is known about what they contain. They enable Berkeley db to be opened from multiple processes. They are berkeley internals.