Attachment 847483 Details for Bug 1048495 – /var/log/cups/error_log

/var/log/cups/error_log

error_log (text/plain), 164.80 KB, created by Fred New on 2014-01-09 05:38:18 UTC

(hide)

Description:

Filename:

MIME Type:

Creator: Fred New

Created: 2014-01-09 05:38:18 UTC

Size: 164.80 KB

patch

obsolete

>I [09/Jan/2014:07:14:52 +0200] Listening to [v1.::1]:631 (IPv6)
>I [09/Jan/2014:07:14:52 +0200] Listening to 127.0.0.1:631 (IPv4)
>I [09/Jan/2014:07:14:52 +0200] Listening to /var/run/cups/cups.sock (Domain)
>d [09/Jan/2014:07:14:52 +0200] cupsdAddLocation: Added location "/"
>d [09/Jan/2014:07:14:52 +0200] cupsdAddLocation: Added location "/admin"
>d [09/Jan/2014:07:14:52 +0200] cupsdAddLocation: Added location "/admin/conf"
>d [09/Jan/2014:07:14:52 +0200] cupsdAddName(loc=0x7f3c917eec50, name="@SYSTEM")
>d [09/Jan/2014:07:14:52 +0200] cupsdAddPolicyOp(p=0x7f3c917eef10, po=(nil), op=5(Create-Job))
>d [09/Jan/2014:07:14:52 +0200] cupsdAddPolicyOp(p=0x7f3c917eef10, po=0x7f3c917efb50, op=2(Print-Job))
>d [09/Jan/2014:07:14:52 +0200] cupsdAddPolicyOp(p=0x7f3c917eef10, po=0x7f3c917efb50, op=3(Print-URI))
>d [09/Jan/2014:07:14:52 +0200] cupsdAddPolicyOp(p=0x7f3c917eef10, po=0x7f3c917efb50, op=4(Validate-Job))
>d [09/Jan/2014:07:14:52 +0200] cupsdAddPolicyOp(p=0x7f3c917eef10, po=(nil), op=6(Send-Document))
>d [09/Jan/2014:07:14:52 +0200] cupsdAddName(loc=0x7f3c917efd20, name="@OWNER")
>d [09/Jan/2014:07:14:52 +0200] cupsdAddName(loc=0x7f3c917efd20, name="@SYSTEM")
>d [09/Jan/2014:07:14:52 +0200] cupsdAddPolicyOp(p=0x7f3c917eef10, po=0x7f3c917efd20, op=7(Send-URI))
>d [09/Jan/2014:07:14:52 +0200] cupsdAddPolicyOp(p=0x7f3c917eef10, po=0x7f3c917efd20, op=c(Hold-Job))
>d [09/Jan/2014:07:14:52 +0200] cupsdAddPolicyOp(p=0x7f3c917eef10, po=0x7f3c917efd20, op=d(Release-Job))
>d [09/Jan/2014:07:14:52 +0200] cupsdAddPolicyOp(p=0x7f3c917eef10, po=0x7f3c917efd20, op=e(Restart-Job))
>d [09/Jan/2014:07:14:52 +0200] cupsdAddPolicyOp(p=0x7f3c917eef10, po=0x7f3c917efd20, op=12(Purge-Jobs))
>d [09/Jan/2014:07:14:52 +0200] cupsdAddPolicyOp(p=0x7f3c917eef10, po=0x7f3c917efd20, op=14(Set-Job-Attributes))
>d [09/Jan/2014:07:14:52 +0200] cupsdAddPolicyOp(p=0x7f3c917eef10, po=0x7f3c917efd20, op=17(Create-Job-Subscription))
>d [09/Jan/2014:07:14:52 +0200] cupsdAddPolicyOp(p=0x7f3c917eef10, po=0x7f3c917efd20, op=1a(Renew-Subscription))
>d [09/Jan/2014:07:14:52 +0200] cupsdAddPolicyOp(p=0x7f3c917eef10, po=0x7f3c917efd20, op=1b(Cancel-Subscription))
>d [09/Jan/2014:07:14:52 +0200] cupsdAddPolicyOp(p=0x7f3c917eef10, po=0x7f3c917efd20, op=1c(Get-Notifications))
>d [09/Jan/2014:07:14:52 +0200] cupsdAddPolicyOp(p=0x7f3c917eef10, po=0x7f3c917efd20, op=2c(Reprocess-Job))
>d [09/Jan/2014:07:14:52 +0200] cupsdAddPolicyOp(p=0x7f3c917eef10, po=0x7f3c917efd20, op=2d(Cancel-Current-Job))
>d [09/Jan/2014:07:14:52 +0200] cupsdAddPolicyOp(p=0x7f3c917eef10, po=0x7f3c917efd20, op=2e(Suspend-Current-Job))
>d [09/Jan/2014:07:14:52 +0200] cupsdAddPolicyOp(p=0x7f3c917eef10, po=0x7f3c917efd20, op=2f(Resume-Job))
>d [09/Jan/2014:07:14:52 +0200] cupsdAddPolicyOp(p=0x7f3c917eef10, po=0x7f3c917efd20, op=39(Cancel-My-Jobs))
>d [09/Jan/2014:07:14:52 +0200] cupsdAddPolicyOp(p=0x7f3c917eef10, po=0x7f3c917efd20, op=3b(Close-Job))
>d [09/Jan/2014:07:14:52 +0200] cupsdAddPolicyOp(p=0x7f3c917eef10, po=0x7f3c917efd20, op=400d(CUPS-Move-Job))
>d [09/Jan/2014:07:14:52 +0200] cupsdAddPolicyOp(p=0x7f3c917eef10, po=0x7f3c917efd20, op=4027(CUPS-Get-Document))
>d [09/Jan/2014:07:14:52 +0200] cupsdAddPolicyOp(p=0x7f3c917eef10, po=(nil), op=4003(CUPS-Add-Modify-Printer))
>d [09/Jan/2014:07:14:52 +0200] cupsdAddName(loc=0x7f3c917f1700, name="@SYSTEM")
>d [09/Jan/2014:07:14:52 +0200] cupsdAddPolicyOp(p=0x7f3c917eef10, po=0x7f3c917f1700, op=4004(CUPS-Delete-Printer))
>d [09/Jan/2014:07:14:52 +0200] cupsdAddPolicyOp(p=0x7f3c917eef10, po=0x7f3c917f1700, op=4006(CUPS-Add-Modify-Class))
>d [09/Jan/2014:07:14:52 +0200] cupsdAddPolicyOp(p=0x7f3c917eef10, po=0x7f3c917f1700, op=4007(CUPS-Delete-Class))
>d [09/Jan/2014:07:14:52 +0200] cupsdAddPolicyOp(p=0x7f3c917eef10, po=0x7f3c917f1700, op=400a(CUPS-Set-Default))
>d [09/Jan/2014:07:14:52 +0200] cupsdAddPolicyOp(p=0x7f3c917eef10, po=0x7f3c917f1700, op=400b(CUPS-Get-Devices))
>d [09/Jan/2014:07:14:52 +0200] cupsdAddPolicyOp(p=0x7f3c917eef10, po=(nil), op=10(Pause-Printer))
>d [09/Jan/2014:07:14:52 +0200] cupsdAddName(loc=0x7f3c917f1f50, name="@SYSTEM")
>d [09/Jan/2014:07:14:52 +0200] cupsdAddPolicyOp(p=0x7f3c917eef10, po=0x7f3c917f1f50, op=11(Resume-Printer))
>d [09/Jan/2014:07:14:52 +0200] cupsdAddPolicyOp(p=0x7f3c917eef10, po=0x7f3c917f1f50, op=22(Enable-Printer))
>d [09/Jan/2014:07:14:52 +0200] cupsdAddPolicyOp(p=0x7f3c917eef10, po=0x7f3c917f1f50, op=23(Disable-Printer))
>d [09/Jan/2014:07:14:52 +0200] cupsdAddPolicyOp(p=0x7f3c917eef10, po=0x7f3c917f1f50, op=24(Pause-Printer-After-Current-Job))
>d [09/Jan/2014:07:14:52 +0200] cupsdAddPolicyOp(p=0x7f3c917eef10, po=0x7f3c917f1f50, op=25(Hold-New-Jobs))
>d [09/Jan/2014:07:14:52 +0200] cupsdAddPolicyOp(p=0x7f3c917eef10, po=0x7f3c917f1f50, op=26(Release-Held-New-Jobs))
>d [09/Jan/2014:07:14:52 +0200] cupsdAddPolicyOp(p=0x7f3c917eef10, po=0x7f3c917f1f50, op=27(Deactivate-Printer))
>d [09/Jan/2014:07:14:52 +0200] cupsdAddPolicyOp(p=0x7f3c917eef10, po=0x7f3c917f1f50, op=28(Activate-Printer))
>d [09/Jan/2014:07:14:52 +0200] cupsdAddPolicyOp(p=0x7f3c917eef10, po=0x7f3c917f1f50, op=29(Restart-Printer))
>d [09/Jan/2014:07:14:52 +0200] cupsdAddPolicyOp(p=0x7f3c917eef10, po=0x7f3c917f1f50, op=2a(Shutdown-Printer))
>d [09/Jan/2014:07:14:52 +0200] cupsdAddPolicyOp(p=0x7f3c917eef10, po=0x7f3c917f1f50, op=2b(Startup-Printer))
>d [09/Jan/2014:07:14:52 +0200] cupsdAddPolicyOp(p=0x7f3c917eef10, po=0x7f3c917f1f50, op=30(Promote-Job))
>d [09/Jan/2014:07:14:52 +0200] cupsdAddPolicyOp(p=0x7f3c917eef10, po=0x7f3c917f1f50, op=31(Schedule-Job-After))
>d [09/Jan/2014:07:14:52 +0200] cupsdAddPolicyOp(p=0x7f3c917eef10, po=0x7f3c917f1f50, op=38(Cancel-Jobs))
>d [09/Jan/2014:07:14:52 +0200] cupsdAddPolicyOp(p=0x7f3c917eef10, po=0x7f3c917f1f50, op=4008(CUPS-Accept-Jobs))
>d [09/Jan/2014:07:14:52 +0200] cupsdAddPolicyOp(p=0x7f3c917eef10, po=0x7f3c917f1f50, op=4009(CUPS-Reject-Jobs))
>d [09/Jan/2014:07:14:52 +0200] cupsdAddPolicyOp(p=0x7f3c917eef10, po=(nil), op=8(Cancel-Job))
>d [09/Jan/2014:07:14:52 +0200] cupsdAddName(loc=0x7f3c917f3720, name="@OWNER")
>d [09/Jan/2014:07:14:52 +0200] cupsdAddName(loc=0x7f3c917f3720, name="@SYSTEM")
>d [09/Jan/2014:07:14:52 +0200] cupsdAddPolicyOp(p=0x7f3c917eef10, po=0x7f3c917f3720, op=400e(CUPS-Authenticate-Job))
>d [09/Jan/2014:07:14:52 +0200] cupsdAddPolicyOp(p=0x7f3c917eef10, po=(nil), op=0(0x0000))
>d [09/Jan/2014:07:14:52 +0200] cupsdFindPolicyOp(p=0x7f3c917eef10, op=4(Validate-Job))
>d [09/Jan/2014:07:14:52 +0200] cupsdFindPolicyOp: Found exact match...
>d [09/Jan/2014:07:14:52 +0200] cupsdFindPolicyOp(p=0x7f3c917eef10, op=38(Cancel-Jobs))
>d [09/Jan/2014:07:14:52 +0200] cupsdFindPolicyOp: Found exact match...
>d [09/Jan/2014:07:14:52 +0200] cupsdFindPolicyOp(p=0x7f3c917eef10, op=39(Cancel-My-Jobs))
>d [09/Jan/2014:07:14:52 +0200] cupsdFindPolicyOp: Found exact match...
>d [09/Jan/2014:07:14:52 +0200] cupsdFindPolicyOp(p=0x7f3c917eef10, op=3b(Close-Job))
>d [09/Jan/2014:07:14:52 +0200] cupsdFindPolicyOp: Found exact match...
>d [09/Jan/2014:07:14:52 +0200] cupsdFindPolicyOp(p=0x7f3c917eef10, op=4027(CUPS-Get-Document))
>d [09/Jan/2014:07:14:52 +0200] cupsdFindPolicyOp: Found exact match...
>d [09/Jan/2014:07:14:52 +0200] cupsdAddPolicyOp(p=0x7f3c917f3a80, po=(nil), op=5(Create-Job))
>d [09/Jan/2014:07:14:52 +0200] cupsdAddPolicyOp(p=0x7f3c917f3a80, po=0x7f3c917f4390, op=2(Print-Job))
>d [09/Jan/2014:07:14:52 +0200] cupsdAddPolicyOp(p=0x7f3c917f3a80, po=0x7f3c917f4390, op=3(Print-URI))
>d [09/Jan/2014:07:14:52 +0200] cupsdAddPolicyOp(p=0x7f3c917f3a80, po=0x7f3c917f4390, op=4(Validate-Job))
>d [09/Jan/2014:07:14:52 +0200] cupsdAddPolicyOp(p=0x7f3c917f3a80, po=(nil), op=6(Send-Document))
>d [09/Jan/2014:07:14:52 +0200] cupsdAddName(loc=0x7f3c917f4560, name="@OWNER")
>d [09/Jan/2014:07:14:52 +0200] cupsdAddName(loc=0x7f3c917f4560, name="@SYSTEM")
>d [09/Jan/2014:07:14:52 +0200] cupsdAddPolicyOp(p=0x7f3c917f3a80, po=0x7f3c917f4560, op=7(Send-URI))
>d [09/Jan/2014:07:14:52 +0200] cupsdAddPolicyOp(p=0x7f3c917f3a80, po=0x7f3c917f4560, op=c(Hold-Job))
>d [09/Jan/2014:07:14:52 +0200] cupsdAddPolicyOp(p=0x7f3c917f3a80, po=0x7f3c917f4560, op=d(Release-Job))
>d [09/Jan/2014:07:14:52 +0200] cupsdAddPolicyOp(p=0x7f3c917f3a80, po=0x7f3c917f4560, op=e(Restart-Job))
>d [09/Jan/2014:07:14:52 +0200] cupsdAddPolicyOp(p=0x7f3c917f3a80, po=0x7f3c917f4560, op=12(Purge-Jobs))
>d [09/Jan/2014:07:14:52 +0200] cupsdAddPolicyOp(p=0x7f3c917f3a80, po=0x7f3c917f4560, op=14(Set-Job-Attributes))
>d [09/Jan/2014:07:14:52 +0200] cupsdAddPolicyOp(p=0x7f3c917f3a80, po=0x7f3c917f4560, op=17(Create-Job-Subscription))
>d [09/Jan/2014:07:14:52 +0200] cupsdAddPolicyOp(p=0x7f3c917f3a80, po=0x7f3c917f4560, op=1a(Renew-Subscription))
>d [09/Jan/2014:07:14:52 +0200] cupsdAddPolicyOp(p=0x7f3c917f3a80, po=0x7f3c917f4560, op=1b(Cancel-Subscription))
>d [09/Jan/2014:07:14:52 +0200] cupsdAddPolicyOp(p=0x7f3c917f3a80, po=0x7f3c917f4560, op=1c(Get-Notifications))
>d [09/Jan/2014:07:14:52 +0200] cupsdAddPolicyOp(p=0x7f3c917f3a80, po=0x7f3c917f4560, op=2c(Reprocess-Job))
>d [09/Jan/2014:07:14:52 +0200] cupsdAddPolicyOp(p=0x7f3c917f3a80, po=0x7f3c917f4560, op=2d(Cancel-Current-Job))
>d [09/Jan/2014:07:14:52 +0200] cupsdAddPolicyOp(p=0x7f3c917f3a80, po=0x7f3c917f4560, op=2e(Suspend-Current-Job))
>d [09/Jan/2014:07:14:52 +0200] cupsdAddPolicyOp(p=0x7f3c917f3a80, po=0x7f3c917f4560, op=2f(Resume-Job))
>d [09/Jan/2014:07:14:52 +0200] cupsdAddPolicyOp(p=0x7f3c917f3a80, po=0x7f3c917f4560, op=39(Cancel-My-Jobs))
>d [09/Jan/2014:07:14:52 +0200] cupsdAddPolicyOp(p=0x7f3c917f3a80, po=0x7f3c917f4560, op=3b(Close-Job))
>d [09/Jan/2014:07:14:52 +0200] cupsdAddPolicyOp(p=0x7f3c917f3a80, po=0x7f3c917f4560, op=400d(CUPS-Move-Job))
>d [09/Jan/2014:07:14:52 +0200] cupsdAddPolicyOp(p=0x7f3c917f3a80, po=0x7f3c917f4560, op=4027(CUPS-Get-Document))
>d [09/Jan/2014:07:14:52 +0200] cupsdAddPolicyOp(p=0x7f3c917f3a80, po=(nil), op=4003(CUPS-Add-Modify-Printer))
>d [09/Jan/2014:07:14:52 +0200] cupsdAddName(loc=0x7f3c917f5f40, name="@SYSTEM")
>d [09/Jan/2014:07:14:52 +0200] cupsdAddPolicyOp(p=0x7f3c917f3a80, po=0x7f3c917f5f40, op=4004(CUPS-Delete-Printer))
>d [09/Jan/2014:07:14:52 +0200] cupsdAddPolicyOp(p=0x7f3c917f3a80, po=0x7f3c917f5f40, op=4006(CUPS-Add-Modify-Class))
>d [09/Jan/2014:07:14:52 +0200] cupsdAddPolicyOp(p=0x7f3c917f3a80, po=0x7f3c917f5f40, op=4007(CUPS-Delete-Class))
>d [09/Jan/2014:07:14:52 +0200] cupsdAddPolicyOp(p=0x7f3c917f3a80, po=0x7f3c917f5f40, op=400a(CUPS-Set-Default))
>d [09/Jan/2014:07:14:52 +0200] cupsdAddPolicyOp(p=0x7f3c917f3a80, po=(nil), op=10(Pause-Printer))
>d [09/Jan/2014:07:14:52 +0200] cupsdAddName(loc=0x7f3c917f6640, name="@SYSTEM")
>d [09/Jan/2014:07:14:52 +0200] cupsdAddPolicyOp(p=0x7f3c917f3a80, po=0x7f3c917f6640, op=11(Resume-Printer))
>d [09/Jan/2014:07:14:52 +0200] cupsdAddPolicyOp(p=0x7f3c917f3a80, po=0x7f3c917f6640, op=22(Enable-Printer))
>d [09/Jan/2014:07:14:52 +0200] cupsdAddPolicyOp(p=0x7f3c917f3a80, po=0x7f3c917f6640, op=23(Disable-Printer))
>d [09/Jan/2014:07:14:52 +0200] cupsdAddPolicyOp(p=0x7f3c917f3a80, po=0x7f3c917f6640, op=24(Pause-Printer-After-Current-Job))
>d [09/Jan/2014:07:14:52 +0200] cupsdAddPolicyOp(p=0x7f3c917f3a80, po=0x7f3c917f6640, op=25(Hold-New-Jobs))
>d [09/Jan/2014:07:14:52 +0200] cupsdAddPolicyOp(p=0x7f3c917f3a80, po=0x7f3c917f6640, op=26(Release-Held-New-Jobs))
>d [09/Jan/2014:07:14:52 +0200] cupsdAddPolicyOp(p=0x7f3c917f3a80, po=0x7f3c917f6640, op=27(Deactivate-Printer))
>d [09/Jan/2014:07:14:52 +0200] cupsdAddPolicyOp(p=0x7f3c917f3a80, po=0x7f3c917f6640, op=28(Activate-Printer))
>d [09/Jan/2014:07:14:52 +0200] cupsdAddPolicyOp(p=0x7f3c917f3a80, po=0x7f3c917f6640, op=29(Restart-Printer))
>d [09/Jan/2014:07:14:52 +0200] cupsdAddPolicyOp(p=0x7f3c917f3a80, po=0x7f3c917f6640, op=2a(Shutdown-Printer))
>d [09/Jan/2014:07:14:52 +0200] cupsdAddPolicyOp(p=0x7f3c917f3a80, po=0x7f3c917f6640, op=2b(Startup-Printer))
>d [09/Jan/2014:07:14:52 +0200] cupsdAddPolicyOp(p=0x7f3c917f3a80, po=0x7f3c917f6640, op=30(Promote-Job))
>d [09/Jan/2014:07:14:52 +0200] cupsdAddPolicyOp(p=0x7f3c917f3a80, po=0x7f3c917f6640, op=31(Schedule-Job-After))
>d [09/Jan/2014:07:14:52 +0200] cupsdAddPolicyOp(p=0x7f3c917f3a80, po=0x7f3c917f6640, op=38(Cancel-Jobs))
>d [09/Jan/2014:07:14:52 +0200] cupsdAddPolicyOp(p=0x7f3c917f3a80, po=0x7f3c917f6640, op=4008(CUPS-Accept-Jobs))
>d [09/Jan/2014:07:14:52 +0200] cupsdAddPolicyOp(p=0x7f3c917f3a80, po=0x7f3c917f6640, op=4009(CUPS-Reject-Jobs))
>d [09/Jan/2014:07:14:52 +0200] cupsdAddPolicyOp(p=0x7f3c917f3a80, po=(nil), op=8(Cancel-Job))
>d [09/Jan/2014:07:14:52 +0200] cupsdAddName(loc=0x7f3c917f7e10, name="@OWNER")
>d [09/Jan/2014:07:14:52 +0200] cupsdAddName(loc=0x7f3c917f7e10, name="@SYSTEM")
>d [09/Jan/2014:07:14:52 +0200] cupsdAddPolicyOp(p=0x7f3c917f3a80, po=0x7f3c917f7e10, op=400e(CUPS-Authenticate-Job))
>d [09/Jan/2014:07:14:52 +0200] cupsdAddPolicyOp(p=0x7f3c917f3a80, po=(nil), op=0(0x0000))
>d [09/Jan/2014:07:14:52 +0200] cupsdFindPolicyOp(p=0x7f3c917f3a80, op=4(Validate-Job))
>d [09/Jan/2014:07:14:52 +0200] cupsdFindPolicyOp: Found exact match...
>d [09/Jan/2014:07:14:52 +0200] cupsdFindPolicyOp(p=0x7f3c917f3a80, op=38(Cancel-Jobs))
>d [09/Jan/2014:07:14:52 +0200] cupsdFindPolicyOp: Found exact match...
>d [09/Jan/2014:07:14:52 +0200] cupsdFindPolicyOp(p=0x7f3c917f3a80, op=39(Cancel-My-Jobs))
>d [09/Jan/2014:07:14:52 +0200] cupsdFindPolicyOp: Found exact match...
>d [09/Jan/2014:07:14:52 +0200] cupsdFindPolicyOp(p=0x7f3c917f3a80, op=3b(Close-Job))
>d [09/Jan/2014:07:14:52 +0200] cupsdFindPolicyOp: Found exact match...
>d [09/Jan/2014:07:14:52 +0200] cupsdFindPolicyOp(p=0x7f3c917f3a80, op=4027(CUPS-Get-Document))
>d [09/Jan/2014:07:14:52 +0200] cupsdFindPolicyOp: Found exact match...
>I [09/Jan/2014:07:14:52 +0200] Remote access is disabled.
>D [09/Jan/2014:07:14:52 +0200] Added auto ServerAlias envy17.salumetsnew.ee
>D [09/Jan/2014:07:14:52 +0200] Added auto ServerAlias envy17
>I [09/Jan/2014:07:14:52 +0200] Loaded configuration file "/etc/cups/cupsd.conf"
>I [09/Jan/2014:07:14:52 +0200] Using default TempDir of /var/spool/cups/tmp...
>d [09/Jan/2014:07:14:52 +0200] cupsdSetEnv: CUPS_CACHEDIR=/var/cache/cups
>d [09/Jan/2014:07:14:52 +0200] cupsdSetEnv: CUPS_DATADIR=/usr/share/cups
>d [09/Jan/2014:07:14:52 +0200] cupsdSetEnv: CUPS_DOCROOT=/usr/share/cups/www
>d [09/Jan/2014:07:14:52 +0200] cupsdSetEnv: CUPS_FONTPATH=/usr/share/cups/fonts
>d [09/Jan/2014:07:14:52 +0200] cupsdSetEnv: CUPS_REQUESTROOT=/var/spool/cups
>d [09/Jan/2014:07:14:52 +0200] cupsdSetEnv: CUPS_SERVERBIN=/usr/lib/cups
>d [09/Jan/2014:07:14:52 +0200] cupsdSetEnv: CUPS_SERVERROOT=/etc/cups
>d [09/Jan/2014:07:14:52 +0200] cupsdSetEnv: CUPS_STATEDIR=/var/run/cups
>d [09/Jan/2014:07:14:52 +0200] cupsdSetEnv: HOME=/var/spool/cups/tmp
>d [09/Jan/2014:07:14:52 +0200] cupsdSetEnv: PATH=/usr/lib/cups/filter:/usr/lib64/cups/filter:/usr/bin:/usr/sbin:/bin:/usr/bin
>d [09/Jan/2014:07:14:52 +0200] cupsdSetEnv: SERVER_ADMIN=root@envy17.salumetsnew.ee
>d [09/Jan/2014:07:14:52 +0200] cupsdSetEnv: SOFTWARE=CUPS/1.7.0
>d [09/Jan/2014:07:14:52 +0200] cupsdSetEnv: TMPDIR=/var/spool/cups/tmp
>d [09/Jan/2014:07:14:52 +0200] cupsdSetEnv: USER=root
>d [09/Jan/2014:07:14:52 +0200] cupsdSetEnv: CUPS_MAX_MESSAGE=2047
>I [09/Jan/2014:07:14:52 +0200] Configured for up to 100 clients.
>I [09/Jan/2014:07:14:52 +0200] Allowing up to 100 client connections per host.
>I [09/Jan/2014:07:14:52 +0200] Using policy "default" as the default.
>d [09/Jan/2014:07:14:52 +0200] cupsdReadConfiguration: NumPolicies=2
>d [09/Jan/2014:07:14:52 +0200] cupsdReadConfiguration: Policies[0]="authenticated"
>d [09/Jan/2014:07:14:52 +0200] cupsdReadConfiguration: Policies[1]="default"
>I [09/Jan/2014:07:14:52 +0200] Full reload is required.
>I [09/Jan/2014:07:14:52 +0200] Loaded MIME database from "/usr/share/cups/mime" and "/etc/cups": 39 types, 57 filters...
>d [09/Jan/2014:07:14:52 +0200] cupsdReadConfiguration: type application/octet-stream
>d [09/Jan/2014:07:14:52 +0200] cupsdReadConfiguration: type application/pdf
>d [09/Jan/2014:07:14:52 +0200] cupsdReadConfiguration: type application/postscript
>d [09/Jan/2014:07:14:52 +0200] cupsdReadConfiguration: type application/rss+xml
>d [09/Jan/2014:07:14:52 +0200] cupsdReadConfiguration: type application/vnd.adobe-reader-postscript
>d [09/Jan/2014:07:14:52 +0200] cupsdReadConfiguration: type application/vnd.cups-banner
>d [09/Jan/2014:07:14:52 +0200] cupsdReadConfiguration: type application/vnd.cups-command
>d [09/Jan/2014:07:14:52 +0200] cupsdReadConfiguration: type application/vnd.cups-pdf
>d [09/Jan/2014:07:14:52 +0200] cupsdReadConfiguration: type application/vnd.cups-pdf-banner
>d [09/Jan/2014:07:14:52 +0200] cupsdReadConfiguration: type application/vnd.cups-postscript
>d [09/Jan/2014:07:14:52 +0200] cupsdReadConfiguration: type application/vnd.cups-ppd
>d [09/Jan/2014:07:14:52 +0200] cupsdReadConfiguration: type application/vnd.cups-raster
>d [09/Jan/2014:07:14:52 +0200] cupsdReadConfiguration: type application/vnd.cups-raw
>d [09/Jan/2014:07:14:52 +0200] cupsdReadConfiguration: type application/x-cshell
>d [09/Jan/2014:07:14:52 +0200] cupsdReadConfiguration: type application/x-csource
>d [09/Jan/2014:07:14:52 +0200] cupsdReadConfiguration: type application/x-perl
>d [09/Jan/2014:07:14:52 +0200] cupsdReadConfiguration: type application/x-shell
>d [09/Jan/2014:07:14:52 +0200] cupsdReadConfiguration: type image/gif
>d [09/Jan/2014:07:14:52 +0200] cupsdReadConfiguration: type image/jpeg
>d [09/Jan/2014:07:14:52 +0200] cupsdReadConfiguration: type image/png
>d [09/Jan/2014:07:14:52 +0200] cupsdReadConfiguration: type image/pwg-raster
>d [09/Jan/2014:07:14:52 +0200] cupsdReadConfiguration: type image/tiff
>d [09/Jan/2014:07:14:52 +0200] cupsdReadConfiguration: type image/urf
>d [09/Jan/2014:07:14:52 +0200] cupsdReadConfiguration: type image/x-alias
>d [09/Jan/2014:07:14:52 +0200] cupsdReadConfiguration: type image/x-bitmap
>d [09/Jan/2014:07:14:52 +0200] cupsdReadConfiguration: type image/x-icon
>d [09/Jan/2014:07:14:52 +0200] cupsdReadConfiguration: type image/x-photocd
>d [09/Jan/2014:07:14:52 +0200] cupsdReadConfiguration: type image/x-portable-anymap
>d [09/Jan/2014:07:14:52 +0200] cupsdReadConfiguration: type image/x-portable-bitmap
>d [09/Jan/2014:07:14:52 +0200] cupsdReadConfiguration: type image/x-portable-graymap
>d [09/Jan/2014:07:14:52 +0200] cupsdReadConfiguration: type image/x-portable-pixmap
>d [09/Jan/2014:07:14:52 +0200] cupsdReadConfiguration: type image/x-sgi-rgb
>d [09/Jan/2014:07:14:52 +0200] cupsdReadConfiguration: type image/x-sun-raster
>d [09/Jan/2014:07:14:52 +0200] cupsdReadConfiguration: type image/x-xbitmap
>d [09/Jan/2014:07:14:52 +0200] cupsdReadConfiguration: type image/x-xpixmap
>d [09/Jan/2014:07:14:52 +0200] cupsdReadConfiguration: type image/x-xwindowdump
>d [09/Jan/2014:07:14:52 +0200] cupsdReadConfiguration: type text/css
>d [09/Jan/2014:07:14:52 +0200] cupsdReadConfiguration: type text/html
>d [09/Jan/2014:07:14:52 +0200] cupsdReadConfiguration: type text/plain
>d [09/Jan/2014:07:14:52 +0200] cupsdReadConfiguration: filter application/octet-stream to application/vnd.cups-raw 0 -
>d [09/Jan/2014:07:14:52 +0200] cupsdReadConfiguration: filter application/pdf to application/vnd.cups-pdf 66 pdftopdf
>d [09/Jan/2014:07:14:52 +0200] cupsdReadConfiguration: filter application/pdf to image/tiff 80 pstotiff
>d [09/Jan/2014:07:14:52 +0200] cupsdReadConfiguration: filter application/postscript to application/pdf 0 pstopdf
>d [09/Jan/2014:07:14:52 +0200] cupsdReadConfiguration: filter application/postscript to application/vnd.cups-postscript 66 pstops
>d [09/Jan/2014:07:14:52 +0200] cupsdReadConfiguration: filter application/postscript to image/tiff 80 pstotiff
>d [09/Jan/2014:07:14:52 +0200] cupsdReadConfiguration: filter application/vnd.adobe-reader-postscript to application/vnd.cups-postscript 66 pstops
>d [09/Jan/2014:07:14:52 +0200] cupsdReadConfiguration: filter application/vnd.cups-pdf to application/vnd.cups-postscript 100 pdftops
>d [09/Jan/2014:07:14:52 +0200] cupsdReadConfiguration: filter application/vnd.cups-pdf to application/vnd.cups-raster 99 gstoraster
>d [09/Jan/2014:07:14:52 +0200] cupsdReadConfiguration: filter application/vnd.cups-pdf to image/tiff 80 pstotiff
>d [09/Jan/2014:07:14:52 +0200] cupsdReadConfiguration: filter application/vnd.cups-pdf-banner to application/pdf 32 bannertopdf
>d [09/Jan/2014:07:14:52 +0200] cupsdReadConfiguration: filter application/vnd.cups-postscript to application/vnd.cups-raster 175 gstoraster
>d [09/Jan/2014:07:14:52 +0200] cupsdReadConfiguration: filter application/vnd.cups-postscript to image/tiff 80 pstotiff
>d [09/Jan/2014:07:14:52 +0200] cupsdReadConfiguration: filter application/vnd.cups-raster to image/pwg-raster 100 rastertopwg
>d [09/Jan/2014:07:14:52 +0200] cupsdReadConfiguration: filter application/x-cshell to application/pdf 32 texttopdf
>d [09/Jan/2014:07:14:52 +0200] cupsdReadConfiguration: filter application/x-cshell to text/plain 100 -
>d [09/Jan/2014:07:14:52 +0200] cupsdReadConfiguration: filter application/x-csource to application/pdf 32 texttopdf
>d [09/Jan/2014:07:14:52 +0200] cupsdReadConfiguration: filter application/x-csource to text/plain 100 -
>d [09/Jan/2014:07:14:52 +0200] cupsdReadConfiguration: filter application/x-perl to application/pdf 32 texttopdf
>d [09/Jan/2014:07:14:52 +0200] cupsdReadConfiguration: filter application/x-perl to text/plain 100 -
>d [09/Jan/2014:07:14:52 +0200] cupsdReadConfiguration: filter application/x-shell to application/pdf 32 texttopdf
>d [09/Jan/2014:07:14:52 +0200] cupsdReadConfiguration: filter application/x-shell to text/plain 100 -
>d [09/Jan/2014:07:14:52 +0200] cupsdReadConfiguration: filter image/gif to application/vnd.cups-pdf 65 imagetopdf
>d [09/Jan/2014:07:14:52 +0200] cupsdReadConfiguration: filter image/gif to application/vnd.cups-raster 100 imagetoraster
>d [09/Jan/2014:07:14:52 +0200] cupsdReadConfiguration: filter image/jpeg to application/vnd.cups-pdf 65 imagetopdf
>d [09/Jan/2014:07:14:52 +0200] cupsdReadConfiguration: filter image/jpeg to application/vnd.cups-raster 100 imagetoraster
>d [09/Jan/2014:07:14:52 +0200] cupsdReadConfiguration: filter image/png to application/vnd.cups-pdf 65 imagetopdf
>d [09/Jan/2014:07:14:52 +0200] cupsdReadConfiguration: filter image/png to application/vnd.cups-raster 100 imagetoraster
>d [09/Jan/2014:07:14:52 +0200] cupsdReadConfiguration: filter image/tiff to application/vnd.cups-pdf 65 imagetopdf
>d [09/Jan/2014:07:14:52 +0200] cupsdReadConfiguration: filter image/tiff to application/vnd.cups-raster 100 imagetoraster
>d [09/Jan/2014:07:14:52 +0200] cupsdReadConfiguration: filter image/urf to application/pdf 0 urftopdf
>d [09/Jan/2014:07:14:52 +0200] cupsdReadConfiguration: filter image/x-bitmap to application/vnd.cups-pdf 65 imagetopdf
>d [09/Jan/2014:07:14:52 +0200] cupsdReadConfiguration: filter image/x-bitmap to application/vnd.cups-raster 100 imagetoraster
>d [09/Jan/2014:07:14:52 +0200] cupsdReadConfiguration: filter image/x-photocd to application/vnd.cups-pdf 65 imagetopdf
>d [09/Jan/2014:07:14:52 +0200] cupsdReadConfiguration: filter image/x-photocd to application/vnd.cups-raster 100 imagetoraster
>d [09/Jan/2014:07:14:52 +0200] cupsdReadConfiguration: filter image/x-portable-anymap to application/vnd.cups-pdf 65 imagetopdf
>d [09/Jan/2014:07:14:52 +0200] cupsdReadConfiguration: filter image/x-portable-anymap to application/vnd.cups-raster 100 imagetoraster
>d [09/Jan/2014:07:14:52 +0200] cupsdReadConfiguration: filter image/x-portable-bitmap to application/vnd.cups-pdf 65 imagetopdf
>d [09/Jan/2014:07:14:52 +0200] cupsdReadConfiguration: filter image/x-portable-bitmap to application/vnd.cups-raster 100 imagetoraster
>d [09/Jan/2014:07:14:52 +0200] cupsdReadConfiguration: filter image/x-portable-graymap to application/vnd.cups-pdf 65 imagetopdf
>d [09/Jan/2014:07:14:52 +0200] cupsdReadConfiguration: filter image/x-portable-graymap to application/vnd.cups-raster 100 imagetoraster
>d [09/Jan/2014:07:14:52 +0200] cupsdReadConfiguration: filter image/x-portable-pixmap to application/vnd.cups-pdf 65 imagetopdf
>d [09/Jan/2014:07:14:52 +0200] cupsdReadConfiguration: filter image/x-portable-pixmap to application/vnd.cups-raster 100 imagetoraster
>d [09/Jan/2014:07:14:52 +0200] cupsdReadConfiguration: filter image/x-sgi-rgb to application/vnd.cups-pdf 65 imagetopdf
>d [09/Jan/2014:07:14:52 +0200] cupsdReadConfiguration: filter image/x-sgi-rgb to application/vnd.cups-raster 100 imagetoraster
>d [09/Jan/2014:07:14:52 +0200] cupsdReadConfiguration: filter image/x-sun-raster to application/vnd.cups-pdf 65 imagetopdf
>d [09/Jan/2014:07:14:52 +0200] cupsdReadConfiguration: filter image/x-sun-raster to application/vnd.cups-raster 100 imagetoraster
>d [09/Jan/2014:07:14:52 +0200] cupsdReadConfiguration: filter image/x-xbitmap to application/vnd.cups-pdf 65 imagetopdf
>d [09/Jan/2014:07:14:52 +0200] cupsdReadConfiguration: filter image/x-xbitmap to application/vnd.cups-raster 100 imagetoraster
>d [09/Jan/2014:07:14:52 +0200] cupsdReadConfiguration: filter image/x-xpixmap to application/vnd.cups-pdf 65 imagetopdf
>d [09/Jan/2014:07:14:52 +0200] cupsdReadConfiguration: filter image/x-xpixmap to application/vnd.cups-raster 100 imagetoraster
>d [09/Jan/2014:07:14:52 +0200] cupsdReadConfiguration: filter image/x-xwindowdump to application/vnd.cups-pdf 65 imagetopdf
>d [09/Jan/2014:07:14:52 +0200] cupsdReadConfiguration: filter text/css to text/plain 100 -
>d [09/Jan/2014:07:14:52 +0200] cupsdReadConfiguration: filter text/html to application/pdf 32 texttopdf
>d [09/Jan/2014:07:14:52 +0200] cupsdReadConfiguration: filter text/html to text/plain 100 -
>d [09/Jan/2014:07:14:52 +0200] cupsdReadConfiguration: filter text/plain to application/pdf 32 texttopdf
>d [09/Jan/2014:07:14:52 +0200] cupsdReadConfiguration: filter text/plain to application/postscript 30 texttopaps
>D [09/Jan/2014:07:14:52 +0200] Loading printer LaserJet-4L...
>d [09/Jan/2014:07:14:52 +0200] cupsdAddPrinter("LaserJet-4L")
>d [09/Jan/2014:07:14:52 +0200] cupsdAddPrinter: Adding LaserJet-4L to Printers
>d [09/Jan/2014:07:14:52 +0200] cupsdSetPrinterReasons(p=0x7f3c917fc2f0(LaserJet-4L),s="-cups-insecure-filter-warning,cups-missing-filter-warning"
>d [09/Jan/2014:07:14:52 +0200] cupsdFindBest: uri = "/printers/LaserJet-4L"...
>d [09/Jan/2014:07:14:52 +0200] cupsdFindBest: Location /admin/conf Limit 7f
>d [09/Jan/2014:07:14:52 +0200] cupsdFindBest: Location /admin Limit 7f
>d [09/Jan/2014:07:14:52 +0200] cupsdFindBest: Location / Limit 7f
>d [09/Jan/2014:07:14:52 +0200] cupsdFindBest: best = /
>d [09/Jan/2014:07:14:52 +0200] cupsdFindPolicyOp(p=0x7f3c917eef10, op=2(Print-Job))
>d [09/Jan/2014:07:14:52 +0200] cupsdFindPolicyOp: Found exact match...
>D [09/Jan/2014:07:14:52 +0200] load_ppd: Loading /var/cache/cups/LaserJet-4L.data...
>d [09/Jan/2014:07:14:52 +0200] cupsdSetPrinterReasons(p=0x7f3c917fc2f0(LaserJet-4L),s="-cups-missing-filter-warning,cups-insecure-filter-warning"
>d [09/Jan/2014:07:14:52 +0200] add_printer_filter(p=0x7f3c917fc2f0(LaserJet-4L), filtertype=0x7f3c917fcae0(printer/LaserJet-4L), filter="application/vnd.cups-raw application/octet-stream 0 -")
>d [09/Jan/2014:07:14:52 +0200] add_printer_filter: LaserJet-4L: adding filter application/vnd.cups-raw printer/LaserJet-4L/application/octet-stream 0 -
>d [09/Jan/2014:07:14:52 +0200] add_printer_filter: LaserJet-4L: adding filter printer/LaserJet-4L/application/octet-stream printer/LaserJet-4L 0 -
>d [09/Jan/2014:07:14:52 +0200] add_printer_filter(p=0x7f3c917fc2f0(LaserJet-4L), filtertype=0x7f3c917fcae0(printer/LaserJet-4L), filter="application/vnd.cups-postscript 100 foomatic-rip")
>d [09/Jan/2014:07:14:52 +0200] LaserJet-4L: File "/usr/lib/cups/filter/foomatic-rip" permissions OK (040755/uid=0/gid=0).
>d [09/Jan/2014:07:14:52 +0200] add_printer_filter: LaserJet-4L: adding filter application/vnd.cups-postscript printer/LaserJet-4L 100 foomatic-rip
>d [09/Jan/2014:07:14:52 +0200] add_printer_filter(p=0x7f3c917fc2f0(LaserJet-4L), filtertype=0x7f3c917fcae0(printer/LaserJet-4L), filter="application/vnd.cups-pdf 0 foomatic-rip")
>d [09/Jan/2014:07:14:52 +0200] LaserJet-4L: File "/usr/lib/cups/filter/foomatic-rip" permissions OK (040755/uid=0/gid=0).
>d [09/Jan/2014:07:14:52 +0200] add_printer_filter: LaserJet-4L: adding filter application/vnd.cups-pdf printer/LaserJet-4L 0 foomatic-rip
>d [09/Jan/2014:07:14:52 +0200] add_printer_filter(p=0x7f3c917fc2f0(LaserJet-4L), filtertype=0x7f3c917fcae0(printer/LaserJet-4L), filter="application/vnd.cups-command application/postscript 100 commandtops")
>d [09/Jan/2014:07:14:52 +0200] LaserJet-4L: File "/usr/lib/cups/filter/commandtops" permissions OK (040755/uid=0/gid=0).
>d [09/Jan/2014:07:14:52 +0200] add_printer_filter: LaserJet-4L: adding filter application/vnd.cups-command printer/LaserJet-4L/application/postscript 100 commandtops
>d [09/Jan/2014:07:14:52 +0200] add_printer_filter: LaserJet-4L: adding filter printer/LaserJet-4L/application/postscript printer/LaserJet-4L 0 -
>d [09/Jan/2014:07:14:52 +0200] add_printer_formats: 42 types, 63 filters
>d [09/Jan/2014:07:14:52 +0200] add_printer_formats: LaserJet-4L: application/octet-stream needs 2 filters
>d [09/Jan/2014:07:14:52 +0200] add_printer_formats: LaserJet-4L: application/pdf needs 1 filters
>d [09/Jan/2014:07:14:52 +0200] add_printer_formats: LaserJet-4L: application/postscript needs 2 filters
>d [09/Jan/2014:07:14:52 +0200] add_printer_formats: LaserJet-4L: application/rss+xml not supported
>d [09/Jan/2014:07:14:52 +0200] add_printer_formats: LaserJet-4L: application/vnd.adobe-reader-postscript needs 1 filters
>d [09/Jan/2014:07:14:52 +0200] add_printer_formats: LaserJet-4L: application/vnd.cups-banner not supported
>d [09/Jan/2014:07:14:52 +0200] add_printer_formats: LaserJet-4L: application/vnd.cups-command needs 1 filters
>d [09/Jan/2014:07:14:52 +0200] add_printer_formats: LaserJet-4L: application/vnd.cups-pdf needs 1 filters
>d [09/Jan/2014:07:14:52 +0200] add_printer_formats: LaserJet-4L: application/vnd.cups-pdf-banner needs 2 filters
>d [09/Jan/2014:07:14:52 +0200] add_printer_formats: LaserJet-4L: application/vnd.cups-postscript needs 1 filters
>d [09/Jan/2014:07:14:52 +0200] add_printer_formats: LaserJet-4L: application/vnd.cups-ppd not supported
>d [09/Jan/2014:07:14:52 +0200] add_printer_formats: LaserJet-4L: application/vnd.cups-raster not supported
>d [09/Jan/2014:07:14:52 +0200] add_printer_formats: LaserJet-4L: application/vnd.cups-raw needs 1 filters
>d [09/Jan/2014:07:14:52 +0200] add_printer_formats: LaserJet-4L: application/x-cshell needs 2 filters
>d [09/Jan/2014:07:14:52 +0200] add_printer_formats: LaserJet-4L: application/x-csource needs 2 filters
>d [09/Jan/2014:07:14:52 +0200] add_printer_formats: LaserJet-4L: application/x-perl needs 2 filters
>d [09/Jan/2014:07:14:52 +0200] add_printer_formats: LaserJet-4L: application/x-shell needs 2 filters
>d [09/Jan/2014:07:14:52 +0200] add_printer_formats: LaserJet-4L: image/gif needs 1 filters
>d [09/Jan/2014:07:14:52 +0200] add_printer_formats: LaserJet-4L: image/jpeg needs 1 filters
>d [09/Jan/2014:07:14:52 +0200] add_printer_formats: LaserJet-4L: image/png needs 1 filters
>d [09/Jan/2014:07:14:52 +0200] add_printer_formats: LaserJet-4L: image/pwg-raster not supported
>d [09/Jan/2014:07:14:52 +0200] add_printer_formats: LaserJet-4L: image/tiff needs 1 filters
>d [09/Jan/2014:07:14:52 +0200] add_printer_formats: LaserJet-4L: image/urf needs 2 filters
>d [09/Jan/2014:07:14:52 +0200] add_printer_formats: LaserJet-4L: image/x-alias not supported
>d [09/Jan/2014:07:14:52 +0200] add_printer_formats: LaserJet-4L: image/x-bitmap needs 1 filters
>d [09/Jan/2014:07:14:52 +0200] add_printer_formats: LaserJet-4L: image/x-icon not supported
>d [09/Jan/2014:07:14:52 +0200] add_printer_formats: LaserJet-4L: image/x-photocd needs 1 filters
>d [09/Jan/2014:07:14:52 +0200] add_printer_formats: LaserJet-4L: image/x-portable-anymap needs 1 filters
>d [09/Jan/2014:07:14:52 +0200] add_printer_formats: LaserJet-4L: image/x-portable-bitmap needs 1 filters
>d [09/Jan/2014:07:14:52 +0200] add_printer_formats: LaserJet-4L: image/x-portable-graymap needs 1 filters
>d [09/Jan/2014:07:14:52 +0200] add_printer_formats: LaserJet-4L: image/x-portable-pixmap needs 1 filters
>d [09/Jan/2014:07:14:52 +0200] add_printer_formats: LaserJet-4L: image/x-sgi-rgb needs 1 filters
>d [09/Jan/2014:07:14:52 +0200] add_printer_formats: LaserJet-4L: image/x-sun-raster needs 1 filters
>d [09/Jan/2014:07:14:52 +0200] add_printer_formats: LaserJet-4L: image/x-xbitmap needs 1 filters
>d [09/Jan/2014:07:14:52 +0200] add_printer_formats: LaserJet-4L: image/x-xpixmap needs 1 filters
>d [09/Jan/2014:07:14:52 +0200] add_printer_formats: LaserJet-4L: image/x-xwindowdump needs 1 filters
>d [09/Jan/2014:07:14:52 +0200] add_printer_formats: LaserJet-4L: text/css needs 4 filters
>d [09/Jan/2014:07:14:52 +0200] add_printer_formats: LaserJet-4L: text/html needs 2 filters
>d [09/Jan/2014:07:14:52 +0200] add_printer_formats: LaserJet-4L: text/plain needs 2 filters
>d [09/Jan/2014:07:14:52 +0200] add_printer_formats: LaserJet-4L: 32 supported types
>D [09/Jan/2014:07:14:52 +0200] cupsdRegisterPrinter(p=0x7f3c917fc2f0(LaserJet-4L))
>I [09/Jan/2014:07:14:52 +0200] Loading job cache file "/var/cache/cups/job.cache"...
>D [09/Jan/2014:07:14:52 +0200] [Job 18] Loading from cache...
>D [09/Jan/2014:07:14:52 +0200] [Job 19] Loading from cache...
>D [09/Jan/2014:07:14:52 +0200] [Job 20] Loading from cache...
>D [09/Jan/2014:07:14:52 +0200] cupsdAddSubscription(mask=0, dest=(nil)(), job=(nil)(0), uri="(null)")
>I [09/Jan/2014:07:14:52 +0200] Full reload complete.
>D [09/Jan/2014:07:14:52 +0200] cupsdCleanFiles(path="/var/spool/cups/tmp", pattern="(null)")
>I [09/Jan/2014:07:14:52 +0200] Cleaning out old files in "/var/spool/cups/tmp".
>D [09/Jan/2014:07:14:52 +0200] cupsdCleanFiles(path="/var/spool/cups/tmp/.hplip", pattern="(null)")
>I [09/Jan/2014:07:14:52 +0200] Cleaning out old files in "/var/spool/cups/tmp/.hplip".
>D [09/Jan/2014:07:14:52 +0200] cupsdCleanFiles(path="/var/cache/cups", pattern="*.ipp")
>I [09/Jan/2014:07:14:52 +0200] Cleaning out old files in "/var/cache/cups".
>D [09/Jan/2014:07:14:52 +0200] systemd_checkin: Matched existing listener /var/run/cups/cups.sock with fd 3...
>D [09/Jan/2014:07:14:52 +0200] Calling FindDeviceById(cups-LaserJet-4L)
>D [09/Jan/2014:07:14:52 +0200] FindDeviceById failed: org.freedesktop.ColorManager.NotFound:device id 'cups-LaserJet-4L' does not exist
>D [09/Jan/2014:07:14:52 +0200] Using profile ID "LaserJet-4L-Gray..".
>D [09/Jan/2014:07:14:52 +0200] Calling CreateProfile(LaserJet-4L-Gray..,temp)
>D [09/Jan/2014:07:14:52 +0200] Created profile "/org/freedesktop/ColorManager/profiles/LaserJet_4L_Gray__".
>I [09/Jan/2014:07:14:52 +0200] Registering ICC color profiles for "LaserJet-4L".
>D [09/Jan/2014:07:14:52 +0200] Calling CreateDevice(cups-LaserJet-4L,temp)
>D [09/Jan/2014:07:14:52 +0200] Created device "/org/freedesktop/ColorManager/devices/cups_LaserJet_4L".
>D [09/Jan/2014:07:14:52 +0200] Calling /org/freedesktop/ColorManager/devices/cups_LaserJet_4L:AddProfile(/org/freedesktop/ColorManager/profiles/LaserJet_4L_Gray__) [soft]
>d [09/Jan/2014:07:14:52 +0200] cupsdCreateProfile(job_id=0) = NULL
>d [09/Jan/2014:07:14:52 +0200] cupsdStartListening: 3 Listeners
>I [09/Jan/2014:07:14:52 +0200] Listening to [v1.::1]:631 on fd 10...
>I [09/Jan/2014:07:14:52 +0200] Listening to 127.0.0.1:631 on fd 11...
>I [09/Jan/2014:07:14:52 +0200] Listening to /var/run/cups/cups.sock:631 on fd 3...
>d [09/Jan/2014:07:14:52 +0200] cupsdSetEnv: CUPS_SERVER=/var/run/cups/cups.sock
>d [09/Jan/2014:07:14:52 +0200] cupsdSetEnv: CUPS_ENCRYPTION=IfRequested
>d [09/Jan/2014:07:14:52 +0200] cupsdSetEnv: IPP_PORT=631
>I [09/Jan/2014:07:14:52 +0200] Resuming new connection processing...
>d [09/Jan/2014:07:14:52 +0200] cupsdResumeListening: Setting input bits...
>d [09/Jan/2014:07:14:52 +0200] cupsdAddSelect(fd=10, read_cb=0x7f3c8f7e0d50, write_cb=(nil), data=0x7f3c917ea330)
>d [09/Jan/2014:07:14:52 +0200] cupsdAddSelect(fd=11, read_cb=0x7f3c8f7e0d50, write_cb=(nil), data=0x7f3c917ee9c0)
>d [09/Jan/2014:07:14:52 +0200] cupsdAddSelect(fd=3, read_cb=0x7f3c8f7e0d50, write_cb=(nil), data=0x7f3c917eeae0)
>d [09/Jan/2014:07:14:52 +0200] cupsdAddSelect(fd=12, read_cb=0x7f3c8f7e0b40, write_cb=(nil), data=(nil))
>D [09/Jan/2014:07:14:52 +0200] cupsdSetBusyState: newbusy="Not busy", busy="Not busy"
>d [09/Jan/2014:07:14:52 +0200] cupsdAddCert: Adding certificate for PID 0
>d [09/Jan/2014:07:14:52 +0200] cupsdAddCert: NumSystemGroups=2
>d [09/Jan/2014:07:14:52 +0200] cupsdAddEvent(event=server-started, dest=(nil)(), job=(nil)(0), text="Scheduler started in foreground.", ...)
>D [09/Jan/2014:07:14:52 +0200] Discarding unused server-started event...
>d [09/Jan/2014:07:14:52 +0200] cupsdCheckJobs: 0 active jobs, sleeping=0, reload=0, curtime=1389244492
>d [09/Jan/2014:07:14:52 +0200] select_timeout: JobHistoryUpdate=0
>D [09/Jan/2014:07:14:53 +0200] Report: clients=0
>D [09/Jan/2014:07:14:53 +0200] Report: jobs=3
>D [09/Jan/2014:07:14:53 +0200] Report: jobs-active=0
>D [09/Jan/2014:07:14:53 +0200] Report: printers=1
>D [09/Jan/2014:07:14:53 +0200] Report: stringpool-string-count=1575
>D [09/Jan/2014:07:14:53 +0200] Report: stringpool-alloc-bytes=8648
>D [09/Jan/2014:07:14:53 +0200] Report: stringpool-total-bytes=29736
>d [09/Jan/2014:07:14:53 +0200] select_timeout: JobHistoryUpdate=0
>d [09/Jan/2014:07:14:53 +0200] select_timeout(0): 1936 seconds to expire subscription
>d [09/Jan/2014:07:15:46 +0200] cupsdAcceptClient(lis=0x7f3c917eeae0(3)) Clients=0
>D [09/Jan/2014:07:15:46 +0200] cupsdAcceptClient: skipping getpeercon()
>D [09/Jan/2014:07:15:46 +0200] [Client 14] Accepted from localhost (Domain)
>d [09/Jan/2014:07:15:46 +0200] cupsdAddSelect(fd=14, read_cb=0x7f3c8f7ddbc0, write_cb=(nil), data=0x7f3c9185c320)
>D [09/Jan/2014:07:15:46 +0200] [Client 14] Waiting for request.
>d [09/Jan/2014:07:15:46 +0200] cupsdCheckJobs: 0 active jobs, sleeping=0, reload=0, curtime=1389244546
>d [09/Jan/2014:07:15:46 +0200] select_timeout: JobHistoryUpdate=0
>d [09/Jan/2014:07:15:46 +0200] cupsdAcceptClient(lis=0x7f3c917eeae0(3)) Clients=1
>D [09/Jan/2014:07:15:46 +0200] cupsdAcceptClient: skipping getpeercon()
>D [09/Jan/2014:07:15:46 +0200] [Client 15] Accepted from localhost (Domain)
>d [09/Jan/2014:07:15:46 +0200] cupsdAddSelect(fd=15, read_cb=0x7f3c8f7ddbc0, write_cb=(nil), data=0x7f3c918606e0)
>D [09/Jan/2014:07:15:46 +0200] [Client 15] Waiting for request.
>d [09/Jan/2014:07:15:46 +0200] [Client 14] cupsdReadClient error=0, used=0, state=HTTP_STATE_WAITING, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=0, request=(nil)(), file=-1
>D [09/Jan/2014:07:15:46 +0200] [Client 14] HTTP_STATE_WAITING Closing on EOF
>D [09/Jan/2014:07:15:46 +0200] [Client 14] Closing connection.
>D [09/Jan/2014:07:15:46 +0200] cupsdSetBusyState: newbusy="Not busy", busy="Not busy"
>d [09/Jan/2014:07:15:46 +0200] cupsdRemoveSelect(fd=14)
>d [09/Jan/2014:07:15:46 +0200] select_timeout: JobHistoryUpdate=0
>d [09/Jan/2014:07:15:46 +0200] [Client 15] cupsdReadClient error=0, used=0, state=HTTP_STATE_WAITING, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=0, request=(nil)(), file=-1
>D [09/Jan/2014:07:15:46 +0200] [Client 15] POST / HTTP/1.1
>D [09/Jan/2014:07:15:46 +0200] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
>d [09/Jan/2014:07:15:46 +0200] cupsdFindBest: uri = "/"...
>d [09/Jan/2014:07:15:46 +0200] cupsdFindBest: Location /admin/conf Limit 7f
>d [09/Jan/2014:07:15:46 +0200] cupsdFindBest: Location /admin Limit 7f
>d [09/Jan/2014:07:15:46 +0200] cupsdFindBest: Location / Limit 7f
>d [09/Jan/2014:07:15:46 +0200] cupsdFindBest: best = /
>d [09/Jan/2014:07:15:46 +0200] [Client 15] con->uri="/", con->best=0x7f3c917ea030(/)
>d [09/Jan/2014:07:15:46 +0200] [Client 15] Authorization=""
>D [09/Jan/2014:07:15:46 +0200] [Client 15] No authentication data provided.
>d [09/Jan/2014:07:15:46 +0200] cupsdIsAuthorized: con->uri="/", con->best=0x7f3c917ea030(/)
>d [09/Jan/2014:07:15:46 +0200] cupsdIsAuthorized: level=CUPSD_AUTH_ANON, type=None, satisfy=CUPSD_AUTH_SATISFY_ALL, num_names=0
>d [09/Jan/2014:07:15:46 +0200] cupsdIsAuthorized: auth=CUPSD_AUTH_ALLOW...
>D [09/Jan/2014:07:15:46 +0200] [Client 15] 1.1 CUPS-Get-Printers 1
>d [09/Jan/2014:07:15:46 +0200] cupsdProcessIPPRequest(0x7f3c918606e0[15]): operation_id = 4002
>D [09/Jan/2014:07:15:46 +0200] CUPS-Get-Printers
>d [09/Jan/2014:07:15:46 +0200] get_printers(0x7f3c918606e0[15], 0)
>d [09/Jan/2014:07:15:46 +0200] cupsdFindPolicyOp(p=0x7f3c917eef10, op=4002(CUPS-Get-Printers))
>d [09/Jan/2014:07:15:46 +0200] cupsdFindPolicyOp: Found wildcard match...
>d [09/Jan/2014:07:15:46 +0200] cupsdIsAuthorized: con->uri="/", con->best=0x7f3c917f3a30((null))
>d [09/Jan/2014:07:15:46 +0200] cupsdIsAuthorized: level=CUPSD_AUTH_ANON, type=None, satisfy=CUPSD_AUTH_SATISFY_ALL, num_names=0
>d [09/Jan/2014:07:15:46 +0200] cupsdIsAuthorized: op=0(0x0000)
>d [09/Jan/2014:07:15:46 +0200] cupsdIsAuthorized: auth=CUPSD_AUTH_ALLOW...
>d [09/Jan/2014:07:15:46 +0200] add_printer_state_reasons(0x7f3c918606e0[15], 0x7f3c917fc2f0[LaserJet-4L])
>d [09/Jan/2014:07:15:46 +0200] printer-uri-supported="ipp://localhost:631/printers/LaserJet-4L"
>d [09/Jan/2014:07:15:46 +0200] copy_attrs(to=0x7f3c91801df0, from=0x7f3c917ff700, ra=0x7f3c9185ab70, group=0, quickcopy=0)
>d [09/Jan/2014:07:15:46 +0200] copy_attrs(to=0x7f3c91801df0, from=0x7f3c918194c0, ra=0x7f3c9185ab70, group=0, quickcopy=0)
>d [09/Jan/2014:07:15:46 +0200] copy_attrs(to=0x7f3c91801df0, from=0x7f3c917fcd50, ra=0x7f3c9185ab70, group=0, quickcopy=-2147483648)
>D [09/Jan/2014:07:15:46 +0200] [Client 15] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost
>D [09/Jan/2014:07:15:46 +0200] [Client 15] Content-Length: 1132
>d [09/Jan/2014:07:15:46 +0200] cupsdAddSelect(fd=15, read_cb=0x7f3c8f7ddbc0, write_cb=0x7f3c8f7dd3c0, data=0x7f3c918606e0)
>d [09/Jan/2014:07:15:46 +0200] select_timeout: JobHistoryUpdate=0
>D [09/Jan/2014:07:15:46 +0200] [Client 15] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=1132, response=0x7f3c91801df0(IPP_IDLE), pipe_pid=0, file=-1
>D [09/Jan/2014:07:15:46 +0200] [Client 15] Writing IPP response, ipp_state=DATA, old wused=0, new wused=0
>D [09/Jan/2014:07:15:46 +0200] [Client 15] bytes=0, http_state=0, data_remaining=0
>d [09/Jan/2014:07:15:46 +0200] cupsdAddSelect(fd=15, read_cb=0x7f3c8f7ddbc0, write_cb=(nil), data=0x7f3c918606e0)
>D [09/Jan/2014:07:15:46 +0200] [Client 15] Waiting for request.
>D [09/Jan/2014:07:15:46 +0200] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
>d [09/Jan/2014:07:15:46 +0200] select_timeout: JobHistoryUpdate=0
>d [09/Jan/2014:07:15:46 +0200] [Client 15] cupsdReadClient error=0, used=0, state=HTTP_STATE_WAITING, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=0, request=(nil)(), file=-1
>D [09/Jan/2014:07:15:46 +0200] [Client 15] POST / HTTP/1.1
>D [09/Jan/2014:07:15:46 +0200] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
>d [09/Jan/2014:07:15:46 +0200] cupsdFindBest: uri = "/"...
>d [09/Jan/2014:07:15:46 +0200] cupsdFindBest: Location /admin/conf Limit 7f
>d [09/Jan/2014:07:15:46 +0200] cupsdFindBest: Location /admin Limit 7f
>d [09/Jan/2014:07:15:46 +0200] cupsdFindBest: Location / Limit 7f
>d [09/Jan/2014:07:15:46 +0200] cupsdFindBest: best = /
>d [09/Jan/2014:07:15:46 +0200] [Client 15] con->uri="/", con->best=0x7f3c917ea030(/)
>d [09/Jan/2014:07:15:46 +0200] [Client 15] Authorization=""
>D [09/Jan/2014:07:15:46 +0200] [Client 15] No authentication data provided.
>d [09/Jan/2014:07:15:46 +0200] cupsdIsAuthorized: con->uri="/", con->best=0x7f3c917ea030(/)
>d [09/Jan/2014:07:15:46 +0200] cupsdIsAuthorized: level=CUPSD_AUTH_ANON, type=None, satisfy=CUPSD_AUTH_SATISFY_ALL, num_names=0
>d [09/Jan/2014:07:15:46 +0200] cupsdIsAuthorized: auth=CUPSD_AUTH_ALLOW...
>D [09/Jan/2014:07:15:46 +0200] [Client 15] 1.1 CUPS-Get-Default 2
>d [09/Jan/2014:07:15:46 +0200] cupsdProcessIPPRequest(0x7f3c918606e0[15]): operation_id = 4001
>D [09/Jan/2014:07:15:46 +0200] CUPS-Get-Default
>d [09/Jan/2014:07:15:46 +0200] get_default(0x7f3c918606e0[15])
>d [09/Jan/2014:07:15:46 +0200] cupsdFindPolicyOp(p=0x7f3c917eef10, op=4001(CUPS-Get-Default))
>d [09/Jan/2014:07:15:46 +0200] cupsdFindPolicyOp: Found wildcard match...
>d [09/Jan/2014:07:15:46 +0200] cupsdIsAuthorized: con->uri="/", con->best=0x7f3c917f3a30((null))
>d [09/Jan/2014:07:15:46 +0200] cupsdIsAuthorized: level=CUPSD_AUTH_ANON, type=None, satisfy=CUPSD_AUTH_SATISFY_ALL, num_names=0
>d [09/Jan/2014:07:15:46 +0200] cupsdIsAuthorized: op=0(0x0000)
>d [09/Jan/2014:07:15:46 +0200] cupsdIsAuthorized: auth=CUPSD_AUTH_ALLOW...
>d [09/Jan/2014:07:15:46 +0200] printer-icons="http://localhost:631/icons/LaserJet-4L.png"
>d [09/Jan/2014:07:15:46 +0200] add_printer_state_reasons(0x7f3c918606e0[15], 0x7f3c917fc2f0[LaserJet-4L])
>d [09/Jan/2014:07:15:46 +0200] printer-uri-supported="ipp://localhost:631/printers/LaserJet-4L"
>d [09/Jan/2014:07:15:46 +0200] add_queued_job_count(0x7f3c918606e0[15], 0x7f3c917fc2f0[LaserJet-4L])
>d [09/Jan/2014:07:15:46 +0200] copy_attrs(to=0x7f3c918011f0, from=0x7f3c917ff700, ra=(nil), group=0, quickcopy=0)
>d [09/Jan/2014:07:15:46 +0200] copy_attrs(to=0x7f3c918011f0, from=0x7f3c918194c0, ra=(nil), group=0, quickcopy=0)
>d [09/Jan/2014:07:15:46 +0200] copy_attrs(to=0x7f3c918011f0, from=0x7f3c917fcd50, ra=(nil), group=0, quickcopy=-2147483648)
>D [09/Jan/2014:07:15:46 +0200] [Client 15] Returning IPP successful-ok for CUPS-Get-Default (no URI) from localhost
>D [09/Jan/2014:07:15:46 +0200] [Client 15] Content-Length: 7244
>d [09/Jan/2014:07:15:46 +0200] cupsdAddSelect(fd=15, read_cb=0x7f3c8f7ddbc0, write_cb=0x7f3c8f7dd3c0, data=0x7f3c918606e0)
>d [09/Jan/2014:07:15:46 +0200] select_timeout: JobHistoryUpdate=0
>D [09/Jan/2014:07:15:46 +0200] [Client 15] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=7244, response=0x7f3c918011f0(IPP_IDLE), pipe_pid=0, file=-1
>D [09/Jan/2014:07:15:46 +0200] [Client 15] Writing IPP response, ipp_state=DATA, old wused=0, new wused=0
>D [09/Jan/2014:07:15:46 +0200] [Client 15] bytes=0, http_state=0, data_remaining=0
>d [09/Jan/2014:07:15:46 +0200] cupsdAddSelect(fd=15, read_cb=0x7f3c8f7ddbc0, write_cb=(nil), data=0x7f3c918606e0)
>D [09/Jan/2014:07:15:46 +0200] [Client 15] Waiting for request.
>D [09/Jan/2014:07:15:46 +0200] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
>d [09/Jan/2014:07:15:46 +0200] select_timeout: JobHistoryUpdate=0
>d [09/Jan/2014:07:15:46 +0200] [Client 15] cupsdReadClient error=0, used=0, state=HTTP_STATE_WAITING, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=0, request=(nil)(), file=-1
>D [09/Jan/2014:07:15:46 +0200] [Client 15] HTTP_STATE_WAITING Closing on EOF
>D [09/Jan/2014:07:15:46 +0200] [Client 15] Closing connection.
>D [09/Jan/2014:07:15:46 +0200] cupsdSetBusyState: newbusy="Not busy", busy="Not busy"
>d [09/Jan/2014:07:15:46 +0200] cupsdRemoveSelect(fd=15)
>d [09/Jan/2014:07:15:46 +0200] select_timeout: JobHistoryUpdate=0
>d [09/Jan/2014:07:15:47 +0200] select_timeout: JobHistoryUpdate=0
>d [09/Jan/2014:07:15:47 +0200] select_timeout(0): 1882 seconds to expire subscription
>d [09/Jan/2014:07:15:54 +0200] cupsdAcceptClient(lis=0x7f3c917eeae0(3)) Clients=0
>D [09/Jan/2014:07:15:54 +0200] cupsdAcceptClient: skipping getpeercon()
>D [09/Jan/2014:07:15:54 +0200] [Client 14] Accepted from localhost (Domain)
>d [09/Jan/2014:07:15:54 +0200] cupsdAddSelect(fd=14, read_cb=0x7f3c8f7ddbc0, write_cb=(nil), data=0x7f3c9185c320)
>D [09/Jan/2014:07:15:54 +0200] [Client 14] Waiting for request.
>D [09/Jan/2014:07:15:54 +0200] Report: clients=1
>D [09/Jan/2014:07:15:54 +0200] Report: jobs=3
>D [09/Jan/2014:07:15:54 +0200] Report: jobs-active=0
>D [09/Jan/2014:07:15:54 +0200] Report: printers=1
>D [09/Jan/2014:07:15:54 +0200] Report: stringpool-string-count=1578
>D [09/Jan/2014:07:15:54 +0200] Report: stringpool-alloc-bytes=8672
>D [09/Jan/2014:07:15:54 +0200] Report: stringpool-total-bytes=29784
>d [09/Jan/2014:07:15:54 +0200] select_timeout: JobHistoryUpdate=0
>d [09/Jan/2014:07:15:54 +0200] cupsdAcceptClient(lis=0x7f3c917eeae0(3)) Clients=1
>D [09/Jan/2014:07:15:54 +0200] cupsdAcceptClient: skipping getpeercon()
>D [09/Jan/2014:07:15:54 +0200] [Client 15] Accepted from localhost (Domain)
>d [09/Jan/2014:07:15:54 +0200] cupsdAddSelect(fd=15, read_cb=0x7f3c8f7ddbc0, write_cb=(nil), data=0x7f3c918606e0)
>D [09/Jan/2014:07:15:54 +0200] [Client 15] Waiting for request.
>d [09/Jan/2014:07:15:54 +0200] [Client 14] cupsdReadClient error=0, used=0, state=HTTP_STATE_WAITING, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=0, request=(nil)(), file=-1
>D [09/Jan/2014:07:15:54 +0200] [Client 14] HTTP_STATE_WAITING Closing on EOF
>D [09/Jan/2014:07:15:54 +0200] [Client 14] Closing connection.
>D [09/Jan/2014:07:15:54 +0200] cupsdSetBusyState: newbusy="Not busy", busy="Not busy"
>d [09/Jan/2014:07:15:54 +0200] cupsdRemoveSelect(fd=14)
>d [09/Jan/2014:07:15:54 +0200] select_timeout: JobHistoryUpdate=0
>d [09/Jan/2014:07:15:54 +0200] [Client 15] cupsdReadClient error=0, used=0, state=HTTP_STATE_WAITING, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=0, request=(nil)(), file=-1
>D [09/Jan/2014:07:15:54 +0200] [Client 15] POST / HTTP/1.1
>D [09/Jan/2014:07:15:54 +0200] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
>d [09/Jan/2014:07:15:54 +0200] cupsdFindBest: uri = "/"...
>d [09/Jan/2014:07:15:54 +0200] cupsdFindBest: Location /admin/conf Limit 7f
>d [09/Jan/2014:07:15:54 +0200] cupsdFindBest: Location /admin Limit 7f
>d [09/Jan/2014:07:15:54 +0200] cupsdFindBest: Location / Limit 7f
>d [09/Jan/2014:07:15:54 +0200] cupsdFindBest: best = /
>d [09/Jan/2014:07:15:54 +0200] [Client 15] con->uri="/", con->best=0x7f3c917ea030(/)
>d [09/Jan/2014:07:15:54 +0200] [Client 15] Authorization=""
>D [09/Jan/2014:07:15:54 +0200] [Client 15] No authentication data provided.
>d [09/Jan/2014:07:15:54 +0200] cupsdIsAuthorized: con->uri="/", con->best=0x7f3c917ea030(/)
>d [09/Jan/2014:07:15:54 +0200] cupsdIsAuthorized: level=CUPSD_AUTH_ANON, type=None, satisfy=CUPSD_AUTH_SATISFY_ALL, num_names=0
>d [09/Jan/2014:07:15:54 +0200] cupsdIsAuthorized: auth=CUPSD_AUTH_ALLOW...
>D [09/Jan/2014:07:15:54 +0200] [Client 15] 1.1 CUPS-Get-Printers 3
>d [09/Jan/2014:07:15:54 +0200] cupsdProcessIPPRequest(0x7f3c918606e0[15]): operation_id = 4002
>D [09/Jan/2014:07:15:54 +0200] CUPS-Get-Printers
>d [09/Jan/2014:07:15:54 +0200] get_printers(0x7f3c918606e0[15], 0)
>d [09/Jan/2014:07:15:54 +0200] cupsdFindPolicyOp(p=0x7f3c917eef10, op=4002(CUPS-Get-Printers))
>d [09/Jan/2014:07:15:54 +0200] cupsdFindPolicyOp: Found wildcard match...
>d [09/Jan/2014:07:15:54 +0200] cupsdIsAuthorized: con->uri="/", con->best=0x7f3c917f3a30((null))
>d [09/Jan/2014:07:15:54 +0200] cupsdIsAuthorized: level=CUPSD_AUTH_ANON, type=None, satisfy=CUPSD_AUTH_SATISFY_ALL, num_names=0
>d [09/Jan/2014:07:15:54 +0200] cupsdIsAuthorized: op=0(0x0000)
>d [09/Jan/2014:07:15:54 +0200] cupsdIsAuthorized: auth=CUPSD_AUTH_ALLOW...
>d [09/Jan/2014:07:15:54 +0200] add_printer_state_reasons(0x7f3c918606e0[15], 0x7f3c917fc2f0[LaserJet-4L])
>d [09/Jan/2014:07:15:54 +0200] printer-uri-supported="ipp://localhost:631/printers/LaserJet-4L"
>d [09/Jan/2014:07:15:54 +0200] copy_attrs(to=0x7f3c91801df0, from=0x7f3c917ff700, ra=0x7f3c9185ab70, group=0, quickcopy=0)
>d [09/Jan/2014:07:15:54 +0200] copy_attrs(to=0x7f3c91801df0, from=0x7f3c918194c0, ra=0x7f3c9185ab70, group=0, quickcopy=0)
>d [09/Jan/2014:07:15:54 +0200] copy_attrs(to=0x7f3c91801df0, from=0x7f3c917fcd50, ra=0x7f3c9185ab70, group=0, quickcopy=-2147483648)
>D [09/Jan/2014:07:15:54 +0200] [Client 15] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost
>D [09/Jan/2014:07:15:54 +0200] [Client 15] Content-Length: 1132
>d [09/Jan/2014:07:15:54 +0200] cupsdAddSelect(fd=15, read_cb=0x7f3c8f7ddbc0, write_cb=0x7f3c8f7dd3c0, data=0x7f3c918606e0)
>d [09/Jan/2014:07:15:54 +0200] select_timeout: JobHistoryUpdate=0
>D [09/Jan/2014:07:15:54 +0200] [Client 15] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=1132, response=0x7f3c91801df0(IPP_IDLE), pipe_pid=0, file=-1
>D [09/Jan/2014:07:15:54 +0200] [Client 15] Writing IPP response, ipp_state=DATA, old wused=0, new wused=0
>D [09/Jan/2014:07:15:54 +0200] [Client 15] bytes=0, http_state=0, data_remaining=0
>d [09/Jan/2014:07:15:54 +0200] cupsdAddSelect(fd=15, read_cb=0x7f3c8f7ddbc0, write_cb=(nil), data=0x7f3c918606e0)
>D [09/Jan/2014:07:15:54 +0200] [Client 15] Waiting for request.
>D [09/Jan/2014:07:15:54 +0200] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
>d [09/Jan/2014:07:15:54 +0200] select_timeout: JobHistoryUpdate=0
>d [09/Jan/2014:07:15:54 +0200] [Client 15] cupsdReadClient error=0, used=0, state=HTTP_STATE_WAITING, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=0, request=(nil)(), file=-1
>D [09/Jan/2014:07:15:54 +0200] [Client 15] POST / HTTP/1.1
>D [09/Jan/2014:07:15:54 +0200] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
>d [09/Jan/2014:07:15:54 +0200] cupsdFindBest: uri = "/"...
>d [09/Jan/2014:07:15:54 +0200] cupsdFindBest: Location /admin/conf Limit 7f
>d [09/Jan/2014:07:15:54 +0200] cupsdFindBest: Location /admin Limit 7f
>d [09/Jan/2014:07:15:54 +0200] cupsdFindBest: Location / Limit 7f
>d [09/Jan/2014:07:15:54 +0200] cupsdFindBest: best = /
>d [09/Jan/2014:07:15:54 +0200] [Client 15] con->uri="/", con->best=0x7f3c917ea030(/)
>d [09/Jan/2014:07:15:54 +0200] [Client 15] Authorization=""
>D [09/Jan/2014:07:15:54 +0200] [Client 15] No authentication data provided.
>d [09/Jan/2014:07:15:54 +0200] cupsdIsAuthorized: con->uri="/", con->best=0x7f3c917ea030(/)
>d [09/Jan/2014:07:15:54 +0200] cupsdIsAuthorized: level=CUPSD_AUTH_ANON, type=None, satisfy=CUPSD_AUTH_SATISFY_ALL, num_names=0
>d [09/Jan/2014:07:15:54 +0200] cupsdIsAuthorized: auth=CUPSD_AUTH_ALLOW...
>D [09/Jan/2014:07:15:54 +0200] [Client 15] 1.1 CUPS-Get-Default 4
>d [09/Jan/2014:07:15:54 +0200] cupsdProcessIPPRequest(0x7f3c918606e0[15]): operation_id = 4001
>D [09/Jan/2014:07:15:54 +0200] CUPS-Get-Default
>d [09/Jan/2014:07:15:54 +0200] get_default(0x7f3c918606e0[15])
>d [09/Jan/2014:07:15:54 +0200] cupsdFindPolicyOp(p=0x7f3c917eef10, op=4001(CUPS-Get-Default))
>d [09/Jan/2014:07:15:54 +0200] cupsdFindPolicyOp: Found wildcard match...
>d [09/Jan/2014:07:15:54 +0200] cupsdIsAuthorized: con->uri="/", con->best=0x7f3c917f3a30((null))
>d [09/Jan/2014:07:15:54 +0200] cupsdIsAuthorized: level=CUPSD_AUTH_ANON, type=None, satisfy=CUPSD_AUTH_SATISFY_ALL, num_names=0
>d [09/Jan/2014:07:15:54 +0200] cupsdIsAuthorized: op=0(0x0000)
>d [09/Jan/2014:07:15:54 +0200] cupsdIsAuthorized: auth=CUPSD_AUTH_ALLOW...
>d [09/Jan/2014:07:15:54 +0200] printer-icons="http://localhost:631/icons/LaserJet-4L.png"
>d [09/Jan/2014:07:15:54 +0200] add_printer_state_reasons(0x7f3c918606e0[15], 0x7f3c917fc2f0[LaserJet-4L])
>d [09/Jan/2014:07:15:54 +0200] printer-uri-supported="ipp://localhost:631/printers/LaserJet-4L"
>d [09/Jan/2014:07:15:54 +0200] add_queued_job_count(0x7f3c918606e0[15], 0x7f3c917fc2f0[LaserJet-4L])
>d [09/Jan/2014:07:15:54 +0200] copy_attrs(to=0x7f3c918573d0, from=0x7f3c917ff700, ra=(nil), group=0, quickcopy=0)
>d [09/Jan/2014:07:15:54 +0200] copy_attrs(to=0x7f3c918573d0, from=0x7f3c918194c0, ra=(nil), group=0, quickcopy=0)
>d [09/Jan/2014:07:15:54 +0200] copy_attrs(to=0x7f3c918573d0, from=0x7f3c917fcd50, ra=(nil), group=0, quickcopy=-2147483648)
>D [09/Jan/2014:07:15:54 +0200] [Client 15] Returning IPP successful-ok for CUPS-Get-Default (no URI) from localhost
>D [09/Jan/2014:07:15:54 +0200] [Client 15] Content-Length: 7244
>d [09/Jan/2014:07:15:54 +0200] cupsdAddSelect(fd=15, read_cb=0x7f3c8f7ddbc0, write_cb=0x7f3c8f7dd3c0, data=0x7f3c918606e0)
>d [09/Jan/2014:07:15:54 +0200] select_timeout: JobHistoryUpdate=0
>D [09/Jan/2014:07:15:54 +0200] [Client 15] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=7244, response=0x7f3c918573d0(IPP_IDLE), pipe_pid=0, file=-1
>D [09/Jan/2014:07:15:54 +0200] [Client 15] Writing IPP response, ipp_state=DATA, old wused=0, new wused=0
>D [09/Jan/2014:07:15:54 +0200] [Client 15] bytes=0, http_state=0, data_remaining=0
>d [09/Jan/2014:07:15:54 +0200] cupsdAddSelect(fd=15, read_cb=0x7f3c8f7ddbc0, write_cb=(nil), data=0x7f3c918606e0)
>D [09/Jan/2014:07:15:54 +0200] [Client 15] Waiting for request.
>D [09/Jan/2014:07:15:54 +0200] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
>d [09/Jan/2014:07:15:54 +0200] select_timeout: JobHistoryUpdate=0
>d [09/Jan/2014:07:15:55 +0200] select_timeout: JobHistoryUpdate=0
>d [09/Jan/2014:07:15:55 +0200] select_timeout(0): 300 seconds to timeout a client connection
>d [09/Jan/2014:07:16:39 +0200] [Client 15] cupsdReadClient error=0, used=0, state=HTTP_STATE_WAITING, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=0, request=(nil)(), file=-1
>D [09/Jan/2014:07:16:39 +0200] [Client 15] POST /printers/LaserJet-4L HTTP/1.1
>D [09/Jan/2014:07:16:39 +0200] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
>d [09/Jan/2014:07:16:39 +0200] cupsdFindBest: uri = "/printers/LaserJet-4L"...
>d [09/Jan/2014:07:16:39 +0200] cupsdFindBest: Location /admin/conf Limit 7f
>d [09/Jan/2014:07:16:39 +0200] cupsdFindBest: Location /admin Limit 7f
>d [09/Jan/2014:07:16:39 +0200] cupsdFindBest: Location / Limit 7f
>d [09/Jan/2014:07:16:39 +0200] cupsdFindBest: best = /
>d [09/Jan/2014:07:16:39 +0200] [Client 15] con->uri="/printers/LaserJet-4L", con->best=0x7f3c917ea030(/)
>d [09/Jan/2014:07:16:39 +0200] [Client 15] Authorization=""
>D [09/Jan/2014:07:16:39 +0200] [Client 15] No authentication data provided.
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: con->uri="/printers/LaserJet-4L", con->best=0x7f3c917ea030(/)
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: level=CUPSD_AUTH_ANON, type=None, satisfy=CUPSD_AUTH_SATISFY_ALL, num_names=0
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: auth=CUPSD_AUTH_ALLOW...
>D [09/Jan/2014:07:16:39 +0200] [Client 15] 1.1 Create-Job 5
>d [09/Jan/2014:07:16:39 +0200] cupsdProcessIPPRequest(0x7f3c918606e0[15]): operation_id = 0005
>D [09/Jan/2014:07:16:39 +0200] Create-Job ipp://localhost:631/printers/LaserJet-4L
>d [09/Jan/2014:07:16:39 +0200] create_job(0x7f3c918606e0[15], ipp://localhost:631/printers/LaserJet-4L)
>d [09/Jan/2014:07:16:39 +0200] add_job(0x7f3c918606e0[15], 0x7f3c917fc2f0(LaserJet-4L), (nil)(none/none))
>d [09/Jan/2014:07:16:39 +0200] cupsdFindPolicyOp(p=0x7f3c917eef10, op=5(Create-Job))
>d [09/Jan/2014:07:16:39 +0200] cupsdFindPolicyOp: Found exact match...
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: con->uri="/printers/LaserJet-4L", con->best=0x7f3c917efb50((null))
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: level=CUPSD_AUTH_ANON, type=None, satisfy=CUPSD_AUTH_SATISFY_ALL, num_names=0
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: op=5(Create-Job)
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: auth=CUPSD_AUTH_ALLOW...
>d [09/Jan/2014:07:16:39 +0200] check_quotas(0x7f3c918606e0[15], 0x7f3c917fc2f0[LaserJet-4L])
>D [09/Jan/2014:07:16:39 +0200] add_job: setting context of job to UNKNOWN SL
>D [09/Jan/2014:07:16:39 +0200] cupsdMarkDirty(---J-)
>D [09/Jan/2014:07:16:39 +0200] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients"
>D [09/Jan/2014:07:16:39 +0200] add_job: requesting-user-name="fred"
>D [09/Jan/2014:07:16:39 +0200] Adding default job-sheets values "none,none"...
>I [09/Jan/2014:07:16:39 +0200] [Job 21] Adding start banner page "none".
>d [09/Jan/2014:07:16:39 +0200] copy_banner(con=0x7f3c918606e0[15], job=0x7f3c9185cc30[21], name="none")
>d [09/Jan/2014:07:16:39 +0200] cupsdAddEvent(event=job-created, dest=0x7f3c917fc2f0(LaserJet-4L), job=0x7f3c9185cc30(21), text="Job created.", ...)
>d [09/Jan/2014:07:16:39 +0200] cupsd_send_notification(sub=0x7f3c918027b0(52), event=0x7f3c9185a050(job-created))
>d [09/Jan/2014:07:16:39 +0200] cupsdAddSelect(fd=14, read_cb=0x7f3c8f8082e0, write_cb=(nil), data=(nil))
>d [09/Jan/2014:07:16:39 +0200] File "/usr/lib/cups/notifier/dbus" permissions OK (040755/uid=0/gid=0).
>d [09/Jan/2014:07:16:39 +0200] cupsdStartProcess(command="/usr/lib/cups/notifier/dbus", argv=0x7fff703fe770, envp=0x7fff703fe790, infd=17, outfd=-1, errfd=16, backfd=-1, sidefd=-1, root=0, profile=(nil), job=(nil)(0), pid=0x7fff703fe75c) = 14979
>D [09/Jan/2014:07:16:39 +0200] Notifier dbus started - PID = 14979
>d [09/Jan/2014:07:16:39 +0200] sub->pipe=18
>D [09/Jan/2014:07:16:39 +0200] cupsdMarkDirty(----S)
>D [09/Jan/2014:07:16:39 +0200] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
>I [09/Jan/2014:07:16:39 +0200] [Job 21] Queued on "LaserJet-4L" by "fred".
>D [09/Jan/2014:07:16:39 +0200] [Client 15] Returning IPP successful-ok for Create-Job (ipp://localhost:631/printers/LaserJet-4L) from localhost
>D [09/Jan/2014:07:16:39 +0200] [Client 15] Content-Length: 182
>d [09/Jan/2014:07:16:39 +0200] cupsdAddSelect(fd=15, read_cb=0x7f3c8f7ddbc0, write_cb=0x7f3c8f7dd3c0, data=0x7f3c918606e0)
>d [09/Jan/2014:07:16:39 +0200] cupsdCheckJobs: 1 active jobs, sleeping=0, reload=0, curtime=1389244599
>d [09/Jan/2014:07:16:39 +0200] cupsdCheckJobs: Job 21 - dest="LaserJet-4L", printer=(nil), state=4, cancel_time=0, hold_until=1389244899, kill_time=0, pending_cost=0, pending_timeout=1
>d [09/Jan/2014:07:16:39 +0200] select_timeout: JobHistoryUpdate=0
>D [09/Jan/2014:07:16:39 +0200] [Client 15] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=182, response=0x7f3c91801df0(IPP_IDLE), pipe_pid=0, file=-1
>D [09/Jan/2014:07:16:39 +0200] [Client 15] Writing IPP response, ipp_state=DATA, old wused=0, new wused=0
>D [09/Jan/2014:07:16:39 +0200] [Client 15] bytes=0, http_state=0, data_remaining=0
>d [09/Jan/2014:07:16:39 +0200] cupsdAddSelect(fd=15, read_cb=0x7f3c8f7ddbc0, write_cb=(nil), data=0x7f3c918606e0)
>D [09/Jan/2014:07:16:39 +0200] [Client 15] Waiting for request.
>D [09/Jan/2014:07:16:39 +0200] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
>d [09/Jan/2014:07:16:39 +0200] select_timeout: JobHistoryUpdate=0
>d [09/Jan/2014:07:16:39 +0200] [Client 15] cupsdReadClient error=0, used=0, state=HTTP_STATE_WAITING, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=0, request=(nil)(), file=-1
>D [09/Jan/2014:07:16:39 +0200] [Client 15] POST /printers/LaserJet-4L HTTP/1.1
>D [09/Jan/2014:07:16:39 +0200] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
>d [09/Jan/2014:07:16:39 +0200] cupsdFindBest: uri = "/printers/LaserJet-4L"...
>d [09/Jan/2014:07:16:39 +0200] cupsdFindBest: Location /admin/conf Limit 7f
>d [09/Jan/2014:07:16:39 +0200] cupsdFindBest: Location /admin Limit 7f
>d [09/Jan/2014:07:16:39 +0200] cupsdFindBest: Location / Limit 7f
>d [09/Jan/2014:07:16:39 +0200] cupsdFindBest: best = /
>d [09/Jan/2014:07:16:39 +0200] [Client 15] con->uri="/printers/LaserJet-4L", con->best=0x7f3c917ea030(/)
>d [09/Jan/2014:07:16:39 +0200] [Client 15] Authorization=""
>D [09/Jan/2014:07:16:39 +0200] [Client 15] No authentication data provided.
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: con->uri="/printers/LaserJet-4L", con->best=0x7f3c917ea030(/)
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: level=CUPSD_AUTH_ANON, type=None, satisfy=CUPSD_AUTH_SATISFY_ALL, num_names=0
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: auth=CUPSD_AUTH_ALLOW...
>D [09/Jan/2014:07:16:39 +0200] [Client 15] 1.1 Send-Document 6
>d [09/Jan/2014:07:16:39 +0200] select_timeout: JobHistoryUpdate=0
>d [09/Jan/2014:07:16:39 +0200] [Client 15] cupsdReadClient error=0, used=0, state=HTTP_STATE_POST_RECV, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=6150, request=0x7f3c91801df0(IPP_DATA), file=17
>d [09/Jan/2014:07:16:39 +0200] select_timeout: JobHistoryUpdate=0
>d [09/Jan/2014:07:16:39 +0200] [Client 15] cupsdReadClient error=0, used=0, state=HTTP_STATE_POST_RECV, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=4081, request=0x7f3c91801df0(IPP_DATA), file=17
>d [09/Jan/2014:07:16:39 +0200] cupsdProcessIPPRequest(0x7f3c918606e0[15]): operation_id = 0006
>D [09/Jan/2014:07:16:39 +0200] Send-Document ipp://localhost:631/printers/LaserJet-4L
>d [09/Jan/2014:07:16:39 +0200] send_document(0x7f3c918606e0[15], ipp://localhost:631/printers/LaserJet-4L)
>d [09/Jan/2014:07:16:39 +0200] validate_user(job=21, con=15, owner="fred", username=0x7fff703fff70, userlen=1024)
>d [09/Jan/2014:07:16:39 +0200] cupsdFindPolicyOp(p=0x7f3c917eef10, op=6(Send-Document))
>d [09/Jan/2014:07:16:39 +0200] cupsdFindPolicyOp: Found exact match...
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: con->uri="/printers/LaserJet-4L", con->best=0x7f3c917efd20((null))
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: owner="fred"
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: level=CUPSD_AUTH_USER, type=None, satisfy=CUPSD_AUTH_SATISFY_ALL, num_names=2
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: op=6(Send-Document)
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: auth=CUPSD_AUTH_ALLOW...
>D [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: requesting-user-name="fred"
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: Checking user membership...
>D [09/Jan/2014:07:16:39 +0200] [Job 21] Auto-typing file...
>D [09/Jan/2014:07:16:39 +0200] [Job 21] Request file type is application/pdf.
>d [09/Jan/2014:07:16:39 +0200] add_file(con=0x7f3c918606e0[15], job=21, filetype=application/pdf, compression=0)
>D [09/Jan/2014:07:16:39 +0200] cupsdMarkDirty(---J-)
>D [09/Jan/2014:07:16:39 +0200] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
>I [09/Jan/2014:07:16:39 +0200] [Job 21] File of type application/pdf queued by "fred".
>I [09/Jan/2014:07:16:39 +0200] [Job 21] Adding end banner page "none".
>d [09/Jan/2014:07:16:39 +0200] copy_banner(con=(nil)[-1], job=0x7f3c9185cc30[21], name="none")
>D [09/Jan/2014:07:16:39 +0200] cupsdMarkDirty(---J-)
>D [09/Jan/2014:07:16:39 +0200] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
>d [09/Jan/2014:07:16:39 +0200] cupsdCheckJobs: 1 active jobs, sleeping=0, reload=0, curtime=1389244599
>d [09/Jan/2014:07:16:39 +0200] cupsdCheckJobs: Job 21 - dest="LaserJet-4L", printer=(nil), state=3, cancel_time=0, hold_until=1389244899, kill_time=0, pending_cost=0, pending_timeout=0
>d [09/Jan/2014:07:16:39 +0200] start_job(job=0x7f3c9185cc30(21), printer=0x7f3c917fc2f0(LaserJet-4L))
>d [09/Jan/2014:07:16:39 +0200] cupsdSetJobState(job=0x7f3c9185cc30(21), state=3, newstate=5, action=0, message="(null)")
>D [09/Jan/2014:07:16:39 +0200] [Job 21] time-at-processing=1389244599
>D [09/Jan/2014:07:16:39 +0200] cupsdMarkDirty(---J-)
>D [09/Jan/2014:07:16:39 +0200] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
>D [09/Jan/2014:07:16:39 +0200] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
>d [09/Jan/2014:07:16:39 +0200] cupsdAddEvent(event=printer-state-changed, dest=0x7f3c917fc2f0(LaserJet-4L), job=(nil)(0), text="%s "%s" state changed to %s.", ...)
>d [09/Jan/2014:07:16:39 +0200] cupsd_send_notification(sub=0x7f3c918027b0(52), event=0x7f3c9185aa80(printer-state-changed))
>d [09/Jan/2014:07:16:39 +0200] sub->pipe=18
>D [09/Jan/2014:07:16:39 +0200] cupsdMarkDirty(----S)
>D [09/Jan/2014:07:16:39 +0200] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
>d [09/Jan/2014:07:16:39 +0200] cupsdSetPrinterReasons(p=0x7f3c917fc2f0(LaserJet-4L),s="-paused"
>d [09/Jan/2014:07:16:39 +0200] cupsdSetPrinterReasons(p=0x7f3c917fc2f0(LaserJet-4L),s="-cups-remote-pending,cups-remote-pending-held,cups-remote-processing,cups-remote-stopped,cups-remote-canceled,cups-remote-aborted,cups-remote-completed"
>d [09/Jan/2014:07:16:39 +0200] cupsdSetPrinterReasons(p=0x7f3c917fc2f0(LaserJet-4L),s="-cups-missing-filter-warning,cups-insecure-filter-warning"
>d [09/Jan/2014:07:16:39 +0200] cupsdCreateProfile(job_id=21) = NULL
>d [09/Jan/2014:07:16:39 +0200] cupsdContinueJob(job=0x7f3c9185cc30(21)): current_file=0, num_files=1
>D [09/Jan/2014:07:16:39 +0200] [Job 21] 2 filters for job:
>D [09/Jan/2014:07:16:39 +0200] [Job 21] pdftopdf (application/pdf to application/vnd.cups-pdf, cost 66)
>D [09/Jan/2014:07:16:39 +0200] [Job 21] foomatic-rip (application/vnd.cups-pdf to printer/LaserJet-4L, cost 0)
>D [09/Jan/2014:07:16:39 +0200] [Job 21] job-sheets=none,none
>D [09/Jan/2014:07:16:39 +0200] [Job 21] argv[0]="LaserJet-4L"
>D [09/Jan/2014:07:16:39 +0200] [Job 21] argv[1]="21"
>D [09/Jan/2014:07:16:39 +0200] [Job 21] argv[2]="fred"
>D [09/Jan/2014:07:16:39 +0200] [Job 21] argv[3]="bensiin"
>D [09/Jan/2014:07:16:39 +0200] [Job 21] argv[4]="1"
>D [09/Jan/2014:07:16:39 +0200] [Job 21] argv[5]="InputSlot=Default PageSize=A4 job-uuid=urn:uuid:36b042d3-d3f1-3d72-5487-889d809d9964 job-originating-host-name=localhost time-at-creation=1389244599 time-at-processing=1389244599"
>D [09/Jan/2014:07:16:39 +0200] [Job 21] argv[6]="/var/spool/cups/d00021-001"
>D [09/Jan/2014:07:16:39 +0200] [Job 21] envp[0]="CUPS_CACHEDIR=/var/cache/cups"
>D [09/Jan/2014:07:16:39 +0200] [Job 21] envp[1]="CUPS_DATADIR=/usr/share/cups"
>D [09/Jan/2014:07:16:39 +0200] [Job 21] envp[2]="CUPS_DOCROOT=/usr/share/cups/www"
>D [09/Jan/2014:07:16:39 +0200] [Job 21] envp[3]="CUPS_FONTPATH=/usr/share/cups/fonts"
>D [09/Jan/2014:07:16:39 +0200] [Job 21] envp[4]="CUPS_REQUESTROOT=/var/spool/cups"
>D [09/Jan/2014:07:16:39 +0200] [Job 21] envp[5]="CUPS_SERVERBIN=/usr/lib/cups"
>D [09/Jan/2014:07:16:39 +0200] [Job 21] envp[6]="CUPS_SERVERROOT=/etc/cups"
>D [09/Jan/2014:07:16:39 +0200] [Job 21] envp[7]="CUPS_STATEDIR=/var/run/cups"
>D [09/Jan/2014:07:16:39 +0200] [Job 21] envp[8]="HOME=/var/spool/cups/tmp"
>D [09/Jan/2014:07:16:39 +0200] [Job 21] envp[9]="PATH=/usr/lib/cups/filter:/usr/lib64/cups/filter:/usr/bin:/usr/sbin:/bin:/usr/bin"
>D [09/Jan/2014:07:16:39 +0200] [Job 21] envp[10]="SERVER_ADMIN=root@envy17.salumetsnew.ee"
>D [09/Jan/2014:07:16:39 +0200] [Job 21] envp[11]="SOFTWARE=CUPS/1.7.0"
>D [09/Jan/2014:07:16:39 +0200] [Job 21] envp[12]="TMPDIR=/var/spool/cups/tmp"
>D [09/Jan/2014:07:16:39 +0200] [Job 21] envp[13]="USER=root"
>D [09/Jan/2014:07:16:39 +0200] [Job 21] envp[14]="CUPS_MAX_MESSAGE=2047"
>D [09/Jan/2014:07:16:39 +0200] [Job 21] envp[15]="CUPS_SERVER=/var/run/cups/cups.sock"
>D [09/Jan/2014:07:16:39 +0200] [Job 21] envp[16]="CUPS_ENCRYPTION=IfRequested"
>D [09/Jan/2014:07:16:39 +0200] [Job 21] envp[17]="IPP_PORT=631"
>D [09/Jan/2014:07:16:39 +0200] [Job 21] envp[18]="CHARSET=utf-8"
>D [09/Jan/2014:07:16:39 +0200] [Job 21] envp[19]="LANG=en_US.UTF-8"
>D [09/Jan/2014:07:16:39 +0200] [Job 21] envp[20]="PPD=/etc/cups/ppd/LaserJet-4L.ppd"
>D [09/Jan/2014:07:16:39 +0200] [Job 21] envp[21]="RIP_MAX_CACHE=128m"
>D [09/Jan/2014:07:16:39 +0200] [Job 21] envp[22]="CONTENT_TYPE=application/pdf"
>D [09/Jan/2014:07:16:39 +0200] [Job 21] envp[23]="DEVICE_URI=usb://HP/LaserJet%204L"
>D [09/Jan/2014:07:16:39 +0200] [Job 21] envp[24]="PRINTER_INFO=Hewlett-Packard LaserJet 4L"
>D [09/Jan/2014:07:16:39 +0200] [Job 21] envp[25]="PRINTER_LOCATION=envy17.salumetsnew.ee"
>D [09/Jan/2014:07:16:39 +0200] [Job 21] envp[26]="PRINTER=LaserJet-4L"
>D [09/Jan/2014:07:16:39 +0200] [Job 21] envp[27]="PRINTER_STATE_REASONS=none"
>D [09/Jan/2014:07:16:39 +0200] [Job 21] envp[28]="CUPS_FILETYPE=document"
>D [09/Jan/2014:07:16:39 +0200] [Job 21] envp[29]="FINAL_CONTENT_TYPE=printer/LaserJet-4L"
>D [09/Jan/2014:07:16:39 +0200] [Job 21] envp[30]="AUTH_I****"
>d [09/Jan/2014:07:16:39 +0200] LaserJet-4L: File "/usr/lib/cups/filter/pdftopdf" permissions OK (040755/uid=0/gid=0).
>d [09/Jan/2014:07:16:39 +0200] cupsdStartProcess(command="/usr/lib/cups/filter/pdftopdf", argv=0x7f3c9185c6d0, envp=0x7fff703fc6d0, infd=-1, outfd=25, errfd=19, backfd=20, sidefd=22, root=0, profile=(nil), job=0x7f3c9185cc30(21), pid=0x7f3c9185cd24) = 14980
>I [09/Jan/2014:07:16:39 +0200] [Job 21] Started filter /usr/lib/cups/filter/pdftopdf (PID 14980)
>d [09/Jan/2014:07:16:39 +0200] LaserJet-4L: File "/usr/lib/cups/filter/foomatic-rip" permissions OK (040755/uid=0/gid=0).
>d [09/Jan/2014:07:16:39 +0200] cupsdStartProcess(command="/usr/lib/cups/filter/foomatic-rip", argv=0x7f3c9185c6d0, envp=0x7fff703fc6d0, infd=24, outfd=27, errfd=19, backfd=20, sidefd=22, root=0, profile=(nil), job=0x7f3c9185cc30(21), pid=0x7f3c9185cd28) = 14981
>I [09/Jan/2014:07:16:39 +0200] [Job 21] Started filter /usr/lib/cups/filter/foomatic-rip (PID 14981)
>d [09/Jan/2014:07:16:39 +0200] LaserJet-4L: File "/usr/lib/cups/backend/usb" permissions OK (040755/uid=0/gid=0).
>d [09/Jan/2014:07:16:39 +0200] cupsdStartProcess(command="/usr/lib/cups/backend/usb", argv=0x7f3c9185c6d0, envp=0x7fff703fc6d0, infd=26, outfd=-1, errfd=19, backfd=21, sidefd=23, root=0, profile=(nil), job=0x7f3c9185cc30(21), pid=0x7f3c9185cd78) = 14982
>I [09/Jan/2014:07:16:39 +0200] [Job 21] Started backend /usr/lib/cups/backend/usb (PID 14982)
>d [09/Jan/2014:07:16:39 +0200] cupsdAddSelect(fd=17, read_cb=0x7f3c8f7f9060, write_cb=(nil), data=0x7f3c9185cc30)
>d [09/Jan/2014:07:16:39 +0200] cupsdAddEvent(event=job-state-changed, dest=0x7f3c917fc2f0(LaserJet-4L), job=0x7f3c9185cc30(21), text="Job #%d started.", ...)
>d [09/Jan/2014:07:16:39 +0200] cupsd_send_notification(sub=0x7f3c918027b0(52), event=0x7f3c9185c6a0(job-state-changed))
>d [09/Jan/2014:07:16:39 +0200] sub->pipe=18
>D [09/Jan/2014:07:16:39 +0200] cupsdMarkDirty(----S)
>D [09/Jan/2014:07:16:39 +0200] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Active clients and dirty files"
>D [09/Jan/2014:07:16:39 +0200] [Client 15] Returning IPP successful-ok for Send-Document (ipp://localhost:631/printers/LaserJet-4L) from localhost
>D [09/Jan/2014:07:16:39 +0200] [Client 15] Content-Length: 174
>d [09/Jan/2014:07:16:39 +0200] cupsdAddSelect(fd=15, read_cb=0x7f3c8f7ddbc0, write_cb=0x7f3c8f7dd3c0, data=0x7f3c918606e0)
>d [09/Jan/2014:07:16:39 +0200] select_timeout: JobHistoryUpdate=0
>D [09/Jan/2014:07:16:39 +0200] [Client 15] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=174, response=0x7f3c9185c150(IPP_IDLE), pipe_pid=0, file=-1
>D [09/Jan/2014:07:16:39 +0200] [Client 15] Writing IPP response, ipp_state=DATA, old wused=0, new wused=0
>D [09/Jan/2014:07:16:39 +0200] [Client 15] bytes=0, http_state=0, data_remaining=0
>d [09/Jan/2014:07:16:39 +0200] cupsdAddSelect(fd=15, read_cb=0x7f3c8f7ddbc0, write_cb=(nil), data=0x7f3c918606e0)
>D [09/Jan/2014:07:16:39 +0200] [Client 15] Waiting for request.
>D [09/Jan/2014:07:16:39 +0200] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients, printing jobs, and dirty files"
>d [09/Jan/2014:07:16:39 +0200] select_timeout: JobHistoryUpdate=0
>D [09/Jan/2014:07:16:39 +0200] [Job 21] Loading USB quirks from "/usr/share/cups/usb".
>D [09/Jan/2014:07:16:39 +0200] [Job 21] Loaded 68 quirks.
>D [09/Jan/2014:07:16:39 +0200] [Job 21] Printing on printer with URI: usb://HP/LaserJet%204L
>d [09/Jan/2014:07:16:39 +0200] select_timeout: JobHistoryUpdate=0
>D [09/Jan/2014:07:16:39 +0200] [Job 21] libusb_get_device_list=11
>d [09/Jan/2014:07:16:39 +0200] select_timeout: JobHistoryUpdate=0
>D [09/Jan/2014:07:16:39 +0200] [Job 21] STATE: +connecting-to-device
>d [09/Jan/2014:07:16:39 +0200] cupsdSetPrinterReasons(p=0x7f3c917fc2f0(LaserJet-4L),s="+connecting-to-device"
>D [09/Jan/2014:07:16:39 +0200] cupsdMarkDirty(---J-)
>D [09/Jan/2014:07:16:39 +0200] cupsdSetBusyState: newbusy="Dirty files", busy="Printing jobs and dirty files"
>d [09/Jan/2014:07:16:39 +0200] cupsdAddEvent(event=printer-state-changed, dest=0x7f3c917fc2f0(LaserJet-4L), job=(nil)(0), text="Printer "%s" state changed.", ...)
>d [09/Jan/2014:07:16:39 +0200] cupsd_send_notification(sub=0x7f3c918027b0(52), event=0x7f3c9185af50(printer-state-changed))
>d [09/Jan/2014:07:16:39 +0200] sub->pipe=18
>D [09/Jan/2014:07:16:39 +0200] cupsdMarkDirty(----S)
>D [09/Jan/2014:07:16:39 +0200] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
>d [09/Jan/2014:07:16:39 +0200] select_timeout: JobHistoryUpdate=0
>D [09/Jan/2014:07:16:39 +0200] [Job 21] STATE: -connecting-to-device
>d [09/Jan/2014:07:16:39 +0200] cupsdSetPrinterReasons(p=0x7f3c917fc2f0(LaserJet-4L),s="-connecting-to-device"
>D [09/Jan/2014:07:16:39 +0200] cupsdMarkDirty(---J-)
>D [09/Jan/2014:07:16:39 +0200] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Dirty files"
>d [09/Jan/2014:07:16:39 +0200] cupsdAddEvent(event=printer-state-changed, dest=0x7f3c917fc2f0(LaserJet-4L), job=(nil)(0), text="Printer "%s" state changed.", ...)
>d [09/Jan/2014:07:16:39 +0200] cupsd_send_notification(sub=0x7f3c918027b0(52), event=0x7f3c9185b040(printer-state-changed))
>d [09/Jan/2014:07:16:39 +0200] sub->pipe=18
>D [09/Jan/2014:07:16:39 +0200] cupsdMarkDirty(----S)
>D [09/Jan/2014:07:16:39 +0200] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
>d [09/Jan/2014:07:16:39 +0200] select_timeout: JobHistoryUpdate=0
>d [09/Jan/2014:07:16:39 +0200] [Job 21] Printer found with device ID: MANUFACTURER:Hewlett-Packard;COMMAND SET:HP ENHANCED PCL5,PJL;MODEL:LaserJet 4L; Device URI: usb://HP/LaserJet%204L
>D [09/Jan/2014:07:16:39 +0200] [Job 21] Device protocol: 2
>D [09/Jan/2014:07:16:39 +0200] [Job 21] Printer reports bi-di support but in reality works only uni-directionally
>D [09/Jan/2014:07:16:39 +0200] [Job 21] Uni-directional USB communication only!
>D [09/Jan/2014:07:16:39 +0200] [Job 21] Printer does not like usblp kernel module to be re-attached after job
>d [09/Jan/2014:07:16:39 +0200] select_timeout: JobHistoryUpdate=0
>D [09/Jan/2014:07:16:39 +0200] [Job 21] Uni-directional device/mode, back channel deactivated.
>d [09/Jan/2014:07:16:39 +0200] select_timeout: JobHistoryUpdate=0
>I [09/Jan/2014:07:16:39 +0200] [Job 21] Sending data to printer.
>D [09/Jan/2014:07:16:39 +0200] cupsdMarkDirty(---J-)
>D [09/Jan/2014:07:16:39 +0200] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
>D [09/Jan/2014:07:16:39 +0200] [Job 21] Set job-printer-state-message to "Sending data to printer.", current level=INFO
>d [09/Jan/2014:07:16:39 +0200] cupsdAddEvent(event=job-progress, dest=0x7f3c917fc2f0(LaserJet-4L), job=0x7f3c9185cc30(21), text="%s", ...)
>D [09/Jan/2014:07:16:39 +0200] Discarding unused job-progress event...
>d [09/Jan/2014:07:16:39 +0200] cupsdAddEvent(event=printer-state-changed, dest=0x7f3c917fc2f0(LaserJet-4L), job=(nil)(0), text="Printer "%s" state changed.", ...)
>d [09/Jan/2014:07:16:39 +0200] cupsd_send_notification(sub=0x7f3c918027b0(52), event=0x7f3c9185ad70(printer-state-changed))
>d [09/Jan/2014:07:16:39 +0200] sub->pipe=18
>D [09/Jan/2014:07:16:39 +0200] cupsdMarkDirty(----S)
>D [09/Jan/2014:07:16:39 +0200] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
>d [09/Jan/2014:07:16:39 +0200] select_timeout: JobHistoryUpdate=0
>D [09/Jan/2014:07:16:39 +0200] [Notifier] state=3
>d [09/Jan/2014:07:16:39 +0200] select_timeout: JobHistoryUpdate=0
>D [09/Jan/2014:07:16:39 +0200] [Notifier] Connected to D-BUS
>d [09/Jan/2014:07:16:39 +0200] select_timeout: JobHistoryUpdate=0
>D [09/Jan/2014:07:16:39 +0200] [Notifier] JobCreated
>d [09/Jan/2014:07:16:39 +0200] select_timeout: JobHistoryUpdate=0
>D [09/Jan/2014:07:16:39 +0200] [Notifier] state=3
>D [09/Jan/2014:07:16:39 +0200] [Notifier] PrinterStateChanged
>d [09/Jan/2014:07:16:39 +0200] select_timeout: JobHistoryUpdate=0
>D [09/Jan/2014:07:16:39 +0200] [Notifier] state=3
>D [09/Jan/2014:07:16:39 +0200] [Notifier] JobState
>d [09/Jan/2014:07:16:39 +0200] select_timeout: JobHistoryUpdate=0
>D [09/Jan/2014:07:16:39 +0200] [Notifier] state=3
>D [09/Jan/2014:07:16:39 +0200] [Notifier] PrinterStateChanged
>d [09/Jan/2014:07:16:39 +0200] select_timeout: JobHistoryUpdate=0
>D [09/Jan/2014:07:16:39 +0200] [Notifier] state=3
>D [09/Jan/2014:07:16:39 +0200] [Notifier] PrinterStateChanged
>d [09/Jan/2014:07:16:39 +0200] select_timeout: JobHistoryUpdate=0
>D [09/Jan/2014:07:16:39 +0200] [Notifier] state=3
>D [09/Jan/2014:07:16:39 +0200] [Notifier] PrinterStateChanged
>d [09/Jan/2014:07:16:39 +0200] select_timeout: JobHistoryUpdate=0
>d [09/Jan/2014:07:16:39 +0200] cupsdAcceptClient(lis=0x7f3c917eeae0(3)) Clients=1
>D [09/Jan/2014:07:16:39 +0200] cupsdAcceptClient: skipping getpeercon()
>D [09/Jan/2014:07:16:39 +0200] [Client 19] Accepted from localhost (Domain)
>d [09/Jan/2014:07:16:39 +0200] cupsdAddSelect(fd=19, read_cb=0x7f3c8f7ddbc0, write_cb=(nil), data=0x7f3c91864aa0)
>D [09/Jan/2014:07:16:39 +0200] [Client 19] Waiting for request.
>d [09/Jan/2014:07:16:39 +0200] select_timeout: JobHistoryUpdate=0
>d [09/Jan/2014:07:16:39 +0200] [Client 19] cupsdReadClient error=0, used=0, state=HTTP_STATE_WAITING, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=0, request=(nil)(), file=-1
>D [09/Jan/2014:07:16:39 +0200] [Client 19] POST / HTTP/1.1
>D [09/Jan/2014:07:16:39 +0200] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Printing jobs and dirty files"
>d [09/Jan/2014:07:16:39 +0200] cupsdFindBest: uri = "/"...
>d [09/Jan/2014:07:16:39 +0200] cupsdFindBest: Location /admin/conf Limit 7f
>d [09/Jan/2014:07:16:39 +0200] cupsdFindBest: Location /admin Limit 7f
>d [09/Jan/2014:07:16:39 +0200] cupsdFindBest: Location / Limit 7f
>d [09/Jan/2014:07:16:39 +0200] cupsdFindBest: best = /
>d [09/Jan/2014:07:16:39 +0200] [Client 19] con->uri="/", con->best=0x7f3c917ea030(/)
>d [09/Jan/2014:07:16:39 +0200] [Client 19] Authorization=""
>D [09/Jan/2014:07:16:39 +0200] [Client 19] No authentication data provided.
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: con->uri="/", con->best=0x7f3c917ea030(/)
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: level=CUPSD_AUTH_ANON, type=None, satisfy=CUPSD_AUTH_SATISFY_ALL, num_names=0
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: auth=CUPSD_AUTH_ALLOW...
>D [09/Jan/2014:07:16:39 +0200] [Client 19] 1.1 Get-Notifications 4
>d [09/Jan/2014:07:16:39 +0200] cupsdProcessIPPRequest(0x7f3c91864aa0[19]): operation_id = 001c
>D [09/Jan/2014:07:16:39 +0200] Get-Notifications /printers/
>d [09/Jan/2014:07:16:39 +0200] get_notifications(con=0x7f3c91864aa0[19])
>d [09/Jan/2014:07:16:39 +0200] cupsdFindPolicyOp(p=0x7f3c917eef10, op=1c(Get-Notifications))
>d [09/Jan/2014:07:16:39 +0200] cupsdFindPolicyOp: Found exact match...
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: con->uri="/", con->best=0x7f3c917f0ab0((null))
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: owner="fred"
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: level=CUPSD_AUTH_USER, type=None, satisfy=CUPSD_AUTH_SATISFY_ALL, num_names=2
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: op=1c(Get-Notifications)
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: auth=CUPSD_AUTH_ALLOW...
>D [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: requesting-user-name="fred"
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: Checking user membership...
>d [09/Jan/2014:07:16:39 +0200] copy_attrs(to=0x7f3c9185ecc0, from=0x7f3c9185c060, ra=(nil), group=7, quickcopy=0)
>d [09/Jan/2014:07:16:39 +0200] copy_attrs(to=0x7f3c9185ecc0, from=0x7f3c9185d300, ra=(nil), group=7, quickcopy=0)
>d [09/Jan/2014:07:16:39 +0200] copy_attrs(to=0x7f3c9185ecc0, from=0x7f3c9185c6d0, ra=(nil), group=7, quickcopy=0)
>d [09/Jan/2014:07:16:39 +0200] copy_attrs(to=0x7f3c9185ecc0, from=0x7f3c9185c150, ra=(nil), group=7, quickcopy=0)
>d [09/Jan/2014:07:16:39 +0200] copy_attrs(to=0x7f3c9185ecc0, from=0x7f3c9185bf50, ra=(nil), group=7, quickcopy=0)
>d [09/Jan/2014:07:16:39 +0200] copy_attrs(to=0x7f3c9185ecc0, from=0x7f3c9185d4c0, ra=(nil), group=7, quickcopy=0)
>D [09/Jan/2014:07:16:39 +0200] [Client 19] Returning IPP successful-ok for Get-Notifications (/printers/) from localhost
>D [09/Jan/2014:07:16:39 +0200] [Client 19] Content-Length: 2929
>d [09/Jan/2014:07:16:39 +0200] cupsdAddSelect(fd=19, read_cb=0x7f3c8f7ddbc0, write_cb=0x7f3c8f7dd3c0, data=0x7f3c91864aa0)
>d [09/Jan/2014:07:16:39 +0200] select_timeout: JobHistoryUpdate=0
>D [09/Jan/2014:07:16:39 +0200] [Client 19] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=2929, response=0x7f3c9185ecc0(IPP_IDLE), pipe_pid=0, file=-1
>D [09/Jan/2014:07:16:39 +0200] [Client 19] Writing IPP response, ipp_state=DATA, old wused=0, new wused=0
>D [09/Jan/2014:07:16:39 +0200] [Client 19] bytes=0, http_state=0, data_remaining=0
>d [09/Jan/2014:07:16:39 +0200] cupsdAddSelect(fd=19, read_cb=0x7f3c8f7ddbc0, write_cb=(nil), data=0x7f3c91864aa0)
>D [09/Jan/2014:07:16:39 +0200] [Client 19] Waiting for request.
>D [09/Jan/2014:07:16:39 +0200] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients, printing jobs, and dirty files"
>d [09/Jan/2014:07:16:39 +0200] select_timeout: JobHistoryUpdate=0
>d [09/Jan/2014:07:16:39 +0200] cupsdAcceptClient(lis=0x7f3c917eeae0(3)) Clients=2
>D [09/Jan/2014:07:16:39 +0200] cupsdAcceptClient: skipping getpeercon()
>D [09/Jan/2014:07:16:39 +0200] [Client 20] Accepted from localhost (Domain)
>d [09/Jan/2014:07:16:39 +0200] cupsdAddSelect(fd=20, read_cb=0x7f3c8f7ddbc0, write_cb=(nil), data=0x7f3c9186e2d0)
>D [09/Jan/2014:07:16:39 +0200] [Client 20] Waiting for request.
>d [09/Jan/2014:07:16:39 +0200] select_timeout: JobHistoryUpdate=0
>d [09/Jan/2014:07:16:39 +0200] [Client 20] cupsdReadClient error=0, used=0, state=HTTP_STATE_WAITING, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=0, request=(nil)(), file=-1
>D [09/Jan/2014:07:16:39 +0200] [Client 20] POST / HTTP/1.1
>D [09/Jan/2014:07:16:39 +0200] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Printing jobs and dirty files"
>d [09/Jan/2014:07:16:39 +0200] cupsdFindBest: uri = "/"...
>d [09/Jan/2014:07:16:39 +0200] cupsdFindBest: Location /admin/conf Limit 7f
>d [09/Jan/2014:07:16:39 +0200] cupsdFindBest: Location /admin Limit 7f
>d [09/Jan/2014:07:16:39 +0200] cupsdFindBest: Location / Limit 7f
>d [09/Jan/2014:07:16:39 +0200] cupsdFindBest: best = /
>d [09/Jan/2014:07:16:39 +0200] [Client 20] con->uri="/", con->best=0x7f3c917ea030(/)
>d [09/Jan/2014:07:16:39 +0200] [Client 20] Authorization=""
>D [09/Jan/2014:07:16:39 +0200] [Client 20] No authentication data provided.
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: con->uri="/", con->best=0x7f3c917ea030(/)
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: level=CUPSD_AUTH_ANON, type=None, satisfy=CUPSD_AUTH_SATISFY_ALL, num_names=0
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: auth=CUPSD_AUTH_ALLOW...
>D [09/Jan/2014:07:16:39 +0200] [Client 20] 1.1 Get-Job-Attributes 5
>d [09/Jan/2014:07:16:39 +0200] cupsdProcessIPPRequest(0x7f3c9186e2d0[20]): operation_id = 0009
>D [09/Jan/2014:07:16:39 +0200] Get-Job-Attributes ipp://localhost/jobs/21
>d [09/Jan/2014:07:16:39 +0200] get_job_attrs(0x7f3c9186e2d0[20], ipp://localhost/jobs/21)
>d [09/Jan/2014:07:16:39 +0200] cupsdFindPolicyOp(p=0x7f3c917eef10, op=9(Get-Job-Attributes))
>d [09/Jan/2014:07:16:39 +0200] cupsdFindPolicyOp: Found wildcard match...
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: con->uri="/", con->best=0x7f3c917f3a30((null))
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: owner="fred"
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: level=CUPSD_AUTH_ANON, type=None, satisfy=CUPSD_AUTH_SATISFY_ALL, num_names=0
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: op=0(0x0000)
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: auth=CUPSD_AUTH_ALLOW...
>d [09/Jan/2014:07:16:39 +0200] copy_attrs(to=0x7f3c9185ec70, from=0x7f3c918573d0, ra=0x7f3c9185ed40, group=2, quickcopy=0)
>D [09/Jan/2014:07:16:39 +0200] [Client 20] Returning IPP successful-ok for Get-Job-Attributes (ipp://localhost/jobs/21) from localhost
>D [09/Jan/2014:07:16:39 +0200] [Client 20] Content-Length: 110
>d [09/Jan/2014:07:16:39 +0200] cupsdAddSelect(fd=20, read_cb=0x7f3c8f7ddbc0, write_cb=0x7f3c8f7dd3c0, data=0x7f3c9186e2d0)
>d [09/Jan/2014:07:16:39 +0200] select_timeout: JobHistoryUpdate=0
>D [09/Jan/2014:07:16:39 +0200] [Client 20] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=110, response=0x7f3c9185ec70(IPP_IDLE), pipe_pid=0, file=-1
>D [09/Jan/2014:07:16:39 +0200] [Client 20] Writing IPP response, ipp_state=DATA, old wused=0, new wused=0
>D [09/Jan/2014:07:16:39 +0200] [Client 20] bytes=0, http_state=0, data_remaining=0
>d [09/Jan/2014:07:16:39 +0200] cupsdAddSelect(fd=20, read_cb=0x7f3c8f7ddbc0, write_cb=(nil), data=0x7f3c9186e2d0)
>D [09/Jan/2014:07:16:39 +0200] [Client 20] Waiting for request.
>D [09/Jan/2014:07:16:39 +0200] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients, printing jobs, and dirty files"
>d [09/Jan/2014:07:16:39 +0200] select_timeout: JobHistoryUpdate=0
>d [09/Jan/2014:07:16:39 +0200] cupsdAcceptClient(lis=0x7f3c917eeae0(3)) Clients=3
>D [09/Jan/2014:07:16:39 +0200] cupsdAcceptClient: skipping getpeercon()
>D [09/Jan/2014:07:16:39 +0200] [Client 21] Accepted from localhost (Domain)
>d [09/Jan/2014:07:16:39 +0200] cupsdAddSelect(fd=21, read_cb=0x7f3c8f7ddbc0, write_cb=(nil), data=0x7f3c91872690)
>D [09/Jan/2014:07:16:39 +0200] [Client 21] Waiting for request.
>d [09/Jan/2014:07:16:39 +0200] select_timeout: JobHistoryUpdate=0
>d [09/Jan/2014:07:16:39 +0200] [Client 21] cupsdReadClient error=0, used=0, state=HTTP_STATE_WAITING, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=0, request=(nil)(), file=-1
>D [09/Jan/2014:07:16:39 +0200] [Client 21] POST / HTTP/1.1
>D [09/Jan/2014:07:16:39 +0200] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Printing jobs and dirty files"
>d [09/Jan/2014:07:16:39 +0200] cupsdFindBest: uri = "/"...
>d [09/Jan/2014:07:16:39 +0200] cupsdFindBest: Location /admin/conf Limit 7f
>d [09/Jan/2014:07:16:39 +0200] cupsdFindBest: Location /admin Limit 7f
>d [09/Jan/2014:07:16:39 +0200] cupsdFindBest: Location / Limit 7f
>d [09/Jan/2014:07:16:39 +0200] cupsdFindBest: best = /
>d [09/Jan/2014:07:16:39 +0200] [Client 21] con->uri="/", con->best=0x7f3c917ea030(/)
>d [09/Jan/2014:07:16:39 +0200] [Client 21] Authorization=""
>D [09/Jan/2014:07:16:39 +0200] [Client 21] No authentication data provided.
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: con->uri="/", con->best=0x7f3c917ea030(/)
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: level=CUPSD_AUTH_ANON, type=None, satisfy=CUPSD_AUTH_SATISFY_ALL, num_names=0
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: auth=CUPSD_AUTH_ALLOW...
>D [09/Jan/2014:07:16:39 +0200] [Client 21] 1.1 Get-Job-Attributes 6
>d [09/Jan/2014:07:16:39 +0200] cupsdProcessIPPRequest(0x7f3c91872690[21]): operation_id = 0009
>D [09/Jan/2014:07:16:39 +0200] Get-Job-Attributes ipp://localhost/jobs/21
>d [09/Jan/2014:07:16:39 +0200] get_job_attrs(0x7f3c91872690[21], ipp://localhost/jobs/21)
>d [09/Jan/2014:07:16:39 +0200] cupsdFindPolicyOp(p=0x7f3c917eef10, op=9(Get-Job-Attributes))
>d [09/Jan/2014:07:16:39 +0200] cupsdFindPolicyOp: Found wildcard match...
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: con->uri="/", con->best=0x7f3c917f3a30((null))
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: owner="fred"
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: level=CUPSD_AUTH_ANON, type=None, satisfy=CUPSD_AUTH_SATISFY_ALL, num_names=0
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: op=0(0x0000)
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: auth=CUPSD_AUTH_ALLOW...
>d [09/Jan/2014:07:16:39 +0200] copy_attrs(to=0x7f3c9185eca0, from=0x7f3c918573d0, ra=0x7f3c9185ed70, group=2, quickcopy=0)
>D [09/Jan/2014:07:16:39 +0200] [Client 21] Returning IPP successful-ok for Get-Job-Attributes (ipp://localhost/jobs/21) from localhost
>D [09/Jan/2014:07:16:39 +0200] [Client 21] Content-Length: 110
>d [09/Jan/2014:07:16:39 +0200] cupsdAddSelect(fd=21, read_cb=0x7f3c8f7ddbc0, write_cb=0x7f3c8f7dd3c0, data=0x7f3c91872690)
>d [09/Jan/2014:07:16:39 +0200] select_timeout: JobHistoryUpdate=0
>D [09/Jan/2014:07:16:39 +0200] [Client 21] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=110, response=0x7f3c9185eca0(IPP_IDLE), pipe_pid=0, file=-1
>D [09/Jan/2014:07:16:39 +0200] [Client 21] Writing IPP response, ipp_state=DATA, old wused=0, new wused=0
>D [09/Jan/2014:07:16:39 +0200] [Client 21] bytes=0, http_state=0, data_remaining=0
>d [09/Jan/2014:07:16:39 +0200] cupsdAddSelect(fd=21, read_cb=0x7f3c8f7ddbc0, write_cb=(nil), data=0x7f3c91872690)
>D [09/Jan/2014:07:16:39 +0200] [Client 21] Waiting for request.
>D [09/Jan/2014:07:16:39 +0200] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients, printing jobs, and dirty files"
>d [09/Jan/2014:07:16:39 +0200] select_timeout: JobHistoryUpdate=0
>d [09/Jan/2014:07:16:39 +0200] [Client 19] cupsdReadClient error=0, used=0, state=HTTP_STATE_WAITING, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=0, request=(nil)(), file=-1
>D [09/Jan/2014:07:16:39 +0200] [Client 19] POST / HTTP/1.1
>D [09/Jan/2014:07:16:39 +0200] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Printing jobs and dirty files"
>d [09/Jan/2014:07:16:39 +0200] cupsdFindBest: uri = "/"...
>d [09/Jan/2014:07:16:39 +0200] cupsdFindBest: Location /admin/conf Limit 7f
>d [09/Jan/2014:07:16:39 +0200] cupsdFindBest: Location /admin Limit 7f
>d [09/Jan/2014:07:16:39 +0200] cupsdFindBest: Location / Limit 7f
>d [09/Jan/2014:07:16:39 +0200] cupsdFindBest: best = /
>d [09/Jan/2014:07:16:39 +0200] [Client 19] con->uri="/", con->best=0x7f3c917ea030(/)
>d [09/Jan/2014:07:16:39 +0200] [Client 19] Authorization=""
>D [09/Jan/2014:07:16:39 +0200] [Client 19] No authentication data provided.
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: con->uri="/", con->best=0x7f3c917ea030(/)
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: level=CUPSD_AUTH_ANON, type=None, satisfy=CUPSD_AUTH_SATISFY_ALL, num_names=0
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: auth=CUPSD_AUTH_ALLOW...
>D [09/Jan/2014:07:16:39 +0200] [Client 19] 1.1 CUPS-Get-Printers 7
>d [09/Jan/2014:07:16:39 +0200] cupsdProcessIPPRequest(0x7f3c91864aa0[19]): operation_id = 4002
>D [09/Jan/2014:07:16:39 +0200] CUPS-Get-Printers
>d [09/Jan/2014:07:16:39 +0200] get_printers(0x7f3c91864aa0[19], 0)
>d [09/Jan/2014:07:16:39 +0200] cupsdFindPolicyOp(p=0x7f3c917eef10, op=4002(CUPS-Get-Printers))
>d [09/Jan/2014:07:16:39 +0200] cupsdFindPolicyOp: Found wildcard match...
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: con->uri="/", con->best=0x7f3c917f3a30((null))
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: level=CUPSD_AUTH_ANON, type=None, satisfy=CUPSD_AUTH_SATISFY_ALL, num_names=0
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: op=0(0x0000)
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: auth=CUPSD_AUTH_ALLOW...
>d [09/Jan/2014:07:16:39 +0200] add_printer_state_reasons(0x7f3c91864aa0[19], 0x7f3c917fc2f0[LaserJet-4L])
>d [09/Jan/2014:07:16:39 +0200] printer-uri-supported="ipp://localhost:631/printers/LaserJet-4L"
>d [09/Jan/2014:07:16:39 +0200] copy_attrs(to=0x7f3c9185eab0, from=0x7f3c917ff700, ra=0x7f3c9185f150, group=0, quickcopy=0)
>d [09/Jan/2014:07:16:39 +0200] copy_attrs(to=0x7f3c9185eab0, from=0x7f3c918194c0, ra=0x7f3c9185f150, group=0, quickcopy=0)
>d [09/Jan/2014:07:16:39 +0200] copy_attrs(to=0x7f3c9185eab0, from=0x7f3c917fcd50, ra=0x7f3c9185f150, group=0, quickcopy=-2147483648)
>D [09/Jan/2014:07:16:39 +0200] [Client 19] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost
>D [09/Jan/2014:07:16:39 +0200] [Client 19] Content-Length: 1132
>d [09/Jan/2014:07:16:39 +0200] cupsdAddSelect(fd=19, read_cb=0x7f3c8f7ddbc0, write_cb=0x7f3c8f7dd3c0, data=0x7f3c91864aa0)
>d [09/Jan/2014:07:16:39 +0200] select_timeout: JobHistoryUpdate=0
>D [09/Jan/2014:07:16:39 +0200] [Client 19] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=1132, response=0x7f3c9185eab0(IPP_IDLE), pipe_pid=0, file=-1
>D [09/Jan/2014:07:16:39 +0200] [Client 19] Writing IPP response, ipp_state=DATA, old wused=0, new wused=0
>D [09/Jan/2014:07:16:39 +0200] [Client 19] bytes=0, http_state=0, data_remaining=0
>d [09/Jan/2014:07:16:39 +0200] cupsdAddSelect(fd=19, read_cb=0x7f3c8f7ddbc0, write_cb=(nil), data=0x7f3c91864aa0)
>D [09/Jan/2014:07:16:39 +0200] [Client 19] Waiting for request.
>D [09/Jan/2014:07:16:39 +0200] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients, printing jobs, and dirty files"
>d [09/Jan/2014:07:16:39 +0200] select_timeout: JobHistoryUpdate=0
>d [09/Jan/2014:07:16:39 +0200] [Client 19] cupsdReadClient error=0, used=0, state=HTTP_STATE_WAITING, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=0, request=(nil)(), file=-1
>D [09/Jan/2014:07:16:39 +0200] [Client 19] POST / HTTP/1.1
>D [09/Jan/2014:07:16:39 +0200] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Printing jobs and dirty files"
>d [09/Jan/2014:07:16:39 +0200] cupsdFindBest: uri = "/"...
>d [09/Jan/2014:07:16:39 +0200] cupsdFindBest: Location /admin/conf Limit 7f
>d [09/Jan/2014:07:16:39 +0200] cupsdFindBest: Location /admin Limit 7f
>d [09/Jan/2014:07:16:39 +0200] cupsdFindBest: Location / Limit 7f
>d [09/Jan/2014:07:16:39 +0200] cupsdFindBest: best = /
>d [09/Jan/2014:07:16:39 +0200] [Client 19] con->uri="/", con->best=0x7f3c917ea030(/)
>d [09/Jan/2014:07:16:39 +0200] [Client 19] Authorization=""
>D [09/Jan/2014:07:16:39 +0200] [Client 19] No authentication data provided.
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: con->uri="/", con->best=0x7f3c917ea030(/)
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: level=CUPSD_AUTH_ANON, type=None, satisfy=CUPSD_AUTH_SATISFY_ALL, num_names=0
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: auth=CUPSD_AUTH_ALLOW...
>D [09/Jan/2014:07:16:39 +0200] [Client 19] 1.1 CUPS-Get-Default 8
>d [09/Jan/2014:07:16:39 +0200] cupsdProcessIPPRequest(0x7f3c91864aa0[19]): operation_id = 4001
>D [09/Jan/2014:07:16:39 +0200] CUPS-Get-Default
>d [09/Jan/2014:07:16:39 +0200] get_default(0x7f3c91864aa0[19])
>d [09/Jan/2014:07:16:39 +0200] cupsdFindPolicyOp(p=0x7f3c917eef10, op=4001(CUPS-Get-Default))
>d [09/Jan/2014:07:16:39 +0200] cupsdFindPolicyOp: Found wildcard match...
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: con->uri="/", con->best=0x7f3c917f3a30((null))
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: level=CUPSD_AUTH_ANON, type=None, satisfy=CUPSD_AUTH_SATISFY_ALL, num_names=0
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: op=0(0x0000)
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: auth=CUPSD_AUTH_ALLOW...
>d [09/Jan/2014:07:16:39 +0200] printer-icons="http://localhost:631/icons/LaserJet-4L.png"
>d [09/Jan/2014:07:16:39 +0200] add_printer_state_reasons(0x7f3c91864aa0[19], 0x7f3c917fc2f0[LaserJet-4L])
>d [09/Jan/2014:07:16:39 +0200] printer-uri-supported="ipp://localhost:631/printers/LaserJet-4L"
>d [09/Jan/2014:07:16:39 +0200] add_queued_job_count(0x7f3c91864aa0[19], 0x7f3c917fc2f0[LaserJet-4L])
>d [09/Jan/2014:07:16:39 +0200] copy_attrs(to=0x7f3c9185eca0, from=0x7f3c917ff700, ra=(nil), group=0, quickcopy=0)
>d [09/Jan/2014:07:16:39 +0200] copy_attrs(to=0x7f3c9185eca0, from=0x7f3c918194c0, ra=(nil), group=0, quickcopy=0)
>d [09/Jan/2014:07:16:39 +0200] copy_attrs(to=0x7f3c9185eca0, from=0x7f3c917fcd50, ra=(nil), group=0, quickcopy=-2147483648)
>D [09/Jan/2014:07:16:39 +0200] [Client 19] Returning IPP successful-ok for CUPS-Get-Default (no URI) from localhost
>D [09/Jan/2014:07:16:39 +0200] [Client 19] Content-Length: 7268
>d [09/Jan/2014:07:16:39 +0200] cupsdAddSelect(fd=19, read_cb=0x7f3c8f7ddbc0, write_cb=0x7f3c8f7dd3c0, data=0x7f3c91864aa0)
>d [09/Jan/2014:07:16:39 +0200] select_timeout: JobHistoryUpdate=0
>D [09/Jan/2014:07:16:39 +0200] [Client 19] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=7268, response=0x7f3c9185eca0(IPP_IDLE), pipe_pid=0, file=-1
>D [09/Jan/2014:07:16:39 +0200] [Client 19] Writing IPP response, ipp_state=DATA, old wused=0, new wused=0
>D [09/Jan/2014:07:16:39 +0200] [Client 19] bytes=0, http_state=0, data_remaining=0
>d [09/Jan/2014:07:16:39 +0200] cupsdAddSelect(fd=19, read_cb=0x7f3c8f7ddbc0, write_cb=(nil), data=0x7f3c91864aa0)
>D [09/Jan/2014:07:16:39 +0200] [Client 19] Waiting for request.
>D [09/Jan/2014:07:16:39 +0200] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients, printing jobs, and dirty files"
>d [09/Jan/2014:07:16:39 +0200] select_timeout: JobHistoryUpdate=0
>d [09/Jan/2014:07:16:39 +0200] [Client 19] cupsdReadClient error=0, used=0, state=HTTP_STATE_WAITING, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=0, request=(nil)(), file=-1
>D [09/Jan/2014:07:16:39 +0200] [Client 19] POST / HTTP/1.1
>D [09/Jan/2014:07:16:39 +0200] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Printing jobs and dirty files"
>d [09/Jan/2014:07:16:39 +0200] cupsdFindBest: uri = "/"...
>d [09/Jan/2014:07:16:39 +0200] cupsdFindBest: Location /admin/conf Limit 7f
>d [09/Jan/2014:07:16:39 +0200] cupsdFindBest: Location /admin Limit 7f
>d [09/Jan/2014:07:16:39 +0200] cupsdFindBest: Location / Limit 7f
>d [09/Jan/2014:07:16:39 +0200] cupsdFindBest: best = /
>d [09/Jan/2014:07:16:39 +0200] [Client 19] con->uri="/", con->best=0x7f3c917ea030(/)
>d [09/Jan/2014:07:16:39 +0200] [Client 19] Authorization=""
>D [09/Jan/2014:07:16:39 +0200] [Client 19] No authentication data provided.
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: con->uri="/", con->best=0x7f3c917ea030(/)
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: level=CUPSD_AUTH_ANON, type=None, satisfy=CUPSD_AUTH_SATISFY_ALL, num_names=0
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: auth=CUPSD_AUTH_ALLOW...
>d [09/Jan/2014:07:16:39 +0200] select_timeout: JobHistoryUpdate=0
>d [09/Jan/2014:07:16:39 +0200] [Client 19] cupsdReadClient error=0, used=0, state=HTTP_STATE_POST_RECV, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=664, request=0x7f3c9185eca0(IPP_ATTRIBUTE), file=-1
>d [09/Jan/2014:07:16:39 +0200] select_timeout: JobHistoryUpdate=0
>d [09/Jan/2014:07:16:39 +0200] [Client 19] cupsdReadClient error=0, used=0, state=HTTP_STATE_POST_RECV, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=635, request=0x7f3c9185eca0(IPP_ATTRIBUTE), file=-1
>d [09/Jan/2014:07:16:39 +0200] select_timeout: JobHistoryUpdate=0
>d [09/Jan/2014:07:16:39 +0200] [Client 19] cupsdReadClient error=0, used=0, state=HTTP_STATE_POST_RECV, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=598, request=0x7f3c9185eca0(IPP_ATTRIBUTE), file=-1
>d [09/Jan/2014:07:16:39 +0200] select_timeout: JobHistoryUpdate=0
>d [09/Jan/2014:07:16:39 +0200] [Client 19] cupsdReadClient error=0, used=0, state=HTTP_STATE_POST_RECV, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=555, request=0x7f3c9185eca0(IPP_ATTRIBUTE), file=-1
>d [09/Jan/2014:07:16:39 +0200] select_timeout: JobHistoryUpdate=0
>d [09/Jan/2014:07:16:39 +0200] [Client 19] cupsdReadClient error=0, used=0, state=HTTP_STATE_POST_RECV, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=540, request=0x7f3c9185eca0(IPP_ATTRIBUTE), file=-1
>d [09/Jan/2014:07:16:39 +0200] select_timeout: JobHistoryUpdate=0
>d [09/Jan/2014:07:16:39 +0200] [Client 19] cupsdReadClient error=0, used=0, state=HTTP_STATE_POST_RECV, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=517, request=0x7f3c9185eca0(IPP_ATTRIBUTE), file=-1
>d [09/Jan/2014:07:16:39 +0200] select_timeout: JobHistoryUpdate=0
>d [09/Jan/2014:07:16:39 +0200] [Client 19] cupsdReadClient error=0, used=0, state=HTTP_STATE_POST_RECV, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=494, request=0x7f3c9185eca0(IPP_ATTRIBUTE), file=-1
>d [09/Jan/2014:07:16:39 +0200] select_timeout: JobHistoryUpdate=0
>d [09/Jan/2014:07:16:39 +0200] [Client 19] cupsdReadClient error=0, used=0, state=HTTP_STATE_POST_RECV, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=476, request=0x7f3c9185eca0(IPP_ATTRIBUTE), file=-1
>d [09/Jan/2014:07:16:39 +0200] select_timeout: JobHistoryUpdate=0
>d [09/Jan/2014:07:16:39 +0200] [Client 19] cupsdReadClient error=0, used=0, state=HTTP_STATE_POST_RECV, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=453, request=0x7f3c9185eca0(IPP_ATTRIBUTE), file=-1
>d [09/Jan/2014:07:16:39 +0200] select_timeout: JobHistoryUpdate=0
>d [09/Jan/2014:07:16:39 +0200] [Client 19] cupsdReadClient error=0, used=0, state=HTTP_STATE_POST_RECV, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=435, request=0x7f3c9185eca0(IPP_ATTRIBUTE), file=-1
>d [09/Jan/2014:07:16:39 +0200] select_timeout: JobHistoryUpdate=0
>d [09/Jan/2014:07:16:39 +0200] [Client 19] cupsdReadClient error=0, used=0, state=HTTP_STATE_POST_RECV, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=413, request=0x7f3c9185eca0(IPP_ATTRIBUTE), file=-1
>d [09/Jan/2014:07:16:39 +0200] select_timeout: JobHistoryUpdate=0
>d [09/Jan/2014:07:16:39 +0200] [Client 19] cupsdReadClient error=0, used=0, state=HTTP_STATE_POST_RECV, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=394, request=0x7f3c9185eca0(IPP_ATTRIBUTE), file=-1
>d [09/Jan/2014:07:16:39 +0200] select_timeout: JobHistoryUpdate=0
>d [09/Jan/2014:07:16:39 +0200] [Client 19] cupsdReadClient error=0, used=0, state=HTTP_STATE_POST_RECV, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=377, request=0x7f3c9185eca0(IPP_ATTRIBUTE), file=-1
>d [09/Jan/2014:07:16:39 +0200] select_timeout: JobHistoryUpdate=0
>d [09/Jan/2014:07:16:39 +0200] [Client 19] cupsdReadClient error=0, used=0, state=HTTP_STATE_POST_RECV, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=360, request=0x7f3c9185eca0(IPP_ATTRIBUTE), file=-1
>d [09/Jan/2014:07:16:39 +0200] select_timeout: JobHistoryUpdate=0
>d [09/Jan/2014:07:16:39 +0200] [Client 19] cupsdReadClient error=0, used=0, state=HTTP_STATE_POST_RECV, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=339, request=0x7f3c9185eca0(IPP_ATTRIBUTE), file=-1
>d [09/Jan/2014:07:16:39 +0200] select_timeout: JobHistoryUpdate=0
>d [09/Jan/2014:07:16:39 +0200] [Client 19] cupsdReadClient error=0, used=0, state=HTTP_STATE_POST_RECV, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=318, request=0x7f3c9185eca0(IPP_ATTRIBUTE), file=-1
>d [09/Jan/2014:07:16:39 +0200] select_timeout: JobHistoryUpdate=0
>d [09/Jan/2014:07:16:39 +0200] [Client 19] cupsdReadClient error=0, used=0, state=HTTP_STATE_POST_RECV, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=301, request=0x7f3c9185eca0(IPP_ATTRIBUTE), file=-1
>d [09/Jan/2014:07:16:39 +0200] select_timeout: JobHistoryUpdate=0
>d [09/Jan/2014:07:16:39 +0200] [Client 19] cupsdReadClient error=0, used=0, state=HTTP_STATE_POST_RECV, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=271, request=0x7f3c9185eca0(IPP_ATTRIBUTE), file=-1
>d [09/Jan/2014:07:16:39 +0200] select_timeout: JobHistoryUpdate=0
>d [09/Jan/2014:07:16:39 +0200] [Client 19] cupsdReadClient error=0, used=0, state=HTTP_STATE_POST_RECV, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=249, request=0x7f3c9185eca0(IPP_ATTRIBUTE), file=-1
>d [09/Jan/2014:07:16:39 +0200] select_timeout: JobHistoryUpdate=0
>d [09/Jan/2014:07:16:39 +0200] [Client 19] cupsdReadClient error=0, used=0, state=HTTP_STATE_POST_RECV, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=228, request=0x7f3c9185eca0(IPP_ATTRIBUTE), file=-1
>d [09/Jan/2014:07:16:39 +0200] select_timeout: JobHistoryUpdate=0
>d [09/Jan/2014:07:16:39 +0200] [Client 19] cupsdReadClient error=0, used=0, state=HTTP_STATE_POST_RECV, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=201, request=0x7f3c9185eca0(IPP_ATTRIBUTE), file=-1
>d [09/Jan/2014:07:16:39 +0200] select_timeout: JobHistoryUpdate=0
>d [09/Jan/2014:07:16:39 +0200] [Client 19] cupsdReadClient error=0, used=0, state=HTTP_STATE_POST_RECV, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=164, request=0x7f3c9185eca0(IPP_ATTRIBUTE), file=-1
>d [09/Jan/2014:07:16:39 +0200] select_timeout: JobHistoryUpdate=0
>d [09/Jan/2014:07:16:39 +0200] [Client 19] cupsdReadClient error=0, used=0, state=HTTP_STATE_POST_RECV, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=147, request=0x7f3c9185eca0(IPP_ATTRIBUTE), file=-1
>d [09/Jan/2014:07:16:39 +0200] select_timeout: JobHistoryUpdate=0
>d [09/Jan/2014:07:16:39 +0200] [Client 19] cupsdReadClient error=0, used=0, state=HTTP_STATE_POST_RECV, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=129, request=0x7f3c9185eca0(IPP_ATTRIBUTE), file=-1
>d [09/Jan/2014:07:16:39 +0200] select_timeout: JobHistoryUpdate=0
>d [09/Jan/2014:07:16:39 +0200] [Client 19] cupsdReadClient error=0, used=0, state=HTTP_STATE_POST_RECV, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=99, request=0x7f3c9185eca0(IPP_ATTRIBUTE), file=-1
>d [09/Jan/2014:07:16:39 +0200] select_timeout: JobHistoryUpdate=0
>d [09/Jan/2014:07:16:39 +0200] [Client 19] cupsdReadClient error=0, used=0, state=HTTP_STATE_POST_RECV, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=73, request=0x7f3c9185eca0(IPP_ATTRIBUTE), file=-1
>d [09/Jan/2014:07:16:39 +0200] select_timeout: JobHistoryUpdate=0
>d [09/Jan/2014:07:16:39 +0200] [Client 19] cupsdReadClient error=0, used=0, state=HTTP_STATE_POST_RECV, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=56, request=0x7f3c9185eca0(IPP_ATTRIBUTE), file=-1
>d [09/Jan/2014:07:16:39 +0200] select_timeout: JobHistoryUpdate=0
>d [09/Jan/2014:07:16:39 +0200] [Client 19] cupsdReadClient error=0, used=0, state=HTTP_STATE_POST_RECV, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=30, request=0x7f3c9185eca0(IPP_ATTRIBUTE), file=-1
>d [09/Jan/2014:07:16:39 +0200] select_timeout: JobHistoryUpdate=0
>d [09/Jan/2014:07:16:39 +0200] [Client 19] cupsdReadClient error=0, used=0, state=HTTP_STATE_POST_RECV, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=1, request=0x7f3c9185eca0(IPP_ATTRIBUTE), file=-1
>D [09/Jan/2014:07:16:39 +0200] [Client 19] 1.1 CUPS-Get-Printers 9
>d [09/Jan/2014:07:16:39 +0200] cupsdProcessIPPRequest(0x7f3c91864aa0[19]): operation_id = 4002
>D [09/Jan/2014:07:16:39 +0200] CUPS-Get-Printers
>d [09/Jan/2014:07:16:39 +0200] get_printers(0x7f3c91864aa0[19], 0)
>d [09/Jan/2014:07:16:39 +0200] cupsdFindPolicyOp(p=0x7f3c917eef10, op=4002(CUPS-Get-Printers))
>d [09/Jan/2014:07:16:39 +0200] cupsdFindPolicyOp: Found wildcard match...
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: con->uri="/", con->best=0x7f3c917f3a30((null))
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: level=CUPSD_AUTH_ANON, type=None, satisfy=CUPSD_AUTH_SATISFY_ALL, num_names=0
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: op=0(0x0000)
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: auth=CUPSD_AUTH_ALLOW...
>d [09/Jan/2014:07:16:39 +0200] add_printer_state_reasons(0x7f3c91864aa0[19], 0x7f3c917fc2f0[LaserJet-4L])
>d [09/Jan/2014:07:16:39 +0200] printer-uri-supported="ipp://localhost:631/printers/LaserJet-4L"
>d [09/Jan/2014:07:16:39 +0200] copy_attrs(to=0x7f3c9185f990, from=0x7f3c917ff700, ra=0x7f3c91869fd0, group=0, quickcopy=0)
>d [09/Jan/2014:07:16:39 +0200] copy_attrs(to=0x7f3c9185f990, from=0x7f3c918194c0, ra=0x7f3c91869fd0, group=0, quickcopy=0)
>d [09/Jan/2014:07:16:39 +0200] copy_attrs(to=0x7f3c9185f990, from=0x7f3c917fcd50, ra=0x7f3c91869fd0, group=0, quickcopy=-2147483648)
>D [09/Jan/2014:07:16:39 +0200] [Client 19] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost
>D [09/Jan/2014:07:16:39 +0200] [Client 19] Content-Length: 1132
>d [09/Jan/2014:07:16:39 +0200] cupsdAddSelect(fd=19, read_cb=0x7f3c8f7ddbc0, write_cb=0x7f3c8f7dd3c0, data=0x7f3c91864aa0)
>d [09/Jan/2014:07:16:39 +0200] select_timeout: JobHistoryUpdate=0
>D [09/Jan/2014:07:16:39 +0200] [Client 19] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=1132, response=0x7f3c9185f990(IPP_IDLE), pipe_pid=0, file=-1
>D [09/Jan/2014:07:16:39 +0200] [Client 19] Writing IPP response, ipp_state=DATA, old wused=0, new wused=0
>D [09/Jan/2014:07:16:39 +0200] [Client 19] bytes=0, http_state=0, data_remaining=0
>d [09/Jan/2014:07:16:39 +0200] cupsdAddSelect(fd=19, read_cb=0x7f3c8f7ddbc0, write_cb=(nil), data=0x7f3c91864aa0)
>D [09/Jan/2014:07:16:39 +0200] [Client 19] Waiting for request.
>D [09/Jan/2014:07:16:39 +0200] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients, printing jobs, and dirty files"
>d [09/Jan/2014:07:16:39 +0200] select_timeout: JobHistoryUpdate=0
>d [09/Jan/2014:07:16:39 +0200] [Client 19] cupsdReadClient error=0, used=0, state=HTTP_STATE_WAITING, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=0, request=(nil)(), file=-1
>D [09/Jan/2014:07:16:39 +0200] [Client 19] POST / HTTP/1.1
>D [09/Jan/2014:07:16:39 +0200] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Printing jobs and dirty files"
>d [09/Jan/2014:07:16:39 +0200] cupsdFindBest: uri = "/"...
>d [09/Jan/2014:07:16:39 +0200] cupsdFindBest: Location /admin/conf Limit 7f
>d [09/Jan/2014:07:16:39 +0200] cupsdFindBest: Location /admin Limit 7f
>d [09/Jan/2014:07:16:39 +0200] cupsdFindBest: Location / Limit 7f
>d [09/Jan/2014:07:16:39 +0200] cupsdFindBest: best = /
>d [09/Jan/2014:07:16:39 +0200] [Client 19] con->uri="/", con->best=0x7f3c917ea030(/)
>d [09/Jan/2014:07:16:39 +0200] [Client 19] Authorization=""
>D [09/Jan/2014:07:16:39 +0200] [Client 19] No authentication data provided.
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: con->uri="/", con->best=0x7f3c917ea030(/)
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: level=CUPSD_AUTH_ANON, type=None, satisfy=CUPSD_AUTH_SATISFY_ALL, num_names=0
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: auth=CUPSD_AUTH_ALLOW...
>D [09/Jan/2014:07:16:39 +0200] [Client 19] 1.1 CUPS-Get-Default 10
>d [09/Jan/2014:07:16:39 +0200] cupsdProcessIPPRequest(0x7f3c91864aa0[19]): operation_id = 4001
>D [09/Jan/2014:07:16:39 +0200] CUPS-Get-Default
>d [09/Jan/2014:07:16:39 +0200] get_default(0x7f3c91864aa0[19])
>d [09/Jan/2014:07:16:39 +0200] cupsdFindPolicyOp(p=0x7f3c917eef10, op=4001(CUPS-Get-Default))
>d [09/Jan/2014:07:16:39 +0200] cupsdFindPolicyOp: Found wildcard match...
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: con->uri="/", con->best=0x7f3c917f3a30((null))
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: level=CUPSD_AUTH_ANON, type=None, satisfy=CUPSD_AUTH_SATISFY_ALL, num_names=0
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: op=0(0x0000)
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: auth=CUPSD_AUTH_ALLOW...
>d [09/Jan/2014:07:16:39 +0200] printer-icons="http://localhost:631/icons/LaserJet-4L.png"
>d [09/Jan/2014:07:16:39 +0200] add_printer_state_reasons(0x7f3c91864aa0[19], 0x7f3c917fc2f0[LaserJet-4L])
>d [09/Jan/2014:07:16:39 +0200] printer-uri-supported="ipp://localhost:631/printers/LaserJet-4L"
>d [09/Jan/2014:07:16:39 +0200] add_queued_job_count(0x7f3c91864aa0[19], 0x7f3c917fc2f0[LaserJet-4L])
>d [09/Jan/2014:07:16:39 +0200] copy_attrs(to=0x7f3c9185eca0, from=0x7f3c917ff700, ra=(nil), group=0, quickcopy=0)
>d [09/Jan/2014:07:16:39 +0200] copy_attrs(to=0x7f3c9185eca0, from=0x7f3c918194c0, ra=(nil), group=0, quickcopy=0)
>d [09/Jan/2014:07:16:39 +0200] copy_attrs(to=0x7f3c9185eca0, from=0x7f3c917fcd50, ra=(nil), group=0, quickcopy=-2147483648)
>D [09/Jan/2014:07:16:39 +0200] [Client 19] Returning IPP successful-ok for CUPS-Get-Default (no URI) from localhost
>D [09/Jan/2014:07:16:39 +0200] [Client 19] Content-Length: 7268
>d [09/Jan/2014:07:16:39 +0200] cupsdAddSelect(fd=19, read_cb=0x7f3c8f7ddbc0, write_cb=0x7f3c8f7dd3c0, data=0x7f3c91864aa0)
>d [09/Jan/2014:07:16:39 +0200] select_timeout: JobHistoryUpdate=0
>D [09/Jan/2014:07:16:39 +0200] [Client 19] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=7268, response=0x7f3c9185eca0(IPP_IDLE), pipe_pid=0, file=-1
>D [09/Jan/2014:07:16:39 +0200] [Client 19] Writing IPP response, ipp_state=DATA, old wused=0, new wused=0
>D [09/Jan/2014:07:16:39 +0200] [Client 19] bytes=0, http_state=0, data_remaining=0
>d [09/Jan/2014:07:16:39 +0200] cupsdAddSelect(fd=19, read_cb=0x7f3c8f7ddbc0, write_cb=(nil), data=0x7f3c91864aa0)
>D [09/Jan/2014:07:16:39 +0200] [Client 19] Waiting for request.
>D [09/Jan/2014:07:16:39 +0200] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients, printing jobs, and dirty files"
>d [09/Jan/2014:07:16:39 +0200] select_timeout: JobHistoryUpdate=0
>d [09/Jan/2014:07:16:39 +0200] [Client 19] cupsdReadClient error=0, used=0, state=HTTP_STATE_WAITING, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=0, request=(nil)(), file=-1
>D [09/Jan/2014:07:16:39 +0200] [Client 19] POST / HTTP/1.1
>D [09/Jan/2014:07:16:39 +0200] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Printing jobs and dirty files"
>d [09/Jan/2014:07:16:39 +0200] cupsdFindBest: uri = "/"...
>d [09/Jan/2014:07:16:39 +0200] cupsdFindBest: Location /admin/conf Limit 7f
>d [09/Jan/2014:07:16:39 +0200] cupsdFindBest: Location /admin Limit 7f
>d [09/Jan/2014:07:16:39 +0200] cupsdFindBest: Location / Limit 7f
>d [09/Jan/2014:07:16:39 +0200] cupsdFindBest: best = /
>d [09/Jan/2014:07:16:39 +0200] [Client 19] con->uri="/", con->best=0x7f3c917ea030(/)
>d [09/Jan/2014:07:16:39 +0200] [Client 19] Authorization=""
>D [09/Jan/2014:07:16:39 +0200] [Client 19] No authentication data provided.
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: con->uri="/", con->best=0x7f3c917ea030(/)
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: level=CUPSD_AUTH_ANON, type=None, satisfy=CUPSD_AUTH_SATISFY_ALL, num_names=0
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: auth=CUPSD_AUTH_ALLOW...
>D [09/Jan/2014:07:16:39 +0200] [Client 19] 1.1 CUPS-Get-Printers 11
>d [09/Jan/2014:07:16:39 +0200] cupsdProcessIPPRequest(0x7f3c91864aa0[19]): operation_id = 4002
>D [09/Jan/2014:07:16:39 +0200] CUPS-Get-Printers
>d [09/Jan/2014:07:16:39 +0200] get_printers(0x7f3c91864aa0[19], 0)
>d [09/Jan/2014:07:16:39 +0200] cupsdFindPolicyOp(p=0x7f3c917eef10, op=4002(CUPS-Get-Printers))
>d [09/Jan/2014:07:16:39 +0200] cupsdFindPolicyOp: Found wildcard match...
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: con->uri="/", con->best=0x7f3c917f3a30((null))
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: level=CUPSD_AUTH_ANON, type=None, satisfy=CUPSD_AUTH_SATISFY_ALL, num_names=0
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: op=0(0x0000)
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: auth=CUPSD_AUTH_ALLOW...
>d [09/Jan/2014:07:16:39 +0200] add_printer_state_reasons(0x7f3c91864aa0[19], 0x7f3c917fc2f0[LaserJet-4L])
>d [09/Jan/2014:07:16:39 +0200] printer-uri-supported="ipp://localhost:631/printers/LaserJet-4L"
>d [09/Jan/2014:07:16:39 +0200] copy_attrs(to=0x7f3c9185f990, from=0x7f3c917ff700, ra=0x7f3c91869fd0, group=0, quickcopy=0)
>d [09/Jan/2014:07:16:39 +0200] copy_attrs(to=0x7f3c9185f990, from=0x7f3c918194c0, ra=0x7f3c91869fd0, group=0, quickcopy=0)
>d [09/Jan/2014:07:16:39 +0200] copy_attrs(to=0x7f3c9185f990, from=0x7f3c917fcd50, ra=0x7f3c91869fd0, group=0, quickcopy=-2147483648)
>D [09/Jan/2014:07:16:39 +0200] [Client 19] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost
>D [09/Jan/2014:07:16:39 +0200] [Client 19] Content-Length: 1132
>d [09/Jan/2014:07:16:39 +0200] cupsdAddSelect(fd=19, read_cb=0x7f3c8f7ddbc0, write_cb=0x7f3c8f7dd3c0, data=0x7f3c91864aa0)
>d [09/Jan/2014:07:16:39 +0200] select_timeout: JobHistoryUpdate=0
>D [09/Jan/2014:07:16:39 +0200] [Client 19] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=1132, response=0x7f3c9185f990(IPP_IDLE), pipe_pid=0, file=-1
>D [09/Jan/2014:07:16:39 +0200] [Client 19] Writing IPP response, ipp_state=DATA, old wused=0, new wused=0
>D [09/Jan/2014:07:16:39 +0200] [Client 19] bytes=0, http_state=0, data_remaining=0
>d [09/Jan/2014:07:16:39 +0200] cupsdAddSelect(fd=19, read_cb=0x7f3c8f7ddbc0, write_cb=(nil), data=0x7f3c91864aa0)
>D [09/Jan/2014:07:16:39 +0200] [Client 19] Waiting for request.
>D [09/Jan/2014:07:16:39 +0200] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients, printing jobs, and dirty files"
>d [09/Jan/2014:07:16:39 +0200] select_timeout: JobHistoryUpdate=0
>d [09/Jan/2014:07:16:39 +0200] [Client 19] cupsdReadClient error=0, used=0, state=HTTP_STATE_WAITING, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=0, request=(nil)(), file=-1
>D [09/Jan/2014:07:16:39 +0200] [Client 19] POST / HTTP/1.1
>D [09/Jan/2014:07:16:39 +0200] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Printing jobs and dirty files"
>d [09/Jan/2014:07:16:39 +0200] cupsdFindBest: uri = "/"...
>d [09/Jan/2014:07:16:39 +0200] cupsdFindBest: Location /admin/conf Limit 7f
>d [09/Jan/2014:07:16:39 +0200] cupsdFindBest: Location /admin Limit 7f
>d [09/Jan/2014:07:16:39 +0200] cupsdFindBest: Location / Limit 7f
>d [09/Jan/2014:07:16:39 +0200] cupsdFindBest: best = /
>d [09/Jan/2014:07:16:39 +0200] [Client 19] con->uri="/", con->best=0x7f3c917ea030(/)
>d [09/Jan/2014:07:16:39 +0200] [Client 19] Authorization=""
>D [09/Jan/2014:07:16:39 +0200] [Client 19] No authentication data provided.
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: con->uri="/", con->best=0x7f3c917ea030(/)
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: level=CUPSD_AUTH_ANON, type=None, satisfy=CUPSD_AUTH_SATISFY_ALL, num_names=0
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: auth=CUPSD_AUTH_ALLOW...
>D [09/Jan/2014:07:16:39 +0200] [Client 19] 1.1 CUPS-Get-Default 12
>d [09/Jan/2014:07:16:39 +0200] cupsdProcessIPPRequest(0x7f3c91864aa0[19]): operation_id = 4001
>D [09/Jan/2014:07:16:39 +0200] CUPS-Get-Default
>d [09/Jan/2014:07:16:39 +0200] get_default(0x7f3c91864aa0[19])
>d [09/Jan/2014:07:16:39 +0200] cupsdFindPolicyOp(p=0x7f3c917eef10, op=4001(CUPS-Get-Default))
>d [09/Jan/2014:07:16:39 +0200] cupsdFindPolicyOp: Found wildcard match...
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: con->uri="/", con->best=0x7f3c917f3a30((null))
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: level=CUPSD_AUTH_ANON, type=None, satisfy=CUPSD_AUTH_SATISFY_ALL, num_names=0
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: op=0(0x0000)
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: auth=CUPSD_AUTH_ALLOW...
>d [09/Jan/2014:07:16:39 +0200] printer-icons="http://localhost:631/icons/LaserJet-4L.png"
>d [09/Jan/2014:07:16:39 +0200] add_printer_state_reasons(0x7f3c91864aa0[19], 0x7f3c917fc2f0[LaserJet-4L])
>d [09/Jan/2014:07:16:39 +0200] printer-uri-supported="ipp://localhost:631/printers/LaserJet-4L"
>d [09/Jan/2014:07:16:39 +0200] add_queued_job_count(0x7f3c91864aa0[19], 0x7f3c917fc2f0[LaserJet-4L])
>d [09/Jan/2014:07:16:39 +0200] copy_attrs(to=0x7f3c9185eca0, from=0x7f3c917ff700, ra=(nil), group=0, quickcopy=0)
>d [09/Jan/2014:07:16:39 +0200] copy_attrs(to=0x7f3c9185eca0, from=0x7f3c918194c0, ra=(nil), group=0, quickcopy=0)
>d [09/Jan/2014:07:16:39 +0200] copy_attrs(to=0x7f3c9185eca0, from=0x7f3c917fcd50, ra=(nil), group=0, quickcopy=-2147483648)
>D [09/Jan/2014:07:16:39 +0200] [Client 19] Returning IPP successful-ok for CUPS-Get-Default (no URI) from localhost
>D [09/Jan/2014:07:16:39 +0200] [Client 19] Content-Length: 7268
>d [09/Jan/2014:07:16:39 +0200] cupsdAddSelect(fd=19, read_cb=0x7f3c8f7ddbc0, write_cb=0x7f3c8f7dd3c0, data=0x7f3c91864aa0)
>d [09/Jan/2014:07:16:39 +0200] select_timeout: JobHistoryUpdate=0
>D [09/Jan/2014:07:16:39 +0200] [Client 19] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=7268, response=0x7f3c9185eca0(IPP_IDLE), pipe_pid=0, file=-1
>D [09/Jan/2014:07:16:39 +0200] [Client 19] Writing IPP response, ipp_state=DATA, old wused=0, new wused=0
>D [09/Jan/2014:07:16:39 +0200] [Client 19] bytes=0, http_state=0, data_remaining=0
>d [09/Jan/2014:07:16:39 +0200] cupsdAddSelect(fd=19, read_cb=0x7f3c8f7ddbc0, write_cb=(nil), data=0x7f3c91864aa0)
>D [09/Jan/2014:07:16:39 +0200] [Client 19] Waiting for request.
>D [09/Jan/2014:07:16:39 +0200] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients, printing jobs, and dirty files"
>d [09/Jan/2014:07:16:39 +0200] select_timeout: JobHistoryUpdate=0
>d [09/Jan/2014:07:16:39 +0200] [Client 19] cupsdReadClient error=0, used=0, state=HTTP_STATE_WAITING, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=0, request=(nil)(), file=-1
>D [09/Jan/2014:07:16:39 +0200] [Client 19] POST / HTTP/1.1
>D [09/Jan/2014:07:16:39 +0200] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Printing jobs and dirty files"
>d [09/Jan/2014:07:16:39 +0200] cupsdFindBest: uri = "/"...
>d [09/Jan/2014:07:16:39 +0200] cupsdFindBest: Location /admin/conf Limit 7f
>d [09/Jan/2014:07:16:39 +0200] cupsdFindBest: Location /admin Limit 7f
>d [09/Jan/2014:07:16:39 +0200] cupsdFindBest: Location / Limit 7f
>d [09/Jan/2014:07:16:39 +0200] cupsdFindBest: best = /
>d [09/Jan/2014:07:16:39 +0200] [Client 19] con->uri="/", con->best=0x7f3c917ea030(/)
>d [09/Jan/2014:07:16:39 +0200] [Client 19] Authorization=""
>D [09/Jan/2014:07:16:39 +0200] [Client 19] No authentication data provided.
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: con->uri="/", con->best=0x7f3c917ea030(/)
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: level=CUPSD_AUTH_ANON, type=None, satisfy=CUPSD_AUTH_SATISFY_ALL, num_names=0
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: auth=CUPSD_AUTH_ALLOW...
>d [09/Jan/2014:07:16:39 +0200] select_timeout: JobHistoryUpdate=0
>d [09/Jan/2014:07:16:39 +0200] [Client 19] cupsdReadClient error=0, used=0, state=HTTP_STATE_POST_RECV, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=204, request=0x7f3c9185eca0(IPP_ATTRIBUTE), file=-1
>d [09/Jan/2014:07:16:39 +0200] select_timeout: JobHistoryUpdate=0
>d [09/Jan/2014:07:16:39 +0200] [Client 19] cupsdReadClient error=0, used=0, state=HTTP_STATE_POST_RECV, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=175, request=0x7f3c9185eca0(IPP_ATTRIBUTE), file=-1
>d [09/Jan/2014:07:16:39 +0200] select_timeout: JobHistoryUpdate=0
>d [09/Jan/2014:07:16:39 +0200] [Client 19] cupsdReadClient error=0, used=0, state=HTTP_STATE_POST_RECV, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=138, request=0x7f3c9185eca0(IPP_ATTRIBUTE), file=-1
>d [09/Jan/2014:07:16:39 +0200] select_timeout: JobHistoryUpdate=0
>d [09/Jan/2014:07:16:39 +0200] [Client 19] cupsdReadClient error=0, used=0, state=HTTP_STATE_POST_RECV, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=109, request=0x7f3c9185eca0(IPP_ATTRIBUTE), file=-1
>d [09/Jan/2014:07:16:39 +0200] select_timeout: JobHistoryUpdate=0
>d [09/Jan/2014:07:16:39 +0200] [Client 19] cupsdReadClient error=0, used=0, state=HTTP_STATE_POST_RECV, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=77, request=0x7f3c9185eca0(IPP_ATTRIBUTE), file=-1
>d [09/Jan/2014:07:16:39 +0200] select_timeout: JobHistoryUpdate=0
>d [09/Jan/2014:07:16:39 +0200] [Client 19] cupsdReadClient error=0, used=0, state=HTTP_STATE_POST_RECV, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=51, request=0x7f3c9185eca0(IPP_ATTRIBUTE), file=-1
>d [09/Jan/2014:07:16:39 +0200] select_timeout: JobHistoryUpdate=0
>d [09/Jan/2014:07:16:39 +0200] [Client 19] cupsdReadClient error=0, used=0, state=HTTP_STATE_POST_RECV, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=33, request=0x7f3c9185eca0(IPP_ATTRIBUTE), file=-1
>d [09/Jan/2014:07:16:39 +0200] select_timeout: JobHistoryUpdate=0
>d [09/Jan/2014:07:16:39 +0200] [Client 19] cupsdReadClient error=0, used=0, state=HTTP_STATE_POST_RECV, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=1, request=0x7f3c9185eca0(IPP_ATTRIBUTE), file=-1
>D [09/Jan/2014:07:16:39 +0200] [Client 19] 1.1 Get-Notifications 13
>d [09/Jan/2014:07:16:39 +0200] cupsdProcessIPPRequest(0x7f3c91864aa0[19]): operation_id = 001c
>D [09/Jan/2014:07:16:39 +0200] Get-Notifications /printers/
>d [09/Jan/2014:07:16:39 +0200] get_notifications(con=0x7f3c91864aa0[19])
>d [09/Jan/2014:07:16:39 +0200] cupsdFindPolicyOp(p=0x7f3c917eef10, op=1c(Get-Notifications))
>d [09/Jan/2014:07:16:39 +0200] cupsdFindPolicyOp: Found exact match...
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: con->uri="/", con->best=0x7f3c917f0ab0((null))
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: owner="fred"
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: level=CUPSD_AUTH_USER, type=None, satisfy=CUPSD_AUTH_SATISFY_ALL, num_names=2
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: op=1c(Get-Notifications)
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: auth=CUPSD_AUTH_ALLOW...
>D [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: requesting-user-name="fred"
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: Checking user membership...
>D [09/Jan/2014:07:16:39 +0200] [Client 19] Returning IPP successful-ok for Get-Notifications (/printers/) from localhost
>D [09/Jan/2014:07:16:39 +0200] [Client 19] Content-Length: 127
>d [09/Jan/2014:07:16:39 +0200] cupsdAddSelect(fd=19, read_cb=0x7f3c8f7ddbc0, write_cb=0x7f3c8f7dd3c0, data=0x7f3c91864aa0)
>d [09/Jan/2014:07:16:39 +0200] select_timeout: JobHistoryUpdate=0
>D [09/Jan/2014:07:16:39 +0200] [Client 19] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=127, response=0x7f3c9185f990(IPP_IDLE), pipe_pid=0, file=-1
>D [09/Jan/2014:07:16:39 +0200] [Client 19] Writing IPP response, ipp_state=DATA, old wused=0, new wused=0
>D [09/Jan/2014:07:16:39 +0200] [Client 19] bytes=0, http_state=0, data_remaining=0
>d [09/Jan/2014:07:16:39 +0200] cupsdAddSelect(fd=19, read_cb=0x7f3c8f7ddbc0, write_cb=(nil), data=0x7f3c91864aa0)
>D [09/Jan/2014:07:16:39 +0200] [Client 19] Waiting for request.
>D [09/Jan/2014:07:16:39 +0200] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients, printing jobs, and dirty files"
>d [09/Jan/2014:07:16:39 +0200] select_timeout: JobHistoryUpdate=0
>d [09/Jan/2014:07:16:39 +0200] [Client 19] cupsdReadClient error=0, used=0, state=HTTP_STATE_WAITING, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=0, request=(nil)(), file=-1
>D [09/Jan/2014:07:16:39 +0200] [Client 19] POST / HTTP/1.1
>D [09/Jan/2014:07:16:39 +0200] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Printing jobs and dirty files"
>d [09/Jan/2014:07:16:39 +0200] cupsdFindBest: uri = "/"...
>d [09/Jan/2014:07:16:39 +0200] cupsdFindBest: Location /admin/conf Limit 7f
>d [09/Jan/2014:07:16:39 +0200] cupsdFindBest: Location /admin Limit 7f
>d [09/Jan/2014:07:16:39 +0200] cupsdFindBest: Location / Limit 7f
>d [09/Jan/2014:07:16:39 +0200] cupsdFindBest: best = /
>d [09/Jan/2014:07:16:39 +0200] [Client 19] con->uri="/", con->best=0x7f3c917ea030(/)
>d [09/Jan/2014:07:16:39 +0200] [Client 19] Authorization=""
>D [09/Jan/2014:07:16:39 +0200] [Client 19] No authentication data provided.
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: con->uri="/", con->best=0x7f3c917ea030(/)
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: level=CUPSD_AUTH_ANON, type=None, satisfy=CUPSD_AUTH_SATISFY_ALL, num_names=0
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: auth=CUPSD_AUTH_ALLOW...
>D [09/Jan/2014:07:16:39 +0200] [Client 19] 1.1 Get-Notifications 14
>d [09/Jan/2014:07:16:39 +0200] cupsdProcessIPPRequest(0x7f3c91864aa0[19]): operation_id = 001c
>D [09/Jan/2014:07:16:39 +0200] Get-Notifications /printers/
>d [09/Jan/2014:07:16:39 +0200] get_notifications(con=0x7f3c91864aa0[19])
>d [09/Jan/2014:07:16:39 +0200] cupsdFindPolicyOp(p=0x7f3c917eef10, op=1c(Get-Notifications))
>d [09/Jan/2014:07:16:39 +0200] cupsdFindPolicyOp: Found exact match...
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: con->uri="/", con->best=0x7f3c917f0ab0((null))
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: owner="fred"
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: level=CUPSD_AUTH_USER, type=None, satisfy=CUPSD_AUTH_SATISFY_ALL, num_names=2
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: op=1c(Get-Notifications)
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: auth=CUPSD_AUTH_ALLOW...
>D [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: requesting-user-name="fred"
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: Checking user membership...
>D [09/Jan/2014:07:16:39 +0200] [Client 19] Returning IPP successful-ok for Get-Notifications (/printers/) from localhost
>D [09/Jan/2014:07:16:39 +0200] [Client 19] Content-Length: 127
>d [09/Jan/2014:07:16:39 +0200] cupsdAddSelect(fd=19, read_cb=0x7f3c8f7ddbc0, write_cb=0x7f3c8f7dd3c0, data=0x7f3c91864aa0)
>d [09/Jan/2014:07:16:39 +0200] select_timeout: JobHistoryUpdate=0
>D [09/Jan/2014:07:16:39 +0200] [Client 19] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=127, response=0x7f3c9185eca0(IPP_IDLE), pipe_pid=0, file=-1
>D [09/Jan/2014:07:16:39 +0200] [Client 19] Writing IPP response, ipp_state=DATA, old wused=0, new wused=0
>D [09/Jan/2014:07:16:39 +0200] [Client 19] bytes=0, http_state=0, data_remaining=0
>d [09/Jan/2014:07:16:39 +0200] cupsdAddSelect(fd=19, read_cb=0x7f3c8f7ddbc0, write_cb=(nil), data=0x7f3c91864aa0)
>D [09/Jan/2014:07:16:39 +0200] [Client 19] Waiting for request.
>D [09/Jan/2014:07:16:39 +0200] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients, printing jobs, and dirty files"
>d [09/Jan/2014:07:16:39 +0200] select_timeout: JobHistoryUpdate=0
>d [09/Jan/2014:07:16:39 +0200] [Client 19] cupsdReadClient error=0, used=0, state=HTTP_STATE_WAITING, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=0, request=(nil)(), file=-1
>D [09/Jan/2014:07:16:39 +0200] [Client 19] POST / HTTP/1.1
>D [09/Jan/2014:07:16:39 +0200] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Printing jobs and dirty files"
>d [09/Jan/2014:07:16:39 +0200] cupsdFindBest: uri = "/"...
>d [09/Jan/2014:07:16:39 +0200] cupsdFindBest: Location /admin/conf Limit 7f
>d [09/Jan/2014:07:16:39 +0200] cupsdFindBest: Location /admin Limit 7f
>d [09/Jan/2014:07:16:39 +0200] cupsdFindBest: Location / Limit 7f
>d [09/Jan/2014:07:16:39 +0200] cupsdFindBest: best = /
>d [09/Jan/2014:07:16:39 +0200] [Client 19] con->uri="/", con->best=0x7f3c917ea030(/)
>d [09/Jan/2014:07:16:39 +0200] [Client 19] Authorization=""
>D [09/Jan/2014:07:16:39 +0200] [Client 19] No authentication data provided.
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: con->uri="/", con->best=0x7f3c917ea030(/)
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: level=CUPSD_AUTH_ANON, type=None, satisfy=CUPSD_AUTH_SATISFY_ALL, num_names=0
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: auth=CUPSD_AUTH_ALLOW...
>D [09/Jan/2014:07:16:39 +0200] [Client 19] 1.1 Get-Notifications 15
>d [09/Jan/2014:07:16:39 +0200] cupsdProcessIPPRequest(0x7f3c91864aa0[19]): operation_id = 001c
>D [09/Jan/2014:07:16:39 +0200] Get-Notifications /printers/
>d [09/Jan/2014:07:16:39 +0200] get_notifications(con=0x7f3c91864aa0[19])
>d [09/Jan/2014:07:16:39 +0200] cupsdFindPolicyOp(p=0x7f3c917eef10, op=1c(Get-Notifications))
>d [09/Jan/2014:07:16:39 +0200] cupsdFindPolicyOp: Found exact match...
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: con->uri="/", con->best=0x7f3c917f0ab0((null))
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: owner="fred"
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: level=CUPSD_AUTH_USER, type=None, satisfy=CUPSD_AUTH_SATISFY_ALL, num_names=2
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: op=1c(Get-Notifications)
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: auth=CUPSD_AUTH_ALLOW...
>D [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: requesting-user-name="fred"
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: Checking user membership...
>D [09/Jan/2014:07:16:39 +0200] [Client 19] Returning IPP successful-ok for Get-Notifications (/printers/) from localhost
>D [09/Jan/2014:07:16:39 +0200] [Client 19] Content-Length: 127
>d [09/Jan/2014:07:16:39 +0200] cupsdAddSelect(fd=19, read_cb=0x7f3c8f7ddbc0, write_cb=0x7f3c8f7dd3c0, data=0x7f3c91864aa0)
>d [09/Jan/2014:07:16:39 +0200] select_timeout: JobHistoryUpdate=0
>D [09/Jan/2014:07:16:39 +0200] [Client 19] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=127, response=0x7f3c9185f990(IPP_IDLE), pipe_pid=0, file=-1
>D [09/Jan/2014:07:16:39 +0200] [Client 19] Writing IPP response, ipp_state=DATA, old wused=0, new wused=0
>D [09/Jan/2014:07:16:39 +0200] [Client 19] bytes=0, http_state=0, data_remaining=0
>d [09/Jan/2014:07:16:39 +0200] cupsdAddSelect(fd=19, read_cb=0x7f3c8f7ddbc0, write_cb=(nil), data=0x7f3c91864aa0)
>D [09/Jan/2014:07:16:39 +0200] [Client 19] Waiting for request.
>D [09/Jan/2014:07:16:39 +0200] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients, printing jobs, and dirty files"
>d [09/Jan/2014:07:16:39 +0200] select_timeout: JobHistoryUpdate=0
>d [09/Jan/2014:07:16:39 +0200] [Client 19] cupsdReadClient error=0, used=0, state=HTTP_STATE_WAITING, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=0, request=(nil)(), file=-1
>D [09/Jan/2014:07:16:39 +0200] [Client 19] POST / HTTP/1.1
>D [09/Jan/2014:07:16:39 +0200] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Printing jobs and dirty files"
>d [09/Jan/2014:07:16:39 +0200] cupsdFindBest: uri = "/"...
>d [09/Jan/2014:07:16:39 +0200] cupsdFindBest: Location /admin/conf Limit 7f
>d [09/Jan/2014:07:16:39 +0200] cupsdFindBest: Location /admin Limit 7f
>d [09/Jan/2014:07:16:39 +0200] cupsdFindBest: Location / Limit 7f
>d [09/Jan/2014:07:16:39 +0200] cupsdFindBest: best = /
>d [09/Jan/2014:07:16:39 +0200] [Client 19] con->uri="/", con->best=0x7f3c917ea030(/)
>d [09/Jan/2014:07:16:39 +0200] [Client 19] Authorization=""
>D [09/Jan/2014:07:16:39 +0200] [Client 19] No authentication data provided.
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: con->uri="/", con->best=0x7f3c917ea030(/)
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: level=CUPSD_AUTH_ANON, type=None, satisfy=CUPSD_AUTH_SATISFY_ALL, num_names=0
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: auth=CUPSD_AUTH_ALLOW...
>D [09/Jan/2014:07:16:39 +0200] [Client 19] 1.1 Get-Notifications 16
>d [09/Jan/2014:07:16:39 +0200] cupsdProcessIPPRequest(0x7f3c91864aa0[19]): operation_id = 001c
>D [09/Jan/2014:07:16:39 +0200] Get-Notifications /printers/
>d [09/Jan/2014:07:16:39 +0200] get_notifications(con=0x7f3c91864aa0[19])
>d [09/Jan/2014:07:16:39 +0200] cupsdFindPolicyOp(p=0x7f3c917eef10, op=1c(Get-Notifications))
>d [09/Jan/2014:07:16:39 +0200] cupsdFindPolicyOp: Found exact match...
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: con->uri="/", con->best=0x7f3c917f0ab0((null))
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: owner="fred"
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: level=CUPSD_AUTH_USER, type=None, satisfy=CUPSD_AUTH_SATISFY_ALL, num_names=2
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: op=1c(Get-Notifications)
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: auth=CUPSD_AUTH_ALLOW...
>D [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: requesting-user-name="fred"
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: Checking user membership...
>D [09/Jan/2014:07:16:39 +0200] [Client 19] Returning IPP successful-ok for Get-Notifications (/printers/) from localhost
>D [09/Jan/2014:07:16:39 +0200] [Client 19] Content-Length: 127
>d [09/Jan/2014:07:16:39 +0200] cupsdAddSelect(fd=19, read_cb=0x7f3c8f7ddbc0, write_cb=0x7f3c8f7dd3c0, data=0x7f3c91864aa0)
>d [09/Jan/2014:07:16:39 +0200] select_timeout: JobHistoryUpdate=0
>D [09/Jan/2014:07:16:39 +0200] [Client 19] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=127, response=0x7f3c9185eca0(IPP_IDLE), pipe_pid=0, file=-1
>D [09/Jan/2014:07:16:39 +0200] [Client 19] Writing IPP response, ipp_state=DATA, old wused=0, new wused=0
>D [09/Jan/2014:07:16:39 +0200] [Client 19] bytes=0, http_state=0, data_remaining=0
>d [09/Jan/2014:07:16:39 +0200] cupsdAddSelect(fd=19, read_cb=0x7f3c8f7ddbc0, write_cb=(nil), data=0x7f3c91864aa0)
>D [09/Jan/2014:07:16:39 +0200] [Client 19] Waiting for request.
>D [09/Jan/2014:07:16:39 +0200] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients, printing jobs, and dirty files"
>d [09/Jan/2014:07:16:39 +0200] select_timeout: JobHistoryUpdate=0
>d [09/Jan/2014:07:16:39 +0200] [Client 19] cupsdReadClient error=0, used=0, state=HTTP_STATE_WAITING, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=0, request=(nil)(), file=-1
>D [09/Jan/2014:07:16:39 +0200] [Client 19] POST / HTTP/1.1
>D [09/Jan/2014:07:16:39 +0200] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Printing jobs and dirty files"
>d [09/Jan/2014:07:16:39 +0200] cupsdFindBest: uri = "/"...
>d [09/Jan/2014:07:16:39 +0200] cupsdFindBest: Location /admin/conf Limit 7f
>d [09/Jan/2014:07:16:39 +0200] cupsdFindBest: Location /admin Limit 7f
>d [09/Jan/2014:07:16:39 +0200] cupsdFindBest: Location / Limit 7f
>d [09/Jan/2014:07:16:39 +0200] cupsdFindBest: best = /
>d [09/Jan/2014:07:16:39 +0200] [Client 19] con->uri="/", con->best=0x7f3c917ea030(/)
>d [09/Jan/2014:07:16:39 +0200] [Client 19] Authorization=""
>D [09/Jan/2014:07:16:39 +0200] [Client 19] No authentication data provided.
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: con->uri="/", con->best=0x7f3c917ea030(/)
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: level=CUPSD_AUTH_ANON, type=None, satisfy=CUPSD_AUTH_SATISFY_ALL, num_names=0
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: auth=CUPSD_AUTH_ALLOW...
>D [09/Jan/2014:07:16:39 +0200] [Client 19] 1.1 Get-Notifications 17
>d [09/Jan/2014:07:16:39 +0200] cupsdProcessIPPRequest(0x7f3c91864aa0[19]): operation_id = 001c
>D [09/Jan/2014:07:16:39 +0200] Get-Notifications /printers/
>d [09/Jan/2014:07:16:39 +0200] get_notifications(con=0x7f3c91864aa0[19])
>d [09/Jan/2014:07:16:39 +0200] cupsdFindPolicyOp(p=0x7f3c917eef10, op=1c(Get-Notifications))
>d [09/Jan/2014:07:16:39 +0200] cupsdFindPolicyOp: Found exact match...
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: con->uri="/", con->best=0x7f3c917f0ab0((null))
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: owner="fred"
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: level=CUPSD_AUTH_USER, type=None, satisfy=CUPSD_AUTH_SATISFY_ALL, num_names=2
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: op=1c(Get-Notifications)
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: auth=CUPSD_AUTH_ALLOW...
>D [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: requesting-user-name="fred"
>d [09/Jan/2014:07:16:39 +0200] cupsdIsAuthorized: Checking user membership...
>D [09/Jan/2014:07:16:39 +0200] [Client 19] Returning IPP successful-ok for Get-Notifications (/printers/) from localhost
>D [09/Jan/2014:07:16:39 +0200] [Client 19] Content-Length: 127
>d [09/Jan/2014:07:16:39 +0200] cupsdAddSelect(fd=19, read_cb=0x7f3c8f7ddbc0, write_cb=0x7f3c8f7dd3c0, data=0x7f3c91864aa0)
>d [09/Jan/2014:07:16:39 +0200] select_timeout: JobHistoryUpdate=0
>D [09/Jan/2014:07:16:39 +0200] [Client 19] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=127, response=0x7f3c9185f990(IPP_IDLE), pipe_pid=0, file=-1
>D [09/Jan/2014:07:16:39 +0200] [Client 19] Writing IPP response, ipp_state=DATA, old wused=0, new wused=0
>D [09/Jan/2014:07:16:39 +0200] [Client 19] bytes=0, http_state=0, data_remaining=0
>d [09/Jan/2014:07:16:39 +0200] cupsdAddSelect(fd=19, read_cb=0x7f3c8f7ddbc0, write_cb=(nil), data=0x7f3c91864aa0)
>D [09/Jan/2014:07:16:39 +0200] [Client 19] Waiting for request.
>D [09/Jan/2014:07:16:39 +0200] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients, printing jobs, and dirty files"
>d [09/Jan/2014:07:16:39 +0200] select_timeout: JobHistoryUpdate=0
>d [09/Jan/2014:07:16:39 +0200] process_children()
>d [09/Jan/2014:07:16:39 +0200] cupsdFinishProcess(pid=14980, name=0x7fff7040df90, namelen=1024, job_id=0x7fff7040df8c(21)) = "/usr/lib/cups/filter/pdftopdf"
>D [09/Jan/2014:07:16:39 +0200] [Job 21] PID 14980 (/usr/lib/cups/filter/pdftopdf) exited with no errors.
>d [09/Jan/2014:07:16:39 +0200] select_timeout: JobHistoryUpdate=0
>d [09/Jan/2014:07:16:39 +0200] select_timeout(-1): 31 seconds to write dirty config/state files
>D [09/Jan/2014:07:16:39 +0200] [Job 21] Getting input from file 
>d [09/Jan/2014:07:16:39 +0200] select_timeout: JobHistoryUpdate=0
>D [09/Jan/2014:07:16:39 +0200] [Job 21] foomatic-rip version 4.0.17.256 running...
>D [09/Jan/2014:07:16:39 +0200] [Job 21] Parsing PPD file ...
>d [09/Jan/2014:07:16:39 +0200] select_timeout: JobHistoryUpdate=0
>D [09/Jan/2014:07:16:39 +0200] [Job 21] Added option ColorSpace
>d [09/Jan/2014:07:16:39 +0200] select_timeout: JobHistoryUpdate=0
>D [09/Jan/2014:07:16:39 +0200] [Job 21] Added option PageSize
>d [09/Jan/2014:07:16:39 +0200] select_timeout: JobHistoryUpdate=0
>D [09/Jan/2014:07:16:39 +0200] [Job 21] Added option ImageableArea
>d [09/Jan/2014:07:16:39 +0200] select_timeout: JobHistoryUpdate=0
>D [09/Jan/2014:07:16:39 +0200] [Job 21] Added option PaperDimension
>d [09/Jan/2014:07:16:39 +0200] select_timeout: JobHistoryUpdate=0
>D [09/Jan/2014:07:16:39 +0200] [Job 21] Added option InputSlot
>d [09/Jan/2014:07:16:39 +0200] select_timeout: JobHistoryUpdate=0
>D [09/Jan/2014:07:16:39 +0200] [Job 21] Added option Manualfeed
>d [09/Jan/2014:07:16:39 +0200] select_timeout: JobHistoryUpdate=0
>D [09/Jan/2014:07:16:39 +0200] [Job 21] Added option Economode
>d [09/Jan/2014:07:16:39 +0200] select_timeout: JobHistoryUpdate=0
>D [09/Jan/2014:07:16:39 +0200] [Job 21] Added option Copies
>d [09/Jan/2014:07:16:39 +0200] select_timeout: JobHistoryUpdate=0
>D [09/Jan/2014:07:16:39 +0200] [Job 21] Added option Resolution
>d [09/Jan/2014:07:16:39 +0200] select_timeout: JobHistoryUpdate=0
>D [09/Jan/2014:07:16:39 +0200] [Job 21] Added option REt
>d [09/Jan/2014:07:16:39 +0200] select_timeout: JobHistoryUpdate=0
>D [09/Jan/2014:07:16:39 +0200] [Job 21] Added option TonerDensity
>d [09/Jan/2014:07:16:39 +0200] select_timeout: JobHistoryUpdate=0
>D [09/Jan/2014:07:16:39 +0200] [Job 21] Added option Font
>d [09/Jan/2014:07:16:39 +0200] select_timeout: JobHistoryUpdate=0
>D [09/Jan/2014:07:16:39 +0200] [Job 21] Parameter Summary
>D [09/Jan/2014:07:16:39 +0200] [Job 21] -----------------
>D [09/Jan/2014:07:16:39 +0200] [Job 21] Spooler: cups
>D [09/Jan/2014:07:16:39 +0200] [Job 21] Printer: LaserJet-4L
>D [09/Jan/2014:07:16:39 +0200] [Job 21] Shell: /bin/bash
>D [09/Jan/2014:07:16:39 +0200] [Job 21] PPD file: /etc/cups/ppd/LaserJet-4L.ppd
>D [09/Jan/2014:07:16:39 +0200] [Job 21] ATTR file: 
>D [09/Jan/2014:07:16:39 +0200] [Job 21] Printer model: HP LaserJet 4L Foomatic/ljet4 (recommended)
>D [09/Jan/2014:07:16:39 +0200] [Job 21] Job title: bensiin
>D [09/Jan/2014:07:16:39 +0200] [Job 21] File(s) to be printed:
>D [09/Jan/2014:07:16:39 +0200] [Job 21] <STDIN>
>d [09/Jan/2014:07:16:39 +0200] select_timeout: JobHistoryUpdate=0
>D [09/Jan/2014:07:16:39 +0200] [Job 21] Ghostscript extra search path ('GS_LIB'): /usr/share/cups/fonts
>d [09/Jan/2014:07:16:39 +0200] select_timeout: JobHistoryUpdate=0
>D [09/Jan/2014:07:16:39 +0200] [Job 21] Printing system options:
>D [09/Jan/2014:07:16:39 +0200] [Job 21] Pondering option 'job-uuid=urn:uuid:36b042d3-d3f1-3d72-5487-889d809d9964'
>D [09/Jan/2014:07:16:39 +0200] [Job 21] Unknown option job-uuid=urn:uuid:36b042d3-d3f1-3d72-5487-889d809d9964.
>d [09/Jan/2014:07:16:39 +0200] select_timeout: JobHistoryUpdate=0
>D [09/Jan/2014:07:16:39 +0200] [Job 21] Pondering option 'job-originating-host-name=localhost'
>D [09/Jan/2014:07:16:39 +0200] [Job 21] Unknown option job-originating-host-name=localhost.
>D [09/Jan/2014:07:16:39 +0200] [Job 21] Pondering option 'time-at-creation=1389244599'
>D [09/Jan/2014:07:16:39 +0200] [Job 21] Unknown option time-at-creation=1389244599.
>D [09/Jan/2014:07:16:39 +0200] [Job 21] Pondering option 'time-at-processing=1389244599'
>D [09/Jan/2014:07:16:39 +0200] [Job 21] Unknown option time-at-processing=1389244599.
>D [09/Jan/2014:07:16:39 +0200] [Job 21] Options from the PPD file:
>D [09/Jan/2014:07:16:39 +0200] [Job 21] Pondering option 'InputSlot=Default'
>D [09/Jan/2014:07:16:39 +0200] [Job 21] Pondering option 'PageSize=A4'
>D [09/Jan/2014:07:16:39 +0200] [Job 21] ================================================
>D [09/Jan/2014:07:16:39 +0200] [Job 21] File: <STDIN>
>D [09/Jan/2014:07:16:39 +0200] [Job 21] ================================================
>d [09/Jan/2014:07:16:39 +0200] select_timeout: JobHistoryUpdate=0
>D [09/Jan/2014:07:16:39 +0200] [Job 21] Filetype: PDF
>D [09/Jan/2014:07:16:39 +0200] [Job 21] Storing temporary files in /var/spool/cups/tmp
>d [09/Jan/2014:07:16:39 +0200] select_timeout: JobHistoryUpdate=0
>D [09/Jan/2014:07:16:40 +0200] [Job 21] File contains 1 pages
>d [09/Jan/2014:07:16:40 +0200] select_timeout: JobHistoryUpdate=0
>D [09/Jan/2014:07:16:40 +0200] [Job 21] Starting renderer with command: gs -dFirstPage=1  -q -dBATCH -dPARANOIDSAFER -dNOPAUSE -dNOINTERPOLATE -sDEVICE=ljet4 -dMediaPosition=0 -dDEVICEWIDTHPOINTS=595 -dDEVICEHEIGHTPOINTS=842 -r300x300 -sOutputFile=- -f   /var/spool/cups/tmp/foomatic-2Qt9YL 
>D [09/Jan/2014:07:16:40 +0200] [Job 21] Starting process "kid3" (generation 1)
>d [09/Jan/2014:07:16:40 +0200] select_timeout: JobHistoryUpdate=0
>D [09/Jan/2014:07:16:40 +0200] [Job 21] Starting process "kid4" (generation 2)
>d [09/Jan/2014:07:16:40 +0200] select_timeout: JobHistoryUpdate=0
>D [09/Jan/2014:07:16:40 +0200] [Job 21] Starting process "renderer" (generation 2)
>d [09/Jan/2014:07:16:40 +0200] select_timeout: JobHistoryUpdate=0
>D [09/Jan/2014:07:16:40 +0200] [Job 21] JCL: %-12345X@PJL
>D [09/Jan/2014:07:16:40 +0200] [Job 21] @PJL SET DENSITY=3
>d [09/Jan/2014:07:16:40 +0200] select_timeout: JobHistoryUpdate=0
>D [09/Jan/2014:07:16:40 +0200] [Job 21] @PJL SET RET=MEDIUM
>D [09/Jan/2014:07:16:40 +0200] [Job 21] @PJL SET COPIES=1
>D [09/Jan/2014:07:16:40 +0200] [Job 21] @PJL SET ECONOMODE=OFF
>D [09/Jan/2014:07:16:40 +0200] [Job 21] @PJL SET MANUALFEED=OFF
>D [09/Jan/2014:07:16:40 +0200] [Job 21] <job data> %-12345X@PJL RESET
>d [09/Jan/2014:07:16:40 +0200] select_timeout: JobHistoryUpdate=0
>D [09/Jan/2014:07:16:40 +0200] [Job 21] Read 8192 bytes of print data...
>d [09/Jan/2014:07:16:40 +0200] select_timeout: JobHistoryUpdate=0
>D [09/Jan/2014:07:16:40 +0200] [Job 21] renderer exited with status 0
>d [09/Jan/2014:07:16:40 +0200] select_timeout: JobHistoryUpdate=0
>D [09/Jan/2014:07:16:40 +0200] [Job 21] Wrote 8192 bytes of print data...
>D [09/Jan/2014:07:16:40 +0200] [Job 21] Read 8192 bytes of print data...
>d [09/Jan/2014:07:16:40 +0200] select_timeout: JobHistoryUpdate=0
>D [09/Jan/2014:07:16:41 +0200] [Job 21] Wrote 8192 bytes of print data...
>D [09/Jan/2014:07:16:41 +0200] [Job 21] Read 8192 bytes of print data...
>d [09/Jan/2014:07:16:41 +0200] select_timeout: JobHistoryUpdate=0
>D [09/Jan/2014:07:16:41 +0200] [Job 21] Wrote 8192 bytes of print data...
>D [09/Jan/2014:07:16:41 +0200] [Job 21] Read 8192 bytes of print data...
>d [09/Jan/2014:07:16:41 +0200] select_timeout: JobHistoryUpdate=0
>D [09/Jan/2014:07:16:42 +0200] [Job 21] Wrote 8192 bytes of print data...
>D [09/Jan/2014:07:16:42 +0200] [Job 21] Read 8192 bytes of print data...
>d [09/Jan/2014:07:16:42 +0200] select_timeout: JobHistoryUpdate=0
>D [09/Jan/2014:07:16:42 +0200] [Job 21] Wrote 8192 bytes of print data...
>D [09/Jan/2014:07:16:42 +0200] [Job 21] Read 8192 bytes of print data...
>d [09/Jan/2014:07:16:42 +0200] select_timeout: JobHistoryUpdate=0
>D [09/Jan/2014:07:16:42 +0200] [Job 21] Wrote 8192 bytes of print data...
>D [09/Jan/2014:07:16:42 +0200] [Job 21] Read 8192 bytes of print data...
>d [09/Jan/2014:07:16:42 +0200] select_timeout: JobHistoryUpdate=0
>D [09/Jan/2014:07:16:42 +0200] [Job 21] kid4 exited with status 0
>D [09/Jan/2014:07:16:42 +0200] [Job 21] kid3 finished
>d [09/Jan/2014:07:16:42 +0200] select_timeout: JobHistoryUpdate=0
>D [09/Jan/2014:07:16:42 +0200] [Job 21] Kid3 exit status: 0
>D [09/Jan/2014:07:16:42 +0200] [Job 21] Closing foomatic-rip.
>d [09/Jan/2014:07:16:42 +0200] process_children()
>d [09/Jan/2014:07:16:42 +0200] cupsdFinishProcess(pid=14981, name=0x7fff7040df90, namelen=1024, job_id=0x7fff7040df8c(21)) = "/usr/lib/cups/filter/foomatic-rip"
>D [09/Jan/2014:07:16:42 +0200] [Job 21] PID 14981 (/usr/lib/cups/filter/foomatic-rip) exited with no errors.
>d [09/Jan/2014:07:16:42 +0200] select_timeout: JobHistoryUpdate=0
>D [09/Jan/2014:07:16:43 +0200] [Job 21] Wrote 8192 bytes of print data...
>D [09/Jan/2014:07:16:43 +0200] [Job 21] Read 8192 bytes of print data...
>d [09/Jan/2014:07:16:43 +0200] select_timeout: JobHistoryUpdate=0
>D [09/Jan/2014:07:16:43 +0200] [Job 21] Wrote 8192 bytes of print data...
>D [09/Jan/2014:07:16:43 +0200] [Job 21] Read 8192 bytes of print data...
>d [09/Jan/2014:07:16:43 +0200] select_timeout: JobHistoryUpdate=0
>D [09/Jan/2014:07:16:43 +0200] [Job 21] Wrote 8192 bytes of print data...
>D [09/Jan/2014:07:16:43 +0200] [Job 21] Read 8192 bytes of print data...
>d [09/Jan/2014:07:16:43 +0200] select_timeout: JobHistoryUpdate=0
>D [09/Jan/2014:07:16:44 +0200] [Job 21] Wrote 8192 bytes of print data...
>D [09/Jan/2014:07:16:44 +0200] [Job 21] Read 8192 bytes of print data...
>d [09/Jan/2014:07:16:44 +0200] select_timeout: JobHistoryUpdate=0
>D [09/Jan/2014:07:16:44 +0200] [Job 21] Wrote 8192 bytes of print data...
>D [09/Jan/2014:07:16:44 +0200] [Job 21] Read 8192 bytes of print data...
>d [09/Jan/2014:07:16:44 +0200] select_timeout: JobHistoryUpdate=0
>D [09/Jan/2014:07:16:45 +0200] [Job 21] Wrote 8192 bytes of print data...
>D [09/Jan/2014:07:16:45 +0200] [Job 21] Read 8192 bytes of print data...
>d [09/Jan/2014:07:16:45 +0200] select_timeout: JobHistoryUpdate=0
>D [09/Jan/2014:07:16:45 +0200] [Job 21] Wrote 8192 bytes of print data...
>D [09/Jan/2014:07:16:45 +0200] [Job 21] Read 8192 bytes of print data...
>d [09/Jan/2014:07:16:45 +0200] select_timeout: JobHistoryUpdate=0
>D [09/Jan/2014:07:16:45 +0200] [Job 21] Wrote 8192 bytes of print data...
>D [09/Jan/2014:07:16:45 +0200] [Job 21] Read 6928 bytes of print data...
>d [09/Jan/2014:07:16:45 +0200] select_timeout: JobHistoryUpdate=0
>D [09/Jan/2014:07:16:46 +0200] [Job 21] Wrote 6928 bytes of print data...
>D [09/Jan/2014:07:16:46 +0200] [Job 21] Sent 121616 bytes...
>d [09/Jan/2014:07:16:46 +0200] select_timeout: JobHistoryUpdate=0
>D [09/Jan/2014:07:16:46 +0200] [Job 21] Resetting printer.
>d [09/Jan/2014:07:16:46 +0200] process_children()
>d [09/Jan/2014:07:16:46 +0200] cupsdFinishProcess(pid=14982, name=0x7fff7040df90, namelen=1024, job_id=0x7fff7040df8c(21)) = "/usr/lib/cups/backend/usb"
>D [09/Jan/2014:07:16:46 +0200] [Job 21] PID 14982 (/usr/lib/cups/backend/usb) exited with no errors.
>d [09/Jan/2014:07:16:46 +0200] select_timeout: JobHistoryUpdate=0
>d [09/Jan/2014:07:16:46 +0200] finalize_job(job=0x7f3c9185cc30(21))
>d [09/Jan/2014:07:16:46 +0200] cupsdSetPrinterReasons(p=0x7f3c917fc2f0(LaserJet-4L),s="-connecting-to-device,cups-remote-pending,cups-remote-pending-held,cups-remote-processing,cups-remote-stopped,cups-remote-canceled,cups-remote-aborted,cups-remote-completed"
>d [09/Jan/2014:07:16:46 +0200] cupsdDeleteProfile(profile="(null)")
>d [09/Jan/2014:07:16:46 +0200] cupsdRemoveSelect(fd=17)
>d [09/Jan/2014:07:16:46 +0200] cupsdSetJobState(job=0x7f3c9185cc30(21), state=5, newstate=9, action=0, message="%s")
>d [09/Jan/2014:07:16:46 +0200] stop_job(job=0x7f3c9185cc30(21), action=0)
>D [09/Jan/2014:07:16:46 +0200] [Job 21] time-at-completed=1389244606
>d [09/Jan/2014:07:16:46 +0200] set_time: JobHistoryUpdate=1389331006
>d [09/Jan/2014:07:16:46 +0200] cupsdAddEvent(event=job-completed, dest=0x7f3c917fc2f0(LaserJet-4L), job=0x7f3c9185cc30(21), text="%s", ...)
>d [09/Jan/2014:07:16:46 +0200] cupsd_send_notification(sub=0x7f3c918027b0(52), event=0x7f3c9185c640(job-completed))
>d [09/Jan/2014:07:16:46 +0200] sub->pipe=18
>D [09/Jan/2014:07:16:46 +0200] cupsdMarkDirty(----S)
>D [09/Jan/2014:07:16:46 +0200] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
>I [09/Jan/2014:07:16:46 +0200] [Job 21] Job completed.
>D [09/Jan/2014:07:16:46 +0200] cupsdMarkDirty(---J-)
>D [09/Jan/2014:07:16:46 +0200] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
>D [09/Jan/2014:07:16:46 +0200] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
>d [09/Jan/2014:07:16:46 +0200] cupsdAddEvent(event=printer-state-changed, dest=0x7f3c917fc2f0(LaserJet-4L), job=(nil)(0), text="%s "%s" state changed to %s.", ...)
>d [09/Jan/2014:07:16:46 +0200] cupsd_send_notification(sub=0x7f3c918027b0(52), event=0x7f3c9185eeb0(printer-state-changed))
>d [09/Jan/2014:07:16:46 +0200] sub->pipe=18
>D [09/Jan/2014:07:16:46 +0200] cupsdMarkDirty(----S)
>D [09/Jan/2014:07:16:46 +0200] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
>d [09/Jan/2014:07:16:46 +0200] cupsdSetPrinterReasons(p=0x7f3c917fc2f0(LaserJet-4L),s="-paused"
>D [09/Jan/2014:07:16:46 +0200] cupsdMarkDirty(---J-)
>D [09/Jan/2014:07:16:46 +0200] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
>d [09/Jan/2014:07:16:46 +0200] cupsdCheckJobs: 0 active jobs, sleeping=0, reload=0, curtime=1389244606
>d [09/Jan/2014:07:16:46 +0200] cupsdCheckJobs: 0 active jobs, sleeping=0, reload=0, curtime=1389244606
>d [09/Jan/2014:07:16:46 +0200] select_timeout: JobHistoryUpdate=1389331006
>D [09/Jan/2014:07:16:46 +0200] [Notifier] state=3
>D [09/Jan/2014:07:16:46 +0200] [Notifier] JobCompleted
>d [09/Jan/2014:07:16:46 +0200] select_timeout: JobHistoryUpdate=1389331006
>D [09/Jan/2014:07:16:46 +0200] [Notifier] state=3
>D [09/Jan/2014:07:16:46 +0200] [Notifier] PrinterStateChanged
>d [09/Jan/2014:07:16:46 +0200] select_timeout: JobHistoryUpdate=1389331006
>d [09/Jan/2014:07:16:46 +0200] [Client 19] cupsdReadClient error=0, used=0, state=HTTP_STATE_WAITING, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=0, request=(nil)(), file=-1
>D [09/Jan/2014:07:16:46 +0200] [Client 19] POST / HTTP/1.1
>D [09/Jan/2014:07:16:46 +0200] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Printing jobs and dirty files"
>d [09/Jan/2014:07:16:46 +0200] cupsdFindBest: uri = "/"...
>d [09/Jan/2014:07:16:46 +0200] cupsdFindBest: Location /admin/conf Limit 7f
>d [09/Jan/2014:07:16:46 +0200] cupsdFindBest: Location /admin Limit 7f
>d [09/Jan/2014:07:16:46 +0200] cupsdFindBest: Location / Limit 7f
>d [09/Jan/2014:07:16:46 +0200] cupsdFindBest: best = /
>d [09/Jan/2014:07:16:46 +0200] [Client 19] con->uri="/", con->best=0x7f3c917ea030(/)
>d [09/Jan/2014:07:16:46 +0200] [Client 19] Authorization=""
>D [09/Jan/2014:07:16:46 +0200] [Client 19] No authentication data provided.
>d [09/Jan/2014:07:16:46 +0200] cupsdIsAuthorized: con->uri="/", con->best=0x7f3c917ea030(/)
>d [09/Jan/2014:07:16:46 +0200] cupsdIsAuthorized: level=CUPSD_AUTH_ANON, type=None, satisfy=CUPSD_AUTH_SATISFY_ALL, num_names=0
>d [09/Jan/2014:07:16:46 +0200] cupsdIsAuthorized: auth=CUPSD_AUTH_ALLOW...
>D [09/Jan/2014:07:16:46 +0200] [Client 19] 1.1 Get-Notifications 18
>d [09/Jan/2014:07:16:46 +0200] cupsdProcessIPPRequest(0x7f3c91864aa0[19]): operation_id = 001c
>D [09/Jan/2014:07:16:46 +0200] Get-Notifications /printers/
>d [09/Jan/2014:07:16:46 +0200] get_notifications(con=0x7f3c91864aa0[19])
>d [09/Jan/2014:07:16:46 +0200] cupsdFindPolicyOp(p=0x7f3c917eef10, op=1c(Get-Notifications))
>d [09/Jan/2014:07:16:46 +0200] cupsdFindPolicyOp: Found exact match...
>d [09/Jan/2014:07:16:46 +0200] cupsdIsAuthorized: con->uri="/", con->best=0x7f3c917f0ab0((null))
>d [09/Jan/2014:07:16:46 +0200] cupsdIsAuthorized: owner="fred"
>d [09/Jan/2014:07:16:46 +0200] cupsdIsAuthorized: level=CUPSD_AUTH_USER, type=None, satisfy=CUPSD_AUTH_SATISFY_ALL, num_names=2
>d [09/Jan/2014:07:16:46 +0200] cupsdIsAuthorized: op=1c(Get-Notifications)
>d [09/Jan/2014:07:16:46 +0200] cupsdIsAuthorized: auth=CUPSD_AUTH_ALLOW...
>D [09/Jan/2014:07:16:46 +0200] cupsdIsAuthorized: requesting-user-name="fred"
>d [09/Jan/2014:07:16:46 +0200] cupsdIsAuthorized: Checking user membership...
>d [09/Jan/2014:07:16:46 +0200] copy_attrs(to=0x7f3c91860640, from=0x7f3c9185f990, ra=(nil), group=7, quickcopy=0)
>d [09/Jan/2014:07:16:46 +0200] copy_attrs(to=0x7f3c91860640, from=0x7f3c9185eca0, ra=(nil), group=7, quickcopy=0)
>D [09/Jan/2014:07:16:46 +0200] [Client 19] Returning IPP successful-ok for Get-Notifications (/printers/) from localhost
>D [09/Jan/2014:07:16:46 +0200] [Client 19] Content-Length: 1101
>d [09/Jan/2014:07:16:46 +0200] cupsdAddSelect(fd=19, read_cb=0x7f3c8f7ddbc0, write_cb=0x7f3c8f7dd3c0, data=0x7f3c91864aa0)
>d [09/Jan/2014:07:16:46 +0200] select_timeout: JobHistoryUpdate=1389331006
>D [09/Jan/2014:07:16:46 +0200] [Client 19] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=1101, response=0x7f3c91860640(IPP_IDLE), pipe_pid=0, file=-1
>D [09/Jan/2014:07:16:46 +0200] [Client 19] Writing IPP response, ipp_state=DATA, old wused=0, new wused=0
>D [09/Jan/2014:07:16:46 +0200] [Client 19] bytes=0, http_state=0, data_remaining=0
>d [09/Jan/2014:07:16:46 +0200] cupsdAddSelect(fd=19, read_cb=0x7f3c8f7ddbc0, write_cb=(nil), data=0x7f3c91864aa0)
>D [09/Jan/2014:07:16:46 +0200] [Client 19] Waiting for request.
>D [09/Jan/2014:07:16:46 +0200] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
>d [09/Jan/2014:07:16:46 +0200] select_timeout: JobHistoryUpdate=1389331006
>d [09/Jan/2014:07:16:46 +0200] cupsdAcceptClient(lis=0x7f3c917eeae0(3)) Clients=4
>D [09/Jan/2014:07:16:46 +0200] cupsdAcceptClient: skipping getpeercon()
>D [09/Jan/2014:07:16:46 +0200] [Client 17] Accepted from localhost (Domain)
>d [09/Jan/2014:07:16:46 +0200] cupsdAddSelect(fd=17, read_cb=0x7f3c8f7ddbc0, write_cb=(nil), data=0x7f3c91876a50)
>D [09/Jan/2014:07:16:46 +0200] [Client 17] Waiting for request.
>d [09/Jan/2014:07:16:46 +0200] select_timeout: JobHistoryUpdate=1389331006
>d [09/Jan/2014:07:16:46 +0200] [Client 17] cupsdReadClient error=0, used=0, state=HTTP_STATE_WAITING, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=0, request=(nil)(), file=-1
>D [09/Jan/2014:07:16:46 +0200] [Client 17] POST / HTTP/1.1
>D [09/Jan/2014:07:16:46 +0200] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
>d [09/Jan/2014:07:16:46 +0200] cupsdFindBest: uri = "/"...
>d [09/Jan/2014:07:16:46 +0200] cupsdFindBest: Location /admin/conf Limit 7f
>d [09/Jan/2014:07:16:46 +0200] cupsdFindBest: Location /admin Limit 7f
>d [09/Jan/2014:07:16:46 +0200] cupsdFindBest: Location / Limit 7f
>d [09/Jan/2014:07:16:46 +0200] cupsdFindBest: best = /
>d [09/Jan/2014:07:16:46 +0200] [Client 17] con->uri="/", con->best=0x7f3c917ea030(/)
>d [09/Jan/2014:07:16:46 +0200] [Client 17] Authorization=""
>D [09/Jan/2014:07:16:46 +0200] [Client 17] No authentication data provided.
>d [09/Jan/2014:07:16:46 +0200] cupsdIsAuthorized: con->uri="/", con->best=0x7f3c917ea030(/)
>d [09/Jan/2014:07:16:46 +0200] cupsdIsAuthorized: level=CUPSD_AUTH_ANON, type=None, satisfy=CUPSD_AUTH_SATISFY_ALL, num_names=0
>d [09/Jan/2014:07:16:46 +0200] cupsdIsAuthorized: auth=CUPSD_AUTH_ALLOW...
>D [09/Jan/2014:07:16:46 +0200] [Client 17] 1.1 Get-Job-Attributes 19
>d [09/Jan/2014:07:16:46 +0200] cupsdProcessIPPRequest(0x7f3c91876a50[17]): operation_id = 0009
>D [09/Jan/2014:07:16:46 +0200] Get-Job-Attributes ipp://localhost/jobs/21
>d [09/Jan/2014:07:16:46 +0200] get_job_attrs(0x7f3c91876a50[17], ipp://localhost/jobs/21)
>d [09/Jan/2014:07:16:46 +0200] cupsdFindPolicyOp(p=0x7f3c917eef10, op=9(Get-Job-Attributes))
>d [09/Jan/2014:07:16:46 +0200] cupsdFindPolicyOp: Found wildcard match...
>d [09/Jan/2014:07:16:46 +0200] cupsdIsAuthorized: con->uri="/", con->best=0x7f3c917f3a30((null))
>d [09/Jan/2014:07:16:46 +0200] cupsdIsAuthorized: owner="fred"
>d [09/Jan/2014:07:16:46 +0200] cupsdIsAuthorized: level=CUPSD_AUTH_ANON, type=None, satisfy=CUPSD_AUTH_SATISFY_ALL, num_names=0
>d [09/Jan/2014:07:16:46 +0200] cupsdIsAuthorized: op=0(0x0000)
>d [09/Jan/2014:07:16:46 +0200] cupsdIsAuthorized: auth=CUPSD_AUTH_ALLOW...
>d [09/Jan/2014:07:16:46 +0200] copy_attrs(to=0x7f3c91860230, from=0x7f3c918573d0, ra=0x7f3c91869fd0, group=2, quickcopy=0)
>D [09/Jan/2014:07:16:46 +0200] [Client 17] Returning IPP successful-ok for Get-Job-Attributes (ipp://localhost/jobs/21) from localhost
>D [09/Jan/2014:07:16:46 +0200] [Client 17] Content-Length: 110
>d [09/Jan/2014:07:16:46 +0200] cupsdAddSelect(fd=17, read_cb=0x7f3c8f7ddbc0, write_cb=0x7f3c8f7dd3c0, data=0x7f3c91876a50)
>d [09/Jan/2014:07:16:46 +0200] select_timeout: JobHistoryUpdate=1389331006
>D [09/Jan/2014:07:16:46 +0200] [Client 17] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=110, response=0x7f3c91860230(IPP_IDLE), pipe_pid=0, file=-1
>D [09/Jan/2014:07:16:46 +0200] [Client 17] Writing IPP response, ipp_state=DATA, old wused=0, new wused=0
>D [09/Jan/2014:07:16:46 +0200] [Client 17] bytes=0, http_state=0, data_remaining=0
>d [09/Jan/2014:07:16:46 +0200] cupsdAddSelect(fd=17, read_cb=0x7f3c8f7ddbc0, write_cb=(nil), data=0x7f3c91876a50)
>D [09/Jan/2014:07:16:46 +0200] [Client 17] Waiting for request.
>D [09/Jan/2014:07:16:46 +0200] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
>d [09/Jan/2014:07:16:46 +0200] select_timeout: JobHistoryUpdate=1389331006
>d [09/Jan/2014:07:16:46 +0200] [Client 19] cupsdReadClient error=0, used=0, state=HTTP_STATE_WAITING, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=0, request=(nil)(), file=-1
>D [09/Jan/2014:07:16:46 +0200] [Client 19] POST / HTTP/1.1
>D [09/Jan/2014:07:16:46 +0200] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
>d [09/Jan/2014:07:16:46 +0200] cupsdFindBest: uri = "/"...
>d [09/Jan/2014:07:16:46 +0200] cupsdFindBest: Location /admin/conf Limit 7f
>d [09/Jan/2014:07:16:46 +0200] cupsdFindBest: Location /admin Limit 7f
>d [09/Jan/2014:07:16:46 +0200] cupsdFindBest: Location / Limit 7f
>d [09/Jan/2014:07:16:46 +0200] cupsdFindBest: best = /
>d [09/Jan/2014:07:16:46 +0200] [Client 19] con->uri="/", con->best=0x7f3c917ea030(/)
>d [09/Jan/2014:07:16:46 +0200] [Client 19] Authorization=""
>D [09/Jan/2014:07:16:46 +0200] [Client 19] No authentication data provided.
>d [09/Jan/2014:07:16:46 +0200] cupsdIsAuthorized: con->uri="/", con->best=0x7f3c917ea030(/)
>d [09/Jan/2014:07:16:46 +0200] cupsdIsAuthorized: level=CUPSD_AUTH_ANON, type=None, satisfy=CUPSD_AUTH_SATISFY_ALL, num_names=0
>d [09/Jan/2014:07:16:46 +0200] cupsdIsAuthorized: auth=CUPSD_AUTH_ALLOW...
>D [09/Jan/2014:07:16:46 +0200] [Client 19] 1.1 Get-Notifications 20
>d [09/Jan/2014:07:16:46 +0200] cupsdProcessIPPRequest(0x7f3c91864aa0[19]): operation_id = 001c
>D [09/Jan/2014:07:16:46 +0200] Get-Notifications /printers/
>d [09/Jan/2014:07:16:46 +0200] get_notifications(con=0x7f3c91864aa0[19])
>d [09/Jan/2014:07:16:46 +0200] cupsdFindPolicyOp(p=0x7f3c917eef10, op=1c(Get-Notifications))
>d [09/Jan/2014:07:16:46 +0200] cupsdFindPolicyOp: Found exact match...
>d [09/Jan/2014:07:16:46 +0200] cupsdIsAuthorized: con->uri="/", con->best=0x7f3c917f0ab0((null))
>d [09/Jan/2014:07:16:46 +0200] cupsdIsAuthorized: owner="fred"
>d [09/Jan/2014:07:16:46 +0200] cupsdIsAuthorized: level=CUPSD_AUTH_USER, type=None, satisfy=CUPSD_AUTH_SATISFY_ALL, num_names=2
>d [09/Jan/2014:07:16:46 +0200] cupsdIsAuthorized: op=1c(Get-Notifications)
>d [09/Jan/2014:07:16:46 +0200] cupsdIsAuthorized: auth=CUPSD_AUTH_ALLOW...
>D [09/Jan/2014:07:16:46 +0200] cupsdIsAuthorized: requesting-user-name="fred"
>d [09/Jan/2014:07:16:46 +0200] cupsdIsAuthorized: Checking user membership...
>D [09/Jan/2014:07:16:46 +0200] [Client 19] Returning IPP successful-ok for Get-Notifications (/printers/) from localhost
>D [09/Jan/2014:07:16:46 +0200] [Client 19] Content-Length: 127
>d [09/Jan/2014:07:16:46 +0200] cupsdAddSelect(fd=19, read_cb=0x7f3c8f7ddbc0, write_cb=0x7f3c8f7dd3c0, data=0x7f3c91864aa0)
>d [09/Jan/2014:07:16:46 +0200] select_timeout: JobHistoryUpdate=1389331006
>D [09/Jan/2014:07:16:46 +0200] [Client 19] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=127, response=0x7f3c9186a0b0(IPP_IDLE), pipe_pid=0, file=-1
>D [09/Jan/2014:07:16:46 +0200] [Client 19] Writing IPP response, ipp_state=DATA, old wused=0, new wused=0
>D [09/Jan/2014:07:16:46 +0200] [Client 19] bytes=0, http_state=0, data_remaining=0
>d [09/Jan/2014:07:16:46 +0200] cupsdAddSelect(fd=19, read_cb=0x7f3c8f7ddbc0, write_cb=(nil), data=0x7f3c91864aa0)
>D [09/Jan/2014:07:16:46 +0200] [Client 19] Waiting for request.
>D [09/Jan/2014:07:16:46 +0200] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
>d [09/Jan/2014:07:16:46 +0200] select_timeout: JobHistoryUpdate=1389331006
>d [09/Jan/2014:07:16:47 +0200] select_timeout: JobHistoryUpdate=1389331006
>d [09/Jan/2014:07:16:47 +0200] select_timeout(0): 23 seconds to write dirty config/state files
>I [09/Jan/2014:07:17:10 +0200] Saving job.cache...
>d [09/Jan/2014:07:17:10 +0200] cupsdSaveJob(job=0x7f3c9185cc30(21)): job->attrs=0x7f3c918573d0
>I [09/Jan/2014:07:17:10 +0200] Saving subscriptions.conf...
>D [09/Jan/2014:07:17:10 +0200] cupsdSetBusyState: newbusy="Not busy", busy="Dirty files"
>d [09/Jan/2014:07:17:10 +0200] cupsdCheckJobs: 0 active jobs, sleeping=0, reload=0, curtime=1389244630
>D [09/Jan/2014:07:17:10 +0200] Report: clients=5
>D [09/Jan/2014:07:17:10 +0200] Report: jobs=4
>D [09/Jan/2014:07:17:10 +0200] Report: jobs-active=0
>D [09/Jan/2014:07:17:10 +0200] Report: printers=1
>D [09/Jan/2014:07:17:10 +0200] Report: stringpool-string-count=1800
>D [09/Jan/2014:07:17:10 +0200] Report: stringpool-alloc-bytes=10320
>D [09/Jan/2014:07:17:10 +0200] Report: stringpool-total-bytes=34424
>d [09/Jan/2014:07:17:10 +0200] select_timeout: JobHistoryUpdate=1389331006
>d [09/Jan/2014:07:17:10 +0200] select_timeout(0): 270 seconds to timeout a client connection

Actions: View

Attachments on bug 1048495: 847483