evbuffer_get_length of autossl in environment where sender speed is slower than receiver (Buffer watermarking not working in autossl)

[minzkn]

HTTPS server => (1 Gbps - faster network) sslsplit autossl tproxy (10 Mbps - slower network) => HTTPS client

sslsplit autossl 0.0.0.0 tproxy
When the client Big file downloads HTTPS from the server

In the pxy_bev_readcb function, evbuffer_get_length(outbuf) in the following implementation always returns 0.

In an environment where the client side speed is slower than the server side speed in the autossl tproxy setting, the inbuf side continues to accumulate and the memory increases. Eventually oom will be raised.

If you do it with ssl instead of autossl in the same environment, it works fine.

using sslsplit v0.5.5, libevent v2.1.8, openssl v1.1.1k

SSLsplit 4aa01f9-dirty (built 2022-03-23)
Copyright (c) 2009-2019, Daniel Roethlisberger <daniel@roe.ch>
https://www.roe.ch/SSLsplit
Build info: V:GIT
Features: -DHAVE_NETFILTER
NAT engines: netfilter* tproxy
netfilter: IP_TRANSPARENT IP6T_SO_ORIGINAL_DST
Local process info support: no
compiled against OpenSSL 1.1.1k  25 Mar 2021 (101010bf)
rtlinked against OpenSSL 1.1.1k  25 Mar 2021 (101010bf)
OpenSSL has support for TLS extensions
TLS Server Name Indication (SNI) supported
OpenSSL is thread-safe with THREADID
OpenSSL has engine support
Using SSL_MODE_RELEASE_BUFFERS
SSL/TLS protocol availability: tls10 tls11 tls12
SSL/TLS algorithm availability: !SHA0 RSA DSA ECDSA DH ECDH EC
OpenSSL option availability: SSL_OP_NO_COMPRESSION SSL_OP_NO_TICKET SSL_OP_ALLOW_UNSAFE_LEGACY_RENEGOTIATION SSL_OP_DONT_INSERT_EMPTY_FRAGMENTS SSL_OP_NO_SESSION_RESUMPTION_ON_RENEGOTIATION SSL_OP_TLS_ROLLBACK_BUG
compiled against libevent 2.1.8-stable
rtlinked against libevent 2.1.8-stable
compiled against libnet 1.1.6
rtlinked against libnet 1.1.6
compiled against libpcap n/a
rtlinked against libpcap 1.1.1
2 CPU cores detected

Thanks for making a great program.

[sonertari]

I use the autossl proxyspecs for POP3 and SMTP servers with STARTTLS support. And I am not aware of any HTTP server with STARTTLS support, perhaps it's my ignorance, but why do you use autossl for HTTP? In other words, I think the issue may not be about the sslsplit code for buffer watermarking.

[minzkn]

Dear Soner Tari

The https I mentioned is an example environment.

I wanted to try using sslsplit for well-known protocols including pop3, STARTTLS from smtp, as well as unknown pseudo-SSL communications that start with plaintext and have an SSL client hello in the middle.

In the end, sslsplit was a solution that basically worked well by using autossl for https, pop3, smtp, ... etc.

However, it seems that evbuffer_get_length(outbuf) always returns 0 only for autossl, so I was wondering why.

It is questionable that buffer watermarking does not work in autossl.

[sonertari]

I cannot create your test environment, and it is hard to guess looking at the code, so we need further info.

If you enable debug logging with -D, what does sslsplit say until oom? Does it say Peek found ClientHello or Peek found no ClientHello?

Also, if you enable content logging do you see any content until oom?

Btw, how do you know "evbuffer_get_length(outbuf) always returns 0"?

[minzkn]

Just before oom occurs, the following message is generated. In some cases, this message occurs just before OOM, but in other cases it is not. But this message doesn't seem to be highly related to OOM as it's been mixed with multiple connection tests.

Error from src bufferevent: 0:- 336151574:1046:(null):20:(null):148:(null)

The log confirms that ClientHello is found as follows:

Connecting to [xxx.yyy.zzz.aaa]:443
tcp 192.168.0.111 18334 xxx.yyy.zzz.aaa 443
TCP connected to [xxx.yyy.zzz.aaa]:443
TCP connected from [192.168.0.111]:18334
Checking for a client hello
Peek found ClientHello
Attempt reuse dst SSL session
Replaced dst bufferevent, new one is 0x7f6794008a50
===> Original server certificate:
Subject DN: /CN=<my domain>
Common Names: <my CN...>
Fingerprint: <my Fingerprint>
Certificate cache: HIT
===> Forged server certificate:
Subject DN: /CN=<my domain>
Common Names: <my CN...>
Fingerprint: <my Fingerprint>
Completing autossl upgrade
Certificate cache: KEEP (SNI match or target mode)
SSL connected to [xxx.yyy.zzz.aaa]:443 TLSv1.3 TLS_AES_256_GCM_SHA384
CLIENT_RANDOM CAD0D36791A9A3D628096233B32A1706339B4040BEDA2943DA4C3E145CB476AE 0000000000000000D066009467000000000000000000000000FAA45DA52A519E508A0094677F0000E071140100000000
Certificate cache: KEEP (SNI match or target mode)
upgrade 192.168.0.111 18334 xxx.yyy.zzz.aaa 443 sni:<my domain> names:<my CN...> sproto:TLSv1.3:TLS_AES_128_GCM_SHA256 dproto:TLSv1.3:TLS_AES_256_GCM_SHA384 origcrt:<my ...> usedcrt:<my ...>
SSL connected from [192.168.0.111]:18334 TLSv1.3 TLS_AES_128_GCM_SHA256
CLIENT_RANDOM 6F675B5529C8D7030E25E655AC4B10B5A32BE2A10FF90F6CC8FD8D40AEB68793 A80BB417808D2C1D467FD2A75E972856E84999602EF9B7C6545C43CADA585CC4161A129C677F0000D0660094677F0000
Garbage collecting caches started.
Garbage collecting caches done.
...
<OOM - Out Of Memory>

When content logging is enabled, content is displayed up to OOM. Until OOM occurs, it seems to work just fine except for the memory increase of sslsplit.

I found out that evbuffer_get_length(outbuf) returns 0 by inserting the following debugging code in that part.

    evbuffer_add_buffer(outbuf, inbuf);
        if (OPTS_DEBUG(ctx->opts)) {
            log_err_printf("buffer watermark control ! (inbuf=%lu, outbuf=%lu, OUTBUF_LIMIT=%lu)\n", (unsigned long)evbuffer_get_length(inbuf), (unsigned long)evbuffer_get_length(outbuf), (unsigned long)OUTBUF_LIMIT);
        }
    if (evbuffer_get_length(outbuf) >= OUTBUF_LIMIT) {
        /* temporarily disable data source;
         * set an appropriate watermark. */
        bufferevent_setwatermark(other->bev, EV_WRITE,
                OUTBUF_LIMIT/2, OUTBUF_LIMIT);
        bufferevent_disable(bev, EV_READ);
    }


=> This case always inbuf/outbuf is zero. but ssl case outbuf not zero

buffer watermark control ! (inbuf=0, outbuf=0, OUTBUF_LIMIT=131072)
buffer watermark control ! (inbuf=0, outbuf=0, OUTBUF_LIMIT=131072)
buffer watermark control ! (inbuf=0, outbuf=0, OUTBUF_LIMIT=131072)
...

P.s.
Even if I look at the sslsplit source, it seems to have been implemented well, but I do not know the cause. The difference between ssl and autossl is the difference in calling bufferevent_openssl_filter_new in pxy_conn_autossl_peek_and_upgrade, but I'm guessing that this is what makes the difference.
I tested with libevent-2.1.12 instead of libevent-2.1.8 just in case, but it is the same.
The peculiar thing is that if you check evbuffer_get_length(inbuf) before calling evbuffer_add_buffer(outbuf, inbuf) it is not 0, but if you check evbuffer_get_length(outbuf) after calling evbuffer_get_length(outbuf) it is 0.

[sonertari]

I look at the debug logs you have provided, and at the code in pxy_bev_readcb(). So far this is what we know:

• This happens with autossl, but not ssl proxyspecs. So, since it is a tcp and ssl connection, the code related with http is never executed.
• Since ClientHello is found, hence the connection is upgraded to ssl (as reported in the debug logs), and the conn is connected and not closed and also not enomem (since you say that you can see the contents until oom), all we do is print the contents, copy the contents of inbuf to outbuf, and check for buffer watermarking.
• But you say that, after copying inbuf to outbuf, the outbuf becomes empty even though inbuf had data, which means that inbuf contents are lost, but memory usage increases. Also since outbuf is empty, the buffer watermarking code is never executed.

Yes, I agree, this is as strange as you say. And, it may be related with libevent, as you have suspected, since you have already tried different versions of libevent.

As you mention you have multiple test connections, so in sslsplit logs it is hard to know which log line is related with which connection.

So, I want to suggest that we use sslproxy instead of sslsplit now. The design of sslproxy is different from sslsplit, but it supports autossl, buffer watermarking, and split style proxyspecs. Also, if you enable the DEBUG_PROXY switch in Mk/main.mk and start sslproxy with -D4, it is going to print very verbose debug logs with connection ids and file descriptor numbers, so we can easily relate debug lines with connections. We can even follow the execution of its source code by looking at those debug logs. (Btw, sslsplit supports the DEBUG_PROXY switch too, but it is much less verbose.)

If we use sslproxy, we can perhaps get more detailed info about the issue, and more importantly perhaps we can rule out libevent as the culprit. Also, since the design and implementation of sslproxy is different from sslsplit, it may be better to try sslproxy now instead of keeping trying sslsplit (for example, if sslproxy succeeds then it is the sslsplit code).

It is possible that sslproxy will not work in your test environment at all. So, it's up to you.

[sonertari]

Also, just to make sure that callbacks for the overridden bevs are disabled, can you apply the following patch and report back please?:

--- pxyconn.c.orig	2022-03-25 22:45:11.607758000 +0300
+++ pxyconn.c	2022-03-25 22:45:32.568031558 +0300
@@ -1691,6 +1691,8 @@
 				               "upgrade\n");
 				return 0;
 			}
+			bufferevent_setcb(ctx->dst.bev, NULL, NULL, NULL, NULL);
+			bufferevent_disable(ctx->dst.bev, EV_READ|EV_WRITE);
 			ctx->dst.bev = bufferevent_openssl_filter_new(
 			               ctx->evbase, ctx->dst.bev, ctx->dst.ssl,
 			               BUFFEREVENT_SSL_CONNECTING,
@@ -2005,6 +2007,8 @@
 			if (OPTS_DEBUG(ctx->opts)) {
 				log_dbg_printf("Completing autossl upgrade\n");
 			}
+			bufferevent_setcb(ctx->src.bev, NULL, NULL, NULL, NULL);
+			bufferevent_disable(ctx->src.bev, EV_READ|EV_WRITE);
 			ctx->src.bev = bufferevent_openssl_filter_new(
 			               ctx->evbase, ctx->src.bev, ctx->src.ssl,
 			               BUFFEREVENT_SSL_ACCEPTING,

It may look unnecessary, but this is what we do while terminating connections and freeing bevs, which we have realized necessary some time ago, so perhaps it is necessary while upgrading too. Just in case.

[minzkn]

I applied the patch you mentioned to sslsplit, but it's the same.
(Additionally, I also enabled DEBUG_PROXY in sslsplt.)

Connecting to [xxx.yyy.zzz.aaa]:443
0xf04e90 0xf050e0 eventcb dst connected
            0x7f5eb4000a50 pxy_bufferevent_setup
tcp 192.168.0.111 34825 xxx.yyy.zzz.aaa 443
TCP connected to [xxx.yyy.zzz.aaa]:443
TCP connected from [192.168.0.111]:34825
0xf04e90 0x7f5eb4000a50 src writecb
0xf04e90 0x7f5eb4000a50 src readcb
Checking for a client hello
Peek found ClientHello
Replaced dst bufferevent, new one is 0x7f5eb4003670
0xf04e90 0x7f5eb4003670 eventcb dst connected
===> Original server certificate:
Subject DN: /CN=<my domain>
Common Names: <my CN>
Fingerprint: <my Fingerprint>
Certificate cache: MISS
===> Forged server certificate:
Subject DN: /CN=<my domain>
Common Names: <my CN>
Fingerprint: <my Fingerprint>
Completing autossl upgrade
Certificate cache: KEEP (SNI match or target mode)
SSL connected to [xxx.yyy.zzz.aaa]:443 TLSv1.3 TLS_AES_256_GCM_SHA384
CLIENT_RANDOM 5BFDBC4D83DE32FCAADB23DC4821440322FBFC4F20E5F6DA836E2116C9C67712 161A06BE5E7F00001A000000000000000D0000000000000010E0EE0000000000504200B45E7F0000801B12BD5E7F0000
0xf04e90 0x7f5eb4009eb0 eventcb src connected
src buffer event connected: ignoring event
upgrade 192.168.0.111 34825 xxx.yyy.zzz.aaa 443 sni:<my domain> names:<my CN> sproto:TLSv1.2:ECDHE-RSA-AES256-GCM-SHA384 dproto:TLSv1.3:TLS_AES_256_GCM_SHA384 origcrt:2C959DC7A662CF1851A3B6E9AE4EE7C0C132BA71 usedcrt:E32AE26ACFE1F85A709D9C0A7563774AF3ECB7B2
SSL connected from [192.168.0.111]:34825 TLSv1.2 ECDHE-RSA-AES256-GCM-SHA384
CLIENT_RANDOM 6240FFCF2AD01588931F9BE844A2FDB727B22418A09B6B331259D4463F391BEC 9A4C26119BA5F70C4D714505ECE07780910389D3F68E30D51B9923F6B45346D9AF206CBD760B50ECEC17550487EB2B1A
0xf04e90 0x7f5eb4009eb0 src readcb
buffer watermark control ! (inbuf=0, outbuf=0, OUTBUF_LIMIT=131072)
0xf04e90 0x7f5eb4003670 dst writecb
0xf04e90 0x7f5eb4003670 dst readcb
buffer watermark control ! (inbuf=0, outbuf=0, OUTBUF_LIMIT=131072)
0xf04e90 0x7f5eb4009eb0 src writecb
0xf04e90 0x7f5eb4003670 dst readcb
buffer watermark control ! (inbuf=0, outbuf=0, OUTBUF_LIMIT=131072)
0xf04e90 0x7f5eb4009eb0 src writecb
0xf04e90 0x7f5eb4003670 dst readcb
buffer watermark control ! (inbuf=0, outbuf=0, OUTBUF_LIMIT=131072)
0xf04e90 0x7f5eb4009eb0 src writecb
0xf04e90 0x7f5eb4003670 dst readcb
buffer watermark control ! (inbuf=0, outbuf=0, OUTBUF_LIMIT=131072)
0xf04e90 0x7f5eb4009eb0 src writecb
0xf04e90 0x7f5eb4003670 dst readcb
buffer watermark control ! (inbuf=0, outbuf=0, OUTBUF_LIMIT=131072)
0xf04e90 0x7f5eb4009eb0 src writecb
0xf04e90 0x7f5eb4003670 dst readcb
buffer watermark control ! (inbuf=0, outbuf=0, OUTBUF_LIMIT=131072)
0xf04e90 0x7f5eb4009eb0 src writecb
0xf04e90 0x7f5eb4003670 dst readcb
...

sslproxy may take some time to test.

[minzkn]

It seems to work well because I set bufferevent_setwatermark in the bev as follows right before the call to bufferevent_openssl_filter_new.

It is probably related to bev_ssl->outbuf_cb of bufferevent_openssl_new_impl function called inside bufferevent_openssl_filter_new .

This is the same behavior that copies when evbuffer_add_buffer is called and is called when evbuffer_invoke_callbacks_() (consider_writing) is called.

That is, it works if high watermark is properly set before calling bufferevent_openssl_filter_new.

diff -urN sslsplit-0.5.5/pxyconn.c sslsplit-0.5.5-trial-fix/pxyconn.c
--- sslsplit-0.5.5/pxyconn.c    2019-08-30 20:09:00.000000000 +0900
+++ sslsplit-0.5.5-trial-fix/pxyconn.c  2022-03-28 16:42:10.137395144 +0900
@@ -1684,6 +1684,8 @@
                                               "upgrade\n");
                                return 0;
                        }
+                       bufferevent_setwatermark(ctx->dst.bev, EV_WRITE,
+                                       OUTBUF_LIMIT/2, OUTBUF_LIMIT);
                        ctx->dst.bev = bufferevent_openssl_filter_new(
                                       ctx->evbase, ctx->dst.bev, ctx->dst.ssl,
                                       BUFFEREVENT_SSL_CONNECTING,
@@ -1998,6 +2000,8 @@
                        if (OPTS_DEBUG(ctx->opts)) {
                                log_dbg_printf("Completing autossl upgrade\n");
                        }
+                       bufferevent_setwatermark(ctx->src.bev, EV_WRITE,
+                                       OUTBUF_LIMIT/2, OUTBUF_LIMIT);
                        ctx->src.bev = bufferevent_openssl_filter_new(
                                       ctx->evbase, ctx->src.bev, ctx->src.ssl,
                                       BUFFEREVENT_SSL_ACCEPTING,

    <N bev> = bufferevent_openssl_filter_new(
                 <struct event_base *>, <T bev>, <SSL *>,
                 BUFFEREVENT_SSL_CONNECTING or BUFFEREVENT_SSL_ACCEPTING,
                 BEV_OPT_DEFER_CALLBACKS);

    N != T
    need high watermark set to T

[sonertari]

Hm, that's interesting. I've also looked into the source code of libevent 2.1.12, and seen that the only time the bufferevent_setwatermark() function is called in the entire libevent code is in bufferevent_openssl_new_impl(), as I guess you have also seen. And I see that it reenables the read (and write) callback which we have disabled in our code for the underlying bev (this is relevant to autossl, since its underlying bev is tcp, and it switches to another ssl bev), but it resets the watermark for the read cb not for the write cb. If that's really the case, then it may explain the strange issue you have seen. Do I understand this correctly?

But, what I don't understand in your trial-fix is that if the theory above is right, your fix was not supposed to work, because you call bufferevent_setwatermark() for the write cb before the call to bufferevent_openssl_filter_new(), which resets the watermark for the read cb and reenables it as I said above. Because in your fix, you set the watermark for the write cb for the underlying bev. So, I currently don't understand why your fix works. In fact, I would expect a fix which would (again) disable the read cb after the call to bufferevent_openssl_filter_new(), of course after checking buffer sizes and watermark limits. Because it seems to me like the actual fix should be about disabling the read cb again, not setting the write watermarks again. Or perhaps they both lead to the same result in our implementation, I don't know yet. Am I missing something?

I may be really missing something, because I am still looking into the source code of libevent, and check with ours. I have also noted that in libevent code both bufferevent_openssl_filter_new() and bufferevent_openssl_socket_new() call bufferevent_openssl_new_impl(). So, I should continue looking into it. But I think you have found a clue.

Btw, if your trial-fix really leads to a solution or a workaround, please do not bother trying sslproxy, unless you want to try it out of interest.

[sonertari]

Also, we enable read callbacks for src and dst bevs after we find ClientHello and while we complete upgrade, not for the underlying bevs, but for the new bevs. I don't know how this affects this issue.

[minzkn]

Here's my understanding of libevent: Of course, since this is the first time I've seen the libevent source, it's not perfect.

Difference between ssl and autossl In the flow, autossl starts with ctx->src|dst.bev as TCP bev and is replaced by bufferevent_openssl_filter_new with SSL bev with this as 'underlying bev'.
In other words, I saw the difference in that autossl has an 'underlying bev' unlike ssl.

At this time, in the process of copying from inbuf to outbuf through evbuffer_add_buffer, 'evbuffer_invoke_callbacks_(outbuf);' It calls be_openssl_outbuf_cb according to the syntax.

If you look at the be_openssl_outbuf_cb function, you will find the following part.

if (bev_ssl->underlying)
            consider_writing(bev_ssl);

Now looking at the consider_writing function, the following 'target' seems to mean the output of the underlying bev .
And there is a comparison condition with high write watermark and write_suspended . This seems to be the part that controls the buffer balance between the ssl bev and the underlying bev.

static void
consider_writing(struct bufferevent_openssl *bev_ssl)
{
...
    if (bev_ssl->underlying) {
        target = bev_ssl->underlying->output;
        wm = &bev_ssl->underlying->wm_write;
    }
    while ((bev_ssl->bev.bev.enabled & EV_WRITE) &&
        (! bev_ssl->bev.write_suspended) &&
        evbuffer_get_length(output) &&
        (!target || (! wm->high || evbuffer_get_length(target) < wm->high))) {
...
}

After all, I think that BIO_new_bufferevent(underlying) / BIO_s_bufferevent() called by bufferevent_openssl_filter_new controls the underlying output through bio_bufferevent_write. (If the high write watermark is not set in the underlying bev, the memory is accumulated as all are added unconditionally by calling evbuffer_add in bio_bufferevent_write )

static int
bio_bufferevent_write(BIO *b, const char *in, int inlen)
{
    struct bufferevent *bufev = BIO_get_data(b);
    struct evbuffer *output;
    size_t outlen;

    BIO_clear_retry_flags(b);

    if (!BIO_get_data(b))
        return -1;

    output = bufferevent_get_output(bufev);
    outlen = evbuffer_get_length(output);

    /* Copy only as much data onto the output buffer as can fit under the
     * high-water mark. */
    if (bufev->wm_write.high && bufev->wm_write.high <= (outlen+inlen)) {
        if (bufev->wm_write.high <= outlen) {
            /* If no data can fit, we'll need to retry later. */
            BIO_set_retry_write(b);
            return -1;
        }
        inlen = bufev->wm_write.high - outlen;
    }

    EVUTIL_ASSERT(inlen > 0);
    evbuffer_add(output, in, inlen);
    return inlen;
}

The point in autossl is that you need to set the high write watermark of the underlying bev to control the output of the underlying bev, and the low write watermark doesn't seem to have any special meaning.

The deeper content seems to be getting lost in my understanding of this.

[sonertari]

The purpose of setting a watermark is to call the write callback when the water level drops to some acceptable level, i.e. outbuf has some space now (otherwise, the write events are suspended until the level drops), so that in the write callback we can reenable the read events, i.e. restart accepting data into inbuf.

So, IMO, while we are switching from tcp to ssl bevs in autossl, we should check if any write watermarks are set and also if the read events are disabled for the underlying bevs, and if so, we should set the watermarks and disable the read events for the new bevs accordingly. We should do these checks and updates in the upgrade code.

Therefore, the following patch is my proposal to fix this issue:

--- pxyconn.c.orig	2022-03-25 22:45:11.607758000 +0300
+++ pxyconn.c	2022-03-29 21:35:05.176463169 +0300
@@ -1653,6 +1653,18 @@
 	}
 }
 
+static int
+pxy_conn_getwatermark_state(struct bufferevent *bev)
+{
+	size_t lowmark = 0;
+	size_t highmark = 0;
+
+	bufferevent_getwatermark(bev, EV_WRITE, &lowmark, &highmark);
+	if (lowmark || highmark)
+		return 1;
+	return 0;
+}
+
 /*
  * Peek into pending data to see if it is an SSL/TLS ClientHello, and if so,
  * upgrade the connection from plain TCP to SSL/TLS.
@@ -1691,6 +1703,10 @@
 				               "upgrade\n");
 				return 0;
 			}
+
+			int underlying_read_enabled = bufferevent_get_enabled(ctx->dst.bev) & EV_READ;
+			int underlying_wm_set = pxy_conn_getwatermark_state(ctx->dst.bev);
+
 			ctx->dst.bev = bufferevent_openssl_filter_new(
 			               ctx->evbase, ctx->dst.bev, ctx->dst.ssl,
 			               BUFFEREVENT_SSL_CONNECTING,
@@ -1703,7 +1719,11 @@
 			bufferevent_setcb(ctx->dst.bev, pxy_bev_readcb,
 			                  pxy_bev_writecb, pxy_bev_eventcb,
 			                  ctx);
-			bufferevent_enable(ctx->dst.bev, EV_READ|EV_WRITE);
+			bufferevent_enable(ctx->dst.bev, (underlying_read_enabled ? EV_READ:0)|EV_WRITE);
+			if (underlying_wm_set) {
+				bufferevent_setwatermark(ctx->dst.bev, EV_WRITE, OUTBUF_LIMIT/2, OUTBUF_LIMIT);
+			}
+
 			if (OPTS_DEBUG(ctx->opts)) {
 				log_err_printf("Replaced dst bufferevent, new "
 				               "one is %p\n",
@@ -2005,6 +2025,10 @@
 			if (OPTS_DEBUG(ctx->opts)) {
 				log_dbg_printf("Completing autossl upgrade\n");
 			}
+
+			int underlying_read_enabled = bufferevent_get_enabled(ctx->src.bev) & EV_READ;
+			int underlying_wm_set = pxy_conn_getwatermark_state(ctx->src.bev);
+
 			ctx->src.bev = bufferevent_openssl_filter_new(
 			               ctx->evbase, ctx->src.bev, ctx->src.ssl,
 			               BUFFEREVENT_SSL_ACCEPTING,
@@ -2017,8 +2041,10 @@
 				                  pxy_bev_writecb,
 				                  pxy_bev_eventcb,
 				                  ctx);
-				bufferevent_enable(ctx->src.bev,
-				                   EV_READ|EV_WRITE);
+				bufferevent_enable(ctx->src.bev, (underlying_read_enabled ? EV_READ:0)|EV_WRITE);
+				if (underlying_wm_set) {
+					bufferevent_setwatermark(ctx->src.bev, EV_WRITE, OUTBUF_LIMIT/2, OUTBUF_LIMIT);
+				}
 			}
 		} else {
 			ctx->src.bev = pxy_bufferevent_setup(ctx, ctx->fd,

@minzkn, can you apply this patch (and this patch only) and try please? So that we can convert this into a pull request if it works.

[minzkn]

@sonertari The patch you suggested still shows the same memory increase. That is, the patch doesn't hit.

The bev passed to the bufferevent_openssl_filter_new argument is read and write enabled as the underlying bev, sets the watermark for READ to low 0, high 0, and creates a new ssl bev and returns it.

Therefore, it is thought that reading and writing should be enabled for the ssl bev returned after the call to bufferevent_openssl_filter_new as the existing implementation, and the WRITE watermark should be set in order not to exceed the buffer limit in the underlying bev passed before calling bufferevent_openssl_filter_new.

The WRITE watermark set on the underlying bev before calling bufferevent_openssl_filter_new will be a control condition inside libevent, and it seems that sslsplit has nothing to control the underlying bev directly after bufferevent_openssl_filter_new.

So, in the trial fix patch I suggested, I think it is right to set the WRITE watermark right before bufferevent_openssl_filter_new.

diff -urN sslsplit-0.5.5/pxyconn.c sslsplit-0.5.5-trial-fix/pxyconn.c
--- sslsplit-0.5.5/pxyconn.c    2019-08-30 20:09:00.000000000 +0900
+++ sslsplit-0.5.5-trial-fix/pxyconn.c  2022-03-28 16:42:10.137395144 +0900
@@ -1684,6 +1684,8 @@
                                               "upgrade\n");
                                return 0;
                        }
+                       bufferevent_setwatermark(ctx->dst.bev, EV_WRITE,
+                                       OUTBUF_LIMIT/2, OUTBUF_LIMIT);
                        ctx->dst.bev = bufferevent_openssl_filter_new(
                                       ctx->evbase, ctx->dst.bev, ctx->dst.ssl,
                                       BUFFEREVENT_SSL_CONNECTING,
@@ -1998,6 +2000,8 @@
                        if (OPTS_DEBUG(ctx->opts)) {
                                log_dbg_printf("Completing autossl upgrade\n");
                        }
+                       bufferevent_setwatermark(ctx->src.bev, EV_WRITE,
+                                       OUTBUF_LIMIT/2, OUTBUF_LIMIT);
                        ctx->src.bev = bufferevent_openssl_filter_new(
                                       ctx->evbase, ctx->src.bev, ctx->src.ssl,
                                       BUFFEREVENT_SSL_ACCEPTING,

Pseudo code :

/*     <SSL bev> != <underlying bev>
    need high watermark set to <underlying bev>    (not <SSL bev>)
*/
+ bufferevent_setwatermark(<underlying bev>, EV_WRITE, OUTBUF_LIMIT/2 /* or zero */, OUTBUF_LIMIT);
 <SSL bev> = bufferevent_openssl_filter_new(
                 <struct event_base *>, <underlying bev>, <SSL *>,
                 BUFFEREVENT_SSL_CONNECTING or BUFFEREVENT_SSL_ACCEPTING,
                 BEV_OPT_DEFER_CALLBACKS);
 // The underlying bev now has read and write enabled, the READ watermark is 0, 0 and the WRITE watermark has OUTBUF_LIMIT. callback is libevent internal BIO implementation.
 // From this point on, I think it's okay to forget the underlying bev

 ...

 bufferevent_setcb(<SSL bev>, <readcb>, <writecb>, <eventcb>, <ctx>);
 bufferevent_enable(<SSL bev>, EV_READ | EV_WRITE);

[sonertari]

I am not surprised about the memory increase you report now, that's why in my earlier post I said we should disable the read events for the underlying bev if we have disabled them, because the bufferevent_openssl_new_impl() function in the libevent code enables them regardless. Back then I wasn't sure how libevent was working if a bev was wrapping an underlying bev, rather than directly connecting to a socket. But I think it is clear now that the main cause for the issue you have reported is the read events for the underlying bev. For example, disabling or watermarking the wrapper bev did not stop filling up the buffer for the underlying bev, as we have observed.

So, contrary to your comments, based on your reports (because I cannot create your test environment), now my theory is that our watermark code should always deal with underlying bevs, never wrapper bevs. To put it perhaps more correctly, we should not disable or watermark wrapper bevs, instead we should always deal with bevs directly connected to sockets. (And the only proxyspec type with underlying bevs is autossl.)

Also, I hope you understand that we cannot use your trial-fix as it is, because it sets watermarks for underlying bevs unconditionally. We should set the watermarks only if the underlying bevs have them set already. Plus, if we deal with wrapper bevs only, as you suggest, who is going to reset the watermarks for the underlying bevs? Note that our read and write callbacks currently deal with wrapper bevs, not underlying bevs.

Therefore, the following patch is my updated proposal to fix this issue:

--- pxyconn.c.orig	2022-03-25 22:45:11.607758000 +0300
+++ pxyconn.c	2022-03-30 16:37:43.785407139 +0300
@@ -1653,6 +1653,18 @@
 	}
 }
 
+static int
+pxy_conn_getwatermark_state(struct bufferevent *bev)
+{
+	size_t lowmark = 0;
+	size_t highmark = 0;
+
+	bufferevent_getwatermark(bev, EV_WRITE, &lowmark, &highmark);
+	if (lowmark || highmark)
+		return 1;
+	return 0;
+}
+
 /*
  * Peek into pending data to see if it is an SSL/TLS ClientHello, and if so,
  * upgrade the connection from plain TCP to SSL/TLS.
@@ -1691,6 +1703,11 @@
 				               "upgrade\n");
 				return 0;
 			}
+
+			int underlying_read_disabled = !(bufferevent_get_enabled(ctx->dst.bev) & EV_READ);
+			int underlying_wm_set = pxy_conn_getwatermark_state(ctx->dst.bev);
+			struct bufferevent *ubev = ctx->dst.bev;
+
 			ctx->dst.bev = bufferevent_openssl_filter_new(
 			               ctx->evbase, ctx->dst.bev, ctx->dst.ssl,
 			               BUFFEREVENT_SSL_CONNECTING,
@@ -1704,6 +1721,14 @@
 			                  pxy_bev_writecb, pxy_bev_eventcb,
 			                  ctx);
 			bufferevent_enable(ctx->dst.bev, EV_READ|EV_WRITE);
+
+			if (underlying_read_disabled) {
+				bufferevent_disable(ubev, EV_READ);
+			}
+			if (underlying_wm_set) {
+				bufferevent_setwatermark(ubev, EV_WRITE, OUTBUF_LIMIT/2, OUTBUF_LIMIT);
+			}
+
 			if (OPTS_DEBUG(ctx->opts)) {
 				log_err_printf("Replaced dst bufferevent, new "
 				               "one is %p\n",
@@ -1899,9 +1924,11 @@
 	if (evbuffer_get_length(outbuf) >= OUTBUF_LIMIT) {
 		/* temporarily disable data source;
 		 * set an appropriate watermark. */
-		bufferevent_setwatermark(other->bev, EV_WRITE,
+		struct bufferevent *ubev = bufferevent_get_underlying(other->bev);
+		bufferevent_setwatermark(ubev ? ubev : other->bev, EV_WRITE,
 				OUTBUF_LIMIT/2, OUTBUF_LIMIT);
-		bufferevent_disable(bev, EV_READ);
+		ubev = bufferevent_get_underlying(bev);
+		bufferevent_disable(ubev ? ubev : bev, EV_READ);
 	}
 }
 
@@ -1934,11 +1961,15 @@
 		return;
 	}
 
-	if (other->bev && !(bufferevent_get_enabled(other->bev) & EV_READ)) {
-		/* data source temporarily disabled;
-		 * re-enable and reset watermark to 0. */
-		bufferevent_setwatermark(bev, EV_WRITE, 0, 0);
-		bufferevent_enable(other->bev, EV_READ);
+	if (other->bev) {
+		struct bufferevent *ubev = bufferevent_get_underlying(other->bev);
+		if (!(bufferevent_get_enabled(ubev ? ubev : other->bev) & EV_READ)) {
+			/* data source temporarily disabled;
+			 * re-enable and reset watermark to 0. */
+			bufferevent_enable(ubev ? ubev : other->bev, EV_READ);
+			ubev = bufferevent_get_underlying(bev);
+			bufferevent_setwatermark(ubev ? ubev : bev, EV_WRITE, 0, 0);
+		}
 	}
 }
 
@@ -2005,6 +2036,11 @@
 			if (OPTS_DEBUG(ctx->opts)) {
 				log_dbg_printf("Completing autossl upgrade\n");
 			}
+
+			int underlying_read_disabled = !(bufferevent_get_enabled(ctx->src.bev) & EV_READ);
+			int underlying_wm_set = pxy_conn_getwatermark_state(ctx->src.bev);
+			struct bufferevent *ubev = ctx->src.bev;
+
 			ctx->src.bev = bufferevent_openssl_filter_new(
 			               ctx->evbase, ctx->src.bev, ctx->src.ssl,
 			               BUFFEREVENT_SSL_ACCEPTING,
@@ -2017,8 +2053,14 @@
 				                  pxy_bev_writecb,
 				                  pxy_bev_eventcb,
 				                  ctx);
-				bufferevent_enable(ctx->src.bev,
-				                   EV_READ|EV_WRITE);
+				bufferevent_enable(ctx->src.bev, EV_READ|EV_WRITE);
+
+				if (underlying_read_disabled) {
+					bufferevent_disable(ubev, EV_READ);
+				}
+				if (underlying_wm_set) {
+					bufferevent_setwatermark(ubev, EV_WRITE, OUTBUF_LIMIT/2, OUTBUF_LIMIT);
+				}
 			}
 		} else {
 			ctx->src.bev = pxy_bufferevent_setup(ctx, ctx->fd,

This patch is supposed to work, because it conditionally includes your trial-fix too. But since I have modified our watermarking code to deal with underlying bevs only, it should be tested properly, with or without autossl.

@minzkn, can you apply this patch (and this patch only) and try please?