Scheduled Maintenance: We are aware of an issue with Google, AOL, and Yahoo services as email providers which are blocking new registrations. We are trying to fix the issue and we have several internal and external support tickets in process to resolve the issue. Please see: viewtopic.php?t=158230

 

 

 

Installing Brother HL-3152CDW Printer

Need help with peripherals or devices?
Post Reply
Message
Author
Mad-Din
Posts: 10
Joined: 2017-10-21 11:48
Has thanked: 1 time

Installing Brother HL-3152CDW Printer

#1 Post by Mad-Din »

Hello,

I'm trying to get my Brother HL-3152CDW Printer working on my newly installed Debian System:

Code: Select all

martin@zuul:~$ cat /etc/*-release
PRETTY_NAME="Debian GNU/Linux 9 (stretch)"
NAME="Debian GNU/Linux"
VERSION_ID="9"
VERSION="9 (stretch)"
ID=debian
HOME_URL="https://www.debian.org/"
SUPPORT_URL="https://www.debian.org/support"
BUG_REPORT_URL="https://bugs.debian.org/"
martin@zuul:~$ cat /etc/debian_version 
9.3
I added i386 architecture, I installed the deb packages from the Brother homepage (http://support.brother.com/g/b/download ... _eu&os=128), everything seemed to work perfect. When I installed the cups-wrapper package the printer was found, and later when I plugged in the USB cord, the printer also got recognizes with the correct type and a printer queue was automatically added. I don't get any error messages when printing test pages, the only problem is, that the printer doesn't print.

Can anybody give me a hint how to get the printer printing, respectively how to get any further information about the reason for not willing to print?

Thank you for your help,
Martin

shep
Posts: 423
Joined: 2011-03-15 15:22

Re: Installing Brother HL-3152CDW Printer

#2 Post by shep »

According to Brother's documentation, the printer needs a GDI data stream:http://support.brother.com/g/b/spec.asp ... 3152cdw_eu. For future readers, the HL-3172CDW additionally supports PCL6 and Postscript which will work natively in X86_64. GDI only printers will only work with a pre-compiled, closed source binary "blob" from Brother. Brother also only provides an i386 "blob"; not an X86_64.

So you are basically stuck using Brothers Documentation. It is likely that your print jobs are dying at the blob. This can happen for the following reasons:
1) The blob is poorly coded and fails
2) Cups cannot find the blob,. The /opt directory is often used in the EU for 3rd party software but Cups in Debian is looking in /usr/share or /usr/lib.
3) Cups finds the blob but cannot execute it due to permissions.

Code: Select all

/var/log/cups/error_log
should tell you if cups cannot find the blob or execute the blob.

The other option is there are some German language forum posts on this specific problem that can be found with a search engine. Maybe those will help

peter_irich
Posts: 1403
Joined: 2009-09-10 20:15
Location: Saint-Petersburg, Russian Federation
Been thanked: 11 times

Re: Installing Brother HL-3152CDW Printer

#3 Post by peter_irich »

Try tweak printer from the web interface, enter in browser in the address string
localhost:631

Peter.

Mad-Din
Posts: 10
Joined: 2017-10-21 11:48
Has thanked: 1 time

Re: Installing Brother HL-3152CDW Printer

#4 Post by Mad-Din »

Hello,

first - thanks for your reply, I really appreciate any help on that topic.

@peter_irich: I allready did this before I started this topic, but I again tried some different drivers from the cups administration interface, the best result was the printer endlessly producing blank sheets of paper. So no idea what else to tweak.
@shed: I had a look at the error log, as you adviced, but even when I send a test page, there is no log-entry that helps me figuring out where the problem is.
I don't wanna annoy you with miles of log output, but if you're in the mood, than you might wanna have a look at what happens during testpage printing a the code section at the bottom of this post. (I had to shorten it in the beginning, because the max number of letters was exceeded)

It's really weired, because I'm quite sure the printer was working on my old Debian system, which doesn't exist anymore and which I upgraded from wheezy over lenny to stretch.
Could it be, that there is just a required package missing?

Whatever... I started a service-call at the brother service hotline and if they (or their documentation) will open up a solution for my problem, then I'll get back here and write a note.

Again, thanks for your help,
Martin

Code: Select all

...
D [26/Feb/2018:18:48:29 +0100] [Client 126] Accepted from localhost:38212 (IPv6)
D [26/Feb/2018:18:48:29 +0100] [Client 126] Waiting for request.
I [26/Feb/2018:18:48:29 +0100] Expiring subscriptions...
D [26/Feb/2018:18:48:29 +0100] [Client 125] POST /printers/HL-3152CDW-series HTTP/1.1
D [26/Feb/2018:18:48:29 +0100] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [26/Feb/2018:18:48:29 +0100] [Client 125] Read: status=200
D [26/Feb/2018:18:48:29 +0100] [Client 125] Authorized as "martin" using Basic.
D [26/Feb/2018:18:48:29 +0100] [CGI] argv[0] = "/usr/lib/cups/cgi-bin/printers.cgi"
D [26/Feb/2018:18:48:29 +0100] [CGI] envp[0] = "CUPS_CACHEDIR=/var/cache/cups"
D [26/Feb/2018:18:48:29 +0100] [CGI] envp[1] = "CUPS_DATADIR=/usr/share/cups"
D [26/Feb/2018:18:48:29 +0100] [CGI] envp[2] = "CUPS_DOCROOT=/usr/share/cups/doc-root"
D [26/Feb/2018:18:48:29 +0100] [CGI] envp[3] = "CUPS_FONTPATH=/usr/share/cups/fonts"
D [26/Feb/2018:18:48:29 +0100] [CGI] envp[4] = "CUPS_REQUESTROOT=/var/spool/cups"
D [26/Feb/2018:18:48:29 +0100] [CGI] envp[5] = "CUPS_SERVERBIN=/usr/lib/cups"
D [26/Feb/2018:18:48:29 +0100] [CGI] envp[6] = "CUPS_SERVERROOT=/etc/cups"
D [26/Feb/2018:18:48:29 +0100] [CGI] envp[7] = "CUPS_STATEDIR=/var/run/cups"
D [26/Feb/2018:18:48:29 +0100] [CGI] envp[8] = "HOME=/var/spool/cups/tmp"
D [26/Feb/2018:18:48:29 +0100] [CGI] envp[9] = "PATH=/usr/lib/cups/filter:/usr/bin:/usr/sbin:/bin:/usr/bin"
D [26/Feb/2018:18:48:29 +0100] [CGI] envp[10] = "SERVER_ADMIN=root@zuul"
D [26/Feb/2018:18:48:29 +0100] [CGI] envp[11] = "SOFTWARE=CUPS/2.2.1"
D [26/Feb/2018:18:48:29 +0100] [CGI] envp[12] = "TMPDIR=/var/spool/cups/tmp"
D [26/Feb/2018:18:48:29 +0100] [CGI] envp[13] = "USER=root"
D [26/Feb/2018:18:48:29 +0100] [CGI] envp[14] = "CUPS_MAX_MESSAGE=2047"
D [26/Feb/2018:18:48:29 +0100] [CGI] envp[15] = "CUPS_SERVER=/var/run/cups/cups.sock"
D [26/Feb/2018:18:48:29 +0100] [CGI] envp[16] = "CUPS_ENCRYPTION=IfRequested"
D [26/Feb/2018:18:48:29 +0100] [CGI] envp[17] = "IPP_PORT=631"
D [26/Feb/2018:18:48:29 +0100] [CGI] envp[18] = "AUTH_TYPE=Basic"
D [26/Feb/2018:18:48:29 +0100] [CGI] envp[19] = "LANG=en_US.UTF8"
D [26/Feb/2018:18:48:29 +0100] [CGI] envp[20] = "REDIRECT_STATUS=1"
D [26/Feb/2018:18:48:29 +0100] [CGI] envp[21] = "GATEWAY_INTERFACE=CGI/1.1"
D [26/Feb/2018:18:48:29 +0100] [CGI] envp[22] = "SERVER_NAME=localhost"
D [26/Feb/2018:18:48:29 +0100] [CGI] envp[23] = "SERVER_PORT=631"
D [26/Feb/2018:18:48:29 +0100] [CGI] envp[24] = "REMOTE_ADDR=[v1.::1]"
D [26/Feb/2018:18:48:29 +0100] [CGI] envp[25] = "REMOTE_HOST=localhost"
D [26/Feb/2018:18:48:29 +0100] [CGI] envp[26] = "SCRIPT_NAME=/printers/HL-3152CDW-series"
D [26/Feb/2018:18:48:29 +0100] [CGI] envp[27] = "SCRIPT_FILENAME=/usr/share/cups/doc-root/printers/HL-3152CDW-series"
D [26/Feb/2018:18:48:29 +0100] [CGI] envp[28] = "PATH_INFO=/HL-3152CDW-series"
D [26/Feb/2018:18:48:29 +0100] [CGI] envp[29] = "REMOTE_USER=martin"
D [26/Feb/2018:18:48:29 +0100] [CGI] envp[30] = "SERVER_PROTOCOL=HTTP/1.1"
D [26/Feb/2018:18:48:29 +0100] [CGI] envp[31] = "HTTP_COOKIE=org.cups.sid=254d17f8915429dcd47c9f7266cc62a2"
D [26/Feb/2018:18:48:29 +0100] [CGI] envp[32] = "HTTP_USER_AGENT=Mozilla/5.0 (X11; Linux x86_64; rv:52.0) Gecko/20100101 Firefox/52.0"
D [26/Feb/2018:18:48:29 +0100] [CGI] envp[33] = "HTTP_REFERER=http://localhost:631/printers/HL-3152CDW-series"
D [26/Feb/2018:18:48:29 +0100] [CGI] envp[34] = "REQUEST_METHOD=POST"
D [26/Feb/2018:18:48:29 +0100] [CGI] envp[35] = "CONTENT_LENGTH=64"
D [26/Feb/2018:18:48:29 +0100] [CGI] envp[36] = "CONTENT_TYPE=application/x-www-form-urlencoded"
D [26/Feb/2018:18:48:29 +0100] cupsdAddCert: Adding certificate for PID 2608
D [26/Feb/2018:18:48:29 +0100] [CGI] Started /usr/lib/cups/cgi-bin/printers.cgi (PID 2608)
I [26/Feb/2018:18:48:29 +0100] [Client 125] Started "/usr/lib/cups/cgi-bin/printers.cgi" (pid=2608, file=18)
...
D [26/Feb/2018:18:48:29 +0100] Print-Job ipp://localhost:631/printers/HL-3152CDW-series
D [26/Feb/2018:18:48:29 +0100] [Job ???] Auto-typing file...
I [26/Feb/2018:18:48:29 +0100] [Job ???] Request file type is application/vnd.cups-pdf-banner.
D [26/Feb/2018:18:48:29 +0100] cupsdMarkDirty(---J-)
D [26/Feb/2018:18:48:29 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients"
D [26/Feb/2018:18:48:29 +0100] add_job: requesting-user-name="martin"
D [26/Feb/2018:18:48:29 +0100] Adding default job-sheets values "none,none"...
I [26/Feb/2018:18:48:29 +0100] [Job 53] Adding start banner page "none".
D [26/Feb/2018:18:48:29 +0100] cupsdMarkDirty(----S)
D [26/Feb/2018:18:48:29 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [26/Feb/2018:18:48:29 +0100] cupsdMarkDirty(---J-)
D [26/Feb/2018:18:48:29 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
I [26/Feb/2018:18:48:29 +0100] [Job 53] Adding end banner page "none".
I [26/Feb/2018:18:48:29 +0100] [Job 53] File of type application/vnd.cups-pdf-banner queued by "martin".
D [26/Feb/2018:18:48:29 +0100] [Job 53] hold_until=0
I [26/Feb/2018:18:48:29 +0100] [Job 53] Queued on "HL-3152CDW-series" by "martin".
D [26/Feb/2018:18:48:29 +0100] [Job 53] time-at-processing=1519667309
...
D [26/Feb/2018:18:48:29 +0100] [Job 53] argv[0]="HL-3152CDW-series"
D [26/Feb/2018:18:48:29 +0100] [Job 53] argv[1]="53"
D [26/Feb/2018:18:48:29 +0100] [Job 53] argv[2]="martin"
D [26/Feb/2018:18:48:29 +0100] [Job 53] argv[3]="Test Page"
D [26/Feb/2018:18:48:29 +0100] [Job 53] argv[4]="1"
D [26/Feb/2018:18:48:29 +0100] [Job 53] argv[5]="job-uuid=urn:uuid:74bd1147-962a-3a38-4384-214e7473c77c job-originating-host-name=localhost date-time-at-creation= date-time-at-processing= time-at-creation=1519667309 time-at-processing=1519667309"
...
I [26/Feb/2018:18:48:29 +0100] [Job 53] Started filter /usr/lib/cups/filter/bannertopdf (PID 2609)
I [26/Feb/2018:18:48:29 +0100] [Job 53] Started filter /usr/lib/cups/filter/pdftopdf (PID 2610)
I [26/Feb/2018:18:48:29 +0100] [Job 53] Started filter /usr/lib/cups/filter/pdftops (PID 2611)
I [26/Feb/2018:18:48:29 +0100] [Job 53] Started filter /usr/lib/cups/filter/brother_lpdwrapper_hl3152cdw (PID 2612)
I [26/Feb/2018:18:48:29 +0100] [Job 53] Started backend /usr/lib/cups/backend/usb (PID 2613)
D [26/Feb/2018:18:48:29 +0100] cupsdMarkDirty(----S)
D [26/Feb/2018:18:48:29 +0100] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Active clients and dirty files"
D [26/Feb/2018:18:48:29 +0100] [Client 127] Returning IPP successful-ok for Print-Job (ipp://localhost:631/printers/HL-3152CDW-series) from localhost
D [26/Feb/2018:18:48:29 +0100] [Client 127] Content-Length: 192
D [26/Feb/2018:18:48:29 +0100] [Client 127] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [26/Feb/2018:18:48:29 +0100] [Client 127] con->http=0x558505cac9d0
D [26/Feb/2018:18:48:29 +0100] [Client 127] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=192, response=0x558505cf9ce0(IPP_STATE_IDLE), pipe_pid=0, file=-1
D [26/Feb/2018:18:48:29 +0100] [Client 127] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [26/Feb/2018:18:48:29 +0100] [Client 127] bytes=0, http_state=0, data_remaining=192
D [26/Feb/2018:18:48:29 +0100] [Client 127] Flushing write buffer.
D [26/Feb/2018:18:48:29 +0100] [Client 127] New state is HTTP_STATE_WAITING
D [26/Feb/2018:18:48:29 +0100] [Client 127] Waiting for request.
...
D [26/Feb/2018:18:48:29 +0100] [Job 53] pagew = 571.0, pagel = 818.0
D [26/Feb/2018:18:48:29 +0100] [Job 53] bboxx = 0, bboxy = 0, bboxw = 595, bboxl = 842
D [26/Feb/2018:18:48:29 +0100] [Job 53] PageLeft = 12.0, PageRight = 583.0
D [26/Feb/2018:18:48:29 +0100] [Job 53] PageTop = 830.0, PageBottom = 12.0
D [26/Feb/2018:18:48:29 +0100] [Job 53] PageWidth = 595.0, PageLength = 842.0
D [26/Feb/2018:18:48:29 +0100] [Job 53] Wrote 1 pages...
D [26/Feb/2018:18:48:29 +0100] [Job 53] PID 2634 (pdftops) exited with no errors.
D [26/Feb/2018:18:48:29 +0100] [Job 53] PID 2635 (pstops) exited with no errors.
D [26/Feb/2018:18:48:29 +0100] [Job 53] PID 2611 (/usr/lib/cups/filter/pdftops) exited with no errors.
D [26/Feb/2018:18:48:29 +0100] [Job 53] /usr/lib/cups/filter/brother_lpdwrapper_hl3152cdw: 129: /usr/lib/cups/filter/brother_lpdwrapper_hl3152cdw: /opt/brother/Printers/hl3152cdw/cupswrapper/brcupsconfpt1: not found
D [26/Feb/2018:18:48:29 +0100] [Job 53] /opt/brother/Printers/hl3152cdw/lpd/filterhl3152cdw: 65: /opt/brother/Printers/hl3152cdw/lpd/filterhl3152cdw: /opt/brother/Printers/hl3152cdw/lpd/brhl3152cdwfilter: not found
D [26/Feb/2018:18:48:29 +0100] [Client 128] Server address is "/var/run/cups/cups.sock".
D [26/Feb/2018:18:48:29 +0100] [Client 128] Accepted from localhost (Domain)
D [26/Feb/2018:18:48:29 +0100] [Client 128] Waiting for request.
D [26/Feb/2018:18:48:29 +0100] [Client 128] POST / HTTP/1.1
D [26/Feb/2018:18:48:29 +0100] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Printing jobs and dirty files"
D [26/Feb/2018:18:48:29 +0100] [Client 128] Read: status=200
D [26/Feb/2018:18:48:29 +0100] [Client 128] No authentication data provided.
D [26/Feb/2018:18:48:29 +0100] [Client 128] 2.0 Get-Notifications 52
D [26/Feb/2018:18:48:29 +0100] Get-Notifications /
D [26/Feb/2018:18:48:29 +0100] cupsdIsAuthorized: requesting-user-name="martin"
D [26/Feb/2018:18:48:29 +0100] [Client 128] Returning IPP successful-ok for Get-Notifications (/) from localhost
D [26/Feb/2018:18:48:29 +0100] [Client 128] Content-Length: 3438
D [26/Feb/2018:18:48:29 +0100] [Client 128] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [26/Feb/2018:18:48:29 +0100] [Client 128] con->http=0x558505cac9d0
D [26/Feb/2018:18:48:29 +0100] [Client 128] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=3438, response=0x558505cabbf0(IPP_STATE_DATA), pipe_pid=0, file=-1
D [26/Feb/2018:18:48:29 +0100] [Client 128] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [26/Feb/2018:18:48:29 +0100] [Client 128] bytes=0, http_state=0, data_remaining=3438
D [26/Feb/2018:18:48:29 +0100] [Client 128] Flushing write buffer.
D [26/Feb/2018:18:48:29 +0100] [Client 128] New state is HTTP_STATE_WAITING
D [26/Feb/2018:18:48:29 +0100] [Client 128] Waiting for request.
D [26/Feb/2018:18:48:29 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients, printing jobs, and dirty files"
D [26/Feb/2018:18:48:29 +0100] [Client 128] POST / HTTP/1.1
D [26/Feb/2018:18:48:29 +0100] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Printing jobs and dirty files"
D [26/Feb/2018:18:48:29 +0100] [Client 128] Read: status=200
D [26/Feb/2018:18:48:29 +0100] [Client 128] No authentication data provided.
D [26/Feb/2018:18:48:29 +0100] [Client 128] 2.0 Get-Job-Attributes 53
D [26/Feb/2018:18:48:29 +0100] Get-Job-Attributes ipp://localhost/jobs/53
D [26/Feb/2018:18:48:29 +0100] [Client 128] Returning IPP successful-ok for Get-Job-Attributes (ipp://localhost/jobs/53) from localhost
D [26/Feb/2018:18:48:29 +0100] [Client 128] Content-Length: 1075
D [26/Feb/2018:18:48:29 +0100] [Client 128] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [26/Feb/2018:18:48:29 +0100] [Client 128] con->http=0x558505cac9d0
D [26/Feb/2018:18:48:29 +0100] [Client 128] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=1075, response=0x558505d1d560(IPP_STATE_DATA), pipe_pid=0, file=-1
D [26/Feb/2018:18:48:29 +0100] [Client 128] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [26/Feb/2018:18:48:29 +0100] [Client 128] bytes=0, http_state=0, data_remaining=1075
D [26/Feb/2018:18:48:29 +0100] [Client 128] Flushing write buffer.
D [26/Feb/2018:18:48:29 +0100] [Client 128] New state is HTTP_STATE_WAITING
D [26/Feb/2018:18:48:29 +0100] [Client 128] Waiting for request.
D [26/Feb/2018:18:48:29 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients, printing jobs, and dirty files"
D [26/Feb/2018:18:48:29 +0100] [Client 129] Server address is "/var/run/cups/cups.sock".
D [26/Feb/2018:18:48:29 +0100] [Client 129] Accepted from localhost (Domain)
D [26/Feb/2018:18:48:29 +0100] [Client 129] Waiting for request.
D [26/Feb/2018:18:48:29 +0100] [Client 129] POST / HTTP/1.1
D [26/Feb/2018:18:48:29 +0100] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Printing jobs and dirty files"
D [26/Feb/2018:18:48:29 +0100] [Client 129] Read: status=200
D [26/Feb/2018:18:48:29 +0100] [Client 129] No authentication data provided.
D [26/Feb/2018:18:48:29 +0100] [Client 129] 2.0 Get-Printer-Attributes 54
D [26/Feb/2018:18:48:29 +0100] Get-Printer-Attributes 
D [26/Feb/2018:18:48:29 +0100] Get-Printer-Attributes client-error-not-found: The printer or class does not exist.
D [26/Feb/2018:18:48:29 +0100] [Client 129] Returning IPP client-error-not-found for Get-Printer-Attributes () from localhost
D [26/Feb/2018:18:48:29 +0100] [Client 129] Content-Length: 130
D [26/Feb/2018:18:48:29 +0100] [Client 129] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [26/Feb/2018:18:48:29 +0100] [Client 129] con->http=0x558505ccd020
D [26/Feb/2018:18:48:29 +0100] [Client 129] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=130, response=0x558505cabd90(IPP_STATE_DATA), pipe_pid=0, file=-1
D [26/Feb/2018:18:48:29 +0100] [Client 129] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [26/Feb/2018:18:48:29 +0100] [Client 129] bytes=0, http_state=0, data_remaining=130
D [26/Feb/2018:18:48:29 +0100] [Client 129] Flushing write buffer.
D [26/Feb/2018:18:48:29 +0100] [Client 129] New state is HTTP_STATE_WAITING
D [26/Feb/2018:18:48:29 +0100] [Client 129] Waiting for request.
D [26/Feb/2018:18:48:29 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients, printing jobs, and dirty files"
D [26/Feb/2018:18:48:29 +0100] [Client 129] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [26/Feb/2018:18:48:29 +0100] [Client 129] Closing connection.
D [26/Feb/2018:18:48:29 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [26/Feb/2018:18:48:29 +0100] [Client 130] Server address is "/var/run/cups/cups.sock".
D [26/Feb/2018:18:48:29 +0100] [Client 130] Accepted from localhost (Domain)
D [26/Feb/2018:18:48:29 +0100] [Client 130] Waiting for request.
D [26/Feb/2018:18:48:29 +0100] [Client 130] POST / HTTP/1.1
D [26/Feb/2018:18:48:29 +0100] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Printing jobs and dirty files"
D [26/Feb/2018:18:48:29 +0100] [Client 130] Read: status=200
D [26/Feb/2018:18:48:29 +0100] [Client 130] No authentication data provided.
D [26/Feb/2018:18:48:29 +0100] [Client 130] 2.0 Get-Job-Attributes 55
D [26/Feb/2018:18:48:29 +0100] Get-Job-Attributes ipp://localhost/jobs/53
D [26/Feb/2018:18:48:29 +0100] [Client 130] Returning IPP successful-ok for Get-Job-Attributes (ipp://localhost/jobs/53) from localhost
D [26/Feb/2018:18:48:29 +0100] [Client 130] Content-Length: 181
D [26/Feb/2018:18:48:29 +0100] [Client 130] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [26/Feb/2018:18:48:29 +0100] [Client 130] con->http=0x558505ccd020
D [26/Feb/2018:18:48:29 +0100] [Client 130] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=181, response=0x558505cabd30(IPP_STATE_DATA), pipe_pid=0, file=-1
D [26/Feb/2018:18:48:29 +0100] [Client 130] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [26/Feb/2018:18:48:29 +0100] [Client 130] bytes=0, http_state=0, data_remaining=181
D [26/Feb/2018:18:48:29 +0100] [Client 130] Flushing write buffer.
D [26/Feb/2018:18:48:29 +0100] [Client 130] New state is HTTP_STATE_WAITING
D [26/Feb/2018:18:48:29 +0100] [Client 130] Waiting for request.
D [26/Feb/2018:18:48:29 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients, printing jobs, and dirty files"
D [26/Feb/2018:18:48:29 +0100] [Client 130] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [26/Feb/2018:18:48:29 +0100] [Client 130] Closing connection.
D [26/Feb/2018:18:48:29 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [26/Feb/2018:18:48:29 +0100] [Client 131] Server address is "/var/run/cups/cups.sock".
D [26/Feb/2018:18:48:29 +0100] [Client 131] Accepted from localhost (Domain)
D [26/Feb/2018:18:48:29 +0100] [Client 131] Waiting for request.
D [26/Feb/2018:18:48:29 +0100] [Client 131] POST / HTTP/1.1
D [26/Feb/2018:18:48:29 +0100] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Printing jobs and dirty files"
D [26/Feb/2018:18:48:29 +0100] [Client 131] Read: status=200
D [26/Feb/2018:18:48:29 +0100] [Client 131] No authentication data provided.
D [26/Feb/2018:18:48:29 +0100] [Client 131] 2.0 Get-Job-Attributes 56
D [26/Feb/2018:18:48:29 +0100] Get-Job-Attributes ipp://localhost/jobs/53
D [26/Feb/2018:18:48:29 +0100] [Client 131] Returning IPP successful-ok for Get-Job-Attributes (ipp://localhost/jobs/53) from localhost
D [26/Feb/2018:18:48:29 +0100] [Client 131] Content-Length: 101
D [26/Feb/2018:18:48:29 +0100] [Client 131] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [26/Feb/2018:18:48:29 +0100] [Client 131] con->http=0x558505ccd020
D [26/Feb/2018:18:48:29 +0100] [Client 131] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=101, response=0x558505cabd90(IPP_STATE_DATA), pipe_pid=0, file=-1
D [26/Feb/2018:18:48:29 +0100] [Client 131] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [26/Feb/2018:18:48:29 +0100] [Client 131] bytes=0, http_state=0, data_remaining=101
D [26/Feb/2018:18:48:29 +0100] [Client 131] Flushing write buffer.
D [26/Feb/2018:18:48:29 +0100] [Client 131] New state is HTTP_STATE_WAITING
D [26/Feb/2018:18:48:29 +0100] [Client 131] Waiting for request.
D [26/Feb/2018:18:48:29 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients, printing jobs, and dirty files"
D [26/Feb/2018:18:48:29 +0100] [Client 131] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [26/Feb/2018:18:48:29 +0100] [Client 131] Closing connection.
D [26/Feb/2018:18:48:29 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [26/Feb/2018:18:48:29 +0100] [Client 132] Server address is "/var/run/cups/cups.sock".
D [26/Feb/2018:18:48:29 +0100] [Client 132] Accepted from localhost (Domain)
D [26/Feb/2018:18:48:29 +0100] [Client 132] Waiting for request.
D [26/Feb/2018:18:48:29 +0100] [Client 132] POST / HTTP/1.1
D [26/Feb/2018:18:48:29 +0100] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Printing jobs and dirty files"
D [26/Feb/2018:18:48:29 +0100] [Client 132] Read: status=200
D [26/Feb/2018:18:48:29 +0100] [Client 132] No authentication data provided.
D [26/Feb/2018:18:48:29 +0100] [Client 132] 2.0 Get-Job-Attributes 57
D [26/Feb/2018:18:48:29 +0100] Get-Job-Attributes ipp://localhost/jobs/53
D [26/Feb/2018:18:48:29 +0100] [Client 132] Returning IPP successful-ok for Get-Job-Attributes (ipp://localhost/jobs/53) from localhost
D [26/Feb/2018:18:48:29 +0100] [Client 132] Content-Length: 101
D [26/Feb/2018:18:48:29 +0100] [Client 132] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [26/Feb/2018:18:48:29 +0100] [Client 132] con->http=0x558505ccd020
D [26/Feb/2018:18:48:29 +0100] [Client 132] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=101, response=0x558505cabd90(IPP_STATE_DATA), pipe_pid=0, file=-1
D [26/Feb/2018:18:48:29 +0100] [Client 132] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [26/Feb/2018:18:48:29 +0100] [Client 132] bytes=0, http_state=0, data_remaining=101
D [26/Feb/2018:18:48:29 +0100] [Client 132] Flushing write buffer.
D [26/Feb/2018:18:48:29 +0100] [Client 132] New state is HTTP_STATE_WAITING
D [26/Feb/2018:18:48:29 +0100] [Client 132] Waiting for request.
D [26/Feb/2018:18:48:29 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients, printing jobs, and dirty files"
D [26/Feb/2018:18:48:29 +0100] [Client 132] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [26/Feb/2018:18:48:29 +0100] [Client 132] Closing connection.
D [26/Feb/2018:18:48:29 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [26/Feb/2018:18:48:29 +0100] [Client 133] Server address is "/var/run/cups/cups.sock".
D [26/Feb/2018:18:48:29 +0100] [Client 133] Accepted from localhost (Domain)
D [26/Feb/2018:18:48:29 +0100] [Client 133] Waiting for request.
D [26/Feb/2018:18:48:29 +0100] [Client 133] POST / HTTP/1.1
D [26/Feb/2018:18:48:29 +0100] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Printing jobs and dirty files"
D [26/Feb/2018:18:48:29 +0100] [Client 133] Read: status=200
D [26/Feb/2018:18:48:29 +0100] [Client 133] No authentication data provided.
D [26/Feb/2018:18:48:29 +0100] [Client 133] 2.0 Get-Job-Attributes 59
D [26/Feb/2018:18:48:29 +0100] Get-Job-Attributes ipp://localhost/jobs/53
D [26/Feb/2018:18:48:29 +0100] [Client 133] Returning IPP successful-ok for Get-Job-Attributes (ipp://localhost/jobs/53) from localhost
D [26/Feb/2018:18:48:29 +0100] [Client 133] Content-Length: 101
D [26/Feb/2018:18:48:29 +0100] [Client 133] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [26/Feb/2018:18:48:29 +0100] [Client 133] con->http=0x558505ccd020
D [26/Feb/2018:18:48:29 +0100] [Client 133] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=101, response=0x558505cabd90(IPP_STATE_DATA), pipe_pid=0, file=-1
D [26/Feb/2018:18:48:29 +0100] [Client 133] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [26/Feb/2018:18:48:29 +0100] [Client 133] bytes=0, http_state=0, data_remaining=101
D [26/Feb/2018:18:48:29 +0100] [Client 133] Flushing write buffer.
D [26/Feb/2018:18:48:29 +0100] [Client 133] New state is HTTP_STATE_WAITING
D [26/Feb/2018:18:48:29 +0100] [Client 133] Waiting for request.
D [26/Feb/2018:18:48:29 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients, printing jobs, and dirty files"
D [26/Feb/2018:18:48:29 +0100] [Client 134] Server address is "/var/run/cups/cups.sock".
D [26/Feb/2018:18:48:29 +0100] [Client 134] Accepted from localhost (Domain)
D [26/Feb/2018:18:48:29 +0100] [Client 134] Waiting for request.
D [26/Feb/2018:18:48:29 +0100] [Client 133] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [26/Feb/2018:18:48:29 +0100] [Client 133] Closing connection.
D [26/Feb/2018:18:48:29 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [26/Feb/2018:18:48:29 +0100] [Client 134] POST /printers/HL-3152CDW-series HTTP/1.1
D [26/Feb/2018:18:48:29 +0100] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Printing jobs and dirty files"
D [26/Feb/2018:18:48:29 +0100] [Client 134] Read: status=200
D [26/Feb/2018:18:48:29 +0100] [Client 134] No authentication data provided.
D [26/Feb/2018:18:48:29 +0100] [Client 134] 2.0 Get-Printer-Attributes 58
D [26/Feb/2018:18:48:29 +0100] Get-Printer-Attributes ipp://localhost/printers/HL-3152CDW-series
D [26/Feb/2018:18:48:29 +0100] [Client 134] Returning IPP successful-ok for Get-Printer-Attributes (ipp://localhost/printers/HL-3152CDW-series) from localhost
D [26/Feb/2018:18:48:29 +0100] [Client 134] Content-Length: 236
D [26/Feb/2018:18:48:29 +0100] [Client 134] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [26/Feb/2018:18:48:29 +0100] [Client 134] con->http=0x558505cd0230
D [26/Feb/2018:18:48:29 +0100] [Client 134] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=236, response=0x558505cabd80(IPP_STATE_DATA), pipe_pid=0, file=-1
D [26/Feb/2018:18:48:29 +0100] [Client 134] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [26/Feb/2018:18:48:29 +0100] [Client 134] bytes=0, http_state=0, data_remaining=236
D [26/Feb/2018:18:48:29 +0100] [Client 134] Flushing write buffer.
D [26/Feb/2018:18:48:29 +0100] [Client 134] New state is HTTP_STATE_WAITING
D [26/Feb/2018:18:48:29 +0100] [Client 134] Waiting for request.
D [26/Feb/2018:18:48:29 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients, printing jobs, and dirty files"
D [26/Feb/2018:18:48:29 +0100] [Client 128] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [26/Feb/2018:18:48:29 +0100] [Client 128] Closing connection.
D [26/Feb/2018:18:48:29 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [26/Feb/2018:18:48:29 +0100] [Client 135] Server address is "/var/run/cups/cups.sock".
D [26/Feb/2018:18:48:29 +0100] [Client 135] Accepted from localhost (Domain)
D [26/Feb/2018:18:48:29 +0100] [Client 135] Waiting for request.
D [26/Feb/2018:18:48:29 +0100] [Client 135] GET /printers/HL-3152CDW-series.ppd HTTP/1.1
D [26/Feb/2018:18:48:29 +0100] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Printing jobs and dirty files"
D [26/Feb/2018:18:48:29 +0100] [Client 135] Read: status=200
D [26/Feb/2018:18:48:29 +0100] [Client 135] No authentication data provided.
D [26/Feb/2018:18:48:29 +0100] [Client 135] Processing GET /printers/HL-3152CDW-series.ppd
D [26/Feb/2018:18:48:29 +0100] [Client 135] filename="/etc/cups/ppd/HL-3152CDW-series.ppd", type=application/vnd.cups-ppd
D [26/Feb/2018:18:48:29 +0100] [Client 135] cupsdSendHeader: code=304, type="(null)", auth_type=0
D [26/Feb/2018:18:48:29 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients, printing jobs, and dirty files"
D [26/Feb/2018:18:48:29 +0100] [Client 135] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [26/Feb/2018:18:48:29 +0100] [Client 135] Closing connection.
D [26/Feb/2018:18:48:29 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [26/Feb/2018:18:48:29 +0100] [Job 53] PID 2612 (/usr/lib/cups/filter/brother_lpdwrapper_hl3152cdw) exited with no errors.
D [26/Feb/2018:18:48:29 +0100] [Job 53] Sent 0 bytes...
D [26/Feb/2018:18:48:29 +0100] [Job 53] Waiting for read thread to exit...
D [26/Feb/2018:18:48:29 +0100] [Job 53] PID 2613 (/usr/lib/cups/backend/usb) exited with no errors.
D [26/Feb/2018:18:48:29 +0100] [Job 53] time-at-completed=1519667309
D [26/Feb/2018:18:48:29 +0100] cupsdMarkDirty(----S)
D [26/Feb/2018:18:48:29 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
I [26/Feb/2018:18:48:29 +0100] [Job 53] Job completed.
I [26/Feb/2018:18:48:29 +0100] Expiring subscriptions...
D [26/Feb/2018:18:48:29 +0100] cupsdMarkDirty(---J-)
D [26/Feb/2018:18:48:29 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [26/Feb/2018:18:48:29 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [26/Feb/2018:18:48:29 +0100] cupsdMarkDirty(----S)
D [26/Feb/2018:18:48:29 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [26/Feb/2018:18:48:29 +0100] cupsdMarkDirty(---J-)
D [26/Feb/2018:18:48:29 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [26/Feb/2018:18:48:29 +0100] [Job 37] Removing document files.
D [26/Feb/2018:18:48:29 +0100] cupsdMarkDirty(---J-)
D [26/Feb/2018:18:48:29 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Printing jobs and dirty files"
D [26/Feb/2018:18:48:29 +0100] [Job 38] Removing document files.
D [26/Feb/2018:18:48:29 +0100] cupsdMarkDirty(---J-)
D [26/Feb/2018:18:48:29 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [26/Feb/2018:18:48:29 +0100] [Job 39] Removing document files.
D [26/Feb/2018:18:48:29 +0100] cupsdMarkDirty(---J-)
D [26/Feb/2018:18:48:29 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [26/Feb/2018:18:48:29 +0100] [Job 40] Removing document files.
D [26/Feb/2018:18:48:29 +0100] cupsdMarkDirty(---J-)
D [26/Feb/2018:18:48:29 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [26/Feb/2018:18:48:29 +0100] [Job 41] Removing document files.
D [26/Feb/2018:18:48:29 +0100] cupsdMarkDirty(---J-)
D [26/Feb/2018:18:48:29 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [26/Feb/2018:18:48:29 +0100] [Job 42] Removing document files.
D [26/Feb/2018:18:48:29 +0100] cupsdMarkDirty(---J-)
D [26/Feb/2018:18:48:29 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [26/Feb/2018:18:48:29 +0100] [Job 43] Removing document files.
D [26/Feb/2018:18:48:29 +0100] cupsdMarkDirty(---J-)
D [26/Feb/2018:18:48:29 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [26/Feb/2018:18:48:29 +0100] [Job 44] Removing document files.
D [26/Feb/2018:18:48:29 +0100] cupsdMarkDirty(---J-)
D [26/Feb/2018:18:48:29 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [26/Feb/2018:18:48:29 +0100] [Job 45] Removing document files.
D [26/Feb/2018:18:48:29 +0100] cupsdMarkDirty(---J-)
D [26/Feb/2018:18:48:29 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [26/Feb/2018:18:48:29 +0100] [Job 46] Removing document files.
D [26/Feb/2018:18:48:29 +0100] cupsdMarkDirty(---J-)
D [26/Feb/2018:18:48:29 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [26/Feb/2018:18:48:29 +0100] [Job 53] Removing document files.
D [26/Feb/2018:18:48:29 +0100] cupsdMarkDirty(---J-)
D [26/Feb/2018:18:48:29 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [26/Feb/2018:18:48:29 +0100] [Notifier] state=3
D [26/Feb/2018:18:48:29 +0100] [Notifier] JobCompleted
D [26/Feb/2018:18:48:29 +0100] [Notifier] state=3
D [26/Feb/2018:18:48:29 +0100] [Notifier] PrinterStateChanged
D [26/Feb/2018:18:48:29 +0100] [Client 136] Server address is "/var/run/cups/cups.sock".
D [26/Feb/2018:18:48:29 +0100] [Client 136] Accepted from localhost (Domain)
D [26/Feb/2018:18:48:29 +0100] [Client 136] Waiting for request.
D [26/Feb/2018:18:48:29 +0100] [Client 136] POST / HTTP/1.1
D [26/Feb/2018:18:48:29 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [26/Feb/2018:18:48:29 +0100] [Client 136] Read: status=200
D [26/Feb/2018:18:48:29 +0100] [Client 136] No authentication data provided.
D [26/Feb/2018:18:48:29 +0100] [Client 136] 2.0 Get-Notifications 60
D [26/Feb/2018:18:48:29 +0100] Get-Notifications /
D [26/Feb/2018:18:48:29 +0100] cupsdIsAuthorized: requesting-user-name="martin"
D [26/Feb/2018:18:48:29 +0100] [Client 136] Returning IPP successful-ok for Get-Notifications (/) from localhost
D [26/Feb/2018:18:48:29 +0100] [Client 136] Content-Length: 1099
D [26/Feb/2018:18:48:29 +0100] [Client 136] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [26/Feb/2018:18:48:29 +0100] [Client 136] con->http=0x558505ccd020
D [26/Feb/2018:18:48:29 +0100] [Client 136] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=1099, response=0x558505ce8400(IPP_STATE_DATA), pipe_pid=0, file=-1
D [26/Feb/2018:18:48:29 +0100] [Client 136] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [26/Feb/2018:18:48:29 +0100] [Client 136] bytes=0, http_state=0, data_remaining=1099
D [26/Feb/2018:18:48:29 +0100] [Client 136] Flushing write buffer.
D [26/Feb/2018:18:48:29 +0100] [Client 136] New state is HTTP_STATE_WAITING
D [26/Feb/2018:18:48:29 +0100] [Client 136] Waiting for request.
D [26/Feb/2018:18:48:29 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [26/Feb/2018:18:48:29 +0100] [Client 137] Server address is "/var/run/cups/cups.sock".
D [26/Feb/2018:18:48:29 +0100] [Client 137] Accepted from localhost (Domain)
D [26/Feb/2018:18:48:29 +0100] [Client 137] Waiting for request.
D [26/Feb/2018:18:48:29 +0100] [Client 137] POST / HTTP/1.1
D [26/Feb/2018:18:48:29 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [26/Feb/2018:18:48:29 +0100] [Client 137] Read: status=200
D [26/Feb/2018:18:48:29 +0100] [Client 137] No authentication data provided.
D [26/Feb/2018:18:48:29 +0100] [Client 137] 2.0 Get-Printer-Attributes 61
D [26/Feb/2018:18:48:29 +0100] Get-Printer-Attributes ipp://zuul/printers/HL-3152CDW-series
D [26/Feb/2018:18:48:29 +0100] [Client 137] Returning IPP successful-ok for Get-Printer-Attributes (ipp://zuul/printers/HL-3152CDW-series) from localhost
D [26/Feb/2018:18:48:29 +0100] [Client 137] Content-Length: 147
D [26/Feb/2018:18:48:29 +0100] [Client 137] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [26/Feb/2018:18:48:29 +0100] [Client 137] con->http=0x558505cd3440
D [26/Feb/2018:18:48:29 +0100] [Client 137] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=147, response=0x558505ce8490(IPP_STATE_DATA), pipe_pid=0, file=-1
D [26/Feb/2018:18:48:29 +0100] [Client 137] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [26/Feb/2018:18:48:29 +0100] [Client 137] bytes=0, http_state=0, data_remaining=147
D [26/Feb/2018:18:48:29 +0100] [Client 137] Flushing write buffer.
D [26/Feb/2018:18:48:29 +0100] [Client 137] New state is HTTP_STATE_WAITING
D [26/Feb/2018:18:48:29 +0100] [Client 137] Waiting for request.
D [26/Feb/2018:18:48:29 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [26/Feb/2018:18:48:29 +0100] [Client 136] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [26/Feb/2018:18:48:29 +0100] [Client 136] Closing connection.
D [26/Feb/2018:18:48:29 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
I [26/Feb/2018:18:48:30 +0100] Expiring subscriptions...
D [26/Feb/2018:18:48:30 +0100] [Job 53] Unloading...
D [26/Feb/2018:18:48:31 +0100] [Client 125] GET /printers/HL-3152CDW-series HTTP/1.1
D [26/Feb/2018:18:48:31 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [26/Feb/2018:18:48:31 +0100] [Client 125] Read: status=200
D [26/Feb/2018:18:48:31 +0100] [Client 125] Authorized as "martin" using Basic.
D [26/Feb/2018:18:48:31 +0100] [Client 125] Processing GET /printers/HL-3152CDW-series
D [26/Feb/2018:18:48:31 +0100] [CGI] argv[0] = "/usr/lib/cups/cgi-bin/printers.cgi"
D [26/Feb/2018:18:48:31 +0100] [CGI] envp[0] = "CUPS_CACHEDIR=/var/cache/cups"
D [26/Feb/2018:18:48:31 +0100] [CGI] envp[1] = "CUPS_DATADIR=/usr/share/cups"
D [26/Feb/2018:18:48:31 +0100] [CGI] envp[2] = "CUPS_DOCROOT=/usr/share/cups/doc-root"
D [26/Feb/2018:18:48:31 +0100] [CGI] envp[3] = "CUPS_FONTPATH=/usr/share/cups/fonts"
D [26/Feb/2018:18:48:31 +0100] [CGI] envp[4] = "CUPS_REQUESTROOT=/var/spool/cups"
D [26/Feb/2018:18:48:31 +0100] [CGI] envp[5] = "CUPS_SERVERBIN=/usr/lib/cups"
D [26/Feb/2018:18:48:31 +0100] [CGI] envp[6] = "CUPS_SERVERROOT=/etc/cups"
D [26/Feb/2018:18:48:31 +0100] [CGI] envp[7] = "CUPS_STATEDIR=/var/run/cups"
D [26/Feb/2018:18:48:31 +0100] [CGI] envp[8] = "HOME=/var/spool/cups/tmp"
D [26/Feb/2018:18:48:31 +0100] [CGI] envp[9] = "PATH=/usr/lib/cups/filter:/usr/bin:/usr/sbin:/bin:/usr/bin"
D [26/Feb/2018:18:48:31 +0100] [CGI] envp[10] = "SERVER_ADMIN=root@zuul"
D [26/Feb/2018:18:48:31 +0100] [CGI] envp[11] = "SOFTWARE=CUPS/2.2.1"
D [26/Feb/2018:18:48:31 +0100] [CGI] envp[12] = "TMPDIR=/var/spool/cups/tmp"
D [26/Feb/2018:18:48:31 +0100] [CGI] envp[13] = "USER=root"
D [26/Feb/2018:18:48:31 +0100] [CGI] envp[14] = "CUPS_MAX_MESSAGE=2047"
D [26/Feb/2018:18:48:31 +0100] [CGI] envp[15] = "CUPS_SERVER=/var/run/cups/cups.sock"
D [26/Feb/2018:18:48:31 +0100] [CGI] envp[16] = "CUPS_ENCRYPTION=IfRequested"
D [26/Feb/2018:18:48:31 +0100] [CGI] envp[17] = "IPP_PORT=631"
D [26/Feb/2018:18:48:31 +0100] [CGI] envp[18] = "AUTH_TYPE=Basic"
D [26/Feb/2018:18:48:31 +0100] [CGI] envp[19] = "LANG=en_US.UTF8"
D [26/Feb/2018:18:48:31 +0100] [CGI] envp[20] = "REDIRECT_STATUS=1"
D [26/Feb/2018:18:48:31 +0100] [CGI] envp[21] = "GATEWAY_INTERFACE=CGI/1.1"
D [26/Feb/2018:18:48:31 +0100] [CGI] envp[22] = "SERVER_NAME=localhost"
D [26/Feb/2018:18:48:31 +0100] [CGI] envp[23] = "SERVER_PORT=631"
D [26/Feb/2018:18:48:31 +0100] [CGI] envp[24] = "REMOTE_ADDR=[v1.::1]"
D [26/Feb/2018:18:48:31 +0100] [CGI] envp[25] = "REMOTE_HOST=localhost"
D [26/Feb/2018:18:48:31 +0100] [CGI] envp[26] = "SCRIPT_NAME=/printers/HL-3152CDW-series"
D [26/Feb/2018:18:48:31 +0100] [CGI] envp[27] = "SCRIPT_FILENAME=/usr/share/cups/doc-root/printers/HL-3152CDW-series"
D [26/Feb/2018:18:48:31 +0100] [CGI] envp[28] = "PATH_INFO=/HL-3152CDW-series"
D [26/Feb/2018:18:48:31 +0100] [CGI] envp[29] = "REMOTE_USER=martin"
D [26/Feb/2018:18:48:31 +0100] [CGI] envp[30] = "SERVER_PROTOCOL=HTTP/1.1"
D [26/Feb/2018:18:48:31 +0100] [CGI] envp[31] = "HTTP_COOKIE=org.cups.sid=254d17f8915429dcd47c9f7266cc62a2"
D [26/Feb/2018:18:48:31 +0100] [CGI] envp[32] = "HTTP_USER_AGENT=Mozilla/5.0 (X11; Linux x86_64; rv:52.0) Gecko/20100101 Firefox/52.0"
D [26/Feb/2018:18:48:31 +0100] [CGI] envp[33] = "REQUEST_METHOD=GET"
D [26/Feb/2018:18:48:31 +0100] [CGI] envp[34] = "QUERY_STRING="
D [26/Feb/2018:18:48:31 +0100] cupsdAddCert: Adding certificate for PID 2699
D [26/Feb/2018:18:48:31 +0100] [CGI] Started /usr/lib/cups/cgi-bin/printers.cgi (PID 2699)
I [26/Feb/2018:18:48:31 +0100] [Client 125] Started "/usr/lib/cups/cgi-bin/printers.cgi" (pid=2699, file=15)
D [26/Feb/2018:18:48:31 +0100] [Client 125] Waiting for CGI data.
I [26/Feb/2018:18:48:31 +0100] Expiring subscriptions...
D [26/Feb/2018:18:48:31 +0100] [CGI] org.cups.sid cookie is \"254d17f8915429dcd47c9f7266cc62a2\"
D [26/Feb/2018:18:48:31 +0100] [CGI] cgiSetVariable: SECTION=\"printers\"
D [26/Feb/2018:18:48:31 +0100] [CGI] cgiSetVariable: REFRESH_PAGE=\"\"
D [26/Feb/2018:18:48:31 +0100] [CGI] cgiSetVariable: PRINTER_NAME=\"HL-3152CDW-series\"
D [26/Feb/2018:18:48:31 +0100] [Client 138] Server address is "/var/run/cups/cups.sock".
D [26/Feb/2018:18:48:31 +0100] [Client 138] Accepted from localhost (Domain)
D [26/Feb/2018:18:48:31 +0100] [Client 138] Waiting for request.
D [26/Feb/2018:18:48:31 +0100] [Client 138] POST / HTTP/1.1
D [26/Feb/2018:18:48:31 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [26/Feb/2018:18:48:31 +0100] [Client 138] Read: status=200
D [26/Feb/2018:18:48:31 +0100] [Client 138] No authentication data provided.
D [26/Feb/2018:18:48:31 +0100] [Client 138] 2.0 CUPS-Get-Default 1
D [26/Feb/2018:18:48:31 +0100] CUPS-Get-Default
D [26/Feb/2018:18:48:31 +0100] [Client 138] Returning IPP successful-ok for CUPS-Get-Default (no URI) from localhost
D [26/Feb/2018:18:48:31 +0100] [Client 138] Content-Length: 178
D [26/Feb/2018:18:48:31 +0100] [Client 138] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [26/Feb/2018:18:48:31 +0100] [Client 138] con->http=0x558505cac3b0
D [26/Feb/2018:18:48:31 +0100] [Client 138] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=178, response=0x558505d1d480(IPP_STATE_DATA), pipe_pid=0, file=-1
D [26/Feb/2018:18:48:31 +0100] [Client 138] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [26/Feb/2018:18:48:31 +0100] [Client 138] bytes=0, http_state=0, data_remaining=178
D [26/Feb/2018:18:48:31 +0100] [Client 138] Flushing write buffer.
D [26/Feb/2018:18:48:31 +0100] [Client 138] New state is HTTP_STATE_WAITING
D [26/Feb/2018:18:48:31 +0100] [Client 138] Waiting for request.
D [26/Feb/2018:18:48:31 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [26/Feb/2018:18:48:31 +0100] [CGI] cgiSetVariable: DEFAULT_NAME=\"HL-3152CDW-series\"
D [26/Feb/2018:18:48:31 +0100] [CGI] cgiSetVariable: DEFAULT_URI=\"/printers/HL-3152CDW-series\"
D [26/Feb/2018:18:48:31 +0100] [CGI] show_printer(http=0x5646125801a0, printer=\"HL-3152CDW-series\")
D [26/Feb/2018:18:48:31 +0100] [Client 138] POST / HTTP/1.1
D [26/Feb/2018:18:48:31 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [26/Feb/2018:18:48:31 +0100] [Client 138] Read: status=200
D [26/Feb/2018:18:48:31 +0100] [Client 138] No authentication data provided.
D [26/Feb/2018:18:48:31 +0100] [Client 138] 2.0 Get-Printer-Attributes 2
D [26/Feb/2018:18:48:31 +0100] Get-Printer-Attributes ipp://localhost/printers/HL-3152CDW-series
D [26/Feb/2018:18:48:31 +0100] [Client 138] Returning IPP successful-ok for Get-Printer-Attributes (ipp://localhost/printers/HL-3152CDW-series) from localhost
D [26/Feb/2018:18:48:31 +0100] [Client 138] Content-Length: 743
D [26/Feb/2018:18:48:31 +0100] [Client 138] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [26/Feb/2018:18:48:31 +0100] [Client 138] con->http=0x558505cac3b0
D [26/Feb/2018:18:48:31 +0100] [Client 138] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=743, response=0x558505ce8420(IPP_STATE_DATA), pipe_pid=0, file=-1
D [26/Feb/2018:18:48:31 +0100] [Client 138] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [26/Feb/2018:18:48:31 +0100] [Client 138] bytes=0, http_state=0, data_remaining=743
D [26/Feb/2018:18:48:31 +0100] [Client 138] Flushing write buffer.
D [26/Feb/2018:18:48:31 +0100] [Client 138] New state is HTTP_STATE_WAITING
D [26/Feb/2018:18:48:31 +0100] [Client 138] Waiting for request.
D [26/Feb/2018:18:48:31 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [26/Feb/2018:18:48:31 +0100] [CGI] cgiSetVariable: SERVER_NAME=\"localhost\"
D [26/Feb/2018:18:48:31 +0100] [CGI] cgiSetVariable: REMOTE_USER=\"martin\"
D [26/Feb/2018:18:48:31 +0100] [CGI] cgiSetVariable: CUPS_VERSION=\"CUPS v2.2.1\"
D [26/Feb/2018:18:48:31 +0100] [CGI] cgiSetVariable: SERVER_NAME=\"localhost\"
D [26/Feb/2018:18:48:31 +0100] [CGI] cgiSetVariable: REMOTE_USER=\"martin\"
D [26/Feb/2018:18:48:31 +0100] [CGI] cgiSetVariable: CUPS_VERSION=\"CUPS v2.2.1\"
D [26/Feb/2018:18:48:31 +0100] [CGI] cgiSetArray: printer_is_accepting_jobs[0]=\"1\"
D [26/Feb/2018:18:48:31 +0100] [CGI] cgiSetArray: printer_is_shared[0]=\"0\"
D [26/Feb/2018:18:48:31 +0100] [CGI] cgiSetArray: printer_state[0]=\"3\"
D [26/Feb/2018:18:48:31 +0100] [CGI] cgiSetArray: admin_uri[0]=\"/admin/\"
D [26/Feb/2018:18:48:31 +0100] [CGI] cgiSetArray: printer_uri_supported[0]=\"/printers/HL-3152CDW-series\"
D [26/Feb/2018:18:48:31 +0100] [CGI] cgiSetArray: printer_name[0]=\"HL-3152CDW-series\"
D [26/Feb/2018:18:48:31 +0100] [CGI] cgiSetArray: printer_location[0]=\"zuul\"
D [26/Feb/2018:18:48:31 +0100] [CGI] cgiSetArray: printer_info[0]=\"Brother HL-3152CDW series\"
D [26/Feb/2018:18:48:31 +0100] [CGI] cgiSetArray: job_sheets_default[0]=\"none, none\"
D [26/Feb/2018:18:48:31 +0100] [CGI] cgiSetArray: device_uri[0]=\"usb://Brother/HL-3152CDW%20series?serial=E74551C6J366709\"
D [26/Feb/2018:18:48:31 +0100] [CGI] cgiSetArray: color_supported[0]=\"1\"
D [26/Feb/2018:18:48:31 +0100] [CGI] cgiSetArray: printer_make_and_model[0]=\"Brother HL-3152CDW series CUPS\"
D [26/Feb/2018:18:48:31 +0100] [CGI] cgiSetArray: media_default[0]=\"iso_a4_210x297mm\"
D [26/Feb/2018:18:48:31 +0100] [CGI] cgiSetArray: sides_supported[0]=\"one-sided, two-sided-long-edge, two-sided-short-edge\"
D [26/Feb/2018:18:48:31 +0100] [CGI] cgiSetArray: sides_default[0]=\"one-sided\"
D [26/Feb/2018:18:48:31 +0100] [CGI] cgiSetArray: printer_commands[0]=\"AutoConfigure, Clean, PrintSelfTestPage\"
D [26/Feb/2018:18:48:31 +0100] [CGI] cgiSetArray: server_is_sharing_printers[0]=\"0\"
D [26/Feb/2018:18:48:31 +0100] [CGI] cgiSetVariable: TITLE=\"HL-3152CDW-series\"
D [26/Feb/2018:18:48:31 +0100] [CGI] cgiSetVariable: SERVER_NAME=\"localhost\"
D [26/Feb/2018:18:48:31 +0100] [CGI] cgiSetVariable: REMOTE_USER=\"martin\"
D [26/Feb/2018:18:48:31 +0100] [CGI] cgiSetVariable: CUPS_VERSION=\"CUPS v2.2.1\"
D [26/Feb/2018:18:48:31 +0100] [Client 125] CGI data ready to be sent.
D [26/Feb/2018:18:48:31 +0100] [Client 125] con->http=0x558505d2c110
D [26/Feb/2018:18:48:31 +0100] [Client 125] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=2147483647, response=(nil)(), pipe_pid=2699, file=15
D [26/Feb/2018:18:48:31 +0100] [Client 125] Waiting for CGI data.
D [26/Feb/2018:18:48:31 +0100] [Client 125] Script header: Content-Type: text/html;charset=utf-8
D [26/Feb/2018:18:48:31 +0100] [Client 125] Script header: 
D [26/Feb/2018:18:48:31 +0100] [Client 125] Sending status 200 for CGI.
D [26/Feb/2018:18:48:31 +0100] [Client 125] cupsdSendHeader: code=200, type="(null)", auth_type=0
D [26/Feb/2018:18:48:31 +0100] [CGI] Regular expression \".*Clean.*\"
D [26/Feb/2018:18:48:31 +0100] [CGI] matches[0].rm_so=0
D [26/Feb/2018:18:48:31 +0100] [CGI] matches[1].rm_so=-1
D [26/Feb/2018:18:48:31 +0100] [Client 125] con->http=0x558505d2c110
D [26/Feb/2018:18:48:31 +0100] [Client 125] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=(nil)(), pipe_pid=2699, file=15
D [26/Feb/2018:18:48:31 +0100] [Client 125] Waiting for CGI data.
D [26/Feb/2018:18:48:31 +0100] [Client 125] CGI data ready to be sent.
D [26/Feb/2018:18:48:31 +0100] [CGI] Regular expression \".*PrintSelfTestPage.*\"
D [26/Feb/2018:18:48:31 +0100] [CGI] matches[0].rm_so=0
D [26/Feb/2018:18:48:31 +0100] [CGI] matches[1].rm_so=-1
D [26/Feb/2018:18:48:31 +0100] [Client 138] POST / HTTP/1.1
D [26/Feb/2018:18:48:31 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [26/Feb/2018:18:48:31 +0100] [Client 138] Read: status=200
D [26/Feb/2018:18:48:31 +0100] [Client 138] No authentication data provided.
D [26/Feb/2018:18:48:31 +0100] [Client 138] 2.0 Get-Jobs 3
D [26/Feb/2018:18:48:31 +0100] Get-Jobs ipp://localhost:631/printers/HL-3152CDW-series
D [26/Feb/2018:18:48:31 +0100] [Client 138] Returning IPP successful-ok for Get-Jobs (ipp://localhost:631/printers/HL-3152CDW-series) from localhost
D [26/Feb/2018:18:48:31 +0100] [Client 138] Content-Length: 75
D [26/Feb/2018:18:48:31 +0100] [Client 138] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [26/Feb/2018:18:48:31 +0100] [Client 125] con->http=0x558505d2c110
D [26/Feb/2018:18:48:31 +0100] [Client 125] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=(nil)(), pipe_pid=2699, file=15
D [26/Feb/2018:18:48:31 +0100] [Client 125] Waiting for CGI data.
D [26/Feb/2018:18:48:31 +0100] [Client 138] con->http=0x558505cac3b0
D [26/Feb/2018:18:48:31 +0100] [Client 138] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=75, response=0x558505cc5e70(IPP_STATE_DATA), pipe_pid=0, file=-1
D [26/Feb/2018:18:48:31 +0100] [Client 138] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [26/Feb/2018:18:48:31 +0100] [Client 138] bytes=0, http_state=0, data_remaining=75
D [26/Feb/2018:18:48:31 +0100] [Client 138] Flushing write buffer.
D [26/Feb/2018:18:48:31 +0100] [Client 138] New state is HTTP_STATE_WAITING
D [26/Feb/2018:18:48:31 +0100] [Client 138] Waiting for request.
D [26/Feb/2018:18:48:31 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [26/Feb/2018:18:48:31 +0100] [Client 125] con->http=0x558505d2c110
D [26/Feb/2018:18:48:31 +0100] [Client 125] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=(nil)(), pipe_pid=2699, file=15
D [26/Feb/2018:18:48:31 +0100] [Client 125] Waiting for CGI data.
D [26/Feb/2018:18:48:31 +0100] [CGI] cgiClearVariables called.
D [26/Feb/2018:18:48:31 +0100] [CGI] cgiSetVariable: SECTION=\"printers\"
D [26/Feb/2018:18:48:31 +0100] [CGI] cgiSetVariable: TOTAL=\"0\"
D [26/Feb/2018:18:48:31 +0100] [CGI] cgiSetVariable: PRINTER_NAME=\"HL-3152CDW-series\"
D [26/Feb/2018:18:48:31 +0100] [CGI] cgiSetVariable: PRINTER_URI_SUPPORTED=\"/printers/HL-3152CDW-series\"
D [26/Feb/2018:18:48:31 +0100] [CGI] cgiSetVariable: THISURL=\"/printers/HL-3152CDW-series\"
D [26/Feb/2018:18:48:31 +0100] [CGI] cgiSetVariable: SEARCH_DEST=\"HL-3152CDW-series\"
D [26/Feb/2018:18:48:31 +0100] [Client 125] CGI data ready to be sent.
D [26/Feb/2018:18:48:31 +0100] [Client 125] con->http=0x558505d2c110
D [26/Feb/2018:18:48:31 +0100] [Client 125] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=(nil)(), pipe_pid=2699, file=15
D [26/Feb/2018:18:48:31 +0100] [Client 125] Waiting for CGI data.
D [26/Feb/2018:18:48:31 +0100] [Client 125] con->http=0x558505d2c110
D [26/Feb/2018:18:48:31 +0100] [Client 125] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=(nil)(), pipe_pid=2699, file=15
D [26/Feb/2018:18:48:31 +0100] [Client 125] Waiting for CGI data.
D [26/Feb/2018:18:48:31 +0100] [Client 125] CGI data ready to be sent.
D [26/Feb/2018:18:48:31 +0100] [Client 138] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [26/Feb/2018:18:48:31 +0100] [Client 138] Closing connection.
D [26/Feb/2018:18:48:31 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [26/Feb/2018:18:48:31 +0100] [Client 125] con->http=0x558505d2c110
D [26/Feb/2018:18:48:31 +0100] [Client 125] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=(nil)(), pipe_pid=2699, file=15
D [26/Feb/2018:18:48:31 +0100] [Client 125] Waiting for CGI data.
D [26/Feb/2018:18:48:31 +0100] [Client 125] con->http=0x558505d2c110
D [26/Feb/2018:18:48:31 +0100] [Client 125] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=(nil)(), pipe_pid=2699, file=15
D [26/Feb/2018:18:48:31 +0100] [Client 125] Waiting for CGI data.
D [26/Feb/2018:18:48:31 +0100] [Client 125] CGI data ready to be sent.
D [26/Feb/2018:18:48:31 +0100] [Client 125] con->http=0x558505d2c110
D [26/Feb/2018:18:48:31 +0100] [Client 125] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=(nil)(), pipe_pid=2699, file=15
D [26/Feb/2018:18:48:31 +0100] [Client 125] Waiting for CGI data.
D [26/Feb/2018:18:48:31 +0100] [Client 125] Sending 0-length chunk.
D [26/Feb/2018:18:48:31 +0100] [Client 125] Flushing write buffer.
D [26/Feb/2018:18:48:31 +0100] [Client 125] New state is HTTP_STATE_WAITING
D [26/Feb/2018:18:48:31 +0100] [Client 125] Waiting for request.
D [26/Feb/2018:18:48:31 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [26/Feb/2018:18:48:31 +0100] PID 2699 (/usr/lib/cups/cgi-bin/printers.cgi) exited with no errors.
D [26/Feb/2018:18:48:31 +0100] [Client 125] GET /cups.css HTTP/1.1
D [26/Feb/2018:18:48:31 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [26/Feb/2018:18:48:31 +0100] [Client 125] Read: status=200
D [26/Feb/2018:18:48:31 +0100] [Client 125] Authorized as "martin" using Basic.
D [26/Feb/2018:18:48:31 +0100] [Client 125] Processing GET /cups.css
D [26/Feb/2018:18:48:31 +0100] [Client 125] filename="/usr/share/cups/doc-root/cups.css", type=text/css
D [26/Feb/2018:18:48:31 +0100] [Client 125] cupsdSendHeader: code=304, type="(null)", auth_type=0
D [26/Feb/2018:18:48:31 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
I [26/Feb/2018:18:48:32 +0100] Expiring subscriptions...
D [26/Feb/2018:18:48:34 +0100] [Client 126] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [26/Feb/2018:18:48:34 +0100] [Client 126] Closing connection.
D [26/Feb/2018:18:48:34 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
I [26/Feb/2018:18:48:34 +0100] Expiring subscriptions...
I [26/Feb/2018:18:48:35 +0100] Expiring subscriptions...
D [26/Feb/2018:18:48:41 +0100] [Client 125] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [26/Feb/2018:18:48:41 +0100] [Client 125] Closing connection.
D [26/Feb/2018:18:48:41 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
I [26/Feb/2018:18:48:41 +0100] Expiring subscriptions...
I [26/Feb/2018:18:48:42 +0100] Expiring subscriptions...
I [26/Feb/2018:18:49:00 +0100] Saving job.cache...
I [26/Feb/2018:18:49:00 +0100] Saving subscriptions.conf...
D [26/Feb/2018:18:49:00 +0100] cupsdSetBusyState: newbusy="Not busy", busy="Dirty files"
I [26/Feb/2018:18:49:00 +0100] Expiring subscriptions...

shep
Posts: 423
Joined: 2011-03-15 15:22

Re: Installing Brother HL-3152CDW Printer

#5 Post by shep »

D [26/Feb/2018:18:48:29 +0100] [Job 53] /usr/lib/cups/filter/brother_lpdwrapper_hl3152cdw: 129: /usr/lib/cups/filter/brother_lpdwrapper_hl3152cdw: /opt/brother/Printers/hl3152cdw/cupswrapper/brcupsconfpt1: not found
D [26/Feb/2018:18:48:29 +0100] [Job 53] /opt/brother/Printers/hl3152cdw/lpd/filterhl3152cdw: 65: /opt/brother/Printers/hl3152cdw/lpd/filterhl3152cdw: /opt/brother/Printers/hl3152cdw/lpd/brhl3152cdwfilter: not found

Mad-Din
Posts: 10
Joined: 2017-10-21 11:48
Has thanked: 1 time

Re: Installing Brother HL-3152CDW Printer

#6 Post by Mad-Din »

D [26/Feb/2018:18:48:29 +0100] [Job 53] /usr/lib/cups/filter/brother_lpdwrapper_hl3152cdw: 129: /usr/lib/cups/filter/brother_lpdwrapper_hl3152cdw: /opt/brother/Printers/hl3152cdw/cupswrapper/brcupsconfpt1: not found
D [26/Feb/2018:18:48:29 +0100] [Job 53] /opt/brother/Printers/hl3152cdw/lpd/filterhl3152cdw: 65: /opt/brother/Printers/hl3152cdw/lpd/filterhl3152cdw: /opt/brother/Printers/hl3152cdw/lpd/brhl3152cdwfilter: not found
Thanks for the hint. What is it, what cannot be found? All the mentioned files exist.
I thought a line starting with 'D' indicates debug level. I would expect a serious printing error resulting in a line starting with A, C, E, W or X

shep
Posts: 423
Joined: 2011-03-15 15:22

Re: Installing Brother HL-3152CDW Printer

#7 Post by shep »

I believe the component "filter's" your print jobs. When filters fail you typically see the printer powerup and print nothing/garbage/blanks.

A rough overview:
Most print jobs originate as postscript files (printjob.ps) and if a printer is postscript capable can be sent directly to the printer.

Postscript was developed by Adobe and printer manufacturers had to pay royalties to Adobe to flash their printer ROM's with Adobe's https://en.wikipedia.org/wiki/PostScript. Adobe abandoned licensing several years ago and printer manufacturers now write their own postscript. Brothers = brscript3

HP developed PCL (Printer Command Language) that would take the original postscript print job and filter it to a form that HP printers understood. This PCL wikipedia entry has more information on the development of PCL and which versions support color, 1200dpi, duplex, etc.. This shifted some the processing workload from the printer to the computer.

Ghostscipt is a GPL's project that provides PCL filters.

Your printer does not support postscript or PCL but Brother has written a filter for it. Brother's Filter is purportedly GPL but no one can find the source code. Brother only provides the binary that was compiled from their source code on an older Ubuntu/Debian system. The references you provided indicate that it was compiled on a 32 bit system.

Back to your problem, you need to be sure that brothers filter is found by cups and runs. One hint is to try to run the filters individually as root.
For example

Code: Select all

# cd opt/brother/Printers/hl3152cdw/lpd/

Code: Select all

# less brhl3152cdwfilter
to see if it is a shell script and

Code: Select all

# ls -al brhl3152cdwfilter
to check the ownership/permissions.
See this Ubuntu thread for problems with owner/permissions
Debian wise, I would try to replicate the owner:group permissions for the ghostscript filters (available online).

Code: Select all

./brhl3152cdwfilter
to see if it executes and what missing libraries come up.
Ghostscript filters are installed in /usr/lib/share and cups definitely can access that directory

If all this seems like a lot of work and your time = money consider upgrading your printer to one that at least supports PCL6. On the other hand, if your are interested in learning and have the time, try the above and post back with additional questions.

Mad-Din
Posts: 10
Joined: 2017-10-21 11:48
Has thanked: 1 time

Re: Installing Brother HL-3152CDW Printer

#8 Post by Mad-Din »

Hey again,

I checked permissions and filter location, this seems to be all right.
Debian wise, I would try to replicate the owner:group permissions for the ghostscript filters (available online).
./brhl3152cdwfilter
to see if it executes and what missing libraries come up.
If I try to execute the filter I get a No such file or directory, which seems to match to the cups error_log entry "/opt/brother/Printers/hl3152cdw/lpd/brhl3152cdwfilter: not found"

Code: Select all

martin@zuul:/opt/brother/Printers/hl3152cdw/lpd$ ll -la
total 2200
drwxr-xr-x 2 root root    4096 Mar  8 18:07 .
drwxr-xr-x 5 root root    4096 Mar  8 18:12 ..
-rwxr-xr-x 1 root root 2235924 Jul  6  2015 brhl3152cdwfilter
-rwxr-xr-x 1 root root    2276 Jul  6  2015 filterhl3152cdw
-rwxr-xr-x 1 root root    2449 Jul  6  2015 psconvertij2
martin@zuul:/opt/brother/Printers/hl3152cdw/lpd$ ./brhl3152cdwfilter
bash: ./brhl3152cdwfilter: No such file or directory
In the same folder, there is a shell script filterhl3152cdw (code below). It executes without errors and seems to wait for some input, when executed without parameters.
If I have a look at the /tmp/ folder, which seems to be read while trying to print a testpage, there are some files being created and removed in less than a second.

Is there anything else I can do? I'm quite close to just giving up...

Code: Select all

#! /bin/sh
#
# Brother Print filter
# Copyright (C) 2003-2015 Brother. Industries, Ltd.

# This program is free software; you can redistribute it and/or modify it
# under the terms of the GNU General Public License as published by the Free
# Software Foundation; either version 2 of the License, or (at your option)
# any later version.
#
# This program is distributed in the hope that it will be useful, but WITHOUT
# ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or
# FITNESS FOR A PARTICULAR PURPOSE.  See the GNU General Public License for
# more details.
#
# You should have received a copy of the GNU General Public License along with
# this program; if not, write to the Free Software Foundation, Inc., 59 Temple
# Place, Suite 330, Boston, MA  02111-1307  USA
#

PRINTER="hl3152cdw"
PRINTER_TMP=$(echo $PRINTER | sed -e 's/ //g' -e 's/-//g')

BR_CFG_PATH=/opt/brother/Printers/${PRINTER}
BR_LPD_PATH=/opt/brother/Printers/${PRINTER}

RCFILE="$BRPRINTERRCFILE"
PAPER_INF=$BR_CFG_PATH/inf/paperinfij2
#
IMAGINGAREA_FILE=$BR_CFG_PATH/inf/ImagingArea

PSCONV=$BR_LPD_PATH/lpd/psconvertij2
BRCONV=$BR_LPD_PATH/lpd/br${PRINTER}filter
if [ "$BRPRINTERRCFILE" = '' ];then
	RCFILE=`eval echo $BR_CFG_PATH/inf/brPRINTERrc | eval sed 's/PRINTER/"$PRINTER_TMP"/'`
	if [ -e /var/tmp/lprng_${PRINTER_TMP}_rcname ];then
	read -r name < /var/tmp/lprng_${PRINTER_TMP}_rcname
	fi

	if [ -z $name ];then
	:
	else
	RCFILE=$name
	fi
fi

INPUT_TEMP=`mktemp /tmp/br_input.XXXXXX`
cat > $INPUT_TEMP
rm -f /var/tmp/lprng_${PRINTER}_rcname

FILE_TYPE=`file $INPUT_TEMP | sed -e 's/^.*:[ ]*//' -e 's/[ ].*//'`

#if [ "$FILE_TYPE" = "PostScript" -o "$FILE_TYPE" = "PDF" ] ; then
	PSCONV_OP="$PAPER_INF $RCFILE $IMAGINGAREA_FILE"
	BRCONV_OP="-pi $PAPER_INF -rc $RCFILE"
#fi

trap '' 2
case "$FILE_TYPE" in      
	"PostScript")
		eval cat $INPUT_TEMP | $PSCONV $PSCONV_OP | $BRCONV $BRCONV_OP
		RET=$?
		;;
	"PDF")
		PS_TEMP=`mktemp /tmp/br_ps.XXXXXX`
		pdf2ps $INPUT_TEMP $PS_TEMP
		eval cat $PS_TEMP | $PSCONV $PSCONV_OP | $BRCONV $BRCONV_OP
		RET=$?
		rm -f $PS_TEMP
		;;
	* )
		A2PS_OP="--output=- -q -1 --no-header --borders no"
		eval cat $INPUT_TEMP | a2ps $A2PS_OP | $PSCONV $PSCONV_OP | $BRCONV $BRCONV_OP
		RET=$?
		;;
esac
trap 2
rm -f $INPUT_TEMP

exit $RET

shep
Posts: 423
Joined: 2011-03-15 15:22

Re: Installing Brother HL-3152CDW Printer

#9 Post by shep »

This prior forum post had similar issues and solved them with a less-than-elegant hack
http://forums.debian.net/viewtopic.php?t=73403

For future readers: for an additional $20-$30USD, a PCL6 compatible printer would avoid all this. The other point is that Brother may supply a linux ppd, but support/updating does not really exist.

Mad-Din
Posts: 10
Joined: 2017-10-21 11:48
Has thanked: 1 time

Re: Installing Brother HL-3152CDW Printer

#10 Post by Mad-Din »

This link did the trick.
I uninstalled the packages, installed what was mentioned in the next-to-last post from the link, started the printer and printed a test-page via usb-connection.
I was not far from giving up, so thank you very much!

If I could, I would buy you a beer or two for your help and patience!
Cheers,
Martin

Post Reply