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

[bmasonrh]

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.

[bmasonrh]

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]

Hi @bmasonrh ,

thank you for the PR! I can reproduce it on CUPS 2.4.7 together with an additional memory leak https://github.com/OpenPrinting/cups/pull/814 - I'll review the patch now.

[zdohnal]

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)

[michaelrsweet]

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