Problems with LPD inbound jobs

Paul Conklin paul.conklin at cerner.com
Wed Feb 22 10:20:49 PST 2012


I figured out how to turn on logging for cups-lpd

from xinetd
Service configuration: printer
        id = printer
        flags = IPv4
        socket_type = stream
        Protocol (name,number) = (tcp,6)
        port = 515
        wait = no
        user = 4
        group = 3
        Groups = yes
        umask = 2
        PER_SOURCE = 10
        Bind = All addresses.
        Server = /usr/lib/cups/daemon/cups-lpd
        Server argv = cups-lpd -o document-format=application/octet-stream
        Only from: All sites
        No access: No blocked sites
        Logging to file: /var/log/cups/cups-lpd.log (no limits)
        Log_on_success flags = HOST DURATION EXIT PID
        Log_on_failure flags = HOST
        Passenv =
        Environment strings:


from the log
12/2/22 at 12:16:56: START: printer pid=19309 from=10.190.250.49
12/2/22 at 12:16:56: EXIT: printer status=1 pid=19309 duration=0(sec)

so it appears that cups-lpd actually thinks it was successful, but the lpdbackend errors out.
> debug info from xinetd
> 12/2/22 at 12:03:10: DEBUG: 16162 {main_loop} select returned 1
> 12/2/22 at 12:03:10: DEBUG: 16162 {server_start} Starting service printer
> 12/2/22 at 12:03:10: DEBUG: 16162 {main_loop} active_services = 2
> 12/2/22 at 12:03:10: DEBUG: 16354 {exec_server} duping 8
> 12/2/22 at 12:03:10: DEBUG: 16162 {main_loop} active_services = 2
> 12/2/22 at 12:03:10: DEBUG: 16162 {main_loop} select returned 1
> 12/2/22 at 12:03:10: DEBUG: 16162 {check_pipe} Got signal 17 (Child exited)
> 12/2/22 at 12:03:10: DEBUG: 16162 {child_exit} waitpid returned = 16354
> 12/2/22 at 12:03:10: DEBUG: 16162 {server_end} printer server 16354 exited
> 12/2/22 at 12:03:10: INFO: 16162 {conn_free} freeing connection
> 12/2/22 at 12:03:10: DEBUG: 16162 {child_exit} waitpid returned = -1
> 12/2/22 at 12:03:10: DEBUG: 16162 {main_loop} active_services = 2
>
>
> > I am, I am only using 515.  just to rule out other hosts, i set up 2 queues.  eventually I'm trying to print to paul from AIX via LPD
> >
> > so I have paul (socket queue to actual printer)
> > and paul2 (lpd queue pointing to paul)
> >
> > so if i print to paul2, it should make it to paul by way of lpd and to the printer.  I've tried using lpd to connect to paul from both AIX and Windows, and i can connect, but it errors out.  Looking through the logs it appears that it connects, sends data, and the mini-server doesn't respond (or responds incorrectly)  that's why I set up paul2 to simulate the same thing, but rules out networking and everything else.
> >
> > Make sense?
> >
> > > Paul Conklin wrote:
> > >
> > > > 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.
> > >
> > > Try to use only reserved ports with the LPD backend (URI option).
> > >
> > > Helge
> > >
> >
>





More information about the cups mailing list