Description of problem:

Our client has a problem with IPA

An error TimeLimitExceeded sometimes reveals while calling IPA JSON API
(/ipa/session/json). Api calls this error. User who calls JSON API is a user
with login czechidm and it has in ds389 unlimited limits for these actions:

dn: uid=czechidm,cn=users,cn=accounts,dc=internal,dc=services
changetype: modify
add: nsIdleTimeout
nsIdleTimeout: -1
-
add: nsLookThroughLimit
nsLookThroughLimit: -1
-
add: nsSizeLimit
nsSizeLimit: -1
-
add: nsTimeLimit
nsTimeLimit: -1

Although it has unlimmited limits sometimes this error reveals in LDAP log. We
are still not able to replicate this error but it reveals regularly with small
changes as a lock of account. There is similar bug in this bugreport but not
the same: https://bugzilla.redhat.com/show_bug.cgi?id=1183655#c37

API in error_log reports an error:

/var/log/httpd/error_log-20171001:[Fri Sep 29 11:13:47.875903 2017] [:error]
[pid 5576] ipa: INFO: [jsonserver_session] czechidm@INTERNAL.SERVICES:
user_find(u'sb70854', uid=u'sb70854', timelimit=20, sizelimit=99999, all=True,
version=u'2.156'): TimeLimitExceeded
/var/log/httpd/error_log-20171015:[Wed Oct 11 10:39:15.167196 2017] [:error]
[pid 25658] ipa: INFO: [jsonserver_session] czechidm@INTERNAL.SERVICES:
user_find(None, uid=u'mcervinkova', timelimit=20, sizelimit=99999, all=True,
version=u'2.156'): TimeLimitExceeded
/var/log/httpd/error_log-20171015:[Wed Oct 11 10:57:57.864386 2017] [:error]
[pid 18378] ipa: INFO: [jsonserver_session] czechidm@INTERNAL.SERVICES:
user_find(u'mdlabacek', uid=u'mdlabacek', timelimit=20, sizelimit=99999,
all=True, version=u'2.156'): TimeLimitExceeded
/var/log/httpd/error_log-20171015:[Wed Oct 11 11:01:00.321893 2017] [:error]
[pid 18369] ipa: INFO: [jsonserver_session] czechidm@INTERNAL.SERVICES:
user_find(None, uid=u'jhyrsova', timelimit=20, sizelimit=99999, all=True,
version=u'2.156'): TimeLimitExceeded
/var/log/httpd/error_log-20171015:[Wed Oct 11 11:01:05.830512 2017] [:error]
[pid 18369] ipa: INFO: [jsonserver_session] czechidm@INTERNAL.SERVICES:
user_find(u'mmatys', uid=u'mmatys', timelimit=20, sizelimit=99999, all=True,
version=u'2.156'): TimeLimitExceeded
/var/log/httpd/error_log-20171015:[Wed Oct 11 12:19:32.850074 2017] [:error]
[pid 30538] ipa: INFO: [jsonserver_session] czechidm@INTERNAL.SERVICES:
group_remove_member(u'ipausers', version=u'2.156', user=u'amichejdova1'):
TimeLimitExceeded
/var/log/httpd/error_log-20171015:[Wed Oct 11 13:04:55.105700 2017] [:error]
[pid 4312] ipa: INFO: [jsonserver_session] czechidm@INTERNAL.SERVICES:
user_find(u'tvasutova', uid=u'tvasutova', timelimit=20, sizelimit=99999,
all=True, version=u'2.156'): TimeLimitExceeded
/var/log/httpd/error_log-20171015:[Wed Oct 11 13:15:27.058749 2017] [:error]
[pid 4082] ipa: INFO: [jsonserver_session] czechidm@INTERNAL.SERVICES:
user_mod(u'mprudicova', nsaccountlock=True, version=u'2.156'):
TimeLimitExceeded
/var/log/httpd/error_log-20171015:[Wed Oct 11 13:22:53.496045 2017] [:error]
[pid 6426] ipa: INFO: [jsonserver_session] czechidm@INTERNAL.SERVICES:
user_find(None, uid=u'zjedlicka', timelimit=20, sizelimit=99999, all=True,
version=u'2.156'): TimeLimitExceeded
/var/log/httpd/error_log-20171015:[Wed Oct 11 14:08:12.039000 2017] [:error]
[pid 12048] ipa: INFO: [jsonserver_session] czechidm@INTERNAL.SERVICES:
user_find(u'msimandl', uid=u'msimandl', timelimit=20, sizelimit=99999,
all=True, version=u'2.156'): TimeLimitExceeded

In the log ds389 is displayed timeout exceeded in the same time while finding
configuration:

[root@ipa-tst-01 ~]# grep conn=328394
/var/log/dirsrv/slapd-INTERNAL-SERVICES/access*
/var/log/dirsrv/slapd-INTERNAL-SERVICES/access.20171010-135042:[11/Oct/2017:13:
15:22.596890581 +0200] conn=328394 fd=152 slot=152 connection from 10.14.145.24
to 10.14.145.24
/var/log/dirsrv/slapd-INTERNAL-SERVICES/access.20171010-135042:[11/Oct/2017:13:
15:22.599036063 +0200] conn=328394 op=0 BIND dn="" method=sasl version=3
mech=GSS-SPNEGO
/var/log/dirsrv/slapd-INTERNAL-SERVICES/access.20171010-135042:[11/Oct/2017:13:
15:22.609078500 +0200] conn=328394 op=0 RESULT err=0 tag=97 nentries=0 etime=0
dn="uid=czechidm,cn=users,cn=accounts,dc=internal,dc=services"
/var/log/dirsrv/slapd-INTERNAL-SERVICES/access.20171010-135042:[11/Oct/2017:13:
15:22.611625173 +0200] conn=328394 op=1 SRCH
base="cn=ipaconfig,cn=etc,dc=internal,dc=services" scope=0
filter="(objectClass=*)" attrs=ALL
/var/log/dirsrv/slapd-INTERNAL-SERVICES/access.20171010-135042:[11/Oct/2017:13:
15:27.058009572 +0200] conn=328394 op=1 RESULT err=3 tag=101 nentries=0 etime=5
/var/log/dirsrv/slapd-INTERNAL-SERVICES/access.20171010-135042:[11/Oct/2017:13:
15:27.059213798 +0200] conn=328394 op=2 UNBIND
/var/log/dirsrv/slapd-INTERNAL-SERVICES/access.20171010-135042:[11/Oct/2017:13:
15:27.059230063 +0200] conn=328394 op=2 fd=152 closed - U1

After turning on debug mode IPA there can be found that problem is in the
method get_ipa_config:

[Fri Sep 29 11:00:01.140338 2017] [:error] [pid 5576] ipa: DEBUG: WSGI
wsgi_execute PublicError: Traceback (most recent call last):
[Fri Sep 29 11:00:01.140370 2017] [:error] [pid 5576] File
"/usr/lib/python2.7/site-packages/ipaserver/rpcserver.py", line 366, in
wsgi_execute
[Fri Sep 29 11:00:01.140377 2017] [:error] [pid 5576] result = command(*args,
**options)
[Fri Sep 29 11:00:01.140382 2017] [:error] [pid 5576] File
"/usr/lib/python2.7/site-packages/ipalib/frontend.py", line 449, in _call_
[Fri Sep 29 11:00:01.140387 2017] [:error] [pid 5576] return
self.__do_call(*args, **options)
[Fri Sep 29 11:00:01.140401 2017] [:error] [pid 5576] File
"/usr/lib/python2.7/site-packages/ipalib/frontend.py", line 477, in __do_call
[Fri Sep 29 11:00:01.140406 2017] [:error] [pid 5576] ret = self.run(*args,
**options)
[Fri Sep 29 11:00:01.140411 2017] [:error] [pid 5576] File
"/usr/lib/python2.7/site-packages/ipalib/frontend.py", line 799, in run
[Fri Sep 29 11:00:01.140416 2017] [:error] [pid 5576] return
self.execute(*args, **options)
[Fri Sep 29 11:00:01.140421 2017] [:error] [pid 5576] File
"/usr/lib/python2.7/site-packages/ipaserver/plugins/baseldap.py", line 1989, in
execute
[Fri Sep 29 11:00:01.140426 2017] [:error] [pid 5576] config =
ldap.get_ipa_config()
[Fri Sep 29 11:00:01.140431 2017] [:error] [pid 5576] File
"/usr/lib/python2.7/site-packages/ipaserver/plugins/ldap2.py", line 242, in
get_ipa_config
[Fri Sep 29 11:00:01.140435 2017] [:error] [pid 5576]
self.handle_truncated_result(truncated)
[Fri Sep 29 11:00:01.140440 2017] [:error] [pid 5576] File
"/usr/lib/python2.7/site-packages/ipapython/ipaldap.py", line 1028, in
handle_truncated_result
[Fri Sep 29 11:00:01.140445 2017] [:error] [pid 5576] raise
errors.TimeLimitExceeded()
[Fri Sep 29 11:00:01.140450 2017] [:error] [pid 5576] TimeLimitExceeded:
Configured time limit exceeded
[Fri Sep 29 11:00:01.140455 2017] [:error] [pid 5576]

If we look at the code on the method get_ipa_config there is obvious that there
is hardcoded timeout and sizelimit(and it is the cause in our opinion):

try:

    use find_entries here lest we hit an infinite recursion when
    ldap2.get_entries tries to determine default time/size limits
    (entries, truncated) = self.find_entries(
    None, attrs_list, base_dn=dn, scope=self.SCOPE_BASE,
    time_limit=2, size_limit=10
    )
    self.handle_truncated_result(truncated)
    config_entry = entries[0]


Version-Release number of selected component (if applicable):

[root@ipa-tst-01 ~]# rpm -qa | grep ipa && cat /etc/*release
ipa-client-common-4.5.0-20.el7.noarch
python-ipaddress-1.0.16-2.el7.noarch
python2-ipalib-4.5.0-20.el7.noarch
ipa-common-4.5.0-20.el7.noarch
sssd-ipa-1.15.2-50.el7.x86_64
ipa-server-common-4.5.0-20.el7.noarch
ipa-client-4.5.0-20.el7.x86_64
ipa-server-dns-4.5.0-20.el7.noarch
python-libipa_hbac-1.15.2-50.el7.x86_64
python2-ipaserver-4.5.0-20.el7.noarch
ipa-server-4.5.0-20.el7.x86_64
libipa_hbac-1.15.2-50.el7.x86_64
python2-ipaclient-4.5.0-20.el7.noarch
python-iniparse-0.4-9.el7.noarch
NAME="Red Hat Enterprise Linux Server"
VERSION="7.4 (Maipo)"
ID="rhel"
ID_LIKE="fedora"
VARIANT="Server"
VARIANT_ID="server"
VERSION_ID="7.4"
PRETTY_NAME="Red Hat Enterprise Linux Server 7.4 (Maipo)"
ANSI_COLOR="0;31"
CPE_NAME="cpe:/o:redhat:enterprise_linux:7.4:GA:server"
HOME_URL="https://www.redhat.com/"
BUG_REPORT_URL="https://bugzilla.redhat.com/"

REDHAT_BUGZILLA_PRODUCT="Red Hat Enterprise Linux 7"
REDHAT_BUGZILLA_PRODUCT_VERSION=7.4
REDHAT_SUPPORT_PRODUCT="Red Hat Enterprise Linux"
REDHAT_SUPPORT_PRODUCT_VERSION="7.4"
Red Hat Enterprise Linux Server release 7.4 (Maipo)
Red Hat Enterprise Linux Server release 7.4 (Maipo)


How reproducible:


Steps to Reproduce:
1.
2.
3.

Actual results:

TimeLimitExceeded

Expected results:

We need this bug to be fixed in future freeipa/ipa versions

Additional info:

Our workaround:
We have tried on test environment to rewrite hardcoded timelimit from 2 to 20.
The error stopped to appear.