here is my error_log file. Hope it can help.

d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:45 +0100] cupsdWriteClient: 8 bytes < 0
d [29/Oct/2008:12:52:45 +0100] cupsdAddSelect: fd=8, read_cb=0xb8056200, write_cb=(nil), data=0xb91666c0
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: Read on fd 8...
d [29/Oct/2008:12:52:45 +0100] cupsdReadClient: 8, used=0, file=-1 state=0
D [29/Oct/2008:12:52:45 +0100] cupsdReadClient: 8 POST / HTTP/1.1
d [29/Oct/2008:12:52:45 +0100] cupsdFindBest: uri = "/"...
d [29/Oct/2008:12:52:45 +0100] cupsdFindBest: Location CUPS_INTERNAL_BROWSE_ACL Limit 0
d [29/Oct/2008:12:52:45 +0100] cupsdFindBest: Location /admin/conf Limit 7f
d [29/Oct/2008:12:52:45 +0100] cupsdFindBest: Location /admin Limit 7f
d [29/Oct/2008:12:52:45 +0100] cupsdFindBest: Location / Limit 7f
d [29/Oct/2008:12:52:45 +0100] cupsdFindBest: best = /
d [29/Oct/2008:12:52:45 +0100] cupsdAuthorize: con->uri="/", con->best=0xb912e958(/)
d [29/Oct/2008:12:52:45 +0100] cupsdAuthorize: Authorization=""
D [29/Oct/2008:12:52:45 +0100] cupsdAuthorize: No authentication data provided.
d [29/Oct/2008:12:52:45 +0100] cupsdIsAuthorized: con->uri="/", con->best=0xb912e958(/)
d [29/Oct/2008:12:52:45 +0100] cupsdIsAuthorized: level=CUPSD_AUTH_ANON, type=None, satisfy=CUPSD_AUTH_SATISFY_ALL, num_names=0
d [29/Oct/2008:12:52:45 +0100] cupsdIsAuthorized: auth=CUPSD_AUTH_ALLOW...
d [29/Oct/2008:12:52:45 +0100] POST /
d [29/Oct/2008:12:52:45 +0100] CONTENT_TYPE = application/ipp
d [29/Oct/2008:12:52:45 +0100] cupsdReadClient: 8 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=415, con->file=-1
d [29/Oct/2008:12:52:45 +0100] cupsdProcessIPPRequest(0xb91666c0[8]): operation_id = 4005
D [29/Oct/2008:12:52:45 +0100] CUPS-Get-Classes
d [29/Oct/2008:12:52:45 +0100] get_printers(0xb91666c0[8], 1)
d [29/Oct/2008:12:52:45 +0100] cupsdFindPolicyOp(p=0xb912eb48, op=4005(CUPS-Get-Classes))
d [29/Oct/2008:12:52:45 +0100] cupsdFindPolicyOp: Found wildcard match...
d [29/Oct/2008:12:52:45 +0100] cupsdIsAuthorized: con->uri="/", con->best=0xb912fc20((null))
d [29/Oct/2008:12:52:45 +0100] cupsdIsAuthorized: level=CUPSD_AUTH_ANON, type=None, satisfy=CUPSD_AUTH_SATISFY_ALL, num_names=0
d [29/Oct/2008:12:52:45 +0100] cupsdIsAuthorized: op=0(unknown-0000)
d [29/Oct/2008:12:52:45 +0100] cupsdIsAuthorized: auth=CUPSD_AUTH_ALLOW...
D [29/Oct/2008:12:52:45 +0100] cupsdProcessIPPRequest: 8 status_code=0 (successful-ok)
d [29/Oct/2008:12:52:45 +0100] cupsdAddSelect: fd=8, read_cb=0xb8056200, write_cb=0xb80559d0, data=0xb91666c0
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:45 +0100] cupsdWriteClient: 8 bytes < 0
d [29/Oct/2008:12:52:45 +0100] cupsdAddSelect: fd=8, read_cb=0xb8056200, write_cb=(nil), data=0xb91666c0
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: Read on fd 8...
d [29/Oct/2008:12:52:45 +0100] cupsdReadClient: 8, used=0, file=-1 state=0
D [29/Oct/2008:12:52:45 +0100] cupsdReadClient: 8 POST / HTTP/1.1
d [29/Oct/2008:12:52:45 +0100] cupsdFindBest: uri = "/"...
d [29/Oct/2008:12:52:45 +0100] cupsdFindBest: Location CUPS_INTERNAL_BROWSE_ACL Limit 0
d [29/Oct/2008:12:52:45 +0100] cupsdFindBest: Location /admin/conf Limit 7f
d [29/Oct/2008:12:52:45 +0100] cupsdFindBest: Location /admin Limit 7f
d [29/Oct/2008:12:52:45 +0100] cupsdFindBest: Location / Limit 7f
d [29/Oct/2008:12:52:45 +0100] cupsdFindBest: best = /
d [29/Oct/2008:12:52:45 +0100] cupsdAuthorize: con->uri="/", con->best=0xb912e958(/)
d [29/Oct/2008:12:52:45 +0100] cupsdAuthorize: Authorization=""
D [29/Oct/2008:12:52:45 +0100] cupsdAuthorize: No authentication data provided.
d [29/Oct/2008:12:52:45 +0100] cupsdIsAuthorized: con->uri="/", con->best=0xb912e958(/)
d [29/Oct/2008:12:52:45 +0100] cupsdIsAuthorized: level=CUPSD_AUTH_ANON, type=None, satisfy=CUPSD_AUTH_SATISFY_ALL, num_names=0
d [29/Oct/2008:12:52:45 +0100] cupsdIsAuthorized: auth=CUPSD_AUTH_ALLOW...
d [29/Oct/2008:12:52:45 +0100] POST /
d [29/Oct/2008:12:52:45 +0100] CONTENT_TYPE = application/ipp
d [29/Oct/2008:12:52:45 +0100] cupsdReadClient: 8 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=75, con->file=-1
d [29/Oct/2008:12:52:45 +0100] cupsdReadClient: 8, used=67, file=-1 state=6
d [29/Oct/2008:12:52:45 +0100] cupsdReadClient: 8 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=67, con->file=-1
d [29/Oct/2008:12:52:45 +0100] cupsdProcessIPPRequest(0xb91666c0[8]): operation_id = 4001
D [29/Oct/2008:12:52:45 +0100] CUPS-Get-Default
d [29/Oct/2008:12:52:45 +0100] get_default(0xb91666c0[8])
d [29/Oct/2008:12:52:45 +0100] cupsdFindPolicyOp(p=0xb912eb48, op=4001(CUPS-Get-Default))
d [29/Oct/2008:12:52:45 +0100] cupsdFindPolicyOp: Found wildcard match...
d [29/Oct/2008:12:52:45 +0100] cupsdIsAuthorized: con->uri="/", con->best=0xb912fc20((null))
d [29/Oct/2008:12:52:45 +0100] cupsdIsAuthorized: level=CUPSD_AUTH_ANON, type=None, satisfy=CUPSD_AUTH_SATISFY_ALL, num_names=0
d [29/Oct/2008:12:52:45 +0100] cupsdIsAuthorized: op=0(unknown-0000)
d [29/Oct/2008:12:52:45 +0100] cupsdIsAuthorized: auth=CUPSD_AUTH_ALLOW...
d [29/Oct/2008:12:52:45 +0100] add_printer_state_reasons(0xb91666c0[8], 0xb9128790[c2424])
d [29/Oct/2008:12:52:45 +0100] printer-uri-supported="ipp://localhost:631/printers/c2424"
d [29/Oct/2008:12:52:45 +0100] add_queued_job_count(0xb91666c0[8], 0xb9128790[c2424])
d [29/Oct/2008:12:52:45 +0100] copy_attrs(to=0xb9174048, from=0xb913be68, ra=(nil), group=0, quickcopy=0)
d [29/Oct/2008:12:52:45 +0100] copy_attribute(0xb9174048, 0xb913be90[uri-authentication-supported,4,44])
d [29/Oct/2008:12:52:45 +0100] copy_attribute(0xb9174048, 0xb913bf20[uri-security-supported,4,44])
d [29/Oct/2008:12:52:45 +0100] copy_attribute(0xb9174048, 0xb913bf78[printer-name,4,42])
d [29/Oct/2008:12:52:45 +0100] copy_attribute(0xb9174048, 0xb913bfc8[printer-location,4,41])
d [29/Oct/2008:12:52:45 +0100] copy_attribute(0xb9174048, 0xb913c038[printer-info,4,41])
d [29/Oct/2008:12:52:45 +0100] copy_attribute(0xb9174048, 0xb913c088[printer-more-info,4,45])
d [29/Oct/2008:12:52:45 +0100] copy_attribute(0xb9174048, 0xb913c0d8[job-quota-period,4,21])
d [29/Oct/2008:12:52:45 +0100] copy_attribute(0xb9174048, 0xb913c128[job-k-limit,4,21])
d [29/Oct/2008:12:52:45 +0100] copy_attribute(0xb9174048, 0xb913c170[job-page-limit,4,21])
d [29/Oct/2008:12:52:45 +0100] copy_attribute(0xb9174048, 0xb913c1c0[auth-info-required,4,44])
d [29/Oct/2008:12:52:45 +0100] copy_attribute(0xb9174048, 0xb913c210[job-sheets-default,4,42])
d [29/Oct/2008:12:52:45 +0100] copy_attribute(0xb9174048, 0xb913c268[device-uri,4,45])
d [29/Oct/2008:12:52:45 +0100] copy_attribute(0xb9174048, 0xb9156b70[color-supported,4,22])
d [29/Oct/2008:12:52:45 +0100] copy_attribute(0xb9174048, 0xb9156bc0[pages-per-minute,4,21])
d [29/Oct/2008:12:52:45 +0100] copy_attribute(0xb9174048, 0xb9156c40[printer-make-and-model,4,41])
d [29/Oct/2008:12:52:45 +0100] copy_attribute(0xb9174048, 0xb914ed88[media-supported,4,44])
d [29/Oct/2008:12:52:45 +0100] copy_attribute(0xb9174048, 0xb913d1c8[media-default,4,44])
d [29/Oct/2008:12:52:45 +0100] copy_attribute(0xb9174048, 0xb913d218[sides-supported,4,44])
d [29/Oct/2008:12:52:45 +0100] copy_attribute(0xb9174048, 0xb913d2f8[sides-default,4,44])
d [29/Oct/2008:12:52:45 +0100] copy_attribute(0xb9174048, 0xb913d568[port-monitor,4,42])
d [29/Oct/2008:12:52:45 +0100] copy_attribute(0xb9174048, 0xb913d5b8[port-monitor-supported,4,42])
d [29/Oct/2008:12:52:45 +0100] copy_attribute(0xb9174048, 0xb9156628[finishings-supported,4,23])
d [29/Oct/2008:12:52:45 +0100] copy_attribute(0xb9174048, 0xb9155f40[finishings-default,4,23])
d [29/Oct/2008:12:52:45 +0100] copy_attribute(0xb9174048, 0xb91459b0[document-format-supported,4,49])
d [29/Oct/2008:12:52:45 +0100] copy_attribute(0xb9174048, 0xb9155ee0[copies-default,4,21])
d [29/Oct/2008:12:52:45 +0100] copy_attribute(0xb9174048, 0xb9155eb8[document-format-default,4,49])
d [29/Oct/2008:12:52:45 +0100] copy_attribute(0xb9174048, 0xb9155c00[job-hold-until-default,4,44])
d [29/Oct/2008:12:52:45 +0100] copy_attribute(0xb9174048, 0xb91562e0[job-priority-default,4,21])
d [29/Oct/2008:12:52:45 +0100] copy_attribute(0xb9174048, 0xb9155bc0[number-up-default,4,21])
d [29/Oct/2008:12:52:45 +0100] copy_attribute(0xb9174048, 0xb9155948[orientation-requested-default,4,13])
d [29/Oct/2008:12:52:45 +0100] copy_attribute(0xb9174048, 0xb9155920[notify-lease-duration-default,4,21])
d [29/Oct/2008:12:52:45 +0100] copy_attribute(0xb9174048, 0xb9155370[notify-events-default,4,44])
d [29/Oct/2008:12:52:45 +0100] copy_attrs(to=0xb9174048, from=0xb91291c0, ra=(nil), group=0, quickcopy=-2147483648)
d [29/Oct/2008:12:52:45 +0100] copy_attribute(0xb9174048, 0xb913be10[charset-configured,4,47])
d [29/Oct/2008:12:52:45 +0100] copy_attribute(0xb9174048, 0xb913d0a8[charset-supported,4,47])
d [29/Oct/2008:12:52:45 +0100] copy_attribute(0xb9174048, 0xb91299d8[compression-supported,4,44])
d [29/Oct/2008:12:52:45 +0100] copy_attribute(0xb9174048, 0xb913bdc8[copies-supported,4,33])
d [29/Oct/2008:12:52:45 +0100] copy_attribute(0xb9174048, 0xb913bcf8[cups-version,4,41])
d [29/Oct/2008:12:52:45 +0100] copy_attribute(0xb9174048, 0xb913bca0[generated-natural-language-supported,4,48])
d [29/Oct/2008:12:52:45 +0100] copy_attribute(0xb9174048, 0xb91298d0[ipp-versions-supported,4,44])
d [29/Oct/2008:12:52:45 +0100] copy_attribute(0xb9174048, 0xb9129518[job-hold-until-supported,4,44])
d [29/Oct/2008:12:52:45 +0100] copy_attribute(0xb9174048, 0xb913bc78[job-priority-supported,4,21])
d [29/Oct/2008:12:52:45 +0100] copy_attribute(0xb9174048, 0xb9129720[job-sheets-supported,4,42])
d [29/Oct/2008:12:52:45 +0100] copy_attribute(0xb9174048, 0xb9129910[multiple-document-handling-supported,4,44])
d [29/Oct/2008:12:52:45 +0100] copy_attribute(0xb9174048, 0xb913b990[multiple-document-jobs-supported,4,22])
d [29/Oct/2008:12:52:45 +0100] copy_attribute(0xb9174048, 0xb913b200[multiple-operation-time-out,4,21])
d [29/Oct/2008:12:52:45 +0100] copy_attribute(0xb9174048, 0xb913b238[natural-language-configured,4,48])
d [29/Oct/2008:12:52:45 +0100] copy_attribute(0xb9174048, 0xb913bd78[notify-attributes-supported,4,44])
d [29/Oct/2008:12:52:45 +0100] copy_attribute(0xb9174048, 0xb913b0a0[notify-lease-duration-supported,4,33])
d [29/Oct/2008:12:52:45 +0100] copy_attribute(0xb9174048, 0xb91299b0[notify-max-events-supported,4,21])
d [29/Oct/2008:12:52:45 +0100] copy_attribute(0xb9174048, 0xb915d068[notify-events-supported,4,44])
d [29/Oct/2008:12:52:45 +0100] copy_attribute(0xb9174048, 0xb9129950[notify-pull-method-supported,4,44])
d [29/Oct/2008:12:52:45 +0100] copy_attribute(0xb9174048, 0xb915d988[notify-schemes-supported,4,44])
d [29/Oct/2008:12:52:45 +0100] copy_attribute(0xb9174048, 0xb915d350[number-up-supported,4,21])
d [29/Oct/2008:12:52:45 +0100] copy_attribute(0xb9174048, 0xb913fd80[operations-supported,4,23])
d [29/Oct/2008:12:52:45 +0100] copy_attribute(0xb9174048, 0xb913d040[orientation-requested-supported,4,23])
d [29/Oct/2008:12:52:45 +0100] copy_attribute(0xb9174048, 0xb9129380[page-ranges-supported,4,22])
d [29/Oct/2008:12:52:45 +0100] copy_attribute(0xb9174048, 0xb91294b8[pdl-override-supported,4,44])
d [29/Oct/2008:12:52:45 +0100] copy_attribute(0xb9174048, 0xb913b0f8[printer-error-policy-supported,4,42])
d [29/Oct/2008:12:52:45 +0100] copy_attribute(0xb9174048, 0xb91293d0[printer-op-policy-supported,4,42])
D [29/Oct/2008:12:52:45 +0100] cupsdProcessIPPRequest: 8 status_code=0 (successful-ok)
d [29/Oct/2008:12:52:45 +0100] cupsdAddSelect: fd=8, read_cb=0xb8056200, write_cb=0xb80559d0, data=0xb91666c0
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:45 +0100] cupsdWriteClient: 8 bytes < 0
d [29/Oct/2008:12:52:45 +0100] cupsdAddSelect: fd=8, read_cb=0xb8056200, write_cb=(nil), data=0xb91666c0
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: Read on fd 8...
d [29/Oct/2008:12:52:45 +0100] cupsdReadClient: 8, used=0, file=-1 state=0
d [29/Oct/2008:12:52:45 +0100] cupsdReadClient: httpGets returned EOF...
D [29/Oct/2008:12:52:45 +0100] cupsdCloseClient: 8
d [29/Oct/2008:12:52:45 +0100] cupsdRemoveSelect: fd=8
d [29/Oct/2008:12:52:45 +0100] cupsdDoSelect: polling 4 fds for 1 seconds...
d [29/Oct/2008:12:52:46 +0100] cupsdDoSelect: epoll() returned 0...
d [29/Oct/2008:12:52:46 +0100] select_timeout(0): 12889 seconds to expire subscription
d [29/Oct/2008:12:52:46 +0100] cupsdDoSelect: polling 4 fds for 12889 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Read on fd 5...
d [29/Oct/2008:12:52:49 +0100] cupsdAcceptClient(lis=0xb912a300) 5 Clients = 0
D [29/Oct/2008:12:52:49 +0100] cupsdAcceptClient: 8 from localhost (Domain)
d [29/Oct/2008:12:52:49 +0100] cupsdAcceptClient: 8 connected to server on localhost:631
d [29/Oct/2008:12:52:49 +0100] cupsdAddSelect: fd=8, read_cb=0xb8056200, write_cb=(nil), data=0xb91666c0
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Read on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdReadClient: 8, used=0, file=-1 state=0
D [29/Oct/2008:12:52:49 +0100] cupsdReadClient: 8 POST / HTTP/1.1
d [29/Oct/2008:12:52:49 +0100] cupsdFindBest: uri = "/"...
d [29/Oct/2008:12:52:49 +0100] cupsdFindBest: Location CUPS_INTERNAL_BROWSE_ACL Limit 0
d [29/Oct/2008:12:52:49 +0100] cupsdFindBest: Location /admin/conf Limit 7f
d [29/Oct/2008:12:52:49 +0100] cupsdFindBest: Location /admin Limit 7f
d [29/Oct/2008:12:52:49 +0100] cupsdFindBest: Location / Limit 7f
d [29/Oct/2008:12:52:49 +0100] cupsdFindBest: best = /
d [29/Oct/2008:12:52:49 +0100] cupsdAuthorize: con->uri="/", con->best=0xb912e958(/)
d [29/Oct/2008:12:52:49 +0100] cupsdAuthorize: Authorization=""
D [29/Oct/2008:12:52:49 +0100] cupsdAuthorize: No authentication data provided.
d [29/Oct/2008:12:52:49 +0100] cupsdIsAuthorized: con->uri="/", con->best=0xb912e958(/)
d [29/Oct/2008:12:52:49 +0100] cupsdIsAuthorized: level=CUPSD_AUTH_ANON, type=None, satisfy=CUPSD_AUTH_SATISFY_ALL, num_names=0
d [29/Oct/2008:12:52:49 +0100] cupsdIsAuthorized: auth=CUPSD_AUTH_ALLOW...
d [29/Oct/2008:12:52:49 +0100] POST /
d [29/Oct/2008:12:52:49 +0100] CONTENT_TYPE = application/ipp
d [29/Oct/2008:12:52:49 +0100] cupsdReadClient: 8 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=200, con->file=-1
d [29/Oct/2008:12:52:49 +0100] cupsdReadClient: 8, used=192, file=-1 state=6
d [29/Oct/2008:12:52:49 +0100] cupsdReadClient: 8 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=192, con->file=-1
d [29/Oct/2008:12:52:49 +0100] cupsdProcessIPPRequest(0xb91666c0[8]): operation_id = 000b
D [29/Oct/2008:12:52:49 +0100] Get-Printer-Attributes ipp://localhost/printers/c2424
d [29/Oct/2008:12:52:49 +0100] get_printer_attrs(0xb91666c0[8], ipp://localhost/printers/c2424)
d [29/Oct/2008:12:52:49 +0100] cupsdFindPolicyOp(p=0xb912eb48, op=b(Get-Printer-Attributes))
d [29/Oct/2008:12:52:49 +0100] cupsdFindPolicyOp: Found wildcard match...
d [29/Oct/2008:12:52:49 +0100] cupsdIsAuthorized: con->uri="/", con->best=0xb912fc20((null))
d [29/Oct/2008:12:52:49 +0100] cupsdIsAuthorized: level=CUPSD_AUTH_ANON, type=None, satisfy=CUPSD_AUTH_SATISFY_ALL, num_names=0
d [29/Oct/2008:12:52:49 +0100] cupsdIsAuthorized: op=0(unknown-0000)
d [29/Oct/2008:12:52:49 +0100] cupsdIsAuthorized: auth=CUPSD_AUTH_ALLOW...
d [29/Oct/2008:12:52:49 +0100] add_printer_state_reasons(0xb91666c0[8], 0xb9128790[c2424])
d [29/Oct/2008:12:52:49 +0100] printer-uri-supported="ipp://localhost:631/printers/c2424"
d [29/Oct/2008:12:52:49 +0100] add_queued_job_count(0xb91666c0[8], 0xb9128790[c2424])
d [29/Oct/2008:12:52:49 +0100] copy_attrs(to=0xb9178680, from=0xb913be68, ra=(nil), group=0, quickcopy=0)
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb9178680, 0xb913be90[uri-authentication-supported,4,44])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb9178680, 0xb913bf20[uri-security-supported,4,44])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb9178680, 0xb913bf78[printer-name,4,42])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb9178680, 0xb913bfc8[printer-location,4,41])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb9178680, 0xb913c038[printer-info,4,41])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb9178680, 0xb913c088[printer-more-info,4,45])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb9178680, 0xb913c0d8[job-quota-period,4,21])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb9178680, 0xb913c128[job-k-limit,4,21])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb9178680, 0xb913c170[job-page-limit,4,21])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb9178680, 0xb913c1c0[auth-info-required,4,44])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb9178680, 0xb913c210[job-sheets-default,4,42])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb9178680, 0xb913c268[device-uri,4,45])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb9178680, 0xb9156b70[color-supported,4,22])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb9178680, 0xb9156bc0[pages-per-minute,4,21])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb9178680, 0xb9156c40[printer-make-and-model,4,41])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb9178680, 0xb914ed88[media-supported,4,44])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb9178680, 0xb913d1c8[media-default,4,44])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb9178680, 0xb913d218[sides-supported,4,44])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb9178680, 0xb913d2f8[sides-default,4,44])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb9178680, 0xb913d568[port-monitor,4,42])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb9178680, 0xb913d5b8[port-monitor-supported,4,42])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb9178680, 0xb9156628[finishings-supported,4,23])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb9178680, 0xb9155f40[finishings-default,4,23])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb9178680, 0xb91459b0[document-format-supported,4,49])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb9178680, 0xb9155ee0[copies-default,4,21])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb9178680, 0xb9155eb8[document-format-default,4,49])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb9178680, 0xb9155c00[job-hold-until-default,4,44])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb9178680, 0xb91562e0[job-priority-default,4,21])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb9178680, 0xb9155bc0[number-up-default,4,21])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb9178680, 0xb9155948[orientation-requested-default,4,13])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb9178680, 0xb9155920[notify-lease-duration-default,4,21])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb9178680, 0xb9155370[notify-events-default,4,44])
d [29/Oct/2008:12:52:49 +0100] copy_attrs(to=0xb9178680, from=0xb91291c0, ra=(nil), group=0, quickcopy=-2147483648)
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb9178680, 0xb913be10[charset-configured,4,47])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb9178680, 0xb913d0a8[charset-supported,4,47])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb9178680, 0xb91299d8[compression-supported,4,44])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb9178680, 0xb913bdc8[copies-supported,4,33])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb9178680, 0xb913bcf8[cups-version,4,41])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb9178680, 0xb913bca0[generated-natural-language-supported,4,48])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb9178680, 0xb91298d0[ipp-versions-supported,4,44])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb9178680, 0xb9129518[job-hold-until-supported,4,44])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb9178680, 0xb913bc78[job-priority-supported,4,21])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb9178680, 0xb9129720[job-sheets-supported,4,42])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb9178680, 0xb9129910[multiple-document-handling-supported,4,44])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb9178680, 0xb913b990[multiple-document-jobs-supported,4,22])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb9178680, 0xb913b200[multiple-operation-time-out,4,21])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb9178680, 0xb913b238[natural-language-configured,4,48])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb9178680, 0xb913bd78[notify-attributes-supported,4,44])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb9178680, 0xb913b0a0[notify-lease-duration-supported,4,33])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb9178680, 0xb91299b0[notify-max-events-supported,4,21])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb9178680, 0xb915d068[notify-events-supported,4,44])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb9178680, 0xb9129950[notify-pull-method-supported,4,44])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb9178680, 0xb915d988[notify-schemes-supported,4,44])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb9178680, 0xb915d350[number-up-supported,4,21])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb9178680, 0xb913fd80[operations-supported,4,23])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb9178680, 0xb913d040[orientation-requested-supported,4,23])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb9178680, 0xb9129380[page-ranges-supported,4,22])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb9178680, 0xb91294b8[pdl-override-supported,4,44])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb9178680, 0xb913b0f8[printer-error-policy-supported,4,42])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb9178680, 0xb91293d0[printer-op-policy-supported,4,42])
D [29/Oct/2008:12:52:49 +0100] cupsdProcessIPPRequest: 8 status_code=0 (successful-ok)
d [29/Oct/2008:12:52:49 +0100] cupsdAddSelect: fd=8, read_cb=0xb8056200, write_cb=0xb80559d0, data=0xb91666c0
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdWriteClient: 8 bytes < 0
d [29/Oct/2008:12:52:49 +0100] cupsdAddSelect: fd=8, read_cb=0xb8056200, write_cb=(nil), data=0xb91666c0
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Read on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdReadClient: 8, used=0, file=-1 state=0
D [29/Oct/2008:12:52:49 +0100] cupsdReadClient: 8 GET /printers/c2424.ppd HTTP/1.1
d [29/Oct/2008:12:52:49 +0100] cupsdFindBest: uri = "/printers/c2424"...
d [29/Oct/2008:12:52:49 +0100] cupsdFindBest: Location CUPS_INTERNAL_BROWSE_ACL Limit 0
d [29/Oct/2008:12:52:49 +0100] cupsdFindBest: Location /admin/conf Limit 7f
d [29/Oct/2008:12:52:49 +0100] cupsdFindBest: Location /admin Limit 7f
d [29/Oct/2008:12:52:49 +0100] cupsdFindBest: Location / Limit 7f
d [29/Oct/2008:12:52:49 +0100] cupsdFindBest: best = /
d [29/Oct/2008:12:52:49 +0100] cupsdAuthorize: con->uri="/printers/c2424.ppd", con->best=0xb912e958(/)
d [29/Oct/2008:12:52:49 +0100] cupsdAuthorize: Authorization=""
D [29/Oct/2008:12:52:49 +0100] cupsdAuthorize: No authentication data provided.
d [29/Oct/2008:12:52:49 +0100] cupsdIsAuthorized: con->uri="/printers/c2424.ppd", con->best=0xb912e958(/)
d [29/Oct/2008:12:52:49 +0100] cupsdIsAuthorized: level=CUPSD_AUTH_ANON, type=None, satisfy=CUPSD_AUTH_SATISFY_ALL, num_names=0
d [29/Oct/2008:12:52:49 +0100] cupsdIsAuthorized: auth=CUPSD_AUTH_ALLOW...
d [29/Oct/2008:12:52:49 +0100] get_file: 8 filename=/etc/cups/ppd/c2424.ppd size=38243
d [29/Oct/2008:12:52:49 +0100] is_cgi(con=0xb91666c0, filename="/etc/cups/ppd/c2424.ppd", filestats=0xbfd998f8, type=application/vnd.cups-ppd)
d [29/Oct/2008:12:52:49 +0100] is_cgi: Returning 0...
d [29/Oct/2008:12:52:49 +0100] write_file: 8 file=12
d [29/Oct/2008:12:52:49 +0100] cupsdAddSelect: fd=8, read_cb=0xb8056200, write_cb=0xb80559d0, data=0xb91666c0
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdWriteClient: Read 16384 bytes from file 12...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdWriteClient: Read 16384 bytes from file 12...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdWriteClient: Read 5475 bytes from file 12...
d [29/Oct/2008:12:52:49 +0100] cupsdWriteClient: 8 bytes < 0
d [29/Oct/2008:12:52:49 +0100] cupsdAddSelect: fd=8, read_cb=0xb8056200, write_cb=(nil), data=0xb91666c0
d [29/Oct/2008:12:52:49 +0100] cupsdRemoveSelect: fd=12
d [29/Oct/2008:12:52:49 +0100] cupsdWriteClient: 8 Closing data file 12.
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Read on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdReadClient: 8, used=0, file=-1 state=0
d [29/Oct/2008:12:52:49 +0100] cupsdReadClient: httpGets returned EOF...
D [29/Oct/2008:12:52:49 +0100] cupsdCloseClient: 8
d [29/Oct/2008:12:52:49 +0100] cupsdRemoveSelect: fd=8
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 4 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Read on fd 5...
d [29/Oct/2008:12:52:49 +0100] cupsdAcceptClient(lis=0xb912a300) 5 Clients = 0
D [29/Oct/2008:12:52:49 +0100] cupsdAcceptClient: 8 from localhost (Domain)
d [29/Oct/2008:12:52:49 +0100] cupsdAcceptClient: 8 connected to server on localhost:631
d [29/Oct/2008:12:52:49 +0100] cupsdAddSelect: fd=8, read_cb=0xb8056200, write_cb=(nil), data=0xb91666c0
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Read on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdReadClient: 8, used=0, file=-1 state=0
D [29/Oct/2008:12:52:49 +0100] cupsdReadClient: 8 POST / HTTP/1.1
d [29/Oct/2008:12:52:49 +0100] cupsdFindBest: uri = "/"...
d [29/Oct/2008:12:52:49 +0100] cupsdFindBest: Location CUPS_INTERNAL_BROWSE_ACL Limit 0
d [29/Oct/2008:12:52:49 +0100] cupsdFindBest: Location /admin/conf Limit 7f
d [29/Oct/2008:12:52:49 +0100] cupsdFindBest: Location /admin Limit 7f
d [29/Oct/2008:12:52:49 +0100] cupsdFindBest: Location / Limit 7f
d [29/Oct/2008:12:52:49 +0100] cupsdFindBest: best = /
d [29/Oct/2008:12:52:49 +0100] cupsdAuthorize: con->uri="/", con->best=0xb912e958(/)
d [29/Oct/2008:12:52:49 +0100] cupsdAuthorize: Authorization=""
D [29/Oct/2008:12:52:49 +0100] cupsdAuthorize: No authentication data provided.
d [29/Oct/2008:12:52:49 +0100] cupsdIsAuthorized: con->uri="/", con->best=0xb912e958(/)
d [29/Oct/2008:12:52:49 +0100] cupsdIsAuthorized: level=CUPSD_AUTH_ANON, type=None, satisfy=CUPSD_AUTH_SATISFY_ALL, num_names=0
d [29/Oct/2008:12:52:49 +0100] cupsdIsAuthorized: auth=CUPSD_AUTH_ALLOW...
d [29/Oct/2008:12:52:49 +0100] POST /
d [29/Oct/2008:12:52:49 +0100] CONTENT_TYPE = application/ipp
d [29/Oct/2008:12:52:49 +0100] cupsdReadClient: 8 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=415, con->file=-1
d [29/Oct/2008:12:52:49 +0100] cupsdProcessIPPRequest(0xb91666c0[8]): operation_id = 4002
D [29/Oct/2008:12:52:49 +0100] CUPS-Get-Printers
d [29/Oct/2008:12:52:49 +0100] get_printers(0xb91666c0[8], 0)
d [29/Oct/2008:12:52:49 +0100] cupsdFindPolicyOp(p=0xb912eb48, op=4002(CUPS-Get-Printers))
d [29/Oct/2008:12:52:49 +0100] cupsdFindPolicyOp: Found wildcard match...
d [29/Oct/2008:12:52:49 +0100] cupsdIsAuthorized: con->uri="/", con->best=0xb912fc20((null))
d [29/Oct/2008:12:52:49 +0100] cupsdIsAuthorized: level=CUPSD_AUTH_ANON, type=None, satisfy=CUPSD_AUTH_SATISFY_ALL, num_names=0
d [29/Oct/2008:12:52:49 +0100] cupsdIsAuthorized: op=0(unknown-0000)
d [29/Oct/2008:12:52:49 +0100] cupsdIsAuthorized: auth=CUPSD_AUTH_ALLOW...
d [29/Oct/2008:12:52:49 +0100] add_printer_state_reasons(0xb91666c0[8], 0xb9128790[c2424])
d [29/Oct/2008:12:52:49 +0100] copy_attrs(to=0xb913b9d8, from=0xb913be68, ra=0xb917b480, group=0, quickcopy=0)
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb913bf78[printer-name,4,42])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb913bfc8[printer-location,4,41])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb913c038[printer-info,4,41])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb913c1c0[auth-info-required,4,44])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb913c210[job-sheets-default,4,42])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb9156c40[printer-make-and-model,4,41])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb913d1c8[media-default,4,44])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb913d2f8[sides-default,4,44])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb9155f40[finishings-default,4,23])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb9155ee0[copies-default,4,21])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb9155eb8[document-format-default,4,49])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb9155c00[job-hold-until-default,4,44])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb91562e0[job-priority-default,4,21])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb9155bc0[number-up-default,4,21])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb9155948[orientation-requested-default,4,13])
d [29/Oct/2008:12:52:49 +0100] copy_attrs(to=0xb913b9d8, from=0xb91291c0, ra=0xb917b480, group=0, quickcopy=-2147483648)
d [29/Oct/2008:12:52:49 +0100] add_printer_state_reasons(0xb91666c0[8], 0xb91444f8[c2424-NB-r])
d [29/Oct/2008:12:52:49 +0100] copy_attrs(to=0xb913b9d8, from=0xb9155150, ra=0xb917b480, group=0, quickcopy=0)
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb9156578[printer-name,4,42])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb91565a0[printer-location,4,41])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb91565c8[printer-info,4,41])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb91552e0[auth-info-required,4,44])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb91555e8[job-sheets-default,4,42])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb914f690[printer-make-and-model,4,41])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb9158b30[media-default,4,44])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb9158b98[sides-default,4,44])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb9158358[finishings-default,4,23])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb9158320[copies-default,4,21])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb91582e0[document-format-default,4,49])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb9157fb8[job-hold-until-default,4,44])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb9157f78[job-priority-default,4,21])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb9157e80[number-up-default,4,21])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb9158158[orientation-requested-default,4,13])
d [29/Oct/2008:12:52:49 +0100] copy_attrs(to=0xb913b9d8, from=0xb91291c0, ra=0xb917b480, group=0, quickcopy=-2147483648)
d [29/Oct/2008:12:52:49 +0100] add_printer_state_reasons(0xb91666c0[8], 0xb9158380[C2424min])
d [29/Oct/2008:12:52:49 +0100] copy_attrs(to=0xb913b9d8, from=0xb91578f8, ra=0xb917b480, group=0, quickcopy=0)
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb9157970[printer-name,4,42])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb9157bb8[printer-location,4,41])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb9157be0[printer-info,4,41])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb9157ce0[auth-info-required,4,44])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb9157d08[job-sheets-default,4,42])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb9156b28[printer-make-and-model,4,41])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb914aae8[media-default,4,44])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb914ab50[sides-default,4,44])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb9156e28[finishings-default,4,23])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb9156e00[copies-default,4,21])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb9157228[document-format-default,4,49])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb914f570[job-hold-until-default,4,44])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb914f548[job-priority-default,4,21])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb9156948[number-up-default,4,21])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb9156908[orientation-requested-default,4,13])
d [29/Oct/2008:12:52:49 +0100] copy_attrs(to=0xb913b9d8, from=0xb91291c0, ra=0xb917b480, group=0, quickcopy=-2147483648)
d [29/Oct/2008:12:52:49 +0100] add_printer_state_reasons(0xb91666c0[8], 0xb914a120[c2424nbr4])
d [29/Oct/2008:12:52:49 +0100] copy_attrs(to=0xb913b9d8, from=0xb9155550, ra=0xb917b480, group=0, quickcopy=0)
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb9155b40[printer-name,4,42])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb9155b68[printer-location,4,41])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb9155b90[printer-info,4,41])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb9146c78[auth-info-required,4,44])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb9146ca0[job-sheets-default,4,42])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb914fcf0[printer-make-and-model,4,41])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb915b380[media-default,4,44])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb915b3e8[sides-default,4,44])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb915a9a0[finishings-default,4,23])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb915a968[copies-default,4,21])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb915a890[document-format-default,4,49])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb915ad78[job-hold-until-default,4,44])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb915a678[job-priority-default,4,21])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb915a630[number-up-default,4,21])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb915a3d8[orientation-requested-default,4,13])
d [29/Oct/2008:12:52:49 +0100] copy_attrs(to=0xb913b9d8, from=0xb91291c0, ra=0xb917b480, group=0, quickcopy=-2147483648)
d [29/Oct/2008:12:52:49 +0100] add_printer_state_reasons(0xb91666c0[8], 0xb914f6b8[PDF])
d [29/Oct/2008:12:52:49 +0100] copy_attrs(to=0xb913b9d8, from=0xb9146cf8, ra=0xb917b480, group=0, quickcopy=0)
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb915ac58[printer-name,4,42])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb9156d50[printer-location,4,41])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb9156d78[printer-info,4,41])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb915a908[auth-info-required,4,44])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb915a930[job-sheets-default,4,42])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb915b080[printer-make-and-model,4,41])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb9159940[media-default,4,44])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb913b418[finishings-default,4,23])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb914bfd8[copies-default,4,21])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb914cb80[document-format-default,4,49])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb914cb58[job-hold-until-default,4,44])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb914c9d0[job-priority-default,4,21])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb913fcb8[number-up-default,4,21])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb914a8a0[orientation-requested-default,4,13])
d [29/Oct/2008:12:52:49 +0100] copy_attrs(to=0xb913b9d8, from=0xb91291c0, ra=0xb917b480, group=0, quickcopy=-2147483648)
d [29/Oct/2008:12:52:49 +0100] add_printer_state_reasons(0xb91666c0[8], 0xb9143228[ttt])
d [29/Oct/2008:12:52:49 +0100] copy_attrs(to=0xb913b9d8, from=0xb91597f8, ra=0xb917b480, group=0, quickcopy=0)
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb915b1d0[printer-name,4,42])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb913c548[printer-location,4,41])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb913c570[printer-info,4,41])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb914c5d8[auth-info-required,4,44])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb913fc08[job-sheets-default,4,42])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb91506b0[printer-make-and-model,4,41])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb915e548[media-default,4,44])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb915e5b0[sides-default,4,44])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb915de78[finishings-default,4,23])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb915dd90[copies-default,4,21])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb915dfb0[document-format-default,4,49])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb915d960[job-hold-until-default,4,44])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb915d918[job-priority-default,4,21])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb915d610[number-up-default,4,21])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb915d5d0[orientation-requested-default,4,13])
d [29/Oct/2008:12:52:49 +0100] copy_attrs(to=0xb913b9d8, from=0xb91291c0, ra=0xb917b480, group=0, quickcopy=-2147483648)
D [29/Oct/2008:12:52:49 +0100] cupsdProcessIPPRequest: 8 status_code=0 (successful-ok)
d [29/Oct/2008:12:52:49 +0100] cupsdAddSelect: fd=8, read_cb=0xb8056200, write_cb=0xb80559d0, data=0xb91666c0
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdWriteClient: 8 bytes < 0
d [29/Oct/2008:12:52:49 +0100] cupsdAddSelect: fd=8, read_cb=0xb8056200, write_cb=(nil), data=0xb91666c0
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Read on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdReadClient: 8, used=0, file=-1 state=0
D [29/Oct/2008:12:52:49 +0100] cupsdReadClient: 8 POST / HTTP/1.1
d [29/Oct/2008:12:52:49 +0100] cupsdFindBest: uri = "/"...
d [29/Oct/2008:12:52:49 +0100] cupsdFindBest: Location CUPS_INTERNAL_BROWSE_ACL Limit 0
d [29/Oct/2008:12:52:49 +0100] cupsdFindBest: Location /admin/conf Limit 7f
d [29/Oct/2008:12:52:49 +0100] cupsdFindBest: Location /admin Limit 7f
d [29/Oct/2008:12:52:49 +0100] cupsdFindBest: Location / Limit 7f
d [29/Oct/2008:12:52:49 +0100] cupsdFindBest: best = /
d [29/Oct/2008:12:52:49 +0100] cupsdAuthorize: con->uri="/", con->best=0xb912e958(/)
d [29/Oct/2008:12:52:49 +0100] cupsdAuthorize: Authorization=""
D [29/Oct/2008:12:52:49 +0100] cupsdAuthorize: No authentication data provided.
d [29/Oct/2008:12:52:49 +0100] cupsdIsAuthorized: con->uri="/", con->best=0xb912e958(/)
d [29/Oct/2008:12:52:49 +0100] cupsdIsAuthorized: level=CUPSD_AUTH_ANON, type=None, satisfy=CUPSD_AUTH_SATISFY_ALL, num_names=0
d [29/Oct/2008:12:52:49 +0100] cupsdIsAuthorized: auth=CUPSD_AUTH_ALLOW...
d [29/Oct/2008:12:52:49 +0100] POST /
d [29/Oct/2008:12:52:49 +0100] CONTENT_TYPE = application/ipp
d [29/Oct/2008:12:52:49 +0100] cupsdReadClient: 8 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=415, con->file=-1
d [29/Oct/2008:12:52:49 +0100] cupsdReadClient: 8, used=407, file=-1 state=6
d [29/Oct/2008:12:52:49 +0100] cupsdReadClient: 8 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=407, con->file=-1
d [29/Oct/2008:12:52:49 +0100] cupsdProcessIPPRequest(0xb91666c0[8]): operation_id = 4005
D [29/Oct/2008:12:52:49 +0100] CUPS-Get-Classes
d [29/Oct/2008:12:52:49 +0100] get_printers(0xb91666c0[8], 1)
d [29/Oct/2008:12:52:49 +0100] cupsdFindPolicyOp(p=0xb912eb48, op=4005(CUPS-Get-Classes))
d [29/Oct/2008:12:52:49 +0100] cupsdFindPolicyOp: Found wildcard match...
d [29/Oct/2008:12:52:49 +0100] cupsdIsAuthorized: con->uri="/", con->best=0xb912fc20((null))
d [29/Oct/2008:12:52:49 +0100] cupsdIsAuthorized: level=CUPSD_AUTH_ANON, type=None, satisfy=CUPSD_AUTH_SATISFY_ALL, num_names=0
d [29/Oct/2008:12:52:49 +0100] cupsdIsAuthorized: op=0(unknown-0000)
d [29/Oct/2008:12:52:49 +0100] cupsdIsAuthorized: auth=CUPSD_AUTH_ALLOW...
D [29/Oct/2008:12:52:49 +0100] cupsdProcessIPPRequest: 8 status_code=0 (successful-ok)
d [29/Oct/2008:12:52:49 +0100] cupsdAddSelect: fd=8, read_cb=0xb8056200, write_cb=0xb80559d0, data=0xb91666c0
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdWriteClient: 8 bytes < 0
d [29/Oct/2008:12:52:49 +0100] cupsdAddSelect: fd=8, read_cb=0xb8056200, write_cb=(nil), data=0xb91666c0
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Read on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdReadClient: 8, used=0, file=-1 state=0
D [29/Oct/2008:12:52:49 +0100] cupsdReadClient: 8 POST / HTTP/1.1
d [29/Oct/2008:12:52:49 +0100] cupsdFindBest: uri = "/"...
d [29/Oct/2008:12:52:49 +0100] cupsdFindBest: Location CUPS_INTERNAL_BROWSE_ACL Limit 0
d [29/Oct/2008:12:52:49 +0100] cupsdFindBest: Location /admin/conf Limit 7f
d [29/Oct/2008:12:52:49 +0100] cupsdFindBest: Location /admin Limit 7f
d [29/Oct/2008:12:52:49 +0100] cupsdFindBest: Location / Limit 7f
d [29/Oct/2008:12:52:49 +0100] cupsdFindBest: best = /
d [29/Oct/2008:12:52:49 +0100] cupsdAuthorize: con->uri="/", con->best=0xb912e958(/)
d [29/Oct/2008:12:52:49 +0100] cupsdAuthorize: Authorization=""
D [29/Oct/2008:12:52:49 +0100] cupsdAuthorize: No authentication data provided.
d [29/Oct/2008:12:52:49 +0100] cupsdIsAuthorized: con->uri="/", con->best=0xb912e958(/)
d [29/Oct/2008:12:52:49 +0100] cupsdIsAuthorized: level=CUPSD_AUTH_ANON, type=None, satisfy=CUPSD_AUTH_SATISFY_ALL, num_names=0
d [29/Oct/2008:12:52:49 +0100] cupsdIsAuthorized: auth=CUPSD_AUTH_ALLOW...
d [29/Oct/2008:12:52:49 +0100] POST /
d [29/Oct/2008:12:52:49 +0100] CONTENT_TYPE = application/ipp
d [29/Oct/2008:12:52:49 +0100] cupsdReadClient: 8 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=75, con->file=-1
d [29/Oct/2008:12:52:49 +0100] cupsdReadClient: 8, used=67, file=-1 state=6
d [29/Oct/2008:12:52:49 +0100] cupsdReadClient: 8 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=67, con->file=-1
d [29/Oct/2008:12:52:49 +0100] cupsdProcessIPPRequest(0xb91666c0[8]): operation_id = 4001
D [29/Oct/2008:12:52:49 +0100] CUPS-Get-Default
d [29/Oct/2008:12:52:49 +0100] get_default(0xb91666c0[8])
d [29/Oct/2008:12:52:49 +0100] cupsdFindPolicyOp(p=0xb912eb48, op=4001(CUPS-Get-Default))
d [29/Oct/2008:12:52:49 +0100] cupsdFindPolicyOp: Found wildcard match...
d [29/Oct/2008:12:52:49 +0100] cupsdIsAuthorized: con->uri="/", con->best=0xb912fc20((null))
d [29/Oct/2008:12:52:49 +0100] cupsdIsAuthorized: level=CUPSD_AUTH_ANON, type=None, satisfy=CUPSD_AUTH_SATISFY_ALL, num_names=0
d [29/Oct/2008:12:52:49 +0100] cupsdIsAuthorized: op=0(unknown-0000)
d [29/Oct/2008:12:52:49 +0100] cupsdIsAuthorized: auth=CUPSD_AUTH_ALLOW...
d [29/Oct/2008:12:52:49 +0100] add_printer_state_reasons(0xb91666c0[8], 0xb9128790[c2424])
d [29/Oct/2008:12:52:49 +0100] printer-uri-supported="ipp://localhost:631/printers/c2424"
d [29/Oct/2008:12:52:49 +0100] add_queued_job_count(0xb91666c0[8], 0xb9128790[c2424])
d [29/Oct/2008:12:52:49 +0100] copy_attrs(to=0xb913b9d8, from=0xb913be68, ra=(nil), group=0, quickcopy=0)
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb913be90[uri-authentication-supported,4,44])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb913bf20[uri-security-supported,4,44])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb913bf78[printer-name,4,42])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb913bfc8[printer-location,4,41])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb913c038[printer-info,4,41])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb913c088[printer-more-info,4,45])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb913c0d8[job-quota-period,4,21])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb913c128[job-k-limit,4,21])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb913c170[job-page-limit,4,21])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb913c1c0[auth-info-required,4,44])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb913c210[job-sheets-default,4,42])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb913c268[device-uri,4,45])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb9156b70[color-supported,4,22])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb9156bc0[pages-per-minute,4,21])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb9156c40[printer-make-and-model,4,41])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb914ed88[media-supported,4,44])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb913d1c8[media-default,4,44])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb913d218[sides-supported,4,44])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb913d2f8[sides-default,4,44])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb913d568[port-monitor,4,42])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb913d5b8[port-monitor-supported,4,42])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb9156628[finishings-supported,4,23])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb9155f40[finishings-default,4,23])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb91459b0[document-format-supported,4,49])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb9155ee0[copies-default,4,21])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb9155eb8[document-format-default,4,49])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb9155c00[job-hold-until-default,4,44])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb91562e0[job-priority-default,4,21])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb9155bc0[number-up-default,4,21])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb9155948[orientation-requested-default,4,13])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb9155920[notify-lease-duration-default,4,21])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb9155370[notify-events-default,4,44])
d [29/Oct/2008:12:52:49 +0100] copy_attrs(to=0xb913b9d8, from=0xb91291c0, ra=(nil), group=0, quickcopy=-2147483648)
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb913be10[charset-configured,4,47])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb913d0a8[charset-supported,4,47])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb91299d8[compression-supported,4,44])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb913bdc8[copies-supported,4,33])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb913bcf8[cups-version,4,41])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb913bca0[generated-natural-language-supported,4,48])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb91298d0[ipp-versions-supported,4,44])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb9129518[job-hold-until-supported,4,44])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb913bc78[job-priority-supported,4,21])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb9129720[job-sheets-supported,4,42])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb9129910[multiple-document-handling-supported,4,44])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb913b990[multiple-document-jobs-supported,4,22])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb913b200[multiple-operation-time-out,4,21])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb913b238[natural-language-configured,4,48])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb913bd78[notify-attributes-supported,4,44])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb913b0a0[notify-lease-duration-supported,4,33])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb91299b0[notify-max-events-supported,4,21])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb915d068[notify-events-supported,4,44])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb9129950[notify-pull-method-supported,4,44])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb915d988[notify-schemes-supported,4,44])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb915d350[number-up-supported,4,21])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb913fd80[operations-supported,4,23])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb913d040[orientation-requested-supported,4,23])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb9129380[page-ranges-supported,4,22])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb91294b8[pdl-override-supported,4,44])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb913b0f8[printer-error-policy-supported,4,42])
d [29/Oct/2008:12:52:49 +0100] copy_attribute(0xb913b9d8, 0xb91293d0[printer-op-policy-supported,4,42])
D [29/Oct/2008:12:52:49 +0100] cupsdProcessIPPRequest: 8 status_code=0 (successful-ok)
d [29/Oct/2008:12:52:49 +0100] cupsdAddSelect: fd=8, read_cb=0xb8056200, write_cb=0xb80559d0, data=0xb91666c0
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdWriteClient: 8 bytes < 0
d [29/Oct/2008:12:52:49 +0100] cupsdAddSelect: fd=8, read_cb=0xb8056200, write_cb=(nil), data=0xb91666c0
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: Read on fd 8...
d [29/Oct/2008:12:52:49 +0100] cupsdReadClient: 8, used=0, file=-1 state=0
d [29/Oct/2008:12:52:49 +0100] cupsdReadClient: httpGets returned EOF...
D [29/Oct/2008:12:52:49 +0100] cupsdCloseClient: 8
d [29/Oct/2008:12:52:49 +0100] cupsdRemoveSelect: fd=8
d [29/Oct/2008:12:52:49 +0100] cupsdDoSelect: polling 4 fds for 1 seconds...
d [29/Oct/2008:12:52:50 +0100] cupsdDoSelect: epoll() returned 0...
d [29/Oct/2008:12:52:50 +0100] select_timeout(0): 12885 seconds to expire subscription
d [29/Oct/2008:12:52:50 +0100] cupsdDoSelect: polling 4 fds for 12885 seconds...
d [29/Oct/2008:12:52:50 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:50 +0100] cupsdDoSelect: Read on fd 5...
d [29/Oct/2008:12:52:50 +0100] cupsdAcceptClient(lis=0xb912a300) 5 Clients = 0
D [29/Oct/2008:12:52:50 +0100] cupsdAcceptClient: 8 from localhost (Domain)
d [29/Oct/2008:12:52:50 +0100] cupsdAcceptClient: 8 connected to server on localhost:631
d [29/Oct/2008:12:52:50 +0100] cupsdAddSelect: fd=8, read_cb=0xb8056200, write_cb=(nil), data=0xb91666c0
d [29/Oct/2008:12:52:50 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:50 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:50 +0100] cupsdDoSelect: Read on fd 8...
d [29/Oct/2008:12:52:50 +0100] cupsdReadClient: 8, used=0, file=-1 state=0
D [29/Oct/2008:12:52:50 +0100] cupsdReadClient: 8 POST /printers/c2424 HTTP/1.1
d [29/Oct/2008:12:52:50 +0100] cupsdFindBest: uri = "/printers/c2424"...
d [29/Oct/2008:12:52:50 +0100] cupsdFindBest: Location CUPS_INTERNAL_BROWSE_ACL Limit 0
d [29/Oct/2008:12:52:50 +0100] cupsdFindBest: Location /admin/conf Limit 7f
d [29/Oct/2008:12:52:50 +0100] cupsdFindBest: Location /admin Limit 7f
d [29/Oct/2008:12:52:50 +0100] cupsdFindBest: Location / Limit 7f
d [29/Oct/2008:12:52:50 +0100] cupsdFindBest: best = /
d [29/Oct/2008:12:52:50 +0100] cupsdAuthorize: con->uri="/printers/c2424", con->best=0xb912e958(/)
d [29/Oct/2008:12:52:50 +0100] cupsdAuthorize: Authorization=""
D [29/Oct/2008:12:52:50 +0100] cupsdAuthorize: No authentication data provided.
d [29/Oct/2008:12:52:50 +0100] cupsdIsAuthorized: con->uri="/printers/c2424", con->best=0xb912e958(/)
d [29/Oct/2008:12:52:50 +0100] cupsdIsAuthorized: level=CUPSD_AUTH_ANON, type=None, satisfy=CUPSD_AUTH_SATISFY_ALL, num_names=0
d [29/Oct/2008:12:52:50 +0100] cupsdIsAuthorized: auth=CUPSD_AUTH_ALLOW...
d [29/Oct/2008:12:52:50 +0100] POST /printers/c2424
d [29/Oct/2008:12:52:50 +0100] CONTENT_TYPE = application/ipp
d [29/Oct/2008:12:52:50 +0100] cupsdReadClient: 8 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=28650, con->file=-1
d [29/Oct/2008:12:52:50 +0100] cupsdReadClient: 8 REQUEST /var/spool/cups/00000003=12
d [29/Oct/2008:12:52:50 +0100] cupsdReadClient: 8 writing 28400 bytes to 12
d [29/Oct/2008:12:52:50 +0100] cupsdReadClient: 8 Closing data file 12, size=28400.
d [29/Oct/2008:12:52:50 +0100] cupsdProcessIPPRequest(0xb91666c0[8]): operation_id = 0002
D [29/Oct/2008:12:52:50 +0100] Print-Job ipp://localhost/printers/c2424
d [29/Oct/2008:12:52:50 +0100] print_job(0xb91666c0[8], ipp://localhost/printers/c2424)
D [29/Oct/2008:12:52:50 +0100] [Job ???] Auto-typing file...
I [29/Oct/2008:12:52:50 +0100] [Job ???] Request file type is application/postscript.
d [29/Oct/2008:12:52:50 +0100] add_job(0xb91666c0[8], 0xb9128790(c2424), 0xb9131ed8(application/postscript))
d [29/Oct/2008:12:52:50 +0100] cupsdFindPolicyOp(p=0xb912eb48, op=2(Print-Job))
d [29/Oct/2008:12:52:50 +0100] cupsdFindPolicyOp: Found wildcard match...
d [29/Oct/2008:12:52:50 +0100] cupsdIsAuthorized: con->uri="/printers/c2424", con->best=0xb912fc20((null))
d [29/Oct/2008:12:52:50 +0100] cupsdIsAuthorized: level=CUPSD_AUTH_ANON, type=None, satisfy=CUPSD_AUTH_SATISFY_ALL, num_names=0
d [29/Oct/2008:12:52:50 +0100] cupsdIsAuthorized: op=0(unknown-0000)
d [29/Oct/2008:12:52:50 +0100] cupsdIsAuthorized: auth=CUPSD_AUTH_ALLOW...
d [29/Oct/2008:12:52:50 +0100] check_quotas(0xb91666c0[8], 0xb9128790[c2424])
D [29/Oct/2008:12:52:50 +0100] add_job: requesting-user-name="sd2"
D [29/Oct/2008:12:52:50 +0100] Adding default job-sheets values "none,none"...
I [29/Oct/2008:12:52:50 +0100] [Job 38] Adding start banner page "none".
d [29/Oct/2008:12:52:50 +0100] copy_banner(con=0xb91666c0[8], job=0xb917b3a8[38], name="none")
d [29/Oct/2008:12:52:50 +0100] add_job_state_reasons(0xb91666c0[8], 38)
d [29/Oct/2008:12:52:50 +0100] cupsdAddEvent(event=job-created, dest=0xb9128790(c2424), job=0xb917b3a8(38), text="Job created.", ...)
d [29/Oct/2008:12:52:50 +0100] cupsd_send_notification(sub=0xb915d858(1), event=0xb91772c8(job-created))
d [29/Oct/2008:12:52:50 +0100] cupsd_send_notification(sub=0xb915cd88(2), event=0xb914bb48(job-created))
d [29/Oct/2008:12:52:50 +0100] cupsd_send_notification(sub=0xb915ce18(3), event=0xb917bc28(job-created))
I [29/Oct/2008:12:52:50 +0100] Saving subscriptions.conf...
d [29/Oct/2008:12:52:50 +0100] add_file(con=0xb91666c0[8], job=38, filetype=application/postscript, compression=0)
I [29/Oct/2008:12:52:50 +0100] [Job 38] Adding end banner page "none".
d [29/Oct/2008:12:52:50 +0100] copy_banner(con=(nil)[-1], job=0xb917b3a8[38], name="none")
I [29/Oct/2008:12:52:50 +0100] [Job 38] File of type application/postscript queued by "sd2".
D [29/Oct/2008:12:52:50 +0100] [Job 38] hold_until=0
d [29/Oct/2008:12:52:50 +0100] cupsdSaveJob(job=0xb917b3a8(38)): job->attrs=0xb913b9d8
I [29/Oct/2008:12:52:50 +0100] [Job 38] Queued on "c2424" by "sd2".
d [29/Oct/2008:12:52:50 +0100] cupsdCheckJobs: 17 active jobs, sleeping=0, reload=0
d [29/Oct/2008:12:52:50 +0100] cupsdCheckJobs: Job 14: state_value=6, loaded=no
d [29/Oct/2008:12:52:50 +0100] cupsdCheckJobs: Job 15: state_value=6, loaded=no
d [29/Oct/2008:12:52:50 +0100] cupsdCheckJobs: Job 17: state_value=6, loaded=no
d [29/Oct/2008:12:52:50 +0100] cupsdCheckJobs: Job 19: state_value=6, loaded=no
d [29/Oct/2008:12:52:50 +0100] cupsdCheckJobs: Job 21: state_value=6, loaded=no
d [29/Oct/2008:12:52:50 +0100] cupsdCheckJobs: Job 22: state_value=6, loaded=no
d [29/Oct/2008:12:52:50 +0100] cupsdCheckJobs: Job 23: state_value=6, loaded=no
d [29/Oct/2008:12:52:50 +0100] cupsdCheckJobs: Job 26: state_value=6, loaded=no
d [29/Oct/2008:12:52:50 +0100] cupsdCheckJobs: Job 30: state_value=6, loaded=no
d [29/Oct/2008:12:52:50 +0100] cupsdCheckJobs: Job 31: state_value=6, loaded=no
d [29/Oct/2008:12:52:50 +0100] cupsdCheckJobs: Job 32: state_value=6, loaded=no
d [29/Oct/2008:12:52:50 +0100] cupsdCheckJobs: Job 33: state_value=6, loaded=no
d [29/Oct/2008:12:52:50 +0100] cupsdCheckJobs: Job 34: state_value=6, loaded=no
d [29/Oct/2008:12:52:50 +0100] cupsdCheckJobs: Job 35: state_value=6, loaded=no
d [29/Oct/2008:12:52:50 +0100] cupsdCheckJobs: Job 36: state_value=6, loaded=no
d [29/Oct/2008:12:52:50 +0100] cupsdCheckJobs: Job 37: state_value=6, loaded=no
d [29/Oct/2008:12:52:50 +0100] cupsdCheckJobs: Job 38: state_value=3, loaded=yes
d [29/Oct/2008:12:52:50 +0100] [Job 38] start_job: file = 0/1
d [29/Oct/2008:12:52:50 +0100] cupsdAddEvent(event=printer-state-changed, dest=0xb9128790(c2424), job=(nil)(0), text="%s "%s" state changed.", ...)
d [29/Oct/2008:12:52:50 +0100] cupsd_send_notification(sub=0xb915d858(1), event=0xb917bfc8(printer-state-changed))
d [29/Oct/2008:12:52:50 +0100] cupsd_send_notification(sub=0xb915cd88(2), event=0xb917c230(printer-state-changed))
d [29/Oct/2008:12:52:50 +0100] cupsd_send_notification(sub=0xb915ce18(3), event=0xb917c450(printer-state-changed))
I [29/Oct/2008:12:52:50 +0100] Saving subscriptions.conf...
D [29/Oct/2008:12:52:50 +0100] [Job 38] job-sheets=none,none
D [29/Oct/2008:12:52:50 +0100] [Job 38] banner_page = 0
D [29/Oct/2008:12:52:50 +0100] [Job 38] argv[0]="c2424"
D [29/Oct/2008:12:52:50 +0100] [Job 38] argv[1]="38"
D [29/Oct/2008:12:52:50 +0100] [Job 38] argv[2]="sd2"
D [29/Oct/2008:12:52:50 +0100] [Job 38] argv[3]="Sans nom1"
D [29/Oct/2008:12:52:50 +0100] [Job 38] argv[4]="1"
D [29/Oct/2008:12:52:50 +0100] [Job 38] argv[5]="InputSlot=Tray2 PageSize=A4 job-uuid=urn:uuid:ac052417-04b9-3fea-5ff1-e38b88cb4764"
D [29/Oct/2008:12:52:50 +0100] [Job 38] argv[6]="/var/spool/cups/d00038-001"
D [29/Oct/2008:12:52:50 +0100] [Job 38] envp[0]="CUPS_CACHEDIR=/var/cache/cups"
D [29/Oct/2008:12:52:50 +0100] [Job 38] envp[1]="CUPS_DATADIR=/usr/share/cups"
D [29/Oct/2008:12:52:50 +0100] [Job 38] envp[2]="CUPS_DOCROOT=/usr/share/cups/doc-root"
D [29/Oct/2008:12:52:50 +0100] [Job 38] envp[3]="CUPS_FONTPATH=/usr/share/cups/fonts"
D [29/Oct/2008:12:52:50 +0100] [Job 38] envp[4]="CUPS_REQUESTROOT=/var/spool/cups"
D [29/Oct/2008:12:52:50 +0100] [Job 38] envp[5]="CUPS_SERVERBIN=/usr/lib/cups"
D [29/Oct/2008:12:52:50 +0100] [Job 38] envp[6]="CUPS_SERVERROOT=/etc/cups"
D [29/Oct/2008:12:52:50 +0100] [Job 38] envp[7]="CUPS_STATEDIR=/var/run/cups"
D [29/Oct/2008:12:52:50 +0100] [Job 38] envp[8]="PATH=/usr/lib/cups/filter:/usr/bin:/usr/sbin:/bin:/usr/bin"
D [29/Oct/2008:12:52:50 +0100] [Job 38] envp[9]="SERVER_ADMIN=root@sd2-desktop"
D [29/Oct/2008:12:52:50 +0100] [Job 38] envp[10]="SOFTWARE=CUPS/1.3.9"
D [29/Oct/2008:12:52:50 +0100] [Job 38] envp[11]="TMPDIR=/var/spool/cups/tmp"
D [29/Oct/2008:12:52:50 +0100] [Job 38] envp[12]="TZ=Europe/Paris"
D [29/Oct/2008:12:52:50 +0100] [Job 38] envp[13]="USER=root"
D [29/Oct/2008:12:52:50 +0100] [Job 38] envp[14]="CUPS_SERVER=/var/run/cups/cups.sock"
D [29/Oct/2008:12:52:50 +0100] [Job 38] envp[15]="CUPS_ENCRYPTION=IfRequested"
D [29/Oct/2008:12:52:50 +0100] [Job 38] envp[16]="IPP_PORT=631"
D [29/Oct/2008:12:52:50 +0100] [Job 38] envp[17]="CHARSET=utf-8"
D [29/Oct/2008:12:52:50 +0100] [Job 38] envp[18]="LANG=fr_FR.UTF8"
D [29/Oct/2008:12:52:50 +0100] [Job 38] envp[19]="PPD=/etc/cups/ppd/c2424.ppd"
D [29/Oct/2008:12:52:50 +0100] [Job 38] envp[20]="RIP_MAX_CACHE=8m"
D [29/Oct/2008:12:52:50 +0100] [Job 38] envp[21]="CONTENT_TYPE=application/postscript"
D [29/Oct/2008:12:52:50 +0100] [Job 38] envp[22]="DEVICE_URI=socket://10.0.0.3:9100"
D [29/Oct/2008:12:52:50 +0100] [Job 38] envp[23]="PRINTER=c2424"
D [29/Oct/2008:12:52:50 +0100] [Job 38] envp[24]="FINAL_CONTENT_TYPE=application/vnd.cups-postscript"
d [29/Oct/2008:12:52:50 +0100] [Job 38] start_job: status_pipes = [ 16 17 ]
d [29/Oct/2008:12:52:50 +0100] [Job 38] start_job: filter="/usr/lib/cups/filter/pstopdf"
d [29/Oct/2008:12:52:50 +0100] [Job 38] start_job: filterfds[0]=[ 18 19 ]
d [29/Oct/2008:12:52:50 +0100] cupsdStartProcess("/usr/lib/cups/filter/pstopdf", 0xb917c080, 0xbfd960b4, -1, 19, 17)
d [29/Oct/2008:12:52:50 +0100] [Job 38] start_job: Closing filter pipes for slot 1 [ -1 -1 ]...
I [29/Oct/2008:12:52:50 +0100] [Job 38] Started filter /usr/lib/cups/filter/pstopdf (PID 7481)
d [29/Oct/2008:12:52:50 +0100] [Job 38] start_job: filter="/usr/lib/cups/filter/pdftopdf"
d [29/Oct/2008:12:52:50 +0100] [Job 38] start_job: filterfds[1]=[ 20 21 ]
d [29/Oct/2008:12:52:50 +0100] cupsdStartProcess("/usr/lib/cups/filter/pdftopdf", 0xb917c080, 0xbfd960b4, 18, 21, 17)
d [29/Oct/2008:12:52:50 +0100] [Job 38] start_job: Closing filter pipes for slot 0 [ 18 19 ]...
I [29/Oct/2008:12:52:50 +0100] [Job 38] Started filter /usr/lib/cups/filter/pdftopdf (PID 7483)
d [29/Oct/2008:12:52:50 +0100] [Job 38] start_job: print_pipes = [ 18 19 ]
d [29/Oct/2008:12:52:50 +0100] [Job 38] start_job: filter="/usr/lib/cups/filter/cpdftocps"
d [29/Oct/2008:12:52:50 +0100] [Job 38] start_job: filterfds[0]=[ 18 19 ]
d [29/Oct/2008:12:52:50 +0100] cupsdStartProcess("/usr/lib/cups/filter/cpdftocps", 0xb917c080, 0xbfd960b4, 20, 19, 17)
d [29/Oct/2008:12:52:50 +0100] [Job 38] start_job: Closing filter pipes for slot 1 [ 20 21 ]...
I [29/Oct/2008:12:52:50 +0100] [Job 38] Started filter /usr/lib/cups/filter/cpdftocps (PID 7487)
d [29/Oct/2008:12:52:50 +0100] [Job 38] start_job: backend="/usr/lib/cups/backend/socket"
d [29/Oct/2008:12:52:50 +0100] [Job 38] start_job: filterfds[1] = [ -1 -1 ]
d [29/Oct/2008:12:52:50 +0100] cupsdStartProcess("/usr/lib/cups/backend/socket", 0xb917c080, 0xbfd960b4, 18, -1, 17)
I [29/Oct/2008:12:52:50 +0100] [Job 38] Started backend /usr/lib/cups/backend/socket (PID 7489)
d [29/Oct/2008:12:52:50 +0100] [Job 38] start_job: Closing print pipes [ 18 19 ]...
d [29/Oct/2008:12:52:50 +0100] [Job 38] start_job: Closing back pipes [ 12 13 ]...
d [29/Oct/2008:12:52:50 +0100] [Job 38] start_job: Closing side pipes [ 14 15 ]...
d [29/Oct/2008:12:52:50 +0100] [Job 38] start_job: Closing status output pipe 17...
d [29/Oct/2008:12:52:50 +0100] [Job 38] start_job: Closing filter pipes for slot 1 [ -1 -1 ]...
d [29/Oct/2008:12:52:50 +0100] cupsdAddSelect: fd=16, read_cb=0xb8085ab0, write_cb=(nil), data=0xb917b3a8
d [29/Oct/2008:12:52:50 +0100] cupsdAddEvent(event=job-state-changed, dest=0xb9128790(c2424), job=0xb917b3a8(38), text="Job #%d started.", ...)
d [29/Oct/2008:12:52:50 +0100] cupsd_send_notification(sub=0xb915d858(1), event=0xb917bf50(job-state-changed))
d [29/Oct/2008:12:52:50 +0100] cupsd_send_notification(sub=0xb915cd88(2), event=0xb913fc98(job-state-changed))
d [29/Oct/2008:12:52:50 +0100] cupsd_send_notification(sub=0xb915ce18(3), event=0xb917c0a8(job-state-changed))
I [29/Oct/2008:12:52:50 +0100] Saving subscriptions.conf...
D [29/Oct/2008:12:52:50 +0100] cupsdProcessIPPRequest: 8 status_code=0 (successful-ok)
d [29/Oct/2008:12:52:50 +0100] cupsdAddSelect: fd=8, read_cb=0xb8056200, write_cb=0xb80559d0, data=0xb91666c0
d [29/Oct/2008:12:52:50 +0100] cupsdDoSelect: polling 6 fds for 1 seconds...
d [29/Oct/2008:12:52:50 +0100] cupsdDoSelect: epoll() returned 2...
d [29/Oct/2008:12:52:50 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:50 +0100] cupsdDoSelect: Read on fd 16...
D [29/Oct/2008:12:52:50 +0100] [Job 38] pstopdf argv[6] = 38 sd2 Sans nom1 1 InputSlot=Tray2 PageSize=A4 job-uuid=urn:uuid:ac052417-04b9-3fea-5ff1-e38b88cb4764 /var/spool/cups/d00038-001
I [29/Oct/2008:12:52:50 +0100] [Job 38] tentative de connexion à l’hôte 10.0.0.3 sur le port 9100
d [29/Oct/2008:12:52:50 +0100] [Job 38] STATE: +connecting-to-device
d [29/Oct/2008:12:52:50 +0100] [Job 38] STATE: -connecting-to-device
I [29/Oct/2008:12:52:50 +0100] [Job 38] connecté à 10.0.0.3...
D [29/Oct/2008:12:52:50 +0100] [Job 38] Connected to 10.0.0.3:9100 (IPv4)...
D [29/Oct/2008:12:52:50 +0100] [Job 38] backendRunLoop(print_fd=0, device_fd=5, use_bc=1, side_cb=0xb808dfc0)
d [29/Oct/2008:12:52:50 +0100] cupsdAddEvent(event=printer-state-changed, dest=0xb9128790(c2424), job=(nil)(0), text="Printer "%s" state changed.", ...)
d [29/Oct/2008:12:52:50 +0100] cupsd_send_notification(sub=0xb915d858(1), event=0xb917d3b0(printer-state-changed))
d [29/Oct/2008:12:52:50 +0100] cupsd_send_notification(sub=0xb915cd88(2), event=0xb917d5d0(printer-state-changed))
d [29/Oct/2008:12:52:50 +0100] cupsd_send_notification(sub=0xb915ce18(3), event=0xb917d7f0(printer-state-changed))
I [29/Oct/2008:12:52:50 +0100] Saving subscriptions.conf...
d [29/Oct/2008:12:52:50 +0100] cupsdDoSelect: polling 6 fds for 1 seconds...
d [29/Oct/2008:12:52:50 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:50 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:50 +0100] cupsdDoSelect: polling 6 fds for 1 seconds...
d [29/Oct/2008:12:52:50 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:50 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:50 +0100] cupsdDoSelect: polling 6 fds for 1 seconds...
d [29/Oct/2008:12:52:50 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:50 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:50 +0100] cupsdDoSelect: polling 6 fds for 1 seconds...
d [29/Oct/2008:12:52:50 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:50 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:50 +0100] cupsdDoSelect: polling 6 fds for 1 seconds...
d [29/Oct/2008:12:52:50 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:50 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:50 +0100] cupsdDoSelect: polling 6 fds for 1 seconds...
d [29/Oct/2008:12:52:50 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:50 +0100] cupsdDoSelect: Write on fd 8...
d [29/Oct/2008:12:52:50 +0100] cupsdWriteClient: 8 bytes < 0
d [29/Oct/2008:12:52:50 +0100] cupsdAddSelect: fd=8, read_cb=0xb8056200, write_cb=(nil), data=0xb91666c0
d [29/Oct/2008:12:52:50 +0100] cupsdDoSelect: polling 6 fds for 1 seconds...
d [29/Oct/2008:12:52:50 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:50 +0100] cupsdDoSelect: Read on fd 16...
D [29/Oct/2008:12:52:50 +0100] [Job 38] pdftops - copying to temp print file "/tmp/49084e92d0fcd"
d [29/Oct/2008:12:52:50 +0100] cupsdDoSelect: polling 6 fds for 1 seconds...
d [29/Oct/2008:12:52:50 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:50 +0100] cupsdDoSelect: Read on fd 16...
D [29/Oct/2008:12:52:50 +0100] [Job 38] Page = 595x842; 14,14 to 581,828
d [29/Oct/2008:12:52:50 +0100] cupsdDoSelect: polling 6 fds for 1 seconds...
d [29/Oct/2008:12:52:50 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:50 +0100] cupsdDoSelect: Read on fd 16...
D [29/Oct/2008:12:52:50 +0100] [Job 38] slow_collate=0, slow_duplex=0, slow_order=0
d [29/Oct/2008:12:52:50 +0100] cupsdDoSelect: polling 6 fds for 1 seconds...
d [29/Oct/2008:12:52:50 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:50 +0100] cupsdDoSelect: Read on fd 16...
D [29/Oct/2008:12:52:50 +0100] [Job 38] Before copy_comments - %!PS-Adobe-3.0
d [29/Oct/2008:12:52:50 +0100] cupsdDoSelect: polling 6 fds for 1 seconds...
d [29/Oct/2008:12:52:50 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:50 +0100] cupsdDoSelect: Read on fd 16...
D [29/Oct/2008:12:52:50 +0100] [Job 38] %!PS-Adobe-3.0
d [29/Oct/2008:12:52:50 +0100] cupsdDoSelect: polling 6 fds for 1 seconds...
d [29/Oct/2008:12:52:50 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:50 +0100] cupsdDoSelect: Read on fd 16...
D [29/Oct/2008:12:52:50 +0100] [Job 38] %%BoundingBox: (atend)
d [29/Oct/2008:12:52:50 +0100] cupsdDoSelect: polling 6 fds for 1 seconds...
d [29/Oct/2008:12:52:50 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:50 +0100] cupsdDoSelect: Read on fd 16...
D [29/Oct/2008:12:52:50 +0100] [Job 38] %%Creator: (OpenOffice.org 2.4)
d [29/Oct/2008:12:52:50 +0100] cupsdDoSelect: polling 6 fds for 1 seconds...
d [29/Oct/2008:12:52:50 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:50 +0100] cupsdDoSelect: Read on fd 16...
D [29/Oct/2008:12:52:50 +0100] [Job 38] %%For: (sd2)
d [29/Oct/2008:12:52:50 +0100] cupsdDoSelect: polling 6 fds for 1 seconds...
d [29/Oct/2008:12:52:50 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:50 +0100] cupsdDoSelect: Read on fd 16...
D [29/Oct/2008:12:52:50 +0100] [Job 38] %%CreationDate: (Wed Oct 29 12:52:50 2008)
d [29/Oct/2008:12:52:50 +0100] cupsdDoSelect: polling 6 fds for 1 seconds...
d [29/Oct/2008:12:52:50 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:50 +0100] cupsdDoSelect: Read on fd 16...
D [29/Oct/2008:12:52:50 +0100] [Job 38] %%Title: (Sans nom1)
d [29/Oct/2008:12:52:50 +0100] cupsdDoSelect: polling 6 fds for 1 seconds...
d [29/Oct/2008:12:52:50 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:50 +0100] cupsdDoSelect: Read on fd 16...
D [29/Oct/2008:12:52:50 +0100] [Job 38] %%LanguageLevel: 3
d [29/Oct/2008:12:52:50 +0100] cupsdDoSelect: polling 6 fds for 1 seconds...
d [29/Oct/2008:12:52:50 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:50 +0100] cupsdDoSelect: Read on fd 16...
D [29/Oct/2008:12:52:50 +0100] [Job 38] %%DocumentData: Clean7Bit
d [29/Oct/2008:12:52:50 +0100] cupsdDoSelect: polling 6 fds for 1 seconds...
d [29/Oct/2008:12:52:50 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:50 +0100] cupsdDoSelect: Read on fd 16...
D [29/Oct/2008:12:52:50 +0100] [Job 38] %%Pages: (atend)
d [29/Oct/2008:12:52:50 +0100] cupsdDoSelect: polling 6 fds for 1 seconds...
d [29/Oct/2008:12:52:50 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:50 +0100] cupsdDoSelect: Read on fd 16...
D [29/Oct/2008:12:52:50 +0100] [Job 38] %%PageOrder: Ascend
d [29/Oct/2008:12:52:50 +0100] cupsdDoSelect: polling 6 fds for 1 seconds...
d [29/Oct/2008:12:52:50 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:50 +0100] cupsdDoSelect: Read on fd 16...
D [29/Oct/2008:12:52:50 +0100] [Job 38] %%EndComments
d [29/Oct/2008:12:52:50 +0100] cupsdDoSelect: polling 6 fds for 1 seconds...
d [29/Oct/2008:12:52:50 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:50 +0100] cupsdDoSelect: Read on fd 16...
D [29/Oct/2008:12:52:50 +0100] [Job 38] Before copy_prolog - %%BeginProlog
d [29/Oct/2008:12:52:50 +0100] cupsdDoSelect: polling 6 fds for 1 seconds...
d [29/Oct/2008:12:52:50 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:50 +0100] cupsdDoSelect: Read on fd 16...
D [29/Oct/2008:12:52:50 +0100] [Job 38] Before copy_setup - %%BeginSetup
d [29/Oct/2008:12:52:50 +0100] cupsdDoSelect: polling 6 fds for 1 seconds...
d [29/Oct/2008:12:52:50 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:50 +0100] cupsdDoSelect: Read on fd 16...
D [29/Oct/2008:12:52:50 +0100] [Job 38] Before page loop - %%Page: 1 1
d [29/Oct/2008:12:52:50 +0100] cupsdDoSelect: polling 6 fds for 1 seconds...
d [29/Oct/2008:12:52:50 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:50 +0100] cupsdDoSelect: Read on fd 16...
D [29/Oct/2008:12:52:50 +0100] [Job 38] Copying page 1...
d [29/Oct/2008:12:52:50 +0100] cupsdDoSelect: polling 6 fds for 1 seconds...
d [29/Oct/2008:12:52:50 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:50 +0100] cupsdDoSelect: Read on fd 16...
d [29/Oct/2008:12:52:50 +0100] [Job 38] PAGE: 1 1
d [29/Oct/2008:12:52:50 +0100] cupsdAddEvent(event=job-progress, dest=0xb9128790(c2424), job=0xb917b3a8(38), text="Printed %d page(s).", ...)
d [29/Oct/2008:12:52:50 +0100] cupsd_send_notification(sub=0xb915d858(1), event=0xb917d390(job-progress))
d [29/Oct/2008:12:52:50 +0100] cupsd_send_notification(sub=0xb915cd88(2), event=0xb917db78(job-progress))
d [29/Oct/2008:12:52:50 +0100] cupsd_send_notification(sub=0xb915ce18(3), event=0xb917de60(job-progress))
I [29/Oct/2008:12:52:50 +0100] Saving subscriptions.conf...
d [29/Oct/2008:12:52:50 +0100] cupsdDoSelect: polling 6 fds for 1 seconds...
d [29/Oct/2008:12:52:50 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:50 +0100] cupsdDoSelect: Read on fd 16...
D [29/Oct/2008:12:52:50 +0100] [Job 38] pagew = 567.0, pagel = 813.6
d [29/Oct/2008:12:52:50 +0100] cupsdDoSelect: polling 6 fds for 1 seconds...
d [29/Oct/2008:12:52:50 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:50 +0100] cupsdDoSelect: Read on fd 16...
D [29/Oct/2008:12:52:50 +0100] [Job 38] bboxx = 0, bboxy = 0, bboxw = 595, bboxl = 842
d [29/Oct/2008:12:52:50 +0100] cupsdDoSelect: polling 6 fds for 1 seconds...
d [29/Oct/2008:12:52:50 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:50 +0100] cupsdDoSelect: Read on fd 16...
D [29/Oct/2008:12:52:50 +0100] [Job 38] PageLeft = 14.2, PageRight = 581.1
d [29/Oct/2008:12:52:50 +0100] cupsdDoSelect: polling 6 fds for 1 seconds...
d [29/Oct/2008:12:52:50 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:50 +0100] cupsdDoSelect: Read on fd 16...
D [29/Oct/2008:12:52:50 +0100] [Job 38] PageTop = 827.8, PageBottom = 14.2
d [29/Oct/2008:12:52:50 +0100] cupsdDoSelect: polling 6 fds for 1 seconds...
d [29/Oct/2008:12:52:50 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:50 +0100] cupsdDoSelect: Read on fd 16...
D [29/Oct/2008:12:52:50 +0100] [Job 38] PageWidth = 595.0, PageLength = 842.0
d [29/Oct/2008:12:52:50 +0100] cupsdDoSelect: polling 6 fds for 1 seconds...
d [29/Oct/2008:12:52:50 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:50 +0100] cupsdDoSelect: Read on fd 16...
D [29/Oct/2008:12:52:50 +0100] [Job 38] Wrote 1 pages...
d [29/Oct/2008:12:52:50 +0100] cupsdDoSelect: polling 6 fds for 1 seconds...
d [29/Oct/2008:12:52:51 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:51 +0100] cupsdDoSelect: Read on fd 16...
D [29/Oct/2008:12:52:51 +0100] [Job 38] Error: /undefined in --get--
D [29/Oct/2008:12:52:51 +0100] [Job 38] Operand stack:
d [29/Oct/2008:12:52:51 +0100] cupsdDoSelect: polling 6 fds for 1 seconds...
d [29/Oct/2008:12:52:51 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:51 +0100] cupsdDoSelect: Read on fd 16...
D [29/Oct/2008:12:52:51 +0100] [Job 38] --dict:70/200(L)--   xerox$pagedevice   --nostringval--   MediaClass   --nostringval--   MediaPosition   --nostringval--   PageSize   --nostringval--   TraySwitch   true   ImagingBBox   --nostringval--   ProcessColorModel   DeviceCMYK   DeviceRenderingInfo   --dict:146/146(ro)(L)--   DeviceRenderingInfo
D [29/Oct/2008:12:52:51 +0100] [Job 38] Execution stack:
d [29/Oct/2008:12:52:51 +0100] cupsdDoSelect: polling 6 fds for 1 seconds...
d [29/Oct/2008:12:52:51 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:51 +0100] cupsdDoSelect: Read on fd 16...
d [29/Oct/2008:12:52:51 +0100] cupsdDoSelect: polling 6 fds for 1 seconds...
d [29/Oct/2008:12:52:51 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:51 +0100] cupsdDoSelect: Read on fd 16...
d [29/Oct/2008:12:52:51 +0100] cupsdDoSelect: polling 6 fds for 1 seconds...
d [29/Oct/2008:12:52:51 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:51 +0100] cupsdDoSelect: Read on fd 16...
D [29/Oct/2008:12:52:51 +0100] [Job 38] %interp_exit   .runexec2   --nostringval--   --nostringval--   --nostringval--   2   %stopped_push   --nostringval--   --nostringval--   --nostringval--   false   1   %stopped_push   1905   1   3   %oparray_pop   1904   1   3   %oparray_pop   1888   1   3   %oparray_pop   1771   1   3   %oparray_pop   --nostringval--   %errorexec_pop   .runexec2   --nostringval--   --nostringval--   --nostringval--   2   %stopped_push   --nostringval--
D [29/Oct/2008:12:52:51 +0100] [Job 38] Dictionary stack:
D [29/Oct/2008:12:52:51 +0100] [Job 38] --dict:1158/1684(ro)(G)--   --dict:0/20(G)--   --dict:70/200(L)--
D [29/Oct/2008:12:52:51 +0100] [Job 38] Current allocation mode is local
d [29/Oct/2008:12:52:51 +0100] cupsdDoSelect: polling 6 fds for 1 seconds...
d [29/Oct/2008:12:52:51 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:51 +0100] cupsdDoSelect: Read on fd 16...
D [29/Oct/2008:12:52:51 +0100] [Job 38] GPL Ghostscript 8.63: Unrecoverable error, exit code 1
d [29/Oct/2008:12:52:51 +0100] cupsdDoSelect: polling 6 fds for 1 seconds...
d [29/Oct/2008:12:52:51 +0100] cupsdDoSelect: epoll() returned -1...
d [29/Oct/2008:12:52:51 +0100] process_children()
E [29/Oct/2008:12:52:51 +0100] PID 7481 (/usr/lib/cups/filter/pstopdf) stopped with status 1!
D [29/Oct/2008:12:52:51 +0100] PID 7483 (/usr/lib/cups/filter/pdftopdf) exited with no errors.
d [29/Oct/2008:12:52:51 +0100] select_timeout(-1): 11 seconds to process active jobs
d [29/Oct/2008:12:52:51 +0100] cupsdDoSelect: polling 6 fds for 11 seconds...
d [29/Oct/2008:12:52:51 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:51 +0100] cupsdDoSelect: Read on fd 16...
D [29/Oct/2008:12:52:51 +0100] [Job 38] Page = 595x842; 14,14 to 581,828
D [29/Oct/2008:12:52:51 +0100] [Job 38] slow_collate=0, slow_duplex=0, slow_order=0
d [29/Oct/2008:12:52:51 +0100] cupsdDoSelect: polling 6 fds for 1 seconds...
d [29/Oct/2008:12:52:51 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:51 +0100] cupsdDoSelect: Read on fd 16...
D [29/Oct/2008:12:52:51 +0100] [Job 38] Before copy_comments - %!PS-Adobe-3.0
D [29/Oct/2008:12:52:51 +0100] [Job 38] %!PS-Adobe-3.0
D [29/Oct/2008:12:52:51 +0100] [Job 38] %%LanguageLevel: 3
D [29/Oct/2008:12:52:51 +0100] [Job 38] %%DocumentSuppliedResources: (atend)
D [29/Oct/2008:12:52:51 +0100] [Job 38] %%DocumentMedia: plain 595 842 0 () ()
D [29/Oct/2008:12:52:51 +0100] [Job 38] %%BoundingBox: 0 0 595 842
D [29/Oct/2008:12:52:51 +0100] [Job 38] %%Pages: 1
D [29/Oct/2008:12:52:51 +0100] [Job 38] %%EndComments
d [29/Oct/2008:12:52:51 +0100] cupsdDoSelect: polling 6 fds for 1 seconds...
d [29/Oct/2008:12:52:51 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:51 +0100] cupsdDoSelect: Read on fd 16...
D [29/Oct/2008:12:52:51 +0100] [Job 38] Before copy_prolog - %%BeginDefaults
D [29/Oct/2008:12:52:51 +0100] [Job 38] Read 4096 bytes of print data...
d [29/Oct/2008:12:52:51 +0100] [Job 38] STATE: -media-empty-error
d [29/Oct/2008:12:52:51 +0100] [Job 38] STATE: -offline-error
I [29/Oct/2008:12:52:51 +0100] [Job 38] imprimante connectée.
D [29/Oct/2008:12:52:51 +0100] [Job 38] Wrote 4096 bytes of print data...
d [29/Oct/2008:12:52:51 +0100] cupsdAddEvent(event=printer-state-changed, dest=0xb9128790(c2424), job=(nil)(0), text="Printer "%s" state changed.", ...)
d [29/Oct/2008:12:52:51 +0100] cupsd_send_notification(sub=0xb915d858(1), event=0xb91564e8(printer-state-changed))
d [29/Oct/2008:12:52:51 +0100] cupsd_send_notification(sub=0xb915cd88(2), event=0xb9156500(printer-state-changed))
d [29/Oct/2008:12:52:51 +0100] cupsd_send_notification(sub=0xb915ce18(3), event=0xb917e508(printer-state-changed))
I [29/Oct/2008:12:52:51 +0100] Saving subscriptions.conf...
d [29/Oct/2008:12:52:51 +0100] cupsdDoSelect: polling 6 fds for 1 seconds...
d [29/Oct/2008:12:52:51 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:51 +0100] cupsdDoSelect: Read on fd 16...
D [29/Oct/2008:12:52:51 +0100] [Job 38] Read 4096 bytes of print data...
D [29/Oct/2008:12:52:51 +0100] [Job 38] Wrote 4096 bytes of print data...
d [29/Oct/2008:12:52:51 +0100] cupsdDoSelect: polling 6 fds for 1 seconds...
d [29/Oct/2008:12:52:51 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:51 +0100] cupsdDoSelect: Read on fd 16...
D [29/Oct/2008:12:52:51 +0100] [Job 38] Read 4096 bytes of print data...
D [29/Oct/2008:12:52:51 +0100] [Job 38] Wrote 4096 bytes of print data...
d [29/Oct/2008:12:52:51 +0100] cupsdDoSelect: polling 6 fds for 1 seconds...
d [29/Oct/2008:12:52:51 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:51 +0100] cupsdDoSelect: Read on fd 16...
D [29/Oct/2008:12:52:51 +0100] [Job 38] Before copy_setup - %%BeginSetup
d [29/Oct/2008:12:52:51 +0100] cupsdDoSelect: polling 6 fds for 1 seconds...
d [29/Oct/2008:12:52:51 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:51 +0100] cupsdDoSelect: Read on fd 16...
D [29/Oct/2008:12:52:51 +0100] [Job 38] Before page loop - %%Page: 1 1
D [29/Oct/2008:12:52:51 +0100] [Job 38] Copying page 1...
d [29/Oct/2008:12:52:51 +0100] [Job 38] PAGE: 1 1
d [29/Oct/2008:12:52:51 +0100] cupsdAddEvent(event=job-progress, dest=0xb9128790(c2424), job=0xb917b3a8(38), text="Printed %d page(s).", ...)
d [29/Oct/2008:12:52:51 +0100] cupsd_send_notification(sub=0xb915d858(1), event=0xb917cae8(job-progress))
d [29/Oct/2008:12:52:51 +0100] cupsd_send_notification(sub=0xb915cd88(2), event=0xb917cb00(job-progress))
d [29/Oct/2008:12:52:51 +0100] cupsd_send_notification(sub=0xb915ce18(3), event=0xb917ecc8(job-progress))
I [29/Oct/2008:12:52:51 +0100] Saving subscriptions.conf...
d [29/Oct/2008:12:52:51 +0100] cupsdDoSelect: polling 6 fds for 1 seconds...
d [29/Oct/2008:12:52:51 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:51 +0100] cupsdDoSelect: Read on fd 16...
D [29/Oct/2008:12:52:51 +0100] [Job 38] pagew = 567.0, pagel = 813.6
D [29/Oct/2008:12:52:51 +0100] [Job 38] bboxx = 0, bboxy = 0, bboxw = 595, bboxl = 842
D [29/Oct/2008:12:52:51 +0100] [Job 38] PageLeft = 14.2, PageRight = 581.1
D [29/Oct/2008:12:52:51 +0100] [Job 38] PageTop = 827.8, PageBottom = 14.2
D [29/Oct/2008:12:52:51 +0100] [Job 38] PageWidth = 595.0, PageLength = 842.0
D [29/Oct/2008:12:52:51 +0100] [Job 38] Read 4096 bytes of print data...
D [29/Oct/2008:12:52:51 +0100] [Job 38] Wrote 4096 bytes of print data...
D [29/Oct/2008:12:52:51 +0100] [Job 38] Read 217 bytes of print data...
D [29/Oct/2008:12:52:51 +0100] [Job 38] Wrote 1 pages...
D [29/Oct/2008:12:52:51 +0100] [Job 38] Wrote 217 bytes of print data...
D [29/Oct/2008:12:52:51 +0100] [Job 38] Read 88 bytes of print data...
D [29/Oct/2008:12:52:51 +0100] [Job 38] Wrote 88 bytes of print data...
d [29/Oct/2008:12:52:51 +0100] cupsdDoSelect: polling 6 fds for 1 seconds...
d [29/Oct/2008:12:52:51 +0100] cupsdDoSelect: epoll() returned -1...
d [29/Oct/2008:12:52:51 +0100] process_children()
D [29/Oct/2008:12:52:51 +0100] PID 7487 (/usr/lib/cups/filter/cpdftocps) exited with no errors.
d [29/Oct/2008:12:52:51 +0100] select_timeout(-1): 11 seconds to process active jobs
d [29/Oct/2008:12:52:51 +0100] cupsdDoSelect: polling 6 fds for 1 seconds...
d [29/Oct/2008:12:52:52 +0100] cupsdDoSelect: epoll() returned 0...
d [29/Oct/2008:12:52:52 +0100] select_timeout(0): 11 seconds to process active jobs
d [29/Oct/2008:12:52:52 +0100] cupsdDoSelect: polling 6 fds for 11 seconds...
d [29/Oct/2008:12:52:56 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:56 +0100] cupsdDoSelect: Read on fd 16...
I [29/Oct/2008:12:52:56 +0100] [Job 38] fichier d’impression envoyé, en attente de la fin de la tâche d’impression...
d [29/Oct/2008:12:52:56 +0100] cupsdCheckJobs: 17 active jobs, sleeping=0, reload=0
d [29/Oct/2008:12:52:56 +0100] cupsdCheckJobs: Job 14: state_value=6, loaded=no
d [29/Oct/2008:12:52:56 +0100] cupsdCheckJobs: Job 15: state_value=6, loaded=no
d [29/Oct/2008:12:52:56 +0100] cupsdCheckJobs: Job 17: state_value=6, loaded=no
d [29/Oct/2008:12:52:56 +0100] cupsdCheckJobs: Job 19: state_value=6, loaded=no
d [29/Oct/2008:12:52:56 +0100] cupsdCheckJobs: Job 21: state_value=6, loaded=no
d [29/Oct/2008:12:52:56 +0100] cupsdCheckJobs: Job 22: state_value=6, loaded=no
d [29/Oct/2008:12:52:56 +0100] cupsdCheckJobs: Job 23: state_value=6, loaded=no
d [29/Oct/2008:12:52:56 +0100] cupsdCheckJobs: Job 26: state_value=6, loaded=no
d [29/Oct/2008:12:52:56 +0100] cupsdCheckJobs: Job 30: state_value=6, loaded=no
d [29/Oct/2008:12:52:56 +0100] cupsdCheckJobs: Job 31: state_value=6, loaded=no
d [29/Oct/2008:12:52:56 +0100] cupsdCheckJobs: Job 32: state_value=6, loaded=no
d [29/Oct/2008:12:52:56 +0100] cupsdCheckJobs: Job 33: state_value=6, loaded=no
d [29/Oct/2008:12:52:56 +0100] cupsdCheckJobs: Job 34: state_value=6, loaded=no
d [29/Oct/2008:12:52:56 +0100] cupsdCheckJobs: Job 35: state_value=6, loaded=no
d [29/Oct/2008:12:52:56 +0100] cupsdCheckJobs: Job 36: state_value=6, loaded=no
d [29/Oct/2008:12:52:56 +0100] cupsdCheckJobs: Job 37: state_value=6, loaded=no
d [29/Oct/2008:12:52:56 +0100] cupsdCheckJobs: Job 38: state_value=5, loaded=yes
d [29/Oct/2008:12:52:56 +0100] cupsdDoSelect: polling 6 fds for 1 seconds...
d [29/Oct/2008:12:52:56 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:56 +0100] cupsdDoSelect: Read on fd 8...
d [29/Oct/2008:12:52:56 +0100] cupsdReadClient: 8, used=0, file=-1 state=0
d [29/Oct/2008:12:52:56 +0100] cupsdReadClient: httpGets returned EOF...
D [29/Oct/2008:12:52:56 +0100] cupsdCloseClient: 8
d [29/Oct/2008:12:52:56 +0100] cupsdRemoveSelect: fd=8
d [29/Oct/2008:12:52:56 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:56 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:56 +0100] cupsdDoSelect: Read on fd 16...
I [29/Oct/2008:12:52:56 +0100] [Job 38] prêt pour l’impression.
d [29/Oct/2008:12:52:56 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:56 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:56 +0100] cupsdDoSelect: Read on fd 16...
d [29/Oct/2008:12:52:56 +0100] process_children()
D [29/Oct/2008:12:52:56 +0100] PID 7489 (/usr/lib/cups/backend/socket) exited with no errors.
d [29/Oct/2008:12:52:56 +0100] cupsdDoSelect: polling 5 fds for 1 seconds...
d [29/Oct/2008:12:52:56 +0100] cupsdDoSelect: epoll() returned 1...
d [29/Oct/2008:12:52:56 +0100] cupsdDoSelect: Read on fd 16...
D [29/Oct/2008:12:52:56 +0100] [Job 38] File 0 is complete.
d [29/Oct/2008:12:52:56 +0100] [Job 38] cupsdFinishJob: job->status is 256
d [29/Oct/2008:12:52:56 +0100] cupsdRemoveSelect: fd=16
d [29/Oct/2008:12:52:56 +0100] [Job 38] cupsdFinishJob: Closing status pipes [ 16 -1 ]...
E [29/Oct/2008:12:52:56 +0100] [Job 38] Job stopped due to filter errors.
d [29/Oct/2008:12:52:56 +0100] [Job 38] cupsdStopJob: force = 1
d [29/Oct/2008:12:52:56 +0100] cupsdAddEvent(event=printer-state-changed, dest=0xb9128790(c2424), job=(nil)(0), text="%s "%s" state changed.", ...)
d [29/Oct/2008:12:52:56 +0100] cupsd_send_notification(sub=0xb915d858(1), event=0xb913ba20(printer-state-changed))
d [29/Oct/2008:12:52:56 +0100] cupsd_send_notification(sub=0xb915cd88(2), event=0xb917c850(printer-state-changed))
d [29/Oct/2008:12:52:56 +0100] cupsd_send_notification(sub=0xb915ce18(3), event=0xb917ca70(printer-state-changed))
I [29/Oct/2008:12:52:56 +0100] Saving subscriptions.conf...
d [29/Oct/2008:12:52:56 +0100] [Job 38] Closing print pipes [ -1 -1 ]...
d [29/Oct/2008:12:52:56 +0100] [Job 38] Closing back pipes [ -1 -1 ]...
d [29/Oct/2008:12:52:56 +0100] [Job 38] Closing side pipes [ -1 -1 ]...
d [29/Oct/2008:12:52:56 +0100] cupsdSaveJob(job=0xb917b3a8(38)): job->attrs=0xb913b9d8
d [29/Oct/2008:12:52:56 +0100] cupsdAddEvent(event=job-stopped, dest=0xb9128790(c2424), job=0xb917b3a8(38), text="Job stopped due to filter errors; please consult the error_log file for details.", ...)
d [29/Oct/2008:12:52:56 +0100] cupsd_send_notification(sub=0xb915d858(1), event=0xb91668a0(job-stopped))
d [29/Oct/2008:12:52:56 +0100] cupsd_send_notification(sub=0xb915cd88(2), event=0xb9166b88(job-stopped))
d [29/Oct/2008:12:52:56 +0100] cupsd_send_notification(sub=0xb915ce18(3), event=0xb9166e70(job-stopped))
I [29/Oct/2008:12:52:56 +0100] Saving subscriptions.conf...
d [29/Oct/2008:12:52:56 +0100] cupsdCheckJobs: 17 active jobs, sleeping=0, reload=0
d [29/Oct/2008:12:52:56 +0100] cupsdCheckJobs: Job 14: state_value=6, loaded=no
d [29/Oct/2008:12:52:56 +0100] cupsdCheckJobs: Job 15: state_value=6, loaded=no
d [29/Oct/2008:12:52:56 +0100] cupsdCheckJobs: Job 17: state_value=6, loaded=no
d [29/Oct/2008:12:52:56 +0100] cupsdCheckJobs: Job 19: state_value=6, loaded=no
d [29/Oct/2008:12:52:56 +0100] cupsdCheckJobs: Job 21: state_value=6, loaded=no
d [29/Oct/2008:12:52:56 +0100] cupsdCheckJobs: Job 22: state_value=6, loaded=no
d [29/Oct/2008:12:52:56 +0100] cupsdCheckJobs: Job 23: state_value=6, loaded=no
d [29/Oct/2008:12:52:56 +0100] cupsdCheckJobs: Job 26: state_value=6, loaded=no
d [29/Oct/2008:12:52:56 +0100] cupsdCheckJobs: Job 30: state_value=6, loaded=no
d [29/Oct/2008:12:52:56 +0100] cupsdCheckJobs: Job 31: state_value=6, loaded=no
d [29/Oct/2008:12:52:56 +0100] cupsdCheckJobs: Job 32: state_value=6, loaded=no
d [29/Oct/2008:12:52:56 +0100] cupsdCheckJobs: Job 33: state_value=6, loaded=no
d [29/Oct/2008:12:52:56 +0100] cupsdCheckJobs: Job 34: state_value=6, loaded=no
d [29/Oct/2008:12:52:56 +0100] cupsdCheckJobs: Job 35: state_value=6, loaded=no
d [29/Oct/2008:12:52:56 +0100] cupsdCheckJobs: Job 36: state_value=6, loaded=no
d [29/Oct/2008:12:52:56 +0100] cupsdCheckJobs: Job 37: state_value=6, loaded=no
d [29/Oct/2008:12:52:56 +0100] cupsdCheckJobs: Job 38: state_value=6, loaded=yes
d [29/Oct/2008:12:52:56 +0100] cupsdDoSelect: polling 4 fds for 1 seconds...
d [29/Oct/2008:12:52:57 +0100] cupsdDoSelect: epoll() returned 0...
D [29/Oct/2008:12:52:57 +0100] [Job 38] Unloading...
d [29/Oct/2008:12:52:57 +0100] select_timeout(0): 12878 seconds to expire subscription
d [29/Oct/2008:12:52:57 +0100] cupsdDoSelect: polling 4 fds for 12878 seconds...