RHEL Engineering is moving the tracking of its product development work on RHEL 6 through RHEL 9 to Red Hat Jira (issues.redhat.com). If you're a Red Hat customer, please continue to file support cases via the Red Hat customer portal. If you're not, please head to the "RHEL project" in Red Hat Jira and file new tickets here. Individual Bugzilla bugs in the statuses "NEW", "ASSIGNED", and "POST" are being migrated throughout September 2023. Bugs of Red Hat partners with an assigned Engineering Partner Manager (EPM) are migrated in late September as per pre-agreed dates. Bugs against components "kernel", "kernel-rt", and "kpatch" are only migrated if still in "NEW" or "ASSIGNED". If you cannot log in to RH Jira, please consult article #7032570. That failing, please send an e-mail to the RH Jira admins at rh-issues@redhat.com to troubleshoot your issue as a user management inquiry. The email creates a ServiceNow ticket with Red Hat. Individual Bugzilla bugs that are migrated will be moved to status "CLOSED", resolution "MIGRATED", and set with "MigratedToJIRA" in "Keywords". The link to the successor Jira issue will be found under "Links", have a little "two-footprint" icon next to it, and direct you to the "RHEL project" in Red Hat Jira (issue links are of type "https://issues.redhat.com/browse/RHEL-XXXX", where "X" is a digit). This same link will be available in a blue banner at the top of the page informing you that that bug has been migrated.
Bug 1653098 - Performance test fails due to high sssd_nss memory consumption
Summary: Performance test fails due to high sssd_nss memory consumption
Keywords:
Status: CLOSED NOTABUG
Alias: None
Product: Red Hat Enterprise Linux 8
Classification: Red Hat
Component: sssd
Version: 8.0
Hardware: Unspecified
OS: Unspecified
unspecified
high
Target Milestone: rc
: 8.0
Assignee: Alexey Tikhonov
QA Contact: sssd-qe
URL:
Whiteboard:
Depends On: 1682305
Blocks:
TreeView+ depends on / blocked
 
Reported: 2018-11-25 18:17 UTC by Amith
Modified: 2019-10-02 10:16 UTC (History)
11 users (show)

Fixed In Version:
Doc Type: If docs needed, set a value
Doc Text:
Clone Of:
Environment:
Last Closed: 2019-04-30 15:33:02 UTC
Type: Bug
Target Upstream Version:
Embargoed:

Attachments (Terms of Use)
IDLE SSSD NSS TALLOC REPORT (66.70 KB, text/plain)
2018-11-28 14:27 UTC, Amith 		no flags Details
First sssd nss talloc report (86.08 KB, text/plain)
2018-11-28 14:30 UTC, Amith 		no flags Details
Second SSSD NSS TALLOC REPORT (6.68 MB, text/plain)
2018-11-28 14:33 UTC, Amith 		no flags Details
Third SSSD NSS TALLOC REPORT (14.05 MB, text/plain)
2018-11-28 14:37 UTC, Amith 		no flags Details
Valgrind log file. (164.79 KB, text/plain)
2018-12-03 16:43 UTC, Amith 		no flags Details
View All

Description Amith 2018-11-25 18:17:40 UTC 
Description of problem:
We have automated test for bug 889182 and bug 888800. This test case fails due to high consumption of sssd_nss memory. Steps followed during investigation:

1) Configure sssd.conf as given below:

[sssd]
config_file_version = 2
services = nss, pam
domains = LDAP

[nss]
filter_groups = root
filter_users = root

[pam]

[domain/LDAP]
debug_level = 0xFFF0
id_provider = ldap
ldap_uri = ldap://SERVER
ldap_tls_cacert = /etc/openldap/certs/cacert.asc
ldap_schema = rfc2307bis

2) Setup a large group with over 5000 users. 

3) Capture the initial memory usage by running a group lookup.
# getent group bulkgroup2
# pid_nss=`pidof sssd_nss`
# nss_mem1=`cat /proc/$pid_nss/status | grep VmRSS: | cut -d" " -f4`

NOTE: Initial sssd_nss memory usage is 38296 (38 MB)

3) In a loop, run user lookup for first set of 1000 users. Then, capture the memory usage.

for ((i=1002 ; i<=2000 ; i++)) 
do "id puser1$i"; done

# cat /proc/$pid_nss/status | grep Vm
VmPeak:	  223180 kB
VmSize:	  223180 kB
VmLck:	       0 kB
VmPin:	       0 kB
VmHWM:	   53204 kB
VmRSS:	   53204 kB
VmData:	   11008 kB
VmStk:	     132 kB
VmExe:	     248 kB
VmLib:	   15244 kB
VmPTE:	     452 kB
VmSwap:	       0 kB

NOTE: sssd_nss memory usage is now 53204 (53 MB), consumption increased by almost 15 MB.

4) Repeat step-3 for the next 4 sets of 1000 user and watch sssd_nss memory growth.

SSSD_NSS MEMORY USAGE STATISTICS:
-----------------------------------
Initial group lookup memory usage = 38296 (38 MB)
After first set of 1000 users lookup = 53204 (53 MB)
After second set of 1000 users lookup = 68024 (68 MB)
After third set of 1000 users lookup = 82776 (82 MB)
After fourth set of 1000 users lookup = 96856 (96 MB)

Note: Fifth set of 1000 users lookup shows a memory decline to O KB usage.
For reference, see beaker job - https://beaker.engineering.redhat.com/jobs/3128319 , https://beaker.engineering.redhat.com/jobs/3128224

The sssd_nss memory shows a growth of 58 MB by the end of test. We have not seen such difference in the past RHEL releases. Looks like a bug to me, but if it is not a regression then we need to set some benchmarks to avoid such failures in future. We need to define acceptable limits in terms of memory usages. 

To avoid such failures, we started scheduling better hardware in beaker jobs. SSSD CLIENT under test has the following h/w configurations:

Vendor       IBM KVM Guest
MAC Address 	52:54:01:4c:e1:2e
Memory 	     16384 MB
NUMA Nodes   1
CPU Vendor   GenuineIntel
Model Name   QEMU Virtual CPU version (cpu64-rhel6)
Family  	6
Model 	     13
Speed 	     2000.0
Processors   4
Cores 	     4


Version-Release number of selected component (if applicable):
sssd-2.0.0-23.el8.x86_64.rpm

How reproducible:
Always.
See beaker job --https://beaker.engineering.redhat.com/jobs/3128319
Comment 1 Pavel Březina 2018-11-26 11:33:29 UTC 
Could you please reproduce the test and attach talloc report please?

It looks like a memory leak. Talloc report will be really helpful to pinpoint the location. I have this [1] script that can be used to obtain talloc report if you need any help with it.

[1] https://github.com/pbrezina/sssd-dev-utils/blob/master/sss-utils.sh#L141
Comment 2 Amith 2018-11-28 14:26:07 UTC 
I didn't know that execution of sss-talloc-report script would require a number of installed debuginfo rpms. It took me sometime to fix the gdb failures and finally generate few reports, some of them are pretty large in size. I have attached them, also with an IDLE sssd_nss report. Anyways while reproducing the issue, i also observed an sssd_nss crash. Details are given below:

---------------------------------------------------------------

time:           Wed 28 Nov 2018 07:57:44 AM EST
package:        sssd-common-2.0.0-23.el8
reason:         sssd_nss killed by SIGABRT
crash_function: _talloc_realloc
cmdline:        /usr/libexec/sssd/sssd_nss --uid 0 --gid 0 --logger=files
executable:     /usr/libexec/sssd/sssd_nss
component:      sssd
uid:            0
username:       root
hostname:       kvm-03-guest16.rhts.eng.bos.redhat.com
os_release:     Red Hat Enterprise Linux release 8.0 Beta (Ootpa)
architecture:   x86_64
pwd:            /
kernel:         4.18.0-45.el8.x86_64
abrt_version:   2.10.9

Reports:

Reporting to FAF server exited with 1


Full Backtrace:
[New LWP 16831]
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib64/libthread_db.so.1".
Core was generated by `/usr/libexec/sssd/sssd_nss --uid 0 --gid 0 --logger=files'.
Program terminated with signal SIGABRT, Aborted.
#0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
50	  return ret;

Thread 1 (Thread 0x7f2b95bf5d80 (LWP 16831)):
#0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
        set = {__val = {6786, 767960, 206158430232, 140733775742528, 2339179437807134039, 3977868379580020786, 2339179437267104826, 14493189915491863552, 94107031843898, 94109543104560, 1, 0, 0, 0, 1, 139825124642006}}
        pid = <optimized out>
        tid = <optimized out>
        ret = <optimized out>
#1  0x00007f2b91affc95 in __GI_abort () at abort.c:79
        save_stage = 1
        act = {__sigaction_handler = {sa_handler = 0x559793cc58c0, sa_sigaction = 0x559793cc58c0}, sa_mask = {__val = {94109507956752, 7, 6, 94109526004336, 139825108339872, 1, 139825110832589, 94109497230312, 94109508193840, 1, 0, 94109541221056, 0, 1, 139825110832589, 94109508164688}}, sa_flags = -1782168896, sa_restorer = 0x1}
        sigs = {__val = {32, 0 <repeats 15 times>}}
#2  0x00007f2b920f8d31 in talloc_abort (reason=0x7f2b92106838 "Bad talloc magic value - access after free") at ../talloc.c:500
No locals.
#3  0x00007f2b920fd6e9 in talloc_abort_access_after_free () at ../talloc.c:525
No locals.
#4  talloc_chunk_from_ptr (ptr=<optimized out>) at ../talloc.c:525
        pp = <optimized out>
        tc = <optimized out>
        ptr = <optimized out>
        pp = <optimized out>
        tc = <optimized out>
        pp = <optimized out>
        tc = <optimized out>
        pp = <optimized out>
        tc = <optimized out>
#5  _talloc_total_mem_internal (ptr=<optimized out>, type=TOTAL_MEM_BLOCKS, old_limit=0x0, new_limit=0x0) at ../talloc.c:2101
        total = 0
        c = <optimized out>
        tc = <optimized out>
        pool_hdr = <optimized out>
#6  0x00007f2b920fd5cd in _talloc_total_mem_internal (ptr=<optimized out>, type=TOTAL_MEM_BLOCKS, old_limit=0x0, new_limit=0x0) at ../talloc.c:2166
        total = 1
        c = 0x559793d02f20
        tc = 0x559793cf08c0
        pool_hdr = <optimized out>
#7  0x00007f2b920fd5cd in _talloc_total_mem_internal (ptr=<optimized out>, type=TOTAL_MEM_BLOCKS, old_limit=0x0, new_limit=0x0) at ../talloc.c:2166
        total = 1
        c = 0x559793cf08c0
        tc = 0x559793d05a00
        pool_hdr = <optimized out>
#8  0x00007f2b920fd5cd in _talloc_total_mem_internal (ptr=<optimized out>, type=TOTAL_MEM_BLOCKS, old_limit=0x0, new_limit=0x0) at ../talloc.c:2166
        total = 13306
        c = 0x559793d05a00
        tc = 0x559793d07a70
        pool_hdr = <optimized out>
#9  0x00007f2b920fd5cd in _talloc_total_mem_internal (ptr=<optimized out>, type=TOTAL_MEM_BLOCKS, old_limit=0x0, new_limit=0x0) at ../talloc.c:2166
        total = 1
        c = 0x559793d07a70
        tc = 0x559793cc6e80
        pool_hdr = <optimized out>
#10 0x00007f2b920fd5cd in _talloc_total_mem_internal (ptr=<optimized out>, type=TOTAL_MEM_BLOCKS, old_limit=0x0, new_limit=0x0) at ../talloc.c:2166
        total = 1
        c = 0x559793cc6e80
        tc = 0x559793cb82e0
        pool_hdr = <optimized out>
#11 0x00007f2b920fd5cd in _talloc_total_mem_internal (ptr=<optimized out>, type=TOTAL_MEM_BLOCKS, old_limit=0x0, new_limit=0x0) at ../talloc.c:2166
        total = 4
        c = 0x559793cb82e0
        tc = 0x559793cb6e10
        pool_hdr = <optimized out>
#12 0x00007f2b920fd5cd in _talloc_total_mem_internal (ptr=<optimized out>, type=TOTAL_MEM_BLOCKS, old_limit=0x0, new_limit=0x0) at ../talloc.c:2166
        total = 1
        c = 0x559793cb6e10
        tc = 0x559793cb6b60
        pool_hdr = <optimized out>
#13 0x00007f2b920fd762 in _talloc_total_mem_internal (new_limit=0x0, old_limit=0x0, type=TOTAL_MEM_BLOCKS, ptr=0x559793cec4d0) at ../talloc.c:2166
        total = 92
        c = 0x559793cb6b60
        tc = 0x559793cec470
        total = <optimized out>
        c = <optimized out>
        tc = <optimized out>
        pool_hdr = <optimized out>
#14 talloc_total_blocks (ptr=<optimized out>) at ../talloc.c:2188
No locals.
#15 0x00007f2b920fd905 in talloc_report_depth_FILE_helper (ptr=0x559793cec4d0, depth=0, max_depth=-1, is_ref=<optimized out>, _f=0x559794de1270) at ../talloc.c:2269
        name = 0x7f2b92106b36 "null_context"
        tc = 0x559793cec470
        f = 0x559794de1270
#16 0x00007f2b920fd1c3 in talloc_report_depth_cb (ptr=0x559793cec4d0, depth=0, max_depth=-1, callback=0x7f2b920fd830 <talloc_report_depth_FILE_helper>, private_data=0x559794de1270) at ../talloc.c:2229
        c = <optimized out>
        tc = 0x559793cec470
#17 0x00007f2b920fd28c in talloc_report_depth_file (ptr=<optimized out>, depth=<optimized out>, max_depth=<optimized out>, f=0x559794de1270) at ../talloc.c:2307
        f = 0x559794de1270
        max_depth = <optimized out>
        depth = <optimized out>
        ptr = <optimized out>
#18 0x00007fff22b60a5f in ?? ()
No symbol table info available.
#19 0x00005597942ff890 in ?? ()
No symbol table info available.
#20 0xcc00559793de49d0 in ?? ()
No symbol table info available.
#21 0x000000000000006b in ?? ()
No symbol table info available.
#22 0x00007f2b953c6fac in ?? () from /usr/lib64/sssd/libsss_util.so
No symbol table info available.
#23 0x0000559793de4a30 in ?? ()
No symbol table info available.
#24 0x0000559793484490 in ?? ()
No symbol table info available.
#25 0x0000559793cec4d0 in ?? ()
No symbol table info available.
#26 0x00007f2b92100e13 in _tc_free_internal (tc=<optimized out>, location=0x559795ad9a50 "\200") at ../talloc.c:1201
        ptr_to_free = <optimized out>
        ptr = <optimized out>
        is_child = <optimized out>
        d = <optimized out>
        pool = <optimized out>
        _flen = <optimized out>
        _fptr = <optimized out>
#27 0x0000000000000019 in ?? ()
No symbol table info available.
#28 0x0000559793d03180 in ?? ()
No symbol table info available.
#29 0x00007f2b91e9cc60 in ?? () from /lib64/libc.so.6
No symbol table info available.
#30 0x00007f2b91e9cc60 in ?? () from /lib64/libc.so.6
No symbol table info available.
#31 0x00007f2b91b62458 in _int_malloc (av=0x559794b16eb0, av@entry=0x7f2b91e9cc60 <main_arena>, bytes=bytes@entry=1633) at malloc.c:3687
        nb = 94109541236864
        idx = 73
        bin = <optimized out>
        victim = <optimized out>
        size = <optimized out>
        victim_index = <optimized out>
        remainder = <optimized out>
        remainder_size = <optimized out>
        block = <optimized out>
        bit = <optimized out>
        map = <optimized out>
        fwd = <optimized out>
        bck = <optimized out>
        tcache_unsorted_count = <optimized out>
        tcache_nb = <optimized out>
        tc_idx = <optimized out>
        return_cached = <optimized out>
        __PRETTY_FUNCTION__ = "_int_malloc"
#32 0x00007f2b91b63635 in _int_realloc (av=av@entry=0x7f2b91e9cc60 <main_arena>, oldp=oldp@entry=0x559793d02f10, oldsize=oldsize@entry=624, nb=nb@entry=1648) at malloc.c:4556
        newp = <optimized out>
        newsize = <optimized out>
        newmem = <optimized out>
        next = 0x559793d03180
        remainder = <optimized out>
        remainder_size = <optimized out>
        bck = <optimized out>
        fwd = <optimized out>
        copysize = <optimized out>
        ncopies = <optimized out>
        s = <optimized out>
        d = <optimized out>
        __PRETTY_FUNCTION__ = "_int_realloc"
        nextsize = <optimized out>
#33 0x00007f2b91b647cf in __GI___libc_realloc (oldmem=oldmem@entry=0x559793d02f20, bytes=bytes@entry=1632) at malloc.c:3205
        ar_ptr = 0x7f2b91e9cc60 <main_arena>
        nb = 1648
        newp = <optimized out>
        hook = <optimized out>
        oldp = 0x559793d02f10
        oldsize = 624
        __PRETTY_FUNCTION__ = "__libc_realloc"
#34 0x00007f2b92105287 in _talloc_realloc (context=context@entry=0x559793cf0920, ptr=0x559793d02f80, size=size@entry=1536, name=name@entry=0x5597932739c8 "src/responder/common/responder_packet.c:127") at ../talloc.c:2016
        new_ptr = <optimized out>
        new_size = 1536
        tc = 0x559793d02f20
        malloced = <optimized out>
        pool_hdr = <optimized out>
        old_size = 512
        new_size = <optimized out>
        next_tc = <optimized out>
        next_tc = <optimized out>
        new_chunk_size = <optimized out>
        ptr = 0x559793d02f80
        tc = <optimized out>
        pool_hdr = <optimized out>
        pool_tc = <optimized out>
        old_used = <optimized out>
        context = 0x559793cf0920
        _fptr = <optimized out>
        _fptr = <optimized out>
        space_needed = <optimized out>
        space_left = <optimized out>
        new_used = <optimized out>
        size = 1536
        malloced = <optimized out>
        _flen = <optimized out>
        _flen = <optimized out>
        new_ptr = <optimized out>
        chunk_count = <optimized out>
        name = 0x5597932739c8 "src/responder/common/responder_packet.c:127"
        old_size = <optimized out>
        old_chunk_size = <optimized out>
        start = <optimized out>
        tc = <optimized out>
        new_ptr = <optimized out>
        next_tc = <optimized out>
        _flen = <optimized out>
        _fptr = <optimized out>
        _flen = <optimized out>
        _fptr = <optimized out>
        pool_tc = <optimized out>
        next_tc = <optimized out>
        old_chunk_size = <optimized out>
        new_chunk_size = <optimized out>
        space_needed = <optimized out>
        space_left = <optimized out>
        chunk_count = <optimized out>
        start = <optimized out>
        old_used = <optimized out>
        new_used = <optimized out>
#35 0x0000559793260145 in sss_packet_grow (packet=packet@entry=0x559793cf0920, size=11) at src/responder/common/responder_packet.c:127
        totlen = 1536
        len = 518
        newmem = <optimized out>
        packet_len = 507
#36 0x000055979326026e in sss_packet_grow (packet=packet@entry=0x559793cf0920, size=<optimized out>) at src/responder/common/responder_packet.c:108
        totlen = <optimized out>
        len = <optimized out>
        newmem = <optimized out>
        packet_len = <optimized out>
        n = <optimized out>
#37 0x0000559793252e8e in nss_protocol_fill_members (nss_ctx=0x559793cdf240, nss_ctx=0x559793cdf240, _num_members=<synthetic pointer>, _rp=<synthetic pointer>, group_name=0x5597960a8780 "bulkgroup2", msg=<optimized out>, domain=0x559793cc9190, packet=0x559793cf0920) at src/responder/nss/nss_protocol_grent.c:173
        rctx = 0x559793cc6ee0
        members = {0x559794302790, 0x5597943026f0}
        member_name = <optimized out>
        num_members = <optimized out>
        body_len = 491
        body = 0x559793d02f90 ""
        j = 42
        ret = <optimized out>
        tmp_ctx = 0x559795c63ca0
        el = <optimized out>
        name = 0x559794b16f30
        i = <optimized out>
        tmp_ctx = <optimized out>
        rctx = <optimized out>
        members = <optimized out>
        el = <optimized out>
        name = <optimized out>
        member_name = <optimized out>
        num_members = <optimized out>
        body_len = <optimized out>
        body = <optimized out>
        ret = <optimized out>
        i = <optimized out>
        j = <optimized out>
        __FUNCTION__ = "nss_protocol_fill_members"
        __debug_macro_level = <optimized out>
        __debug_macro_level = <optimized out>
        CV_MACRO_val = <optimized out>
#38 nss_protocol_fill_grent (nss_ctx=nss_ctx@entry=0x559793cdf240, cmd_ctx=cmd_ctx@entry=0x559793d1a7c0, packet=0x559793cf0920, result=result@entry=0x559793d9b8b0) at src/responder/nss/nss_protocol_grent.c:266
        tmp_ctx = 0x559795c63a70
        msg = <optimized out>
        name = 0x559795c643a0
        pwfield = {str = 0x559793cdf9f0 "*", len = 2}
        gid = 9998
        num_results = 0
        num_members = <optimized out>
        members = <optimized out>
        members_size = <optimized out>
        rp = <optimized out>
        rp_members = 29
        rp_num_members = 12
        body_len = 29
        body = 0x559793d02f90 ""
        i = <optimized out>
        ret = <optimized out>
        __FUNCTION__ = "nss_protocol_fill_grent"
#39 0x00005597932515f2 in nss_protocol_reply (cli_ctx=0x559793d07ad0, nss_ctx=0x559793cdf240, cmd_ctx=cmd_ctx@entry=0x559793d1a7c0, result=result@entry=0x559793d9b8b0, fill_fn=0x559793252ac0 <nss_protocol_fill_grent>) at src/responder/nss/nss_protocol.c:90
        pctx = 0x559796406630
        ret = <optimized out>
#40 0x000055979324e754 in nss_getby_done (subreq=0x0) at src/responder/nss/nss_cmd.c:568
        result = 0x559793d9b8b0
        cmd_ctx = 0x559793d1a7c0
        ret = <optimized out>
        __FUNCTION__ = "nss_getby_done"
#41 0x00007f2b923110f9 in tevent_common_invoke_immediate_handler (im=0x55979520deb0, removed=removed@entry=0x0) at ../tevent_immediate.c:165
        handler_ev = 0x559793cb6e70
        ev = 0x559793cb6e70
        cur = {prev = <optimized out>, next = <optimized out>, event_ctx = <optimized out>, wrapper = 0x0, busy = <optimized out>, destroyed = <optimized out>, handler = <optimized out>, private_data = <optimized out>, handler_name = <optimized out>, create_location = <optimized out>, schedule_location = <optimized out>, cancel_fn = <optimized out>, additional_data = <optimized out>}
#42 0x00007f2b92311127 in tevent_common_loop_immediate (ev=ev@entry=0x559793cb6e70) at ../tevent_immediate.c:202
        im = <optimized out>
        ret = <optimized out>
#43 0x00007f2b92316f1f in epoll_event_loop_once (ev=0x559793cb6e70, location=<optimized out>) at ../tevent_epoll.c:917
        epoll_ev = 0x559793cb7100
        tval = {tv_sec = 6, tv_usec = 287047}
        panic_triggered = false
#44 0x00007f2b923151bb in std_event_loop_once (ev=0x559793cb6e70, location=0x7f2b953ca779 "src/util/server.c:724") at ../tevent_standard.c:110
        glue_ptr = <optimized out>
        glue = 0x559793cb6fb0
        ret = <optimized out>
#45 0x00007f2b92310395 in _tevent_loop_once (ev=ev@entry=0x559793cb6e70, location=location@entry=0x7f2b953ca779 "src/util/server.c:724") at ../tevent.c:772
        ret = <optimized out>
        nesting_stack_ptr = 0x0
#46 0x00007f2b9231063b in tevent_common_loop_wait (ev=0x559793cb6e70, location=0x7f2b953ca779 "src/util/server.c:724") at ../tevent.c:895
        ret = <optimized out>
#47 0x00007f2b9231514b in std_event_loop_wait (ev=0x559793cb6e70, location=0x7f2b953ca779 "src/util/server.c:724") at ../tevent_standard.c:141
        glue_ptr = <optimized out>
        glue = 0x559793cb6fb0
        ret = <optimized out>
#48 0x00007f2b953a9947 in server_loop (main_ctx=0x559793cb8340) at src/util/server.c:724
No locals.
#49 0x000055979324ce61 in main (argc=6, argv=<optimized out>) at src/responder/nss/nsssrv.c:464
        opt = <optimized out>
        pc = 0x559793cb1770
        opt_logger = 0x559793cb1c10 "files"
        main_ctx = 0x559793cb8340
        ret = 0
        uid = 0
        gid = 0
        long_options = {{longName = 0x0, shortName = 0 '\000', argInfo = 4, arg = 0x559793484380 <poptHelpOptions>, val = 0, descrip = 0x55979326cc2e "Help options:", argDescrip = 0x0}, {longName = 0x55979326cc3c "debug-level", shortName = 100 'd', argInfo = 2, arg = 0x559793484490 <debug_level>, val = 0, descrip = 0x55979326cc48 "Debug level", argDescrip = 0x0}, {longName = 0x55979326cc54 "debug-to-files", shortName = 102 'f', argInfo = 1073741824, arg = 0x559793484364 <debug_to_file>, val = 0, descrip = 0x55979326d0e8 "Send the debug output to files instead of stderr", argDescrip = 0x0}, {longName = 0x55979326cc63 "debug-to-stderr", shortName = 0 '\000', argInfo = 1073741824, arg = 0x559793484360 <debug_to_stderr>, val = 0, descrip = 0x55979326d120 "Send the debug output to stderr directly.", argDescrip = 0x0}, {longName = 0x55979326cc73 "debug-timestamps", shortName = 0 '\000', argInfo = 2, arg = 0x559793484448 <debug_timestamps>, val = 0, descrip = 0x55979326cc84 "Add debug timestamps", argDescrip = 0x0}, {longName = 0x55979326cc99 "debug-microseconds", shortName = 0 '\000', argInfo = 2, arg = 0x559793484460 <debug_microseconds>, val = 0, descrip = 0x55979326d150 "Show timestamps with microseconds", argDescrip = 0x0}, {longName = 0x55979326ccb0 "logger", shortName = 0 '\000', argInfo = 1, arg = 0x7fff22b61080, val = 0, descrip = 0x55979326ccac "Set logger", argDescrip = 0x55979326ccb7 "stderr|files|journald"}, {longName = 0x55979326cccd "uid", shortName = 0 '\000', argInfo = 2, arg = 0x7fff22b61078, val = 0, descrip = 0x55979326d178 "The user ID to run the server as", argDescrip = 0x0}, {longName = 0x55979326ccd1 "gid", shortName = 0 '\000', argInfo = 2, arg = 0x7fff22b6107c, val = 0, descrip = 0x55979326d1a0 "The group ID to run the server as", argDescrip = 0x0}, {longName = 0x55979326ccd5 "socket-activated", shortName = 0 '\000', argInfo = 0, arg = 0x559793484368 <socket_activated>, val = 0, descrip = 0x55979326d1c8 "Informs that the responder has been socket-activated", argDescrip = 0x0}, {longName = 0x55979326cce6 "dbus-activated", shortName = 0 '\000', argInfo = 0, arg = 0x559793484488 <dbus_activated>, val = 0, descrip = 0x55979326d200 "Informs that the responder has been dbus-activated", argDescrip = 0x0}, {longName = 0x0, shortName = 0 '\000', argInfo = 0, arg = 0x0, val = 0, descrip = 0x0, argDescrip = 0x0}}
        __FUNCTION__ = "main"
From                To                  Syms Read   Shared Object Library
0x00007f2b957e8910  0x00007f2b957eb88c  Yes         /lib64/libsss_idmap.so.0
0x00007f2b955e1e10  0x00007f2b955e3be8  Yes         /usr/lib64/sssd/libsss_cert.so
0x00007f2b95374ce0  0x00007f2b953bae02  Yes         /usr/lib64/sssd/libsss_util.so
0x00007f2b951595e0  0x00007f2b9515c950  Yes         /lib64/librt.so.1
0x00007f2b94f4c980  0x00007f2b94f53a56  Yes         /lib64/libpopt.so.0
0x00007f2b94d20980  0x00007f2b94d3a942  Yes         /lib64/libldb.so.1
0x00007f2b94af49b0  0x00007f2b94b0c5af  Yes         /lib64/libselinux.so.1
0x00007f2b948d9b70  0x00007f2b948e6162  Yes         /lib64/libtdb.so.1
0x00007f2b945da050  0x00007f2b946552b2  Yes         /lib64/libglib-2.0.so.0
0x00007f2b9434f760  0x00007f2b9439fd66  Yes         /lib64/libpcre.so.1
0x00007f2b94139970  0x00007f2b9414801d  Yes         /lib64/libini_config.so.5
0x00007f2b93f30a60  0x00007f2b93f30d78  Yes         /lib64/libbasicobjects.so.0
0x00007f2b93d2db10  0x00007f2b93d2e4da  Yes         /lib64/libref_array.so.1
0x00007f2b93b23750  0x00007f2b93b2919d  Yes         /lib64/libcollection.so.4
0x00007f2b9391b070  0x00007f2b9391d6ac  Yes         /usr/lib64/sssd/libsss_crypt.so
0x00007f2b937148d0  0x00007f2b9371655c  Yes         /usr/lib64/sssd/libsss_child.so
0x00007f2b935078a0  0x00007f2b9350e1c8  Yes         /lib64/libsss_certmap.so.0
0x00007f2b930a5000  0x00007f2b93244d00  Yes         /lib64/libcrypto.so.1.1
0x00007f2b92e284f0  0x00007f2b92e297bd  Yes         /usr/lib64/sssd/libsss_debug.so
0x00007f2b92b93c60  0x00007f2b92bfb3a4  Yes         /lib64/libsystemd.so.0
0x00007f2b92969cb0  0x00007f2b929765e6  Yes         /usr/lib64/sssd/libsss_iface.so
0x00007f2b927309f0  0x00007f2b9274b798  Yes         /usr/lib64/sssd/libsss_sbus.so
0x00007f2b9251eba0  0x00007f2b9251ff0b  Yes         /lib64/libdhash.so.1
0x00007f2b9230f2a0  0x00007f2b92317890  Yes         /lib64/libtevent.so.0
0x00007f2b920f8af0  0x00007f2b921067e2  Yes         /lib64/libtalloc.so.2
0x00007f2b91eb2810  0x00007f2b91edef25  Yes         /lib64/libdbus-1.so.3
0x00007f2b91affa70  0x00007f2b91c4af8f  Yes         /lib64/libc.so.6
0x00007f2b918c48a0  0x00007f2b918d2db5  Yes         /lib64/libpthread.so.0
0x00007f2b916bb090  0x00007f2b916bbe49  Yes         /lib64/libdl.so.2
0x00007f2b91492340  0x00007f2b9149c020  Yes         /lib64/libcrypt.so.1
0x00007f2b91213350  0x00007f2b9126e1c3  Yes         /lib64/libpcre2-8.so.0
0x00007f2b959ef030  0x00007f2b95a0e1d4  Yes         /lib64/ld-linux-x86-64.so.2
0x00007f2b9100de00  0x00007f2b9100f0f5  Yes         /lib64/libpath_utils.so.1
0x00007f2b90df8700  0x00007f2b90e058c7  Yes         /lib64/libz.so.1
0x00007f2b90bd25a0  0x00007f2b90be9436  Yes         /lib64/liblzma.so.5
0x00007f2b909ba1d0  0x00007f2b909cb5bb  Yes         /lib64/liblz4.so.1
0x00007f2b907b4740  0x00007f2b907b601f  Yes         /lib64/libcap.so.2
0x00007f2b90568900  0x00007f2b9059e402  Yes         /lib64/libmount.so.1
0x00007f2b9024a580  0x00007f2b9031847c  Yes         /lib64/libgcrypt.so.20
0x00007f2b90029dc0  0x00007f2b9003aa05  Yes         /lib64/libgcc_s.so.1
0x00007f2b8fde05f0  0x00007f2b8fe11362  Yes         /lib64/libblkid.so.1
0x00007f2b8fbcea20  0x00007f2b8fbd24d1  Yes         /lib64/libuuid.so.1
0x00007f2b8f9b0850  0x00007f2b8f9c1e62  Yes         /lib64/libgpg-error.so.0
0x00007f2b8f531130  0x00007f2b8f531a32  Yes         /usr/lib64/ldb/modules/ldb/asq.so
0x00007f2b8f32c180  0x00007f2b8f32d768  Yes         /usr/lib64/ldb/modules/ldb/ldap.so
0x00007f2b8f11dca0  0x00007f2b8f124fea  Yes         /lib64/liblber-2.4.so.2
0x00007f2b8eedbc10  0x00007f2b8ef099f0  Yes         /lib64/libldap-2.4.so.2
0x00007f2b8ecb8c10  0x00007f2b8ecc4b6e  Yes         /lib64/libresolv.so.2
0x00007f2b8ea9c360  0x00007f2b8eaad587  Yes         /lib64/libsasl2.so.3
0x00007f2b8e8239f0  0x00007f2b8e86f4aa  Yes         /lib64/libssl.so.1.1
0x00007f2b8e5c1d90  0x00007f2b8e5f4fcf  Yes         /lib64/libgssapi_krb5.so.2
0x00007f2b8e2ecce0  0x00007f2b8e3586d1  Yes         /lib64/libkrb5.so.3
0x00007f2b8e0adce0  0x00007f2b8e0bc634  Yes         /lib64/libk5crypto.so.3
0x00007f2b8dea5780  0x00007f2b8dea63a9  Yes         /lib64/libcom_err.so.2
0x00007f2b8dc98370  0x00007f2b8dc9f9bb  Yes         /lib64/libkrb5support.so.0
0x00007f2b8da91790  0x00007f2b8da92508  Yes         /lib64/libkeyutils.so.1
0x00007f2b8d88e820  0x00007f2b8d88e9f2  Yes         /usr/lib64/ldb/modules/ldb/ldb.so
0x00007f2b8d67da50  0x00007f2b8d687811  Yes         /usr/lib64/ldb/libldb-key-value.so
0x00007f2b8d46b1c0  0x00007f2b8d473ea3  Yes         /usr/lib64/ldb/modules/ldb/memberof.so
0x00007f2b8d265310  0x00007f2b8d265ee2  Yes         /usr/lib64/ldb/modules/ldb/paged_results.so
0x00007f2b8d0612f0  0x00007f2b8d061ae2  Yes         /usr/lib64/ldb/modules/ldb/paged_searches.so
0x00007f2b8ce5d430  0x00007f2b8ce5e522  Yes         /usr/lib64/ldb/modules/ldb/rdn_name.so
0x00007f2b8cc59bc0  0x00007f2b8cc59ec2  Yes         /usr/lib64/ldb/modules/ldb/sample.so
0x00007f2b8ca56210  0x00007f2b8ca56bc2  Yes         /usr/lib64/ldb/modules/ldb/server_sort.so
0x00007f2b8c852d30  0x00007f2b8c852fb2  Yes         /usr/lib64/ldb/modules/ldb/skel.so
0x00007f2b8c650750  0x00007f2b8c650882  Yes         /usr/lib64/ldb/modules/ldb/tdb.so
0x00007f2b8bec27f0  0x00007f2b8bec7670  Yes         /lib64/libnss_sss.so.2
0x00007f2b8bcb0720  0x00007f2b8bcb6d5c  Yes         /lib64/libnss_files.so.2
0x00007f2b8942dad0  0x00007f2b89463244  Yes         /lib64/libnss_systemd.so.2
$1 = 0x0
$2 = 0x0
rax            0x0                 0
rbx            0x6                 6
rcx            0x7f2b91b1593f      139825104640319
rdx            0x0                 0
rsi            0x7fff22b60540      140733775742272
rdi            0x2                 2
rbp            0x1                 0x1
rsp            0x7fff22b60540      0x7fff22b60540
r8             0x0                 0
r9             0x7fff22b60540      140733775742272
r10            0x8                 8
r11            0x246               582
r12            0x0                 0
r13            0x0                 0
r14            0x0                 0
r15            0x1                 1
rip            0x7f2b91b1593f      0x7f2b91b1593f <__GI_raise+271>
eflags         0x246               [ PF ZF IF ]
cs             0x33                51
ss             0x2b                43
ds             0x0                 0
es             0x0                 0
fs             0x0                 0
gs             0x0                 0
st0            0                   (raw 0x00000000000000000000)
st1            0                   (raw 0x00000000000000000000)
st2            0                   (raw 0x00000000000000000000)
st3            0                   (raw 0x00000000000000000000)
st4            0                   (raw 0x00000000000000000000)
st5            0                   (raw 0x00000000000000000000)
st6            0                   (raw 0x00000000000000000000)
st7            0                   (raw 0x00000000000000000000)
fctrl          0x37f               895
fstat          0x0                 0
ftag           0xffff              65535
fiseg          0x0                 0
fioff          0x0                 0
foseg          0x0                 0
fooff          0x0                 0
fop            0x0                 0
mxcsr          0x1fa0              [ PE IM DM ZM OM UM PM ]
bndcfgu        {raw = 0x0, config = {base = 0x0, reserved = 0x0, preserved = 0x0, enabled = 0x0}} {raw = 0x0, config = {base = 0, reserved = 0, preserved = 0, enabled = 0}}
bndstatus      {raw = 0x0, status = {bde = 0x0, error = 0x0}} {raw = 0x0, status = {bde = 0, error = 0}}
k0             0x0                 0
k1             0x0                 0
k2             0x0                 0
k3             0x0                 0
k4             0x0                 0
k5             0x0                 0
k6             0x0                 0
k7             0x0                 0
pkru           0x55555554          1431655764
zmm0           {v16_float = {0x0, 0x0, 0x0, 0x0, 0x0 <repeats 12 times>}, v8_double = {0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0}, v64_int8 = {0x25 <repeats 16 times>, 0x0 <repeats 48 times>}, v32_int16 = {0x2525, 0x2525, 0x2525, 0x2525, 0x2525, 0x2525, 0x2525, 0x2525, 0x0 <repeats 24 times>}, v16_int32 = {0x25252525, 0x25252525, 0x25252525, 0x25252525, 0x0 <repeats 12 times>}, v8_int64 = {0x2525252525252525, 0x2525252525252525, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0}, v4_int128 = {0x25252525252525252525252525252525, 0x0, 0x0, 0x0}}
zmm1           {v16_float = {0x0, 0x0, 0x0 <repeats 14 times>}, v8_double = {0x8000000000000000, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0}, v64_int8 = {0xff, 0xff, 0x0, 0x0, 0xff, 0xff, 0xff, 0xff, 0x0 <repeats 56 times>}, v32_int16 = {0xffff, 0x0, 0xffff, 0xffff, 0x0 <repeats 28 times>}, v16_int32 = {0xffff, 0xffffffff, 0x0 <repeats 14 times>}, v8_int64 = {0xffffffff0000ffff, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0}, v4_int128 = {0xffffffff0000ffff, 0x0, 0x0, 0x0}}
zmm2           {v16_float = {0x0, 0x0, 0x0 <repeats 14 times>}, v8_double = {0x8000000000000000, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0}, v64_int8 = {0xff, 0x0, 0x0, 0x0, 0xff, 0xff, 0xff, 0xff, 0x0 <repeats 56 times>}, v32_int16 = {0xff, 0x0, 0xffff, 0xffff, 0x0 <repeats 28 times>}, v16_int32 = {0xff, 0xffffffff, 0x0 <repeats 14 times>}, v8_int64 = {0xffffffff000000ff, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0}, v4_int128 = {0xffffffff000000ff, 0x0, 0x0, 0x0}}
zmm3           {v16_float = {0xffffffff, 0xffffffff, 0xffffffff, 0xffffffff, 0x0 <repeats 12 times>}, v8_double = {0x7fffffffffffffff, 0x7fffffffffffffff, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0}, v64_int8 = {0x66, 0x69, 0x72, 0x73, 0x74, 0x20, 0x66, 0x72, 0x65, 0x65, 0x20, 0x6d, 0x61, 0x79, 0x20, 0x62, 0x0 <repeats 48 times>}, v32_int16 = {0x6966, 0x7372, 0x2074, 0x7266, 0x6565, 0x6d20, 0x7961, 0x6220, 0x0 <repeats 24 times>}, v16_int32 = {0x73726966, 0x72662074, 0x6d206565, 0x62207961, 0x0 <repeats 12 times>}, v8_int64 = {0x7266207473726966, 0x622079616d206565, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0}, v4_int128 = {0x622079616d2065657266207473726966, 0x0, 0x0, 0x0}}
zmm4           {v16_float = {0x0, 0x0, 0x0, 0x0, 0x0 <repeats 12 times>}, v8_double = {0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0}, v64_int8 = {0xf8, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0xff, 0xff, 0xff, 0xff, 0x5e, 0x3, 0xf0, 0x90, 0x0 <repeats 48 times>}, v32_int16 = {0xf8, 0x0, 0x0, 0x0, 0xffff, 0xffff, 0x35e, 0x90f0, 0x0 <repeats 24 times>}, v16_int32 = {0xf8, 0x0, 0xffffffff, 0x90f0035e, 0x0 <repeats 12 times>}, v8_int64 = {0xf8, 0x90f0035effffffff, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0}, v4_int128 = {0x90f0035effffffff00000000000000f8, 0x0, 0x0, 0x0}}
zmm5           {v16_float = {0x0, 0x0, 0x0, 0x0, 0x0 <repeats 12 times>}, v8_double = {0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0}, v64_int8 = {0x1, 0x2, 0x1, 0x2, 0x1, 0x2, 0x1, 0x2, 0x1, 0x2, 0x1, 0x2, 0x1, 0x2, 0x1, 0x2, 0x0 <repeats 48 times>}, v32_int16 = {0x201, 0x201, 0x201, 0x201, 0x201, 0x201, 0x201, 0x201, 0x0 <repeats 24 times>}, v16_int32 = {0x2010201, 0x2010201, 0x2010201, 0x2010201, 0x0 <repeats 12 times>}, v8_int64 = {0x201020102010201, 0x201020102010201, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0}, v4_int128 = {0x2010201020102010201020102010201, 0x0, 0x0, 0x0}}
zmm6           {v16_float = {0x0, 0x0, 0x0, 0x0, 0x0 <repeats 12 times>}, v8_double = {0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0}, v64_int8 = {0x1, 0x2, 0x1, 0x2, 0x1, 0x2, 0x1, 0x2, 0x1, 0x2, 0x1, 0x2, 0x1, 0x2, 0x1, 0x2, 0x0 <repeats 48 times>}, v32_int16 = {0x201, 0x201, 0x201, 0x201, 0x201, 0x201, 0x201, 0x201, 0x0 <repeats 24 times>}, v16_int32 = {0x2010201, 0x2010201, 0x2010201, 0x2010201, 0x0 <repeats 12 times>}, v8_int64 = {0x201020102010201, 0x201020102010201, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0}, v4_int128 = {0x2010201020102010201020102010201, 0x0, 0x0, 0x0}}
zmm7           {v16_float = {0x0 <repeats 16 times>}, v8_double = {0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0}, v64_int8 = {0x0 <repeats 64 times>}, v32_int16 = {0x0 <repeats 32 times>}, v16_int32 = {0x0 <repeats 16 times>}, v8_int64 = {0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0}, v4_int128 = {0x0, 0x0, 0x0, 0x0}}
zmm8           {v16_float = {0x0, 0x0, 0xffffffff, 0xffffffff, 0x0 <repeats 12 times>}, v8_double = {0x0, 0x7fffffffffffffff, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0}, v64_int8 = {0x0, 0x25, 0x73, 0xa, 0x0, 0x0, 0x0, 0x0, 0x55, 0x6e, 0x65, 0x78, 0x70, 0x65, 0x63, 0x74, 0x0 <repeats 48 times>}, v32_int16 = {0x2500, 0xa73, 0x0, 0x0, 0x6e55, 0x7865, 0x6570, 0x7463, 0x0 <repeats 24 times>}, v16_int32 = {0xa732500, 0x0, 0x78656e55, 0x74636570, 0x0 <repeats 12 times>}, v8_int64 = {0xa732500, 0x7463657078656e55, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0}, v4_int128 = {0x7463657078656e55000000000a732500, 0x0, 0x0, 0x0}}
zmm9           {v16_float = {0x0 <repeats 16 times>}, v8_double = {0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0}, v64_int8 = {0x0 <repeats 64 times>}, v32_int16 = {0x0 <repeats 32 times>}, v16_int32 = {0x0 <repeats 16 times>}, v8_int64 = {0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0}, v4_int128 = {0x0, 0x0, 0x0, 0x0}}
zmm10          {v16_float = {0x0, 0x0, 0x0, 0x0 <repeats 13 times>}, v8_double = {0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0}, v64_int8 = {0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x20, 0x0 <repeats 55 times>}, v32_int16 = {0x0, 0x0, 0x0, 0x0, 0x20, 0x0 <repeats 27 times>}, v16_int32 = {0x0, 0x0, 0x20, 0x0 <repeats 13 times>}, v8_int64 = {0x0, 0x20, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0}, v4_int128 = {0x200000000000000000, 0x0, 0x0, 0x0}}
zmm11          {v16_float = {0x0 <repeats 16 times>}, v8_double = {0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0}, v64_int8 = {0x0 <repeats 64 times>}, v32_int16 = {0x0 <repeats 32 times>}, v16_int32 = {0x0 <repeats 16 times>}, v8_int64 = {0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0}, v4_int128 = {0x0, 0x0, 0x0, 0x0}}
zmm12          {v16_float = {0x0 <repeats 16 times>}, v8_double = {0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0}, v64_int8 = {0x0 <repeats 64 times>}, v32_int16 = {0x0 <repeats 32 times>}, v16_int32 = {0x0 <repeats 16 times>}, v8_int64 = {0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0}, v4_int128 = {0x0, 0x0, 0x0, 0x0}}
zmm13          {v16_float = {0x0 <repeats 16 times>}, v8_double = {0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0}, v64_int8 = {0x0 <repeats 64 times>}, v32_int16 = {0x0 <repeats 32 times>}, v16_int32 = {0x0 <repeats 16 times>}, v8_int64 = {0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0}, v4_int128 = {0x0, 0x0, 0x0, 0x0}}
zmm14          {v16_float = {0x0 <repeats 16 times>}, v8_double = {0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0}, v64_int8 = {0x0 <repeats 64 times>}, v32_int16 = {0x0 <repeats 32 times>}, v16_int32 = {0x0 <repeats 16 times>}, v8_int64 = {0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0}, v4_int128 = {0x0, 0x0, 0x0, 0x0}}
zmm15          {v16_float = {0x0 <repeats 16 times>}, v8_double = {0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0}, v64_int8 = {0x0 <repeats 64 times>}, v32_int16 = {0x0 <repeats 32 times>}, v16_int32 = {0x0 <repeats 16 times>}, v8_int64 = {0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0}, v4_int128 = {0x0, 0x0, 0x0, 0x0}}
zmm16          {v16_float = {0x0 <repeats 16 times>}, v8_double = {0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0}, v64_int8 = {0x0 <repeats 64 times>}, v32_int16 = {0x0 <repeats 32 times>}, v16_int32 = {0x0 <repeats 16 times>}, v8_int64 = {0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0}, v4_int128 = {0x0, 0x0, 0x0, 0x0}}
zmm17          {v16_float = {0x0 <repeats 16 times>}, v8_double = {0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0}, v64_int8 = {0x0 <repeats 64 times>}, v32_int16 = {0x0 <repeats 32 times>}, v16_int32 = {0x0 <repeats 16 times>}, v8_int64 = {0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0}, v4_int128 = {0x0, 0x0, 0x0, 0x0}}
zmm18          {v16_float = {0x0 <repeats 16 times>}, v8_double = {0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0}, v64_int8 = {0x0 <repeats 64 times>}, v32_int16 = {0x0 <repeats 32 times>}, v16_int32 = {0x0 <repeats 16 times>}, v8_int64 = {0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0}, v4_int128 = {0x0, 0x0, 0x0, 0x0}}
zmm19          {v16_float = {0x0 <repeats 16 times>}, v8_double = {0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0}, v64_int8 = {0x0 <repeats 64 times>}, v32_int16 = {0x0 <repeats 32 times>}, v16_int32 = {0x0 <repeats 16 times>}, v8_int64 = {0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0}, v4_int128 = {0x0, 0x0, 0x0, 0x0}}
zmm20          {v16_float = {0x0 <repeats 16 times>}, v8_double = {0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0}, v64_int8 = {0x0 <repeats 64 times>}, v32_int16 = {0x0 <repeats 32 times>}, v16_int32 = {0x0 <repeats 16 times>}, v8_int64 = {0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0}, v4_int128 = {0x0, 0x0, 0x0, 0x0}}
zmm21          {v16_float = {0x0 <repeats 16 times>}, v8_double = {0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0}, v64_int8 = {0x0 <repeats 64 times>}, v32_int16 = {0x0 <repeats 32 times>}, v16_int32 = {0x0 <repeats 16 times>}, v8_int64 = {0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0}, v4_int128 = {0x0, 0x0, 0x0, 0x0}}
zmm22          {v16_float = {0x0 <repeats 16 times>}, v8_double = {0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0}, v64_int8 = {0x0 <repeats 64 times>}, v32_int16 = {0x0 <repeats 32 times>}, v16_int32 = {0x0 <repeats 16 times>}, v8_int64 = {0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0}, v4_int128 = {0x0, 0x0, 0x0, 0x0}}
zmm23          {v16_float = {0x0 <repeats 16 times>}, v8_double = {0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0}, v64_int8 = {0x0 <repeats 64 times>}, v32_int16 = {0x0 <repeats 32 times>}, v16_int32 = {0x0 <repeats 16 times>}, v8_int64 = {0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0}, v4_int128 = {0x0, 0x0, 0x0, 0x0}}
zmm24          {v16_float = {0x0 <repeats 16 times>}, v8_double = {0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0}, v64_int8 = {0x0 <repeats 64 times>}, v32_int16 = {0x0 <repeats 32 times>}, v16_int32 = {0x0 <repeats 16 times>}, v8_int64 = {0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0}, v4_int128 = {0x0, 0x0, 0x0, 0x0}}
zmm25          {v16_float = {0x0 <repeats 16 times>}, v8_double = {0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0}, v64_int8 = {0x0 <repeats 64 times>}, v32_int16 = {0x0 <repeats 32 times>}, v16_int32 = {0x0 <repeats 16 times>}, v8_int64 = {0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0}, v4_int128 = {0x0, 0x0, 0x0, 0x0}}
zmm26          {v16_float = {0x0 <repeats 16 times>}, v8_double = {0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0}, v64_int8 = {0x0 <repeats 64 times>}, v32_int16 = {0x0 <repeats 32 times>}, v16_int32 = {0x0 <repeats 16 times>}, v8_int64 = {0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0}, v4_int128 = {0x0, 0x0, 0x0, 0x0}}
zmm27          {v16_float = {0x0 <repeats 16 times>}, v8_double = {0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0}, v64_int8 = {0x0 <repeats 64 times>}, v32_int16 = {0x0 <repeats 32 times>}, v16_int32 = {0x0 <repeats 16 times>}, v8_int64 = {0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0}, v4_int128 = {0x0, 0x0, 0x0, 0x0}}
zmm28          {v16_float = {0x0 <repeats 16 times>}, v8_double = {0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0}, v64_int8 = {0x0 <repeats 64 times>}, v32_int16 = {0x0 <repeats 32 times>}, v16_int32 = {0x0 <repeats 16 times>}, v8_int64 = {0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0}, v4_int128 = {0x0, 0x0, 0x0, 0x0}}
zmm29          {v16_float = {0x0 <repeats 16 times>}, v8_double = {0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0}, v64_int8 = {0x0 <repeats 64 times>}, v32_int16 = {0x0 <repeats 32 times>}, v16_int32 = {0x0 <repeats 16 times>}, v8_int64 = {0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0}, v4_int128 = {0x0, 0x0, 0x0, 0x0}}
zmm30          {v16_float = {0x0 <repeats 16 times>}, v8_double = {0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0}, v64_int8 = {0x0 <repeats 64 times>}, v32_int16 = {0x0 <repeats 32 times>}, v16_int32 = {0x0 <repeats 16 times>}, v8_int64 = {0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0}, v4_int128 = {0x0, 0x0, 0x0, 0x0}}
zmm31          {v16_float = {0x0 <repeats 16 times>}, v8_double = {0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0}, v64_int8 = {0x0 <repeats 64 times>}, v32_int16 = {0x0 <repeats 32 times>}, v16_int32 = {0x0 <repeats 16 times>}, v8_int64 = {0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0}, v4_int128 = {0x0, 0x0, 0x0, 0x0}}
bnd0           {lbound = 0x0, ubound = 0xffffffffffffffff} {lbound = 0x0, ubound = 0xffffffffffffffff}
bnd1           {lbound = 0x0, ubound = 0xffffffffffffffff} {lbound = 0x0, ubound = 0xffffffffffffffff}
bnd2           {lbound = 0x0, ubound = 0xffffffffffffffff} {lbound = 0x0, ubound = 0xffffffffffffffff}
bnd3           {lbound = 0x0, ubound = 0xffffffffffffffff} {lbound = 0x0, ubound = 0xffffffffffffffff}
Dump of assembler code for function __GI_raise:
   0x00007f2b91b15830 <+0>:	endbr64 
   0x00007f2b91b15834 <+4>:	push   %rbx
   0x00007f2b91b15835 <+5>:	mov    $0xffffffffffffffff,%r8
   0x00007f2b91b1583c <+12>:	mov    %edi,%ebx
   0x00007f2b91b1583e <+14>:	mov    $0x8,%r10d
   0x00007f2b91b15844 <+20>:	xor    %edi,%edi
   0x00007f2b91b15846 <+22>:	sub    $0x110,%rsp
   0x00007f2b91b1584d <+29>:	mov    %fs:0x28,%rax
   0x00007f2b91b15856 <+38>:	mov    %rax,0x108(%rsp)
   0x00007f2b91b1585e <+46>:	xor    %eax,%eax
   0x00007f2b91b15860 <+48>:	mov    %rsp,%r9
   0x00007f2b91b15863 <+51>:	movabs $0xfffffffe7fffffff,%rax
   0x00007f2b91b1586d <+61>:	mov    %r8,0x88(%rsp)
   0x00007f2b91b15875 <+69>:	mov    %rax,0x80(%rsp)
   0x00007f2b91b1587d <+77>:	mov    %r9,%rdx
   0x00007f2b91b15880 <+80>:	lea    0x80(%rsp),%rsi
   0x00007f2b91b15888 <+88>:	mov    $0xe,%eax
   0x00007f2b91b1588d <+93>:	mov    %r8,0x90(%rsp)
   0x00007f2b91b15895 <+101>:	mov    %r8,0x98(%rsp)
   0x00007f2b91b1589d <+109>:	mov    %r8,0xa0(%rsp)
   0x00007f2b91b158a5 <+117>:	mov    %r8,0xa8(%rsp)
   0x00007f2b91b158ad <+125>:	mov    %r8,0xb0(%rsp)
   0x00007f2b91b158b5 <+133>:	mov    %r8,0xb8(%rsp)
   0x00007f2b91b158bd <+141>:	mov    %r8,0xc0(%rsp)
   0x00007f2b91b158c5 <+149>:	mov    %r8,0xc8(%rsp)
   0x00007f2b91b158cd <+157>:	mov    %r8,0xd0(%rsp)
   0x00007f2b91b158d5 <+165>:	mov    %r8,0xd8(%rsp)
   0x00007f2b91b158dd <+173>:	mov    %r8,0xe0(%rsp)
   0x00007f2b91b158e5 <+181>:	mov    %r8,0xe8(%rsp)
   0x00007f2b91b158ed <+189>:	mov    %r8,0xf0(%rsp)
   0x00007f2b91b158f5 <+197>:	mov    %r8,0xf8(%rsp)
   0x00007f2b91b158fd <+205>:	syscall 
   0x00007f2b91b158ff <+207>:	mov    $0x27,%ecx
   0x00007f2b91b15904 <+212>:	mov    %ecx,%eax
   0x00007f2b91b15906 <+214>:	syscall 
   0x00007f2b91b15908 <+216>:	mov    %rax,%rdi
   0x00007f2b91b1590b <+219>:	mov    $0xba,%eax
   0x00007f2b91b15910 <+224>:	syscall 
   0x00007f2b91b15912 <+226>:	mov    %eax,%esi
   0x00007f2b91b15914 <+228>:	mov    %ebx,%edx
   0x00007f2b91b15916 <+230>:	mov    $0xea,%eax
   0x00007f2b91b1591b <+235>:	syscall 
   0x00007f2b91b1591d <+237>:	cmp    $0xfffffffffffff000,%rax
   0x00007f2b91b15923 <+243>:	ja     0x7f2b91b15960 <__GI_raise+304>
   0x00007f2b91b15925 <+245>:	mov    %eax,%r8d
   0x00007f2b91b15928 <+248>:	mov    $0x8,%r10d
   0x00007f2b91b1592e <+254>:	xor    %edx,%edx
   0x00007f2b91b15930 <+256>:	mov    %r9,%rsi
   0x00007f2b91b15933 <+259>:	mov    $0x2,%edi
   0x00007f2b91b15938 <+264>:	mov    $0xe,%eax
   0x00007f2b91b1593d <+269>:	syscall 
=> 0x00007f2b91b1593f <+271>:	mov    0x108(%rsp),%rcx
   0x00007f2b91b15947 <+279>:	xor    %fs:0x28,%rcx
   0x00007f2b91b15950 <+288>:	mov    %r8d,%eax
   0x00007f2b91b15953 <+291>:	jne    0x7f2b91b1596e <__GI_raise+318>
   0x00007f2b91b15955 <+293>:	add    $0x110,%rsp
   0x00007f2b91b1595c <+300>:	pop    %rbx
   0x00007f2b91b1595d <+301>:	retq   
   0x00007f2b91b1595e <+302>:	xchg   %ax,%ax
   0x00007f2b91b15960 <+304>:	mov    0x386501(%rip),%rdx        # 0x7f2b91e9be68
   0x00007f2b91b15967 <+311>:	neg    %eax
   0x00007f2b91b15969 <+313>:	mov    %eax,%fs:(%rdx)
   0x00007f2b91b1596c <+316>:	jmp    0x7f2b91b15928 <__GI_raise+248>
   0x00007f2b91b1596e <+318>:	callq  0x7f2b91bec3f0 <__stack_chk_fail>
End of assembler dump.

Additional information:
limits:
:Limit                     Soft Limit           Hard Limit           Units     
:Max cpu time              unlimited            unlimited            seconds   
:Max file size             unlimited            unlimited            bytes     
:Max data size             unlimited            unlimited            bytes     
:Max stack size            8388608              unlimited            bytes     
:Max core file size        unlimited            unlimited            bytes     
:Max resident set          unlimited            unlimited            bytes     
:Max processes             31132                31132                processes 
:Max open files            8192                 8192                 files     
:Max locked memory         16777216             16777216             bytes     
:Max address space         unlimited            unlimited            bytes     
:Max file locks            unlimited            unlimited            locks     
:Max pending signals       31132                31132                signals   
:Max msgqueue size         819200               819200               bytes     
:Max nice priority         0                    0                    
:Max realtime priority     0                    0                    
:Max realtime timeout      unlimited            unlimited            us        
environ:
:LANG=en_US.UTF-8
:PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin
:NOTIFY_SOCKET=/run/systemd/notify
:INVOCATION_ID=0246006f0bad4471a292a921fb709806
:JOURNAL_STREAM=9:116003
:DEBUG_LOGGER=--logger=files
:_SSS_LOOPS=NO
:KRB5RCACHEDIR=/var/cache/krb5rcache
abrt_msgs:
:Nov 28 07:57:47 kvm-03-guest16 abrt-server[22511]: Analyzing coredump 'coredump'
:Nov 28 07:57:48 kvm-03-guest16 abrt-server[22511]: All debuginfo files are available
:Nov 28 07:57:48 kvm-03-guest16 abrt-server[22511]: Generating backtrace
:Nov 28 07:57:50 kvm-03-guest16 abrt-server[22511]: Backtrace is generated and saved, 41125 bytes
:Nov 28 07:57:50 kvm-03-guest16 abrt-server[22511]: -----Backtrace generated, upload coredump-----
Comment 3 Amith 2018-11-28 14:27:50 UTC 
Created attachment 1509534 [details]
IDLE SSSD NSS TALLOC REPORT
Comment 4 Amith 2018-11-28 14:30:17 UTC 
Created attachment 1509535 [details]
First sssd nss talloc report
Comment 5 Amith 2018-11-28 14:33:37 UTC 
Created attachment 1509536 [details]
Second SSSD NSS TALLOC REPORT
Comment 6 Amith 2018-11-28 14:37:24 UTC 
Created attachment 1509537 [details]
Third SSSD NSS TALLOC REPORT
Comment 7 Pavel Březina 2018-11-30 10:36:04 UTC 
There does not seem to be any memory leak related to talloc. The second and third attachment are huge but it is actually a member list of "bulkgroup2". How many members is this group supposed to have?

Can you run sssd_nss via valgrind?
Comment 8 Amith 2018-11-30 11:00:17 UTC 
(In reply to Pavel Březina from comment #7)
> There does not seem to be any memory leak related to talloc. The second and
> third attachment are huge but it is actually a member list of "bulkgroup2".
> How many members is this group supposed to have?

I think over 7000 users in bulkgroup2.

> 
> Can you run sssd_nss via valgrind?

Sure, will run and update the results.
Comment 9 Pavel Březina 2018-11-30 12:55:33 UTC 
> I think over 7000 users in bulkgroup2.

So it is actually expected for the talloc hierarchy to be this big.
Comment 10 Amith 2018-12-03 16:42:29 UTC 
(In reply to Pavel Březina from comment #9)
> > I think over 7000 users in bulkgroup2.
> 
> So it is actually expected for the talloc hierarchy to be this big.

I have attached the valgrind log. I followed the below steps to generate it:

1. Configure sssd.conf as follows:

[sssd]
config_file_version = 2
services = nss, pam
domains = LDAP

[nss]
command = valgrind -v --leak-check=full --show-reachable=yes --log-file=/var/log/sssd/valgrind_nss_%p.log /usr/libexec/sssd/sssd_nss --uid 0 --gid 0 --debug-to-files

[pam]

[domain/LDAP]
debug_level = 0xFFF0
id_provider = ldap
ldap_uri = ldap://auto-hv-02-guest01.idmqe.lab.eng.bos.redhat.com
ldap_tls_cacert = /etc/openldap/certs/cacert.asc
ldap_schema = rfc2307bis

2. Clear the cache and restart sssd service.

3. Execute the test steps, which i automated in a script (/root/test.sh).

4. Stop the sssd service and copy the /var/log/sssd/valgrind_nss_5036.log file.

After finishing the above tests, i cleared the cache and ran the test again to reproduce the issue
. The script writes its output to a local file /root/repor. The contents of this file shows high consumption of nss memory:
-----------------------------------------------------------
Initial sssd_nss memory usage is now 38236
After first set of 1000 users, sssd_nss memory usage is 41464
PID of sssd_nss is: 10424
After second set of 1000 users, sssd_nss memory usage is 67564
PID of sssd_nss is: 10424
After third set of 1000 users, sssd_nss memory usage is 80700
PID of sssd_nss is: 10424
After fourth set of 1000 users, sssd_nss memory usage is 96380
PID of sssd_nss is: 10424
After fifth set of 1000 users, sssd_nss memory usage is kB
PID of sssd_nss is: 10424
-----------------------------------------------------------

TEST Environment:
I have reserved the test system for 48 hours. You can login and verify this issue.

Host name: kvm-04-guest21.rhts.eng.bos.redhat.com
System Credentials: root/redhat

Script for running the test steps is in /root/test.sh. User lookups are executed in sets of 1000 users in loops. Also, the sssd_nss memory is captured.
Comment 11 Amith 2018-12-03 16:43:54 UTC 
Created attachment 1511000 [details]
Valgrind log file.
Comment 12 Pavel Březina 2018-12-05 12:04:09 UTC 
==5036== LEAK SUMMARY:
==5036==    definitely lost: 0 bytes in 0 blocks
==5036==    indirectly lost: 0 bytes in 0 blocks
==5036==      possibly lost: 6,968 bytes in 35 blocks
==5036==    still reachable: 1,467,655 bytes in 283 blocks
==5036==         suppressed: 0 bytes in 0 blocks

Valgrind shown some leaks that needs investigation but the total amount of leaks is about 1MB, but the above test shows 50MB difference.
Comment 13 Pavel Březina 2018-12-07 11:53:13 UTC 
This is a tricky one but it can be reproduced. Create ldap with 1000 users and run:

$ cat /proc/$(pidof sssd_nss)/status | grep VmRSS && for i in $(seq 1 1000); do id user-$i &> /dev/null; done ; cat /proc/$(pidof sssd_nss)/status | grep VmRSS
VmRSS:	   34892 kB
VmRSS:	   39332 kB

Comparing talloc report before and after this execution does not show anything interesting. The leak is not visible in talloc. Valgrind show some leaks but there are probably not relevant to this as they are very small, also I looked at the dbus related once but they seem to be false positives (although another pair of eyes should look at them).

I do suspect some dbus stuff, maybe unfreed dbus message or something as the memory growth happens only when the responder contacts data provider not when the users come from cache. It won't be easy to track this down.
Comment 14 Pavel Březina 2019-01-21 10:36:46 UTC 
I went through the sbus code again and was not able to find any leak there. I need someone else to look into this to bring new perspective.
Comment 18 Alexey Tikhonov 2019-04-16 15:41:57 UTC 
(In reply to Pavel Březina from comment #9)
> > I think over 7000 users in bulkgroup2.
> 
> So it is actually expected for the talloc hierarchy to be this big.

But why? After request is served and data is provided to the client, memory should be released. Right?


(In reply to Pavel Březina from comment #13)

> I do suspect some dbus stuff, maybe unfreed dbus message or something as the
> memory growth happens only when the responder contacts data provider not
> when the users come from cache.

I observe the same leak even if data is being served from sysdb cache (so provider is not involved)
Comment 19 Alexey Tikhonov 2019-04-16 15:55:04 UTC 
(In reply to Pavel Březina from comment #13)
> Comparing talloc report before and after this execution does not show
> anything interesting.

I confirm this statement.
Comment 20 Pavel Březina 2019-04-17 11:54:48 UTC 
(In reply to Alexey Tikhonov from comment #18)
> (In reply to Pavel Březina from comment #9)
> > > I think over 7000 users in bulkgroup2.
> > 
> > So it is actually expected for the talloc hierarchy to be this big.
> 
> But why? After request is served and data is provided to the client, memory
> should be released. Right?

The report says:
full talloc report on 'null_context' (total 3488396 bytes in 131685 blocks)
    1) talloc_new: src/db/sysdb_ops.c:5318 contains 3101344 bytes in 123004 blocks (ref 0) 0x559793f485d0
        struct ldb_message *           contains 3100979 bytes in 122996 blocks (ref 0) 0x559794366060
    ...
    2) talloc_new: src/db/sysdb_views.c:1536 contains      0 bytes in   1 blocks (ref 0) 0x559793f48560
    3) talloc_new: src/db/sysdb_search.c:998 contains 352201 bytes in 8084 blocks (ref 0) 0x559793d0af20
        struct ldb_result              contains 352201 bytes in 8083 blocks (ref 0) 0x559793cc6af0
            struct ldb_message *           contains 352161 bytes in 8082 blocks (ref 0) 0x559793ce51e0
                struct ldb_message             contains 352145 bytes in 8081 blocks (ref 0) 0x559793cee300
                    struct ldb_message_element     contains 351665 bytes in 8060 blocks (ref 0) 0x559794b862a0
                        struct ldb_val                 contains  97088 bytes in 3035 blocks (ref 0) 0x559793d58a50
                            uint8_t                        contains     16 bytes in   1 blocks (ref 0) 0x5597954b4810

The call stack is as follows:
a) dp_req_initgr_pp_sr_overlay
b) sysdb_getgrgid_with_views = 3)
c) sysdb_add_group_member_overrides = 2)
d) sysdb_get_user_members_recursively = 1)

The logic is:
1. dp_req_initgr_pp_sr_overlay calls sysdb_getgrgid_with_views
2. sysdb_getgrgid_with_views creates new tmp_ctx (=3) and gets bunch of gids (unit8_t values in talloc report), then calls sysdb_add_group_member_overrides
3. sysdb_add_group_member_overrides creates new tmp_ctx (=2) that will hold results of sysdb_get_user_members_recursively, but this is empty so sysdb_get_user_members_recursively did not yet finished
4. sysdb_get_user_members_recursively creates new tmp_ctx that hold the member dn (=1)

However, apparently sysdb_get_user_members_recursively did not yet finished (its tmp_ctx still exist in talloc report) so either there is something seriously wrong and I missed it or the talloc report was obtained when sssd was executing this function. I checked all these functions and there are not memory leaks so I assumed the latter.

So yes, it should be freed in the end. But the talloc report was obtain when sssd was in this function, not after the request finished, unless I missed something.
Comment 21 Alexey Tikhonov 2019-04-23 21:30:07 UTC 
(In reply to Pavel Březina from comment #20)
> However, apparently sysdb_get_user_members_recursively did not yet finished
> (its tmp_ctx still exist in talloc report) so either there is something
> seriously wrong and I missed it or the talloc report was obtained when sssd
> was executing this function. I checked all these functions and there are not
> memory leaks so I assumed the latter.
> 
> So yes, it should be freed in the end. But the talloc report was obtain when
> sssd was in this function, not after the request finished, unless I missed
> something.

This makes sense.

I thought that talloc report was obtained in the moment of crash (as in comment 2) - because of `talloc_report_depth_file()` in bt. And since bt has `nss_protocol_fill_grent()` then `sysdb_get_user_members_recursively()` had already finished.

Then I wonder what is the reason of this crash. Bt is quite weird:
> nss_protocol_fill_grent() -> nss_protocol_fill_members() -> sss_packet_grow() -> _talloc_realloc() -> ... -> _int_malloc() -> ..? -> _tc_free_internal() -> ..? -> ?? libsss_util.so -> talloc_report_depth_file() ... -> talloc_abort("Bad talloc magic value - access after free")

This part - `_int_malloc()` -> _tc_free_internal() -> libsss_util.so() - looks very strange. Does libtalloc ever hook libc memory allocator?

"Bad talloc magic value - access after free" during internal report => memory corruption (so not a "use after free" actually)

But what could be the trigger of `talloc_report_depth_file()`?
Comment 22 Pavel Březina 2019-04-24 12:25:37 UTC 
/*
  enable leak reporting on exit
*/
_PUBLIC_ void talloc_enable_leak_report(void)
{
	talloc_enable_null_tracking();
	talloc_report_null = true;
	talloc_setup_atexit();
}

/*
  enable full leak reporting on exit
*/
_PUBLIC_ void talloc_enable_leak_report_full(void)
{
	talloc_enable_null_tracking();
	talloc_report_null_full = true;
	talloc_setup_atexit();
}

static void talloc_setup_atexit(void)
{
	static bool done;

	if (done) {
		return;
	}

	atexit(talloc_lib_atexit);
	done = true;
}

These functions will enable automatic report on exit. So perhaps this is the reason why it was called. It would be good to know the functions behind question marks in the backtrace, otherwise we are literally shooting blind.
Comment 23 Alexey Tikhonov 2019-04-25 19:11:09 UTC 
Probably we can't find a leak because... there is no leak.

Yes, VmRSS grows, but take a look at details.

Before:
mRSS:     36304 kB
RssAnon:            1328 kB
RssFile:           34976 kB
RssShmem:              0 kB

After:
VmRSS:     43300 kB
RssAnon:            1608 kB
RssFile:           41692 kB
RssShmem:              0 kB

VmRSS =  RssAnon + RssFile + RssShmem

So VmRSS grows mostly due to RssFile. And "RssFile: Size of resident file mappings."
I wonder if it might be simply memcache being populated?

(RssAnon still needs closer inspection)
Comment 24 Pavel Březina 2019-04-26 08:06:20 UTC 
That is possible, nice thinking. Can you try it with memcache_timeout=0? This should disable the memory cache.
Comment 25 Alexey Tikhonov 2019-04-26 09:49:40 UTC 
(In reply to Pavel Březina from comment #24)
> That is possible, nice thinking. Can you try it with memcache_timeout=0?
> This should disable the memory cache.

Before scenario execution:
VmRSS:     11696 kB
RssAnon:            1328 kB
RssFile:           10368 kB
RssShmem:              0 kB

After scenario execution:
VmRSS:     18876 kB
RssAnon:            1716 kB
RssFile:           17160 kB
RssShmem:              0 kB

Memcache is really off: RssFile is much less.
But it still grows by approx the same 6900kb.

I need to dig further. I wonder if it might be libldb who mmap's some files while sssd reads sysdb cache...
Comment 26 Alexey Tikhonov 2019-04-26 12:04:39 UTC 
(In reply to Alexey Tikhonov from comment #25)
> I need to dig further. I wonder if it might be libldb who mmap's some files
> while sssd reads sysdb cache...

Yes, RssFile grows due to mmap() in sysdb(libldb(libtdb)). I compiled test version of sssd with `LDB_FLG_NOMMAP,` passed to ldb_connect() and results are:

Before scenario execution:
VmRSS:     11196 kB
RssAnon:            1328 kB
RssFile:            9868 kB
RssShmem:              0 kB


After scenario execution:
VmRSS:     11504 kB
RssAnon:            1600 kB
RssFile:            9904 kB
RssShmem:              0 kB


Now have to investigate RssAnon growth.
Comment 27 Alexey Tikhonov 2019-04-26 17:13:37 UTC 
(In reply to Alexey Tikhonov from comment #26)
> Now have to investigate RssAnon growth.

Created 5k of users in ldap and fetch it in batches:
batch:    initially     +200     +200     +200     +200     +200     +500     +500     +1000     +1000     +1000
RssAnon:  1332          1540     1540     1664     1708     1712     1716     1980      1720      1732      1740

From my point of view, what we observe here, is normal behavior of glibc memory allocator.

glibc allocator is very complicated and it doesn't really allocate / free memory when program calls malloc()/free().
glibc uses brk/sbrk to increase heap (or mmap to allocate additional memory arena) if it can't find free chunk of memory for malloc() in current heap. And when program calls free() it may mark appropriate page as free (madvise) to avoid kernel swapping page to the disk when page is purged from RAM. (This is oversimplified, just to back up my statement)

So I think we observe growth and fragmentation of heap due to *a lot* of small malloc()

To test assumption I added `malloc_trim(0)` to `nss_protocol_done()` and repeated the same test.
Results are:
RssAnon:  1332          1556     1568     1572     1580     1580     1584     1588      1588      1532      1772

Last result spoils the picture a little bit. But still I think those results confirm my assumptions.
Comment 28 Alexey Tikhonov 2019-04-30 15:33:02 UTC 
Conclusion.

tl,dr: There is no memory leak. I close this ticket as "NOTABUG"


Long version:

VmRSS grows due to two reasons:

(I) Mostly: RssFile.
This is libtdb (used by libldb used by sysdb cache) who mmap()'s cache files into memory.
As was discussed with Jakub, this is not a concern because:
1) It is limited in total size.
2) It is equal to amount of cached data. So to grow to GBs it requires a *lot* of data.
This can't lead to OOM. Purging this pages from RAM is very cheap and is not a performance issue.

(II) To less extent: RssAnon
I run additional tests with 10k users, fetching by 1k and calling `malloc_trim(0)` in `nss_protocol_done()`.
Results are: 1332 - 1572 - 1588 - 1588 - 1588 - 1592 - 1596 - 1596 - 1596 - 1592 - 1596
So after glibc allocator acquired enough initial heap it didn't grow anymore and this is not a concern.
Note You need to log in before you can comment on or make changes to this bug.