qzind / tray

Browser plugin for sending documents and raw commands to a printer or attached device.
https://qz.io
Other
841 stars 274 forks source link

Unable to Print to Printer Until Kills Java #1257

Open FinishingLine opened 5 months ago

FinishingLine commented 5 months ago

Strange one ... we have the same setup on several PCs (the PCs are all the same) with the same "normal" printer (on all but one) as well as a Zebra label printer

We have QZ loading just fine in the background and can print to the label printer as well with no issue, however, if we try printing to a "normal" printer, nothing comes out the printer (it appears like the job gets created but then is subsequently deleted)

Everything was working fine previously, though this issue just started on one computer and we also just changed the printers on the one that had a different printer so that everything was the same, but since doing that the issue seems to also now affect that one as well

Have tried both 2.1.1 (which we had originally) and also the latest 2.2.4-snapshot version

On the latest snapshot version of QZ, looking at the debug logs have spotted the below:

2024-04-23T11:42:10,082 [INFO] Connection opened from /0:0:0:0:0:0:0:1:63820 on socket port 8181
2024-04-23T11:42:10,082 [DEBUG] Message: {"certificate":"-----BEGIN CERTIFICATE-----\n....................\n-----END CERTIFICATE-----\n","timestamp":1713868930090,"uid":"..........","position":{"x":960,"y":540}}
2024-04-23T11:42:10,082 [WARN] Problem building certificate chain (normal if multiple CAs are in use)
2024-04-23T11:42:10,082 [DEBUG] Successfully chained certificate: CN=localhost, O=XXX (....................)
2024-04-23T11:42:10,082 [DEBUG] Adding XXX (localhost) to allowed list
2024-04-23T11:42:10,093 [DEBUG] Received new certificate from connection through 63820
2024-04-23T11:42:10,193 [DEBUG] Message: {"call":"getVersion","timestamp":1713868930095,"uid":".......","position":{"x":960,"y":540}}
2024-04-23T11:42:10,194 [DEBUG] Message: {"call":"printers.find","params":{"query":"ECOSYS P2040dn"},"signature":"........................","timestamp":1713868930095,"uid":"...........","position":{"x":960,"y":540}}
2024-04-23T11:42:10,194 [DEBUG] Searching for PrintService matching ECOSYS P2040dn
2024-04-23T11:42:10,194 [DEBUG] Matched default printer, skipping further search
2024-04-23T11:42:10,311 [DEBUG] Message: .................
2024-04-23T11:42:10,327 [DEBUG] Using qz.printer.action.PrintPDF to print
2024-04-23T11:42:10,327 [DEBUG] Searching for PrintService matching ECOSYS P2040dn
2024-04-23T11:42:10,327 [DEBUG] Matched default printer, skipping further search
2024-04-23T11:42:10,327 [WARN] Raw option "altPrinting" is deprecated.  Please use "forceRaw" instead.
2024-04-23T11:42:13,311 [INFO] Connection closed: 1001 - null
2024-04-23T11:42:13,311 [INFO] Closing all communication channels for localhost
2024-04-23T11:42:14,084 [DEBUG] Parsed 1 files for printing
2024-04-23T11:42:14,178 [INFO] Starting printing (1 copies)
2024-04-23T11:42:14,287 [DEBUG] Paper area: 0,0:597,842
2024-04-23T11:42:14,413 [DEBUG] Paper area: 0,0:597,842
2024-04-23T11:42:14,413 [DEBUG] Paper area: 0,0:597,842
2024-04-23T11:42:14,491 [INFO] Printing complete
**2024-04-23T11:42:14,506 [ERROR] Could not send message
java.io.IOException: java.nio.channels.ClosedChannelException
    at org.eclipse.jetty.util.FutureCallback.block(FutureCallback.java:163) ~[qz-tray.jar:?]
    at org.eclipse.jetty.util.FutureCallback.block(FutureCallback.java:139) ~[qz-tray.jar:?]
    at org.eclipse.jetty.websocket.common.JettyWebSocketRemoteEndpoint.sendBlocking(JettyWebSocketRemoteEndpoint.java:191) ~[qz-tray.jar:?]
    at org.eclipse.jetty.websocket.common.JettyWebSocketRemoteEndpoint.sendString(JettyWebSocketRemoteEndpoint.java:52) ~[qz-tray.jar:?]
    at qz.ws.PrintSocketClient.send(PrintSocketClient.java:793) ~[qz-tray.jar:?]
    at qz.ws.PrintSocketClient.sendResult(PrintSocketClient.java:724) ~[qz-tray.jar:?]
    at qz.utils.PrintingUtilities.processPrintRequest(PrintingUtilities.java:215) ~[qz-tray.jar:?]
    at qz.ws.PrintSocketClient.processMessage(PrintSocketClient.java:315) ~[qz-tray.jar:?]
    at qz.ws.PrintSocketClient.lambda$onMessage$0(PrintSocketClient.java:169) ~[qz-tray.jar:?]
    at java.base/java.lang.Thread.run(Unknown Source) [?:?]
Caused by: java.nio.channels.ClosedChannelException
    at org.eclipse.jetty.websocket.core.internal.WebSocketSessionState.onOutgoingFrame(WebSocketSessionState.java:184) ~[qz-tray.jar:?]
    at org.eclipse.jetty.websocket.core.internal.WebSocketCoreSession.sendFrame(WebSocketCoreSession.java:514) ~[qz-tray.jar:?]
    at org.eclipse.jetty.websocket.common.JettyWebSocketRemoteEndpoint.sendBlocking(JettyWebSocketRemoteEndpoint.java:190) ~[qz-tray.jar:?]
    ... 7 more**

I'm wondering if the exception is the reason?

When trying a different brand printer, the same happens, though this particular printer starts whirling like its about to print, but then the job gets cancelled and it just stops

The strange thing is; once we kill Java via Task Manager and re-open QZ, everything starts working fine for the "normal" printer (and the label printer continues to works as it did before)

Originally wondered if this was something to do with a Windows Update, but if that then the other machines should have the same issue

tresf commented 5 months ago

Thanks for the detailed report.

My initial observations...

tresf commented 5 months ago

Oh... and this one is just a "have you turned your computer off and back on again" recommendation, but nothing has caused more grief in my modern troubleshooting life than pending windows updates that haven't been applied and worn bits on an SSD hard drive, so as a general rule of thumb, before I go insane, I do a chkdsk /f /r on any problematic computer.

FinishingLine commented 5 months ago

@tresf Many thanks for the above

For clarity, this issue happens at bootup (and we've rebooted a lot of times when trying to figure this one out), once Java is killed, everything is fine. The label printer also continues working after the exception, without needing to restart/reload QZ

Have also tried doing a full factory reset on the PC, but the issue didn't disappear

We have tried using the IPP driver but will also look to see if we can use a different Kyocera driver as well (and will try to completely remove the existing one too)

Will also give print to PDF a try

tresf commented 5 months ago

For clarity, this issue happens at bootup

Can you describe the symptom in more detail? I'm not sure that I understand. The original bug report show the websocket closure occuring fractions of a second after a print occurs. I assume when you say "Happens at bootup", what you're describing is:

  1. When QZ Tray starts for the first time (specifically, when started through the routine startup process), it misbehaves, but only after a PIXEL print is performed (I assume this due to the label printer being OK, but please correct this statement if it's wrong).
  2. When QZ Tray starts for the second and subsequent times (after being manually killed) it behaves properly

Is this correct?

Furthermore, if you wait long enough, does it eventually crash on its own? Are there any other symptoms that would suggest that QZ Tray is still performing any type of operation (CPU, ram, etc?). You've peaked my interest.

We did have an oddball issue where 3rd party apps caused troubles paired with QZ Tray (it has a group policy to do JVM enforcement and we were being punished). In the case of one, it was using some advanced techniques to affect DLL search and load order. If something similar is happening on your machine (an incorrect DLL is being confused at startup) it may explain the odd behavior. This is just a shot in the dark.

Another shot in the dark is to see if something is stealing port 8181. We try to fallback on 8282 if 8181 is already taken, but perhaps something is breaking in this process.

FinishingLine commented 5 months ago

@tresf just to give you an update, we played around with various drivers and have found one that doesn't seem to cause the issue :)

Microsoft Print to PDF also seemed to work when we changed the printer, so perhaps it was a driver issue that oddly only affected 2 out of 5 machines (not sure if possibly as we removed and added the printer back on these two, but setup was exactly the same across all 5)

Can you describe the symptom in more detail? I'm not sure that I understand. The original bug report show the websocket closure occuring fractions of a second after a print occurs. I assume when you say "Happens at bootup", what you're describing is:

  1. When QZ Tray starts for the first time (specifically, when started through the routine startup process), it misbehaves, but only after a PIXEL print is performed (I assume this due to the label printer being OK, but please correct this statement if it's wrong).
  2. When QZ Tray starts for the second and subsequent times (after being manually killed) it behaves properly

Is this correct?

Yes, this is what was happening (loading on startup) in both versions

Furthermore, if you wait long enough, does it eventually crash on its own? Are there any other symptoms that would suggest that QZ Tray is still performing any type of operation (CPU, ram, etc?). You've peaked my interest.

It didn't crash per se, it just refused to print (by the print job being deleted without us doing anything) to the printer until Java was killed and QZ was re-opened; printing to a Zebra label printer via QZ tray worked just fine

Didn't spot any obvious CPU/RAM spikes when attempting to print

tresf commented 5 months ago

@FinishingLine thanks for the detailed explanation. Is this still happening and something you believe requires a remote session to escalate, or do you plan on considering this an edge-case issue that we can close and revist at a later time?