Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

scheduler/job.c: unload job before freeing job history in cupsdDeletejob() #813

Merged
merged 1 commit into from
Oct 30, 2023

Conversation

bmasonrh
Copy link
Contributor

With "PreserveJobHistory Off", LogLevel not set to debug (or debug2), and "LogDebugHistory 200" (the default), cupsdDeleteJob() frees the job history and then unloads the job. However, unload_job() calls cupsdLogJob() which re-creates the job history and puts "Unloading..." into it because level (debug) is greater than LogLevel (warn) and LogDebugHistory is set to 200 messages by default. Unused (and unreachable) job history is left behind, resulting in a memory leak.

The solution seems to be to unload the job before freeing the job history.

…Job()

With "PreserveJobHistory Off", LogLevel not set to debug (or debug2),
and "LogDebugHistory 200" (the default), cupsdDeleteJob() frees the
job history and then unloads the job.  However, unload_job() calls
cupsdLogJob() which re-creates the job history and puts "Unloading..."
into it because level (debug) is greater than LogLevel (warn) and
LogDebugHistory is set to 200 messages by default.  Unused (and
unreachable) job history is left behind, resulting in a memory leak.
@bmasonrh
Copy link
Contributor Author

bmasonrh commented Oct 27, 2023

To reproduce the issue:

  1. Add "PreserveJobHistory Off" to cupsd.conf
  2. Add a simple print queue (lpadmin -p test -v file:/dev/null -E)
  3. Stop CUPS (systemctl stop cups.service cups.path cups.socket)
  4. Re-run cupsd with valgrind (valgrind --leak-check=yes /usr/sbin/cupsd -l)
  5. Print a file (lp -d test /etc/fstab)

Tested in CentOS 9 Stream (relevant code is the same). Before the patch:

# valgrind --leak-check=yes /usr/sbin/cupsd -l
==25887== Memcheck, a memory error detector
==25887== Copyright (C) 2002-2022, and GNU GPL'd, by Julian Seward et al.
==25887== Using Valgrind-3.19.0 and LibVEX; rerun with -h for copyright info
==25887== Command: /usr/sbin/cupsd -l
==25887== 
^C==25887== 
==25887== Process terminating with default action of signal 2 (SIGINT)
==25887==    at 0x4C12A7A: epoll_wait (in /usr/lib64/libc.so.6)
==25887==    by 0x116200: UnknownInlinedFun (select.c:458)
==25887==    by 0x116200: main (main.c:881)
==25887== 
==25887== HEAP SUMMARY:
==25887==     in use at exit: 637,557 bytes in 13,965 blocks
==25887==   total heap usage: 16,121 allocs, 2,156 frees, 1,409,904 bytes allocated
==25887== 
==25887== 380 (216 direct, 164 indirect) bytes in 1 blocks are definitely lost in loss record 440 of 502
==25887==    at 0x4849464: calloc (vg_replace_malloc.c:1328)
==25887==    by 0x4A48E33: cupsArrayNew3 (array.c:742)
==25887==    by 0x14455E: cupsdLogJob (log.c:608)
==25887==    by 0x14C3CF: UnknownInlinedFun (job.c:5358)
==25887==    by 0x14C3CF: UnknownInlinedFun (job.c:5353)
==25887==    by 0x14C3CF: cupsdDeleteJob (job.c:1502)
==25887==    by 0x14C706: cupsdCleanJobs (job.c:474)
==25887==    by 0x116B57: main (main.c:1046)
==25887== 
==25887== LEAK SUMMARY:
==25887==    definitely lost: 216 bytes in 1 blocks
==25887==    indirectly lost: 164 bytes in 2 blocks
==25887==      possibly lost: 0 bytes in 0 blocks
==25887==    still reachable: 637,177 bytes in 13,962 blocks
==25887==         suppressed: 0 bytes in 0 blocks
==25887== Reachable blocks (those to which a pointer was found) are not shown.
==25887== To see them, rerun with: --leak-check=full --show-leak-kinds=all
==25887== 
==25887== For lists of detected and suppressed errors, rerun with: -s
==25887== ERROR SUMMARY: 1 errors from 1 contexts (suppressed: 0 from 0)

After the patch:

# valgrind --leak-check=yes /usr/sbin/cupsd -l
==26237== Memcheck, a memory error detector
==26237== Copyright (C) 2002-2022, and GNU GPL'd, by Julian Seward et al.
==26237== Using Valgrind-3.19.0 and LibVEX; rerun with -h for copyright info
==26237== Command: /usr/sbin/cupsd -l
==26237== 
^C==26237== 
==26237== Process terminating with default action of signal 2 (SIGINT)
==26237==    at 0x4C12A7A: epoll_wait (in /usr/lib64/libc.so.6)
==26237==    by 0x116200: UnknownInlinedFun (select.c:458)
==26237==    by 0x116200: main (main.c:881)
==26237== 
==26237== HEAP SUMMARY:
==26237==     in use at exit: 637,177 bytes in 13,962 blocks
==26237==   total heap usage: 16,119 allocs, 2,157 frees, 1,409,560 bytes allocated
==26237== 
==26237== LEAK SUMMARY:
==26237==    definitely lost: 0 bytes in 0 blocks
==26237==    indirectly lost: 0 bytes in 0 blocks
==26237==      possibly lost: 0 bytes in 0 blocks
==26237==    still reachable: 637,177 bytes in 13,962 blocks
==26237==         suppressed: 0 bytes in 0 blocks
==26237== Reachable blocks (those to which a pointer was found) are not shown.
==26237== To see them, rerun with: --leak-check=full --show-leak-kinds=all
==26237== 
==26237== For lists of detected and suppressed errors, rerun with: -s
==26237== ERROR SUMMARY: 0 errors from 0 contexts (suppressed: 0 from 0)

zdohnal added a commit to zdohnal/cups that referenced this pull request Oct 30, 2023
Since the array `profiles` is set to use `strdup()` as a copy function, we
don't have to use `strdup()` on the element which is passed as parameter
of `cupsArrayAdd()` - using the `strdup()` as we used till now causes
memory leak.

Reproducer is the same as OpenPrinting#813
.
@zdohnal
Copy link
Member

zdohnal commented Oct 30, 2023

Hi @bmasonrh ,

thank you for the PR! I can reproduce it on CUPS 2.4.7 together with an additional memory leak #814 - I'll review the patch now.

zdohnal added a commit to zdohnal/cups that referenced this pull request Oct 30, 2023
 Since the array `profiles` is set to use `strdup()` as a copy function, we
 don't have to use `strdup()` on the element which is passed as parameter
 of `cupsArrayAdd()` - using the `strdup()` as we used till now causes
 memory leak.

 Reproducer is the same as OpenPrinting#813
Copy link
Member

@zdohnal zdohnal left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

LGTM, thanks! I've verified the leak is gone.

@zdohnal
Copy link
Member

zdohnal commented Oct 30, 2023

The CI failures are the same as before - @michaelrsweet macos failure looks the same as from branch 2.4.x -

httpDecode64_3()/httpEncode64_3(): PASS
httpGetHostname(): PASS (mac-1698431313578.local.)
httpAddrGetList(mac-1698431313578.local.): FAIL
httpSeparateURI(): PASS (44 URIs tested)
httpAssembleURI(): PASS (16 URIs tested)

@zdohnal zdohnal merged commit e6fcc26 into OpenPrinting:master Oct 30, 2023
3 of 6 checks passed
@michaelrsweet
Copy link
Member

@zdohnal Yes, it is a problem with the macOS runners... :/

zdohnal added a commit that referenced this pull request Nov 24, 2023
Since the array profiles is set to use strdup() as a copy function, we
don't have to use strdup() on the element which is passed as parameter
of cupsArrayAdd() - using the strdup() as we used till now causes
memory leak.

Reproducer is the same as #813
zdohnal added a commit that referenced this pull request Nov 24, 2023
Since the array profiles is set to use strdup() as a copy function, we don't have to use strdup() on the element which is passed as parameter of cupsArrayAdd() - using the strdup() as we used till now causes memory leak.

Reproducer is the same as #813 .
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

3 participants