Printing to CUPS printer via LPR from Embedded System

Ian ian.sanderson at gmail.com
Mon Feb 16 12:07:47 PST 2009


Hello,

I am trying to print to a CUPS printer from an embedded system that supports LPR. When I user a hardware print server (i.e. HP JetDirect) I can print fine, but when I try to use CUPS I get no printout. However, if I try to print from a windows machine to the CUPS printer using LPR it works fine.

This is my /var/log/messages file after first trying to print from the embedded system and then printing from windows:

*************************************
---/var/log/messages---
Feb 14 14:04:13 haroldws08 syslogd 1.4.1: restart.
Feb 14 14:04:13 haroldws08 kernel: klogd 1.4.1, log source = /proc/kmsg started.
Feb 14 14:04:35 haroldws08 xinetd[8197]: START: printer pid=8239 from=192.168.2.201
Feb 14 14:04:35 haroldws08 cups-lpd[8239]: Connection from 192.168.2.201 (IPv4 192.168.2.201)
Feb 14 14:04:35 haroldws08 cups-lpd[8239]: Receive print job for PRINTER
Feb 14 14:04:36 haroldws08 cups-lpd[8239]: Error while reading file - No such file or directory
Feb 14 14:04:36 haroldws08 cups-lpd[8239]: Closing connection
Feb 14 14:04:36 haroldws08 xinetd[8197]: EXIT: printer status=1 pid=8239 duration=1(sec)
Feb 14 14:11:47 haroldws08 xinetd[8197]: START: printer pid=8363 from=192.168.2.158
Feb 14 14:11:47 haroldws08 cups-lpd[8363]: Connection from calws-20.barbereng.com (IPv4 192.168.2.158)
Feb 14 14:11:47 haroldws08 cups-lpd[8363]: Receive print job for printer
Feb 14 14:11:47 haroldws08 cups-lpd[8363]: Print file - job ID = 7
Feb 14 14:11:47 haroldws08 cups-lpd[8363]: Closing connection
Feb 14 14:11:47 haroldws08 xinetd[8197]: EXIT: printer status=0 pid=8363 duration=0(sec)
*************************************

This is my /var/log/cups/error_log file after first trying to print from the embedded system and then printing from windows:

*************************************
---/var/log/cups/error_log---
d [14/Feb/2009:13:42:20 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:13:42:20 -0700] cupsdDoSelect: Read on fd 5...
d [14/Feb/2009:13:42:20 -0700] cupsdAcceptClient(lis=0x95643d0) 5 Clients = 0
D [14/Feb/2009:13:42:20 -0700] cupsdAcceptClient: skipping getpeercon()
D [14/Feb/2009:13:42:20 -0700] cupsdAcceptClient: 9 from localhost (Domain)
d [14/Feb/2009:13:42:20 -0700] cupsdAcceptClient: 9 connected to server on localhost:631
d [14/Feb/2009:13:42:20 -0700] cupsdAddSelect: fd=9, read_cb=0xd957d0, write_cb=(nil), data=0x958cd80
d [14/Feb/2009:13:42:20 -0700] cupsdCheckJobs: 0 active jobs, sleeping=0, reload=0
d [14/Feb/2009:13:42:20 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:13:42:20 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:13:42:20 -0700] cupsdDoSelect: Read on fd 9...
d [14/Feb/2009:13:42:20 -0700] cupsdReadClient: 9, used=0, file=-1 state=0
D [14/Feb/2009:13:42:20 -0700] cupsdReadClient: 9 POST / HTTP/1.1
d [14/Feb/2009:13:42:20 -0700] cupsdFindBest: uri = "/"...
d [14/Feb/2009:13:42:20 -0700] cupsdFindBest: Location CUPS_INTERNAL_BROWSE_ACL Limit 0
d [14/Feb/2009:13:42:20 -0700] cupsdFindBest: Location /printers/printer Limit 7f
d [14/Feb/2009:13:42:20 -0700] cupsdFindBest: Location /admin/conf Limit 7f
d [14/Feb/2009:13:42:20 -0700] cupsdFindBest: Location /admin Limit 7f
d [14/Feb/2009:13:42:20 -0700] cupsdFindBest: Location / Limit 7f
d [14/Feb/2009:13:42:20 -0700] cupsdFindBest: best = /
d [14/Feb/2009:13:42:20 -0700] cupsdAuthorize: con->uri="/", con->best=0x9564b08(/)
d [14/Feb/2009:13:42:20 -0700] cupsdAuthorize: Authorization=""
D [14/Feb/2009:13:42:20 -0700] cupsdAuthorize: No authentication data provided.
d [14/Feb/2009:13:42:20 -0700] cupsdIsAuthorized: con->uri="/", con->best=0x9564b08(/)
d [14/Feb/2009:13:42:20 -0700] cupsdIsAuthorized: level=CUPSD_AUTH_ANON, type=None, satisfy=CUPSD_AUTH_SATISFY_ALL, num_names=0
d [14/Feb/2009:13:42:20 -0700] cupsdIsAuthorized: auth=CUPSD_AUTH_ALLOW...
d [14/Feb/2009:13:42:20 -0700] POST /
d [14/Feb/2009:13:42:20 -0700] CONTENT_TYPE = application/ipp
d [14/Feb/2009:13:42:20 -0700] cupsdReadClient: 9 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=247, con->file=-1
d [14/Feb/2009:13:42:20 -0700] cupsdReadClient: 9, used=239, file=-1 state=6
d [14/Feb/2009:13:42:20 -0700] cupsdReadClient: 9 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=239, con->file=-1
d [14/Feb/2009:13:42:20 -0700] cupsdProcessIPPRequest(0x958cd80[9]): operation_id = 000b
D [14/Feb/2009:13:42:20 -0700] Get-Printer-Attributes ipp://localhost/printers/PRINTER
d [14/Feb/2009:13:42:20 -0700] get_printer_attrs(0x958cd80[9], ipp://localhost/printers/PRINTER)
d [14/Feb/2009:13:42:20 -0700] cupsdFindPolicyOp(p=0x9564cc0, op=b(Get-Printer-Attributes))
d [14/Feb/2009:13:42:20 -0700] cupsdFindPolicyOp: Found wildcard match...
d [14/Feb/2009:13:42:20 -0700] cupsdIsAuthorized: con->uri="/", con->best=0x9565f80((null))
d [14/Feb/2009:13:42:20 -0700] cupsdIsAuthorized: level=CUPSD_AUTH_ANON, type=None, satisfy=CUPSD_AUTH_SATISFY_ALL, num_names=0
d [14/Feb/2009:13:42:20 -0700] cupsdIsAuthorized: op=0(unknown-0000)
d [14/Feb/2009:13:42:20 -0700] cupsdIsAuthorized: auth=CUPSD_AUTH_ALLOW...
d [14/Feb/2009:13:42:20 -0700] copy_attrs(to=0x9590640, from=0x956fdc0, ra=0x9590760, group=0, quickcopy=0)
d [14/Feb/2009:13:42:20 -0700] copy_attribute(0x9590640, 0x956fed0[printer-name,4,42])
d [14/Feb/2009:13:42:20 -0700] copy_attribute(0x9590640, 0x956ff90[printer-info,4,41])
d [14/Feb/2009:13:42:20 -0700] copy_attrs(to=0x9590640, from=0x955efb8, ra=0x9590760, group=0, quickcopy=-2147483648)
D [14/Feb/2009:13:42:20 -0700] cupsdProcessIPPRequest: 9 status_code=0 (successful-ok)
d [14/Feb/2009:13:42:20 -0700] cupsdAddSelect: fd=9, read_cb=0xd957d0, write_cb=0xd94500, data=0x958cd80
d [14/Feb/2009:13:42:20 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:13:42:20 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:13:42:20 -0700] cupsdDoSelect: Write on fd 9...
d [14/Feb/2009:13:42:20 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:13:42:20 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:13:42:20 -0700] cupsdDoSelect: Write on fd 9...
d [14/Feb/2009:13:42:20 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:13:42:20 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:13:42:20 -0700] cupsdDoSelect: Write on fd 9...
d [14/Feb/2009:13:42:20 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:13:42:20 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:13:42:20 -0700] cupsdDoSelect: Write on fd 9...
d [14/Feb/2009:13:42:20 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:13:42:20 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:13:42:20 -0700] cupsdDoSelect: Write on fd 9...
d [14/Feb/2009:13:42:20 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:13:42:20 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:13:42:20 -0700] cupsdDoSelect: Write on fd 9...
d [14/Feb/2009:13:42:20 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:13:42:20 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:13:42:20 -0700] cupsdDoSelect: Write on fd 9...
d [14/Feb/2009:13:42:20 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:13:42:20 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:13:42:20 -0700] cupsdDoSelect: Write on fd 9...
d [14/Feb/2009:13:42:20 -0700] cupsdWriteClient: 9 bytes < 0
d [14/Feb/2009:13:42:20 -0700] cupsdAddSelect: fd=9, read_cb=0xd957d0, write_cb=(nil), data=0x958cd80
d [14/Feb/2009:13:42:20 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:13:42:21 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:13:42:21 -0700] cupsdDoSelect: Read on fd 9...
d [14/Feb/2009:13:42:21 -0700] cupsdReadClient: 9, used=0, file=-1 state=0
d [14/Feb/2009:13:42:21 -0700] cupsdReadClient: httpGets returned EOF...
D [14/Feb/2009:13:42:21 -0700] cupsdCloseClient: 9
d [14/Feb/2009:13:42:21 -0700] cupsdRemoveSelect: fd=9
d [14/Feb/2009:13:42:21 -0700] cupsdDoSelect: polling 4 fds for 1 seconds...
d [14/Feb/2009:13:42:22 -0700] cupsdDoSelect: epoll() returned 0...
d [14/Feb/2009:13:42:22 -0700] select_timeout(0): 86400 seconds to do nothing
d [14/Feb/2009:13:42:22 -0700] cupsdDoSelect: polling 4 fds for 86400 seconds...
d [14/Feb/2009:13:57:02 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:13:57:02 -0700] cupsdDoSelect: Read on fd 5...
d [14/Feb/2009:13:57:02 -0700] cupsdAcceptClient(lis=0x95643d0) 5 Clients = 0
D [14/Feb/2009:13:57:02 -0700] cupsdAcceptClient: skipping getpeercon()
D [14/Feb/2009:13:57:02 -0700] cupsdAcceptClient: 9 from localhost (Domain)
d [14/Feb/2009:13:57:02 -0700] cupsdAcceptClient: 9 connected to server on localhost:631
d [14/Feb/2009:13:57:02 -0700] cupsdAddSelect: fd=9, read_cb=0xd957d0, write_cb=(nil), data=0x958cd80
d [14/Feb/2009:13:57:02 -0700] cupsdDeleteCert: removing certificate for pid 0
d [14/Feb/2009:13:57:02 -0700] cupsdAddCert: adding certificate for pid 0
d [14/Feb/2009:13:57:02 -0700] cupsdAddCert: NumSystemGroups=2
d [14/Feb/2009:13:57:02 -0700] cupsdCheckJobs: 0 active jobs, sleeping=0, reload=0
D [14/Feb/2009:13:57:02 -0700] Report: clients=1
D [14/Feb/2009:13:57:02 -0700] Report: jobs=0
D [14/Feb/2009:13:57:02 -0700] Report: jobs-active=0
D [14/Feb/2009:13:57:02 -0700] Report: printers=1
D [14/Feb/2009:13:57:02 -0700] Report: printers-implicit=0
D [14/Feb/2009:13:57:02 -0700] Report: stringpool-string-count=317
D [14/Feb/2009:13:57:02 -0700] Report: stringpool-alloc-bytes=7256
D [14/Feb/2009:13:57:02 -0700] Report: stringpool-total-bytes=6456
d [14/Feb/2009:13:57:02 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:13:57:02 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:13:57:02 -0700] cupsdDoSelect: Read on fd 9...
d [14/Feb/2009:13:57:02 -0700] cupsdReadClient: 9, used=0, file=-1 state=0
D [14/Feb/2009:13:57:02 -0700] cupsdReadClient: 9 POST / HTTP/1.1
d [14/Feb/2009:13:57:02 -0700] cupsdFindBest: uri = "/"...
d [14/Feb/2009:13:57:02 -0700] cupsdFindBest: Location CUPS_INTERNAL_BROWSE_ACL Limit 0
d [14/Feb/2009:13:57:02 -0700] cupsdFindBest: Location /printers/printer Limit 7f
d [14/Feb/2009:13:57:02 -0700] cupsdFindBest: Location /admin/conf Limit 7f
d [14/Feb/2009:13:57:02 -0700] cupsdFindBest: Location /admin Limit 7f
d [14/Feb/2009:13:57:02 -0700] cupsdFindBest: Location / Limit 7f
d [14/Feb/2009:13:57:02 -0700] cupsdFindBest: best = /
d [14/Feb/2009:13:57:02 -0700] cupsdAuthorize: con->uri="/", con->best=0x9564b08(/)
d [14/Feb/2009:13:57:02 -0700] cupsdAuthorize: Authorization=""
D [14/Feb/2009:13:57:02 -0700] cupsdAuthorize: No authentication data provided.
d [14/Feb/2009:13:57:02 -0700] cupsdIsAuthorized: con->uri="/", con->best=0x9564b08(/)
d [14/Feb/2009:13:57:02 -0700] cupsdIsAuthorized: level=CUPSD_AUTH_ANON, type=None, satisfy=CUPSD_AUTH_SATISFY_ALL, num_names=0
d [14/Feb/2009:13:57:02 -0700] cupsdIsAuthorized: auth=CUPSD_AUTH_ALLOW...
d [14/Feb/2009:13:57:02 -0700] POST /
d [14/Feb/2009:13:57:02 -0700] CONTENT_TYPE = application/ipp
d [14/Feb/2009:13:57:02 -0700] cupsdReadClient: 9 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=247, con->file=-1
d [14/Feb/2009:13:57:02 -0700] cupsdProcessIPPRequest(0x958cd80[9]): operation_id = 000b
D [14/Feb/2009:13:57:02 -0700] Get-Printer-Attributes ipp://localhost/printers/PRINTER
d [14/Feb/2009:13:57:02 -0700] get_printer_attrs(0x958cd80[9], ipp://localhost/printers/PRINTER)
d [14/Feb/2009:13:57:02 -0700] cupsdFindPolicyOp(p=0x9564cc0, op=b(Get-Printer-Attributes))
d [14/Feb/2009:13:57:02 -0700] cupsdFindPolicyOp: Found wildcard match...
d [14/Feb/2009:13:57:02 -0700] cupsdIsAuthorized: con->uri="/", con->best=0x9565f80((null))
d [14/Feb/2009:13:57:02 -0700] cupsdIsAuthorized: level=CUPSD_AUTH_ANON, type=None, satisfy=CUPSD_AUTH_SATISFY_ALL, num_names=0
d [14/Feb/2009:13:57:02 -0700] cupsdIsAuthorized: op=0(unknown-0000)
d [14/Feb/2009:13:57:02 -0700] cupsdIsAuthorized: auth=CUPSD_AUTH_ALLOW...
d [14/Feb/2009:13:57:02 -0700] copy_attrs(to=0x95906d0, from=0x956fdc0, ra=0x95907f0, group=0, quickcopy=0)
d [14/Feb/2009:13:57:02 -0700] copy_attribute(0x95906d0, 0x956fed0[printer-name,4,42])
d [14/Feb/2009:13:57:02 -0700] copy_attribute(0x95906d0, 0x956ff90[printer-info,4,41])
d [14/Feb/2009:13:57:02 -0700] copy_attrs(to=0x95906d0, from=0x955efb8, ra=0x95907f0, group=0, quickcopy=-2147483648)
D [14/Feb/2009:13:57:02 -0700] cupsdProcessIPPRequest: 9 status_code=0 (successful-ok)
d [14/Feb/2009:13:57:02 -0700] cupsdAddSelect: fd=9, read_cb=0xd957d0, write_cb=0xd94500, data=0x958cd80
d [14/Feb/2009:13:57:02 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:13:57:02 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:13:57:02 -0700] cupsdDoSelect: Write on fd 9...
d [14/Feb/2009:13:57:02 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:13:57:02 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:13:57:02 -0700] cupsdDoSelect: Write on fd 9...
d [14/Feb/2009:13:57:02 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:13:57:02 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:13:57:02 -0700] cupsdDoSelect: Write on fd 9...
d [14/Feb/2009:13:57:02 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:13:57:02 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:13:57:02 -0700] cupsdDoSelect: Write on fd 9...
d [14/Feb/2009:13:57:02 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:13:57:02 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:13:57:02 -0700] cupsdDoSelect: Write on fd 9...
d [14/Feb/2009:13:57:02 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:13:57:02 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:13:57:02 -0700] cupsdDoSelect: Write on fd 9...
d [14/Feb/2009:13:57:02 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:13:57:02 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:13:57:02 -0700] cupsdDoSelect: Write on fd 9...
d [14/Feb/2009:13:57:02 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:13:57:02 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:13:57:02 -0700] cupsdDoSelect: Write on fd 9...
d [14/Feb/2009:13:57:02 -0700] cupsdWriteClient: 9 bytes < 0
d [14/Feb/2009:13:57:02 -0700] cupsdAddSelect: fd=9, read_cb=0xd957d0, write_cb=(nil), data=0x958cd80
d [14/Feb/2009:13:57:02 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:13:57:03 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:13:57:03 -0700] cupsdDoSelect: Read on fd 9...
d [14/Feb/2009:13:57:03 -0700] cupsdReadClient: 9, used=0, file=-1 state=0
d [14/Feb/2009:13:57:03 -0700] cupsdReadClient: httpGets returned EOF...
D [14/Feb/2009:13:57:03 -0700] cupsdCloseClient: 9
d [14/Feb/2009:13:57:03 -0700] cupsdRemoveSelect: fd=9
d [14/Feb/2009:13:57:03 -0700] cupsdDoSelect: polling 4 fds for 1 seconds...
d [14/Feb/2009:13:57:04 -0700] cupsdDoSelect: epoll() returned 0...
d [14/Feb/2009:13:57:04 -0700] select_timeout(0): 86400 seconds to do nothing
d [14/Feb/2009:13:57:04 -0700] cupsdDoSelect: polling 4 fds for 86400 seconds...
d [14/Feb/2009:13:58:56 -0700] cupsdDoSelect: epoll() returned -1...
I [14/Feb/2009:13:58:56 -0700] Scheduler shutting down normally.
d [14/Feb/2009:13:58:56 -0700] cupsdStopListening: closing all listen sockets.
d [14/Feb/2009:13:58:56 -0700] cupsdPauseListening: Clearing input bits...
d [14/Feb/2009:13:58:56 -0700] cupsdRemoveSelect: fd=4
d [14/Feb/2009:13:58:56 -0700] cupsdRemoveSelect: fd=5
d [14/Feb/2009:13:58:56 -0700] cupsdRemoveSelect: fd=6
d [14/Feb/2009:13:58:56 -0700] cupsdRemoveSelect: fd=-1
D [14/Feb/2009:13:58:56 -0700] Saving remote.cache...
d [14/Feb/2009:13:58:56 -0700] cupsdRemoveSelect: fd=7
I [14/Feb/2009:13:58:56 -0700] Saving job cache file "/var/cache/cups/job.cache"...
I [14/Feb/2009:13:58:57 -0700] Listening to 127.0.0.1:631 (IPv4)
I [14/Feb/2009:13:58:57 -0700] Listening to /var/run/cups/cups.sock (Domain)
E [14/Feb/2009:13:58:57 -0700] Hostname lookup for "All" failed!
E [14/Feb/2009:13:58:57 -0700] Bad Listen address All at line 21.
d [14/Feb/2009:13:58:57 -0700] cupsdAddLocation: added location '/printers/printer'
d [14/Feb/2009:13:58:57 -0700] cupsdAllowIP(loc=0x9f65100(/printers/printer), address=0:0:0:0, netmask=0:0:0:0)
d [14/Feb/2009:13:58:57 -0700] cupsdAddLocation: added location 'CUPS_INTERNAL_BROWSE_ACL'
d [14/Feb/2009:13:58:57 -0700] cupsdAllowHost(loc=0x9f69948(CUPS_INTERNAL_BROWSE_ACL), name="@LOCAL")
I [14/Feb/2009:13:58:57 -0700] Sending browsing info to 255.255.255.255:631 (IPv4)
I [14/Feb/2009:13:58:57 -0700] Listening to :::631 (IPv6)
I [14/Feb/2009:13:58:57 -0700] Listening to 0.0.0.0:631 (IPv4)
d [14/Feb/2009:13:58:57 -0700] cupsdAllowHost(loc=0x9f69948(CUPS_INTERNAL_BROWSE_ACL), name="@LOCAL")
d [14/Feb/2009:13:58:57 -0700] cupsdAddLocation: added location '/'
d [14/Feb/2009:13:58:57 -0700] cupsdAllowIP(loc=0x9f69b08(/), address=0:0:0:0, netmask=0:0:0:0)
d [14/Feb/2009:13:58:57 -0700] cupsdAddLocation: added location '/admin'
d [14/Feb/2009:13:58:57 -0700] cupsdAddLocation: added location '/admin/conf'
d [14/Feb/2009:13:58:57 -0700] cupsdAddName(loc=0x9f69c40, name="@SYSTEM")
d [14/Feb/2009:13:58:57 -0700] cupsdAddPolicyOp(p=0x9f69cc0, po=(nil), op=6(Send-Document))
d [14/Feb/2009:13:58:57 -0700] cupsdAddName(loc=0x9f69cf0, name="@OWNER")
d [14/Feb/2009:13:58:57 -0700] cupsdAddName(loc=0x9f69cf0, name="@SYSTEM")
d [14/Feb/2009:13:58:57 -0700] cupsdAddPolicyOp(p=0x9f69cc0, po=0x9f69cf0, op=7(Send-URI))
d [14/Feb/2009:13:58:57 -0700] cupsdAddName(loc=0x9f69fb0, name="@OWNER")
d [14/Feb/2009:13:58:57 -0700] cupsdAddName(loc=0x9f69fb0, name="@SYSTEM")
d [14/Feb/2009:13:58:57 -0700] cupsdAddPolicyOp(p=0x9f69cc0, po=0x9f69cf0, op=c(Hold-Job))
d [14/Feb/2009:13:58:57 -0700] cupsdAddName(loc=0x9f69ff0, name="@OWNER")
d [14/Feb/2009:13:58:57 -0700] cupsdAddName(loc=0x9f69ff0, name="@SYSTEM")
d [14/Feb/2009:13:58:57 -0700] cupsdAddPolicyOp(p=0x9f69cc0, po=0x9f69cf0, op=d(Release-Job))
d [14/Feb/2009:13:58:57 -0700] cupsdAddName(loc=0x9f6a078, name="@OWNER")
d [14/Feb/2009:13:58:57 -0700] cupsdAddName(loc=0x9f6a078, name="@SYSTEM")
d [14/Feb/2009:13:58:57 -0700] cupsdAddPolicyOp(p=0x9f69cc0, po=0x9f69cf0, op=e(Restart-Job))
d [14/Feb/2009:13:58:57 -0700] cupsdAddName(loc=0x9f6a0d8, name="@OWNER")
d [14/Feb/2009:13:58:57 -0700] cupsdAddName(loc=0x9f6a0d8, name="@SYSTEM")
d [14/Feb/2009:13:58:57 -0700] cupsdAddPolicyOp(p=0x9f69cc0, po=0x9f69cf0, op=12(Purge-Jobs))
d [14/Feb/2009:13:58:57 -0700] cupsdAddName(loc=0x9f6a168, name="@OWNER")
d [14/Feb/2009:13:58:57 -0700] cupsdAddName(loc=0x9f6a168, name="@SYSTEM")
d [14/Feb/2009:13:58:57 -0700] cupsdAddPolicyOp(p=0x9f69cc0, po=0x9f69cf0, op=14(Set-Job-Attributes))
d [14/Feb/2009:13:58:57 -0700] cupsdAddName(loc=0x9f6a1d8, name="@OWNER")
d [14/Feb/2009:13:58:57 -0700] cupsdAddName(loc=0x9f6a1d8, name="@SYSTEM")
d [14/Feb/2009:13:58:57 -0700] cupsdAddPolicyOp(p=0x9f69cc0, po=0x9f69cf0, op=17(Create-Job-Subscription))
d [14/Feb/2009:13:58:57 -0700] cupsdAddName(loc=0x9f6a270, name="@OWNER")
d [14/Feb/2009:13:58:57 -0700] cupsdAddName(loc=0x9f6a270, name="@SYSTEM")
d [14/Feb/2009:13:58:57 -0700] cupsdAddPolicyOp(p=0x9f69cc0, po=0x9f69cf0, op=1a(Renew-Subscription))
d [14/Feb/2009:13:58:57 -0700] cupsdAddName(loc=0x9f6a2e0, name="@OWNER")
d [14/Feb/2009:13:58:57 -0700] cupsdAddName(loc=0x9f6a2e0, name="@SYSTEM")
d [14/Feb/2009:13:58:57 -0700] cupsdAddPolicyOp(p=0x9f69cc0, po=0x9f69cf0, op=1b(Cancel-Subscription))
d [14/Feb/2009:13:58:57 -0700] cupsdAddName(loc=0x9f6a380, name="@OWNER")
d [14/Feb/2009:13:58:57 -0700] cupsdAddName(loc=0x9f6a380, name="@SYSTEM")
d [14/Feb/2009:13:58:57 -0700] cupsdAddPolicyOp(p=0x9f69cc0, po=0x9f69cf0, op=1c(Get-Notifications))
d [14/Feb/2009:13:58:57 -0700] cupsdAddName(loc=0x9f6a3f0, name="@OWNER")
d [14/Feb/2009:13:58:57 -0700] cupsdAddName(loc=0x9f6a3f0, name="@SYSTEM")
d [14/Feb/2009:13:58:57 -0700] cupsdAddPolicyOp(p=0x9f69cc0, po=0x9f69cf0, op=2c(Reprocess-Job))
d [14/Feb/2009:13:58:57 -0700] cupsdAddName(loc=0x9f6a460, name="@OWNER")
d [14/Feb/2009:13:58:57 -0700] cupsdAddName(loc=0x9f6a460, name="@SYSTEM")
d [14/Feb/2009:13:58:57 -0700] cupsdAddPolicyOp(p=0x9f69cc0, po=0x9f69cf0, op=2d(Cancel-Current-Job))
d [14/Feb/2009:13:58:57 -0700] cupsdAddName(loc=0x9f6a4d0, name="@OWNER")
d [14/Feb/2009:13:58:57 -0700] cupsdAddName(loc=0x9f6a4d0, name="@SYSTEM")
d [14/Feb/2009:13:58:57 -0700] cupsdAddPolicyOp(p=0x9f69cc0, po=0x9f69cf0, op=2e(Suspend-Current-Job))
d [14/Feb/2009:13:58:57 -0700] cupsdAddName(loc=0x9f6a580, name="@OWNER")
d [14/Feb/2009:13:58:57 -0700] cupsdAddName(loc=0x9f6a580, name="@SYSTEM")
d [14/Feb/2009:13:58:57 -0700] cupsdAddPolicyOp(p=0x9f69cc0, po=0x9f69cf0, op=2f(Resume-Job))
d [14/Feb/2009:13:58:57 -0700] cupsdAddName(loc=0x9f6a5f0, name="@OWNER")
d [14/Feb/2009:13:58:57 -0700] cupsdAddName(loc=0x9f6a5f0, name="@SYSTEM")
d [14/Feb/2009:13:58:57 -0700] cupsdAddPolicyOp(p=0x9f69cc0, po=0x9f69cf0, op=400d(CUPS-Move-Job))
d [14/Feb/2009:13:58:57 -0700] cupsdAddName(loc=0x9f6a540, name="@OWNER")
d [14/Feb/2009:13:58:57 -0700] cupsdAddName(loc=0x9f6a540, name="@SYSTEM")
d [14/Feb/2009:13:58:57 -0700] cupsdAddPolicyOp(p=0x9f69cc0, po=(nil), op=4003(CUPS-Add-Modify-Printer))
d [14/Feb/2009:13:58:57 -0700] cupsdAddName(loc=0x9f6a6d8, name="@SYSTEM")
d [14/Feb/2009:13:58:57 -0700] cupsdAddPolicyOp(p=0x9f69cc0, po=0x9f6a6d8, op=4004(CUPS-Delete-Printer))
d [14/Feb/2009:13:58:57 -0700] cupsdAddName(loc=0x9f6a788, name="@SYSTEM")
d [14/Feb/2009:13:58:57 -0700] cupsdAddPolicyOp(p=0x9f69cc0, po=0x9f6a6d8, op=4006(CUPS-Add-Modify-Class))
d [14/Feb/2009:13:58:57 -0700] cupsdAddName(loc=0x9f6a7e8, name="@SYSTEM")
d [14/Feb/2009:13:58:57 -0700] cupsdAddPolicyOp(p=0x9f69cc0, po=0x9f6a6d8, op=4007(CUPS-Delete-Class))
d [14/Feb/2009:13:58:57 -0700] cupsdAddName(loc=0x9f6a738, name="@SYSTEM")
d [14/Feb/2009:13:58:57 -0700] cupsdAddPolicyOp(p=0x9f69cc0, po=0x9f6a6d8, op=400a(CUPS-Set-Default))
d [14/Feb/2009:13:58:57 -0700] cupsdAddName(loc=0x9f6a8b0, name="@SYSTEM")
d [14/Feb/2009:13:58:57 -0700] cupsdAddPolicyOp(p=0x9f69cc0, po=(nil), op=10(Pause-Printer))
d [14/Feb/2009:13:58:57 -0700] cupsdAddName(loc=0x9f6a848, name="@SYSTEM")
d [14/Feb/2009:13:58:57 -0700] cupsdAddPolicyOp(p=0x9f69cc0, po=0x9f6a848, op=11(Resume-Printer))
d [14/Feb/2009:13:58:57 -0700] cupsdAddName(loc=0x9f6a980, name="@SYSTEM")
d [14/Feb/2009:13:58:57 -0700] cupsdAddPolicyOp(p=0x9f69cc0, po=0x9f6a848, op=22(Enable-Printer))
d [14/Feb/2009:13:58:57 -0700] cupsdAddName(loc=0x9f6a910, name="@SYSTEM")
d [14/Feb/2009:13:58:57 -0700] cupsdAddPolicyOp(p=0x9f69cc0, po=0x9f6a848, op=23(Disable-Printer))
d [14/Feb/2009:13:58:57 -0700] cupsdAddName(loc=0x9f6aa48, name="@SYSTEM")
d [14/Feb/2009:13:58:57 -0700] cupsdAddPolicyOp(p=0x9f69cc0, po=0x9f6a848, op=24(Pause-Printer-After-Current-Job))
d [14/Feb/2009:13:58:57 -0700] cupsdAddName(loc=0x9f6a9e0, name="@SYSTEM")
d [14/Feb/2009:13:58:57 -0700] cupsdAddPolicyOp(p=0x9f69cc0, po=0x9f6a848, op=25(Hold-New-Jobs))
d [14/Feb/2009:13:58:57 -0700] cupsdAddName(loc=0x9f6ab18, name="@SYSTEM")
d [14/Feb/2009:13:58:57 -0700] cupsdAddPolicyOp(p=0x9f69cc0, po=0x9f6a848, op=26(Release-Held-New-Jobs))
d [14/Feb/2009:13:58:57 -0700] cupsdAddName(loc=0x9f6aaa8, name="@SYSTEM")
d [14/Feb/2009:13:58:57 -0700] cupsdAddPolicyOp(p=0x9f69cc0, po=0x9f6a848, op=27(Deactivate-Printer))
d [14/Feb/2009:13:58:57 -0700] cupsdAddName(loc=0x9f6abf0, name="@SYSTEM")
d [14/Feb/2009:13:58:57 -0700] cupsdAddPolicyOp(p=0x9f69cc0, po=0x9f6a848, op=28(Activate-Printer))
d [14/Feb/2009:13:58:57 -0700] cupsdAddName(loc=0x9f6ab78, name="@SYSTEM")
d [14/Feb/2009:13:58:57 -0700] cupsdAddPolicyOp(p=0x9f69cc0, po=0x9f6a848, op=29(Restart-Printer))
d [14/Feb/2009:13:58:57 -0700] cupsdAddName(loc=0x9f6acc0, name="@SYSTEM")
d [14/Feb/2009:13:58:57 -0700] cupsdAddPolicyOp(p=0x9f69cc0, po=0x9f6a848, op=2a(Shutdown-Printer))
d [14/Feb/2009:13:58:57 -0700] cupsdAddName(loc=0x9f6ac40, name="@SYSTEM")
d [14/Feb/2009:13:58:57 -0700] cupsdAddPolicyOp(p=0x9f69cc0, po=0x9f6a848, op=2b(Startup-Printer))
d [14/Feb/2009:13:58:57 -0700] cupsdAddName(loc=0x9f6ad98, name="@SYSTEM")
d [14/Feb/2009:13:58:57 -0700] cupsdAddPolicyOp(p=0x9f69cc0, po=0x9f6a848, op=30(Promote-Job))
d [14/Feb/2009:13:58:57 -0700] cupsdAddName(loc=0x9f6ad10, name="@SYSTEM")
d [14/Feb/2009:13:58:57 -0700] cupsdAddPolicyOp(p=0x9f69cc0, po=0x9f6a848, op=31(Schedule-Job-After))
d [14/Feb/2009:13:58:57 -0700] cupsdAddName(loc=0x9f6ae68, name="@SYSTEM")
d [14/Feb/2009:13:58:57 -0700] cupsdAddPolicyOp(p=0x9f69cc0, po=0x9f6a848, op=4008(CUPS-Accept-Jobs))
d [14/Feb/2009:13:58:57 -0700] cupsdAddName(loc=0x9f6add8, name="@SYSTEM")
d [14/Feb/2009:13:58:57 -0700] cupsdAddPolicyOp(p=0x9f69cc0, po=0x9f6a848, op=4009(CUPS-Reject-Jobs))
d [14/Feb/2009:13:58:57 -0700] cupsdAddName(loc=0x9f6af40, name="@SYSTEM")
d [14/Feb/2009:13:58:57 -0700] cupsdAddPolicyOp(p=0x9f69cc0, po=(nil), op=8(Cancel-Job))
d [14/Feb/2009:13:58:57 -0700] cupsdAddName(loc=0x9f6aea8, name="@OWNER")
d [14/Feb/2009:13:58:57 -0700] cupsdAddName(loc=0x9f6aea8, name="@SYSTEM")
d [14/Feb/2009:13:58:57 -0700] cupsdAddPolicyOp(p=0x9f69cc0, po=0x9f6aea8, op=400e(CUPS-Authenticate-Job))
d [14/Feb/2009:13:58:57 -0700] cupsdAddName(loc=0x9f6b020, name="@OWNER")
d [14/Feb/2009:13:58:57 -0700] cupsdAddName(loc=0x9f6b020, name="@SYSTEM")
d [14/Feb/2009:13:58:57 -0700] cupsdAddPolicyOp(p=0x9f69cc0, po=(nil), op=0(unknown-0000))
I [14/Feb/2009:13:58:57 -0700] Loaded configuration file "/etc/cups/cupsd.conf"
I [14/Feb/2009:13:58:57 -0700] Using default TempDir of /var/spool/cups/tmp...
d [14/Feb/2009:13:58:57 -0700] cupsdSetEnv: CUPS_CACHEDIR=/var/cache/cups
d [14/Feb/2009:13:58:57 -0700] cupsdSetEnv: CUPS_DATADIR=/usr/share/cups
d [14/Feb/2009:13:58:57 -0700] cupsdSetEnv: CUPS_DOCROOT=/usr/share/doc/cups-1.3.7
d [14/Feb/2009:13:58:57 -0700] cupsdSetEnv: CUPS_FONTPATH=/usr/share/cups/fonts
d [14/Feb/2009:13:58:57 -0700] cupsdSetEnv: CUPS_REQUESTROOT=/var/spool/cups
d [14/Feb/2009:13:58:57 -0700] cupsdSetEnv: CUPS_SERVERBIN=/usr/lib/cups
d [14/Feb/2009:13:58:57 -0700] cupsdSetEnv: CUPS_SERVERROOT=/etc/cups
d [14/Feb/2009:13:58:57 -0700] cupsdSetEnv: CUPS_STATEDIR=/var/run/cups
d [14/Feb/2009:13:58:57 -0700] cupsdSetEnv: PATH=/usr/lib/cups/filter:/usr/bin:/usr/sbin:/bin:/usr/bin
d [14/Feb/2009:13:58:57 -0700] cupsdSetEnv: SERVER_ADMIN=root at haroldws08.barbereng.com
d [14/Feb/2009:13:58:57 -0700] cupsdSetEnv: SOFTWARE=CUPS/1.3.7
d [14/Feb/2009:13:58:57 -0700] cupsdSetEnv: TMPDIR=/var/spool/cups/tmp
d [14/Feb/2009:13:58:57 -0700] cupsdSetEnv: USER=root
I [14/Feb/2009:13:58:57 -0700] Configured for up to 100 clients.
I [14/Feb/2009:13:58:57 -0700] Allowing up to 100 client connections per host.
I [14/Feb/2009:13:58:57 -0700] Using policy "default" as the default!
d [14/Feb/2009:13:58:57 -0700] cupsdReadConfiguration: NumPolicies=1
d [14/Feb/2009:13:58:57 -0700] cupsdReadConfiguration: Policies[0]="default"
I [14/Feb/2009:13:58:57 -0700] Full reload is required.
I [14/Feb/2009:13:58:57 -0700] Loaded MIME database from '/etc/cups': 35 types, 38 filters...
d [14/Feb/2009:13:58:57 -0700] cupsdReadConfiguration: type application/octet-stream
d [14/Feb/2009:13:58:57 -0700] cupsdReadConfiguration: type application/pdf
d [14/Feb/2009:13:58:57 -0700] cupsdReadConfiguration: type application/postscript
d [14/Feb/2009:13:58:57 -0700] cupsdReadConfiguration: type application/rss+xml
d [14/Feb/2009:13:58:57 -0700] cupsdReadConfiguration: type application/vnd.cups-command
d [14/Feb/2009:13:58:57 -0700] cupsdReadConfiguration: type application/vnd.cups-form
d [14/Feb/2009:13:58:57 -0700] cupsdReadConfiguration: type application/vnd.cups-pdf
d [14/Feb/2009:13:58:57 -0700] cupsdReadConfiguration: type application/vnd.cups-postscript
d [14/Feb/2009:13:58:57 -0700] cupsdReadConfiguration: type application/vnd.cups-ppd
d [14/Feb/2009:13:58:57 -0700] cupsdReadConfiguration: type application/vnd.cups-raster
d [14/Feb/2009:13:58:57 -0700] cupsdReadConfiguration: type application/vnd.cups-raw
d [14/Feb/2009:13:58:57 -0700] cupsdReadConfiguration: type application/vnd.hp-hpgl
d [14/Feb/2009:13:58:57 -0700] cupsdReadConfiguration: type application/x-cshell
d [14/Feb/2009:13:58:57 -0700] cupsdReadConfiguration: type application/x-csource
d [14/Feb/2009:13:58:57 -0700] cupsdReadConfiguration: type application/x-perl
d [14/Feb/2009:13:58:57 -0700] cupsdReadConfiguration: type application/x-shell
d [14/Feb/2009:13:58:57 -0700] cupsdReadConfiguration: type image/gif
d [14/Feb/2009:13:58:57 -0700] cupsdReadConfiguration: type image/jpeg
d [14/Feb/2009:13:58:57 -0700] cupsdReadConfiguration: type image/png
d [14/Feb/2009:13:58:57 -0700] cupsdReadConfiguration: type image/tiff
d [14/Feb/2009:13:58:57 -0700] cupsdReadConfiguration: type image/x-alias
d [14/Feb/2009:13:58:57 -0700] cupsdReadConfiguration: type image/x-bitmap
d [14/Feb/2009:13:58:57 -0700] cupsdReadConfiguration: type image/x-icon
d [14/Feb/2009:13:58:57 -0700] cupsdReadConfiguration: type image/x-photocd
d [14/Feb/2009:13:58:57 -0700] cupsdReadConfiguration: type image/x-portable-anymap
d [14/Feb/2009:13:58:57 -0700] cupsdReadConfiguration: type image/x-portable-bitmap
d [14/Feb/2009:13:58:57 -0700] cupsdReadConfiguration: type image/x-portable-graymap
d [14/Feb/2009:13:58:57 -0700] cupsdReadConfiguration: type image/x-portable-pixmap
d [14/Feb/2009:13:58:57 -0700] cupsdReadConfiguration: type image/x-sgi-rgb
d [14/Feb/2009:13:58:57 -0700] cupsdReadConfiguration: type image/x-sun-raster
d [14/Feb/2009:13:58:57 -0700] cupsdReadConfiguration: type image/x-xbitmap
d [14/Feb/2009:13:58:57 -0700] cupsdReadConfiguration: type image/x-xpixmap
d [14/Feb/2009:13:58:57 -0700] cupsdReadConfiguration: type text/css
d [14/Feb/2009:13:58:57 -0700] cupsdReadConfiguration: type text/html
d [14/Feb/2009:13:58:57 -0700] cupsdReadConfiguration: type text/plain
d [14/Feb/2009:13:58:57 -0700] cupsdReadConfiguration: filter application/pdf to application/postscript 33 pdftops
d [14/Feb/2009:13:58:57 -0700] cupsdReadConfiguration: filter application/postscript to application/vnd.cups-postscript 66 pstops
d [14/Feb/2009:13:58:57 -0700] cupsdReadConfiguration: filter application/vnd.cups-postscript to application/vnd.cups-raster 100 pstoraster
d [14/Feb/2009:13:58:57 -0700] cupsdReadConfiguration: filter application/vnd.hp-hpgl to application/postscript 66 hpgltops
d [14/Feb/2009:13:58:57 -0700] cupsdReadConfiguration: filter application/x-cshell to application/postscript 33 texttops
d [14/Feb/2009:13:58:57 -0700] cupsdReadConfiguration: filter application/x-csource to application/postscript 33 texttops
d [14/Feb/2009:13:58:57 -0700] cupsdReadConfiguration: filter application/x-perl to application/postscript 33 texttops
d [14/Feb/2009:13:58:57 -0700] cupsdReadConfiguration: filter application/x-shell to application/postscript 33 texttops
d [14/Feb/2009:13:58:57 -0700] cupsdReadConfiguration: filter image/gif to application/vnd.cups-postscript 66 imagetops
d [14/Feb/2009:13:58:57 -0700] cupsdReadConfiguration: filter image/gif to application/vnd.cups-raster 100 imagetoraster
d [14/Feb/2009:13:58:57 -0700] cupsdReadConfiguration: filter image/jpeg to application/vnd.cups-postscript 66 imagetops
d [14/Feb/2009:13:58:57 -0700] cupsdReadConfiguration: filter image/jpeg to application/vnd.cups-raster 100 imagetoraster
d [14/Feb/2009:13:58:57 -0700] cupsdReadConfiguration: filter image/png to application/vnd.cups-postscript 66 imagetops
d [14/Feb/2009:13:58:57 -0700] cupsdReadConfiguration: filter image/png to application/vnd.cups-raster 100 imagetoraster
d [14/Feb/2009:13:58:57 -0700] cupsdReadConfiguration: filter image/tiff to application/vnd.cups-postscript 66 imagetops
d [14/Feb/2009:13:58:57 -0700] cupsdReadConfiguration: filter image/tiff to application/vnd.cups-raster 100 imagetoraster
d [14/Feb/2009:13:58:57 -0700] cupsdReadConfiguration: filter image/x-bitmap to application/vnd.cups-postscript 66 imagetops
d [14/Feb/2009:13:58:57 -0700] cupsdReadConfiguration: filter image/x-bitmap to application/vnd.cups-raster 100 imagetoraster
d [14/Feb/2009:13:58:57 -0700] cupsdReadConfiguration: filter image/x-photocd to application/vnd.cups-postscript 66 imagetops
d [14/Feb/2009:13:58:57 -0700] cupsdReadConfiguration: filter image/x-photocd to application/vnd.cups-raster 100 imagetoraster
d [14/Feb/2009:13:58:57 -0700] cupsdReadConfiguration: filter image/x-portable-anymap to application/vnd.cups-postscript 66 imagetops
d [14/Feb/2009:13:58:57 -0700] cupsdReadConfiguration: filter image/x-portable-anymap to application/vnd.cups-raster 100 imagetoraster
d [14/Feb/2009:13:58:57 -0700] cupsdReadConfiguration: filter image/x-portable-bitmap to application/vnd.cups-postscript 66 imagetops
d [14/Feb/2009:13:58:57 -0700] cupsdReadConfiguration: filter image/x-portable-bitmap to application/vnd.cups-raster 100 imagetoraster
d [14/Feb/2009:13:58:57 -0700] cupsdReadConfiguration: filter image/x-portable-graymap to application/vnd.cups-postscript 66 imagetops
d [14/Feb/2009:13:58:57 -0700] cupsdReadConfiguration: filter image/x-portable-graymap to application/vnd.cups-raster 100 imagetoraster
d [14/Feb/2009:13:58:57 -0700] cupsdReadConfiguration: filter image/x-portable-pixmap to application/vnd.cups-postscript 66 imagetops
d [14/Feb/2009:13:58:57 -0700] cupsdReadConfiguration: filter image/x-portable-pixmap to application/vnd.cups-raster 100 imagetoraster
d [14/Feb/2009:13:58:57 -0700] cupsdReadConfiguration: filter image/x-sgi-rgb to application/vnd.cups-postscript 66 imagetops
d [14/Feb/2009:13:58:57 -0700] cupsdReadConfiguration: filter image/x-sgi-rgb to application/vnd.cups-raster 100 imagetoraster
d [14/Feb/2009:13:58:57 -0700] cupsdReadConfiguration: filter image/x-sun-raster to application/vnd.cups-postscript 66 imagetops
d [14/Feb/2009:13:58:57 -0700] cupsdReadConfiguration: filter image/x-sun-raster to application/vnd.cups-raster 100 imagetoraster
d [14/Feb/2009:13:58:57 -0700] cupsdReadConfiguration: filter image/x-xbitmap to application/vnd.cups-postscript 66 imagetops
d [14/Feb/2009:13:58:57 -0700] cupsdReadConfiguration: filter image/x-xbitmap to application/vnd.cups-raster 100 imagetoraster
d [14/Feb/2009:13:58:57 -0700] cupsdReadConfiguration: filter image/x-xpixmap to application/vnd.cups-postscript 66 imagetops
d [14/Feb/2009:13:58:57 -0700] cupsdReadConfiguration: filter image/x-xpixmap to application/vnd.cups-raster 100 imagetoraster
d [14/Feb/2009:13:58:57 -0700] cupsdReadConfiguration: filter text/html to application/postscript 33 texttopaps
d [14/Feb/2009:13:58:57 -0700] cupsdReadConfiguration: filter text/plain to application/postscript 33 texttopaps
D [14/Feb/2009:13:58:57 -0700] Loading printer PRINTER...
d [14/Feb/2009:13:58:57 -0700] cupsdAddPrinter("PRINTER")
d [14/Feb/2009:13:58:57 -0700] cupsdFindBest: uri = "/printers/PRINTER"...
d [14/Feb/2009:13:58:57 -0700] cupsdFindBest: Location CUPS_INTERNAL_BROWSE_ACL Limit 0
d [14/Feb/2009:13:58:57 -0700] cupsdFindBest: Location /printers/printer Limit 7f
d [14/Feb/2009:13:58:57 -0700] cupsdFindBest: Location /admin/conf Limit 7f
d [14/Feb/2009:13:58:57 -0700] cupsdFindBest: Location /admin Limit 7f
d [14/Feb/2009:13:58:57 -0700] cupsdFindBest: Location / Limit 7f
d [14/Feb/2009:13:58:57 -0700] cupsdFindBest: best = /printers/printer
d [14/Feb/2009:13:58:57 -0700] cupsdFindPolicyOp(p=0x9f69cc0, op=2(Print-Job))
d [14/Feb/2009:13:58:57 -0700] cupsdFindPolicyOp: Found wildcard match...
d [14/Feb/2009:13:58:57 -0700] add_printer_filter: PRINTER: adding filter application/vnd.cups-raw printer/PRINTER 0 -
d [14/Feb/2009:13:58:57 -0700] add_printer_filter: PRINTER: adding filter application/vnd.cups-postscript printer/PRINTER 0 foomatic-rip
d [14/Feb/2009:13:58:57 -0700] add_printer_formats: 36 types, 40 filters
d [14/Feb/2009:13:58:57 -0700] add_printer_formats: PRINTER: application/octet-stream not supported
d [14/Feb/2009:13:58:57 -0700] add_printer_formats: PRINTER: application/pdf needs 2 filters
d [14/Feb/2009:13:58:57 -0700] add_printer_formats: PRINTER: application/postscript needs 1 filters
d [14/Feb/2009:13:58:57 -0700] add_printer_formats: PRINTER: application/rss+xml not supported
d [14/Feb/2009:13:58:57 -0700] add_printer_formats: PRINTER: application/vnd.cups-command not supported
d [14/Feb/2009:13:58:57 -0700] add_printer_formats: PRINTER: application/vnd.cups-form not supported
d [14/Feb/2009:13:58:57 -0700] add_printer_formats: PRINTER: application/vnd.cups-pdf not supported
d [14/Feb/2009:13:58:57 -0700] add_printer_formats: PRINTER: application/vnd.cups-postscript needs 1 filters
d [14/Feb/2009:13:58:57 -0700] add_printer_formats: PRINTER: application/vnd.cups-ppd not supported
d [14/Feb/2009:13:58:57 -0700] add_printer_formats: PRINTER: application/vnd.cups-raster not supported
d [14/Feb/2009:13:58:57 -0700] add_printer_formats: PRINTER: application/vnd.cups-raw needs 1 filters
d [14/Feb/2009:13:58:57 -0700] add_printer_formats: PRINTER: application/vnd.hp-hpgl needs 2 filters
d [14/Feb/2009:13:58:57 -0700] add_printer_formats: PRINTER: application/x-cshell needs 2 filters
d [14/Feb/2009:13:58:57 -0700] add_printer_formats: PRINTER: application/x-csource needs 2 filters
d [14/Feb/2009:13:58:57 -0700] add_printer_formats: PRINTER: application/x-perl needs 2 filters
d [14/Feb/2009:13:58:57 -0700] add_printer_formats: PRINTER: application/x-shell needs 2 filters
d [14/Feb/2009:13:58:57 -0700] add_printer_formats: PRINTER: image/gif needs 1 filters
d [14/Feb/2009:13:58:57 -0700] add_printer_formats: PRINTER: image/jpeg needs 1 filters
d [14/Feb/2009:13:58:57 -0700] add_printer_formats: PRINTER: image/png needs 1 filters
d [14/Feb/2009:13:58:57 -0700] add_printer_formats: PRINTER: image/tiff needs 1 filters
d [14/Feb/2009:13:58:57 -0700] add_printer_formats: PRINTER: image/x-alias not supported
d [14/Feb/2009:13:58:57 -0700] add_printer_formats: PRINTER: image/x-bitmap needs 1 filters
d [14/Feb/2009:13:58:57 -0700] add_printer_formats: PRINTER: image/x-icon not supported
d [14/Feb/2009:13:58:57 -0700] add_printer_formats: PRINTER: image/x-photocd needs 1 filters
d [14/Feb/2009:13:58:57 -0700] add_printer_formats: PRINTER: image/x-portable-anymap needs 1 filters
d [14/Feb/2009:13:58:57 -0700] add_printer_formats: PRINTER: image/x-portable-bitmap needs 1 filters
d [14/Feb/2009:13:58:57 -0700] add_printer_formats: PRINTER: image/x-portable-graymap needs 1 filters
d [14/Feb/2009:13:58:57 -0700] add_printer_formats: PRINTER: image/x-portable-pixmap needs 1 filters
d [14/Feb/2009:13:58:57 -0700] add_printer_formats: PRINTER: image/x-sgi-rgb needs 1 filters
d [14/Feb/2009:13:58:57 -0700] add_printer_formats: PRINTER: image/x-sun-raster needs 1 filters
d [14/Feb/2009:13:58:57 -0700] add_printer_formats: PRINTER: image/x-xbitmap needs 1 filters
d [14/Feb/2009:13:58:57 -0700] add_printer_formats: PRINTER: image/x-xpixmap needs 1 filters
d [14/Feb/2009:13:58:57 -0700] add_printer_formats: PRINTER: printer/PRINTER not supported
d [14/Feb/2009:13:58:57 -0700] add_printer_formats: PRINTER: text/css not supported
d [14/Feb/2009:13:58:57 -0700] add_printer_formats: PRINTER: text/html needs 2 filters
d [14/Feb/2009:13:58:57 -0700] add_printer_formats: PRINTER: text/plain needs 2 filters
d [14/Feb/2009:13:58:57 -0700] add_printer_formats: PRINTER: 26 supported types
D [14/Feb/2009:13:58:57 -0700] cupsdLoadRemoteCache: Not loading remote cache.
I [14/Feb/2009:13:58:57 -0700] Loading job cache file "/var/cache/cups/job.cache"...
I [14/Feb/2009:13:58:57 -0700] Full reload complete.
I [14/Feb/2009:13:58:57 -0700] Cleaning out old temporary files in "/var/spool/cups/tmp"...
d [14/Feb/2009:13:58:57 -0700] cupsdStartListening: 4 Listeners
I [14/Feb/2009:13:58:57 -0700] Listening to 127.0.0.1:631 on fd 4...
I [14/Feb/2009:13:58:57 -0700] Listening to /var/run/cups/cups.sock on fd 5...
I [14/Feb/2009:13:58:57 -0700] Listening to :::631 on fd 6...
E [14/Feb/2009:13:58:57 -0700] Unable to bind socket for address 0.0.0.0:631 - Address already in use.
d [14/Feb/2009:13:58:57 -0700] cupsdSetEnv: CUPS_SERVER=/var/run/cups/cups.sock
d [14/Feb/2009:13:58:57 -0700] cupsdSetEnv: CUPS_ENCRYPTION=IfRequested
d [14/Feb/2009:13:58:57 -0700] cupsdSetEnv: IPP_PORT=631
I [14/Feb/2009:13:58:57 -0700] Resuming new connection processing...
d [14/Feb/2009:13:58:57 -0700] cupsdResumeListening: Setting input bits...
d [14/Feb/2009:13:58:57 -0700] cupsdAddSelect: fd=4, read_cb=0x5f5c80, write_cb=(nil), data=0x9f65218
d [14/Feb/2009:13:58:57 -0700] cupsdAddSelect: fd=5, read_cb=0x5f5c80, write_cb=(nil), data=0x9f693d0
d [14/Feb/2009:13:58:57 -0700] cupsdAddSelect: fd=6, read_cb=0x5f5c80, write_cb=(nil), data=0x9f69d90
d [14/Feb/2009:13:58:57 -0700] cupsdAddSelect: fd=-1, read_cb=0x5f5c80, write_cb=(nil), data=0x9f69ea0
d [14/Feb/2009:13:58:57 -0700] cupsdAddSelect: fd=7, read_cb=0x5f1f70, write_cb=(nil), data=(nil)
d [14/Feb/2009:13:58:57 -0700] cupsdAddCert: adding certificate for pid 0
d [14/Feb/2009:13:58:57 -0700] cupsdAddCert: NumSystemGroups=2
d [14/Feb/2009:13:58:57 -0700] cupsdCheckJobs: 0 active jobs, sleeping=0, reload=0
d [14/Feb/2009:13:58:57 -0700] cupsdDoSelect: polling 4 fds for 1 seconds...
d [14/Feb/2009:13:58:58 -0700] cupsdDoSelect: epoll() returned 0...
D [14/Feb/2009:13:58:58 -0700] Report: clients=0
D [14/Feb/2009:13:58:58 -0700] Report: jobs=0
D [14/Feb/2009:13:58:58 -0700] Report: jobs-active=0
D [14/Feb/2009:13:58:58 -0700] Report: printers=1
D [14/Feb/2009:13:58:58 -0700] Report: printers-implicit=0
D [14/Feb/2009:13:58:58 -0700] Report: stringpool-string-count=315
D [14/Feb/2009:13:58:58 -0700] Report: stringpool-alloc-bytes=7232
D [14/Feb/2009:13:58:58 -0700] Report: stringpool-total-bytes=6424
d [14/Feb/2009:13:58:58 -0700] select_timeout(0): 86400 seconds to do nothing
d [14/Feb/2009:13:58:58 -0700] cupsdDoSelect: polling 4 fds for 86400 seconds...
d [14/Feb/2009:14:03:37 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:03:37 -0700] cupsdDoSelect: Read on fd 5...
d [14/Feb/2009:14:03:37 -0700] cupsdAcceptClient(lis=0x9f693d0) 5 Clients = 0
D [14/Feb/2009:14:03:37 -0700] cupsdAcceptClient: skipping getpeercon()
D [14/Feb/2009:14:03:37 -0700] cupsdAcceptClient: 9 from localhost (Domain)
d [14/Feb/2009:14:03:37 -0700] cupsdAcceptClient: 9 connected to server on localhost:631
d [14/Feb/2009:14:03:37 -0700] cupsdAddSelect: fd=9, read_cb=0x5f67d0, write_cb=(nil), data=0x9f91d80
d [14/Feb/2009:14:03:37 -0700] cupsdCheckJobs: 0 active jobs, sleeping=0, reload=0
D [14/Feb/2009:14:03:37 -0700] Report: clients=1
D [14/Feb/2009:14:03:37 -0700] Report: jobs=0
D [14/Feb/2009:14:03:37 -0700] Report: jobs-active=0
D [14/Feb/2009:14:03:37 -0700] Report: printers=1
D [14/Feb/2009:14:03:37 -0700] Report: printers-implicit=0
D [14/Feb/2009:14:03:37 -0700] Report: stringpool-string-count=316
D [14/Feb/2009:14:03:37 -0700] Report: stringpool-alloc-bytes=7256
D [14/Feb/2009:14:03:37 -0700] Report: stringpool-total-bytes=6440
d [14/Feb/2009:14:03:37 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:03:37 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:03:37 -0700] cupsdDoSelect: Read on fd 9...
d [14/Feb/2009:14:03:37 -0700] cupsdReadClient: 9, used=0, file=-1 state=0
D [14/Feb/2009:14:03:37 -0700] cupsdReadClient: 9 POST / HTTP/1.1
d [14/Feb/2009:14:03:37 -0700] cupsdFindBest: uri = "/"...
d [14/Feb/2009:14:03:37 -0700] cupsdFindBest: Location CUPS_INTERNAL_BROWSE_ACL Limit 0
d [14/Feb/2009:14:03:37 -0700] cupsdFindBest: Location /printers/printer Limit 7f
d [14/Feb/2009:14:03:37 -0700] cupsdFindBest: Location /admin/conf Limit 7f
d [14/Feb/2009:14:03:37 -0700] cupsdFindBest: Location /admin Limit 7f
d [14/Feb/2009:14:03:37 -0700] cupsdFindBest: Location / Limit 7f
d [14/Feb/2009:14:03:37 -0700] cupsdFindBest: best = /
d [14/Feb/2009:14:03:37 -0700] cupsdAuthorize: con->uri="/", con->best=0x9f69b08(/)
d [14/Feb/2009:14:03:37 -0700] cupsdAuthorize: Authorization=""
D [14/Feb/2009:14:03:37 -0700] cupsdAuthorize: No authentication data provided.
d [14/Feb/2009:14:03:37 -0700] cupsdIsAuthorized: con->uri="/", con->best=0x9f69b08(/)
d [14/Feb/2009:14:03:37 -0700] cupsdIsAuthorized: level=CUPSD_AUTH_ANON, type=None, satisfy=CUPSD_AUTH_SATISFY_ALL, num_names=0
d [14/Feb/2009:14:03:37 -0700] cupsdIsAuthorized: auth=CUPSD_AUTH_ALLOW...
d [14/Feb/2009:14:03:37 -0700] POST /
d [14/Feb/2009:14:03:37 -0700] CONTENT_TYPE = application/ipp
d [14/Feb/2009:14:03:37 -0700] cupsdReadClient: 9 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=247, con->file=-1
d [14/Feb/2009:14:03:37 -0700] cupsdReadClient: 9, used=239, file=-1 state=6
d [14/Feb/2009:14:03:37 -0700] cupsdReadClient: 9 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=239, con->file=-1
d [14/Feb/2009:14:03:37 -0700] cupsdProcessIPPRequest(0x9f91d80[9]): operation_id = 000b
D [14/Feb/2009:14:03:37 -0700] Get-Printer-Attributes ipp://localhost/printers/PRINTER
d [14/Feb/2009:14:03:37 -0700] get_printer_attrs(0x9f91d80[9], ipp://localhost/printers/PRINTER)
d [14/Feb/2009:14:03:37 -0700] cupsdFindPolicyOp(p=0x9f69cc0, op=b(Get-Printer-Attributes))
d [14/Feb/2009:14:03:37 -0700] cupsdFindPolicyOp: Found wildcard match...
d [14/Feb/2009:14:03:37 -0700] cupsdIsAuthorized: con->uri="/", con->best=0x9f6af80((null))
d [14/Feb/2009:14:03:37 -0700] cupsdIsAuthorized: level=CUPSD_AUTH_ANON, type=None, satisfy=CUPSD_AUTH_SATISFY_ALL, num_names=0
d [14/Feb/2009:14:03:37 -0700] cupsdIsAuthorized: op=0(unknown-0000)
d [14/Feb/2009:14:03:37 -0700] cupsdIsAuthorized: auth=CUPSD_AUTH_ALLOW...
d [14/Feb/2009:14:03:37 -0700] copy_attrs(to=0x9f95640, from=0x9f74dc0, ra=0x9f95760, group=0, quickcopy=0)
d [14/Feb/2009:14:03:37 -0700] copy_attribute(0x9f95640, 0x9f74ed0[printer-name,4,42])
d [14/Feb/2009:14:03:37 -0700] copy_attribute(0x9f95640, 0x9f74f90[printer-info,4,41])
d [14/Feb/2009:14:03:37 -0700] copy_attrs(to=0x9f95640, from=0x9f63fb8, ra=0x9f95760, group=0, quickcopy=-2147483648)
D [14/Feb/2009:14:03:37 -0700] cupsdProcessIPPRequest: 9 status_code=0 (successful-ok)
d [14/Feb/2009:14:03:37 -0700] cupsdAddSelect: fd=9, read_cb=0x5f67d0, write_cb=0x5f5500, data=0x9f91d80
d [14/Feb/2009:14:03:37 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:03:37 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:03:37 -0700] cupsdDoSelect: Write on fd 9...
d [14/Feb/2009:14:03:37 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:03:37 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:03:37 -0700] cupsdDoSelect: Write on fd 9...
d [14/Feb/2009:14:03:37 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:03:37 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:03:37 -0700] cupsdDoSelect: Write on fd 9...
d [14/Feb/2009:14:03:37 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:03:37 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:03:37 -0700] cupsdDoSelect: Write on fd 9...
d [14/Feb/2009:14:03:37 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:03:37 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:03:37 -0700] cupsdDoSelect: Write on fd 9...
d [14/Feb/2009:14:03:37 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:03:37 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:03:37 -0700] cupsdDoSelect: Write on fd 9...
d [14/Feb/2009:14:03:37 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:03:37 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:03:37 -0700] cupsdDoSelect: Write on fd 9...
d [14/Feb/2009:14:03:37 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:03:37 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:03:37 -0700] cupsdDoSelect: Write on fd 9...
d [14/Feb/2009:14:03:37 -0700] cupsdWriteClient: 9 bytes < 0
d [14/Feb/2009:14:03:37 -0700] cupsdAddSelect: fd=9, read_cb=0x5f67d0, write_cb=(nil), data=0x9f91d80
d [14/Feb/2009:14:03:37 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:03:38 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:03:38 -0700] cupsdDoSelect: Read on fd 9...
d [14/Feb/2009:14:03:38 -0700] cupsdReadClient: 9, used=0, file=-1 state=0
d [14/Feb/2009:14:03:38 -0700] cupsdReadClient: httpGets returned EOF...
D [14/Feb/2009:14:03:38 -0700] cupsdCloseClient: 9
d [14/Feb/2009:14:03:38 -0700] cupsdRemoveSelect: fd=9
d [14/Feb/2009:14:03:38 -0700] cupsdDoSelect: polling 4 fds for 1 seconds...
d [14/Feb/2009:14:03:39 -0700] cupsdDoSelect: epoll() returned 0...
d [14/Feb/2009:14:03:39 -0700] select_timeout(0): 86400 seconds to do nothing
d [14/Feb/2009:14:03:39 -0700] cupsdDoSelect: polling 4 fds for 86400 seconds...
d [14/Feb/2009:14:04:35 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:04:35 -0700] cupsdDoSelect: Read on fd 5...
d [14/Feb/2009:14:04:35 -0700] cupsdAcceptClient(lis=0x9f693d0) 5 Clients = 0
D [14/Feb/2009:14:04:35 -0700] cupsdAcceptClient: skipping getpeercon()
D [14/Feb/2009:14:04:35 -0700] cupsdAcceptClient: 9 from localhost (Domain)
d [14/Feb/2009:14:04:35 -0700] cupsdAcceptClient: 9 connected to server on localhost:631
d [14/Feb/2009:14:04:35 -0700] cupsdAddSelect: fd=9, read_cb=0x5f67d0, write_cb=(nil), data=0x9f91d80
d [14/Feb/2009:14:04:35 -0700] cupsdDeleteCert: removing certificate for pid 0
d [14/Feb/2009:14:04:35 -0700] cupsdAddCert: adding certificate for pid 0
d [14/Feb/2009:14:04:35 -0700] cupsdAddCert: NumSystemGroups=2
d [14/Feb/2009:14:04:35 -0700] cupsdCheckJobs: 0 active jobs, sleeping=0, reload=0
d [14/Feb/2009:14:04:35 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:04:35 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:04:35 -0700] cupsdDoSelect: Read on fd 9...
d [14/Feb/2009:14:04:35 -0700] cupsdReadClient: 9, used=0, file=-1 state=0
D [14/Feb/2009:14:04:35 -0700] cupsdReadClient: 9 POST / HTTP/1.1
d [14/Feb/2009:14:04:35 -0700] cupsdFindBest: uri = "/"...
d [14/Feb/2009:14:04:35 -0700] cupsdFindBest: Location CUPS_INTERNAL_BROWSE_ACL Limit 0
d [14/Feb/2009:14:04:35 -0700] cupsdFindBest: Location /printers/printer Limit 7f
d [14/Feb/2009:14:04:35 -0700] cupsdFindBest: Location /admin/conf Limit 7f
d [14/Feb/2009:14:04:35 -0700] cupsdFindBest: Location /admin Limit 7f
d [14/Feb/2009:14:04:35 -0700] cupsdFindBest: Location / Limit 7f
d [14/Feb/2009:14:04:35 -0700] cupsdFindBest: best = /
d [14/Feb/2009:14:04:35 -0700] cupsdAuthorize: con->uri="/", con->best=0x9f69b08(/)
d [14/Feb/2009:14:04:35 -0700] cupsdAuthorize: Authorization=""
D [14/Feb/2009:14:04:35 -0700] cupsdAuthorize: No authentication data provided.
d [14/Feb/2009:14:04:35 -0700] cupsdIsAuthorized: con->uri="/", con->best=0x9f69b08(/)
d [14/Feb/2009:14:04:35 -0700] cupsdIsAuthorized: level=CUPSD_AUTH_ANON, type=None, satisfy=CUPSD_AUTH_SATISFY_ALL, num_names=0
d [14/Feb/2009:14:04:35 -0700] cupsdIsAuthorized: auth=CUPSD_AUTH_ALLOW...
d [14/Feb/2009:14:04:35 -0700] POST /
d [14/Feb/2009:14:04:35 -0700] CONTENT_TYPE = application/ipp
d [14/Feb/2009:14:04:35 -0700] cupsdReadClient: 9 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=247, con->file=-1
d [14/Feb/2009:14:04:35 -0700] cupsdReadClient: 9, used=239, file=-1 state=6
d [14/Feb/2009:14:04:35 -0700] cupsdReadClient: 9 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=239, con->file=-1
d [14/Feb/2009:14:04:35 -0700] cupsdProcessIPPRequest(0x9f91d80[9]): operation_id = 000b
D [14/Feb/2009:14:04:35 -0700] Get-Printer-Attributes ipp://localhost/printers/PRINTER
d [14/Feb/2009:14:04:35 -0700] get_printer_attrs(0x9f91d80[9], ipp://localhost/printers/PRINTER)
d [14/Feb/2009:14:04:35 -0700] cupsdFindPolicyOp(p=0x9f69cc0, op=b(Get-Printer-Attributes))
d [14/Feb/2009:14:04:35 -0700] cupsdFindPolicyOp: Found wildcard match...
d [14/Feb/2009:14:04:35 -0700] cupsdIsAuthorized: con->uri="/", con->best=0x9f6af80((null))
d [14/Feb/2009:14:04:35 -0700] cupsdIsAuthorized: level=CUPSD_AUTH_ANON, type=None, satisfy=CUPSD_AUTH_SATISFY_ALL, num_names=0
d [14/Feb/2009:14:04:35 -0700] cupsdIsAuthorized: op=0(unknown-0000)
d [14/Feb/2009:14:04:35 -0700] cupsdIsAuthorized: auth=CUPSD_AUTH_ALLOW...
d [14/Feb/2009:14:04:35 -0700] copy_attrs(to=0x9f956d0, from=0x9f74dc0, ra=0x9f957f0, group=0, quickcopy=0)
d [14/Feb/2009:14:04:35 -0700] copy_attribute(0x9f956d0, 0x9f74ed0[printer-name,4,42])
d [14/Feb/2009:14:04:35 -0700] copy_attribute(0x9f956d0, 0x9f74f90[printer-info,4,41])
d [14/Feb/2009:14:04:35 -0700] copy_attrs(to=0x9f956d0, from=0x9f63fb8, ra=0x9f957f0, group=0, quickcopy=-2147483648)
D [14/Feb/2009:14:04:35 -0700] cupsdProcessIPPRequest: 9 status_code=0 (successful-ok)
d [14/Feb/2009:14:04:35 -0700] cupsdAddSelect: fd=9, read_cb=0x5f67d0, write_cb=0x5f5500, data=0x9f91d80
d [14/Feb/2009:14:04:35 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:04:35 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:04:35 -0700] cupsdDoSelect: Write on fd 9...
d [14/Feb/2009:14:04:35 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:04:35 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:04:35 -0700] cupsdDoSelect: Write on fd 9...
d [14/Feb/2009:14:04:35 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:04:35 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:04:35 -0700] cupsdDoSelect: Write on fd 9...
d [14/Feb/2009:14:04:35 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:04:35 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:04:35 -0700] cupsdDoSelect: Write on fd 9...
d [14/Feb/2009:14:04:35 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:04:35 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:04:35 -0700] cupsdDoSelect: Write on fd 9...
d [14/Feb/2009:14:04:35 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:04:35 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:04:35 -0700] cupsdDoSelect: Write on fd 9...
d [14/Feb/2009:14:04:35 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:04:35 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:04:35 -0700] cupsdDoSelect: Write on fd 9...
d [14/Feb/2009:14:04:35 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:04:35 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:04:35 -0700] cupsdDoSelect: Write on fd 9...
d [14/Feb/2009:14:04:35 -0700] cupsdWriteClient: 9 bytes < 0
d [14/Feb/2009:14:04:35 -0700] cupsdAddSelect: fd=9, read_cb=0x5f67d0, write_cb=(nil), data=0x9f91d80
d [14/Feb/2009:14:04:35 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:04:36 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:04:36 -0700] cupsdDoSelect: Read on fd 9...
d [14/Feb/2009:14:04:36 -0700] cupsdReadClient: 9, used=0, file=-1 state=0
d [14/Feb/2009:14:04:36 -0700] cupsdReadClient: httpGets returned EOF...
D [14/Feb/2009:14:04:36 -0700] cupsdCloseClient: 9
d [14/Feb/2009:14:04:36 -0700] cupsdRemoveSelect: fd=9
d [14/Feb/2009:14:04:36 -0700] cupsdDoSelect: polling 4 fds for 1 seconds...
d [14/Feb/2009:14:04:37 -0700] cupsdDoSelect: epoll() returned 0...
D [14/Feb/2009:14:04:37 -0700] Report: clients=0
D [14/Feb/2009:14:04:37 -0700] Report: jobs=0
D [14/Feb/2009:14:04:37 -0700] Report: jobs-active=0
D [14/Feb/2009:14:04:37 -0700] Report: printers=1
D [14/Feb/2009:14:04:37 -0700] Report: printers-implicit=0
D [14/Feb/2009:14:04:37 -0700] Report: stringpool-string-count=317
D [14/Feb/2009:14:04:37 -0700] Report: stringpool-alloc-bytes=7256
D [14/Feb/2009:14:04:37 -0700] Report: stringpool-total-bytes=6456
d [14/Feb/2009:14:04:37 -0700] select_timeout(0): 86400 seconds to do nothing
d [14/Feb/2009:14:04:37 -0700] cupsdDoSelect: polling 4 fds for 86400 seconds...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: Read on fd 5...
d [14/Feb/2009:14:11:47 -0700] cupsdAcceptClient(lis=0x9f693d0) 5 Clients = 0
D [14/Feb/2009:14:11:47 -0700] cupsdAcceptClient: skipping getpeercon()
D [14/Feb/2009:14:11:47 -0700] cupsdAcceptClient: 9 from localhost (Domain)
d [14/Feb/2009:14:11:47 -0700] cupsdAcceptClient: 9 connected to server on localhost:631
d [14/Feb/2009:14:11:47 -0700] cupsdAddSelect: fd=9, read_cb=0x5f67d0, write_cb=(nil), data=0x9f91d80
d [14/Feb/2009:14:11:47 -0700] cupsdDeleteCert: removing certificate for pid 0
d [14/Feb/2009:14:11:47 -0700] cupsdAddCert: adding certificate for pid 0
d [14/Feb/2009:14:11:47 -0700] cupsdAddCert: NumSystemGroups=2
d [14/Feb/2009:14:11:47 -0700] cupsdCheckJobs: 0 active jobs, sleeping=0, reload=0
D [14/Feb/2009:14:11:47 -0700] Report: clients=1
D [14/Feb/2009:14:11:47 -0700] Report: jobs=0
D [14/Feb/2009:14:11:47 -0700] Report: jobs-active=0
D [14/Feb/2009:14:11:47 -0700] Report: printers=1
D [14/Feb/2009:14:11:47 -0700] Report: printers-implicit=0
D [14/Feb/2009:14:11:47 -0700] Report: stringpool-string-count=318
D [14/Feb/2009:14:11:47 -0700] Report: stringpool-alloc-bytes=7256
D [14/Feb/2009:14:11:47 -0700] Report: stringpool-total-bytes=6472
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: Read on fd 9...
d [14/Feb/2009:14:11:47 -0700] cupsdReadClient: 9, used=0, file=-1 state=0
D [14/Feb/2009:14:11:47 -0700] cupsdReadClient: 9 POST / HTTP/1.1
d [14/Feb/2009:14:11:47 -0700] cupsdFindBest: uri = "/"...
d [14/Feb/2009:14:11:47 -0700] cupsdFindBest: Location CUPS_INTERNAL_BROWSE_ACL Limit 0
d [14/Feb/2009:14:11:47 -0700] cupsdFindBest: Location /printers/printer Limit 7f
d [14/Feb/2009:14:11:47 -0700] cupsdFindBest: Location /admin/conf Limit 7f
d [14/Feb/2009:14:11:47 -0700] cupsdFindBest: Location /admin Limit 7f
d [14/Feb/2009:14:11:47 -0700] cupsdFindBest: Location / Limit 7f
d [14/Feb/2009:14:11:47 -0700] cupsdFindBest: best = /
d [14/Feb/2009:14:11:47 -0700] cupsdAuthorize: con->uri="/", con->best=0x9f69b08(/)
d [14/Feb/2009:14:11:47 -0700] cupsdAuthorize: Authorization=""
D [14/Feb/2009:14:11:47 -0700] cupsdAuthorize: No authentication data provided.
d [14/Feb/2009:14:11:47 -0700] cupsdIsAuthorized: con->uri="/", con->best=0x9f69b08(/)
d [14/Feb/2009:14:11:47 -0700] cupsdIsAuthorized: level=CUPSD_AUTH_ANON, type=None, satisfy=CUPSD_AUTH_SATISFY_ALL, num_names=0
d [14/Feb/2009:14:11:47 -0700] cupsdIsAuthorized: auth=CUPSD_AUTH_ALLOW...
d [14/Feb/2009:14:11:47 -0700] POST /
d [14/Feb/2009:14:11:47 -0700] CONTENT_TYPE = application/ipp
d [14/Feb/2009:14:11:47 -0700] cupsdReadClient: 9 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=247, con->file=-1
d [14/Feb/2009:14:11:47 -0700] cupsdReadClient: 9, used=239, file=-1 state=6
d [14/Feb/2009:14:11:47 -0700] cupsdReadClient: 9 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=239, con->file=-1
d [14/Feb/2009:14:11:47 -0700] cupsdProcessIPPRequest(0x9f91d80[9]): operation_id = 000b
D [14/Feb/2009:14:11:47 -0700] Get-Printer-Attributes ipp://localhost/printers/printer
d [14/Feb/2009:14:11:47 -0700] get_printer_attrs(0x9f91d80[9], ipp://localhost/printers/printer)
d [14/Feb/2009:14:11:47 -0700] cupsdFindPolicyOp(p=0x9f69cc0, op=b(Get-Printer-Attributes))
d [14/Feb/2009:14:11:47 -0700] cupsdFindPolicyOp: Found wildcard match...
d [14/Feb/2009:14:11:47 -0700] cupsdIsAuthorized: con->uri="/", con->best=0x9f6af80((null))
d [14/Feb/2009:14:11:47 -0700] cupsdIsAuthorized: level=CUPSD_AUTH_ANON, type=None, satisfy=CUPSD_AUTH_SATISFY_ALL, num_names=0
d [14/Feb/2009:14:11:47 -0700] cupsdIsAuthorized: op=0(unknown-0000)
d [14/Feb/2009:14:11:47 -0700] cupsdIsAuthorized: auth=CUPSD_AUTH_ALLOW...
d [14/Feb/2009:14:11:47 -0700] copy_attrs(to=0x9f956d0, from=0x9f74dc0, ra=0x9f957f0, group=0, quickcopy=0)
d [14/Feb/2009:14:11:47 -0700] copy_attribute(0x9f956d0, 0x9f74ed0[printer-name,4,42])
d [14/Feb/2009:14:11:47 -0700] copy_attribute(0x9f956d0, 0x9f74f90[printer-info,4,41])
d [14/Feb/2009:14:11:47 -0700] copy_attrs(to=0x9f956d0, from=0x9f63fb8, ra=0x9f957f0, group=0, quickcopy=-2147483648)
D [14/Feb/2009:14:11:47 -0700] cupsdProcessIPPRequest: 9 status_code=0 (successful-ok)
d [14/Feb/2009:14:11:47 -0700] cupsdAddSelect: fd=9, read_cb=0x5f67d0, write_cb=0x5f5500, data=0x9f91d80
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: Write on fd 9...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: Write on fd 9...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: Write on fd 9...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: Write on fd 9...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: Write on fd 9...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: Write on fd 9...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: Write on fd 9...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: Write on fd 9...
d [14/Feb/2009:14:11:47 -0700] cupsdWriteClient: 9 bytes < 0
d [14/Feb/2009:14:11:47 -0700] cupsdAddSelect: fd=9, read_cb=0x5f67d0, write_cb=(nil), data=0x9f91d80
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: Read on fd 9...
d [14/Feb/2009:14:11:47 -0700] cupsdReadClient: 9, used=0, file=-1 state=0
D [14/Feb/2009:14:11:47 -0700] cupsdReadClient: 9 POST /printers/printer HTTP/1.1
d [14/Feb/2009:14:11:47 -0700] cupsdFindBest: uri = "/printers/printer"...
d [14/Feb/2009:14:11:47 -0700] cupsdFindBest: Location CUPS_INTERNAL_BROWSE_ACL Limit 0
d [14/Feb/2009:14:11:47 -0700] cupsdFindBest: Location /printers/printer Limit 7f
d [14/Feb/2009:14:11:47 -0700] cupsdFindBest: Location /admin/conf Limit 7f
d [14/Feb/2009:14:11:47 -0700] cupsdFindBest: Location /admin Limit 7f
d [14/Feb/2009:14:11:47 -0700] cupsdFindBest: Location / Limit 7f
d [14/Feb/2009:14:11:47 -0700] cupsdFindBest: best = /printers/printer
d [14/Feb/2009:14:11:47 -0700] cupsdAuthorize: con->uri="/printers/printer", con->best=0x9f65100(/printers/printer)
d [14/Feb/2009:14:11:47 -0700] cupsdAuthorize: Authorization=""
D [14/Feb/2009:14:11:47 -0700] cupsdAuthorize: No authentication data provided.
d [14/Feb/2009:14:11:47 -0700] cupsdIsAuthorized: con->uri="/printers/printer", con->best=0x9f65100(/printers/printer)
d [14/Feb/2009:14:11:47 -0700] cupsdIsAuthorized: level=CUPSD_AUTH_ANON, type=None, satisfy=CUPSD_AUTH_SATISFY_ALL, num_names=0
d [14/Feb/2009:14:11:47 -0700] cupsdIsAuthorized: auth=CUPSD_AUTH_ALLOW...
d [14/Feb/2009:14:11:47 -0700] POST /printers/printer
d [14/Feb/2009:14:11:47 -0700] CONTENT_TYPE = application/ipp
d [14/Feb/2009:14:11:47 -0700] cupsdReadClient: 9 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=270, con->file=-1
d [14/Feb/2009:14:11:47 -0700] cupsdReadClient: 9, used=262, file=-1 state=6
d [14/Feb/2009:14:11:47 -0700] cupsdReadClient: 9 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=262, con->file=-1
d [14/Feb/2009:14:11:47 -0700] cupsdProcessIPPRequest(0x9f91d80[9]): operation_id = 0005
D [14/Feb/2009:14:11:47 -0700] Create-Job ipp://localhost/printers/printer
d [14/Feb/2009:14:11:47 -0700] create_job(0x9f91d80[9], ipp://localhost/printers/printer)
d [14/Feb/2009:14:11:47 -0700] add_job(0x9f91d80[9], 0x9f635c0(PRINTER), (nil)(none/none))
d [14/Feb/2009:14:11:47 -0700] cupsdFindPolicyOp(p=0x9f69cc0, op=5(Create-Job))
d [14/Feb/2009:14:11:47 -0700] cupsdFindPolicyOp: Found wildcard match...
d [14/Feb/2009:14:11:47 -0700] cupsdIsAuthorized: con->uri="/printers/printer", con->best=0x9f6af80((null))
d [14/Feb/2009:14:11:47 -0700] cupsdIsAuthorized: level=CUPSD_AUTH_ANON, type=None, satisfy=CUPSD_AUTH_SATISFY_ALL, num_names=0
d [14/Feb/2009:14:11:47 -0700] cupsdIsAuthorized: op=0(unknown-0000)
d [14/Feb/2009:14:11:47 -0700] cupsdIsAuthorized: auth=CUPSD_AUTH_ALLOW...
d [14/Feb/2009:14:11:47 -0700] check_quotas(0x9f91d80[9], 0x9f635c0[PRINTER])
D [14/Feb/2009:14:11:47 -0700] add_job: setting context of job to UNKNOWN SL
D [14/Feb/2009:14:11:47 -0700] add_job: requesting-user-name="ian"
D [14/Feb/2009:14:11:47 -0700] Adding default job-sheets values "none,none"...
I [14/Feb/2009:14:11:47 -0700] [Job 7] Adding start banner page "none".
d [14/Feb/2009:14:11:47 -0700] copy_banner(0x9f91d80[9], 0x9f95560[7], none)
d [14/Feb/2009:14:11:47 -0700] add_job_state_reasons(0x9f91d80[9], 7)
d [14/Feb/2009:14:11:47 -0700] cupsdAddEvent(event=job-created, dest=0x9f635c0(PRINTER), job=0x9f95560(7), text="Job created.", ...)
D [14/Feb/2009:14:11:47 -0700] Discarding unused job-created event...
d [14/Feb/2009:14:11:47 -0700] cupsdSaveJob(job=0x9f95560(7)): job->attrs=0x9f956d0
I [14/Feb/2009:14:11:47 -0700] [Job 7] Queued on "PRINTER" by "ian".
D [14/Feb/2009:14:11:47 -0700] cupsdProcessIPPRequest: 9 status_code=0 (successful-ok)
d [14/Feb/2009:14:11:47 -0700] cupsdAddSelect: fd=9, read_cb=0x5f67d0, write_cb=0x5f5500, data=0x9f91d80
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: Write on fd 9...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: Write on fd 9...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: Write on fd 9...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: Write on fd 9...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: Write on fd 9...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: Write on fd 9...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: Write on fd 9...
d [14/Feb/2009:14:11:47 -0700] cupsdWriteClient: 9 bytes < 0
d [14/Feb/2009:14:11:47 -0700] cupsdAddSelect: fd=9, read_cb=0x5f67d0, write_cb=(nil), data=0x9f91d80
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: Read on fd 9...
d [14/Feb/2009:14:11:47 -0700] cupsdReadClient: 9, used=0, file=-1 state=0
D [14/Feb/2009:14:11:47 -0700] cupsdReadClient: 9 POST /jobs/7 HTTP/1.1
d [14/Feb/2009:14:11:47 -0700] cupsdFindBest: uri = "/jobs/7"...
d [14/Feb/2009:14:11:47 -0700] cupsdFindBest: Location CUPS_INTERNAL_BROWSE_ACL Limit 0
d [14/Feb/2009:14:11:47 -0700] cupsdFindBest: Location /printers/printer Limit 7f
d [14/Feb/2009:14:11:47 -0700] cupsdFindBest: Location /admin/conf Limit 7f
d [14/Feb/2009:14:11:47 -0700] cupsdFindBest: Location /admin Limit 7f
d [14/Feb/2009:14:11:47 -0700] cupsdFindBest: Location / Limit 7f
d [14/Feb/2009:14:11:47 -0700] cupsdFindBest: best = /
d [14/Feb/2009:14:11:47 -0700] cupsdAuthorize: con->uri="/jobs/7", con->best=0x9f69b08(/)
d [14/Feb/2009:14:11:47 -0700] cupsdAuthorize: Authorization=""
D [14/Feb/2009:14:11:47 -0700] cupsdAuthorize: No authentication data provided.
d [14/Feb/2009:14:11:47 -0700] cupsdIsAuthorized: con->uri="/jobs/7", con->best=0x9f69b08(/)
d [14/Feb/2009:14:11:47 -0700] cupsdIsAuthorized: level=CUPSD_AUTH_ANON, type=None, satisfy=CUPSD_AUTH_SATISFY_ALL, num_names=0
d [14/Feb/2009:14:11:47 -0700] cupsdIsAuthorized: auth=CUPSD_AUTH_ALLOW...
d [14/Feb/2009:14:11:47 -0700] POST /jobs/7
d [14/Feb/2009:14:11:47 -0700] CONTENT_TYPE = application/ipp
d [14/Feb/2009:14:11:47 -0700] cupsdReadClient: 9 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=1742, con->file=-1
d [14/Feb/2009:14:11:47 -0700] cupsdReadClient: 9, used=210, file=-1 state=6
d [14/Feb/2009:14:11:47 -0700] cupsdReadClient: 9 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=1734, con->file=-1
d [14/Feb/2009:14:11:47 -0700] cupsdReadClient: 9 REQUEST /var/spool/cups/00000000=12
d [14/Feb/2009:14:11:47 -0700] cupsdReadClient: 9 writing 1524 bytes to 12
d [14/Feb/2009:14:11:47 -0700] cupsdReadClient: 9 Closing data file 12, size=1524.
d [14/Feb/2009:14:11:47 -0700] cupsdProcessIPPRequest(0x9f91d80[9]): operation_id = 0006
D [14/Feb/2009:14:11:47 -0700] Send-Document ipp://localhost/jobs/7
d [14/Feb/2009:14:11:47 -0700] send_document(0x9f91d80[9], ipp://localhost/jobs/7)
d [14/Feb/2009:14:11:47 -0700] validate_user(job=7, con=9, owner="ian", username=0xbf930ba2, userlen=1024)
d [14/Feb/2009:14:11:47 -0700] cupsdFindPolicyOp(p=0x9f69cc0, op=6(Send-Document))
d [14/Feb/2009:14:11:47 -0700] cupsdFindPolicyOp: Found exact match...
d [14/Feb/2009:14:11:47 -0700] cupsdIsAuthorized: con->uri="/jobs/7", con->best=0x9f69cf0((null))
d [14/Feb/2009:14:11:47 -0700] cupsdIsAuthorized: owner="ian"
d [14/Feb/2009:14:11:47 -0700] cupsdIsAuthorized: level=CUPSD_AUTH_USER, type=None, satisfy=CUPSD_AUTH_SATISFY_ALL, num_names=2
d [14/Feb/2009:14:11:47 -0700] cupsdIsAuthorized: op=6(Send-Document)
d [14/Feb/2009:14:11:47 -0700] cupsdIsAuthorized: auth=CUPSD_AUTH_ALLOW...
D [14/Feb/2009:14:11:47 -0700] cupsdIsAuthorized: requesting-user-name="ian"
d [14/Feb/2009:14:11:47 -0700] cupsdIsAuthorized: Checking user membership...
D [14/Feb/2009:14:11:47 -0700] send_document: auto-typing file...
D [14/Feb/2009:14:11:47 -0700] send_document: request file type is text/plain.
d [14/Feb/2009:14:11:47 -0700] add_file(con=0x9f91d80[9], job=7, filetype=text/plain, compression=0)
I [14/Feb/2009:14:11:47 -0700] File of type text/plain queued in job #7 by "ian".
I [14/Feb/2009:14:11:47 -0700] [Job 7] Adding end banner page "none".
d [14/Feb/2009:14:11:47 -0700] copy_banner((nil)[-1], 0x9f95560[7], none)
d [14/Feb/2009:14:11:47 -0700] cupsdSaveJob(job=0x9f95560(7)): job->attrs=0x9f956d0
d [14/Feb/2009:14:11:47 -0700] cupsdCheckJobs: 1 active jobs, sleeping=0, reload=0
d [14/Feb/2009:14:11:47 -0700] cupsdCheckJobs: Job 7: state_value=3, loaded=yes
d [14/Feb/2009:14:11:47 -0700] [Job 7] start_job: file = 0/1
d [14/Feb/2009:14:11:47 -0700] cupsdAddEvent(event=printer-state-changed, dest=0x9f635c0(PRINTER), job=(nil)(0), text="%s "%s" state changed.", ...)
D [14/Feb/2009:14:11:47 -0700] Discarding unused printer-state-changed event...
D [14/Feb/2009:14:11:47 -0700] [Job 7] job-sheets=none,none
D [14/Feb/2009:14:11:47 -0700] [Job 7] banner_page = 0
D [14/Feb/2009:14:11:47 -0700] [Job 7] argv[0]="PRINTER"
D [14/Feb/2009:14:11:47 -0700] [Job 7] argv[1]="7"
D [14/Feb/2009:14:11:47 -0700] [Job 7] argv[2]="ian"
D [14/Feb/2009:14:11:47 -0700] [Job 7] argv[3]="Test Page"
D [14/Feb/2009:14:11:47 -0700] [Job 7] argv[4]="1"
D [14/Feb/2009:14:11:47 -0700] [Job 7] argv[5]="job-uuid=urn:uuid:24a551c0-ce00-3d9b-5a07-0cbc9b45e5c7"
D [14/Feb/2009:14:11:47 -0700] [Job 7] argv[6]="/var/spool/cups/d00007-001"
D [14/Feb/2009:14:11:47 -0700] [Job 7] envp[0]="CUPS_CACHEDIR=/var/cache/cups"
D [14/Feb/2009:14:11:47 -0700] [Job 7] envp[1]="CUPS_DATADIR=/usr/share/cups"
D [14/Feb/2009:14:11:47 -0700] [Job 7] envp[2]="CUPS_DOCROOT=/usr/share/doc/cups-1.3.7"
D [14/Feb/2009:14:11:47 -0700] [Job 7] envp[3]="CUPS_FONTPATH=/usr/share/cups/fonts"
D [14/Feb/2009:14:11:47 -0700] [Job 7] envp[4]="CUPS_REQUESTROOT=/var/spool/cups"
D [14/Feb/2009:14:11:47 -0700] [Job 7] envp[5]="CUPS_SERVERBIN=/usr/lib/cups"
D [14/Feb/2009:14:11:47 -0700] [Job 7] envp[6]="CUPS_SERVERROOT=/etc/cups"
D [14/Feb/2009:14:11:47 -0700] [Job 7] envp[7]="CUPS_STATEDIR=/var/run/cups"
D [14/Feb/2009:14:11:47 -0700] [Job 7] envp[8]="PATH=/usr/lib/cups/filter:/usr/bin:/usr/sbin:/bin:/usr/bin"
D [14/Feb/2009:14:11:47 -0700] [Job 7] envp[9]="SERVER_ADMIN=root at haroldws08.barbereng.com"
D [14/Feb/2009:14:11:47 -0700] [Job 7] envp[10]="SOFTWARE=CUPS/1.3.7"
D [14/Feb/2009:14:11:47 -0700] [Job 7] envp[11]="TMPDIR=/var/spool/cups/tmp"
D [14/Feb/2009:14:11:47 -0700] [Job 7] envp[12]="USER=root"
D [14/Feb/2009:14:11:47 -0700] [Job 7] envp[13]="CUPS_SERVER=/var/run/cups/cups.sock"
D [14/Feb/2009:14:11:47 -0700] [Job 7] envp[14]="CUPS_ENCRYPTION=IfRequested"
D [14/Feb/2009:14:11:47 -0700] [Job 7] envp[15]="IPP_PORT=631"
D [14/Feb/2009:14:11:47 -0700] [Job 7] envp[16]="CHARSET=utf-8"
D [14/Feb/2009:14:11:47 -0700] [Job 7] envp[17]="LANG=en_US.UTF8"
D [14/Feb/2009:14:11:47 -0700] [Job 7] envp[18]="PPD=/etc/cups/ppd/PRINTER.ppd"
D [14/Feb/2009:14:11:47 -0700] [Job 7] envp[19]="RIP_MAX_CACHE=8m"
D [14/Feb/2009:14:11:47 -0700] [Job 7] envp[20]="CONTENT_TYPE=text/plain"
D [14/Feb/2009:14:11:47 -0700] [Job 7] envp[21]="DEVICE_URI=usb://Lexmark/E238"
D [14/Feb/2009:14:11:47 -0700] [Job 7] envp[22]="PRINTER=PRINTER"
D [14/Feb/2009:14:11:47 -0700] [Job 7] envp[23]="FINAL_CONTENT_TYPE=printer/PRINTER"
d [14/Feb/2009:14:11:47 -0700] [Job 7] start_job: status_pipes = [ 16 17 ]
d [14/Feb/2009:14:11:47 -0700] [Job 7] start_job: filter="/usr/lib/cups/filter/texttopaps"
d [14/Feb/2009:14:11:47 -0700] [Job 7] start_job: filterfds[0]=[ 18 19 ]
d [14/Feb/2009:14:11:47 -0700] cupsdStartProcess("/usr/lib/cups/filter/texttopaps", 0x9f9a520, 0xbf92d190, -1, 19, 17)
d [14/Feb/2009:14:11:47 -0700] [Job 7] start_job: Closing filter pipes for slot 1 [ -1 -1 ]...
I [14/Feb/2009:14:11:47 -0700] [Job 7] Started filter /usr/lib/cups/filter/texttopaps (PID 8364)
d [14/Feb/2009:14:11:47 -0700] [Job 7] start_job: filter="/usr/lib/cups/filter/pstops"
d [14/Feb/2009:14:11:47 -0700] [Job 7] start_job: filterfds[1]=[ 20 21 ]
d [14/Feb/2009:14:11:47 -0700] cupsdStartProcess("/usr/lib/cups/filter/pstops", 0x9f9a520, 0xbf92d190, 18, 21, 17)
d [14/Feb/2009:14:11:47 -0700] [Job 7] start_job: Closing filter pipes for slot 0 [ 18 19 ]...
I [14/Feb/2009:14:11:47 -0700] [Job 7] Started filter /usr/lib/cups/filter/pstops (PID 8365)
d [14/Feb/2009:14:11:47 -0700] [Job 7] start_job: print_pipes = [ 18 19 ]
d [14/Feb/2009:14:11:47 -0700] [Job 7] start_job: filter="/usr/lib/cups/filter/foomatic-rip"
d [14/Feb/2009:14:11:47 -0700] [Job 7] start_job: filterfds[0]=[ 18 19 ]
d [14/Feb/2009:14:11:47 -0700] cupsdStartProcess("/usr/lib/cups/filter/foomatic-rip", 0x9f9a520, 0xbf92d190, 20, 19, 17)
d [14/Feb/2009:14:11:47 -0700] [Job 7] start_job: Closing filter pipes for slot 1 [ 20 21 ]...
I [14/Feb/2009:14:11:47 -0700] [Job 7] Started filter /usr/lib/cups/filter/foomatic-rip (PID 8366)
d [14/Feb/2009:14:11:47 -0700] [Job 7] start_job: backend="/usr/lib/cups/backend/usb"
d [14/Feb/2009:14:11:47 -0700] [Job 7] start_job: filterfds[1] = [ -1 -1 ]
d [14/Feb/2009:14:11:47 -0700] cupsdStartProcess("/usr/lib/cups/backend/usb", 0x9f9a520, 0xbf92d190, 18, -1, 17)
I [14/Feb/2009:14:11:47 -0700] [Job 7] Started backend /usr/lib/cups/backend/usb (PID 8367)
d [14/Feb/2009:14:11:47 -0700] [Job 7] start_job: Closing print pipes [ 18 19 ]...
d [14/Feb/2009:14:11:47 -0700] [Job 7] start_job: Closing back pipes [ 12 13 ]...
d [14/Feb/2009:14:11:47 -0700] [Job 7] start_job: Closing side pipes [ 14 15 ]...
d [14/Feb/2009:14:11:47 -0700] [Job 7] start_job: Closing status output pipe 17...
d [14/Feb/2009:14:11:47 -0700] [Job 7] start_job: Closing filter pipes for slot 1 [ -1 -1 ]...
d [14/Feb/2009:14:11:47 -0700] cupsdAddSelect: fd=16, read_cb=0x624520, write_cb=(nil), data=0x9f95560
d [14/Feb/2009:14:11:47 -0700] cupsdAddEvent(event=job-state-changed, dest=0x9f635c0(PRINTER), job=0x9f95560(7), text="Job #%d started.", ...)
D [14/Feb/2009:14:11:47 -0700] Discarding unused job-state-changed event...
d [14/Feb/2009:14:11:47 -0700] add_job_state_reasons(0x9f91d80[9], 7)
D [14/Feb/2009:14:11:47 -0700] cupsdProcessIPPRequest: 9 status_code=0 (successful-ok)
d [14/Feb/2009:14:11:47 -0700] cupsdAddSelect: fd=9, read_cb=0x5f67d0, write_cb=0x5f5500, data=0x9f91d80
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: polling 6 fds for 1 seconds...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: epoll() returned 2...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: Read on fd 16...
d [14/Feb/2009:14:11:47 -0700] [Job 7] STATE: +connecting-to-device
d [14/Feb/2009:14:11:47 -0700] cupsdAddEvent(event=printer-state-changed, dest=0x9f635c0(PRINTER), job=(nil)(0), text="Printer "%s" state changed.", ...)
D [14/Feb/2009:14:11:47 -0700] Discarding unused printer-state-changed event...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: Write on fd 9...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: polling 6 fds for 1 seconds...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: Write on fd 9...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: polling 6 fds for 1 seconds...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: Write on fd 9...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: polling 6 fds for 1 seconds...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: Write on fd 9...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: polling 6 fds for 1 seconds...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: Write on fd 9...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: polling 6 fds for 1 seconds...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: Write on fd 9...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: polling 6 fds for 1 seconds...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: Write on fd 9...
d [14/Feb/2009:14:11:47 -0700] cupsdWriteClient: 9 bytes < 0
d [14/Feb/2009:14:11:47 -0700] cupsdAddSelect: fd=9, read_cb=0x5f67d0, write_cb=(nil), data=0x9f91d80
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: polling 6 fds for 1 seconds...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: epoll() returned 2...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:47 -0700] [Job 7] Page = 612x792; 18,14 to 594,778
D [14/Feb/2009:14:11:47 -0700] [Job 7] slow_collate=0, slow_duplex=0, slow_order=0
D [14/Feb/2009:14:11:47 -0700] [Job 7] Before copy_comments - %!PS-Adobe-3.0
D [14/Feb/2009:14:11:47 -0700] [Job 7] %!PS-Adobe-3.0
D [14/Feb/2009:14:11:47 -0700] [Job 7] %cupsRotation: 0
D [14/Feb/2009:14:11:47 -0700] [Job 7] %%Title: Test Page
D [14/Feb/2009:14:11:47 -0700] [Job 7] %%Creator: paps version 0.6.3 by Dov Grobgeld
D [14/Feb/2009:14:11:47 -0700] [Job 7] %%Pages: (atend)
D [14/Feb/2009:14:11:47 -0700] [Job 7] %%BoundingBox: 0 0 612 792
D [14/Feb/2009:14:11:47 -0700] [Job 7] %%For: ian
D [14/Feb/2009:14:11:47 -0700] [Job 7] %%BeginProlog
D [14/Feb/2009:14:11:47 -0700] [Job 7] %%Orientation: Portrait
D [14/Feb/2009:14:11:47 -0700] [Job 7] Before copy_prolog - /papsdict 1 dict def
D [14/Feb/2009:14:11:47 -0700] [Job 7] Before copy_setup - %%EndPrologue
D [14/Feb/2009:14:11:47 -0700] [Job 7] Before page loop - %%Page: 1 1
D [14/Feb/2009:14:11:47 -0700] [Job 7] Copying page 1...
D [14/Feb/2009:14:11:47 -0700] [Job 7] pagew = 576.0, pagel = 763.2
D [14/Feb/2009:14:11:47 -0700] [Job 7] bboxx = 0, bboxy = 0, bboxw = 612, bboxl = 792
D [14/Feb/2009:14:11:47 -0700] [Job 7] PageLeft = 18.0, PageRight = 594.0
D [14/Feb/2009:14:11:47 -0700] [Job 7] PageTop = 777.6, PageBottom = 14.4
D [14/Feb/2009:14:11:47 -0700] [Job 7] PageWidth = 612.0, PageLength = 792.0
D [14/Feb/2009:14:11:47 -0700] [Job 7] Copying page 2...
D [14/Feb/2009:14:11:47 -0700] [Job 7] pagew = 576.0, pagel = 763.2
D [14/Feb/2009:14:11:47 -0700] [Job 7] bboxx = 0, bboxy = 0, bboxw = 612, bboxl = 792
D [14/Feb/2009:14:11:47 -0700] [Job 7] PageLeft = 18.0, PageRight = 594.0
D [14/Feb/2009:14:11:47 -0700] [Job 7] PageTop = 777.6, PageBottom = 14.4
D [14/Feb/2009:14:11:47 -0700] [Job 7] PageWidth = 612.0, PageLength = 792.0
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: Read on fd 9...
d [14/Feb/2009:14:11:47 -0700] cupsdReadClient: 9, used=0, file=-1 state=0
d [14/Feb/2009:14:11:47 -0700] cupsdReadClient: httpGets returned EOF...
D [14/Feb/2009:14:11:47 -0700] cupsdCloseClient: 9
d [14/Feb/2009:14:11:47 -0700] cupsdRemoveSelect: fd=9
d [14/Feb/2009:14:11:47 -0700] process_children()
D [14/Feb/2009:14:11:47 -0700] PID 8364 (/usr/lib/cups/filter/texttopaps) exited with no errors.
D [14/Feb/2009:14:11:47 -0700] PID 8365 (/usr/lib/cups/filter/pstops) exited with no errors.
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:47 -0700] [Job 7] Copying page 3...
D [14/Feb/2009:14:11:47 -0700] [Job 7] pagew = 576.0, pagel = 763.2
D [14/Feb/2009:14:11:47 -0700] [Job 7] bboxx = 0, bboxy = 0, bboxw = 612, bboxl = 792
D [14/Feb/2009:14:11:47 -0700] [Job 7] PageLeft = 18.0, PageRight = 594.0
D [14/Feb/2009:14:11:47 -0700] [Job 7] PageTop = 777.6, PageBottom = 14.4
D [14/Feb/2009:14:11:47 -0700] [Job 7] PageWidth = 612.0, PageLength = 792.0
D [14/Feb/2009:14:11:47 -0700] [Job 7] Wrote 3 pages...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:47 -0700] [Job 7] Printer using device file "/dev/usb/lp0"...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: Read on fd 16...
d [14/Feb/2009:14:11:47 -0700] [Job 7] STATE: -connecting-to-device
d [14/Feb/2009:14:11:47 -0700] cupsdAddEvent(event=printer-state-changed, dest=0x9f635c0(PRINTER), job=(nil)(0), text="Printer "%s" state changed.", ...)
D [14/Feb/2009:14:11:47 -0700] Discarding unused printer-state-changed event...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:47 -0700] [Job 7] backendRunLoop(print_fd=0, device_fd=5, use_bc=1, side_cb=0x356bf0)
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:47 -0700] [Job 7] foomatic-rip version $Revision: 3.43.2.15 $ running...
D [14/Feb/2009:14:11:47 -0700] [Job 7] Parsing PPD file ...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:47 -0700] [Job 7] *cupsFilter: "application/vnd.cups-postscript 0 foomatic-rip"
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:47 -0700] [Job 7] Added option ColorSpace
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:47 -0700] [Job 7] Added option Resolution
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:47 -0700] [Job 7] Added option PageSize
D [14/Feb/2009:14:11:47 -0700] [Job 7] Added option PageRegion
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:47 -0700] [Job 7] Added option Model
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:47 -0700] [Job 7] Added option PrintoutMode
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:47 -0700] [Job 7] Added option InputSlot
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:47 -0700] [Job 7] Added option ImageableArea
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:47 -0700] [Job 7] Added option PaperDimension
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:47 -0700] [Job 7] Added option Duplex
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:47 -0700] [Job 7] Added option Quality
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:47 -0700] [Job 7] Added option Font
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:47 -0700] [Job 7]
D [14/Feb/2009:14:11:47 -0700] [Job 7] Parameter Summary
D [14/Feb/2009:14:11:47 -0700] [Job 7] -----------------
D [14/Feb/2009:14:11:47 -0700] [Job 7]
D [14/Feb/2009:14:11:47 -0700] [Job 7] Spooler: cups
D [14/Feb/2009:14:11:47 -0700] [Job 7] Printer: PRINTER
D [14/Feb/2009:14:11:47 -0700] [Job 7] PPD file: /etc/cups/ppd/PRINTER.ppd
D [14/Feb/2009:14:11:47 -0700] [Job 7] Printer model: Generic PCL 5e Printer Foomatic/hpijs (recommended)
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:47 -0700] [Job 7] Job title: Test Page
D [14/Feb/2009:14:11:47 -0700] [Job 7] File(s) to be printed:
D [14/Feb/2009:14:11:47 -0700] [Job 7] <STDIN>
D [14/Feb/2009:14:11:47 -0700] [Job 7]
D [14/Feb/2009:14:11:47 -0700] [Job 7] GhostScript extra search path ('GS_LIB'): /usr/share/cups/fonts
D [14/Feb/2009:14:11:47 -0700] [Job 7] Pondering option 'job-uuid=urn:uuid:24a551c0-ce00-3d9b-5a07-0cbc9b45e5c7'
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:47 -0700] [Job 7] Unknown option job-uuid=urn:uuid:24a551c0-ce00-3d9b-5a07-0cbc9b45e5c7.
D [14/Feb/2009:14:11:47 -0700] [Job 7]
D [14/Feb/2009:14:11:47 -0700] [Job 7] ================================================
D [14/Feb/2009:14:11:47 -0700] [Job 7]
D [14/Feb/2009:14:11:47 -0700] [Job 7] File: <STDIN>
D [14/Feb/2009:14:11:47 -0700] [Job 7]
D [14/Feb/2009:14:11:47 -0700] [Job 7] ================================================
D [14/Feb/2009:14:11:47 -0700] [Job 7]
D [14/Feb/2009:14:11:47 -0700] [Job 7] Reading PostScript input ...
D [14/Feb/2009:14:11:47 -0700] [Job 7] --> This document is DSC-conforming!
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:47 -0700] [Job 7]
D [14/Feb/2009:14:11:47 -0700] [Job 7] -----------
D [14/Feb/2009:14:11:47 -0700] [Job 7] Found: %%BeginProlog
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:47 -0700] [Job 7]
D [14/Feb/2009:14:11:47 -0700] [Job 7] -----------
D [14/Feb/2009:14:11:47 -0700] [Job 7] Found: %%BeginProlog
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:47 -0700] [Job 7] Found: %%EndProlog
D [14/Feb/2009:14:11:47 -0700] [Job 7] Found: %%EndProlog
D [14/Feb/2009:14:11:47 -0700] [Job 7]
D [14/Feb/2009:14:11:47 -0700] [Job 7] -----------
D [14/Feb/2009:14:11:47 -0700] [Job 7] Found: %%BeginSetup
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:47 -0700] [Job 7] Found: %%BeginFeature: *PrintoutMode Normal
D [14/Feb/2009:14:11:47 -0700] [Job 7] Option: PrintoutMode=Normal --> Setting option
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:47 -0700] [Job 7] Found: %% FoomaticRIPOptionSetting: PrintoutMode=Normal
D [14/Feb/2009:14:11:47 -0700] [Job 7] Option: PrintoutMode=Normal --> Setting option
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:47 -0700] [Job 7] Found: %%BeginFeature: *InputSlot Default
D [14/Feb/2009:14:11:47 -0700] [Job 7] Option: InputSlot=Default --> Setting option
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:47 -0700] [Job 7] Found: %% FoomaticRIPOptionSetting: InputSlot=Default
D [14/Feb/2009:14:11:47 -0700] [Job 7] Option: InputSlot=Default --> Setting option
D [14/Feb/2009:14:11:47 -0700] [Job 7] Found: %%BeginFeature: *Quality FromPrintoutMode
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:47 -0700] [Job 7] Option: Quality=FromPrintoutMode --> Setting option
D [14/Feb/2009:14:11:47 -0700] [Job 7] Found: %% FoomaticRIPOptionSetting: Quality=@PrintoutMode
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:47 -0700] [Job 7] Option: Quality=FromPrintoutMode --> Setting option
D [14/Feb/2009:14:11:47 -0700] [Job 7] Found: %%BeginFeature: *PageRegion Letter
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:47 -0700] [Job 7] Option: PageRegion=Letter --> Option will be set by PostScript interpreter
D [14/Feb/2009:14:11:47 -0700] [Job 7] Found: %% FoomaticRIPOptionSetting: PageSize=Letter
D [14/Feb/2009:14:11:47 -0700] [Job 7] Option: PageSize=Letter --> Setting option
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:47 -0700] [Job 7] Found: %%BeginFeature: *Duplex None
D [14/Feb/2009:14:11:47 -0700] [Job 7] Option: Duplex=None --> Setting option
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:47 -0700] [Job 7] Found: %% FoomaticRIPOptionSetting: Duplex=None
D [14/Feb/2009:14:11:47 -0700] [Job 7] Option: Duplex=None --> Setting option
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:47 -0700] [Job 7] Found: %%EndSetup
D [14/Feb/2009:14:11:47 -0700] [Job 7] Inserting PostScript code for CUPS' page accounting
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:47 -0700] [Job 7]
D [14/Feb/2009:14:11:47 -0700] [Job 7] -----------
D [14/Feb/2009:14:11:47 -0700] [Job 7] New page:  1 1
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:47 -0700] [Job 7] Inserting option code into "PageSetup" section.
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:47 -0700] [Job 7]
D [14/Feb/2009:14:11:47 -0700] [Job 7] Found: %%BeginPageSetup
D [14/Feb/2009:14:11:47 -0700] [Job 7] Found: %%EndPageSetup
D [14/Feb/2009:14:11:47 -0700] [Job 7] End of page header
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:47 -0700] [Job 7] New page found but previous not printed, print it now.
D [14/Feb/2009:14:11:47 -0700] [Job 7] Found:
D [14/Feb/2009:14:11:47 -0700] [Job 7] %%Page: 2 2
D [14/Feb/2009:14:11:47 -0700] [Job 7] --> Output goes directly to the renderer now.
D [14/Feb/2009:14:11:47 -0700] [Job 7]
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:47 -0700] [Job 7]
D [14/Feb/2009:14:11:47 -0700] [Job 7] Starting renderer
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:47 -0700] [Job 7]
D [14/Feb/2009:14:11:47 -0700] [Job 7] -----------
D [14/Feb/2009:14:11:47 -0700] [Job 7] New page:  2 2
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:47 -0700] [Job 7] Inserting option code into "PageSetup" section.
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:47 -0700] [Job 7] Found:
D [14/Feb/2009:14:11:47 -0700] [Job 7] %%Page: 2 2
D [14/Feb/2009:14:11:47 -0700] [Job 7] --> Output goes to the FIFO buffer now.
D [14/Feb/2009:14:11:47 -0700] [Job 7]
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:47 -0700] [Job 7]
D [14/Feb/2009:14:11:47 -0700] [Job 7] Found: %%BeginPageSetup
D [14/Feb/2009:14:11:47 -0700] [Job 7] Found: %%EndPageSetup
D [14/Feb/2009:14:11:47 -0700] [Job 7] End of page header
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:47 -0700] [Job 7] New page found but previous not printed, print it now.
D [14/Feb/2009:14:11:47 -0700] [Job 7] Found:
D [14/Feb/2009:14:11:47 -0700] [Job 7] %%Page: 3 3
D [14/Feb/2009:14:11:47 -0700] [Job 7] --> Output goes directly to the renderer now.
D [14/Feb/2009:14:11:47 -0700] [Job 7]
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:47 -0700] [Job 7]
D [14/Feb/2009:14:11:47 -0700] [Job 7] -----------
D [14/Feb/2009:14:11:47 -0700] [Job 7] New page:  3 3
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:47 -0700] [Job 7] Inserting option code into "PageSetup" section.
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:47 -0700] [Job 7] Found:
D [14/Feb/2009:14:11:47 -0700] [Job 7] %%Page: 3 3
D [14/Feb/2009:14:11:47 -0700] [Job 7] --> Output goes to the FIFO buffer now.
D [14/Feb/2009:14:11:47 -0700] [Job 7]
D [14/Feb/2009:14:11:47 -0700] [Job 7]
D [14/Feb/2009:14:11:47 -0700] [Job 7] Found: %%BeginPageSetup
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:47 -0700] [Job 7] Found: %%EndPageSetup
D [14/Feb/2009:14:11:47 -0700] [Job 7] End of page header
D [14/Feb/2009:14:11:47 -0700] [Job 7] Flushing FIFO.
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:47 -0700] [Job 7]
D [14/Feb/2009:14:11:47 -0700] [Job 7] Closing renderer
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:47 -0700] [Job 7] JCL: <job data>
D [14/Feb/2009:14:11:47 -0700] [Job 7]
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:47 -0700] [Job 7] renderer PID kid4=8370
D [14/Feb/2009:14:11:47 -0700] [Job 7] renderer command: gs -q -dBATCH -dPARANOIDSAFER -dQUIET -dNOPAUSE -sDEVICE=ijs -sIjsServer=hpijs -sDeviceManufacturer="HEWLETT-PACKARD" -sDeviceModel="HP LaserJet" -dDEVICEWIDTHPOINTS=612 -dDEVICEHEIGHTPOINTS=792 -dDuplex=false -r300 -sIjsParams=Quality:Quality=0,Quality:ColorMode=0,Quality:MediaType=0,Quality:Pe
nSet=0,PS:MediaPosition=7 -dIjsUseOutputFD -sOutputFile=- -
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:47 -0700] [Job 7] foomatic-gswrapper: gs '-dBATCH' '-dPARANOIDSAFER' '-dQUIET' '-dNOPAUSE' '-sDEVICE=ijs' '-sIjsServer=hpijs' '-sDeviceManufacturer=HEWLETT-PACKARD' '-sDeviceModel=HP LaserJet' '-dDEVICEWIDTHPOINTS=612' '-dDEVICEHEIGHTPOINTS=792' '-dDuplex=false' '-r300' '-sIjsParams=Quality:Quality=0,Quality:ColorMode=0,Quality:MediaType=0,Quality:P
enSet=0,PS:MediaPosition=7' '-dIjsUseOutputFD' '-sOutputFile=/dev/fd/3' '/dev/fd/0' 3>&1 1>&2
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: Read on fd 16...
d [14/Feb/2009:14:11:47 -0700] [Job 7] PAGE: 1 1
d [14/Feb/2009:14:11:47 -0700] cupsdAddEvent(event=job-progress, dest=0x9f635c0(PRINTER), job=0x9f95560(7), text="Printed %d page(s).", ...)
D [14/Feb/2009:14:11:47 -0700] Discarding unused job-progress event...
d [14/Feb/2009:14:11:47 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:48 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:48 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:48 -0700] [Job 7] Read 61 bytes of print data...
d [14/Feb/2009:14:11:48 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:48 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:48 -0700] cupsdDoSelect: Read on fd 16...
d [14/Feb/2009:14:11:48 -0700] [Job 7] STATE: -media-empty-error
d [14/Feb/2009:14:11:48 -0700] cupsdAddEvent(event=printer-state-changed, dest=0x9f635c0(PRINTER), job=(nil)(0), text="Printer "%s" state changed.", ...)
D [14/Feb/2009:14:11:48 -0700] Discarding unused printer-state-changed event...
d [14/Feb/2009:14:11:48 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:48 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:48 -0700] cupsdDoSelect: Read on fd 16...
d [14/Feb/2009:14:11:48 -0700] [Job 7] STATE: -offline-error
d [14/Feb/2009:14:11:48 -0700] cupsdAddEvent(event=printer-state-changed, dest=0x9f635c0(PRINTER), job=(nil)(0), text="Printer "%s" state changed.", ...)
D [14/Feb/2009:14:11:48 -0700] Discarding unused printer-state-changed event...
d [14/Feb/2009:14:11:48 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:48 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:48 -0700] cupsdDoSelect: Read on fd 16...
I [14/Feb/2009:14:11:48 -0700] [Job 7] Printer is now on-line.
d [14/Feb/2009:14:11:48 -0700] cupsdAddEvent(event=printer-state-changed, dest=0x9f635c0(PRINTER), job=(nil)(0), text="Printer "%s" state changed.", ...)
D [14/Feb/2009:14:11:48 -0700] Discarding unused printer-state-changed event...
d [14/Feb/2009:14:11:48 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:48 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:48 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:48 -0700] [Job 7] Wrote 61 bytes of print data...
d [14/Feb/2009:14:11:48 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:48 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:48 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:48 -0700] [Job 7] Read 66 bytes of print data...
d [14/Feb/2009:14:11:48 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:48 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:48 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:48 -0700] [Job 7] Wrote 66 bytes of print data...
d [14/Feb/2009:14:11:48 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:48 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:48 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:48 -0700] [Job 7] Read 8192 bytes of print data...
d [14/Feb/2009:14:11:48 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:48 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:48 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:48 -0700] [Job 7] Wrote 8192 bytes of print data...
D [14/Feb/2009:14:11:48 -0700] [Job 7] Read 8192 bytes of print data...
d [14/Feb/2009:14:11:48 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:48 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:48 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:48 -0700] [Job 7] Wrote 8192 bytes of print data...
D [14/Feb/2009:14:11:48 -0700] [Job 7] Read 8192 bytes of print data...
d [14/Feb/2009:14:11:48 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:48 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:48 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:48 -0700] [Job 7] Wrote 8192 bytes of print data...
D [14/Feb/2009:14:11:48 -0700] [Job 7] Read 8192 bytes of print data...
d [14/Feb/2009:14:11:48 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:48 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:48 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:48 -0700] [Job 7] Wrote 8192 bytes of print data...
D [14/Feb/2009:14:11:48 -0700] [Job 7] Read 8192 bytes of print data...
d [14/Feb/2009:14:11:48 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:48 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:48 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:48 -0700] [Job 7] Wrote 8192 bytes of print data...
D [14/Feb/2009:14:11:48 -0700] [Job 7] Read 8192 bytes of print data...
d [14/Feb/2009:14:11:48 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:48 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:48 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:48 -0700] [Job 7] Wrote 8192 bytes of print data...
D [14/Feb/2009:14:11:48 -0700] [Job 7] Read 8192 bytes of print data...
d [14/Feb/2009:14:11:48 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:48 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:48 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:48 -0700] [Job 7] Wrote 8192 bytes of print data...
D [14/Feb/2009:14:11:48 -0700] [Job 7] Read 8192 bytes of print data...
d [14/Feb/2009:14:11:48 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:48 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:48 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:48 -0700] [Job 7] Wrote 8192 bytes of print data...
D [14/Feb/2009:14:11:48 -0700] [Job 7] Read 8192 bytes of print data...
d [14/Feb/2009:14:11:48 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:48 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:48 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:48 -0700] [Job 7] Wrote 8192 bytes of print data...
D [14/Feb/2009:14:11:48 -0700] [Job 7] Read 8192 bytes of print data...
d [14/Feb/2009:14:11:48 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:48 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:48 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:48 -0700] [Job 7] Wrote 8192 bytes of print data...
D [14/Feb/2009:14:11:48 -0700] [Job 7] Read 8192 bytes of print data...
d [14/Feb/2009:14:11:48 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:48 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:48 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:48 -0700] [Job 7] Wrote 8192 bytes of print data...
D [14/Feb/2009:14:11:48 -0700] [Job 7] Read 8192 bytes of print data...
d [14/Feb/2009:14:11:48 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:48 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:48 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:48 -0700] [Job 7] Wrote 8192 bytes of print data...
D [14/Feb/2009:14:11:48 -0700] [Job 7] Read 8192 bytes of print data...
d [14/Feb/2009:14:11:48 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:48 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:48 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:48 -0700] [Job 7] Wrote 8192 bytes of print data...
D [14/Feb/2009:14:11:48 -0700] [Job 7] Read 8192 bytes of print data...
d [14/Feb/2009:14:11:48 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:48 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:48 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:48 -0700] [Job 7] Wrote 8192 bytes of print data...
D [14/Feb/2009:14:11:48 -0700] [Job 7] Read 8192 bytes of print data...
d [14/Feb/2009:14:11:48 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:48 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:48 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:48 -0700] [Job 7] Wrote 8192 bytes of print data...
D [14/Feb/2009:14:11:48 -0700] [Job 7] Read 8192 bytes of print data...
d [14/Feb/2009:14:11:48 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:48 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:48 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:48 -0700] [Job 7] Wrote 8192 bytes of print data...
D [14/Feb/2009:14:11:48 -0700] [Job 7] Read 8192 bytes of print data...
d [14/Feb/2009:14:11:48 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:48 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:48 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:48 -0700] [Job 7] Wrote 8192 bytes of print data...
D [14/Feb/2009:14:11:48 -0700] [Job 7] Read 8192 bytes of print data...
d [14/Feb/2009:14:11:48 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:48 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:48 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:48 -0700] [Job 7] Wrote 8192 bytes of print data...
D [14/Feb/2009:14:11:48 -0700] [Job 7] Read 8192 bytes of print data...
d [14/Feb/2009:14:11:48 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:48 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:48 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:48 -0700] [Job 7] Wrote 8192 bytes of print data...
D [14/Feb/2009:14:11:48 -0700] [Job 7] Read 8192 bytes of print data...
d [14/Feb/2009:14:11:48 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:49 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:49 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:49 -0700] [Job 7] Wrote 8192 bytes of print data...
D [14/Feb/2009:14:11:49 -0700] [Job 7] Read 8192 bytes of print data...
d [14/Feb/2009:14:11:49 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:49 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:49 -0700] cupsdDoSelect: Read on fd 16...
d [14/Feb/2009:14:11:49 -0700] [Job 7] PAGE: 2 1
d [14/Feb/2009:14:11:49 -0700] cupsdAddEvent(event=job-progress, dest=0x9f635c0(PRINTER), job=0x9f95560(7), text="Printed %d page(s).", ...)
D [14/Feb/2009:14:11:49 -0700] Discarding unused job-progress event...
d [14/Feb/2009:14:11:49 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:49 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:49 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:49 -0700] [Job 7] Wrote 8192 bytes of print data...
D [14/Feb/2009:14:11:49 -0700] [Job 7] Read 8192 bytes of print data...
d [14/Feb/2009:14:11:49 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:49 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:49 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:49 -0700] [Job 7] Wrote 8192 bytes of print data...
D [14/Feb/2009:14:11:49 -0700] [Job 7] Read 8192 bytes of print data...
d [14/Feb/2009:14:11:49 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:49 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:49 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:49 -0700] [Job 7] Wrote 8192 bytes of print data...
D [14/Feb/2009:14:11:49 -0700] [Job 7] Read 8192 bytes of print data...
d [14/Feb/2009:14:11:49 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:49 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:49 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:49 -0700] [Job 7] Wrote 8192 bytes of print data...
D [14/Feb/2009:14:11:49 -0700] [Job 7] Read 8192 bytes of print data...
d [14/Feb/2009:14:11:49 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:49 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:49 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:49 -0700] [Job 7] Wrote 8192 bytes of print data...
D [14/Feb/2009:14:11:49 -0700] [Job 7] Read 8192 bytes of print data...
d [14/Feb/2009:14:11:49 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:49 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:49 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:49 -0700] [Job 7] Wrote 8192 bytes of print data...
D [14/Feb/2009:14:11:49 -0700] [Job 7] Read 8192 bytes of print data...
d [14/Feb/2009:14:11:49 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:49 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:49 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:49 -0700] [Job 7] Wrote 8192 bytes of print data...
D [14/Feb/2009:14:11:49 -0700] [Job 7] Read 8192 bytes of print data...
d [14/Feb/2009:14:11:49 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:49 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:49 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:49 -0700] [Job 7] Wrote 8192 bytes of print data...
D [14/Feb/2009:14:11:49 -0700] [Job 7] Read 8192 bytes of print data...
d [14/Feb/2009:14:11:49 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:49 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:49 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:49 -0700] [Job 7] Wrote 8192 bytes of print data...
D [14/Feb/2009:14:11:49 -0700] [Job 7] Read 8192 bytes of print data...
d [14/Feb/2009:14:11:49 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:49 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:49 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:49 -0700] [Job 7] Wrote 8192 bytes of print data...
D [14/Feb/2009:14:11:49 -0700] [Job 7] Read 8192 bytes of print data...
d [14/Feb/2009:14:11:49 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:49 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:49 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:49 -0700] [Job 7] Wrote 8192 bytes of print data...
D [14/Feb/2009:14:11:49 -0700] [Job 7] Read 8192 bytes of print data...
d [14/Feb/2009:14:11:49 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:49 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:49 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:49 -0700] [Job 7] Wrote 8192 bytes of print data...
D [14/Feb/2009:14:11:49 -0700] [Job 7] Read 8192 bytes of print data...
d [14/Feb/2009:14:11:49 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:49 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:49 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:49 -0700] [Job 7] Wrote 8192 bytes of print data...
D [14/Feb/2009:14:11:49 -0700] [Job 7] Read 8192 bytes of print data...
d [14/Feb/2009:14:11:49 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:49 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:49 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:49 -0700] [Job 7] Wrote 8192 bytes of print data...
D [14/Feb/2009:14:11:49 -0700] [Job 7] Read 8192 bytes of print data...
d [14/Feb/2009:14:11:49 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:49 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:49 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:49 -0700] [Job 7] Wrote 8192 bytes of print data...
D [14/Feb/2009:14:11:49 -0700] [Job 7] Read 8192 bytes of print data...
d [14/Feb/2009:14:11:49 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:49 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:49 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:49 -0700] [Job 7] Wrote 8192 bytes of print data...
D [14/Feb/2009:14:11:49 -0700] [Job 7] Read 8192 bytes of print data...
d [14/Feb/2009:14:11:49 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:49 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:49 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:49 -0700] [Job 7] Wrote 8192 bytes of print data...
D [14/Feb/2009:14:11:49 -0700] [Job 7] Read 8192 bytes of print data...
d [14/Feb/2009:14:11:49 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:49 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:49 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:49 -0700] [Job 7] Wrote 8192 bytes of print data...
D [14/Feb/2009:14:11:49 -0700] [Job 7] Read 8192 bytes of print data...
d [14/Feb/2009:14:11:49 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:49 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:49 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:49 -0700] [Job 7] Wrote 8192 bytes of print data...
D [14/Feb/2009:14:11:49 -0700] [Job 7] Read 8192 bytes of print data...
d [14/Feb/2009:14:11:49 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:49 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:49 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:49 -0700] [Job 7] Wrote 8192 bytes of print data...
D [14/Feb/2009:14:11:49 -0700] [Job 7] Read 8192 bytes of print data...
d [14/Feb/2009:14:11:49 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:50 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:50 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:50 -0700] [Job 7] Wrote 8192 bytes of print data...
D [14/Feb/2009:14:11:50 -0700] [Job 7] Read 8192 bytes of print data...
d [14/Feb/2009:14:11:50 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:50 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:50 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:50 -0700] [Job 7] Wrote 8192 bytes of print data...
D [14/Feb/2009:14:11:50 -0700] [Job 7] Read 8192 bytes of print data...
d [14/Feb/2009:14:11:50 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:50 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:50 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:50 -0700] [Job 7] Wrote 8192 bytes of print data...
D [14/Feb/2009:14:11:50 -0700] [Job 7] Read 8192 bytes of print data...
d [14/Feb/2009:14:11:50 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:50 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:50 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:50 -0700] [Job 7] Wrote 8192 bytes of print data...
D [14/Feb/2009:14:11:50 -0700] [Job 7] Read 8192 bytes of print data...
d [14/Feb/2009:14:11:50 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:50 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:50 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:50 -0700] [Job 7] Wrote 8192 bytes of print data...
D [14/Feb/2009:14:11:50 -0700] [Job 7] Read 8192 bytes of print data...
d [14/Feb/2009:14:11:50 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:50 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:50 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:50 -0700] [Job 7] Wrote 8192 bytes of print data...
D [14/Feb/2009:14:11:50 -0700] [Job 7] Read 8192 bytes of print data...
d [14/Feb/2009:14:11:50 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:50 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:50 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:50 -0700] [Job 7] Wrote 8192 bytes of print data...
D [14/Feb/2009:14:11:50 -0700] [Job 7] Read 8192 bytes of print data...
d [14/Feb/2009:14:11:50 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:50 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:50 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:50 -0700] [Job 7] Wrote 8192 bytes of print data...
D [14/Feb/2009:14:11:50 -0700] [Job 7] Read 8192 bytes of print data...
d [14/Feb/2009:14:11:50 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:50 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:50 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:50 -0700] [Job 7] Wrote 8192 bytes of print data...
D [14/Feb/2009:14:11:50 -0700] [Job 7] Read 8192 bytes of print data...
d [14/Feb/2009:14:11:50 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:50 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:50 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:50 -0700] [Job 7] Wrote 8192 bytes of print data...
D [14/Feb/2009:14:11:50 -0700] [Job 7] Read 8192 bytes of print data...
d [14/Feb/2009:14:11:50 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:50 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:50 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:50 -0700] [Job 7] Wrote 8192 bytes of print data...
D [14/Feb/2009:14:11:50 -0700] [Job 7] Read 8192 bytes of print data...
d [14/Feb/2009:14:11:50 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:50 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:50 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:50 -0700] [Job 7] Wrote 8192 bytes of print data...
D [14/Feb/2009:14:11:50 -0700] [Job 7] Read 8192 bytes of print data...
d [14/Feb/2009:14:11:50 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:50 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:50 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:50 -0700] [Job 7] Wrote 8192 bytes of print data...
D [14/Feb/2009:14:11:50 -0700] [Job 7] Read 8192 bytes of print data...
d [14/Feb/2009:14:11:50 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:50 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:50 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:50 -0700] [Job 7] Wrote 8192 bytes of print data...
D [14/Feb/2009:14:11:50 -0700] [Job 7] Read 8192 bytes of print data...
d [14/Feb/2009:14:11:50 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:50 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:50 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:50 -0700] [Job 7] Wrote 8192 bytes of print data...
D [14/Feb/2009:14:11:50 -0700] [Job 7] Read 8192 bytes of print data...
d [14/Feb/2009:14:11:50 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:50 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:50 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:50 -0700] [Job 7] Wrote 8192 bytes of print data...
D [14/Feb/2009:14:11:50 -0700] [Job 7] Read 8192 bytes of print data...
d [14/Feb/2009:14:11:50 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:50 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:50 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:50 -0700] [Job 7] Wrote 8192 bytes of print data...
D [14/Feb/2009:14:11:50 -0700] [Job 7] Read 8192 bytes of print data...
d [14/Feb/2009:14:11:50 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:50 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:50 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:50 -0700] [Job 7] Wrote 8192 bytes of print data...
D [14/Feb/2009:14:11:50 -0700] [Job 7] Read 8192 bytes of print data...
d [14/Feb/2009:14:11:50 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:50 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:50 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:50 -0700] [Job 7] Wrote 8192 bytes of print data...
D [14/Feb/2009:14:11:50 -0700] [Job 7] Read 8192 bytes of print data...
d [14/Feb/2009:14:11:50 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:50 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:50 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:50 -0700] [Job 7] Wrote 8192 bytes of print data...
D [14/Feb/2009:14:11:50 -0700] [Job 7] Read 8192 bytes of print data...
d [14/Feb/2009:14:11:50 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:50 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:50 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:50 -0700] [Job 7] Wrote 8192 bytes of print data...
D [14/Feb/2009:14:11:50 -0700] [Job 7] Read 8192 bytes of print data...
d [14/Feb/2009:14:11:50 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:50 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:50 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:50 -0700] [Job 7] Wrote 8192 bytes of print data...
D [14/Feb/2009:14:11:50 -0700] [Job 7] Read 8192 bytes of print data...
d [14/Feb/2009:14:11:50 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:50 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:50 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:50 -0700] [Job 7] Wrote 8192 bytes of print data...
D [14/Feb/2009:14:11:50 -0700] [Job 7] Read 8192 bytes of print data...
d [14/Feb/2009:14:11:50 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:50 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:50 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:50 -0700] [Job 7] Wrote 8192 bytes of print data...
D [14/Feb/2009:14:11:50 -0700] [Job 7] Read 8192 bytes of print data...
d [14/Feb/2009:14:11:50 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:50 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:50 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:50 -0700] [Job 7] Wrote 8192 bytes of print data...
D [14/Feb/2009:14:11:50 -0700] [Job 7] Read 8192 bytes of print data...
d [14/Feb/2009:14:11:50 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:50 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:50 -0700] cupsdDoSelect: Read on fd 16...
d [14/Feb/2009:14:11:50 -0700] [Job 7] PAGE: 3 1
d [14/Feb/2009:14:11:50 -0700] cupsdAddEvent(event=job-progress, dest=0x9f635c0(PRINTER), job=0x9f95560(7), text="Printed %d page(s).", ...)
D [14/Feb/2009:14:11:50 -0700] Discarding unused job-progress event...
d [14/Feb/2009:14:11:50 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:50 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:50 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:50 -0700] [Job 7] Wrote 8192 bytes of print data...
D [14/Feb/2009:14:11:50 -0700] [Job 7] Read 7841 bytes of print data...
d [14/Feb/2009:14:11:50 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:50 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:50 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:50 -0700] [Job 7] Wrote 7841 bytes of print data...
d [14/Feb/2009:14:11:50 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:51 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:51 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:51 -0700] [Job 7] Read 260 bytes of print data...
d [14/Feb/2009:14:11:51 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:51 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:51 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:51 -0700] [Job 7] Wrote 260 bytes of print data...
D [14/Feb/2009:14:11:51 -0700] [Job 7] Read 875 bytes of print data...
d [14/Feb/2009:14:11:51 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:51 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:51 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:51 -0700] [Job 7] Wrote 875 bytes of print data...
d [14/Feb/2009:14:11:51 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:51 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:51 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:51 -0700] [Job 7] Read 3244 bytes of print data...
D [14/Feb/2009:14:11:51 -0700] [Job 7] tail process done writing data to STDOUT
d [14/Feb/2009:14:11:51 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:51 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:51 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:51 -0700] [Job 7] KID4 finished
d [14/Feb/2009:14:11:51 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:51 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:51 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:51 -0700] [Job 7] KID3 exited with status 0
D [14/Feb/2009:14:11:51 -0700] [Job 7] KID4 exited with status 0
D [14/Feb/2009:14:11:51 -0700] [Job 7] Renderer exit stat: 0
d [14/Feb/2009:14:11:51 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:51 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:51 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:51 -0700] [Job 7] Wrote 3244 bytes of print data...
d [14/Feb/2009:14:11:51 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:51 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:51 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:51 -0700] [Job 7] KID3 finished
d [14/Feb/2009:14:11:51 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:51 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:51 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:51 -0700] [Job 7] Renderer process finished
d [14/Feb/2009:14:11:51 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:51 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:51 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:51 -0700] [Job 7]
D [14/Feb/2009:14:11:51 -0700] [Job 7] Closing foomatic-rip.
d [14/Feb/2009:14:11:51 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:51 -0700] cupsdDoSelect: epoll() returned -1...
d [14/Feb/2009:14:11:51 -0700] process_children()
D [14/Feb/2009:14:11:51 -0700] PID 8366 (/usr/lib/cups/filter/foomatic-rip) exited with no errors.
d [14/Feb/2009:14:11:51 -0700] select_timeout(-1): 11 seconds to process active jobs
d [14/Feb/2009:14:11:51 -0700] cupsdDoSelect: polling 5 fds for 11 seconds...
d [14/Feb/2009:14:11:51 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:51 -0700] cupsdDoSelect: Read on fd 16...
d [14/Feb/2009:14:11:51 -0700] process_children()
D [14/Feb/2009:14:11:51 -0700] PID 8367 (/usr/lib/cups/backend/usb) exited with no errors.
d [14/Feb/2009:14:11:51 -0700] cupsdDoSelect: polling 5 fds for 1 seconds...
d [14/Feb/2009:14:11:51 -0700] cupsdDoSelect: epoll() returned 1...
d [14/Feb/2009:14:11:51 -0700] cupsdDoSelect: Read on fd 16...
D [14/Feb/2009:14:11:51 -0700] [Job 7] File 0 is complete.
d [14/Feb/2009:14:11:51 -0700] [Job 7] cupsdFinishJob: job->status is 0
d [14/Feb/2009:14:11:51 -0700] cupsdRemoveSelect: fd=16
d [14/Feb/2009:14:11:51 -0700] [Job 7] cupsdFinishJob: Closing status pipes [ 16 -1 ]...
I [14/Feb/2009:14:11:51 -0700] [Job 7] Completed successfully.
d [14/Feb/2009:14:11:51 -0700] cupsdCancelJob: id = 7
d [14/Feb/2009:14:11:51 -0700] [Job 7] cupsdStopJob: force = 0
d [14/Feb/2009:14:11:51 -0700] cupsdAddEvent(event=printer-state-changed, dest=0x9f635c0(PRINTER), job=(nil)(0), text="%s "%s" state changed.", ...)
D [14/Feb/2009:14:11:51 -0700] Discarding unused printer-state-changed event...
d [14/Feb/2009:14:11:51 -0700] [Job 7] Closing print pipes [ -1 -1 ]...
d [14/Feb/2009:14:11:51 -0700] [Job 7] Closing back pipes [ -1 -1 ]...
d [14/Feb/2009:14:11:51 -0700] [Job 7] Closing side pipes [ -1 -1 ]...
d [14/Feb/2009:14:11:51 -0700] cupsdAddEvent(event=job-completed, dest=0x9f635c0(PRINTER), job=0x9f95560(7), text="Job completed.", ...)
D [14/Feb/2009:14:11:51 -0700] Discarding unused job-completed event...
d [14/Feb/2009:14:11:51 -0700] cupsdSaveJob(job=0x9f95560(7)): job->attrs=0x9f956d0
d [14/Feb/2009:14:11:51 -0700] cupsdCheckJobs: 0 active jobs, sleeping=0, reload=0
d [14/Feb/2009:14:11:51 -0700] cupsdDoSelect: polling 4 fds for 1 seconds...
d [14/Feb/2009:14:11:52 -0700] cupsdDoSelect: epoll() returned 0...
D [14/Feb/2009:14:11:52 -0700] [Job 7] Unloading...
d [14/Feb/2009:14:11:52 -0700] select_timeout(0): 86400 seconds to do nothing
d [14/Feb/2009:14:11:52 -0700] cupsdDoSelect: polling 4 fds for 86400 seconds...
***************************************

Any help you might be able to offer would be appreciated.

Thanks,
Ian






More information about the cups-devel mailing list