See <https://builds.apache.org/job/Tajo-0.8.0-build/64/changes>
Changes:
[jinossy] TAJO-717: Improve file splitting for large number of splits. (jinho)
[jinossy] TAJO-743: Change the default resource allocation policy of leaf
tasks. (jinho)
------------------------------------------
[...truncated 4788 lines...]
2014-04-10 06:30:02,847 INFO [IPC Server handler 5 on 50408]
FSNamesystem.audit (FSNamesystem.java:logAuditMessage(7409)) - allowed=true
ugi=jenkins (auth:SIMPLE) ip=/127.0.0.1 cmd=open
src=/testGetSplitWithBlockStorageLocationsBatching/tmpfile91.dat
dst=null perm=null
2014-04-10 06:30:02,849 INFO [IPC Server handler 8 on 50408]
FSNamesystem.audit (FSNamesystem.java:logAuditMessage(7409)) - allowed=true
ugi=jenkins (auth:SIMPLE) ip=/127.0.0.1 cmd=open
src=/testGetSplitWithBlockStorageLocationsBatching/tmpfile92.dat
dst=null perm=null
2014-04-10 06:30:02,850 INFO [IPC Server handler 7 on 50408]
FSNamesystem.audit (FSNamesystem.java:logAuditMessage(7409)) - allowed=true
ugi=jenkins (auth:SIMPLE) ip=/127.0.0.1 cmd=open
src=/testGetSplitWithBlockStorageLocationsBatching/tmpfile93.dat
dst=null perm=null
2014-04-10 06:30:02,851 INFO [IPC Server handler 9 on 50408]
FSNamesystem.audit (FSNamesystem.java:logAuditMessage(7409)) - allowed=true
ugi=jenkins (auth:SIMPLE) ip=/127.0.0.1 cmd=open
src=/testGetSplitWithBlockStorageLocationsBatching/tmpfile94.dat
dst=null perm=null
2014-04-10 06:30:02,853 INFO [IPC Server handler 0 on 50408]
FSNamesystem.audit (FSNamesystem.java:logAuditMessage(7409)) - allowed=true
ugi=jenkins (auth:SIMPLE) ip=/127.0.0.1 cmd=open
src=/testGetSplitWithBlockStorageLocationsBatching/tmpfile95.dat
dst=null perm=null
2014-04-10 06:30:02,854 INFO [IPC Server handler 2 on 50408]
FSNamesystem.audit (FSNamesystem.java:logAuditMessage(7409)) - allowed=true
ugi=jenkins (auth:SIMPLE) ip=/127.0.0.1 cmd=open
src=/testGetSplitWithBlockStorageLocationsBatching/tmpfile96.dat
dst=null perm=null
2014-04-10 06:30:02,856 INFO [IPC Server handler 1 on 50408]
FSNamesystem.audit (FSNamesystem.java:logAuditMessage(7409)) - allowed=true
ugi=jenkins (auth:SIMPLE) ip=/127.0.0.1 cmd=open
src=/testGetSplitWithBlockStorageLocationsBatching/tmpfile97.dat
dst=null perm=null
2014-04-10 06:30:02,857 INFO [IPC Server handler 3 on 50408]
FSNamesystem.audit (FSNamesystem.java:logAuditMessage(7409)) - allowed=true
ugi=jenkins (auth:SIMPLE) ip=/127.0.0.1 cmd=open
src=/testGetSplitWithBlockStorageLocationsBatching/tmpfile98.dat
dst=null perm=null
2014-04-10 06:30:02,858 INFO [IPC Server handler 4 on 50408]
FSNamesystem.audit (FSNamesystem.java:logAuditMessage(7409)) - allowed=true
ugi=jenkins (auth:SIMPLE) ip=/127.0.0.1 cmd=open
src=/testGetSplitWithBlockStorageLocationsBatching/tmpfile99.dat
dst=null perm=null
2014-04-10 06:30:03,110 INFO [main] hdfs.BlockStorageLocationUtil
(BlockStorageLocationUtil.java:queryDatanodesForHdfsBlocksMetadata(156)) -
Failed to connect to datanode 127.0.0.1:48807
2014-04-10 06:30:03,110 WARN [IPC Server handler 0 on 48807] ipc.Server
(Server.java:processResponse(973)) - IPC Server handler 0 on 48807, call
org.apache.hadoop.hdfs.protocol.ClientDatanodeProtocol.getHdfsBlockLocations
from 127.0.0.1:34556 Call#2125 Retry#0: output error
2014-04-10 06:30:03,110 WARN [IPC Server handler 1 on 36656] ipc.Server
(Server.java:processResponse(973)) - IPC Server handler 1 on 36656, call
org.apache.hadoop.hdfs.protocol.ClientDatanodeProtocol.getHdfsBlockLocations
from 127.0.0.1:55251 Call#2124 Retry#0: output error
2014-04-10 06:30:03,111 INFO [main] hdfs.BlockStorageLocationUtil
(BlockStorageLocationUtil.java:queryDatanodesForHdfsBlocksMetadata(156)) -
Failed to connect to datanode 127.0.0.1:36656
2014-04-10 06:30:03,112 INFO [IPC Server handler 0 on 48807] ipc.Server
(Server.java:run(2025)) - IPC Server handler 0 on 48807 caught an exception
java.nio.channels.ClosedChannelException
at
sun.nio.ch.SocketChannelImpl.ensureWriteOpen(SocketChannelImpl.java:133)
at sun.nio.ch.SocketChannelImpl.write(SocketChannelImpl.java:324)
at org.apache.hadoop.ipc.Server.channelWrite(Server.java:2482)
at org.apache.hadoop.ipc.Server.access$1900(Server.java:124)
at
org.apache.hadoop.ipc.Server$Responder.processResponse(Server.java:923)
at org.apache.hadoop.ipc.Server$Responder.doRespond(Server.java:988)
at org.apache.hadoop.ipc.Server$Handler.run(Server.java:2018)
2014-04-10 06:30:03,113 INFO [IPC Server handler 1 on 36656] ipc.Server
(Server.java:run(2025)) - IPC Server handler 1 on 36656 caught an exception
java.nio.channels.ClosedChannelException
at
sun.nio.ch.SocketChannelImpl.ensureWriteOpen(SocketChannelImpl.java:133)
at sun.nio.ch.SocketChannelImpl.write(SocketChannelImpl.java:324)
at org.apache.hadoop.ipc.Server.channelWrite(Server.java:2482)
at org.apache.hadoop.ipc.Server.access$1900(Server.java:124)
at
org.apache.hadoop.ipc.Server$Responder.processResponse(Server.java:923)
at org.apache.hadoop.ipc.Server$Responder.doRespond(Server.java:988)
at org.apache.hadoop.ipc.Server$Handler.run(Server.java:2018)
2014-04-10 06:30:03,115 INFO [main] storage.AbstractStorageManager
(AbstractStorageManager.java:setVolumeMeta(658)) - # of splits with volumeId 100
2014-04-10 06:30:03,115 INFO [main] storage.AbstractStorageManager
(AbstractStorageManager.java:getSplits(622)) - Total # of splits: 100
2014-04-10 06:30:03,115 INFO [main] hdfs.MiniDFSCluster
(MiniDFSCluster.java:shutdown(1445)) - Shutting down the Mini HDFS Cluster
2014-04-10 06:30:03,115 INFO [main] hdfs.MiniDFSCluster
(MiniDFSCluster.java:shutdownDataNodes(1477)) - Shutting down DataNode 1
2014-04-10 06:30:03,115 WARN [main] datanode.DirectoryScanner
(DirectoryScanner.java:shutdown(376)) - DirectoryScanner: shutdown has been
called
2014-04-10 06:30:03,121 INFO [main] mortbay.log (Slf4jLog.java:info(67)) -
Stopped [email protected]:0
2014-04-10 06:30:03,221 INFO [main] ipc.Server (Server.java:stop(2342)) -
Stopping server on 36656
2014-04-10 06:30:03,223 INFO [IPC Server listener on 36656] ipc.Server
(Server.java:run(652)) - Stopping IPC Server listener on 36656
2014-04-10 06:30:03,223 INFO [main] datanode.DataNode
(DataNode.java:shutdown(1265)) - Waiting for threadgroup to exit, active
threads is 1
2014-04-10 06:30:03,223 INFO [IPC Server Responder] ipc.Server
(Server.java:run(778)) - Stopping IPC Server Responder
2014-04-10 06:30:03,224 WARN [DataNode:
[[[DISK]<https://builds.apache.org/job/Tajo-0.8.0-build/ws/tajo-storage/target/test-data/TestStorageManager/45d979cf-b725-438f-be63-4b07c2602d2b/data/data3/,>
[DISK]<https://builds.apache.org/job/Tajo-0.8.0-build/ws/tajo-storage/target/test-data/TestStorageManager/45d979cf-b725-438f-be63-4b07c2602d2b/data/data4/]]>
heartbeating to localhost/127.0.0.1:50408] datanode.DataNode
(BPServiceActor.java:offerService(685)) - BPOfferService for Block pool
BP-237417143-67.195.138.31-1397111400114 (Datanode Uuid
bc73abdb-b2e8-4bd8-b96a-25a04aa8724b) service to localhost/127.0.0.1:50408
interrupted
2014-04-10 06:30:03,224 WARN [DataNode:
[[[DISK]<https://builds.apache.org/job/Tajo-0.8.0-build/ws/tajo-storage/target/test-data/TestStorageManager/45d979cf-b725-438f-be63-4b07c2602d2b/data/data3/,>
[DISK]<https://builds.apache.org/job/Tajo-0.8.0-build/ws/tajo-storage/target/test-data/TestStorageManager/45d979cf-b725-438f-be63-4b07c2602d2b/data/data4/]]>
heartbeating to localhost/127.0.0.1:50408] datanode.DataNode
(BPServiceActor.java:run(795)) - Ending block pool service for: Block pool
BP-237417143-67.195.138.31-1397111400114 (Datanode Uuid
bc73abdb-b2e8-4bd8-b96a-25a04aa8724b) service to localhost/127.0.0.1:50408
2014-04-10 06:30:03,224 INFO [DataNode:
[[[DISK]<https://builds.apache.org/job/Tajo-0.8.0-build/ws/tajo-storage/target/test-data/TestStorageManager/45d979cf-b725-438f-be63-4b07c2602d2b/data/data3/,>
[DISK]<https://builds.apache.org/job/Tajo-0.8.0-build/ws/tajo-storage/target/test-data/TestStorageManager/45d979cf-b725-438f-be63-4b07c2602d2b/data/data4/]]>
heartbeating to localhost/127.0.0.1:50408] datanode.DataNode
(BlockPoolManager.java:remove(99)) - Removed Block pool
BP-237417143-67.195.138.31-1397111400114 (Datanode Uuid
bc73abdb-b2e8-4bd8-b96a-25a04aa8724b)
2014-04-10 06:30:03,224 INFO [DataNode:
[[[DISK]<https://builds.apache.org/job/Tajo-0.8.0-build/ws/tajo-storage/target/test-data/TestStorageManager/45d979cf-b725-438f-be63-4b07c2602d2b/data/data3/,>
[DISK]<https://builds.apache.org/job/Tajo-0.8.0-build/ws/tajo-storage/target/test-data/TestStorageManager/45d979cf-b725-438f-be63-4b07c2602d2b/data/data4/]]>
heartbeating to localhost/127.0.0.1:50408] datanode.DataBlockScanner
(DataBlockScanner.java:removeBlockPool(274)) - Removed
bpid=BP-237417143-67.195.138.31-1397111400114 from blockPoolScannerMap
2014-04-10 06:30:03,225 INFO [DataNode:
[[[DISK]<https://builds.apache.org/job/Tajo-0.8.0-build/ws/tajo-storage/target/test-data/TestStorageManager/45d979cf-b725-438f-be63-4b07c2602d2b/data/data3/,>
[DISK]<https://builds.apache.org/job/Tajo-0.8.0-build/ws/tajo-storage/target/test-data/TestStorageManager/45d979cf-b725-438f-be63-4b07c2602d2b/data/data4/]]>
heartbeating to localhost/127.0.0.1:50408] impl.FsDatasetImpl
(FsDatasetImpl.java:shutdownBlockPool(1775)) - Removing block pool
BP-237417143-67.195.138.31-1397111400114
2014-04-10 06:30:03,225 INFO [main] impl.FsDatasetAsyncDiskService
(FsDatasetAsyncDiskService.java:shutdown(139)) - Shutting down all async disk
service threads
2014-04-10 06:30:03,225 INFO [main] impl.FsDatasetAsyncDiskService
(FsDatasetAsyncDiskService.java:shutdown(147)) - All async disk service threads
have been shut down
2014-04-10 06:30:03,226 INFO [main] hdfs.MiniDFSCluster
(MiniDFSCluster.java:shutdownDataNodes(1477)) - Shutting down DataNode 0
2014-04-10 06:30:03,226 WARN [main] datanode.DirectoryScanner
(DirectoryScanner.java:shutdown(376)) - DirectoryScanner: shutdown has been
called
2014-04-10 06:30:03,228 INFO [main] mortbay.log (Slf4jLog.java:info(67)) -
Stopped [email protected]:0
2014-04-10 06:30:03,328 INFO [main] ipc.Server (Server.java:stop(2342)) -
Stopping server on 48807
2014-04-10 06:30:03,330 INFO [IPC Server listener on 48807] ipc.Server
(Server.java:run(652)) - Stopping IPC Server listener on 48807
2014-04-10 06:30:03,330 INFO [main] datanode.DataNode
(DataNode.java:shutdown(1265)) - Waiting for threadgroup to exit, active
threads is 1
2014-04-10 06:30:03,330 INFO [IPC Server Responder] ipc.Server
(Server.java:run(778)) - Stopping IPC Server Responder
2014-04-10 06:30:03,331 WARN [DataNode:
[[[DISK]<https://builds.apache.org/job/Tajo-0.8.0-build/ws/tajo-storage/target/test-data/TestStorageManager/45d979cf-b725-438f-be63-4b07c2602d2b/data/data1/,>
[DISK]<https://builds.apache.org/job/Tajo-0.8.0-build/ws/tajo-storage/target/test-data/TestStorageManager/45d979cf-b725-438f-be63-4b07c2602d2b/data/data2/]]>
heartbeating to localhost/127.0.0.1:50408] datanode.DataNode
(BPServiceActor.java:offerService(685)) - BPOfferService for Block pool
BP-237417143-67.195.138.31-1397111400114 (Datanode Uuid
3e97a66c-0e7d-4251-a57e-bfc9f11fb203) service to localhost/127.0.0.1:50408
interrupted
2014-04-10 06:30:03,331 WARN [DataNode:
[[[DISK]<https://builds.apache.org/job/Tajo-0.8.0-build/ws/tajo-storage/target/test-data/TestStorageManager/45d979cf-b725-438f-be63-4b07c2602d2b/data/data1/,>
[DISK]<https://builds.apache.org/job/Tajo-0.8.0-build/ws/tajo-storage/target/test-data/TestStorageManager/45d979cf-b725-438f-be63-4b07c2602d2b/data/data2/]]>
heartbeating to localhost/127.0.0.1:50408] datanode.DataNode
(BPServiceActor.java:run(795)) - Ending block pool service for: Block pool
BP-237417143-67.195.138.31-1397111400114 (Datanode Uuid
3e97a66c-0e7d-4251-a57e-bfc9f11fb203) service to localhost/127.0.0.1:50408
2014-04-10 06:30:03,331 INFO [DataNode:
[[[DISK]<https://builds.apache.org/job/Tajo-0.8.0-build/ws/tajo-storage/target/test-data/TestStorageManager/45d979cf-b725-438f-be63-4b07c2602d2b/data/data1/,>
[DISK]<https://builds.apache.org/job/Tajo-0.8.0-build/ws/tajo-storage/target/test-data/TestStorageManager/45d979cf-b725-438f-be63-4b07c2602d2b/data/data2/]]>
heartbeating to localhost/127.0.0.1:50408] datanode.DataNode
(BlockPoolManager.java:remove(99)) - Removed Block pool
BP-237417143-67.195.138.31-1397111400114 (Datanode Uuid
3e97a66c-0e7d-4251-a57e-bfc9f11fb203)
2014-04-10 06:30:03,332 INFO [DataNode:
[[[DISK]<https://builds.apache.org/job/Tajo-0.8.0-build/ws/tajo-storage/target/test-data/TestStorageManager/45d979cf-b725-438f-be63-4b07c2602d2b/data/data1/,>
[DISK]<https://builds.apache.org/job/Tajo-0.8.0-build/ws/tajo-storage/target/test-data/TestStorageManager/45d979cf-b725-438f-be63-4b07c2602d2b/data/data2/]]>
heartbeating to localhost/127.0.0.1:50408] datanode.DataBlockScanner
(DataBlockScanner.java:removeBlockPool(274)) - Removed
bpid=BP-237417143-67.195.138.31-1397111400114 from blockPoolScannerMap
2014-04-10 06:30:03,332 INFO [DataNode:
[[[DISK]<https://builds.apache.org/job/Tajo-0.8.0-build/ws/tajo-storage/target/test-data/TestStorageManager/45d979cf-b725-438f-be63-4b07c2602d2b/data/data1/,>
[DISK]<https://builds.apache.org/job/Tajo-0.8.0-build/ws/tajo-storage/target/test-data/TestStorageManager/45d979cf-b725-438f-be63-4b07c2602d2b/data/data2/]]>
heartbeating to localhost/127.0.0.1:50408] impl.FsDatasetImpl
(FsDatasetImpl.java:shutdownBlockPool(1775)) - Removing block pool
BP-237417143-67.195.138.31-1397111400114
2014-04-10 06:30:03,332 INFO [main] impl.FsDatasetAsyncDiskService
(FsDatasetAsyncDiskService.java:shutdown(139)) - Shutting down all async disk
service threads
2014-04-10 06:30:03,333 INFO [main] impl.FsDatasetAsyncDiskService
(FsDatasetAsyncDiskService.java:shutdown(147)) - All async disk service threads
have been shut down
2014-04-10 06:30:03,333 INFO [main] namenode.FSNamesystem
(FSNamesystem.java:stopActiveServices(1034)) - Stopping services started for
active state
2014-04-10 06:30:03,333 INFO [main] namenode.FSEditLog
(FSEditLog.java:endCurrentLogSegment(1114)) - Ending log segment 1
2014-04-10 06:30:03,333 INFO
[org.apache.hadoop.hdfs.server.namenode.FSNamesystem$NameNodeEditLogRoller@1f32c4a]
namenode.FSNamesystem (FSNamesystem.java:run(4268)) - NameNodeEditLogRoller
was interrupted, exiting
2014-04-10 06:30:03,352 INFO [main] namenode.FSEditLog
(FSEditLog.java:printStatistics(667)) - Number of transactions: 503 Total time
for transactions(ms): 18 Number of transactions batched in Syncs: 95 Number of
syncs: 308 SyncTimes(ms): 410 353
2014-04-10 06:30:03,353 INFO [main] namenode.FileJournalManager
(FileJournalManager.java:finalizeLogSegment(128)) - Finalizing edits file
<https://builds.apache.org/job/Tajo-0.8.0-build/ws/tajo-storage/target/test-data/TestStorageManager/45d979cf-b725-438f-be63-4b07c2602d2b/name1/current/edits_inprogress_0000000000000000001>
->
<https://builds.apache.org/job/Tajo-0.8.0-build/ws/tajo-storage/target/test-data/TestStorageManager/45d979cf-b725-438f-be63-4b07c2602d2b/name1/current/edits_0000000000000000001-0000000000000000503>
2014-04-10 06:30:03,354 INFO [main] namenode.FileJournalManager
(FileJournalManager.java:finalizeLogSegment(128)) - Finalizing edits file
<https://builds.apache.org/job/Tajo-0.8.0-build/ws/tajo-storage/target/test-data/TestStorageManager/45d979cf-b725-438f-be63-4b07c2602d2b/name2/current/edits_inprogress_0000000000000000001>
->
<https://builds.apache.org/job/Tajo-0.8.0-build/ws/tajo-storage/target/test-data/TestStorageManager/45d979cf-b725-438f-be63-4b07c2602d2b/name2/current/edits_0000000000000000001-0000000000000000503>
2014-04-10 06:30:03,354 INFO [CacheReplicationMonitor(24545724)]
blockmanagement.CacheReplicationMonitor (CacheReplicationMonitor.java:run(167))
- Shutting down CacheReplicationMonitor
2014-04-10 06:30:03,354 INFO [main] ipc.Server (Server.java:stop(2342)) -
Stopping server on 50408
2014-04-10 06:30:03,355 INFO [IPC Server listener on 50408] ipc.Server
(Server.java:run(652)) - Stopping IPC Server listener on 50408
2014-04-10 06:30:03,355 INFO [IPC Server Responder] ipc.Server
(Server.java:run(778)) - Stopping IPC Server Responder
2014-04-10 06:30:03,356 INFO
[org.apache.hadoop.hdfs.server.blockmanagement.BlockManager$ReplicationMonitor@e94c62]
blockmanagement.BlockManager (BlockManager.java:run(3209)) - Stopping
ReplicationMonitor.
2014-04-10 06:30:03,356 WARN
[org.apache.hadoop.hdfs.server.blockmanagement.DecommissionManager$Monitor@13e49a8]
blockmanagement.DecommissionManager (DecommissionManager.java:run(78)) -
Monitor interrupted: java.lang.InterruptedException: sleep interrupted
2014-04-10 06:30:03,363 INFO [main] namenode.FSNamesystem
(FSNamesystem.java:stopActiveServices(1034)) - Stopping services started for
active state
2014-04-10 06:30:03,363 INFO [main] namenode.FSNamesystem
(FSNamesystem.java:stopStandbyServices(1103)) - Stopping services started for
standby state
2014-04-10 06:30:03,365 INFO [main] mortbay.log (Slf4jLog.java:info(67)) -
Stopped [email protected]:0
2014-04-10 06:30:03,466 INFO [main] impl.MetricsSystemImpl
(MetricsSystemImpl.java:stop(200)) - Stopping DataNode metrics system...
2014-04-10 06:30:03,467 INFO [main] impl.MetricsSystemImpl
(MetricsSystemImpl.java:stop(206)) - DataNode metrics system stopped.
2014-04-10 06:30:03,468 INFO [main] impl.MetricsSystemImpl
(MetricsSystemImpl.java:shutdown(572)) - DataNode metrics system shutdown
complete.
Tests run: 3, Failures: 1, Errors: 0, Skipped: 0, Time elapsed: 9.256 sec <<<
FAILURE!
testGetSplitWithBlockStorageLocationsBatching(org.apache.tajo.storage.TestStorageManager)
Time elapsed: 3.452 sec <<< FAILURE!
java.lang.AssertionError: Values should be different. Actual: -1
at org.junit.Assert.fail(Assert.java:88)
at org.junit.Assert.failEquals(Assert.java:185)
at org.junit.Assert.assertNotEquals(Assert.java:161)
at org.junit.Assert.assertNotEquals(Assert.java:198)
at org.junit.Assert.assertNotEquals(Assert.java:209)
at
org.apache.tajo.storage.TestStorageManager.testGetSplitWithBlockStorageLocationsBatching(TestStorageManager.java:193)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at
org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:47)
at
org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
at
org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:44)
at
org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
at
org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:26)
at
org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:27)
at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:271)
at
org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:70)
at
org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:50)
at org.junit.runners.ParentRunner$3.run(ParentRunner.java:238)
at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:63)
at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:236)
at org.junit.runners.ParentRunner.access$000(ParentRunner.java:53)
at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:229)
at org.junit.runners.ParentRunner.run(ParentRunner.java:309)
at
org.apache.maven.surefire.junit4.JUnit4Provider.execute(JUnit4Provider.java:252)
at
org.apache.maven.surefire.junit4.JUnit4Provider.executeTestSet(JUnit4Provider.java:141)
at
org.apache.maven.surefire.junit4.JUnit4Provider.invoke(JUnit4Provider.java:112)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at
org.apache.maven.surefire.util.ReflectionUtils.invokeMethodWithArray(ReflectionUtils.java:189)
at
org.apache.maven.surefire.booter.ProviderFactory$ProviderProxy.invoke(ProviderFactory.java:165)
at
org.apache.maven.surefire.booter.ProviderFactory.invokeProvider(ProviderFactory.java:85)
at
org.apache.maven.surefire.booter.ForkedBooter.runSuitesInProcess(ForkedBooter.java:115)
at
org.apache.maven.surefire.booter.ForkedBooter.main(ForkedBooter.java:75)
Running org.apache.tajo.storage.TestCompressionStorages
2014-04-10 06:30:05,165 INFO [main] compress.CodecPool
(CodecPool.java:getCompressor(108)) - Got brand-new compressor [.gz]
2014-04-10 06:30:05,409 INFO [main] compress.CodecPool
(CodecPool.java:getDecompressor(137)) - Got brand-new decompressor [.gz]
2014-04-10 06:30:06,052 INFO [main] compress.CodecPool
(CodecPool.java:getDecompressor(137)) - Got brand-new decompressor [.bz2]
2014-04-10 06:30:06,662 INFO [main] compress.CodecPool
(CodecPool.java:getDecompressor(137)) - Got brand-new decompressor [.deflate]
2014-04-10 06:30:06,905 INFO [main] compress.CodecPool
(CodecPool.java:getCompressor(151)) - Got brand-new compressor [.bz2]
2014-04-10 06:30:07,653 INFO [main] compress.CodecPool
(CodecPool.java:getDecompressor(179)) - Got brand-new decompressor [.bz2]
2014-04-10 06:30:07,653 INFO [main] compress.CodecPool
(CodecPool.java:getDecompressor(179)) - Got brand-new decompressor [.bz2]
2014-04-10 06:30:07,653 INFO [main] compress.CodecPool
(CodecPool.java:getDecompressor(179)) - Got brand-new decompressor [.bz2]
2014-04-10 06:30:07,654 INFO [main] compress.CodecPool
(CodecPool.java:getDecompressor(179)) - Got brand-new decompressor [.bz2]
2014-04-10 06:30:07,995 INFO [main] compress.CodecPool
(CodecPool.java:getCompressor(151)) - Got brand-new compressor [.deflate]
2014-04-10 06:30:08,291 INFO [main] compress.CodecPool
(CodecPool.java:getDecompressor(179)) - Got brand-new decompressor [.deflate]
2014-04-10 06:30:08,292 INFO [main] compress.CodecPool
(CodecPool.java:getDecompressor(179)) - Got brand-new decompressor [.deflate]
2014-04-10 06:30:08,292 INFO [main] compress.CodecPool
(CodecPool.java:getDecompressor(179)) - Got brand-new decompressor [.deflate]
2014-04-10 06:30:08,292 INFO [main] compress.CodecPool
(CodecPool.java:getDecompressor(179)) - Got brand-new decompressor [.deflate]
Tests run: 18, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 5.468 sec
Running org.apache.tajo.storage.TestVTuple
Tests run: 6, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.002 sec
Running org.apache.tajo.storage.parquet.TestReadWrite
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.066 sec
Running org.apache.tajo.storage.parquet.TestSchemaConverter
Tests run: 2, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.002 sec
Running org.apache.tajo.storage.TestTupleComparator
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0 sec
Running org.apache.tajo.storage.TestMergeScanner
2014-04-10 06:30:09,151 WARN [main] storage.AbstractStorageManager
(AbstractStorageManager.java:<init>(86)) - does not support block metadata.
('dfs.datanode.hdfs-blocks-metadata.enabled')
Tests run: 6, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 1.387 sec
comp, 1 pages, encodings: [PLAIN, RLE, BIT_PACKED]
Apr 10, 2014 6:29:24 AM INFO: parquet.hadoop.ColumnChunkPageWriteStore: written
27B for [col7] FLOAT: 1 values, 10B raw, 10B comp, 1 pages, encodings: [PLAIN,
RLE, BIT_PACKED]
Apr 10, 2014 6:29:24 AM INFO: parquet.hadoop.ColumnChunkPageWriteStore: written
31B for [col8] DOUBLE: 1 values, 14B raw, 14B comp, 1 pages, encodings: [PLAIN,
RLE, BIT_PACKED]
Apr 10, 2014 6:29:24 AM INFO: parquet.hadoop.ColumnChunkPageWriteStore: written
34B for [col9] BINARY: 1 values, 17B raw, 17B comp, 1 pages, encodings: [PLAIN,
RLE, BIT_PACKED]
Apr 10, 2014 6:29:24 AM INFO: parquet.hadoop.ColumnChunkPageWriteStore: written
34B for [col10] BINARY: 1 values, 17B raw, 17B comp, 1 pages, encodings:
[PLAIN, RLE, BIT_PACKED]
Apr 10, 2014 6:29:24 AM INFO: parquet.hadoop.ColumnChunkPageWriteStore: written
31B for [col11] BINARY: 1 values, 14B raw, 14B comp, 1 pages, encodings:
[PLAIN, RLE, BIT_PACKED]
Apr 10, 2014 6:29:24 AM INFO: parquet.hadoop.ParquetFileReader: reading another
1 footers
Apr 10, 2014 6:29:24 AM INFO: parquet.hadoop.InternalParquetRecordReader:
RecordReader initialized will read a total of 1 records.
Apr 10, 2014 6:29:24 AM INFO: parquet.hadoop.InternalParquetRecordReader: at
row 0. reading next block
Apr 10, 2014 6:29:24 AM INFO: parquet.hadoop.InternalParquetRecordReader: block
read in memory in 1 ms. row count = 1
Apr 10, 2014 6:29:24 AM INFO: parquet.hadoop.InternalParquetRecordWriter:
Flushing mem store to file. allocated memory: 34,044,142
Apr 10, 2014 6:29:24 AM INFO: parquet.hadoop.ColumnChunkPageWriteStore: written
40,031B for [id] INT32: 10,000 values, 40,008B raw, 40,008B comp, 1 pages,
encodings: [PLAIN, RLE, BIT_PACKED]
Apr 10, 2014 6:29:24 AM INFO: parquet.hadoop.ColumnChunkPageWriteStore: written
80,031B for [age] INT64: 10,000 values, 80,008B raw, 80,008B comp, 1 pages,
encodings: [PLAIN, RLE, BIT_PACKED]
Apr 10, 2014 6:29:24 AM INFO: parquet.hadoop.ColumnChunkPageWriteStore: written
40,031B for [score] FLOAT: 10,000 values, 40,008B raw, 40,008B comp, 1 pages,
encodings: [PLAIN, RLE, BIT_PACKED]
Apr 10, 2014 6:29:24 AM INFO: parquet.hadoop.ParquetFileReader: reading another
1 footers
Apr 10, 2014 6:29:24 AM INFO: parquet.hadoop.InternalParquetRecordReader:
RecordReader initialized will read a total of 10000 records.
Apr 10, 2014 6:29:24 AM INFO: parquet.hadoop.InternalParquetRecordReader: at
row 0. reading next block
Apr 10, 2014 6:29:24 AM INFO: parquet.hadoop.InternalParquetRecordReader: block
read in memory in 1 ms. row count = 10000
Apr 10, 2014 6:30:09 AM INFO: parquet.hadoop.InternalParquetRecordWriter:
Flushing mem store to file. allocated memory: 48,824,426
Apr 10, 2014 6:30:09 AM INFO: parquet.hadoop.ColumnChunkPageWriteStore: written
24B for [myboolean] BOOLEAN: 1 values, 7B raw, 7B comp, 1 pages, encodings:
[PLAIN, RLE, BIT_PACKED]
Apr 10, 2014 6:30:09 AM INFO: parquet.hadoop.ColumnChunkPageWriteStore: written
27B for [mybit] INT32: 1 values, 10B raw, 10B comp, 1 pages, encodings: [PLAIN,
RLE, BIT_PACKED]
Apr 10, 2014 6:30:09 AM INFO: parquet.hadoop.ColumnChunkPageWriteStore: written
28B for [mychar] BINARY: 1 values, 11B raw, 11B comp, 1 pages, encodings:
[PLAIN, RLE, BIT_PACKED]
Apr 10, 2014 6:30:09 AM INFO: parquet.hadoop.ColumnChunkPageWriteStore: written
27B for [myint2] INT32: 1 values, 10B raw, 10B comp, 1 pages, encodings:
[PLAIN, RLE, BIT_PACKED]
Apr 10, 2014 6:30:09 AM INFO: parquet.hadoop.ColumnChunkPageWriteStore: written
27B for [myint4] INT32: 1 values, 10B raw, 10B comp, 1 pages, encodings:
[PLAIN, RLE, BIT_PACKED]
Apr 10, 2014 6:30:09 AM INFO: parquet.hadoop.ColumnChunkPageWriteStore: written
31B for [myint8] INT64: 1 values, 14B raw, 14B comp, 1 pages, encodings:
[PLAIN, RLE, BIT_PACKED]
Apr 10, 2014 6:30:09 AM INFO: parquet.hadoop.ColumnChunkPageWriteStore: written
27B for [myfloat4] FLOAT: 1 values, 10B raw, 10B comp, 1 pages, encodings:
[PLAIN, RLE, BIT_PACKED]
Apr 10, 2014 6:30:09 AM INFO: parquet.hadoop.ColumnChunkPageWriteStore: written
31B for [myfloat8] DOUBLE: 1 values, 14B raw, 14B comp, 1 pages, encodings:
[PLAIN, RLE, BIT_PACKED]
Apr 10, 2014 6:30:09 AM INFO: parquet.hadoop.ColumnChunkPageWriteStore: written
32B for [mytext] BINARY: 1 values, 15B raw, 15B comp, 1 pages, encodings:
[PLAIN, RLE, BIT_PACKED]
Apr 10, 2014 6:30:09 AM INFO: parquet.hadoop.ColumnChunkPageWriteStore: written
32B for [myblob] BINARY: 1 values, 15B raw, 15B comp, 1 pages, encodings:
[PLAIN, RLE, BIT_PACKED]
Apr 10, 2014 6:30:09 AM INFO: parquet.hadoop.ParquetFileReader: reading another
1 footers
Apr 10, 2014 6:30:09 AM INFO: parquet.hadoop.InternalParquetRecordReader:
RecordReader initialized will read a total of 1 records.
Apr 10, 2014 6:30:09 AM INFO: parquet.hadoop.InternalParquetRecordReader: at
row 0. reading next block
Apr 10, 2014 6:30:09 AM INFO: parquet.hadoop.InternalParquetRecordReader: block
read in memory in 0 ms. row count = 1
Apr 10, 2014 6:30:10 AM INFO: parquet.hadoop.InternalParquetRecordWriter:
Flushing mem store to file. allocated memory: 36,271,037
Apr 10, 2014 6:30:10 AM INFO: parquet.hadoop.ColumnChunkPageWriteStore: written
40,031B for [id] INT32: 10,000 values, 40,008B raw, 40,008B comp, 1 pages,
encodings: [PLAIN, RLE, BIT_PACKED]
Apr 10, 2014 6:30:10 AM INFO: parquet.hadoop.ColumnChunkPageWriteStore: written
31B for [file] BINARY: 10,000 values, 12B raw, 12B comp, 1 pages, encodings:
[RLE, PLAIN_DICTIONARY, BIT_PACKED], dic { 1 entries, 11B raw, 1B comp}
Apr 10, 2014 6:30:10 AM INFO: parquet.hadoop.ColumnChunkPageWriteStore: written
31B for [name] BINARY: 10,000 values, 12B raw, 12B comp, 1 pages, encodings:
[RLE, PLAIN_DICTIONARY, BIT_PACKED], dic { 1 entries, 10B raw, 1B comp}
Apr 10, 2014 6:30:10 AM INFO: parquet.hadoop.ColumnChunkPageWriteStore: written
31B for [age] INT64: 10,000 values, 12B raw, 12B comp, 1 pages, encodings:
[RLE, PLAIN_DICTIONARY, BIT_PACKED], dic { 1 entries, 8B raw, 1B comp}
Apr 10, 2014 6:30:10 AM INFO: parquet.hadoop.InternalParquetRecordWriter:
Flushing mem store to file. allocated memory: 36,271,037
Apr 10, 2014 6:30:10 AM INFO: parquet.hadoop.ColumnChunkPageWriteStore: written
40,031B for [id] INT32: 10,000 values, 40,008B raw, 40,008B comp, 1 pages,
encodings: [PLAIN, RLE, BIT_PACKED]
Apr 10, 2014 6:30:10 AM INFO: parquet.hadoop.ColumnChunkPageWriteStore: written
31B for [file] BINARY: 10,000 values, 12B raw, 12B comp, 1 pages, encodings:
[RLE, PLAIN_DICTIONARY, BIT_PACKED], dic { 1 entries, 11B raw, 1B comp}
Apr 10, 2014 6:30:10 AM INFO: parquet.hadoop.ColumnChunkPageWriteStore: written
31B for [name] BINARY: 10,000 values, 12B raw, 12B comp, 1 pages, encodings:
[RLE, PLAIN_DICTIONARY, BIT_PACKED], dic { 1 entries, 10B raw, 1B comp}
Apr 10, 2014 6:30:10 AM INFO: parquet.hadoop.ColumnChunkPageWriteStore: written
31B for [age] INT64: 10,000 values, 12B raw, 12B comp, 1 pages, encodings:
[RLE, PLAIN_DICTIONARY, BIT_PACKED], dic { 1 entries, 8B raw, 1B comp}
Apr 10, 2014 6:30:10 AM INFO: parquet.hadoop.ParquetFileReader: reading another
1 footers
Apr 10, 2014 6:30:10 AM INFO: parquet.hadoop.InternalParquetRecordReader:
RecordReader initialized will read a total of 10000 records.
Apr 10, 2014 6:30:10 AM INFO: parquet.hadoop.InternalParquetRecordReader: at
row 0. reading next block
Apr 10, 2014 6:30:10 AM INFO: parquet.hadoop.InternalParquetRecordReader: block
read in memory in 0 ms. row count = 10000
Apr 10, 2014 6:30:10 AM INFO: parquet.hadoop.ParquetFileReader: reading another
1 footers
Apr 10, 2014 6:30:10 AM INFO: parquet.hadoop.InternalParquetRecordReader:
RecordReader initialized will read a total of 10000 records.
Apr 10, 2014 6:30:10 AM INFO: parquet.hadoop.InternalParquetRecordReader: at
row 0. reading next block
Apr 10, 2014 6:30:10 AM INFO: parquet.hadoop.InternalParquetRecordReader: block
read in memory in 0 ms. row count = 10000
Results :
Failed tests:
testGetSplitWithBlockStorageLocationsBatching(org.apache.tajo.storage.TestStorageManager):
Values should be different. Actual: -1
Tests run: 136, Failures: 1, Errors: 0, Skipped: 0
[INFO] ------------------------------------------------------------------------
[INFO] Reactor Summary:
[INFO]
[INFO] Tajo Main ......................................... SUCCESS [50.628s]
[INFO] Tajo Project POM .................................. SUCCESS [2.601s]
[INFO] Tajo Common ....................................... SUCCESS [9.178s]
[INFO] Tajo Algebra ...................................... SUCCESS [4.810s]
[INFO] Tajo Rpc .......................................... SUCCESS [21.513s]
[INFO] Tajo Catalog Common ............................... SUCCESS [6.853s]
[INFO] Tajo Catalog Client ............................... SUCCESS [1.359s]
[INFO] Tajo Catalog Server ............................... SUCCESS [11.479s]
[INFO] Tajo Storage ...................................... FAILURE [59.930s]
[INFO] Tajo Core PullServer .............................. SKIPPED
[INFO] Tajo Client ....................................... SKIPPED
[INFO] Tajo JDBC Driver .................................. SKIPPED
[INFO] Tajo Core Backend ................................. SKIPPED
[INFO] Tajo Core ......................................... SKIPPED
[INFO] Tajo Catalog Drivers .............................. SKIPPED
[INFO] Tajo Catalog ...................................... SKIPPED
[INFO] Tajo Distribution ................................. SKIPPED
[INFO] ------------------------------------------------------------------------
[INFO] BUILD FAILURE
[INFO] ------------------------------------------------------------------------
[INFO] Total time: 2:49.630s
[INFO] Finished at: Thu Apr 10 06:30:10 UTC 2014
[INFO] Final Memory: 31M/116M
[INFO] ------------------------------------------------------------------------
[ERROR] Failed to execute goal
org.apache.maven.plugins:maven-surefire-plugin:2.12.4:test (default-test) on
project tajo-storage: There are test failures.
[ERROR]
[ERROR] Please refer to
<https://builds.apache.org/job/Tajo-0.8.0-build/ws/tajo-storage/target/surefire-reports>
for the individual test results.
[ERROR] -> [Help 1]
[ERROR]
[ERROR] To see the full stack trace of the errors, re-run Maven with the -e
switch.
[ERROR] Re-run Maven using the -X switch to enable full debug logging.
[ERROR]
[ERROR] For more information about the errors and possible solutions, please
read the following articles:
[ERROR] [Help 1]
http://cwiki.apache.org/confluence/display/MAVEN/MojoFailureException
[ERROR]
[ERROR] After correcting the problems, you can resume the build with the command
[ERROR] mvn <goals> -rf :tajo-storage
Build step 'Execute shell' marked build as failure
Updating TAJO-743
Updating TAJO-717
