Bug#974828: printer-driver-hpcups: SIGABRT with "free(): invalid next size (normal)" in HPCupsFilter::cleanup
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 <bernhardu@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
Reply to: