You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@hbase.apache.org by "Prakash Khemani (JIRA)" <ji...@apache.org> on 2011/04/26 23:55:03 UTC
[jira] [Created] (HBASE-3824) region server timed out during open
region
region server timed out during open region
------------------------------------------
Key: HBASE-3824
URL: https://issues.apache.org/jira/browse/HBASE-3824
Project: HBase
Issue Type: Bug
Reporter: Prakash Khemani
When replaying a large log file, mestore flushes can happen. But there is no Progressible report being sent during memstore flushes. That can lead to master timing out the region server during region open.
===
Another related issue and Jonathan's response
> So if a region server that is handed a region for opening and has done part of
> the work ... it has created some HFiles (because the logs were so huge that
> the mestore got flushed while the logs were being replayed) ... and then it is
> asked to give up because the master thought the region server was taking
> too long to open the region.
>
> When the region server gives up on the region then will it make sure that it
> removes all the HFiles it had created for that region?
Will need to check the code, but would it matter? One issue is whether it cleans up after itself (I'm guessing not). Another issue is whether the replay is idempotent (duplicate KVs across files shouldn't matter in most cases).
===
2011-04-25 09:11:36,844 ERROR org.apache.hadoop.hbase.executor.EventHandler: Caught throwable while processing event M_RS_OPEN_REGION
java.lang.NullPointerException
at org.apache.hadoop.hbase.util.Writables.getWritable(Writables.java:75)
at org.apache.hadoop.hbase.executor.RegionTransitionData.fromBytes(RegionTransitionData.java:198)
at org.apache.hadoop.hbase.zookeeper.ZKAssign.transitionNode(ZKAssign.java:672)
at org.apache.hadoop.hbase.zookeeper.ZKAssign.transitionNodeOpened(ZKAssign.java:621)
at org.apache.hadoop.hbase.regionserver.handler.OpenRegionHandler.process(OpenRegionHandler.java:168)
at org.apache.hadoop.hbase.executor.EventHandler.run(EventHandler.java:151)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
at java.lang.Thread.run(Thread.java:619)
byte [] existingBytes =
ZKUtil.getDataNoWatch(zkw, node, stat);
RegionTransitionData existingData =
RegionTransitionData.fromBytes(existingBytes);
existingBytes can be null. have to return -1 if null.
===
master logs
2011-04-25 05:24:03,250 DEBUG org.apache.hadoop.hbase.regionserver.wal.HLogSplitter: Creating writer path=hdfs://pumahbase002-snc5-dfs.data.facebook.com:9000/PUMAHBASE002-SNC5-HBASE/realtime_domain_imps_urls/e7a478b4bd164525052f1dedb832de0a/recovered.edits/0000000057528037047 region=e7a478b4bd164525052f1dedb832de0a
2011-04-25 09:09:19,246 INFO org.apache.hadoop.hbase.regionserver.wal.HLogSplitter: Closed path hdfs://pumahbase002-snc5-dfs.data.facebook.com:9000/PUMAHBASE002-SNC5-HBASE/realtime_domain_imps_urls/e7a478b4bd164525052f1dedb832de0a/recovered.edits/0000000057528037047 (wrote 4342690 edits in 46904ms)
2011-04-25 09:09:26,134 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: master:60000-0x32f7bb74e8a0000 Creating (or updating) unassigned node for e7a478b4bd164525052f1dedb832de0a with OFFLINE state
2011-04-25 09:09:26,136 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: No previous transition plan was found (or we are ignoring an existing plan) for realtime_domain_imps_urls,afffffbe,1295556905482.e7a478b4bd164525052f1dedb832de0a. so generated a random one; hri=realtime_domain_imps_urls,afffffbe,1295556905482.e7a478b4bd164525052f1dedb832de0a., src=, dest=pumahbase107.snc5.facebook.com,60020,1303450731227; 70 (online=70, exclude=null) available servers
2011-04-25 09:09:26,136 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: Assigning region realtime_domain_imps_urls,afffffbe,1295556905482.e7a478b4bd164525052f1dedb832de0a. to pumahbase107.snc5.facebook.com,60020,1303450731227
2011-04-25 09:09:26,139 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: Handling transition=RS_ZK_REGION_OPENING, server=pumahbase107.snc5.facebook.com,60020,1303450731227, region=e7a478b4bd164525052f1dedb832de0a
2011-04-25 09:09:44,045 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: Handling transition=RS_ZK_REGION_OPENING, server=pumahbase107.snc5.facebook.com,60020,1303450731227, region=e7a478b4bd164525052f1dedb832de0a
2011-04-25 09:09:59,050 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: Handling transition=RS_ZK_REGION_OPENING, server=pumahbase107.snc5.facebook.com,60020,1303450731227, region=e7a478b4bd164525052f1dedb832de0a
2011-04-25 09:10:14,054 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: Handling transition=RS_ZK_REGION_OPENING, server=pumahbase107.snc5.facebook.com,60020,1303450731227, region=e7a478b4bd164525052f1dedb832de0a
2011-04-25 09:10:29,055 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: Handling transition=RS_ZK_REGION_OPENING, server=pumahbase107.snc5.facebook.com,60020,1303450731227, region=e7a478b4bd164525052f1dedb832de0a
2011-04-25 09:10:44,060 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: Handling transition=RS_ZK_REGION_OPENING, server=pumahbase107.snc5.facebook.com,60020,1303450731227, region=e7a478b4bd164525052f1dedb832de0a
2011-04-25 09:10:59,062 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: Handling transition=RS_ZK_REGION_OPENING, server=pumahbase107.snc5.facebook.com,60020,1303450731227, region=e7a478b4bd164525052f1dedb832de0a
2011-04-25 09:10:59,388 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: Handling transition=RS_ZK_REGION_OPENING, server=pumahbase107.snc5.facebook.com,60020,1303450731227, region=e7a478b4bd164525052f1dedb832de0a
2011-04-25 09:11:33,411 INFO org.apache.hadoop.hbase.master.AssignmentManager: Regions in transition timed out: realtime_domain_imps_urls,afffffbe,1295556905482.e7a478b4bd164525052f1dedb832de0a. state=OPENING, ts=1303747859386
2011-04-25 09:11:33,411 INFO org.apache.hadoop.hbase.master.AssignmentManager: Region has been OPENING for too long, reassigning region=realtime_domain_imps_urls,afffffbe,1295556905482.e7a478b4bd164525052f1dedb832de0a.
2011-04-25 09:11:33,412 INFO org.apache.hadoop.hbase.master.AssignmentManager: Successfully transitioned region=realtime_domain_imps_urls,afffffbe,1295556905482.e7a478b4bd164525052f1dedb832de0a. into OFFLINE and forcing a new assignment
2011-04-25 09:11:33,412 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: No previous transition plan was found (or we are ignoring an existing plan) for realtime_domain_imps_urls,afffffbe,1295556905482.e7a478b4bd164525052f1dedb832de0a. so generated a random one; hri=realtime_domain_imps_urls,afffffbe,1295556905482.e7a478b4bd164525052f1dedb832de0a., src=, dest=pumahbase150.snc5.facebook.com,60020,1303450731207; 70 (online=70, exclude=null) available servers
2011-04-25 09:11:33,413 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: Assigning region realtime_domain_imps_urls,afffffbe,1295556905482.e7a478b4bd164525052f1dedb832de0a. to pumahbase150.snc5.facebook.com,60020,1303450731207
2011-04-25 09:11:33,414 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: Handling transition=M_ZK_REGION_OFFLINE, server=pumahbase162.snc5.facebook.com:60000, region=e7a478b4bd164525052f1dedb832de0a
2011-04-25 09:11:33,416 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: Handling transition=RS_ZK_REGION_OPENING, server=pumahbase150.snc5.facebook.com,60020,1303450731207, region=e7a478b4bd164525052f1dedb832de0a
2011-04-25 09:11:33,825 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: Handling transition=RS_ZK_REGION_OPENING, server=pumahbase150.snc5.facebook.com,60020,1303450731207, region=e7a478b4bd164525052f1dedb832de0a
2011-04-25 09:11:36,804 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: Handling transition=RS_ZK_REGION_OPENED, server=pumahbase150.snc5.facebook.com,60020,1303450731207, region=e7a478b4bd164525052f1dedb832de0a
2011-04-25 09:11:36,804 DEBUG org.apache.hadoop.hbase.master.handler.OpenedRegionHandler: Handling OPENED event for e7a478b4bd164525052f1dedb832de0a; deleting unassigned node
2011-04-25 09:11:36,804 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: master:60000-0x32f7bb74e8a0000 Deleting existing unassigned node for e7a478b4bd164525052f1dedb832de0a that is in expected state RS_ZK_REGION_OPENED
2011-04-25 09:11:36,805 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: master:60000-0x32f7bb74e8a0000 Successfully deleted unassigned node for region e7a478b4bd164525052f1dedb832de0a in expected state RS_ZK_REGION_OPENED
2011-04-25 09:11:36,805 DEBUG org.apache.hadoop.hbase.master.handler.OpenedRegionHandler: Opened region realtime_domain_imps_urls,afffffbe,1295556905482.e7a478b4bd164525052f1dedb832de0a. on pumahbase150.snc5.facebook.com,60020,1303450731207
===
region server log
2011-04-25 09:09:26,136 INFO org.apache.hadoop.hbase.regionserver.HRegionServer: Received request to open region: realtime_domain_imps_urls,afffffbe,1295556905482.e7a478b4bd164525052f1dedb832de0a.
2011-04-25 09:09:26,136 DEBUG org.apache.hadoop.hbase.regionserver.handler.OpenRegionHandler: Processing open of realtime_domain_imps_urls,afffffbe,1295556905482.e7a478b4bd164525052f1dedb832de0a.
2011-04-25 09:09:26,136 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: regionserver:60020-0x22f7bb74e8e000a Attempting to transition node e7a478b4bd164525052f1dedb832de0a from M_ZK_REGION_OFFLINE to RS_ZK_REGION_OPENING
2011-04-25 09:09:26,138 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: regionserver:60020-0x22f7bb74e8e000a Successfully transitioned node e7a478b4bd164525052f1dedb832de0a from M_ZK_REGION_OFFLINE to RS_ZK_REGION_OPENING
2011-04-25 09:09:26,139 DEBUG org.apache.hadoop.hbase.regionserver.HRegion: Opening region: REGION => {NAME => 'realtime_domain_imps_urls,afffffbe,1295556905482.e7a478b4bd164525052f1dedb832de0a.', STARTKEY => 'afffffbe', ENDKEY => 'b040ebdbf81a3750f0eaa71842ff09dagr.insomnia li 294576344998', ENCODED => e7a478b4bd164525052f1dedb832de0a, TABLE => {{NAME => 'realtime_domain_imps_urls', FAMILIES => [{NAME => 'COUNTERS_0', BLOOMFILTER => 'NONE', REPLICATION_SCOPE => '0', COMPRESSION => 'LZO', VERSIONS => '1', TTL => '2147483647', BLOCKSIZE => '16384', IN_MEMORY => 'false', BLOCKCACHE => 'true'}, {NAME => 'COUNTERS_3600', BLOOMFILTER => 'NONE', REPLICATION_SCOPE => '0', COMPRESSION => 'LZO', VERSIONS => '1', TTL => '172800', BLOCKSIZE => '16384', IN_MEMORY => 'false', BLOCKCACHE => 'true'}, {NAME => 'COUNTERS_86400', BLOOMFILTER => 'NONE', REPLICATION_SCOPE => '0', COMPRESSION => 'LZO', VERSIONS => '1', TTL => '2592000', BLOCKSIZE => '16384', IN_MEMORY => 'false', BLOCKCACHE => 't
rue'}]}}
2011-04-25 09:09:26,140 DEBUG org.apache.hadoop.hbase.regionserver.HRegion: Instantiated realtime_domain_imps_urls,afffffbe,1295556905482.e7a478b4bd164525052f1dedb832de0a.
2011-04-25 09:09:26,140 INFO org.apache.hadoop.hbase.regionserver.logger.HRegionLogger: HRegionLogger for region realtime_domain_imps_urls,afffffbe,1295556905482.e7a478b4bd164525052f1dedb832de0a., category nectar_titan_hbase_updates
2011-04-25 09:09:26,190 DEBUG org.apache.hadoop.hbase.regionserver.Store: loaded hdfs://pumahbase002-snc5-dfs.data.facebook.com:9000/PUMAHBASE002-SNC5-HBASE/realtime_domain_imps_urls/e7a478b4bd164525052f1dedb832de0a/COUNTERS_0/87cf11f68701404b862d631ba3d20213, isReference=false, isBulkLoadResult=false, seqid=58137870275, majorCompaction=false
2011-04-25 09:09:28,572 DEBUG org.apache.hadoop.hbase.regionserver.Store: loaded hdfs://pumahbase002-snc5-dfs.data.facebook.com:9000/PUMAHBASE002-SNC5-HBASE/realtime_domain_imps_urls/e7a478b4bd164525052f1dedb832de0a/COUNTERS_0/c58d9a33653a4e5e966c426b33a57598, isReference=false, isBulkLoadResult=false, seqid=57847795298, majorCompaction=true
2011-04-25 09:09:28,796 DEBUG org.apache.hadoop.hbase.regionserver.Store: loaded hdfs://pumahbase002-snc5-dfs.data.facebook.com:9000/PUMAHBASE002-SNC5-HBASE/realtime_domain_imps_urls/e7a478b4bd164525052f1dedb832de0a/COUNTERS_3600/1bc513e915b741d59d4f113c273e67d4, isReference=false, isBulkLoadResult=false, seqid=58137870275, majorCompaction=false
2011-04-25 09:09:28,826 DEBUG org.apache.hadoop.hbase.regionserver.Store: loaded hdfs://pumahbase002-snc5-dfs.data.facebook.com:9000/PUMAHBASE002-SNC5-HBASE/realtime_domain_imps_urls/e7a478b4bd164525052f1dedb832de0a/COUNTERS_3600/5a50b17f3ad045368229680414987ae7, isReference=false, isBulkLoadResult=false, seqid=57847795298, majorCompaction=true
2011-04-25 09:09:28,850 DEBUG org.apache.hadoop.hbase.regionserver.Store: loaded hdfs://pumahbase002-snc5-dfs.data.facebook.com:9000/PUMAHBASE002-SNC5-HBASE/realtime_domain_imps_urls/e7a478b4bd164525052f1dedb832de0a/COUNTERS_86400/23648dce8d4243c5b804c0e766f5a235, isReference=false, isBulkLoadResult=false, seqid=58137870275, majorCompaction=false
2011-04-25 09:09:29,016 DEBUG org.apache.hadoop.hbase.regionserver.Store: loaded hdfs://pumahbase002-snc5-dfs.data.facebook.com:9000/PUMAHBASE002-SNC5-HBASE/realtime_domain_imps_urls/e7a478b4bd164525052f1dedb832de0a/COUNTERS_86400/d6820d86715049c087fa5c3f4355f2fc, isReference=false, isBulkLoadResult=false, seqid=57847795298, majorCompaction=true
2011-04-25 09:09:29,017 INFO org.apache.hadoop.hbase.regionserver.HRegion: Replaying edits from hdfs://pumahbase002-snc5-dfs.data.facebook.com:9000/PUMAHBASE002-SNC5-HBASE/realtime_domain_imps_urls/e7a478b4bd164525052f1dedb832de0a/recovered.edits/0000000057528037047; minSequenceid=58137870275
2011-04-25 09:09:44,041 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: regionserver:60020-0x22f7bb74e8e000a Attempting to transition node e7a478b4bd164525052f1dedb832de0a from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENING
2011-04-25 09:09:44,044 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: regionserver:60020-0x22f7bb74e8e000a Successfully transitioned node e7a478b4bd164525052f1dedb832de0a from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENING
2011-04-25 09:09:59,046 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: regionserver:60020-0x22f7bb74e8e000a Attempting to transition node e7a478b4bd164525052f1dedb832de0a from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENING
2011-04-25 09:09:59,050 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: regionserver:60020-0x22f7bb74e8e000a Successfully transitioned node e7a478b4bd164525052f1dedb832de0a from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENING
2011-04-25 09:10:14,050 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: regionserver:60020-0x22f7bb74e8e000a Attempting to transition node e7a478b4bd164525052f1dedb832de0a from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENING
832de0a from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENING
2011-04-25 09:10:29,055 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: regionserver:60020-0x22f7bb74e8e000a Successfully transitioned node e7a478b4bd164525052f1dedb832de0a from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENING
2011-04-25 09:10:44,056 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: regionserver:60020-0x22f7bb74e8e000a Attempting to transition node e7a478b4bd164525052f1dedb832de0a from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENING
2011-04-25 09:10:44,059 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: regionserver:60020-0x22f7bb74e8e000a Successfully transitioned node e7a478b4bd164525052f1dedb832de0a from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENING
2011-04-25 09:10:59,057 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: regionserver:60020-0x22f7bb74e8e000a Attempting to transition node e7a478b4bd164525052f1dedb832de0a from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENING
2011-04-25 09:10:59,062 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: regionserver:60020-0x22f7bb74e8e000a Successfully transitioned node e7a478b4bd164525052f1dedb832de0a from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENING
2011-04-25 09:10:59,154 DEBUG org.apache.hadoop.hbase.regionserver.HRegion: Started memstore flush for realtime_domain_imps_urls,afffffbe,1295556905482.e7a478b4bd164525052f1dedb832de0a., current region memstore size 18.9m; wal is null, using passed sequenceid=58140219688
2011-04-25 09:10:59,277 INFO org.apache.hadoop.hbase.regionserver.Store: Flushed , sequenceid=58140219688, memsize=12.4m, into tmp file hdfs://pumahbase002-snc5-dfs.data.facebook.com:9000/PUMAHBASE002-SNC5-HBASE/realtime_domain_imps_urls/e7a478b4bd164525052f1dedb832de0a/.tmp/a1df4f1ac37a4c7fbf4067f3bcff49a5
2011-04-25 09:10:59,312 INFO org.apache.hadoop.hbase.regionserver.Store: Flushed , sequenceid=58140219688, memsize=3.2m, into tmp file hdfs://pumahbase002-snc5-dfs.data.facebook.com:9000/PUMAHBASE002-SNC5-HBASE/realtime_domain_imps_urls/e7a478b4bd164525052f1dedb832de0a/.tmp/eefd1540ca644f06b251201894ef5dd8
2011-04-25 09:10:59,357 INFO org.apache.hadoop.hbase.regionserver.Store: Flushed , sequenceid=58140219688, memsize=3.2m, into tmp file hdfs://pumahbase002-snc5-dfs.data.facebook.com:9000/PUMAHBASE002-SNC5-HBASE/realtime_domain_imps_urls/e7a478b4bd164525052f1dedb832de0a/.tmp/83c87fcdbf7147ceac873a1e97e2990f
2011-04-25 09:10:59,357 INFO org.apache.hadoop.hbase.regionserver.Store: Renaming flushed file at hdfs://pumahbase002-snc5-dfs.data.facebook.com:9000/PUMAHBASE002-SNC5-HBASE/realtime_domain_imps_urls/e7a478b4bd164525052f1dedb832de0a/.tmp/a1df4f1ac37a4c7fbf4067f3bcff49a5 to hdfs://pumahbase002-snc5-dfs.data.facebook.com:9000/PUMAHBASE002-SNC5-HBASE/realtime_domain_imps_urls/e7a478b4bd164525052f1dedb832de0a/COUNTERS_0/a1df4f1ac37a4c7fbf4067f3bcff49a5
2011-04-25 09:10:59,372 INFO org.apache.hadoop.hbase.regionserver.Store: Added hdfs://pumahbase002-snc5-dfs.data.facebook.com:9000/PUMAHBASE002-SNC5-HBASE/realtime_domain_imps_urls/e7a478b4bd164525052f1dedb832de0a/COUNTERS_0/a1df4f1ac37a4c7fbf4067f3bcff49a5, entries=45626, sequenceid=58140219688, filesize=549.1k
2011-04-25 09:10:59,372 INFO org.apache.hadoop.hbase.regionserver.Store: Renaming flushed file at hdfs://pumahbase002-snc5-dfs.data.facebook.com:9000/PUMAHBASE002-SNC5-HBASE/realtime_domain_imps_urls/e7a478b4bd164525052f1dedb832de0a/.tmp/eefd1540ca644f06b251201894ef5dd8 to hdfs://pumahbase002-snc5-dfs.data.facebook.com:9000/PUMAHBASE002-SNC5-HBASE/realtime_domain_imps_urls/e7a478b4bd164525052f1dedb832de0a/COUNTERS_3600/eefd1540ca644f06b251201894ef5dd8
2011-04-25 09:10:59,375 INFO org.apache.hadoop.hbase.regionserver.Store: Added hdfs://pumahbase002-snc5-dfs.data.facebook.com:9000/PUMAHBASE002-SNC5-HBASE/realtime_domain_imps_urls/e7a478b4bd164525052f1dedb832de0a/COUNTERS_3600/eefd1540ca644f06b251201894ef5dd8, entries=11411, sequenceid=58140219688, filesize=167.9k
2011-04-25 09:10:59,375 INFO org.apache.hadoop.hbase.regionserver.Store: Renaming flushed file at hdfs://pumahbase002-snc5-dfs.data.facebook.com:9000/PUMAHBASE002-SNC5-HBASE/realtime_domain_imps_urls/e7a478b4bd164525052f1dedb832de0a/.tmp/83c87fcdbf7147ceac873a1e97e2990f to hdfs://pumahbase002-snc5-dfs.data.facebook.com:9000/PUMAHBASE002-SNC5-HBASE/realtime_domain_imps_urls/e7a478b4bd164525052f1dedb832de0a/COUNTERS_86400/83c87fcdbf7147ceac873a1e97e2990f
2011-04-25 09:10:59,378 INFO org.apache.hadoop.hbase.regionserver.Store: Added hdfs://pumahbase002-snc5-dfs.data.facebook.com:9000/PUMAHBASE002-SNC5-HBASE/realtime_domain_imps_urls/e7a478b4bd164525052f1dedb832de0a/COUNTERS_86400/83c87fcdbf7147ceac873a1e97e2990f, entries=11404, sequenceid=58140219688, filesize=161.5k
2011-04-25 09:10:59,378 INFO org.apache.hadoop.hbase.regionserver.HRegion: Finished memstore flush of ~18.9m for region realtime_domain_imps_urls,afffffbe,1295556905482.e7a478b4bd164525052f1dedb832de0a. in 224ms, sequenceid=58140219688, compaction requested=true; wal=null
2011-04-25 09:10:59,385 DEBUG org.apache.hadoop.hbase.regionserver.HRegion: Deleted recovered.edits file=hdfs://pumahbase002-snc5-dfs.data.facebook.com:9000/PUMAHBASE002-SNC5-HBASE/realtime_domain_imps_urls/e7a478b4bd164525052f1dedb832de0a/recovered.edits/0000000057528037047
2011-04-25 09:10:59,385 INFO org.apache.hadoop.hbase.regionserver.HRegion: Onlined realtime_domain_imps_urls,afffffbe,1295556905482.e7a478b4bd164525052f1dedb832de0a.; next sequenceid=58140219689
2011-04-25 09:10:59,385 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: regionserver:60020-0x22f7bb74e8e000a Attempting to transition node e7a478b4bd164525052f1dedb832de0a from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENING
2011-04-25 09:10:59,388 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: regionserver:60020-0x22f7bb74e8e000a Successfully transitioned node e7a478b4bd164525052f1dedb832de0a from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENING
2011-04-25 09:11:36,843 INFO org.apache.hadoop.hbase.catalog.MetaEditor: Updated row realtime_domain_imps_urls,afffffbe,1295556905482.e7a478b4bd164525052f1dedb832de0a. in region .META.,,1 with server=pumahbase107.snc5.facebook.com:60020, startcode=1303450731227
2011-04-25 09:11:36,843 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: regionserver:60020-0x22f7bb74e8e000a Attempting to transition node e7a478b4bd164525052f1dedb832de0a from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENED
java.lang.NullPointerException
===
--
This message is automatically generated by JIRA.
For more information on JIRA, see: http://www.atlassian.com/software/jira
[jira] [Commented] (HBASE-3824) region server timed out during open
region
Posted by "Jean-Daniel Cryans (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/HBASE-3824?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13025483#comment-13025483 ]
Jean-Daniel Cryans commented on HBASE-3824:
-------------------------------------------
So what's the issue about exactly? We expect region server to time out opening AFAIK, so is the problem more about the idempotent nature of opening a region and then failing at doing it when it's assigned somewhere else?
> region server timed out during open region
> ------------------------------------------
>
> Key: HBASE-3824
> URL: https://issues.apache.org/jira/browse/HBASE-3824
> Project: HBase
> Issue Type: Bug
> Reporter: Prakash Khemani
>
> When replaying a large log file, mestore flushes can happen. But there is no Progressible report being sent during memstore flushes. That can lead to master timing out the region server during region open.
> ===
> Another related issue and Jonathan's response
> > So if a region server that is handed a region for opening and has done part of
> > the work ... it has created some HFiles (because the logs were so huge that
> > the mestore got flushed while the logs were being replayed) ... and then it is
> > asked to give up because the master thought the region server was taking
> > too long to open the region.
> >
> > When the region server gives up on the region then will it make sure that it
> > removes all the HFiles it had created for that region?
> Will need to check the code, but would it matter? One issue is whether it cleans up after itself (I'm guessing not). Another issue is whether the replay is idempotent (duplicate KVs across files shouldn't matter in most cases).
> ===
> 2011-04-25 09:11:36,844 ERROR org.apache.hadoop.hbase.executor.EventHandler: Caught throwable while processing event M_RS_OPEN_REGION
> java.lang.NullPointerException
> at org.apache.hadoop.hbase.util.Writables.getWritable(Writables.java:75)
> at org.apache.hadoop.hbase.executor.RegionTransitionData.fromBytes(RegionTransitionData.java:198)
> at org.apache.hadoop.hbase.zookeeper.ZKAssign.transitionNode(ZKAssign.java:672)
> at org.apache.hadoop.hbase.zookeeper.ZKAssign.transitionNodeOpened(ZKAssign.java:621)
> at org.apache.hadoop.hbase.regionserver.handler.OpenRegionHandler.process(OpenRegionHandler.java:168)
> at org.apache.hadoop.hbase.executor.EventHandler.run(EventHandler.java:151)
> at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
> at java.lang.Thread.run(Thread.java:619)
> byte [] existingBytes =
> ZKUtil.getDataNoWatch(zkw, node, stat);
> RegionTransitionData existingData =
> RegionTransitionData.fromBytes(existingBytes);
> existingBytes can be null. have to return -1 if null.
> ===
> master logs
> 2011-04-25 05:24:03,250 DEBUG org.apache.hadoop.hbase.regionserver.wal.HLogSplitter: Creating writer path=hdfs://pumahbase002-snc5-dfs.data.facebook.com:9000/PUMAHBASE002-SNC5-HBASE/realtime_domain_imps_urls/e7a478b4bd164525052f1dedb832de0a/recovered.edits/0000000057528037047 region=e7a478b4bd164525052f1dedb832de0a
> 2011-04-25 09:09:19,246 INFO org.apache.hadoop.hbase.regionserver.wal.HLogSplitter: Closed path hdfs://pumahbase002-snc5-dfs.data.facebook.com:9000/PUMAHBASE002-SNC5-HBASE/realtime_domain_imps_urls/e7a478b4bd164525052f1dedb832de0a/recovered.edits/0000000057528037047 (wrote 4342690 edits in 46904ms)
> 2011-04-25 09:09:26,134 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: master:60000-0x32f7bb74e8a0000 Creating (or updating) unassigned node for e7a478b4bd164525052f1dedb832de0a with OFFLINE state
> 2011-04-25 09:09:26,136 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: No previous transition plan was found (or we are ignoring an existing plan) for realtime_domain_imps_urls,afffffbe,1295556905482.e7a478b4bd164525052f1dedb832de0a. so generated a random one; hri=realtime_domain_imps_urls,afffffbe,1295556905482.e7a478b4bd164525052f1dedb832de0a., src=, dest=pumahbase107.snc5.facebook.com,60020,1303450731227; 70 (online=70, exclude=null) available servers
> 2011-04-25 09:09:26,136 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: Assigning region realtime_domain_imps_urls,afffffbe,1295556905482.e7a478b4bd164525052f1dedb832de0a. to pumahbase107.snc5.facebook.com,60020,1303450731227
> 2011-04-25 09:09:26,139 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: Handling transition=RS_ZK_REGION_OPENING, server=pumahbase107.snc5.facebook.com,60020,1303450731227, region=e7a478b4bd164525052f1dedb832de0a
> 2011-04-25 09:09:44,045 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: Handling transition=RS_ZK_REGION_OPENING, server=pumahbase107.snc5.facebook.com,60020,1303450731227, region=e7a478b4bd164525052f1dedb832de0a
> 2011-04-25 09:09:59,050 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: Handling transition=RS_ZK_REGION_OPENING, server=pumahbase107.snc5.facebook.com,60020,1303450731227, region=e7a478b4bd164525052f1dedb832de0a
> 2011-04-25 09:10:14,054 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: Handling transition=RS_ZK_REGION_OPENING, server=pumahbase107.snc5.facebook.com,60020,1303450731227, region=e7a478b4bd164525052f1dedb832de0a
> 2011-04-25 09:10:29,055 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: Handling transition=RS_ZK_REGION_OPENING, server=pumahbase107.snc5.facebook.com,60020,1303450731227, region=e7a478b4bd164525052f1dedb832de0a
> 2011-04-25 09:10:44,060 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: Handling transition=RS_ZK_REGION_OPENING, server=pumahbase107.snc5.facebook.com,60020,1303450731227, region=e7a478b4bd164525052f1dedb832de0a
> 2011-04-25 09:10:59,062 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: Handling transition=RS_ZK_REGION_OPENING, server=pumahbase107.snc5.facebook.com,60020,1303450731227, region=e7a478b4bd164525052f1dedb832de0a
> 2011-04-25 09:10:59,388 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: Handling transition=RS_ZK_REGION_OPENING, server=pumahbase107.snc5.facebook.com,60020,1303450731227, region=e7a478b4bd164525052f1dedb832de0a
> 2011-04-25 09:11:33,411 INFO org.apache.hadoop.hbase.master.AssignmentManager: Regions in transition timed out: realtime_domain_imps_urls,afffffbe,1295556905482.e7a478b4bd164525052f1dedb832de0a. state=OPENING, ts=1303747859386
> 2011-04-25 09:11:33,411 INFO org.apache.hadoop.hbase.master.AssignmentManager: Region has been OPENING for too long, reassigning region=realtime_domain_imps_urls,afffffbe,1295556905482.e7a478b4bd164525052f1dedb832de0a.
> 2011-04-25 09:11:33,412 INFO org.apache.hadoop.hbase.master.AssignmentManager: Successfully transitioned region=realtime_domain_imps_urls,afffffbe,1295556905482.e7a478b4bd164525052f1dedb832de0a. into OFFLINE and forcing a new assignment
> 2011-04-25 09:11:33,412 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: No previous transition plan was found (or we are ignoring an existing plan) for realtime_domain_imps_urls,afffffbe,1295556905482.e7a478b4bd164525052f1dedb832de0a. so generated a random one; hri=realtime_domain_imps_urls,afffffbe,1295556905482.e7a478b4bd164525052f1dedb832de0a., src=, dest=pumahbase150.snc5.facebook.com,60020,1303450731207; 70 (online=70, exclude=null) available servers
> 2011-04-25 09:11:33,413 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: Assigning region realtime_domain_imps_urls,afffffbe,1295556905482.e7a478b4bd164525052f1dedb832de0a. to pumahbase150.snc5.facebook.com,60020,1303450731207
> 2011-04-25 09:11:33,414 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: Handling transition=M_ZK_REGION_OFFLINE, server=pumahbase162.snc5.facebook.com:60000, region=e7a478b4bd164525052f1dedb832de0a
> 2011-04-25 09:11:33,416 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: Handling transition=RS_ZK_REGION_OPENING, server=pumahbase150.snc5.facebook.com,60020,1303450731207, region=e7a478b4bd164525052f1dedb832de0a
> 2011-04-25 09:11:33,825 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: Handling transition=RS_ZK_REGION_OPENING, server=pumahbase150.snc5.facebook.com,60020,1303450731207, region=e7a478b4bd164525052f1dedb832de0a
> 2011-04-25 09:11:36,804 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: Handling transition=RS_ZK_REGION_OPENED, server=pumahbase150.snc5.facebook.com,60020,1303450731207, region=e7a478b4bd164525052f1dedb832de0a
> 2011-04-25 09:11:36,804 DEBUG org.apache.hadoop.hbase.master.handler.OpenedRegionHandler: Handling OPENED event for e7a478b4bd164525052f1dedb832de0a; deleting unassigned node
> 2011-04-25 09:11:36,804 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: master:60000-0x32f7bb74e8a0000 Deleting existing unassigned node for e7a478b4bd164525052f1dedb832de0a that is in expected state RS_ZK_REGION_OPENED
> 2011-04-25 09:11:36,805 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: master:60000-0x32f7bb74e8a0000 Successfully deleted unassigned node for region e7a478b4bd164525052f1dedb832de0a in expected state RS_ZK_REGION_OPENED
> 2011-04-25 09:11:36,805 DEBUG org.apache.hadoop.hbase.master.handler.OpenedRegionHandler: Opened region realtime_domain_imps_urls,afffffbe,1295556905482.e7a478b4bd164525052f1dedb832de0a. on pumahbase150.snc5.facebook.com,60020,1303450731207
> ===
> region server log
> 2011-04-25 09:09:26,136 INFO org.apache.hadoop.hbase.regionserver.HRegionServer: Received request to open region: realtime_domain_imps_urls,afffffbe,1295556905482.e7a478b4bd164525052f1dedb832de0a.
> 2011-04-25 09:09:26,136 DEBUG org.apache.hadoop.hbase.regionserver.handler.OpenRegionHandler: Processing open of realtime_domain_imps_urls,afffffbe,1295556905482.e7a478b4bd164525052f1dedb832de0a.
> 2011-04-25 09:09:26,136 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: regionserver:60020-0x22f7bb74e8e000a Attempting to transition node e7a478b4bd164525052f1dedb832de0a from M_ZK_REGION_OFFLINE to RS_ZK_REGION_OPENING
> 2011-04-25 09:09:26,138 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: regionserver:60020-0x22f7bb74e8e000a Successfully transitioned node e7a478b4bd164525052f1dedb832de0a from M_ZK_REGION_OFFLINE to RS_ZK_REGION_OPENING
> 2011-04-25 09:09:26,139 DEBUG org.apache.hadoop.hbase.regionserver.HRegion: Opening region: REGION => {NAME => 'realtime_domain_imps_urls,afffffbe,1295556905482.e7a478b4bd164525052f1dedb832de0a.', STARTKEY => 'afffffbe', ENDKEY => 'b040ebdbf81a3750f0eaa71842ff09dagr.insomnia li 294576344998', ENCODED => e7a478b4bd164525052f1dedb832de0a, TABLE => {{NAME => 'realtime_domain_imps_urls', FAMILIES => [{NAME => 'COUNTERS_0', BLOOMFILTER => 'NONE', REPLICATION_SCOPE => '0', COMPRESSION => 'LZO', VERSIONS => '1', TTL => '2147483647', BLOCKSIZE => '16384', IN_MEMORY => 'false', BLOCKCACHE => 'true'}, {NAME => 'COUNTERS_3600', BLOOMFILTER => 'NONE', REPLICATION_SCOPE => '0', COMPRESSION => 'LZO', VERSIONS => '1', TTL => '172800', BLOCKSIZE => '16384', IN_MEMORY => 'false', BLOCKCACHE => 'true'}, {NAME => 'COUNTERS_86400', BLOOMFILTER => 'NONE', REPLICATION_SCOPE => '0', COMPRESSION => 'LZO', VERSIONS => '1', TTL => '2592000', BLOCKSIZE => '16384', IN_MEMORY => 'false', BLOCKCACHE => 'true'}]}}
> 2011-04-25 09:09:26,140 DEBUG org.apache.hadoop.hbase.regionserver.HRegion: Instantiated realtime_domain_imps_urls,afffffbe,1295556905482.e7a478b4bd164525052f1dedb832de0a.
> 2011-04-25 09:09:26,140 INFO org.apache.hadoop.hbase.regionserver.logger.HRegionLogger: HRegionLogger for region realtime_domain_imps_urls,afffffbe,1295556905482.e7a478b4bd164525052f1dedb832de0a., category nectar_titan_hbase_updates
> 2011-04-25 09:09:26,190 DEBUG org.apache.hadoop.hbase.regionserver.Store: loaded hdfs://pumahbase002-snc5-dfs.data.facebook.com:9000/PUMAHBASE002-SNC5-HBASE/realtime_domain_imps_urls/e7a478b4bd164525052f1dedb832de0a/COUNTERS_0/87cf11f68701404b862d631ba3d20213, isReference=false, isBulkLoadResult=false, seqid=58137870275, majorCompaction=false
> 2011-04-25 09:09:28,572 DEBUG org.apache.hadoop.hbase.regionserver.Store: loaded hdfs://pumahbase002-snc5-dfs.data.facebook.com:9000/PUMAHBASE002-SNC5-HBASE/realtime_domain_imps_urls/e7a478b4bd164525052f1dedb832de0a/COUNTERS_0/c58d9a33653a4e5e966c426b33a57598, isReference=false, isBulkLoadResult=false, seqid=57847795298, majorCompaction=true
> 2011-04-25 09:09:28,796 DEBUG org.apache.hadoop.hbase.regionserver.Store: loaded hdfs://pumahbase002-snc5-dfs.data.facebook.com:9000/PUMAHBASE002-SNC5-HBASE/realtime_domain_imps_urls/e7a478b4bd164525052f1dedb832de0a/COUNTERS_3600/1bc513e915b741d59d4f113c273e67d4, isReference=false, isBulkLoadResult=false, seqid=58137870275, majorCompaction=false
> 2011-04-25 09:09:28,826 DEBUG org.apache.hadoop.hbase.regionserver.Store: loaded hdfs://pumahbase002-snc5-dfs.data.facebook.com:9000/PUMAHBASE002-SNC5-HBASE/realtime_domain_imps_urls/e7a478b4bd164525052f1dedb832de0a/COUNTERS_3600/5a50b17f3ad045368229680414987ae7, isReference=false, isBulkLoadResult=false, seqid=57847795298, majorCompaction=true
> 2011-04-25 09:09:28,850 DEBUG org.apache.hadoop.hbase.regionserver.Store: loaded hdfs://pumahbase002-snc5-dfs.data.facebook.com:9000/PUMAHBASE002-SNC5-HBASE/realtime_domain_imps_urls/e7a478b4bd164525052f1dedb832de0a/COUNTERS_86400/23648dce8d4243c5b804c0e766f5a235, isReference=false, isBulkLoadResult=false, seqid=58137870275, majorCompaction=false
> 2011-04-25 09:09:29,016 DEBUG org.apache.hadoop.hbase.regionserver.Store: loaded hdfs://pumahbase002-snc5-dfs.data.facebook.com:9000/PUMAHBASE002-SNC5-HBASE/realtime_domain_imps_urls/e7a478b4bd164525052f1dedb832de0a/COUNTERS_86400/d6820d86715049c087fa5c3f4355f2fc, isReference=false, isBulkLoadResult=false, seqid=57847795298, majorCompaction=true
> 2011-04-25 09:09:29,017 INFO org.apache.hadoop.hbase.regionserver.HRegion: Replaying edits from hdfs://pumahbase002-snc5-dfs.data.facebook.com:9000/PUMAHBASE002-SNC5-HBASE/realtime_domain_imps_urls/e7a478b4bd164525052f1dedb832de0a/recovered.edits/0000000057528037047; minSequenceid=58137870275
> 2011-04-25 09:09:44,041 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: regionserver:60020-0x22f7bb74e8e000a Attempting to transition node e7a478b4bd164525052f1dedb832de0a from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENING
> 2011-04-25 09:09:44,044 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: regionserver:60020-0x22f7bb74e8e000a Successfully transitioned node e7a478b4bd164525052f1dedb832de0a from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENING
> 2011-04-25 09:09:59,046 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: regionserver:60020-0x22f7bb74e8e000a Attempting to transition node e7a478b4bd164525052f1dedb832de0a from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENING
> 2011-04-25 09:09:59,050 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: regionserver:60020-0x22f7bb74e8e000a Successfully transitioned node e7a478b4bd164525052f1dedb832de0a from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENING
> 2011-04-25 09:10:14,050 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: regionserver:60020-0x22f7bb74e8e000a Attempting to transition node e7a478b4bd164525052f1dedb832de0a from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENING
> 832de0a from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENING
> 2011-04-25 09:10:29,055 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: regionserver:60020-0x22f7bb74e8e000a Successfully transitioned node e7a478b4bd164525052f1dedb832de0a from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENING
> 2011-04-25 09:10:44,056 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: regionserver:60020-0x22f7bb74e8e000a Attempting to transition node e7a478b4bd164525052f1dedb832de0a from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENING
> 2011-04-25 09:10:44,059 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: regionserver:60020-0x22f7bb74e8e000a Successfully transitioned node e7a478b4bd164525052f1dedb832de0a from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENING
> 2011-04-25 09:10:59,057 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: regionserver:60020-0x22f7bb74e8e000a Attempting to transition node e7a478b4bd164525052f1dedb832de0a from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENING
> 2011-04-25 09:10:59,062 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: regionserver:60020-0x22f7bb74e8e000a Successfully transitioned node e7a478b4bd164525052f1dedb832de0a from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENING
> 2011-04-25 09:10:59,154 DEBUG org.apache.hadoop.hbase.regionserver.HRegion: Started memstore flush for realtime_domain_imps_urls,afffffbe,1295556905482.e7a478b4bd164525052f1dedb832de0a., current region memstore size 18.9m; wal is null, using passed sequenceid=58140219688
> 2011-04-25 09:10:59,277 INFO org.apache.hadoop.hbase.regionserver.Store: Flushed , sequenceid=58140219688, memsize=12.4m, into tmp file hdfs://pumahbase002-snc5-dfs.data.facebook.com:9000/PUMAHBASE002-SNC5-HBASE/realtime_domain_imps_urls/e7a478b4bd164525052f1dedb832de0a/.tmp/a1df4f1ac37a4c7fbf4067f3bcff49a5
> 2011-04-25 09:10:59,312 INFO org.apache.hadoop.hbase.regionserver.Store: Flushed , sequenceid=58140219688, memsize=3.2m, into tmp file hdfs://pumahbase002-snc5-dfs.data.facebook.com:9000/PUMAHBASE002-SNC5-HBASE/realtime_domain_imps_urls/e7a478b4bd164525052f1dedb832de0a/.tmp/eefd1540ca644f06b251201894ef5dd8
> 2011-04-25 09:10:59,357 INFO org.apache.hadoop.hbase.regionserver.Store: Flushed , sequenceid=58140219688, memsize=3.2m, into tmp file hdfs://pumahbase002-snc5-dfs.data.facebook.com:9000/PUMAHBASE002-SNC5-HBASE/realtime_domain_imps_urls/e7a478b4bd164525052f1dedb832de0a/.tmp/83c87fcdbf7147ceac873a1e97e2990f
> 2011-04-25 09:10:59,357 INFO org.apache.hadoop.hbase.regionserver.Store: Renaming flushed file at hdfs://pumahbase002-snc5-dfs.data.facebook.com:9000/PUMAHBASE002-SNC5-HBASE/realtime_domain_imps_urls/e7a478b4bd164525052f1dedb832de0a/.tmp/a1df4f1ac37a4c7fbf4067f3bcff49a5 to hdfs://pumahbase002-snc5-dfs.data.facebook.com:9000/PUMAHBASE002-SNC5-HBASE/realtime_domain_imps_urls/e7a478b4bd164525052f1dedb832de0a/COUNTERS_0/a1df4f1ac37a4c7fbf4067f3bcff49a5
> 2011-04-25 09:10:59,372 INFO org.apache.hadoop.hbase.regionserver.Store: Added hdfs://pumahbase002-snc5-dfs.data.facebook.com:9000/PUMAHBASE002-SNC5-HBASE/realtime_domain_imps_urls/e7a478b4bd164525052f1dedb832de0a/COUNTERS_0/a1df4f1ac37a4c7fbf4067f3bcff49a5, entries=45626, sequenceid=58140219688, filesize=549.1k
> 2011-04-25 09:10:59,372 INFO org.apache.hadoop.hbase.regionserver.Store: Renaming flushed file at hdfs://pumahbase002-snc5-dfs.data.facebook.com:9000/PUMAHBASE002-SNC5-HBASE/realtime_domain_imps_urls/e7a478b4bd164525052f1dedb832de0a/.tmp/eefd1540ca644f06b251201894ef5dd8 to hdfs://pumahbase002-snc5-dfs.data.facebook.com:9000/PUMAHBASE002-SNC5-HBASE/realtime_domain_imps_urls/e7a478b4bd164525052f1dedb832de0a/COUNTERS_3600/eefd1540ca644f06b251201894ef5dd8
> 2011-04-25 09:10:59,375 INFO org.apache.hadoop.hbase.regionserver.Store: Added hdfs://pumahbase002-snc5-dfs.data.facebook.com:9000/PUMAHBASE002-SNC5-HBASE/realtime_domain_imps_urls/e7a478b4bd164525052f1dedb832de0a/COUNTERS_3600/eefd1540ca644f06b251201894ef5dd8, entries=11411, sequenceid=58140219688, filesize=167.9k
> 2011-04-25 09:10:59,375 INFO org.apache.hadoop.hbase.regionserver.Store: Renaming flushed file at hdfs://pumahbase002-snc5-dfs.data.facebook.com:9000/PUMAHBASE002-SNC5-HBASE/realtime_domain_imps_urls/e7a478b4bd164525052f1dedb832de0a/.tmp/83c87fcdbf7147ceac873a1e97e2990f to hdfs://pumahbase002-snc5-dfs.data.facebook.com:9000/PUMAHBASE002-SNC5-HBASE/realtime_domain_imps_urls/e7a478b4bd164525052f1dedb832de0a/COUNTERS_86400/83c87fcdbf7147ceac873a1e97e2990f
> 2011-04-25 09:10:59,378 INFO org.apache.hadoop.hbase.regionserver.Store: Added hdfs://pumahbase002-snc5-dfs.data.facebook.com:9000/PUMAHBASE002-SNC5-HBASE/realtime_domain_imps_urls/e7a478b4bd164525052f1dedb832de0a/COUNTERS_86400/83c87fcdbf7147ceac873a1e97e2990f, entries=11404, sequenceid=58140219688, filesize=161.5k
> 2011-04-25 09:10:59,378 INFO org.apache.hadoop.hbase.regionserver.HRegion: Finished memstore flush of ~18.9m for region realtime_domain_imps_urls,afffffbe,1295556905482.e7a478b4bd164525052f1dedb832de0a. in 224ms, sequenceid=58140219688, compaction requested=true; wal=null
> 2011-04-25 09:10:59,385 DEBUG org.apache.hadoop.hbase.regionserver.HRegion: Deleted recovered.edits file=hdfs://pumahbase002-snc5-dfs.data.facebook.com:9000/PUMAHBASE002-SNC5-HBASE/realtime_domain_imps_urls/e7a478b4bd164525052f1dedb832de0a/recovered.edits/0000000057528037047
> 2011-04-25 09:10:59,385 INFO org.apache.hadoop.hbase.regionserver.HRegion: Onlined realtime_domain_imps_urls,afffffbe,1295556905482.e7a478b4bd164525052f1dedb832de0a.; next sequenceid=58140219689
> 2011-04-25 09:10:59,385 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: regionserver:60020-0x22f7bb74e8e000a Attempting to transition node e7a478b4bd164525052f1dedb832de0a from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENING
> 2011-04-25 09:10:59,388 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: regionserver:60020-0x22f7bb74e8e000a Successfully transitioned node e7a478b4bd164525052f1dedb832de0a from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENING
> 2011-04-25 09:11:36,843 INFO org.apache.hadoop.hbase.catalog.MetaEditor: Updated row realtime_domain_imps_urls,afffffbe,1295556905482.e7a478b4bd164525052f1dedb832de0a. in region .META.,,1 with server=pumahbase107.snc5.facebook.com:60020, startcode=1303450731227
> 2011-04-25 09:11:36,843 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: regionserver:60020-0x22f7bb74e8e000a Attempting to transition node e7a478b4bd164525052f1dedb832de0a from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENED
> java.lang.NullPointerException
> ===
--
This message is automatically generated by JIRA.
For more information on JIRA, see: http://www.atlassian.com/software/jira
[jira] [Commented] (HBASE-3824) region server timed out during open
region
Posted by "Prakash Khemani (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/HBASE-3824?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13025491#comment-13025491 ]
Prakash Khemani commented on HBASE-3824:
----------------------------------------
Probably not an issue. The memstore flush happens in the background and cannot cause the log-replay thread to block. My mistake. I will close this.
> region server timed out during open region
> ------------------------------------------
>
> Key: HBASE-3824
> URL: https://issues.apache.org/jira/browse/HBASE-3824
> Project: HBase
> Issue Type: Bug
> Reporter: Prakash Khemani
>
> When replaying a large log file, mestore flushes can happen. But there is no Progressible report being sent during memstore flushes. That can lead to master timing out the region server during region open.
> ===
> Another related issue and Jonathan's response
> > So if a region server that is handed a region for opening and has done part of
> > the work ... it has created some HFiles (because the logs were so huge that
> > the mestore got flushed while the logs were being replayed) ... and then it is
> > asked to give up because the master thought the region server was taking
> > too long to open the region.
> >
> > When the region server gives up on the region then will it make sure that it
> > removes all the HFiles it had created for that region?
> Will need to check the code, but would it matter? One issue is whether it cleans up after itself (I'm guessing not). Another issue is whether the replay is idempotent (duplicate KVs across files shouldn't matter in most cases).
> ===
> 2011-04-25 09:11:36,844 ERROR org.apache.hadoop.hbase.executor.EventHandler: Caught throwable while processing event M_RS_OPEN_REGION
> java.lang.NullPointerException
> at org.apache.hadoop.hbase.util.Writables.getWritable(Writables.java:75)
> at org.apache.hadoop.hbase.executor.RegionTransitionData.fromBytes(RegionTransitionData.java:198)
> at org.apache.hadoop.hbase.zookeeper.ZKAssign.transitionNode(ZKAssign.java:672)
> at org.apache.hadoop.hbase.zookeeper.ZKAssign.transitionNodeOpened(ZKAssign.java:621)
> at org.apache.hadoop.hbase.regionserver.handler.OpenRegionHandler.process(OpenRegionHandler.java:168)
> at org.apache.hadoop.hbase.executor.EventHandler.run(EventHandler.java:151)
> at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
> at java.lang.Thread.run(Thread.java:619)
> byte [] existingBytes =
> ZKUtil.getDataNoWatch(zkw, node, stat);
> RegionTransitionData existingData =
> RegionTransitionData.fromBytes(existingBytes);
> existingBytes can be null. have to return -1 if null.
> ===
> master logs
> 2011-04-25 05:24:03,250 DEBUG org.apache.hadoop.hbase.regionserver.wal.HLogSplitter: Creating writer path=hdfs://pumahbase002-snc5-dfs.data.facebook.com:9000/PUMAHBASE002-SNC5-HBASE/realtime_domain_imps_urls/e7a478b4bd164525052f1dedb832de0a/recovered.edits/0000000057528037047 region=e7a478b4bd164525052f1dedb832de0a
> 2011-04-25 09:09:19,246 INFO org.apache.hadoop.hbase.regionserver.wal.HLogSplitter: Closed path hdfs://pumahbase002-snc5-dfs.data.facebook.com:9000/PUMAHBASE002-SNC5-HBASE/realtime_domain_imps_urls/e7a478b4bd164525052f1dedb832de0a/recovered.edits/0000000057528037047 (wrote 4342690 edits in 46904ms)
> 2011-04-25 09:09:26,134 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: master:60000-0x32f7bb74e8a0000 Creating (or updating) unassigned node for e7a478b4bd164525052f1dedb832de0a with OFFLINE state
> 2011-04-25 09:09:26,136 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: No previous transition plan was found (or we are ignoring an existing plan) for realtime_domain_imps_urls,afffffbe,1295556905482.e7a478b4bd164525052f1dedb832de0a. so generated a random one; hri=realtime_domain_imps_urls,afffffbe,1295556905482.e7a478b4bd164525052f1dedb832de0a., src=, dest=pumahbase107.snc5.facebook.com,60020,1303450731227; 70 (online=70, exclude=null) available servers
> 2011-04-25 09:09:26,136 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: Assigning region realtime_domain_imps_urls,afffffbe,1295556905482.e7a478b4bd164525052f1dedb832de0a. to pumahbase107.snc5.facebook.com,60020,1303450731227
> 2011-04-25 09:09:26,139 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: Handling transition=RS_ZK_REGION_OPENING, server=pumahbase107.snc5.facebook.com,60020,1303450731227, region=e7a478b4bd164525052f1dedb832de0a
> 2011-04-25 09:09:44,045 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: Handling transition=RS_ZK_REGION_OPENING, server=pumahbase107.snc5.facebook.com,60020,1303450731227, region=e7a478b4bd164525052f1dedb832de0a
> 2011-04-25 09:09:59,050 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: Handling transition=RS_ZK_REGION_OPENING, server=pumahbase107.snc5.facebook.com,60020,1303450731227, region=e7a478b4bd164525052f1dedb832de0a
> 2011-04-25 09:10:14,054 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: Handling transition=RS_ZK_REGION_OPENING, server=pumahbase107.snc5.facebook.com,60020,1303450731227, region=e7a478b4bd164525052f1dedb832de0a
> 2011-04-25 09:10:29,055 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: Handling transition=RS_ZK_REGION_OPENING, server=pumahbase107.snc5.facebook.com,60020,1303450731227, region=e7a478b4bd164525052f1dedb832de0a
> 2011-04-25 09:10:44,060 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: Handling transition=RS_ZK_REGION_OPENING, server=pumahbase107.snc5.facebook.com,60020,1303450731227, region=e7a478b4bd164525052f1dedb832de0a
> 2011-04-25 09:10:59,062 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: Handling transition=RS_ZK_REGION_OPENING, server=pumahbase107.snc5.facebook.com,60020,1303450731227, region=e7a478b4bd164525052f1dedb832de0a
> 2011-04-25 09:10:59,388 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: Handling transition=RS_ZK_REGION_OPENING, server=pumahbase107.snc5.facebook.com,60020,1303450731227, region=e7a478b4bd164525052f1dedb832de0a
> 2011-04-25 09:11:33,411 INFO org.apache.hadoop.hbase.master.AssignmentManager: Regions in transition timed out: realtime_domain_imps_urls,afffffbe,1295556905482.e7a478b4bd164525052f1dedb832de0a. state=OPENING, ts=1303747859386
> 2011-04-25 09:11:33,411 INFO org.apache.hadoop.hbase.master.AssignmentManager: Region has been OPENING for too long, reassigning region=realtime_domain_imps_urls,afffffbe,1295556905482.e7a478b4bd164525052f1dedb832de0a.
> 2011-04-25 09:11:33,412 INFO org.apache.hadoop.hbase.master.AssignmentManager: Successfully transitioned region=realtime_domain_imps_urls,afffffbe,1295556905482.e7a478b4bd164525052f1dedb832de0a. into OFFLINE and forcing a new assignment
> 2011-04-25 09:11:33,412 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: No previous transition plan was found (or we are ignoring an existing plan) for realtime_domain_imps_urls,afffffbe,1295556905482.e7a478b4bd164525052f1dedb832de0a. so generated a random one; hri=realtime_domain_imps_urls,afffffbe,1295556905482.e7a478b4bd164525052f1dedb832de0a., src=, dest=pumahbase150.snc5.facebook.com,60020,1303450731207; 70 (online=70, exclude=null) available servers
> 2011-04-25 09:11:33,413 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: Assigning region realtime_domain_imps_urls,afffffbe,1295556905482.e7a478b4bd164525052f1dedb832de0a. to pumahbase150.snc5.facebook.com,60020,1303450731207
> 2011-04-25 09:11:33,414 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: Handling transition=M_ZK_REGION_OFFLINE, server=pumahbase162.snc5.facebook.com:60000, region=e7a478b4bd164525052f1dedb832de0a
> 2011-04-25 09:11:33,416 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: Handling transition=RS_ZK_REGION_OPENING, server=pumahbase150.snc5.facebook.com,60020,1303450731207, region=e7a478b4bd164525052f1dedb832de0a
> 2011-04-25 09:11:33,825 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: Handling transition=RS_ZK_REGION_OPENING, server=pumahbase150.snc5.facebook.com,60020,1303450731207, region=e7a478b4bd164525052f1dedb832de0a
> 2011-04-25 09:11:36,804 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: Handling transition=RS_ZK_REGION_OPENED, server=pumahbase150.snc5.facebook.com,60020,1303450731207, region=e7a478b4bd164525052f1dedb832de0a
> 2011-04-25 09:11:36,804 DEBUG org.apache.hadoop.hbase.master.handler.OpenedRegionHandler: Handling OPENED event for e7a478b4bd164525052f1dedb832de0a; deleting unassigned node
> 2011-04-25 09:11:36,804 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: master:60000-0x32f7bb74e8a0000 Deleting existing unassigned node for e7a478b4bd164525052f1dedb832de0a that is in expected state RS_ZK_REGION_OPENED
> 2011-04-25 09:11:36,805 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: master:60000-0x32f7bb74e8a0000 Successfully deleted unassigned node for region e7a478b4bd164525052f1dedb832de0a in expected state RS_ZK_REGION_OPENED
> 2011-04-25 09:11:36,805 DEBUG org.apache.hadoop.hbase.master.handler.OpenedRegionHandler: Opened region realtime_domain_imps_urls,afffffbe,1295556905482.e7a478b4bd164525052f1dedb832de0a. on pumahbase150.snc5.facebook.com,60020,1303450731207
> ===
> region server log
> 2011-04-25 09:09:26,136 INFO org.apache.hadoop.hbase.regionserver.HRegionServer: Received request to open region: realtime_domain_imps_urls,afffffbe,1295556905482.e7a478b4bd164525052f1dedb832de0a.
> 2011-04-25 09:09:26,136 DEBUG org.apache.hadoop.hbase.regionserver.handler.OpenRegionHandler: Processing open of realtime_domain_imps_urls,afffffbe,1295556905482.e7a478b4bd164525052f1dedb832de0a.
> 2011-04-25 09:09:26,136 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: regionserver:60020-0x22f7bb74e8e000a Attempting to transition node e7a478b4bd164525052f1dedb832de0a from M_ZK_REGION_OFFLINE to RS_ZK_REGION_OPENING
> 2011-04-25 09:09:26,138 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: regionserver:60020-0x22f7bb74e8e000a Successfully transitioned node e7a478b4bd164525052f1dedb832de0a from M_ZK_REGION_OFFLINE to RS_ZK_REGION_OPENING
> 2011-04-25 09:09:26,139 DEBUG org.apache.hadoop.hbase.regionserver.HRegion: Opening region: REGION => {NAME => 'realtime_domain_imps_urls,afffffbe,1295556905482.e7a478b4bd164525052f1dedb832de0a.', STARTKEY => 'afffffbe', ENDKEY => 'b040ebdbf81a3750f0eaa71842ff09dagr.insomnia li 294576344998', ENCODED => e7a478b4bd164525052f1dedb832de0a, TABLE => {{NAME => 'realtime_domain_imps_urls', FAMILIES => [{NAME => 'COUNTERS_0', BLOOMFILTER => 'NONE', REPLICATION_SCOPE => '0', COMPRESSION => 'LZO', VERSIONS => '1', TTL => '2147483647', BLOCKSIZE => '16384', IN_MEMORY => 'false', BLOCKCACHE => 'true'}, {NAME => 'COUNTERS_3600', BLOOMFILTER => 'NONE', REPLICATION_SCOPE => '0', COMPRESSION => 'LZO', VERSIONS => '1', TTL => '172800', BLOCKSIZE => '16384', IN_MEMORY => 'false', BLOCKCACHE => 'true'}, {NAME => 'COUNTERS_86400', BLOOMFILTER => 'NONE', REPLICATION_SCOPE => '0', COMPRESSION => 'LZO', VERSIONS => '1', TTL => '2592000', BLOCKSIZE => '16384', IN_MEMORY => 'false', BLOCKCACHE => 'true'}]}}
> 2011-04-25 09:09:26,140 DEBUG org.apache.hadoop.hbase.regionserver.HRegion: Instantiated realtime_domain_imps_urls,afffffbe,1295556905482.e7a478b4bd164525052f1dedb832de0a.
> 2011-04-25 09:09:26,140 INFO org.apache.hadoop.hbase.regionserver.logger.HRegionLogger: HRegionLogger for region realtime_domain_imps_urls,afffffbe,1295556905482.e7a478b4bd164525052f1dedb832de0a., category nectar_titan_hbase_updates
> 2011-04-25 09:09:26,190 DEBUG org.apache.hadoop.hbase.regionserver.Store: loaded hdfs://pumahbase002-snc5-dfs.data.facebook.com:9000/PUMAHBASE002-SNC5-HBASE/realtime_domain_imps_urls/e7a478b4bd164525052f1dedb832de0a/COUNTERS_0/87cf11f68701404b862d631ba3d20213, isReference=false, isBulkLoadResult=false, seqid=58137870275, majorCompaction=false
> 2011-04-25 09:09:28,572 DEBUG org.apache.hadoop.hbase.regionserver.Store: loaded hdfs://pumahbase002-snc5-dfs.data.facebook.com:9000/PUMAHBASE002-SNC5-HBASE/realtime_domain_imps_urls/e7a478b4bd164525052f1dedb832de0a/COUNTERS_0/c58d9a33653a4e5e966c426b33a57598, isReference=false, isBulkLoadResult=false, seqid=57847795298, majorCompaction=true
> 2011-04-25 09:09:28,796 DEBUG org.apache.hadoop.hbase.regionserver.Store: loaded hdfs://pumahbase002-snc5-dfs.data.facebook.com:9000/PUMAHBASE002-SNC5-HBASE/realtime_domain_imps_urls/e7a478b4bd164525052f1dedb832de0a/COUNTERS_3600/1bc513e915b741d59d4f113c273e67d4, isReference=false, isBulkLoadResult=false, seqid=58137870275, majorCompaction=false
> 2011-04-25 09:09:28,826 DEBUG org.apache.hadoop.hbase.regionserver.Store: loaded hdfs://pumahbase002-snc5-dfs.data.facebook.com:9000/PUMAHBASE002-SNC5-HBASE/realtime_domain_imps_urls/e7a478b4bd164525052f1dedb832de0a/COUNTERS_3600/5a50b17f3ad045368229680414987ae7, isReference=false, isBulkLoadResult=false, seqid=57847795298, majorCompaction=true
> 2011-04-25 09:09:28,850 DEBUG org.apache.hadoop.hbase.regionserver.Store: loaded hdfs://pumahbase002-snc5-dfs.data.facebook.com:9000/PUMAHBASE002-SNC5-HBASE/realtime_domain_imps_urls/e7a478b4bd164525052f1dedb832de0a/COUNTERS_86400/23648dce8d4243c5b804c0e766f5a235, isReference=false, isBulkLoadResult=false, seqid=58137870275, majorCompaction=false
> 2011-04-25 09:09:29,016 DEBUG org.apache.hadoop.hbase.regionserver.Store: loaded hdfs://pumahbase002-snc5-dfs.data.facebook.com:9000/PUMAHBASE002-SNC5-HBASE/realtime_domain_imps_urls/e7a478b4bd164525052f1dedb832de0a/COUNTERS_86400/d6820d86715049c087fa5c3f4355f2fc, isReference=false, isBulkLoadResult=false, seqid=57847795298, majorCompaction=true
> 2011-04-25 09:09:29,017 INFO org.apache.hadoop.hbase.regionserver.HRegion: Replaying edits from hdfs://pumahbase002-snc5-dfs.data.facebook.com:9000/PUMAHBASE002-SNC5-HBASE/realtime_domain_imps_urls/e7a478b4bd164525052f1dedb832de0a/recovered.edits/0000000057528037047; minSequenceid=58137870275
> 2011-04-25 09:09:44,041 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: regionserver:60020-0x22f7bb74e8e000a Attempting to transition node e7a478b4bd164525052f1dedb832de0a from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENING
> 2011-04-25 09:09:44,044 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: regionserver:60020-0x22f7bb74e8e000a Successfully transitioned node e7a478b4bd164525052f1dedb832de0a from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENING
> 2011-04-25 09:09:59,046 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: regionserver:60020-0x22f7bb74e8e000a Attempting to transition node e7a478b4bd164525052f1dedb832de0a from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENING
> 2011-04-25 09:09:59,050 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: regionserver:60020-0x22f7bb74e8e000a Successfully transitioned node e7a478b4bd164525052f1dedb832de0a from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENING
> 2011-04-25 09:10:14,050 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: regionserver:60020-0x22f7bb74e8e000a Attempting to transition node e7a478b4bd164525052f1dedb832de0a from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENING
> 832de0a from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENING
> 2011-04-25 09:10:29,055 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: regionserver:60020-0x22f7bb74e8e000a Successfully transitioned node e7a478b4bd164525052f1dedb832de0a from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENING
> 2011-04-25 09:10:44,056 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: regionserver:60020-0x22f7bb74e8e000a Attempting to transition node e7a478b4bd164525052f1dedb832de0a from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENING
> 2011-04-25 09:10:44,059 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: regionserver:60020-0x22f7bb74e8e000a Successfully transitioned node e7a478b4bd164525052f1dedb832de0a from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENING
> 2011-04-25 09:10:59,057 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: regionserver:60020-0x22f7bb74e8e000a Attempting to transition node e7a478b4bd164525052f1dedb832de0a from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENING
> 2011-04-25 09:10:59,062 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: regionserver:60020-0x22f7bb74e8e000a Successfully transitioned node e7a478b4bd164525052f1dedb832de0a from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENING
> 2011-04-25 09:10:59,154 DEBUG org.apache.hadoop.hbase.regionserver.HRegion: Started memstore flush for realtime_domain_imps_urls,afffffbe,1295556905482.e7a478b4bd164525052f1dedb832de0a., current region memstore size 18.9m; wal is null, using passed sequenceid=58140219688
> 2011-04-25 09:10:59,277 INFO org.apache.hadoop.hbase.regionserver.Store: Flushed , sequenceid=58140219688, memsize=12.4m, into tmp file hdfs://pumahbase002-snc5-dfs.data.facebook.com:9000/PUMAHBASE002-SNC5-HBASE/realtime_domain_imps_urls/e7a478b4bd164525052f1dedb832de0a/.tmp/a1df4f1ac37a4c7fbf4067f3bcff49a5
> 2011-04-25 09:10:59,312 INFO org.apache.hadoop.hbase.regionserver.Store: Flushed , sequenceid=58140219688, memsize=3.2m, into tmp file hdfs://pumahbase002-snc5-dfs.data.facebook.com:9000/PUMAHBASE002-SNC5-HBASE/realtime_domain_imps_urls/e7a478b4bd164525052f1dedb832de0a/.tmp/eefd1540ca644f06b251201894ef5dd8
> 2011-04-25 09:10:59,357 INFO org.apache.hadoop.hbase.regionserver.Store: Flushed , sequenceid=58140219688, memsize=3.2m, into tmp file hdfs://pumahbase002-snc5-dfs.data.facebook.com:9000/PUMAHBASE002-SNC5-HBASE/realtime_domain_imps_urls/e7a478b4bd164525052f1dedb832de0a/.tmp/83c87fcdbf7147ceac873a1e97e2990f
> 2011-04-25 09:10:59,357 INFO org.apache.hadoop.hbase.regionserver.Store: Renaming flushed file at hdfs://pumahbase002-snc5-dfs.data.facebook.com:9000/PUMAHBASE002-SNC5-HBASE/realtime_domain_imps_urls/e7a478b4bd164525052f1dedb832de0a/.tmp/a1df4f1ac37a4c7fbf4067f3bcff49a5 to hdfs://pumahbase002-snc5-dfs.data.facebook.com:9000/PUMAHBASE002-SNC5-HBASE/realtime_domain_imps_urls/e7a478b4bd164525052f1dedb832de0a/COUNTERS_0/a1df4f1ac37a4c7fbf4067f3bcff49a5
> 2011-04-25 09:10:59,372 INFO org.apache.hadoop.hbase.regionserver.Store: Added hdfs://pumahbase002-snc5-dfs.data.facebook.com:9000/PUMAHBASE002-SNC5-HBASE/realtime_domain_imps_urls/e7a478b4bd164525052f1dedb832de0a/COUNTERS_0/a1df4f1ac37a4c7fbf4067f3bcff49a5, entries=45626, sequenceid=58140219688, filesize=549.1k
> 2011-04-25 09:10:59,372 INFO org.apache.hadoop.hbase.regionserver.Store: Renaming flushed file at hdfs://pumahbase002-snc5-dfs.data.facebook.com:9000/PUMAHBASE002-SNC5-HBASE/realtime_domain_imps_urls/e7a478b4bd164525052f1dedb832de0a/.tmp/eefd1540ca644f06b251201894ef5dd8 to hdfs://pumahbase002-snc5-dfs.data.facebook.com:9000/PUMAHBASE002-SNC5-HBASE/realtime_domain_imps_urls/e7a478b4bd164525052f1dedb832de0a/COUNTERS_3600/eefd1540ca644f06b251201894ef5dd8
> 2011-04-25 09:10:59,375 INFO org.apache.hadoop.hbase.regionserver.Store: Added hdfs://pumahbase002-snc5-dfs.data.facebook.com:9000/PUMAHBASE002-SNC5-HBASE/realtime_domain_imps_urls/e7a478b4bd164525052f1dedb832de0a/COUNTERS_3600/eefd1540ca644f06b251201894ef5dd8, entries=11411, sequenceid=58140219688, filesize=167.9k
> 2011-04-25 09:10:59,375 INFO org.apache.hadoop.hbase.regionserver.Store: Renaming flushed file at hdfs://pumahbase002-snc5-dfs.data.facebook.com:9000/PUMAHBASE002-SNC5-HBASE/realtime_domain_imps_urls/e7a478b4bd164525052f1dedb832de0a/.tmp/83c87fcdbf7147ceac873a1e97e2990f to hdfs://pumahbase002-snc5-dfs.data.facebook.com:9000/PUMAHBASE002-SNC5-HBASE/realtime_domain_imps_urls/e7a478b4bd164525052f1dedb832de0a/COUNTERS_86400/83c87fcdbf7147ceac873a1e97e2990f
> 2011-04-25 09:10:59,378 INFO org.apache.hadoop.hbase.regionserver.Store: Added hdfs://pumahbase002-snc5-dfs.data.facebook.com:9000/PUMAHBASE002-SNC5-HBASE/realtime_domain_imps_urls/e7a478b4bd164525052f1dedb832de0a/COUNTERS_86400/83c87fcdbf7147ceac873a1e97e2990f, entries=11404, sequenceid=58140219688, filesize=161.5k
> 2011-04-25 09:10:59,378 INFO org.apache.hadoop.hbase.regionserver.HRegion: Finished memstore flush of ~18.9m for region realtime_domain_imps_urls,afffffbe,1295556905482.e7a478b4bd164525052f1dedb832de0a. in 224ms, sequenceid=58140219688, compaction requested=true; wal=null
> 2011-04-25 09:10:59,385 DEBUG org.apache.hadoop.hbase.regionserver.HRegion: Deleted recovered.edits file=hdfs://pumahbase002-snc5-dfs.data.facebook.com:9000/PUMAHBASE002-SNC5-HBASE/realtime_domain_imps_urls/e7a478b4bd164525052f1dedb832de0a/recovered.edits/0000000057528037047
> 2011-04-25 09:10:59,385 INFO org.apache.hadoop.hbase.regionserver.HRegion: Onlined realtime_domain_imps_urls,afffffbe,1295556905482.e7a478b4bd164525052f1dedb832de0a.; next sequenceid=58140219689
> 2011-04-25 09:10:59,385 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: regionserver:60020-0x22f7bb74e8e000a Attempting to transition node e7a478b4bd164525052f1dedb832de0a from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENING
> 2011-04-25 09:10:59,388 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: regionserver:60020-0x22f7bb74e8e000a Successfully transitioned node e7a478b4bd164525052f1dedb832de0a from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENING
> 2011-04-25 09:11:36,843 INFO org.apache.hadoop.hbase.catalog.MetaEditor: Updated row realtime_domain_imps_urls,afffffbe,1295556905482.e7a478b4bd164525052f1dedb832de0a. in region .META.,,1 with server=pumahbase107.snc5.facebook.com:60020, startcode=1303450731227
> 2011-04-25 09:11:36,843 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: regionserver:60020-0x22f7bb74e8e000a Attempting to transition node e7a478b4bd164525052f1dedb832de0a from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENED
> java.lang.NullPointerException
> ===
--
This message is automatically generated by JIRA.
For more information on JIRA, see: http://www.atlassian.com/software/jira
[jira] [Resolved] (HBASE-3824) region server timed out during open
region
Posted by "Prakash Khemani (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/HBASE-3824?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Prakash Khemani resolved HBASE-3824.
------------------------------------
Resolution: Not A Problem
> region server timed out during open region
> ------------------------------------------
>
> Key: HBASE-3824
> URL: https://issues.apache.org/jira/browse/HBASE-3824
> Project: HBase
> Issue Type: Bug
> Reporter: Prakash Khemani
>
> When replaying a large log file, mestore flushes can happen. But there is no Progressible report being sent during memstore flushes. That can lead to master timing out the region server during region open.
> ===
> Another related issue and Jonathan's response
> > So if a region server that is handed a region for opening and has done part of
> > the work ... it has created some HFiles (because the logs were so huge that
> > the mestore got flushed while the logs were being replayed) ... and then it is
> > asked to give up because the master thought the region server was taking
> > too long to open the region.
> >
> > When the region server gives up on the region then will it make sure that it
> > removes all the HFiles it had created for that region?
> Will need to check the code, but would it matter? One issue is whether it cleans up after itself (I'm guessing not). Another issue is whether the replay is idempotent (duplicate KVs across files shouldn't matter in most cases).
> ===
> 2011-04-25 09:11:36,844 ERROR org.apache.hadoop.hbase.executor.EventHandler: Caught throwable while processing event M_RS_OPEN_REGION
> java.lang.NullPointerException
> at org.apache.hadoop.hbase.util.Writables.getWritable(Writables.java:75)
> at org.apache.hadoop.hbase.executor.RegionTransitionData.fromBytes(RegionTransitionData.java:198)
> at org.apache.hadoop.hbase.zookeeper.ZKAssign.transitionNode(ZKAssign.java:672)
> at org.apache.hadoop.hbase.zookeeper.ZKAssign.transitionNodeOpened(ZKAssign.java:621)
> at org.apache.hadoop.hbase.regionserver.handler.OpenRegionHandler.process(OpenRegionHandler.java:168)
> at org.apache.hadoop.hbase.executor.EventHandler.run(EventHandler.java:151)
> at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
> at java.lang.Thread.run(Thread.java:619)
> byte [] existingBytes =
> ZKUtil.getDataNoWatch(zkw, node, stat);
> RegionTransitionData existingData =
> RegionTransitionData.fromBytes(existingBytes);
> existingBytes can be null. have to return -1 if null.
> ===
> master logs
> 2011-04-25 05:24:03,250 DEBUG org.apache.hadoop.hbase.regionserver.wal.HLogSplitter: Creating writer path=hdfs://pumahbase002-snc5-dfs.data.facebook.com:9000/PUMAHBASE002-SNC5-HBASE/realtime_domain_imps_urls/e7a478b4bd164525052f1dedb832de0a/recovered.edits/0000000057528037047 region=e7a478b4bd164525052f1dedb832de0a
> 2011-04-25 09:09:19,246 INFO org.apache.hadoop.hbase.regionserver.wal.HLogSplitter: Closed path hdfs://pumahbase002-snc5-dfs.data.facebook.com:9000/PUMAHBASE002-SNC5-HBASE/realtime_domain_imps_urls/e7a478b4bd164525052f1dedb832de0a/recovered.edits/0000000057528037047 (wrote 4342690 edits in 46904ms)
> 2011-04-25 09:09:26,134 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: master:60000-0x32f7bb74e8a0000 Creating (or updating) unassigned node for e7a478b4bd164525052f1dedb832de0a with OFFLINE state
> 2011-04-25 09:09:26,136 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: No previous transition plan was found (or we are ignoring an existing plan) for realtime_domain_imps_urls,afffffbe,1295556905482.e7a478b4bd164525052f1dedb832de0a. so generated a random one; hri=realtime_domain_imps_urls,afffffbe,1295556905482.e7a478b4bd164525052f1dedb832de0a., src=, dest=pumahbase107.snc5.facebook.com,60020,1303450731227; 70 (online=70, exclude=null) available servers
> 2011-04-25 09:09:26,136 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: Assigning region realtime_domain_imps_urls,afffffbe,1295556905482.e7a478b4bd164525052f1dedb832de0a. to pumahbase107.snc5.facebook.com,60020,1303450731227
> 2011-04-25 09:09:26,139 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: Handling transition=RS_ZK_REGION_OPENING, server=pumahbase107.snc5.facebook.com,60020,1303450731227, region=e7a478b4bd164525052f1dedb832de0a
> 2011-04-25 09:09:44,045 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: Handling transition=RS_ZK_REGION_OPENING, server=pumahbase107.snc5.facebook.com,60020,1303450731227, region=e7a478b4bd164525052f1dedb832de0a
> 2011-04-25 09:09:59,050 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: Handling transition=RS_ZK_REGION_OPENING, server=pumahbase107.snc5.facebook.com,60020,1303450731227, region=e7a478b4bd164525052f1dedb832de0a
> 2011-04-25 09:10:14,054 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: Handling transition=RS_ZK_REGION_OPENING, server=pumahbase107.snc5.facebook.com,60020,1303450731227, region=e7a478b4bd164525052f1dedb832de0a
> 2011-04-25 09:10:29,055 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: Handling transition=RS_ZK_REGION_OPENING, server=pumahbase107.snc5.facebook.com,60020,1303450731227, region=e7a478b4bd164525052f1dedb832de0a
> 2011-04-25 09:10:44,060 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: Handling transition=RS_ZK_REGION_OPENING, server=pumahbase107.snc5.facebook.com,60020,1303450731227, region=e7a478b4bd164525052f1dedb832de0a
> 2011-04-25 09:10:59,062 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: Handling transition=RS_ZK_REGION_OPENING, server=pumahbase107.snc5.facebook.com,60020,1303450731227, region=e7a478b4bd164525052f1dedb832de0a
> 2011-04-25 09:10:59,388 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: Handling transition=RS_ZK_REGION_OPENING, server=pumahbase107.snc5.facebook.com,60020,1303450731227, region=e7a478b4bd164525052f1dedb832de0a
> 2011-04-25 09:11:33,411 INFO org.apache.hadoop.hbase.master.AssignmentManager: Regions in transition timed out: realtime_domain_imps_urls,afffffbe,1295556905482.e7a478b4bd164525052f1dedb832de0a. state=OPENING, ts=1303747859386
> 2011-04-25 09:11:33,411 INFO org.apache.hadoop.hbase.master.AssignmentManager: Region has been OPENING for too long, reassigning region=realtime_domain_imps_urls,afffffbe,1295556905482.e7a478b4bd164525052f1dedb832de0a.
> 2011-04-25 09:11:33,412 INFO org.apache.hadoop.hbase.master.AssignmentManager: Successfully transitioned region=realtime_domain_imps_urls,afffffbe,1295556905482.e7a478b4bd164525052f1dedb832de0a. into OFFLINE and forcing a new assignment
> 2011-04-25 09:11:33,412 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: No previous transition plan was found (or we are ignoring an existing plan) for realtime_domain_imps_urls,afffffbe,1295556905482.e7a478b4bd164525052f1dedb832de0a. so generated a random one; hri=realtime_domain_imps_urls,afffffbe,1295556905482.e7a478b4bd164525052f1dedb832de0a., src=, dest=pumahbase150.snc5.facebook.com,60020,1303450731207; 70 (online=70, exclude=null) available servers
> 2011-04-25 09:11:33,413 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: Assigning region realtime_domain_imps_urls,afffffbe,1295556905482.e7a478b4bd164525052f1dedb832de0a. to pumahbase150.snc5.facebook.com,60020,1303450731207
> 2011-04-25 09:11:33,414 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: Handling transition=M_ZK_REGION_OFFLINE, server=pumahbase162.snc5.facebook.com:60000, region=e7a478b4bd164525052f1dedb832de0a
> 2011-04-25 09:11:33,416 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: Handling transition=RS_ZK_REGION_OPENING, server=pumahbase150.snc5.facebook.com,60020,1303450731207, region=e7a478b4bd164525052f1dedb832de0a
> 2011-04-25 09:11:33,825 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: Handling transition=RS_ZK_REGION_OPENING, server=pumahbase150.snc5.facebook.com,60020,1303450731207, region=e7a478b4bd164525052f1dedb832de0a
> 2011-04-25 09:11:36,804 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: Handling transition=RS_ZK_REGION_OPENED, server=pumahbase150.snc5.facebook.com,60020,1303450731207, region=e7a478b4bd164525052f1dedb832de0a
> 2011-04-25 09:11:36,804 DEBUG org.apache.hadoop.hbase.master.handler.OpenedRegionHandler: Handling OPENED event for e7a478b4bd164525052f1dedb832de0a; deleting unassigned node
> 2011-04-25 09:11:36,804 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: master:60000-0x32f7bb74e8a0000 Deleting existing unassigned node for e7a478b4bd164525052f1dedb832de0a that is in expected state RS_ZK_REGION_OPENED
> 2011-04-25 09:11:36,805 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: master:60000-0x32f7bb74e8a0000 Successfully deleted unassigned node for region e7a478b4bd164525052f1dedb832de0a in expected state RS_ZK_REGION_OPENED
> 2011-04-25 09:11:36,805 DEBUG org.apache.hadoop.hbase.master.handler.OpenedRegionHandler: Opened region realtime_domain_imps_urls,afffffbe,1295556905482.e7a478b4bd164525052f1dedb832de0a. on pumahbase150.snc5.facebook.com,60020,1303450731207
> ===
> region server log
> 2011-04-25 09:09:26,136 INFO org.apache.hadoop.hbase.regionserver.HRegionServer: Received request to open region: realtime_domain_imps_urls,afffffbe,1295556905482.e7a478b4bd164525052f1dedb832de0a.
> 2011-04-25 09:09:26,136 DEBUG org.apache.hadoop.hbase.regionserver.handler.OpenRegionHandler: Processing open of realtime_domain_imps_urls,afffffbe,1295556905482.e7a478b4bd164525052f1dedb832de0a.
> 2011-04-25 09:09:26,136 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: regionserver:60020-0x22f7bb74e8e000a Attempting to transition node e7a478b4bd164525052f1dedb832de0a from M_ZK_REGION_OFFLINE to RS_ZK_REGION_OPENING
> 2011-04-25 09:09:26,138 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: regionserver:60020-0x22f7bb74e8e000a Successfully transitioned node e7a478b4bd164525052f1dedb832de0a from M_ZK_REGION_OFFLINE to RS_ZK_REGION_OPENING
> 2011-04-25 09:09:26,139 DEBUG org.apache.hadoop.hbase.regionserver.HRegion: Opening region: REGION => {NAME => 'realtime_domain_imps_urls,afffffbe,1295556905482.e7a478b4bd164525052f1dedb832de0a.', STARTKEY => 'afffffbe', ENDKEY => 'b040ebdbf81a3750f0eaa71842ff09dagr.insomnia li 294576344998', ENCODED => e7a478b4bd164525052f1dedb832de0a, TABLE => {{NAME => 'realtime_domain_imps_urls', FAMILIES => [{NAME => 'COUNTERS_0', BLOOMFILTER => 'NONE', REPLICATION_SCOPE => '0', COMPRESSION => 'LZO', VERSIONS => '1', TTL => '2147483647', BLOCKSIZE => '16384', IN_MEMORY => 'false', BLOCKCACHE => 'true'}, {NAME => 'COUNTERS_3600', BLOOMFILTER => 'NONE', REPLICATION_SCOPE => '0', COMPRESSION => 'LZO', VERSIONS => '1', TTL => '172800', BLOCKSIZE => '16384', IN_MEMORY => 'false', BLOCKCACHE => 'true'}, {NAME => 'COUNTERS_86400', BLOOMFILTER => 'NONE', REPLICATION_SCOPE => '0', COMPRESSION => 'LZO', VERSIONS => '1', TTL => '2592000', BLOCKSIZE => '16384', IN_MEMORY => 'false', BLOCKCACHE => 'true'}]}}
> 2011-04-25 09:09:26,140 DEBUG org.apache.hadoop.hbase.regionserver.HRegion: Instantiated realtime_domain_imps_urls,afffffbe,1295556905482.e7a478b4bd164525052f1dedb832de0a.
> 2011-04-25 09:09:26,140 INFO org.apache.hadoop.hbase.regionserver.logger.HRegionLogger: HRegionLogger for region realtime_domain_imps_urls,afffffbe,1295556905482.e7a478b4bd164525052f1dedb832de0a., category nectar_titan_hbase_updates
> 2011-04-25 09:09:26,190 DEBUG org.apache.hadoop.hbase.regionserver.Store: loaded hdfs://pumahbase002-snc5-dfs.data.facebook.com:9000/PUMAHBASE002-SNC5-HBASE/realtime_domain_imps_urls/e7a478b4bd164525052f1dedb832de0a/COUNTERS_0/87cf11f68701404b862d631ba3d20213, isReference=false, isBulkLoadResult=false, seqid=58137870275, majorCompaction=false
> 2011-04-25 09:09:28,572 DEBUG org.apache.hadoop.hbase.regionserver.Store: loaded hdfs://pumahbase002-snc5-dfs.data.facebook.com:9000/PUMAHBASE002-SNC5-HBASE/realtime_domain_imps_urls/e7a478b4bd164525052f1dedb832de0a/COUNTERS_0/c58d9a33653a4e5e966c426b33a57598, isReference=false, isBulkLoadResult=false, seqid=57847795298, majorCompaction=true
> 2011-04-25 09:09:28,796 DEBUG org.apache.hadoop.hbase.regionserver.Store: loaded hdfs://pumahbase002-snc5-dfs.data.facebook.com:9000/PUMAHBASE002-SNC5-HBASE/realtime_domain_imps_urls/e7a478b4bd164525052f1dedb832de0a/COUNTERS_3600/1bc513e915b741d59d4f113c273e67d4, isReference=false, isBulkLoadResult=false, seqid=58137870275, majorCompaction=false
> 2011-04-25 09:09:28,826 DEBUG org.apache.hadoop.hbase.regionserver.Store: loaded hdfs://pumahbase002-snc5-dfs.data.facebook.com:9000/PUMAHBASE002-SNC5-HBASE/realtime_domain_imps_urls/e7a478b4bd164525052f1dedb832de0a/COUNTERS_3600/5a50b17f3ad045368229680414987ae7, isReference=false, isBulkLoadResult=false, seqid=57847795298, majorCompaction=true
> 2011-04-25 09:09:28,850 DEBUG org.apache.hadoop.hbase.regionserver.Store: loaded hdfs://pumahbase002-snc5-dfs.data.facebook.com:9000/PUMAHBASE002-SNC5-HBASE/realtime_domain_imps_urls/e7a478b4bd164525052f1dedb832de0a/COUNTERS_86400/23648dce8d4243c5b804c0e766f5a235, isReference=false, isBulkLoadResult=false, seqid=58137870275, majorCompaction=false
> 2011-04-25 09:09:29,016 DEBUG org.apache.hadoop.hbase.regionserver.Store: loaded hdfs://pumahbase002-snc5-dfs.data.facebook.com:9000/PUMAHBASE002-SNC5-HBASE/realtime_domain_imps_urls/e7a478b4bd164525052f1dedb832de0a/COUNTERS_86400/d6820d86715049c087fa5c3f4355f2fc, isReference=false, isBulkLoadResult=false, seqid=57847795298, majorCompaction=true
> 2011-04-25 09:09:29,017 INFO org.apache.hadoop.hbase.regionserver.HRegion: Replaying edits from hdfs://pumahbase002-snc5-dfs.data.facebook.com:9000/PUMAHBASE002-SNC5-HBASE/realtime_domain_imps_urls/e7a478b4bd164525052f1dedb832de0a/recovered.edits/0000000057528037047; minSequenceid=58137870275
> 2011-04-25 09:09:44,041 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: regionserver:60020-0x22f7bb74e8e000a Attempting to transition node e7a478b4bd164525052f1dedb832de0a from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENING
> 2011-04-25 09:09:44,044 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: regionserver:60020-0x22f7bb74e8e000a Successfully transitioned node e7a478b4bd164525052f1dedb832de0a from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENING
> 2011-04-25 09:09:59,046 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: regionserver:60020-0x22f7bb74e8e000a Attempting to transition node e7a478b4bd164525052f1dedb832de0a from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENING
> 2011-04-25 09:09:59,050 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: regionserver:60020-0x22f7bb74e8e000a Successfully transitioned node e7a478b4bd164525052f1dedb832de0a from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENING
> 2011-04-25 09:10:14,050 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: regionserver:60020-0x22f7bb74e8e000a Attempting to transition node e7a478b4bd164525052f1dedb832de0a from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENING
> 832de0a from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENING
> 2011-04-25 09:10:29,055 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: regionserver:60020-0x22f7bb74e8e000a Successfully transitioned node e7a478b4bd164525052f1dedb832de0a from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENING
> 2011-04-25 09:10:44,056 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: regionserver:60020-0x22f7bb74e8e000a Attempting to transition node e7a478b4bd164525052f1dedb832de0a from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENING
> 2011-04-25 09:10:44,059 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: regionserver:60020-0x22f7bb74e8e000a Successfully transitioned node e7a478b4bd164525052f1dedb832de0a from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENING
> 2011-04-25 09:10:59,057 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: regionserver:60020-0x22f7bb74e8e000a Attempting to transition node e7a478b4bd164525052f1dedb832de0a from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENING
> 2011-04-25 09:10:59,062 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: regionserver:60020-0x22f7bb74e8e000a Successfully transitioned node e7a478b4bd164525052f1dedb832de0a from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENING
> 2011-04-25 09:10:59,154 DEBUG org.apache.hadoop.hbase.regionserver.HRegion: Started memstore flush for realtime_domain_imps_urls,afffffbe,1295556905482.e7a478b4bd164525052f1dedb832de0a., current region memstore size 18.9m; wal is null, using passed sequenceid=58140219688
> 2011-04-25 09:10:59,277 INFO org.apache.hadoop.hbase.regionserver.Store: Flushed , sequenceid=58140219688, memsize=12.4m, into tmp file hdfs://pumahbase002-snc5-dfs.data.facebook.com:9000/PUMAHBASE002-SNC5-HBASE/realtime_domain_imps_urls/e7a478b4bd164525052f1dedb832de0a/.tmp/a1df4f1ac37a4c7fbf4067f3bcff49a5
> 2011-04-25 09:10:59,312 INFO org.apache.hadoop.hbase.regionserver.Store: Flushed , sequenceid=58140219688, memsize=3.2m, into tmp file hdfs://pumahbase002-snc5-dfs.data.facebook.com:9000/PUMAHBASE002-SNC5-HBASE/realtime_domain_imps_urls/e7a478b4bd164525052f1dedb832de0a/.tmp/eefd1540ca644f06b251201894ef5dd8
> 2011-04-25 09:10:59,357 INFO org.apache.hadoop.hbase.regionserver.Store: Flushed , sequenceid=58140219688, memsize=3.2m, into tmp file hdfs://pumahbase002-snc5-dfs.data.facebook.com:9000/PUMAHBASE002-SNC5-HBASE/realtime_domain_imps_urls/e7a478b4bd164525052f1dedb832de0a/.tmp/83c87fcdbf7147ceac873a1e97e2990f
> 2011-04-25 09:10:59,357 INFO org.apache.hadoop.hbase.regionserver.Store: Renaming flushed file at hdfs://pumahbase002-snc5-dfs.data.facebook.com:9000/PUMAHBASE002-SNC5-HBASE/realtime_domain_imps_urls/e7a478b4bd164525052f1dedb832de0a/.tmp/a1df4f1ac37a4c7fbf4067f3bcff49a5 to hdfs://pumahbase002-snc5-dfs.data.facebook.com:9000/PUMAHBASE002-SNC5-HBASE/realtime_domain_imps_urls/e7a478b4bd164525052f1dedb832de0a/COUNTERS_0/a1df4f1ac37a4c7fbf4067f3bcff49a5
> 2011-04-25 09:10:59,372 INFO org.apache.hadoop.hbase.regionserver.Store: Added hdfs://pumahbase002-snc5-dfs.data.facebook.com:9000/PUMAHBASE002-SNC5-HBASE/realtime_domain_imps_urls/e7a478b4bd164525052f1dedb832de0a/COUNTERS_0/a1df4f1ac37a4c7fbf4067f3bcff49a5, entries=45626, sequenceid=58140219688, filesize=549.1k
> 2011-04-25 09:10:59,372 INFO org.apache.hadoop.hbase.regionserver.Store: Renaming flushed file at hdfs://pumahbase002-snc5-dfs.data.facebook.com:9000/PUMAHBASE002-SNC5-HBASE/realtime_domain_imps_urls/e7a478b4bd164525052f1dedb832de0a/.tmp/eefd1540ca644f06b251201894ef5dd8 to hdfs://pumahbase002-snc5-dfs.data.facebook.com:9000/PUMAHBASE002-SNC5-HBASE/realtime_domain_imps_urls/e7a478b4bd164525052f1dedb832de0a/COUNTERS_3600/eefd1540ca644f06b251201894ef5dd8
> 2011-04-25 09:10:59,375 INFO org.apache.hadoop.hbase.regionserver.Store: Added hdfs://pumahbase002-snc5-dfs.data.facebook.com:9000/PUMAHBASE002-SNC5-HBASE/realtime_domain_imps_urls/e7a478b4bd164525052f1dedb832de0a/COUNTERS_3600/eefd1540ca644f06b251201894ef5dd8, entries=11411, sequenceid=58140219688, filesize=167.9k
> 2011-04-25 09:10:59,375 INFO org.apache.hadoop.hbase.regionserver.Store: Renaming flushed file at hdfs://pumahbase002-snc5-dfs.data.facebook.com:9000/PUMAHBASE002-SNC5-HBASE/realtime_domain_imps_urls/e7a478b4bd164525052f1dedb832de0a/.tmp/83c87fcdbf7147ceac873a1e97e2990f to hdfs://pumahbase002-snc5-dfs.data.facebook.com:9000/PUMAHBASE002-SNC5-HBASE/realtime_domain_imps_urls/e7a478b4bd164525052f1dedb832de0a/COUNTERS_86400/83c87fcdbf7147ceac873a1e97e2990f
> 2011-04-25 09:10:59,378 INFO org.apache.hadoop.hbase.regionserver.Store: Added hdfs://pumahbase002-snc5-dfs.data.facebook.com:9000/PUMAHBASE002-SNC5-HBASE/realtime_domain_imps_urls/e7a478b4bd164525052f1dedb832de0a/COUNTERS_86400/83c87fcdbf7147ceac873a1e97e2990f, entries=11404, sequenceid=58140219688, filesize=161.5k
> 2011-04-25 09:10:59,378 INFO org.apache.hadoop.hbase.regionserver.HRegion: Finished memstore flush of ~18.9m for region realtime_domain_imps_urls,afffffbe,1295556905482.e7a478b4bd164525052f1dedb832de0a. in 224ms, sequenceid=58140219688, compaction requested=true; wal=null
> 2011-04-25 09:10:59,385 DEBUG org.apache.hadoop.hbase.regionserver.HRegion: Deleted recovered.edits file=hdfs://pumahbase002-snc5-dfs.data.facebook.com:9000/PUMAHBASE002-SNC5-HBASE/realtime_domain_imps_urls/e7a478b4bd164525052f1dedb832de0a/recovered.edits/0000000057528037047
> 2011-04-25 09:10:59,385 INFO org.apache.hadoop.hbase.regionserver.HRegion: Onlined realtime_domain_imps_urls,afffffbe,1295556905482.e7a478b4bd164525052f1dedb832de0a.; next sequenceid=58140219689
> 2011-04-25 09:10:59,385 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: regionserver:60020-0x22f7bb74e8e000a Attempting to transition node e7a478b4bd164525052f1dedb832de0a from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENING
> 2011-04-25 09:10:59,388 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: regionserver:60020-0x22f7bb74e8e000a Successfully transitioned node e7a478b4bd164525052f1dedb832de0a from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENING
> 2011-04-25 09:11:36,843 INFO org.apache.hadoop.hbase.catalog.MetaEditor: Updated row realtime_domain_imps_urls,afffffbe,1295556905482.e7a478b4bd164525052f1dedb832de0a. in region .META.,,1 with server=pumahbase107.snc5.facebook.com:60020, startcode=1303450731227
> 2011-04-25 09:11:36,843 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: regionserver:60020-0x22f7bb74e8e000a Attempting to transition node e7a478b4bd164525052f1dedb832de0a from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENED
> java.lang.NullPointerException
> ===
--
This message is automatically generated by JIRA.
For more information on JIRA, see: http://www.atlassian.com/software/jira