[Freeipa-users] IPA 4.2.0 httpd errors

[Martin Babinsky]

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

-- 
Martin^3 Babinsky