Page MenuHomeSolus

Latest cups-filters package regression
Open, HighPublic

Description

Driverless printing stopped working with our Konica Minolta C-253 network printer after upgrading from 1.23.0-44-1-x86_64 to 1.25.1-45-1-x86_64.
I rolled back, it works again.
Here I posted logs etc. https://discuss.getsol.us/d/1901-printer-stopped-working-cups-browsed-problem/8

Event Timeline

logTom created this task.Aug 8 2019, 11:41 AM
JoshStrobl triaged this task as High priority.
JoshStrobl edited projects, added Software; removed Hardware.
JoshStrobl added subscribers: joebonrichie, JoshStrobl.

Assigning to kyrios as he was the last one to modify it. That being said, @joebonrichie shouldn't have been approving patches to begin with, that's for Core Team to do.

JoshStrobl moved this task from Backlog to Package Fixes on the Software board.Aug 8 2019, 11:50 AM
kyrios123 added a subscriber: brent.Aug 9 2019, 4:04 PM
 py  ~  4  systemctl status org.cups.cupsd.socket 
● org.cups.cupsd.socket - CUPS Scheduler
   Loaded: loaded (/usr/lib/systemd/system/org.cups.cupsd.socket; disabled; vendor preset: enabled)
   Active: active (running) since Fri 2019-08-09 17:56:22 CEST; 3min 10s ago
   Listen: /run/cups/cups.sock (Stream)
   CGroup: /system.slice/org.cups.cupsd.socket

Warning: Journal has been rotated since unit was started. Log output is incomplete or unavailable.
 py  ~  systemctl status org.cups.cupsd.service 
● org.cups.cupsd.service - CUPS Scheduler
   Loaded: loaded (/usr/lib/systemd/system/org.cups.cupsd.service; disabled; vendor preset: enabled)
   Active: active (running) since Fri 2019-08-09 17:56:22 CEST; 3min 13s ago
     Docs: man:cupsd(8)
 Main PID: 623 (cupsd)
   Status: "Scheduler is running..."
    Tasks: 1 (limit: 4915)
   Memory: 3.1M
   CGroup: /system.slice/org.cups.cupsd.service
           └─623 /usr/sbin/cupsd -l

Warning: Journal has been rotated since unit was started. Log output is incomplete or unavailable.
 py  ~  systemctl status org.cups.cupsd.path 
● org.cups.cupsd.path - CUPS Scheduler
   Loaded: loaded (/usr/lib/systemd/system/org.cups.cupsd.path; disabled; vendor preset: enabled)
   Active: active (waiting) since Fri 2019-08-09 17:56:22 CEST; 3min 18s ago

Warning: Journal has been rotated since unit was started. Log output is incomplete or unavailable.
 py  ~  systemctl status cups-browsed.service 
● cups-browsed.service - Make remote CUPS printers available locally
   Loaded: loaded (/usr/lib/systemd/system/cups-browsed.service; disabled; vendor preset: enabled)
   Active: active (running) since Fri 2019-08-09 17:56:22 CEST; 3min 25s ago
 Main PID: 627 (cups-browsed)
    Tasks: 3 (limit: 4915)
   Memory: 3.4M
   CGroup: /system.slice/cups-browsed.service
           └─627 /usr/sbin/cups-browsed

Warning: Journal has been rotated since unit was started. Log output is incomplete or unavailable.
 py  ~  

@logTom @brent any extra info about this issue?
Here all cups services are loaded & active.

Could check the status of cups-browsed after a fresh boot and let me know if it's active or failed. If it's active, could you try to see when it fails please?

brent added a comment.Aug 9 2019, 4:34 PM

Did a lot of research regarding a forum poster's cups problem. I've never seen this 'rotated' message, but many other parts of message I do recognize. Let me gather my research and report back.

brent added a comment.Aug 9 2019, 4:44 PM

from searches "No destination host name supplied by cups-browsed for printer" and "cups-browsed.service: Main process exited, code=exited, status=1/FAILURE."

Please skim enclosed notes with sources--the 'greatest hits' of my research. Hope one may see clues that I can't.

Thanks @brent but that doesn't answer my question

Also could anyone with the problem do this:

  • stop the cups-browsed service
  • edit the file (with sudo) /etc/cups/cups-browsed.conf and uncomment the line DebugLogging stderr
  • run sudo /usr/sbin/cups-browsed
  • copy/paste the output in a pastebin to share it with us

Yeah, I can provide that. It's kinda short, so I post it here:

sudo /usr/sbin/cups-browsed
Mon Aug 12 09:58:26 2019 Reading config: BrowseRemoteProtocols dnssd cups
Mon Aug 12 09:58:26 2019 Reading config: CreateIPPPrinterQueues All
Mon Aug 12 09:58:26 2019 No "Browse..." line at all, accept all servers ("BrowseOrder Deny,Allow").
Mon Aug 12 09:58:26 2019 main() in THREAD 139740392815168
Mon Aug 12 09:58:26 2019 cups-browsed: Creating http connection to local CUPS daemon: /run/cups/cups.sock:631
Mon Aug 12 09:58:26 2019 update_netifs() in THREAD 139740392815168
Mon Aug 12 09:58:26 2019 network interface lo: Local host name/address: 127.0.0.1
Mon Aug 12 09:58:26 2019 network interface lo: Local host name/address: localhost
Mon Aug 12 09:58:26 2019 network interface eno1: Local host name/address: 192.168.1.59
Mon Aug 12 09:58:26 2019 network interface eno1: Local host name/address: logmediapc002.local
Mon Aug 12 09:58:26 2019 Network interface eno1 at 192.168.1.59 for legacy CUPS browsing/broadcasting
Mon Aug 12 09:58:26 2019 network interface virbr0: Local host name/address: 192.168.122.1
Mon Aug 12 09:58:26 2019 Network interface virbr0 at 192.168.122.1 for legacy CUPS browsing/broadcasting
Mon Aug 12 09:58:26 2019 network interface lo: Local host name/address: ::1
Mon Aug 12 09:58:26 2019 network interface eno1: Local host name/address: fe80::f289:46da:cf7b:1d4d
Mon Aug 12 09:58:26 2019 network interface eno1: Local host name/address: logmediapc002
Mon Aug 12 09:58:26 2019 cups-browsed [BrowsePoll /run/cups/cups.sock:0]: IPP-Create-Subscription
Mon Aug 12 09:58:26 2019 cups-browsed [BrowsePoll /run/cups/cups.sock:0]: subscription ID=1746
Mon Aug 12 09:58:26 2019 cups-browsed (/run/cups/cups.sock): cupsEnumDests
Mon Aug 12 09:58:26 2019 find_previous_queue() in THREAD 139740392815168
Mon Aug 12 09:58:26 2019 get-printer-attributes IPP call failed on printer konica_minolta_bizhub_c253_5e_92_c6_ (implicitclass://KONICA_MINOLTA_bizhub_C253_5E_92_C6_/).
Mon Aug 12 09:58:26 2019 ERROR: Unable to create print queue, ignoring printer.
Mon Aug 12 09:58:26 2019 ERROR: Unable to allocate memory.

Thanks, at least now we get the error message.
But it's strange we don't see any debug trace. It doesn't display the stderr ???

I'm not sure what you mean? Did I make a mistake? I can provide any additional logs if needed, but please give me instructions how I can obtain them.

When you remove the comment (# symbol) in front of DebugLogging and save the file /etc/cups/cups-browsed.conf the log messages should be more verbose. I was expecting some more messages starting with debug and in particular a line with the exact command that returned

get-printer-attributes IPP call failed on printer konica_minolta_bizhub_c253_5e_92_c6_ (implicitclass://KONICA_MINOLTA_bizhub_C253_5E_92_C6_/).

We can try backporting the proposed fix https://github.com/OpenPrinting/cups-filters/pull/128. Should be noted that it is not finalized yet.

Might be worth updating cups to latest version 2.2.11+ as well

Hi, I'm afraid I need someone to hand-hold me here.

On github user deepak0405 send me this patch.
https://github.com/deepak0405/cups-filters/blob/master/ipp.patch

How can I test it?

I guess I need to remove the currently installed cups-filters package with oepkg.

Clone the current master from github and apply the patch.

Then follow the installation instructions here
https://github.com/deepak0405/cups-filters/blob/master/INSTALL

Then I should be able to start/use/test it.

But because this is on my production rig I need to reinstall the working cups-filters 1.23 then.

How do I uninstall the self compiled cups-filters then? Or is no uninstall needed?
So I can safely do eopk history and restore my working package.

logTom added a comment.Mon, Sep 2, 7:19 AM

Never mind I did it on a VM and posted to github.
Special thanks to chax on IRC for the --disable-mutool configure option!

Can you confirm that with the patch deepak0405 provided fixed your issue? If so we'll backport it into our repository version.

No, the patch is not a fix. deepak0405 only provided it to gain more verbose debug output.

siru added a subscriber: siru.Mon, Sep 2, 6:52 PM

This has been happening to me too, and I've temporarily downgraded to 1.23 to fix the issue.

Is there anything I can do to help debug it?

I saw this issue of cups-filter get fixed 5 hours ago: https://github.com/OpenPrinting/cups-filters/issues/148. Could this be what was causing it? It looks similar.