[ 
https://issues.apache.org/jira/browse/ZOOKEEPER-597?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12784202#action_12784202
 ] 

Flavio Paiva Junqueira commented on ZOOKEEPER-597:
--------------------------------------------------

I have added some more log messages on my own to track the session that causes 
a run of the test to fail, and here is what I got for the culprit:

{noformat}
2009-12-01 13:04:07,883 - INFO  
[FollowerRequestProcessor:1:commitproces...@167] - Adding request to queue 
(CP): 1254a2022040016
2009-12-01 13:04:07,884 - INFO  [ProcessThread:-1:preprequestproces...@353] - 
Processing create session in PRP: 1254a2022040016
2009-12-01 13:04:07,884 - INFO  [ProcessThread:-1:commitproces...@167] - Adding 
request to queue (CP): 1254a2022040016
2009-12-01 13:04:07,886 - INFO  [SyncThread:2:sendackrequestproces...@41] - 
Send ack is processing create session (SARP): 1254a2022040016
2009-12-01 13:04:07,886 - INFO  [SyncThread:1:sendackrequestproces...@41] - 
Send ack is processing create session (SARP): 1254a2022040016
2009-12-01 13:04:07,886 - WARN  [LeanerHandler-/127.0.0.1:57817:lea...@470] - 
Processing ack (Leader): 1254a2022040016, 1
2009-12-01 13:04:07,886 - WARN  [SyncThread:0:lea...@470] - Processing ack 
(Leader): 1254a2022040016, 2
2009-12-01 13:04:07,887 - WARN  [SyncThread:0:lea...@481] - Going to apply 
(Leader): 1254a2022040016, 2
2009-12-01 13:04:07,887 - WARN  
[CommitProcessor:0:leader$tobeappliedrequestproces...@542] - Applying (TBARP): 
1254a2022040016
2009-12-01 13:04:40,000 - INFO  [SessionTracker:zookeeperser...@327] - Expiring 
session 0x1254a2022040016, timeout of 30000ms exceeded
2009-12-01 13:04:40,000 - INFO  [ProcessThread:-1:preprequestproces...@386] - 
Processed session termination for sessionid: 0x1254a2022040016
{noformat}

For a session that has been correctly established, we can see that there is an 
extra message for FinalRequestProcessor:

{noformat}
2009-12-01 13:04:37,924 - INFO  
[FollowerRequestProcessor:2:commitproces...@167] - Adding request to queue 
(CP): 2254a2022070017
2009-12-01 13:04:37,924 - INFO  [ProcessThread:-1:preprequestproces...@353] - 
Processing create session in PRP: 2254a2022070017
2009-12-01 13:04:37,925 - INFO  [ProcessThread:-1:commitproces...@167] - Adding 
request to queue (CP): 2254a2022070017
2009-12-01 13:04:37,925 - WARN  [SyncThread:0:lea...@470] - Processing ack 
(Leader): 2254a2022070017, 1
2009-12-01 13:04:37,925 - INFO  [SyncThread:2:sendackrequestproces...@41] - 
Send ack is processing create session (SARP): 2254a2022070017
2009-12-01 13:04:37,925 - WARN  [LeanerHandler-/127.0.0.1:57817:lea...@470] - 
Processing ack (Leader): 2254a2022070017, 2
2009-12-01 13:04:37,926 - WARN  [LeanerHandler-/127.0.0.1:57817:lea...@481] - 
Going to apply (Leader): 2254a2022070017, 2
2009-12-01 13:04:37,926 - WARN  
[CommitProcessor:0:leader$tobeappliedrequestproces...@542] - Applying (TBARP): 
2254a2022070017
2009-12-01 13:04:37,926 - INFO  [SyncThread:1:sendackrequestproces...@41] - 
Send ack is processing create session (SARP): 2254a2022070017
2009-12-01 13:04:37,926 - INFO  [CommitProcessor:2:finalrequestproces...@175] - 
Processing create session in FRP: 2254a2022070017
{noformat}

It sounds like the createSession request goes as far as ToBeAppliedProcessor, 
but it doesn't make it to FinalRequestProcessor. If my observation is correct, 
I think it is getting lost between the two. Is that possible?



> ASyncHammerTest is failing intermittently on hudson trunk
> ---------------------------------------------------------
>
>                 Key: ZOOKEEPER-597
>                 URL: https://issues.apache.org/jira/browse/ZOOKEEPER-597
>             Project: Zookeeper
>          Issue Type: Bug
>          Components: tests
>            Reporter: Patrick Hunt
>            Assignee: Patrick Hunt
>            Priority: Critical
>             Fix For: 3.3.0
>
>         Attachments: ZOOKEEPER-597.patch
>
>
> ASyncHammerTest is failing intermittently on hudson trunk. There is no clear 
> reason why this is happening, but
> it seems from the logs that a session connection to a follower is failing 
> during session establishment - the
> failure seems to be a problem either on the follower or leader. The server 
> gets the session create request, but
> it stalls in the request processor pipeline. (we see it go in, but we do not 
> see it com eout)
> unfortunately all efforts to reproduce this on non-hudson trunk have failed. 
> Even trying to reproduce by
> running on hudson host itself (manually) has failed.
> We need to instrument the client session creation code in the test to dump 
> the thread stack if the
> session creation fails.

-- 
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.

Reply via email to