Return-Path: Delivered-To: apmail-hbase-user-archive@www.apache.org Received: (qmail 55133 invoked from network); 12 Nov 2010 16:14:59 -0000 Received: from unknown (HELO mail.apache.org) (140.211.11.3) by 140.211.11.9 with SMTP; 12 Nov 2010 16:14:59 -0000 Received: (qmail 15146 invoked by uid 500); 12 Nov 2010 16:15:29 -0000 Delivered-To: apmail-hbase-user-archive@hbase.apache.org Received: (qmail 15025 invoked by uid 500); 12 Nov 2010 16:15:28 -0000 Mailing-List: contact user-help@hbase.apache.org; run by ezmlm Precedence: bulk List-Help: List-Unsubscribe: List-Post: List-Id: Reply-To: user@hbase.apache.org Delivered-To: mailing list user@hbase.apache.org Received: (qmail 15017 invoked by uid 99); 12 Nov 2010 16:15:28 -0000 Received: from nike.apache.org (HELO nike.apache.org) (192.87.106.230) by apache.org (qpsmtpd/0.29) with ESMTP; Fri, 12 Nov 2010 16:15:28 +0000 X-ASF-Spam-Status: No, hits=2.2 required=10.0 tests=HTML_MESSAGE,NORMAL_HTTP_TO_IP,RCVD_IN_DNSWL_NONE,SPF_PASS,WEIRD_PORT X-Spam-Check-By: apache.org Received-SPF: pass (nike.apache.org: domain of jeffw@qualtrics.com designates 209.85.213.41 as permitted sender) Received: from [209.85.213.41] (HELO mail-yw0-f41.google.com) (209.85.213.41) by apache.org (qpsmtpd/0.29) with ESMTP; Fri, 12 Nov 2010 16:15:19 +0000 Received: by ywi6 with SMTP id 6so67404ywi.14 for ; Fri, 12 Nov 2010 08:14:57 -0800 (PST) Received: by 10.100.106.7 with SMTP id e7mr1738497anc.59.1289578496910; Fri, 12 Nov 2010 08:14:56 -0800 (PST) Received: from [192.168.1.186] ([76.8.195.82]) by mx.google.com with ESMTPS id 6sm201854anx.32.2010.11.12.08.14.55 (version=TLSv1/SSLv3 cipher=RC4-MD5); Fri, 12 Nov 2010 08:14:56 -0800 (PST) Message-ID: <4CDD67F0.5040101@qualtrics.com> Date: Fri, 12 Nov 2010 09:14:40 -0700 From: Jeff Whiting User-Agent: Mozilla/5.0 (Windows; U; Windows NT 6.1; en-US; rv:1.9.2.12) Gecko/20101027 Thunderbird/3.1.6 MIME-Version: 1.0 To: user@hbase.apache.org Subject: Re: Unable to disable table, DroppedSnapshotException, .META. inconsistency References: In-Reply-To: Content-Type: multipart/alternative; boundary="------------020306090100000401040203" X-Virus-Checked: Checked by ClamAV on apache.org --------------020306090100000401040203 Content-Type: text/plain; charset=ISO-8859-1; format=flowed Content-Transfer-Encoding: 7bit Something else I'm seeing in the web interface: Master has: surveySession,,1289578320747.edb037e879e0df212556205751f60a39. ds4.internal:60030 But ds4 has: surveySession,,1289521116693.92f678a946ea7dfc999564c202132ecf. stores=2, storefiles=0, storefileSizeMB=0, memstoreSizeMB=0, storefileIndexSizeMB=0 Why would the region names be different between the master and the region server? ~Jeff On 11/12/2010 8:59 AM, Jeff Whiting wrote: > I'm unit testing some of our internal framework that interacts with hbase (version cdh3b3 => > 0.89.20100924+28). The unit test is small inserting and updating ~100 rows. My unit test expects > the hbase table to be empty when starting. So I go into hbase shell table disable the table, > drop it, and then recreate it. However hbase is having problems when I try to disable the table > "surveySession". In the region server holding the region I see the following in the log: > > 2010-11-11 16:44:39,387 INFO org.apache.hadoop.hbase. > regionserver.HRegionServer: MSG_REGION_CLOSE: > surveySession,,1289518197042.29b693fa3ef2edc940fd979ba9ce2c07. > 2010-11-11 16:44:39,387 INFO org.apache.hadoop.hbase.regionserver.HRegionServer: Worker: > MSG_REGION_CLOSE: surveySession,,1289518197042.29b693fa3ef2edc940fd979ba9ce2c07. > 2010-11-11 16:44:39,387 DEBUG org.apache.hadoop.hbase.regionserver.HRegion: Closing > surveySession,,1289518197042.29b693fa3ef2edc940fd979ba9ce2c07.: disabling compactions & flushes > 2010-11-11 16:44:39,387 DEBUG org.apache.hadoop.hbase.regionserver.HRegion: Updates disabled for > region surveySession,,1289518197042.29b693fa3ef2edc940fd979ba9ce2c07. > 2010-11-11 16:44:39,387 DEBUG org.apache.hadoop.hbase.regionserver.HRegion: Started memstore flush > for region surveySession,,1289518197042.29b693fa3ef2edc940fd979ba9ce2c07.. Current region memstore > size 242.7k > 2010-11-11 16:44:39,388 DEBUG org.apache.hadoop.hbase.regionserver.HRegion: Finished snapshotting, > commencing flushing stores > 2010-11-11 16:44:39,426 INFO com.hadoop.compression.lzo.GPLNativeCodeLoader: Loaded native gpl library > 2010-11-11 16:44:39,454 INFO com.hadoop.compression.lzo.LzoCodec: Successfully loaded & > initialized native-lzo library [hadoop-lzo rev 6a0ca93ae7b5070f61cca4be2d96a29d184a48ef] > 2010-11-11 16:44:39,456 INFO org.apache.hadoop.io.compress.CodecPool: Got brand-new compressor > 2010-11-11 16:44:39,478 WARN org.apache.hadoop.hbase.regionserver.HRegionServer: > org.apache.hadoop.hbase.DroppedSnapshotException: region: > surveySession,,1289518197042.29b693fa3ef2edc940fd979ba9ce2c07. > 2010-11-11 16:44:39,478 INFO org.apache.hadoop.hbase.regionserver.HRegionServer: Worker: > MSG_REGION_CLOSE: surveySession,,1289518197042.29b693fa3ef2edc940fd979ba9ce2c07. > 2010-11-11 16:44:40,391 INFO org.apache.hadoop.hbase.regionserver.HRegionServer: MSG_REGION_CLOSE: > surveySession,,1289518197042.29b693fa3ef2edc940fd979ba9ce2c07. > 2010-11-11 16:44:40,391 INFO org.apache.hadoop.hbase.regionserver.HRegionServer: Worker: > MSG_REGION_CLOSE: surveySession,,1289518197042.29b693fa3ef2edc940fd979ba9ce2c07. > 2010-11-11 16:44:41,395 INFO org.apache.hadoop.hbase.regionserver.HRegionServer: MSG_REGION_CLOSE: > surveySession,,1289518197042.29b693fa3ef2edc940fd979ba9ce2c07. > 2010-11-11 16:44:41,395 INFO org.apache.hadoop.hbase.regionserver.HRegionServer: Worker: > MSG_REGION_CLOSE: surveySession,,1289518197042.29b693fa3ef2edc940fd979ba9ce2c07. > 2010-11-11 16:44:42,399 INFO org.apache.hadoop.hbase.regionserver.HRegionServer: MSG_REGION_CLOSE: > surveySession,,1289518197042.29b693fa3ef2edc940fd979ba9ce2c07. > 2010-11-11 16:44:42,399 INFO org.apache.hadoop.hbase.regionserver.HRegionServer: Worker: > MSG_REGION_CLOSE: surveySession,,1289518197042.29b693fa3ef2edc940fd979ba9ce2c07. > 2010-11-11 16:44:44,408 INFO org.apache.hadoop.hbase.regionserver.HRegionServer: MSG_REGION_CLOSE: > surveySession,,1289518197042.29b693fa3ef2edc940fd979ba9ce2c07. > 2010-11-11 16:44:44,408 INFO org.apache.hadoop.hbase.regionserver.HRegionServer: Worker: > MSG_REGION_CLOSE: surveySession,,1289518197042.29b693fa3ef2edc940fd979ba9ce2c07. > 2010-11-11 16:44:46,416 INFO org.apache.hadoop.hbase.regionserver.HRegionServer: MSG_REGION_CLOSE: > surveySession,,1289518197042.29b693fa3ef2edc940fd979ba9ce2c07. > 2010-11-11 16:44:46,416 INFO org.apache.hadoop.hbase.regionserver.HRegionServer: Worker: > MSG_REGION_CLOSE: surveySession,,1289518197042.29b693fa3ef2edc940fd979ba9ce2c07. > 2010-11-11 16:44:50,436 INFO org.apache.hadoop.hbase.regionserver.HRegionServer: MSG_REGION_CLOSE: > surveySession,,1289518197042.29b693fa3ef2edc940fd979ba9ce2c07. > 2010-11-11 16:44:50,436 INFO org.apache.hadoop.hbase.regionserver.HRegionServer: Worker: > MSG_REGION_CLOSE: surveySession,,1289518197042.29b693fa3ef2edc940fd979ba9ce2c07. > 2010-11-11 16:44:54,454 INFO org.apache.hadoop.hbase.regionserver.HRegionServer: MSG_REGION_CLOSE: > surveySession,,1289518197042.29b693fa3ef2edc940fd979ba9ce2c07. > 2010-11-11 16:44:54,454 INFO org.apache.hadoop.hbase.regionserver.HRegionServer: Worker: > MSG_REGION_CLOSE: surveySession,,1289518197042.29b693fa3ef2edc940fd979ba9ce2c07. > 2010-11-11 16:45:02,487 INFO org.apache.hadoop.hbase.regionserver.HRegionServer: MSG_REGION_CLOSE: > surveySession,,1289518197042.29b693fa3ef2edc940fd979ba9ce2c07. > 2010-11-11 16:45:02,488 INFO org.apache.hadoop.hbase.regionserver.HRegionServer: Worker: > MSG_REGION_CLOSE: surveySession,,1289518197042.29b693fa3ef2edc940fd979ba9ce2c07. > 2010-11-11 16:45:18,557 INFO org.apache.hadoop.hbase.regionserver.HRegionServer: MSG_REGION_CLOSE: > surveySession,,1289518197042.29b693fa3ef2edc940fd979ba9ce2c07. > 2010-11-11 16:45:18,557 INFO org.apache.hadoop.hbase.regionserver.HRegionServer: Worker: > MSG_REGION_CLOSE: surveySession,,1289518197042.29b693fa3ef2edc940fd979ba9ce2c07. > > The only potential problem I'm seeing is the WARN: > 2010-11-11 16:44:39,478 WARN org.apache.hadoop.hbase.regionserver.HRegionServer: > org.apache.hadoop.hbase.DroppedSnapshotException: region: > surveySession,,1289518197042.29b693fa3ef2edc940fd979ba9ce2c07. > > Then if I run a hbase hbck I get: > ERROR: Region surveySession,,1289518197042.29b693fa3ef2edc940fd979ba9ce2c07. is not served by any > region server but is listed in META to be on server ds2.internal:60020 > > The region server on port 60020 says that it is not servering the region. > > At this point the table is "stuck." I can't disable it, I can't insert any records into it > (RegionNotServingException), nor do anything with it really. > > I can "fix" the problem by shutting down the region server forcing the master reassign all the > regions then disable it on the new region server. It does seem to be somewhat time dependent > because I have to try to disable the table after insert the records. Waiting a couple of hours > then doing it there seems to be no problem. > > Master Log entries at the time of disabling: > 2010-11-11 16:44:38,650 DEBUG org.apache.hadoop.hbase.master.ChangeTableState: Processing unserved > regions > 2010-11-11 16:44:38,650 DEBUG org.apache.hadoop.hbase.master.ChangeTableState: Processing regions > currently being served > 2010-11-11 16:44:38,651 DEBUG org.apache.hadoop.hbase.master.ChangeTableState: Adding region > surveySession,,1289518197042.29b693fa3ef2edc940fd979ba9ce2c07. to setClosing list > 2010-11-11 16:44:39,669 DEBUG org.apache.hadoop.hbase.master.ChangeTableState: Processing unserved > regions > 2010-11-11 16:44:39,669 DEBUG org.apache.hadoop.hbase.master.ChangeTableState: Processing regions > currently being served > 2010-11-11 16:44:39,670 DEBUG org.apache.hadoop.hbase.master.ChangeTableState: Adding region > surveySession,,1289518197042.29b693fa3ef2edc940fd979ba9ce2c07. to setClosing list > 2010-11-11 16:44:40,674 DEBUG org.apache.hadoop.hbase.master.ChangeTableState: Processing unserved > regions > 2010-11-11 16:44:40,675 DEBUG org.apache.hadoop.hbase.master.ChangeTableState: Processing regions > currently being served > 2010-11-11 16:44:40,675 DEBUG org.apache.hadoop.hbase.master.ChangeTableState: Adding region > surveySession,,1289518197042.29b693fa3ef2edc940fd979ba9ce2c07. to setClosing list > 2010-11-11 16:44:41,689 DEBUG org.apache.hadoop.hbase.master.ChangeTableState: Processing unserved > regions > 2010-11-11 16:44:41,689 DEBUG org.apache.hadoop.hbase.master.ChangeTableState: Processing regions > currently being served > 2010-11-11 16:44:41,689 DEBUG org.apache.hadoop.hbase.master.ChangeTableState: Adding region > surveySession,,1289518197042.29b693fa3ef2edc940fd979ba9ce2c07. to setClosing list > 2010-11-11 16:44:43,704 DEBUG org.apache.hadoop.hbase.master.ChangeTableState: Processing unserved > regions > 2010-11-11 16:44:43,704 DEBUG org.apache.hadoop.hbase.master.ChangeTableState: Processing regions > currently being served > 2010-11-11 16:44:43,704 DEBUG org.apache.hadoop.hbase.master.ChangeTableState: Adding region > surveySession,,1289518197042.29b693fa3ef2edc940fd979ba9ce2c07. to setClosing list > 2010-11-11 16:44:45,718 DEBUG org.apache.hadoop.hbase.master.ChangeTableState: Processing unserved > regions > 2010-11-11 16:44:45,718 DEBUG org.apache.hadoop.hbase.master.ChangeTableState: Processing regions > currently being served > 2010-11-11 16:44:45,719 DEBUG org.apache.hadoop.hbase.master.ChangeTableState: Adding region > surveySession,,1289518197042.29b693fa3ef2edc940fd979ba9ce2c07. to setClosing list > 2010-11-11 16:44:49,733 DEBUG org.apache.hadoop.hbase.master.ChangeTableState: Processing unserved > regions > 2010-11-11 16:44:49,733 DEBUG org.apache.hadoop.hbase.master.ChangeTableState: Processing regions > currently being served > 2010-11-11 16:44:49,733 DEBUG org.apache.hadoop.hbase.master.ChangeTableState: Adding region > surveySession,,1289518197042.29b693fa3ef2edc940fd979ba9ce2c07. to setClosing list > 2010-11-11 16:44:53,747 DEBUG org.apache.hadoop.hbase.master.ChangeTableState: Processing unserved > regions > 2010-11-11 16:44:53,747 DEBUG org.apache.hadoop.hbase.master.ChangeTableState: Processing regions > currently being served > 2010-11-11 16:44:53,747 DEBUG org.apache.hadoop.hbase.master.ChangeTableState: Adding region > surveySession,,1289518197042.29b693fa3ef2edc940fd979ba9ce2c07. to setClosing list > 2010-11-11 16:44:54,157 INFO org.apache.hadoop.hbase.master.BaseScanner: RegionManager.metaScanner > scanning meta region {server: 192.168.1.168:60020 , regionname: > .META.,,1.1028785192, startKey: <>} > 2010-11-11 16:44:54,167 INFO org.apache.hadoop.hbase.master.BaseScanner: RegionManager.metaScanner > scan of 21 row(s) of meta region {server: 192.168.1.168:60020 , > regionname: .META.,,1.1028785192, startKey: <>} complete > 2010-11-11 16:44:54,167 INFO org.apache.hadoop.hbase.master.BaseScanner: All 1 .META. region(s) > scanned > 2010-11-11 16:45:01,762 DEBUG org.apache.hadoop.hbase.master.ChangeTableState: Processing unserved > regions > 2010-11-11 16:45:01,762 DEBUG org.apache.hadoop.hbase.master.ChangeTableState: Processing regions > currently being served > 2010-11-11 16:45:01,762 DEBUG org.apache.hadoop.hbase.master.ChangeTableState: Adding region > surveySession,,1289518197042.29b693fa3ef2edc940fd979ba9ce2c07. to setClosing list > 2010-11-11 16:45:06,616 INFO org.apache.hadoop.hbase.master.ServerManager: 4 region servers, 0 > dead, average load 5.5 > 2010-11-11 16:45:13,556 DEBUG org.apache.hadoop.hbase.client.HConnectionManager$TableServers: > Cache hit for row <> in tableName surveySession: location server ds1.internal:60020, location > region name surveySession,,1289352541018.ecd63368b7933af078b9a714b715d6d4. > 2010-11-11 16:45:13,557 DEBUG org.apache.hadoop.hbase.client.HConnectionManager$TableServers: > Cache hit for row <> in tableName .META.: location server ds2.internal:60020, location region name > .META.,,1.1028785192 > 2010-11-11 16:45:13,564 DEBUG org.apache.hadoop.hbase.client.HConnectionManager$TableServers: > Rowscanned=1, rowsOffline=0 > 2010-11-11 16:45:16,110 DEBUG org.apache.hadoop.hbase.client.HConnectionManager$TableServers: > Cache hit for row <> in tableName surveySession: location server ds1.internal:60020, location > region name surveySession,,1289352541018.ecd63368b7933af078b9a714b715d6d4. > 2010-11-11 16:45:16,111 DEBUG org.apache.hadoop.hbase.client.HConnectionManager$TableServers: > Cache hit for row <> in tableName .META.: location server ds2.internal:60020, location region name > .META.,,1.1028785192 > 2010-11-11 16:45:16,117 DEBUG org.apache.hadoop.hbase.client.HConnectionManager$TableServers: > Rowscanned=1, rowsOffline=0 > 2010-11-11 16:45:17,780 DEBUG org.apache.hadoop.hbase.master.ChangeTableState: Processing unserved > regions > 2010-11-11 16:45:17,780 DEBUG org.apache.hadoop.hbase.master.ChangeTableState: Processing regions > currently being served > 2010-11-11 16:45:17,780 DEBUG org.apache.hadoop.hbase.master.ChangeTableState: Adding region > surveySession,,1289518197042.29b693fa3ef2edc940fd979ba9ce2c07. to setClosing list > 2010-11-11 16:45:30,993 INFO org.apache.hadoop.hbase.master.BaseScanner: RegionManager.rootScanner > scanning meta region {server: 192.168.1.169:60020 , regionname: > -ROOT-,,0.70236052, startKey: <>} > 2010-11-11 16:45:30,996 INFO org.apache.hadoop.hbase.master.BaseScanner: RegionManager.rootScanner > scan of 1 row(s) of meta region {server: 192.168.1.169:60020 , > regionname: -ROOT-,,0.70236052, startKey: <>} complete > 2010-11-11 16:45:54,160 INFO org.apache.hadoop.hbase.master.BaseScanner: RegionManager.metaScanner > scanning meta region {server: 192.168.1.168:60020 , regionname: > .META.,,1.1028785192, startKey: <>} > 2010-11-11 16:45:54,172 INFO org.apache.hadoop.hbase.master.BaseScanner: RegionManager.metaScanner > scan of 21 row(s) of meta region {server: 192.168.1.168:60020 , > regionname: .META.,,1.1028785192, startKey: <>} complete > 2010-11-11 16:45:54,172 INFO org.apache.hadoop.hbase.master.BaseScanner: All 1 .META. region(s) > scanned > 2010-11-11 16:46:06,623 INFO org.apache.hadoop.hbase.master.ServerManager: 4 region servers, 0 > dead, average load 5.5 > > ~Jeff > > > -- > Jeff Whiting > Qualtrics Senior Software Engineer > jeffw@qualtrics.com -- Jeff Whiting Qualtrics Senior Software Engineer jeffw@qualtrics.com --------------020306090100000401040203--