CUPS 1.5 Software Test Report

This software test report provides detailed test results that are used to evaluate the stability and compliance of CUPS Version 1.5.

Document Overview

This software test plan is organized into the following sections:

1 - IPP Compliance Tests

This section provides the results to the IPP compliance tests outlined in the CUPS Software Test Plan. These tests were run on 2012-07-24 by root on newbook.


"4.1-requests.test":
    No Attributes                                                        [PASS]
    Charset Attribute                                                    [PASS]
    Language Attribute                                                   [PASS]
    Language + Charset Attributes                                        [PASS]
    Charset + Language Attributes                                        [PASS]
    Charset + Language + Printer URI Attributes                          [PASS]
    Charset + Language + Job URI Attributes                              [PASS]
    Bad IPP Version                                                      [PASS]

Summary: 8 tests, 8 passed, 0 failed, 0 skipped
Score: 100%

"4.2-cups-printer-ops.test":
    Add Printer Test1                                                    [PASS]
    Verify Printer Test1 Added                                           [
"4.3-job-ops.test":
    Print PostScript Job with bad job-sheets value to Test1              [FAIL]
        RECEIVED: 133 bytes in response
        status-code = server-error-not-accepting-jobs (Destination "Test1" is not accepting jobs.)
        attributes-charset (charset) = utf-8
        attributes-natural-language (naturalLanguage) = en
        status-message (textWithoutLanguage) = Destination \"Test1\" is not accepting jobs.
        EXPECTED: STATUS client-error-bad-request (got server-error-not-accepting-jobs)
        status-message="Destination "Test1" is not accepting jobs."
    Print PostScript Job to Test1                                        [FAIL]
        RECEIVED: 133 bytes in response
        status-code = server-error-not-accepting-jobs (Destination "Test1" is not accepting jobs.)
        attributes-charset (charset) = utf-8
        attributes-natural-language (naturalLanguage) = en
        status-message (textWithoutLanguage) = Destination \"Test1\" is not accepting jobs.
        EXPECTED: STATUS successful-ok (got server-error-not-accepting-jobs)
        status-message="Destination "Test1" is not accepting jobs."
        EXPECTED: job-id
    Get Job Attributes                                                   [FAIL]
        RECEIVED: 113 bytes in response
        status-code = client-error-not-found (Job #0 does not exist.)
        attributes-charset (charset) = utf-8
        attributes-natural-language (naturalLanguage) = en
        status-message (textWithoutLanguage) = Job #0 does not exist.
        EXPECTED: STATUS successful-ok (got client-error-not-found)
        status-message="Job #0 does not exist."
        EXPECTED: job-id
        EXPECTED: job-uri
        EXPECTED: job-state
    Print JPEG Job to Test2                                              [FAIL]
        RECEIVED: 127 bytes in response
        status-code = client-error-not-found (The printer or class does not exist.)
        attributes-charset (charset) = utf-8
        attributes-natural-language (naturalLanguage) = en
        status-message (textWithoutLanguage) = The printer or class does not exist.
        EXPECTED: STATUS successful-ok (got client-error-not-found)
        status-message="The printer or class does not exist."
        EXPECTED: job-id
        EXPECTED: notify-subscription-id
    Get Job Attributes                                                   [FAIL]
        RECEIVED: 113 bytes in response
        status-code = client-error-not-found (Job #0 does not exist.)
        attributes-charset (charset) = utf-8
        attributes-natural-language (naturalLanguage) = en
        status-message (textWithoutLanguage) = Job #0 does not exist.
        EXPECTED: STATUS successful-ok (got client-error-not-found)
        status-message="Job #0 does not exist."
        EXPECTED: job-id
        EXPECTED: job-uri
        EXPECTED: job-state
    Print Text Job to Test1                                              [FAIL]
        RECEIVED: 133 bytes in response
        status-code = server-error-not-accepting-jobs (Destination "Test1" is not accepting jobs.)
        attributes-charset (charset) = utf-8
        attributes-natural-language (naturalLanguage) = en
        status-message (textWithoutLanguage) = Destination \"Test1\" is not accepting jobs.
        EXPECTED: STATUS successful-ok (got server-error-not-accepting-jobs)
        status-message="Destination "Test1" is not accepting jobs."
        EXPECTED: job-id
    Print PDF Job to Test1                                               [FAIL]
        RECEIVED: 133 bytes in response
        status-code = server-error-not-accepting-jobs (Destination "Test1" is not accepting jobs.)
        attributes-charset (charset) = utf-8
        attributes-natural-language (naturalLanguage) = en
        status-message (textWithoutLanguage) = Destination \"Test1\" is not accepting jobs.
        EXPECTED: STATUS successful-ok (got server-error-not-accepting-jobs)
        status-message="Destination "Test1" is not accepting jobs."
        EXPECTED: job-id
    Hold Job on Test1                                                    [FAIL]
        RECEIVED: 113 bytes in response
        status-code = client-error-not-found (Job #0 does not exist.)
        attributes-charset (charset) = utf-8
        attributes-natural-language (naturalLanguage) = en
        status-message (textWithoutLanguage) = Job #0 does not exist.
        EXPECTED: STATUS successful-ok (got client-error-not-found)
        status-message="Job #0 does not exist."
    Release Job on Test1                                                 [FAIL]
        RECEIVED: 113 bytes in response
        status-code = client-error-not-found (Job #0 does not exist.)
        attributes-charset (charset) = utf-8
        attributes-natural-language (naturalLanguage) = en
        status-message (textWithoutLanguage) = Job #0 does not exist.
        EXPECTED: STATUS successful-ok (got client-error-not-found)
        status-message="Job #0 does not exist."
    Print Held Image Job to Test1                                        [FAIL]
        RECEIVED: 133 bytes in response
        status-code = server-error-not-accepting-jobs (Destination "Test1" is not accepting jobs.)
        attributes-charset (charset) = utf-8
        attributes-natural-language (naturalLanguage) = en
        status-message (textWithoutLanguage) = Destination \"Test1\" is not accepting jobs.
        EXPECTED: STATUS successful-ok (got server-error-not-accepting-jobs)
        status-message="Destination "Test1" is not accepting jobs."
        EXPECTED: job-id
    Cancel Job                                                           [FAIL]
        RECEIVED: 113 bytes in response
        status-code = client-error-not-found (Job #0 does not exist.)
        attributes-charset (charset) = utf-8
        attributes-natural-language (naturalLanguage) = en
        status-message (textWithoutLanguage) = Job #0 does not exist.
        EXPECTED: STATUS successful-ok (got client-error-not-found)
        status-message="Job #0 does not exist."
    Get Job List on Test1                                                [PASS]
    Get All Jobs                                                         [FAIL]
        RECEIVED: 72 bytes in response
        status-code = successful-ok (successful-ok)
        attributes-charset (charset) = utf-8
        attributes-natural-language (naturalLanguage) = en
        EXPECTED: job-uri
        EXPECTED: job-id
        EXPECTED: job-state
        EXPECTED: job-printer-uri

Summary: 13 tests, 1 passed, 12 failed, 0 skipped
Score: 7%

"4.4-subscription-ops.test":
    Add Printer Subscription w/Lease                                     [PASS]
        notify-subscription-id (integer) = 1
    [7 second delay]
    Verify Subscription Expiration                                       [PASS]
    Add 2 Printer Subscriptions w/Lease                                  [PASS]
        notify-subscription-id (integer) = 2
        notify-subscription-id (integer) = 3
    List Printer Subscriptions                                           [PASS]
        notify-events (keyword) = printer-state-changed
        notify-printer-uri (uri) = ipp://localhost:8631/printers/Test1
        notify-subscription-id (integer) = 2
        notify-events (keyword) = printer-config-changed
        notify-printer-uri (uri) = ipp://localhost:8631/printers/Test1
        notify-subscription-id (integer) = 3
    Check MaxSubscriptions limits                                        [FAIL]
        RECEIVED: 104 bytes in response
        status-code = successful-ok (successful-ok)
        attributes-charset (charset) = utf-8
        attributes-natural-language (naturalLanguage) = en
        notify-subscription-id (integer) = 4
        EXPECTED: STATUS client-error-too-many-subscriptions (got successful-ok)

Summary: 5 tests, 4 passed, 1 failed, 0 skipped
Score: 80%

2 - Command Tests

This section provides the results to the command tests outlined in the CUPS Software Test Plan. These tests were run on 2012-07-24 by root on newbook.


"5.1-lpadmin.sh":
Add Printer Test

    lpadmin -p Test3 -v file:/dev/null -E -m drv:///sample.drv/deskjet.ppd
lpadmin: Unable to copy PPD file.
    FAILED

"5.2-lpc.sh":
LPC Test

    lpc status
test-1:
	printer is on device '/dev/null' speed -1
	queuing is enabled
	printing is enabled
	no entries
	daemon present
test-10:
	printer is on device '/dev/null' speed -1
	queuing is enabled
	printing is enabled
	no entries
	daemon present
test-11:
	printer is on device '/dev/null' speed -1
	queuing is enabled
	printing is enabled
	no entries
	daemon present
test-12:
	printer is on device '/dev/null' speed -1
	queuing is enabled
	printing is enabled
	no entries
	daemon present
test-13:
	printer is on device '/dev/null' speed -1
	queuing is enabled
	printing is enabled
	no entries
	daemon present
test-14:
	printer is on device '/dev/null' speed -1
	queuing is enabled
	printing is enabled
	no entries
	daemon present
test-15:
	printer is on device '/dev/null' speed -1
	queuing is enabled
	printing is enabled
	no entries
	daemon present
test-16:
	printer is on device '/dev/null' speed -1
	queuing is enabled
	printing is enabled
	no entries
	daemon present
test-17:
	printer is on device '/dev/null' speed -1
	queuing is enabled
	printing is enabled
	no entries
	daemon present
test-18:
	printer is on device '/dev/null' speed -1
	queuing is enabled
	printing is enabled
	no entries
	daemon present
test-19:
	printer is on device '/dev/null' speed -1
	queuing is enabled
	printing is enabled
	no entries
	daemon present
test-2:
	printer is on device '/dev/null' speed -1
	queuing is enabled
	printing is enabled
	no entries
	daemon present
test-20:
	printer is on device '/dev/null' speed -1
	queuing is enabled
	printing is enabled
	no entries
	daemon present
test-3:
	printer is on device '/dev/null' speed -1
	queuing is enabled
	printing is enabled
	no entries
	daemon present
test-4:
	printer is on device '/dev/null' speed -1
	queuing is enabled
	printing is enabled
	no entries
	daemon present
test-5:
	printer is on device '/dev/null' speed -1
	queuing is enabled
	printing is enabled
	no entries
	daemon present
test-6:
	printer is on device '/dev/null' speed -1
	queuing is enabled
	printing is enabled
	no entries
	daemon present
test-7:
	printer is on device '/dev/null' speed -1
	queuing is enabled
	printing is enabled
	no entries
	daemon present
test-8:
	printer is on device '/dev/null' speed -1
	queuing is enabled
	printing is enabled
	no entries
	daemon present
test-9:
	printer is on device '/dev/null' speed -1
	queuing is enabled
	printing is enabled
	no entries
	daemon present
Test1:
	printer is on device '///dev/null' speed -1
	queuing is disabled
	printing is disabled
	no entries
	daemon present
Test3:
	printer is on device '///dev/null' speed -1
	queuing is enabled
	printing is enabled
	no entries
	daemon present
    PASSED


"5.3-lpq.sh":
LPQ Test

    lpq -P Test1
Test1 is not ready
no entries
    PASSED


"5.4-lpstat.sh":
LPSTAT Test

    lpstat -t
scheduler is running
no system default destination
device for test-1: /dev/null
device for test-10: /dev/null
device for test-11: /dev/null
device for test-12: /dev/null
device for test-13: /dev/null
device for test-14: /dev/null
device for test-15: /dev/null
device for test-16: /dev/null
device for test-17: /dev/null
device for test-18: /dev/null
device for test-19: /dev/null
device for test-2: /dev/null
device for test-20: /dev/null
device for test-3: /dev/null
device for test-4: /dev/null
device for test-5: /dev/null
device for test-6: /dev/null
device for test-7: /dev/null
device for test-8: /dev/null
device for test-9: /dev/null
device for Test1: ///dev/null
device for Test3: ///dev/null
test-1 accepting requests since Tue Jul 24 22:39:36 2012
test-10 accepting requests since Tue Jul 24 22:39:36 2012
test-11 accepting requests since Tue Jul 24 22:39:36 2012
test-12 accepting requests since Tue Jul 24 22:39:36 2012
test-13 accepting requests since Tue Jul 24 22:39:36 2012
test-14 accepting requests since Tue Jul 24 22:39:36 2012
test-15 accepting requests since Tue Jul 24 22:39:36 2012
test-16 accepting requests since Tue Jul 24 22:39:36 2012
test-17 accepting requests since Tue Jul 24 22:39:36 2012
test-18 accepting requests since Tue Jul 24 22:39:36 2012
test-19 accepting requests since Tue Jul 24 22:39:36 2012
test-2 accepting requests since Tue Jul 24 22:39:36 2012
test-20 accepting requests since Tue Jul 24 22:39:36 2012
test-3 accepting requests since Tue Jul 24 22:39:36 2012
test-4 accepting requests since Tue Jul 24 22:39:36 2012
test-5 accepting requests since Tue Jul 24 22:39:36 2012
test-6 accepting requests since Tue Jul 24 22:39:36 2012
test-7 accepting requests since Tue Jul 24 22:39:36 2012
test-8 accepting requests since Tue Jul 24 22:39:36 2012
test-9 accepting requests since Tue Jul 24 22:39:36 2012
Test1 not accepting requests since Tue Jul 24 22:39:42 2012 -
	reason unknown
Test3 accepting requests since Tue Jul 24 22:39:49 2012
printer test-1 is idle.  enabled since Tue Jul 24 22:39:36 2012
	Printer  is idle.
printer test-10 is idle.  enabled since Tue Jul 24 22:39:36 2012
	Printer  is idle.
printer test-11 is idle.  enabled since Tue Jul 24 22:39:36 2012
	Printer  is idle.
printer test-12 is idle.  enabled since Tue Jul 24 22:39:36 2012
	Printer  is idle.
printer test-13 is idle.  enabled since Tue Jul 24 22:39:36 2012
	Printer  is idle.
printer test-14 is idle.  enabled since Tue Jul 24 22:39:36 2012
	Printer  is idle.
printer test-15 is idle.  enabled since Tue Jul 24 22:39:36 2012
	Printer  is idle.
printer test-16 is idle.  enabled since Tue Jul 24 22:39:36 2012
	Printer  is idle.
printer test-17 is idle.  enabled since Tue Jul 24 22:39:36 2012
	Printer  is idle.
printer test-18 is idle.  enabled since Tue Jul 24 22:39:36 2012
	Printer  is idle.
printer test-19 is idle.  enabled since Tue Jul 24 22:39:36 2012
	Printer  is idle.
printer test-2 is idle.  enabled since Tue Jul 24 22:39:36 2012
	Printer  is idle.
printer test-20 is idle.  enabled since Tue Jul 24 22:39:36 2012
	Printer  is idle.
printer test-3 is idle.  enabled since Tue Jul 24 22:39:36 2012
	Printer  is idle.
printer test-4 is idle.  enabled since Tue Jul 24 22:39:36 2012
	Printer  is idle.
printer test-5 is idle.  enabled since Tue Jul 24 22:39:36 2012
	Printer  is idle.
printer test-6 is idle.  enabled since Tue Jul 24 22:39:36 2012
	Printer  is idle.
printer test-7 is idle.  enabled since Tue Jul 24 22:39:36 2012
	Printer  is idle.
printer test-8 is idle.  enabled since Tue Jul 24 22:39:36 2012
	Printer  is idle.
printer test-9 is idle.  enabled since Tue Jul 24 22:39:36 2012
	Printer  is idle.
printer Test1 disabled since Tue Jul 24 22:39:42 2012 -
	reason unknown
printer Test3 is idle.  enabled since Tue Jul 24 22:39:49 2012
    PASSED

LPSTAT Test

    lpstat -H
    PASSED (localhost:8631)


"5.5-lp.sh":
LP Default Test

    lp testfile.pdf
./systemv/lp: Error - no default destination available.
    FAILED

"5.6-lpr.sh":
LPR Default Test

    lpr testfile.pdf
./berkeley/lpr: Error - no default destination available.
    FAILED

"5.7-lprm.sh":
LPRM Current Test

    lpr -o job-hold-until=indefinite testfile.jpg
./berkeley/lpr: Error - no default destination available.
    lprm
    PASSED

LPRM Destination Test

    lpr -P Test1 -o job-hold-until=indefinite testfile.jpg
./berkeley/lpr: Destination "Test1" is not accepting jobs.
    lprm Test1
./berkeley/lprm: No active jobs on Test1.
    FAILED

"5.8-cancel.sh":
Cancel Destination Test

    lp -d Test1 -o job-hold-until=indefinite testfile.jpg
./systemv/lp: Destination "Test1" is not accepting jobs.
    cancel Test1
./systemv/cancel: cancel-job failed: No active jobs on Test1.
    FAILED

"5.9-lpinfo.sh":
LPINFO Devices Test

    lpinfo -v
lpinfo: cups-deviced failed to execute.
    FAILED

3 - Log Files

Summary

PASS: All job control files purged.

PASS: Printer 'Test1' correctly produced 0 page(s).

FAIL: Printer 'Test2' produced 0 page(s), expected 43.

FAIL: 27 requests logged, expected 1015.

PASS: CUPS-Get-Default not logged.

PASS: 0 emergency messages.

PASS: 0 alert messages.

PASS: 0 critical messages.

FAIL: 29 error messages, expected 18.

E [24/Jul/2012:22:39:42.547398 +0000] Returning IPP client-error-bad-request for Get-Jobs (no URI) from localhost
E [24/Jul/2012:22:39:42.551837 +0000] Missing attributes-natural-language attribute
E [24/Jul/2012:22:39:42.552009 +0000] Missing printer-uri, job-uri, or ppd-name attribute
E [24/Jul/2012:22:39:42.552529 +0000] Returning IPP client-error-bad-request for Get-Jobs (no URI) from localhost
E [24/Jul/2012:22:39:42.556566 +0000] Missing attributes-charset attribute
E [24/Jul/2012:22:39:42.556737 +0000] Missing attributes-natural-language attribute
E [24/Jul/2012:22:39:42.556901 +0000] Missing printer-uri, job-uri, or ppd-name attribute
E [24/Jul/2012:22:39:42.557321 +0000] Returning IPP client-error-bad-request for Get-Jobs (no URI) from localhost
E [24/Jul/2012:22:39:42.561391 +0000] Missing attributes-charset attribute
E [24/Jul/2012:22:39:42.561563 +0000] Missing attributes-natural-language attribute
E [24/Jul/2012:22:39:42.561727 +0000] Missing printer-uri, job-uri, or ppd-name attribute
E [24/Jul/2012:22:39:42.562200 +0000] Returning IPP client-error-bad-request for Get-Jobs (no URI) from localhost
E [24/Jul/2012:22:39:42.566386 +0000] Missing printer-uri, job-uri, or ppd-name attribute
E [24/Jul/2012:22:39:42.566868 +0000] Returning IPP client-error-bad-request for Get-Jobs (no URI) from localhost
E [24/Jul/2012:22:39:42.576108 +0000] Returning IPP client-error-bad-request for Get-Jobs (ipp://localhost:8631/jobs) from localhost
E [24/Jul/2012:22:39:42.580597 +0000] Returning IPP server-error-version-not-supported for Get-Jobs (no URI) from localhost
E [24/Jul/2012:22:39:42.817091 +0000] Returning IPP server-error-not-accepting-jobs for Print-Job (ipp://localhost:8631/printers/Test1) from localhost
E [24/Jul/2012:22:39:42.821735 +0000] Returning IPP server-error-not-accepting-jobs for Print-Job (ipp://localhost:8631/printers/Test1) from localhost
E [24/Jul/2012:22:39:42.842505 +0000] Returning IPP server-error-not-accepting-jobs for Print-Job (ipp://localhost:8631/printers/Test1) from localhost
E [24/Jul/2012:22:39:42.856835 +0000] Returning IPP server-error-not-accepting-jobs for Print-Job (ipp://localhost:8631/printers/Test1) from localhost
E [24/Jul/2012:22:39:42.872813 +0000] Returning IPP server-error-not-accepting-jobs for Print-Job (ipp://localhost:8631/printers/Test1) from localhost
E [24/Jul/2012:22:39:59.987517 +0000] Directory "/tmp/cups-root/bin/daemon" has insecure permissions (040775/uid=501/gid=10).
E [24/Jul/2012:22:39:59.987755 +0000] Returning IPP server-error-internal-error for CUPS-Add-Modify-Printer (ipp://localhost:8631/printers/Test3) from localhost
E [24/Jul/2012:22:40:00.330355 +0000] Returning IPP server-error-not-accepting-jobs for Create-Job (ipp://localhost:8631/printers/Test1) from localhost
E [24/Jul/2012:22:40:00.355468 +0000] Returning IPP client-error-not-possible for Cancel-Job (ipp://localhost:8631/printers/Test1) from localhost
E [24/Jul/2012:22:40:00.373068 +0000] Returning IPP server-error-not-accepting-jobs for Create-Job (ipp://localhost:8631/printers/Test1) from localhost
E [24/Jul/2012:22:40:00.438671 +0000] Returning IPP client-error-not-possible for Cancel-Job (ipp://localhost/printers/Test1) from localhost
E [24/Jul/2012:22:40:00.450835 +0000] Directory "/tmp/cups-root/bin/daemon" has insecure permissions (040775/uid=501/gid=10).
E [24/Jul/2012:22:40:00.451046 +0000] Returning IPP server-error-internal-error for CUPS-Get-Devices (no URI) from localhost

PASS: 9 warning messages.

PASS: 0 notice messages.

PASS: 31 info messages.

PASS: 805 debug messages.

PASS: 7512 debug2 messages.

access_log

localhost - - [24/Jul/2012:22:39:42.546084 +0000] "POST /printers HTTP/1.1" 200 9 Get-Jobs client-error-bad-request
localhost - - [24/Jul/2012:22:39:42.550835 +0000] "POST /printers HTTP/1.1" 200 38 Get-Jobs client-error-bad-request
localhost - - [24/Jul/2012:22:39:42.555446 +0000] "POST /printers HTTP/1.1" 200 44 Get-Jobs client-error-bad-request
localhost - - [24/Jul/2012:22:39:42.560278 +0000] "POST /printers HTTP/1.1" 200 72 Get-Jobs client-error-bad-request
localhost - - [24/Jul/2012:22:39:42.565174 +0000] "POST /printers HTTP/1.1" 200 72 Get-Jobs client-error-bad-request
localhost - - [24/Jul/2012:22:39:42.574506 +0000] "POST /printers HTTP/1.1" 200 109 Get-Jobs client-error-bad-request
localhost - - [24/Jul/2012:22:39:42.578999 +0000] "POST /printers HTTP/1.1" 200 112 Get-Jobs server-error-version-not-supported
localhost - - [24/Jul/2012:22:39:42.593502 +0000] "POST /admin/ HTTP/1.1" 200 9273 CUPS-Add-Modify-Printer successful-ok
localhost - - [24/Jul/2012:22:39:42.814835 +0000] "POST /printers/Test1 HTTP/1.1" 200 17502 Print-Job server-error-not-accepting-jobs
localhost - - [24/Jul/2012:22:39:42.819695 +0000] "POST /printers/Test1 HTTP/1.1" 200 17473 Print-Job server-error-not-accepting-jobs
localhost - - [24/Jul/2012:22:39:42.827290 +0000] "POST /printers/Test2 HTTP/1.1" 200 204348 Print-Job client-error-not-found
localhost - - [24/Jul/2012:22:39:42.840425 +0000] "POST /printers/Test1 HTTP/1.1" 200 3904 Print-Job server-error-not-accepting-jobs
localhost - - [24/Jul/2012:22:39:42.845802 +0000] "POST /printers/Test1 HTTP/1.1" 200 279925 Print-Job server-error-not-accepting-jobs
localhost - - [24/Jul/2012:22:39:42.859412 +0000] "POST /printers/Test1 HTTP/1.1" 200 167 Hold-Job client-error-not-found
localhost - - [24/Jul/2012:22:39:42.862663 +0000] "POST /printers/Test1 HTTP/1.1" 200 167 Release-Job client-error-not-found
localhost - - [24/Jul/2012:22:39:42.865970 +0000] "POST /printers/Test1 HTTP/1.1" 200 204338 Print-Job server-error-not-accepting-jobs
localhost - - [24/Jul/2012:22:39:42.875265 +0000] "POST /jobs HTTP/1.1" 200 139 Cancel-Job client-error-not-found
localhost - - [24/Jul/2012:22:39:42.892502 +0000] "POST / HTTP/1.1" 200 260 Create-Printer-Subscription successful-ok
localhost - - [24/Jul/2012:22:39:49.902091 +0000] "POST / HTTP/1.1" 200 369 Create-Printer-Subscription successful-ok
localhost - - [24/Jul/2012:22:39:49.916603 +0000] "POST / HTTP/1.1" 200 260 Create-Printer-Subscription successful-ok
localhost - - [24/Jul/2012:22:39:49.939256 +0000] "POST /admin/ HTTP/1.1" 200 206 CUPS-Add-Modify-Printer successful-ok
localhost - - [24/Jul/2012:22:39:59.984657 +0000] "POST /admin/ HTTP/1.1" 200 224 CUPS-Add-Modify-Printer server-error-internal-error
localhost - - [24/Jul/2012:22:40:00.327087 +0000] "POST /printers/Test1 HTTP/1.1" 200 352 Create-Job server-error-not-accepting-jobs
localhost - - [24/Jul/2012:22:40:00.354549 +0000] "POST /jobs/ HTTP/1.1" 200 167 Cancel-Job client-error-not-possible
localhost - - [24/Jul/2012:22:40:00.371272 +0000] "POST /printers/Test1 HTTP/1.1" 200 352 Create-Job server-error-not-accepting-jobs
localhost - - [24/Jul/2012:22:40:00.437690 +0000] "POST /jobs/ HTTP/1.1" 200 162 Cancel-Job client-error-not-possible
localhost - - [24/Jul/2012:22:40:00.448112 +0000] "POST / HTTP/1.1" 200 72 CUPS-Get-Devices server-error-internal-error

error_log

W [24/Jul/2012:22:39:36.459902 +0000] No limit for Validate-Job defined in policy default and no suitable template found.
W [24/Jul/2012:22:39:36.460080 +0000] No limit for Cancel-Jobs defined in policy default and no suitable template found.
W [24/Jul/2012:22:39:36.460261 +0000] No limit for Cancel-My-Jobs defined in policy default and no suitable template found.
W [24/Jul/2012:22:39:36.460448 +0000] No limit for Close-Job defined in policy default and no suitable template found.
W [24/Jul/2012:22:39:36.460626 +0000] No limit for CUPS-Get-Document defined in policy default and no suitable template found.
W [24/Jul/2012:22:39:36.460662 +0000] No JobPrivateAccess defined in policy default - using defaults.
W [24/Jul/2012:22:39:36.460707 +0000] No JobPrivateValues defined in policy default - using defaults.
W [24/Jul/2012:22:39:36.460757 +0000] No SubscriptionPrivateAccess defined in policy default - using defaults.
W [24/Jul/2012:22:39:36.460799 +0000] No SubscriptionPrivateValues defined in policy default - using defaults.
I [24/Jul/2012:22:39:36.460875 +0000] Remote access is disabled.
D [24/Jul/2012:22:39:36.460923 +0000] Added auto ServerAlias newbook
I [24/Jul/2012:22:39:36.461277 +0000] Loaded configuration file "/tmp/cups-root/cupsd.conf"
D [24/Jul/2012:22:39:36.461335 +0000] Repairing ownership of "/tmp/cups-root/spool"
D [24/Jul/2012:22:39:36.461387 +0000] Repairing access permissions of "/tmp/cups-root/spool"
D [24/Jul/2012:22:39:36.461445 +0000] Repairing ownership of "/tmp/cups-root/share"
D [24/Jul/2012:22:39:36.461498 +0000] Repairing access permissions of "/tmp/cups-root/share"
D [24/Jul/2012:22:39:36.461566 +0000] Creating missing directory "/tmp/cups-root/share/rss"
D [24/Jul/2012:22:39:36.461687 +0000] Repairing ownership of "/tmp/cups-root/share/rss"
D [24/Jul/2012:22:39:36.461739 +0000] Repairing access permissions of "/tmp/cups-root/share/rss"
D [24/Jul/2012:22:39:36.461833 +0000] Repairing ownership of "/tmp/cups-root"
D [24/Jul/2012:22:39:36.461894 +0000] Repairing ownership of "/tmp/cups-root/certs"
D [24/Jul/2012:22:39:36.461944 +0000] Repairing access permissions of "/tmp/cups-root/certs"
D [24/Jul/2012:22:39:36.462005 +0000] Repairing ownership of "/tmp/cups-root/ppd"
D [24/Jul/2012:22:39:36.462067 +0000] Repairing ownership of "/tmp/cups-root/ssl"
D [24/Jul/2012:22:39:36.462117 +0000] Repairing access permissions of "/tmp/cups-root/ssl"
D [24/Jul/2012:22:39:36.462178 +0000] Repairing ownership of "/tmp/cups-root/cupsd.conf"
D [24/Jul/2012:22:39:36.462230 +0000] Repairing access permissions of "/tmp/cups-root/cupsd.conf"
D [24/Jul/2012:22:39:36.462314 +0000] Repairing ownership of "/tmp/cups-root/printers.conf"
D [24/Jul/2012:22:39:36.462437 +0000] Repairing access permissions of "/tmp/cups-root/printers.conf"
D [24/Jul/2012:22:39:36.462511 +0000] Repairing ownership of "/tmp/cups-root/spool/temp"
D [24/Jul/2012:22:39:36.462564 +0000] Repairing access permissions of "/tmp/cups-root/spool/temp"
I [24/Jul/2012:22:39:36.463546 +0000] Configured for up to 100 clients.
I [24/Jul/2012:22:39:36.463583 +0000] Allowing up to 100 client connections per host.
I [24/Jul/2012:22:39:36.463624 +0000] Using policy "default" as the default.
I [24/Jul/2012:22:39:36.463730 +0000] Full reload is required.
I [24/Jul/2012:22:39:36.465817 +0000] Loaded MIME database from "/tmp/cups-root/share/mime" and "/tmp/cups-root": 35 types, 40 filters...
D [24/Jul/2012:22:39:36.469239 +0000] Loading printer test-1...
D [24/Jul/2012:22:39:36.470124 +0000] cupsdMarkDirty(P-----)
D [24/Jul/2012:22:39:36.470158 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Not busy"
D [24/Jul/2012:22:39:36.470185 +0000] load_ppd: Loading /tmp/cups-root/ppd/test-1.ppd...
D [24/Jul/2012:22:39:36.479577 +0000] load_ppd: Saving /tmp/cups-root/share/test-1.data...
D [24/Jul/2012:22:39:36.488198 +0000] cupsdRegisterPrinter(p=0x40fcffa0(test-1))
D [24/Jul/2012:22:39:36.488233 +0000] Loading printer test-2...
D [24/Jul/2012:22:39:36.488648 +0000] cupsdMarkDirty(P-----)
D [24/Jul/2012:22:39:36.488679 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [24/Jul/2012:22:39:36.488707 +0000] load_ppd: Loading /tmp/cups-root/ppd/test-2.ppd...
D [24/Jul/2012:22:39:36.497424 +0000] load_ppd: Saving /tmp/cups-root/share/test-2.data...
D [24/Jul/2012:22:39:36.505968 +0000] cupsdRegisterPrinter(p=0x40fd5570(test-2))
D [24/Jul/2012:22:39:36.506003 +0000] Loading printer test-3...
D [24/Jul/2012:22:39:36.506420 +0000] cupsdMarkDirty(P-----)
D [24/Jul/2012:22:39:36.506451 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [24/Jul/2012:22:39:36.506478 +0000] load_ppd: Loading /tmp/cups-root/ppd/test-3.ppd...
D [24/Jul/2012:22:39:36.515084 +0000] load_ppd: Saving /tmp/cups-root/share/test-3.data...
D [24/Jul/2012:22:39:36.523713 +0000] cupsdRegisterPrinter(p=0x41053850(test-3))
D [24/Jul/2012:22:39:36.523748 +0000] Loading printer test-4...
D [24/Jul/2012:22:39:36.524169 +0000] cupsdMarkDirty(P-----)
D [24/Jul/2012:22:39:36.524200 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [24/Jul/2012:22:39:36.524227 +0000] load_ppd: Loading /tmp/cups-root/ppd/test-4.ppd...
D [24/Jul/2012:22:39:36.532889 +0000] load_ppd: Saving /tmp/cups-root/share/test-4.data...
D [24/Jul/2012:22:39:36.541574 +0000] cupsdRegisterPrinter(p=0x41053000(test-4))
D [24/Jul/2012:22:39:36.541608 +0000] Loading printer test-5...
D [24/Jul/2012:22:39:36.542031 +0000] cupsdMarkDirty(P-----)
D [24/Jul/2012:22:39:36.542062 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [24/Jul/2012:22:39:36.542089 +0000] load_ppd: Loading /tmp/cups-root/ppd/test-5.ppd...
D [24/Jul/2012:22:39:36.550769 +0000] load_ppd: Saving /tmp/cups-root/share/test-5.data...
D [24/Jul/2012:22:39:36.559509 +0000] cupsdRegisterPrinter(p=0x40fe1960(test-5))
D [24/Jul/2012:22:39:36.559544 +0000] Loading printer test-6...
D [24/Jul/2012:22:39:36.559968 +0000] cupsdMarkDirty(P-----)
D [24/Jul/2012:22:39:36.559999 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [24/Jul/2012:22:39:36.560026 +0000] load_ppd: Loading /tmp/cups-root/ppd/test-6.ppd...
D [24/Jul/2012:22:39:36.568772 +0000] load_ppd: Saving /tmp/cups-root/share/test-6.data...
D [24/Jul/2012:22:39:36.577867 +0000] cupsdRegisterPrinter(p=0x4106fe80(test-6))
D [24/Jul/2012:22:39:36.577902 +0000] Loading printer test-7...
D [24/Jul/2012:22:39:36.578329 +0000] cupsdMarkDirty(P-----)
D [24/Jul/2012:22:39:36.578360 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [24/Jul/2012:22:39:36.578387 +0000] load_ppd: Loading /tmp/cups-root/ppd/test-7.ppd...
D [24/Jul/2012:22:39:36.587198 +0000] load_ppd: Saving /tmp/cups-root/share/test-7.data...
D [24/Jul/2012:22:39:36.596370 +0000] cupsdRegisterPrinter(p=0x41032b20(test-7))
D [24/Jul/2012:22:39:36.596405 +0000] Loading printer test-8...
D [24/Jul/2012:22:39:36.596831 +0000] cupsdMarkDirty(P-----)
D [24/Jul/2012:22:39:36.596862 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [24/Jul/2012:22:39:36.596920 +0000] load_ppd: Loading /tmp/cups-root/ppd/test-8.ppd...
D [24/Jul/2012:22:39:36.605714 +0000] load_ppd: Saving /tmp/cups-root/share/test-8.data...
D [24/Jul/2012:22:39:36.614943 +0000] cupsdRegisterPrinter(p=0x41033950(test-8))
D [24/Jul/2012:22:39:36.614978 +0000] Loading printer test-9...
D [24/Jul/2012:22:39:36.615410 +0000] cupsdMarkDirty(P-----)
D [24/Jul/2012:22:39:36.615441 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [24/Jul/2012:22:39:36.615468 +0000] load_ppd: Loading /tmp/cups-root/ppd/test-9.ppd...
D [24/Jul/2012:22:39:36.624394 +0000] load_ppd: Saving /tmp/cups-root/share/test-9.data...
D [24/Jul/2012:22:39:36.633732 +0000] cupsdRegisterPrinter(p=0x4108c650(test-9))
D [24/Jul/2012:22:39:36.633768 +0000] Loading printer test-10...
D [24/Jul/2012:22:39:36.634236 +0000] cupsdMarkDirty(P-----)
D [24/Jul/2012:22:39:36.634267 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [24/Jul/2012:22:39:36.634294 +0000] load_ppd: Loading /tmp/cups-root/ppd/test-10.ppd...
D [24/Jul/2012:22:39:36.643121 +0000] load_ppd: Saving /tmp/cups-root/share/test-10.data...
D [24/Jul/2012:22:39:36.652635 +0000] cupsdRegisterPrinter(p=0x410a4810(test-10))
D [24/Jul/2012:22:39:36.652670 +0000] Loading printer test-11...
D [24/Jul/2012:22:39:36.653117 +0000] cupsdMarkDirty(P-----)
D [24/Jul/2012:22:39:36.653149 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [24/Jul/2012:22:39:36.653175 +0000] load_ppd: Loading /tmp/cups-root/ppd/test-11.ppd...
D [24/Jul/2012:22:39:36.653536 +0000] cupsdRegisterPrinter(p=0x410bc9d0(test-11))
D [24/Jul/2012:22:39:36.653568 +0000] Loading printer test-12...
D [24/Jul/2012:22:39:36.654019 +0000] cupsdMarkDirty(P-----)
D [24/Jul/2012:22:39:36.654050 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [24/Jul/2012:22:39:36.654077 +0000] load_ppd: Loading /tmp/cups-root/ppd/test-12.ppd...
D [24/Jul/2012:22:39:36.654420 +0000] cupsdRegisterPrinter(p=0x410d4c70(test-12))
D [24/Jul/2012:22:39:36.654452 +0000] Loading printer test-13...
D [24/Jul/2012:22:39:36.654866 +0000] cupsdMarkDirty(P-----)
D [24/Jul/2012:22:39:36.654897 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [24/Jul/2012:22:39:36.654924 +0000] load_ppd: Loading /tmp/cups-root/ppd/test-13.ppd...
D [24/Jul/2012:22:39:36.655266 +0000] cupsdRegisterPrinter(p=0x410588d0(test-13))
D [24/Jul/2012:22:39:36.655298 +0000] Loading printer test-14...
D [24/Jul/2012:22:39:36.655739 +0000] cupsdMarkDirty(P-----)
D [24/Jul/2012:22:39:36.655770 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [24/Jul/2012:22:39:36.655797 +0000] load_ppd: Loading /tmp/cups-root/ppd/test-14.ppd...
D [24/Jul/2012:22:39:36.656175 +0000] cupsdRegisterPrinter(p=0x410598f0(test-14))
D [24/Jul/2012:22:39:36.656208 +0000] Loading printer test-15...
D [24/Jul/2012:22:39:36.656622 +0000] cupsdMarkDirty(P-----)
D [24/Jul/2012:22:39:36.656653 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [24/Jul/2012:22:39:36.656680 +0000] load_ppd: Loading /tmp/cups-root/ppd/test-15.ppd...
D [24/Jul/2012:22:39:36.657024 +0000] cupsdRegisterPrinter(p=0x4106d540(test-15))
D [24/Jul/2012:22:39:36.657056 +0000] Loading printer test-16...
D [24/Jul/2012:22:39:36.657469 +0000] cupsdMarkDirty(P-----)
D [24/Jul/2012:22:39:36.657499 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [24/Jul/2012:22:39:36.657526 +0000] load_ppd: Loading /tmp/cups-root/ppd/test-16.ppd...
D [24/Jul/2012:22:39:36.657875 +0000] cupsdRegisterPrinter(p=0x4106e530(test-16))
D [24/Jul/2012:22:39:36.657936 +0000] Loading printer test-17...
D [24/Jul/2012:22:39:36.658358 +0000] cupsdMarkDirty(P-----)
D [24/Jul/2012:22:39:36.658389 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [24/Jul/2012:22:39:36.658416 +0000] load_ppd: Loading /tmp/cups-root/ppd/test-17.ppd...
D [24/Jul/2012:22:39:36.658761 +0000] cupsdRegisterPrinter(p=0x410ea060(test-17))
D [24/Jul/2012:22:39:36.658793 +0000] Loading printer test-18...
D [24/Jul/2012:22:39:36.659233 +0000] cupsdMarkDirty(P-----)
D [24/Jul/2012:22:39:36.659264 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [24/Jul/2012:22:39:36.659291 +0000] load_ppd: Loading /tmp/cups-root/ppd/test-18.ppd...
D [24/Jul/2012:22:39:36.659630 +0000] cupsdRegisterPrinter(p=0x410eab70(test-18))
D [24/Jul/2012:22:39:36.659662 +0000] Loading printer test-19...
D [24/Jul/2012:22:39:36.660106 +0000] cupsdMarkDirty(P-----)
D [24/Jul/2012:22:39:36.660137 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [24/Jul/2012:22:39:36.660164 +0000] load_ppd: Loading /tmp/cups-root/ppd/test-19.ppd...
D [24/Jul/2012:22:39:36.660504 +0000] cupsdRegisterPrinter(p=0x410ebb60(test-19))
D [24/Jul/2012:22:39:36.660536 +0000] Loading printer test-20...
D [24/Jul/2012:22:39:36.660963 +0000] cupsdMarkDirty(P-----)
D [24/Jul/2012:22:39:36.660994 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [24/Jul/2012:22:39:36.661021 +0000] load_ppd: Loading /tmp/cups-root/ppd/test-20.ppd...
D [24/Jul/2012:22:39:36.661360 +0000] cupsdRegisterPrinter(p=0x410ecb50(test-20))
D [24/Jul/2012:22:39:36.661438 +0000] cupsdLoadRemoteCache: Not loading remote cache.
D [24/Jul/2012:22:39:36.662036 +0000] Scanning /tmp/cups-root/spool for jobs...
I [24/Jul/2012:22:39:36.662447 +0000] Full reload complete.
D [24/Jul/2012:22:39:36.662487 +0000] cupsdCleanFiles(path="/tmp/cups-root/spool/temp", pattern="(null)")
I [24/Jul/2012:22:39:36.662530 +0000] Cleaning out old files in "/tmp/cups-root/spool/temp"...
D [24/Jul/2012:22:39:36.662593 +0000] cupsdCleanFiles(path="/tmp/cups-root/share", pattern="*.ipp")
I [24/Jul/2012:22:39:36.662636 +0000] Cleaning out old files in "/tmp/cups-root/share"...
I [24/Jul/2012:22:39:36.663053 +0000] Listening to 127.0.0.1:8631 on fd 7...
I [24/Jul/2012:22:39:36.663212 +0000] Resuming new connection processing...
D [24/Jul/2012:22:39:36.663417 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [24/Jul/2012:22:39:36.665726 +0000] Discarding unused server-started event...
D [24/Jul/2012:22:39:37.666880 +0000] Report: clients=0
D [24/Jul/2012:22:39:37.666960 +0000] Report: jobs=0
D [24/Jul/2012:22:39:37.667013 +0000] Report: jobs-active=0
D [24/Jul/2012:22:39:37.667063 +0000] Report: printers=20
D [24/Jul/2012:22:39:37.667113 +0000] Report: printers-implicit=0
D [24/Jul/2012:22:39:37.667288 +0000] Report: stringpool-string-count=20666
D [24/Jul/2012:22:39:37.667341 +0000] Report: stringpool-alloc-bytes=11632
D [24/Jul/2012:22:39:37.667391 +0000] Report: stringpool-total-bytes=383816
D [24/Jul/2012:22:39:42.518748 +0000] cupsdAcceptClient: 10 from localhost:8631 (IPv4)
D [24/Jul/2012:22:39:42.519242 +0000] cupsdReadClient: 10 WAITING Closing on EOF
D [24/Jul/2012:22:39:42.519318 +0000] cupsdCloseClient: 10
D [24/Jul/2012:22:39:42.519398 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [24/Jul/2012:22:39:42.545416 +0000] cupsdAcceptClient: 10 from localhost:8631 (IPv4)
D [24/Jul/2012:22:39:42.546102 +0000] cupsdReadClient: 10 POST /printers HTTP/1.1
D [24/Jul/2012:22:39:42.546170 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [24/Jul/2012:22:39:42.546634 +0000] cupsdAuthorize: No authentication data provided.
D [24/Jul/2012:22:39:42.546993 +0000] cupsdReadClient: 10 1.1 Get-Jobs 9455
D [24/Jul/2012:22:39:42.547185 +0000] Discarding unused server-audit event...
D [24/Jul/2012:22:39:42.547254 +0000] Get-Jobs client-error-bad-request: No attributes in request.
E [24/Jul/2012:22:39:42.547398 +0000] Returning IPP client-error-bad-request for Get-Jobs (no URI) from localhost
D [24/Jul/2012:22:39:42.548615 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [24/Jul/2012:22:39:42.550853 +0000] cupsdReadClient: 10 POST /printers HTTP/1.1
D [24/Jul/2012:22:39:42.550918 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [24/Jul/2012:22:39:42.551249 +0000] cupsdAuthorize: No authentication data provided.
D [24/Jul/2012:22:39:42.551689 +0000] cupsdReadClient: 10 1.1 Get-Jobs 9456
E [24/Jul/2012:22:39:42.551837 +0000] Missing attributes-natural-language attribute
D [24/Jul/2012:22:39:42.551959 +0000] Discarding unused server-audit event...
E [24/Jul/2012:22:39:42.552009 +0000] Missing printer-uri, job-uri, or ppd-name attribute
D [24/Jul/2012:22:39:42.552123 +0000] Discarding unused server-audit event...
D [24/Jul/2012:22:39:42.552173 +0000] Request attributes follow...
D [24/Jul/2012:22:39:42.552227 +0000] attr "attributes-charset": group_tag = 1, value_tag = 47
D [24/Jul/2012:22:39:42.552276 +0000] End of attributes...
D [24/Jul/2012:22:39:42.552335 +0000] Get-Jobs client-error-bad-request: Missing required attributes.
E [24/Jul/2012:22:39:42.552529 +0000] Returning IPP client-error-bad-request for Get-Jobs (no URI) from localhost
D [24/Jul/2012:22:39:42.553698 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [24/Jul/2012:22:39:42.555464 +0000] cupsdReadClient: 10 POST /printers HTTP/1.1
D [24/Jul/2012:22:39:42.555528 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [24/Jul/2012:22:39:42.555974 +0000] cupsdAuthorize: No authentication data provided.
D [24/Jul/2012:22:39:42.556413 +0000] cupsdReadClient: 10 1.1 Get-Jobs 9457
E [24/Jul/2012:22:39:42.556566 +0000] Missing attributes-charset attribute
D [24/Jul/2012:22:39:42.556687 +0000] Discarding unused server-audit event...
E [24/Jul/2012:22:39:42.556737 +0000] Missing attributes-natural-language attribute
D [24/Jul/2012:22:39:42.556851 +0000] Discarding unused server-audit event...
E [24/Jul/2012:22:39:42.556901 +0000] Missing printer-uri, job-uri, or ppd-name attribute
D [24/Jul/2012:22:39:42.557014 +0000] Discarding unused server-audit event...
D [24/Jul/2012:22:39:42.557063 +0000] Request attributes follow...
D [24/Jul/2012:22:39:42.557118 +0000] attr "attributes-natural-language": group_tag = 1, value_tag = 48
D [24/Jul/2012:22:39:42.557167 +0000] End of attributes...
D [24/Jul/2012:22:39:42.557225 +0000] Get-Jobs client-error-bad-request: Missing required attributes.
E [24/Jul/2012:22:39:42.557321 +0000] Returning IPP client-error-bad-request for Get-Jobs (no URI) from localhost
D [24/Jul/2012:22:39:42.558466 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [24/Jul/2012:22:39:42.560296 +0000] cupsdReadClient: 10 POST /printers HTTP/1.1
D [24/Jul/2012:22:39:42.560360 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [24/Jul/2012:22:39:42.560692 +0000] cupsdAuthorize: No authentication data provided.
D [24/Jul/2012:22:39:42.561257 +0000] cupsdReadClient: 10 1.1 Get-Jobs 9458
E [24/Jul/2012:22:39:42.561391 +0000] Missing attributes-charset attribute
D [24/Jul/2012:22:39:42.561513 +0000] Discarding unused server-audit event...
E [24/Jul/2012:22:39:42.561563 +0000] Missing attributes-natural-language attribute
D [24/Jul/2012:22:39:42.561677 +0000] Discarding unused server-audit event...
E [24/Jul/2012:22:39:42.561727 +0000] Missing printer-uri, job-uri, or ppd-name attribute
D [24/Jul/2012:22:39:42.561840 +0000] Discarding unused server-audit event...
D [24/Jul/2012:22:39:42.561889 +0000] Request attributes follow...
D [24/Jul/2012:22:39:42.561944 +0000] attr "attributes-natural-language": group_tag = 1, value_tag = 48
D [24/Jul/2012:22:39:42.561998 +0000] attr "attributes-charset": group_tag = 1, value_tag = 47
D [24/Jul/2012:22:39:42.562047 +0000] End of attributes...
D [24/Jul/2012:22:39:42.562105 +0000] Get-Jobs client-error-bad-request: Missing required attributes.
E [24/Jul/2012:22:39:42.562200 +0000] Returning IPP client-error-bad-request for Get-Jobs (no URI) from localhost
D [24/Jul/2012:22:39:42.563431 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [24/Jul/2012:22:39:42.565191 +0000] cupsdReadClient: 10 POST /printers HTTP/1.1
D [24/Jul/2012:22:39:42.565256 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [24/Jul/2012:22:39:42.565587 +0000] cupsdAuthorize: No authentication data provided.
D [24/Jul/2012:22:39:42.566251 +0000] cupsdReadClient: 10 1.1 Get-Jobs 9459
E [24/Jul/2012:22:39:42.566386 +0000] Missing printer-uri, job-uri, or ppd-name attribute
D [24/Jul/2012:22:39:42.566508 +0000] Discarding unused server-audit event...
D [24/Jul/2012:22:39:42.566557 +0000] Request attributes follow...
D [24/Jul/2012:22:39:42.566612 +0000] attr "attributes-charset": group_tag = 1, value_tag = 47
D [24/Jul/2012:22:39:42.566666 +0000] attr "attributes-natural-language": group_tag = 1, value_tag = 48
D [24/Jul/2012:22:39:42.566715 +0000] End of attributes...
D [24/Jul/2012:22:39:42.566774 +0000] Get-Jobs client-error-bad-request: Missing required attributes.
E [24/Jul/2012:22:39:42.566868 +0000] Returning IPP client-error-bad-request for Get-Jobs (no URI) from localhost
D [24/Jul/2012:22:39:42.567947 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [24/Jul/2012:22:39:42.569871 +0000] cupsdReadClient: 10 POST /printers HTTP/1.1
D [24/Jul/2012:22:39:42.569936 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [24/Jul/2012:22:39:42.570268 +0000] cupsdAuthorize: No authentication data provided.
D [24/Jul/2012:22:39:42.570964 +0000] cupsdReadClient: 10 1.1 Get-Jobs 9460
D [24/Jul/2012:22:39:42.571105 +0000] Get-Jobs ipp://localhost:8631/printers
D [24/Jul/2012:22:39:42.571675 +0000] Returning IPP successful-ok for Get-Jobs (ipp://localhost:8631/printers) from localhost
D [24/Jul/2012:22:39:42.572678 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [24/Jul/2012:22:39:42.574523 +0000] cupsdReadClient: 10 POST /printers HTTP/1.1
D [24/Jul/2012:22:39:42.574587 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [24/Jul/2012:22:39:42.574986 +0000] cupsdAuthorize: No authentication data provided.
D [24/Jul/2012:22:39:42.575685 +0000] cupsdReadClient: 10 1.1 Get-Jobs 9461
D [24/Jul/2012:22:39:42.575893 +0000] Get-Jobs ipp://localhost:8631/jobs
D [24/Jul/2012:22:39:42.576014 +0000] Get-Jobs client-error-bad-request: No printer-uri in request.
E [24/Jul/2012:22:39:42.576108 +0000] Returning IPP client-error-bad-request for Get-Jobs (ipp://localhost:8631/jobs) from localhost
D [24/Jul/2012:22:39:42.577207 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [24/Jul/2012:22:39:42.579016 +0000] cupsdReadClient: 10 POST /printers HTTP/1.1
D [24/Jul/2012:22:39:42.579138 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [24/Jul/2012:22:39:42.579476 +0000] cupsdAuthorize: No authentication data provided.
D [24/Jul/2012:22:39:42.580246 +0000] cupsdReadClient: 10 0.0 Get-Jobs 9462
D [24/Jul/2012:22:39:42.580426 +0000] Discarding unused server-audit event...
D [24/Jul/2012:22:39:42.580488 +0000] Get-Jobs server-error-version-not-supported: Bad request version number 0.0.
E [24/Jul/2012:22:39:42.580597 +0000] Returning IPP server-error-version-not-supported for Get-Jobs (no URI) from localhost
D [24/Jul/2012:22:39:42.581698 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [24/Jul/2012:22:39:42.583268 +0000] cupsdReadClient: 10 WAITING Closing on EOF
D [24/Jul/2012:22:39:42.583343 +0000] cupsdCloseClient: 10
D [24/Jul/2012:22:39:42.583419 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [24/Jul/2012:22:39:42.593093 +0000] cupsdAcceptClient: 10 from localhost:8631 (IPv4)
D [24/Jul/2012:22:39:42.593514 +0000] cupsdReadClient: 10 POST /admin/ HTTP/1.1
D [24/Jul/2012:22:39:42.593552 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [24/Jul/2012:22:39:42.593727 +0000] cupsdAuthorize: No authentication data provided.
D [24/Jul/2012:22:39:42.594285 +0000] cupsdReadClient: 10 1.1 CUPS-Add-Modify-Printer 9455
D [24/Jul/2012:22:39:42.594720 +0000] CUPS-Add-Modify-Printer ipp://localhost:8631/printers/Test1
D [24/Jul/2012:22:39:42.595519 +0000] Copied PPD file successfully
D [24/Jul/2012:22:39:42.595616 +0000] cupsdMarkDirty(P-----)
D [24/Jul/2012:22:39:42.595646 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [24/Jul/2012:22:39:42.595970 +0000] cupsdMarkDirty(P-----)
D [24/Jul/2012:22:39:42.596000 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [24/Jul/2012:22:39:42.596028 +0000] load_ppd: Loading /tmp/cups-root/ppd/Test1.ppd...
D [24/Jul/2012:22:39:42.606951 +0000] load_ppd: Saving /tmp/cups-root/share/Test1.data...
D [24/Jul/2012:22:39:42.617570 +0000] cupsdRegisterPrinter(p=0x40fda160(Test1))
D [24/Jul/2012:22:39:42.617602 +0000] cupsdMarkDirty(P-----)
D [24/Jul/2012:22:39:42.617631 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [24/Jul/2012:22:39:42.617690 +0000] cupsdMarkDirty(---p--)
D [24/Jul/2012:22:39:42.617754 +0000] Discarding unused printer-added event...
I [24/Jul/2012:22:39:42.617783 +0000] New printer "Test1" added by "anonymous".
D [24/Jul/2012:22:39:42.617816 +0000] Returning IPP successful-ok for CUPS-Add-Modify-Printer (ipp://localhost:8631/printers/Test1) from localhost
D [24/Jul/2012:22:39:42.618478 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [24/Jul/2012:22:39:42.619747 +0000] cupsdReadClient: 10 POST / HTTP/1.1
D [24/Jul/2012:22:39:42.619781 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [24/Jul/2012:22:39:42.619957 +0000] cupsdAuthorize: No authentication data provided.
D [24/Jul/2012:22:39:42.620334 +0000] cupsdReadClient: 10 1.1 Get-Printer-Attributes 9456
D [24/Jul/2012:22:39:42.620409 +0000] Get-Printer-Attributes ipp://localhost:8631/printers/Test1
D [24/Jul/2012:22:39:42.624247 +0000] Returning IPP successful-ok for Get-Printer-Attributes (ipp://localhost:8631/printers/Test1) from localhost
D [24/Jul/2012:22:39:42.631364 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [24/Jul/2012:22:39:42.805123 +0000] cupsdReadClient: 10 WAITING Closing on EOF
D [24/Jul/2012:22:39:42.805167 +0000] cupsdCloseClient: 10
D [24/Jul/2012:22:39:42.805212 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [24/Jul/2012:22:39:42.814355 +0000] cupsdAcceptClient: 10 from localhost:8631 (IPv4)
D [24/Jul/2012:22:39:42.814849 +0000] cupsdReadClient: 10 POST /printers/Test1 HTTP/1.1
D [24/Jul/2012:22:39:42.814886 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [24/Jul/2012:22:39:42.815064 +0000] cupsdAuthorize: No authentication data provided.
D [24/Jul/2012:22:39:42.815819 +0000] cupsdReadClient: 10 1.1 Print-Job 9455
D [24/Jul/2012:22:39:42.816435 +0000] Print-Job ipp://localhost:8631/printers/Test1
D [24/Jul/2012:22:39:42.816536 +0000] [Job ???] Auto-typing file...
I [24/Jul/2012:22:39:42.816730 +0000] [Job ???] Request file type is application/postscript.
D [24/Jul/2012:22:39:42.817035 +0000] Print-Job server-error-not-accepting-jobs: Destination "Test1" is not accepting jobs.
E [24/Jul/2012:22:39:42.817091 +0000] Returning IPP server-error-not-accepting-jobs for Print-Job (ipp://localhost:8631/printers/Test1) from localhost
D [24/Jul/2012:22:39:42.817806 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [24/Jul/2012:22:39:42.819705 +0000] cupsdReadClient: 10 POST /printers/Test1 HTTP/1.1
D [24/Jul/2012:22:39:42.819741 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [24/Jul/2012:22:39:42.819917 +0000] cupsdAuthorize: No authentication data provided.
D [24/Jul/2012:22:39:42.820447 +0000] cupsdReadClient: 10 1.1 Print-Job 9456
D [24/Jul/2012:22:39:42.821124 +0000] Print-Job ipp://localhost:8631/printers/Test1
D [24/Jul/2012:22:39:42.821197 +0000] [Job ???] Auto-typing file...
I [24/Jul/2012:22:39:42.821390 +0000] [Job ???] Request file type is application/postscript.
D [24/Jul/2012:22:39:42.821684 +0000] Print-Job server-error-not-accepting-jobs: Destination "Test1" is not accepting jobs.
E [24/Jul/2012:22:39:42.821735 +0000] Returning IPP server-error-not-accepting-jobs for Print-Job (ipp://localhost:8631/printers/Test1) from localhost
D [24/Jul/2012:22:39:42.822530 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [24/Jul/2012:22:39:42.824165 +0000] cupsdReadClient: 10 POST /jobs HTTP/1.1
D [24/Jul/2012:22:39:42.824199 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [24/Jul/2012:22:39:42.824375 +0000] cupsdAuthorize: No authentication data provided.
D [24/Jul/2012:22:39:42.824865 +0000] cupsdReadClient: 10 1.1 Get-Job-Attributes 9457
D [24/Jul/2012:22:39:42.824939 +0000] Get-Job-Attributes ipp://localhost:8631/printers/Test1
D [24/Jul/2012:22:39:42.825005 +0000] Get-Job-Attributes client-error-not-found: Job #0 does not exist.
D [24/Jul/2012:22:39:42.825054 +0000] Returning IPP client-error-not-found for Get-Job-Attributes (ipp://localhost:8631/printers/Test1) from localhost
D [24/Jul/2012:22:39:42.825606 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [24/Jul/2012:22:39:42.827300 +0000] cupsdReadClient: 10 POST /printers/Test2 HTTP/1.1
D [24/Jul/2012:22:39:42.827334 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [24/Jul/2012:22:39:42.827509 +0000] cupsdAuthorize: No authentication data provided.
D [24/Jul/2012:22:39:42.828184 +0000] cupsdReadClient: 10 1.1 Print-Job 9458
D [24/Jul/2012:22:39:42.833620 +0000] Print-Job ipp://localhost:8631/printers/Test2
D [24/Jul/2012:22:39:42.833715 +0000] Print-Job client-error-not-found: The printer or class does not exist.
D [24/Jul/2012:22:39:42.833777 +0000] Returning IPP client-error-not-found for Print-Job (ipp://localhost:8631/printers/Test2) from localhost
D [24/Jul/2012:22:39:42.834763 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [24/Jul/2012:22:39:42.836787 +0000] cupsdReadClient: 10 POST /jobs HTTP/1.1
D [24/Jul/2012:22:39:42.836827 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [24/Jul/2012:22:39:42.837038 +0000] cupsdAuthorize: No authentication data provided.
D [24/Jul/2012:22:39:42.837599 +0000] cupsdReadClient: 10 1.1 Get-Job-Attributes 9459
D [24/Jul/2012:22:39:42.837687 +0000] Get-Job-Attributes ipp://localhost:8631/printers/Test2
D [24/Jul/2012:22:39:42.837766 +0000] Get-Job-Attributes client-error-not-found: Job #0 does not exist.
D [24/Jul/2012:22:39:42.837825 +0000] Returning IPP client-error-not-found for Get-Job-Attributes (ipp://localhost:8631/printers/Test2) from localhost
D [24/Jul/2012:22:39:42.838464 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [24/Jul/2012:22:39:42.840437 +0000] cupsdReadClient: 10 POST /printers/Test1 HTTP/1.1
D [24/Jul/2012:22:39:42.840478 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [24/Jul/2012:22:39:42.840684 +0000] cupsdAuthorize: No authentication data provided.
D [24/Jul/2012:22:39:42.841298 +0000] cupsdReadClient: 10 1.1 Print-Job 9460
D [24/Jul/2012:22:39:42.841712 +0000] Print-Job ipp://localhost:8631/printers/Test1
D [24/Jul/2012:22:39:42.841801 +0000] [Job ???] Auto-typing file...
I [24/Jul/2012:22:39:42.842027 +0000] [Job ???] Request file type is text/plain.
D [24/Jul/2012:22:39:42.842336 +0000] Print-Job server-error-not-accepting-jobs: Destination "Test1" is not accepting jobs.
E [24/Jul/2012:22:39:42.842505 +0000] Returning IPP server-error-not-accepting-jobs for Print-Job (ipp://localhost:8631/printers/Test1) from localhost
D [24/Jul/2012:22:39:42.843450 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [24/Jul/2012:22:39:42.845816 +0000] cupsdReadClient: 10 POST /printers/Test1 HTTP/1.1
D [24/Jul/2012:22:39:42.845869 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [24/Jul/2012:22:39:42.846125 +0000] cupsdAuthorize: No authentication data provided.
D [24/Jul/2012:22:39:42.847096 +0000] cupsdReadClient: 10 1.1 Print-Job 9461
D [24/Jul/2012:22:39:42.856192 +0000] Print-Job ipp://localhost:8631/printers/Test1
D [24/Jul/2012:22:39:42.856292 +0000] [Job ???] Auto-typing file...
I [24/Jul/2012:22:39:42.856485 +0000] [Job ???] Request file type is application/pdf.
D [24/Jul/2012:22:39:42.856783 +0000] Print-Job server-error-not-accepting-jobs: Destination "Test1" is not accepting jobs.
E [24/Jul/2012:22:39:42.856835 +0000] Returning IPP server-error-not-accepting-jobs for Print-Job (ipp://localhost:8631/printers/Test1) from localhost
D [24/Jul/2012:22:39:42.857763 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [24/Jul/2012:22:39:42.859422 +0000] cupsdReadClient: 10 POST /printers/Test1 HTTP/1.1
D [24/Jul/2012:22:39:42.859456 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [24/Jul/2012:22:39:42.859634 +0000] cupsdAuthorize: No authentication data provided.
D [24/Jul/2012:22:39:42.860179 +0000] cupsdReadClient: 10 1.1 Hold-Job 9462
D [24/Jul/2012:22:39:42.860255 +0000] Hold-Job ipp://localhost:8631/printers/Test1
D [24/Jul/2012:22:39:42.860322 +0000] Hold-Job client-error-not-found: Job #0 does not exist.
D [24/Jul/2012:22:39:42.860372 +0000] Returning IPP client-error-not-found for Hold-Job (ipp://localhost:8631/printers/Test1) from localhost
D [24/Jul/2012:22:39:42.860969 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [24/Jul/2012:22:39:42.862677 +0000] cupsdReadClient: 10 POST /printers/Test1 HTTP/1.1
D [24/Jul/2012:22:39:42.862727 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [24/Jul/2012:22:39:42.862975 +0000] cupsdAuthorize: No authentication data provided.
D [24/Jul/2012:22:39:42.863474 +0000] cupsdReadClient: 10 1.1 Release-Job 9463
D [24/Jul/2012:22:39:42.863596 +0000] Release-Job ipp://localhost:8631/printers/Test1
D [24/Jul/2012:22:39:42.863674 +0000] Release-Job client-error-not-found: Job #0 does not exist.
D [24/Jul/2012:22:39:42.863725 +0000] Returning IPP client-error-not-found for Release-Job (ipp://localhost:8631/printers/Test1) from localhost
D [24/Jul/2012:22:39:42.864328 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [24/Jul/2012:22:39:42.865980 +0000] cupsdReadClient: 10 POST /printers/Test1 HTTP/1.1
D [24/Jul/2012:22:39:42.866017 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [24/Jul/2012:22:39:42.866192 +0000] cupsdAuthorize: No authentication data provided.
D [24/Jul/2012:22:39:42.866824 +0000] cupsdReadClient: 10 1.1 Print-Job 9464
D [24/Jul/2012:22:39:42.872193 +0000] Print-Job ipp://localhost:8631/printers/Test1
D [24/Jul/2012:22:39:42.872268 +0000] [Job ???] Auto-typing file...
I [24/Jul/2012:22:39:42.872489 +0000] [Job ???] Request file type is image/jpeg.
D [24/Jul/2012:22:39:42.872761 +0000] Print-Job server-error-not-accepting-jobs: Destination "Test1" is not accepting jobs.
E [24/Jul/2012:22:39:42.872813 +0000] Returning IPP server-error-not-accepting-jobs for Print-Job (ipp://localhost:8631/printers/Test1) from localhost
D [24/Jul/2012:22:39:42.873677 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [24/Jul/2012:22:39:42.875275 +0000] cupsdReadClient: 10 POST /jobs HTTP/1.1
D [24/Jul/2012:22:39:42.875308 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [24/Jul/2012:22:39:42.875485 +0000] cupsdAuthorize: No authentication data provided.
D [24/Jul/2012:22:39:42.876004 +0000] cupsdReadClient: 10 1.1 Cancel-Job 9465
D [24/Jul/2012:22:39:42.876078 +0000] Cancel-Job ipp://localhost:8631/jobs/
D [24/Jul/2012:22:39:42.876152 +0000] Cancel-Job client-error-not-found: Job #0 does not exist.
D [24/Jul/2012:22:39:42.876203 +0000] Returning IPP client-error-not-found for Cancel-Job (ipp://localhost:8631/jobs/) from localhost
D [24/Jul/2012:22:39:42.876799 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [24/Jul/2012:22:39:42.878345 +0000] cupsdReadClient: 10 POST /printers/Test1 HTTP/1.1
D [24/Jul/2012:22:39:42.878378 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [24/Jul/2012:22:39:42.878553 +0000] cupsdAuthorize: No authentication data provided.
D [24/Jul/2012:22:39:42.878974 +0000] cupsdReadClient: 10 1.1 Get-Jobs 9466
D [24/Jul/2012:22:39:42.879084 +0000] Get-Jobs ipp://localhost:8631/printers/Test1
D [24/Jul/2012:22:39:42.879379 +0000] Returning IPP successful-ok for Get-Jobs (ipp://localhost:8631/printers/Test1) from localhost
D [24/Jul/2012:22:39:42.879871 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [24/Jul/2012:22:39:42.880868 +0000] cupsdReadClient: 10 POST /jobs HTTP/1.1
D [24/Jul/2012:22:39:42.880902 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [24/Jul/2012:22:39:42.881077 +0000] cupsdAuthorize: No authentication data provided.
D [24/Jul/2012:22:39:42.881521 +0000] cupsdReadClient: 10 1.1 Get-Jobs 9467
D [24/Jul/2012:22:39:42.881642 +0000] Get-Jobs ipp://localhost:8631/
D [24/Jul/2012:22:39:42.881917 +0000] Returning IPP successful-ok for Get-Jobs (ipp://localhost:8631/) from localhost
D [24/Jul/2012:22:39:42.882501 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [24/Jul/2012:22:39:42.884195 +0000] cupsdReadClient: 10 WAITING Closing on EOF
D [24/Jul/2012:22:39:42.884239 +0000] cupsdCloseClient: 10
D [24/Jul/2012:22:39:42.884286 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [24/Jul/2012:22:39:42.891856 +0000] cupsdAcceptClient: 10 from localhost:8631 (IPv4)
D [24/Jul/2012:22:39:42.892520 +0000] cupsdReadClient: 10 POST / HTTP/1.1
D [24/Jul/2012:22:39:42.892586 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [24/Jul/2012:22:39:42.892841 +0000] cupsdAuthorize: No authentication data provided.
D [24/Jul/2012:22:39:42.893856 +0000] cupsdReadClient: 10 1.1 Create-Printer-Subscription 9455
D [24/Jul/2012:22:39:42.893967 +0000] Create-Printer-Subscription ipp://localhost:8631/printers/Test1
D [24/Jul/2012:22:39:42.894023 +0000] cupsdCreateSubscription(con=0x4110fde0(10), uri="ipp://localhost:8631/printers/Test1")
D [24/Jul/2012:22:39:42.894417 +0000] recipient="testnotify://"
D [24/Jul/2012:22:39:42.894460 +0000] notify-lease-duration=5
D [24/Jul/2012:22:39:42.894499 +0000] notify-time-interval=0
D [24/Jul/2012:22:39:42.894544 +0000] cupsdAddSubscription(mask=f, dest=0x40fda160(Test1), job=0(0), uri="testnotify://")
D [24/Jul/2012:22:39:42.894595 +0000] Added subscription #1 for printer "Test1".
D [24/Jul/2012:22:39:42.894658 +0000] cupsdMarkDirty(-----S)
D [24/Jul/2012:22:39:42.894701 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [24/Jul/2012:22:39:42.894747 +0000] Returning IPP successful-ok for Create-Printer-Subscription (ipp://localhost:8631/printers/Test1) from localhost
D [24/Jul/2012:22:39:42.895632 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
I [24/Jul/2012:22:39:48.901970 +0000] Subscription 1 has expired...
D [24/Jul/2012:22:39:48.902095 +0000] cupsdMarkDirty(-----S)
D [24/Jul/2012:22:39:48.902142 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [24/Jul/2012:22:39:49.897697 +0000] cupsdReadClient: 10 POST / HTTP/1.1
D [24/Jul/2012:22:39:49.897745 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [24/Jul/2012:22:39:49.898001 +0000] cupsdAuthorize: No authentication data provided.
D [24/Jul/2012:22:39:49.898737 +0000] cupsdReadClient: 10 1.1 Get-Subscription-Attributes 9456
D [24/Jul/2012:22:39:49.898848 +0000] Get-Subscription-Attributes ipp://localhost:8631/printers/Test1
D [24/Jul/2012:22:39:49.898942 +0000] Get-Subscription-Attributes client-error-not-found: Subscription #1 does not exist.
D [24/Jul/2012:22:39:49.899016 +0000] Returning IPP client-error-not-found for Get-Subscription-Attributes (ipp://localhost:8631/printers/Test1) from localhost
D [24/Jul/2012:22:39:49.899864 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [24/Jul/2012:22:39:49.902110 +0000] cupsdReadClient: 10 POST / HTTP/1.1
D [24/Jul/2012:22:39:49.902176 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [24/Jul/2012:22:39:49.902569 +0000] cupsdAuthorize: No authentication data provided.
D [24/Jul/2012:22:39:49.904118 +0000] cupsdReadClient: 10 1.1 Create-Printer-Subscription 9457
D [24/Jul/2012:22:39:49.904266 +0000] Create-Printer-Subscription ipp://localhost:8631/printers/Test1
D [24/Jul/2012:22:39:49.904328 +0000] cupsdCreateSubscription(con=0x4110fde0(10), uri="ipp://localhost:8631/printers/Test1")
D [24/Jul/2012:22:39:49.904830 +0000] recipient="testnotify://"
D [24/Jul/2012:22:39:49.904945 +0000] notify-lease-duration=5
D [24/Jul/2012:22:39:49.904999 +0000] notify-time-interval=0
D [24/Jul/2012:22:39:49.905059 +0000] cupsdAddSubscription(mask=f, dest=0x40fda160(Test1), job=0(0), uri="testnotify://")
D [24/Jul/2012:22:39:49.905124 +0000] Added subscription #2 for printer "Test1".
D [24/Jul/2012:22:39:49.905253 +0000] recipient="testnotify://"
D [24/Jul/2012:22:39:49.905310 +0000] notify-lease-duration=5
D [24/Jul/2012:22:39:49.905360 +0000] notify-time-interval=0
D [24/Jul/2012:22:39:49.905419 +0000] cupsdAddSubscription(mask=70, dest=0x40fda160(Test1), job=0(0), uri="testnotify://")
D [24/Jul/2012:22:39:49.905482 +0000] Added subscription #3 for printer "Test1".
D [24/Jul/2012:22:39:49.905555 +0000] cupsdMarkDirty(-----S)
D [24/Jul/2012:22:39:49.905611 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [24/Jul/2012:22:39:49.905672 +0000] Returning IPP successful-ok for Create-Printer-Subscription (ipp://localhost:8631/printers/Test1) from localhost
D [24/Jul/2012:22:39:49.906999 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [24/Jul/2012:22:39:49.908976 +0000] cupsdReadClient: 10 POST / HTTP/1.1
D [24/Jul/2012:22:39:49.909081 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [24/Jul/2012:22:39:49.909419 +0000] cupsdAuthorize: No authentication data provided.
D [24/Jul/2012:22:39:49.910305 +0000] cupsdReadClient: 10 1.1 Get-Subscriptions 9458
D [24/Jul/2012:22:39:49.910453 +0000] Get-Subscriptions ipp://localhost:8631/printers/Test1
D [24/Jul/2012:22:39:49.911465 +0000] Returning IPP successful-ok for Get-Subscriptions (ipp://localhost:8631/printers/Test1) from localhost
D [24/Jul/2012:22:39:49.913824 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [24/Jul/2012:22:39:49.916620 +0000] cupsdReadClient: 10 POST / HTTP/1.1
D [24/Jul/2012:22:39:49.916685 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [24/Jul/2012:22:39:49.917024 +0000] cupsdAuthorize: No authentication data provided.
D [24/Jul/2012:22:39:49.918200 +0000] cupsdReadClient: 10 1.1 Create-Printer-Subscription 9459
D [24/Jul/2012:22:39:49.918346 +0000] Create-Printer-Subscription ipp://localhost:8631/printers/Test1
D [24/Jul/2012:22:39:49.918408 +0000] cupsdCreateSubscription(con=0x4110fde0(10), uri="ipp://localhost:8631/printers/Test1")
D [24/Jul/2012:22:39:49.918909 +0000] recipient="testnotify://"
D [24/Jul/2012:22:39:49.918965 +0000] notify-lease-duration=5
D [24/Jul/2012:22:39:49.919016 +0000] notify-time-interval=0
D [24/Jul/2012:22:39:49.919132 +0000] cupsdAddSubscription(mask=f, dest=0x40fda160(Test1), job=0(0), uri="testnotify://")
D [24/Jul/2012:22:39:49.919199 +0000] Added subscription #4 for printer "Test1".
D [24/Jul/2012:22:39:49.919280 +0000] cupsdMarkDirty(-----S)
D [24/Jul/2012:22:39:49.919338 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [24/Jul/2012:22:39:49.919471 +0000] Returning IPP successful-ok for Create-Printer-Subscription (ipp://localhost:8631/printers/Test1) from localhost
D [24/Jul/2012:22:39:49.920619 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [24/Jul/2012:22:39:49.923389 +0000] cupsdReadClient: 10 WAITING Closing on EOF
D [24/Jul/2012:22:39:49.923463 +0000] cupsdCloseClient: 10
D [24/Jul/2012:22:39:49.923538 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [24/Jul/2012:22:39:49.935273 +0000] cupsdAcceptClient: 10 from localhost:8631 (IPv4)
D [24/Jul/2012:22:39:49.935745 +0000] cupsdReadClient: 10 POST / HTTP/1.1
D [24/Jul/2012:22:39:49.935833 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [24/Jul/2012:22:39:49.936171 +0000] cupsdAuthorize: No authentication data provided.
D [24/Jul/2012:22:39:49.937242 +0000] cupsdReadClient: 10 1.1 Get-Printer-Attributes 1
D [24/Jul/2012:22:39:49.937391 +0000] Get-Printer-Attributes ipp://localhost:8631/printers/Test3
D [24/Jul/2012:22:39:49.937536 +0000] Get-Printer-Attributes client-error-not-found: The printer or class does not exist.
D [24/Jul/2012:22:39:49.937634 +0000] Returning IPP client-error-not-found for Get-Printer-Attributes (ipp://localhost:8631/printers/Test3) from localhost
D [24/Jul/2012:22:39:49.938681 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [24/Jul/2012:22:39:49.939273 +0000] cupsdReadClient: 10 POST /admin/ HTTP/1.1
D [24/Jul/2012:22:39:49.939337 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [24/Jul/2012:22:39:49.939671 +0000] cupsdAuthorize: No authentication data provided.
D [24/Jul/2012:22:39:49.940707 +0000] cupsdReadClient: 10 1.1 CUPS-Add-Modify-Printer 1
D [24/Jul/2012:22:39:49.940916 +0000] CUPS-Add-Modify-Printer ipp://localhost:8631/printers/Test3
I [24/Jul/2012:22:39:49.941678 +0000] Setting Test3 printer-is-accepting-jobs to 1 (was 0.)
D [24/Jul/2012:22:39:49.941797 +0000] Discarding unused printer-state-changed event...
I [24/Jul/2012:22:39:49.941858 +0000] Setting Test3 printer-state to 3 (was 5.)
D [24/Jul/2012:22:39:49.941974 +0000] Discarding unused printer-state-changed event...
D [24/Jul/2012:22:39:49.942820 +0000] cupsdMarkDirty(P-----)
D [24/Jul/2012:22:39:49.942881 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [24/Jul/2012:22:39:49.942935 +0000] load_ppd: Loading /tmp/cups-root/ppd/Test3.ppd...
D [24/Jul/2012:22:39:49.943652 +0000] cupsdRegisterPrinter(p=0x410fa430(Test3))
D [24/Jul/2012:22:39:49.943713 +0000] cupsdMarkDirty(P-----)
D [24/Jul/2012:22:39:49.943769 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [24/Jul/2012:22:39:49.943825 +0000] cupsdMarkDirty(---p--)
D [24/Jul/2012:22:39:49.943944 +0000] Discarding unused printer-added event...
I [24/Jul/2012:22:39:49.944000 +0000] New printer "Test3" added by "root".
D [24/Jul/2012:22:39:49.944060 +0000] Returning IPP successful-ok for CUPS-Add-Modify-Printer (ipp://localhost:8631/printers/Test3) from localhost
D [24/Jul/2012:22:39:49.945166 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [24/Jul/2012:22:39:49.945651 +0000] cupsdReadClient: 10 POST / HTTP/1.1
D [24/Jul/2012:22:39:49.945771 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [24/Jul/2012:22:39:49.946135 +0000] cupsdAuthorize: No authentication data provided.
D [24/Jul/2012:22:39:49.947072 +0000] cupsdReadClient: 10 1.1 Get-Printer-Attributes 1
D [24/Jul/2012:22:39:49.947217 +0000] Get-Printer-Attributes ipp://localhost:8631/printers/Test3
D [24/Jul/2012:22:39:49.948020 +0000] Returning IPP successful-ok for Get-Printer-Attributes (ipp://localhost:8631/printers/Test3) from localhost
D [24/Jul/2012:22:39:49.949088 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [24/Jul/2012:22:39:49.950021 +0000] cupsdAcceptClient: 11 from localhost:8631 (IPv4)
D [24/Jul/2012:22:39:49.950428 +0000] cupsdReadClient: 11 POST / HTTP/1.1
D [24/Jul/2012:22:39:49.950490 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [24/Jul/2012:22:39:49.950825 +0000] cupsdAuthorize: No authentication data provided.
D [24/Jul/2012:22:39:49.951911 +0000] cupsdReadClient: 11 1.1 Get-Printer-Attributes 1
D [24/Jul/2012:22:39:49.952126 +0000] Get-Printer-Attributes ipp://localhost/printers/Test3
D [24/Jul/2012:22:39:49.958036 +0000] Returning IPP successful-ok for Get-Printer-Attributes (ipp://localhost/printers/Test3) from localhost
D [24/Jul/2012:22:39:49.965849 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
I [24/Jul/2012:22:39:55.972167 +0000] Subscription 2 has expired...
I [24/Jul/2012:22:39:55.972294 +0000] Subscription 3 has expired...
I [24/Jul/2012:22:39:55.972430 +0000] Subscription 4 has expired...
D [24/Jul/2012:22:39:55.972469 +0000] cupsdMarkDirty(-----S)
D [24/Jul/2012:22:39:55.972501 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [24/Jul/2012:22:39:59.983073 +0000] cupsdReadClient: 11 GET /printers/Test3.ppd HTTP/1.1
D [24/Jul/2012:22:39:59.983139 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [24/Jul/2012:22:39:59.983445 +0000] cupsdAuthorize: No authentication data provided.
D [24/Jul/2012:22:39:59.983924 +0000] cupsdReadClient: 11 Closing because Keep-Alive disabled
D [24/Jul/2012:22:39:59.984000 +0000] cupsdCloseClient: 11
D [24/Jul/2012:22:39:59.984075 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [24/Jul/2012:22:39:59.984674 +0000] cupsdReadClient: 10 POST /admin/ HTTP/1.1
D [24/Jul/2012:22:39:59.984736 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [24/Jul/2012:22:39:59.985069 +0000] cupsdAuthorize: No authentication data provided.
D [24/Jul/2012:22:39:59.986268 +0000] cupsdReadClient: 10 1.1 CUPS-Add-Modify-Printer 1
D [24/Jul/2012:22:39:59.986484 +0000] CUPS-Add-Modify-Printer ipp://localhost:8631/printers/Test3
I [24/Jul/2012:22:39:59.986998 +0000] Setting Test3 device-uri to "file:/dev/null" (was "file:///dev/null".)
D [24/Jul/2012:22:39:59.987383 +0000] copy_model: Running "cups-driverd cat drv:///sample.drv/deskjet.ppd"...
E [24/Jul/2012:22:39:59.987517 +0000] Directory "/tmp/cups-root/bin/daemon" has insecure permissions (040775/uid=501/gid=10).
D [24/Jul/2012:22:39:59.987653 +0000] CUPS-Add-Modify-Printer server-error-internal-error: Unable to copy PPD file.
E [24/Jul/2012:22:39:59.987755 +0000] Returning IPP server-error-internal-error for CUPS-Add-Modify-Printer (ipp://localhost:8631/printers/Test3) from localhost
D [24/Jul/2012:22:39:59.988939 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [24/Jul/2012:22:39:59.989498 +0000] cupsdReadClient: 10 WAITING Closing on EOF
D [24/Jul/2012:22:39:59.989573 +0000] cupsdCloseClient: 10
D [24/Jul/2012:22:39:59.989650 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [24/Jul/2012:22:40:00.003892 +0000] cupsdAcceptClient: 10 from localhost:8631 (IPv4)
D [24/Jul/2012:22:40:00.004308 +0000] cupsdReadClient: 10 POST / HTTP/1.1
D [24/Jul/2012:22:40:00.004372 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [24/Jul/2012:22:40:00.004786 +0000] cupsdAuthorize: No authentication data provided.
D [24/Jul/2012:22:40:00.006028 +0000] cupsdReadClient: 10 1.1 CUPS-Get-Printers 1
D [24/Jul/2012:22:40:00.006172 +0000] CUPS-Get-Printers
D [24/Jul/2012:22:40:00.017403 +0000] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost
D [24/Jul/2012:22:40:00.026655 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [24/Jul/2012:22:40:00.028490 +0000] cupsdReadClient: 10 WAITING Closing on EOF
D [24/Jul/2012:22:40:00.028528 +0000] cupsdCloseClient: 10
D [24/Jul/2012:22:40:00.028567 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [24/Jul/2012:22:40:00.035258 +0000] cupsdAcceptClient: 10 from localhost:8631 (IPv4)
D [24/Jul/2012:22:40:00.035547 +0000] cupsdReadClient: 10 POST / HTTP/1.1
D [24/Jul/2012:22:40:00.035593 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [24/Jul/2012:22:40:00.035811 +0000] cupsdAuthorize: No authentication data provided.
D [24/Jul/2012:22:40:00.037726 +0000] cupsdReadClient: 10 1.1 CUPS-Get-Printers 1
D [24/Jul/2012:22:40:00.037803 +0000] CUPS-Get-Printers
D [24/Jul/2012:22:40:00.057072 +0000] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost
D [24/Jul/2012:22:40:00.089867 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [24/Jul/2012:22:40:00.094883 +0000] cupsdReadClient: 10 POST / HTTP/1.1
D [24/Jul/2012:22:40:00.094918 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [24/Jul/2012:22:40:00.095138 +0000] cupsdAuthorize: No authentication data provided.
D [24/Jul/2012:22:40:00.095454 +0000] cupsdReadClient: 10 1.1 CUPS-Get-Default 1
D [24/Jul/2012:22:40:00.095528 +0000] CUPS-Get-Default
D [24/Jul/2012:22:40:00.095818 +0000] CUPS-Get-Default client-error-not-found: No default printer.
D [24/Jul/2012:22:40:00.095868 +0000] Returning IPP client-error-not-found for CUPS-Get-Default (no URI) from localhost
D [24/Jul/2012:22:40:00.096409 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [24/Jul/2012:22:40:00.096777 +0000] cupsdReadClient: 10 POST / HTTP/1.1
D [24/Jul/2012:22:40:00.096810 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [24/Jul/2012:22:40:00.096983 +0000] cupsdAuthorize: No authentication data provided.
D [24/Jul/2012:22:40:00.097393 +0000] cupsdReadClient: 10 1.1 Get-Printer-Attributes 1
D [24/Jul/2012:22:40:00.097465 +0000] Get-Printer-Attributes ipp://localhost/printers/Test1
D [24/Jul/2012:22:40:00.101255 +0000] Returning IPP successful-ok for Get-Printer-Attributes (ipp://localhost/printers/Test1) from localhost
D [24/Jul/2012:22:40:00.108462 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [24/Jul/2012:22:40:00.114051 +0000] cupsdReadClient: 10 POST / HTTP/1.1
D [24/Jul/2012:22:40:00.114085 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [24/Jul/2012:22:40:00.114262 +0000] cupsdAuthorize: No authentication data provided.
D [24/Jul/2012:22:40:00.115159 +0000] cupsdReadClient: 10 1.1 Get-Jobs 1
D [24/Jul/2012:22:40:00.115233 +0000] Get-Jobs ipp://localhost/printers/Test1
D [24/Jul/2012:22:40:00.115527 +0000] Returning IPP successful-ok for Get-Jobs (ipp://localhost/printers/Test1) from localhost
D [24/Jul/2012:22:40:00.116109 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [24/Jul/2012:22:40:00.117136 +0000] cupsdReadClient: 10 WAITING Closing on EOF
D [24/Jul/2012:22:40:00.117173 +0000] cupsdCloseClient: 10
D [24/Jul/2012:22:40:00.117212 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [24/Jul/2012:22:40:00.124175 +0000] cupsdAcceptClient: 10 from localhost:8631 (IPv4)
D [24/Jul/2012:22:40:00.124433 +0000] cupsdReadClient: 10 POST / HTTP/1.1
D [24/Jul/2012:22:40:00.124466 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [24/Jul/2012:22:40:00.124652 +0000] cupsdAuthorize: No authentication data provided.
D [24/Jul/2012:22:40:00.126589 +0000] cupsdReadClient: 10 1.1 CUPS-Get-Printers 1
D [24/Jul/2012:22:40:00.126667 +0000] CUPS-Get-Printers
D [24/Jul/2012:22:40:00.146139 +0000] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost
D [24/Jul/2012:22:40:00.178761 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [24/Jul/2012:22:40:00.183844 +0000] cupsdReadClient: 10 POST / HTTP/1.1
D [24/Jul/2012:22:40:00.183878 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [24/Jul/2012:22:40:00.184095 +0000] cupsdAuthorize: No authentication data provided.
D [24/Jul/2012:22:40:00.184407 +0000] cupsdReadClient: 10 1.1 CUPS-Get-Default 1
D [24/Jul/2012:22:40:00.184481 +0000] CUPS-Get-Default
D [24/Jul/2012:22:40:00.184717 +0000] CUPS-Get-Default client-error-not-found: No default printer.
D [24/Jul/2012:22:40:00.184765 +0000] Returning IPP client-error-not-found for CUPS-Get-Default (no URI) from localhost
D [24/Jul/2012:22:40:00.185298 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [24/Jul/2012:22:40:00.185869 +0000] cupsdAcceptClient: 11 from localhost:8631 (IPv4)
D [24/Jul/2012:22:40:00.186048 +0000] cupsdReadClient: 11 WAITING Closing on EOF
D [24/Jul/2012:22:40:00.186084 +0000] cupsdCloseClient: 11
D [24/Jul/2012:22:40:00.186115 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [24/Jul/2012:22:40:00.186394 +0000] cupsdReadClient: 10 POST / HTTP/1.1
D [24/Jul/2012:22:40:00.186426 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [24/Jul/2012:22:40:00.186644 +0000] cupsdAuthorize: No authentication data provided.
D [24/Jul/2012:22:40:00.187197 +0000] cupsdReadClient: 10 1.1 CUPS-Get-Classes 1
D [24/Jul/2012:22:40:00.187271 +0000] CUPS-Get-Classes
D [24/Jul/2012:22:40:00.187525 +0000] Returning IPP successful-ok for CUPS-Get-Classes (no URI) from localhost
D [24/Jul/2012:22:40:00.188016 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [24/Jul/2012:22:40:00.188278 +0000] cupsdReadClient: 10 POST / HTTP/1.1
D [24/Jul/2012:22:40:00.188310 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [24/Jul/2012:22:40:00.188521 +0000] cupsdAuthorize: No authentication data provided.
D [24/Jul/2012:22:40:00.189124 +0000] cupsdReadClient: 10 1.1 CUPS-Get-Printers 1
D [24/Jul/2012:22:40:00.189198 +0000] CUPS-Get-Printers
D [24/Jul/2012:22:40:00.195243 +0000] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost
D [24/Jul/2012:22:40:00.199678 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [24/Jul/2012:22:40:00.201449 +0000] cupsdReadClient: 10 POST / HTTP/1.1
D [24/Jul/2012:22:40:00.201483 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [24/Jul/2012:22:40:00.201658 +0000] cupsdAuthorize: No authentication data provided.
D [24/Jul/2012:22:40:00.202300 +0000] cupsdReadClient: 10 1.1 CUPS-Get-Printers 1
D [24/Jul/2012:22:40:00.202441 +0000] CUPS-Get-Printers
D [24/Jul/2012:22:40:00.207178 +0000] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost
D [24/Jul/2012:22:40:00.213527 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [24/Jul/2012:22:40:00.215485 +0000] cupsdReadClient: 10 POST / HTTP/1.1
D [24/Jul/2012:22:40:00.215518 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [24/Jul/2012:22:40:00.215720 +0000] cupsdAuthorize: No authentication data provided.
D [24/Jul/2012:22:40:00.216835 +0000] cupsdReadClient: 10 1.1 CUPS-Get-Printers 1
D [24/Jul/2012:22:40:00.216909 +0000] CUPS-Get-Printers
D [24/Jul/2012:22:40:00.225343 +0000] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost
D [24/Jul/2012:22:40:00.239080 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [24/Jul/2012:22:40:00.241208 +0000] cupsdReadClient: 10 POST / HTTP/1.1
D [24/Jul/2012:22:40:00.241241 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [24/Jul/2012:22:40:00.241418 +0000] cupsdAuthorize: No authentication data provided.
D [24/Jul/2012:22:40:00.242497 +0000] cupsdReadClient: 10 1.1 Get-Jobs 1
D [24/Jul/2012:22:40:00.242574 +0000] Get-Jobs ipp://localhost/
D [24/Jul/2012:22:40:00.242858 +0000] Returning IPP successful-ok for Get-Jobs (ipp://localhost/) from localhost
D [24/Jul/2012:22:40:00.243390 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [24/Jul/2012:22:40:00.243763 +0000] cupsdReadClient: 10 WAITING Closing on EOF
D [24/Jul/2012:22:40:00.243801 +0000] cupsdCloseClient: 10
D [24/Jul/2012:22:40:00.243843 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [24/Jul/2012:22:40:00.246330 +0000] cupsdAcceptClient: 10 from localhost:8631 (IPv4)
D [24/Jul/2012:22:40:00.246541 +0000] cupsdReadClient: 10 POST / HTTP/1.1
D [24/Jul/2012:22:40:00.246573 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [24/Jul/2012:22:40:00.246754 +0000] cupsdAuthorize: No authentication data provided.
D [24/Jul/2012:22:40:00.247817 +0000] cupsdReadClient: 10 1.1 Get-Jobs 1
D [24/Jul/2012:22:40:00.247894 +0000] Get-Jobs ipp://localhost/
D [24/Jul/2012:22:40:00.248180 +0000] Returning IPP successful-ok for Get-Jobs (ipp://localhost/) from localhost
D [24/Jul/2012:22:40:00.248751 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [24/Jul/2012:22:40:00.249404 +0000] cupsdReadClient: 10 WAITING Closing on EOF
D [24/Jul/2012:22:40:00.249445 +0000] cupsdCloseClient: 10
D [24/Jul/2012:22:40:00.249490 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [24/Jul/2012:22:40:00.256325 +0000] cupsdAcceptClient: 10 from localhost:8631 (IPv4)
D [24/Jul/2012:22:40:00.256573 +0000] cupsdReadClient: 10 POST / HTTP/1.1
D [24/Jul/2012:22:40:00.256611 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [24/Jul/2012:22:40:00.256829 +0000] cupsdAuthorize: No authentication data provided.
D [24/Jul/2012:22:40:00.259120 +0000] cupsdReadClient: 10 1.1 CUPS-Get-Default 1
D [24/Jul/2012:22:40:00.259214 +0000] CUPS-Get-Default
D [24/Jul/2012:22:40:00.259527 +0000] CUPS-Get-Default client-error-not-found: No default printer.
D [24/Jul/2012:22:40:00.259586 +0000] Returning IPP client-error-not-found for CUPS-Get-Default (no URI) from localhost
D [24/Jul/2012:22:40:00.260320 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [24/Jul/2012:22:40:00.260679 +0000] cupsdReadClient: 10 WAITING Closing on EOF
D [24/Jul/2012:22:40:00.260725 +0000] cupsdCloseClient: 10
D [24/Jul/2012:22:40:00.260773 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [24/Jul/2012:22:40:00.270584 +0000] cupsdAcceptClient: 10 from localhost:8631 (IPv4)
D [24/Jul/2012:22:40:00.270882 +0000] cupsdReadClient: 10 POST / HTTP/1.1
D [24/Jul/2012:22:40:00.270929 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [24/Jul/2012:22:40:00.271197 +0000] cupsdAuthorize: No authentication data provided.
D [24/Jul/2012:22:40:00.274576 +0000] cupsdReadClient: 10 1.1 CUPS-Get-Default 1
D [24/Jul/2012:22:40:00.274725 +0000] CUPS-Get-Default
D [24/Jul/2012:22:40:00.275183 +0000] CUPS-Get-Default client-error-not-found: No default printer.
D [24/Jul/2012:22:40:00.275278 +0000] Returning IPP client-error-not-found for CUPS-Get-Default (no URI) from localhost
D [24/Jul/2012:22:40:00.276495 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [24/Jul/2012:22:40:00.276988 +0000] cupsdReadClient: 10 WAITING Closing on EOF
D [24/Jul/2012:22:40:00.277064 +0000] cupsdCloseClient: 10
D [24/Jul/2012:22:40:00.277146 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [24/Jul/2012:22:40:00.290919 +0000] cupsdAcceptClient: 10 from localhost:8631 (IPv4)
D [24/Jul/2012:22:40:00.291380 +0000] cupsdReadClient: 10 POST / HTTP/1.1
D [24/Jul/2012:22:40:00.291443 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [24/Jul/2012:22:40:00.291795 +0000] cupsdAuthorize: No authentication data provided.
D [24/Jul/2012:22:40:00.295425 +0000] cupsdReadClient: 10 1.1 CUPS-Get-Default 1
D [24/Jul/2012:22:40:00.295573 +0000] CUPS-Get-Default
D [24/Jul/2012:22:40:00.296096 +0000] CUPS-Get-Default client-error-not-found: No default printer.
D [24/Jul/2012:22:40:00.296192 +0000] Returning IPP client-error-not-found for CUPS-Get-Default (no URI) from localhost
D [24/Jul/2012:22:40:00.297426 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [24/Jul/2012:22:40:00.297935 +0000] cupsdReadClient: 10 WAITING Closing on EOF
D [24/Jul/2012:22:40:00.298007 +0000] cupsdCloseClient: 10
D [24/Jul/2012:22:40:00.298090 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [24/Jul/2012:22:40:00.301968 +0000] cupsdAcceptClient: 10 from localhost:8631 (IPv4)
D [24/Jul/2012:22:40:00.302451 +0000] cupsdReadClient: 10 POST / HTTP/1.1
D [24/Jul/2012:22:40:00.302527 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [24/Jul/2012:22:40:00.302881 +0000] cupsdAuthorize: No authentication data provided.
D [24/Jul/2012:22:40:00.306531 +0000] cupsdReadClient: 10 1.1 CUPS-Get-Default 1
D [24/Jul/2012:22:40:00.306679 +0000] CUPS-Get-Default
D [24/Jul/2012:22:40:00.307196 +0000] CUPS-Get-Default client-error-not-found: No default printer.
D [24/Jul/2012:22:40:00.307292 +0000] Returning IPP client-error-not-found for CUPS-Get-Default (no URI) from localhost
D [24/Jul/2012:22:40:00.308464 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [24/Jul/2012:22:40:00.309835 +0000] cupsdReadClient: 10 WAITING Closing on EOF
D [24/Jul/2012:22:40:00.309914 +0000] cupsdCloseClient: 10
D [24/Jul/2012:22:40:00.309995 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [24/Jul/2012:22:40:00.313538 +0000] cupsdAcceptClient: 10 from localhost:8631 (IPv4)
D [24/Jul/2012:22:40:00.313929 +0000] cupsdReadClient: 10 POST / HTTP/1.1
D [24/Jul/2012:22:40:00.313992 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [24/Jul/2012:22:40:00.314347 +0000] cupsdAuthorize: No authentication data provided.
D [24/Jul/2012:22:40:00.318206 +0000] cupsdReadClient: 10 1.1 Get-Printer-Attributes 1
D [24/Jul/2012:22:40:00.318358 +0000] Get-Printer-Attributes ipp://localhost:8631/printers/Test1
D [24/Jul/2012:22:40:00.320598 +0000] Returning IPP successful-ok for Get-Printer-Attributes (ipp://localhost:8631/printers/Test1) from localhost
D [24/Jul/2012:22:40:00.324188 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [24/Jul/2012:22:40:00.327105 +0000] cupsdReadClient: 10 POST /printers/Test1 HTTP/1.1
D [24/Jul/2012:22:40:00.327171 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [24/Jul/2012:22:40:00.327513 +0000] cupsdAuthorize: No authentication data provided.
D [24/Jul/2012:22:40:00.329484 +0000] cupsdReadClient: 10 1.1 Create-Job 1
D [24/Jul/2012:22:40:00.329702 +0000] Create-Job ipp://localhost:8631/printers/Test1
D [24/Jul/2012:22:40:00.330259 +0000] Create-Job server-error-not-accepting-jobs: Destination "Test1" is not accepting jobs.
E [24/Jul/2012:22:40:00.330355 +0000] Returning IPP server-error-not-accepting-jobs for Create-Job (ipp://localhost:8631/printers/Test1) from localhost
D [24/Jul/2012:22:40:00.331557 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [24/Jul/2012:22:40:00.332550 +0000] cupsdReadClient: 10 WAITING Closing on EOF
D [24/Jul/2012:22:40:00.332631 +0000] cupsdCloseClient: 10
D [24/Jul/2012:22:40:00.332713 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [24/Jul/2012:22:40:00.336115 +0000] cupsdAcceptClient: 10 from localhost:8631 (IPv4)
D [24/Jul/2012:22:40:00.336504 +0000] cupsdReadClient: 10 POST / HTTP/1.1
D [24/Jul/2012:22:40:00.336565 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [24/Jul/2012:22:40:00.336917 +0000] cupsdAuthorize: No authentication data provided.
D [24/Jul/2012:22:40:00.340589 +0000] cupsdReadClient: 10 1.1 CUPS-Get-Default 1
D [24/Jul/2012:22:40:00.340738 +0000] CUPS-Get-Default
D [24/Jul/2012:22:40:00.341197 +0000] CUPS-Get-Default client-error-not-found: No default printer.
D [24/Jul/2012:22:40:00.341293 +0000] Returning IPP client-error-not-found for CUPS-Get-Default (no URI) from localhost
D [24/Jul/2012:22:40:00.342546 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [24/Jul/2012:22:40:00.343136 +0000] cupsdReadClient: 10 POST / HTTP/1.1
D [24/Jul/2012:22:40:00.343200 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [24/Jul/2012:22:40:00.343614 +0000] cupsdAuthorize: No authentication data provided.
D [24/Jul/2012:22:40:00.347400 +0000] cupsdReadClient: 10 1.1 Get-Printer-Attributes 1
D [24/Jul/2012:22:40:00.347552 +0000] Get-Printer-Attributes ipp://localhost:8631/printers/Test1
D [24/Jul/2012:22:40:00.349806 +0000] Returning IPP successful-ok for Get-Printer-Attributes (ipp://localhost:8631/printers/Test1) from localhost
D [24/Jul/2012:22:40:00.353109 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [24/Jul/2012:22:40:00.354558 +0000] cupsdReadClient: 10 POST /jobs/ HTTP/1.1
D [24/Jul/2012:22:40:00.354592 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [24/Jul/2012:22:40:00.354767 +0000] cupsdAuthorize: No authentication data provided.
D [24/Jul/2012:22:40:00.355265 +0000] cupsdReadClient: 10 1.1 Cancel-Job 1
D [24/Jul/2012:22:40:00.355340 +0000] Cancel-Job ipp://localhost:8631/printers/Test1
D [24/Jul/2012:22:40:00.355417 +0000] Cancel-Job client-error-not-possible: No active jobs on Test1.
E [24/Jul/2012:22:40:00.355468 +0000] Returning IPP client-error-not-possible for Cancel-Job (ipp://localhost:8631/printers/Test1) from localhost
D [24/Jul/2012:22:40:00.356158 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [24/Jul/2012:22:40:00.356685 +0000] cupsdReadClient: 10 WAITING Closing on EOF
D [24/Jul/2012:22:40:00.356726 +0000] cupsdCloseClient: 10
D [24/Jul/2012:22:40:00.356769 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [24/Jul/2012:22:40:00.364134 +0000] cupsdAcceptClient: 10 from localhost:8631 (IPv4)
D [24/Jul/2012:22:40:00.364344 +0000] cupsdReadClient: 10 POST / HTTP/1.1
D [24/Jul/2012:22:40:00.364376 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [24/Jul/2012:22:40:00.364562 +0000] cupsdAuthorize: No authentication data provided.
D [24/Jul/2012:22:40:00.366619 +0000] cupsdReadClient: 10 1.1 Get-Printer-Attributes 1
D [24/Jul/2012:22:40:00.366699 +0000] Get-Printer-Attributes ipp://localhost:8631/printers/Test1
D [24/Jul/2012:22:40:00.367775 +0000] Returning IPP successful-ok for Get-Printer-Attributes (ipp://localhost:8631/printers/Test1) from localhost
D [24/Jul/2012:22:40:00.369697 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [24/Jul/2012:22:40:00.371282 +0000] cupsdReadClient: 10 POST /printers/Test1 HTTP/1.1
D [24/Jul/2012:22:40:00.371316 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [24/Jul/2012:22:40:00.371540 +0000] cupsdAuthorize: No authentication data provided.
D [24/Jul/2012:22:40:00.372615 +0000] cupsdReadClient: 10 1.1 Create-Job 1
D [24/Jul/2012:22:40:00.372694 +0000] Create-Job ipp://localhost:8631/printers/Test1
D [24/Jul/2012:22:40:00.373018 +0000] Create-Job server-error-not-accepting-jobs: Destination "Test1" is not accepting jobs.
E [24/Jul/2012:22:40:00.373068 +0000] Returning IPP server-error-not-accepting-jobs for Create-Job (ipp://localhost:8631/printers/Test1) from localhost
D [24/Jul/2012:22:40:00.373712 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [24/Jul/2012:22:40:00.373985 +0000] cupsdReadClient: 10 WAITING Closing on EOF
D [24/Jul/2012:22:40:00.374024 +0000] cupsdCloseClient: 10
D [24/Jul/2012:22:40:00.374065 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [24/Jul/2012:22:40:00.376395 +0000] cupsdAcceptClient: 10 from localhost:8631 (IPv4)
D [24/Jul/2012:22:40:00.376637 +0000] cupsdReadClient: 10 POST / HTTP/1.1
D [24/Jul/2012:22:40:00.376675 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [24/Jul/2012:22:40:00.376893 +0000] cupsdAuthorize: No authentication data provided.
D [24/Jul/2012:22:40:00.379191 +0000] cupsdReadClient: 10 1.1 CUPS-Get-Printers 1
D [24/Jul/2012:22:40:00.379283 +0000] CUPS-Get-Printers
D [24/Jul/2012:22:40:00.397596 +0000] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost
D [24/Jul/2012:22:40:00.430382 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [24/Jul/2012:22:40:00.435397 +0000] cupsdReadClient: 10 POST / HTTP/1.1
D [24/Jul/2012:22:40:00.435431 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [24/Jul/2012:22:40:00.435607 +0000] cupsdAuthorize: No authentication data provided.
D [24/Jul/2012:22:40:00.435961 +0000] cupsdReadClient: 10 1.1 CUPS-Get-Default 1
D [24/Jul/2012:22:40:00.436035 +0000] CUPS-Get-Default
D [24/Jul/2012:22:40:00.436316 +0000] CUPS-Get-Default client-error-not-found: No default printer.
D [24/Jul/2012:22:40:00.436366 +0000] Returning IPP client-error-not-found for CUPS-Get-Default (no URI) from localhost
D [24/Jul/2012:22:40:00.436911 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [24/Jul/2012:22:40:00.437477 +0000] cupsdAcceptClient: 11 from localhost:8631 (IPv4)
D [24/Jul/2012:22:40:00.437699 +0000] cupsdReadClient: 11 POST /jobs/ HTTP/1.1
D [24/Jul/2012:22:40:00.437732 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [24/Jul/2012:22:40:00.437908 +0000] cupsdAuthorize: No authentication data provided.
D [24/Jul/2012:22:40:00.438423 +0000] cupsdReadClient: 11 1.1 Cancel-Job 1
D [24/Jul/2012:22:40:00.438497 +0000] Cancel-Job ipp://localhost/printers/Test1
D [24/Jul/2012:22:40:00.438577 +0000] Cancel-Job client-error-not-possible: No active jobs on Test1.
E [24/Jul/2012:22:40:00.438671 +0000] Returning IPP client-error-not-possible for Cancel-Job (ipp://localhost/printers/Test1) from localhost
D [24/Jul/2012:22:40:00.439320 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [24/Jul/2012:22:40:00.439916 +0000] cupsdReadClient: 10 WAITING Closing on EOF
D [24/Jul/2012:22:40:00.439959 +0000] cupsdCloseClient: 10
D [24/Jul/2012:22:40:00.440002 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [24/Jul/2012:22:40:00.440280 +0000] cupsdReadClient: 11 WAITING Closing on EOF
D [24/Jul/2012:22:40:00.440318 +0000] cupsdCloseClient: 11
D [24/Jul/2012:22:40:00.440354 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [24/Jul/2012:22:40:00.447861 +0000] cupsdAcceptClient: 10 from localhost:8631 (IPv4)
D [24/Jul/2012:22:40:00.448123 +0000] cupsdReadClient: 10 POST / HTTP/1.1
D [24/Jul/2012:22:40:00.448161 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [24/Jul/2012:22:40:00.448368 +0000] cupsdAuthorize: No authentication data provided.
D [24/Jul/2012:22:40:00.448751 +0000] cupsdReadClient: 10 1.1 CUPS-Get-Devices 1
D [24/Jul/2012:22:40:00.448887 +0000] CUPS-Get-Devices
D [24/Jul/2012:22:40:00.449365 +0000] [CGI] argv[0] = "/tmp/cups-root/bin/daemon/cups-deviced"
D [24/Jul/2012:22:40:00.449400 +0000] [CGI] argv[1] = "1"
D [24/Jul/2012:22:40:00.449433 +0000] [CGI] argv[2] = "0"
D [24/Jul/2012:22:40:00.449464 +0000] [CGI] argv[3] = "15"
D [24/Jul/2012:22:40:00.449495 +0000] [CGI] argv[4] = "2"
D [24/Jul/2012:22:40:00.449526 +0000] [CGI] argv[5] = "requested-attributes=all"
D [24/Jul/2012:22:40:00.449558 +0000] [CGI] envp[0] = "LOCALEDIR=/tmp/cups-root/share/locale"
D [24/Jul/2012:22:40:00.449589 +0000] [CGI] envp[1] = "CUPS_CACHEDIR=/tmp/cups-root/share"
D [24/Jul/2012:22:40:00.449620 +0000] [CGI] envp[2] = "CUPS_DATADIR=/tmp/cups-root/share"
D [24/Jul/2012:22:40:00.449652 +0000] [CGI] envp[3] = "CUPS_DOCROOT=/root/cups-1.5.3/doc"
D [24/Jul/2012:22:40:00.449683 +0000] [CGI] envp[4] = "CUPS_FONTPATH=/tmp/cups-root/share/fonts"
D [24/Jul/2012:22:40:00.449714 +0000] [CGI] envp[5] = "CUPS_REQUESTROOT=/tmp/cups-root/spool"
D [24/Jul/2012:22:40:00.449746 +0000] [CGI] envp[6] = "CUPS_SERVERBIN=/tmp/cups-root/bin"
D [24/Jul/2012:22:40:00.449777 +0000] [CGI] envp[7] = "CUPS_SERVERROOT=/tmp/cups-root"
D [24/Jul/2012:22:40:00.449808 +0000] [CGI] envp[8] = "CUPS_STATEDIR=/tmp/cups-root"
D [24/Jul/2012:22:40:00.449840 +0000] [CGI] envp[9] = "DYLD_LIBRARY_PATH=/root/cups-1.5.3/cups:/root/cups-1.5.3/filter:/root/cups-1.5.3/cgi-bin:/root/cups-1.5.3/scheduler:/root/cups-1.5.3/driver:/root/cups-1.5.3/ppdc"
D [24/Jul/2012:22:40:00.449872 +0000] [CGI] envp[10] = "HOME=/tmp/cups-root/spool/temp"
D [24/Jul/2012:22:40:00.449905 +0000] [CGI] envp[11] = "LD_LIBRARY_PATH=/root/cups-1.5.3/cups:/root/cups-1.5.3/filter:/root/cups-1.5.3/cgi-bin:/root/cups-1.5.3/scheduler:/root/cups-1.5.3/driver:/root/cups-1.5.3/ppdc"
D [24/Jul/2012:22:40:00.449938 +0000] [CGI] envp[12] = "LD_PRELOAD=/root/cups-1.5.3/cups/libcups.so.2:/root/cups-1.5.3/filter/libcupsimage.so.2:/root/cups-1.5.3/cgi-bin/libcupscgi.so.1:/root/cups-1.5.3/scheduler/libcupsmime.so.1:/root/cups-1.5.3/driver/libcupsdriver.so.1:/root/cups-1.5.3/ppdc/libcupsppdc.so.1"
D [24/Jul/2012:22:40:00.449971 +0000] [CGI] envp[13] = "PATH=/tmp/cups-root/bin/filter:/usr/bin:/usr/sbin:/bin:/usr/bin"
D [24/Jul/2012:22:40:00.450003 +0000] [CGI] envp[14] = "SERVER_ADMIN=root@newbook"
D [24/Jul/2012:22:40:00.450035 +0000] [CGI] envp[15] = "SHLIB_PATH=/root/cups-1.5.3/cups:/root/cups-1.5.3/filter:/root/cups-1.5.3/cgi-bin:/root/cups-1.5.3/scheduler:/root/cups-1.5.3/driver:/root/cups-1.5.3/ppdc"
D [24/Jul/2012:22:40:00.450067 +0000] [CGI] envp[16] = "SOFTWARE=CUPS/1.5.3"
D [24/Jul/2012:22:40:00.450098 +0000] [CGI] envp[17] = "TMPDIR=/tmp/cups-root/spool/temp"
D [24/Jul/2012:22:40:00.450129 +0000] [CGI] envp[18] = "TZ=PST"
D [24/Jul/2012:22:40:00.450160 +0000] [CGI] envp[19] = "USER=root"
D [24/Jul/2012:22:40:00.450191 +0000] [CGI] envp[20] = "CUPS_SERVER=localhost"
D [24/Jul/2012:22:40:00.450222 +0000] [CGI] envp[21] = "CUPS_ENCRYPTION=IfRequested"
D [24/Jul/2012:22:40:00.450254 +0000] [CGI] envp[22] = "IPP_PORT=8631"
D [24/Jul/2012:22:40:00.450285 +0000] [CGI] envp[23] = "LANG=en.UTF8"
D [24/Jul/2012:22:40:00.450316 +0000] [CGI] envp[24] = "REDIRECT_STATUS=1"
D [24/Jul/2012:22:40:00.450347 +0000] [CGI] envp[25] = "GATEWAY_INTERFACE=CGI/1.1"
D [24/Jul/2012:22:40:00.450409 +0000] [CGI] envp[26] = "SERVER_NAME=localhost"
D [24/Jul/2012:22:40:00.450443 +0000] [CGI] envp[27] = "SERVER_PORT=8631"
D [24/Jul/2012:22:40:00.450474 +0000] [CGI] envp[28] = "REMOTE_ADDR=127.0.0.1"
D [24/Jul/2012:22:40:00.450506 +0000] [CGI] envp[29] = "REMOTE_HOST=localhost"
D [24/Jul/2012:22:40:00.450537 +0000] [CGI] envp[30] = "SCRIPT_NAME=/"
D [24/Jul/2012:22:40:00.450569 +0000] [CGI] envp[31] = "SCRIPT_FILENAME=/root/cups-1.5.3/doc/"
D [24/Jul/2012:22:40:00.450600 +0000] [CGI] envp[32] = "SERVER_PROTOCOL=HTTP/1.1"
D [24/Jul/2012:22:40:00.450632 +0000] [CGI] envp[33] = "HTTP_USER_AGENT=CUPS/1.5.3"
D [24/Jul/2012:22:40:00.450663 +0000] [CGI] envp[34] = "REQUEST_METHOD=POST"
D [24/Jul/2012:22:40:00.450695 +0000] [CGI] envp[35] = "CONTENT_LENGTH=72"
D [24/Jul/2012:22:40:00.450726 +0000] [CGI] envp[36] = "CONTENT_TYPE=application/ipp"
E [24/Jul/2012:22:40:00.450835 +0000] Directory "/tmp/cups-root/bin/daemon" has insecure permissions (040775/uid=501/gid=10).
D [24/Jul/2012:22:40:00.450873 +0000] [CGI] Started /tmp/cups-root/bin/daemon/cups-deviced (PID 0)
I [24/Jul/2012:22:40:00.450914 +0000] Started "/tmp/cups-root/bin/daemon/cups-deviced" (pid=0)
D [24/Jul/2012:22:40:00.450947 +0000] cupsdSendCommand: 10 file=11
D [24/Jul/2012:22:40:00.450984 +0000] CUPS-Get-Devices server-error-internal-error: cups-deviced failed to execute.
E [24/Jul/2012:22:40:00.451046 +0000] Returning IPP server-error-internal-error for CUPS-Get-Devices (no URI) from localhost
D [24/Jul/2012:22:40:00.451919 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [24/Jul/2012:22:40:00.452099 +0000] cupsdReadClient: 10 WAITING Closing on EOF
D [24/Jul/2012:22:40:00.452145 +0000] cupsdCloseClient: 10
D [24/Jul/2012:22:40:00.452194 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
I [24/Jul/2012:22:40:00.458080 +0000] Scheduler shutting down normally.
D [24/Jul/2012:22:40:00.458220 +0000] Discarding unused server-stopped event...
I [24/Jul/2012:22:40:00.459216 +0000] Saving printers.conf...
I [24/Jul/2012:22:40:00.461039 +0000] Saving subscriptions.conf...
D [24/Jul/2012:22:40:00.461280 +0000] cupsdSetBusyState: newbusy="Not busy", busy="Dirty files"
I [24/Jul/2012:22:40:00.461503 +0000] Saving job.cache...

page_log