I [29/Jul/2015:16:54:08 +0200] Listening to [v1.::1]:631 (IPv6)
I [29/Jul/2015:16:54:08 +0200] Listening to 127.0.0.1:631 (IPv4)
I [29/Jul/2015:16:54:08 +0200] Listening to /var/run/cups/cups.sock (Domain)
I [29/Jul/2015:16:54:08 +0200] Remote access is disabled.
D [29/Jul/2015:16:54:08 +0200] Added auto ServerAlias debiansid
I [29/Jul/2015:16:54:08 +0200] Loaded configuration file "/etc/cups/cupsd.conf"
D [29/Jul/2015:16:54:08 +0200] Using keychain "/etc/cups/ssl" for server name "debiansid".
I [29/Jul/2015:16:54:08 +0200] Using default TempDir of /var/spool/cups/tmp...
I [29/Jul/2015:16:54:08 +0200] Configured for up to 100 clients.
I [29/Jul/2015:16:54:08 +0200] Allowing up to 100 client connections per host.
I [29/Jul/2015:16:54:08 +0200] Using policy "default" as the default.
I [29/Jul/2015:16:54:08 +0200] Full reload is required.
I [29/Jul/2015:16:54:08 +0200] Loaded MIME database from "/usr/share/cups/mime" and "/etc/cups": 39 types, 57 filters...
D [29/Jul/2015:16:54:08 +0200] Loading printer tofile-boomaga...
D [29/Jul/2015:16:54:08 +0200] load_ppd: Loading /var/cache/cups/tofile-boomaga.data...
D [29/Jul/2015:16:54:08 +0200] cupsdRegisterPrinter(p=0x7f1b381b8ba0(tofile-boomaga))
I [29/Jul/2015:16:54:08 +0200] Loading job cache file "/var/cache/cups/job.cache"...
D [29/Jul/2015:16:54:08 +0200] [Job 1] Loading from cache...
D [29/Jul/2015:16:54:08 +0200] [Job 2] Loading from cache...
D [29/Jul/2015:16:54:08 +0200] [Job 3] Loading from cache...
D [29/Jul/2015:16:54:08 +0200] [Job 3] Loading attributes...
D [29/Jul/2015:16:54:08 +0200] [Job 3] Unloading...
D [29/Jul/2015:16:54:08 +0200] cupsdAddSubscription(mask=0, dest=(nil)(), job=(nil)(0), uri="(null)")
I [29/Jul/2015:16:54:08 +0200] Full reload complete.
D [29/Jul/2015:16:54:08 +0200] cupsdCleanFiles(path="/var/spool/cups/tmp", pattern="(null)")
I [29/Jul/2015:16:54:08 +0200] Cleaning out old files in "/var/spool/cups/tmp".
D [29/Jul/2015:16:54:08 +0200] cupsdCleanFiles(path="/var/cache/cups", pattern="*.ipp")
I [29/Jul/2015:16:54:08 +0200] Cleaning out old files in "/var/cache/cups".
D [29/Jul/2015:16:54:08 +0200] service_checkin: pid=1316
D [29/Jul/2015:16:54:08 +0200] service_checkin: 1 listeners.
D [29/Jul/2015:16:54:08 +0200] service_checkin: Listener #1 at fd 3, "/var/run/cups/cups.sock".
D [29/Jul/2015:16:54:08 +0200] service_checkin: Matched existing listener #1 to /var/run/cups/cups.sock.
D [29/Jul/2015:16:54:08 +0200] Creating keep-alive file "/var/cache/cups/org.cups.cupsd".
D [29/Jul/2015:16:54:08 +0200] Calling FindDeviceById(cups-tofile-boomaga)
D [29/Jul/2015:16:54:08 +0200] FindDeviceById failed: org.freedesktop.ColorManager.NotFound:device id 'cups-tofile-boomaga' does not exist
D [29/Jul/2015:16:54:08 +0200] Using profile ID "tofile-boomaga-Gray..".
D [29/Jul/2015:16:54:08 +0200] Calling CreateProfile(tofile-boomaga-Gray..,temp)
D [29/Jul/2015:16:54:08 +0200] Created profile "/org/freedesktop/ColorManager/profiles/tofile_boomaga_Gray__".
D [29/Jul/2015:16:54:08 +0200] Using profile ID "tofile-boomaga-CMYK..".
D [29/Jul/2015:16:54:08 +0200] Calling CreateProfile(tofile-boomaga-CMYK..,temp)
D [29/Jul/2015:16:54:08 +0200] Created profile "/org/freedesktop/ColorManager/profiles/tofile_boomaga_CMYK__".
I [29/Jul/2015:16:54:08 +0200] Registering ICC color profiles for "tofile-boomaga".
D [29/Jul/2015:16:54:08 +0200] Calling CreateDevice(cups-tofile-boomaga,temp)
D [29/Jul/2015:16:54:08 +0200] Created device "/org/freedesktop/ColorManager/devices/cups_tofile_boomaga".
D [29/Jul/2015:16:54:08 +0200] Calling /org/freedesktop/ColorManager/devices/cups_tofile_boomaga:AddProfile(/org/freedesktop/ColorManager/profiles/tofile_boomaga_Gray__) [soft]
D [29/Jul/2015:16:54:08 +0200] Calling /org/freedesktop/ColorManager/devices/cups_tofile_boomaga:AddProfile(/org/freedesktop/ColorManager/profiles/tofile_boomaga_CMYK__) [soft]
I [29/Jul/2015:16:54:08 +0200] Listening to [v1.::1]:631 on fd 10...
I [29/Jul/2015:16:54:08 +0200] Listening to 127.0.0.1:631 on fd 11...
I [29/Jul/2015:16:54:08 +0200] Listening to /var/run/cups/cups.sock on fd 3...
I [29/Jul/2015:16:54:08 +0200] Resuming new connection processing...
D [29/Jul/2015:16:54:08 +0200] cupsdSetBusyState: newbusy="Not busy", busy="Not busy"
D [29/Jul/2015:16:54:08 +0200] cupsdAddCert: Adding certificate for PID 0
D [29/Jul/2015:16:54:08 +0200] Discarding unused server-started event...
D [29/Jul/2015:16:54:09 +0200] Report: clients=0
D [29/Jul/2015:16:54:09 +0200] Report: jobs=3
D [29/Jul/2015:16:54:09 +0200] Report: jobs-active=0
D [29/Jul/2015:16:54:09 +0200] Report: printers=1
D [29/Jul/2015:16:54:09 +0200] Report: stringpool-string-count=597
D [29/Jul/2015:16:54:09 +0200] Report: stringpool-alloc-bytes=7216
D [29/Jul/2015:16:54:09 +0200] Report: stringpool-total-bytes=11008
D [29/Jul/2015:16:54:13 +0200] [Client 1] Accepted from localhost (Domain)
D [29/Jul/2015:16:54:13 +0200] [Client 1] Waiting for request.
D [29/Jul/2015:16:54:13 +0200] [Client 1] POST / HTTP/1.1
D [29/Jul/2015:16:54:13 +0200] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [29/Jul/2015:16:54:13 +0200] [Client 1] Read: status=200
D [29/Jul/2015:16:54:13 +0200] [Client 1] No authentication data provided.
D [29/Jul/2015:16:54:13 +0200] [Client 1] 2.0 Get-Printer-Attributes 1
D [29/Jul/2015:16:54:13 +0200] Get-Printer-Attributes ipp://localhost:631/printers/tofile-boomaga
D [29/Jul/2015:16:54:13 +0200] [Client 1] Returning IPP successful-ok for Get-Printer-Attributes (ipp://localhost:631/printers/tofile-boomaga) from localhost
D [29/Jul/2015:16:54:13 +0200] [Client 1] Content-Length: 1093
D [29/Jul/2015:16:54:13 +0200] [Client 1] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [29/Jul/2015:16:54:13 +0200] [Client 1] con->http=0x7f1b381f75a0
D [29/Jul/2015:16:54:13 +0200] [Client 1] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=1093, response=0x7f1b381ff140(IPP_STATE_DATA), pipe_pid=0, file=-1
D [29/Jul/2015:16:54:13 +0200] [Client 1] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [29/Jul/2015:16:54:13 +0200] [Client 1] bytes=0, http_state=0, data_remaining=1093
D [29/Jul/2015:16:54:13 +0200] [Client 1] Flushing write buffer.
D [29/Jul/2015:16:54:13 +0200] [Client 1] New state is HTTP_STATE_WAITING
D [29/Jul/2015:16:54:13 +0200] [Client 1] Waiting for request.
D [29/Jul/2015:16:54:13 +0200] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [29/Jul/2015:16:54:13 +0200] [Client 1] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [29/Jul/2015:16:54:13 +0200] [Client 1] Closing connection.
D [29/Jul/2015:16:54:13 +0200] cupsdSetBusyState: newbusy="Not busy", busy="Not busy"
D [29/Jul/2015:16:54:13 +0200] [Client 2] Accepted from localhost (Domain)
D [29/Jul/2015:16:54:13 +0200] [Client 2] Waiting for request.
D [29/Jul/2015:16:54:13 +0200] [Client 2] POST /printers/tofile-boomaga HTTP/1.1
D [29/Jul/2015:16:54:13 +0200] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [29/Jul/2015:16:54:13 +0200] [Client 2] Read: status=200
D [29/Jul/2015:16:54:13 +0200] [Client 2] No authentication data provided.
D [29/Jul/2015:16:54:13 +0200] [Client 2] 2.0 Create-Job 2
D [29/Jul/2015:16:54:13 +0200] Create-Job ipp://localhost:631/printers/tofile-boomaga
D [29/Jul/2015:16:54:13 +0200] cupsdMarkDirty(---J-)
D [29/Jul/2015:16:54:13 +0200] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients"
D [29/Jul/2015:16:54:13 +0200] add_job: requesting-user-name="michi"
I [29/Jul/2015:16:54:13 +0200] [Job 4] Adding start banner page "none".
D [29/Jul/2015:16:54:13 +0200] Discarding unused job-created event...
I [29/Jul/2015:16:54:13 +0200] [Job 4] Queued on "tofile-boomaga" by "michi".
D [29/Jul/2015:16:54:13 +0200] [Client 2] Returning IPP successful-ok for Create-Job (ipp://localhost:631/printers/tofile-boomaga) from localhost
D [29/Jul/2015:16:54:13 +0200] [Client 2] Content-Length: 177
D [29/Jul/2015:16:54:13 +0200] [Client 2] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [29/Jul/2015:16:54:13 +0200] [Client 2] con->http=0x7f1b381f75a0
D [29/Jul/2015:16:54:13 +0200] [Client 2] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=177, response=0x7f1b381fef40(IPP_STATE_IDLE), pipe_pid=0, file=-1
D [29/Jul/2015:16:54:13 +0200] [Client 2] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [29/Jul/2015:16:54:13 +0200] [Client 2] bytes=0, http_state=0, data_remaining=177
D [29/Jul/2015:16:54:13 +0200] [Client 2] Flushing write buffer.
D [29/Jul/2015:16:54:13 +0200] [Client 2] New state is HTTP_STATE_WAITING
D [29/Jul/2015:16:54:13 +0200] [Client 2] Waiting for request.
D [29/Jul/2015:16:54:13 +0200] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [29/Jul/2015:16:54:13 +0200] [Client 2] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [29/Jul/2015:16:54:13 +0200] [Client 2] Closing connection.
D [29/Jul/2015:16:54:13 +0200] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [29/Jul/2015:16:54:13 +0200] [Client 3] Accepted from localhost (Domain)
D [29/Jul/2015:16:54:13 +0200] [Client 3] Waiting for request.
D [29/Jul/2015:16:54:13 +0200] [Client 3] POST /printers/tofile-boomaga HTTP/1.1
D [29/Jul/2015:16:54:13 +0200] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [29/Jul/2015:16:54:13 +0200] [Client 3] Read: status=200
D [29/Jul/2015:16:54:13 +0200] [Client 3] No authentication data provided.
D [29/Jul/2015:16:54:13 +0200] [Client 3] 2.0 Send-Document 3
D [29/Jul/2015:16:54:13 +0200] Send-Document ipp://localhost:631/printers/tofile-boomaga
D [29/Jul/2015:16:54:13 +0200] cupsdIsAuthorized: requesting-user-name="michi"
D [29/Jul/2015:16:54:13 +0200] [Job 4] Auto-typing file...
D [29/Jul/2015:16:54:13 +0200] [Job 4] Request file type is text/plain.
D [29/Jul/2015:16:54:13 +0200] cupsdMarkDirty(---J-)
D [29/Jul/2015:16:54:13 +0200] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
I [29/Jul/2015:16:54:13 +0200] [Job 4] File of type text/plain queued by "michi".
I [29/Jul/2015:16:54:13 +0200] [Job 4] Adding end banner page "none".
D [29/Jul/2015:16:54:13 +0200] cupsdMarkDirty(---J-)
D [29/Jul/2015:16:54:13 +0200] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [29/Jul/2015:16:54:13 +0200] [Job 4] time-at-processing=1438181653
D [29/Jul/2015:16:54:13 +0200] cupsdMarkDirty(---J-)
D [29/Jul/2015:16:54:13 +0200] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [29/Jul/2015:16:54:13 +0200] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [29/Jul/2015:16:54:13 +0200] cupsdMarkDirty(----S)
D [29/Jul/2015:16:54:13 +0200] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [29/Jul/2015:16:54:13 +0200] [Job 4] 2 filters for job:
D [29/Jul/2015:16:54:13 +0200] [Job 4] texttopdf (text/plain to application/pdf, cost 32)
D [29/Jul/2015:16:54:13 +0200] [Job 4] - (application/pdf to printer/tofile-boomaga, cost 0)
D [29/Jul/2015:16:54:13 +0200] [Job 4] job-sheets=none,none
D [29/Jul/2015:16:54:13 +0200] [Job 4] argv[0]="tofile-boomaga"
D [29/Jul/2015:16:54:13 +0200] [Job 4] argv[1]="4"
D [29/Jul/2015:16:54:13 +0200] [Job 4] argv[2]="michi"
D [29/Jul/2015:16:54:13 +0200] [Job 4] argv[3]="test.txt"
D [29/Jul/2015:16:54:13 +0200] [Job 4] argv[4]="1"
D [29/Jul/2015:16:54:13 +0200] [Job 4] argv[5]="finishings=3 number-up=1 job-uuid=urn:uuid:3eabc71b-2801-3e76-7999-08dfdd83f159 job-originating-host-name=localhost time-at-creation=1438181653 time-at-processing=1438181653"
D [29/Jul/2015:16:54:13 +0200] [Job 4] argv[6]="/var/spool/cups/d00004-001"
D [29/Jul/2015:16:54:13 +0200] [Job 4] envp[0]="CUPS_CACHEDIR=/var/cache/cups"
D [29/Jul/2015:16:54:13 +0200] [Job 4] envp[1]="CUPS_DATADIR=/usr/share/cups"
D [29/Jul/2015:16:54:13 +0200] [Job 4] envp[2]="CUPS_DOCROOT=/usr/share/cups/doc-root"
D [29/Jul/2015:16:54:13 +0200] [Job 4] envp[3]="CUPS_FONTPATH=/usr/share/cups/fonts"
D [29/Jul/2015:16:54:13 +0200] [Job 4] envp[4]="CUPS_REQUESTROOT=/var/spool/cups"
D [29/Jul/2015:16:54:13 +0200] [Job 4] envp[5]="CUPS_SERVERBIN=/usr/lib/cups"
D [29/Jul/2015:16:54:13 +0200] [Job 4] envp[6]="CUPS_SERVERROOT=/etc/cups"
D [29/Jul/2015:16:54:13 +0200] [Job 4] envp[7]="CUPS_STATEDIR=/var/run/cups"
D [29/Jul/2015:16:54:13 +0200] [Job 4] envp[8]="HOME=/var/spool/cups/tmp"
D [29/Jul/2015:16:54:13 +0200] [Job 4] envp[9]="PATH=/usr/lib/cups/filter:/usr/bin:/usr/sbin:/bin:/usr/bin"
D [29/Jul/2015:16:54:13 +0200] [Job 4] envp[10]="SERVER_ADMIN=root@debiansid"
D [29/Jul/2015:16:54:13 +0200] [Job 4] envp[11]="SOFTWARE=CUPS/2.0.3"
D [29/Jul/2015:16:54:13 +0200] [Job 4] envp[12]="TMPDIR=/var/spool/cups/tmp"
D [29/Jul/2015:16:54:13 +0200] [Job 4] envp[13]="USER=root"
D [29/Jul/2015:16:54:13 +0200] [Job 4] envp[14]="CUPS_MAX_MESSAGE=2047"
D [29/Jul/2015:16:54:13 +0200] [Job 4] envp[15]="CUPS_SERVER=/var/run/cups/cups.sock"
D [29/Jul/2015:16:54:13 +0200] [Job 4] envp[16]="CUPS_ENCRYPTION=IfRequested"
D [29/Jul/2015:16:54:13 +0200] [Job 4] envp[17]="IPP_PORT=631"
D [29/Jul/2015:16:54:13 +0200] [Job 4] envp[18]="CHARSET=utf-8"
D [29/Jul/2015:16:54:13 +0200] [Job 4] envp[19]="LANG=en_GB.UTF-8"
D [29/Jul/2015:16:54:13 +0200] [Job 4] envp[20]="PPD=/etc/cups/ppd/tofile-boomaga.ppd"
D [29/Jul/2015:16:54:13 +0200] [Job 4] envp[21]="RIP_MAX_CACHE=128m"
D [29/Jul/2015:16:54:13 +0200] [Job 4] envp[22]="CONTENT_TYPE=text/plain"
D [29/Jul/2015:16:54:13 +0200] [Job 4] envp[23]="DEVICE_URI=file:/home/michi/tofile-boomaga"
D [29/Jul/2015:16:54:13 +0200] [Job 4] envp[24]="PRINTER_INFO=tofile-boomaga"
D [29/Jul/2015:16:54:13 +0200] [Job 4] envp[25]="PRINTER_LOCATION="
D [29/Jul/2015:16:54:13 +0200] [Job 4] envp[26]="PRINTER=tofile-boomaga"
D [29/Jul/2015:16:54:13 +0200] [Job 4] envp[27]="PRINTER_STATE_REASONS=none"
D [29/Jul/2015:16:54:13 +0200] [Job 4] envp[28]="CUPS_FILETYPE=document"
D [29/Jul/2015:16:54:13 +0200] [Job 4] envp[29]="FINAL_CONTENT_TYPE=application/pdf"
D [29/Jul/2015:16:54:13 +0200] [Job 4] envp[30]="AUTH_I****"
I [29/Jul/2015:16:54:13 +0200] [Job 4] Started filter /usr/lib/cups/filter/texttopdf (PID 1320)
D [29/Jul/2015:16:54:13 +0200] Discarding unused job-state-changed event...
D [29/Jul/2015:16:54:13 +0200] [Client 3] Returning IPP successful-ok for Send-Document (ipp://localhost:631/printers/tofile-boomaga) from localhost
D [29/Jul/2015:16:54:13 +0200] [Client 3] Content-Length: 169
D [29/Jul/2015:16:54:13 +0200] [Client 3] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [29/Jul/2015:16:54:13 +0200] [Client 3] con->http=0x7f1b381f75a0
D [29/Jul/2015:16:54:13 +0200] [Client 3] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=169, response=0x7f1b381f68b0(IPP_STATE_DATA), pipe_pid=0, file=-1
D [29/Jul/2015:16:54:13 +0200] [Client 3] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [29/Jul/2015:16:54:13 +0200] [Client 3] bytes=0, http_state=0, data_remaining=169
D [29/Jul/2015:16:54:13 +0200] [Client 3] Flushing write buffer.
D [29/Jul/2015:16:54:13 +0200] [Client 3] New state is HTTP_STATE_WAITING
D [29/Jul/2015:16:54:13 +0200] [Client 3] Waiting for request.
D [29/Jul/2015:16:54:13 +0200] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients and dirty files"
D [29/Jul/2015:16:54:13 +0200] [Client 3] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [29/Jul/2015:16:54:13 +0200] [Client 3] Closing connection.
D [29/Jul/2015:16:54:13 +0200] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [29/Jul/2015:16:54:13 +0200] [Job 4] Page = 595x842; 18,36 to 577,806
D [29/Jul/2015:16:54:14 +0200] [Job 4] PID 1320 (/usr/lib/cups/filter/texttopdf) exited with no errors.
D [29/Jul/2015:16:54:14 +0200] [Job 4] time-at-completed=1438181654
D [29/Jul/2015:16:54:14 +0200] Discarding unused job-completed event...
I [29/Jul/2015:16:54:14 +0200] [Job 4] Job completed.
D [29/Jul/2015:16:54:14 +0200] cupsdMarkDirty(---J-)
D [29/Jul/2015:16:54:14 +0200] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [29/Jul/2015:16:54:14 +0200] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [29/Jul/2015:16:54:14 +0200] cupsdMarkDirty(----S)
D [29/Jul/2015:16:54:14 +0200] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [29/Jul/2015:16:54:14 +0200] cupsdMarkDirty(---J-)
D [29/Jul/2015:16:54:14 +0200] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [29/Jul/2015:16:54:14 +0200] cupsdMarkDirty(---J-)
D [29/Jul/2015:16:54:14 +0200] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [29/Jul/2015:16:54:15 +0200] [Job 4] Unloading...
