PerfTest connection recovery

.gitignore

*env*/
*.pcap*
logs/
rabbitmq-perf-test*/
toxiproxy-*-amd64

README.md

Issue

Running repro.bash while RabbitMQ is running and listening on port 5672 will reproduce the issue:

• Download artifacts
• Start up toxiproxy-server listening on port 55672, forwarding to RMQ
• Start up PerfTest with defaults connecting to port 55672
• After 10 seconds, disable TCP proxy which immediately kills the connection
• After 30 seconds, re-enable TCP proxy
• You will see PerfTest try to reconnect, but the following is logged by RabbitMQ:

  2018-07-17 15:21:27.432 [warning] <0.23374.2> closing AMQP connection <0.23374.2> (127.0.0.1:19192 -> 127.0.0.1:5672 - perf-test-consumer-0):
  {handshake_timeout,frame_header}
  

• The following is the exception shown by PerfTest:

  15:21:27.442 [AMQP Connection 127.0.0.1:55672] ERROR com.rabbitmq.client.impl.ForgivingExceptionHandler - Caught an exception during connection recovery!
  java.util.concurrent.RejectedExecutionException: Task java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask@7268228e rejected from java.util.concurrent.ScheduledThreadPoolExecutor@744259fb[Terminated, pool size = 0, active threads = 0, queued tasks = 0, completed tasks = 0]
          at java.util.concurrent.ThreadPoolExecutor$AbortPolicy.rejectedExecution(ThreadPoolExecutor.java:2063)
          at java.util.concurrent.ThreadPoolExecutor.reject(ThreadPoolExecutor.java:830)
          at java.util.concurrent.ScheduledThreadPoolExecutor.delayedExecute(ScheduledThreadPoolExecutor.java:326)
          at java.util.concurrent.ScheduledThreadPoolExecutor.scheduleAtFixedRate(ScheduledThreadPoolExecutor.java:573)
          at com.rabbitmq.client.impl.HeartbeatSender.setHeartbeat(HeartbeatSender.java:85)
          at com.rabbitmq.client.impl.AMQConnection.setHeartbeat(AMQConnection.java:479)
          at com.rabbitmq.client.impl.AMQConnection.start(AMQConnection.java:394)
          at com.rabbitmq.client.impl.recovery.RecoveryAwareAMQConnectionFactory.newConnection(RecoveryAwareAMQConnectionFactory.java:64)
          at com.rabbitmq.client.impl.recovery.AutorecoveringConnection.recoverConnection(AutorecoveringConnection.java:585)
          at com.rabbitmq.client.impl.recovery.AutorecoveringConnection.beginAutomaticRecovery(AutorecoveringConnection.java:547)
          at com.rabbitmq.client.impl.recovery.AutorecoveringConnection.access$000(AutorecoveringConnection.java:58)
          at com.rabbitmq.client.impl.recovery.AutorecoveringConnection$3.recoveryCanBegin(AutorecoveringConnection.java:488)
          at com.rabbitmq.client.impl.AMQConnection.notifyRecoveryCanBeginListeners(AMQConnection.java:748)
          at com.rabbitmq.client.impl.AMQConnection.doFinalShutdown(AMQConnection.java:725)
          at com.rabbitmq.client.impl.AMQConnection$MainLoop.run(AMQConnection.java:609)
          at java.lang.Thread.run(Thread.java:748)
  

repro.bash

#!/usr/bin/env bash

set -o errexit
set -o nounset

readonly debug='false'
readonly curdir="$(realpath "$PWD")"

declare -i toxiproxy_server_pid=0
declare -i perftest_pid=0

function command_exists
{
    command -v "$1" > /dev/null 2>&1
}

function now
{
    date '+%Y-%m-%d %H:%M:%S'
}

function pwarn
{
    echo "$(now) [warning]: $*" 1>&2
}

function perr
{
    echo "$(now) [error]: $*" 1>&2
}

function pinfo
{
    echo "$(now) [info]: $*"
}

function pinfo_n
{
    echo -n "$(now) [info]: $*"
}

function pdebug
{
    if [[ $debug == 'true' ]]
    then
        echo "$(now) [debug]: $*"
    fi
}

function errexit
{
    perr "$@"
    exit 1
}

function onexit
{
    set +o errexit
    if (( toxiproxy_server_pid > 0 ))
    then
        kill "$toxiproxy_server_pid"
    fi
    if (( perftest_pid > 0 ))
    then
        kill "$perftest_pid"
    fi
    set -o errexit
    return 0
}

trap onexit EXIT

if (( BASH_VERSINFO != 4 ))
then
    errexit "this script requires bash version 4"
fi

readonly uname="$(uname)"
readonly uname_lc="${uname,,}"

if ! command_exists curl
then
    errexit "please ensure curl is in PATH"
fi
if ! command_exists jq
then
    errexit "please ensure jq is in PATH"
fi
if ! command_exists java
then
    errexit "please ensure java is in PATH"
fi

readonly perf_test_rel_json="$(curl -s https://api.github.com/repos/rabbitmq/rabbitmq-perf-test/releases/latest)"
readonly perf_test_rel_name="$(jq -r '.name' <<< "$perf_test_rel_json")"

readonly runjava="$curdir/rabbitmq-perf-test-$perf_test_rel_name/bin/runjava"

if [[ -x $runjava ]]
then
    pinfo "PerfTest runjava exists at $runjava"
else
    readonly perf_test_archive="rabbitmq-perf-test-$perf_test_rel_name-bin.tar.gz"
    pinfo_n "downloading and extracting $perf_test_archive..."
    readonly perf_test_download_url="$(jq -r ".assets[] | select(.name == \"$perf_test_archive\") | .browser_download_url" <<< "$perf_test_rel_json")"
    curl -sLO "$perf_test_download_url"
    tar xf "$perf_test_archive"
    echo 'done'
fi

readonly perftest="$runjava com.rabbitmq.perf.PerfTest"

readonly toxiproxy_cli="$curdir/toxiproxy-cli-$uname_lc-amd64"
readonly toxiproxy_server="$curdir/toxiproxy-server-$uname_lc-amd64"

if [[ -x $toxiproxy_cli && -x $toxiproxy_server ]]
then
    pinfo "toxiproxy cli and server exist in $curdir"
else
    readonly toxiproxy_json="$(curl -s https://api.github.com/repos/Shopify/toxiproxy/releases/latest)"
    for toxibin in "toxiproxy-cli-$uname_lc-amd64" "toxiproxy-server-$uname_lc-amd64"
    do
        pinfo_n "downloading $toxibin..."
        browser_download_url="$(jq -r ".assets[] | select(.name == \"$toxibin\") | .browser_download_url" <<< "$toxiproxy_json")"
        curl -sLO "$browser_download_url"
        chmod 755 "$toxibin"
        echo 'done'
    done
fi

"$toxiproxy_server" --config "$curdir/toxiproxy.json" &
toxiproxy_server_pid="$!"
sleep 5

$perftest --uri 'amqp://guest:guest@localhost:55672' &
perftest_pid="$!"

# Wait for PerfTest to get going
sleep 10

# Introduce a rule to timeout connections
# "$toxiproxy_cli" toxic add --toxicName amqp_5672_timeout --type timeout --attribute timeout=5000 --downstream amqp_5672

# Toggle status of proxy
"$toxiproxy_cli" toggle amqp_5672

# Wait a while for mayhem to ensue
sleep 30

# Remove rule to timeout connections, PerfTest should recover
# "$toxiproxy_cli" toxic remove --toxicName amqp_5672_timeout amqp_5672

# Toggle status of proxy to re-enable
"$toxiproxy_cli" toggle amqp_5672

wait

toxiproxy.json

[
  {
    "name": "amqp_5672",
    "listen": "127.0.0.1:55672",
    "upstream": "127.0.0.1:5672"
  }
]