Okay, I set my LogLevel to debug. As I said, the print job starts going
to the printer, the printer starts processing, then the job clears the
queue and the printer goes back to Ready status without printing
anything.
Now, this first listing is of error_log when I tried and failed to print
a normal print job. The next one is of error_log when I successfully
printed a test page.
The key difference I see: The test page went to a tmpprinter
representation of the printer, while the regular print job went to the
original printer representation.
So, here's the output from a non-working print job:
D [06/Apr/2004:08:32:35 -0700] LoadAllJobs: Loading attributes for job
1...
D [06/Apr/2004:08:32:35 -0700] LoadAllJobs: Loading attributes for job
2...
D [06/Apr/2004:08:32:35 -0700] LoadAllJobs: Loading attributes for job
3...
D [06/Apr/2004:08:32:35 -0700] LoadAllJobs: Loading attributes for job
4...
D [06/Apr/2004:08:32:35 -0700] LoadAllJobs: Loading attributes for job
5...
D [06/Apr/2004:08:32:35 -0700] LoadAllJobs: Loading attributes for job
6...
I [06/Apr/2004:08:32:35 -0700] Full reload complete.
D [06/Apr/2004:08:32:35 -0700] StartListening: NumListeners=1
D [06/Apr/2004:08:32:35 -0700] StartListening: address=00000000 port=631
D [06/Apr/2004:08:32:35 -0700] ResumeListening: setting input bits...
D [06/Apr/2004:08:33:08 -0700] AcceptClient: 5 from localhost:631.
D [06/Apr/2004:08:33:08 -0700] CloseClient: 5
D [06/Apr/2004:08:33:08 -0700] AcceptClient: 5 from localhost:631.
D [06/Apr/2004:08:33:08 -0700] ReadClient: 5 POST /printers/ HTTP/1.1
D [06/Apr/2004:08:33:08 -0700] ProcessIPPRequest: 5 status_code=1
D [06/Apr/2004:08:33:08 -0700] AcceptClient: 7 from localhost:631.
D [06/Apr/2004:08:33:08 -0700] CloseClient: 5
D [06/Apr/2004:08:33:08 -0700] ReadClient: 7 POST /printers/ HTTP/1.1
D [06/Apr/2004:08:33:08 -0700] ProcessIPPRequest: 7 status_code=1
D [06/Apr/2004:08:33:08 -0700] CloseClient: 7
D [06/Apr/2004:08:33:08 -0700] AcceptClient: 5 from localhost:631.
D [06/Apr/2004:08:33:08 -0700] ReadClient: 5 POST /classes/ HTTP/1.1
D [06/Apr/2004:08:33:08 -0700] ProcessIPPRequest: 5 status_code=1
D [06/Apr/2004:08:33:08 -0700] AcceptClient: 7 from localhost:631.
D [06/Apr/2004:08:33:08 -0700] CloseClient: 5
D [06/Apr/2004:08:33:08 -0700] ReadClient: 7 POST /printers/ HTTP/1.1
D [06/Apr/2004:08:33:08 -0700] ProcessIPPRequest: 7 status_code=1
D [06/Apr/2004:08:33:08 -0700] CloseClient: 7
D [06/Apr/2004:08:33:09 -0700] AcceptClient: 5 from localhost:631.
D [06/Apr/2004:08:33:09 -0700] ReadClient: 5 POST /printers/ HTTP/1.1
D [06/Apr/2004:08:33:09 -0700] ProcessIPPRequest: 5 status_code=1
D [06/Apr/2004:08:33:09 -0700] CloseClient: 5
D [06/Apr/2004:08:33:15 -0700] AcceptClient: 5 from localhost:631.
D [06/Apr/2004:08:33:15 -0700] ReadClient: 5 POST / HTTP/1.1
D [06/Apr/2004:08:33:15 -0700] ProcessIPPRequest: 5 status_code=0
D [06/Apr/2004:08:33:15 -0700] ReadClient: 5 GET /printers/Elite600.ppd
HTTP/1.1
D [06/Apr/2004:08:33:15 -0700] SendFile: 5 file=7
D [06/Apr/2004:08:33:17 -0700] AcceptClient: 7 from localhost:631.
D [06/Apr/2004:08:33:17 -0700] ReadClient: 7 POST /printers/Elite600
HTTP/1.1
D [06/Apr/2004:08:33:17 -0700] print_job: auto-typing file...
D [06/Apr/2004:08:33:17 -0700] print_job: request file type is
application/postscript.
D [06/Apr/2004:08:33:17 -0700] check_quotas: requesting-user-name =
'root'
D [06/Apr/2004:08:33:17 -0700] print_job: requesting-user-name = 'root'
D [06/Apr/2004:08:33:17 -0700] Adding default job-sheets values
"none,none"...
I [06/Apr/2004:08:33:17 -0700] Adding start banner page "none" to job 7.
I [06/Apr/2004:08:33:17 -0700] Adding end banner page "none" to job 7.
I [06/Apr/2004:08:33:17 -0700] Job 7 queued on 'Elite600' by 'root'.
D [06/Apr/2004:08:33:17 -0700] Job 7 hold_until = 0
D [06/Apr/2004:08:33:17 -0700] StartJob(7, 0x8096ca8)
D [06/Apr/2004:08:33:17 -0700] StartJob() id = 7, file = 0/1
D [06/Apr/2004:08:33:17 -0700] job-sheets=none,none
D [06/Apr/2004:08:33:17 -0700] banner_page = 0
D [06/Apr/2004:08:33:17 -0700] StartJob: argv =
"Elite600","7","root","foo.txt","1","PageSize=Letter multipl
e-document-handling=separate-documents-collated-copies
orientation-requested=3","/var/spool/cups/d00007-001"
D [06/Apr/2004:08:33:17 -0700] StartJob:
envp[0]="PATH=/usr/lib/cups/filter:/bin:/usr/bin"
D [06/Apr/2004:08:33:17 -0700] StartJob: envp[1]="SOFTWARE=CUPS/1.1"
D [06/Apr/2004:08:33:17 -0700] StartJob: envp[2]="USER=root"
D [06/Apr/2004:08:33:17 -0700] StartJob: envp[3]="CHARSET=iso-8859-1"
D [06/Apr/2004:08:33:17 -0700] StartJob: envp[4]="LANG=en"
D [06/Apr/2004:08:33:17 -0700] StartJob: envp[5]="TZ=US/Pacific"
D [06/Apr/2004:08:33:17 -0700] StartJob:
envp[6]="PPD=/etc/cups/ppd/Elite600.ppd"
D [06/Apr/2004:08:33:17 -0700] StartJob:
envp[7]="CUPS_SERVERROOT=/etc/cups"
D [06/Apr/2004:08:33:17 -0700] StartJob: envp[8]="RIP_MAX_CACHE=8m"
D [06/Apr/2004:08:33:17 -0700] StartJob:
envp[9]="TMPDIR=/var/spool/cups/tmp"
D [06/Apr/2004:08:33:17 -0700] StartJob:
envp[10]="CONTENT_TYPE=application/postscript"
D [06/Apr/2004:08:33:17 -0700] StartJob:
envp[11]="DEVICE_URI=parallel:/dev/lp0"
D [06/Apr/2004:08:33:17 -0700] StartJob: envp[12]="PRINTER=Elite600"
D [06/Apr/2004:08:33:17 -0700] StartJob:
envp[13]="CUPS_DATADIR=/usr/share/cups"
D [06/Apr/2004:08:33:17 -0700] StartJob:
envp[14]="CUPS_FONTPATH=/usr/share/cups/fonts"
D [06/Apr/2004:08:33:17 -0700] StartJob:
envp[15]="CUPS_SERVER=localhost"
D [06/Apr/2004:08:33:17 -0700] StartJob: envp[16]="IPP_PORT=631"
D [06/Apr/2004:08:33:17 -0700] StartJob: statusfds = [ 8 9 ]
D [06/Apr/2004:08:33:17 -0700] StartJob: filterfds[1] = [ 10 -1 ]
D [06/Apr/2004:08:33:17 -0700] StartJob: filter =
"/usr/lib/cups/filter/pstops"
D [06/Apr/2004:08:33:17 -0700] StartJob: filterfds[0] = [ 11 12 ]
D [06/Apr/2004:08:33:17 -0700]
start_process("/usr/lib/cups/filter/pstops", 0xbffefc80, 0xbffeeff0, 10,
12, 9)
I [06/Apr/2004:08:33:17 -0700] Started filter
/usr/lib/cups/filter/pstops (PID 12131) for job 7.
D [06/Apr/2004:08:33:17 -0700] StartJob: backend =
"/usr/lib/cups/backend/parallel"
D [06/Apr/2004:08:33:17 -0700] StartJob: filterfds[1] = [ -1 10 ]
D [06/Apr/2004:08:33:17 -0700]
start_process("/usr/lib/cups/backend/parallel", 0xbffefc80, 0xbffeeff0,
11, 10, 9)
I [06/Apr/2004:08:33:17 -0700] Started backend
/usr/lib/cups/backend/parallel (PID 12132) for job 7.
D [06/Apr/2004:08:33:17 -0700] ProcessIPPRequest: 7 status_code=0
D [06/Apr/2004:08:33:17 -0700] CloseClient: 7
D [06/Apr/2004:08:33:17 -0700] [Job 7] Page = 612x792; 0,0 to 612,792
D [06/Apr/2004:08:33:17 -0700] [Job 7] slowcollate=0, slowduplex=0,
sloworder=0
D [06/Apr/2004:08:33:17 -0700] [Job 7] 0 %%BoundingBox: 0 0 612 792
D [06/Apr/2004:08:33:17 -0700] [Job 7] 0 %%Creator: Qt 3.2.3
D [06/Apr/2004:08:33:17 -0700] [Job 7] 0 %%Title: foo.txt
D [06/Apr/2004:08:33:17 -0700] [Job 7] 0 %%CreationDate: Tue Apr 6
08:33:16 2004
D [06/Apr/2004:08:33:17 -0700] [Job 7] 0 %%Orientation: Portrait
D [06/Apr/2004:08:33:17 -0700] [Job 7] 0 %%Pages: 1
D [06/Apr/2004:08:33:17 -0700] [Job 7] 0 %%DocumentFonts: Tahoma
CourierNewPSMT
D [06/Apr/2004:08:33:17 -0700] [Job 7] 0 %%EndComments
D [06/Apr/2004:08:33:17 -0700] [Job 7] 0 %%BeginProlog
D [06/Apr/2004:08:33:17 -0700] [Job 7] 0 %%EndProlog
D [06/Apr/2004:08:33:17 -0700] [Job 7] 0 %%BeginSetup
D [06/Apr/2004:08:33:17 -0700] [Job 7] 0 %%BeginFont: Tahoma
D [06/Apr/2004:08:33:17 -0700] [Job 7] 0 %%Copyright: Typeface and data
© 1995-1999 Microsoft Corporation. All Rights Reserved.
D [06/Apr/2004:08:33:17 -0700] [Job 7] 0 %%Creator: Converted from
TrueType by Qt
D [06/Apr/2004:08:33:18 -0700] [Job 7] 0 %% Font Page 00
D [06/Apr/2004:08:33:18 -0700] [Job 7] 0 %%BeginFont: Tahoma
D [06/Apr/2004:08:33:18 -0700] [Job 7] 0 %%FontName: Tahoma-Uni
D [06/Apr/2004:08:33:18 -0700] [Job 7] 0 %%Creator: Composite font
created by Qt
D [06/Apr/2004:08:33:18 -0700] [Job 7] 0 %%EndFont
D [06/Apr/2004:08:33:18 -0700] [Job 7] 0 %%EndFont
D [06/Apr/2004:08:33:18 -0700] [Job 7] 0 %%BeginFont: Courier New
D [06/Apr/2004:08:33:18 -0700] [Job 7] 0 %%Copyright: Typeface © The
Monotype Corporation plc. Data © The Monotype Corporation plc/Type
Solutions Inc. 1990-1994. All Rights Reserved
D [06/Apr/2004:08:33:18 -0700] [Job 7] 0 %%Creator: Converted from
TrueType by Qt
D [06/Apr/2004:08:33:21 -0700] [Job 7] 0 %% Font Page 00
D [06/Apr/2004:08:33:21 -0700] [Job 7] 0 %%BeginFont: CourierNewPSMT
D [06/Apr/2004:08:33:21 -0700] [Job 7] 0 %%FontName: CourierNewPSMT-Uni
D [06/Apr/2004:08:33:21 -0700] [Job 7] 0 %%Creator: Composite font
created by Qt
D [06/Apr/2004:08:33:21 -0700] [Job 7] 0 %%EndFont
D [06/Apr/2004:08:33:21 -0700] [Job 7] 0 %%EndFont
D [06/Apr/2004:08:33:21 -0700] [Job 7] 0 %%EndSetup
D [06/Apr/2004:08:33:21 -0700] [Job 7] 0 %%Page: 1 1
D [06/Apr/2004:08:33:21 -0700] [Job 7] 0 %%Page: 1 1
D [06/Apr/2004:08:33:21 -0700] [Job 7] pw = 611.9, pl = 791.9
D [06/Apr/2004:08:33:21 -0700] [Job 7] PageLeft = 0.0, PageRight = 611.9
D [06/Apr/2004:08:33:21 -0700] [Job 7] PageTop = 792.0, PageBottom = 0.1
D [06/Apr/2004:08:33:21 -0700] [Job 7] PageWidth = 612.0, PageLength =
792.0
D [06/Apr/2004:08:33:21 -0700] [Job 7] 0 %%BeginPageSetup
D [06/Apr/2004:08:33:21 -0700] [Job 7] 0 %%EndPageSetup
D [06/Apr/2004:08:33:21 -0700] AcceptClient: 9 from localhost:631.
D [06/Apr/2004:08:33:21 -0700] ReadClient: 9 POST /printers/ HTTP/1.1
D [06/Apr/2004:08:33:21 -0700] ProcessIPPRequest: 9 status_code=1
D [06/Apr/2004:08:33:21 -0700] CloseClient: 9
D [06/Apr/2004:08:33:21 -0700] AcceptClient: 9 from localhost:631.
D [06/Apr/2004:08:33:21 -0700] ReadClient: 9 POST /classes/ HTTP/1.1
D [06/Apr/2004:08:33:21 -0700] ProcessIPPRequest: 9 status_code=1
D [06/Apr/2004:08:33:21 -0700] CloseClient: 9
D [06/Apr/2004:08:33:21 -0700] AcceptClient: 9 from localhost:631.
D [06/Apr/2004:08:33:21 -0700] ReadClient: 9 POST /printers/ HTTP/1.1
D [06/Apr/2004:08:33:21 -0700] ProcessIPPRequest: 9 status_code=1
D [06/Apr/2004:08:33:21 -0700] CloseClient: 9
D [06/Apr/2004:08:33:21 -0700] AcceptClient: 9 from localhost:631.
D [06/Apr/2004:08:33:21 -0700] ReadClient: 9 POST / HTTP/1.1
D [06/Apr/2004:08:33:21 -0700] ProcessIPPRequest: 9 status_code=1
D [06/Apr/2004:08:33:21 -0700] CloseClient: 9
D [06/Apr/2004:08:33:22 -0700] AcceptClient: 9 from localhost:631.
D [06/Apr/2004:08:33:22 -0700] ReadClient: 9 POST /printers/ HTTP/1.1
D [06/Apr/2004:08:33:22 -0700] ProcessIPPRequest: 9 status_code=1
D [06/Apr/2004:08:33:22 -0700] CloseClient: 9
D [06/Apr/2004:08:33:22 -0700] AcceptClient: 9 from localhost:631.
D [06/Apr/2004:08:33:22 -0700] ReadClient: 9 POST /classes/ HTTP/1.1
D [06/Apr/2004:08:33:22 -0700] ProcessIPPRequest: 9 status_code=1
D [06/Apr/2004:08:33:22 -0700] CloseClient: 9
D [06/Apr/2004:08:33:22 -0700] AcceptClient: 9 from localhost:631.
D [06/Apr/2004:08:33:22 -0700] ReadClient: 9 POST /printers/ HTTP/1.1
D [06/Apr/2004:08:33:22 -0700] ProcessIPPRequest: 9 status_code=1
D [06/Apr/2004:08:33:22 -0700] CloseClient: 9
D [06/Apr/2004:08:33:22 -0700] AcceptClient: 9 from localhost:631.
D [06/Apr/2004:08:33:22 -0700] ReadClient: 9 POST / HTTP/1.1
D [06/Apr/2004:08:33:22 -0700] ProcessIPPRequest: 9 status_code=1
D [06/Apr/2004:08:33:22 -0700] CloseClient: 9
D [06/Apr/2004:08:33:22 -0700] [Job 7] 0 %%Trailer
D [06/Apr/2004:08:33:22 -0700] [Job 7] Saw Trailer!
D [06/Apr/2004:08:33:22 -0700] [Job 7] Saw EOF!
D [06/Apr/2004:08:33:23 -0700] UpdateJob: job 7, file 0 is complete.
D [06/Apr/2004:08:33:23 -0700] CancelJob: id = 7
D [06/Apr/2004:08:33:23 -0700] StopJob: id = 7, force = 0
D [06/Apr/2004:08:33:23 -0700] StopJob: printer state is 3
D [06/Apr/2004:08:33:27 -0700] AcceptClient: 8 from localhost:631.
D [06/Apr/2004:08:33:27 -0700] ReadClient: 8 POST /printers/ HTTP/1.1
D [06/Apr/2004:08:33:27 -0700] ProcessIPPRequest: 8 status_code=1
D [06/Apr/2004:08:33:27 -0700] AcceptClient: 9 from localhost:631.
D [06/Apr/2004:08:33:27 -0700] CloseClient: 8
D [06/Apr/2004:08:33:27 -0700] ReadClient: 9 POST /classes/ HTTP/1.1
D [06/Apr/2004:08:33:27 -0700] ProcessIPPRequest: 9 status_code=1
D [06/Apr/2004:08:33:27 -0700] AcceptClient: 8 from localhost:631.
D [06/Apr/2004:08:33:27 -0700] CloseClient: 9
D [06/Apr/2004:08:33:27 -0700] ReadClient: 8 POST /printers/ HTTP/1.1
D [06/Apr/2004:08:33:27 -0700] ProcessIPPRequest: 8 status_code=1
D [06/Apr/2004:08:33:27 -0700] CloseClient: 8
D [06/Apr/2004:08:33:27 -0700] AcceptClient: 8 from localhost:631.
D [06/Apr/2004:08:33:27 -0700] ReadClient: 8 POST / HTTP/1.1
D [06/Apr/2004:08:33:27 -0700] ProcessIPPRequest: 8 status_code=1
D [06/Apr/2004:08:33:27 -0700] CloseClient: 8
-----------------------
And here's the output from a working test page print:
D [06/Apr/2004:08:38:00 -0700] AcceptClient: 8 from localhost:631.
D [06/Apr/2004:08:38:00 -0700] ReadClient: 8 POST /printers/ HTTP/1.1
D [06/Apr/2004:08:38:00 -0700] ProcessIPPRequest: 8 status_code=1
D [06/Apr/2004:08:38:00 -0700] AcceptClient: 9 from localhost:631.
D [06/Apr/2004:08:38:00 -0700] CloseClient: 8
D [06/Apr/2004:08:38:00 -0700] ReadClient: 9 POST /classes/ HTTP/1.1
D [06/Apr/2004:08:38:00 -0700] ProcessIPPRequest: 9 status_code=1
D [06/Apr/2004:08:38:00 -0700] AcceptClient: 8 from localhost:631.
D [06/Apr/2004:08:38:00 -0700] CloseClient: 9
D [06/Apr/2004:08:38:00 -0700] ReadClient: 8 POST /printers/ HTTP/1.1
D [06/Apr/2004:08:38:00 -0700] ProcessIPPRequest: 8 status_code=1
D [06/Apr/2004:08:38:00 -0700] CloseClient: 8
D [06/Apr/2004:08:38:02 -0700] AcceptClient: 8 from localhost:631.
D [06/Apr/2004:08:38:02 -0700] ReadClient: 8 POST /printers/ HTTP/1.1
D [06/Apr/2004:08:38:02 -0700] ProcessIPPRequest: 8 status_code=1
D [06/Apr/2004:08:38:02 -0700] AcceptClient: 9 from localhost:631.
D [06/Apr/2004:08:38:02 -0700] CloseClient: 8
D [06/Apr/2004:08:38:02 -0700] ReadClient: 9 POST / HTTP/1.1
D [06/Apr/2004:08:38:02 -0700] ProcessIPPRequest: 9 status_code=0
D [06/Apr/2004:08:38:02 -0700] ReadClient: 9 GET /printers/Elite600.ppd
HTTP/1.1
D [06/Apr/2004:08:38:02 -0700] SendFile: 9 file=8
D [06/Apr/2004:08:38:02 -0700] AcceptClient: 8 from localhost:631.
D [06/Apr/2004:08:38:02 -0700] ReadClient: 8 POST / HTTP/1.1
D [06/Apr/2004:08:38:02 -0700] ProcessIPPRequest: 8 status_code=1
D [06/Apr/2004:08:38:02 -0700] CloseClient: 8
D [06/Apr/2004:08:38:05 -0700] AcceptClient: 8 from localhost:631.
D [06/Apr/2004:08:38:05 -0700] ReadClient: 8 POST /printers/ HTTP/1.1
D [06/Apr/2004:08:38:05 -0700] ProcessIPPRequest: 8 status_code=1
D [06/Apr/2004:08:38:05 -0700] AcceptClient: 10 from localhost:631.
D [06/Apr/2004:08:38:05 -0700] CloseClient: 8
D [06/Apr/2004:08:38:05 -0700] ReadClient: 10 POST /classes/ HTTP/1.1
D [06/Apr/2004:08:38:05 -0700] ProcessIPPRequest: 10 status_code=1
D [06/Apr/2004:08:38:05 -0700] AcceptClient: 8 from localhost:631.
D [06/Apr/2004:08:38:05 -0700] CloseClient: 10
D [06/Apr/2004:08:38:05 -0700] ReadClient: 8 POST /printers/ HTTP/1.1
D [06/Apr/2004:08:38:05 -0700] ProcessIPPRequest: 8 status_code=1
D [06/Apr/2004:08:38:05 -0700] AcceptClient: 10 from localhost:631.
D [06/Apr/2004:08:38:05 -0700] CloseClient: 8
D [06/Apr/2004:08:38:05 -0700] ReadClient: 10 POST /printers/ HTTP/1.1
D [06/Apr/2004:08:38:05 -0700] ProcessIPPRequest: 10 status_code=1
D [06/Apr/2004:08:38:05 -0700] ReadClient: 9 POST / HTTP/1.1
D [06/Apr/2004:08:38:05 -0700] ProcessIPPRequest: 9 status_code=0
D [06/Apr/2004:08:38:05 -0700] CloseClient: 10
D [06/Apr/2004:08:38:05 -0700] ReadClient: 9 GET /printers/Elite600.ppd
HTTP/1.1
D [06/Apr/2004:08:38:05 -0700] SendFile: 9 file=8
D [06/Apr/2004:08:38:05 -0700] AcceptClient: 8 from localhost:631.
D [06/Apr/2004:08:38:05 -0700] ReadClient: 8 POST / HTTP/1.1
D [06/Apr/2004:08:38:05 -0700] ProcessIPPRequest: 8 status_code=1
D [06/Apr/2004:08:38:05 -0700] CloseClient: 8
D [06/Apr/2004:08:38:10 -0700] AcceptClient: 8 from localhost:631.
D [06/Apr/2004:08:38:10 -0700] ReadClient: 8 POST / HTTP/1.1
D [06/Apr/2004:08:38:10 -0700] ProcessIPPRequest: 8 status_code=0
D [06/Apr/2004:08:38:10 -0700] CloseClient: 8
D [06/Apr/2004:08:38:10 -0700] AcceptClient: 8 from localhost:631.
D [06/Apr/2004:08:38:10 -0700] ReadClient: 8 POST / HTTP/1.1
D [06/Apr/2004:08:38:10 -0700] ProcessIPPRequest: 8 status_code=0
D [06/Apr/2004:08:38:10 -0700] CloseClient: 8
D [06/Apr/2004:08:38:15 -0700] AcceptClient: 8 from localhost:631.
D [06/Apr/2004:08:38:15 -0700] ReadClient: 8 POST / HTTP/1.1
D [06/Apr/2004:08:38:15 -0700] ProcessIPPRequest: 8 status_code=0
D [06/Apr/2004:08:38:15 -0700] CloseClient: 8
D [06/Apr/2004:08:38:15 -0700] AcceptClient: 8 from localhost:631.
D [06/Apr/2004:08:38:15 -0700] ReadClient: 8 POST / HTTP/1.1
D [06/Apr/2004:08:38:15 -0700] ProcessIPPRequest: 8 status_code=0
D [06/Apr/2004:08:38:15 -0700] CloseClient: 8
D [06/Apr/2004:08:38:16 -0700] Closing client 5 after 300 seconds of
inactivity...
D [06/Apr/2004:08:38:16 -0700] CloseClient: 5
D [06/Apr/2004:08:38:16 -0700] AcceptClient: 5 from localhost:631.
D [06/Apr/2004:08:38:16 -0700] ReadClient: 5 POST / HTTP/1.1
D [06/Apr/2004:08:38:16 -0700] ProcessIPPRequest: 5 status_code=0
D [06/Apr/2004:08:38:16 -0700] CloseClient: 5
D [06/Apr/2004:08:38:20 -0700] AcceptClient: 5 from localhost:631.
D [06/Apr/2004:08:38:20 -0700] ReadClient: 5 POST / HTTP/1.1
D [06/Apr/2004:08:38:20 -0700] ProcessIPPRequest: 5 status_code=0
D [06/Apr/2004:08:38:20 -0700] AcceptClient: 8 from localhost:631.
D [06/Apr/2004:08:38:20 -0700] CloseClient: 5
D [06/Apr/2004:08:38:20 -0700] ReadClient: 8 POST / HTTP/1.1
D [06/Apr/2004:08:38:20 -0700] ProcessIPPRequest: 8 status_code=0
D [06/Apr/2004:08:38:20 -0700] CloseClient: 8
D [06/Apr/2004:08:38:30 -0700] AcceptClient: 5 from localhost:631.
D [06/Apr/2004:08:38:30 -0700] ReadClient: 5 POST /admin/ HTTP/1.1
D [06/Apr/2004:08:38:30 -0700] SendError: 5 code=401 (Unauthorized)
D [06/Apr/2004:08:38:30 -0700] CloseClient: 5
D [06/Apr/2004:08:38:30 -0700] AcceptClient: 5 from localhost:631.
D [06/Apr/2004:08:38:30 -0700] ReadClient: 5 POST /admin/ HTTP/1.1
I [06/Apr/2004:08:38:30 -0700] Setting tmpprinter_W9K5W7pf device-uri to
"parallel:/dev/lp0" (was "file:/dev/null".)
D [06/Apr/2004:08:38:30 -0700] add_printer: Setting job-quota-period to
0...
D [06/Apr/2004:08:38:30 -0700] add_printer: Setting job-k-limit to 0...
D [06/Apr/2004:08:38:30 -0700] add_printer: Setting job-page-limit to
0...
I [06/Apr/2004:08:38:30 -0700] Saving printers.conf...
I [06/Apr/2004:08:38:30 -0700] New printer 'tmpprinter_W9K5W7pf' added
by 'root'.
D [06/Apr/2004:08:38:30 -0700] ProcessIPPRequest: 5 status_code=0
D [06/Apr/2004:08:38:30 -0700] CloseClient: 5
D [06/Apr/2004:08:38:30 -0700] AcceptClient: 5 from localhost:631.
D [06/Apr/2004:08:38:30 -0700] ReadClient: 5 POST /admin/ HTTP/1.1
D [06/Apr/2004:08:38:30 -0700] add_printer: Copied PPD file
successfully!
I [06/Apr/2004:08:38:30 -0700] Saving printers.conf...
I [06/Apr/2004:08:38:30 -0700] Printer 'tmpprinter_W9K5W7pf' modified by
'root'.
D [06/Apr/2004:08:38:30 -0700] ProcessIPPRequest: 5 status_code=0
D [06/Apr/2004:08:38:30 -0700] AcceptClient: 8 from localhost:631.
D [06/Apr/2004:08:38:30 -0700] CloseClient: 5
D [06/Apr/2004:08:38:30 -0700] ReadClient: 8 POST /admin/ HTTP/1.1
I [06/Apr/2004:08:38:30 -0700] Saving printers.conf...
I [06/Apr/2004:08:38:30 -0700] Printer 'tmpprinter_W9K5W7pf' now
accepting jobs ('root').
D [06/Apr/2004:08:38:30 -0700] ProcessIPPRequest: 8 status_code=0
D [06/Apr/2004:08:38:30 -0700] AcceptClient: 5 from localhost:631.
D [06/Apr/2004:08:38:30 -0700] CloseClient: 8
D [06/Apr/2004:08:38:30 -0700] ReadClient: 5 POST /admin/ HTTP/1.1
I [06/Apr/2004:08:38:30 -0700] Saving printers.conf...
I [06/Apr/2004:08:38:30 -0700] Printer 'tmpprinter_W9K5W7pf' started by
'root'.
D [06/Apr/2004:08:38:30 -0700] ProcessIPPRequest: 5 status_code=0
D [06/Apr/2004:08:38:30 -0700] CloseClient: 5
D [06/Apr/2004:08:38:30 -0700] ReadClient: 9 POST / HTTP/1.1
D [06/Apr/2004:08:38:30 -0700] ProcessIPPRequest: 9 status_code=0
D [06/Apr/2004:08:38:30 -0700] ReadClient: 9 GET
/printers/tmpprinter_W9K5W7pf.ppd HTTP/1.1
D [06/Apr/2004:08:38:30 -0700] SendFile: 9 file=5
D [06/Apr/2004:08:38:30 -0700] AcceptClient: 5 from localhost:631.
D [06/Apr/2004:08:38:30 -0700] ReadClient: 5 POST
/printers/tmpprinter_W9K5W7pf HTTP/1.1
D [06/Apr/2004:08:38:30 -0700] print_job: auto-typing file...
D [06/Apr/2004:08:38:30 -0700] print_job: request file type is
application/postscript.
D [06/Apr/2004:08:38:30 -0700] check_quotas: requesting-user-name =
'root'
D [06/Apr/2004:08:38:30 -0700] print_job: requesting-user-name = 'root'
D [06/Apr/2004:08:38:30 -0700] Adding default job-sheets values
"none,none"...
I [06/Apr/2004:08:38:30 -0700] Adding start banner page "none" to job 8.
I [06/Apr/2004:08:38:30 -0700] Adding end banner page "none" to job 8.
I [06/Apr/2004:08:38:30 -0700] Job 8 queued on 'tmpprinter_W9K5W7pf' by
'root'.
D [06/Apr/2004:08:38:30 -0700] Job 8 hold_until = 0
D [06/Apr/2004:08:38:30 -0700] StartJob(8, 0x818c1d0)
D [06/Apr/2004:08:38:30 -0700] StartJob() id = 8, file = 0/1
D [06/Apr/2004:08:38:30 -0700] job-sheets=none,none
D [06/Apr/2004:08:38:30 -0700] banner_page = 0
D [06/Apr/2004:08:38:30 -0700] StartJob: argv =
"tmpprinter_W9K5W7pf","8","root","KDE Print
Test","1","multiple-document-handling=separate-documents-uncollated-copies
orientation-requested=3","/var/spool/cups/d00008-001"
D [06/Apr/2004:08:38:30 -0700] StartJob:
envp[0]="PATH=/usr/lib/cups/filter:/bin:/usr/bin"
D [06/Apr/2004:08:38:30 -0700] StartJob: envp[1]="SOFTWARE=CUPS/1.1"
D [06/Apr/2004:08:38:30 -0700] StartJob: envp[2]="USER=root"
D [06/Apr/2004:08:38:30 -0700] StartJob: envp[3]="CHARSET=iso-8859-1"
D [06/Apr/2004:08:38:30 -0700] StartJob: envp[4]="LANG=en"
D [06/Apr/2004:08:38:30 -0700] StartJob: envp[5]="TZ=US/Pacific"
D [06/Apr/2004:08:38:30 -0700] StartJob:
envp[6]="PPD=/etc/cups/ppd/tmpprinter_W9K5W7pf.ppd"
D [06/Apr/2004:08:38:30 -0700] StartJob:
envp[7]="CUPS_SERVERROOT=/etc/cups"
D [06/Apr/2004:08:38:30 -0700] StartJob: envp[8]="RIP_MAX_CACHE=8m"
D [06/Apr/2004:08:38:30 -0700] StartJob:
envp[9]="TMPDIR=/var/spool/cups/tmp"
D [06/Apr/2004:08:38:30 -0700] StartJob:
envp[10]="CONTENT_TYPE=application/postscript"
D [06/Apr/2004:08:38:30 -0700] StartJob:
envp[11]="DEVICE_URI=parallel:/dev/lp0"
D [06/Apr/2004:08:38:30 -0700] StartJob:
envp[12]="PRINTER=tmpprinter_W9K5W7pf"
D [06/Apr/2004:08:38:30 -0700] StartJob:
envp[13]="CUPS_DATADIR=/usr/share/cups"
D [06/Apr/2004:08:38:30 -0700] StartJob:
envp[14]="CUPS_FONTPATH=/usr/share/cups/fonts"
D [06/Apr/2004:08:38:30 -0700] StartJob:
envp[15]="CUPS_SERVER=localhost"
D [06/Apr/2004:08:38:30 -0700] StartJob: envp[16]="IPP_PORT=631"
D [06/Apr/2004:08:38:30 -0700] StartJob: statusfds = [ 8 10 ]
D [06/Apr/2004:08:38:30 -0700] StartJob: filterfds[1] = [ 11 -1 ]
D [06/Apr/2004:08:38:30 -0700] StartJob: filter =
"/usr/lib/cups/filter/pstops"
D [06/Apr/2004:08:38:30 -0700] StartJob: filterfds[0] = [ 12 13 ]
D [06/Apr/2004:08:38:30 -0700]
start_process("/usr/lib/cups/filter/pstops", 0xbffefc80, 0xbffeeff0, 11,
13, 10)
I [06/Apr/2004:08:38:30 -0700] Started filter
/usr/lib/cups/filter/pstops (PID 12219) for job 8.
D [06/Apr/2004:08:38:30 -0700] StartJob: backend =
"/usr/lib/cups/backend/parallel"
D [06/Apr/2004:08:38:30 -0700] StartJob: filterfds[1] = [ -1 11 ]
D [06/Apr/2004:08:38:30 -0700]
start_process("/usr/lib/cups/backend/parallel", 0xbffefc80, 0xbffeeff0,
12, 11, 10)
I [06/Apr/2004:08:38:30 -0700] Started backend
/usr/lib/cups/backend/parallel (PID 12220) for job 8.
D [06/Apr/2004:08:38:30 -0700] ProcessIPPRequest: 5 status_code=0
D [06/Apr/2004:08:38:30 -0700] CloseClient: 5
D [06/Apr/2004:08:38:30 -0700] [Job 8] slowcollate=0, slowduplex=0,
sloworder=0
D [06/Apr/2004:08:38:30 -0700] [Job 8] 0 %%BoundingBox: 0 0 612 792
D [06/Apr/2004:08:38:30 -0700] [Job 8] 0 %%Pages: 1
D [06/Apr/2004:08:38:30 -0700] [Job 8] 0 %%LanguageLevel: 1
D [06/Apr/2004:08:38:30 -0700] [Job 8] 0 %%DocumentData: Clean7Bit
D [06/Apr/2004:08:38:30 -0700] [Job 8] 0 %%DocumentSuppliedResources:
procset testprint/1.0
D [06/Apr/2004:08:38:30 -0700] [Job 8] 0 %%DocumentNeededResources: font
Helvetica Helvetica-Bold Times-Roman
D [06/Apr/2004:08:38:30 -0700] [Job 8] 0 %%Creator: Michael Sweet, Easy
Software Products
D [06/Apr/2004:08:38:30 -0700] [Job 8] 0 %%CreationDate: May 11, 1999
D [06/Apr/2004:08:38:30 -0700] [Job 8] 0 %%Title: Test Page
D [06/Apr/2004:08:38:30 -0700] [Job 8] 0 %%EndComments
D [06/Apr/2004:08:38:30 -0700] [Job 8] 0 %%BeginProlog
D [06/Apr/2004:08:38:30 -0700] [Job 8] 0 %%BeginResource procset
testprint 1.1 0
D [06/Apr/2004:08:38:30 -0700] [Job 8] 0 %%EndResource
D [06/Apr/2004:08:38:30 -0700] [Job 8] 0 %%EndProlog
D [06/Apr/2004:08:38:30 -0700] [Job 8] 0 %%Page: 1 1
D [06/Apr/2004:08:38:30 -0700] [Job 8] 0 %%Page: 1 1
D [06/Apr/2004:08:38:30 -0700] [Job 8] pw = 576.0, pl = 720.0
D [06/Apr/2004:08:38:30 -0700] [Job 8] PageLeft = 18.0, PageRight =
594.0
D [06/Apr/2004:08:38:30 -0700] [Job 8] PageTop = 756.0, PageBottom =
36.0
D [06/Apr/2004:08:38:30 -0700] [Job 8] PageWidth = 612.0, PageLength =
792.0
D [06/Apr/2004:08:38:30 -0700] [Job 8] 0 %%EOF
D [06/Apr/2004:08:38:30 -0700] [Job 8] Saw EOF!
D [06/Apr/2004:08:38:32 -0700] AcceptClient: 5 from localhost:631.
D [06/Apr/2004:08:38:32 -0700] ReadClient: 5 POST /admin/ HTTP/1.1
D [06/Apr/2004:08:38:32 -0700] CancelJob: id = 8
D [06/Apr/2004:08:38:32 -0700] StopJob: id = 8, force = 0
D [06/Apr/2004:08:38:32 -0700] StopJob: printer state is 3
I [06/Apr/2004:08:38:32 -0700] Printer 'tmpprinter_W9K5W7pf' deleted by
'root'.
I [06/Apr/2004:08:38:32 -0700] Saving printers.conf...
D [06/Apr/2004:08:38:32 -0700] ProcessIPPRequest: 5 status_code=0
D [06/Apr/2004:08:38:32 -0700] CloseClient: 5
D [06/Apr/2004:08:38:35 -0700] CloseClient: 9
Thanks!
Steve Freitas
On Tue, 2004-04-06 at 07:36, hugo vanwoerkom wrote:
> Steve Freitas wrote:
> > Hi all,
> >
> >
> > So, any idea what might cause a test page to go fine and everything else to
> > fail quietly? Any idea what is different between a test page and a regular
> > print job?
>
> Set the logging level to debug in the cups config file.
> Then find out what's bugging him.
>
--
To UNSUBSCRIBE, email to [EMAIL PROTECTED]
with a subject of "unsubscribe". Trouble? Contact [EMAIL PROTECTED]
