You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@trafficserver.apache.org by "Sudheer Vinukonda (JIRA)" <ji...@apache.org> on 2014/05/01 01:48:14 UTC
[jira] [Updated] (TS-2767) ATS Memory Leak related to SPDY
[ https://issues.apache.org/jira/browse/TS-2767?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Sudheer Vinukonda updated TS-2767:
----------------------------------
Description:
During production testing of SPDY, we noticed ATS's memory quickly grows to about 20g RES and 31g VIRT and eventually becomes unresponsive. dstat shows a lot of disk/paging activity.
Running Valgrind on a single request (using spdycat) shows the below possible leaks.
{code}
==23000== 103 bytes in 1 blocks are possibly lost in loss record 3,133 of 3,823
==23000== at 0x4C285BC: operator new(unsigned long) (vg_replace_malloc.c:298)
==23000== by 0x72CC3C8: std::string::_Rep::_S_create(unsigned long, unsigned long, std::allocator<char> const&) (in /usr/lib64/libstdc++.so.6.0.13)
==23000== by 0x72CD19A: std::string::_Rep::_M_clone(std::allocator<char> const&, unsigned long) (in /usr/lib64/libstdc++.so.6.0.13)
==23000== by 0x72CD5EB: std::string::reserve(unsigned long) (in /usr/lib64/libstdc++.so.6.0.13)
==23000== by 0x72CDABE: std::string::append(std::string const&) (in /usr/lib64/libstdc++.so.6.0.13)
==23000== by 0x5D28DE: spdy_fetcher_launch(SpdyRequest*, TSFetchMethod) (basic_string.h:2165)
==23000== by 0x5D379D: spdy_on_ctrl_recv_callback(spdylay_session*, spdylay_frame_type, spdylay_frame*, void*) (SpdyCallbacks.cc:294)
==23000== by 0x715E9F: spdylay_session_on_syn_stream_received (spdylay_session.c:1782)
==23000== by 0x716BA6: spdylay_session_mem_recv (spdylay_session.c:2246)
==23000== by 0x716DD8: spdylay_session_recv (spdylay_session.c:2828)
==23000== by 0x5D0E57: spdy_default_handler(tsapi_cont*, TSEvent, void*) (SpdySM.cc:263)
==23000== by 0x6EC1A6: UnixNetVConnection::readSignalAndUpdate(int) (I_Continuation.h:146)
==23000==
==23000== 128 bytes in 1 blocks are possibly lost in loss record 3,256 of 3,823
==23000== at 0x4C285BC: operator new(unsigned long) (vg_replace_malloc.c:298)
==23000== by 0x5D3C8E: std::vector<std::pair<std::string, std::string>, std::allocator<std::pair<std::string, std::string> > >::_M_insert_aux(__gnu_cxx::__normal_iterator<std::pair<std::string, std::string>*, std::vector<std::pair<std::string, std::string>, std::allocator<std::pair<std::string, std::string> > > >, std::pair<std::string, std::string> const&) (new_allocator.h:89)
==23000== by 0x5D32CF: spdy_on_ctrl_recv_callback(spdylay_session*, spdylay_frame_type, spdylay_frame*, void*) (stl_vector.h:741)
==23000== by 0x715E9F: spdylay_session_on_syn_stream_received (spdylay_session.c:1782)
==23000== by 0x716BA6: spdylay_session_mem_recv (spdylay_session.c:2246)
==23000== by 0x716DD8: spdylay_session_recv (spdylay_session.c:2828)
==23000== by 0x5D0E57: spdy_default_handler(tsapi_cont*, TSEvent, void*) (SpdySM.cc:263)
==23000== by 0x6EC1A6: UnixNetVConnection::readSignalAndUpdate(int) (I_Continuation.h:146)
==23000== by 0x6DC779: SSLNetVConnection::net_read_io(NetHandler*, EThread*) (SSLNetVConnection.cc:294)
==23000== by 0x6E39F1: NetHandler::mainNetEvent(int, Event*) (UnixNet.cc:384)
==23000== by 0x71059E: EThread::process_event(Event*, int) (I_Continuation.h:146)
==23000== by 0x710DCA: EThread::execute() (UnixEThread.cc:269)
==23000==
==23000== 173 bytes in 5 blocks are possibly lost in loss record 3,303 of 3,823
==23000== at 0x4C285BC: operator new(unsigned long) (vg_replace_malloc.c:298)
==23000== by 0x72CC3C8: std::string::_Rep::_S_create(unsigned long, unsigned long, std::allocator<char> const&) (in /usr/lib64/libstdc++.so.6.0.13)
==23000== by 0x72CCDE4: ??? (in /usr/lib64/libstdc++.so.6.0.13)
==23000== by 0x72CCF32: std::basic_string<char, std::char_traits<char>, std::allocator<char> >::basic_string(char const*, std::allocator<char> const&) (in /usr/lib64/libstdc++.so.6.0.13)
==23000== by 0x5D32A2: spdy_on_ctrl_recv_callback(spdylay_session*, spdylay_frame_type, spdylay_frame*, void*) (stl_pair.h:101)
==23000== by 0x715E9F: spdylay_session_on_syn_stream_received (spdylay_session.c:1782)
==23000== by 0x716BA6: spdylay_session_mem_recv (spdylay_session.c:2246)
==23000== by 0x716DD8: spdylay_session_recv (spdylay_session.c:2828)
==23000== by 0x5D0E57: spdy_default_handler(tsapi_cont*, TSEvent, void*) (SpdySM.cc:263)
==23000== by 0x6EC1A6: UnixNetVConnection::readSignalAndUpdate(int) (I_Continuation.h:146)
==23000== by 0x6DC779: SSLNetVConnection::net_read_io(NetHandler*, EThread*) (SSLNetVConnection.cc:294)
==23000== by 0x6E39F1: NetHandler::mainNetEvent(int, Event*) (UnixNet.cc:384)
==23000==
{code}
Upon closer look, one possible issue might be the usage std::string in the SpdyRequest object. The string objects created during spdy request processing may not be getting released correctly.
Adding the below additional code in SpdyRequest::clear() to swap out the string objects with dummy/empty string objects seems to satisfy Valgrind to not report the above leaks. Am trying this version on the production host to confirm further.
{code}
void
SpdyRequest::clear()
{
if (fetch_sm)
TSFetchDestroy(fetch_sm);
vector<pair<string, string> >().swap(headers);
headers.clear();
std::string().swap(url);
std::string().swap(host);
std::string().swap(path);
std::string().swap(scheme);
std::string().swap(method);
std::string().swap(version);
Debug("spdy", "****Delete Request[%" PRIu64 ":%d]", spdy_sm->sm_id, stream_id);
}
{code}
was:
During production testing of SPDY, we noticed ATS's memory quickly grows to about 20g RES and 31g VIRT and eventually becomes unresponsive. dstat shows a lot of disk/paging activity.
Running Valgrind on a single request (using spdycat) shows the below possible leaks.
{code}
==23000== 103 bytes in 1 blocks are possibly lost in loss record 3,133 of 3,823
==23000== at 0x4C285BC: operator new(unsigned long) (vg_replace_malloc.c:298)
==23000== by 0x72CC3C8: std::string::_Rep::_S_create(unsigned long, unsigned long, std::allocator<char> const&) (in /usr/lib64/libstdc++.so.6.0.13)
==23000== by 0x72CD19A: std::string::_Rep::_M_clone(std::allocator<char> const&, unsigned long) (in /usr/lib64/libstdc++.so.6.0.13)
==23000== by 0x72CD5EB: std::string::reserve(unsigned long) (in /usr/lib64/libstdc++.so.6.0.13)
==23000== by 0x72CDABE: std::string::append(std::string const&) (in /usr/lib64/libstdc++.so.6.0.13)
==23000== by 0x5D28DE: spdy_fetcher_launch(SpdyRequest*, TSFetchMethod) (basic_string.h:2165)
==23000== by 0x5D379D: spdy_on_ctrl_recv_callback(spdylay_session*, spdylay_frame_type, spdylay_frame*, void*) (SpdyCallbacks.cc:294)
==23000== by 0x715E9F: spdylay_session_on_syn_stream_received (spdylay_session.c:1782)
==23000== by 0x716BA6: spdylay_session_mem_recv (spdylay_session.c:2246)
==23000== by 0x716DD8: spdylay_session_recv (spdylay_session.c:2828)
==23000== by 0x5D0E57: spdy_default_handler(tsapi_cont*, TSEvent, void*) (SpdySM.cc:263)
==23000== by 0x6EC1A6: UnixNetVConnection::readSignalAndUpdate(int) (I_Continuation.h:146)
==23000==
==23000== 128 bytes in 1 blocks are possibly lost in loss record 3,256 of 3,823
==23000== at 0x4C285BC: operator new(unsigned long) (vg_replace_malloc.c:298)
==23000== by 0x5D3C8E: std::vector<std::pair<std::string, std::string>, std::allocator<std::pair<std::string, std::string> > >::_M_insert_aux(__gnu_cxx::__normal_iterator<std::pair<std::string, std::string>*, std::vector<std::pair<std::string, std::string>, std::allocator<std::pair<std::string, std::string> > > >, std::pair<std::string, std::string> const&) (new_allocator.h:89)
==23000== by 0x5D32CF: spdy_on_ctrl_recv_callback(spdylay_session*, spdylay_frame_type, spdylay_frame*, void*) (stl_vector.h:741)
==23000== by 0x715E9F: spdylay_session_on_syn_stream_received (spdylay_session.c:1782)
==23000== by 0x716BA6: spdylay_session_mem_recv (spdylay_session.c:2246)
==23000== by 0x716DD8: spdylay_session_recv (spdylay_session.c:2828)
==23000== by 0x5D0E57: spdy_default_handler(tsapi_cont*, TSEvent, void*) (SpdySM.cc:263)
==23000== by 0x6EC1A6: UnixNetVConnection::readSignalAndUpdate(int) (I_Continuation.h:146)
==23000== by 0x6DC779: SSLNetVConnection::net_read_io(NetHandler*, EThread*) (SSLNetVConnection.cc:294)
==23000== by 0x6E39F1: NetHandler::mainNetEvent(int, Event*) (UnixNet.cc:384)
==23000== by 0x71059E: EThread::process_event(Event*, int) (I_Continuation.h:146)
==23000== by 0x710DCA: EThread::execute() (UnixEThread.cc:269)
==23000==
==23000== 173 bytes in 5 blocks are possibly lost in loss record 3,303 of 3,823
==23000== at 0x4C285BC: operator new(unsigned long) (vg_replace_malloc.c:298)
==23000== by 0x72CC3C8: std::string::_Rep::_S_create(unsigned long, unsigned long, std::allocator<char> const&) (in /usr/lib64/libstdc++.so.6.0.13)
==23000== by 0x72CCDE4: ??? (in /usr/lib64/libstdc++.so.6.0.13)
==23000== by 0x72CCF32: std::basic_string<char, std::char_traits<char>, std::allocator<char> >::basic_string(char const*, std::allocator<char> const&) (in /usr/lib64/libstdc++.so.6.0.13)
==23000== by 0x5D32A2: spdy_on_ctrl_recv_callback(spdylay_session*, spdylay_frame_type, spdylay_frame*, void*) (stl_pair.h:101)
==23000== by 0x715E9F: spdylay_session_on_syn_stream_received (spdylay_session.c:1782)
==23000== by 0x716BA6: spdylay_session_mem_recv (spdylay_session.c:2246)
==23000== by 0x716DD8: spdylay_session_recv (spdylay_session.c:2828)
==23000== by 0x5D0E57: spdy_default_handler(tsapi_cont*, TSEvent, void*) (SpdySM.cc:263)
==23000== by 0x6EC1A6: UnixNetVConnection::readSignalAndUpdate(int) (I_Continuation.h:146)
==23000== by 0x6DC779: SSLNetVConnection::net_read_io(NetHandler*, EThread*) (SSLNetVConnection.cc:294)
==23000== by 0x6E39F1: NetHandler::mainNetEvent(int, Event*) (UnixNet.cc:384)
==23000==
{code}
Upon closer look, one possible issue might be the usage std::string in the SpdyRequest object. The string objects created during spdy request processing may not be getting released correctly.
Adding the below additional code in SpdyRequest::clear() to swap out the string objects with dummy/empty string objects seems to satisfy Valgrind to not report the above leaks. Am trying this version on the production host to confirm further.
{code}
void
SpdyRequest::clear()
{
if (fetch_sm)
TSFetchDestroy(fetch_sm);
vector<pair<string, string> >().swap(headers);
headers.clear();
std::string().swap(url);
std::string().swap(host);
std::string().swap(path);
std::string().swap(scheme);
std::string().swap(method);
std::string().swap(version);
Debug("spdy", "****Delete Request[%" PRIu64 ":%d]", spdy_sm->sm_id, stream_id);
}
{code}
> ATS Memory Leak related to SPDY
> -------------------------------
>
> Key: TS-2767
> URL: https://issues.apache.org/jira/browse/TS-2767
> Project: Traffic Server
> Issue Type: Bug
> Components: SPDY
> Reporter: Sudheer Vinukonda
> Labels: SPDY_ATS, yahoo
>
> During production testing of SPDY, we noticed ATS's memory quickly grows to about 20g RES and 31g VIRT and eventually becomes unresponsive. dstat shows a lot of disk/paging activity.
> Running Valgrind on a single request (using spdycat) shows the below possible leaks.
> {code}
> ==23000== 103 bytes in 1 blocks are possibly lost in loss record 3,133 of 3,823
> ==23000== at 0x4C285BC: operator new(unsigned long) (vg_replace_malloc.c:298)
> ==23000== by 0x72CC3C8: std::string::_Rep::_S_create(unsigned long, unsigned long, std::allocator<char> const&) (in /usr/lib64/libstdc++.so.6.0.13)
> ==23000== by 0x72CD19A: std::string::_Rep::_M_clone(std::allocator<char> const&, unsigned long) (in /usr/lib64/libstdc++.so.6.0.13)
> ==23000== by 0x72CD5EB: std::string::reserve(unsigned long) (in /usr/lib64/libstdc++.so.6.0.13)
> ==23000== by 0x72CDABE: std::string::append(std::string const&) (in /usr/lib64/libstdc++.so.6.0.13)
> ==23000== by 0x5D28DE: spdy_fetcher_launch(SpdyRequest*, TSFetchMethod) (basic_string.h:2165)
> ==23000== by 0x5D379D: spdy_on_ctrl_recv_callback(spdylay_session*, spdylay_frame_type, spdylay_frame*, void*) (SpdyCallbacks.cc:294)
> ==23000== by 0x715E9F: spdylay_session_on_syn_stream_received (spdylay_session.c:1782)
> ==23000== by 0x716BA6: spdylay_session_mem_recv (spdylay_session.c:2246)
> ==23000== by 0x716DD8: spdylay_session_recv (spdylay_session.c:2828)
> ==23000== by 0x5D0E57: spdy_default_handler(tsapi_cont*, TSEvent, void*) (SpdySM.cc:263)
> ==23000== by 0x6EC1A6: UnixNetVConnection::readSignalAndUpdate(int) (I_Continuation.h:146)
> ==23000==
> ==23000== 128 bytes in 1 blocks are possibly lost in loss record 3,256 of 3,823
> ==23000== at 0x4C285BC: operator new(unsigned long) (vg_replace_malloc.c:298)
> ==23000== by 0x5D3C8E: std::vector<std::pair<std::string, std::string>, std::allocator<std::pair<std::string, std::string> > >::_M_insert_aux(__gnu_cxx::__normal_iterator<std::pair<std::string, std::string>*, std::vector<std::pair<std::string, std::string>, std::allocator<std::pair<std::string, std::string> > > >, std::pair<std::string, std::string> const&) (new_allocator.h:89)
> ==23000== by 0x5D32CF: spdy_on_ctrl_recv_callback(spdylay_session*, spdylay_frame_type, spdylay_frame*, void*) (stl_vector.h:741)
> ==23000== by 0x715E9F: spdylay_session_on_syn_stream_received (spdylay_session.c:1782)
> ==23000== by 0x716BA6: spdylay_session_mem_recv (spdylay_session.c:2246)
> ==23000== by 0x716DD8: spdylay_session_recv (spdylay_session.c:2828)
> ==23000== by 0x5D0E57: spdy_default_handler(tsapi_cont*, TSEvent, void*) (SpdySM.cc:263)
> ==23000== by 0x6EC1A6: UnixNetVConnection::readSignalAndUpdate(int) (I_Continuation.h:146)
> ==23000== by 0x6DC779: SSLNetVConnection::net_read_io(NetHandler*, EThread*) (SSLNetVConnection.cc:294)
> ==23000== by 0x6E39F1: NetHandler::mainNetEvent(int, Event*) (UnixNet.cc:384)
> ==23000== by 0x71059E: EThread::process_event(Event*, int) (I_Continuation.h:146)
> ==23000== by 0x710DCA: EThread::execute() (UnixEThread.cc:269)
> ==23000==
> ==23000== 173 bytes in 5 blocks are possibly lost in loss record 3,303 of 3,823
> ==23000== at 0x4C285BC: operator new(unsigned long) (vg_replace_malloc.c:298)
> ==23000== by 0x72CC3C8: std::string::_Rep::_S_create(unsigned long, unsigned long, std::allocator<char> const&) (in /usr/lib64/libstdc++.so.6.0.13)
> ==23000== by 0x72CCDE4: ??? (in /usr/lib64/libstdc++.so.6.0.13)
> ==23000== by 0x72CCF32: std::basic_string<char, std::char_traits<char>, std::allocator<char> >::basic_string(char const*, std::allocator<char> const&) (in /usr/lib64/libstdc++.so.6.0.13)
> ==23000== by 0x5D32A2: spdy_on_ctrl_recv_callback(spdylay_session*, spdylay_frame_type, spdylay_frame*, void*) (stl_pair.h:101)
> ==23000== by 0x715E9F: spdylay_session_on_syn_stream_received (spdylay_session.c:1782)
> ==23000== by 0x716BA6: spdylay_session_mem_recv (spdylay_session.c:2246)
> ==23000== by 0x716DD8: spdylay_session_recv (spdylay_session.c:2828)
> ==23000== by 0x5D0E57: spdy_default_handler(tsapi_cont*, TSEvent, void*) (SpdySM.cc:263)
> ==23000== by 0x6EC1A6: UnixNetVConnection::readSignalAndUpdate(int) (I_Continuation.h:146)
> ==23000== by 0x6DC779: SSLNetVConnection::net_read_io(NetHandler*, EThread*) (SSLNetVConnection.cc:294)
> ==23000== by 0x6E39F1: NetHandler::mainNetEvent(int, Event*) (UnixNet.cc:384)
> ==23000==
> {code}
> Upon closer look, one possible issue might be the usage std::string in the SpdyRequest object. The string objects created during spdy request processing may not be getting released correctly.
> Adding the below additional code in SpdyRequest::clear() to swap out the string objects with dummy/empty string objects seems to satisfy Valgrind to not report the above leaks. Am trying this version on the production host to confirm further.
> {code}
> void
> SpdyRequest::clear()
> {
> if (fetch_sm)
> TSFetchDestroy(fetch_sm);
> vector<pair<string, string> >().swap(headers);
> headers.clear();
> std::string().swap(url);
> std::string().swap(host);
> std::string().swap(path);
> std::string().swap(scheme);
> std::string().swap(method);
> std::string().swap(version);
> Debug("spdy", "****Delete Request[%" PRIu64 ":%d]", spdy_sm->sm_id, stream_id);
> }
> {code}
--
This message was sent by Atlassian JIRA
(v6.2#6252)