See http://lucene.zones.apache.org:8080/hudson/job/Hadoop-Nightly/353/changes
Changes: [acmurthy] Added missing attribution of HADOOP-2344 for Amar Kamat. [acmurthy] HADOOP-2344. Enhance the utility for executing shell commands to read the stdout/stderr streams while waiting for the command to finish (to free up the buffers). Also, this patch throws away stderr of the DF utility. @deprecated org.apache.hadoop.fs.ShellCommand for org.apache.hadoop.util.Shell org.apache.hadoop.util.ShellUtil for org.apache.hadoop.util.Shell.ShellCommandExecutor [dhruba] HADOOP-2492. Additional debugging in the rpc server to better diagnose ConcurrentModificationException. (dhruba) ------------------------------------------ [...truncated 51259 lines...] [junit] 2008-01-02 13:39:36,594 DEBUG [IPC Server handler 1 on 60000] hbase.HStore(601): starting r2,,1199281176236/e (195367671/e) (no reconstruction log) [junit] 2008-01-02 13:39:36,597 DEBUG [IPC Server handler 1 on 60000] hbase.HStore(629): maximum sequence id for hstore r2,,1199281176236/e (195367671/e) is -1 [junit] 2008-01-02 13:39:36,599 DEBUG [IPC Server handler 1 on 60000] hbase.HRegion(300): Next sequence id for region r2,,1199281176236 is 0 [junit] 2008-01-02 13:39:36,601 INFO [IPC Server handler 1 on 60000] hbase.HRegion(328): region r2,,1199281176236 available [junit] 2008-01-02 13:39:36,604 DEBUG [IPC Server handler 1 on 60000] hbase.HStore(880): closed r2,,1199281176236/e (195367671/e) [junit] 2008-01-02 13:39:36,605 DEBUG [IPC Server handler 1 on 60000] hbase.HStore(880): closed r2,,1199281176236/d (195367671/d) [junit] 2008-01-02 13:39:36,606 INFO [IPC Server handler 1 on 60000] hbase.HRegion(430): closed r2,,1199281176236 [junit] 2008-01-02 13:39:36,607 DEBUG [IPC Server handler 1 on 60000] hbase.HLog(399): closing log writer in /hbase/hregion_195367671/log [junit] 2008-01-02 13:39:36,731 INFO [IPC Server handler 1 on 60000] hbase.HMaster(2547): created table r2 [junit] 2008-01-02 13:39:36,733 DEBUG [main] hbase.HConnectionManager$TableServers(308): No servers for r2. Doing a find... [junit] 2008-01-02 13:39:36,738 DEBUG [main] hbase.HConnectionManager$TableServers(778): no server address for regionname: r2,,1199281176236, startKey: <>, encodedName(195367671) 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] 2008-01-02 13:39:36,739 DEBUG [main] hbase.HConnectionManager$TableServers(676): Sleeping. Table r2 not currently being served. [junit] 2008-01-02 13:39:37,465 INFO [IPC Server handler 2 on 60000] hbase.HMaster(1858): assigning region r2,,1199281176236 to the only server 140.211.11.75:52289 [junit] 2008-01-02 13:39:37,467 INFO [RegionServer:0.worker] hbase.HRegionServer$Worker(1153): MSG_REGION_OPEN : r2,,1199281176236 [junit] 2008-01-02 13:39:37,473 DEBUG [RegionServer:0.worker] hbase.HStore(601): starting r2,,1199281176236/d (195367671/d) (no reconstruction log) [junit] 2008-01-02 13:39:37,474 DEBUG [RegionServer:0.cacheFlusher] hbase.HRegion(837): Started memcache flush for region -ROOT-,,0. Size 92.0 [junit] 2008-01-02 13:39:37,478 DEBUG [RegionServer:0.worker] hbase.HStore(629): maximum sequence id for hstore r2,,1199281176236/d (195367671/d) is -1 [junit] 2008-01-02 13:39:37,485 DEBUG [RegionServer:0.worker] hbase.HStore(601): starting r2,,1199281176236/e (195367671/e) (no reconstruction log) [junit] 2008-01-02 13:39:37,488 DEBUG [RegionServer:0.worker] hbase.HStore(629): maximum sequence id for hstore r2,,1199281176236/e (195367671/e) is -1 [junit] 2008-01-02 13:39:37,489 DEBUG [RegionServer:0.worker] hbase.HRegion(300): Next sequence id for region r2,,1199281176236 is 0 [junit] 2008-01-02 13:39:37,490 INFO [RegionServer:0.worker] hbase.HRegion(328): region r2,,1199281176236 available [junit] 2008-01-02 13:39:38,005 DEBUG [RegionServer:0.cacheFlusher] hbase.HStore(972): Added 70236052/info/4306440574436419582 with 2 entries, sequence id 23, and size 230.0 for -ROOT-,,0/info [junit] 2008-01-02 13:39:38,006 DEBUG [RegionServer:0.cacheFlusher] hbase.HRegion(943): Finished memcache flush for region -ROOT-,,0 in 532ms, sequenceid=23 [junit] 2008-01-02 13:39:38,007 DEBUG [RegionServer:0.compactor] hbase.HStore(996): compaction for HStore -ROOT-,,0/info not needed. [junit] 2008-01-02 13:39:38,008 DEBUG [RegionServer:0.compactor] hbase.HRegion(707): region -ROOT-,,0 does not need compaction [junit] 2008-01-02 13:39:38,444 INFO [HMaster.rootScanner] hbase.HMaster$BaseScanner(211): HMaster.rootScanner scanning meta region {regionname: -ROOT-,,0, startKey: <>, server: 140.211.11.75:52289} [junit] 2008-01-02 13:39:38,475 DEBUG [IPC Server handler 4 on 60000] hbase.HMaster(1516): Received MSG_REPORT_PROCESS_OPEN : r2,,1199281176236 from 140.211.11.75:52289 [junit] 2008-01-02 13:39:38,477 DEBUG [IPC Server handler 4 on 60000] hbase.HMaster(1516): Received MSG_REPORT_OPEN : r2,,1199281176236 from 140.211.11.75:52289 [junit] 2008-01-02 13:39:38,477 INFO [IPC Server handler 4 on 60000] hbase.HMaster(1577): 140.211.11.75:52289 serving r2,,1199281176236 [junit] 2008-01-02 13:39:38,478 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:52289, startCode: 1199281167185 [junit] 2008-01-02 13:39:38,478 DEBUG [HMaster] hbase.HMaster(1055): Main processing loop: PendingOpenOperation from 140.211.11.75:52289 [junit] 2008-01-02 13:39:38,480 INFO [HMaster] hbase.HMaster$ProcessRegionOpen(2458): regionname: r2,,1199281176236, startKey: <>, encodedName(195367671) 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:52289 [junit] 2008-01-02 13:39:38,480 DEBUG [HMaster] hbase.HMaster$RegionServerOperation(1907): numberOfMetaRegions: 1, onlineMetaRegions.size(): 1 [junit] 2008-01-02 13:39:38,481 INFO [HMaster] hbase.HMaster$ProcessRegionOpen(2472): updating row r2,,1199281176236 in table .META.,,1 with startcode 1199281167185 and server 140.211.11.75:52289 [junit] 2008-01-02 13:39:38,483 INFO [HMaster.rootScanner] hbase.HMaster$BaseScanner(293): HMaster.rootScanner scan of meta region {regionname: -ROOT-,,0, startKey: <>, server: 140.211.11.75:52289} complete [junit] 2008-01-02 13:39:39,414 DEBUG [RegionServer:0.cacheFlusher] hbase.HRegion(837): Started memcache flush for region .META.,,1. Size 472.0 [junit] 2008-01-02 13:39:39,938 DEBUG [RegionServer:0.cacheFlusher] hbase.HStore(972): Added 1028785192/info/91662947690732964 with 6 entries, sequence id 26, and size 666.0 for .META.,,1/info [junit] 2008-01-02 13:39:39,939 DEBUG [RegionServer:0.cacheFlusher] hbase.HRegion(943): Finished memcache flush for region .META.,,1 in 525ms, sequenceid=26 [junit] 2008-01-02 13:39:39,941 DEBUG [RegionServer:0.compactor] hbase.HStore(996): compaction for HStore .META.,,1/info not needed. [junit] 2008-01-02 13:39:39,942 DEBUG [RegionServer:0.compactor] hbase.HRegion(707): region .META.,,1 does not need compaction [junit] 2008-01-02 13:39:40,424 INFO [HMaster.metaScanner] hbase.HMaster$BaseScanner(211): HMaster.metaScanner scanning meta region {regionname: .META.,,1, startKey: <>, server: 140.211.11.75:52289} [junit] 2008-01-02 13:39:40,452 DEBUG [HMaster.metaScanner] hbase.HMaster$BaseScanner(247): HMaster.metaScanner regioninfo: {regionname: r1,,1199281167218, startKey: <>, encodedName(1426859610) 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:52289, startCode: 1199281167185 [junit] 2008-01-02 13:39:40,456 DEBUG [HMaster.metaScanner] hbase.HMaster$BaseScanner(247): HMaster.metaScanner regioninfo: {regionname: r2,,1199281176236, startKey: <>, encodedName(195367671) 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:52289, startCode: 1199281167185 [junit] 2008-01-02 13:39:40,458 INFO [HMaster.metaScanner] hbase.HMaster$BaseScanner(293): HMaster.metaScanner scan of meta region {regionname: .META.,,1, startKey: <>, server: 140.211.11.75:52289} complete [junit] 2008-01-02 13:39:40,459 INFO [HMaster.metaScanner] hbase.HMaster$MetaScanner(763): all meta regions scanned [junit] 2008-01-02 13:39:41,444 DEBUG [RegionServer:0.cacheFlusher] hbase.HRegion(837): Started memcache flush for region r1,,1199281167218. Size 310.0 [junit] 2008-01-02 13:39:41,743 DEBUG [main] hbase.HConnectionManager$TableServers(685): Wake. Retry finding table r2 [junit] 2008-01-02 13:39:41,761 DEBUG [main] hbase.HConnectionManager$TableServers(728): Found 1 region(s) for r2 at address: 140.211.11.75:52289, 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] 2008-01-02 13:39:42,824 INFO [IPC Server handler 2 on 60000] hbase.HLog(313): new log writer created at /hbase/hregion_326816702/log/hlog.dat.000 [junit] 2008-01-02 13:39:43,600 DEBUG [IPC Server handler 2 on 60000] hbase.HStore(601): starting result_table,,1199281181768/a (326816702/a) (no reconstruction log) [junit] 2008-01-02 13:39:43,608 DEBUG [IPC Server handler 2 on 60000] hbase.HStore(629): maximum sequence id for hstore result_table,,1199281181768/a (326816702/a) is -1 [junit] 2008-01-02 13:39:43,924 DEBUG [RegionServer:0.cacheFlusher] hbase.HStore(972): Added 1426859610/a/6276154632038349785 with 5 entries, sequence id 27, and size 270.0 for r1,,1199281167218/a [junit] 2008-01-02 13:39:44,113 DEBUG [IPC Server handler 2 on 60000] hbase.HStore(601): starting result_table,,1199281181768/b (326816702/b) (no reconstruction log) [junit] 2008-01-02 13:39:44,116 DEBUG [IPC Server handler 2 on 60000] hbase.HStore(629): maximum sequence id for hstore result_table,,1199281181768/b (326816702/b) is -1 [junit] 2008-01-02 13:39:44,395 DEBUG [IPC Server handler 2 on 60000] hbase.HStore(601): starting result_table,,1199281181768/c (326816702/c) (no reconstruction log) [junit] 2008-01-02 13:39:44,397 DEBUG [IPC Server handler 2 on 60000] hbase.HStore(629): maximum sequence id for hstore result_table,,1199281181768/c (326816702/c) is -1 [junit] 2008-01-02 13:39:44,570 DEBUG [IPC Server handler 2 on 60000] hbase.HStore(601): starting result_table,,1199281181768/d (326816702/d) (no reconstruction log) [junit] 2008-01-02 13:39:44,572 DEBUG [IPC Server handler 2 on 60000] hbase.HStore(629): maximum sequence id for hstore result_table,,1199281181768/d (326816702/d) is -1 [junit] 2008-01-02 13:39:44,653 DEBUG [IPC Server handler 2 on 60000] hbase.HStore(601): starting result_table,,1199281181768/e (326816702/e) (no reconstruction log) [junit] 2008-01-02 13:39:44,656 DEBUG [IPC Server handler 2 on 60000] hbase.HStore(629): maximum sequence id for hstore result_table,,1199281181768/e (326816702/e) is -1 [junit] 2008-01-02 13:39:44,657 DEBUG [IPC Server handler 2 on 60000] hbase.HRegion(300): Next sequence id for region result_table,,1199281181768 is 0 [junit] 2008-01-02 13:39:44,658 INFO [IPC Server handler 2 on 60000] hbase.HRegion(328): region result_table,,1199281181768 available [junit] 2008-01-02 13:39:44,661 DEBUG [IPC Server handler 2 on 60000] hbase.HStore(880): closed result_table,,1199281181768/e (326816702/e) [junit] 2008-01-02 13:39:44,661 DEBUG [IPC Server handler 2 on 60000] hbase.HStore(880): closed result_table,,1199281181768/d (326816702/d) [junit] 2008-01-02 13:39:44,662 DEBUG [IPC Server handler 2 on 60000] hbase.HStore(880): closed result_table,,1199281181768/a (326816702/a) [junit] 2008-01-02 13:39:44,662 DEBUG [IPC Server handler 2 on 60000] hbase.HStore(880): closed result_table,,1199281181768/b (326816702/b) [junit] 2008-01-02 13:39:44,662 DEBUG [IPC Server handler 2 on 60000] hbase.HStore(880): closed result_table,,1199281181768/c (326816702/c) [junit] 2008-01-02 13:39:44,663 INFO [IPC Server handler 2 on 60000] hbase.HRegion(430): closed result_table,,1199281181768 [junit] 2008-01-02 13:39:44,663 DEBUG [IPC Server handler 2 on 60000] hbase.HLog(399): closing log writer in /hbase/hregion_326816702/log [junit] 2008-01-02 13:39:44,795 INFO [IPC Server handler 2 on 60000] hbase.HMaster(2547): created table result_table [junit] 2008-01-02 13:39:44,796 DEBUG [main] hbase.HConnectionManager$TableServers(308): No servers for result_table. Doing a find... [junit] 2008-01-02 13:39:44,811 DEBUG [main] hbase.HConnectionManager$TableServers(778): no server address for regionname: result_table,,1199281181768, startKey: <>, encodedName(326816702) 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] 2008-01-02 13:39:44,812 DEBUG [main] hbase.HConnectionManager$TableServers(676): Sleeping. Table result_table not currently being served. [junit] 2008-01-02 13:39:45,290 DEBUG [RegionServer:0.cacheFlusher] hbase.HStore(972): Added 1426859610/b/4486848146279812977 with 5 entries, sequence id 27, and size 270.0 for r1,,1199281167218/b [junit] 2008-01-02 13:39:45,544 INFO [IPC Server handler 1 on 60000] hbase.HMaster(1858): assigning region result_table,,1199281181768 to the only server 140.211.11.75:52289 [junit] 2008-01-02 13:39:45,545 INFO [RegionServer:0.worker] hbase.HRegionServer$Worker(1153): MSG_REGION_OPEN : result_table,,1199281181768 [junit] 2008-01-02 13:39:45,549 DEBUG [RegionServer:0.worker] hbase.HStore(601): starting result_table,,1199281181768/a (326816702/a) (no reconstruction log) [junit] 2008-01-02 13:39:45,551 DEBUG [RegionServer:0.worker] hbase.HStore(629): maximum sequence id for hstore result_table,,1199281181768/a (326816702/a) is -1 [junit] 2008-01-02 13:39:45,558 DEBUG [RegionServer:0.worker] hbase.HStore(601): starting result_table,,1199281181768/b (326816702/b) (no reconstruction log) [junit] 2008-01-02 13:39:45,560 DEBUG [RegionServer:0.worker] hbase.HStore(629): maximum sequence id for hstore result_table,,1199281181768/b (326816702/b) is -1 [junit] 2008-01-02 13:39:45,566 DEBUG [RegionServer:0.worker] hbase.HStore(601): starting result_table,,1199281181768/c (326816702/c) (no reconstruction log) [junit] 2008-01-02 13:39:45,569 DEBUG [RegionServer:0.worker] hbase.HStore(629): maximum sequence id for hstore result_table,,1199281181768/c (326816702/c) is -1 [junit] 2008-01-02 13:39:45,576 DEBUG [RegionServer:0.worker] hbase.HStore(601): starting result_table,,1199281181768/d (326816702/d) (no reconstruction log) [junit] 2008-01-02 13:39:45,578 DEBUG [RegionServer:0.worker] hbase.HStore(629): maximum sequence id for hstore result_table,,1199281181768/d (326816702/d) is -1 [junit] 2008-01-02 13:39:45,583 DEBUG [RegionServer:0.worker] hbase.HStore(601): starting result_table,,1199281181768/e (326816702/e) (no reconstruction log) [junit] 2008-01-02 13:39:45,585 DEBUG [RegionServer:0.worker] hbase.HStore(629): maximum sequence id for hstore result_table,,1199281181768/e (326816702/e) is -1 [junit] 2008-01-02 13:39:45,587 DEBUG [RegionServer:0.worker] hbase.HRegion(300): Next sequence id for region result_table,,1199281181768 is 0 [junit] 2008-01-02 13:39:45,589 INFO [RegionServer:0.worker] hbase.HRegion(328): region result_table,,1199281181768 available [junit] 2008-01-02 13:39:45,735 DEBUG [RegionServer:0.cacheFlusher] hbase.HStore(972): Added 1426859610/c/6572207897595388638 with 5 entries, sequence id 27, and size 310.0 for r1,,1199281167218/c [junit] 2008-01-02 13:39:45,736 DEBUG [RegionServer:0.cacheFlusher] hbase.HRegion(943): Finished memcache flush for region r1,,1199281167218 in 4292ms, sequenceid=27 [junit] 2008-01-02 13:39:45,736 DEBUG [RegionServer:0.compactor] hbase.HStore(996): compaction for HStore r1,,1199281167218/a not needed. [junit] 2008-01-02 13:39:45,737 DEBUG [RegionServer:0.compactor] hbase.HStore(996): compaction for HStore r1,,1199281167218/b not needed. [junit] 2008-01-02 13:39:45,737 DEBUG [RegionServer:0.compactor] hbase.HStore(996): compaction for HStore r1,,1199281167218/c not needed. [junit] 2008-01-02 13:39:45,738 DEBUG [RegionServer:0.compactor] hbase.HRegion(707): region r1,,1199281167218 does not need compaction [junit] 2008-01-02 13:39:46,555 DEBUG [IPC Server handler 4 on 60000] hbase.HMaster(1516): Received MSG_REPORT_PROCESS_OPEN : result_table,,1199281181768 from 140.211.11.75:52289 [junit] 2008-01-02 13:39:46,555 DEBUG [IPC Server handler 4 on 60000] hbase.HMaster(1516): Received MSG_REPORT_OPEN : result_table,,1199281181768 from 140.211.11.75:52289 [junit] 2008-01-02 13:39:46,555 INFO [IPC Server handler 4 on 60000] hbase.HMaster(1577): 140.211.11.75:52289 serving result_table,,1199281181768 [junit] 2008-01-02 13:39:46,556 DEBUG [HMaster] hbase.HMaster(1055): Main processing loop: PendingOpenOperation from 140.211.11.75:52289 [junit] 2008-01-02 13:39:46,557 INFO [HMaster] hbase.HMaster$ProcessRegionOpen(2458): regionname: result_table,,1199281181768, startKey: <>, encodedName(326816702) 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:52289 [junit] 2008-01-02 13:39:46,557 DEBUG [HMaster] hbase.HMaster$RegionServerOperation(1907): numberOfMetaRegions: 1, onlineMetaRegions.size(): 1 [junit] 2008-01-02 13:39:46,557 INFO [HMaster] hbase.HMaster$ProcessRegionOpen(2472): updating row result_table,,1199281181768 in table .META.,,1 with startcode 1199281167185 and server 140.211.11.75:52289 [junit] 2008-01-02 13:39:47,493 DEBUG [RegionServer:0.cacheFlusher] hbase.HRegion(837): Started memcache flush for region r2,,1199281176236. Size 132.0 [junit] 2008-01-02 13:39:47,926 DEBUG [RegionServer:0.cacheFlusher] hbase.HStore(972): Added 195367671/e/3101153976359177550 with 3 entries, sequence id 37, and size 218.0 for r2,,1199281176236/e [junit] 2008-01-02 13:39:48,453 INFO [HMaster.rootScanner] hbase.HMaster$BaseScanner(211): HMaster.rootScanner scanning meta region {regionname: -ROOT-,,0, startKey: <>, server: 140.211.11.75:52289} [junit] 2008-01-02 13:39:48,509 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:52289, startCode: 1199281167185 [junit] 2008-01-02 13:39:48,513 INFO [HMaster.rootScanner] hbase.HMaster$BaseScanner(293): HMaster.rootScanner scan of meta region {regionname: -ROOT-,,0, startKey: <>, server: 140.211.11.75:52289} complete [junit] 2008-01-02 13:39:48,897 DEBUG [RegionServer:0.cacheFlusher] hbase.HStore(972): Added 195367671/d/7980928966242705583 with 3 entries, sequence id 37, and size 218.0 for r2,,1199281176236/d [junit] 2008-01-02 13:39:48,898 DEBUG [RegionServer:0.cacheFlusher] hbase.HRegion(943): Finished memcache flush for region r2,,1199281176236 in 1405ms, sequenceid=37 [junit] 2008-01-02 13:39:48,898 DEBUG [RegionServer:0.compactor] hbase.HStore(996): compaction for HStore r2,,1199281176236/e not needed. [junit] 2008-01-02 13:39:48,898 DEBUG [RegionServer:0.compactor] hbase.HStore(996): compaction for HStore r2,,1199281176236/d not needed. [junit] 2008-01-02 13:39:48,899 DEBUG [RegionServer:0.compactor] hbase.HRegion(707): region r2,,1199281176236 does not need compaction [junit] 2008-01-02 13:39:49,813 DEBUG [main] hbase.HConnectionManager$TableServers(685): Wake. Retry finding table result_table [junit] 2008-01-02 13:39:49,830 DEBUG [main] hbase.HConnectionManager$TableServers(728): Found 1 region(s) for result_table at address: 140.211.11.75:52289, 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] 2008-01-02 13:39:49,943 DEBUG [RegionServer:0.cacheFlusher] hbase.HRegion(837): Started memcache flush for region .META.,,1. Size 331.0 [junit] 2008-01-02 13:39:50,129 WARN [IPC Server handler 1 on 52242] dfs.FSDirectory(400): DIR* FSDirectory.unprotectedDelete: failed to remove /user/hudson/build/contrib/hbase/test/system because it does not exist [junit] 2008-01-02 13:39:50,433 INFO [HMaster.metaScanner] hbase.HMaster$BaseScanner(211): HMaster.metaScanner scanning meta region {regionname: .META.,,1, startKey: <>, server: 140.211.11.75:52289} [junit] 2008-01-02 13:39:50,447 DEBUG [HMaster.metaScanner] hbase.HMaster$BaseScanner(247): HMaster.metaScanner regioninfo: {regionname: r1,,1199281167218, startKey: <>, encodedName(1426859610) 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:52289, startCode: 1199281167185 [junit] 2008-01-02 13:39:50,449 DEBUG [HMaster.metaScanner] hbase.HMaster$BaseScanner(247): HMaster.metaScanner regioninfo: {regionname: r2,,1199281176236, startKey: <>, encodedName(195367671) 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:52289, startCode: 1199281167185 [junit] 2008-01-02 13:39:50,451 INFO [HMaster.metaScanner] hbase.HMaster$BaseScanner(293): HMaster.metaScanner scan of meta region {regionname: .META.,,1, startKey: <>, server: 140.211.11.75:52289} complete [junit] 2008-01-02 13:39:50,452 INFO [HMaster.metaScanner] hbase.HMaster$MetaScanner(763): all meta regions scanned [junit] 2008-01-02 13:39:50,977 DEBUG [RegionServer:0.cacheFlusher] hbase.HStore(972): Added 1028785192/info/7178006554177543494 with 3 entries, sequence id 38, and size 483.0 for .META.,,1/info [junit] 2008-01-02 13:39:50,978 DEBUG [RegionServer:0.cacheFlusher] hbase.HRegion(943): Finished memcache flush for region .META.,,1 in 1035ms, sequenceid=38 [junit] 2008-01-02 13:39:50,978 DEBUG [RegionServer:0.compactor] hbase.HStore(996): compaction for HStore .META.,,1/info not needed. [junit] 2008-01-02 13:39:50,979 DEBUG [RegionServer:0.compactor] hbase.HRegion(707): region .META.,,1 does not need compaction [junit] 2008-01-02 13:39:51,980 WARN [IPC Server handler 6 on 52242] 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] 2008-01-02 13:39:51,981 WARN [main] mapred.JobClient(496): No job jar file set. User classes may not be found. See JobConf(Class) or JobConf#setJar(String). [junit] 2008-01-02 13:39:52,034 DEBUG [main] hbase.HConnectionManager$TableServers(308): No servers for r1. Doing a find... [junit] 2008-01-02 13:39:52,059 DEBUG [main] hbase.HConnectionManager$TableServers(759): Found 1 servers for table r1 [junit] 2008-01-02 13:39:52,096 DEBUG [main] mapred.TableInputFormat(175): split: 0->r1,, [junit] 2008-01-02 13:39:52,711 DEBUG [Thread-204] mapred.TableInputFormat(175): split: 0->r1,, [junit] 2008-01-02 13:39:52,859 DEBUG [Thread-204] hbase.HConnectionManager$TableServers(308): No servers for r2. Doing a find... [junit] 2008-01-02 13:39:52,892 DEBUG [Thread-204] hbase.HConnectionManager$TableServers(759): Found 1 servers for table r2 [junit] 2008-01-02 13:39:55,016 WARN [Task Commit Thread] mapred.JobTracker$TaskCommitQueue(2032): Task Commit Thread exiting... [junit] 2008-01-02 13:39:55,592 DEBUG [RegionServer:0.cacheFlusher] hbase.HRegion(837): Started memcache flush for region result_table,,1199281181768. Size 306.0 [junit] 2008-01-02 13:39:56,985 DEBUG [RegionServer:0.cacheFlusher] hbase.HStore(972): Added 326816702/e/493596157583612290 with 3 entries, sequence id 54, and size 212.0 for result_table,,1199281181768/e [junit] 2008-01-02 13:39:57,986 DEBUG [RegionServer:0.cacheFlusher] hbase.HStore(972): Added 326816702/d/1363113781485101250 with 3 entries, sequence id 54, and size 212.0 for result_table,,1199281181768/d [junit] 2008-01-02 13:39:58,462 INFO [HMaster.rootScanner] hbase.HMaster$BaseScanner(211): HMaster.rootScanner scanning meta region {regionname: -ROOT-,,0, startKey: <>, server: 140.211.11.75:52289} [junit] 2008-01-02 13:39:58,491 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:52289, startCode: 1199281167185 [junit] 2008-01-02 13:39:58,494 INFO [HMaster.rootScanner] hbase.HMaster$BaseScanner(293): HMaster.rootScanner scan of meta region {regionname: -ROOT-,,0, startKey: <>, server: 140.211.11.75:52289} complete [junit] 2008-01-02 13:39:58,657 DEBUG [RegionServer:0.cacheFlusher] hbase.HStore(972): Added 326816702/a/8442079636926915353 with 3 entries, sequence id 54, and size 206.0 for result_table,,1199281181768/a [junit] 2008-01-02 13:39:59,256 DEBUG [RegionServer:0.cacheFlusher] hbase.HStore(972): Added 326816702/b/4777187673889836021 with 3 entries, sequence id 54, and size 206.0 for result_table,,1199281181768/b [junit] 2008-01-02 13:39:59,887 DEBUG [RegionServer:0.cacheFlusher] hbase.HStore(972): Added 326816702/c/3292054299989590801 with 3 entries, sequence id 54, and size 230.0 for result_table,,1199281181768/c [junit] 2008-01-02 13:39:59,887 DEBUG [RegionServer:0.cacheFlusher] hbase.HRegion(943): Finished memcache flush for region result_table,,1199281181768 in 4295ms, sequenceid=54 [junit] 2008-01-02 13:39:59,888 DEBUG [RegionServer:0.compactor] hbase.HStore(996): compaction for HStore result_table,,1199281181768/e not needed. [junit] 2008-01-02 13:39:59,889 DEBUG [RegionServer:0.compactor] hbase.HStore(996): compaction for HStore result_table,,1199281181768/d not needed. [junit] 2008-01-02 13:39:59,890 DEBUG [RegionServer:0.compactor] hbase.HStore(996): compaction for HStore result_table,,1199281181768/a not needed. [junit] 2008-01-02 13:39:59,890 DEBUG [RegionServer:0.compactor] hbase.HStore(996): compaction for HStore result_table,,1199281181768/b not needed. [junit] 2008-01-02 13:39:59,891 DEBUG [RegionServer:0.compactor] hbase.HStore(996): compaction for HStore result_table,,1199281181768/c not needed. [junit] 2008-01-02 13:39:59,891 DEBUG [RegionServer:0.compactor] hbase.HRegion(707): region result_table,,1199281181768 does not need compaction [junit] 2008-01-02 13:40:00,442 INFO [HMaster.metaScanner] hbase.HMaster$BaseScanner(211): HMaster.metaScanner scanning meta region {regionname: .META.,,1, startKey: <>, server: 140.211.11.75:52289} [junit] 2008-01-02 13:40:00,478 DEBUG [HMaster.metaScanner] hbase.HMaster$BaseScanner(247): HMaster.metaScanner regioninfo: {regionname: r1,,1199281167218, startKey: <>, encodedName(1426859610) 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:52289, startCode: 1199281167185 [junit] 2008-01-02 13:40:00,483 DEBUG [HMaster.metaScanner] hbase.HMaster$BaseScanner(247): HMaster.metaScanner regioninfo: {regionname: r2,,1199281176236, startKey: <>, encodedName(195367671) 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:52289, startCode: 1199281167185 [junit] 2008-01-02 13:40:00,486 DEBUG [HMaster.metaScanner] hbase.HMaster$BaseScanner(247): HMaster.metaScanner regioninfo: {regionname: result_table,,1199281181768, startKey: <>, encodedName(326816702) 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:52289, startCode: 1199281167185 [junit] 2008-01-02 13:40:00,489 INFO [HMaster.metaScanner] hbase.HMaster$BaseScanner(293): HMaster.metaScanner scan of meta region {regionname: .META.,,1, startKey: <>, server: 140.211.11.75:52289} complete [junit] 2008-01-02 13:40:00,490 INFO [HMaster.metaScanner] hbase.HMaster$MetaScanner(763): all meta regions scanned [junit] 2008-01-02 13:40:05,101 INFO [main] algebra.TestTableJoinMapReduce(239): result_table.column.size: 5 [junit] 2008-01-02 13:40:05,104 INFO [main] algebra.TestTableJoinMapReduce(239): result_table.column.size: 5 [junit] 2008-01-02 13:40:05,106 INFO [main] algebra.TestTableJoinMapReduce(239): result_table.column.size: 5 [junit] 2008-01-02 13:40:05,109 INFO [main] algebra.TestTableJoinMapReduce(244): result_table.row.count: 3 [junit] 2008-01-02 13:40:05,110 DEBUG [main] hbase.LocalHBaseCluster(212): Shutting down HBase Cluster [junit] 2008-01-02 13:40:05,111 INFO [main] hbase.HMaster(2526): Cluster shutdown requested. Starting to quiesce servers [junit] 2008-01-02 13:40:05,764 INFO [RegionServer:0] hbase.HRegionServer(774): Got quiesce server message [junit] 2008-01-02 13:40:05,765 INFO [RegionServer:0.worker] hbase.HRegionServer$Worker(1153): MSG_REGIONSERVER_QUIESCE : [junit] 2008-01-02 13:40:05,766 DEBUG [RegionServer:0.worker] hbase.HRegionServer(1295): closing region r1,,1199281167218 [junit] 2008-01-02 13:40:05,766 DEBUG [RegionServer:0.worker] hbase.HStore(880): closed r1,,1199281167218/a (1426859610/a) [junit] 2008-01-02 13:40:05,767 DEBUG [RegionServer:0.worker] hbase.HStore(880): closed r1,,1199281167218/b (1426859610/b) [junit] 2008-01-02 13:40:05,767 DEBUG [RegionServer:0.worker] hbase.HStore(880): closed r1,,1199281167218/c (1426859610/c) [junit] 2008-01-02 13:40:05,768 INFO [RegionServer:0.worker] hbase.HRegion(430): closed r1,,1199281167218 [junit] 2008-01-02 13:40:05,768 DEBUG [RegionServer:0.worker] hbase.HRegionServer(1295): closing region r2,,1199281176236 [junit] 2008-01-02 13:40:05,769 DEBUG [RegionServer:0.worker] hbase.HStore(880): closed r2,,1199281176236/e (195367671/e) [junit] 2008-01-02 13:40:05,769 DEBUG [RegionServer:0.worker] hbase.HStore(880): closed r2,,1199281176236/d (195367671/d) [junit] 2008-01-02 13:40:05,770 INFO [RegionServer:0.worker] hbase.HRegion(430): closed r2,,1199281176236 [junit] 2008-01-02 13:40:05,770 DEBUG [RegionServer:0.worker] hbase.HRegionServer(1295): closing region result_table,,1199281181768 [junit] 2008-01-02 13:40:05,771 DEBUG [RegionServer:0.worker] hbase.HStore(880): closed result_table,,1199281181768/e (326816702/e) [junit] 2008-01-02 13:40:05,772 DEBUG [RegionServer:0.worker] hbase.HStore(880): closed result_table,,1199281181768/d (326816702/d) [junit] 2008-01-02 13:40:05,773 DEBUG [RegionServer:0.worker] hbase.HStore(880): closed result_table,,1199281181768/a (326816702/a) [junit] 2008-01-02 13:40:05,773 DEBUG [RegionServer:0.worker] hbase.HStore(880): closed result_table,,1199281181768/b (326816702/b) [junit] 2008-01-02 13:40:05,774 DEBUG [RegionServer:0.worker] hbase.HStore(880): closed result_table,,1199281181768/c (326816702/c) [junit] 2008-01-02 13:40:05,774 INFO [RegionServer:0.worker] hbase.HRegion(430): closed result_table,,1199281181768 [junit] 2008-01-02 13:40:06,773 INFO [IPC Server handler 4 on 60000] hbase.HMaster(1372): Region server 140.211.11.75:52289 quiesced [junit] 2008-01-02 13:40:06,774 INFO [IPC Server handler 4 on 60000] hbase.HMaster(1380): All user tables quiesced. Proceeding with shutdown [junit] 2008-01-02 13:40:06,774 DEBUG [IPC Server handler 4 on 60000] hbase.HMaster(1206): telling root scanner to stop [junit] 2008-01-02 13:40:06,775 DEBUG [IPC Server handler 4 on 60000] hbase.HMaster(1214): telling meta scanner to stop [junit] 2008-01-02 13:40:06,775 INFO [HMaster.rootScanner] hbase.Chore(66): HMaster.rootScanner exiting [junit] 2008-01-02 13:40:06,775 INFO [HMaster.metaScanner] hbase.Chore(66): HMaster.metaScanner exiting [junit] 2008-01-02 13:40:06,775 DEBUG [IPC Server handler 4 on 60000] hbase.HMaster(1222): meta and root scanners notified [junit] 2008-01-02 13:40:06,778 INFO [RegionServer:0] hbase.HRegionServer(768): Got regionserver stop message [junit] 2008-01-02 13:40:06,778 INFO [RegionServer:0] hbase.Leases(109): RegionServer:0 closing leases [junit] 2008-01-02 13:40:06,779 INFO [RegionServer:0.leaseChecker] hbase.Chore(66): RegionServer:0.leaseChecker exiting [junit] 2008-01-02 13:40:06,779 INFO [RegionServer:0] hbase.Leases(125): RegionServer:0 closed leases [junit] 2008-01-02 13:40:06,780 INFO [RegionServer:0.cacheFlusher] hbase.HRegionServer$Flusher(535): RegionServer:0.cacheFlusher exiting [junit] 2008-01-02 13:40:06,782 INFO [RegionServer:0.worker] hbase.HRegionServer$Worker(1202): worker thread exiting [junit] 2008-01-02 13:40:06,781 DEBUG [RegionServer:0] hbase.HRegionServer(1261): closing region -ROOT-,,0 [junit] 2008-01-02 13:40:06,782 INFO [RegionServer:0.splitter] hbase.HRegionServer$Splitter(302): RegionServer:0.splitter exiting [junit] 2008-01-02 13:40:06,784 DEBUG [RegionServer:0] hbase.HStore(880): closed -ROOT-,,0/info (70236052/info) [junit] 2008-01-02 13:40:06,781 INFO [RegionServer:0.compactor] hbase.HRegionServer$Compactor(425): RegionServer:0.compactor exiting [junit] 2008-01-02 13:40:06,785 INFO [RegionServer:0] hbase.HRegion(430): closed -ROOT-,,0 [junit] 2008-01-02 13:40:06,786 DEBUG [RegionServer:0] hbase.HRegionServer(1261): closing region .META.,,1 [junit] 2008-01-02 13:40:06,787 DEBUG [RegionServer:0] hbase.HStore(880): closed .META.,,1/info (1028785192/info) [junit] 2008-01-02 13:40:06,787 INFO [RegionServer:0] hbase.HRegion(430): closed .META.,,1 [junit] 2008-01-02 13:40:06,788 DEBUG [RegionServer:0] hbase.HLog(399): closing log writer in /hbase/log_140.211.11.75_1199281167185_52289 [junit] 2008-01-02 13:40:06,966 INFO [RegionServer:0] hbase.HRegionServer(888): telling master that region server is shutting down at: 140.211.11.75:52289 [junit] 2008-01-02 13:40:06,968 DEBUG [IPC Server handler 0 on 60000] hbase.HMaster(1339): Region server 140.211.11.75:52289: MSG_REPORT_EXITING -- cancelling lease [junit] 2008-01-02 13:40:06,969 INFO [IPC Server handler 0 on 60000] hbase.HMaster(1481): Cancelling lease for 140.211.11.75:52289 [junit] 2008-01-02 13:40:06,970 INFO [IPC Server handler 0 on 60000] hbase.HMaster(1346): Region server 140.211.11.75:52289: MSG_REPORT_EXITING -- lease cancelled [junit] 2008-01-02 13:40:06,970 INFO [RegionServer:0] hbase.HRegionServer(895): stopping server at: 140.211.11.75:52289 [junit] 2008-01-02 13:40:06,971 INFO [RegionServer:0] hbase.HRegionServer(900): RegionServer:0 exiting [junit] 2008-01-02 13:40:07,781 DEBUG [HMaster] hbase.HMaster(1206): telling root scanner to stop [junit] 2008-01-02 13:40:07,782 DEBUG [HMaster] hbase.HMaster(1214): telling meta scanner to stop [junit] 2008-01-02 13:40:07,783 DEBUG [HMaster] hbase.HMaster(1222): meta and root scanners notified [junit] 2008-01-02 13:40:07,783 INFO [HMaster] hbase.Leases(109): HMaster closing leases [junit] 2008-01-02 13:40:07,785 INFO [HMaster.leaseChecker] hbase.Chore(66): HMaster.leaseChecker exiting [junit] 2008-01-02 13:40:07,786 INFO [HMaster] hbase.Leases(125): HMaster closed leases [junit] 2008-01-02 13:40:07,787 INFO [HMaster] hbase.HMaster(1139): HMaster main thread exiting [junit] 2008-01-02 13:40:07,787 INFO [main] hbase.LocalHBaseCluster(238): Shutdown HMaster 1 region server(s) [junit] 2008-01-02 13:40:08,342 INFO [main] hbase.StaticTestEnvironment(133): Shutting down FileSystem [junit] 2008-01-02 13:40:08,421 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: 48.683 sec [junit] 2008-01-02 13:40:09,324 INFO [main] hbase.HRegionServer$ShutdownThread(151): Starting shutdown thread. [junit] 2008-01-02 13:40:09,325 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.314 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.059 sec [junit] Running org.onelab.test.TestFilter [junit] Tests run: 3, Failures: 0, Errors: 0, Time elapsed: 0.057 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: 130 minutes 59 seconds Recording fingerprints Publishing Javadoc Recording test results Updating HADOOP-2344 Updating HADOOP-2492