search

apple / cups

Apple CUPS Sources
https://www.cups.org
Apache License 2.0
1.93k stars 464 forks source link

cupsd freezes and consumes 100% CPU #5860

Closed arobert-delfingen closed 3 years ago

arobert-delfingen commented 3 years ago

On several servers, from time to time cups is not responding : the cupsd processus consumes 100% CPU. The only solution is to kill then restart it.

We are using IPP protocol, through CUPS4J to communicate with cups.

Version of cups we are using : 2.2.10-6+deb10u3

Below is 2 debug logs :

D [02/Dec/2020:08:57:44 +0100] [Client 13425] Read: status=100, state=6 D [02/Dec/2020:08:57:44 +0100] [Client 13425] Read: status=100, state=6 D [02/Dec/2020:08:57:44 +0100] [Client 13425] Read: status=100, state=6 D [02/Dec/2020:08:57:44 +0100] [Client 13425] Read: status=100, state=6 D [02/Dec/2020:08:57:44 +0100] [Client 13425] Read: status=100, state=6 D [02/Dec/2020:08:57:44 +0100] [Client 13425] Read: status=100, state=6 D [02/Dec/2020:08:57:44 +0100] [Client 13425] Read: status=100, state=6 D [02/Dec/2020:08:57:44 +0100] [Client 13425] Read: status=100, state=6 D [02/Dec/2020:08:57:44 +0100] [Client 13425] Read: status=100, state=6 D [02/Dec/2020:08:57:44 +0100] [Client 13425] Read: status=100, state=6 D [02/Dec/2020:08:57:44 +0100] [Client 13425] Read: status=100, state=6 D [02/Dec/2020:08:57:44 +0100] [Client 13425] Read: status=100, state=6 D [02/Dec/2020:08:57:44 +0100] [Client 13425] Read: status=100, state=6 D [02/Dec/2020:08:57:44 +0100] [Client 13425] 2.0 Get-Printer-Attributes 1 D [02/Dec/2020:08:57:44 +0100] Get-Printer-Attributes ipp://localhost:631/printers/IT08872 D [02/Dec/2020:08:57:44 +0100] [Client 13425] Returning IPP successful-ok for Get-Printer-Attributes (ipp://localhost:631/printers/IT08872) from localhost. D [02/Dec/2020:08:57:44 +0100] [Client 13425] Content-Length: 1994 D [02/Dec/2020:08:57:44 +0100] [Client 13425] cupsdSendHeader: code=200, type=""application/ipp"", auth_type=0 D [02/Dec/2020:08:57:44 +0100] [Client 13425] con->http=0x564da04ac080 D [02/Dec/2020:08:57:44 +0100] [Client 13425] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=1994, response=0x564da04a3bf0(IPP_STATE_DATA), pipe_pid=0, file=-1 D [02/Dec/2020:08:57:44 +0100] [Client 13425] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0 D [02/Dec/2020:08:57:44 +0100] [Client 13425] bytes=0, http_state=0, data_remaining=1994 D [02/Dec/2020:08:57:44 +0100] [Client 13425] Flushing write buffer. D [02/Dec/2020:08:57:44 +0100] [Client 13425] New state is HTTP_STATE_WAITING D [02/Dec/2020:08:57:44 +0100] [Client 13425] Waiting for request. D [02/Dec/2020:08:57:44 +0100] cupsdSetBusyState: newbusy=""Printing jobs and dirty files"", busy=""Active clients, printing jobs, and dirty files"" D [02/Dec/2020:08:57:44 +0100] [Job 4993] Get-Printer-Attributes: successful-ok (successful-ok) D [02/Dec/2020:08:57:44 +0100] [Job 4993] copies-supported=1-9999 D [02/Dec/2020:08:57:44 +0100] [Job 4993] cups-version = "2.2.10" D [02/Dec/2020:08:57:44 +0100] [Job 4993] document-format-supported (34 values) D [02/Dec/2020:08:57:44 +0100] [Job 4993] [0] = "application/octet-stream" D [02/Dec/2020:08:57:44 +0100] [Job 4993] [1] = "application/pdf" D [02/Dec/2020:08:57:44 +0100] [Job 4993] [2] = "application/postscript" D [02/Dec/2020:08:57:44 +0100] [Job 4993] [3] = "application/vnd.adobe-reader-postscript" D [02/Dec/2020:08:57:44 +0100] [Job 4993] [4] = "application/vnd.cups-command" D [02/Dec/2020:08:57:44 +0100] [Job 4993] [5] = "application/vnd.cups-pdf" D [02/Dec/2020:08:57:44 +0100] [Job 4993] [6] = "application/vnd.cups-pdf-banner" D [02/Dec/2020:08:57:44 +0100] [Job 4993] [7] = "application/vnd.cups-postscript" D [02/Dec/2020:08:57:44 +0100] [Job 4993] [8] = "application/vnd.cups-raster" D [02/Dec/2020:08:57:44 +0100] [Job 4993] [9] = "application/vnd.cups-raw" D [02/Dec/2020:08:57:44 +0100] [Job 4993] [10] = "application/x-cshell" D [02/Dec/2020:08:57:44 +0100] [Job 4993] [11] = "application/x-csource" D [02/Dec/2020:08:57:44 +0100] [Job 4993] [12] = "application/x-perl" D [02/Dec/2020:08:57:44 +0100] [Job 4993] [13] = "application/x-shell" D [02/Dec/2020:08:57:44 +0100] [Job 4993] [14] = "image/gif" D [02/Dec/2020:08:57:44 +0100] [Job 4993] [15] = "image/jpeg" D [02/Dec/2020:08:57:44 +0100] [Job 4993] [16] = "image/png" D [02/Dec/2020:08:57:44 +0100] [Job 4993] [17] = "image/pwg-raster" D [02/Dec/2020:08:57:44 +0100] [Job 4993] [18] = "image/tiff" D [02/Dec/2020:08:57:44 +0100] [Job 4993] [19] = "image/urf" D [02/Dec/2020:08:57:44 +0100] [Job 4993] [20] = "image/x-bitmap" D [02/Dec/2020:08:57:44 +0100] [Job 4993] [21] = "image/x-photocd" D [02/Dec/2020:08:57:44 +0100] [Job 4993] [22] = "image/x-portable-anymap" D [02/Dec/2020:08:57:44 +0100] [Job 4993] [23] = "image/x-portable-bitmap" D [02/Dec/2020:08:57:44 +0100] [Job 4993] [24] = "image/x-portable-graymap" D [02/Dec/2020:08:57:44 +0100] [Job 4993] [25] = "image/x-portable-pixmap" D [02/Dec/2020:08:57:44 +0100] [Job 4993] [26] = "image/x-sgi-rgb" D [02/Dec/2020:08:57:44 +0100] [Job 4993] [27] = "image/x-sun-raster" D [02/Dec/2020:08:57:44 +0100] [Job 4993] [28] = "image/x-xbitmap" D [02/Dec/2020:08:57:44 +0100] [Job 4993] [29] = "image/x-xpixmap" D [02/Dec/2020:08:57:44 +0100] [Job 4993] [30] = "image/x-xwindowdump" D [02/Dec/2020:08:57:44 +0100] [Job 4993] [31] = "text/css" D [02/Dec/2020:08:57:44 +0100] [Job 4993] [32] = "text/html" D [02/Dec/2020:08:57:44 +0100] [Job 4993] [33] = "text/plain" D [02/Dec/2020:08:57:44 +0100] [Job 4993] media-col-supported (7 values) D [02/Dec/2020:08:57:44 +0100] [Job 4993] [0] = "media-bottom-margin" D [02/Dec/2020:08:57:44 +0100] [Job 4993] [1] = "media-left-margin" D [02/Dec/2020:08:57:44 +0100] [Job 4993] [2] = "media-right-margin" D [02/Dec/2020:08:57:44 +0100] [Job 4993] [3] = "media-size" D [02/Dec/2020:08:57:44 +0100] [Job 4993] [4] = "media-source" D [02/Dec/2020:08:57:44 +0100] [Job 4993] [5] = "media-top-margin" D [02/Dec/2020:08:57:44 +0100] [Job 4993] [6] = "media-type" D [02/Dec/2020:08:57:44 +0100] [Job 4993] operations-supported (47 values) D [02/Dec/2020:08:57:44 +0100] [Job 4993] [0] = Print-Job D [02/Dec/2020:08:57:44 +0100] [Job 4993] [1] = Validate-Job D [02/Dec/2020:08:57:44 +0100] [Job 4993] [2] = Create-Job D [02/Dec/2020:08:57:44 +0100] [Job 4993] [3] = Send-Document D [02/Dec/2020:08:57:44 +0100] [Job 4993] [4] = Cancel-Job D [02/Dec/2020:08:57:44 +0100] [Job 4993] [5] = Get-Job-Attributes D [02/Dec/2020:08:57:44 +0100] [Job 4993] [6] = Get-Jobs D [02/Dec/2020:08:57:44 +0100] [Job 4993] [7] = Get-Printer-Attributes D [02/Dec/2020:08:57:44 +0100] [Job 4993] [8] = Hold-Job D [02/Dec/2020:08:57:44 +0100] [Job 4993] [9] = Release-Job D [02/Dec/2020:08:57:44 +0100] [Job 4993] [10] = Pause-Printer D [02/Dec/2020:08:57:44 +0100] [Job 4993] [11] = Resume-Printer D [02/Dec/2020:08:57:44 +0100] [Job 4993] [12] = Purge-Jobs D [02/Dec/2020:08:57:44 +0100] [Job 4993] [13] = Set-Printer-Attributes D [02/Dec/2020:08:57:44 +0100] [Job 4993] [14] = Set-Job-Attributes D [02/Dec/2020:08:57:44 +0100] [Job 4993] [15] = Get-Printer-Supported-Values D [02/Dec/2020:08:57:44 +0100] [Job 4993] [16] = Create-Printer-Subscriptions D [02/Dec/2020:08:57:44 +0100] [Job 4993] [17] = Create-Job-Subscriptions D [02/Dec/2020:08:57:44 +0100] [Job 4993] [18] = Get-Subscription-Attributes D [02/Dec/2020:08:57:44 +0100] [Job 4993] [19] = Get-Subscriptions D [02/Dec/2020:08:57:44 +0100] [Job 4993] [20] = Renew-Subscription D [02/Dec/2020:08:57:44 +0100] [Job 4993] [21] = Cancel-Subscription D [02/Dec/2020:08:57:44 +0100] [Job 4993] [22] = Get-Notifications D [02/Dec/2020:08:57:44 +0100] [Job 4993] [23] = Enable-Printer D [02/Dec/2020:08:57:44 +0100] [Job 4993] [24] = Disable-Printer D [02/Dec/2020:08:57:44 +0100] [Job 4993] [25] = Hold-New-Jobs D [02/Dec/2020:08:57:44 +0100] [Job 4993] [26] = Release-Held-New-Jobs D [02/Dec/2020:08:57:44 +0100] [Job 4993] [27] = Cancel-Jobs D [02/Dec/2020:08:57:44 +0100] [Job 4993] [28] = Cancel-My-Jobs D [02/Dec/2020:08:57:44 +0100] [Job 4993] [29] = Close-Job D [02/Dec/2020:08:57:44 +0100] [Job 4993] [30] = CUPS-Get-Default D [02/Dec/2020:08:57:44 +0100] [Job 4993] [31] = CUPS-Get-Printers D [02/Dec/2020:08:57:44 +0100] [Job 4993] [32] = CUPS-Add-Modify-Printer D [02/Dec/2020:08:57:44 +0100] [Job 4993] [33] = CUPS-Delete-Printer D [02/Dec/2020:08:57:44 +0100] [Job 4993] [34] = CUPS-Get-Classes D [02/Dec/2020:08:57:44 +0100] [Job 4993] [35] = CUPS-Add-Modify-Class D [02/Dec/2020:08:57:44 +0100] [Job 4993] [36] = CUPS-Delete-Class D [02/Dec/2020:08:57:44 +0100] [Job 4993] [37] = CUPS-Accept-Jobs D [02/Dec/2020:08:57:44 +0100] [Job 4993] [38] = CUPS-Reject-Jobs D [02/Dec/2020:08:57:44 +0100] [Job 4993] [39] = CUPS-Set-Default D [02/Dec/2020:08:57:44 +0100] [Job 4993] [40] = CUPS-Get-Devices D [02/Dec/2020:08:57:44 +0100] [Job 4993] [41] = CUPS-Get-PPDs D [02/Dec/2020:08:57:44 +0100] [Job 4993] [42] = CUPS-Move-Job D [02/Dec/2020:08:57:44 +0100] [Job 4993] [43] = CUPS-Authenticate-Job D [02/Dec/2020:08:57:44 +0100] [Job 4993] [44] = CUPS-Get-PPD D [02/Dec/2020:08:57:44 +0100] [Job 4993] [45] = CUPS-Get-Document D [02/Dec/2020:08:57:44 +0100] [Job 4993] [46] = Restart-Job D [02/Dec/2020:08:57:44 +0100] [Job 4993] Set job-printer-state-message to ""Connected to printer."", current level=INFO D [02/Dec/2020:08:57:44 +0100] [Job 4993] update_reasons(attr=1(none), s="(null)") D [02/Dec/2020:08:57:44 +0100] [Job 4993] STATE: -none D [02/Dec/2020:08:57:44 +0100] Discarding unused job-progress event... D [02/Dec/2020:08:57:44 +0100] Discarding unused printer-state-changed event... D [02/Dec/2020:08:57:44 +0100] [Job 4993] ATTR: marker-colors=\'"#000000"\' D [02/Dec/2020:08:57:44 +0100] cupsdMarkDirty(P----) D [02/Dec/2020:08:57:44 +0100] cupsdSetBusyState: newbusy=""Printing jobs and dirty files"", busy=""Printing jobs and dirty files"" D [02/Dec/2020:08:57:44 +0100] [Job 4993] ATTR: marker-levels=60 D [02/Dec/2020:08:57:44 +0100] cupsdMarkDirty(P----) D [02/Dec/2020:08:57:44 +0100] cupsdSetBusyState: newbusy=""Printing jobs and dirty files"", busy=""Printing jobs and dirty files"" D [02/Dec/2020:08:57:44 +0100] [Job 4993] ATTR: marker-names=\'"Canon CRG052 Black Toner"\' D [02/Dec/2020:08:57:44 +0100] cupsdMarkDirty(P----) D [02/Dec/2020:08:57:44 +0100] cupsdSetBusyState: newbusy=""Printing jobs and dirty files"", busy=""Printing jobs and dirty files"" D [02/Dec/2020:08:57:44 +0100] [Job 4993] ATTR: marker-types=\'"toner-cartridge"\' D [02/Dec/2020:08:57:44 +0100] cupsdMarkDirty(P----) D [02/Dec/2020:08:57:44 +0100] cupsdSetBusyState: newbusy=""Printing jobs and dirty files"", busy=""Printing jobs and dirty files"" D [02/Dec/2020:08:57:44 +0100] Discarding unused printer-state-changed event... D [02/Dec/2020:08:57:44 +0100] [Job 4993] final_content_type="application/vnd.cups-postscript", document_format="application/vnd.cups-postscript" D [02/Dec/2020:08:57:44 +0100] [Job 4993] Validate-Job IPP/2.0 D [02/Dec/2020:08:57:44 +0100] [Job 4993] printer-uri="ipp://localhost:631/printers/IT08872" D [02/Dec/2020:08:57:44 +0100] [Job 4993] requesting-user-name="remroot" D [02/Dec/2020:08:57:44 +0100] [Job 4993] job-name="Untitled" D [02/Dec/2020:08:57:44 +0100] [Job 4993] document-format="application/vnd.cups-postscript" D [02/Dec/2020:08:57:44 +0100] [Job 4993] IPP/2.0 Validate-Job #2 D [02/Dec/2020:08:57:44 +0100] [Job 4993] ---- operation-attributes-tag ---- D [02/Dec/2020:08:57:44 +0100] [Job 4993] attributes-charset charset utf-8 D [02/Dec/2020:08:57:44 +0100] [Job 4993] attributes-natural-language naturalLanguage en-us D [02/Dec/2020:08:57:44 +0100] [Job 4993] printer-uri uri ipp://localhost:631/printers/IT08872 D [02/Dec/2020:08:57:44 +0100] [Job 4993] requesting-user-name nameWithoutLanguage remroot D [02/Dec/2020:08:57:44 +0100] [Job 4993] job-name nameWithoutLanguage Untitled D [02/Dec/2020:08:57:44 +0100] [Job 4993] document-format mimeMediaType application/vnd.cups-postscript D [02/Dec/2020:08:57:44 +0100] [Job 4993] ---- end-of-attributes-tag ---- D [02/Dec/2020:08:57:44 +0100] [Job 4993] IPP/2.0 Get-Printer-Attributes #3 D [02/Dec/2020:08:57:44 +0100] [Job 4993] ---- operation-attributes-tag ---- D [02/Dec/2020:08:57:44 +0100] [Job 4993] attributes-charset charset utf-8 D [02/Dec/2020:08:57:44 +0100] [Job 4993] attributes-natural-language naturalLanguage en-us D [02/Dec/2020:08:57:44 +0100] [Job 4993] printer-uri uri ipp://localhost:631/printers/IT08872 D [02/Dec/2020:08:57:44 +0100] [Job 4993] requesting-user-name nameWithoutLanguage remroot D [02/Dec/2020:08:57:44 +0100] [Job 4993] requested-attributes 1setOf keyword compression-supported,copies-supported,cups-version,document-format-supported,job-password-encryption-supported,marker-colors,marker-high-levels,marker-levels,marker-low-levels,marker-message,marker-names,marker-types,media-col-supported,multiple-document-handling-supported,operations-supported,print-color-mode-supported,printer-alert,printer-alert-description,printer-is-accepting-jobs,printer-mandatory-job-attributes,printer-state,printer-state-message,printer-state-reasons D [02/Dec/2020:08:57:44 +0100] [Job 4993] ---- end-of-attributes-tag ---- D [02/Dec/2020:08:57:44 +0100] [Client 13425] POST /printers/IT08872 HTTP/1.1 D [02/Dec/2020:08:57:44 +0100] cupsdSetBusyState: newbusy=""Active clients, printing jobs, and dirty files"", busy=""Printing jobs and dirty files"" D [02/Dec/2020:08:57:44 +0100] [Client 13425] Read: status=200, state=6 D [02/Dec/2020:08:57:44 +0100] [Client 13425] No authentication data provided. D [02/Dec/2020:08:57:44 +0100] [Client 13425] 2.0 Validate-Job 2 D [02/Dec/2020:08:57:44 +0100] Validate-Job ipp://localhost:631/printers/IT08872 D [02/Dec/2020:08:57:44 +0100] [Client 13425] Returning IPP successful-ok for Validate-Job (ipp://localhost:631/printers/IT08872) from localhost. D [02/Dec/2020:08:57:44 +0100] [Client 13425] Content-Length: 75 D [02/Dec/2020:08:57:44 +0100] [Client 13425] cupsdSendHeader: code=200, type=""application/ipp"", auth_type=0 D [02/Dec/2020:08:57:44 +0100] cupsdSetBusyState: newbusy=""Active clients, printing jobs, and dirty files"", busy=""Active clients, printing jobs, and dirty files"" D [02/Dec/2020:08:57:44 +0100] [Client 13426] Server address is ""127.0.0.1"". D [02/Dec/2020:08:57:44 +0100] [Client 13426] Accepted from localhost:44662 (IPv4) D [02/Dec/2020:08:57:44 +0100] [Client 13426] Waiting for request. D [02/Dec/2020:08:57:44 +0100] [Client 13425] con->http=0x564da04ac080 D [02/Dec/2020:08:57:44 +0100] [Client 13425] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=75, response=0x564d9fffb7f0(IPP_STATE_DATA), pipe_pid=0, file=-1 D [02/Dec/2020:08:57:44 +0100] [Client 13425] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0 D [02/Dec/2020:08:57:44 +0100] [Client 13425] bytes=0, http_state=0, data_remaining=75 "localhost - - [02/Dec/2020:08:57:44 +0100] ""POST /printers/IT08872 HTTP/1.1"" 200 231 Validate-Job successful-ok D [02/Dec/2020:08:57:44 +0100] [Client 13425] Flushing write buffer. D [02/Dec/2020:08:57:44 +0100] [Client 13425] New state is HTTP_STATE_WAITING D [02/Dec/2020:08:57:44 +0100] [Client 13425] Waiting for request. D [02/Dec/2020:08:57:44 +0100] cupsdSetBusyState: newbusy=""Printing jobs and dirty files"", busy=""Active clients, printing jobs, and dirty files"" D [02/Dec/2020:08:57:44 +0100] [Client 13426] POST /printers/IT08872 HTTP/1.1 D [02/Dec/2020:08:57:44 +0100] cupsdSetBusyState: newbusy=""Active clients, printing jobs, and dirty files"", busy=""Printing jobs and dirty files"" D [02/Dec/2020:08:57:44 +0100] [Client 13426] Read: status=200, state=6 D [02/Dec/2020:08:57:44 +0100] [Client 13426] No authentication data provided. D [02/Dec/2020:08:57:44 +0100] [Client 13426] 2.0 Get-Printer-Attributes 3 D [02/Dec/2020:08:57:44 +0100] Get-Printer-Attributes ipp://localhost:631/printers/IT08872 D [02/Dec/2020:08:57:44 +0100] [Client 13426] Returning IPP successful-ok for Get-Printer-Attributes (ipp://localhost:631/printers/IT08872) from localhost. D [02/Dec/2020:08:57:44 +0100] [Client 13426] Content-Length: 1994 D [02/Dec/2020:08:57:44 +0100] [Client 13426] cupsdSendHeader: code=200, type=""application/ipp"", auth_type=0 D [02/Dec/2020:08:57:44 +0100] [Client 13425] POST /printers/IT08872 HTTP/1.1 D [02/Dec/2020:08:57:44 +0100] cupsdSetBusyState: newbusy=""Active clients, printing jobs, and dirty files"", busy=""Active clients, printing jobs, and dirty files"" D [02/Dec/2020:08:57:44 +0100] [Client 13425] Read: status=200, state=6 D [02/Dec/2020:08:57:44 +0100] [Client 13425] No authentication data provided. D [02/Dec/2020:08:57:44 +0100] [Client 13425] 2.0 Create-Job 4 D [02/Dec/2020:08:57:44 +0100] Create-Job ipp://localhost:631/printers/IT08872 D [02/Dec/2020:08:57:44 +0100] [Job 4495] Removing from history. D [02/Dec/2020:08:57:44 +0100] cupsdMarkDirty(---J-) D [02/Dec/2020:08:57:44 +0100] cupsdSetBusyState: newbusy=""Active clients, printing jobs, and dirty files"", busy=""Active clients, printing jobs, and dirty files"" D [02/Dec/2020:08:57:44 +0100] [Job 4995] Applying default options... D [02/Dec/2020:08:57:44 +0100] add_job: requesting-user-name=""remroot"" D [02/Dec/2020:08:57:44 +0100] Adding default job-sheets values ""none,none""... "I [02/Dec/2020:08:57:44 +0100] [Job 4995] Adding start banner page ""none"". D [02/Dec/2020:08:57:44 +0100] Discarding unused job-created event... "I [02/Dec/2020:08:57:44 +0100] [Job 4995] Queued on ""IT08872"" by ""remroot"". D [02/Dec/2020:08:57:44 +0100] [Client 13425] Returning IPP successful-ok for Create-Job (ipp://localhost:631/printers/IT08872) from localhost. D [02/Dec/2020:08:57:44 +0100] [Client 13425] Content-Length: 206 D [02/Dec/2020:08:57:44 +0100] [Client 13425] cupsdSendHeader: code=200, type=""application/ipp"", auth_type=0 D [02/Dec/2020:08:57:44 +0100] [Client 13426] con->http=0x564d9fff6bf0 D [02/Dec/2020:08:57:44 +0100] [Client 13426] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=1994, response=0x564da04a3bf0(IPP_STATE_DATA), pipe_pid=0, file=-1 D [02/Dec/2020:08:57:44 +0100] [Client 13426] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0 D [02/Dec/2020:08:57:44 +0100] [Client 13426] bytes=0, http_state=0, data_remaining=1994 D [02/Dec/2020:08:57:44 +0100] [Client 13426] Flushing write buffer. D [02/Dec/2020:08:57:44 +0100] [Client 13426] New state is HTTP_STATE_WAITING D [02/Dec/2020:08:57:44 +0100] [Client 13426] Waiting for request. D [02/Dec/2020:08:57:44 +0100] cupsdSetBusyState: newbusy=""Active clients, printing jobs, and dirty files"", busy=""Active clients, printing jobs, and dirty files"" D [02/Dec/2020:08:57:44 +0100] [Job 4993] Validate-Job: successful-ok (successful-ok) D [02/Dec/2020:08:57:44 +0100] [Job 4993] ---- operation-attributes-tag ---- D [02/Dec/2020:08:57:44 +0100] [Job 4993] attributes-charset charset utf-8 D [02/Dec/2020:08:57:44 +0100] [Job 4993] attributes-natural-language naturalLanguage en-us D [02/Dec/2020:08:57:44 +0100] [Job 4993] ---- end-of-attributes-tag ---- D [02/Dec/2020:08:57:44 +0100] [Job 4993] Create-Job IPP/2.0 D [02/Dec/2020:08:57:44 +0100] [Job 4993] printer-uri="ipp://localhost:631/printers/IT08872" D [02/Dec/2020:08:57:44 +0100] [Job 4993] requesting-user-name="remroot" D [02/Dec/2020:08:57:44 +0100] [Job 4993] job-name="Untitled" D [02/Dec/2020:08:57:44 +0100] [Job 4993] IPP/2.0 Create-Job #4 D [02/Dec/2020:08:57:44 +0100] [Job 4993] ---- operation-attributes-tag ---- D [02/Dec/2020:08:57:44 +0100] [Job 4993] attributes-charset charset utf-8 D [02/Dec/2020:08:57:44 +0100] [Job 4993] attributes-natural-language naturalLanguage en-us D [02/Dec/2020:08:57:44 +0100] [Job 4993] printer-uri uri ipp://localhost:631/printers/IT08872 D [02/Dec/2020:08:57:44 +0100] [Job 4993] requesting-user-name nameWithoutLanguage remroot D [02/Dec/2020:08:57:44 +0100] [Job 4993] job-name nameWithoutLanguage Untitled D [02/Dec/2020:08:57:44 +0100] [Job 4993] ---- end-of-attributes-tag ---- D [02/Dec/2020:08:57:44 +0100] [Client 13425] con->http=0x564da04ac080 D [02/Dec/2020:08:57:44 +0100] [Client 13425] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=206, response=0x564da04a8b30(IPP_STATE_IDLE), pipe_pid=0, file=-1 D [02/Dec/2020:08:57:44 +0100] [Client 13425] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0 D [02/Dec/2020:08:57:44 +0100] [Client 13425] bytes=0, http_state=0, data_remaining=206 "localhost - - [02/Dec/2020:08:57:44 +0100] ""POST /printers/IT08872 HTTP/1.1"" 200 180 Create-Job successful-ok D [02/Dec/2020:08:57:44 +0100] [Client 13425] Flushing write buffer. D [02/Dec/2020:08:57:44 +0100] [Client 13425] New state is HTTP_STATE_WAITING D [02/Dec/2020:08:57:44 +0100] [Client 13425] Waiting for request. D [02/Dec/2020:08:57:44 +0100] cupsdSetBusyState: newbusy=""Printing jobs and dirty files"", busy=""Active clients, printing jobs, and dirty files"" D [02/Dec/2020:08:57:44 +0100] [Job 4993] Create-Job: successful-ok (successful-ok) D [02/Dec/2020:08:57:44 +0100] [Job 4993] ---- operation-attributes-tag ---- D [02/Dec/2020:08:57:44 +0100] [Job 4993] attributes-charset charset utf-8 D [02/Dec/2020:08:57:44 +0100] [Job 4993] attributes-natural-language naturalLanguage en-us D [02/Dec/2020:08:57:44 +0100] [Job 4993] ---- job-attributes-tag ---- D [02/Dec/2020:08:57:44 +0100] [Job 4993] job-uri uri ipp://localhost:631/jobs/4995 D [02/Dec/2020:08:57:44 +0100] [Job 4993] job-id integer 4995 D [02/Dec/2020:08:57:44 +0100] [Job 4993] job-state enum pending-held D [02/Dec/2020:08:57:44 +0100] [Job 4993] job-state-message textWithoutLanguage D [02/Dec/2020:08:57:44 +0100] [Job 4993] job-state-reasons keyword job-incoming D [02/Dec/2020:08:57:44 +0100] [Job 4993] ---- end-of-attributes-tag ---- D [02/Dec/2020:08:57:44 +0100] [Job 4993] Print job accepted - job ID 4995. D [02/Dec/2020:08:57:44 +0100] [Job 4993] Sending file 1 using chunking... D [02/Dec/2020:08:57:44 +0100] [Job 4993] IPP/2.0 Send-Document #5 D [02/Dec/2020:08:57:44 +0100] [Job 4993] ---- operation-attributes-tag ---- D [02/Dec/2020:08:57:44 +0100] [Job 4993] attributes-charset charset utf-8 D [02/Dec/2020:08:57:44 +0100] [Job 4993] attributes-natural-language naturalLanguage en-us D [02/Dec/2020:08:57:44 +0100] [Job 4993] printer-uri uri ipp://localhost:631/printers/IT08872 D [02/Dec/2020:08:57:44 +0100] [Job 4993] job-id integer 4995 D [02/Dec/2020:08:57:44 +0100] [Job 4993] requesting-user-name nameWithoutLanguage remroot D [02/Dec/2020:08:57:44 +0100] [Job 4993] last-document boolean true D [02/Dec/2020:08:57:44 +0100] [Job 4993] document-format mimeMediaType application/vnd.cups-postscript D [02/Dec/2020:08:57:44 +0100] [Job 4993] compression keyword gzip D [02/Dec/2020:08:57:44 +0100] [Job 4993] ---- end-of-attributes-tag ---- D [02/Dec/2020:08:57:44 +0100] [Job 4993] update_reasons(attr=1(none), s="(null)") D [02/Dec/2020:08:57:44 +0100] [Job 4993] Get-Printer-Attributes: successful-ok (successful-ok) D [02/Dec/2020:08:57:44 +0100] [Job 4993] ---- operation-attributes-tag ---- D [02/Dec/2020:08:57:44 +0100] [Job 4993] attributes-charset charset utf-8 D [02/Dec/2020:08:57:44 +0100] [Job 4993] attributes-natural-language naturalLanguage en-us D [02/Dec/2020:08:57:44 +0100] [Job 4993] ---- printer-attributes-tag ---- D [02/Dec/2020:08:57:44 +0100] [Job 4993] printer-is-accepting-jobs boolean true D [02/Dec/2020:08:57:44 +0100] [Job 4993] printer-state enum idle D [02/Dec/2020:08:57:44 +0100] [Job 4993] printer-state-message textWithoutLanguage D [02/Dec/2020:08:57:44 +0100] [Job 4993] printer-state-reasons keyword none D [02/Dec/2020:08:57:44 +0100] [Job 4993] marker-colors nameWithoutLanguage #000000 D [02/Dec/2020:08:57:44 +0100] [Job 4993] marker-levels integer 60 D [02/Dec/2020:08:57:44 +0100] [Job 4993] marker-names nameWithoutLanguage Canon CRG052 Black Toner D [02/Dec/2020:08:57:44 +0100] [Job 4993] marker-types keyword toner-cartridge D [02/Dec/2020:08:57:44 +0100] [Job 4993] document-format-supported 1setOf mimeMediaType application/octet-stream,application/pdf,application/postscript,application/vnd.adobe-reader-postscript,application/vnd.cups-command,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 D [02/Dec/2020:08:57:44 +0100] [Job 4993] print-color-mode-supported 1setOf keyword monochrome,color D [02/Dec/2020:08:57:44 +0100] [Job 4993] compression-supported 1setOf keyword none,gzip D [02/Dec/2020:08:57:44 +0100] [Job 4993] copies-supported rangeOfInteger 1-9999 D [02/Dec/2020:08:57:44 +0100] [Job 4993] cups-version textWithoutLanguage 2.2.10 D [02/Dec/2020:08:57:44 +0100] [Job 4993] media-col-supported 1setOf keyword media-bottom-margin,media-left-margin,media-right-margin,media-size,media-source,media-top-margin,media-type D [02/Dec/2020:08:57:44 +0100] [Client 13425] POST /printers/IT08872 HTTP/1.1 D [02/Dec/2020:08:57:44 +0100] cupsdSetBusyState: newbusy=""Active clients, printing jobs, and dirty files"", busy=""Printing jobs and dirty files"" D [02/Dec/2020:08:57:44 +0100] [Client 13425] Read: status=200, state=6 D [02/Dec/2020:08:57:44 +0100] [Client 13425] No authentication data provided. D [02/Dec/2020:08:57:44 +0100] [Client 13425] 2.0 Send-Document 5 D [02/Dec/2020:08:57:44 +0100] [Client 13426] POST /printers/IT08872 HTTP/1.1 D [02/Dec/2020:08:57:44 +0100] cupsdSetBusyState: newbusy=""Active clients, printing jobs, and dirty files"", busy=""Active clients, printing jobs, and dirty files"" D [02/Dec/2020:08:57:44 +0100] [Client 13426] Read: status=200, state=6 D [02/Dec/2020:08:57:44 +0100] [Client 13426] No authentication data provided. D [02/Dec/2020:08:57:44 +0100] [Client 13426] 2.0 Get-Job-Attributes 6 D [02/Dec/2020:08:57:44 +0100] Get-Job-Attributes ipp://localhost:631/printers/IT08872

2nd debug log (on another server) :

D [02/Dec/2020:13:25:05 +0200] [Job 13042] [10] = \application/x-csource\ D [02/Dec/2020:13:25:05 +0200] [Job 13042] [11] = \application/x-perl\ D [02/Dec/2020:13:25:05 +0200] [Job 13042] [12] = \application/x-shell\ D [02/Dec/2020:13:25:05 +0200] [Job 13042] [13] = \image/gif\ D [02/Dec/2020:13:25:05 +0200] [Job 13042] [14] = \image/jpeg\ D [02/Dec/2020:13:25:05 +0200] [Job 13042] [15] = \image/png\ D [02/Dec/2020:13:25:05 +0200] [Job 13042] [16] = \image/pwg-raster\ D [02/Dec/2020:13:25:05 +0200] [Job 13042] [17] = \image/tiff\ D [02/Dec/2020:13:25:05 +0200] [Job 13042] [18] = \image/urf\ D [02/Dec/2020:13:25:05 +0200] [Job 13042] [19] = \image/x-bitmap\ D [02/Dec/2020:13:25:05 +0200] [Job 13042] [20] = \image/x-photocd\ D [02/Dec/2020:13:25:05 +0200] [Job 13042] [21] = \image/x-portable-anymap\ D [02/Dec/2020:13:25:05 +0200] [Job 13042] [22] = \image/x-portable-bitmap\ D [02/Dec/2020:13:25:05 +0200] [Job 13042] [23] = \image/x-portable-graymap\ D [02/Dec/2020:13:25:05 +0200] [Job 13042] [24] = \image/x-portable-pixmap\ D [02/Dec/2020:13:25:05 +0200] [Job 13042] [25] = \image/x-sgi-rgb\ D [02/Dec/2020:13:25:05 +0200] [Job 13042] [26] = \image/x-sun-raster\ D [02/Dec/2020:13:25:05 +0200] [Job 13042] [27] = \image/x-xbitmap\ D [02/Dec/2020:13:25:05 +0200] [Job 13042] [28] = \image/x-xpixmap\ D [02/Dec/2020:13:25:05 +0200] [Job 13042] [29] = \image/x-xwindowdump\ D [02/Dec/2020:13:25:05 +0200] [Job 13042] [30] = \text/css\ D [02/Dec/2020:13:25:05 +0200] [Job 13042] [31] = \text/html\ D [02/Dec/2020:13:25:05 +0200] [Job 13042] [32] = \text/plain\ D [02/Dec/2020:13:25:05 +0200] [Job 13042] media-col-supported (7 values) D [02/Dec/2020:13:25:05 +0200] [Job 13042] [0] = \media-bottom-margin\ D [02/Dec/2020:13:25:05 +0200] [Job 13042] [1] = \media-left-margin\ D [02/Dec/2020:13:25:05 +0200] [Job 13042] [2] = \media-right-margin\ D [02/Dec/2020:13:25:05 +0200] [Job 13042] [3] = \media-size\ D [02/Dec/2020:13:25:05 +0200] [Job 13042] [4] = \media-source\ D [02/Dec/2020:13:25:05 +0200] [Job 13042] [5] = \media-top-margin\ D [02/Dec/2020:13:25:05 +0200] [Job 13042] [6] = \media-type\ D [02/Dec/2020:13:25:05 +0200] [Job 13042] operations-supported (47 values) D [02/Dec/2020:13:25:05 +0200] [Job 13042] [0] = Print-Job D [02/Dec/2020:13:25:05 +0200] [Job 13042] [1] = Validate-Job D [02/Dec/2020:13:25:05 +0200] [Job 13042] [2] = Create-Job D [02/Dec/2020:13:25:05 +0200] [Job 13042] [3] = Send-Document D [02/Dec/2020:13:25:05 +0200] [Job 13042] [4] = Cancel-Job D [02/Dec/2020:13:25:05 +0200] [Job 13042] [5] = Get-Job-Attributes D [02/Dec/2020:13:25:05 +0200] [Job 13042] [6] = Get-Jobs D [02/Dec/2020:13:25:05 +0200] [Job 13042] [7] = Get-Printer-Attributes D [02/Dec/2020:13:25:05 +0200] [Job 13042] [8] = Hold-Job D [02/Dec/2020:13:25:05 +0200] [Job 13042] [9] = Release-Job D [02/Dec/2020:13:25:05 +0200] [Job 13042] [10] = Pause-Printer D [02/Dec/2020:13:25:05 +0200] [Job 13042] [11] = Resume-Printer D [02/Dec/2020:13:25:05 +0200] [Job 13042] [12] = Purge-Jobs D [02/Dec/2020:13:25:05 +0200] [Job 13042] [13] = Set-Printer-Attributes D [02/Dec/2020:13:25:05 +0200] [Job 13042] [14] = Set-Job-Attributes D [02/Dec/2020:13:25:05 +0200] [Job 13042] [15] = Get-Printer-Supported-Values D [02/Dec/2020:13:25:05 +0200] [Job 13042] [16] = Create-Printer-Subscriptions D [02/Dec/2020:13:25:05 +0200] [Job 13042] [17] = Create-Job-Subscriptions D [02/Dec/2020:13:25:05 +0200] [Job 13042] [18] = Get-Subscription-Attributes D [02/Dec/2020:13:25:05 +0200] [Job 13042] [19] = Get-Subscriptions D [02/Dec/2020:13:25:05 +0200] [Job 13042] [20] = Renew-Subscription D [02/Dec/2020:13:25:05 +0200] [Job 13042] [21] = Cancel-Subscription D [02/Dec/2020:13:25:05 +0200] [Job 13042] [22] = Get-Notifications D [02/Dec/2020:13:25:05 +0200] [Job 13042] [23] = Enable-Printer D [02/Dec/2020:13:25:05 +0200] [Job 13042] [24] = Disable-Printer D [02/Dec/2020:13:25:05 +0200] [Job 13042] [25] = Hold-New-Jobs D [02/Dec/2020:13:25:05 +0200] [Job 13042] [26] = Release-Held-New-Jobs D [02/Dec/2020:13:25:05 +0200] [Job 13042] [27] = Cancel-Jobs D [02/Dec/2020:13:25:05 +0200] [Job 13042] [28] = Cancel-My-Jobs D [02/Dec/2020:13:25:05 +0200] [Job 13042] [29] = Close-Job D [02/Dec/2020:13:25:05 +0200] [Job 13042] [30] = CUPS-Get-Default D [02/Dec/2020:13:25:05 +0200] [Job 13042] [31] = CUPS-Get-Printers D [02/Dec/2020:13:25:05 +0200] [Job 13042] [32] = CUPS-Add-Modify-Printer D [02/Dec/2020:13:25:05 +0200] [Job 13042] [33] = CUPS-Delete-Printer D [02/Dec/2020:13:25:05 +0200] [Job 13042] [34] = CUPS-Get-Classes D [02/Dec/2020:13:25:05 +0200] [Job 13042] [35] = CUPS-Add-Modify-Class D [02/Dec/2020:13:25:05 +0200] [Job 13042] [36] = CUPS-Delete-Class D [02/Dec/2020:13:25:05 +0200] [Job 13042] [37] = CUPS-Accept-Jobs D [02/Dec/2020:13:25:05 +0200] [Job 13042] [38] = CUPS-Reject-Jobs D [02/Dec/2020:13:25:05 +0200] [Job 13042] [39] = CUPS-Set-Default D [02/Dec/2020:13:25:05 +0200] [Job 13042] [40] = CUPS-Get-Devices D [02/Dec/2020:13:25:05 +0200] [Job 13042] [41] = CUPS-Get-PPDs D [02/Dec/2020:13:25:05 +0200] [Job 13042] [42] = CUPS-Move-Job D [02/Dec/2020:13:25:05 +0200] [Job 13042] [43] = CUPS-Authenticate-Job D [02/Dec/2020:13:25:05 +0200] [Job 13042] [44] = CUPS-Get-PPD D [02/Dec/2020:13:25:05 +0200] [Job 13042] [45] = CUPS-Get-Document D [02/Dec/2020:13:25:05 +0200] [Job 13042] [46] = Restart-Job D [02/Dec/2020:13:25:05 +0200] [Job 13042] Set job-printer-state-message to Connected to printer., current level=INFO D [02/Dec/2020:13:25:05 +0200] [Job 13042] update_reasons(attr=1(none), s=(null)) D [02/Dec/2020:13:25:05 +0200] Discarding unused job-progress event... D [02/Dec/2020:13:25:05 +0200] Discarding unused printer-state-changed event... D [02/Dec/2020:13:25:05 +0200] [Job 13042] STATE: -none D [02/Dec/2020:13:25:05 +0200] [Job 13042] final_content_type=\application/vnd.cups-postscript\, document_format=\application/vnd.cups-postscript\ D [02/Dec/2020:13:25:05 +0200] [Job 13042] Validate-Job IPP/2.0 D [02/Dec/2020:13:25:05 +0200] [Job 13042] printer-uri=\ipp://localhost:631/printers/IT08845\ D [02/Dec/2020:13:25:05 +0200] [Job 13042] requesting-user-name=\remroot\ D [02/Dec/2020:13:25:05 +0200] [Job 13042] job-name=\Untitled\ D [02/Dec/2020:13:25:05 +0200] [Job 13042] document-format=\application/vnd.cups-postscript\ D [02/Dec/2020:13:25:05 +0200] [Job 13042] IPP/2.0 Validate-Job #2 D [02/Dec/2020:13:25:05 +0200] [Job 13042] ---- operation-attributes-tag ---- D [02/Dec/2020:13:25:05 +0200] [Job 13042] attributes-charset charset utf-8 D [02/Dec/2020:13:25:05 +0200] [Job 13042] attributes-natural-language naturalLanguage en-us D [02/Dec/2020:13:25:05 +0200] [Job 13042] printer-uri uri ipp://localhost:631/printers/IT08845 D [02/Dec/2020:13:25:05 +0200] [Job 13042] requesting-user-name nameWithoutLanguage remroot D [02/Dec/2020:13:25:05 +0200] [Job 13042] job-name nameWithoutLanguage Untitled D [02/Dec/2020:13:25:05 +0200] [Job 13042] document-format mimeMediaType application/vnd.cups-postscript D [02/Dec/2020:13:25:05 +0200] [Job 13042] ---- end-of-attributes-tag ---- D [02/Dec/2020:13:25:05 +0200] [Client 339] POST /printers/IT08845 HTTP/1.1 D [02/Dec/2020:13:25:05 +0200] cupsdSetBusyState: newbusy=Active clients, printing jobs, and dirty files, busy=Printing jobs and dirty files D [02/Dec/2020:13:25:05 +0200] [Client 339] Read: status=200, state=6 D [02/Dec/2020:13:25:05 +0200] [Client 339] No authentication data provided. D [02/Dec/2020:13:25:05 +0200] [Client 339] Read: status=100, state=6 D [02/Dec/2020:13:25:05 +0200] [Client 339] Read: status=100, state=6 D [02/Dec/2020:13:25:05 +0200] [Client 339] Read: status=100, state=6 D [02/Dec/2020:13:25:05 +0200] cupsdSetBusyState: newbusy=Active clients, printing jobs, and dirty files, busy=Active clients, printing jobs, and dirty files D [02/Dec/2020:13:25:05 +0200] [Client 340] Server address is 127.0.0.1. D [02/Dec/2020:13:25:05 +0200] [Client 340] Accepted from localhost:43874 (IPv4) D [02/Dec/2020:13:25:05 +0200] [Client 340] Waiting for request. D [02/Dec/2020:13:25:05 +0200] [Client 339] Read: status=100, state=6 D [02/Dec/2020:13:25:05 +0200] [Client 339] Read: status=100, state=6 D [02/Dec/2020:13:25:05 +0200] [Client 339] Read: status=100, state=6 D [02/Dec/2020:13:25:05 +0200] [Client 339] Read: status=100, state=6 D [02/Dec/2020:13:25:05 +0200] [Client 339] 2.0 Validate-Job 2 D [02/Dec/2020:13:25:05 +0200] Validate-Job ipp://localhost:631/printers/IT08845 D [02/Dec/2020:13:25:05 +0200] [Client 339] Returning IPP successful-ok for Validate-Job (ipp://localhost:631/printers/IT08845) from localhost. D [02/Dec/2020:13:25:05 +0200] [Client 339] Content-Length: 75 D [02/Dec/2020:13:25:05 +0200] [Client 339] cupsdSendHeader: code=200, type=application/ipp, auth_type=0 D [02/Dec/2020:13:25:05 +0200] [Job 13042] IPP/2.0 Get-Printer-Attributes #3 D [02/Dec/2020:13:25:05 +0200] [Job 13042] ---- operation-attributes-tag ---- D [02/Dec/2020:13:25:05 +0200] [Job 13042] attributes-charset charset utf-8 D [02/Dec/2020:13:25:05 +0200] [Job 13042] attributes-natural-language naturalLanguage en-us D [02/Dec/2020:13:25:05 +0200] [Job 13042] printer-uri uri ipp://localhost:631/printers/IT08845 D [02/Dec/2020:13:25:05 +0200] [Job 13042] requesting-user-name nameWithoutLanguage remroot D [02/Dec/2020:13:25:05 +0200] [Job 13042] requested-attributes 1setOf keyword compression-supported,copies-supported,cups-version,document-format-supported,job-password-encryption-supported,marker-colors,marker-high-levels,marker-levels,marker-low-levels,marker-message,marker-names,marker-types,media-col-supported,multiple-document-handling-supported,operations-supported,print-color-mode-supported,printer-alert,printer-alert-description,printer-is-accepting-jobs,printer-mandatory-job-attributes,printer-state,printer-state-message,printer-state-reasons D [02/Dec/2020:13:25:05 +0200] [Job 13042] ---- end-of-attributes-tag ---- D [02/Dec/2020:13:25:05 +0200] [Client 339] con->http=0x55f313039320 D [02/Dec/2020:13:25:05 +0200] [Client 339] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=75, response=0x55f3123789a0(IPP_STATE_DATA), pipe_pid=0, file=-1 D [02/Dec/2020:13:25:05 +0200] [Client 339] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0 D [02/Dec/2020:13:25:05 +0200] [Client 339] bytes=0, http_state=0, data_remaining=75 localhost - - [02/Dec/2020:13:25:05 +0200] POST /printers/IT08845 HTTP/1.1 200 231 Validate-Job successful-ok D [02/Dec/2020:13:25:05 +0200] [Client 339] Flushing write buffer. D [02/Dec/2020:13:25:05 +0200] [Client 339] New state is HTTP_STATE_WAITING D [02/Dec/2020:13:25:05 +0200] [Client 339] Waiting for request. D [02/Dec/2020:13:25:05 +0200] cupsdSetBusyState: newbusy=Printing jobs and dirty files, busy=Active clients, printing jobs, and dirty files D [02/Dec/2020:13:25:05 +0200] [Client 340] POST /printers/IT08845 HTTP/1.1 D [02/Dec/2020:13:25:05 +0200] cupsdSetBusyState: newbusy=Active clients, printing jobs, and dirty files, busy=Printing jobs and dirty files D [02/Dec/2020:13:25:05 +0200] [Client 340] Read: status=200, state=6 D [02/Dec/2020:13:25:05 +0200] [Client 340] No authentication data provided. D [02/Dec/2020:13:25:05 +0200] [Client 340] 2.0 Get-Printer-Attributes 3 D [02/Dec/2020:13:25:05 +0200] Get-Printer-Attributes ipp://localhost:631/printers/IT08845 D [02/Dec/2020:13:25:05 +0200] [Client 340] Returning IPP successful-ok for Get-Printer-Attributes (ipp://localhost:631/printers/IT08845) from localhost. D [02/Dec/2020:13:25:05 +0200] [Client 340] Content-Length: 1831 D [02/Dec/2020:13:25:05 +0200] [Client 340] cupsdSendHeader: code=200, type=application/ipp, auth_type=0 D [02/Dec/2020:13:25:05 +0200] [Client 339] POST /printers/IT08845 HTTP/1.1 D [02/Dec/2020:13:25:05 +0200] cupsdSetBusyState: newbusy=Active clients, printing jobs, and dirty files, busy=Active clients, printing jobs, and dirty files D [02/Dec/2020:13:25:05 +0200] [Client 339] Read: status=200, state=6 D [02/Dec/2020:13:25:05 +0200] [Client 339] No authentication data provided. D [02/Dec/2020:13:25:05 +0200] [Client 339] 2.0 Create-Job 4 D [02/Dec/2020:13:25:05 +0200] Create-Job ipp://localhost:631/printers/IT08845 D [02/Dec/2020:13:25:05 +0200] [Job 12649] Removing from history. D [02/Dec/2020:13:25:05 +0200] cupsdMarkDirty(---J-) D [02/Dec/2020:13:25:05 +0200] cupsdSetBusyState: newbusy=Active clients, printing jobs, and dirty files, busy=Active clients, printing jobs, and dirty files D [02/Dec/2020:13:25:05 +0200] [Job 13046] Applying default options... D [02/Dec/2020:13:25:05 +0200] add_job: requesting-user-name=remroot D [02/Dec/2020:13:25:05 +0200] Adding default job-sheets values none,none... I [02/Dec/2020:13:25:05 +0200] [Job 13046] Adding start banner page none. D [02/Dec/2020:13:25:05 +0200] Discarding unused job-created event... I [02/Dec/2020:13:25:05 +0200] [Job 13046] Queued on IT08845 by remroot. D [02/Dec/2020:13:25:05 +0200] [Client 339] Returning IPP successful-ok for Create-Job (ipp://localhost:631/printers/IT08845) from localhost. D [02/Dec/2020:13:25:05 +0200] [Client 339] Content-Length: 207 D [02/Dec/2020:13:25:05 +0200] [Client 339] cupsdSendHeader: code=200, type=application/ipp, auth_type=0 D [02/Dec/2020:13:25:05 +0200] [Client 340] con->http=0x55f313132100 D [02/Dec/2020:13:25:05 +0200] [Client 340] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=1831, response=0x55f313038f00(IPP_STATE_DATA), pipe_pid=0, file=-1 D [02/Dec/2020:13:25:05 +0200] [Client 340] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0 D [02/Dec/2020:13:25:05 +0200] [Client 340] bytes=0, http_state=0, data_remaining=1831 D [02/Dec/2020:13:25:05 +0200] [Client 340] Flushing write buffer. D [02/Dec/2020:13:25:05 +0200] [Client 340] New state is HTTP_STATE_WAITING D [02/Dec/2020:13:25:05 +0200] [Client 340] Waiting for request. D [02/Dec/2020:13:25:05 +0200] cupsdSetBusyState: newbusy=Active clients, printing jobs, and dirty files, busy=Active clients, printing jobs, and dirty files D [02/Dec/2020:13:25:05 +0200] [Job 13042] Validate-Job: successful-ok (successful-ok) D [02/Dec/2020:13:25:05 +0200] [Job 13042] ---- operation-attributes-tag ---- D [02/Dec/2020:13:25:05 +0200] [Job 13042] attributes-charset charset utf-8 D [02/Dec/2020:13:25:05 +0200] [Job 13042] attributes-natural-language naturalLanguage en-us D [02/Dec/2020:13:25:05 +0200] [Job 13042] ---- end-of-attributes-tag ---- D [02/Dec/2020:13:25:05 +0200] [Job 13042] Create-Job IPP/2.0 D [02/Dec/2020:13:25:05 +0200] [Job 13042] printer-uri=\ipp://localhost:631/printers/IT08845\ D [02/Dec/2020:13:25:05 +0200] [Job 13042] requesting-user-name=\remroot\ D [02/Dec/2020:13:25:05 +0200] [Job 13042] job-name=\Untitled\ D [02/Dec/2020:13:25:05 +0200] [Job 13042] IPP/2.0 Create-Job #4 D [02/Dec/2020:13:25:05 +0200] [Job 13042] ---- operation-attributes-tag ---- D [02/Dec/2020:13:25:05 +0200] [Job 13042] attributes-charset charset utf-8 D [02/Dec/2020:13:25:05 +0200] [Job 13042] attributes-natural-language naturalLanguage en-us D [02/Dec/2020:13:25:05 +0200] [Job 13042] printer-uri uri ipp://localhost:631/printers/IT08845 D [02/Dec/2020:13:25:05 +0200] [Job 13042] requesting-user-name nameWithoutLanguage remroot D [02/Dec/2020:13:25:05 +0200] [Job 13042] job-name nameWithoutLanguage Untitled D [02/Dec/2020:13:25:05 +0200] [Job 13042] ---- end-of-attributes-tag ---- D [02/Dec/2020:13:25:05 +0200] [Client 339] con->http=0x55f313039320 D [02/Dec/2020:13:25:05 +0200] [Client 339] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=207, response=0x55f3123787c0(IPP_STATE_IDLE), pipe_pid=0, file=-1 D [02/Dec/2020:13:25:05 +0200] [Client 339] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0 D [02/Dec/2020:13:25:05 +0200] [Client 339] bytes=0, http_state=0, data_remaining=207 localhost - - [02/Dec/2020:13:25:05 +0200] POST /printers/IT08845 HTTP/1.1 200 180 Create-Job successful-ok D [02/Dec/2020:13:25:05 +0200] [Client 339] Flushing write buffer. D [02/Dec/2020:13:25:05 +0200] [Client 339] New state is HTTP_STATE_WAITING D [02/Dec/2020:13:25:05 +0200] [Client 339] Waiting for request. D [02/Dec/2020:13:25:05 +0200] cupsdSetBusyState: newbusy=Printing jobs and dirty files, busy=Active clients, printing jobs, and dirty files D [02/Dec/2020:13:25:05 +0200] [Job 13042] Create-Job: successful-ok (successful-ok) D [02/Dec/2020:13:25:05 +0200] [Job 13042] ---- operation-attributes-tag ---- D [02/Dec/2020:13:25:05 +0200] [Job 13042] attributes-charset charset utf-8 D [02/Dec/2020:13:25:05 +0200] [Job 13042] attributes-natural-language naturalLanguage en-us D [02/Dec/2020:13:25:05 +0200] [Job 13042] ---- job-attributes-tag ---- D [02/Dec/2020:13:25:05 +0200] [Job 13042] job-uri uri ipp://localhost:631/jobs/13046 D [02/Dec/2020:13:25:05 +0200] [Job 13042] job-id integer 13046 D [02/Dec/2020:13:25:05 +0200] [Job 13042] job-state enum pending-held D [02/Dec/2020:13:25:05 +0200] [Job 13042] job-state-message textWithoutLanguage D [02/Dec/2020:13:25:05 +0200] [Job 13042] job-state-reasons keyword job-incoming D [02/Dec/2020:13:25:05 +0200] [Job 13042] ---- end-of-attributes-tag ---- D [02/Dec/2020:13:25:05 +0200] [Job 13042] Print job accepted - job ID 13046. D [02/Dec/2020:13:25:05 +0200] [Job 13042] Sending file 1 using chunking... D [02/Dec/2020:13:25:05 +0200] [Job 13042] IPP/2.0 Send-Document #5 D [02/Dec/2020:13:25:05 +0200] [Job 13042] ---- operation-attributes-tag ---- D [02/Dec/2020:13:25:05 +0200] [Job 13042] attributes-charset charset utf-8 D [02/Dec/2020:13:25:05 +0200] [Job 13042] attributes-natural-language naturalLanguage en-us D [02/Dec/2020:13:25:05 +0200] [Job 13042] printer-uri uri ipp://localhost:631/printers/IT08845 D [02/Dec/2020:13:25:05 +0200] [Job 13042] job-id integer 13046 D [02/Dec/2020:13:25:05 +0200] [Job 13042] requesting-user-name nameWithoutLanguage remroot D [02/Dec/2020:13:25:05 +0200] [Job 13042] last-document boolean true D [02/Dec/2020:13:25:05 +0200] [Job 13042] document-format mimeMediaType application/vnd.cups-postscript D [02/Dec/2020:13:25:05 +0200] [Job 13042] compression keyword gzip D [02/Dec/2020:13:25:05 +0200] [Job 13042] ---- end-of-attributes-tag ---- D [02/Dec/2020:13:25:05 +0200] [Client 339] POST /printers/IT08845 HTTP/1.1 D [02/Dec/2020:13:25:05 +0200] cupsdSetBusyState: newbusy=Active clients, printing jobs, and dirty files, busy=Printing jobs and dirty files D [02/Dec/2020:13:25:05 +0200] [Client 339] Read: status=200, state=6 D [02/Dec/2020:13:25:05 +0200] [Client 339] No authentication data provided. D [02/Dec/2020:13:25:05 +0200] [Client 339] Read: status=100, state=6 D [02/Dec/2020:13:25:05 +0200] [Client 339] Read: status=100, state=6 D [02/Dec/2020:13:25:05 +0200] [Client 339] Read: status=100, state=6 D [02/Dec/2020:13:25:05 +0200] [Client 339] Read: status=100, state=6 D [02/Dec/2020:13:25:05 +0200] [Client 339] Read: status=100, state=6 D [02/Dec/2020:13:25:05 +0200] [Client 339] Read: status=100, state=6 D [02/Dec/2020:13:25:05 +0200] [Client 339] Read: status=100, state=6 D [02/Dec/2020:13:25:05 +0200] [Client 339] Read: status=100, state=6 D [02/Dec/2020:13:25:05 +0200] [Client 339] Read: status=100, state=6 D [02/Dec/2020:13:25:05 +0200] [Client 339] 2.0 Send-Document 5 D [02/Dec/2020:13:25:05 +0200] [Job 13042] update_reasons(attr=1(none), s=(null)) D [02/Dec/2020:13:25:05 +0200] [Job 13042] Get-Printer-Attributes: successful-ok (successful-ok) D [02/Dec/2020:13:25:05 +0200] [Job 13042] ---- operation-attributes-tag ---- D [02/Dec/2020:13:25:05 +0200] [Job 13042] attributes-charset charset utf-8 D [02/Dec/2020:13:25:05 +0200] [Job 13042] attributes-natural-language naturalLanguage en-us D [02/Dec/2020:13:25:05 +0200] [Job 13042] ---- printer-attributes-tag ---- D [02/Dec/2020:13:25:05 +0200] [Job 13042] printer-is-accepting-jobs boolean true D [02/Dec/2020:13:25:05 +0200] [Job 13042] printer-state enum idle D [02/Dec/2020:13:25:05 +0200] [Job 13042] printer-state-message textWithoutLanguage D [02/Dec/2020:13:25:05 +0200] [Job 13042] printer-state-reasons keyword none D [02/Dec/2020:13:25:05 +0200] [Job 13042] document-format-supported 1setOf 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 D [02/Dec/2020:13:25:05 +0200] [Job 13042] print-color-mode-supported keyword monochrome D [02/Dec/2020:13:25:05 +0200] [Job 13042] compression-supported 1setOf keyword none,gzip D [02/Dec/2020:13:25:05 +0200] [Job 13042] copies-supported rangeOfInteger 1-9999 D [02/Dec/2020:13:25:05 +0200] [Job 13042] cups-version textWithoutLanguage 2.2.10 D [02/Dec/2020:13:25:05 +0200] [Job 13042] media-col-supported 1setOf keyword media-bottom-margin,media-left-margin,media-right-margin,media-size,media-source,media-top-margin,media-type D [02/Dec/2020:13:25:05 +0200] [Job 13042] multiple-document-handling-supported 1setOf keyword separate-documents-uncollated-copies,separate-documents-collated-copies D [02/Dec/2020:13:25:05 +0200] [Job 13042] operations-supported 1setOf 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 D [02/Dec/2020:13:25:05 +0200] [Job 13042] ---- end-of-attributes-tag ---- D [02/Dec/2020:13:25:05 +0200] [Client 340] POST /printers/IT08845 HTTP/1.1 D [02/Dec/2020:13:25:05 +0200] cupsdSetBusyState: newbusy=Active clients, printing jobs, and dirty files, busy=Active clients, printing jobs, and dirty files D [02/Dec/2020:13:25:05 +0200] [Client 340] Read: status=200, state=6 D [02/Dec/2020:13:25:05 +0200] [Client 340] No authentication data provided. D [02/Dec/2020:13:25:05 +0200] [Client 340] Read: status=100, state=6 D [02/Dec/2020:13:25:05 +0200] [Client 340] Read: status=100, state=6 D [02/Dec/2020:13:25:05 +0200] [Client 340] Read: status=100, state=6 D [02/Dec/2020:13:25:05 +0200] [Client 340] Read: status=100, state=6 D [02/Dec/2020:13:25:05 +0200] [Client 340] Read: status=100, state=6 D [02/Dec/2020:13:25:05 +0200] [Client 340] Read: status=100, state=6 D [02/Dec/2020:13:25:05 +0200] [Client 340] Read: status=100, state=6 D [02/Dec/2020:13:25:05 +0200] [Client 340] Read: status=100, state=6 D [02/Dec/2020:13:25:05 +0200] [Client 340] Read: status=100, state=6 D [02/Dec/2020:13:25:05 +0200] [Client 340] Read: status=100, state=6 D [02/Dec/2020:13:25:05 +0200] [Client 340] Read: status=100, state=6 D [02/Dec/2020:13:25:05 +0200] [Job 13039] ATTR: marker-colors=#000000,#000000 D [02/Dec/2020:13:25:05 +0200] cupsdMarkDirty(P----) D [02/Dec/2020:13:25:05 +0200] cupsdSetBusyState: newbusy=Active clients, printing jobs, and dirty files, busy=Active clients, printing jobs, and dirty files D [02/Dec/2020:13:25:05 +0200] [Job 13039] ATTR: marker-names=\'\Xerox Black Toner Cartridge, Replace with P/N 106R03773,106R03621,106R03623; S/N CRUM-18021115556\',\'\SMart Kit Drum Cartridge, Replace with P/N 650N05435; S/N CRUM-19111906070\' D [02/Dec/2020:13:25:05 +0200] cupsdMarkDirty(P----) D [02/Dec/2020:13:25:05 +0200] cupsdSetBusyState: newbusy=Active clients, printing jobs, and dirty files, busy=Active clients, printing jobs, and dirty files D [02/Dec/2020:13:25:05 +0200] [Job 13039] ATTR: marker-types=toner,developer D [02/Dec/2020:13:25:05 +0200] cupsdMarkDirty(P----) D [02/Dec/2020:13:25:05 +0200] cupsdSetBusyState: newbusy=Active clients, printing jobs, and dirty files, busy=Active clients, printing jobs, and dirty files D [02/Dec/2020:13:25:05 +0200] [Job 13039] ATTR: marker-levels=98,89 D [02/Dec/2020:13:25:05 +0200] cupsdMarkDirty(P----) D [02/Dec/2020:13:25:05 +0200] cupsdSetBusyState: newbusy=Active clients, printing jobs, and dirty files, busy=Active clients, printing jobs, and dirty files D [02/Dec/2020:13:25:05 +0200] [Job 13039] new_supply_state=0, change_state=ffff D [02/Dec/2020:13:25:05 +0200] [Job 13039] STATE: -developer-low-report D [02/Dec/2020:13:25:05 +0200] [Job 13039] STATE: -developer-empty-warning D [02/Dec/2020:13:25:05 +0200] [Job 13039] STATE: -marker-supply-low-report D [02/Dec/2020:13:25:05 +0200] [Job 13039] STATE: -marker-supply-empty-warning D [02/Dec/2020:13:25:05 +0200] [Job 13039] STATE: -opc-near-eol-report D [02/Dec/2020:13:25:05 +0200] [Job 13039] STATE: -opc-life-over-warning D [02/Dec/2020:13:25:05 +0200] [Job 13039] STATE: -toner-low-report D [02/Dec/2020:13:25:05 +0200] [Job 13039] STATE: -toner-empty-warning D [02/Dec/2020:13:25:05 +0200] [Job 13039] STATE: -waste-receptacle-almost-full-report D [02/Dec/2020:13:25:05 +0200] [Job 13039] STATE: -waste-receptacle-full-warning D [02/Dec/2020:13:25:05 +0200] [Job 13039] STATE: -cleaner-life-almost-over-report D [02/Dec/2020:13:25:05 +0200] [Job 13039] STATE: -cleaner-life-over-warning D [02/Dec/2020:13:25:05 +0200] Discarding unused printer-state-changed event... D [02/Dec/2020:13:25:05 +0200] [Client 340] Read: status=100, state=6 D [02/Dec/2020:13:25:05 +0200] [Client 340] Read: status=100, state=6 D [02/Dec/2020:13:25:05 +0200] [Client 340] 2.0 Get-Job-Attributes 6 D [02/Dec/2020:13:25:05 +0200] Get-Job-Attributes ipp://localhost:631/printers/IT08845

If you need more information, Thanks

michaelrsweet commented 3 years ago

Please contact the OpenPrinting CUPS project for assistance. I'm guessing this issue has been fixed already, however.