after upgrade to bionic, printing fails without explanation / logs / debuggability

Bug #1763520 reported by Steve Langasek on 2018-04-12
12
This bug affects 2 people
Affects Status Importance Assigned to Milestone
gtk+3.0 (Ubuntu)
High
Till Kamppeter
Bionic
High
Till Kamppeter
Cosmic
High
Till Kamppeter

Bug Description

[Impact]

The problem occurs when the printer's driver package is updated and with this the PPD is replaced and one of the default settings of the queue is not available any more in the new PPD file. Then the setting is prefixed with "Custom." and with this the jobs fail.

See comment #15 for more info.

[Test Case]

- Create a print queue with a PPD.
- evince an arbitrary PDF file
- Click the print icon
- In the print dialog choose the newly created queue and choose some uncommon paper size (not custom). Click "Print".
- Check /var/log/cups/error_log, the page size gets correctly received.
- Close evince.
- Stop CUPS, edit the PPD file (in /etc/cups/ppd/) removing the paper size you have selected for your job in the PageSize, PageRegion, PaperDimension, and ImageableArea lines.
- Start CUPS.
- Open the same PDF file again with evince, click Print and then select "Print" in the print dialog without changing anything.
- The job fails, in /var/log/cups/error_log you see that the page size is prefixed with "Custom.".

With the fixed package installed the job will print.

[Regression Potential]

The change applies only to saved settings of the print dialog not matching with any of the settings available in the PPD file. In rare cases the fix could fail by mis-understanding the setting and this way not being effective. For options which do not support setting custom values (the vast majority) the patch should always prevent a job failure though.

[Other Info]

Complete info about the bug and the fix in comment #15,

Original bug description:

I am unable to print to my network-attached printer after upgrade to bionic. ps shows:

lp 26047 0.0 0.0 91668 5756 ? S 15:06 0:00 \_ HP-ENVY-4500-new 473 vorlon USCIS Form I-9 1 print-content-optimize=auto print-rendering-intent=auto cupsPrintQuality=4 number-up=1 MediaType=Stationery noCollate print-scaling=auto PageSize=Custom.Letter.SM ColorModel=RGB Duplex=DuplexNoTumble job-uuid=urn:uuid:08c937ec-ccb6-3ff1-6ed4-212128e4257b job-originating-host-name=localhost date-time-at-creation= date-time-at-processing= time-at-creation=1523570792 time-at-processing=1523570792 print-quality=4
lp 26050 0.1 0.0 0 0 ? Z 15:06 0:00 | \_ [gs] <defunct>
lp 26048 0.0 0.0 79908 3836 ? S 15:06 0:00 \_ HP-ENVY-4500-new 473 vorlon USCIS Form I-9 1 print-content-optimize=auto print-rendering-intent=auto cupsPrintQuality=4 number-up=1 MediaType=Stationery noCollate print-scaling=auto PageSize=Custom.Letter.SM ColorModel=RGB Duplex=DuplexNoTumble job-uuid=urn:uuid:08c937ec-ccb6-3ff1-6ed4-212128e4257b job-originating-host-name=localhost date-time-at-creation= date-time-at-processing= time-at-creation=1523570792 time-at-processing=1523570792 print-quality=4
root 26049 0.0 0.0 84388 6192 ? S 15:06 0:00 \_ ipp://HP645106EA160E.local:631/ipp/print 473 vorlon USCIS Form I-9 1 print-content-optimize=auto print-rendering-intent=auto cupsPrintQuality=4 number-up=1 MediaType=Stationery noCollate print-scaling=auto PageSize=Custom.Letter.SM ColorModel=RGB Duplex=DuplexNoTumble job-uuid=urn:uuid:08c937ec-ccb6-3ff1-6ed4-212128e4257b job-originating-host-name=localhost date-time-at-creation= date-time-at-processing= time-at-creation=1523570792 time-at-processing=1523570792 print-quality=4

Note the un-reaped gs process.

ProblemType: Bug
DistroRelease: Ubuntu 18.04
Package: cups 2.2.7-1ubuntu2
ProcVersionSignature: Ubuntu 4.15.0-13.14-generic 4.15.10
Uname: Linux 4.15.0-13-generic x86_64
NonfreeKernelModules: zfs zunicode zavl icp zcommon znvpair
ApportVersion: 2.20.9-0ubuntu4
Architecture: amd64
CurrentDesktop: ubuntu:GNOME
Date: Thu Apr 12 15:07:49 2018
InstallationDate: Installed on 2010-09-24 (2757 days ago)
InstallationMedia: Ubuntu 10.04.1 LTS "Lucid Lynx" - Release amd64 (20100816.1)
MachineType: LENOVO 2306CTO
Papersize: letter
ProcKernelCmdLine: BOOT_IMAGE=/vmlinuz-4.15.0-13-generic.efi.signed root=/dev/mapper/hostname-root ro quiet splash vt.handoff=1
SourcePackage: cups
UpgradeStatus: Upgraded to bionic on 2018-03-21 (21 days ago)
dmi.bios.date: 10/25/2013
dmi.bios.vendor: LENOVO
dmi.bios.version: G2ET97WW (2.57 )
dmi.board.asset.tag: Not Available
dmi.board.name: 2306CTO
dmi.board.vendor: LENOVO
dmi.board.version: Not Defined
dmi.chassis.asset.tag: No Asset Information
dmi.chassis.type: 10
dmi.chassis.vendor: LENOVO
dmi.chassis.version: Not Available
dmi.modalias: dmi:bvnLENOVO:bvrG2ET97WW(2.57):bd10/25/2013:svnLENOVO:pn2306CTO:pvrThinkPadX230:rvnLENOVO:rn2306CTO:rvrNotDefined:cvnLENOVO:ct10:cvrNotAvailable:
dmi.product.family: ThinkPad X230
dmi.product.name: 2306CTO
dmi.product.version: ThinkPad X230
dmi.sys.vendor: LENOVO
modified.conffile..etc.cups.cupsd.conf: [inaccessible: [Errno 13] Permission denied: '/etc/cups/cupsd.conf']

Steve Langasek (vorlon) wrote :
Steve Langasek (vorlon) wrote :

The particular printer instance showing this failure is one that I've set up specifically in the course of trying to debug this (hence, '-new' in the queue name), but the problem exists also with my previously-existing queue.

Changed in cups (Ubuntu):
importance: Undecided → High
Changed in cups (Ubuntu):
assignee: nobody → Till Kamppeter (till-kamppeter)
Till Kamppeter (till-kamppeter) wrote :

Have you checked

https://wiki.ubuntu.com/DebuggingPrintingProblems

Especially follow the instructions of the section "CUPS error_log".

Changed in cups (Ubuntu):
status: New → Incomplete
Till Kamppeter (till-kamppeter) wrote :

Please run the command

ps auxwww | grep cups

and post the output here.

Till Kamppeter (till-kamppeter) wrote :

Please also attach your file /etc/cups/cupsd.conf.

Please attach files one by one, do not package them together and do not compress them.

Steve Langasek (vorlon) wrote :

debug error log attached. I believe the failed print job starts at 03/Jul/2018:12:22:01.

I've also discovered in the course of reproducing this that it appears to only be affecting jobs printed from evince, and not e.g. directly from chromium. I don't remember if I had tested printing directly from chromium before. So perhaps this is an evince bug rather than cups proper.

And this looks possibly relevant.
D [03/Jul/2018:12:22:01 -0700] [Job 489] Unrecoverable error: rangecheck in setpagedevice

Changed in cups (Ubuntu):
status: Incomplete → New
Till Kamppeter (till-kamppeter) wrote :

It seems that evince has supplied a wrong name for the paper size. See these two lines in the error_log:

[...]
D [03/Jul/2018:12:22:01 -0700] [Job 489] argv[5]="InputSlot=Auto number-up=1 MediaType=Plain PageSize=Custom.Letter.SM noCollate OutputMode=Normal ColorModel=RGB Duplex=DuplexNoTumble job-uuid=urn:uuid:a6bdd000-69b3-313b-6cfc-def9b98a0769 job-originating-host-name=localhost date-time-at-creation= date-time-at-processing= time-at-creation=1530645721 time-at-processing=1530645721"
[...]
D [03/Jul/2018:12:22:01 -0700] [Job 489] Ghostscript command line: gs -dQUIET -dPARANOIDSAFER -dNOPAUSE -dBATCH -dNOINTERPOLATE -dNOMEDIAATTRS -dShowAcroForm -sstdout=%stderr -sOutputFile=%stdout -sDEVICE=cups -sMediaType=Plain -sOutputType=0 -dDuplex -r600x300 -dMediaPosition=7 -dDEVICEWIDTHPOINTS=0 -dDEVICEHEIGHTPOINTS=0 -dcupsBitsPerColor=8 -dcupsColorOrder=0 -dcupsColorSpace=17 -scupsPageSizeName=Custom -I/usr/share/cups/fonts -c -f -_
[...]

The client has sent the job with a "PageSize=Custom.Letter.SM" attribute and it should have used "Letter.SM". In the second line you see that in the Ghostscript command line zero got inserted for the width and the height of the page, due to the broken page size name.

This is a bug of the client. As it occurs with evince it is most probably the print dialog of GTK. Adding GTK task ...

affects: cups (Ubuntu) → cups-filters (Ubuntu)
Changed in gtk+3.0 (Ubuntu):
importance: Undecided → High
Changed in cups-filters (Ubuntu):
importance: High → Low
Till Kamppeter (till-kamppeter) wrote :

Turned cups task into cups-filters as one could improve the filters by putting an error message into error_log if the page size name is not correct.

Till Kamppeter (till-kamppeter) wrote :

Steve, which page size did you select when printing from evince?

Can you also attach the PDF file which fails to print from evince?

Steve Langasek (vorlon) wrote :

> Steve, which page size did you select when printing from evince?

I did not choose a page size. I used the defaults, which should have been US Letter, as my locale is en_US.UTF-8 and my printer was purchased in the US, and the files to be printed are formatted as US Letter.

In the printer properties, this is displayed as Printer Options -> Media Size: Letter 8.5x11in

> Can you also attach the PDF file which fails to print from evince?

Here is a link to an example file which fails to print in this way. https://eforms.state.gov/Forms/ds82.pdf

I see as the only problem here that jobs are submitted with PageSize=Custom.Letter.SM (and not PageSize=Letter.SM). This is most probably a problem of the GTK print dialog.

Changed in cups-filters (Ubuntu):
status: New → Invalid
Steve Langasek (vorlon) wrote :

I went into evince's printer settings, and found that under 'Page Setup', the 'Paper size' had been set to something named 'Letter small borders' or similar. So it looks like the severity of the bug could reasonably reduced since at some point in the past there WAS a user non-default configuration that triggered this error, and it's not reproducible by default on bionic if you're just using US Letter as your paper size. Nevertheless it still means that after upgrade, a gtk printer config that was valid ceases to be valid with no obvious explanation why.

Steve Langasek (vorlon) wrote :

BTW when I say it was named 'something like [...]', after I changed the paper size to US Letter and confirmed that printing now worked, I went back into the dialog and the original paper size name had disappeared.

Then the bug is that the GTK print dialog in the case that the page size saved from the last session is an invalid one, prefixes it with "Custom.", which is completely wrong. What it should do is removing the saved wrong size and return to the printer's system default size.

"Custom." should only appear in the syntax "Custom.[WIDTH]x[HEIGHT][UNIT]" where [UNIT] is optional and not supplying it makes PostScript points (1/72 inches) being used. Example: "Custom.21x29.7cm". Sending "Custom." followed by a name makes absolutely no sense and CUPS is not able to convert it into an actual size.

Changed in gtk+3.0 (Ubuntu):
status: New → Triaged

The attached patch fixes the bug.

If the GTK print dialog finds a choice for a print option (Page Size, Media Type, Resolution, Print Quality, ...) which is not under the currently available choices (according to the PPD file in /etc/cups/ppd/) it checks whether the option supports custom values and if so, it considers the value a custom value and prefixes it with "Custom." regardless of whether this is a valid custom value. This usually works, if the user types in a custom value in the print dialog, as the dialog provides the correct interface for a custom value for this option.

Now there is a case where this easily breaks:

The dialog saves the last settings (printer selection and option settings) which the user has used for printing so that the next time the app is opened and the document printed, the saved settings are used by default. Now let us choose a certain not that common paper size and print. Then we close the app and do a system update. The update contains a new version of our printer driver and one of the changes is that some paper sizes in the PPD get renamed. So the paper size name we have used for our last print job is not contained in the new PPD any more. Now we open the app again and print the document right away, without going through the options tabs of the print dialog and also not changing to another printer. The print dialog recovers the saved options including the (old) page size name. As the name does not match any page size name of the new PPD, the dialog prefixes it with "Custom." and sends off the job. The CUPS filters are not able to identify the paper size name and the job errors.

Reproducer:

- Create a print queue with a PPD.
- evince an arbitrary PDF file
- Click the print icon
- In the print dialog choose the newly created queue and choose some uncommon paper size (not custom). Click "Print".
- Check /var/log/cups/error_log, the page size gets correctly received.
- Close evince.
- Stop CUPS, edit the PPD file removing the paper size you have selected for your job in the PageSize, PageRegion, PaperDimension, and ImageableArea lines.
- Start CUPS.
- Open the same PDF file again with evince, click Print and then select "Print" in the print dialog without changing anything.
- The job fails, in /var/log/cups/error_log you see that the page size is prefixed with "Custom.".

With the attached patch the print dialog checks the syntax of the unknown option value and only if the syntax is correct for the particular option, "Custom." is added. In the case of a page size name this does not happen as a custom page size has to be specified as "Custom.XXXxYYY[unit]", like "Custom.21x29.7cm".

tags: added: patch
Sebastien Bacher (seb128) wrote :

@Till, did you try to upstream that patch?

No, not yet.

Sebastien Bacher (seb128) wrote :

@Till, k, can you add that to your todolist then?

Sebastien Bacher (seb128) wrote :

Thanks!

Changed in cups-filters (Ubuntu Bionic):
status: New → Invalid
Changed in cups-filters (Ubuntu Cosmic):
status: New → Invalid
Iain Lane (laney) on 2018-12-04
Changed in gtk+3.0 (Ubuntu):
assignee: nobody → Till Kamppeter (till-kamppeter)
Changed in gtk+3.0 (Ubuntu Bionic):
assignee: nobody → Till Kamppeter (till-kamppeter)
Changed in gtk+3.0 (Ubuntu Cosmic):
assignee: nobody → Till Kamppeter (till-kamppeter)

debdiff for disco.

debdiff for cosmic.

debdiff for bionic.

I have now added debdiffs for disco and for the SRUs. Please can someone with appropriate rights upload them? Thanks.

description: updated
Changed in gtk+3.0 (Ubuntu):
status: Triaged → In Progress
Changed in gtk+3.0 (Ubuntu Bionic):
status: New → In Progress
Changed in gtk+3.0 (Ubuntu Cosmic):
status: New → In Progress
Jeremy Bicha (jbicha) on 2019-01-29
no longer affects: cups-filters (Ubuntu Bionic)
no longer affects: cups-filters (Ubuntu Cosmic)
Changed in gtk+3.0 (Ubuntu Bionic):
importance: Undecided → High
Changed in gtk+3.0 (Ubuntu Cosmic):
importance: Undecided → High
no longer affects: cups-filters (Ubuntu)
tags: added: patch-forwarded-upstream

Updated the proposed patch for upstream according to their requirements.

As soon as the patch is incorporated upstream I will post the resulting patch here.

The patch got also merged into the 3.24 branch of GTK:

https://gitlab.gnome.org/GNOME/gtk/merge_requests/717

Here is an updated debdiff for gtk+3.0 in Ubuntu Disco. It is based on the current gtk_3.0 package of Disco with the patch of

https://gitlab.gnome.org/GNOME/gtk/merge_requests/717

applied, this patch exactly:

https://gitlab.gnome.org/GNOME/gtk/commit/8b85f38093ac7b22d7d34f634faf69dd607e942c.patch

Please sponsor the upload before Final Freeze this Thursday. Thanks.

Iain Lane (laney) wrote :

Thanks, but there's no need. We'll get it via 3.24.8 which I'm uploading now.

Sebastien Bacher (seb128) wrote :
Changed in gtk+3.0 (Ubuntu):
status: In Progress → Fix Committed
Launchpad Janitor (janitor) wrote :

This bug was fixed in the package gtk+3.0 - 3.24.8-1ubuntu1

---------------
gtk+3.0 (3.24.8-1ubuntu1) disco; urgency=medium

  * Merge with Debian. Remaining changes:
    + Install a settings.ini file to set our themes
    + Update debian/libgtk-3-0.symbols
    + debian/control.in and debian/tests/control (installed-tests):
      - Build-depend on adwaita-icon-theme-full for icon name check test
    + debian/control.in: Build-Depend on dh-sequence-translations
    + Ubuntu-specific patches:
      - 073_treeview_almost_fixed.patch
      - bzg_gtkcellrenderer_grabbing_modifier.patch
      - ubuntu_gtk_custom_menu_items.patch
      - print-dialog-show-options-of-remote-dnssd-printers.patch
      - uimanager-guard-against-nested-node-updates.patch
      - x-canonical-accel.patch
      - message-dialog-restore-traditional-look-on-unity.patch
      - 0001-gtk-reftest-Force-icon-theme-to-Adwaita.patch
      - restore_filechooser_typeaheadfind.patch
      - 0001-calendar-always-emit-day-selected-once.patch
      - 0001-gtkwindow-set-transparent-background-color.patch
      - unity-border-radius.patch
      - unity-headerbar-maximized-mode.patch

gtk+3.0 (3.24.8-1) experimental; urgency=medium

  * New upstream release
    + Color editor: don't warn if editing is cancelled
    + Always redraw on allocate - not doing so is not safe when any widget can
      have a background
    + Use GLSL 3.30 for shaders
    + Wayland: properly place window menus
    + GtkApplication: support session state changes in sandboxes, using the
      inhibit portal
    + Fix a problem with autostart notification
    + Places: Show loop devices as reported by gvfs
    + Print dialog, CUPS: Check unknown option values whether they are
      actually custom settings (LP: #1763520)
  * Refresh patches. debian/patches/018_gdkenumtypes.c_location.patch needed
    slight rebasing

 -- Iain Lane <email address hidden> Thu, 11 Apr 2019 11:18:54 +0100

Changed in gtk+3.0 (Ubuntu):
status: Fix Committed → Fix Released
tags: added: patch-accepted-upstream
removed: patch-forwarded-upstream
Iain Lane (laney) wrote :

Till, can you provide updated debdiffs and re-subscribe ubuntu-sponsors / ping someone on the desktop team when there's something to upload please?

Closing Cosmic task as Cosmic goes EOL in a month from now and Disco is available. In addition, the problem only occurs when updating from an older Ubuntu release. So it is recommended to generally update to Disco instead of to Cosmic and in case one updated to Cosmic getting this problem to update again to Disco.

Changed in gtk+3.0 (Ubuntu Cosmic):
status: In Progress → Won't Fix

Debdiff for Bionic SRU, using the patch from upstream.

Sebastien Bacher (seb128) wrote :

I've sponsored the uploaded to Bionic now

Changed in gtk+3.0 (Ubuntu Bionic):
status: In Progress → Fix Committed

Hello Steve, or anyone else affected,

Accepted gtk+3.0 into bionic-proposed. The package will build now and be available at https://launchpad.net/ubuntu/+source/gtk+3.0/3.22.30-1ubuntu4 in a few hours, and then in the -proposed repository.

Please help us by testing this new package. See https://wiki.ubuntu.com/Testing/EnableProposed for documentation on how to enable and use -proposed. Your feedback will aid us getting this update out to other Ubuntu users.

If this package fixes the bug for you, please add a comment to this bug, mentioning the version of the package you tested and change the tag from verification-needed-bionic to verification-done-bionic. If it does not fix the bug for you, please add a comment stating that, and change the tag to verification-failed-bionic. In either case, without details of your testing we will not be able to proceed.

Further information regarding the verification process can be found at https://wiki.ubuntu.com/QATeam/PerformingSRUVerification . Thank you in advance for helping!

N.B. The updated package will be released to -updates after the bug(s) fixed by this package have been verified and the package has been in -proposed for a minimum of 7 days.

tags: added: verification-needed verification-needed-bionic

All autopkgtests for the newly accepted gtk+3.0 (3.22.30-1ubuntu4) for bionic have finished running.
There have been regressions in tests triggered by the package. Please visit the sru report page and investigate the failures.

https://people.canonical.com/~ubuntu-archive/pending-sru.html#bionic

Lukasz, I do not see any problems with this package, neither on the

https://people.canonical.com/~ubuntu-archive/pending-sru.html#bionic

page nor on

https://people.canonical.com/~ubuntu-archive/proposed-migration/bionic/update_excuses.html

which are the regressions actually caused?

Iain Lane (laney) wrote :

seb128 retried apport/i386 and libreoffice/ppc64el, blaming "infrastructure issue[s]" (I don't see evidence of that; it seems like slightly flaky tests to me). They passed on the retry, and so I think you are OK for testing now.

Till, you or somebody else needs to verify this bug now.

(Seb, it's probably good to comment on the bug when doing things like retrying tests, btw, so that the uploader doesn't get confused. Ideally you'll monitor your retries and comment with the results, but at least saying that you've done it would be better than nothing.)

Jason Currie (jcurrie84) wrote :

I am experiencing this same problem in Linux Mint 19.1. After creating a print job, there is no response from the printer (it doesn't wake up or anything), there is no printing, but the only message in the error log is "CreateProfile failed: org.freedesktop.ColorManager.AlreadyExists:profile id \'MaisonLaser-Gray..\' already exists"

I was able to resolve this on another machine by removing Gutenprint and doing something else, but it was a while ago and I didn't keep notes.

Jason, the message you mention has nothing to do with the bug reported here, it is from the color management daemon and in no case prevents a job from printing. The bug reported here is about a problem of the GTK/GNOME print dialog not handling printer driver updates correctly. It only happens when a printer driver gets updated (can happen during a general system update or an upgrade to a new Ubuntu version). We need your error_log (in debug mode, see "CUPS error_log" on https://wiki.ubuntu.com/DebuggingPrintingProblems) to judge whether you are suffering this bug or something else.

description: updated

I have checked the gtk+3.0 SRU in bionic-proposed now and could reproduce the bug before updating and encountered correct behavior after the update. So I am marking this SRU as verified.

tags: added: verification-done verification-done-bionic
removed: verification-needed verification-needed-bionic
Launchpad Janitor (janitor) wrote :

This bug was fixed in the package gtk+3.0 - 3.22.30-1ubuntu4

---------------
gtk+3.0 (3.22.30-1ubuntu4) bionic; urgency=medium

  * debian/patches/print-dialog-check-cups-custom-options.patch:
    - Print dialog: Check whether an unknown option setting is actually a
      custom setting, patch from upstream (LP: #1763520, Upstream merge
      request: #434, #717).

 -- Till Kamppeter <email address hidden> Wed, 5 Jun 2019 15:46:01 +0200

Changed in gtk+3.0 (Ubuntu Bionic):
status: Fix Committed → Fix Released

The verification of the Stable Release Update for gtk+3.0 has completed successfully and the package has now been released to -updates. Subsequently, the Ubuntu Stable Release Updates Team is being unsubscribed and will not receive messages about this bug report. In the event that you encounter a regression using the package from -updates please report a new bug using ubuntu-bug and tag the bug report regression-update so we can easily find any regressions.

To post a comment you must log in.