search

qzind / tray

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

Printer Job Status #736

Closed tresf closed 3 years ago

tresf commented 3 years ago

It turns out in Windows (and probably in CUPS too), we can report specific job status directly from the spooler. This is a huge improvement over our existing printer status, but will require adding additional entropy to the printer status messages.

- hChangeObject = spool.FindFirstPrinterChangeNotification(phPrinterObject.getValue(), Winspool.PRINTER_CHANGE_SET_PRINTER, 0, null);
+ hChangeObject = spool.FindFirstPrinterChangeNotification(phPrinterObject.getValue(), Winspool.PRINTER_CHANGE_ALL, 0, null);
WinNT.HANDLEByReference phPrinter = new WinNT.HANDLEByReference();
Winspool.INSTANCE.OpenPrinter(printerName, phPrinter, null);
for(Winspool.JOB_INFO_1 info : WinspoolUtil.getJobInfo1(phPrinter)) {
   jobStatus = info.Status;
   if(jobStatus != lastJobStatus) {
      lastJobStatus = jobStatus;
      PrinterStatus[] statuses = PrinterStatus.getFromWMICode(jobStatus, printerName);
      StatusMonitor.statusChanged(statuses);
      break;
   }
}
tresf commented 3 years ago

Please use branch job-status for code.

klabarge commented 3 years ago

macOS

macOS: Big Sur 11.1 Java: AdoptOpenJDK 11.0.4 Printer: Zebra LP 2844

I tested this branch on the Zebra LP 2844. The information provided by the spooler is limited, but expected based off previous testing of this printer.

Offline

When the printer is disconnected, this is the only scenario where the print job doesn't complete successfully.

When the printer is offline, the print queue actually displays this, however it is not clear in the logs. The logs indicate that a job is "processing". Can anything be done to get the "the printer is offline" status?

 Mon Feb 22 2021 21:55:05 GMT-0500 (Eastern Standard Time): PROCESSING: Level: INFO, From: Zebra LP2844, EventType: PRINTER, Code: processing

 Mon Feb 22 2021 21:55:53 GMT-0500 (Eastern Standard Time): OK: Level: INFO, From: Zebra LP2844, EventType: PRINTER, Code: connecting-to-device

 Mon Feb 22 2021 21:55:55 GMT-0500 (Eastern Standard Time): PROCESSING: Level: INFO, From: Zebra LP2844, EventType: PRINTER, Code: processing
image

Logging

The below was logged 57 times over the period of ~20 seconds while listening during a print job. This info doesn't seem useful and a bit spammy.

[DEBUG] 2021-02-22 21:20:34,742 @ qz.printer.PrintServiceMatcher:?
    Searching for PrintService matching Zebra_LP2844
[DEBUG] 2021-02-22 21:20:34,931 @ qz.printer.PrintServiceMatcher:?
    Found 7 printers
[DEBUG] 2021-02-22 21:20:35,105 @ qz.printer.PrintServiceMatcher:?
    Found match: Zebra LP2844

During print job

Here's a sample of the (end) of the information that is available during a print job. Looks good!

 Mon Feb 22 2021 21:38:09 GMT-0500 (Eastern Standard Time): PROCESSING: Level: INFO, From: Zebra LP2844, EventType: PRINTER, Code: processing

 Mon Feb 22 2021 21:38:11 GMT-0500 (Eastern Standard Time): PROCESSING: Level: INFO, From: Zebra LP2844, EventType: PRINTER, Code: processing

 Mon Feb 22 2021 21:38:12 GMT-0500 (Eastern Standard Time): PROCESSING: Level: INFO, From: Zebra LP2844, EventType: PRINTER, Code: processing

 Mon Feb 22 2021 21:38:13 GMT-0500 (Eastern Standard Time): PRINTING: Level: INFO, From: Zebra LP2844, EventType: PRINTER, Code: cups-waiting-for-job-completed

 Mon Feb 22 2021 21:38:15 GMT-0500 (Eastern Standard Time): COMPLETE: Level: INFO, From: Zebra LP2844, EventType: JOB, Code: job-completed-successfully, JobId: 889, Job Name: QZ Tray HTML Print

 Mon Feb 22 2021 21:38:16 GMT-0500 (Eastern Standard Time): OK: Level: INFO, From: Zebra LP2844, EventType: PRINTER, Code: idle
tresf commented 3 years ago

The below was logged 57 times over the period of ~20 seconds while listening during a print job. This info doesn't seem useful and a bit spammy.

Yeah, we do a printer look up each time a message arrives. I'm not sure if this has performance implications, but for now I've suppressed the logs via 23c9496.

Can anything be done to get the "the printer is offline" status?

Not sure, pinging @Vzor-, since he's one of just a few humans ever that has successfully parsed the RSS feed from CUPS.

Vzor- commented 3 years ago

I will take a look.

tresf commented 3 years ago

Can anything be done to get the "the printer is offline" status?

@klabarge, done via 46b81f1.

klabarge commented 3 years ago

Can anything be done to get the "the printer is offline" status?

@klabarge, done via 46b81f1.

Confirmed, the logs now show an error.

- Wed Feb 24 2021 21:19:19 GMT-0500 (Eastern Standard Time): OFFLINE: Level: FATAL, From: Zebra LP2844, EventType: PRINTER, Code: offline-report

More testing to come...

Vzor- commented 3 years ago

@tresf I got job status changes coming through on windows now. None of them get lost, even if I add a sleep(1000) in the loop. I also found a way to get status information for both jobs and printers without needing to call printer_info_1.

I have not found a way to get rid of duplicate statuses yet. Right now in my branch the event should only fire for job status changes, but I still get a couple of dupes. Dupes are less frequent than it looks though, since the unwind exaggerates it.

This is the commit 7bb63f4a1930ed5af23b07966cc966cd648981f4 It's a pretty slapdash proof of concept but I thought I'd show what I found before calling it a night.

Vzor- commented 3 years ago

@klabarge So it is ready for a bit of testing on Windows. Along with the general testing, try changing the Printer Properties>Advanced>Keep Printed Documents of a few printers. It is ok to change it back and forth during runtime, no need to restart Tray. When a job runs through, the logs should end with We remember 0 jobs, we also want to see valid jobNames on all of the events on the sample page.

Known exceptions:

  1. If a job fails to print, it will report We remember 1 jobs or some other number.
  2. If a job is deleted from a printer that holds jobs, it will throw events lacking a jobName
  3. If a job is started before qz is listening, the jobName will be missing

If you get a failure, copy down the last 3 or so codes from the logs

klabarge commented 3 years ago

Printer: Epson TM-T88VI

we also want to see valid jobNames on all of the events on the sample page.

I sent the HTML sample to this printer and the jobName is incorrect. The printer queue shows QZ Tray HTML Print, but the logs show Local Downlevel Document

image

tresf commented 3 years ago

@klabarge this is somewhat expected for jobs stuck in the SPOOLING status, the jobName hasn't made it to the spooler at the time of that message arrive to QZ Tray. Please continue testing keeping this in mind.

Meanwhile @Vzor- has a creative idea for filtering that out which may retain the SPOOLING messaging. Working on that now.

klabarge commented 3 years ago

changing the Printer Properties>Advanced>Keep Printed Documents of a few printers.[...] When a job runs through, the logs should end with We remember 0 jobs

I tested this against the Epson TM-T88VI and the logs do end in We remember 0 jobs

General Testing

This printer has fantastic status reporting and so far everything has been captured.

 Wed Mar 03 2021 19:34:35 GMT-0500 (Colombia Standard Time): DOOR_OPEN: Level: WARN, From: EPSON TM-T88VI Receipt, EventType: PRINTER, Code: 4194304

 Wed Mar 03 2021 19:34:35 GMT-0500 (Colombia Standard Time): OFFLINE: Level: FATAL, From: EPSON TM-T88VI Receipt, EventType: PRINTER, Code: 128

 Wed Mar 03 2021 19:34:35 GMT-0500 (Colombia Standard Time): PAPER_OUT: Level: WARN, From: EPSON TM-T88VI Receipt, EventType: PRINTER, Code: 16

 Wed Mar 03 2021 19:35:28 GMT-0500 (Colombia Standard Time): SPOOLING: Level: INFO, From: EPSON TM-T88VI Receipt, EventType: JOB, Code: 8, JobId: 4, Job Name: Local Downlevel Document

 Wed Mar 03 2021 19:58:34 GMT-0500 (Colombia Standard Time): DELETING: Level: WARN, From: EPSON TM-T88VI Receipt, EventType: JOB, Code: 4, JobId: 4, Job Name: QZ Tray HTML Print

 Wed Mar 03 2021 19:58:34 GMT-0500 (Colombia Standard Time): DELETED: Level: WARN, From: EPSON TM-T88VI Receipt, EventType: JOB, Code: 256, JobId: 4, Job Name: QZ Tray HTML Print

 Wed Mar 03 2021 20:43:18 GMT-0500 (Colombia Standard Time): NOT_AVAILABLE: Level: FATAL, From: EPSON TM-T88VI Receipt, EventType: PRINTER, Code: 4096
tresf commented 3 years ago

@klabarge we made some improvements in d77000c. This should remove occasional duplicate COMPLETE messages and fix the Local Downlevel Document you're seeing when a job is in SPOOLING status. Can you try it out?

klabarge commented 3 years ago

This should remove occasional duplicate COMPLETE messages and fix the Local Downlevel Document

Confirmed, I no longer see Local Downlevel Document in the logs after this patch.

I'm testing on Ubuntu and I've noticed that cups sometimes has a description along with the status code. It doesn't look like this is ever captured in the logs. In the below scenario, the queue is in error despite having a status of "idle". Can this be captured?

 Mon Mar 08 2021 20:10:23 GMT-0500 (Eastern Standard Time): OK: Level: INFO, From: EPSON_TM-T88VI, EventType: PRINTER, Code: idle

image

tresf commented 3 years ago

the queue is in error despite having a status of "idle". Can this be captured?

We can check it out, can you offer steps to reproduce? I assume part of it is installing the Epson driver or something?

tresf commented 3 years ago

@klabarge,

@Vzor- will send you instructions for grabbing this data via his Java cups tool.

Vzor- commented 3 years ago

@klabarge Go ahead and download the cupstool.jar from that repo. Select "Get detailed printer info" and upload the result. If there is an associated job when the printer is in the error state, run "Get detailed job info"

klabarge commented 3 years ago

Here's the get detailed printer info output

attributes-charset: 1 charset {utf-8}
attributes-natural-language: 1 naturalLanguage {en-us}
marker-change-time: 1 integer {0}
printer-config-change-date-time: 1 dateTime {null}
printer-config-change-time: 1 integer {1615250897}
printer-current-time: 1 dateTime {null}
printer-dns-sd-name: 1 no-value {null}
printer-error-policy: 1 nameWithoutLanguage {retry-job}
printer-error-policy-supported: 4 nameWithoutLanguage {abort-job, retry-current-job, retry-job, stop-printer}
printer-icons: 1 uri {http://localhost/icons/EPSON_TM-T88VI.png}
printer-is-accepting-jobs: 1 boolean {false}
printer-is-shared: 1 boolean {false}
printer-is-temporary: 1 boolean {false}
printer-more-info: 1 uri {http://localhost/printers/EPSON_TM-T88VI}
printer-op-policy: 1 nameWithoutLanguage {default}
printer-state: 1 enum {idle}
printer-state-change-date-time: 1 dateTime {null}
printer-state-change-time: 1 integer {1615252328}
printer-state-message: 1 textWithoutLanguage {File "/usr/lib/cups/filter/rastertotmtr" not available: No such file or directory}
printer-state-reasons: 1 keyword {cups-missing-filter-warning}
printer-type: 1 enum {2150404}
printer-up-time: 1 integer {1616030675}
printer-uri-supported: 1 uri {ipp://localhost/printers/EPSON_TM-T88VI}
queued-job-count: 1 integer {0}
uri-authentication-supported: 1 keyword {requesting-user-name}
uri-security-supported: 1 keyword {none}
printer-name: 1 nameWithoutLanguage {EPSON_TM-T88VI}
printer-location: 1 textWithoutLanguage {}
printer-geo-location: 1 unknown {null}
printer-info: 1 textWithoutLanguage {EPSON TM-T88VI}
printer-organization: 1 textWithoutLanguage {}
printer-organizational-unit: 1 textWithoutLanguage {}
printer-uuid: 1 uri {urn:uuid:f2cbf368-2925-307a-40d5-ca5b15faa826}
job-quota-period: 1 integer {0}
job-k-limit: 1 integer {0}
job-page-limit: 1 integer {0}
job-sheets-default: 2 nameWithoutLanguage {none, none}
device-uri: 1 uri {usb://EPSON/TM-T88VI?serial=583254350422170000}
document-format-supported: 33 mimeMediaType {application/octet-stream, application/pdf, application/postscript, application/vnd.adobe-reader-postscript, application/vnd.cups-pdf, application/vnd.cups-pdf-banner, application/vnd.cups-postscript, application/vnd.cups-raster, application/vnd.cups-raw, application/x-cshell, application/x-csource, application/x-perl, application/x-shell, image/gif, image/jpeg, image/png, image/pwg-raster, image/tiff, image/urf, image/x-bitmap, image/x-photocd, image/x-portable-anymap, image/x-portable-bitmap, image/x-portable-graymap, image/x-portable-pixmap, image/x-sgi-rgb, image/x-sun-raster, image/x-xbitmap, image/x-xpixmap, image/x-xwindowdump, text/css, text/html, text/plain}
pwg-raster-document-resolution-supported: 1 resolution {null}
pwg-raster-document-sheet-back: 1 keyword {normal}
pwg-raster-document-type-supported: 14 keyword {adobergb-8, adobergb-16, black-1, black-8, black-16, cmyk-8, cmyk-16, rgb-8, rgb-16, sgray-1, sgray-8, sgray-16, srgb-8, srgb-16}
copies-default: 1 integer {1}
document-format-default: 1 mimeMediaType {application/octet-stream}
job-cancel-after-default: 1 integer {10800}
job-hold-until-default: 1 keyword {no-hold}
job-priority-default: 1 integer {50}
number-up-default: 1 integer {1}
notify-lease-duration-default: 1 integer {86400}
notify-events-default: 1 keyword {job-completed}
orientation-requested-default: 1 no-value {null}
print-quality-default: 1 enum {normal}
color-supported: 1 boolean {false}
pages-per-minute: 1 integer {1}
print-quality-supported: 1 enum {normal}
printer-make-and-model: 1 textWithoutLanguage {EPSON TM Thermal (203dpi)}
media-default: 1 keyword {om_rp-80x-2000_72.07x2000mm}
media-col-default: 1 collection {null}
media-supported: 6 keyword {om_rp-80x-200_72.07x199.99mm, om_rp-80x-2000_72.07x2000mm, om_rp-58x-200_52.6x199.99mm, om_rp-58x-2000_52.6x2000mm, custom_min_1x1in, custom_max_72.07x2000mm}
media-size-supported: 5 collection {null, null, null, null, null}
media-bottom-margin-supported: 1 integer {0}
media-left-margin-supported: 1 integer {0}
media-right-margin-supported: 1 integer {0}
media-top-margin-supported: 1 integer {0}
output-bin-supported: 1 keyword {face-up}
output-bin-default: 1 keyword {face-up}
print-color-mode-supported: 1 keyword {monochrome}
print-color-mode-default: 1 keyword {monochrome}
pwg-raster-document-type-supported: 2 keyword {black_1, sgray_8}
printer-resolution-supported: 1 resolution {null}
printer-resolution-default: 1 resolution {null}
pwg-raster-document-resolution-supported: 1 resolution {null}
sides-supported: 1 keyword {one-sided}
sides-default: 1 keyword {one-sided}
printer-commands: 1 keyword {none}
port-monitor: 1 nameWithoutLanguage {none}
port-monitor-supported: 1 nameWithoutLanguage {none}
finishings-supported: 1 enum {none}
finishings-default: 1 enum {none}
charset-configured: 1 charset {utf-8}
charset-supported: 2 charset {us-ascii, utf-8}
compression-supported: 2 keyword {none, gzip}
copies-supported: 1 rangeOfInteger {null}
cups-version: 1 textWithoutLanguage {2.2.7}
generated-natural-language-supported: 1 naturalLanguage {en-us}
ipp-features-supported: 1 keyword {subscription-object}
ipp-versions-supported: 4 keyword {1.0, 1.1, 2.0, 2.1}
ippget-event-life: 1 integer {15}
job-cancel-after-supported: 1 rangeOfInteger {null}
job-creation-attributes-supported: 18 keyword {copies, finishings, ipp-attribute-fidelity, job-hold-until, job-name, job-priority, job-sheets, media, media-col, multiple-document-handling, number-up, output-bin, orientation-requested, page-ranges, print-color-mode, print-quality, printer-resolution, sides}
job-hold-until-supported: 8 keyword {no-hold, indefinite, day-time, evening, night, second-shift, third-shift, weekend}
job-ids-supported: 1 boolean {false}
job-k-octets-supported: 1 rangeOfInteger {null}
job-priority-supported: 1 integer {100}
job-settable-attributes-supported: 16 keyword {copies, finishings, job-hold-until, job-name, job-priority, media, media-col, multiple-document-handling, number-up, output-bin, orientation-requested, page-ranges, print-color-mode, print-quality, printer-resolution, sides}
job-sheets-supported: 8 nameWithoutLanguage {none, classified, confidential, form, secret, standard, topsecret, unclassified}
jpeg-k-octets-supported: 1 rangeOfInteger {null}
jpeg-x-dimension-supported: 1 rangeOfInteger {null}
jpeg-y-dimension-supported: 1 rangeOfInteger {null}
media-col-supported: 7 keyword {media-bottom-margin, media-left-margin, media-right-margin, media-size, media-source, media-top-margin, media-type}
multiple-document-handling-supported: 2 keyword {separate-documents-uncollated-copies, separate-documents-collated-copies}
multiple-document-jobs-supported: 1 boolean {false}
multiple-operation-time-out: 1 integer {300}
multiple-operation-time-out-action: 1 keyword {process-job}
natural-language-configured: 1 naturalLanguage {en-us}
notify-attributes-supported: 3 keyword {printer-state-change-time, notify-lease-expiration-time, notify-subscriber-user-name}
notify-lease-duration-supported: 1 rangeOfInteger {null}
notify-max-events-supported: 1 integer {100}
notify-events-supported: 21 keyword {job-completed, job-config-changed, job-created, job-progress, job-state-changed, job-stopped, printer-added, printer-changed, printer-config-changed, printer-deleted, printer-finishings-changed, printer-media-changed, printer-modified, printer-restarted, printer-shutdown, printer-state-changed, printer-stopped, server-audit, server-restarted, server-started, server-stopped}
notify-pull-method-supported: 1 keyword {ippget}
notify-schemes-supported: 3 keyword {dbus, mailto, rss}
number-up-supported: 6 integer {1, 2, 4, 6, 9, 16}
operations-supported: 47 enum {Print-Job, Validate-Job, Create-Job, Send-Document, Cancel-Job, Get-Job-Attributes, Get-Jobs, Get-Printer-Attributes, Hold-Job, Release-Job, Pause-Printer, Resume-Printer, Purge-Jobs, Set-Printer-Attributes, Set-Job-Attributes, Get-Printer-Supported-Values, Create-Printer-Subscriptions, Create-Job-Subscriptions, Get-Subscription-Attributes, Get-Subscriptions, Renew-Subscription, Cancel-Subscription, Get-Notifications, Enable-Printer, Disable-Printer, Hold-New-Jobs, Release-Held-New-Jobs, Cancel-Jobs, Cancel-My-Jobs, Close-Job, CUPS-Get-Default, CUPS-Get-Printers, CUPS-Add-Modify-Printer, CUPS-Delete-Printer, CUPS-Get-Classes, CUPS-Add-Modify-Class, CUPS-Delete-Class, CUPS-Accept-Jobs, CUPS-Reject-Jobs, CUPS-Set-Default, CUPS-Get-Devices, CUPS-Get-PPDs, CUPS-Move-Job, CUPS-Authenticate-Job, CUPS-Get-PPD, CUPS-Get-Document, Restart-Job}
orientation-requested-supported: 4 enum {portrait, landscape, reverse-landscape, reverse-portrait}
page-ranges-supported: 1 boolean {false}
pdf-k-octets-supported: 1 rangeOfInteger {null}
pdf-versions-supported: 9 keyword {adobe-1.2, adobe-1.3, adobe-1.4, adobe-1.5, adobe-1.6, adobe-1.7, iso-19005-1_2005, iso-32000-1_2008, pwg-5102.3}
pdl-override-supported: 1 keyword {attempted}
printer-get-attributes-supported: 1 keyword {document-format}
printer-op-policy-supported: 3 nameWithoutLanguage {authenticated, default, kerberos}
printer-settable-attributes-supported: 5 keyword {printer-geo-location, printer-info, printer-location, printer-organization, printer-organizational-unit}
server-is-sharing-printers: 1 boolean {false}
which-jobs-supported: 9 keyword {completed, not-completed, aborted, all, canceled, pending, pending-held, processing, processing-stopped}
Vzor- commented 3 years ago

"cups-missing-filter" should be an error https://github.com/qzind/tray/blob/job-status/src/qz/printer/status/printer/CupsPrinterStatusMap.java#L62 Something odd is happening

Vzor- commented 3 years ago

@klabarge Could you do a "get all statuses" with the printer in that state

klabarge commented 3 years ago

@klabarge Could you do a "get all statuses" with the printer in that state

I'm not exactly sure what "get all statuses" is.

Here's the printer status as reported by QZ Tray.

Wed Mar 17 2021 23:08:31 GMT-0400 (Eastern Daylight Time): OK: Level: INFO, From: EPSON_TM-T88VI, EventType: PRINTER, Code: idle

This is the printer state from the cups-tool. It looks like this information is in the status message

Status Enum: idle
Status Message: printer-state-message: 1 textWithoutLanguage {File "/usr/lib/cups/filter/rastertotmtr" not available: No such file or directory}
Status Reason: printer-state-reasons: 1 keyword {cups-missing-filter-warning}
Vzor- commented 3 years ago

@klabarge Give it a try now, the text about which file is missing still won't be there but it should come up as an error.

klabarge commented 3 years ago

The printer is now in ERROR after that patch.

Thu Mar 25 2021 20:38:31 GMT-0400 (Eastern Daylight Time): ERROR: Level: FATAL, From: EPSON_TM-T88VI, EventType: PRINTER, Code: cups-missing-filter-warning

I re-tested on macOS and now there are a TON of code: processing in the logs. What's weird is the print job had already spooled, printed, and left the queue after only a few seconds. Then, for the next minute the jobs were spammed with PROCESSING

 Thu Mar 25 2021 20:54:42 GMT-0400 (Eastern Daylight Time): PAUSED: Level: WARN, From: Zebra LP2844, EventType: JOB, Code: job-hold-until-specified, JobId: 914, Job Name: QZ Tray HTML Print

 Thu Mar 25 2021 20:54:42 GMT-0400 (Eastern Daylight Time): SPOOLING: Level: INFO, From: Zebra LP2844, EventType: JOB, Code: pending, JobId: 914, Job Name: QZ Tray HTML Print

 Thu Mar 25 2021 20:54:43 GMT-0400 (Eastern Daylight Time): SPOOLING: Level: INFO, From: Zebra LP2844, EventType: JOB, Code: pending, JobId: 914, Job Name: QZ Tray HTML Print

 Thu Mar 25 2021 20:54:44 GMT-0400 (Eastern Daylight Time): PROCESSING: Level: INFO, From: Zebra LP2844, EventType: PRINTER, Code: processing

 Thu Mar 25 2021 20:54:45 GMT-0400 (Eastern Daylight Time): PRINTING: Level: INFO, From: Zebra LP2844, EventType: JOB, Code: job-printing, JobId: 914, Job Name: QZ Tray HTML Print

 Thu Mar 25 2021 20:54:45 GMT-0400 (Eastern Daylight Time): OK: Level: INFO, From: Zebra LP2844, EventType: PRINTER, Code: connecting-to-device

 Thu Mar 25 2021 20:54:46 GMT-0400 (Eastern Daylight Time): PROCESSING: Level: INFO, From: Zebra LP2844, EventType: PRINTER, Code: processing

 Thu Mar 25 2021 20:54:47 GMT-0400 (Eastern Daylight Time): PROCESSING: Level: INFO, From: Zebra LP2844, EventType: PRINTER, Code: processing

 Thu Mar 25 2021 20:54:47 GMT-0400 (Eastern Daylight Time): PROCESSING: Level: INFO, From: Zebra LP2844, EventType: PRINTER, Code: processing

 Thu Mar 25 2021 20:54:48 GMT-0400 (Eastern Daylight Time): PROCESSING: Level: INFO, From: Zebra LP2844, EventType: PRINTER, Code: processing

 Thu Mar 25 2021 20:54:49 GMT-0400 (Eastern Daylight Time): PROCESSING: Level: INFO, From: Zebra LP2844, EventType: PRINTER, Code: processing

 Thu Mar 25 2021 20:54:50 GMT-0400 (Eastern Daylight Time): PROCESSING: Level: INFO, From: Zebra LP2844, EventType: PRINTER, Code: processing

 Thu Mar 25 2021 20:54:50 GMT-0400 (Eastern Daylight Time): PROCESSING: Level: INFO, From: Zebra LP2844, EventType: PRINTER, Code: processing

 Thu Mar 25 2021 20:54:51 GMT-0400 (Eastern Daylight Time): PROCESSING: Level: INFO, From: Zebra LP2844, EventType: PRINTER, Code: processing

 Thu Mar 25 2021 20:54:52 GMT-0400 (Eastern Daylight Time): PROCESSING: Level: INFO, From: Zebra LP2844, EventType: PRINTER, Code: processing

 Thu Mar 25 2021 20:54:53 GMT-0400 (Eastern Daylight Time): PROCESSING: Level: INFO, From: Zebra LP2844, EventType: PRINTER, Code: processing

 Thu Mar 25 2021 20:54:53 GMT-0400 (Eastern Daylight Time): PROCESSING: Level: INFO, From: Zebra LP2844, EventType: PRINTER, Code: processing

 Thu Mar 25 2021 20:54:54 GMT-0400 (Eastern Daylight Time): PROCESSING: Level: INFO, From: Zebra LP2844, EventType: PRINTER, Code: processing

 Thu Mar 25 2021 20:54:55 GMT-0400 (Eastern Daylight Time): PROCESSING: Level: INFO, From: Zebra LP2844, EventType: PRINTER, Code: processing

 Thu Mar 25 2021 20:54:56 GMT-0400 (Eastern Daylight Time): PROCESSING: Level: INFO, From: Zebra LP2844, EventType: PRINTER, Code: processing

 Thu Mar 25 2021 20:54:56 GMT-0400 (Eastern Daylight Time): PROCESSING: Level: INFO, From: Zebra LP2844, EventType: PRINTER, Code: processing

 Thu Mar 25 2021 20:54:57 GMT-0400 (Eastern Daylight Time): PROCESSING: Level: INFO, From: Zebra LP2844, EventType: PRINTER, Code: processing

 Thu Mar 25 2021 20:54:58 GMT-0400 (Eastern Daylight Time): PROCESSING: Level: INFO, From: Zebra LP2844, EventType: PRINTER, Code: processing

 Thu Mar 25 2021 20:54:59 GMT-0400 (Eastern Daylight Time): PROCESSING: Level: INFO, From: Zebra LP2844, EventType: PRINTER, Code: processing

 Thu Mar 25 2021 20:54:59 GMT-0400 (Eastern Daylight Time): PROCESSING: Level: INFO, From: Zebra LP2844, EventType: PRINTER, Code: processing

 Thu Mar 25 2021 20:55:00 GMT-0400 (Eastern Daylight Time): PROCESSING: Level: INFO, From: Zebra LP2844, EventType: PRINTER, Code: processing

 Thu Mar 25 2021 20:55:01 GMT-0400 (Eastern Daylight Time): PROCESSING: Level: INFO, From: Zebra LP2844, EventType: PRINTER, Code: processing

 Thu Mar 25 2021 20:55:02 GMT-0400 (Eastern Daylight Time): PROCESSING: Level: INFO, From: Zebra LP2844, EventType: PRINTER, Code: processing

 Thu Mar 25 2021 20:55:03 GMT-0400 (Eastern Daylight Time): PROCESSING: Level: INFO, From: Zebra LP2844, EventType: PRINTER, Code: processing

 Thu Mar 25 2021 20:55:03 GMT-0400 (Eastern Daylight Time): PROCESSING: Level: INFO, From: Zebra LP2844, EventType: PRINTER, Code: processing

 Thu Mar 25 2021 20:55:04 GMT-0400 (Eastern Daylight Time): PROCESSING: Level: INFO, From: Zebra LP2844, EventType: PRINTER, Code: processing

 Thu Mar 25 2021 20:55:05 GMT-0400 (Eastern Daylight Time): PROCESSING: Level: INFO, From: Zebra LP2844, EventType: PRINTER, Code: processing

 Thu Mar 25 2021 20:55:06 GMT-0400 (Eastern Daylight Time): PROCESSING: Level: INFO, From: Zebra LP2844, EventType: PRINTER, Code: processing

 Thu Mar 25 2021 20:55:07 GMT-0400 (Eastern Daylight Time): PROCESSING: Level: INFO, From: Zebra LP2844, EventType: PRINTER, Code: processing

 Thu Mar 25 2021 20:55:08 GMT-0400 (Eastern Daylight Time): PROCESSING: Level: INFO, From: Zebra LP2844, EventType: PRINTER, Code: processing

 Thu Mar 25 2021 20:55:08 GMT-0400 (Eastern Daylight Time): PROCESSING: Level: INFO, From: Zebra LP2844, EventType: PRINTER, Code: processing

 Thu Mar 25 2021 20:55:09 GMT-0400 (Eastern Daylight Time): PROCESSING: Level: INFO, From: Zebra LP2844, EventType: PRINTER, Code: processing

 Thu Mar 25 2021 20:55:10 GMT-0400 (Eastern Daylight Time): PROCESSING: Level: INFO, From: Zebra LP2844, EventType: PRINTER, Code: processing

 Thu Mar 25 2021 20:55:11 GMT-0400 (Eastern Daylight Time): PROCESSING: Level: INFO, From: Zebra LP2844, EventType: PRINTER, Code: processing

 Thu Mar 25 2021 20:55:12 GMT-0400 (Eastern Daylight Time): PROCESSING: Level: INFO, From: Zebra LP2844, EventType: PRINTER, Code: processing

 Thu Mar 25 2021 20:55:13 GMT-0400 (Eastern Daylight Time): PROCESSING: Level: INFO, From: Zebra LP2844, EventType: PRINTER, Code: processing

 Thu Mar 25 2021 20:55:14 GMT-0400 (Eastern Daylight Time): PROCESSING: Level: INFO, From: Zebra LP2844, EventType: PRINTER, Code: processing

 Thu Mar 25 2021 20:55:15 GMT-0400 (Eastern Daylight Time): PROCESSING: Level: INFO, From: Zebra LP2844, EventType: PRINTER, Code: processing

 Thu Mar 25 2021 20:55:16 GMT-0400 (Eastern Daylight Time): PROCESSING: Level: INFO, From: Zebra LP2844, EventType: PRINTER, Code: processing

 Thu Mar 25 2021 20:55:17 GMT-0400 (Eastern Daylight Time): PROCESSING: Level: INFO, From: Zebra LP2844, EventType: PRINTER, Code: processing

 Thu Mar 25 2021 20:55:18 GMT-0400 (Eastern Daylight Time): PROCESSING: Level: INFO, From: Zebra LP2844, EventType: PRINTER, Code: processing

 Thu Mar 25 2021 20:55:19 GMT-0400 (Eastern Daylight Time): PROCESSING: Level: INFO, From: Zebra LP2844, EventType: PRINTER, Code: processing

 Thu Mar 25 2021 20:55:20 GMT-0400 (Eastern Daylight Time): PROCESSING: Level: INFO, From: Zebra LP2844, EventType: PRINTER, Code: processing

 Thu Mar 25 2021 20:55:21 GMT-0400 (Eastern Daylight Time): PROCESSING: Level: INFO, From: Zebra LP2844, EventType: PRINTER, Code: processing

 Thu Mar 25 2021 20:55:22 GMT-0400 (Eastern Daylight Time): PROCESSING: Level: INFO, From: Zebra LP2844, EventType: PRINTER, Code: processing

 Thu Mar 25 2021 20:55:23 GMT-0400 (Eastern Daylight Time): PROCESSING: Level: INFO, From: Zebra LP2844, EventType: PRINTER, Code: processing

 Thu Mar 25 2021 20:55:24 GMT-0400 (Eastern Daylight Time): PROCESSING: Level: INFO, From: Zebra LP2844, EventType: PRINTER, Code: processing

 Thu Mar 25 2021 20:55:25 GMT-0400 (Eastern Daylight Time): PROCESSING: Level: INFO, From: Zebra LP2844, EventType: PRINTER, Code: processing

 Thu Mar 25 2021 20:55:26 GMT-0400 (Eastern Daylight Time): PROCESSING: Level: INFO, From: Zebra LP2844, EventType: PRINTER, Code: processing

 Thu Mar 25 2021 20:55:27 GMT-0400 (Eastern Daylight Time): PROCESSING: Level: INFO, From: Zebra LP2844, EventType: PRINTER, Code: processing

 Thu Mar 25 2021 20:55:28 GMT-0400 (Eastern Daylight Time): PROCESSING: Level: INFO, From: Zebra LP2844, EventType: PRINTER, Code: processing

 Thu Mar 25 2021 20:55:28 GMT-0400 (Eastern Daylight Time): PROCESSING: Level: INFO, From: Zebra LP2844, EventType: PRINTER, Code: processing

 Thu Mar 25 2021 20:55:29 GMT-0400 (Eastern Daylight Time): PROCESSING: Level: INFO, From: Zebra LP2844, EventType: PRINTER, Code: processing

 Thu Mar 25 2021 20:55:30 GMT-0400 (Eastern Daylight Time): PROCESSING: Level: INFO, From: Zebra LP2844, EventType: PRINTER, Code: processing

 Thu Mar 25 2021 20:55:31 GMT-0400 (Eastern Daylight Time): PROCESSING: Level: INFO, From: Zebra LP2844, EventType: PRINTER, Code: processing

 Thu Mar 25 2021 20:55:32 GMT-0400 (Eastern Daylight Time): PROCESSING: Level: INFO, From: Zebra LP2844, EventType: PRINTER, Code: processing

 Thu Mar 25 2021 20:55:33 GMT-0400 (Eastern Daylight Time): PROCESSING: Level: INFO, From: Zebra LP2844, EventType: PRINTER, Code: processing

 Thu Mar 25 2021 20:55:34 GMT-0400 (Eastern Daylight Time): PROCESSING: Level: INFO, From: Zebra LP2844, EventType: PRINTER, Code: processing

 Thu Mar 25 2021 20:55:35 GMT-0400 (Eastern Daylight Time): PROCESSING: Level: INFO, From: Zebra LP2844, EventType: PRINTER, Code: processing

 Thu Mar 25 2021 20:55:36 GMT-0400 (Eastern Daylight Time): PROCESSING: Level: INFO, From: Zebra LP2844, EventType: PRINTER, Code: processing

 Thu Mar 25 2021 20:55:37 GMT-0400 (Eastern Daylight Time): PROCESSING: Level: INFO, From: Zebra LP2844, EventType: PRINTER, Code: processing

 Thu Mar 25 2021 20:55:38 GMT-0400 (Eastern Daylight Time): PROCESSING: Level: INFO, From: Zebra LP2844, EventType: PRINTER, Code: processing

 Thu Mar 25 2021 20:55:39 GMT-0400 (Eastern Daylight Time): PROCESSING: Level: INFO, From: Zebra LP2844, EventType: PRINTER, Code: processing

 Thu Mar 25 2021 20:55:41 GMT-0400 (Eastern Daylight Time): PROCESSING: Level: INFO, From: Zebra LP2844, EventType: PRINTER, Code: processing

 Thu Mar 25 2021 20:55:42 GMT-0400 (Eastern Daylight Time): PROCESSING: Level: INFO, From: Zebra LP2844, EventType: PRINTER, Code: processing

 Thu Mar 25 2021 20:55:43 GMT-0400 (Eastern Daylight Time): PROCESSING: Level: INFO, From: Zebra LP2844, EventType: PRINTER, Code: processing

 Thu Mar 25 2021 20:55:44 GMT-0400 (Eastern Daylight Time): PROCESSING: Level: INFO, From: Zebra LP2844, EventType: PRINTER, Code: processing

 Thu Mar 25 2021 20:55:45 GMT-0400 (Eastern Daylight Time): PRINTING: Level: INFO, From: Zebra LP2844, EventType: PRINTER, Code: cups-waiting-for-job-completed

 Thu Mar 25 2021 20:55:46 GMT-0400 (Eastern Daylight Time): COMPLETE: Level: INFO, From: Zebra LP2844, EventType: JOB, Code: job-completed-successfully, JobId: 914, Job Name: QZ Tray HTML Print

 Thu Mar 25 2021 20:55:47 GMT-0400 (Eastern Daylight Time): OK: Level: INFO, From: Zebra LP2844, EventType: PRINTER, Code: idle
klabarge commented 3 years ago

The printer status messages look much better now.

 Mon Mar 29 2021 21:11:32 GMT-0400 (Eastern Daylight Time): PAUSED: Level: WARN, From: Zebra LP2844, EventType: JOB, Code: job-hold-until-specified, JobId: 915, Job Name: QZ Tray HTML Print

 Mon Mar 29 2021 21:11:33 GMT-0400 (Eastern Daylight Time): SPOOLING: Level: INFO, From: Zebra LP2844, EventType: JOB, Code: pending, JobId: 915, Job Name: QZ Tray HTML Print

 Mon Mar 29 2021 21:11:34 GMT-0400 (Eastern Daylight Time): PROCESSING: Level: INFO, From: Zebra LP2844, EventType: PRINTER, Code: processing

 Mon Mar 29 2021 21:11:34 GMT-0400 (Eastern Daylight Time): PRINTING: Level: INFO, From: Zebra LP2844, EventType: JOB, Code: job-printing, JobId: 915, Job Name: QZ Tray HTML Print

 Mon Mar 29 2021 21:11:35 GMT-0400 (Eastern Daylight Time): PROCESSING: Level: INFO, From: Zebra LP2844, EventType: PRINTER, Code: connecting-to-device

 Mon Mar 29 2021 21:11:35 GMT-0400 (Eastern Daylight Time): PROCESSING: Level: INFO, From: Zebra LP2844, EventType: PRINTER, Code: processing

 Mon Mar 29 2021 21:11:36 GMT-0400 (Eastern Daylight Time): PRINTING: Level: INFO, From: Zebra LP2844, EventType: PRINTER, Code: cups-waiting-for-job-completed

 Mon Mar 29 2021 21:11:40 GMT-0400 (Eastern Daylight Time): COMPLETE: Level: INFO, From: Zebra LP2844, EventType: JOB, Code: job-completed-successfully, JobId: 915, Job Name: QZ Tray HTML Print

 Mon Mar 29 2021 21:11:40 GMT-0400 (Eastern Daylight Time): OK: Level: INFO, From: Zebra LP2844, EventType: PRINTER, Code: idle

However, now the logs have many We remember x jobs messages.

[INFO] 2021-03-29 21:11:31,894 @ qz.utils.PrintingUtilities:?
    Printing complete
[TRACE] 2021-03-29 21:11:31,894 @ qz.utils.PrintingUtilities:?
    Returning processor back to pool
[WARN] 2021-03-29 21:11:32,439 @ qz.printer.status.CupsStatusHandler:?
    We remember 1 jobs
[WARN] 2021-03-29 21:11:36,579 @ qz.printer.status.CupsStatusHandler:?
    We remember 1 jobs
[WARN] 2021-03-29 21:11:36,583 @ qz.printer.status.CupsStatusHandler:?
    We remember 1 jobs
[WARN] 2021-03-29 21:11:37,593 @ qz.printer.status.CupsStatusHandler:?
    We remember 1 jobs
[WARN] 2021-03-29 21:11:37,597 @ qz.printer.status.CupsStatusHandler:?
    We remember 1 jobs
[WARN] 2021-03-29 21:11:38,603 @ qz.printer.status.CupsStatusHandler:?
    We remember 1 jobs
[WARN] 2021-03-29 21:11:38,606 @ qz.printer.status.CupsStatusHandler:?
    We remember 1 jobs
[WARN] 2021-03-29 21:11:40,569 @ qz.printer.status.CupsStatusHandler:?
    We remember 0 jobs
[WARN] 2021-03-29 21:11:40,574 @ qz.printer.status.CupsStatusHandler:?
    We remember 0 jobs
[WARN] 2021-03-29 21:11:41,578 @ qz.printer.status.CupsStatusHandler:?
    We remember 0 jobs
[WARN] 2021-03-29 21:11:41,583 @ qz.printer.status.CupsStatusHandler:?
    We remember 0 jobs
[WARN] 2021-03-29 21:11:42,586 @ qz.printer.status.CupsStatusHandler:?
    We remember 0 jobs
[WARN] 2021-03-29 21:11:42,590 @ qz.printer.status.CupsStatusHandler:?
    We remember 0 jobs
[WARN] 2021-03-29 21:11:43,595 @ qz.printer.status.CupsStatusHandler:?
    We remember 0 jobs
[WARN] 2021-03-29 21:11:43,601 @ qz.printer.status.CupsStatusHandler:?
    We remember 0 jobs
[WARN] 2021-03-29 21:11:44,609 @ qz.printer.status.CupsStatusHandler:?
    We remember 0 jobs
[WARN] 2021-03-29 21:11:44,615 @ qz.printer.status.CupsStatusHandler:?
    We remember 0 jobs
[WARN] 2021-03-29 21:11:45,622 @ qz.printer.status.CupsStatusHandler:?
    We remember 0 jobs
[WARN] 2021-03-29 21:11:45,627 @ qz.printer.status.CupsStatusHandler:?
    We remember 0 jobs
[WARN] 2021-03-29 21:11:46,633 @ qz.printer.status.CupsStatusHandler:?
    We remember 0 jobs
[WARN] 2021-03-29 21:11:46,638 @ qz.printer.status.CupsStatusHandler:?
    We remember 0 jobs
[WARN] 2021-03-29 21:11:47,656 @ qz.printer.status.CupsStatusHandler:?
    We remember 0 jobs
[WARN] 2021-03-29 21:11:47,661 @ qz.printer.status.CupsStatusHandler:?
    We remember 0 jobs
[WARN] 2021-03-29 21:11:48,669 @ qz.printer.status.CupsStatusHandler:?
    We remember 0 jobs
[WARN] 2021-03-29 21:11:48,674 @ qz.printer.status.CupsStatusHandler:?
    We remember 0 jobs
[WARN] 2021-03-29 21:11:49,678 @ qz.printer.status.CupsStatusHandler:?
    We remember 0 jobs
[WARN] 2021-03-29 21:11:49,684 @ qz.printer.status.CupsStatusHandler:?
    We remember 0 jobs
[WARN] 2021-03-29 21:11:50,692 @ qz.printer.status.CupsStatusHandler:?
    We remember 0 jobs
[WARN] 2021-03-29 21:11:50,700 @ qz.printer.status.CupsStatusHandler:?
    We remember 0 jobs
[WARN] 2021-03-29 21:11:51,708 @ qz.printer.status.CupsStatusHandler:?
    We remember 0 jobs
[WARN] 2021-03-29 21:11:51,713 @ qz.printer.status.CupsStatusHandler:?
    We remember 0 jobs
[WARN] 2021-03-29 21:11:52,719 @ qz.printer.status.CupsStatusHandler:?
    We remember 0 jobs
[WARN] 2021-03-29 21:11:52,722 @ qz.printer.status.CupsStatusHandler:?
    We remember 0 jobs
[WARN] 2021-03-29 21:11:53,729 @ qz.printer.status.CupsStatusHandler:?
    We remember 0 jobs
[WARN] 2021-03-29 21:11:53,734 @ qz.printer.status.CupsStatusHandler:?
    We remember 0 jobs
[WARN] 2021-03-29 21:11:54,738 @ qz.printer.status.CupsStatusHandler:?
    We remember 0 jobs
[WARN] 2021-03-29 21:11:54,743 @ qz.printer.status.CupsStatusHandler:?
    We remember 0 jobs
[WARN] 2021-03-29 21:11:55,749 @ qz.printer.status.CupsStatusHandler:?
    We remember 0 jobs
[WARN] 2021-03-29 21:11:55,754 @ qz.printer.status.CupsStatusHandler:?
    We remember 0 jobs
[WARN] 2021-03-29 21:11:56,759 @ qz.printer.status.CupsStatusHandler:?
    We remember 0 jobs
[WARN] 2021-03-29 21:11:56,765 @ qz.printer.status.CupsStatusHandler:?
    We remember 0 jobs
[WARN] 2021-03-29 21:11:57,773 @ qz.printer.status.CupsStatusHandler:?
    We remember 0 jobs
tresf commented 3 years ago

However, now the logs have many We remember x jobs messages.

We won't be keeping these in; they should go to zero after jobs are done and @Vzor- wanted to double-check we didn't have stuff lingering. I'll let @Vzor- chime in in regards to if the frequency is of a concern, but please continue, we'd like to merge tonight if possible.

Vzor- commented 3 years ago

I'm going to assume that level of spam is unique to this issue of multiple PROCESSING statuses. This looks good to me.