Hi Brian,
This seems to be a different problem than the original one.
Previously, it was the FileStateHandler object that got deleted twice:
-
There was a read timeout for a request that was in the inQueue
(waiting for a response), this triggered the CloseHandler callback,
which in turn triggered your routine DelayedClose, which deletes the
FileStateHandler.
-
There was a second read timeout for the same request that was handled in 1).
So the same things happend and we got a double delete. The bottom line is
the request must have been reinserted into the inQueue.
Since we have seen something similar I pointed you to #483
Now, in this case, we see a double delete of the incoming response:
- A new response comes in and a new Message object gets allocated:
https://github.com/xrootd/xrootd/blob/master/src/XrdCl/XrdClAsyncSocketHandler.cc#L585
The AsyncSocketHandler holds a pointer to this message: pIncoming.
Then the Message is being passed to the Stream::OnIncoming(), and in here
it is being passed further to the XRootDTransport::MessageReceived().
In the MessageReceived we check if the SID of the message is in the Timed-Out SIDs set,
and if yes we remove it from the set and delete the message:
https://github.com/xrootd/xrootd/blob/master/src/XrdCl/XrdClXRootDTransport.cc#L1128
According to the memcheck output that's what happend.
The MessageReceived routine returns DigestMsg, so the Stream::OnIncoming knows that the
message was deleted and it returns:
https://github.com/xrootd/xrootd/blob/master/src/XrdCl/XrdClStream.cc#L465
-
Then from the memcheck output we now that the same message object has been deleted for
a second time in XRootDMsgHandler::Process method, the callstack looks like that:
JobManager::RunJobs() -> HandleIncMsgJob::Run() -> XRootDMsgHandler::Process
Now the really peculiar thing is that we are creating the HandleIncMsgJob only in one place:
https://github.com/xrootd/xrootd/blob/master/src/XrdCl/XrdClStream.cc#L509
The HandleIncMsgJob is being created (it holds pointer to the message) and submitted
to the thread-pool.
Note that this happens also in the Stream::OnIncoming, and it happens after the return
statement we reached in 1), so this means the message was not submitted to the
thread-pool in 1). It seems that the Stream::OnIncoming has been invoked for a second
time with the same message. But the Stream::OnIncoming is only being called from the
AsyncSocketHandler, and the AsyncSocketHandler resets the pointer to pIncoming after
calling Stream::OnIncoming:
https://github.com/xrootd/xrootd/blob/master/src/XrdCl/XrdClAsyncSocketHandler.cc#L665
So right now I cannot see why this happened and I'm really puzzled,
I need more time to investigate.
Cheers,
Mcihal
—
You are receiving this because you are subscribed to this thread.
Reply to this email directly, view it on GitHub, or mute the thread.
{"api_version":"1.0","publisher":{"api_key":"05dde50f1d1a384dd78767c55493e4bb","name":"GitHub"},"entity":{"external_key":"github/xrootd/xrootd","title":"xrootd/xrootd","subtitle":"GitHub repository","main_image_url":"https://cloud.githubusercontent.com/assets/143418/17495839/a5054eac-5d88-11e6-95fc-7290892c7bb5.png","avatar_image_url":"https://cloud.githubusercontent.com/assets/143418/15842166/7c72db34-2c0b-11e6-9aed-b52498112777.png","action":{"name":"Open in GitHub","url":"https://github.com/xrootd/xrootd"}},"updates":{"snippets":[{"icon":"PERSON","message":"@simonmichal in #488: Hi Brian,\r\n\r\nThis seems to be a different problem than the original one.\r\n\r\nPreviously, it was the FileStateHandler object that got deleted twice:\r\n\r\n1) There was a read timeout for a request that was in the inQueue \r\n (waiting for a response), this triggered the CloseHandler callback,\r\n which in turn triggered your routine DelayedClose, which deletes the\r\n FileStateHandler.\r\n\r\n2) There was a second read timeout for the same request that was handled in 1).\r\n So the same things happend and we got a double delete. The bottom line is\r\n the request must have been reinserted into the inQueue.\r\n\r\nSince we have seen something similar I pointed you to #483\r\n\r\n\r\nNow, in this case, we see a double delete of the incoming response:\r\n\r\n1) A new response comes in and a new Message object gets allocated:\r\n\r\nhttps://github.com/xrootd/xrootd/blob/master/src/XrdCl/XrdClAsyncSocketHandler.cc#L585\r\n\r\n The AsyncSocketHandler holds a pointer to this message: pIncoming.\r\n Then the Message is being passed to the Stream::OnIncoming(), and in here \r\n it is being passed further to the XRootDTransport::MessageReceived().\r\n\r\n In the MessageReceived we check if the SID of the message is in the Timed-Out SIDs set,\r\n and if yes we remove it from the set and delete the message:\r\n\r\nhttps://github.com/xrootd/xrootd/blob/master/src/XrdCl/XrdClXRootDTransport.cc#L1128\r\n\r\n According to the memcheck output that's what happend.\r\n\r\n The MessageReceived routine returns DigestMsg, so the Stream::OnIncoming knows that the\r\n message was deleted and it returns:\r\n\r\nhttps://github.com/xrootd/xrootd/blob/master/src/XrdCl/XrdClStream.cc#L465\r\n\r\n\r\n2) Then from the memcheck output we now that the same message object has been deleted for \r\n a second time in XRootDMsgHandler::Process method, the callstack looks like that:\r\n\r\n JobManager::RunJobs() -\u003e HandleIncMsgJob::Run() -\u003e XRootDMsgHandler::Process\r\n\r\n Now the really peculiar thing is that we are creating the HandleIncMsgJob only in one place:\r\n\r\nhttps://github.com/xrootd/xrootd/blob/master/src/XrdCl/XrdClStream.cc#L509\r\n\r\n The HandleIncMsgJob is being created (it holds pointer to the message) and submitted \r\n to the thread-pool.\r\n\r\n Note that this happens also in the Stream::OnIncoming, and it happens after the return \r\n statement we reached in 1), so this means the message was not submitted to the \r\n thread-pool in 1). It seems that the Stream::OnIncoming has been invoked for a second\r\n time with the same message. But the Stream::OnIncoming is only being called from the\r\n AsyncSocketHandler, and the AsyncSocketHandler resets the pointer to pIncoming after\r\n calling Stream::OnIncoming:\r\n\r\nhttps://github.com/xrootd/xrootd/blob/master/src/XrdCl/XrdClAsyncSocketHandler.cc#L665\r\n\r\n So right now I cannot see why this happened and I'm really puzzled, \r\n I need more time to investigate. \r\n\r\nCheers,\r\nMcihal\r\n\r\n\r\n"}],"action":{"name":"View Issue","url":"https://github.com/xrootd/xrootd/issues/488#issuecomment-292227790"}}}
Use REPLY-ALL to reply to list
To unsubscribe from the XROOTD-DEV list, click the following link:
https://listserv.slac.stanford.edu/cgi-bin/wa?SUBED1=XROOTD-DEV&A=1