Exception caught in the client:
java.io.IOException: HRegionInfo was null or empty in .META.
at org.apache.hadoop.hbase.HConnectionManager$TableServers.locateRegionInMeta(HConnectionManager.java:429)
at org.apache.hadoop.hbase.HConnectionManager$TableServers.locateRegion(HConnectionManager.java:350)
at org.apache.hadoop.hbase.HConnectionManager$TableServers.relocateRegion(HConnectionManager.java:318)
at org.apache.hadoop.hbase.HTable.getRegionLocation(HTable.java:114)
at org.apache.hadoop.hbase.HTable$ServerCallable.instantiateServer(HTable.java:1009)
at org.apache.hadoop.hbase.HTable.getRegionServerWithRetries(HTable.java:1024)
at org.apache.hadoop.hbase.HTable.commit(HTable.java:763)
at org.apache.hadoop.hbase.HTable.commit(HTable.java:744)
at com.openplaces.util.hbaserecord.HBaseImpl.updateHBaseEntry(HBaseImpl.java:185)
at com.openplaces.util.hbaserecord.HBaseImpl.writeHBaseEntry(HBaseImpl.java:101)
at com.openplaces.models.WebPage.save(WebPage.java:129)
at com.openplaces.ned.SemanticLinkExtractor.reduce(SemanticLinkExtractor.java:271)
at org.apache.hadoop.mapred.ReduceTask.run(ReduceTask.java:333)
at org.apache.hadoop.mapred.TaskTracker$Child.main(TaskTracker.java:2071)
Weird behavior found in the log file of the master at that same time:
2008-04-17 11:10:44,584 INFO org.apache.hadoop.hbase.HMaster: HMaster.rootScanner scanning meta region {regionname: -ROOT-,,0, startKey: <>, server: 192.168.1.84:64020}
2008-04-17 11:10:44,600 INFO org.apache.hadoop.hbase.HMaster: HMaster.rootScanner scan of meta region {regionname: -ROOT-,,0, startKey: <>, server: 192.168.1.84:64020} complete
2008-04-17 11:10:48,606 INFO org.apache.hadoop.hbase.HMaster: HMaster.metaScanner scanning meta region {regionname: .META.,,1, startKey: <>, server: 192.168.1.85:64020}
2008-04-17 11:10:48,638 INFO org.apache.hadoop.hbase.HMaster: HMaster.metaScanner scan of meta region {regionname: .META.,,1, startKey: <>, server: 192.168.1.85:64020} complete
2008-04-17 11:10:48,638 INFO org.apache.hadoop.hbase.HMaster: all meta regions scanned
2008-04-17 11:11:44,584 INFO org.apache.hadoop.hbase.HMaster: HMaster.rootScanner scanning meta region {regionname: -ROOT-,,0, startKey: <>, server: 192.168.1.84:64020}
2008-04-17 11:11:44,601 INFO org.apache.hadoop.hbase.HMaster: HMaster.rootScanner scan of meta region {regionname: -ROOT-,,0, startKey: <>, server: 192.168.1.84:64020} complete
2008-04-17 11:11:48,606 INFO org.apache.hadoop.hbase.HMaster: HMaster.metaScanner scanning meta region {regionname: .META.,,1, startKey: <>, server: 192.168.1.85:64020}
2008-04-17 11:11:48,639 INFO org.apache.hadoop.hbase.HMaster: HMaster.metaScanner scan of meta region {regionname: .META.,,1, startKey: <>, server: 192.168.1.85:64020} complete
2008-04-17 11:11:48,639 INFO org.apache.hadoop.hbase.HMaster: all meta regions scanned
2008-04-17 11:12:15,871 INFO org.apache.hadoop.hbase.HMaster: Region web_pages,,1208443153118 split; new regions: web_pages,,1208445132848, web_pages,http://www.culturecanada.gc.ca/index_e.cfm,1208445132849
2008-04-17 11:12:16,804 INFO org.apache.hadoop.hbase.HMaster: assigning region web_pages,http://www.culturecanada.gc.ca/index_e.cfm,1208445132849 to server 192.168.1.85:64020
2008-04-17 11:12:19,815 INFO org.apache.hadoop.hbase.HMaster: 192.168.1.85:64020 serving web_pages,http://www.culturecanada.gc.ca/index_e.cfm,1208445132849
2008-04-17 11:12:19,816 INFO org.apache.hadoop.hbase.HMaster: regionname: web_pages,http://www.culturecanada.gc.ca/index_e.cfm,1208445132849, startKey: <http://www.culturecanada.gc.ca/index_e.cfm>, endKey: <
>, encodedName: 701727028, tableDesc: {name: web_pages, families: {attribute:={name: attribute, max versions: 3, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, view:={name:
view, max versions: 3, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}} open on 192.168.1.85:64020
2008-04-17 11:12:19,816 INFO org.apache.hadoop.hbase.HMaster: assigning region web_pages,,1208445132848 to server 192.168.1.85:64020
2008-04-17 11:12:19,816 INFO org.apache.hadoop.hbase.HMaster: updating row web_pages,http://www.culturecanada.gc.ca/index_e.cfm,1208445132849 in table .META.,,1 with startcode 1208443465232 and server 192.16
8.1.85:64020
2008-04-17 11:12:22,824 INFO org.apache.hadoop.hbase.HMaster: 192.168.1.85:64020 serving web_pages,,1208445132848
2008-04-17 11:12:22,825 INFO org.apache.hadoop.hbase.HMaster: regionname: web_pages,,1208445132848, startKey: <>, endKey: <http://www.culturecanada.gc.ca/index_e.cfm>, encodedName: 1077249611, tableDesc: {na
me: web_pages, families: {attribute:={name: attribute, max versions: 3, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, view:={name: view, max versions: 3, compression: NONE
, in memory: false, max length: 2147483647, bloom filter: none}}} open on 192.168.1.85:64020
2008-04-17 11:12:22,825 INFO org.apache.hadoop.hbase.HMaster: updating row web_pages,,1208445132848 in table .META.,,1 with startcode 1208443465232 and server 192.168.1.85:64020
2008-04-17 11:12:44,584 INFO org.apache.hadoop.hbase.HMaster: HMaster.rootScanner scanning meta region {regionname: -ROOT-,,0, startKey: <>, server: 192.168.1.84:64020}
2008-04-17 11:12:44,604 INFO org.apache.hadoop.hbase.HMaster: HMaster.rootScanner scan of meta region {regionname: -ROOT-,,0, startKey: <>, server: 192.168.1.84:64020} complete
2008-04-17 11:12:48,606 INFO org.apache.hadoop.hbase.HMaster: HMaster.metaScanner scanning meta region {regionname: .META.,,1, startKey: <>, server: 192.168.1.85:64020}
2008-04-17 11:12:48,637 WARN org.apache.hadoop.hbase.HMaster: info:regioninfo is empty for row: web_pages,,1208445132848; has keys: [info:server, info:serverstartcode]
2008-04-17 11:12:48,638 WARN org.apache.hadoop.hbase.HMaster: info:regioninfo is empty for row: web_pages,http://www.culturecanada.gc.ca/index_e.cfm,1208445132849; has keys: [info:server, info:serverstartcod
e]
2008-04-17 11:12:48,641 WARN org.apache.hadoop.hbase.HMaster: Found 2 rows with empty HRegionInfo while scanning meta region .META.,,1
2008-04-17 11:12:48,645 WARN org.apache.hadoop.hbase.HMaster: Removed region: web_pages,,1208445132848 from meta region: .META.,,1 because HRegionInfo was empty
2008-04-17 11:12:48,650 WARN org.apache.hadoop.hbase.HMaster: Removed region: web_pages,http://www.culturecanada.gc.ca/index_e.cfm,1208445132849 from meta region: .META.,,1 because HRegionInfo was empty
2008-04-17 11:12:48,650 INFO org.apache.hadoop.hbase.HMaster: HMaster.metaScanner scan of meta region {regionname: .META.,,1, startKey: <>, server: 192.168.1.85:64020} complete
2008-04-17 11:12:48,650 INFO org.apache.hadoop.hbase.HMaster: all meta regions scanned
2008-04-17 11:13:44,584 INFO org.apache.hadoop.hbase.HMaster: HMaster.rootScanner scanning meta region {regionname: -ROOT-,,0, startKey: <>, server: 192.168.1.84:64020}
2008-04-17 11:13:44,600 INFO org.apache.hadoop.hbase.HMaster: HMaster.rootScanner scan of meta region {regionname: -ROOT-,,0, startKey: <>, server: 192.168.1.84:64020} complete
2008-04-17 11:13:48,606 INFO org.apache.hadoop.hbase.HMaster: HMaster.metaScanner scanning meta region {regionname: .META.,,1, startKey: <>, server: 192.168.1.85:64020}
2008-04-17 11:13:48,638 INFO org.apache.hadoop.hbase.HMaster: HMaster.metaScanner scan of meta region {regionname: .META.,,1, startKey: <>, server: 192.168.1.85:64020} complete
2008-04-17 11:13:48,638 INFO org.apache.hadoop.hbase.HMaster: all meta regions scanned
In the log file of one of the region servers (192.168.1.84):
2008-04-17 10:40:51,056 INFO org.apache.hadoop.hbase.HRegion: region sources,,1206655366617 available
2008-04-17 10:40:51,057 INFO org.apache.hadoop.hbase.HRegionServer: MSG_REGION_OPEN : entity_candidates,,1208281442063
2008-04-17 10:40:51,068 INFO org.apache.hadoop.hbase.HRegion: region entity_candidates,,1208281442063 available
2008-04-17 10:40:51,068 INFO org.apache.hadoop.hbase.HRegionServer: MSG_REGION_OPEN : web_pages,,1208443153118
2008-04-17 10:40:51,077 INFO org.apache.hadoop.hbase.HRegion: region web_pages,,1208443153118 available
2008-04-17 11:08:30,306 INFO org.apache.hadoop.hbase.HRegionServer: Rolling hlog. Number of entries: 30006
2008-04-17 11:08:30,349 INFO org.apache.hadoop.hbase.HLog: new log writer created at hdfs://cluster04.lab.mtl:9400/hbase/amsterdam_migration/log_192.168.1.84_1208443239497_64020/hlog.dat.001
2008-04-17 11:08:59,222 INFO org.apache.hadoop.hbase.HRegion: starting compaction on region web_pages,,1208443153118
2008-04-17 11:09:07,520 INFO org.apache.hadoop.hbase.HRegion: compaction completed on region web_pages,,1208443153118. Took 8sec
2008-04-17 11:12:12,836 INFO org.apache.hadoop.hbase.HRegion: Splitting web_pages,,1208443153118 because largest aggregate size is 257.0m and desired size is 256.0m
2008-04-17 11:12:12,873 INFO org.apache.hadoop.ipc.Server: IPC Server handler 8 on 64020, call batchUpdate(web_pages,,1208443153118, 9223372036854775807, org.apache.hadoop.hbase.io.BatchUpdate@1d753b7) from
192.168.1.81:35148: error: org.apache.hadoop.hbase.NotServingRegionException: web_pages,,1208443153118
org.apache.hadoop.hbase.NotServingRegionException: web_pages,,1208443153118
at org.apache.hadoop.hbase.HRegionServer.getRegion(HRegionServer.java:1639)
at org.apache.hadoop.hbase.HRegionServer.getRegion(HRegionServer.java:1611)
at org.apache.hadoop.hbase.HRegionServer.batchUpdate(HRegionServer.java:1460)
at sun.reflect.GeneratedMethodAccessor8.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at org.apache.hadoop.hbase.ipc.HbaseRPC$Server.call(HbaseRPC.java:413)
at org.apache.hadoop.ipc.Server$Handler.run(Server.java:899)
2008-04-17 11:12:12,879 INFO org.apache.hadoop.ipc.Server: IPC Server handler 2 on 64020, call batchUpdate(web_pages,,1208443153118, 9223372036854775807, org.apache.hadoop.hbase.io.BatchUpdate@1d602b3) from
192.168.1.83:44454: error: org.apache.hadoop.hbase.NotServingRegionException: web_pages,,1208443153118
org.apache.hadoop.hbase.NotServingRegionException: web_pages,,1208443153118
at org.apache.hadoop.hbase.HRegionServer.getRegion(HRegionServer.java:1639)
at org.apache.hadoop.hbase.HRegionServer.getRegion(HRegionServer.java:1611)
at org.apache.hadoop.hbase.HRegionServer.batchUpdate(HRegionServer.java:1460)
at sun.reflect.GeneratedMethodAccessor8.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at org.apache.hadoop.hbase.ipc.HbaseRPC$Server.call(HbaseRPC.java:413)
at org.apache.hadoop.ipc.Server$Handler.run(Server.java:899)
2008-04-17 11:12:12,936 INFO org.apache.hadoop.ipc.Server: IPC Server handler 6 on 64020, call batchUpdate(web_pages,,1208443153118, 9223372036854775807, org.apache.hadoop.hbase.io.BatchUpdate@fbfb30) from 1
92.168.1.82:59273: error: org.apache.hadoop.hbase.NotServingRegionException: web_pages,,1208443153118
org.apache.hadoop.hbase.NotServingRegionException: web_pages,,1208443153118
at org.apache.hadoop.hbase.HRegionServer.getRegion(HRegionServer.java:1639)
at org.apache.hadoop.hbase.HRegionServer.getRegion(HRegionServer.java:1611)
at org.apache.hadoop.hbase.HRegionServer.batchUpdate(HRegionServer.java:1460)
at sun.reflect.GeneratedMethodAccessor8.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at org.apache.hadoop.hbase.ipc.HbaseRPC$Server.call(HbaseRPC.java:413)
at org.apache.hadoop.ipc.Server$Handler.run(Server.java:899)
And nothing weird happened in the second region server (192.168.1.85) during that period of time:
2008-04-17 10:44:29,788 INFO org.apache.hadoop.hbase.HRegionServer: MSG_REGION_OPEN : .META.,,1
2008-04-17 10:44:29,964 WARN org.apache.hadoop.util.NativeCodeLoader: Unable to load native-hadoop library for your platform... using builtin-java classes where applicable
2008-04-17 10:44:29,982 INFO org.apache.hadoop.hbase.HRegion: region .META.,,1 available
2008-04-17 11:16:01,224 INFO org.apache.hadoop.hbase.HRegionServer: MSG_REGION_OPEN : web_pages,http://www.culturecanada.gc.ca/index_e.cfm,1208445132849
2008-04-17 11:16:01,330 INFO org.apache.hadoop.hbase.HRegion: region web_pages,http://www.culturecanada.gc.ca/index_e.cfm,1208445132849 available
2008-04-17 11:16:01,330 INFO org.apache.hadoop.hbase.HRegion: starting compaction on region web_pages,http://www.culturecanada.gc.ca/index_e.cfm,1208445132849
2008-04-17 11:16:04,237 INFO org.apache.hadoop.hbase.HRegionServer: MSG_REGION_OPEN : web_pages,,1208445132848
2008-04-17 11:16:04,482 INFO org.apache.hadoop.hbase.HRegion: region web_pages,,1208445132848 available
2008-04-17 11:16:06,980 INFO org.apache.hadoop.hbase.HRegion: compaction completed on region web_pages,http://www.culturecanada.gc.ca/index_e.cfm,1208445132849. Took 5sec
2008-04-17 11:16:06,994 INFO org.apache.hadoop.hbase.HRegion: starting compaction on region web_pages,,1208445132848
2008-04-17 11:16:13,610 INFO org.apache.hadoop.hbase.HRegion: compaction completed on region web_pages,,1208445132848. Took 6sec
2008-04-17 13:12:32,810 INFO org.apache.hadoop.hbase.HRegionServer: Got quiesce server message
2008-04-17 13:12:32,811 INFO org.apache.hadoop.hbase.HRegionServer: MSG_REGIONSERVER_QUIESCE :
2008-04-17 13:12:34,695 INFO org.apache.hadoop.hbase.HRegion: closed web_pages,,1208445132848
2008-04-17 13:12:34,695 INFO org.apache.hadoop.hbase.HRegion: closed web_pages,http://www.culturecanada.gc.ca/index_e.cfm,1208445132849