[Freeipa-users] IPA 4.2.0 httpd errors

Mon Feb 22 13:47:41 UTC 2016

On 02/22/16 01:16, Martin Babinsky wrote:
> On 02/19/2016 03:12 PM, Daryl Fonseca-Holt wrote:
>> 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
>>
> Hi Daryl,
>
> it looks like you ran into https://fedorahosted.org/freeipa/ticket/5653
>
Hi Martin,

Thanks for confirming and updating the ticket. Now I can happily use 
retry work-around without wondering if I'm doing it wrong!

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