Problem with kreberos auth to linux machine (user/pass from AD)

[George]

Welcome!

As I wrote in subject, problem is with logging to the linux machine,
with kerberos authorization..

This is my first time when I am configuring kerberos.. so please be
forgiving ;)


The basics: What I done:


On Windows (win server 2008R2 – computer name: active, full name:
active.linux.domain)
- Installed Active Directory, Microsoft Identity for UNIX and
DNS server)
- create forest linux.domain
- add linux box record (ubuntu.linux.domain) to windows DNS
- Create SRV record for windows machine (active.linux.domain)
- Add user (ldapquery) to made authorization for linux boxes
and create credentials for it.
- create regular user testuser, with the unix attributes (uid,
group, home dir etc..)
- create grup for this user


On Linux box (ubuntu.linux.domain)
- install packages : krb5-* libkrb-*
- download and compile nss-pam-ldapd-0.8.10.tar.gz
- install and configure nslcd deamon
- installed and configured NTP server, to get current time from
Windows machine


What is important:
- ldapsearch gives the results perfectly
- getent passwd - also shows remote AD users
- when I am logging to the machine, it let me in correctly (but
without kerberos auth)



Now, when I try to log-in to the server using the credentials from AD, I
get the following logs:


Aug 14 01:58:15 ubuntu32 sshd[15831]: pam_krb5(sshd:auth):
pam_sm_authenticate: entry (nonull)
Aug 14 01:58:15 ubuntu32 sshd[15831]: pam_krb5(sshd:auth): (user
testuser) attempting authentication as test...@LINUX.DOMAIN
Aug 14 01:58:15 ubuntu32 sshd[15831]: pam_krb5(sshd:auth): (user
testuser) krb5_get_init_creds_password: Clock skew too great
Aug 14 01:58:15 ubuntu32 sshd[15831]: pam_krb5(sshd:auth):
authentication failure; logname=testuser uid=0 euid=0 tty=ssh ruser=
rhost=192.168.2.159
Aug 14 01:58:15 ubuntu32 sshd[15831]: pam_krb5(sshd:auth):
pam_sm_authenticate: exit (failure)
Aug 14 01:58:15 ubuntu32 sshd[15831]: pam_unix(sshd:auth):
authentication failure; logname= uid=0 euid=0 tty=ssh ruser=
rhost=192.168.2.159 user=testuser
Aug 14 01:58:16 ubuntu32 sshd[15831]: pam_krb5(sshd:account):
pam_sm_acct_mgmt: entry
Aug 14 01:58:16 ubuntu32 sshd[15831]: pam_krb5(sshd:account): skipping
non-Kerberos login
Aug 14 01:58:16 ubuntu32 sshd[15831]: pam_krb5(sshd:account):
pam_sm_acct_mgmt: exit (ignore)
Aug 14 01:58:16 ubuntu32 sshd[15831]: Accepted password for testuser
from 192.168.2.159 port 51594 ssh2
Aug 14 01:58:16 ubuntu32 sshd[15831]: pam_krb5(sshd:setcred):
pam_sm_setcred: entry (establish)
Aug 14 01:58:16 ubuntu32 sshd[15831]: pam_krb5(sshd:setcred): no context
found, creating one
Aug 14 01:58:16 ubuntu32 sshd[15831]: pam_krb5(sshd:setcred): (user
testuser) unable to get PAM_KRB5CCNAME, assuming non-Kerberos login
Aug 14 01:58:16 ubuntu32 sshd[15831]: pam_krb5(sshd:setcred):
pam_sm_setcred: exit (success)
Aug 14 01:58:16 ubuntu32 sshd[15831]: pam_krb5(sshd:session):
pam_sm_open_session: entry
Aug 14 01:58:16 ubuntu32 sshd[15831]: pam_krb5(sshd:session): no context
found, creating one
Aug 14 01:58:16 ubuntu32 sshd[15831]: pam_krb5(sshd:session): (user
testuser) unable to get PAM_KRB5CCNAME, assuming non-Kerberos login
Aug 14 01:58:16 ubuntu32 sshd[15831]: pam_krb5(sshd:session):
pam_sm_open_session: exit (ignore)
Aug 14 01:58:16 ubuntu32 sshd[15831]: pam_unix(sshd:session): session
opened for user testuser by (uid=0)
Aug 14 01:58:16 ubuntu32 sshd[15947]: pam_krb5(sshd:setcred):
pam_sm_setcred: entry (establish)
Aug 14 01:58:16 ubuntu32 sshd[15947]: pam_krb5(sshd:setcred): no context
found, creating one
Aug 14 01:58:16 ubuntu32 sshd[15947]: pam_krb5(sshd:setcred): (user
testuser) unable to get PAM_KRB5CCNAME, assuming non-Kerberos login
Aug 14 01:58:16 ubuntu32 sshd[15947]: pam_krb5(sshd:setcred):
pam_sm_setcred: exit (success)
Aug 14 01:58:17 ubuntu32 sshd[15831]: pam_krb5(sshd:session):
pam_sm_close_session: entry (silent)
Aug 14 01:58:17 ubuntu32 sshd[15831]: pam_krb5(sshd:session):
pam_sm_close_session: exit (success)
Aug 14 01:58:17 ubuntu32 sshd[15831]: pam_unix(sshd:session): session
closed for user testuser
Aug 14 01:58:17 ubuntu32 sshd[15831]: pam_krb5(sshd:setcred):
pam_sm_setcred: entry (delete)
Aug 14 01:58:17 ubuntu32 sshd[15831]: pam_krb5(sshd:setcred):
pam_sm_setcred: exit (success)


My athorization goes well, but as we see in logs, kerberos isn't used ;/
What could it be? I will be glad for any hints, suggestions, or
solutions.. How to test it deeper, what to correct, check?

Regards!










--
Best Regards
George

[Russ Allbery]

George <geor...@wp.pl> writes:

> Aug 14 01:58:15 ubuntu32 sshd[15831]: pam_krb5(sshd:auth): (user
> testuser) krb5_get_init_creds_password: Clock skew too great

Check the client system clock? Kerberos uses timestamps fairly heavily as
part of its protocol, and if the time on the server and the client differs
by too much, everything stops working.

In general, you probably want to be running ntpd or some equivalent on any
host that's involved in Kerberos.

--
Russ Allbery (r...@stanford.edu) <http://www.eyrie.org/~eagle/>

[George]

What is interesting..

What I done:
Remove the /etc/krb5.keytab file
Stop the ntp server on Linux box
Manually adjust the date from windows machine (ntpdate 192.168.144.143) and
start the ntp server again.

And try to log-in:

Now I see the following logs:

Aug 14 19:16:19 ubu03 sshd[1681]: pam_krb5(sshd:auth): pam_sm_authenticate:
entry (nonull)
Aug 14 19:16:19 ubu03 sshd[1681]: pam_krb5(sshd:auth): (user testuser)
attempting authentication as test...@LINUX.DOMAIN
Aug 14 19:16:22 ubu03 sshd[1681]: pam_krb5(sshd:auth): user testuser
authenticated as test...@LINUX.DOMAIN
Aug 14 19:16:22 ubu03 sshd[1681]: pam_krb5(sshd:auth): pam_sm_authenticate:
exit (success)
Aug 14 19:16:22 ubu03 sshd[1681]: pam_krb5(sshd:account): pam_sm_acct_mgmt:
entry
Aug 14 19:16:22 ubu03 sshd[1681]: pam_krb5(sshd:account): (user testuser)
retrieving principal from cache
Aug 14 19:16:22 ubu03 sshd[1681]: pam_krb5(sshd:account): pam_sm_acct_mgmt:
exit (success)
Aug 14 19:16:22 ubu03 sshd[1679]: Accepted keyboard-interactive/pam for
testuser from 192.168.147.102 port 31194 ssh2
Aug 14 19:16:22 ubu03 nslcd[999]: [200854] <group/member="testuser">
ldap_result() failed: No such object
Aug 14 19:16:22 ubu03 sshd[1679]: pam_krb5(sshd:setcred): pam_sm_setcred:
entry (establish)
Aug 14 19:16:22 ubu03 sshd[1679]: pam_krb5(sshd:setcred): no context found,
creating one
Aug 14 19:16:22 ubu03 sshd[1679]: pam_krb5(sshd:setcred): (user testuser)
found initial ticket cache at /var/tmp/krb5cc_pam_4Kw0LB
Aug 14 19:16:22 ubu03 sshd[1679]: pam_krb5(sshd:setcred): (user testuser)
initializing ticket cache /var/tmp/krb5cc_10001_wyCVAA
Aug 14 19:16:22 ubu03 sshd[1679]: pam_krb5(sshd:setcred): pam_sm_setcred:
exit (success)
Aug 14 19:16:22 ubu03 nslcd[999]: [b127f8] <group=10000> ldap_result()
failed: No such object
Aug 14 19:16:22 ubu03 sshd[1679]: pam_krb5(sshd:session):
pam_sm_open_session: entry
Aug 14 19:16:22 ubu03 sshd[1679]: pam_krb5(sshd:session):
pam_sm_open_session: exit (success)
Aug 14 19:16:22 ubu03 sshd[1679]: pam_unix(sshd:session): session opened for
user testuser by (uid=0)
Aug 14 19:16:22 ubu03 sshd[1796]: pam_krb5(sshd:setcred): pam_sm_setcred:
entry (establish)
Aug 14 19:16:22 ubu03 sshd[1796]: pam_krb5(sshd:setcred): pam_sm_setcred:
exit (success)
Aug 14 19:16:23 ubu03 sshd[1679]: pam_krb5(sshd:session):
pam_sm_close_session: entry (silent)
Aug 14 19:16:23 ubu03 sshd[1679]: pam_krb5(sshd:session):
pam_sm_close_session: exit (success)
Aug 14 19:16:23 ubu03 sshd[1679]: pam_unix(sshd:session): session closed for
user testuser
Aug 14 19:16:24 ubu03 sshd[1679]: pam_krb5(sshd:setcred): pam_sm_setcred:
entry (delete)
Aug 14 19:16:24 ubu03 sshd[1679]: pam_krb5(sshd:setcred): pam_sm_setcred:
exit (success)


So it looks that the user is correctly authenticated.. Right?

testuser@ubu03:~$ mkdir xx
testuser@ubu03:~$ ls -l
total 4
drwxr-xr-x 2 testuser 10000 4096 Aug 14 13:55 xx

So I do not see the group associated with the user (SecureLDAP). Why?

What is interesting too, is that I have also errors of nslcd deamon:
Aug 14 19:12:56 ubu03 nslcd[999]: [45e146] <passwd="testuser">
ldap_search_ext() failed: Can't contact LDAP server
Aug 14 19:12:56 ubu03 nslcd[999]: [45e146] <passwd="testuser"> no available
LDAP server found, sleeping 1 seconds
Aug 14 19:16:22 ubu03 nslcd[999]: [200854] <group/member="testuser">
ldap_result() failed: No such object
Aug 14 19:16:22 ubu03 nslcd[999]: [b127f8] <group=10000> ldap_result()
failed: No such object
Aug 14 19:17:01 ubu03 nslcd[999]: [90cde7] <group/member="root">
ldap_result() failed: No such object