See <http://hudson.zones.apache.org/hudson/job/HBase-Patch/1116/changes>
Changes:
[apurtell] HBASE-2242 [EC2] Downgrade JDK to 1.6.0u17
------------------------------------------
[...truncated 136429 lines...]
[junit] 10/02/20 05:54:24 INFO zookeeper.ClientCnxn: Priming connection to
java.nio.channels.SocketChannel[connected local=/127.0.0.1:50057
remote=localhost/127.0.0.1:21810]
[junit] 10/02/20 05:54:24 INFO zookeeper.ClientCnxn: Server connection
successful
[junit] 10/02/20 05:54:24 INFO server.NIOServerCnxn: Connected to
/127.0.0.1:50057 lastZxid 0
[junit] 10/02/20 05:54:24 INFO server.NIOServerCnxn: Creating new session
0x126e9f0e5820002
[junit] 10/02/20 05:54:24 INFO server.NIOServerCnxn: Finished init of
0x126e9f0e5820002 valid:true
[junit] 10/02/20 05:54:25 INFO master.ServerManager: Received start message
from: vesta.apache.org,35043,1266645264944
[junit] 10/02/20 05:54:25 WARN conf.Configuration: fs.default.name is
deprecated. Instead, use fs.defaultFS
[junit] 10/02/20 05:54:25 WARN conf.Configuration: fs.default.name is
deprecated. Instead, use fs.defaultFS
[junit] 10/02/20 05:54:25 INFO regionserver.HRegionServer: Master passed us
address to use. Was=67.195.138.9:35043, Now=67.195.138.9
[junit] 10/02/20 05:54:25 INFO FSNamesystem.audit: ugi=hudson,hudson
ip=/127.0.0.1 cmd=mkdirs
src=/user/hudson/.logs/vesta.apache.org,35043,1266645264944 dst=null
perm=hudson:supergroup:rwxr-xr-x
[junit] 10/02/20 05:54:25 INFO wal.HLog: HLog configuration:
blocksize=67108864, rollsize=63753420, enabled=true, flushlogentries=1,
optionallogflushinternal=1000ms
[junit] 10/02/20 05:54:25 WARN conf.Configuration: fs.checkpoint.size is
deprecated. Instead, use dfs.namenode.checkpoint.size
[junit] 10/02/20 05:54:25 WARN conf.Configuration: fs.checkpoint.dir is
deprecated. Instead, use dfs.namenode.checkpoint.dir
[junit] 10/02/20 05:54:25 WARN conf.Configuration: fs.checkpoint.edits.dir
is deprecated. Instead, use dfs.namenode.checkpoint.edits.dir
[junit] 10/02/20 05:54:25 WARN conf.Configuration: fs.checkpoint.period is
deprecated. Instead, use dfs.namenode.checkpoint.period
[junit] 10/02/20 05:54:25 INFO FSNamesystem.audit: ugi=hudson,hudson
ip=/127.0.0.1 cmd=create
src=/user/hudson/.logs/vesta.apache.org,35043,1266645264944/hlog.dat.1266645265118
dst=null perm=hudson:supergroup:rw-r--r--
[junit] 10/02/20 05:54:25 INFO wal.HLog: New hlog
/user/hudson/.logs/vesta.apache.org,35043,1266645264944/hlog.dat.1266645265118
[junit] 10/02/20 05:54:25 INFO jvm.JvmMetrics: Cannot initialize JVM
Metrics with processName=RegionServer, sessionId=RegionServer:0 - already
initialized
[junit] 10/02/20 05:54:25 INFO metrics.RegionServerMetrics: Initialized
[junit] 10/02/20 05:54:25 INFO ipc.HBaseServer: IPC Server Responder:
starting
[junit] 10/02/20 05:54:25 INFO ipc.HBaseServer: IPC Server handler 2 on
35043: starting
[junit] 10/02/20 05:54:25 INFO ipc.HBaseServer: IPC Server handler 1 on
35043: starting
[junit] 10/02/20 05:54:25 INFO ipc.HBaseServer: IPC Server handler 0 on
35043: starting
[junit] 10/02/20 05:54:25 INFO ipc.HBaseServer: IPC Server listener on
35043: starting
[junit] 10/02/20 05:54:25 INFO ipc.HBaseServer: IPC Server handler 4 on
35043: starting
[junit] 10/02/20 05:54:25 INFO regionserver.HRegionServer: HRegionServer
started at: 67.195.138.9:35043
[junit] 10/02/20 05:54:25 INFO ipc.HBaseServer: IPC Server handler 3 on
35043: starting
[junit] 10/02/20 05:54:25 INFO regionserver.StoreFile: Allocating
LruBlockCache with maximum size 49.3m
[junit] 10/02/20 05:54:25 INFO master.RegionManager: Assigning region
-ROOT-,,0 to vesta.apache.org,35043,1266645264944
[junit] 10/02/20 05:54:25 INFO regionserver.HRegionServer: MSG_REGION_OPEN:
-ROOT-,,0
[junit] 10/02/20 05:54:25 INFO regionserver.HRegionServer: Worker:
MSG_REGION_OPEN: -ROOT-,,0
[junit] 10/02/20 05:54:25 INFO FSNamesystem.audit: ugi=hudson,hudson
ip=/127.0.0.1 cmd=listStatus src=/user/hudson/-ROOT-/70236052/info
dst=null perm=null
[junit] 10/02/20 05:54:25 INFO FSNamesystem.audit: ugi=hudson,hudson
ip=/127.0.0.1 cmd=open
src=/user/hudson/-ROOT-/70236052/info/3402942063288325861 dst=null
perm=null
[junit] 10/02/20 05:54:25 INFO DataNode.clienttrace: src: /127.0.0.1:59065,
dest: /127.0.0.1:42722, bytes: 354, op: HDFS_READ, cliID: DFSClient_681180107,
offset: 512, srvID: DS-222971694-67.195.138.9-59065-1266645263311, blockid:
blk_2634721434437608541_1006, duration: 239095
[junit] 10/02/20 05:54:25 INFO DataNode.clienttrace: src: /127.0.0.1:59065,
dest: /127.0.0.1:42723, bytes: 354, op: HDFS_READ, cliID: DFSClient_681180107,
offset: 512, srvID: DS-222971694-67.195.138.9-59065-1266645263311, blockid:
blk_2634721434437608541_1006, duration: 221451
[junit] 10/02/20 05:54:25 INFO regionserver.HRegion: region
-ROOT-,,0/70236052 available; sequence id is 3
[junit] 10/02/20 05:54:25 INFO master.ServerManager: Processing
MSG_REPORT_OPEN: -ROOT-,,0 from vesta.apache.org,35043,1266645264944; 1 of 1
[junit] 10/02/20 05:54:25 WARN server.PrepRequestProcessor: Got exception
when processing sessionid:0x126e9f0e5820000 type:create cxid:0xc
zxid:0xfffffffffffffffe txntype:unknown n/a
[junit] org.apache.zookeeper.KeeperException$NodeExistsException:
KeeperErrorCode = NodeExists
[junit] at
org.apache.zookeeper.server.PrepRequestProcessor.pRequest(PrepRequestProcessor.java:245)
[junit] at
org.apache.zookeeper.server.PrepRequestProcessor.run(PrepRequestProcessor.java:114)
[junit] 10/02/20 05:54:25 INFO master.BaseScanner:
RegionManager.rootScanner scanning meta region {server: 67.195.138.9:35043,
regionname: -ROOT-,,0, startKey: <>}
[junit] 10/02/20 05:54:25 INFO DataNode.clienttrace: src: /127.0.0.1:59065,
dest: /127.0.0.1:42725, bytes: 870, op: HDFS_READ, cliID: DFSClient_681180107,
offset: 0, srvID: DS-222971694-67.195.138.9-59065-1266645263311, blockid:
blk_2634721434437608541_1006, duration: 228328
[junit] 10/02/20 05:54:25 INFO master.BaseScanner:
RegionManager.rootScanner scan of 1 row(s) of meta region {server:
67.195.138.9:35043, regionname: -ROOT-,,0, startKey: <>} complete
[junit] 10/02/20 05:54:26 INFO master.RegionManager: Assigning region
.META.,,1 to vesta.apache.org,35043,1266645264944
[junit] 10/02/20 05:54:26 INFO regionserver.HRegionServer: MSG_REGION_OPEN:
.META.,,1
[junit] 10/02/20 05:54:26 INFO regionserver.HRegionServer: Worker:
MSG_REGION_OPEN: .META.,,1
[junit] 10/02/20 05:54:26 INFO FSNamesystem.audit: ugi=hudson,hudson
ip=/127.0.0.1 cmd=listStatus src=/user/hudson/.META./1028785192/historian
dst=null perm=null
[junit] 10/02/20 05:54:26 INFO FSNamesystem.audit: ugi=hudson,hudson
ip=/127.0.0.1 cmd=listStatus src=/user/hudson/.META./1028785192/info
dst=null perm=null
[junit] 10/02/20 05:54:26 INFO regionserver.HRegion: region
.META.,,1/1028785192 available; sequence id is 0
[junit] 10/02/20 05:54:26 INFO master.ServerManager: Processing
MSG_REPORT_OPEN: .META.,,1 from vesta.apache.org,35043,1266645264944; 1 of 1
[junit] 10/02/20 05:54:26 INFO master.RegionServerOperation: .META.,,1 open
on 67.195.138.9:35043
[junit] 10/02/20 05:54:26 INFO master.RegionServerOperation: Updated row
.META.,,1 in region -ROOT-,,0 with startcode=1266645264944,
server=67.195.138.9:35043
[junit] 10/02/20 05:54:27 INFO hdfs.StateChange: BLOCK*
NameSystem.allocateBlock:
/user/hudson/.logs/vesta.apache.org,35043,1266645264944/hlog.dat.1266645265118.
blk_5884570991278334618_1007{blockUCState=UNDER_CONSTRUCTION,
primaryNodeIndex=-1, replicas=[ReplicaUnderConstruction[127.0.0.1:59065|RBW],
ReplicaUnderConstruction[127.0.0.1:33622|RBW]]}
[junit] 10/02/20 05:54:27 INFO datanode.DataNode: Receiving block
blk_5884570991278334618_1007 src: /127.0.0.1:42726 dest: /127.0.0.1:59065
[junit] 10/02/20 05:54:27 INFO datanode.DataNode: Receiving block
blk_5884570991278334618_1007 src: /127.0.0.1:60091 dest: /127.0.0.1:33622
[junit] 10/02/20 05:54:27 INFO hdfs.StateChange: BLOCK* NameSystem.fsync:
file
/user/hudson/.logs/vesta.apache.org,35043,1266645264944/hlog.dat.1266645265118
for DFSClient_681180107
[junit] 10/02/20 05:54:30 WARN hbase.HBaseConfiguration: instantinating
HBaseConfiguration() is deprecated. Please use HBaseConfiguration#create() to
construct a plain Configuration
[junit] 10/02/20 05:54:30 INFO FSNamesystem.audit: ugi=hudson,hudson
ip=/127.0.0.1 cmd=mkdirs src=/user/hudson/table1/48576282
dst=null perm=hudson:supergroup:rwxr-xr-x
[junit] 10/02/20 05:54:30 INFO FSNamesystem.audit: ugi=hudson,hudson
ip=/127.0.0.1 cmd=mkdirs src=/user/hudson/table1/48576282/.logs
dst=null perm=hudson:supergroup:rwxr-xr-x
[junit] 10/02/20 05:54:30 INFO FSNamesystem.audit: ugi=hudson,hudson
ip=/127.0.0.1 cmd=mkdirs src=/user/hudson/table1/48576282/.oldlogs
dst=null perm=hudson:supergroup:rwxr-xr-x
[junit] 10/02/20 05:54:30 INFO wal.HLog: HLog configuration:
blocksize=67108864, rollsize=63753420, enabled=true, flushlogentries=1,
optionallogflushinternal=1000ms
[junit] 10/02/20 05:54:30 WARN conf.Configuration: fs.checkpoint.size is
deprecated. Instead, use dfs.namenode.checkpoint.size
[junit] 10/02/20 05:54:30 WARN conf.Configuration: fs.checkpoint.dir is
deprecated. Instead, use dfs.namenode.checkpoint.dir
[junit] 10/02/20 05:54:30 WARN conf.Configuration: fs.checkpoint.edits.dir
is deprecated. Instead, use dfs.namenode.checkpoint.edits.dir
[junit] 10/02/20 05:54:30 WARN conf.Configuration: fs.checkpoint.period is
deprecated. Instead, use dfs.namenode.checkpoint.period
[junit] 10/02/20 05:54:30 INFO FSNamesystem.audit: ugi=hudson,hudson
ip=/127.0.0.1 cmd=create
src=/user/hudson/table1/48576282/.logs/hlog.dat.1266645270219 dst=null
perm=hudson:supergroup:rw-r--r--
[junit] 10/02/20 05:54:30 INFO wal.HLog: New hlog
/user/hudson/table1/48576282/.logs/hlog.dat.1266645270219
[junit] 10/02/20 05:54:30 INFO FSNamesystem.audit: ugi=hudson,hudson
ip=/127.0.0.1 cmd=create src=/user/hudson/table1/48576282/.regioninfo
dst=null perm=hudson:supergroup:rw-r--r--
[junit] 10/02/20 05:54:30 INFO hdfs.StateChange: BLOCK*
NameSystem.allocateBlock: /user/hudson/table1/48576282/.regioninfo.
blk_2714995312636739172_1009{blockUCState=UNDER_CONSTRUCTION,
primaryNodeIndex=-1, replicas=[ReplicaUnderConstruction[127.0.0.1:59065|RBW],
ReplicaUnderConstruction[127.0.0.1:33622|RBW]]}
[junit] 10/02/20 05:54:30 INFO datanode.DataNode: Receiving block
blk_2714995312636739172_1009 src: /127.0.0.1:42728 dest: /127.0.0.1:59065
[junit] 10/02/20 05:54:30 INFO datanode.DataNode: Receiving block
blk_2714995312636739172_1009 src: /127.0.0.1:60093 dest: /127.0.0.1:33622
[junit] 10/02/20 05:54:30 INFO DataNode.clienttrace: src: /127.0.0.1:60093,
dest: /127.0.0.1:33622, bytes: 1206, op: HDFS_WRITE, cliID:
DFSClient_681180107, offset: 0, srvID:
DS-998759985-67.195.138.9-33622-1266645262565, blockid:
blk_2714995312636739172_1009, duration: 2032431
[junit] 10/02/20 05:54:30 INFO datanode.DataNode: PacketResponder 0 for
block blk_2714995312636739172_1009 terminating
[junit] 10/02/20 05:54:30 INFO hdfs.StateChange: BLOCK*
NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:33622 is added to
blk_2714995312636739172_1009{blockUCState=UNDER_CONSTRUCTION,
primaryNodeIndex=-1, replicas=[ReplicaUnderConstruction[127.0.0.1:59065|RBW],
ReplicaUnderConstruction[127.0.0.1:33622|RBW]]} size 0
[junit] 10/02/20 05:54:30 INFO DataNode.clienttrace: src: /127.0.0.1:42728,
dest: /127.0.0.1:59065, bytes: 1206, op: HDFS_WRITE, cliID:
DFSClient_681180107, offset: 0, srvID:
DS-222971694-67.195.138.9-59065-1266645263311, blockid:
blk_2714995312636739172_1009, duration: 4061631
[junit] 10/02/20 05:54:30 INFO datanode.DataNode: PacketResponder 1 for
block blk_2714995312636739172_1009 terminating
[junit] 10/02/20 05:54:30 INFO hdfs.StateChange: BLOCK*
NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:59065 is added to
blk_2714995312636739172_1009{blockUCState=UNDER_CONSTRUCTION,
primaryNodeIndex=-1, replicas=[ReplicaUnderConstruction[127.0.0.1:59065|RBW],
ReplicaUnderConstruction[127.0.0.1:33622|RBW]]} size 0
[junit] 10/02/20 05:54:30 INFO hdfs.StateChange: DIR*
NameSystem.completeFile: file /user/hudson/table1/48576282/.regioninfo is
closed by DFSClient_681180107
[junit] 10/02/20 05:54:30 INFO FSNamesystem.audit: ugi=hudson,hudson
ip=/127.0.0.1 cmd=mkdirs src=/user/hudson/table1/48576282/family
dst=null perm=hudson:supergroup:rwxr-xr-x
[junit] 10/02/20 05:54:30 INFO FSNamesystem.audit: ugi=hudson,hudson
ip=/127.0.0.1 cmd=listStatus src=/user/hudson/table1/48576282/family
dst=null perm=null
[junit] 10/02/20 05:54:30 INFO regionserver.HRegion: region
table1,,1266645270053/48576282 available; sequence id is 0
[junit] 10/02/20 05:54:30 INFO regionserver.HRegion: Closed
table1,,1266645270053
[junit] 10/02/20 05:54:30 INFO wal.HLog: IPC Server handler 2 on
60000.logSyncer exiting
[junit] 10/02/20 05:54:30 INFO hdfs.StateChange: BLOCK*
NameSystem.allocateBlock:
/user/hudson/table1/48576282/.logs/hlog.dat.1266645270219.
blk_-4845567271917072610_1009{blockUCState=UNDER_CONSTRUCTION,
primaryNodeIndex=-1, replicas=[ReplicaUnderConstruction[127.0.0.1:33622|RBW],
ReplicaUnderConstruction[127.0.0.1:59065|RBW]]}
[junit] 10/02/20 05:54:30 INFO datanode.DataNode: Receiving block
blk_-4845567271917072610_1009 src: /127.0.0.1:60094 dest: /127.0.0.1:33622
[junit] 10/02/20 05:54:30 INFO datanode.DataNode: Receiving block
blk_-4845567271917072610_1009 src: /127.0.0.1:42731 dest: /127.0.0.1:59065
[junit] 10/02/20 05:54:30 INFO DataNode.clienttrace: src: /127.0.0.1:42731,
dest: /127.0.0.1:59065, bytes: 119, op: HDFS_WRITE, cliID: DFSClient_681180107,
offset: 0, srvID: DS-222971694-67.195.138.9-59065-1266645263311, blockid:
blk_-4845567271917072610_1009, duration: 1668914
[junit] 10/02/20 05:54:30 INFO datanode.DataNode: PacketResponder 0 for
block blk_-4845567271917072610_1009 terminating
[junit] 10/02/20 05:54:30 INFO hdfs.StateChange: BLOCK*
NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:59065 is added to
blk_-4845567271917072610_1009{blockUCState=UNDER_CONSTRUCTION,
primaryNodeIndex=-1, replicas=[ReplicaUnderConstruction[127.0.0.1:33622|RBW],
ReplicaUnderConstruction[127.0.0.1:59065|RBW]]} size 0
[junit] 10/02/20 05:54:30 INFO DataNode.clienttrace: src: /127.0.0.1:60094,
dest: /127.0.0.1:33622, bytes: 119, op: HDFS_WRITE, cliID: DFSClient_681180107,
offset: 0, srvID: DS-998759985-67.195.138.9-33622-1266645262565, blockid:
blk_-4845567271917072610_1009, duration: 3707809
[junit] 10/02/20 05:54:30 INFO datanode.DataNode: PacketResponder 1 for
block blk_-4845567271917072610_1009 terminating
[junit] 10/02/20 05:54:30 INFO hdfs.StateChange: BLOCK*
NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:33622 is added to
blk_-4845567271917072610_1009{blockUCState=UNDER_CONSTRUCTION,
primaryNodeIndex=-1, replicas=[ReplicaUnderConstruction[127.0.0.1:33622|RBW],
ReplicaUnderConstruction[127.0.0.1:59065|RBW]]} size 0
[junit] 10/02/20 05:54:30 INFO hdfs.StateChange: DIR*
NameSystem.completeFile: file
/user/hudson/table1/48576282/.logs/hlog.dat.1266645270219 is closed by
DFSClient_681180107
[junit] 10/02/20 05:54:30 INFO FSNamesystem.audit: ugi=hudson,hudson
ip=/127.0.0.1 cmd=listStatus src=/user/hudson/table1/48576282/.logs
dst=null perm=null
[junit] 10/02/20 05:54:30 INFO FSNamesystem.audit: ugi=hudson,hudson
ip=/127.0.0.1 cmd=rename
src=/user/hudson/table1/48576282/.logs/hlog.dat.1266645270219
dst=/user/hudson/table1/48576282/.oldlogs/1266645270340.hlog.dat.1266645270219
perm=hudson:supergroup:rw-r--r--
[junit] 10/02/20 05:54:30 INFO FSNamesystem.audit: ugi=hudson,hudson
ip=/127.0.0.1 cmd=delete src=/user/hudson/table1/48576282/.logs
dst=null perm=null
[junit] 10/02/20 05:54:30 INFO master.HMaster: created table table1
[junit] 10/02/20 05:54:31 INFO datanode.DataNode: Changing meta file offset
of block blk_5884570991278334618_1007 from 11 to 7
[junit] 10/02/20 05:54:31 INFO datanode.DataNode: Changing meta file offset
of block blk_5884570991278334618_1007 from 11 to 7
[junit] 10/02/20 05:54:31 INFO master.RegionManager: Assigning region
table1,,1266645270053 to vesta.apache.org,35043,1266645264944
[junit] 10/02/20 05:54:31 INFO regionserver.HRegionServer: MSG_REGION_OPEN:
table1,,1266645270053
[junit] 10/02/20 05:54:31 INFO regionserver.HRegionServer: Worker:
MSG_REGION_OPEN: table1,,1266645270053
[junit] 10/02/20 05:54:31 INFO FSNamesystem.audit: ugi=hudson,hudson
ip=/127.0.0.1 cmd=listStatus src=/user/hudson/table1/48576282/family
dst=null perm=null
[junit] 10/02/20 05:54:31 INFO regionserver.HRegion: region
table1,,1266645270053/48576282 available; sequence id is 0
[junit] 10/02/20 05:54:31 INFO master.ServerManager: Processing
MSG_REPORT_OPEN: table1,,1266645270053 from
vesta.apache.org,35043,1266645264944; 1 of 1
[junit] 10/02/20 05:54:31 INFO master.RegionServerOperation:
table1,,1266645270053 open on 67.195.138.9:35043
[junit] 10/02/20 05:54:31 INFO master.RegionServerOperation: Updated row
table1,,1266645270053 in region .META.,,1 with startcode=1266645264944,
server=67.195.138.9:35043
[junit] 10/02/20 05:54:32 INFO datanode.DataNode: Changing meta file offset
of block blk_5884570991278334618_1007 from 19 to 15
[junit] 10/02/20 05:54:32 INFO datanode.DataNode: Changing meta file offset
of block blk_5884570991278334618_1007 from 19 to 15
[junit] 10/02/20 05:54:34 INFO master.ServerManager: 1 region servers, 0
dead, average load 3.0
[junit] 10/02/20 05:54:34 INFO FSNamesystem.audit: ugi=hudson,hudson
ip=/127.0.0.1 cmd=listStatus src=/user/hudson/.oldlogs dst=null
perm=null
[junit] 10/02/20 05:54:34 INFO master.BaseScanner:
RegionManager.rootScanner scanning meta region {server: 67.195.138.9:35043,
regionname: -ROOT-,,0, startKey: <>}
[junit] 10/02/20 05:54:34 INFO master.BaseScanner:
RegionManager.metaScanner scanning meta region {server: 67.195.138.9:35043,
regionname: .META.,,1, startKey: <>}
[junit] 10/02/20 05:54:34 INFO master.BaseScanner:
RegionManager.metaScanner scan of 1 row(s) of meta region {server:
67.195.138.9:35043, regionname: .META.,,1, startKey: <>} complete
[junit] 10/02/20 05:54:34 INFO master.BaseScanner: All 1 .META. region(s)
scanned
[junit] 10/02/20 05:54:34 INFO master.BaseScanner:
RegionManager.rootScanner scan of 1 row(s) of meta region {server:
67.195.138.9:35043, regionname: -ROOT-,,0, startKey: <>} complete
[junit] 10/02/20 05:54:35 INFO FSNamesystem.audit: ugi=hudson,hudson
ip=/127.0.0.1 cmd=mkdirs src=/user/hudson/table1-A/214080301
dst=null perm=hudson:supergroup:rwxr-xr-x
[junit] 10/02/20 05:54:35 INFO FSNamesystem.audit: ugi=hudson,hudson
ip=/127.0.0.1 cmd=mkdirs src=/user/hudson/table1-A/214080301/.logs
dst=null perm=hudson:supergroup:rwxr-xr-x
[junit] 10/02/20 05:54:35 INFO FSNamesystem.audit: ugi=hudson,hudson
ip=/127.0.0.1 cmd=mkdirs src=/user/hudson/table1-A/214080301/.oldlogs
dst=null perm=hudson:supergroup:rwxr-xr-x
[junit] 10/02/20 05:54:35 INFO wal.HLog: HLog configuration:
blocksize=67108864, rollsize=63753420, enabled=true, flushlogentries=1,
optionallogflushinternal=1000ms
[junit] 10/02/20 05:54:35 WARN conf.Configuration: fs.checkpoint.size is
deprecated. Instead, use dfs.namenode.checkpoint.size
[junit] 10/02/20 05:54:35 WARN conf.Configuration: fs.checkpoint.dir is
deprecated. Instead, use dfs.namenode.checkpoint.dir
[junit] 10/02/20 05:54:35 WARN conf.Configuration: fs.checkpoint.edits.dir
is deprecated. Instead, use dfs.namenode.checkpoint.edits.dir
[junit] 10/02/20 05:54:35 WARN conf.Configuration: fs.checkpoint.period is
deprecated. Instead, use dfs.namenode.checkpoint.period
[junit] 10/02/20 05:54:35 INFO FSNamesystem.audit: ugi=hudson,hudson
ip=/127.0.0.1 cmd=create
src=/user/hudson/table1-A/214080301/.logs/hlog.dat.1266645275488
dst=null perm=hudson:supergroup:rw-r--r--
[junit] 10/02/20 05:54:35 INFO wal.HLog: New hlog
/user/hudson/table1-A/214080301/.logs/hlog.dat.1266645275488
[junit] 10/02/20 05:54:35 INFO FSNamesystem.audit: ugi=hudson,hudson
ip=/127.0.0.1 cmd=create src=/user/hudson/table1-A/214080301/.regioninfo
dst=null perm=hudson:supergroup:rw-r--r--
[junit] 10/02/20 05:54:35 INFO hdfs.StateChange: BLOCK*
NameSystem.allocateBlock: /user/hudson/table1-A/214080301/.regioninfo.
blk_6920727824723981508_1011{blockUCState=UNDER_CONSTRUCTION,
primaryNodeIndex=-1, replicas=[ReplicaUnderConstruction[127.0.0.1:33622|RBW],
ReplicaUnderConstruction[127.0.0.1:59065|RBW]]}
[junit] 10/02/20 05:54:35 INFO datanode.DataNode: Receiving block
blk_6920727824723981508_1011 src: /127.0.0.1:60097 dest: /127.0.0.1:33622
[junit] 10/02/20 05:54:35 INFO datanode.DataNode: Receiving block
blk_6920727824723981508_1011 src: /127.0.0.1:42734 dest: /127.0.0.1:59065
[junit] 10/02/20 05:54:35 INFO DataNode.clienttrace: src: /127.0.0.1:42734,
dest: /127.0.0.1:59065, bytes: 979, op: HDFS_WRITE, cliID: DFSClient_681180107,
offset: 0, srvID: DS-222971694-67.195.138.9-59065-1266645263311, blockid:
blk_6920727824723981508_1011, duration: 2027484
[junit] 10/02/20 05:54:35 INFO datanode.DataNode: PacketResponder 0 for
block blk_6920727824723981508_1011 terminating
[junit] 10/02/20 05:54:35 INFO hdfs.StateChange: BLOCK*
NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:59065 is added to
blk_6920727824723981508_1011{blockUCState=UNDER_CONSTRUCTION,
primaryNodeIndex=-1, replicas=[ReplicaUnderConstruction[127.0.0.1:33622|RBW],
ReplicaUnderConstruction[127.0.0.1:59065|RBW]]} size 0
[junit] 10/02/20 05:54:35 INFO DataNode.clienttrace: src: /127.0.0.1:60097,
dest: /127.0.0.1:33622, bytes: 979, op: HDFS_WRITE, cliID: DFSClient_681180107,
offset: 0, srvID: DS-998759985-67.195.138.9-33622-1266645262565, blockid:
blk_6920727824723981508_1011, duration: 2817888
[junit] 10/02/20 05:54:35 INFO hdfs.StateChange: BLOCK*
NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:33622 is added to
blk_6920727824723981508_1011{blockUCState=UNDER_CONSTRUCTION,
primaryNodeIndex=-1, replicas=[ReplicaUnderConstruction[127.0.0.1:33622|RBW],
ReplicaUnderConstruction[127.0.0.1:59065|RBW]]} size 0
[junit] 10/02/20 05:54:35 INFO datanode.DataNode: PacketResponder 1 for
block blk_6920727824723981508_1011 terminating
[junit] 10/02/20 05:54:35 INFO hdfs.StateChange: DIR*
NameSystem.completeFile: file /user/hudson/table1-A/214080301/.regioninfo is
closed by DFSClient_681180107
[junit] 10/02/20 05:54:35 INFO FSNamesystem.audit: ugi=hudson,hudson
ip=/127.0.0.1 cmd=mkdirs src=/user/hudson/table1-A/214080301/__INDEX__
dst=null perm=hudson:supergroup:rwxr-xr-x
[junit] 10/02/20 05:54:35 INFO FSNamesystem.audit: ugi=hudson,hudson
ip=/127.0.0.1 cmd=listStatus src=/user/hudson/table1-A/214080301/__INDEX__
dst=null perm=null
[junit] 10/02/20 05:54:35 INFO FSNamesystem.audit: ugi=hudson,hudson
ip=/127.0.0.1 cmd=mkdirs src=/user/hudson/table1-A/214080301/family
dst=null perm=hudson:supergroup:rwxr-xr-x
[junit] 10/02/20 05:54:35 INFO FSNamesystem.audit: ugi=hudson,hudson
ip=/127.0.0.1 cmd=listStatus src=/user/hudson/table1-A/214080301/family
dst=null perm=null
[junit] 10/02/20 05:54:35 INFO regionserver.HRegion: region
table1-A,,1266645275392/214080301 available; sequence id is 0
[junit] 10/02/20 05:54:35 INFO regionserver.HRegion: Closed
table1-A,,1266645275392
[junit] 10/02/20 05:54:35 INFO wal.HLog: IPC Server handler 0 on
60000.logSyncer exiting
[junit] 10/02/20 05:54:35 INFO hdfs.StateChange: BLOCK*
NameSystem.allocateBlock:
/user/hudson/table1-A/214080301/.logs/hlog.dat.1266645275488.
blk_-1484314412078791539_1011{blockUCState=UNDER_CONSTRUCTION,
primaryNodeIndex=-1, replicas=[ReplicaUnderConstruction[127.0.0.1:33622|RBW],
ReplicaUnderConstruction[127.0.0.1:59065|RBW]]}
[junit] 10/02/20 05:54:35 INFO datanode.DataNode: Receiving block
blk_-1484314412078791539_1011 src: /127.0.0.1:60099 dest: /127.0.0.1:33622
[junit] 10/02/20 05:54:35 INFO datanode.DataNode: Receiving block
blk_-1484314412078791539_1011 src: /127.0.0.1:42736 dest: /127.0.0.1:59065
[junit] 10/02/20 05:54:35 INFO DataNode.clienttrace: src: /127.0.0.1:42736,
dest: /127.0.0.1:59065, bytes: 119, op: HDFS_WRITE, cliID: DFSClient_681180107,
offset: 0, srvID: DS-222971694-67.195.138.9-59065-1266645263311, blockid:
blk_-1484314412078791539_1011, duration: 1322745
[junit] 10/02/20 05:54:35 INFO datanode.DataNode: PacketResponder 0 for
block blk_-1484314412078791539_1011 terminating
[junit] 10/02/20 05:54:35 INFO hdfs.StateChange: BLOCK*
NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:59065 is added to
blk_-1484314412078791539_1011{blockUCState=UNDER_CONSTRUCTION,
primaryNodeIndex=-1, replicas=[ReplicaUnderConstruction[127.0.0.1:33622|RBW],
ReplicaUnderConstruction[127.0.0.1:59065|RBW]]} size 0
[junit] 10/02/20 05:54:35 INFO DataNode.clienttrace: src: /127.0.0.1:60099,
dest: /127.0.0.1:33622, bytes: 119, op: HDFS_WRITE, cliID: DFSClient_681180107,
offset: 0, srvID: DS-998759985-67.195.138.9-33622-1266645262565, blockid:
blk_-1484314412078791539_1011, duration: 2426000
[junit] 10/02/20 05:54:35 INFO datanode.DataNode: PacketResponder 1 for
block blk_-1484314412078791539_1011 terminating
[junit] 10/02/20 05:54:35 INFO hdfs.StateChange: BLOCK*
NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:33622 is added to
blk_-1484314412078791539_1011{blockUCState=UNDER_CONSTRUCTION,
primaryNodeIndex=-1, replicas=[ReplicaUnderConstruction[127.0.0.1:33622|RBW],
ReplicaUnderConstruction[127.0.0.1:59065|RBW]]} size 0
[junit] 10/02/20 05:54:35 INFO hdfs.StateChange: DIR*
NameSystem.completeFile: file
/user/hudson/table1-A/214080301/.logs/hlog.dat.1266645275488 is closed by
DFSClient_681180107
[junit] 10/02/20 05:54:35 INFO FSNamesystem.audit: ugi=hudson,hudson
ip=/127.0.0.1 cmd=listStatus src=/user/hudson/table1-A/214080301/.logs
dst=null perm=null
[junit] 10/02/20 05:54:35 INFO FSNamesystem.audit: ugi=hudson,hudson
ip=/127.0.0.1 cmd=rename
src=/user/hudson/table1-A/214080301/.logs/hlog.dat.1266645275488
dst=/user/hudson/table1-A/214080301/.oldlogs/1266645275645.hlog.dat.1266645275488
perm=hudson:supergroup:rw-r--r--
[junit] 10/02/20 05:54:35 INFO FSNamesystem.audit: ugi=hudson,hudson
ip=/127.0.0.1 cmd=delete src=/user/hudson/table1-A/214080301/.logs
dst=null perm=null
[junit] 10/02/20 05:54:35 INFO master.HMaster: created table table1-A
[junit] 10/02/20 05:54:36 INFO datanode.DataNode: Changing meta file offset
of block blk_5884570991278334618_1007 from 19 to 15
[junit] 10/02/20 05:54:36 INFO datanode.DataNode: Changing meta file offset
of block blk_5884570991278334618_1007 from 19 to 15
[junit] 10/02/20 05:54:36 INFO master.RegionManager: Assigning region
table1-A,,1266645275392 to vesta.apache.org,35043,1266645264944
[junit] 10/02/20 05:54:36 INFO regionserver.HRegionServer: MSG_REGION_OPEN:
table1-A,,1266645275392
[junit] 10/02/20 05:54:36 INFO regionserver.HRegionServer: Worker:
MSG_REGION_OPEN: table1-A,,1266645275392
[junit] 10/02/20 05:54:36 INFO FSNamesystem.audit: ugi=hudson,hudson
ip=/127.0.0.1 cmd=listStatus src=/user/hudson/table1-A/214080301/__INDEX__
dst=null perm=null
[junit] 10/02/20 05:54:36 INFO FSNamesystem.audit: ugi=hudson,hudson
ip=/127.0.0.1 cmd=listStatus src=/user/hudson/table1-A/214080301/family
dst=null perm=null
[junit] 10/02/20 05:54:36 INFO regionserver.HRegion: region
table1-A,,1266645275392/214080301 available; sequence id is 0
[junit] 10/02/20 05:54:36 INFO master.ServerManager: Processing
MSG_REPORT_OPEN: table1-A,,1266645275392 from
vesta.apache.org,35043,1266645264944; 1 of 1
[junit] 10/02/20 05:54:36 INFO master.RegionServerOperation:
table1-A,,1266645275392 open on 67.195.138.9:35043
[junit] 10/02/20 05:54:36 INFO master.RegionServerOperation: Updated row
table1-A,,1266645275392 in region .META.,,1 with startcode=1266645264944,
server=67.195.138.9:35043
[junit] 10/02/20 05:54:37 INFO datanode.DataNode: Changing meta file offset
of block blk_5884570991278334618_1007 from 23 to 19
[junit] 10/02/20 05:54:37 INFO datanode.DataNode: Changing meta file offset
of block blk_5884570991278334618_1007 from 23 to 19
[junit] 10/02/20 05:54:40 INFO tableindexed.TestIndexedTable: Inserted row
[0000000000] val: [0000006913]
[junit] 10/02/20 05:54:40 INFO tableindexed.TestIndexedTable: Inserted row
[0000000001] val: [0000002990]
[junit] 10/02/20 05:54:40 INFO tableindexed.TestIndexedTable: Inserted row
[0000000002] val: [0000004505]
[junit] 10/02/20 05:54:41 INFO tableindexed.TestIndexedTable: Inserted row
[0000000003] val: [0000003970]
[junit] 10/02/20 05:54:41 INFO tableindexed.TestIndexedTable: Inserted row
[0000000004] val: [0000009858]
[junit] 10/02/20 05:54:41 INFO datanode.DataNode: Changing meta file offset
of block blk_5884570991278334618_1007 from 27 to 23
[junit] 10/02/20 05:54:41 INFO datanode.DataNode: Changing meta file offset
of block blk_5884570991278334618_1007 from 27 to 23
[junit] 10/02/20 05:54:41 INFO tableindexed.TestIndexedTable: Inserted row
[0000000005] val: [0000004667]
[junit] 10/02/20 05:54:41 INFO tableindexed.TestIndexedTable: Inserted row
[0000000006] val: [0000007694]
[junit] 10/02/20 05:54:41 INFO tableindexed.TestIndexedTable: Inserted row
[0000000007] val: [0000007359]
[junit] 10/02/20 05:54:41 INFO tableindexed.TestIndexedTable: Inserted row
[0000000008] val: [0000000061]
[junit] 10/02/20 05:54:41 INFO tableindexed.TestIndexedTable: Inserted row
[0000000009] val: [0000001534]
[junit] 10/02/20 05:54:41 INFO tableindexed.TestIndexedTable: index scan :
row [0000000008] value [0000000061]
[junit] 10/02/20 05:54:41 INFO tableindexed.TestIndexedTable: index scan :
row [0000000009] value [0000001534]
[junit] 10/02/20 05:54:41 INFO tableindexed.TestIndexedTable: index scan :
row [0000000001] value [0000002990]
[junit] 10/02/20 05:54:41 INFO tableindexed.TestIndexedTable: index scan :
row [0000000003] value [0000003970]
[junit] 10/02/20 05:54:41 INFO tableindexed.TestIndexedTable: index scan :
row [0000000002] value [0000004505]
[junit] 10/02/20 05:54:41 INFO tableindexed.TestIndexedTable: index scan :
row [0000000005] value [0000004667]
[junit] 10/02/20 05:54:41 INFO tableindexed.TestIndexedTable: index scan :
row [0000000000] value [0000006913]
[junit] 10/02/20 05:54:41 INFO tableindexed.TestIndexedTable: index scan :
row [0000000007] value [0000007359]
[junit] 10/02/20 05:54:41 INFO tableindexed.TestIndexedTable: index scan :
row [0000000006] value [0000007694]
[junit] 10/02/20 05:54:41 INFO tableindexed.TestIndexedTable: index scan :
row [0000000004] value [0000009858]
[junit] 10/02/20 05:54:41 INFO master.HMaster: Cluster shutdown requested.
Starting to quiesce servers
[junit] 10/02/20 05:54:41 WARN server.PrepRequestProcessor: Got exception
when processing sessionid:0x126e9f0e5820000 type:create cxid:0xf
zxid:0xfffffffffffffffe txntype:unknown n/a
[junit] org.apache.zookeeper.KeeperException$NodeExistsException:
KeeperErrorCode = NodeExists
[junit] at
org.apache.zookeeper.server.PrepRequestProcessor.pRequest(PrepRequestProcessor.java:245)
[junit] at
org.apache.zookeeper.server.PrepRequestProcessor.run(PrepRequestProcessor.java:114)
[junit] 10/02/20 05:54:41 INFO master.ZKMasterAddressWatcher: Cluster
shutdown while waiting, shutting down this master.
[junit] 10/02/20 05:54:42 INFO datanode.DataNode: Changing meta file offset
of block blk_5884570991278334618_1007 from 47 to 43
[junit] 10/02/20 05:54:42 INFO datanode.DataNode: Changing meta file offset
of block blk_5884570991278334618_1007 from 47 to 43
[junit] 10/02/20 05:54:42 INFO master.MetaScanner:
RegionManager.metaScanner exiting
FATAL: command execution failed.
hudson.util.IOException2: Failed to join the process
at hudson.Proc$RemoteProc.join(Proc.java:312)
at hudson.Launcher$ProcStarter.join(Launcher.java:275)
at hudson.tasks.Ant.perform(Ant.java:207)
at hudson.tasks.BuildStepMonitor$1.perform(BuildStepMonitor.java:19)
at
hudson.model.AbstractBuild$AbstractRunner.perform(AbstractBuild.java:582)
at hudson.model.Build$RunnerImpl.build(Build.java:165)
at hudson.model.Build$RunnerImpl.doRun(Build.java:132)
at hudson.model.AbstractBuild$AbstractRunner.run(AbstractBuild.java:416)
at hudson.model.Run.run(Run.java:1198)
at hudson.model.FreeStyleBuild.run(FreeStyleBuild.java:46)
at hudson.model.ResourceController.execute(ResourceController.java:88)
at hudson.model.Executor.run(Executor.java:122)
Caused by: java.util.concurrent.ExecutionException:
hudson.remoting.RequestAbortedException: java.io.EOFException
at hudson.remoting.Request$1.get(Request.java:218)
at hudson.remoting.Request$1.get(Request.java:172)
at hudson.remoting.FutureAdapter.get(FutureAdapter.java:55)
at hudson.Proc$RemoteProc.join(Proc.java:304)
... 11 more
Caused by: hudson.remoting.RequestAbortedException: java.io.EOFException
at hudson.remoting.Request.abort(Request.java:257)
at hudson.remoting.Channel.terminate(Channel.java:598)
at hudson.remoting.Channel$ReaderThread.run(Channel.java:876)
Caused by: java.io.EOFException
at
java.io.ObjectInputStream$BlockDataInputStream.peekByte(ObjectInputStream.java:2554)
at java.io.ObjectInputStream.skipCustomData(ObjectInputStream.java:1900)
at
java.io.ObjectInputStream.readNonProxyDesc(ObjectInputStream.java:1581)
at java.io.ObjectInputStream.readClassDesc(ObjectInputStream.java:1496)
at
java.io.ObjectInputStream.readOrdinaryObject(ObjectInputStream.java:1732)
at java.io.ObjectInputStream.readObject0(ObjectInputStream.java:1329)
at java.io.ObjectInputStream.readObject(ObjectInputStream.java:351)
at hudson.remoting.Channel$ReaderThread.run(Channel.java:856)
[locks-and-latches] Releasing all the locks
[locks-and-latches] All the locks released
FATAL: channel is already closed
hudson.remoting.ChannelClosedException: channel is already closed
at hudson.remoting.Channel.send(Channel.java:412)
at hudson.remoting.Request.call(Request.java:105)
at hudson.remoting.Channel.call(Channel.java:551)
at hudson.Launcher$RemoteLauncher.kill(Launcher.java:735)
at hudson.model.AbstractBuild$AbstractRunner.run(AbstractBuild.java:421)
at hudson.model.Run.run(Run.java:1198)
at hudson.model.FreeStyleBuild.run(FreeStyleBuild.java:46)
at hudson.model.ResourceController.execute(ResourceController.java:88)
at hudson.model.Executor.run(Executor.java:122)
