Hi Brian,

This seems to be a different problem than the original one.

Previously, it was the FileStateHandler object that got deleted twice:

  1. 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.

  2. 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:

  1. 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

  1. 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