Can't print to PDF using cups-pdf; used to work, now "failed to set file mode" printing as non-root

Question

Here's something really odd: something that used to work fine in Debian, and then broke, even without a dist-upgrade.

I used to be able to use the CUPS PDF virtual printer to print anything to a PDF file. Now, it doesn't work: nothing shows up in ~/PDF when I print as an ordinary user. If I log into the CUPS administration interface and use that to print a test page to the printer, though, it works; the PDF shows up nicely in ~root/PDF. But I want to be able to print to PDF as a non-root user...

/var/log/cups/cups-pdf_log has this to say:

Fri Feb  7 18:31:57 2014  [STATUS] ***Experimental Option: DecodeHexStrings
Fri Feb  7 18:31:57 2014  [ERROR] failed to set file mode for PDF file (non fatal) (/michael/home/PDF/PDF_-_CUPS_1_5.pdf)
Fri Feb  7 18:31:57 2014  [STATUS] PDF creation successfully finished (michael)

OK, so there's failed to set file mode for PDF file. Googling for that, however, doesn't help much. I did find one web page that suggested changing the Out directory in /etc/cups/cups-pdf.conf, so I did (Out /tmp/${USER}.cups-pdf) and restarted CUPS, and when I try to print to PDF it picks up that change because it created such a directory, but then complained about the same error in the new location.

Despite seemingly being at the latest version (CUPS 1.5.3-5+deb7u1, CUPS-PDF 2.6.1-6, Debian Wheezy), I decided to reinstall CUPS just in case it had broken somehow.

sudo apt-get --reinstall -u install cups cups-pdf cups-bsd cups-client cups-common cups-driver-gutenprint cups-filters cups-pk-helper cups-ppdc

However, I am still getting the same error.

Setting LogType 7 in /etc/cups/cups-pdf.conf produces this:

Fri Feb  7 19:01:29 2014  [DEBUG] switching to new gid (lpadmin)
Fri Feb  7 19:01:29 2014  [DEBUG] initialization finished (v2.6.1)
Fri Feb  7 19:01:29 2014  [DEBUG] user identified (michael)
Fri Feb  7 19:01:29 2014  [DEBUG] output directory name generated (/tmp/michael.cups-pdf)
Fri Feb  7 19:01:29 2014  [DEBUG] user information prepared
Fri Feb  7 19:01:29 2014  [DEBUG] spoolfile name created (/var/spool/cups-pdf/SPOOL/cups2pdf-18015)
Fri Feb  7 19:01:29 2014  [DEBUG] source stream ready
Fri Feb  7 19:01:29 2014  [DEBUG] destination stream ready (/var/spool/cups-pdf/SPOOL/cups2pdf-18015)
Fri Feb  7 19:01:29 2014  [DEBUG] owner set for spoolfile (/var/spool/cups-pdf/SPOOL/cups2pdf-18015)
Fri Feb  7 19:01:29 2014  [DEBUG] using traditional fgets
Fri Feb  7 19:01:30 2014  [DEBUG] found beginning of postscript code (%!PS-Adobe-3.0)
Fri Feb  7 19:01:30 2014  [DEBUG] now extracting postscript code
Fri Feb  7 19:01:30 2014  [DEBUG] found title in ps code ((What does the CUPS PDF printer need to be able to set file mode? - Unix & Linux Stack Exchange))
Fri Feb  7 19:01:30 2014  [DEBUG] found end of postscript code (%%EOF)
Fri Feb  7 19:01:30 2014  [DEBUG] all data written to spoolfile (/var/spool/cups-pdf/SPOOL/cups2pdf-18015)
Fri Feb  7 19:01:30 2014  [DEBUG] trying to use PS title ((What does the CUPS PDF printer need to be able to set file mode? - Unix & Linux Stack Exchange))
Fri Feb  7 19:01:30 2014  [DEBUG] removing trailing newlines from title ((What does the CUPS PDF printer need to be able to set file mode? - Unix & Linux Stack Exchange))
Fri Feb  7 19:01:30 2014  [STATUS] ***Experimental Option: DecodeHexStrings
Fri Feb  7 19:01:30 2014  [DEBUG] checking for hex strings ((What does the CUPS PDF printer need to be able to set file mode? - Unix & Linux Stack Exchange))
Fri Feb  7 19:01:30 2014  [DEBUG] not a hex string, has no start marker ((What does the CUPS PDF printer need to be able to set file mode? - Unix & Linux Stack Exchange))
Fri Feb  7 19:01:30 2014  [DEBUG] removing enclosing parentheses () from full title ((What does the CUPS PDF printer need to be able to set file mode? - Unix & Linux Stack Exchange))
Fri Feb  7 19:01:30 2014  [DEBUG] calling alternate_replace_string
Fri Feb  7 19:01:30 2014  [DEBUG] removing alternate special characters from title (What does the CUPS PDF printer need to be able to set file mode? - Unix & Linux Stack Exchange)
Fri Feb  7 19:01:30 2014  [DEBUG] truncating title (What_does_the_CUPS_PDF_printer_need_to_be_able_to_set_file_mode_)
Fri Feb  7 19:01:30 2014  [DEBUG] title successfully retrieved (What_does_the_CUPS_PDF_printer_need_to_be_able_to_set_file_mode_)
Fri Feb  7 19:01:30 2014  [DEBUG] input data read from stdin
Fri Feb  7 19:01:30 2014  [DEBUG] output filename created (/tmp/michael.cups-pdf/What_does_the_CUPS_PDF_printer_need_to_be_able_to_set_file_mode_.pdf)
Fri Feb  7 19:01:30 2014  [DEBUG] ghostscript commandline built (/usr/bin/gs -q -dCompatibilityLevel=1.4 -dNOPAUSE -dBATCH -dSAFER -sDEVICE=pdfwrite -sOutputFile="/tmp/michael.cups-pdf/What_does_the_CUPS_PDF_printer_need_to_be_able_to_set_file_mode_.pdf" -dAutoRotatePages=/PageByPage -dAutoFilterColorImages=false -dColorImageFilter=/FlateEncode -dPDFSETTINGS=/prepress -c .setpdfwrite -f /var/spool/cups-pdf/SPOOL/cups2pdf-18015)
Fri Feb  7 19:01:30 2014  [DEBUG] output file unlinked (/tmp/michael.cups-pdf/What_does_the_CUPS_PDF_printer_need_to_be_able_to_set_file_mode_.pdf)
Fri Feb  7 19:01:30 2014  [DEBUG] TMPDIR set for GhostScript (/var/tmp)
Fri Feb  7 19:01:30 2014  [DEBUG] waiting for child to exit
Fri Feb  7 19:01:30 2014  [DEBUG] entering child process
Fri Feb  7 19:01:30 2014  [DEBUG] GID set for current user
Fri Feb  7 19:01:30 2014  [DEBUG] supplementary groups set for current user
Fri Feb  7 19:01:30 2014  [DEBUG] UID set for current user (michael)
Fri Feb  7 19:01:30 2014  [DEBUG] ghostscript has finished (256)
Fri Feb  7 19:01:30 2014  [ERROR] failed to set file mode for PDF file (non fatal) (/tmp/michael.cups-pdf/What_does_the_CUPS_PDF_printer_need_to_be_able_to_set_file_mode_.pdf)
Fri Feb  7 19:01:30 2014  [DEBUG] ERRNO: 2
Fri Feb  7 19:01:30 2014  [DEBUG] no postprocessing
Fri Feb  7 19:01:30 2014  [DEBUG] spoolfile unlinked (/var/spool/cups-pdf/SPOOL/cups2pdf-18015)
Fri Feb  7 19:01:30 2014  [DEBUG] all memory has been freed
Fri Feb  7 19:01:30 2014  [STATUS] PDF creation successfully finished (michael)

I do notice that it looks like Ghostscript is exiting with status 256 ([DEBUG] ghostscript has finished (256)), but I can't find anything that tells me why exactly it would exit with that error code.

My user account is not a member of the lp or lpadmin groups, but that hasn't changed.

Printing to the physical printer on my desk works fine; I did that just recently, long after printing to PDF started acting up like this.

What might be my problem?

Solution 1

Having Referred to the following post: https://ubuntuforums.org/showthread.php?t=1975881

After many research, in the end I found my problem was the permission of the folder /var/tmp/, it was 755 (drwxr-xr-x, root, root).

After changing it to 777 (drwxrwxrwx), cups-pdf works again ..

Because in the /etc/cups/cups-pdf.conf, it is indicating either /var/tmp or /tmp must be user-writable!

Solution 2

As you can see at this post: https://bugs.launchpad.net/ubuntu/+source/cups/+bug/270046/comments/28

SOLVED by the easiest way (Disabling cups apparmor profile)

Run these commands ...

sudo mv /etc/apparmor.d/usr.sbin.cupsd /etc/apparmor.d/disable
sudo /etc/init.d/apparmor restart

Solution 3

My users' home directories are in /local/home, so I had to change the line

@{HOMEDIRS}=/home/ /local/home/

in /etc/apparmor.d/tunables/home. Then restart apparmor with

sudo service apparmor restart

Comments

[Admin]

Hi Michael, did you figure this one out? If so, add an update.

[Admin]

@FaheemMitha Unfortunately, not yet.

[user]

CUPS created that directory a few attempts before that, with mode 0700. /tmp is 1777 (double-checked). See the paragraph just below the first log snippet.

[slm]

@MichaelKjörling - a potential lead: bugs.launchpad.net/ubuntu/+source/cupsys/+bug/147551. It's dated but looks like maybe an issue w/ apparmor?

[user]

Sorry, no apparmor installed at all here. So that's not it either.

[user]

Good idea, and probably well worth capturing in an answer here, but as I mentioned in this comment I don't have apparmor installed on my system.

[RalfFriedl]

How is this related to the question?

[Yamcha_Kippur]

His problem is right here. [ERROR] failed to set file mode for PDF file (non fatal) (/tmp/michael.cups-pdf/What_does_the_CUPS_PDF_printer_need_t‌​o_be_able_to_set_fil‌​e_mode_.pdf) I had the same problem and I solved it by changing ownership of the directory cups-pdf was trying to write to.

[user]

Generally, global temporary directories should be mode 1777 (rwxrwxrwt), not 0777. The sticky bit on a directory means that only the user who created a file can delete that file.

[eMPee584]

Thx! This was the relevant fix for our debian live distro, the live-boot scripts set the sticky bit only for /tmp; gonna submit a patch the other day..