[Freeipa-users] IPA 4.2.0 httpd errors

Fri Feb 19 14:12:32 UTC 2016

Hello,

Doing a bulk load of 150,000+ users to an IPA 4.2.0 server running 
RedHat Enterprise Linux 7.

Running 25 parallel ipa user-add at once, waiting for completion, then 
starting another 25, and so on.

The httpd error_log is filling with many of these messages (457,189 in 
four days):

[Fri Feb 19 07:41:08.100903 2016] [:error] [pid 76505] [remote 
10.0.1.177:40] mod_wsgi (pid=76505): Exception occurred processing WSGI 
script '/usr/share/ipa/wsgi.py'.
[Fri Feb 19 07:41:08.100989 2016] [:error] [pid 76505] [remote 
10.0.1.177:40] Traceback (most recent call last):
[Fri Feb 19 07:41:08.101018 2016] [:error] [pid 76505] [remote 
10.0.1.177:40]   File "/usr/share/ipa/wsgi.py", line 49, in application
[Fri Feb 19 07:41:08.101073 2016] [:error] [pid 76505] [remote 
10.0.1.177:40]     return api.Backend.wsgi_dispatch(environ, start_response)
[Fri Feb 19 07:41:08.101087 2016] [:error] [pid 76505] [remote 
10.0.1.177:40]   File 
"/usr/lib/python2.7/site-packages/ipaserver/rpcserver.py", line 258, in 
__call__
[Fri Feb 19 07:41:08.101109 2016] [:error] [pid 76505] [remote 
10.0.1.177:40]     return self.route(environ, start_response)
[Fri Feb 19 07:41:08.101120 2016] [:error] [pid 76505] [remote 
10.0.1.177:40]   File 
"/usr/lib/python2.7/site-packages/ipaserver/rpcserver.py", line 270, in 
route
[Fri Feb 19 07:41:08.101140 2016] [:error] [pid 76505] [remote 
10.0.1.177:40]     return app(environ, start_response)
[Fri Feb 19 07:41:08.101152 2016] [:error] [pid 76505] [remote 
10.0.1.177:40]   File 
"/usr/lib/python2.7/site-packages/ipaserver/rpcserver.py", line 447, in 
__call__
[Fri Feb 19 07:41:08.101169 2016] [:error] [pid 76505] [remote 
10.0.1.177:40]     response = super(jsonserver, self).__call__(environ, 
start_response)
[Fri Feb 19 07:41:08.101180 2016] [:error] [pid 76505] [remote 
10.0.1.177:40]   File 
"/usr/lib/python2.7/site-packages/ipaserver/rpcserver.py", line 647, in 
__call__
[Fri Feb 19 07:41:08.101198 2016] [:error] [pid 76505] [remote 
10.0.1.177:40]     'xmlserver', user_ccache, environ, start_response, 
headers)
[Fri Feb 19 07:41:08.101210 2016] [:error] [pid 76505] [remote 
10.0.1.177:40]   File 
"/usr/lib/python2.7/site-packages/ipaserver/rpcserver.py", line 593, in 
finalize_kerberos_acquisition
[Fri Feb 19 07:41:08.101229 2016] [:error] [pid 76505] [remote 
10.0.1.177:40]     session_data['ccache_data'] = 
load_ccache_data(ccache_name)
[Fri Feb 19 07:41:08.101240 2016] [:error] [pid 76505] [remote 
10.0.1.177:40]   File 
"/usr/lib/python2.7/site-packages/ipalib/session.py", line 1231, in 
load_ccache_data
[Fri Feb 19 07:41:08.101259 2016] [:error] [pid 76505] [remote 
10.0.1.177:40]     src = open(name)
[Fri Feb 19 07:41:08.101294 2016] [:error] [pid 76505] [remote 
10.0.1.177:40] IOError: [Errno 2] No such file or directory: 
'/var/run/httpd/ipa/clientcaches/admin at UOFMT1'
[Fri Feb 19 07:41:09.788839 2016] [auth_gssapi:error] [pid 75336] 
[client 10.0.1.177:42610] failed to store delegated creds: [Unspecified 
GSS failure.  Minor code may provide more information (Internal 
credentials cache error)], referer: https://mork.cc.umanitoba.ca/ipa/xml
[Fri Feb 19 07:41:09.788844 2016] [auth_gssapi:error] [pid 78642] 
[client 10.0.1.177:42621] failed to store delegated creds: [Unspecified 
GSS failure.  Minor code may provide more information (Internal 
credentials cache error)], referer: https://mork.cc.umanitoba.ca/ipa/xml
[Fri Feb 19 07:41:09.788961 2016] [auth_gssapi:error] [pid 78643] 
[client 10.0.1.177:42613] failed to store delegated creds: [Unspecified 
GSS failure.  Minor code may provide more information (Internal 
credentials cache error)], referer: https://mork.cc.umanitoba.ca/ipa/xml
[Fri Feb 19 07:41:09.789154 2016] [auth_gssapi:error] [pid 77367] 
[client 10.0.1.177:42615] KRB5CCNAME file 
(/var/run/httpd/ipa/clientcaches/admin at UOFMT1) lookup failed!, referer: 
https://mork.cc.umanitoba.ca/ipa/xml

When the batches are first started there are no errors.
Started batch script at 11:34:54. First error at 12:17:31 after 48 
batches of 25 users.

The 25 users are each added concurrently by separate processes using ipa 
user-add <user> ...
When the script gets the authentication error it simply retries the 
user-add so the user are added anyway.

I think there was a similiar incident, Subject: Client-Install failures 
in January 2016 but the thread seemed to fade away without an answer AFAICT.

Thanks, Daryl

-- 
  --
  Daryl Fonseca-Holt
  IST/CNS/Unix Server Team
  University of Manitoba
  204.480.1079