Login
[x]
Log in using an account from:
Fedora Account System
Red Hat Associate
Red Hat Customer
Or login using a Red Hat Bugzilla account
Forgot Password
Login:
Hide Forgot
Create an Account
Red Hat Bugzilla – Attachment 847483 Details for
Bug 1048495
LaserJet 4L - Last page doesn't get printed without manual form feed
[?]
New
Simple Search
Advanced Search
My Links
Browse
Requests
Reports
Current State
Search
Tabular reports
Graphical reports
Duplicates
Other Reports
User Changes
Plotly Reports
Bug Status
Bug Severity
Non-Defaults
|
Product Dashboard
Help
Page Help!
Bug Writing Guidelines
What's new
Browser Support Policy
5.0.4.rh83 Release notes
FAQ
Guides index
User guide
Web Services
Contact
Legal
This site requires JavaScript to be enabled to function correctly, please enable it.
/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:
/var/log/cups/error_log
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
You cannot view the attachment while viewing its details because your browser does not support IFRAMEs.
View the attachment on a separate page
.
View Attachment As Raw
Actions:
View
Attachments on
bug 1048495
: 847483