[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

You can also use

      ifconfig lo: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

Actually, above output comes from an experiment that I did on Port 22222 (not 9111 as used in the script). But the result was the same in either case.

> 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
>
> ????