On 3/6/25 05:17, Martin-Éric Racine wrote:
ke 5.3.2025 klo 21.06 Eric W. Bates (er...@ericx.net) kirjoitti:
On 3/3/25 09:34, Martin-Éric Racine wrote:
On Fri, 14 Jul 2023 13:46:22 -0400 "Eric W. Bates" <er...@ericx.net> wrote:
Package: printer-driver-cups-pdf
Version: 3.0.1-14
Severity: normal
Dear Maintainer,
*** Reporter, please consider answering these questions, where appropriate ***
* What led up to the situation?
* What exactly did you do (or not do) that was effective (or
ineffective)?
* What was the outcome of this action?
* What outcome did you expect instead?
*** End of the template - remove these template lines ***
Installed with apt.
Modified cups-pdf.conf to print to ${HOME}/tmp/cups-pdf
Attempt to print.
"Backend failed"
Increased cupsd.conf LogLevel to "debug"
Attempt to print.
"Backend failed"
Deleted PDF printer from cups
Forced reinstall of printer-driver-cups-pdf
Attempt to print.
"Backend failed"
Remove edit from cups-pdf.conf (e.g. back to default destination)
Attempt to print.
"Backend failed"
Attempt to find command line invocation in order to perhaps see a more useful
error message.
invoke:
# lpstat -p -d
printer isxerox-8145 is idle. enabled since Fri 14 Jul 2023 12:54:50 PM EDT
printer PDF is idle. enabled since Fri 14 Jul 2023 01:24:33 PM EDT
Backend failed
system default destination: PDF
Most information from /var/log/cups/error_log:
D [14/Jul/2023:12:59:27 -0400] [Job 7] PID 963955
(/usr/lib/cups/filter/pdftops) exited with no errors.
D [14/Jul/2023:12:59:27 -0400] [Job 7] PID 963956
(/usr/lib/cups/backend/cups-pdf) crashed on signal 11.
W [14/Jul/2023:12:59:27 -0400] [Job 7] Backend returned status -139 (crashed)
A little frustrating because there is so little information; but I will happily
execute anything you request.
Have you modified the AppArmor profile to match the path change? See
the NEWS and README for more info.
Martin-Éric
That's an excellent suggestion.
Where would I find NEWS or README?
I'm assuming they are part of the dpkg?
Found /usr/share/doc/printer-driver-cups-pdf/README.Debian (there is no
NEWS in the dpkg), and it does have a discussion of apparmor.
It says that if apparmor were the culprit, there would be messages in
dmesg 'audit[11578]: AVC apparmor="DENIED" ...' and there are no
messages from apparmor in dmesg at all other than things like "[
0.070165] AppArmor: AppArmor initialized"
I was trying to print to ~/tmp/cups-pdf/ and the existing apparmor
(/etc/apparmor.d/usr.sbin.cupsd) has an explicit allow for cups-pdf
already which looks like it should work:
# allow read and write on almost anything in @{HOME} (lenient, but
# private-files-strict is in effect), to support customized "Out"
# setting in cups-pdf.conf (Debian#940578)
#include <abstractions/private-files-strict>
@{HOME}/[^.]*/{,**/} rw,
@{HOME}/[^.]*/** rw,
I've also removed the "Out" in cups-pdf.conf and fallen back to the
default of /var/spool/cups-pdf/${USER} and there is still no output.
/var/spool/cups-pdf doesn't even get a folder with my account name.
There are no errors anywhere that I can find.
Now that we've ruled out any AppArmor issue, let's look at CUPS-PDF itself.
Please uncomment the following in /etc/cups/cups-pdf.conf and change
the value to 7:
LogType 3
This will produce tons of log info, but it should shed some light on
what causes this.
Martin-Éric
I incremented the log flag in /etc/cups/cups-pdf.conf to 7. Attempted
another PDF print job and took a look at journalctl -u cups; but there
is nothing about cups-pdf in there (cups restarts at midnight?):
Mar 06 00:00:00 ericx-office2 systemd[1]: cups.service: Deactivated
successfully.
Mar 06 00:00:00 ericx-office2 systemd[1]: Stopped cups.service - CUPS
Scheduler.
Mar 06 00:00:00 ericx-office2 systemd[1]: cups.service: Consumed 1.178s
CPU time.
Mar 06 00:00:00 ericx-office2 systemd[1]: Starting cups.service - CUPS
Scheduler...
Mar 06 00:00:00 ericx-office2 systemd[1]: Started cups.service - CUPS
Scheduler.
Found /var/log/cups/cups-pdf_log; but it's empty.
Found references to cups-pdf in /var/log/cups/error_log and way at the
bottom there is a crash by /usr/lib/cups/backend/cups-pdf:
D [06/Mar/2025:00:00:00 -0500] Calling FindDeviceById(cups-PDF)
D [06/Mar/2025:00:00:00 -0500] FindDeviceById failed:
org.freedesktop.DBus.Error.ServiceUnknown:The name is not activatable
D [06/Mar/2025:00:00:00 -0500] Using profile ID "PDF-Gray..".
D [06/Mar/2025:00:00:00 -0500] Calling CreateProfile(PDF-Gray..,temp)
W [06/Mar/2025:00:00:00 -0500] CreateProfile failed:
org.freedesktop.DBus.Error.ServiceUnknown:The name is not activatable
D [06/Mar/2025:00:00:00 -0500] Using profile ID "PDF-RGB..".
D [06/Mar/2025:00:00:00 -0500] Calling CreateProfile(PDF-RGB..,temp)
W [06/Mar/2025:00:00:00 -0500] CreateProfile failed:
org.freedesktop.DBus.Error.ServiceUnknown:The name is not activatable
I [06/Mar/2025:00:00:00 -0500] Registering ICC color profiles for "PDF".
D [06/Mar/2025:00:00:00 -0500] Calling CreateDevice(cups-PDF,temp)
...
D [06/Mar/2025:00:00:00 -0500] [Client 1] POST /printers/PDF HTTP/1.1
D [06/Mar/2025:00:00:00 -0500] cupsdSetBusyState: newbusy="Active
clients and dirty files", busy="Dirty files"
D [06/Mar/2025:00:00:00 -0500] [Client 1] Read: status=200, state=6
D [06/Mar/2025:00:00:00 -0500] [Client 1] No authentication data provided.
D [06/Mar/2025:00:00:00 -0500] [Client 1] 2.0 Get-Printer-Attributes 5
D [06/Mar/2025:00:00:00 -0500] Get-Printer-Attributes
ipp://localhost/printers/PDF
D [06/Mar/2025:00:00:00 -0500] [Client 1] Returning IPP successful-ok
for Get-Printer-Attributes (ipp://localhost/printers/PDF) from localhost.
...
D [06/Mar/2025:09:08:03 -0500] Get-Printer-Attributes
ipp://localhost:631/printers/PDF
D [06/Mar/2025:09:08:03 -0500] [Client 3] Returning IPP successful-ok
for Get-Printer-Attributes (ipp://localhost:631/printers/PDF) from
localhost.
(above is repeated about 4 times)
...
D [06/Mar/2025:09:08:08 -0500] cupsdSetBusyState: newbusy="Active
clients and dirty files", busy="Active clients and dirty files"
I [06/Mar/2025:09:08:08 -0500] [Job 57] Adding end banner page "none".
I [06/Mar/2025:09:08:08 -0500] [Job 57] File of type application/pdf
queued by "ericx".
D [06/Mar/2025:09:08:08 -0500] [Job 57] hold_until=0
I [06/Mar/2025:09:08:08 -0500] [Job 57] Queued on "PDF" by "ericx".
D [06/Mar/2025:09:08:08 -0500] [Job 57] time-at-processing=1741270088
...
D [06/Mar/2025:09:08:08 -0500] [Job 57] pdftops - copying to temp print
file \"/var/spool/cups/tmp/217ba67cc4fc8\"
D [06/Mar/2025:09:08:08 -0500] [Job 57] pdftopdf: Last filter determined
by the PPD: None; FINAL_CONTENT_TYPE: application/vnd.cups-postscript =>
pdftopdf will not log pages in page_log.
D [06/Mar/2025:09:08:08 -0500] [Job 57] PDF interactive form and
annotation flattening done via QPDF
D [06/Mar/2025:09:08:08 -0500] [Job 57] pdftopdf: \"print-scaling\" IPP
attribute: auto
D [06/Mar/2025:09:08:08 -0500] [Job 57] pdftopdf: Print scaling mode: Do
not scale, center, crop if needed
D [06/Mar/2025:09:08:08 -0500] [Job 57] After Cropping: 594.959961
841.919983 595.000000 842.000000
D [06/Mar/2025:09:08:08 -0500] [Job 57] PID 137145
(/usr/lib/cups/filter/pdftopdf) exited with no errors.
D [06/Mar/2025:09:08:08 -0500] [Job 57] Printer make and model: Generic
CUPS v1.1
D [06/Mar/2025:09:08:08 -0500] [Job 57] Running command line for pstops:
pstops 57 ericx \'WHOI Observium - coregw1.whoinet.whoi.edu - Settings\'
1 \'printer-state-reasons=none printer-is-accepting-jobs
Resolution=300dpi PageSize=A4 noprinter-is-shared printer-location=
marker-change-time=0 Duplex=None device-uri=cups-pdf:/ printer-state=3
printer-uri-supported=ipp://localhost/printers/PDF ColorModel=Grayscale
print-color-mode=color printer-type=10678348 pdftops-renderer=pdftocairo
printer-commands=AutoConfigure,Clean,PrintSelfTestPage
printer-state-change-time=1708103673 noprinter-is-temporary finishings=3
job-uuid=urn:uuid:abbc8b5d-f06f-379f-5380-014c427e9418
job-originating-host-name=localhost date-time-at-creation=
date-time-at-processing= time-at-creation=1741270088
time-at-processing=1741270088\'
D [06/Mar/2025:09:08:08 -0500] [Job 57] Using image rendering resolution
300 dpi
D [06/Mar/2025:09:08:08 -0500] [Job 57] Running command line for
pdftocairo: pdftocairo -ps -level2 -origpagesizes -nocenter -r 300
/var/spool/cups/tmp/217ba67cc4fc8 -
D [06/Mar/2025:09:08:08 -0500] [Job 57] Started filter pdftocairo (PID
137149)
D [06/Mar/2025:09:08:08 -0500] [Job 57] Started filter pstops (PID 137150)
...
D [06/Mar/2025:09:08:08 -0500] [Job 57] PID 137150 (pstops) exited with
no errors.
D [06/Mar/2025:09:08:08 -0500] [Job 57] PID 137149 (pdftocairo) exited
with no errors.
D [06/Mar/2025:09:08:08 -0500] [Job 57] PID 137146
(/usr/lib/cups/filter/pdftops) exited with no errors.
D [06/Mar/2025:09:08:08 -0500] [Job 57] PID 137147
(/usr/lib/cups/backend/cups-pdf) crashed on signal 11.
W [06/Mar/2025:09:08:08 -0500] [Job 57] Backend returned status -139
(crashed)
D [06/Mar/2025:09:08:08 -0500] cupsdMarkDirty(----S)
D [06/Mar/2025:09:08:08 -0500] cupsdSetBusyState: newbusy="Printing jobs
and dirty files", busy="Printing jobs and dirty files"
I [06/Mar/2025:09:08:08 -0500] [Job 57] Job held for 300 seconds since
it could not be sent.
