See http://lucene.zones.apache.org:8080/hudson/job/Hadoop-Nightly/335/changes
------------------------------------------ [...truncated 48049 lines...] [junit] 2007-12-17 13:14:06,676 DEBUG [IPC Server handler 2 on 60000] hbase.HStore(600): starting r2,,1197897246655/d (2124584548/d) (no reconstruction log) [junit] 2007-12-17 13:14:06,679 DEBUG [IPC Server handler 2 on 60000] hbase.HStore(628): maximum sequence id for hstore r2,,1197897246655/d (2124584548/d) is -1 [junit] 2007-12-17 13:14:06,692 DEBUG [IPC Server handler 2 on 60000] hbase.HStore(600): starting r2,,1197897246655/e (2124584548/e) (no reconstruction log) [junit] 2007-12-17 13:14:06,695 DEBUG [IPC Server handler 2 on 60000] hbase.HStore(628): maximum sequence id for hstore r2,,1197897246655/e (2124584548/e) is -1 [junit] 2007-12-17 13:14:06,696 DEBUG [IPC Server handler 2 on 60000] hbase.HRegion(300): Next sequence id for region r2,,1197897246655 is 0 [junit] 2007-12-17 13:14:06,699 INFO [IPC Server handler 2 on 60000] hbase.HRegion(328): region r2,,1197897246655 available [junit] 2007-12-17 13:14:06,701 DEBUG [IPC Server handler 2 on 60000] hbase.HStore(879): closed r2,,1197897246655/e (2124584548/e) [junit] 2007-12-17 13:14:06,701 DEBUG [IPC Server handler 2 on 60000] hbase.HStore(879): closed r2,,1197897246655/d (2124584548/d) [junit] 2007-12-17 13:14:06,702 INFO [IPC Server handler 2 on 60000] hbase.HRegion(430): closed r2,,1197897246655 [junit] 2007-12-17 13:14:06,702 DEBUG [IPC Server handler 2 on 60000] hbase.HLog(388): closing log writer in /hbase/hregion_2124584548/log [junit] 2007-12-17 13:14:07,122 INFO [IPC Server handler 2 on 60000] hbase.HMaster(2545): created table r2 [junit] 2007-12-17 13:14:07,123 DEBUG [main] hbase.HConnectionManager$TableServers(308): No servers for r2. Doing a find... [junit] 2007-12-17 13:14:07,127 INFO [IPC Server handler 4 on 60000] hbase.HMaster(1856): assigning region r2,,1197897246655 to the only server 140.211.11.75:47023 [junit] 2007-12-17 13:14:07,128 DEBUG [main] hbase.HConnectionManager$TableServers(782): no server address for regionname: r2,,1197897246655, startKey: <>, encodedName(2124584548) tableDesc: {name: r2, families: {d:={name: d, max versions: 3, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, e:={name: e, max versions: 3, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}} [junit] 2007-12-17 13:14:07,129 INFO [RegionServer:0.worker] hbase.HRegionServer$Worker(1153): MSG_REGION_OPEN : r2,,1197897246655 [junit] 2007-12-17 13:14:07,130 DEBUG [main] hbase.HConnectionManager$TableServers(680): Sleeping. Table r2 not currently being served. [junit] 2007-12-17 13:14:07,136 DEBUG [RegionServer:0.worker] hbase.HStore(600): starting r2,,1197897246655/d (2124584548/d) (no reconstruction log) [junit] 2007-12-17 13:14:07,139 DEBUG [RegionServer:0.worker] hbase.HStore(628): maximum sequence id for hstore r2,,1197897246655/d (2124584548/d) is -1 [junit] 2007-12-17 13:14:07,144 DEBUG [RegionServer:0.worker] hbase.HStore(600): starting r2,,1197897246655/e (2124584548/e) (no reconstruction log) [junit] 2007-12-17 13:14:07,148 DEBUG [RegionServer:0.worker] hbase.HStore(628): maximum sequence id for hstore r2,,1197897246655/e (2124584548/e) is -1 [junit] 2007-12-17 13:14:07,149 DEBUG [RegionServer:0.worker] hbase.HRegion(300): Next sequence id for region r2,,1197897246655 is 0 [junit] 2007-12-17 13:14:07,151 INFO [RegionServer:0.worker] hbase.HRegion(328): region r2,,1197897246655 available [junit] 2007-12-17 13:14:08,097 DEBUG [RegionServer:0.cacheFlusher] hbase.HRegion(837): Started memcache flush for region -ROOT-,,0. Size 92.0 [junit] 2007-12-17 13:14:08,139 DEBUG [IPC Server handler 1 on 60000] hbase.HMaster(1514): Received MSG_REPORT_PROCESS_OPEN : r2,,1197897246655 from 140.211.11.75:47023 [junit] 2007-12-17 13:14:08,140 DEBUG [IPC Server handler 1 on 60000] hbase.HMaster(1514): Received MSG_REPORT_OPEN : r2,,1197897246655 from 140.211.11.75:47023 [junit] 2007-12-17 13:14:08,141 INFO [IPC Server handler 1 on 60000] hbase.HMaster(1575): 140.211.11.75:47023 serving r2,,1197897246655 [junit] 2007-12-17 13:14:08,142 DEBUG [HMaster] hbase.HMaster(1053): Main processing loop: PendingOpenOperation from 140.211.11.75:47023 [junit] 2007-12-17 13:14:08,143 INFO [HMaster] hbase.HMaster$ProcessRegionOpen(2456): regionname: r2,,1197897246655, startKey: <>, encodedName(2124584548) tableDesc: {name: r2, families: {d:={name: d, max versions: 3, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, e:={name: e, max versions: 3, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}} open on 140.211.11.75:47023 [junit] 2007-12-17 13:14:08,144 DEBUG [HMaster] hbase.HMaster$RegionServerOperation(1905): numberOfMetaRegions: 1, onlineMetaRegions.size(): 1 [junit] 2007-12-17 13:14:08,145 INFO [HMaster] hbase.HMaster$ProcessRegionOpen(2470): updating row r2,,1197897246655 in table .META.,,1 with startcode 1197897237977 and server 140.211.11.75:47023 [junit] 2007-12-17 13:14:08,419 DEBUG [RegionServer:0.cacheFlusher] hbase.HStore(969): Added 70236052/info/3729789325086364017 with sequence id 23 and size 230.0 for -ROOT-,,0/info [junit] 2007-12-17 13:14:08,420 DEBUG [RegionServer:0.cacheFlusher] hbase.HRegion(943): Finished memcache flush for region -ROOT-,,0 in 324ms, sequenceid=23 [junit] 2007-12-17 13:14:08,421 DEBUG [RegionServer:0.compactor] hbase.HStore(993): compaction for HStore -ROOT-,,0/info not needed. [junit] 2007-12-17 13:14:08,421 DEBUG [RegionServer:0.compactor] hbase.HRegion(707): region -ROOT-,,0 does not need compaction [junit] 2007-12-17 13:14:09,116 INFO [HMaster.rootScanner] hbase.HMaster$BaseScanner(211): HMaster.rootScanner scanning meta region regionname: -ROOT-,,0, startKey: <>, server: 140.211.11.75:47023} [junit] 2007-12-17 13:14:09,148 DEBUG [HMaster.rootScanner] hbase.HMaster$BaseScanner(247): HMaster.rootScanner regioninfo: {regionname: .META.,,1, startKey: <>, encodedName(1028785192) tableDesc: {name: .META., families: {info:={name: info, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}}, server: 140.211.11.75:47023, startCode: 1197897237977 [junit] 2007-12-17 13:14:09,151 INFO [HMaster.rootScanner] hbase.HMaster$BaseScanner(293): HMaster.rootScanner scan of meta region regionname: -ROOT-,,0, startKey: <>, server: 140.211.11.75:47023} complete [junit] 2007-12-17 13:14:10,086 DEBUG [RegionServer:0.cacheFlusher] hbase.HRegion(837): Started memcache flush for region .META.,,1. Size 472.0 [junit] 2007-12-17 13:14:10,144 DEBUG [RegionServer:0.cacheFlusher] hbase.HStore(969): Added 1028785192/info/1601232028110529711 with sequence id 26 and size 666.0 for .META.,,1/info [junit] 2007-12-17 13:14:10,145 DEBUG [RegionServer:0.cacheFlusher] hbase.HRegion(943): Finished memcache flush for region .META.,,1 in 59ms, sequenceid=26 [junit] 2007-12-17 13:14:10,145 DEBUG [RegionServer:0.compactor] hbase.HStore(993): compaction for HStore .META.,,1/info not needed. [junit] 2007-12-17 13:14:10,146 DEBUG [RegionServer:0.compactor] hbase.HRegion(707): region .META.,,1 does not need compaction [junit] 2007-12-17 13:14:11,096 INFO [HMaster.metaScanner] hbase.HMaster$BaseScanner(211): HMaster.metaScanner scanning meta region regionname: .META.,,1, startKey: <>, server: 140.211.11.75:47023} [junit] 2007-12-17 13:14:11,123 DEBUG [HMaster.metaScanner] hbase.HMaster$BaseScanner(247): HMaster.metaScanner regioninfo: {regionname: r1,,1197897237999, startKey: <>, encodedName(1061212237) tableDesc: {name: r1, families: {a:={name: a, max versions: 3, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, b:={name: b, max versions: 3, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, c:={name: c, max versions: 3, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}}, server: 140.211.11.75:47023, startCode: 1197897237977 [junit] 2007-12-17 13:14:11,127 DEBUG [HMaster.metaScanner] hbase.HMaster$BaseScanner(247): HMaster.metaScanner regioninfo: {regionname: r2,,1197897246655, startKey: <>, encodedName(2124584548) tableDesc: {name: r2, families: {d:={name: d, max versions: 3, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, e:={name: e, max versions: 3, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}}, server: 140.211.11.75:47023, startCode: 1197897237977 [junit] 2007-12-17 13:14:11,130 INFO [HMaster.metaScanner] hbase.HMaster$BaseScanner(293): HMaster.metaScanner scan of meta region regionname: .META.,,1, startKey: <>, server: 140.211.11.75:47023} complete [junit] 2007-12-17 13:14:11,131 INFO [HMaster.metaScanner] hbase.HMaster$MetaScanner(761): all meta regions scanned [junit] 2007-12-17 13:14:12,126 DEBUG [RegionServer:0.cacheFlusher] hbase.HRegion(837): Started memcache flush for region r1,,1197897237999. Size 310.0 [junit] 2007-12-17 13:14:12,138 DEBUG [main] hbase.HConnectionManager$TableServers(689): Wake. Retry finding table r2 [junit] 2007-12-17 13:14:12,171 DEBUG [main] hbase.HConnectionManager$TableServers(732): Found 1 region(s) for r2 at address: 140.211.11.75:47023, regioninfo: regionname: .META.,,1, startKey: <>, encodedName(1028785192) tableDesc: {name: .META., families: {info:={name: info, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}} [junit] 2007-12-17 13:14:12,217 INFO [IPC Server handler 1 on 60000] hbase.HLog(302): new log writer created at /hbase/hregion_1987603939/log/hlog.dat.000 [junit] 2007-12-17 13:14:12,232 DEBUG [IPC Server handler 1 on 60000] hbase.HStore(600): starting result_table,,1197897252182/a (1987603939/a) (no reconstruction log) [junit] 2007-12-17 13:14:12,234 DEBUG [IPC Server handler 1 on 60000] hbase.HStore(628): maximum sequence id for hstore result_table,,1197897252182/a (1987603939/a) is -1 [junit] 2007-12-17 13:14:12,241 DEBUG [IPC Server handler 1 on 60000] hbase.HStore(600): starting result_table,,1197897252182/b (1987603939/b) (no reconstruction log) [junit] 2007-12-17 13:14:12,243 DEBUG [IPC Server handler 1 on 60000] hbase.HStore(628): maximum sequence id for hstore result_table,,1197897252182/b (1987603939/b) is -1 [junit] 2007-12-17 13:14:12,250 DEBUG [IPC Server handler 1 on 60000] hbase.HStore(600): starting result_table,,1197897252182/c (1987603939/c) (no reconstruction log) [junit] 2007-12-17 13:14:12,252 DEBUG [IPC Server handler 1 on 60000] hbase.HStore(628): maximum sequence id for hstore result_table,,1197897252182/c (1987603939/c) is -1 [junit] 2007-12-17 13:14:12,260 DEBUG [IPC Server handler 1 on 60000] hbase.HStore(600): starting result_table,,1197897252182/d (1987603939/d) (no reconstruction log) [junit] 2007-12-17 13:14:12,262 DEBUG [IPC Server handler 1 on 60000] hbase.HStore(628): maximum sequence id for hstore result_table,,1197897252182/d (1987603939/d) is -1 [junit] 2007-12-17 13:14:12,269 DEBUG [IPC Server handler 1 on 60000] hbase.HStore(600): starting result_table,,1197897252182/e (1987603939/e) (no reconstruction log) [junit] 2007-12-17 13:14:12,272 DEBUG [IPC Server handler 1 on 60000] hbase.HStore(628): maximum sequence id for hstore result_table,,1197897252182/e (1987603939/e) is -1 [junit] 2007-12-17 13:14:12,273 DEBUG [IPC Server handler 1 on 60000] hbase.HRegion(300): Next sequence id for region result_table,,1197897252182 is 0 [junit] 2007-12-17 13:14:12,275 INFO [IPC Server handler 1 on 60000] hbase.HRegion(328): region result_table,,1197897252182 available [junit] 2007-12-17 13:14:12,277 DEBUG [IPC Server handler 1 on 60000] hbase.HStore(879): closed result_table,,1197897252182/e (1987603939/e) [junit] 2007-12-17 13:14:12,277 DEBUG [IPC Server handler 1 on 60000] hbase.HStore(879): closed result_table,,1197897252182/d (1987603939/d) [junit] 2007-12-17 13:14:12,278 DEBUG [IPC Server handler 1 on 60000] hbase.HStore(879): closed result_table,,1197897252182/a (1987603939/a) [junit] 2007-12-17 13:14:12,278 DEBUG [IPC Server handler 1 on 60000] hbase.HStore(879): closed result_table,,1197897252182/b (1987603939/b) [junit] 2007-12-17 13:14:12,278 DEBUG [IPC Server handler 1 on 60000] hbase.HStore(879): closed result_table,,1197897252182/c (1987603939/c) [junit] 2007-12-17 13:14:12,279 INFO [IPC Server handler 1 on 60000] hbase.HRegion(430): closed result_table,,1197897252182 [junit] 2007-12-17 13:14:12,279 DEBUG [IPC Server handler 1 on 60000] hbase.HLog(388): closing log writer in /hbase/hregion_1987603939/log [junit] 2007-12-17 13:14:12,657 DEBUG [RegionServer:0.cacheFlusher] hbase.HStore(969): Added 1061212237/a/6310597502408849350 with sequence id 27 and size 270.0 for r1,,1197897237999/a [junit] 2007-12-17 13:14:12,691 INFO [IPC Server handler 1 on 60000] hbase.HMaster(2545): created table result_table [junit] 2007-12-17 13:14:12,692 DEBUG [main] hbase.HConnectionManager$TableServers(308): No servers for result_table. Doing a find... [junit] 2007-12-17 13:14:12,711 DEBUG [main] hbase.HConnectionManager$TableServers(782): no server address for regionname: result_table,,1197897252182, startKey: <>, encodedName(1987603939) tableDesc: {name: result_table, families: {a:={name: a, max versions: 3, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, b:={name: b, max versions: 3, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, c:={name: c, max versions: 3, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, d:={name: d, max versions: 3, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, e:={name: e, max versions: 3, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}} [junit] 2007-12-17 13:14:12,712 DEBUG [main] hbase.HConnectionManager$TableServers(680): Sleeping. Table result_table not currently being served. [junit] 2007-12-17 13:14:12,726 DEBUG [RegionServer:0.cacheFlusher] hbase.HStore(969): Added 1061212237/b/683064164177937252 with sequence id 27 and size 270.0 for r1,,1197897237999/b [junit] 2007-12-17 13:14:12,781 DEBUG [RegionServer:0.cacheFlusher] hbase.HStore(969): Added 1061212237/c/2138090524135364454 with sequence id 27 and size 310.0 for r1,,1197897237999/c [junit] 2007-12-17 13:14:12,782 DEBUG [RegionServer:0.cacheFlusher] hbase.HRegion(943): Finished memcache flush for region r1,,1197897237999 in 656ms, sequenceid=27 [junit] 2007-12-17 13:14:12,782 DEBUG [RegionServer:0.compactor] hbase.HStore(993): compaction for HStore r1,,1197897237999/a not needed. [junit] 2007-12-17 13:14:12,783 DEBUG [RegionServer:0.compactor] hbase.HStore(993): compaction for HStore r1,,1197897237999/b not needed. [junit] 2007-12-17 13:14:12,783 DEBUG [RegionServer:0.compactor] hbase.HStore(993): compaction for HStore r1,,1197897237999/c not needed. [junit] 2007-12-17 13:14:12,783 DEBUG [RegionServer:0.compactor] hbase.HRegion(707): region r1,,1197897237999 does not need compaction [junit] 2007-12-17 13:14:13,187 INFO [IPC Server handler 3 on 60000] hbase.HMaster(1856): assigning region result_table,,1197897252182 to the only server 140.211.11.75:47023 [junit] 2007-12-17 13:14:13,188 INFO [RegionServer:0.worker] hbase.HRegionServer$Worker(1153): MSG_REGION_OPEN : result_table,,1197897252182 [junit] 2007-12-17 13:14:13,193 DEBUG [RegionServer:0.worker] hbase.HStore(600): starting result_table,,1197897252182/a (1987603939/a) (no reconstruction log) [junit] 2007-12-17 13:14:13,195 DEBUG [RegionServer:0.worker] hbase.HStore(628): maximum sequence id for hstore result_table,,1197897252182/a (1987603939/a) is -1 [junit] 2007-12-17 13:14:13,199 DEBUG [RegionServer:0.worker] hbase.HStore(600): starting result_table,,1197897252182/b (1987603939/b) (no reconstruction log) [junit] 2007-12-17 13:14:13,201 DEBUG [RegionServer:0.worker] hbase.HStore(628): maximum sequence id for hstore result_table,,1197897252182/b (1987603939/b) is -1 [junit] 2007-12-17 13:14:13,205 DEBUG [RegionServer:0.worker] hbase.HStore(600): starting result_table,,1197897252182/c (1987603939/c) (no reconstruction log) [junit] 2007-12-17 13:14:13,208 DEBUG [RegionServer:0.worker] hbase.HStore(628): maximum sequence id for hstore result_table,,1197897252182/c (1987603939/c) is -1 [junit] 2007-12-17 13:14:13,217 DEBUG [RegionServer:0.worker] hbase.HStore(600): starting result_table,,1197897252182/d (1987603939/d) (no reconstruction log) [junit] 2007-12-17 13:14:13,220 DEBUG [RegionServer:0.worker] hbase.HStore(628): maximum sequence id for hstore result_table,,1197897252182/d (1987603939/d) is -1 [junit] 2007-12-17 13:14:13,224 DEBUG [RegionServer:0.worker] hbase.HStore(600): starting result_table,,1197897252182/e (1987603939/e) (no reconstruction log) [junit] 2007-12-17 13:14:13,226 DEBUG [RegionServer:0.worker] hbase.HStore(628): maximum sequence id for hstore result_table,,1197897252182/e (1987603939/e) is -1 [junit] 2007-12-17 13:14:13,228 DEBUG [RegionServer:0.worker] hbase.HRegion(300): Next sequence id for region result_table,,1197897252182 is 0 [junit] 2007-12-17 13:14:13,229 INFO [RegionServer:0.worker] hbase.HRegion(328): region result_table,,1197897252182 available [junit] 2007-12-17 13:14:14,197 DEBUG [IPC Server handler 0 on 60000] hbase.HMaster(1514): Received MSG_REPORT_PROCESS_OPEN : result_table,,1197897252182 from 140.211.11.75:47023 [junit] 2007-12-17 13:14:14,197 DEBUG [IPC Server handler 0 on 60000] hbase.HMaster(1514): Received MSG_REPORT_OPEN : result_table,,1197897252182 from 140.211.11.75:47023 [junit] 2007-12-17 13:14:14,198 INFO [IPC Server handler 0 on 60000] hbase.HMaster(1575): 140.211.11.75:47023 serving result_table,,1197897252182 [junit] 2007-12-17 13:14:14,198 DEBUG [HMaster] hbase.HMaster(1053): Main processing loop: PendingOpenOperation from 140.211.11.75:47023 [junit] 2007-12-17 13:14:14,199 INFO [HMaster] hbase.HMaster$ProcessRegionOpen(2456): regionname: result_table,,1197897252182, startKey: <>, encodedName(1987603939) tableDesc: {name: result_table, families: {a:={name: a, max versions: 3, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, b:={name: b, max versions: 3, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, c:={name: c, max versions: 3, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, d:={name: d, max versions: 3, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, e:={name: e, max versions: 3, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}} open on 140.211.11.75:47023 [junit] 2007-12-17 13:14:14,199 DEBUG [HMaster] hbase.HMaster$RegionServerOperation(1905): numberOfMetaRegions: 1, onlineMetaRegions.size(): 1 [junit] 2007-12-17 13:14:14,199 INFO [HMaster] hbase.HMaster$ProcessRegionOpen(2470): updating row result_table,,1197897252182 in table .META.,,1 with startcode 1197897237977 and server 140.211.11.75:47023 [junit] 2007-12-17 13:14:17,155 DEBUG [RegionServer:0.cacheFlusher] hbase.HRegion(837): Started memcache flush for region r2,,1197897246655. Size 132.0 [junit] 2007-12-17 13:14:17,206 DEBUG [RegionServer:0.cacheFlusher] hbase.HStore(969): Added 2124584548/e/5938864879758723285 with sequence id 37 and size 218.0 for r2,,1197897246655/e [junit] 2007-12-17 13:14:17,264 DEBUG [RegionServer:0.cacheFlusher] hbase.HStore(969): Added 2124584548/d/8657494430963688649 with sequence id 37 and size 218.0 for r2,,1197897246655/d [junit] 2007-12-17 13:14:17,265 DEBUG [RegionServer:0.cacheFlusher] hbase.HRegion(943): Finished memcache flush for region r2,,1197897246655 in 110ms, sequenceid=37 [junit] 2007-12-17 13:14:17,265 DEBUG [RegionServer:0.compactor] hbase.HStore(993): compaction for HStore r2,,1197897246655/e not needed. [junit] 2007-12-17 13:14:17,266 DEBUG [RegionServer:0.compactor] hbase.HStore(993): compaction for HStore r2,,1197897246655/d not needed. [junit] 2007-12-17 13:14:17,266 DEBUG [RegionServer:0.compactor] hbase.HRegion(707): region r2,,1197897246655 does not need compaction [junit] 2007-12-17 13:14:17,715 DEBUG [main] hbase.HConnectionManager$TableServers(689): Wake. Retry finding table result_table [junit] 2007-12-17 13:14:17,730 DEBUG [main] hbase.HConnectionManager$TableServers(732): Found 1 region(s) for result_table at address: 140.211.11.75:47023, regioninfo: regionname: .META.,,1, startKey: <>, encodedName(1028785192) tableDesc: {name: .META., families: {info:={name: info, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}} [junit] 2007-12-17 13:14:18,132 WARN [IPC Server handler 2 on 47009] dfs.FSDirectory(400): DIR* FSDirectory.unprotectedDelete: failed to remove /user/hudson/build/contrib/hbase/test/system because it does not exist [junit] 2007-12-17 13:14:19,125 INFO [HMaster.rootScanner] hbase.HMaster$BaseScanner(211): HMaster.rootScanner scanning meta region regionname: -ROOT-,,0, startKey: <>, server: 140.211.11.75:47023} [junit] 2007-12-17 13:14:19,147 DEBUG [HMaster.rootScanner] hbase.HMaster$BaseScanner(247): HMaster.rootScanner regioninfo: {regionname: .META.,,1, startKey: <>, encodedName(1028785192) tableDesc: {name: .META., families: {info:={name: info, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}}, server: 140.211.11.75:47023, startCode: 1197897237977 [junit] 2007-12-17 13:14:19,149 INFO [HMaster.rootScanner] hbase.HMaster$BaseScanner(293): HMaster.rootScanner scan of meta region regionname: -ROOT-,,0, startKey: <>, server: 140.211.11.75:47023} complete [junit] 2007-12-17 13:14:19,921 WARN [IPC Server handler 8 on 47009] dfs.FSDirectory(400): DIR* FSDirectory.unprotectedDelete: failed to remove /user/hudson/build/contrib/hbase/test/system/job_local_1 because it does not exist [junit] 2007-12-17 13:14:19,923 WARN [main] mapred.JobClient(496): No job jar file set. User classes may not be found. See JobConf(Class) or JobConf#setJar(String). [junit] 2007-12-17 13:14:19,955 DEBUG [main] hbase.HConnectionManager$TableServers(308): No servers for r1. Doing a find... [junit] 2007-12-17 13:14:19,971 DEBUG [main] hbase.HConnectionManager$TableServers(763): Found 1 servers for table r1 [junit] 2007-12-17 13:14:20,006 DEBUG [main] mapred.TableInputFormat(175): split: 0->r1,, [junit] 2007-12-17 13:14:20,155 DEBUG [RegionServer:0.cacheFlusher] hbase.HRegion(837): Started memcache flush for region .META.,,1. Size 331.0 [junit] 2007-12-17 13:14:20,185 DEBUG [Thread-181] mapred.TableInputFormat(175): split: 0->r1,, [junit] 2007-12-17 13:14:20,573 DEBUG [Thread-181] hbase.HConnectionManager$TableServers(308): No servers for r2. Doing a find... [junit] 2007-12-17 13:14:20,594 DEBUG [Thread-181] hbase.HConnectionManager$TableServers(732): Found 1 region(s) for r2 at address: 140.211.11.75:47023, regioninfo: regionname: .META.,,1, startKey: <>, encodedName(1028785192) tableDesc: {name: .META., families: {info:={name: info, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}} [junit] 2007-12-17 13:14:20,627 DEBUG [RegionServer:0.cacheFlusher] hbase.HStore(969): Added 1028785192/info/1185285674360729526 with sequence id 38 and size 483.0 for .META.,,1/info [junit] 2007-12-17 13:14:20,627 DEBUG [RegionServer:0.cacheFlusher] hbase.HRegion(943): Finished memcache flush for region .META.,,1 in 472ms, sequenceid=38 [junit] 2007-12-17 13:14:20,628 DEBUG [RegionServer:0.compactor] hbase.HStore(993): compaction for HStore .META.,,1/info not needed. [junit] 2007-12-17 13:14:20,628 DEBUG [RegionServer:0.compactor] hbase.HRegion(707): region .META.,,1 does not need compaction [junit] 2007-12-17 13:14:21,105 INFO [HMaster.metaScanner] hbase.HMaster$BaseScanner(211): HMaster.metaScanner scanning meta region regionname: .META.,,1, startKey: <>, server: 140.211.11.75:47023} [junit] 2007-12-17 13:14:21,126 DEBUG [HMaster.metaScanner] hbase.HMaster$BaseScanner(247): HMaster.metaScanner regioninfo: {regionname: r1,,1197897237999, startKey: <>, encodedName(1061212237) tableDesc: {name: r1, families: {a:={name: a, max versions: 3, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, b:={name: b, max versions: 3, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, c:={name: c, max versions: 3, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}}, server: 140.211.11.75:47023, startCode: 1197897237977 [junit] 2007-12-17 13:14:21,128 DEBUG [HMaster.metaScanner] hbase.HMaster$BaseScanner(247): HMaster.metaScanner regioninfo: {regionname: r2,,1197897246655, startKey: <>, encodedName(2124584548) tableDesc: {name: r2, families: {d:={name: d, max versions: 3, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, e:={name: e, max versions: 3, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}}, server: 140.211.11.75:47023, startCode: 1197897237977 [junit] 2007-12-17 13:14:21,131 DEBUG [HMaster.metaScanner] hbase.HMaster$BaseScanner(247): HMaster.metaScanner regioninfo: {regionname: result_table,,1197897252182, startKey: <>, encodedName(1987603939) tableDesc: {name: result_table, families: {a:={name: a, max versions: 3, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, b:={name: b, max versions: 3, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, c:={name: c, max versions: 3, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, d:={name: d, max versions: 3, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, e:={name: e, max versions: 3, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}}, server: 140.211.11.75:47023, startCode: 1197897237977 [junit] 2007-12-17 13:14:21,132 INFO [HMaster.metaScanner] hbase.HMaster$BaseScanner(293): HMaster.metaScanner scan of meta region regionname: .META.,,1, startKey: <>, server: 140.211.11.75:47023} complete [junit] 2007-12-17 13:14:21,133 INFO [HMaster.metaScanner] hbase.HMaster$MetaScanner(761): all meta regions scanned [junit] 2007-12-17 13:14:22,356 WARN [Task Commit Thread] mapred.JobTracker$TaskCommitQueue(2032): Task Commit Thread exiting... [junit] 2007-12-17 13:14:23,234 DEBUG [RegionServer:0.cacheFlusher] hbase.HRegion(837): Started memcache flush for region result_table,,1197897252182. Size 306.0 [junit] 2007-12-17 13:14:23,437 DEBUG [RegionServer:0.cacheFlusher] hbase.HStore(969): Added 1987603939/e/5401399114053385601 with sequence id 54 and size 212.0 for result_table,,1197897252182/e [junit] 2007-12-17 13:14:23,481 DEBUG [RegionServer:0.cacheFlusher] hbase.HStore(969): Added 1987603939/d/686156171825494110 with sequence id 54 and size 212.0 for result_table,,1197897252182/d [junit] 2007-12-17 13:14:23,536 DEBUG [RegionServer:0.cacheFlusher] hbase.HStore(969): Added 1987603939/a/2849024392948606825 with sequence id 54 and size 206.0 for result_table,,1197897252182/a [junit] 2007-12-17 13:14:23,586 DEBUG [RegionServer:0.cacheFlusher] hbase.HStore(969): Added 1987603939/b/1325333232192358463 with sequence id 54 and size 206.0 for result_table,,1197897252182/b [junit] 2007-12-17 13:14:24,034 DEBUG [RegionServer:0.cacheFlusher] hbase.HStore(969): Added 1987603939/c/691907286132866123 with sequence id 54 and size 230.0 for result_table,,1197897252182/c [junit] 2007-12-17 13:14:24,035 DEBUG [RegionServer:0.cacheFlusher] hbase.HRegion(943): Finished memcache flush for region result_table,,1197897252182 in 801ms, sequenceid=54 [junit] 2007-12-17 13:14:24,035 DEBUG [RegionServer:0.compactor] hbase.HStore(993): compaction for HStore result_table,,1197897252182/e not needed. [junit] 2007-12-17 13:14:24,036 DEBUG [RegionServer:0.compactor] hbase.HStore(993): compaction for HStore result_table,,1197897252182/d not needed. [junit] 2007-12-17 13:14:24,036 DEBUG [RegionServer:0.compactor] hbase.HStore(993): compaction for HStore result_table,,1197897252182/a not needed. [junit] 2007-12-17 13:14:24,036 DEBUG [RegionServer:0.compactor] hbase.HStore(993): compaction for HStore result_table,,1197897252182/b not needed. [junit] 2007-12-17 13:14:24,036 DEBUG [RegionServer:0.compactor] hbase.HStore(993): compaction for HStore result_table,,1197897252182/c not needed. [junit] 2007-12-17 13:14:24,037 DEBUG [RegionServer:0.compactor] hbase.HRegion(707): region result_table,,1197897252182 does not need compaction [junit] 2007-12-17 13:14:29,133 INFO [HMaster.rootScanner] hbase.HMaster$BaseScanner(211): HMaster.rootScanner scanning meta region regionname: -ROOT-,,0, startKey: <>, server: 140.211.11.75:47023} [junit] 2007-12-17 13:14:29,158 DEBUG [HMaster.rootScanner] hbase.HMaster$BaseScanner(247): HMaster.rootScanner regioninfo: {regionname: .META.,,1, startKey: <>, encodedName(1028785192) tableDesc: {name: .META., families: {info:={name: info, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}}, server: 140.211.11.75:47023, startCode: 1197897237977 [junit] 2007-12-17 13:14:29,160 INFO [HMaster.rootScanner] hbase.HMaster$BaseScanner(293): HMaster.rootScanner scan of meta region regionname: -ROOT-,,0, startKey: <>, server: 140.211.11.75:47023} complete [junit] 2007-12-17 13:14:31,113 INFO [HMaster.metaScanner] hbase.HMaster$BaseScanner(211): HMaster.metaScanner scanning meta region regionname: .META.,,1, startKey: <>, server: 140.211.11.75:47023} [junit] 2007-12-17 13:14:31,133 DEBUG [HMaster.metaScanner] hbase.HMaster$BaseScanner(247): HMaster.metaScanner regioninfo: {regionname: r1,,1197897237999, startKey: <>, encodedName(1061212237) tableDesc: {name: r1, families: {a:={name: a, max versions: 3, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, b:={name: b, max versions: 3, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, c:={name: c, max versions: 3, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}}, server: 140.211.11.75:47023, startCode: 1197897237977 [junit] 2007-12-17 13:14:31,135 DEBUG [HMaster.metaScanner] hbase.HMaster$BaseScanner(247): HMaster.metaScanner regioninfo: {regionname: r2,,1197897246655, startKey: <>, encodedName(2124584548) tableDesc: {name: r2, families: {d:={name: d, max versions: 3, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, e:={name: e, max versions: 3, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}}, server: 140.211.11.75:47023, startCode: 1197897237977 [junit] 2007-12-17 13:14:31,138 DEBUG [HMaster.metaScanner] hbase.HMaster$BaseScanner(247): HMaster.metaScanner regioninfo: {regionname: result_table,,1197897252182, startKey: <>, encodedName(1987603939) tableDesc: {name: result_table, families: {a:={name: a, max versions: 3, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, b:={name: b, max versions: 3, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, c:={name: c, max versions: 3, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, d:={name: d, max versions: 3, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, e:={name: e, max versions: 3, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}}, server: 140.211.11.75:47023, startCode: 1197897237977 [junit] 2007-12-17 13:14:31,140 INFO [HMaster.metaScanner] hbase.HMaster$BaseScanner(293): HMaster.metaScanner scan of meta region regionname: .META.,,1, startKey: <>, server: 140.211.11.75:47023} complete [junit] 2007-12-17 13:14:31,145 INFO [HMaster.metaScanner] hbase.HMaster$MetaScanner(761): all meta regions scanned [junit] 2007-12-17 13:14:32,416 INFO [main] algebra.TestTableJoinMapReduce(239): result_table.column.size: 5 [junit] 2007-12-17 13:14:32,419 INFO [main] algebra.TestTableJoinMapReduce(239): result_table.column.size: 5 [junit] 2007-12-17 13:14:32,422 INFO [main] algebra.TestTableJoinMapReduce(239): result_table.column.size: 5 [junit] 2007-12-17 13:14:32,424 INFO [main] algebra.TestTableJoinMapReduce(244): result_table.row.count: 3 [junit] 2007-12-17 13:14:32,425 DEBUG [main] hbase.LocalHBaseCluster(212): Shutting down HBase Cluster [junit] 2007-12-17 13:14:32,426 INFO [main] hbase.HMaster(2524): Cluster shutdown requested. Starting to quiesce servers [junit] 2007-12-17 13:14:32,716 INFO [RegionServer:0] hbase.HRegionServer(774): Got quiesce server message [junit] 2007-12-17 13:14:32,716 INFO [RegionServer:0.worker] hbase.HRegionServer$Worker(1153): MSG_REGIONSERVER_QUIESCE : [junit] 2007-12-17 13:14:32,717 DEBUG [RegionServer:0.worker] hbase.HRegionServer(1295): closing region r1,,1197897237999 [junit] 2007-12-17 13:14:32,717 DEBUG [RegionServer:0.worker] hbase.HStore(879): closed r1,,1197897237999/a (1061212237/a) [junit] 2007-12-17 13:14:32,718 DEBUG [RegionServer:0.worker] hbase.HStore(879): closed r1,,1197897237999/b (1061212237/b) [junit] 2007-12-17 13:14:32,718 DEBUG [RegionServer:0.worker] hbase.HStore(879): closed r1,,1197897237999/c (1061212237/c) [junit] 2007-12-17 13:14:32,718 INFO [RegionServer:0.worker] hbase.HRegion(430): closed r1,,1197897237999 [junit] 2007-12-17 13:14:32,718 DEBUG [RegionServer:0.worker] hbase.HRegionServer(1295): closing region r2,,1197897246655 [junit] 2007-12-17 13:14:32,718 DEBUG [RegionServer:0.worker] hbase.HStore(879): closed r2,,1197897246655/e (2124584548/e) [junit] 2007-12-17 13:14:32,719 DEBUG [RegionServer:0.worker] hbase.HStore(879): closed r2,,1197897246655/d (2124584548/d) [junit] 2007-12-17 13:14:32,719 INFO [RegionServer:0.worker] hbase.HRegion(430): closed r2,,1197897246655 [junit] 2007-12-17 13:14:32,719 DEBUG [RegionServer:0.worker] hbase.HRegionServer(1295): closing region result_table,,1197897252182 [junit] 2007-12-17 13:14:32,719 DEBUG [RegionServer:0.worker] hbase.HStore(879): closed result_table,,1197897252182/e (1987603939/e) [junit] 2007-12-17 13:14:32,720 DEBUG [RegionServer:0.worker] hbase.HStore(879): closed result_table,,1197897252182/d (1987603939/d) [junit] 2007-12-17 13:14:32,720 DEBUG [RegionServer:0.worker] hbase.HStore(879): closed result_table,,1197897252182/a (1987603939/a) [junit] 2007-12-17 13:14:32,720 DEBUG [RegionServer:0.worker] hbase.HStore(879): closed result_table,,1197897252182/b (1987603939/b) [junit] 2007-12-17 13:14:32,721 DEBUG [RegionServer:0.worker] hbase.HStore(879): closed result_table,,1197897252182/c (1987603939/c) [junit] 2007-12-17 13:14:32,721 INFO [RegionServer:0.worker] hbase.HRegion(430): closed result_table,,1197897252182 [junit] 2007-12-17 13:14:33,724 INFO [IPC Server handler 3 on 60000] hbase.HMaster(1370): Region server 140.211.11.75:47023 quiesced [junit] 2007-12-17 13:14:33,725 INFO [IPC Server handler 3 on 60000] hbase.HMaster(1378): All user tables quiesced. Proceeding with shutdown [junit] 2007-12-17 13:14:33,725 DEBUG [IPC Server handler 3 on 60000] hbase.HMaster(1204): telling root scanner to stop [junit] 2007-12-17 13:14:33,725 DEBUG [IPC Server handler 3 on 60000] hbase.HMaster(1212): telling meta scanner to stop [junit] 2007-12-17 13:14:33,726 INFO [HMaster.rootScanner] hbase.Chore(66): HMaster.rootScanner exiting [junit] 2007-12-17 13:14:33,726 INFO [HMaster.metaScanner] hbase.Chore(66): HMaster.metaScanner exiting [junit] 2007-12-17 13:14:33,726 DEBUG [IPC Server handler 3 on 60000] hbase.HMaster(1220): meta and root scanners notified [junit] 2007-12-17 13:14:33,727 INFO [RegionServer:0] hbase.HRegionServer(768): Got regionserver stop message [junit] 2007-12-17 13:14:33,728 INFO [RegionServer:0] hbase.Leases(109): RegionServer:0 closing leases [junit] 2007-12-17 13:14:33,728 INFO [RegionServer:0.leaseChecker] hbase.Chore(66): RegionServer:0.leaseChecker exiting [junit] 2007-12-17 13:14:33,728 INFO [RegionServer:0] hbase.Leases(125): RegionServer:0 closed leases [junit] 2007-12-17 13:14:33,729 INFO [RegionServer:0.cacheFlusher] hbase.HRegionServer$Flusher(535): RegionServer:0.cacheFlusher exiting [junit] 2007-12-17 13:14:33,729 INFO [RegionServer:0.compactor] hbase.HRegionServer$Compactor(425): RegionServer:0.compactor exiting [junit] 2007-12-17 13:14:33,729 INFO [RegionServer:0.splitter] hbase.HRegionServer$Splitter(302): RegionServer:0.splitter exiting [junit] 2007-12-17 13:14:33,729 DEBUG [RegionServer:0] hbase.HRegionServer(1261): closing region -ROOT-,,0 [junit] 2007-12-17 13:14:33,731 DEBUG [RegionServer:0] hbase.HStore(879): closed -ROOT-,,0/info (70236052/info) [junit] 2007-12-17 13:14:33,731 INFO [RegionServer:0] hbase.HRegion(430): closed -ROOT-,,0 [junit] 2007-12-17 13:14:33,732 DEBUG [RegionServer:0] hbase.HRegionServer(1261): closing region .META.,,1 [junit] 2007-12-17 13:14:33,732 DEBUG [RegionServer:0] hbase.HStore(879): closed .META.,,1/info (1028785192/info) [junit] 2007-12-17 13:14:33,732 INFO [RegionServer:0] hbase.HRegion(430): closed .META.,,1 [junit] 2007-12-17 13:14:33,733 DEBUG [RegionServer:0] hbase.HLog(388): closing log writer in /hbase/log_140.211.11.75_1197897237977_47023 [junit] 2007-12-17 13:14:34,167 INFO [RegionServer:0] hbase.HRegionServer(888): telling master that region server is shutting down at: 140.211.11.75:47023 [junit] 2007-12-17 13:14:34,168 DEBUG [IPC Server handler 0 on 60000] hbase.HMaster(1337): Region server 140.211.11.75:47023: MSG_REPORT_EXITING -- cancelling lease [junit] 2007-12-17 13:14:34,169 INFO [IPC Server handler 0 on 60000] hbase.HMaster(1479): Cancelling lease for 140.211.11.75:47023 [junit] 2007-12-17 13:14:34,169 INFO [IPC Server handler 0 on 60000] hbase.HMaster(1344): Region server 140.211.11.75:47023: MSG_REPORT_EXITING -- lease cancelled [junit] 2007-12-17 13:14:34,169 INFO [RegionServer:0] hbase.HRegionServer(895): stopping server at: 140.211.11.75:47023 [junit] 2007-12-17 13:14:34,732 DEBUG [HMaster] hbase.HMaster(1204): telling root scanner to stop [junit] 2007-12-17 13:14:34,732 INFO [RegionServer:0.worker] hbase.HRegionServer$Worker(1202): worker thread exiting [junit] 2007-12-17 13:14:34,733 DEBUG [HMaster] hbase.HMaster(1212): telling meta scanner to stop [junit] 2007-12-17 13:14:34,733 DEBUG [HMaster] hbase.HMaster(1220): meta and root scanners notified [junit] 2007-12-17 13:14:34,733 INFO [RegionServer:0] hbase.HRegionServer(900): RegionServer:0 exiting [junit] 2007-12-17 13:14:34,734 INFO [HMaster] hbase.Leases(109): HMaster closing leases [junit] 2007-12-17 13:14:34,735 INFO [HMaster.leaseChecker] hbase.Chore(66): HMaster.leaseChecker exiting [junit] 2007-12-17 13:14:34,735 INFO [HMaster] hbase.Leases(125): HMaster closed leases [junit] 2007-12-17 13:14:34,736 INFO [HMaster] hbase.HMaster(1137): HMaster main thread exiting [junit] 2007-12-17 13:14:34,736 INFO [main] hbase.LocalHBaseCluster(238): Shutdown HMaster 1 region server(s) [junit] 2007-12-17 13:14:34,753 INFO [main] hbase.StaticTestEnvironment(133): Shutting down FileSystem [junit] 2007-12-17 13:14:35,742 INFO [main] hbase.StaticTestEnvironment(140): Shutting down Mini DFS [junit] Shutting down the Mini HDFS Cluster [junit] Shutting down DataNode 0 [junit] Tests run: 1, Failures: 0, Errors: 0, Time elapsed: 43.875 sec [junit] 2007-12-17 13:14:36,485 INFO [main] hbase.HRegionServer$ShutdownThread(151): Starting shutdown thread. [junit] 2007-12-17 13:14:36,485 INFO [main] hbase.HRegionServer$ShutdownThread(156): Shutdown thread complete [junit] Running org.apache.hadoop.hbase.util.TestBase64 [junit] Tests run: 1, Failures: 0, Errors: 0, Time elapsed: 0.233 sec [junit] Running org.apache.hadoop.hbase.util.TestKeying [junit] Original url http://abc:[EMAIL PROTECTED]/index.html?query=something#middle, Transformed url r:http://abc:[EMAIL PROTECTED]/index.html?query=something#middle [junit] Original url file:///usr/bin/java, Transformed url file:///usr/bin/java [junit] Original url dns:www.powerset.com, Transformed url dns:www.powerset.com [junit] Original url dns://dns.powerset.com/www.powerset.com, Transformed url r:dns://com.powerset.dns/www.powerset.com [junit] Original url http://one.two.three/index.html, Transformed url r:http://three.two.one/index.html [junit] Original url https://one.two.three:9443/index.html, Transformed url r:https://three.two.one:9443/index.html [junit] Original url ftp://one.two.three/index.html, Transformed url r:ftp://three.two.one/index.html [junit] Original url filename, Transformed url filename [junit] Tests run: 1, Failures: 0, Errors: 0, Time elapsed: 0.046 sec [junit] Running org.onelab.test.TestFilter [junit] Tests run: 3, Failures: 0, Errors: 0, Time elapsed: 0.058 sec BUILD FAILED http://lucene.zones.apache.org:8080/hudson/job/Hadoop-Nightly/ws/trunk/build.xml :515: The following error occurred while executing this line: http://lucene.zones.apache.org:8080/hudson/job/Hadoop-Nightly/ws/trunk/src/contrib/build.xml :31: The following error occurred while executing this line: http://lucene.zones.apache.org:8080/hudson/job/Hadoop-Nightly/ws/trunk/src/contrib/build-contrib.xml :206: Tests failed! Total time: 59 minutes 1 second Recording fingerprints Publishing Javadoc Recording test results