Description of problem: mod_auth_kerb does not work correctly in FreeIPA deployment on rawhide (Fedora 18). After successful authorization in FreeIPA KDC, our CLI always return an error: # kinit admin Password for admin.BOS.REDHAT.COM: # ipa user-find ipa: ERROR: cannot connect to 'http://master-1.example.com/ipa/xml': Internal Server Error /var/log/httpd/error_log: ... /run/user/apache/[Wed Aug 08 09:32:40.936589 2012] [:error] [pid 2182] ipa: INFO: *** PROCESS START *** [Wed Aug 08 09:46:04.384766 2012] [auth_kerb:error] [pid 2152] [client 192.168.122.115:44461] mkstemp() failed: No such file or directory, referer: https://master-1.example.com/ipa/xml [Wed Aug 08 09:46:04.385811 2012] [auth_kerb:error] [pid 2152] [client 192.168.122.115:44461] Cannot create krb5 ccache (Unknown code A 244), referer: https://master-1.example.com/ipa/xml [Wed Aug 08 09:46:04.390190 2012] [:error] [pid 2147] ipa: ERROR: 500 Internal Server Error: xmlserver.__call__: KRB5CCNAME not defined in HTTP request environment [Wed Aug 08 09:46:04.395161 2012] [core:error] [pid 2152] [client 192.168.122.115:44461] Invalid status line from script 'wsgi.py': Status, referer: https://master-1.example.com/ipa/xml [Wed Aug 08 09:46:04.489927 2012] [core:error] [pid 2152] (104)Connection reset by peer: [client 192.168.122.115:44461] AH00574: ap_content_length_filter: apr_bucket_read() failed, referer: https://master-1.example.com/ipa/xml [Wed Aug 08 09:46:04.522915 2012] [core:notice] [pid 2145] AH00052: child pid 2147 exit signal Segmentation fault (11) [Wed Aug 08 09:46:06.395752 2012] [:error] [pid 2323] ipa: INFO: *** PROCESS START *** After some investigation in the source code, it seems that mod_auth_kerb tries to store the Kerberos cache to /run/user/apache/ (mkstemp template FILE:/run/user/apache/krb5cc_apache_XXXXXX), but this directory does not exist in Fedora 18, maybe the correct directory is /run/httpd/? To workround the issue, I had to do the following: # mkdir /run/user/apache/ # chmod 0700 /run/user/apache/ # chown apache:apache /run/user/apache/ Version-Release number of selected component (if applicable): httpd-2.4.2-23.fc18.x86_64 mod_auth_kerb-5.4-17.fc18.x86_64 freeipa-server-3.0.0-0.3.fc18.x86_64 How reproducible: Steps to Reproduce: 1a. Configure httpd to use mod_auth_kerb and try to access some page secured with Kerberos authentication Alternative steps: 1b. Install freeipa-server package 2b. Run ipa-server-install 3b. kinit admin 4b. Run any CLI command, e.g. ipa user-find Actual results: mod_auth_kerb fails to store Kerberos CCACHE, authentication fails Expected results: authentication succeeds
I see that the %install phase seem to create the tmpfile.d entry and creates the /run/usr/apache directory. But shouldn't the creation of the directory be done during the %post phase ? Also I am not sure apache should own it, it is not a persistent directory, but I'll leave the ownership problem to people with better knowledge than me on packaging guidelines.
Ah, we had a discussion about this, but it looks like I never actually pushed the change, sorry guys. This: http://pkgs.fedoraproject.org/cgit/mod_auth_kerb.git/commit/?id=6546d41e7fd8268f356a05d7f91dd596eb76d619 switches to /run/httpd/krbcache, owned by apache:apache
Can you test this build? http://koji.fedoraproject.org/koji/buildinfo?buildID=346712
Generally, this issue is now gone and I was able to run FreeIPA CLI commands. I just now sometimes experience a hang in httpd service restart executed during IPA installation. I am investigating this issue to check if it is related to this bug.
I did various tests of the httpd, I can experience the hang quite often. I am still not sure if this is caused by mod_auth_kerb, but I am seeing a suspicious pattern in strace of the hanging httpd processes: 6522 stat("/run/httpd/krbcache/krb5cc_apache_aPKQ7Y", {st_mode=S_IFREG|0600, st_size=2174, ...}) = 0 6522 unlink("/run/httpd/krbcache/krb5cc_apache_aPKQ7Y") = 0 ... 6492 open("/run/httpd/krbcache/krb5cc_apache_aPKQ7Y", O_RDWR <unfinished ...> 6492 <... open resumed> ) = -1 ENOENT (No such file or directory) 6492 gettimeofday( <unfinished ...> 6492 <... gettimeofday resumed> {1344587919, 766350}, NULL) = 0 6492 open("/run/httpd/krbcache/krb5cc_apache_aPKQ7Y", O_RDWR <unfinished ...> 6492 <... open resumed> ) = -1 ENOENT (No such file or directory) 6492 gettimeofday( <unfinished ...> 6492 <... gettimeofday resumed> {1344587919, 766969}, NULL) = 0 6492 semop(2359305, {{0, -1, SEM_UNDO}}, 1 <unfinished ...> It looks like that the krb5cc_apache_aPKQ7Y tempfile was removed, but then still referenced and read somewhere in mod_auth_kerb. Is this an expectable behavior? May it be related to the httpd hang? I will attached debug httpd log + the referenced strace.
Created attachment 603462 [details] httpd error log
Created attachment 603463 [details] httpd strace
The cache is only intended to last as long as the client connection, so it should get deleted when the connection is terminated. I'm not sure why it could get re-used.
Exactly. That's why I paid an attention to this and would like to ask you if you could check in the mod_auth_kerb if this is not a bad handling of the cache file name, or some kind of use-after-cleanup misuse.
I wonder how move to the common location and DIR vs FILE cchec type affects this.
It should not. I will thus close this Bugzilla as the issue with invalid directory for CCACHE files is now resolved. I was just curious if Joe would see some specific issue with mod_auth_kerb based on the strace and that would help us fix httpd hangs. We will continue our investigation on F18 and open another Bug when we find the root cause.