[OpenAFS] Solaris 10 (x86): pam_afs_session
John Tang Boyland
boyland@cs.uwm.edu
Wed, 23 Jan 2008 15:09:56 -0600
] John Tang Boyland <boyland@cs.uwm.edu> writes:
]
] > I'm using pam_afs_session (v1.4) on Solaris 10 (x86 Generic_120012-14)
] > and have an interesting problem: the screen login system starts the
] > session before it does the authentication. I have the Sun-provided
] > pam_krb5 in the pam stack for auth, but it gets called AFTER
] > pam_afs_session has tried to get an AFS token (verified using truss).
] > The workaround is to log on twice: the first time fails because it
] > doesn't get a token, but it does get the krb5 TGT. Then the second
] > time, it picks up the *old* TGT and gets an AFS token.
]
] It looks like you're not running pam_krb5 in the session stack. pam_krb5
] should be listed in the session stack before pam_afs_session, and that
] will probably fix the problem.
(BTW: This is Sun-provided pam_krb5)
Ok I added it so pam.conf now has:
# ...
other session required pam_unix_session.so.1
other session required pam_krb5.so.1
other session required pam_afs_session.so always_aklog
# ...
It didn't work, so I rebooted. It still didn't work.
The truss output is strange (to my untrained eye):
The main process proceeds to do a lot of krb5 things
before ever looking at pam_krb5.so.1, for example:
560: xstat(2, "/etc/krb5/krb5.conf", 0x080463C0) = 0^M
560: xstat(2, "/etc/krb5/krb5.conf", 0x080463C0) = 0^M
560: xstat(2, "/etc/krb5/krb5.conf", 0x080463C0) = 0^M
560: xstat(2, "/etc/krb5/krb5.conf", 0x080463C0) = 0^M
560: xstat(2, "/etc/krb5/krb5.conf", 0x080463C0) = 0^M
...
But there are also "real" things with /dev/urandom /etc/krb5/krb5.keytab etc.
A long time later (about 1800 lines) we get:
560: stat64("/usr/lib/security/pam_unix_session.so.1", 0x08046930) = 0^M
560: xstat(2, "/usr/lib/security/pam_unix_session.so.1", 0x08046168) = 0^M
560: resolvepath("/usr/lib/security/pam_unix_session.so.1", "/usr/lib/securit
y/pam_unix_session.so.1", 1023) = 39^M
560: open("/usr/lib/security/pam_unix_session.so.1", O_RDONLY) = 11^M
560: mmap(0x00010000, 4096, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_ALIGN, 11, 0
) = 0xCD560000^M
560: mmap(0x00010000, 73728, PROT_NONE, MAP_PRIVATE|MAP_NORESERVE|MAP_ANON|MA
P_ALIGN, -1, 0) = 0xCD4A0000^M
560: mmap(0xCD4A0000, 2802, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_FIXED|MAP_TE
XT, 11, 0) = 0xCD4A0000^M
560: mmap(0xCD4B1000, 276, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_IN
ITDATA, 11, 4096) = 0xCD4B1000^M
560: munmap(0xCD4A1000, 65536) = 0^M
560: memcntl(0xCD4A0000, 1300, MC_ADVISE, MADV_WILLNEED, 0, 0) = 0^M
560: close(11) = 0^M
560: munmap(0xCD560000, 4096) = 0^M
560: stat64("/usr/lib/security/pam_krb5.so.1", 0x08046930) = 0^M
560: stat64("/usr/lib/security/pam_afs_session.so", 0x08046930) = 0^M
560: xstat(2, "/usr/lib/security/pam_afs_session.so", 0x08046168) = 0^M
560: resolvepath("/usr/lib/security/pam_afs_session.so", "/usr/lib/security/p
am_afs_session.so", 1023) = 36^M
560: open("/usr/lib/security/pam_afs_session.so", O_RDONLY) = 11^M
Here we see the first instance of "pam_krb5.so.1" and it didn't
even read the file. Then soon afterward (100 lines), it
forks off a child that execve's aklog. aklog fails
because /tmp/krb5cc_920 doesn't exist:
690: open("/tmp/krb5cc_920", O_RDONLY) Err#2 ENOENT^M
690: open("/tmp/krb5cc_920", O_RDONLY) Err#2 ENOENT^M
690: fstat64(2, 0x0803FCF0) = 0^M
690: write(2, " a k l o g", 5) = 5^M
690: write(2, " : C o u l d n ' t g".., 15) = 15^M
690: write(2, " c s . u w m . e d u", 10) = 10^M
690: write(2, " A F S t i c k e t s".., 14) = 14^M
Then it forks off Xstartup
560: fork1() = 692^M
692: fork1() (returning as child ...) = 560^M
692: getpid() = 692 [560]^M
...
692: execve("/usr/dt/config/Xstartup", 0x08047B70, 0x080A3710) argc = 2^M
Then it does chown on mouse etc.
Then it forks a process that
698: stat64("/usr/lib/security/pam_authtok_get.so.1", 0x08046DA0) = 0^M
698: stat64("/usr/lib/security/pam_dhkeys.so.1", 0x08046DA0) = 0^M
698: stat64("/usr/lib/security/pam_unix_cred.so.1", 0x08046DA0) = 0^M
698: stat64("/usr/lib/security/pam_krb5.so.1", 0x08046DA0) = 0^M
698: stat64("/usr/lib/security/pam_unix_auth.so.1", 0x08046DA0) = 0^M
...
698: xstat(2, "//.sunw/pkcs11_softtoken/objstore_info", 0x080467F8) = 0^M
698: open("//.sunw/pkcs11_softtoken/objstore_info", O_RDONLY|O_NONBLOCK) = 4^
...
698: open("/tmp/krb5cc_920", O_RDWR|O_CREAT|O_EXCL, 0600) = 4^M
and then it writes the TGT into place. (This is line 3200)
Far too late for aklog to get it.
John