Return-Path: X-Original-To: apmail-hbase-issues-archive@www.apache.org Delivered-To: apmail-hbase-issues-archive@www.apache.org Received: from mail.apache.org (hermes.apache.org [140.211.11.3]) by minotaur.apache.org (Postfix) with SMTP id C6294ED68 for ; Tue, 12 Mar 2013 04:45:13 +0000 (UTC) Received: (qmail 2693 invoked by uid 500); 12 Mar 2013 04:45:13 -0000 Delivered-To: apmail-hbase-issues-archive@hbase.apache.org Received: (qmail 2412 invoked by uid 500); 12 Mar 2013 04:45:13 -0000 Mailing-List: contact issues-help@hbase.apache.org; run by ezmlm Precedence: bulk List-Help: List-Unsubscribe: List-Post: List-Id: Delivered-To: mailing list issues@hbase.apache.org Received: (qmail 2361 invoked by uid 99); 12 Mar 2013 04:45:12 -0000 Received: from arcas.apache.org (HELO arcas.apache.org) (140.211.11.28) by apache.org (qpsmtpd/0.29) with ESMTP; Tue, 12 Mar 2013 04:45:12 +0000 Date: Tue, 12 Mar 2013 04:45:12 +0000 (UTC) From: "Hudson (JIRA)" To: issues@hbase.apache.org Message-ID: In-Reply-To: References: Subject: [jira] [Commented] (HBASE-8071) TestRestoreFlushSnapshotFromClient fails intermittently in trunk builds MIME-Version: 1.0 Content-Type: text/plain; charset=utf-8 Content-Transfer-Encoding: 7bit X-JIRA-FingerPrint: 30527f35849b9dde25b450d4833f0394 [ https://issues.apache.org/jira/browse/HBASE-8071?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13599700#comment-13599700 ] Hudson commented on HBASE-8071: ------------------------------- Integrated in hbase-0.95 #63 (See [https://builds.apache.org/job/hbase-0.95/63/]) HBASE-8071 TestRestoreFlushSnapshotFromClient fails intermittently in trunk builds (Ted Yu) (Revision 1455367) Result = FAILURE tedyu : Files : * /hbase/branches/0.95/hbase-server/src/test/java/org/apache/hadoop/hbase/snapshot/TestRestoreFlushSnapshotFromClient.java > TestRestoreFlushSnapshotFromClient fails intermittently in trunk builds > ----------------------------------------------------------------------- > > Key: HBASE-8071 > URL: https://issues.apache.org/jira/browse/HBASE-8071 > Project: HBase > Issue Type: Test > Reporter: Ted Yu > Assignee: Ted Yu > Fix For: 0.95.0, 0.98.0 > > Attachments: 8071.txt > > > From https://builds.apache.org/job/HBase-TRUNK/3945/testReport/org.apache.hadoop.hbase.snapshot/TestRestoreFlushSnapshotFromClient/testRestoreSnapshot/: > {code} > 2013-03-11 19:35:54,162 DEBUG [IPC Server handler 1 on 51923] master.HMaster(2410): Submitting snapshot request for:{ ss=snaptb1-1363030509407 table=testtb-1363030509407 type=FLUSH } > 2013-03-11 19:35:54,162 DEBUG [IPC Server handler 1 on 51923] snapshot.SnapshotDescriptionUtils(235): Creation time not specified, setting to:1363030554162 (current time:1363030554162). > 2013-03-11 19:35:54,163 DEBUG [IPC Server handler 1 on 51923] snapshot.SnapshotManager(465): No existing snapshot, attempting snapshot... > ... > 2013-03-11 19:36:52,139 DEBUG [pool-1-thread-1] client.HBaseAdmin(2234): Getting current status of snapshot from master... > 2013-03-11 19:36:52,140 DEBUG [IPC Server handler 1 on 51923] master.HMaster(2481): Checking to see if snapshot from request:{ ss=snaptb1-1363030509407 table=testtb-1363030509407 type=FLUSH } is done > 2013-03-11 19:36:52,140 DEBUG [IPC Server handler 1 on 51923] snapshot.SnapshotManager(344): Snapshoting '{ ss=snaptb1-1363030509407 table=testtb-1363030509407 type=FLUSH }' is still in progress! > 2013-03-11 19:36:52,140 DEBUG [pool-1-thread-1] client.HBaseAdmin(2226): (#16) Sleeping: 8000ms while waiting for snapshot completion. > 2013-03-11 19:36:55,740 DEBUG [Timer-28] errorhandling.ForeignExceptionDispatcher(68): accepting received exception > org.apache.hadoop.hbase.errorhandling.TimeoutException via timer-java.util.Timer@1ed8384b:org.apache.hadoop.hbase.errorhandling.TimeoutException: Timeout elapsed! Source:Timeout caused Foreign Exception Start:1363030555739, End:1363030615740, diff:60001, max:60000 ms > at org.apache.hadoop.hbase.errorhandling.TimeoutExceptionInjector$1.run(TimeoutExceptionInjector.java:71) > at java.util.TimerThread.mainLoop(Timer.java:555) > at java.util.TimerThread.run(Timer.java:505) > Caused by: org.apache.hadoop.hbase.errorhandling.TimeoutException: Timeout elapsed! Source:Timeout caused Foreign Exception Start:1363030555739, End:1363030615740, diff:60001, max:60000 ms > at org.apache.hadoop.hbase.errorhandling.TimeoutExceptionInjector$1.run(TimeoutExceptionInjector.java:68) > ... 2 more > 2013-03-11 19:36:55,759 DEBUG [MASTER_TABLE_OPERATIONS-janus.apache.org,51923,1363030251194-0] client.HConnectionManager$HConnectionImplementation(944): Looking up meta region location in ZK, connection=hconnection 0x25c6f10 > 2013-03-11 19:36:55,760 DEBUG [MASTER_TABLE_OPERATIONS-janus.apache.org,51923,1363030251194-0] zookeeper.ZKUtil(1682): hconnection 0x25c6f10-0x13d5aef12b70004 Retrieved 35 byte(s) of data from znode /hbase/meta-region-server; data=janus.apache.org,42570,1363030252791 > 2013-03-11 19:36:55,760 DEBUG [MASTER_TABLE_OPERATIONS-janus.apache.org,51923,1363030251194-0] client.HConnectionManager$HConnectionImplementation(949): Looked up meta region location, connection=hconnection 0x25c6f10; serverName=janus.apache.org,42570,1363030252791 > 2013-03-11 19:36:55,760 DEBUG [MASTER_TABLE_OPERATIONS-janus.apache.org,51923,1363030251194-0] client.ClientScanner(96): Creating scanner over .META. starting at key 'testtb-1363030509407,,' > 2013-03-11 19:36:55,760 DEBUG [MASTER_TABLE_OPERATIONS-janus.apache.org,51923,1363030251194-0] client.ClientScanner(209): Advancing internal scanner to startKey at 'testtb-1363030509407,,' > 2013-03-11 19:36:55,760 DEBUG [MASTER_TABLE_OPERATIONS-janus.apache.org,51923,1363030251194-0] client.HConnectionManager$HConnectionImplementation(944): Looking up meta region location in ZK, connection=hconnection 0x25c6f10 > 2013-03-11 19:36:55,761 DEBUG [MASTER_TABLE_OPERATIONS-janus.apache.org,51923,1363030251194-0] zookeeper.ZKUtil(1682): hconnection 0x25c6f10-0x13d5aef12b70004 Retrieved 35 byte(s) of data from znode /hbase/meta-region-server; data=janus.apache.org,42570,1363030252791 > 2013-03-11 19:36:55,761 DEBUG [MASTER_TABLE_OPERATIONS-janus.apache.org,51923,1363030251194-0] client.HConnectionManager$HConnectionImplementation(949): Looked up meta region location, connection=hconnection 0x25c6f10; serverName=janus.apache.org,42570,1363030252791 > 2013-03-11 19:36:55,764 DEBUG [MASTER_TABLE_OPERATIONS-janus.apache.org,51923,1363030251194-0] client.ClientScanner(196): Finished with scanning at {NAME => '.META.,,1', STARTKEY => '', ENDKEY => '', ENCODED => 1028785192,} > 2013-03-11 19:36:55,790 ERROR [MASTER_TABLE_OPERATIONS-janus.apache.org,51923,1363030251194-0] snapshot.TakeSnapshotHandler(152): Failed taking snapshot { ss=snaptb1-1363030509407 table=testtb-1363030509407 type=FLUSH } due to exception:No region directory found for region:{NAME => 'testtb-1363030509407,4,1363030509409.8a41cf1a6517ac9f9d4e6aaf2c906588.', STARTKEY => '4', ENDKEY => '5', ENCODED => 8a41cf1a6517ac9f9d4e6aaf2c906588,} > org.apache.hadoop.hbase.exceptions.CorruptedSnapshotException: No region directory found for region:{NAME => 'testtb-1363030509407,4,1363030509409.8a41cf1a6517ac9f9d4e6aaf2c906588.', STARTKEY => '4', ENDKEY => '5', ENCODED => 8a41cf1a6517ac9f9d4e6aaf2c906588,} > at org.apache.hadoop.hbase.master.snapshot.MasterSnapshotVerifier.verifyRegion(MasterSnapshotVerifier.java:166) > at org.apache.hadoop.hbase.master.snapshot.MasterSnapshotVerifier.verifyRegions(MasterSnapshotVerifier.java:151) > at org.apache.hadoop.hbase.master.snapshot.MasterSnapshotVerifier.verifySnapshot(MasterSnapshotVerifier.java:114) > at org.apache.hadoop.hbase.master.snapshot.TakeSnapshotHandler.process(TakeSnapshotHandler.java:145) > at org.apache.hadoop.hbase.executor.EventHandler.run(EventHandler.java:130) > at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110) > at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603) > at java.lang.Thread.run(Thread.java:722) > 2013-03-11 19:36:55,791 INFO [MASTER_TABLE_OPERATIONS-janus.apache.org,51923,1363030251194-0] snapshot.TakeSnapshotHandler(203): Stop taking snapshot={ ss=snaptb1-1363030509407 table=testtb-1363030509407 type=FLUSH } because: Failed to take snapshot '{ ss=snaptb1-1363030509407 table=testtb-1363030509407 type=FLUSH }' due to exception > 2013-03-11 19:36:55,791 DEBUG [MASTER_TABLE_OPERATIONS-janus.apache.org,51923,1363030251194-0] snapshot.TakeSnapshotHandler(159): Launching cleanup of working dir:hdfs://localhost:50807/user/jenkins/hbase/.snapshot/.tmp/snaptb1-1363030509407 > 2013-03-11 19:36:55,838 DEBUG [Timer-31] errorhandling.ForeignExceptionDispatcher(68): accepting received exception > org.apache.hadoop.hbase.errorhandling.TimeoutException via timer-java.util.Timer@4baf3db1:org.apache.hadoop.hbase.errorhandling.TimeoutException: Timeout elapsed! Source:Timeout caused Foreign Exception Start:1363030555838, End:1363030615838, diff:60000, max:60000 ms > at org.apache.hadoop.hbase.errorhandling.TimeoutExceptionInjector$1.run(TimeoutExceptionInjector.java:71) > at java.util.TimerThread.mainLoop(Timer.java:555) > at java.util.TimerThread.run(Timer.java:505) > Caused by: org.apache.hadoop.hbase.errorhandling.TimeoutException: Timeout elapsed! Source:Timeout caused Foreign Exception Start:1363030555838, End:1363030615838, diff:60000, max:60000 ms > at org.apache.hadoop.hbase.errorhandling.TimeoutExceptionInjector$1.run(TimeoutExceptionInjector.java:68) > ... 2 more > 2013-03-11 19:36:55,839 DEBUG [Timer-31] procedure.ZKProcedureMemberRpcs(285): Aborting procedure (snaptb1-1363030509407) in zk > 2013-03-11 19:36:56,061 ERROR [(janus.apache.org,51923,1363030251194)-proc-coordinator-pool1-thread-1] procedure.Procedure(225): Procedure 'snaptb1-1363030509407' execution failed! > org.apache.hadoop.hbase.errorhandling.TimeoutException via timer-java.util.Timer@1ed8384b:org.apache.hadoop.hbase.errorhandling.TimeoutException: Timeout elapsed! Source:Timeout caused Foreign Exception Start:1363030555739, End:1363030615740, diff:60001, max:60000 ms > at org.apache.hadoop.hbase.errorhandling.ForeignExceptionDispatcher.rethrowException(ForeignExceptionDispatcher.java:85) > at org.apache.hadoop.hbase.procedure.Procedure.waitForLatch(Procedure.java:371) > at org.apache.hadoop.hbase.procedure.Procedure.call(Procedure.java:215) > at org.apache.hadoop.hbase.procedure.Procedure.call(Procedure.java:68) > at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334) > at java.util.concurrent.FutureTask.run(FutureTask.java:166) > at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110) > at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603) > at java.lang.Thread.run(Thread.java:722) > Caused by: org.apache.hadoop.hbase.errorhandling.TimeoutException: Timeout elapsed! Source:Timeout caused Foreign Exception Start:1363030555739, End:1363030615740, diff:60001, max:60000 ms > at org.apache.hadoop.hbase.errorhandling.TimeoutExceptionInjector$1.run(TimeoutExceptionInjector.java:68) > at java.util.TimerThread.mainLoop(Timer.java:555) > at java.util.TimerThread.run(Timer.java:505) > 2013-03-11 19:36:56,061 DEBUG [(janus.apache.org,51923,1363030251194)-proc-coordinator-pool1-thread-1] procedure.Procedure(228): Running finish phase. > 2013-03-11 19:36:56,061 DEBUG [(janus.apache.org,51923,1363030251194)-proc-coordinator-pool1-thread-1] procedure.Procedure(279): Finished coordinator procedure - removing self from list of running procedures > 2013-03-11 19:36:56,061 DEBUG [(janus.apache.org,51923,1363030251194)-proc-coordinator-pool1-thread-1] procedure.ZKProcedureCoordinatorRpcs(142): Attempting to clean out zk node for op:snaptb1-1363030509407 > 2013-03-11 19:36:56,061 INFO [(janus.apache.org,51923,1363030251194)-proc-coordinator-pool1-thread-1] procedure.ZKProcedureUtil(279): Clearing all znodes for procedure snaptb1-1363030509407including nodes /hbase/online-snapshot/acquired /hbase/online-snapshot/reached /hbase/online-snapshot/abort > 2013-03-11 19:36:56,080 DEBUG [RegionServer:1;janus.apache.org,59357,1363030252847-EventThread] zookeeper.ZooKeeperWatcher(274): regionserver:59357-0x13d5aef12b70002 Received ZooKeeper Event, type=NodeCreated, state=SyncConnected, path=/hbase/online-snapshot/abort/snaptb1-1363030509407 > 2013-03-11 19:36:56,080 DEBUG [RegionServer:2;janus.apache.org,37320,1363030252872-EventThread] zookeeper.ZooKeeperWatcher(274): regionserver:37320-0x13d5aef12b70003 Received ZooKeeper Event, type=NodeCreated, state=SyncConnected, path=/hbase/online-snapshot/abort/snaptb1-1363030509407 > {code} -- This message is automatically generated by JIRA. If you think it was sent incorrectly, please contact your JIRA administrators For more information on JIRA, see: http://www.atlassian.com/software/jira