Fedora loses connection to printer when resumed from Hibernate/Sleep

eeijlar · January 21, 2021, 10:17am

I am printing to a wireless Brother printer model MFC-L2710DW. If I try and print after resuming the system from a sleep or hibernate it can’t locate the printer. However, if I reboot Fedora (33) it manages to find the printer on the network and the printer starts printing the jobs.

There is nothing in the cups log:

Jan 21 10:15:06 fedora cupsd[1049]: Get-Printer-Attributes ipp://john@localhost:631/printers/Brother_MFC-L2710DW_series
Jan 21 10:15:06 fedora cupsd[1049]: [Client 452] Returning IPP successful-ok for Get-Printer-Attributes (ipp://john@localhost:631/printers/Brother_MFC-L2710DW_series) from localhost.
Jan 21 10:15:06 fedora cupsd[1049]: [Client 452] Content-Length: 628
Jan 21 10:15:06 fedora cupsd[1049]: [Client 452] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
Jan 21 10:15:06 fedora cupsd[1049]: [Client 452] con->http=0x556c0a8a6060
Jan 21 10:15:06 fedora cupsd[1049]: [Client 452] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=628, response=0x556c0a7fd1a0(IPP_STATE_DATA), pipe_pid=0, file=-1
Jan 21 10:15:06 fedora cupsd[1049]: [Client 452] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
Jan 21 10:15:06 fedora cupsd[1049]: [Client 452] bytes=0, http_state=0, data_remaining=628
Jan 21 10:15:06 fedora cupsd[1049]: [Client 452] Flushing write buffer.
Jan 21 10:15:06 fedora cupsd[1049]: [Client 452] New state is HTTP_STATE_WAITING
Jan 21 10:15:06 fedora cupsd[1049]: [Client 452] Waiting for request.
Jan 21 10:15:06 fedora cupsd[1049]: cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients, printing jobs, and dirty files"
Jan 21 10:15:06 fedora cupsd[1049]: [Client 447] POST / HTTP/1.1
Jan 21 10:15:06 fedora cupsd[1049]: cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Printing jobs and dirty files"
Jan 21 10:15:06 fedora cupsd[1049]: [Client 447] Read: status=200, state=6
Jan 21 10:15:06 fedora cupsd[1049]: [Client 447] No authentication data provided.
Jan 21 10:15:06 fedora cupsd[1049]: [Client 447] 2.0 Get-Jobs 2852
Jan 21 10:15:06 fedora cupsd[1049]: Get-Jobs ipp://john@localhost:631/printers/
Jan 21 10:15:06 fedora cupsd[1049]: [Client 447] Returning IPP successful-ok for Get-Jobs (ipp://john@localhost:631/printers/) from localhost.
Jan 21 10:15:06 fedora cupsd[1049]: [Client 447] Content-Length: 571
Jan 21 10:15:06 fedora cupsd[1049]: [Client 447] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
Jan 21 10:15:06 fedora cupsd[1049]: [Client 447] con->http=0x556c0a825810
Jan 21 10:15:06 fedora cupsd[1049]: [Client 447] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=571, response=0x556c0a7e84c0(IPP_STATE_DATA), pipe_pid=0, file=-1
Jan 21 10:15:06 fedora cupsd[1049]: [Client 447] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
Jan 21 10:15:06 fedora cupsd[1049]: [Client 447] bytes=0, http_state=0, data_remaining=571
Jan 21 10:15:06 fedora cupsd[1049]: [Client 447] Flushing write buffer.
Jan 21 10:15:06 fedora cupsd[1049]: [Client 447] New state is HTTP_STATE_WAITING
Jan 21 10:15:06 fedora cupsd[1049]: [Client 447] Waiting for request.
Jan 21 10:15:06 fedora cupsd[1049]: cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients, printing jobs, and dirty files"
Jan 21 10:15:06 fedora cupsd[1049]: [Client 447] POST / HTTP/1.1
Jan 21 10:15:06 fedora cupsd[1049]: cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Printing jobs and dirty files"
Jan 21 10:15:06 fedora cupsd[1049]: [Client 447] Read: status=200, state=6
Jan 21 10:15:06 fedora cupsd[1049]: [Client 447] No authentication data provided.
Jan 21 10:15:06 fedora cupsd[1049]: [Client 447] 2.0 Get-Printer-Attributes 2853
Jan 21 10:15:06 fedora cupsd[1049]: Get-Printer-Attributes ipp://john@localhost:631/printers/Brother_MFC-L2710DW_series
Jan 21 10:15:06 fedora cupsd[1049]: [Client 447] Returning IPP successful-ok for Get-Printer-Attributes (ipp://john@localhost:631/printers/Brother_MFC-L2710DW_series) from localhost.
Jan 21 10:15:06 fedora cupsd[1049]: [Client 447] Content-Length: 628
Jan 21 10:15:06 fedora cupsd[1049]: [Client 447] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
Jan 21 10:15:06 fedora cupsd[1049]: [Client 447] con->http=0x556c0a825810
Jan 21 10:15:06 fedora cupsd[1049]: [Client 447] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=628, response=0x556c0a804190(IPP_STATE_DATA), pipe_pid=0, file=-1
Jan 21 10:15:06 fedora cupsd[1049]: [Client 447] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
Jan 21 10:15:06 fedora cupsd[1049]: [Client 447] bytes=0, http_state=0, data_remaining=628
Jan 21 10:15:06 fedora cupsd[1049]: [Client 447] Flushing write buffer.
Jan 21 10:15:06 fedora cupsd[1049]: [Client 447] New state is HTTP_STATE_WAITING
Jan 21 10:15:06 fedora cupsd[1049]: [Client 447] Waiting for request.
Jan 21 10:15:06 fedora cupsd[1049]: cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients, printing jobs, and dirty files"
Jan 21 10:15:07 fedora cupsd[1049]: Expiring subscriptions...

vgaetera · January 21, 2021, 10:34am

Collect the output when the issue happens:

sudo systemctl --no-pager status cups\*; lpstat -t

Also check whether restarting the services helps or not:

sudo systemctl restart cups.service cups.socket cups.path cups-browsed.service

eeijlar · January 25, 2021, 7:21pm

Here is the output of systemctl status:

[john@localhost bin]$ sudo systemctl --no-pager status cups\*; lpstat -t
● cups-browsed.service - Make remote CUPS printers available locally
     Loaded: loaded (/usr/lib/systemd/system/cups-browsed.service; disabled; vendor preset: disabled)
     Active: active (running) since Thu 2021-01-21 14:10:32 GMT; 57s ago
   Main PID: 12151 (cups-browsed)
      Tasks: 3 (limit: 19137)
     Memory: 2.6M
     CGroup: /system.slice/cups-browsed.service
             └─12151 /usr/sbin/cups-browsed

Jan 21 14:10:32 localhost.localdomain systemd[1]: Started Make remote CUPS printers available locally.

● cups.path - CUPS Scheduler
     Loaded: loaded (/usr/lib/systemd/system/cups.path; enabled; vendor preset: enabled)
     Active: active (running) since Thu 2021-01-21 14:10:32 GMT; 57s ago
   Triggers: ● cups.service

Jan 21 14:10:32 localhost.localdomain systemd[1]: Started CUPS Scheduler.

● cups.service - CUPS Scheduler
     Loaded: loaded (/usr/lib/systemd/system/cups.service; disabled; vendor preset: disabled)
    Drop-In: /usr/lib/systemd/system/cups.service.d
             └─server.conf
     Active: active (running) since Thu 2021-01-21 14:10:32 GMT; 57s ago
TriggeredBy: ● cups.socket
             ● cups.path
       Docs: man:cupsd(8)
   Main PID: 12143 (cupsd)
     Status: "Scheduler is running..."
      Tasks: 10 (limit: 19137)
     Memory: 12.2M
     CGroup: /system.slice/cups.service
             ├─12143 /usr/sbin/cupsd -l
             ├─12147 /usr/lib/cups/notifier/dbus dbus://
             ├─12149 /usr/bin/perl /usr/lib/cups/filter/brother_lpdwrapper_MFCL2710DW 67 john grazing-notification. 1 media=A4 sides=one-sided number-up=1 number-up-layout=lrtb job-billing= job-uuid=urn:uuid:38b6f838-1dc4-33b7-61b4-5c5…
             ├─12150 ipp://BRWE89EB4307787.local:631/ipp/print 67 john grazing-notification. 1 media=A4 sides=one-sided number-up=1 number-up-layout=lrtb job-billing= job-uuid=urn:uuid:38b6f838-1dc4-33b7-61b4-5c57952b2dde job-originati…
             ├─12166 sh -c cat  |  /opt/brother/Printers/MFCL2710DW/lpd/lpdfilter
             ├─12168 /usr/bin/perl /opt/brother/Printers/MFCL2710DW/lpd/lpdfilter
             ├─12176 sh -c cat  | /usr/bin/gs -r600 -g4961x7016 -q -dNOPROMPT -dNOPAUSE -dSAFER -sDEVICE=bit -sstdout=%stderr -sOutputFile=- - -c quit | /opt/brother/Printers/MFCL2710DW/lpd/rawtobr3 -rc /tmp/brMFCL2710DWrc_12149 -flags…
             ├─12179 /opt/brother/Printers/MFCL2710DW/lpd/rawtobr3 -rc /tmp/brMFCL2710DWrc_12149 -flags 0000000000000500 -offset 0 -ps 4961x7016
             └─12182 /usr/lib/cups/notifier/dbus dbus://

Jan 21 14:11:07 localhost.localdomain cupsd[12143]: [Client 4] bytes=0, http_state=0, data_remaining=651
Jan 21 14:11:07 localhost.localdomain cupsd[12143]: [Client 4] Flushing write buffer.
Jan 21 14:11:07 localhost.localdomain cupsd[12143]: [Client 4] New state is HTTP_STATE_WAITING
Jan 21 14:11:07 localhost.localdomain cupsd[12143]: [Client 4] Waiting for request.
Jan 21 14:11:07 localhost.localdomain cupsd[12143]: cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients, printing jobs, and dirty files"
Jan 21 14:11:07 localhost.localdomain cupsd[12143]: [Client 4] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
Jan 21 14:11:07 localhost.localdomain cupsd[12143]: [Client 4] Closing connection.
Jan 21 14:11:07 localhost.localdomain cupsd[12143]: cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
Jan 21 14:11:08 localhost.localdomain cupsd[12143]: Expiring subscriptions...
Jan 21 14:11:19 localhost.localdomain cupsd[12143]: Expiring subscriptions...

● cups.socket - CUPS Scheduler
     Loaded: loaded (/usr/lib/systemd/system/cups.socket; enabled; vendor preset: enabled)
     Active: active (running) since Thu 2021-01-21 14:10:32 GMT; 58s ago
   Triggers: ● cups.service
     Listen: /run/cups/cups.sock (Stream)
     CGroup: /system.slice/cups.socket

Jan 21 14:10:32 localhost.localdomain systemd[1]: Stopping CUPS Scheduler.
Jan 21 14:10:32 localhost.localdomain systemd[1]: Listening on CUPS Scheduler.
scheduler is running
system default destination: Brother_MFC-L2710DW_series
device for Brother_MFC-L2710DW_series: dnssd://Brother%20MFC-L2710DW%20series._ipp._tcp.local/?uuid=e3248000-80ce-11db-8000-3c2af42da8fc
Brother_MFC-L2710DW_series accepting requests since Thu 21 Jan 2021 14:10:32
printer Brother_MFC-L2710DW_series now printing Brother_MFC-L2710DW_series-67.  enabled since Thu 21 Jan 2021 14:10:32
        Connecting to printer.
Brother_MFC-L2710DW_series-67 john             15360   Thu 21 Jan 2021 13:28:27
Brother_MFC-L2710DW_series-68 john             15360   Thu 21 Jan 2021 14:09:58
[john@localhost bin]$

All looks ok, restarting the services didn’t make any difference. There must be a service that doesn’t get starting or else the wifi comes up after the printer service maybe, not sure…

vgaetera · January 25, 2021, 7:30pm

Try to use another protocol such as AppSocket/JetDirect, IPP or LPD.