[offtopic] Incomplete data received with scripted netcat that emulates a JetDirect printjob receiver

[Kurt Pfeifle]

Executive Summary:
==================
I'm trying to create a primitive port listener for CUPS which emulates AppSocket/JetDirect behaviour. It is meant to forward incoming jobs to a certain printer (say, "targetprinter at cupshost"). For that purpose I'm using a shell (Bash) script that utilizes netcat to listen on the receiving port (let's say, 9111).

All works perfectly well directly in the shell. But I have problems receiving the full job when I run this basic setup via a set of scripts.

(This is not a CUPS problem, I know. But I still hope some more knowledgable Bash scripter (on this list) than I am can pinpoint the exact cause of the problem and help me solve it.)


Details for interested readers:
===============================
First, how it works directly in the shell...

I start the listener like this in one console window on my host, that currently has (amongst others) the IP address 11.12.13.14:

-------- snip ----------------
while true; do
    netcat -v -v -w 3600 -n -s 11.12.13.14 -l -p 9111 \
    | lp -h cupshost -d targetprinter -
    sleep 1;
done
-------- snap ----------------

To print to this listener, you may use any CUPS queue with a "socket://11.12.13.14:9111" backend (or the respective Windows variant of such a backend, called "port monitor").

However, when I try to transfer this concept into a set of scripts, something goes wrong, and I have no clue why.

My scripts are 3:

 1. /etc/init.d/rclistener
 2. /usr/local/bin/listener-watchdog
 3. /usr/local/bin/listener-wrapper


ad 1: "rclistener" automatically starts the "listener-watchdog" (in the background) via the standard SysV concept.

ad 2: "listener-watchdog" holds a variant of the above loop: basically: "while true; listener-wrapper; done".

ad 3.: "listener-wrapper" runs the listening netcat and pipes the incoming data to the CUPS queue.

This works only for "small" printjobs. Larger jobs get truncated and therefore do not print.

You may reproduce the problem without wasting too much harddisk space (or without even running CUPS) by using this variant of a listener, that does not involve piping to a CUPS queue, but to a compressed file (to be started in one console window):

-------- snip ----------------
while true; do
    now=$(date +%s)
    netcat -v -v -w 3600 -n -s 11.12.13.14 -l -p 9111 \
    | gzip - \
    > /var/spool/netcat/${now}.prn \
    && gzip /var/spool/netcat/${now}.prn
    sleep 1;
done
-------- snap ----------------


As "sender", we can use a different virtual IP address on the same host which we created with the command

    ifconfig eth0:1 10.0.1.2

On the sender, instead of a CUPS client we'll use another (sending) netcat that uses highly compressible file created by /dev/null output:

-------- snip ----------------
while true; do
    dd if=/dev/zero bs=512 count=1000000 \
    | nc -n -vvv -s 10.0.1.2 11.12.13.14 9111;
    sleep 1;
done
-------- snap ----------------

This setup reliably sends chunks of 510,200,000 Bytes to the listener side which stores it to double-compressed files of a size of 272 Bytes each (be careful when you expand them again -- they are "nullbyte bombs" that can easily eat your available disk space).

(On both sides, listener and receiver, use [ctrl]+[c] to stop the respective loops...)

On the sending side, you'll see a repetition of this output of netcat on stderr:

   (UNKNOWN) [11.12.13.14] 22222 (?) open
   1000000+0 records in
   1000000+0 records out
   512000000 bytes (512 MB) copied, 17.497 s, 29.3 MB/s
     sent 512000000, rcvd 0

The receiving netcat will output this:

   listening on [11.12.13.14] 22222 ...
   connect to [11.12.13.14] from (UNKNOWN) [10.0.1.2] 25261
     sent 0, rcvd 512000000


However, this basic setup stops working reliably, when I put the listener setup into this set of 3 scripts:

-------- snip rclistener ----------------
%  cat /etc/init.d/rclistener
#!/bin/bash
case $1 in
'start')
    /usr/local/bin/listener-watchdog &
    sleep 1
    $0 status
    ;;
'stop')
    lpid=$(ps aux|grep "/bin/bash /usr/local/bin/listener-watchdog"|grep -v grep|awk '{print $2}')
    if [[ -n ${lpid} ]]; then
        kill ${lpid}
    fi
    sleep 1
    $0 status
    ;;
'status')
    lpid=$(ps aux|grep "/bin/bash /usr/local/bin/listener-watchdog"|grep -v grep|awk '{print $2}')
    if [[ -n ${lpid} ]]; then
        echo "netcat listener watchdog is running with PID ${lpid}"
    else
        echo "no netcat listener running."
    fi
    ;;
*)
    echo "Usage: $0 start|stop|status"
    ;;
esac
-------- snap ----------------

Note, how the startscript needs to put the "listener-watchdog" into the background, otherwise it would not return immediately.

The watchdog is creating a "while true; ...; done" loop the netcat listener to run in:

-------- snip listener-watchdog ----------------
%  cat /usr/local/bin/listener-watchdog
#!/bin/bash
while true; do
  /usr/local/bin/listener-wrapper
done
-------- snap ----------------


Finally, the wrapper itself. It

-------- snip listener-wrapper ----------------
%  cat /usr/local/bin/listener-wrapper
#!/bin/bash
now=$(date +%s)
        netcat -l -v -v -w 3600 -n -s 11.12.13.14 -p 9111 \
        2>>/var/log/cups/netcat_err.log \
        | gzip - \
        > /var/spool/netcat/${now}.prn \
        && gzip /var/spool/netcat/${now}.prn
sleep 1;
-------- snap ----------------


Now the problem is this: when I send small files, everything works fine. When I send big ones (like above, chunks of 512,000,000 Bytes), they get truncated at arbitrary multiples of 8192 Bytes. See this log extract:

   (UNKNOWN) [11.12.13.14] 22222 (?) open
    sent 8192, rcvd 0
   (UNKNOWN) [11.12.13.14] 22222 (?) open
    sent 196608, rcvd 0
   (UNKNOWN) [11.12.13.14] 22222 (?) open
    sent 189440, rcvd 0
   (UNKNOWN) [11.12.13.14] 22222 (?) open
    sent 73728, rcvd 0
   (UNKNOWN) [11.12.13.14] 22222 (?) open
    sent 8192, rcvd 0

If I remove the "&" from the listener-watchdog call in the "rc-listener" startup script, that script does not return the shell console to me. However, if I use "^Z;bg" to put it into the background, it works perfectly, and all data arrive without fail.

I'm at my wits' end. It seems to be connected to the mentioned backgrounding of the "listener-watchdog" call inside the "rclistener" script.

Why...
   ...does putting that one line directly into the background inside
      the script *not* work,
   ...while calling it normally, but instead putting the whole script
      manually into the background work

????