From: Daniel Lenski Date: Wed, 24 Feb 2021 05:03:47 +0000 (-0800) Subject: ppp-over-tls tests: try to keep CentOS 6 CI working, and improve flaky startup of... X-Git-Tag: v8.20~327^2~5 X-Git-Url: https://www.infradead.org/git/?a=commitdiff_plain;h=8a90c88be16a8940a449e8261faec53460ee7884;p=users%2Fdwmw2%2Fopenconnect.git ppp-over-tls tests: try to keep CentOS 6 CI working, and improve flaky startup of pppd Even with EPEL, CentOS has an old version of socat which doesn't support the 'rawer' option, so let's use the older 'raw,echo=0' combination to keep it limping along. More carefully try to verify that socat and pppd start up and connect to each other: - Wait for socat to create PTY in 1-second increments, and keep going until PTY actually exists (up to 15 seconds). - Wait for ppp to connect to PTY in 1-second increments, and keep going until pppd creates a "UUCP-style lockfile" for the PTY. - Log how long it takes for the above process to complete (socat and pppd combined startup) in the test output. Signed-off-by: Daniel Lenski --- diff --git a/tests/common.sh b/tests/common.sh index f0de258c..f125755d 100644 --- a/tests/common.sh +++ b/tests/common.sh @@ -73,19 +73,37 @@ launch_simple_pppd() { CERT="$1" KEY="$2" shift 2 + # The 'raw,echo=0' option is obsolete (http://www.dest-unreach.org/socat/doc/CHANGES), but its + # replacement 'rawer' isn't available until v1.7.3.0, which is newer than what we have available + # on our CentOS 6 CI image. LD_PRELOAD=libsocket_wrapper.so socat \ - PTY,rawer,b9600,link="$SOCKDIR/pppd.$$.pty" \ + PTY,raw,echo=0,b9600,link="$SOCKDIR/pppd.$$.pty" \ OPENSSL-LISTEN:443,verify=0,cert="$CERT",key="$KEY" 2>&1 & PID=$! - sleep 3 # Wait for socat to create the PTY link + # Wait for socat to create the PTY link + for ii in `seq 15`; do + PTY=`readlink "$SOCKDIR/pppd.$$.pty"` + test -n "$PTY" && break + sleep 1 + done # It would be preferable to invoke `pppd notty` directly using socat, but it seemingly cannot handle # being wrapped by libsocket_wrapper.so. # pppd's option parsing is notably brittle: it must have the actual PTY device node, not a symlink - $SUDO $PPPD $(readlink "$SOCKDIR/pppd.$$.pty") noauth local debug nodetach nodefaultroute logfile "$LOGFILE" $* 2>&1 & + $SUDO $PPPD "$PTY" noauth lock local debug nodetach nodefaultroute logfile "$LOGFILE" $* 2>&1 & PID="$PID $!" + # Wait for pppd to create the "UUCP-style lockfile" indicating that it has started + # (https://refspecs.linuxfoundation.org/FHS_3.0/fhs/ch05s09.html) + for ii in `seq 15`; do + case "$PTY" in + /dev/pts/*) test -e "/var/lock/LCK..pts_`basename $PTY`" && break ;; + *) test -e "/var/lock/LCK..`basename $PTY`" && break ;; + esac + sleep 1 + done + # XX: Caller needs to use PID, rather than $! } diff --git a/tests/ppp-over-tls b/tests/ppp-over-tls index 2aa4ba59..1b041d41 100755 --- a/tests/ppp-over-tls +++ b/tests/ppp-over-tls @@ -43,77 +43,107 @@ TIMEOUT_3S_IDLE="idle 3" echo "Testing PPP ... " -echo -n "Connecting to PPP peer (HDLC/RFC1662, IPv4+IPv6, DNS, extraneous VJ and CCP)... " +echo -n "Starting PPP peer (HDLC/RFC1662, IPv4+IPv6, DNS, extraneous VJ and CCP)... " +start=$(date +%s) launch_simple_pppd $CERT $KEY $HDLC_YES $IPV4_YES $OFFER_DNS $IPV6_YES 2>&1 +echo "started in $(( $(date +%s) - start )) seconds" wait_server "$PID" +echo -n "Connecting to it with openconnect --protocol=nullppp... " start=$(date +%s) LD_PRELOAD=libsocket_wrapper.so $OPENCONNECT -q --protocol=nullppp $ADDRESS:443 -u test $FINGERPRINT --cookie "hdlc,term" -Ss '' >/dev/null 2>&1 took=$(( $(date +%s) - start )) if grep -qF "$IPV4_SUCCESS_1" $LOGFILE && grep -qF "$IPV4_SUCCESS_2" $LOGFILE && grep -qF "$IPV6_SUCCESS_1" $LOGFILE && grep -qF "$IPV6_SUCCESS_2" $LOGFILE; then echo "ok (took $took seconds)" else - fail "$PID" "Did not negotiate IPCP and IP6CP successfully." + echo "failed (after $took seconds)" + echo "Log from pppd"; echo "===== START pppd log =====" cat $LOGFILE + echo "===== END pppd log =====" + fail "$PID" "Did not negotiate IPCP and IP6CP successfully." fi cleanup -echo -n "Connecting to PPP peer (HDLC/RFC1662, IPv4+IPv6, DNS, extraneous VJ and CCP, no header compression)... " +echo -n "Starting PPP peer (HDLC/RFC1662, IPv4+IPv6, DNS, extraneous VJ and CCP, no header compression)... " +start=$(date +%s) launch_simple_pppd $CERT $KEY $HDLC_YES $IPV4_YES $OFFER_DNS $IPV6_YES $NO_HDR_COMP 2>&1 +echo "started in $(( $(date +%s) - start )) seconds" wait_server "$PID" +echo -n "Connecting to it with openconnect --protocol=nullppp... " start=$(date +%s) LD_PRELOAD=libsocket_wrapper.so $OPENCONNECT -q --protocol=nullppp $ADDRESS:443 -u test $FINGERPRINT --cookie "hdlc,term" -Ss '' >/dev/null 2>&1 took=$(( $(date +%s) - start )) if grep -qF "$IPV4_SUCCESS_1" $LOGFILE && grep -qF "$IPV4_SUCCESS_2" $LOGFILE && grep -qF "$IPV6_SUCCESS_1" $LOGFILE && grep -qF "$IPV6_SUCCESS_2" $LOGFILE; then echo "ok (took $took seconds)" else - fail "$PID" "Did not negotiate IPCP and IP6CP successfully." + echo "failed (after $took seconds)" + echo "Log from pppd"; echo "===== START pppd log =====" cat $LOGFILE + echo "===== END pppd log =====" + fail "$PID" "Did not negotiate IPCP and IP6CP successfully." fi cleanup -echo -n "Connecting to PPP peer (sync/no-HDLC, IPv4+IPv6, DNS, extraneous VJ and CCP)... " +echo -n "Starting PPP peer (sync/no-HDLC, IPv4+IPv6, DNS, extraneous VJ and CCP)... " +start=$(date +%s) launch_simple_pppd $CERT $KEY $HDLC_NO $IPV4_YES $OFFER_DNS $IPV6_YES 2>&1 +echo "started in $(( $(date +%s) - start )) seconds" wait_server "$PID" +echo -n "Connecting to it with openconnect --protocol=nullppp... " start=$(date +%s) LD_PRELOAD=libsocket_wrapper.so $OPENCONNECT -q --protocol=nullppp $ADDRESS:443 -u test $FINGERPRINT --cookie "term" -Ss '' >/dev/null 2>&1 took=$(( $(date +%s) - start )) if grep -qF "$IPV4_SUCCESS_1" $LOGFILE && grep -qF "$IPV4_SUCCESS_2" $LOGFILE && grep -qF "$IPV6_SUCCESS_1" $LOGFILE && grep -qF "$IPV6_SUCCESS_2" $LOGFILE; then echo "ok (took $took seconds)" else - fail "$PID" "Did not negotiate IPCP and IP6CP successfully." + echo "failed (after $took seconds)" + echo "Log from pppd"; echo "===== START pppd log =====" cat $LOGFILE + echo "===== END pppd log =====" + fail "$PID" "Did not negotiate IPCP and IP6CP successfully." fi cleanup -echo -n "Connecting to PPP peer (HDLC/RFC1662, IPv4 only)... " +echo -n "Starting PPP peer (HDLC/RFC1662, IPv4 only)... " +start=$(date +%s) launch_simple_pppd $CERT $KEY $HDLC_YES $NO_JUNK_COMP $IPV4_YES $IPV6_NO 2>&1 +echo "started in $(( $(date +%s) - start )) seconds" wait_server "$PID" +echo -n "Connecting to it with openconnect --protocol=nullppp... " start=$(date +%s) LD_PRELOAD=libsocket_wrapper.so $OPENCONNECT -q --protocol=nullppp $ADDRESS:443 -u test $FINGERPRINT --cookie "hdlc,term" -Ss '' >/dev/null 2>&1 took=$(( $(date +%s) - start )) if grep -qF "$IPV4_SUCCESS_1" $LOGFILE && grep -qF "$IPV4_SUCCESS_2" $LOGFILE; then echo "ok (took $took seconds)" else - fail "$PID" "Did not negotiate IPCP successfully." + echo "failed (after $took seconds)" + echo "Log from pppd"; echo "===== START pppd log =====" cat $LOGFILE + echo "===== END pppd log =====" + fail "$PID" "Did not negotiate IPCP successfully." fi cleanup -echo -n "Connecting to PPP peer (HDLC/RFC1662, IPv6 only, 3s idle timeout)... " +echo -n "Starting PPP peer (HDLC/RFC1662, IPv6 only, 3s idle timeout)... " +start=$(date +%s) launch_simple_pppd $CERT $KEY $HDLC_YES $NO_JUNK_COMP $IPV4_NO $IPV6_YES $TIMEOUT_3S_IDLE 2>&1 +echo "started in $(( $(date +%s) - start )) seconds" wait_server "$PID" +echo -n "Connecting to it with openconnect --protocol=nullppp... " start=$(date +%s) LD_PRELOAD=libsocket_wrapper.so $OPENCONNECT -q --protocol=nullppp $ADDRESS:443 -u test $FINGERPRINT --cookie "hdlc" -Ss '' >/dev/null 2>&1 took=$(( $(date +%s) - start )) if grep -qF "$IPV6_SUCCESS_1" $LOGFILE && grep -qF "$IPV6_SUCCESS_2" $LOGFILE; then echo "ok (took $took seconds)" else - fail "$PID" "Did not negotiate IP6CP successfully." + echo "failed (after $took seconds)" + echo "Log from pppd"; echo "===== START pppd log =====" cat $LOGFILE + echo "===== END pppd log =====" + fail "$PID" "Did not negotiate IP6CP successfully." fi cleanup