Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Occasional crash in client when server disconnects (std::logic_error: uninitialized stream object) #979

Closed
zpalmtree opened this issue Nov 21, 2018 · 11 comments

Comments

@zpalmtree
Copy link

zpalmtree commented Nov 21, 2018

I've got this library working well in my client, however, I'm having a rare exception thrown which I can't handle, when the server terminates. After closing the server, occasionally, a few seconds after, the client will terminate with:

terminate called after throwing an instance of 'std::logic_error'
  what():  uninitialized stream object

This appears to be thrown from here: https://github.com/Microsoft/cpprestsdk/blob/2a19d84af30567ad6c1ce6d14ab13f89bb618d74/Release/include/cpprest/streams.h

Note that I am not running cpprestsdk on the server - It's a custom stack.

Now, I have no issue with it throwing if the server disconnects, that's to be expected. However, it's an exception thrown in another thread, so I am unable to catch it.

Most of the time, I'll get one of these exceptions:

Caught exception: Failed to read HTTP status line
Caught exception: Failed to write request body
Caught exception: Failed to connect to any resolved endpoint

All good - I can just put a catch around my .wait() or .get() and handle them.

However, with the std::logic_error, we can see from the backtrace that it is thrown in another thread, so there is no way for us to catch it (I think):

(gdb) bt
#0  0x00007f5660c67d7f in raise () from /usr/lib/libc.so.6
#1  0x00007f5660c52672 in abort () from /usr/lib/libc.so.6
#2  0x00007f566101e58e in __gnu_cxx::__verbose_terminate_handler () at /build/gcc/src/gcc/libstdc++-v3/libsupc++/vterminate.cc:95
#3  0x00007f5661024dfa in __cxxabiv1::__terminate (handler=<optimized out>) at /build/gcc/src/gcc/libstdc++-v3/libsupc++/eh_terminate.cc:47
#4  0x00007f5661024e57 in std::terminate () at /build/gcc/src/gcc/libstdc++-v3/libsupc++/eh_terminate.cc:57
#5  0x000055c7ff06be9f in __clang_call_terminate () at /usr/bin/../lib64/gcc/x86_64-pc-linux-gnu/8.2.1/../../../../include/c++/8.2.1/bits/basic_string.h:657
#6  0x000055c7ff35d441 in (anonymous namespace)::threadpool_impl::thread_start (arg=0x55c7ff764770 <(anonymous namespace)::initialize_shared_threadpool(unsigned long)::storage>)
    at /home/zach/Code/turtlecoin/turtlecoin/external/cpprestsdk/Release/src/pplx/threadpool.cpp:99
#7  0x000055c7ff35d3e8 in (anonymous namespace)::threadpool_impl::add_thread()::{lambda()#1}::operator()() const (this=0x55c8009e25d8)
    at /home/zach/Code/turtlecoin/turtlecoin/external/cpprestsdk/Release/src/pplx/threadpool.cpp:81
#8  0x000055c7ff35d3c9 in boost::asio::detail::posix_thread::func<(anonymous namespace)::threadpool_impl::add_thread()::{lambda()#1}>::run() (this=0x55c8009e25d0)
    at /usr/include/boost/asio/detail/posix_thread.hpp:86
#9  0x000055c7ff361c39 in boost::asio::detail::boost_asio_detail_posix_thread_function (arg=0x55c8009e25d0) at /usr/include/boost/asio/detail/impl/posix_thread.ipp:74
#10 0x00007f566112ba9d in start_thread () from /usr/lib/libpthread.so.0
#11 0x00007f5660d2bb23 in clone () from /usr/lib/libc.so.6

Am I doing something wrong, or is this a fault in the library? Here's a slightly simplified version of what I'm doing:

void Proxy::backgroundRefresh()
{
    while (!m_shouldStop)
    {
        try
        {
            getDaemonInfo().wait();
        }
        catch (const std::exception &e)
        {
            std::cout << "Caught exception: " << e.what() << std::endl;
        }

        Utilities::sleepUnlessStopping(std::chrono::seconds(10), m_shouldStop);
    }
}

pplx::task<void> Proxy::getDaemonInfo()
{
    return m_httpClient->request(methods::GET, "/getinfo").then(
    [](http_response response)
    {
        return response.extract_string(true);
    })
    .then([this](std::string body)
    {
        // do some stuff
    });
}

I'm running this code, and in another thread calling another function, which does basically the same thing. Is it possible this is due to me using multiple threads? It seems strange that disconnecting the server would cause the crash, whilst it does not crash at any other point.

The other function:

std::vector<WalletTypes::WalletBlockInfo> Proxy::getWalletSyncData(
    const std::vector<Crypto::Hash> blockHashCheckpoints,
    uint64_t startHeight,
    uint64_t startTimestamp) const
{
    http_request req(methods::POST);
    req.set_request_uri("/getwalletsyncdata");

    json j = {
        {"blockHashCheckpoints", blockHashCheckpoints},
        {"startHeight", startHeight},
        {"startTimestamp", startTimestamp}
    };

    req.set_body(j.dump());

    try
    {
        return m_httpClient->request(req).then(
        [](http_response response)
        {
            return response.extract_string(true);
        })
        .then([](std::string body) -> std::vector<WalletTypes::WalletBlockInfo>
        {
            try
            {
                json j = json::parse(body);

                if (j.at("status").get<std::string>() != "OK")
                {
                     return {};
                }

                return j.at("items").get<std::vector<WalletTypes::WalletBlockInfo>>();
             }
             catch (const json::exception &e)
             {
                std::cout << "Caught exception: " << e.what() << std::endl;
             }

             return {};
        }).get();
    }
    catch (const std::exception &e)
    {
         std::cout << "Caught exception: " << e.what() << std::endl;
         return {};
    }
}

Possibly related to #857 - but I see that's been patched.

System info: Linux
Compiler: Clang-7
Library version: v2.10.8

Thanks.

@Tymolc
Copy link
Contributor

Tymolc commented Nov 23, 2018

Looks very much like #857, indeed. We (@reneme) actually managed to reproduce this again with 2.10.7.

@reneme
Copy link
Contributor

reneme commented Nov 26, 2018

That it happens when the server disconnects is an interesting observation. As a short-term solution, I'd advice you to downgrade to cpprestsdk 2.10.2, which doesn't suffer from this problem.

@fcharlie
Copy link

fcharlie commented Jan 9, 2019

@reneme @BillyONeal When I use the startup cpprestsdk to connect to the HTTP server, loop the request server, then close the HTTP server, and then the same error occurs.

Request:

GET path/to/some/url

Stacktrace:

   #0 0x5655299473ea in std::__shared_ptr<pplx::scheduler_interface, (__gnu_cxx::_Lock_policy)2>::__shared_ptr(std::__shared_ptr<pplx::scheduler_interface, (__gnu_cxx::_Lock_policy)2> const&) /usr/include/c++/7/bits/shared_ptr_base.h:1121
    #1 0x565529a0d106 in std::shared_ptr<Concurrency::streams::details::basic_streambuf<unsigned char> >::shared_ptr(std::shared_ptr<Concurrency::streams::details::basic_streambuf<unsigned char> > const&) /usr/include/c++/7/bits/shared_ptr.h:119
    #2 0x565529a0d106 in Concurrency::streams::streambuf<unsigned char>::streambuf(Concurrency::streams::streambuf<unsigned char> const&) /home/charlie/development/server/svnsbz/build/cpprestsdk-prefix/src/cpprestsdk/Release/include/cpprest/astreambuf.h:819
    #3 0x565529a0d106 in Concurrency::streams::details::basic_istream_helper<unsigned char>::basic_istream_helper(Concurrency::streams::details::basic_istream_helper<unsigned char> const&) /home/charlie/development/server/svnsbz/build/cpprestsdk-prefix/src/cpprestsdk/Release/include/cpprest/streams.h:42
    #4 0x565529a0d106 in Concurrency::streams::basic_istream<unsigned char>::helper() const /home/charlie/development/server/svnsbz/build/cpprestsdk-prefix/src/cpprestsdk/Release/include/cpprest/streams.h:1094
    #5 0x565529a706e2 in Concurrency::streams::basic_istream<unsigned char>::_verify_and_throw(char const*) const /home/charlie/development/server/svnsbz/build/cpprestsdk-prefix/src/cpprestsdk/Release/include/cpprest/streams.h:1083
    #6 0x565529ad9096 in seek /home/charlie/development/server/svnsbz/build/cpprestsdk-prefix/src/cpprestsdk/Release/include/cpprest/streams.h:987
    #7 0x565529ad9096 in web::http::client::details::asio_context::handle_failed_read_status_line(boost::system::error_code const&, char const*) /home/charlie/development/server/svnsbz/build/cpprestsdk-prefix/src/cpprestsdk/Release/src/http/client/http_client_asio.cpp:1325
    #8 0x565529aeb073 in handle_status_line /home/charlie/development/server/svnsbz/build/cpprestsdk-prefix/src/cpprestsdk/Release/src/http/client/http_client_asio.cpp:1308
    #9 0x565529b0d6ad in void boost::_mfi::mf1<void, web::http::client::details::asio_context, boost::system::error_code const&>::call<std::shared_ptr<web::http::client::details::asio_context>, boost::system::error_code const>(std::shared_ptr<web::http::client::details::asio_context>&, void const*, boost::system::error_code const&) const /home/charlie/development/server/svnsbz/build/cleanroot/include/boost/bind/mem_fn_template.hpp:156
    #10 0x565529b0d6ad in operator() /home/charlie/development/server/svnsbz/build/cleanroot/include/boost/bind/mem_fn_template.hpp:171
    #11 0x565529b0eb0b in boost::asio::detail::binder2<boost::asio::detail::read_until_delim_string_op<boost::asio::basic_stream_socket<boost::asio::ip::tcp>, boost::asio::basic_streambuf_ref<std::allocator<char> >, boost::_bi::bind_t<void, boost::_mfi::mf1<void, web::http::client::details::asio_context, boost::system::error_code const&>, boost::_bi::list2<boost::_bi::value<std::shared_ptr<web::http::client::details::asio_context> >, boost::arg<1> (*)()> > >, boost::system::error_code, unsigned long>::operator()() /home/charlie/development/server/svnsbz/build/cleanroot/include/boost/asio/detail/bind_handler.hpp:164
    #12 0x565529b0eb0b in do_complete /home/charlie/development/server/svnsbz/build/cleanroot/include/boost/asio/handler_invoke_hook.hpp:69
    #13 0x565529855e82 in boost::asio::detail::scheduler_operation::complete(void*, boost::system::error_code const&, unsigned long) /home/charlie/development/server/svnsbz/build/cleanroot/include/boost/asio/detail/scheduler_operation.hpp:40
    #14 0x56552986220c in boost::asio::detail::scheduler::do_run_one(boost::asio::detail::conditionally_enabled_mutex::scoped_lock&, boost::asio::detail::scheduler_thread_info&, boost::system::error_code const&) /home/charlie/development/server/svnsbz/build/cleanroot/include/boost/asio/detail/impl/scheduler.ipp:401
    #15 0x56552986128f in boost::asio::detail::scheduler::run(boost::system::error_code&) /home/charlie/development/server/svnsbz/build/cleanroot/include/boost/asio/detail/impl/scheduler.ipp:154
    #16 0x565529a2911a in boost::asio::io_context::run() [clone .isra.309] /home/charlie/development/server/svnsbz/build/cleanroot/include/boost/asio/impl/io_context.ipp:62
    #17 0x565529a2911a in thread_start /home/charlie/development/server/svnsbz/build/cpprestsdk-prefix/src/cpprestsdk/Release/src/pplx/threadpool.cpp:99
    #18 0x565529a2911a in operator() /home/charlie/development/server/svnsbz/build/cpprestsdk-prefix/src/cpprestsdk/Release/src/pplx/threadpool.cpp:81
    #19 0x565529a2911a in run /home/charlie/development/server/svnsbz/build/cleanroot/include/boost/asio/detail/posix_thread.hpp:86
    #20 0x5655299396ba in boost_asio_detail_posix_thread_function /home/charlie/development/server/svnsbz/build/cleanroot/include/boost/asio/detail/impl/posix_thread.ipp:74
    #21 0x7f4d08d9a6da in start_thread (/lib/x86_64-linux-gnu/libpthread.so.0+0x76da)
    #22 0x7f4d08ac388e in __clone (/lib/x86_64-linux-gnu/libc.so.6+0x12188e)

AddressSanitizer can not provide additional info.
SUMMARY: AddressSanitizer: SEGV /usr/include/c++/7/bits/shared_ptr_base.h:1121 in std::__shared_ptr<pplx::scheduler_interface, (__gnu_cxx::_Lock_policy)2>::__shared_ptr(std::__shared_ptr<pplx::scheduler_interface, (__gnu_cxx::_Lock_policy)2> const&)
Thread T2 created by T0 here:
    #0 0x7f4d091edd2f in __interceptor_pthread_create (/usr/lib/x86_64-linux-gnu/libasan.so.4+0x37d2f)
    #1 0x565529a42f7d in boost::asio::detail::posix_thread::start_thread(boost::asio::detail::posix_thread::func_base*) /home/charlie/development/server/svnsbz/build/cleanroot/include/boost/asio/detail/impl/posix_thread.ipp:60
    #2 0x565529a42f7d in boost::asio::detail::posix_thread::posix_thread<(anonymous namespace)::threadpool_impl::add_thread()::{lambda()#1}>((anonymous namespace)::threadpool_impl::add_thread()::{lambda()#1}, unsigned int) [clone .isra.308] /home/charlie/development/server/svnsbz/build/cleanroot/include/boost/asio/detail/posix_thread.hpp:46
    #3 0x565529a42f7d in add_thread /home/charlie/development/server/svnsbz/build/cpprestsdk-prefix/src/cpprestsdk/Release/src/pplx/threadpool.cpp:81
    #4 0x565529a42f7d in __base_ctor  /home/charlie/development/server/svnsbz/build/cpprestsdk-prefix/src/cpprestsdk/Release/src/pplx/threadpool.cpp:60
    #5 0x565529a42f7d in operator() /home/charlie/development/server/svnsbz/build/cpprestsdk-prefix/src/cpprestsdk/Release/src/pplx/threadpool.cpp:171
    #6 0x565529a42f7d in operator() /usr/include/c++/7/bits/invoke.h:60
    #7 0x565529a42f7d in operator() /usr/include/c++/7/mutex:677
    #8 0x565529a42f7d in void std::call_once<(anonymous namespace)::initialize_shared_threadpool(unsigned long)::{lambda()#1}>(std::once_flag&, (anonymous namespace)::initialize_shared_threadpool(unsigned long)::{lambda()#1}&&)::{lambda()#2}::_FUN() [clone .lto_priv.550] /usr/include/c++/7/mutex:677

https://github.com/Microsoft/cpprestsdk/blob/v2.10.8/Release/src/http/client/http_client_asio.cpp#L1325

Connect is closed:

    void handle_failed_read_status_line(const boost::system::error_code& ec, const char* generic_error_message)
    {
        if (m_connection->was_reused_and_closed_by_server(ec))
        {
            // Failed to write to socket because connection was already closed while it was in the pool.
            // close() here ensures socket is closed in a robust way and prevents the connection from being put to the
            // pool again.
            m_connection->close();

            // Create a new context and copy the request object, completion event and
            // cancellation registration to maintain the old state.
            // This also obtains a new connection from pool.
            auto new_ctx = create_request_context(m_http_client, m_request);
            new_ctx->m_request._get_impl()->instream().seek(0);
            new_ctx->m_request_completion = m_request_completion;
            new_ctx->m_cancellationRegistration = m_cancellationRegistration;

            auto client = std::static_pointer_cast<asio_client>(m_http_client);
            // Resend the request using the new context.
            client->send_request(new_ctx);
        }
        else
        {
            report_error(generic_error_message, ec, httpclient_errorcode_context::readheader);
        }
    }
       new_ctx->m_request._get_impl()->instream().seek(0);

seek() throw error

https://github.com/Microsoft/cpprestsdk/blob/v2.10.8/Release/include/cpprest/streams.h#L1083

        void _verify_and_throw(const char *msg) const
        {
            auto buffer = helper()->m_buffer;
            if ( !(buffer.exception() == nullptr) )
                std::rethrow_exception(buffer.exception());
            if ( !buffer.can_read() )
                throw std::runtime_error(msg);
        }

Hotfix:

diff --git a/Release/src/http/client/http_client_asio.cpp b/Release/src/http/client/http_client_asio.cpp
index 0ef90695..ef8c56a9 100644
--- a/Release/src/http/client/http_client_asio.cpp
+++ b/Release/src/http/client/http_client_asio.cpp
@@ -1322,7 +1322,10 @@ private:
             // cancellation registration to maintain the old state.
             // This also obtains a new connection from pool.
             auto new_ctx = create_request_context(m_http_client, m_request);
-            new_ctx->m_request._get_impl()->instream().seek(0);
+            if (new_ctx->m_request._get_impl()->instream().can_seek())
+            {
+               new_ctx->m_request._get_impl()->instream().seek(0);
+            }
             new_ctx->m_request_completion = m_request_completion;
             new_ctx->m_cancellationRegistration = m_cancellationRegistration;

Test OK.

@BillyONeal
Copy link
Member

I think we need to report that situation as an error because the request can't be meaningfully restarted without seek.

@fcharlie
Copy link

I think we need to report that situation as an error because the request can't be meaningfully restarted without seek.

For GET requests, there is definitely no request body, and the seek call is not appropriate.

@BillyONeal
Copy link
Member

Sure, if there wasn't a body at all we shouldn't even be trying that.

@reneme
Copy link
Contributor

reneme commented Jan 16, 2019

I opened a PR that builds on @fcharlie's hotfix and extends it with some error reporting at least. Some feedback would be appreciated.

@aowrew
Copy link

aowrew commented Jan 16, 2019

For those who can't wait for the solution to be released - setting the body to an empty string for GET requests worked for me (linux).

http_request request(http::methods::GET);
request.set_body("");

@reneme
Copy link
Contributor

reneme commented Jan 16, 2019

@zpalmtree Probably this could be closed with our PR merged into master. Please feel free to verify that it works for you now.

@zpalmtree
Copy link
Author

@reneme Thank you for your work, unfortunately I ended up using another library as the crashes were too frequent for my use case. I'll reopen if I end up using the library again and hit this issue.

@garethsb
Copy link
Contributor

FWIW, my team also found an easy repro for the exact exception shown by the OP in v2.10.8 and have confirmed as working correctly in v2.10.10. Thank you for the fix.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

7 participants