zookeeper-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Flavio Paiva Junqueira (JIRA)" <j...@apache.org>
Subject [jira] Commented: (ZOOKEEPER-597) ASyncHammerTest is failing intermittently on hudson trunk
Date Tue, 01 Dec 2009 12:34:20 GMT

    [ 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:CommitProcessor@167] - Adding
request to queue (CP): 1254a2022040016
2009-12-01 13:04:07,884 - INFO  [ProcessThread:-1:PrepRequestProcessor@353] - Processing create
session in PRP: 1254a2022040016
2009-12-01 13:04:07,884 - INFO  [ProcessThread:-1:CommitProcessor@167] - Adding request to
queue (CP): 1254a2022040016
2009-12-01 13:04:07,886 - INFO  [SyncThread:2:SendAckRequestProcessor@41] - Send ack is processing
create session (SARP): 1254a2022040016
2009-12-01 13:04:07,886 - INFO  [SyncThread:1:SendAckRequestProcessor@41] - Send ack is processing
create session (SARP): 1254a2022040016
2009-12-01 13:04:07,886 - WARN  [LeanerHandler-/127.0.0.1:57817:Leader@470] - Processing ack
(Leader): 1254a2022040016, 1
2009-12-01 13:04:07,886 - WARN  [SyncThread:0:Leader@470] - Processing ack (Leader): 1254a2022040016,
2
2009-12-01 13:04:07,887 - WARN  [SyncThread:0:Leader@481] - Going to apply (Leader): 1254a2022040016,
2
2009-12-01 13:04:07,887 - WARN  [CommitProcessor:0:Leader$ToBeAppliedRequestProcessor@542]
- Applying (TBARP): 1254a2022040016
2009-12-01 13:04:40,000 - INFO  [SessionTracker:ZooKeeperServer@327] - Expiring session 0x1254a2022040016,
timeout of 30000ms exceeded
2009-12-01 13:04:40,000 - INFO  [ProcessThread:-1:PrepRequestProcessor@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:CommitProcessor@167] - Adding
request to queue (CP): 2254a2022070017
2009-12-01 13:04:37,924 - INFO  [ProcessThread:-1:PrepRequestProcessor@353] - Processing create
session in PRP: 2254a2022070017
2009-12-01 13:04:37,925 - INFO  [ProcessThread:-1:CommitProcessor@167] - Adding request to
queue (CP): 2254a2022070017
2009-12-01 13:04:37,925 - WARN  [SyncThread:0:Leader@470] - Processing ack (Leader): 2254a2022070017,
1
2009-12-01 13:04:37,925 - INFO  [SyncThread:2:SendAckRequestProcessor@41] - Send ack is processing
create session (SARP): 2254a2022070017
2009-12-01 13:04:37,925 - WARN  [LeanerHandler-/127.0.0.1:57817:Leader@470] - Processing ack
(Leader): 2254a2022070017, 2
2009-12-01 13:04:37,926 - WARN  [LeanerHandler-/127.0.0.1:57817:Leader@481] - Going to apply
(Leader): 2254a2022070017, 2
2009-12-01 13:04:37,926 - WARN  [CommitProcessor:0:Leader$ToBeAppliedRequestProcessor@542]
- Applying (TBARP): 2254a2022070017
2009-12-01 13:04:37,926 - INFO  [SyncThread:1:SendAckRequestProcessor@41] - Send ack is processing
create session (SARP): 2254a2022070017
2009-12-01 13:04:37,926 - INFO  [CommitProcessor:2:FinalRequestProcessor@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.


Mime
View raw message