Canon printer stopped working, seeing error in /var/log/cups/error_log

gps1539 · 2025-05-02 23:18:41

I have a canon LBP622 connected over wifi and it had been working fine for years, but now I can not get it to print.
The printer still works over wifi for my wife's MAC.

When I try to print the system says it printed, I see no error, but nothing is printed.

In /var/log/cups/error_log I see "[Job 132] src = libcanon_pdlwrapper.c, line = 514, err = 0¥nINFO: cfFilterGhostscript: Processing page 2..."

I can ping the printer IP address
I believe I have the right driver via the ufrii-print package
I removed then re-added the printer. I could select the driver for the LBP622 and it appears to add correctly. It looks to be healthy per setting/printers and lpstat -t, but nothing prints and I still get the above errors in /var/log/cups/error_log.

I don't use the printer often and arch has been updated many time since I did, so I'm guessing I have a missing/broken dependency somewhere.

Any help much appreciated.

liticovjesac · 2025-05-03 05:25:22

I had similar problem yesterday. Canon TR8500 , KDE.
In my case I first done system update, restart.
Then I went to cups settings in browser and there to administration - modify printer.
I could see there that printer was connected through the socket. To change that I choose first one on the list (there was several options with name canon tr8500) and as driver IPP everywhere. That worked.

This is what I see in cups settings now:

Description: Canon TR8500 series
Location:
Driver: TR8500 series - IPP Everywhere (color, 2-sided printing)
Connection: dnssd://Canon%20TR8500%20series._ipp._tcp.local/?uuid=00000000-0000-1000-8000-00182332d478
Defaults: job-sheets=none, none media=iso_a4_210x297mm sides=one-sided

seth · 2025-05-03 07:00:03

If the printer doesn't support IPP everywhere/airprint (preferable solution for sure) please see https://wiki.archlinux.org/title/CUPS/T … #Debug_log and post the log after attempting to print some file.

themew · 2025-05-03 16:34:57

gps1539 wrote:

I have a canon LBP622 connected over wifi and it had been working fine for years, but now I can not get it to print.
The printer still works over wifi for my wife's MAC.
When I try to print the system says it printed, I see no error, but nothing is printed.
In /var/log/cups/error_log I see "[Job 132] src = libcanon_pdlwrapper.c, line = 514, err = 0¥nINFO: cfFilterGhostscript: Processing page 2..."
I can ping the printer IP address
I believe I have the right driver via the ufrii-print package
I removed then re-added the printer. I could select the driver for the LBP622 and it appears to add correctly. It looks to be healthy per setting/printers and lpstat -t, but nothing prints and I still get the above errors in /var/log/cups/error_log.
I don't use the printer often and arch has been updated many time since I did, so I'm guessing I have a missing/broken dependency somewhere.
Any help much appreciated.

I've got a Canon MF232W and first time in 5+ years, I'm seeing the same thing since the Ghostscript and other updates I did on May 1st.

I was able to switch to IPP and Generic IPP but same libcanon_pldwrapper.c etc... as you're getting.

I've literally tried everything that worked (and didn't work) in the past and can't get around the issue. BTW, the printer is networked via ethernet.

Just don't know where to start -- even rolled back Ghostscript to the previous version (when everything worked) and still stuck on the error.

EDIT: These 2 files: pdftocpca in /usr/lib/cups/filter/pdftocpca and rastertoufr2 in /usr/lib/cups/filter/rastertoufr2 were the only 2 files in 'filters' replaced during the last update of CNRDRVCUPS. Wondering if this is the issue.

EDIT2: Both files above were updated in /usr/lib/cups/filter and /usr/lib64/cups/filter

Last edited by themew (2025-05-03 17:50:07)

seth · 2025-05-03 18:54:07

seth wrote:

If the printer doesn't support IPP everywhere/airprint (preferable solution for sure) please see https://wiki.archlinux.org/title/CUPS/T … #Debug_log and post the log after attempting to print some file.

On a wild guess, it's libxml2 but do NOT downgrade that!!
Post the cups debug log, we'll see on from there.

gps1539 · 2025-05-03 19:10:34

seth wrote:

If the printer doesn't support IPP everywhere/airprint (preferable solution for sure) please see https://wiki.archlinux.org/title/CUPS/T … #Debug_log and post the log after attempting to print some file.

Thanks, it does support IPP and after I enabled it on the print it is discovered via avahi-discover and gets automatically added when I look at settings (gnome), printers. However it still doesn't print.

Here is the error_log

D [03/May/2025:11:53:39 -0700] Expiring subscriptions...
D [03/May/2025:11:53:39 -0700] Creating KeepAlive/PID file "/var/cache/cups/org.cups.cupsd".
I [03/May/2025:11:53:39 -0700] Saving job.cache...
D [03/May/2025:11:53:39 -0700] [Job 140] Unloading...
D [03/May/2025:11:53:39 -0700] [Job 141] Unloading...
D [03/May/2025:11:53:39 -0700] cupsdStopSelect()
I [03/May/2025:11:53:39 -0700] Listening to [v1.::1]:631 (IPv6)
I [03/May/2025:11:53:39 -0700] Listening to 127.0.0.1:631 (IPv4)
I [03/May/2025:11:53:39 -0700] Remote access is disabled.
D [03/May/2025:11:53:39 -0700] Added auto ServerAlias hp8330
I [03/May/2025:11:53:39 -0700] Loaded configuration file "/etc/cups/cupsd.conf"
D [03/May/2025:11:53:39 -0700] Using keychain "/etc/cups/ssl" for server name "hp8330".
D [03/May/2025:11:53:39 -0700] Repairing access permissions of "/etc/cups/classes.conf"
I [03/May/2025:11:53:39 -0700] Using default TempDir of /var/spool/cups/tmp...
I [03/May/2025:11:53:39 -0700] Configured for up to 100 clients.
I [03/May/2025:11:53:39 -0700] Allowing up to 100 client connections per host.
I [03/May/2025:11:53:39 -0700] Using policy "default" as the default.
I [03/May/2025:11:53:39 -0700] Full reload is required.
I [03/May/2025:11:53:39 -0700] Loaded MIME database from "/usr/share/cups/mime" and "/etc/cups": 41 types, 31 filters...
D [03/May/2025:11:53:39 -0700] Loading printer Canon_LBP622C_623C_UFR_II...
D [03/May/2025:11:53:39 -0700] load_ppd: Loading /var/cache/cups/Canon_LBP622C_623C_UFR_II.data...
D [03/May/2025:11:53:39 -0700] Canon_LBP622C_623C_UFR_II: pdl='application/pdf,application/postscript,image/jpeg,image/png,image/pwg-raster,image/urf'
D [03/May/2025:11:53:39 -0700] cupsdRegisterPrinter(p=0x5f10caa8bd40(Canon_LBP622C_623C_UFR_II))
D [03/May/2025:11:53:39 -0700] load_ppd: Loading /var/cache/cups/Canon_LBP622C_623C_UFR_II.data...
D [03/May/2025:11:53:39 -0700] Canon_LBP622C_623C_UFR_II: pdl='application/pdf,application/postscript,image/jpeg,image/png,image/pwg-raster,image/urf'
D [03/May/2025:11:53:39 -0700] cupsdRegisterPrinter(p=0x5f10caa8bd40(Canon_LBP622C_623C_UFR_II))
D [03/May/2025:11:53:39 -0700] Queue Canon_LBP622C_623C_UFR_II uses a printer driver, which is deprecated.
D [03/May/2025:11:53:39 -0700] Loading printer CUPS-PDF...
D [03/May/2025:11:53:39 -0700] load_ppd: Loading /var/cache/cups/CUPS-PDF.data...
D [03/May/2025:11:53:39 -0700] CUPS-PDF: pdl='application/pdf,application/postscript,image/jpeg,image/png,image/pwg-raster,image/urf'
D [03/May/2025:11:53:39 -0700] cupsdRegisterPrinter(p=0x5f10cab30120(CUPS-PDF))
D [03/May/2025:11:53:39 -0700] Queue CUPS-PDF uses a printer driver, which is deprecated.
W [03/May/2025:11:53:39 -0700] Printer drivers are deprecated and will stop working in a future version of CUPS. See https://github.com/OpenPrinting/cups/issues/103
I [03/May/2025:11:53:39 -0700] Loading job cache file "/var/cache/cups/job.cache"...
D [03/May/2025:11:53:39 -0700] [Job 140] Loading from cache...
D [03/May/2025:11:53:39 -0700] [Job 141] Loading from cache...
D [03/May/2025:11:53:39 -0700] cupsdAddSubscription(mask=0, dest=(nil)(), job=(nil)(0), uri="(null)")
I [03/May/2025:11:53:39 -0700] Full reload complete.
D [03/May/2025:11:53:39 -0700] cupsdCleanFiles(path="/var/spool/cups/tmp", pattern="(null)")
I [03/May/2025:11:53:39 -0700] Cleaning out old files in "/var/spool/cups/tmp".
D [03/May/2025:11:53:39 -0700] cupsdCleanFiles(path="/var/cache/cups", pattern="*.ipp")
I [03/May/2025:11:53:39 -0700] Cleaning out old files in "/var/cache/cups".
D [03/May/2025:11:53:39 -0700] service_checkin: pid=5289
D [03/May/2025:11:53:39 -0700] service_checkin: 1 listeners.
D [03/May/2025:11:53:39 -0700] service_add_listener: Listener #1 at fd 3, "/run/cups/cups.sock".
D [03/May/2025:11:53:39 -0700] service_add_listener: Adding new listener #1 for /run/cups/cups.sock.
D [03/May/2025:11:53:39 -0700] Creating KeepAlive/PID file "/var/cache/cups/org.cups.cupsd".
D [03/May/2025:11:53:39 -0700] Calling FindDeviceById(cups-Canon_LBP622C_623C_UFR_II)
D [03/May/2025:11:53:39 -0700] FindDeviceById failed: org.freedesktop.ColorManager.NotFound:device id \'cups-Canon_LBP622C_623C_UFR_II\' does not exist
D [03/May/2025:11:53:39 -0700] Using profile ID "Canon_LBP622C_623C_UFR_II-Gray..".
D [03/May/2025:11:53:39 -0700] Calling CreateProfile(Canon_LBP622C_623C_UFR_II-Gray..,temp)
D [03/May/2025:11:53:39 -0700] Created profile "/org/freedesktop/ColorManager/profiles/Canon_LBP622C_623C_UFR_II_Gray__".
D [03/May/2025:11:53:39 -0700] Using profile ID "Canon_LBP622C_623C_UFR_II-RGB..".
D [03/May/2025:11:53:39 -0700] Calling CreateProfile(Canon_LBP622C_623C_UFR_II-RGB..,temp)
D [03/May/2025:11:53:39 -0700] Created profile "/org/freedesktop/ColorManager/profiles/Canon_LBP622C_623C_UFR_II_RGB__".
I [03/May/2025:11:53:39 -0700] Registering ICC color profiles for "Canon_LBP622C_623C_UFR_II".
D [03/May/2025:11:53:39 -0700] Calling CreateDevice(cups-Canon_LBP622C_623C_UFR_II,temp)
D [03/May/2025:11:53:39 -0700] Created device "/org/freedesktop/ColorManager/devices/cups_Canon_LBP622C_623C_UFR_II".
D [03/May/2025:11:53:39 -0700] Calling /org/freedesktop/ColorManager/devices/cups_Canon_LBP622C_623C_UFR_II:AddProfile(/org/freedesktop/ColorManager/profiles/Canon_LBP622C_623C_UFR_II_Gray__) [soft]
D [03/May/2025:11:53:39 -0700] Calling /org/freedesktop/ColorManager/devices/cups_Canon_LBP622C_623C_UFR_II:AddProfile(/org/freedesktop/ColorManager/profiles/Canon_LBP622C_623C_UFR_II_RGB__) [soft]
D [03/May/2025:11:53:39 -0700] Calling FindDeviceById(cups-CUPS-PDF)
D [03/May/2025:11:53:39 -0700] FindDeviceById failed: org.freedesktop.ColorManager.NotFound:device id \'cups-CUPS-PDF\' does not exist
D [03/May/2025:11:53:39 -0700] Using profile ID "CUPS-PDF-Gray..".
D [03/May/2025:11:53:39 -0700] Calling CreateProfile(CUPS-PDF-Gray..,temp)
D [03/May/2025:11:53:39 -0700] Created profile "/org/freedesktop/ColorManager/profiles/CUPS_PDF_Gray__".
D [03/May/2025:11:53:39 -0700] Using profile ID "CUPS-PDF-RGB..".
D [03/May/2025:11:53:39 -0700] Calling CreateProfile(CUPS-PDF-RGB..,temp)
D [03/May/2025:11:53:39 -0700] Created profile "/org/freedesktop/ColorManager/profiles/CUPS_PDF_RGB__".
I [03/May/2025:11:53:39 -0700] Registering ICC color profiles for "CUPS-PDF".
D [03/May/2025:11:53:39 -0700] Calling CreateDevice(cups-CUPS-PDF,temp)
D [03/May/2025:11:53:39 -0700] Created device "/org/freedesktop/ColorManager/devices/cups_CUPS_PDF".
D [03/May/2025:11:53:39 -0700] Calling /org/freedesktop/ColorManager/devices/cups_CUPS_PDF:AddProfile(/org/freedesktop/ColorManager/profiles/CUPS_PDF_Gray__) [soft]
D [03/May/2025:11:53:39 -0700] Calling /org/freedesktop/ColorManager/devices/cups_CUPS_PDF:AddProfile(/org/freedesktop/ColorManager/profiles/CUPS_PDF_RGB__) [soft]
I [03/May/2025:11:53:39 -0700] Listening to [v1.::1]:631 on fd 7...
I [03/May/2025:11:53:39 -0700] Listening to 127.0.0.1:631 on fd 8...
I [03/May/2025:11:53:39 -0700] Listening to /run/cups/cups.sock on fd 3...
I [03/May/2025:11:53:39 -0700] Resuming new connection processing...
D [03/May/2025:11:53:39 -0700] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [03/May/2025:11:53:39 -0700] cupsdAddCert: Adding certificate for PID 0
D [03/May/2025:11:53:39 -0700] Discarding unused server-started event...
D [03/May/2025:11:53:39 -0700] cupsdSetBusyState: newbusy="Not busy", busy="Not busy"
D [03/May/2025:11:53:40 -0700] Expiring subscriptions...
D [03/May/2025:11:53:40 -0700] Report: clients=0
D [03/May/2025:11:53:40 -0700] Report: jobs=2
D [03/May/2025:11:53:40 -0700] Report: jobs-active=0
D [03/May/2025:11:53:40 -0700] Report: printers=2
D [03/May/2025:11:53:40 -0700] Report: stringpool-string-count=1530
D [03/May/2025:11:53:40 -0700] Report: stringpool-alloc-bytes=10808
D [03/May/2025:11:53:40 -0700] Report: stringpool-total-bytes=29032
D [03/May/2025:11:53:48 -0700] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [03/May/2025:11:53:48 -0700] [Client 1] Server address is "/run/cups/cups.sock".
D [03/May/2025:11:53:48 -0700] [Client 1] Accepted from localhost (Domain)
D [03/May/2025:11:53:48 -0700] [Client 1] Waiting for request.
D [03/May/2025:11:53:48 -0700] Expiring subscriptions...
D [03/May/2025:11:53:48 -0700] [Client 1] POST / HTTP/1.1
D [03/May/2025:11:53:48 -0700] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
D [03/May/2025:11:53:48 -0700] [Client 1] Read: status=200, state=6
D [03/May/2025:11:53:48 -0700] [Client 1] No authentication data provided.
D [03/May/2025:11:53:48 -0700] [Client 1] 2.0 CUPS-Get-Default 1
D [03/May/2025:11:53:48 -0700] CUPS-Get-Default
D [03/May/2025:11:53:48 -0700] [Client 1] Returning IPP successful-ok for CUPS-Get-Default (no URI) from localhost.
D [03/May/2025:11:53:48 -0700] [Client 1] Content-Length: 1653
D [03/May/2025:11:53:48 -0700] [Client 1] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [03/May/2025:11:53:48 -0700] [Client 1] con->http=0x5f10cab66170
D [03/May/2025:11:53:48 -0700] [Client 1] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=1653, response=0x5f10cab39870(IPP_STATE_DATA), pipe_pid=0, file=-1
D [03/May/2025:11:53:48 -0700] [Client 1] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [03/May/2025:11:53:48 -0700] [Client 1] bytes=0, http_state=0, data_remaining=1653
D [03/May/2025:11:53:48 -0700] [Client 1] Flushing write buffer.
D [03/May/2025:11:53:48 -0700] [Client 1] New state is HTTP_STATE_WAITING
D [03/May/2025:11:53:48 -0700] [Client 1] Waiting for request.
D [03/May/2025:11:53:48 -0700] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [03/May/2025:11:53:48 -0700] [Client 1] POST / HTTP/1.1
D [03/May/2025:11:53:48 -0700] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [03/May/2025:11:53:48 -0700] [Client 1] Read: status=200, state=6
D [03/May/2025:11:53:48 -0700] [Client 1] No authentication data provided.
D [03/May/2025:11:53:48 -0700] [Client 1] 2.0 Get-Printer-Attributes 2
D [03/May/2025:11:53:48 -0700] Get-Printer-Attributes ipp://localhost:631/printers/Canon_LBP622C_623C_UFR_II
D [03/May/2025:11:53:48 -0700] [Client 1] Returning IPP successful-ok for Get-Printer-Attributes (ipp://localhost:631/printers/Canon_LBP622C_623C_UFR_II) from localhost.
D [03/May/2025:11:53:48 -0700] [Client 1] Content-Length: 1653
D [03/May/2025:11:53:48 -0700] [Client 1] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [03/May/2025:11:53:48 -0700] [Client 1] con->http=0x5f10cab66170
D [03/May/2025:11:53:48 -0700] [Client 1] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=1653, response=0x5f10cab3cc00(IPP_STATE_DATA), pipe_pid=0, file=-1
D [03/May/2025:11:53:48 -0700] [Client 1] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [03/May/2025:11:53:48 -0700] [Client 1] bytes=0, http_state=0, data_remaining=1653
D [03/May/2025:11:53:48 -0700] [Client 1] Flushing write buffer.
D [03/May/2025:11:53:48 -0700] [Client 1] New state is HTTP_STATE_WAITING
D [03/May/2025:11:53:48 -0700] [Client 1] Waiting for request.
D [03/May/2025:11:53:48 -0700] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [03/May/2025:11:53:48 -0700] [Client 1] POST /printers/Canon_LBP622C_623C_UFR_II HTTP/1.1
D [03/May/2025:11:53:48 -0700] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [03/May/2025:11:53:48 -0700] [Client 1] Read: status=200, state=6
D [03/May/2025:11:53:48 -0700] [Client 1] No authentication data provided.
D [03/May/2025:11:53:48 -0700] [Client 1] 2.0 Get-Printer-Attributes 3
D [03/May/2025:11:53:48 -0700] Get-Printer-Attributes ipp://localhost/printers/Canon_LBP622C_623C_UFR_II
D [03/May/2025:11:53:48 -0700] [Client 1] Returning IPP successful-ok for Get-Printer-Attributes (ipp://localhost/printers/Canon_LBP622C_623C_UFR_II) from localhost.
D [03/May/2025:11:53:48 -0700] [Client 1] Content-Length: 14742
D [03/May/2025:11:53:48 -0700] [Client 1] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [03/May/2025:11:53:48 -0700] [Client 1] con->http=0x5f10cab66170
D [03/May/2025:11:53:48 -0700] [Client 1] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=14742, response=0x5f10cab5d6e0(IPP_STATE_DATA), pipe_pid=0, file=-1
D [03/May/2025:11:53:48 -0700] [Client 1] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [03/May/2025:11:53:48 -0700] [Client 1] bytes=0, http_state=0, data_remaining=14742
D [03/May/2025:11:53:48 -0700] [Client 1] Flushing write buffer.
D [03/May/2025:11:53:48 -0700] [Client 1] New state is HTTP_STATE_WAITING
D [03/May/2025:11:53:48 -0700] [Client 1] Waiting for request.
D [03/May/2025:11:53:48 -0700] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [03/May/2025:11:53:48 -0700] [Client 1] POST /printers/Canon_LBP622C_623C_UFR_II HTTP/1.1
D [03/May/2025:11:53:48 -0700] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [03/May/2025:11:53:48 -0700] [Client 1] Read: status=200, state=6
D [03/May/2025:11:53:48 -0700] [Client 1] No authentication data provided.
D [03/May/2025:11:53:48 -0700] [Client 1] 2.0 Create-Job 4
D [03/May/2025:11:53:48 -0700] Create-Job ipp://localhost/printers/Canon_LBP622C_623C_UFR_II
D [03/May/2025:11:53:48 -0700] cupsdMarkDirty(---J-)
D [03/May/2025:11:53:48 -0700] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients"
D [03/May/2025:11:53:48 -0700] [Job 142] Applying default options...
D [03/May/2025:11:53:48 -0700] add_job: requesting-user-name="grahams"
I [03/May/2025:11:53:48 -0700] [Job 142] Adding start banner page "none".
D [03/May/2025:11:53:48 -0700] Notifier dbus started - PID = 5302
D [03/May/2025:11:53:48 -0700] cupsdMarkDirty(----S)
D [03/May/2025:11:53:48 -0700] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
I [03/May/2025:11:53:48 -0700] [Job 142] Queued on "Canon_LBP622C_623C_UFR_II" by "grahams".
D [03/May/2025:11:53:48 -0700] [Client 1] Returning IPP successful-ok for Create-Job (no URI) from localhost.
D [03/May/2025:11:53:48 -0700] [Client 1] Content-Length: 201
D [03/May/2025:11:53:48 -0700] [Client 1] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [03/May/2025:11:53:48 -0700] [Client 1] con->http=0x5f10cab66170
D [03/May/2025:11:53:48 -0700] [Client 1] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=201, response=0x5f10cab50820(IPP_STATE_IDLE), pipe_pid=0, file=-1
D [03/May/2025:11:53:48 -0700] [Client 1] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [03/May/2025:11:53:48 -0700] [Client 1] bytes=0, http_state=0, data_remaining=201
D [03/May/2025:11:53:48 -0700] [Client 1] Flushing write buffer.
D [03/May/2025:11:53:48 -0700] [Client 1] New state is HTTP_STATE_WAITING
D [03/May/2025:11:53:48 -0700] [Client 1] Waiting for request.
D [03/May/2025:11:53:48 -0700] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [03/May/2025:11:53:48 -0700] [Client 1] POST /printers/Canon_LBP622C_623C_UFR_II HTTP/1.1
D [03/May/2025:11:53:48 -0700] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [03/May/2025:11:53:48 -0700] [Client 1] Read: status=200, state=6
D [03/May/2025:11:53:48 -0700] [Client 1] No authentication data provided.
D [03/May/2025:11:53:48 -0700] [Client 1] 2.0 Send-Document 5
D [03/May/2025:11:53:48 -0700] [Notifier] state=3
D [03/May/2025:11:53:48 -0700] [Notifier] Connected to D-BUS
D [03/May/2025:11:53:48 -0700] [Notifier] JobCreated
D [03/May/2025:11:53:48 -0700] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [03/May/2025:11:53:48 -0700] [Client 2] Server address is "/run/cups/cups.sock".
D [03/May/2025:11:53:48 -0700] [Client 2] Accepted from localhost (Domain)
D [03/May/2025:11:53:48 -0700] [Client 2] Waiting for request.
D [03/May/2025:11:53:48 -0700] [Client 2] POST / HTTP/1.1
D [03/May/2025:11:53:48 -0700] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [03/May/2025:11:53:48 -0700] [Client 2] Read: status=200, state=6
D [03/May/2025:11:53:48 -0700] [Client 2] No authentication data provided.
D [03/May/2025:11:53:48 -0700] [Client 2] 2.0 Get-Notifications 213
D [03/May/2025:11:53:48 -0700] Get-Notifications /printers/
D [03/May/2025:11:53:48 -0700] cupsdIsAuthorized: requesting-user-name="grahams"
D [03/May/2025:11:53:48 -0700] [Client 2] Returning IPP successful-ok for Get-Notifications (/printers/) from localhost.
D [03/May/2025:11:53:48 -0700] [Client 2] Content-Length: 673
D [03/May/2025:11:53:48 -0700] [Client 2] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [03/May/2025:11:53:48 -0700] [Client 2] con->http=0x5f10cab6ca40
D [03/May/2025:11:53:48 -0700] [Client 2] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=673, response=0x5f10cab37600(IPP_STATE_DATA), pipe_pid=0, file=-1
D [03/May/2025:11:53:48 -0700] [Client 2] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [03/May/2025:11:53:48 -0700] [Client 2] bytes=0, http_state=0, data_remaining=673
D [03/May/2025:11:53:48 -0700] [Client 2] Flushing write buffer.
D [03/May/2025:11:53:48 -0700] [Client 2] New state is HTTP_STATE_WAITING
D [03/May/2025:11:53:48 -0700] [Client 2] Waiting for request.
D [03/May/2025:11:53:48 -0700] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [03/May/2025:11:53:48 -0700] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [03/May/2025:11:53:48 -0700] [Client 3] Server address is "/run/cups/cups.sock".
D [03/May/2025:11:53:48 -0700] [Client 3] Accepted from localhost (Domain)
D [03/May/2025:11:53:48 -0700] [Client 3] Waiting for request.
D [03/May/2025:11:53:48 -0700] [Client 3] POST / HTTP/1.1
D [03/May/2025:11:53:48 -0700] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [03/May/2025:11:53:48 -0700] [Client 3] Read: status=200, state=6
D [03/May/2025:11:53:48 -0700] [Client 3] No authentication data provided.
D [03/May/2025:11:53:48 -0700] [Client 3] 2.0 Get-Job-Attributes 214
D [03/May/2025:11:53:48 -0700] Get-Job-Attributes ipp://localhost/jobs/142
D [03/May/2025:11:53:48 -0700] [Client 3] Returning IPP successful-ok for Get-Job-Attributes (ipp://localhost/jobs/142) from localhost.
D [03/May/2025:11:53:48 -0700] [Client 3] Content-Length: 113
D [03/May/2025:11:53:48 -0700] [Client 3] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [03/May/2025:11:53:48 -0700] [Client 3] con->http=0x5f10cab71250
D [03/May/2025:11:53:48 -0700] [Client 3] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=113, response=0x5f10cab5e490(IPP_STATE_DATA), pipe_pid=0, file=-1
D [03/May/2025:11:53:48 -0700] [Client 3] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [03/May/2025:11:53:48 -0700] [Client 3] bytes=0, http_state=0, data_remaining=113
D [03/May/2025:11:53:48 -0700] [Client 3] Flushing write buffer.
D [03/May/2025:11:53:48 -0700] [Client 3] New state is HTTP_STATE_WAITING
D [03/May/2025:11:53:48 -0700] [Client 3] Waiting for request.
D [03/May/2025:11:53:48 -0700] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [03/May/2025:11:53:48 -0700] [Client 3] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [03/May/2025:11:53:48 -0700] [Client 3] Closing connection.
D [03/May/2025:11:53:48 -0700] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [03/May/2025:11:53:49 -0700] Expiring subscriptions...
D [03/May/2025:11:53:51 -0700] [Client 1] Read: status=100, state=6
D [03/May/2025:11:53:51 -0700] Send-Document ipp://localhost:631/printers/Canon_LBP622C_623C_UFR_II
D [03/May/2025:11:53:51 -0700] cupsdIsAuthorized: requesting-user-name="grahams"
D [03/May/2025:11:53:51 -0700] [Job 142] Auto-typing file...
D [03/May/2025:11:53:51 -0700] [Job 142] Request file type is text/plain.
D [03/May/2025:11:53:51 -0700] cupsdMarkDirty(---J-)
D [03/May/2025:11:53:51 -0700] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
I [03/May/2025:11:53:51 -0700] [Job 142] File of type text/plain queued by "grahams".
I [03/May/2025:11:53:51 -0700] [Job 142] Adding end banner page "none".
D [03/May/2025:11:53:51 -0700] cupsdMarkDirty(---J-)
D [03/May/2025:11:53:51 -0700] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [03/May/2025:11:53:51 -0700] [Job 142] time-at-processing=1746298431
D [03/May/2025:11:53:51 -0700] cupsdMarkDirty(---J-)
D [03/May/2025:11:53:51 -0700] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [03/May/2025:11:53:51 -0700] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [03/May/2025:11:53:51 -0700] cupsdMarkDirty(----S)
D [03/May/2025:11:53:51 -0700] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [03/May/2025:11:53:51 -0700] [Job 142] 3 filters for job:
D [03/May/2025:11:53:51 -0700] [Job 142] - (text/plain to application/vnd.universal-input, cost 0)
D [03/May/2025:11:53:51 -0700] [Job 142] universal (application/vnd.universal-input to application/vnd.cups-raster, cost 0)
D [03/May/2025:11:53:51 -0700] [Job 142] rastertoufr2 (application/vnd.cups-raster to printer/Canon_LBP622C_623C_UFR_II, cost 0)
D [03/May/2025:11:53:51 -0700] [Job 142] job-sheets=none,none
D [03/May/2025:11:53:51 -0700] [Job 142] argv[0]="Canon_LBP622C_623C_UFR_II"
D [03/May/2025:11:53:51 -0700] [Job 142] argv[1]="142"
D [03/May/2025:11:53:51 -0700] [Job 142] argv[2]="grahams"
D [03/May/2025:11:53:51 -0700] [Job 142] argv[3]="(stdin)"
D [03/May/2025:11:53:51 -0700] [Job 142] argv[4]="1"
D [03/May/2025:11:53:51 -0700] [Job 142] argv[5]="finishings=3 number-up=1 print-color-mode=color job-uuid=urn:uuid:4a7590d5-26ed-3ed1-5c73-daf86fe4bbca job-originating-host-name=localhost date-time-at-creation= date-time-at-processing= time-at-creation=1746298428 time-at-processing=1746298431"
D [03/May/2025:11:53:51 -0700] [Job 142] argv[6]="/var/spool/cups/d00142-001"
D [03/May/2025:11:53:51 -0700] [Job 142] envp[0]="CUPS_CACHEDIR=/var/cache/cups"
D [03/May/2025:11:53:51 -0700] [Job 142] envp[1]="CUPS_DATADIR=/usr/share/cups"
D [03/May/2025:11:53:51 -0700] [Job 142] envp[2]="CUPS_DOCROOT=/usr/share/cups/doc"
D [03/May/2025:11:53:51 -0700] [Job 142] envp[3]="CUPS_REQUESTROOT=/var/spool/cups"
D [03/May/2025:11:53:51 -0700] [Job 142] envp[4]="CUPS_SERVERBIN=/usr/lib/cups"
D [03/May/2025:11:53:51 -0700] [Job 142] envp[5]="CUPS_SERVERROOT=/etc/cups"
D [03/May/2025:11:53:51 -0700] [Job 142] envp[6]="CUPS_STATEDIR=/run/cups"
D [03/May/2025:11:53:51 -0700] [Job 142] envp[7]="HOME=/var/spool/cups/tmp"
D [03/May/2025:11:53:51 -0700] [Job 142] envp[8]="PATH=/usr/lib/cups/filter:/usr/bin:/usr/bin:/bin:/usr/bin"
D [03/May/2025:11:53:51 -0700] [Job 142] envp[9]="SERVER_ADMIN=root@hp8330"
D [03/May/2025:11:53:51 -0700] [Job 142] envp[10]="SOFTWARE=CUPS/2.4.12"
D [03/May/2025:11:53:51 -0700] [Job 142] envp[11]="TMPDIR=/var/spool/cups/tmp"
D [03/May/2025:11:53:51 -0700] [Job 142] envp[12]="USER=root"
D [03/May/2025:11:53:51 -0700] [Job 142] envp[13]="CUPS_MAX_MESSAGE=2047"
D [03/May/2025:11:53:51 -0700] [Job 142] envp[14]="CUPS_SERVER=/run/cups/cups.sock"
D [03/May/2025:11:53:51 -0700] [Job 142] envp[15]="CUPS_ENCRYPTION=IfRequested"
D [03/May/2025:11:53:51 -0700] [Job 142] envp[16]="IPP_PORT=631"
D [03/May/2025:11:53:51 -0700] [Job 142] envp[17]="CHARSET=utf-8"
D [03/May/2025:11:53:51 -0700] [Job 142] envp[18]="LANG=en_US.UTF-8"
D [03/May/2025:11:53:51 -0700] [Job 142] envp[19]="PPD=/etc/cups/ppd/Canon_LBP622C_623C_UFR_II.ppd"
D [03/May/2025:11:53:51 -0700] [Job 142] envp[20]="CONTENT_TYPE=text/plain"
D [03/May/2025:11:53:51 -0700] [Job 142] envp[21]="DEVICE_URI=socket://192.168.2.137"
D [03/May/2025:11:53:51 -0700] [Job 142] envp[22]="PRINTER_INFO=Canon LBP622C/623C UFR II"
D [03/May/2025:11:53:51 -0700] [Job 142] envp[23]="PRINTER_LOCATION="
D [03/May/2025:11:53:51 -0700] [Job 142] envp[24]="PRINTER=Canon_LBP622C_623C_UFR_II"
D [03/May/2025:11:53:51 -0700] [Job 142] envp[25]="PRINTER_STATE_REASONS=none"
D [03/May/2025:11:53:51 -0700] [Job 142] envp[26]="CUPS_FILETYPE=document"
D [03/May/2025:11:53:51 -0700] [Job 142] envp[27]="FINAL_CONTENT_TYPE=application/vnd.cups-raster"
D [03/May/2025:11:53:51 -0700] [Job 142] envp[28]="AUTH_I****"
I [03/May/2025:11:53:51 -0700] [Job 142] Started filter /usr/lib/cups/filter/universal (PID 5303)
I [03/May/2025:11:53:51 -0700] [Job 142] Started filter /usr/lib/cups/filter/rastertoufr2 (PID 5304)
I [03/May/2025:11:53:51 -0700] [Job 142] Started backend /usr/lib/cups/backend/socket (PID 5305)
D [03/May/2025:11:53:51 -0700] cupsdMarkDirty(----S)
D [03/May/2025:11:53:51 -0700] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Active clients and dirty files"
D [03/May/2025:11:53:51 -0700] [Client 1] Returning IPP successful-ok for Send-Document (ipp://localhost:631/printers/Canon_LBP622C_623C_UFR_II) from localhost.
D [03/May/2025:11:53:51 -0700] [Client 1] Content-Length: 171
D [03/May/2025:11:53:51 -0700] [Client 1] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [03/May/2025:11:53:51 -0700] Expiring subscriptions...
D [03/May/2025:11:53:51 -0700] [Client 1] con->http=0x5f10cab66170
D [03/May/2025:11:53:51 -0700] [Client 1] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=171, response=0x5f10cab5e490(IPP_STATE_DATA), pipe_pid=0, file=-1
D [03/May/2025:11:53:51 -0700] [Client 1] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [03/May/2025:11:53:51 -0700] [Client 1] bytes=0, http_state=0, data_remaining=171
D [03/May/2025:11:53:51 -0700] [Client 1] Flushing write buffer.
D [03/May/2025:11:53:51 -0700] [Client 1] New state is HTTP_STATE_WAITING
D [03/May/2025:11:53:51 -0700] [Client 1] Waiting for request.
D [03/May/2025:11:53:51 -0700] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients, printing jobs, and dirty files"
D [03/May/2025:11:53:51 -0700] [Notifier] state=3
D [03/May/2025:11:53:51 -0700] [Notifier] PrinterStateChanged
D [03/May/2025:11:53:51 -0700] [Notifier] state=3
D [03/May/2025:11:53:51 -0700] [Notifier] JobState
D [03/May/2025:11:53:51 -0700] [Client 2] POST / HTTP/1.1
D [03/May/2025:11:53:51 -0700] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Printing jobs and dirty files"
D [03/May/2025:11:53:51 -0700] [Client 2] Read: status=200, state=6
D [03/May/2025:11:53:51 -0700] [Client 2] No authentication data provided.
D [03/May/2025:11:53:51 -0700] [Client 2] 2.0 Get-Notifications 215
D [03/May/2025:11:53:51 -0700] Get-Notifications /printers/
D [03/May/2025:11:53:51 -0700] cupsdIsAuthorized: requesting-user-name="grahams"
D [03/May/2025:11:53:51 -0700] [Client 2] Returning IPP successful-ok for Get-Notifications (/printers/) from localhost.
D [03/May/2025:11:53:51 -0700] [Client 2] Content-Length: 1140
D [03/May/2025:11:53:51 -0700] [Client 2] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [03/May/2025:11:53:51 -0700] [Client 2] con->http=0x5f10cab6ca40
D [03/May/2025:11:53:51 -0700] [Client 2] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=1140, response=0x5f10cab50820(IPP_STATE_DATA), pipe_pid=0, file=-1
D [03/May/2025:11:53:51 -0700] [Client 2] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [03/May/2025:11:53:51 -0700] [Client 2] bytes=0, http_state=0, data_remaining=1140
D [03/May/2025:11:53:51 -0700] [Client 2] Flushing write buffer.
D [03/May/2025:11:53:51 -0700] [Client 2] New state is HTTP_STATE_WAITING
D [03/May/2025:11:53:51 -0700] [Client 2] Waiting for request.
D [03/May/2025:11:53:51 -0700] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients, printing jobs, and dirty files"
D [03/May/2025:11:53:51 -0700] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Printing jobs and dirty files"
D [03/May/2025:11:53:51 -0700] [Client 4] Server address is "/run/cups/cups.sock".
D [03/May/2025:11:53:51 -0700] [Client 4] Accepted from localhost (Domain)
D [03/May/2025:11:53:51 -0700] [Client 4] Waiting for request.
D [03/May/2025:11:53:51 -0700] [Client 4] POST / HTTP/1.1
D [03/May/2025:11:53:51 -0700] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Active clients, printing jobs, and dirty files"
D [03/May/2025:11:53:51 -0700] [Client 4] Read: status=200, state=6
D [03/May/2025:11:53:51 -0700] [Client 4] No authentication data provided.
D [03/May/2025:11:53:51 -0700] [Client 4] 2.0 Get-Job-Attributes 216
D [03/May/2025:11:53:51 -0700] Get-Job-Attributes ipp://localhost/jobs/142
D [03/May/2025:11:53:51 -0700] [Client 4] Returning IPP successful-ok for Get-Job-Attributes (ipp://localhost/jobs/142) from localhost.
D [03/May/2025:11:53:51 -0700] [Client 4] Content-Length: 113
D [03/May/2025:11:53:51 -0700] [Client 4] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [03/May/2025:11:53:51 -0700] [Client 4] con->http=0x5f10cab71250
D [03/May/2025:11:53:51 -0700] [Client 4] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=113, response=0x5f10cab5e490(IPP_STATE_DATA), pipe_pid=0, file=-1
D [03/May/2025:11:53:51 -0700] [Client 4] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [03/May/2025:11:53:51 -0700] [Client 4] bytes=0, http_state=0, data_remaining=113
D [03/May/2025:11:53:51 -0700] [Client 4] Flushing write buffer.
D [03/May/2025:11:53:51 -0700] [Client 4] New state is HTTP_STATE_WAITING
D [03/May/2025:11:53:51 -0700] [Client 4] Waiting for request.
D [03/May/2025:11:53:51 -0700] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients, printing jobs, and dirty files"
D [03/May/2025:11:53:51 -0700] [Client 4] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [03/May/2025:11:53:51 -0700] [Client 4] Closing connection.
D [03/May/2025:11:53:51 -0700] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [03/May/2025:11:53:51 -0700] [Client 1] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [03/May/2025:11:53:51 -0700] [Client 1] Closing connection.
D [03/May/2025:11:53:51 -0700] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [03/May/2025:11:53:51 -0700] [Job 142] STATE: +connecting-to-device
D [03/May/2025:11:53:51 -0700] cupsdMarkDirty(---J-)
D [03/May/2025:11:53:51 -0700] cupsdSetBusyState: newbusy="Dirty files", busy="Printing jobs and dirty files"
D [03/May/2025:11:53:51 -0700] [Job 142] Looking up \"192.168.2.137\"...
D [03/May/2025:11:53:51 -0700] [Job 142] STATE: -connecting-to-device
D [03/May/2025:11:53:51 -0700] cupsdMarkDirty(---J-)
D [03/May/2025:11:53:51 -0700] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Dirty files"
D [03/May/2025:11:53:51 -0700] [Job 142] 192.168.2.137=192.168.2.137
D [03/May/2025:11:53:51 -0700] cupsdMarkDirty(----S)
D [03/May/2025:11:53:51 -0700] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [03/May/2025:11:53:51 -0700] [Notifier] state=3
D [03/May/2025:11:53:51 -0700] [Notifier] PrinterStateChanged
D [03/May/2025:11:53:51 -0700] [Job 142] ppdFilterLoadPPD: Color profile qualifier determined from job and PPD data \'.Auto.600\'
D [03/May/2025:11:53:51 -0700] [Job 142] ppdFilterLoadPPD: No ICC profiles specified in PPD
D [03/May/2025:11:53:51 -0700] [Job 142] ppdFilterLoadPPD: Searching for profile \"600/Auto\"...
D [03/May/2025:11:53:51 -0700] [Job 142] ppdFilterLoadPPD: Last filter determined by the PPD: rastertoufr2; Final data MIME type: application/vnd.cups-raster => PDF filter will not log pages in page_log.
D [03/May/2025:11:53:51 -0700] [Job 142] ppdFilterUniversal: \"*cupsFilter(2): ...\" lines in the PPD file:
D [03/May/2025:11:53:51 -0700] [Job 142] ppdFilterUniversal:    application/vnd.cups-raw application/octet-stream 0 -
D [03/May/2025:11:53:51 -0700] [Job 142] ppdFilterUniversal:    application/vnd.cups-raster 0 rastertoufr2
D [03/May/2025:11:53:51 -0700] [Job 142] ppdFilterUniversal: PPD uses \"*cupsFilter: ...\" lines, so we always convert to format given by FINAL_CONTENT_TYPE
D [03/May/2025:11:53:51 -0700] [Job 142] ppdFilterUniversal: Converting from text/plain to application/vnd.cups-raster
D [03/May/2025:11:53:51 -0700] [Job 142] cfFilterUniversal: Converting from text/plain to application/vnd.cups-raster
D [03/May/2025:11:53:51 -0700] [Job 142] cfFilterUniversal: Final output format for job: application/vnd.cups-raster
D [03/May/2025:11:53:51 -0700] [Job 142] cfFilterUniversal: Adding texttopdf to chain
D [03/May/2025:11:53:51 -0700] [Job 142] cfFilterUniversal: Adding pdftopdf to chain
D [03/May/2025:11:53:51 -0700] [Job 142] cfFilterUniversal: Adding ghostscript to chain
D [03/May/2025:11:53:51 -0700] [Job 142] cfFilterChain: Running filter: texttopdf
D [03/May/2025:11:53:51 -0700] cupsdMarkDirty(---J-)
D [03/May/2025:11:53:51 -0700] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [03/May/2025:11:53:51 -0700] [Job 142] Set job-printer-state-message to "cfFilterChain: Running filter: texttopdf", current level=INFO
D [03/May/2025:11:53:51 -0700] [Job 142] cfFilterChain: Running filter: pdftopdf
D [03/May/2025:11:53:51 -0700] cupsdMarkDirty(---J-)
D [03/May/2025:11:53:51 -0700] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [03/May/2025:11:53:51 -0700] [Job 142] Set job-printer-state-message to "cfFilterChain: Running filter: pdftopdf", current level=INFO
D [03/May/2025:11:53:51 -0700] [Job 142] cfFilterChain: Running filter: ghostscript
D [03/May/2025:11:53:51 -0700] cupsdMarkDirty(---J-)
D [03/May/2025:11:53:51 -0700] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [03/May/2025:11:53:51 -0700] [Job 142] Set job-printer-state-message to "cfFilterChain: Running filter: ghostscript", current level=INFO
D [03/May/2025:11:53:51 -0700] Discarding unused job-progress event...
D [03/May/2025:11:53:51 -0700] cupsdMarkDirty(----S)
D [03/May/2025:11:53:51 -0700] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [03/May/2025:11:53:51 -0700] [Notifier] state=3
D [03/May/2025:11:53:51 -0700] [Notifier] PrinterStateChanged
D [03/May/2025:11:53:51 -0700] [Job 142] cfFilterChain: texttopdf (PID 5307) started.
D [03/May/2025:11:53:51 -0700] cupsdMarkDirty(---J-)
D [03/May/2025:11:53:51 -0700] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [03/May/2025:11:53:51 -0700] [Job 142] Set job-printer-state-message to "cfFilterChain: texttopdf (PID 5307) started.", current level=INFO
D [03/May/2025:11:53:51 -0700] Discarding unused job-progress event...
D [03/May/2025:11:53:51 -0700] cupsdMarkDirty(----S)
D [03/May/2025:11:53:51 -0700] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [03/May/2025:11:53:51 -0700] [Notifier] state=3
D [03/May/2025:11:53:51 -0700] [Notifier] PrinterStateChanged
D [03/May/2025:11:53:51 -0700] [Job 142] Color space requested: Default
D [03/May/2025:11:53:51 -0700] [Job 142] Final output format: CUPS Raster
D [03/May/2025:11:53:51 -0700] [Job 142] Format of the input document: text/plain
D [03/May/2025:11:53:51 -0700] [Job 142] Document\'s input format does not provide absolute size dimensions for each page, falling back to US Letter if no output page size is provided.
D [03/May/2025:11:53:51 -0700] [Job 142] cfFilterPDFToPDF: Suppressed page logging selected by options.
D [03/May/2025:11:53:51 -0700] [Job 142] cfFilterChain: pdftopdf (PID 5308) started.
D [03/May/2025:11:53:51 -0700] cupsdMarkDirty(---J-)
D [03/May/2025:11:53:51 -0700] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [03/May/2025:11:53:51 -0700] [Job 142] Set job-printer-state-message to "cfFilterChain: pdftopdf (PID 5308) started.", current level=INFO
D [03/May/2025:11:53:51 -0700] [Job 142] cfFilterChain: ghostscript (PID 5309) started.
D [03/May/2025:11:53:51 -0700] cupsdMarkDirty(---J-)
D [03/May/2025:11:53:51 -0700] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [03/May/2025:11:53:51 -0700] [Job 142] Set job-printer-state-message to "cfFilterChain: ghostscript (PID 5309) started.", current level=INFO
D [03/May/2025:11:53:51 -0700] [Job 142] cfFilterGhostscript: Output format: CUPS Raster
D [03/May/2025:11:53:51 -0700] [Job 142] cfFilterGhostscript: Copying input to temp file \"/var/spool/cups/tmp/014bd681db9b0\"
D [03/May/2025:11:53:51 -0700] Discarding unused job-progress event...
D [03/May/2025:11:53:51 -0700] cupsdMarkDirty(----S)
D [03/May/2025:11:53:51 -0700] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [03/May/2025:11:53:51 -0700] [Notifier] state=3
D [03/May/2025:11:53:51 -0700] [Notifier] PrinterStateChanged
D [03/May/2025:11:53:51 -0700] [Client 2] POST / HTTP/1.1
D [03/May/2025:11:53:51 -0700] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Printing jobs and dirty files"
D [03/May/2025:11:53:51 -0700] [Client 2] Read: status=200, state=6
D [03/May/2025:11:53:51 -0700] [Client 2] No authentication data provided.
D [03/May/2025:11:53:51 -0700] [Client 2] 2.0 Get-Notifications 217
D [03/May/2025:11:53:51 -0700] Get-Notifications /printers/
D [03/May/2025:11:53:51 -0700] cupsdIsAuthorized: requesting-user-name="grahams"
D [03/May/2025:11:53:51 -0700] [Client 2] Returning IPP successful-ok for Get-Notifications (/printers/) from localhost.
D [03/May/2025:11:53:51 -0700] [Client 2] Content-Length: 1943
D [03/May/2025:11:53:51 -0700] [Client 2] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [03/May/2025:11:53:51 -0700] [Client 2] con->http=0x5f10cab6ca40
D [03/May/2025:11:53:51 -0700] [Client 2] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=1943, response=0x5f10cab5dab0(IPP_STATE_DATA), pipe_pid=0, file=-1
D [03/May/2025:11:53:51 -0700] [Client 2] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [03/May/2025:11:53:51 -0700] [Client 2] bytes=0, http_state=0, data_remaining=1943
D [03/May/2025:11:53:51 -0700] [Client 2] Flushing write buffer.
D [03/May/2025:11:53:51 -0700] [Client 2] New state is HTTP_STATE_WAITING
D [03/May/2025:11:53:51 -0700] [Client 2] Waiting for request.
D [03/May/2025:11:53:51 -0700] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients, printing jobs, and dirty files"
D [03/May/2025:11:53:51 -0700] [Client 2] POST / HTTP/1.1
D [03/May/2025:11:53:51 -0700] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Printing jobs and dirty files"
D [03/May/2025:11:53:51 -0700] [Client 2] Read: status=200, state=6
D [03/May/2025:11:53:51 -0700] [Client 2] No authentication data provided.
D [03/May/2025:11:53:51 -0700] [Client 2] 2.0 CUPS-Get-Default 218
D [03/May/2025:11:53:51 -0700] CUPS-Get-Default
D [03/May/2025:11:53:51 -0700] [Client 2] Returning IPP successful-ok for CUPS-Get-Default (no URI) from localhost.
D [03/May/2025:11:53:51 -0700] [Client 2] Content-Length: 11419
D [03/May/2025:11:53:51 -0700] [Client 2] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [03/May/2025:11:53:51 -0700] [Client 2] con->http=0x5f10cab6ca40
D [03/May/2025:11:53:51 -0700] [Client 2] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=11419, response=0x5f10cab3be40(IPP_STATE_DATA), pipe_pid=0, file=-1
D [03/May/2025:11:53:51 -0700] [Client 2] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [03/May/2025:11:53:51 -0700] [Client 2] bytes=0, http_state=0, data_remaining=11419
D [03/May/2025:11:53:51 -0700] [Client 2] Flushing write buffer.
D [03/May/2025:11:53:51 -0700] [Client 2] New state is HTTP_STATE_WAITING
D [03/May/2025:11:53:51 -0700] [Client 2] Waiting for request.
D [03/May/2025:11:53:51 -0700] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients, printing jobs, and dirty files"
D [03/May/2025:11:53:51 -0700] [Client 2] POST / HTTP/1.1
D [03/May/2025:11:53:51 -0700] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Printing jobs and dirty files"
D [03/May/2025:11:53:51 -0700] [Client 2] Read: status=200, state=6
D [03/May/2025:11:53:51 -0700] [Client 2] No authentication data provided.
D [03/May/2025:11:53:51 -0700] [Client 2] 2.0 CUPS-Get-Printers 219
D [03/May/2025:11:53:51 -0700] CUPS-Get-Printers
D [03/May/2025:11:53:51 -0700] [Client 2] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost.
D [03/May/2025:11:53:51 -0700] [Client 2] Content-Length: 2840
D [03/May/2025:11:53:51 -0700] [Client 2] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [03/May/2025:11:53:51 -0700] [Client 2] con->http=0x5f10cab6ca40
D [03/May/2025:11:53:51 -0700] [Client 2] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=2840, response=0x5f10cab5f6a0(IPP_STATE_DATA), pipe_pid=0, file=-1
D [03/May/2025:11:53:51 -0700] [Client 2] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [03/May/2025:11:53:51 -0700] [Client 2] bytes=0, http_state=0, data_remaining=2840
D [03/May/2025:11:53:51 -0700] [Client 2] Flushing write buffer.
D [03/May/2025:11:53:51 -0700] [Client 2] New state is HTTP_STATE_WAITING
D [03/May/2025:11:53:51 -0700] [Client 2] Waiting for request.
D [03/May/2025:11:53:51 -0700] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients, printing jobs, and dirty files"
D [03/May/2025:11:53:51 -0700] [Job 142] cfFilterChain: texttopdf completed with status 0.
D [03/May/2025:11:53:51 -0700] [Job 142] cfFilterPDFToPDF: Processing PDF input with QPDF: Page-ranges, page-set, number-up, booklet, size adjustment, ...
D [03/May/2025:11:53:51 -0700] [Job 142] cfFilterPDFToPDF: \"print-scaling\" IPP attribute: auto
D [03/May/2025:11:53:51 -0700] [Job 142] cfFilterPDFToPDF: Print scaling mode: Do not scale, center, crop if needed
D [03/May/2025:11:53:51 -0700] [Job 142] cfFilterPDFToPDF: After Cropping: 612.000000 792.000000 612.000000 792.000000
D [03/May/2025:11:53:51 -0700] [Job 142] cfFilterChain: texttopdf (PID 5307) exited with no errors.
D [03/May/2025:11:53:51 -0700] cupsdMarkDirty(---J-)
D [03/May/2025:11:53:51 -0700] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [03/May/2025:11:53:51 -0700] [Job 142] Set job-printer-state-message to "cfFilterChain: texttopdf (PID 5307) exited with no errors.", current level=INFO
D [03/May/2025:11:53:51 -0700] Discarding unused job-progress event...
D [03/May/2025:11:53:51 -0700] cupsdMarkDirty(----S)
D [03/May/2025:11:53:51 -0700] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [03/May/2025:11:53:51 -0700] [Notifier] state=3
D [03/May/2025:11:53:51 -0700] [Notifier] PrinterStateChanged
D [03/May/2025:11:53:51 -0700] [Job 142] cfFilterChain: pdftopdf completed with status 0.
D [03/May/2025:11:53:51 -0700] [Job 142] cfFilterGhostscript: Input format: PDF
D [03/May/2025:11:53:51 -0700] [Job 142] Color space requested: Default
D [03/May/2025:11:53:51 -0700] [Job 142] Final output format: CUPS Raster
D [03/May/2025:11:53:51 -0700] [Job 142] Format of the input document: text/plain
D [03/May/2025:11:53:51 -0700] [Job 142] Document\'s input format does not provide absolute size dimensions for each page, falling back to US Letter if no output page size is provided.
D [03/May/2025:11:53:51 -0700] [Job 142] Print rendering intent = auto
D [03/May/2025:11:53:51 -0700] [Job 142] Color Manager: Calibration Mode/Off
D [03/May/2025:11:53:51 -0700] [Job 142] Calling FindDeviceById(cups-Canon_LBP622C_623C_UFR_II)
D [03/May/2025:11:53:51 -0700] [Job 142] cfFilterChain: pdftopdf (PID 5308) exited with no errors.
D [03/May/2025:11:53:51 -0700] cupsdMarkDirty(---J-)
D [03/May/2025:11:53:51 -0700] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [03/May/2025:11:53:51 -0700] [Job 142] Set job-printer-state-message to "cfFilterChain: pdftopdf (PID 5308) exited with no errors.", current level=INFO
D [03/May/2025:11:53:51 -0700] Discarding unused job-progress event...
D [03/May/2025:11:53:51 -0700] cupsdMarkDirty(----S)
D [03/May/2025:11:53:51 -0700] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [03/May/2025:11:53:51 -0700] [Job 142] Found device /org/freedesktop/ColorManager/devices/cups_Canon_LBP622C_623C_UFR_II
D [03/May/2025:11:53:51 -0700] [Job 142] Calling org.freedesktop.ColorManager.Device.Get(ProfilingInhibitors)
D [03/May/2025:11:53:51 -0700] [Notifier] state=3
D [03/May/2025:11:53:51 -0700] [Notifier] PrinterStateChanged
D [03/May/2025:11:53:51 -0700] [Job 142] Calling FindDeviceById(cups-Canon_LBP622C_623C_UFR_II)
D [03/May/2025:11:53:51 -0700] [Job 142] Found device /org/freedesktop/ColorManager/devices/cups_Canon_LBP622C_623C_UFR_II
D [03/May/2025:11:53:51 -0700] [Job 142] Calling GetProfileForQualifiers(.Auto.600...)
D [03/May/2025:11:53:51 -0700] [Job 142] Found profile /org/freedesktop/ColorManager/profiles/Canon_LBP622C_623C_UFR_II_RGB__
D [03/May/2025:11:53:51 -0700] [Job 142] Calling org.freedesktop.ColorManager.Profile.Get(Filename)
D [03/May/2025:11:53:51 -0700] [Job 142] Failed to get profile filename for cups-Canon_LBP622C_623C_UFR_II
D [03/May/2025:11:53:51 -0700] [Job 142] Color Manager: ICC Profile: 
D [03/May/2025:11:53:51 -0700] [Job 142] cfFilterGhostscript: Ghostscript using Any-Part-of-Pixel method to fill paths.
D [03/May/2025:11:53:51 -0700] [Job 142] cfFilterGhostscript: Ghostscript command line: gs -dQUIET -dSAFER -dNOPAUSE -dBATCH -dNOINTERPOLATE -dNOMEDIAATTRS -dUsePDFX3Profile -sstdout=%stderr -sOutputFile=%stdout -sDEVICE=cups -sMediaType=Auto -r600x600 -dDEVICEWIDTHPOINTS=612 -dDEVICEHEIGHTPOINTS=792 -dcupsBitsPerColor=8 -dcupsColorOrder=0 -dcupsColorSpace=1 -scupsRenderingIntent=auto -scupsPageSizeName=Letter -dcupsManualCopies -I/usr/share/cups/fonts -c \'<</.HWMargins[14.173228 14.173228 14.173218 14.173218] /Margins[0 0]>>setpagedevice\' -f -_
D [03/May/2025:11:53:51 -0700] [Job 142] cfFilterGhostscript: Started Ghostscript (PID 5310)
D [03/May/2025:11:53:51 -0700] [Job 142] cfFilterGhostscript: Started logging (PID 5311)
D [03/May/2025:11:53:51 -0700] [Job 142] cfFilterGhostscript: Start rendering...
D [03/May/2025:11:53:51 -0700] cupsdMarkDirty(---J-)
D [03/May/2025:11:53:51 -0700] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [03/May/2025:11:53:51 -0700] [Job 142] Set job-printer-state-message to "cfFilterGhostscript: Start rendering...", current level=INFO
D [03/May/2025:11:53:51 -0700] [Job 142] cfFilterGhostscript: Processing page 1...
D [03/May/2025:11:53:51 -0700] cupsdMarkDirty(---J-)
D [03/May/2025:11:53:51 -0700] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [03/May/2025:11:53:51 -0700] [Job 142] Set job-printer-state-message to "cfFilterGhostscript: Processing page 1...", current level=INFO
D [03/May/2025:11:53:51 -0700] Discarding unused job-progress event...
D [03/May/2025:11:53:51 -0700] cupsdMarkDirty(----S)
D [03/May/2025:11:53:51 -0700] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [03/May/2025:11:53:51 -0700] [Notifier] state=3
D [03/May/2025:11:53:51 -0700] [Notifier] PrinterStateChanged
D [03/May/2025:11:53:51 -0700] [Job 142] cfFilterGhostscript: Input data feed completed
D [03/May/2025:11:53:51 -0700] [Job 142] PID 5304 (/usr/lib/cups/filter/rastertoufr2) did not catch or ignore signal 13.
E [03/May/2025:11:53:51 -0700] [Job 142] src = libcanon_pdlwrapper.c, line = 514, err = 0¥nINFO: cfFilterGhostscript: Processing page 2...
D [03/May/2025:11:53:51 -0700] cupsdMarkDirty(---J-)
D [03/May/2025:11:53:51 -0700] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [03/May/2025:11:53:51 -0700] [Job 142] Set job-printer-state-message to "src = libcanon_pdlwrapper.c, line = 514, err = 0¥nINFO: cfFilterGhostscript: Processing page 2...", current level=ERROR
D [03/May/2025:11:53:51 -0700] Discarding unused job-progress event...
D [03/May/2025:11:53:51 -0700] cupsdMarkDirty(----S)
D [03/May/2025:11:53:51 -0700] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [03/May/2025:11:53:51 -0700] [Notifier] state=3
D [03/May/2025:11:53:51 -0700] [Notifier] PrinterStateChanged
D [03/May/2025:11:53:51 -0700] [Job 142] cfFilterGhostscript: Rendering completed
D [03/May/2025:11:53:51 -0700] Discarding unused job-progress event...
D [03/May/2025:11:53:51 -0700] cupsdMarkDirty(----S)
D [03/May/2025:11:53:51 -0700] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [03/May/2025:11:53:51 -0700] [Notifier] state=3
D [03/May/2025:11:53:51 -0700] [Notifier] PrinterStateChanged
D [03/May/2025:11:53:51 -0700] [Job 142] cfFilterGhostscript: Ghostscript (PID 5310) exited with no errors.
D [03/May/2025:11:53:51 -0700] [Job 142] cfFilterGhostscript: Logging (PID 5311) exited with no errors.
D [03/May/2025:11:53:51 -0700] [Job 142] cfFilterChain: ghostscript completed with status 0.
D [03/May/2025:11:53:51 -0700] [Job 142] cfFilterChain: ghostscript (PID 5309) exited with no errors.
D [03/May/2025:11:53:51 -0700] Discarding unused job-progress event...
D [03/May/2025:11:53:51 -0700] cupsdMarkDirty(----S)
D [03/May/2025:11:53:51 -0700] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [03/May/2025:11:53:51 -0700] [Notifier] state=3
D [03/May/2025:11:53:51 -0700] [Notifier] PrinterStateChanged
D [03/May/2025:11:53:51 -0700] [Job 142] PID 5303 (/usr/lib/cups/filter/universal) exited with no errors.
D [03/May/2025:11:53:51 -0700] [Job 142] ATTR: marker-colors=#000000,#00FFFF,#FF00FF,#FFFF00
D [03/May/2025:11:53:51 -0700] cupsdMarkDirty(P----)
D [03/May/2025:11:53:51 -0700] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [03/May/2025:11:53:51 -0700] [Job 142] ATTR: marker-names=\'\"Canon Cartridge 054 Black Toner\"\',\'\"Canon Cartridge 054 Cyan Toner\"\',\'\"Canon Cartridge 054 Magenta Toner\"\',\'\"Canon Cartridge 054 Yellow Toner\"\'
D [03/May/2025:11:53:51 -0700] cupsdMarkDirty(P----)
D [03/May/2025:11:53:51 -0700] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [03/May/2025:11:53:51 -0700] [Job 142] ATTR: marker-types=toner-cartridge,toner-cartridge,toner-cartridge,toner-cartridge
D [03/May/2025:11:53:51 -0700] cupsdMarkDirty(P----)
D [03/May/2025:11:53:51 -0700] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [03/May/2025:11:53:51 -0700] [Job 142] ATTR: marker-levels=65,100,100,89
D [03/May/2025:11:53:51 -0700] cupsdMarkDirty(P----)
D [03/May/2025:11:53:51 -0700] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [03/May/2025:11:53:51 -0700] [Job 142] new_supply_state=0, change_state=ffff
D [03/May/2025:11:53:51 -0700] [Job 142] STATE: -developer-low-report
D [03/May/2025:11:53:51 -0700] [Job 142] STATE: -developer-empty-warning
D [03/May/2025:11:53:51 -0700] [Job 142] STATE: -marker-supply-low-report
D [03/May/2025:11:53:51 -0700] [Job 142] STATE: -marker-supply-empty-warning
D [03/May/2025:11:53:51 -0700] [Job 142] STATE: -opc-near-eol-report
D [03/May/2025:11:53:51 -0700] [Job 142] STATE: -opc-life-over-warning
D [03/May/2025:11:53:51 -0700] [Job 142] STATE: -toner-low-report
D [03/May/2025:11:53:51 -0700] [Job 142] STATE: -toner-empty-warning
D [03/May/2025:11:53:51 -0700] [Job 142] STATE: -waste-receptacle-almost-full-report
D [03/May/2025:11:53:51 -0700] [Job 142] STATE: -waste-receptacle-full-warning
D [03/May/2025:11:53:51 -0700] [Job 142] STATE: -cleaner-life-almost-over-report
D [03/May/2025:11:53:51 -0700] [Job 142] STATE: -cleaner-life-over-warning
D [03/May/2025:11:53:51 -0700] cupsdMarkDirty(----S)
D [03/May/2025:11:53:51 -0700] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [03/May/2025:11:53:51 -0700] [Notifier] state=3
D [03/May/2025:11:53:51 -0700] [Notifier] PrinterStateChanged
D [03/May/2025:11:53:51 -0700] [Job 142] new_state=0, change_state=ffff
D [03/May/2025:11:53:51 -0700] [Job 142] STATE: -media-empty-warning
D [03/May/2025:11:53:51 -0700] [Job 142] STATE: -door-open-report
D [03/May/2025:11:53:51 -0700] [Job 142] STATE: -media-jam-warning
D [03/May/2025:11:53:51 -0700] [Job 142] STATE: -input-tray-missing-warning
D [03/May/2025:11:53:51 -0700] [Job 142] STATE: -output-tray-missing-warning
D [03/May/2025:11:53:51 -0700] [Job 142] STATE: -marker-supply-missing-warning
D [03/May/2025:11:53:51 -0700] [Job 142] STATE: -output-area-almost-full-report
D [03/May/2025:11:53:51 -0700] [Job 142] STATE: -output-area-full-warning
D [03/May/2025:11:53:51 -0700] [Job 142] backendWaitLoop(snmp_fd=5, addr=0x62f29e182fe8, side_cb=0x62f291499920)
D [03/May/2025:11:53:51 -0700] [Job 142] PID 5305 (/usr/lib/cups/backend/socket) exited with no errors.
D [03/May/2025:11:53:51 -0700] [Job 142] time-at-completed=1746298431
D [03/May/2025:11:53:51 -0700] cupsdMarkDirty(----S)
D [03/May/2025:11:53:51 -0700] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
I [03/May/2025:11:53:51 -0700] [Job 142] Job completed.
D [03/May/2025:11:53:51 -0700] Expiring subscriptions...
D [03/May/2025:11:53:51 -0700] cupsdMarkDirty(---J-)
D [03/May/2025:11:53:51 -0700] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [03/May/2025:11:53:51 -0700] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [03/May/2025:11:53:51 -0700] cupsdMarkDirty(----S)
D [03/May/2025:11:53:51 -0700] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [03/May/2025:11:53:51 -0700] [Notifier] state=3
D [03/May/2025:11:53:51 -0700] [Notifier] JobCompleted
D [03/May/2025:11:53:51 -0700] [Notifier] state=3
D [03/May/2025:11:53:51 -0700] [Notifier] PrinterStateChanged
D [03/May/2025:11:53:52 -0700] [Client 2] POST / HTTP/1.1
D [03/May/2025:11:53:52 -0700] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Printing jobs and dirty files"
D [03/May/2025:11:53:52 -0700] [Client 2] Read: status=200, state=6
D [03/May/2025:11:53:52 -0700] [Client 2] No authentication data provided.
D [03/May/2025:11:53:52 -0700] [Client 2] 2.0 CUPS-Get-Default 220
D [03/May/2025:11:53:52 -0700] CUPS-Get-Default
D [03/May/2025:11:53:52 -0700] [Client 2] Returning IPP successful-ok for CUPS-Get-Default (no URI) from localhost.
D [03/May/2025:11:53:52 -0700] [Client 2] Content-Length: 12097
D [03/May/2025:11:53:52 -0700] [Client 2] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [03/May/2025:11:53:52 -0700] Expiring subscriptions...
D [03/May/2025:11:53:52 -0700] [Job 142] Unloading...
D [03/May/2025:11:53:52 -0700] [Client 2] con->http=0x5f10cab6ca40
D [03/May/2025:11:53:52 -0700] [Client 2] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=12097, response=0x5f10cab5f440(IPP_STATE_DATA), pipe_pid=0, file=-1
D [03/May/2025:11:53:52 -0700] [Client 2] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [03/May/2025:11:53:52 -0700] [Client 2] bytes=0, http_state=0, data_remaining=12097
D [03/May/2025:11:53:52 -0700] [Client 2] Flushing write buffer.
D [03/May/2025:11:53:52 -0700] [Client 2] New state is HTTP_STATE_WAITING
D [03/May/2025:11:53:52 -0700] [Client 2] Waiting for request.
D [03/May/2025:11:53:52 -0700] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [03/May/2025:11:53:52 -0700] [Client 2] POST / HTTP/1.1
D [03/May/2025:11:53:52 -0700] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [03/May/2025:11:53:52 -0700] [Client 2] Read: status=200, state=6
D [03/May/2025:11:53:52 -0700] [Client 2] No authentication data provided.
D [03/May/2025:11:53:52 -0700] [Client 2] 2.0 CUPS-Get-Printers 221
D [03/May/2025:11:53:52 -0700] CUPS-Get-Printers
D [03/May/2025:11:53:52 -0700] [Client 2] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost.
D [03/May/2025:11:53:52 -0700] [Client 2] Content-Length: 2840
D [03/May/2025:11:53:52 -0700] [Client 2] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [03/May/2025:11:53:52 -0700] [Client 2] con->http=0x5f10cab6ca40
D [03/May/2025:11:53:52 -0700] [Client 2] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=2840, response=0x5f10cab3a470(IPP_STATE_DATA), pipe_pid=0, file=-1
D [03/May/2025:11:53:52 -0700] [Client 2] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [03/May/2025:11:53:52 -0700] [Client 2] bytes=0, http_state=0, data_remaining=2840
D [03/May/2025:11:53:52 -0700] [Client 2] Flushing write buffer.
D [03/May/2025:11:53:52 -0700] [Client 2] New state is HTTP_STATE_WAITING
D [03/May/2025:11:53:52 -0700] [Client 2] Waiting for request.
D [03/May/2025:11:53:52 -0700] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [03/May/2025:11:53:53 -0700] Expiring subscriptions...
D [03/May/2025:11:53:53 -0700] [Client 2] POST / HTTP/1.1
D [03/May/2025:11:53:53 -0700] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [03/May/2025:11:53:53 -0700] [Client 2] Read: status=200, state=6
D [03/May/2025:11:53:53 -0700] [Client 2] No authentication data provided.
D [03/May/2025:11:53:53 -0700] [Client 2] 2.0 CUPS-Get-Default 222
D [03/May/2025:11:53:53 -0700] CUPS-Get-Default
D [03/May/2025:11:53:53 -0700] [Client 2] Returning IPP successful-ok for CUPS-Get-Default (no URI) from localhost.
D [03/May/2025:11:53:53 -0700] [Client 2] Content-Length: 12097
D [03/May/2025:11:53:53 -0700] [Client 2] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [03/May/2025:11:53:53 -0700] [Client 2] con->http=0x5f10cab6ca40
D [03/May/2025:11:53:53 -0700] [Client 2] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=12097, response=0x5f10cab3a5a0(IPP_STATE_DATA), pipe_pid=0, file=-1
D [03/May/2025:11:53:53 -0700] [Client 2] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [03/May/2025:11:53:53 -0700] [Client 2] bytes=0, http_state=0, data_remaining=12097
D [03/May/2025:11:53:53 -0700] [Client 2] Flushing write buffer.
D [03/May/2025:11:53:53 -0700] [Client 2] New state is HTTP_STATE_WAITING
D [03/May/2025:11:53:53 -0700] [Client 2] Waiting for request.
D [03/May/2025:11:53:53 -0700] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [03/May/2025:11:53:53 -0700] [Client 2] POST / HTTP/1.1
D [03/May/2025:11:53:53 -0700] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [03/May/2025:11:53:53 -0700] [Client 2] Read: status=200, state=6
D [03/May/2025:11:53:53 -0700] [Client 2] No authentication data provided.
D [03/May/2025:11:53:53 -0700] [Client 2] 2.0 CUPS-Get-Printers 223
D [03/May/2025:11:53:53 -0700] CUPS-Get-Printers
D [03/May/2025:11:53:53 -0700] [Client 2] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost.
D [03/May/2025:11:53:53 -0700] [Client 2] Content-Length: 2840
D [03/May/2025:11:53:53 -0700] [Client 2] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [03/May/2025:11:53:53 -0700] [Client 2] con->http=0x5f10cab6ca40
D [03/May/2025:11:53:53 -0700] [Client 2] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=2840, response=0x5f10cab4fee0(IPP_STATE_DATA), pipe_pid=0, file=-1
D [03/May/2025:11:53:53 -0700] [Client 2] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [03/May/2025:11:53:53 -0700] [Client 2] bytes=0, http_state=0, data_remaining=2840
D [03/May/2025:11:53:53 -0700] [Client 2] Flushing write buffer.
D [03/May/2025:11:53:53 -0700] [Client 2] New state is HTTP_STATE_WAITING
D [03/May/2025:11:53:53 -0700] [Client 2] Waiting for request.
D [03/May/2025:11:53:53 -0700] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [03/May/2025:11:53:54 -0700] Expiring subscriptions...
D [03/May/2025:11:53:54 -0700] [Client 2] POST / HTTP/1.1
D [03/May/2025:11:53:54 -0700] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [03/May/2025:11:53:54 -0700] [Client 2] Read: status=200, state=6
D [03/May/2025:11:53:54 -0700] [Client 2] No authentication data provided.
D [03/May/2025:11:53:54 -0700] [Client 2] 2.0 CUPS-Get-Default 224
D [03/May/2025:11:53:54 -0700] CUPS-Get-Default
D [03/May/2025:11:53:54 -0700] [Client 2] Returning IPP successful-ok for CUPS-Get-Default (no URI) from localhost.
D [03/May/2025:11:53:54 -0700] [Client 2] Content-Length: 12097
D [03/May/2025:11:53:54 -0700] [Client 2] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [03/May/2025:11:53:54 -0700] [Client 2] con->http=0x5f10cab6ca40
D [03/May/2025:11:53:54 -0700] [Client 2] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=12097, response=0x5f10cab37380(IPP_STATE_DATA), pipe_pid=0, file=-1
D [03/May/2025:11:53:54 -0700] [Client 2] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [03/May/2025:11:53:54 -0700] [Client 2] bytes=0, http_state=0, data_remaining=12097
D [03/May/2025:11:53:54 -0700] [Client 2] Flushing write buffer.
D [03/May/2025:11:53:54 -0700] [Client 2] New state is HTTP_STATE_WAITING
D [03/May/2025:11:53:54 -0700] [Client 2] Waiting for request.
D [03/May/2025:11:53:54 -0700] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [03/May/2025:11:53:54 -0700] [Client 2] POST / HTTP/1.1
D [03/May/2025:11:53:54 -0700] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [03/May/2025:11:53:54 -0700] [Client 2] Read: status=200, state=6
D [03/May/2025:11:53:54 -0700] [Client 2] No authentication data provided.
D [03/May/2025:11:53:54 -0700] [Client 2] 2.0 CUPS-Get-Printers 225
D [03/May/2025:11:53:54 -0700] CUPS-Get-Printers
D [03/May/2025:11:53:54 -0700] [Client 2] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost.
D [03/May/2025:11:53:54 -0700] [Client 2] Content-Length: 2840
D [03/May/2025:11:53:54 -0700] [Client 2] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [03/May/2025:11:53:54 -0700] [Client 2] con->http=0x5f10cab6ca40
D [03/May/2025:11:53:54 -0700] [Client 2] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=2840, response=0x5f10cab3a470(IPP_STATE_DATA), pipe_pid=0, file=-1
D [03/May/2025:11:53:54 -0700] [Client 2] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [03/May/2025:11:53:54 -0700] [Client 2] bytes=0, http_state=0, data_remaining=2840
D [03/May/2025:11:53:54 -0700] [Client 2] Flushing write buffer.
D [03/May/2025:11:53:54 -0700] [Client 2] New state is HTTP_STATE_WAITING
D [03/May/2025:11:53:54 -0700] [Client 2] Waiting for request.
D [03/May/2025:11:53:54 -0700] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [03/May/2025:11:53:55 -0700] Expiring subscriptions...
D [03/May/2025:11:53:55 -0700] [Client 2] POST / HTTP/1.1
D [03/May/2025:11:53:55 -0700] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [03/May/2025:11:53:55 -0700] [Client 2] Read: status=200, state=6
D [03/May/2025:11:53:55 -0700] [Client 2] No authentication data provided.
D [03/May/2025:11:53:55 -0700] [Client 2] 2.0 Get-Notifications 226
D [03/May/2025:11:53:55 -0700] Get-Notifications /printers/
D [03/May/2025:11:53:55 -0700] cupsdIsAuthorized: requesting-user-name="grahams"
D [03/May/2025:11:53:55 -0700] [Client 2] Returning IPP successful-ok for Get-Notifications (/printers/) from localhost.
D [03/May/2025:11:53:55 -0700] [Client 2] Content-Length: 4319
D [03/May/2025:11:53:55 -0700] [Client 2] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [03/May/2025:11:53:55 -0700] [Client 2] con->http=0x5f10cab6ca40
D [03/May/2025:11:53:55 -0700] [Client 2] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=4319, response=0x5f10cab5eec0(IPP_STATE_DATA), pipe_pid=0, file=-1
D [03/May/2025:11:53:55 -0700] [Client 2] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [03/May/2025:11:53:55 -0700] [Client 2] bytes=0, http_state=0, data_remaining=4319
D [03/May/2025:11:53:55 -0700] [Client 2] Flushing write buffer.
D [03/May/2025:11:53:55 -0700] [Client 2] New state is HTTP_STATE_WAITING
D [03/May/2025:11:53:55 -0700] [Client 2] Waiting for request.
D [03/May/2025:11:53:55 -0700] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [03/May/2025:11:53:55 -0700] [Client 2] POST / HTTP/1.1
D [03/May/2025:11:53:55 -0700] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [03/May/2025:11:53:55 -0700] [Client 2] Read: status=200, state=6
D [03/May/2025:11:53:55 -0700] [Client 2] No authentication data provided.
D [03/May/2025:11:53:55 -0700] [Client 2] 2.0 CUPS-Get-Default 227
D [03/May/2025:11:53:55 -0700] CUPS-Get-Default
D [03/May/2025:11:53:55 -0700] [Client 2] Returning IPP successful-ok for CUPS-Get-Default (no URI) from localhost.
D [03/May/2025:11:53:55 -0700] [Client 2] Content-Length: 12097
D [03/May/2025:11:53:55 -0700] [Client 2] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [03/May/2025:11:53:55 -0700] [Client 2] con->http=0x5f10cab6ca40
D [03/May/2025:11:53:55 -0700] [Client 2] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=12097, response=0x5f10cab3a470(IPP_STATE_DATA), pipe_pid=0, file=-1
D [03/May/2025:11:53:55 -0700] [Client 2] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [03/May/2025:11:53:55 -0700] [Client 2] bytes=0, http_state=0, data_remaining=12097
D [03/May/2025:11:53:55 -0700] [Client 2] Flushing write buffer.
D [03/May/2025:11:53:55 -0700] [Client 2] New state is HTTP_STATE_WAITING
D [03/May/2025:11:53:55 -0700] [Client 2] Waiting for request.
D [03/May/2025:11:53:55 -0700] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [03/May/2025:11:53:55 -0700] [Client 2] POST / HTTP/1.1
D [03/May/2025:11:53:55 -0700] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [03/May/2025:11:53:55 -0700] [Client 2] Read: status=200, state=6
D [03/May/2025:11:53:55 -0700] [Client 2] No authentication data provided.
D [03/May/2025:11:53:55 -0700] [Client 2] 2.0 CUPS-Get-Printers 228
D [03/May/2025:11:53:55 -0700] CUPS-Get-Printers
D [03/May/2025:11:53:55 -0700] [Client 2] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost.
D [03/May/2025:11:53:55 -0700] [Client 2] Content-Length: 2840
D [03/May/2025:11:53:55 -0700] [Client 2] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [03/May/2025:11:53:55 -0700] [Client 2] con->http=0x5f10cab6ca40
D [03/May/2025:11:53:55 -0700] [Client 2] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=2840, response=0x5f10cab4fee0(IPP_STATE_DATA), pipe_pid=0, file=-1
D [03/May/2025:11:53:55 -0700] [Client 2] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [03/May/2025:11:53:55 -0700] [Client 2] bytes=0, http_state=0, data_remaining=2840
D [03/May/2025:11:53:55 -0700] [Client 2] Flushing write buffer.
D [03/May/2025:11:53:55 -0700] [Client 2] New state is HTTP_STATE_WAITING
D [03/May/2025:11:53:55 -0700] [Client 2] Waiting for request.
D [03/May/2025:11:53:55 -0700] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [03/May/2025:11:53:56 -0700] Expiring subscriptions...
D [03/May/2025:11:53:56 -0700] [Client 2] POST / HTTP/1.1
D [03/May/2025:11:53:56 -0700] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [03/May/2025:11:53:56 -0700] [Client 2] Read: status=200, state=6
D [03/May/2025:11:53:56 -0700] [Client 2] No authentication data provided.
D [03/May/2025:11:53:56 -0700] [Client 2] 2.0 CUPS-Get-Default 229
D [03/May/2025:11:53:56 -0700] CUPS-Get-Default
D [03/May/2025:11:53:56 -0700] [Client 2] Returning IPP successful-ok for CUPS-Get-Default (no URI) from localhost.
D [03/May/2025:11:53:56 -0700] [Client 2] Content-Length: 12097
D [03/May/2025:11:53:56 -0700] [Client 2] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [03/May/2025:11:53:56 -0700] [Client 2] con->http=0x5f10cab6ca40
D [03/May/2025:11:53:56 -0700] [Client 2] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=12097, response=0x5f10cab3a5a0(IPP_STATE_DATA), pipe_pid=0, file=-1
D [03/May/2025:11:53:56 -0700] [Client 2] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [03/May/2025:11:53:56 -0700] [Client 2] bytes=0, http_state=0, data_remaining=12097
D [03/May/2025:11:53:56 -0700] [Client 2] Flushing write buffer.
D [03/May/2025:11:53:56 -0700] [Client 2] New state is HTTP_STATE_WAITING
D [03/May/2025:11:53:56 -0700] [Client 2] Waiting for request.
D [03/May/2025:11:53:56 -0700] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [03/May/2025:11:53:56 -0700] [Client 2] POST / HTTP/1.1
D [03/May/2025:11:53:56 -0700] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [03/May/2025:11:53:56 -0700] [Client 2] Read: status=200, state=6
D [03/May/2025:11:53:56 -0700] [Client 2] No authentication data provided.
D [03/May/2025:11:53:56 -0700] [Client 2] 2.0 CUPS-Get-Printers 230
D [03/May/2025:11:53:56 -0700] CUPS-Get-Printers
D [03/May/2025:11:53:56 -0700] [Client 2] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost.
D [03/May/2025:11:53:56 -0700] [Client 2] Content-Length: 2840
D [03/May/2025:11:53:56 -0700] [Client 2] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [03/May/2025:11:53:56 -0700] [Client 2] con->http=0x5f10cab6ca40
D [03/May/2025:11:53:56 -0700] [Client 2] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=2840, response=0x5f10cab64940(IPP_STATE_DATA), pipe_pid=0, file=-1
D [03/May/2025:11:53:56 -0700] [Client 2] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [03/May/2025:11:53:56 -0700] [Client 2] bytes=0, http_state=0, data_remaining=2840
D [03/May/2025:11:53:56 -0700] [Client 2] Flushing write buffer.
D [03/May/2025:11:53:56 -0700] [Client 2] New state is HTTP_STATE_WAITING
D [03/May/2025:11:53:56 -0700] [Client 2] Waiting for request.
D [03/May/2025:11:53:56 -0700] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [03/May/2025:11:53:57 -0700] Expiring subscriptions...
D [03/May/2025:11:53:57 -0700] [Client 2] POST / HTTP/1.1
D [03/May/2025:11:53:57 -0700] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [03/May/2025:11:53:57 -0700] [Client 2] Read: status=200, state=6
D [03/May/2025:11:53:57 -0700] [Client 2] No authentication data provided.
D [03/May/2025:11:53:57 -0700] [Client 2] 2.0 CUPS-Get-Default 231
D [03/May/2025:11:53:57 -0700] CUPS-Get-Default
D [03/May/2025:11:53:57 -0700] [Client 2] Returning IPP successful-ok for CUPS-Get-Default (no URI) from localhost.
D [03/May/2025:11:53:57 -0700] [Client 2] Content-Length: 12097
D [03/May/2025:11:53:57 -0700] [Client 2] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [03/May/2025:11:53:57 -0700] [Client 2] con->http=0x5f10cab6ca40
D [03/May/2025:11:53:57 -0700] [Client 2] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=12097, response=0x5f10cab37380(IPP_STATE_DATA), pipe_pid=0, file=-1
D [03/May/2025:11:53:57 -0700] [Client 2] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [03/May/2025:11:53:57 -0700] [Client 2] bytes=0, http_state=0, data_remaining=12097
D [03/May/2025:11:53:57 -0700] [Client 2] Flushing write buffer.
D [03/May/2025:11:53:57 -0700] [Client 2] New state is HTTP_STATE_WAITING
D [03/May/2025:11:53:57 -0700] [Client 2] Waiting for request.
D [03/May/2025:11:53:57 -0700] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [03/May/2025:11:53:57 -0700] [Client 2] POST / HTTP/1.1
D [03/May/2025:11:53:57 -0700] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [03/May/2025:11:53:57 -0700] [Client 2] Read: status=200, state=6
D [03/May/2025:11:53:57 -0700] [Client 2] No authentication data provided.
D [03/May/2025:11:53:57 -0700] [Client 2] 2.0 CUPS-Get-Printers 232
D [03/May/2025:11:53:57 -0700] CUPS-Get-Printers
D [03/May/2025:11:53:57 -0700] [Client 2] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost.
D [03/May/2025:11:53:57 -0700] [Client 2] Content-Length: 2840
D [03/May/2025:11:53:57 -0700] [Client 2] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [03/May/2025:11:53:57 -0700] [Client 2] con->http=0x5f10cab6ca40
D [03/May/2025:11:53:57 -0700] [Client 2] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=2840, response=0x5f10cab4fee0(IPP_STATE_DATA), pipe_pid=0, file=-1
D [03/May/2025:11:53:57 -0700] [Client 2] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [03/May/2025:11:53:57 -0700] [Client 2] bytes=0, http_state=0, data_remaining=2840
D [03/May/2025:11:53:57 -0700] [Client 2] Flushing write buffer.
D [03/May/2025:11:53:57 -0700] [Client 2] New state is HTTP_STATE_WAITING
D [03/May/2025:11:53:57 -0700] [Client 2] Waiting for request.
D [03/May/2025:11:53:57 -0700] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [03/May/2025:11:53:58 -0700] Expiring subscriptions...
D [03/May/2025:11:53:58 -0700] [Client 2] POST / HTTP/1.1
D [03/May/2025:11:53:58 -0700] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [03/May/2025:11:53:58 -0700] [Client 2] Read: status=200, state=6
D [03/May/2025:11:53:58 -0700] [Client 2] No authentication data provided.
D [03/May/2025:11:53:58 -0700] [Client 2] 2.0 CUPS-Get-Default 233
D [03/May/2025:11:53:58 -0700] CUPS-Get-Default
D [03/May/2025:11:53:58 -0700] [Client 2] Returning IPP successful-ok for CUPS-Get-Default (no URI) from localhost.
D [03/May/2025:11:53:58 -0700] [Client 2] Content-Length: 12097
D [03/May/2025:11:53:58 -0700] [Client 2] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [03/May/2025:11:53:58 -0700] [Client 2] con->http=0x5f10cab6ca40
D [03/May/2025:11:53:58 -0700] [Client 2] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=12097, response=0x5f10cab3a470(IPP_STATE_DATA), pipe_pid=0, file=-1
D [03/May/2025:11:53:58 -0700] [Client 2] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [03/May/2025:11:53:58 -0700] [Client 2] bytes=0, http_state=0, data_remaining=12097
D [03/May/2025:11:53:58 -0700] [Client 2] Flushing write buffer.
D [03/May/2025:11:53:58 -0700] [Client 2] New state is HTTP_STATE_WAITING
D [03/May/2025:11:53:58 -0700] [Client 2] Waiting for request.
D [03/May/2025:11:53:58 -0700] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [03/May/2025:11:53:58 -0700] [Client 2] POST / HTTP/1.1
D [03/May/2025:11:53:58 -0700] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [03/May/2025:11:53:58 -0700] [Client 2] Read: status=200, state=6
D [03/May/2025:11:53:58 -0700] [Client 2] No authentication data provided.
D [03/May/2025:11:53:58 -0700] [Client 2] 2.0 CUPS-Get-Printers 234
D [03/May/2025:11:53:58 -0700] CUPS-Get-Printers
D [03/May/2025:11:53:58 -0700] [Client 2] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost.
D [03/May/2025:11:53:58 -0700] [Client 2] Content-Length: 2840
D [03/May/2025:11:53:58 -0700] [Client 2] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [03/May/2025:11:53:58 -0700] [Client 2] con->http=0x5f10cab6ca40
D [03/May/2025:11:53:58 -0700] [Client 2] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=2840, response=0x5f10cab64940(IPP_STATE_DATA), pipe_pid=0, file=-1
D [03/May/2025:11:53:58 -0700] [Client 2] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [03/May/2025:11:53:58 -0700] [Client 2] bytes=0, http_state=0, data_remaining=2840
D [03/May/2025:11:53:58 -0700] [Client 2] Flushing write buffer.
D [03/May/2025:11:53:58 -0700] [Client 2] New state is HTTP_STATE_WAITING
D [03/May/2025:11:53:58 -0700] [Client 2] Waiting for request.
D [03/May/2025:11:53:58 -0700] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [03/May/2025:11:53:59 -0700] Expiring subscriptions...
D [03/May/2025:11:53:59 -0700] [Client 2] POST / HTTP/1.1
D [03/May/2025:11:53:59 -0700] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [03/May/2025:11:53:59 -0700] [Client 2] Read: status=200, state=6
D [03/May/2025:11:53:59 -0700] [Client 2] No authentication data provided.
D [03/May/2025:11:53:59 -0700] [Client 2] 2.0 CUPS-Get-Default 235
D [03/May/2025:11:53:59 -0700] CUPS-Get-Default
D [03/May/2025:11:53:59 -0700] [Client 2] Returning IPP successful-ok for CUPS-Get-Default (no URI) from localhost.
D [03/May/2025:11:53:59 -0700] [Client 2] Content-Length: 12097
D [03/May/2025:11:53:59 -0700] [Client 2] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [03/May/2025:11:53:59 -0700] [Client 2] con->http=0x5f10cab6ca40
D [03/May/2025:11:53:59 -0700] [Client 2] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=12097, response=0x5f10cab3a5a0(IPP_STATE_DATA), pipe_pid=0, file=-1
D [03/May/2025:11:53:59 -0700] [Client 2] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [03/May/2025:11:53:59 -0700] [Client 2] bytes=0, http_state=0, data_remaining=12097
D [03/May/2025:11:53:59 -0700] [Client 2] Flushing write buffer.
D [03/May/2025:11:53:59 -0700] [Client 2] New state is HTTP_STATE_WAITING
D [03/May/2025:11:53:59 -0700] [Client 2] Waiting for request.
D [03/May/2025:11:53:59 -0700] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [03/May/2025:11:53:59 -0700] [Client 2] POST / HTTP/1.1
D [03/May/2025:11:53:59 -0700] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [03/May/2025:11:53:59 -0700] [Client 2] Read: status=200, state=6
D [03/May/2025:11:53:59 -0700] [Client 2] No authentication data provided.
D [03/May/2025:11:53:59 -0700] [Client 2] 2.0 CUPS-Get-Printers 236
D [03/May/2025:11:53:59 -0700] CUPS-Get-Printers
D [03/May/2025:11:53:59 -0700] [Client 2] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost.
D [03/May/2025:11:53:59 -0700] [Client 2] Content-Length: 2840
D [03/May/2025:11:53:59 -0700] [Client 2] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [03/May/2025:11:53:59 -0700] [Client 2] con->http=0x5f10cab6ca40
D [03/May/2025:11:53:59 -0700] [Client 2] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=2840, response=0x5f10cab4fee0(IPP_STATE_DATA), pipe_pid=0, file=-1
D [03/May/2025:11:53:59 -0700] [Client 2] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [03/May/2025:11:53:59 -0700] [Client 2] bytes=0, http_state=0, data_remaining=2840
D [03/May/2025:11:53:59 -0700] [Client 2] Flushing write buffer.
D [03/May/2025:11:53:59 -0700] [Client 2] New state is HTTP_STATE_WAITING
D [03/May/2025:11:53:59 -0700] [Client 2] Waiting for request.
D [03/May/2025:11:53:59 -0700] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [03/May/2025:11:54:00 -0700] Expiring subscriptions...
D [03/May/2025:11:54:00 -0700] [Client 2] POST / HTTP/1.1
D [03/May/2025:11:54:00 -0700] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [03/May/2025:11:54:00 -0700] [Client 2] Read: status=200, state=6
D [03/May/2025:11:54:00 -0700] [Client 2] No authentication data provided.
D [03/May/2025:11:54:00 -0700] [Client 2] Read: status=100, state=6
D [03/May/2025:11:54:00 -0700] [Client 2] Read: status=100, state=6
D [03/May/2025:11:54:00 -0700] [Client 2] Read: status=100, state=6
D [03/May/2025:11:54:00 -0700] [Client 2] 2.0 CUPS-Get-Default 237
D [03/May/2025:11:54:00 -0700] CUPS-Get-Default
D [03/May/2025:11:54:00 -0700] [Client 2] Returning IPP successful-ok for CUPS-Get-Default (no URI) from localhost.
D [03/May/2025:11:54:00 -0700] [Client 2] Content-Length: 12097
D [03/May/2025:11:54:00 -0700] [Client 2] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [03/May/2025:11:54:00 -0700] [Client 2] con->http=0x5f10cab6ca40
D [03/May/2025:11:54:00 -0700] [Client 2] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=12097, response=0x5f10cab37380(IPP_STATE_DATA), pipe_pid=0, file=-1
D [03/May/2025:11:54:00 -0700] [Client 2] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [03/May/2025:11:54:00 -0700] [Client 2] bytes=0, http_state=0, data_remaining=12097
D [03/May/2025:11:54:00 -0700] [Client 2] Flushing write buffer.
D [03/May/2025:11:54:00 -0700] [Client 2] New state is HTTP_STATE_WAITING
D [03/May/2025:11:54:00 -0700] [Client 2] Waiting for request.
D [03/May/2025:11:54:00 -0700] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [03/May/2025:11:54:00 -0700] [Client 2] POST / HTTP/1.1
D [03/May/2025:11:54:00 -0700] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [03/May/2025:11:54:00 -0700] [Client 2] Read: status=200, state=6
D [03/May/2025:11:54:00 -0700] [Client 2] No authentication data provided.
D [03/May/2025:11:54:00 -0700] [Client 2] 2.0 CUPS-Get-Printers 238
D [03/May/2025:11:54:00 -0700] CUPS-Get-Printers
D [03/May/2025:11:54:00 -0700] [Client 2] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost.
D [03/May/2025:11:54:00 -0700] [Client 2] Content-Length: 2840
D [03/May/2025:11:54:00 -0700] [Client 2] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [03/May/2025:11:54:00 -0700] [Client 2] con->http=0x5f10cab6ca40
D [03/May/2025:11:54:00 -0700] [Client 2] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=2840, response=0x5f10cab64940(IPP_STATE_DATA), pipe_pid=0, file=-1
D [03/May/2025:11:54:00 -0700] [Client 2] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [03/May/2025:11:54:00 -0700] [Client 2] bytes=0, http_state=0, data_remaining=2840
D [03/May/2025:11:54:00 -0700] [Client 2] Flushing write buffer.
D [03/May/2025:11:54:00 -0700] [Client 2] New state is HTTP_STATE_WAITING
D [03/May/2025:11:54:00 -0700] [Client 2] Waiting for request.
D [03/May/2025:11:54:00 -0700] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [03/May/2025:11:54:01 -0700] Expiring subscriptions...
D [03/May/2025:11:54:01 -0700] [Client 2] POST / HTTP/1.1
D [03/May/2025:11:54:01 -0700] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [03/May/2025:11:54:01 -0700] [Client 2] Read: status=200, state=6
D [03/May/2025:11:54:01 -0700] [Client 2] No authentication data provided.
D [03/May/2025:11:54:01 -0700] [Client 2] 2.0 CUPS-Get-Default 239
D [03/May/2025:11:54:01 -0700] CUPS-Get-Default
D [03/May/2025:11:54:01 -0700] [Client 2] Returning IPP successful-ok for CUPS-Get-Default (no URI) from localhost.
D [03/May/2025:11:54:01 -0700] [Client 2] Content-Length: 12097
D [03/May/2025:11:54:01 -0700] [Client 2] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [03/May/2025:11:54:01 -0700] [Client 2] con->http=0x5f10cab6ca40
D [03/May/2025:11:54:01 -0700] [Client 2] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=12097, response=0x5f10cab3a470(IPP_STATE_DATA), pipe_pid=0, file=-1
D [03/May/2025:11:54:01 -0700] [Client 2] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [03/May/2025:11:54:01 -0700] [Client 2] bytes=0, http_state=0, data_remaining=12097
D [03/May/2025:11:54:01 -0700] [Client 2] Flushing write buffer.
D [03/May/2025:11:54:01 -0700] [Client 2] New state is HTTP_STATE_WAITING
D [03/May/2025:11:54:01 -0700] [Client 2] Waiting for request.
D [03/May/2025:11:54:01 -0700] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [03/May/2025:11:54:01 -0700] [Client 2] POST / HTTP/1.1
D [03/May/2025:11:54:01 -0700] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [03/May/2025:11:54:01 -0700] [Client 2] Read: status=200, state=6
D [03/May/2025:11:54:01 -0700] [Client 2] No authentication data provided.
D [03/May/2025:11:54:01 -0700] [Client 2] 2.0 CUPS-Get-Printers 240
D [03/May/2025:11:54:01 -0700] CUPS-Get-Printers
D [03/May/2025:11:54:01 -0700] [Client 2] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost.
D [03/May/2025:11:54:01 -0700] [Client 2] Content-Length: 2840
D [03/May/2025:11:54:01 -0700] [Client 2] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [03/May/2025:11:54:01 -0700] [Client 2] con->http=0x5f10cab6ca40
D [03/May/2025:11:54:01 -0700] [Client 2] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=2840, response=0x5f10cab4fee0(IPP_STATE_DATA), pipe_pid=0, file=-1
D [03/May/2025:11:54:01 -0700] [Client 2] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [03/May/2025:11:54:01 -0700] [Client 2] bytes=0, http_state=0, data_remaining=2840
D [03/May/2025:11:54:01 -0700] [Client 2] Flushing write buffer.
D [03/May/2025:11:54:01 -0700] [Client 2] New state is HTTP_STATE_WAITING
D [03/May/2025:11:54:01 -0700] [Client 2] Waiting for request.
D [03/May/2025:11:54:01 -0700] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [03/May/2025:11:54:02 -0700] Expiring subscriptions...
D [03/May/2025:11:54:02 -0700] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [03/May/2025:11:54:02 -0700] [Client 5] Server address is "/run/cups/cups.sock".
D [03/May/2025:11:54:02 -0700] [Client 5] Accepted from localhost (Domain)
D [03/May/2025:11:54:02 -0700] [Client 5] Waiting for request.
D [03/May/2025:11:54:02 -0700] [Client 5] POST / HTTP/1.1
D [03/May/2025:11:54:02 -0700] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [03/May/2025:11:54:02 -0700] [Client 5] Read: status=200, state=6
D [03/May/2025:11:54:02 -0700] [Client 5] No authentication data provided.
D [03/May/2025:11:54:02 -0700] [Client 5] 2.0 Get-Job-Attributes 241
D [03/May/2025:11:54:02 -0700] Get-Job-Attributes ipp://localhost/jobs/142
D [03/May/2025:11:54:02 -0700] [Job 142] Loading attributes...
D [03/May/2025:11:54:02 -0700] [Client 5] Returning IPP successful-ok for Get-Job-Attributes (ipp://localhost/jobs/142) from localhost.
D [03/May/2025:11:54:02 -0700] [Client 5] Content-Length: 113
D [03/May/2025:11:54:02 -0700] [Client 5] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [03/May/2025:11:54:02 -0700] [Client 5] con->http=0x5f10cab71250
D [03/May/2025:11:54:02 -0700] [Client 5] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=113, response=0x5f10cab3a5a0(IPP_STATE_DATA), pipe_pid=0, file=-1
D [03/May/2025:11:54:02 -0700] [Client 5] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [03/May/2025:11:54:02 -0700] [Client 5] bytes=0, http_state=0, data_remaining=113
D [03/May/2025:11:54:02 -0700] [Client 5] Flushing write buffer.
D [03/May/2025:11:54:02 -0700] [Client 5] New state is HTTP_STATE_WAITING
D [03/May/2025:11:54:02 -0700] [Client 5] Waiting for request.
D [03/May/2025:11:54:02 -0700] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [03/May/2025:11:54:02 -0700] [Client 5] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [03/May/2025:11:54:02 -0700] [Client 5] Closing connection.
D [03/May/2025:11:54:02 -0700] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [03/May/2025:11:54:02 -0700] [Client 2] POST / HTTP/1.1
D [03/May/2025:11:54:02 -0700] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [03/May/2025:11:54:02 -0700] [Client 2] Read: status=200, state=6
D [03/May/2025:11:54:02 -0700] [Client 2] No authentication data provided.
D [03/May/2025:11:54:02 -0700] [Client 2] 2.0 Get-Notifications 242
D [03/May/2025:11:54:02 -0700] Get-Notifications /printers/
D [03/May/2025:11:54:02 -0700] cupsdIsAuthorized: requesting-user-name="grahams"
D [03/May/2025:11:54:02 -0700] [Client 2] Returning IPP successful-ok for Get-Notifications (/printers/) from localhost.
D [03/May/2025:11:54:02 -0700] [Client 2] Content-Length: 127
D [03/May/2025:11:54:02 -0700] [Client 2] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [03/May/2025:11:54:02 -0700] [Client 2] con->http=0x5f10cab6ca40
D [03/May/2025:11:54:02 -0700] [Client 2] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=127, response=0x5f10cab4fee0(IPP_STATE_DATA), pipe_pid=0, file=-1
D [03/May/2025:11:54:02 -0700] [Client 2] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [03/May/2025:11:54:02 -0700] [Client 2] bytes=0, http_state=0, data_remaining=127
D [03/May/2025:11:54:02 -0700] [Client 2] Flushing write buffer.
D [03/May/2025:11:54:02 -0700] [Client 2] New state is HTTP_STATE_WAITING
D [03/May/2025:11:54:02 -0700] [Client 2] Waiting for request.
D [03/May/2025:11:54:02 -0700] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [03/May/2025:11:54:02 -0700] [Client 2] POST / HTTP/1.1
D [03/May/2025:11:54:02 -0700] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [03/May/2025:11:54:02 -0700] [Client 2] Read: status=200, state=6
D [03/May/2025:11:54:02 -0700] [Client 2] No authentication data provided.
D [03/May/2025:11:54:02 -0700] [Client 2] 2.0 Get-Notifications 243
D [03/May/2025:11:54:02 -0700] Get-Notifications /printers/
D [03/May/2025:11:54:02 -0700] cupsdIsAuthorized: requesting-user-name="grahams"
D [03/May/2025:11:54:02 -0700] [Client 2] Returning IPP successful-ok for Get-Notifications (/printers/) from localhost.
D [03/May/2025:11:54:02 -0700] [Client 2] Content-Length: 127
D [03/May/2025:11:54:02 -0700] [Client 2] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [03/May/2025:11:54:02 -0700] [Client 2] con->http=0x5f10cab6ca40
D [03/May/2025:11:54:02 -0700] [Client 2] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=127, response=0x5f10cab3a5a0(IPP_STATE_DATA), pipe_pid=0, file=-1
D [03/May/2025:11:54:02 -0700] [Client 2] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [03/May/2025:11:54:02 -0700] [Client 2] bytes=0, http_state=0, data_remaining=127
D [03/May/2025:11:54:02 -0700] [Client 2] Flushing write buffer.
D [03/May/2025:11:54:02 -0700] [Client 2] New state is HTTP_STATE_WAITING
D [03/May/2025:11:54:02 -0700] [Client 2] Waiting for request.
D [03/May/2025:11:54:02 -0700] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [03/May/2025:11:54:02 -0700] [Client 2] POST / HTTP/1.1
D [03/May/2025:11:54:02 -0700] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [03/May/2025:11:54:02 -0700] [Client 2] Read: status=200, state=6
D [03/May/2025:11:54:02 -0700] [Client 2] No authentication data provided.
D [03/May/2025:11:54:02 -0700] [Client 2] 2.0 Get-Notifications 244
D [03/May/2025:11:54:02 -0700] Get-Notifications /printers/
D [03/May/2025:11:54:02 -0700] cupsdIsAuthorized: requesting-user-name="grahams"
D [03/May/2025:11:54:02 -0700] [Client 2] Returning IPP successful-ok for Get-Notifications (/printers/) from localhost.
D [03/May/2025:11:54:02 -0700] [Client 2] Content-Length: 127
D [03/May/2025:11:54:02 -0700] [Client 2] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [03/May/2025:11:54:02 -0700] [Client 2] con->http=0x5f10cab6ca40
D [03/May/2025:11:54:02 -0700] [Client 2] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=127, response=0x5f10cab4fee0(IPP_STATE_DATA), pipe_pid=0, file=-1
D [03/May/2025:11:54:02 -0700] [Client 2] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [03/May/2025:11:54:02 -0700] [Client 2] bytes=0, http_state=0, data_remaining=127
D [03/May/2025:11:54:02 -0700] [Client 2] Flushing write buffer.
D [03/May/2025:11:54:02 -0700] [Client 2] New state is HTTP_STATE_WAITING
D [03/May/2025:11:54:02 -0700] [Client 2] Waiting for request.
D [03/May/2025:11:54:02 -0700] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [03/May/2025:11:54:02 -0700] [Client 2] POST / HTTP/1.1
D [03/May/2025:11:54:02 -0700] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [03/May/2025:11:54:02 -0700] [Client 2] Read: status=200, state=6
D [03/May/2025:11:54:02 -0700] [Client 2] No authentication data provided.
D [03/May/2025:11:54:02 -0700] [Client 2] 2.0 Get-Notifications 245
D [03/May/2025:11:54:02 -0700] Get-Notifications /printers/
D [03/May/2025:11:54:02 -0700] cupsdIsAuthorized: requesting-user-name="grahams"
D [03/May/2025:11:54:02 -0700] [Client 2] Returning IPP successful-ok for Get-Notifications (/printers/) from localhost.
D [03/May/2025:11:54:02 -0700] [Client 2] Content-Length: 127
D [03/May/2025:11:54:02 -0700] [Client 2] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [03/May/2025:11:54:02 -0700] [Client 2] con->http=0x5f10cab6ca40
D [03/May/2025:11:54:02 -0700] [Client 2] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=127, response=0x5f10cab3a5a0(IPP_STATE_DATA), pipe_pid=0, file=-1
D [03/May/2025:11:54:02 -0700] [Client 2] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [03/May/2025:11:54:02 -0700] [Client 2] bytes=0, http_state=0, data_remaining=127
D [03/May/2025:11:54:02 -0700] [Client 2] Flushing write buffer.
D [03/May/2025:11:54:02 -0700] [Client 2] New state is HTTP_STATE_WAITING
D [03/May/2025:11:54:02 -0700] [Client 2] Waiting for request.
D [03/May/2025:11:54:02 -0700] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [03/May/2025:11:54:02 -0700] [Client 2] POST / HTTP/1.1
D [03/May/2025:11:54:02 -0700] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [03/May/2025:11:54:02 -0700] [Client 2] Read: status=200, state=6
D [03/May/2025:11:54:02 -0700] [Client 2] No authentication data provided.
D [03/May/2025:11:54:02 -0700] [Client 2] 2.0 Get-Notifications 246
D [03/May/2025:11:54:02 -0700] Get-Notifications /printers/
D [03/May/2025:11:54:02 -0700] cupsdIsAuthorized: requesting-user-name="grahams"
D [03/May/2025:11:54:02 -0700] [Client 2] Returning IPP successful-ok for Get-Notifications (/printers/) from localhost.
D [03/May/2025:11:54:02 -0700] [Client 2] Content-Length: 127
D [03/May/2025:11:54:02 -0700] [Client 2] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [03/May/2025:11:54:02 -0700] [Client 2] con->http=0x5f10cab6ca40
D [03/May/2025:11:54:02 -0700] [Client 2] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=127, response=0x5f10cab4fee0(IPP_STATE_DATA), pipe_pid=0, file=-1
D [03/May/2025:11:54:02 -0700] [Client 2] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [03/May/2025:11:54:02 -0700] [Client 2] bytes=0, http_state=0, data_remaining=127
D [03/May/2025:11:54:02 -0700] [Client 2] Flushing write buffer.
D [03/May/2025:11:54:02 -0700] [Client 2] New state is HTTP_STATE_WAITING
D [03/May/2025:11:54:02 -0700] [Client 2] Waiting for request.
D [03/May/2025:11:54:02 -0700] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [03/May/2025:11:54:02 -0700] [Client 2] POST / HTTP/1.1
D [03/May/2025:11:54:02 -0700] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [03/May/2025:11:54:02 -0700] [Client 2] Read: status=200, state=6
D [03/May/2025:11:54:02 -0700] [Client 2] No authentication data provided.
D [03/May/2025:11:54:02 -0700] [Client 2] 2.0 Get-Notifications 247
D [03/May/2025:11:54:02 -0700] Get-Notifications /printers/
D [03/May/2025:11:54:02 -0700] cupsdIsAuthorized: requesting-user-name="grahams"
D [03/May/2025:11:54:02 -0700] [Client 2] Returning IPP successful-ok for Get-Notifications (/printers/) from localhost.
D [03/May/2025:11:54:02 -0700] [Client 2] Content-Length: 127
D [03/May/2025:11:54:02 -0700] [Client 2] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [03/May/2025:11:54:02 -0700] [Client 2] con->http=0x5f10cab6ca40
D [03/May/2025:11:54:02 -0700] [Client 2] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=127, response=0x5f10cab3a5a0(IPP_STATE_DATA), pipe_pid=0, file=-1
D [03/May/2025:11:54:02 -0700] [Client 2] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [03/May/2025:11:54:02 -0700] [Client 2] bytes=0, http_state=0, data_remaining=127
D [03/May/2025:11:54:02 -0700] [Client 2] Flushing write buffer.
D [03/May/2025:11:54:02 -0700] [Client 2] New state is HTTP_STATE_WAITING
D [03/May/2025:11:54:02 -0700] [Client 2] Waiting for request.
D [03/May/2025:11:54:02 -0700] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [03/May/2025:11:54:02 -0700] [Client 2] POST / HTTP/1.1
D [03/May/2025:11:54:02 -0700] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [03/May/2025:11:54:02 -0700] [Client 2] Read: status=200, state=6
D [03/May/2025:11:54:02 -0700] [Client 2] No authentication data provided.
D [03/May/2025:11:54:02 -0700] [Client 2] 2.0 Get-Notifications 248
D [03/May/2025:11:54:02 -0700] Get-Notifications /printers/
D [03/May/2025:11:54:02 -0700] cupsdIsAuthorized: requesting-user-name="grahams"
D [03/May/2025:11:54:02 -0700] [Client 2] Returning IPP successful-ok for Get-Notifications (/printers/) from localhost.
D [03/May/2025:11:54:02 -0700] [Client 2] Content-Length: 127
D [03/May/2025:11:54:02 -0700] [Client 2] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [03/May/2025:11:54:02 -0700] [Client 2] con->http=0x5f10cab6ca40
D [03/May/2025:11:54:02 -0700] [Client 2] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=127, response=0x5f10cab4fee0(IPP_STATE_DATA), pipe_pid=0, file=-1
D [03/May/2025:11:54:02 -0700] [Client 2] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [03/May/2025:11:54:02 -0700] [Client 2] bytes=0, http_state=0, data_remaining=127
D [03/May/2025:11:54:02 -0700] [Client 2] Flushing write buffer.
D [03/May/2025:11:54:02 -0700] [Client 2] New state is HTTP_STATE_WAITING
D [03/May/2025:11:54:02 -0700] [Client 2] Waiting for request.
D [03/May/2025:11:54:02 -0700] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [03/May/2025:11:54:02 -0700] [Client 2] POST / HTTP/1.1
D [03/May/2025:11:54:02 -0700] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [03/May/2025:11:54:02 -0700] [Client 2] Read: status=200, state=6
D [03/May/2025:11:54:02 -0700] [Client 2] No authentication data provided.
D [03/May/2025:11:54:02 -0700] [Client 2] 2.0 Get-Notifications 249
D [03/May/2025:11:54:02 -0700] Get-Notifications /printers/
D [03/May/2025:11:54:02 -0700] cupsdIsAuthorized: requesting-user-name="grahams"
D [03/May/2025:11:54:02 -0700] [Client 2] Returning IPP successful-ok for Get-Notifications (/printers/) from localhost.
D [03/May/2025:11:54:02 -0700] [Client 2] Content-Length: 127
D [03/May/2025:11:54:02 -0700] [Client 2] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [03/May/2025:11:54:02 -0700] [Client 2] con->http=0x5f10cab6ca40
D [03/May/2025:11:54:02 -0700] [Client 2] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=127, response=0x5f10cab3a5a0(IPP_STATE_DATA), pipe_pid=0, file=-1
D [03/May/2025:11:54:02 -0700] [Client 2] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [03/May/2025:11:54:02 -0700] [Client 2] bytes=0, http_state=0, data_remaining=127
D [03/May/2025:11:54:02 -0700] [Client 2] Flushing write buffer.
D [03/May/2025:11:54:02 -0700] [Client 2] New state is HTTP_STATE_WAITING
D [03/May/2025:11:54:02 -0700] [Client 2] Waiting for request.
D [03/May/2025:11:54:02 -0700] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [03/May/2025:11:54:02 -0700] [Client 2] POST / HTTP/1.1
D [03/May/2025:11:54:02 -0700] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [03/May/2025:11:54:02 -0700] [Client 2] Read: status=200, state=6
D [03/May/2025:11:54:02 -0700] [Client 2] No authentication data provided.
D [03/May/2025:11:54:02 -0700] [Client 2] 2.0 Get-Notifications 250
D [03/May/2025:11:54:02 -0700] Get-Notifications /printers/
D [03/May/2025:11:54:02 -0700] cupsdIsAuthorized: requesting-user-name="grahams"
D [03/May/2025:11:54:02 -0700] [Client 2] Returning IPP successful-ok for Get-Notifications (/printers/) from localhost.
D [03/May/2025:11:54:02 -0700] [Client 2] Content-Length: 127
D [03/May/2025:11:54:02 -0700] [Client 2] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [03/May/2025:11:54:02 -0700] [Client 2] con->http=0x5f10cab6ca40
D [03/May/2025:11:54:02 -0700] [Client 2] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=127, response=0x5f10cab4fee0(IPP_STATE_DATA), pipe_pid=0, file=-1
D [03/May/2025:11:54:02 -0700] [Client 2] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [03/May/2025:11:54:02 -0700] [Client 2] bytes=0, http_state=0, data_remaining=127
D [03/May/2025:11:54:02 -0700] [Client 2] Flushing write buffer.
D [03/May/2025:11:54:02 -0700] [Client 2] New state is HTTP_STATE_WAITING
D [03/May/2025:11:54:02 -0700] [Client 2] Waiting for request.
D [03/May/2025:11:54:02 -0700] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [03/May/2025:11:54:02 -0700] [Client 2] POST / HTTP/1.1
D [03/May/2025:11:54:02 -0700] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [03/May/2025:11:54:02 -0700] [Client 2] Read: status=200, state=6
D [03/May/2025:11:54:02 -0700] [Client 2] No authentication data provided.
D [03/May/2025:11:54:02 -0700] [Client 2] 2.0 Get-Notifications 251
D [03/May/2025:11:54:02 -0700] Get-Notifications /printers/
D [03/May/2025:11:54:02 -0700] cupsdIsAuthorized: requesting-user-name="grahams"
D [03/May/2025:11:54:02 -0700] [Client 2] Returning IPP successful-ok for Get-Notifications (/printers/) from localhost.
D [03/May/2025:11:54:02 -0700] [Client 2] Content-Length: 127
D [03/May/2025:11:54:02 -0700] [Client 2] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [03/May/2025:11:54:02 -0700] [Client 2] con->http=0x5f10cab6ca40
D [03/May/2025:11:54:02 -0700] [Client 2] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=127, response=0x5f10cab3a5a0(IPP_STATE_DATA), pipe_pid=0, file=-1
D [03/May/2025:11:54:02 -0700] [Client 2] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [03/May/2025:11:54:02 -0700] [Client 2] bytes=0, http_state=0, data_remaining=127
D [03/May/2025:11:54:02 -0700] [Client 2] Flushing write buffer.
D [03/May/2025:11:54:02 -0700] [Client 2] New state is HTTP_STATE_WAITING
D [03/May/2025:11:54:02 -0700] [Client 2] Waiting for request.
D [03/May/2025:11:54:02 -0700] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [03/May/2025:11:54:02 -0700] [Client 2] POST / HTTP/1.1
D [03/May/2025:11:54:02 -0700] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [03/May/2025:11:54:02 -0700] [Client 2] Read: status=200, state=6
D [03/May/2025:11:54:02 -0700] [Client 2] No authentication data provided.
D [03/May/2025:11:54:02 -0700] [Client 2] 2.0 Get-Notifications 252
D [03/May/2025:11:54:02 -0700] Get-Notifications /printers/
D [03/May/2025:11:54:02 -0700] cupsdIsAuthorized: requesting-user-name="grahams"
D [03/May/2025:11:54:02 -0700] [Client 2] Returning IPP successful-ok for Get-Notifications (/printers/) from localhost.
D [03/May/2025:11:54:02 -0700] [Client 2] Content-Length: 127
D [03/May/2025:11:54:02 -0700] [Client 2] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [03/May/2025:11:54:02 -0700] [Client 2] con->http=0x5f10cab6ca40
D [03/May/2025:11:54:02 -0700] [Client 2] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=127, response=0x5f10cab4fee0(IPP_STATE_DATA), pipe_pid=0, file=-1
D [03/May/2025:11:54:02 -0700] [Client 2] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [03/May/2025:11:54:02 -0700] [Client 2] bytes=0, http_state=0, data_remaining=127
D [03/May/2025:11:54:02 -0700] [Client 2] Flushing write buffer.
D [03/May/2025:11:54:02 -0700] [Client 2] New state is HTTP_STATE_WAITING
D [03/May/2025:11:54:02 -0700] [Client 2] Waiting for request.
D [03/May/2025:11:54:02 -0700] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [03/May/2025:11:54:02 -0700] [Client 2] POST / HTTP/1.1
D [03/May/2025:11:54:02 -0700] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [03/May/2025:11:54:02 -0700] [Client 2] Read: status=200, state=6
D [03/May/2025:11:54:02 -0700] [Client 2] No authentication data provided.
D [03/May/2025:11:54:02 -0700] [Client 2] 2.0 Get-Notifications 253
D [03/May/2025:11:54:02 -0700] Get-Notifications /printers/
D [03/May/2025:11:54:02 -0700] cupsdIsAuthorized: requesting-user-name="grahams"
D [03/May/2025:11:54:02 -0700] [Client 2] Returning IPP successful-ok for Get-Notifications (/printers/) from localhost.
D [03/May/2025:11:54:02 -0700] [Client 2] Content-Length: 127
D [03/May/2025:11:54:02 -0700] [Client 2] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [03/May/2025:11:54:02 -0700] [Client 2] con->http=0x5f10cab6ca40
D [03/May/2025:11:54:02 -0700] [Client 2] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=127, response=0x5f10cab3a5a0(IPP_STATE_DATA), pipe_pid=0, file=-1
D [03/May/2025:11:54:02 -0700] [Client 2] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [03/May/2025:11:54:02 -0700] [Client 2] bytes=0, http_state=0, data_remaining=127
D [03/May/2025:11:54:02 -0700] [Client 2] Flushing write buffer.
D [03/May/2025:11:54:02 -0700] [Client 2] New state is HTTP_STATE_WAITING
D [03/May/2025:11:54:02 -0700] [Client 2] Waiting for request.
D [03/May/2025:11:54:02 -0700] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [03/May/2025:11:54:03 -0700] Expiring subscriptions...
I [03/May/2025:11:54:19 -0700] Saving printers.conf...
I [03/May/2025:11:54:19 -0700] Saving job.cache...
I [03/May/2025:11:54:19 -0700] Saving subscriptions.conf...
D [03/May/2025:11:54:19 -0700] cupsdSetBusyState: newbusy="Not busy", busy="Dirty files"
D [03/May/2025:11:54:19 -0700] Expiring subscriptions...
D [03/May/2025:11:54:25 -0700] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [03/May/2025:11:54:25 -0700] [Client 6] Server address is "127.0.0.1".
D [03/May/2025:11:54:25 -0700] [Client 6] Accepted from localhost:40410 (IPv4)
D [03/May/2025:11:54:25 -0700] [Client 6] Waiting for request.
D [03/May/2025:11:54:25 -0700] Expiring subscriptions...
D [03/May/2025:11:54:26 -0700] Expiring subscriptions...
D [03/May/2025:11:54:27 -0700] [Client 6] GET /printers/Canon_LBP622C_623C_UFR_II?which_jobs=completed HTTP/1.1
D [03/May/2025:11:54:27 -0700] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
D [03/May/2025:11:54:27 -0700] [Client 6] Read: status=200, state=3
D [03/May/2025:11:54:27 -0700] [Client 6] Authorized as "root" using Basic.
D [03/May/2025:11:54:27 -0700] [Client 6] Processing GET /printers/Canon_LBP622C_623C_UFR_II?which_jobs=completed
D [03/May/2025:11:54:27 -0700] [CGI] argv[0] = "/usr/lib/cups/cgi-bin/printers.cgi"
D [03/May/2025:11:54:27 -0700] [CGI] argv[1] = "which_jobs=completed"
D [03/May/2025:11:54:27 -0700] [CGI] envp[0] = "CUPS_CACHEDIR=/var/cache/cups"
D [03/May/2025:11:54:27 -0700] [CGI] envp[1] = "CUPS_DATADIR=/usr/share/cups"
D [03/May/2025:11:54:27 -0700] [CGI] envp[2] = "CUPS_DOCROOT=/usr/share/cups/doc"
D [03/May/2025:11:54:27 -0700] [CGI] envp[3] = "CUPS_REQUESTROOT=/var/spool/cups"
D [03/May/2025:11:54:27 -0700] [CGI] envp[4] = "CUPS_SERVERBIN=/usr/lib/cups"
D [03/May/2025:11:54:27 -0700] [CGI] envp[5] = "CUPS_SERVERROOT=/etc/cups"
D [03/May/2025:11:54:27 -0700] [CGI] envp[6] = "CUPS_STATEDIR=/run/cups"
D [03/May/2025:11:54:27 -0700] [CGI] envp[7] = "HOME=/var/spool/cups/tmp"
D [03/May/2025:11:54:27 -0700] [CGI] envp[8] = "PATH=/usr/lib/cups/filter:/usr/bin:/usr/bin:/bin:/usr/bin"
D [03/May/2025:11:54:27 -0700] [CGI] envp[9] = "SERVER_ADMIN=root@hp8330"
D [03/May/2025:11:54:27 -0700] [CGI] envp[10] = "SOFTWARE=CUPS/2.4.12"
D [03/May/2025:11:54:27 -0700] [CGI] envp[11] = "TMPDIR=/var/spool/cups/tmp"
D [03/May/2025:11:54:27 -0700] [CGI] envp[12] = "USER=root"
D [03/May/2025:11:54:27 -0700] [CGI] envp[13] = "CUPS_MAX_MESSAGE=2047"
D [03/May/2025:11:54:27 -0700] [CGI] envp[14] = "CUPS_SERVER=/run/cups/cups.sock"
D [03/May/2025:11:54:27 -0700] [CGI] envp[15] = "CUPS_ENCRYPTION=IfRequested"
D [03/May/2025:11:54:27 -0700] [CGI] envp[16] = "IPP_PORT=631"
D [03/May/2025:11:54:27 -0700] [CGI] envp[17] = "AUTH_TYPE=Basic"
D [03/May/2025:11:54:27 -0700] [CGI] envp[18] = "LANG=en_US.UTF8"
D [03/May/2025:11:54:27 -0700] [CGI] envp[19] = "REDIRECT_STATUS=1"
D [03/May/2025:11:54:27 -0700] [CGI] envp[20] = "GATEWAY_INTERFACE=CGI/1.1"
D [03/May/2025:11:54:27 -0700] [CGI] envp[21] = "SERVER_NAME=localhost"
D [03/May/2025:11:54:27 -0700] [CGI] envp[22] = "SERVER_PORT=631"
D [03/May/2025:11:54:27 -0700] [CGI] envp[23] = "REMOTE_ADDR=127.0.0.1"
D [03/May/2025:11:54:27 -0700] [CGI] envp[24] = "REMOTE_HOST=localhost"
D [03/May/2025:11:54:27 -0700] [CGI] envp[25] = "SCRIPT_NAME=/printers/Canon_LBP622C_623C_UFR_II"
D [03/May/2025:11:54:27 -0700] [CGI] envp[26] = "SCRIPT_FILENAME=/usr/share/cups/doc/printers/Canon_LBP622C_623C_UFR_II"
D [03/May/2025:11:54:27 -0700] [CGI] envp[27] = "PATH_INFO=/Canon_LBP622C_623C_UFR_II"
D [03/May/2025:11:54:27 -0700] [CGI] envp[28] = "REMOTE_USER=root"
D [03/May/2025:11:54:27 -0700] [CGI] envp[29] = "SERVER_PROTOCOL=HTTP/1.1"
D [03/May/2025:11:54:27 -0700] [CGI] envp[30] = "HTTP_COOKIE=org.cups.sid=05cc8383c68a9632c511327f16a5315f"
D [03/May/2025:11:54:27 -0700] [CGI] envp[31] = "HTTP_USER_AGENT=Mozilla/5.0 (X11; Linux x86_64; rv:138.0) Gecko/20100101 Firefox/138.0"
D [03/May/2025:11:54:27 -0700] [CGI] envp[32] = "HTTP_REFERER=http://localhost:631/printers/Canon_LBP622C_623C_UFR_II?which_jobs=all"
D [03/May/2025:11:54:27 -0700] [CGI] envp[33] = "REQUEST_METHOD=GET"
D [03/May/2025:11:54:27 -0700] [CGI] envp[34] = "QUERY_STRING=which_jobs=completed"
D [03/May/2025:11:54:27 -0700] cupsdAddCert: Adding certificate for PID 5362
D [03/May/2025:11:54:27 -0700] [CGI] Started /usr/lib/cups/cgi-bin/printers.cgi (PID 5362)
I [03/May/2025:11:54:27 -0700] [Client 6] Started "/usr/lib/cups/cgi-bin/printers.cgi" (pid=5362, file=18)
D [03/May/2025:11:54:27 -0700] [Client 6] Waiting for CGI data.
D [03/May/2025:11:54:27 -0700] Expiring subscriptions...
D [03/May/2025:11:54:27 -0700] [CGI] org.cups.sid cookie is \"05cc8383c68a9632c511327f16a5315f\"
D [03/May/2025:11:54:27 -0700] [CGI] cgiSetVariable: which_jobs=\"completed\"
D [03/May/2025:11:54:27 -0700] [CGI] cgiSetVariable: SECTION=\"printers\"
D [03/May/2025:11:54:27 -0700] [CGI] cgiSetVariable: REFRESH_PAGE=\"\"
D [03/May/2025:11:54:27 -0700] [CGI] cgiSetVariable: PRINTER_NAME=\"Canon_LBP622C_623C_UFR_II\"
D [03/May/2025:11:54:27 -0700] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
D [03/May/2025:11:54:27 -0700] [Client 7] Server address is "/run/cups/cups.sock".
D [03/May/2025:11:54:27 -0700] [Client 7] Accepted from localhost (Domain)
D [03/May/2025:11:54:27 -0700] [Client 7] Waiting for request.
D [03/May/2025:11:54:27 -0700] [Client 7] POST / HTTP/1.1
D [03/May/2025:11:54:27 -0700] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
D [03/May/2025:11:54:27 -0700] [Client 7] Read: status=200, state=6
D [03/May/2025:11:54:27 -0700] [Client 7] No authentication data provided.
D [03/May/2025:11:54:27 -0700] [Client 7] 2.0 CUPS-Get-Default 1
D [03/May/2025:11:54:27 -0700] CUPS-Get-Default
D [03/May/2025:11:54:27 -0700] [Client 7] Returning IPP successful-ok for CUPS-Get-Default (no URI) from localhost.
D [03/May/2025:11:54:27 -0700] [Client 7] Content-Length: 194
D [03/May/2025:11:54:27 -0700] [Client 7] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [03/May/2025:11:54:27 -0700] [Client 7] con->http=0x5f10cab79c20
D [03/May/2025:11:54:27 -0700] [Client 7] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=194, response=0x5f10cab75860(IPP_STATE_DATA), pipe_pid=0, file=-1
D [03/May/2025:11:54:27 -0700] [Client 7] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [03/May/2025:11:54:27 -0700] [Client 7] bytes=0, http_state=0, data_remaining=194
D [03/May/2025:11:54:27 -0700] [Client 7] Flushing write buffer.
D [03/May/2025:11:54:27 -0700] [Client 7] New state is HTTP_STATE_WAITING
D [03/May/2025:11:54:27 -0700] [Client 7] Waiting for request.
D [03/May/2025:11:54:27 -0700] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
D [03/May/2025:11:54:27 -0700] [CGI] cgiSetVariable: DEFAULT_NAME=\"Canon_LBP622C_623C_UFR_II\"
D [03/May/2025:11:54:27 -0700] [CGI] cgiSetVariable: DEFAULT_URI=\"/printers/Canon_LBP622C_623C_UFR_II\"
D [03/May/2025:11:54:27 -0700] [CGI] show_printer(http=0x63958d19d780, printer=\"Canon_LBP622C_623C_UFR_II\")
D [03/May/2025:11:54:27 -0700] [Client 7] POST / HTTP/1.1
D [03/May/2025:11:54:27 -0700] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
D [03/May/2025:11:54:27 -0700] [Client 7] Read: status=200, state=6
D [03/May/2025:11:54:27 -0700] [Client 7] No authentication data provided.
D [03/May/2025:11:54:27 -0700] [Client 7] 2.0 Get-Printer-Attributes 2
D [03/May/2025:11:54:27 -0700] Get-Printer-Attributes ipp://localhost/printers/Canon_LBP622C_623C_UFR_II
D [03/May/2025:11:54:27 -0700] [Client 7] Returning IPP successful-ok for Get-Printer-Attributes (ipp://localhost/printers/Canon_LBP622C_623C_UFR_II) from localhost.
D [03/May/2025:11:54:27 -0700] [Client 7] Content-Length: 672
D [03/May/2025:11:54:27 -0700] [Client 7] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [03/May/2025:11:54:27 -0700] [Client 7] con->http=0x5f10cab79c20
D [03/May/2025:11:54:27 -0700] [Client 7] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=672, response=0x5f10cab3a5a0(IPP_STATE_DATA), pipe_pid=0, file=-1
D [03/May/2025:11:54:27 -0700] [Client 7] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [03/May/2025:11:54:27 -0700] [Client 7] bytes=0, http_state=0, data_remaining=672
D [03/May/2025:11:54:27 -0700] [Client 7] Flushing write buffer.
D [03/May/2025:11:54:27 -0700] [Client 7] New state is HTTP_STATE_WAITING
D [03/May/2025:11:54:27 -0700] [Client 7] Waiting for request.
D [03/May/2025:11:54:27 -0700] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
D [03/May/2025:11:54:27 -0700] [CGI] cgiSetVariable: SERVER_NAME=\"localhost\"
D [03/May/2025:11:54:27 -0700] [CGI] cgiSetVariable: REMOTE_USER=\"root\"
D [03/May/2025:11:54:27 -0700] [CGI] cgiSetVariable: CUPS_VERSION=\"CUPS v2.4.12\"
D [03/May/2025:11:54:27 -0700] [CGI] cgiSetVariable: SERVER_NAME=\"localhost\"
D [03/May/2025:11:54:27 -0700] [CGI] cgiSetVariable: REMOTE_USER=\"root\"
D [03/May/2025:11:54:27 -0700] [CGI] cgiSetVariable: CUPS_VERSION=\"CUPS v2.4.12\"
D [03/May/2025:11:54:27 -0700] [CGI] cgiSetArray: printer_is_accepting_jobs[0]=\"1\"
D [03/May/2025:11:54:27 -0700] [CGI] cgiSetArray: printer_is_shared[0]=\"1\"
D [03/May/2025:11:54:27 -0700] [CGI] cgiSetArray: printer_state[0]=\"3\"
D [03/May/2025:11:54:27 -0700] [CGI] cgiSetArray: admin_uri[0]=\"/admin/\"
D [03/May/2025:11:54:27 -0700] [CGI] cgiSetArray: printer_uri_supported[0]=\"/printers/Canon_LBP622C_623C_UFR_II\"
D [03/May/2025:11:54:27 -0700] [CGI] cgiSetArray: printer_name[0]=\"Canon_LBP622C_623C_UFR_II\"
D [03/May/2025:11:54:27 -0700] [CGI] cgiSetArray: printer_location[0]=\"\"
D [03/May/2025:11:54:27 -0700] [CGI] cgiSetArray: printer_info[0]=\"Canon LBP622C/623C UFR II\"
D [03/May/2025:11:54:27 -0700] [CGI] cgiSetArray: job_sheets_default[0]=\"none, none\"
D [03/May/2025:11:54:27 -0700] [CGI] cgiSetArray: device_uri[0]=\"socket://192.168.2.137\"
D [03/May/2025:11:54:27 -0700] [CGI] cgiSetArray: color_supported[0]=\"1\"
D [03/May/2025:11:54:27 -0700] [CGI] cgiSetArray: printer_make_and_model[0]=\"Canon LBP632C UFR II\"
D [03/May/2025:11:54:27 -0700] [CGI] cgiSetArray: media_default[0]=\"na_letter_8.5x11in\"
D [03/May/2025:11:54:27 -0700] [CGI] cgiSetArray: sides_supported[0]=\"one-sided, two-sided-long-edge, two-sided-short-edge\"
D [03/May/2025:11:54:27 -0700] [CGI] cgiSetArray: sides_default[0]=\"one-sided\"
D [03/May/2025:11:54:27 -0700] [CGI] cgiSetArray: printer_commands[0]=\"none\"
D [03/May/2025:11:54:27 -0700] [CGI] cgiSetArray: server_is_sharing_printers[0]=\"0\"
D [03/May/2025:11:54:27 -0700] [CGI] cgiSetVariable: TITLE=\"Canon_LBP622C_623C_UFR_II\"
D [03/May/2025:11:54:27 -0700] [CGI] cgiSetVariable: SERVER_NAME=\"localhost\"
D [03/May/2025:11:54:27 -0700] [CGI] cgiSetVariable: REMOTE_USER=\"root\"
D [03/May/2025:11:54:27 -0700] [CGI] cgiSetVariable: CUPS_VERSION=\"CUPS v2.4.12\"
D [03/May/2025:11:54:27 -0700] [Client 6] CGI data ready to be sent.
D [03/May/2025:11:54:27 -0700] [Client 6] con->http=0x5f10cab71250
D [03/May/2025:11:54:27 -0700] [Client 6] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=2147483647, response=(nil)(), pipe_pid=5362, file=18
D [03/May/2025:11:54:27 -0700] [Client 6] Waiting for CGI data.
D [03/May/2025:11:54:27 -0700] [Client 6] Script header: Content-Type: text/html;charset=utf-8
D [03/May/2025:11:54:27 -0700] [Client 6] Script header: 
D [03/May/2025:11:54:27 -0700] [Client 6] Sending status 200 for CGI.
D [03/May/2025:11:54:27 -0700] [Client 6] cupsdSendHeader: code=200, type="(null)", auth_type=0
D [03/May/2025:11:54:27 -0700] [Client 6] con->http=0x5f10cab71250
D [03/May/2025:11:54:27 -0700] [Client 6] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=(nil)(), pipe_pid=5362, file=18
D [03/May/2025:11:54:27 -0700] [Client 6] Waiting for CGI data.
D [03/May/2025:11:54:27 -0700] [Client 6] CGI data ready to be sent.
D [03/May/2025:11:54:27 -0700] [Client 6] con->http=0x5f10cab71250
D [03/May/2025:11:54:27 -0700] [Client 6] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=(nil)(), pipe_pid=5362, file=18
D [03/May/2025:11:54:27 -0700] [Client 6] Waiting for CGI data.
D [03/May/2025:11:54:27 -0700] [CGI] Regular expression \".*Clean.*\"
D [03/May/2025:11:54:27 -0700] [Client 6] con->http=0x5f10cab71250
D [03/May/2025:11:54:27 -0700] [Client 6] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=(nil)(), pipe_pid=5362, file=18
D [03/May/2025:11:54:27 -0700] [Client 6] Waiting for CGI data.
D [03/May/2025:11:54:27 -0700] [Client 6] CGI data ready to be sent.
D [03/May/2025:11:54:27 -0700] [CGI] Regular expression \".*PrintSelfTestPage.*\"
D [03/May/2025:11:54:27 -0700] [Client 6] con->http=0x5f10cab71250
D [03/May/2025:11:54:27 -0700] [Client 6] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=(nil)(), pipe_pid=5362, file=18
D [03/May/2025:11:54:27 -0700] [Client 6] Waiting for CGI data.
D [03/May/2025:11:54:27 -0700] [Client 6] con->http=0x5f10cab71250
D [03/May/2025:11:54:27 -0700] [Client 6] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=(nil)(), pipe_pid=5362, file=18
D [03/May/2025:11:54:27 -0700] [Client 6] Waiting for CGI data.
D [03/May/2025:11:54:27 -0700] [Client 6] CGI data ready to be sent.
D [03/May/2025:11:54:27 -0700] [Client 6] con->http=0x5f10cab71250
D [03/May/2025:11:54:27 -0700] [Client 6] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=(nil)(), pipe_pid=5362, file=18
D [03/May/2025:11:54:27 -0700] [Client 6] Waiting for CGI data.
D [03/May/2025:11:54:27 -0700] [Client 6] con->http=0x5f10cab71250
D [03/May/2025:11:54:27 -0700] [Client 6] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=(nil)(), pipe_pid=5362, file=18
D [03/May/2025:11:54:27 -0700] [Client 6] Waiting for CGI data.
D [03/May/2025:11:54:27 -0700] [Client 7] POST / HTTP/1.1
D [03/May/2025:11:54:27 -0700] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
D [03/May/2025:11:54:27 -0700] [Client 7] Read: status=200, state=6
D [03/May/2025:11:54:27 -0700] [Client 7] No authentication data provided.
D [03/May/2025:11:54:27 -0700] [Client 7] 2.0 Get-Jobs 3
D [03/May/2025:11:54:27 -0700] Get-Jobs ipp://localhost:631/printers/Canon_LBP622C_623C_UFR_II
I [03/May/2025:11:54:27 -0700] [Client 7] Limiting Get-Jobs response to 500 jobs.
D [03/May/2025:11:54:27 -0700] [Job 141] Loading attributes...
D [03/May/2025:11:54:27 -0700] [Job 140] Loading attributes...
D [03/May/2025:11:54:27 -0700] [Client 7] Returning IPP successful-ok for Get-Jobs (ipp://localhost:631/printers/Canon_LBP622C_623C_UFR_II) from localhost.
D [03/May/2025:11:54:27 -0700] [Client 7] Content-Length: 1319
D [03/May/2025:11:54:27 -0700] [Client 7] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [03/May/2025:11:54:27 -0700] [Client 7] con->http=0x5f10cab79c20
D [03/May/2025:11:54:27 -0700] [Client 7] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=1319, response=0x5f10cab58690(IPP_STATE_DATA), pipe_pid=0, file=-1
D [03/May/2025:11:54:27 -0700] [Client 7] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [03/May/2025:11:54:27 -0700] [Client 7] bytes=0, http_state=0, data_remaining=1319
D [03/May/2025:11:54:27 -0700] [Client 7] Flushing write buffer.
D [03/May/2025:11:54:27 -0700] [Client 7] New state is HTTP_STATE_WAITING
D [03/May/2025:11:54:27 -0700] [Client 7] Waiting for request.
D [03/May/2025:11:54:27 -0700] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
D [03/May/2025:11:54:27 -0700] [CGI] cgiClearVariables called.
D [03/May/2025:11:54:27 -0700] [CGI] cgiSetVariable: SECTION=\"printers\"
D [03/May/2025:11:54:27 -0700] [CGI] cgiSetVariable: TOTAL=\"3\"
D [03/May/2025:11:54:27 -0700] [CGI] cgiSetVariable: WHICH_JOBS=\"completed\"
D [03/May/2025:11:54:27 -0700] [CGI] cgiSetVariable: SERVER_NAME=\"localhost\"
D [03/May/2025:11:54:27 -0700] [CGI] cgiSetVariable: REMOTE_USER=\"root\"
D [03/May/2025:11:54:27 -0700] [CGI] cgiSetVariable: CUPS_VERSION=\"CUPS v2.4.12\"
D [03/May/2025:11:54:27 -0700] [CGI] cgiSetArray: job_preserved[0]=\"1\"
D [03/May/2025:11:54:27 -0700] [CGI] cgiSetArray: job_printer_name[0]=\"Canon_LBP622C_623C_UFR_II\"
D [03/May/2025:11:54:27 -0700] [CGI] cgiSetArray: job_printer_uri[0]=\"/printers/Canon_LBP622C_623C_UFR_II\"
D [03/May/2025:11:54:27 -0700] [CGI] cgiSetArray: job_hold_until[0]=\"no-hold\"
D [03/May/2025:11:54:27 -0700] [CGI] cgiSetArray: time_at_completed[0]=\"Sat 03 May 2025 11:53:51 AM PDT\"
D [03/May/2025:11:54:27 -0700] [CGI] cgiSetArray: time_at_creation[0]=\"Sat 03 May 2025 11:53:48 AM PDT\"
D [03/May/2025:11:54:27 -0700] [CGI] cgiSetArray: time_at_processing[0]=\"Sat 03 May 2025 11:53:51 AM PDT\"
D [03/May/2025:11:54:27 -0700] [CGI] cgiSetArray: job_id[0]=\"142\"
D [03/May/2025:11:54:27 -0700] [CGI] cgiSetArray: job_state[0]=\"9\"
D [03/May/2025:11:54:27 -0700] [CGI] cgiSetArray: job_impressions_completed[0]=\"0\"
D [03/May/2025:11:54:27 -0700] [CGI] cgiSetArray: job_k_octets[0]=\"1\"
D [03/May/2025:11:54:27 -0700] [CGI] cgiSetArray: job_printer_state_message[0]=\"src = libcanon_pdlwrapper.c, line = 514, err = 0¥nINFO: cfFilterGhostscript: Processing page 2...\"
D [03/May/2025:11:54:27 -0700] [CGI] cgiSetVariable: SERVER_NAME=\"localhost\"
D [03/May/2025:11:54:27 -0700] [CGI] cgiSetVariable: REMOTE_USER=\"root\"
D [03/May/2025:11:54:27 -0700] [CGI] cgiSetVariable: CUPS_VERSION=\"CUPS v2.4.12\"
D [03/May/2025:11:54:27 -0700] [CGI] cgiSetArray: job_preserved[1]=\"1\"
D [03/May/2025:11:54:27 -0700] [CGI] cgiSetArray: job_printer_name[1]=\"Canon_LBP622C_623C_UFR_II\"
D [03/May/2025:11:54:27 -0700] [CGI] cgiSetArray: job_printer_uri[1]=\"/printers/Canon_LBP622C_623C_UFR_II\"
D [03/May/2025:11:54:27 -0700] [CGI] cgiSetArray: job_hold_until[1]=\"no-hold\"
D [03/May/2025:11:54:27 -0700] [CGI] cgiSetArray: time_at_completed[1]=\"Sat 03 May 2025 11:52:53 AM PDT\"
D [03/May/2025:11:54:27 -0700] [CGI] cgiSetArray: time_at_creation[1]=\"Sat 03 May 2025 11:52:48 AM PDT\"
D [03/May/2025:11:54:27 -0700] [CGI] cgiSetArray: time_at_processing[1]=\"Sat 03 May 2025 11:52:53 AM PDT\"
D [03/May/2025:11:54:27 -0700] [CGI] cgiSetArray: job_id[1]=\"141\"
D [03/May/2025:11:54:27 -0700] [CGI] cgiSetArray: job_state[1]=\"9\"
D [03/May/2025:11:54:27 -0700] [CGI] cgiSetArray: job_impressions_completed[1]=\"0\"
D [03/May/2025:11:54:27 -0700] [CGI] cgiSetArray: job_k_octets[1]=\"1\"
D [03/May/2025:11:54:27 -0700] [CGI] cgiSetArray: job_printer_state_message[1]=\"src = libcanon_pdlwrapper.c, line = 514, err = 0¥nINFO: cfFilterGhostscript: Processing page 2...\"
D [03/May/2025:11:54:27 -0700] [CGI] cgiSetVariable: SERVER_NAME=\"localhost\"
D [03/May/2025:11:54:27 -0700] [CGI] cgiSetVariable: REMOTE_USER=\"root\"
D [03/May/2025:11:54:27 -0700] [CGI] cgiSetVariable: CUPS_VERSION=\"CUPS v2.4.12\"
D [03/May/2025:11:54:27 -0700] [CGI] cgiSetArray: job_preserved[2]=\"1\"
D [03/May/2025:11:54:27 -0700] [CGI] cgiSetArray: job_printer_name[2]=\"Canon_LBP622C_623C_UFR_II\"
D [03/May/2025:11:54:27 -0700] [CGI] cgiSetArray: job_printer_uri[2]=\"/printers/Canon_LBP622C_623C_UFR_II\"
D [03/May/2025:11:54:27 -0700] [CGI] cgiSetArray: job_hold_until[2]=\"no-hold\"
D [03/May/2025:11:54:27 -0700] [CGI] cgiSetArray: time_at_completed[2]=\"Sat 03 May 2025 11:49:32 AM PDT\"
D [03/May/2025:11:54:27 -0700] [CGI] cgiSetArray: time_at_creation[2]=\"Sat 03 May 2025 11:49:29 AM PDT\"
D [03/May/2025:11:54:27 -0700] [CGI] cgiSetArray: time_at_processing[2]=\"Sat 03 May 2025 11:49:31 AM PDT\"
D [03/May/2025:11:54:27 -0700] [CGI] cgiSetArray: job_id[2]=\"140\"
D [03/May/2025:11:54:27 -0700] [CGI] cgiSetArray: job_state[2]=\"9\"
D [03/May/2025:11:54:27 -0700] [CGI] cgiSetArray: job_impressions_completed[2]=\"0\"
D [03/May/2025:11:54:27 -0700] [CGI] cgiSetArray: job_k_octets[2]=\"1\"
D [03/May/2025:11:54:27 -0700] [CGI] cgiSetArray: job_printer_state_message[2]=\"src = libcanon_pdlwrapper.c, line = 514, err = 0¥nINFO: cfFilterGhostscript: Processing page 2...\"
D [03/May/2025:11:54:27 -0700] [CGI] cgiSetVariable: PRINTER_NAME=\"Canon_LBP622C_623C_UFR_II\"
D [03/May/2025:11:54:27 -0700] [CGI] cgiSetVariable: PRINTER_URI_SUPPORTED=\"/printers/Canon_LBP622C_623C_UFR_II\"
D [03/May/2025:11:54:27 -0700] [CGI] cgiSetVariable: THISURL=\"/printers/Canon_LBP622C_623C_UFR_II\"
D [03/May/2025:11:54:27 -0700] [CGI] cgiSetVariable: SEARCH_DEST=\"Canon_LBP622C_623C_UFR_II\"
D [03/May/2025:11:54:27 -0700] [Client 6] CGI data ready to be sent.
D [03/May/2025:11:54:27 -0700] [Client 6] con->http=0x5f10cab71250
D [03/May/2025:11:54:27 -0700] [Client 6] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=(nil)(), pipe_pid=5362, file=18
D [03/May/2025:11:54:27 -0700] [Client 6] Waiting for CGI data.
D [03/May/2025:11:54:27 -0700] [Client 6] con->http=0x5f10cab71250
D [03/May/2025:11:54:27 -0700] [Client 6] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=(nil)(), pipe_pid=5362, file=18
D [03/May/2025:11:54:27 -0700] [Client 6] Waiting for CGI data.
D [03/May/2025:11:54:27 -0700] [Client 6] CGI data ready to be sent.
D [03/May/2025:11:54:27 -0700] [Client 6] con->http=0x5f10cab71250
D [03/May/2025:11:54:27 -0700] [Client 6] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=(nil)(), pipe_pid=5362, file=18
D [03/May/2025:11:54:27 -0700] [Client 6] Waiting for CGI data.
D [03/May/2025:11:54:27 -0700] [Client 6] con->http=0x5f10cab71250
D [03/May/2025:11:54:27 -0700] [Client 6] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=(nil)(), pipe_pid=5362, file=18
D [03/May/2025:11:54:27 -0700] [Client 6] Waiting for CGI data.
D [03/May/2025:11:54:27 -0700] [Client 6] CGI data ready to be sent.
D [03/May/2025:11:54:27 -0700] [Client 6] con->http=0x5f10cab71250
D [03/May/2025:11:54:27 -0700] [Client 6] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=(nil)(), pipe_pid=5362, file=18
D [03/May/2025:11:54:27 -0700] [Client 6] Waiting for CGI data.
D [03/May/2025:11:54:27 -0700] [Client 6] con->http=0x5f10cab71250
D [03/May/2025:11:54:27 -0700] [Client 6] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=(nil)(), pipe_pid=5362, file=18
D [03/May/2025:11:54:27 -0700] [Client 6] Waiting for CGI data.
D [03/May/2025:11:54:27 -0700] [Client 6] CGI data ready to be sent.
D [03/May/2025:11:54:27 -0700] [Client 6] con->http=0x5f10cab71250
D [03/May/2025:11:54:27 -0700] [Client 6] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=(nil)(), pipe_pid=5362, file=18
D [03/May/2025:11:54:27 -0700] [Client 6] Waiting for CGI data.
D [03/May/2025:11:54:27 -0700] [Client 6] con->http=0x5f10cab71250
D [03/May/2025:11:54:27 -0700] [Client 6] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=(nil)(), pipe_pid=5362, file=18
D [03/May/2025:11:54:27 -0700] [Client 6] Waiting for CGI data.
D [03/May/2025:11:54:27 -0700] [Client 6] CGI data ready to be sent.
D [03/May/2025:11:54:27 -0700] [Client 6] con->http=0x5f10cab71250
D [03/May/2025:11:54:27 -0700] [Client 6] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=(nil)(), pipe_pid=5362, file=18
D [03/May/2025:11:54:27 -0700] [Client 6] Waiting for CGI data.
D [03/May/2025:11:54:27 -0700] [Client 6] con->http=0x5f10cab71250
D [03/May/2025:11:54:27 -0700] [Client 6] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=(nil)(), pipe_pid=5362, file=18
D [03/May/2025:11:54:27 -0700] [Client 6] Waiting for CGI data.
D [03/May/2025:11:54:27 -0700] [Client 6] CGI data ready to be sent.
D [03/May/2025:11:54:27 -0700] [Client 6] con->http=0x5f10cab71250
D [03/May/2025:11:54:27 -0700] [Client 6] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=(nil)(), pipe_pid=5362, file=18
D [03/May/2025:11:54:27 -0700] [Client 6] Waiting for CGI data.
D [03/May/2025:11:54:27 -0700] [Client 6] con->http=0x5f10cab71250
D [03/May/2025:11:54:27 -0700] [Client 6] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=(nil)(), pipe_pid=5362, file=18
D [03/May/2025:11:54:27 -0700] [Client 6] Waiting for CGI data.
D [03/May/2025:11:54:27 -0700] [Client 6] CGI data ready to be sent.
D [03/May/2025:11:54:27 -0700] [Client 6] con->http=0x5f10cab71250
D [03/May/2025:11:54:27 -0700] [Client 6] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=(nil)(), pipe_pid=5362, file=18
D [03/May/2025:11:54:27 -0700] [Client 6] Waiting for CGI data.
D [03/May/2025:11:54:27 -0700] [Client 6] con->http=0x5f10cab71250
D [03/May/2025:11:54:27 -0700] [Client 6] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=(nil)(), pipe_pid=5362, file=18
D [03/May/2025:11:54:27 -0700] [Client 6] Waiting for CGI data.
D [03/May/2025:11:54:27 -0700] [Client 6] CGI data ready to be sent.
D [03/May/2025:11:54:27 -0700] [Client 6] con->http=0x5f10cab71250
D [03/May/2025:11:54:27 -0700] [Client 6] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=(nil)(), pipe_pid=5362, file=18
D [03/May/2025:11:54:27 -0700] [Client 6] Waiting for CGI data.
D [03/May/2025:11:54:27 -0700] [Client 6] con->http=0x5f10cab71250
D [03/May/2025:11:54:27 -0700] [Client 6] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=(nil)(), pipe_pid=5362, file=18
D [03/May/2025:11:54:27 -0700] [Client 6] Waiting for CGI data.
D [03/May/2025:11:54:27 -0700] [Client 6] CGI data ready to be sent.
D [03/May/2025:11:54:27 -0700] [Client 6] con->http=0x5f10cab71250
D [03/May/2025:11:54:27 -0700] [Client 6] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=(nil)(), pipe_pid=5362, file=18
D [03/May/2025:11:54:27 -0700] [Client 6] Waiting for CGI data.
D [03/May/2025:11:54:27 -0700] [Client 6] con->http=0x5f10cab71250
D [03/May/2025:11:54:27 -0700] [Client 6] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=(nil)(), pipe_pid=5362, file=18
D [03/May/2025:11:54:27 -0700] [Client 6] Waiting for CGI data.
D [03/May/2025:11:54:27 -0700] [Client 6] CGI data ready to be sent.
D [03/May/2025:11:54:27 -0700] [Client 6] con->http=0x5f10cab71250
D [03/May/2025:11:54:27 -0700] [Client 6] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=(nil)(), pipe_pid=5362, file=18
D [03/May/2025:11:54:27 -0700] [Client 6] Waiting for CGI data.
D [03/May/2025:11:54:27 -0700] [Client 6] con->http=0x5f10cab71250
D [03/May/2025:11:54:27 -0700] [Client 6] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=(nil)(), pipe_pid=5362, file=18
D [03/May/2025:11:54:27 -0700] [Client 6] Waiting for CGI data.
D [03/May/2025:11:54:27 -0700] [Client 6] CGI data ready to be sent.
D [03/May/2025:11:54:27 -0700] [Client 6] con->http=0x5f10cab71250
D [03/May/2025:11:54:27 -0700] [Client 6] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=(nil)(), pipe_pid=5362, file=18
D [03/May/2025:11:54:27 -0700] [Client 6] Waiting for CGI data.
D [03/May/2025:11:54:27 -0700] [Client 6] con->http=0x5f10cab71250
D [03/May/2025:11:54:27 -0700] [Client 6] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=(nil)(), pipe_pid=5362, file=18
D [03/May/2025:11:54:27 -0700] [Client 6] Waiting for CGI data.
D [03/May/2025:11:54:27 -0700] [Client 7] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [03/May/2025:11:54:27 -0700] [Client 7] Closing connection.
D [03/May/2025:11:54:27 -0700] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
D [03/May/2025:11:54:27 -0700] [Client 6] CGI data ready to be sent.
D [03/May/2025:11:54:27 -0700] [Client 6] con->http=0x5f10cab71250
D [03/May/2025:11:54:27 -0700] [Client 6] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=(nil)(), pipe_pid=5362, file=18
D [03/May/2025:11:54:27 -0700] [Client 6] Waiting for CGI data.
D [03/May/2025:11:54:27 -0700] [Client 6] Sending 0-length chunk.
D [03/May/2025:11:54:27 -0700] [Client 6] Flushing write buffer.
D [03/May/2025:11:54:27 -0700] [Client 6] New state is HTTP_STATE_WAITING
D [03/May/2025:11:54:27 -0700] [Client 6] Waiting for request.
D [03/May/2025:11:54:27 -0700] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [03/May/2025:11:54:27 -0700] PID 5362 (/usr/lib/cups/cgi-bin/printers.cgi) exited with no errors.
D [03/May/2025:11:54:28 -0700] Expiring subscriptions...
D [03/May/2025:11:54:37 -0700] [Client 6] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [03/May/2025:11:54:37 -0700] [Client 6] Closing connection.
D [03/May/2025:11:54:37 -0700] cupsdSetBusyState: newbusy="Not busy", busy="Not busy"
D [03/May/2025:11:54:37 -0700] Expiring subscriptions...
D [03/May/2025:11:54:38 -0700] Expiring subscriptions...

Last edited by gps1539 (2025-05-03 19:12:08)

seth · 2025-05-03 19:23:32

IPP or IPP everywhere? The nice part about the latter is that you won't need any filters/drivers.

lpstat -t

(The log doesn't show an IPPE printer being used)

D [03/May/2025:11:53:51 -0700] [Job 142] PID 5304 (/usr/lib/cups/filter/rastertoufr2) did not catch or ignore signal 13.

file /usr/lib/cups/filter/rastertoufr2

If it's a script, post it.
If it's a binary,

ldd /usr/lib/cups/filter/rastertoufr2

gps1539 · 2025-05-03 19:59:28

seth wrote:

IPP or IPP everywhere? The nice part about the latter is that you won't need any filters/drivers.
lpstat -t
(The log doesn't show an IPPE printer being used)
D [03/May/2025:11:53:51 -0700] [Job 142] PID 5304 (/usr/lib/cups/filter/rastertoufr2) did not catch or ignore signal 13.
file /usr/lib/cups/filter/rastertoufr2
If it's a script, post it.
If it's a binary,
ldd /usr/lib/cups/filter/rastertoufr2

I believe it is using IPP

Note. I tried to use IPPE, but cups fails to add it. After a few attempts to "find new printer" it discovers it at "dnssd://Canon%20LBP622C%2F623C%20(9f%3A5d%3A18)%20(2)%20(9f%3A5d%3A18)%20(9f%20(9f%20(9f%3A5d%3A18)._ipp._tcp.local/?uuid=6d4ff0ce-6b11-11d8-8020-349f7ba1dd57". I then select IPP Everywhere and click Add Printer, but Cups fails with

Unable to add printer:

    Couldn't resolve mDNS URI "dnssd://Canon%20LBP622C%2F623C%20(9f%3A5d%3A18)%20(2)%20(9f%3A5d%3A18)%20(9f%20(9f%20(9f%3A5d%3A18)._ipp._tcp.local/?uuid=6d4ff0ce-6b11-11d8-8020-349f7ba1dd57".

$ lpstat -t
scheduler is running
system default destination: Canon_LBP622C_623C
device for Canon_LBP622C_623C: ipps://Canon%20LBP622C%2F623C%20(9f%3A5d%3A18)%20(2)%20(9f%3A5d%3A18)%20(9f%20(9f%20(9f%3A5d%3A18)._ipps._tcp.local/
device for CUPS-PDF: cups-pdf:/
Canon_LBP622C_623C accepting requests since Sat 03 May 2025 12:47:16 PM PDT
CUPS-PDF accepting requests since Thu 09 Dec 2021 10:44:29 AM PST
printer Canon_LBP622C_623C is idle.  enabled since Sat 03 May 2025 12:47:16 PM PDT
printer CUPS-PDF is idle.  enabled since Thu 09 Dec 2021 10:44:29 AM PST

$ file /usr/lib/cups/filter/rastertoufr2
/usr/lib/cups/filter/rastertoufr2: ELF 64-bit LSB pie executable, x86-64, version 1 (SYSV), dynamically linked, interpreter /lib64/ld-linux-x86-64.so.2, for GNU/Linux 3.2.0, BuildID[sha1]=a8b918ed9e34a1e1a21f41acb2149f2f0aaa4165, stripped
$ ldd /usr/lib/cups/filter/rastertoufr2
	linux-vdso.so.1 (0x000071a451f91000)
	libcups.so.2 => /usr/lib/libcups.so.2 (0x000071a451ec1000)
	libcupsimage.so.2 => /usr/lib/libcupsimage.so.2 (0x000071a451ebc000)
	libc.so.6 => /usr/lib/libc.so.6 (0x000071a451ccc000)
	libavahi-common.so.3 => /usr/lib/libavahi-common.so.3 (0x000071a451cbe000)
	libavahi-client.so.3 => /usr/lib/libavahi-client.so.3 (0x000071a451cac000)
	libgnutls.so.30 => /usr/lib/libgnutls.so.30 (0x000071a451a00000)
	libz.so.1 => /usr/lib/libz.so.1 (0x000071a451c91000)
	libm.so.6 => /usr/lib/libm.so.6 (0x000071a451908000)
	/lib64/ld-linux-x86-64.so.2 => /usr/lib64/ld-linux-x86-64.so.2 (0x000071a451f93000)
	libdbus-1.so.3 => /usr/lib/libdbus-1.so.3 (0x000071a451c3e000)
	libleancrypto.so.1 => /usr/lib/libleancrypto.so.1 (0x000071a4517c5000)
	libp11-kit.so.0 => /usr/lib/libp11-kit.so.0 (0x000071a451662000)
	libidn2.so.0 => /usr/lib/libidn2.so.0 (0x000071a451c1a000)
	libunistring.so.5 => /usr/lib/libunistring.so.5 (0x000071a45147f000)
	libtasn1.so.6 => /usr/lib/libtasn1.so.6 (0x000071a451c04000)
	libhogweed.so.6 => /usr/lib/libhogweed.so.6 (0x000071a451435000)
	libnettle.so.8 => /usr/lib/libnettle.so.8 (0x000071a4513dc000)
	libgmp.so.10 => /usr/lib/libgmp.so.10 (0x000071a451336000)
	libsystemd.so.0 => /usr/lib/libsystemd.so.0 (0x000071a451211000)
	libffi.so.8 => /usr/lib/libffi.so.8 (0x000071a451206000)
	libcap.so.2 => /usr/lib/libcap.so.2 (0x000071a4511fa000)
	libgcc_s.so.1 => /usr/lib/libgcc_s.so.1 (0x000071a4511cd000)

seth · 2025-05-03 20:10:51

For IPP:

nmap <printer ip here>

libgcc_s.so.1 => /usr/lib/libgcc_s.so.1 (0x000071a4511cd000)

was gcc-libs in the critical update?

gps1539 · 2025-05-03 20:36:11

seth wrote:

For IPP:

nmap <printer ip here>

 sudo nmap 192.168.2.137
Starting Nmap 7.95 ( https://nmap.org ) at 2025-05-03 13:31 PDT
Nmap scan report for Canon_printer.lan (192.168.2.137)
Host is up (0.010s latency).
Not shown: 995 closed tcp ports (reset)
PORT     STATE SERVICE
80/tcp   open  http
443/tcp  open  https
515/tcp  open  printer
631/tcp  open  ipp
9100/tcp open  jetdirect
MAC Address: C4:AC:59:9F:5D:18 (Murata Manufacturing)

libgcc_s.so.1 => /usr/lib/libgcc_s.so.1 (0x000071a4511cd000)

was gcc-libs in the critical update?

gcc-libs 15.1.1+r7+gf36ec88aa85a-1
Looks like it was released April 29th. However I haven't used the printer for a couple of months, so many things have changed.

seth · 2025-05-03 20:51:15

* http://localhost:631/
* remove the current printer
* (optionally uninstall the canon driver package)
* add a new printer
* ipps, ipps://192.168.2.137/ (though it seems properly detected via avahi?)
* add printer name, location whatever
* choose Generic/IPP Everywhere™ or Generic/Generic IPP Everywhere Printer (en) as driver (idk. which one is the correct one nor why there're two) - I assume you picked the canon driver when adding the printer the last time?
* try to print a test page
* profit ?

gps1539 · 2025-05-03 22:29:38

seth wrote:

* http://localhost:631/
* remove the current printer
* (optionally uninstall the canon driver package)
* add a new printer
* ipps, ipps://192.168.2.137/ (though it seems properly detected via avahi?)
* add printer name, location whatever
* choose Generic/IPP Everywhere™ or Generic/Generic IPP Everywhere Printer (en) as driver (idk. which one is the correct one nor why there're two) - I assume you picked the canon driver when adding the printer the last time?
* try to print a test page
* profit ?

I added it as a generic/IPP Everywhere printer using ipps://192.168.2.137/, but cups can not connect to it. After a test print it finally goes to "The printer is not responding."

seth · 2025-05-04 05:38:10

Try ipps://192.168.2.137/ipp or ipps://192.168.2.137/ipp/print instead (first url was from the wiki, second from a canon manual, third from the forum) and in doubt the unsecured (it's a friendly LAN anyway?) ipp://

If you previsouly tried to use the canon driver w/ the IPP url, I suspect autodetecting it via avahi would work as well

gps1539 · 2025-05-04 07:55:28

seth wrote:

Try ipps://192.168.2.137/ipp or ipps://192.168.2.137/ipp/print instead (first url was from the wiki, second from a canon manual, third from the forum) and in doubt the unsecured (it's a friendly LAN anyway?) ipp://
If you previsouly tried to use the canon driver w/ the IPP url, I suspect autodetecting it via avahi would work as well

Alas, same result with all of those ipp(s) urls.

The auto-detected url

dnssd://Canon%20LBP622C%2F623C%20(9f%3A5d%3A18)%20(2)%20(9f%3A5d%3A18)%20(9f%20(9f%20(9f%3A5d%3A18)._ipp._tcp.local/?uuid=6d4ff0ce-6b11-11d8-8020-349f7ba1dd57

Gives me a different error "Unable to locate printer "Cano._printer.local"." But the same result.

I also have a laptop running Arch, I will try the printer from that tomorrow.

seth · 2025-05-04 11:51:40

The printer seems to be resolved as Canon_printer.lan (in case the IP is dynamic and has changed)

ipp://Canon_printer.lan/ipp/print

- have you tried both IPP Everywhere drivers?
The printer has 631 open, so you should™ be able to use it.
Since it apparently also has a web server, check http://Canon_printer.lan/ (in your browser, not as printer URL

gps1539 · 2025-05-04 18:21:52

seth wrote:

The printer seems to be resolved as Canon_printer.lan (in case the IP is dynamic and has changed)
ipp://Canon_printer.lan/ipp/print
- have you tried both IPP Everywhere drivers?
The printer has 631 open, so you should™ be able to use it.
Since it apparently also has a web server, check http://Canon_printer.lan/ (in your browser, not as printer URL

Yes I tried both IPP drivers and I get the same issue on a separate arch laptop both with IPP and the Canon UFRII driver.

Printer works fine from Mac and Android phone, so they are my workaround for now.

Thanks for your help looking into this.

Last edited by gps1539 (2025-05-04 18:22:03)

themew · 2025-05-04 21:09:38

Seeing the same thing. Tried sending to the printer using LPD, IPP, and the original socket: that worked for years. Always stuck with the "libcanon_pdlwrapper.c" error. The printer was accessible prior the large daily update on 5-2 (or 5-1... it's all a blur) and the CNRDRVCUPS update from the AUR.

Also tried it on a Fedora machine -- exactly the same results.

Stuck with printing through our wired network using an Android phone after exhausting all options.

gps1539 · 2025-05-05 06:29:09

themew wrote:

Seeing the same thing. Tried sending to the printer using LPD, IPP, and the original socket: that worked for years. Always stuck with the "libcanon_pdlwrapper.c" error. The printer was accessible prior the large daily update on 5-2 (or 5-1... it's all a blur) and the CNRDRVCUPS update from the AUR.
Also tried it on a Fedora machine -- exactly the same results.
Stuck with printing through our wired network using an Android phone after exhausting all options.

Looks like Cups was updated on Apr 11th according to the ALA. Did you update Arch after that date and print successfully?

iq2luc · 2025-05-05 08:14:50

I get the same problem (the print job doesn't get to the printer) with a Canon MF657Cdw.
No printing issues until the recent Arch update (1st of May); I'm using the printer on a daily basis.
In the cups "error_log" I can see "[Job 217] Set job-printer-state-message to "src = libcanon_pdlwrapper.c, line = 514, err = 0¥nINFO: cfFilterGhostscript: Processing page 2...", current level=ERROR" and "[Job 217] cfFilterChain: ghostscript (PID 73253) exited with no errors.".

Downgrading cups and ghostscript related packages didn't solve the problem (tried different combinations, going back to 2024).
Also downgraded several ghostscript dependencies to various older versions (filter / image processing related) and even gcc related packages (relative to gcc 14.2.x version).
Tried with two "cnrdrvcups-lb" versions: 6.00.1.06 - the one I was using before the problematic update, and the latest 6.10.1.01.
Normally I'm using IPP, but I also tried using socket connectivity.

Nothing works - always hitting the same issue.

Last edited by iq2luc (2025-05-05 08:16:00)

seth · 2025-05-05 08:24:32

Everyone seeing ibcanon_pdlwrapper.c in the log isn't using IPP everywhere.
Check nmap to see whether the printer has 631 open, then please post an (updated) cups log

And check the printer settings, https://oip.manual.canon/USRMA-3590-zz- … 0706_h1_01 suggests that all of this is configurable via the printers browser interface.

The problems w/ the binary-release canon driver probably stem from the gcc(-libs) update, do NOT downgrade gcc* in isolation! If you want to test that theory, roll the system back to April 28th.

iq2luc · 2025-05-05 09:30:26

seth wrote:

Everyone seeing libcanon_pdlwrapper.c in the log isn't using IPP everywhere.

I've always used IPP (or at least that is what CUPS is telling me), please see the the CUPS log file content: https://hastebin.com/share/alarulocum.log

seth wrote:

Check nmap to see whether the printer has 631 open, then please post an (updated) cups log

Please find the output here: https://hastebin.com/share/qegoxahoza.console

I will try the Arch rollback suggestion and I'll get back with a feedback.
Still, I think this will only help confirm the current supposition that "something" in the latest updates broke "something" related to cnrdrvcups-lb.

Last edited by iq2luc (2025-05-05 09:32:23)

seth · 2025-05-05 09:38:24

I've always used IPP

D [05/May/2025:10:45:05 +0300] [Job 217] PID 73248 (/usr/lib/cups/filter/rastertoufr2) did not catch or ignore signal 13.

lpstat -t

ipp is port 631 - the local cups uses that
You're looking for https://wiki.archlinux.org/title/CUPS#A … Everywhere and that does not involve "rastertoufr2"
Your printer has 631 open (as well) so that's what we'll be shooting for.
See https://bbs.archlinux.org/viewtopic.php … 1#p2239961 - adjust the IP - and post an updated log.

iq2luc · 2025-05-05 11:06:06

seth wrote:

lpstat -t
ipp is port 631 - the local cups uses that
You're looking for https://wiki.archlinux.org/title/CUPS#A … Everywhere and that does not involve "rastertoufr2"
Your printer has 631 open (as well) so that's what we'll be shooting for.
See https://bbs.archlinux.org/viewtopic.php … 1#p2239961 - adjust the IP - and post an updated log.

First of all, thank you for your good intentions and your prompt replies.
Probably there is something I'm missing (I really didn't encountered printing issues until now) so please let me know why do you say I'm not using IPP.

Please see: https://hastebin.com/share/agujoyemip.console

Also, please see: https://postimg.cc/HrnnY86Q

No matter how the printer is connected and / or configured, I always get the same "error":

cfFilterChain: ghostscript (PID ####) exited with no errors.

and in the CUPS log I can see:

[Job ###] src = libcanon_pdlwrapper.c, line = 514, err = 0¥nINFO: cfFilterGhostscript: Processing page #...

In my neophyte eyes it looks like some CUPS filter returned a non-error code, but the Canon driver interprets it as an error.
The really curious part for me (because I didn't studied yet how CUPS is working) is why even for driverless setup it still looks like it is going trough the Canon driver (but again, probably that has to do with my lack of understanding how CUPS / Linux printing in general works).

Thanks again for your support.

---

EDIT

Forgot to mention that all listed printers:

device for Canon-MF657Cdw-CARPS2: ipp://prt/ipp
device for Canon-MF657Cdw-UFR2: ipp://prt/ipp
device for MF650C_Series_AUTO: ipps://Canon%20MF657Cdw._ipps._tcp.local/
device for MF650C_Series_DNSSD: dnssd://Canon%20MF657Cdw._ipp._tcp.local/?uuid=6d4ff0ce-6b11-11d8-8020-40f8dfc644ac

...are actually the same printer under different connection / configuration options.

Last edited by iq2luc (2025-05-05 11:17:32)

Lone_Wolf · 2025-05-05 12:03:32

Probably there is something I'm missing (I really didn't encountered printing issues until now) so please let me know why do you say I'm not using IPP.

UFR2 is a proprietary protocol from canon. rastertoufr2 only works with that proprietary protocol.

The majority of canon printers that support ipp everywhere mention it on explicitly on the product page or list a generic driver for unix/linux for it.
Your MFC657Cdw only shows the UFR2 driver for linux.

Incase you want to give ipp everywhere a chance, remove all canon related packages before creating a new printer in cups .

I expect ipp everywhere will still fails, but it's worth a try.

Next would be to try running the canon driver pacakge with an older ghostscipt version .
Also verify you do have libjpeg6-turbo & jbigkit installed as they solve hangs on some models.

seth · 2025-05-05 13:07:41

https://oip.manual.canon/USRMA-6625-zz- … e-aap.html and ufr2 will likely be 9100 - just make sure you're NOT selecting any canon driver when configuring the IPP everywhere printer and restart cups for a fresh log so there's no confusion about what has been used at that time.

(IPP everywhere uses cups-pdf to locally render a pdf and sends that to the printer which will then just print it on paper)

Arch Linux

#1 2025-05-02 23:18:41

Canon printer stopped working, seeing error in /var/log/cups/error_log

#2 2025-05-03 05:25:22

Re: Canon printer stopped working, seeing error in /var/log/cups/error_log

#3 2025-05-03 07:00:03

Re: Canon printer stopped working, seeing error in /var/log/cups/error_log

#4 2025-05-03 16:34:57

Re: Canon printer stopped working, seeing error in /var/log/cups/error_log

#5 2025-05-03 18:54:07

Re: Canon printer stopped working, seeing error in /var/log/cups/error_log

#6 2025-05-03 19:10:34

Re: Canon printer stopped working, seeing error in /var/log/cups/error_log

#7 2025-05-03 19:23:32

Re: Canon printer stopped working, seeing error in /var/log/cups/error_log

#8 2025-05-03 19:59:28

Re: Canon printer stopped working, seeing error in /var/log/cups/error_log

#9 2025-05-03 20:10:51

Re: Canon printer stopped working, seeing error in /var/log/cups/error_log

#10 2025-05-03 20:36:11

Re: Canon printer stopped working, seeing error in /var/log/cups/error_log

#11 2025-05-03 20:51:15

Re: Canon printer stopped working, seeing error in /var/log/cups/error_log

#12 2025-05-03 22:29:38

Re: Canon printer stopped working, seeing error in /var/log/cups/error_log

#13 2025-05-04 05:38:10

Re: Canon printer stopped working, seeing error in /var/log/cups/error_log

#14 2025-05-04 07:55:28

Re: Canon printer stopped working, seeing error in /var/log/cups/error_log

#15 2025-05-04 11:51:40

Re: Canon printer stopped working, seeing error in /var/log/cups/error_log

#16 2025-05-04 18:21:52

Re: Canon printer stopped working, seeing error in /var/log/cups/error_log

#17 2025-05-04 21:09:38

Re: Canon printer stopped working, seeing error in /var/log/cups/error_log

#18 2025-05-05 06:29:09

Re: Canon printer stopped working, seeing error in /var/log/cups/error_log

#19 2025-05-05 08:14:50

Re: Canon printer stopped working, seeing error in /var/log/cups/error_log

#20 2025-05-05 08:24:32

Re: Canon printer stopped working, seeing error in /var/log/cups/error_log

#21 2025-05-05 09:30:26

Re: Canon printer stopped working, seeing error in /var/log/cups/error_log

#22 2025-05-05 09:38:24

Re: Canon printer stopped working, seeing error in /var/log/cups/error_log

#23 2025-05-05 11:06:06

Re: Canon printer stopped working, seeing error in /var/log/cups/error_log

#24 2025-05-05 12:03:32

Re: Canon printer stopped working, seeing error in /var/log/cups/error_log

#25 2025-05-05 13:07:41

Re: Canon printer stopped working, seeing error in /var/log/cups/error_log

Board footer