Attachment 145681 Details for Bug 222639 – /var/log/cups/error_log (debug)

/var/log/cups/error_log (debug)

var_log_cups_error_log_debug.txt (text/plain), 88.13 KB, created by Tim Wegener on 2007-01-16 12:21:11 UTC

(hide)

Description:

Filename:

MIME Type:

Creator: Tim Wegener

Created: 2007-01-16 12:21:11 UTC

Size: 88.13 KB

patch

obsolete

>I [14/Jan/2007:20:18:51 +1030] Listening to 127.0.0.1:631 (IPv4)
>I [14/Jan/2007:20:18:51 +1030] Listening to ::1:631 (IPv6)
>I [14/Jan/2007:20:18:51 +1030] Listening to /var/run/cups/cups.sock (Domain)
>I [14/Jan/2007:20:18:51 +1030] Loaded configuration file "/etc/cups/cupsd.conf"
>I [14/Jan/2007:20:18:51 +1030] Using default TempDir of /var/spool/cups/tmp...
>I [14/Jan/2007:20:18:51 +1030] Cleaning out old temporary files in "/var/spool/cups/tmp"...
>I [14/Jan/2007:20:18:51 +1030] Configured for up to 100 clients.
>I [14/Jan/2007:20:18:51 +1030] Allowing up to 100 client connections per host.
>I [14/Jan/2007:20:18:51 +1030] Using policy "default" as the default!
>I [14/Jan/2007:20:18:51 +1030] Full reload is required.
>I [14/Jan/2007:20:18:51 +1030] Saving job cache file "/var/cache/cups/job.cache"...
>I [14/Jan/2007:20:18:51 +1030] Loaded MIME database from '/etc/cups': 34 types, 38 filters...
>I [14/Jan/2007:20:18:51 +1030] Loading job cache file "/var/cache/cups/job.cache"...
>I [14/Jan/2007:20:18:51 +1030] Full reload complete.
>I [14/Jan/2007:20:18:51 +1030] Listening to 127.0.0.1:631 on fd 2...
>I [14/Jan/2007:20:18:51 +1030] Listening to ::1:631 on fd 4...
>I [14/Jan/2007:20:18:51 +1030] Listening to /var/run/cups/cups.sock on fd 5...
>I [14/Jan/2007:20:51:56 +1030] Adding start banner page "none" to job 5.
>I [14/Jan/2007:20:51:56 +1030] Adding end banner page "none" to job 5.
>I [14/Jan/2007:20:51:56 +1030] Job 5 queued on "Photosmart_C4100_series" by "tim".
>I [14/Jan/2007:20:51:56 +1030] Started filter /usr/lib/cups/filter/pstops (PID 10507) for job 5.
>I [14/Jan/2007:20:51:56 +1030] Started filter /usr/lib/cups/filter/foomatic-rip (PID 10508) for job 5.
>I [14/Jan/2007:20:51:56 +1030] Started backend /usr/lib/cups/backend/hal (PID 10509) for job 5.
>I [14/Jan/2007:21:01:14 +1030] Started "/usr/lib/cups/daemon/cups-deviced" (pid=10984)
>I [14/Jan/2007:21:06:06 +1030] Started "/usr/lib/cups/daemon/cups-driverd" (pid=11215)
>E [14/Jan/2007:21:08:00 +1030] cupsdAuthorize: Local authentication certificate not found!
>E [14/Jan/2007:21:08:09 +1030] cupsdAuthorize: Local authentication certificate not found!
>I [14/Jan/2007:21:12:59 +1030] Saving printers.conf...
>I [14/Jan/2007:21:12:59 +1030] Printer "Photosmart_C4100_series" stopped by "root".
>I [14/Jan/2007:21:13:10 +1030] Scheduler shutting down normally.
>I [14/Jan/2007:21:13:10 +1030] Saving remote.cache...
>I [14/Jan/2007:21:13:10 +1030] Saving job cache file "/var/cache/cups/job.cache"...
>I [15/Jan/2007:20:09:15 +1030] Listening to 127.0.0.1:631 (IPv4)
>I [15/Jan/2007:20:09:15 +1030] Listening to ::1:631 (IPv6)
>I [15/Jan/2007:20:09:15 +1030] Listening to /var/run/cups/cups.sock (Domain)
>I [15/Jan/2007:20:09:15 +1030] Loaded configuration file "/etc/cups/cupsd.conf"
>I [15/Jan/2007:20:09:15 +1030] Using default TempDir of /var/spool/cups/tmp...
>I [15/Jan/2007:20:09:15 +1030] Cleaning out old temporary files in "/var/spool/cups/tmp"...
>I [15/Jan/2007:20:09:15 +1030] Configured for up to 100 clients.
>I [15/Jan/2007:20:09:15 +1030] Allowing up to 100 client connections per host.
>I [15/Jan/2007:20:09:15 +1030] Using policy "default" as the default!
>I [15/Jan/2007:20:09:15 +1030] Full reload is required.
>I [15/Jan/2007:20:09:15 +1030] Loaded MIME database from '/etc/cups': 34 types, 38 filters...
>I [15/Jan/2007:20:09:16 +1030] Loading job cache file "/var/cache/cups/job.cache"...
>I [15/Jan/2007:20:09:16 +1030] Full reload complete.
>I [15/Jan/2007:20:09:16 +1030] Listening to 127.0.0.1:631 on fd 3...
>I [15/Jan/2007:20:09:16 +1030] Listening to ::1:631 on fd 4...
>I [15/Jan/2007:20:09:16 +1030] Listening to /var/run/cups/cups.sock on fd 5...
>I [15/Jan/2007:20:18:39 +1030] Saving printers.conf...
>I [15/Jan/2007:20:18:39 +1030] Printer "Photosmart_C4100_series" started by "root".
>I [15/Jan/2007:20:19:28 +1030] Adding start banner page "none" to job 6.
>I [15/Jan/2007:20:19:28 +1030] Adding end banner page "none" to job 6.
>I [15/Jan/2007:20:19:28 +1030] Job 6 queued on "Photosmart_C4100_series" by "lorinda".
>I [15/Jan/2007:20:19:28 +1030] Started filter /usr/lib/cups/filter/pstops (PID 2829) for job 6.
>I [15/Jan/2007:20:19:28 +1030] Started filter /usr/lib/cups/filter/foomatic-rip (PID 2830) for job 6.
>I [15/Jan/2007:20:19:28 +1030] Started backend /usr/lib/cups/backend/hal (PID 2831) for job 6.
>E [15/Jan/2007:22:39:47 +1030] CUPS-Add-Modify-Printer: Unauthorized
>I [15/Jan/2007:22:39:47 +1030] Setting Photosmart_C4100 device-uri to "hp:/usb/Photosmart_C4100_series?serial=MY65CB919404J7" (was "file:/dev/null".)
>I [15/Jan/2007:22:39:47 +1030] Setting Photosmart_C4100 printer-is-accepting-jobs to 1 (was 0.)
>I [15/Jan/2007:22:39:47 +1030] Setting Photosmart_C4100 printer-state to 3 (was 5.)
>I [15/Jan/2007:22:39:47 +1030] Saving printers.conf...
>I [15/Jan/2007:22:39:47 +1030] New printer "Photosmart_C4100" added by "root".
>I [15/Jan/2007:22:40:35 +1030] Adding start banner page "none" to job 7.
>I [15/Jan/2007:22:40:35 +1030] Adding end banner page "none" to job 7.
>I [15/Jan/2007:22:40:35 +1030] Job 7 queued on "Photosmart_C4100" by "root".
>I [15/Jan/2007:22:40:35 +1030] Started filter /usr/lib/cups/filter/pstops (PID 8704) for job 7.
>I [15/Jan/2007:22:40:35 +1030] Started filter /usr/lib/cups/filter/foomatic-rip (PID 8705) for job 7.
>I [15/Jan/2007:22:40:35 +1030] Started backend /usr/lib/cups/backend/hp (PID 8706) for job 7.
>I [15/Jan/2007:22:40:37 +1030] Saving printers.conf...
>I [15/Jan/2007:22:40:37 +1030] Printer "Photosmart_C4100_series" stopped by "root".
>I [15/Jan/2007:23:15:41 +1030] Adding start banner page "none" to job 8.
>I [15/Jan/2007:23:15:41 +1030] Adding end banner page "none" to job 8.
>I [15/Jan/2007:23:15:41 +1030] Job 8 queued on "Photosmart_C4100" by "tim".
>I [15/Jan/2007:23:15:41 +1030] Started filter /usr/lib/cups/filter/pstops (PID 9451) for job 8.
>I [15/Jan/2007:23:15:41 +1030] Started filter /usr/lib/cups/filter/foomatic-rip (PID 9452) for job 8.
>I [15/Jan/2007:23:15:41 +1030] Started backend /usr/lib/cups/backend/hp (PID 9453) for job 8.
>E [15/Jan/2007:23:15:55 +1030] PID 9452 (/usr/lib/cups/filter/foomatic-rip) stopped with status 3!
>I [15/Jan/2007:23:15:55 +1030] Hint: Try setting the LogLevel to "debug" to find out more.
>I [15/Jan/2007:23:17:03 +1030] Adding start banner page "none" to job 9.
>I [15/Jan/2007:23:17:03 +1030] Adding end banner page "none" to job 9.
>I [15/Jan/2007:23:17:03 +1030] Job 9 queued on "Photosmart_C4100_series" by "tim".
>I [15/Jan/2007:23:17:51 +1030] Started "/usr/lib/cups/cgi-bin/printers.cgi" (pid=9577)
>I [15/Jan/2007:23:18:06 +1030] Started "/usr/lib/cups/cgi-bin/admin.cgi" (pid=9578)
>E [15/Jan/2007:23:18:07 +1030] Resume-Printer: Unauthorized
>I [15/Jan/2007:23:18:16 +1030] Started "/usr/lib/cups/cgi-bin/admin.cgi" (pid=9582)
>E [15/Jan/2007:23:18:16 +1030] Resume-Printer: Unauthorized
>I [15/Jan/2007:23:18:16 +1030] Saving printers.conf...
>I [15/Jan/2007:23:18:16 +1030] Printer "Photosmart_C4100_series" started by "root".
>I [15/Jan/2007:23:18:16 +1030] Started filter /usr/lib/cups/filter/pstops (PID 9583) for job 9.
>I [15/Jan/2007:23:18:16 +1030] Started filter /usr/lib/cups/filter/foomatic-rip (PID 9584) for job 9.
>I [15/Jan/2007:23:18:16 +1030] Started backend /usr/lib/cups/backend/hal (PID 9585) for job 9.
>E [15/Jan/2007:23:18:17 +1030] [Job 9] Unable to open HAL device "hal:///org/freedesktop/Hal/devices/usb_device_3f0_5711_MY65CB919404J7_if1_printer_MY65CB919404J7"
>E [15/Jan/2007:23:18:18 +1030] PID 9585 (/usr/lib/cups/backend/hal) stopped with status 1!
>I [15/Jan/2007:23:18:18 +1030] Hint: Try setting the LogLevel to "debug" to find out more.
>I [15/Jan/2007:23:18:24 +1030] Started "/usr/lib/cups/cgi-bin/admin.cgi" (pid=9594)
>I [15/Jan/2007:23:18:24 +1030] Started "/usr/lib/cups/cgi-bin/jobs.cgi" (pid=9595)
>E [15/Jan/2007:23:19:06 +1030] PID 9584 (/usr/lib/cups/filter/foomatic-rip) stopped with status 9!
>I [15/Jan/2007:23:19:06 +1030] Hint: Try setting the LogLevel to "debug" to find out more.
>I [15/Jan/2007:23:19:06 +1030] [Job 9] Backend returned status 1 (failed)
>I [15/Jan/2007:23:19:06 +1030] Saving printers.conf...
>I [15/Jan/2007:23:19:37 +1030] Started "/usr/lib/cups/cgi-bin/printers.cgi" (pid=9602)
>I [15/Jan/2007:23:21:44 +1030] Started "/usr/lib/cups/cgi-bin/jobs.cgi" (pid=9635)
>I [15/Jan/2007:23:21:49 +1030] Started "/usr/lib/cups/cgi-bin/printers.cgi" (pid=9637)
>I [15/Jan/2007:23:22:03 +1030] Started "/usr/lib/cups/cgi-bin/jobs.cgi" (pid=9639)
>E [15/Jan/2007:23:22:03 +1030] Restart-Job: Unauthorized
>I [15/Jan/2007:23:22:03 +1030] Started "/usr/lib/cups/cgi-bin/jobs.cgi" (pid=9642)
>I [15/Jan/2007:23:22:03 +1030] Started filter /usr/lib/cups/filter/pstops (PID 9643) for job 8.
>I [15/Jan/2007:23:22:03 +1030] Started filter /usr/lib/cups/filter/foomatic-rip (PID 9644) for job 8.
>I [15/Jan/2007:23:22:03 +1030] Started backend /usr/lib/cups/backend/hp (PID 9645) for job 8.
>I [15/Jan/2007:23:22:03 +1030] Job 8 was restarted by "root".
>I [15/Jan/2007:23:22:11 +1030] Started "/usr/lib/cups/cgi-bin/jobs.cgi" (pid=9670)
>E [15/Jan/2007:23:22:34 +1030] PID 9644 (/usr/lib/cups/filter/foomatic-rip) stopped with status 3!
>I [15/Jan/2007:23:22:34 +1030] Hint: Try setting the LogLevel to "debug" to find out more.
>I [15/Jan/2007:23:22:54 +1030] Started "/usr/lib/cups/cgi-bin/jobs.cgi" (pid=9688)
>I [15/Jan/2007:23:23:01 +1030] Started "/usr/lib/cups/cgi-bin/printers.cgi" (pid=9689)
>I [15/Jan/2007:23:24:43 +1030] Adding start banner page "none" to job 10.
>I [15/Jan/2007:23:24:43 +1030] Adding end banner page "none" to job 10.
>I [15/Jan/2007:23:24:43 +1030] Job 10 queued on "Photosmart_C4100" by "tim".
>I [15/Jan/2007:23:24:43 +1030] Started filter /usr/lib/cups/filter/pstops (PID 9753) for job 10.
>I [15/Jan/2007:23:24:43 +1030] Started filter /usr/lib/cups/filter/foomatic-rip (PID 9754) for job 10.
>I [15/Jan/2007:23:24:43 +1030] Started backend /usr/lib/cups/backend/hp (PID 9755) for job 10.
>I [15/Jan/2007:23:31:35 +1030] Started "/usr/lib/cups/daemon/cups-deviced" (pid=9830)
>I [15/Jan/2007:23:34:21 +1030] Adding start banner page "none" to job 11.
>I [15/Jan/2007:23:34:21 +1030] Adding end banner page "none" to job 11.
>I [15/Jan/2007:23:34:21 +1030] Job 11 queued on "Photosmart_C4100" by "tim".
>I [15/Jan/2007:23:34:21 +1030] Started filter /usr/lib/cups/filter/pstops (PID 9882) for job 11.
>I [15/Jan/2007:23:34:21 +1030] Started filter /usr/lib/cups/filter/foomatic-rip (PID 9883) for job 11.
>I [15/Jan/2007:23:34:21 +1030] Started backend /usr/lib/cups/backend/hp (PID 9884) for job 11.
>I [16/Jan/2007:21:52:09 +1030] Listening to 127.0.0.1:631 (IPv4)
>I [16/Jan/2007:21:52:09 +1030] Listening to ::1:631 (IPv6)
>I [16/Jan/2007:21:52:09 +1030] Listening to /var/run/cups/cups.sock (Domain)
>I [16/Jan/2007:21:52:09 +1030] Loaded configuration file "/etc/cups/cupsd.conf"
>I [16/Jan/2007:21:52:09 +1030] Using default TempDir of /var/spool/cups/tmp...
>I [16/Jan/2007:21:52:09 +1030] Cleaning out old temporary files in "/var/spool/cups/tmp"...
>I [16/Jan/2007:21:52:09 +1030] Configured for up to 100 clients.
>I [16/Jan/2007:21:52:09 +1030] Allowing up to 100 client connections per host.
>I [16/Jan/2007:21:52:09 +1030] Using policy "default" as the default!
>I [16/Jan/2007:21:52:09 +1030] Full reload is required.
>I [16/Jan/2007:21:52:09 +1030] Loaded MIME database from '/etc/cups': 34 types, 38 filters...
>I [16/Jan/2007:21:52:09 +1030] Loading job cache file "/var/cache/cups/job.cache"...
>I [16/Jan/2007:21:52:09 +1030] Full reload complete.
>I [16/Jan/2007:21:52:09 +1030] Listening to 127.0.0.1:631 on fd 3...
>I [16/Jan/2007:21:52:09 +1030] Listening to ::1:631 on fd 4...
>I [16/Jan/2007:21:52:09 +1030] Listening to /var/run/cups/cups.sock on fd 5...
>I [16/Jan/2007:22:16:03 +1030] Started "/usr/lib/cups/cgi-bin/jobs.cgi" (pid=2730)
>I [16/Jan/2007:22:32:20 +1030] Saving printers.conf...
>I [16/Jan/2007:22:32:20 +1030] Printer "Photosmart_C4100_series" started by "root".
>I [16/Jan/2007:22:33:24 +1030] Saving printers.conf...
>I [16/Jan/2007:22:33:24 +1030] Printer "Photosmart_C4100_series" stopped by "root".
>I [16/Jan/2007:22:34:44 +1030] Scheduler shutting down normally.
>I [16/Jan/2007:22:34:44 +1030] Saving remote.cache...
>I [16/Jan/2007:22:34:44 +1030] Saving job cache file "/var/cache/cups/job.cache"...
>I [16/Jan/2007:22:34:44 +1030] Listening to 127.0.0.1:631 (IPv4)
>I [16/Jan/2007:22:34:44 +1030] Listening to ::1:631 (IPv6)
>I [16/Jan/2007:22:34:44 +1030] Listening to /var/run/cups/cups.sock (Domain)
>I [16/Jan/2007:22:34:44 +1030] Loaded configuration file "/etc/cups/cupsd.conf"
>I [16/Jan/2007:22:34:44 +1030] Using default TempDir of /var/spool/cups/tmp...
>I [16/Jan/2007:22:34:44 +1030] Cleaning out old temporary files in "/var/spool/cups/tmp"...
>I [16/Jan/2007:22:34:44 +1030] Configured for up to 100 clients.
>I [16/Jan/2007:22:34:44 +1030] Allowing up to 100 client connections per host.
>I [16/Jan/2007:22:34:44 +1030] Using policy "default" as the default!
>I [16/Jan/2007:22:34:44 +1030] Full reload is required.
>I [16/Jan/2007:22:34:44 +1030] Loaded MIME database from '/etc/cups': 34 types, 38 filters...
>D [16/Jan/2007:22:34:44 +1030] Loading printer Photosmart_C4100...
>D [16/Jan/2007:22:34:44 +1030] Loading printer Photosmart_C4100_series...
>I [16/Jan/2007:22:34:44 +1030] Loading job cache file "/var/cache/cups/job.cache"...
>D [16/Jan/2007:22:34:44 +1030] Loading job 1 from cache...
>D [16/Jan/2007:22:34:44 +1030] Loading job 2 from cache...
>D [16/Jan/2007:22:34:44 +1030] Loading job 3 from cache...
>D [16/Jan/2007:22:34:44 +1030] Loading job 4 from cache...
>D [16/Jan/2007:22:34:44 +1030] Loading job 5 from cache...
>D [16/Jan/2007:22:34:44 +1030] Loading job 6 from cache...
>D [16/Jan/2007:22:34:44 +1030] Loading job 7 from cache...
>D [16/Jan/2007:22:34:44 +1030] Loading job 8 from cache...
>D [16/Jan/2007:22:34:44 +1030] Loading job 9 from cache...
>D [16/Jan/2007:22:34:44 +1030] Loading job 10 from cache...
>D [16/Jan/2007:22:34:44 +1030] Loading job 11 from cache...
>D [16/Jan/2007:22:34:44 +1030] Loading job 12 from cache...
>D [16/Jan/2007:22:34:44 +1030] Loading job 13 from cache...
>D [16/Jan/2007:22:34:44 +1030] Loading job 14 from cache...
>D [16/Jan/2007:22:34:44 +1030] Loading job 15 from cache...
>I [16/Jan/2007:22:34:44 +1030] Full reload complete.
>I [16/Jan/2007:22:34:44 +1030] Listening to 127.0.0.1:631 on fd 3...
>I [16/Jan/2007:22:34:44 +1030] Listening to ::1:631 on fd 4...
>I [16/Jan/2007:22:34:44 +1030] Listening to /var/run/cups/cups.sock on fd 5...
>D [16/Jan/2007:22:35:09 +1030] cupsdAcceptClient: skipping getpeercon()
>D [16/Jan/2007:22:35:09 +1030] cupsdAcceptClient: 9 from localhost:631 (IPv4)
>D [16/Jan/2007:22:35:09 +1030] cupsdReadClient: 9 GET /jobs/ HTTP/1.1
>D [16/Jan/2007:22:35:09 +1030] cupsdReadClient: 9 Browser asked for language "en-us.utf-8"...
>D [16/Jan/2007:22:35:09 +1030] cupsdAuthorize: No authentication data provided.
>D [16/Jan/2007:22:35:09 +1030] CGI /usr/lib/cups/cgi-bin/jobs.cgi started - PID = 3259
>I [16/Jan/2007:22:35:09 +1030] Started "/usr/lib/cups/cgi-bin/jobs.cgi" (pid=3259)
>D [16/Jan/2007:22:35:09 +1030] cupsdSendCommand: 9 file=10
>D [16/Jan/2007:22:35:09 +1030] [CGI] cgiCopyTemplateLang(tmpl="header.tmpl")
>D [16/Jan/2007:22:35:09 +1030] [CGI] locale="en_us"...
>D [16/Jan/2007:22:35:09 +1030] [CGI] Template file is "/usr/share/cups/templates/header.tmpl"...
>D [16/Jan/2007:22:35:09 +1030] [CGI] Starting at file position 0...
>D [16/Jan/2007:22:35:09 +1030] [CGI] "{title}" at 205...
>D [16/Jan/2007:22:35:09 +1030] [CGI] Starting "{refresh_page?" at 374, result=0...
>D [16/Jan/2007:22:35:09 +1030] [CGI] Skip first part...
>D [16/Jan/2007:22:35:09 +1030] [CGI] Starting at file position 374...
>D [16/Jan/2007:22:35:09 +1030] [CGI] "{refresh_page}" at 424...
>D [16/Jan/2007:22:35:09 +1030] [CGI] Returning at file position 427 on character ':'...
>D [16/Jan/2007:22:35:09 +1030] [CGI] Output second part...
>D [16/Jan/2007:22:35:09 +1030] [CGI] Starting at file position 427...
>D [16/Jan/2007:22:35:09 +1030] [CGI] Returning at file position 428 on character '}'...
>D [16/Jan/2007:22:35:09 +1030] [CGI] Finished "{refresh_page?", out=0x2644c0...
>D [16/Jan/2007:22:35:09 +1030] [CGI] "{title}" at 671...
>D [16/Jan/2007:22:35:09 +1030] [CGI] "{title}" at 952...
>D [16/Jan/2007:22:35:09 +1030] [CGI] Starting "{SECTION=admin" at 1411, result=0...
>D [16/Jan/2007:22:35:09 +1030] [CGI] Skip first part...
>D [16/Jan/2007:22:35:09 +1030] [CGI] Starting at file position 1411...
>D [16/Jan/2007:22:35:09 +1030] [CGI] Returning at file position 1412 on character ':'...
>D [16/Jan/2007:22:35:09 +1030] [CGI] Output second part...
>D [16/Jan/2007:22:35:09 +1030] [CGI] Starting at file position 1412...
>D [16/Jan/2007:22:35:09 +1030] [CGI] Returning at file position 1415 on character '}'...
>D [16/Jan/2007:22:35:09 +1030] [CGI] Finished "{SECTION=admin", out=0x2644c0...
>D [16/Jan/2007:22:35:09 +1030] cupsdAcceptClient: skipping getpeercon()
>D [16/Jan/2007:22:35:09 +1030] cupsdAcceptClient: 12 from localhost (Domain)
>D [16/Jan/2007:22:35:11 +1030] [CGI] Starting "{SECTION=classes" at 1678, result=0...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Skip first part...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Starting at file position 1678...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Returning at file position 1679 on character ':'...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Output second part...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Starting at file position 1679...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Returning at file position 1682 on character '}'...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Finished "{SECTION=classes", out=0x2644c0...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Starting "{SECTION=help" at 1938, result=0...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Skip first part...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Starting at file position 1938...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Returning at file position 1939 on character ':'...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Output second part...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Starting at file position 1939...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Returning at file position 1942 on character '}'...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Finished "{SECTION=help", out=0x2644c0...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Starting "{SECTION=jobs" at 2206, result=1...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Output first part...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Starting at file position 2206...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Returning at file position 2207 on character ':'...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Skip second part...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Starting at file position 2207...
>D [16/Jan/2007:22:35:11 +1030] cupsdReadClient: 12 POST / HTTP/1.1
>D [16/Jan/2007:22:35:11 +1030] cupsdAuthorize: No authentication data provided.
>D [16/Jan/2007:22:35:11 +1030] Get-Jobs ipp://localhost/jobs
>D [16/Jan/2007:22:35:11 +1030] cupsdProcessIPPRequest: 12 status_code=0 (successful-ok)
>D [16/Jan/2007:22:35:11 +1030] [CGI] Returning at file position 2210 on character '}'...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Finished "{SECTION=jobs", out=0x2644c0...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Starting "{SECTION=printers" at 2464, result=0...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Skip first part...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Starting at file position 2464...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Returning at file position 2465 on character ':'...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Output second part...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Starting at file position 2465...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Returning at file position 2468 on character '}'...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Finished "{SECTION=printers", out=0x2644c0...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Returning at file position 2830 on EOF...
>D [16/Jan/2007:22:35:11 +1030] PID 3259 (/usr/lib/cups/cgi-bin/jobs.cgi) exited with no errors.
>D [16/Jan/2007:22:35:11 +1030] [CGI] cgiCopyTemplateLang(tmpl="search.tmpl")
>D [16/Jan/2007:22:35:11 +1030] [CGI] locale="en_us"...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Template file is "/usr/share/cups/templates/search.tmpl"...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Starting at file position 0...
>D [16/Jan/2007:22:35:11 +1030] [CGI] "{SECTION}" at 24...
>D [16/Jan/2007:22:35:11 +1030] [CGI] "{?SEARCH_DEST}" at 39...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Starting "{WHICH_JOBS?" at 67, result=0...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Skip first part...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Starting at file position 67...
>D [16/Jan/2007:22:35:11 +1030] [CGI] "{WHICH_JOBS}" at 125...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Returning at file position 128 on character ':'...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Output second part...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Starting at file position 128...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Returning at file position 129 on character '}'...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Finished "{WHICH_JOBS?", out=0x2644c0...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Starting "{ORDER?" at 137, result=1...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Output first part...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Starting at file position 137...
>D [16/Jan/2007:22:35:11 +1030] [CGI] "{ORDER}" at 185...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Returning at file position 188 on character ':'...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Skip second part...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Starting at file position 188...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Returning at file position 189 on character '}'...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Finished "{ORDER?", out=0x2644c0...
>D [16/Jan/2007:22:35:11 +1030] cupsdCloseClient: 12
>D [16/Jan/2007:22:35:11 +1030] [CGI] Starting "{SEARCH_DEST?" at 235, result=0...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Skip first part...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Starting at file position 235...
>D [16/Jan/2007:22:35:11 +1030] [CGI] "{SEARCH_DEST}" at 248...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Returning at file position 249 on character ':'...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Output second part...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Starting at file position 249...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Starting "{SECTION=classes" at 266, result=0...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Skip first part...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Starting at file position 266...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Returning at file position 274 on character ':'...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Output second part...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Starting at file position 274...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Starting "{SECTION=jobs" at 288, result=1...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Output first part...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Starting at file position 288...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Returning at file position 293 on character ':'...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Skip second part...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Starting at file position 293...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Returning at file position 302 on character '}'...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Finished "{SECTION=jobs", out=0x2644c0...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Returning at file position 303 on character '}'...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Finished "{SECTION=classes", out=0x2644c0...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Returning at file position 304 on character '}'...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Finished "{SEARCH_DEST?", out=0x2644c0...
>D [16/Jan/2007:22:35:11 +1030] [CGI] "{?QUERY}" at 357...
>D [16/Jan/2007:22:35:11 +1030] [CGI] "{SECTION}" at 455...
>D [16/Jan/2007:22:35:11 +1030] [CGI] "{?SEARCH_DEST}" at 470...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Starting "{WHICH_JOBS?" at 482, result=0...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Skip first part...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Starting at file position 482...
>D [16/Jan/2007:22:35:11 +1030] [CGI] "{WHICH_JOBS}" at 506...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Starting "{ORDER?" at 513, result=1...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Output first part...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Starting at file position 513...
>D [16/Jan/2007:22:35:11 +1030] [CGI] "{ORDER}" at 531...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Returning at file position 532 on character ':'...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Skip second part...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Starting at file position 532...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Returning at file position 533 on character '}'...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Finished "{ORDER?", out=(nil)...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Returning at file position 534 on character ':'...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Output second part...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Starting at file position 534...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Starting "{ORDER?" at 541, result=1...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Output first part...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Starting at file position 541...
>D [16/Jan/2007:22:35:11 +1030] [CGI] "{ORDER}" at 555...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Returning at file position 556 on character ':'...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Skip second part...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Starting at file position 556...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Returning at file position 557 on character '}'...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Finished "{ORDER?", out=0x2644c0...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Returning at file position 558 on character '}'...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Finished "{WHICH_JOBS?", out=0x2644c0...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Returning at file position 641 on EOF...
>D [16/Jan/2007:22:35:11 +1030] [CGI] cgiCopyTemplateLang(tmpl="jobs-header.tmpl")
>D [16/Jan/2007:22:35:11 +1030] [CGI] locale="en_us"...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Template file is "/usr/share/cups/templates/jobs-header.tmpl"...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Starting at file position 0...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Starting "{?which_jobs=" at 17, result=1...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Output first part...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Starting at file position 17...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Starting "{?printer_name=" at 42, result=1...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Output first part...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Starting at file position 42...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Returning at file position 48 on character ':'...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Skip second part...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Starting at file position 48...
>D [16/Jan/2007:22:35:11 +1030] [CGI] "{printer_uri_supported}" at 71...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Returning at file position 72 on character '}'...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Finished "{?printer_name=", out=0x2644c0...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Starting "{?printer_name=" at 211, result=1...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Output first part...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Starting at file position 211...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Returning at file position 217 on character ':'...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Skip second part...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Starting at file position 217...
>D [16/Jan/2007:22:35:11 +1030] [CGI] "{printer_uri_supported}" at 240...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Returning at file position 241 on character '}'...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Finished "{?printer_name=", out=0x2644c0...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Returning at file position 333 on character ':'...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Skip second part...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Starting at file position 333...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Starting "{which_jobs=all" at 349, result=0...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Skip first part...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Starting at file position 349...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Starting "{?printer_name=" at 374, result=1...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Output first part...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Starting at file position 374...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Returning at file position 380 on character ':'...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Skip second part...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Starting at file position 380...
>D [16/Jan/2007:22:35:11 +1030] [CGI] "{printer_uri_supported}" at 403...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Returning at file position 404 on character '}'...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Finished "{?printer_name=", out=(nil)...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Starting "{?printer_name=" at 543, result=1...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Output first part...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Starting at file position 543...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Returning at file position 549 on character ':'...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Skip second part...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Starting at file position 549...
>D [16/Jan/2007:22:35:11 +1030] [CGI] "{printer_uri_supported}" at 572...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Returning at file position 573 on character '}'...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Finished "{?printer_name=", out=(nil)...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Returning at file position 656 on character ':'...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Output second part...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Starting at file position 656...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Starting "{?printer_name=" at 681, result=1...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Output first part...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Starting at file position 681...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Returning at file position 687 on character ':'...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Skip second part...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Starting at file position 687...
>D [16/Jan/2007:22:35:11 +1030] [CGI] "{printer_uri_supported}" at 710...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Returning at file position 711 on character '}'...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Finished "{?printer_name=", out=(nil)...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Starting "{?printer_name=" at 823, result=1...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Output first part...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Starting at file position 823...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Returning at file position 829 on character ':'...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Skip second part...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Starting at file position 829...
>D [16/Jan/2007:22:35:11 +1030] [CGI] "{printer_uri_supported}" at 852...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Returning at file position 853 on character '}'...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Finished "{?printer_name=", out=(nil)...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Returning at file position 945 on character '}'...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Finished "{which_jobs=all", out=(nil)...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Returning at file position 946 on character '}'...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Finished "{?which_jobs=", out=0x2644c0...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Starting "{total=0" at 983, result=1...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Output first part...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Starting at file position 983...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Returning at file position 991 on character ':'...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Skip second part...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Starting at file position 991...
>D [16/Jan/2007:22:35:11 +1030] [CGI] "{#job_id}" at 1008...
>D [16/Jan/2007:22:35:11 +1030] [CGI] "{total}" at 1019...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Starting "{?which_jobs=" at 1034, result=1...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Output first part...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Starting at file position 1034...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Returning at file position 1041 on character ':'...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Skip second part...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Starting at file position 1041...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Starting "{which_jobs=all" at 1057, result=0...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Skip first part...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Starting at file position 1057...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Returning at file position 1058 on character ':'...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Output second part...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Starting at file position 1058...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Returning at file position 1068 on character '}'...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Finished "{which_jobs=all", out=(nil)...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Returning at file position 1069 on character '}'...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Finished "{?which_jobs=", out=(nil)...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Starting "{total=1" at 1082, result=0...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Skip first part...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Starting at file position 1082...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Returning at file position 1083 on character ':'...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Output second part...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Starting at file position 1083...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Returning at file position 1085 on character '}'...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Finished "{total=1", out=(nil)...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Returning at file position 1086 on character '}'...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Finished "{total=0", out=0x2644c0...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Returning at file position 1092 on EOF...
>D [16/Jan/2007:22:35:11 +1030] [CGI] cgiCopyTemplateLang(tmpl="jobs.tmpl")
>D [16/Jan/2007:22:35:11 +1030] [CGI] locale="en_us"...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Template file is "/usr/share/cups/templates/jobs.tmpl"...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Starting at file position 0...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Starting "{#job_id=0" at 11, result=1...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Output first part...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Starting at file position 11...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Returning at file position 12 on character ':'...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Skip second part...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Starting at file position 12...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Looping on "job_id" at 277, count=0...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Starting at file position 277...
>D [16/Jan/2007:22:35:11 +1030] [CGI] "{job_printer_uri}" at 339...
>D [16/Jan/2007:22:35:11 +1030] [CGI] "{job_printer_name}" at 359...
>D [16/Jan/2007:22:35:11 +1030] [CGI] "{job_id}" at 372...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Starting "{?job_name=" at 400, result=1...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Output first part...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Starting at file position 400...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Returning at file position 408 on character ':'...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Skip second part...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Starting at file position 408...
>D [16/Jan/2007:22:35:11 +1030] [CGI] "{job_name}" at 418...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Returning at file position 419 on character '}'...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Finished "{?job_name=", out=(nil)...
>D [16/Jan/2007:22:35:11 +1030] [CGI] "{job_originating_user_name}" at 462...
>D [16/Jan/2007:22:35:11 +1030] [CGI] "{job_k_octets}" at 492...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Starting "{job_media_sheets_completed=0" at 539, result=0...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Skip first part...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Starting at file position 539...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Returning at file position 547 on character ':'...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Output second part...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Starting at file position 547...
>D [16/Jan/2007:22:35:11 +1030] [CGI] "{?job_media_sheets_completed}" at 576...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Returning at file position 577 on character '}'...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Finished "{job_media_sheets_completed=0", out=(nil)...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Starting "{job_state=3" at 600, result=0...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Skip first part...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Starting at file position 600...
>D [16/Jan/2007:22:35:11 +1030] [CGI] "{time_at_creation}" at 635...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Returning at file position 636 on character ':'...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Output second part...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Starting at file position 636...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Starting "{job_state=4" at 649, result=0...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Skip first part...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Starting at file position 649...
>D [16/Jan/2007:22:35:11 +1030] [CGI] "{time_at_creation}" at 681...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Returning at file position 682 on character ':'...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Output second part...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Starting at file position 682...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Starting "{job_state=5" at 696, result=0...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Skip first part...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Starting at file position 696...
>D [16/Jan/2007:22:35:11 +1030] [CGI] "{time_at_processing}" at 736...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Returning at file position 737 on character ':'...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Output second part...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Starting at file position 737...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Starting "{job_state=6" at 750, result=0...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Skip first part...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Starting at file position 750...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Returning at file position 758 on character ':'...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Output second part...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Starting at file position 758...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Starting "{job_state=7" at 772, result=0...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Skip first part...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Starting at file position 772...
>D [16/Jan/2007:22:35:11 +1030] [CGI] "{time_at_completed}" at 806...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Returning at file position 807 on character ':'...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Output second part...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Starting at file position 807...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Starting "{job_state=8" at 820, result=0...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Skip first part...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Starting at file position 820...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Returning at file position 828 on character ':'...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Output second part...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Starting at file position 828...
>D [16/Jan/2007:22:35:11 +1030] [CGI] "{time_at_completed}" at 863...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Returning at file position 864 on character '}'...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Finished "{job_state=8", out=(nil)...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Returning at file position 865 on character '}'...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Finished "{job_state=7", out=(nil)...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Returning at file position 866 on character '}'...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Finished "{job_state=6", out=(nil)...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Returning at file position 867 on character '}'...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Finished "{job_state=5", out=(nil)...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Returning at file position 868 on character '}'...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Finished "{job_state=4", out=(nil)...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Returning at file position 869 on character '}'...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Finished "{job_state=3", out=(nil)...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Starting "{job_preserved>0" at 903, result=1...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Output first part...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Starting at file position 903...
>D [16/Jan/2007:22:35:11 +1030] [CGI] "{job_id}" at 954...
>D [16/Jan/2007:22:35:11 +1030] [CGI] "{job_printer_uri}" at 992...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Returning at file position 1075 on character ':'...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Skip second part...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Starting at file position 1075...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Returning at file position 1076 on character '}'...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Finished "{job_preserved>0", out=(nil)...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Starting "{job_state=4" at 1090, result=0...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Skip first part...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Starting at file position 1090...
>D [16/Jan/2007:22:35:11 +1030] [CGI] "{job_id}" at 1141...
>D [16/Jan/2007:22:35:11 +1030] [CGI] "{job_printer_uri}" at 1179...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Returning at file position 1262 on character ':'...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Output second part...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Starting at file position 1262...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Returning at file position 1263 on character '}'...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Finished "{job_state=4", out=(nil)...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Starting "{job_state=3" at 1277, result=0...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Skip first part...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Starting at file position 1277...
>D [16/Jan/2007:22:35:11 +1030] [CGI] "{job_id}" at 1325...
>D [16/Jan/2007:22:35:11 +1030] [CGI] "{job_printer_uri}" at 1363...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Returning at file position 1440 on character ':'...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Output second part...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Starting at file position 1440...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Returning at file position 1441 on character '}'...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Finished "{job_state=3", out=(nil)...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Starting "{job_state<7" at 1455, result=0...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Skip first part...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Starting at file position 1455...
>D [16/Jan/2007:22:35:11 +1030] [CGI] "{job_id}" at 1505...
>D [16/Jan/2007:22:35:11 +1030] [CGI] "{job_printer_uri}" at 1543...
>D [16/Jan/2007:22:35:11 +1030] [CGI] "{job_id}" at 1671...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Returning at file position 1747 on character ':'...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Output second part...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Starting at file position 1747...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Returning at file position 1748 on character '}'...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Finished "{job_state<7", out=(nil)...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Returning at file position 1768 on character '}'...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Finished looping on "job_id"...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Returning at file position 1779 on character '}'...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Finished "{#job_id=0", out=0x2644c0...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Returning at file position 1780 on EOF...
>D [16/Jan/2007:22:35:11 +1030] [CGI] cgiCopyTemplateLang(tmpl="trailer.tmpl")
>D [16/Jan/2007:22:35:11 +1030] [CGI] locale="en_us"...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Template file is "/usr/share/cups/templates/trailer.tmpl"...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Starting at file position 0...
>D [16/Jan/2007:22:35:11 +1030] [CGI] Returning at file position 614 on EOF...
>D [16/Jan/2007:22:35:34 +1030] cupsdAcceptClient: skipping getpeercon()
>D [16/Jan/2007:22:35:34 +1030] cupsdAcceptClient: 10 from localhost (Domain)
>D [16/Jan/2007:22:35:34 +1030] cupsdReadClient: 10 GET /admin/conf/printers.conf HTTP/1.1
>D [16/Jan/2007:22:35:34 +1030] cupsdAuthorize: No authentication data provided.
>D [16/Jan/2007:22:35:34 +1030] cupsdSendError: 10 code=401 (Unauthorized)
>D [16/Jan/2007:22:35:34 +1030] cupsdCloseClient: 10
>D [16/Jan/2007:22:35:34 +1030] cupsdAcceptClient: skipping getpeercon()
>D [16/Jan/2007:22:35:34 +1030] cupsdAcceptClient: 10 from localhost (Domain)
>D [16/Jan/2007:22:35:34 +1030] cupsdReadClient: 10 GET /admin/conf/printers.conf HTTP/1.1
>D [16/Jan/2007:22:35:34 +1030] cupsdAuthorize: username="root"
>D [16/Jan/2007:22:35:34 +1030] write_file: 10 file=12
>D [16/Jan/2007:22:35:34 +1030] cupsdReadClient: 10 GET /admin/conf/classes.conf HTTP/1.1
>D [16/Jan/2007:22:35:34 +1030] cupsdAuthorize: username="root"
>D [16/Jan/2007:22:35:34 +1030] write_file: 10 file=12
>D [16/Jan/2007:22:35:34 +1030] cupsdReadClient: 10 POST / HTTP/1.1
>D [16/Jan/2007:22:35:34 +1030] cupsdAuthorize: username="root"
>D [16/Jan/2007:22:35:34 +1030] CUPS-Get-Printers
>D [16/Jan/2007:22:35:34 +1030] cupsdProcessIPPRequest: 10 status_code=0 (successful-ok)
>D [16/Jan/2007:22:35:34 +1030] cupsdReadClient: 10 POST / HTTP/1.1
>D [16/Jan/2007:22:35:34 +1030] cupsdAuthorize: username="root"
>D [16/Jan/2007:22:35:34 +1030] CUPS-Get-Classes
>D [16/Jan/2007:22:35:34 +1030] cupsdProcessIPPRequest: 10 status_code=0 (successful-ok)
>D [16/Jan/2007:22:35:34 +1030] cupsdReadClient: 10 POST / HTTP/1.1
>D [16/Jan/2007:22:35:34 +1030] cupsdAuthorize: username="root"
>D [16/Jan/2007:22:35:34 +1030] Get-Printer-Attributes ipp://localhost/printers/Photosmart_C4100
>D [16/Jan/2007:22:35:34 +1030] cupsdProcessIPPRequest: 10 status_code=0 (successful-ok)
>D [16/Jan/2007:22:35:34 +1030] cupsdReadClient: 10 POST / HTTP/1.1
>D [16/Jan/2007:22:35:34 +1030] cupsdAuthorize: username="root"
>D [16/Jan/2007:22:35:34 +1030] Get-Printer-Attributes ipp://localhost/printers/Photosmart_C4100_series
>D [16/Jan/2007:22:35:34 +1030] cupsdProcessIPPRequest: 10 status_code=0 (successful-ok)
>D [16/Jan/2007:22:35:34 +1030] cupsdReadClient: 10 POST /admin/ HTTP/1.1
>D [16/Jan/2007:22:35:34 +1030] cupsdAuthorize: username="root"
>D [16/Jan/2007:22:35:34 +1030] Resume-Printer ipp://localhost/printers/Photosmart_C4100_series
>D [16/Jan/2007:22:35:34 +1030] Discarding unused printer-state-changed event...
>I [16/Jan/2007:22:35:34 +1030] Saving printers.conf...
>I [16/Jan/2007:22:35:34 +1030] Printer "Photosmart_C4100_series" started by "root".
>D [16/Jan/2007:22:35:34 +1030] cupsdProcessIPPRequest: 10 status_code=0 (successful-ok)
>D [16/Jan/2007:22:35:34 +1030] cupsdCloseClient: 10
>D [16/Jan/2007:22:36:23 +1030] cupsdCloseClient: 9
>D [16/Jan/2007:22:36:30 +1030] cupsdAcceptClient: skipping getpeercon()
>D [16/Jan/2007:22:36:30 +1030] cupsdAcceptClient: 9 from localhost (Domain)
>D [16/Jan/2007:22:36:30 +1030] cupsdReadClient: 9 POST / HTTP/1.1
>D [16/Jan/2007:22:36:30 +1030] cupsdAuthorize: No authentication data provided.
>D [16/Jan/2007:22:36:30 +1030] CUPS-Get-Default
>D [16/Jan/2007:22:36:30 +1030] CUPS-Get-Default client-error-not-found: No default printer
>D [16/Jan/2007:22:36:30 +1030] cupsdProcessIPPRequest: 9 status_code=406 (client-error-not-found)
>D [16/Jan/2007:22:36:30 +1030] cupsdReadClient: 9 POST / HTTP/1.1
>D [16/Jan/2007:22:36:30 +1030] cupsdAuthorize: No authentication data provided.
>D [16/Jan/2007:22:36:30 +1030] CUPS-Get-Printers
>D [16/Jan/2007:22:36:30 +1030] cupsdProcessIPPRequest: 9 status_code=0 (successful-ok)
>D [16/Jan/2007:22:36:30 +1030] cupsdReadClient: 9 POST / HTTP/1.1
>D [16/Jan/2007:22:36:30 +1030] cupsdAuthorize: No authentication data provided.
>D [16/Jan/2007:22:36:30 +1030] Get-Printer-Attributes ipp://localhost/printers/Photosmart_C4100
>D [16/Jan/2007:22:36:30 +1030] cupsdProcessIPPRequest: 9 status_code=0 (successful-ok)
>D [16/Jan/2007:22:36:30 +1030] cupsdReadClient: 9 POST / HTTP/1.1
>D [16/Jan/2007:22:36:30 +1030] cupsdAuthorize: No authentication data provided.
>D [16/Jan/2007:22:36:30 +1030] Get-Printer-Attributes ipp://localhost/printers/Photosmart_C4100_series
>D [16/Jan/2007:22:36:30 +1030] cupsdProcessIPPRequest: 9 status_code=0 (successful-ok)
>D [16/Jan/2007:22:36:31 +1030] cupsdAcceptClient: skipping getpeercon()
>D [16/Jan/2007:22:36:31 +1030] cupsdAcceptClient: 10 from localhost:631 (IPv4)
>D [16/Jan/2007:22:36:31 +1030] cupsdReadClient: 10 GET /printers/Photosmart_C4100.ppd HTTP/1.1
>D [16/Jan/2007:22:36:31 +1030] cupsdAuthorize: No authentication data provided.
>D [16/Jan/2007:22:36:31 +1030] write_file: 10 file=13
>D [16/Jan/2007:22:36:31 +1030] cupsdReadClient: 10 GET /printers/Photosmart_C4100_series.ppd HTTP/1.1
>D [16/Jan/2007:22:36:31 +1030] cupsdAuthorize: No authentication data provided.
>D [16/Jan/2007:22:36:31 +1030] write_file: 10 file=13
>D [16/Jan/2007:22:36:56 +1030] cupsdReadClient: 9 POST / HTTP/1.1
>D [16/Jan/2007:22:36:56 +1030] cupsdAuthorize: No authentication data provided.
>D [16/Jan/2007:22:36:56 +1030] Get-Printer-Attributes ipp://localhost/printers/Photosmart_C4100_series
>D [16/Jan/2007:22:36:56 +1030] cupsdProcessIPPRequest: 9 status_code=0 (successful-ok)
>D [16/Jan/2007:22:36:56 +1030] cupsdReadClient: 9 POST / HTTP/1.1
>D [16/Jan/2007:22:36:56 +1030] cupsdAuthorize: No authentication data provided.
>D [16/Jan/2007:22:36:56 +1030] Get-Printer-Attributes ipp://localhost/printers/Photosmart_C4100
>D [16/Jan/2007:22:36:56 +1030] cupsdProcessIPPRequest: 9 status_code=0 (successful-ok)
>D [16/Jan/2007:22:37:32 +1030] cupsdAcceptClient: skipping getpeercon()
>D [16/Jan/2007:22:37:32 +1030] cupsdAcceptClient: 13 from localhost (Domain)
>D [16/Jan/2007:22:37:32 +1030] cupsdReadClient: 13 POST /printers/Photosmart_C4100 HTTP/1.1
>D [16/Jan/2007:22:37:32 +1030] cupsdAuthorize: No authentication data provided.
>D [16/Jan/2007:22:37:33 +1030] Print-Job ipp://localhost/printers/Photosmart_C4100
>D [16/Jan/2007:22:37:33 +1030] print_job: auto-typing file...
>D [16/Jan/2007:22:37:33 +1030] print_job: request file type is application/postscript.
>D [16/Jan/2007:22:37:33 +1030] add_job: setting context of job to UNKNOWN SL
>D [16/Jan/2007:22:37:33 +1030] add_job: requesting-user-name="tim"
>D [16/Jan/2007:22:37:33 +1030] Adding default job-sheets values "none,none"...
>I [16/Jan/2007:22:37:33 +1030] Adding start banner page "none" to job 16.
>D [16/Jan/2007:22:37:33 +1030] Discarding unused job-created event...
>I [16/Jan/2007:22:37:33 +1030] Adding end banner page "none" to job 16.
>I [16/Jan/2007:22:37:33 +1030] Job 16 queued on "Photosmart_C4100" by "tim".
>D [16/Jan/2007:22:37:33 +1030] Job 16 hold_until = 0
>D [16/Jan/2007:22:37:33 +1030] Discarding unused printer-state-changed event...
>D [16/Jan/2007:22:37:33 +1030] job-sheets=none,none
>D [16/Jan/2007:22:37:33 +1030] banner_page = 0
>D [16/Jan/2007:22:37:33 +1030] [Job 16] argv[0]="Photosmart_C4100"
>D [16/Jan/2007:22:37:33 +1030] [Job 16] argv[1]="16"
>D [16/Jan/2007:22:37:33 +1030] [Job 16] argv[2]="tim"
>D [16/Jan/2007:22:37:33 +1030] [Job 16] argv[3]=""
>D [16/Jan/2007:22:37:33 +1030] [Job 16] argv[4]="1"
>D [16/Jan/2007:22:37:33 +1030] [Job 16] argv[5]="InputSlot=Default job-uuid=urn:uuid:e7f3a7d8-8159-35b8-6a3a-e1948c58b5b3"
>D [16/Jan/2007:22:37:33 +1030] [Job 16] argv[6]="/var/spool/cups/d00016-001"
>D [16/Jan/2007:22:37:33 +1030] [Job 16] envp[0]="CUPS_CACHEDIR=/var/cache/cups"
>D [16/Jan/2007:22:37:33 +1030] [Job 16] envp[1]="CUPS_DATADIR=/usr/share/cups"
>D [16/Jan/2007:22:37:33 +1030] [Job 16] envp[2]="CUPS_DOCROOT=/usr/share/doc/cups-1.2.7"
>D [16/Jan/2007:22:37:33 +1030] [Job 16] envp[3]="CUPS_FONTPATH=/usr/share/cups/fonts"
>D [16/Jan/2007:22:37:33 +1030] [Job 16] envp[4]="CUPS_REQUESTROOT=/var/spool/cups"
>D [16/Jan/2007:22:37:33 +1030] [Job 16] envp[5]="CUPS_SERVERBIN=/usr/lib/cups"
>D [16/Jan/2007:22:37:33 +1030] [Job 16] envp[6]="CUPS_SERVERROOT=/etc/cups"
>D [16/Jan/2007:22:37:33 +1030] [Job 16] envp[7]="CUPS_STATEDIR=/var/run/cups"
>D [16/Jan/2007:22:37:33 +1030] [Job 16] envp[8]="PATH=/usr/lib/cups/filter:/usr/bin:/usr/sbin:/bin:/usr/bin"
>D [16/Jan/2007:22:37:33 +1030] [Job 16] envp[9]="SERVER_ADMIN=root@bergamot.wegener.org"
>D [16/Jan/2007:22:37:33 +1030] [Job 16] envp[10]="SOFTWARE=CUPS/1.2.7"
>D [16/Jan/2007:22:37:33 +1030] [Job 16] envp[11]="TMPDIR=/var/spool/cups/tmp"
>D [16/Jan/2007:22:37:33 +1030] [Job 16] envp[12]="USER=root"
>D [16/Jan/2007:22:37:33 +1030] [Job 16] envp[13]="CUPS_SERVER=/var/run/cups/cups.sock"
>D [16/Jan/2007:22:37:33 +1030] [Job 16] envp[14]="CUPS_ENCRYPTION=IfRequested"
>D [16/Jan/2007:22:37:33 +1030] [Job 16] envp[15]="IPP_PORT=631"
>D [16/Jan/2007:22:37:33 +1030] [Job 16] envp[16]="CHARSET=utf-8"
>D [16/Jan/2007:22:37:33 +1030] [Job 16] envp[17]="LANG=en_US"
>D [16/Jan/2007:22:37:33 +1030] [Job 16] envp[18]="PPD=/etc/cups/ppd/Photosmart_C4100.ppd"
>D [16/Jan/2007:22:37:33 +1030] [Job 16] envp[19]="RIP_MAX_CACHE=8m"
>D [16/Jan/2007:22:37:33 +1030] [Job 16] envp[20]="CONTENT_TYPE=application/postscript"
>D [16/Jan/2007:22:37:33 +1030] [Job 16] envp[21]="DEVICE_URI=hp:/usb/Photosmart_C4100_series?serial=MY65CB919404J7"
>D [16/Jan/2007:22:37:33 +1030] [Job 16] envp[22]="PRINTER=Photosmart_C4100"
>D [16/Jan/2007:22:37:33 +1030] [Job 16] envp[23]="FINAL_CONTENT_TYPE=printer/Photosmart_C4100"
>I [16/Jan/2007:22:37:33 +1030] Started filter /usr/lib/cups/filter/pstops (PID 3405) for job 16.
>I [16/Jan/2007:22:37:33 +1030] Started filter /usr/lib/cups/filter/foomatic-rip (PID 3406) for job 16.
>I [16/Jan/2007:22:37:33 +1030] Started backend /usr/lib/cups/backend/hp (PID 3407) for job 16.
>D [16/Jan/2007:22:37:33 +1030] Discarding unused job-state event...
>D [16/Jan/2007:22:37:33 +1030] cupsdProcessIPPRequest: 13 status_code=0 (successful-ok)
>D [16/Jan/2007:22:37:33 +1030] cupsdCloseClient: 10
>D [16/Jan/2007:22:37:33 +1030] cupsdCloseClient: 9
>D [16/Jan/2007:22:37:33 +1030] [Job 16] Page = 595x842; 10,36 to 585,833
>D [16/Jan/2007:22:37:33 +1030] [Job 16] slow_collate=0, slow_duplex=0, slow_order=0
>D [16/Jan/2007:22:37:33 +1030] [Job 16] Before copy_comments - %!PS-Adobe-3.0
>D [16/Jan/2007:22:37:33 +1030] [Job 16] %!PS-Adobe-3.0
>D [16/Jan/2007:22:37:33 +1030] [Job 16] %%Creator: Gnome Print Version 2.12.1
>D [16/Jan/2007:22:37:33 +1030] [Job 16] %%CreationDate: D:20070116223731
>D [16/Jan/2007:22:37:33 +1030] [Job 16] %%LanguageLevel: 2
>D [16/Jan/2007:22:37:33 +1030] [Job 16] %%DocumentMedia: Regular 288 432 0 () ()
>D [16/Jan/2007:22:37:33 +1030] [Job 16] %%Orientation: Portrait
>D [16/Jan/2007:22:37:33 +1030] [Job 16] %%BoundingBox: 0 0 288 432
>D [16/Jan/2007:22:37:33 +1030] [Job 16] %%Pages: 1
>D [16/Jan/2007:22:37:33 +1030] [Job 16] %%PageOrder: Ascend
>D [16/Jan/2007:22:37:33 +1030] [Job 16] %%Title:
>D [16/Jan/2007:22:37:33 +1030] [Job 16] %%DocumentSuppliedResources: procset pnome-print-procs-2.12.1
>D [16/Jan/2007:22:37:33 +1030] [Job 16] %%Requirements: numcopies(1)
>D [16/Jan/2007:22:37:33 +1030] [Job 16] %%EndComments
>D [16/Jan/2007:22:37:33 +1030] [Job 16] Before copy_prolog - %%BeginDefaults
>D [16/Jan/2007:22:37:33 +1030] [Job 16] Before copy_setup - %%BeginSetup
>D [16/Jan/2007:22:37:33 +1030] [Job 16] Before page loop - %%Page: 1 1
>D [16/Jan/2007:22:37:33 +1030] [Job 16] Copying page 1...
>D [16/Jan/2007:22:37:33 +1030] [Job 16] pagew = 575.6, pagel = 797.0
>D [16/Jan/2007:22:37:33 +1030] [Job 16] bboxw = 595, bboxl = 842
>D [16/Jan/2007:22:37:33 +1030] [Job 16] PageLeft = 9.7, PageRight = 585.3
>D [16/Jan/2007:22:37:33 +1030] [Job 16] PageTop = 833.0, PageBottom = 36.0
>D [16/Jan/2007:22:37:33 +1030] [Job 16] PageWidth = 595.0, PageLength = 842.0
>D [16/Jan/2007:22:37:34 +1030] [Job 16] foomatic-rip version $Revision: 3.43.2.15 $ running...
>D [16/Jan/2007:22:37:34 +1030] [Job 16] Parsing PPD file ...
>D [16/Jan/2007:22:37:34 +1030] [Job 16] *cupsFilter: "application/vnd.cups-postscript 0 foomatic-rip"
>D [16/Jan/2007:22:37:34 +1030] [Job 16] Added option ColorSpace
>D [16/Jan/2007:22:37:34 +1030] [Job 16] Added option Resolution
>D [16/Jan/2007:22:37:34 +1030] [Job 16] Added option PageSize
>D [16/Jan/2007:22:37:34 +1030] [Job 16] Added option PageRegion
>D [16/Jan/2007:22:37:34 +1030] [Job 16] Added option Model
>D [16/Jan/2007:22:37:34 +1030] [Job 16] Added option PrintoutMode
>D [16/Jan/2007:22:37:34 +1030] [Job 16] Added option InputSlot
>D [16/Jan/2007:22:37:34 +1030] [Job 16] Added option ImageableArea
>D [16/Jan/2007:22:37:34 +1030] [Job 16] Added option PaperDimension
>D [16/Jan/2007:22:37:34 +1030] [Job 16] Added option Duplex
>D [16/Jan/2007:22:37:34 +1030] [Job 16] Added option Quality
>D [16/Jan/2007:22:37:34 +1030] [Job 16] Added option Font
>D [16/Jan/2007:22:37:34 +1030] [Job 16] 
>D [16/Jan/2007:22:37:34 +1030] [Job 16] Parameter Summary
>D [16/Jan/2007:22:37:34 +1030] [Job 16] -----------------
>D [16/Jan/2007:22:37:34 +1030] [Job 16] 
>D [16/Jan/2007:22:37:34 +1030] [Job 16] Spooler: cups
>D [16/Jan/2007:22:37:34 +1030] [Job 16] Printer: Photosmart_C4100
>D [16/Jan/2007:22:37:34 +1030] [Job 16] PPD file: /etc/cups/ppd/Photosmart_C4100.ppd
>D [16/Jan/2007:22:37:34 +1030] [Job 16] Printer model: HP PhotoSmart C4100 Foomatic/hpijs (recommended)
>D [16/Jan/2007:22:37:34 +1030] [Job 16] Job title: 
>D [16/Jan/2007:22:37:34 +1030] [Job 16] File(s) to be printed: 
>D [16/Jan/2007:22:37:34 +1030] [Job 16] <STDIN>
>D [16/Jan/2007:22:37:34 +1030] [Job 16] 
>D [16/Jan/2007:22:37:34 +1030] [Job 16] GhostScript extra search path ('GS_LIB'): /usr/share/cups/fonts
>D [16/Jan/2007:22:37:34 +1030] [Job 16] Pondering option 'InputSlot=Default'
>D [16/Jan/2007:22:37:34 +1030] [Job 16] Pondering option 'job-uuid=urn:uuid:e7f3a7d8-8159-35b8-6a3a-e1948c58b5b3'
>D [16/Jan/2007:22:37:34 +1030] [Job 16] Unknown option job-uuid=urn:uuid:e7f3a7d8-8159-35b8-6a3a-e1948c58b5b3.
>D [16/Jan/2007:22:37:34 +1030] [Job 16] 
>D [16/Jan/2007:22:37:34 +1030] [Job 16] ================================================
>D [16/Jan/2007:22:37:34 +1030] [Job 16] 
>D [16/Jan/2007:22:37:34 +1030] [Job 16] File: <STDIN>
>D [16/Jan/2007:22:37:34 +1030] [Job 16] 
>D [16/Jan/2007:22:37:34 +1030] [Job 16] ================================================
>D [16/Jan/2007:22:37:34 +1030] [Job 16] 
>D [16/Jan/2007:22:37:34 +1030] [Job 16] Reading PostScript input ...
>D [16/Jan/2007:22:37:34 +1030] [Job 16] --> This document is DSC-conforming!
>D [16/Jan/2007:22:37:34 +1030] [Job 16] Job claims to be DSC-conforming, but "%%BeginProlog" was missing before first line with another "%%Begin..." comment (is this a TeX/LaTeX/dvips-generated PostScript file?). Assuming start of "Prolog" here.
>D [16/Jan/2007:22:37:34 +1030] [Job 16] 
>D [16/Jan/2007:22:37:34 +1030] [Job 16] -----------
>D [16/Jan/2007:22:37:34 +1030] [Job 16] Found: %%BeginProlog
>D [16/Jan/2007:22:37:34 +1030] [Job 16] Found: %%EndProlog
>D [16/Jan/2007:22:37:34 +1030] [Job 16] 
>D [16/Jan/2007:22:37:34 +1030] [Job 16] -----------
>D [16/Jan/2007:22:37:34 +1030] [Job 16] Found: %%BeginSetup
>D [16/Jan/2007:22:37:34 +1030] [Job 16] Found: %%BeginFeature: *PrintoutMode Normal
>D [16/Jan/2007:22:37:34 +1030] [Job 16] Option: PrintoutMode=Normal --> Setting option
>D [16/Jan/2007:22:37:34 +1030] [Job 16] Found: %% FoomaticRIPOptionSetting: PrintoutMode=Normal
>D [16/Jan/2007:22:37:34 +1030] [Job 16] Option: PrintoutMode=Normal --> Setting option
>D [16/Jan/2007:22:37:34 +1030] [Job 16] Found: %%BeginFeature: *InputSlot Default
>D [16/Jan/2007:22:37:34 +1030] [Job 16] Option: InputSlot=Default --> Setting option
>D [16/Jan/2007:22:37:34 +1030] [Job 16] Found: %% FoomaticRIPOptionSetting: InputSlot=Default
>D [16/Jan/2007:22:37:34 +1030] [Job 16] Option: InputSlot=Default --> Setting option
>D [16/Jan/2007:22:37:34 +1030] [Job 16] Found: %%BeginFeature: *Quality FromPrintoutMode
>D [16/Jan/2007:22:37:34 +1030] [Job 16] Option: Quality=FromPrintoutMode --> Setting option
>D [16/Jan/2007:22:37:34 +1030] [Job 16] Found: %% FoomaticRIPOptionSetting: Quality=@PrintoutMode
>D [16/Jan/2007:22:37:34 +1030] [Job 16] Option: Quality=FromPrintoutMode --> Setting option
>D [16/Jan/2007:22:37:34 +1030] [Job 16] Found: %%BeginFeature: *PageRegion A4
>D [16/Jan/2007:22:37:34 +1030] [Job 16] Option: PageRegion=A4 --> Option will be set by PostScript interpreter
>D [16/Jan/2007:22:37:34 +1030] [Job 16] Found: %% FoomaticRIPOptionSetting: PageSize=A4
>D [16/Jan/2007:22:37:34 +1030] [Job 16] Option: PageSize=A4 --> Setting option
>D [16/Jan/2007:22:37:34 +1030] [Job 16] Found: %%BeginFeature: *Duplex None
>D [16/Jan/2007:22:37:34 +1030] [Job 16] Option: Duplex=None --> Setting option
>D [16/Jan/2007:22:37:34 +1030] [Job 16] Found: %% FoomaticRIPOptionSetting: Duplex=None
>D [16/Jan/2007:22:37:34 +1030] [Job 16] Option: Duplex=None --> Setting option
>D [16/Jan/2007:22:37:34 +1030] [Job 16] Found: %%EndSetup
>D [16/Jan/2007:22:37:34 +1030] [Job 16] Inserting PostScript code for CUPS' page accounting
>D [16/Jan/2007:22:37:34 +1030] [Job 16] 
>D [16/Jan/2007:22:37:34 +1030] [Job 16] -----------
>D [16/Jan/2007:22:37:34 +1030] [Job 16] New page:  1 1
>D [16/Jan/2007:22:37:34 +1030] [Job 16] Inserting option code into "PageSetup" section.
>D [16/Jan/2007:22:37:34 +1030] [Job 16] 
>D [16/Jan/2007:22:37:34 +1030] [Job 16] Found: %%BeginPageSetup
>D [16/Jan/2007:22:37:34 +1030] [Job 16] Found: %%EndPageSetup
>D [16/Jan/2007:22:37:34 +1030] [Job 16] End of page header
>D [16/Jan/2007:22:37:34 +1030] [Job 16] Stopping search for page header options
>D [16/Jan/2007:22:37:34 +1030] [Job 16] Found:
>D [16/Jan/2007:22:37:34 +1030] [Job 16] 1e39281e3a291f3b2b1e3a2a1d38281b39291c3a281c3b291d3e2a1f432d22442c2244292043281f
>D [16/Jan/2007:22:37:34 +1030] [Job 16] --> Output goes directly to the renderer now.
>D [16/Jan/2007:22:37:34 +1030] [Job 16] 
>D [16/Jan/2007:22:37:34 +1030] [Job 16] 
>D [16/Jan/2007:22:37:34 +1030] [Job 16] Starting renderer
>D [16/Jan/2007:22:37:34 +1030] [Job 16] JCL: <job data> 
>D [16/Jan/2007:22:37:34 +1030] [Job 16] 
>D [16/Jan/2007:22:37:34 +1030] [Job 16] renderer PID kid4=3410
>D [16/Jan/2007:22:37:34 +1030] [Job 16] renderer command: gs -q -dBATCH -dPARANOIDSAFER -dQUIET -dNOPAUSE -sDEVICE=ijs -sIjsServer=hpijs -sDeviceManufacturer="HEWLETT-PACKARD" -sDeviceModel="deskjet 5600" -dDEVICEWIDTHPOINTS=595 -dDEVICEHEIGHTPOINTS=842 -dDuplex=false -r300 -sIjsParams=Quality:Quality=0,Quality:ColorMode=2,Quality:MediaType=0,Quality:PenSet=2,PS:MediaPosition=7 -dIjsUseOutputFD -sOutputFile=- -
>D [16/Jan/2007:22:37:36 +1030] [Job 16] foomatic-gswrapper: gs '-dBATCH' '-dPARANOIDSAFER' '-dQUIET' '-dNOPAUSE' '-sDEVICE=ijs' '-sIjsServer=hpijs' '-sDeviceManufacturer=HEWLETT-PACKARD' '-sDeviceModel=deskjet 5600' '-dDEVICEWIDTHPOINTS=595' '-dDEVICEHEIGHTPOINTS=842' '-dDuplex=false' '-r300' '-sIjsParams=Quality:Quality=0,Quality:ColorMode=2,Quality:MediaType=0,Quality:PenSet=2,PS:MediaPosition=7' '-dIjsUseOutputFD' '-sOutputFile=/dev/fd/3' '/dev/fd/0' 3>&1 1>&2
>D [16/Jan/2007:22:37:36 +1030] cupsdAcceptClient: skipping getpeercon()
>D [16/Jan/2007:22:37:36 +1030] cupsdAcceptClient: 9 from localhost (Domain)
>D [16/Jan/2007:22:37:36 +1030] cupsdReadClient: 9 POST / HTTP/1.1
>D [16/Jan/2007:22:37:36 +1030] cupsdAuthorize: No authentication data provided.
>D [16/Jan/2007:22:37:36 +1030] Get-Jobs ipp://localhost/jobs
>D [16/Jan/2007:22:37:36 +1030] cupsdProcessIPPRequest: 9 status_code=0 (successful-ok)
>D [16/Jan/2007:22:37:36 +1030] cupsdCloseClient: 9
>D [16/Jan/2007:22:37:36 +1030] cupsdAcceptClient: skipping getpeercon()
>D [16/Jan/2007:22:37:36 +1030] cupsdAcceptClient: 9 from localhost (Domain)
>D [16/Jan/2007:22:37:36 +1030] cupsdReadClient: 9 POST / HTTP/1.1
>D [16/Jan/2007:22:37:36 +1030] cupsdAuthorize: No authentication data provided.
>D [16/Jan/2007:22:37:36 +1030] Get-Jobs ipp://localhost/jobs
>D [16/Jan/2007:22:37:36 +1030] Loading attributes for job 1...
>D [16/Jan/2007:22:37:36 +1030] Loading attributes for job 2...
>D [16/Jan/2007:22:37:36 +1030] Loading attributes for job 3...
>D [16/Jan/2007:22:37:36 +1030] Loading attributes for job 4...
>D [16/Jan/2007:22:37:36 +1030] Loading attributes for job 5...
>D [16/Jan/2007:22:37:36 +1030] Loading attributes for job 6...
>D [16/Jan/2007:22:37:36 +1030] Loading attributes for job 7...
>D [16/Jan/2007:22:37:36 +1030] Loading attributes for job 8...
>D [16/Jan/2007:22:37:36 +1030] Loading attributes for job 9...
>D [16/Jan/2007:22:37:36 +1030] Loading attributes for job 10...
>D [16/Jan/2007:22:37:36 +1030] Loading attributes for job 11...
>D [16/Jan/2007:22:37:36 +1030] Loading attributes for job 12...
>D [16/Jan/2007:22:37:36 +1030] Loading attributes for job 13...
>D [16/Jan/2007:22:37:36 +1030] Loading attributes for job 14...
>D [16/Jan/2007:22:37:36 +1030] Loading attributes for job 15...
>D [16/Jan/2007:22:37:36 +1030] cupsdProcessIPPRequest: 9 status_code=0 (successful-ok)
>D [16/Jan/2007:22:37:37 +1030] cupsdAcceptClient: skipping getpeercon()
>D [16/Jan/2007:22:37:37 +1030] cupsdAcceptClient: 10 from localhost (Domain)
>D [16/Jan/2007:22:37:37 +1030] cupsdReadClient: 10 GET /admin/conf/printers.conf HTTP/1.1
>D [16/Jan/2007:22:37:37 +1030] cupsdAuthorize: No authentication data provided.
>D [16/Jan/2007:22:37:37 +1030] cupsdSendError: 10 code=401 (Unauthorized)
>D [16/Jan/2007:22:37:37 +1030] cupsdCloseClient: 10
>D [16/Jan/2007:22:37:37 +1030] cupsdAcceptClient: skipping getpeercon()
>D [16/Jan/2007:22:37:37 +1030] cupsdAcceptClient: 10 from localhost (Domain)
>D [16/Jan/2007:22:37:37 +1030] cupsdReadClient: 10 GET /admin/conf/printers.conf HTTP/1.1
>D [16/Jan/2007:22:37:37 +1030] cupsdAuthorize: username="root"
>D [16/Jan/2007:22:37:37 +1030] write_file: 10 file=14
>D [16/Jan/2007:22:37:37 +1030] cupsdReadClient: 10 GET /admin/conf/classes.conf HTTP/1.1
>D [16/Jan/2007:22:37:37 +1030] cupsdAuthorize: username="root"
>D [16/Jan/2007:22:37:37 +1030] write_file: 10 file=14
>D [16/Jan/2007:22:37:37 +1030] cupsdReadClient: 10 POST / HTTP/1.1
>D [16/Jan/2007:22:37:37 +1030] cupsdAuthorize: username="root"
>D [16/Jan/2007:22:37:37 +1030] CUPS-Get-Printers
>D [16/Jan/2007:22:37:37 +1030] cupsdProcessIPPRequest: 10 status_code=0 (successful-ok)
>D [16/Jan/2007:22:37:37 +1030] cupsdReadClient: 10 POST / HTTP/1.1
>D [16/Jan/2007:22:37:37 +1030] cupsdAuthorize: username="root"
>D [16/Jan/2007:22:37:37 +1030] CUPS-Get-Classes
>D [16/Jan/2007:22:37:37 +1030] cupsdProcessIPPRequest: 10 status_code=0 (successful-ok)
>D [16/Jan/2007:22:37:37 +1030] cupsdReadClient: 10 POST / HTTP/1.1
>D [16/Jan/2007:22:37:37 +1030] cupsdAuthorize: username="root"
>D [16/Jan/2007:22:37:37 +1030] Get-Printer-Attributes ipp://localhost/printers/Photosmart_C4100
>D [16/Jan/2007:22:37:37 +1030] cupsdProcessIPPRequest: 10 status_code=0 (successful-ok)
>D [16/Jan/2007:22:37:37 +1030] cupsdReadClient: 10 POST / HTTP/1.1
>D [16/Jan/2007:22:37:37 +1030] cupsdAuthorize: username="root"
>D [16/Jan/2007:22:37:37 +1030] Get-Printer-Attributes ipp://localhost/printers/Photosmart_C4100_series
>D [16/Jan/2007:22:37:37 +1030] cupsdProcessIPPRequest: 10 status_code=0 (successful-ok)
>D [16/Jan/2007:22:37:37 +1030] cupsdReadClient: 10 POST /admin/ HTTP/1.1
>D [16/Jan/2007:22:37:37 +1030] cupsdAuthorize: username="root"
>D [16/Jan/2007:22:37:37 +1030] Pause-Printer ipp://localhost/printers/Photosmart_C4100_series
>D [16/Jan/2007:22:37:37 +1030] Discarding unused printer-state-changed event...
>I [16/Jan/2007:22:37:37 +1030] Saving printers.conf...
>I [16/Jan/2007:22:37:37 +1030] Printer "Photosmart_C4100_series" stopped by "root".
>D [16/Jan/2007:22:37:37 +1030] cupsdProcessIPPRequest: 10 status_code=0 (successful-ok)
>D [16/Jan/2007:22:37:37 +1030] cupsdCloseClient: 10
>D [16/Jan/2007:22:37:38 +1030] [Job 16] unable to read client data err=-2
>D [16/Jan/2007:22:37:38 +1030] [Job 16] sh: line 1:  3414 Segmentation fault      gs '-dBATCH' '-dPARANOIDSAFER' '-dQUIET' '-dNOPAUSE' '-sDEVICE=ijs' '-sIjsServer=hpijs' '-sDeviceManufacturer=HEWLETT-PACKARD' '-sDeviceModel=deskjet 5600' '-dDEVICEWIDTHPOINTS=595' '-dDEVICEHEIGHTPOINTS=842' '-dDuplex=false' '-r300' '-sIjsParams=Quality:Quality=0,Quality:ColorMode=2,Quality:MediaType=0,Quality:PenSet=2,PS:MediaPosition=7' '-dIjsUseOutputFD' '-sOutputFile=/dev/fd/3' '/dev/fd/0' 3>&1 1>&2
>D [16/Jan/2007:22:37:38 +1030] [Job 16] renderer return value: 139
>D [16/Jan/2007:22:37:38 +1030] [Job 16] renderer received signal: 139
>D [16/Jan/2007:22:37:38 +1030] [Job 16] Process dying with "The renderer may have dumped core.", exit stat: 3
>D [16/Jan/2007:22:37:38 +1030] [Job 16] error: Illegal seek (29)
>D [16/Jan/2007:22:37:38 +1030] [Job 16] The renderer may have dumped core.
>D [16/Jan/2007:22:37:38 +1030] [Job 16] tail process done writing data to STDOUT
>D [16/Jan/2007:22:37:38 +1030] [Job 16] KID4 finished
>D [16/Jan/2007:22:37:51 +1030] [Job 16] Wrote 1 pages...
>D [16/Jan/2007:22:37:51 +1030] PID 3405 (/usr/lib/cups/filter/pstops) exited with no errors.
>D [16/Jan/2007:22:37:51 +1030] [Job 16] 
>D [16/Jan/2007:22:37:51 +1030] [Job 16] Closing renderer
>D [16/Jan/2007:22:37:51 +1030] [Job 16] KID3 exited with status 3
>D [16/Jan/2007:22:37:51 +1030] [Job 16] Renderer exit stat: 3
>D [16/Jan/2007:22:37:51 +1030] [Job 16] Renderer process finished
>D [16/Jan/2007:22:37:51 +1030] [Job 16] Killing process 3409 (KID3)
>D [16/Jan/2007:22:37:51 +1030] [Job 16] Process dying with "Error closing renderer", exit stat: 3
>D [16/Jan/2007:22:37:51 +1030] [Job 16] error: Illegal seek (29)
>D [16/Jan/2007:22:37:51 +1030] [Job 16] Error closing renderer
>E [16/Jan/2007:22:37:51 +1030] PID 3406 (/usr/lib/cups/filter/foomatic-rip) stopped with status 3!
>D [16/Jan/2007:22:37:53 +1030] Discarding unused printer-state-changed event...
>D [16/Jan/2007:22:37:53 +1030] cupsdAcceptClient: skipping getpeercon()
>D [16/Jan/2007:22:37:53 +1030] cupsdAcceptClient: 10 from localhost (Domain)
>D [16/Jan/2007:22:37:53 +1030] cupsdCloseClient: 9
>D [16/Jan/2007:22:37:53 +1030] PID 3407 (/usr/lib/cups/backend/hp) exited with no errors.
>D [16/Jan/2007:22:37:53 +1030] [Job 16] File 0 is complete.
>D [16/Jan/2007:22:37:53 +1030] Discarding unused printer-state-changed event...
>D [16/Jan/2007:22:37:53 +1030] Discarding unused job-stopped event...
>D [16/Jan/2007:22:37:53 +1030] cupsdReadClient: 10 POST / HTTP/1.1
>D [16/Jan/2007:22:37:53 +1030] cupsdAuthorize: No authentication data provided.
>D [16/Jan/2007:22:37:53 +1030] Get-Jobs ipp://localhost/jobs
>D [16/Jan/2007:22:37:53 +1030] cupsdProcessIPPRequest: 10 status_code=0 (successful-ok)
>D [16/Jan/2007:22:37:53 +1030] cupsdAcceptClient: skipping getpeercon()
>D [16/Jan/2007:22:37:53 +1030] cupsdAcceptClient: 9 from localhost (Domain)
>D [16/Jan/2007:22:37:53 +1030] cupsdCloseClient: 10
>D [16/Jan/2007:22:37:53 +1030] cupsdReadClient: 9 POST / HTTP/1.1
>D [16/Jan/2007:22:37:53 +1030] cupsdAuthorize: No authentication data provided.
>D [16/Jan/2007:22:37:53 +1030] Get-Jobs ipp://localhost/jobs
>D [16/Jan/2007:22:37:53 +1030] cupsdProcessIPPRequest: 9 status_code=0 (successful-ok)
>D [16/Jan/2007:22:37:54 +1030] Unloading job 16...
>D [16/Jan/2007:22:38:56 +1030] Unloading job 1...
>D [16/Jan/2007:22:38:56 +1030] Unloading job 2...
>D [16/Jan/2007:22:38:56 +1030] Unloading job 3...
>D [16/Jan/2007:22:38:56 +1030] Unloading job 4...
>D [16/Jan/2007:22:38:56 +1030] Unloading job 5...
>D [16/Jan/2007:22:38:56 +1030] Unloading job 6...
>D [16/Jan/2007:22:38:56 +1030] Unloading job 7...
>D [16/Jan/2007:22:38:56 +1030] Unloading job 8...
>D [16/Jan/2007:22:38:56 +1030] Unloading job 9...
>D [16/Jan/2007:22:38:56 +1030] Unloading job 10...
>D [16/Jan/2007:22:38:56 +1030] Unloading job 11...
>D [16/Jan/2007:22:38:56 +1030] Unloading job 12...
>D [16/Jan/2007:22:38:56 +1030] Unloading job 13...
>D [16/Jan/2007:22:38:56 +1030] Unloading job 14...
>D [16/Jan/2007:22:38:56 +1030] Unloading job 15...
>D [16/Jan/2007:22:41:26 +1030] cupsdCloseClient: 13
>D [16/Jan/2007:22:42:11 +1030] cupsdAcceptClient: skipping getpeercon()
>D [16/Jan/2007:22:42:11 +1030] cupsdAcceptClient: 10 from localhost (Domain)
>D [16/Jan/2007:22:42:11 +1030] cupsdReadClient: 10 POST / HTTP/1.1
>D [16/Jan/2007:22:42:11 +1030] cupsdAuthorize: No authentication data provided.
>D [16/Jan/2007:22:42:11 +1030] CUPS-Get-Printers
>D [16/Jan/2007:22:42:11 +1030] cupsdProcessIPPRequest: 10 status_code=0 (successful-ok)
>D [16/Jan/2007:22:42:11 +1030] cupsdReadClient: 10 POST / HTTP/1.1
>D [16/Jan/2007:22:42:11 +1030] cupsdAuthorize: No authentication data provided.
>D [16/Jan/2007:22:42:11 +1030] CUPS-Get-Classes
>D [16/Jan/2007:22:42:11 +1030] cupsdProcessIPPRequest: 10 status_code=0 (successful-ok)
>D [16/Jan/2007:22:42:11 +1030] cupsdReadClient: 10 POST / HTTP/1.1
>D [16/Jan/2007:22:42:11 +1030] cupsdAuthorize: No authentication data provided.
>D [16/Jan/2007:22:42:11 +1030] CUPS-Get-Default
>D [16/Jan/2007:22:42:11 +1030] CUPS-Get-Default client-error-not-found: No default printer
>D [16/Jan/2007:22:42:11 +1030] cupsdProcessIPPRequest: 10 status_code=406 (client-error-not-found)
>D [16/Jan/2007:22:42:11 +1030] cupsdReadClient: 10 POST / HTTP/1.1
>D [16/Jan/2007:22:42:11 +1030] cupsdAuthorize: No authentication data provided.
>D [16/Jan/2007:22:42:11 +1030] CUPS-Get-Printers
>D [16/Jan/2007:22:42:11 +1030] cupsdProcessIPPRequest: 10 status_code=0 (successful-ok)
>D [16/Jan/2007:22:42:11 +1030] cupsdCloseClient: 10
>D [16/Jan/2007:22:42:37 +1030] cupsdAcceptClient: skipping getpeercon()
>D [16/Jan/2007:22:42:37 +1030] cupsdAcceptClient: 10 from localhost (Domain)
>D [16/Jan/2007:22:42:37 +1030] cupsdReadClient: 10 POST / HTTP/1.1
>D [16/Jan/2007:22:42:37 +1030] cupsdAuthorize: No authentication data provided.
>D [16/Jan/2007:22:42:37 +1030] CUPS-Get-Printers
>D [16/Jan/2007:22:42:37 +1030] cupsdProcessIPPRequest: 10 status_code=0 (successful-ok)
>D [16/Jan/2007:22:42:37 +1030] cupsdReadClient: 10 POST / HTTP/1.1
>D [16/Jan/2007:22:42:37 +1030] cupsdAuthorize: No authentication data provided.
>D [16/Jan/2007:22:42:37 +1030] CUPS-Get-Classes
>D [16/Jan/2007:22:42:37 +1030] cupsdProcessIPPRequest: 10 status_code=0 (successful-ok)
>D [16/Jan/2007:22:42:37 +1030] cupsdReadClient: 10 POST / HTTP/1.1
>D [16/Jan/2007:22:42:37 +1030] cupsdAuthorize: No authentication data provided.
>D [16/Jan/2007:22:42:37 +1030] CUPS-Get-Default
>D [16/Jan/2007:22:42:37 +1030] CUPS-Get-Default client-error-not-found: No default printer
>D [16/Jan/2007:22:42:37 +1030] cupsdProcessIPPRequest: 10 status_code=406 (client-error-not-found)
>D [16/Jan/2007:22:42:38 +1030] cupsdCloseClient: 10
>D [16/Jan/2007:22:42:39 +1030] cupsdAcceptClient: skipping getpeercon()
>D [16/Jan/2007:22:42:39 +1030] cupsdAcceptClient: 10 from localhost (Domain)
>D [16/Jan/2007:22:42:39 +1030] cupsdReadClient: 10 POST /printers/Photosmart_C4100 HTTP/1.1
>D [16/Jan/2007:22:42:39 +1030] cupsdAuthorize: No authentication data provided.
>D [16/Jan/2007:22:42:40 +1030] Print-Job ipp://localhost/printers/Photosmart_C4100
>D [16/Jan/2007:22:42:40 +1030] print_job: auto-typing file...
>D [16/Jan/2007:22:42:40 +1030] print_job: request file type is application/postscript.
>D [16/Jan/2007:22:42:40 +1030] add_job: setting context of job to UNKNOWN SL
>D [16/Jan/2007:22:42:40 +1030] add_job: requesting-user-name="tim"
>I [16/Jan/2007:22:42:40 +1030] Adding start banner page "none" to job 17.
>D [16/Jan/2007:22:42:40 +1030] Discarding unused job-created event...
>I [16/Jan/2007:22:42:40 +1030] Adding end banner page "none" to job 17.
>I [16/Jan/2007:22:42:40 +1030] Job 17 queued on "Photosmart_C4100" by "tim".
>D [16/Jan/2007:22:42:40 +1030] Job 17 hold_until = 0
>D [16/Jan/2007:22:42:40 +1030] Discarding unused printer-state-changed event...
>D [16/Jan/2007:22:42:40 +1030] job-sheets=none,none
>D [16/Jan/2007:22:42:40 +1030] banner_page = 0
>D [16/Jan/2007:22:42:40 +1030] [Job 17] argv[0]="Photosmart_C4100"
>D [16/Jan/2007:22:42:40 +1030] [Job 17] argv[1]="17"
>D [16/Jan/2007:22:42:40 +1030] [Job 17] argv[2]="tim"
>D [16/Jan/2007:22:42:40 +1030] [Job 17] argv[3]="(stdin)"
>D [16/Jan/2007:22:42:40 +1030] [Job 17] argv[4]="1"
>D [16/Jan/2007:22:42:40 +1030] [Job 17] argv[5]="job-uuid=urn:uuid:d88c5689-dfa0-3e2b-6c00-3755265d662e"
>D [16/Jan/2007:22:42:40 +1030] [Job 17] argv[6]="/var/spool/cups/d00017-001"
>D [16/Jan/2007:22:42:40 +1030] [Job 17] envp[0]="CUPS_CACHEDIR=/var/cache/cups"
>D [16/Jan/2007:22:42:40 +1030] [Job 17] envp[1]="CUPS_DATADIR=/usr/share/cups"
>D [16/Jan/2007:22:42:40 +1030] [Job 17] envp[2]="CUPS_DOCROOT=/usr/share/doc/cups-1.2.7"
>D [16/Jan/2007:22:42:40 +1030] [Job 17] envp[3]="CUPS_FONTPATH=/usr/share/cups/fonts"
>D [16/Jan/2007:22:42:40 +1030] [Job 17] envp[4]="CUPS_REQUESTROOT=/var/spool/cups"
>D [16/Jan/2007:22:42:40 +1030] [Job 17] envp[5]="CUPS_SERVERBIN=/usr/lib/cups"
>D [16/Jan/2007:22:42:40 +1030] [Job 17] envp[6]="CUPS_SERVERROOT=/etc/cups"
>D [16/Jan/2007:22:42:40 +1030] [Job 17] envp[7]="CUPS_STATEDIR=/var/run/cups"
>D [16/Jan/2007:22:42:40 +1030] [Job 17] envp[8]="PATH=/usr/lib/cups/filter:/usr/bin:/usr/sbin:/bin:/usr/bin"
>D [16/Jan/2007:22:42:40 +1030] [Job 17] envp[9]="SERVER_ADMIN=root@bergamot.wegener.org"
>D [16/Jan/2007:22:42:40 +1030] [Job 17] envp[10]="SOFTWARE=CUPS/1.2.7"
>D [16/Jan/2007:22:42:40 +1030] [Job 17] envp[11]="TMPDIR=/var/spool/cups/tmp"
>D [16/Jan/2007:22:42:40 +1030] [Job 17] envp[12]="USER=root"
>D [16/Jan/2007:22:42:40 +1030] [Job 17] envp[13]="CUPS_SERVER=/var/run/cups/cups.sock"
>D [16/Jan/2007:22:42:40 +1030] [Job 17] envp[14]="CUPS_ENCRYPTION=IfRequested"
>D [16/Jan/2007:22:42:40 +1030] [Job 17] envp[15]="IPP_PORT=631"
>D [16/Jan/2007:22:42:40 +1030] [Job 17] envp[16]="CHARSET=utf-8"
>D [16/Jan/2007:22:42:40 +1030] [Job 17] envp[17]="LANG=en_US"
>D [16/Jan/2007:22:42:40 +1030] [Job 17] envp[18]="PPD=/etc/cups/ppd/Photosmart_C4100.ppd"
>D [16/Jan/2007:22:42:40 +1030] [Job 17] envp[19]="RIP_MAX_CACHE=8m"
>D [16/Jan/2007:22:42:40 +1030] [Job 17] envp[20]="CONTENT_TYPE=application/postscript"
>D [16/Jan/2007:22:42:40 +1030] [Job 17] envp[21]="DEVICE_URI=hp:/usb/Photosmart_C4100_series?serial=MY65CB919404J7"
>D [16/Jan/2007:22:42:40 +1030] [Job 17] envp[22]="PRINTER=Photosmart_C4100"
>D [16/Jan/2007:22:42:40 +1030] [Job 17] envp[23]="FINAL_CONTENT_TYPE=printer/Photosmart_C4100"
>I [16/Jan/2007:22:42:40 +1030] Started filter /usr/lib/cups/filter/pstops (PID 3512) for job 17.
>I [16/Jan/2007:22:42:40 +1030] Started filter /usr/lib/cups/filter/foomatic-rip (PID 3513) for job 17.
>I [16/Jan/2007:22:42:40 +1030] Started backend /usr/lib/cups/backend/hp (PID 3514) for job 17.
>D [16/Jan/2007:22:42:40 +1030] Discarding unused job-state event...
>D [16/Jan/2007:22:42:40 +1030] cupsdProcessIPPRequest: 10 status_code=0 (successful-ok)
>D [16/Jan/2007:22:42:40 +1030] cupsdCloseClient: 10
>D [16/Jan/2007:22:42:40 +1030] [Job 17] Page = 595x842; 10,36 to 585,833
>D [16/Jan/2007:22:42:40 +1030] [Job 17] slow_collate=0, slow_duplex=0, slow_order=0
>D [16/Jan/2007:22:42:40 +1030] [Job 17] Before copy_comments - %!PS-Adobe-3.0
>D [16/Jan/2007:22:42:40 +1030] [Job 17] %!PS-Adobe-3.0
>D [16/Jan/2007:22:42:40 +1030] [Job 17] %%Creator: GQview Version 2.0.4
>D [16/Jan/2007:22:42:40 +1030] [Job 17] %%CreationDate:
>D [16/Jan/2007:22:42:40 +1030] [Job 17] %%LanguageLevel 2
>D [16/Jan/2007:22:42:40 +1030] [Job 17] %%DocumentMedia:
>D [16/Jan/2007:22:42:40 +1030] [Job 17] %%Orientation: Portrait
>D [16/Jan/2007:22:42:40 +1030] [Job 17] %%BoundingBox: 0.000000 0.000000 432.000000 288.000000
>E [16/Jan/2007:22:42:40 +1030] [Job 17] Bad %%BoundingBox: comment seen!
>D [16/Jan/2007:22:42:40 +1030] Discarding unused printer-state-changed event...
>D [16/Jan/2007:22:42:40 +1030] [Job 17] %%Pages: 1
>D [16/Jan/2007:22:42:40 +1030] [Job 17] %%PageOrder: Ascend
>D [16/Jan/2007:22:42:40 +1030] [Job 17] %%Title:
>D [16/Jan/2007:22:42:40 +1030] [Job 17] %% page 1
>D [16/Jan/2007:22:42:40 +1030] [Job 17] Before copy_prolog - gsave
>D [16/Jan/2007:22:42:40 +1030] cupsdAcceptClient: skipping getpeercon()
>D [16/Jan/2007:22:42:40 +1030] cupsdAcceptClient: 10 from localhost (Domain)
>D [16/Jan/2007:22:42:40 +1030] cupsdCloseClient: 9
>D [16/Jan/2007:22:42:40 +1030] cupsdReadClient: 10 POST / HTTP/1.1
>D [16/Jan/2007:22:42:40 +1030] cupsdAuthorize: No authentication data provided.
>D [16/Jan/2007:22:42:40 +1030] Get-Jobs ipp://localhost/jobs
>D [16/Jan/2007:22:42:40 +1030] Loading attributes for job 16...
>D [16/Jan/2007:22:42:40 +1030] cupsdProcessIPPRequest: 10 status_code=0 (successful-ok)
>D [16/Jan/2007:22:42:40 +1030] cupsdAcceptClient: skipping getpeercon()
>D [16/Jan/2007:22:42:40 +1030] cupsdAcceptClient: 9 from localhost (Domain)
>D [16/Jan/2007:22:42:40 +1030] cupsdCloseClient: 10
>D [16/Jan/2007:22:42:40 +1030] cupsdReadClient: 9 POST / HTTP/1.1
>D [16/Jan/2007:22:42:40 +1030] cupsdAuthorize: No authentication data provided.
>D [16/Jan/2007:22:42:40 +1030] Get-Jobs ipp://localhost/jobs
>D [16/Jan/2007:22:42:40 +1030] Loading attributes for job 1...
>D [16/Jan/2007:22:42:40 +1030] Loading attributes for job 2...
>D [16/Jan/2007:22:42:40 +1030] Loading attributes for job 3...
>D [16/Jan/2007:22:42:40 +1030] Loading attributes for job 4...
>D [16/Jan/2007:22:42:40 +1030] Loading attributes for job 5...
>D [16/Jan/2007:22:42:40 +1030] Loading attributes for job 6...
>D [16/Jan/2007:22:42:40 +1030] Loading attributes for job 7...
>D [16/Jan/2007:22:42:40 +1030] Loading attributes for job 8...
>D [16/Jan/2007:22:42:40 +1030] Loading attributes for job 9...
>D [16/Jan/2007:22:42:40 +1030] Loading attributes for job 10...
>D [16/Jan/2007:22:42:40 +1030] Loading attributes for job 11...
>D [16/Jan/2007:22:42:40 +1030] Loading attributes for job 12...
>D [16/Jan/2007:22:42:40 +1030] Loading attributes for job 13...
>D [16/Jan/2007:22:42:40 +1030] Loading attributes for job 14...
>D [16/Jan/2007:22:42:40 +1030] Loading attributes for job 15...
>D [16/Jan/2007:22:42:40 +1030] cupsdProcessIPPRequest: 9 status_code=0 (successful-ok)
>D [16/Jan/2007:22:42:41 +1030] [Job 17] foomatic-rip version $Revision: 3.43.2.15 $ running...
>D [16/Jan/2007:22:42:41 +1030] [Job 17] Parsing PPD file ...
>D [16/Jan/2007:22:42:41 +1030] [Job 17] *cupsFilter: "application/vnd.cups-postscript 0 foomatic-rip"
>D [16/Jan/2007:22:42:41 +1030] [Job 17] Added option ColorSpace
>D [16/Jan/2007:22:42:41 +1030] [Job 17] Added option Resolution
>D [16/Jan/2007:22:42:41 +1030] [Job 17] Added option PageSize
>D [16/Jan/2007:22:42:41 +1030] [Job 17] Added option PageRegion
>D [16/Jan/2007:22:42:41 +1030] [Job 17] Added option Model
>D [16/Jan/2007:22:42:41 +1030] [Job 17] Added option PrintoutMode
>D [16/Jan/2007:22:42:41 +1030] [Job 17] Added option InputSlot
>D [16/Jan/2007:22:42:41 +1030] [Job 17] Added option ImageableArea
>D [16/Jan/2007:22:42:41 +1030] [Job 17] Added option PaperDimension
>D [16/Jan/2007:22:42:41 +1030] [Job 17] Added option Duplex
>D [16/Jan/2007:22:42:41 +1030] [Job 17] Added option Quality
>D [16/Jan/2007:22:42:41 +1030] [Job 17] Added option Font
>D [16/Jan/2007:22:42:41 +1030] [Job 17] 
>D [16/Jan/2007:22:42:41 +1030] [Job 17] Parameter Summary
>D [16/Jan/2007:22:42:41 +1030] [Job 17] -----------------
>D [16/Jan/2007:22:42:41 +1030] [Job 17] 
>D [16/Jan/2007:22:42:41 +1030] [Job 17] Spooler: cups
>D [16/Jan/2007:22:42:41 +1030] [Job 17] Printer: Photosmart_C4100
>D [16/Jan/2007:22:42:41 +1030] [Job 17] PPD file: /etc/cups/ppd/Photosmart_C4100.ppd
>D [16/Jan/2007:22:42:41 +1030] [Job 17] Printer model: HP PhotoSmart C4100 Foomatic/hpijs (recommended)
>D [16/Jan/2007:22:42:41 +1030] [Job 17] Job title: stdin
>D [16/Jan/2007:22:42:41 +1030] [Job 17] File(s) to be printed: 
>D [16/Jan/2007:22:42:41 +1030] [Job 17] <STDIN>
>D [16/Jan/2007:22:42:41 +1030] [Job 17] 
>D [16/Jan/2007:22:42:41 +1030] [Job 17] GhostScript extra search path ('GS_LIB'): /usr/share/cups/fonts
>D [16/Jan/2007:22:42:41 +1030] [Job 17] Pondering option 'job-uuid=urn:uuid:d88c5689-dfa0-3e2b-6c00-3755265d662e'
>D [16/Jan/2007:22:42:41 +1030] [Job 17] Unknown option job-uuid=urn:uuid:d88c5689-dfa0-3e2b-6c00-3755265d662e.
>D [16/Jan/2007:22:42:41 +1030] [Job 17] 
>D [16/Jan/2007:22:42:41 +1030] [Job 17] ================================================
>D [16/Jan/2007:22:42:41 +1030] [Job 17] 
>D [16/Jan/2007:22:42:41 +1030] [Job 17] File: <STDIN>
>D [16/Jan/2007:22:42:41 +1030] [Job 17] 
>D [16/Jan/2007:22:42:41 +1030] [Job 17] ================================================
>D [16/Jan/2007:22:42:41 +1030] [Job 17] 
>D [16/Jan/2007:22:42:41 +1030] [Job 17] Reading PostScript input ...
>D [16/Jan/2007:22:42:41 +1030] [Job 17] --> This document is DSC-conforming!
>D [16/Jan/2007:22:42:41 +1030] [Job 17] This job seems not to be DSC-conforming, DSC-comment for next section not found, stopping to parse the rest, passing it directly to the renderer.
>D [16/Jan/2007:22:42:41 +1030] [Job 17] "Prolog" section is missing, inserting it.
>D [16/Jan/2007:22:42:41 +1030] [Job 17] "Setup" section is missing, inserting it.
>D [16/Jan/2007:22:42:41 +1030] [Job 17] Inserting PostScript code for CUPS' page accounting
>D [16/Jan/2007:22:42:41 +1030] [Job 17] "PageSetup" section is missing, inserting it.
>D [16/Jan/2007:22:42:41 +1030] [Job 17] Inserting option code into "PageSetup" section.
>D [16/Jan/2007:22:42:41 +1030] [Job 17] Stopped parsing the PostScript data, sending rest directly to renderer.
>D [16/Jan/2007:22:42:41 +1030] [Job 17] 
>D [16/Jan/2007:22:42:41 +1030] [Job 17] Starting renderer
>D [16/Jan/2007:22:42:41 +1030] [Job 17] JCL: <job data> 
>D [16/Jan/2007:22:42:41 +1030] [Job 17] 
>D [16/Jan/2007:22:42:41 +1030] [Job 17] renderer PID kid4=3532
>D [16/Jan/2007:22:42:41 +1030] [Job 17] renderer command: gs -q -dBATCH -dPARANOIDSAFER -dQUIET -dNOPAUSE -sDEVICE=ijs -sIjsServer=hpijs -sDeviceManufacturer="HEWLETT-PACKARD" -sDeviceModel="deskjet 5600" -dDEVICEWIDTHPOINTS=595 -dDEVICEHEIGHTPOINTS=842 -dDuplex=false -r300 -sIjsParams=Quality:Quality=0,Quality:ColorMode=2,Quality:MediaType=0,Quality:PenSet=2,PS:MediaPosition=7 -dIjsUseOutputFD -sOutputFile=- -
>D [16/Jan/2007:22:42:41 +1030] [Job 17] foomatic-gswrapper: gs '-dBATCH' '-dPARANOIDSAFER' '-dQUIET' '-dNOPAUSE' '-sDEVICE=ijs' '-sIjsServer=hpijs' '-sDeviceManufacturer=HEWLETT-PACKARD' '-sDeviceModel=deskjet 5600' '-dDEVICEWIDTHPOINTS=595' '-dDEVICEHEIGHTPOINTS=842' '-dDuplex=false' '-r300' '-sIjsParams=Quality:Quality=0,Quality:ColorMode=2,Quality:MediaType=0,Quality:PenSet=2,PS:MediaPosition=7' '-dIjsUseOutputFD' '-sOutputFile=/dev/fd/3' '/dev/fd/0' 3>&1 1>&2
>D [16/Jan/2007:22:42:46 +1030] [Job 17] Before copy_setup - DEBUG: Before page loop - DEBUG: Wrote 0 pages...
>D [16/Jan/2007:22:42:46 +1030] PID 3512 (/usr/lib/cups/filter/pstops) exited with no errors.
>D [16/Jan/2007:22:42:46 +1030] [Job 17] 
>D [16/Jan/2007:22:42:46 +1030] [Job 17] Closing renderer
>D [16/Jan/2007:22:42:46 +1030] Discarding unused job-progress event...
>D [16/Jan/2007:22:43:18 +1030] cupsdAcceptClient: skipping getpeercon()
>D [16/Jan/2007:22:43:18 +1030] cupsdAcceptClient: 13 from localhost (Domain)
>D [16/Jan/2007:22:43:18 +1030] cupsdCloseClient: 9
>D [16/Jan/2007:22:43:18 +1030] cupsdReadClient: 13 POST / HTTP/1.1
>D [16/Jan/2007:22:43:18 +1030] cupsdAuthorize: No authentication data provided.
>D [16/Jan/2007:22:43:18 +1030] Get-Jobs ipp://localhost/jobs
>D [16/Jan/2007:22:43:18 +1030] cupsdProcessIPPRequest: 13 status_code=0 (successful-ok)
>D [16/Jan/2007:22:43:18 +1030] cupsdAcceptClient: skipping getpeercon()
>D [16/Jan/2007:22:43:18 +1030] cupsdAcceptClient: 9 from localhost (Domain)
>D [16/Jan/2007:22:43:18 +1030] cupsdCloseClient: 13
>D [16/Jan/2007:22:43:18 +1030] cupsdReadClient: 9 POST / HTTP/1.1
>D [16/Jan/2007:22:43:18 +1030] cupsdAuthorize: No authentication data provided.
>D [16/Jan/2007:22:43:18 +1030] Get-Jobs ipp://localhost/jobs
>D [16/Jan/2007:22:43:18 +1030] cupsdProcessIPPRequest: 9 status_code=0 (successful-ok)
>D [16/Jan/2007:22:43:18 +1030] Discarding unused printer-state-changed event...
>D [16/Jan/2007:22:43:41 +1030] Unloading job 16...
>D [16/Jan/2007:22:43:48 +1030] cupsdAcceptClient: skipping getpeercon()
>D [16/Jan/2007:22:43:48 +1030] cupsdAcceptClient: 13 from localhost (Domain)
>D [16/Jan/2007:22:43:48 +1030] cupsdCloseClient: 9
>D [16/Jan/2007:22:43:48 +1030] cupsdReadClient: 13 POST / HTTP/1.1
>D [16/Jan/2007:22:43:48 +1030] cupsdAuthorize: No authentication data provided.
>D [16/Jan/2007:22:43:48 +1030] Get-Jobs ipp://localhost/jobs
>D [16/Jan/2007:22:43:48 +1030] Loading attributes for job 16...
>D [16/Jan/2007:22:43:48 +1030] cupsdProcessIPPRequest: 13 status_code=0 (successful-ok)
>D [16/Jan/2007:22:43:48 +1030] cupsdAcceptClient: skipping getpeercon()
>D [16/Jan/2007:22:43:48 +1030] cupsdAcceptClient: 9 from localhost (Domain)
>D [16/Jan/2007:22:43:48 +1030] cupsdCloseClient: 13
>D [16/Jan/2007:22:43:48 +1030] cupsdReadClient: 9 POST / HTTP/1.1
>D [16/Jan/2007:22:43:48 +1030] cupsdAuthorize: No authentication data provided.
>D [16/Jan/2007:22:43:48 +1030] Get-Jobs ipp://localhost/jobs
>D [16/Jan/2007:22:43:48 +1030] cupsdProcessIPPRequest: 9 status_code=0 (successful-ok)
>D [16/Jan/2007:22:44:05 +1030] [Job 17] KID3 exited with status 0
>D [16/Jan/2007:22:44:05 +1030] [Job 17] tail process done writing data to STDOUT
>D [16/Jan/2007:22:44:05 +1030] [Job 17] KID4 finished
>D [16/Jan/2007:22:44:05 +1030] [Job 17] KID3 finished
>D [16/Jan/2007:22:44:05 +1030] [Job 17] KID4 exited with status 0
>D [16/Jan/2007:22:44:05 +1030] [Job 17] Renderer exit stat: 0
>D [16/Jan/2007:22:44:05 +1030] [Job 17] Renderer process finished
>D [16/Jan/2007:22:44:05 +1030] [Job 17] 
>D [16/Jan/2007:22:44:05 +1030] [Job 17] Closing foomatic-rip.
>D [16/Jan/2007:22:44:05 +1030] PID 3513 (/usr/lib/cups/filter/foomatic-rip) exited with no errors.
>D [16/Jan/2007:22:44:11 +1030] Discarding unused printer-state-changed event...
>D [16/Jan/2007:22:44:11 +1030] cupsdAcceptClient: skipping getpeercon()
>D [16/Jan/2007:22:44:11 +1030] cupsdAcceptClient: 13 from localhost (Domain)
>D [16/Jan/2007:22:44:11 +1030] cupsdCloseClient: 9
>D [16/Jan/2007:22:44:11 +1030] cupsdReadClient: 13 POST / HTTP/1.1
>D [16/Jan/2007:22:44:11 +1030] cupsdAuthorize: No authentication data provided.
>D [16/Jan/2007:22:44:11 +1030] Get-Jobs ipp://localhost/jobs
>D [16/Jan/2007:22:44:11 +1030] cupsdProcessIPPRequest: 13 status_code=0 (successful-ok)
>D [16/Jan/2007:22:44:11 +1030] cupsdAcceptClient: skipping getpeercon()
>D [16/Jan/2007:22:44:11 +1030] cupsdAcceptClient: 9 from localhost (Domain)
>D [16/Jan/2007:22:44:11 +1030] cupsdCloseClient: 13
>D [16/Jan/2007:22:44:11 +1030] cupsdReadClient: 9 POST / HTTP/1.1
>D [16/Jan/2007:22:44:11 +1030] cupsdAuthorize: No authentication data provided.
>D [16/Jan/2007:22:44:11 +1030] Get-Jobs ipp://localhost/jobs
>D [16/Jan/2007:22:44:11 +1030] cupsdProcessIPPRequest: 9 status_code=0 (successful-ok)
>D [16/Jan/2007:22:44:11 +1030] PID 3514 (/usr/lib/cups/backend/hp) exited with no errors.
>D [16/Jan/2007:22:44:11 +1030] [Job 17] File 0 is complete.
>D [16/Jan/2007:22:44:11 +1030] Discarding unused printer-state-changed event...
>D [16/Jan/2007:22:44:11 +1030] Discarding unused job-completed event...
>D [16/Jan/2007:22:44:12 +1030] Unloading job 17...
>D [16/Jan/2007:22:44:52 +1030] Unloading job 16...

Actions: View

Attachments on bug 222639: 145572 | 145573 | 145677 | 145681 | 145686 | 145687 | 145688 | 145689