michaelrsweet / lprint

A Label Printer Application
https://www.msweet.org/lprint
Apache License 2.0
219 stars 29 forks source link

Issue printing with native Chrome dialog and with IPPS #145

Open markusdd opened 1 month ago

markusdd commented 1 month ago
Mai 15 20:35:34 phantom-pc plasmashell[54257]: Warning: disabling flag --expose_wasm due to conflicting flags
Mai 15 20:36:20 phantom-pc cupsd[1805]: REQUEST localhost - - "POST /printers/Zebra-EPL-Page-Mode-4-inch-203dpi-Direct-Thermal HTTP/1.1" 200 530060 Print-Job successful-ok
Mai 15 20:36:20 phantom-pc lprint[51447]: I [2024-05-15T18:36:20.592Z] [Client 39] Accepted connection from '192.168.1.228'.
Mai 15 20:36:20 phantom-pc lprint[51447]: I [2024-05-15T18:36:20.592Z] [Client 39] HTTP_STATE_POST http://phantom-pc.local:8000/ipp/print/lprint_lp2844 HTTP/1.1 ()
Mai 15 20:36:20 phantom-pc lprint[51447]: I [2024-05-15T18:36:20.592Z] [Client 39] Continue
Mai 15 20:36:20 phantom-pc lprint[51447]: I [2024-05-15T18:36:20.592Z] [Client 39] Get-Printer-Attributes successful-ok
Mai 15 20:36:20 phantom-pc lprint[51447]: I [2024-05-15T18:36:20.592Z] [Client 39] OK application/ipp 1105
Mai 15 20:36:20 phantom-pc lprint[51447]: I [2024-05-15T18:36:20.593Z] [Client 39] HTTP_STATE_POST http://phantom-pc.local:8000/ipp/print/lprint_lp2844 HTTP/1.1 ()
Mai 15 20:36:20 phantom-pc lprint[51447]: I [2024-05-15T18:36:20.593Z] [Client 39] Continue
vvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvv
Mai 15 20:36:20 phantom-pc lprint[51447]: I [2024-05-15T18:36:20.593Z] [Client 39] Validate-Job client-error-attributes-or-values-not-supported (Unsupported print-color-mode keyword value.)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
Mai 15 20:36:20 phantom-pc lprint[51447]: I [2024-05-15T18:36:20.593Z] [Client 39] OK application/ipp 164
Mai 15 20:36:20 phantom-pc lprint[51447]: I [2024-05-15T18:36:20.593Z] [Client 39] Closing connection from '192.168.1.228'.
Mai 15 20:36:20 phantom-pc cupsd[1805]: [Job 55] Printer cannot print with supplied options.
Mai 15 20:36:20 phantom-pc cupsd[1805]: Zebra-EPL-Page-Mode-4-inch-203dpi-Direct-Thermal mkrause 55 [15/May/2024:20:36:20 +0200] total 1 - localhost Screenshot_20240515_011834.png (2984×1527)  -
Mai 15 20:36:20 phantom-pc cupsd[1805]: [Job 55] Backend ipp returned status 5 (cancel job)

I marked the relevant log line. Printing itself works beautifully on my LP2844, but when using the native Chrome dialog it fails probably because they send something unintelligible regarding color. Would it make sense to ignore this?

Second problem: I cannot use ipps on my machine (Nobara 39, which essentially is a latest greatest Fedora) because I get an error that the CUPS pki is invalid. When I modify the local connection address to just ipp it works. Is this expected?

EDIT: Firefox does not have the issue but they also list an explicit color setting which is set to black and white and can't be changed.

michaelrsweet commented 1 month ago

WRT "ignoring" unknown values, Print-Job and Create-Job will do so (assuming "ipp-attribute-fidelity" is false) but Validate-Job explicitly has to report unknown/unsupported/conflicting values or attributes (that's its purpose...)

Can you enable debug logging for LPrint (open web interface and toggle the log level in the View Log File page) and CUPS (cupsctl --debug-logging) and attach the logs to this issue? That will help me determine where the problem lies.

WRT the PKI errors, again having debug logs would be useful.

markusdd commented 1 month ago

image

I am not seeing the log option for lprint in the web interface weirdly enough unless I'm blind. any more specific hints? Cups I was able to enable debug logging, see below.

The funny thing is lprint logs taht the connection is now encrypted, still cups seems to get a PKI error back (see screenshot)

Mai 17 16:51:05 phantom-pc cupsd[86844]: [Client 2] 2.0 Get-Printer-Attributes 168
Mai 17 16:51:05 phantom-pc cupsd[86844]: Get-Printer-Attributes ipp://mkrause@localhost:631/printers/DYMO-LabelWriter-400
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Client 2] Returning IPP successful-ok for Get-Printer-Attributes (ipp://mkrause@localhost:631/printers/DYMO-LabelWriter-400) from localhost.
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Client 2] Content-Length: 601
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Client 2] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Client 2] con->http=0x562a0507c470
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Client 2] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=601, response=0x562a05117350(IPP_STATE_DATA), pipe_pid=0, file=-1
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Client 2] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Client 2] bytes=0, http_state=0, data_remaining=601
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Client 2] Flushing write buffer.
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Client 2] New state is HTTP_STATE_WAITING
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Client 2] Waiting for request.
Mai 17 16:51:05 phantom-pc cupsd[86844]: cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients, printing jobs, and dirty files"
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Job 74] Connecting to printer.
Mai 17 16:51:05 phantom-pc cupsd[86844]: cupsdMarkDirty(---J-)
Mai 17 16:51:05 phantom-pc cupsd[86844]: cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Job 74] Set job-printer-state-message to "Connecting to printer.", current level=INFO
Mai 17 16:51:05 phantom-pc cupsd[86844]: cupsdMarkDirty(----S)
Mai 17 16:51:05 phantom-pc lprint[1777]: I [2024-05-17T14:51:05.030Z] [Client 132] Accepted connection from '192.168.1.228'.
Mai 17 16:51:05 phantom-pc cupsd[86844]: cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
Mai 17 16:51:05 phantom-pc cupsd[86844]: cupsdMarkDirty(----S)
Mai 17 16:51:05 phantom-pc cupsd[86844]: cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Notifier] state=3
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Notifier] state=3
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Notifier] state=3
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Notifier] PrinterStateChanged
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Client 2] POST / HTTP/1.1
Mai 17 16:51:05 phantom-pc lprint[1777]: I [2024-05-17T14:51:05.031Z] [Client 132] Starting HTTPS session.
Mai 17 16:51:05 phantom-pc cupsd[86844]: cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Printing jobs and dirty files"
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Client 2] Read: status=200, state=6
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Client 2] No authentication data provided.
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Client 2] 2.0 Get-Printer-Attributes 169
Mai 17 16:51:05 phantom-pc cupsd[86844]: Get-Printer-Attributes ipp://mkrause@localhost:631/printers/DYMO-LabelWriter-400
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Client 2] Returning IPP successful-ok for Get-Printer-Attributes (ipp://mkrause@localhost:631/printers/DYMO-LabelWriter-400) from localhost.
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Client 2] Content-Length: 562
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Client 2] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Client 1476] POST / HTTP/1.1
Mai 17 16:51:05 phantom-pc cupsd[86844]: cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Active clients, printing jobs, and dirty files"
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Client 1476] Read: status=200, state=6
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Client 1476] No authentication data provided.
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Client 1476] 2.0 Get-Printer-Attributes 159
Mai 17 16:51:05 phantom-pc cupsd[86844]: Get-Printer-Attributes ipp://mkrause@localhost:631/printers/DYMO-LabelWriter-400
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Client 1476] Returning IPP successful-ok for Get-Printer-Attributes (ipp://mkrause@localhost:631/printers/DYMO-LabelWriter-400) from localhost.
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Client 1476] Content-Length: 562
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Client 1476] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Client 2] con->http=0x562a0507c470
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Client 2] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=562, response=0x562a05118ac0(IPP_STATE_DATA), pipe_pid=0, file=-1
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Client 2] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Client 2] bytes=0, http_state=0, data_remaining=562
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Client 2] Flushing write buffer.
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Client 2] New state is HTTP_STATE_WAITING
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Client 2] Waiting for request.
Mai 17 16:51:05 phantom-pc cupsd[86844]: cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Active clients, printing jobs, and dirty files"
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Client 1476] con->http=0x562a05088480
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Client 1476] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=562, response=0x562a051197e0(IPP_STATE_DATA), pipe_pid=0, file=-1
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Client 1476] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Client 1476] bytes=0, http_state=0, data_remaining=562
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Client 1476] Flushing write buffer.
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Client 1476] New state is HTTP_STATE_WAITING
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Client 1476] Waiting for request.
Mai 17 16:51:05 phantom-pc cupsd[86844]: cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients, printing jobs, and dirty files"
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Client 2] POST / HTTP/1.1
Mai 17 16:51:05 phantom-pc cupsd[86844]: cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Printing jobs and dirty files"
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Client 2] Read: status=200, state=6
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Client 2] No authentication data provided.
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Client 2] 2.0 Get-Printer-Attributes 170
Mai 17 16:51:05 phantom-pc cupsd[86844]: Get-Printer-Attributes ipp://mkrause@localhost:631/printers/DYMO-LabelWriter-400
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Client 2] Returning IPP successful-ok for Get-Printer-Attributes (ipp://mkrause@localhost:631/printers/DYMO-LabelWriter-400) from localhost.
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Client 2] Content-Length: 562
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Client 2] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Client 2] con->http=0x562a0507c470
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Client 2] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=562, response=0x562a05118970(IPP_STATE_DATA), pipe_pid=0, file=-1
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Client 2] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Client 2] bytes=0, http_state=0, data_remaining=562
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Client 2] Flushing write buffer.
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Client 2] New state is HTTP_STATE_WAITING
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Client 2] Waiting for request.
Mai 17 16:51:05 phantom-pc cupsd[86844]: cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients, printing jobs, and dirty files"
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Client 1476] POST / HTTP/1.1
Mai 17 16:51:05 phantom-pc cupsd[86844]: cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Printing jobs and dirty files"
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Client 1476] Read: status=200, state=6
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Client 1476] No authentication data provided.
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Client 1476] 2.0 Get-Printer-Attributes 160
Mai 17 16:51:05 phantom-pc cupsd[86844]: Get-Printer-Attributes ipp://mkrause@localhost:631/printers/DYMO-LabelWriter-400
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Client 1476] Returning IPP successful-ok for Get-Printer-Attributes (ipp://mkrause@localhost:631/printers/DYMO-LabelWriter-400) from localhost.
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Client 1476] Content-Length: 562
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Client 1476] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Client 1476] con->http=0x562a05088480
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Client 1476] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=562, response=0x562a05119140(IPP_STATE_DATA), pipe_pid=0, file=-1
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Client 1476] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Client 1476] bytes=0, http_state=0, data_remaining=562
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Client 1476] Flushing write buffer.
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Client 1476] New state is HTTP_STATE_WAITING
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Client 1476] Waiting for request.
Mai 17 16:51:05 phantom-pc cupsd[86844]: cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients, printing jobs, and dirty files"
Mai 17 16:51:05 phantom-pc lprint[1777]: I [2024-05-17T14:51:05.034Z] [Client 132] Connection now encrypted.
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Job 74] update_reasons(attr=0(), s=\"-cups-certificate-error\")
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Job 74] Connection is encrypted.
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Job 74] Credentials are invalid (New credentials are older than stored credentials.)
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Job 74] Printer credentials: phantom-pc (issued by phantom-pc) / Sat, 13 May 2034 18:16:52 GMT / RSA-SHA256 / 43CA381A93D08E6B5C914617E930E483
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Job 74] Stored credentials: phantom-pc.local (issued by phantom-pc.local) / Sat, 13 May 2034 18:24:07 GMT / RSA-SHA256 / 0A36E22F98145D083BF210B771D8534D
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Job 74] update_reasons(attr=0(), s=\"-cups-pki-invalid,cups-pki-changed,cups-pki-expired,cups-pki-unknown\")
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Job 74] STATE: -cups-pki-invalid
Mai 17 16:51:05 phantom-pc cupsd[86844]: cupsdMarkDirty(P----)
Mai 17 16:51:05 phantom-pc cupsd[86844]: cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
Mai 17 16:51:05 phantom-pc cupsd[86844]: cupsdMarkDirty(---J-)
Mai 17 16:51:05 phantom-pc cupsd[86844]: cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Job 74] update_reasons(attr=0(), s=\"+cups-pki-invalid\")
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Job 74] STATE: +cups-pki-invalid
Mai 17 16:51:05 phantom-pc cupsd[86844]: cupsdMarkDirty(P----)
Mai 17 16:51:05 phantom-pc cupsd[86844]: cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
Mai 17 16:51:05 phantom-pc cupsd[86844]: cupsdMarkDirty(---J-)
Mai 17 16:51:05 phantom-pc cupsd[86844]: cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
Mai 17 16:51:05 phantom-pc cupsd[86844]: cupsdMarkDirty(----S)
Mai 17 16:51:05 phantom-pc cupsd[86844]: cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Notifier] state=3
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Notifier] state=3
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Notifier] PrinterStateChanged
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Client 1476] POST / HTTP/1.1
Mai 17 16:51:05 phantom-pc cupsd[86844]: cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Printing jobs and dirty files"
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Client 1476] Read: status=200, state=6
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Client 1476] No authentication data provided.
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Client 1476] 2.0 Get-Printer-Attributes 161
Mai 17 16:51:05 phantom-pc cupsd[86844]: Get-Printer-Attributes ipp://mkrause@localhost:631/printers/DYMO-LabelWriter-400
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Client 1476] Returning IPP successful-ok for Get-Printer-Attributes (ipp://mkrause@localhost:631/printers/DYMO-LabelWriter-400) from localhost.
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Client 1476] Content-Length: 562
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Client 1476] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Client 2] POST / HTTP/1.1
Mai 17 16:51:05 phantom-pc cupsd[86844]: cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Active clients, printing jobs, and dirty files"
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Client 2] Read: status=200, state=6
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Client 2] No authentication data provided.
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Client 2] 2.0 Get-Printer-Attributes 171
Mai 17 16:51:05 phantom-pc cupsd[86844]: Get-Printer-Attributes ipp://mkrause@localhost:631/printers/DYMO-LabelWriter-400
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Client 2] Returning IPP successful-ok for Get-Printer-Attributes (ipp://mkrause@localhost:631/printers/DYMO-LabelWriter-400) from localhost.
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Client 2] Content-Length: 562
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Client 2] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Client 1476] con->http=0x562a05088480
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Client 1476] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=562, response=0x562a05119ed0(IPP_STATE_DATA), pipe_pid=0, file=-1
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Client 1476] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Client 1476] bytes=0, http_state=0, data_remaining=562
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Client 1476] Flushing write buffer.
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Client 1476] New state is HTTP_STATE_WAITING
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Client 1476] Waiting for request.
Mai 17 16:51:05 phantom-pc cupsd[86844]: cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Active clients, printing jobs, and dirty files"
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Client 2] con->http=0x562a0507c470
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Client 2] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=562, response=0x562a0511a890(IPP_STATE_DATA), pipe_pid=0, file=-1
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Client 2] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Client 2] bytes=0, http_state=0, data_remaining=562
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Client 2] Flushing write buffer.
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Client 2] New state is HTTP_STATE_WAITING
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Client 2] Waiting for request.
Mai 17 16:51:05 phantom-pc cupsd[86844]: cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients, printing jobs, and dirty files"
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Client 1476] POST / HTTP/1.1
Mai 17 16:51:05 phantom-pc cupsd[86844]: cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Printing jobs and dirty files"
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Client 1476] Read: status=200, state=6
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Client 1476] No authentication data provided.
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Client 1476] 2.0 Get-Printer-Attributes 162
Mai 17 16:51:05 phantom-pc cupsd[86844]: Get-Printer-Attributes ipp://mkrause@localhost:631/printers/DYMO-LabelWriter-400
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Client 1476] Returning IPP successful-ok for Get-Printer-Attributes (ipp://mkrause@localhost:631/printers/DYMO-LabelWriter-400) from localhost.
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Client 1476] Content-Length: 562
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Client 1476] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Client 1476] con->http=0x562a05088480
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Client 1476] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=562, response=0x562a05119de0(IPP_STATE_DATA), pipe_pid=0, file=-1
Mai 17 16:51:05 phantom-pc lprint[1777]: I [2024-05-17T14:51:05.035Z] [Client 132] Closing connection from '192.168.1.228'.
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Client 1476] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Client 1476] bytes=0, http_state=0, data_remaining=562
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Client 1476] Flushing write buffer.
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Client 1476] New state is HTTP_STATE_WAITING
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Client 1476] Waiting for request.
Mai 17 16:51:05 phantom-pc cupsd[86844]: cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients, printing jobs, and dirty files"
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Client 2] POST / HTTP/1.1
Mai 17 16:51:05 phantom-pc cupsd[86844]: cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Printing jobs and dirty files"
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Client 2] Read: status=200, state=6
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Client 2] No authentication data provided.
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Client 2] 2.0 Get-Printer-Attributes 172
Mai 17 16:51:05 phantom-pc cupsd[86844]: Get-Printer-Attributes ipp://mkrause@localhost:631/printers/DYMO-LabelWriter-400
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Client 2] Returning IPP successful-ok for Get-Printer-Attributes (ipp://mkrause@localhost:631/printers/DYMO-LabelWriter-400) from localhost.
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Client 2] Content-Length: 562
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Client 2] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Client 2] con->http=0x562a0507c470
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Client 2] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=562, response=0x562a0511a1b0(IPP_STATE_DATA), pipe_pid=0, file=-1
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Client 2] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Client 2] bytes=0, http_state=0, data_remaining=562
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Client 2] Flushing write buffer.
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Client 2] New state is HTTP_STATE_WAITING
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Client 2] Waiting for request.
Mai 17 16:51:05 phantom-pc cupsd[86844]: cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients, printing jobs, and dirty files"
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Job 74] PID 88064 (/usr/lib/cups/backend/ipps) stopped with status 4.
Mai 17 16:51:05 phantom-pc cupsd[86844]: DYMO-LabelWriter-400 mkrause 74 [17/May/2024:16:51:05 +0200] total 1 - localhost Test Page - -
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Job 74] Backend ipps returned status 4 (stop printer)
Mai 17 16:51:05 phantom-pc cupsd[86844]: cupsdMarkDirty(----S)
Mai 17 16:51:05 phantom-pc cupsd[86844]: cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Job 74] Printer stopped due to backend errors; please consult the syslog file for details.
Mai 17 16:51:05 phantom-pc cupsd[86844]: cupsdMarkDirty(---J-)
Mai 17 16:51:05 phantom-pc cupsd[86844]: cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
Mai 17 16:51:05 phantom-pc cupsd[86844]: cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
Mai 17 16:51:05 phantom-pc cupsd[86844]: cupsdMarkDirty(----S)
Mai 17 16:51:05 phantom-pc cupsd[86844]: cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
Mai 17 16:51:05 phantom-pc cupsd[86844]: cupsdMarkDirty(P----)
Mai 17 16:51:05 phantom-pc cupsd[86844]: cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
Mai 17 16:51:05 phantom-pc cupsd[86844]: cupsdRegisterPrinter(p=0x562a050951c0(DYMO-LabelWriter-400))
Mai 17 16:51:05 phantom-pc cupsd[86844]: cupsdMarkDirty(P----)
Mai 17 16:51:05 phantom-pc cupsd[86844]: cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
Mai 17 16:51:05 phantom-pc cupsd[86844]: cupsdMarkDirty(---J-)
Mai 17 16:51:05 phantom-pc cupsd[86844]: cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
Mai 17 16:51:05 phantom-pc cupsd[86844]: cupsdMarkDirty(---J-)
Mai 17 16:51:05 phantom-pc cupsd[86844]: cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Notifier] state=3
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Notifier] state=3
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Notifier] state=3
Mai 17 16:51:05 phantom-pc cupsd[86844]: [Notifier] PrinterStopped

modded the systemd service file but the output is not really any more plentyful. lprint does not complain in the logs but it does apparently to CUPS

mkrause@phantom-pc:~$ sudo systemctl status lprint
● lprint.service - LPrint Service
     Loaded: loaded (/usr/local/lib/systemd/system/lprint.service; enabled; preset: disabled)
    Drop-In: /usr/lib/systemd/system/service.d
             └─10-timeout-abort.conf
     Active: active (running) since Fri 2024-05-17 17:04:26 CEST; 2min 26s ago
   Main PID: 89394 (lprint)
      Tasks: 2 (limit: 38330)
     Memory: 3.9M
        CPU: 26ms
     CGroup: /system.slice/lprint.service
             └─89394 /usr/local/bin/lprint server -o log-file=- -o log-level=debug

Mai 17 17:04:56 phantom-pc lprint[89394]: I [2024-05-17T15:04:56.821Z] [Client 2] Closing connection from '192.168.1.214'.
Mai 17 17:04:56 phantom-pc lprint[89394]: I [2024-05-17T15:04:56.837Z] [Client 1] Closing connection from '192.168.1.214'.
Mai 17 17:05:37 phantom-pc lprint[89394]: I [2024-05-17T15:05:37.239Z] [Client 4] Accepted connection from '192.168.1.228'.
Mai 17 17:05:37 phantom-pc lprint[89394]: I [2024-05-17T15:05:37.239Z] [Client 4] Starting HTTPS session.
Mai 17 17:05:37 phantom-pc lprint[89394]: I [2024-05-17T15:05:37.243Z] [Client 4] Connection now encrypted.
Mai 17 17:05:37 phantom-pc lprint[89394]: I [2024-05-17T15:05:37.245Z] [Client 4] Closing connection from '192.168.1.228'.
Mai 17 17:06:16 phantom-pc lprint[89394]: I [2024-05-17T15:06:16.575Z] [Client 5] Accepted connection from '192.168.1.228'.
Mai 17 17:06:16 phantom-pc lprint[89394]: I [2024-05-17T15:06:16.575Z] [Client 5] Starting HTTPS session.
Mai 17 17:06:16 phantom-pc lprint[89394]: I [2024-05-17T15:06:16.578Z] [Client 5] Connection now encrypted.
Mai 17 17:06:16 phantom-pc lprint[89394]: I [2024-05-17T15:06:16.579Z] [Client 5] Closing connection from '192.168.1.228'.

Ok so lprint is ot printing any debug info for this print trial, I again confirmed on the console it is in fact printing debug info on startup (see the 'D' markers), but when I try to launch the job the causes the CUPS error only cups complains, lprint just prints infos and seems happy. weird.

mkrause@phantom-pc:~$ sudo journalctl -fu lprint 
Mai 17 17:09:00 phantom-pc lprint[89742]: D [2024-05-17T15:09:00.287Z] [Client 2] Get-Printer-Attributes response:   printer-make-and-model textWithoutLanguage Zebra EPL Page Mode 4-inch/203dpi/Direct-Thermal
Mai 17 17:09:00 phantom-pc lprint[89742]: D [2024-05-17T15:09:00.287Z] [Client 2] Get-Printer-Attributes response:   printer-state enum idle
Mai 17 17:09:00 phantom-pc lprint[89742]: D [2024-05-17T15:09:00.287Z] [Client 2] Get-Printer-Attributes response:   printer-state-message textWithoutLanguage Idle.
Mai 17 17:09:00 phantom-pc lprint[89742]: D [2024-05-17T15:09:00.287Z] [Client 2] Get-Printer-Attributes response:   printer-firmware-string-version 1setOf textWithoutLanguage 1.3.2,1.4.6,2.4.7,8.0,1.6.37
Mai 17 17:09:00 phantom-pc lprint[89742]: D [2024-05-17T15:09:00.287Z] [Client 2] Get-Printer-Attributes response:   printer-location textWithoutLanguage
Mai 17 17:09:00 phantom-pc lprint[89742]: D [2024-05-17T15:09:00.287Z] [Client 2] Get-Printer-Attributes response:   printer-more-info uri http://192.168.1.228:8000/lprint_lp2844/
Mai 17 17:09:00 phantom-pc lprint[89742]: D [2024-05-17T15:09:00.287Z] [Client 2] Get-Printer-Attributes response:   printer-up-time integer 1
Mai 17 17:09:00 phantom-pc lprint[89742]: D [2024-05-17T15:09:00.287Z] [Client 2] Get-Printer-Attributes response:   printer-uri-supported 1setOf uri ipp://192.168.1.228:8000/ipp/print/lprint_lp2844,ipps://192.168.1.228:8000/ipp/print/lprint_lp2844
Mai 17 17:09:27 phantom-pc lprint[89742]: I [2024-05-17T15:09:27.253Z] [Client 2] Closing connection from '192.168.1.214'.
Mai 17 17:09:27 phantom-pc lprint[89742]: I [2024-05-17T15:09:27.253Z] [Client 1] Closing connection from '192.168.1.214'.
Mai 17 17:11:13 phantom-pc lprint[89742]: I [2024-05-17T15:11:13.023Z] [Client 3] Accepted connection from '192.168.1.228'.
Mai 17 17:11:13 phantom-pc lprint[89742]: I [2024-05-17T15:11:13.023Z] [Client 3] Starting HTTPS session.
Mai 17 17:11:13 phantom-pc lprint[89742]: I [2024-05-17T15:11:13.027Z] [Client 3] Connection now encrypted.
Mai 17 17:11:13 phantom-pc lprint[89742]: I [2024-05-17T15:11:13.028Z] [Client 3] Closing connection from '192.168.1.228'.
markusdd commented 1 month ago

As for the Chrome issue, I switched back the printer to ipp protocol so that the connection works, and I have attached the resulting logfile.

Here there is a lot more lprint debug output in there. This issue exists with both printers (the Zebra LP2844 and the DYMO, Dymo example in the log).

debug_chrome.log