Unable to open file "/var/spool/cups/d00004-001" - Permission denied

Kyle Jones kyle at hotelicom.com
Tue Jul 10 11:03:33 PDT 2007 

Hello,
I am trying to get cups working on a non-standard Debian install and after much fiddling I am finally able to get cups to get to the point of allowing me to set up printers and attempt to print a test page.
The problem seems to be that the jobs stops at "Unable to open file "/var/spool/cups/d00004-001" - Permission denied"
Below is a copy of the cups log as well as my cupsd.conf and an ls -al /var/spool/cups

Any help would be greatly appreciated.
If this is a particularly difficult problem to solve then I would be willing to talk $s...
Thanks,
Kyle


D [10/Jul/2007:10:48:20 -0700] Saving remote.cache...
I [10/Jul/2007:10:48:20 -0700] Listening to :::631 (IPv6)
I [10/Jul/2007:10:48:20 -0700] Listening to 0.0.0.0:631 (IPv4)
I [10/Jul/2007:10:48:20 -0700] Listening to /var/run/cups/cups.sock (Domain)
E [10/Jul/2007:10:48:20 -0700] Unknown directive DefaultEncryption on line 21.
I [10/Jul/2007:10:48:20 -0700] Loaded configuration file "/etc/cups/cupsd.conf"
N [10/Jul/2007:10:48:20 -0700] Group and SystemGroup cannot use the same groups!
I [10/Jul/2007:10:48:20 -0700] Resetting Group to "nobody"...
I [10/Jul/2007:10:48:20 -0700] Using default TempDir of /var/spool/cups/tmp...
I [10/Jul/2007:10:48:20 -0700] Cleaning out old temporary files in "/var/spool/cups/tmp"...
I [10/Jul/2007:10:48:20 -0700] Configured for up to 100 clients.
I [10/Jul/2007:10:48:20 -0700] Allowing up to 100 client connections per host.
I [10/Jul/2007:10:48:20 -0700] Using policy "default" as the default!
I [10/Jul/2007:10:48:20 -0700] Full reload is required.
I [10/Jul/2007:10:48:20 -0700] Saving job cache file "/var/cache/cups/job.cache"...
D [10/Jul/2007:10:48:20 -0700] Discarding unused printer-state-changed event...
I [10/Jul/2007:10:48:20 -0700] Loaded MIME database from '/etc/cups': 35 types, 37 filters...
D [10/Jul/2007:10:48:20 -0700] Loading printer Samsung...
I [10/Jul/2007:10:48:20 -0700] Loading job cache file "/var/cache/cups/job.cache"...
D [10/Jul/2007:10:48:20 -0700] [Job 1] Loading from cache...
D [10/Jul/2007:10:48:20 -0700] [Job 1] Loading attributes...
D [10/Jul/2007:10:48:20 -0700] [Job 2] Loading from cache...
D [10/Jul/2007:10:48:20 -0700] [Job 2] Loading attributes...
D [10/Jul/2007:10:48:20 -0700] [Job 3] Loading from cache...
D [10/Jul/2007:10:48:20 -0700] [Job 3] Loading attributes...
I [10/Jul/2007:10:48:20 -0700] Full reload complete.
I [10/Jul/2007:10:48:20 -0700] Listening to :::631 on fd 1...
I [10/Jul/2007:10:48:20 -0700] Listening to 0.0.0.0:631 on fd 3...
I [10/Jul/2007:10:48:20 -0700] Listening to /var/run/cups/cups.sock on fd 4...
D [10/Jul/2007:10:48:25 -0700] cupsdAcceptClient: 8 from 10.127.240.10:631 (IPv4)
D [10/Jul/2007:10:48:25 -0700] cupsdReadClient: 8 GET /printers/Samsung?op=print-test-page HTTP/1.1
D [10/Jul/2007:10:48:25 -0700] cupsdReadClient: 8 Browser asked for language "en-ca.utf-8"...
D [10/Jul/2007:10:48:25 -0700] cupsdAuthorize: username="root"
I [10/Jul/2007:10:48:25 -0700] commptr="?op=print-test-page"
D [10/Jul/2007:10:48:25 -0700] CGI /usr/lib/cups/cgi-bin/printers.cgi started - PID = 5086
I [10/Jul/2007:10:48:25 -0700] Started "/usr/lib/cups/cgi-bin/printers.cgi" (pid=5086)
D [10/Jul/2007:10:48:25 -0700] cupsdSendCommand: 8 file=9
D [10/Jul/2007:10:48:25 -0700] [CGI] HERE1  HERE: open_device
D [10/Jul/2007:10:48:25 -0700] cupsdAcceptClient: 11 from localhost (Domain)
D [10/Jul/2007:10:48:25 -0700] cupsdReadClient: 11 POST /printers/Samsung HTTP/1.1
D [10/Jul/2007:10:48:25 -0700] cupsdAuthorize: No authentication data provided.
D [10/Jul/2007:10:48:25 -0700] Print-Job ipp://localhost:631/printers/Samsung
D [10/Jul/2007:10:48:25 -0700] print_job: request file type is application/postscript.
D [10/Jul/2007:10:48:25 -0700] add_job: requesting-user-name="root"
D [10/Jul/2007:10:48:25 -0700] Adding default job-sheets values "none,none"...
I [10/Jul/2007:10:48:25 -0700] [Job 4] Adding start banner page "none".
D [10/Jul/2007:10:48:25 -0700] Discarding unused job-created event...
I [10/Jul/2007:10:48:25 -0700] [Job 4] Adding end banner page "none".
I [10/Jul/2007:10:48:25 -0700] [Job 4] Queued on "Samsung" by "root".
D [10/Jul/2007:10:48:25 -0700] [Job 4] hold_until = 0
D [10/Jul/2007:10:48:25 -0700] Discarding unused printer-state-changed event...
D [10/Jul/2007:10:48:25 -0700] [Job 4] job-sheets=none,none
D [10/Jul/2007:10:48:25 -0700] [Job 4] banner_page = 0
D [10/Jul/2007:10:48:25 -0700] [Job 4] argv[0]="Samsung"
D [10/Jul/2007:10:48:25 -0700] [Job 4] argv[1]="4"
D [10/Jul/2007:10:48:25 -0700] [Job 4] argv[2]="root"
D [10/Jul/2007:10:48:25 -0700] [Job 4] argv[3]="Test Page"
D [10/Jul/2007:10:48:25 -0700] [Job 4] argv[4]="1"
D [10/Jul/2007:10:48:25 -0700] [Job 4] argv[5]="job-uuid=urn:uuid:151b77f4-ae57-37b1-6456-68847a169146"
D [10/Jul/2007:10:48:25 -0700] [Job 4] argv[6]="/var/spool/cups/d00004-001"
D [10/Jul/2007:10:48:25 -0700] [Job 4] envp[0]="CUPS_CACHEDIR=/var/cache/cups"
D [10/Jul/2007:10:48:25 -0700] [Job 4] envp[1]="CUPS_DATADIR=/usr/share/cups"
D [10/Jul/2007:10:48:25 -0700] [Job 4] envp[2]="CUPS_DOCROOT=/usr/share/doc/cups"
D [10/Jul/2007:10:48:25 -0700] [Job 4] envp[3]="CUPS_FONTPATH=/usr/share/cups/fonts"
D [10/Jul/2007:10:48:25 -0700] [Job 4] envp[4]="CUPS_REQUESTROOT=/var/spool/cups"
D [10/Jul/2007:10:48:25 -0700] [Job 4] envp[5]="CUPS_SERVERBIN=/usr/lib/cups"
D [10/Jul/2007:10:48:25 -0700] [Job 4] envp[6]="CUPS_SERVERROOT=/etc/cups"
D [10/Jul/2007:10:48:25 -0700] [Job 4] envp[7]="CUPS_STATEDIR=/var/run/cups"
D [10/Jul/2007:10:48:25 -0700] [Job 4] envp[8]="PATH=/usr/lib/cups/filter:/usr/bin:/usr/sbin:/bin:/usr/bin"
D [10/Jul/2007:10:48:25 -0700] [Job 4] envp[9]="SERVER_ADMIN=root at hotelicomclient"
D [10/Jul/2007:10:48:25 -0700] [Job 4] envp[10]="SOFTWARE=CUPS/1.3svn-r6596"
D [10/Jul/2007:10:48:25 -0700] [Job 4] envp[11]="TMPDIR=/var/spool/cups/tmp"
D [10/Jul/2007:10:48:25 -0700] [Job 4] envp[12]="USER=root"
D [10/Jul/2007:10:48:25 -0700] [Job 4] envp[13]="CUPS_SERVER=/var/run/cups/cups.sock"
D [10/Jul/2007:10:48:25 -0700] [Job 4] envp[14]="CUPS_ENCRYPTION=IfRequested"
D [10/Jul/2007:10:48:25 -0700] [Job 4] envp[15]="IPP_PORT=631"
D [10/Jul/2007:10:48:25 -0700] [Job 4] envp[16]="CHARSET=utf-8"
D [10/Jul/2007:10:48:25 -0700] [Job 4] envp[17]="LANG=en_CA"
D [10/Jul/2007:10:48:25 -0700] [Job 4] envp[18]="PPD=/etc/cups/ppd/Samsung.ppd"
D [10/Jul/2007:10:48:25 -0700] [Job 4] envp[19]="RIP_MAX_CACHE=8m"
D [10/Jul/2007:10:48:25 -0700] [Job 4] envp[20]="CONTENT_TYPE=application/postscript"
D [10/Jul/2007:10:48:25 -0700] [Job 4] envp[21]="DEVICE_URI=usb://Samsung/ML-2010"
D [10/Jul/2007:10:48:25 -0700] [Job 4] envp[22]="PRINTER=Samsung"
D [10/Jul/2007:10:48:25 -0700] [Job 4] envp[23]="FINAL_CONTENT_TYPE=printer/Samsung"
I [10/Jul/2007:10:48:25 -0700] [Job 4] Started filter /usr/lib/cups/filter/pstops (PID 5087)
I [10/Jul/2007:10:48:25 -0700] [Job 4] Started filter /usr/lib/cups/filter/foomatic-rip (PID 5088)
I [10/Jul/2007:10:48:25 -0700] [Job 4] Started backend /usr/lib/cups/backend/usb (PID 5089)
D [10/Jul/2007:10:48:25 -0700] Discarding unused job-state event...
D [10/Jul/2007:10:48:25 -0700] cupsdProcessIPPRequest: 11 status_code=0 (successful-ok)
E [10/Jul/2007:10:48:25 -0700] [Job 4] Unable to open file "/var/spool/cups/d00004-001" - Permission denied
D [10/Jul/2007:10:48:25 -0700] Discarding unused printer-state-changed event...
D [10/Jul/2007:10:48:25 -0700] [CGI] HERE2  HERE1  HERE2  HERE1  HERE2  HERE1  HERE2  HERE1  HERE2  DEBUG2: cgiSetIPPVars(response=0x80735c0, filter_name="(null)", filter_value="(null)", prefix="(null)", parent_el=0)
E [10/Jul/2007:10:48:25 -0700] PID 5087 (/usr/lib/cups/filter/pstops) stopped with status 1!
D [10/Jul/2007:10:48:25 -0700] [CGI] cgiCopyTemplateLang(tmpl="header.tmpl")
D [10/Jul/2007:10:48:25 -0700] [CGI] locale="en_ca"...
D [10/Jul/2007:10:48:25 -0700] [CGI] Template file is "/usr/share/cups/templates/header.tmpl"...
D [10/Jul/2007:10:48:25 -0700] [CGI] Starting at file position 0...
D [10/Jul/2007:10:48:25 -0700] [CGI] "{title}" at 205...
D [10/Jul/2007:10:48:25 -0700] [CGI] Starting "{refresh_page?" at 381, result=1...
D [10/Jul/2007:10:48:25 -0700] [CGI] Output first part...
D [10/Jul/2007:10:48:25 -0700] [CGI] Starting at file position 381...
D [10/Jul/2007:10:48:25 -0700] [CGI] "{refresh_page}" at 431...
D [10/Jul/2007:10:48:25 -0700] [CGI] Returning at file position 434 on character ':'...
D [10/Jul/2007:10:48:25 -0700] [CGI] Skip second part...
D [10/Jul/2007:10:48:25 -0700] [CGI] Starting at file position 434...
D [10/Jul/2007:10:48:25 -0700] [CGI] Returning at file position 435 on character '}'...
D [10/Jul/2007:10:48:25 -0700] [CGI] Finished "{refresh_page?", out=0xb7e893a0...
D [10/Jul/2007:10:48:25 -0700] [CGI] "{title}" at 678...
D [10/Jul/2007:10:48:25 -0700] [CGI] "{title}" at 959...
D [10/Jul/2007:10:48:25 -0700] [CGI] Starting "{SECTION=admin" at 1418, result=0...
D [10/Jul/2007:10:48:25 -0700] [CGI] Skip first part...
D [10/Jul/2007:10:48:25 -0700] [CGI] Starting at file position 1418...
D [10/Jul/2007:10:48:25 -0700] [CGI] Returning at file position 1419 on character ':'...
D [10/Jul/2007:10:48:25 -0700] [CGI] Output second part...
D [10/Jul/2007:10:48:25 -0700] [CGI] Starting at file position 1419...
D [10/Jul/2007:10:48:25 -0700] [CGI] Returning at file position 1422 on character '}'...
D [10/Jul/2007:10:48:25 -0700] [CGI] Finished "{SECTION=admin", out=0xb7e893a0...
D [10/Jul/2007:10:48:25 -0700] [CGI] Starting "{SECTION=classes" at 1685, result=0...
D [10/Jul/2007:10:48:25 -0700] [CGI] Skip first part...
D [10/Jul/2007:10:48:25 -0700] [CGI] Starting at file position 1685...
D [10/Jul/2007:10:48:25 -0700] [CGI] Returning at file position 1686 on character ':'...
D [10/Jul/2007:10:48:25 -0700] [CGI] Output second part...
D [10/Jul/2007:10:48:25 -0700] [CGI] Starting at file position 1686...
D [10/Jul/2007:10:48:25 -0700] [CGI] Returning at file position 1689 on character '}'...
D [10/Jul/2007:10:48:25 -0700] [CGI] Finished "{SECTION=classes", out=0xb7e893a0...
D [10/Jul/2007:10:48:25 -0700] [CGI] Starting "{SECTION=help" at 1945, result=0...
D [10/Jul/2007:10:48:25 -0700] [CGI] Skip first part...
D [10/Jul/2007:10:48:25 -0700] [CGI] Starting at file position 1945...
D [10/Jul/2007:10:48:25 -0700] [CGI] Returning at file position 1946 on character ':'...
D [10/Jul/2007:10:48:25 -0700] [CGI] Output second part...
D [10/Jul/2007:10:48:25 -0700] cupsdCloseClient: 11
D [10/Jul/2007:10:48:25 -0700] [CGI] Starting at file position 1946...
D [10/Jul/2007:10:48:25 -0700] [CGI] Returning at file position 1949 on character '}'...
D [10/Jul/2007:10:48:25 -0700] [CGI] Finished "{SECTION=help", out=0xb7e893a0...
D [10/Jul/2007:10:48:25 -0700] [CGI] Starting "{SECTION=jobs" at 2213, result=0...
D [10/Jul/2007:10:48:25 -0700] [CGI] Skip first part...
D [10/Jul/2007:10:48:25 -0700] [CGI] Starting at file position 2213...
D [10/Jul/2007:10:48:25 -0700] [CGI] Returning at file position 2214 on character ':'...
D [10/Jul/2007:10:48:25 -0700] [CGI] Output second part...
D [10/Jul/2007:10:48:25 -0700] [CGI] Starting at file position 2214...
D [10/Jul/2007:10:48:25 -0700] [CGI] Returning at file position 2217 on character '}'...
D [10/Jul/2007:10:48:25 -0700] [CGI] Finished "{SECTION=jobs", out=0xb7e893a0...
D [10/Jul/2007:10:48:25 -0700] [CGI] Starting "{SECTION=printers" at 2471, result=1...
D [10/Jul/2007:10:48:25 -0700] [CGI] Output first part...
D [10/Jul/2007:10:48:25 -0700] [CGI] Starting at file position 2471...
D [10/Jul/2007:10:48:25 -0700] [CGI] Returning at file position 2472 on character ':'...
D [10/Jul/2007:10:48:25 -0700] [CGI] Skip second part...
D [10/Jul/2007:10:48:25 -0700] [CGI] Starting at file position 2472...
D [10/Jul/2007:10:48:25 -0700] [CGI] Returning at file position 2475 on character '}'...
D [10/Jul/2007:10:48:25 -0700] [CGI] Finished "{SECTION=printers", out=0xb7e893a0...
D [10/Jul/2007:10:48:25 -0700] [CGI] Returning at file position 2837 on EOF...
D [10/Jul/2007:10:48:25 -0700] [CGI] cgiCopyTemplateLang(tmpl="test-page.tmpl")
D [10/Jul/2007:10:48:25 -0700] [CGI] locale="en_ca"...
D [10/Jul/2007:10:48:25 -0700] PID 5086 (/usr/lib/cups/cgi-bin/printers.cgi) exited with no errors.
D [10/Jul/2007:10:48:25 -0700] [CGI] Template file is "/usr/share/cups/templates/test-page.tmpl"...
D [10/Jul/2007:10:48:25 -0700] [CGI] Starting at file position 0...
D [10/Jul/2007:10:48:25 -0700] [CGI] "{SECTION}" at 48...
D [10/Jul/2007:10:48:25 -0700] [CGI] "{printer_name}" at 63...
D [10/Jul/2007:10:48:25 -0700] [CGI] "{printer_name}" at 80...
D [10/Jul/2007:10:48:25 -0700] [CGI] "{job_id}" at 89...
D [10/Jul/2007:10:48:25 -0700] [CGI] Returning at file position 99 on EOF...
D [10/Jul/2007:10:48:25 -0700] [CGI] cgiCopyTemplateLang(tmpl="trailer.tmpl")
D [10/Jul/2007:10:48:25 -0700] [CGI] locale="en_ca"...
D [10/Jul/2007:10:48:25 -0700] [CGI] Template file is "/usr/share/cups/templates/trailer.tmpl"...
D [10/Jul/2007:10:48:25 -0700] [CGI] Starting at file position 0...
D [10/Jul/2007:10:48:25 -0700] [CGI] Returning at file position 614 on EOF...
D [10/Jul/2007:10:48:25 -0700] Discarding unused printer-state-changed event...
D [10/Jul/2007:10:48:25 -0700] [Job 4] Printer using device file "/dev/usb/lp0"...
D [10/Jul/2007:10:48:25 -0700] Discarding unused printer-state-changed event...
D [10/Jul/2007:10:48:25 -0700] [Job 4] backendRunLoop(print_fd=0, device_fd=5, use_bc=1, side_cb=0x804954a)
D [10/Jul/2007:10:48:25 -0700] [Job 4] whoami: cannot find name for user ID 7
D [10/Jul/2007:10:48:25 -0700] [Job 4] foomatic-rip version $Revision$ running...
D [10/Jul/2007:10:48:25 -0700] [Job 4] Parsing PPD file ...
D [10/Jul/2007:10:48:25 -0700] [Job 4] *cupsFilter: "application/vnd.cups-postscript 0 foomatic-rip"
D [10/Jul/2007:10:48:25 -0700] [Job 4] Added option ColorSpace
D [10/Jul/2007:10:48:25 -0700] [Job 4] Added option Manualfeed
D [10/Jul/2007:10:48:25 -0700] [Job 4] Added option Resolution
D [10/Jul/2007:10:48:25 -0700] [Job 4] Added option Economode
D [10/Jul/2007:10:48:25 -0700] [Job 4] Added option MediaType
D [10/Jul/2007:10:48:25 -0700] [Job 4] Added option RET
D [10/Jul/2007:10:48:25 -0700] [Job 4] Added option Copies
D [10/Jul/2007:10:48:25 -0700] [Job 4] Added option PageSize
D [10/Jul/2007:10:48:25 -0700] [Job 4] Added option PageRegion
D [10/Jul/2007:10:48:25 -0700] [Job 4] Added option ImageableArea
D [10/Jul/2007:10:48:25 -0700] [Job 4] Added option PaperDimension
D [10/Jul/2007:10:48:25 -0700] [Job 4] Added option HalftoningAlgorithm
D [10/Jul/2007:10:48:25 -0700] [Job 4] Added option Density
D [10/Jul/2007:10:48:25 -0700] [Job 4] Added option JamRecovery
D [10/Jul/2007:10:48:25 -0700] [Job 4] Added option AllowReprint
D [10/Jul/2007:10:48:25 -0700] [Job 4] Added option Altitude
D [10/Jul/2007:10:48:25 -0700] [Job 4] Added option PageTimeout
D [10/Jul/2007:10:48:25 -0700] [Job 4] Added option PowerSaving
D [10/Jul/2007:10:48:25 -0700] [Job 4] Added option PowerSaveTime
D [10/Jul/2007:10:48:25 -0700] [Job 4] Added option PageSizeJCL
D [10/Jul/2007:10:48:25 -0700] [Job 4] Added option PageSizePS
D [10/Jul/2007:10:48:25 -0700] [Job 4] Added option Font
D [10/Jul/2007:10:48:25 -0700] [Job 4]
D [10/Jul/2007:10:48:25 -0700] [Job 4] Parameter Summary
D [10/Jul/2007:10:48:25 -0700] [Job 4] -----------------
D [10/Jul/2007:10:48:25 -0700] [Job 4]
D [10/Jul/2007:10:48:25 -0700] [Job 4] Spooler: cups
D [10/Jul/2007:10:48:25 -0700] [Job 4] Printer: Samsung
D [10/Jul/2007:10:48:25 -0700] [Job 4] Shell: /bin/sh
D [10/Jul/2007:10:48:25 -0700] [Job 4] PPD file: /etc/cups/ppd/Samsung.ppd
D [10/Jul/2007:10:48:25 -0700] [Job 4] ATTR file:
D [10/Jul/2007:10:48:25 -0700] [Job 4] Printer model: Samsung ML-2010 Foomatic/gdi (recommended)
D [10/Jul/2007:10:48:25 -0700] [Job 4] Job title: Test Page
D [10/Jul/2007:10:48:25 -0700] [Job 4] File(s) to be printed:
D [10/Jul/2007:10:48:25 -0700] [Job 4] <STDIN>
D [10/Jul/2007:10:48:25 -0700] [Job 4]
D [10/Jul/2007:10:48:25 -0700] [Job 4] GhostScript extra search path ('GS_LIB'): /usr/share/cups/fonts
D [10/Jul/2007:10:48:25 -0700] [Job 4] Pondering option 'job-uuid=urn:uuid:151b77f4-ae57-37b1-6456-68847a169146'
D [10/Jul/2007:10:48:25 -0700] [Job 4] Unknown option job-uuid=urn:uuid:151b77f4-ae57-37b1-6456-68847a169146.
D [10/Jul/2007:10:48:25 -0700] [Job 4]
D [10/Jul/2007:10:48:25 -0700] [Job 4] ================================================
D [10/Jul/2007:10:48:25 -0700] [Job 4]
D [10/Jul/2007:10:48:25 -0700] [Job 4] File: <STDIN>
D [10/Jul/2007:10:48:25 -0700] [Job 4]
D [10/Jul/2007:10:48:25 -0700] [Job 4] ================================================
D [10/Jul/2007:10:48:25 -0700] [Job 4]
D [10/Jul/2007:10:48:25 -0700] [Job 4] Reading PostScript input ...
D [10/Jul/2007:10:48:25 -0700] [Job 4]
D [10/Jul/2007:10:48:25 -0700] [Job 4] Job does not start with "%!", is it PostScript?
D [10/Jul/2007:10:48:25 -0700] [Job 4] Starting file converter
D [10/Jul/2007:10:48:25 -0700] [Job 4]
D [10/Jul/2007:10:48:25 -0700] [Job 4] Starting converter for non-PostScript files
D [10/Jul/2007:10:48:25 -0700] [Job 4] tail process done reading data from STDIN
D [10/Jul/2007:10:48:25 -0700] [Job 4] KID2 finished
D [10/Jul/2007:10:48:25 -0700] [Job 4] file converter PID kid2=5095
D [10/Jul/2007:10:48:25 -0700] [Job 4] Page = 612x792; 0,0 to 612,792
D [10/Jul/2007:10:48:25 -0700] [Job 4] ppd->num_fonts = 35
D [10/Jul/2007:10:48:25 -0700] [Job 4] ppd->fonts[0] = AvantGarde-Book
D [10/Jul/2007:10:48:25 -0700] [Job 4] ppd->fonts[1] = AvantGarde-BookOblique
D [10/Jul/2007:10:48:25 -0700] [Job 4] ppd->fonts[2] = AvantGarde-Demi
D [10/Jul/2007:10:48:25 -0700] [Job 4] ppd->fonts[3] = AvantGarde-DemiOblique
D [10/Jul/2007:10:48:25 -0700] [Job 4] ppd->fonts[4] = Bookman-Demi
D [10/Jul/2007:10:48:25 -0700] [Job 4] ppd->fonts[5] = Bookman-DemiItalic
D [10/Jul/2007:10:48:25 -0700] [Job 4] ppd->fonts[6] = Bookman-Light
D [10/Jul/2007:10:48:25 -0700] [Job 4] ppd->fonts[7] = Bookman-LightItalic
D [10/Jul/2007:10:48:25 -0700] [Job 4] ppd->fonts[8] = Courier
D [10/Jul/2007:10:48:25 -0700] [Job 4] ppd->fonts[9] = Courier-Bold
D [10/Jul/2007:10:48:25 -0700] [Job 4] ppd->num_fonts = 35
D [10/Jul/2007:10:48:25 -0700] [Job 4] ppd->fonts[0] = AvantGarde-Book
D [10/Jul/2007:10:48:25 -0700] [Job 4] ppd->fonts[1] = AvantGarde-BookOblique
D [10/Jul/2007:10:48:25 -0700] [Job 4] ppd->fonts[2] = AvantGarde-Demi
D [10/Jul/2007:10:48:25 -0700] [Job 4] ppd->fonts[3] = AvantGarde-DemiOblique
D [10/Jul/2007:10:48:25 -0700] [Job 4] ppd->fonts[4] = Bookman-Demi
D [10/Jul/2007:10:48:25 -0700] [Job 4] ppd->fonts[5] = Bookman-DemiItalic
D [10/Jul/2007:10:48:25 -0700] [Job 4] ppd->fonts[6] = Bookman-Light
D [10/Jul/2007:10:48:25 -0700] [Job 4] ppd->fonts[7] = Bookman-LightItalic
D [10/Jul/2007:10:48:25 -0700] [Job 4] ppd->fonts[8] = Courier
D [10/Jul/2007:10:48:25 -0700] [Job 4] ppd->num_fonts = 35
D [10/Jul/2007:10:48:25 -0700] [Job 4] ppd->fonts[0] = AvantGarde-Book
D [10/Jul/2007:10:48:25 -0700] [Job 4] ppd->fonts[1] = AvantGarde-BookOblique
D [10/Jul/2007:10:48:25 -0700] [Job 4] ppd->fonts[2] = AvantGarde-Demi
D [10/Jul/2007:10:48:25 -0700] [Job 4] ppd->fonts[3] = AvantGarde-DemiOblique
D [10/Jul/2007:10:48:25 -0700] [Job 4] ppd->fonts[4] = Bookman-Demi
D [10/Jul/2007:10:48:25 -0700] [Job 4] ppd->fonts[5] = Bookman-DemiItalic
D [10/Jul/2007:10:48:25 -0700] [Job 4] ppd->fonts[6] = Bookman-Light
D [10/Jul/2007:10:48:25 -0700] [Job 4] ppd->fonts[7] = Bookman-LightItalic
D [10/Jul/2007:10:48:25 -0700] [Job 4] ppd->fonts[8] = Courier
D [10/Jul/2007:10:48:25 -0700] [Job 4] ppd->fonts[9] = Courier-Bold
D [10/Jul/2007:10:48:25 -0700] [Job 4] ppd->fonts[10] = Courier-BoldOblique
D [10/Jul/2007:10:48:25 -0700] [Job 4] ppd->fonts[11] = Courier-Oblique
D [10/Jul/2007:10:48:25 -0700] [Job 4] ppd->fonts[12] = Helvetica
D [10/Jul/2007:10:48:25 -0700] [Job 4] ppd->fonts[13] = Helvetica-Bold
D [10/Jul/2007:10:48:25 -0700] [Job 4] ppd->fonts[14] = Helvetica-BoldOblique
D [10/Jul/2007:10:48:25 -0700] [Job 4] ppd->fonts[15] = Helvetica-Narrow
D [10/Jul/2007:10:48:25 -0700] [Job 4] ppd->fonts[16] = Helvetica-Narrow-Bold
D [10/Jul/2007:10:48:25 -0700] [Job 4] ppd->fonts[17] = Helvetica-Narrow-BoldOblique
D [10/Jul/2007:10:48:25 -0700] [Job 4] ppd->fonts[18] = Helvetica-Narrow-Oblique
D [10/Jul/2007:10:48:25 -0700] [Job 4] ppd->fonts[19] = Helvetica-Oblique
D [10/Jul/2007:10:48:25 -0700] [Job 4] ppd->fonts[20] = NewCenturySchlbk-Bold
D [10/Jul/2007:10:48:25 -0700] [Job 4] ppd->fonts[21] = NewCenturySchlbk-BoldItalic
D [10/Jul/2007:10:48:25 -0700] [Job 4] ppd->fonts[22] = NewCenturySchlbk-Italic
D [10/Jul/2007:10:48:25 -0700] [Job 4] ppd->fonts[23] = NewCenturySchlbk-Roman
D [10/Jul/2007:10:48:25 -0700] [Job 4] ppd->fonts[24] = Palatino-Bold
D [10/Jul/2007:10:48:25 -0700] [Job 4] ppd->fonts[25] = Palatino-BoldItalic
D [10/Jul/2007:10:48:25 -0700] [Job 4] ppd->fonts[26] = Palatino-Italic
D [10/Jul/2007:10:48:25 -0700] [Job 4] ppd->fonts[27] = Palatino-Roman
D [10/Jul/2007:10:48:25 -0700] [Job 4] ppd->fonts[28] = Symbol
D [10/Jul/2007:10:48:25 -0700] [Job 4] Page = 612x792; 0,0 to 612,792
D [10/Jul/2007:10:48:25 -0700] [Job 4] slow_collate=0, slow_duplex=0, slow_order=0
D [10/Jul/2007:10:48:25 -0700] [Job 4] Before copy_comments - %!PS-Adobe-3.0
D [10/Jul/2007:10:48:25 -0700] [Job 4] %!PS-Adobe-3.0
D [10/Jul/2007:10:48:25 -0700] [Job 4] %%BoundingBox: 0 0 612 792
D [10/Jul/2007:10:48:25 -0700] [Job 4] %cupsRotation: 0
D [10/Jul/2007:10:48:25 -0700] [Job 4] %%Creator: texttops/CUPS v1.3svn-r6596
D [10/Jul/2007:10:48:25 -0700] [Job 4] %%CreationDate: Tue 10 Jul 2007 05:48:25 PM UTC
D [10/Jul/2007:10:48:25 -0700] [Job 4] %%Title: (Test Page)
D [10/Jul/2007:10:48:25 -0700] [Job 4] %%For: (root)
D [10/Jul/2007:10:48:25 -0700] [Job 4] %%Pages: (atend)
D [10/Jul/2007:10:48:25 -0700] [Job 4] %%DocumentNeededResources: font Courier-Bold
D [10/Jul/2007:10:48:25 -0700] [Job 4] %%+ font Courier
D [10/Jul/2007:10:48:25 -0700] [Job 4] %%+ font Symbol
D [10/Jul/2007:10:48:25 -0700] [Job 4] %%DocumentSuppliedResources: procset texttops 1.1 0
D [10/Jul/2007:10:48:25 -0700] [Job 4] %%+ font Courier-Bold
D [10/Jul/2007:10:48:25 -0700] [Job 4] %%+ font Courier
D [10/Jul/2007:10:48:25 -0700] [Job 4] %%+ font Symbol
D [10/Jul/2007:10:48:25 -0700] [Job 4] %%EndComments
D [10/Jul/2007:10:48:25 -0700] [Job 4] Before copy_prolog - %%BeginProlog
D [10/Jul/2007:10:48:25 -0700] [Job 4] --> This document is DSC-conforming!
D [10/Jul/2007:10:48:25 -0700] [Job 4]
D [10/Jul/2007:10:48:25 -0700] [Job 4] -----------
D [10/Jul/2007:10:48:25 -0700] [Job 4] Found: %%BeginProlog
D [10/Jul/2007:10:48:25 -0700] [Job 4] Before copy_setup - %%Trailer
D [10/Jul/2007:10:48:25 -0700] [Job 4] Before page loop - DEBUG: Wrote 0 pages...
D [10/Jul/2007:10:48:25 -0700] [Job 4] KID1 finished
D [10/Jul/2007:10:48:25 -0700] [Job 4] Found: %%EndProlog
D [10/Jul/2007:10:48:25 -0700] [Job 4]
D [10/Jul/2007:10:48:25 -0700] [Job 4] -----------
D [10/Jul/2007:10:48:25 -0700] [Job 4] Found: %%BeginSetup
D [10/Jul/2007:10:48:25 -0700] [Job 4] Found: %%BeginFeature: *PageSize Letter
D [10/Jul/2007:10:48:25 -0700] [Job 4] Option: PageSize=Letter --> Setting option
D [10/Jul/2007:10:48:25 -0700] [Job 4] Found: %% FoomaticRIPOptionSetting: PageSize=Letter
D [10/Jul/2007:10:48:25 -0700] [Job 4] Option: PageSize=Letter --> Setting option
D [10/Jul/2007:10:48:25 -0700] [Job 4] Found: %%BeginFeature: *Manualfeed Off
D [10/Jul/2007:10:48:25 -0700] [Job 4] Option: Manualfeed=Off --> Setting option
D [10/Jul/2007:10:48:25 -0700] [Job 4] Found: %% FoomaticRIPOptionSetting: Manualfeed=Off
D [10/Jul/2007:10:48:25 -0700] [Job 4] Option: Manualfeed=Off --> Setting option
D [10/Jul/2007:10:48:25 -0700] [Job 4] Found: %%BeginFeature: *Resolution 600x600dpi
D [10/Jul/2007:10:48:25 -0700] [Job 4] Option: Resolution=600x600dpi --> Option will be set by PostScript interpreter
D [10/Jul/2007:10:48:25 -0700] [Job 4] Found: %%BeginFeature: *Economode Off
D [10/Jul/2007:10:48:25 -0700] [Job 4] Option: Economode=Off --> Setting option
D [10/Jul/2007:10:48:25 -0700] [Job 4] Found: %% FoomaticRIPOptionSetting: Economode=Off
D [10/Jul/2007:10:48:25 -0700] [Job 4] Option: Economode=Off --> Setting option
D [10/Jul/2007:10:48:25 -0700] [Job 4] Found: %%BeginFeature: *MediaType Normal
D [10/Jul/2007:10:48:25 -0700] [Job 4] Option: MediaType=Normal --> Setting option
D [10/Jul/2007:10:48:25 -0700] [Job 4] Found: %% FoomaticRIPOptionSetting: MediaType=Normal
D [10/Jul/2007:10:48:25 -0700] [Job 4] Option: MediaType=Normal --> Setting option
D [10/Jul/2007:10:48:25 -0700] [Job 4] Found: %%BeginFeature: *Density 3
D [10/Jul/2007:10:48:25 -0700] [Job 4] Option: Density=3 --> Setting option
D [10/Jul/2007:10:48:25 -0700] [Job 4] Found: %% FoomaticRIPOptionSetting: Density=3
D [10/Jul/2007:10:48:25 -0700] [Job 4] Option: Density=3 --> Setting option
D [10/Jul/2007:10:48:25 -0700] [Job 4] Found: %%BeginFeature: *JamRecovery Yes
D [10/Jul/2007:10:48:25 -0700] [Job 4] Option: JamRecovery=Yes --> Setting option
D [10/Jul/2007:10:48:25 -0700] [Job 4] Found: %% FoomaticRIPOptionSetting: JamRecovery=Yes
D [10/Jul/2007:10:48:25 -0700] [Job 4] Option: JamRecovery=Yes --> Setting option
D [10/Jul/2007:10:48:25 -0700] [Job 4] Found: %%BeginFeature: *AllowReprint Yes
D [10/Jul/2007:10:48:25 -0700] [Job 4] Option: AllowReprint=Yes --> Setting option
D [10/Jul/2007:10:48:25 -0700] [Job 4] Found: %% FoomaticRIPOptionSetting: AllowReprint=Yes
D [10/Jul/2007:10:48:25 -0700] [Job 4] Option: AllowReprint=Yes --> Setting option
D [10/Jul/2007:10:48:25 -0700] [Job 4] Found: %%BeginFeature: *Altitude Low
D [10/Jul/2007:10:48:25 -0700] [Job 4] Option: Altitude=Low --> Setting option
D [10/Jul/2007:10:48:25 -0700] [Job 4] Found: %% FoomaticRIPOptionSetting: Altitude=Low
D [10/Jul/2007:10:48:25 -0700] [Job 4] Option: Altitude=Low --> Setting option
D [10/Jul/2007:10:48:25 -0700] [Job 4] Found: %%BeginFeature: *Copies 1
D [10/Jul/2007:10:48:25 -0700] [Job 4] Option: Copies=1 --> Setting option
D [10/Jul/2007:10:48:25 -0700] [Job 4] Found: %% FoomaticRIPOptionSetting: Copies=1
D [10/Jul/2007:10:48:25 -0700] [Job 4] Option: Copies=1 --> Setting option
D [10/Jul/2007:10:48:25 -0700] [Job 4] Found: %%BeginFeature: *PageTimeout 15
D [10/Jul/2007:10:48:25 -0700] [Job 4] Option: PageTimeout=15 --> Setting option
D [10/Jul/2007:10:48:25 -0700] [Job 4] Found: %% FoomaticRIPOptionSetting: PageTimeout=15
D [10/Jul/2007:10:48:25 -0700] [Job 4] Option: PageTimeout=15 --> Setting option
D [10/Jul/2007:10:48:25 -0700] [Job 4] Found: %%BeginFeature: *PowerSaving On
D [10/Jul/2007:10:48:25 -0700] [Job 4] Option: PowerSaving=On --> Setting option
D [10/Jul/2007:10:48:25 -0700] [Job 4] Found: %% FoomaticRIPOptionSetting: PowerSaving=On
D [10/Jul/2007:10:48:25 -0700] [Job 4] Option: PowerSaving=On --> Setting option
D [10/Jul/2007:10:48:25 -0700] [Job 4] Found: %%BeginFeature: *PowerSaveTime 5
D [10/Jul/2007:10:48:25 -0700] [Job 4] Option: PowerSaveTime=5 --> Setting option
D [10/Jul/2007:10:48:25 -0700] [Job 4] Found: %% FoomaticRIPOptionSetting: PowerSaveTime=5
D [10/Jul/2007:10:48:25 -0700] [Job 4] Option: PowerSaveTime=5 --> Setting option
D [10/Jul/2007:10:48:25 -0700] [Job 4] Found: %%EndSetup
D [10/Jul/2007:10:48:25 -0700] [Job 4] Inserting PostScript code for CUPS' page accounting
D [10/Jul/2007:10:48:25 -0700] [Job 4] Flushing FIFO.
D [10/Jul/2007:10:48:25 -0700] [Job 4] "PageSetup" section is missing, inserting it.
D [10/Jul/2007:10:48:25 -0700] [Job 4] Inserting option code into "PageSetup" section.
D [10/Jul/2007:10:48:25 -0700] [Job 4]
D [10/Jul/2007:10:48:25 -0700] [Job 4] Starting renderer
D [10/Jul/2007:10:48:25 -0700] [Job 4] renderer PID kid4=5100
D [10/Jul/2007:10:48:25 -0700] [Job 4] renderer command: gs -q -dBATCH -dPARANOIDSAFER -dQUIET -dNOPAUSE -sDEVICE=gdi -sOutputFile=- - | perl -p -e 's/PJL PAGE LETTER/PJL PAGE LETTER/; s/PJL PAGE (\S*) AUTO/PJL PAGE $1 AUTO/; s/PJL SET TONERSAVE = OFF/PJL SET TONERSAVE = OFF\r\n\@PJL SET ECONOMODE = OFF/; s/PJL SET PAPERTYPE = NORMAL/PJL SET PAPERTYPE = NORMAL/; s/PJL SET DENSITY = 1/PJL SET DENSITY = 3/; s/(\@PJL ENTER LANGUAGE)/\@PJL SET RET = OFF\r\n$1/; s/(\@PJL ENTER LANGUAGE)/\@PJL SET JAMRECOVERY = ON\r\n$1/; s/(\@PJL ENTER LANGUAGE)/\@PJL SET REPRINT = ON\r\n$1/; s/(\@PJL ENTER LANGUAGE)/\@PJL SET ALTITUDE = OFF\r\n$1/; s/PJL COPIES = 1/PJL COPIES = 1/; s/(\@PJL ENTER LANGUAGE)/\@PJL DEFAULT TIMEOUT = 15\r\n$1/; s/(\@PJL ENTER LANGUAGE)/\@PJL DEFAULT POWERSAVE = ON\r\n$1/; s/(\@PJL ENTER LANGUAGE)/\@PJL DEFAULT POWERSAVETIME = 5\r\n$1/; '
D [10/Jul/2007:10:48:25 -0700] [Job 4] JCL: <job data>
D [10/Jul/2007:10:48:25 -0700] [Job 4]
D [10/Jul/2007:10:48:25 -0700] [Job 4] foomatic-gswrapper: gs '-dBATCH' '-dPARANOIDSAFER' '-dQUIET' '-dNOPAUSE' '-sDEVICE=gdi' '-sOutputFile=/dev/fd/3' '/dev/fd/0' 3>&1 1>&2
D [10/Jul/2007:10:48:25 -0700] [Job 4] sh: gs: command not found
D [10/Jul/2007:10:48:25 -0700] [Job 4] tail process done writing data to STDOUT
D [10/Jul/2007:10:48:25 -0700] [Job 4] KID4 finished
D [10/Jul/2007:10:48:25 -0700] [Job 4]
D [10/Jul/2007:10:48:25 -0700] [Job 4] Closing renderer
D [10/Jul/2007:10:48:25 -0700] [Job 4] KID4 exited with status 0
D [10/Jul/2007:10:48:25 -0700] [Job 4] KID3 exited with status 0
D [10/Jul/2007:10:48:25 -0700] [Job 4] Renderer exit stat: 0
D [10/Jul/2007:10:48:25 -0700] [Job 4] KID3 finished
D [10/Jul/2007:10:48:25 -0700] [Job 4] Renderer process finished
D [10/Jul/2007:10:48:25 -0700] [Job 4]
D [10/Jul/2007:10:48:25 -0700] [Job 4] Closing file converter
D [10/Jul/2007:10:48:25 -0700] [Job 4] KID2 exited with status 0
D [10/Jul/2007:10:48:25 -0700] [Job 4] KID1 exited with status 0
D [10/Jul/2007:10:48:25 -0700] [Job 4] File converter exit stat: 0
D [10/Jul/2007:10:48:25 -0700] [Job 4] File converter process finished
D [10/Jul/2007:10:48:25 -0700] [Job 4]
D [10/Jul/2007:10:48:25 -0700] [Job 4] Closing foomatic-rip.
D [10/Jul/2007:10:48:25 -0700] PID 5088 (/usr/lib/cups/filter/foomatic-rip) exited with no errors.
D [10/Jul/2007:10:48:25 -0700] PID 5089 (/usr/lib/cups/backend/usb) exited with no errors.
D [10/Jul/2007:10:48:25 -0700] [Job 4] File 0 is complete.
D [10/Jul/2007:10:48:25 -0700] Discarding unused printer-state-changed event...
D [10/Jul/2007:10:48:25 -0700] Discarding unused job-stopped event...
D [10/Jul/2007:10:48:26 -0700] [Job 4] Unloading...
D [10/Jul/2007:10:48:27 -0700] cupsdReadClient: 8 GET /printers/Samsung HTTP/1.1
D [10/Jul/2007:10:48:27 -0700] cupsdReadClient: 8 Browser asked for language "en-ca.utf-8"...
D [10/Jul/2007:10:48:27 -0700] cupsdAuthorize: username="root"
I [10/Jul/2007:10:48:27 -0700] commptr=""
D [10/Jul/2007:10:48:27 -0700] CGI /usr/lib/cups/cgi-bin/printers.cgi started - PID = 5107
I [10/Jul/2007:10:48:27 -0700] Started "/usr/lib/cups/cgi-bin/printers.cgi" (pid=5107)
D [10/Jul/2007:10:48:27 -0700] cupsdSendCommand: 8 file=9
D [10/Jul/2007:10:48:27 -0700] [CGI] HERE1  HERE: open_device
D [10/Jul/2007:10:48:27 -0700] cupsdAcceptClient: 11 from localhost (Domain)
D [10/Jul/2007:10:48:27 -0700] cupsdReadClient: 11 POST / HTTP/1.1
D [10/Jul/2007:10:48:27 -0700] cupsdAuthorize: No authentication data provided.
D [10/Jul/2007:10:48:27 -0700] CUPS-Get-Default
D [10/Jul/2007:10:48:27 -0700] CUPS-Get-Default client-error-not-found: No default printer
D [10/Jul/2007:10:48:27 -0700] cupsdProcessIPPRequest: 11 status_code=406 (client-error-not-found)
D [10/Jul/2007:10:48:27 -0700] [CGI] HERE2  HERE1  HERE2  HERE1  HERE2  HERE1  HERE2  HERE1  HERE2  DEBUG: show_printer(http=0x8070028, printer="Samsung")
D [10/Jul/2007:10:48:27 -0700] cupsdReadClient: 11 POST / HTTP/1.1
D [10/Jul/2007:10:48:27 -0700] cupsdAuthorize: No authentication data provided.
D [10/Jul/2007:10:48:27 -0700] Get-Printer-Attributes ipp://localhost/printers/Samsung
D [10/Jul/2007:10:48:27 -0700] cupsdProcessIPPRequest: 11 status_code=0 (successful-ok)
D [10/Jul/2007:10:48:27 -0700] [CGI] cgiCopyTemplateLang(tmpl="header.tmpl")
D [10/Jul/2007:10:48:27 -0700] [CGI] locale="en_ca"...
D [10/Jul/2007:10:48:27 -0700] [CGI] Template file is "/usr/share/cups/templates/header.tmpl"...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 0...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{title}" at 205...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting "{refresh_page?" at 381, result=0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Skip first part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 381...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{refresh_page}" at 431...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 434 on character ':'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Output second part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 434...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 435 on character '}'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Finished "{refresh_page?", out=0xb7ead3a0...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{title}" at 678...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{title}" at 959...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting "{SECTION=admin" at 1418, result=0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Skip first part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 1418...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 1419 on character ':'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Output second part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 1419...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 1422 on character '}'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Finished "{SECTION=admin", out=0xb7ead3a0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting "{SECTION=classes" at 1685, result=0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Skip first part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 1685...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 1686 on character ':'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Output second part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 1686...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 1689 on character '}'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Finished "{SECTION=classes", out=0xb7ead3a0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting "{SECTION=help" at 1945, result=0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Skip first part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 1945...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 1946 on character ':'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Output second part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 1946...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 1949 on character '}'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Finished "{SECTION=help", out=0xb7ead3a0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting "{SECTION=jobs" at 2213, result=0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Skip first part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 2213...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 2214 on character ':'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Output second part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 2214...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 2217 on character '}'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Finished "{SECTION=jobs", out=0xb7ead3a0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting "{SECTION=printers" at 2471, result=1...
D [10/Jul/2007:10:48:27 -0700] [CGI] Output first part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 2471...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 2472 on character ':'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Skip second part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 2472...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 2475 on character '}'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Finished "{SECTION=printers", out=0xb7ead3a0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 2837 on EOF...
D [10/Jul/2007:10:48:27 -0700] [CGI] cgiCopyTemplateLang(tmpl="printers.tmpl")
D [10/Jul/2007:10:48:27 -0700] [CGI] locale="en_ca"...
D [10/Jul/2007:10:48:27 -0700] [CGI] Template file is "/usr/share/cups/templates/printers.tmpl"...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting "{printer_type?" at 14, result=1...
D [10/Jul/2007:10:48:27 -0700] [CGI] Output first part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 14...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 15 on character ':'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Skip second part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 15...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 16 on character '}'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Finished "{printer_type?", out=0xb7ead3a0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting "{#printer_name=0" at 33, result=0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Skip first part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 33...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 34 on character ':'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Output second part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 34...
D [10/Jul/2007:10:48:27 -0700] [CGI] Looping on "printer_name" at 50, count=1...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 50...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{printer_uri_supported}" at 101...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{printer_name}" at 117...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting "{default_name=Samsung" at 150, result=0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Skip first part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 150...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 169 on character ':'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Output second part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 169...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 170 on character '}'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Finished "{default_name=Samsung", out=0xb7ead3a0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting "{?printer_state_message=" at 196, result=0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Skip first part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 196...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 197 on character ':'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Output second part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 197...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{printer_state_message}" at 243...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 252 on character '}'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Finished "{?printer_state_message=", out=0xb7ead3a0...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{printer_name}" at 349...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{printer_uri_supported}" at 406...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting "{printer_state=3" at 452, result=1...
D [10/Jul/2007:10:48:27 -0700] [CGI] Output first part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 452...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 457 on character ':'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Skip second part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 457...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting "{printer_state=4" at 474, result=0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Skip first part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 474...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 485 on character ':'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Output second part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 485...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 493 on character '}'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Finished "{printer_state=4", out=(nil)...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 494 on character '}'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Finished "{printer_state=3", out=0xb7ead3a0...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{printer_info}" at 584...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{printer_location}" at 624...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{printer_make_and_model}" at 676...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting "{printer_state=3" at 720, result=1...
D [10/Jul/2007:10:48:27 -0700] [CGI] Output first part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 720...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 725 on character ':'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Skip second part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 725...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting "{printer_state=4" at 742, result=0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Skip first part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 742...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 753 on character ':'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Output second part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 753...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 761 on character '}'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Finished "{printer_state=4", out=(nil)...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 762 on character '}'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Finished "{printer_state=3", out=0xb7ead3a0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting "{printer_is_accepting_jobs=0" at 793, result=0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Skip first part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 793...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 808 on character ':'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Output second part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 808...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 823 on character '}'...
D [10/Jul/2007:10:48:27 -0700] cupsdReadClient: 11 POST / HTTP/1.1
D [10/Jul/2007:10:48:27 -0700] cupsdAuthorize: No authentication data provided.
D [10/Jul/2007:10:48:27 -0700] Get-Jobs ipp://localhost:631/printers/Samsung
D [10/Jul/2007:10:48:27 -0700] [Job 4] Loading attributes...
D [10/Jul/2007:10:48:27 -0700] cupsdProcessIPPRequest: 11 status_code=0 (successful-ok)
D [10/Jul/2007:10:48:27 -0700] [CGI] Finished "{printer_is_accepting_jobs=0", out=0xb7ead3a0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting "{printer_is_shared=0" at 846, result=0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Skip first part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 846...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 850 on character ':'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Output second part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 850...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 851 on character '}'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Finished "{printer_is_shared=0", out=0xb7ead3a0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting "{?device_uri=" at 877, result=0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Skip first part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 877...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 878 on character ':'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Output second part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 878...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{device_uri}" at 913...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 914 on character '}'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Finished "{?device_uri=", out=0xb7ead3a0...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{printer_uri_supported}" at 1028...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting "{?cupscommand=1" at 1154, result=0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Skip first part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 1154...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{printer_uri_supported}" at 1186...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{printer_uri_supported}" at 1334...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 1459 on character ':'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Output second part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 1459...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 1460 on character '}'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Finished "{?cupscommand=1", out=0xb7ead3a0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting "{printer_state=5" at 1487, result=0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Skip first part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 1487...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{admin_uri}" at 1508...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{printer_name}" at 1558...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 1646 on character ':'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Output second part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 1646...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{admin_uri}" at 1667...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{printer_name}" at 1716...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 1802 on character '}'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Finished "{printer_state=5", out=0xb7ead3a0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting "{printer_is_accepting_jobs=0" at 1832, result=0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Skip first part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 1832...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{admin_uri}" at 1853...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{printer_name}" at 1901...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 1985 on character ':'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Output second part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 1985...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{admin_uri}" at 2006...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{printer_name}" at 2054...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 2138 on character '}'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Finished "{printer_is_accepting_jobs=0", out=0xb7ead3a0...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{printer_uri_supported}" at 2171...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{printer_name}" at 2217...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{admin_uri}" at 2320...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{printer_name}" at 2367...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting "{printer_is_shared=0" at 2488, result=0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Skip first part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 2488...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{admin_uri}" at 2509...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{printer_name}" at 2557...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 2662 on character ':'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Output second part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 2662...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{admin_uri}" at 2683...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{printer_name}" at 2731...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 2840 on character '}'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Finished "{printer_is_shared=0", out=0xb7ead3a0...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{admin_uri}" at 2861...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{printer_name}" at 2912...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{admin_uri}" at 3021...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{printer_name}" at 3077...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{admin_uri}" at 3196...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{printer_name}" at 3247...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{admin_uri}" at 3356...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{printer_name}" at 3407...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{admin_uri}" at 3516...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{printer_name}" at 3570...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 3711 on character '}'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Finished looping on "printer_name"...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 3712 on character '}'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Finished "{#printer_name=0", out=0xb7ead3a0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 3713 on EOF...
D [10/Jul/2007:10:48:27 -0700] [CGI] cgiCopyTemplateLang(tmpl="printer-jobs-header.tmpl")
D [10/Jul/2007:10:48:27 -0700] [CGI] locale="en_ca"...
D [10/Jul/2007:10:48:27 -0700] [CGI] Template file is "/usr/share/cups/templates/printer-jobs-header.tmpl"...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 28 on EOF...
D [10/Jul/2007:10:48:27 -0700] [CGI] cgiCopyTemplateLang(tmpl="search.tmpl")
D [10/Jul/2007:10:48:27 -0700] [CGI] locale="en_ca"...
D [10/Jul/2007:10:48:27 -0700] [CGI] Template file is "/usr/share/cups/templates/search.tmpl"...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 0...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{SECTION}" at 24...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{?SEARCH_DEST}" at 39...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting "{WHICH_JOBS?" at 67, result=0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Skip first part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 67...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{WHICH_JOBS}" at 125...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 128 on character ':'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Output second part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 128...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 129 on character '}'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Finished "{WHICH_JOBS?", out=0xb7ead3a0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting "{ORDER?" at 137, result=1...
D [10/Jul/2007:10:48:27 -0700] [CGI] Output first part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 137...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{ORDER}" at 185...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 188 on character ':'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Skip second part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 188...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 189 on character '}'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Finished "{ORDER?", out=0xb7ead3a0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting "{SEARCH_DEST?" at 235, result=1...
D [10/Jul/2007:10:48:27 -0700] [CGI] Output first part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 235...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{SEARCH_DEST}" at 248...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 249 on character ':'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Skip second part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 249...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting "{SECTION=classes" at 266, result=0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Skip first part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 266...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 274 on character ':'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Output second part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 274...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting "{SECTION=jobs" at 288, result=0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Skip first part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 288...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 293 on character ':'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Output second part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 293...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 302 on character '}'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Finished "{SECTION=jobs", out=(nil)...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 303 on character '}'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Finished "{SECTION=classes", out=(nil)...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 304 on character '}'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Finished "{SEARCH_DEST?", out=0xb7ead3a0...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{?QUERY}" at 357...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{SECTION}" at 455...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{?SEARCH_DEST}" at 470...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting "{WHICH_JOBS?" at 482, result=0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Skip first part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 482...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{WHICH_JOBS}" at 506...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting "{ORDER?" at 513, result=1...
D [10/Jul/2007:10:48:27 -0700] [CGI] Output first part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 513...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{ORDER}" at 531...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 532 on character ':'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Skip second part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 532...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 533 on character '}'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Finished "{ORDER?", out=(nil)...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 534 on character ':'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Output second part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 534...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting "{ORDER?" at 541, result=1...
D [10/Jul/2007:10:48:27 -0700] [CGI] Output first part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 541...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{ORDER}" at 555...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 556 on character ':'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Skip second part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 556...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 557 on character '}'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Finished "{ORDER?", out=0xb7ead3a0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 558 on character '}'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Finished "{WHICH_JOBS?", out=0xb7ead3a0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 641 on EOF...
D [10/Jul/2007:10:48:27 -0700] [CGI] cgiCopyTemplateLang(tmpl="jobs-header.tmpl")
D [10/Jul/2007:10:48:27 -0700] [CGI] locale="en_ca"...
D [10/Jul/2007:10:48:27 -0700] [CGI] Template file is "/usr/share/cups/templates/jobs-header.tmpl"...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting "{?which_jobs=" at 17, result=1...
D [10/Jul/2007:10:48:27 -0700] [CGI] Output first part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 17...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting "{?printer_name=" at 42, result=0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Skip first part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 42...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 48 on character ':'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Output second part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 48...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{printer_uri_supported}" at 71...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 72 on character '}'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Finished "{?printer_name=", out=0xb7ead3a0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting "{?printer_name=" at 211, result=0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Skip first part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 211...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 217 on character ':'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Output second part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 217...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{printer_uri_supported}" at 240...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 241 on character '}'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Finished "{?printer_name=", out=0xb7ead3a0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 333 on character ':'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Skip second part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 333...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting "{which_jobs=all" at 349, result=0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Skip first part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 349...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting "{?printer_name=" at 374, result=0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Skip first part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 374...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 380 on character ':'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Output second part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 380...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{printer_uri_supported}" at 403...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 404 on character '}'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Finished "{?printer_name=", out=(nil)...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting "{?printer_name=" at 543, result=0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Skip first part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 543...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 549 on character ':'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Output second part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 549...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{printer_uri_supported}" at 572...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 573 on character '}'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Finished "{?printer_name=", out=(nil)...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 656 on character ':'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Output second part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 656...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting "{?printer_name=" at 681, result=0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Skip first part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 681...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 687 on character ':'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Output second part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 687...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{printer_uri_supported}" at 710...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 711 on character '}'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Finished "{?printer_name=", out=(nil)...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting "{?printer_name=" at 823, result=0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Skip first part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 823...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 829 on character ':'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Output second part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 829...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{printer_uri_supported}" at 852...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 853 on character '}'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Finished "{?printer_name=", out=(nil)...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 945 on character '}'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Finished "{which_jobs=all", out=(nil)...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 946 on character '}'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Finished "{?which_jobs=", out=0xb7ead3a0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting "{total=0" at 983, result=0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Skip first part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 983...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 991 on character ':'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Output second part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 991...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{#job_id}" at 1008...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{total}" at 1019...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting "{?which_jobs=" at 1034, result=1...
D [10/Jul/2007:10:48:27 -0700] [CGI] Output first part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 1034...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 1041 on character ':'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Skip second part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 1041...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting "{which_jobs=all" at 1057, result=0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Skip first part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 1057...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 1058 on character ':'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Output second part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 1058...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 1068 on character '}'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Finished "{which_jobs=all", out=(nil)...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 1069 on character '}'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Finished "{?which_jobs=", out=0xb7ead3a0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting "{total=1" at 1082, result=0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Skip first part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 1082...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 1083 on character ':'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Output second part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 1083...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 1085 on character '}'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Finished "{total=1", out=0xb7ead3a0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 1086 on character '}'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Finished "{total=0", out=0xb7ead3a0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 1092 on EOF...
D [10/Jul/2007:10:48:27 -0700] [CGI] cgiCopyTemplateLang(tmpl="pager.tmpl")
D [10/Jul/2007:10:48:27 -0700] [CGI] locale="en_ca"...
D [10/Jul/2007:10:48:27 -0700] [CGI] Template file is "/usr/share/cups/templates/pager.tmpl"...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting "{PREVURL?" at 87, result=0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Skip first part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 87...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{PREVURL}" at 105...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 191 on character ':'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Output second part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 191...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 198 on character '}'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Finished "{PREVURL?", out=0xb7ead3a0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting "{ORDER=dec" at 247, result=0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Skip first part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 247...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{THISURL}" at 265...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 367 on character ':'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Output second part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 367...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{THISURL}" at 385...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 489 on character '}'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Finished "{ORDER=dec", out=0xb7ead3a0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting "{NEXTURL?" at 535, result=0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Skip first part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 535...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{NEXTURL}" at 553...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 631 on character ':'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Output second part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 631...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 638 on character '}'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Finished "{NEXTURL?", out=0xb7ead3a0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 659 on EOF...
D [10/Jul/2007:10:48:27 -0700] [CGI] cgiCopyTemplateLang(tmpl="jobs.tmpl")
D [10/Jul/2007:10:48:27 -0700] [CGI] locale="en_ca"...
D [10/Jul/2007:10:48:27 -0700] [CGI] Template file is "/usr/share/cups/templates/jobs.tmpl"...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting "{#job_id=0" at 11, result=0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Skip first part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 11...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 12 on character ':'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Output second part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 12...
D [10/Jul/2007:10:48:27 -0700] [CGI] Looping on "job_id" at 277, count=4...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 277...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{job_printer_uri}" at 339...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{job_printer_name}" at 359...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{job_id}" at 372...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting "{?job_name=" at 400, result=0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Skip first part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 400...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 408 on character ':'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Output second part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 408...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{job_name}" at 418...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 419 on character '}'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Finished "{?job_name=", out=0xb7ead3a0...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{job_originating_user_name}" at 462...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{job_k_octets}" at 492...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting "{job_media_sheets_completed=0" at 539, result=1...
D [10/Jul/2007:10:48:27 -0700] [CGI] Output first part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 539...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 547 on character ':'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Skip second part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 547...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{?job_media_sheets_completed}" at 576...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 577 on character '}'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Finished "{job_media_sheets_completed=0", out=0xb7ead3a0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting "{job_state=3" at 606, result=0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Skip first part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 606...
D [10/Jul/2007:10:48:27 -0700] cupsdCloseClient: 11
D [10/Jul/2007:10:48:27 -0700] [CGI] "{time_at_creation}" at 641...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 642 on character ':'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Output second part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 642...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting "{job_state=4" at 655, result=0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Skip first part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 655...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{time_at_creation}" at 687...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 688 on character ':'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Output second part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 688...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting "{job_state=5" at 702, result=0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Skip first part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 702...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{time_at_processing}" at 742...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 743 on character ':'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Output second part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 743...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting "{job_state=6" at 756, result=1...
D [10/Jul/2007:10:48:27 -0700] [CGI] Output first part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 756...
D [10/Jul/2007:10:48:27 -0700] PID 5107 (/usr/lib/cups/cgi-bin/printers.cgi) exited with no errors.
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 764 on character ':'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Skip second part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 764...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting "{job_state=7" at 778, result=0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Skip first part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 778...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{time_at_completed}" at 812...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 813 on character ':'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Output second part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 813...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting "{job_state=8" at 826, result=0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Skip first part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 826...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 834 on character ':'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Output second part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 834...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{time_at_completed}" at 869...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 870 on character '}'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Finished "{job_state=8", out=(nil)...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 871 on character '}'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Finished "{job_state=7", out=(nil)...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 872 on character '}'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Finished "{job_state=6", out=0xb7ead3a0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 873 on character '}'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Finished "{job_state=5", out=0xb7ead3a0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 874 on character '}'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Finished "{job_state=4", out=0xb7ead3a0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 875 on character '}'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Finished "{job_state=3", out=0xb7ead3a0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting "{job_preserved>0" at 909, result=1...
D [10/Jul/2007:10:48:27 -0700] [CGI] Output first part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 909...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{job_id}" at 960...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{job_printer_uri}" at 998...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 1081 on character ':'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Skip second part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 1081...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 1082 on character '}'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Finished "{job_preserved>0", out=0xb7ead3a0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting "{job_state=4" at 1096, result=0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Skip first part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 1096...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{job_id}" at 1147...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{job_printer_uri}" at 1185...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 1268 on character ':'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Output second part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 1268...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 1269 on character '}'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Finished "{job_state=4", out=0xb7ead3a0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting "{job_state=3" at 1283, result=0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Skip first part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 1283...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{job_id}" at 1331...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{job_printer_uri}" at 1369...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 1446 on character ':'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Output second part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 1446...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 1447 on character '}'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Finished "{job_state=3", out=0xb7ead3a0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting "{job_state<7" at 1461, result=1...
D [10/Jul/2007:10:48:27 -0700] [CGI] Output first part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 1461...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{job_id}" at 1511...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{job_printer_uri}" at 1549...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{job_id}" at 1677...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 1753 on character ':'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Skip second part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 1753...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 1754 on character '}'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Finished "{job_state<7", out=0xb7ead3a0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 1774 on character '}'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 277...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{job_printer_uri}" at 339...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{job_printer_name}" at 359...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{job_id}" at 372...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting "{?job_name=" at 400, result=0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Skip first part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 400...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 408 on character ':'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Output second part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 408...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{job_name}" at 418...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 419 on character '}'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Finished "{?job_name=", out=0xb7ead3a0...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{job_originating_user_name}" at 462...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{job_k_octets}" at 492...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting "{job_media_sheets_completed=0" at 539, result=1...
D [10/Jul/2007:10:48:27 -0700] [CGI] Output first part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 539...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 547 on character ':'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Skip second part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 547...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{?job_media_sheets_completed}" at 576...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 577 on character '}'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Finished "{job_media_sheets_completed=0", out=0xb7ead3a0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting "{job_state=3" at 606, result=0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Skip first part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 606...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{time_at_creation}" at 641...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 642 on character ':'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Output second part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 642...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting "{job_state=4" at 655, result=0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Skip first part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 655...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{time_at_creation}" at 687...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 688 on character ':'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Output second part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 688...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting "{job_state=5" at 702, result=0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Skip first part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 702...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{time_at_processing}" at 742...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 743 on character ':'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Output second part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 743...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting "{job_state=6" at 756, result=1...
D [10/Jul/2007:10:48:27 -0700] [CGI] Output first part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 756...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 764 on character ':'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Skip second part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 764...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting "{job_state=7" at 778, result=0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Skip first part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 778...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{time_at_completed}" at 812...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 813 on character ':'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Output second part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 813...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting "{job_state=8" at 826, result=0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Skip first part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 826...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 834 on character ':'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Output second part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 834...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{time_at_completed}" at 869...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 870 on character '}'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Finished "{job_state=8", out=(nil)...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 871 on character '}'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Finished "{job_state=7", out=(nil)...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 872 on character '}'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Finished "{job_state=6", out=0xb7ead3a0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 873 on character '}'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Finished "{job_state=5", out=0xb7ead3a0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 874 on character '}'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Finished "{job_state=4", out=0xb7ead3a0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 875 on character '}'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Finished "{job_state=3", out=0xb7ead3a0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting "{job_preserved>0" at 909, result=1...
D [10/Jul/2007:10:48:27 -0700] [CGI] Output first part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 909...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{job_id}" at 960...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{job_printer_uri}" at 998...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 1081 on character ':'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Skip second part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 1081...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 1082 on character '}'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Finished "{job_preserved>0", out=0xb7ead3a0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting "{job_state=4" at 1096, result=0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Skip first part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 1096...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{job_id}" at 1147...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{job_printer_uri}" at 1185...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 1268 on character ':'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Output second part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 1268...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 1269 on character '}'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Finished "{job_state=4", out=0xb7ead3a0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting "{job_state=3" at 1283, result=0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Skip first part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 1283...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{job_id}" at 1331...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{job_printer_uri}" at 1369...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 1446 on character ':'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Output second part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 1446...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 1447 on character '}'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Finished "{job_state=3", out=0xb7ead3a0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting "{job_state<7" at 1461, result=1...
D [10/Jul/2007:10:48:27 -0700] [CGI] Output first part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 1461...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{job_id}" at 1511...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{job_printer_uri}" at 1549...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{job_id}" at 1677...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 1753 on character ':'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Skip second part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 1753...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 1754 on character '}'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Finished "{job_state<7", out=0xb7ead3a0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 1774 on character '}'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 277...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{job_printer_uri}" at 339...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{job_printer_name}" at 359...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{job_id}" at 372...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting "{?job_name=" at 400, result=0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Skip first part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 400...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 408 on character ':'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Output second part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 408...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{job_name}" at 418...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 419 on character '}'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Finished "{?job_name=", out=0xb7ead3a0...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{job_originating_user_name}" at 462...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{job_k_octets}" at 492...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting "{job_media_sheets_completed=0" at 539, result=1...
D [10/Jul/2007:10:48:27 -0700] [CGI] Output first part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 539...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 547 on character ':'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Skip second part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 547...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{?job_media_sheets_completed}" at 576...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 577 on character '}'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Finished "{job_media_sheets_completed=0", out=0xb7ead3a0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting "{job_state=3" at 606, result=0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Skip first part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 606...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{time_at_creation}" at 641...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 642 on character ':'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Output second part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 642...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting "{job_state=4" at 655, result=0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Skip first part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 655...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{time_at_creation}" at 687...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 688 on character ':'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Output second part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 688...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting "{job_state=5" at 702, result=0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Skip first part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 702...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{time_at_processing}" at 742...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 743 on character ':'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Output second part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 743...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting "{job_state=6" at 756, result=1...
D [10/Jul/2007:10:48:27 -0700] [CGI] Output first part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 756...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 764 on character ':'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Skip second part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 764...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting "{job_state=7" at 778, result=0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Skip first part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 778...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{time_at_completed}" at 812...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 813 on character ':'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Output second part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 813...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting "{job_state=8" at 826, result=0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Skip first part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 826...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 834 on character ':'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Output second part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 834...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{time_at_completed}" at 869...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 870 on character '}'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Finished "{job_state=8", out=(nil)...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 871 on character '}'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Finished "{job_state=7", out=(nil)...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 872 on character '}'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Finished "{job_state=6", out=0xb7ead3a0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 873 on character '}'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Finished "{job_state=5", out=0xb7ead3a0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 874 on character '}'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Finished "{job_state=4", out=0xb7ead3a0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 875 on character '}'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Finished "{job_state=3", out=0xb7ead3a0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting "{job_preserved>0" at 909, result=1...
D [10/Jul/2007:10:48:27 -0700] [CGI] Output first part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 909...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{job_id}" at 960...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{job_printer_uri}" at 998...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 1081 on character ':'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Skip second part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 1081...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 1082 on character '}'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Finished "{job_preserved>0", out=0xb7ead3a0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting "{job_state=4" at 1096, result=0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Skip first part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 1096...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{job_id}" at 1147...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{job_printer_uri}" at 1185...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 1268 on character ':'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Output second part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 1268...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 1269 on character '}'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Finished "{job_state=4", out=0xb7ead3a0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting "{job_state=3" at 1283, result=0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Skip first part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 1283...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{job_id}" at 1331...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{job_printer_uri}" at 1369...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 1446 on character ':'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Output second part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 1446...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 1447 on character '}'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Finished "{job_state=3", out=0xb7ead3a0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting "{job_state<7" at 1461, result=1...
D [10/Jul/2007:10:48:27 -0700] [CGI] Output first part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 1461...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{job_id}" at 1511...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{job_printer_uri}" at 1549...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{job_id}" at 1677...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 1753 on character ':'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Skip second part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 1753...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 1754 on character '}'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Finished "{job_state<7", out=0xb7ead3a0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 1774 on character '}'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 277...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{job_printer_uri}" at 339...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{job_printer_name}" at 359...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{job_id}" at 372...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting "{?job_name=" at 400, result=0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Skip first part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 400...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 408 on character ':'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Output second part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 408...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{job_name}" at 418...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 419 on character '}'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Finished "{?job_name=", out=0xb7ead3a0...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{job_originating_user_name}" at 462...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{job_k_octets}" at 492...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting "{job_media_sheets_completed=0" at 539, result=1...
D [10/Jul/2007:10:48:27 -0700] [CGI] Output first part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 539...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 547 on character ':'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Skip second part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 547...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{?job_media_sheets_completed}" at 576...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 577 on character '}'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Finished "{job_media_sheets_completed=0", out=0xb7ead3a0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting "{job_state=3" at 606, result=0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Skip first part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 606...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{time_at_creation}" at 641...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 642 on character ':'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Output second part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 642...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting "{job_state=4" at 655, result=0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Skip first part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 655...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{time_at_creation}" at 687...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 688 on character ':'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Output second part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 688...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting "{job_state=5" at 702, result=0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Skip first part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 702...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{time_at_processing}" at 742...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 743 on character ':'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Output second part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 743...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting "{job_state=6" at 756, result=1...
D [10/Jul/2007:10:48:27 -0700] [CGI] Output first part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 756...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 764 on character ':'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Skip second part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 764...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting "{job_state=7" at 778, result=0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Skip first part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 778...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{time_at_completed}" at 812...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 813 on character ':'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Output second part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 813...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting "{job_state=8" at 826, result=0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Skip first part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 826...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 834 on character ':'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Output second part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 834...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{time_at_completed}" at 869...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 870 on character '}'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Finished "{job_state=8", out=(nil)...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 871 on character '}'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Finished "{job_state=7", out=(nil)...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 872 on character '}'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Finished "{job_state=6", out=0xb7ead3a0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 873 on character '}'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Finished "{job_state=5", out=0xb7ead3a0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 874 on character '}'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Finished "{job_state=4", out=0xb7ead3a0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 875 on character '}'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Finished "{job_state=3", out=0xb7ead3a0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting "{job_preserved>0" at 909, result=1...
D [10/Jul/2007:10:48:27 -0700] [CGI] Output first part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 909...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{job_id}" at 960...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{job_printer_uri}" at 998...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 1081 on character ':'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Skip second part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 1081...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 1082 on character '}'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Finished "{job_preserved>0", out=0xb7ead3a0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting "{job_state=4" at 1096, result=0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Skip first part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 1096...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{job_id}" at 1147...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{job_printer_uri}" at 1185...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 1268 on character ':'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Output second part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 1268...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 1269 on character '}'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Finished "{job_state=4", out=0xb7ead3a0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting "{job_state=3" at 1283, result=0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Skip first part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 1283...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{job_id}" at 1331...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{job_printer_uri}" at 1369...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 1446 on character ':'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Output second part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 1446...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 1447 on character '}'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Finished "{job_state=3", out=0xb7ead3a0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting "{job_state<7" at 1461, result=1...
D [10/Jul/2007:10:48:27 -0700] [CGI] Output first part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 1461...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{job_id}" at 1511...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{job_printer_uri}" at 1549...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{job_id}" at 1677...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 1753 on character ':'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Skip second part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 1753...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 1754 on character '}'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Finished "{job_state<7", out=0xb7ead3a0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 1774 on character '}'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Finished looping on "job_id"...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 1785 on character '}'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Finished "{#job_id=0", out=0xb7ead3a0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 1786 on EOF...
D [10/Jul/2007:10:48:27 -0700] [CGI] cgiCopyTemplateLang(tmpl="pager.tmpl")
D [10/Jul/2007:10:48:27 -0700] [CGI] locale="en_ca"...
D [10/Jul/2007:10:48:27 -0700] [CGI] Template file is "/usr/share/cups/templates/pager.tmpl"...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting "{PREVURL?" at 87, result=0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Skip first part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 87...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{PREVURL}" at 105...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 191 on character ':'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Output second part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 191...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 198 on character '}'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Finished "{PREVURL?", out=0xb7ead3a0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting "{ORDER=dec" at 247, result=0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Skip first part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 247...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{THISURL}" at 265...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 367 on character ':'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Output second part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 367...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{THISURL}" at 385...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 489 on character '}'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Finished "{ORDER=dec", out=0xb7ead3a0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting "{NEXTURL?" at 535, result=0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Skip first part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 535...
D [10/Jul/2007:10:48:27 -0700] [CGI] "{NEXTURL}" at 553...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 631 on character ':'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Output second part...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 631...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 638 on character '}'...
D [10/Jul/2007:10:48:27 -0700] [CGI] Finished "{NEXTURL?", out=0xb7ead3a0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 659 on EOF...
D [10/Jul/2007:10:48:27 -0700] [CGI] cgiCopyTemplateLang(tmpl="trailer.tmpl")
D [10/Jul/2007:10:48:27 -0700] [CGI] locale="en_ca"...
D [10/Jul/2007:10:48:27 -0700] [CGI] Template file is "/usr/share/cups/templates/trailer.tmpl"...
D [10/Jul/2007:10:48:27 -0700] [CGI] Starting at file position 0...
D [10/Jul/2007:10:48:27 -0700] [CGI] Returning at file position 614 on EOF...


#
# "$Id: cupsd.conf.in 6268 2007-02-12 02:46:11Z mike $"
#
#   Sample configuration file for the Common UNIX Printing System (CUPS)
#   scheduler.  See "man cupsd.conf" for a complete description of this
#   file.
#

# Log general information in error_log - change "info" to "debug" for
# troubleshooting...
LogLevel debug

# Administrator user group...
SystemGroup lp sys root
User lp
Group lp

# Only listen for connections from the local machine.
Listen *:631
Listen /var/run/cups/cups.sock
DefaultEncryption Never
MaxJobs 10
PreserveJobHistory Off
# Show shared printers on the local network.
Browsing On
BrowseOrder allow,deny
BrowseAllow all

# Default authentication type, when authentication is required...
DefaultAuthType Basic

# Restrict access to the server...
<Location />
  Order allow,deny
  Allow All
</Location>

# Restrict access to the admin pages...
<Location /admin>

  Order allow,deny
  Allow All
</Location>

# Restrict access to configuration files...
<Location /admin/conf>
  AuthType Basic
  Require user @SYSTEM
  Order allow,deny
  Allow All
</Location>

# Set the default printer/job policies...
<Policy default>
  # Job-related operations must be done by the owner or an adminstrator...
  <Limit Send-Document Send-URI Hold-Job Release-Job Restart-Job Purge-Jobs Set-Job-Attributes Create-Job-Subscription Renew-Subscription Cancel-Subscription Get-Notifications Reprocess-Job Cancel-Current-Job Suspend-Current-Job Resume-Job CUPS-Move-Job>
    Require user @OWNER @SYSTEM
    Order deny,allow
  </Limit>

  # All administration operations require an adminstrator to authenticate...
  <Limit Pause-Printer Resume-Printer Set-Printer-Attributes Enable-Printer Disable-Printer Pause-Printer-After-Current-Job Hold-New-Jobs Release-Held-New-Jobs Deactivate-Printer Activate-Printer Restart-Printer Shutdown-Printer Startup-Printer Promote-Job Schedule-Job-After CUPS-Add-Printer CUPS-Delete-Printer CUPS-Add-Class CUPS-Delete-Class CUPS-Accept-Jobs CUPS-Reject-Jobs CUPS-Set-Default>
    AuthType Basic
    Require user @SYSTEM
    Order deny,allow
  </Limit>

  # Only the owner or an administrator can cancel or authenticate a job...
  <Limit Cancel-Job CUPS-Authenticate-Job>
    Require user @OWNER @SYSTEM
    Order deny,allow
  </Limit>

  <Limit All>
    Order deny,allow
  </Limit>
</Policy>

#
# End of "$Id: cupsd.conf.in 6268 2007-02-12 02:46:11Z mike $".
#

#ls -al /var/spool/cups

total 96
drwx--x--- 4 root nogroup   456 Jul 10 10:48 .
drwxr-xr-x 6 root staff      72 Jul 10 10:24 ..
-rw------- 1 root nogroup   645 Jul 10 10:42 c00001
-rw------- 1 root nogroup   645 Jul 10 10:43 c00002
-rw------- 1 root nogroup   645 Jul 10 10:46 c00003
-rw------- 1 root nogroup   645 Jul 10 10:48 c00004
-rw-r----- 1 root nogroup 18441 Jul 10 10:42 d00001-001
-rw-r----- 1 root nogroup 18441 Jul 10 10:43 d00002-001
-rw-r----- 1 root nogroup 18441 Jul 10 10:46 d00003-001
-rw-r----- 1 root nogroup 18441 Jul 10 10:48 d00004-001
drwxrwx--T 2 root nogroup    80 Jul 10 10:42 tmp

More information about the cups mailing list