510703 – Jobs to HP LaserJet 2600n do not arrive or are not printed (hplib_t)

Bug 510703 - Jobs to HP LaserJet 2600n do not arrive or are not printed (hplib_t)

Summary: Jobs to HP LaserJet 2600n do not arrive or are not printed (hplib_t)

Keywords:
Status:	CLOSED INSUFFICIENT_DATA
Alias:	None
Product:	Fedora
Classification:	Fedora
Component:	foomatic
Sub Component:
Version:	11
Hardware:	i386
OS:	Linux
Priority:	low
Severity:	high
Target Milestone:	---
Assignee:	Tim Waugh
QA Contact:	Fedora Extras Quality Assurance
Docs Contact:
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+	depends on / blocked

Reported:	2009-07-10 11:04 UTC by Andrew
Modified:	2010-04-12 10:05 UTC (History)
CC List:	1 user (show)
Fixed In Version:
Doc Type:	Bug Fix
Doc Text:
Clone Of:
Environment:
Last Closed:	2010-04-12 10:05:28 UTC
Type:	---
Embargoed:
Dependent Products:

Attachments	(Terms of Use)
system-config-printers troubelshoot.txt (44.96 KB, text/plain) 2009-07-10 16:27 UTC, Andrew	no flags	Details
system-config-printers troubelshoot.txt number 2 (75.77 KB, text/plain) 2009-07-10 16:27 UTC, Andrew	no flags	Details
system-config-printers troubleshoot.txt after updates (49.73 KB, text/plain) 2009-07-11 11:46 UTC, Andrew	no flags	Details
View All

Description Andrew 2009-07-10 11:04:52 UTC

Description of problem:

Cannot print under F11 with HP Color Laserjet 2600n where under F9 and F10 things went perfect. Everything is detected it just won't print and jobs sent there either don't arrive (SELINUX Enforcing) and don't get printed but set to 'stopped' (SELINUX Permissive).


Version-Release number of selected component (if applicable):

F11, fully updated, hplib


How reproducible:

Every time reproducible.

Steps to Reproduce:
1. Hook up HP 2600n on USB
2. F11 detects things properly
3. "print test page"
  
Actual results:

Jobs do not arrive at printer and if they do jobs are not printed but after a minute go to 'stopped'.

Expected results:

Print my thesis :)

Additional info:


Summary:

SELinux is preventing python (hplip_t) "open" security_t.

Detailed Description:

SELinux denied access requested by python. It is not expected that this access
is required by python and this access may signal an intrusion attempt. It is
also possible that the specific version or configuration of the application is
causing it to require additional access.

Allowing Access:

You can generate a local policy module to allow this access - see FAQ
(http://fedora.redhat.com/docs/selinux-faq-fc5/#id2961385) Or you can disable
SELinux protection altogether. Disabling SELinux protection is not recommended.
Please file a bug report (http://bugzilla.redhat.com/bugzilla/enter_bug.cgi)
against this package.

Additional Information:

This isn't purely a SELINUX issue as with it disabled the pages are still not printed. However this is the only indication I have of an error message.

Even after "grep avc /var/log/audit/audit.log | audit2allow -M mypol" and "semodule -i mypol.pp" it won't print the jobs.

Source Context                system_u:system_r:hplip_t:s0
Target Context                system_u:object_r:security_t:s0
Target Objects                mls [ file ]
Source                        python
Source Path                   /usr/bin/python
Port                          <Unknown>
Host                          blackbox
Source RPM Packages           python-2.6-9.fc11
Target RPM Packages           
Policy RPM                    selinux-policy-3.6.12-53.fc11
Selinux Enabled               True
Policy Type                   targeted
MLS Enabled                   True
Enforcing Mode                Enforcing
Plugin Name                   catchall
Host Name                     blackbox
Platform                      Linux blackbox 2.6.29.5-191.fc11.i586 #1 SMP Tue
                              Jun 16 23:11:39 EDT 2009 i686 i686
Alert Count                   2
First Seen                    Fri 10 Jul 2009 11:27:32 AM CEST
Last Seen                     Fri 10 Jul 2009 11:32:13 AM CEST
Local ID                      3de9a48f-0e5e-4f3c-a5e9-ed68c1b359fd
Line Numbers                  

Raw Audit Messages            

node=blackbox type=AVC msg=audit(1247218333.442:42): avc:  denied  { open } for  pid=4044 comm="python" name="mls" dev=selinuxfs ino=12 scontext=system_u:system_r:hplip_t:s0 tcontext=system_u:object_r:security_t:s0 tclass=file

node=blackbox type=SYSCALL msg=audit(1247218333.442:42): arch=40000003 syscall=5 success=no exit=-13 a0=bf9c9fb8 a1=8000 a2=0 a3=bf9c9fb8 items=0 ppid=4041 pid=4044 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=4294967295 comm="python" exe="/usr/bin/python" subj=system_u:system_r:hplip_t:s0 key=(null)

Comment 1 Tim Waugh 2009-07-10 16:10:08 UTC

Please install the system-config-printer test update:

yum --enablerepo=updates-testing update 'system-config-printer*'

After that, run the printing troubleshooter: System->Administration->Printing, then Help->Troubleshoot.  Follow the on-screen instructions.  At the end of that process you will probably have a troubleshoot.txt file that you can attach to this bug report.

Comment 2 Andrew 2009-07-10 16:25:47 UTC

Updated both system-config-printer* and selinux* (no selinux warning this time). Enabled CUPS debugging. Tested it twice on both USB ports.

Error Log Messages FIRST TIME

D [10/Jul/2009:18:19:07 +0200] cupsdReadClient: 12 POST / HTTP/1.1
D [10/Jul/2009:18:19:07 +0200] cupsdAuthorize: No authentication data provided.
D [10/Jul/2009:18:19:07 +0200] Get-Jobs ipp://localhost/printers/
D [10/Jul/2009:18:19:07 +0200] Returning IPP successful-ok for Get-Jobs (ipp://localhost/printers/) from localhost
D [10/Jul/2009:18:19:07 +0200] cupsdReadClient: 12 POST / HTTP/1.1
D [10/Jul/2009:18:19:07 +0200] cupsdAuthorize: No authentication data provided.
D [10/Jul/2009:18:19:07 +0200] Get-Jobs ipp://localhost/printers/
D [10/Jul/2009:18:19:07 +0200] [Job 1] Loading attributes...
E [10/Jul/2009:18:19:07 +0200] [Job 1] Unable to queue job for destination "HP-Color-LaserJet-2600n"!
D [10/Jul/2009:18:19:07 +0200] [Job 3] Loading attributes...
E [10/Jul/2009:18:19:07 +0200] [Job 3] Unable to queue job for destination "HP-Color-LaserJet-2600n"!
D [10/Jul/2009:18:19:07 +0200] [Job 4] Loading attributes...
E [10/Jul/2009:18:19:07 +0200] [Job 4] Unable to queue job for destination "HP-Color-LaserJet-2600n"!
D [10/Jul/2009:18:19:07 +0200] [Job 5] Loading attributes...
E [10/Jul/2009:18:19:07 +0200] [Job 5] Unable to queue job for destination "HP-Color-LaserJet-2600n"!
D [10/Jul/2009:18:19:07 +0200] [Job 6] Loading attributes...
E [10/Jul/2009:18:19:07 +0200] [Job 6] Unable to queue job for destination "HP-Color-LaserJet-2600n"!
D [10/Jul/2009:18:19:07 +0200] [Job 7] Loading attributes...
E [10/Jul/2009:18:19:07 +0200] [Job 7] Unable to queue job for destination "HP-Color-LaserJet-2600n"!
D [10/Jul/2009:18:19:07 +0200] [Job 8] Loading attributes...
D [10/Jul/2009:18:19:07 +0200] [Job 9] Loading attributes...
D [10/Jul/2009:18:19:07 +0200] [Job 10] Loading attributes...
D [10/Jul/2009:18:19:07 +0200] [Job 11] Loading attributes...
D [10/Jul/2009:18:19:07 +0200] Returning IPP successful-ok for Get-Jobs (ipp://localhost/printers/) from localhost
D [10/Jul/2009:18:19:07 +0200] cupsdReadClient: 12 POST / HTTP/1.1
D [10/Jul/2009:18:19:07 +0200] cupsdAuthorize: No authentication data provided.
D [10/Jul/2009:18:19:07 +0200] Create-Printer-Subscription /
D [10/Jul/2009:18:19:07 +0200] cupsdCreateSubscription(con=0x2482978(12), uri="/")
D [10/Jul/2009:18:19:07 +0200] pullmethod="ippget"
D [10/Jul/2009:18:19:07 +0200] notify-lease-duration=86400
D [10/Jul/2009:18:19:07 +0200] notify-time-interval=0
D [10/Jul/2009:18:19:07 +0200] cupsdAddSubscription(mask=17800, dest=(nil)(), job=(nil)(0), uri="(null)")
D [10/Jul/2009:18:19:07 +0200] Added subscription 22 for server
D [10/Jul/2009:18:19:07 +0200] Returning IPP successful-ok for Create-Printer-Subscription (/) from localhost
D [10/Jul/2009:18:19:08 +0200] cupsdReadClient: 12 POST / HTTP/1.1
D [10/Jul/2009:18:19:08 +0200] cupsdAuthorize: No authentication data provided.
D [10/Jul/2009:18:19:08 +0200] Get-Notifications /
D [10/Jul/2009:18:19:08 +0200] cupsdIsAuthorized: requesting-user-name="root"
D [10/Jul/2009:18:19:08 +0200] Returning IPP successful-ok for Get-Notifications (/) from localhost
D [10/Jul/2009:18:19:17 +0200] cupsdAcceptClient: skipping getpeercon()
D [10/Jul/2009:18:19:17 +0200] cupsdAcceptClient: 14 from localhost (Domain)
D [10/Jul/2009:18:19:17 +0200] cupsdReadClient: 14 POST /printers/hp-2600n HTTP/1.1
D [10/Jul/2009:18:19:17 +0200] cupsdAuthorize: No authentication data provided.
D [10/Jul/2009:18:19:17 +0200] Print-Job ipp://localhost/printers/hp-2600n
D [10/Jul/2009:18:19:17 +0200] [Job ???] Auto-typing file...
I [10/Jul/2009:18:19:17 +0200] [Job ???] Request file type is application/vnd.cups-banner.
D [10/Jul/2009:18:19:17 +0200] add_job: setting context of job to UNKNOWN SL
D [10/Jul/2009:18:19:17 +0200] add_job: requesting-user-name="andrew"
D [10/Jul/2009:18:19:17 +0200] Adding default job-sheets values "none,none"...
I [10/Jul/2009:18:19:17 +0200] [Job 12] Adding start banner page "none".
I [10/Jul/2009:18:19:17 +0200] [Job 12] Adding end banner page "none".
I [10/Jul/2009:18:19:17 +0200] [Job 12] File of type application/vnd.cups-banner queued by "andrew".
D [10/Jul/2009:18:19:17 +0200] [Job 12] hold_until=0
I [10/Jul/2009:18:19:17 +0200] [Job 12] Queued on "hp-2600n" by "andrew".
D [10/Jul/2009:18:19:17 +0200] cupsdSetBusyState: Active clients, printing jobs, and dirty files
D [10/Jul/2009:18:19:17 +0200] [Job 12] job-sheets=none,none
D [10/Jul/2009:18:19:17 +0200] [Job 12] argv[0]="hp-2600n"
D [10/Jul/2009:18:19:17 +0200] [Job 12] argv[1]="12"
D [10/Jul/2009:18:19:17 +0200] [Job 12] argv[2]="andrew"
D [10/Jul/2009:18:19:17 +0200] [Job 12] argv[3]="Test Page"
D [10/Jul/2009:18:19:17 +0200] [Job 12] argv[4]="1"
D [10/Jul/2009:18:19:17 +0200] [Job 12] argv[5]="job-uuid=urn:uuid:251d00a2-1b85-3aa5-67fb-b71e31c4dc90 job-originating-host-name=localhost"
D [10/Jul/2009:18:19:17 +0200] [Job 12] argv[6]="/var/spool/cups/d00012-001"
D [10/Jul/2009:18:19:17 +0200] [Job 12] envp[0]="CUPS_CACHEDIR=/var/cache/cups"
D [10/Jul/2009:18:19:17 +0200] [Job 12] envp[1]="CUPS_DATADIR=/usr/share/cups"
D [10/Jul/2009:18:19:17 +0200] [Job 12] envp[2]="CUPS_DOCROOT=/usr/share/cups/www"
D [10/Jul/2009:18:19:17 +0200] [Job 12] envp[3]="CUPS_FONTPATH=/usr/share/cups/fonts"
D [10/Jul/2009:18:19:17 +0200] [Job 12] envp[4]="CUPS_REQUESTROOT=/var/spool/cups"
D [10/Jul/2009:18:19:17 +0200] [Job 12] envp[5]="CUPS_SERVERBIN=/usr/lib/cups"
D [10/Jul/2009:18:19:17 +0200] [Job 12] envp[6]="CUPS_SERVERROOT=/etc/cups"
D [10/Jul/2009:18:19:17 +0200] [Job 12] envp[7]="CUPS_STATEDIR=/var/run/cups"
D [10/Jul/2009:18:19:17 +0200] [Job 12] envp[8]="PATH=/usr/lib/cups/filter:/usr/bin:/usr/sbin:/bin:/usr/bin"
D [10/Jul/2009:18:19:17 +0200] [Job 12] envp[9]="SERVER_ADMIN=root@blackbox"
D [10/Jul/2009:18:19:17 +0200] [Job 12] envp[10]="SOFTWARE=CUPS/1.4b3"
D [10/Jul/2009:18:19:17 +0200] [Job 12] envp[11]="TMPDIR=/var/spool/cups/tmp"
D [10/Jul/2009:18:19:17 +0200] [Job 12] envp[12]="USER=root"
D [10/Jul/2009:18:19:17 +0200] [Job 12] envp[13]="CUPS_SERVER=/var/run/cups/cups.sock"
D [10/Jul/2009:18:19:17 +0200] [Job 12] envp[14]="CUPS_ENCRYPTION=IfRequested"
D [10/Jul/2009:18:19:17 +0200] [Job 12] envp[15]="IPP_PORT=631"
D [10/Jul/2009:18:19:17 +0200] [Job 12] envp[16]="CHARSET=utf-8"
D [10/Jul/2009:18:19:17 +0200] [Job 12] envp[17]="LANG=en_US.UTF8"
D [10/Jul/2009:18:19:17 +0200] [Job 12] envp[18]="PPD=/etc/cups/ppd/hp-2600n.ppd"
D [10/Jul/2009:18:19:17 +0200] [Job 12] envp[19]="RIP_MAX_CACHE=8m"
D [10/Jul/2009:18:19:17 +0200] [Job 12] envp[20]="CONTENT_TYPE=application/vnd.cups-banner"
D [10/Jul/2009:18:19:17 +0200] [Job 12] envp[21]="DEVICE_URI=hp:/usb/HP_Color_LaserJet_2600n?serial=F944RPG"
D [10/Jul/2009:18:19:17 +0200] [Job 12] envp[22]="PRINTER_INFO=HP HP Color LaserJet 2600n"
D [10/Jul/2009:18:19:17 +0200] [Job 12] envp[23]="PRINTER_LOCATION=blackbox"
D [10/Jul/2009:18:19:17 +0200] [Job 12] envp[24]="PRINTER=hp-2600n"
D [10/Jul/2009:18:19:17 +0200] [Job 12] envp[25]="CUPS_FILETYPE=document"
D [10/Jul/2009:18:19:17 +0200] [Job 12] envp[26]="FINAL_CONTENT_TYPE=printer/hp-2600n"
I [10/Jul/2009:18:19:17 +0200] [Job 12] Started filter /usr/lib/cups/filter/bannertops (PID 6420)
I [10/Jul/2009:18:19:17 +0200] [Job 12] Started filter /usr/lib/cups/filter/pstops (PID 6421)
I [10/Jul/2009:18:19:17 +0200] [Job 12] Started filter /usr/lib/cups/filter/foomatic-rip (PID 6422)
I [10/Jul/2009:18:19:17 +0200] [Job 12] Started backend /usr/lib/cups/backend/hp (PID 6423)
D [10/Jul/2009:18:19:17 +0200] Returning IPP successful-ok for Print-Job (ipp://localhost/printers/hp-2600n) from localhost
D [10/Jul/2009:18:19:17 +0200] [Job 12] STATE: +connecting-to-device
D [10/Jul/2009:18:19:17 +0200] cupsdAcceptClient: skipping getpeercon()
D [10/Jul/2009:18:19:17 +0200] cupsdAcceptClient: 17 from localhost (Domain)
D [10/Jul/2009:18:19:17 +0200] cupsdAcceptClient: skipping getpeercon()
D [10/Jul/2009:18:19:17 +0200] cupsdAcceptClient: 18 from localhost (Domain)
D [10/Jul/2009:18:19:17 +0200] cupsdReadClient: 17 POST / HTTP/1.1
D [10/Jul/2009:18:19:17 +0200] cupsdAuthorize: No authentication data provided.
D [10/Jul/2009:18:19:17 +0200] cupsdReadClient: 18 POST / HTTP/1.1
D [10/Jul/2009:18:19:17 +0200] cupsdAuthorize: No authentication data provided.
D [10/Jul/2009:18:19:17 +0200] Get-Notifications /
D [10/Jul/2009:18:19:17 +0200] cupsdIsAuthorized: requesting-user-name="andrew"
D [10/Jul/2009:18:19:17 +0200] Returning IPP successful-ok for Get-Notifications (/) from localhost
D [10/Jul/2009:18:19:17 +0200] Get-Jobs ipp://localhost/printers/
D [10/Jul/2009:18:19:17 +0200] Returning IPP successful-ok for Get-Jobs (ipp://localhost/printers/) from localhost
D [10/Jul/2009:18:19:17 +0200] cupsdAcceptClient: skipping getpeercon()
D [10/Jul/2009:18:19:17 +0200] cupsdAcceptClient: 18 from localhost (Domain)
D [10/Jul/2009:18:19:17 +0200] cupsdReadClient: 18 POST / HTTP/1.1
D [10/Jul/2009:18:19:17 +0200] cupsdAuthorize: No authentication data provided.
D [10/Jul/2009:18:19:17 +0200] Get-Notifications /
D [10/Jul/2009:18:19:17 +0200] cupsdIsAuthorized: requesting-user-name="andrew"
D [10/Jul/2009:18:19:17 +0200] Returning IPP successful-ok for Get-Notifications (/) from localhost
D [10/Jul/2009:18:19:17 +0200] cupsdReadClient: 18 POST / HTTP/1.1
D [10/Jul/2009:18:19:17 +0200] cupsdAuthorize: No authentication data provided.
D [10/Jul/2009:18:19:17 +0200] Get-Job-Attributes ipp://localhost/jobs/12
D [10/Jul/2009:18:19:17 +0200] Returning IPP successful-ok for Get-Job-Attributes (ipp://localhost/jobs/12) from localhost
D [10/Jul/2009:18:19:17 +0200] cupsdReadClient: 12 POST / HTTP/1.1
D [10/Jul/2009:18:19:17 +0200] cupsdAuthorize: No authentication data provided.
D [10/Jul/2009:18:19:17 +0200] Get-Notifications /
D [10/Jul/2009:18:19:17 +0200] cupsdIsAuthorized: requesting-user-name="root"
D [10/Jul/2009:18:19:17 +0200] Returning IPP successful-ok for Get-Notifications (/) from localhost
D [10/Jul/2009:18:19:18 +0200] PID 6420 (/usr/lib/cups/filter/bannertops) exited with no errors.
D [10/Jul/2009:18:19:18 +0200] PID 6421 (/usr/lib/cups/filter/pstops) exited with no errors.
D [10/Jul/2009:18:19:18 +0200] PID 6422 (/usr/lib/cups/filter/foomatic-rip) stopped with status 3!
I [10/Jul/2009:18:19:36 +0200] Saving job cache file "/var/cache/cups/job.cache"...
I [10/Jul/2009:18:19:36 +0200] Saving subscriptions.conf...
D [10/Jul/2009:18:19:36 +0200] cupsdSetBusyState: Active clients and printing jobs
D [10/Jul/2009:18:20:18 +0200] cupsdReadClient: 12 POST / HTTP/1.1
D [10/Jul/2009:18:20:18 +0200] cupsdAuthorize: No authentication data provided.
D [10/Jul/2009:18:20:18 +0200] [Job 8] Unloading...
D [10/Jul/2009:18:20:18 +0200] [Job 9] Unloading...
D [10/Jul/2009:18:20:18 +0200] [Job 10] Unloading...
D [10/Jul/2009:18:20:18 +0200] [Job 11] Unloading...
D [10/Jul/2009:18:20:18 +0200] Report: clients=2
D [10/Jul/2009:18:20:18 +0200] Report: jobs=11
D [10/Jul/2009:18:20:18 +0200] Report: jobs-active=1
D [10/Jul/2009:18:20:18 +0200] Report: printers=1
D [10/Jul/2009:18:20:18 +0200] Report: printers-implicit=0
D [10/Jul/2009:18:20:18 +0200] Report: stringpool-string-count=1394
D [10/Jul/2009:18:20:18 +0200] Report: stringpool-alloc-bytes=8224
D [10/Jul/2009:18:20:18 +0200] Report: stringpool-total-bytes=29496
D [10/Jul/2009:18:20:18 +0200] Get-Notifications /
D [10/Jul/2009:18:20:18 +0200] cupsdIsAuthorized: requesting-user-name="root"
D [10/Jul/2009:18:20:18 +0200] Returning IPP successful-ok for Get-Notifications (/) from localhost
D [10/Jul/2009:18:21:05 +0200] cupsdReadClient: 12 POST / HTTP/1.1
D [10/Jul/2009:18:21:05 +0200] cupsdAuthorize: No authentication data provided.
D [10/Jul/2009:18:21:05 +0200] Get-Job-Attributes ipp://localhost/jobs/12
D [10/Jul/2009:18:21:05 +0200] Returning IPP successful-ok for Get-Job-Attributes (ipp://localhost/jobs/12) from localhost
D [10/Jul/2009:18:21:05 +0200] cupsdReadClient: 12 POST / HTTP/1.1
D [10/Jul/2009:18:21:05 +0200] cupsdAuthorize: No authentication data provided.
D [10/Jul/2009:18:21:05 +0200] Cancel-Subscription /
D [10/Jul/2009:18:21:05 +0200] cupsdIsAuthorized: requesting-user-name="root"
D [10/Jul/2009:18:21:05 +0200] cupsdSetBusyState: Active clients, printing jobs, and dirty files
D [10/Jul/2009:18:21:05 +0200] Returning IPP successful-ok for Cancel-Subscription (/) from localhost
D [10/Jul/2009:18:21:05 +0200] cupsdAcceptClient: skipping getpeercon()
D [10/Jul/2009:18:21:05 +0200] cupsdAcceptClient: 17 from localhost (Domain)
D [10/Jul/2009:18:21:05 +0200] cupsdReadClient: 17 GET /admin/log/error_log HTTP/1.1
D [10/Jul/2009:18:21:05 +0200] cupsdAuthorize: No authentication data provided.

Error messages SECOND TIME

D [10/Jul/2009:18:23:45 +0200] cupsdReadClient: 12 POST / HTTP/1.1
D [10/Jul/2009:18:23:45 +0200] cupsdAuthorize: No authentication data provided.
D [10/Jul/2009:18:23:45 +0200] Get-Jobs ipp://localhost/printers/
D [10/Jul/2009:18:23:45 +0200] [Job 12] Loading attributes...
D [10/Jul/2009:18:23:45 +0200] Returning IPP successful-ok for Get-Jobs (ipp://localhost/printers/) from localhost
D [10/Jul/2009:18:23:45 +0200] cupsdReadClient: 12 POST / HTTP/1.1
D [10/Jul/2009:18:23:45 +0200] cupsdAuthorize: No authentication data provided.
D [10/Jul/2009:18:23:45 +0200] Get-Jobs ipp://localhost/printers/
D [10/Jul/2009:18:23:45 +0200] [Job 8] Loading attributes...
D [10/Jul/2009:18:23:45 +0200] [Job 9] Loading attributes...
D [10/Jul/2009:18:23:45 +0200] [Job 10] Loading attributes...
D [10/Jul/2009:18:23:45 +0200] [Job 11] Loading attributes...
D [10/Jul/2009:18:23:45 +0200] Returning IPP successful-ok for Get-Jobs (ipp://localhost/printers/) from localhost
D [10/Jul/2009:18:23:45 +0200] cupsdReadClient: 12 POST / HTTP/1.1
D [10/Jul/2009:18:23:45 +0200] cupsdAuthorize: No authentication data provided.
D [10/Jul/2009:18:23:45 +0200] Create-Printer-Subscription /
D [10/Jul/2009:18:23:45 +0200] cupsdCreateSubscription(con=0x26f93e8(12), uri="/")
D [10/Jul/2009:18:23:45 +0200] pullmethod="ippget"
D [10/Jul/2009:18:23:45 +0200] notify-lease-duration=86400
D [10/Jul/2009:18:23:45 +0200] notify-time-interval=0
D [10/Jul/2009:18:23:45 +0200] cupsdAddSubscription(mask=17800, dest=(nil)(), job=(nil)(0), uri="(null)")
D [10/Jul/2009:18:23:45 +0200] Added subscription 23 for server
D [10/Jul/2009:18:23:45 +0200] Returning IPP successful-ok for Create-Printer-Subscription (/) from localhost
D [10/Jul/2009:18:23:47 +0200] cupsdReadClient: 12 POST / HTTP/1.1
D [10/Jul/2009:18:23:47 +0200] cupsdAuthorize: No authentication data provided.
D [10/Jul/2009:18:23:47 +0200] Get-Notifications /
D [10/Jul/2009:18:23:47 +0200] cupsdIsAuthorized: requesting-user-name="root"
D [10/Jul/2009:18:23:47 +0200] Returning IPP successful-ok for Get-Notifications (/) from localhost
D [10/Jul/2009:18:23:48 +0200] cupsdReadClient: 12 POST /jobs/ HTTP/1.1
D [10/Jul/2009:18:23:48 +0200] cupsdAuthorize: No authentication data provided.
D [10/Jul/2009:18:23:48 +0200] Cancel-Job ipp://localhost/jobs/12
D [10/Jul/2009:18:23:48 +0200] cupsdIsAuthorized: requesting-user-name="root"
I [10/Jul/2009:18:23:48 +0200] [Job 12] Job canceled by "root"
I [10/Jul/2009:18:23:48 +0200] [Job 12] Canceled by "root".
D [10/Jul/2009:18:23:48 +0200] Returning IPP successful-ok for Cancel-Job (ipp://localhost/jobs/12) from localhost
D [10/Jul/2009:18:23:48 +0200] cupsdAcceptClient: skipping getpeercon()
D [10/Jul/2009:18:23:48 +0200] cupsdAcceptClient: 15 from localhost (Domain)
D [10/Jul/2009:18:23:48 +0200] cupsdReadClient: 15 POST / HTTP/1.1
D [10/Jul/2009:18:23:48 +0200] cupsdAuthorize: No authentication data provided.
D [10/Jul/2009:18:23:48 +0200] Get-Jobs ipp://localhost/printers/
D [10/Jul/2009:18:23:48 +0200] Returning IPP successful-ok for Get-Jobs (ipp://localhost/printers/) from localhost
D [10/Jul/2009:18:23:48 +0200] cupsdAcceptClient: skipping getpeercon()
D [10/Jul/2009:18:23:48 +0200] cupsdAcceptClient: 16 from localhost (Domain)
D [10/Jul/2009:18:23:48 +0200] cupsdReadClient: 16 POST / HTTP/1.1
D [10/Jul/2009:18:23:48 +0200] cupsdAuthorize: No authentication data provided.
D [10/Jul/2009:18:23:48 +0200] Get-Notifications /
D [10/Jul/2009:18:23:48 +0200] cupsdIsAuthorized: requesting-user-name="andrew"
D [10/Jul/2009:18:23:48 +0200] Returning IPP successful-ok for Get-Notifications (/) from localhost
D [10/Jul/2009:18:23:48 +0200] cupsdAcceptClient: skipping getpeercon()
D [10/Jul/2009:18:23:48 +0200] cupsdAcceptClient: 15 from localhost (Domain)
D [10/Jul/2009:18:23:48 +0200] cupsdReadClient: 15 POST / HTTP/1.1
D [10/Jul/2009:18:23:48 +0200] cupsdAuthorize: No authentication data provided.
D [10/Jul/2009:18:23:48 +0200] Get-Notifications /
D [10/Jul/2009:18:23:48 +0200] cupsdIsAuthorized: requesting-user-name="andrew"
D [10/Jul/2009:18:23:48 +0200] Returning IPP successful-ok for Get-Notifications (/) from localhost
D [10/Jul/2009:18:23:48 +0200] cupsdReadClient: 12 POST / HTTP/1.1
D [10/Jul/2009:18:23:48 +0200] cupsdAuthorize: No authentication data provided.
D [10/Jul/2009:18:23:48 +0200] Get-Notifications /
D [10/Jul/2009:18:23:48 +0200] cupsdIsAuthorized: requesting-user-name="root"
D [10/Jul/2009:18:23:48 +0200] Returning IPP successful-ok for Get-Notifications (/) from localhost
D [10/Jul/2009:18:23:50 +0200] cupsdAcceptClient: skipping getpeercon()
D [10/Jul/2009:18:23:50 +0200] cupsdAcceptClient: 15 from localhost (Domain)
D [10/Jul/2009:18:23:50 +0200] cupsdReadClient: 15 POST /printers/hp-2600n HTTP/1.1
D [10/Jul/2009:18:23:50 +0200] cupsdAuthorize: No authentication data provided.
D [10/Jul/2009:18:23:50 +0200] Print-Job ipp://localhost/printers/hp-2600n
D [10/Jul/2009:18:23:50 +0200] [Job ???] Auto-typing file...
I [10/Jul/2009:18:23:50 +0200] [Job ???] Request file type is application/vnd.cups-banner.
D [10/Jul/2009:18:23:50 +0200] add_job: setting context of job to UNKNOWN SL
D [10/Jul/2009:18:23:50 +0200] add_job: requesting-user-name="andrew"
D [10/Jul/2009:18:23:50 +0200] Adding default job-sheets values "none,none"...
I [10/Jul/2009:18:23:50 +0200] [Job 13] Adding start banner page "none".
I [10/Jul/2009:18:23:50 +0200] [Job 13] Adding end banner page "none".
I [10/Jul/2009:18:23:50 +0200] [Job 13] File of type application/vnd.cups-banner queued by "andrew".
D [10/Jul/2009:18:23:50 +0200] [Job 13] hold_until=0
I [10/Jul/2009:18:23:50 +0200] [Job 13] Queued on "hp-2600n" by "andrew".
D [10/Jul/2009:18:23:50 +0200] cupsdSetBusyState: Active clients, printing jobs, and dirty files
D [10/Jul/2009:18:23:50 +0200] [Job 13] job-sheets=none,none
D [10/Jul/2009:18:23:50 +0200] [Job 13] argv[0]="hp-2600n"
D [10/Jul/2009:18:23:50 +0200] [Job 13] argv[1]="13"
D [10/Jul/2009:18:23:50 +0200] [Job 13] argv[2]="andrew"
D [10/Jul/2009:18:23:50 +0200] [Job 13] argv[3]="Test Page"
D [10/Jul/2009:18:23:50 +0200] [Job 13] argv[4]="1"
D [10/Jul/2009:18:23:50 +0200] [Job 13] argv[5]="job-uuid=urn:uuid:16a14ecc-886c-3a51-4d25-f889eab456b5 job-originating-host-name=localhost"
D [10/Jul/2009:18:23:50 +0200] [Job 13] argv[6]="/var/spool/cups/d00013-001"
D [10/Jul/2009:18:23:50 +0200] [Job 13] envp[0]="CUPS_CACHEDIR=/var/cache/cups"
D [10/Jul/2009:18:23:50 +0200] [Job 13] envp[1]="CUPS_DATADIR=/usr/share/cups"
D [10/Jul/2009:18:23:50 +0200] [Job 13] envp[2]="CUPS_DOCROOT=/usr/share/cups/www"
D [10/Jul/2009:18:23:50 +0200] [Job 13] envp[3]="CUPS_FONTPATH=/usr/share/cups/fonts"
D [10/Jul/2009:18:23:50 +0200] [Job 13] envp[4]="CUPS_REQUESTROOT=/var/spool/cups"
D [10/Jul/2009:18:23:50 +0200] [Job 13] envp[5]="CUPS_SERVERBIN=/usr/lib/cups"
D [10/Jul/2009:18:23:50 +0200] [Job 13] envp[6]="CUPS_SERVERROOT=/etc/cups"
D [10/Jul/2009:18:23:50 +0200] [Job 13] envp[7]="CUPS_STATEDIR=/var/run/cups"
D [10/Jul/2009:18:23:50 +0200] [Job 13] envp[8]="PATH=/usr/lib/cups/filter:/usr/bin:/usr/sbin:/bin:/usr/bin"
D [10/Jul/2009:18:23:50 +0200] [Job 13] envp[9]="SERVER_ADMIN=root@blackbox"
D [10/Jul/2009:18:23:50 +0200] [Job 13] envp[10]="SOFTWARE=CUPS/1.4b3"
D [10/Jul/2009:18:23:50 +0200] [Job 13] envp[11]="TMPDIR=/var/spool/cups/tmp"
D [10/Jul/2009:18:23:50 +0200] [Job 13] envp[12]="USER=root"
D [10/Jul/2009:18:23:50 +0200] [Job 13] envp[13]="CUPS_SERVER=/var/run/cups/cups.sock"
D [10/Jul/2009:18:23:50 +0200] [Job 13] envp[14]="CUPS_ENCRYPTION=IfRequested"
D [10/Jul/2009:18:23:50 +0200] [Job 13] envp[15]="IPP_PORT=631"
D [10/Jul/2009:18:23:50 +0200] [Job 13] envp[16]="CHARSET=utf-8"
D [10/Jul/2009:18:23:50 +0200] [Job 13] envp[17]="LANG=en_US.UTF8"
D [10/Jul/2009:18:23:50 +0200] [Job 13] envp[18]="PPD=/etc/cups/ppd/hp-2600n.ppd"
D [10/Jul/2009:18:23:50 +0200] [Job 13] envp[19]="RIP_MAX_CACHE=8m"
D [10/Jul/2009:18:23:50 +0200] [Job 13] envp[20]="CONTENT_TYPE=application/vnd.cups-banner"
D [10/Jul/2009:18:23:50 +0200] [Job 13] envp[21]="DEVICE_URI=hp:/usb/HP_Color_LaserJet_2600n?serial=F944RPG"
D [10/Jul/2009:18:23:50 +0200] [Job 13] envp[22]="PRINTER_INFO=HP HP Color LaserJet 2600n"
D [10/Jul/2009:18:23:50 +0200] [Job 13] envp[23]="PRINTER_LOCATION=blackbox"
D [10/Jul/2009:18:23:50 +0200] [Job 13] envp[24]="PRINTER=hp-2600n"
D [10/Jul/2009:18:23:50 +0200] [Job 13] envp[25]="CUPS_FILETYPE=document"
D [10/Jul/2009:18:23:50 +0200] [Job 13] envp[26]="FINAL_CONTENT_TYPE=printer/hp-2600n"
I [10/Jul/2009:18:23:50 +0200] [Job 13] Started filter /usr/lib/cups/filter/bannertops (PID 6622)
I [10/Jul/2009:18:23:50 +0200] [Job 13] Started filter /usr/lib/cups/filter/pstops (PID 6623)
I [10/Jul/2009:18:23:50 +0200] [Job 13] Started filter /usr/lib/cups/filter/foomatic-rip (PID 6624)
I [10/Jul/2009:18:23:50 +0200] [Job 13] Started backend /usr/lib/cups/backend/hp (PID 6625)
D [10/Jul/2009:18:23:50 +0200] Returning IPP successful-ok for Print-Job (ipp://localhost/printers/hp-2600n) from localhost
D [10/Jul/2009:18:23:50 +0200] [Job 13] STATE: +connecting-to-device
D [10/Jul/2009:18:23:50 +0200] PID 6622 (/usr/lib/cups/filter/bannertops) exited with no errors.
D [10/Jul/2009:18:23:50 +0200] PID 6623 (/usr/lib/cups/filter/pstops) exited with no errors.
D [10/Jul/2009:18:23:50 +0200] cupsdAcceptClient: skipping getpeercon()
D [10/Jul/2009:18:23:50 +0200] cupsdAcceptClient: 17 from localhost (Domain)
D [10/Jul/2009:18:23:50 +0200] cupsdReadClient: 17 POST / HTTP/1.1
D [10/Jul/2009:18:23:50 +0200] cupsdAuthorize: No authentication data provided.
D [10/Jul/2009:18:23:50 +0200] Get-Jobs ipp://localhost/printers/
D [10/Jul/2009:18:23:50 +0200] Returning IPP successful-ok for Get-Jobs (ipp://localhost/printers/) from localhost
D [10/Jul/2009:18:23:50 +0200] cupsdAcceptClient: skipping getpeercon()
D [10/Jul/2009:18:23:50 +0200] cupsdAcceptClient: 18 from localhost (Domain)
D [10/Jul/2009:18:23:50 +0200] cupsdReadClient: 18 POST / HTTP/1.1
D [10/Jul/2009:18:23:50 +0200] cupsdAuthorize: No authentication data provided.
D [10/Jul/2009:18:23:50 +0200] Get-Notifications /
D [10/Jul/2009:18:23:50 +0200] cupsdIsAuthorized: requesting-user-name="andrew"
D [10/Jul/2009:18:23:50 +0200] Returning IPP successful-ok for Get-Notifications (/) from localhost
D [10/Jul/2009:18:23:50 +0200] cupsdAcceptClient: skipping getpeercon()
D [10/Jul/2009:18:23:50 +0200] cupsdAcceptClient: 19 from localhost (Domain)
D [10/Jul/2009:18:23:50 +0200] cupsdReadClient: 19 POST / HTTP/1.1
D [10/Jul/2009:18:23:50 +0200] cupsdAuthorize: No authentication data provided.
D [10/Jul/2009:18:23:50 +0200] Get-Notifications /
D [10/Jul/2009:18:23:50 +0200] cupsdIsAuthorized: requesting-user-name="andrew"
D [10/Jul/2009:18:23:50 +0200] Returning IPP successful-ok for Get-Notifications (/) from localhost
D [10/Jul/2009:18:23:50 +0200] cupsdReadClient: 19 POST / HTTP/1.1
D [10/Jul/2009:18:23:50 +0200] cupsdAuthorize: No authentication data provided.
D [10/Jul/2009:18:23:50 +0200] Get-Job-Attributes ipp://localhost/jobs/13
D [10/Jul/2009:18:23:50 +0200] Returning IPP successful-ok for Get-Job-Attributes (ipp://localhost/jobs/13) from localhost
D [10/Jul/2009:18:23:50 +0200] cupsdReadClient: 12 POST / HTTP/1.1
D [10/Jul/2009:18:23:50 +0200] cupsdAuthorize: No authentication data provided.
D [10/Jul/2009:18:23:50 +0200] Get-Notifications /
D [10/Jul/2009:18:23:50 +0200] cupsdIsAuthorized: requesting-user-name="root"
D [10/Jul/2009:18:23:50 +0200] Returning IPP successful-ok for Get-Notifications (/) from localhost
D [10/Jul/2009:18:23:51 +0200] [Job 13] STATE: -connecting-to-device
D [10/Jul/2009:18:23:51 +0200] PID 6624 (/usr/lib/cups/filter/foomatic-rip) stopped with status 3!
D [10/Jul/2009:18:23:51 +0200] cupsdAcceptClient: skipping getpeercon()
D [10/Jul/2009:18:23:51 +0200] cupsdAcceptClient: 17 from localhost (Domain)
D [10/Jul/2009:18:23:51 +0200] cupsdReadClient: 17 POST / HTTP/1.1
D [10/Jul/2009:18:23:51 +0200] cupsdAuthorize: No authentication data provided.
D [10/Jul/2009:18:23:51 +0200] Get-Jobs ipp://localhost/printers/
D [10/Jul/2009:18:23:51 +0200] Returning IPP successful-ok for Get-Jobs (ipp://localhost/printers/) from localhost
D [10/Jul/2009:18:23:51 +0200] cupsdAcceptClient: skipping getpeercon()
D [10/Jul/2009:18:23:51 +0200] cupsdAcceptClient: 18 from localhost (Domain)
D [10/Jul/2009:18:23:51 +0200] cupsdReadClient: 18 POST / HTTP/1.1
D [10/Jul/2009:18:23:51 +0200] cupsdAuthorize: No authentication data provided.
D [10/Jul/2009:18:23:51 +0200] Get-Notifications /
D [10/Jul/2009:18:23:51 +0200] cupsdIsAuthorized: requesting-user-name="andrew"
D [10/Jul/2009:18:23:51 +0200] Returning IPP successful-ok for Get-Notifications (/) from localhost
D [10/Jul/2009:18:23:51 +0200] cupsdAcceptClient: skipping getpeercon()
D [10/Jul/2009:18:23:51 +0200] cupsdAcceptClient: 17 from localhost (Domain)
D [10/Jul/2009:18:23:51 +0200] cupsdReadClient: 17 POST / HTTP/1.1
D [10/Jul/2009:18:23:51 +0200] cupsdAuthorize: No authentication data provided.
D [10/Jul/2009:18:23:51 +0200] Get-Notifications /
D [10/Jul/2009:18:23:51 +0200] cupsdIsAuthorized: requesting-user-name="andrew"
D [10/Jul/2009:18:23:51 +0200] Returning IPP successful-ok for Get-Notifications (/) from localhost
D [10/Jul/2009:18:23:51 +0200] cupsdReadClient: 12 POST / HTTP/1.1
D [10/Jul/2009:18:23:51 +0200] cupsdAuthorize: No authentication data provided.
D [10/Jul/2009:18:23:51 +0200] Get-Notifications /
D [10/Jul/2009:18:23:51 +0200] cupsdIsAuthorized: requesting-user-name="root"
D [10/Jul/2009:18:23:51 +0200] Returning IPP successful-ok for Get-Notifications (/) from localhost
D [10/Jul/2009:18:23:52 +0200] cupsdAcceptClient: skipping getpeercon()
D [10/Jul/2009:18:23:52 +0200] cupsdAcceptClient: 17 from localhost (Domain)
D [10/Jul/2009:18:23:52 +0200] cupsdReadClient: 17 POST / HTTP/1.1
D [10/Jul/2009:18:23:52 +0200] cupsdAuthorize: No authentication data provided.
D [10/Jul/2009:18:23:52 +0200] CUPS-Get-Printers
D [10/Jul/2009:18:23:52 +0200] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost
D [10/Jul/2009:18:23:52 +0200] cupsdReadClient: 17 POST / HTTP/1.1
D [10/Jul/2009:18:23:52 +0200] cupsdAuthorize: No authentication data provided.
D [10/Jul/2009:18:23:52 +0200] CUPS-Get-Classes
D [10/Jul/2009:18:23:52 +0200] Returning IPP successful-ok for CUPS-Get-Classes (no URI) from localhost
D [10/Jul/2009:18:23:54 +0200] cupsdReadClient: 12 POST /jobs/ HTTP/1.1
D [10/Jul/2009:18:23:54 +0200] cupsdAuthorize: No authentication data provided.
D [10/Jul/2009:18:23:54 +0200] Cancel-Job ipp://localhost/jobs/12
D [10/Jul/2009:18:23:54 +0200] cupsdIsAuthorized: requesting-user-name="root"
D [10/Jul/2009:18:23:54 +0200] Cancel-Job client-error-not-possible: Job #12 is already canceled - can't cancel.
E [10/Jul/2009:18:23:54 +0200] Returning IPP client-error-not-possible for Cancel-Job (ipp://localhost/jobs/12) from localhost
D [10/Jul/2009:18:23:54 +0200] cupsdReadClient: 12 POST /jobs/ HTTP/1.1
D [10/Jul/2009:18:23:54 +0200] cupsdAuthorize: No authentication data provided.
D [10/Jul/2009:18:23:54 +0200] Cancel-Job ipp://localhost/jobs/13
D [10/Jul/2009:18:23:54 +0200] cupsdIsAuthorized: requesting-user-name="root"
I [10/Jul/2009:18:23:54 +0200] [Job 13] Job canceled by "root"
I [10/Jul/2009:18:23:54 +0200] [Job 13] Canceled by "root".
D [10/Jul/2009:18:23:54 +0200] Returning IPP successful-ok for Cancel-Job (ipp://localhost/jobs/13) from localhost
D [10/Jul/2009:18:23:54 +0200] PID 6625 (/usr/lib/cups/backend/hp) was terminated normally with signal 15.
E [10/Jul/2009:18:23:54 +0200] [Job 13] Job stopped due to filter errors; please consult the error_log file for details.
D [10/Jul/2009:18:23:54 +0200] cupsdAcceptClient: skipping getpeercon()
D [10/Jul/2009:18:23:54 +0200] cupsdAcceptClient: 16 from localhost (Domain)
D [10/Jul/2009:18:23:54 +0200] cupsdReadClient: 16 POST / HTTP/1.1
D [10/Jul/2009:18:23:54 +0200] cupsdSetBusyState: Active clients and dirty files
D [10/Jul/2009:18:23:54 +0200] cupsdAuthorize: No authentication data provided.
D [10/Jul/2009:18:23:54 +0200] Get-Jobs ipp://localhost/printers/
D [10/Jul/2009:18:23:54 +0200] Returning IPP successful-ok for Get-Jobs (ipp://localhost/printers/) from localhost
D [10/Jul/2009:18:23:54 +0200] cupsdAcceptClient: skipping getpeercon()
D [10/Jul/2009:18:23:54 +0200] cupsdAcceptClient: 17 from localhost (Domain)
D [10/Jul/2009:18:23:54 +0200] cupsdReadClient: 17 POST / HTTP/1.1
D [10/Jul/2009:18:23:54 +0200] cupsdAuthorize: No authentication data provided.
D [10/Jul/2009:18:23:54 +0200] Get-Notifications /
D [10/Jul/2009:18:23:54 +0200] cupsdIsAuthorized: requesting-user-name="andrew"
D [10/Jul/2009:18:23:54 +0200] Returning IPP successful-ok for Get-Notifications (/) from localhost
D [10/Jul/2009:18:23:54 +0200] cupsdAcceptClient: skipping getpeercon()
D [10/Jul/2009:18:23:54 +0200] cupsdAcceptClient: 16 from localhost (Domain)
D [10/Jul/2009:18:23:54 +0200] cupsdReadClient: 16 POST / HTTP/1.1
D [10/Jul/2009:18:23:54 +0200] cupsdAuthorize: No authentication data provided.
D [10/Jul/2009:18:23:54 +0200] Get-Notifications /
D [10/Jul/2009:18:23:54 +0200] cupsdIsAuthorized: requesting-user-name="andrew"
D [10/Jul/2009:18:23:54 +0200] Returning IPP successful-ok for Get-Notifications (/) from localhost
D [10/Jul/2009:18:23:54 +0200] cupsdReadClient: 12 POST / HTTP/1.1
D [10/Jul/2009:18:23:54 +0200] cupsdAuthorize: No authentication data provided.
D [10/Jul/2009:18:23:54 +0200] Get-Notifications /
D [10/Jul/2009:18:23:54 +0200] cupsdIsAuthorized: requesting-user-name="root"
D [10/Jul/2009:18:23:54 +0200] Returning IPP successful-ok for Get-Notifications (/) from localhost
D [10/Jul/2009:18:23:56 +0200] cupsdReadClient: 12 POST /jobs/ HTTP/1.1
D [10/Jul/2009:18:23:56 +0200] cupsdAuthorize: No authentication data provided.
D [10/Jul/2009:18:23:56 +0200] Cancel-Job ipp://localhost/jobs/12
D [10/Jul/2009:18:23:56 +0200] cupsdIsAuthorized: requesting-user-name="root"
D [10/Jul/2009:18:23:56 +0200] Cancel-Job client-error-not-possible: Job #12 is already canceled - can't cancel.
E [10/Jul/2009:18:23:56 +0200] Returning IPP client-error-not-possible for Cancel-Job (ipp://localhost/jobs/12) from localhost
D [10/Jul/2009:18:23:56 +0200] cupsdReadClient: 12 POST /jobs/ HTTP/1.1
D [10/Jul/2009:18:23:56 +0200] cupsdAuthorize: No authentication data provided.
D [10/Jul/2009:18:23:56 +0200] Cancel-Job ipp://localhost/jobs/13
D [10/Jul/2009:18:23:56 +0200] cupsdIsAuthorized: requesting-user-name="root"
I [10/Jul/2009:18:23:56 +0200] [Job 13] Job canceled by "root"
I [10/Jul/2009:18:23:56 +0200] [Job 13] Canceled by "root".
D [10/Jul/2009:18:23:56 +0200] Returning IPP successful-ok for Cancel-Job (ipp://localhost/jobs/13) from localhost
D [10/Jul/2009:18:23:56 +0200] cupsdAcceptClient: skipping getpeercon()
D [10/Jul/2009:18:23:56 +0200] cupsdAcceptClient: 16 from localhost (Domain)
D [10/Jul/2009:18:23:56 +0200] cupsdReadClient: 16 POST / HTTP/1.1
D [10/Jul/2009:18:23:56 +0200] cupsdAuthorize: No authentication data provided.
D [10/Jul/2009:18:23:56 +0200] Get-Jobs ipp://localhost/printers/
D [10/Jul/2009:18:23:56 +0200] Returning IPP successful-ok for Get-Jobs (ipp://localhost/printers/) from localhost
D [10/Jul/2009:18:23:56 +0200] cupsdAcceptClient: skipping getpeercon()
D [10/Jul/2009:18:23:56 +0200] cupsdAcceptClient: 17 from localhost (Domain)
D [10/Jul/2009:18:23:56 +0200] cupsdReadClient: 17 POST / HTTP/1.1
D [10/Jul/2009:18:23:56 +0200] cupsdAuthorize: No authentication data provided.
D [10/Jul/2009:18:23:56 +0200] Get-Notifications /
D [10/Jul/2009:18:23:56 +0200] cupsdIsAuthorized: requesting-user-name="andrew"
D [10/Jul/2009:18:23:56 +0200] Returning IPP successful-ok for Get-Notifications (/) from localhost
D [10/Jul/2009:18:23:56 +0200] cupsdAcceptClient: skipping getpeercon()
D [10/Jul/2009:18:23:56 +0200] cupsdAcceptClient: 16 from localhost (Domain)
D [10/Jul/2009:18:23:56 +0200] cupsdReadClient: 16 POST / HTTP/1.1
D [10/Jul/2009:18:23:56 +0200] cupsdAuthorize: No authentication data provided.
D [10/Jul/2009:18:23:56 +0200] Get-Notifications /
D [10/Jul/2009:18:23:56 +0200] cupsdIsAuthorized: requesting-user-name="andrew"
D [10/Jul/2009:18:23:56 +0200] Returning IPP successful-ok for Get-Notifications (/) from localhost
D [10/Jul/2009:18:23:56 +0200] cupsdReadClient: 12 POST / HTTP/1.1
D [10/Jul/2009:18:23:56 +0200] cupsdAuthorize: No authentication data provided.
D [10/Jul/2009:18:23:56 +0200] Get-Notifications /
D [10/Jul/2009:18:23:56 +0200] cupsdIsAuthorized: requesting-user-name="root"
D [10/Jul/2009:18:23:56 +0200] Returning IPP successful-ok for Get-Notifications (/) from localhost
D [10/Jul/2009:18:23:58 +0200] cupsdAcceptClient: skipping getpeercon()
D [10/Jul/2009:18:23:58 +0200] cupsdAcceptClient: 16 from localhost (Domain)
D [10/Jul/2009:18:23:58 +0200] cupsdReadClient: 16 POST /printers/hp-2600n HTTP/1.1
D [10/Jul/2009:18:23:58 +0200] cupsdAuthorize: No authentication data provided.
D [10/Jul/2009:18:23:58 +0200] Print-Job ipp://localhost/printers/hp-2600n
D [10/Jul/2009:18:23:58 +0200] [Job ???] Auto-typing file...
I [10/Jul/2009:18:23:58 +0200] [Job ???] Request file type is application/vnd.cups-banner.
D [10/Jul/2009:18:23:58 +0200] add_job: setting context of job to UNKNOWN SL
D [10/Jul/2009:18:23:58 +0200] add_job: requesting-user-name="andrew"
D [10/Jul/2009:18:23:58 +0200] Adding default job-sheets values "none,none"...
I [10/Jul/2009:18:23:58 +0200] [Job 14] Adding start banner page "none".
I [10/Jul/2009:18:23:58 +0200] [Job 14] Adding end banner page "none".
I [10/Jul/2009:18:23:58 +0200] [Job 14] File of type application/vnd.cups-banner queued by "andrew".
D [10/Jul/2009:18:23:58 +0200] [Job 14] hold_until=0
I [10/Jul/2009:18:23:58 +0200] [Job 14] Queued on "hp-2600n" by "andrew".
D [10/Jul/2009:18:23:58 +0200] cupsdSetBusyState: Active clients, printing jobs, and dirty files
D [10/Jul/2009:18:23:58 +0200] [Job 14] job-sheets=none,none
D [10/Jul/2009:18:23:58 +0200] [Job 14] argv[0]="hp-2600n"
D [10/Jul/2009:18:23:58 +0200] [Job 14] argv[1]="14"
D [10/Jul/2009:18:23:58 +0200] [Job 14] argv[2]="andrew"
D [10/Jul/2009:18:23:58 +0200] [Job 14] argv[3]="Test Page"
D [10/Jul/2009:18:23:58 +0200] [Job 14] argv[4]="1"
D [10/Jul/2009:18:23:58 +0200] [Job 14] argv[5]="job-uuid=urn:uuid:fc918b7e-e4dd-3a03-5d10-d9b914589487 job-originating-host-name=localhost"
D [10/Jul/2009:18:23:58 +0200] [Job 14] argv[6]="/var/spool/cups/d00014-001"
D [10/Jul/2009:18:23:58 +0200] [Job 14] envp[0]="CUPS_CACHEDIR=/var/cache/cups"
D [10/Jul/2009:18:23:58 +0200] [Job 14] envp[1]="CUPS_DATADIR=/usr/share/cups"
D [10/Jul/2009:18:23:58 +0200] [Job 14] envp[2]="CUPS_DOCROOT=/usr/share/cups/www"
D [10/Jul/2009:18:23:58 +0200] [Job 14] envp[3]="CUPS_FONTPATH=/usr/share/cups/fonts"
D [10/Jul/2009:18:23:58 +0200] [Job 14] envp[4]="CUPS_REQUESTROOT=/var/spool/cups"
D [10/Jul/2009:18:23:58 +0200] [Job 14] envp[5]="CUPS_SERVERBIN=/usr/lib/cups"
D [10/Jul/2009:18:23:58 +0200] [Job 14] envp[6]="CUPS_SERVERROOT=/etc/cups"
D [10/Jul/2009:18:23:58 +0200] [Job 14] envp[7]="CUPS_STATEDIR=/var/run/cups"
D [10/Jul/2009:18:23:58 +0200] [Job 14] envp[8]="PATH=/usr/lib/cups/filter:/usr/bin:/usr/sbin:/bin:/usr/bin"
D [10/Jul/2009:18:23:58 +0200] [Job 14] envp[9]="SERVER_ADMIN=root@blackbox"
D [10/Jul/2009:18:23:58 +0200] [Job 14] envp[10]="SOFTWARE=CUPS/1.4b3"
D [10/Jul/2009:18:23:58 +0200] [Job 14] envp[11]="TMPDIR=/var/spool/cups/tmp"
D [10/Jul/2009:18:23:58 +0200] [Job 14] envp[12]="USER=root"
D [10/Jul/2009:18:23:58 +0200] [Job 14] envp[13]="CUPS_SERVER=/var/run/cups/cups.sock"
D [10/Jul/2009:18:23:58 +0200] [Job 14] envp[14]="CUPS_ENCRYPTION=IfRequested"
D [10/Jul/2009:18:23:58 +0200] [Job 14] envp[15]="IPP_PORT=631"
D [10/Jul/2009:18:23:58 +0200] [Job 14] envp[16]="CHARSET=utf-8"
D [10/Jul/2009:18:23:58 +0200] [Job 14] envp[17]="LANG=en_US.UTF8"
D [10/Jul/2009:18:23:58 +0200] [Job 14] envp[18]="PPD=/etc/cups/ppd/hp-2600n.ppd"
D [10/Jul/2009:18:23:58 +0200] [Job 14] envp[19]="RIP_MAX_CACHE=8m"
D [10/Jul/2009:18:23:58 +0200] [Job 14] envp[20]="CONTENT_TYPE=application/vnd.cups-banner"
D [10/Jul/2009:18:23:58 +0200] [Job 14] envp[21]="DEVICE_URI=hp:/usb/HP_Color_LaserJet_2600n?serial=F944RPG"
D [10/Jul/2009:18:23:58 +0200] [Job 14] envp[22]="PRINTER_INFO=HP HP Color LaserJet 2600n"
D [10/Jul/2009:18:23:58 +0200] [Job 14] envp[23]="PRINTER_LOCATION=blackbox"
D [10/Jul/2009:18:23:58 +0200] [Job 14] envp[24]="PRINTER=hp-2600n"
D [10/Jul/2009:18:23:58 +0200] [Job 14] envp[25]="CUPS_FILETYPE=document"
D [10/Jul/2009:18:23:58 +0200] [Job 14] envp[26]="FINAL_CONTENT_TYPE=printer/hp-2600n"
I [10/Jul/2009:18:23:58 +0200] [Job 14] Started filter /usr/lib/cups/filter/bannertops (PID 6650)
I [10/Jul/2009:18:23:58 +0200] [Job 14] Started filter /usr/lib/cups/filter/pstops (PID 6651)
I [10/Jul/2009:18:23:58 +0200] [Job 14] Started filter /usr/lib/cups/filter/foomatic-rip (PID 6652)
I [10/Jul/2009:18:23:58 +0200] [Job 14] Started backend /usr/lib/cups/backend/hp (PID 6653)
D [10/Jul/2009:18:23:58 +0200] Returning IPP successful-ok for Print-Job (ipp://localhost/printers/hp-2600n) from localhost
D [10/Jul/2009:18:23:58 +0200] [Job 14] STATE: +connecting-to-device
D [10/Jul/2009:18:23:58 +0200] PID 6650 (/usr/lib/cups/filter/bannertops) exited with no errors.
D [10/Jul/2009:18:23:58 +0200] PID 6651 (/usr/lib/cups/filter/pstops) exited with no errors.
D [10/Jul/2009:18:23:58 +0200] cupsdAcceptClient: skipping getpeercon()
D [10/Jul/2009:18:23:58 +0200] cupsdAcceptClient: 17 from localhost (Domain)
D [10/Jul/2009:18:23:58 +0200] cupsdReadClient: 17 POST / HTTP/1.1
D [10/Jul/2009:18:23:58 +0200] cupsdAuthorize: No authentication data provided.
D [10/Jul/2009:18:23:58 +0200] Get-Jobs ipp://localhost/printers/
D [10/Jul/2009:18:23:58 +0200] Returning IPP successful-ok for Get-Jobs (ipp://localhost/printers/) from localhost
D [10/Jul/2009:18:23:58 +0200] cupsdAcceptClient: skipping getpeercon()
D [10/Jul/2009:18:23:58 +0200] cupsdAcceptClient: 18 from localhost (Domain)
D [10/Jul/2009:18:23:58 +0200] cupsdReadClient: 18 POST / HTTP/1.1
D [10/Jul/2009:18:23:58 +0200] cupsdAuthorize: No authentication data provided.
D [10/Jul/2009:18:23:58 +0200] Get-Notifications /
D [10/Jul/2009:18:23:58 +0200] cupsdIsAuthorized: requesting-user-name="andrew"
D [10/Jul/2009:18:23:58 +0200] Returning IPP successful-ok for Get-Notifications (/) from localhost
D [10/Jul/2009:18:23:58 +0200] cupsdReadClient: 18 POST / HTTP/1.1
D [10/Jul/2009:18:23:58 +0200] cupsdAuthorize: No authentication data provided.
D [10/Jul/2009:18:23:58 +0200] Get-Job-Attributes ipp://localhost/jobs/14
D [10/Jul/2009:18:23:58 +0200] Returning IPP successful-ok for Get-Job-Attributes (ipp://localhost/jobs/14) from localhost
D [10/Jul/2009:18:23:58 +0200] cupsdAcceptClient: skipping getpeercon()
D [10/Jul/2009:18:23:58 +0200] cupsdAcceptClient: 17 from localhost (Domain)
D [10/Jul/2009:18:23:58 +0200] cupsdReadClient: 17 POST / HTTP/1.1
D [10/Jul/2009:18:23:58 +0200] cupsdAuthorize: No authentication data provided.
D [10/Jul/2009:18:23:58 +0200] Get-Notifications /
D [10/Jul/2009:18:23:58 +0200] cupsdIsAuthorized: requesting-user-name="andrew"
D [10/Jul/2009:18:23:58 +0200] Returning IPP successful-ok for Get-Notifications (/) from localhost
D [10/Jul/2009:18:23:58 +0200] cupsdReadClient: 12 POST / HTTP/1.1
D [10/Jul/2009:18:23:58 +0200] cupsdAuthorize: No authentication data provided.
D [10/Jul/2009:18:23:58 +0200] Get-Notifications /
D [10/Jul/2009:18:23:58 +0200] cupsdIsAuthorized: requesting-user-name="root"
D [10/Jul/2009:18:23:58 +0200] Returning IPP successful-ok for Get-Notifications (/) from localhost
D [10/Jul/2009:18:23:58 +0200] [Job 14] STATE: -connecting-to-device
D [10/Jul/2009:18:23:58 +0200] PID 6652 (/usr/lib/cups/filter/foomatic-rip) stopped with status 3!
D [10/Jul/2009:18:23:58 +0200] cupsdAcceptClient: skipping getpeercon()
D [10/Jul/2009:18:23:58 +0200] cupsdAcceptClient: 17 from localhost (Domain)
D [10/Jul/2009:18:23:58 +0200] cupsdReadClient: 17 POST / HTTP/1.1
D [10/Jul/2009:18:23:58 +0200] cupsdAuthorize: No authentication data provided.
D [10/Jul/2009:18:23:58 +0200] Get-Jobs ipp://localhost/printers/
D [10/Jul/2009:18:23:58 +0200] Returning IPP successful-ok for Get-Jobs (ipp://localhost/printers/) from localhost
D [10/Jul/2009:18:23:58 +0200] cupsdAcceptClient: skipping getpeercon()
D [10/Jul/2009:18:23:58 +0200] cupsdAcceptClient: 18 from localhost (Domain)
D [10/Jul/2009:18:23:58 +0200] cupsdReadClient: 18 POST / HTTP/1.1
D [10/Jul/2009:18:23:58 +0200] cupsdAuthorize: No authentication data provided.
D [10/Jul/2009:18:23:58 +0200] Get-Notifications /
D [10/Jul/2009:18:23:58 +0200] cupsdIsAuthorized: requesting-user-name="andrew"
D [10/Jul/2009:18:23:58 +0200] Returning IPP successful-ok for Get-Notifications (/) from localhost
D [10/Jul/2009:18:23:58 +0200] cupsdAcceptClient: skipping getpeercon()
D [10/Jul/2009:18:23:58 +0200] cupsdAcceptClient: 19 from localhost (Domain)
D [10/Jul/2009:18:23:58 +0200] cupsdReadClient: 19 POST / HTTP/1.1
D [10/Jul/2009:18:23:58 +0200] cupsdAuthorize: No authentication data provided.
D [10/Jul/2009:18:23:58 +0200] Get-Notifications /
D [10/Jul/2009:18:23:58 +0200] cupsdIsAuthorized: requesting-user-name="andrew"
D [10/Jul/2009:18:23:58 +0200] Returning IPP successful-ok for Get-Notifications (/) from localhost
D [10/Jul/2009:18:23:58 +0200] cupsdReadClient: 12 POST / HTTP/1.1
D [10/Jul/2009:18:23:58 +0200] cupsdAuthorize: No authentication data provided.
D [10/Jul/2009:18:23:58 +0200] Get-Notifications /
D [10/Jul/2009:18:23:58 +0200] cupsdIsAuthorized: requesting-user-name="root"
D [10/Jul/2009:18:23:58 +0200] Returning IPP successful-ok for Get-Notifications (/) from localhost
I [10/Jul/2009:18:24:05 +0200] Saving job cache file "/var/cache/cups/job.cache"...
I [10/Jul/2009:18:24:05 +0200] Saving subscriptions.conf...
D [10/Jul/2009:18:24:05 +0200] cupsdSetBusyState: Active clients and printing jobs
D [10/Jul/2009:18:24:06 +0200] cupsdSetBusyState: Active clients, printing jobs, and dirty files
D [10/Jul/2009:18:24:06 +0200] PID 6653 (/usr/lib/cups/backend/hp) exited with no errors.
E [10/Jul/2009:18:24:06 +0200] [Job 14] Job stopped due to filter errors; please consult the error_log file for details.
D [10/Jul/2009:18:24:06 +0200] cupsdAcceptClient: skipping getpeercon()
D [10/Jul/2009:18:24:06 +0200] cupsdAcceptClient: 15 from localhost (Domain)
D [10/Jul/2009:18:24:06 +0200] cupsdReadClient: 15 POST / HTTP/1.1
D [10/Jul/2009:18:24:06 +0200] cupsdSetBusyState: Active clients and dirty files
D [10/Jul/2009:18:24:06 +0200] cupsdAuthorize: No authentication data provided.
D [10/Jul/2009:18:24:06 +0200] Get-Notifications /
D [10/Jul/2009:18:24:06 +0200] cupsdIsAuthorized: requesting-user-name="andrew"
D [10/Jul/2009:18:24:06 +0200] Returning IPP successful-ok for Get-Notifications (/) from localhost
D [10/Jul/2009:18:24:06 +0200] cupsdReadClient: 12 POST / HTTP/1.1
D [10/Jul/2009:18:24:06 +0200] cupsdAuthorize: No authentication data provided.
D [10/Jul/2009:18:24:06 +0200] Get-Notifications /
D [10/Jul/2009:18:24:06 +0200] cupsdIsAuthorized: requesting-user-name="root"
D [10/Jul/2009:18:24:06 +0200] Returning IPP successful-ok for Get-Notifications (/) from localhost
D [10/Jul/2009:18:24:06 +0200] cupsdAcceptClient: skipping getpeercon()
D [10/Jul/2009:18:24:06 +0200] cupsdAcceptClient: 15 from localhost (Domain)
D [10/Jul/2009:18:24:06 +0200] cupsdReadClient: 15 POST / HTTP/1.1
D [10/Jul/2009:18:24:06 +0200] cupsdAuthorize: No authentication data provided.
D [10/Jul/2009:18:24:06 +0200] Get-Jobs ipp://localhost/printers/
D [10/Jul/2009:18:24:06 +0200] Returning IPP successful-ok for Get-Jobs (ipp://localhost/printers/) from localhost
D [10/Jul/2009:18:24:06 +0200] cupsdAcceptClient: skipping getpeercon()
D [10/Jul/2009:18:24:06 +0200] cupsdAcceptClient: 17 from localhost (Domain)
D [10/Jul/2009:18:24:06 +0200] cupsdReadClient: 17 POST / HTTP/1.1
D [10/Jul/2009:18:24:06 +0200] cupsdAuthorize: No authentication data provided.
D [10/Jul/2009:18:24:06 +0200] Get-Notifications /
D [10/Jul/2009:18:24:06 +0200] cupsdIsAuthorized: requesting-user-name="andrew"
D [10/Jul/2009:18:24:06 +0200] Returning IPP successful-ok for Get-Notifications (/) from localhost
D [10/Jul/2009:18:24:06 +0200] cupsdAcceptClient: skipping getpeercon()
D [10/Jul/2009:18:24:06 +0200] cupsdAcceptClient: 15 from localhost (Domain)
D [10/Jul/2009:18:24:06 +0200] cupsdReadClient: 15 POST / HTTP/1.1
D [10/Jul/2009:18:24:06 +0200] cupsdAuthorize: No authentication data provided.
D [10/Jul/2009:18:24:06 +0200] Get-Printer-Attributes ipp://blackbox:631/printers/hp-2600n
D [10/Jul/2009:18:24:06 +0200] Returning IPP successful-ok for Get-Printer-Attributes (ipp://blackbox:631/printers/hp-2600n) from localhost
D [10/Jul/2009:18:24:06 +0200] cupsdReadClient: 15 POST / HTTP/1.1
D [10/Jul/2009:18:24:06 +0200] cupsdAuthorize: No authentication data provided.
D [10/Jul/2009:18:24:06 +0200] Get-Job-Attributes ipp://localhost/jobs/14
D [10/Jul/2009:18:24:06 +0200] Returning IPP successful-ok for Get-Job-Attributes (ipp://localhost/jobs/14) from localhost
D [10/Jul/2009:18:24:07 +0200] [Job 14] Unloading...
D [10/Jul/2009:18:24:11 +0200] cupsdReadClient: 12 POST / HTTP/1.1
D [10/Jul/2009:18:24:11 +0200] cupsdAuthorize: No authentication data provided.
D [10/Jul/2009:18:24:11 +0200] Get-Job-Attributes ipp://localhost/jobs/12
D [10/Jul/2009:18:24:11 +0200] Returning IPP successful-ok for Get-Job-Attributes (ipp://localhost/jobs/12) from localhost
D [10/Jul/2009:18:24:11 +0200] cupsdReadClient: 12 POST / HTTP/1.1
D [10/Jul/2009:18:24:11 +0200] cupsdAuthorize: No authentication data provided.
D [10/Jul/2009:18:24:11 +0200] Get-Job-Attributes ipp://localhost/jobs/13
D [10/Jul/2009:18:24:11 +0200] Returning IPP successful-ok for Get-Job-Attributes (ipp://localhost/jobs/13) from localhost
D [10/Jul/2009:18:24:11 +0200] cupsdReadClient: 12 POST / HTTP/1.1
D [10/Jul/2009:18:24:11 +0200] cupsdAuthorize: No authentication data provided.
D [10/Jul/2009:18:24:11 +0200] Get-Job-Attributes ipp://localhost/jobs/14
D [10/Jul/2009:18:24:11 +0200] [Job 14] Loading attributes...
D [10/Jul/2009:18:24:11 +0200] Returning IPP successful-ok for Get-Job-Attributes (ipp://localhost/jobs/14) from localhost
D [10/Jul/2009:18:24:12 +0200] cupsdReadClient: 12 POST / HTTP/1.1
D [10/Jul/2009:18:24:12 +0200] cupsdAuthorize: No authentication data provided.
D [10/Jul/2009:18:24:12 +0200] Cancel-Subscription /
D [10/Jul/2009:18:24:12 +0200] cupsdIsAuthorized: requesting-user-name="root"
D [10/Jul/2009:18:24:12 +0200] Returning IPP successful-ok for Cancel-Subscription (/) from localhost
D [10/Jul/2009:18:24:12 +0200] cupsdAcceptClient: skipping getpeercon()
D [10/Jul/2009:18:24:12 +0200] cupsdAcceptClient: 17 from localhost (Domain)
D [10/Jul/2009:18:24:12 +0200] cupsdReadClient: 17 GET /admin/log/error_log HTTP/1.1
D [10/Jul/2009:18:24:12 +0200] cupsdAuthorize: No authentication data provided.

Comment 3 Andrew 2009-07-10 16:27:18 UTC

Created attachment 351278 [details]
system-config-printers troubelshoot.txt

Comment 4 Andrew 2009-07-10 16:27:50 UTC

Created attachment 351280 [details]
system-config-printers troubelshoot.txt number 2

both had same result

Comment 5 Tim Waugh 2009-07-10 16:34:17 UTC

Thanks.  Now please download and install the test foomatic package by running this command as root:

rpm -Uvh http://kojipkgs.fedoraproject.org/packages/foomatic/4.0.2/3.fc11/i586/foomatic-4.0.2-3.fc11.i586.rpm

(it's all one line)

After that, do you still see the problem when you print?

Comment 6 Andrew 2009-07-11 11:45:28 UTC

Yes, still experiencing problems.

The test-page job switches from processing to switched.. 

Note that the hardware itself works fine under Windows and F9 and does not display any errors itself and can actually print a test page from it's own printer menu.

D [11/Jul/2009:13:43:39 +0200] cupsdReadClient: 12 POST / HTTP/1.1
D [11/Jul/2009:13:43:39 +0200] cupsdAuthorize: No authentication data provided.
D [11/Jul/2009:13:43:39 +0200] Get-Jobs ipp://localhost/printers/
D [11/Jul/2009:13:43:39 +0200] Returning IPP successful-ok for Get-Jobs (ipp://localhost/printers/) from localhost
D [11/Jul/2009:13:43:39 +0200] cupsdReadClient: 12 POST / HTTP/1.1
D [11/Jul/2009:13:43:39 +0200] cupsdAuthorize: No authentication data provided.
D [11/Jul/2009:13:43:39 +0200] Get-Jobs ipp://localhost/printers/
D [11/Jul/2009:13:43:39 +0200] [Job 8] Loading attributes...
D [11/Jul/2009:13:43:39 +0200] [Job 9] Loading attributes...
D [11/Jul/2009:13:43:39 +0200] [Job 10] Loading attributes...
D [11/Jul/2009:13:43:39 +0200] [Job 11] Loading attributes...
D [11/Jul/2009:13:43:39 +0200] [Job 12] Loading attributes...
D [11/Jul/2009:13:43:39 +0200] [Job 13] Loading attributes...
D [11/Jul/2009:13:43:39 +0200] [Job 14] Loading attributes...
D [11/Jul/2009:13:43:39 +0200] Returning IPP successful-ok for Get-Jobs (ipp://localhost/printers/) from localhost
D [11/Jul/2009:13:43:39 +0200] cupsdReadClient: 12 POST / HTTP/1.1
D [11/Jul/2009:13:43:39 +0200] cupsdAuthorize: No authentication data provided.
D [11/Jul/2009:13:43:39 +0200] Create-Printer-Subscription /
D [11/Jul/2009:13:43:39 +0200] cupsdCreateSubscription(con=0x2745e00(12), uri="/")
D [11/Jul/2009:13:43:39 +0200] pullmethod="ippget"
D [11/Jul/2009:13:43:39 +0200] notify-lease-duration=86400
D [11/Jul/2009:13:43:39 +0200] notify-time-interval=0
D [11/Jul/2009:13:43:39 +0200] cupsdAddSubscription(mask=17800, dest=(nil)(), job=(nil)(0), uri="(null)")
D [11/Jul/2009:13:43:39 +0200] Added subscription 26 for server
D [11/Jul/2009:13:43:39 +0200] Returning IPP successful-ok for Create-Printer-Subscription (/) from localhost
D [11/Jul/2009:13:43:40 +0200] cupsdReadClient: 12 POST / HTTP/1.1
D [11/Jul/2009:13:43:40 +0200] cupsdAuthorize: No authentication data provided.
D [11/Jul/2009:13:43:40 +0200] Get-Notifications /
D [11/Jul/2009:13:43:40 +0200] cupsdIsAuthorized: requesting-user-name="root"
D [11/Jul/2009:13:43:40 +0200] Returning IPP successful-ok for Get-Notifications (/) from localhost
D [11/Jul/2009:13:43:41 +0200] cupsdAcceptClient: skipping getpeercon()
D [11/Jul/2009:13:43:41 +0200] cupsdAcceptClient: 15 from localhost (Domain)
D [11/Jul/2009:13:43:41 +0200] cupsdReadClient: 15 POST /printers/hp-2600n HTTP/1.1
D [11/Jul/2009:13:43:41 +0200] cupsdAuthorize: No authentication data provided.
D [11/Jul/2009:13:43:41 +0200] Print-Job ipp://localhost/printers/hp-2600n
D [11/Jul/2009:13:43:41 +0200] [Job ???] Auto-typing file...
I [11/Jul/2009:13:43:41 +0200] [Job ???] Request file type is application/vnd.cups-banner.
D [11/Jul/2009:13:43:41 +0200] add_job: setting context of job to UNKNOWN SL
D [11/Jul/2009:13:43:41 +0200] add_job: requesting-user-name="andrew"
D [11/Jul/2009:13:43:41 +0200] Adding default job-sheets values "none,none"...
I [11/Jul/2009:13:43:41 +0200] [Job 15] Adding start banner page "none".
I [11/Jul/2009:13:43:41 +0200] [Job 15] Adding end banner page "none".
I [11/Jul/2009:13:43:41 +0200] [Job 15] File of type application/vnd.cups-banner queued by "andrew".
D [11/Jul/2009:13:43:41 +0200] [Job 15] hold_until=0
I [11/Jul/2009:13:43:41 +0200] [Job 15] Queued on "hp-2600n" by "andrew".
D [11/Jul/2009:13:43:41 +0200] cupsdSetBusyState: Active clients, printing jobs, and dirty files
D [11/Jul/2009:13:43:41 +0200] [Job 15] job-sheets=none,none
D [11/Jul/2009:13:43:41 +0200] [Job 15] argv[0]="hp-2600n"
D [11/Jul/2009:13:43:41 +0200] [Job 15] argv[1]="15"
D [11/Jul/2009:13:43:41 +0200] [Job 15] argv[2]="andrew"
D [11/Jul/2009:13:43:41 +0200] [Job 15] argv[3]="Test Page"
D [11/Jul/2009:13:43:41 +0200] [Job 15] argv[4]="1"
D [11/Jul/2009:13:43:41 +0200] [Job 15] argv[5]="job-uuid=urn:uuid:c835f2ff-5d35-3ee9-63dd-6197d85a88ed job-originating-host-name=localhost"
D [11/Jul/2009:13:43:41 +0200] [Job 15] argv[6]="/var/spool/cups/d00015-001"
D [11/Jul/2009:13:43:41 +0200] [Job 15] envp[0]="CUPS_CACHEDIR=/var/cache/cups"
D [11/Jul/2009:13:43:41 +0200] [Job 15] envp[1]="CUPS_DATADIR=/usr/share/cups"
D [11/Jul/2009:13:43:41 +0200] [Job 15] envp[2]="CUPS_DOCROOT=/usr/share/cups/www"
D [11/Jul/2009:13:43:41 +0200] [Job 15] envp[3]="CUPS_FONTPATH=/usr/share/cups/fonts"
D [11/Jul/2009:13:43:41 +0200] [Job 15] envp[4]="CUPS_REQUESTROOT=/var/spool/cups"
D [11/Jul/2009:13:43:41 +0200] [Job 15] envp[5]="CUPS_SERVERBIN=/usr/lib/cups"
D [11/Jul/2009:13:43:41 +0200] [Job 15] envp[6]="CUPS_SERVERROOT=/etc/cups"
D [11/Jul/2009:13:43:41 +0200] [Job 15] envp[7]="CUPS_STATEDIR=/var/run/cups"
D [11/Jul/2009:13:43:41 +0200] [Job 15] envp[8]="PATH=/usr/lib/cups/filter:/usr/bin:/usr/sbin:/bin:/usr/bin"
D [11/Jul/2009:13:43:41 +0200] [Job 15] envp[9]="SERVER_ADMIN=root@blackbox"
D [11/Jul/2009:13:43:41 +0200] [Job 15] envp[10]="SOFTWARE=CUPS/1.4b3"
D [11/Jul/2009:13:43:41 +0200] [Job 15] envp[11]="TMPDIR=/var/spool/cups/tmp"
D [11/Jul/2009:13:43:41 +0200] [Job 15] envp[12]="USER=root"
D [11/Jul/2009:13:43:41 +0200] [Job 15] envp[13]="CUPS_SERVER=/var/run/cups/cups.sock"
D [11/Jul/2009:13:43:41 +0200] [Job 15] envp[14]="CUPS_ENCRYPTION=IfRequested"
D [11/Jul/2009:13:43:41 +0200] [Job 15] envp[15]="IPP_PORT=631"
D [11/Jul/2009:13:43:41 +0200] [Job 15] envp[16]="CHARSET=utf-8"
D [11/Jul/2009:13:43:41 +0200] [Job 15] envp[17]="LANG=en_US.UTF8"
D [11/Jul/2009:13:43:41 +0200] [Job 15] envp[18]="PPD=/etc/cups/ppd/hp-2600n.ppd"
D [11/Jul/2009:13:43:41 +0200] [Job 15] envp[19]="RIP_MAX_CACHE=8m"
D [11/Jul/2009:13:43:41 +0200] [Job 15] envp[20]="CONTENT_TYPE=application/vnd.cups-banner"
D [11/Jul/2009:13:43:41 +0200] [Job 15] envp[21]="DEVICE_URI=hp:/usb/HP_Color_LaserJet_2600n?serial=F944RPG"
D [11/Jul/2009:13:43:41 +0200] [Job 15] envp[22]="PRINTER_INFO=HP HP Color LaserJet 2600n"
D [11/Jul/2009:13:43:41 +0200] [Job 15] envp[23]="PRINTER_LOCATION=blackbox"
D [11/Jul/2009:13:43:41 +0200] [Job 15] envp[24]="PRINTER=hp-2600n"
D [11/Jul/2009:13:43:41 +0200] [Job 15] envp[25]="CUPS_FILETYPE=document"
D [11/Jul/2009:13:43:41 +0200] [Job 15] envp[26]="FINAL_CONTENT_TYPE=printer/hp-2600n"
I [11/Jul/2009:13:43:41 +0200] [Job 15] Started filter /usr/lib/cups/filter/bannertops (PID 10833)
I [11/Jul/2009:13:43:41 +0200] [Job 15] Started filter /usr/lib/cups/filter/pstops (PID 10834)
I [11/Jul/2009:13:43:41 +0200] [Job 15] Started filter /usr/lib/cups/filter/foomatic-rip (PID 10835)
I [11/Jul/2009:13:43:41 +0200] [Job 15] Started backend /usr/lib/cups/backend/hp (PID 10836)
D [11/Jul/2009:13:43:41 +0200] Returning IPP successful-ok for Print-Job (ipp://localhost/printers/hp-2600n) from localhost
D [11/Jul/2009:13:43:41 +0200] [Job 15] STATE: +connecting-to-device
D [11/Jul/2009:13:43:41 +0200] cupsdAcceptClient: skipping getpeercon()
D [11/Jul/2009:13:43:41 +0200] cupsdAcceptClient: 17 from localhost (Domain)
D [11/Jul/2009:13:43:41 +0200] cupsdAcceptClient: skipping getpeercon()
D [11/Jul/2009:13:43:41 +0200] cupsdAcceptClient: 18 from localhost (Domain)
D [11/Jul/2009:13:43:41 +0200] cupsdReadClient: 17 POST / HTTP/1.1
D [11/Jul/2009:13:43:41 +0200] cupsdAuthorize: No authentication data provided.
D [11/Jul/2009:13:43:41 +0200] cupsdReadClient: 18 POST / HTTP/1.1
D [11/Jul/2009:13:43:41 +0200] cupsdAuthorize: No authentication data provided.
D [11/Jul/2009:13:43:41 +0200] Get-Notifications /
D [11/Jul/2009:13:43:41 +0200] cupsdIsAuthorized: requesting-user-name="andrew"
D [11/Jul/2009:13:43:41 +0200] Returning IPP successful-ok for Get-Notifications (/) from localhost
D [11/Jul/2009:13:43:41 +0200] Get-Jobs ipp://localhost/printers/
D [11/Jul/2009:13:43:41 +0200] Returning IPP successful-ok for Get-Jobs (ipp://localhost/printers/) from localhost
D [11/Jul/2009:13:43:41 +0200] cupsdAcceptClient: skipping getpeercon()
D [11/Jul/2009:13:43:41 +0200] cupsdAcceptClient: 18 from localhost (Domain)
D [11/Jul/2009:13:43:41 +0200] cupsdReadClient: 18 POST / HTTP/1.1
D [11/Jul/2009:13:43:41 +0200] cupsdAuthorize: No authentication data provided.
D [11/Jul/2009:13:43:41 +0200] Get-Notifications /
D [11/Jul/2009:13:43:41 +0200] cupsdIsAuthorized: requesting-user-name="andrew"
D [11/Jul/2009:13:43:41 +0200] Returning IPP successful-ok for Get-Notifications (/) from localhost
D [11/Jul/2009:13:43:41 +0200] cupsdReadClient: 18 POST / HTTP/1.1
D [11/Jul/2009:13:43:41 +0200] cupsdAuthorize: No authentication data provided.
D [11/Jul/2009:13:43:41 +0200] Get-Job-Attributes ipp://localhost/jobs/15
D [11/Jul/2009:13:43:41 +0200] Returning IPP successful-ok for Get-Job-Attributes (ipp://localhost/jobs/15) from localhost
D [11/Jul/2009:13:43:41 +0200] cupsdReadClient: 12 POST / HTTP/1.1
D [11/Jul/2009:13:43:41 +0200] cupsdAuthorize: No authentication data provided.
D [11/Jul/2009:13:43:41 +0200] Get-Notifications /
D [11/Jul/2009:13:43:41 +0200] cupsdIsAuthorized: requesting-user-name="root"
D [11/Jul/2009:13:43:41 +0200] Returning IPP successful-ok for Get-Notifications (/) from localhost
D [11/Jul/2009:13:43:42 +0200] PID 10833 (/usr/lib/cups/filter/bannertops) exited with no errors.
D [11/Jul/2009:13:43:42 +0200] PID 10834 (/usr/lib/cups/filter/pstops) exited with no errors.
D [11/Jul/2009:13:43:43 +0200] [Job 15] STATE: -connecting-to-device
D [11/Jul/2009:13:43:43 +0200] PID 10835 (/usr/lib/cups/filter/foomatic-rip) stopped with status 3!
D [11/Jul/2009:13:43:43 +0200] cupsdAcceptClient: skipping getpeercon()
D [11/Jul/2009:13:43:43 +0200] cupsdAcceptClient: 17 from localhost (Domain)
D [11/Jul/2009:13:43:43 +0200] cupsdReadClient: 17 POST / HTTP/1.1
D [11/Jul/2009:13:43:43 +0200] cupsdAuthorize: No authentication data provided.
D [11/Jul/2009:13:43:43 +0200] Get-Jobs ipp://localhost/printers/
D [11/Jul/2009:13:43:43 +0200] Returning IPP successful-ok for Get-Jobs (ipp://localhost/printers/) from localhost
D [11/Jul/2009:13:43:43 +0200] cupsdAcceptClient: skipping getpeercon()
D [11/Jul/2009:13:43:43 +0200] cupsdAcceptClient: 18 from localhost (Domain)
D [11/Jul/2009:13:43:43 +0200] cupsdReadClient: 18 POST / HTTP/1.1
D [11/Jul/2009:13:43:43 +0200] cupsdAuthorize: No authentication data provided.
D [11/Jul/2009:13:43:43 +0200] Get-Notifications /
D [11/Jul/2009:13:43:43 +0200] cupsdIsAuthorized: requesting-user-name="andrew"
D [11/Jul/2009:13:43:43 +0200] Returning IPP successful-ok for Get-Notifications (/) from localhost
D [11/Jul/2009:13:43:43 +0200] cupsdAcceptClient: skipping getpeercon()
D [11/Jul/2009:13:43:43 +0200] cupsdAcceptClient: 17 from localhost (Domain)
D [11/Jul/2009:13:43:43 +0200] cupsdReadClient: 17 POST / HTTP/1.1
D [11/Jul/2009:13:43:43 +0200] cupsdAuthorize: No authentication data provided.
D [11/Jul/2009:13:43:43 +0200] Get-Notifications /
D [11/Jul/2009:13:43:43 +0200] cupsdIsAuthorized: requesting-user-name="andrew"
D [11/Jul/2009:13:43:43 +0200] Returning IPP successful-ok for Get-Notifications (/) from localhost
D [11/Jul/2009:13:43:43 +0200] cupsdReadClient: 12 POST / HTTP/1.1
D [11/Jul/2009:13:43:43 +0200] cupsdAuthorize: No authentication data provided.
D [11/Jul/2009:13:43:43 +0200] Get-Notifications /
D [11/Jul/2009:13:43:43 +0200] cupsdIsAuthorized: requesting-user-name="root"
D [11/Jul/2009:13:43:43 +0200] Returning IPP successful-ok for Get-Notifications (/) from localhost
I [11/Jul/2009:13:43:50 +0200] Saving job cache file "/var/cache/cups/job.cache"...
I [11/Jul/2009:13:43:50 +0200] Saving subscriptions.conf...
D [11/Jul/2009:13:43:50 +0200] cupsdSetBusyState: Active clients and printing jobs
D [11/Jul/2009:13:43:51 +0200] cupsdSetBusyState: Active clients, printing jobs, and dirty files
D [11/Jul/2009:13:43:51 +0200] PID 10836 (/usr/lib/cups/backend/hp) exited with no errors.
E [11/Jul/2009:13:43:51 +0200] [Job 15] Job stopped due to filter errors; please consult the error_log file for details.
D [11/Jul/2009:13:43:51 +0200] cupsdAcceptClient: skipping getpeercon()
D [11/Jul/2009:13:43:51 +0200] cupsdAcceptClient: 16 from localhost (Domain)
D [11/Jul/2009:13:43:51 +0200] cupsdReadClient: 16 POST / HTTP/1.1
D [11/Jul/2009:13:43:51 +0200] cupsdSetBusyState: Active clients and dirty files
D [11/Jul/2009:13:43:51 +0200] cupsdAuthorize: No authentication data provided.
D [11/Jul/2009:13:43:51 +0200] Get-Notifications /
D [11/Jul/2009:13:43:51 +0200] cupsdIsAuthorized: requesting-user-name="andrew"
D [11/Jul/2009:13:43:51 +0200] Returning IPP successful-ok for Get-Notifications (/) from localhost
D [11/Jul/2009:13:43:51 +0200] cupsdAcceptClient: skipping getpeercon()
D [11/Jul/2009:13:43:51 +0200] cupsdAcceptClient: 17 from localhost (Domain)
D [11/Jul/2009:13:43:51 +0200] cupsdReadClient: 17 POST / HTTP/1.1
D [11/Jul/2009:13:43:51 +0200] cupsdAuthorize: No authentication data provided.
D [11/Jul/2009:13:43:51 +0200] Get-Jobs ipp://localhost/printers/
D [11/Jul/2009:13:43:51 +0200] Returning IPP successful-ok for Get-Jobs (ipp://localhost/printers/) from localhost
D [11/Jul/2009:13:43:51 +0200] cupsdAcceptClient: skipping getpeercon()
D [11/Jul/2009:13:43:51 +0200] cupsdAcceptClient: 18 from localhost (Domain)
D [11/Jul/2009:13:43:51 +0200] cupsdReadClient: 18 POST / HTTP/1.1
D [11/Jul/2009:13:43:51 +0200] cupsdAuthorize: No authentication data provided.
D [11/Jul/2009:13:43:51 +0200] Get-Notifications /
D [11/Jul/2009:13:43:51 +0200] cupsdIsAuthorized: requesting-user-name="andrew"
D [11/Jul/2009:13:43:51 +0200] Returning IPP successful-ok for Get-Notifications (/) from localhost
D [11/Jul/2009:13:43:51 +0200] cupsdAcceptClient: skipping getpeercon()
D [11/Jul/2009:13:43:51 +0200] cupsdAcceptClient: 17 from localhost (Domain)
D [11/Jul/2009:13:43:51 +0200] cupsdReadClient: 17 POST / HTTP/1.1
D [11/Jul/2009:13:43:51 +0200] cupsdAuthorize: No authentication data provided.
D [11/Jul/2009:13:43:51 +0200] Get-Printer-Attributes ipp://blackbox:631/printers/hp-2600n
D [11/Jul/2009:13:43:51 +0200] Returning IPP successful-ok for Get-Printer-Attributes (ipp://blackbox:631/printers/hp-2600n) from localhost
D [11/Jul/2009:13:43:51 +0200] cupsdReadClient: 17 POST / HTTP/1.1
D [11/Jul/2009:13:43:51 +0200] cupsdAuthorize: No authentication data provided.
D [11/Jul/2009:13:43:51 +0200] Get-Job-Attributes ipp://localhost/jobs/15
D [11/Jul/2009:13:43:51 +0200] Returning IPP successful-ok for Get-Job-Attributes (ipp://localhost/jobs/15) from localhost
D [11/Jul/2009:13:43:51 +0200] cupsdReadClient: 12 POST / HTTP/1.1
D [11/Jul/2009:13:43:51 +0200] cupsdAuthorize: No authentication data provided.
D [11/Jul/2009:13:43:51 +0200] Get-Notifications /
D [11/Jul/2009:13:43:51 +0200] cupsdIsAuthorized: requesting-user-name="root"
D [11/Jul/2009:13:43:51 +0200] Returning IPP successful-ok for Get-Notifications (/) from localhost
D [11/Jul/2009:13:43:52 +0200] [Job 15] Unloading...
D [11/Jul/2009:13:44:16 +0200] cupsdReadClient: 12 POST / HTTP/1.1
D [11/Jul/2009:13:44:16 +0200] cupsdAuthorize: No authentication data provided.
D [11/Jul/2009:13:44:16 +0200] Get-Job-Attributes ipp://localhost/jobs/15
D [11/Jul/2009:13:44:16 +0200] [Job 15] Loading attributes...
D [11/Jul/2009:13:44:16 +0200] Returning IPP successful-ok for Get-Job-Attributes (ipp://localhost/jobs/15) from localhost
D [11/Jul/2009:13:44:16 +0200] cupsdReadClient: 12 POST / HTTP/1.1
D [11/Jul/2009:13:44:16 +0200] cupsdAuthorize: No authentication data provided.
D [11/Jul/2009:13:44:16 +0200] Cancel-Subscription /
D [11/Jul/2009:13:44:16 +0200] cupsdIsAuthorized: requesting-user-name="root"
D [11/Jul/2009:13:44:16 +0200] Returning IPP successful-ok for Cancel-Subscription (/) from localhost
D [11/Jul/2009:13:44:16 +0200] cupsdAcceptClient: skipping getpeercon()
D [11/Jul/2009:13:44:16 +0200] cupsdAcceptClient: 16 from localhost (Domain)
D [11/Jul/2009:13:44:16 +0200] cupsdReadClient: 16 GET /admin/log/error_log HTTP/1.1
D [11/Jul/2009:13:44:16 +0200] cupsdAuthorize: No authentication data provided.

Comment 7 Andrew 2009-07-11 11:46:51 UTC

Created attachment 351337 [details]
system-config-printers troubleshoot.txt after updates

Comment 8 Tim Waugh 2009-07-11 22:06:55 UTC

OK, please now run this command as root:

echo 'debug: 1' >> /etc/foomatic/filter.conf

After that, please try another test print and then attach this file:

/tmp/foomatic-rip.log

Thanks.

Note You need to log in before you can comment on or make changes to this bug.