<div dir="ltr"><div>I am using stunnel v5.32 compiled on a RHEL 6.7 with openssl-1.0.1e-42.el6.x86_64.<br><br>The stunnel.conf cache settings are (for testing cache behaviour): <br><i>sessionCacheSize = 3<br>sessionCacheTimeout = 60<br></i><br>What I expect is that after sessioncache size is reached, the memory (RSS) allocated to stunnel process does not grow with new sessions which are not in cache.<br>Instead of this the stunnel allocates about 28K for any new session which does not have a stored session in cache and does not free this anymore.<br>For new connections, but with session stored in cache, the memory does not grow. This lead me to a problem in memory deallocation for expired session in internal session cache.( I know that openssl frees expired session cache entries at every 255 sessions).<br><br>See example below:<br>--> stunnel start (see RSS)<br>USER       PID %CPU %MEM    VSZ   RSS TTY      STAT START   TIME COMMAND<br>stunnel  20655  0.0  0.0 117760  1440 ?        Ss   15:49   0:00 /usr/local/bin/stunnel5<br>--> after 3 sessions with no cache hits<br>stunnel  20655  0.0  0.0 117828  2976 ?        Ss   15:49   0:00 /usr/local/bin/stunnel5<br>- stunnel log<br>2016.05.11 15:50:57 LOG7[kngHAM6DLUpVRXEqHcUMIt]: New session callback<br>2016.05.11 15:50:57 LOG7[kngHAM6DLUpVRXEqHcUMIt]:      4 server accept(s) requested<br>2016.05.11 15:50:57 LOG7[kngHAM6DLUpVRXEqHcUMIt]:      4 server accept(s) succeeded<br>2016.05.11 15:50:57 LOG7[kngHAM6DLUpVRXEqHcUMIt]:      0 server renegotiation(s) requested<br>2016.05.11 15:50:57 LOG7[kngHAM6DLUpVRXEqHcUMIt]:      0 session reuse(s)<br>2016.05.11 15:50:57 LOG7[kngHAM6DLUpVRXEqHcUMIt]:      3 internal session cache item(s)<br>2016.05.11 15:50:57 LOG7[kngHAM6DLUpVRXEqHcUMIt]:      0 internal session cache fill-up(s)<br>2016.05.11 15:50:57 LOG7[kngHAM6DLUpVRXEqHcUMIt]:      0 internal session cache miss(es)<br>2016.05.11 15:50:57 LOG7[kngHAM6DLUpVRXEqHcUMIt]:      0 external session cache hit(s)<br>2016.05.11 15:50:57 LOG7[kngHAM6DLUpVRXEqHcUMIt]:      0 expired session(s) retrieved<br>2016.05.11 15:50:57 LOG6[kngHAM6DLUpVRXEqHcUMIt]: SSL accepted: new session negotiated<br>2016.05.11 15:50:57 LOG7[kngHAM6DLUpVRXEqHcUMIt]: Remove session callback<br>-----------------------------------------------------<br>--> after another 1 request with cache hit: as you can see no RSS memory was added<br>stunnel  20655  0.0  0.0 117828  2976 ?        Ss   15:49   0:00 /usr/local/bin/stunnel5<br>- stunnel log<br>2016.05.11 15:51:57 LOG7[Slq6WdqS97Ox4G8eOKfGg0]: SSL state (accept): SSLv3 read finished A<br>2016.05.11 15:51:57 LOG7[Slq6WdqS97Ox4G8eOKfGg0]:      5 server accept(s) requested<br>2016.05.11 15:51:57 LOG7[Slq6WdqS97Ox4G8eOKfGg0]:      5 server accept(s) succeeded<br>2016.05.11 15:51:57 LOG7[Slq6WdqS97Ox4G8eOKfGg0]:      0 server renegotiation(s) requested<br>2016.05.11 15:51:57 LOG7[Slq6WdqS97Ox4G8eOKfGg0]:      1 session reuse(s)<br>2016.05.11 15:51:57 LOG7[Slq6WdqS97Ox4G8eOKfGg0]:      3 internal session cache item(s)<br>2016.05.11 15:51:57 LOG7[Slq6WdqS97Ox4G8eOKfGg0]:      1 internal session cache fill-up(s)<br>2016.05.11 15:51:57 LOG7[Slq6WdqS97Ox4G8eOKfGg0]:      0 internal session cache miss(es)<br>2016.05.11 15:51:57 LOG7[Slq6WdqS97Ox4G8eOKfGg0]:      0 external session cache hit(s)<br>2016.05.11 15:51:57 LOG7[Slq6WdqS97Ox4G8eOKfGg0]:      0 expired session(s) retrieved<br>2016.05.11 15:51:57 LOG6[Slq6WdqS97Ox4G8eOKfGg0]: SSL accepted: previous session reused<br>----------------------------------------------------<br>--> after another 1 request with no cache hit (now we have the first cache fill-up)<br>stunnel  20655  0.0  0.0 117828  3000 ?        Ss   15:49   0:00 /usr/local/bin/stunnel5<br><br>- stunnel log<br>2016.05.11 15:53:31 LOG7[P8n33mFxzHVAZEeRwnFccK]: New session callback<br>2016.05.11 15:53:31 LOG7[P8n33mFxzHVAZEeRwnFccK]:      6 server accept(s) requested<br>2016.05.11 15:53:31 LOG7[P8n33mFxzHVAZEeRwnFccK]:      6 server accept(s) succeeded<br>2016.05.11 15:53:31 LOG7[P8n33mFxzHVAZEeRwnFccK]:      0 server renegotiation(s) requested<br>2016.05.11 15:53:31 LOG7[P8n33mFxzHVAZEeRwnFccK]:      1 session reuse(s)<br>2016.05.11 15:53:31 LOG7[P8n33mFxzHVAZEeRwnFccK]:      3 internal session cache item(s)<br>2016.05.11 15:53:31 LOG7[P8n33mFxzHVAZEeRwnFccK]:      1 internal session cache fill-up(s)<br>2016.05.11 15:53:31 LOG7[P8n33mFxzHVAZEeRwnFccK]:      0 internal session cache miss(es)<br>2016.05.11 15:53:31 LOG7[P8n33mFxzHVAZEeRwnFccK]:      0 external session cache hit(s)<br>2016.05.11 15:53:31 LOG7[P8n33mFxzHVAZEeRwnFccK]:      0 expired session(s) retrieved<br>2016.05.11 15:53:31 LOG6[P8n33mFxzHVAZEeRwnFccK]: SSL accepted: new session negotiated<br>2016.05.11 15:53:31 LOG7[P8n33mFxzHVAZEeRwnFccK]: Remove session callback<br>----------------------------------------------------<br>--> after another 300 new session with no cache hits and after waiting 1 minute for entries in session cache to expire (as said in documentation openssl must free expired entries every 255 sessions)<br>stunnel  20655  0.0  0.2 117828 11632 ?        Ss   15:49   0:03 /usr/local/bin/stunnel5<br><br>- stunnel log<br>2016.05.11 16:13:26 LOG7[vWvoFT1DXuJ9x0eEfFnQBf]: New session callback<br>2016.05.11 16:13:26 LOG7[vWvoFT1DXuJ9x0eEfFnQBf]:    306 server accept(s) requested<br>2016.05.11 16:13:26 LOG7[vWvoFT1DXuJ9x0eEfFnQBf]:    306 server accept(s) succeeded<br>2016.05.11 16:13:26 LOG7[vWvoFT1DXuJ9x0eEfFnQBf]:      0 server renegotiation(s) requested<br>2016.05.11 16:13:26 LOG7[vWvoFT1DXuJ9x0eEfFnQBf]:      1 session reuse(s)<br>2016.05.11 16:13:26 LOG7[vWvoFT1DXuJ9x0eEfFnQBf]:      3 internal session cache item(s)<br>2016.05.11 16:13:26 LOG7[vWvoFT1DXuJ9x0eEfFnQBf]:    301 internal session cache fill-up(s)<br>2016.05.11 16:13:26 LOG7[vWvoFT1DXuJ9x0eEfFnQBf]:      0 internal session cache miss(es)<br>2016.05.11 16:13:26 LOG7[vWvoFT1DXuJ9x0eEfFnQBf]:      0 external session cache hit(s)<br>2016.05.11 16:13:26 LOG7[vWvoFT1DXuJ9x0eEfFnQBf]:      0 expired session(s) retrieved<br>2016.05.11 16:13:26 LOG6[vWvoFT1DXuJ9x0eEfFnQBf]: SSL accepted: new session negotiated<br>2016.05.11 16:13:26 LOG7[vWvoFT1DXuJ9x0eEfFnQBf]: Remove session callback<br><br>----------------------------------------------------<br><br>What I can see is tat memory grows with ~28K for every new session after session cache was filled and never deallocates this memory.<br>In my production env. this really creates problems because after 2 weeks stunnel fils all 32GB of server RAM.<br><b><br>Anyone has encountered a similar problem? </b> <br><br>Of course the stunnel service restart clears the memory but I loose all cache entries and is not acceptable.<br><br>After some code analysis between different versions of stunnel I can see that between v5.26 ans v5.27 the ctx callbacks functions was changed.<br>In my tests with versions prior to 5.27 I can see that this memory problems does not appear. See logs below:<br><br></div>---- stunnel v5.26 --------<br><div>2016.05.12 13:08:14 LOG5[ui]: stunnel 5.26 on x86_64-unknown-linux-gnu platform<br>2016.05.12 13:08:14 LOG5[ui]: Compiled/running with OpenSSL 1.0.1e-fips 11 Feb 2013<br><br>stunnel  27402  0.0  0.0 117604  1316 ?        Ss   13:08   0:00 /usr/local/bin/stunnel5<br>stunnel  27402  0.0  0.0 117672  2756 ?        Ss   13:08   0:00 /usr/local/bin/stunnel5<br>stunnel  27402  0.0  0.0 117672  2804 ?        Ss   13:08   0:00 /usr/local/bin/stunnel5<br>stunnel  27402  0.0  0.0 117672  2828 ?        Ss   13:08   0:00 /usr/local/bin/stunnel5<br>stunnel  27402  0.0  0.0 117672  2868 ?        Ss   13:08   0:00 /usr/local/bin/stunnel5<br>cache fill-up<br>2016.05.12 13:11:01 LOG7[FdNYw7uGlV9xNElZSPBfyh]:      0 session reuse(s)<br>2016.05.12 13:11:01 LOG7[FdNYw7uGlV9xNElZSPBfyh]:      3 internal session cache item(s)<br>2016.05.12 13:11:01 LOG7[FdNYw7uGlV9xNElZSPBfyh]:      1 internal session cache fill-up(s)<br><br>stunnel  27402  0.0  0.0 117672  2868 ?        Ss   13:08   0:00 /usr/local/bin/stunnel5<br>stunnel  27402  0.0  0.0 117672  2868 ?        Ss   13:08   0:00 /usr/local/bin/stunnel5<br>after 100 fill-ups<br>2016.05.12 13:13:55 LOG7[TWO1OFFPYvsW4qdjyJ0IZK]: SSL state (accept): SSLv3 flush data<br>2016.05.12 13:13:55 LOG7[TWO1OFFPYvsW4qdjyJ0IZK]:    107 server accept(s) requested<br>2016.05.12 13:13:55 LOG7[TWO1OFFPYvsW4qdjyJ0IZK]:    107 server accept(s) succeeded<br>2016.05.12 13:13:55 LOG7[TWO1OFFPYvsW4qdjyJ0IZK]:      0 server renegotiation(s) requested<br>2016.05.12 13:13:55 LOG7[TWO1OFFPYvsW4qdjyJ0IZK]:      1 session reuse(s)<br>2016.05.12 13:13:55 LOG7[TWO1OFFPYvsW4qdjyJ0IZK]:      3 internal session cache item(s)<br>2016.05.12 13:13:55 LOG7[TWO1OFFPYvsW4qdjyJ0IZK]:    102 internal session cache fill-up(s)<br>2016.05.12 13:13:55 LOG7[TWO1OFFPYvsW4qdjyJ0IZK]:      0 internal session cache miss(es)<br>2016.05.12 13:13:55 LOG7[TWO1OFFPYvsW4qdjyJ0IZK]:      0 external session cache hit(s)<br>2016.05.12 13:13:55 LOG7[TWO1OFFPYvsW4qdjyJ0IZK]:      0 expired session(s) retrieved<br>2016.05.12 13:13:55 LOG6[TWO1OFFPYvsW4qdjyJ0IZK]: SSL accepted: new session negotiated<br><br>stunnel  27402  0.1  0.0 117672  2872 ?        Ss   13:08   0:00 /usr/local/bin/stunnel5<br><br>after another 100 fill-ups<br>2016.05.12 13:19:03 LOG7[InwkBBOxJrfptxYx6wXTxU]: SSL state (accept): SSLv3 flush data<br>2016.05.12 13:19:03 LOG7[InwkBBOxJrfptxYx6wXTxU]:    207 server accept(s) requested<br>2016.05.12 13:19:03 LOG7[InwkBBOxJrfptxYx6wXTxU]:    207 server accept(s) succeeded<br>2016.05.12 13:19:03 LOG7[InwkBBOxJrfptxYx6wXTxU]:      0 server renegotiation(s) requested<br>2016.05.12 13:19:03 LOG7[InwkBBOxJrfptxYx6wXTxU]:      1 session reuse(s)<br>2016.05.12 13:19:03 LOG7[InwkBBOxJrfptxYx6wXTxU]:      3 internal session cache item(s)<br>2016.05.12 13:19:03 LOG7[InwkBBOxJrfptxYx6wXTxU]:    202 internal session cache fill-up(s)<br>2016.05.12 13:19:03 LOG7[InwkBBOxJrfptxYx6wXTxU]:      0 internal session cache miss(es)<br>2016.05.12 13:19:03 LOG7[InwkBBOxJrfptxYx6wXTxU]:      0 external session cache hit(s)<br>2016.05.12 13:19:03 LOG7[InwkBBOxJrfptxYx6wXTxU]:      0 expired session(s) retrieved<br>2016.05.12 13:19:03 LOG6[InwkBBOxJrfptxYx6wXTxU]: SSL accepted: new session negotiated<br><br><br>stunnel  27402  0.0  0.0 117672  2872 ?        Ss   13:08   0:01 /usr/local/bin/stunnel5<br><br></div><div>Code:<br>--->>> callbacks in v5.26 L605<br><i>NOEXPORT int sess_new_cb(SSL *ssl, SSL_SESSION *sess) {<br>    unsigned char *val, *val_tmp;<br>    ssize_t val_len;<br>    const unsigned char *session_id;<br>    unsigned int session_id_length;<br><br>    val_len=i2d_SSL_SESSION(sess, NULL);<br>    val_tmp=val=str_alloc((size_t)val_len);<br>    i2d_SSL_SESSION(sess, &val_tmp);<br><br>#if OPENSSL_VERSION_NUMBER>=0x0090800fL<br>    session_id=SSL_SESSION_get_id(sess, &session_id_length);<br>#else<br>    session_id=(const unsigned char *)sess->session_id;<br>    session_id_length=sess->session_id_length;<br>#endif<br>    cache_transfer(SSL_get_SSL_CTX(ssl), CACHE_CMD_NEW,<br>        SSL_SESSION_get_timeout(sess),<br>        session_id, session_id_length, val, (size_t)val_len, NULL, NULL);<br>    str_free(val);<br>    return 1; /* leave the session in local cache for reuse */<br>}<br><br>NOEXPORT SSL_SESSION *sess_get_cb(SSL *ssl,<br>        unsigned char *key, int key_len, int *do_copy) {<br>    unsigned char *val, *val_tmp=NULL;<br>    ssize_t val_len=0;<br>    SSL_SESSION *sess;<br><br>    *do_copy = 0; /* allow the session to be freed autmatically */<br>    cache_transfer(SSL_get_SSL_CTX(ssl), CACHE_CMD_GET, 0,<br>        key, (size_t)key_len, NULL, 0, &val, (size_t *)&val_len);<br>    if(!val)<br>        return NULL;<br>    val_tmp=val;<br>    sess=d2i_SSL_SESSION(NULL,<br>#if OPENSSL_VERSION_NUMBER>=0x0090800fL<br>        (const unsigned char **)<br>#endif /* OpenSSL version >= 0.8.0 */<br>        &val_tmp, val_len);<br>    str_free(val);</i><br><br>--->>> callbacks in v5.32<br>/**************************************** session callbacks */<br><br><i>NOEXPORT int sess_new_cb(SSL *ssl, SSL_SESSION *sess) {<br>    CLI *c;<br><br>    s_log(LOG_DEBUG, "New session callback");<br>    c=SSL_get_ex_data(ssl, index_cli);<br>    if(c->opt->option.sessiond)<br>        cache_new(ssl, sess);<br>    return 1; /* leave the session in local cache for reuse */<br>}<br><br>NOEXPORT SSL_SESSION *sess_get_cb(SSL *ssl,<br>#if OPENSSL_VERSION_NUMBER>=0x10100000L<br>        const<br>#endif<br>        unsigned char *key, int key_len, int *do_copy) {<br>    CLI *c;<br><br>    s_log(LOG_DEBUG, "Get session callback");<br>    *do_copy=0; /* allow the session to be freed automatically */<br>    c=SSL_get_ex_data(ssl, index_cli);<br>    if(c->opt->option.sessiond)<br>        return cache_get(ssl, key, key_len);<br>    return NULL; /* no session to resume */<br>}<br><br>NOEXPORT void sess_remove_cb(SSL_CTX *ctx, SSL_SESSION *sess) {<br>    SERVICE_OPTIONS *opt;<br><br>    s_log(LOG_DEBUG, "Remove session callback");<br>    opt=SSL_CTX_get_ex_data(ctx, index_opt);<br>    if(opt->option.sessiond)<br>        cache_remove(ctx, sess);<br>}</i><br><br><br></div><div>In production env. I have downgraded today at stunnel v5.26 and memory seems to be OK (untill now). <br></div><div><br></div><div>Regards,<br><br></div><div>Adrian Irimescu<br><br></div></div>