See <https://builds.apache.org/job/gora-trunk/293/>
------------------------------------------ [...truncated 5049 lines...] 12/05/26 07:00:47 INFO wal.HLog: HLog configuration: blocksize=64 MB, rollsize=60.8 MB, enabled=true, optionallogflushinternal=1000ms 12/05/26 07:00:47 INFO wal.SequenceFileLogWriter: syncFs -- HDFS-200 -- not available, dfs.support.append=false 12/05/26 07:00:47 INFO wal.HLog: New hlog /user/hudson/Employee/a8a5b5ddd22d6bd3f9a16ea629a55d04/.logs/hlog.1338015647797 12/05/26 07:00:47 INFO wal.HLog: Using getNumCurrentReplicas--HDFS-826 12/05/26 07:00:47 INFO hdfs.StateChange: BLOCK* NameSystem.allocateBlock: /user/hudson/Employee/a8a5b5ddd22d6bd3f9a16ea629a55d04/.tmp/.regioninfo. blk_813251679085492658_1101 12/05/26 07:00:47 INFO datanode.DataNode: Receiving block blk_813251679085492658_1101 src: /127.0.0.1:35834 dest: /127.0.0.1:34519 12/05/26 07:00:47 INFO DataNode.clienttrace: src: /127.0.0.1:35834, dest: /127.0.0.1:34519, bytes: 720, op: HDFS_WRITE, cliID: DFSClient_557503250, offset: 0, srvID: DS-531900178-192.87.106.251-34519-1338014972975, blockid: blk_813251679085492658_1101, duration: 1427109 12/05/26 07:00:47 INFO datanode.DataNode: PacketResponder 0 for block blk_813251679085492658_1101 terminating 12/05/26 07:00:47 INFO hdfs.StateChange: BLOCK* NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:34519 is added to blk_813251679085492658_1101 size 720 12/05/26 07:00:48 INFO hdfs.StateChange: Removing lease on file /user/hudson/Employee/a8a5b5ddd22d6bd3f9a16ea629a55d04/.tmp/.regioninfo from client DFSClient_557503250 12/05/26 07:00:48 INFO hdfs.StateChange: DIR* NameSystem.completeFile: file /user/hudson/Employee/a8a5b5ddd22d6bd3f9a16ea629a55d04/.tmp/.regioninfo is closed by DFSClient_557503250 12/05/26 07:00:48 INFO regionserver.HRegion: Onlined Employee,,1338015647696.a8a5b5ddd22d6bd3f9a16ea629a55d04.; next sequenceid=1 12/05/26 07:00:48 INFO catalog.MetaEditor: Added region Employee,,1338015647696.a8a5b5ddd22d6bd3f9a16ea629a55d04. to META 12/05/26 07:00:48 INFO regionserver.HRegion: Closed Employee,,1338015647696.a8a5b5ddd22d6bd3f9a16ea629a55d04. 12/05/26 07:00:48 INFO wal.HLog: IPC Server handler 3 on 34526.logSyncer exiting 12/05/26 07:00:48 INFO hdfs.StateChange: BLOCK* NameSystem.allocateBlock: /user/hudson/Employee/a8a5b5ddd22d6bd3f9a16ea629a55d04/.logs/hlog.1338015647797. blk_-6192303727943096279_1101 12/05/26 07:00:48 INFO datanode.DataNode: Receiving block blk_-6192303727943096279_1101 src: /127.0.0.1:35835 dest: /127.0.0.1:34519 12/05/26 07:00:48 INFO DataNode.clienttrace: src: /127.0.0.1:35835, dest: /127.0.0.1:34519, bytes: 124, op: HDFS_WRITE, cliID: DFSClient_557503250, offset: 0, srvID: DS-531900178-192.87.106.251-34519-1338014972975, blockid: blk_-6192303727943096279_1101, duration: 2241491 12/05/26 07:00:48 INFO datanode.DataNode: PacketResponder 0 for block blk_-6192303727943096279_1101 terminating 12/05/26 07:00:48 INFO hdfs.StateChange: BLOCK* NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:34519 is added to blk_-6192303727943096279_1101 size 124 12/05/26 07:00:48 INFO hdfs.StateChange: Removing lease on file /user/hudson/Employee/a8a5b5ddd22d6bd3f9a16ea629a55d04/.logs/hlog.1338015647797 from client DFSClient_557503250 12/05/26 07:00:48 INFO hdfs.StateChange: DIR* NameSystem.completeFile: file /user/hudson/Employee/a8a5b5ddd22d6bd3f9a16ea629a55d04/.logs/hlog.1338015647797 is closed by DFSClient_557503250 12/05/26 07:00:48 INFO regionserver.HRegionServer: Received request to open region: Employee,,1338015647696.a8a5b5ddd22d6bd3f9a16ea629a55d04. 12/05/26 07:00:48 INFO regionserver.HRegion: Onlined Employee,,1338015647696.a8a5b5ddd22d6bd3f9a16ea629a55d04.; next sequenceid=1 12/05/26 07:00:48 INFO catalog.MetaEditor: Updated row Employee,,1338015647696.a8a5b5ddd22d6bd3f9a16ea629a55d04. in region .META.,,1 with server=hudson_solaris:34530, startcode=1338014976212 12/05/26 07:00:53 INFO store.DataStoreTestBase: test method: testSchemaExists 12/05/26 07:00:53 INFO handler.DisableTableHandler: Attemping to disable table WebPage 12/05/26 07:00:53 INFO client.HBaseAdmin: Started disable of WebPage 12/05/26 07:00:54 INFO handler.DisableTableHandler: Offlining 1 regions. 12/05/26 07:00:54 INFO regionserver.HRegionServer: Received close region: WebPage,,1338015630905.af6aef34a62da66713ef47e3ca55a3d2. 12/05/26 07:00:54 INFO regionserver.HRegion: Closed WebPage,,1338015630905.af6aef34a62da66713ef47e3ca55a3d2. 12/05/26 07:00:55 INFO handler.DisableTableHandler: Disabled table is done=true 12/05/26 07:00:59 INFO client.HBaseAdmin: Disabled WebPage 12/05/26 07:00:59 INFO handler.TableEventHandler: Handling table operation C_M_DELETE_TABLE on table WebPage 12/05/26 07:00:59 INFO catalog.MetaEditor: Deleted region WebPage,,1338015630905.af6aef34a62da66713ef47e3ca55a3d2. from META 12/05/26 07:00:59 INFO hdfs.StateChange: BLOCK* NameSystem.addToInvalidates: blk_3197738430278173045 is added to invalidSet of 127.0.0.1:34519 12/05/26 07:00:59 INFO hdfs.StateChange: BLOCK* NameSystem.addToInvalidates: blk_-2345647315332369826 is added to invalidSet of 127.0.0.1:34519 12/05/26 07:01:01 INFO hdfs.StateChange: BLOCK* ask 127.0.0.1:34519 to delete blk_3197738430278173045_1099 blk_-2345647315332369826_1099 12/05/26 07:01:01 INFO datanode.DataNode: Scheduling block blk_-2345647315332369826_1099 file <https://builds.apache.org/job/gora-trunk/ws/trunk./gora-hbase/target/test-data/55ed0b77-4552-4eb5-8c2c-f52732bc5d41/dfs/data/data2/current/blk_-2345647315332369826> for deletion 12/05/26 07:01:01 INFO datanode.DataNode: Scheduling block blk_3197738430278173045_1099 file <https://builds.apache.org/job/gora-trunk/ws/trunk./gora-hbase/target/test-data/55ed0b77-4552-4eb5-8c2c-f52732bc5d41/dfs/data/data1/current/blk_3197738430278173045> for deletion 12/05/26 07:01:01 INFO datanode.DataNode: Deleted block blk_-2345647315332369826_1099 at file <https://builds.apache.org/job/gora-trunk/ws/trunk./gora-hbase/target/test-data/55ed0b77-4552-4eb5-8c2c-f52732bc5d41/dfs/data/data2/current/blk_-2345647315332369826> 12/05/26 07:01:01 INFO datanode.DataNode: Deleted block blk_3197738430278173045_1099 at file <https://builds.apache.org/job/gora-trunk/ws/trunk./gora-hbase/target/test-data/55ed0b77-4552-4eb5-8c2c-f52732bc5d41/dfs/data/data1/current/blk_3197738430278173045> 12/05/26 07:01:04 INFO client.HBaseAdmin: Deleted WebPage 12/05/26 07:01:04 INFO store.DataStoreTestBase: tearing down test 12/05/26 07:01:04 INFO gora.GoraTestDriver: tearing down test 12/05/26 07:01:04 INFO handler.DisableTableHandler: Attemping to disable table Employee 12/05/26 07:01:04 INFO client.HBaseAdmin: Started disable of Employee 12/05/26 07:01:04 INFO handler.DisableTableHandler: Offlining 1 regions. 12/05/26 07:01:04 INFO regionserver.HRegionServer: Received close region: Employee,,1338015647696.a8a5b5ddd22d6bd3f9a16ea629a55d04. 12/05/26 07:01:04 INFO regionserver.HRegion: Closed Employee,,1338015647696.a8a5b5ddd22d6bd3f9a16ea629a55d04. 12/05/26 07:01:05 INFO handler.DisableTableHandler: Disabled table is done=true 12/05/26 07:01:09 INFO client.HBaseAdmin: Disabled Employee 12/05/26 07:01:09 INFO handler.TableEventHandler: Handling table operation C_M_DELETE_TABLE on table Employee 12/05/26 07:01:09 INFO catalog.MetaEditor: Deleted region Employee,,1338015647696.a8a5b5ddd22d6bd3f9a16ea629a55d04. from META 12/05/26 07:01:09 INFO hdfs.StateChange: BLOCK* NameSystem.addToInvalidates: blk_-6192303727943096279 is added to invalidSet of 127.0.0.1:34519 12/05/26 07:01:09 INFO hdfs.StateChange: BLOCK* NameSystem.addToInvalidates: blk_813251679085492658 is added to invalidSet of 127.0.0.1:34519 12/05/26 07:01:09 INFO namenode.FSNamesystem: Number of transactions: 899 Total time for transactions(ms): 28Number of transactions batched in Syncs: 80 Number of syncs: 711 SyncTimes(ms): 6841 5982 12/05/26 07:01:10 INFO hdfs.StateChange: BLOCK* ask 127.0.0.1:34519 to delete blk_813251679085492658_1101 blk_-6192303727943096279_1101 12/05/26 07:01:10 INFO datanode.DataNode: Scheduling block blk_-6192303727943096279_1101 file <https://builds.apache.org/job/gora-trunk/ws/trunk./gora-hbase/target/test-data/55ed0b77-4552-4eb5-8c2c-f52732bc5d41/dfs/data/data1/current/blk_-6192303727943096279> for deletion 12/05/26 07:01:10 INFO datanode.DataNode: Deleted block blk_-6192303727943096279_1101 at file <https://builds.apache.org/job/gora-trunk/ws/trunk./gora-hbase/target/test-data/55ed0b77-4552-4eb5-8c2c-f52732bc5d41/dfs/data/data1/current/blk_-6192303727943096279> 12/05/26 07:01:10 INFO datanode.DataNode: Scheduling block blk_813251679085492658_1101 file <https://builds.apache.org/job/gora-trunk/ws/trunk./gora-hbase/target/test-data/55ed0b77-4552-4eb5-8c2c-f52732bc5d41/dfs/data/data2/current/blk_813251679085492658> for deletion 12/05/26 07:01:10 INFO datanode.DataNode: Deleted block blk_813251679085492658_1101 at file <https://builds.apache.org/job/gora-trunk/ws/trunk./gora-hbase/target/test-data/55ed0b77-4552-4eb5-8c2c-f52732bc5d41/dfs/data/data2/current/blk_813251679085492658> 12/05/26 07:01:14 INFO client.HBaseAdmin: Deleted Employee 12/05/26 07:01:14 INFO store.DataStoreTestBase: setting up test 12/05/26 07:01:14 INFO zookeeper.ZooKeeper: Initiating client connection, connectString=localhost:21818 sessionTimeout=180000 watcher=hconnection 12/05/26 07:01:14 INFO zookeeper.ClientCnxn: Opening socket connection to server localhost/127.0.0.1:21818 12/05/26 07:01:14 INFO zookeeper.ClientCnxn: Socket connection established to localhost/127.0.0.1:21818, initiating session 12/05/26 07:01:14 INFO server.NIOServerCnxn: Accepted socket connection from /127.0.0.1:35942 12/05/26 07:01:14 INFO server.NIOServerCnxn: Client attempting to establish new session at /127.0.0.1:35942 12/05/26 07:01:14 INFO server.NIOServerCnxn: Established session 0x13787e83eae0020 with negotiated timeout 40000 for client /127.0.0.1:35942 12/05/26 07:01:14 INFO zookeeper.ClientCnxn: Session establishment complete on server localhost/127.0.0.1:21818, sessionid = 0x13787e83eae0020, negotiated timeout = 40000 12/05/26 07:01:14 WARN zookeeper.ZKTable: Moving table Employee state to enabled but was already enabled 12/05/26 07:01:14 INFO server.PrepRequestProcessor: Got user-level KeeperException when processing sessionid:0x13787e83eae0000 type:delete cxid:0x487 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/hbase/table/Employee Error:KeeperErrorCode = NoNode for /hbase/table/Employee 12/05/26 07:01:14 INFO wal.HLog: HLog configuration: blocksize=64 MB, rollsize=60.8 MB, enabled=true, optionallogflushinternal=1000ms 12/05/26 07:01:14 INFO wal.SequenceFileLogWriter: syncFs -- HDFS-200 -- not available, dfs.support.append=false 12/05/26 07:01:14 INFO wal.HLog: New hlog /user/hudson/Employee/a58a76d497a4616abc7c6c47fbc9bd99/.logs/hlog.1338015674515 12/05/26 07:01:14 INFO wal.HLog: Using getNumCurrentReplicas--HDFS-826 12/05/26 07:01:14 INFO hdfs.StateChange: BLOCK* NameSystem.allocateBlock: /user/hudson/Employee/a58a76d497a4616abc7c6c47fbc9bd99/.tmp/.regioninfo. blk_8342440413718110761_1103 12/05/26 07:01:14 INFO datanode.DataNode: Receiving block blk_8342440413718110761_1103 src: /127.0.0.1:35943 dest: /127.0.0.1:34519 12/05/26 07:01:14 INFO DataNode.clienttrace: src: /127.0.0.1:35943, dest: /127.0.0.1:34519, bytes: 720, op: HDFS_WRITE, cliID: DFSClient_557503250, offset: 0, srvID: DS-531900178-192.87.106.251-34519-1338014972975, blockid: blk_8342440413718110761_1103, duration: 1078626 12/05/26 07:01:14 INFO hdfs.StateChange: BLOCK* NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:34519 is added to blk_8342440413718110761_1103 size 720 12/05/26 07:01:14 INFO datanode.DataNode: PacketResponder 0 for block blk_8342440413718110761_1103 terminating 12/05/26 07:01:14 INFO hdfs.StateChange: Removing lease on file /user/hudson/Employee/a58a76d497a4616abc7c6c47fbc9bd99/.tmp/.regioninfo from client DFSClient_557503250 12/05/26 07:01:14 INFO hdfs.StateChange: DIR* NameSystem.completeFile: file /user/hudson/Employee/a58a76d497a4616abc7c6c47fbc9bd99/.tmp/.regioninfo is closed by DFSClient_557503250 12/05/26 07:01:14 INFO regionserver.HRegion: Onlined Employee,,1338015674500.a58a76d497a4616abc7c6c47fbc9bd99.; next sequenceid=1 12/05/26 07:01:14 INFO catalog.MetaEditor: Added region Employee,,1338015674500.a58a76d497a4616abc7c6c47fbc9bd99. to META 12/05/26 07:01:14 INFO regionserver.HRegion: Closed Employee,,1338015674500.a58a76d497a4616abc7c6c47fbc9bd99. 12/05/26 07:01:14 INFO wal.HLog: IPC Server handler 1 on 34526.logSyncer exiting 12/05/26 07:01:14 INFO hdfs.StateChange: BLOCK* NameSystem.allocateBlock: /user/hudson/Employee/a58a76d497a4616abc7c6c47fbc9bd99/.logs/hlog.1338015674515. blk_399910535230890227_1103 12/05/26 07:01:14 INFO datanode.DataNode: Receiving block blk_399910535230890227_1103 src: /127.0.0.1:35944 dest: /127.0.0.1:34519 12/05/26 07:01:14 INFO DataNode.clienttrace: src: /127.0.0.1:35944, dest: /127.0.0.1:34519, bytes: 124, op: HDFS_WRITE, cliID: DFSClient_557503250, offset: 0, srvID: DS-531900178-192.87.106.251-34519-1338014972975, blockid: blk_399910535230890227_1103, duration: 1132311 12/05/26 07:01:14 INFO datanode.DataNode: PacketResponder 0 for block blk_399910535230890227_1103 terminating 12/05/26 07:01:14 INFO hdfs.StateChange: BLOCK* NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:34519 is added to blk_399910535230890227_1103 size 124 12/05/26 07:01:14 INFO hdfs.StateChange: Removing lease on file /user/hudson/Employee/a58a76d497a4616abc7c6c47fbc9bd99/.logs/hlog.1338015674515 from client DFSClient_557503250 12/05/26 07:01:14 INFO hdfs.StateChange: DIR* NameSystem.completeFile: file /user/hudson/Employee/a58a76d497a4616abc7c6c47fbc9bd99/.logs/hlog.1338015674515 is closed by DFSClient_557503250 12/05/26 07:01:14 INFO regionserver.HRegionServer: Received request to open region: Employee,,1338015674500.a58a76d497a4616abc7c6c47fbc9bd99. 12/05/26 07:01:14 INFO regionserver.HRegion: Onlined Employee,,1338015674500.a58a76d497a4616abc7c6c47fbc9bd99.; next sequenceid=1 12/05/26 07:01:14 INFO catalog.MetaEditor: Updated row Employee,,1338015674500.a58a76d497a4616abc7c6c47fbc9bd99. in region .META.,,1 with server=hudson_solaris:34530, startcode=1338014976212 12/05/26 07:01:20 INFO zookeeper.ZooKeeper: Initiating client connection, connectString=localhost:21818 sessionTimeout=180000 watcher=hconnection 12/05/26 07:01:20 INFO zookeeper.ClientCnxn: Opening socket connection to server localhost/127.0.0.1:21818 12/05/26 07:01:20 INFO zookeeper.ClientCnxn: Socket connection established to localhost/127.0.0.1:21818, initiating session 12/05/26 07:01:20 INFO server.NIOServerCnxn: Accepted socket connection from /127.0.0.1:35965 12/05/26 07:01:20 INFO server.NIOServerCnxn: Client attempting to establish new session at /127.0.0.1:35965 12/05/26 07:01:20 INFO server.NIOServerCnxn: Established session 0x13787e83eae0021 with negotiated timeout 40000 for client /127.0.0.1:35965 12/05/26 07:01:20 INFO zookeeper.ClientCnxn: Session establishment complete on server localhost/127.0.0.1:21818, sessionid = 0x13787e83eae0021, negotiated timeout = 40000 12/05/26 07:01:20 WARN zookeeper.ZKTable: Moving table WebPage state to enabled but was already enabled 12/05/26 07:01:20 INFO server.PrepRequestProcessor: Got user-level KeeperException when processing sessionid:0x13787e83eae0000 type:delete cxid:0x494 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/hbase/table/WebPage Error:KeeperErrorCode = NoNode for /hbase/table/WebPage 12/05/26 07:01:20 INFO wal.HLog: HLog configuration: blocksize=64 MB, rollsize=60.8 MB, enabled=true, optionallogflushinternal=1000ms 12/05/26 07:01:20 INFO wal.SequenceFileLogWriter: syncFs -- HDFS-200 -- not available, dfs.support.append=false 12/05/26 07:01:20 INFO wal.HLog: New hlog /user/hudson/WebPage/59eec86722ffb36c6c55c710598a11ea/.logs/hlog.1338015680073 12/05/26 07:01:20 INFO wal.HLog: Using getNumCurrentReplicas--HDFS-826 12/05/26 07:01:20 INFO hdfs.StateChange: BLOCK* NameSystem.allocateBlock: /user/hudson/WebPage/59eec86722ffb36c6c55c710598a11ea/.tmp/.regioninfo. blk_1450009752543371551_1105 12/05/26 07:01:20 INFO datanode.DataNode: Receiving block blk_1450009752543371551_1105 src: /127.0.0.1:35966 dest: /127.0.0.1:34519 12/05/26 07:01:20 INFO DataNode.clienttrace: src: /127.0.0.1:35966, dest: /127.0.0.1:34519, bytes: 1892, op: HDFS_WRITE, cliID: DFSClient_557503250, offset: 0, srvID: DS-531900178-192.87.106.251-34519-1338014972975, blockid: blk_1450009752543371551_1105, duration: 1105144 12/05/26 07:01:20 INFO datanode.DataNode: PacketResponder 0 for block blk_1450009752543371551_1105 terminating 12/05/26 07:01:20 INFO hdfs.StateChange: BLOCK* NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:34519 is added to blk_1450009752543371551_1105 size 1892 12/05/26 07:01:20 INFO hdfs.StateChange: Removing lease on file /user/hudson/WebPage/59eec86722ffb36c6c55c710598a11ea/.tmp/.regioninfo from client DFSClient_557503250 12/05/26 07:01:20 INFO hdfs.StateChange: DIR* NameSystem.completeFile: file /user/hudson/WebPage/59eec86722ffb36c6c55c710598a11ea/.tmp/.regioninfo is closed by DFSClient_557503250 12/05/26 07:01:20 INFO regionserver.HRegion: Onlined WebPage,,1338015680054.59eec86722ffb36c6c55c710598a11ea.; next sequenceid=1 12/05/26 07:01:20 INFO catalog.MetaEditor: Added region WebPage,,1338015680054.59eec86722ffb36c6c55c710598a11ea. to META 12/05/26 07:01:20 INFO regionserver.HRegion: Closed WebPage,,1338015680054.59eec86722ffb36c6c55c710598a11ea. 12/05/26 07:01:20 INFO wal.HLog: IPC Server handler 1 on 34526.logSyncer exiting 12/05/26 07:01:20 INFO hdfs.StateChange: BLOCK* NameSystem.allocateBlock: /user/hudson/WebPage/59eec86722ffb36c6c55c710598a11ea/.logs/hlog.1338015680073. blk_-5986318168678310834_1105 12/05/26 07:01:20 INFO datanode.DataNode: Receiving block blk_-5986318168678310834_1105 src: /127.0.0.1:35967 dest: /127.0.0.1:34519 12/05/26 07:01:20 INFO DataNode.clienttrace: src: /127.0.0.1:35967, dest: /127.0.0.1:34519, bytes: 124, op: HDFS_WRITE, cliID: DFSClient_557503250, offset: 0, srvID: DS-531900178-192.87.106.251-34519-1338014972975, blockid: blk_-5986318168678310834_1105, duration: 2108880 12/05/26 07:01:20 INFO datanode.DataNode: PacketResponder 0 for block blk_-5986318168678310834_1105 terminating 12/05/26 07:01:20 INFO hdfs.StateChange: BLOCK* NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:34519 is added to blk_-5986318168678310834_1105 size 124 12/05/26 07:01:21 INFO hdfs.StateChange: Removing lease on file /user/hudson/WebPage/59eec86722ffb36c6c55c710598a11ea/.logs/hlog.1338015680073 from client DFSClient_557503250 12/05/26 07:01:21 INFO hdfs.StateChange: DIR* NameSystem.completeFile: file /user/hudson/WebPage/59eec86722ffb36c6c55c710598a11ea/.logs/hlog.1338015680073 is closed by DFSClient_557503250 12/05/26 07:01:21 INFO regionserver.HRegionServer: Received request to open region: WebPage,,1338015680054.59eec86722ffb36c6c55c710598a11ea. 12/05/26 07:01:21 INFO regionserver.HRegion: Onlined WebPage,,1338015680054.59eec86722ffb36c6c55c710598a11ea.; next sequenceid=1 12/05/26 07:01:21 INFO catalog.MetaEditor: Updated row WebPage,,1338015680054.59eec86722ffb36c6c55c710598a11ea. in region .META.,,1 with server=hudson_solaris:34530, startcode=1338014976212 12/05/26 07:01:26 INFO gora.GoraTestDriver: setting up test 12/05/26 07:01:26 INFO handler.DisableTableHandler: Attemping to disable table Employee 12/05/26 07:01:26 INFO client.HBaseAdmin: Started disable of Employee 12/05/26 07:01:26 INFO handler.DisableTableHandler: Offlining 1 regions. 12/05/26 07:01:26 INFO regionserver.HRegionServer: Received close region: Employee,,1338015674500.a58a76d497a4616abc7c6c47fbc9bd99. 12/05/26 07:01:26 INFO regionserver.HRegion: Closed Employee,,1338015674500.a58a76d497a4616abc7c6c47fbc9bd99. 12/05/26 07:01:27 INFO handler.DisableTableHandler: Disabled table is done=true 12/05/26 07:01:31 INFO client.HBaseAdmin: Disabled Employee 12/05/26 07:01:31 INFO handler.TableEventHandler: Handling table operation C_M_DELETE_TABLE on table Employee 12/05/26 07:01:31 INFO catalog.MetaEditor: Deleted region Employee,,1338015674500.a58a76d497a4616abc7c6c47fbc9bd99. from META 12/05/26 07:01:31 INFO hdfs.StateChange: BLOCK* NameSystem.addToInvalidates: blk_399910535230890227 is added to invalidSet of 127.0.0.1:34519 12/05/26 07:01:31 INFO hdfs.StateChange: BLOCK* NameSystem.addToInvalidates: blk_8342440413718110761 is added to invalidSet of 127.0.0.1:34519 12/05/26 07:01:31 INFO hdfs.StateChange: BLOCK* ask 127.0.0.1:34519 to delete blk_399910535230890227_1103 blk_8342440413718110761_1103 12/05/26 07:01:31 INFO datanode.DataNode: Scheduling block blk_399910535230890227_1103 file <https://builds.apache.org/job/gora-trunk/ws/trunk./gora-hbase/target/test-data/55ed0b77-4552-4eb5-8c2c-f52732bc5d41/dfs/data/data1/current/blk_399910535230890227> for deletion 12/05/26 07:01:31 INFO datanode.DataNode: Scheduling block blk_8342440413718110761_1103 file <https://builds.apache.org/job/gora-trunk/ws/trunk./gora-hbase/target/test-data/55ed0b77-4552-4eb5-8c2c-f52732bc5d41/dfs/data/data2/current/blk_8342440413718110761> for deletion 12/05/26 07:01:31 INFO datanode.DataNode: Deleted block blk_399910535230890227_1103 at file <https://builds.apache.org/job/gora-trunk/ws/trunk./gora-hbase/target/test-data/55ed0b77-4552-4eb5-8c2c-f52732bc5d41/dfs/data/data1/current/blk_399910535230890227> 12/05/26 07:01:31 INFO datanode.DataNode: Deleted block blk_8342440413718110761_1103 at file <https://builds.apache.org/job/gora-trunk/ws/trunk./gora-hbase/target/test-data/55ed0b77-4552-4eb5-8c2c-f52732bc5d41/dfs/data/data2/current/blk_8342440413718110761> Build timed out (after 120 minutes). Marking the build as failed. 12/05/26 07:01:36 INFO client.HBaseAdmin: Deleted Employee 12/05/26 07:01:36 WARN zookeeper.ZKTable: Moving table Employee state to enabled but was already enabled 12/05/26 07:01:36 INFO server.PrepRequestProcessor: Got user-level KeeperException when processing sessionid:0x13787e83eae0000 type:delete cxid:0x4af zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/hbase/table/Employee Error:KeeperErrorCode = NoNode for /hbase/table/Employee 12/05/26 07:01:36 INFO wal.HLog: HLog configuration: blocksize=64 MB, rollsize=60.8 MB, enabled=true, optionallogflushinternal=1000ms 12/05/26 07:01:36 INFO wal.SequenceFileLogWriter: syncFs -- HDFS-200 -- not available, dfs.support.append=false 12/05/26 07:01:36 INFO wal.HLog: New hlog /user/hudson/Employee/3eb2a6e9945f33e7e9ee5be53c07b933/.logs/hlog.1338015696131 12/05/26 07:01:36 INFO wal.HLog: Using getNumCurrentReplicas--HDFS-826 12/05/26 07:01:36 INFO hdfs.StateChange: BLOCK* NameSystem.allocateBlock: /user/hudson/Employee/3eb2a6e9945f33e7e9ee5be53c07b933/.tmp/.regioninfo. blk_-2822330889576646630_1107 12/05/26 07:01:36 INFO datanode.DataNode: Receiving block blk_-2822330889576646630_1107 src: /127.0.0.1:35986 dest: /127.0.0.1:34519 12/05/26 07:01:36 INFO DataNode.clienttrace: src: /127.0.0.1:35986, dest: /127.0.0.1:34519, bytes: 720, op: HDFS_WRITE, cliID: DFSClient_557503250, offset: 0, srvID: DS-531900178-192.87.106.251-34519-1338014972975, blockid: blk_-2822330889576646630_1107, duration: 1247552 12/05/26 07:01:36 INFO datanode.DataNode: PacketResponder 0 for block blk_-2822330889576646630_1107 terminating 12/05/26 07:01:36 INFO hdfs.StateChange: BLOCK* NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:34519 is added to blk_-2822330889576646630_1107 size 720 12/05/26 07:01:36 INFO hdfs.StateChange: Removing lease on file /user/hudson/Employee/3eb2a6e9945f33e7e9ee5be53c07b933/.tmp/.regioninfo from client DFSClient_557503250 12/05/26 07:01:36 INFO hdfs.StateChange: DIR* NameSystem.completeFile: file /user/hudson/Employee/3eb2a6e9945f33e7e9ee5be53c07b933/.tmp/.regioninfo is closed by DFSClient_557503250 12/05/26 07:01:36 INFO regionserver.HRegion: Onlined Employee,,1338015696116.3eb2a6e9945f33e7e9ee5be53c07b933.; next sequenceid=1 12/05/26 07:01:36 INFO catalog.MetaEditor: Added region Employee,,1338015696116.3eb2a6e9945f33e7e9ee5be53c07b933. to META 12/05/26 07:01:36 INFO regionserver.HRegion: Closed Employee,,1338015696116.3eb2a6e9945f33e7e9ee5be53c07b933. 12/05/26 07:01:36 INFO wal.HLog: IPC Server handler 0 on 34526.logSyncer exiting 12/05/26 07:01:36 INFO hdfs.StateChange: BLOCK* NameSystem.allocateBlock: /user/hudson/Employee/3eb2a6e9945f33e7e9ee5be53c07b933/.logs/hlog.1338015696131. blk_-5425765802159357090_1107 12/05/26 07:01:36 INFO datanode.DataNode: Receiving block blk_-5425765802159357090_1107 src: /127.0.0.1:35987 dest: /127.0.0.1:34519 12/05/26 07:01:36 INFO DataNode.clienttrace: src: /127.0.0.1:35987, dest: /127.0.0.1:34519, bytes: 124, op: HDFS_WRITE, cliID: DFSClient_557503250, offset: 0, srvID: DS-531900178-192.87.106.251-34519-1338014972975, blockid: blk_-5425765802159357090_1107, duration: 1302112 12/05/26 07:01:36 INFO datanode.DataNode: PacketResponder 0 for block blk_-5425765802159357090_1107 terminating 12/05/26 07:01:36 INFO hdfs.StateChange: BLOCK* NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:34519 is added to blk_-5425765802159357090_1107 size 124 12/05/26 07:01:36 INFO hdfs.StateChange: Removing lease on file /user/hudson/Employee/3eb2a6e9945f33e7e9ee5be53c07b933/.logs/hlog.1338015696131 from client DFSClient_557503250 12/05/26 07:01:36 INFO hdfs.StateChange: DIR* NameSystem.completeFile: file /user/hudson/Employee/3eb2a6e9945f33e7e9ee5be53c07b933/.logs/hlog.1338015696131 is closed by DFSClient_557503250 12/05/26 07:01:36 INFO regionserver.HRegionServer: Received request to open region: Employee,,1338015696116.3eb2a6e9945f33e7e9ee5be53c07b933. 12/05/26 07:01:37 INFO regionserver.HRegion: Onlined Employee,,1338015696116.3eb2a6e9945f33e7e9ee5be53c07b933.; next sequenceid=1 12/05/26 07:01:37 INFO catalog.MetaEditor: Updated row Employee,,1338015696116.3eb2a6e9945f33e7e9ee5be53c07b933. in region .META.,,1 with server=hudson_solaris:34530, startcode=1338014976212 12/05/26 07:01:42 INFO handler.DisableTableHandler: Attemping to disable table WebPage 12/05/26 07:01:42 INFO client.HBaseAdmin: Started disable of WebPage 12/05/26 07:01:42 INFO handler.DisableTableHandler: Offlining 1 regions. 12/05/26 07:01:42 INFO regionserver.HRegionServer: Received close region: WebPage,,1338015680054.59eec86722ffb36c6c55c710598a11ea. 12/05/26 07:01:42 INFO regionserver.HRegion: Closed WebPage,,1338015680054.59eec86722ffb36c6c55c710598a11ea. 12/05/26 07:01:43 INFO handler.DisableTableHandler: Disabled table is done=true 12/05/26 07:01:47 INFO client.HBaseAdmin: Disabled WebPage 12/05/26 07:01:47 INFO handler.TableEventHandler: Handling table operation C_M_DELETE_TABLE on table WebPage 12/05/26 07:01:47 INFO catalog.MetaEditor: Deleted region WebPage,,1338015680054.59eec86722ffb36c6c55c710598a11ea. from META 12/05/26 07:01:47 INFO hdfs.StateChange: BLOCK* NameSystem.addToInvalidates: blk_-5986318168678310834 is added to invalidSet of 127.0.0.1:34519 12/05/26 07:01:47 INFO hdfs.StateChange: BLOCK* NameSystem.addToInvalidates: blk_1450009752543371551 is added to invalidSet of 127.0.0.1:34519 12/05/26 07:01:49 INFO hdfs.StateChange: BLOCK* ask 127.0.0.1:34519 to delete blk_1450009752543371551_1105 blk_-5986318168678310834_1105 12/05/26 07:01:49 INFO datanode.DataNode: Scheduling block blk_-5986318168678310834_1105 file <https://builds.apache.org/job/gora-trunk/ws/trunk./gora-hbase/target/test-data/55ed0b77-4552-4eb5-8c2c-f52732bc5d41/dfs/data/data1/current/blk_-5986318168678310834> for deletion 12/05/26 07:01:49 INFO datanode.DataNode: Scheduling block blk_1450009752543371551_1105 file <https://builds.apache.org/job/gora-trunk/ws/trunk./gora-hbase/target/test-data/55ed0b77-4552-4eb5-8c2c-f52732bc5d41/dfs/data/data2/current/blk_1450009752543371551> for deletion 12/05/26 07:01:49 INFO datanode.DataNode: Deleted block blk_-5986318168678310834_1105 at file <https://builds.apache.org/job/gora-trunk/ws/trunk./gora-hbase/target/test-data/55ed0b77-4552-4eb5-8c2c-f52732bc5d41/dfs/data/data1/current/blk_-5986318168678310834> 12/05/26 07:01:49 INFO datanode.DataNode: Deleted block blk_1450009752543371551_1105 at file <https://builds.apache.org/job/gora-trunk/ws/trunk./gora-hbase/target/test-data/55ed0b77-4552-4eb5-8c2c-f52732bc5d41/dfs/data/data2/current/blk_1450009752543371551> 12/05/26 07:01:52 INFO client.HBaseAdmin: Deleted WebPage 12/05/26 07:01:52 WARN zookeeper.ZKTable: Moving table WebPage state to enabled but was already enabled 12/05/26 07:01:52 INFO server.PrepRequestProcessor: Got user-level KeeperException when processing sessionid:0x13787e83eae0000 type:delete cxid:0x4ca zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/hbase/table/WebPage Error:KeeperErrorCode = NoNode for /hbase/table/WebPage 12/05/26 07:01:52 INFO wal.HLog: HLog configuration: blocksize=64 MB, rollsize=60.8 MB, enabled=true, optionallogflushinternal=1000ms 12/05/26 07:01:52 INFO wal.SequenceFileLogWriter: syncFs -- HDFS-200 -- not available, dfs.support.append=false 12/05/26 07:01:52 INFO wal.HLog: New hlog /user/hudson/WebPage/07f91498906785f8549c7899460560e7/.logs/hlog.1338015712063 12/05/26 07:01:52 INFO wal.HLog: Using getNumCurrentReplicas--HDFS-826 12/05/26 07:01:52 INFO hdfs.StateChange: BLOCK* NameSystem.allocateBlock: /user/hudson/WebPage/07f91498906785f8549c7899460560e7/.tmp/.regioninfo. blk_-5476337004793552046_1109 12/05/26 07:01:52 INFO datanode.DataNode: Receiving block blk_-5476337004793552046_1109 src: /127.0.0.1:36015 dest: /127.0.0.1:34519 12/05/26 07:01:52 INFO DataNode.clienttrace: src: /127.0.0.1:36015, dest: /127.0.0.1:34519, bytes: 1892, op: HDFS_WRITE, cliID: DFSClient_557503250, offset: 0, srvID: DS-531900178-192.87.106.251-34519-1338014972975, blockid: blk_-5476337004793552046_1109, duration: 1117066 12/05/26 07:01:52 INFO datanode.DataNode: PacketResponder 0 for block blk_-5476337004793552046_1109 terminating 12/05/26 07:01:52 INFO hdfs.StateChange: BLOCK* NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:34519 is added to blk_-5476337004793552046_1109 size 1892 12/05/26 07:01:52 INFO hdfs.StateChange: Removing lease on file /user/hudson/WebPage/07f91498906785f8549c7899460560e7/.tmp/.regioninfo from client DFSClient_557503250 12/05/26 07:01:52 INFO hdfs.StateChange: DIR* NameSystem.completeFile: file /user/hudson/WebPage/07f91498906785f8549c7899460560e7/.tmp/.regioninfo is closed by DFSClient_557503250 12/05/26 07:01:52 INFO regionserver.HRegion: Onlined WebPage,,1338015712048.07f91498906785f8549c7899460560e7.; next sequenceid=1 12/05/26 07:01:52 INFO catalog.MetaEditor: Added region WebPage,,1338015712048.07f91498906785f8549c7899460560e7. to META 12/05/26 07:01:52 INFO regionserver.HRegion: Closed WebPage,,1338015712048.07f91498906785f8549c7899460560e7. 12/05/26 07:01:52 INFO wal.HLog: IPC Server handler 2 on 34526.logSyncer exiting 12/05/26 07:01:52 INFO hdfs.StateChange: BLOCK* NameSystem.allocateBlock: /user/hudson/WebPage/07f91498906785f8549c7899460560e7/.logs/hlog.1338015712063. blk_-8007423273821588464_1109 12/05/26 07:01:52 INFO datanode.DataNode: Receiving block blk_-8007423273821588464_1109 src: /127.0.0.1:36017 dest: /127.0.0.1:34519 12/05/26 07:01:52 INFO DataNode.clienttrace: src: /127.0.0.1:36017, dest: /127.0.0.1:34519, bytes: 124, op: HDFS_WRITE, cliID: DFSClient_557503250, offset: 0, srvID: DS-531900178-192.87.106.251-34519-1338014972975, blockid: blk_-8007423273821588464_1109, duration: 1173121 12/05/26 07:01:52 INFO datanode.DataNode: PacketResponder 0 for block blk_-8007423273821588464_1109 terminating 12/05/26 07:01:52 INFO hdfs.StateChange: BLOCK* NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:34519 is added to blk_-8007423273821588464_1109 size 124 12/05/26 07:01:52 INFO hdfs.StateChange: Removing lease on file /user/hudson/WebPage/07f91498906785f8549c7899460560e7/.logs/hlog.1338015712063 from client DFSClient_557503250 12/05/26 07:01:52 INFO hdfs.StateChange: DIR* NameSystem.completeFile: file /user/hudson/WebPage/07f91498906785f8549c7899460560e7/.logs/hlog.1338015712063 is closed by DFSClient_557503250 12/05/26 07:01:52 INFO regionserver.HRegionServer: Received request to open region: WebPage,,1338015712048.07f91498906785f8549c7899460560e7. 12/05/26 07:01:52 INFO regionserver.HRegion: Onlined WebPage,,1338015712048.07f91498906785f8549c7899460560e7.; next sequenceid=1 12/05/26 07:01:52 INFO catalog.MetaEditor: Updated row WebPage,,1338015712048.07f91498906785f8549c7899460560e7. in region .META.,,1 with server=hudson_solaris:34530, startcode=1338014976212 12/05/26 07:01:57 INFO store.DataStoreTestBase: test method: testPut 12/05/26 07:01:57 INFO store.DataStoreTestBase: tearing down test 12/05/26 07:01:57 INFO gora.GoraTestDriver: tearing down test 12/05/26 07:01:57 INFO handler.DisableTableHandler: Attemping to disable table Employee 12/05/26 07:01:57 INFO client.HBaseAdmin: Started disable of Employee 12/05/26 07:01:57 INFO handler.DisableTableHandler: Offlining 1 regions. 12/05/26 07:01:57 INFO regionserver.HRegionServer: Received close region: Employee,,1338015696116.3eb2a6e9945f33e7e9ee5be53c07b933. 12/05/26 07:01:57 INFO regionserver.HRegion: Closed Employee,,1338015696116.3eb2a6e9945f33e7e9ee5be53c07b933. 12/05/26 07:01:59 INFO handler.DisableTableHandler: Disabled table is done=true 12/05/26 07:02:02 INFO client.HBaseAdmin: Disabled Employee 12/05/26 07:02:02 INFO handler.TableEventHandler: Handling table operation C_M_DELETE_TABLE on table Employee 12/05/26 07:02:02 INFO catalog.MetaEditor: Deleted region Employee,,1338015696116.3eb2a6e9945f33e7e9ee5be53c07b933. from META 12/05/26 07:02:02 INFO hdfs.StateChange: BLOCK* NameSystem.addToInvalidates: blk_-5425765802159357090 is added to invalidSet of 127.0.0.1:34519 12/05/26 07:02:03 INFO hdfs.StateChange: BLOCK* NameSystem.addToInvalidates: blk_-2822330889576646630 is added to invalidSet of 127.0.0.1:34519 12/05/26 07:02:04 INFO hdfs.StateChange: BLOCK* ask 127.0.0.1:34519 to delete blk_-5425765802159357090_1107 blk_-2822330889576646630_1107 12/05/26 07:02:04 INFO datanode.DataNode: Scheduling block blk_-5425765802159357090_1107 file <https://builds.apache.org/job/gora-trunk/ws/trunk./gora-hbase/target/test-data/55ed0b77-4552-4eb5-8c2c-f52732bc5d41/dfs/data/data1/current/blk_-5425765802159357090> for deletion 12/05/26 07:02:04 INFO datanode.DataNode: Scheduling block blk_-2822330889576646630_1107 file <https://builds.apache.org/job/gora-trunk/ws/trunk./gora-hbase/target/test-data/55ed0b77-4552-4eb5-8c2c-f52732bc5d41/dfs/data/data2/current/blk_-2822330889576646630> for deletion 12/05/26 07:02:04 INFO datanode.DataNode: Deleted block blk_-5425765802159357090_1107 at file <https://builds.apache.org/job/gora-trunk/ws/trunk./gora-hbase/target/test-data/55ed0b77-4552-4eb5-8c2c-f52732bc5d41/dfs/data/data1/current/blk_-5425765802159357090> 12/05/26 07:02:04 INFO datanode.DataNode: Deleted block blk_-2822330889576646630_1107 at file <https://builds.apache.org/job/gora-trunk/ws/trunk./gora-hbase/target/test-data/55ed0b77-4552-4eb5-8c2c-f52732bc5d41/dfs/data/data2/current/blk_-2822330889576646630> 12/05/26 07:02:07 INFO client.HBaseAdmin: Deleted Employee 12/05/26 07:02:08 INFO handler.DisableTableHandler: Attemping to disable table WebPage 12/05/26 07:02:08 INFO client.HBaseAdmin: Started disable of WebPage 12/05/26 07:02:08 INFO handler.DisableTableHandler: Offlining 1 regions. 12/05/26 07:02:08 INFO regionserver.HRegionServer: Received close region: WebPage,,1338015712048.07f91498906785f8549c7899460560e7. 12/05/26 07:02:08 INFO regionserver.HRegion: Closed WebPage,,1338015712048.07f91498906785f8549c7899460560e7. 12/05/26 07:02:09 INFO handler.DisableTableHandler: Disabled table is done=true channel stopped
