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 2209636 - libipa_otp_lasttoken plugin memory leak
Summary: libipa_otp_lasttoken plugin memory leak
Keywords:
Status: CLOSED ERRATA
Alias: None
Product: Red Hat Enterprise Linux 7
Classification: Red Hat
Component: ipa
Version: 7.9
Hardware: Unspecified
OS: Unspecified
unspecified
unspecified
Target Milestone: rc
: ---
Assignee: Rob Crittenden
QA Contact: Sudhir Menon
URL:
Whiteboard:
Depends On:
Blocks: 2227783 2227784
TreeView+ depends on / blocked
 
Reported: 2023-05-24 10:20 UTC by Aleksandr Sharov
Modified: 2023-09-20 15:51 UTC (History)
7 users (show)

Fixed In Version: ipa-4.6.8-5.el7_9.15
Doc Type: If docs needed, set a value
Doc Text:
Clone Of:
: 2227783 2227784 (view as bug list)
Environment:
Last Closed: 2023-08-29 09:29:51 UTC
Target Upstream Version:
Embargoed:

Attachments (Terms of Use)
valgrind.out (3.40 MB, text/plain)
2023-05-24 10:20 UTC, Aleksandr Sharov 		no flags Details
Show Obsolete (1) View All


Links
System ID Private Priority Status Summary Last Updated
Fedora Pagure freeipa issue 9403 0 None None None 2023-06-26 21:03:32 UTC
Red Hat Issue Tracker FREEIPA-9916 0 None None None 2023-05-24 10:20:56 UTC
Red Hat Issue Tracker RHELPLAN-158044 0 None None None 2023-05-24 10:21:01 UTC
Red Hat Product Errata RHBA-2023:4827 0 None None None 2023-08-29 09:30:02 UTC

Description Aleksandr Sharov 2023-05-24 10:20:09 UTC 
Created attachment 1966602 [details]
valgrind.out

Description of problem:
Freshly installed replica is leaking memory. From the valgrind output it seems it's actually libipa_otp_lasttoken plugin library:

The leak summary gives this ( 2,5 MB definitely lost overall + 350K indirectly lost ) :

==23733== LEAK SUMMARY:
==23733==    definitely lost: 2,493,525 bytes in 66,549 blocks
==23733==    indirectly lost: 347,788 bytes in 34,963 blocks
==23733==      possibly lost: 3,818 bytes in 9 blocks
==23733==    still reachable: 3,897,465 bytes in 40,026 blocks
==23733==                       of which reachable via heuristic:
==23733==                         stdstring          : 30 bytes in 1 blocks
==23733==         suppressed: 0 bytes in 0 blocks
==23733==

==> libipa_otp_lasttoken plugin seems to be involved here ...

951,768 bytes in 10,116 blocks are definitely lost in loss record 2,421 of 2,422
==23733==    at 0x4C29F73: malloc (vg_replace_malloc.c:309)
==23733==    by 0x63C0B89: strdup (in /usr/lib64/libc-2.17.so)
==23733==    by 0x5094AF2: slapi_ch_strdup (in /usr/lib64/dirsrv/libslapd.so.0.1.0)
==23733==    by 0x50E0FB6: slapi_pblock_get (in /usr/lib64/dirsrv/libslapd.so.0.1.0)
===> ==23733==    by 0x14DF6233: ??? (in /usr/lib64/dirsrv/plugins/libipa_otp_lasttoken.so)
==> ==23733==    by 0x14DF6500: ??? (in /usr/lib64/dirsrv/plugins/libipa_otp_lasttoken.so)
==23733==    by 0x50E8077: ??? (in /usr/lib64/dirsrv/libslapd.so.0.1.0)
==23733==    by 0x50E8332: plugin_call_plugins (in /usr/lib64/dirsrv/libslapd.so.0.1.0)
==23733==    by 0x16ADE22D: ldbm_back_modify (in /usr/lib64/dirsrv/plugins/libback-ldbm.so)
==23733==    by 0x50D3FE5: ??? (in /usr/lib64/dirsrv/libslapd.so.0.1.0)
==23733==    by 0x50D550A: do_modify (in /usr/lib64/dirsrv/libslapd.so.0.1.0)
==23733==    by 0x123886: ??? (in /usr/sbin/ns-slapd)
==23733==    by 0x8042F7A: ??? (in /usr/lib64/libnspr4.so)
==23733==    by 0x8683EA4: start_thread (in /usr/lib64/libpthread-2.17.so)
==23733==    by 0x6432B0C: clone (in /usr/lib64/libc-2.17.so)

==> and here too ..

==23733== 660,205 (353,280 direct, 306,925 indirect) bytes in 10,116 blocks are definitely lost in loss record 2,420 of 2,422
==23733==    at 0x4C2C291: realloc (vg_replace_malloc.c:836)
==23733==    by 0x509495A: slapi_ch_realloc (in /usr/lib64/dirsrv/libslapd.so.0.1.0)
==23733==    by 0x5093AD1: slapi_ch_array_add_ext (in /usr/lib64/dirsrv/libslapd.so.0.1.0)
==23733==    by 0x50A54B7: slapi_entry_attr_get_charray_ext (in /usr/lib64/dirsrv/libslapd.so.0.1.0)
==23733==    by 0x50A551D: slapi_entry_attr_get_charray (in /usr/lib64/dirsrv/libslapd.so.0.1.0)
==> ==23733==    by 0x14DF6265: ??? (in /usr/lib64/dirsrv/plugins/libipa_otp_lasttoken.so)
==> ==23733==    by 0x14DF6500: ??? (in /usr/lib64/dirsrv/plugins/libipa_otp_lasttoken.so)
==23733==    by 0x50E8077: ??? (in /usr/lib64/dirsrv/libslapd.so.0.1.0)
==23733==    by 0x50E8332: plugin_call_plugins (in /usr/lib64/dirsrv/libslapd.so.0.1.0)
==23733==    by 0x16ADE22D: ldbm_back_modify (in /usr/lib64/dirsrv/plugins/libback-ldbm.so)
==23733==    by 0x50D3FE5: ??? (in /usr/lib64/dirsrv/libslapd.so.0.1.0)
==23733==    by 0x50D550A: do_modify (in /usr/lib64/dirsrv/libslapd.so.0.1.0)
==23733==    by 0x123886: ??? (in /usr/sbin/ns-slapd)
==23733==    by 0x8042F7A: ??? (in /usr/lib64/libnspr4.so)
==23733==    by 0x8683EA4: start_thread (in /usr/lib64/libpthread-2.17.so)

==> And again here ...

==23733== 492,254 bytes in 5,023 blocks are definitely lost in loss record 2,418 of 2,422
==23733==    at 0x4C29F73: malloc (vg_replace_malloc.c:309)
==23733==    by 0x63C0B89: strdup (in /usr/lib64/libc-2.17.so)
==23733==    by 0x5094AF2: slapi_ch_strdup (in /usr/lib64/dirsrv/libslapd.so.0.1.0)
==23733==    by 0x50E0FB6: slapi_pblock_get (in /usr/lib64/dirsrv/libslapd.so.0.1.0)
==23733==    by 0x14DF6233: ??? (in /usr/lib64/dirsrv/plugins/libipa_otp_lasttoken.so)
==23733==    by 0x14DF662E: ??? (in /usr/lib64/dirsrv/plugins/libipa_otp_lasttoken.so)
==23733==    by 0x50E8077: ??? (in /usr/lib64/dirsrv/libslapd.so.0.1.0)
==23733==    by 0x50E8332: plugin_call_plugins (in /usr/lib64/dirsrv/libslapd.so.0.1.0)
==23733==    by 0x16AD2047: ldbm_back_delete (in /usr/lib64/dirsrv/plugins/libback-ldbm.so)
==23733==    by 0x509881A: ??? (in /usr/lib64/dirsrv/libslapd.so.0.1.0)
==23733==    by 0x5098BB2: do_delete (in /usr/lib64/dirsrv/libslapd.so.0.1.0)
==23733==    by 0x1238A0: ??? (in /usr/sbin/ns-slapd)
==23733==    by 0x8042F7A: ??? (in /usr/lib64/libnspr4.so)
==23733==    by 0x8683EA4: start_thread (in /usr/lib64/libpthread-2.17.so)
==23733==    by 0x6432B0C: clone (in /usr/lib64/libc-2.17.so)
==23733==    by 0x6432B0C: clone (in /usr/lib64/libc-2.17.so)

==> And still ..

==23733== 306,925 bytes in 34,044 blocks are indirectly lost in loss record 2,416 of 2,422
==23733==    at 0x4C29F73: malloc (vg_replace_malloc.c:309)
==23733==    by 0x50947D2: slapi_ch_malloc (in /usr/lib64/dirsrv/libslapd.so.0.1.0)
==23733==    by 0x50A5493: slapi_entry_attr_get_charray_ext (in /usr/lib64/dirsrv/libslapd.so.0.1.0)
==23733==    by 0x50A551D: slapi_entry_attr_get_charray (in /usr/lib64/dirsrv/libslapd.so.0.1.0)
==> ==23733==    by 0x14DF6265: ??? (in /usr/lib64/dirsrv/plugins/libipa_otp_lasttoken.so)
==> ==23733==    by 0x14DF6500: ??? (in /usr/lib64/dirsrv/plugins/libipa_otp_lasttoken.so)
==23733==    by 0x50E8077: ??? (in /usr/lib64/dirsrv/libslapd.so.0.1.0)
==23733==    by 0x50E8332: plugin_call_plugins (in /usr/lib64/dirsrv/libslapd.so.0.1.0)
==23733==    by 0x16ADE22D: ldbm_back_modify (in /usr/lib64/dirsrv/plugins/libback-ldbm.so)
==23733==    by 0x50D3FE5: ??? (in /usr/lib64/dirsrv/libslapd.so.0.1.0)
==23733==    by 0x50D550A: do_modify (in /usr/lib64/dirsrv/libslapd.so.0.1.0)
==23733==    by 0x123886: ??? (in /usr/sbin/ns-slapd)
==23733==    by 0x8042F7A: ??? (in /usr/lib64/libnspr4.so)
==23733==    by 0x8683EA4: start_thread (in /usr/lib64/libpthread-2.17.so)
==23733==    by 0x6432B0C: clone (in /usr/lib64/libc-2.17.so)

Version-Release number of selected component (if applicable):
ipa-server-4.6.8-5.el7_9.12.x86_64                          Mon Apr 17 14:58:57 2023


How reproducible:
can't reproduce it on test environment

Actual results:
Memory leaks with consiquent failure of dirsrv

Expected results:
No memory leak

Additional info:
valgrind output in attachement, you can find sosreport from the server in attached case.
Comment 3 Rob Crittenden 2023-05-24 13:46:39 UTC 
Please install the ipa debuginfo packages and reproduce so we can see where in the plugin the leaks originate.
Comment 5 Aleksandr Sharov 2023-06-02 07:20:51 UTC 
Hi Rob!

Sorry, initially I've concluded issue is somewhere in 389ds (where it may very well be), so went only with 389ds debuginfo packages. 

New valgrind output with ipa-debuginfo installed is attached.

389-ds-base-debuginfo-1.3.10.2-14.el7_9.x86_64              Tue May 16 11:46:00 2023
ipa-debuginfo-4.6.8-5.el7_9.9.x86_64                        Wed May 31 18:03:40 2023

Thank you!
Comment 6 Rob Crittenden 2023-06-02 13:47:57 UTC 
There seems to be a mismatch between the debuginfo and the libraries somehow.

--21549-- Reading syms from /usr/lib64/dirsrv/plugins/libipa_otp_counter.so
--21549--   Considering /usr/lib/debug/usr/lib64/dirsrv/plugins/libipa_otp_counter.so.debug ..
--21549--   .. CRC mismatch (computed a3b8c5c2 wanted ff1c1b9b)

In the first BZ comment this is ipa-server-4.6.8-5.el7_9.12.x86_64 but the debuginfo is from 4.6.8-5.el7_9.9.

I was able to identify one potential leak from a call to slapi_entry_attr_get_charray.

==21549== 41,219 bytes in 4,026 blocks are indirectly lost in loss record 7,222 of 7,333
==21549==    at 0x4C29F73: malloc (vg_replace_malloc.c:309)
==21549==    by 0x50947D2: slapi_ch_malloc (in /usr/lib64/dirsrv/libslapd.so.0.1.0)
==21549==    by 0x50A5493: slapi_entry_attr_get_charray_ext (in /usr/lib64/dirsrv/libslapd.so.0.1.0)
==21549==    by 0x50A551D: slapi_entry_attr_get_charray (in /usr/lib64/dirsrv/libslapd.so.0.1.0)
==21549==    by 0x14DF6265: ??? (in /usr/lib64/dirsrv/plugins/libipa_otp_lasttok

The set of objectclasses is only freed if ipaToken one of the objectclasses.

diff --git a/daemons/ipa-slapi-plugins/ipa-otp-lasttoken/ipa_otp_lasttoken.c 
b/daemons/ipa-slapi-plugins/ipa-otp-lasttoken/ipa_otp_lasttoken.c
index b7a2ba7f0..ff80e812d 100644
--- a/daemons/ipa-slapi-plugins/ipa-otp-lasttoken/ipa_otp_lasttoken.c
+++ b/daemons/ipa-slapi-plugins/ipa-otp-lasttoken/ipa_otp_lasttoken.c
@@ -64,6 +64,7 @@ static bool entry_is_token(Slapi_Entry *entry)
         }
     }
 
+    slapi_ch_array_free(ocls);
     return false;
 }

The other leaks are in slapi_pblock_get(), e.g:

==21549== 54,239 bytes in 735 blocks are definitely lost in loss record 7,236 of 7,333
==21549==    at 0x4C29F73: malloc (vg_replace_malloc.c:309)
==21549==    by 0x63C0B89: strdup (in /usr/lib64/libc-2.17.so)
==21549==    by 0x5094AF2: slapi_ch_strdup (in /usr/lib64/dirsrv/libslapd.so.0.1.0)
==21549==    by 0x50E0FB6: slapi_pblock_get (in /usr/lib64/dirsrv/libslapd.so.0.1.0)
==21549==    by 0x14DF6233: ??? (in /usr/lib64/dirsrv/plugins/libipa_otp_lasttoken.so)
==21549==    by 0x14DF6500: ??? (in /usr/lib64/dirsrv/plugins/libipa_otp_lasttok

There are only five instances of this call in the plugin but generally speaking the caller is not responsible for freeing the values returned. That is done by slapi_pblock_destroy() when the connection is closed.

I don't see any obvious reason why any of these five calls would be problematic, so being able to narrow down which one is the culprit could help greatly.
Comment 9 Rob Crittenden 2023-06-26 19:08:17 UTC 
The latest trace has pointed me in the right direction, thanks. Taking a look at:

==17484==    by 0x14DF6233: is_allowed (ipa_otp_lasttoken.c:149)
Comment 10 Florence Blanc-Renaud 2023-07-31 16:06:49 UTC 
Fixed upstream
master:
https://pagure.io/freeipa/c/089907b4853207ea70c7ca02896b84718251cf6f
Comment 12 Florence Blanc-Renaud 2023-08-01 06:12:31 UTC 
Fixed upstream
ipa-4-10:
https://pagure.io/freeipa/c/421e8e9ac886c50b4bb463a62b8ad5de8da94f31

ipa-4-9:
https://pagure.io/freeipa/c/9438ce9207445e4ad4a9c7bdf0c9e569cabac571

ipa-4-6:
https://pagure.io/freeipa/c/66c35a574e2f2e43773fb4c60bc6983cca724579
Comment 23 errata-xmlrpc 2023-08-29 09:29:51 UTC 
Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory (ipa bug fix update), and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

https://access.redhat.com/errata/RHBA-2023:4827
Note You need to log in before you can comment on or make changes to this bug.