Return-Path: X-Original-To: apmail-hbase-user-archive@www.apache.org Delivered-To: apmail-hbase-user-archive@www.apache.org Received: from mail.apache.org (hermes.apache.org [140.211.11.3]) by minotaur.apache.org (Postfix) with SMTP id 221E8D547 for ; Tue, 17 Jul 2012 14:02:06 +0000 (UTC) Received: (qmail 14533 invoked by uid 500); 17 Jul 2012 14:02:03 -0000 Delivered-To: apmail-hbase-user-archive@hbase.apache.org Received: (qmail 14481 invoked by uid 500); 17 Jul 2012 14:02:03 -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 14460 invoked by uid 99); 17 Jul 2012 14:02:02 -0000 Received: from athena.apache.org (HELO athena.apache.org) (140.211.11.136) by apache.org (qpsmtpd/0.29) with ESMTP; Tue, 17 Jul 2012 14:02:02 +0000 X-ASF-Spam-Status: No, hits=1.5 required=5.0 tests=FSL_RCVD_USER,HTML_MESSAGE,RCVD_IN_DNSWL_LOW,SPF_PASS X-Spam-Check-By: apache.org Received-SPF: pass (athena.apache.org: domain of rj03hou@gmail.com designates 209.85.160.41 as permitted sender) Received: from [209.85.160.41] (HELO mail-pb0-f41.google.com) (209.85.160.41) by apache.org (qpsmtpd/0.29) with ESMTP; Tue, 17 Jul 2012 14:01:56 +0000 Received: by pbbrp2 with SMTP id rp2so1083617pbb.14 for ; Tue, 17 Jul 2012 07:01:36 -0700 (PDT) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=20120113; h=mime-version:in-reply-to:references:date:message-id:subject:from:to :content-type; bh=nYG/eVtqn743HxYh7i3PyKEErsNhadx1CxXjNCoyjCM=; b=SMQyZnqmOXxZ+Rv3A7VfXMjBLn8eUgYWgrVwde3FW3EwY7UAQrc7WhU+i2d3QE47tG SyhJbAFLCjsaa7bgtI+UHGvoPc0fAZ+SKiWgYaFwrj+WR3IhTVh6Tc7quGPndRnX9Onh ynQqbWIPP4ohw28Fk2ex6YRWgllyf8d/NIiXOQiGy9KNVzJGKn8dysWk/ihWArbbcYWi kK8SZcRYUHIn0xPV8+9/igGhRZSyvB+19SZ9d6yCsk262hty5v6XGBtOa24k3HLb3Bsy S4e8UpCT47UJ/swUxpFW9IsxlKsGU9oiYlkrv0sA95zz0PtrBhjyJLPOJ5/bA95pYWMU K7jA== MIME-Version: 1.0 Received: by 10.68.226.131 with SMTP id rs3mr6697953pbc.62.1342533696009; Tue, 17 Jul 2012 07:01:36 -0700 (PDT) Received: by 10.142.149.36 with HTTP; Tue, 17 Jul 2012 07:01:35 -0700 (PDT) In-Reply-To: References: Date: Tue, 17 Jul 2012 22:01:35 +0800 Message-ID: Subject: Re: Load balancer repeatedly close and open region in the same regionserver. From: Howard To: user@hbase.apache.org Content-Type: multipart/alternative; boundary=047d7b1634230cb6ff04c506fc4c X-Virus-Checked: Checked by ClamAV on apache.org --047d7b1634230cb6ff04c506fc4c Content-Type: text/plain; charset=windows-1252 Content-Transfer-Encoding: quoted-printable *hi,Ted Yu,thanks for your reply:* the hbase and hadoop version is HBase Version0.94.0, r1332822Hadoop Version0.20.2-cdh3u1, rbdafb1dbffd0d5f2fbc6ee022e1c8df6500fd638 the following is a detail log about the same region trackurl_status_list,zO6u4o8,1342291884831.93caf5147d40f5dd4625e160e1b7e956= , and it repeats again and again.: 2012-07-16 00:12:49,843 INFO org.apache.hadoop.hbase.master.HMaster: balanc= e hri=3Dtrackurl_status_list,zO6u4o8,1342291884831.93caf5147d40f5dd4625e160e1= b7e956., src=3D192.168.1.2,60020,1342017399608, dest=3D192.168.1.2,60020,13420020825= 92 2012-07-16 00:12:49,843 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: Starting unassignment of region trackurl_status_list,zO6u4o8,1342291884831.93caf5147d40f5dd4625e160e1b7e956= . (offlining) 2012-07-16 00:12:49,843 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: master:60000-0x4384d0a47f40068 Creating unassigned node for 93caf5147d40f5dd4625e160e1b7e956 in a CLOSING state 2012-07-16 00:12:49,845 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: Sent CLOSE to 192.168.1.2,60020,1342017399608 for region trackurl_status_list,zO6u4o8,1342291884831.93caf5147d40f5dd4625e160e1b7e956= . 2012-07-16 00:12:50,555 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: Handling transition=3DRS_ZK_REGION_CLOSED, server=3D192.168.1.2,60020,1342017399608, region=3D93caf5147d40f5dd4625e160e1b7e956 2012-07-16 00:12:50,555 DEBUG org.apache.hadoop.hbase.master.handler.ClosedRegionHandler: Handling CLOSED event for 93caf5147d40f5dd4625e160e1b7e956 2012-07-16 00:12:50,555 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: Forcing OFFLINE; was=3Dtrackurl_status_list,zO6u4o8,1342291884831.93caf5147d40f5dd4625e160e1= b7e956. state=3DCLOSED, ts=3D1342368770556, server=3D192.168.1.2,60020,134201739960= 8 2012-07-16 00:12:50,555 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: master:60000-0x4384d0a47f40068 Creating (or updating) unassigned node for 93caf5147d40f5dd4625e160e1b7e956 with OFFLINE state 2012-07-16 00:12:50,558 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: Handling transition=3DM_ZK_REGION_OFFLINE, server=3D10.75.18.34,60000,1342017369575, region=3D93caf5147d40f5dd4625e160e1b7e956 2012-07-16 00:12:50,558 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: Found an existing plan for trackurl_status_list,zO6u4o8,1342291884831.93caf5147d40f5dd4625e160e1b7e956= . destination server is 192.168.1.2,60020,1342002082592 2012-07-16 00:12:50,558 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: Using pre-existing plan for region trackurl_status_list,zO6u4o8,1342291884831.93caf5147d40f5dd4625e160e1b7e956= .; plan=3Dhri=3Dtrackurl_status_list,zO6u4o8,1342291884831.93caf5147d40f5dd462= 5e160e1b7e956., src=3D192.168.1.2,60020,1342017399608, dest=3D192.168.1.2,60020,13420020825= 92 2012-07-16 00:12:50,558 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: Assigning region trackurl_status_list,zO6u4o8,1342291884831.93caf5147d40f5dd4625e160e1b7e956= . to 192.168.1.2,60020,1342002082592 2012-07-16 00:12:50,574 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: Handling transition=3DRS_ZK_REGION_OPENING, server=3D192.168.1.2,60020,1342017399608= , region=3D93caf5147d40f5dd4625e160e1b7e956 2012-07-16 00:12:50,635 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: Handling transition=3DRS_ZK_REGION_OPENING, server=3D192.168.1.2,60020,1342017399608= , region=3D93caf5147d40f5dd4625e160e1b7e956 2012-07-16 00:12:50,639 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: Handling transition=3DRS_ZK_REGION_OPENED, server=3D192.168.1.2,60020,1342017399608, region=3D93caf5147d40f5dd4625e160e1b7e956 2012-07-16 00:12:50,639 DEBUG org.apache.hadoop.hbase.master.handler.OpenedRegionHandler: Handling OPENED event for trackurl_status_list,zO6u4o8,1342291884831.93caf5147d40f5dd4625e160e1b7e956= . from 192.168.1.2,60020,1342017399608; deleting unassigned node 2012-07-16 00:12:50,640 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: master:60000-0x4384d0a47f40068 Deleting existing unassigned node for 93caf5147d40f5dd4625e160e1b7e956 that is in expected state RS_ZK_REGION_OPENED 2012-07-16 00:12:50,641 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: The znode of region trackurl_status_list,zO6u4o8,1342291884831.93caf5147d40f5dd4625e160e1b7e956= . has been deleted. 2012-07-16 00:12:50,641 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: master:60000-0x4384d0a47f40068 Successfully deleted unassigned node for region 93caf5147d40f5dd4625e160e1b7e956 in expected state RS_ZK_REGION_OPENED 2012-07-16 00:12:50,641 INFO org.apache.hadoop.hbase.master.AssignmentManager: The master has opened the region trackurl_status_list,zO6u4o8,1342291884831.93caf5147d40f5dd4625e160e1b7e956= . that was online on 192.168.1.2,60020,1342017399608 2012-07-16 00:17:49,870 INFO org.apache.hadoop.hbase.master.HMaster: balanc= e hri=3Dtrackurl_status_list,zO6u4o8,1342291884831.93caf5147d40f5dd4625e160e1= b7e956., src=3D192.168.1.2,60020,1342017399608, dest=3D192.168.1.2,60020,13420020825= 92 2012-07-16 00:17:49,870 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: Starting unassignment of region trackurl_status_list,zO6u4o8,1342291884831.93caf5147d40f5dd4625e160e1b7e956= . (offlining) 2012-07-16 00:17:49,870 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: master:60000-0x4384d0a47f40068 Creating unassigned node for 93caf5147d40f5dd4625e160e1b7e956 in a CLOSING state 2012-07-16 00:17:49,872 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: Sent CLOSE to 192.168.1.2,60020,1342017399608 for region trackurl_status_list,zO6u4o8,1342291884831.93caf5147d40f5dd4625e160e1b7e956= . 2012-07-16 00:17:50,464 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: Handling transition=3DRS_ZK_REGION_CLOSED, server=3D192.168.1.2,60020,1342017399608, region=3D93caf5147d40f5dd4625e160e1b7e956 2012-07-16 00:17:50,464 DEBUG org.apache.hadoop.hbase.master.handler.ClosedRegionHandler: Handling CLOSED event for 93caf5147d40f5dd4625e160e1b7e956 2012-07-16 00:17:50,464 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: Forcing OFFLINE; was=3Dtrackurl_status_list,zO6u4o8,1342291884831.93caf5147d40f5dd4625e160e1= b7e956. state=3DCLOSED, ts=3D1342369070465, server=3D192.168.1.2,60020,134201739960= 8 2012-07-16 00:17:50,464 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: master:60000-0x4384d0a47f40068 Creating (or updating) unassigned node for 93caf5147d40f5dd4625e160e1b7e956 with OFFLINE state 2012-07-16 00:17:50,467 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: Handling transition=3DM_ZK_REGION_OFFLINE, server=3D10.75.18.34,60000,1342017369575, region=3D93caf5147d40f5dd4625e160e1b7e956 2012-07-16 00:17:50,467 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: Found an existing plan for trackurl_status_list,zO6u4o8,1342291884831.93caf5147d40f5dd4625e160e1b7e956= . destination server is 192.168.1.2,60020,1342002082592 2012-07-16 00:17:50,467 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: Using pre-existing plan for region trackurl_status_list,zO6u4o8,1342291884831.93caf5147d40f5dd4625e160e1b7e956= .; plan=3Dhri=3Dtrackurl_status_list,zO6u4o8,1342291884831.93caf5147d40f5dd462= 5e160e1b7e956., src=3D192.168.1.2,60020,1342017399608, dest=3D192.168.1.2,60020,13420020825= 92 2012-07-16 00:17:50,467 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: Assigning region trackurl_status_list,zO6u4o8,1342291884831.93caf5147d40f5dd4625e160e1b7e956= . to 192.168.1.2,60020,1342002082592 2012-07-16 00:17:50,509 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: Handling transition=3DRS_ZK_REGION_OPENING, server=3D192.168.1.2,60020,1342017399608= , region=3D93caf5147d40f5dd4625e160e1b7e956 2012-07-16 00:17:50,761 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: Handling transition=3DRS_ZK_REGION_OPENING, server=3D192.168.1.2,60020,1342017399608= , region=3D93caf5147d40f5dd4625e160e1b7e956 2012-07-16 00:17:50,774 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: Handling transition=3DRS_ZK_REGION_OPENED, server=3D192.168.1.2,60020,1342017399608, region=3D93caf5147d40f5dd4625e160e1b7e956 2012-07-16 00:17:50,774 DEBUG org.apache.hadoop.hbase.master.handler.OpenedRegionHandler: Handling OPENED event for trackurl_status_list,zO6u4o8,1342291884831.93caf5147d40f5dd4625e160e1b7e956= . from 192.168.1.2,60020,1342017399608; deleting unassigned node 2012-07-16 00:17:50,774 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: master:60000-0x4384d0a47f40068 Deleting existing unassigned node for 93caf5147d40f5dd4625e160e1b7e956 that is in expected state RS_ZK_REGION_OPENED 2012-07-16 00:17:50,775 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: The znode of region trackurl_status_list,zO6u4o8,1342291884831.93caf5147d40f5dd4625e160e1b7e956= . has been deleted. 2012-07-16 00:17:50,775 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: master:60000-0x4384d0a47f40068 Successfully deleted unassigned node for region 93caf5147d40f5dd4625e160e1b7e956 in expected state RS_ZK_REGION_OPENED 2012-07-16 00:17:50,775 INFO org.apache.hadoop.hbase.master.AssignmentManager: The master has opened the region trackurl_status_list,zO6u4o8,1342291884831.93caf5147d40f5dd4625e160e1b7e956= . that was online on 192.168.1.2,60020,1342017399608 2012-07-16 00:22:49,916 INFO org.apache.hadoop.hbase.master.HMaster: balanc= e hri=3Dtrackurl_status_list,zO6u4o8,1342291884831.93caf5147d40f5dd4625e160e1= b7e956., src=3D192.168.1.2,60020,1342017399608, dest=3D192.168.1.2,60020,13420020825= 92 =85=85=85=85 2012/7/17 Ted Yu > Which HBase version were you using ? > > The log messages below were in very short time period. Can you provide mo= re > logs ? > > Thanks > > On Tue, Jul 17, 2012 at 5:09 AM, Howard wrote: > > > Through the master and regionserver log,I find load balancer repeatedly > > close and open region in the same regionserver(period in > > hbase.balancer.period ). > > Does this is a bug in load balancer and how can I dig into or avoid thi= s? > > The log like this: > > 2012-07-16 00:12:50,055 INFO > > org.apache.hadoop.hbase.regionserver.HRegionServer: Received request to > > open region: > > > > > trackurl_status_list,zOwMwdi,1342294447440.7608037379153932a30f4bdd6d7edf= 5d. > > 2012-07-16 00:12:50,069 INFO > > org.apache.hadoop.hbase.regionserver.HRegionServer: Received request to > > open region: > > > > > trackurl_comment_list,zO7vqv1,1342192347676.0c9036e183055ff2df93eca348aee= ada. > > 2012-07-16 00:12:50,206 INFO > > org.apache.hadoop.hbase.regionserver.HRegionServer: Received request to > > open region: > > > > > trackurl_status_list,zOzYDL9,1342294447440.47eb162f6aecffcddfa897fdbb7047= 2b. > > 2012-07-16 00:12:50,301 INFO > > org.apache.hadoop.hbase.regionserver.HRegionServer: Received request to > > open region: > > > > > trackurl_status_list,zOM1HZP,1342293292587.9af5de3db0bad0470d9b8fe6b9eadf= 14. > > 2012-07-16 00:12:50,428 INFO > > org.apache.hadoop.hbase.regionserver.HRegionServer: Received request to > > open region: > > > > > trackurl_status_list,zOPKLDi,1342293292587.f89dbfc1dad366c991eba3c2482286= 37. > > 2012-07-16 00:12:50,562 INFO > > org.apache.hadoop.hbase.regionserver.HRegionServer: Received request to > > open region: > > > > > trackurl_status_list,zO6u4o8,1342291884831.93caf5147d40f5dd4625e160e1b7e9= 56. > > 2012-07-16 00:12:50,685 INFO > > org.apache.hadoop.hbase.regionserver.HRegionServer: Received request to > > open region: > > > > > trackurl_status_list,zOIR8Tw,1342283152067.6284e9f69042266cde88a7b19071d7= 01. > > 2012-07-16 00:12:50,791 INFO > > org.apache.hadoop.hbase.regionserver.HRegionServer: Received request to > > open region: > > > > > trackurl_comment_list,zOqzaNw,1342195266309.bd8e19c1063f4f2984f9ca63365c5= 573. > > > --047d7b1634230cb6ff04c506fc4c--