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.
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.
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...