Bernhard Übelacker wrote on 22/08/2020 13:33:
>
> sorry for the delay.
No problem at all.
> You wrote you recompiled - then I guess your build directory should
> also contain the libcups2-dbgsym and cups-daemon-dbgsym packages.
Yes. I'd already installed libcups2-dbgsym. I've now installed cups-daemon-dbgsym too.
> If you still get this crash, could you install these dbgsym packages
> from your build and recreate that backtrace in coredumpctl?
> A 'bt full' could contain some details too.
We're getting the crash 50-100 times a day on a weekday so no problem reproducing...
The "bt full" on a recent crash:
root@samba-prn-01:~# coredumpctl gdb 22744
PID: 22744 (cupsd)
UID: 0 (root)
GID: 0 (root)
Signal: 6 (ABRT)
Timestamp: Mon 2020-08-24 11:41:07 BST (3min 32s ago)
Command Line: /usr/sbin/cupsd -l
Executable: /usr/sbin/cupsd
Control Group: /system.slice/cups.service
Unit: cups.service
Slice: system.slice
Boot ID: e7b5643e81964f88b7b34a712caf323a
Machine ID: d5fab4a49a044739a79685e71c58019c
Hostname: samba-prn-01.graysofwestminster.co.uk
Storage: /var/lib/systemd/coredump/core.cupsd.0.e7b5643e81964f88b7b34a712caf323a.22744.1598265667000000.lz4
Message: Process 22744 (cupsd) of user 0 dumped core.
Stack trace of thread 22744:
#0 0x00007f4c25f2f7bb __GI_raise (libc.so.6)
#1 0x00007f4c25f1a535 __GI_abort (libc.so.6)
#2 0x00007f4c25f71508 __libc_message (libc.so.6)
#3 0x00007f4c25f77c1a malloc_printerr (libc.so.6)
#4 0x00007f4c25f7942c _int_free (libc.so.6)
#5 0x00007f4c260f543e n/a (libcups.so.2)
#6 0x00007f4c260f53a8 ippDelete (libcups.so.2)
#7 0x0000558e8fde4ce4 cupsdWriteClient (cupsd)
#8 0x0000558e8fe1ed37 cupsdDoSelect (cupsd)
#9 0x0000558e8fddc2f5 main (cupsd)
#10 0x00007f4c25f1c09b __libc_start_main (libc.so.6)
#11 0x0000558e8fddd5da _start (cupsd)
GNU gdb (Debian 8.2.1-2+b3) 8.2.1
Copyright (C) 2018 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.
Type "show copying" and "show warranty" for details.
This GDB was configured as "x86_64-linux-gnu".
Type "show configuration" for configuration details.
For bug reporting instructions, please see:
<http://www.gnu.org/software/gdb/bugs/>.
Find the GDB manual and other documentation resources online at:
<http://www.gnu.org/software/gdb/documentation/>.
For help, type "help".
Type "apropos word" to search for commands related to "word"...
Reading symbols from /usr/sbin/cupsd...Reading symbols from /usr/lib/debug/.build-id/6d/c083ea4548b510e5e2e225f09345d3ef998629.debug...done.
done.
[New LWP 22744]
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
Core was generated by `/usr/sbin/cupsd -l'.
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: No such file or directory.
(gdb) bnt full
Undefined command: "bnt". Try "help".
(gdb) bt full
#0 __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
set = {__val = {0, 1, 1023, 139965031776793, 140733120872449,
94070787803904, 94070787803904, 94070787803904, 94070787803904,
94070787803932, 94070787804927, 94070787803904, 94070787804927,
16322178772337255680, 140732327528640, 140732327528640}}
pid = <optimized out>
tid = <optimized out>
ret = <optimized out>
#1 0x00007f4c25f1a535 in __GI_abort () at abort.c:79
save_stage = 1
act = {__sigaction_handler = {sa_handler = 0x3000000030,
sa_sigaction = 0x3000000030}, sa_mask = {__val = {140732327529160,
140732327528912, 16322178772337255680, 94070792526160,
16322178772337255680, 0, 139965031440801, 209,
16322178772337255680, 208, 94070790887360, 94070790879152,
94070787745283, 140732327529024, 140732327529056,
140732327529312}}, sa_flags = -865858976, sa_restorer = 0x1000}
sigs = {__val = {32, 0 <repeats 15 times>}}
#2 0x00007f4c25f71508 in __libc_message (action=action@entry=do_abort,
fmt=fmt@entry=0x7f4c2607c28d "%s\n") at ../sysdeps/posix/libc_fatal.c:181
ap = {{gp_offset = 24, fp_offset = 0,
overflow_arg_area = 0x7ffecc640b70,
reg_save_area = 0x7ffecc640b00}}
fd = 2
list = <optimized out>
nlist = <optimized out>
cp = <optimized out>
written = <optimized out>
#3 0x00007f4c25f77c1a in malloc_printerr (
str=str@entry=0x7f4c2607a43b "free(): invalid pointer") at malloc.c:5341
No locals.
#4 0x00007f4c25f7942c in _int_free (av=<optimized out>, p=<optimized out>,
have_lock=<optimized out>) at malloc.c:4165
size = 4294967296
fb = <optimized out>
nextchunk = <optimized out>
nextsize = <optimized out>
nextinuse = <optimized out>
prevsize = <optimized out>
--Type <RET> for more, q to quit, c to continue without paging--c
bck = <optimized out>
fwd = <optimized out>
__PRETTY_FUNCTION__ = "_int_free"
#5 0x00007f4c260f543e in ipp_free_values (attr=attr@entry=0x558e903207d0, element=element@entry=0, count=1) at ipp.c:6324
i = <optimized out>
value = 0x558e903207f0
#6 0x00007f4c260f53a8 in ippDelete (ipp=0x558e90317170) at ipp.c:1755
attr = 0x558e903207d0
next = 0x558e902d2310
attr = <optimized out>
next = <optimized out>
#7 ippDelete (ipp=0x558e90317170) at ipp.c:1729
attr = <optimized out>
next = <optimized out>
#8 0x0000558e8fde4ce4 in cupsdWriteClient (con=0x558e90351530) at client.c:2563
bytes = <optimized out>
field_col = <optimized out>
bufptr = <optimized out>
bufend = <optimized out>
ipp_state = <optimized out>
#9 0x0000558e8fe1ed37 in cupsdDoSelect (timeout=<optimized out>) at select.c:485
i = <optimized out>
event = 0x7f4c247a9010
nfds = 1
fdptr = 0x558e902c1950
pfd = <optimized out>
count = <optimized out>
#10 0x0000558e8fddc2f5 in main (argc=<optimized out>, argv=<optimized out>) at main.c:847
i = 2
opt = <optimized out>
close_all = <optimized out>
disconnect = <optimized out>
fg = <optimized out>
run_as_child = <optimized out>
print_profile = <optimized out>
fds = 1
con = <optimized out>
job = <optimized out>
lis = <optimized out>
current_time = <optimized out>
activity = <optimized out>
senddoc_time = 1598265667
expire_time = 1598265667
report_time = 0
event_time = 1598265646
timeout = 1
limit = {rlim_cur = 524288, rlim_max = 524288}
action = {__sigaction_handler = {sa_handler = 0x558e8fdf34a0 <sigterm_handler>, sa_sigaction = 0x558e8fdf34a0 <sigterm_handler>}, sa_mask = {__val = {81920, 0 <repeats 15 times>}}, sa_flags = 0, sa_restorer = 0x0}
netif_time = 1598265627
service_idle_exit = 0
(gdb)
> Otherwise running cupsd within valgrind could also give some hints.
I'll see if I can do this. I'll have to schedule some down time so it won't be immediate (or possibly even quick).
> This bug might describe the same issue, unfortunately also without solution:
> https://bugs.launchpad.net/ubuntu/+source/cups/+bug/1846334
> https://bugs.launchpad.net/ubuntu/+source/cups/+bug/1826648
> https://marc.info/?l=openbsd-ports&m=157331902608071&w=2
The first two, certainly, look the same.
It might be coincident but both the launchpad bugs seems to be Samsung printers which is what we currently have. Could a bad PPD be causing this?
> https://sources.debian.org/src/cups/2.3.3-2/cups/ipp.c/#L1729
> https://sources.debian.org/src/cups/2.3.3-2/scheduler/client.c/#L2244
Looks like we're hitting the default part of the case statement that frees memory and then trying to free the invalid pointer:
https://sources.debian.org/src/cups/2.3.3-2/cups/ipp.c/#L6324
My C foo is insufficient to get much further than this I'm afraid.
Thanks.
Ronny
--
Ronny Adsetts
Technical Director
Amazing Internet Ltd, London
t: +44 20 8977 8943
w: www.amazinginternet.com
Registered office: 85 Waldegrave Park, Twickenham, TW1 4TJ
Registered in England. Company No. 4042957
Attachment:
signature.asc
Description: OpenPGP digital signature