[
https://issues.apache.org/jira/browse/TS-3029?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=14259879#comment-14259879
]
Wei Sun commented on TS-3029:
-----------------------------
We observed the following error logs when the crash happened:
[Aug 19 16:00:16.381] Server {0x2b8fa6f5e700} ERROR: spdy_process_fetch fetch
error, fetch_sm 0x2b907bb63d10, ret -1 for sm_id 6086046, stream_id 103, req
time 1408464016381152420, url
https://s.yimg.com/bt/api/res/1.2/MzHNr6ctgTgvHxpIc2CQQw--/YXBwaWQ9eW5ld3M7Zmk9ZmlsbDtoPTk4O3B5b2ZmPTE1O3E9NzU7dz0xODA-/http://media.zenfs.com/en_GB/Sports/Eurosport/1139793-18355072-2560-1440.jpg
[Aug 19 16:00:16.381] Server {0x2b8fa6f5e700} ERROR: spdy_process_fetch sending
STATUS_500, fetch_sm (nil), ret -1 for sm_id 6086046, stream_id 103, req time
1408464016381152420, url
https://s.yimg.com/bt/api/res/1.2/MzHNr6ctgTgvHxpIc2CQQw--/YXBwaWQ9eW5ld3M7Zmk9ZmlsbDtoPTk4O3B5b2ZmPTE1O3E9NzU7dz0xODA-/http://media.zenfs.com/en_GB/Sports/Eurosport/1139793-18355072-2560-1440.jpg
[Aug 19 16:00:16.429] Server {0x2b8fa6f5e700} ERROR: spdy_process_fetch fetch
error, fetch_sm (nil), ret -1 for sm_id 6086046, stream_id 103, req time
1408464016381152420, url
[Aug 19 16:00:16.429] Server {0x2b8fa6f5e700} ERROR: spdy_process_fetch sending
STATUS_500, fetch_sm (nil), ret -1 for sm_id 6086046, stream_id 103, req time
1408464016381152420, url
Looks like the stream request (SpdyRequest* req) was erased from the req_map
due to a fetch error, but the same stream request was accessed again.
{code}
(gdb) f 1
#1 0x000000000061e386 in spdy_prepare_status_response (sm=0x2b90b68a5d90,
stream_id=103, status=0x792cad "500 Internal Server Error") at
SpdyCallbacks.cc:57
57 SpdyCallbacks.cc: No such file or directory.
in SpdyCallbacks.cc
(gdb) p req
$10 = (SpdyRequest *) 0x0
(gdb) p sm->req_map
$11 = std::map with 1 elements = {
[103] = 0x0
}
(gdb) f 2
#2 0x000000000061b4ef in spdy_process_fetch (event=TS_EVENT_VCONN_READ_READY,
sm=0x2b90b68a5d90, edata=0x2b907bb63d10) at SpdyClientSession.cc:381
381 SpdyClientSession.cc: No such file or directory.
in SpdyClientSession.cc
(gdb) p req
$12 = (SpdyRequest *) 0x2b932f141d70
{code}
Ran the below fix for several months, didn't observe the same issue.
{code}
diff --git a/proxy/spdy/SpdyClientSession.cc b/proxy/spdy/SpdyClientSession.cc
index 79fed77..58e544f 100644
--- a/proxy/spdy/SpdyClientSession.cc
+++ b/proxy/spdy/SpdyClientSession.cc
@@ -371,7 +371,6 @@ spdy_process_fetch(TSEvent event, SpdyClientSession *sm,
void *edata)
ret = 0; // Ignore fetch errors after FETCH BODY DONE
else {
Error("spdy_process_fetch fetch error, fetch_sm %p, ret %d for sm_id %"
PRId64 ", stream_id %u, req time %" PRId64 ", url %s", req->fetch_sm, ret,
sm->sm_id, req->stream_id, req->start_time, req->url.c_str());
- req->fetch_sm = NULL;
}
break;
}
{code}
> ats-5.0.1 crash when SPDY enabled
> ---------------------------------
>
> Key: TS-3029
> URL: https://issues.apache.org/jira/browse/TS-3029
> Project: Traffic Server
> Issue Type: Bug
> Components: SPDY
> Reporter: Wei Sun
> Labels: yahoo
> Fix For: 5.3.0
>
>
> {code}
> #0 0x00000000006200ba in std::vector<std::pair<std::basic_string<char,
> std::char_traits<char>, std::allocator<char> >, std::basic_string<char,
> std::char_traits<char>, std::allocator<char> > >,
> std::allocator<std::pair<std::basic_string<char, std::char_traits<char>,
> std::allocator<char> >, std::basic_string<char, std::char_traits<char>,
> std::allocator<char> > > > >::size (this=0x38)
> at
> /usr/lib/gcc/x86_64-redhat-linux/4.4.7/../../../../include/c++/4.4.7/bits/stl_vector.h:533
> #1 0x000000000061e386 in spdy_prepare_status_response (sm=0x2b90b68a5d90,
> stream_id=103, status=0x792cad "500 Internal Server Error") at
> SpdyCallbacks.cc:57
> #2 0x000000000061b4ef in spdy_process_fetch (event=TS_EVENT_VCONN_READ_READY,
> sm=0x2b90b68a5d90, edata=0x2b907bb63d10) at SpdyClientSession.cc:381
> #3 0x000000000061af63 in SpdyClientSession::state_session_readwrite
> (this=0x2b90b68a5d90, event=100, edata=0x2b907bb63d10) at
> SpdyClientSession.cc:284
> #4 0x00000000004f460e in Continuation::handleEvent (this=0x2b90b68a5d90,
> event=100, data=0x2b907bb63d10) at ../iocore/eventsystem/I_Continuation.h:146
> #5 0x00000000004f28b0 in FetchSM::InvokePluginExt (this=0x2b907bb63d10,
> error_event=100) at FetchSM.cc:239
> #6 0x00000000004f3620 in FetchSM::fetch_handler (this=0x2b907bb63d10,
> event=100, edata=0x2b90c23d8d48) at FetchSM.cc:479
> #7 0x00000000004f460e in Continuation::handleEvent (this=0x2b907bb63d10,
> event=100, data=0x2b90c23d8d48) at ../iocore/eventsystem/I_Continuation.h:146
> #8 0x000000000053054d in PluginVC::process_read_side (this=0x2b90c23d8c50,
> other_side_call=true) at PluginVC.cc:671
> #9 0x000000000052fde2 in PluginVC::process_write_side (this=0x2b90c23d8e30,
> other_side_call=false) at PluginVC.cc:567
> #10 0x000000000052eb84 in PluginVC::main_handler (this=0x2b90c23d8e30,
> event=1,
> data=0x2b90a2a6da00) at PluginVC.cc:212
> #11 0x00000000004f460e in Continuation::handleEvent (this=0x2b90c23d8e30,
> event=1, data=0x2b90a2a6da00) at ../iocore/eventsystem/I_Continuation.h:146
> #12 0x0000000000751dca in EThread::process_event (this=0x2b8fa5646010,
> e=0x2b90a2a6da00, calling_code=1) at UnixEThread.cc:145
> #13 0x0000000000751f98 in EThread::execute (this=0x2b8fa5646010) at
> UnixEThread.cc:196
> #14 0x0000000000751328 in spawn_thread_internal (a=0x262c020) at Thread.cc:88
> #15 0x00002b8f08129851 in start_thread () from /lib64/libpthread.so.0
> #16 0x0000003d158e890d in clone () from /lib64/libc.so.6
> {code}
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
