cups_error

d [28/Nov/2013:14:10:46 +0100] cupsdAcceptClient(lis=0x7f6c91fd9cc0(10)) Clients=0
D [28/Nov/2013:14:10:46 +0100] cupsdAcceptClient: 15 from localhost (Domain)
d [28/Nov/2013:14:10:46 +0100] cupsdAddSelect(fd=15, read_cb=0x7f6c904d7cb0, write_cb=(nil), data=0x7f6c91fe4150)
d [28/Nov/2013:14:10:46 +0100] cupsdCheckJobs: 0 active jobs, sleeping=0, reload=0
D [28/Nov/2013:14:10:46 +0100] Report: clients=1
D [28/Nov/2013:14:10:46 +0100] Report: jobs=237
D [28/Nov/2013:14:10:46 +0100] Report: jobs-active=0
D [28/Nov/2013:14:10:46 +0100] Report: printers=1
D [28/Nov/2013:14:10:46 +0100] Report: printers-implicit=0
D [28/Nov/2013:14:10:46 +0100] Report: stringpool-string-count=1479
D [28/Nov/2013:14:10:46 +0100] Report: stringpool-alloc-bytes=9768
D [28/Nov/2013:14:10:46 +0100] Report: stringpool-total-bytes=26720
d [28/Nov/2013:14:10:46 +0100] cupsdReadClient(con=0x7f6c91fe4150(15)) con->http.error=0 con->http.used=0, con->http.state=0 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=0, con->file=-1
D [28/Nov/2013:14:10:46 +0100] cupsdReadClient: 15 POST / HTTP/1.1
D [28/Nov/2013:14:10:46 +0100] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
d [28/Nov/2013:14:10:46 +0100] cupsdFindBest: uri = "/"...
d [28/Nov/2013:14:10:46 +0100] cupsdFindBest: Location CUPS_INTERNAL_BROWSE_ACL Limit 0
d [28/Nov/2013:14:10:46 +0100] cupsdFindBest: Location /admin/conf Limit 7f
d [28/Nov/2013:14:10:46 +0100] cupsdFindBest: Location /admin Limit 7f
d [28/Nov/2013:14:10:46 +0100] cupsdFindBest: Location / Limit 7f
d [28/Nov/2013:14:10:46 +0100] cupsdFindBest: best = /
d [28/Nov/2013:14:10:46 +0100] cupsdAuthorize: con->uri="/", con->best=0x7f6c91fda100(/)
d [28/Nov/2013:14:10:46 +0100] cupsdAuthorize: Authorization=""
D [28/Nov/2013:14:10:46 +0100] cupsdAuthorize: No authentication data provided.
d [28/Nov/2013:14:10:46 +0100] cupsdIsAuthorized: con->uri="/", con->best=0x7f6c91fda100(/)
d [28/Nov/2013:14:10:46 +0100] cupsdIsAuthorized: level=CUPSD_AUTH_ANON, type=None, satisfy=CUPSD_AUTH_SATISFY_ALL, num_names=0
d [28/Nov/2013:14:10:46 +0100] cupsdIsAuthorized: auth=CUPSD_AUTH_ALLOW...
d [28/Nov/2013:14:10:46 +0100] cupsdReadClient(con=0x7f6c91fe4150(15)) con->http.error=0 con->http.used=682, con->http.state=6 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=682, con->file=-1
d [28/Nov/2013:14:10:46 +0100] cupsdReadClient(con=0x7f6c91fe4150(15)) con->http.error=0 con->http.used=653, con->http.state=6 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=653, con->file=-1
d [28/Nov/2013:14:10:46 +0100] cupsdReadClient(con=0x7f6c91fe4150(15)) con->http.error=0 con->http.used=616, con->http.state=6 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=616, con->file=-1
d [28/Nov/2013:14:10:46 +0100] cupsdReadClient(con=0x7f6c91fe4150(15)) con->http.error=0 con->http.used=573, con->http.state=6 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=573, con->file=-1
d [28/Nov/2013:14:10:46 +0100] cupsdReadClient(con=0x7f6c91fe4150(15)) con->http.error=0 con->http.used=558, con->http.state=6 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=558, con->file=-1
d [28/Nov/2013:14:10:46 +0100] cupsdReadClient(con=0x7f6c91fe4150(15)) con->http.error=0 con->http.used=535, con->http.state=6 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=535, con->file=-1
d [28/Nov/2013:14:10:46 +0100] cupsdReadClient(con=0x7f6c91fe4150(15)) con->http.error=0 con->http.used=512, con->http.state=6 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=512, con->file=-1
d [28/Nov/2013:14:10:46 +0100] cupsdReadClient(con=0x7f6c91fe4150(15)) con->http.error=0 con->http.used=494, con->http.state=6 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=494, con->file=-1
d [28/Nov/2013:14:10:46 +0100] cupsdReadClient(con=0x7f6c91fe4150(15)) con->http.error=0 con->http.used=471, con->http.state=6 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=471, con->file=-1
d [28/Nov/2013:14:10:46 +0100] cupsdReadClient(con=0x7f6c91fe4150(15)) con->http.error=0 con->http.used=453, con->http.state=6 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=453, con->file=-1
d [28/Nov/2013:14:10:46 +0100] cupsdReadClient(con=0x7f6c91fe4150(15)) con->http.error=0 con->http.used=431, con->http.state=6 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=431, con->file=-1
d [28/Nov/2013:14:10:46 +0100] cupsdReadClient(con=0x7f6c91fe4150(15)) con->http.error=0 con->http.used=412, con->http.state=6 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=412, con->file=-1
d [28/Nov/2013:14:10:46 +0100] cupsdReadClient(con=0x7f6c91fe4150(15)) con->http.error=0 con->http.used=395, con->http.state=6 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=395, con->file=-1
d [28/Nov/2013:14:10:46 +0100] cupsdReadClient(con=0x7f6c91fe4150(15)) con->http.error=0 con->http.used=378, con->http.state=6 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=378, con->file=-1
d [28/Nov/2013:14:10:46 +0100] cupsdReadClient(con=0x7f6c91fe4150(15)) con->http.error=0 con->http.used=357, con->http.state=6 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=357, con->file=-1
d [28/Nov/2013:14:10:46 +0100] cupsdReadClient(con=0x7f6c91fe4150(15)) con->http.error=0 con->http.used=336, con->http.state=6 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=336, con->file=-1
d [28/Nov/2013:14:10:46 +0100] cupsdReadClient(con=0x7f6c91fe4150(15)) con->http.error=0 con->http.used=319, con->http.state=6 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=319, con->file=-1
d [28/Nov/2013:14:10:46 +0100] cupsdReadClient(con=0x7f6c91fe4150(15)) con->http.error=0 con->http.used=289, con->http.state=6 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=289, con->file=-1
d [28/Nov/2013:14:10:46 +0100] cupsdReadClient(con=0x7f6c91fe4150(15)) con->http.error=0 con->http.used=267, con->http.state=6 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=267, con->file=-1
d [28/Nov/2013:14:10:46 +0100] cupsdReadClient(con=0x7f6c91fe4150(15)) con->http.error=0 con->http.used=246, con->http.state=6 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=246, con->file=-1
d [28/Nov/2013:14:10:46 +0100] cupsdReadClient(con=0x7f6c91fe4150(15)) con->http.error=0 con->http.used=219, con->http.state=6 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=219, con->file=-1
d [28/Nov/2013:14:10:46 +0100] cupsdReadClient(con=0x7f6c91fe4150(15)) con->http.error=0 con->http.used=202, con->http.state=6 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=202, con->file=-1
d [28/Nov/2013:14:10:46 +0100] cupsdReadClient(con=0x7f6c91fe4150(15)) con->http.error=0 con->http.used=184, con->http.state=6 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=184, con->file=-1
d [28/Nov/2013:14:10:46 +0100] cupsdReadClient(con=0x7f6c91fe4150(15)) con->http.error=0 con->http.used=154, con->http.state=6 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=154, con->file=-1
d [28/Nov/2013:14:10:46 +0100] cupsdReadClient(con=0x7f6c91fe4150(15)) con->http.error=0 con->http.used=128, con->http.state=6 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=128, con->file=-1
d [28/Nov/2013:14:10:46 +0100] cupsdReadClient(con=0x7f6c91fe4150(15)) con->http.error=0 con->http.used=111, con->http.state=6 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=111, con->file=-1
d [28/Nov/2013:14:10:46 +0100] cupsdReadClient(con=0x7f6c91fe4150(15)) con->http.error=0 con->http.used=85, con->http.state=6 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=85, con->file=-1
d [28/Nov/2013:14:10:46 +0100] cupsdReadClient(con=0x7f6c91fe4150(15)) con->http.error=0 con->http.used=56, con->http.state=6 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=56, con->file=-1
d [28/Nov/2013:14:10:46 +0100] cupsdReadClient(con=0x7f6c91fe4150(15)) con->http.error=0 con->http.used=1, con->http.state=6 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=1, con->file=-1
D [28/Nov/2013:14:10:46 +0100] cupsdReadClient: 15 1.1 Get-Printer-Attributes 1
d [28/Nov/2013:14:10:46 +0100] cupsdProcessIPPRequest(0x7f6c91fe4150[15]): operation_id = 000b
D [28/Nov/2013:14:10:46 +0100] Get-Printer-Attributes ipp://localhost:631/printers/SIJN_BLP01
d [28/Nov/2013:14:10:46 +0100] get_printer_attrs(0x7f6c91fe4150[15], ipp://localhost:631/printers/SIJN_BLP01)
d [28/Nov/2013:14:10:46 +0100] cupsdFindPolicyOp(p=0x7f6c91fd3cf0, op=b(Get-Printer-Attributes))
d [28/Nov/2013:14:10:46 +0100] cupsdFindPolicyOp: Found wildcard match...
d [28/Nov/2013:14:10:46 +0100] cupsdIsAuthorized: con->uri="/", con->best=0x7f6c91fcde00((null))
d [28/Nov/2013:14:10:46 +0100] cupsdIsAuthorized: level=CUPSD_AUTH_ANON, type=None, satisfy=CUPSD_AUTH_SATISFY_ALL, num_names=0
d [28/Nov/2013:14:10:46 +0100] cupsdIsAuthorized: op=0(0x0000)
d [28/Nov/2013:14:10:46 +0100] cupsdIsAuthorized: auth=CUPSD_AUTH_ALLOW...
d [28/Nov/2013:14:10:46 +0100] add_printer_state_reasons(0x7f6c91fe4150[15], 0x7f6c91f70a80[SIJN_BLP01])
d [28/Nov/2013:14:10:46 +0100] printer-uri-supported="ipp://localhost:631/printers/SIJN_BLP01"
d [28/Nov/2013:14:10:46 +0100] copy_attrs(to=0x7f6c91f87700, from=0x7f6c91f71cf0, ra=0x7f6c91f5e680, group=0, quickcopy=0)
d [28/Nov/2013:14:10:46 +0100] copy_attribute(0x7f6c91f87700, 0x7f6c91f5d590[printer-name,4,42])
d [28/Nov/2013:14:10:46 +0100] copy_attribute(0x7f6c91f87700, 0x7f6c91ff5b80[printer-location,4,41])
d [28/Nov/2013:14:10:46 +0100] copy_attribute(0x7f6c91f87700, 0x7f6c91ffb120[printer-info,4,41])
d [28/Nov/2013:14:10:46 +0100] copy_attribute(0x7f6c91f87700, 0x7f6c91ff0f10[auth-info-required,4,44])
d [28/Nov/2013:14:10:46 +0100] copy_attribute(0x7f6c91f87700, 0x7f6c91f717a0[job-sheets-default,4,42])
d [28/Nov/2013:14:10:46 +0100] copy_attribute(0x7f6c91f87700, 0x7f6c91ffac00[device-uri,4,45])
d [28/Nov/2013:14:10:46 +0100] copy_attribute(0x7f6c91f87700, 0x7f6c91ff4420[marker-colors,4,42])
d [28/Nov/2013:14:10:46 +0100] copy_attribute(0x7f6c91f87700, 0x7f6c91ff4460[marker-levels,4,21])
d [28/Nov/2013:14:10:46 +0100] copy_attribute(0x7f6c91f87700, 0x7f6c91ff44a0[marker-types,4,44])
d [28/Nov/2013:14:10:46 +0100] copy_attribute(0x7f6c91f87700, 0x7f6c91f60080[copies-default,4,21])
d [28/Nov/2013:14:10:46 +0100] copy_attribute(0x7f6c91f87700, 0x7f6c91f5e2b0[document-format-default,4,49])
d [28/Nov/2013:14:10:46 +0100] copy_attribute(0x7f6c91f87700, 0x7f6c91fa4840[job-hold-until-default,4,44])
d [28/Nov/2013:14:10:46 +0100] copy_attribute(0x7f6c91f87700, 0x7f6c91fa3920[job-priority-default,4,21])
d [28/Nov/2013:14:10:46 +0100] copy_attribute(0x7f6c91f87700, 0x7f6c91f5e520[number-up-default,4,21])
d [28/Nov/2013:14:10:46 +0100] copy_attribute(0x7f6c91f87700, 0x7f6c91ff2830[orientation-requested-default,4,13])
d [28/Nov/2013:14:10:46 +0100] copy_attrs(to=0x7f6c91f87700, from=0x7f6c91f5d8a0, ra=0x7f6c91f5e680, group=0, quickcopy=0)
d [28/Nov/2013:14:10:46 +0100] copy_attribute(0x7f6c91f87700, 0x7f6c91f5ee60[printer-make-and-model,4,41])
d [28/Nov/2013:14:10:46 +0100] copy_attribute(0x7f6c91f87700, 0x7f6c91fc6350[media-col-default,4,34])
d [28/Nov/2013:14:10:46 +0100] copy_attribute(0x7f6c91f87700, 0x7f6c91ff1f20[printer-commands,4,44])
d [28/Nov/2013:14:10:46 +0100] copy_attribute(0x7f6c91f87700, 0x7f6c91ff20a0[finishings-default,4,23])
d [28/Nov/2013:14:10:46 +0100] copy_attrs(to=0x7f6c91f87700, from=0x7f6c91f6b570, ra=0x7f6c91f5e680, group=0, quickcopy=-2147483648)
D [28/Nov/2013:14:10:46 +0100] Returning IPP successful-ok for Get-Printer-Attributes (ipp://localhost:631/printers/SIJN_BLP01) from localhost
d [28/Nov/2013:14:10:46 +0100] cupsdProcessIPPRequest: ippLength(response)=1150
d [28/Nov/2013:14:10:46 +0100] cupsdAddSelect(fd=15, read_cb=0x7f6c904d7cb0, write_cb=0x7f6c904d7660, data=0x7f6c91fe4150)
d [28/Nov/2013:14:10:46 +0100] select_timeout(0): 301 seconds to timeout a client connection
d [28/Nov/2013:14:10:46 +0100] cupsdWriteClient(con=0x7f6c91fe4150(15)) response=0x7f6c91f87700(0), file=-1 pipe_pid=0 state=7
d [28/Nov/2013:14:10:46 +0100] cupsdWriteClient(con=0x7f6c91fe4150(15)) response=0x7f6c91f87700(2), file=-1 pipe_pid=0 state=7
d [28/Nov/2013:14:10:46 +0100] cupsdWriteClient(con=0x7f6c91fe4150(15)) response=0x7f6c91f87700(2), file=-1 pipe_pid=0 state=7
d [28/Nov/2013:14:10:46 +0100] cupsdWriteClient(con=0x7f6c91fe4150(15)) response=0x7f6c91f87700(2), file=-1 pipe_pid=0 state=7
d [28/Nov/2013:14:10:46 +0100] cupsdWriteClient(con=0x7f6c91fe4150(15)) response=0x7f6c91f87700(2), file=-1 pipe_pid=0 state=7
d [28/Nov/2013:14:10:46 +0100] cupsdWriteClient(con=0x7f6c91fe4150(15)) response=0x7f6c91f87700(2), file=-1 pipe_pid=0 state=7
d [28/Nov/2013:14:10:46 +0100] cupsdWriteClient(con=0x7f6c91fe4150(15)) response=0x7f6c91f87700(2), file=-1 pipe_pid=0 state=7
d [28/Nov/2013:14:10:46 +0100] cupsdWriteClient(con=0x7f6c91fe4150(15)) response=0x7f6c91f87700(2), file=-1 pipe_pid=0 state=7
d [28/Nov/2013:14:10:46 +0100] cupsdWriteClient(con=0x7f6c91fe4150(15)) response=0x7f6c91f87700(2), file=-1 pipe_pid=0 state=7
d [28/Nov/2013:14:10:46 +0100] cupsdWriteClient(con=0x7f6c91fe4150(15)) response=0x7f6c91f87700(2), file=-1 pipe_pid=0 state=7
d [28/Nov/2013:14:10:46 +0100] cupsdWriteClient(con=0x7f6c91fe4150(15)) response=0x7f6c91f87700(2), file=-1 pipe_pid=0 state=7
d [28/Nov/2013:14:10:46 +0100] cupsdWriteClient(con=0x7f6c91fe4150(15)) response=0x7f6c91f87700(2), file=-1 pipe_pid=0 state=7
d [28/Nov/2013:14:10:46 +0100] cupsdWriteClient(con=0x7f6c91fe4150(15)) response=0x7f6c91f87700(2), file=-1 pipe_pid=0 state=7
d [28/Nov/2013:14:10:46 +0100] cupsdWriteClient(con=0x7f6c91fe4150(15)) response=0x7f6c91f87700(2), file=-1 pipe_pid=0 state=7
d [28/Nov/2013:14:10:46 +0100] cupsdWriteClient(con=0x7f6c91fe4150(15)) response=0x7f6c91f87700(2), file=-1 pipe_pid=0 state=7
d [28/Nov/2013:14:10:46 +0100] cupsdWriteClient(con=0x7f6c91fe4150(15)) response=0x7f6c91f87700(2), file=-1 pipe_pid=0 state=7
d [28/Nov/2013:14:10:46 +0100] cupsdWriteClient(con=0x7f6c91fe4150(15)) response=0x7f6c91f87700(2), file=-1 pipe_pid=0 state=7
d [28/Nov/2013:14:10:46 +0100] cupsdWriteClient(con=0x7f6c91fe4150(15)) response=0x7f6c91f87700(2), file=-1 pipe_pid=0 state=7
d [28/Nov/2013:14:10:46 +0100] cupsdWriteClient(con=0x7f6c91fe4150(15)) response=0x7f6c91f87700(2), file=-1 pipe_pid=0 state=7
d [28/Nov/2013:14:10:46 +0100] cupsdWriteClient(con=0x7f6c91fe4150(15)) response=0x7f6c91f87700(2), file=-1 pipe_pid=0 state=7
d [28/Nov/2013:14:10:46 +0100] cupsdWriteClient(con=0x7f6c91fe4150(15)) response=0x7f6c91f87700(2), file=-1 pipe_pid=0 state=7
d [28/Nov/2013:14:10:46 +0100] cupsdWriteClient(con=0x7f6c91fe4150(15)) response=0x7f6c91f87700(2), file=-1 pipe_pid=0 state=7
d [28/Nov/2013:14:10:46 +0100] cupsdWriteClient(con=0x7f6c91fe4150(15)) response=0x7f6c91f87700(2), file=-1 pipe_pid=0 state=7
d [28/Nov/2013:14:10:46 +0100] cupsdWriteClient(con=0x7f6c91fe4150(15)) response=0x7f6c91f87700(2), file=-1 pipe_pid=0 state=7
d [28/Nov/2013:14:10:46 +0100] cupsdWriteClient(con=0x7f6c91fe4150(15)) response=0x7f6c91f87700(2), file=-1 pipe_pid=0 state=7
d [28/Nov/2013:14:10:46 +0100] cupsdWriteClient(con=0x7f6c91fe4150(15)) response=0x7f6c91f87700(2), file=-1 pipe_pid=0 state=7
d [28/Nov/2013:14:10:46 +0100] cupsdWriteClient(con=0x7f6c91fe4150(15)) response=0x7f6c91f87700(2), file=-1 pipe_pid=0 state=7
d [28/Nov/2013:14:10:46 +0100] cupsdWriteClient(con=0x7f6c91fe4150(15)) response=0x7f6c91f87700(2), file=-1 pipe_pid=0 state=7
d [28/Nov/2013:14:10:46 +0100] cupsdWriteClient(con=0x7f6c91fe4150(15)) response=0x7f6c91f87700(2), file=-1 pipe_pid=0 state=7
d [28/Nov/2013:14:10:46 +0100] cupsdWriteClient(con=0x7f6c91fe4150(15)) response=0x7f6c91f87700(2), file=-1 pipe_pid=0 state=7
d [28/Nov/2013:14:10:46 +0100] cupsdAddSelect(fd=15, read_cb=0x7f6c904d7cb0, write_cb=(nil), data=0x7f6c91fe4150)
D [28/Nov/2013:14:10:46 +0100] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
d [28/Nov/2013:14:10:46 +0100] cupsdReadClient(con=0x7f6c91fe4150(15)) con->http.error=0 con->http.used=0, con->http.state=0 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=0, con->file=-1
D [28/Nov/2013:14:10:46 +0100] cupsdReadClient: 15 POST /printers/SIJN_BLP01 HTTP/1.1
D [28/Nov/2013:14:10:46 +0100] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
d [28/Nov/2013:14:10:46 +0100] cupsdFindBest: uri = "/printers/SIJN_BLP01"...
d [28/Nov/2013:14:10:46 +0100] cupsdFindBest: Location CUPS_INTERNAL_BROWSE_ACL Limit 0
d [28/Nov/2013:14:10:46 +0100] cupsdFindBest: Location /admin/conf Limit 7f
d [28/Nov/2013:14:10:46 +0100] cupsdFindBest: Location /admin Limit 7f
d [28/Nov/2013:14:10:46 +0100] cupsdFindBest: Location / Limit 7f
d [28/Nov/2013:14:10:46 +0100] cupsdFindBest: best = /
d [28/Nov/2013:14:10:46 +0100] cupsdAuthorize: con->uri="/printers/SIJN_BLP01", con->best=0x7f6c91fda100(/)
d [28/Nov/2013:14:10:46 +0100] cupsdAuthorize: Authorization=""
D [28/Nov/2013:14:10:46 +0100] cupsdAuthorize: No authentication data provided.
d [28/Nov/2013:14:10:46 +0100] cupsdIsAuthorized: con->uri="/printers/SIJN_BLP01", con->best=0x7f6c91fda100(/)
d [28/Nov/2013:14:10:46 +0100] cupsdIsAuthorized: level=CUPSD_AUTH_ANON, type=None, satisfy=CUPSD_AUTH_SATISFY_ALL, num_names=0
d [28/Nov/2013:14:10:46 +0100] cupsdIsAuthorized: auth=CUPSD_AUTH_ALLOW...
d [28/Nov/2013:14:10:46 +0100] cupsdReadClient(con=0x7f6c91fe4150(15)) con->http.error=0 con->http.used=339, con->http.state=6 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=339, con->file=-1
d [28/Nov/2013:14:10:46 +0100] cupsdReadClient(con=0x7f6c91fe4150(15)) con->http.error=0 con->http.used=310, con->http.state=6 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=310, con->file=-1
d [28/Nov/2013:14:10:46 +0100] cupsdReadClient(con=0x7f6c91fe4150(15)) con->http.error=0 con->http.used=273, con->http.state=6 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=273, con->file=-1
d [28/Nov/2013:14:10:46 +0100] cupsdReadClient(con=0x7f6c91fe4150(15)) con->http.error=0 con->http.used=218, con->http.state=6 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=218, con->file=-1
d [28/Nov/2013:14:10:46 +0100] cupsdReadClient(con=0x7f6c91fe4150(15)) con->http.error=0 con->http.used=189, con->http.state=6 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=189, con->file=-1
d [28/Nov/2013:14:10:46 +0100] cupsdReadClient(con=0x7f6c91fe4150(15)) con->http.error=0 con->http.used=173, con->http.state=6 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=173, con->file=-1
d [28/Nov/2013:14:10:46 +0100] cupsdReadClient(con=0x7f6c91fe4150(15)) con->http.error=0 con->http.used=129, con->http.state=6 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=129, con->file=-1
d [28/Nov/2013:14:10:46 +0100] cupsdReadClient(con=0x7f6c91fe4150(15)) con->http.error=0 con->http.used=113, con->http.state=6 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=113, con->file=-1
d [28/Nov/2013:14:10:46 +0100] cupsdReadClient(con=0x7f6c91fe4150(15)) con->http.error=0 con->http.used=94, con->http.state=6 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=94, con->file=-1
d [28/Nov/2013:14:10:46 +0100] cupsdReadClient(con=0x7f6c91fe4150(15)) con->http.error=0 con->http.used=68, con->http.state=6 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=68, con->file=-1
d [28/Nov/2013:14:10:46 +0100] cupsdReadClient(con=0x7f6c91fe4150(15)) con->http.error=0 con->http.used=47, con->http.state=6 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=47, con->file=-1
d [28/Nov/2013:14:10:46 +0100] cupsdReadClient(con=0x7f6c91fe4150(15)) con->http.error=0 con->http.used=28, con->http.state=6 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=28, con->file=-1
d [28/Nov/2013:14:10:46 +0100] cupsdReadClient(con=0x7f6c91fe4150(15)) con->http.error=0 con->http.used=19, con->http.state=6 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=19, con->file=-1
d [28/Nov/2013:14:10:46 +0100] cupsdReadClient(con=0x7f6c91fe4150(15)) con->http.error=0 con->http.used=1, con->http.state=6 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=1, con->file=-1
D [28/Nov/2013:14:10:46 +0100] cupsdReadClient: 15 1.1 Create-Job 1
d [28/Nov/2013:14:10:46 +0100] cupsdProcessIPPRequest(0x7f6c91fe4150[15]): operation_id = 0005
D [28/Nov/2013:14:10:46 +0100] Create-Job ipp://localhost:631/printers/SIJN_BLP01
d [28/Nov/2013:14:10:46 +0100] create_job(0x7f6c91fe4150[15], ipp://localhost:631/printers/SIJN_BLP01)
d [28/Nov/2013:14:10:46 +0100] add_job(0x7f6c91fe4150[15], 0x7f6c91f70a80(SIJN_BLP01), (nil)(none/none))
d [28/Nov/2013:14:10:46 +0100] cupsdFindPolicyOp(p=0x7f6c91fd3cf0, op=5(Create-Job))
d [28/Nov/2013:14:10:46 +0100] cupsdFindPolicyOp: Found wildcard match...
d [28/Nov/2013:14:10:46 +0100] cupsdIsAuthorized: con->uri="/printers/SIJN_BLP01", con->best=0x7f6c91fcde00((null))
d [28/Nov/2013:14:10:46 +0100] cupsdIsAuthorized: level=CUPSD_AUTH_ANON, type=None, satisfy=CUPSD_AUTH_SATISFY_ALL, num_names=0
d [28/Nov/2013:14:10:46 +0100] cupsdIsAuthorized: op=0(0x0000)
d [28/Nov/2013:14:10:46 +0100] cupsdIsAuthorized: auth=CUPSD_AUTH_ALLOW...
d [28/Nov/2013:14:10:46 +0100] check_quotas(0x7f6c91fe4150[15], 0x7f6c91f70a80[SIJN_BLP01])
D [28/Nov/2013:14:10:46 +0100] cupsdMarkDirty(----J-)
D [28/Nov/2013:14:10:46 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients"
D [28/Nov/2013:14:10:46 +0100] add_job: requesting-user-name="root"
I [28/Nov/2013:14:10:46 +0100] [Job 241] Adding start banner page "none".
d [28/Nov/2013:14:10:46 +0100] copy_banner(con=0x7f6c91fe4150[15], job=0x7f6c91f5ce60[241], name="none")
d [28/Nov/2013:14:10:46 +0100] add_job_state_reasons(0x7f6c91fe4150[15], 241)
d [28/Nov/2013:14:10:46 +0100] cupsdAddEvent(event=job-created, dest=0x7f6c91f70a80(SIJN_BLP01), job=0x7f6c91f5ce60(241), text="Job created.", ...)
D [28/Nov/2013:14:10:46 +0100] Discarding unused job-created event...
I [28/Nov/2013:14:10:46 +0100] [Job 241] Queued on "SIJN_BLP01" by "root".
D [28/Nov/2013:14:10:46 +0100] Returning IPP successful-ok for Create-Job (ipp://localhost:631/printers/SIJN_BLP01) from localhost
d [28/Nov/2013:14:10:46 +0100] cupsdProcessIPPRequest: ippLength(response)=183
d [28/Nov/2013:14:10:46 +0100] cupsdAddSelect(fd=15, read_cb=0x7f6c904d7cb0, write_cb=0x7f6c904d7660, data=0x7f6c91fe4150)
d [28/Nov/2013:14:10:46 +0100] select_timeout(0): 31 seconds to write dirty config/state files
d [28/Nov/2013:14:10:46 +0100] cupsdWriteClient(con=0x7f6c91fe4150(15)) response=0x7f6c91fb0410(0), file=-1 pipe_pid=0 state=7
d [28/Nov/2013:14:10:46 +0100] cupsdWriteClient(con=0x7f6c91fe4150(15)) response=0x7f6c91fb0410(2), file=-1 pipe_pid=0 state=7
d [28/Nov/2013:14:10:46 +0100] cupsdWriteClient(con=0x7f6c91fe4150(15)) response=0x7f6c91fb0410(2), file=-1 pipe_pid=0 state=7
d [28/Nov/2013:14:10:46 +0100] cupsdWriteClient(con=0x7f6c91fe4150(15)) response=0x7f6c91fb0410(2), file=-1 pipe_pid=0 state=7
d [28/Nov/2013:14:10:46 +0100] cupsdWriteClient(con=0x7f6c91fe4150(15)) response=0x7f6c91fb0410(2), file=-1 pipe_pid=0 state=7
d [28/Nov/2013:14:10:46 +0100] cupsdWriteClient(con=0x7f6c91fe4150(15)) response=0x7f6c91fb0410(2), file=-1 pipe_pid=0 state=7
d [28/Nov/2013:14:10:46 +0100] cupsdWriteClient(con=0x7f6c91fe4150(15)) response=0x7f6c91fb0410(2), file=-1 pipe_pid=0 state=7
d [28/Nov/2013:14:10:46 +0100] cupsdAddSelect(fd=15, read_cb=0x7f6c904d7cb0, write_cb=(nil), data=0x7f6c91fe4150)
D [28/Nov/2013:14:10:46 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
d [28/Nov/2013:14:10:46 +0100] cupsdReadClient(con=0x7f6c91fe4150(15)) con->http.error=0 con->http.used=0, con->http.state=0 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=0, con->file=-1
D [28/Nov/2013:14:10:46 +0100] cupsdReadClient: 15 POST /printers/SIJN_BLP01 HTTP/1.1
D [28/Nov/2013:14:10:46 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
d [28/Nov/2013:14:10:46 +0100] cupsdFindBest: uri = "/printers/SIJN_BLP01"...
d [28/Nov/2013:14:10:46 +0100] cupsdFindBest: Location CUPS_INTERNAL_BROWSE_ACL Limit 0
d [28/Nov/2013:14:10:46 +0100] cupsdFindBest: Location /admin/conf Limit 7f
d [28/Nov/2013:14:10:46 +0100] cupsdFindBest: Location /admin Limit 7f
d [28/Nov/2013:14:10:46 +0100] cupsdFindBest: Location / Limit 7f
d [28/Nov/2013:14:10:46 +0100] cupsdFindBest: best = /
d [28/Nov/2013:14:10:46 +0100] cupsdAuthorize: con->uri="/printers/SIJN_BLP01", con->best=0x7f6c91fda100(/)
d [28/Nov/2013:14:10:46 +0100] cupsdAuthorize: Authorization=""
D [28/Nov/2013:14:10:46 +0100] cupsdAuthorize: No authentication data provided.
d [28/Nov/2013:14:10:46 +0100] cupsdIsAuthorized: con->uri="/printers/SIJN_BLP01", con->best=0x7f6c91fda100(/)
d [28/Nov/2013:14:10:46 +0100] cupsdIsAuthorized: level=CUPSD_AUTH_ANON, type=None, satisfy=CUPSD_AUTH_SATISFY_ALL, num_names=0
d [28/Nov/2013:14:10:46 +0100] cupsdIsAuthorized: auth=CUPSD_AUTH_ALLOW...
d [28/Nov/2013:14:10:46 +0100] cupsdReadClient(con=0x7f6c91fe4150(15)) con->http.error=0 con->http.used=252, con->http.state=6 con->data_encoding=HTTP_ENCODE_CHUNKED, con->data_remaining=250, con->file=-1
d [28/Nov/2013:14:10:46 +0100] cupsdReadClient(con=0x7f6c91fe4150(15)) con->http.error=0 con->http.used=223, con->http.state=6 con->data_encoding=HTTP_ENCODE_CHUNKED, con->data_remaining=221, con->file=-1
d [28/Nov/2013:14:10:46 +0100] cupsdReadClient(con=0x7f6c91fe4150(15)) con->http.error=0 con->http.used=186, con->http.state=6 con->data_encoding=HTTP_ENCODE_CHUNKED, con->data_remaining=184, con->file=-1
d [28/Nov/2013:14:10:46 +0100] cupsdReadClient(con=0x7f6c91fe4150(15)) con->http.error=0 con->http.used=131, con->http.state=6 con->data_encoding=HTTP_ENCODE_CHUNKED, con->data_remaining=129, con->file=-1
d [28/Nov/2013:14:10:46 +0100] cupsdReadClient(con=0x7f6c91fe4150(15)) con->http.error=0 con->http.used=116, con->http.state=6 con->data_encoding=HTTP_ENCODE_CHUNKED, con->data_remaining=114, con->file=-1
d [28/Nov/2013:14:10:46 +0100] cupsdReadClient(con=0x7f6c91fe4150(15)) con->http.error=0 con->http.used=87, con->http.state=6 con->data_encoding=HTTP_ENCODE_CHUNKED, con->data_remaining=85, con->file=-1
d [28/Nov/2013:14:10:46 +0100] cupsdReadClient(con=0x7f6c91fe4150(15)) con->http.error=0 con->http.used=66, con->http.state=6 con->data_encoding=HTTP_ENCODE_CHUNKED, con->data_remaining=64, con->file=-1
d [28/Nov/2013:14:10:46 +0100] cupsdReadClient(con=0x7f6c91fe4150(15)) con->http.error=0 con->http.used=22, con->http.state=6 con->data_encoding=HTTP_ENCODE_CHUNKED, con->data_remaining=20, con->file=-1
d [28/Nov/2013:14:10:46 +0100] cupsdReadClient(con=0x7f6c91fe4150(15)) con->http.error=0 con->http.used=3, con->http.state=6 con->data_encoding=HTTP_ENCODE_CHUNKED, con->data_remaining=1, con->file=-1
D [28/Nov/2013:14:10:46 +0100] cupsdReadClient: 15 1.1 Send-Document 1
d [28/Nov/2013:14:10:46 +0100] cupsdProcessIPPRequest(0x7f6c91fe4150[15]): operation_id = 0006
D [28/Nov/2013:14:10:46 +0100] Send-Document ipp://localhost:631/printers/SIJN_BLP01
d [28/Nov/2013:14:10:46 +0100] send_document(0x7f6c91fe4150[15], ipp://localhost:631/printers/SIJN_BLP01)
d [28/Nov/2013:14:10:46 +0100] validate_user(job=241, con=15, owner="root", username=0x7fff94902bd6, userlen=1024)
d [28/Nov/2013:14:10:46 +0100] cupsdFindPolicyOp(p=0x7f6c91fd3cf0, op=6(Send-Document))
d [28/Nov/2013:14:10:46 +0100] cupsdFindPolicyOp: Found exact match...
d [28/Nov/2013:14:10:46 +0100] cupsdIsAuthorized: con->uri="/printers/SIJN_BLP01", con->best=0x7f6c91f4c990((null))
d [28/Nov/2013:14:10:46 +0100] cupsdIsAuthorized: owner="root"
d [28/Nov/2013:14:10:46 +0100] cupsdIsAuthorized: level=CUPSD_AUTH_USER, type=None, satisfy=CUPSD_AUTH_SATISFY_ALL, num_names=2
d [28/Nov/2013:14:10:46 +0100] cupsdIsAuthorized: op=6(Send-Document)
d [28/Nov/2013:14:10:46 +0100] cupsdIsAuthorized: auth=CUPSD_AUTH_ALLOW...
D [28/Nov/2013:14:10:46 +0100] cupsdIsAuthorized: requesting-user-name="root"
D [28/Nov/2013:14:10:46 +0100] [Job 241] Auto-typing file...
D [28/Nov/2013:14:10:46 +0100] [Job 241] Request file type is text/plain.
d [28/Nov/2013:14:10:46 +0100] add_file(con=0x7f6c91fe4150[15], job=241, filetype=text/plain, compression=0)
D [28/Nov/2013:14:10:46 +0100] cupsdMarkDirty(----J-)
D [28/Nov/2013:14:10:46 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
I [28/Nov/2013:14:10:46 +0100] [Job 241] File of type text/plain queued by "root".
I [28/Nov/2013:14:10:46 +0100] [Job 241] Adding end banner page "none".
d [28/Nov/2013:14:10:46 +0100] copy_banner(con=(nil)[-1], job=0x7f6c91f5ce60[241], name="none")
D [28/Nov/2013:14:10:46 +0100] cupsdMarkDirty(----J-)
D [28/Nov/2013:14:10:46 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
d [28/Nov/2013:14:10:46 +0100] add_job_state_reasons(0x7f6c91fe4150[15], 241)
d [28/Nov/2013:14:10:46 +0100] cupsdCheckJobs: 1 active jobs, sleeping=0, reload=0
d [28/Nov/2013:14:10:46 +0100] start_job(job=0x7f6c91f5ce60(241), printer=0x7f6c91f70a80(SIJN_BLP01))
d [28/Nov/2013:14:10:46 +0100] cupsdSetJobState(job=0x7f6c91f5ce60(241), state=3, newstate=5, action=0, message="(null)")
D [28/Nov/2013:14:10:46 +0100] cupsdMarkDirty(----J-)
D [28/Nov/2013:14:10:46 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [28/Nov/2013:14:10:46 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
d [28/Nov/2013:14:10:46 +0100] cupsdAddEvent(event=printer-state-changed, dest=0x7f6c91f70a80(SIJN_BLP01), job=(nil)(0), text="%s "%s" state changed to %s.", ...)
D [28/Nov/2013:14:10:46 +0100] Discarding unused printer-state-changed event...
d [28/Nov/2013:14:10:46 +0100] cupsdSetPrinterReasons(p=0x7f6c91f70a80(SIJN_BLP01),s="-paused"
d [28/Nov/2013:14:10:46 +0100] cupsdSetPrinterReasons(p=0x7f6c91f70a80(SIJN_BLP01),s="-cups-remote-pending,cups-remote-pending-held,cups-remote-processing,cups-remote-stopped,cups-remote-canceled,cups-remote-aborted,cups-remote-completed"
d [28/Nov/2013:14:10:46 +0100] cupsdCreateProfile(job_id=241) = NULL
d [28/Nov/2013:14:10:46 +0100] cupsdContinueJob(job=0x7f6c91f5ce60(241)): current_file=0, num_files=1
D [28/Nov/2013:14:10:46 +0100] [Job 241] job-sheets=none,none
D [28/Nov/2013:14:10:46 +0100] [Job 241] argv[0]="SIJN_BLP01"
D [28/Nov/2013:14:10:46 +0100] [Job 241] argv[1]="241"
D [28/Nov/2013:14:10:46 +0100] [Job 241] argv[2]="root"
D [28/Nov/2013:14:10:46 +0100] [Job 241] argv[3]="bla"
D [28/Nov/2013:14:10:46 +0100] [Job 241] argv[4]="1"
D [28/Nov/2013:14:10:46 +0100] [Job 241] argv[5]="finishings=3 number-up=1 job-uuid=urn:uuid:fdf52b40-ffc0-35e8-6e4d-fb78921ea6ff job-originating-host-name=localhost time-at-creation=1385644246 time-at-processing=1385644246"
D [28/Nov/2013:14:10:46 +0100] [Job 241] argv[6]="/var/spool/cups/d00241-001"
D [28/Nov/2013:14:10:46 +0100] [Job 241] envp[0]="CUPS_CACHEDIR=/var/cache/cups"
D [28/Nov/2013:14:10:46 +0100] [Job 241] envp[1]="CUPS_DATADIR=/usr/share/cups"
D [28/Nov/2013:14:10:46 +0100] [Job 241] envp[2]="CUPS_DOCROOT=/usr/share/cups/doc-root"
D [28/Nov/2013:14:10:46 +0100] [Job 241] envp[3]="CUPS_FONTPATH=/usr/share/cups/fonts"
D [28/Nov/2013:14:10:46 +0100] [Job 241] envp[4]="CUPS_REQUESTROOT=/var/spool/cups"
D [28/Nov/2013:14:10:46 +0100] [Job 241] envp[5]="CUPS_SERVERBIN=/usr/lib/cups"
D [28/Nov/2013:14:10:46 +0100] [Job 241] envp[6]="CUPS_SERVERROOT=/etc/cups"
D [28/Nov/2013:14:10:46 +0100] [Job 241] envp[7]="CUPS_STATEDIR=/var/run/cups"
D [28/Nov/2013:14:10:46 +0100] [Job 241] envp[8]="HOME=/var/spool/cups/tmp"
D [28/Nov/2013:14:10:46 +0100] [Job 241] envp[9]="PATH=/usr/lib/cups/filter:/usr/bin:/usr/sbin:/bin:/usr/bin"
D [28/Nov/2013:14:10:46 +0100] [Job 241] envp[10]="SERVER_ADMIN=root@SIJN-SRV22"
D [28/Nov/2013:14:10:46 +0100] [Job 241] envp[11]="SOFTWARE=CUPS/1.5.3"
D [28/Nov/2013:14:10:46 +0100] [Job 241] envp[12]="TMPDIR=/var/spool/cups/tmp"
D [28/Nov/2013:14:10:46 +0100] [Job 241] envp[13]="USER=root"
D [28/Nov/2013:14:10:46 +0100] [Job 241] envp[14]="CUPS_SERVER=/var/run/cups/cups.sock"
D [28/Nov/2013:14:10:46 +0100] [Job 241] envp[15]="CUPS_ENCRYPTION=IfRequested"
D [28/Nov/2013:14:10:46 +0100] [Job 241] envp[16]="IPP_PORT=631"
D [28/Nov/2013:14:10:46 +0100] [Job 241] envp[17]="CHARSET=utf-8"
D [28/Nov/2013:14:10:46 +0100] [Job 241] envp[18]="LANG=en_US.UTF-8"
D [28/Nov/2013:14:10:46 +0100] [Job 241] envp[19]="PPD=/etc/cups/ppd/SIJN_BLP01.ppd"
D [28/Nov/2013:14:10:46 +0100] [Job 241] envp[20]="RIP_MAX_CACHE=128m"
D [28/Nov/2013:14:10:46 +0100] [Job 241] envp[21]="CONTENT_TYPE=text/plain"
D [28/Nov/2013:14:10:46 +0100] [Job 241] envp[22]="DEVICE_URI=lpd://SIJN-BLP01/BINARY_P1"
D [28/Nov/2013:14:10:46 +0100] [Job 241] envp[23]="PRINTER_INFO=SIJN-BLP01"
D [28/Nov/2013:14:10:46 +0100] [Job 241] envp[24]="PRINTER_LOCATION="
D [28/Nov/2013:14:10:46 +0100] [Job 241] envp[25]="PRINTER=SIJN_BLP01"
D [28/Nov/2013:14:10:46 +0100] [Job 241] envp[26]="PRINTER_STATE_REASONS=none"
D [28/Nov/2013:14:10:46 +0100] [Job 241] envp[27]="CUPS_FILETYPE=document"
D [28/Nov/2013:14:10:46 +0100] [Job 241] envp[28]="FINAL_CONTENT_TYPE=printer/SIJN_BLP01"
D [28/Nov/2013:14:10:46 +0100] [Job 241] envp[29]="AUTH_I****"
d [28/Nov/2013:14:10:46 +0100] cupsdSetPrinterReasons(p=0x7f6c91f70a80(SIJN_BLP01),s="-cups-missing-filter-warning,cups-insecure-filter-warning"
d [28/Nov/2013:14:10:46 +0100] SIJN_BLP01: File "/usr/lib/cups/filter/texttopdf" permissions OK (040755/uid=0/gid=0).
d [28/Nov/2013:14:10:46 +0100] cupsdStartProcess(command="/usr/lib/cups/filter/texttopdf", argv=0x7f6c91f6c7d0, envp=0x7fff948ff420, infd=-1, outfd=23, errfd=17, backfd=18, sidefd=20, root=0, profile=(nil), job=0x7f6c91f5ce60(241), pid=0x7f6c91f5cf34) = 4724
I [28/Nov/2013:14:10:46 +0100] [Job 241] Started filter /usr/lib/cups/filter/texttopdf (PID 4724)
d [28/Nov/2013:14:10:46 +0100] SIJN_BLP01: File "/usr/lib/cups/filter/pdftopdf" permissions OK (040755/uid=0/gid=0).
d [28/Nov/2013:14:10:46 +0100] cupsdStartProcess(command="/usr/lib/cups/filter/pdftopdf", argv=0x7f6c91f6c7d0, envp=0x7fff948ff420, infd=22, outfd=25, errfd=17, backfd=18, sidefd=20, root=0, profile=(nil), job=0x7f6c91f5ce60(241), pid=0x7f6c91f5cf38) = 4725
I [28/Nov/2013:14:10:46 +0100] [Job 241] Started filter /usr/lib/cups/filter/pdftopdf (PID 4725)
d [28/Nov/2013:14:10:46 +0100] SIJN_BLP01: File "/usr/lib/cups/filter/pdftops" permissions OK (040755/uid=0/gid=0).
d [28/Nov/2013:14:10:46 +0100] cupsdStartProcess(command="/usr/lib/cups/filter/pdftops", argv=0x7f6c91f6c7d0, envp=0x7fff948ff420, infd=24, outfd=23, errfd=17, backfd=18, sidefd=20, root=0, profile=(nil), job=0x7f6c91f5ce60(241), pid=0x7f6c91f5cf3c) = 4726
I [28/Nov/2013:14:10:46 +0100] [Job 241] Started filter /usr/lib/cups/filter/pdftops (PID 4726)
d [28/Nov/2013:14:10:46 +0100] SIJN_BLP01: File "/usr/lib/cups/filter/brlpdwrapperql580n" permissions OK (040755/uid=0/gid=0).
d [28/Nov/2013:14:10:46 +0100] cupsdStartProcess(command="/usr/lib/cups/filter/brlpdwrapperql580n", argv=0x7f6c91f6c7d0, envp=0x7fff948ff420, infd=22, outfd=25, errfd=17, backfd=18, sidefd=20, root=0, profile=(nil), job=0x7f6c91f5ce60(241), pid=0x7f6c91f5cf40) = 4727
I [28/Nov/2013:14:10:46 +0100] [Job 241] Started filter /usr/lib/cups/filter/brlpdwrapperql580n (PID 4727)
d [28/Nov/2013:14:10:46 +0100] SIJN_BLP01: File "/usr/lib/cups/backend/lpd" permissions OK (040755/uid=0/gid=0).
d [28/Nov/2013:14:10:46 +0100] cupsdStartProcess(command="/usr/lib/cups/backend/lpd", argv=0x7f6c91f6c7d0, envp=0x7fff948ff420, infd=24, outfd=-1, errfd=17, backfd=19, sidefd=21, root=1, profile=(nil), job=0x7f6c91f5ce60(241), pid=0x7f6c91f5cf88) = 4728
I [28/Nov/2013:14:10:46 +0100] [Job 241] Started backend /usr/lib/cups/backend/lpd (PID 4728)
d [28/Nov/2013:14:10:46 +0100] cupsdAddSelect(fd=16, read_cb=0x7f6c904f7390, write_cb=(nil), data=0x7f6c91f5ce60)
d [28/Nov/2013:14:10:46 +0100] cupsdAddEvent(event=job-state-changed, dest=0x7f6c91f70a80(SIJN_BLP01), job=0x7f6c91f5ce60(241), text="Job #%d started.", ...)
D [28/Nov/2013:14:10:46 +0100] Discarding unused job-state-changed event...
D [28/Nov/2013:14:10:46 +0100] Returning IPP successful-ok for Send-Document (ipp://localhost:631/printers/SIJN_BLP01) from localhost
d [28/Nov/2013:14:10:46 +0100] cupsdProcessIPPRequest: ippLength(response)=175
d [28/Nov/2013:14:10:46 +0100] cupsdAddSelect(fd=15, read_cb=0x7f6c904d7cb0, write_cb=0x7f6c904d7660, data=0x7f6c91fe4150)
d [28/Nov/2013:14:10:46 +0100] cupsdWriteClient(con=0x7f6c91fe4150(15)) response=0x7f6c91f70650(0), file=-1 pipe_pid=0 state=7
d [28/Nov/2013:14:10:46 +0100] cupsdWriteClient(con=0x7f6c91fe4150(15)) response=0x7f6c91f70650(2), file=-1 pipe_pid=0 state=7
d [28/Nov/2013:14:10:46 +0100] cupsdWriteClient(con=0x7f6c91fe4150(15)) response=0x7f6c91f70650(2), file=-1 pipe_pid=0 state=7
d [28/Nov/2013:14:10:46 +0100] cupsdWriteClient(con=0x7f6c91fe4150(15)) response=0x7f6c91f70650(2), file=-1 pipe_pid=0 state=7
d [28/Nov/2013:14:10:46 +0100] cupsdWriteClient(con=0x7f6c91fe4150(15)) response=0x7f6c91f70650(2), file=-1 pipe_pid=0 state=7
d [28/Nov/2013:14:10:46 +0100] cupsdWriteClient(con=0x7f6c91fe4150(15)) response=0x7f6c91f70650(2), file=-1 pipe_pid=0 state=7
d [28/Nov/2013:14:10:46 +0100] cupsdWriteClient(con=0x7f6c91fe4150(15)) response=0x7f6c91f70650(2), file=-1 pipe_pid=0 state=7
d [28/Nov/2013:14:10:46 +0100] cupsdAddSelect(fd=15, read_cb=0x7f6c904d7cb0, write_cb=(nil), data=0x7f6c91fe4150)
D [28/Nov/2013:14:10:46 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients and dirty files"
d [28/Nov/2013:14:10:46 +0100] cupsdReadClient(con=0x7f6c91fe4150(15)) con->http.error=0 con->http.used=0, con->http.state=0 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=0, con->file=-1
D [28/Nov/2013:14:10:46 +0100] cupsdReadClient: 15 WAITING Closing on EOF
D [28/Nov/2013:14:10:46 +0100] cupsdCloseClient: 15
D [28/Nov/2013:14:10:46 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
d [28/Nov/2013:14:10:46 +0100] cupsdRemoveSelect(fd=15)
D [28/Nov/2013:14:10:46 +0100] [Job 241] Page = 176x82; 4,8 to 171,73
D [28/Nov/2013:14:10:46 +0100] [Job 241] pdftops - copying to temp print file "/tmp/01276529f2fb9"
D [28/Nov/2013:14:10:46 +0100] [Job 241] STATE: +connecting-to-device
d [28/Nov/2013:14:10:46 +0100] cupsdSetPrinterReasons(p=0x7f6c91f70a80(SIJN_BLP01),s="+connecting-to-device"
d [28/Nov/2013:14:10:46 +0100] cupsdAddEvent(event=printer-state-changed, dest=0x7f6c91f70a80(SIJN_BLP01), job=(nil)(0), text="Printer "%s" state changed.", ...)
D [28/Nov/2013:14:10:46 +0100] Discarding unused printer-state-changed event...
D [28/Nov/2013:14:10:46 +0100] [Job 241] Looking up "SIJN-BLP01"...
d [28/Nov/2013:14:10:46 +0100] process_children()
d [28/Nov/2013:14:10:46 +0100] cupsdFinishProcess(pid=4724, name=0x7fff94910e30, namelen=1024, job_id=0x7fff94910e2c(241)) = "/usr/lib/cups/filter/texttopdf"
D [28/Nov/2013:14:10:46 +0100] PID 4724 (/usr/lib/cups/filter/texttopdf) exited with no errors.
d [28/Nov/2013:14:10:46 +0100] cupsdFinishProcess(pid=4725, name=0x7fff94910e30, namelen=1024, job_id=0x7fff94910e2c(241)) = "/usr/lib/cups/filter/pdftopdf"
D [28/Nov/2013:14:10:46 +0100] PID 4725 (/usr/lib/cups/filter/pdftopdf) exited with no errors.
d [28/Nov/2013:14:10:46 +0100] select_timeout(-1): 31 seconds to write dirty config/state files
D [28/Nov/2013:14:10:46 +0100] [Job 241] Using image rendering resolution 300 dpi
D [28/Nov/2013:14:10:46 +0100] [Job 241] Started filter pdftops (PID 4737)
D [28/Nov/2013:14:10:46 +0100] [Job 241] Started filter pstops (PID 4738)
D [28/Nov/2013:14:10:46 +0100] [Job 241] Page = 176x82; 4,8 to 171,73
D [28/Nov/2013:14:10:46 +0100] [Job 241] slow_collate=0, slow_duplex=0, slow_order=0
D [28/Nov/2013:14:10:46 +0100] [Job 241] Before copy_comments - %!PS-Adobe-3.0
D [28/Nov/2013:14:10:46 +0100] [Job 241] %!PS-Adobe-3.0
D [28/Nov/2013:14:10:46 +0100] [Job 241] %Produced by poppler pdftops version: 0.18.4 (http://poppler.freedesktop.org)
D [28/Nov/2013:14:10:46 +0100] [Job 241] %%LanguageLevel: 2
D [28/Nov/2013:14:10:46 +0100] [Job 241] %%DocumentSuppliedResources: (atend)
D [28/Nov/2013:14:10:46 +0100] [Job 241] %%DocumentMedia: plain 176 82 0 () ()
D [28/Nov/2013:14:10:46 +0100] [Job 241] %%BoundingBox: 0 0 176 82
D [28/Nov/2013:14:10:46 +0100] [Job 241] %%Pages: 1
D [28/Nov/2013:14:10:46 +0100] [Job 241] %%EndComments
D [28/Nov/2013:14:10:46 +0100] [Job 241] Before copy_prolog - %%BeginDefaults
D [28/Nov/2013:14:10:46 +0100] [Job 241] Before copy_setup - %%BeginSetup
D [28/Nov/2013:14:10:46 +0100] [Job 241] Before page loop - %%Page: 1 1
D [28/Nov/2013:14:10:46 +0100] [Job 241] Copying page 1...
D [28/Nov/2013:14:10:46 +0100] [Job 241] pagew = 167.0, pagel = 65.0
D [28/Nov/2013:14:10:46 +0100] [Job 241] bboxx = 0, bboxy = 0, bboxw = 175, bboxl = 81
D [28/Nov/2013:14:10:46 +0100] [Job 241] PageLeft = 4.3, PageRight = 171.4
D [28/Nov/2013:14:10:46 +0100] [Job 241] PageTop = 73.4, PageBottom = 8.4
D [28/Nov/2013:14:10:46 +0100] [Job 241] PageWidth = 175.7, PageLength = 81.8
D [28/Nov/2013:14:10:46 +0100] [Job 241] Wrote 1 pages...
D [28/Nov/2013:14:10:46 +0100] [Job 241] PID 4737 (pdftops) exited with no errors.
D [28/Nov/2013:14:10:46 +0100] [Job 241] PID 4738 (pstops) exited with no errors.
d [28/Nov/2013:14:10:46 +0100] process_children()
d [28/Nov/2013:14:10:46 +0100] cupsdFinishProcess(pid=4726, name=0x7fff94910e30, namelen=1024, job_id=0x7fff94910e2c(241)) = "/usr/lib/cups/filter/pdftops"
D [28/Nov/2013:14:10:46 +0100] PID 4726 (/usr/lib/cups/filter/pdftops) exited with no errors.
d [28/Nov/2013:14:10:46 +0100] select_timeout(-1): 31 seconds to write dirty config/state files
d [28/Nov/2013:14:10:46 +0100] process_children()
d [28/Nov/2013:14:10:46 +0100] cupsdFinishProcess(pid=4727, name=0x7fff94910e30, namelen=1024, job_id=0x7fff94910e2c(241)) = "/usr/lib/cups/filter/brlpdwrapperql580n"
D [28/Nov/2013:14:10:46 +0100] PID 4727 (/usr/lib/cups/filter/brlpdwrapperql580n) exited with no errors.
d [28/Nov/2013:14:10:46 +0100] select_timeout(-1): 31 seconds to write dirty config/state files
D [28/Nov/2013:14:10:46 +0100] [Job 241] backendWaitLoop(snmp_fd=5, addr=0x7f214b73a5b8, side_cb=0x7f214a04e950)
d [28/Nov/2013:14:10:46 +0100] process_children()
d [28/Nov/2013:14:10:46 +0100] cupsdFinishProcess(pid=4728, name=0x7fff94910e30, namelen=1024, job_id=0x7fff94910e2c(241)) = "/usr/lib/cups/backend/lpd"
D [28/Nov/2013:14:10:46 +0100] PID 4728 (/usr/lib/cups/backend/lpd) exited with no errors.
d [28/Nov/2013:14:10:46 +0100] finalize_job(job=0x7f6c91f5ce60(241))
d [28/Nov/2013:14:10:46 +0100] cupsdSetPrinterReasons(p=0x7f6c91f70a80(SIJN_BLP01),s="-connecting-to-device,cups-remote-pending,cups-remote-pending-held,cups-remote-processing,cups-remote-stopped,cups-remote-canceled,cups-remote-aborted,cups-remote-completed"
d [28/Nov/2013:14:10:46 +0100] cupsdSetPrinterReasons(p=0x7f6c91f70a80(SIJN_BLP01),s="-offline-report"
d [28/Nov/2013:14:10:46 +0100] cupsdDeleteProfile(profile="(null)")
d [28/Nov/2013:14:10:46 +0100] cupsdRemoveSelect(fd=16)
d [28/Nov/2013:14:10:46 +0100] cupsdSetJobState(job=0x7f6c91f5ce60(241), state=5, newstate=9, action=0, message="%s")
d [28/Nov/2013:14:10:46 +0100] stop_job(job=0x7f6c91f5ce60(241), action=0)
d [28/Nov/2013:14:10:46 +0100] cupsdAddEvent(event=job-completed, dest=0x7f6c91f70a80(SIJN_BLP01), job=0x7f6c91f5ce60(241), text="%s", ...)
D [28/Nov/2013:14:10:46 +0100] Discarding unused job-completed event...
I [28/Nov/2013:14:10:46 +0100] [Job 241] Job completed.
D [28/Nov/2013:14:10:46 +0100] cupsdMarkDirty(----J-)
D [28/Nov/2013:14:10:46 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [28/Nov/2013:14:10:46 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
d [28/Nov/2013:14:10:46 +0100] cupsdAddEvent(event=printer-state-changed, dest=0x7f6c91f70a80(SIJN_BLP01), job=(nil)(0), text="%s "%s" state changed to %s.", ...)
D [28/Nov/2013:14:10:46 +0100] Discarding unused printer-state-changed event...
d [28/Nov/2013:14:10:46 +0100] cupsdSetPrinterReasons(p=0x7f6c91f70a80(SIJN_BLP01),s="-paused"
d [28/Nov/2013:14:10:46 +0100] cupsdCheckJobs: 0 active jobs, sleeping=0, reload=0
d [28/Nov/2013:14:10:46 +0100] cupsdCheckJobs: 0 active jobs, sleeping=0, reload=0
d [28/Nov/2013:14:10:47 +0100] cupsdSaveJob(job=0x7f6c91f5ce60(241)): job->attrs=0x7f6c91f87700
D [28/Nov/2013:14:10:47 +0100] [Job 241] Unloading...
d [28/Nov/2013:14:10:47 +0100] select_timeout(0): 30 seconds to write dirty config/state files

cups_log

localhost - - [28/Nov/2013:13:52:40 +0100] "POST /printers/SIJN_BLP01 HTTP/1.1" 200 347 Create-Job successful-ok
localhost - - [28/Nov/2013:13:52:40 +0100] "POST /printers/SIJN_BLP01 HTTP/1.1" 200 284 Send-Document successful-ok