I have an issue regarding kerberos / httpd / RHEL
System 1
This is the problematic system.
OS: RHEL 6.6
Kernel: 2.6.32-431.29.2.el6.x86_64
CPU: Intel Xeon X5570
There is a kerberized website running on the server.
System 2
This system is working with the same kerberos configuration.
OS: RHEL 6.5
Kernel: 2.6.32-431.23.3.el6.x86_64
CPU: Intel Xeon E5-2697
Also running a kerberized website.
Issue
When a user is accessing the website the following messages are shown in the apache error log (LogLevel debug) and the user gets an "Internal Server Error" page:
[Tue Aug 07 11:22:03 2015] [debug] src/mod_auth_kerb.c(1944): [client 10.70.30.50] kerb_authenticate_user entered with user (NULL) and auth_type Kerberos
[Tue Aug 07 11:22:03 2015] [debug] src/mod_auth_kerb.c(1279): [client 10.70.30.50] Acquiring creds for HTTP/app-srv.domain.ch
[Tue Aug 07 11:22:03 2015] [debug] src/mod_auth_kerb.c(1139): [client 10.70.30.50] GSS-API major_status:00020000, minor_status:000186a4
[Tue Aug 07 11:22:03 2015] [error] [client 10.70.30.50] gss_acquire_cred() failed: An invalid name was supplied (, )
This error can be reproduced on System 2 by changing the permissions of /etc/krb5.conf so the user running the apache processes (apache) can not read the file.
The permissions of the /etc/krb5.conf on both systems are set to root:root 644
I am able to cat the file with sudo -u apache cat /etc/krb5.conf.
Debug Info System 1
When debugging with strace (ps h --ppid $(sudo cat /var/run/httpd/httpd.pid) | awk '{print"-p " $1}' | xargs sudo strace -o /tmp/stracehttpd.log) System 1 will produce these results (only showing the snippet where the apache child process is accessing /etc/krb5.conf):
30216 fcntl(13, F_GETFD <unfinished ...>
30214 poll([{fd=14, events=POLLIN}], 1, 60000 <unfinished ...>
30216 <... fcntl resumed> ) = 0
30216 fcntl(13, F_SETFD, FD_CLOEXEC) = 0
30216 getsockname(13, {sa_family=AF_INET6, sin6_port=htons(80), inet_pton(AF_INET6, "::ffff:10.70.30.50", &sin6_addr), sin6_flowinfo=0, sin6_scope_id=0}, [28]) = 0
30216 fcntl(13, F_GETFL) = 0x2 (flags O_RDWR)
30216 fcntl(13, F_SETFL, O_RDWR|O_NONBLOCK) = 0
30216 read(13, "GET /le HTTP/1.1\r\nHost: app-s"..., 8000) = 3519
30216 write(7, "[Tue Aug 11 14:47:03 2015] [debu"..., 155) = 155
30216 write(7, "[Tue Aug 11 14:47:03 2015] [debu"..., 134) = 134
30216 futex(0x7f04b63a00a0, FUTEX_WAKE_PRIVATE, 2147483647) = 0
30216 stat("/etc/gss/mech", 0x7ffff7f3d540) = -1 ENOENT (No such file or directory)
30216 stat("/etc/gss/mech", 0x7ffff7f3d490) = -1 ENOENT (No such file or directory)
30216 stat("/etc/krb5.conf", 0x7ffff7f39090) = -1 EACCES (Permission denied)
30216 stat("/etc/krb5.conf", 0x7ffff7f39090) = -1 EACCES (Permission denied)
30216 stat("/etc/krb5.conf", 0x7ffff7f39090) = -1 EACCES (Permission denied)
30216 stat("/etc/krb5.conf", 0x7ffff7f39090) = -1 EACCES (Permission denied)
30216 stat("/etc/gss/mech", 0x7ffff7f3d350) = -1 ENOENT (No such file or directory)
30216 stat("/etc/gss/mech", 0x7ffff7f3d2a0) = -1 ENOENT (No such file or directory)
30216 stat("/etc/krb5.conf", 0x7ffff7f38db0) = -1 EACCES (Permission denied)
30216 stat("/etc/krb5.conf", 0x7ffff7f38db0) = -1 EACCES (Permission denied)
30216 stat("/etc/krb5.conf", 0x7ffff7f38db0) = -1 EACCES (Permission denied)
30216 stat("/etc/krb5.conf", 0x7ffff7f38db0) = -1 EACCES (Permission denied)
30216 write(7, "[Tue Aug 11 14:47:03 2015] [debu"..., 137) = 137
30216 write(7, "[Tue Aug 11 14:47:03 2015] [erro"..., 118) = 118
30216 writev(13, [{"HTTP/1.1 500 Internal Server Err"..., 160}, {"<!DOCTYPE HTML PUBLIC \"-//IETF//"..., 625}], 2) = 785
30214 <... poll resumed> ) = 1 ([{fd=14, revents=POLLIN}])
30216 write(9, "10.70.30.50 - - [11/Aug/2015:14"..., 242) = 242
30214 read(14, <unfinished ...>
30216 shutdown(13, 1 /* send */) = 0
30214 <... read resumed> "HTTP/1.1 500 Internal Server Err"..., 8000) = 785
30216 poll([{fd=13, events=POLLIN}], 1, 2000 <unfinished ...>
Debug Info System 2
When debugging with strace (ps h --ppid $(sudo cat /var/run/httpd/httpd.pid) | awk '{print"-p " $1}' | xargs sudo strace -o /tmp/stracehttpd.log) System 2 will produce these results (only showing the snippet where the apache child process is accessing /etc/krb5.conf):
6423 <... accept resumed> {sa_family=AF_INET6, sin6_port=htons(51438), inet_pton(AF_INET6, "::1", &sin6_addr), sin6_flowinfo=0, sin6_scope_id=0}, [28]) = 13
6424 read(14, <unfinished ...>
6423 fcntl(13, F_GETFD <unfinished ...>
6424 <... read resumed> 0x7f1ad64e7198, 8000) = -1 EAGAIN (Resource temporarily unavailable)
6423 <... fcntl resumed> ) = 0
6424 poll([{fd=14, events=POLLIN}], 1, 60000 <unfinished ...>
6423 fcntl(13, F_SETFD, FD_CLOEXEC) = 0
6423 getsockname(13, {sa_family=AF_INET6, sin6_port=htons(80), inet_pton(AF_INET6, "::1", &sin6_addr), sin6_flowinfo=0, sin6_scope_id=0}, [28]) = 0
6423 fcntl(13, F_GETFL) = 0x2 (flags O_RDWR)
6423 fcntl(13, F_SETFL, O_RDWR|O_NONBLOCK) = 0
6423 read(13, "GET /le HTTP/1.1\r\nHost: app-srv.dom"..., 8000) = 3082
6423 gettimeofday({1439292761, 106843}, NULL) = 0
6423 gettimeofday({1439292761, 107010}, NULL) = 0
6423 write(7, "[Tue Aug 11 13:32:41 2015] [debu"..., 146) = 146
6423 gettimeofday({1439292761, 107124}, NULL) = 0
6423 write(7, "[Tue Aug 11 13:32:41 2015] [debu"..., 115) = 115
6423 futex(0x7f1aca0ae308, FUTEX_WAKE_PRIVATE, 2147483647) = 0
6423 futex(0x7f1aca0ae290, FUTEX_WAKE_PRIVATE, 2147483647) = 0
6423 futex(0x7f1acaa090a0, FUTEX_WAKE_PRIVATE, 2147483647) = 0
6423 stat("/etc/gss/mech", 0x7fff7298d2e0) = -1 ENOENT (No such file or directory)
6423 stat("/etc/gss/mech", 0x7fff7298d230) = -1 ENOENT (No such file or directory)
6423 futex(0x7f1aca7c52c0, FUTEX_WAKE_PRIVATE, 2147483647) = 0
6423 futex(0x7f1aca7c5750, FUTEX_WAKE_PRIVATE, 2147483647) = 0
6423 gettimeofday({1439292761, 107404}, NULL) = 0
6423 stat("/etc/krb5.conf", {st_mode=S_IFREG|0644, st_size=2294, ...}) = 0
6423 open("/etc/krb5.conf", O_RDONLY) = 14
6423 fcntl(14, F_SETFD, FD_CLOEXEC) = 0
6423 brk(0x7f1ad6504000) = 0x7f1ad6504000
6423 fstat(14, {st_mode=S_IFREG|0644, st_size=2294, ...}) = 0
6423 mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f1ad535d000
6423 read(14, "[logging]\n default = FILE:/var/l"..., 4096) = 2294
6423 read(14, "", 4096) = 0
6423 close(14) = 0
6423 munmap(0x7f1ad535d000, 4096) = 0
6423 gettimeofday({1439292761, 107642}, NULL) = 0
6423 gettimeofday({1439292761, 107663}, NULL) = 0
6423 open("/dev/urandom", O_RDONLY) = 14
6423 fcntl(14, F_SETFD, FD_CLOEXEC) = 0
6423 fstat(14, {st_mode=S_IFCHR|0666, st_rdev=makedev(1, 9), ...}) = 0
6423 read(14, "bh\357\327\333\316\321\327\37\0\215[\37\331\213?o\34\272\246\303].\227\367p\23\225\356\352\272>"..., 64) = 64
6423 close(14) = 0
6423 open("/dev/urandom", O_RDONLY) = 14
6423 fcntl(14, F_SETFD, FD_CLOEXEC) = 0
6423 fstat(14, {st_mode=S_IFCHR|0666, st_rdev=makedev(1, 9), ...}) = 0
6423 read(14, "N\301;|\377'\370\32\214u!%\234\25\21\365\10gi\227\362\273\321\373\324,\321\306*~\323\334"..., 64) = 64
6423 close(14) = 0
6423 futex(0x7f1aca4dd2c0, FUTEX_WAKE_PRIVATE, 2147483647) = 0
6423 gettimeofday({1439292761, 107952}, NULL) = 0
Additional Info
The kerberos configuration is the same on both systems. I also have a Ubuntu 12.04 system running the same kerberos configuration successfully.
I was not able to reproduce the error on System 2 other than denying access to /etc/krb5.conf to the apache user.
