hbase-user mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Ey-Chih chow <eyc...@gmail.com>
Subject Re: hbase threw NotServingRegionException
Date Mon, 23 Jul 2012 21:05:15 GMT
Thanks.  But if we do a scan on the table via the hbase shell, data in the table did show up.

Ey-Chih
 
On Jul 23, 2012, at 1:10 PM, Mohammad Tariq wrote:

> Hello sir,
> 
>     A possible reason could be, your client is contacting the given
> regionserver, and that regionserver kept on rejecting the requests.
> Are you sure your table and all regions online? Use hbck once and see
> if you find anything interesting.
> 
> Regards,
>    Mohammad Tariq
> 
> 
> On Tue, Jul 24, 2012 at 1:26 AM, Ey-Chih chow <eychih@gmail.com> wrote:
>> Sorry I pasted the wrong portion of the region server log.  The right portion should
be as follows:
>> 
>> 
>> ======================================
>> 2012-07-22T00:48:57.147-0700: [GC [ParNew: 18863K->2112K(19136K), 0.0029870 secs]
57106K->42831K(97048K) icms_dc=0 , 0.0030480 secs] [Times: user=0.01 sys=0.00, real=0.00
secs]
>> 2012-07-22T00:49:09.475-0700: [GC [ParNew: 18686K->2112K(19136K), 0.0219960 secs]
59405K->43951K(97048K) icms_dc=0 , 0.0220530 secs] [Times: user=0.15 sys=0.00, real=0.02
secs]
>> 2012-07-22T00:49:20.872-0700: [GC [ParNew: 19135K->2112K(19136K), 0.0091670 secs]
60974K->44659K(97048K) icms_dc=0 , 0.0092480 secs] [Times: user=0.06 sys=0.00, real=0.01
secs]
>> 2012-07-22T00:49:22.285-0700: [GC [ParNew: 19136K->2112K(19136K), 0.0021870 secs]
61683K->46380K(97048K) icms_dc=0 , 0.0022480 secs] [Times: user=0.01 sys=0.00, real=0.00
secs]
>> 2012-07-22T00:49:24.999-0700: [GC [ParNew: 19136K->2087K(19136K), 0.0019340 secs]
63404K->47842K(97048K) icms_dc=0 , 0.0019910 secs] [Times: user=0.01 sys=0.00, real=0.00
secs]
>> 2012-07-22T00:49:26.618-0700: [GC [ParNew: 18002K->2112K(19136K), 0.0016160 secs]
63757K->48065K(97048K) icms_dc=0 , 0.0016780 secs] [Times: user=0.01 sys=0.00, real=0.00
secs]
>> 2012-07-22T00:49:28.089-0700: [GC [ParNew: 19136K->1413K(19136K), 0.0033140 secs]
65089K->48748K(97048K) icms_dc=0 , 0.0033810 secs] [Times: user=0.01 sys=0.00, real=0.00
secs]
>> 2012-07-22T00:49:29.352-0700: [GC [ParNew: 18423K->2112K(19136K), 0.0063630 secs]
65759K->50827K(97048K) icms_dc=0 , 0.0064210 secs] [Times: user=0.05 sys=0.00, real=0.01
secs]
>> 2012-07-22T00:49:30.226-0700: [GC [ParNew: 19136K->1897K(19136K), 0.0021470 secs]
67851K->52058K(97048K) icms_dc=0 , 0.0022010 secs] [Times: user=0.01 sys=0.00, real=0.00
secs]
>> 2012-07-22T00:49:31.190-0700: [GC [ParNew: 18921K->1606K(19136K), 0.0013270 secs]
69082K->52336K(97048K) icms_dc=0 , 0.0013780 secs] [Times: user=0.01 sys=0.00, real=0.00
secs]
>> 2012-07-22T00:49:33.111-0700: [GC [ParNew: 18482K->2112K(19136K), 0.0017970 secs]
69212K->53496K(97048K) icms_dc=0 , 0.0018510 secs] [Times: user=0.01 sys=0.00, real=0.00
secs]
>> 2012-07-22T00:49:34.396-0700: [GC [ParNew: 19136K->1468K(19136K), 0.0120290 secs]
70520K->54718K(97048K) icms_dc=0 , 0.0120820 secs] [Times: user=0.07 sys=0.00, real=0.02
secs]
>> 2012-07-22T00:49:35.294-0700: [GC [ParNew: 18181K->2112K(19136K), 0.0011290 secs]
71431K->55399K(97048K) icms_dc=0 , 0.0011840 secs] [Times: user=0.01 sys=0.00, real=0.00
secs]
>> 2012-07-22T00:49:39.165-0700: [GC [ParNew: 19003K->547K(19136K), 0.0130200 secs]
72291K->55364K(97048K) icms_dc=0 , 0.0130880 secs] [Times: user=0.08 sys=0.00, real=0.02
secs]
>> 2012-07-22T00:49:40.642-0700: [GC [ParNew: 17571K->646K(19136K), 0.0006740 secs]
72388K->55463K(97048K) icms_dc=0 , 0.0007220 secs] [Times: user=0.00 sys=0.00, real=0.00
secs]
>> 2012-07-22T00:49:41.541-0700: [GC [ParNew: 17670K->2112K(19136K), 0.0104430 secs]
72487K->58179K(97048K) icms_dc=0 , 0.0105000 secs] [Times: user=0.07 sys=0.00, real=0.01
secs]
>> 2012-07-22T00:49:42.972-0700: [GC [ParNew: 19136K->868K(19136K), 0.0015360 secs]
75203K->58718K(97048K) icms_dc=0 , 0.0015880 secs] [Times: user=0.02 sys=0.00, real=0.00
secs]
>> 2012-07-22T00:49:43.355-0700: [GC [ParNew: 17892K->2112K(19136K), 0.0017450 secs]
75742K->60552K(97048K) icms_dc=0 , 0.0018070 secs] [Times: user=0.01 sys=0.00, real=0.00
secs]
>> 2012-07-22T00:49:46.711-0700: [GC [ParNew: 18900K->644K(19136K), 0.0015250 secs]
77340K->60427K(97048K) icms_dc=0 , 0.0015760 secs] [Times: user=0.01 sys=0.00, real=0.00
secs]
>> 2012-07-22T00:49:47.824-0700: [GC [ParNew: 17668K->1986K(19136K), 0.0015260 secs]
77451K->61943K(97048K) icms_dc=0 , 0.0015780 secs] [Times: user=0.00 sys=0.00, real=0.00
secs]
>> 2012-07-22T00:49:51.552-0700: [GC [ParNew: 19010K->752K(19136K), 0.0011550 secs]
78967K->60715K(97048K) icms_dc=0 , 0.0012500 secs] [Times: user=0.00 sys=0.00, real=0.00
secs]
>> 2012-07-22T00:49:58.460-0700: [GC [ParNew: 17776K->2055K(19136K), 0.0010860 secs]
77739K->62018K(97048K) icms_dc=0 , 0.0011440 secs] [Times: user=0.01 sys=0.00, real=0.00
secs]
>> 2012-07-22T00:50:03.692-0700: [GC [ParNew: 19079K->2112K(19136K), 0.0257530 secs]
79042K->63417K(97048K) icms_dc=0 , 0.0258130 secs] [Times: user=0.18 sys=0.00, real=0.02
secs]
>> 2012-07-22T00:50:07.522-0700: [GC [ParNew: 19136K->2112K(19136K), 0.0028960 secs]
80441K->67709K(97048K) icms_dc=0 , 0.0029600 secs] [Times: user=0.02 sys=0.00, real=0.00
secs]
>> 2012-07-22T00:50:30.491-0700: [GC [ParNew: 19136K->2112K(19136K), 0.0023910 secs]
84733K->70543K(97048K) icms_dc=0 , 0.0024560 secs] [Times: user=0.02 sys=0.01, real=0.00
secs]
>> 2012-07-22T00:50:39.242-0700: [GC [ParNew: 18974K->1947K(19136K), 0.0009880 secs]
87406K->70737K(97048K) icms_dc=0 , 0.0010440 secs] [Times: user=0.01 sys=0.00, real=0.00
secs]
>> 2012-07-22T00:50:51.654-0700: [GC [ParNew: 18765K->2112K(19136K), 0.0017700 secs]
87555K->71087K(97048K) icms_dc=0 , 0.0018250 secs] [Times: user=0.01 sys=0.00, real=0.00
secs]
>> 2012-07-22T00:51:01.245-0700: [GC [ParNew: 18136K->1984K(19136K), 0.0015550 secs]
87112K->70974K(97048K) icms_dc=0 , 0.0016230 secs] [Times: user=0.00 sys=0.00, real=0.00
secs]
>> 2012-07-22T00:51:03.300-0700: [GC [ParNew: 19008K->2112K(19136K), 0.0193190 secs]
87998K->73184K(97048K) icms_dc=0 , 0.0193830 secs] [Times: user=0.10 sys=0.00, real=0.01
secs]
>> 2012-07-22T00:51:08.001-0700: [GC [ParNew: 19111K->2112K(19136K), 0.0014340 secs]
90183K->73830K(97048K) icms_dc=0 , 0.0014900 secs] [Times: user=0.01 sys=0.00, real=0.00
secs]
>> 2012-07-22T00:51:10.532-0700: [GC [ParNew: 19136K->2112K(19136K), 0.0037150 secs]
90854K->76592K(97048K) icms_dc=15 , 0.0037930 secs] [Times: user=0.01 sys=0.00, real=0.00
secs]
>> ==========================================
>> 
>> 
>> On Jul 23, 2012, at 12:39 PM, Ey-Chih chow wrote:
>> 
>>> Hi,
>>> 
>>> We got a Map/Reduce job that threw NotServingRegionException when the reducer
was about to insert data into a Hbase table. The error message is as follows.  I also copied
the corresponding region server log at the end of the message.  Also, we browsed through the
hbase administrative page of the table. We couldn't see the list of Table Regions (the table
is pre-splitted.) Is there anybody who knows what's happening?  Thanks.
>>> 
>>> Ey-Chih Chow
>>> 
>>> ========= log from the map/reduce job =========================
>>> 
>>> 12:59:06 [dba@dba@h01 1-exec][INFO] 12/07/22 00:50:35 INFO mapred.JobClient:
Task Id : attempt_201206142240_19696_r_000005_0, Status : FAILED
>>> 12:59:06 [dba@dba@h01 1-exec][INFO] org.apache.hadoop.hbase.client.RetriesExhaustedWithDetailsException:
Failed 110 actions: NotServingRegionException: 110 times, servers with issues: h07.mtv.byah.net:60020,
>>> 12:59:06 [dba@dba@h01 1-exec][INFO] at org.apache.hadoop.hbase.client.HConnectionManager$HConnectionImplementation.processBatch(HConnectionManager.java:1227)
>>> 12:59:06 [dba@dba@h01 1-exec][INFO] at org.apache.hadoop.hbase.client.HConnectionManager$HConnectionImplementation.processBatchOfPuts(HConnectionManager.java:1241)
>>> 12:59:06 [dba@dba@h01 1-exec][INFO] at org.apache.hadoop.hbase.client.HTable.flushCommits(HTable.java:826)
>>> 12:59:06 [dba@dba@h01 1-exec][INFO] at org.apache.hadoop.hbase.client.HTable.doPut(HTable.java:682)
>>> 12:59:06 [dba@dba@h01 1-exec][INFO] at org.apache.hadoop.hbase.client.HTable.put(HTable.java:667)
>>> 12:59:06 [dba@dba@h01 1-exec][INFO] at org.apache.hadoop.hbase.mapreduce.TableOutputFormat$TableRecordWriter.write(TableOutputFormat.java:127)
>>> 12:59:06 [dba@dba@h01 1-exec][INFO] at org.apache.hadoop.hbase.mapreduce.TableOutputFormat$TableRecordWriter.write(TableOutputFormat.java:82)
>>> 12:59:06 [dba@dba@h01 1-exec][INFO] at com.booyah.analytics.mapreduce.AvroHbaseTableOutputFormat$AvroHbaseTableRecordWriter.write(AvroHbaseTableOutputFormat.java:75)
>>> 12:59:06 [dba@dba@h01 1-exec][INFO] at com.booyah.analytics.mapred.AdaptAvroHbaseTableOu
>>> 12:59:06 [dba@dba@h01 1-exec][INFO] attempt_201206142240_19696_r_000005_0: INFO
22-07 00:45:54,927 - Loaded the native-hadoop library
>>> 
>>> =================================================================
>>> 
>>> 
>>> 
>>> 
>>> ========log from the corresponding region server==========================
>>> 
>>> 2012-07-22T09:08:25.833-0700: [GC [ParNew: 136739K->138K(153344K), 0.0027890
secs] 316329K->179757K(1621376K) icms_dc=0 , 0.0028470 secs] [Times: user=0.03 sys=0.00,
real=0.01 secs]
>>> 2012-07-22T09:25:00.822-0700: [GC [ParNew: 136458K->82K(153344K), 0.0028930
secs] 316077K->179701K(1621376K) icms_dc=0 , 0.0029500 secs] [Times: user=0.02 sys=0.00,
real=0.00 secs]
>>> 2012-07-22T09:41:35.638-0700: [GC [ParNew: 136402K->49K(153344K), 0.0030770
secs] 316021K->179668K(1621376K) icms_dc=0 , 0.0031310 secs] [Times: user=0.02 sys=0.00,
real=0.01 secs]
>>> 2012-07-22T09:58:10.796-0700: [GC [ParNew: 136351K->44K(153344K), 0.0028190
secs] 315970K->179663K(1621376K) icms_dc=0 , 0.0028750 secs] [Times: user=0.03 sys=0.00,
real=0.01 secs]
>>> 2012-07-22T10:14:45.638-0700: [GC [ParNew: 136364K->66K(153344K), 0.0031410
secs] 315983K->179694K(1621376K) icms_dc=0 , 0.0031960 secs] [Times: user=0.02 sys=0.00,
real=0.01 secs]
>>> 2012-07-22T10:31:15.761-0700: [GC [ParNew: 136346K->52K(153344K), 0.0029310
secs] 315974K->179680K(1621376K) icms_dc=0 , 0.0029870 secs] [Times: user=0.02 sys=0.00,
real=0.00 secs]
>>> 2012-07-22T10:47:48.745-0700: [GC [ParNew: 136341K->37K(153344K), 0.0031490
secs] 315969K->179665K(1621376K) icms_dc=0 , 0.0032070 secs] [Times: user=0.02 sys=0.00,
real=0.00 secs]
>>> 2012-07-22T11:04:25.008-0700: [GC [ParNew: 136357K->39K(153344K), 0.0027710
secs] 315985K->179667K(1621376K) icms_dc=0 , 0.0028260 secs] [Times: user=0.01 sys=0.00,
real=0.00 secs]
>>> 2012-07-22T11:20:55.715-0700: [GC [ParNew: 136337K->39K(153344K), 0.0032670
secs] 315965K->179667K(1621376K) icms_dc=0 , 0.0033210 secs] [Times: user=0.03 sys=0.00,
real=0.00 secs]
>>> 2012-07-22T11:37:28.701-0700: [GC [ParNew: 136327K->39K(153344K), 0.0027510
secs] 315955K->179667K(1621376K) icms_dc=0 , 0.0028070 secs] [Times: user=0.02 sys=0.00,
real=0.01 secs]
>>> 2012-07-22T11:54:02.688-0700: [GC [ParNew: 136342K->39K(153344K), 0.0033410
secs] 315971K->179667K(1621376K) icms_dc=0 , 0.0033980 secs] [Times: user=0.03 sys=0.00,
real=0.00 secs]
>>> 2012-07-22T12:10:35.639-0700: [GC [ParNew: 136359K->39K(153344K), 0.0026440
secs] 315987K->179667K(1621376K) icms_dc=0 , 0.0027000 secs] [Times: user=0.02 sys=0.00,
real=0.00 secs]
>>> 2012-07-22T12:27:05.649-0700: [GC [ParNew: 136359K->39K(153344K), 0.0027960
secs] 315987K->179667K(1621376K) icms_dc=0 , 0.0028520 secs] [Times: user=0.02 sys=0.00,
real=0.00 secs]
>>> 2012-07-22T12:43:35.627-0700: [GC [ParNew: 136340K->39K(153344K), 0.0030750
secs] 315968K->179667K(1621376K) icms_dc=0 , 0.0031320 secs] [Times: user=0.02 sys=0.00,
real=0.00 secs]
>>> 2012-07-22T13:00:05.607-0700: [GC [ParNew: 136359K->39K(153344K), 0.0032030
secs] 315987K->179667K(1621376K) icms_dc=0 , 0.0032770 secs] [Times: user=0.03 sys=0.01,
real=0.00 secs]
>>> 2012-07-22T13:16:35.587-0700: [GC [ParNew: 136359K->39K(153344K), 0.0027270
secs] 315987K->179667K(1621376K) icms_dc=0 , 0.0027820 secs] [Times: user=0.02 sys=0.00,
real=0.00 secs]
>>> 2012-07-22T13:33:05.565-0700: [GC [ParNew: 136325K->39K(153344K), 0.0028510
secs] 315953K->179667K(1621376K) icms_dc=0 , 0.0029060 secs] [Times: user=0.02 sys=0.00,
real=0.00 secs]
>>> 2012-07-22T13:49:35.545-0700: [GC [ParNew: 136359K->39K(153344K), 0.0030620
secs] 315987K->179667K(1621376K) icms_dc=0 , 0.0031170 secs] [Times: user=0.03 sys=0.00,
real=0.01 secs]
>>> 2012-07-22T14:06:05.524-0700: [GC [ParNew: 136359K->56K(153344K), 0.0029310
secs] 315987K->179684K(1621376K) icms_dc=0 , 0.0029870 secs] [Times: user=0.03 sys=0.00,
real=0.01 secs]
>>> 2012-07-22T14:22:35.502-0700: [GC [ParNew: 136376K->55K(153344K), 0.0028840
secs] 316004K->179684K(1621376K) icms_dc=0 , 0.0029400 secs] [Times: user=0.02 sys=0.00,
real=0.01 secs]
>>> 2012-07-22T14:39:06.248-0700: [GC [ParNew: 136375K->55K(153344K), 0.0032820
secs] 316004K->179684K(1621376K) icms_dc=0 , 0.0033360 secs] [Times: user=0.02 sys=0.00,
real=0.00 secs]
>>> 12/07/22 14:47:33 INFO regionserver.Store: Renaming flushed file at hdfs://h01.mtv.byah.net/hbase/session_prod2/010f43c1636e86b8546bd480158df536/.tmp/7069292654066145383
to hdfs://h01.mtv.byah.net/hbase/session_prod2/010f43c1636e86b8546bd480158df536/M/8185820606610414476
>>> 12/07/22 14:47:33 INFO regionserver.Store: Added hdfs://h01.mtv.byah.net/hbase/session_prod2/010f43c1636e86b8546bd480158df536/M/8185820606610414476,
entries=91568, sequenceid=15360597, memsize=22.4m, filesize=1.4m
>>> 2012-07-22T14:47:33.177-0700: [GC [ParNew: 136324K->12390K(153344K), 0.0061720
secs] 315953K->192019K(1621376K) icms_dc=0 , 0.0062440 secs] [Times: user=0.04 sys=0.00,
real=0.01 secs]
>>> 12/07/22 14:47:33 INFO regionserver.Store: Renaming flushed file at hdfs://h01.mtv.byah.net/hbase/session_prod2/010f43c1636e86b8546bd480158df536/.tmp/4192914148964281571
to hdfs://h01.mtv.byah.net/hbase/session_prod2/010f43c1636e86b8546bd480158df536/P/5830576607855695317
>>> 12/07/22 14:47:33 INFO regionserver.Store: Added hdfs://h01.mtv.byah.net/hbase/session_prod2/010f43c1636e86b8546bd480158df536/P/5830576607855695317,
entries=101249, sequenceid=15360597, memsize=46.1m, filesize=4.2m
>>> 12/07/22 14:47:33 INFO regionserver.HRegion: Finished memstore flush of ~68.5m
for region session_prod2,2EEEEEEC-0000-0000-0000-000000000000,1342965495011.010f43c1636e86b8546bd480158df536.
in 275ms, sequenceid=15360597, compaction requested=false
>>> 2012-07-22T14:47:35.138-0700: [GC [ParNew: 148634K->8478K(153344K), 0.0116530
secs] 328263K->198054K(1621376K) icms_dc=0 , 0.0117260 secs] [Times: user=0.06 sys=0.00,
real=0.01 secs]
>>> 2012-07-22T14:47:43.631-0700: [GC [ParNew: 144640K->17024K(153344K), 0.0302560
secs] 334216K->238447K(1621376K) icms_dc=0 , 0.0303350 secs] [Times: user=0.20 sys=0.00,
real=0.03 secs]
>>> =================================================================
>> 


Mime
View raw message