Dear Maintainer, with the original PPD and input files from Ian I could reproduce the issue and with the help of rr-debugger this is what I assume what happens:
- The buffer m_pPrinterBuffer is allocated here with the current sizes inside cups_header. [1] - The first page got processed and for the second page a new cups_header record gets copied. [2] Unfortunately now the header contains higher sizes, but the buffer is not grown accordingly. - Now to this buffer is written by a read function, and beyond where the management information of malloc got overwritten for some other random memory. [3] - The defect in the management information of malloc is detected and the process is aborted. [4] The attached patch is an attempt to grow the buffer size if the header changes on a new page. This is just tested for the given crash, nothing more, therefore there might be side effects on replacing this buffer? Kind regards, Bernhard [1] 500 m_pPrinterBuffer = new BYTE[cups_header->cupsWidth * 4 + 32]; (rr) bt #0 HPCupsFilter::startPage (this=0x556369c551c0 <filter>, cups_header=0x7ffe94b8e030) at prnt/hpcups/HPCupsFilter.cpp:500 #1 0x0000556369bf4793 in HPCupsFilter::processRasterData (this=this@entry=0x556369c551c0 <filter>, cups_raster=<optimized out>, cups_raster@entry=0x55636ac39d00) at prnt/hpcups/HPCupsFilter.cpp:668 #2 0x0000556369bf4de9 in HPCupsFilter::StartPrintJob (this=0x556369c551c0 <filter>, argc=<optimized out>, argv=0x7ffe94b8ecf8) at prnt/hpcups/HPCupsFilter.cpp:597 ... (rr) when Current event: 898 [2] #0 0x00007f504dcaa190 in memcpy (__len=1796, __src=0x564615c8cd1c, __dest=0x7ffc2a13f080) at /usr/include/x86_64-linux-gnu/bits/string_fortified.h:34 #1 cupsRasterReadHeader2 (r=0x564615c8cd00, h=h@entry=0x7ffc2a13f080) at raster-stubs.c:209 #2 0x00005646141d356d in HPCupsFilter::processRasterData (this=this@entry=0x5646142341c0 <filter>, cups_raster=<optimized out>, cups_raster@entry=0x564615c8cd00) at prnt/hpcups/HPCupsFilter.cpp:661 #3 0x00005646141d3de9 in HPCupsFilter::StartPrintJob (this=0x5646142341c0 <filter>, argc=<optimized out>, argv=0x7ffc2a13fd48) at prnt/hpcups/HPCupsFilter.cpp:597 #4 0x00007f504d83fd0a in __libc_start_main (main=0x5646141d0e10 <main(int, char**)>, argc=6, argv=0x7ffc2a13fd48, init=<optimized out>, fini=<optimized out>, rtld_fini=<optimized out>, stack_end=0x7ffc2a13fd38) at ../csu/libc-start.c:308 #5 0x00005646141d0efa in _start () (rr) when Current event: 1230 [3] ... #9 0x00007f504dcaa00d in read (__nbytes=19220, __buf=0x564615cb1ca0, __fd=0) at /usr/include/x86_64-linux-gnu/bits/unistd.h:44 #10 cups_read_fd (ctx=<optimized out>, buf=0x564615cb1ca0 '\377' <repeats 200 times>..., bytes=19220) at raster-stubs.c:323 #11 0x00007f504dca9340 in cups_raster_io (bytes=19220, buf=0x564615cb1ca0 '\377' <repeats 200 times>..., r=0x564615c8cd00) at raster-stream.c:1372 #12 _cupsRasterReadPixels (r=0x564615c8cd00, p=0x564615cb1ca0 '\377' <repeats 200 times>..., len=19220) at raster-stream.c:782 #13 0x00007f504dcaa1e5 in cupsRasterReadPixels (r=<optimized out>, p=<optimized out>, len=<optimized out>) at raster-stubs.c:228 #14 0x00005646141d36e8 in HPCupsFilter::processRasterData (this=this@entry=0x5646142341c0 <filter>, cups_raster=<optimized out>, cups_raster@entry=0x564615c8cd00) at prnt/hpcups/HPCupsFilter.cpp:758 #15 0x00005646141d3de9 in HPCupsFilter::StartPrintJob (this=0x5646142341c0 <filter>, argc=<optimized out>, argv=0x7ffc2a13fd48) at prnt/hpcups/HPCupsFilter.cpp:597 ... [4] #0 __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50 #1 0x00007f504d83e537 in __GI_abort () at abort.c:79 #2 0x00007f504d897768 in __libc_message (action=action@entry=do_abort, fmt=fmt@entry=0x7f504d9a5e31 "%s\n") at ../sysdeps/posix/libc_fatal.c:155 #3 0x00007f504d89ea5a in malloc_printerr (str=str@entry=0x7f504d9a8258 "free(): invalid next size (normal)") at malloc.c:5347 #4 0x00007f504d89ff2c in _int_free (av=0x7f504d9d7b80 <main_arena>, p=0x564615cb1c90, have_lock=<optimized out>) at malloc.c:4322 #5 0x00005646141d15c6 in HPCupsFilter::cleanup (this=this@entry=0x5646142341c0 <filter>) at prnt/hpcups/HPCupsFilter.cpp:227 #6 0x00005646141d3e1b in HPCupsFilter::closeFilter (this=0x5646142341c0 <filter>) at prnt/hpcups/HPCupsFilter.cpp:221 #7 HPCupsFilter::StartPrintJob (this=0x5646142341c0 <filter>, argc=<optimized out>, argv=0x7ffc2a13fd48) at prnt/hpcups/HPCupsFilter.cpp:617 ...
Description: Grow m_pPrinterBuffer if needed on each page Author: Bernhard Übelacker <bernha...@mailbox.org> Bug-Debian: https://bugs.debian.org/974828 Bug-Ubuntu: https://launchpad.net/bugs/1904318 Last-Update: 2021-02-26 Index: hplip-3.20.11+dfsg0/prnt/hpcups/HPCupsFilter.cpp =================================================================== --- hplip-3.20.11+dfsg0.orig/prnt/hpcups/HPCupsFilter.cpp +++ hplip-3.20.11+dfsg0/prnt/hpcups/HPCupsFilter.cpp @@ -199,7 +199,7 @@ void HPCupsFilter::WriteKBMPRaster (FILE fwrite (black_raster, 1, adj_k_width, fp); } -HPCupsFilter::HPCupsFilter() : m_pPrinterBuffer(NULL) +HPCupsFilter::HPCupsFilter() : m_pPrinterBuffer(NULL), m_PrinterBufferSize(0) { setbuf (stderr, NULL); @@ -226,6 +226,7 @@ void HPCupsFilter::cleanup() if (m_pPrinterBuffer) { delete [] m_pPrinterBuffer; m_pPrinterBuffer = NULL; + m_PrinterBufferSize = 0; } if(m_ppd){ @@ -497,8 +498,6 @@ DRIVER_ERROR HPCupsFilter::startPage (cu dbglog("HPCUPS: returning NO_ERROR from startPage\n"); } - m_pPrinterBuffer = new BYTE[cups_header->cupsWidth * 4 + 32]; - return NO_ERROR; } @@ -663,6 +662,14 @@ int HPCupsFilter::processRasterData(cups current_page_number++; + if (m_PrinterBufferSize < (cups_header.cupsWidth * 4 + 32)) { + m_PrinterBufferSize = cups_header.cupsWidth * 4 + 32; + if (m_pPrinterBuffer) { + delete [] m_pPrinterBuffer; + } + m_pPrinterBuffer = new BYTE[m_PrinterBufferSize]; + } + if (current_page_number == 1) { if (startPage(&cups_header) != NO_ERROR) { Index: hplip-3.20.11+dfsg0/prnt/hpcups/HPCupsFilter.h =================================================================== --- hplip-3.20.11+dfsg0.orig/prnt/hpcups/HPCupsFilter.h +++ hplip-3.20.11+dfsg0/prnt/hpcups/HPCupsFilter.h @@ -89,6 +89,7 @@ public: private: BYTE *m_pPrinterBuffer; + int m_PrinterBufferSize; Job m_Job; SystemServices *m_pSys; int child_pid;
# Bullseye/testing amd64 qemu VM 2021-02-25 apt update apt dist-upgrade apt install systemd-coredump mc quilt fakeroot gdb valgrind rr git cups hplip hplip-dbgsym printer-driver-hpcups-dbgsym libcups2-dbgsym apt build-dep glibc apt build-dep hplip mkdir /home/benutzer/source/glibc/orig -p cd /home/benutzer/source/glibc/orig apt source glibc cd mkdir /home/benutzer/source/cups/orig -p cd /home/benutzer/source/cups/orig apt source cups cd mkdir /home/benutzer/source/hplip/orig -p cd /home/benutzer/source/hplip/orig apt source hplip cd mkdir 974828 cd 974828 wget "https://bugs.debian.org/cgi-bin/bugreport.cgi?att=1;bug=974828;filename=974828.tar.gz;msg=38" -O 974828.tar.gz tar -zxf 974828.tar.gz export PPD=/home/benutzer/974828/HP_Officejet_Pro_8610.ppd /usr/lib/cups/filter/pdftopdf 1 debian '' 1 '' <1605427739.pdf >my_print_step_1.pdf /usr/lib/cups/filter/gstoraster 1 debian '' 1 '' <my_print_step_1.pdf >my_print_step_2.raster /usr/lib/cups/filter/hpcups 1 debian '' 1 '' <my_print_step_2.raster >my_print_step_3.hpcups benutzer@debian:~/974828$ /usr/lib/cups/filter/hpcups 1 debian '' 1 '' <my_print_step_2.raster >my_print_step_3.hpcups STATE: -marker-supply-low-warning PAGE: 1 1 PAGE: 2 1 free(): invalid next size (normal) Abgebrochen (Speicherabzug geschrieben) root@debian:~# coredumpctl list TIME PID UID GID SIG COREFILE EXE Fri 2021-02-26 05:48:46 CET 4520 1000 1000 6 present /usr/lib/cups/filter/hpcups root@debian:~# coredumpctl gdb 4520 PID: 4520 (hpcups) UID: 1000 (benutzer) GID: 1000 (benutzer) Signal: 6 (ABRT) Timestamp: Fri 2021-02-26 05:48:46 CET (2min 21s ago) Command Line: /usr/lib/cups/filter/hpcups 1 debian 1 Executable: /usr/lib/cups/filter/hpcups Control Group: /user.slice/user-1000.slice/session-3.scope Unit: session-3.scope Slice: user-1000.slice Session: 3 Owner UID: 1000 (benutzer) Boot ID: bbc7b40a5b0549bc8f275b755e0fc7b7 Machine ID: 33f18f39d2a9438eb75b0ed52848afcd Hostname: debian Storage: /var/lib/systemd/coredump/core.hpcups.1000.bbc7b40a5b0549bc8f275b755e0fc7b7.4520.1614314926000000.zst Message: Process 4520 (hpcups) of user 1000 dumped core. Stack trace of thread 4520: #0 0x00007f530d66ace1 raise (libc.so.6 + 0x3bce1) #1 0x00007f530d654537 abort (libc.so.6 + 0x25537) #2 0x00007f530d6ad768 n/a (libc.so.6 + 0x7e768) #3 0x00007f530d6b4a5a n/a (libc.so.6 + 0x85a5a) #4 0x00007f530d6b5f2c n/a (libc.so.6 + 0x86f2c) #5 0x000055c2847f55c6 n/a (hpcups + 0x85c6) #6 0x000055c2847f7e1b n/a (hpcups + 0xae1b) #7 0x00007f530d655d0a __libc_start_main (libc.so.6 + 0x26d0a) #8 0x000055c2847f4efa n/a (hpcups + 0x7efa) ... Core was generated by `/usr/lib/cups/filter/hpcups 1 debian 1 '. Program terminated with signal SIGABRT, Aborted. #0 __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50 50 ../sysdeps/unix/sysv/linux/raise.c: Datei oder Verzeichnis nicht gefunden. (gdb) bt #0 __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50 #1 0x00007f530d654537 in __GI_abort () at abort.c:79 #2 0x00007f530d6ad768 in __libc_message (action=action@entry=do_abort, fmt=fmt@entry=0x7f530d7bbe31 "%s\n") at ../sysdeps/posix/libc_fatal.c:155 #3 0x00007f530d6b4a5a in malloc_printerr (str=str@entry=0x7f530d7be258 "free(): invalid next size (normal)") at malloc.c:5347 #4 0x00007f530d6b5f2c in _int_free (av=0x7f530d7edb80 <main_arena>, p=0x55c284b3f840, have_lock=<optimized out>) at malloc.c:4322 #5 0x000055c2847f55c6 in ?? () #6 0x000055c2847f7e1b in ?? () #7 0x00007f530d655d0a in __libc_start_main (main=0x55c2847f4e10, argc=6, argv=0x7ffd61e19d78, init=<optimized out>, fini=<optimized out>, rtld_fini=<optimized out>, stack_end=0x7ffd61e19d68) at ../csu/libc-start.c:308 #8 0x000055c2847f4efa in ?? () (gdb) (gdb) bt #0 __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50 #1 0x00007f530d654537 in __GI_abort () at abort.c:79 #2 0x00007f530d6ad768 in __libc_message (action=action@entry=do_abort, fmt=fmt@entry=0x7f530d7bbe31 "%s\n") at ../sysdeps/posix/libc_fatal.c:155 #3 0x00007f530d6b4a5a in malloc_printerr (str=str@entry=0x7f530d7be258 "free(): invalid next size (normal)") at malloc.c:5347 #4 0x00007f530d6b5f2c in _int_free (av=0x7f530d7edb80 <main_arena>, p=0x55c284b3f840, have_lock=<optimized out>) at malloc.c:4322 #5 0x000055c2847f55c6 in HPCupsFilter::cleanup (this=this@entry=0x55c2848581c0 <filter>) at prnt/hpcups/HPCupsFilter.cpp:227 #6 0x000055c2847f7e1b in HPCupsFilter::closeFilter (this=0x55c2848581c0 <filter>) at prnt/hpcups/HPCupsFilter.cpp:221 #7 HPCupsFilter::StartPrintJob (this=0x55c2848581c0 <filter>, argc=<optimized out>, argv=0x7ffd61e19d78) at prnt/hpcups/HPCupsFilter.cpp:617 #8 0x00007f530d655d0a in __libc_start_main (main=0x55c2847f4e10 <main(int, char**)>, argc=6, argv=0x7ffd61e19d78, init=<optimized out>, fini=<optimized out>, rtld_fini=<optimized out>, stack_end=0x7ffd61e19d68) at ../csu/libc-start.c:308 #9 0x000055c2847f4efa in _start () benutzer@debian:~/974828$ valgrind /usr/lib/cups/filter/hpcups 1 debian '' 1 '' <my_print_step_2.raster >my_print_step_3.hpcups ==84343== Memcheck, a memory error detector ==84343== Copyright (C) 2002-2017, and GNU GPL'd, by Julian Seward et al. ==84343== Using Valgrind-3.16.1 and LibVEX; rerun with -h for copyright info ==84343== Command: /usr/lib/cups/filter/hpcups 1 debian 1 ==84343== STATE: -marker-supply-low-warning PAGE: 1 1 PAGE: 2 1 ==84343== Syscall param read(buf) points to unaddressable byte(s) ==84343== at 0x49F404E: read (read.c:26) ==84343== by 0x492000C: UnknownInlinedFun (unistd.h:44) ==84343== by 0x492000C: cups_read_fd (raster-stubs.c:323) ==84343== by 0x491F33F: cups_raster_io (raster-stream.c:1372) ==84343== by 0x491F33F: _cupsRasterReadPixels (raster-stream.c:782) ==84343== by 0x1126E7: HPCupsFilter::processRasterData(_cups_raster_s*) (HPCupsFilter.cpp:758) ==84343== by 0x112DE8: HPCupsFilter::StartPrintJob(int, char**) (HPCupsFilter.cpp:597) ==84343== by 0x4C18D09: (below main) (libc-start.c:308) ==84343== Address 0x5af9bd4 is 0 bytes after a block of size 11,140 alloc'd ==84343== at 0x483950F: operator new[](unsigned long) (vg_replace_malloc.c:431) ==84343== by 0x111BE8: HPCupsFilter::startPage(cups_page_header2_s*) (HPCupsFilter.cpp:500) ==84343== by 0x112792: HPCupsFilter::processRasterData(_cups_raster_s*) (HPCupsFilter.cpp:668) ==84343== by 0x112DE8: HPCupsFilter::StartPrintJob(int, char**) (HPCupsFilter.cpp:597) ==84343== by 0x4C18D09: (below main) (libc-start.c:308) ==84343== ==84343== ==84343== HEAP SUMMARY: ==84343== in use at exit: 18,040 bytes in 5 blocks ==84343== total heap usage: 2,179 allocs, 2,174 frees, 938,220 bytes allocated ==84343== ==84343== LEAK SUMMARY: ==84343== definitely lost: 11,108 bytes in 2 blocks ==84343== indirectly lost: 0 bytes in 0 blocks ==84343== possibly lost: 0 bytes in 0 blocks ==84343== still reachable: 6,932 bytes in 3 blocks ==84343== suppressed: 0 bytes in 0 blocks ==84343== Rerun with --leak-check=full to see details of leaked memory ==84343== ==84343== For lists of detected and suppressed errors, rerun with: -s ==84343== ERROR SUMMARY: 1 errors from 1 contexts (suppressed: 0 from 0) echo 1 > /proc/sys/kernel/perf_event_paranoid benutzer@debian:~/974828$ rr record /usr/lib/cups/filter/hpcups 1 debian '' 1 '' <my_print_step_2.raster >my_print_step_3.hpcups STATE: -marker-supply-low-warning PAGE: 1 1 PAGE: 2 1 free(): invalid next size (normal) Abgebrochen benutzer@debian:~/974828$ rr ls cpu_lock hpcups-0 latest-trace benutzer@debian:~/974828$ rr ps hpcups-0 PID PPID EXIT CMD 4928 -- -6 /usr/lib/cups/filter/hpcups 1 debian 1 benutzer@debian:~/974828$ rr replay hpcups-0 directory /home/benutzer/source/glibc/orig/glibc-2.31/malloc directory /home/benutzer/source/cups/orig/cups-2.3.3op2/cups directory /home/benutzer/source/hplip/orig/hplip-3.20.11+dfsg0/prnt/hpcups set width 0 set pagination off display/i $pc cont bt reverse-finish 12345Xfree(): invalid next size (normal) Program received signal SIGABRT, Aborted. __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50 50 ../sysdeps/unix/sysv/linux/raise.c: Datei oder Verzeichnis nicht gefunden. (rr) bt #0 __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50 #1 0x00007f504d83e537 in __GI_abort () at abort.c:79 #2 0x00007f504d897768 in __libc_message (action=action@entry=do_abort, fmt=fmt@entry=0x7f504d9a5e31 "%s\n") at ../sysdeps/posix/libc_fatal.c:155 #3 0x00007f504d89ea5a in malloc_printerr (str=str@entry=0x7f504d9a8258 "free(): invalid next size (normal)") at malloc.c:5347 #4 0x00007f504d89ff2c in _int_free (av=0x7f504d9d7b80 <main_arena>, p=0x564615cb1c90, have_lock=<optimized out>) at malloc.c:4322 #5 0x00005646141d15c6 in HPCupsFilter::cleanup (this=this@entry=0x5646142341c0 <filter>) at prnt/hpcups/HPCupsFilter.cpp:227 #6 0x00005646141d3e1b in HPCupsFilter::closeFilter (this=0x5646142341c0 <filter>) at prnt/hpcups/HPCupsFilter.cpp:221 #7 HPCupsFilter::StartPrintJob (this=0x5646142341c0 <filter>, argc=<optimized out>, argv=0x7ffc2a13fd48) at prnt/hpcups/HPCupsFilter.cpp:617 #8 0x00007f504d83fd0a in __libc_start_main (main=0x5646141d0e10 <main(int, char**)>, argc=6, argv=0x7ffc2a13fd48, init=<optimized out>, fini=<optimized out>, rtld_fini=<optimized out>, stack_end=0x7ffc2a13fd38) at ../csu/libc-start.c:308 #9 0x00005646141d0efa in _start () (rr) when Current event: 1744 (rr) reverse-finish Run back to call of #0 __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50 Program received signal SIGABRT, Aborted. __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50 50 return ret; 1: x/i $pc => 0x7f504d854ce1 <__GI_raise+321>: mov 0x108(%rsp),%rax (rr) reverse-finish Run back to call of #0 __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50 0x00007f504d83e532 in __GI_abort () at abort.c:79 79 abort.c: Datei oder Verzeichnis nicht gefunden. 1: x/i $pc => 0x7f504d83e532 <__GI_abort+286>: call 0x7f504d854ba0 <__GI_raise> (rr) reverse-finish Run back to call of #0 0x00007f504d83e532 in __GI_abort () at abort.c:79 __libc_message (action=action@entry=do_abort, fmt=fmt@entry=0x7f504d9a5e31 "%s\n") at ../sysdeps/posix/libc_fatal.c:155 155 abort (); 1: x/i $pc => 0x7f504d897763 <__libc_message+595>: call 0x7f504d83e414 <__GI_abort> (rr) reverse-finish Run back to call of #0 __libc_message (action=action@entry=do_abort, fmt=fmt@entry=0x7f504d9a5e31 "%s\n") at ../sysdeps/posix/libc_fatal.c:155 0x00007f504d89ea55 in malloc_printerr (str=str@entry=0x7f504d9a8258 "free(): invalid next size (normal)") at malloc.c:5347 5347 __libc_message (do_abort, "%s\n", str); 1: x/i $pc => 0x7f504d89ea55 <malloc_printerr+21>: call 0x7f504d897510 <__libc_message> (rr) reverse-finish Run back to call of #0 0x00007f504d89ea55 in malloc_printerr (str=str@entry=0x7f504d9a8258 "free(): invalid next size (normal)") at malloc.c:5347 0x00007f504d89ff27 in _int_free (av=0x7f504d9d7b80 <main_arena>, p=0x564615cb1c90, have_lock=<optimized out>) at malloc.c:4322 4322 malloc_printerr ("free(): invalid next size (normal)"); 1: x/i $pc => 0x7f504d89ff27 <_int_free+1543>: call 0x7f504d89ea40 <malloc_printerr> (rr) list 4317 malloc_printerr ("double free or corruption (!prev)"); 4318 4319 nextsize = chunksize(nextchunk); 4320 if (__builtin_expect (chunksize_nomask (nextchunk) <= 2 * SIZE_SZ, 0) 4321 || __builtin_expect (nextsize >= av->system_mem, 0)) 4322 malloc_printerr ("free(): invalid next size (normal)"); 4323 4324 free_perturb (chunk2mem(p), size - 2 * SIZE_SZ); 4325 4326 /* consolidate backward */ (rr) print nextchunk $1 = (mchunkptr) 0x564615cb4820 (rr) print/x nextsize $2 = 0xfffffffffffffff8 (rr) print av->system_mem $3 = 454656 (rr) print/x av->system_mem $4 = 0x6f000 (rr) display nextsize 2: nextsize = 18446744073709551608 (rr) undisp 2 (rr) display/x nextsize 3: /x nextsize = 0xfffffffffffffff8 (rr) reverse-stepi 4322 malloc_printerr ("free(): invalid next size (normal)"); 1: x/i $pc => 0x7f504d89ff20 <_int_free+1536>: lea 0x108331(%rip),%rdi # 0x7f504d9a8258 3: /x nextsize = 0xfffffffffffffff8 (rr) 0x00007f504d89fadd 4321 || __builtin_expect (nextsize >= av->system_mem, 0)) 1: x/i $pc => 0x7f504d89fadd <_int_free+445>: jbe 0x7f504d89ff20 <_int_free+1536> 3: /x nextsize = 0xfffffffffffffff8 (rr) 0x00007f504d89fad6 4321 || __builtin_expect (nextsize >= av->system_mem, 0)) 1: x/i $pc => 0x7f504d89fad6 <_int_free+438>: cmp %r14,0x888(%rbp) 3: /x nextsize = 0xfffffffffffffff8 (rr) 0x00007f504d89fad0 4320 if (__builtin_expect (chunksize_nomask (nextchunk) <= 2 * SIZE_SZ, 0) 1: x/i $pc => 0x7f504d89fad0 <_int_free+432>: jbe 0x7f504d89ff20 <_int_free+1536> 3: /x nextsize = 0xfffffffffffffff8 (rr) 4320 if (__builtin_expect (chunksize_nomask (nextchunk) <= 2 * SIZE_SZ, 0) 1: x/i $pc => 0x7f504d89facc <_int_free+428>: cmp $0x10,%rax 3: /x nextsize = 0xfffffffffffffff8 (rr) info reg rax 0xffffffffffffffff -1 rbx 0x2b90 11152 rcx 0x564615c5c010 94859012980752 rdx 0x13c50 80976 rsi 0x564615cb1c90 94859013332112 rdi 0x7f504d9d7b80 139982876277632 rbp 0x7f504d9d7b80 0x7f504d9d7b80 <main_arena> rsp 0x7ffc2a13fb40 0x7ffc2a13fb40 r8 0x0 0 r9 0x5 5 r10 0x7f504ddb6110 139982880334096 r11 0x7f504d8a3720 139982875014944 r12 0x564615cb1c90 94859013332112 r13 0x564615cb4820 94859013343264 r14 0xfffffffffffffff8 -8 r15 0x5646142348b0 94858985556144 rip 0x7f504d89facc 0x7f504d89facc <_int_free+428> eflags 0x282 [ SF IF ] cs 0x33 51 ss 0x2b 43 ds 0x0 0 es 0x0 0 fs 0x0 0 gs 0x0 0 fs_base 0x7f504cbe0400 0x7f504cbe0400 gs_base 0x0 0x0 (rr) reverse-stepi 0x00007f504d89fac8 4319 nextsize = chunksize(nextchunk); 1: x/i $pc => 0x7f504d89fac8 <_int_free+424>: and $0xfffffffffffffff8,%r14 3: /x nextsize = <optimized out> (rr) display/x $r14 4: /x $r14 = 0xffffffffffffffff (rr) reverse-stepi 4319 nextsize = chunksize(nextchunk); 1: x/i $pc => 0x7f504d89fac5 <_int_free+421>: mov %rax,%r14 3: /x nextsize = <optimized out> 4: /x $r14 = 0x0 (rr) undisp 4 (rr) display/x $rax 5: /x $rax = 0xffffffffffffffff (rr) reverse-stepi 0x00007f504d89fabf 4316 if (__glibc_unlikely (!prev_inuse(nextchunk))) 1: x/i $pc => 0x7f504d89fabf <_int_free+415>: je 0x7f504d8a0090 <_int_free+1904> 3: /x nextsize = <optimized out> 5: /x $rax = 0xffffffffffffffff (rr) 0x00007f504d89fabd 4316 if (__glibc_unlikely (!prev_inuse(nextchunk))) 1: x/i $pc => 0x7f504d89fabd <_int_free+413>: test $0x1,%al 3: /x nextsize = <optimized out> 5: /x $rax = 0xffffffffffffffff (rr) 4316 if (__glibc_unlikely (!prev_inuse(nextchunk))) 1: x/i $pc => 0x7f504d89fab9 <_int_free+409>: mov 0x8(%r13),%rax 3: /x nextsize = <optimized out> 5: /x $rax = 0x564615ccb000 (rr) undisp 5 (rr) x/1xg $r13 + 0x8 0x564615cb4828: 0xffffffffffffffff (rr) watch *0x564615cb4828 Hardware watchpoint 1: *0x564615cb4828 (rr) reverse-cont Continuing. Hardware watchpoint 1: *0x564615cb4828 Old value = -1 New value = 16777215 0x00007f504dd88d43 in local_memcpy (n=19220, source=0x7f504cadd02e, dest=0x564615cb1ca0) at ./src/preload/syscallbuf.c:194 194 ./src/preload/syscallbuf.c: Datei oder Verzeichnis nicht gefunden. 1: x/i $pc => 0x7f504dd88d43 <sys_read+387>: rep movsb %ds:(%rsi),%es:(%rdi) (rr) bt #0 0x00007f504dd88d43 in local_memcpy (n=19220, source=0x7f504cadd02e, dest=0x564615cb1ca0) at ./src/preload/syscallbuf.c:194 #1 copy_output_buffer (buf2=0x7f504cadd02e, buf=0x564615cb1ca0, ptr=0x7f504cae1b42, ret_size=19220) at ./src/preload/syscallbuf.c:1135 #2 sys_read (call=call@entry=0x681fffa0) at ./src/preload/syscallbuf.c:2281 #3 0x00007f504dd89fd2 in syscall_hook_internal (call=0x681fffa0) at ./src/preload/syscallbuf.c:3223 #4 syscall_hook (call=0x681fffa0) at ./src/preload/syscallbuf.c:3329 #5 0x00007f504dd86270 in _syscall_hook_trampoline () at /build/rr-7fqooc/rr-5.4.0/src/preload/syscall_hook.S:313 #6 0x00007f504dd862cf in __morestack () at /build/rr-7fqooc/rr-5.4.0/src/preload/syscall_hook.S:458 #7 0x00007f504dd862ea in _syscall_hook_trampoline_48_3d_00_f0_ff_ff () at /build/rr-7fqooc/rr-5.4.0/src/preload/syscall_hook.S:469 #8 0x00007f504dbe0054 in __libc_read (fd=fd@entry=0, buf=buf@entry=0x564615cb1ca0, nbytes=nbytes@entry=19220) at ../sysdeps/unix/sysv/linux/read.c:26 #9 0x00007f504dcaa00d in read (__nbytes=19220, __buf=0x564615cb1ca0, __fd=0) at /usr/include/x86_64-linux-gnu/bits/unistd.h:44 #10 cups_read_fd (ctx=<optimized out>, buf=0x564615cb1ca0 '\377' <repeats 200 times>..., bytes=19220) at raster-stubs.c:323 #11 0x00007f504dca9340 in cups_raster_io (bytes=19220, buf=0x564615cb1ca0 '\377' <repeats 200 times>..., r=0x564615c8cd00) at raster-stream.c:1372 #12 _cupsRasterReadPixels (r=0x564615c8cd00, p=0x564615cb1ca0 '\377' <repeats 200 times>..., len=19220) at raster-stream.c:782 #13 0x00007f504dcaa1e5 in cupsRasterReadPixels (r=<optimized out>, p=<optimized out>, len=<optimized out>) at raster-stubs.c:228 #14 0x00005646141d36e8 in HPCupsFilter::processRasterData (this=this@entry=0x5646142341c0 <filter>, cups_raster=<optimized out>, cups_raster@entry=0x564615c8cd00) at prnt/hpcups/HPCupsFilter.cpp:758 #15 0x00005646141d3de9 in HPCupsFilter::StartPrintJob (this=0x5646142341c0 <filter>, argc=<optimized out>, argv=0x7ffc2a13fd48) at prnt/hpcups/HPCupsFilter.cpp:597 #16 0x00007f504d83fd0a in __libc_start_main (main=0x5646141d0e10 <main(int, char**)>, argc=6, argv=0x7ffc2a13fd48, init=<optimized out>, fini=<optimized out>, rtld_fini=<optimized out>, stack_end=0x7ffc2a13fd38) at ../csu/libc-start.c:308 #17 0x00005646141d0efa in _start () (rr) when Current event: 1235 (rr) b read Breakpoint 2 at 0x7f504d907e80: read. (5 locations) (rr) disa 1 (rr) reverse-cont Continuing. Breakpoint 2, __libc_read (fd=fd@entry=0, buf=buf@entry=0x564615cb1ca0, nbytes=nbytes@entry=19220) at ../sysdeps/unix/sysv/linux/read.c:26 26 return SYSCALL_CANCEL (read, fd, buf, nbytes); 1: x/i $pc => 0x7f504dbe0040 <__libc_read>: mov %fs:0x18,%eax (rr) reverse-finish Run back to call of #0 __libc_read (fd=fd@entry=0, buf=buf@entry=0x564615cb1ca0, nbytes=nbytes@entry=19220) at ../sysdeps/unix/sysv/linux/read.c:26 0x00007f504dcaa008 in read (__nbytes=19220, __buf=0x564615cb1ca0, __fd=0) at /usr/include/x86_64-linux-gnu/bits/unistd.h:44 44 return __read_alias (__fd, __buf, __nbytes); 1: x/i $pc => 0x7f504dcaa008 <cups_read_fd+24>: call 0x7f504dc7d740 <read@plt> (rr) Run till exit from #0 0x00007f504dcaa008 in read (__nbytes=19220, __buf=0x564615cb1ca0, __fd=0) at /usr/include/x86_64-linux-gnu/bits/unistd.h:44 Breakpoint 2, read (__nbytes=19220, __buf=0x564615cb1ca0, __fd=0) at /usr/include/x86_64-linux-gnu/bits/unistd.h:44 44 return __read_alias (__fd, __buf, __nbytes); 1: x/i $pc => 0x7f504dcaa000 <cups_read_fd+16>: mov %rbp,%rdx (rr) reverse-finish Run till exit from #0 read (__nbytes=19220, __buf=0x564615cb1ca0, __fd=0) at /usr/include/x86_64-linux-gnu/bits/unistd.h:44 cups_read_fd (ctx=<optimized out>, buf=0x564615cb1ca0 '\377' <repeats 200 times>..., bytes=19220) at raster-stubs.c:323 323 while ((count = read(fd, buf, bytes)) < 0) 1: x/i $pc => 0x7f504dca9ffc <cups_read_fd+12>: nopl 0x0(%rax) (rr) bt #0 cups_read_fd (ctx=<optimized out>, buf=0x564615cb1ca0 '\377' <repeats 200 times>..., bytes=19220) at raster-stubs.c:323 #1 0x00007f504dca9340 in cups_raster_io (bytes=19220, buf=0x564615cb1ca0 '\377' <repeats 200 times>..., r=0x564615c8cd00) at raster-stream.c:1372 #2 _cupsRasterReadPixels (r=0x564615c8cd00, p=0x564615cb1ca0 '\377' <repeats 200 times>..., len=19220) at raster-stream.c:782 #3 0x00007f504dcaa1e5 in cupsRasterReadPixels (r=<optimized out>, p=<optimized out>, len=<optimized out>) at raster-stubs.c:228 #4 0x00005646141d36e8 in HPCupsFilter::processRasterData (this=this@entry=0x5646142341c0 <filter>, cups_raster=<optimized out>, cups_raster@entry=0x564615c8cd00) at prnt/hpcups/HPCupsFilter.cpp:758 #5 0x00005646141d3de9 in HPCupsFilter::StartPrintJob (this=0x5646142341c0 <filter>, argc=<optimized out>, argv=0x7ffc2a13fd48) at prnt/hpcups/HPCupsFilter.cpp:597 #6 0x00007f504d83fd0a in __libc_start_main (main=0x5646141d0e10 <main(int, char**)>, argc=6, argv=0x7ffc2a13fd48, init=<optimized out>, fini=<optimized out>, rtld_fini=<optimized out>, stack_end=0x7ffc2a13fd38) at ../csu/libc-start.c:308 #7 0x00005646141d0efa in _start () (rr) when Current event: 1235 (rr) up #1 0x00007f504dca9340 in cups_raster_io (bytes=19220, buf=0x564615cb1ca0 '\377' <repeats 200 times>..., r=0x564615c8cd00) at raster-stream.c:1372 1372 count = (*r->iocb)(r->ctx, buf, bytes - (size_t)total); (rr) print buf $5 = (unsigned char *) 0x564615cb1ca0 '\377' <repeats 200 times>... (rr) print bytes - (size_t)total $6 = 19220 (rr) up #2 _cupsRasterReadPixels (r=0x564615c8cd00, p=0x564615cb1ca0 '\377' <repeats 200 times>..., len=19220) at raster-stream.c:782 782 if (cups_raster_io(r, p, len) < (ssize_t)len) (rr) print p $7 = (unsigned char *) 0x564615cb1ca0 '\377' <repeats 200 times>... (rr) print len $8 = 19220 (rr) up #3 0x00007f504dcaa1e5 in cupsRasterReadPixels (r=<optimized out>, p=<optimized out>, len=<optimized out>) at raster-stubs.c:228 228 return (_cupsRasterReadPixels(r, p, len)); (rr) print p $9 = <optimized out> (rr) print len $10 = <optimized out> (rr) up #4 0x00005646141d36e8 in HPCupsFilter::processRasterData (this=this@entry=0x5646142341c0 <filter>, cups_raster=<optimized out>, cups_raster@entry=0x564615c8cd00) at prnt/hpcups/HPCupsFilter.cpp:758 warning: Source file is more recent than executable. 758 cupsRasterReadPixels (cups_raster, m_pPrinterBuffer, cups_header.cupsBytesPerLine); (rr) print m_pPrinterBuffer $11 = (BYTE *) 0x564615cb1ca0 '\377' <repeats 200 times>... (rr) print cups_header.cupsBytesPerLine $12 = 19220 (rr) print &m_pPrinterBuffer $13 = (BYTE **) 0x5646142341c0 <filter> (rr) watch *0x5646142341c0 Hardware watchpoint 3: *0x5646142341c0 (rr) disa 2 (rr) reverse-cont Continuing. Hardware watchpoint 3: *0x5646142341c0 Old value = 365632672 New value = 0 0x00005646141d2be9 in HPCupsFilter::startPage (this=0x5646142341c0 <filter>, cups_header=0x7ffc2a13f080) at prnt/hpcups/HPCupsFilter.cpp:500 500 m_pPrinterBuffer = new BYTE[cups_header->cupsWidth * 4 + 32]; 1: x/i $pc => 0x5646141d2be9 <_ZN12HPCupsFilter9startPageEP19cups_page_header2_s+2329>: mov %rax,(%rbx) (rr) bt #0 0x00005646141d2be9 in HPCupsFilter::startPage (this=0x5646142341c0 <filter>, cups_header=0x7ffc2a13f080) at prnt/hpcups/HPCupsFilter.cpp:500 #1 0x00005646141d3793 in HPCupsFilter::processRasterData (this=this@entry=0x5646142341c0 <filter>, cups_raster=<optimized out>, cups_raster@entry=0x564615c8cd00) at prnt/hpcups/HPCupsFilter.cpp:668 #2 0x00005646141d3de9 in HPCupsFilter::StartPrintJob (this=0x5646142341c0 <filter>, argc=<optimized out>, argv=0x7ffc2a13fd48) at prnt/hpcups/HPCupsFilter.cpp:597 #3 0x00007f504d83fd0a in __libc_start_main (main=0x5646141d0e10 <main(int, char**)>, argc=6, argv=0x7ffc2a13fd48, init=<optimized out>, fini=<optimized out>, rtld_fini=<optimized out>, stack_end=0x7ffc2a13fd38) at ../csu/libc-start.c:308 #4 0x00005646141d0efa in _start () (rr) when Current event: 898 (rr) print cups_header->cupsWidth $14 = 2777 (rr) print cups_header->cupsWidth * 4 + 32 $15 = 11140 (rr) print cups_header.cupsBytesPerLine $16 = 11108 (rr) print &cups_header.cupsBytesPerLine $17 = (unsigned int *) 0x7ffc2a13f208 --> At the time of allocation cupsBytesPerLine == 11108, but at time of read it is 19220 (rr) watch *0x7ffc2a13f208 Hardware watchpoint 4: *0x7ffc2a13f208 (rr) disa 3 (rr) cont Hardware watchpoint 4: *0x7ffc2a13f208 Old value = 11108 New value = 19220 0x00007f504dcaa190 in memcpy (__len=1796, __src=0x564615c8cd1c, __dest=0x7ffc2a13f080) at /usr/include/x86_64-linux-gnu/bits/string_fortified.h:34 34 return __builtin___memcpy_chk (__dest, __src, __len, __bos0 (__dest)); 1: x/i $pc => 0x7f504dcaa190 <cupsRasterReadHeader2+80>: rep movsq %ds:(%rsi),%es:(%rdi) (rr) bt #0 0x00007f504dcaa190 in memcpy (__len=1796, __src=0x564615c8cd1c, __dest=0x7ffc2a13f080) at /usr/include/x86_64-linux-gnu/bits/string_fortified.h:34 #1 cupsRasterReadHeader2 (r=0x564615c8cd00, h=h@entry=0x7ffc2a13f080) at raster-stubs.c:209 #2 0x00005646141d356d in HPCupsFilter::processRasterData (this=this@entry=0x5646142341c0 <filter>, cups_raster=<optimized out>, cups_raster@entry=0x564615c8cd00) at prnt/hpcups/HPCupsFilter.cpp:661 #3 0x00005646141d3de9 in HPCupsFilter::StartPrintJob (this=0x5646142341c0 <filter>, argc=<optimized out>, argv=0x7ffc2a13fd48) at prnt/hpcups/HPCupsFilter.cpp:597 #4 0x00007f504d83fd0a in __libc_start_main (main=0x5646141d0e10 <main(int, char**)>, argc=6, argv=0x7ffc2a13fd48, init=<optimized out>, fini=<optimized out>, rtld_fini=<optimized out>, stack_end=0x7ffc2a13fd38) at ../csu/libc-start.c:308 #5 0x00005646141d0efa in _start () (rr) when Current event: 1230 (rr) disa 4 (rr) reverse-finish Run till exit from #0 0x00007f504dcaa190 in memcpy (__len=1796, __src=0x564615c8cd1c, __dest=0x7ffc2a13f080) at /usr/include/x86_64-linux-gnu/bits/string_fortified.h:34 cupsRasterReadHeader2 (r=0x564615c8cd00, h=h@entry=0x7ffc2a13f080) at raster-stubs.c:209 209 memcpy(h, &(r->header), sizeof(cups_page_header2_t)); 1: x/i $pc => 0x7f504dcaa182 <cupsRasterReadHeader2+66>: sub %rbx,%rsi (rr) print h->cupsBytesPerLine $20 = 11108 (rr) print h->cupsWidth $21 = 2777 (rr) print r->header->cupsBytesPerLine $22 = 19220 (rr) print r->header->cupsWidth $23 = 4805 (rr) up #1 0x00005646141d356d in HPCupsFilter::processRasterData (this=this@entry=0x5646142341c0 <filter>, cups_raster=<optimized out>, cups_raster@entry=0x564615c8cd00) at prnt/hpcups/HPCupsFilter.cpp:661 661 while (cupsRasterReadHeader2(cups_raster, &cups_header)) (rr) print m_pPrinterBuffer $24 = (BYTE *) 0x564615cb1ca0 '\377' <repeats 200 times>... dpkg-buildpackage dpkg -i hplip_3.20.11+dfsg0-2_amd64.deb hplip-data_3.20.11+dfsg0-2_all.deb hplip-dbgsym_3.20.11+dfsg0-2_amd64.deb libhpmud0_3.20.11+dfsg0-2_amd64.deb libsane-hpaio_3.20.11+dfsg0-2_amd64.deb printer-driver-hpcups_3.20.11+dfsg0-2_amd64.deb printer-driver-hpcups-dbgsym_3.20.11+dfsg0-2_amd64.deb printer-driver-postscript-hp_3.20.11+dfsg0-2_amd64.deb benutzer@debian:~/974828$ valgrind /usr/lib/cups/filter/hpcups 1 debian '' 1 '' <my_print_step_2.raster >my_print_step_3.hpcups ==123764== Memcheck, a memory error detector ==123764== Copyright (C) 2002-2017, and GNU GPL'd, by Julian Seward et al. ==123764== Using Valgrind-3.16.1 and LibVEX; rerun with -h for copyright info ==123764== Command: /usr/lib/cups/filter/hpcups 1 debian 1 ==123764== STATE: -marker-supply-low-warning PAGE: 1 1 PAGE: 2 1 ==123764== ==123764== HEAP SUMMARY: ==123764== in use at exit: 18,040 bytes in 5 blocks ==123764== total heap usage: 2,180 allocs, 2,175 frees, 957,472 bytes allocated ==123764== ==123764== LEAK SUMMARY: ==123764== definitely lost: 11,108 bytes in 2 blocks ==123764== indirectly lost: 0 bytes in 0 blocks ==123764== possibly lost: 0 bytes in 0 blocks ==123764== still reachable: 6,932 bytes in 3 blocks ==123764== suppressed: 0 bytes in 0 blocks ==123764== Rerun with --leak-check=full to see details of leaked memory ==123764== ==123764== For lists of detected and suppressed errors, rerun with: -s ==123764== ERROR SUMMARY: 0 errors from 0 contexts (suppressed: 0 from 0) benutzer@debian:~/974828$ ls -lisah insgesamt 382M 786802 4,0K drwxr-xr-x 2 benutzer benutzer 4,0K 26. Feb 11:37 . 791941 4,0K drwxr-xr-x 8 benutzer benutzer 4,0K 26. Feb 14:42 .. 788374 224K -rw-r--r-- 1 benutzer benutzer 224K 25. Feb 19:17 1605427739.pdf 788287 1,4M -rw-r--r-- 1 benutzer benutzer 1,4M 26. Feb 11:36 974828.tar.gz 788373 28K -rw-r--r-- 1 benutzer benutzer 28K 25. Feb 19:25 HP_Officejet_Pro_8610.ppd 793120 224K -rw-r--r-- 1 benutzer benutzer 224K 26. Feb 11:37 my_print_step_1.pdf 793121 190M -rw-r--r-- 1 benutzer benutzer 190M 26. Feb 11:37 my_print_step_2.raster 793122 396K -rw-r--r-- 1 benutzer benutzer 394K 26. Feb 15:12 my_print_step_3.hpcups 788376 224K -rw-r--r-- 1 benutzer benutzer 224K 25. Feb 19:25 print_step_1.pdf 788377 190M -rw-r--r-- 1 benutzer benutzer 190M 25. Feb 19:25 print_step_2.raster 788390 396K -rw-r--r-- 1 benutzer benutzer 394K 25. Feb 19:25 print_step_3.hpcups