You are not logged in.

Pages: 1

#1 2023-01-18 16:25:48

stefano
Member
Registered: 2011-04-09
Posts: 287

Print server rejects jobs from a local (but externally managed) mac

I have a small  network with a mix of linux desktops/laptops and mac laptops. Printing jobs are managed by a linux box acting as a print server (among other duties). The server uses iptables.
All but one of my machines can access the printer server. The lone exception is a Mac laptop, whose jobs are dropped by the server for what it seems to be a Firewall violation.  System log shows messages of this kind when I try to print from the mentioned laptop:

Jan 18 09:45:49 polus kernel: [UFW BLOCK] IN=enp3s0 OUT= MAC=00:e0:81:cc:9c:75:3c:22:fb:16:f5:52:86:dd SRC=2605:a601:ab14:ea00:01b0:d7b4:36cb:d4d3 DST=2605:a601:ab14:ea00:02e0:81ff:fecc:9c75 LEN=91 TC=0 HOPLIMIT=64 FLOWLBL=590080 PROTO=UDP SPT=64772 DPT=161 LEN=51 
Jan 18 09:45:51 polus kernel: [UFW BLOCK] IN=enp3s0 OUT= MAC=00:e0:81:cc:9c:75:3c:22:fb:16:f5:52:86:dd SRC=2605:a601:ab14:ea00:01b0:d7b4:36cb:d4d3 DST=2605:a601:ab14:ea00:02e0:81ff:fecc:9c75 LEN=91 TC=0 HOPLIMIT=64 FLOWLBL=590080 PROTO=UDP SPT=64772 DPT=161 LEN=51 
Jan 18 09:45:56 polus kernel: usblp0: removed
Jan 18 09:45:56 polus kernel: usblp 2-1.1:1.0: usblp0: USB Bidirectional printer dev 20 if 0 alt 0 proto 2 vid 0x04F9 pid 0x009B

The MAC address of the guilty laptop is 3c:22:fb:16:f5:52 , the MAC address of the print server is 00:e0:81:cc:9c:75.  I am not sure what the final two octets in the OUT address  reported by UFW stand for (86:dd). I have this rule affecting port 631 in iptables, which seems pretty liberal:

$> iptables -nvL | grep -n 631
[sudo] password for stefano: 
165:    0     0 ACCEPT     tcp  --  *      *       0.0.0.0/0            0.0.0.0/0            tcp dpt:631

and finally, the server's cupsd.conf has the following location directives:

<Location />
  # Allow remote access...
  Order allow,deny
  Allow localhost
  Allow 192.168.0.*
</Location>

As I said above, no other local boxes or laptops have issues, just this one.
Additional, possibly important,  detail: this laptop is owned and managed by my employer (local university) and it often travels back and forth between home and office. Printing used to work fine from both location, before the latest software update to the remote login software the university uses (i need to use the id and password I would use to login to any other campus-based machines to log into this laptop, no matter its physical location).

My guess is that the firewall does not recognize the laptop as being local and rejects the job. How can I find out if that is the case? And if it is, how can I fix the issue? As far as I know, iptables cannot allow access by MAC address. But I may be wrong.

Help greatly welcome.

Offline

#2 2023-01-18 18:09:25

seth
Member
From: Won't reply 2 private help req
Registered: 2012-09-03
Posts: 76,403

Re: Print server rejects jobs from a local (but externally managed) mac

Did you stop the FW to confirm it's the interceptor?

ACCEPT     tcp

but 

PROTO=UDP

How to upload text · How to boot w/o GUI · Disable Windows Fast-Start! · Fix your xinitrc

Online

#3 2023-01-18 20:49:47

stefano
Member
Registered: 2011-04-09
Posts: 287

Re: Print server rejects jobs from a local (but externally managed) mac

After trying many different options, including stopping and restarting iptables, I managed to morph the problem into the following:

- The MacOs the culprit laptop uses (Big Sur) identifies itself to the server using only a IPv6 address, which the server interprets as being not on the local network and therefore rejects it (to be more precise, the server  waits for authentication from the client, and it never gets it).

I could not find out the specific syntax needed to allow a specific ipv6 address or a range of ipv6 addresses in cupsd.conf. The client identifies itself with this address:

2605:a601:ab14:ea00:2e0:81ff:fecc:9c75

What would be the correct cupsd "Allow from" directive to let it go through?

Offline

#4 2023-01-18 21:12:59

stefano
Member
Registered: 2011-04-09
Posts: 287

Re: Print server rejects jobs from a local (but externally managed) mac

stefano wrote:

2605:a601:ab14:ea00:2e0:81ff:fecc:9c75

What would be the correct cupsd "Allow from" directive to let it go through?

Well, that was actually easy to find out from cupsd manual page: it is just the address in square brackets. However, even after adding the two ipv6 addresses that show up in the culprit mac's network panel to cupsd.conf Location block, the job are stuck waiting for authentication. Here is my complete cupsd.conf:

MaxLogSize 1m
LogLevel debug
# Allow remote access
Port 631
Listen /run/cups/cups.sock
Browsing On
BrowseLocalProtocols dnssd
BrowseAddress 192.168.0.*:631
DefaultAuthType Basic
WebInterface Yes
<Location />
  # Allow remote access...
  Order allow,deny
  Allow localhost
  Allow 192.168.0.*
# The two ipv6 addresses showing up in the mac Network panel
  Allow [2605:a601:ab14:ea00:2dd7:fa10:1cc2:ca5b]
  Allow [2605:a601:ab14:ea00:1c24:b28a:3759:12b4]
</Location>
<Location /admin>
</Location>
<Location /admin/conf>
  AuthType Default
  Require user @SYSTEM
</Location>
<Location /admin/log>
  AuthType Default
  Require user @SYSTEM
</Location>
<Policy default>
  JobPrivateAccess default
  JobPrivateValues default
  SubscriptionPrivateAccess default
  SubscriptionPrivateValues default
  <Limit Create-Job Print-Job Print-URI Validate-Job>
    Order deny,allow
  </Limit>
  <Limit Send-Document Send-URI Hold-Job Release-Job Restart-Job Purge-Jobs Set-Job-Attributes Create-Job-Subscription Renew-Subscription Cancel-Subscription Get-Notifications Reprocess-Job Cancel-Current-Job Suspend-Current-Job Resume-Job Cancel-My-Jobs Close-Job CUPS-Move-Job CUPS-Get-Document>
    Require user @OWNER @SYSTEM
    Order deny,allow
  </Limit>
  <Limit CUPS-Add-Modify-Printer CUPS-Delete-Printer CUPS-Add-Modify-Class CUPS-Delete-Class CUPS-Set-Default CUPS-Get-Devices>
    AuthType Default
    Require user @SYSTEM
    Order deny,allow
  </Limit>
  <Limit Pause-Printer Resume-Printer Enable-Printer Disable-Printer Pause-Printer-After-Current-Job Hold-New-Jobs Release-Held-New-Jobs Deactivate-Printer Activate-Printer Restart-Printer Shutdown-Printer Startup-Printer Promote-Job Schedule-Job-After Cancel-Jobs CUPS-Accept-Jobs CUPS-Reject-Jobs>
    AuthType Default
    Require user @SYSTEM
    Order deny,allow
  </Limit>
  <Limit CUPS-Authenticate-Job>
    Require user @OWNER @SYSTEM
    Order deny,allow
  </Limit>
  <Limit All>
    Order deny,allow
  </Limit>
  <Limit Cancel-Job>
    Order deny,allow
    Require user @OWNER @SYSTEM
  </Limit>
</Policy>
<Policy authenticated>
  JobPrivateAccess default
  JobPrivateValues default
  SubscriptionPrivateAccess default
  SubscriptionPrivateValues default
  <Limit Create-Job Print-Job Print-URI Validate-Job>
    AuthType Default
    Order deny,allow
  </Limit>
  <Limit Send-Document Send-URI Hold-Job Release-Job Restart-Job Purge-Jobs Set-Job-Attributes Create-Job-Subscription Renew-Subscription Cancel-Subscription Get-Notifications Reprocess-Job Cancel-Current-Job Suspend-Current-Job Resume-Job Cancel-My-Jobs Close-Job CUPS-Move-Job CUPS-Get-Document>
    AuthType Default
    Require user @OWNER @SYSTEM
    Order deny,allow
  </Limit>
  <Limit CUPS-Add-Modify-Printer CUPS-Delete-Printer CUPS-Add-Modify-Class CUPS-Delete-Class CUPS-Set-Default>
    AuthType Default
    Require user @SYSTEM
    Order deny,allow
  </Limit>
  <Limit Pause-Printer Resume-Printer Enable-Printer Disable-Printer Pause-Printer-After-Current-Job Hold-New-Jobs Release-Held-New-Jobs Deactivate-Printer Activate-Printer Restart-Printer Shutdown-Printer Startup-Printer Promote-Job Schedule-Job-After Cancel-Jobs CUPS-Accept-Jobs CUPS-Reject-Jobs>
    AuthType Default
    Require user @SYSTEM
    Order deny,allow
  </Limit>
  <Limit Cancel-Job CUPS-Authenticate-Job>
    AuthType Default
    Require user @OWNER @SYSTEM
    Order deny,allow
  </Limit>
  <Limit All>
    Order deny,allow
  </Limit>
</Policy>

I am as stuck as the printing job...

Offline

#5 2023-01-19 09:03:12

seth
Member
From: Won't reply 2 private help req
Registered: 2012-09-03
Posts: 76,403

Re: Print server rejects jobs from a local (but externally managed) mac

https://wiki.archlinux.org/title/CUPS/T … #Debug_log
Can you ping the IPv6 from the print server?

But I'd focus on getting the macbook an IPv4 LAN lease to generally "move" it into the LAN

How to upload text · How to boot w/o GUI · Disable Windows Fast-Start! · Fix your xinitrc

Online

#6 2023-01-19 16:02:55

stefano
Member
Registered: 2011-04-09
Posts: 287

Re: Print server rejects jobs from a local (but externally managed) mac

seth wrote:

I am not sure what your suggestion was here. I already have the log level set to debug, that's how I was able to figure out what was happening. Am I missing something?

seth wrote:

Can you ping the IPv6 from the print server?

Yes, I can, perhaps surprisingly (to me). So the laptop is visible from the server and it is explicitly authorized in cupsd.conf. What else does cups want?

seth wrote:

But I'd focus on getting the macbook an IPv4 LAN lease to generally "move" it into the LAN

Well, the confusing thing is that the laptop has *both* an ipv4 address assigned by my local router (192.168.0.33) *and* an ipv6 address (probably) assigned by the university network (my wild guess). But cups on the print server sees the laptop only through the ipv6 address and ignores the ipv4 one. I need to understand how the reverse the situation, but I literally have no idea where to start...

Offline

#7 2023-01-19 16:12:10

seth
Member
From: Won't reply 2 private help req
Registered: 2012-09-03
Posts: 76,403

Re: Print server rejects jobs from a local (but externally managed) mac

Ideally post the cups log after a failing print attempt.
Can you ping the IPv4 LAN IP as well?
How do you address the print server from the macbook?
CUPS_SERVER environment, avahi (BonJours) or w/ an IPP url? (or less likely lpd or smb)
In case of the latter: domain, IPv4 or IPv6?

How to upload text · How to boot w/o GUI · Disable Windows Fast-Start! · Fix your xinitrc

Online

#8 2023-01-19 18:52:21

stefano
Member
Registered: 2011-04-09
Posts: 287

Re: Print server rejects jobs from a local (but externally managed) mac

Possibly some progress:

1. I changed the network IPv6 settings on the mac laptop (in the Network settings panel) to use link-local only
2. Then, I added the following line to cupsd.conf's Location block  to all local ipv6 connections:

 Allow from [fe80::]/10

I tried printing again. Now I don't get any error messages, nor is the job stuck in the queue waiting for authentication. Unfortunately, not a single page gets printed. Here is the complete error  log:

seth wrote:

Ideally post the cups log after a failing print attempt.

[stefano@polus ~]$ tail -f /var/log/cups/error_log
D [19/Jan/2023:12:30:20 -0600] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [19/Jan/2023:12:30:20 -0600] [Client 13] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [19/Jan/2023:12:30:20 -0600] [Client 13] Closing connection.
D [19/Jan/2023:12:30:20 -0600] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [19/Jan/2023:12:30:20 -0600] [Client 13] Waiting for socket close.
D [19/Jan/2023:12:30:20 -0600] [Client 13] Closing on EOF.
D [19/Jan/2023:12:30:20 -0600] [Client 13] Closing connection.
D [19/Jan/2023:12:30:20 -0600] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
I [19/Jan/2023:12:30:50 -0600] Saving job.cache...
D [19/Jan/2023:12:30:50 -0600] cupsdSetBusyState: newbusy="Not busy", busy="Dirty files"
D [19/Jan/2023:12:33:27 -0600] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [19/Jan/2023:12:33:27 -0600] [Client 16] Server address is "192.168.0.4".
D [19/Jan/2023:12:33:27 -0600] [Client 16] Accepted from 192.168.0.33:59363 (IPv4)
D [19/Jan/2023:12:33:27 -0600] [Client 16] Waiting for request.
D [19/Jan/2023:12:33:27 -0600] [Job 1526] Unloading...
D [19/Jan/2023:12:33:27 -0600] cupsdAddCert: Adding certificate for PID 0
D [19/Jan/2023:12:33:27 -0600] Report: clients=1
D [19/Jan/2023:12:33:27 -0600] Report: jobs=71
D [19/Jan/2023:12:33:27 -0600] Report: jobs-active=0
D [19/Jan/2023:12:33:27 -0600] Report: printers=1
D [19/Jan/2023:12:33:27 -0600] Report: stringpool-string-count=690
D [19/Jan/2023:12:33:27 -0600] Report: stringpool-alloc-bytes=9112
D [19/Jan/2023:12:33:27 -0600] Report: stringpool-total-bytes=13912
D [19/Jan/2023:12:33:27 -0600] [Client 16] Connection now encrypted.
D [19/Jan/2023:12:33:27 -0600] [Client 16] POST /printers/Brother_Polus HTTP/1.1
D [19/Jan/2023:12:33:27 -0600] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
D [19/Jan/2023:12:33:27 -0600] [Client 16] Read: status=200, state=6
D [19/Jan/2023:12:33:27 -0600] [Client 16] No authentication data provided.
D [19/Jan/2023:12:33:27 -0600] [Client 16] 2.0 Get-Printer-Attributes 1
D [19/Jan/2023:12:33:27 -0600] Get-Printer-Attributes ipps://polus.local.:631/printers/Brother_Polus
D [19/Jan/2023:12:33:27 -0600] [Client 16] Returning IPP successful-ok for Get-Printer-Attributes (ipps://polus.local.:631/printers/Brother_Polus) from 192.168.0.33.
D [19/Jan/2023:12:33:27 -0600] [Client 16] Content-Length: 1863
D [19/Jan/2023:12:33:27 -0600] [Client 16] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [19/Jan/2023:12:33:27 -0600] [Client 16] con->http=0x557083395360
D [19/Jan/2023:12:33:27 -0600] [Client 16] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=1863, response=0x55708339f440(IPP_STATE_DATA), pipe_pid=0, file=-1
D [19/Jan/2023:12:33:27 -0600] [Client 16] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [19/Jan/2023:12:33:27 -0600] [Client 16] bytes=0, http_state=0, data_remaining=1863
D [19/Jan/2023:12:33:27 -0600] [Client 16] Flushing write buffer.
D [19/Jan/2023:12:33:27 -0600] [Client 16] New state is HTTP_STATE_WAITING
D [19/Jan/2023:12:33:27 -0600] [Client 16] Waiting for request.
D [19/Jan/2023:12:33:27 -0600] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [19/Jan/2023:12:33:27 -0600] [Client 16] POST /printers/Brother_Polus HTTP/1.1
D [19/Jan/2023:12:33:27 -0600] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [19/Jan/2023:12:33:27 -0600] [Client 16] Read: status=200, state=6
D [19/Jan/2023:12:33:27 -0600] [Client 16] No authentication data provided.
D [19/Jan/2023:12:33:27 -0600] [Client 16] 2.0 Validate-Job 2
D [19/Jan/2023:12:33:27 -0600] Validate-Job ipps://polus.local.:631/printers/Brother_Polus
D [19/Jan/2023:12:33:27 -0600] [Client 16] Returning IPP successful-ok for Validate-Job (ipps://polus.local.:631/printers/Brother_Polus) from 192.168.0.33.
D [19/Jan/2023:12:33:27 -0600] [Client 16] Content-Length: 75
D [19/Jan/2023:12:33:27 -0600] [Client 16] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [19/Jan/2023:12:33:27 -0600] [Client 16] con->http=0x557083395360
D [19/Jan/2023:12:33:27 -0600] [Client 16] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=75, response=0x55708338f330(IPP_STATE_DATA), pipe_pid=0, file=-1
D [19/Jan/2023:12:33:27 -0600] [Client 16] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [19/Jan/2023:12:33:27 -0600] [Client 16] bytes=0, http_state=0, data_remaining=75
D [19/Jan/2023:12:33:27 -0600] [Client 16] Flushing write buffer.
D [19/Jan/2023:12:33:27 -0600] [Client 16] New state is HTTP_STATE_WAITING
D [19/Jan/2023:12:33:27 -0600] [Client 16] Waiting for request.
D [19/Jan/2023:12:33:27 -0600] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [19/Jan/2023:12:33:27 -0600] [Client 16] POST /printers/Brother_Polus HTTP/1.1
D [19/Jan/2023:12:33:27 -0600] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [19/Jan/2023:12:33:27 -0600] [Client 16] Read: status=200, state=6
D [19/Jan/2023:12:33:27 -0600] [Client 16] No authentication data provided.
D [19/Jan/2023:12:33:27 -0600] [Client 16] 2.0 Create-Job 3
D [19/Jan/2023:12:33:27 -0600] Create-Job ipps://polus.local.:631/printers/Brother_Polus
D [19/Jan/2023:12:33:27 -0600] cupsdMarkDirty(---J-)
D [19/Jan/2023:12:33:27 -0600] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients"
D [19/Jan/2023:12:33:27 -0600] [Job 1527] Applying default options...
D [19/Jan/2023:12:33:27 -0600] add_job: requesting-user-name="mmarchesini"
D [19/Jan/2023:12:33:27 -0600] Adding default job-sheets values "none,none"...
I [19/Jan/2023:12:33:27 -0600] [Job 1527] Adding start banner page "none".
D [19/Jan/2023:12:33:27 -0600] Discarding unused job-created event...
I [19/Jan/2023:12:33:27 -0600] [Job 1527] Queued on "Brother_Polus" by "mmarchesini".
D [19/Jan/2023:12:33:27 -0600] [Client 16] Returning IPP successful-ok for Create-Job (ipps://polus.local.:631/printers/Brother_Polus) from 192.168.0.33.
D [19/Jan/2023:12:33:27 -0600] [Client 16] Content-Length: 208
D [19/Jan/2023:12:33:27 -0600] [Client 16] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [19/Jan/2023:12:33:27 -0600] [Client 16] con->http=0x557083395360
D [19/Jan/2023:12:33:27 -0600] [Client 16] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=208, response=0x55708339f440(IPP_STATE_IDLE), pipe_pid=0, file=-1
D [19/Jan/2023:12:33:27 -0600] [Client 16] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [19/Jan/2023:12:33:27 -0600] [Client 16] bytes=0, http_state=0, data_remaining=208
D [19/Jan/2023:12:33:27 -0600] [Client 16] Flushing write buffer.
D [19/Jan/2023:12:33:27 -0600] [Client 16] New state is HTTP_STATE_WAITING
D [19/Jan/2023:12:33:27 -0600] [Client 16] Waiting for request.
D [19/Jan/2023:12:33:27 -0600] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [19/Jan/2023:12:33:27 -0600] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [19/Jan/2023:12:33:27 -0600] [Client 17] Server address is "192.168.0.4".
D [19/Jan/2023:12:33:27 -0600] [Client 17] Accepted from 192.168.0.33:59364 (IPv4)
D [19/Jan/2023:12:33:27 -0600] [Client 17] Waiting for request.
D [19/Jan/2023:12:33:27 -0600] [Client 17] Connection now encrypted.
D [19/Jan/2023:12:33:27 -0600] [Client 16] POST /printers/Brother_Polus HTTP/1.1
D [19/Jan/2023:12:33:27 -0600] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [19/Jan/2023:12:33:27 -0600] [Client 16] Read: status=200, state=6
D [19/Jan/2023:12:33:27 -0600] [Client 16] No authentication data provided.
D [19/Jan/2023:12:33:27 -0600] [Client 16] 2.0 Send-Document 4
D [19/Jan/2023:12:33:27 -0600] [Client 16] Read: status=100, state=6
D [19/Jan/2023:12:33:27 -0600] [Client 16] Read: status=100, state=6
D [19/Jan/2023:12:33:27 -0600] [Client 17] POST /printers/Brother_Polus HTTP/1.1
D [19/Jan/2023:12:33:27 -0600] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [19/Jan/2023:12:33:27 -0600] [Client 17] Read: status=200, state=6
D [19/Jan/2023:12:33:27 -0600] [Client 17] No authentication data provided.
D [19/Jan/2023:12:33:27 -0600] [Client 17] 2.0 Get-Printer-Attributes 5
D [19/Jan/2023:12:33:27 -0600] Get-Printer-Attributes ipps://polus.local.:631/printers/Brother_Polus
D [19/Jan/2023:12:33:27 -0600] [Client 17] Returning IPP successful-ok for Get-Printer-Attributes (ipps://polus.local.:631/printers/Brother_Polus) from 192.168.0.33.
D [19/Jan/2023:12:33:27 -0600] [Client 17] Content-Length: 1863
D [19/Jan/2023:12:33:27 -0600] [Client 17] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [19/Jan/2023:12:33:27 -0600] [Client 16] Read: status=100, state=6
D [19/Jan/2023:12:33:27 -0600] [Client 17] con->http=0x5570833ae360
D [19/Jan/2023:12:33:27 -0600] [Client 17] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=1863, response=0x5570833a1c10(IPP_STATE_DATA), pipe_pid=0, file=-1
D [19/Jan/2023:12:33:27 -0600] [Client 17] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [19/Jan/2023:12:33:27 -0600] [Client 17] bytes=0, http_state=0, data_remaining=1863
D [19/Jan/2023:12:33:27 -0600] [Client 17] Flushing write buffer.
D [19/Jan/2023:12:33:27 -0600] [Client 17] New state is HTTP_STATE_WAITING
D [19/Jan/2023:12:33:27 -0600] [Client 17] Waiting for request.
D [19/Jan/2023:12:33:27 -0600] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [19/Jan/2023:12:33:27 -0600] [Client 16] Read: status=100, state=6
D [19/Jan/2023:12:33:27 -0600] [Client 16] Read: status=100, state=6
D [19/Jan/2023:12:33:27 -0600] Send-Document ipps://polus.local.:631/printers/Brother_Polus
D [19/Jan/2023:12:33:27 -0600] cupsdIsAuthorized: requesting-user-name="mmarchesini"
D [19/Jan/2023:12:33:27 -0600] cupsdMarkDirty(---J-)
D [19/Jan/2023:12:33:27 -0600] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
I [19/Jan/2023:12:33:27 -0600] [Job 1527] File of type application/vnd.cups-postscript queued by "mmarchesini".
I [19/Jan/2023:12:33:27 -0600] [Job 1527] Adding end banner page "none".
D [19/Jan/2023:12:33:27 -0600] cupsdMarkDirty(---J-)
D [19/Jan/2023:12:33:27 -0600] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [19/Jan/2023:12:33:27 -0600] [Job 1527] time-at-processing=1674153207
D [19/Jan/2023:12:33:27 -0600] cupsdMarkDirty(---J-)
D [19/Jan/2023:12:33:27 -0600] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [19/Jan/2023:12:33:27 -0600] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [19/Jan/2023:12:33:27 -0600] Discarding unused printer-state-changed event...
D [19/Jan/2023:12:33:27 -0600] [Job 1527] 1 filters for job:
D [19/Jan/2023:12:33:27 -0600] [Job 1527] brother_lpdwrapper_HLL2325DW (application/vnd.cups-postscript to printer/Brother_Polus, cost 0)
D [19/Jan/2023:12:33:27 -0600] [Job 1527] job-sheets=none,none
D [19/Jan/2023:12:33:27 -0600] [Job 1527] argv[0]="Brother_Polus"
D [19/Jan/2023:12:33:27 -0600] [Job 1527] argv[1]="1527"
D [19/Jan/2023:12:33:27 -0600] [Job 1527] argv[2]="mmarchesini"
D [19/Jan/2023:12:33:27 -0600] [Job 1527] argv[3]="The Climate of History in a Planetary Age Dipesh Chakrabarty z-liborg.pdf"
D [19/Jan/2023:12:33:27 -0600] [Job 1527] argv[4]="1"
D [19/Jan/2023:12:33:27 -0600] [Job 1527] argv[5]="job-uuid=urn:uuid:a38ac996-ed0b-3181-52f8-23eb83599e7d job-originating-host-name=192.168.0.33 date-time-at-creation= date-time-at-processing= time-at-creation=1674153207 time-at-processing=1674153207"
D [19/Jan/2023:12:33:27 -0600] [Job 1527] argv[6]="/var/spool/cups/d01527-001"
D [19/Jan/2023:12:33:27 -0600] [Job 1527] envp[0]="CUPS_CACHEDIR=/var/cache/cups"
D [19/Jan/2023:12:33:27 -0600] [Job 1527] envp[1]="CUPS_DATADIR=/usr/share/cups"
D [19/Jan/2023:12:33:27 -0600] [Job 1527] envp[2]="CUPS_DOCROOT=/usr/share/cups/doc"
D [19/Jan/2023:12:33:27 -0600] [Job 1527] envp[3]="CUPS_REQUESTROOT=/var/spool/cups"
D [19/Jan/2023:12:33:27 -0600] [Job 1527] envp[4]="CUPS_SERVERBIN=/usr/lib/cups"
D [19/Jan/2023:12:33:27 -0600] [Job 1527] envp[5]="CUPS_SERVERROOT=/etc/cups"
D [19/Jan/2023:12:33:27 -0600] [Job 1527] envp[6]="CUPS_STATEDIR=/run/cups"
D [19/Jan/2023:12:33:27 -0600] [Job 1527] envp[7]="HOME=/var/spool/cups/tmp"
D [19/Jan/2023:12:33:27 -0600] [Job 1527] envp[8]="PATH=/usr/lib/cups/filter:/usr/bin:/usr/bin:/bin:/usr/bin"
D [19/Jan/2023:12:33:27 -0600] [Job 1527] envp[9]="SERVER_ADMIN=root@polus"
D [19/Jan/2023:12:33:27 -0600] [Job 1527] envp[10]="SOFTWARE=CUPS/2.4.2"
D [19/Jan/2023:12:33:27 -0600] [Job 1527] envp[11]="TMPDIR=/var/spool/cups/tmp"
D [19/Jan/2023:12:33:27 -0600] [Job 1527] envp[12]="USER=root"
D [19/Jan/2023:12:33:27 -0600] [Job 1527] envp[13]="CUPS_MAX_MESSAGE=2047"
D [19/Jan/2023:12:33:27 -0600] [Job 1527] envp[14]="CUPS_SERVER=/run/cups/cups.sock"
D [19/Jan/2023:12:33:27 -0600] [Job 1527] envp[15]="CUPS_ENCRYPTION=IfRequested"
D [19/Jan/2023:12:33:27 -0600] [Job 1527] envp[16]="IPP_PORT=631"
D [19/Jan/2023:12:33:27 -0600] [Job 1527] envp[17]="CHARSET=utf-8"
D [19/Jan/2023:12:33:27 -0600] [Job 1527] envp[18]="LANG=en_US.UTF-8"
D [19/Jan/2023:12:33:27 -0600] [Job 1527] envp[19]="PPD=/etc/cups/ppd/Brother_Polus.ppd"
D [19/Jan/2023:12:33:27 -0600] [Job 1527] envp[20]="CONTENT_TYPE=application/vnd.cups-postscript"
D [19/Jan/2023:12:33:27 -0600] [Job 1527] envp[21]="DEVICE_URI=usb://Brother/HL-L2325DW?serial=U65528F2N910977"
D [19/Jan/2023:12:33:27 -0600] [Job 1527] envp[22]="PRINTER_INFO=Brother_Polus"
D [19/Jan/2023:12:33:27 -0600] [Job 1527] envp[23]="PRINTER_LOCATION=Leo\'s room"
D [19/Jan/2023:12:33:27 -0600] [Job 1527] envp[24]="PRINTER=Brother_Polus"
D [19/Jan/2023:12:33:27 -0600] [Job 1527] envp[25]="PRINTER_STATE_REASONS=none"
D [19/Jan/2023:12:33:27 -0600] [Job 1527] envp[26]="CUPS_FILETYPE=document"
D [19/Jan/2023:12:33:27 -0600] [Job 1527] envp[27]="FINAL_CONTENT_TYPE=printer/Brother_Polus"
D [19/Jan/2023:12:33:27 -0600] [Job 1527] envp[28]="AUTH_I****"
I [19/Jan/2023:12:33:27 -0600] [Job 1527] Started filter /usr/lib/cups/filter/brother_lpdwrapper_HLL2325DW (PID 3056025)
I [19/Jan/2023:12:33:27 -0600] [Job 1527] Started backend /usr/lib/cups/backend/usb (PID 3056026)
D [19/Jan/2023:12:33:27 -0600] Discarding unused job-state-changed event...
D [19/Jan/2023:12:33:27 -0600] [Client 16] Returning IPP successful-ok for Send-Document (ipps://polus.local.:631/printers/Brother_Polus) from 192.168.0.33.
D [19/Jan/2023:12:33:27 -0600] [Client 16] Content-Length: 178
D [19/Jan/2023:12:33:27 -0600] [Client 16] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [19/Jan/2023:12:33:27 -0600] [Client 16] con->http=0x557083395360
D [19/Jan/2023:12:33:27 -0600] [Client 16] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=178, response=0x55708339bd30(IPP_STATE_DATA), pipe_pid=0, file=-1
D [19/Jan/2023:12:33:27 -0600] [Client 16] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [19/Jan/2023:12:33:27 -0600] [Client 16] bytes=0, http_state=0, data_remaining=178
D [19/Jan/2023:12:33:27 -0600] [Client 16] Flushing write buffer.
D [19/Jan/2023:12:33:27 -0600] [Client 16] New state is HTTP_STATE_WAITING
D [19/Jan/2023:12:33:27 -0600] [Client 16] Waiting for request.
D [19/Jan/2023:12:33:27 -0600] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients and dirty files"
D [19/Jan/2023:12:33:27 -0600] [Client 17] POST /printers/Brother_Polus HTTP/1.1
D [19/Jan/2023:12:33:27 -0600] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Printing jobs and dirty files"
D [19/Jan/2023:12:33:27 -0600] [Client 17] Read: status=200, state=6
D [19/Jan/2023:12:33:27 -0600] [Client 17] No authentication data provided.
D [19/Jan/2023:12:33:27 -0600] [Client 17] 2.0 Get-Job-Attributes 6
D [19/Jan/2023:12:33:27 -0600] Get-Job-Attributes ipps://polus.local.:631/printers/Brother_Polus
D [19/Jan/2023:12:33:27 -0600] [Client 17] Returning IPP successful-ok for Get-Job-Attributes (ipps://polus.local.:631/printers/Brother_Polus) from 192.168.0.33.
D [19/Jan/2023:12:33:27 -0600] [Client 17] Content-Length: 339
D [19/Jan/2023:12:33:27 -0600] [Client 17] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [19/Jan/2023:12:33:27 -0600] [Client 17] con->http=0x5570833ae360
D [19/Jan/2023:12:33:27 -0600] [Client 17] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=339, response=0x55708337f260(IPP_STATE_DATA), pipe_pid=0, file=-1
D [19/Jan/2023:12:33:27 -0600] [Client 17] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [19/Jan/2023:12:33:27 -0600] [Client 17] bytes=0, http_state=0, data_remaining=339
D [19/Jan/2023:12:33:27 -0600] [Client 17] Flushing write buffer.
D [19/Jan/2023:12:33:27 -0600] [Client 17] New state is HTTP_STATE_WAITING
D [19/Jan/2023:12:33:27 -0600] [Client 17] Waiting for request.
D [19/Jan/2023:12:33:27 -0600] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients, printing jobs, and dirty files"
D [19/Jan/2023:12:33:27 -0600] [Client 16] POST /printers/Brother_Polus HTTP/1.1
D [19/Jan/2023:12:33:27 -0600] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Printing jobs and dirty files"
D [19/Jan/2023:12:33:27 -0600] [Client 16] Read: status=200, state=6
D [19/Jan/2023:12:33:27 -0600] [Client 16] No authentication data provided.
D [19/Jan/2023:12:33:27 -0600] [Client 16] 2.0 Get-Printer-Attributes 7
D [19/Jan/2023:12:33:27 -0600] Get-Printer-Attributes ipps://polus.local.:631/printers/Brother_Polus
D [19/Jan/2023:12:33:27 -0600] [Client 16] Returning IPP successful-ok for Get-Printer-Attributes (ipps://polus.local.:631/printers/Brother_Polus) from 192.168.0.33.
D [19/Jan/2023:12:33:27 -0600] [Client 16] Content-Length: 1863
D [19/Jan/2023:12:33:27 -0600] [Client 16] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [19/Jan/2023:12:33:27 -0600] [Client 16] con->http=0x557083395360
D [19/Jan/2023:12:33:27 -0600] [Client 16] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=1863, response=0x5570833a7ea0(IPP_STATE_DATA), pipe_pid=0, file=-1
D [19/Jan/2023:12:33:27 -0600] [Client 16] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [19/Jan/2023:12:33:27 -0600] [Client 16] bytes=0, http_state=0, data_remaining=1863
D [19/Jan/2023:12:33:27 -0600] [Client 16] Flushing write buffer.
D [19/Jan/2023:12:33:27 -0600] [Client 16] New state is HTTP_STATE_WAITING
D [19/Jan/2023:12:33:27 -0600] [Client 16] Waiting for request.
D [19/Jan/2023:12:33:27 -0600] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients, printing jobs, and dirty files"
D [19/Jan/2023:12:33:27 -0600] [Job 1527] Loading USB quirks from \"/usr/share/cups/usb\".
D [19/Jan/2023:12:33:27 -0600] [Job 1527] Loaded 216 quirks.
D [19/Jan/2023:12:33:27 -0600] [Job 1527] Printing on printer with URI: usb://Brother/HL-L2325DW?serial=U65528F2N910977
D [19/Jan/2023:12:33:27 -0600] [Job 1527] libusb_get_device_list=8
D [19/Jan/2023:12:33:27 -0600] [Job 1527] STATE: +connecting-to-device
D [19/Jan/2023:12:33:27 -0600] cupsdMarkDirty(---J-)
D [19/Jan/2023:12:33:27 -0600] cupsdSetBusyState: newbusy="Dirty files", busy="Printing jobs and dirty files"
D [19/Jan/2023:12:33:27 -0600] Discarding unused printer-state-changed event...
D [19/Jan/2023:12:33:27 -0600] [Client 16] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [19/Jan/2023:12:33:27 -0600] [Client 16] Closing connection.
D [19/Jan/2023:12:33:27 -0600] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [19/Jan/2023:12:33:27 -0600] [Client 16] Waiting for socket close.
D [19/Jan/2023:12:33:27 -0600] [Client 16] Closing on EOF.
D [19/Jan/2023:12:33:27 -0600] [Client 16] Closing connection.
D [19/Jan/2023:12:33:27 -0600] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [19/Jan/2023:12:33:27 -0600] [Job 1527] STATE: -connecting-to-device
D [19/Jan/2023:12:33:27 -0600] cupsdMarkDirty(---J-)
D [19/Jan/2023:12:33:27 -0600] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Dirty files"
D [19/Jan/2023:12:33:27 -0600] Discarding unused printer-state-changed event...
D [19/Jan/2023:12:33:27 -0600] [Job 1527] Device protocol: 2
D [19/Jan/2023:12:33:27 -0600] [Job 1527] Sending data to printer.
D [19/Jan/2023:12:33:27 -0600] cupsdMarkDirty(---J-)
D [19/Jan/2023:12:33:27 -0600] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [19/Jan/2023:12:33:27 -0600] [Job 1527] Set job-printer-state-message to "Sending data to printer.", current level=INFO
D [19/Jan/2023:12:33:27 -0600] Discarding unused job-progress event...
D [19/Jan/2023:12:33:27 -0600] Discarding unused printer-state-changed event...
D [19/Jan/2023:12:33:27 -0600] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Printing jobs and dirty files"
D [19/Jan/2023:12:33:27 -0600] [Client 18] Server address is "192.168.0.4".
D [19/Jan/2023:12:33:27 -0600] [Client 18] Accepted from 192.168.0.33:59365 (IPv4)
D [19/Jan/2023:12:33:27 -0600] [Client 18] Waiting for request.
D [19/Jan/2023:12:33:27 -0600] [Client 18] Connection now encrypted.
D [19/Jan/2023:12:33:27 -0600] [Client 18] POST /printers/Brother_Polus HTTP/1.1
D [19/Jan/2023:12:33:27 -0600] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Active clients, printing jobs, and dirty files"
D [19/Jan/2023:12:33:27 -0600] [Client 18] Read: status=200, state=6
D [19/Jan/2023:12:33:27 -0600] [Client 18] No authentication data provided.
D [19/Jan/2023:12:33:27 -0600] [Client 18] 2.0 Get-Job-Attributes 8
D [19/Jan/2023:12:33:27 -0600] Get-Job-Attributes ipps://polus.local.:631/printers/Brother_Polus
D [19/Jan/2023:12:33:27 -0600] [Client 18] Returning IPP successful-ok for Get-Job-Attributes (ipps://polus.local.:631/printers/Brother_Polus) from 192.168.0.33.
D [19/Jan/2023:12:33:27 -0600] [Client 18] Content-Length: 339
D [19/Jan/2023:12:33:27 -0600] [Client 18] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [19/Jan/2023:12:33:27 -0600] [Client 18] con->http=0x557083395360
D [19/Jan/2023:12:33:27 -0600] [Client 18] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=339, response=0x55708339f990(IPP_STATE_DATA), pipe_pid=0, file=-1
D [19/Jan/2023:12:33:27 -0600] [Client 18] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [19/Jan/2023:12:33:27 -0600] [Client 18] bytes=0, http_state=0, data_remaining=339
D [19/Jan/2023:12:33:27 -0600] [Client 18] Flushing write buffer.
D [19/Jan/2023:12:33:27 -0600] [Client 18] New state is HTTP_STATE_WAITING
D [19/Jan/2023:12:33:27 -0600] [Client 18] Waiting for request.
D [19/Jan/2023:12:33:27 -0600] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients, printing jobs, and dirty files"
D [19/Jan/2023:12:33:27 -0600] [Job 1527] Read 665 bytes of print data...
D [19/Jan/2023:12:33:27 -0600] [Job 1527] Wrote 665 bytes of print data...
D [19/Jan/2023:12:33:27 -0600] [Job 1527] PID 3056025 (/usr/lib/cups/filter/brother_lpdwrapper_HLL2325DW) exited with no errors.
D [19/Jan/2023:12:33:27 -0600] [Job 1527] Sent 665 bytes...
D [19/Jan/2023:12:33:27 -0600] [Job 1527] Waiting for read thread to exit...
D [19/Jan/2023:12:33:27 -0600] [Job 1527] PID 3056026 (/usr/lib/cups/backend/usb) exited with no errors.
D [19/Jan/2023:12:33:27 -0600] [Job 1527] time-at-completed=1674153207
D [19/Jan/2023:12:33:27 -0600] Discarding unused job-completed event...
I [19/Jan/2023:12:33:27 -0600] [Job 1527] Job completed.
D [19/Jan/2023:12:33:27 -0600] cupsdMarkDirty(---J-)
D [19/Jan/2023:12:33:27 -0600] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [19/Jan/2023:12:33:27 -0600] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [19/Jan/2023:12:33:27 -0600] Discarding unused printer-state-changed event...
D [19/Jan/2023:12:33:27 -0600] cupsdMarkDirty(---J-)
D [19/Jan/2023:12:33:27 -0600] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [19/Jan/2023:12:33:28 -0600] [Client 17] POST /printers/Brother_Polus HTTP/1.1
D [19/Jan/2023:12:33:28 -0600] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Printing jobs and dirty files"
D [19/Jan/2023:12:33:28 -0600] [Client 17] Read: status=200, state=6
D [19/Jan/2023:12:33:28 -0600] [Client 17] No authentication data provided.
D [19/Jan/2023:12:33:28 -0600] [Job 1527] Unloading...
D [19/Jan/2023:12:33:28 -0600] [Client 17] Read: status=100, state=6
D [19/Jan/2023:12:33:28 -0600] [Client 17] 2.0 Get-Printer-Attributes 9
D [19/Jan/2023:12:33:28 -0600] Get-Printer-Attributes ipps://polus.local.:631/printers/Brother_Polus
D [19/Jan/2023:12:33:28 -0600] [Client 17] Returning IPP successful-ok for Get-Printer-Attributes (ipps://polus.local.:631/printers/Brother_Polus) from 192.168.0.33.
D [19/Jan/2023:12:33:28 -0600] [Client 17] Content-Length: 1863
D [19/Jan/2023:12:33:28 -0600] [Client 17] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [19/Jan/2023:12:33:28 -0600] [Client 17] con->http=0x5570833ae360
D [19/Jan/2023:12:33:28 -0600] [Client 17] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=1863, response=0x557083390eb0(IPP_STATE_DATA), pipe_pid=0, file=-1
D [19/Jan/2023:12:33:28 -0600] [Client 17] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [19/Jan/2023:12:33:28 -0600] [Client 17] bytes=0, http_state=0, data_remaining=1863
D [19/Jan/2023:12:33:28 -0600] [Client 17] Flushing write buffer.
D [19/Jan/2023:12:33:28 -0600] [Client 17] New state is HTTP_STATE_WAITING
D [19/Jan/2023:12:33:28 -0600] [Client 17] Waiting for request.
D [19/Jan/2023:12:33:28 -0600] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [19/Jan/2023:12:33:28 -0600] [Client 17] POST /printers/Brother_Polus HTTP/1.1
D [19/Jan/2023:12:33:28 -0600] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [19/Jan/2023:12:33:28 -0600] [Client 17] Read: status=200, state=6
D [19/Jan/2023:12:33:28 -0600] [Client 17] No authentication data provided.
D [19/Jan/2023:12:33:28 -0600] [Client 17] 2.0 Get-Job-Attributes 10
D [19/Jan/2023:12:33:28 -0600] Get-Job-Attributes ipps://polus.local.:631/printers/Brother_Polus
D [19/Jan/2023:12:33:28 -0600] [Job 1527] Loading attributes...
D [19/Jan/2023:12:33:28 -0600] [Client 17] Returning IPP successful-ok for Get-Job-Attributes (ipps://polus.local.:631/printers/Brother_Polus) from 192.168.0.33.
D [19/Jan/2023:12:33:28 -0600] [Client 17] Content-Length: 351
D [19/Jan/2023:12:33:28 -0600] [Client 17] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [19/Jan/2023:12:33:28 -0600] [Client 17] con->http=0x5570833ae360
D [19/Jan/2023:12:33:28 -0600] [Client 17] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=351, response=0x5570833711e0(IPP_STATE_DATA), pipe_pid=0, file=-1
D [19/Jan/2023:12:33:28 -0600] [Client 17] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [19/Jan/2023:12:33:28 -0600] [Client 17] bytes=0, http_state=0, data_remaining=351
D [19/Jan/2023:12:33:28 -0600] [Client 17] Flushing write buffer.
D [19/Jan/2023:12:33:28 -0600] [Client 17] New state is HTTP_STATE_WAITING
D [19/Jan/2023:12:33:28 -0600] [Client 17] Waiting for request.
D [19/Jan/2023:12:33:28 -0600] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [19/Jan/2023:12:33:28 -0600] [Client 18] POST /printers/Brother_Polus HTTP/1.1
D [19/Jan/2023:12:33:28 -0600] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [19/Jan/2023:12:33:28 -0600] [Client 18] Read: status=200, state=6
D [19/Jan/2023:12:33:28 -0600] [Client 18] No authentication data provided.
D [19/Jan/2023:12:33:28 -0600] [Client 18] Read: status=100, state=6
D [19/Jan/2023:12:33:28 -0600] [Client 18] 2.0 Get-Printer-Attributes 11
D [19/Jan/2023:12:33:28 -0600] Get-Printer-Attributes ipps://polus.local.:631/printers/Brother_Polus
D [19/Jan/2023:12:33:28 -0600] [Client 18] Returning IPP successful-ok for Get-Printer-Attributes (ipps://polus.local.:631/printers/Brother_Polus) from 192.168.0.33.
D [19/Jan/2023:12:33:28 -0600] [Client 18] Content-Length: 1863
D [19/Jan/2023:12:33:28 -0600] [Client 18] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [19/Jan/2023:12:33:28 -0600] [Client 18] con->http=0x557083395360
D [19/Jan/2023:12:33:28 -0600] [Client 18] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=1863, response=0x5570833b6420(IPP_STATE_DATA), pipe_pid=0, file=-1
D [19/Jan/2023:12:33:28 -0600] [Client 18] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [19/Jan/2023:12:33:28 -0600] [Client 18] bytes=0, http_state=0, data_remaining=1863
D [19/Jan/2023:12:33:28 -0600] [Client 18] Flushing write buffer.
D [19/Jan/2023:12:33:28 -0600] [Client 18] New state is HTTP_STATE_WAITING
D [19/Jan/2023:12:33:28 -0600] [Client 18] Waiting for request.
D [19/Jan/2023:12:33:28 -0600] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [19/Jan/2023:12:33:28 -0600] [Client 18] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [19/Jan/2023:12:33:28 -0600] [Client 18] Closing connection.
D [19/Jan/2023:12:33:28 -0600] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [19/Jan/2023:12:33:28 -0600] [Client 18] Waiting for socket close.
D [19/Jan/2023:12:33:28 -0600] [Client 18] Closing on EOF.
D [19/Jan/2023:12:33:28 -0600] [Client 18] Closing connection.
D [19/Jan/2023:12:33:28 -0600] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [19/Jan/2023:12:33:28 -0600] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [19/Jan/2023:12:33:28 -0600] [Client 19] Server address is "192.168.0.4".
D [19/Jan/2023:12:33:28 -0600] [Client 19] Accepted from 192.168.0.33:59366 (IPv4)
D [19/Jan/2023:12:33:28 -0600] [Client 19] Waiting for request.
D [19/Jan/2023:12:33:28 -0600] [Client 19] Connection now encrypted.
D [19/Jan/2023:12:33:28 -0600] [Client 19] POST /printers/Brother_Polus HTTP/1.1
D [19/Jan/2023:12:33:28 -0600] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [19/Jan/2023:12:33:28 -0600] [Client 19] Read: status=200, state=6
D [19/Jan/2023:12:33:28 -0600] [Client 19] No authentication data provided.
D [19/Jan/2023:12:33:28 -0600] [Client 19] 2.0 Get-Job-Attributes 12
D [19/Jan/2023:12:33:28 -0600] Get-Job-Attributes ipps://polus.local.:631/printers/Brother_Polus
D [19/Jan/2023:12:33:28 -0600] [Client 19] Returning IPP successful-ok for Get-Job-Attributes (ipps://polus.local.:631/printers/Brother_Polus) from 192.168.0.33.
D [19/Jan/2023:12:33:28 -0600] [Client 19] Content-Length: 351
D [19/Jan/2023:12:33:28 -0600] [Client 19] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [19/Jan/2023:12:33:28 -0600] [Client 19] con->http=0x557083395360
D [19/Jan/2023:12:33:28 -0600] [Client 19] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=351, response=0x557083389880(IPP_STATE_DATA), pipe_pid=0, file=-1
D [19/Jan/2023:12:33:28 -0600] [Client 19] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [19/Jan/2023:12:33:28 -0600] [Client 19] bytes=0, http_state=0, data_remaining=351
D [19/Jan/2023:12:33:28 -0600] [Client 19] Flushing write buffer.
D [19/Jan/2023:12:33:28 -0600] [Client 19] New state is HTTP_STATE_WAITING
D [19/Jan/2023:12:33:28 -0600] [Client 19] Waiting for request.
D [19/Jan/2023:12:33:28 -0600] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [19/Jan/2023:12:33:28 -0600] [Client 19] POST /printers/Brother_Polus HTTP/1.1
D [19/Jan/2023:12:33:28 -0600] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [19/Jan/2023:12:33:28 -0600] [Client 19] Read: status=200, state=6
D [19/Jan/2023:12:33:28 -0600] [Client 19] No authentication data provided.
D [19/Jan/2023:12:33:28 -0600] [Client 19] 2.0 Get-Printer-Attributes 13
D [19/Jan/2023:12:33:28 -0600] Get-Printer-Attributes ipps://polus.local.:631/printers/Brother_Polus
D [19/Jan/2023:12:33:28 -0600] [Client 19] Returning IPP successful-ok for Get-Printer-Attributes (ipps://polus.local.:631/printers/Brother_Polus) from 192.168.0.33.
D [19/Jan/2023:12:33:28 -0600] [Client 19] Content-Length: 1863
D [19/Jan/2023:12:33:28 -0600] [Client 19] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [19/Jan/2023:12:33:28 -0600] [Client 19] con->http=0x557083395360
D [19/Jan/2023:12:33:28 -0600] [Client 19] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=1863, response=0x5570833b6420(IPP_STATE_DATA), pipe_pid=0, file=-1
D [19/Jan/2023:12:33:28 -0600] [Client 19] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [19/Jan/2023:12:33:28 -0600] [Client 19] bytes=0, http_state=0, data_remaining=1863
D [19/Jan/2023:12:33:28 -0600] [Client 19] Flushing write buffer.
D [19/Jan/2023:12:33:28 -0600] [Client 19] New state is HTTP_STATE_WAITING
D [19/Jan/2023:12:33:28 -0600] [Client 19] Waiting for request.
D [19/Jan/2023:12:33:28 -0600] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [19/Jan/2023:12:33:28 -0600] [Client 19] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [19/Jan/2023:12:33:28 -0600] [Client 19] Closing connection.
D [19/Jan/2023:12:33:28 -0600] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [19/Jan/2023:12:33:28 -0600] [Client 19] Waiting for socket close.
D [19/Jan/2023:12:33:28 -0600] [Client 19] Closing on EOF.
D [19/Jan/2023:12:33:28 -0600] [Client 19] Closing connection.
D [19/Jan/2023:12:33:28 -0600] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [19/Jan/2023:12:33:28 -0600] [Client 17] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [19/Jan/2023:12:33:28 -0600] [Client 17] Closing connection.
D [19/Jan/2023:12:33:28 -0600] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [19/Jan/2023:12:33:28 -0600] [Client 17] Waiting for socket close.
D [19/Jan/2023:12:33:28 -0600] [Client 17] Closing on EOF.
D [19/Jan/2023:12:33:28 -0600] [Client 17] Closing connection.
D [19/Jan/2023:12:33:28 -0600] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
I [19/Jan/2023:12:33:58 -0600] Saving job.cache...
D [19/Jan/2023:12:33:58 -0600] cupsdSetBusyState: newbusy="Not busy", busy="Dirty files"

Now the addresses reported by cups are all IPv4 and they are all correct (.33 is the mac, .04 is the print server). The mac user is also correctly reported, but then the connection is closed and no print job is generated.

seth wrote:

Can you ping the IPv4 LAN IP as well?

Yes.

seth wrote:

How do you address the print server from the macbook?
CUPS_SERVER environment, avahi (BonJours) or w/ an IPP url? (or less likely lpd or smb)
In case of the latter: domain, IPv4 or IPv6?

I chose the printer from the mac's printer selection dialog (I forget what's called), where it is listed as  Bonjour shared.

Offline

#9 2023-01-19 20:58:24

seth
Member
From: Won't reply 2 private help req
Registered: 2012-09-03
Posts: 76,403

Re: Print server rejects jobs from a local (but externally managed) mac

D [19/Jan/2023:12:33:27 -0600] [Job 1527] argv[3]="The Climate of History in a Planetary Age Dipesh Chakrabarty z-liborg.pdf"
…
D [19/Jan/2023:12:33:27 -0600] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients, printing jobs, and dirty files"
D [19/Jan/2023:12:33:27 -0600] [Job 1527] Read 665 bytes of print data...
D [19/Jan/2023:12:33:27 -0600] [Job 1527] Wrote 665 bytes of print data...
D [19/Jan/2023:12:33:27 -0600] [Job 1527] PID 3056025 (/usr/lib/cups/filter/brother_lpdwrapper_HLL2325DW) exited with no errors.
D [19/Jan/2023:12:33:27 -0600] [Job 1527] Sent 665 bytes...
D [19/Jan/2023:12:33:27 -0600] [Job 1527] Waiting for read thread to exit...
D [19/Jan/2023:12:33:27 -0600] [Job 1527] PID 3056026 (/usr/lib/cups/backend/usb) exited with no errors.

665 bytes seems a rather short history then…

Try to
a) use the https://archlinux.org/packages/extra/x86_64/cups-pdf/ printer for testing purposes
b) print some other document (some ascii text, maybe?) to make sure there's no DRM interference (did you try that very document from one of the working systems?) and the mac also doesn't pre-process the document. See whether you can set the mac to "raw", https://wiki.archlinux.org/title/CUPS#Network_2

How to upload text · How to boot w/o GUI · Disable Windows Fast-Start! · Fix your xinitrc

Online

Pages: 1

Board footer

Powered by FluxBB