0
I have the exact same problem, only in my case enabling IPv6 does not fix it.
Environment
Raspberry Pi Zero W
Linux Kernel 4.14.98+
CUPS 2.2.1
avahi-daemon 0.6.32
My printer is attached to the Pi Zero W via a regular USB cable.
Problem
Printing via Windows using the Windows drivers works perfectly, the same goes for printing via Ubuntu or Arch using my printer's ppd file. But on iOS devices (iOS 12) it takes about 30 seconds from starting the job until the printer starts printing.
This is an excerpt from /var/log/cups/error_log:
D [***TIMESTAMP***] [Client 73] 2.0 Get-Printer-Attributes 21
D [***TIMESTAMP***] Get-Printer-Attributes ipp://raspberrypi.local.:631/printers/MY_PRINTER
D [***TIMESTAMP***] [Client 73] Returning IPP successful-ok for Get-Printer-Attributes (ipp://raspberrypi.local.:631/printers/MY_PRINTER) from ***.***.***.***
D [***TIMESTAMP***] [Client 73] Content-Length: 106
D [***TIMESTAMP***] [Client 73] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [***TIMESTAMP***] [Client 73] con->http=0x1f8ba70
D [***TIMESTAMP***] [Client 73] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=106, response=0x1f7ddf0(IPP_STATE_DATA), pipe_pid=0, file=-1
D [***TIMESTAMP***] [Client 73] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [***TIMESTAMP***] [Client 73] bytes=0, http_state=0, data_remaining=106
D [***TIMESTAMP***] [Client 73] Flushing write buffer.
D [***TIMESTAMP***] [Client 73] New state is HTTP_STATE_WAITING
D [***TIMESTAMP***] [Client 73] Waiting for request.
D [***TIMESTAMP***] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients, printing jobs, and dirty files"
D [***TIMESTAMP***] [Client 73] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [***TIMESTAMP***] [Client 73] Closing connection.
D [***TIMESTAMP***] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [***TIMESTAMP***] [Client 65] POST /printers/MY_PRINTER HTTP/1.1
D [***TIMESTAMP***] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Printing jobs and dirty files"
D [***TIMESTAMP***] [Client 65] Read: status=200
D [***TIMESTAMP***] [Client 65] No authentication data provided.
D [***TIMESTAMP***] [Client 65] 2.0 Get-Job-Attributes 22
D [***TIMESTAMP***] Get-Job-Attributes ipp://raspberrypi.local.:631/printers/MY_PRINTER
D [***TIMESTAMP***] [Client 65] Returning IPP successful-ok for Get-Job-Attributes (ipp://raspberrypi.local.:631/printers/MY_PRINTER) from ***.***.***.***
D [***TIMESTAMP***] [Client 65] Content-Length: 197
D [***TIMESTAMP***] [Client 65] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
I [***TIMESTAMP***] Expiring subscriptions...
D [***TIMESTAMP***] [Client 65] con->http=0x1f962b8
D [***TIMESTAMP***] [Client 65] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=197, response=0x1fa1190(IPP_STATE_DATA), pipe_pid=0, file=-1
D [***TIMESTAMP***] [Client 65] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [***TIMESTAMP***] [Client 65] bytes=0, http_state=0, data_remaining=197
D [***TIMESTAMP***] [Client 65] Flushing write buffer.
D [***TIMESTAMP***] [Client 65] New state is HTTP_STATE_WAITING
D [***TIMESTAMP***] [Client 65] Waiting for request.
D [***TIMESTAMP***] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients, printing jobs, and dirty files"
D [***TIMESTAMP***] [Client 74] Server address is "***.***.***.***".
D [***TIMESTAMP***] [Client 74] Accepted from ***.***.***.***:60436 (IPv4)
D [***TIMESTAMP***] [Client 74] Waiting for request.
D [***TIMESTAMP***] [Client 74] POST /printers/MY_PRINTER HTTP/1.1
D [***TIMESTAMP***] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Printing jobs and dirty files"
D [***TIMESTAMP***] [Client 74] Read: status=200
D [***TIMESTAMP***] [Client 74] No authentication data provided.
This repeats itself multiple times until finally:
D [***TIMESTAMP***] [Job 66] Read 8192 bytes of print data...
D [***TIMESTAMP***] [Job 66] Wrote 8192 bytes of print data...
Even though print data is being sent at that point, the Get-Printer-Attributes loop still continues.
The Client ID as visible in the log file excerpt changes multiple times over the course of a running print job. Maybe that has got to do something with the delay? I already enabled IPv6 by loading the kernel module on startup. The raspberry pi's IPv6 address is pingable from my Windows PC.
Does anybody know of a fix?