cupsd "Error: Couldn't open file"

[John A. Murdie]

I've just made a new server installation of CUPS, for the first time on a Linux system (10.0.1.34) as an experimental vehicle. (The older existing cupsd on this system has been stopped.) We've been running a "production" CUPS server on a Solaris system here (for Linux clients) since September last year and it's been reliable, but there are aspects of CUPS' behaviour that I wish to understand, yet I cannot interrupt service. The experimental installation was made with:

# tar xvfj cups-1.2.7-source.tar.bz2
# ./configure --prefix=/usr/local/pkg/cups-1.2.7 --localstatedir=/var/spool/cups-1.2.7
# make
# make install
-- make the follow alterations to cupsd.conf to allow a Linux client (10.0.1.39) to use and administrate the server:
---
11c11
< LogLevel info
---
> LogLevel debug
17,18c17,18
< Listen localhost:631
< Listen /var/spool/cups-1.2.7/run/cups/cups.sock
---
> Listen 631
> #Listen /var/spool/cups-1.2.7/run/cups/cups.sock
23a24
> BrowseAddress @LOCAL
31a33
>   Allow 10.0.1.39
38a41
>   Allow 10.0.1.39
46a50
>   Allow 10.0.1.39
---
# cp HP_LaserJet_8150_Series.ppd /usr/local/pkg/cups-1.2.7/share/cups/model
# /usr/local/pkg/cups-1.2.7/sbin/cupsd
# ps -ef | fgrep cupsd
root      9436     1  0 12:09 ?        00:00:00 /usr/local/pkg/cups-1.2.7/sbin/cupsd
#

I start a browser on both a client (10.0.1.39) on the same subnet as my experimental server (a Slackware Linux 11.0 client with an 'out-of-the-box' CUPS 1.2.4 installation) and the server - http://10.0.1.34:631/ on the first, http://localhost:631/ on the second,
then create a printer 'pp23' using the web interface and submit three jobs with three 'lpr -P pp23 lorem.pdf' commands in succession.

I wanted to see under what conditions did all three jobs go immediately to the server, and those in which only the first job goes and the other two stay behind on the client - because this aspect of CUPS' behaviour has caused confusion to users here. (Since lpq(1) shows the state of the local print queue and not that of the server, they have been asked to point a browser at http://cups:631/ - `cups' being our "production" print server - to see the status of their printing. They complain that jobs are slow getting from the client to the server, can't see them in the server queue via the browser, and so send things to print repeatedly, resulting in multiple copies! One user claims that some documents he queues on his client never reach the server, but I have no evidence of that.)

However, I run across a cupsd "Error: Couldn't open file" message in my experimental setup which prevents me from seeing what can be done about the reported problem(s). Even though I have on the server:

# ls -ld /var
drwxr-xr-x 19 root root 4096 2007-01-18 15:08 /var/
# ls -ld /var/spool
drwxr-xr-x 18 root root 4096 2007-02-12 18:32 /var/spool/
# ls -ld /var/spool/cups-1.2.7
drwxr-xr-x 6 root root 4096 2007-02-12 18:32 /var/spool/cups-1.2.7/
# ls -ld /var/spool/cups-1.2.7/spool
drwx--x--- 3 root root 4096 2007-02-12 18:32 /var/spool/cups-1.2.7/spool/
# ls -ld /var/spool/cups-1.2.7/spool/cups
drwx--x--- 3 root lp 4096 2007-02-13 12:36 /var/spool/cups-1.2.7/spool/cups/
# ls -l /var/spool/cups-1.2.7/spool/cups
total 64
-rw------- 1 root lp   662 2007-02-13 12:36 c00001
-rw------- 1 root lp   662 2007-02-13 12:36 c00002
-rw------- 1 root lp   662 2007-02-13 12:36 c00003
-rw-r----- 1 root lp 15131 2007-02-13 12:36 d00001-001
-rw-r----- 1 root lp 15131 2007-02-13 12:36 d00002-001
-rw-r----- 1 root lp 15131 2007-02-13 12:36 d00003-001
drwxrwx--T 2 root lp  4096 2007-02-12 18:32 tmp/
#

I see the error message:

D [13/Feb/2007:12:36:23 +0000] [Job 1] Connected to 144.32.40.62:9100 (IPv4)...
D [13/Feb/2007:12:36:23 +0000] [Job 1] backendRunLoop(print_fd=0, device_fd=4, use_bc=1)
D [13/Feb/2007:12:36:23 +0000] [Job 1] pdftops - opened PPD file "/usr/local/pkg/cups-1.2.7/etc/cups/ppd/pp23.ppd"...
D [13/Feb/2007:12:36:23 +0000] [Job 1] pdftops - level = 2, width = 595, length = 842
D [13/Feb/2007:12:36:23 +0000] [Job 1] Error: Couldn't open file '/var/spool/cups-1.2.7/spool/cups/d00001-001'
D [13/Feb/2007:12:36:23 +0000] [Job 1] Error: Unable to print this document.
E [13/Feb/2007:12:36:23 +0000] [Job 1] Empty print file!

(and ditto for the other two print jobs).

cupsd is running as root:

# ps -ef | fgrep cupsd
root      9436     1  0 12:09 ?        00:00:00 /usr/local/pkg/cups-1.2.7/sbin/cupsd
root      9971  9400  0 14:25 pts/0    00:00:00 fgrep cupsd
#

How can the error message be true? I've not altered the permissions on the spool directory since 'make install' created it.

John A. Murdie