If I try to print the Self Test Page the cups webinterface shows: ▼ ID ▼ Name User Size Pages State Control Laserjet1300Grizzly-2628 Print Self-Test Page anonymous 1k Unknown processing since Mon 30 Jul 2012 09:09:56 AM CEST but nothing is printed. In /var/log/cups/error_log I find: D [30/Jul/2012:09:27:20 +0200] [CGI] cgiClearVariables called. D [30/Jul/2012:09:27:20 +0200] [CGI] cgiSetVariable: ORDER="asc" D [30/Jul/2012:09:27:20 +0200] [CGI] cgiSetVariable: SECTION="printers" D [30/Jul/2012:09:27:20 +0200] [CGI] cgiSetVariable: TOTAL="1" D [30/Jul/2012:09:27:20 +0200] [CGI] cgiSetVariable: SERVER_NAME="localhost" D [30/Jul/2012:09:27:20 +0200] [CGI] cgiSetVariable: CUPS_VERSION="CUPS v1.6.0" D [30/Jul/2012:09:27:20 +0200] [CGI] cgiSetArray: job_printer_name[0]="Laserjet1300Grizzly" D [30/Jul/2012:09:27:20 +0200] [CGI] cgiSetArray: job_printer_uri[0]="/printers/Laserjet1300Grizzly" D [30/Jul/2012:09:27:20 +0200] [CGI] cgiSetArray: job_originating_user_name[0]="anonymous" D [30/Jul/2012:09:27:20 +0200] [CGI] cgiSetArray: job_name[0]="Print Self-Test Page" D [30/Jul/2012:09:27:20 +0200] [CGI] cgiSetArray: time_at_creation[0]="Mon 30 Jul 2012 09:06:53 AM CEST" D [30/Jul/2012:09:27:20 +0200] [CGI] cgiSetArray: time_at_processing[0]="Mon 30 Jul 2012 09:09:56 AM CEST" D [30/Jul/2012:09:27:20 +0200] [CGI] cgiSetArray: time_at_completed[0]="novalue" D [30/Jul/2012:09:27:20 +0200] [CGI] cgiSetArray: job_id[0]="2628" D [30/Jul/2012:09:27:20 +0200] [CGI] cgiSetArray: job_state[0]="5" D [30/Jul/2012:09:27:20 +0200] [CGI] cgiSetArray: job_media_sheets_completed[0]="0" D [30/Jul/2012:09:27:20 +0200] [CGI] cgiSetArray: job_k_octets[0]="1" D [30/Jul/2012:09:27:20 +0200] [CGI] cgiSetArray: job_printer_state_message[0]="" D [30/Jul/2012:09:27:20 +0200] [CGI] cgiSetVariable: PRINTER_NAME="Laserjet1300Grizzly" D [30/Jul/2012:09:27:20 +0200] [CGI] cgiSetVariable: PRINTER_URI_SUPPORTED="/printers/Laserjet1300Grizzly" D [30/Jul/2012:09:27:20 +0200] [CGI] cgiSetVariable: THISURL="/printers/Laserjet1300Grizzly" D [30/Jul/2012:09:27:20 +0200] [CGI] cgiSetVariable: SEARCH_DEST="Laserjet1300Grizzly" D [30/Jul/2012:09:27:20 +0200] [Client 17] HTTP_WAITING Closing on EOF D [30/Jul/2012:09:27:20 +0200] [Client 17] Closing connection. D [30/Jul/2012:09:27:20 +0200] cupsdSetBusyState: newbusy="Active clients and printing jobs", busy="Active clients and printing jobs" D [30/Jul/2012:09:27:20 +0200] PID 24209 (/usr/libexec/cups/cgi-bin/printers.cgi) exited with no errors. D [30/Jul/2012:09:27:20 +0200] cupsdSetBusyState: newbusy="Printing jobs", busy="Active clients and printing jobs" D [30/Jul/2012:09:27:20 +0200] [Client 15] Accepted from localhost:631 (IPv4) D [30/Jul/2012:09:27:20 +0200] [Client 15] GET /cups.css HTTP/1.1 D [30/Jul/2012:09:27:20 +0200] cupsdSetBusyState: newbusy="Active clients and printing jobs", busy="Printing jobs" D [30/Jul/2012:09:27:20 +0200] [Client 15] No authentication data provided. D [30/Jul/2012:09:27:20 +0200] cupsdSetBusyState: newbusy="Printing jobs", busy="Active clients and printing jobs" D [30/Jul/2012:09:27:20 +0200] [Client 15] HTTP_WAITING Closing on EOF D [30/Jul/2012:09:27:20 +0200] [Client 15] Closing connection. D [30/Jul/2012:09:27:20 +0200] cupsdSetBusyState: newbusy="Printing jobs", busy="Printing jobs" D [30/Jul/2012:09:27:20 +0200] [Client 15] Accepted from localhost:631 (IPv4) D [30/Jul/2012:09:27:20 +0200] [Client 17] Accepted from localhost:631 (IPv4) D [30/Jul/2012:09:27:20 +0200] [Client 18] Accepted from localhost:631 (IPv4) D [30/Jul/2012:09:27:20 +0200] [Client 15] GET /images/left.gif HTTP/1.1 D [30/Jul/2012:09:27:20 +0200] cupsdSetBusyState: newbusy="Active clients and printing jobs", busy="Printing jobs" D [30/Jul/2012:09:27:20 +0200] [Client 15] No authentication data provided. D [30/Jul/2012:09:27:20 +0200] cupsdSetBusyState: newbusy="Printing jobs", busy="Active clients and printing jobs" D [30/Jul/2012:09:27:20 +0200] [Client 17] GET /images/unsel.gif HTTP/1.1 D [30/Jul/2012:09:27:20 +0200] cupsdSetBusyState: newbusy="Active clients and printing jobs", busy="Printing jobs" D [30/Jul/2012:09:27:20 +0200] [Client 17] No authentication data provided. D [30/Jul/2012:09:27:20 +0200] cupsdSetBusyState: newbusy="Printing jobs", busy="Active clients and printing jobs" D [30/Jul/2012:09:27:20 +0200] [Client 18] GET /images/sel.gif HTTP/1.1 D [30/Jul/2012:09:27:20 +0200] cupsdSetBusyState: newbusy="Active clients and printing jobs", busy="Printing jobs" D [30/Jul/2012:09:27:20 +0200] [Client 18] No authentication data provided. D [30/Jul/2012:09:27:20 +0200] cupsdSetBusyState: newbusy="Printing jobs", busy="Active clients and printing jobs" D [30/Jul/2012:09:27:20 +0200] [Client 15] HTTP_WAITING Closing on EOF D [30/Jul/2012:09:27:20 +0200] [Client 15] Closing connection. D [30/Jul/2012:09:27:20 +0200] cupsdSetBusyState: newbusy="Printing jobs", busy="Printing jobs" D [30/Jul/2012:09:27:20 +0200] [Client 17] HTTP_WAITING Closing on EOF D [30/Jul/2012:09:27:20 +0200] [Client 17] Closing connection. D [30/Jul/2012:09:27:20 +0200] cupsdSetBusyState: newbusy="Printing jobs", busy="Printing jobs" D [30/Jul/2012:09:27:20 +0200] [Client 18] HTTP_WAITING Closing on EOF D [30/Jul/2012:09:27:20 +0200] [Client 18] Closing connection. D [30/Jul/2012:09:27:20 +0200] cupsdSetBusyState: newbusy="Printing jobs", busy="Printing jobs" D [30/Jul/2012:09:27:20 +0200] [Client 15] Accepted from localhost:631 (IPv4) D [30/Jul/2012:09:27:20 +0200] [Client 15] GET /images/right.gif HTTP/1.1 D [30/Jul/2012:09:27:20 +0200] cupsdSetBusyState: newbusy="Active clients and printing jobs", busy="Printing jobs" D [30/Jul/2012:09:27:20 +0200] [Client 15] No authentication data provided. D [30/Jul/2012:09:27:20 +0200] cupsdSetBusyState: newbusy="Printing jobs", busy="Active clients and printing jobs" D [30/Jul/2012:09:27:20 +0200] [Client 15] HTTP_WAITING Closing on EOF D [30/Jul/2012:09:27:20 +0200] [Client 15] Closing connection. D [30/Jul/2012:09:27:20 +0200] cupsdSetBusyState: newbusy="Printing jobs", busy="Printing jobs" D [30/Jul/2012:09:27:30 +0200] [Client 16] GET /printers/Laserjet1300Grizzly HTTP/1.1 D [30/Jul/2012:09:27:30 +0200] cupsdSetBusyState: newbusy="Active clients and printing jobs", busy="Printing jobs" D [30/Jul/2012:09:27:30 +0200] [Client 16] No authentication data provided. D [30/Jul/2012:09:27:30 +0200] [CGI] argv[0] = "/usr/libexec/cups/cgi-bin/printers.cgi" D [30/Jul/2012:09:27:30 +0200] [CGI] envp[0] = "CUPS_CACHEDIR=/var/cache/cups" D [30/Jul/2012:09:27:30 +0200] [CGI] envp[1] = "CUPS_DATADIR=/usr/share/cups" D [30/Jul/2012:09:27:30 +0200] [CGI] envp[2] = "CUPS_DOCROOT=/usr/share/cups/html" D [30/Jul/2012:09:27:30 +0200] [CGI] envp[3] = "CUPS_FONTPATH=/usr/share/cups/fonts" D [30/Jul/2012:09:27:30 +0200] [CGI] envp[4] = "CUPS_REQUESTROOT=/var/spool/cups" D [30/Jul/2012:09:27:30 +0200] [CGI] envp[5] = "CUPS_SERVERBIN=/usr/libexec/cups" D [30/Jul/2012:09:27:30 +0200] [CGI] envp[6] = "CUPS_SERVERROOT=/etc/cups" D [30/Jul/2012:09:27:30 +0200] [CGI] envp[7] = "CUPS_STATEDIR=/var/run/cups" D [30/Jul/2012:09:27:30 +0200] [CGI] envp[8] = "HOME=/var/spool/cups/tmp" D [30/Jul/2012:09:27:30 +0200] [CGI] envp[9] = "PATH=/usr/libexec/cups/filter:/usr/bin:/usr/sbin:/bin:/usr/bin" D [30/Jul/2012:09:27:30 +0200] [CGI] envp[10] = "SERVER_ADMIN=root@grizzly.homenet" D [30/Jul/2012:09:27:30 +0200] [CGI] envp[11] = "SOFTWARE=CUPS/1.6.0" D [30/Jul/2012:09:27:30 +0200] [CGI] envp[12] = "TMPDIR=/var/spool/cups/tmp" D [30/Jul/2012:09:27:30 +0200] [CGI] envp[13] = "USER=root" D [30/Jul/2012:09:27:30 +0200] [CGI] envp[14] = "CUPS_MAX_MESSAGE=2047" D [30/Jul/2012:09:27:30 +0200] [CGI] envp[15] = "CUPS_SERVER=/var/run/cups/cups.sock" D [30/Jul/2012:09:27:30 +0200] [CGI] envp[16] = "CUPS_ENCRYPTION=IfRequested" D [30/Jul/2012:09:27:30 +0200] [CGI] envp[17] = "IPP_PORT=631" D [30/Jul/2012:09:27:30 +0200] [CGI] envp[18] = "LANG=en_US.UTF8" D [30/Jul/2012:09:27:30 +0200] [CGI] envp[19] = "REDIRECT_STATUS=1" D [30/Jul/2012:09:27:30 +0200] [CGI] envp[20] = "GATEWAY_INTERFACE=CGI/1.1" D [30/Jul/2012:09:27:30 +0200] [CGI] envp[21] = "SERVER_NAME=localhost" D [30/Jul/2012:09:27:30 +0200] [CGI] envp[22] = "SERVER_PORT=631" D [30/Jul/2012:09:27:30 +0200] [CGI] envp[23] = "REMOTE_ADDR=127.0.0.1" D [30/Jul/2012:09:27:30 +0200] [CGI] envp[24] = "REMOTE_HOST=localhost" D [30/Jul/2012:09:27:30 +0200] [CGI] envp[25] = "SCRIPT_NAME=/printers/Laserjet1300Grizzly" D [30/Jul/2012:09:27:30 +0200] [CGI] envp[26] = "SCRIPT_FILENAME=/usr/share/cups/html/printers/Laserjet1300Grizzly" D [30/Jul/2012:09:27:30 +0200] [CGI] envp[27] = "PATH_INFO=/Laserjet1300Grizzly" D [30/Jul/2012:09:27:30 +0200] [CGI] envp[28] = "SERVER_PROTOCOL=HTTP/1.1" D [30/Jul/2012:09:27:30 +0200] [CGI] envp[29] = "HTTP_COOKIE=org.cups.sid=ed2889ba7b4d791679d27e5060d9d99d" D [30/Jul/2012:09:27:30 +0200] [CGI] envp[30] = "HTTP_USER_AGENT=Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/535.22+ (KHTML, like Gecko) Chromium/17.0.963.56 Chrome/17.0.963.56 Safari/535.22+ Epiphany/3.4.2" D [30/Jul/2012:09:27:30 +0200] [CGI] envp[31] = "HTTP_REFERER=http://localhost:631/printers/Laserjet1300Grizzly" D [30/Jul/2012:09:27:30 +0200] [CGI] envp[32] = "REQUEST_METHOD=GET" D [30/Jul/2012:09:27:30 +0200] [CGI] envp[33] = "QUERY_STRING=" D [30/Jul/2012:09:27:30 +0200] [CGI] Started /usr/libexec/cups/cgi-bin/printers.cgi (PID 24212) I [30/Jul/2012:09:27:30 +0200] [Client 16] Started "/usr/libexec/cups/cgi-bin/printers.cgi" (pid=24212) D [30/Jul/2012:09:27:30 +0200] [Client 16] file=15 D [30/Jul/2012:09:27:30 +0200] [CGI] org.cups.sid cookie is "ed2889ba7b4d791679d27e5060d9d99d" D [30/Jul/2012:09:27:30 +0200] [CGI] cgiSetVariable: SECTION="printers" D [30/Jul/2012:09:27:30 +0200] [CGI] cgiSetVariable: REFRESH_PAGE="" D [30/Jul/2012:09:27:30 +0200] [CGI] cgiSetVariable: PRINTER_NAME="Laserjet1300Grizzly" D [30/Jul/2012:09:27:30 +0200] [Client 17] Accepted from localhost (Domain) D [30/Jul/2012:09:27:30 +0200] [Client 17] POST / HTTP/1.1 D [30/Jul/2012:09:27:30 +0200] cupsdSetBusyState: newbusy="Active clients and printing jobs", busy="Active clients and printing jobs" D [30/Jul/2012:09:27:30 +0200] [Client 17] No authentication data provided. D [30/Jul/2012:09:27:30 +0200] [Client 17] 2.0 CUPS-Get-Default 1 D [30/Jul/2012:09:27:30 +0200] CUPS-Get-Default D [30/Jul/2012:09:27:30 +0200] Returning IPP successful-ok for CUPS-Get-Default (no URI) from localhost D [30/Jul/2012:09:27:30 +0200] cupsdSetBusyState: newbusy="Active clients and printing jobs", busy="Active clients and printing jobs" D [30/Jul/2012:09:27:30 +0200] [CGI] cgiSetVariable: DEFAULT_NAME="Laserjet1300Grizzly" D [30/Jul/2012:09:27:30 +0200] [CGI] cgiSetVariable: DEFAULT_URI="/printers/Laserjet1300Grizzly" D [30/Jul/2012:09:27:30 +0200] [CGI] show_printer(http=0x7f48f12963f0, printer="Laserjet1300Grizzly") D [30/Jul/2012:09:27:30 +0200] [Client 17] POST / HTTP/1.1 D [30/Jul/2012:09:27:30 +0200] cupsdSetBusyState: newbusy="Active clients and printing jobs", busy="Active clients and printing jobs" D [30/Jul/2012:09:27:30 +0200] [Client 17] No authentication data provided. D [30/Jul/2012:09:27:30 +0200] [Client 17] 2.0 Get-Printer-Attributes 2 D [30/Jul/2012:09:27:30 +0200] Get-Printer-Attributes ipp://localhost/printers/Laserjet1300Grizzly D [30/Jul/2012:09:27:30 +0200] Returning IPP successful-ok for Get-Printer-Attributes (ipp://localhost/printers/Laserjet1300Grizzly) from localhost D [30/Jul/2012:09:27:30 +0200] cupsdSetBusyState: newbusy="Active clients and printing jobs", busy="Active clients and printing jobs" D [30/Jul/2012:09:27:30 +0200] [CGI] cgiSetVariable: SERVER_NAME="localhost" D [30/Jul/2012:09:27:30 +0200] [CGI] cgiSetVariable: CUPS_VERSION="CUPS v1.6.0" D [30/Jul/2012:09:27:30 +0200] [CGI] cgiSetVariable: SERVER_NAME="localhost" D [30/Jul/2012:09:27:30 +0200] [CGI] cgiSetVariable: CUPS_VERSION="CUPS v1.6.0" D [30/Jul/2012:09:27:30 +0200] [CGI] cgiSetArray: printer_is_accepting_jobs[0]="1" D [30/Jul/2012:09:27:30 +0200] [CGI] cgiSetArray: printer_is_shared[0]="1" D [30/Jul/2012:09:27:30 +0200] [CGI] cgiSetArray: printer_state[0]="4" D [30/Jul/2012:09:27:30 +0200] [CGI] cgiSetArray: admin_uri[0]="/admin/" D [30/Jul/2012:09:27:30 +0200] [CGI] cgiSetArray: printer_uri_supported[0]="/printers/Laserjet1300Grizzly" D [30/Jul/2012:09:27:30 +0200] [CGI] cgiSetArray: printer_name[0]="Laserjet1300Grizzly" D [30/Jul/2012:09:27:30 +0200] [CGI] cgiSetArray: printer_location[0]="Parkettzimmer" D [30/Jul/2012:09:27:30 +0200] [CGI] cgiSetArray: printer_info[0]="Laserjet 1300 at Parallel Port of Grizzly" D [30/Jul/2012:09:27:30 +0200] [CGI] cgiSetArray: job_sheets_default[0]="none, none" D [30/Jul/2012:09:27:30 +0200] [CGI] cgiSetArray: device_uri[0]="parallel:/dev/lp0" D [30/Jul/2012:09:27:30 +0200] [CGI] cgiSetArray: color_supported[0]="0" D [30/Jul/2012:09:27:30 +0200] [CGI] cgiSetArray: printer_make_and_model[0]="HP LaserJet 1300 Series Postscript (recommended)" D [30/Jul/2012:09:27:30 +0200] [CGI] cgiSetArray: media_default[0]="iso_a4_210x297mm" D [30/Jul/2012:09:27:30 +0200] [CGI] cgiSetArray: sides_supported[0]="one-sided" D [30/Jul/2012:09:27:30 +0200] [CGI] cgiSetArray: sides_default[0]="one-sided" D [30/Jul/2012:09:27:30 +0200] [CGI] cgiSetArray: printer_commands[0]="AutoConfigure, Clean, PrintSelfTestPage" D [30/Jul/2012:09:27:30 +0200] [CGI] cgiSetArray: server_is_sharing_printers[0]="0" D [30/Jul/2012:09:27:30 +0200] [CGI] cgiSetVariable: refresh_page="10;URL=/printers/Laserjet1300Grizzly" D [30/Jul/2012:09:27:30 +0200] [CGI] cgiSetVariable: TITLE="Laserjet1300Grizzly" D [30/Jul/2012:09:27:30 +0200] [CGI] cgiSetVariable: SERVER_NAME="localhost" D [30/Jul/2012:09:27:30 +0200] [CGI] cgiSetVariable: CUPS_VERSION="CUPS v1.6.0" D [30/Jul/2012:09:27:30 +0200] Script header: Content-Type: text/html;charset=utf-8 D [30/Jul/2012:09:27:30 +0200] Script header: D [30/Jul/2012:09:27:30 +0200] [CGI] Regular expression ".*Clean.*" D [30/Jul/2012:09:27:30 +0200] [CGI] matches[0].rm_so=0 D [30/Jul/2012:09:27:30 +0200] [CGI] matches[1].rm_so=-1 D [30/Jul/2012:09:27:30 +0200] [CGI] Regular expression ".*PrintSelfTestPage.*" D [30/Jul/2012:09:27:30 +0200] [CGI] matches[0].rm_so=0 D [30/Jul/2012:09:27:30 +0200] [CGI] matches[1].rm_so=-1 D [30/Jul/2012:09:27:30 +0200] [Client 17] POST / HTTP/1.1 D [30/Jul/2012:09:27:30 +0200] cupsdSetBusyState: newbusy="Active clients and printing jobs", busy="Active clients and printing jobs" D [30/Jul/2012:09:27:30 +0200] [Client 17] No authentication data provided. D [30/Jul/2012:09:27:30 +0200] [Client 17] 2.0 Get-Jobs 3 D [30/Jul/2012:09:27:30 +0200] Get-Jobs ipp://localhost:631/printers/Laserjet1300Grizzly D [30/Jul/2012:09:27:30 +0200] Returning IPP successful-ok for Get-Jobs (ipp://localhost:631/printers/Laserjet1300Grizzly) from localhost D [30/Jul/2012:09:27:30 +0200] cupsdSetBusyState: newbusy="Active clients and printing jobs", busy="Active clients and printing jobs" D [30/Jul/2012:09:27:30 +0200] [CGI] cgiClearVariables called. D [30/Jul/2012:09:27:30 +0200] [CGI] cgiSetVariable: ORDER="asc" D [30/Jul/2012:09:27:30 +0200] [CGI] cgiSetVariable: SECTION="printers" D [30/Jul/2012:09:27:30 +0200] [CGI] cgiSetVariable: TOTAL="1" D [30/Jul/2012:09:27:30 +0200] [CGI] cgiSetVariable: SERVER_NAME="localhost" D [30/Jul/2012:09:27:30 +0200] [CGI] cgiSetVariable: CUPS_VERSION="CUPS v1.6.0" D [30/Jul/2012:09:27:30 +0200] [CGI] cgiSetArray: job_printer_name[0]="Laserjet1300Grizzly" D [30/Jul/2012:09:27:30 +0200] [CGI] cgiSetArray: job_printer_uri[0]="/printers/Laserjet1300Grizzly" D [30/Jul/2012:09:27:30 +0200] [CGI] cgiSetArray: job_originating_user_name[0]="anonymous" ... Reproducible: Always
for me nothing shows in the logs for printing a self test page .. printing a "test page" gives some thing but not the standard cups test page .. it starts with: #PDF-BANNER Template-default-testpage.pdf Show-printer-name printer-info printer-location printer-make-and-model printer-driver-name printer-driver-version paper-size imageable-area job-id options time-at-creation time-at-processing So the page ends looks like it is printing the instructions to make the page instead of the page itself .. in addition after the initial cups page at localhost:631 in english i get either " chinese style hieorgyphics or boxes with numbers in them instead of the regular tab labels to select between home/administration/classes/online help/jobs/printers etc. the search help box at the end appears normal .. all this suggests that the cups web interface code has been munged in someway so it no longer works properly I add this extra info because I think the problems are related .. to the same root cause regular printing seems to work okay but I have not tried adding or removing a printer .. I suspect this may also not work properly .. and I'd like to keep my printers working ..
stranger still .. a reboot got rid of the "test page" anomoly .. it now works .. self test page .. debug error log now turned on .. similar result to yours .. lots of messages no additional info so I omit .. printer self test does not happen I noticed the other bugs on the tabs errors are fix in version 1.6.1 so they are not the same error .. sorry for the extra noise ..
Created attachment 319756 [details] /var/spool/cups/d00084-001 cups command string file
I have been trying to add another attachment file which contains the actual commands sent to the printer (also found in the /var/spool/cups directory) c00084 but for some reason it will not submit .. i'll try later
Created attachment 319758 [details] c00084 has control strings in it ... but can be opened with some editors this is the file sent to the printer/printer driver
Below should be the relevent eror log portion for the files attached above .. note .. snagged them before they were autodeleted (1 day lag) D [30/Jul/2012:14:25:12 -0400] Script header: Content-Type: text/html;charset=utf-8 D [30/Jul/2012:14:25:12 -0400] Script header: D [30/Jul/2012:14:25:12 -0400] [CGI] Regular expression ".*Clean.*" D [30/Jul/2012:14:25:12 -0400] [CGI] matches[0].rm_so=0 D [30/Jul/2012:14:25:12 -0400] [CGI] matches[1].rm_so=-1 D [30/Jul/2012:14:25:12 -0400] [CGI] Regular expression ".*PrintSelfTestPage.*" D [30/Jul/2012:14:25:12 -0400] [CGI] matches[0].rm_so=0 D [30/Jul/2012:14:25:12 -0400] [CGI] matches[1].rm_so=-1 D [30/Jul/2012:14:25:12 -0400] [Client 16] POST / HTTP/1.1 D [30/Jul/2012:14:25:12 -0400] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files" D [30/Jul/2012:14:25:12 -0400] [Client 16] No authentication data provided. D [30/Jul/2012:14:25:12 -0400] [Client 16] 2.0 Get-Jobs 3 D [30/Jul/2012:14:25:12 -0400] Get-Jobs ipp://localhost:631/printers/DCP-7040 D [30/Jul/2012:14:25:12 -0400] Returning IPP successful-ok for Get-Jobs (ipp://localhost:631/printers/DCP-7040) from localhost D [30/Jul/2012:14:25:12 -0400] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files" D [30/Jul/2012:14:25:12 -0400] [CGI] cgiClearVariables called. D [30/Jul/2012:14:25:12 -0400] [CGI] cgiSetVariable: ORDER="asc" D [30/Jul/2012:14:25:12 -0400] [CGI] cgiSetVariable: SECTION="printers" D [30/Jul/2012:14:25:12 -0400] [CGI] cgiSetVariable: TOTAL="0" D [30/Jul/2012:14:25:12 -0400] [CGI] cgiSetVariable: PRINTER_NAME="DCP-7040" D [30/Jul/2012:14:25:12 -0400] [CGI] cgiSetVariable: PRINTER_URI_SUPPORTED="/printers/DCP-7040" D [30/Jul/2012:14:25:12 -0400] [CGI] cgiSetVariable: THISURL="/printers/DCP-7040" D [30/Jul/2012:14:25:12 -0400] [CGI] cgiSetVariable: SEARCH_DEST="DCP-7040" D [30/Jul/2012:14:25:12 -0400] [Client 16] HTTP_WAITING Closing on EOF D [30/Jul/2012:14:25:12 -0400] [Client 16] Closing connection. D [30/Jul/2012:14:25:12 -0400] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files" D [30/Jul/2012:14:25:12 -0400] PID 1357 (/usr/libexec/cups/cgi-bin/printers.cgi) exited with no errors. D [30/Jul/2012:14:25:12 -0400] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files" D [30/Jul/2012:14:25:12 -0400] [Client 14] GET /cups.css HTTP/1.1 D [30/Jul/2012:14:25:12 -0400] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files" D [30/Jul/2012:14:25:12 -0400] [Client 14] Authorized as root using Basic D [30/Jul/2012:14:25:12 -0400] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files" D [30/Jul/2012:14:25:12 -0400] [Client 15] Accepted from localhost:631 (IPv4) D [30/Jul/2012:14:25:12 -0400] [Client 16] Accepted from localhost:631 (IPv4) D [30/Jul/2012:14:25:12 -0400] [Client 15] GET /images/left.gif HTTP/1.1 D [30/Jul/2012:14:25:12 -0400] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files" D [30/Jul/2012:14:25:12 -0400] [Client 15] Authorized as root using Basic D [30/Jul/2012:14:25:12 -0400] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files" D [30/Jul/2012:14:25:12 -0400] [Client 16] GET /images/right.gif HTTP/1.1 D [30/Jul/2012:14:25:12 -0400] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files" D [30/Jul/2012:14:25:12 -0400] [Client 16] Authorized as root using Basic D [30/Jul/2012:14:25:12 -0400] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files" D [30/Jul/2012:14:25:12 -0400] [Client 14] GET /images/unsel.gif HTTP/1.1 D [30/Jul/2012:14:25:12 -0400] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files" D [30/Jul/2012:14:25:12 -0400] [Client 14] Authorized as root using Basic D [30/Jul/2012:14:25:12 -0400] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files" D [30/Jul/2012:14:25:12 -0400] [Client 15] GET /images/sel.gif HTTP/1.1 D [30/Jul/2012:14:25:12 -0400] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files" D [30/Jul/2012:14:25:12 -0400] [Client 15] Authorized as root using Basic D [30/Jul/2012:14:25:12 -0400] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files" I [30/Jul/2012:14:25:38 -0400] Saving job.cache... D [30/Jul/2012:14:25:38 -0400] cupsdSetBusyState: newbusy="Not busy", busy="Dirty files" D [30/Jul/2012:14:25:43 -0400] [Client 16] HTTP_WAITING Closing on EOF D [30/Jul/2012:14:25:43 -0400] [Client 16] Closing connection. D [30/Jul/2012:14:25:43 -0400] cupsdSetBusyState: newbusy="Not busy", busy="Not busy" D [30/Jul/2012:14:25:43 -0400] [Client 15] HTTP_WAITING Closing on EOF D [30/Jul/2012:14:25:43 -0400] [Client 15] Closing connection. D [30/Jul/2012:14:25:43 -0400] cupsdSetBusyState: newbusy="Not busy", busy="Not busy" D [30/Jul/2012:14:25:43 -0400] [Client 14] HTTP_WAITING Closing on EOF D [30/Jul/2012:14:25:43 -0400] [Client 14] Closing connection. D [30/Jul/2012:14:25:43 -0400] cupsdSetBusyState: newbusy="Not busy", busy="Not busy" D [30/Jul/2012:14:30:04 -0400] [Client 14] Accepted from localhost:631 (IPv4) D [30/Jul/2012:14:30:04 -0400] Report: clients=1 D [30/Jul/2012:14:30:04 -0400] Report: jobs=15 D [30/Jul/2012:14:30:04 -0400] Report: jobs-active=0 D [30/Jul/2012:14:30:04 -0400] Report: printers=1 D [30/Jul/2012:14:30:04 -0400] Report: stringpool-string-count=4645 D [30/Jul/2012:14:30:04 -0400] Report: stringpool-alloc-bytes=8712 D [30/Jul/2012:14:30:04 -0400] Report: stringpool-total-bytes=79600 D [30/Jul/2012:14:30:04 -0400] [Client 14] GET /admin HTTP/1.1 D [30/Jul/2012:14:30:04 -0400] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
Created attachment 319766 [details] job 84-error-log-fragment.txt as per name
comment 6 error.log fragment was incomplete .. only caught second header ..
Please try 1.6.1 ...
Sorry but cups-1.6.1 does not fix the self-test-page printing issue .. still does not print .. because of a weird interaction noticed earlier I did a complete reboot before testing this again. Sending a test page to the printer works .. flips to job queue .. prints and returns .. but the self test page never shows the job queue page although looking afterwards you see the entry .. in " Show Completed Jobs " but it never appears at the printer .. some process is skipped it appears and the printer never gets the page ..
question is the intermediate phase of printing now a pdf file? if so why does the self-test-page command generate a commandtops instruction instead of a commandtopdf ?? is this correct?
I can't print with cups-1.6.1 either. At 'wildcat' I made a fresh printer configuration. root@wildcat:/root(6)# egrep "<Printer|Dev" /etc/cups/printers.conf <Printer CANON_direct_irc2620c2ps_2nd_floor> DeviceURI ipp://10.101.18.57/ipp?version=1.1 Lpq shows that the printer queue is empty, but neither the Printer Test Page nor a PDF document is printed. In /var/log/cups/error_log I find: ... D [31/Jul/2012:15:25:17 +0200] [Job 2] Starting renderer with command: "/bin/cat - | sicgsfilter -MPS -NP -E1 -A1 -uanonymous -V"Test Page" -n1 " D [31/Jul/2012:15:25:17 +0200] [Job 2] Starting process "kid3" (generation 1) D [31/Jul/2012:15:25:17 +0200] [Job 2] Starting process "kid4" (generation 2) D [31/Jul/2012:15:25:17 +0200] [Job 2] Starting process "renderer" (generation 2) D [31/Jul/2012:15:25:17 +0200] [Job 2] JCL: 12345X@PJL D [31/Jul/2012:15:25:17 +0200] [Job 2] <job data> D [31/Jul/2012:15:25:17 +0200] [Job 2] /bin/bash: sicgsfilter: command not found D [31/Jul/2012:15:25:17 +0200] [Job 2] renderer exited with status 127 D [31/Jul/2012:15:25:17 +0200] [Job 2] PID 9546 (/usr/libexec/cups/filter/foomatic-rip) did not catch or ignore signal 13. D [31/Jul/2012:15:25:17 +0200] [Client 16] GET /printers/CANON_direct_irc2620c2ps_2nd_floor HTTP/1.1 ... D [31/Jul/2012:15:25:18 +0200] CUPS-Get-Default client-error-not-found: No default printer. ... D [31/Jul/2012:15:25:18 +0200] [Client 18] No authentication data provided. ... D [31/Jul/2012:15:25:18 +0200] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files" D [31/Jul/2012:15:25:18 +0200] [Client 15] No authentication data provided. D [31/Jul/2012:15:25:18 +0200] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files" D [31/Jul/2012:15:25:18 +0200] [Client 17] GET /images/unsel.gif HTTP/1.1 Also reboot of the system did not help. I just found that sicgsfilter is part of the Canon cque-de-1.0.9 package. At 'moose' I had the printers CANON_direct_irc2620c2ps, Canon_direct_irc2620c2ps_2OG and cque which worked more or less until cups-1.5.3. Now I am not able to print, neither with these old printers nor with the new CANON_direct_irc2620c2ps_ipp-1.1_2nd_floor: root@moose:/usr/local/portage/app-text(84)# egrep "Default|<Printer|Dev" /etc/cups/printers.conf <DefaultPrinter CANON_direct_irc2620c2ps> DeviceURI ipp://10.101.18.57/ipp/ <Printer Canon_direct_irc2620c2ps_2OG> DeviceURI ipp://10.101.18.58/ipp/ <Printer CANON_direct_irc2620c2ps_ipp1.1_2nd_floor> DeviceURI ipp://10.101.18.57/ipp?version=1.1 <Printer cque> DeviceURI ipp://10.101.18.57/ipp/631 <Printer hp3005n_HP_uri> DeviceURI hp:/net/HP_LaserJet_P3005?ip=192.168.2.220 <Printer hplj_p3005n> DeviceURI ipp://192.168.2.220/ipp/ The cups web interface says for cque and CANON_direct_irc2620c2ps "The printer does not support IPP/2.0, trying IPP/1.1." and for CANON_direct_irc2620c2ps_ipp1.1_2nd_floor "Connected to printer." but nothing is printed. I restarted cups, but I did not reboot 'moose'. In /var/log/cups/error_log I find also the "No authentication data provided" lines but no other suspicious lines: D [31/Jul/2012:17:00:46 +0200] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Printing jobs and dirty files" D [31/Jul/2012:17:00:46 +0200] [Client 20] No authentication data provided. D [31/Jul/2012:17:00:46 +0200] [Client 20] 2.0 CUPS-Get-Default 5131
Now I still get an overflow of /var/spool/cups/tmp: root@moose:/root(28)# du -s /var/spool/cups/tmp 1715804 /var/spool/cups/tmp root@moose:/root(32)# du -s /var/spool/cups/tmp/* | wc 1099 2198 43870 1099 files, all with timestamp of today. And I tried to print about five documents.
root@moose:/root(34)# ll -t /var/spool/cups/tmp | tail -rw------- 1 lp lp 5136296 Jul 31 15:29 foomatic-avPfOg -rw------- 1 lp lp 168362 Jul 31 15:29 foomatic-hVV9n7 -rw------- 1 lp lp 5136296 Jul 31 15:29 foomatic-K5dnZ9 -rw------- 1 lp lp 168362 Jul 31 15:29 foomatic-jPHpw9 -rw------- 1 lp lp 5136296 Jul 31 15:29 foomatic-hcI4lN -rw------- 1 lp lp 168362 Jul 31 15:28 foomatic-KDZWCQ -rw------- 1 lp lp 168362 Jul 31 15:28 foomatic-UIyqKZ -rw------- 1 lp lp 168362 Jul 31 15:28 foomatic-eYUkm2 -rw------- 1 lp lp 168362 Jul 31 15:27 foomatic-9IWyw6 -rw------- 1 lp lp 168362 Jul 31 15:27 foomatic-pmVsN2
I have not had any trouble printing .. except for the self-test-page .. did you by chance upgrade to poppler-0.20.2-r1 and cups-filter-1.0.19-r1 as well as cups-1.6.1 ? they also contain some recommended fixes ..
After rebooting 'moose' I see at http://localhost:631/jobs/ Printer State cque stopped - "Filter failed" CANON_direct_irc2620c2ps stopped - "Filter failed" CANON_direct_irc2620c2ps_ip1.1_2nd_floor stopped - "Can't copy stdin to temporary file" and in /var/log/cups/error_log: D [31/Jul/2012:18:08:37 +0200] [Job 1538] Loading attributes... D [31/Jul/2012:18:08:37 +0200] Returning IPP successful-ok for Get-Jobs (ipp://localhost/) from localhost D [31/Jul/2012:18:08:37 +0200] cupsdSetBusyState: newbusy="Active clients", busy="Active clients" D [31/Jul/2012:18:08:37 +0200] [CGI] cgiClearVariables called. D [31/Jul/2012:18:08:37 +0200] [CGI] cgiSetVariable: ORDER="asc" D [31/Jul/2012:18:08:37 +0200] [CGI] cgiSetVariable: SECTION="jobs" D [31/Jul/2012:18:08:37 +0200] [CGI] cgiSetVariable: TOTAL="3" D [31/Jul/2012:18:08:37 +0200] [CGI] cgiSetVariable: SERVER_NAME="localhost" D [31/Jul/2012:18:08:37 +0200] [CGI] cgiSetVariable: CUPS_VERSION="CUPS v1.6.1" D [31/Jul/2012:18:08:37 +0200] [CGI] cgiSetArray: job_preserved[0]="1" D [31/Jul/2012:18:08:37 +0200] [CGI] cgiSetArray: job_printer_name[0]="cque" D [31/Jul/2012:18:08:37 +0200] [CGI] cgiSetArray: job_printer_uri[0]="/printers/cque" D [31/Jul/2012:18:08:37 +0200] [CGI] cgiSetArray: time_at_creation[0]="Mo 30 Jul 2012 18:01:32 CEST" D [31/Jul/2012:18:08:37 +0200] [CGI] cgiSetArray: time_at_processing[0]="Di 31 Jul 2012 17:38:26 CEST" D [31/Jul/2012:18:08:37 +0200] [CGI] cgiSetArray: time_at_completed[0]="novalue" D [31/Jul/2012:18:08:37 +0200] [CGI] cgiSetArray: job_id[0]="1536" D [31/Jul/2012:18:08:37 +0200] [CGI] cgiSetArray: job_state[0]="6" D [31/Jul/2012:18:08:37 +0200] [CGI] cgiSetArray: job_media_sheets_completed[0]="0" D [31/Jul/2012:18:08:37 +0200] [CGI] cgiSetArray: job_k_octets[0]="151" D [31/Jul/2012:18:08:37 +0200] [CGI] cgiSetArray: job_printer_state_message[0]="Filter failed" D [31/Jul/2012:18:08:37 +0200] [CGI] cgiSetVariable: SERVER_NAME="localhost" D [31/Jul/2012:18:08:37 +0200] [CGI] cgiSetVariable: CUPS_VERSION="CUPS v1.6.1" D [31/Jul/2012:18:08:37 +0200] [CGI] cgiSetArray: job_preserved[1]="1" D [31/Jul/2012:18:08:37 +0200] [CGI] cgiSetArray: job_printer_name[1]="CANON_direct_irc2620c2ps" D [31/Jul/2012:18:08:37 +0200] [CGI] cgiSetArray: job_printer_uri[1]="/printers/CANON_direct_irc2620c2ps" D [31/Jul/2012:18:08:37 +0200] [CGI] cgiSetArray: time_at_creation[1]="Di 31 Jul 2012 13:40:39 CEST" D [31/Jul/2012:18:08:37 +0200] [CGI] cgiSetArray: time_at_processing[1]="Di 31 Jul 2012 17:38:17 CEST" D [31/Jul/2012:18:08:37 +0200] [CGI] cgiSetArray: time_at_completed[1]="novalue" D [31/Jul/2012:18:08:37 +0200] [CGI] cgiSetArray: job_id[1]="1537" D [31/Jul/2012:18:08:37 +0200] [CGI] cgiSetArray: job_state[1]="6" D [31/Jul/2012:18:08:37 +0200] [CGI] cgiSetArray: job_media_sheets_completed[1]="0" D [31/Jul/2012:18:08:37 +0200] [CGI] cgiSetArray: job_k_octets[1]="5016" D [31/Jul/2012:18:08:37 +0200] [CGI] cgiSetArray: job_printer_state_message[1]="Filter failed" D [31/Jul/2012:18:08:37 +0200] [CGI] cgiSetVariable: SERVER_NAME="localhost" D [31/Jul/2012:18:08:37 +0200] [CGI] cgiSetVariable: CUPS_VERSION="CUPS v1.6.1" D [31/Jul/2012:18:08:37 +0200] [CGI] cgiSetArray: job_preserved[2]="1" D [31/Jul/2012:18:08:37 +0200] [CGI] cgiSetArray: job_printer_name[2]="CANON_direct_irc2620c2ps_ip1.1_2nd_floor" D [31/Jul/2012:18:08:37 +0200] [CGI] cgiSetArray: job_printer_uri[2]="/printers/CANON_direct_irc2620c2ps_ip1%2E1_2nd_floor" D [31/Jul/2012:18:08:37 +0200] [CGI] cgiSetArray: time_at_creation[2]="Di 31 Jul 2012 15:38:17 CEST" D [31/Jul/2012:18:08:37 +0200] [CGI] cgiSetArray: time_at_processing[2]="Di 31 Jul 2012 17:38:28 CEST" D [31/Jul/2012:18:08:37 +0200] [CGI] cgiSetArray: time_at_completed[2]="novalue" D [31/Jul/2012:18:08:37 +0200] [CGI] cgiSetArray: job_id[2]="1538" D [31/Jul/2012:18:08:37 +0200] [CGI] cgiSetArray: job_state[2]="6" D [31/Jul/2012:18:08:37 +0200] [CGI] cgiSetArray: job_media_sheets_completed[2]="0" D [31/Jul/2012:18:08:37 +0200] [CGI] cgiSetArray: job_k_octets[2]="1" D [31/Jul/2012:18:08:37 +0200] [CGI] cgiSetArray: job_printer_state_message[2]="Can't copy stdin to temporary file" D [31/Jul/2012:18:08:37 +0200] [CGI] cgiSetVariable: THISURL="/jobs/" D [31/Jul/2012:18:08:37 +0200] [Client 20] HTTP_WAITING Closing on EOF D [31/Jul/2012:18:08:37 +0200] [Client 20] Closing connection. D [31/Jul/2012:18:08:37 +0200] cupsdSetBusyState: newbusy="Active clients", busy="Active clients" D [31/Jul/2012:18:08:37 +0200] PID 10996 (/usr/libexec/cups/cgi-bin/jobs.cgi) exited with no errors. D [31/Jul/2012:18:08:37 +0200] cupsdSetBusyState: newbusy="Not busy", busy="Active clients" D [31/Jul/2012:18:08:53 +0200] [Client 17] HTTP_WAITING Closing on EOF D [31/Jul/2012:18:08:53 +0200] [Client 17] Closing connection. D [31/Jul/2012:18:08:53 +0200] cupsdSetBusyState: newbusy="Not busy", busy="Not busy" D [31/Jul/2012:18:08:53 +0200] [Client 16] HTTP_WAITING Closing on EOF And to Comment 6, I have all these packages installed: root@moose:/root(7)# genlop -t cups | tail -n 6 Mon Jul 30 18:15:57 2012 >>> net-print/cups-1.6.0 merge time: 1 minute and 9 seconds. Tue Jul 31 14:19:18 2012 >>> net-print/cups-1.6.1 merge time: 1 minute and 2 seconds. root@moose:/root(8)# genlop -t poppler | tail -n 6 Thu Jul 26 19:25:20 2012 >>> app-text/poppler-0.20.2 merge time: 47 seconds. Tue Jul 31 14:14:35 2012 >>> app-text/poppler-0.20.2-r1 merge time: 48 seconds. root@moose:/root(12)# genlop -t cups-filters | tail -n 6 Mon Jul 30 18:16:26 2012 >>> net-print/cups-filters-1.0.19 merge time: 29 seconds. Tue Jul 31 14:19:50 2012 >>> net-print/cups-filters-1.0.19-r1 merge time: 32 seconds.
On the next system printing of the Test Page fails with: root@grizzly:/root(14)# cat /var/log/cups/error_log D [30/Jul/2012:10:06:31 +0200] [CGI] cgiSetVariable: SECTION="printers" D [30/Jul/2012:10:06:31 +0200] [CGI] cgiSetVariable: TOTAL="1" D [30/Jul/2012:10:06:31 +0200] [CGI] cgiSetVariable: SERVER_NAME="localhost" D [30/Jul/2012:10:06:31 +0200] [CGI] cgiSetVariable: CUPS_VERSION="CUPS v1.6.0" D [30/Jul/2012:10:06:31 +0200] [CGI] cgiSetArray: job_printer_name[0]="Laserjet1300Grizzly" D [30/Jul/2012:10:06:31 +0200] [CGI] cgiSetArray: job_printer_uri[0]="/printers/Laserjet1300Grizzly" D [30/Jul/2012:10:06:31 +0200] [CGI] cgiSetArray: job_originating_user_name[0]="anonymous" D [30/Jul/2012:10:06:31 +0200] [CGI] cgiSetArray: job_name[0]="Print Self-Test Page" D [30/Jul/2012:10:06:31 +0200] [CGI] cgiSetArray: time_at_creation[0]="Mon 30 Jul 2012 09:06:53 AM CEST" D [30/Jul/2012:10:06:31 +0200] [CGI] cgiSetArray: time_at_processing[0]="Mon 30 Jul 2012 09:09:56 AM CEST" D [30/Jul/2012:10:06:31 +0200] [CGI] cgiSetArray: time_at_completed[0]="novalue" D [30/Jul/2012:10:06:31 +0200] [CGI] cgiSetArray: job_id[0]="2628" D [30/Jul/2012:10:06:31 +0200] [CGI] cgiSetArray: job_state[0]="5" D [30/Jul/2012:10:06:31 +0200] [CGI] cgiSetArray: job_media_sheets_completed[0]="0" D [30/Jul/2012:10:06:31 +0200] [CGI] cgiSetArray: job_k_octets[0]="1" D [30/Jul/2012:10:06:31 +0200] [CGI] cgiSetArray: job_printer_state_message[0]="" D [30/Jul/2012:10:06:31 +0200] [CGI] cgiSetVariable: PRINTER_NAME="Laserjet1300Grizzly" D [30/Jul/2012:10:06:31 +0200] [CGI] cgiSetVariable: PRINTER_URI_SUPPORTED="/printers/Laserjet1300Grizzly" D [30/Jul/2012:10:06:31 +0200] [CGI] cgiSetVariable: THISURL="/printers/Laserjet1300Grizzly" D [30/Jul/2012:10:06:31 +0200] [CGI] cgiSetVariable: SEARCH_DEST="Laserjet1300Grizzly" D [30/Jul/2012:10:06:31 +0200] [Client 17] HTTP_WAITING Closing on EOF D [30/Jul/2012:10:06:31 +0200] [Client 17] Closing connection. D [30/Jul/2012:10:06:31 +0200] cupsdSetBusyState: newbusy="Active clients and printing jobs", busy="Active clients and printing jobs" D [30/Jul/2012:10:06:31 +0200] PID 24752 (/usr/libexec/cups/cgi-bin/printers.cgi) exited with no errors. D [30/Jul/2012:10:06:31 +0200] cupsdSetBusyState: newbusy="Printing jobs", busy="Active clients and printing jobs" D [30/Jul/2012:10:06:31 +0200] [Client 16] Accepted from localhost:631 (IPv4) D [30/Jul/2012:10:06:31 +0200] [Client 16] GET /cups.css HTTP/1.1 D [30/Jul/2012:10:06:31 +0200] cupsdSetBusyState: newbusy="Active clients and printing jobs", busy="Printing jobs" D [30/Jul/2012:10:06:31 +0200] [Client 16] No authentication data provided. D [30/Jul/2012:10:06:31 +0200] cupsdSetBusyState: newbusy="Printing jobs", busy="Active clients and printing jobs" D [30/Jul/2012:10:06:31 +0200] [Client 16] HTTP_WAITING Closing on EOF D [30/Jul/2012:10:06:31 +0200] [Client 16] Closing connection. D [30/Jul/2012:10:06:31 +0200] cupsdSetBusyState: newbusy="Printing jobs", busy="Printing jobs" D [30/Jul/2012:10:06:31 +0200] [Client 16] Accepted from localhost:631 (IPv4) D [30/Jul/2012:10:06:31 +0200] [Client 17] Accepted from localhost:631 (IPv4) D [30/Jul/2012:10:06:31 +0200] [Client 18] Accepted from localhost:631 (IPv4) D [30/Jul/2012:10:06:31 +0200] [Client 16] GET /images/left.gif HTTP/1.1 D [30/Jul/2012:10:06:31 +0200] cupsdSetBusyState: newbusy="Active clients and printing jobs", busy="Printing jobs" D [30/Jul/2012:10:06:31 +0200] [Client 16] No authentication data provided. D [30/Jul/2012:10:06:31 +0200] cupsdSetBusyState: newbusy="Printing jobs", busy="Active clients and printing jobs" D [30/Jul/2012:10:06:31 +0200] [Client 17] GET /images/unsel.gif HTTP/1.1 D [30/Jul/2012:10:06:31 +0200] cupsdSetBusyState: newbusy="Active clients and printing jobs", busy="Printing jobs" D [30/Jul/2012:10:06:31 +0200] [Client 17] No authentication data provided. D [30/Jul/2012:10:06:31 +0200] cupsdSetBusyState: newbusy="Printing jobs", busy="Active clients and printing jobs" D [30/Jul/2012:10:06:31 +0200] [Client 18] GET /images/sel.gif HTTP/1.1 D [30/Jul/2012:10:06:31 +0200] cupsdSetBusyState: newbusy="Active clients and printing jobs", busy="Printing jobs" D [30/Jul/2012:10:06:31 +0200] [Client 18] No authentication data provided. D [30/Jul/2012:10:06:31 +0200] cupsdSetBusyState: newbusy="Printing jobs", busy="Active clients and printing jobs" D [30/Jul/2012:10:06:31 +0200] [Client 16] HTTP_WAITING Closing on EOF D [30/Jul/2012:10:06:31 +0200] [Client 16] Closing connection. D [30/Jul/2012:10:06:31 +0200] cupsdSetBusyState: newbusy="Printing jobs", busy="Printing jobs" D [30/Jul/2012:10:06:31 +0200] [Client 17] HTTP_WAITING Closing on EOF D [30/Jul/2012:10:06:31 +0200] [Client 17] Closing connection. D [30/Jul/2012:10:06:31 +0200] cupsdSetBusyState: newbusy="Printing jobs", busy="Printing jobs" D [30/Jul/2012:10:06:31 +0200] [Client 18] HTTP_WAITING Closing on EOF D [30/Jul/2012:10:06:31 +0200] [Client 18] Closing connection. D [30/Jul/2012:10:06:31 +0200] cupsdSetBusyState: newbusy="Printing jobs", busy="Printing jobs" D [30/Jul/2012:10:06:31 +0200] [Client 16] Accepted from localhost:631 (IPv4) D [30/Jul/2012:10:06:31 +0200] [Client 16] GET /images/right.gif HTTP/1.1 D [30/Jul/2012:10:06:31 +0200] cupsdSetBusyState: newbusy="Active clients and printing jobs", busy="Printing jobs" D [30/Jul/2012:10:06:31 +0200] [Client 16] No authentication data provided. D [30/Jul/2012:10:06:31 +0200] cupsdSetBusyState: newbusy="Printing jobs", busy="Active clients and printing jobs" D [30/Jul/2012:10:06:31 +0200] [Client 16] HTTP_WAITING Closing on EOF D [30/Jul/2012:10:06:31 +0200] [Client 16] Closing connection. D [30/Jul/2012:10:06:31 +0200] cupsdSetBusyState: newbusy="Printing jobs", busy="Printing jobs" I [30/Jul/2012:10:06:39 +0200] Scheduler shutting down normally. D [30/Jul/2012:10:06:39 +0200] Discarding unused server-stopped event... D [30/Jul/2012:10:06:39 +0200] [Client 15] Closing connection. D [30/Jul/2012:10:06:39 +0200] cupsdSetBusyState: newbusy="Printing jobs", busy="Printing jobs" D [30/Jul/2012:10:06:39 +0200] cupsdMarkDirty(---J-) D [30/Jul/2012:10:06:39 +0200] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs" D [30/Jul/2012:10:06:39 +0200] Discarding unused printer-state-changed event... D [30/Jul/2012:10:06:39 +0200] cupsdMarkDirty(---J-) D [30/Jul/2012:10:06:39 +0200] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files" D [30/Jul/2012:10:06:39 +0200] cupsdSetBusyState: newbusy="Dirty files", busy="Printing jobs and dirty files" I [30/Jul/2012:10:06:39 +0200] Saving job.cache... D [30/Jul/2012:10:06:39 +0200] [Job 2628] Unloading... E [30/Jul/2012:10:06:39 +0200] Filter "hpgltops" not found. W [30/Jul/2012:10:06:39 +0200] AddProfile failed: org.freedesktop.DBus.Error.UnknownMethod:No such interface `org.freedesktop.ColorManager' on object at path /org/freedesktop/ColorManager/devices/cups_Hp1300GrizzlyGutenprint W [30/Jul/2012:10:06:39 +0200] AddProfile failed: org.freedesktop.DBus.Error.UnknownMethod:No such interface `org.freedesktop.ColorManager' on object at path /org/freedesktop/ColorManager/devices/cups_Laserjet1300Grizzly E [30/Jul/2012:10:11:59 +0200] [Job 2628] Stopping unresponsive job. E [30/Jul/2012:13:17:05 +0200] [Job 2629] Stopping unresponsive job. E [01/Aug/2012:08:07:57 +0200] Filter "hpgltops" not found. W [01/Aug/2012:08:07:59 +0200] AddProfile failed: org.freedesktop.DBus.Error.UnknownMethod:No such interface `org.freedesktop.ColorManager' on object at path /org/freedesktop/ColorManager/devices/cups_Hp1300GrizzlyGutenprint W [01/Aug/2012:08:08:00 +0200] AddProfile failed: org.freedesktop.DBus.Error.UnknownMethod:No such interface `org.freedesktop.ColorManager' on object at path /org/freedesktop/ColorManager/devices/cups_Laserjet1300Grizzly E [01/Aug/2012:08:20:57 +0200] Filter "hpgltops" not found. W [01/Aug/2012:08:21:02 +0200] AddProfile failed: org.freedesktop.DBus.Error.UnknownMethod:No such interface `org.freedesktop.ColorManager' on object at path /org/freedesktop/ColorManager/devices/cups_Hp1300GrizzlyGutenprint W [01/Aug/2012:08:21:02 +0200] AddProfile failed: org.freedesktop.DBus.Error.UnknownMethod:No such interface `org.freedesktop.ColorManager' on object at path /org/freedesktop/ColorManager/devices/cups_Laserjet1300Grizzly E [01/Aug/2012:08:31:00 +0200] Filter "hpgltops" not found. W [01/Aug/2012:08:31:04 +0200] AddProfile failed: org.freedesktop.DBus.Error.UnknownMethod:No such interface `org.freedesktop.ColorManager' on object at path /org/freedesktop/ColorManager/devices/cups_Hp1300GrizzlyGutenprint W [01/Aug/2012:08:31:04 +0200] AddProfile failed: org.freedesktop.DBus.Error.UnknownMethod:No such interface `org.freedesktop.ColorManager' on object at path /org/freedesktop/ColorManager/devices/cups_Laserjet1300Grizzly Where is hpgltops? It was part of the older cups versions. Now it belongs neither to cups nor to cups-filters: root@grizzly:/root(16)# qlist cups | grep hpgltops root@grizzly:/root(17)# qlist cups-filters | grep hpgltops
After modifying Hp1300GrizzlyGutenprint and trying to the test page with this printer I get now: E [01/Aug/2012:10:12:28 +0200] [cups-driverd] Bad driver information file "/usr/share/cups/drv/cupsfilters.drv"! E [01/Aug/2012:10:12:29 +0200] [cups-driverd] Bad driver information file "/usr/share/ppd/DEC/DEC-LN03-ln03.ppd.gz.gz"! E [01/Aug/2012:10:12:29 +0200] [cups-driverd] Bad driver information file "/usr/share/ppd/IBM/IBM-Page_Printer_3112-Postscript.ppd.gz.gz"! E [01/Aug/2012:10:12:29 +0200] [cups-driverd] Bad driver information file "/usr/share/ppd/Oce/Oce-9050-oce9050.ppd.gz.gz"! E [01/Aug/2012:10:12:29 +0200] [cups-driverd] Bad driver information file "/usr/share/ppd/Oce/Oce-PPC3114PS-Postscript.ppd.gz.gz"! E [01/Aug/2012:10:12:29 +0200] [cups-driverd] Bad driver information file "/usr/share/ppd/Alps/Alps-MD-1500-ppmtocpva.ppd.gz.gz"! E [01/Aug/2012:10:12:29 +0200] [cups-driverd] Bad driver information file "/usr/share/ppd/Dymo/Dymo-CoStar-EL40-pbm2lwxl.ppd.gz.gz"! E [01/Aug/2012:10:12:29 +0200] [cups-driverd] Bad driver information file "/usr/share/ppd/Apollo/Apollo-P-2200-cdj550.ppd.gz.gz"! E [01/Aug/2012:10:12:29 +0200] [cups-driverd] Bad driver information file "/usr/share/ppd/Apollo/Apollo-P-1250-pcl3.ppd.gz.gz"! E [01/Aug/2012:10:12:29 +0200] [cups-driverd] Bad driver information file "/usr/share/ppd/Apollo/Apollo-P-1220_Barbie-pcl3.ppd.gz.gz"! E [01/Aug/2012:10:12:29 +0200] [cups-driverd] Bad driver information file "/usr/share/ppd/Hitachi/Hitachi-DDP_70_with_MicroPress-Postscript.ppd.gz.gz"! E [01/Aug/2012:10:12:29 +0200] [cups-driverd] Bad driver information file "/usr/share/ppd/Compaq/Compaq-IJ1200-drv_z42.ppd.gz.gz"! E [01/Aug/2012:10:12:29 +0200] [cups-driverd] Bad driver information file "/usr/share/ppd/Compaq/Compaq-IJ900-pbm2l7k.ppd.gz.gz"! E [01/Aug/2012:10:12:29 +0200] [cups-driverd] Bad driver information file "/usr/share/ppd/Compaq/Compaq-IJ900-lex5700.ppd.gz.gz"! E [01/Aug/2012:10:12:29 +0200] [cups-driverd] Bad driver information file "/usr/share/ppd/Compaq/Compaq-IJ900-lxm5700m.ppd.gz.gz"! E [01/Aug/2012:10:12:29 +0200] [cups-driverd] Bad driver information file "/usr/share/ppd/Okidata/Okidata-Okipage_8w-oki4drv.ppd.gz.gz"! E [01/Aug/2012:10:12:29 +0200] [cups-driverd] Bad driver information file "/usr/share/ppd/Gestetner/Gestetner-2212-pxlmono.ppd.gz.gz"! E [01/Aug/2012:10:12:29 +0200] [cups-driverd] Bad driver information file "/usr/share/ppd/Gestetner/Gestetner-MP6500_DSm765-Postscript.ppd.gz.gz"! E [01/Aug/2012:10:12:29 +0200] [cups-driverd] Bad driver information file "/usr/share/ppd/Apple/Apple-StyleWriter_I-lpstyl.ppd.gz.gz"! E [01/Aug/2012:10:12:29 +0200] [cups-driverd] Bad driver information file "/usr/share/ppd/Epson/Epson-Stylus_Color_1500-mj500c.ppd.gz.gz"! E [01/Aug/2012:10:12:29 +0200] [cups-driverd] Bad driver information file "/usr/share/ppd/Ricoh/Ricoh-Aficio_SP_8100DN-Postscript.ppd.gz.gz"! E [01/Aug/2012:10:12:29 +0200] [cups-driverd] Bad driver information file "/usr/share/ppd/Ricoh/Ricoh-Aficio_MP_2550B-pxlmono.ppd.gz.gz"! E [01/Aug/2012:10:12:29 +0200] [cups-driverd] Bad driver information file "/usr/share/ppd/Ricoh/Ricoh-Aficio_CL7100-Postscript.ppd.gz.gz"! E [01/Aug/2012:10:12:29 +0200] [cups-driverd] Bad driver information file "/usr/share/ppd/Sharp/Sharp-AR-161-ljet4.ppd.gz.gz"! E [01/Aug/2012:10:12:29 +0200] [cups-driverd] Bad driver information file "/usr/share/ppd/Sharp/Sharp-AJ-1800-pcl3.ppd.gz.gz"! E [01/Aug/2012:10:12:29 +0200] [cups-driverd] Bad driver information file "/usr/share/ppd/Tally/Tally-MT908-ljet3.ppd.gz.gz"! E [01/Aug/2012:10:12:29 +0200] [cups-driverd] Bad driver information file "/usr/share/ppd/Xerox/Xerox-Document_Centre_400-ljet4.ppd.gz.gz"! E [01/Aug/2012:10:12:29 +0200] [cups-driverd] Bad driver information file "/usr/share/ppd/Lanier/Lanier-MP_3350_LD433-Postscript.ppd.gz.gz"! E [01/Aug/2012:10:12:29 +0200] [cups-driverd] Bad driver information file "/usr/share/ppd/Lanier/Lanier-MP_3500_LD335-pxlmono.ppd.gz.gz"! E [01/Aug/2012:10:12:29 +0200] [cups-driverd] Bad driver information file "/usr/share/ppd/Pentax/Pentax-PocketJet_200-pentaxpj.ppd.gz.gz"! E [01/Aug/2012:10:12:29 +0200] [cups-driverd] Bad driver information file "/usr/share/ppd/Infotec/Infotec-IPC_2525DN-Postscript.ppd.gz.gz"! E [01/Aug/2012:10:12:29 +0200] [cups-driverd] Bad driver information file "/usr/share/ppd/Infotec/Infotec-MP_2550-pxlmono.ppd.gz.gz"! E [01/Aug/2012:10:12:29 +0200] [cups-driverd] Bad driver information file "/usr/share/ppd/Infotec/Infotec-IP_280-Postscript.ppd.gz.gz"! E [01/Aug/2012:10:12:29 +0200] [cups-driverd] Bad driver information file "/usr/share/ppd/Infotec/Infotec-4353_MF-pxlmono.ppd.gz.gz"! E [01/Aug/2012:10:12:29 +0200] [cups-driverd] Bad driver information file "/usr/share/ppd/Infotec/Infotec-IS_2325-pxlmono.ppd.gz.gz"! E [01/Aug/2012:10:12:29 +0200] [cups-driverd] Bad driver information file "/usr/share/ppd/Infotec/Infotec-ISC_1032c-pxlmono.ppd.gz.gz"! E [01/Aug/2012:10:12:29 +0200] [cups-driverd] Bad driver information file "/usr/share/ppd/Infotec/Infotec-IS_2015-Postscript.ppd.gz.gz"! E [01/Aug/2012:10:12:29 +0200] [cups-driverd] Bad driver information file "/usr/share/ppd/Citizen/Citizen-printiva1700-ppmtomd.ppd.gz.gz"! E [01/Aug/2012:10:12:29 +0200] [cups-driverd] Bad driver information file "/usr/share/ppd/Generic/Generic-ESC_P_Dot_Matrix_Printer-lq850.ppd.gz.gz"! E [01/Aug/2012:10:12:29 +0200] [cups-driverd] Bad driver information file "/usr/share/ppd/Generic/Generic-PCL_5e_Printer-lj4dith.ppd.gz.gz"! E [01/Aug/2012:10:12:29 +0200] [cups-driverd] Bad driver information file "/usr/share/ppd/Generic/Generic-PCL_5e_Printer-ljet4d.ppd.gz.gz.gz"! E [01/Aug/2012:10:12:29 +0200] [cups-driverd] Bad driver information file "/usr/share/ppd/Generic/Generic-PCL_5c_Printer-cljet5.ppd.gz.gz"! E [01/Aug/2012:10:12:29 +0200] [cups-driverd] Bad driver information file "/usr/share/ppd/Generic/Generic-ESC_P_Dot_Matrix_Printer-epson.ppd.gz.gz"! E [01/Aug/2012:10:12:29 +0200] [cups-driverd] Bad driver information file "/usr/share/ppd/Toshiba/Toshiba-e-Studio_200L-Postscript.ppd.gz.gz"! W [01/Aug/2012:10:13:02 +0200] CreateProfile failed: org.freedesktop.ColorManager.AlreadyExists:profile id 'Hp1300GrizzlyGutenprint-Gray..' already exists W [01/Aug/2012:10:13:02 +0200] CreateDevice failed: org.freedesktop.ColorManager.AlreadyExists:device id 'cups-Hp1300GrizzlyGutenprint' already exists E [01/Aug/2012:10:16:18 +0200] [Job 2630] Stopping unresponsive job.
Created attachment 319968 [details] printers.conf at grizzly
I rebooted grizzly again and tried to print three pages of a pdf file to the local printer Laserjet1300Grizzly at the parallel port and with LogLevel warn. Not any line is written to /var/log/cups/error_log. The last lines written 30 minutes ago are: D [01/Aug/2012:14:37:52 +0200] cupsdMarkDirty(---J-) D [01/Aug/2012:14:37:52 +0200] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files" D [01/Aug/2012:14:37:52 +0200] cupsdSetBusyState: newbusy="Dirty files", busy="Printing jobs and dirty files" I [01/Aug/2012:14:37:52 +0200] Saving job.cache... D [01/Aug/2012:14:37:53 +0200] [Job 2633] Unloading... E [01/Aug/2012:14:40:04 +0200] Filter "hpgltops" not found. W [01/Aug/2012:14:40:08 +0200] AddProfile failed: org.freedesktop.DBus.Error.UnknownMethod:No such interface `org.freedesktop.ColorManager' on object at path /org/freedesktop/ColorManager/devices/cups_Hp1300GrizzlyGutenprint W [01/Aug/2012:14:40:08 +0200] AddProfile failed: org.freedesktop.DBus.Error.UnknownMethod:No such interface `org.freedesktop.ColorManager' on object at path /org/freedesktop/ColorManager/devices/cups_Laserjet1300Grizzly The Web-Interface says: ▼ ID ▼ State Laserjet1300Grizzly-2635 processing since Wed 01 Aug 2012 02:56:47 PM CEST After ten minutes the first page is printed, after 17 minutes the second page is printed. The load average is almost zero: rose@grizzly:/home/rose(14)$ uptime 15:14:35 up 35 min, 1 user, load average: 0.00, 0.05, 0.12 Htop shows me that the print job: parallel:/dev/lp0 2635 rose usb_wikipedia.pdf uses sometimes 97% of CPU. Now after 26 minutes the third page is printed. Something does not work as expected.
Have had mostly non-printing issues with CUPS this past week. Most recently... This laptop was upgraded from: net-print/cups-1.6.1; net-print/cups-filters-1.0.19-r1; app-text/poppler-0.20.2-r1 to net-print/cups-1.6.1; net-print/cups-filters-1.0.20; app-text/poppler-0.20.2-r1 and does not print properly. Also app-text/poppler-0.20.2-r1 and net-print/cups-1.6.1 were rebuilt. It printed a file from Inkscape fine with cups-filters-1.0.19-r1, but after the upgrade and rebooting laptop, restarting CUPS and the printer, it won't print the same file from Inkscape. It also won't Print Test Page from the Printers > Maintenance of the CUPS interface. Here's a screenshot of those attempts: http://ompldr.org/vZXo1bQ mingdao@laptop ~ $ less /var/log/cups/error_log <snip all but Aug 3> W [03/Aug/2012:14:19:04 -0500] CreateProfile failed: org.freedesktop.DBus.Error.ServiceUnknown:The name org.freedesktop.ColorManager was not provided by any .service files W [03/Aug/2012:14:19:04 -0500] CreateProfile failed: org.freedesktop.DBus.Error.ServiceUnknown:The name org.freedesktop.ColorManager was not provided by any .service files W [03/Aug/2012:14:19:04 -0500] CreateDevice failed: org.freedesktop.DBus.Error.ServiceUnknown:The name org.freedesktop.ColorManager was not provided by any .service files E [03/Aug/2012:14:19:04 -0500] Unable to open listen socket for address [v1.::1]:631 - Address family not supported by protocol. W [03/Aug/2012:15:01:14 -0500] CreateProfile failed: org.freedesktop.DBus.Error.ServiceUnknown:The name org.freedesktop.ColorManager was not provided by any .service files W [03/Aug/2012:15:01:14 -0500] CreateProfile failed: org.freedesktop.DBus.Error.ServiceUnknown:The name org.freedesktop.ColorManager was not provided by any .service files W [03/Aug/2012:15:01:14 -0500] CreateDevice failed: org.freedesktop.DBus.Error.ServiceUnknown:The name org.freedesktop.ColorManager was not provided by any .service files E [03/Aug/2012:15:01:14 -0500] Unable to open listen socket for address [v1.::1]:631 - Address family not supported by protocol. mingdao@laptop ~ $ less /var/log/cups/access_log <snip all but Aug 3> localhost - - [03/Aug/2012:14:08:54 -0500] "POST /printers/HP_Officejet_Pro_8500_A910 HTTP/1.1" 200 1119449 Print-Job successful-ok localhost - - [03/Aug/2012:14:12:21 -0500] "POST /admin/ HTTP/1.1" 200 108 - - localhost - - [03/Aug/2012:14:12:21 -0500] "POST /admin/ HTTP/1.1" 200 10482 - - localhost - - [03/Aug/2012:14:12:23 -0500] "POST /admin HTTP/1.1" 200 374 - - localhost - - [03/Aug/2012:14:12:23 -0500] "POST /admin/ HTTP/1.1" 401 31864 CUPS-Add-Modify-Printer successful-ok localhost - - [03/Aug/2012:14:12:23 -0500] "POST /admin HTTP/1.1" 401 374 - - localhost - - [03/Aug/2012:14:12:23 -0500] "POST /admin HTTP/1.1" 200 374 - - localhost - root [03/Aug/2012:14:12:23 -0500] "POST /admin HTTP/1.1" 200 374 - - localhost - - [03/Aug/2012:14:12:23 -0500] "POST /admin/ HTTP/1.1" 401 31864 CUPS-Add-Modify-Printer successful-ok localhost - root [03/Aug/2012:14:12:23 -0500] "POST /admin/ HTTP/1.1" 200 31864 CUPS-Add-Modify-Printer successful-ok localhost - root [03/Aug/2012:14:12:23 -0500] "POST /admin HTTP/1.1" 200 2410 - - localhost - - [03/Aug/2012:14:12:27 -0500] "POST /printers/HP_Officejet_Pro_8500_A910 HTTP/1.1" 200 431 Print-Job successful-ok localhost - - [03/Aug/2012:14:51:00 -0500] "POST /printers/HP_Officejet_Pro_8500_A910 HTTP/1.1" 200 1119449 Print-Job successful-ok localhost - - [03/Aug/2012:14:59:39 -0500] "POST /jobs HTTP/1.1" 401 141 Cancel-Job successful-ok localhost - - [03/Aug/2012:14:59:40 -0500] "POST /jobs HTTP/1.1" 200 140 Cancel-Job successful-ok localhost - - [03/Aug/2012:15:09:09 -0500] "GET /admin/log/error_log HTTP/1.1" 200 159288 - - localhost - - [03/Aug/2012:15:09:34 -0500] "GET /admin/log/page_log HTTP/1.1" 200 74662 - - localhost - - [03/Aug/2012:15:12:27 -0500] "POST /printers/HP_Officejet_Pro_8500_A910 HTTP/1.1" 200 1119449 Print-Job successful-ok localhost - - [03/Aug/2012:15:16:27 -0500] "POST /printers/HP_Officejet_Pro_8500_A910 HTTP/1.1" 200 402 Print-Job successful-ok mingdao@laptop ~ $ less /var/log/cups/page_log <snip all but Aug 3> HP_Officejet_Pro_8500_A910 mingdao 135 [03/Aug/2012:14:09:04 -0500] 1 1 - localhost Print Fall-2012-schedule.svg - - HP_Officejet_Pro_8500_A910 mingdao 135 [03/Aug/2012:14:09:34 -0500] 2 1 - localhost Print Fall-2012-schedule.svg - - HP_Officejet_Pro_8500_A910 mingdao 135 [03/Aug/2012:14:09:34 -0500] 3 1 - localhost Print Fall-2012-schedule.svg - - HP_Officejet_Pro_8500_A910 mingdao 135 [03/Aug/2012:14:10:00 -0500] total 3 - localhost Print Fall-2012-schedule.svg - - HP_Officejet_Pro_8500_A910 root 136 [03/Aug/2012:14:12:27 -0500] 1 1 - localhost Test Page - - HP_Officejet_Pro_8500_A910 root 136 [03/Aug/2012:14:12:38 -0500] total 1 - localhost Test Page - -
Sorry for above ... noticed it's 1.6.0 and not 1.6.1 bug report ... adding to 1.6.1
Everyone, please dont mix up different issues here. * "Printing Test Page fails" seems to have been some upgrade fluke, see comment 2. I think we can forget this. * "Printing Self-Test Page fails": Some printers just dont support this. Quoting from askubuntu.com: A self-test page is a simple command sent to the printer to instruct it to do exactly that - most printers will print out a sheet showing the expected life of their ink cartridges/drum, toner, how many pages they've printed in their life and so on. Having said that, Self-Test Page doesn't work on either my Brother HL-2030 or my HP 2605dn via CUPS. The 2605dn prints "PrintSelfTestPage" and the HL-2030 does nothing! So, I guess this is not really a CUPS bug, more like a new CUPS feature that is not supported by all printers. * All printing fails- Juergen, please make a new bug for this. We already have enough confusion here.
