PDA

View Full Version : Cups printing problem

brittm
1st September 2004, 02:22 AM
I'm running several machines with FC2, and have a shared LaserJet on the server. Prior to upgrading to FC2 on the server, cups printing worked just fine. Now:

Printing works fine from the server.
All clients automatically pick up the shared printer as lp0 and set it as their default.
When a client prints, the printer icon is placed on the task bar and shows the print job in queue.
The client will hold the print job in queue indefinitely, and the job never prints.
Firewalls on all of the machines, including the server, are disabled.

Anyone seen anything like this before?

Thanks for your time and input,
brittm
2nd September 2004, 04:44 AM
Output from the clients /var/log/cups/error_log (yes, kinda long, but I wanted to get everything from the reboot) :

D [01/Sep/2004:20:10:18 -0500] AddLocation: added location '/admin'
D [01/Sep/2004:20:10:18 -0500] DenyIP: /admin deny 00000000/00000000
D [01/Sep/2004:20:10:18 -0500] AllowIP: /admin allow 7f000001/ffffffff
D [01/Sep/2004:20:10:18 -0500] AddLocation: added location '/'
D [01/Sep/2004:20:10:18 -0500] DenyIP: / deny 00000000/00000000
D [01/Sep/2004:20:10:18 -0500] AllowIP: / allow 7f000001/ffffffff
D [01/Sep/2004:20:10:18 -0500] AddLocation: added location 'CUPS_INTERNAL_BROWSE_ACL'
D [01/Sep/2004:20:10:18 -0500] AllowHost: CUPS_INTERNAL_BROWSE_ACL allow @LOCAL
I [01/Sep/2004:20:10:18 -0500] Listening to 7f000001:631
I [01/Sep/2004:20:10:18 -0500] Loaded configuration file "/etc/cups/cupsd.conf"
I [01/Sep/2004:20:10:18 -0500] Configured for up to 100 clients.
I [01/Sep/2004:20:10:18 -0500] Allowing up to 100 client connections per host.
I [01/Sep/2004:20:10:18 -0500] Full reload is required.
D [01/Sep/2004:20:10:19 -0500] LoadDevices: Added device "serial:/dev/ttyS0?baud=115200"...
D [01/Sep/2004:20:10:19 -0500] LoadDevices: Added device "serial:/dev/ttyS1?baud=115200"...
D [01/Sep/2004:20:10:19 -0500] LoadDevices: Added device "serial:/dev/ttyS2?baud=115200"...
D [01/Sep/2004:20:10:19 -0500] LoadDevices: Added device "serial:/dev/ttyS3?baud=115200"...
D [01/Sep/2004:20:10:19 -0500] LoadDevices: Added device "serial:/dev/ttyS4?baud=115200"...
D [01/Sep/2004:20:10:19 -0500] LoadDevices: Added device "serial:/dev/ttyS5?baud=115200"...
D [01/Sep/2004:20:10:19 -0500] LoadDevices: Added device "serial:/dev/ttyS6?baud=115200"...
D [01/Sep/2004:20:10:19 -0500] LoadDevices: Added device "serial:/dev/ttyS7?baud=115200"...
D [01/Sep/2004:20:10:19 -0500] LoadDevices: Added device "ipp"...
D [01/Sep/2004:20:10:19 -0500] LoadDevices: Added device "parallel:/dev/lp0"...
D [01/Sep/2004:20:10:19 -0500] LoadDevices: Added device "lpd"...
D [01/Sep/2004:20:10:19 -0500] LoadDevices: Added device "socket"...
D [01/Sep/2004:20:10:19 -0500] LoadDevices: Added device "http"...
D [01/Sep/2004:20:10:19 -0500] LoadDevices: Added device "usb:/dev/usb/lp0"...
D [01/Sep/2004:20:10:19 -0500] LoadDevices: Added device "usb:/dev/usb/lp1"...
D [01/Sep/2004:20:10:19 -0500] LoadDevices: Added device "usb:/dev/usb/lp2"...
D [01/Sep/2004:20:10:19 -0500] LoadDevices: Added device "usb:/dev/usb/lp3"...
D [01/Sep/2004:20:10:19 -0500] LoadDevices: Added device "usb:/dev/usb/lp4"...
D [01/Sep/2004:20:10:19 -0500] LoadDevices: Added device "usb:/dev/usb/lp5"...
D [01/Sep/2004:20:10:19 -0500] LoadDevices: Added device "usb:/dev/usb/lp6"...
D [01/Sep/2004:20:10:19 -0500] LoadDevices: Added device "usb:/dev/usb/lp7"...
D [01/Sep/2004:20:10:19 -0500] LoadDevices: Added device "usb:/dev/usb/lp8"...
D [01/Sep/2004:20:10:19 -0500] LoadDevices: Added device "usb:/dev/usb/lp9"...
D [01/Sep/2004:20:10:19 -0500] LoadDevices: Added device "usb:/dev/usb/lp10"...
D [01/Sep/2004:20:10:19 -0500] LoadDevices: Added device "usb:/dev/usb/lp11"...
D [01/Sep/2004:20:10:19 -0500] LoadDevices: Added device "usb:/dev/usb/lp12"...
D [01/Sep/2004:20:10:19 -0500] LoadDevices: Added device "usb:/dev/usb/lp13"...
D [01/Sep/2004:20:10:19 -0500] LoadDevices: Added device "usb:/dev/usb/lp14"...
D [01/Sep/2004:20:10:19 -0500] LoadDevices: Added device "usb:/dev/usb/lp15"...
D [01/Sep/2004:20:10:19 -0500] LoadDevices: Added device "scsi"...
I [01/Sep/2004:20:10:19 -0500] LoadPPDs: Read "/etc/cups/ppds.dat", 13 PPDs...
I [01/Sep/2004:20:10:19 -0500] LoadPPDs: No new or changed PPDs...
D [01/Sep/2004:20:10:19 -0500] LoadAllJobs: Scanning /var/spool/cups...
D [01/Sep/2004:20:10:19 -0500] LoadAllJobs: Loading attributes for job 4...
D [01/Sep/2004:20:10:19 -0500] LoadAllJobs: Auto-typing document file d00004-001...
I [01/Sep/2004:20:10:19 -0500] Full reload complete.
D [01/Sep/2004:20:10:19 -0500] StartListening: NumListeners=1
D [01/Sep/2004:20:10:19 -0500] StartListening: address=7f000001 port=631
D [01/Sep/2004:20:10:19 -0500] ResumeListening: setting input bits...
D [01/Sep/2004:20:10:19 -0500] StartJob(4, 0x99286d0)
D [01/Sep/2004:20:10:19 -0500] StartJob() id = 4, file = 0/1
D [01/Sep/2004:20:10:19 -0500] StartJob: Sending job to queue tagged as raw...
D [01/Sep/2004:20:10:19 -0500] No job-sheets attribute.
D [01/Sep/2004:20:10:19 -0500] banner_page = 0
D [01/Sep/2004:20:10:19 -0500] StartJob: argv = "lp0","4","root","","1","job-hold-until=no-hold job-priority=50","/var/spool/cups/d00004-001"
D [01/Sep/2004:20:10:19 -0500] StartJob: envp[0]="PATH=/usr/lib/cups/filter:/bin:/usr/bin"
D [01/Sep/2004:20:10:19 -0500] StartJob: envp[1]="SOFTWARE=CUPS/1.1"
D [01/Sep/2004:20:10:19 -0500] StartJob: envp[2]="USER=root"
D [01/Sep/2004:20:10:19 -0500] StartJob: envp[3]="CHARSET=utf-8"
D [01/Sep/2004:20:10:19 -0500] StartJob: envp[4]="LANG=en_US"
D [01/Sep/2004:20:10:19 -0500] StartJob: envp[5]="PPD=/etc/cups/ppd/lp0.ppd"
D [01/Sep/2004:20:10:19 -0500] StartJob: envp[6]="CUPS_SERVERROOT=/etc/cups"
D [01/Sep/2004:20:10:19 -0500] StartJob: envp[7]="RIP_MAX_CACHE=8m"
D [01/Sep/2004:20:10:19 -0500] StartJob: envp[8]="TMPDIR=/var/spool/cups/tmp"
D [01/Sep/2004:20:10:19 -0500] StartJob: envp[9]="CONTENT_TYPE=application/postscript"
D [01/Sep/2004:20:10:19 -0500] StartJob: envp[10]="DEVICE_URI=file:/dev/null"
D [01/Sep/2004:20:10:19 -0500] StartJob: envp[11]="PRINTER=lp0"
D [01/Sep/2004:20:10:19 -0500] StartJob: envp[12]="CUPS_DATADIR=/usr/share/cups"
D [01/Sep/2004:20:10:19 -0500] StartJob: envp[13]="CUPS_FONTPATH=/usr/share/cups/fonts"
D [01/Sep/2004:20:10:19 -0500] StartJob: envp[14]="CUPS_SERVER=localhost"
D [01/Sep/2004:20:10:19 -0500] StartJob: envp[15]="IPP_PORT=631"
D [01/Sep/2004:20:10:19 -0500] StartJob: statusfds = [ 5 6 ]
D [01/Sep/2004:20:10:19 -0500] StartJob: filterfds[1] = [ 7 -1 ]
D [01/Sep/2004:20:10:19 -0500] UpdateJob: job 4, file 0 is complete.
D [01/Sep/2004:20:10:19 -0500] CancelJob: id = 4
D [01/Sep/2004:20:10:19 -0500] StopJob: id = 4, force = 0
D [01/Sep/2004:20:10:19 -0500] StopJob: printer state is 5
I [01/Sep/2004:20:10:39 -0500] Added remote printer "lp0@pine.brittsplace.com"...
I [01/Sep/2004:20:10:39 -0500] Added implicit class "lp0"...
D [01/Sep/2004:22:03:50 -0500] AcceptClient() 5 from localhost:631.
D [01/Sep/2004:22:03:50 -0500] ReadClient() 5 POST / HTTP/1.1
D [01/Sep/2004:22:03:50 -0500] ProcessIPPRequest: 5 status_code=1
D [01/Sep/2004:22:08:51 -0500] Closing client 5 after 300 seconds of inactivity...
D [01/Sep/2004:22:08:51 -0500] CloseClient() 5
D [01/Sep/2004:22:10:08 -0500] AcceptClient() 5 from localhost:631.
D [01/Sep/2004:22:10:08 -0500] AcceptClient() 7 from localhost:631.
D [01/Sep/2004:22:10:08 -0500] ReadClient() 7 POST / HTTP/1.1
D [01/Sep/2004:22:10:08 -0500] ProcessIPPRequest: 7 status_code=1
D [01/Sep/2004:22:10:08 -0500] CloseClient() 7
D [01/Sep/2004:22:10:08 -0500] AcceptClient() 7 from localhost:631.


...cont....
brittm
2nd September 2004, 05:04 AM

...cont...

D [01/Sep/2004:22:10:08 -0500] ReadClient() 7 POST / HTTP/1.1
D [01/Sep/2004:22:10:08 -0500] ProcessIPPRequest: 7 status_code=1
D [01/Sep/2004:22:10:08 -0500] CloseClient() 7
D [01/Sep/2004:22:10:08 -0500] AcceptClient() 7 from localhost:631.
D [01/Sep/2004:22:10:08 -0500] ReadClient() 7 POST / HTTP/1.1
D [01/Sep/2004:22:10:08 -0500] ProcessIPPRequest: 7 status_code=1
D [01/Sep/2004:22:10:08 -0500] CloseClient() 7
D [01/Sep/2004:22:10:08 -0500] AcceptClient() 7 from localhost:631.
D [01/Sep/2004:22:10:08 -0500] ReadClient() 7 POST / HTTP/1.1
D [01/Sep/2004:22:10:08 -0500] ProcessIPPRequest: 7 status_code=1
D [01/Sep/2004:22:10:08 -0500] CloseClient() 7
D [01/Sep/2004:22:10:08 -0500] AcceptClient() 7 from localhost:631.
D [01/Sep/2004:22:10:08 -0500] ReadClient() 7 POST / HTTP/1.1
D [01/Sep/2004:22:10:08 -0500] ProcessIPPRequest: 7 status_code=0
D [01/Sep/2004:22:10:08 -0500] ReadClient() 5 POST / HTTP/1.1
D [01/Sep/2004:22:10:08 -0500] ProcessIPPRequest: 5 status_code=1
D [01/Sep/2004:22:10:08 -0500] CloseClient() 5
D [01/Sep/2004:22:10:08 -0500] CloseClient() 7
D [01/Sep/2004:22:10:09 -0500] AcceptClient() 5 from localhost:631.
D [01/Sep/2004:22:10:09 -0500] ReadClient() 5 POST / HTTP/1.1
D [01/Sep/2004:22:10:09 -0500] ProcessIPPRequest: 5 status_code=0
D [01/Sep/2004:22:10:09 -0500] CloseClient() 5
D [01/Sep/2004:22:10:09 -0500] AcceptClient() 5 from localhost:631.
D [01/Sep/2004:22:10:09 -0500] AcceptClient() 7 from localhost:631.
D [01/Sep/2004:22:10:09 -0500] AcceptClient() 8 from localhost:631.
D [01/Sep/2004:22:10:09 -0500] ReadClient() 8 POST / HTTP/1.1
D [01/Sep/2004:22:10:09 -0500] ProcessIPPRequest: 8 status_code=1
D [01/Sep/2004:22:10:09 -0500] CloseClient() 8
D [01/Sep/2004:22:10:09 -0500] AcceptClient() 8 from localhost:631.
D [01/Sep/2004:22:10:09 -0500] ReadClient() 8 POST / HTTP/1.1
D [01/Sep/2004:22:10:09 -0500] ProcessIPPRequest: 8 status_code=1
D [01/Sep/2004:22:10:09 -0500] CloseClient() 8
D [01/Sep/2004:22:10:09 -0500] AcceptClient() 8 from localhost:631.
D [01/Sep/2004:22:10:09 -0500] ReadClient() 8 POST / HTTP/1.1
D [01/Sep/2004:22:10:09 -0500] ProcessIPPRequest: 8 status_code=1
D [01/Sep/2004:22:10:09 -0500] CloseClient() 8
D [01/Sep/2004:22:10:09 -0500] AcceptClient() 8 from localhost:631.
D [01/Sep/2004:22:10:09 -0500] ReadClient() 8 POST / HTTP/1.1
D [01/Sep/2004:22:10:09 -0500] ProcessIPPRequest: 8 status_code=1
D [01/Sep/2004:22:10:09 -0500] CloseClient() 8
D [01/Sep/2004:22:10:09 -0500] AcceptClient() 8 from localhost:631.
D [01/Sep/2004:22:10:09 -0500] ReadClient() 8 POST / HTTP/1.1
D [01/Sep/2004:22:10:09 -0500] ProcessIPPRequest: 8 status_code=0
D [01/Sep/2004:22:10:09 -0500] ReadClient() 5 POST / HTTP/1.1
D [01/Sep/2004:22:10:09 -0500] ProcessIPPRequest: 5 status_code=1
D [01/Sep/2004:22:10:09 -0500] CloseClient() 5
D [01/Sep/2004:22:10:09 -0500] CloseClient() 8
D [01/Sep/2004:22:10:09 -0500] AcceptClient() 5 from localhost:631.
D [01/Sep/2004:22:10:09 -0500] ReadClient() 5 POST / HTTP/1.1
D [01/Sep/2004:22:10:09 -0500] ProcessIPPRequest: 5 status_code=0
D [01/Sep/2004:22:10:09 -0500] ReadClient() 7 POST / HTTP/1.1
D [01/Sep/2004:22:10:09 -0500] ProcessIPPRequest: 7 status_code=1
D [01/Sep/2004:22:10:09 -0500] CloseClient() 7
D [01/Sep/2004:22:10:09 -0500] CloseClient() 5
D [01/Sep/2004:22:10:09 -0500] AcceptClient() 5 from localhost:631.
D [01/Sep/2004:22:10:09 -0500] AcceptClient() 7 from localhost:631.
D [01/Sep/2004:22:10:09 -0500] AcceptClient() 8 from localhost:631.
D [01/Sep/2004:22:10:09 -0500] ReadClient() 8 POST / HTTP/1.1
D [01/Sep/2004:22:10:09 -0500] ProcessIPPRequest: 8 status_code=1
D [01/Sep/2004:22:10:09 -0500] CloseClient() 8
D [01/Sep/2004:22:10:09 -0500] AcceptClient() 8 from localhost:631.
D [01/Sep/2004:22:10:09 -0500] ReadClient() 8 POST / HTTP/1.1
D [01/Sep/2004:22:10:09 -0500] ProcessIPPRequest: 8 status_code=1
D [01/Sep/2004:22:10:09 -0500] CloseClient() 8
D [01/Sep/2004:22:10:09 -0500] AcceptClient() 8 from localhost:631.
D [01/Sep/2004:22:10:09 -0500] ReadClient() 8 POST / HTTP/1.1
D [01/Sep/2004:22:10:09 -0500] ProcessIPPRequest: 8 status_code=1
D [01/Sep/2004:22:10:09 -0500] CloseClient() 8
D [01/Sep/2004:22:10:09 -0500] AcceptClient() 8 from localhost:631.
D [01/Sep/2004:22:10:09 -0500] ReadClient() 8 POST / HTTP/1.1
D [01/Sep/2004:22:10:09 -0500] ProcessIPPRequest: 8 status_code=1
D [01/Sep/2004:22:10:09 -0500] CloseClient() 8
D [01/Sep/2004:22:10:09 -0500] AcceptClient() 8 from localhost:631.
D [01/Sep/2004:22:10:09 -0500] ReadClient() 8 POST / HTTP/1.1
D [01/Sep/2004:22:10:09 -0500] ProcessIPPRequest: 8 status_code=1
D [01/Sep/2004:22:10:09 -0500] CloseClient() 8
D [01/Sep/2004:22:10:09 -0500] AcceptClient() 8 from localhost:631.
D [01/Sep/2004:22:10:09 -0500] ReadClient() 8 POST / HTTP/1.1
D [01/Sep/2004:22:10:09 -0500] ProcessIPPRequest: 8 status_code=0
D [01/Sep/2004:22:10:09 -0500] ReadClient() 5 POST / HTTP/1.1
D [01/Sep/2004:22:10:09 -0500] ProcessIPPRequest: 5 status_code=1
D [01/Sep/2004:22:10:09 -0500] CloseClient() 5
D [01/Sep/2004:22:10:09 -0500] CloseClient() 8
D [01/Sep/2004:22:10:09 -0500] AcceptClient() 5 from localhost:631.
D [01/Sep/2004:22:10:09 -0500] ReadClient() 5 POST / HTTP/1.1
D [01/Sep/2004:22:10:09 -0500] ProcessIPPRequest: 5 status_code=0
D [01/Sep/2004:22:10:09 -0500] ReadClient() 7 POST / HTTP/1.1
D [01/Sep/2004:22:10:09 -0500] ProcessIPPRequest: 7 status_code=1
D [01/Sep/2004:22:10:09 -0500] CloseClient() 7
D [01/Sep/2004:22:10:09 -0500] CloseClient() 5
D [01/Sep/2004:22:10:09 -0500] AcceptClient() 5 from localhost:631.
D [01/Sep/2004:22:10:09 -0500] AcceptClient() 7 from localhost:631.
D [01/Sep/2004:22:10:09 -0500] ReadClient() 7 POST / HTTP/1.1
D [01/Sep/2004:22:10:09 -0500] ProcessIPPRequest: 7 status_code=1
D [01/Sep/2004:22:10:09 -0500] CloseClient() 7
D [01/Sep/2004:22:10:09 -0500] AcceptClient() 7 from localhost:631.
D [01/Sep/2004:22:10:09 -0500] ReadClient() 7 POST / HTTP/1.1
D [01/Sep/2004:22:10:09 -0500] ProcessIPPRequest: 7 status_code=1
D [01/Sep/2004:22:10:09 -0500] CloseClient() 7
D [01/Sep/2004:22:10:10 -0500] AcceptClient() 7 from localhost:631.
D [01/Sep/2004:22:10:10 -0500] ReadClient() 7 POST / HTTP/1.1
D [01/Sep/2004:22:10:10 -0500] ProcessIPPRequest: 7 status_code=0
D [01/Sep/2004:22:10:10 -0500] ReadClient() 5 POST / HTTP/1.1
D [01/Sep/2004:22:10:10 -0500] ProcessIPPRequest: 5 status_code=1
D [01/Sep/2004:22:10:10 -0500] CloseClient() 5
D [01/Sep/2004:22:10:10 -0500] CloseClient() 7
D [01/Sep/2004:22:10:10 -0500] AcceptClient() 5 from localhost:631.
D [01/Sep/2004:22:10:10 -0500] AcceptClient() 7 from localhost:631.
D [01/Sep/2004:22:10:10 -0500] AcceptClient() 8 from localhost:631.


...cont...
brittm
2nd September 2004, 05:05 AM
...cont...

D [01/Sep/2004:22:10:10 -0500] ReadClient() 8 POST / HTTP/1.1
D [01/Sep/2004:22:10:10 -0500] ProcessIPPRequest: 8 status_code=1
D [01/Sep/2004:22:10:10 -0500] CloseClient() 8
D [01/Sep/2004:22:10:10 -0500] AcceptClient() 8 from localhost:631.
D [01/Sep/2004:22:10:10 -0500] ReadClient() 8 POST / HTTP/1.1
D [01/Sep/2004:22:10:10 -0500] ProcessIPPRequest: 8 status_code=1
D [01/Sep/2004:22:10:10 -0500] CloseClient() 8
D [01/Sep/2004:22:10:10 -0500] AcceptClient() 8 from localhost:631.
D [01/Sep/2004:22:10:10 -0500] ReadClient() 8 POST / HTTP/1.1
D [01/Sep/2004:22:10:10 -0500] ProcessIPPRequest: 8 status_code=1
D [01/Sep/2004:22:10:10 -0500] CloseClient() 8
D [01/Sep/2004:22:10:10 -0500] AcceptClient() 8 from localhost:631.
D [01/Sep/2004:22:10:10 -0500] ReadClient() 8 POST / HTTP/1.1
D [01/Sep/2004:22:10:10 -0500] ProcessIPPRequest: 8 status_code=1
D [01/Sep/2004:22:10:10 -0500] CloseClient() 8
D [01/Sep/2004:22:10:10 -0500] AcceptClient() 8 from localhost:631.
D [01/Sep/2004:22:10:10 -0500] ReadClient() 8 POST / HTTP/1.1
D [01/Sep/2004:22:10:10 -0500] ProcessIPPRequest: 8 status_code=1
D [01/Sep/2004:22:10:10 -0500] CloseClient() 8
D [01/Sep/2004:22:10:10 -0500] AcceptClient() 8 from localhost:631.
D [01/Sep/2004:22:10:10 -0500] ReadClient() 8 POST / HTTP/1.1
D [01/Sep/2004:22:10:10 -0500] ProcessIPPRequest: 8 status_code=0
D [01/Sep/2004:22:10:10 -0500] AcceptClient() 9 from localhost:631.
D [01/Sep/2004:22:10:10 -0500] ReadClient() 9 POST / HTTP/1.1
D [01/Sep/2004:22:10:10 -0500] ProcessIPPRequest: 9 status_code=0
D [01/Sep/2004:22:10:10 -0500] ReadClient() 5 POST / HTTP/1.1
D [01/Sep/2004:22:10:10 -0500] ProcessIPPRequest: 5 status_code=1
D [01/Sep/2004:22:10:10 -0500] ReadClient() 7 POST / HTTP/1.1
D [01/Sep/2004:22:10:10 -0500] ProcessIPPRequest: 7 status_code=1
D [01/Sep/2004:22:10:10 -0500] CloseClient() 5
D [01/Sep/2004:22:10:10 -0500] CloseClient() 8
D [01/Sep/2004:22:10:10 -0500] CloseClient() 7
D [01/Sep/2004:22:10:10 -0500] CloseClient() 9
D [01/Sep/2004:22:10:25 -0500] AcceptClient() 5 from localhost:631.
D [01/Sep/2004:22:10:25 -0500] ReadClient() 5 POST / HTTP/1.1
D [01/Sep/2004:22:10:25 -0500] ProcessIPPRequest: 5 status_code=1
D [01/Sep/2004:22:10:25 -0500] CloseClient() 5
D [01/Sep/2004:22:10:25 -0500] AcceptClient() 5 from localhost:631.
D [01/Sep/2004:22:10:25 -0500] ReadClient() 5 POST / HTTP/1.1
D [01/Sep/2004:22:10:25 -0500] ProcessIPPRequest: 5 status_code=1
D [01/Sep/2004:22:10:25 -0500] CloseClient() 5
D [01/Sep/2004:22:10:25 -0500] AcceptClient() 5 from localhost:631.
D [01/Sep/2004:22:10:25 -0500] ReadClient() 5 POST / HTTP/1.1
D [01/Sep/2004:22:10:25 -0500] ProcessIPPRequest: 5 status_code=0
D [01/Sep/2004:22:10:25 -0500] ReadClient() 5 POST / HTTP/1.1
D [01/Sep/2004:22:10:25 -0500] ProcessIPPRequest: 5 status_code=0
D [01/Sep/2004:22:10:25 -0500] ReadClient() 5 GET /printers/lp0.ppd HTTP/1.1
D [01/Sep/2004:22:10:25 -0500] SendError() 5 code=404 (Not Found)
D [01/Sep/2004:22:10:25 -0500] CloseClient() 5
D [01/Sep/2004:22:10:27 -0500] AcceptClient() 5 from localhost:631.
D [01/Sep/2004:22:10:27 -0500] ReadClient() 5 POST /printers/lp0 HTTP/1.1
D [01/Sep/2004:22:10:27 -0500] print_job: auto-typing file...
D [01/Sep/2004:22:10:27 -0500] print_job: request file type is application/postscript.
D [01/Sep/2004:22:10:27 -0500] check_quotas: requesting-user-name = 'britt'
D [01/Sep/2004:22:10:27 -0500] print_job: requesting-user-name = 'britt'
I [01/Sep/2004:22:10:27 -0500] Job 5 queued on 'lp0' by 'britt'.
D [01/Sep/2004:22:10:27 -0500] Job 5 hold_until = 0
D [01/Sep/2004:22:10:27 -0500] StartJob(5, 0x99334a8)
D [01/Sep/2004:22:10:27 -0500] StartJob() id = 5, file = 0/1
D [01/Sep/2004:22:10:27 -0500] StartJob: Sending job to queue tagged as raw...
D [01/Sep/2004:22:10:27 -0500] No job-sheets attribute.
D [01/Sep/2004:22:10:27 -0500] banner_page = 0
D [01/Sep/2004:22:10:27 -0500] StartJob: argv = "lp0@pine.brittsplace.com","5","britt","","1","job-hold-until=no-hold job-priority=50","/var/spool/cups/d00005-001"
D [01/Sep/2004:22:10:27 -0500] StartJob: envp[0]="PATH=/usr/lib/cups/filter:/bin:/usr/bin"
D [01/Sep/2004:22:10:27 -0500] StartJob: envp[1]="SOFTWARE=CUPS/1.1"
D [01/Sep/2004:22:10:27 -0500] StartJob: envp[2]="USER=root"
D [01/Sep/2004:22:10:27 -0500] StartJob: envp[3]="CHARSET=utf-8"
D [01/Sep/2004:22:10:27 -0500] StartJob: envp[4]="LANG=en_US"
D [01/Sep/2004:22:10:27 -0500] StartJob: envp[5]="PPD=/etc/cups/ppd/lp0@pine.brittsplace.com.ppd"
D [01/Sep/2004:22:10:27 -0500] StartJob: envp[6]="CUPS_SERVERROOT=/etc/cups"
D [01/Sep/2004:22:10:27 -0500] StartJob: envp[7]="RIP_MAX_CACHE=8m"
D [01/Sep/2004:22:10:27 -0500] StartJob: envp[8]="TMPDIR=/var/spool/cups/tmp"
D [01/Sep/2004:22:10:27 -0500] StartJob: envp[9]="CONTENT_TYPE=application/postscript"
D [01/Sep/2004:22:10:27 -0500] StartJob: envp[10]="DEVICE_URI=ipp://pine.brittsplace.com:631/printers/lp0"
D [01/Sep/2004:22:10:27 -0500] StartJob: envp[11]="PRINTER=lp0@pine.brittsplace.com"
D [01/Sep/2004:22:10:27 -0500] StartJob: envp[12]="CUPS_DATADIR=/usr/share/cups"
D [01/Sep/2004:22:10:27 -0500] StartJob: envp[13]="CUPS_FONTPATH=/usr/share/cups/fonts"
D [01/Sep/2004:22:10:27 -0500] StartJob: envp[14]="CUPS_SERVER=localhost"
D [01/Sep/2004:22:10:27 -0500] StartJob: envp[15]="IPP_PORT=631"
D [01/Sep/2004:22:10:27 -0500] StartJob: envp[16]="CLASS=lp0"
D [01/Sep/2004:22:10:27 -0500] StartJob: statusfds = [ 8 9 ]
D [01/Sep/2004:22:10:27 -0500] StartJob: filterfds[1] = [ 10 -1 ]
D [01/Sep/2004:22:10:27 -0500] StartJob: backend = "/usr/lib/cups/backend/ipp"
D [01/Sep/2004:22:10:27 -0500] StartJob: filterfds[0] = [ -1 11 ]
D [01/Sep/2004:22:10:27 -0500] start_process("/usr/lib/cups/backend/ipp", 0xfee4cfe0, 0xfee4c350, 10, 11, 9)
I [01/Sep/2004:22:10:27 -0500] Started backend /usr/lib/cups/backend/ipp (PID 3807) for job 5.
D [01/Sep/2004:22:10:27 -0500] ProcessIPPRequest: 5 status_code=0
D [01/Sep/2004:22:10:27 -0500] AcceptClient() 9 from localhost:631.
D [01/Sep/2004:22:10:27 -0500] ReadClient() 9 POST / HTTP/1.1
D [01/Sep/2004:22:10:27 -0500] ProcessIPPRequest: 9 status_code=1
D [01/Sep/2004:22:10:33 -0500] UpdateJob: job 5, file 0 is complete.
D [01/Sep/2004:22:10:33 -0500] CancelJob: id = 5
D [01/Sep/2004:22:10:33 -0500] StopJob: id = 5, force = 0
D [01/Sep/2004:22:10:33 -0500] StopJob: printer state is 3
E [01/Sep/2004:22:10:33 -0500] PID 3807 stopped with status 1!
D [01/Sep/2004:22:10:33 -0500] ReadClient() 9 POST / HTTP/1.1
D [01/Sep/2004:22:10:33 -0500] ProcessIPPRequest: 9 status_code=1
D [01/Sep/2004:22:10:39 -0500] CloseClient() 5

On the server, there is nothing in /var/log/cups/access_log for 01/Sep. The only entries for the server's error_log for this day are as follows:

I [01/Sep/2004:04:02:06 -0500] Scheduler shutting down normally.
I [01/Sep/2004:04:02:07 -0500] Sending browsing info to ffffffff:631
I [01/Sep/2004:04:02:07 -0500] Listening to 0:631
I [01/Sep/2004:04:02:07 -0500] Loaded configuration file "/etc/cups/cupsd.conf"
I [01/Sep/2004:04:02:07 -0500] Configured for up to 100 clients.
I [01/Sep/2004:04:02:07 -0500] Allowing up to 100 client connections per host.
I [01/Sep/2004:04:02:07 -0500] Full reload is required.
I [01/Sep/2004:04:02:10 -0500] LoadPPDs: Read "/etc/cups/ppds.dat", 3388 PPDs...
I [01/Sep/2004:04:02:11 -0500] LoadPPDs: No new or changed PPDs...
I [01/Sep/2004:04:02:11 -0500] Full reload complete.