W [02/May/2012:08:04:58 +0100] failed to CreateProfile: org.freedesktop.ColorManager.AlreadyExists:profile id 'LaserJet-4L-Gray..' already exists
W [02/May/2012:08:04:58 +0100] failed to CreateDevice: org.freedesktop.ColorManager.AlreadyExists:device id 'cups-LaserJet-4L' already exists
I [02/May/2012:18:41:30 +0100] Remote access is disabled.
D [02/May/2012:18:41:30 +0100] Added auto ServerAlias al-desktop
I [02/May/2012:18:41:30 +0100] Loaded configuration file "/etc/cups/cupsd.conf"
I [02/May/2012:18:41:30 +0100] Using default TempDir of /var/spool/cups/tmp...
I [02/May/2012:18:41:30 +0100] Configured for up to 100 clients.
I [02/May/2012:18:41:30 +0100] Allowing up to 100 client connections per host.
I [02/May/2012:18:41:30 +0100] Using policy "default" as the default.
D [02/May/2012:18:41:30 +0100] load_ppd: Loading /var/cache/cups/LaserJet-4L.data...
D [02/May/2012:18:41:30 +0100] Calling DeleteDevice(cups-LaserJet-4L)
D [02/May/2012:18:41:30 +0100] failed to DeleteDevice: org.freedesktop.DBus.Error.InvalidArgs:Type of message, `(s)', does not match expected type `(o)'
D [02/May/2012:18:41:30 +0100] Using profile id of LaserJet-4L-Gray..
D [02/May/2012:18:41:30 +0100] Calling CreateProfile(LaserJet-4L-Gray..,temp)
W [02/May/2012:18:41:30 +0100] failed to CreateProfile: org.freedesktop.ColorManager.AlreadyExists:profile id 'LaserJet-4L-Gray..' already exists
I [02/May/2012:18:41:30 +0100] Registering ICC color profiles for "LaserJet-4L"
D [02/May/2012:18:41:30 +0100] Calling CreateDevice(cups-LaserJet-4L,temp)
W [02/May/2012:18:41:30 +0100] failed to CreateDevice: org.freedesktop.ColorManager.AlreadyExists:device id 'cups-LaserJet-4L' already exists
D [02/May/2012:18:41:30 +0100] cupsdRegisterPrinter(p=0x7f82a6ff0850(LaserJet-4L))
D [02/May/2012:18:41:30 +0100] cupsdMarkDirty(---p--)
D [02/May/2012:18:41:30 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Not busy"
I [02/May/2012:18:41:30 +0100] Partial reload complete.
I [02/May/2012:18:41:30 +0100] Listening to [v1.::1]:631 on fd 9...
I [02/May/2012:18:41:30 +0100] Listening to 127.0.0.1:631 on fd 10...
I [02/May/2012:18:41:30 +0100] Listening to /var/run/cups/cups.sock:631 on fd 11...
I [02/May/2012:18:41:30 +0100] Resuming new connection processing...
D [02/May/2012:18:41:30 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [02/May/2012:18:41:30 +0100] Notifier dbus started - PID = 14155
D [02/May/2012:18:41:30 +0100] cupsdMarkDirty(-----S)
D [02/May/2012:18:41:30 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [02/May/2012:18:41:30 +0100] Report: clients=0
D [02/May/2012:18:41:30 +0100] Report: jobs=0
D [02/May/2012:18:41:30 +0100] Report: jobs-active=0
D [02/May/2012:18:41:30 +0100] Report: printers=1
D [02/May/2012:18:41:30 +0100] Report: printers-implicit=0
D [02/May/2012:18:41:30 +0100] Report: stringpool-string-count=2470
D [02/May/2012:18:41:30 +0100] Report: stringpool-alloc-bytes=9208
D [02/May/2012:18:41:30 +0100] Report: stringpool-total-bytes=40472
D [02/May/2012:18:41:30 +0100] PID 5490 (/usr/lib/cups/notifier/dbus) was terminated normally with signal 15.
D [02/May/2012:18:41:30 +0100] [Notifier] state=3
D [02/May/2012:18:41:30 +0100] [Notifier] Connected to D-BUS
D [02/May/2012:18:41:37 +0100] cupsdAcceptClient: 17 from localhost (Domain)
D [02/May/2012:18:41:37 +0100] cupsdReadClient: 17 PUT /admin/conf/cupsd.conf HTTP/1.1
D [02/May/2012:18:41:37 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [02/May/2012:18:41:37 +0100] cupsdAuthorize: No authentication data provided.
D [02/May/2012:18:41:37 +0100] cupsdIsAuthorized: username=""
D [02/May/2012:18:41:37 +0100] cupsdSendHeader: 17 WWW-Authenticate: Basic realm="CUPS", trc="y"
D [02/May/2012:18:41:37 +0100] cupsdCloseClient: 17
D [02/May/2012:18:41:37 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [02/May/2012:18:41:37 +0100] cupsdAcceptClient: 17 from localhost (Domain)
D [02/May/2012:18:41:37 +0100] cupsdReadClient: 17 PUT /admin/conf/cupsd.conf HTTP/1.1
D [02/May/2012:18:41:37 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [02/May/2012:18:41:37 +0100] cupsdAuthorize: Authorized as al using PeerCred
D [02/May/2012:18:41:37 +0100] cupsdIsAuthorized: username="al"
I [02/May/2012:18:41:37 +0100] Installing config file "/etc/cups/cupsd.conf"...
D [02/May/2012:18:41:38 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [02/May/2012:18:41:38 +0100] cupsdCloseClient: 17
D [02/May/2012:18:41:38 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
I [02/May/2012:18:41:38 +0100] Generating printcap /var/run/cups/printcap...
I [02/May/2012:18:41:38 +0100] Saving subscriptions.conf...
D [02/May/2012:18:41:38 +0100] cupsdSetBusyState: newbusy="Not busy", busy="Dirty files"
I [02/May/2012:18:41:38 +0100] Remote access is disabled.
D [02/May/2012:18:41:38 +0100] Added auto ServerAlias al-desktop
I [02/May/2012:18:41:38 +0100] Loaded configuration file "/etc/cups/cupsd.conf"
I [02/May/2012:18:41:38 +0100] Using default TempDir of /var/spool/cups/tmp...
I [02/May/2012:18:41:38 +0100] Configured for up to 100 clients.
I [02/May/2012:18:41:38 +0100] Allowing up to 100 client connections per host.
I [02/May/2012:18:41:38 +0100] Using policy "default" as the default.
D [02/May/2012:18:41:38 +0100] load_ppd: Loading /var/cache/cups/LaserJet-4L.data...
D [02/May/2012:18:41:38 +0100] Calling DeleteDevice(cups-LaserJet-4L)
D [02/May/2012:18:41:38 +0100] failed to DeleteDevice: org.freedesktop.DBus.Error.InvalidArgs:Type of message, `(s)', does not match expected type `(o)'
D [02/May/2012:18:41:38 +0100] Using profile id of LaserJet-4L-Gray..
D [02/May/2012:18:41:38 +0100] Calling CreateProfile(LaserJet-4L-Gray..,temp)
W [02/May/2012:18:41:38 +0100] failed to CreateProfile: org.freedesktop.ColorManager.AlreadyExists:profile id 'LaserJet-4L-Gray..' already exists
I [02/May/2012:18:41:38 +0100] Registering ICC color profiles for "LaserJet-4L"
D [02/May/2012:18:41:38 +0100] Calling CreateDevice(cups-LaserJet-4L,temp)
W [02/May/2012:18:41:38 +0100] failed to CreateDevice: org.freedesktop.ColorManager.AlreadyExists:device id 'cups-LaserJet-4L' already exists
D [02/May/2012:18:41:38 +0100] cupsdRegisterPrinter(p=0x7f82a6ff0850(LaserJet-4L))
D [02/May/2012:18:41:38 +0100] cupsdMarkDirty(---p--)
D [02/May/2012:18:41:38 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Not busy"
I [02/May/2012:18:41:38 +0100] Partial reload complete.
I [02/May/2012:18:41:38 +0100] Listening to [v1.::1]:631 on fd 9...
I [02/May/2012:18:41:38 +0100] Listening to 127.0.0.1:631 on fd 10...
I [02/May/2012:18:41:38 +0100] Listening to /var/run/cups/cups.sock:631 on fd 11...
I [02/May/2012:18:41:38 +0100] Resuming new connection processing...
D [02/May/2012:18:41:38 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [02/May/2012:18:41:38 +0100] Notifier dbus started - PID = 14158
D [02/May/2012:18:41:38 +0100] cupsdMarkDirty(-----S)
D [02/May/2012:18:41:38 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [02/May/2012:18:41:38 +0100] PID 14155 (/usr/lib/cups/notifier/dbus) was terminated normally with signal 15.
D [02/May/2012:18:41:38 +0100] [Notifier] state=3
D [02/May/2012:18:41:38 +0100] [Notifier] Connected to D-BUS
D [02/May/2012:18:41:49 +0100] cupsdAcceptClient: 17 from localhost (Domain)
D [02/May/2012:18:41:49 +0100] cupsdReadClient: 17 WAITING Closing on EOF
D [02/May/2012:18:41:49 +0100] cupsdCloseClient: 17
D [02/May/2012:18:41:49 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [02/May/2012:18:41:49 +0100] cupsdAcceptClient: 17 from localhost (Domain)
D [02/May/2012:18:41:49 +0100] cupsdReadClient: 17 POST / HTTP/1.1
D [02/May/2012:18:41:49 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [02/May/2012:18:41:49 +0100] cupsdAuthorize: No authentication data provided.
D [02/May/2012:18:41:49 +0100] cupsdReadClient: 17 1.1 CUPS-Get-Printers 1
D [02/May/2012:18:41:49 +0100] CUPS-Get-Printers
D [02/May/2012:18:41:49 +0100] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost
D [02/May/2012:18:41:49 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [02/May/2012:18:41:49 +0100] cupsdAcceptClient: 19 from localhost (Domain)
D [02/May/2012:18:41:49 +0100] cupsdReadClient: 17 WAITING Closing on EOF
D [02/May/2012:18:41:49 +0100] cupsdCloseClient: 17
D [02/May/2012:18:41:49 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [02/May/2012:18:41:49 +0100] cupsdReadClient: 19 GET /printers/LaserJet-4L.ppd HTTP/1.1
D [02/May/2012:18:41:49 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [02/May/2012:18:41:49 +0100] cupsdAuthorize: No authentication data provided.
D [02/May/2012:18:41:49 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [02/May/2012:18:41:49 +0100] cupsdReadClient: 19 WAITING Closing on EOF
D [02/May/2012:18:41:49 +0100] cupsdCloseClient: 19
D [02/May/2012:18:41:49 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [02/May/2012:18:41:49 +0100] cupsdAcceptClient: 17 from localhost (Domain)
D [02/May/2012:18:41:49 +0100] cupsdAcceptClient: 19 from localhost (Domain)
D [02/May/2012:18:41:49 +0100] cupsdReadClient: 17 WAITING Closing on EOF
D [02/May/2012:18:41:49 +0100] cupsdCloseClient: 17
D [02/May/2012:18:41:49 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [02/May/2012:18:41:49 +0100] cupsdReadClient: 19 POST / HTTP/1.1
D [02/May/2012:18:41:49 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [02/May/2012:18:41:49 +0100] cupsdAuthorize: No authentication data provided.
D [02/May/2012:18:41:49 +0100] cupsdReadClient: 19 1.1 CUPS-Get-Printers 1
D [02/May/2012:18:41:49 +0100] CUPS-Get-Printers
D [02/May/2012:18:41:49 +0100] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost
D [02/May/2012:18:41:49 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [02/May/2012:18:41:49 +0100] cupsdReadClient: 19 WAITING Closing on EOF
D [02/May/2012:18:41:49 +0100] cupsdCloseClient: 19
D [02/May/2012:18:41:49 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [02/May/2012:18:41:49 +0100] cupsdAcceptClient: 17 from localhost (Domain)
D [02/May/2012:18:41:49 +0100] cupsdAcceptClient: 19 from localhost (Domain)
D [02/May/2012:18:41:49 +0100] cupsdReadClient: 17 WAITING Closing on EOF
D [02/May/2012:18:41:49 +0100] cupsdCloseClient: 17
D [02/May/2012:18:41:49 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [02/May/2012:18:41:49 +0100] cupsdReadClient: 19 POST / HTTP/1.1
D [02/May/2012:18:41:49 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [02/May/2012:18:41:49 +0100] cupsdAuthorize: No authentication data provided.
D [02/May/2012:18:41:49 +0100] cupsdReadClient: 19 1.1 CUPS-Get-Printers 1
D [02/May/2012:18:41:49 +0100] CUPS-Get-Printers
D [02/May/2012:18:41:49 +0100] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost
D [02/May/2012:18:41:49 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [02/May/2012:18:41:49 +0100] cupsdReadClient: 19 WAITING Closing on EOF
D [02/May/2012:18:41:49 +0100] cupsdCloseClient: 19
D [02/May/2012:18:41:49 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [02/May/2012:18:41:49 +0100] cupsdAcceptClient: 17 from localhost (Domain)
D [02/May/2012:18:41:49 +0100] cupsdAcceptClient: 19 from localhost (Domain)
D [02/May/2012:18:41:49 +0100] cupsdReadClient: 17 WAITING Closing on EOF
D [02/May/2012:18:41:49 +0100] cupsdCloseClient: 17
D [02/May/2012:18:41:49 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [02/May/2012:18:41:49 +0100] cupsdReadClient: 19 POST / HTTP/1.1
D [02/May/2012:18:41:49 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [02/May/2012:18:41:49 +0100] cupsdAuthorize: No authentication data provided.
D [02/May/2012:18:41:49 +0100] cupsdReadClient: 19 1.1 CUPS-Get-Printers 1
D [02/May/2012:18:41:49 +0100] CUPS-Get-Printers
D [02/May/2012:18:41:49 +0100] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost
D [02/May/2012:18:41:49 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [02/May/2012:18:41:49 +0100] cupsdReadClient: 19 WAITING Closing on EOF
D [02/May/2012:18:41:49 +0100] cupsdCloseClient: 19
D [02/May/2012:18:41:49 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [02/May/2012:18:41:50 +0100] cupsdAcceptClient: 17 from localhost (Domain)
D [02/May/2012:18:41:50 +0100] cupsdAcceptClient: 19 from localhost (Domain)
D [02/May/2012:18:41:50 +0100] cupsdReadClient: 17 WAITING Closing on EOF
D [02/May/2012:18:41:50 +0100] cupsdCloseClient: 17
D [02/May/2012:18:41:50 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [02/May/2012:18:41:50 +0100] cupsdReadClient: 19 POST / HTTP/1.1
D [02/May/2012:18:41:50 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [02/May/2012:18:41:50 +0100] cupsdAuthorize: No authentication data provided.
D [02/May/2012:18:41:50 +0100] cupsdReadClient: 19 1.1 CUPS-Get-Printers 1
D [02/May/2012:18:41:50 +0100] CUPS-Get-Printers
D [02/May/2012:18:41:50 +0100] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost
D [02/May/2012:18:41:50 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [02/May/2012:18:41:50 +0100] cupsdReadClient: 19 WAITING Closing on EOF
D [02/May/2012:18:41:50 +0100] cupsdCloseClient: 19
D [02/May/2012:18:41:50 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [02/May/2012:18:41:50 +0100] cupsdAcceptClient: 17 from localhost (Domain)
D [02/May/2012:18:41:50 +0100] cupsdAcceptClient: 19 from localhost (Domain)
D [02/May/2012:18:41:50 +0100] cupsdReadClient: 17 WAITING Closing on EOF
D [02/May/2012:18:41:50 +0100] cupsdCloseClient: 17
D [02/May/2012:18:41:50 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [02/May/2012:18:41:50 +0100] cupsdReadClient: 19 POST / HTTP/1.1
D [02/May/2012:18:41:50 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [02/May/2012:18:41:50 +0100] cupsdAuthorize: No authentication data provided.
D [02/May/2012:18:41:50 +0100] cupsdReadClient: 19 1.1 CUPS-Get-Printers 1
D [02/May/2012:18:41:50 +0100] CUPS-Get-Printers
D [02/May/2012:18:41:50 +0100] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost
D [02/May/2012:18:41:50 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [02/May/2012:18:41:50 +0100] cupsdReadClient: 19 WAITING Closing on EOF
D [02/May/2012:18:41:50 +0100] cupsdCloseClient: 19
D [02/May/2012:18:41:50 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [02/May/2012:18:41:50 +0100] cupsdAcceptClient: 17 from localhost (Domain)
D [02/May/2012:18:41:50 +0100] cupsdAcceptClient: 19 from localhost (Domain)
D [02/May/2012:18:41:50 +0100] cupsdReadClient: 17 WAITING Closing on EOF
D [02/May/2012:18:41:50 +0100] cupsdCloseClient: 17
D [02/May/2012:18:41:50 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [02/May/2012:18:41:50 +0100] cupsdReadClient: 19 POST / HTTP/1.1
D [02/May/2012:18:41:50 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [02/May/2012:18:41:50 +0100] cupsdAuthorize: No authentication data provided.
D [02/May/2012:18:41:50 +0100] cupsdReadClient: 19 1.1 CUPS-Get-Printers 1
D [02/May/2012:18:41:50 +0100] CUPS-Get-Printers
D [02/May/2012:18:41:50 +0100] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost
D [02/May/2012:18:41:50 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [02/May/2012:18:41:50 +0100] cupsdReadClient: 19 WAITING Closing on EOF
D [02/May/2012:18:41:50 +0100] cupsdCloseClient: 19
D [02/May/2012:18:41:50 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [02/May/2012:18:41:50 +0100] cupsdAcceptClient: 17 from localhost (Domain)
D [02/May/2012:18:41:50 +0100] cupsdAcceptClient: 19 from localhost (Domain)
D [02/May/2012:18:41:50 +0100] cupsdReadClient: 17 WAITING Closing on EOF
D [02/May/2012:18:41:50 +0100] cupsdCloseClient: 17
D [02/May/2012:18:41:50 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [02/May/2012:18:41:50 +0100] cupsdReadClient: 19 POST / HTTP/1.1
D [02/May/2012:18:41:50 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [02/May/2012:18:41:50 +0100] cupsdAuthorize: No authentication data provided.
D [02/May/2012:18:41:50 +0100] cupsdReadClient: 19 1.1 CUPS-Get-Printers 1
D [02/May/2012:18:41:50 +0100] CUPS-Get-Printers
D [02/May/2012:18:41:50 +0100] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost
D [02/May/2012:18:41:50 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [02/May/2012:18:41:50 +0100] cupsdReadClient: 19 WAITING Closing on EOF
D [02/May/2012:18:41:50 +0100] cupsdCloseClient: 19
D [02/May/2012:18:41:50 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [02/May/2012:18:41:50 +0100] cupsdAcceptClient: 17 from localhost (Domain)
D [02/May/2012:18:41:50 +0100] cupsdAcceptClient: 19 from localhost (Domain)
D [02/May/2012:18:41:50 +0100] cupsdReadClient: 17 WAITING Closing on EOF
D [02/May/2012:18:41:50 +0100] cupsdCloseClient: 17
D [02/May/2012:18:41:50 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [02/May/2012:18:41:50 +0100] cupsdReadClient: 19 POST / HTTP/1.1
D [02/May/2012:18:41:50 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [02/May/2012:18:41:50 +0100] cupsdAuthorize: No authentication data provided.
D [02/May/2012:18:41:50 +0100] cupsdReadClient: 19 1.1 CUPS-Get-Printers 1
D [02/May/2012:18:41:50 +0100] CUPS-Get-Printers
D [02/May/2012:18:41:50 +0100] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost
D [02/May/2012:18:41:50 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [02/May/2012:18:41:50 +0100] cupsdReadClient: 19 WAITING Closing on EOF
D [02/May/2012:18:41:50 +0100] cupsdCloseClient: 19
D [02/May/2012:18:41:50 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [02/May/2012:18:41:51 +0100] cupsdAcceptClient: 17 from localhost (Domain)
D [02/May/2012:18:41:51 +0100] cupsdAcceptClient: 19 from localhost (Domain)
D [02/May/2012:18:41:51 +0100] cupsdReadClient: 17 WAITING Closing on EOF
D [02/May/2012:18:41:51 +0100] cupsdCloseClient: 17
D [02/May/2012:18:41:51 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [02/May/2012:18:41:51 +0100] cupsdReadClient: 19 POST / HTTP/1.1
D [02/May/2012:18:41:51 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [02/May/2012:18:41:51 +0100] cupsdAuthorize: No authentication data provided.
D [02/May/2012:18:41:51 +0100] cupsdReadClient: 19 1.1 CUPS-Get-Printers 1
D [02/May/2012:18:41:51 +0100] CUPS-Get-Printers
D [02/May/2012:18:41:51 +0100] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost
D [02/May/2012:18:41:51 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [02/May/2012:18:41:51 +0100] cupsdReadClient: 19 WAITING Closing on EOF
D [02/May/2012:18:41:51 +0100] cupsdCloseClient: 19
D [02/May/2012:18:41:51 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [02/May/2012:18:41:51 +0100] cupsdAcceptClient: 17 from localhost (Domain)
D [02/May/2012:18:41:51 +0100] cupsdAcceptClient: 19 from localhost (Domain)
D [02/May/2012:18:41:51 +0100] cupsdReadClient: 17 WAITING Closing on EOF
D [02/May/2012:18:41:51 +0100] cupsdCloseClient: 17
D [02/May/2012:18:41:51 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [02/May/2012:18:41:51 +0100] cupsdReadClient: 19 POST / HTTP/1.1
D [02/May/2012:18:41:51 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [02/May/2012:18:41:51 +0100] cupsdAuthorize: No authentication data provided.
D [02/May/2012:18:41:51 +0100] cupsdReadClient: 19 1.1 CUPS-Get-Printers 1
D [02/May/2012:18:41:51 +0100] CUPS-Get-Printers
D [02/May/2012:18:41:51 +0100] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost
D [02/May/2012:18:41:51 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [02/May/2012:18:41:51 +0100] cupsdReadClient: 19 WAITING Closing on EOF
D [02/May/2012:18:41:51 +0100] cupsdCloseClient: 19
D [02/May/2012:18:41:51 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [02/May/2012:18:41:51 +0100] cupsdAcceptClient: 17 from localhost (Domain)
D [02/May/2012:18:41:51 +0100] cupsdAcceptClient: 19 from localhost (Domain)
D [02/May/2012:18:41:51 +0100] cupsdReadClient: 17 WAITING Closing on EOF
D [02/May/2012:18:41:51 +0100] cupsdCloseClient: 17
D [02/May/2012:18:41:51 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [02/May/2012:18:41:51 +0100] cupsdReadClient: 19 POST / HTTP/1.1
D [02/May/2012:18:41:51 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [02/May/2012:18:41:51 +0100] cupsdAuthorize: No authentication data provided.
D [02/May/2012:18:41:51 +0100] cupsdReadClient: 19 1.1 CUPS-Get-Printers 1
D [02/May/2012:18:41:51 +0100] CUPS-Get-Printers
D [02/May/2012:18:41:51 +0100] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost
D [02/May/2012:18:41:51 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [02/May/2012:18:41:51 +0100] cupsdReadClient: 19 WAITING Closing on EOF
D [02/May/2012:18:41:51 +0100] cupsdCloseClient: 19
D [02/May/2012:18:41:51 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [02/May/2012:18:41:51 +0100] cupsdAcceptClient: 17 from localhost (Domain)
D [02/May/2012:18:41:51 +0100] cupsdAcceptClient: 19 from localhost (Domain)
D [02/May/2012:18:41:51 +0100] cupsdReadClient: 17 WAITING Closing on EOF
D [02/May/2012:18:41:51 +0100] cupsdCloseClient: 17
D [02/May/2012:18:41:51 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [02/May/2012:18:41:51 +0100] cupsdReadClient: 19 POST / HTTP/1.1
D [02/May/2012:18:41:51 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [02/May/2012:18:41:51 +0100] cupsdAuthorize: No authentication data provided.
D [02/May/2012:18:41:51 +0100] cupsdReadClient: 19 1.1 CUPS-Get-Printers 1
D [02/May/2012:18:41:51 +0100] CUPS-Get-Printers
D [02/May/2012:18:41:51 +0100] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost
D [02/May/2012:18:41:51 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [02/May/2012:18:41:51 +0100] cupsdReadClient: 19 WAITING Closing on EOF
D [02/May/2012:18:41:51 +0100] cupsdCloseClient: 19
D [02/May/2012:18:41:51 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [02/May/2012:18:41:52 +0100] cupsdAcceptClient: 17 from localhost (Domain)
D [02/May/2012:18:41:52 +0100] cupsdReadClient: 17 POST /printers/LaserJet-4L HTTP/1.1
D [02/May/2012:18:41:52 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [02/May/2012:18:41:52 +0100] cupsdAuthorize: No authentication data provided.
D [02/May/2012:18:41:52 +0100] cupsdReadClient: 17 1.1 Print-Job 1
D [02/May/2012:18:41:52 +0100] Print-Job ipp://localhost:631/printers/LaserJet-4L
D [02/May/2012:18:41:52 +0100] [Job ???] Auto-typing file...
I [02/May/2012:18:41:52 +0100] [Job ???] Request file type is application/pdf.
D [02/May/2012:18:41:52 +0100] cupsdMarkDirty(----J-)
D [02/May/2012:18:41:52 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [02/May/2012:18:41:52 +0100] add_job: requesting-user-name="al"
I [02/May/2012:18:41:52 +0100] [Job 28] Adding start banner page "none".
D [02/May/2012:18:41:52 +0100] cupsdMarkDirty(-----S)
D [02/May/2012:18:41:52 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [02/May/2012:18:41:52 +0100] cupsdMarkDirty(----J-)
D [02/May/2012:18:41:52 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
I [02/May/2012:18:41:52 +0100] [Job 28] Adding end banner page "none".
I [02/May/2012:18:41:52 +0100] [Job 28] File of type application/pdf queued by "al".
D [02/May/2012:18:41:52 +0100] [Job 28] hold_until=0
I [02/May/2012:18:41:52 +0100] [Job 28] Queued on "LaserJet-4L" by "al".
D [02/May/2012:18:41:52 +0100] cupsdMarkDirty(----J-)
D [02/May/2012:18:41:52 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [02/May/2012:18:41:52 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [02/May/2012:18:41:52 +0100] cupsdMarkDirty(-----S)
D [02/May/2012:18:41:52 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [02/May/2012:18:41:52 +0100] [Job 28] job-sheets=none,none
D [02/May/2012:18:41:52 +0100] [Job 28] argv[0]="LaserJet-4L"
D [02/May/2012:18:41:52 +0100] [Job 28] argv[1]="28"
D [02/May/2012:18:41:52 +0100] [Job 28] argv[2]="al"
D [02/May/2012:18:41:52 +0100] [Job 28] argv[3]="Untitled Document 2"
D [02/May/2012:18:41:52 +0100] [Job 28] argv[4]="1"
D [02/May/2012:18:41:52 +0100] [Job 28] argv[5]="InputSlot=Default TonerDensity=3 PageSize=A4 number-up=1 REt=Medium Manualfeed=Off Economode=Off Resolution=300x300dpi job-uuid=urn:uuid:786a4a3c-27ea-31fe-4ae2-043b5bae8555 lpi=5.600000 print-quality=5 job-originating-host-name=localhost time-at-creation=1335980512 time-at-processing=1335980512"
D [02/May/2012:18:41:52 +0100] [Job 28] argv[6]="/var/spool/cups/d00028-001"
D [02/May/2012:18:41:52 +0100] [Job 28] envp[0]="CUPS_CACHEDIR=/var/cache/cups"
D [02/May/2012:18:41:52 +0100] [Job 28] envp[1]="CUPS_DATADIR=/usr/share/cups"
D [02/May/2012:18:41:52 +0100] [Job 28] envp[2]="CUPS_DOCROOT=/usr/share/cups/doc-root"
D [02/May/2012:18:41:52 +0100] [Job 28] envp[3]="CUPS_FONTPATH=/usr/share/cups/fonts"
D [02/May/2012:18:41:52 +0100] [Job 28] envp[4]="CUPS_REQUESTROOT=/var/spool/cups"
D [02/May/2012:18:41:52 +0100] [Job 28] envp[5]="CUPS_SERVERBIN=/usr/lib/cups"
D [02/May/2012:18:41:52 +0100] [Job 28] envp[6]="CUPS_SERVERROOT=/etc/cups"
D [02/May/2012:18:41:52 +0100] [Job 28] envp[7]="CUPS_STATEDIR=/var/run/cups"
D [02/May/2012:18:41:52 +0100] [Job 28] envp[8]="HOME=/var/spool/cups/tmp"
D [02/May/2012:18:41:52 +0100] [Job 28] envp[9]="PATH=/usr/lib/cups/filter:/usr/bin:/usr/sbin:/bin:/usr/bin"
D [02/May/2012:18:41:52 +0100] [Job 28] envp[10]="SERVER_ADMIN=root@al-desktop"
D [02/May/2012:18:41:52 +0100] [Job 28] envp[11]="SOFTWARE=CUPS/1.5.2"
D [02/May/2012:18:41:52 +0100] [Job 28] envp[12]="TMPDIR=/var/spool/cups/tmp"
D [02/May/2012:18:41:52 +0100] [Job 28] envp[13]="USER=root"
D [02/May/2012:18:41:52 +0100] [Job 28] envp[14]="CUPS_SERVER=/var/run/cups/cups.sock"
D [02/May/2012:18:41:52 +0100] [Job 28] envp[15]="CUPS_ENCRYPTION=IfRequested"
D [02/May/2012:18:41:52 +0100] [Job 28] envp[16]="IPP_PORT=631"
D [02/May/2012:18:41:52 +0100] [Job 28] envp[17]="CHARSET=utf-8"
D [02/May/2012:18:41:52 +0100] [Job 28] envp[18]="LANG=en_GB.UTF-8"
D [02/May/2012:18:41:52 +0100] [Job 28] envp[19]="PPD=/etc/cups/ppd/LaserJet-4L.ppd"
D [02/May/2012:18:41:52 +0100] [Job 28] envp[20]="RIP_MAX_CACHE=128m"
D [02/May/2012:18:41:52 +0100] [Job 28] envp[21]="CONTENT_TYPE=application/pdf"
D [02/May/2012:18:41:52 +0100] [Job 28] envp[22]="DEVICE_URI=usb://HP/LaserJet%204L"
D [02/May/2012:18:41:52 +0100] [Job 28] envp[23]="PRINTER_INFO=Hewlett-Packard LaserJet 4L"
D [02/May/2012:18:41:52 +0100] [Job 28] envp[24]="PRINTER_LOCATION=al-desktop"
D [02/May/2012:18:41:52 +0100] [Job 28] envp[25]="PRINTER=LaserJet-4L"
D [02/May/2012:18:41:52 +0100] [Job 28] envp[26]="PRINTER_STATE_REASONS=none"
D [02/May/2012:18:41:52 +0100] [Job 28] envp[27]="CUPS_FILETYPE=document"
D [02/May/2012:18:41:52 +0100] [Job 28] envp[28]="FINAL_CONTENT_TYPE=printer/LaserJet-4L"
D [02/May/2012:18:41:52 +0100] [Job 28] envp[29]="AUTH_I****"
I [02/May/2012:18:41:52 +0100] [Job 28] Started filter /usr/lib/cups/filter/pdftopdf (PID 14167)
I [02/May/2012:18:41:52 +0100] [Job 28] Started filter /usr/lib/cups/filter/foomatic-rip (PID 14168)
I [02/May/2012:18:41:52 +0100] [Job 28] Started backend /usr/lib/cups/backend/usb (PID 14169)
D [02/May/2012:18:41:52 +0100] cupsdMarkDirty(-----S)
D [02/May/2012:18:41:52 +0100] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Active clients and dirty files"
D [02/May/2012:18:41:52 +0100] Returning IPP successful-ok for Print-Job (ipp://localhost:631/printers/LaserJet-4L) from localhost
D [02/May/2012:18:41:52 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients, printing jobs, and dirty files"
D [02/May/2012:18:41:52 +0100] [Notifier] state=3
D [02/May/2012:18:41:52 +0100] [Notifier] state=3
D [02/May/2012:18:41:52 +0100] [Notifier] state=3
D [02/May/2012:18:41:52 +0100] cupsdReadClient: 17 WAITING Closing on EOF
D [02/May/2012:18:41:52 +0100] cupsdCloseClient: 17
D [02/May/2012:18:41:52 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [02/May/2012:18:41:52 +0100] [Job 28] print_device
D [02/May/2012:18:41:52 +0100] [Job 28] libusb_get_device_list=18
D [02/May/2012:18:41:52 +0100] [Job 28] Getting input from file 
D [02/May/2012:18:41:52 +0100] [Job 28] foomatic-rip version 4.0.15.251 running...
D [02/May/2012:18:41:52 +0100] [Job 28] Parsing PPD file ...
D [02/May/2012:18:41:52 +0100] [Job 28] Added option ColorSpace
D [02/May/2012:18:41:52 +0100] [Job 28] Added option PageSize
D [02/May/2012:18:41:52 +0100] [Job 28] Added option ImageableArea
D [02/May/2012:18:41:52 +0100] [Job 28] Added option PaperDimension
D [02/May/2012:18:41:52 +0100] [Job 28] Added option InputSlot
D [02/May/2012:18:41:52 +0100] [Job 28] Added option Manualfeed
D [02/May/2012:18:41:52 +0100] [Job 28] Added option Economode
D [02/May/2012:18:41:52 +0100] [Job 28] Added option Copies
D [02/May/2012:18:41:52 +0100] [Job 28] Added option Resolution
D [02/May/2012:18:41:52 +0100] [Job 28] Added option REt
D [02/May/2012:18:41:52 +0100] [Job 28] Added option TonerDensity
D [02/May/2012:18:41:52 +0100] [Job 28] Added option Font
D [02/May/2012:18:41:52 +0100] [Job 28] 
D [02/May/2012:18:41:52 +0100] [Job 28] Parameter Summary
D [02/May/2012:18:41:52 +0100] [Job 28] -----------------
D [02/May/2012:18:41:52 +0100] [Job 28] 
D [02/May/2012:18:41:52 +0100] [Job 28] Spooler: cups
D [02/May/2012:18:41:52 +0100] [Job 28] Printer: LaserJet-4L
D [02/May/2012:18:41:52 +0100] [Job 28] Shell: /bin/bash
D [02/May/2012:18:41:52 +0100] [Job 28] PPD file: /etc/cups/ppd/LaserJet-4L.ppd
D [02/May/2012:18:41:52 +0100] [Job 28] ATTR file: 
D [02/May/2012:18:41:52 +0100] [Job 28] Printer model: HP LaserJet 4L Foomatic/ljet4 (recommended)
D [02/May/2012:18:41:52 +0100] [Job 28] Job title: Untitled Document 2
D [02/May/2012:18:41:52 +0100] [Job 28] File(s) to be printed:
D [02/May/2012:18:41:52 +0100] [Job 28] <STDIN>
D [02/May/2012:18:41:52 +0100] [Job 28] 
D [02/May/2012:18:41:52 +0100] [Job 28] Ghostscript extra search path ('GS_LIB'): /usr/share/cups/fonts
D [02/May/2012:18:41:52 +0100] [Job 28] Printing system options:
D [02/May/2012:18:41:52 +0100] [Job 28] Pondering option 'number-up=1'
D [02/May/2012:18:41:52 +0100] [Job 28] Unknown option number-up=1.
D [02/May/2012:18:41:52 +0100] [Job 28] Pondering option 'job-uuid=urn:uuid:786a4a3c-27ea-31fe-4ae2-043b5bae8555'
D [02/May/2012:18:41:52 +0100] [Job 28] Unknown option job-uuid=urn:uuid:786a4a3c-27ea-31fe-4ae2-043b5bae8555.
D [02/May/2012:18:41:52 +0100] [Job 28] Pondering option 'lpi=5.600000'
D [02/May/2012:18:41:52 +0100] [Job 28] Unknown option lpi=5.600000.
D [02/May/2012:18:41:52 +0100] [Job 28] Pondering option 'print-quality=5'
D [02/May/2012:18:41:52 +0100] [Job 28] Unknown option print-quality=5.
D [02/May/2012:18:41:52 +0100] [Job 28] Pondering option 'job-originating-host-name=localhost'
D [02/May/2012:18:41:52 +0100] [Job 28] Unknown option job-originating-host-name=localhost.
D [02/May/2012:18:41:52 +0100] [Job 28] Pondering option 'time-at-creation=1335980512'
D [02/May/2012:18:41:52 +0100] [Job 28] Unknown option time-at-creation=1335980512.
D [02/May/2012:18:41:52 +0100] [Job 28] Pondering option 'time-at-processing=133598051'
D [02/May/2012:18:41:52 +0100] [Job 28] Unknown option time-at-processing=133598051.
D [02/May/2012:18:41:52 +0100] [Job 28] Options from the PPD file:
D [02/May/2012:18:41:52 +0100] [Job 28] Pondering option 'InputSlot=Default'
D [02/May/2012:18:41:52 +0100] [Job 28] Pondering option 'TonerDensity=3'
D [02/May/2012:18:41:52 +0100] [Job 28] Pondering option 'PageSize=A4'
D [02/May/2012:18:41:52 +0100] [Job 28] Pondering option 'REt=Medium'
D [02/May/2012:18:41:52 +0100] [Job 28] Pondering option 'Manualfeed=Off'
D [02/May/2012:18:41:52 +0100] [Job 28] Pondering option 'Economode=Off'
D [02/May/2012:18:41:52 +0100] [Job 28] Pondering option 'Resolution=300x300dpi'
D [02/May/2012:18:41:52 +0100] [Job 28] 
D [02/May/2012:18:41:52 +0100] [Job 28] ================================================
D [02/May/2012:18:41:52 +0100] [Job 28] 
D [02/May/2012:18:41:52 +0100] [Job 28] File: <STDIN>
D [02/May/2012:18:41:52 +0100] [Job 28] 
D [02/May/2012:18:41:52 +0100] [Job 28] ================================================
D [02/May/2012:18:41:52 +0100] [Job 28] 
D [02/May/2012:18:41:52 +0100] [Job 28] Filetype: PDF
D [02/May/2012:18:41:52 +0100] [Job 28] Storing temporary files in /var/spool/cups/tmp
D [02/May/2012:18:41:52 +0100] PID 14167 (/usr/lib/cups/filter/pdftopdf) exited with no errors.
D [02/May/2012:18:41:52 +0100] [Job 28] STATE: +connecting-to-device
D [02/May/2012:18:41:52 +0100] cupsdMarkDirty(-----S)
D [02/May/2012:18:41:52 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Printing jobs and dirty files"
D [02/May/2012:18:41:52 +0100] [Notifier] state=3
D [02/May/2012:18:41:52 +0100] [Job 28] STATE: -connecting-to-device
D [02/May/2012:18:41:52 +0100] cupsdMarkDirty(-----S)
D [02/May/2012:18:41:52 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Dirty files"
D [02/May/2012:18:41:52 +0100] [Notifier] state=3
I [02/May/2012:18:41:52 +0100] [Job 28] Sending data to printer.
D [02/May/2012:18:41:52 +0100] [Job 28] Set job-printer-state-message to "Sending data to printer.", current level=INFO
D [02/May/2012:18:41:52 +0100] cupsdMarkDirty(-----S)
D [02/May/2012:18:41:52 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [02/May/2012:18:41:52 +0100] cupsdMarkDirty(-----S)
D [02/May/2012:18:41:52 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [02/May/2012:18:41:52 +0100] [Notifier] state=3
D [02/May/2012:18:41:52 +0100] [Notifier] state=3
D [02/May/2012:18:41:52 +0100] [Job 28] Read 54 bytes of back-channel data...
D [02/May/2012:18:41:53 +0100] [Job 28] File contains 1 pages
D [02/May/2012:18:41:53 +0100] [Job 28] 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-YqNpAx 
D [02/May/2012:18:41:53 +0100] [Job 28] Starting process "kid3" (generation 1)
D [02/May/2012:18:41:53 +0100] [Job 28] Starting process "kid4" (generation 2)
D [02/May/2012:18:41:53 +0100] [Job 28] Starting process "renderer" (generation 2)
D [02/May/2012:18:41:53 +0100] [Job 28] JCL: %-12345X@PJL
D [02/May/2012:18:41:53 +0100] [Job 28] @PJL SET DENSITY=3
D [02/May/2012:18:41:53 +0100] [Job 28] @PJL SET RET=MEDIUM
D [02/May/2012:18:41:53 +0100] [Job 28] @PJL SET COPIES=1
D [02/May/2012:18:41:53 +0100] [Job 28] @PJL SET ECONOMODE=OFF
D [02/May/2012:18:41:53 +0100] [Job 28] @PJL SET MANUALFEED=OFF
D [02/May/2012:18:41:53 +0100] [Job 28] <job data> %-12345X@PJL RESET
D [02/May/2012:18:41:53 +0100] [Job 28] 
D [02/May/2012:18:41:53 +0100] [Job 28] 
D [02/May/2012:18:41:53 +0100] [Job 28] renderer exited with status 0
D [02/May/2012:18:41:53 +0100] [Job 28] Read 1943 bytes of print data...
D [02/May/2012:18:41:53 +0100] [Job 28] kid4 exited with status 0
D [02/May/2012:18:41:53 +0100] [Job 28] kid3 finished
D [02/May/2012:18:41:53 +0100] [Job 28] Kid3 exit status: 0
D [02/May/2012:18:41:53 +0100] [Job 28] 
D [02/May/2012:18:41:53 +0100] [Job 28] Closing foomatic-rip.
D [02/May/2012:18:41:53 +0100] PID 14168 (/usr/lib/cups/filter/foomatic-rip) exited with no errors.
D [02/May/2012:18:41:53 +0100] [Job 28] Wrote 1943 bytes of print data...
D [02/May/2012:18:41:53 +0100] [Job 28] Sent 1943 bytes...
D [02/May/2012:18:41:53 +0100] [Job 28] Waiting for read thread to exit...
D [02/May/2012:18:41:54 +0100] [Job 28] Read 57 bytes of back-channel data...
D [02/May/2012:18:41:59 +0100] PID 14169 (/usr/lib/cups/backend/usb) exited with no errors.
D [02/May/2012:18:41:59 +0100] cupsdMarkDirty(-----S)
D [02/May/2012:18:41:59 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
I [02/May/2012:18:41:59 +0100] [Job 28] Job completed.
D [02/May/2012:18:41:59 +0100] cupsdMarkDirty(----J-)
D [02/May/2012:18:41:59 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [02/May/2012:18:41:59 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [02/May/2012:18:41:59 +0100] cupsdMarkDirty(-----S)
D [02/May/2012:18:41:59 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [02/May/2012:18:41:59 +0100] [Notifier] state=3
D [02/May/2012:18:41:59 +0100] [Notifier] state=3
D [02/May/2012:18:42:00 +0100] [Job 28] Unloading...
I [02/May/2012:18:42:09 +0100] Generating printcap /var/run/cups/printcap...
I [02/May/2012:18:42:09 +0100] Saving job.cache...
I [02/May/2012:18:42:09 +0100] Saving subscriptions.conf...
D [02/May/2012:18:42:09 +0100] cupsdSetBusyState: newbusy="Not busy", busy="Printing jobs and dirty files"
D [02/May/2012:18:42:37 +0100] cupsdAcceptClient: 17 from localhost (Domain)
D [02/May/2012:18:42:37 +0100] Report: clients=1
D [02/May/2012:18:42:37 +0100] Report: jobs=1
D [02/May/2012:18:42:37 +0100] Report: jobs-active=0
D [02/May/2012:18:42:37 +0100] Report: printers=1
D [02/May/2012:18:42:37 +0100] Report: printers-implicit=0
D [02/May/2012:18:42:37 +0100] Report: stringpool-string-count=2800
D [02/May/2012:18:42:37 +0100] Report: stringpool-alloc-bytes=9880
D [02/May/2012:18:42:37 +0100] Report: stringpool-total-bytes=45776
D [02/May/2012:18:42:37 +0100] cupsdAcceptClient: 19 from localhost (Domain)
D [02/May/2012:18:42:37 +0100] cupsdReadClient: 17 WAITING Closing on EOF
D [02/May/2012:18:42:37 +0100] cupsdCloseClient: 17
D [02/May/2012:18:42:37 +0100] cupsdSetBusyState: newbusy="Not busy", busy="Not busy"
D [02/May/2012:18:42:37 +0100] cupsdReadClient: 19 POST / HTTP/1.1
D [02/May/2012:18:42:37 +0100] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [02/May/2012:18:42:37 +0100] cupsdAuthorize: No authentication data provided.
D [02/May/2012:18:42:37 +0100] cupsdReadClient: 19 1.1 CUPS-Get-Printers 1
D [02/May/2012:18:42:37 +0100] CUPS-Get-Printers
D [02/May/2012:18:42:37 +0100] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost
D [02/May/2012:18:42:37 +0100] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [02/May/2012:18:42:37 +0100] cupsdAcceptClient: 17 from localhost (Domain)
D [02/May/2012:18:42:37 +0100] cupsdReadClient: 19 WAITING Closing on EOF
D [02/May/2012:18:42:37 +0100] cupsdCloseClient: 19
D [02/May/2012:18:42:37 +0100] cupsdSetBusyState: newbusy="Not busy", busy="Not busy"
D [02/May/2012:18:42:37 +0100] cupsdReadClient: 17 GET /printers/LaserJet-4L.ppd HTTP/1.1
D [02/May/2012:18:42:37 +0100] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [02/May/2012:18:42:37 +0100] cupsdAuthorize: No authentication data provided.
D [02/May/2012:18:42:37 +0100] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [02/May/2012:18:42:37 +0100] cupsdReadClient: 17 WAITING Closing on EOF
D [02/May/2012:18:42:37 +0100] cupsdCloseClient: 17
D [02/May/2012:18:42:37 +0100] cupsdSetBusyState: newbusy="Not busy", busy="Not busy"
D [02/May/2012:18:42:37 +0100] cupsdAcceptClient: 17 from localhost (Domain)
D [02/May/2012:18:42:37 +0100] cupsdAcceptClient: 19 from localhost (Domain)
D [02/May/2012:18:42:37 +0100] cupsdReadClient: 17 WAITING Closing on EOF
D [02/May/2012:18:42:37 +0100] cupsdCloseClient: 17
D [02/May/2012:18:42:37 +0100] cupsdSetBusyState: newbusy="Not busy", busy="Not busy"
D [02/May/2012:18:42:37 +0100] cupsdReadClient: 19 POST / HTTP/1.1
D [02/May/2012:18:42:37 +0100] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [02/May/2012:18:42:37 +0100] cupsdAuthorize: No authentication data provided.
D [02/May/2012:18:42:37 +0100] cupsdReadClient: 19 1.1 CUPS-Get-Printers 1
D [02/May/2012:18:42:37 +0100] CUPS-Get-Printers
D [02/May/2012:18:42:37 +0100] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost
D [02/May/2012:18:42:37 +0100] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [02/May/2012:18:42:37 +0100] cupsdReadClient: 19 WAITING Closing on EOF
D [02/May/2012:18:42:37 +0100] cupsdCloseClient: 19
D [02/May/2012:18:42:37 +0100] cupsdSetBusyState: newbusy="Not busy", busy="Not busy"
D [02/May/2012:18:42:37 +0100] cupsdAcceptClient: 17 from localhost (Domain)
D [02/May/2012:18:42:37 +0100] cupsdAcceptClient: 19 from localhost (Domain)
D [02/May/2012:18:42:37 +0100] cupsdReadClient: 17 WAITING Closing on EOF
D [02/May/2012:18:42:37 +0100] cupsdCloseClient: 17
D [02/May/2012:18:42:37 +0100] cupsdSetBusyState: newbusy="Not busy", busy="Not busy"
D [02/May/2012:18:42:37 +0100] cupsdReadClient: 19 POST / HTTP/1.1
D [02/May/2012:18:42:37 +0100] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [02/May/2012:18:42:37 +0100] cupsdAuthorize: No authentication data provided.
D [02/May/2012:18:42:37 +0100] cupsdReadClient: 19 1.1 CUPS-Get-Printers 1
D [02/May/2012:18:42:37 +0100] CUPS-Get-Printers
D [02/May/2012:18:42:37 +0100] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost
D [02/May/2012:18:42:37 +0100] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [02/May/2012:18:42:37 +0100] cupsdReadClient: 19 WAITING Closing on EOF
D [02/May/2012:18:42:37 +0100] cupsdCloseClient: 19
D [02/May/2012:18:42:37 +0100] cupsdSetBusyState: newbusy="Not busy", busy="Not busy"
D [02/May/2012:18:42:37 +0100] cupsdAcceptClient: 17 from localhost (Domain)
D [02/May/2012:18:42:37 +0100] cupsdAcceptClient: 19 from localhost (Domain)
D [02/May/2012:18:42:37 +0100] cupsdReadClient: 17 WAITING Closing on EOF
D [02/May/2012:18:42:37 +0100] cupsdCloseClient: 17
D [02/May/2012:18:42:37 +0100] cupsdSetBusyState: newbusy="Not busy", busy="Not busy"
D [02/May/2012:18:42:37 +0100] cupsdReadClient: 19 POST / HTTP/1.1
D [02/May/2012:18:42:37 +0100] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [02/May/2012:18:42:37 +0100] cupsdAuthorize: No authentication data provided.
D [02/May/2012:18:42:37 +0100] cupsdReadClient: 19 1.1 CUPS-Get-Printers 1
D [02/May/2012:18:42:37 +0100] CUPS-Get-Printers
D [02/May/2012:18:42:37 +0100] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost
D [02/May/2012:18:42:37 +0100] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [02/May/2012:18:42:37 +0100] cupsdReadClient: 19 WAITING Closing on EOF
D [02/May/2012:18:42:37 +0100] cupsdCloseClient: 19
D [02/May/2012:18:42:37 +0100] cupsdSetBusyState: newbusy="Not busy", busy="Not busy"
D [02/May/2012:18:42:37 +0100] cupsdAcceptClient: 17 from localhost (Domain)
D [02/May/2012:18:42:37 +0100] cupsdAcceptClient: 19 from localhost (Domain)
D [02/May/2012:18:42:37 +0100] cupsdReadClient: 17 WAITING Closing on EOF
D [02/May/2012:18:42:37 +0100] cupsdCloseClient: 17
D [02/May/2012:18:42:37 +0100] cupsdSetBusyState: newbusy="Not busy", busy="Not busy"
D [02/May/2012:18:42:37 +0100] cupsdReadClient: 19 POST / HTTP/1.1
D [02/May/2012:18:42:37 +0100] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [02/May/2012:18:42:37 +0100] cupsdAuthorize: No authentication data provided.
D [02/May/2012:18:42:37 +0100] cupsdReadClient: 19 1.1 CUPS-Get-Printers 1
D [02/May/2012:18:42:37 +0100] CUPS-Get-Printers
D [02/May/2012:18:42:37 +0100] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost
D [02/May/2012:18:42:37 +0100] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [02/May/2012:18:42:37 +0100] cupsdReadClient: 19 WAITING Closing on EOF
D [02/May/2012:18:42:37 +0100] cupsdCloseClient: 19
D [02/May/2012:18:42:37 +0100] cupsdSetBusyState: newbusy="Not busy", busy="Not busy"
D [02/May/2012:18:42:37 +0100] cupsdAcceptClient: 17 from localhost (Domain)
D [02/May/2012:18:42:37 +0100] cupsdAcceptClient: 19 from localhost (Domain)
D [02/May/2012:18:42:37 +0100] cupsdReadClient: 17 WAITING Closing on EOF
D [02/May/2012:18:42:37 +0100] cupsdCloseClient: 17
D [02/May/2012:18:42:37 +0100] cupsdSetBusyState: newbusy="Not busy", busy="Not busy"
D [02/May/2012:18:42:37 +0100] cupsdReadClient: 19 POST / HTTP/1.1
D [02/May/2012:18:42:37 +0100] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [02/May/2012:18:42:37 +0100] cupsdAuthorize: No authentication data provided.
D [02/May/2012:18:42:37 +0100] cupsdReadClient: 19 1.1 CUPS-Get-Printers 1
D [02/May/2012:18:42:37 +0100] CUPS-Get-Printers
D [02/May/2012:18:42:37 +0100] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost
D [02/May/2012:18:42:37 +0100] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [02/May/2012:18:42:37 +0100] cupsdReadClient: 19 WAITING Closing on EOF
D [02/May/2012:18:42:37 +0100] cupsdCloseClient: 19
D [02/May/2012:18:42:37 +0100] cupsdSetBusyState: newbusy="Not busy", busy="Not busy"
D [02/May/2012:18:42:38 +0100] cupsdAcceptClient: 17 from localhost (Domain)
D [02/May/2012:18:42:38 +0100] cupsdAcceptClient: 19 from localhost (Domain)
D [02/May/2012:18:42:38 +0100] cupsdReadClient: 17 WAITING Closing on EOF
D [02/May/2012:18:42:38 +0100] cupsdCloseClient: 17
D [02/May/2012:18:42:38 +0100] cupsdSetBusyState: newbusy="Not busy", busy="Not busy"
D [02/May/2012:18:42:38 +0100] cupsdReadClient: 19 POST / HTTP/1.1
D [02/May/2012:18:42:38 +0100] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [02/May/2012:18:42:38 +0100] cupsdAuthorize: No authentication data provided.
D [02/May/2012:18:42:38 +0100] cupsdReadClient: 19 1.1 CUPS-Get-Printers 1
D [02/May/2012:18:42:38 +0100] CUPS-Get-Printers
D [02/May/2012:18:42:38 +0100] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost
D [02/May/2012:18:42:38 +0100] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [02/May/2012:18:42:38 +0100] cupsdReadClient: 19 WAITING Closing on EOF
D [02/May/2012:18:42:38 +0100] cupsdCloseClient: 19
D [02/May/2012:18:42:38 +0100] cupsdSetBusyState: newbusy="Not busy", busy="Not busy"
D [02/May/2012:18:42:38 +0100] cupsdAcceptClient: 17 from localhost (Domain)
D [02/May/2012:18:42:38 +0100] cupsdAcceptClient: 19 from localhost (Domain)
D [02/May/2012:18:42:38 +0100] cupsdReadClient: 17 WAITING Closing on EOF
D [02/May/2012:18:42:38 +0100] cupsdCloseClient: 17
D [02/May/2012:18:42:38 +0100] cupsdSetBusyState: newbusy="Not busy", busy="Not busy"
D [02/May/2012:18:42:38 +0100] cupsdReadClient: 19 POST / HTTP/1.1
D [02/May/2012:18:42:38 +0100] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [02/May/2012:18:42:38 +0100] cupsdAuthorize: No authentication data provided.
D [02/May/2012:18:42:38 +0100] cupsdReadClient: 19 1.1 CUPS-Get-Printers 1
D [02/May/2012:18:42:38 +0100] CUPS-Get-Printers
D [02/May/2012:18:42:38 +0100] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost
D [02/May/2012:18:42:38 +0100] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [02/May/2012:18:42:38 +0100] cupsdReadClient: 19 WAITING Closing on EOF
D [02/May/2012:18:42:38 +0100] cupsdCloseClient: 19
D [02/May/2012:18:42:38 +0100] cupsdSetBusyState: newbusy="Not busy", busy="Not busy"
D [02/May/2012:18:42:38 +0100] cupsdAcceptClient: 17 from localhost (Domain)
D [02/May/2012:18:42:38 +0100] cupsdAcceptClient: 19 from localhost (Domain)
D [02/May/2012:18:42:38 +0100] cupsdReadClient: 17 WAITING Closing on EOF
D [02/May/2012:18:42:38 +0100] cupsdCloseClient: 17
D [02/May/2012:18:42:38 +0100] cupsdSetBusyState: newbusy="Not busy", busy="Not busy"
D [02/May/2012:18:42:38 +0100] cupsdReadClient: 19 POST / HTTP/1.1
D [02/May/2012:18:42:38 +0100] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [02/May/2012:18:42:38 +0100] cupsdAuthorize: No authentication data provided.
D [02/May/2012:18:42:38 +0100] cupsdReadClient: 19 1.1 CUPS-Get-Printers 1
D [02/May/2012:18:42:38 +0100] CUPS-Get-Printers
D [02/May/2012:18:42:38 +0100] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost
D [02/May/2012:18:42:38 +0100] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [02/May/2012:18:42:38 +0100] cupsdReadClient: 19 WAITING Closing on EOF
D [02/May/2012:18:42:38 +0100] cupsdCloseClient: 19
D [02/May/2012:18:42:38 +0100] cupsdSetBusyState: newbusy="Not busy", busy="Not busy"
D [02/May/2012:18:42:38 +0100] cupsdAcceptClient: 17 from localhost (Domain)
D [02/May/2012:18:42:38 +0100] cupsdAcceptClient: 19 from localhost (Domain)
D [02/May/2012:18:42:38 +0100] cupsdReadClient: 17 WAITING Closing on EOF
D [02/May/2012:18:42:38 +0100] cupsdCloseClient: 17
D [02/May/2012:18:42:38 +0100] cupsdSetBusyState: newbusy="Not busy", busy="Not busy"
D [02/May/2012:18:42:38 +0100] cupsdReadClient: 19 POST / HTTP/1.1
D [02/May/2012:18:42:38 +0100] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [02/May/2012:18:42:38 +0100] cupsdAuthorize: No authentication data provided.
D [02/May/2012:18:42:38 +0100] cupsdReadClient: 19 1.1 CUPS-Get-Printers 1
D [02/May/2012:18:42:38 +0100] CUPS-Get-Printers
D [02/May/2012:18:42:38 +0100] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost
D [02/May/2012:18:42:38 +0100] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [02/May/2012:18:42:38 +0100] cupsdReadClient: 19 WAITING Closing on EOF
D [02/May/2012:18:42:38 +0100] cupsdCloseClient: 19
D [02/May/2012:18:42:38 +0100] cupsdSetBusyState: newbusy="Not busy", busy="Not busy"
D [02/May/2012:18:42:38 +0100] cupsdAcceptClient: 17 from localhost (Domain)
D [02/May/2012:18:42:38 +0100] cupsdReadClient: 17 POST /printers/LaserJet-4L HTTP/1.1
D [02/May/2012:18:42:38 +0100] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [02/May/2012:18:42:38 +0100] cupsdAuthorize: No authentication data provided.
D [02/May/2012:18:42:39 +0100] cupsdReadClient: 17 1.1 Print-Job 1
D [02/May/2012:18:42:39 +0100] Print-Job ipp://localhost:631/printers/LaserJet-4L
D [02/May/2012:18:42:39 +0100] [Job ???] Auto-typing file...
I [02/May/2012:18:42:39 +0100] [Job ???] Request file type is application/pdf.
D [02/May/2012:18:42:39 +0100] cupsdMarkDirty(----J-)
D [02/May/2012:18:42:39 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients"
D [02/May/2012:18:42:39 +0100] add_job: requesting-user-name="al"
I [02/May/2012:18:42:39 +0100] [Job 29] Adding start banner page "none".
D [02/May/2012:18:42:39 +0100] cupsdMarkDirty(-----S)
D [02/May/2012:18:42:39 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [02/May/2012:18:42:39 +0100] cupsdMarkDirty(----J-)
D [02/May/2012:18:42:39 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
I [02/May/2012:18:42:39 +0100] [Job 29] Adding end banner page "none".
I [02/May/2012:18:42:39 +0100] [Job 29] File of type application/pdf queued by "al".
D [02/May/2012:18:42:39 +0100] [Job 29] hold_until=0
I [02/May/2012:18:42:39 +0100] [Job 29] Queued on "LaserJet-4L" by "al".
D [02/May/2012:18:42:39 +0100] cupsdMarkDirty(----J-)
D [02/May/2012:18:42:39 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [02/May/2012:18:42:39 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [02/May/2012:18:42:39 +0100] cupsdMarkDirty(-----S)
D [02/May/2012:18:42:39 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [02/May/2012:18:42:39 +0100] [Job 29] job-sheets=none,none
D [02/May/2012:18:42:39 +0100] [Job 29] argv[0]="LaserJet-4L"
D [02/May/2012:18:42:39 +0100] [Job 29] argv[1]="29"
D [02/May/2012:18:42:39 +0100] [Job 29] argv[2]="al"
D [02/May/2012:18:42:39 +0100] [Job 29] argv[3]="Untitled Document 2"
D [02/May/2012:18:42:39 +0100] [Job 29] argv[4]="1"
D [02/May/2012:18:42:39 +0100] [Job 29] argv[5]="InputSlot=Default TonerDensity=3 PageSize=A4 number-up=1 REt=Medium Manualfeed=Off Economode=Off Resolution=300x300dpi job-uuid=urn:uuid:405e9606-5883-3129-5760-6279bcf13b9d lpi=5.600000 print-quality=5 job-originating-host-name=localhost time-at-creation=1335980559 time-at-processing=1335980559"
D [02/May/2012:18:42:39 +0100] [Job 29] argv[6]="/var/spool/cups/d00029-001"
D [02/May/2012:18:42:39 +0100] [Job 29] envp[0]="CUPS_CACHEDIR=/var/cache/cups"
D [02/May/2012:18:42:39 +0100] [Job 29] envp[1]="CUPS_DATADIR=/usr/share/cups"
D [02/May/2012:18:42:39 +0100] [Job 29] envp[2]="CUPS_DOCROOT=/usr/share/cups/doc-root"
D [02/May/2012:18:42:39 +0100] [Job 29] envp[3]="CUPS_FONTPATH=/usr/share/cups/fonts"
D [02/May/2012:18:42:39 +0100] [Job 29] envp[4]="CUPS_REQUESTROOT=/var/spool/cups"
D [02/May/2012:18:42:39 +0100] [Job 29] envp[5]="CUPS_SERVERBIN=/usr/lib/cups"
D [02/May/2012:18:42:39 +0100] [Job 29] envp[6]="CUPS_SERVERROOT=/etc/cups"
D [02/May/2012:18:42:39 +0100] [Job 29] envp[7]="CUPS_STATEDIR=/var/run/cups"
D [02/May/2012:18:42:39 +0100] [Job 29] envp[8]="HOME=/var/spool/cups/tmp"
D [02/May/2012:18:42:39 +0100] [Job 29] envp[9]="PATH=/usr/lib/cups/filter:/usr/bin:/usr/sbin:/bin:/usr/bin"
D [02/May/2012:18:42:39 +0100] [Job 29] envp[10]="SERVER_ADMIN=root@al-desktop"
D [02/May/2012:18:42:39 +0100] [Job 29] envp[11]="SOFTWARE=CUPS/1.5.2"
D [02/May/2012:18:42:39 +0100] [Job 29] envp[12]="TMPDIR=/var/spool/cups/tmp"
D [02/May/2012:18:42:39 +0100] [Job 29] envp[13]="USER=root"
D [02/May/2012:18:42:39 +0100] [Job 29] envp[14]="CUPS_SERVER=/var/run/cups/cups.sock"
D [02/May/2012:18:42:39 +0100] [Job 29] envp[15]="CUPS_ENCRYPTION=IfRequested"
D [02/May/2012:18:42:39 +0100] [Job 29] envp[16]="IPP_PORT=631"
D [02/May/2012:18:42:39 +0100] [Job 29] envp[17]="CHARSET=utf-8"
D [02/May/2012:18:42:39 +0100] [Job 29] envp[18]="LANG=en_GB.UTF-8"
D [02/May/2012:18:42:39 +0100] [Job 29] envp[19]="PPD=/etc/cups/ppd/LaserJet-4L.ppd"
D [02/May/2012:18:42:39 +0100] [Job 29] envp[20]="RIP_MAX_CACHE=128m"
D [02/May/2012:18:42:39 +0100] [Job 29] envp[21]="CONTENT_TYPE=application/pdf"
D [02/May/2012:18:42:39 +0100] [Job 29] envp[22]="DEVICE_URI=usb://HP/LaserJet%204L"
D [02/May/2012:18:42:39 +0100] [Job 29] envp[23]="PRINTER_INFO=Hewlett-Packard LaserJet 4L"
D [02/May/2012:18:42:39 +0100] [Job 29] envp[24]="PRINTER_LOCATION=al-desktop"
D [02/May/2012:18:42:39 +0100] [Job 29] envp[25]="PRINTER=LaserJet-4L"
D [02/May/2012:18:42:39 +0100] [Job 29] envp[26]="PRINTER_STATE_REASONS=none"
D [02/May/2012:18:42:39 +0100] [Job 29] envp[27]="CUPS_FILETYPE=document"
D [02/May/2012:18:42:39 +0100] [Job 29] envp[28]="FINAL_CONTENT_TYPE=printer/LaserJet-4L"
D [02/May/2012:18:42:39 +0100] [Job 29] envp[29]="AUTH_I****"
I [02/May/2012:18:42:39 +0100] [Job 29] Started filter /usr/lib/cups/filter/pdftopdf (PID 14187)
I [02/May/2012:18:42:39 +0100] [Job 29] Started filter /usr/lib/cups/filter/foomatic-rip (PID 14188)
I [02/May/2012:18:42:39 +0100] [Job 29] Started backend /usr/lib/cups/backend/usb (PID 14189)
D [02/May/2012:18:42:39 +0100] cupsdMarkDirty(-----S)
D [02/May/2012:18:42:39 +0100] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Active clients and dirty files"
D [02/May/2012:18:42:39 +0100] Returning IPP successful-ok for Print-Job (ipp://localhost:631/printers/LaserJet-4L) from localhost
D [02/May/2012:18:42:39 +0100] [Notifier] state=3
D [02/May/2012:18:42:39 +0100] [Notifier] state=3
D [02/May/2012:18:42:39 +0100] [Notifier] state=3
D [02/May/2012:18:42:39 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients, printing jobs, and dirty files"
D [02/May/2012:18:42:39 +0100] cupsdReadClient: 17 WAITING Closing on EOF
D [02/May/2012:18:42:39 +0100] cupsdCloseClient: 17
D [02/May/2012:18:42:39 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [02/May/2012:18:42:39 +0100] [Job 29] print_device
D [02/May/2012:18:42:39 +0100] [Job 29] Getting input from file 
D [02/May/2012:18:42:39 +0100] [Job 29] foomatic-rip version 4.0.15.251 running...
D [02/May/2012:18:42:39 +0100] [Job 29] Parsing PPD file ...
D [02/May/2012:18:42:39 +0100] [Job 29] Added option ColorSpace
D [02/May/2012:18:42:39 +0100] [Job 29] Added option PageSize
D [02/May/2012:18:42:39 +0100] [Job 29] libusb_get_device_list=18
D [02/May/2012:18:42:39 +0100] [Job 29] Added option ImageableArea
D [02/May/2012:18:42:39 +0100] [Job 29] Added option PaperDimension
D [02/May/2012:18:42:39 +0100] [Job 29] Added option InputSlot
D [02/May/2012:18:42:39 +0100] [Job 29] Added option Manualfeed
D [02/May/2012:18:42:39 +0100] [Job 29] Added option Economode
D [02/May/2012:18:42:39 +0100] [Job 29] Added option Copies
D [02/May/2012:18:42:39 +0100] [Job 29] Added option Resolution
D [02/May/2012:18:42:39 +0100] [Job 29] Added option REt
D [02/May/2012:18:42:39 +0100] [Job 29] Added option TonerDensity
D [02/May/2012:18:42:39 +0100] [Job 29] Added option Font
D [02/May/2012:18:42:39 +0100] [Job 29] 
D [02/May/2012:18:42:39 +0100] [Job 29] Parameter Summary
D [02/May/2012:18:42:39 +0100] [Job 29] -----------------
D [02/May/2012:18:42:39 +0100] [Job 29] 
D [02/May/2012:18:42:39 +0100] [Job 29] Spooler: cups
D [02/May/2012:18:42:39 +0100] [Job 29] Printer: LaserJet-4L
D [02/May/2012:18:42:39 +0100] [Job 29] Shell: /bin/bash
D [02/May/2012:18:42:39 +0100] [Job 29] PPD file: /etc/cups/ppd/LaserJet-4L.ppd
D [02/May/2012:18:42:39 +0100] [Job 29] ATTR file: 
D [02/May/2012:18:42:39 +0100] [Job 29] Printer model: HP LaserJet 4L Foomatic/ljet4 (recommended)
D [02/May/2012:18:42:39 +0100] [Job 29] Job title: Untitled Document 2
D [02/May/2012:18:42:39 +0100] [Job 29] File(s) to be printed:
D [02/May/2012:18:42:39 +0100] [Job 29] <STDIN>
D [02/May/2012:18:42:39 +0100] [Job 29] 
D [02/May/2012:18:42:39 +0100] [Job 29] Ghostscript extra search path ('GS_LIB'): /usr/share/cups/fonts
D [02/May/2012:18:42:39 +0100] [Job 29] Printing system options:
D [02/May/2012:18:42:39 +0100] [Job 29] Pondering option 'number-up=1'
D [02/May/2012:18:42:39 +0100] [Job 29] Unknown option number-up=1.
D [02/May/2012:18:42:39 +0100] [Job 29] Pondering option 'job-uuid=urn:uuid:405e9606-5883-3129-5760-6279bcf13b9d'
D [02/May/2012:18:42:39 +0100] [Job 29] Unknown option job-uuid=urn:uuid:405e9606-5883-3129-5760-6279bcf13b9d.
D [02/May/2012:18:42:39 +0100] [Job 29] Pondering option 'lpi=5.600000'
D [02/May/2012:18:42:39 +0100] [Job 29] Unknown option lpi=5.600000.
D [02/May/2012:18:42:39 +0100] [Job 29] Pondering option 'print-quality=5'
D [02/May/2012:18:42:39 +0100] [Job 29] Unknown option print-quality=5.
D [02/May/2012:18:42:39 +0100] [Job 29] Pondering option 'job-originating-host-name=localhost'
D [02/May/2012:18:42:39 +0100] [Job 29] Unknown option job-originating-host-name=localhost.
D [02/May/2012:18:42:39 +0100] [Job 29] Pondering option 'time-at-creation=1335980559'
D [02/May/2012:18:42:39 +0100] [Job 29] Unknown option time-at-creation=1335980559.
D [02/May/2012:18:42:39 +0100] [Job 29] Pondering option 'time-at-processing=133598055'
D [02/May/2012:18:42:39 +0100] [Job 29] Unknown option time-at-processing=133598055.
D [02/May/2012:18:42:39 +0100] [Job 29] Options from the PPD file:
D [02/May/2012:18:42:39 +0100] [Job 29] Pondering option 'InputSlot=Default'
D [02/May/2012:18:42:39 +0100] [Job 29] Pondering option 'TonerDensity=3'
D [02/May/2012:18:42:39 +0100] [Job 29] Pondering option 'PageSize=A4'
D [02/May/2012:18:42:39 +0100] [Job 29] Pondering option 'REt=Medium'
D [02/May/2012:18:42:39 +0100] [Job 29] Pondering option 'Manualfeed=Off'
D [02/May/2012:18:42:39 +0100] [Job 29] Pondering option 'Economode=Off'
D [02/May/2012:18:42:39 +0100] [Job 29] Pondering option 'Resolution=300x300dpi'
D [02/May/2012:18:42:39 +0100] [Job 29] 
D [02/May/2012:18:42:39 +0100] [Job 29] ================================================
D [02/May/2012:18:42:39 +0100] [Job 29] 
D [02/May/2012:18:42:39 +0100] [Job 29] File: <STDIN>
D [02/May/2012:18:42:39 +0100] [Job 29] 
D [02/May/2012:18:42:39 +0100] [Job 29] ================================================
D [02/May/2012:18:42:39 +0100] [Job 29] 
D [02/May/2012:18:42:39 +0100] [Job 29] Filetype: PDF
D [02/May/2012:18:42:39 +0100] [Job 29] Storing temporary files in /var/spool/cups/tmp
D [02/May/2012:18:42:39 +0100] PID 14187 (/usr/lib/cups/filter/pdftopdf) exited with no errors.
D [02/May/2012:18:42:39 +0100] [Job 29] File contains 1 pages
D [02/May/2012:18:42:39 +0100] [Job 29] 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-SBOh4J 
D [02/May/2012:18:42:39 +0100] [Job 29] Starting process "kid3" (generation 1)
D [02/May/2012:18:42:39 +0100] [Job 29] Starting process "kid4" (generation 2)
D [02/May/2012:18:42:39 +0100] [Job 29] JCL: %-12345X@PJL
D [02/May/2012:18:42:39 +0100] [Job 29] @PJL SET DENSITY=3
D [02/May/2012:18:42:39 +0100] [Job 29] @PJL SET RET=MEDIUM
D [02/May/2012:18:42:39 +0100] [Job 29] @PJL SET COPIES=1
D [02/May/2012:18:42:39 +0100] [Job 29] @PJL SET ECONOMODE=OFF
D [02/May/2012:18:42:39 +0100] [Job 29] @PJL SET MANUALFEED=OFF
D [02/May/2012:18:42:39 +0100] [Job 29] <job data> %-12345X@PJL RESET
D [02/May/2012:18:42:39 +0100] [Job 29] 
D [02/May/2012:18:42:39 +0100] [Job 29] 
D [02/May/2012:18:42:39 +0100] [Job 29] Starting process "renderer" (generation 2)
D [02/May/2012:18:42:39 +0100] [Job 29] STATE: +connecting-to-device
D [02/May/2012:18:42:39 +0100] cupsdMarkDirty(-----S)
D [02/May/2012:18:42:39 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Printing jobs and dirty files"
D [02/May/2012:18:42:39 +0100] [Notifier] state=3
D [02/May/2012:18:42:39 +0100] [Job 29] STATE: -connecting-to-device
D [02/May/2012:18:42:39 +0100] cupsdMarkDirty(-----S)
D [02/May/2012:18:42:39 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Dirty files"
D [02/May/2012:18:42:39 +0100] [Notifier] state=3
D [02/May/2012:18:42:39 +0100] [Job 29] renderer exited with status 0
D [02/May/2012:18:42:39 +0100] [Job 29] kid4 exited with status 0
D [02/May/2012:18:42:39 +0100] [Job 29] kid3 finished
D [02/May/2012:18:42:39 +0100] [Job 29] Kid3 exit status: 0
D [02/May/2012:18:42:39 +0100] [Job 29] 
D [02/May/2012:18:42:39 +0100] [Job 29] Closing foomatic-rip.
D [02/May/2012:18:42:39 +0100] PID 14188 (/usr/lib/cups/filter/foomatic-rip) exited with no errors.
I [02/May/2012:18:42:44 +0100] [Job 29] Waiting for printer to become available.
D [02/May/2012:18:42:44 +0100] [Job 29] Set job-printer-state-message to "Waiting for printer to become available.", current level=INFO
D [02/May/2012:18:42:44 +0100] cupsdMarkDirty(-----S)
D [02/May/2012:18:42:44 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [02/May/2012:18:42:44 +0100] cupsdMarkDirty(-----S)
D [02/May/2012:18:42:44 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [02/May/2012:18:42:44 +0100] [Notifier] state=3
D [02/May/2012:18:42:44 +0100] [Notifier] state=3
D [02/May/2012:18:42:49 +0100] [Job 29] libusb_get_device_list=18
D [02/May/2012:18:42:49 +0100] [Job 29] STATE: +connecting-to-device
D [02/May/2012:18:42:49 +0100] cupsdMarkDirty(-----S)
D [02/May/2012:18:42:49 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Printing jobs and dirty files"
D [02/May/2012:18:42:49 +0100] [Notifier] state=3
D [02/May/2012:18:42:49 +0100] [Job 29] STATE: -connecting-to-device
D [02/May/2012:18:42:49 +0100] cupsdMarkDirty(-----S)
D [02/May/2012:18:42:49 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Dirty files"
D [02/May/2012:18:42:49 +0100] [Notifier] state=3
I [02/May/2012:18:42:59 +0100] [Job 29] Waiting for printer to become available.
D [02/May/2012:18:43:04 +0100] [Job 29] libusb_get_device_list=18
D [02/May/2012:18:43:04 +0100] [Job 29] STATE: +connecting-to-device
D [02/May/2012:18:43:04 +0100] cupsdMarkDirty(-----S)
D [02/May/2012:18:43:04 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Printing jobs and dirty files"
D [02/May/2012:18:43:04 +0100] [Notifier] state=3
D [02/May/2012:18:43:04 +0100] [Job 29] STATE: -connecting-to-device
D [02/May/2012:18:43:04 +0100] cupsdMarkDirty(-----S)
D [02/May/2012:18:43:04 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Dirty files"
D [02/May/2012:18:43:04 +0100] [Notifier] state=3
I [02/May/2012:18:43:10 +0100] Saving job.cache...
I [02/May/2012:18:43:10 +0100] Saving subscriptions.conf...
D [02/May/2012:18:43:10 +0100] cupsdSetBusyState: newbusy="Printing jobs", busy="Printing jobs and dirty files"
I [02/May/2012:18:43:14 +0100] [Job 29] Waiting for printer to become available.
D [02/May/2012:18:43:19 +0100] [Job 29] libusb_get_device_list=18
D [02/May/2012:18:43:19 +0100] [Job 29] STATE: +connecting-to-device
D [02/May/2012:18:43:19 +0100] cupsdMarkDirty(-----S)
D [02/May/2012:18:43:19 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Printing jobs"
D [02/May/2012:18:43:19 +0100] [Notifier] state=3
D [02/May/2012:18:43:19 +0100] [Job 29] STATE: -connecting-to-device
D [02/May/2012:18:43:19 +0100] cupsdMarkDirty(-----S)
D [02/May/2012:18:43:19 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Dirty files"
D [02/May/2012:18:43:19 +0100] [Notifier] state=3
I [02/May/2012:18:43:29 +0100] [Job 29] Waiting for printer to become available.
D [02/May/2012:18:43:34 +0100] [Job 29] libusb_get_device_list=18
D [02/May/2012:18:43:34 +0100] [Job 29] STATE: +connecting-to-device
D [02/May/2012:18:43:34 +0100] cupsdMarkDirty(-----S)
D [02/May/2012:18:43:34 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Printing jobs and dirty files"
D [02/May/2012:18:43:34 +0100] [Notifier] state=3
D [02/May/2012:18:43:34 +0100] [Job 29] STATE: -connecting-to-device
D [02/May/2012:18:43:34 +0100] cupsdMarkDirty(-----S)
D [02/May/2012:18:43:34 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Dirty files"
D [02/May/2012:18:43:34 +0100] [Notifier] state=3
I [02/May/2012:18:43:44 +0100] [Job 29] Waiting for printer to become available.
D [02/May/2012:18:43:44 +0100] Report: clients=0
D [02/May/2012:18:43:44 +0100] Report: jobs=2
D [02/May/2012:18:43:44 +0100] Report: jobs-active=1
D [02/May/2012:18:43:44 +0100] Report: printers=1
D [02/May/2012:18:43:44 +0100] Report: printers-implicit=0
D [02/May/2012:18:43:44 +0100] Report: stringpool-string-count=3161
D [02/May/2012:18:43:44 +0100] Report: stringpool-alloc-bytes=10848
D [02/May/2012:18:43:44 +0100] Report: stringpool-total-bytes=53248
D [02/May/2012:18:43:49 +0100] [Job 29] libusb_get_device_list=18
I [02/May/2012:18:43:49 +0100] Saving subscriptions.conf...
D [02/May/2012:18:43:50 +0100] cupsdSetBusyState: newbusy="Printing jobs", busy="Printing jobs and dirty files"
D [02/May/2012:18:43:50 +0100] [Job 29] STATE: +connecting-to-device
D [02/May/2012:18:43:50 +0100] [Job 29] STATE: -connecting-to-device
D [02/May/2012:18:43:50 +0100] cupsdMarkDirty(-----S)
D [02/May/2012:18:43:50 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs"
D [02/May/2012:18:43:50 +0100] [Notifier] state=3
I [02/May/2012:18:44:00 +0100] [Job 29] Waiting for printer to become available.
D [02/May/2012:18:44:05 +0100] [Job 29] libusb_get_device_list=18
D [02/May/2012:18:44:05 +0100] [Job 29] STATE: +connecting-to-device
D [02/May/2012:18:44:05 +0100] cupsdMarkDirty(-----S)
D [02/May/2012:18:44:05 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Printing jobs and dirty files"
D [02/May/2012:18:44:05 +0100] [Notifier] state=3
D [02/May/2012:18:44:05 +0100] [Job 29] STATE: -connecting-to-device
D [02/May/2012:18:44:05 +0100] cupsdMarkDirty(-----S)
D [02/May/2012:18:44:05 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Dirty files"
D [02/May/2012:18:44:05 +0100] [Notifier] state=3
I [02/May/2012:18:44:15 +0100] [Job 29] Waiting for printer to become available.
D [02/May/2012:18:44:20 +0100] [Job 29] libusb_get_device_list=18
I [02/May/2012:18:44:20 +0100] Saving subscriptions.conf...
D [02/May/2012:18:44:20 +0100] cupsdSetBusyState: newbusy="Printing jobs", busy="Printing jobs and dirty files"
D [02/May/2012:18:44:20 +0100] [Job 29] STATE: +connecting-to-device
D [02/May/2012:18:44:20 +0100] [Job 29] STATE: -connecting-to-device
D [02/May/2012:18:44:20 +0100] cupsdMarkDirty(-----S)
D [02/May/2012:18:44:20 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs"
D [02/May/2012:18:44:20 +0100] [Notifier] state=3
I [02/May/2012:18:44:30 +0100] [Job 29] Waiting for printer to become available.
D [02/May/2012:18:44:35 +0100] [Job 29] libusb_get_device_list=18
D [02/May/2012:18:44:35 +0100] [Job 29] STATE: +connecting-to-device
D [02/May/2012:18:44:35 +0100] cupsdMarkDirty(-----S)
D [02/May/2012:18:44:35 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Printing jobs and dirty files"
D [02/May/2012:18:44:35 +0100] [Notifier] state=3
D [02/May/2012:18:44:35 +0100] [Job 29] STATE: -connecting-to-device
D [02/May/2012:18:44:35 +0100] cupsdMarkDirty(-----S)
D [02/May/2012:18:44:35 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Dirty files"
D [02/May/2012:18:44:35 +0100] [Notifier] state=3
I [02/May/2012:18:44:45 +0100] [Job 29] Waiting for printer to become available.
D [02/May/2012:18:44:45 +0100] Report: clients=0
D [02/May/2012:18:44:45 +0100] Report: jobs=2
D [02/May/2012:18:44:45 +0100] Report: jobs-active=1
D [02/May/2012:18:44:45 +0100] Report: printers=1
D [02/May/2012:18:44:45 +0100] Report: printers-implicit=0
D [02/May/2012:18:44:45 +0100] Report: stringpool-string-count=3275
D [02/May/2012:18:44:45 +0100] Report: stringpool-alloc-bytes=10848
D [02/May/2012:18:44:45 +0100] Report: stringpool-total-bytes=55680
D [02/May/2012:18:44:50 +0100] [Job 29] libusb_get_device_list=18
I [02/May/2012:18:44:50 +0100] Saving subscriptions.conf...
D [02/May/2012:18:44:50 +0100] cupsdSetBusyState: newbusy="Printing jobs", busy="Printing jobs and dirty files"
D [02/May/2012:18:44:50 +0100] [Job 29] STATE: +connecting-to-device
D [02/May/2012:18:44:50 +0100] [Job 29] STATE: -connecting-to-device
D [02/May/2012:18:44:50 +0100] cupsdMarkDirty(-----S)
D [02/May/2012:18:44:50 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs"
D [02/May/2012:18:44:50 +0100] [Notifier] state=3
I [02/May/2012:18:45:00 +0100] [Job 29] Waiting for printer to become available.
D [02/May/2012:18:45:05 +0100] [Job 29] libusb_get_device_list=18
D [02/May/2012:18:45:05 +0100] [Job 29] STATE: +connecting-to-device
D [02/May/2012:18:45:05 +0100] cupsdMarkDirty(-----S)
D [02/May/2012:18:45:05 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Printing jobs and dirty files"
D [02/May/2012:18:45:05 +0100] [Notifier] state=3
D [02/May/2012:18:45:05 +0100] [Job 29] STATE: -connecting-to-device
D [02/May/2012:18:45:05 +0100] cupsdMarkDirty(-----S)
D [02/May/2012:18:45:05 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Dirty files"
D [02/May/2012:18:45:05 +0100] [Notifier] state=3
I [02/May/2012:18:45:15 +0100] [Job 29] Waiting for printer to become available.
D [02/May/2012:18:45:20 +0100] [Job 29] libusb_get_device_list=18
I [02/May/2012:18:45:20 +0100] Saving subscriptions.conf...
D [02/May/2012:18:45:21 +0100] cupsdSetBusyState: newbusy="Printing jobs", busy="Printing jobs and dirty files"
D [02/May/2012:18:45:21 +0100] [Job 29] STATE: +connecting-to-device
D [02/May/2012:18:45:21 +0100] [Job 29] STATE: -connecting-to-device
D [02/May/2012:18:45:21 +0100] cupsdMarkDirty(-----S)
D [02/May/2012:18:45:21 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs"
D [02/May/2012:18:45:21 +0100] [Notifier] state=3
I [02/May/2012:18:45:31 +0100] [Job 29] Waiting for printer to become available.
D [02/May/2012:18:45:36 +0100] [Job 29] libusb_get_device_list=18
D [02/May/2012:18:45:36 +0100] [Job 29] STATE: +connecting-to-device
D [02/May/2012:18:45:36 +0100] cupsdMarkDirty(-----S)
D [02/May/2012:18:45:36 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Printing jobs and dirty files"
D [02/May/2012:18:45:36 +0100] [Notifier] state=3
D [02/May/2012:18:45:36 +0100] [Job 29] STATE: -connecting-to-device
D [02/May/2012:18:45:36 +0100] cupsdMarkDirty(-----S)
D [02/May/2012:18:45:36 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Dirty files"
D [02/May/2012:18:45:36 +0100] [Notifier] state=3
D [02/May/2012:18:45:38 +0100] cupsdAcceptClient: 17 from localhost (Domain)
D [02/May/2012:18:45:38 +0100] cupsdReadClient: 17 POST / HTTP/1.1
D [02/May/2012:18:45:38 +0100] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Printing jobs and dirty files"
D [02/May/2012:18:45:38 +0100] cupsdAuthorize: Authorized as al using PeerCred
D [02/May/2012:18:45:38 +0100] cupsdReadClient: 17 1.1 Renew-Subscription 1
D [02/May/2012:18:45:38 +0100] Renew-Subscription /
D [02/May/2012:18:45:38 +0100] cupsdIsAuthorized: username="al"
D [02/May/2012:18:45:38 +0100] cupsdMarkDirty(-----S)
D [02/May/2012:18:45:38 +0100] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Active clients, printing jobs, and dirty files"
D [02/May/2012:18:45:38 +0100] Returning IPP successful-ok for Renew-Subscription (/) from localhost
D [02/May/2012:18:45:38 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients, printing jobs, and dirty files"
I [02/May/2012:18:45:46 +0100] [Job 29] Waiting for printer to become available.
D [02/May/2012:18:45:46 +0100] Report: clients=1
D [02/May/2012:18:45:46 +0100] Report: jobs=2
D [02/May/2012:18:45:46 +0100] Report: jobs-active=1
D [02/May/2012:18:45:46 +0100] Report: printers=1
D [02/May/2012:18:45:46 +0100] Report: printers-implicit=0
D [02/May/2012:18:45:46 +0100] Report: stringpool-string-count=3389
D [02/May/2012:18:45:46 +0100] Report: stringpool-alloc-bytes=10848
D [02/May/2012:18:45:46 +0100] Report: stringpool-total-bytes=58112
D [02/May/2012:18:45:51 +0100] [Job 29] libusb_get_device_list=18
I [02/May/2012:18:45:51 +0100] Saving subscriptions.conf...
D [02/May/2012:18:45:51 +0100] cupsdSetBusyState: newbusy="Printing jobs", busy="Printing jobs and dirty files"
D [02/May/2012:18:45:51 +0100] [Job 29] STATE: +connecting-to-device
D [02/May/2012:18:45:51 +0100] [Job 29] STATE: -connecting-to-device
D [02/May/2012:18:45:51 +0100] cupsdMarkDirty(-----S)
D [02/May/2012:18:45:51 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs"
D [02/May/2012:18:45:51 +0100] [Notifier] state=3
I [02/May/2012:18:46:01 +0100] [Job 29] Waiting for printer to become available.
D [02/May/2012:18:46:06 +0100] [Job 29] libusb_get_device_list=18
D [02/May/2012:18:46:06 +0100] [Job 29] STATE: +connecting-to-device
D [02/May/2012:18:46:06 +0100] cupsdMarkDirty(-----S)
D [02/May/2012:18:46:06 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Printing jobs and dirty files"
D [02/May/2012:18:46:06 +0100] [Notifier] state=3
D [02/May/2012:18:46:06 +0100] [Job 29] STATE: -connecting-to-device
D [02/May/2012:18:46:06 +0100] cupsdMarkDirty(-----S)
D [02/May/2012:18:46:06 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Dirty files"
D [02/May/2012:18:46:06 +0100] [Notifier] state=3
I [02/May/2012:18:46:16 +0100] [Job 29] Waiting for printer to become available.
D [02/May/2012:18:46:21 +0100] [Job 29] libusb_get_device_list=18
I [02/May/2012:18:46:21 +0100] Saving subscriptions.conf...
D [02/May/2012:18:46:21 +0100] cupsdSetBusyState: newbusy="Printing jobs", busy="Printing jobs and dirty files"
D [02/May/2012:18:46:21 +0100] [Job 29] STATE: +connecting-to-device
D [02/May/2012:18:46:21 +0100] [Job 29] STATE: -connecting-to-device
D [02/May/2012:18:46:21 +0100] cupsdMarkDirty(-----S)
D [02/May/2012:18:46:21 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs"
D [02/May/2012:18:46:21 +0100] [Notifier] state=3
I [02/May/2012:18:46:31 +0100] [Job 29] Waiting for printer to become available.
D [02/May/2012:18:46:36 +0100] [Job 29] libusb_get_device_list=18
D [02/May/2012:18:46:36 +0100] [Job 29] STATE: +connecting-to-device
D [02/May/2012:18:46:36 +0100] cupsdMarkDirty(-----S)
D [02/May/2012:18:46:36 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Printing jobs and dirty files"
D [02/May/2012:18:46:36 +0100] [Notifier] state=3
D [02/May/2012:18:46:36 +0100] [Job 29] STATE: -connecting-to-device
D [02/May/2012:18:46:36 +0100] cupsdMarkDirty(-----S)
D [02/May/2012:18:46:36 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Dirty files"
D [02/May/2012:18:46:36 +0100] [Notifier] state=3
I [02/May/2012:18:46:46 +0100] [Job 29] Waiting for printer to become available.
D [02/May/2012:18:46:46 +0100] Report: clients=1
D [02/May/2012:18:46:46 +0100] Report: jobs=2
D [02/May/2012:18:46:46 +0100] Report: jobs-active=1
D [02/May/2012:18:46:46 +0100] Report: printers=1
D [02/May/2012:18:46:46 +0100] Report: printers-implicit=0
D [02/May/2012:18:46:46 +0100] Report: stringpool-string-count=3503
D [02/May/2012:18:46:46 +0100] Report: stringpool-alloc-bytes=10848
D [02/May/2012:18:46:46 +0100] Report: stringpool-total-bytes=60544
D [02/May/2012:18:46:51 +0100] [Job 29] libusb_get_device_list=18
I [02/May/2012:18:46:51 +0100] Saving subscriptions.conf...
D [02/May/2012:18:46:52 +0100] cupsdSetBusyState: newbusy="Printing jobs", busy="Printing jobs and dirty files"
D [02/May/2012:18:46:52 +0100] [Job 29] STATE: +connecting-to-device
D [02/May/2012:18:46:52 +0100] [Job 29] STATE: -connecting-to-device
D [02/May/2012:18:46:52 +0100] cupsdMarkDirty(-----S)
D [02/May/2012:18:46:52 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs"
D [02/May/2012:18:46:52 +0100] [Notifier] state=3