Problems with LPD inbound jobs

Wed Feb 22 09:26:43 PST 2012

It seems to connect, but the cups-lpd mini-server doesn't seem to respond correctly  I've tried from AIX and Windows as well.

 [22/Feb/2012:11:24:35 -0600] [Job 246] Looking up "talinux02"...
D [22/Feb/2012:11:24:35 -0600] [Job 246] Connecting to talinux02:515 for printer paul
D [22/Feb/2012:11:24:35 -0600] [Job 246] Connecting to printer...
D [22/Feb/2012:11:24:35 -0600] [Job 246] Set job-printer-state-message to "Connecting to printer...", current level=INFO
D [22/Feb/2012:11:24:35 -0600] [Job 246] STATE: -connecting-to-device
D [22/Feb/2012:11:24:35 -0600] [Job 246] Connected to printer...
D [22/Feb/2012:11:24:35 -0600] [Job 246] Set job-printer-state-message to "Connected to printer...", current level=INFO
D [22/Feb/2012:11:24:35 -0600] [Job 246] Connected to 10.190.250.49:515 (IPv4) (local port 1023)...
D [22/Feb/2012:11:24:35 -0600] [Job 246] lpd_command 02 paul
D [22/Feb/2012:11:24:35 -0600] [Job 246] Sending command string (6 bytes)...
D [22/Feb/2012:11:24:35 -0600] [Job 246] Reading command status...
D [22/Feb/2012:11:24:35 -0600] [Job 246] lpd_command returning 1
D [22/Feb/2012:11:24:35 -0600] [Job 246] Backend returned status 1 (failed)
D [22/Feb/2012:11:24:35 -0600] [Job 246] Job held for 300 seconds since it could not be sent.
D [22/Feb/2012:11:24:35 -0600] [Job 246] End of messages
D [22/Feb/2012:11:24:35 -0600] [Job 246] printer-state=3(idle)
D [22/Feb/2012:11:24:35 -0600] [Job 246] printer-state-message="/usr/lib/cups/backend/lpd failed"
D [22/Feb/2012:11:24:35 -0600] [Job 246] printer-state-reasons=none

> I enabled the lpd miniserver in xinetd and i can telnet to port 515, but I can't even print from paul2 (lpd://talinux02/paul) to paul (socket://10.190.44.17:9100)
>
> Ideas?  RHEL 5.3 on CUPS 1.4.7
>
> Error_log
> root:talinux02 at talinux02:/etc/xinetd.d
> # grep "Job 238" /var/log/cups/error_log
> D [22/Feb/2012:10:45:13 -0600] [Job 238] Unloading...
> D [22/Feb/2012:10:45:13 -0600] [Job 238] Loading from cache...
> D [22/Feb/2012:10:45:13 -0600] [Job 238] Loading attributes...
> D [22/Feb/2012:10:46:03 -0600] [Job 238] Sending job to queue tagged as raw...
> D [22/Feb/2012:10:46:03 -0600] [Job 238] job-sheets=none,none
> D [22/Feb/2012:10:46:03 -0600] [Job 238] argv[0]="paul2"
> D [22/Feb/2012:10:46:03 -0600] [Job 238] argv[1]="238"
> D [22/Feb/2012:10:46:03 -0600] [Job 238] argv[2]="root"
> D [22/Feb/2012:10:46:03 -0600] [Job 238] argv[3]="test.txt"
> D [22/Feb/2012:10:46:03 -0600] [Job 238] argv[4]="1"
> D [22/Feb/2012:10:46:03 -0600] [Job 238] argv[5]="finishings=3 number-up=1 job-uuid=urn:uuid:a0d0c0c3-9ada-3cd5-5b03-c12e140566ee job-originating-host-name=localhost time-at-creation=1329928950 time-at-processing=1329929163"
> D [22/Feb/2012:10:46:03 -0600] [Job 238] argv[6]="/var/spool/cups/d00238-001"
> D [22/Feb/2012:10:46:03 -0600] [Job 238] envp[0]="CUPS_CACHEDIR=/var/cache/cups"
> D [22/Feb/2012:10:46:03 -0600] [Job 238] envp[1]="CUPS_DATADIR=/usr/share/cups"
> D [22/Feb/2012:10:46:03 -0600] [Job 238] envp[2]="CUPS_DOCROOT=/usr/share/doc/cups"
> D [22/Feb/2012:10:46:03 -0600] [Job 238] envp[3]="CUPS_FONTPATH=/usr/share/cups/fonts"
> D [22/Feb/2012:10:46:03 -0600] [Job 238] envp[4]="CUPS_REQUESTROOT=/var/spool/cups"
> D [22/Feb/2012:10:46:03 -0600] [Job 238] envp[5]="CUPS_SERVERBIN=/usr/lib/cups"
> D [22/Feb/2012:10:46:03 -0600] [Job 238] envp[6]="CUPS_SERVERROOT=/etc/cups"
> D [22/Feb/2012:10:46:03 -0600] [Job 238] envp[7]="CUPS_STATEDIR=/var/run/cups"
> D [22/Feb/2012:10:46:03 -0600] [Job 238] envp[8]="HOME=/var/spool/cups/tmp"
> D [22/Feb/2012:10:46:03 -0600] [Job 238] envp[9]="PATH=/usr/lib/cups/filter:/usr/bin:/usr/sbin:/bin:/usr/bin"
> D [22/Feb/2012:10:46:03 -0600] [Job 238] envp[10]="SERVER_ADMIN=root at talinux02"
> D [22/Feb/2012:10:46:03 -0600] [Job 238] envp[11]="SOFTWARE=CUPS/1.4.7.2"
> D [22/Feb/2012:10:46:03 -0600] [Job 238] envp[12]="TMPDIR=/var/spool/cups/tmp"
> D [22/Feb/2012:10:46:03 -0600] [Job 238] envp[13]="TZ=America/Chicago"
> D [22/Feb/2012:10:46:03 -0600] [Job 238] envp[14]="USER=root"
> D [22/Feb/2012:10:46:03 -0600] [Job 238] envp[15]="CUPS_SERVER=/var/run/cups/cups.sock"
> D [22/Feb/2012:10:46:03 -0600] [Job 238] envp[16]="CUPS_ENCRYPTION=IfRequested"
> D [22/Feb/2012:10:46:03 -0600] [Job 238] envp[17]="IPP_PORT=631"
> D [22/Feb/2012:10:46:03 -0600] [Job 238] envp[18]="CHARSET=utf-8"
> D [22/Feb/2012:10:46:03 -0600] [Job 238] envp[19]="LANG=en_US.UTF-8"
> D [22/Feb/2012:10:46:03 -0600] [Job 238] envp[20]="PPD=/etc/cups/ppd/paul2.ppd"
> D [22/Feb/2012:10:46:03 -0600] [Job 238] envp[21]="RIP_MAX_CACHE=8m"
> D [22/Feb/2012:10:46:03 -0600] [Job 238] envp[22]="CONTENT_TYPE=text/plain"
> D [22/Feb/2012:10:46:03 -0600] [Job 238] envp[23]="DEVICE_URI=lpd://talinux02/paul"
> D [22/Feb/2012:10:46:03 -0600] [Job 238] envp[24]="PRINTER_INFO=paul2"
> D [22/Feb/2012:10:46:03 -0600] [Job 238] envp[25]="PRINTER_LOCATION="
> D [22/Feb/2012:10:46:03 -0600] [Job 238] envp[26]="PRINTER=paul2"
> D [22/Feb/2012:10:46:03 -0600] [Job 238] envp[27]="CUPS_FILETYPE=document"
> I [22/Feb/2012:10:46:03 -0600] [Job 238] Started backend /usr/lib/cups/backend/lpd (PID 31755)
> D [22/Feb/2012:10:46:03 -0600] [Job 238] STATE: +connecting-to-device
> D [22/Feb/2012:10:46:03 -0600] [Job 238] Looking up "talinux02"...
> D [22/Feb/2012:10:46:03 -0600] [Job 238] Connecting to talinux02:515 for printer paul
> I [22/Feb/2012:10:46:03 -0600] [Job 238] Connecting to printer...
> D [22/Feb/2012:10:46:03 -0600] [Job 238] Set job-printer-state-message to "Connecting to printer...", current level=INFO
> D [22/Feb/2012:10:46:03 -0600] [Job 238] STATE: -connecting-to-device
> I [22/Feb/2012:10:46:03 -0600] [Job 238] Connected to printer...
> D [22/Feb/2012:10:46:03 -0600] [Job 238] Set job-printer-state-message to "Connected to printer...", current level=INFO
> D [22/Feb/2012:10:46:03 -0600] [Job 238] Connected to 10.190.250.49:515 (IPv4) (local port 1023)...
> D [22/Feb/2012:10:46:03 -0600] [Job 238] lpd_command 02 paul
> D [22/Feb/2012:10:46:03 -0600] [Job 238] Sending command string (6 bytes)...
> D [22/Feb/2012:10:46:03 -0600] [Job 238] Reading command status...
> D [22/Feb/2012:10:46:03 -0600] [Job 238] lpd_command returning 1
> I [22/Feb/2012:10:46:03 -0600] [Job 238] Backend returned status 1 (failed)
> I [22/Feb/2012:10:46:03 -0600] [Job 238] Printer stopped due to backend errors; please consult the error_log file for details.
> D [22/Feb/2012:10:46:28 -0600] [Job 238] Sending job to queue tagged as raw...
> D [22/Feb/2012:10:46:28 -0600] [Job 238] job-sheets=none,none
> D [22/Feb/2012:10:46:28 -0600] [Job 238] argv[0]="paul2"
> D [22/Feb/2012:10:46:28 -0600] [Job 238] argv[1]="238"
> D [22/Feb/2012:10:46:28 -0600] [Job 238] argv[2]="root"
> D [22/Feb/2012:10:46:28 -0600] [Job 238] argv[3]="test.txt"
> D [22/Feb/2012:10:46:28 -0600] [Job 238] argv[4]="1"
> D [22/Feb/2012:10:46:28 -0600] [Job 238] argv[5]="finishings=3 number-up=1 job-uuid=urn:uuid:a0d0c0c3-9ada-3cd5-5b03-c12e140566ee job-originating-host-name=localhost time-at-creation=1329928950 time-at-processing=1329929188"
> D [22/Feb/2012:10:46:28 -0600] [Job 238] argv[6]="/var/spool/cups/d00238-001"
> D [22/Feb/2012:10:46:28 -0600] [Job 238] envp[0]="CUPS_CACHEDIR=/var/cache/cups"
> D [22/Feb/2012:10:46:28 -0600] [Job 238] envp[1]="CUPS_DATADIR=/usr/share/cups"
> D [22/Feb/2012:10:46:28 -0600] [Job 238] envp[2]="CUPS_DOCROOT=/usr/share/doc/cups"
> D [22/Feb/2012:10:46:28 -0600] [Job 238] envp[3]="CUPS_FONTPATH=/usr/share/cups/fonts"
> D [22/Feb/2012:10:46:28 -0600] [Job 238] envp[4]="CUPS_REQUESTROOT=/var/spool/cups"
> D [22/Feb/2012:10:46:28 -0600] [Job 238] envp[5]="CUPS_SERVERBIN=/usr/lib/cups"
> D [22/Feb/2012:10:46:28 -0600] [Job 238] envp[6]="CUPS_SERVERROOT=/etc/cups"
> D [22/Feb/2012:10:46:28 -0600] [Job 238] envp[7]="CUPS_STATEDIR=/var/run/cups"
> D [22/Feb/2012:10:46:28 -0600] [Job 238] envp[8]="HOME=/var/spool/cups/tmp"
> D [22/Feb/2012:10:46:28 -0600] [Job 238] envp[9]="PATH=/usr/lib/cups/filter:/usr/bin:/usr/sbin:/bin:/usr/bin"
> D [22/Feb/2012:10:46:28 -0600] [Job 238] envp[10]="SERVER_ADMIN=root at talinux02"
> D [22/Feb/2012:10:46:28 -0600] [Job 238] envp[11]="SOFTWARE=CUPS/1.4.7.2"
> D [22/Feb/2012:10:46:28 -0600] [Job 238] envp[12]="TMPDIR=/var/spool/cups/tmp"
> D [22/Feb/2012:10:46:28 -0600] [Job 238] envp[13]="TZ=America/Chicago"
> D [22/Feb/2012:10:46:28 -0600] [Job 238] envp[14]="USER=root"
> D [22/Feb/2012:10:46:28 -0600] [Job 238] envp[15]="CUPS_SERVER=/var/run/cups/cups.sock"
> D [22/Feb/2012:10:46:28 -0600] [Job 238] envp[16]="CUPS_ENCRYPTION=IfRequested"
> D [22/Feb/2012:10:46:28 -0600] [Job 238] envp[17]="IPP_PORT=631"
> D [22/Feb/2012:10:46:28 -0600] [Job 238] envp[18]="CHARSET=utf-8"
> D [22/Feb/2012:10:46:28 -0600] [Job 238] envp[19]="LANG=en_US.UTF-8"
> D [22/Feb/2012:10:46:28 -0600] [Job 238] envp[20]="PPD=/etc/cups/ppd/paul2.ppd"
> D [22/Feb/2012:10:46:28 -0600] [Job 238] envp[21]="RIP_MAX_CACHE=8m"
> D [22/Feb/2012:10:46:28 -0600] [Job 238] envp[22]="CONTENT_TYPE=text/plain"
> D [22/Feb/2012:10:46:28 -0600] [Job 238] envp[23]="DEVICE_URI=lpd://talinux02/paul"
> D [22/Feb/2012:10:46:28 -0600] [Job 238] envp[24]="PRINTER_INFO=paul2"
> D [22/Feb/2012:10:46:28 -0600] [Job 238] envp[25]="PRINTER_LOCATION="
> D [22/Feb/2012:10:46:28 -0600] [Job 238] envp[26]="PRINTER=paul2"
> D [22/Feb/2012:10:46:28 -0600] [Job 238] envp[27]="CUPS_FILETYPE=document"
> I [22/Feb/2012:10:46:28 -0600] [Job 238] Started backend /usr/lib/cups/backend/lpd (PID 31849)
> D [22/Feb/2012:10:46:28 -0600] [Job 238] STATE: +connecting-to-device
> D [22/Feb/2012:10:46:28 -0600] [Job 238] Looking up "talinux02"...
> D [22/Feb/2012:10:46:28 -0600] [Job 238] Connecting to talinux02:515 for printer paul
> I [22/Feb/2012:10:46:28 -0600] [Job 238] Connecting to printer...
> D [22/Feb/2012:10:46:28 -0600] [Job 238] Set job-printer-state-message to "Connecting to printer...", current level=INFO
> D [22/Feb/2012:10:46:28 -0600] [Job 238] STATE: -connecting-to-device
> I [22/Feb/2012:10:46:28 -0600] [Job 238] Connected to printer...
> D [22/Feb/2012:10:46:28 -0600] [Job 238] Set job-printer-state-message to "Connected to printer...", current level=INFO
> D [22/Feb/2012:10:46:28 -0600] [Job 238] Connected to 10.190.250.49:515 (IPv4) (local port 1022)...
> D [22/Feb/2012:10:46:28 -0600] [Job 238] lpd_command 02 paul
> D [22/Feb/2012:10:46:28 -0600] [Job 238] Sending command string (6 bytes)...
> D [22/Feb/2012:10:46:28 -0600] [Job 238] Reading command status...
> D [22/Feb/2012:10:46:28 -0600] [Job 238] lpd_command returning 1
> I [22/Feb/2012:10:46:28 -0600] [Job 238] Backend returned status 1 (failed)
> I [22/Feb/2012:10:46:28 -0600] [Job 238] Printer stopped due to backend errors; please consult the error_log file for details.
>