Attachment 9691 Details for Bug 47885 – Profiling output

Profiling output

output.txt (text/plain), 19.63 KB, created by Sönke Schwardt-Krummrich on 2018-10-04 18:30:17 CEST

(hide)

Description:

Filename:

MIME Type:

Creator: Sönke Schwardt-Krummrich

Created: 2018-10-04 18:30:17 CEST

Size: 19.63 KB

patch

obsolete

>Connecting as uid=d.krause1,cn=lehrer,cn=users,ou=gsmitte,dc=nstx,dc=local to LDAP...
>Fetching data...
>UAS.User.lookup(<class 'ucsschool.lib.models.user.User'>, lo, school='gsmitte', filter_s='(&(|(lastname=*)(username=*)(firstname=*)))')
>object.lookup(<class 'univention.admin.handlers.users.user.object'>, co, lo, filter_s=(&(&(|(objectClass=ucsschoolTeacher)(objectClass=ucsschoolStaff)(objectClass=ucsschoolStudent))(ucsschoolSchool=gsmitte))(&(|(lastname=*)(username=*)(firstname=*)))))
>UAS.super(User,cls).lookup(lo, school='gsmitte', filter_s='(&(|(lastname=*)(username=*)(firstname=*)))')
>object.lookup(<class 'univention.admin.handlers.users.user.object'>, co, lo, filter_s=(&(|(lastname=*)(username=*)(firstname=*))))
><univention.admin.handlers.users.user.object object at 0x7ff3b1211a10>
>COUNT: 1468
>Trace:
>  File "./uas-lib-profiling.py", line 61, in <module>
>    cProfile.run('main()', 'test1')
>  File "/usr/lib/python2.7/cProfile.py", line 29, in run
>    prof = prof.run(statement)
>  File "/usr/lib/python2.7/cProfile.py", line 135, in run
>    return self.runctx(cmd, dict, dict)
>  File "/usr/lib/python2.7/cProfile.py", line 140, in runctx
>    exec cmd in globals, locals
>  File "<string>", line 1, in <module>
>  File "./uas-lib-profiling.py", line 54, in main
>    testmod.test_me()
>  File "./uas-lib-profiling.py", line 45, in test_me
>    _users = cls.get_all(lo, school, LDAP_Filter.forUsers(pattern))
>  File "/usr/lib/pymodules/python2.7/ucsschool/lib/models/base.py", line 761, in get_all
>    udm_obj.open()
>  File "/usr/lib/pymodules/python2.7/univention/admin/handlers/users/user.py", line 1550, in open
>    self._load_groups(loadGroups)
>  File "/usr/lib/pymodules/python2.7/univention/admin/handlers/users/user.py", line 1558, in _load_groups
>    self['groups'] = self.lo.searchDn(filter=filter_format('(&(cn=*)(|(objectClass=univentionGroup)(objectClass=sambaGroupMapping))(uniqueMember=%s))', [self.dn]))
>  File "/usr/lib/pymodules/python2.7/univention/admin/uldap.py", line 736, in searchDn
>    return self.lo.searchDn(filter, base, scope, unique, required, timeout, sizelimit)
>  File "/usr/lib/pymodules/python2.7/univention/uldap.py", line 335, in searchDn
>    return [x[0] for x in self.search(filter, base, scope, ['dn'], unique, required, timeout, sizelimit, serverctrls)]
>  File "/usr/lib/pymodules/python2.7/univention/uldap.py", line 303, in search
>    trace = ''.join(traceback.format_stack())
>
>
>
>COUNT: 1468
>Trace:
>  File "./uas-lib-profiling.py", line 61, in <module>
>    cProfile.run('main()', 'test1')
>  File "/usr/lib/python2.7/cProfile.py", line 29, in run
>    prof = prof.run(statement)
>  File "/usr/lib/python2.7/cProfile.py", line 135, in run
>    return self.runctx(cmd, dict, dict)
>  File "/usr/lib/python2.7/cProfile.py", line 140, in runctx
>    exec cmd in globals, locals
>  File "<string>", line 1, in <module>
>  File "./uas-lib-profiling.py", line 54, in main
>    testmod.test_me()
>  File "./uas-lib-profiling.py", line 45, in test_me
>    _users = cls.get_all(lo, school, LDAP_Filter.forUsers(pattern))
>  File "/usr/lib/pymodules/python2.7/ucsschool/lib/models/base.py", line 763, in get_all
>    ret.append(cls.from_udm_obj(udm_obj, school, lo))
>  File "/usr/lib/pymodules/python2.7/ucsschool/lib/models/user.py", line 218, in from_udm_obj
>    obj = super(User, cls).from_udm_obj(udm_obj, school, lo)
>  File "/usr/lib/pymodules/python2.7/ucsschool/lib/models/base.py", line 814, in from_udm_obj
>    return klass.from_udm_obj(udm_obj, school, lo)
>  File "/usr/lib/pymodules/python2.7/ucsschool/lib/models/user.py", line 218, in from_udm_obj
>    obj = super(User, cls).from_udm_obj(udm_obj, school, lo)
>  File "/usr/lib/pymodules/python2.7/ucsschool/lib/models/base.py", line 815, in from_udm_obj
>    udm_obj.open()
>  File "/usr/lib/pymodules/python2.7/univention/admin/handlers/users/user.py", line 1550, in open
>    self._load_groups(loadGroups)
>  File "/usr/lib/pymodules/python2.7/univention/admin/handlers/users/user.py", line 1564, in _load_groups
>    primaryGroupResult = self.lo.searchDn(filter=filter_format('(&(cn=*)(|(objectClass=posixGroup)(objectClass=sambaGroupMapping))(gidNumber=%s))', [primaryGroupNumber]))
>  File "/usr/lib/pymodules/python2.7/univention/admin/uldap.py", line 736, in searchDn
>    return self.lo.searchDn(filter, base, scope, unique, required, timeout, sizelimit)
>  File "/usr/lib/pymodules/python2.7/univention/uldap.py", line 335, in searchDn
>    return [x[0] for x in self.search(filter, base, scope, ['dn'], unique, required, timeout, sizelimit, serverctrls)]
>  File "/usr/lib/pymodules/python2.7/univention/uldap.py", line 303, in search
>    trace = ''.join(traceback.format_stack())
>
>
>
>COUNT: 1
>Trace:
>  File "./uas-lib-profiling.py", line 61, in <module>
>    cProfile.run('main()', 'test1')
>  File "/usr/lib/python2.7/cProfile.py", line 29, in run
>    prof = prof.run(statement)
>  File "/usr/lib/python2.7/cProfile.py", line 135, in run
>    return self.runctx(cmd, dict, dict)
>  File "/usr/lib/python2.7/cProfile.py", line 140, in runctx
>    exec cmd in globals, locals
>  File "<string>", line 1, in <module>
>  File "./uas-lib-profiling.py", line 54, in main
>    testmod.test_me()
>  File "./uas-lib-profiling.py", line 45, in test_me
>    _users = cls.get_all(lo, school, LDAP_Filter.forUsers(pattern))
>  File "/usr/lib/pymodules/python2.7/ucsschool/lib/models/base.py", line 746, in get_all
>    cls.init_udm_module(lo)
>  File "/usr/lib/pymodules/python2.7/ucsschool/lib/models/base.py", line 735, in init_udm_module
>    udm_modules.init(lo, pos, udm_modules.get(cls._meta.udm_module))
>  File "/usr/lib/pymodules/python2.7/univention/admin/modules.py", line 136, in init
>    update_extended_attributes(lo, module, position)
>  File "/usr/lib/pymodules/python2.7/univention/admin/modules.py", line 267, in update_extended_attributes
>    for dn, attrs in lo.search(base=position.getDomainConfigBase(), filter=filter_format('(&(objectClass=univentionUDMProperty)(univentionUDMPropertyModule=%s)(univentionUDMPropertyVersion=2))', [name(module)])):
>  File "/usr/lib/pymodules/python2.7/univention/admin/uldap.py", line 696, in search
>    return self.lo.search(filter, base, scope, attr, unique, required, timeout, sizelimit)
>  File "/usr/lib/pymodules/python2.7/univention/uldap.py", line 303, in search
>    trace = ''.join(traceback.format_stack())
>
>
>
>COUNT: 1468
>Trace:
>  File "./uas-lib-profiling.py", line 61, in <module>
>    cProfile.run('main()', 'test1')
>  File "/usr/lib/python2.7/cProfile.py", line 29, in run
>    prof = prof.run(statement)
>  File "/usr/lib/python2.7/cProfile.py", line 135, in run
>    return self.runctx(cmd, dict, dict)
>  File "/usr/lib/python2.7/cProfile.py", line 140, in runctx
>    exec cmd in globals, locals
>  File "<string>", line 1, in <module>
>  File "./uas-lib-profiling.py", line 54, in main
>    testmod.test_me()
>  File "./uas-lib-profiling.py", line 45, in test_me
>    _users = cls.get_all(lo, school, LDAP_Filter.forUsers(pattern))
>  File "/usr/lib/pymodules/python2.7/ucsschool/lib/models/base.py", line 763, in get_all
>    ret.append(cls.from_udm_obj(udm_obj, school, lo))
>  File "/usr/lib/pymodules/python2.7/ucsschool/lib/models/user.py", line 218, in from_udm_obj
>    obj = super(User, cls).from_udm_obj(udm_obj, school, lo)
>  File "/usr/lib/pymodules/python2.7/ucsschool/lib/models/base.py", line 814, in from_udm_obj
>    return klass.from_udm_obj(udm_obj, school, lo)
>  File "/usr/lib/pymodules/python2.7/ucsschool/lib/models/user.py", line 218, in from_udm_obj
>    obj = super(User, cls).from_udm_obj(udm_obj, school, lo)
>  File "/usr/lib/pymodules/python2.7/ucsschool/lib/models/base.py", line 815, in from_udm_obj
>    udm_obj.open()
>  File "/usr/lib/pymodules/python2.7/univention/admin/handlers/users/user.py", line 1550, in open
>    self._load_groups(loadGroups)
>  File "/usr/lib/pymodules/python2.7/univention/admin/handlers/users/user.py", line 1558, in _load_groups
>    self['groups'] = self.lo.searchDn(filter=filter_format('(&(cn=*)(|(objectClass=univentionGroup)(objectClass=sambaGroupMapping))(uniqueMember=%s))', [self.dn]))
>  File "/usr/lib/pymodules/python2.7/univention/admin/uldap.py", line 736, in searchDn
>    return self.lo.searchDn(filter, base, scope, unique, required, timeout, sizelimit)
>  File "/usr/lib/pymodules/python2.7/univention/uldap.py", line 335, in searchDn
>    return [x[0] for x in self.search(filter, base, scope, ['dn'], unique, required, timeout, sizelimit, serverctrls)]
>  File "/usr/lib/pymodules/python2.7/univention/uldap.py", line 303, in search
>    trace = ''.join(traceback.format_stack())
>
>
>
>COUNT: 1
>Trace:
>  File "./uas-lib-profiling.py", line 61, in <module>
>    cProfile.run('main()', 'test1')
>  File "/usr/lib/python2.7/cProfile.py", line 29, in run
>    prof = prof.run(statement)
>  File "/usr/lib/python2.7/cProfile.py", line 135, in run
>    return self.runctx(cmd, dict, dict)
>  File "/usr/lib/python2.7/cProfile.py", line 140, in runctx
>    exec cmd in globals, locals
>  File "<string>", line 1, in <module>
>  File "./uas-lib-profiling.py", line 54, in main
>    testmod.test_me()
>  File "./uas-lib-profiling.py", line 45, in test_me
>    _users = cls.get_all(lo, school, LDAP_Filter.forUsers(pattern))
>  File "/usr/lib/pymodules/python2.7/ucsschool/lib/models/base.py", line 760, in get_all
>    for udm_obj in cls.lookup(lo, school, complete_filter, superordinate=superordinate):
>  File "/usr/lib/pymodules/python2.7/ucsschool/lib/models/user.py", line 561, in lookup
>    objects = udm_modules.lookup(cls._meta.udm_module, None, lo, filter=unicode(filter_object_type), scope='sub', superordinate=superordinate)
>  File "/usr/lib/pymodules/python2.7/univention/admin/modules.py", line 732, in lookup
>    tmpres = module.lookup(co, lo, filter, base=base, superordinate=superordinate, scope=scope, unique=unique, required=required, timeout=timeout, sizelimit=sizelimit)
>  File "/usr/lib/pymodules/python2.7/univention/admin/handlers/__init__.py", line 1566, in lookup
>    for dn, attrs in lo.search(filter_str, base, scope, attr, unique, required, timeout, sizelimit):
>  File "/usr/lib/pymodules/python2.7/univention/admin/uldap.py", line 696, in search
>    return self.lo.search(filter, base, scope, attr, unique, required, timeout, sizelimit)
>  File "/usr/lib/pymodules/python2.7/univention/uldap.py", line 303, in search
>    trace = ''.join(traceback.format_stack())
>
>
>
>COUNT: 1
>Trace:
>  File "./uas-lib-profiling.py", line 61, in <module>
>    cProfile.run('main()', 'test1')
>  File "/usr/lib/python2.7/cProfile.py", line 29, in run
>    prof = prof.run(statement)
>  File "/usr/lib/python2.7/cProfile.py", line 135, in run
>    return self.runctx(cmd, dict, dict)
>  File "/usr/lib/python2.7/cProfile.py", line 140, in runctx
>    exec cmd in globals, locals
>  File "<string>", line 1, in <module>
>  File "./uas-lib-profiling.py", line 54, in main
>    testmod.test_me()
>  File "./uas-lib-profiling.py", line 45, in test_me
>    _users = cls.get_all(lo, school, LDAP_Filter.forUsers(pattern))
>  File "/usr/lib/pymodules/python2.7/ucsschool/lib/models/base.py", line 760, in get_all
>    for udm_obj in cls.lookup(lo, school, complete_filter, superordinate=superordinate):
>  File "/usr/lib/pymodules/python2.7/ucsschool/lib/models/user.py", line 563, in lookup
>    objects.extend(obj for obj in super(User, cls).lookup(lo, school, filter_s, superordinate=superordinate) if not any(obj.dn == x.dn for x in objects))
>  File "/usr/lib/pymodules/python2.7/ucsschool/lib/models/base.py", line 771, in lookup
>    return udm_modules.lookup(cls._meta.udm_module, None, lo, filter=filter_s, base=cls.get_container(school), scope='sub', superordinate=superordinate)
>  File "/usr/lib/pymodules/python2.7/univention/admin/modules.py", line 732, in lookup
>    tmpres = module.lookup(co, lo, filter, base=base, superordinate=superordinate, scope=scope, unique=unique, required=required, timeout=timeout, sizelimit=sizelimit)
>  File "/usr/lib/pymodules/python2.7/univention/admin/handlers/__init__.py", line 1566, in lookup
>    for dn, attrs in lo.search(filter_str, base, scope, attr, unique, required, timeout, sizelimit):
>  File "/usr/lib/pymodules/python2.7/univention/admin/uldap.py", line 696, in search
>    return self.lo.search(filter, base, scope, attr, unique, required, timeout, sizelimit)
>  File "/usr/lib/pymodules/python2.7/univention/uldap.py", line 303, in search
>    trace = ''.join(traceback.format_stack())
>
>
>
>COUNT: 1
>Trace:
>  File "./uas-lib-profiling.py", line 61, in <module>
>    cProfile.run('main()', 'test1')
>  File "/usr/lib/python2.7/cProfile.py", line 29, in run
>    prof = prof.run(statement)
>  File "/usr/lib/python2.7/cProfile.py", line 135, in run
>    return self.runctx(cmd, dict, dict)
>  File "/usr/lib/python2.7/cProfile.py", line 140, in runctx
>    exec cmd in globals, locals
>  File "<string>", line 1, in <module>
>  File "./uas-lib-profiling.py", line 54, in main
>    testmod.test_me()
>  File "./uas-lib-profiling.py", line 45, in test_me
>    _users = cls.get_all(lo, school, LDAP_Filter.forUsers(pattern))
>  File "/usr/lib/pymodules/python2.7/ucsschool/lib/models/base.py", line 746, in get_all
>    cls.init_udm_module(lo)
>  File "/usr/lib/pymodules/python2.7/ucsschool/lib/models/base.py", line 735, in init_udm_module
>    udm_modules.init(lo, pos, udm_modules.get(cls._meta.udm_module))
>  File "/usr/lib/pymodules/python2.7/univention/admin/modules.py", line 135, in init
>    update_extended_options(lo, module, position)
>  File "/usr/lib/pymodules/python2.7/univention/admin/modules.py", line 202, in update_extended_options
>    for dn, attrs in lo.search(base=position.getDomainConfigBase(), filter=filter_format('(&(objectClass=univentionUDMOption)(univentionUDMOptionModule=%s))', [name(module)])):
>  File "/usr/lib/pymodules/python2.7/univention/admin/uldap.py", line 696, in search
>    return self.lo.search(filter, base, scope, attr, unique, required, timeout, sizelimit)
>  File "/usr/lib/pymodules/python2.7/univention/uldap.py", line 303, in search
>    trace = ''.join(traceback.format_stack())
>
>
>
>COUNT: 1468
>Trace:
>  File "./uas-lib-profiling.py", line 61, in <module>
>    cProfile.run('main()', 'test1')
>  File "/usr/lib/python2.7/cProfile.py", line 29, in run
>    prof = prof.run(statement)
>  File "/usr/lib/python2.7/cProfile.py", line 135, in run
>    return self.runctx(cmd, dict, dict)
>  File "/usr/lib/python2.7/cProfile.py", line 140, in runctx
>    exec cmd in globals, locals
>  File "<string>", line 1, in <module>
>  File "./uas-lib-profiling.py", line 54, in main
>    testmod.test_me()
>  File "./uas-lib-profiling.py", line 45, in test_me
>    _users = cls.get_all(lo, school, LDAP_Filter.forUsers(pattern))
>  File "/usr/lib/pymodules/python2.7/ucsschool/lib/models/base.py", line 761, in get_all
>    udm_obj.open()
>  File "/usr/lib/pymodules/python2.7/univention/admin/handlers/users/user.py", line 1550, in open
>    self._load_groups(loadGroups)
>  File "/usr/lib/pymodules/python2.7/univention/admin/handlers/users/user.py", line 1564, in _load_groups
>    primaryGroupResult = self.lo.searchDn(filter=filter_format('(&(cn=*)(|(objectClass=posixGroup)(objectClass=sambaGroupMapping))(gidNumber=%s))', [primaryGroupNumber]))
>  File "/usr/lib/pymodules/python2.7/univention/admin/uldap.py", line 736, in searchDn
>    return self.lo.searchDn(filter, base, scope, unique, required, timeout, sizelimit)
>  File "/usr/lib/pymodules/python2.7/univention/uldap.py", line 335, in searchDn
>    return [x[0] for x in self.search(filter, base, scope, ['dn'], unique, required, timeout, sizelimit, serverctrls)]
>  File "/usr/lib/pymodules/python2.7/univention/uldap.py", line 303, in search
>    trace = ''.join(traceback.format_stack())
>
>
>
>Fri Aug 31 15:16:04 2018    test1
>
>         8507541 function calls (7862828 primitive calls) in 35.494 seconds
>
>   Ordered by: cumulative time
>   List reduced from 357 to 20 due to restriction <20>
>
>   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
>        1    0.000    0.000   35.694   35.694 <string>:1(<module>)
>        1    0.032    0.032   35.694   35.694 ./uas-lib-profiling.py:52(main)
>        1    0.000    0.000   35.662   35.662 ./uas-lib-profiling.py:38(test_me)
>        1    0.004    0.004   35.646   35.646 /usr/lib/pymodules/python2.7/ucsschool/lib/models/base.py:738(get_all)
>     5876    0.073    0.000   31.962    0.005 /usr/lib/pymodules/python2.7/univention/uldap.py:300(search)
>     5876    0.012    0.000   31.148    0.005 /usr/lib/python2.7/dist-packages/ldap/ldapobject.py:992(search_ext_s)
>     5878    0.014    0.000   31.143    0.005 /usr/lib/python2.7/dist-packages/ldap/ldapobject.py:927(_apply_method_s)
>     5876    0.013    0.000   31.121    0.005 /usr/lib/python2.7/dist-packages/ldap/ldapobject.py:589(search_ext_s)
>    11756    0.046    0.000   31.049    0.003 /usr/lib/python2.7/dist-packages/ldap/ldapobject.py:87(_ldap_call)
>     5876    0.005    0.000   30.861    0.005 /usr/lib/python2.7/dist-packages/ldap/ldapobject.py:452(result)
>     5876    0.005    0.000   30.856    0.005 /usr/lib/python2.7/dist-packages/ldap/ldapobject.py:506(result2)
>     5877    0.008    0.000   30.851    0.005 /usr/lib/python2.7/dist-packages/ldap/ldapobject.py:510(result3)
>     5877    0.021    0.000   30.843    0.005 /usr/lib/python2.7/dist-packages/ldap/ldapobject.py:518(result4)
>     5877   30.771    0.005   30.771    0.005 {built-in method result4}
>        1    0.000    0.000   27.094   27.094 /usr/lib/pymodules/python2.7/ucsschool/lib/models/user.py:555(lookup)
>        2    0.000    0.000   26.782   13.391 /usr/lib/pymodules/python2.7/univention/admin/modules.py:726(lookup)
>        2    0.008    0.004   26.782   13.391 /usr/lib/pymodules/python2.7/univention/admin/handlers/__init__.py:1544(lookup)
>        4    0.000    0.000   25.601    6.400 /usr/lib/pymodules/python2.7/univention/admin/uldap.py:672(search)
>        1    0.000    0.000   12.120   12.120 /usr/lib/pymodules/python2.7/ucsschool/lib/models/base.py:768(lookup)
>     2936    0.020    0.000    7.908    0.003 /usr/lib/pymodules/python2.7/univention/admin/handlers/users/user.py:1542(open)
>
>
>Fri Aug 31 15:16:04 2018    test1
>
>         8507541 function calls (7862828 primitive calls) in 35.494 seconds
>
>   Ordered by: internal time
>   List reduced from 357 to 20 due to restriction <20>
>
>   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
>     5877   30.771    0.005   30.771    0.005 {built-in method result4}
>669421/27893    0.759    0.000    1.606    0.000 /usr/lib/python2.7/copy.py:145(deepcopy)
>   634781    0.301    0.000    0.393    0.000 /usr/lib/python2.7/copy.py:267(_keep_alive)
>     5876    0.192    0.000    0.192    0.000 {built-in method search_ext}
>10354/10277    0.173    0.000    1.455    0.000 /usr/lib/python2.7/copy.py:253(_deepcopy_dict)
>     5876    0.163    0.000    0.536    0.000 /usr/lib/python2.7/traceback.py:281(extract_stack)
>    82258    0.158    0.000    0.158    0.000 {posix.stat}
>     8808    0.154    0.000    0.225    0.000 /usr/lib/pymodules/python2.7/univention/admin/handlers/__init__.py:353(__setitem__)
>  1485446    0.147    0.000    0.147    0.000 {method 'get' of 'dict' objects}
>     5876    0.107    0.000    0.121    0.000 /usr/lib/python2.7/traceback.py:27(format_list)
>     2936    0.104    0.000    0.260    0.000 /usr/lib/pymodules/python2.7/univention/admin/mapping.py:360(mapDict)
>     5880    0.097    0.000    0.301    0.000 {any}
>    48814    0.088    0.000    0.139    0.000 /usr/lib/python2.7/dist-packages/ldap/dn.py:20(escape_dn_chars)
>   897932    0.088    0.000    0.088    0.000 {method 'append' of 'list' objects}
>  1401204    0.084    0.000    0.084    0.000 {id}
>    88133    0.083    0.000    0.241    0.000 /usr/lib/python2.7/linecache.py:47(checkcache)
>     5876    0.073    0.000   31.962    0.005 /usr/lib/pymodules/python2.7/univention/uldap.py:300(search)
>    15152    0.070    0.000    0.070    0.000 {str2dn}
>     8808    0.060    0.000    1.575    0.000 /usr/lib/pymodules/python2.7/univention/admin/handlers/__init__.py:237(save)
>    58678    0.059    0.000    0.214    0.000 /usr/lib/python2.7/copy.py:226(_deepcopy_list)
>
>

Actions: View

Attachments on bug 47885: 9691 | 9692