SNI hook, blind tunnels and thread - strange behavior under load

[Lev Stipakov]

Hello,

I made a simple plugin that sets up TS_SSL_SNI_HOOK and creates a
blind tunnel from a separate thread. With low load everything works
fine, but with moderate load (100 simultaneous users, each user sends
200 HTTPS requests) I see somewhat strange behavior.

On a client side I use Tsung, which creates users and sends number of
requests per user. For each user Tsung waits for a response before
sending a new request, so if response never arrives, a particular user
(and the whole test) stalls.

So, with load mentioned above I see few 'stalled' connections on both
client and proxy – netstat shows them as ”established”, ATS seems to
have data structures for those (checked
proxy.process.net.connections_currently_open value), but no traffic
goes between proxy and client.

Client side (.175):

tcp 0 0 10.133.3.175:40737 10.133.3.250:443 ESTABLISHED 14332/beam.smp
(more similar connections here)

Proxy side (.250 is a server):
tcp 0 0 10.133.3.250:443 10.133.3.175:40737 ESTABLISHED 28117/traffic_serve
(more similar connections here)

I checked traffic.out log and found out that
”SSLNextProtocolAccept:mainEvent” does not get called as many times as
it should. This can probably be explained by the fact that client does
not send requests for given user anymore if response to previous
request hasn't been received. Which, in turn, may indicate that at
some point tunnel has not been created.

The interesting thing is that everything works fine if a tunnel is
created directly from TS_SSL_SNI_HOOK but not from the separate
thread.

The plugin code is very simple – I set up TS_SSL_SNI_HOOK and start a
thread with TSThreadCreate. When hook got called, I push TSVConn to a
thread-safe queue. The thread wakes up when item has been pushed,
calls TSVConnTunnel / TSVConnReenable for given vconn and then waits
for the next item. I have attached the code.

Do you guys have any suggestions how I can investigate this problem further?

-- 
-Lev

#include <ts/ts.h>
#include <openssl/ssl.h>
#include <arpa/inet.h>
#include <netinet/in.h>
#include <ts/IpMap.h>
#include <queue>
#include <mutex>
#include <condition_variable>

#define INET_ADDRSTRLEN 16

TSTextLogObject logger;

class Queue {
private:
    std::queue<TSVConn> _queue;
    std::mutex _mutex;
    std::condition_variable _cond;

public:
    TSVConn pop() {
        std::unique_lock<std::mutex> mlock(_mutex);
        while (_queue.empty()) {
            _cond.wait(mlock);
        }
        auto item = _queue.front();
        _queue.pop();
        return item;
    }

    void push(const TSVConn &item) {
        std::unique_lock<std::mutex> mlock(_mutex);
        _queue.push(item);
        mlock.unlock();
        _cond.notify_one();
    }
};

Queue queue;

void* foo(void* edata) {
    while (true) {
        TSVConn conn = queue.pop();
        TSVConnTunnel(conn);
        TSVConnReenable(conn);
    }
}

int CB_sni(TSCont contp, TSEvent event, void *edata) {
    TSVConn ssl_vc = reinterpret_cast<TSVConn>(edata);
    SSL *ssl = reinterpret_cast<SSL*>(TSVConnSSLConnectionGet(ssl_vc));
    const char *servername = SSL_get_servername(ssl, TLSEXT_NAMETYPE_host_name);
    TSTextLogObjectWrite(logger, "SNI callback: %s", servername);

    queue.push(ssl_vc);

    //TSVConnTunnel(ssl_vc);

    return TS_SUCCESS;
}

void TSPluginInit(int argc, const char *argv[]) {
    // register plugin
    TSPluginRegistrationInfo info;
    info.plugin_name = "ts-tls";
    info.vendor_name = "";
    info.support_email = "";
    TSPluginRegister(TS_SDK_VERSION_3_0, &info);

    // setup logging
    TSTextLogObjectCreate("ts-tls", TS_LOG_MODE_ADD_TIMESTAMP, &logger);

    // set up SNI hook
    TSCont cb_sni = TSContCreate(&CB_sni, TSMutexCreate());
    TSHttpHookAdd(TS_SSL_SNI_HOOK, cb_sni);

    TSThreadCreate(foo, NULL);

    TSTextLogObjectWrite(logger, "ts-tls plugin initialized");
}