You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@trafficserver.apache.org by "Nick Kew (Issue Comment Edited) (JIRA)" <ji...@apache.org> on 2011/11/06 00:56:51 UTC
[jira] [Issue Comment Edited] (TS-1007) SSN Close called before TXN
Close
[ https://issues.apache.org/jira/browse/TS-1007?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13144873#comment-13144873 ]
Nick Kew edited comment on TS-1007 at 11/5/11 11:56 PM:
--------------------------------------------------------
Having said Blocker, I meant *potential blocker*. I don't think it's actually causing a race condition in my plugin. Downgrading.
I've looked at the tracebacks for this. It's coming from HttpTunnel::main_handler at lines 1456 and 1468 respectively, and I've verified that it's the same call to Http::main_handler.
(whoops, just managed to cut&paste the same stack twice)
(gdb) bt
#0 ironbee_plugin (contp=0x95bc0b0, event=TS_EVENT_HTTP_TXN_CLOSE,
edata=0xb28f5280) at ironbee.c:407
#1 0x0811e832 in INKContInternal::handle_event (this=0x95bc0b0, event=60012,
edata=0xb28f5280) at InkAPI.cc:978
#2 0x081154db in Continuation::handleEvent (this=0x95bc0b0, event=60012,
data=0xb28f5280) at ../iocore/eventsystem/I_Continuation.h:146
#3 0x0811f1f2 in APIHook::invoke (this=0x95bc960, event=60012,
edata=0xb28f5280) at InkAPI.cc:1197
#4 0x0819d8ec in HttpSM::state_api_callout (this=0xb28f5280, event=0,
data=0x0) at HttpSM.cc:1374
#5 0x081a71b6 in HttpSM::do_api_callout_internal (this=0xb28f5280)
at HttpSM.cc:4342
#6 0x081b19bc in HttpSM::do_api_callout (this=0xb28f5280) at HttpSM.cc:497
#7 0x081abbea in HttpSM::kill_this (this=0xb28f5280) at HttpSM.cc:5961
#8 0x081a0c90 in HttpSM::main_handler (this=0xb28f5280, event=2301,
data=0xb28f6a44) at HttpSM.cc:2452
#9 0x081154db in Continuation::handleEvent (this=0xb28f5280, event=2301,
data=0xb28f6a44) at ../iocore/eventsystem/I_Continuation.h:146
#10 0x081e032d in HttpTunnel::main_handler (this=0xb28f6a44, event=103,
data=0x9619d90) at HttpTunnel.cc:1468
#11 0x081154db in Continuation::handleEvent (this=0xb28f6a44, event=103,
data=0x9619d90) at ../iocore/eventsystem/I_Continuation.h:146
#12 0x082f5f20 in write_signal_and_update (event=103, vc=0x9619bd0)
at UnixNetVConnection.cc:153
#13 0x082f601a in write_signal_done (event=103, nh=0xb7497528, vc=0x9619bd0)
at UnixNetVConnection.cc:180
#14 0x082f70c8 in write_to_net_io (nh=0xb7497528, vc=0x9619bd0,
thread=0xb7496008) at UnixNetVConnection.cc:479
#15 0x082f69a8 in write_to_net (nh=0xb7497528, vc=0x9619bd0, pd=0xb6a4b008,
thread=0xb7496008) at UnixNetVConnection.cc:352
#16 0x082f2979 in NetHandler::mainNetEvent (this=0xb7497528, event=5,
e=0x8932790) at UnixNet.cc:405
#17 0x081154db in Continuation::handleEvent (this=0xb7497528, event=5,
data=0x8932790) at ../iocore/eventsystem/I_Continuation.h:146
#18 0x0831a906 in EThread::process_event (this=0xb7496008, e=0x8932790,
calling_code=5) at UnixEThread.cc:140
#19 0x0831aed5 in EThread::execute (this=0xb7496008) at UnixEThread.cc:262
#20 0x08318f22 in spawn_thread_internal (a=0x892ba28) at Thread.cc:88
#21 0x0016596e in start_thread (arg=0xb7394b70) at pthread_create.c:300
#22 0x00677a4e in clone () at ../sysdeps/unix/sysv/linux/i386/clone.S:130
was (Author: nick@webthing.com):
Having said Blocker, I meant *potential blocker*. I don't think it's actually causing a race condition in my plugin. Downgrading.
I've looked at the tracebacks for this. It's coming from HttpTunnel::main_handler at lines 1456 and 1468 respectively, and I've verified that it's the same call to Http::main_handler.
(gdb) bt
#0 ironbee_plugin (contp=0x95bc0f0, event=TS_EVENT_HTTP_SSN_CLOSE,
edata=0x9624030) at ironbee.c:407
#1 0x0811e832 in INKContInternal::handle_event (this=0x95bc0f0, event=60014,
edata=0x9624030) at InkAPI.cc:978
#2 0x081154db in Continuation::handleEvent (this=0x95bc0f0, event=60014,
data=0x9624030) at ../iocore/eventsystem/I_Continuation.h:146
#3 0x0811f1f2 in APIHook::invoke (this=0x95bc970, event=60014,
edata=0x9624030) at InkAPI.cc:1197
#4 0x0818b820 in HttpClientSession::state_api_callout (this=0x9624030,
event=0, data=0x0) at HttpClientSession.cc:473
#5 0x0818c31d in HttpClientSession::do_api_callout (this=0x9624030,
id=TS_HTTP_SSN_CLOSE_HOOK) at HttpClientSession.cc:172
#6 0x0818b028 in HttpClientSession::do_io_close (this=0x9624030, alerrno=-1)
at HttpClientSession.cc:316
#7 0x081a29d2 in HttpSM::tunnel_handler_ua (this=0xb28f5280, event=103,
c=0xb28f6aac) at HttpSM.cc:3027
#8 0x081dfbdc in HttpTunnel::consumer_handler (this=0xb28f6a44, event=103,
c=0xb28f6aac) at HttpTunnel.cc:1232
#9 0x081e02ce in HttpTunnel::main_handler (this=0xb28f6a44, event=103,
data=0x9619d90) at HttpTunnel.cc:1456
#10 0x081154db in Continuation::handleEvent (this=0xb28f6a44, event=103,
data=0x9619d90) at ../iocore/eventsystem/I_Continuation.h:146
#11 0x082f5f20 in write_signal_and_update (event=103, vc=0x9619bd0)
at UnixNetVConnection.cc:153
#12 0x082f601a in write_signal_done (event=103, nh=0xb7497528, vc=0x9619bd0)
at UnixNetVConnection.cc:180
#13 0x082f70c8 in write_to_net_io (nh=0xb7497528, vc=0x9619bd0,
thread=0xb7496008) at UnixNetVConnection.cc:479
#14 0x082f69a8 in write_to_net (nh=0xb7497528, vc=0x9619bd0, pd=0xb6a4b008,
thread=0xb7496008) at UnixNetVConnection.cc:352
#15 0x082f2979 in NetHandler::mainNetEvent (this=0xb7497528, event=5,
e=0x8932790) at UnixNet.cc:405
#16 0x081154db in Continuation::handleEvent (this=0xb7497528, event=5,
data=0x8932790) at ../iocore/eventsystem/I_Continuation.h:146
#17 0x0831a906 in EThread::process_event (this=0xb7496008, e=0x8932790,
calling_code=5) at UnixEThread.cc:140
#18 0x0831aed5 in EThread::execute (this=0xb7496008) at UnixEThread.cc:262
#19 0x08318f22 in spawn_thread_internal (a=0x892ba28) at Thread.cc:88
#20 0x0016596e in start_thread (arg=0xb7394b70) at pthread_create.c:300
#21 0x00677a4e in clone () at ../sysdeps/unix/sysv/linux/i386/clone.S:130
(gdb) bt
#0 ironbee_plugin (contp=0x95bc0f0, event=TS_EVENT_HTTP_SSN_CLOSE,
edata=0x9624030) at ironbee.c:407
#1 0x0811e832 in INKContInternal::handle_event (this=0x95bc0f0, event=60014,
edata=0x9624030) at InkAPI.cc:978
#2 0x081154db in Continuation::handleEvent (this=0x95bc0f0, event=60014,
data=0x9624030) at ../iocore/eventsystem/I_Continuation.h:146
#3 0x0811f1f2 in APIHook::invoke (this=0x95bc970, event=60014,
edata=0x9624030) at InkAPI.cc:1197
#4 0x0818b820 in HttpClientSession::state_api_callout (this=0x9624030,
event=0, data=0x0) at HttpClientSession.cc:473
#5 0x0818c31d in HttpClientSession::do_api_callout (this=0x9624030,
id=TS_HTTP_SSN_CLOSE_HOOK) at HttpClientSession.cc:172
#6 0x0818b028 in HttpClientSession::do_io_close (this=0x9624030, alerrno=-1)
at HttpClientSession.cc:316
#7 0x081a29d2 in HttpSM::tunnel_handler_ua (this=0xb28f5280, event=103,
c=0xb28f6aac) at HttpSM.cc:3027
#8 0x081dfbdc in HttpTunnel::consumer_handler (this=0xb28f6a44, event=103,
c=0xb28f6aac) at HttpTunnel.cc:1232
#9 0x081e02ce in HttpTunnel::main_handler (this=0xb28f6a44, event=103,
data=0x9619d90) at HttpTunnel.cc:1456
#10 0x081154db in Continuation::handleEvent (this=0xb28f6a44, event=103,
data=0x9619d90) at ../iocore/eventsystem/I_Continuation.h:146
#11 0x082f5f20 in write_signal_and_update (event=103, vc=0x9619bd0)
at UnixNetVConnection.cc:153
#12 0x082f601a in write_signal_done (event=103, nh=0xb7497528, vc=0x9619bd0)
at UnixNetVConnection.cc:180
#13 0x082f70c8 in write_to_net_io (nh=0xb7497528, vc=0x9619bd0,
thread=0xb7496008) at UnixNetVConnection.cc:479
#14 0x082f69a8 in write_to_net (nh=0xb7497528, vc=0x9619bd0, pd=0xb6a4b008,
thread=0xb7496008) at UnixNetVConnection.cc:352
#15 0x082f2979 in NetHandler::mainNetEvent (this=0xb7497528, event=5,
e=0x8932790) at UnixNet.cc:405
#16 0x081154db in Continuation::handleEvent (this=0xb7497528, event=5,
data=0x8932790) at ../iocore/eventsystem/I_Continuation.h:146
#17 0x0831a906 in EThread::process_event (this=0xb7496008, e=0x8932790,
calling_code=5) at UnixEThread.cc:140
#18 0x0831aed5 in EThread::execute (this=0xb7496008) at UnixEThread.cc:262
#19 0x08318f22 in spawn_thread_internal (a=0x892ba28) at Thread.cc:88
#20 0x0016596e in start_thread (arg=0xb7394b70) at pthread_create.c:300
#21 0x00677a4e in clone () at ../sysdeps/unix/sysv/linux/i386/clone.S:130
> SSN Close called before TXN Close
> ---------------------------------
>
> Key: TS-1007
> URL: https://issues.apache.org/jira/browse/TS-1007
> Project: Traffic Server
> Issue Type: Bug
> Components: TS API
> Affects Versions: 3.0.1
> Reporter: Nick Kew
> Priority: Critical
>
> Where a plugin implements both SSN_CLOSE_HOOK and TXN_CLOSE_HOOK, the SSN_CLOSE_HOOK is called first of the two. This messes up normal cleanups!
> Details:
> Register a SSN_START event globally
> In the SSN START, add a TXN_START and a SSN_CLOSE
> In the TXN START, add a TXN_CLOSE
> Stepping through, I see the order of events actually called, for the simple case of a one-off HTTP request with no keepalive:
> SSN_START
> TXN_START
> SSN_END
> TXN_END
> Whoops, SSN_END cleaned up the SSN context, leaving dangling pointers in the TXN!
--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators: https://issues.apache.org/jira/secure/ContactAdministrators!default.jspa
For more information on JIRA, see: http://www.atlassian.com/software/jira