CUPS won't print to a brother MFC-8460N

Tue Oct 18 23:45:49 PDT 2011

Hi,

Would be great if someone could help to come a step further in this problem.

I use CUPS version 1.4.6.
To save memory, I'm using MDEV instead of UDEV on my system.
I already tried with UDEV - this is working - but it need to get it running using MDEV.

The strange thing I face:
If I run the usb backend by hand, it recogizes the printer:

root at ccp511:~# /usr/lib/cups/backend/usb
DEBUG: list_devices
DEBUG: usb_find_busses=4
DEBUG: usb_find_devices=6
direct usb://Brother/MFC-8460N?serial=000K7J552309 "Brother MFC-8460N" "Brother MFC-8460N" "MFG:Brother;CMD:PJL,PCL,PCLXL;MDL:MFC-8460N;CLS:PRINTER;" ""
root at ccp511:~#

So I use usb://Brother/MFC-8460N?serial=000K7J552309 as device URI which was working perfect with udev.
But trying to print something leads to the following printer state:

root at ccp511:~# lpstat -t
scheduler is running
system default destination: brother
device for brother: usb://Brother/MFC-8460N?serial=000K7J552309
brother accepting requests since Wed Oct 19 08:20:06 2011
printer brother now printing brother-1.  enabled since Wed Oct 19 08:20:06 2011
	Waiting for printer to become available...
brother-1               root            656384   Wed Oct 19 07:54:48 2011
root at ccp511:~#

I already searched with all the Debug messages in the cups log in the internet but nothing helped so far. here the debugLog:

root at ccp511:~# cat /var/log/cups/error_log
E [19/Oct/2011:07:51:27 +0000] Unknown SystemGroup "lpadmin sys root" on line 15, ignoring!
I [19/Oct/2011:07:51:27 +0000] Listening to ::1:631 (IPv6)
I [19/Oct/2011:07:51:27 +0000] Listening to 127.0.0.1:631 (IPv4)
I [19/Oct/2011:07:51:27 +0000] Listening to /var/run/cups/cups.sock (Domain)
I [19/Oct/2011:07:51:27 +0000] Remote access is disabled.
D [19/Oct/2011:07:51:27 +0000] Added auto ServerAlias ccp511
I [19/Oct/2011:07:51:27 +0000] Loaded configuration file "/etc/cups/cupsd.conf"
D [19/Oct/2011:07:51:27 +0000] Creating missing directory "/var/cache/cups"
D [19/Oct/2011:07:51:27 +0000] Repairing ownership of "/var/cache/cups"
D [19/Oct/2011:07:51:27 +0000] Repairing access permissions of "/var/cache/cups"
D [19/Oct/2011:07:51:27 +0000] Creating missing directory "/var/cache/cups/rss"
D [19/Oct/2011:07:51:27 +0000] Repairing ownership of "/var/cache/cups/rss"
D [19/Oct/2011:07:51:27 +0000] Repairing access permissions of "/var/cache/cups/rss"
D [19/Oct/2011:07:51:27 +0000] Creating missing directory "/var/run/cups"
D [19/Oct/2011:07:51:27 +0000] Repairing ownership of "/var/run/cups"
D [19/Oct/2011:07:51:27 +0000] Repairing access permissions of "/var/run/cups"
D [19/Oct/2011:07:51:28 +0000] Creating missing directory "/var/run/cups/certs"
D [19/Oct/2011:07:51:28 +0000] Repairing ownership of "/var/run/cups/certs"
D [19/Oct/2011:07:51:28 +0000] Repairing access permissions of "/var/run/cups/certs"
I [19/Oct/2011:07:51:28 +0000] Using default TempDir of /var/spool/cups/tmp...
I [19/Oct/2011:07:51:28 +0000] Configured for up to 100 clients.
I [19/Oct/2011:07:51:28 +0000] Allowing up to 100 client connections per host.
I [19/Oct/2011:07:51:28 +0000] Using policy "default" as the default!
I [19/Oct/2011:07:51:28 +0000] Full reload is required.
I [19/Oct/2011:07:51:28 +0000] Loaded MIME database from "/usr/share/cups/mime" and "/mnt/drive-C/sysprint": 35 types, 46 filters...
D [19/Oct/2011:07:51:28 +0000] Scanning /var/spool/cups for jobs...
I [19/Oct/2011:07:51:28 +0000] Full reload complete.
D [19/Oct/2011:07:51:28 +0000] cupsd_clean_files(path="/var/spool/cups/tmp", pattern="(null)")
I [19/Oct/2011:07:51:28 +0000] Cleaning out old files in "/var/spool/cups/tmp"...
D [19/Oct/2011:07:51:28 +0000] cupsd_clean_files(path="/var/cache/cups", pattern="*.ipp")
I [19/Oct/2011:07:51:28 +0000] Cleaning out old files in "/var/cache/cups"...
E [19/Oct/2011:07:51:28 +0000] Unable to open listen socket for address ::1:631 - Address family not supported by protocol.
I [19/Oct/2011:07:51:28 +0000] Listening to 127.0.0.1:631 on fd 4...
I [19/Oct/2011:07:51:28 +0000] Listening to /var/run/cups/cups.sock on fd 6...
I [19/Oct/2011:07:51:28 +0000] Resuming new connection processing...
D [19/Oct/2011:07:51:28 +0000] Discarding unused server-started event...
D [19/Oct/2011:07:51:29 +0000] Report: clients=0
D [19/Oct/2011:07:51:29 +0000] Report: jobs=0
D [19/Oct/2011:07:51:29 +0000] Report: jobs-active=0
D [19/Oct/2011:07:51:29 +0000] Report: printers=0
D [19/Oct/2011:07:51:29 +0000] Report: printers-implicit=0
D [19/Oct/2011:07:51:29 +0000] Report: stringpool-string-count=122
D [19/Oct/2011:07:51:29 +0000] Report: stringpool-alloc-bytes=3872
D [19/Oct/2011:07:51:29 +0000] Report: stringpool-total-bytes=2944
D [19/Oct/2011:07:54:39 +0000] cupsdAcceptClient: 10 from localhost (Domain)
D [19/Oct/2011:07:54:39 +0000] Report: clients=1
D [19/Oct/2011:07:54:39 +0000] Report: jobs=0
D [19/Oct/2011:07:54:39 +0000] Report: jobs-active=0
D [19/Oct/2011:07:54:39 +0000] Report: printers=0
D [19/Oct/2011:07:54:39 +0000] Report: printers-implicit=0
D [19/Oct/2011:07:54:39 +0000] Report: stringpool-string-count=122
D [19/Oct/2011:07:54:39 +0000] Report: stringpool-alloc-bytes=3872
D [19/Oct/2011:07:54:39 +0000] Report: stringpool-total-bytes=2944
D [19/Oct/2011:07:54:39 +0000] cupsdReadClient: 10 POST /root/ HTTP/1.1
D [19/Oct/2011:07:54:39 +0000] cupsdSetBusyState: Active clients
D [19/Oct/2011:07:54:39 +0000] cupsdAuthorize: No authentication data provided.
D [19/Oct/2011:07:54:39 +0000] cupsdReadClient: 10 1.1 CUPS-Add-Modify-Printer 1
D [19/Oct/2011:07:54:39 +0000] CUPS-Add-Modify-Printer ipp://localhost/printers/brother
D [19/Oct/2011:07:54:39 +0000] cupsdIsAuthorized: username=""
D [19/Oct/2011:07:54:39 +0000] Returning HTTP Unauthorized for CUPS-Add-Modify-Printer (ipp://localhost/printers/brother) from localhost
D [19/Oct/2011:07:54:39 +0000] cupsdSendHeader: 10 WWW-Authenticate: Basic realm="CUPS", trc="y"
D [19/Oct/2011:07:54:39 +0000] cupsdReadClient: 10 WAITING Closing on EOF
D [19/Oct/2011:07:54:39 +0000] cupsdCloseClient: 10
D [19/Oct/2011:07:54:39 +0000] cupsdSetBusyState: Not busy
D [19/Oct/2011:07:54:39 +0000] cupsdAcceptClient: 10 from localhost (Domain)
D [19/Oct/2011:07:54:39 +0000] cupsdReadClient: 10 WAITING Closing on EOF
D [19/Oct/2011:07:54:39 +0000] cupsdCloseClient: 10
D [19/Oct/2011:07:54:39 +0000] cupsdAcceptClient: 10 from localhost (Domain)
D [19/Oct/2011:07:54:39 +0000] cupsdReadClient: 10 POST /root/ HTTP/1.1
D [19/Oct/2011:07:54:39 +0000] cupsdSetBusyState: Active clients
D [19/Oct/2011:07:54:39 +0000] cupsdAuthorize: Authorized as root using PeerCred
D [19/Oct/2011:07:54:39 +0000] cupsdReadClient: 10 1.1 CUPS-Add-Modify-Printer 1
D [19/Oct/2011:07:54:39 +0000] CUPS-Add-Modify-Printer ipp://localhost/printers/brother
D [19/Oct/2011:07:54:39 +0000] cupsdIsAuthorized: username="root"
I [19/Oct/2011:07:54:39 +0000] Setting brother printer-is-accepting-jobs to 1 (was 0.)
D [19/Oct/2011:07:54:39 +0000] Discarding unused printer-state-changed event...
I [19/Oct/2011:07:54:39 +0000] Setting brother printer-state to 3 (was 5.)
D [19/Oct/2011:07:54:39 +0000] Discarding unused printer-state-changed event...
D [19/Oct/2011:07:54:39 +0000] cupsdMarkDirty(P-----)
D [19/Oct/2011:07:54:39 +0000] cupsdSetBusyState: Active clients and dirty files
D [19/Oct/2011:07:54:39 +0000] load_ppd: Loading /mnt/drive-C/sysprint/ppd/brother.ppd...
D [19/Oct/2011:07:54:39 +0000] cupsdRegisterPrinter(p=0x80c9c78(brother))
D [19/Oct/2011:07:54:39 +0000] cupsdMarkDirty(P-----)
D [19/Oct/2011:07:54:39 +0000] cupsdMarkDirty(---p--)
D [19/Oct/2011:07:54:39 +0000] Discarding unused printer-added event...
I [19/Oct/2011:07:54:39 +0000] New printer "brother" added by "root".
D [19/Oct/2011:07:54:39 +0000] Returning IPP successful-ok for CUPS-Add-Modify-Printer (ipp://localhost/printers/brother) from localhost
D [19/Oct/2011:07:54:39 +0000] cupsdSetBusyState: Dirty files
D [19/Oct/2011:07:54:39 +0000] cupsdReadClient: 10 POST / HTTP/1.1
D [19/Oct/2011:07:54:39 +0000] cupsdSetBusyState: Active clients and dirty files
D [19/Oct/2011:07:54:39 +0000] cupsdAuthorize: Authorized as root using PeerCred
D [19/Oct/2011:07:54:39 +0000] cupsdReadClient: 10 1.1 Get-Printer-Attributes 1
D [19/Oct/2011:07:54:39 +0000] Get-Printer-Attributes ipp://localhost/printers/brother
D [19/Oct/2011:07:54:39 +0000] Returning IPP successful-ok for Get-Printer-Attributes (ipp://localhost/printers/brother) from localhost
D [19/Oct/2011:07:54:39 +0000] cupsdSetBusyState: Dirty files
D [19/Oct/2011:07:54:39 +0000] cupsdReadClient: 10 POST /root/ HTTP/1.1
D [19/Oct/2011:07:54:39 +0000] cupsdSetBusyState: Active clients and dirty files
D [19/Oct/2011:07:54:39 +0000] cupsdAuthorize: Authorized as root using PeerCred
D [19/Oct/2011:07:54:39 +0000] cupsdReadClient: 10 1.1 CUPS-Add-Modify-Printer 1
D [19/Oct/2011:07:54:39 +0000] CUPS-Add-Modify-Printer ipp://localhost/printers/brother
D [19/Oct/2011:07:54:39 +0000] cupsdIsAuthorized: username="root"
I [19/Oct/2011:07:54:39 +0000] Setting brother device-uri to "usb://Brother/MFC-8460N?serial=000K7J552309" (was "file:///dev/null".)
D [19/Oct/2011:07:54:39 +0000] Copied PPD file successfully!
D [19/Oct/2011:07:54:39 +0000] cupsdMarkDirty(P-----)
D [19/Oct/2011:07:54:39 +0000] cupsdMarkDirty(P-----)
D [19/Oct/2011:07:54:39 +0000] load_ppd: Loading /mnt/drive-C/sysprint/ppd/brother.ppd...
D [19/Oct/2011:07:54:39 +0000] load_ppd: Saving /var/cache/cups/brother.ipp4...
D [19/Oct/2011:07:54:40 +0000] cupsdRegisterPrinter(p=0x80c9c78(brother))
D [19/Oct/2011:07:54:40 +0000] cupsdMarkDirty(P-----)
D [19/Oct/2011:07:54:40 +0000] cupsdMarkDirty(---p--)
D [19/Oct/2011:07:54:40 +0000] Discarding unused printer-modified event...
I [19/Oct/2011:07:54:40 +0000] Printer "brother" modified by "root".
D [19/Oct/2011:07:54:40 +0000] Returning IPP successful-ok for CUPS-Add-Modify-Printer (ipp://localhost/printers/brother) from localhost
D [19/Oct/2011:07:54:40 +0000] cupsdSetBusyState: Dirty files
D [19/Oct/2011:07:54:40 +0000] cupsdAcceptClient: 13 from localhost (Domain)
D [19/Oct/2011:07:54:40 +0000] cupsdReadClient: 13 POST / HTTP/1.1
D [19/Oct/2011:07:54:40 +0000] cupsdSetBusyState: Active clients and dirty files
D [19/Oct/2011:07:54:40 +0000] cupsdAuthorize: No authentication data provided.
D [19/Oct/2011:07:54:40 +0000] cupsdReadClient: 13 1.1 CUPS-Get-Default 1
D [19/Oct/2011:07:54:40 +0000] CUPS-Get-Default
D [19/Oct/2011:07:54:40 +0000] CUPS-Get-Default client-error-not-found: No default printer
D [19/Oct/2011:07:54:40 +0000] Returning IPP client-error-not-found for CUPS-Get-Default (no URI) from localhost
D [19/Oct/2011:07:54:40 +0000] cupsdSetBusyState: Dirty files
D [19/Oct/2011:07:54:40 +0000] cupsdReadClient: 13 POST / HTTP/1.1
D [19/Oct/2011:07:54:40 +0000] cupsdSetBusyState: Active clients and dirty files
D [19/Oct/2011:07:54:40 +0000] cupsdAuthorize: No authentication data provided.
D [19/Oct/2011:07:54:40 +0000] cupsdReadClient: 13 1.1 CUPS-Get-Printers 1
D [19/Oct/2011:07:54:40 +0000] CUPS-Get-Printers
D [19/Oct/2011:07:54:40 +0000] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost
D [19/Oct/2011:07:54:40 +0000] cupsdSetBusyState: Dirty files
D [19/Oct/2011:07:54:40 +0000] cupsdReadClient: 13 POST / HTTP/1.1
D [19/Oct/2011:07:54:40 +0000] cupsdSetBusyState: Active clients and dirty files
D [19/Oct/2011:07:54:40 +0000] cupsdAuthorize: No authentication data provided.
D [19/Oct/2011:07:54:40 +0000] cupsdReadClient: 13 1.1 CUPS-Get-Default 1
D [19/Oct/2011:07:54:40 +0000] CUPS-Get-Default
D [19/Oct/2011:07:54:40 +0000] CUPS-Get-Default client-error-not-found: No default printer
D [19/Oct/2011:07:54:40 +0000] Returning IPP client-error-not-found for CUPS-Get-Default (no URI) from localhost
D [19/Oct/2011:07:54:40 +0000] cupsdSetBusyState: Dirty files
D [19/Oct/2011:07:54:40 +0000] cupsdReadClient: 13 POST / HTTP/1.1
D [19/Oct/2011:07:54:40 +0000] cupsdSetBusyState: Active clients and dirty files
D [19/Oct/2011:07:54:40 +0000] cupsdAuthorize: No authentication data provided.
D [19/Oct/2011:07:54:40 +0000] cupsdReadClient: 13 1.1 CUPS-Get-Printers 1
D [19/Oct/2011:07:54:40 +0000] CUPS-Get-Printers
D [19/Oct/2011:07:54:40 +0000] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost
D [19/Oct/2011:07:54:40 +0000] cupsdSetBusyState: Dirty files
D [19/Oct/2011:07:54:44 +0000] cupsdReadClient: 13 POST / HTTP/1.1
D [19/Oct/2011:07:54:44 +0000] cupsdSetBusyState: Active clients and dirty files
D [19/Oct/2011:07:54:44 +0000] cupsdAuthorize: No authentication data provided.
D [19/Oct/2011:07:54:44 +0000] cupsdReadClient: 13 1.1 CUPS-Get-Printers 1
D [19/Oct/2011:07:54:44 +0000] CUPS-Get-Printers
D [19/Oct/2011:07:54:44 +0000] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost
D [19/Oct/2011:07:54:44 +0000] cupsdSetBusyState: Dirty files
D [19/Oct/2011:07:54:44 +0000] cupsdReadClient: 13 POST / HTTP/1.1
D [19/Oct/2011:07:54:44 +0000] cupsdSetBusyState: Active clients and dirty files
D [19/Oct/2011:07:54:44 +0000] cupsdAuthorize: No authentication data provided.
D [19/Oct/2011:07:54:44 +0000] cupsdReadClient: 13 1.1 CUPS-Get-Default 1
D [19/Oct/2011:07:54:44 +0000] CUPS-Get-Default
D [19/Oct/2011:07:54:44 +0000] CUPS-Get-Default client-error-not-found: No default printer
D [19/Oct/2011:07:54:44 +0000] Returning IPP client-error-not-found for CUPS-Get-Default (no URI) from localhost
D [19/Oct/2011:07:54:44 +0000] cupsdSetBusyState: Dirty files
D [19/Oct/2011:07:54:44 +0000] cupsdReadClient: 13 POST / HTTP/1.1
D [19/Oct/2011:07:54:44 +0000] cupsdSetBusyState: Active clients and dirty files
D [19/Oct/2011:07:54:44 +0000] cupsdAuthorize: No authentication data provided.
D [19/Oct/2011:07:54:44 +0000] cupsdReadClient: 13 1.1 CUPS-Get-Printers 1
D [19/Oct/2011:07:54:44 +0000] CUPS-Get-Printers
D [19/Oct/2011:07:54:44 +0000] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost
D [19/Oct/2011:07:54:44 +0000] cupsdSetBusyState: Dirty files
D [19/Oct/2011:07:54:48 +0000] cupsdReadClient: 13 POST / HTTP/1.1
D [19/Oct/2011:07:54:48 +0000] cupsdSetBusyState: Active clients and dirty files
D [19/Oct/2011:07:54:48 +0000] cupsdAuthorize: No authentication data provided.
D [19/Oct/2011:07:54:48 +0000] cupsdReadClient: 13 1.1 Get-Printer-Attributes 1
D [19/Oct/2011:07:54:48 +0000] Get-Printer-Attributes ipp://localhost:631/printers/brother
D [19/Oct/2011:07:54:48 +0000] Returning IPP successful-ok for Get-Printer-Attributes (ipp://localhost:631/printers/brother) from localhost
D [19/Oct/2011:07:54:48 +0000] cupsdSetBusyState: Dirty files
D [19/Oct/2011:07:54:48 +0000] cupsdReadClient: 13 POST /printers/brother HTTP/1.1
D [19/Oct/2011:07:54:48 +0000] cupsdSetBusyState: Active clients and dirty files
D [19/Oct/2011:07:54:48 +0000] cupsdAuthorize: No authentication data provided.
D [19/Oct/2011:07:54:48 +0000] cupsdReadClient: 13 1.1 Create-Job 1
D [19/Oct/2011:07:54:48 +0000] Create-Job ipp://localhost:631/printers/brother
D [19/Oct/2011:07:54:48 +0000] cupsdMarkDirty(----J-)
D [19/Oct/2011:07:54:48 +0000] add_job: requesting-user-name="root"
I [19/Oct/2011:07:54:48 +0000] [Job 1] Adding start banner page "none".
D [19/Oct/2011:07:54:48 +0000] Discarding unused job-created event...
I [19/Oct/2011:07:54:48 +0000] [Job 1] Queued on "brother" by "root".
D [19/Oct/2011:07:54:48 +0000] Returning IPP successful-ok for Create-Job (ipp://localhost:631/printers/brother) from localhost
D [19/Oct/2011:07:54:48 +0000] cupsdSetBusyState: Dirty files
D [19/Oct/2011:07:54:48 +0000] cupsdReadClient: 13 POST /printers/brother HTTP/1.1
D [19/Oct/2011:07:54:48 +0000] cupsdSetBusyState: Active clients and dirty files
D [19/Oct/2011:07:54:48 +0000] cupsdAuthorize: No authentication data provided.
D [19/Oct/2011:07:54:48 +0000] cupsdReadClient: 13 1.1 Send-Document 1
D [19/Oct/2011:07:54:49 +0000] Send-Document ipp://localhost:631/printers/brother
D [19/Oct/2011:07:54:49 +0000] cupsdIsAuthorized: requesting-user-name="root"
D [19/Oct/2011:07:54:49 +0000] [Job 1] Auto-typing file...
D [19/Oct/2011:07:54:49 +0000] [Job 1] Request file type is image/x-bitmap.
D [19/Oct/2011:07:54:49 +0000] cupsdMarkDirty(----J-)
I [19/Oct/2011:07:54:49 +0000] [Job 1] File of type image/x-bitmap queued by "root".
I [19/Oct/2011:07:54:49 +0000] [Job 1] Adding end banner page "none".
D [19/Oct/2011:07:54:49 +0000] cupsdMarkDirty(----J-)
D [19/Oct/2011:07:54:49 +0000] cupsdMarkDirty(----J-)
D [19/Oct/2011:07:54:49 +0000] cupsdSetBusyState: Active clients, printing jobs, and dirty files
D [19/Oct/2011:07:54:49 +0000] Discarding unused printer-state-changed event...
D [19/Oct/2011:07:54:49 +0000] [Job 1] job-sheets=none,none
D [19/Oct/2011:07:54:49 +0000] [Job 1] argv[0]="brother"
D [19/Oct/2011:07:54:49 +0000] [Job 1] argv[1]="1"
D [19/Oct/2011:07:54:49 +0000] [Job 1] argv[2]="root"
D [19/Oct/2011:07:54:49 +0000] [Job 1] argv[3]="/mnt/drive-C/test.bmp"
D [19/Oct/2011:07:54:49 +0000] [Job 1] argv[4]="1"
D [19/Oct/2011:07:54:49 +0000] [Job 1] argv[5]="finishings=3 media=A4 number-up=1 job-uuid=urn:uuid:47ad159d-0abc-3473-4c6e-6dfd200cf637 job-originating-host-name=localhost time-at-creation=1319010888 time-at-processing=1319010889 AP_D_InputSlot= PageSize=A4"
D [19/Oct/2011:07:54:49 +0000] [Job 1] argv[6]="/var/spool/cups/d00001-001"
D [19/Oct/2011:07:54:49 +0000] [Job 1] envp[0]="CUPS_CACHEDIR=/var/cache/cups"
D [19/Oct/2011:07:54:49 +0000] [Job 1] envp[1]="CUPS_DATADIR=/usr/share/cups"
D [19/Oct/2011:07:54:49 +0000] [Job 1] envp[2]="CUPS_DOCROOT=/usr/share/doc/cups"
D [19/Oct/2011:07:54:49 +0000] [Job 1] envp[3]="CUPS_FONTPATH=/usr/share/cups/fonts"
D [19/Oct/2011:07:54:49 +0000] [Job 1] envp[4]="CUPS_REQUESTROOT=/var/spool/cups"
D [19/Oct/2011:07:54:49 +0000] [Job 1] envp[5]="CUPS_SERVERBIN=/usr/lib/cups"
D [19/Oct/2011:07:54:49 +0000] [Job 1] envp[6]="CUPS_SERVERROOT=/mnt/drive-C/sysprint"
D [19/Oct/2011:07:54:49 +0000] [Job 1] envp[7]="CUPS_STATEDIR=/var/run/cups"
D [19/Oct/2011:07:54:49 +0000] [Job 1] envp[8]="HOME=/var/spool/cups/tmp"
D [19/Oct/2011:07:54:49 +0000] [Job 1] envp[9]="PATH=/usr/lib/cups/filter:/usr/bin:/usr/sbin:/bin:/usr/bin"
D [19/Oct/2011:07:54:49 +0000] [Job 1] envp[10]="SERVER_ADMIN=root at ccp511"
D [19/Oct/2011:07:54:49 +0000] [Job 1] envp[11]="SOFTWARE=CUPS/1.4.6"
D [19/Oct/2011:07:54:49 +0000] [Job 1] envp[12]="TMPDIR=/var/spool/cups/tmp"
D [19/Oct/2011:07:54:49 +0000] [Job 1] envp[13]="USER=root"
D [19/Oct/2011:07:54:49 +0000] [Job 1] envp[14]="CUPS_SERVER=/var/run/cups/cups.sock"
D [19/Oct/2011:07:54:49 +0000] [Job 1] envp[15]="CUPS_ENCRYPTION=IfRequested"
D [19/Oct/2011:07:54:49 +0000] [Job 1] envp[16]="IPP_PORT=631"
D [19/Oct/2011:07:54:49 +0000] [Job 1] envp[17]="CHARSET=utf-8"
D [19/Oct/2011:07:54:49 +0000] [Job 1] envp[18]="LANG=en_US.UTF-8"
D [19/Oct/2011:07:54:49 +0000] [Job 1] envp[19]="PPD=/mnt/drive-C/sysprint/ppd/brother.ppd"
D [19/Oct/2011:07:54:49 +0000] [Job 1] envp[20]="RIP_MAX_CACHE=8m"
D [19/Oct/2011:07:54:49 +0000] [Job 1] envp[21]="CONTENT_TYPE=image/x-bitmap"
D [19/Oct/2011:07:54:49 +0000] [Job 1] envp[22]="DEVICE_URI=usb://Brother/MFC-8460N?serial=000K7J552309"
D [19/Oct/2011:07:54:49 +0000] [Job 1] envp[23]="PRINTER_INFO=brother"
D [19/Oct/2011:07:54:49 +0000] [Job 1] envp[24]="PRINTER_LOCATION="
D [19/Oct/2011:07:54:49 +0000] [Job 1] envp[25]="PRINTER=brother"
D [19/Oct/2011:07:54:49 +0000] [Job 1] envp[26]="CUPS_FILETYPE=document"
D [19/Oct/2011:07:54:49 +0000] [Job 1] envp[27]="FINAL_CONTENT_TYPE=application/vnd.cups-postscript"
I [19/Oct/2011:07:54:49 +0000] [Job 1] Started filter /usr/lib/cups/filter/imagetops (PID 339)
I [19/Oct/2011:07:54:49 +0000] [Job 1] Started backend /usr/lib/cups/backend/usb (PID 340)
D [19/Oct/2011:07:54:49 +0000] Discarding unused job-state-changed event...
D [19/Oct/2011:07:54:49 +0000] Returning IPP successful-ok for Send-Document (ipp://localhost:631/printers/brother) from localhost
D [19/Oct/2011:07:54:49 +0000] cupsdSetBusyState: Printing jobs and dirty files
D [19/Oct/2011:07:54:49 +0000] [Job 1] Page = 595x842; 12,12 to 583,830
D [19/Oct/2011:07:54:49 +0000] [Job 1] offset = 54
D [19/Oct/2011:07:54:49 +0000] [Job 1] Bad BMP resolution 0x0 PPI.
D [19/Oct/2011:07:54:49 +0000] [Job 1] info_size = 40, xsize = 658, ysize = 332, planes = 1, depth = 24
D [19/Oct/2011:07:54:49 +0000] [Job 1] compression = 0, image_size = 656032, xppi = 128, yppi = 128
D [19/Oct/2011:07:54:49 +0000] [Job 1] colors_used = 0, colors_important = 0
D [19/Oct/2011:07:54:49 +0000] [Job 1] print_device
D [19/Oct/2011:07:54:49 +0000] [Job 1] usb_find_busses=4
D [19/Oct/2011:07:54:49 +0000] [Job 1] usb_find_devices=6
D [19/Oct/2011:07:54:49 +0000] [Job 1] STATE: +connecting-to-device
D [19/Oct/2011:07:54:49 +0000] Discarding unused printer-state-changed event...
D [19/Oct/2011:07:54:49 +0000] [Job 1] Failed to set configuration 1 for 04f9:01a5
D [19/Oct/2011:07:54:49 +0000] [Job 1] Failed to claim interface 0 for 04f9:01a5: Operation not permitted
D [19/Oct/2011:07:54:49 +0000] [Job 1] STATE: -connecting-to-device
D [19/Oct/2011:07:54:49 +0000] Discarding unused printer-state-changed event...
I [19/Oct/2011:07:54:49 +0000] [Job 1] Waiting for printer to become available...
D [19/Oct/2011:07:54:49 +0000] Discarding unused job-progress event...
D [19/Oct/2011:07:54:49 +0000] Discarding unused printer-state-changed event...
D [19/Oct/2011:07:54:50 +0000] [Job 1] Before scaling: xppi=128, yppi=128, zoom=0.00
D [19/Oct/2011:07:54:50 +0000] [Job 1] Before scaling: xprint=7.9, yprint=11.4
D [19/Oct/2011:07:54:50 +0000] [Job 1] Image size is 5.1 x 2.6 inches...
D [19/Oct/2011:07:54:50 +0000] [Job 1] Auto orientation...
D [19/Oct/2011:07:54:50 +0000] [Job 1] xpages = 1x5.14in, ypages = 1x2.59in
D [19/Oct/2011:07:54:50 +0000] [Job 1] XPosition=0, YPosition=0, Orientation=0
D [19/Oct/2011:07:54:50 +0000] [Job 1] xprint=5, yprint=3
D [19/Oct/2011:07:54:50 +0000] [Job 1] PageLeft=12, PageRight=583, PageWidth=595
D [19/Oct/2011:07:54:50 +0000] [Job 1] PageBottom=12, PageTop=830, PageLength=842
D [19/Oct/2011:07:54:50 +0000] [Job 1] left=112.48, top=514.45
D [19/Oct/2011:07:54:50 +0000] [Job 1] PAGE: 1 1
D [19/Oct/2011:07:54:50 +0000] Discarding unused job-progress event...
I [19/Oct/2011:07:54:50 +0000] [Job 1] Printing page 1...
D [19/Oct/2011:07:54:50 +0000] Discarding unused job-progress event...
D [19/Oct/2011:07:54:50 +0000] Discarding unused printer-state-changed event...
D [19/Oct/2011:07:54:54 +0000] [Job 1] usb_find_busses=0
D [19/Oct/2011:07:54:54 +0000] [Job 1] usb_find_devices=0
D [19/Oct/2011:07:54:54 +0000] [Job 1] STATE: +connecting-to-device
D [19/Oct/2011:07:54:54 +0000] Discarding unused printer-state-changed event...
D [19/Oct/2011:07:54:54 +0000] [Job 1] Failed to set configuration 1 for 04f9:01a5
D [19/Oct/2011:07:54:54 +0000] [Job 1] Failed to claim interface 0 for 04f9:01a5: Operation not permitted
D [19/Oct/2011:07:54:54 +0000] [Job 1] STATE: -connecting-to-device
D [19/Oct/2011:07:54:54 +0000] Discarding unused printer-state-changed event...
I [19/Oct/2011:07:54:54 +0000] [Job 1] Waiting for printer to become available...
D [19/Oct/2011:07:54:54 +0000] Discarding unused job-progress event...
D [19/Oct/2011:07:54:54 +0000] Discarding unused printer-state-changed event...
D [19/Oct/2011:07:54:59 +0000] [Job 1] usb_find_busses=0
D [19/Oct/2011:07:54:59 +0000] [Job 1] usb_find_devices=0
D [19/Oct/2011:07:54:59 +0000] [Job 1] STATE: +connecting-to-device
D [19/Oct/2011:07:54:59 +0000] Discarding unused printer-state-changed event...
D [19/Oct/2011:07:54:59 +0000] [Job 1] Failed to set configuration 1 for 04f9:01a5
D [19/Oct/2011:07:54:59 +0000] [Job 1] Failed to claim interface 0 for 04f9:01a5: Operation not permitted
D [19/Oct/2011:07:54:59 +0000] [Job 1] STATE: -connecting-to-device
D [19/Oct/2011:07:54:59 +0000] Discarding unused printer-state-changed event...
I [19/Oct/2011:07:54:59 +0000] [Job 1] Waiting for printer to become available...
D [19/Oct/2011:07:55:01 +0000] cupsdAcceptClient: 16 from localhost (Domain)
D [19/Oct/2011:07:55:01 +0000] cupsdReadClient: 16 POST / HTTP/1.1
D [19/Oct/2011:07:55:01 +0000] cupsdSetBusyState: Active clients, printing jobs, and dirty files
D [19/Oct/2011:07:55:01 +0000] cupsdAuthorize: No authentication data provided.
D [19/Oct/2011:07:55:01 +0000] cupsdReadClient: 16 1.1 CUPS-Get-Printers 1
D [19/Oct/2011:07:55:01 +0000] CUPS-Get-Printers
D [19/Oct/2011:07:55:01 +0000] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost
D [19/Oct/2011:07:55:01 +0000] cupsdSetBusyState: Printing jobs and dirty files
D [19/Oct/2011:07:55:01 +0000] cupsdReadClient: 16 POST / HTTP/1.1
D [19/Oct/2011:07:55:01 +0000] cupsdSetBusyState: Active clients, printing jobs, and dirty files
D [19/Oct/2011:07:55:01 +0000] cupsdAuthorize: No authentication data provided.
D [19/Oct/2011:07:55:01 +0000] cupsdReadClient: 16 1.1 CUPS-Get-Default 1
D [19/Oct/2011:07:55:01 +0000] CUPS-Get-Default
D [19/Oct/2011:07:55:01 +0000] CUPS-Get-Default client-error-not-found: No default printer
D [19/Oct/2011:07:55:01 +0000] Returning IPP client-error-not-found for CUPS-Get-Default (no URI) from localhost
D [19/Oct/2011:07:55:01 +0000] cupsdSetBusyState: Printing jobs and dirty files
D [19/Oct/2011:07:55:01 +0000] cupsdAcceptClient: 17 from localhost (Domain)
D [19/Oct/2011:07:55:01 +0000] cupsdReadClient: 17 WAITING Closing on EOF
D [19/Oct/2011:07:55:01 +0000] cupsdCloseClient: 17
D [19/Oct/2011:07:55:01 +0000] cupsdReadClient: 16 POST / HTTP/1.1
D [19/Oct/2011:07:55:01 +0000] cupsdSetBusyState: Active clients, printing jobs, and dirty files
D [19/Oct/2011:07:55:01 +0000] cupsdAuthorize: No authentication data provided.
D [19/Oct/2011:07:55:01 +0000] cupsdReadClient: 16 1.1 CUPS-Get-Classes 1
D [19/Oct/2011:07:55:01 +0000] CUPS-Get-Classes
D [19/Oct/2011:07:55:01 +0000] Returning IPP successful-ok for CUPS-Get-Classes (no URI) from localhost
D [19/Oct/2011:07:55:01 +0000] cupsdSetBusyState: Printing jobs and dirty files
D [19/Oct/2011:07:55:01 +0000] cupsdReadClient: 16 POST / HTTP/1.1
D [19/Oct/2011:07:55:01 +0000] cupsdSetBusyState: Active clients, printing jobs, and dirty files
D [19/Oct/2011:07:55:01 +0000] cupsdAuthorize: No authentication data provided.
D [19/Oct/2011:07:55:01 +0000] cupsdReadClient: 16 1.1 CUPS-Get-Printers 1
D [19/Oct/2011:07:55:01 +0000] CUPS-Get-Printers
D [19/Oct/2011:07:55:01 +0000] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost
D [19/Oct/2011:07:55:01 +0000] cupsdSetBusyState: Printing jobs and dirty files
D [19/Oct/2011:07:55:01 +0000] cupsdReadClient: 16 POST / HTTP/1.1
D [19/Oct/2011:07:55:01 +0000] cupsdSetBusyState: Active clients, printing jobs, and dirty files
D [19/Oct/2011:07:55:01 +0000] cupsdAuthorize: No authentication data provided.
D [19/Oct/2011:07:55:01 +0000] cupsdReadClient: 16 1.1 CUPS-Get-Printers 1
D [19/Oct/2011:07:55:01 +0000] CUPS-Get-Printers
D [19/Oct/2011:07:55:01 +0000] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost
D [19/Oct/2011:07:55:01 +0000] cupsdSetBusyState: Printing jobs and dirty files
D [19/Oct/2011:07:55:01 +0000] cupsdReadClient: 16 POST / HTTP/1.1
D [19/Oct/2011:07:55:01 +0000] cupsdSetBusyState: Active clients, printing jobs, and dirty files
D [19/Oct/2011:07:55:01 +0000] cupsdAuthorize: No authentication data provided.
D [19/Oct/2011:07:55:01 +0000] cupsdReadClient: 16 1.1 CUPS-Get-Printers 1
D [19/Oct/2011:07:55:01 +0000] CUPS-Get-Printers
D [19/Oct/2011:07:55:01 +0000] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost
D [19/Oct/2011:07:55:01 +0000] cupsdSetBusyState: Printing jobs and dirty files
D [19/Oct/2011:07:55:01 +0000] cupsdReadClient: 16 POST / HTTP/1.1
D [19/Oct/2011:07:55:01 +0000] cupsdSetBusyState: Active clients, printing jobs, and dirty files
D [19/Oct/2011:07:55:01 +0000] cupsdAuthorize: No authentication data provided.
D [19/Oct/2011:07:55:01 +0000] cupsdReadClient: 16 1.1 Get-Jobs 1
D [19/Oct/2011:07:55:01 +0000] Get-Jobs ipp://localhost/printers/brother
D [19/Oct/2011:07:55:01 +0000] Returning IPP successful-ok for Get-Jobs (ipp://localhost/printers/brother) from localhost
D [19/Oct/2011:07:55:01 +0000] cupsdSetBusyState: Printing jobs and dirty files
D [19/Oct/2011:07:55:01 +0000] cupsdReadClient: 16 POST / HTTP/1.1
D [19/Oct/2011:07:55:01 +0000] cupsdSetBusyState: Active clients, printing jobs, and dirty files
D [19/Oct/2011:07:55:01 +0000] cupsdAuthorize: No authentication data provided.
D [19/Oct/2011:07:55:01 +0000] cupsdReadClient: 16 1.1 Get-Jobs 1
D [19/Oct/2011:07:55:01 +0000] Get-Jobs ipp://localhost/
D [19/Oct/2011:07:55:01 +0000] Returning IPP successful-ok for Get-Jobs (ipp://localhost/) from localhost
D [19/Oct/2011:07:55:01 +0000] cupsdSetBusyState: Printing jobs and dirty files
D [19/Oct/2011:07:55:01 +0000] cupsdReadClient: 16 WAITING Closing on EOF
D [19/Oct/2011:07:55:01 +0000] cupsdCloseClient: 16
D [19/Oct/2011:07:55:04 +0000] [Job 1] usb_find_busses=0
D [19/Oct/2011:07:55:04 +0000] [Job 1] usb_find_devices=0
D [19/Oct/2011:07:55:04 +0000] [Job 1] STATE: +connecting-to-device
D [19/Oct/2011:07:55:04 +0000] Discarding unused printer-state-changed event...
D [19/Oct/2011:07:55:04 +0000] [Job 1] Failed to set configuration 1 for 04f9:01a5
D [19/Oct/2011:07:55:04 +0000] [Job 1] Failed to claim interface 0 for 04f9:01a5: Operation not permitted
D [19/Oct/2011:07:55:04 +0000] [Job 1] STATE: -connecting-to-device
D [19/Oct/2011:07:55:04 +0000] Discarding unused printer-state-changed event...
I [19/Oct/2011:07:55:04 +0000] [Job 1] Waiting for printer to become available...
D [19/Oct/2011:07:55:09 +0000] [Job 1] usb_find_busses=0
I [19/Oct/2011:07:55:09 +0000] Saving printers.conf...
I [19/Oct/2011:07:55:09 +0000] Generating printcap /etc/printcap...
I [19/Oct/2011:07:55:09 +0000] Saving job cache file "/var/cache/cups/job.cache"...
D [19/Oct/2011:07:55:09 +0000] cupsdSetBusyState: Printing jobs
D [19/Oct/2011:07:55:09 +0000] [Job 1] usb_find_devices=0
D [19/Oct/2011:07:55:09 +0000] [Job 1] STATE: +connecting-to-device
D [19/Oct/2011:07:55:09 +0000] [Job 1] Failed to set configuration 1 for 04f9:01a5
D [19/Oct/2011:07:55:09 +0000] Discarding unused printer-state-changed event...
D [19/Oct/2011:07:55:09 +0000] [Job 1] Failed to claim interface 0 for 04f9:01a5: Operation not permitted
D [19/Oct/2011:07:55:09 +0000] [Job 1] STATE: -connecting-to-device
I [19/Oct/2011:07:55:09 +0000] [Job 1] Waiting for printer to become available...
D [19/Oct/2011:07:55:09 +0000] Discarding unused printer-state-changed event...
D [19/Oct/2011:07:55:14 +0000] [Job 1] usb_find_busses=0
D [19/Oct/2011:07:55:14 +0000] [Job 1] usb_find_devices=0
D [19/Oct/2011:07:55:14 +0000] [Job 1] STATE: +connecting-to-device
D [19/Oct/2011:07:55:14 +0000] Discarding unused printer-state-changed event...
D [19/Oct/2011:07:55:14 +0000] [Job 1] Failed to set configuration 1 for 04f9:01a5
D [19/Oct/2011:07:55:14 +0000] [Job 1] Failed to claim interface 0 for 04f9:01a5: Operation not permitted
D [19/Oct/2011:07:55:14 +0000] [Job 1] STATE: -connecting-to-device
D [19/Oct/2011:07:55:14 +0000] Discarding unused printer-state-changed event...
I [19/Oct/2011:07:55:14 +0000] [Job 1] Waiting for printer to become available...
D [19/Oct/2011:07:55:19 +0000] [Job 1] usb_find_busses=0
D [19/Oct/2011:07:55:19 +0000] [Job 1] usb_find_devices=0
D [19/Oct/2011:07:55:19 +0000] [Job 1] STATE: +connecting-to-device
D [19/Oct/2011:07:55:19 +0000] [Job 1] Failed to set configuration 1 for 04f9:01a5
D [19/Oct/2011:07:55:19 +0000] [Job 1] Failed to claim interface 0 for 04f9:01a5: Operation not permitted
D [19/Oct/2011:07:55:19 +0000] [Job 1] STATE: -connecting-to-device
I [19/Oct/2011:07:55:19 +0000] [Job 1] Waiting for printer to become available...
D [19/Oct/2011:07:55:19 +0000] Discarding unused printer-state-changed event...
D [19/Oct/2011:07:55:24 +0000] [Job 1] usb_find_busses=0
D [19/Oct/2011:07:55:25 +0000] [Job 1] usb_find_devices=0
D [19/Oct/2011:07:55:25 +0000] [Job 1] STATE: +connecting-to-device
D [19/Oct/2011:07:55:25 +0000] Discarding unused printer-state-changed event...
D [19/Oct/2011:07:55:25 +0000] [Job 1] Failed to set configuration 1 for 04f9:01a5
D [19/Oct/2011:07:55:25 +0000] [Job 1] Failed to claim interface 0 for 04f9:01a5: Operation not permitted
D [19/Oct/2011:07:55:25 +0000] [Job 1] STATE: -connecting-to-device
D [19/Oct/2011:07:55:25 +0000] Discarding unused printer-state-changed event...
I [19/Oct/2011:07:55:25 +0000] [Job 1] Waiting for printer to become available...
D [19/Oct/2011:07:55:30 +0000] [Job 1] usb_find_busses=0
D [19/Oct/2011:07:55:30 +0000] [Job 1] usb_find_devices=0
D [19/Oct/2011:07:55:30 +0000] [Job 1] STATE: +connecting-to-device
D [19/Oct/2011:07:55:30 +0000] Discarding unused printer-state-changed event...
D [19/Oct/2011:07:55:30 +0000] [Job 1] Failed to set configuration 1 for 04f9:01a5
D [19/Oct/2011:07:55:30 +0000] [Job 1] Failed to claim interface 0 for 04f9:01a5: Operation not permitted
D [19/Oct/2011:07:55:30 +0000] [Job 1] STATE: -connecting-to-device
I [19/Oct/2011:07:55:30 +0000] [Job 1] Waiting for printer to become available...
D [19/Oct/2011:07:55:30 +0000] Discarding unused printer-state-changed event...
D [19/Oct/2011:07:55:35 +0000] [Job 1] usb_find_busses=0
D [19/Oct/2011:07:55:35 +0000] [Job 1] usb_find_devices=0
D [19/Oct/2011:07:55:35 +0000] [Job 1] STATE: +connecting-to-device

Would be great if someone had an idea what could be the problem here.

Greets
Markus