Package: printer-driver-cups-pdf
Version: 3.0.1-5
Severity: normal
The PDF driver is failing to write the output PDFs. For example, a
command like
echo foo | lp -d PDF
yields the following DEBUG output in the log:
Wed Jul 3 09:40:55 2019 [DEBUG] *** Final Configuration ***
Wed Jul 3 09:40:55 2019 [DEBUG] AnonDirName = "/var/spool/cups-pdf/ANONYMOUS"
Wed Jul 3 09:40:55 2019 [DEBUG] AnonUser = "nobody"
Wed Jul 3 09:40:55 2019 [DEBUG] GhostScript = "/usr/bin/gs"
Wed Jul 3 09:40:55 2019 [DEBUG] GSCall = "%s -q -dCompatibilityLevel=%s -dNOPAUSE -dBATCH -dSAFER -sDEVICE=pdfwrite -sOutputFile="%s" -dAutoRotatePages=/PageByPage -dAutoFilterColorImages=false -dColorImageFilter=/FlateEncode -dPDFSETTINGS=/prepress -c .setpdfwrite -f %s"
Wed Jul 3 09:40:55 2019 [DEBUG] Grp = "lpadmin"
Wed Jul 3 09:40:55 2019 [DEBUG] GSTmp = "TMPDIR=/var/tmp"
Wed Jul 3 09:40:55 2019 [DEBUG] Log = "/var/log/cups"
Wed Jul 3 09:40:55 2019 [DEBUG] PDFVer = "1.4"
Wed Jul 3 09:40:55 2019 [DEBUG] PostProcessing = ""
Wed Jul 3 09:40:55 2019 [DEBUG] Out = "${HOME}/PDF"
Wed Jul 3 09:40:55 2019 [DEBUG] Spool = "/var/spool/cups-pdf/SPOOL"
Wed Jul 3 09:40:55 2019 [DEBUG] UserPrefix = ""
Wed Jul 3 09:40:55 2019 [DEBUG] RemovePrefix = ""
Wed Jul 3 09:40:55 2019 [DEBUG] OutExtension = "pdf"
Wed Jul 3 09:40:55 2019 [DEBUG] Cut = -1
Wed Jul 3 09:40:55 2019 [DEBUG] Truncate = 256
Wed Jul 3 09:40:55 2019 [DEBUG] DirPrefix = 0
Wed Jul 3 09:40:55 2019 [DEBUG] Label = 0
Wed Jul 3 09:40:55 2019 [DEBUG] LogType = 4
Wed Jul 3 09:40:55 2019 [DEBUG] LowerCase = 1
Wed Jul 3 09:40:55 2019 [DEBUG] TitlePref = 1
Wed Jul 3 09:40:55 2019 [DEBUG] DecodeHexStrings = 1
Wed Jul 3 09:40:55 2019 [DEBUG] FixNewlines = 0
Wed Jul 3 09:40:55 2019 [DEBUG] AllowUnsafeOptions = 0
Wed Jul 3 09:40:55 2019 [DEBUG] AnonUMask = 0000
Wed Jul 3 09:40:55 2019 [DEBUG] UserUMask = 0077
Wed Jul 3 09:40:55 2019 [DEBUG] *** End of Configuration ***
Wed Jul 3 09:40:55 2019 [DEBUG] set new gid: lpadmin
Wed Jul 3 09:40:55 2019 [DEBUG] initialization finished: v3.0.1
Wed Jul 3 09:40:55 2019 [DEBUG] user identified: madduck
Wed Jul 3 09:40:55 2019 [DEBUG] output directory name generated: /home/ssd/madduck/PDF
Wed Jul 3 09:40:55 2019 [DEBUG] user information prepared
Wed Jul 3 09:40:55 2019 [DEBUG] spoolfile name created: /var/spool/cups-pdf/SPOOL/cups2pdf-8702
Wed Jul 3 09:40:55 2019 [DEBUG] source stream ready
Wed Jul 3 09:40:55 2019 [DEBUG] destination stream ready: /var/spool/cups-pdf/SPOOL/cups2pdf-8702
Wed Jul 3 09:40:55 2019 [DEBUG] owner set for spoolfile: /var/spool/cups-pdf/SPOOL/cups2pdf-8702
Wed Jul 3 09:40:55 2019 [DEBUG] using traditional fgets
Wed Jul 3 09:40:55 2019 [DEBUG] found beginning of postscript code: %!PS-Adobe-3.0
Wed Jul 3 09:40:55 2019 [DEBUG] now extracting postscript code
Wed Jul 3 09:40:55 2019 [DEBUG] found title in ps code: ((stdin))
madduck/PDF
Wed Jul 3 09:40:55 2019 [DEBUG] found end of postscript code: %%EOF
Wed Jul 3 09:40:55 2019 [DEBUG] all data written to spoolfile: /var/spool/cups-pdf/SPOOL/cups2pdf-8702
Wed Jul 3 09:40:55 2019 [DEBUG] trying to use commandline title:
Wed Jul 3 09:40:55 2019 [DEBUG] checking for hex strings:
Wed Jul 3 09:40:55 2019 [DEBUG] not a hex string, has no start marker:
Wed Jul 3 09:40:55 2019 [DEBUG] calling alternate_replace_string
Wed Jul 3 09:40:55 2019 [DEBUG] removing alternate special characters from title:
Wed Jul 3 09:40:55 2019 [DEBUG] empty commandline title, using PS title: ((stdin))
madduck/PDF
Wed Jul 3 09:40:55 2019 [DEBUG] checking for hex strings: ((stdin))
madduck/PDF
Wed Jul 3 09:40:55 2019 [DEBUG] not a hex string, has no start marker: ((stdin))
madduck/PDF
Wed Jul 3 09:40:55 2019 [DEBUG] calling alternate_replace_string
Wed Jul 3 09:40:55 2019 [DEBUG] removing alternate special characters from title: ((stdin))
madduck/PDF
Wed Jul 3 09:40:55 2019 [DEBUG] removing leading _ from title: __stdin___madduck_PDF
Wed Jul 3 09:40:55 2019 [DEBUG] title successfully retrieved: stdin___madduck_PDF
Wed Jul 3 09:40:55 2019 [DEBUG] input data read from stdin
Wed Jul 3 09:40:55 2019 [DEBUG] output filename created: /home/ssd/madduck/PDF/stdin___madduck_PDF.pdf
Wed Jul 3 09:40:55 2019 [DEBUG] ghostscript commandline built: /usr/bin/gs -q -dCompatibilityLevel=1.4 -dNOPAUSE -dBATCH -dSAFER -sDEVICE=pdfwrite -sOutputFile="/home/ssd/madduck/PDF/stdin___madduck_PDF.pdf" -dAutoRotatePages=/PageByPage -dAutoFilterColorImages=false -dColorImageFilter=/FlateEncode -dPDFSETTINGS=/prepress -c .setpdfwrite -f /var/spool/cups-pdf/SPOOL/cups2pdf-8702
Wed Jul 3 09:40:55 2019 [DEBUG] output file unlinked: /home/ssd/madduck/PDF/stdin___madduck_PDF.pdf
Wed Jul 3 09:40:55 2019 [DEBUG] TMPDIR set for GhostScript: /var/tmp
Wed Jul 3 09:40:55 2019 [DEBUG] waiting for child to exit
Wed Jul 3 09:40:55 2019 [DEBUG] entering child process
Wed Jul 3 09:40:55 2019 [DEBUG] GID set for current user
Wed Jul 3 09:40:55 2019 [DEBUG] supplementary groups set for current user
Wed Jul 3 09:40:55 2019 [DEBUG] UID set for current user: madduck
Wed Jul 3 09:40:55 2019 [DEBUG] ghostscript has finished: 256
Wed Jul 3 09:40:55 2019 [DEBUG] no postprocessing
Wed Jul 3 09:40:55 2019 [DEBUG] spoolfile unlinked: /var/spool/cups-pdf/SPOOL/cups2pdf-8702
Wed Jul 3 09:40:55 2019 [DEBUG] all memory has been freed
Not only is the output file unlinked right after the call to
/usr/bin/gs; This call itself also fails with a "permission denied"
error, according to strace:
[pid 2545] openat(AT_FDCWD, "/home/ssd/madduck/PDF/stdin___madduck_PDF.pdf", O_RDWR|O_CREAT|O_TRUNC, 0666) = -1 EACCES (Permission denied)
The target directory is 0700, but even changing it to 1777 doesn't
fix things.
Note that if I reduce the LogLevel to 3 in /etc/cups/cups-pdf.conf,
then the log output suggests that PDF creation is being successful,
after failing to set the file mode:
Wed Jul 3 09:44:00 2019 [ERROR] failed to set file mode for PDF file: /home/ssd/madduck/PDF/2019-07-03-094400-740472161-muttprint.pdf (non fatal)
Wed Jul 3 09:44:00 2019 [STATUS] PDF creation successfully finished for madduck
Again, using strace, the error derives from the following call to
chmod
[pid 2543] chmod("/home/ssd/madduck/PDF/stdin___madduck_PDF.pdf", 0600) = -1 ENOENT (No such file or directory)
which obviously fails, as the file has never been created, and it
was unlinked anyway.
Finally, please note that I have a second sid system, pretty much
identical to this one, with an identical cups-pdf.conf file, but
there, the PDF file is written just fine.
Also note that this used to work, but recently stopped working on
this machine. Unfortunately, I am unable to say what has changed
since then, as I didn't take note when the problem first appeared.
--
System Information:
Debian Release: 10.0
APT prefers unstable
APT policy: (500, 'unstable'), (1, 'experimental')
Architecture: amd64 (x86_64)
Foreign Architectures: i386
Kernel: Linux 4.19.0-4-amd64 (SMP w/8 CPU cores)
Kernel taint flags: TAINT_FIRMWARE_WORKAROUND
Locale: LANG=en_NZ, LC_CTYPE=en_NZ.UTF-8 (charmap=UTF-8), LANGUAGE=en_NZ:en (charmap=UTF-8)
Shell: /bin/sh linked to /bin/dash
Init: systemd (via /run/systemd/system)
LSM: AppArmor: enabled
Versions of packages printer-driver-cups-pdf depends on:
ii cups 2.2.10-6
ii cups-client 2.2.10-6
ii ghostscript 9.27~dfsg-2
ii libc6 2.28-10
ii libcups2 2.2.10-6
ii libpaper-utils 1.1.28
printer-driver-cups-pdf recommends no packages.
Versions of packages printer-driver-cups-pdf suggests:
pn system-config-printer <none>
--
Configuration Files:
/etc/cups/cups-pdf.conf changed:
Out ${HOME}/PDF
Truncate 256
Cut -1
TitlePref 1
Grp lpadmin
DecodeHexStrings 1
--
no debconf information
--
.''`. martin f. krafft <madduck@d.o> @martinkrafft
: :' : proud Debian developer
`. `'` http://people.debian.org/~madduck
`- Debian - when you have better things to do than fixing systems