Bug 2209636 - libipa_otp_lasttoken plugin memory leak
Summary: libipa_otp_lasttoken plugin memory leak
Keywords:
Status: VERIFIED
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-08-17 13:04 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:
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


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

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


Note You need to log in before you can comment on or make changes to this bug.