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@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@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

--
Manage your subscription for the Freeipa-users mailing list:
https://www.redhat.com/mailman/listinfo/freeipa-users
Go to http://freeipa.org for more info on the project

Reply via email to