Re: Core dump happens with Apache 2.2.15 using openssl 0.9.8n

[matty roland <matty.roland1@xxxxxxxxx>]

Further to my problem mentioned below, I found possible flaw in Apache 2.2.15, which is mentioned below:

 

It is found with gdb that it is getting SIGSEGV as a result of accessing memory that is already free()ed.

 
After looking at the source code, possible root cause is mentioned below:

Here is the stack trace of free()ing the memoroy:

 

Breakpoint 1, 0x9fffffffef6c0b60:0 in free+0x10 ()

   from /usr/lib/hpux64/libdmalloc.so

$308 = 0x60000000002b1d00

#0  0x9fffffffef6c0b60:0 in free+0x10 () from /usr/lib/hpux64/libdmalloc.so

#1  0x9fffffffeeeb3230:0 in CRYPTO_free (str=0x60000000002b1d00) at mem.c:402

#2  0x9fffffffeef85200:0 in BIO_free (a=0x60000000002b1d00) at bio_lib.c:137

#3  0x9fffffffeef86e20:0 in BIO_free_all (bio=0x0) at bio_lib.c:516

#4  0x9fffffffeee8c670:0 in SSL_free (s=0x60000000000ab800) at ssl_lib.c:491

#5  0x9fffffffef0cf450:0 in ssl_filter_io_shutdown (

    filter_ctx=0x60000000002adaa0, c=0x60000000002ad1f8, abortive=1)

    at ssl_engine_io.c:1001

#6  0x9fffffffef0d0060:0 in ssl_io_filter_connect (

    filter_ctx=0x60000000002adaa0) at ssl_engine_io.c:1160

#7  0x9fffffffef0d1280:0 in ssl_io_filter_output (f=0x60000000002adad8,

    bb=0x600000000019a210) at ssl_engine_io.c:1429

#8  0x40000000000bfeb0:0 in ap_pass_brigade (next=0x60000000002adad8,

    bb=0x600000000019a210) at util_filter.c:526

#9  0x40000000000b5760:0 in ap_flush_conn (c=0x60000000002ad1f8)

    at connection.c:84

#10 0x40000000000b5870:0 in ap_lingering_close (c=0x60000000002ad1f8)

    at connection.c:123

#11 0x4000000000131e90:0 in process_socket (p=0x60000000002ad028,

    sock=0x60000000002ad0a0, my_child_num=0, my_thread_num=0,

    bucket_alloc=0x60000000002af028) at worker.c:545

#12 0x4000000000133650:0 in worker_thread (thd=0x60000000000fec70,

    dummy=0x600000000006fab0) at worker.c:894

#13 0x9fffffffef72e740:0 in dummy_worker (opaque=0x60000000000fec70)

    at threadproc/unix/thread.c:142

#14 0x9fffffffef3ccc00:0 in __pthread_bound_body+0x190 ()

   from /usr/lib/hpux64/libpthread.so.1

 

 

This is free()ing the address 0x60000000002b1d00.

 

And then it is accessing this address again and getting SIGSEGV:

 

Program received signal SIGSEGV, Segmentation fault

  si_code: 1 - SEGV_MAPERR - Address not mapped to object.

0x9fffffffef0ccef0:0 in bio_filter_out_flush (bio=0x60000000002b1d00)

    at ssl_engine_io.c:138

138         if (!(outctx->blen || outctx->length)) {

(gdb) bt

#0  0x9fffffffef0ccef0:0 in bio_filter_out_flush (bio=0x60000000002b1d00)

    at ssl_engine_io.c:138

#1  0x9fffffffef0d1390:0 in ssl_io_filter_output (f=0x60000000002adad8,

    bb=0x600000000019a210) at ssl_engine_io.c:1440

#2  0x40000000000bfeb0:0 in ap_pass_brigade (next=0x60000000002adad8,

    bb=0x600000000019a210) at util_filter.c:526

#3  0x40000000000b5760:0 in ap_flush_conn (c=0x60000000002ad1f8)

    at connection.c:84

#4  0x40000000000b5870:0 in ap_lingering_close (c=0x60000000002ad1f8)

    at connection.c:123

#5  0x4000000000131e90:0 in process_socket (p=0x60000000002ad028,

    sock=0x60000000002ad0a0, my_child_num=0, my_thread_num=0,

    bucket_alloc=0x60000000002af028) at worker.c:545

#6  0x4000000000133650:0 in worker_thread (thd=0x60000000000fec70,

    dummy=0x600000000006fab0) at worker.c:894

#7  0x9fffffffef72e740:0 in dummy_worker (opaque=0x60000000000fec70)

    at threadproc/unix/thread.c:142

#8  0x9fffffffef3ccc00:0 in __pthread_bound_body+0x190 ()

   from /usr/lib/hpux64/libpthread.so.1

 

Here is the explanation about my root cause analysis.

 

When freeing(), ssl_filter_io_shutdown() calls SSL_free()

and setting filter_ctx->pssl == NULL.

 

=====

    :

    /* deallocate the SSL connection */

    if (sslconn->client_cert) {

        X509_free(sslconn->client_cert);

        sslconn->client_cert = NULL;

    }

    SSL_free(ssl);

    sslconn->ssl = NULL;

    filter_ctx->pssl = NULL; /* so filters know we've been shutdown */

    :

    return APR_SUCCESS;

=====

 

Here seems to be the place where ssl_io_filter_connect()

and bio_filter_out_flush() are called within ssl_io_filter_output:

 

=====

                :

    if ((status = ssl_io_filter_connect(filter_ctx)) != APR_SUCCESS) {

        return ssl_io_filter_error(f, bb, status);

    }

 

    while (!APR_BRIGADE_EMPTY(bb)) {

        apr_bucket *bucket = APR_BRIGADE_FIRST(bb);

 

        /* If it is a flush or EOS, we need to pass this down.

         * These types do not require translation by OpenSSL.

         */

        if (APR_BUCKET_IS_EOS(bucket) || APR_BUCKET_IS_FLUSH(bucket)) {

            if (bio_filter_out_flush(filter_ctx->pbioWrite) < 0) {

                status = outctx->rc;

                break;

            }

                :

=====

 

At ssl_io_filter_connect() filter_ctx->pssl is already free()ed

but it is accessing it again at bio_filter_out_flush().

 

Thinking about the case for calling ssl_filter_io_shutdown(),I think it is terminating the connection so I think some error has happened.

So, I wonder ssl_io_filter_connect() should return error when it called ssl_filter_io_shutdown().

 

Looking at the source around here....

 

 

=====

                :

static int ssl_io_filter_connect(ssl_filter_ctx_t *filter_ctx)

{

                :

    if ((n = SSL_accept(filter_ctx->pssl)) <= 0) {

                :

        return ssl_filter_io_shutdown(filter_ctx, c, 1);

    }

 

    if ((verify_result != X509_V_OK) ||

        sslconn->verify_error)

    {

                :

            ap_log_cerror(APLOG_MARK, APLOG_INFO, 0, c,

                         "SSL client authentication failed: %s",

                         error ? error : "unknown");

            ssl_log_ssl_error(APLOG_MARK, APLOG_INFO, c->base_server);

 

            return ssl_filter_io_shutdown(filter_ctx, c, 1);

        }

    }

 

 

                :

 

    if ((sc->server->auth.verify_mode == SSL_CVERIFY_REQUIRE) &&

        !sslconn->client_cert)

    {

        ap_log_cerror(APLOG_MARK, APLOG_INFO, 0, c,

                      "No acceptable peer certificate available");

 

        return ssl_filter_io_shutdown(filter_ctx, c, 1);

    }

 return APR_SUCCESS;

}

                :

=====

 

In any case, it is just forwarding the return value of ssl_filter_io_shutdown() but I think we should return the error value after calling ssl_filter_io_shutdown().

Otherwise, ssl_filter_io_shutdown() will return APR_SUCCESS when it was successfully shutdown the ssl connection.

 

So, the fix will be returning appropriate error code after calling ssl_filter_io_shutdown() in ssl_io_filter_connect().

 

How do you think about this analysis?

 

If you agree with this analysis, please implement the fix ASAP in Apache.

Considering the error code to be returned after calling

ssl_filter_io_shutdown…

 

        if (inctx->rc == APR_SUCCESS) {

            inctx->rc = APR_EGENERAL;

        }

 

        return ssl_filter_io_shutdown(filter_ctx, c, 1);

    }

 

This will be:

 

        if (inctx->rc == APR_SUCCESS) {

            inctx->rc = APR_EGENERAL;

        }

 

        ssl_filter_io_shutdown(filter_ctx, c, 1);

       return ssl_err; /* set by SSL_get_error(). */

    }

 

For this part:

 

        else {

            const char *error = sslconn->verify_error ?

                sslconn->verify_error :

                X509_verify_cert_error_string(verify_result);

 

            ap_log_cerror(APLOG_MARK, APLOG_INFO, 0, c,

                         "SSL client authentication failed: %s",

                         error ? error : "unknown");

            ssl_log_ssl_error(APLOG_MARK, APLOG_INFO, c->base_server);

 

            return ssl_filter_io_shutdown(filter_ctx, c, 1);

        }

 

 

this will be:

 

        else {

            const char *error = sslconn->verify_error ?

                sslconn->verify_error :

                X509_verify_cert_error_string(verify_result);

 

            ap_log_cerror(APLOG_MARK, APLOG_INFO, 0, c,

                         "SSL client authentication failed: %s",

                         error ? error : "unknown");

            ssl_log_ssl_error(APLOG_MARK, APLOG_INFO, c->base_server);

 

            ssl_filter_io_shutdown(filter_ctx, c, 1);

           return (verify_result?verify_result:SSL_ERROR_SSL);

        }

 

For this:

 

    if ((sc->server->auth.verify_mode == SSL_CVERIFY_REQUIRE) &&

        !sslconn->client_cert)

    {

        ap_log_cerror(APLOG_MARK, APLOG_INFO, 0, c,

                      "No acceptable peer certificate available");

 

        return ssl_filter_io_shutdown(filter_ctx, c, 1);

    }

 

we may modify like:

 

    if ((sc->server->auth.verify_mode == SSL_CVERIFY_REQUIRE) &&

        !sslconn->client_cert)

    {

        ap_log_cerror(APLOG_MARK, APLOG_INFO, 0, c,

                      "No acceptable peer certificate available");

 

        ssl_filter_io_shutdown(filter_ctx, c, 1);

       return SSL_ERROR_SSL;

    }

 

At least we can avoid the crash with above change because it won’t return APR_SUCCESS.

 

I just looked at Apache 2.2.8 as well as Apache 2.0.63 code and code is same as that of Apache 2.2.15 for ssl_filter_io_shutdown regarding returning APR_SUCCESS.

So just wondering how come no user has encountered this problem till now after using Apache 2.0.x and Apache 2.2.x after so many years.

 

Expecting early reply to my analysis above.

 
Best Wishes,

 

Matty

 

On Thu, Jan 20, 2011 at 5:17 PM, matty roland <matty.roland1@xxxxxxxxx> wrote:

Hi All,

Below issue i am facing:
Core dump happens with Apache 2.2.15. Problem is happening under stress condition of normal http requests along with the additional condition of insecure client renegotiation requests generated. For insecure client renegotiation requests, "SSLInsecureRenegotiation" option is already set in the apache configuration.

Following is the core trace:

#0  0xc000000000203010:0 in memmove+0x350 ()
     from /mnt1/4624XXXXXX/4624461128/packcore/libc.so.1
  #1  0xc000000000a23a80:0 in buffer_write () at bf_buff.c:212
  #2  0xc000000000947760:0 in BIO_write () at bio_lib.c:247
  #3  0xc000000000a29cb0:0 in ssl3_write_pending () at s3_pkt.c:757
  #4  0xc000000000a295e0:0 in do_ssl3_write () at s3_pkt.c:723
  #5  0xc000000000a28e60:0 in ssl3_write_bytes () at s3_pkt.c:552
  #6  0xc000000000a28ba0:0 in ssl3_do_write () at s3_both.c:132
  #7  0xc000000000a2a380:0 in ssl3_send_server_hello () at
  s3_srvr.c:1213
  #8  0xc000000000a27410:0 in ssl3_accept () at s3_srvr.c:302
  #9  0xc000000000a8d160:0 in SSL_accept () at ssl_lib.c:870
  #10 0xc000000000ac2710:0 in ssl23_get_client_hello () at
  s23_srvr.c:583
  #11 0xc000000000ac24e0:0 in ssl23_accept () at s23_srvr.c:189
  #12 0xc000000000a8d160:0 in SSL_accept () at ssl_lib.c:870
  #13 0xc000000001108180:0 in <unknown_procedure> + 0x1a0 ()
     from /mnt1/4624XXXXXX/4624461128/packcore/mod_ssl.so
  #14 0xc0000000011093e0:0 in <unknown_procedure> + 0x120 ()
     from /mnt1/4624XXXXXX/4624461128/packcore/mod_ssl.so
  #15 0x40000000000c50d0:0 in ap_get_brigade () at util_filter.c:489
  #16 0x4000000000075060:0 in ap_rgetline_core () at protocol.c:231
  #17 0x4000000000076280:0 in read_request_line () at protocol.c:596
  #18 0x40000000000778f0:0 in ap_read_request () at protocol.c:891
  #19 0x40000000000c6900:0 in ap_process_http_connection () at
  http_core.c:183
  ---Type <return> to continue, or q <return> to quit---
  #20 0x40000000000b9ba0:0 in ap_process_connection () at
  connection.c:189
  #21 0x40000000000debe0:0 in process_socket () at worker.c:590
  #22 0x40000000000dffd0:0 in worker_thread () at worker.c:974
  #23 0xc0000000005da320:0 in dummy_worker () at
  threadproc/unix/thread.c:160
  #24 0xc0000000000ea0e0:0 in __pthread_bound_body ()
      at /ux/core/libs/threadslibs/src/common/pthreads/pthread.c:4612

We need to know whether this is a known issue with Apache 2.2.15 with openssl 0.9.8n  and any workaround available for this.

Your prompt response is highly appreciated.
Thanks in advance.
Regards,
Matty